https://www.ory.sh/ logo
Join Slack
Powered by
Having trouble getting Kratos to send messages in ...
# ory-selfhosting
q
Having trouble getting Kratos to send messages in my local development. Using Mailhog for this (saw Kratos uses this in CI). I can use Mailhog using 
nodemailer
in my application code but not Kratos. It looks like Kratos is prematurely QUIT'ing the process? Not sure... Any help/pointers appreciated
Copy code
courier:
  smtp:
    connection_uri: <smtp://test:test@mailhog:1025/?disable_starttls=true>
    from_address: <mailto:noreply@takaro.io|noreply@takaro.io>
    from_name: Takaro
Logs:
Copy code
kratos_1             | time=2023-07-27T18:53:23Z level=error msg=Unable to send email using SMTP connection. audience=application error=map[message:unencrypted connection stack_trace:stack trace could not be recovered from error type *errors.errorString] message_from=noreply@takaro.io message_id=58add558-8930-4ce4-a2db-182179f75123 message_nid=b8cba482-c1e1-4957-8150-f6e32940d80f service_name=Ory Kratos service_version=v0.11.1 smtp_server=mailhog:1025 smtp_ssl_enabled=false
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] Received 14 bytes: 'EHLO mailhog\r\n'
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] [PROTO: ESTABLISH] Processing line: EHLO mailhog
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] [PROTO: ESTABLISH] In state 1, got command 'EHLO', args 'mailhog'
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] [PROTO: ESTABLISH] In ESTABLISH state
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] [PROTO: ESTABLISH] Got EHLO command, switching to MAIL state
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] Sent 19 bytes: '250-Hello mailhog\r\n'
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] Sent 16 bytes: '250-PIPELINING\r\n'
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] Sent 16 bytes: '250 AUTH PLAIN\r\n'
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] Received 6 bytes: 'QUIT\r\n'
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] [PROTO: MAIL] Processing line: QUIT
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] [PROTO: MAIL] In state 6, got command 'QUIT', args ''
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] [PROTO: MAIL] Got QUIT verb, staying in MAIL state
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] Sent 9 bytes: '221 Bye\r\n'
mailhog              | 2023/07/27 18:53:23 [SMTP 172.16.238.13:51696] Session ended
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Starting session
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: INVALID] Started session, switching to ESTABLISH state
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Sent 35 bytes: '220 mailhog.example ESMTP MailHog\r\n'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Received 14 bytes: 'EHLO mailhog\r\n'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: ESTABLISH] Processing line: EHLO mailhog
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: ESTABLISH] In state 1, got command 'EHLO', args 'mailhog'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: ESTABLISH] In ESTABLISH state
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: ESTABLISH] Got EHLO command, switching to MAIL state
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Sent 19 bytes: '250-Hello mailhog\r\n'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Sent 16 bytes: '250-PIPELINING\r\n'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Sent 16 bytes: '250 AUTH PLAIN\r\n'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Received 6 bytes: 'QUIT\r\n'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: MAIL] Processing line: QUIT
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: MAIL] In state 6, got command 'QUIT', args ''
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] [PROTO: MAIL] Got QUIT verb, staying in MAIL state
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Sent 9 bytes: '221 Bye\r\n'
mailhog              | 2023/07/27 18:53:24 [SMTP 172.16.238.13:51708] Session ended
Updated to Kratos 1.0.0 Took the SMTP connection URL from Kratos' CI and adjusted the smtp hostname from 127.0.0.1 to 'mailhog' (since I'm running it all in containers) Still getting similar logs... Kratos seemingly prematurely ending the SMTP connection and not showing a reason in the logs even though I've set it to trace level 😞
Copy code
log:
  level: trace
From 
nodemailer
I can send messages fine, I'm comparing the logs between when Kratos sends mails and when my app sends them and they seem similar EXCEPT that it looks like Kratos doesn't send the auth details. (I don't see 
Received 29 bytes: 'AUTH PLAIN AHRlc3QAdGVzdA==\r\n'
in the logs when Kratos sends a mail) Sorry for the ping but I'm starting to think this is a bug... Should I make a Github issue? @high-optician-2097
Copy code
NODEMAILER

mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Starting session
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: INVALID] Started session, switching to ESTABLISH state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 35 bytes: '220 mailhog.example ESMTP MailHog\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Received 18 bytes: 'EHLO [127.0.0.1]\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: ESTABLISH] Processing line: EHLO [127.0.0.1]
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: ESTABLISH] In state 1, got command 'EHLO', args '[127.0.0.1]'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: ESTABLISH] In ESTABLISH state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: ESTABLISH] Got EHLO command, switching to MAIL state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 23 bytes: '250-Hello [127.0.0.1]\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 16 bytes: '250-PIPELINING\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 16 bytes: '250 AUTH PLAIN\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Received 29 bytes: 'AUTH PLAIN AHRlc3QAdGVzdA==\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] Processing line: AUTH PLAIN AHRlc3QAdGVzdA==
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] In state 6, got command 'AUTH', args 'PLAIN AHRlc3QAdGVzdA=='
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] In MAIL state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] Got AUTH command, staying in MAIL state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] Got PLAIN authentication: AHRlc3QAdGVzdA==
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 31 bytes: '235 Authentication successful\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Received 31 bytes: 'MAIL FROM:<noreply@takaro.io>\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] Processing line: MAIL FROM:<noreply@takaro.io>
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] In state 6, got command 'MAIL', args 'FROM:<noreply@takaro.io>'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] In MAIL state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: MAIL] Got MAIL command, switching to RCPT state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 33 bytes: '250 Sender <mailto:noreply@takaro.io|noreply@takaro.io> ok\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Received 30 bytes: 'RCPT TO:<user35@example.com>\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] Processing line: RCPT TO:<user35@example.com>
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] In state 7, got command 'RCPT', args 'TO:<user35@example.com>'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] In RCPT state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] Got RCPT command
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 37 bytes: '250 Recipient <mailto:user35@example.com|user35@example.com> ok\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Received 6 bytes: 'DATA\r\n'
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] Processing line: DATA
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] In state 7, got command 'DATA', args ''
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] In RCPT state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] [PROTO: RCPT] Got DATA command, switching to DATA state
mailhog              | 2023/07/28 06:04:17 [SMTP 172.16.238.253:60240] Sent 37 bytes: '354 End data with <CR><LF>.<CR><LF>\r\n'


KRATOS

mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] Starting session
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] [PROTO: INVALID] Started session, switching to ESTABLISH state
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] Sent 35 bytes: '220 mailhog.example ESMTP MailHog\r\n'
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] Received 16 bytes: 'EHLO localhost\r\n'
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] [PROTO: ESTABLISH] Processing line: EHLO localhost
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] [PROTO: ESTABLISH] In state 1, got command 'EHLO', args 'localhost'
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] [PROTO: ESTABLISH] In ESTABLISH state
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] [PROTO: ESTABLISH] Got EHLO command, switching to MAIL state
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] Sent 21 bytes: '250-Hello localhost\r\n'
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] Sent 16 bytes: '250-PIPELINING\r\n'
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] Sent 16 bytes: '250 AUTH PLAIN\r\n'
mailhog              | 2023/07/28 06:08:23 [SMTP 172.16.238.6:49786] Received 6 bytes: 'QUIT\r\n'
Confirmed now I think, disabled auth on mailhog, changed my smtp url to 
connection_uri: "<smtp://mailhog:1025/?disable_starttls=true>"
and now the mails are getting through... This is fine for a dev env but I do hope that production config will support authentication on the mailserver 😮
34 Views
Open in Slack
PreviousNext
Powered by