Sync and Send NOT reusing connections for operations

SebastianKrupinski commented 3 weeks ago

Steps to reproduce

Send or Sync messages
Check server or mail client logs

Expected behavior

Use a single connection for all operations then close connection once completed

Actual behavior

Sync operation opens new IMAP connection for every mailbox that needs to sync.

Send operation opens one new SMTP connection and two new IMAP connections for every email it sends.

Mail app version

Lastest Dev

Mailserver or service

IMAP/SMTP

Operating system

No response

PHP engine version

PHP 8.3

Web server

Nginx

Database

MySQL

Additional info

No response

SebastianKrupinski commented 3 weeks ago

Test Results of sending 3 messages at the same time from the same account.

Thu, 08 Aug 2024 12:37:22 - INFO - Network connection ended (network.connection-end) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 60796, elapsed = 29ms
Thu, 08 Aug 2024 12:37:22 - INFO - SMTP EHLO command (smtp.ehlo) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 60796, domain = "localhost"
Thu, 08 Aug 2024 12:37:22 - INFO - Network connection started (network.connection-start) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 60796

Thu, 08 Aug 2024 12:37:20 - INFO - Network connection ended (network.connection-end) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 60792, elapsed = 28ms
Thu, 08 Aug 2024 12:37:20 - INFO - SMTP EHLO command (smtp.ehlo) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 60792, domain = "localhost"
Thu, 08 Aug 2024 12:37:20 - INFO - Network connection started (network.connection-start) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 60792

Thu, 08 Aug 2024 12:37:17 - INFO - Network connection ended (network.connection-end) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 58302, elapsed = 55ms
Thu, 08 Aug 2024 12:37:17 - INFO - SMTP EHLO command (smtp.ehlo) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 58302, domain = "localhost"
Thu, 08 Aug 2024 12:37:17 - INFO - Network connection started (network.connection-start) listenerId = "submission", protocol = smtp, remoteIp = 127.0.0.1, remotePort = 58302

Thu, 08 Aug 2024 12:43:50 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53268, elapsed = 10ms
Thu, 08 Aug 2024 12:43:50 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53268, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 12:43:50 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53268

Thu, 08 Aug 2024 12:43:50 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53262, elapsed = 47ms
Thu, 08 Aug 2024 12:43:50 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53262, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 12:43:50 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53262

Thu, 08 Aug 2024 12:43:50 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53256, elapsed = 24ms
Thu, 08 Aug 2024 12:43:50 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53256, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 12:43:50 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53256

Thu, 08 Aug 2024 12:43:50 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53252, elapsed = 27ms
Thu, 08 Aug 2024 12:43:50 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53252, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 12:43:50 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53252

Thu, 08 Aug 2024 12:43:50 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53236, elapsed = 27ms
Thu, 08 Aug 2024 12:43:50 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53236, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 12:43:50 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53236

Thu, 08 Aug 2024 12:43:50 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53222, elapsed = 68ms
Thu, 08 Aug 2024 12:43:50 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53222, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 12:43:50 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 53222

Total of 3 SMTP connections created and 6 IMAP connections created.

Issue: Ths Send chain modules, each module creates a new connection for each message instead of reusing the connection. https://github.com/nextcloud/mail/tree/main/lib/Send

Solutions:

Rewrite modules to pass IMAP and SMTP connection down the chain.
Rewrite connection factory method to cache connections based on hash of server host and username, and return cached connection on second call

SebastianKrupinski commented 3 weeks ago

Test results of syncing an account, with 3 mailboxes (folders)

Thu, 08 Aug 2024 14:32:24 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49226, elapsed = 38ms
Thu, 08 Aug 2024 14:32:24 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49226, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 14:32:24 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49226

Thu, 08 Aug 2024 14:32:24 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49212, elapsed = 52ms
Thu, 08 Aug 2024 14:32:24 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49212, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 14:32:24 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49212

Thu, 08 Aug 2024 14:32:24 - INFO - Network connection ended (network.connection-end) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49210, elapsed = 98ms
Thu, 08 Aug 2024 14:32:24 - INFO - Authentication successful (auth.success) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49210, name = "user1@testmail.com", accountId = 61, type = Individual
Thu, 08 Aug 2024 14:32:24 - INFO - Network connection started (network.connection-start) listenerId = "imap", protocol = imap, remoteIp = 127.0.0.1, remotePort = 49210

Issue: The connection is created in the mailbox sync function https://github.com/nextcloud/mail/blob/a41a0754fd91f8f292dff28c9ef6a014318c8f99/lib/Service/Sync/ImapToDbSynchronizer.php#L194 instead of the Account Sync function https://github.com/nextcloud/mail/blob/a41a0754fd91f8f292dff28c9ef6a014318c8f99/lib/Service/Sync/ImapToDbSynchronizer.php#L103 which causes the connection to be created per mailbox.

Solutions:

Rewrite account sync function to create the connection and pass it to mailbox sync.
Rewrite connection factory method to cache connections based on hash of server host and username, and return cached connection on second call

ChristophWurst commented 3 weeks ago

Rewrite connection factory method to cache connections based on hash of server host and username, and return cached connection on second call

We tried that and it caused too many open connections: https://github.com/nextcloud/mail/pull/6174

nextcloud / mail