mjl- / mox

modern full-featured open source secure mail server for low-maintenance self-hosted email
https://www.xmox.nl
MIT License
3.55k stars 100 forks source link

Invalid Addresses 550 5.1.1 no such user #189

Open mattfbacon opened 3 months ago

mattfbacon commented 3 months ago

I tried to reply to a group email and got this error. There is nothing special about the email address, just <name>@<example>.org. Also I have sent mail to this person as the primary recipient before, and it worked, but in this case they were a CC recipient (i.e., not the first RCPT TO in the transaction) and I guess that may have led to this issue.

I don't want to post the specific address here but I am happy to email it to the maintainers if necessary.

mjl- commented 3 months ago

Is this is a message sent with the mox webmail client, or with a separate email client? (It could be webmail-related). I suppose you can't easily test sending to this group address? If you do have a way to reproduce this (perhaps with "mox localserve"), that would help. Do you have logging (perhaps even including tracing) of the delivery attempt? It may very well not help debugging this case, but you could configure a "keep info about messages retired from queue" period to keep some information about deliveries around (see https://www.xmox.nl/config/#cfg-domains-conf-Accounts-x-KeepRetiredMessagePeriod).

We should also keep the option open that the "550 5.1.1" response is a way of the remote server to say "go away" when it decides a message looks like spam. Whether that's an option depends on the remote server.

mattfbacon commented 3 months ago

It is with fairemail. With the mox webmail I was able to send the message successfully. But the mox client doesn't use smtp, right?

To be clear, the error is from mox, not from any remote server. As far as I can tell the message doesn't even get to the point of contacting any remote servers, though I may be misunderstanding the SMTP log.

