Ok, so, I was able to get to a point where Lollipop will see the emails,
contacts and calendars, but in a non-user acceptable way. Maybe someone can
help me improving my current solution. Here is the list of problems I found
out so far:

1 - Sending duplicate folders is a show stopper. Fixing it won't solve the
problem by itself but it is a necessary step toward fixing it. I created a
patch to ugly-ly fix the problem at the ActiveSync level to test this. I
created a bug at http://www.sogo.nu/bugs/view.php?id=3268 about this
problem.

2 - Android Lollipop doesn't like special folders as a child folder of
INBOX. Since on my setup I migrated from courier-imap about three years ago
everything is under INBOX. I created a patch that moves the folder to the
place Android is expecting and it was a necessary step towards making
Lollipop work. http://www.sogo.nu/bugs/view.php?id=3269

I think those were both great steps considering I have never had any
contact with the ActiveSync spec or with Objective-C before. I had a sick
day yesterday so a lot of time was available :).

Moving on now there is still the invalid SyncKey problem. I have found a
work-arround it. After the creation of the accountm wait for it to finish
syncing, uncheck sync of Mail, Contacts and Calendar, and then check them
again, one at a time, waiting for it to finish syncing. Usually Calendar
will take a long time to sync while the other ones will be fast.

If you do all that you will be able to access all your mail, contacts and
calendar events and even create your own contact!

I was wondering if anyone woud have any tip on the SyncKey problem. We seem
to be sending something take makes Android's Exchange code CPU-busy for
long seconds, eating a lot of battery, for up to one minute. Then it gets
back to a previous state where the error happens. I couldn't figure out
what it is. I'm thinking about opening another bug but I would like to have
at least a patch or to understand the problem better before doing that.

This is the log of my last run, with both patches and the work-arround:
http://pastebin.com/hd0TmUb5
Screenshots of it working: http://ibin.co/26RDMOm7Z1FH
http://ibin.co/26RDQSQHUhIe http://ibin.co/26RDUpQbiqqv
http://ibin.co/26RDYZibLjMX http://ibin.co/26RDcwiva42L

One strange think I saw was at line 1596 of the log where it send two
requests without getting an answer to the first one.

Thank you all for the help, I think we can make it work!

Best,
Daniel Colchete


On Wed, Jun 24, 2015 at 5:42 PM, Daniel van Ham Colchete <
[email protected]> wrote:

