Problems recovering failed connection when idling (ie. IMAP server restart)
I apologize if this is long winded, I wanted to post this for years and it seems today is the day!
I have imapfilter running at a box that is local to the IMAP server and I am using a loop with idle.
I've been using it for a few years but it exits when the connection to the server gets interrupted (say mail server restart etc).
I tried the available options but I may have misunderstood something, since I am getting strange errors.
This is also with the latest version 2.7.5 from Github freshly built, so I don't think it's an old bug.
Ubuntu 18.04 Server
IMAPFilter 2.7.5 Copyright (c) 2001-2020 Eleftherios Chatzimparmpas
To illustrate, here my loop is running fine and I am intentionally shutting down the mail server for a few seconds before I start it up again.
Debug log:
1135 OK SEARCH completed
sending command (7):
1136 IDLE
getting response (7):
+ idling
recovering connection: imaps://[email protected]@mail.servercom:993/INBOX
getting response (7):
* OK mail.server.com IMAP4rev1 ready
sending command (7):
1137 NOOP
recovering connection: imaps://[email protected]@D:993/
recovering connection: imaps://[email protected]@(null):D/
recovering connection: imaps://[email protected]@(null):pa^E_�U/
recovering connection: imaps://[email protected]@(null):050 /
These "special" characters are not a copy and paste error, that's what I have in the log. It also doens't seem a terminal issue, it's what I get in the log.
Error log:
Sat Jun 26 08:14:32 2021: reading data through SSL; the connection has been closed cleanly
Sat Jun 26 08:14:32 2021: unexpected network error for [email protected]@mail.server.com
Sat Jun 26 08:14:34 2021: reading data through SSL; the connection has been closed cleanly
Sat Jun 26 08:15:34 2021: error while initiating connection to at port p��^W>^?
At this point imapfilter exits.
I tried using the internal IP addresses instead of the mail server's domain names (mail.server.com) with options.hostnames = false but I get the same result.
These are my options and structure of the script:
---------------
-- Options --
---------------
options.timeout = 60
options.subscribe = true
options.info = true
options.reenter = false
options.persist = true
options.wakeonany = true
options.charset = 'UTF-8'
----------------
-- Accounts --
----------------
account1 = IMAP {
server = 'mail.server.com',
username = '[email protected]',
password = string1,
ssl = 'auto',
}
account2 = IMAP {
server = 'mail.server.com',
username = '[email protected]',
password = string2,
ssl = 'auto',
}
------------------
-- Main Loop --
------------------
local i = 1 -- counting rounds
repeat
print("Starting loop " .. i .. ".")
dofile('imapfilter_rules.lua')
i = i + 1
print("Done processing this round, waiting for mail server to return from idle.")
account1.INBOX:enter_idle()
until not true
With options.reenter = true I get the following (imapfilter doesn't exit):
[...]
* SEARCH
1112 OK SEARCH completed
conversion: 'Postmaster' -> 'Postmaster'
sending command (7):
1113 SELECT "Postmaster"
recovering connection: imaps://[email protected]@172.31.42.100:993/INBOX (using IP addresses this time)
getting response (7):
* OK mail.server.com IMAP4rev1 ready
sending command (7):
1114 NOOP
recovering connection: imaps://[email protected]@69]:993/
recovering connection: imaps://[email protected]@(null):69]/
recovering connection: imaps://[email protected]@(null):pQ��JV/
recovering connection: imaps://[email protected]@(null):/
recovering connection: imaps://[email protected]@(null):/
recovering connection: imaps://[email protected]@(null):/
recovering connection: imaps://[email protected]@(null):/
Debug log:
Sat Jun 26 08:29:24 2021: reading data through SSL; the connection has been closed cleanly
Sat Jun 26 08:29:24 2021: unexpected network error for [email protected]@172.31.42.100
Sat Jun 26 08:29:26 2021: reading data through SSL; the connection has been closed cleanly
Sat Jun 26 08:30:26 2021: gettaddrinfo; Temporary failure in name resolution
Sat Jun 26 08:31:26 2021: gettaddrinfo; Servname not supported for ai_socktype
Sat Jun 26 08:32:26 2021: gettaddrinfo; Servname not supported for ai_socktype
Sat Jun 26 08:33:26 2021: error while initiating connection to at port
Sat Jun 26 08:34:26 2021: error while initiating connection to at port
Sat Jun 26 08:35:26 2021: error while initiating connection to at port
Sat Jun 26 08:36:26 2021: error while initiating connection to at port
imapfilter won't exit this way, but continue like this.
Any idea what the problem could be and how I could get this sorted out ?
Take a look at my configuration in the last comment of the following issue: https://github.com/lefcha/imapfilter/issues/211#
This is a bug, and the incorrect recovering connection print outs is a proof of that. I know where the problem is and will have a fix soon.
@alexhk I pushed a fix, could you try with the latest Git version?
I experience a similar issue when imapfilter dies once in a while (a couple of times per month) and gets restarted by systemd.
Here's my setup (relevant details):
…
while true do
inbox = account.INBOX
…
if not inbox:enter_idle() then
sleep(60)
end
end
and here's the systemd log:
Mar 08 22:34:56 sajuuk imapfilter[2314]: imapfilter: idle request to [email protected] failed
Mar 08 22:34:56 sajuuk imapfilter[2314]: stack traceback:
Mar 08 22:34:56 sajuuk imapfilter[2314]: [C]: in ?
Mar 08 22:34:56 sajuuk imapfilter[2314]: [C]: in function 'error'
Mar 08 22:34:56 sajuuk imapfilter[2314]: /usr/share/imapfilter/mailbox.lua:41: in field '_check_result'
Mar 08 22:34:56 sajuuk imapfilter[2314]: /usr/share/imapfilter/mailbox.lua:1070: in method 'enter_idle'
Mar 08 22:34:56 sajuuk imapfilter[2314]: /home/stealth/.imapfilter/config.lua:37: in main chunk
Mar 08 22:34:56 sajuuk systemd[2104]: imapfilter.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Mar 08 22:34:56 sajuuk systemd[2104]: imapfilter.service: Failed with result 'exit-code'.
systemd unit:
Description=Imapfilter Mail Filter
Documentation="man:imapfilter(1)" "man:imapfilter_config(5)"
ConditionPathExists=%h/.imapfilter/config.lua
[Service]
Type=simple
ExecStart=/usr/bin/imapfilter -c %h/.imapfilter/config.lua
RestartSec=60
Restart=on-failure
[Install]
WantedBy=default.target
I can probably re-run impafilter with debug file enabled, but maybe these details can give you an idea on where to look.