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

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