cannot parse reply from rspamd: bad top object

[dotlambda]

I'm seeing many of these errors in journalctl:

rmilter[9968]: <6c7cb98904>; cannot parse reply from rspamd: bad top object                                                          
rmilter[9968]: <6c7cb98904>; rspamd; HTTP parser error: the on_body callback failed when rspamd reply

Is this normal?

(I'm using v2.1.1)

[phdoerfler]

I just checked on mine (running latest master with the quota policy server rule commented out) and watched a mail get delivered and handled by rmilter and rspamd just fine after a fresh reboot except for these errors in name resolution (which other than being logged didn't do any harm):

Feb 23 10:24:04 turtle rspamd[1145]: <f46034>; lua; rbl.lua:67: error looking up 20.11.188.131.zen.spamhaus.org: query timed out
Feb 23 10:24:04 turtle rspamd[1145]: <f46034>; lua; rbl.lua:67: error looking up 37.11.188.131.zen.spamhaus.org: query timed out
Feb 23 10:24:04 turtle rspamd[1145]: <f46034>; lua; rbl.lua:67: error looking up 4.1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.5.2.0.1.0.0.0.a.8.3.6.0.1.0.0.2.zen.spamhaus.org: query timed out

A second email did not even show these errors but went through just fine. Here is the complete log for that email. May you find it helpful:

Feb 23 10:26:22 turtle postfix/smtpd[1161]: connect from mx.example2.com[123.123.123.123]
Feb 23 10:26:22 turtle rmilter[729]: <b078c5e011>; accepted connection from mail.example.com; client: 123.123.123.123:60788 (mx.example2.com)
Feb 23 10:26:22 turtle postfix/smtpd[1161]: Anonymous TLS connection established from mx.example2.com[123.123.123.123]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Feb 23 10:26:22 turtle postfix/smtpd[1161]: 270BF1603D5: client=mx.example2.com[123.123.123.123]
Feb 23 10:26:22 turtle rmilter[729]: <b078c5e011>; mlfi_data: queue id: <270BF1603D5>
Feb 23 10:26:22 turtle postfix/cleanup[1204]: 270BF1603D5: message-id=<a2915c5b5eafcb38627f18c7ae58b09d@example2.com>
Feb 23 10:26:22 turtle rmilter[729]: <b078c5e011>; mlfi_eom: tempfile=/tmp/msg.XXCzfHJ6, size=2447
Feb 23 10:26:22 turtle rmilter[729]: <b078c5e011>; spamdscan: start scanning message on /run/rspamd/rspamd.sock
Feb 23 10:26:22 turtle rspamd[1145]: <383826>; task; accept_socket: accepted connection from /run/rspamd/rspamd.sock port 0, task ptr: 0000000001FD07B0
Feb 23 10:26:22 turtle rspamd[1145]: <383826>; task; rspamd_message_parse: loaded message; id: <a2915c5b5eafcb38627f18c7ae58b09d@example2.com>; queue-id: <270BF1603D5>; size: 2447; checksum: <78189116d6a0d619827ba77f5789b059>
Feb 23 10:26:22 turtle rspamd[1145]: <383826>; task; fuzzy_generate_commands: <a2915c5b5eafcb38627f18c7ae58b09d@example2.com>, part is shorter than 100 bytes (77 bytes), skip fuzzy check
Feb 23 10:26:23 turtle rspamd[1145]: <383826>; task; bayes_classify: skip classification as ham class has not enough learns: 0, 200 required
Feb 23 10:26:23 turtle rspamd[1145]: <383826>; task; rspamd_task_write_log: id: <a2915c5b5eafcb38627f18c7ae58b09d@example2.com>, qid: <270BF1603D5>, ip: 123.123.123.123, from: <user@example2.com>, (default: F (no action): [-0.50/15.00] [R_DKIM_ALLOW(-0.20){example2.com;},R_SPF_ALLOW(-0.20){+mx;},MIME_GOOD(-0.10){text/plain;},DMARC_NA(0.00){example2.com;},FROM_EQ_ENVFROM(0.00){},FROM_HAS_DN(0.00){},MID_RHS_MATCH_FROM(0.00){},PREVIOUSLY_DELIVERED(0.00){user@example.com;},RCPT_COUNT_1(0.00){},RCVD_COUNT_4(0.00){},RCVD_IN_DNSWL_MED(0.00){22.11.188.131.list.dnswl.org : 127.0.11.2;},TO_DN_NONE(0.00){},TO_MATCH_ENVRCPT_ALL(0.00){}]), len: 2447, time: 1056.992ms real, 6.467ms virtual, dns req: 19, digest: <78189116d6a0d619827ba77f5789b059>, rcpts: <user@example.com>, mime_rcpt: <user@example.com>
Feb 23 10:26:23 turtle rspamd[1145]: <383826>; task; rspamd_protocol_http_reply: regexp statistics: 126 pcre regexps scanned, 4 regexps matched, 270 regexps total, 25 regexps cached, 22.07k bytes scanned using pcre, 22.07k bytes scanned total
Feb 23 10:26:23 turtle rmilter[729]: <b078c5e011>; spamdscan: finish scanning message on /run/rspamd/rspamd.sock
Feb 23 10:26:23 turtle rmilter[729]: <b078c5e011>; spamdscan: scan, time: 1.059, server: /run/rspamd/rspamd.sock, metric: default: [-0.500 / 15.000], symbols: R_SPF_ALLOW(-0.20)[+mx], TO_DN_NONE(0.00)[], FROM_HAS_DN(0.00)[], PREVIOUSLY_DELIVERED(0.00)[user@example.com], FROM_EQ_ENVFROM(0.00)[], R_DKIM_ALLOW(-0.20)[example2.com], RCPT_COUNT_1(0.00)[], RCVD_COUNT_4(0.00)[], TO_MATCH_ENVRCPT_ALL(0.00)[], MID_RHS_MATCH_FROM(0.00)[], DMARC_NA(0.00)[example2.com], RCVD_IN_DNSWL_MED(0.00)[22.11.188.131.list.dnswl.org : 127.0.11.2], MIME_GOOD(-0.10)[text/plain]
Feb 23 10:26:23 turtle rmilter[729]: <b078c5e011>; msg done: queue_id: <270BF1603D5>; message id: <a2915c5b5eafcb38627f18c7ae58b09d@example2.com>; ip: 123.123.123.123; from: <user@example2.com>; rcpt: <user@example.com> (1 total); user: unauthorized; spam scan: no spam; virus scan: skipped, no av servers; dkim: not signed, ignored
Feb 23 10:26:23 turtle postfix/qmgr[1075]: 270BF1603D5: from=<user@example2.com>, size=2532, nrcpt=1 (queue active)
Feb 23 10:26:23 turtle postfix/smtpd[1161]: disconnect from mx.example2.com[123.123.123.123] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Feb 23 10:26:23 turtle dovecot[1139]: lmtp(1207): Connect from local
Feb 23 10:26:23 turtle dovecot[1139]: lmtp(user@example.com): GKXsD0/sj1q3BAAAqbrqQQ: sieve: msgid=<a2915c5b5eafcb38627f18c7ae58b09d@example2.com>: stored mail into mailbox 'Testmehl'
Feb 23 10:26:23 turtle postfix/lmtp[1206]: 270BF1603D5: to=<user@example.com>, orig_to=<user@example.com>, relay=mail.example.com[private/dovecot-lmtp], delay=1.1, delays=1.1/0.01/0.01/0.01, dsn=2.0.0, status=sent (250 2.0.0 <user@example.com> GKXsD0/sj1q3BAAAqbrqQQ Saved)
Feb 23 10:26:23 turtle dovecot[1139]: lmtp(1207): Disconnect from local: Successful quit
Feb 23 10:26:23 turtle postfix/qmgr[1075]: 270BF1603D5: removed

[dotlambda]

I commented out that line as well. Otherwise, no email gets delivered at all. I didn't try rebooting yet. But without rebooting, each mail sent to my server reproducably shows that error. They are being delivered though.

[phdoerfler]

For comparison I'm on nixos-17.09-small using:

$ rspamd --version
Rspamd daemon version 1.4.3

Do you happen to run a newer rspamd?

[dotlambda]

Newer version on unstable:

$ rspamd --version                                                                                                                       
Rspamd daemon version 1.6.5
$ nix-info                                                                                                                               
system: "x86_64-linux", multi-user?: yes, version: nix-env (Nix) 1.11.16, channels(rschuetz): "", channels(root): "nixos-18.03pre129076.831ef4756e3", nixpkgs: /nix/var/nix/profiles/per-user/root/channels/nixos/nixpkgs

[r-raymond]

@dotlambda The new version of rspamd does not work with rmitler anymore (it absorbs all the features into rspamd). We'll have to rewrite the code to use rspamd. I guess that should happen within the next month before it becomes stable. Any help is welcome (see #25)

[telent]

I don't pretend to understand rspamd or postfix or SNM so I am the last person you should trust with your mail setup, but here is my workaround which appears to work for me and appears to filter spam into the Junk folder. I added this to the bottom of my module (i.e. if you were using the "quick start" you would paste this gubbins into it before the final closing } )

This is brutal and messy and there are better ways to do it: this is just a hack to reduce the number of emails I'm getting about hair loss and photo editing until we can converge on one.

  services.rmilter.enable = lib.mkOverride 0 false;
  services.rmilter.postfix.enable = lib.mkOverride 0 false;
  services.postfix.extraConfig = ''
    smtpd_milters = inet:localhost:11332
    # skip mail without checks if something goes wrong
    milter_default_action = accept
  '';

  services.rspamd = {
    workers.normal.enable = false;
    socketActivation = false;
  };
  services.rspamd.workers."rspamd_proxy" = {
    enable = true;
    bindSockets = ["localhost:11332"];
    type = "proxy";
    extraConfig = ''
      milter = yes;
    spam_header = "X-Spam"; # Use the specific spam header

    upstream "local" {
      self_scan = yes;
      default = yes;
      hosts = "localhost";
    }
    '';
  }; 
}