Topic: Errore autenticazione SMTP al primo invio

[RickestRick]

Buongiorno.
Avrei bisogno di delucidazioni riguardo ad un problema un po' strano.

Io ho un cliente che utilizza Thunderbird nel quale ha configurato 4 account in IMAP, 2 dei quali sono indirizzi @virgilio.it, configurati con sicurezza SSL.

I due account di virgilio funzionano normalmente in ricezione. Il problema è che ogni volta, al primo tentativo di invio da uno di questi due account dopo aver avviato thunderbird, il mio cliente ottiente l'errore di password errata dove ha la possibilità di riprovare o reinserire una nuova password. Facendo click su Riprova per una o due volte il messaggio parte e poi il tutto funziona correttamente fino al prossimo avvio di thinderbird.

Ho configurato i due account sul mio pc in una nuova installazione ed ho riscontrato lo stesso problema.

Ho salvato il log della connessione smtp:

2017-05-30 12:59:11.502000 UTC - 0[170f140]: SMTP Connecting to: out.virgilio.it
2017-05-30 12:59:11.673000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.673000 UTC - 0[170f140]: SMTP Response: 220 smtp-42.iol.local smtp-42.iol.local ESMTP server ready
2017-05-30 12:59:11.673000 UTC - 0[170f140]: SMTP entering state: 14
2017-05-30 12:59:11.673000 UTC - 0[170f140]: SMTP Send: EHLO [10.0.0.112]
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP Response: 250-smtp-42.iol.local hello [79.0.226.235], pleased to meet you
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP Response: 250-HELP
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP Response: 250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP Response: 250-SIZE 50000000
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP Response: 250-8BITMIME
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP Response: 250 OK
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 4
2017-05-30 12:59:11.722000 UTC - 0[170f140]: SMTP entering state: 21
2017-05-30 12:59:11.723000 UTC - 0[170f140]: SMTP auth: server caps 0x12310, pref 0x300, failed 0x0, avail caps 0x300
2017-05-30 12:59:11.723000 UTC - 0[170f140]: (GSSAPI = 0x800, CRAM = 0x2000, NTLM = 0x4000, MSN =  0x8000, PLAIN = 0x200, LOGIN = 0x100, EXTERNAL = 0x400)
2017-05-30 12:59:11.723000 UTC - 0[170f140]: trying auth method 0x200
2017-05-30 12:59:11.723000 UTC - 0[170f140]: SMTP entering state: 16
2017-05-30 12:59:11.723000 UTC - 0[170f140]: SMTP AuthLoginStep1() for <XXXXXXXXX@virgilio.it>@P]®R@]®R
2017-05-30 12:59:11.728000 UTC - 0[170f140]: PLAIN auth
2017-05-30 12:59:11.728000 UTC - 0[170f140]: Logging suppressed for this command (it probably contained authentication information)
2017-05-30 12:59:11.783000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:11.783000 UTC - 0[170f140]: SMTP Response: 535 Invalid User or Password [smtp-42.iol.local; VIR_300]
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP entering state: 18
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP Login response, code 535
2017-05-30 12:59:11.784000 UTC - 0[170f140]: marking auth method 0x200 failed
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP auth: server caps 0x12310, pref 0x300, failed 0x200, avail caps 0x100
2017-05-30 12:59:11.784000 UTC - 0[170f140]: (GSSAPI = 0x800, CRAM = 0x2000, NTLM = 0x4000, MSN =  0x8000, PLAIN = 0x200, LOGIN = 0x100, EXTERNAL = 0x400)
2017-05-30 12:59:11.784000 UTC - 0[170f140]: trying auth method 0x100
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP: login failed: failed 200, current 100
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP entering state: 21
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP auth: server caps 0x12310, pref 0x300, failed 0x200, avail caps 0x100
2017-05-30 12:59:11.784000 UTC - 0[170f140]: (GSSAPI = 0x800, CRAM = 0x2000, NTLM = 0x4000, MSN =  0x8000, PLAIN = 0x200, LOGIN = 0x100, EXTERNAL = 0x400)
2017-05-30 12:59:11.784000 UTC - 0[170f140]: trying auth method 0x100
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP entering state: 15
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP: MSN or LOGIN auth, step 0
2017-05-30 12:59:11.784000 UTC - 0[170f140]: SMTP Send: AUTH LOGIN
2017-05-30 12:59:11.786000 UTC - 0[170f140]: SMTP connection dropped after 261 total bytes read
2017-05-30 12:59:11.787000 UTC - 0[170f140]: SMTP Login response, code 535
2017-05-30 12:59:11.787000 UTC - 0[170f140]: marking auth method 0x100 failed
2017-05-30 12:59:11.787000 UTC - 0[170f140]: SMTP auth: server caps 0x12311, pref 0x300, failed 0x300, avail caps 0x0
2017-05-30 12:59:11.787000 UTC - 0[170f140]: (GSSAPI = 0x800, CRAM = 0x2000, NTLM = 0x4000, MSN =  0x8000, PLAIN = 0x200, LOGIN = 0x100, EXTERNAL = 0x400)
2017-05-30 12:59:11.787000 UTC - 0[170f140]: no auth method remaining
2017-05-30 12:59:11.787000 UTC - 0[170f140]: SMTP: ask user what to do (after login failed): new password, retry or cancel
2017-05-30 12:59:13.660000 UTC - 0[170f140]: retry button pressed
2017-05-30 12:59:13.660000 UTC - 0[170f140]: SMTP: login failed: failed 0, current 0
2017-05-30 12:59:13.661000 UTC - 0[170f140]: SMTP Connecting to: out.virgilio.it
2017-05-30 12:59:13.832000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.832000 UTC - 0[170f140]: SMTP Response: 220 smtp-42.iol.local smtp-42.iol.local ESMTP server ready
2017-05-30 12:59:13.832000 UTC - 0[170f140]: SMTP entering state: 14
2017-05-30 12:59:13.832000 UTC - 0[170f140]: SMTP Send: EHLO [10.0.0.112]

