Re: ActiveSync: got "ERR: Invalid address book" on Nokia Mail for exchange, but worked on WindowsMobile 6.1

Lukas Gradl <[email protected]>
Newsgroups gmane.comp.horde.sync
Message-ID <[email protected]>
On 2010-05-20 02:15, Lukas Gradl wrote:
> Hi!
>
> I tried to use ActiveSync for Horde.
>

OK after some further testing I discovered that when synching with Mail 
for Exchange 3 in function listContacts() in turba/lib/Api.php the 
variable $cfgSources is an empty array. When synching with WM 6.1 
everything works fine...

I made a trace of the synching-attempt with Mail for Exchange on a Nokia 
E90 Communicator.

Anyone an Idea what I missed?

Regards
Lukas

2010-05-20T19:08:30+02:00 DEBUG: Horde_Rpc::__construct complete
2010-05-20T19:08:30+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() starting
2010-05-20T19:08:30+02:00 INFO: Horde_ActiveSync_Driver_Horde::logon 
attempt for: grl
2010-05-20T19:08:33+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() exiting
2010-05-20T19:08:33+02:00 DEBUG: Horde_Rpc_ActiveSync::getResponse() 
starting for OPTIONS
2010-05-20T19:08:34+02:00 DEBUG: Horde_Rpc::__construct complete
2010-05-20T19:08:34+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() starting
2010-05-20T19:08:34+02:00 INFO: Horde_ActiveSync_Driver_Horde::logon 
attempt for: grl
2010-05-20T19:08:37+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() exiting
2010-05-20T19:08:37+02:00 DEBUG: Horde_Rpc_ActiveSync::getResponse() 
starting for FolderSync
2010-05-20T19:08:37+02:00 DEBUG: [IMEI353659015123157] Device entry does 
not exist, creating it.
2010-05-20T19:08:37+02:00 DEBUG: [IMEI353659015123157] Device entry does 
not exist for user grl, creating it.
2010-05-20T19:08:37+02:00 INFO: Request received from device: 
IMEI353659015123157 Supporting protocol version: 2.5
2010-05-20T19:08:37+02:00 INFO: [Horde_ActiveSync::handleFolderSync] 
Beginning FOLDERSYNC
2010-05-20T19:08:37+02:00 DEBUG: Policykey: 0 verified.
2010-05-20T19:08:37+02:00 DEBUG: I  <FolderHierarchy:FolderSync>
2010-05-20T19:08:37+02:00 DEBUG: I   <FolderHierarchy:SyncKey>
2010-05-20T19:08:37+02:00 DEBUG: I    0
2010-05-20T19:08:37+02:00 DEBUG: I   </FolderHierarchy:SyncKey>
2010-05-20T19:08:37+02:00 DEBUG: [Horde_ActiveSync::handleFolderSync] 
syncKey: 0
2010-05-20T19:08:37+02:00 DEBUG: [IMEI353659015123157] Resetting device 
state.
2010-05-20T19:08:37+02:00 DEBUG: [Horde_ActiveSync::handleFolderSync] 
newSyncKey: {18c57e14-6825-4cd2-be35-7681d9b13bb5}1
2010-05-20T19:08:37+02:00 DEBUG: I  </FolderHierarchy:FolderSync>
2010-05-20T19:08:37+02:00 DEBUG: Unmatched tagFolderHierarchy:Changes:
2010-05-20T19:08:37+02:00 DEBUG: [Horde_ActiveSync::handleFolderSync] 
Preparing to send changes to PIM
2010-05-20T19:08:37+02:00 DEBUG: [IMEI353659015123157] Initializing 
folder diff engine
2010-05-20T19:08:37+02:00 DEBUG: Horde::getFolderList()
2010-05-20T19:08:37+02:00 DEBUG: Horde::statFolder(Calendar)
2010-05-20T19:08:37+02:00 DEBUG: Horde::statFolder(Contacts)
2010-05-20T19:08:37+02:00 DEBUG: Horde::statFolder(Tasks)
2010-05-20T19:08:37+02:00 DEBUG: [IMEI353659015123157] Found 3 folder 
changes
2010-05-20T19:08:37+02:00 DEBUG: Horde::getFolder(Tasks)
2010-05-20T19:08:37+02:00 DEBUG: Horde::statFolder(Tasks)
2010-05-20T19:08:37+02:00 DEBUG: Updating state during foldersync
2010-05-20T19:08:37+02:00 DEBUG: Horde::getFolder(Contacts)
2010-05-20T19:08:37+02:00 DEBUG: Horde::statFolder(Contacts)
2010-05-20T19:08:37+02:00 DEBUG: Updating state during foldersync
2010-05-20T19:08:37+02:00 DEBUG: Horde::getFolder(Calendar)
2010-05-20T19:08:37+02:00 DEBUG: Horde::statFolder(Calendar)
2010-05-20T19:08:37+02:00 DEBUG: Updating state during foldersync
2010-05-20T19:08:37+02:00 DEBUG: O  <FolderHierarchy:FolderSync>
2010-05-20T19:08:37+02:00 DEBUG: O   <FolderHierarchy:Status>
2010-05-20T19:08:37+02:00 DEBUG: O   1
2010-05-20T19:08:37+02:00 DEBUG: O    <FolderHierarchy:Status/>
2010-05-20T19:08:37+02:00 DEBUG: O   <FolderHierarchy:SyncKey>
2010-05-20T19:08:37+02:00 DEBUG: O   {18c57e14-6825-4cd2-be35-7681d9b13bb5}1
2010-05-20T19:08:37+02:00 DEBUG: O    <FolderHierarchy:SyncKey/>
2010-05-20T19:08:37+02:00 DEBUG: O   <FolderHierarchy:Changes>
2010-05-20T19:08:37+02:00 DEBUG: O    <FolderHierarchy:Count>
2010-05-20T19:08:37+02:00 DEBUG: O    3
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:Count/>
2010-05-20T19:08:37+02:00 DEBUG: O    <FolderHierarchy:Add>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:ServerEntryId>
2010-05-20T19:08:37+02:00 DEBUG: O     Tasks
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:ServerEntryId/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:ParentId>
2010-05-20T19:08:37+02:00 DEBUG: O     0
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:ParentId/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:DisplayName>
2010-05-20T19:08:37+02:00 DEBUG: O     Tasks
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:DisplayName/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:Type>
2010-05-20T19:08:37+02:00 DEBUG: O     7
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:Type/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:Add/>
2010-05-20T19:08:37+02:00 DEBUG: O    <FolderHierarchy:Add>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:ServerEntryId>
2010-05-20T19:08:37+02:00 DEBUG: O     Contacts
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:ServerEntryId/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:ParentId>
2010-05-20T19:08:37+02:00 DEBUG: O     0
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:ParentId/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:DisplayName>
2010-05-20T19:08:37+02:00 DEBUG: O     Contacts
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:DisplayName/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:Type>
2010-05-20T19:08:37+02:00 DEBUG: O     9
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:Type/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:Add/>
2010-05-20T19:08:37+02:00 DEBUG: O    <FolderHierarchy:Add>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:ServerEntryId>
2010-05-20T19:08:37+02:00 DEBUG: O     Calendar
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:ServerEntryId/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:ParentId>
2010-05-20T19:08:37+02:00 DEBUG: O     0
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:ParentId/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:DisplayName>
2010-05-20T19:08:37+02:00 DEBUG: O     Calendar
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:DisplayName/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:Type>
2010-05-20T19:08:37+02:00 DEBUG: O     8
2010-05-20T19:08:37+02:00 DEBUG: O      <FolderHierarchy:Type/>
2010-05-20T19:08:37+02:00 DEBUG: O     <FolderHierarchy:Add/>
2010-05-20T19:08:37+02:00 DEBUG: O    <FolderHierarchy:Changes/>
2010-05-20T19:08:37+02:00 DEBUG: O   <FolderHierarchy:FolderSync/>
2010-05-20T19:08:37+02:00 DEBUG: [IMEI353659015123157] Saving state for 
synckey {18c57e14-6825-4cd2-be35-7681d9b13bb5}1
2010-05-20T19:08:37+02:00 INFO: User grl logged off
2010-05-20T19:08:38+02:00 DEBUG: Horde_Rpc::__construct complete
2010-05-20T19:08:38+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() starting
2010-05-20T19:08:38+02:00 INFO: Horde_ActiveSync_Driver_Horde::logon 
attempt for: grl
2010-05-20T19:08:42+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() exiting
2010-05-20T19:08:42+02:00 DEBUG: Horde_Rpc_ActiveSync::getResponse() 
starting for Sync
2010-05-20T19:08:42+02:00 DEBUG: SQL QUERY: SELECT device_type, 
device_agent, device_ping, device_policykey, device_rwstatus, 
device_supported FROM horde_activesync_device d INNER JOIN 
horde_activesync_device_users u ON d.device_id = u.device_id WHERE 
u.device_id = ? AND u.device_user = ? VALUES: IMEI353659015123157 grl
2010-05-20T19:08:42+02:00 INFO: Request received from device: 
IMEI353659015123157 Supporting protocol version: 2.5
2010-05-20T19:08:42+02:00 INFO: [IMEI353659015123157] Handling SYNC command.
2010-05-20T19:08:42+02:00 DEBUG: Policykey: 0 verified.
2010-05-20T19:08:42+02:00 DEBUG: I  <Synchronize>
2010-05-20T19:08:42+02:00 DEBUG: I   <Folders>
2010-05-20T19:08:42+02:00 DEBUG: I    <Folder>
2010-05-20T19:08:42+02:00 DEBUG: I     <FolderType>
2010-05-20T19:08:42+02:00 DEBUG: I      Contacts
2010-05-20T19:08:42+02:00 INFO: [IMEI353659015123157] Syncing folder 
class: Contacts
2010-05-20T19:08:42+02:00 DEBUG: I     </FolderType>
2010-05-20T19:08:42+02:00 DEBUG: I     <SyncKey>
2010-05-20T19:08:42+02:00 DEBUG: I      0
2010-05-20T19:08:42+02:00 DEBUG: I     </SyncKey>
2010-05-20T19:08:42+02:00 DEBUG: I     <FolderId>
2010-05-20T19:08:42+02:00 DEBUG: I      Contacts
2010-05-20T19:08:42+02:00 INFO: [IMEI353659015123157] Folder server id: 
Contacts
2010-05-20T19:08:42+02:00 DEBUG: I     </FolderId>
2010-05-20T19:08:42+02:00 DEBUG: I    </Folder>
2010-05-20T19:08:42+02:00 DEBUG: Unmatched tagSupported:
2010-05-20T19:08:42+02:00 DEBUG: Unmatched tagDeletesAsMoves:
2010-05-20T19:08:42+02:00 DEBUG: Unmatched tagGetChanges:
2010-05-20T19:08:42+02:00 DEBUG: Unmatched tagWindowSize:
2010-05-20T19:08:42+02:00 DEBUG: Unmatched tagOptions:
2010-05-20T19:08:42+02:00 DEBUG: [IMEI353659015123157] Resetting device 
state.
2010-05-20T19:08:42+02:00 DEBUG: Unmatched tagCommands:
2010-05-20T19:08:42+02:00 DEBUG: I   </Folders>
2010-05-20T19:08:42+02:00 DEBUG: Unmatched tagFolder:
2010-05-20T19:08:42+02:00 DEBUG: I  </Synchronize>
2010-05-20T19:08:42+02:00 INFO: [IMEI353659015123157] Beginning SYNC 
Response.
2010-05-20T19:08:42+02:00 DEBUG: O  <Synchronize>
2010-05-20T19:08:42+02:00 DEBUG: O   <Folders>
2010-05-20T19:08:42+02:00 DEBUG: O    <Folder>
2010-05-20T19:08:42+02:00 DEBUG: O     <FolderType>
2010-05-20T19:08:42+02:00 DEBUG: O     Contacts
2010-05-20T19:08:42+02:00 DEBUG: O      <FolderType/>
2010-05-20T19:08:42+02:00 DEBUG: O     <SyncKey>
2010-05-20T19:08:42+02:00 DEBUG: O {497e376d-d562-4f55-8a0d-5689e6c4fd65}1
2010-05-20T19:08:42+02:00 DEBUG: O      <SyncKey/>
2010-05-20T19:08:42+02:00 DEBUG: O     <FolderId>
2010-05-20T19:08:42+02:00 DEBUG: O     Contacts
2010-05-20T19:08:42+02:00 DEBUG: O      <FolderId/>
2010-05-20T19:08:42+02:00 DEBUG: O     <Status>
2010-05-20T19:08:42+02:00 DEBUG: O     1
2010-05-20T19:08:42+02:00 DEBUG: O      <Status/>
2010-05-20T19:08:42+02:00 DEBUG: O     <Folder/>
2010-05-20T19:08:42+02:00 DEBUG: [IMEI353659015123157] Saving state for 
synckey {497e376d-d562-4f55-8a0d-5689e6c4fd65}1
2010-05-20T19:08:42+02:00 DEBUG: O    <Folders/>
2010-05-20T19:08:42+02:00 DEBUG: O   <Synchronize/>
2010-05-20T19:08:42+02:00 INFO: User grl logged off
2010-05-20T19:08:43+02:00 DEBUG: Horde_Rpc::__construct complete
2010-05-20T19:08:43+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() starting
2010-05-20T19:08:43+02:00 INFO: Horde_ActiveSync_Driver_Horde::logon 
attempt for: grl
2010-05-20T19:08:46+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() exiting
2010-05-20T19:08:46+02:00 DEBUG: Horde_Rpc_ActiveSync::getResponse() 
starting for Sync
2010-05-20T19:08:46+02:00 DEBUG: SQL QUERY: SELECT device_type, 
device_agent, device_ping, device_policykey, device_rwstatus, 
device_supported FROM horde_activesync_device d INNER JOIN 
horde_activesync_device_users u ON d.device_id = u.device_id WHERE 
u.device_id = ? AND u.device_user = ? VALUES: IMEI353659015123157 grl
2010-05-20T19:08:46+02:00 INFO: Request received from device: 
IMEI353659015123157 Supporting protocol version: 2.5
2010-05-20T19:08:46+02:00 INFO: [IMEI353659015123157] Handling SYNC command.
2010-05-20T19:08:46+02:00 DEBUG: Policykey: 0 verified.
2010-05-20T19:08:46+02:00 DEBUG: I  <Synchronize>
2010-05-20T19:08:46+02:00 DEBUG: I   <Folders>
2010-05-20T19:08:46+02:00 DEBUG: I    <Folder>
2010-05-20T19:08:46+02:00 DEBUG: I     <FolderType>
2010-05-20T19:08:46+02:00 DEBUG: I      Contacts
2010-05-20T19:08:46+02:00 INFO: [IMEI353659015123157] Syncing folder 
class: Contacts
2010-05-20T19:08:46+02:00 DEBUG: I     </FolderType>
2010-05-20T19:08:46+02:00 DEBUG: I     <SyncKey>
2010-05-20T19:08:46+02:00 DEBUG: I {497e376d-d562-4f55-8a0d-5689e6c4fd65}1
2010-05-20T19:08:46+02:00 DEBUG: I     </SyncKey>
2010-05-20T19:08:46+02:00 DEBUG: I     <FolderId>
2010-05-20T19:08:46+02:00 DEBUG: I      Contacts
2010-05-20T19:08:46+02:00 INFO: [IMEI353659015123157] Folder server id: 
Contacts
2010-05-20T19:08:46+02:00 DEBUG: I     </FolderId>
2010-05-20T19:08:46+02:00 DEBUG: I     <DeletesAsMoves/>
2010-05-20T19:08:46+02:00 DEBUG: Unmatched tagSupported:
2010-05-20T19:08:46+02:00 DEBUG: I     <GetChanges/>
2010-05-20T19:08:46+02:00 DEBUG: I     <WindowSize>
2010-05-20T19:08:46+02:00 DEBUG: I      50
2010-05-20T19:08:46+02:00 DEBUG: I     </WindowSize>
2010-05-20T19:08:46+02:00 DEBUG: I     <Options>
2010-05-20T19:08:46+02:00 DEBUG: I      <FilterType>
2010-05-20T19:08:46+02:00 DEBUG: I       0
2010-05-20T19:08:46+02:00 DEBUG: I      </FilterType>
2010-05-20T19:08:46+02:00 DEBUG: I      <Truncation>
2010-05-20T19:08:46+02:00 DEBUG: I       2
2010-05-20T19:08:46+02:00 DEBUG: I      </Truncation>
2010-05-20T19:08:46+02:00 DEBUG: I      <Conflict>
2010-05-20T19:08:46+02:00 DEBUG: Unmatched tagRtfTruncation:
2010-05-20T19:08:46+02:00 DEBUG: Unmatched tagMIMESupport:
2010-05-20T19:08:46+02:00 DEBUG: Unmatched tagMIMETruncation:
2010-05-20T19:08:46+02:00 DEBUG: I       1
2010-05-20T19:08:46+02:00 DEBUG: I      </Conflict>
2010-05-20T19:08:46+02:00 DEBUG: I     </Options>
2010-05-20T19:08:46+02:00 DEBUG: [IMEI353659015123157] Loading state for 
synckey {497e376d-d562-4f55-8a0d-5689e6c4fd65}1
2010-05-20T19:08:46+02:00 DEBUG: [IMEI353659015123157] SQL query by 
Horde_ActiveSync_State:_gc(): SELECT sync_key FROM 
horde_activesync_state WHERE sync_devid = ? AND sync_folderid = ? 
VALUES: Array
(
     [0] => IMEI353659015123157
     [1] => Contacts
)

