[horde] ActiveSync 2.0.12 update, error finding IMAP Server

Wed Dec 26 03:34:42 UTC 2012

Zitat von Michael J Rubinsky <mrubinsk at horde.org>:

> Quoting Tom Buehlmann <tomnet at tbuhl.ch>:
>
>> Zitat von Michael J Rubinsky <mrubinsk at horde.org>:
>>
>>> Quoting tomnet at tbuhl.ch:
>>>
>>>> Hello
>>>>
>>>> I opend a different thread as mike thinks mine is a different issue.
>>>>
>>>>> ----- Original Message ----- From: "Samuel Wolf" <samuel at sheepflock.de>
>>>>> To: <horde at lists.horde.org>
>>>>> Sent: Tuesday, December 25, 2012 4:48 PM
>>>>> Subject: Re: [horde] ActiveSync 2.0.12 update, account error  
>>>>> Android 2.3.6
>>>>>
>>>>>
>>>>>>
>>>>>> Zitat von Michael J Rubinsky <mrubinsk at horde.org>:
>>>>>>
>>>>>>> If possible, an email that causes this to break would be helpful.
>>>>>>>
>>>>>>> mike
>>>>>>
>>>>>> I do not know which of all emails in the inbox break activesync.
>>>>>>
>>>>>
>>>>> I don't think it's a specific mail.
>>>>> Reading the ActiveSync Debug log (below) it looks like it "lost" the
>>>>> IMAP server..(Unable to obtain the IMAP Client...)
>>>>> This is a different issue, I believe. I've been trying to track this
>>>>> one down for quite some time - I have never been able to reproduce
>>>>> this, so any additional information you can provide would be helpful.
>>>>> Does this go away if you downgrade?
>>>>
>>>> No, i tried ActiveSync 2.0.11 and no change.
>>>>
>>>> I upgraded to 2.0.12 again and reset the device in the admins  
>>>> ActiveSync tab.
>>>> The Error message then changed to:
>>>> Problem loading mail folders from IMAP server
>>>> (See log below)
>>>> I use dovecot 2.0.16 on an opensuse 12.1 box with horde current to pear.
>>>> In the dovecot log i see several connection attempts from  
>>>> localhost (::1), this can only be horde as no other local mua  
>>>> exists.
>>>> Unfortunately my xperia go wont let me get a emaillog.txt.
>>>>
>>>> --Tom
>>>>
>>>> 2012-12-25T21:09:17+00:00 INFO:  
>>>> Horde_Core_ActiveSync_Driver::authenticate() attempt for: tom
>>>> 2012-12-25T21:09:17+00:00 DEBUG: [androidc1311749349] OPTIONS  
>>>> request received for user tom
>>>> 2012-12-25T21:09:17+00:00 DEBUG: [androidc1311749349] Device  
>>>> entry does not exist, creating it.
>>>> 2012-12-25T21:09:17+00:00 DEBUG: [androidc1311749349] Device  
>>>> entry does not exist for user tom, creating it.
>>>> 2012-12-25T21:09:18+00:00 INFO:  
>>>> Horde_Core_ActiveSync_Driver::authenticate() attempt for: tom
>>>> 2012-12-25T21:09:19+00:00 DEBUG: [androidc1311749349] FOLDERSYNC  
>>>> request received for user tom
>>>> 2012-12-25T21:09:19+00:00 DEBUG: [androidc1311749349] loadDeviceInfo: tom
>>>> 2012-12-25T21:09:19+00:00 INFO: Request being handled for device:  
>>>> androidc1311749349 Supporting protocol version: 2.5
>>>> 2012-12-25T21:09:19+00:00 INFO: [androidc1311749349] Handling  
>>>> FOLDERSYNC command.
>>>> 2012-12-25T21:09:19+00:00 DEBUG: [androidc1311749349] Checking  
>>>> policykey for device: 0 user: tom
>>>> 2012-12-25T21:09:19+00:00 DEBUG: [androidc1311749349] Stored key: 0
>>>> 2012-12-25T21:09:19+00:00 DEBUG: Policykey:  verified.
>>>> 2012-12-25T21:09:19+00:00 DEBUG: I  <FolderHierarchy:FolderSync>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: I   <FolderHierarchy:SyncKey>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: I    0
>>>> 2012-12-25T21:09:19+00:00 DEBUG: I   </FolderHierarchy:SyncKey>
>>>> 2012-12-25T21:09:19+00:00 DEBUG:  
>>>> [Horde_ActiveSync::handleFolderSync] syncKey: 0
>>>> 2012-12-25T21:09:19+00:00 DEBUG: [11017] Resetting device state.
>>>> 2012-12-25T21:09:19+00:00 DEBUG: Adding new SYNC_CACHE entry for  
>>>> user tom and device androidc1311749349:  
>>>> a:11:{s:18:"confirmed_synckeys";a:0:{}s:17:"lasthbsyncstarted";b:0;s:17:"lastsyncendnormal";b:0;s:9:"lastuntil";b:0;s:9:"timestamp";s:10:"1356469759";s:4:"wait";b:0;s:10:"hbinterval";b:0;s:7:"folders";a:0:{}s:9:"hierarchy";b:0;s:11:"collections";a:0:{}s:14:"synckeycounter";a:0:{}}
>>>> 2012-12-25T21:09:19+00:00 DEBUG: I  </FolderHierarchy:FolderSync>
>>>> 2012-12-25T21:09:19+00:00 DEBUG:  
>>>> [Horde_ActiveSync::handleFolderSync] newSyncKey:  
>>>> {50da15ff-74ac-47c2-9757-2b09c0a8000a}1
>>>> 2012-12-25T21:09:19+00:00 DEBUG: [11017] Initializing folder diff engine
>>>> 2012-12-25T21:09:19+00:00 DEBUG:  
>>>> Horde_Core_ActiveSync_Driver::getFolderList()
>>>> 2012-12-25T21:09:19+00:00 DEBUG: Polling  
>>>> Horde_Core_ActiveSync_Driver::_getMailFolders()
>>>> 2012-12-25T21:09:19+00:00 ERR: Problem loading mail folders from  
>>>> IMAP server:
>>>> 2012-12-25T21:09:19+00:00 ERR:
>>>> 2012-12-25T21:09:19+00:00 DEBUG: [11017] No folder changes found.
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O  <FolderHierarchy:FolderSync>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O   <FolderHierarchy:Status>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O    1
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O   <FolderHierarchy:Status/>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O   <FolderHierarchy:SyncKey>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O    0
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O   <FolderHierarchy:SyncKey/>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O   <FolderHierarchy:Changes>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O    <FolderHierarchy:Count>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O     0
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O    <FolderHierarchy:Count/>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O   <FolderHierarchy:Changes/>
>>>> 2012-12-25T21:09:19+00:00 DEBUG: O  <FolderHierarchy:FolderSync/>
>>>> 2012-12-25T21:09:19+00:00 INFO: User tom logged off
>>>>
>>>>>
>>>>> Perhaps this can help any further?
>>>>> If you need more debug logs i'd be happy to help.
>>>
>>> I'm pushing a new release of Horde/Rpc that *might* fix this  
>>> issue. Can you let me know if it works or not after you update  
>>> Horde/Rpc?
>>>
>>>
>> No, sorry mike, no luck..! :(
>
> Darn. I thought for sure that would do it. I'm at a loss here.  
> Something is causing IMP to drop the IMAP connection at some point  
> *after* the user has already authenticated to Horde.
>

But IMP itself works without problems. I'm writing this mail with IMP  
on the problematic acccount.
>

>> Still "Problem loading mail folders..."
>> Strange thing is, that only one user seems to be affected. I can  
>> create another or use an existing one and it works fine.
>> Deleting the affected user including all mail related files didn't fix it.
>> What i tried further:
>> -Removed all imap folders (except of course inbox)
>> -Deleting the user account (physical user)
>> -Delete Activesync related entries in the database and rebuild with  
>> horde-db-migrate
>> -removed ingo and his preferences in the DB
>> -tried to get my mobile to write a maillog.txt ;)
>>
>> any ideas what i can try further?
>> I'm running out of ideas :)
>
> Yeah, me too.

Well, in this case i use activesync for calendar and adresses, and good ol'
imap directly on my phone (witch, of course, works with the defective  
account...)

Perhaps i have another idea tomorrow, it's late now here...!

Since it's my personal machine, i keep the defective account for  
further investigation, so if anyone has an idea..?!

-- Tom

>
> -- 
> mike
>
> The Horde Project (www.horde.org)
> mrubinsk at horde.org