2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP Response: 250-smtp-42.iol.local hello [79.0.226.235], pleased to meet you
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP Response: 250-HELP
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP Response: 250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP Response: 250-SIZE 50000000
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP Response: 250-8BITMIME
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP Response: 250 OK
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 4
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 21
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP auth: server caps 0x12310, pref 0x300, failed 0x0, avail caps 0x300
2017-05-30 12:59:13.883000 UTC - 0[170f140]: (GSSAPI = 0x800, CRAM = 0x2000, NTLM = 0x4000, MSN =  0x8000, PLAIN = 0x200, LOGIN = 0x100, EXTERNAL = 0x400)
2017-05-30 12:59:13.883000 UTC - 0[170f140]: trying auth method 0x200
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP entering state: 16
2017-05-30 12:59:13.883000 UTC - 0[170f140]: SMTP AuthLoginStep1() for <XXXXXX@virgilio.it>@P]®R@]®R
2017-05-30 12:59:13.883000 UTC - 0[170f140]: PLAIN auth
2017-05-30 12:59:13.883000 UTC - 0[170f140]: Logging suppressed for this command (it probably contained authentication information)
2017-05-30 12:59:13.947000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:13.947000 UTC - 0[170f140]: SMTP Response: 235 ... authentication succeeded
2017-05-30 12:59:13.947000 UTC - 0[170f140]: SMTP entering state: 18
2017-05-30 12:59:13.947000 UTC - 0[170f140]: SMTP Login response, code 235
2017-05-30 12:59:13.947000 UTC - 0[170f140]: SMTP entering state: 3
2017-05-30 12:59:13.947000 UTC - 0[170f140]: SMTP Send: MAIL FROM:<XXXXXXX@virgilio.it> SIZE=431
2017-05-30 12:59:14.048000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:14.049000 UTC - 0[170f140]: SMTP Response: 250 <XXXXXXX@virgilio.it> sender ok
2017-05-30 12:59:14.049000 UTC - 0[170f140]: SMTP entering state: 5
2017-05-30 12:59:14.049000 UTC - 0[170f140]: SMTP Send: RCPT TO:<XXXXXXX@gmail.com>
2017-05-30 12:59:14.102000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:14.103000 UTC - 0[170f140]: SMTP Response: 250 <XXXXXXX@gmail.com> recipient ok
2017-05-30 12:59:14.103000 UTC - 0[170f140]: SMTP entering state: 6
2017-05-30 12:59:14.103000 UTC - 0[170f140]: SMTP Send: DATA
2017-05-30 12:59:14.149000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:14.149000 UTC - 0[170f140]: SMTP Response: 354 OK
2017-05-30 12:59:14.149000 UTC - 0[170f140]: SMTP entering state: 7
2017-05-30 12:59:14.149000 UTC - 0[170f140]: SMTP entering state: 8
2017-05-30 12:59:14.155000 UTC - 0[170f140]: SMTP Send: .
2017-05-30 12:59:14.238000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:14.238000 UTC - 0[170f140]: SMTP Response: 250 FgjydWLsdq4M0FgjydGZ6V mail accepted for delivery
2017-05-30 12:59:14.238000 UTC - 0[170f140]: SMTP entering state: 9
2017-05-30 12:59:14.238000 UTC - 0[170f140]: SMTP Send: QUIT
2017-05-30 12:59:14.239000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:14.288000 UTC - 0[170f140]: SMTP entering state: 0
2017-05-30 12:59:14.288000 UTC - 0[170f140]: SMTP Response: 221 smtp-42.iol.local smtp-42.iol.local closing connection
2017-05-30 12:59:14.288000 UTC - 0[170f140]: SMTP entering state: 10
2017-05-30 12:59:14.291000 UTC - 0[170f140]: SMTP entering state: 12
2017-05-30 12:59:14.291000 UTC - 0[170f140]: SMTP connection error quitting 804b0002, ignoring

Qualcuno che abbia riscontrato lo stesso problema o che sappia da cosa dipenda e come risolverlo?

Grazie