2010-05-20T19:08:46+02:00 DEBUG: I    </Folder>
2010-05-20T19:08:46+02:00 DEBUG: Unmatched tagCommands:
2010-05-20T19:08:46+02:00 DEBUG: I   </Folders>
2010-05-20T19:08:46+02:00 DEBUG: Unmatched tagFolder:
2010-05-20T19:08:46+02:00 DEBUG: I  </Synchronize>
2010-05-20T19:08:46+02:00 INFO: [IMEI353659015123157] Beginning SYNC 
Response.
2010-05-20T19:08:46+02:00 DEBUG: O  <Synchronize>
2010-05-20T19:08:46+02:00 DEBUG: O   <Folders>
2010-05-20T19:08:46+02:00 DEBUG: O    <Folder>
2010-05-20T19:08:46+02:00 DEBUG: O     <FolderType>
2010-05-20T19:08:46+02:00 DEBUG: O     Contacts
2010-05-20T19:08:46+02:00 DEBUG: O      <FolderType/>
2010-05-20T19:08:46+02:00 DEBUG: O     <SyncKey>
2010-05-20T19:08:46+02:00 DEBUG: O {497e376d-d562-4f55-8a0d-5689e6c4fd65}2
2010-05-20T19:08:46+02:00 DEBUG: O      <SyncKey/>
2010-05-20T19:08:46+02:00 DEBUG: O     <FolderId>
2010-05-20T19:08:46+02:00 DEBUG: O     Contacts
2010-05-20T19:08:46+02:00 DEBUG: O      <FolderId/>
2010-05-20T19:08:46+02:00 DEBUG: O     <Status>
2010-05-20T19:08:46+02:00 DEBUG: O     1
2010-05-20T19:08:46+02:00 DEBUG: O      <Status/>
2010-05-20T19:08:46+02:00 DEBUG: [IMEI353659015123157] Initializing 
message diff engine for Contacts
2010-05-20T19:08:46+02:00 DEBUG: 
Horde_ActiveSync_Driver_Horde::getServerChanges(Contacts, 0, 1274375326, 0)
2010-05-20T19:08:46+02:00 ERR: Invalid address book: privat
2010-05-20T19:08:46+02:00 DEBUG: [IMEI353659015123157] Found 0 message 
changes, checking for PIM initiated changes.
2010-05-20T19:08:46+02:00 DEBUG: [IMEI353659015123157] No PIM changes 
present, returning all messages.
2010-05-20T19:08:46+02:00 DEBUG: O     <Folder/>
2010-05-20T19:08:46+02:00 DEBUG: [IMEI353659015123157] Saving state for 
synckey {497e376d-d562-4f55-8a0d-5689e6c4fd65}2
2010-05-20T19:08:46+02:00 DEBUG: O    <Folders/>
2010-05-20T19:08:46+02:00 DEBUG: O   <Synchronize/>
2010-05-20T19:08:46+02:00 INFO: User grl logged off


-- 

----------------------------
software security networks
Lukas Gradl <horde#ssn.at>
Eduard-Bodem-Gasse 5
A - 6020 Innsbruck
Tel: +43-512-214040-0
Fax: +43-512-214040-21
----------------------------
-- 
sync mailing list - Join the hunt: http://horde.org/bounties/#sync
Frequently Asked Questions: http://horde.org/faq/
To unsubscribe, mail: [email protected]
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.