[horde] ActiveSync Ping/Sync flooding in webserver log

Thu Jul 20 23:50:30 UTC 2017

Quoting Volker Then <horde40 at volkerthen.com>:

> Quoting Volker Then <horde40 at volkerthen.com>:
>
>> Hi Mike,
>>
>> I have activesync problems with two clients, both using Outlook  
>> 15.0.4945 (and alos Outlook 16), and both are flooding the  
>> webserver log with Ping/sync requests.
>>
>> In the device logs I found lines like this
>>
>> NOTICE: STATE: Error saving state, checking if this is due to  
>> previous synckey {596f159b-37c0-4f03-aaa9-2a9494fb36a2}3 not being  
>> accepted by client.
>>
>>
>>
>> [31116][2017-07-19T12:29:47+02:00] ERR: Permission Denied

Looks like something permissions related.

>> [822][2017-07-19T12:29:47+02:00] INFO:  
>> ----------Horde_Core_ActiveSync_Driver::authenticate() attempt for  
>> *********_wagner----------
>> [822][2017-07-19T12:29:47+02:00] INFO: ----------PING request  
>> received for user *********_wagner
>> [822][2017-07-19T12:29:47+02:00] INFO: ----------Request being  
>> handled for device: C7192254727E416BB3F0D430B5363C9E, Supporting  
>> protocol version: 14.0, Using Horde_ActiveSync v2.38.6
>>
>>
>> [886][2017-07-19T12:29:43+02:00] ERR: COLLECTIONS: Attempting to  
>> add a collection
>>                    to the sync cache while requiring a synckey, but no
>>                    synckey could be found. Most likely a client error in
>>                    requesting a collection during PING before it  
>> has issued a
>>
>>
>> Both users share their resources (calendars) with each other and  
>> other users. Syncing on iOS and Android, both native and Outlook  
>> work properly.
>>
>> What can cause the issue? I tried to remove the device and resync.  
>> No success. Removing and reinstalling the accounts on Outlook, no  
>> success.
>>
>> Regards,
>>
>> Volker
>
> Hi,
>
> seems I don't receive anymore list mails, something broken?
>
> I checked the accounts now on an older Outlook version, but again  
> the sync process floods the logfiles. Constant Login/Logouts on the  
> IMAP server, and loads of error messages in the horde.log,  
> "integrity constraint violation". Any way that I can fix this?
>
>
>
> 2017-07-20T10:40:15+02:00 ERR: HORDE Buffer contents:  [pid 28620 on  
> line 165 of "/usr/share/php/Horde/Rpc/ActiveSync.php"]
> 2017-07-20T10:40:16+02:00 NOTICE: HORDE [imp] Login success for  
> user_petri (84.189.194.183) to {imap://localhost/} [pid 28833 on  
> line 157 of "/var/www/horde/imp/lib/Auth.php"]
> 2017-07-20T10:40:16+02:00 NOTICE: HORDE [imp] Login success for  
> user_petri (84.189.194.183) to {imap://localhost/} [pid 29854 on  
> line 157 of "/var/www/horde/imp/lib/Auth.php"]
> 2017-07-20T10:40:16+02:00 ERR: HORDE SQL QUERY FAILED:  
> SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate  
> entry '{59706a84-5788-4862-8c5b-651b94fb36a2}5' for key 'PRIMARY'
>         INSERT INTO `horde_activesync_state` (`sync_key`, `sync_data`,
>           `sync_devid`, `sync_mod`, `sync_folderid`, `sync_user`,
>           `sync_pending`, `sync_timestamp`) VALUES (?, :binary0, ?,  
> ?, ?, ?, ?,
>           ?) [pid 29854 on line 282 of  
> "/usr/share/php/Horde/Db/Adapter/Pdo/Base.php"]
> 2017-07-20T10:40:17+02:00 ERR: HORDE SQL QUERY FAILED:  
> SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate  
> entry '{59706a84-be84-4252-89d1-651b94fb36a2}5' for key 'PRIMARY'
>         INSERT INTO `horde_activesync_state` (`sync_key`, `sync_data`,
>           `sync_devid`, `sync_mod`, `sync_folderid`, `sync_user`,
>           `sync_pending`, `sync_timestamp`) VALUES (?, :binary0, ?,  
> ?, ?, ?, ?,
>           ?) [pid 29854 on line 282 of  
> "/usr/share/php/Horde/Db/Adapter/Pdo/Base.php"]
> 2017-07-20T10:40:17+02:00 ERR: HORDE Returning HTTP 500 while  
> handling Sync command. Error is: Permission Denied [pid 29854 on  
> line 160 of "/var/www/horde/rpc.php"]
> 2017-07-20T10:40:17+02:00 ERR: HORDE Error in communicating with  
> ActiveSync server: Permission Denied [pid 29854 on line 165 of  
> "/usr/share/php/Horde/Rpc/ActiveSync.php"]

