On Tue, Jul 27, 2010 at 04:44:45PM +0200, John Feuerstein wrote:
[snip]
Fatal Error
reading authentication information from client
192.168.10.100:34680->192.168.10.100:143: Exiting child
... I also get this on each login using Thunderbird 3.1.1.
However, this doesn't seem "fatal" to the real IMAP session.
It seems like TB opens an additional connection to the server to check
capatibilities, then closes it without sending any authentication. The
authentication is then done on the initial connection (probably after
STARTTLS...) instead.
The debug log confirms this (PID 6245 is this mysterious connection that
just sends nothing (EOF?) after capability, while PID 6243 is the
initial connection that continues just fine...):
perdition.imap4[6243]: Connect:
192.168.10.100:34679->192.168.10.100:143·
perdition.imap4[6243]: SELF: "* OK [CAPABILITY IMAP4 IMAP4REV1 STARTTLS] perdition
ready on 0N\030\303\377\177 000297fe\r\n"·
perdition.imap4[6245]: Connect: 192.168.10.100:34680->192.168.10.100:143·
perdition.imap4[6245]: SELF: "* OK [CAPABILITY IMAP4 IMAP4REV1 STARTTLS] perdition
ready on 0N\030\303\377\177 000297fe\r\n"·
perdition.imap4[6245]: CLIENT: "1 STARTTLS\r\n"·
perdition.imap4[6245]: SELF: "1 OK Begin TLS negotiation now\r\n"·
perdition.imap4[6243]: CLIENT: "1 STARTTLS\r\n"·
perdition.imap4[6243]: SELF: "1 OK Begin TLS negotiation now\r\n"·
perdition.imap4[6243]: SSL connection using CAMELLIA256-SHA·
perdition.imap4[6245]: SSL connection using CAMELLIA256-SHA·
perdition.imap4[6243]: CLIENT: "2 capability\r\n"·
perdition.imap4[6243]: SELF: "* CAPABILITY IMAP4 IMAP4REV1\r\n"·
perdition.imap4[6243]: SELF: "2 OK CAPABILITY\r\n"·
perdition.imap4[6245]: CLIENT: "2 capability\r\n"·
perdition.imap4[6245]: SELF: "* CAPABILITY IMAP4 IMAP4REV1\r\n"·
perdition.imap4[6245]: SELF: "2 OK CAPABILITY\r\n"·
perdition.imap4[6243]: CLIENT: "4 login \"foo(a)bar.com\"
\"foobar\"\r\n"·
perdition.imap4[6243]: username_add_domain: username_add_domain 0 1·
perdition.imap4[6243]: username_add_domain: username_add_domain 0 4·
perdition.imap4[6245]: CLIENT: ""·
perdition.imap4[6245]: token_read: token_fill_buffer·
perdition.imap4[6245]: read_line: token_read·
perdition.imap4[6245]: imap4_in_get_auth: read_imap4_line 1·
perdition.imap4[6245]: main: protocol->in_get_auth·
perdition.imap4[6245]: Fatal Error reading authentication information from client
192.168.10.100:34680->192.168.10.100:143: Exiting child·
perdition.imap4[6243]: REAL: "* OK IMAP4 Ready 10.10.4.4 0001ce47\r\n"·
perdition.imap4[6243]: SELF: "flim07 CAPABILITY\r\n"·
perdition.imap4[6243]: REAL: "* CAPABILITY IMAP4 IMAP4REV1 STARTTLS\r\n"·
perdition.imap4[6243]: REAL: "flim07 OK CAPABILITY\r\n"·
perdition.imap4[6243]: SELF: "flim08 LOGIN {15}\r\n"·
perdition.imap4[6243]: REAL: "+ OK ready for additional input\r\n"·
perdition.imap4[6243]: SELF: "foo(a)bar.com {10}\r\n"·
perdition.imap4[6243]: REAL: "+ OK ready for additional input\r\n"·
perdition.imap4[6243]: SELF: "foobar\r\n"·
perdition.imap4[6243]: REAL: "flim08 OK SUCCESS - REAL MAIL SERVICE\r\n"·
perdition.imap4[6243]: SELF: "4 OK SUCCESS - PROXY\r\n"·
perdition.imap4[6243]: Auth: 192.168.10.100:34679->192.168.10.100:143
client-secure=starttls authorisation_id=NONE authentication_id="foo(a)bar.com"
server="127.0.0.1:10143" protocol=IMAP4 server-secure=plaintext
status="ok"·
...
... so perhaps you can catch this in imap4_in_get_auth() or just leave
it this way. (After all, it's just TB trying to be smart...)
Hi John,
I agree with your analysis.
What seems to be happening is that Thunderbird is closing
a connection without issuing a LOGOUT, command and perdition is complaining
about that.
I think that is is worth fixing perdition so that it doesn't complain here.
But the fix is non-trival, so I think it is post 1.19 material.