CRAM-MD5 Issue: a flow diagram, of sorts ...

[Marc G. Fournier]

Okay, spent this aft going through the code, and trying ot narrow down
where in the process things are getting 'hosed' ... It turns out that the
initial login works, and its not until the horde system is 'setting up'
the registry that the second attempt happens, and fails ...

Feb 14 18:11:02 earth myScripLog[39661]: /usr/local/www/horde/imp/lib/IMP.php: 279
Feb 14 18:11:02 earth myScripLog[39661]: /usr/local/www/horde/imp/lib/IMP.php: 306
Feb 14 18:11:02 earth myScripLog[39661]: /usr/local/www/horde/imp/lib/IMP.php: 320
Feb 14 18:11:02 earth myScripLog[39661]: /usr/local/www/horde/imp/lib/IMP.php: 322
Feb 14 18:11:03 earth myScripLog[39661]: /usr/local/www/horde/imp/lib/IMP.php: 337
Feb 14 18:11:03 earth HORDE[39661]: [imp] [/imp/redirect.php] Login Attempt(flags: 64, connstr: {earth.hub.org:143/imap}): 142.177.110.175 to earth.hub.org:143[imap] as scrappy with [HBUAAA==#0fINATo8OiEL] [on line 338 of "/usr/local/www/horde/imp/lib/IMP.php"]
Feb 14 18:11:03 earth HORDE[39661]: [imp] Login success for scrappy [142.177.110.175] to {earth.hub.org:143} [on line 51 of "/usr/local/www/horde/imp/redirect.php"]
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 47
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 54
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 60
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 63
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 65
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 69
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 71
Feb 14 18:11:04 earth last message repeated 2 times
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/login.php: 73
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/lib/Registry.php: 198
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/lib/Registry.php: 210
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/lib/Registry.php: 220
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/lib/Registry.php: 230
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/imp/lib/api.php: 27
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/imp/lib/api.php: 33
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/imp/lib/IMP.php: 279
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/imp/lib/IMP.php: 306
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/imp/lib/IMP.php: 320
Feb 14 18:11:04 earth myScripLog[39680]: /usr/local/www/horde/imp/lib/IMP.php: 322
Feb 14 18:11:13 earth myScripLog[39680]: /usr/local/www/horde/imp/lib/IMP.php: 337
Feb 14 18:11:13 earth HORDE[39680]: [imp] [/login.php] Login Attempt(flags: 64, connstr: {earth.hub.org:143/imap}): 142.177.110.175 to earth.hub.org:143[imap] as scrappy with [HBUAAA==#0fINATo8OiEL] [on line 338 of "/usr/local/www/horde/imp/lib/IMP.php"]
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/imp/lib/IMP.php: 351
Feb 14 18:11:13 earth HORDE[39680]: [imp] [] FAILED LOGIN 142.177.110.175 to earth.hub.org:143[imap] as scrappy [on line 352 of "/usr/local/www/horde/imp/lib/IMP.php"]
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/imp/lib/api.php: 60
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/lib/Registry.php: 232
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/lib/Registry.php: 239
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/login.php: 75
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/login.php: 71
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/login.php: 81
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/login.php: 85
Feb 14 18:11:13 earth HORDE[39680]: /usr/local/www/horde/login.php: 95

In particular, lines 27/33, in imp/lib/api.h, revolves around:

        syslog(LOG_DEBUG , __FILE__ . ": ". __LINE__ );
    if (IMP::authenticate(OP_HALFOPEN, true) === true) {
        syslog(LOG_DEBUG , __FILE__ . ": ". __LINE__ );

And, adding a bit of code to Registry.php's syslog output:

Feb 14 18:16:26 earth myScripLog[46623]: /usr/local/www/horde/lib/Registry.php: 230 => function == impSummary ; args = Array

shows the 'offending' registry entry is impSummary() ...

which is defined on my system as:

$this->services['imp']['horde']['summary'] = array(
    'file' => '%application%/lib/api.php',
    'function' => 'impSummary',
    'args' => array(),
    'type' => 'string'
);

Does this help?  Can I provide any more detail that might shed further
light on this?