[horde] FW: [sync] Activesync Errors
Simon Brereton
simon.brereton at buongiorno.com
Fri Sep 30 20:37:51 UTC 2011
> -----Original Message-----
> From: horde-bounces at lists.horde.org [mailto:horde-
> bounces at lists.horde.org] On Behalf Of Michael J Rubinsky
> Quoting Simon Brereton <simon.brereton at buongiorno.com>:
>
> >> -----Original Message-----
> >> From: horde-bounces at lists.horde.org [mailto:horde-
> >> bounces at lists.horde.org] On Behalf Of Michael J Rubinsky Quoting
> >> Simon Brereton <simon.brereton at buongiorno.com>:
> >>
> >> > Originally submitted to sync at lists.horde.org - perhaps that's
> the
> >> not
> >> > the right location?
> >> >
> >> >
> >> > Address book is a whole other ball game. I created a new
> contact
> >> on
> >> > the phone and it never appeared in Horde. None of the contacts
> in
> >> > Horde appear on the phone either.
> >> >
> >> > The sync.log has these errors:
> >> >
> >> > 2011-09-29T20:29:45+01:00 ERR: Returning HTTP 500:Invalid date
> >> format
> >> > 2011-09-29T20:30:39+01:00 ERR: Invalid address book:
> >> > b3790d4757f941c995645660f0ba886c 2011-09-29T20:30:39+01:00 ERR:
> >> > Invalid address book: b3790d4757f941c995645660f0ba886c
> >> > 2011-09-29T20:30:39+01:00 ERR: Invalid address book:
> >> > b3790d4757f941c995645660f0ba886c 2011-09-29T20:30:39+01:00 ERR:
> >> > Returning HTTP 500:Invalid date format 2011-09-29T20:31:55+01:00
> >> > ERR: Invalid address book:
> >>
> >> Your client is sending broken activesync date datatypes. Per the
> >> specification:
> >
> > Odd. I could have sworn that was from Horde to the client.
>
> Well, the only place this error is thrown is during WBXML stream
> *decoding*, which means it is coming from the client. When it comes
> from the server we control the format and ensure it is sent
> correctly.
> Plus, any errors in date format when going server->client (which
> would only happen if the turba data became corrupt), would be
> silently ignored and no date would be sent to the client.
Well, it wouldn't be the first time I was wrong - especially as I was syncing before I got the logging sorted. I agree that it's device to server - see below. Apologies for the noise.
> > Basically, when I removed Funambol from the device the contacts
> list
> > on the phone was emptied. I waited 3 hours and nothing was synched
> > from Horde to the device (as I would have expected and as was the
> case
> > with the calendar). In an effort to prompt it, I created a test
> > contact on the phone (just a name, no number, no DoB, no email)
> > and waited for it to be synched to Horde. After 2 hours - nada.
> > Since I needed my contacts, I reloaded them (under the Activesync
> > account) from an vcard I have on the device SD card...
>
> I'm confused...You mean you reloaded them from the SD card directly
> onto the device? If that's the case, then of course these would be
> changes from the device to server, you are essentially adding new
> contacts to the device.
>
> > .. The caveat is that vcard on the SD card is a direct export from
> Horde...
>
> Again, what are you doing with the vcard on the SD card?
Long story and rather boring. Short version, Funambol wouldn't store the contacts in the same format I had them in Turba (+1-347-xxx-xxxx vs. +1347xxxxxxx) and that meant that if I let Funambol synch them, I ended up with duplicates in Turba. And I didn't see why Turba should fix Funambol's problem.
> > Not saying that Horde isn't doing what it should be - but I have a
> > standard OG Droid - have you heard of an issue where it doesn't
> send
> > the date in UTC? Since the only dates in the contact forms (and in
> > the logs) that I can see are birthdates - i.e. 1964-01-01 - I'm not
> > sure how to address this.
>
> I also have a OG Droid as my primary day to day phone. I have no
> issues with this at all.
Stepping back for a moment - before I loaded the contacts from the SD card, I created a test contact on the phone. That one never got to the server even though it was the only one on the phone. However, a test contact created in Horde was also not sent to the device. Given how quickly Kronolith sent the event, I'm surprised/confused/baffled.
I think there shouldn't be an issue with the date because that data was imported from Horde (unless Horde isn't exporting it correctly - which I doubt). But realistically, the bigger problem I have have/had is that contacts aren't synching in either direction.
If they had just synched from Horde to the device then I wouldn't have an issue..
Since I've never seen a synch attempt from Horde to the device, I can only assume that during a sync it asks the Device if it has anything new first. Accordingly I deleted the account - all contacts are now gone.
I recreate the account and all I have in the logs is:
2011-09-30T21:32:52+01:00 INFO: Horde_ActiveSync_Driver_Horde::logon attempt for: simon at mydomain.net
2011-09-30T21:32:52+01:00 DEBUG: [androidc1387223434] FOLDERSYNC request received for user simon at mydomain.net
2011-09-30T21:32:52+01:00 DEBUG: [androidc1387223434] loadDeviceInfo: simon at mydomain.net
2011-09-30T21:32:52+01:00 DEBUG: Resetting PING state
2011-09-30T21:32:52+01:00 INFO: Request being handled for device: androidc1387223434 Supporting protocol version: 2.5
2011-09-30T21:32:52+01:00 INFO: [Horde_ActiveSync::handleFolderSync] Beginning FOLDERSYNC
2011-09-30T21:32:52+01:00 DEBUG: [androidc1387223434] Checking policykey for device Key: 0 User: simon at mydomain.net
2011-09-30T21:32:52+01:00 DEBUG: [androidc1387223434] loadDeviceInfo: simon at mydomain.net
2011-09-30T21:32:52+01:00 DEBUG: Policykey: verified.
2011-09-30T21:32:52+01:00 DEBUG: I <FolderHierarchy:FolderSync>
2011-09-30T21:32:52+01:00 DEBUG: I <FolderHierarchy:SyncKey>
2011-09-30T21:32:52+01:00 DEBUG: I {munged-data}1
2011-09-30T21:32:52+01:00 DEBUG: I </FolderHierarchy:SyncKey>
2011-09-30T21:32:52+01:00 DEBUG: [Horde_ActiveSync::handleFolderSync] syncKey: {munged-data}1
2011-09-30T21:32:52+01:00 DEBUG: [androidc1387223434] Loading state for synckey {munged-data}1
2011-09-30T21:32:52+01:00 DEBUG: [androidc1387223434] Loading FOLDERSYNC state: Array
(
[0] => Array
(
[id] => Tasks
[mod] => Tasks
[parent] => 0
)
[1] => Array
(
[id] => Contacts
[mod] => Contacts
[parent] => 0
)
[2] => Array
(
[id] => Calendar
[mod] => Calendar
[parent] => 0
)
)
2011-09-30T21:32:52+01:00 DEBUG: I </FolderHierarchy:FolderSync>
2011-09-30T21:23:56+01:00 DEBUG: [Horde_ActiveSync::handleFolderSync] Preparing to send changes to PIM
2011-09-30T21:23:56+01:00 DEBUG: [Horde_ActiveSync::handleFolderSync] newSyncKey: {munged-data}2
2011-09-30T21:23:56+01:00 DEBUG: [androidc1387223434] Initializing folder diff engine
2011-09-30T21:23:56+01:00 DEBUG: Horde::getFolderList()
2011-09-30T21:23:56+01:00 DEBUG: Horde::statFolder(Calendar)
2011-09-30T21:23:56+01:00 DEBUG: Horde::statFolder(Contacts)
2011-09-30T21:23:56+01:00 DEBUG: Horde::statFolder(Tasks)
2011-09-30T21:23:56+01:00 DEBUG: [androidc1387223434] Found 0 folder changes
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:FolderSync>
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:Status>
2011-09-30T21:23:56+01:00 DEBUG: O 1
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:Status/>
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:SyncKey>
2011-09-30T21:23:56+01:00 DEBUG: O {munged-data}1
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:SyncKey/>
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:Changes>
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:Count>
2011-09-30T21:23:56+01:00 DEBUG: O 0
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:Count/>
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:Changes/>
2011-09-30T21:23:56+01:00 DEBUG: O <FolderHierarchy:FolderSync/>
2011-09-30T21:23:56+01:00 INFO: User simon at mydomain.net logged off
Now I have nothing in the calendar or the address book :)
> >> The invalid address book error sounds to me like your "default"
> >> address book is either corrupt or pointing to an address book that
> no
> >> longer exists.
> >
> > How do I debug that? I mean ever since I installed H4 and imported
> > the data from the H3 DB and updates the schemas everything has
> worked
> > fine. I can see my default address book, add, edit and delete with
> no
> > issue. I have only one address book, so I can't really see how
> > anything can be pointing to something else. I could reimport the
> data
> > (from the vcard above) and overwrite the address book if you think
> > that would help..
>
> What do the turba prefs say about your default and sync'd address
> books?
Turba says I only have Address book of Simon B and sure enough that's the one the Turba preferences say to sync.
> I use the defaults. If you want to change them, you'll have to
> experiment as to what gives you the best performance vs battery life
> you are looking for.
Thanks! I'll set it to forced and see what gives. Are these rules as whether the waitinterval can be? I.e. Not longer than the heatbeat, I assume..?
Simon
More information about the horde
mailing list