Re: smtpd not passing data to rspamd
‐‐‐ Original Message ‐‐‐ On Thursday, August 22, 2019 1:45 PM, Thomas Smith wrote: > On Wed, Aug 21, 2019 at 23:14, Gilles Chehade wrote: > > > On Wed, Aug 21, 2019 at 08:06:58PM +, Thomas Smith wrote: > > > > > > ? Original Message ? > > > On Wednesday, August 21, 2019 8:28 AM, Gilles Chehade > > > wrote: > > > > > > > On Wed, Aug 21, 2019 at 03:22:39PM +, Thomas Smith wrote: > > > > > > > > > Hi, > > > > > I've setup filter-rspamd with rspamd. Both appear to be running > > > > > (smtpd and rspamd), I'm able to query rspamd's controller, access the > > > > > web UI; smtpd is processing and delivering mail as expected. > > > > > ps wuax | grep rspam > > > > > root 86736 0.0 0.4 45236 4008 ?? I 6:30AM 0:00.05 rspamd: main > > > > > process (rspamd) > > > > > _rspamd 32135 0.0 1.0 45344 10140 ?? S 6:30AM 0:00.23 rspamd: > > > > > rspamd_proxy process (localhost:11332) (rspamd) > > > > > _rspamd 4059 0.0 1.4 45688 14632 ?? S 6:30AM 0:01.63 rspamd: > > > > > controller process (localhost:11334) (rspamd) > > > > > _rspamd 16743 0.0 1.1 45384 11020 ?? S 6:30AM 0:00.33 rspamd: normal > > > > > process (localhost:11333) (rspamd) > > > > > _smtpd 32851 0.0 0.4 105520 3624 ?? I 6:56AM 0:00.01 > > > > > /usr/local/bin/filter-rspamd > > > > > _smtpd 68802 0.0 0.1 844 808 ?? Ip 6:56AM 0:00.00 sh -c > > > > > /usr/local/bin/filter-rspamd > > > > > However, I don't see any messages being processed by rspamd. Nor do I > > > > > see any indication that data is being sent to rspamd (nothing in the > > > > > logs, no stats appearing in the web UI). > > > > > > > > can you show full logs for a sample smtpd session that didn't go > > > > through rspamd ? > > > > > > Is this what you're looking for? > > > > > > Aug 21 12:42:22 host smtpd[71198]: 43e03ee20005a41f smtp connected > > > address=x.x.x.x host=***t.com > > > Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp message > > > msgid= size=338369 nrcpt=1 proto=ESMTP > > > Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp envelope > > > evpid= > > > from=> > > to=<***.***> > > > Aug 21 12:42:24 host smtpd[71198]: 43e03ee20005a41f smtp disconnected > > > reason=quit > > > > > > The msgid reveals some additional data, but the server doesn't manage > > > final delivery--emails are received and relayed only. So the additional > > > message information is related to the outbound (relayed) email but I can > > > provide if needed. > > > > > > > sorry but this is tricky to troubleshoot with so few logs, obfuscated on > > top of it :-/ > > I understand. That's kind of where I'm at, I just don't see anything that's > indicating what's not working. I've not had a need to troubleshoot OpenSMTPd > at this level before, so I'm probably not as familiar with debugging it as I > need to be. > > The output below (from my previous post) is what's generated with verbosity > enabled. I hadn't thought about the '-T' option until I did some reading > after receiving your email (looking to further increase logging verbosity). > However, when I enable '-T all' or '-T filters', smtpd still only returns > those four lines of logging output for inbound connections. > > What can I do to provide you with more useful information? > > Regarding the obfuscation, I can leave the msgid and evpid, but the source > and destination email addresses need to be obfuscated. I can't share the > emails publicly--but I can populate those with fake email addresses instead > if that'll help with clarity. > > Thank you for replying despite my previous post not being very useful. Alright, so I think I understand what's going on now. I prefer to log every to syslog, even when debugging. So for OpenSMTPd, this meant a couple of things for me. I added the '-v' flag to the daemon and restarted. This results in no debugging output to maillog. Or I run directly with `smtpd -Fv`. This results in no debugging output to syslog. However, if I run `smtpd -dv` from the CLI, I get full debugging output. This isn't what I would've expected when utilizing the verbose daemon flag or '-F' from the CLI. Am I seeing this correctly? In either case, I'll dig more into the filtering issue tonight and see if I can gather some more useful information regarding that problem.
Re: smtpd not passing data to rspamd
On Wed, Aug 21, 2019 at 23:14, Gilles Chehade wrote: > On Wed, Aug 21, 2019 at 08:06:58PM +, Thomas Smith wrote: >> >> ? Original Message ? >> On Wednesday, August 21, 2019 8:28 AM, Gilles Chehade >> wrote: >> >> > On Wed, Aug 21, 2019 at 03:22:39PM +, Thomas Smith wrote: >> > >> > > Hi, >> > > I've setup filter-rspamd with rspamd. Both appear to be running (smtpd >> > > and rspamd), I'm able to query rspamd's controller, access the web UI; >> > > smtpd is processing and delivering mail as expected. >> > > ps wuax | grep rspam >> > > root 86736 0.0 0.4 45236 4008 ?? I 6:30AM 0:00.05 rspamd: main process >> > > (rspamd) >> > > _rspamd 32135 0.0 1.0 45344 10140 ?? S 6:30AM 0:00.23 rspamd: >> > > rspamd_proxy process (localhost:11332) (rspamd) >> > > _rspamd 4059 0.0 1.4 45688 14632 ?? S 6:30AM 0:01.63 rspamd: controller >> > > process (localhost:11334) (rspamd) >> > > _rspamd 16743 0.0 1.1 45384 11020 ?? S 6:30AM 0:00.33 rspamd: normal >> > > process (localhost:11333) (rspamd) >> > > _smtpd 32851 0.0 0.4 105520 3624 ?? I 6:56AM 0:00.01 >> > > /usr/local/bin/filter-rspamd >> > > _smtpd 68802 0.0 0.1 844 808 ?? Ip 6:56AM 0:00.00 sh -c >> > > /usr/local/bin/filter-rspamd >> > > However, I don't see any messages being processed by rspamd. Nor do I >> > > see any indication that data is being sent to rspamd (nothing in the >> > > logs, no stats appearing in the web UI). >> > >> > can you show full logs for a sample smtpd session that didn't go through >> > rspamd ? >> >> Is this what you're looking for? >> >> Aug 21 12:42:22 host smtpd[71198]: 43e03ee20005a41f smtp connected >> address=x.x.x.x host=***t.com >> Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp message >> msgid= size=338369 nrcpt=1 proto=ESMTP >> Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp envelope >> evpid= >> from=>> to=<***.***> >> Aug 21 12:42:24 host smtpd[71198]: 43e03ee20005a41f smtp disconnected >> reason=quit >> >> The msgid reveals some additional data, but the server doesn't manage final >> delivery--emails are received and relayed only. So the additional message >> information is related to the outbound (relayed) email but I can provide if >> needed. >> > > sorry but this is tricky to troubleshoot with so few logs, obfuscated on > top of it :-/ I understand. That's kind of where I'm at, I just don't see anything that's indicating what's not working. I've not had a need to troubleshoot OpenSMTPd at this level before, so I'm probably not as familiar with debugging it as I need to be. The output below (from my previous post) is what's generated with verbosity enabled. I hadn't thought about the '-T' option until I did some reading after receiving your email (looking to further increase logging verbosity). However, when I enable '-T all' or '-T filters', smtpd still only returns those four lines of logging output for inbound connections. What can I do to provide you with more useful information? Regarding the obfuscation, I can leave the msgid and evpid, but the source and destination email addresses need to be obfuscated. I can't share the emails publicly--but I can populate those with fake email addresses instead if that'll help with clarity. Thank you for replying despite my previous post not being very useful.
Re: smtpd not passing data to rspamd
On Wed, Aug 21, 2019 at 08:06:58PM +, Thomas Smith wrote: > > ? Original Message ? > On Wednesday, August 21, 2019 8:28 AM, Gilles Chehade > wrote: > > > On Wed, Aug 21, 2019 at 03:22:39PM +, Thomas Smith wrote: > > > > > Hi, > > > I've setup filter-rspamd with rspamd. Both appear to be running (smtpd > > > and rspamd), I'm able to query rspamd's controller, access the web UI; > > > smtpd is processing and delivering mail as expected. > > > ps wuax | grep rspam > > > root 86736 0.0 0.4 45236 4008 ?? I 6:30AM 0:00.05 rspamd: main process > > > (rspamd) > > > _rspamd 32135 0.0 1.0 45344 10140 ?? S 6:30AM 0:00.23 rspamd: > > > rspamd_proxy process (localhost:11332) (rspamd) > > > _rspamd 4059 0.0 1.4 45688 14632 ?? S 6:30AM 0:01.63 rspamd: controller > > > process (localhost:11334) (rspamd) > > > _rspamd 16743 0.0 1.1 45384 11020 ?? S 6:30AM 0:00.33 rspamd: normal > > > process (localhost:11333) (rspamd) > > > _smtpd 32851 0.0 0.4 105520 3624 ?? I 6:56AM 0:00.01 > > > /usr/local/bin/filter-rspamd > > > _smtpd 68802 0.0 0.1 844 808 ?? Ip 6:56AM 0:00.00 sh -c > > > /usr/local/bin/filter-rspamd > > > However, I don't see any messages being processed by rspamd. Nor do I see > > > any indication that data is being sent to rspamd (nothing in the logs, no > > > stats appearing in the web UI). > > > > can you show full logs for a sample smtpd session that didn't go through > > rspamd ? > > Is this what you're looking for? > > Aug 21 12:42:22 host smtpd[71198]: 43e03ee20005a41f smtp connected > address=x.x.x.x host=***t.com > Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp message > msgid= size=338369 nrcpt=1 proto=ESMTP > Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp envelope > evpid= > from=> to=<***.***> > Aug 21 12:42:24 host smtpd[71198]: 43e03ee20005a41f smtp disconnected > reason=quit > > The msgid reveals some additional data, but the server doesn't manage final > delivery--emails are received and relayed only. So the additional message > information is related to the outbound (relayed) email but I can provide if > needed. > sorry but this is tricky to troubleshoot with so few logs, obfuscated on top of it :-/ -- Gilles Chehade @poolpOrg https://www.poolp.orgpatreon: https://www.patreon.com/gilles
Re: smtpd not passing data to rspamd
‐‐‐ Original Message ‐‐‐ On Wednesday, August 21, 2019 8:28 AM, Gilles Chehade wrote: > On Wed, Aug 21, 2019 at 03:22:39PM +, Thomas Smith wrote: > > > Hi, > > I've setup filter-rspamd with rspamd. Both appear to be running (smtpd and > > rspamd), I'm able to query rspamd's controller, access the web UI; smtpd is > > processing and delivering mail as expected. > > ps wuax | grep rspam > > root 86736 0.0 0.4 45236 4008 ?? I 6:30AM 0:00.05 rspamd: main process > > (rspamd) > > _rspamd 32135 0.0 1.0 45344 10140 ?? S 6:30AM 0:00.23 rspamd: rspamd_proxy > > process (localhost:11332) (rspamd) > > _rspamd 4059 0.0 1.4 45688 14632 ?? S 6:30AM 0:01.63 rspamd: controller > > process (localhost:11334) (rspamd) > > _rspamd 16743 0.0 1.1 45384 11020 ?? S 6:30AM 0:00.33 rspamd: normal > > process (localhost:11333) (rspamd) > > _smtpd 32851 0.0 0.4 105520 3624 ?? I 6:56AM 0:00.01 > > /usr/local/bin/filter-rspamd > > _smtpd 68802 0.0 0.1 844 808 ?? Ip 6:56AM 0:00.00 sh -c > > /usr/local/bin/filter-rspamd > > However, I don't see any messages being processed by rspamd. Nor do I see > > any indication that data is being sent to rspamd (nothing in the logs, no > > stats appearing in the web UI). > > can you show full logs for a sample smtpd session that didn't go through > rspamd ? Is this what you're looking for? Aug 21 12:42:22 host smtpd[71198]: 43e03ee20005a41f smtp connected address=x.x.x.x host=***t.com Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp message msgid= size=338369 nrcpt=1 proto=ESMTP Aug 21 12:42:23 host smtpd[71198]: 43e03ee20005a41f smtp envelope evpid= from=to=<***.***> Aug 21 12:42:24 host smtpd[71198]: 43e03ee20005a41f smtp disconnected reason=quit The msgid reveals some additional data, but the server doesn't manage final delivery--emails are received and relayed only. So the additional message information is related to the outbound (relayed) email but I can provide if needed.
Re: smtpd not passing data to rspamd
On Wed, Aug 21, 2019 at 03:22:39PM +, Thomas Smith wrote: > Hi, > > I've setup filter-rspamd with rspamd. Both appear to be running (smtpd and > rspamd), I'm able to query rspamd's controller, access the web UI; smtpd is > processing and delivering mail as expected. > > ps wuax | grep rspam > root 86736 0.0 0.4 45236 4008 ?? I 6:30AM0:00.05 rspamd: > main process (rspamd) > _rspamd 32135 0.0 1.0 45344 10140 ?? S 6:30AM0:00.23 rspamd: > rspamd_proxy process (localhost:11332) (rspamd) > _rspamd 4059 0.0 1.4 45688 14632 ?? S 6:30AM0:01.63 rspamd: > controller process (localhost:11334) (rspamd) > _rspamd 16743 0.0 1.1 45384 11020 ?? S 6:30AM0:00.33 rspamd: > normal process (localhost:11333) (rspamd) > _smtpd 32851 0.0 0.4 105520 3624 ?? I 6:56AM0:00.01 > /usr/local/bin/filter-rspamd > _smtpd 68802 0.0 0.1 844 808 ?? Ip 6:56AM0:00.00 sh -c > /usr/local/bin/filter-rspamd > > However, I don't see any messages being processed by rspamd. Nor do I see any > indication that data is being sent to rspamd (nothing in the logs, no stats > appearing in the web UI). > can you show full logs for a sample smtpd session that didnt go through rspamd ? > smtpd.conf: > filter "rspamd" proc-exec "/usr/local/bin/filter-rspamd" > listen on egress tls hostname $mx_domain pki $mx_domain filter "rspamd" > > 'smtpd -d -v': > debug: smtp: listen on x.x.x.x port 25 flags 0x2401 pki "" ca "" > > I also don't see any debug messages regarding rspamd. > your config is correct -- Gilles Chehade @poolpOrg https://www.poolp.orgpatreon: https://www.patreon.com/gilles
