[horde] EMERG: HORDE-BETA Missing required state object [pid 15927 on line 122 of "/usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/Driver/Base.php"]

[Simon B]

On 6 January 2014 17:47, Michael J Rubinsky <mrubinsk at horde.org> wrote:
>
> Quoting Michael J Rubinsky <mrubinsk at horde.org>:
>
>> Quoting Simon B <simon.buongiorno at gmail.com>:
>>
>>>> Horde::debug($variable_name);
>>>>
>>>> Will output the contents of said variable to horde_debug.txt in your tmp
>>>> directory. The call on line 216 is probably the one that you are most
>>>> interested in.
>>>
>>>
>>>
>>> Hi Michael
>>>
>>> Introducing Horde::debug($username); and Horde::debug($password);
>>> after line 216 of
>>>
>>> "/usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php"
>>> yields:
>>>
>>> ==> /tmp/horde_debug.txt <==
>>> 2014-01-06T08:59:32+00:00 DEBUG: Variable information:
>>> string(17) "simon at example.net"
>>>
>>> Backtrace:
>>> 1. Horde_Rpc_ActiveSync->getResponse()
>>> /usr/share/git-horde5/horde/rpc.php:156
>>> 2. Horde_ActiveSync->handleRequest()
>>> /usr/share/git-horde5/framework/Rpc/lib/Horde/Rpc/ActiveSync.php:122
>>> 3. Horde_ActiveSync->authenticate()
>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php:723
>>> 4. Horde_Core_ActiveSync_Driver->authenticate()
>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php:561
>>> 5. Horde::debug()
>>>
>>> /usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php:217
>>>
>>> 2014-01-06T08:59:32+00:00 DEBUG: Variable information:
>>> string(18) "CorrectPassword"
>>>
>>> Backtrace:
>>> 1. Horde_Rpc_ActiveSync->getResponse()
>>> /usr/share/git-horde5/horde/rpc.php:156
>>> 2. Horde_ActiveSync->handleRequest()
>>> /usr/share/git-horde5/framework/Rpc/lib/Horde/Rpc/ActiveSync.php:122
>>> 3. Horde_ActiveSync->authenticate()
>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php:723
>>> 4. Horde_Core_ActiveSync_Driver->authenticate()
>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php:561
>>> 5. Horde::debug()
>>>
>>> /usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php:218
>>>
>>> This tells me nothing other than than the variables being entered are
>>> actually correct (well, at least this wasn't all my fat fingers).  I
>>> still see no authentication attempt in the IMAP server logs (but then
>>> should I expect to - I mean I don't see authentication attempts for
>>> every activesync attempt, so probably not).
>>
>>
>> You *should* see IMAP login for each discreet ActiveSync connection.
>>
>>
>>> In an effort to attempt to look competent, I added
>>> Horde::debug($result); to
>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php:561
>>> and
>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php:723
>>> but neither of these resulted in extra output in horde_debug.txt

>> It's not clear from your comment exactly where you placed the debug call
>> in relation to the authenticate calls, but this is probably expected since
>> it seems that authentication fails in the Core driver.

Hi Michael

In all instances I simply inserted a carriage return and added the
debug code on a separate line immediately below the line numbers
listed in the backtrace.

 561         if ($result = $this->_driver->authenticate($user, $pass,
$domain)) {
So, $result immediately below it

 721             return $result;
So, $result immediately below it

Looking at this after a day's worth of coffee consumption, I think
might have put it in the wrong place.  If you agree, I can put it
somewhere else.

>>> Neither did adding  Horde::debug($this); to
>>> /usr/share/git-horde5/framework/Rpc/lib/Horde/Rpc/ActiveSync.php:122
>>
>>
>> Again, without knowing exactly where the line was in relation to the other
>> code (since 122 currently has code on it), not sure. Though it's worth
>> mentioning the conditional on that line deals only with OPTIONS requests.

122                     if (!$this->_server->handleRequest('Options', null)) {

So here I put $this after line 122


>>> Then I did something wrong.  Adding debugs for for the variables on
>>> /usr/share/git-horde5/framework/Rpc/lib/Horde/Rpc/ActiveSync.php:122
>>
>>
>> *What* variables?

122                     if (!$this->_server->handleRequest('Options', null)) {

So here I put $this after line 122


>>> and /usr/share/git-horde5/horde/rpc.php:156 resulted in 24k lines out
>>> output :)  Including details about my entire installation and all
>>> related configs.

156         $out = $server->getResponse($input);

Here I put $server and $input *before* line 156 and $out after it

>>> Could it be that ActiveSync is somehow trying to sync against the
>>> horde DB and not against the IMAP server?
>>
>>
>> ActiveSync uses the authentication driver configured for Horde. If this is
>> IMAP (or Application/IMP) then it will use the IMAP server.

> Also, make sure that you have 'hordeauth' set appropriately in
> imp/config/backends.local.php

This is "full" as it has always been (and is in prod, where I
currently have no problems authenticating).

Simon