> Hi Thomas!
>
> Thanks for the tips. So, here is what I did. I renamed every folder with
> special chars to its ASCII version. I also added an email to every mail
> folder that should exist: INBOX, Trash, Draft, Sent. Also wiped the device
> I used for testing. When I tried again I had to luck. I sill had the same
> problems.
>
> So, trying to get a better insight in the problem I got an Android
> emulator to test everything. The test producedure was:
> 1 - Wipe the device
> 2 - Create a new Account
> 3 - Wait for it to sync
> 4 - Access Email, Contact, Calendar
>
> Here are the results:
>
> Android 4.3:
>  - Contacts, Email and Calendar sync worked. The only noticeable problem
> was that mail folders where appearing duplicated.
>  - Logs: http://pastebin.com/CrD6gmGh
>  - Images: http://ibin.co/26N7rDTtOMCN http://ibin.co/26N828zhyJVf
> http://ibin.co/26N8H89gTrgF http://ibin.co/26N8PsAKwMNE
>
> Android 5.0:
>  - Nothing synced, Contacts and Calanders don't recognize the folders,
> Email is always trying to "Get new messages"
>  - Logs: http://pastebin.com/XMb19rPK
>  - Images: http://ibin.co/26N8iIG8m9Id http://ibin.co/26N8zSvHOjNo
> http://ibin.co/26N949HlvmH2
>
> Looking at Android 5 SOGo's logs, I saw that SyncKey error I noticed.
> Looking at the PIDs it seems that Android is using two connections in
> parallel to sync different stuff and the first connection didn't know about
> the SyncKey change. It seems to be using connection 6065 and 6071.
>
> Connection 6071 happenned between Jun 24 16:15:02 and Jun 24 16:15:33.
> Connection 6065 happenned between Jun 24 16:16:19 and Jun 24 16:16:21.
>
> Here connection 6071 received the *-2 SyncKey:
>
> Jun 24 16:15:17 sogod [6071]: <0x0x7f6970847e40[SOGoActiveSyncDispatcher]>
> EAS - request for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <SyncKey>0</SyncKey>
> </FolderSync>
>
> Jun 24 16:15:18 sogod [6071]: <0x0x7f6970847e40[SOGoActiveSyncDispatcher]>
> EAS - response for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <Status>1</Status>
>  <SyncKey>mia1-sogo_17b7_1b3b3936_2</SyncKey>
>  <Changes>
>
>
> Connection 6071 latter will sync Mail, Calendar and Contact stuff.
>
> After syncing everything it starts over! Like something bad happened. And
> then it gets the mia1-sogo_17b7_1b3b3936_3 SyncKey.
>
> Jun 24 16:15:26 sogod [6071]: <0x0x7f6970cda900[SOGoActiveSyncDispatcher]>
> EAS - request for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <SyncKey>0</SyncKey>
> </FolderSync>
>
> Jun 24 16:15:26 sogod [6071]: <0x0x7f6970cda900[SOGoActiveSyncDispatcher]>
> EAS - response for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <Status>1</Status>
>  <SyncKey>mia1-sogo_17b7_1b3b3936_3</SyncKey>
>
>
> Connection 6071 will then procede to syncing Mail, but not Calendars and
> Contacts.
>
> Connection 6065 starts about 44 seconds latter syncing Calendars and
> Contacts, but not Mail. Before calling FolderSync again but as if it didn't
> know about 6071's last FolderSync.
>
> Here is where it sends the wrong key before sending the right one on the
> 6065 connection:
>
> Jun 24 16:16:20 sogod [6065]: 187.20.229.6 "POST
> /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=daniel.teste%40mav.com.br&DeviceId=android1435173182656&DeviceType=Android
> HTTP/1.1" 20
> 0 530/65 0.021 - - 0
> Jun 24 16:16:20 sogod [6065]: <0x0x7f6970d00690[SOGoActiveSyncDispatcher]>
> EAS - request for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <SyncKey>mia1-sogo_17b7_1b3b3936_2</SyncKey>
> </FolderSync>
>
> Jun 24 16:16:20 sogod [6065]: <0x0x7f6970d00690[SOGoActiveSyncDispatcher]>
> EAS - response for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <Status>9</Status>
> </FolderSync>
>
> Jun 24 16:16:20 sogod [6065]: 187.20.229.6 "POST
> /SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync&User=daniel.teste%
> 40mav.com.br&DeviceId=android1435173182656&DeviceType=Android HTTP/1
> .1" 200 13/37 0.002 - - 0
> Jun 24 16:16:21 sogod [6065]: <0x0x7f6970d20c20[SOGoActiveSyncDispatcher]>
> EAS - request for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <SyncKey>mia1-sogo_17b7_1b3b3936_3</SyncKey>
> </FolderSync>
>
> Jun 24 16:16:21 sogod [6065]: <0x0x7f6970d20c20[SOGoActiveSyncDispatcher]>
> EAS - response for device android1435173182656: <?xml version="1.0"?>
> <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
> http://www.microsoft.com/";>
> <FolderSync xmlns="FolderHierarchy:">
>  <Status>1</Status>
>  <SyncKey>mia1-sogo_17b7_1b3b3936_3</SyncKey>
>  <Changes>
>   <Count>0</Count>
>  </Changes>
> </FolderSync>
>
>
> I tried looking at Android's debug logs (logcat) but I couldn't find
> anything there. I think that sending duplicate mail folders might be
> causing the issue but I couldn't find anything on my configuration that
> would do that. SOGO's web interface is running smoothly (as is ActiveSync
> with IOS 8.3 and Outlook 2013).
>
> What do you guys think?
>
> Best,
> Daniel Colchete
>
> On Wed, Jun 24, 2015 at 1:48 PM, Thomas Fuehrer <[email protected]> wrote:
>
>>
>> Am Mittwoch, 24. Juni 2015 18:33 CEST, "Thomas Fuehrer" <[email protected]>
>> schrieb:
>>
>> > > this is the log with SOGoEASDebugEnabled = YES:
>> http://pastebin.com/S1MVyEtp
>> > >
>> > > From what I could see it is sending the info correctly. At least all
>> my
>> > > items are there.
>> > >
>> > > Is there a way to debug the Android side?
>> >
>> > What I see in the log looks very strange to me. The device gets the
>> folders via foldersync and then syncs mails, calendar and contacts.
>> > Later the devices sends another foldersync but since the synckey
>> doesn't match the servers expectation the response is with
>> > status=9 causing the device to forget all folders and so start over.
>> > I've not seen that a device sends 2 foldersync requests with different
>> synckey at the same time:
>> >
>> > ....
>> > Jun 23 19:12:47 sogod [32522]: 187.114.2.106 "POST
>> /SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync&User=daniel.teste%
>> 40mav.com.br&DeviceId=android1435097460670&DeviceType=Android HTTP/1.1"
>> 200 281/13 0.370 - - -76K
>> > Jun 23 19:12:47 sogod [32522]:
>> <0x0x7fd054187fc0[SOGoActiveSyncDispatcher]> EAS - request for device
>> android1435097460670: <?xml version="1.0"?>
>> > <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
>> http://www.microsoft.com/";>
>> > <FolderSync xmlns="FolderHierarchy:">
>> >  <SyncKey>mia1-sogo_7f0a_1b3a1154_0</SyncKey>
>> > </FolderSync>
>> >
>> > Jun 23 19:12:47 sogod [32522]:
>> <0x0x7fd054187fc0[SOGoActiveSyncDispatcher]> EAS - response for device
>> android1435097460670: <?xml version="1.0"?>
>> > <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
>> http://www.microsoft.com/";>
>> > <FolderSync xmlns="FolderHierarchy:">
>> >  <Status>9</Status>
>> > </FolderSync>
>> >
>> > Jun 23 19:12:47 sogod [32522]: 187.114.2.106 "POST
>> /SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync&User=daniel.teste%
>> 40mav.com.br&DeviceId=android1435097460670&DeviceType=Android HTTP/1.1"
>> 200 13/37 0.003 - - 0
>> > Jun 23 19:12:48 sogod [32522]:
>> <0x0x7fd0546dbef0[SOGoActiveSyncDispatcher]> EAS - request for device
>> android1435097460670: <?xml version="1.0"?>
>> > <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
>> http://www.microsoft.com/";>
>> > <FolderSync xmlns="FolderHierarchy:">
>> >  <SyncKey>mia1-sogo_7f0a_1b3a1154_1</SyncKey>
>> > </FolderSync>
>> >
>> > Jun 23 19:12:48 sogod [32522]:
>> <0x0x7fd0546dbef0[SOGoActiveSyncDispatcher]> EAS - response for device
>> android1435097460670: <?xml version="1.0"?>
>> > <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
>> http://www.microsoft.com/";>
>> > <FolderSync xmlns="FolderHierarchy:">
>> >  <Status>9</Status>
>> > </FolderSync>
>> > ....
>> >
>> > Have you removed the eas profile from your mobile? Any leftovers from
>> previous tests?
>> >
>> > Check the logfile whether following response is continuously   sent:
>>
>> > <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "
>> http://www.microsoft.com/";>
>> > <FolderSync xmlns="FolderHierarchy:">
>> >  <Status>9</Status>
>> > </FolderSync>
>> >
>> > Regards,
>> > Thomas
>>
>>
>> A view more things to check whether the foldersync response is the
>> problem:
>> Send a mail via the web ui and delete a mail via the web ui.
>> -> this will create the Sent and the Trash folder (I haved seen these
>> folder in the the log)
>> Rename the Calendar folder (Calendário Pessoal) -> remove the á
>>
>> ... not sure whether this changes anything, but ....
>>
>> Regards,
>> Thomas
>>
>
>
-- 
[email protected]
https://inverse.ca/sogo/lists

Reply via email to