Looks like it's a calendar that the user no longer has permissions for?

a
> 2017-07-20T10:40:17+02:00 ERR: HORDE #0 [internal function]:  
> Kronolith_Api->listEvents(1500539585, 0, Array, false, false, false,  
> true, false)
> #1 /usr/share/php/Horde/Registry.php(1132):  
> call_user_func_array(Array, Array)
> #2 /usr/share/php/Horde/Registry.php(1089):  
> Horde_Registry->callByPackage('kronolith', 'listEvents', Array)
> #3 /usr/share/php/Horde/Registry/Caller.php(41):  
> Horde_Registry->call('calendar/listEv...', Array)
> #4 /usr/share/php/Horde/Core/ActiveSync/Connector.php(1187):  
> Horde_Registry_Caller->__call('listEvents', Array)
> #5 /usr/share/php/Horde/Core/ActiveSync/Connector.php(1187):  
> Horde_Registry_Caller->listEvents(1500539585, 0, Array, false,  
> false, false, true, false)
> #6 /usr/share/php/Horde/Core/ActiveSync/Driver.php(1004):  
> Horde_Core_ActiveSync_Connector->softDelete('calendar', 1500539585,  
> 0, 'RNE1Y4G7GEhobMo...')
> #7 /usr/share/php/Horde/ActiveSync/State/Base.php(433):  
> Horde_Core_ActiveSync_Driver->getServerChanges(Object(Horde_ActiveSync_Folder_Collection), 23552, 23552, 0, false, true, 100,  
> false)
> #8 /usr/share/php/Horde/ActiveSync/Collections.php(1395):  
> Horde_ActiveSync_State_Base->getChanges(Array)
> #9 /usr/share/php/Horde/ActiveSync/Collections.php(1411):  
> Horde_ActiveSync_Collections->getCollectionChanges(false)
> #10 /usr/share/php/Horde/ActiveSync/Request/Sync.php(371):  
> Horde_ActiveSync_Collections->getCollectionChangeCount()
> #11 /usr/share/php/Horde/ActiveSync/Request/Base.php(249):  
> Horde_ActiveSync_Request_Sync->_handle()
> #12 /usr/share/php/Horde/ActiveSync.php(839):  
> Horde_ActiveSync_Request_Base->handle()
> #13 /usr/share/php/Horde/Rpc/ActiveSync.php(143):  
> Horde_ActiveSync->handleRequest('Sync', '4E5767145FF1415...')
> #14 /var/www/horde/rpc.php(160): Horde_Rpc_ActiveSync->getResponse(NULL)
> #15 {main} [pid 29854 on line 165 of  
> "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>
>
>
>
> -- 
> Horde mailing list
> Frequently Asked Questions: http://horde.org/faq/
> To unsubscribe, mail: horde-unsubscribe at lists.horde.org

-- 
mike
The Horde Project
http://www.horde.org
https://www.facebook.com/hordeproject
https://www.twitter.com/hordeproject
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-keys
Size: 9272 bytes
Desc: PGP Public Key
URL: <https://lists.horde.org/archives/horde/attachments/20170720/721c889f/attachment.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 821 bytes
Desc: PGP Digital Signature
URL: <https://lists.horde.org/archives/horde/attachments/20170720/721c889f/attachment-0001.bin>