You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

rspamd_stats.pl 32KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011
  1. #!/usr/bin/env perl
  2. use 5.010;
  3. use Data::Dumper;
  4. use Getopt::Long;
  5. use Pod::Usage;
  6. use Time::Local;
  7. use IO::Handle;
  8. use warnings;
  9. use strict;
  10. my @symbols_search;
  11. my @symbols_exclude;
  12. my @symbols_bidirectional;
  13. my @symbols_groups;
  14. my @symbols_ignored;
  15. my %groups;
  16. my $reject_score = 15.0;
  17. my $junk_score = 6.0;
  18. my $diff_alpha = 0.1;
  19. my $correlations = 0;
  20. my $nrelated = 10;
  21. my $log_file = "";
  22. my $search_pattern = "";
  23. my $startTime = "";
  24. my $endTime;
  25. my $num_logs;
  26. my $exclude_logs = 0;
  27. my $man = 0;
  28. my $json = 0;
  29. my $help = 0;
  30. # Associate file extensions with decompressors
  31. my %decompressor = (
  32. 'bz2' => 'bzip2 -cd',
  33. 'gz' => 'gzip -cd',
  34. 'xz' => 'xz -cd',
  35. 'zst' => 'zstd -cd',
  36. );
  37. GetOptions(
  38. "reject-score|r=f" => \$reject_score,
  39. "junk-score|j=f" => \$junk_score,
  40. "symbol|s=s@" => \@symbols_search,
  41. "symbol-bidir|S=s@" => \@symbols_bidirectional,
  42. "exclude|X=s@" => \@symbols_exclude,
  43. "ignore=s@" => \@symbols_ignored,
  44. "group|g=s@" => \@symbols_groups,
  45. "log|l=s" => \$log_file,
  46. "alpha-score|alpha|a=f" => \$diff_alpha,
  47. "correlations|c" => \$correlations,
  48. "nrelated=i" => \$nrelated,
  49. "search-pattern=s" => \$search_pattern,
  50. "start=s" => \$startTime,
  51. "end=s" => \$endTime,
  52. "num-logs|n=i" => \$num_logs,
  53. "exclude-logs|x=i" => \$exclude_logs,
  54. "json|j" => \$json,
  55. "help|?" => \$help,
  56. "man" => \$man
  57. ) or pod2usage(2);
  58. pod2usage(1) if $help;
  59. pod2usage( -exitval => 0, -verbose => 2 ) if $man;
  60. # Global vars
  61. my $total = 0;
  62. my $total_spam = 0;
  63. my $total_junk = 0;
  64. my $junk_symbols = 0;
  65. my $spam_symbols = 0;
  66. my $ham_symbols = 0;
  67. my $ham_spam_change = 0;
  68. my $ham_junk_change = 0;
  69. my %sym_res;
  70. my $rspamd_log;
  71. my $enabled = 0;
  72. my $log_file_num = 1;
  73. my $spinner_update_time = 0;
  74. my %action;
  75. my %timeStamp;
  76. my %scanTime = (
  77. max => 0,
  78. total => 0,
  79. );
  80. my %bidir_match;
  81. foreach ( $startTime, $endTime ) { $_ = &normalized_time($_) }
  82. # Convert bidirectional symbols
  83. foreach my $s (@symbols_bidirectional) {
  84. $bidir_match{$s} = {
  85. spam => "${s}_SPAM",
  86. ham => "${s}_HAM",
  87. };
  88. push @symbols_search, $s unless grep /^$s$/, @symbols_search;
  89. }
  90. # Deal with groups
  91. my $group_id = 0;
  92. foreach my $g (@symbols_groups) {
  93. my @symbols = split /,/, $g;
  94. my $group_name = "group$group_id";
  95. foreach my $s (@symbols) {
  96. $groups{$s} = $group_name;
  97. push @symbols_search, $s unless grep /^$s$/, @symbols_search;
  98. }
  99. }
  100. @symbols_search = '.*'
  101. unless @symbols_search;
  102. if ( $log_file eq '-' || $log_file eq '' ) {
  103. $rspamd_log = \*STDIN;
  104. &ProcessLog();
  105. }
  106. elsif ( -d "$log_file" ) {
  107. my $log_dir = "$log_file";
  108. my @logs = &GetLogfilesList($log_dir);
  109. # Process logs
  110. foreach (@logs) {
  111. my $ext = (/[^.]+\.?([^.]*?)$/)[0];
  112. my $dc = $decompressor{$ext} || 'cat';
  113. open( $rspamd_log, "-|", "$dc $log_dir/$_" )
  114. or die "cannot execute $dc $log_dir/$_ : $!";
  115. printf { interactive(*STDERR) } "\033[J Parsing log files: [%d/%d] %s\033[G", $log_file_num++, scalar @logs,
  116. $_;
  117. $spinner_update_time = 0; # Force spinner update
  118. &spinner;
  119. &ProcessLog;
  120. close($rspamd_log)
  121. or warn "cannot close $dc $log_dir/$_: $!";
  122. }
  123. print { interactive(*STDERR) } "\033[J\033[G"; # Progress indicator clean-up
  124. }
  125. else {
  126. my $ext = ( $log_file =~ /[^.]+\.?([^.]*?)$/ )[0];
  127. my $dc = $decompressor{$ext} || 'cat';
  128. open( $rspamd_log, "-|", "$dc $log_file" )
  129. or die "cannot execute $dc $log_file : $!";
  130. $spinner_update_time = 0; # Force spinner update
  131. &spinner;
  132. &ProcessLog();
  133. }
  134. my $total_ham = $total - ( $total_spam + $total_junk );
  135. if ($json) {
  136. print "{";
  137. &Summary();
  138. print '"symbols":{';
  139. &SymbolsStat();
  140. print "}}\n";
  141. }
  142. else {
  143. &SymbolsStat();
  144. &Summary();
  145. }
  146. exit;
  147. sub IsIgnored {
  148. my ($sym) = @_;
  149. foreach my $ex (@symbols_ignored) {
  150. if ( $sym =~ /^$ex$/ ) {
  151. return 1;
  152. }
  153. }
  154. return 0;
  155. }
  156. sub GenRelated {
  157. my ( $htb, $target_sym ) = @_;
  158. my @result;
  159. my $i = 0;
  160. foreach my $sym ( sort { $htb->{$b} <=> $htb->{$a} } keys %{$htb} ) {
  161. if ( $sym ne $target_sym ) {
  162. my @elt = ( $sym, $htb->{$sym} );
  163. push @result, \@elt;
  164. $i++;
  165. }
  166. last if $i > $nrelated;
  167. }
  168. return \@result;
  169. }
  170. sub StringifyRelated {
  171. my ( $ar, $total ) = @_;
  172. return
  173. join( "\n", ( map { sprintf "\t%s(%s: %.1f%%)", $_->[0], $_->[1], $_->[1] / ( $total * 1.0 ) * 100.0 } @{$ar} ) );
  174. }
  175. sub SymbolsStat {
  176. if ( $total > 0 ) {
  177. my $has_comma = 0;
  178. while ( my ( $s, $r ) = each(%sym_res) ) {
  179. if ( $r->{hits} > 0 ) {
  180. my $th = $r->{hits};
  181. my $sh = $r->{spam_hits};
  182. my $jh = $r->{junk_hits};
  183. my $hh = $r->{hits} - $sh - $jh;
  184. my ( $htp, $stp, $jtp );
  185. $htp = $hh * 100.0 / $total_ham if $total_ham != 0;
  186. $stp = $sh * 100.0 / $total_spam if $total_spam != 0;
  187. $jtp = $jh * 100.0 / $total_junk if $total_junk != 0;
  188. if ($json) {
  189. if ($has_comma) {
  190. print ",";
  191. }
  192. else {
  193. $has_comma = 1;
  194. }
  195. print "\"$s\":{";
  196. JsonObjectElt( "avg_weight", $r->{'weight'}, "%.4f" );
  197. print ",";
  198. JsonObjectElt( "hits", $th, "%d" );
  199. print ",";
  200. JsonObjectElt( "hits_percentage", $th / $total, "%.4f" );
  201. print ",";
  202. JsonObjectElt( "spam_hits", $sh, "%d" );
  203. print ",";
  204. JsonObjectElt( "spam_to_total", $sh / $th, "%.4f" );
  205. print ",";
  206. JsonObjectElt( "spam_percentage", $stp / 100.0 || 0, "%.4f" );
  207. print ",";
  208. JsonObjectElt( "ham_hits", $hh, "%d" );
  209. print ",";
  210. JsonObjectElt( "ham_to_total", $hh / $th, "%.4f" );
  211. print ",";
  212. JsonObjectElt( "ham_percentage", $htp / 100.0 || 0, "%.4f" );
  213. print ",";
  214. JsonObjectElt( "junk_hits", $jh, "%d" );
  215. print ",";
  216. JsonObjectElt( "junk_to_total", $jh / $th, "%.4f" );
  217. print ",";
  218. JsonObjectElt( "junk_percentage", $jtp / 100.0 || 0, "%.4f" );
  219. }
  220. else {
  221. printf "%s avg. weight %.3f, hits %d(%.3f%%):
  222. Ham %7.3f%%, %6d/%-6d (%7.3f%%)
  223. Spam %7.3f%%, %6d/%-6d (%7.3f%%)
  224. Junk %7.3f%%, %6d/%-6d (%7.3f%%)
  225. ", $s, $r->{weight} / $r->{hits}, $th, ( $th / $total * 100 ),
  226. ( $hh / $th * 100 ), $hh, $total_ham, ( $htp or 0 ),
  227. ( $sh / $th * 100 ), $sh, $total_spam, ( $stp or 0 ),
  228. ( $jh / $th * 100 ), $jh, $total_junk, ( $jtp or 0 );
  229. }
  230. my ( $schp, $jchp );
  231. $schp = $r->{spam_change} / $total_spam * 100.0 if $total_spam;
  232. $jchp = $r->{junk_change} / $total_junk * 100.0 if $total_junk;
  233. if ( $r->{weight} != 0 ) {
  234. if ( !$json ) {
  235. if ( $r->{weight} > 0 ) {
  236. printf "
  237. Spam changes (ham/junk -> spam): %6d/%-6d (%7.3f%%)
  238. Spam changes / total spam hits: %6d/%-6d (%7.3f%%)
  239. Junk changes (ham -> junk): %6d/%-6d (%7.3f%%)
  240. Junk changes / total junk hits: %6d/%-6d (%7.3f%%)
  241. ",
  242. $r->{spam_change}, $th, ( $r->{spam_change} / $th * 100 ),
  243. $r->{spam_change}, $total_spam, ( $schp or 0 ),
  244. $r->{junk_change}, $th, ( $r->{junk_change} / $th * 100 ),
  245. $r->{junk_change}, $total_junk, ( $jchp or 0 );
  246. }
  247. else {
  248. printf "
  249. Spam changes (spam -> junk/ham): %6d/%-6d (%7.3f%%)
  250. Spam changes / total spam hits : %6d/%-6d (%7.3f%%)
  251. Junk changes (junk -> ham) : %6d/%-6d (%7.3f%%)
  252. Junk changes / total junk hits : %6d/%-6d (%7.3f%%)
  253. ",
  254. $r->{spam_change}, $th, ( $r->{spam_change} / $th * 100 ),
  255. $r->{spam_change}, $total_spam, ( $schp or 0 ),
  256. $r->{junk_change}, $th, ( $r->{junk_change} / $th * 100 ),
  257. $r->{junk_change}, $total_junk, ( $jchp or 0 );
  258. }
  259. }
  260. else {
  261. print ",";
  262. JsonObjectElt( "spam_change", $r->{spam_change}, "%.4f" );
  263. print ",";
  264. JsonObjectElt( "junk_change", $r->{junk_change}, "%.4f" );
  265. }
  266. }
  267. if ($correlations) {
  268. my $spam_related = GenRelated( $r->{symbols_met_spam}, $s );
  269. my $junk_related = GenRelated( $r->{symbols_met_junk}, $s );
  270. my $ham_related = GenRelated( $r->{symbols_met_ham}, $s );
  271. if ( !$json ) {
  272. print "Correlations report:\n";
  273. while ( my ( $cs, $hits ) = each %{ $r->{corr} } ) {
  274. my $corr_prob = $r->{'hits'} / $total;
  275. my $merged_hits = 0;
  276. if ( $r->{symbols_met_spam}->{$cs} ) {
  277. $merged_hits += $r->{symbols_met_spam}->{$cs};
  278. }
  279. if ( $r->{symbols_met_junk}->{$cs} ) {
  280. $merged_hits += $r->{symbols_met_junk}->{$cs};
  281. }
  282. if ( $r->{symbols_met_ham}->{$cs} ) {
  283. $merged_hits += $r->{symbols_met_ham}->{$cs};
  284. }
  285. if ( $merged_hits > 0 ) {
  286. printf "Probability of %s when %s fires: %.3f\n", $cs, $s,
  287. ( ( $merged_hits / $total ) / $corr_prob );
  288. }
  289. }
  290. print "Related symbols report:\n";
  291. printf "Top related in spam:\n %s\n", StringifyRelated( $spam_related, $r->{spam_hits} );
  292. printf "Top related in junk:\n %s\n", StringifyRelated( $junk_related, $r->{junk_hits} );
  293. printf "Top related in ham:\n %s\n",
  294. StringifyRelated( $ham_related, $r->{hits} - $r->{spam_hits} - $r->{junk_hits} );
  295. }
  296. else {
  297. print ",";
  298. print "\"correllations\":{";
  299. my $has_comma_ = 0;
  300. while ( my ( $cs, $hits ) = each %{ $r->{corr} } ) {
  301. if ($has_comma_) {
  302. print ",";
  303. }
  304. else {
  305. $has_comma_ = 1;
  306. }
  307. my $corr_prob = $hits / $total;
  308. my $sym_prob = $r->{hits} / $total;
  309. JsonObjectElt( $cs, ( $corr_prob / $sym_prob ), "%.4f" );
  310. }
  311. print "}";
  312. }
  313. }
  314. print "}" if $json;
  315. }
  316. else {
  317. print "Symbol $s has not been met\n" if !$json;
  318. }
  319. print '-' x 80 . "\n" if !$json;
  320. }
  321. }
  322. }
  323. sub Summary() {
  324. if ( !$json ) {
  325. print "
  326. === Summary ", '=' x 68, "
  327. Messages scanned: $total";
  328. printf " [ %s / %s ]
  329. ", $timeStamp{'start'}, $timeStamp{'end'}
  330. if defined $timeStamp{'start'};
  331. say '';
  332. printf "%11s: %6.2f%%, %d\n", $_, 100 * $action{$_} / $total, $action{$_} for sort keys %action;
  333. say '';
  334. printf "scan time min/avg/max = %.2f/%.2f/%.2f s
  335. ", $scanTime{'min'} / 1000, ($total) ? $scanTime{'total'} / $total / 1000 : undef, $scanTime{'max'} / 1000
  336. if exists $scanTime{'min'};
  337. say '=' x 80;
  338. }
  339. else {
  340. JsonObjectElt( "total", $total, "%d" );
  341. print ",";
  342. if ( defined $timeStamp{'start'} ) {
  343. JsonObjectElt( "start", $timeStamp{'start'} );
  344. print ",";
  345. }
  346. if ( defined $timeStamp{'end'} ) {
  347. JsonObjectElt( "end", $timeStamp{'end'} );
  348. print ",";
  349. }
  350. print "\"actions\":{";
  351. my $has_comma = 0;
  352. foreach my $a ( sort keys %action ) {
  353. if ($has_comma) {
  354. print ",";
  355. }
  356. else {
  357. $has_comma = 1;
  358. }
  359. JsonObjectElt( $a, $action{$a}, "%d" );
  360. }
  361. print "},";
  362. }
  363. }
  364. sub ProcessRelated {
  365. my ( $symbols, $target, $source ) = @_;
  366. foreach my $s ( @{$symbols} ) {
  367. $s =~ /^([^\(]+)(\(([^\)]+)\))?/;
  368. my $sym_name = $1;
  369. my $sym_score = 0;
  370. if ( $groups{$sym_name} ) {
  371. $sym_name = $groups{$sym_name};
  372. }
  373. next if ( $source eq $sym_name );
  374. next if IsIgnored($sym_name);
  375. if ($2) {
  376. $sym_score = $3 * 1.0;
  377. if ( abs($sym_score) < $diff_alpha ) {
  378. next;
  379. }
  380. my $bm = $bidir_match{$sym_name};
  381. if ($bm) {
  382. if ( $sym_score >= 0 ) {
  383. $sym_name = $bm->{'spam'};
  384. }
  385. else {
  386. $sym_name = $bm->{'ham'};
  387. }
  388. }
  389. }
  390. if ( exists( $target->{$sym_name} ) ) {
  391. $target->{$sym_name}++;
  392. }
  393. else {
  394. $target->{$sym_name} = 1;
  395. }
  396. }
  397. }
  398. sub ProcessLog {
  399. my ( $ts_format, @line ) = &log_time_format($rspamd_log);
  400. while () {
  401. last if eof $rspamd_log;
  402. $_ = (@line) ? shift @line : <$rspamd_log>;
  403. if ( !$enabled && ( $search_pattern eq "" || /$search_pattern/ ) ) {
  404. $enabled = 1;
  405. }
  406. next if !$enabled;
  407. if (/^.*rspamd_task_write_log.*$/) {
  408. &spinner;
  409. my $ts;
  410. if ( $ts_format eq 'syslog' ) {
  411. $ts = syslog2iso( join ' ', ( split /\s+/ )[ 0 .. 2 ] );
  412. }
  413. elsif ( $ts_format eq 'syslog5424' ) {
  414. /^([0-9-]+)T([0-9:]+)/;
  415. $ts = "$1 $2";
  416. }
  417. else {
  418. $ts = join ' ', ( split /\s+/ )[ 0 .. 1 ];
  419. }
  420. next if ( $ts lt $startTime );
  421. next if ( defined $endTime && $ts gt $endTime );
  422. if ( $_ !~
  423. /\(([^()]+)\): \[(NaN|-?\d+(?:\.\d+)?)\/(-?\d+(?:\.\d+)?)\]\s+\[([^\]]+)\].+? time: (\d+\.\d+)ms real/ )
  424. {
  425. #print "BAD: $_\n";
  426. next;
  427. }
  428. my @symbols = split /(?:\{[^}]*\})?(?:$|,)/, $4;
  429. my $scan_time = $5;
  430. my $act = $1;
  431. my $score = $2 * 1.0;
  432. my $skip = 0;
  433. foreach my $ex (@symbols_exclude) {
  434. my @found = grep { /^$ex/ } @symbols;
  435. if ( scalar(@found) > 0 ) {
  436. $skip = 1;
  437. last;
  438. }
  439. }
  440. next if ( $skip != 0 );
  441. if ( defined( $timeStamp{'end'} ) ) {
  442. $timeStamp{'end'} = $ts if ( $ts gt $timeStamp{'end'} );
  443. }
  444. else {
  445. $timeStamp{'end'} = $ts;
  446. }
  447. if ( defined( $timeStamp{'start'} ) ) {
  448. $timeStamp{'start'} = $ts if ( $ts lt $timeStamp{'start'} );
  449. }
  450. else {
  451. $timeStamp{'start'} = $ts;
  452. }
  453. $scanTime{'min'} = $scan_time if ( !exists $scanTime{'min'} || $scanTime{'min'} > $scan_time );
  454. $scanTime{'max'} = $scan_time if ( $scanTime{'max'} < $scan_time );
  455. $scanTime{'total'} += $scan_time;
  456. $action{$act}++;
  457. $total++;
  458. if ( $score >= $reject_score ) {
  459. $total_spam++;
  460. }
  461. elsif ( $score >= $junk_score ) {
  462. $total_junk++;
  463. }
  464. my @sym_names;
  465. foreach my $s (@symbols_search) {
  466. my @selected = grep /$s/, @symbols;
  467. if ( scalar(@selected) > 0 ) {
  468. foreach my $sym (@selected) {
  469. $sym =~ /^([^\(]+)(\(([^\)]+)\))?/;
  470. my $sym_name = $1;
  471. my $sym_score = 0;
  472. my $orig_name = $sym_name;
  473. if ($2) {
  474. $sym_score = $3 * 1.0;
  475. if ( abs($sym_score) < $diff_alpha ) {
  476. next;
  477. }
  478. my $bm = $bidir_match{$sym_name};
  479. if ($bm) {
  480. if ( $sym_score >= 0 ) {
  481. $sym_name = $bm->{'spam'};
  482. }
  483. else {
  484. $sym_name = $bm->{'ham'};
  485. }
  486. }
  487. }
  488. next if $orig_name !~ /^$s/;
  489. if ( $groups{$s} ) {
  490. # Replace with group
  491. $sym_name = $groups{$s};
  492. }
  493. push @sym_names, $sym_name;
  494. if ( !$sym_res{$sym_name} ) {
  495. $sym_res{$sym_name} = {
  496. hits => 0,
  497. spam_hits => 0,
  498. junk_hits => 0,
  499. spam_change => 0,
  500. junk_change => 0,
  501. weight => 0,
  502. corr => {},
  503. symbols_met_spam => {},
  504. symbols_met_ham => {},
  505. symbols_met_junk => {},
  506. };
  507. }
  508. my $r = $sym_res{$sym_name};
  509. $r->{hits}++;
  510. $r->{weight} += $sym_score;
  511. my $is_spam = 0;
  512. my $is_junk = 0;
  513. if ( $score >= $reject_score ) {
  514. $is_spam = 1;
  515. $r->{spam_hits}++;
  516. if ($correlations) {
  517. ProcessRelated( \@symbols, $r->{symbols_met_spam}, $sym_name );
  518. }
  519. }
  520. elsif ( $score >= $junk_score ) {
  521. $is_junk = 1;
  522. $r->{junk_hits}++;
  523. if ($correlations) {
  524. ProcessRelated( \@symbols, $r->{symbols_met_junk}, $sym_name );
  525. }
  526. }
  527. else {
  528. if ($correlations) {
  529. ProcessRelated( \@symbols, $r->{symbols_met_ham}, $sym_name );
  530. }
  531. }
  532. if ( $sym_score != 0 ) {
  533. my $score_without = $score - $sym_score;
  534. if ( $sym_score > 0 ) {
  535. if ( $is_spam && $score_without < $reject_score ) {
  536. $r->{spam_change}++;
  537. }
  538. if ( $is_junk && $score_without < $junk_score ) {
  539. $r->{junk_change}++;
  540. }
  541. }
  542. else {
  543. if ( !$is_spam && $score_without >= $reject_score ) {
  544. $r->{spam_change}++;
  545. }
  546. if ( !$is_junk && $score_without >= $junk_score ) {
  547. $r->{junk_change}++;
  548. }
  549. }
  550. }
  551. } # End foreach symbols selected
  552. }
  553. }
  554. if ($correlations) {
  555. foreach my $sym (@sym_names) {
  556. next if IsIgnored($sym);
  557. my $r = $sym_res{$sym};
  558. foreach my $corr_sym (@sym_names) {
  559. if ( $corr_sym ne $sym ) {
  560. if ( $r->{'corr'}->{$corr_sym} ) {
  561. $r->{'corr'}->{$corr_sym}++;
  562. }
  563. else {
  564. $r->{'corr'}->{$corr_sym} = 1;
  565. }
  566. }
  567. }
  568. } # End of correlations check
  569. }
  570. }
  571. }
  572. }
  573. sub JsonObjectElt() {
  574. my ( $k, $v ) = @_;
  575. my $f = defined $_[2] ? $_[2] : '%s';
  576. if ( $f eq "%s" ) {
  577. $f = "\"%s\"";
  578. }
  579. printf "\"%s\":$f", $k, $v;
  580. }
  581. sub GetLogfilesList {
  582. my ($dir) = @_;
  583. opendir( DIR, $dir ) or die $!;
  584. my $pattern = join( '|', keys %decompressor );
  585. my $re = qr/\.[0-9]+(?:\.(?:$pattern))?/;
  586. # Add unnumbered logs first
  587. my @logs =
  588. grep { -f "$dir/$_" && !/$re/ } readdir(DIR);
  589. # Add numbered logs
  590. rewinddir(DIR);
  591. push( @logs, ( sort numeric ( grep { -f "$dir/$_" && /$re/ } readdir(DIR) ) ) );
  592. closedir(DIR);
  593. # Select required logs and revers their order
  594. @logs =
  595. reverse splice( @logs, $exclude_logs, $num_logs ||= @logs - $exclude_logs );
  596. # Loop through array printing out filenames
  597. print { interactive(*STDERR) } "\nLog files to process:\n";
  598. foreach my $file (@logs) {
  599. print { interactive(*STDERR) } " $file\n";
  600. }
  601. print { interactive(*STDERR) } "\n";
  602. return @logs;
  603. }
  604. sub log_time_format {
  605. my $fh = shift;
  606. my ( $format, $line );
  607. while (<$fh>) {
  608. $line = $_;
  609. # 2017-08-08 00:00:01 #66984(
  610. # 2017-08-08 00:00:01.001 #66984(
  611. if (/^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d(\.\d{3})? #\d+\(/) {
  612. $format = 'rspamd';
  613. last;
  614. }
  615. # Aug 8 00:02:50 #66986(
  616. elsif (/^\w{3} (?:\s?\d|\d\d) \d\d:\d\d:\d\d #\d+\(/) {
  617. $format = 'syslog';
  618. last;
  619. }
  620. # Aug 8 00:02:50 hostname rspamd[66986]
  621. elsif (/^\w{3} (?:\s?\d|\d\d) \d\d:\d\d:\d\d \S+ rspamd\[\d+\]/) {
  622. $format = 'syslog';
  623. last;
  624. }
  625. # 2018-04-16T06:25:46.012590+02:00 rspamd rspamd[12968]
  626. elsif (/\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{1,6})?(Z|[-+]\d{2}:\d{2}) \S+ rspamd\[\d+\]/) {
  627. $format = 'syslog5424';
  628. last;
  629. }
  630. # Skip newsyslog messages
  631. # Aug 8 00:00:00 hostname newsyslog[63284]: logfile turned over
  632. elsif (/^\w{3} (?:\s?\d|\d\d) \d\d:\d\d:\d\d\ \S+ newsyslog\[\d+\]: logfile turned over$/) {
  633. next;
  634. }
  635. # Skip journalctl messages
  636. # -- Logs begin at Mon 2018-01-15 11:16:24 MSK, end at Fri 2018-04-27 09:10:30 MSK. --
  637. elsif (
  638. /^-- Logs begin at \w{3} \d{4}-\d\d-\d\d \d\d:\d\d:\d\d [A-Z]{3}, end at \w{3} \d{4}-\d\d-\d\d \d\d:\d\d:\d\d [A-Z]{3}\. --$/
  639. )
  640. {
  641. next;
  642. }
  643. else {
  644. print "Unknown log format\n";
  645. exit 1;
  646. }
  647. }
  648. return ( $format, $line );
  649. }
  650. sub normalized_time {
  651. return
  652. if !defined( $_ = shift );
  653. /^\d\d(?::\d\d){0,2}$/
  654. ? sprintf '%04d-%02d-%02d %s', 1900 + (localtime)[5], 1 + (localtime)[4], (localtime)[3], $_
  655. : $_;
  656. }
  657. sub numeric {
  658. $a =~ /\.(\d+)\./;
  659. my $a_num = $1;
  660. $b =~ /\.(\d+)\./;
  661. my $b_num = $1;
  662. $a_num <=> $b_num;
  663. }
  664. sub spinner {
  665. my @spinner = qw{/ - \ |};
  666. return
  667. if ( ( time - $spinner_update_time ) < 1 );
  668. $spinner_update_time = time;
  669. printf { interactive(*STDERR) } "%s\r", $spinner[ $spinner_update_time % @spinner ];
  670. select()->flush();
  671. }
  672. # Convert syslog timestamp to "ISO 8601 like" format
  673. # using current year as syslog does not record the year (nor the timezone)
  674. # or the last year if the guessed time is in the future.
  675. sub syslog2iso {
  676. my %month_map;
  677. @month_map{qw(Jan Feb Mar Apr May Jun Jul Aug Sep Oct Nov Dec)} = 0 .. 11;
  678. my ( $month, @t ) = $_[0] =~ m/^(\w{3}) \s\s? (\d\d?) \s (\d\d):(\d\d):(\d\d)/x;
  679. my $epoch =
  680. timelocal( ( reverse @t ), $month_map{$month}, 1900 + (localtime)[5] );
  681. sprintf '%04d-%02d-%02d %02d:%02d:%02d', 1900 + (localtime)[5] - ( $epoch > time ), $month_map{$month} + 1, @t;
  682. }
  683. ### Imported from IO::Interactive 1.022 Perl module
  684. sub is_interactive {
  685. ## no critic (ProhibitInteractiveTest)
  686. my ($out_handle) = ( @_, select ); # Default to default output handle
  687. # Not interactive if output is not to terminal...
  688. return 0 if not -t $out_handle;
  689. # If *ARGV is opened, we're interactive if...
  690. if ( tied(*ARGV) or defined( fileno(ARGV) ) ) { # this is what 'Scalar::Util::openhandle *ARGV' boils down to
  691. # ...it's currently opened to the magic '-' file
  692. return -t *STDIN if defined $ARGV && $ARGV eq '-';
  693. # ...it's at end-of-file and the next file is the magic '-' file
  694. return @ARGV > 0 && $ARGV[0] eq '-' && -t *STDIN if eof *ARGV;
  695. # ...it's directly attached to the terminal
  696. return -t *ARGV;
  697. }
  698. # If *ARGV isn't opened, it will be interactive if *STDIN is attached
  699. # to a terminal.
  700. else {
  701. return -t *STDIN;
  702. }
  703. }
  704. ### Imported from IO::Interactive 1.022 Perl module
  705. local ( *DEV_NULL, *DEV_NULL2 );
  706. my $dev_null;
  707. BEGIN {
  708. pipe *DEV_NULL, *DEV_NULL2
  709. or die "Internal error: can't create null filehandle";
  710. $dev_null = \*DEV_NULL;
  711. }
  712. ### Imported from IO::Interactive 1.022 Perl module
  713. sub interactive {
  714. my ($out_handle) = ( @_, \*STDOUT ); # Default to STDOUT
  715. return &is_interactive ? $out_handle : $dev_null;
  716. }
  717. __END__
  718. =head1 NAME
  719. rspamd_stats - analyze Rspamd rules by parsing log files
  720. =head1 SYNOPSIS
  721. rspamd_stats [options] [--symbol=SYM1 [--symbol=SYM2...]] [--log file]
  722. Options:
  723. --log=file log file or directory to read (stdin by default)
  724. --reject-score=score set reject threshold (15 by default)
  725. --junk-score=score set junk score (6.0 by default)
  726. --symbol=sym check specified symbol (perl regexps, '.*' by default)
  727. --alpha-score=score set ignore score for symbols (0.1 by default)
  728. --correlations enable correlations report
  729. --nrelated=integer show that amount of related symbols (10 by default)
  730. --search-pattern do not process input unless the desired pattern is found
  731. --start starting time (oldest) for log parsing
  732. --end ending time (newest) for log parsing
  733. --num-logs=integer number of recent logfiles to analyze (all files in the directory by default)
  734. --exclude-logs=integer number of latest logs to exclude (0 by default)
  735. --json print json output instead of human readable
  736. --help brief help message
  737. --man full documentation
  738. =head1 OPTIONS
  739. =over 8
  740. =item B<--log>
  741. Specifies log file or directory to read data from. If a directory is specified B<rspamd_stats> analyses files in the
  742. directory including known compressed file types. Number of log files can be limited using B<--num-logs> and
  743. B<--exclude-logs> options. This assumes that files in the log directory have B<newsyslog(8)>- or B<logrotate(8)>-like
  744. name format with numeric indexes. Files without indexes (generally it is merely one file) are considered the most
  745. recent and files with lower indexes are considered newer.
  746. =item B<--reject-score>
  747. Specifies the reject (spam) threshold.
  748. =item B<--junk-score>
  749. Specifies the junk (add header or rewrite subject) threshold.
  750. =item B<--alpha-score>
  751. Specifies the minimum score for a symbol to be considered by this script.
  752. =item B<--symbol>
  753. Add symbol or pattern (pcre format) to analyze.
  754. =item B<--num-logs>
  755. If set, limits number of analyzed logfiles in the directory to the specified value.
  756. =item B<--exclude-logs>
  757. Number of latest logs to exclude (0 by default).
  758. =item B<--correlations>
  759. Additionally print correlation rate for each symbol displayed. This routine calculates merely paired correlations
  760. between symbols.
  761. =item B<--search-pattern>
  762. Do not process input unless finding the specified regular expression. Useful to skip logs to a certain position.
  763. =item B<--exclude>
  764. Exclude log lines if certain symbols are fired (e.g. GTUBE). You may specify this option multiple time to skip multiple
  765. symbols.
  766. =item B<--start>
  767. Select log entries after this time. Format: C<YYYY-MM-DD HH:MM:SS> (can be truncated to any desired accuracy). If used
  768. with B<--end> select entries between B<--start> and B<--end>. The omitted date defaults to the current date if you
  769. supply the time.
  770. =item B<--end>
  771. Select log entries before this time. Format: C<YYYY-MM-DD HH:MM:SS> (can be truncated to any desired accuracy). If used
  772. with B<--start> select entries between B<--start> and B<--end>. The omitted date defaults to the current date if you
  773. supply the time.
  774. =item B<--help>
  775. Print a brief help message and exits.
  776. =item B<--man>
  777. Prints the manual page and exits.
  778. =back
  779. =head1 DESCRIPTION
  780. B<rspamd_stats> will read the given log file (or standard input) and provide statistics for the specified symbols:
  781. Symbol: BAYES_SPAM (weight 3.763) (381985 hits, 26.827%)
  782. Ham hits: 184557 (48.315%), total ham: 1095487 (ham with BAYES_SPAM: 16.847%)
  783. Spam hits: 15134 (3.962%), total spam: 16688 (spam with BAYES_SPAM: 90.688%)
  784. Junk hits: 182294 (47.723%), total junk: 311699 (junk with BAYES_SPAM: 58.484%)
  785. Spam changes (ham/junk -> spam): 7026 (1.839%), total percentage (changes / spam hits): 42.102%
  786. Junk changes (ham -> junk): 95192 (24.920%), total percentage (changes / junk hits): 30.540%
  787. Where there are the following attributes:
  788. =over 4
  789. =item *
  790. B<Weight>: average score for a symbols
  791. =item *
  792. B<Total hits>: total number of hits and percentage of symbol hits divided by total number of messages
  793. =item *
  794. B<HAM hits>: provides the following information about B<HAM> messages with the specified symbol (from left to right):
  795. =over 4
  796. =item 1.
  797. B<total symbol hits>: number of messages that has this symbol and are B<HAM>
  798. =item 2.
  799. B<ham percentage>: number of symbol hits divided by overall B<HAM> messages count
  800. =item 3.
  801. B<total ham hits>: overall number of B<HAM> messages
  802. =item 4.
  803. B<ham with symbol percentage>: percentage of number of hits with specified symbol in B<HAM> messages divided by total
  804. number of B<HAM> messages.
  805. =back
  806. =item *
  807. B<SPAM hits>: provides the following information about B<SPAM> messages - same as previous but for B<SPAM> class.
  808. =item *
  809. B<Junk hits>: provides the following information about B<Junk> messages - same as previous but for B<JUNK> class.
  810. =item *
  811. B<Spam changes>: displays data about how much messages switched their class because of the specific symbol weight.
  812. =item *
  813. B<Junk changes>: displays data about how much messages switched their class because of the specific symbol weight.
  814. =back
  815. =cut