[horde] Activesync - no logging and INBOX sync

Tom Seeley horde at tomseeley.co.uk
Sat Jan 12 22:02:24 UTC 2013


Quoting Michael J Rubinsky <mrubinsk at horde.org>:

>>
>> hopefully once the logging is working it will be become obvious  
>> what the syncing problem is.
>>
>> Thanks,
>>
>> Tom.
>>

> As far as the Inbox not synching, have you tried issuing a manual  
> sync from the client?

OK, so that was an SELINUX problem apparently (despite auditd not  
logging anything of the sort), with that out of the way, we have the  
attached log.

I hope this makes more sense to you than it does to me.

No amount of manual syncing makes any difference to the INBOX, it just  
tells me it was last updated on Friday at 13:29

Thanks,

Tom.
-------------- next part --------------
2013-01-12T21:45:01+00:00 INFO: [28468] Horde_Core_ActiveSync_Driver::authenticate() attempt for tom
2013-01-12T21:45:01+00:00 DEBUG: [SAMSUNG1359778045082797] SYNC request received for user tom
2013-01-12T21:45:01+00:00 DEBUG: [SAMSUNG1359778045082797] loadDeviceInfo: tom
2013-01-12T21:45:01+00:00 INFO: Request being handled for device: SAMSUNG1359778045082797 Supporting protocol version: 12.1
2013-01-12T21:45:01+00:00 INFO: [SAMSUNG1359778045082797] Handling SYNC command.
2013-01-12T21:45:01+00:00 DEBUG: [SAMSUNG1359778045082797] Checking policykey for device: 0 user: tom
2013-01-12T21:45:01+00:00 DEBUG: Policykey: 0 verified.
2013-01-12T21:45:01+00:00 DEBUG: I  <Synchronize>
2013-01-12T21:45:01+00:00 DEBUG: I   <Folders>
2013-01-12T21:45:01+00:00 DEBUG: I    <Folder>
2013-01-12T21:45:01+00:00 DEBUG: I     <SyncKey>
2013-01-12T21:45:01+00:00 DEBUG: I      {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:01+00:00 DEBUG: I     </SyncKey>
2013-01-12T21:45:01+00:00 DEBUG: I     <FolderId>
2013-01-12T21:45:01+00:00 DEBUG: I      INBOX
2013-01-12T21:45:01+00:00 DEBUG: I     </FolderId>
2013-01-12T21:45:01+00:00 DEBUG: I     <DeletesAsMoves/>
2013-01-12T21:45:01+00:00 DEBUG: I     <GetChanges/>
2013-01-12T21:45:01+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:01+00:00 DEBUG: I     <WindowSize>
2013-01-12T21:45:01+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:01+00:00 DEBUG: I      100
2013-01-12T21:45:01+00:00 DEBUG: I     </WindowSize>
2013-01-12T21:45:01+00:00 DEBUG: I     <Options>
2013-01-12T21:45:01+00:00 DEBUG: I      <FilterType>
2013-01-12T21:45:01+00:00 DEBUG: I       5
2013-01-12T21:45:01+00:00 DEBUG: I      </FilterType>
2013-01-12T21:45:01+00:00 DEBUG: I      <AirSyncBase:BodyPreference>
2013-01-12T21:45:01+00:00 DEBUG: I       <AirSyncBase:Type>
2013-01-12T21:45:01+00:00 DEBUG: I        2
2013-01-12T21:45:01+00:00 DEBUG: I       </AirSyncBase:Type>
2013-01-12T21:45:01+00:00 DEBUG: I       <AirSyncBase:TruncationSize>
2013-01-12T21:45:01+00:00 DEBUG: I        2048
2013-01-12T21:45:01+00:00 DEBUG: I       </AirSyncBase:TruncationSize>
2013-01-12T21:45:01+00:00 DEBUG: I      </AirSyncBase:BodyPreference>
2013-01-12T21:45:01+00:00 DEBUG: I     </Options>
2013-01-12T21:45:01+00:00 DEBUG: I     <Commands>
2013-01-12T21:45:01+00:00 DEBUG: Obtaining folder INBOX class from sync_cache: Email
2013-01-12T21:45:01+00:00 DEBUG: [28468] Initializing state for collection: INBOX, synckey: {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:01+00:00 DEBUG: [28468] Loading state for synckey {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:01+00:00 DEBUG: [28468] Removing device state for sync_key {50e5ad75-d49c-4115-a375-3c37052c630d}107 only.
2013-01-12T21:45:01+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:01+00:00 DEBUG: O   <Folders>
2013-01-12T21:45:01+00:00 DEBUG: O    <Folder>
2013-01-12T21:45:01+00:00 DEBUG: O     <FolderType>
2013-01-12T21:45:01+00:00 DEBUG: O      Email
2013-01-12T21:45:01+00:00 DEBUG: O     <FolderType/>
2013-01-12T21:45:01+00:00 DEBUG: O     <SyncKey>
2013-01-12T21:45:01+00:00 DEBUG: O      {50f1d95d-a43c-4123-8585-6f34052c630d}1
2013-01-12T21:45:01+00:00 DEBUG: O     <SyncKey/>
2013-01-12T21:45:01+00:00 DEBUG: O     <FolderId>
2013-01-12T21:45:01+00:00 DEBUG: O      INBOX
2013-01-12T21:45:01+00:00 DEBUG: O     <FolderId/>
2013-01-12T21:45:01+00:00 DEBUG: O     <Status>
2013-01-12T21:45:01+00:00 DEBUG: O      3
2013-01-12T21:45:01+00:00 DEBUG: O     <Status/>
2013-01-12T21:45:01+00:00 DEBUG: O    <Folder/>
2013-01-12T21:45:01+00:00 DEBUG: O   <Folders/>
2013-01-12T21:45:01+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:01+00:00 DEBUG: I      <Remove>
2013-01-12T21:45:01+00:00 DEBUG: No collections - looking in sync_cache.
2013-01-12T21:45:01+00:00 DEBUG: Found a syncable collection:  : {50f1cc44-28f0-468c-962a-6a5c052c630d}2
2013-01-12T21:45:01+00:00 ERR: Unmatched end tag:
2013-01-12T21:45:01+00:00 ERR: Array
(
    [1] => 1
    [2] => Remove
    [4] => 1
)

2013-01-12T21:45:01+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:01+00:00 DEBUG: O   <Status>
2013-01-12T21:45:01+00:00 DEBUG: O    4
2013-01-12T21:45:01+00:00 DEBUG: O   <Status/>
2013-01-12T21:45:01+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:01+00:00 ERR: PROTOCOL ERROR: Missing closing SYNC tag
2013-01-12T21:45:01+00:00 INFO: [28468] User tom logged off
2013-01-12T21:45:10+00:00 INFO: [28466] Horde_Core_ActiveSync_Driver::authenticate() attempt for tom
2013-01-12T21:45:10+00:00 DEBUG: [SAMSUNG1359778045082797] SYNC request received for user tom
2013-01-12T21:45:10+00:00 DEBUG: [SAMSUNG1359778045082797] loadDeviceInfo: tom
2013-01-12T21:45:10+00:00 INFO: Request being handled for device: SAMSUNG1359778045082797 Supporting protocol version: 12.1
2013-01-12T21:45:10+00:00 INFO: [SAMSUNG1359778045082797] Handling SYNC command.
2013-01-12T21:45:10+00:00 DEBUG: [SAMSUNG1359778045082797] Checking policykey for device: 0 user: tom
2013-01-12T21:45:10+00:00 DEBUG: Policykey: 0 verified.
2013-01-12T21:45:10+00:00 DEBUG: I  <Synchronize>
2013-01-12T21:45:10+00:00 DEBUG: I   <Folders>
2013-01-12T21:45:10+00:00 DEBUG: I    <Folder>
2013-01-12T21:45:10+00:00 DEBUG: I     <SyncKey>
2013-01-12T21:45:10+00:00 DEBUG: I      {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:10+00:00 DEBUG: I     </SyncKey>
2013-01-12T21:45:10+00:00 DEBUG: I     <FolderId>
2013-01-12T21:45:10+00:00 DEBUG: I      INBOX
2013-01-12T21:45:10+00:00 DEBUG: I     </FolderId>
2013-01-12T21:45:10+00:00 DEBUG: I     <DeletesAsMoves/>
2013-01-12T21:45:10+00:00 DEBUG: I     <GetChanges/>
2013-01-12T21:45:10+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:10+00:00 DEBUG: I     <WindowSize>
2013-01-12T21:45:10+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:10+00:00 DEBUG: I      100
2013-01-12T21:45:10+00:00 DEBUG: I     </WindowSize>
2013-01-12T21:45:10+00:00 DEBUG: I     <Options>
2013-01-12T21:45:10+00:00 DEBUG: I      <FilterType>
2013-01-12T21:45:10+00:00 DEBUG: I       5
2013-01-12T21:45:10+00:00 DEBUG: I      </FilterType>
2013-01-12T21:45:10+00:00 DEBUG: I      <AirSyncBase:BodyPreference>
2013-01-12T21:45:10+00:00 DEBUG: I       <AirSyncBase:Type>
2013-01-12T21:45:10+00:00 DEBUG: I        2
2013-01-12T21:45:10+00:00 DEBUG: I       </AirSyncBase:Type>
2013-01-12T21:45:10+00:00 DEBUG: I       <AirSyncBase:TruncationSize>
2013-01-12T21:45:10+00:00 DEBUG: I        2048
2013-01-12T21:45:10+00:00 DEBUG: I       </AirSyncBase:TruncationSize>
2013-01-12T21:45:10+00:00 DEBUG: I      </AirSyncBase:BodyPreference>
2013-01-12T21:45:10+00:00 DEBUG: I     </Options>
2013-01-12T21:45:10+00:00 DEBUG: I     <Commands>
2013-01-12T21:45:10+00:00 DEBUG: Obtaining folder INBOX class from sync_cache: Email
2013-01-12T21:45:10+00:00 DEBUG: [28466] Initializing state for collection: INBOX, synckey: {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:10+00:00 DEBUG: [28466] Loading state for synckey {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:10+00:00 DEBUG: [28466] Removing device state for sync_key {50e5ad75-d49c-4115-a375-3c37052c630d}107 only.
2013-01-12T21:45:10+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:10+00:00 DEBUG: O   <Folders>
2013-01-12T21:45:10+00:00 DEBUG: O    <Folder>
2013-01-12T21:45:10+00:00 DEBUG: O     <FolderType>
2013-01-12T21:45:10+00:00 DEBUG: O      Email
2013-01-12T21:45:10+00:00 DEBUG: O     <FolderType/>
2013-01-12T21:45:10+00:00 DEBUG: O     <SyncKey>
2013-01-12T21:45:10+00:00 DEBUG: O      {50f1d966-c870-4267-b5ae-6f32052c630d}1
2013-01-12T21:45:10+00:00 DEBUG: O     <SyncKey/>
2013-01-12T21:45:10+00:00 DEBUG: O     <FolderId>
2013-01-12T21:45:10+00:00 DEBUG: O      INBOX
2013-01-12T21:45:10+00:00 DEBUG: O     <FolderId/>
2013-01-12T21:45:10+00:00 DEBUG: O     <Status>
2013-01-12T21:45:10+00:00 DEBUG: O      3
2013-01-12T21:45:10+00:00 DEBUG: O     <Status/>
2013-01-12T21:45:10+00:00 DEBUG: O    <Folder/>
2013-01-12T21:45:10+00:00 DEBUG: O   <Folders/>
2013-01-12T21:45:10+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:10+00:00 DEBUG: I      <Remove>
2013-01-12T21:45:10+00:00 DEBUG: No collections - looking in sync_cache.
2013-01-12T21:45:10+00:00 DEBUG: Found a syncable collection:  : {50f1cc44-28f0-468c-962a-6a5c052c630d}2
2013-01-12T21:45:10+00:00 ERR: Unmatched end tag:
2013-01-12T21:45:10+00:00 ERR: Array
(
    [1] => 1
    [2] => Remove
    [4] => 1
)

2013-01-12T21:45:10+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:10+00:00 DEBUG: O   <Status>
2013-01-12T21:45:10+00:00 DEBUG: O    4
2013-01-12T21:45:10+00:00 DEBUG: O   <Status/>
2013-01-12T21:45:10+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:10+00:00 ERR: PROTOCOL ERROR: Missing closing SYNC tag
2013-01-12T21:45:11+00:00 INFO: [28466] User tom logged off
2013-01-12T21:45:27+00:00 INFO: [28467] Horde_Core_ActiveSync_Driver::authenticate() attempt for tom
2013-01-12T21:45:27+00:00 DEBUG: [SAMSUNG1359778045082797] SYNC request received for user tom
2013-01-12T21:45:27+00:00 DEBUG: [SAMSUNG1359778045082797] loadDeviceInfo: tom
2013-01-12T21:45:27+00:00 INFO: Request being handled for device: SAMSUNG1359778045082797 Supporting protocol version: 12.1
2013-01-12T21:45:27+00:00 INFO: [SAMSUNG1359778045082797] Handling SYNC command.
2013-01-12T21:45:27+00:00 DEBUG: [SAMSUNG1359778045082797] Checking policykey for device: 0 user: tom
2013-01-12T21:45:27+00:00 DEBUG: Policykey: 0 verified.
2013-01-12T21:45:27+00:00 DEBUG: I  <Synchronize>
2013-01-12T21:45:27+00:00 DEBUG: I   <Folders>
2013-01-12T21:45:27+00:00 DEBUG: I    <Folder>
2013-01-12T21:45:27+00:00 DEBUG: I     <SyncKey>
2013-01-12T21:45:27+00:00 DEBUG: I      {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:27+00:00 DEBUG: I     </SyncKey>
2013-01-12T21:45:27+00:00 DEBUG: I     <FolderId>
2013-01-12T21:45:27+00:00 DEBUG: I      INBOX
2013-01-12T21:45:27+00:00 DEBUG: I     </FolderId>
2013-01-12T21:45:27+00:00 DEBUG: I     <DeletesAsMoves/>
2013-01-12T21:45:27+00:00 DEBUG: I     <GetChanges/>
2013-01-12T21:45:27+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:27+00:00 DEBUG: I     <WindowSize>
2013-01-12T21:45:27+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:27+00:00 DEBUG: I      100
2013-01-12T21:45:27+00:00 DEBUG: I     </WindowSize>
2013-01-12T21:45:27+00:00 DEBUG: I     <Options>
2013-01-12T21:45:27+00:00 DEBUG: I      <FilterType>
2013-01-12T21:45:27+00:00 DEBUG: I       5
2013-01-12T21:45:27+00:00 DEBUG: I      </FilterType>
2013-01-12T21:45:27+00:00 DEBUG: I      <AirSyncBase:BodyPreference>
2013-01-12T21:45:27+00:00 DEBUG: I       <AirSyncBase:Type>
2013-01-12T21:45:27+00:00 DEBUG: I        2
2013-01-12T21:45:27+00:00 DEBUG: I       </AirSyncBase:Type>
2013-01-12T21:45:27+00:00 DEBUG: I       <AirSyncBase:TruncationSize>
2013-01-12T21:45:27+00:00 DEBUG: I        2048
2013-01-12T21:45:27+00:00 DEBUG: I       </AirSyncBase:TruncationSize>
2013-01-12T21:45:27+00:00 DEBUG: I      </AirSyncBase:BodyPreference>
2013-01-12T21:45:27+00:00 DEBUG: I     </Options>
2013-01-12T21:45:27+00:00 DEBUG: I     <Commands>
2013-01-12T21:45:27+00:00 DEBUG: Obtaining folder INBOX class from sync_cache: Email
2013-01-12T21:45:27+00:00 DEBUG: [28467] Initializing state for collection: INBOX, synckey: {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:27+00:00 DEBUG: [28467] Loading state for synckey {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:27+00:00 DEBUG: [28467] Removing device state for sync_key {50e5ad75-d49c-4115-a375-3c37052c630d}107 only.
2013-01-12T21:45:27+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:27+00:00 DEBUG: O   <Folders>
2013-01-12T21:45:27+00:00 DEBUG: O    <Folder>
2013-01-12T21:45:27+00:00 DEBUG: O     <FolderType>
2013-01-12T21:45:27+00:00 DEBUG: O      Email
2013-01-12T21:45:27+00:00 DEBUG: O     <FolderType/>
2013-01-12T21:45:27+00:00 DEBUG: O     <SyncKey>
2013-01-12T21:45:27+00:00 DEBUG: O      {50f1d977-c79c-4c9d-8afc-6f33052c630d}1
2013-01-12T21:45:27+00:00 DEBUG: O     <SyncKey/>
2013-01-12T21:45:27+00:00 DEBUG: O     <FolderId>
2013-01-12T21:45:27+00:00 DEBUG: O      INBOX
2013-01-12T21:45:27+00:00 DEBUG: O     <FolderId/>
2013-01-12T21:45:27+00:00 DEBUG: O     <Status>
2013-01-12T21:45:27+00:00 DEBUG: O      3
2013-01-12T21:45:27+00:00 DEBUG: O     <Status/>
2013-01-12T21:45:27+00:00 DEBUG: O    <Folder/>
2013-01-12T21:45:27+00:00 DEBUG: O   <Folders/>
2013-01-12T21:45:27+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:27+00:00 DEBUG: I      <Remove>
2013-01-12T21:45:27+00:00 DEBUG: No collections - looking in sync_cache.
2013-01-12T21:45:27+00:00 DEBUG: Found a syncable collection:  : {50f1cc44-28f0-468c-962a-6a5c052c630d}2
2013-01-12T21:45:27+00:00 ERR: Unmatched end tag:
2013-01-12T21:45:27+00:00 ERR: Array
(
    [1] => 1
    [2] => Remove
    [4] => 1
)

2013-01-12T21:45:27+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:27+00:00 DEBUG: O   <Status>
2013-01-12T21:45:27+00:00 DEBUG: O    4
2013-01-12T21:45:27+00:00 DEBUG: O   <Status/>
2013-01-12T21:45:27+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:27+00:00 ERR: PROTOCOL ERROR: Missing closing SYNC tag
2013-01-12T21:45:27+00:00 INFO: [28467] User tom logged off
2013-01-12T21:45:59+00:00 INFO: [28469] Horde_Core_ActiveSync_Driver::authenticate() attempt for tom
2013-01-12T21:45:59+00:00 DEBUG: [SAMSUNG1359778045082797] SYNC request received for user tom
2013-01-12T21:45:59+00:00 DEBUG: [SAMSUNG1359778045082797] loadDeviceInfo: tom
2013-01-12T21:45:59+00:00 INFO: Request being handled for device: SAMSUNG1359778045082797 Supporting protocol version: 12.1
2013-01-12T21:45:59+00:00 INFO: [SAMSUNG1359778045082797] Handling SYNC command.
2013-01-12T21:45:59+00:00 DEBUG: [SAMSUNG1359778045082797] Checking policykey for device: 0 user: tom
2013-01-12T21:45:59+00:00 DEBUG: Policykey: 0 verified.
2013-01-12T21:45:59+00:00 DEBUG: I  <Synchronize>
2013-01-12T21:45:59+00:00 DEBUG: I   <Folders>
2013-01-12T21:45:59+00:00 DEBUG: I    <Folder>
2013-01-12T21:45:59+00:00 DEBUG: I     <SyncKey>
2013-01-12T21:45:59+00:00 DEBUG: I      {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:59+00:00 DEBUG: I     </SyncKey>
2013-01-12T21:45:59+00:00 DEBUG: I     <FolderId>
2013-01-12T21:45:59+00:00 DEBUG: I      INBOX
2013-01-12T21:45:59+00:00 DEBUG: I     </FolderId>
2013-01-12T21:45:59+00:00 DEBUG: I     <DeletesAsMoves/>
2013-01-12T21:45:59+00:00 DEBUG: I     <GetChanges/>
2013-01-12T21:45:59+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:59+00:00 DEBUG: I     <WindowSize>
2013-01-12T21:45:59+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:45:59+00:00 DEBUG: I      100
2013-01-12T21:45:59+00:00 DEBUG: I     </WindowSize>
2013-01-12T21:45:59+00:00 DEBUG: I     <Options>
2013-01-12T21:45:59+00:00 DEBUG: I      <FilterType>
2013-01-12T21:45:59+00:00 DEBUG: I       5
2013-01-12T21:45:59+00:00 DEBUG: I      </FilterType>
2013-01-12T21:45:59+00:00 DEBUG: I      <AirSyncBase:BodyPreference>
2013-01-12T21:45:59+00:00 DEBUG: I       <AirSyncBase:Type>
2013-01-12T21:45:59+00:00 DEBUG: I        2
2013-01-12T21:45:59+00:00 DEBUG: I       </AirSyncBase:Type>
2013-01-12T21:45:59+00:00 DEBUG: I       <AirSyncBase:TruncationSize>
2013-01-12T21:45:59+00:00 DEBUG: I        2048
2013-01-12T21:45:59+00:00 DEBUG: I       </AirSyncBase:TruncationSize>
2013-01-12T21:45:59+00:00 DEBUG: I      </AirSyncBase:BodyPreference>
2013-01-12T21:45:59+00:00 DEBUG: I     </Options>
2013-01-12T21:45:59+00:00 DEBUG: I     <Commands>
2013-01-12T21:45:59+00:00 DEBUG: Obtaining folder INBOX class from sync_cache: Email
2013-01-12T21:45:59+00:00 DEBUG: [28469] Initializing state for collection: INBOX, synckey: {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:59+00:00 DEBUG: [28469] Loading state for synckey {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:45:59+00:00 DEBUG: [28469] Removing device state for sync_key {50e5ad75-d49c-4115-a375-3c37052c630d}107 only.
2013-01-12T21:45:59+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:59+00:00 DEBUG: O   <Folders>
2013-01-12T21:45:59+00:00 DEBUG: O    <Folder>
2013-01-12T21:45:59+00:00 DEBUG: O     <FolderType>
2013-01-12T21:45:59+00:00 DEBUG: O      Email
2013-01-12T21:45:59+00:00 DEBUG: O     <FolderType/>
2013-01-12T21:45:59+00:00 DEBUG: O     <SyncKey>
2013-01-12T21:45:59+00:00 DEBUG: O      {50f1d997-4f50-4625-be08-6f35052c630d}1
2013-01-12T21:45:59+00:00 DEBUG: O     <SyncKey/>
2013-01-12T21:45:59+00:00 DEBUG: O     <FolderId>
2013-01-12T21:45:59+00:00 DEBUG: O      INBOX
2013-01-12T21:45:59+00:00 DEBUG: O     <FolderId/>
2013-01-12T21:45:59+00:00 DEBUG: O     <Status>
2013-01-12T21:45:59+00:00 DEBUG: O      3
2013-01-12T21:45:59+00:00 DEBUG: O     <Status/>
2013-01-12T21:45:59+00:00 DEBUG: O    <Folder/>
2013-01-12T21:45:59+00:00 DEBUG: O   <Folders/>
2013-01-12T21:45:59+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:59+00:00 DEBUG: I      <Remove>
2013-01-12T21:45:59+00:00 DEBUG: No collections - looking in sync_cache.
2013-01-12T21:45:59+00:00 DEBUG: Found a syncable collection:  : {50f1cc44-28f0-468c-962a-6a5c052c630d}2
2013-01-12T21:45:59+00:00 ERR: Unmatched end tag:
2013-01-12T21:45:59+00:00 ERR: Array
(
    [1] => 1
    [2] => Remove
    [4] => 1
)

2013-01-12T21:45:59+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:45:59+00:00 DEBUG: O   <Status>
2013-01-12T21:45:59+00:00 DEBUG: O    4
2013-01-12T21:45:59+00:00 DEBUG: O   <Status/>
2013-01-12T21:45:59+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:45:59+00:00 ERR: PROTOCOL ERROR: Missing closing SYNC tag
2013-01-12T21:45:59+00:00 INFO: [28469] User tom logged off
2013-01-12T21:47:03+00:00 INFO: [28470] Horde_Core_ActiveSync_Driver::authenticate() attempt for tom
2013-01-12T21:47:03+00:00 DEBUG: [SAMSUNG1359778045082797] SYNC request received for user tom
2013-01-12T21:47:03+00:00 DEBUG: [SAMSUNG1359778045082797] loadDeviceInfo: tom
2013-01-12T21:47:03+00:00 INFO: Request being handled for device: SAMSUNG1359778045082797 Supporting protocol version: 12.1
2013-01-12T21:47:03+00:00 INFO: [SAMSUNG1359778045082797] Handling SYNC command.
2013-01-12T21:47:03+00:00 DEBUG: [SAMSUNG1359778045082797] Checking policykey for device: 0 user: tom
2013-01-12T21:47:03+00:00 DEBUG: Policykey: 0 verified.
2013-01-12T21:47:03+00:00 DEBUG: I  <Synchronize>
2013-01-12T21:47:03+00:00 DEBUG: I   <Folders>
2013-01-12T21:47:03+00:00 DEBUG: I    <Folder>
2013-01-12T21:47:03+00:00 DEBUG: I     <SyncKey>
2013-01-12T21:47:03+00:00 DEBUG: I      {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:47:03+00:00 DEBUG: I     </SyncKey>
2013-01-12T21:47:03+00:00 DEBUG: I     <FolderId>
2013-01-12T21:47:03+00:00 DEBUG: I      INBOX
2013-01-12T21:47:03+00:00 DEBUG: I     </FolderId>
2013-01-12T21:47:03+00:00 DEBUG: I     <DeletesAsMoves/>
2013-01-12T21:47:03+00:00 DEBUG: I     <GetChanges/>
2013-01-12T21:47:03+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:47:03+00:00 DEBUG: I     <WindowSize>
2013-01-12T21:47:03+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:47:03+00:00 DEBUG: I      100
2013-01-12T21:47:03+00:00 DEBUG: I     </WindowSize>
2013-01-12T21:47:03+00:00 DEBUG: I     <Options>
2013-01-12T21:47:03+00:00 DEBUG: I      <FilterType>
2013-01-12T21:47:03+00:00 DEBUG: I       5
2013-01-12T21:47:03+00:00 DEBUG: I      </FilterType>
2013-01-12T21:47:03+00:00 DEBUG: I      <AirSyncBase:BodyPreference>
2013-01-12T21:47:03+00:00 DEBUG: I       <AirSyncBase:Type>
2013-01-12T21:47:03+00:00 DEBUG: I        2
2013-01-12T21:47:03+00:00 DEBUG: I       </AirSyncBase:Type>
2013-01-12T21:47:03+00:00 DEBUG: I       <AirSyncBase:TruncationSize>
2013-01-12T21:47:03+00:00 DEBUG: I        2048
2013-01-12T21:47:03+00:00 DEBUG: I       </AirSyncBase:TruncationSize>
2013-01-12T21:47:03+00:00 DEBUG: I      </AirSyncBase:BodyPreference>
2013-01-12T21:47:03+00:00 DEBUG: I     </Options>
2013-01-12T21:47:03+00:00 DEBUG: I     <Commands>
2013-01-12T21:47:03+00:00 DEBUG: Obtaining folder INBOX class from sync_cache: Email
2013-01-12T21:47:03+00:00 DEBUG: [28470] Initializing state for collection: INBOX, synckey: {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:47:03+00:00 DEBUG: [28470] Loading state for synckey {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:47:03+00:00 DEBUG: [28470] Removing device state for sync_key {50e5ad75-d49c-4115-a375-3c37052c630d}107 only.
2013-01-12T21:47:03+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:47:03+00:00 DEBUG: O   <Folders>
2013-01-12T21:47:03+00:00 DEBUG: O    <Folder>
2013-01-12T21:47:03+00:00 DEBUG: O     <FolderType>
2013-01-12T21:47:03+00:00 DEBUG: O      Email
2013-01-12T21:47:03+00:00 DEBUG: O     <FolderType/>
2013-01-12T21:47:03+00:00 DEBUG: O     <SyncKey>
2013-01-12T21:47:03+00:00 DEBUG: O      {50f1d9d7-7bcc-4793-a831-6f36052c630d}1
2013-01-12T21:47:03+00:00 DEBUG: O     <SyncKey/>
2013-01-12T21:47:03+00:00 DEBUG: O     <FolderId>
2013-01-12T21:47:03+00:00 DEBUG: O      INBOX
2013-01-12T21:47:03+00:00 DEBUG: O     <FolderId/>
2013-01-12T21:47:03+00:00 DEBUG: O     <Status>
2013-01-12T21:47:03+00:00 DEBUG: O      3
2013-01-12T21:47:03+00:00 DEBUG: O     <Status/>
2013-01-12T21:47:03+00:00 DEBUG: O    <Folder/>
2013-01-12T21:47:03+00:00 DEBUG: O   <Folders/>
2013-01-12T21:47:03+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:47:03+00:00 DEBUG: I      <Remove>
2013-01-12T21:47:03+00:00 DEBUG: No collections - looking in sync_cache.
2013-01-12T21:47:03+00:00 DEBUG: Found a syncable collection:  : {50f1cc44-28f0-468c-962a-6a5c052c630d}2
2013-01-12T21:47:03+00:00 ERR: Unmatched end tag:
2013-01-12T21:47:03+00:00 ERR: Array
(
    [1] => 1
    [2] => Remove
    [4] => 1
)

2013-01-12T21:47:03+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:47:03+00:00 DEBUG: O   <Status>
2013-01-12T21:47:03+00:00 DEBUG: O    4
2013-01-12T21:47:03+00:00 DEBUG: O   <Status/>
2013-01-12T21:47:03+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:47:03+00:00 ERR: PROTOCOL ERROR: Missing closing SYNC tag
2013-01-12T21:47:03+00:00 INFO: [28470] User tom logged off
2013-01-12T21:49:08+00:00 INFO: [28466] Horde_Core_ActiveSync_Driver::authenticate() attempt for tom
2013-01-12T21:49:08+00:00 DEBUG: [SAMSUNG1359778045082797] SYNC request received for user tom
2013-01-12T21:49:08+00:00 DEBUG: [SAMSUNG1359778045082797] loadDeviceInfo: tom
2013-01-12T21:49:08+00:00 INFO: Request being handled for device: SAMSUNG1359778045082797 Supporting protocol version: 12.1
2013-01-12T21:49:08+00:00 INFO: [SAMSUNG1359778045082797] Handling SYNC command.
2013-01-12T21:49:08+00:00 DEBUG: [SAMSUNG1359778045082797] Checking policykey for device: 0 user: tom
2013-01-12T21:49:08+00:00 DEBUG: Policykey: 0 verified.
2013-01-12T21:49:08+00:00 DEBUG: I  <Synchronize>
2013-01-12T21:49:08+00:00 DEBUG: I   <Folders>
2013-01-12T21:49:08+00:00 DEBUG: I    <Folder>
2013-01-12T21:49:08+00:00 DEBUG: I     <SyncKey>
2013-01-12T21:49:08+00:00 DEBUG: I      {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:49:08+00:00 DEBUG: I     </SyncKey>
2013-01-12T21:49:08+00:00 DEBUG: I     <FolderId>
2013-01-12T21:49:08+00:00 DEBUG: I      INBOX
2013-01-12T21:49:08+00:00 DEBUG: I     </FolderId>
2013-01-12T21:49:08+00:00 DEBUG: I     <DeletesAsMoves/>
2013-01-12T21:49:08+00:00 DEBUG: I     <GetChanges/>
2013-01-12T21:49:08+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:49:08+00:00 DEBUG: I     <WindowSize>
2013-01-12T21:49:08+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:49:08+00:00 DEBUG: I      100
2013-01-12T21:49:08+00:00 DEBUG: I     </WindowSize>
2013-01-12T21:49:08+00:00 DEBUG: I     <Options>
2013-01-12T21:49:08+00:00 DEBUG: I      <FilterType>
2013-01-12T21:49:08+00:00 DEBUG: I       5
2013-01-12T21:49:08+00:00 DEBUG: I      </FilterType>
2013-01-12T21:49:08+00:00 DEBUG: I      <AirSyncBase:BodyPreference>
2013-01-12T21:49:08+00:00 DEBUG: I       <AirSyncBase:Type>
2013-01-12T21:49:08+00:00 DEBUG: I        2
2013-01-12T21:49:08+00:00 DEBUG: I       </AirSyncBase:Type>
2013-01-12T21:49:08+00:00 DEBUG: I       <AirSyncBase:TruncationSize>
2013-01-12T21:49:08+00:00 DEBUG: I        2048
2013-01-12T21:49:08+00:00 DEBUG: I       </AirSyncBase:TruncationSize>
2013-01-12T21:49:08+00:00 DEBUG: I      </AirSyncBase:BodyPreference>
2013-01-12T21:49:08+00:00 DEBUG: I     </Options>
2013-01-12T21:49:08+00:00 DEBUG: I     <Commands>
2013-01-12T21:49:08+00:00 DEBUG: Obtaining folder INBOX class from sync_cache: Email
2013-01-12T21:49:08+00:00 DEBUG: [28466] Initializing state for collection: INBOX, synckey: {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:49:08+00:00 DEBUG: [28466] Loading state for synckey {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:49:08+00:00 DEBUG: [28466] Removing device state for sync_key {50e5ad75-d49c-4115-a375-3c37052c630d}107 only.
2013-01-12T21:49:08+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:49:08+00:00 DEBUG: O   <Folders>
2013-01-12T21:49:08+00:00 DEBUG: O    <Folder>
2013-01-12T21:49:08+00:00 DEBUG: O     <FolderType>
2013-01-12T21:49:08+00:00 DEBUG: O      Email
2013-01-12T21:49:08+00:00 DEBUG: O     <FolderType/>
2013-01-12T21:49:08+00:00 DEBUG: O     <SyncKey>
2013-01-12T21:49:08+00:00 DEBUG: O      {50f1da54-a290-4b81-8ebb-6f32052c630d}1
2013-01-12T21:49:08+00:00 DEBUG: O     <SyncKey/>
2013-01-12T21:49:08+00:00 DEBUG: O     <FolderId>
2013-01-12T21:49:08+00:00 DEBUG: O      INBOX
2013-01-12T21:49:08+00:00 DEBUG: O     <FolderId/>
2013-01-12T21:49:08+00:00 DEBUG: O     <Status>
2013-01-12T21:49:08+00:00 DEBUG: O      3
2013-01-12T21:49:08+00:00 DEBUG: O     <Status/>
2013-01-12T21:49:08+00:00 DEBUG: O    <Folder/>
2013-01-12T21:49:08+00:00 DEBUG: O   <Folders/>
2013-01-12T21:49:08+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:49:08+00:00 DEBUG: I      <Remove>
2013-01-12T21:49:08+00:00 DEBUG: No collections - looking in sync_cache.
2013-01-12T21:49:08+00:00 DEBUG: Found a syncable collection:  : {50f1cc44-28f0-468c-962a-6a5c052c630d}2
2013-01-12T21:49:08+00:00 ERR: Unmatched end tag:
2013-01-12T21:49:08+00:00 ERR: Array
(
    [1] => 1
    [2] => Remove
    [4] => 1
)

2013-01-12T21:49:08+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:49:08+00:00 DEBUG: O   <Status>
2013-01-12T21:49:08+00:00 DEBUG: O    4
2013-01-12T21:49:08+00:00 DEBUG: O   <Status/>
2013-01-12T21:49:08+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:49:08+00:00 ERR: PROTOCOL ERROR: Missing closing SYNC tag
2013-01-12T21:49:08+00:00 INFO: [28466] User tom logged off
2013-01-12T21:53:12+00:00 INFO: [28467] Horde_Core_ActiveSync_Driver::authenticate() attempt for tom
2013-01-12T21:53:12+00:00 DEBUG: [SAMSUNG1359778045082797] SYNC request received for user tom
2013-01-12T21:53:12+00:00 DEBUG: [SAMSUNG1359778045082797] loadDeviceInfo: tom
2013-01-12T21:53:12+00:00 INFO: Request being handled for device: SAMSUNG1359778045082797 Supporting protocol version: 12.1
2013-01-12T21:53:12+00:00 INFO: [SAMSUNG1359778045082797] Handling SYNC command.
2013-01-12T21:53:12+00:00 DEBUG: [SAMSUNG1359778045082797] Checking policykey for device: 0 user: tom
2013-01-12T21:53:12+00:00 DEBUG: Policykey: 0 verified.
2013-01-12T21:53:12+00:00 DEBUG: I  <Synchronize>
2013-01-12T21:53:12+00:00 DEBUG: I   <Folders>
2013-01-12T21:53:12+00:00 DEBUG: I    <Folder>
2013-01-12T21:53:12+00:00 DEBUG: I     <SyncKey>
2013-01-12T21:53:12+00:00 DEBUG: I      {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:53:12+00:00 DEBUG: I     </SyncKey>
2013-01-12T21:53:12+00:00 DEBUG: I     <FolderId>
2013-01-12T21:53:12+00:00 DEBUG: I      INBOX
2013-01-12T21:53:12+00:00 DEBUG: I     </FolderId>
2013-01-12T21:53:12+00:00 DEBUG: I     <DeletesAsMoves/>
2013-01-12T21:53:12+00:00 DEBUG: I     <GetChanges/>
2013-01-12T21:53:12+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:53:12+00:00 DEBUG: I     <WindowSize>
2013-01-12T21:53:12+00:00 INFO: Possible unmatched content (peeking or empty tag?)
2013-01-12T21:53:12+00:00 DEBUG: I      100
2013-01-12T21:53:12+00:00 DEBUG: I     </WindowSize>
2013-01-12T21:53:12+00:00 DEBUG: I     <Options>
2013-01-12T21:53:12+00:00 DEBUG: I      <FilterType>
2013-01-12T21:53:12+00:00 DEBUG: I       5
2013-01-12T21:53:12+00:00 DEBUG: I      </FilterType>
2013-01-12T21:53:12+00:00 DEBUG: I      <AirSyncBase:BodyPreference>
2013-01-12T21:53:12+00:00 DEBUG: I       <AirSyncBase:Type>
2013-01-12T21:53:12+00:00 DEBUG: I        2
2013-01-12T21:53:12+00:00 DEBUG: I       </AirSyncBase:Type>
2013-01-12T21:53:12+00:00 DEBUG: I       <AirSyncBase:TruncationSize>
2013-01-12T21:53:12+00:00 DEBUG: I        2048
2013-01-12T21:53:12+00:00 DEBUG: I       </AirSyncBase:TruncationSize>
2013-01-12T21:53:12+00:00 DEBUG: I      </AirSyncBase:BodyPreference>
2013-01-12T21:53:12+00:00 DEBUG: I     </Options>
2013-01-12T21:53:12+00:00 DEBUG: I     <Commands>
2013-01-12T21:53:12+00:00 DEBUG: Obtaining folder INBOX class from sync_cache: Email
2013-01-12T21:53:12+00:00 DEBUG: [28467] Initializing state for collection: INBOX, synckey: {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:53:12+00:00 DEBUG: [28467] Loading state for synckey {50e5ad75-d49c-4115-a375-3c37052c630d}107
2013-01-12T21:53:12+00:00 DEBUG: [28467] Removing device state for sync_key {50e5ad75-d49c-4115-a375-3c37052c630d}107 only.
2013-01-12T21:53:12+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:53:12+00:00 DEBUG: O   <Folders>
2013-01-12T21:53:12+00:00 DEBUG: O    <Folder>
2013-01-12T21:53:12+00:00 DEBUG: O     <FolderType>
2013-01-12T21:53:12+00:00 DEBUG: O      Email
2013-01-12T21:53:12+00:00 DEBUG: O     <FolderType/>
2013-01-12T21:53:12+00:00 DEBUG: O     <SyncKey>
2013-01-12T21:53:12+00:00 DEBUG: O      {50f1db48-49a4-45e1-837e-6f33052c630d}1
2013-01-12T21:53:12+00:00 DEBUG: O     <SyncKey/>
2013-01-12T21:53:12+00:00 DEBUG: O     <FolderId>
2013-01-12T21:53:12+00:00 DEBUG: O      INBOX
2013-01-12T21:53:12+00:00 DEBUG: O     <FolderId/>
2013-01-12T21:53:12+00:00 DEBUG: O     <Status>
2013-01-12T21:53:12+00:00 DEBUG: O      3
2013-01-12T21:53:12+00:00 DEBUG: O     <Status/>
2013-01-12T21:53:12+00:00 DEBUG: O    <Folder/>
2013-01-12T21:53:12+00:00 DEBUG: O   <Folders/>
2013-01-12T21:53:12+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:53:12+00:00 DEBUG: I      <Remove>
2013-01-12T21:53:12+00:00 DEBUG: No collections - looking in sync_cache.
2013-01-12T21:53:12+00:00 DEBUG: Found a syncable collection:  : {50f1cc44-28f0-468c-962a-6a5c052c630d}2
2013-01-12T21:53:12+00:00 ERR: Unmatched end tag:
2013-01-12T21:53:12+00:00 ERR: Array
(
    [1] => 1
    [2] => Remove
    [4] => 1
)

2013-01-12T21:53:12+00:00 DEBUG: O  <Synchronize>
2013-01-12T21:53:12+00:00 DEBUG: O   <Status>
2013-01-12T21:53:12+00:00 DEBUG: O    4
2013-01-12T21:53:12+00:00 DEBUG: O   <Status/>
2013-01-12T21:53:12+00:00 DEBUG: O  <Synchronize/>
2013-01-12T21:53:12+00:00 ERR: PROTOCOL ERROR: Missing closing SYNC tag
2013-01-12T21:53:12+00:00 INFO: [28467] User tom logged off


More information about the horde mailing list