[horde] ActiveSync 2.0.12 update, error finding IMAP Server

Wed Dec 26 02:58:30 UTC 2012

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.

> 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.

-- 
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: 6062 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.horde.org/archives/horde/attachments/20121225/349cc6de/attachment.bin>