conn_max_idle_time ignored leading to remote: QUIT error

[lukastribus]

Describe the bug

conn_max_idle_time is not respected, connections to Office 365 after successfully email delivery timeout with a forced error from the O365 side after 5 minutes, when it should exit gracefully (QUIT) after conn_max_idle_time time (default: 2.5 minutes).

Note: a SMTP "protocol error" like a QUIT error may negatively impacting IP address reputation, so this could have a more important impact than just an log error.

Steps to reproduce

Send an email to a Office 365 domain, observe logs looking for remote: QUIT error 5 minutes after delivery.

Log files

Mar 18 12:09:06 htznr2 maddy[501510]: submission: incoming message        {"msg_id":"7ee6b562","sender":"lukas@ltri.eu","src_host":"mail-il1-f178.google.com","src_ip":"209.85.166.178:57381","username":"lukas@ltri.eu"}
Mar 18 12:09:06 htznr2 maddy[501510]: submission: RCPT ok        {"msg_id":"7ee6b562","rcpt":"customerservice@example.com"}
Mar 18 12:09:06 htznr2 maddy[501510]: submission: accepted        {"msg_id":"7ee6b562"}
Mar 18 12:09:06 htznr2 maddy[501510]: [debug] remote: opening new connection        {"cache_ignored":false,"domain":"example.com","msg_id":"7ee6b562-65f820d2"}
Mar 18 12:09:06 htznr2 maddy[501510]: [debug] remote: trying        {"domain":"example.com","msg_id":"7ee6b562-65f820d2","remote_server":"example-com.mail.protection.outlook.com."}
Mar 18 12:09:06 htznr2 maddy[501510]: [debug] remote: connected        {"local_addr":"159.69.2.121:38204","msg_id":"7ee6b562-65f820d2","remote_addr":"52.101.68.12:25","remote_server":"example-com.mail.protection.outlook.com."}
Mar 18 12:09:07 htznr2 maddy[501510]: [debug] remote: returning connection 159.69.2.121:38204 for example-com.mail.protection.outlook.com. to pool        {"msg_id":"7ee6b562-65f820d2"}
Mar 18 12:09:07 htznr2 maddy[501510]: queue: delivered        {"attempt":1,"msg_id":"7ee6b562","rcpt":"customerservice@example.com"}
Mar 18 12:14:42 htznr2 maddy[501510]: remote: QUIT error        {"msg_id":"7ee6b562-65f820d2","reason":"SMTP error 451: Timeout waiting for client input [DB1PEPF000509F5.eurprd02.prod.outlook.com 2024-03-18T11:14:07.999Z 08DC46703A14496B]","remote_server":"example-com.mail.protection.outlook.com.","smtp_code":451,"smtp_enchcode":"4.7.0","smtp_msg":"example-com.mail.protection.outlook.com. said: Timeout waiting for client input [DB1PEPF000509F5.eurprd02.prod.outlook.com 2024-03-18T11:14:07.999Z 08DC46703A14496B]"}

Mar 18 12:48:20 htznr2 maddy[501510]: submission: handler error: EOF
Mar 18 12:48:50 htznr2 maddy[501510]: submission: handler error: EOF

Mar 18 13:03:50 htznr2 maddy[501510]: submission: incoming message        {"msg_id":"d8c05cb2","sender":"lukas@ltri.eu","src_host":"mail-io1-f50.google.com","src_ip":"209.85.166.50:47322","username":"lukas@ltri.eu"}
Mar 18 13:03:50 htznr2 maddy[501510]: submission: RCPT ok        {"msg_id":"d8c05cb2","rcpt":"lukas.tribus@example.org"}
Mar 18 13:03:50 htznr2 maddy[501510]: submission: accepted        {"msg_id":"d8c05cb2"}
Mar 18 13:03:50 htznr2 maddy[501510]: [debug] remote: opening new connection        {"cache_ignored":false,"domain":"example.org","msg_id":"d8c05cb2-65f82da6"}
Mar 18 13:03:50 htznr2 maddy[501510]: [debug] remote: trying        {"domain":"example.org","msg_id":"d8c05cb2-65f82da6","remote_server":"example-org.mail.protection.outlook.com."}
Mar 18 13:03:50 htznr2 maddy[501510]: [debug] remote: connected        {"local_addr":"159.69.2.121:38636","msg_id":"d8c05cb2-65f82da6","remote_addr":"52.101.73.21:25","remote_server":"example-org.mail.protection.outlook.com."}
Mar 18 13:03:51 htznr2 maddy[501510]: [debug] remote: returning connection 159.69.2.121:38636 for example-org.mail.protection.outlook.com. to pool        {"msg_id":"d8c05cb2-65f82da6"}
Mar 18 13:03:51 htznr2 maddy[501510]: queue: delivered        {"attempt":1,"msg_id":"d8c05cb2","rcpt":"lukas.tribus@example.org"}
Mar 18 13:09:42 htznr2 maddy[501510]: remote: QUIT error        {"msg_id":"d8c05cb2-65f82da6","reason":"SMTP error 451: Timeout waiting for client input [AM2PEPF0001C70A.eurprd05.prod.outlook.com 2024-03-18T12:08:51.314Z 08DC46B3649E7B65]","remote_server":"example-org.mail.protection.outlook.com.","smtp_code":451,"smtp_enchcode":"4.7.0","smtp_msg":"example-org.mail.protection.outlook.com. said: Timeout waiting for client input [AM2PEPF0001C70A.eurprd05.prod.outlook.com 2024-03-18T12:08:51.314Z 08DC46B3649E7B65]"}

Configuration file

The configuration is pretty much default, conn_max_idle_time is not configured (so the default of 150 seconds should apply).

Environment information

• maddy version: cee5777