Tickets :: Comment on [#13274] Sporadic IMAP login errors

* Your Email Address
* Spam protection	Enter the letters below: .__ .__ __..___.. . [ __[__)(__ _/ \ / [_./[__).__)./__. \/
Comment	> Hi, > > I'm currently testing git "master" and from time to time I'm facing > very sporadic IMAP login errors. > They seem to happen randomly when I click around the UI of the apps. > This will generate IMAP traffic in my case since I'm using a Kolab > backend. I didn't see anything like that before using the old > FRAMEWORK_5_1 code. > > The horde log shows it can authenticate successfully and then on the > next request it's broken: > ---------------------------------------- > 2014-06-21T09:59:07+02:00 NOTICE: HORDE [horde] Login success for > admin to horde (172.16.1.145) [pid 2207 on line 164 of > "/datastore/DEVEL/horde/login.php"] > 2014-06-21T09:59:19+02:00 WARN: HORDE [imp] [login] Mail server > denied authentication. [pid 2207 on line 732 of > "/datastore/DEVEL/imp/lib/Imap.php"] > 2014-06-21T09:59:19+02:00 WARN: HORDE PHP ERROR: json_encode() [<a > href='function.json-encode'>function.json-encode</a>]: Invalid UTF-8 > sequence in argument [pid 2207 on line 45 of > "/datastore/DEVEL/framework/Pack/lib/Horde/Pack/Driver/Json.php"] > 2014-06-21T09:59:19+02:00 WARN: HORDE PHP ERROR: json_encode() [<a > href='function.json-encode'>function.json-encode</a>]: Invalid UTF-8 > sequence in argument [pid 2207 on line 45 of > "/datastore/DEVEL/framework/Pack/lib/Horde/Pack/Driver/Json.php"] > 2014-06-21T09:59:19+02:00 WARN: HORDE PHP ERROR: json_encode() [<a > href='function.json-encode'>function.json-encode</a>]: Invalid UTF-8 > sequence in argument [pid 2207 on line 45 of > "/datastore/DEVEL/framework/Pack/lib/Horde/Pack/Driver/Json.php"] > 2014-06-21T09:59:19+02:00 WARN: HORDE PHP ERROR: json_encode() [<a > href='function.json-encode'>function.json-encode</a>]: Invalid UTF-8 > sequence in argument [pid 2207 on line 45 of > "/datastore/DEVEL/framework/Pack/lib/Horde/Pack/Driver/Json.php"] > 2014-06-21T09:59:19+02:00 WARN: HORDE PHP ERROR: json_encode() [<a > href='function.json-encode'>function.json-encode</a>]: Invalid UTF-8 > sequence in argument [pid 2207 on line 45 of > "/datastore/DEVEL/framework/Pack/lib/Horde/Pack/Driver/Json.php"] > 2014-06-21T09:59:20+02:00 ERR: HORDE [kronolith] No password > provided. [pid 2207 on line 123 of > "/datastore/DEVEL/framework/Share/lib/Horde/Share/Kolab.php"] > ... > ("the no password provided" message repeats for all horde apps using > a Kolab backend) > ---------------------------------------- > > > The corresponding syslog from cyrus-imapd 2.4.17: > ---------------------------------------- > Jun 21 09:59:07 horde-git imaploc[3887]: starttls: TLSv1 with cipher > DHE-RSA-AES256-SHA (256/256 bits new) no authentication > Jun 21 09:59:07 horde-git imaploc[3887]: login: horde-git.m.i2n > [127.0.0.1] admin PLAIN+TLS User logged in > SESSIONID=<horde-git.m.i2n-3887-1403337547-1> > Jun 21 09:59:07 horde-git imaploc[3887]: USAGE admin user: 0.012000 > sys: 0.000000 > Jun 21 09:59:07 horde-git imaploc[3941]: badlogin: horde-git.m.i2n > [127.0.0.1] CRAM-MD5 [SASL(-13): authentication failure: incorrect > digest response] > Jun 21 09:59:10 horde-git imaploc[3941]: badlogin: horde-git.m.i2n > [127.0.0.1] PLAIN [SASL(-13): authentication failure: Password > verification failed] > Jun 21 09:59:13 horde-git imaploc[3941]: badlogin: horde-git.m.i2n > [127.0.0.1] plaintext admin SASL(-13): authentication failure: > checkpass failed > Jun 21 09:59:16 horde-git imaploc[3941]: badlogin: horde-git.m.i2n > [127.0.0.1] plaintext admin SASL(-13): authentication failure: > checkpass failed > ---------------------------------------- > > I also have a backtrace of the "No password provided" error message > but I doubt it's of any use: > > ---------------------------------------- > 1. Horde_Registry::appInit() /datastore/DEVEL/turba/index.php:14 > 2. Horde_Registry->pushApp() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:299 > 3. Horde_Registry->_pushAppError() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1606 > 4. Horde_Registry::appInit() /datastore/DEVEL/turba/index.php:14 > 5. Horde_Registry->pushApp() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:299 > 6. Horde_Registry->callAppMethod() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1601 > 7. call_user_func_array() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1201 > 8. Horde_Registry_Application->init() > 9. Turba_Application->_init() > /datastore/DEVEL/framework/Core/lib/Horde/Registry/Application.php:105 > 10. Turba::getConfigFromShares() > /datastore/DEVEL/turba/lib/Application.php:114 > 11. Turba_Driver_Kolab->createShare() > /datastore/DEVEL/turba/lib/Turba.php:564 > 12. Turba::createShare() /datastore/DEVEL/turba/lib/Driver/Kolab.php:975 > 13. Horde_Registry::appInit() /datastore/DEVEL/turba/index.php:14 > 14. Horde_Registry->pushApp() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:299 > 15. Horde_Registry->callAppMethod() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1601 > 16. call_user_func_array() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1201 > 17. Horde_Registry_Application->init() > 18. Turba_Application->_init() > /datastore/DEVEL/framework/Core/lib/Horde/Registry/Application.php:105 > 19. Turba::getConfigFromShares() > /datastore/DEVEL/turba/lib/Application.php:114 > 20. Turba_Driver_Kolab->createShare() > /datastore/DEVEL/turba/lib/Turba.php:564 > 21. Turba::createShare() /datastore/DEVEL/turba/lib/Driver/Kolab.php:975 > 22. Horde_Core_Share_Driver->newShare() > /datastore/DEVEL/turba/lib/Turba.php:675 > 23. Horde_Core_Share_Driver->__call() > /datastore/DEVEL/turba/lib/Turba.php:675 > 24. call_user_func_array() > /datastore/DEVEL/framework/Core/lib/Horde/Core/Share/Driver.php:63 > 25. Horde_Share_Base->newShare() > 26. Horde_Share_Object_Kolab->set() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Base.php:419 > 27. Horde_Share_Kolab->constructFolderName() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Object/Kolab.php:232 > 28. Horde_Registry::appInit() /datastore/DEVEL/turba/index.php:14 > 29. Horde_Registry->pushApp() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:299 > 30. Horde_Registry->callAppMethod() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1601 > 31. call_user_func_array() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1201 > 32. Horde_Registry_Application->init() > 33. Turba_Application->_init() > /datastore/DEVEL/framework/Core/lib/Horde/Registry/Application.php:105 > 34. Turba::getConfigFromShares() > /datastore/DEVEL/turba/lib/Application.php:114 > 35. Turba_Driver_Kolab->createShare() > /datastore/DEVEL/turba/lib/Turba.php:564 > 36. Turba::createShare() /datastore/DEVEL/turba/lib/Driver/Kolab.php:975 > 37. Horde_Core_Share_Driver->newShare() > /datastore/DEVEL/turba/lib/Turba.php:675 > 38. Horde_Core_Share_Driver->__call() > /datastore/DEVEL/turba/lib/Turba.php:675 > 39. call_user_func_array() > /datastore/DEVEL/framework/Core/lib/Horde/Core/Share/Driver.php:63 > 40. Horde_Share_Base->newShare() > 41. Horde_Share_Object_Kolab->set() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Base.php:419 > 42. Horde_Share_Kolab->constructFolderName() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Object/Kolab.php:232 > 43. Horde_Kolab_Storage_List_Tools->getNamespace() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Kolab.php:187 > 44. Horde_Kolab_Storage_Driver_Decorator_Timer->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/List/Tools.php:276 > 45. Horde_Kolab_Storage_Driver_Decorator_Base->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Timer.php:187 > 46. Horde_Kolab_Storage_Driver_Decorator_Log->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Base.php:310 > 47. Horde_Kolab_Storage_Driver_Decorator_Base->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Log.php:262 > 48. Horde_Kolab_Storage_Driver_Imap->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Base.php:310 > 49. Horde_Registry::appInit() /datastore/DEVEL/turba/index.php:14 > 50. Horde_Registry->pushApp() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:299 > 51. Horde_Registry->callAppMethod() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1601 > 52. call_user_func_array() > /datastore/DEVEL/framework/Core/lib/Horde/Registry.php:1201 > 53. Horde_Registry_Application->init() > 54. Turba_Application->_init() > /datastore/DEVEL/framework/Core/lib/Horde/Registry/Application.php:105 > 55. Turba::getConfigFromShares() > /datastore/DEVEL/turba/lib/Application.php:114 > 56. Turba_Driver_Kolab->createShare() > /datastore/DEVEL/turba/lib/Turba.php:564 > 57. Turba::createShare() /datastore/DEVEL/turba/lib/Driver/Kolab.php:975 > 58. Horde_Core_Share_Driver->newShare() > /datastore/DEVEL/turba/lib/Turba.php:675 > 59. Horde_Core_Share_Driver->__call() > /datastore/DEVEL/turba/lib/Turba.php:675 > 60. call_user_func_array() > /datastore/DEVEL/framework/Core/lib/Horde/Core/Share/Driver.php:63 > 61. Horde_Share_Base->newShare() > 62. Horde_Share_Object_Kolab->set() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Base.php:419 > 63. Horde_Share_Kolab->constructFolderName() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Object/Kolab.php:232 > 64. Horde_Kolab_Storage_List_Tools->getNamespace() > /datastore/DEVEL/framework/Share/lib/Horde/Share/Kolab.php:187 > 65. Horde_Kolab_Storage_Driver_Decorator_Timer->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/List/Tools.php:276 > 66. Horde_Kolab_Storage_Driver_Decorator_Base->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Timer.php:187 > 67. Horde_Kolab_Storage_Driver_Decorator_Log->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Base.php:310 > 68. Horde_Kolab_Storage_Driver_Decorator_Base->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Log.php:262 > 69. Horde_Kolab_Storage_Driver_Imap->getNamespace() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Decorator/Base.php:310 > 70. Horde_Imap_Client_Base->login() > /datastore/DEVEL/framework/Kolab_Storage/lib/Horde/Kolab/Storage/Driver/Imap.php:295 > 71. Horde_Imap_Client_Socket->_login() > /datastore/DEVEL/framework/Imap_Client/lib/Horde/Imap/Client/Base.php:784 > ---------------------------------------- > > > What I'm wondering about: Does the failed CRAM-MD5 authentication > kill the stored password or is a "lost password" the cause for the > failing CRAM-MD5 authentication? ;) > > I'll try to add debug code to the CRAM-MD5 code to log the password > it uses. Let's see if that sheds any light on this. > > Other ideas welcome ;) > > Cheers, > Thomas >
Attachment
Watch this ticket

Saved Queries