I have logs, but they may not be of use without the redacted email addresses:

Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="RC: EHLO dummy.faircode.eu\r\n" pkg=smtpserver cid=1907c5c86b9 delta=612.885834ms
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=ehlo code=250 ecode= duration="22.68µs" cid=1907c5c86b9 delta="95.84µs"
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="LS: 250-vps2.felle.nz\r\n250-PIPELINING\r\n250-SIZE 104857600\r\n250-REQUIRETLS\r\n250-AUTH SCRAM-SHA-256-PLUS SCRAM-SHA-256 SCRAM-SHA-1-PLUS SCRAM-SHA-1 CRAM-MD5 PLAIN LOGIN\r\n250-FUTURERELEASE 5184000 2024-09-02T06:10:14Z\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250-LIMITS RCPTMAX=1000\r\n250 SMTPUTF8\r\n" pkg=smtpserver cid=1907c5c86b9 delta="30.561µs"
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="RC: AUTH CRAM-MD5\r\n" pkg=smtpserver cid=1907c5c86b9 delta=214.107239ms
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="LS: 334 redacted\r\n" pkg=smtpserver cid=1907c5c86b9 delta="65.2µs"
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="RC: redacted\r\n" pkg=smtpserver cid=1907c5c86b9 delta=298.04627ms
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=debug m="cram-md5 auth" pkg=smtpserver address=matt@felle.nz cid=1907c5c86b9 delta="40.72µs"
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=auth code=235 ecode=2.7.0 duration=298.200591ms cid=1907c5c86b9 delta="95.801µs" username=matt@felle.nz
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="LS: 235 2.7.0 nice\r\n" pkg=smtpserver cid=1907c5c86b9 delta="9.6µs" username=matt@felle.nz
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="RC: MAIL FROM:<matt@felle.nz>\r\n" pkg=smtpserver cid=1907c5c86b9 delta=210.61426ms username=matt@felle.nz
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=mail code=250 ecode=2.1.0 duration="35.88µs" cid=1907c5c86b9 delta="87.12µs" username=matt@felle.nz
Jul 04 06:10:14 vps2.felle.nz mox[4289]: l=trace m="LS: 250 2.1.0 looking good\r\n" pkg=smtpserver cid=1907c5c86b9 delta="14.8µs" username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=trace m="RC: RCPT TO:<redacted1>\r\n" pkg=smtpserver cid=1907c5c86b9 delta=304.469026ms username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=rcpt code=250 ecode=2.1.0 duration="36µs" cid=1907c5c86b9 delta="78.041µs" username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=trace m="LS: 250 2.1.0 now on the list\r\n" pkg=smtpserver cid=1907c5c86b9 delta="9.52µs" username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=trace m="RC: RCPT TO:<redacted2>\r\n" pkg=smtpserver cid=1907c5c86b9 delta=306.607317ms username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=debug m="smtp command result" err="no such user" pkg=smtpserver kind=submission cmd=rcpt code=550 ecode=5.1.1 duration="67.761µs" cid=1907c5c86b9 delta="112.561µs" username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=trace m="LS: 550 5.1.1 no such user (redacted)\r\n" pkg=smtpserver cid=1907c5c86b9 delta="11.44µs" username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=trace m="RC: RCPT TO:<redacted3>\r\n" pkg=smtpserver cid=1907c5c86b9 delta=410.186218ms username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=rcpt code=250 ecode=2.1.0 duration="31.72µs" cid=1907c5c86b9 delta="74.08µs" username=matt@felle.nz
Jul 04 06:10:15 vps2.felle.nz mox[4289]: l=trace m="LS: 250 2.1.0 now on the list\r\n" pkg=smtpserver cid=1907c5c86b9 delta="21.88µs" username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=trace m="RC: RCPT TO:<redacted4>\r\n" pkg=smtpserver cid=1907c5c86b9 delta=306.428037ms username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=rcpt code=250 ecode=2.1.0 duration="19.64µs" cid=1907c5c86b9 delta="60.44µs" username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=trace m="LS: 250 2.1.0 now on the list\r\n" pkg=smtpserver cid=1907c5c86b9 delta="9.56µs" username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=trace m="RC: RSET\r\n" pkg=smtpserver cid=1907c5c86b9 delta=310.493299ms username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=rset code=250 ecode=2.0.0 duration="12.441µs" cid=1907c5c86b9 delta="51.721µs" username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=trace m="LS: 250 2.0.0 all clear\r\n" pkg=smtpserver cid=1907c5c86b9 delta="10.08µs" username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=trace m="RC: NOOP\r\n" pkg=smtpserver cid=1907c5c86b9 delta=330.28669ms username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=noop code=250 ecode=2.0.0 duration="27.2µs" cid=1907c5c86b9 delta="87.96µs" username=matt@felle.nz
Jul 04 06:10:16 vps2.felle.nz mox[4289]: l=trace m="LS: 250 2.0.0 alrighty\r\n" pkg=smtpserver cid=1907c5c86b9 delta="12.6µs" username=matt@felle.nz
Jul 04 06:10:17 vps2.felle.nz mox[4289]: l=trace m="RC: QUIT\r\n" pkg=smtpserver cid=1907c5c86b9 delta=277.745116ms username=matt@felle.nz
Jul 04 06:10:17 vps2.felle.nz mox[4289]: l=debug m="smtp command result" pkg=smtpserver kind=submission cmd=quit code=221 ecode=2.0.0 duration="42.2µs" cid=1907c5c86b9 delta="85.921µs" username=matt@felle.nz
Jul 04 06:10:17 vps2.felle.nz mox[4289]: l=trace m="LS: 221 2.0.0 okay thanks bye\r\n" pkg=smtpserver cid=1907c5c86b9 delta="11.96µs" username=matt@felle.nz
Jul 04 06:10:17 vps2.felle.nz mox[4289]: l=info m="connection closed" pkg=smtpserver cid=1907c5c86b9 delta="100.08µs" username=matt@felle.nz
mjl- commented 2 months ago

(sorry for the delay)

Indeed I hadn't understood this is from an SMTP client submitting a message to mox. I followed the code paths, and it must be this line that was triggered:

https://github.com/mjl-/mox/blob/v0.0.11/smtpserver/server.go#L1667

The ErrAddressNotFound would be coming from LookupAddress, I think this line:

https://github.com/mjl-/mox/blob/v0.0.11/mox-/lookup.go#L73

From looking at the function I can't see many reasons for that error to be triggered. Could the address have a different capitalization than the address configured in the domain, with case-sensitivity enabled for the domain? Or does the recipient address contain the localpart-catchall-separator? Or is the recipient an alias (or one of the other recipients)? If you could send me the address privately, that may help to reproduce this locally.

mattfbacon commented 2 months ago

OK I emailed it.

I was not able to follow the code you sent very well, so maybe I am not understanding, but isn't that code for handling local addresses? I probably should have been clearer from the start: I was sending the email through my server, to multiple non-local recipients (some To, some CC) and the error was produced by one of the SMTP RCPT TO, which was one of the CC recipients.