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

Tue May 25 18:10:44 UTC 2010

Quoting Lukas Gradl <horde at ssn.at>:

>>
>> Thanks for the report, need to know some more though:
>>
>> Did you by any chance change the value for the turba pref that selects
>> the address books to use for sync between sync attempts?
>
> No, only thing I changed was emptying all the horde_activesync_*  
> tables to get something comparable
>
>>
>> What *is* the value of your sync_books pref...and what is the source
>> name for you ldap source? I'm not sure how this could be Nokia specific
>> - unless the error is a red-herring. The device knows nothing about the
>> source names in turba, so this would not have come from the device.
>
> After the first problems I changed it to "privat" everywhere - the  
> pref, the Name of the Addressbook, name in $cfgSources...
>
>>
>> Can you also check the web server error log for any php errors?
>>
>
> No, no PHP-Errors. 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 and $cfgSources is filled  
> as expected.

Hm. It sounds like the username isn't being passed by Nokia in the  
Http auth headers, as it's supposed to do. Can you check to see what  
the value of Horde_Auth::getAuth() is in turba's listBy api method? If  
you are able to provide a wireshark trace (sanitized, of course) that  
would be even better.

>
> As a difference I could see, that the WM device called  
> getitemestimate after the first contact, the Nokia called foldersync.
>
> I attach the first lines of the log of a WM-Sync as well.
>
> Regards
> Lukas
>
>
> Windows-Mobile 6.1 Sync:
>
> 2010-05-25T19:51:14+02:00 DEBUG: Horde_Rpc::__construct complete
> 2010-05-25T19:51:14+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() starting
> 2010-05-25T19:51:14+02:00 INFO: Horde_ActiveSync_Driver_Horde::logon  
> attempt for:
> 2010-05-25T19:51:14+02:00 INFO: Access denied for user: . Username  
> or password incorrect.
> 2010-05-25T19:51:14+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() exiting
> 2010-05-25T19:51:14+02:00 DEBUG: Horde_Rpc_ActiveSync::getResponse()  
> starting for OPTIONS
> 2010-05-25T19:51:15+02:00 DEBUG: Horde_Rpc::__construct complete
> 2010-05-25T19:51:15+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() starting
> 2010-05-25T19:51:15+02:00 INFO: Horde_ActiveSync_Driver_Horde::logon  
> attempt for: grl
> 2010-05-25T19:51:18+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() exiting
> 2010-05-25T19:51:18+02:00 DEBUG: Horde_Rpc_ActiveSync::getResponse()  
> starting for OPTIONS
> 2010-05-25T19:51:20+02:00 DEBUG: Horde_Rpc::__construct complete
> 2010-05-25T19:51:20+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() starting
> 2010-05-25T19:51:20+02:00 INFO: Horde_ActiveSync_Driver_Horde::logon  
> attempt for: grl
> 2010-05-25T19:51:24+02:00 DEBUG: Horde_Rpc_ActiveSync::authorize() exiting
> 2010-05-25T19:51:24+02:00 DEBUG: Horde_Rpc_ActiveSync::getResponse()  
> starting for GetItemEstimate
> 2010-05-25T19:51:24+02:00 DEBUG: [0233926CB617045293D42FFAA8EA33F1]  
> Device entry does not exist, creating it.
> 2010-05-25T19:51:24+02:00 DEBUG: [0233926CB617045293D42FFAA8EA33F1]  
> Device entry does not exist for user grl, creating it.
> 2010-05-25T19:51:24+02:00 INFO: Request received from device:  
> 0233926CB617045293D42FFAA8EA33F1 Supporting protocol version: 2.5
> 2010-05-25T19:51:24+02:00 INFO: [0233926CB617045293D42FFAA8EA33F1]  
> Beginning GETITEMESTIMATE
> 2010-05-25T19:51:24+02:00 DEBUG: Policykey: 0 verified.
> 2010-05-25T19:51:24+02:00 DEBUG: I  <GetItemEstimate:GetItemEstimate>
> 2010-05-25T19:51:24+02:00 DEBUG: I   <GetItemEstimate:Folders>
> 2010-05-25T19:51:24+02:00 DEBUG: I    <GetItemEstimate:Folder>
> 2010-05-25T19:51:24+02:00 DEBUG: I     <GetItemEstimate:FolderType>
> 2010-05-25T19:51:24+02:00 DEBUG: I      Contacts
> 2010-05-25T19:51:24+02:00 DEBUG: I     </GetItemEstimate:FolderType>
> 2010-05-25T19:51:24+02:00 DEBUG: I     <GetItemEstimate:FolderId>
> 2010-05-25T19:51:24+02:00 DEBUG: I      Contacts
> 2010-05-25T19:51:24+02:00 DEBUG: I     </GetItemEstimate:FolderId>
> 2010-05-25T19:51:24+02:00 DEBUG: I     <FilterType>
> 2010-05-25T19:51:24+02:00 DEBUG: I      0
> 2010-05-25T19:51:24+02:00 DEBUG: I     </FilterType>
> 2010-05-25T19:51:24+02:00 DEBUG: I     <SyncKey>
> 2010-05-25T19:51:24+02:00 DEBUG: I {f40871c4-5359-4a67-8b28-0dfb101f8083}1
> 2010-05-25T19:51:24+02:00 DEBUG: I     </SyncKey>
> 2010-05-25T19:51:24+02:00 DEBUG: I    </GetItemEstimate:Folder>
> 2010-05-25T19:51:24+02:00 DEBUG: I   </GetItemEstimate:Folders>
> 2010-05-25T19:51:24+02:00 DEBUG: Unmatched tagGetItemEstimate:Folder:
> 2010-05-25T19:51:24+02:00 DEBUG: [0233926CB617045293D42FFAA8EA33F1]  
> Loading state for synckey {f40871c4-5359-4a67-8b28-0dfb101f8083}1
> 2010-05-25T19:51:24+02:00 DEBUG: [0233926CB617045293D42FFAA8EA33F1]  
> SQL query by Horde_ActiveSync_State:_gc(): SELECT sync_key FROM  
> horde_activesy
> nc_state WHERE sync_devid = ? AND sync_folderid = ? VALUES: Array
> (
>     [0] => 0233926CB617045293D42FFAA8EA33F1
>     [1] => Contacts
> )
>
> 2010-05-25T19:51:24+02:00 DEBUG: O  <GetItemEstimate:GetItemEstimate>
> 2010-05-25T19:51:24+02:00 DEBUG: O   <GetItemEstimate:Response>
> 2010-05-25T19:51:24+02:00 DEBUG: O    <GetItemEstimate:Status>
> 2010-05-25T19:51:24+02:00 DEBUG: O    4
>
>
> Regards
>
>
>
> -- 
>
> ----------------------------
> 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
> ----------------------------
>
> -- 
> Horde developers mailing list - Join the hunt: http://horde.org/bounties/
> Frequently Asked Questions: http://horde.org/faq/
> To unsubscribe, mail: dev-unsubscribe at lists.horde.org

-- 
Mike

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

"Reality is merely an illusion, albeit a very persistent one." - A. Einstein