[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"]

Tue Jan 7 15:10:24 UTC 2014

Quoting Simon B <simon.buongiorno at gmail.com>:

> On 6 January 2014 19:25, Michael J Rubinsky <mrubinsk at horde.org> wrote:
>>
>> Quoting Simon B <simon.buongiorno at gmail.com>:
>>
>>> 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
>>
>>
>> This won't show anything because the debug line won't be reached when auth
>> fails.
>>
>>>
>>>  721             return $result;
>>> So, $result immediately below it
>>
>>
>> This won't show anything because the code returns before the debug line is
>> reached.
>>
>>
>>> 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.
>>
>>
>>
>> Anyway, from what you are telling me authentication is failing in Horde, so
>> the ActiveSync library code doesn't matter. Do this to verify:
>>
>> In Horde_Core_ActiveSync_Driver:: on line 213 (currently blank), right
>> before the comment about trying Basic auth, add something like
>>
>> Horde::debug($conf['activesync']['auth']['type']);
>>
>> This will output the configured activesync auth type, as well as provide a
>> sanity check that the code is reached. Then, between line 216 and 217 add:
>>
>> Horde::debug('Authentication failed');
>>
>> This will show that authentication failed when checking the horde auth
>> backend.
>>
>>
>> For completeness, add this between 231 and 232
>>
>> Horde::debug('Permission check failed.');
>>
>> This shows that the device or user was denied access based on permission
>> settings.
>>
>> Then finally on line 235 add Horde::debug('So far so good.');
>>
>> This shows that up to that point authentication succeeded, and I have no
>> idea wtf is going on.
>
> Hi Michael
>
> Here's the horde_debug.txt
>
> root at mail:~# less /tmp/horde_debug.txt
> 2014-01-07T09:10:39+00:00 DEBUG: Variable information:
> string(5) "basic"
>
> 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:725
> 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:213
>
> 2014-01-07T09:10:39+00:00 DEBUG: Variable information:
> string(21) "Authentication failed"

Ok. This means that Horde's authentication backend does not accept  
your credentials. It's not ActiveSync code.

> 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:725
> 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-07T09:10:39+00:00 DEBUG: Variable information:
> string(17) "simon at example.net"

Is this the correct username? I.e., do you use the full email address  
when you log in to Horde's interface?

>
> 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:725
> 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
>
> 2014-01-07T09:10:39+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:725
> 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:219
>
> According to Horde, the authentication is failing.  And yet the
> password is correct.  To prove this, I've copied the password in the
> Horde_debug.txt into the Mail database  (not that I believe two
> different devices are somehow sending it wrong) before doing the
> authentication again.

If the activesync library is sending the correct username and password  
to horde's authentication backend, and it is rejecting it, it is not  
something in the activesync code that is broken.

> For this last attempt, I turned on mysql logging to check my theory
> that it wasn't trying to authenticate using the wrong details (I
> manages to isolate just my attempt to set up the account, but I'll
> send you the log off list).  However, that proved to me that it IS
> using the IMAP auth details and even seems to initiate a sync (the
> time-stamps are a full 7 seconds later than the timestamps in the
> horde_debug.txt).
>
> How would I roll back to the previous version (or say the version that
> was there on the 21st of Dec when it was last known to be working?  I
> know it's working for you, but something in the new AS code is funky
> (at least on my system).  A git pull should overwrite any changes I've
> made to  
> /usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php
> and any other files, yes?

If you are using Git, you can checkout a specific commit id that you  
know was working for you:

git checkout {commit hash}

you can use the commit history on github to find a commit you want to  
revert to:

https://github.com/horde/horde/commits/master

However, this will roll back *ALL* changes between current HEAD and  
that commit, not just the ActiveSync library. It's worth noting that  
NOTHING related to authentication changed in the ActiveSync code  
between 12/21 and today.
-- 
mike

The Horde Project (www.horde.org)
mrubinsk at horde.org
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 5849 bytes
Desc: S/MIME Signature
URL: <http://lists.horde.org/archives/horde/attachments/20140107/d7f090e5/attachment-0001.bin>