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

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