[horde] ActiveSync 2.0.12 update, error finding IMAP Server

Wed Dec 26 02:47:05 UTC 2012

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..! :(
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 :)

--Tom

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