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 25KB

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