[horde] Fwd: Ungültige Serveradresse oder nicht unterstützte Protokollversion

Mauser Info andreas at mauser.info
Fri Mar 8 21:08:21 UTC 2013


Am 08.03.2013 21:42, schrieb Michael J Rubinsky:
>
> Quoting Mauser Info <andreas at mauser.info>:
>
>> Am 07.03.2013 20:37, schrieb Michael J Rubinsky:
>>>
>>> Quoting Andreas Mauser <andreas at mauser.info>:
>>>
>>>> ----- Nachricht von Michael J Rubinsky <mrubinsk at horde.org> ---------
>>>>      Datum: Wed, 06 Mar 2013 16:04:42 -0500
>>>>        Von: Michael J Rubinsky <mrubinsk at horde.org>
>>>> Antwort an: mrubinsk at horde.org
>>>>    Betreff: Re: [horde] Fwd: Ungültige Serveradresse oder nicht
>>>> unterstützte Protokollversion
>>>>         An: Andreas Mauser <andreas at mauser.info>
>>>>         Cc: horde at lists.horde.org
>>>>
>>>>
>>>>> Quoting Andreas Mauser <andreas at mauser.info>:
>>>>>
>>>>>> ----- Nachricht von Michael J Rubinsky <mrubinsk at horde.org>
>>>>>> ---------
>>>>>>    Datum: Wed, 06 Mar 2013 13:47:16 -0500
>>>>>>      Von: Michael J Rubinsky <mrubinsk at horde.org>
>>>>>> Antwort an: mrubinsk at horde.org
>>>>>>  Betreff: Re: [horde] Fwd: Ungültige Serveradresse oder nicht
>>>>>> unterstützte Protokollversion
>>>>>>       An: Andreas Mauser <andreas at mauser.info>,
>>>>>> horde at lists.horde.org
>>>>>>
>>>>>>
>>>>>>> Quoting Andreas Mauser <andreas at mauser.info>:
>>>>>>>
>>>>>>>> right, Im sorry, attached the unencrypted trace.
>>>>>>>> Thank you for looking in.
>>>>>>>> Andreas
>>>>>>>
>>>>>>> The server is not sending the Version or Commands headers in
>>>>>>> response to the OPTIONS request. I've tried to duplicate it
>>>>>>> locally but cannot. You will have to find out why this is failing.
>>>>>>>
>>>>>>> If you are using Git, please update; I've recently added some
>>>>>>> improvements to the logging that are not yet in the released
>>>>>>> packages. It might help log the error.
>>>>>>
>>>>>> I do not use Git, but if you recommend it I will use Git.
>>>>>> Does an Update with Git affect my pear installed Horde installation?
>>>>>> Will your improvements go into pear and when?
>>>>>
>>>>> No, if you are not already using or familiar with our Git checkouts,
>>>>> I would not recommend this. The fixes will be in the next Horde_Core
>>>>> release.
>>>>
>>>> I updated Horde right now over PEAR - can you tell if your
>>>> improvements are in this update?
>>>
>>> The new Horde_Core package hasn't been released yet. I'll try and push
>>> it out later today if somebody else doesn't beat me to it.
>>>
>>>
>> I updated Horde_Core today and found no new messages iin access.log and
>> error.log, but there is some more in syslog:
>>
>> 2013-03-08T20:42:26.712647+01:00 webster HORDE: [horde] SQL  (0.0003s)
>> #012#011SELECT cache_data FROM horde_activesync_cache WHERE cache_devid
>> =#012#011  '333534393135303539303730373634' AND cache_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.716632+01:00 webster HORDE: [horde] SQL  (0.0003s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid = 'INBOX'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.717276+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.717774+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.718416+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{51324c2c-a19c-43af-9351-3e780a001802}45' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.761170+01:00 webster HORDE: [horde] SQL  (0.0003s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid =
>> '@Tasks@' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.761745+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.762406+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.762848+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{513219d8-d264-4129-bbc9-1c260a001802}2' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.765343+01:00 webster HORDE: [nag] SQL  (0.0004s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362237914 AND history_action = 'add' AND
>> history_ts <#012#011  1362771746 AND object_uid LIKE
>> 'nag:g0aYQhPLm4NPQ9zMj4FQi6A:%' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.766282+01:00 webster HORDE: [nag] SQL  (0.0002s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362237914 AND history_action = 'modify' AND
>> history_ts <#012#011  1362771746 AND object_uid LIKE
>> 'nag:g0aYQhPLm4NPQ9zMj4FQi6A:%' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.767263+01:00 webster HORDE: [nag] SQL  (0.0004s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362237914 AND history_action = 'delete' AND
>> history_ts <#012#011  1362771746 AND object_uid LIKE
>> 'nag:g0aYQhPLm4NPQ9zMj4FQi6A:%' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.768269+01:00 webster HORDE: [horde] SQL  (0.0003s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid =
>> '@Contacts@' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.768824+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.769392+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.769826+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{513219dd-0d08-4d09-bb3c-1c1f0a001802}13' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.772081+01:00 webster HORDE: [turba] SQL  (0.0003s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362238129 AND history_action = 'add' AND
>> history_ts <#012#011  1362771746 AND object_uid LIKE
>> 'turba:Gr_sLxPLm4NPQ9zLwrTQi6A:%' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.772824+01:00 webster HORDE: [turba] SQL  (0.0003s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362238129 AND history_action = 'modify' AND
>> history_ts <#012#011  1362771746 AND object_uid LIKE
>> 'turba:Gr_sLxPLm4NPQ9zLwrTQi6A:%' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.773729+01:00 webster HORDE: [turba] SQL  (0.0003s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362238129 AND history_action = 'delete' AND
>> history_ts <#012#011  1362771746 AND object_uid LIKE
>> 'turba:Gr_sLxPLm4NPQ9zLwrTQi6A:%' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.774751+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid =
>> '@Calendar@' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.775341+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.775815+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 19451 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.776470+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{5139dd08-f8fc-4294-b50a-18410a001802}2' [pid 19451 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.779091+01:00 webster HORDE: [kronolith] SQL
>> (0.0003s)  #012#011SELECT DISTINCT object_uid, history_id FROM
>> horde_histories WHERE#012#011  history_ts > 1362746636 AND
>> history_action = 'add' AND history_ts <#012#011  1362771746 AND
>> object_uid LIKE 'kronolith:mP_yDxPLm4NPQ9zNIL6Qi6A:%' [pid 19451 on line
>> 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.779881+01:00 webster HORDE: [kronolith] SQL
>> (0.0002s)  #012#011SELECT DISTINCT object_uid, history_id FROM
>> horde_histories WHERE#012#011  history_ts > 1362746636 AND
>> history_action = 'modify' AND history_ts <#012#011  1362771746 AND
>> object_uid LIKE 'kronolith:mP_yDxPLm4NPQ9zNIL6Qi6A:%' [pid 19451 on line
>> 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:42:26.781441+01:00 webster HORDE: [kronolith] SQL
>> (0.0006s)  #012#011SELECT DISTINCT object_uid, history_id FROM
>> horde_histories WHERE#012#011  history_ts > 1362746636 AND
>> history_action = 'delete' AND history_ts <#012#011  1362771746 AND
>> object_uid LIKE 'kronolith:mP_yDxPLm4NPQ9zNIL6Qi6A:%' [pid 19451 on line
>> 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>>
>>
>>
>> and this part looks different, I tried to sync with exchange connector
>> at this time:
>>
>> 2013-03-08T20:49:13.162682+01:00 webster HORDE: [horde]
>> Horde_Rpc::__construct complete [pid 17703 on line 96 of
>> "/usr/share/pear/Horde/Rpc.php"]
>> 2013-03-08T20:49:13.163244+01:00 webster HORDE: [horde]
>> Horde_Rpc_ActiveSync::getResponse() starting for OPTIONS [pid 17703 on
>> line 124 of "/usr/share/pear/Horde/Rpc/ActiveSync.php"]
>> 2013-03-08T20:49:13.165847+01:00 webster HORDE: [horde] Error in
>> communicating with ActiveSync server: Horde_Log_Handler_Stream: Unable
>> to write to stream [pid 17703 on line 223 of
>> "/usr/share/pear/Horde/Rpc/ActiveSync.php"]
>> 2013-03-08T20:49:13.166108+01:00 webster HORDE: [horde] #0
>> /usr/share/pear/Horde/Log/Handler/Base.php(69):
>> Horde_Log_Handler_Stream->write(Array)#012#1
>> /usr/share/pear/Horde/Log/Logger.php(193):
>> Horde_Log_Handler_Base->log(Array)#012#2
>> /usr/share/pear/Horde/Log/Logger.php(134):
>> Horde_Log_Logger->log('[17703] Horde_C...', 6)#012#3
>> /usr/share/pear/Horde/Core/ActiveSync/Driver.php(157):
>> Horde_Log_Logger->__call('info', Array)#012#4
>> /usr/share/pear/Horde/Core/ActiveSync/Driver.php(157):
>> Horde_Log_Logger->info('[17703] Horde_C...')#012#5
>> /usr/share/pear/Horde/ActiveSync.php(406):
>> Horde_Core_ActiveSync_Driver->authenticate('andreas at mauser....',
>> 'sogzumirnetoida...', NULL)#012#6
>> /usr/share/pear/Horde/ActiveSync.php(559):
>> Horde_ActiveSync->authenticate()#012#7
>> /usr/share/pear/Horde/Rpc/ActiveSync.php(126):
>> Horde_ActiveSync->handleRequest('Options', NULL)#012#8
>> /var/www/html/mauser.info/mailoffice/rpc.php(157):
>> Horde_Rpc_ActiveSync->getResponse(NULL)#012#9 {main} [pid 17703 on line
>> 224 of "/usr/share/pear/Horde/Rpc/ActiveSync.php"]
>> 2013-03-08T20:49:13.166271+01:00 webster HORDE: [horde] Buffer
>> contents:  [pid 17703 on line 225 of
>> "/usr/share/pear/Horde/Rpc/ActiveSync.php"]
>> 2013-03-08T20:49:13.166745+01:00 webster HORDE: [horde] Max memory
>> usage: 9699328 bytes [pid 17703 on line 555 of
>> "/usr/share/pear/Horde/Registry.php"]
>> 2013-03-08T20:49:13.470627+01:00 webster HORDE: [horde] SQL  (0.0003s)
>> #012#011SELECT cache_data FROM horde_activesync_cache WHERE cache_devid
>> =#012#011  '333534393135303539303730373634' AND cache_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.471359+01:00 webster HORDE: [horde] SQL  (0.0004s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid = 'INBOX'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.472092+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.472652+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.473224+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{51324c2c-a19c-43af-9351-3e780a001802}45' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.516222+01:00 webster HORDE: [horde] SQL  (0.0003s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid =
>> '@Tasks@' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.516793+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.517506+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.518152+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{513219d8-d264-4129-bbc9-1c260a001802}2' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.520531+01:00 webster HORDE: [nag] SQL  (0.0004s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362237914 AND history_action = 'add' AND
>> history_ts <#012#011  1362772153 AND object_uid LIKE
>> 'nag:g0aYQhPLm4NPQ9zMj4FQi6A:%' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.521580+01:00 webster HORDE: [nag] SQL  (0.0005s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362237914 AND history_action = 'modify' AND
>> history_ts <#012#011  1362772153 AND object_uid LIKE
>> 'nag:g0aYQhPLm4NPQ9zMj4FQi6A:%' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.522421+01:00 webster HORDE: [nag] SQL  (0.0003s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362237914 AND history_action = 'delete' AND
>> history_ts <#012#011  1362772153 AND object_uid LIKE
>> 'nag:g0aYQhPLm4NPQ9zMj4FQi6A:%' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.523485+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid =
>> '@Contacts@' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.524094+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.524626+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.525249+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{513219dd-0d08-4d09-bb3c-1c1f0a001802}13' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.527621+01:00 webster HORDE: [turba] SQL  (0.0004s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362238129 AND history_action = 'add' AND
>> history_ts <#012#011  1362772153 AND object_uid LIKE
>> 'turba:Gr_sLxPLm4NPQ9zLwrTQi6A:%' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.528624+01:00 webster HORDE: [turba] SQL  (0.0003s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362238129 AND history_action = 'modify' AND
>> history_ts <#012#011  1362772153 AND object_uid LIKE
>> 'turba:Gr_sLxPLm4NPQ9zLwrTQi6A:%' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.529416+01:00 webster HORDE: [turba] SQL  (0.0003s)
>> #012#011SELECT DISTINCT object_uid, history_id FROM horde_histories
>> WHERE#012#011  history_ts > 1362238129 AND history_action = 'delete' AND
>> history_ts <#012#011  1362772153 AND object_uid LIKE
>> 'turba:Gr_sLxPLm4NPQ9zLwrTQi6A:%' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.530543+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_state WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_folderid =
>> '@Calendar@' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.531173+01:00 webster HORDE: [horde] SQL  (0.0001s)
>> #012#011SELECT sync_key FROM horde_activesync_map WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.531670+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_key FROM horde_activesync_mailmap WHERE sync_devid
>> =#012#011  '333534393135303539303730373634' AND sync_user = 'andreas'
>> [pid 16942 on line 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.532219+01:00 webster HORDE: [horde] SQL  (0.0002s)
>> #012#011SELECT sync_data, sync_devid, sync_time, sync_pending
>> FROM#012#011  horde_activesync_state WHERE sync_key =#012#011
>> '{5139dd08-f8fc-4294-b50a-18410a001802}2' [pid 16942 on line 806 of
>> "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.534177+01:00 webster HORDE: [kronolith] SQL
>> (0.0003s)  #012#011SELECT DISTINCT object_uid, history_id FROM
>> horde_histories WHERE#012#011  history_ts > 1362746636 AND
>> history_action = 'add' AND history_ts <#012#011  1362772153 AND
>> object_uid LIKE 'kronolith:mP_yDxPLm4NPQ9zNIL6Qi6A:%' [pid 16942 on line
>> 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.534833+01:00 webster HORDE: [kronolith] SQL
>> (0.0002s)  #012#011SELECT DISTINCT object_uid, history_id FROM
>> horde_histories WHERE#012#011  history_ts > 1362746636 AND
>> history_action = 'modify' AND history_ts <#012#011  1362772153 AND
>> object_uid LIKE 'kronolith:mP_yDxPLm4NPQ9zNIL6Qi6A:%' [pid 16942 on line
>> 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>> 2013-03-08T20:49:13.535576+01:00 webster HORDE: [kronolith] SQL
>> (0.0002s)  #012#011SELECT DISTINCT object_uid, history_id FROM
>> horde_histories WHERE#012#011  history_ts > 1362746636 AND
>> history_action = 'delete' AND history_ts <#012#011  1362772153 AND
>> object_uid LIKE 'kronolith:mP_yDxPLm4NPQ9zNIL6Qi6A:%' [pid 16942 on line
>> 806 of "/usr/share/pear/Horde/Db/Adapter/Base.php"]
>>
>> The error message on the phone is still the same (invalid server URL or
>> protocol not supported via mail)
>>
>> Do you need a new tshark log?
>>
>> Thank you,
>> Andreas
>
> It looks like you have enabled the synclog in the config, but gave it
> a path to a directory that is not writable by the webserver.

Hm. The given path was owned by the webserver and had full permissions
on the ActivesyncLog folder itself.
The files in the folder had owner:rw only right. So being unsure I just
deleted the old logs which stopped logging on the 24th February, and
watched the directory while trying a new sync.
A new logfile appeared with the same rights than the old logfile has been

BUT

then the logfile started to fill up again and all data - as far as I can
see - has been replicated to the phone now..

Now I watched the log and I can see permanent checks, if these are checks.

2013-03-08T21:57:40+01:00 DEBUG: [20706]
Horde_Core_ActiveSync_Driver::getServerChanges(INBOX, 1362775950,
1362776260, 1360357060, 1)
2013-03-08T21:57:40+01:00 DEBUG: [20706] Found 0 message changes in INBOX.
2013-03-08T21:57:40+01:00 DEBUG: [20706] Initializing state for
collection: @Tasks@, synckey: {513a4f7a-3768-49fc-ab1f-50e20a001802}2
2013-03-08T21:57:40+01:00 DEBUG: [20706] Loading state for synckey
{513a4f7a-3768-49fc-ab1f-50e20a001802}2
2013-03-08T21:57:40+01:00 DEBUG: [20706] Initializing message diff
engine for @Tasks@
2013-03-08T21:57:40+01:00 DEBUG: [20706]
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1362775933,
1362776260, 0, 1)
2013-03-08T21:57:40+01:00 DEBUG: [20706] Found 0 message changes in @Tasks at .
2013-03-08T21:57:40+01:00 DEBUG: [20706] Initializing state for
collection: @Calendar@, synckey: {513a4f7c-a99c-4526-8fdb-50230a001802}5
2013-03-08T21:57:40+01:00 DEBUG: [20706] Loading state for synckey
{513a4f7c-a99c-4526-8fdb-50230a001802}5
2013-03-08T21:57:40+01:00 DEBUG: [20706] Initializing message diff
engine for @Calendar@
2013-03-08T21:57:40+01:00 DEBUG: [20706]
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362775956,
1362776260, 1361566660, 1)
2013-03-08T21:57:40+01:00 DEBUG: [20706] Found 0 message changes in
@Calendar at .
2013-03-08T21:57:42+01:00 DEBUG: [20519] Initializing state for
collection: INBOX, synckey: {513a4f77-e788-46c0-a23e-50e30a001802}6
2013-03-08T21:57:42+01:00 DEBUG: [20519] Loading state for synckey
{513a4f77-e788-46c0-a23e-50e30a001802}6
2013-03-08T21:57:42+01:00 DEBUG: [20519] Initializing message diff
engine for INBOX
2013-03-08T21:57:42+01:00 DEBUG: [20519]
Horde_Core_ActiveSync_Driver::getServerChanges(INBOX, 1362775950,
1362776262, 1360357062, 1)
2013-03-08T21:57:42+01:00 DEBUG: [20519] Found 0 message changes in INBOX.
2013-03-08T21:57:42+01:00 DEBUG: [20519] Initializing state for
collection: @Tasks@, synckey: {513a4f7a-3768-49fc-ab1f-50e20a001802}2
2013-03-08T21:57:42+01:00 DEBUG: [20519] Loading state for synckey
{513a4f7a-3768-49fc-ab1f-50e20a001802}2
2013-03-08T21:57:42+01:00 DEBUG: [20519] Initializing message diff
engine for @Tasks@
2013-03-08T21:57:42+01:00 DEBUG: [20519]
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1362775933,
1362776262, 0, 1)
2013-03-08T21:57:42+01:00 DEBUG: [20519] Found 0 message changes in @Tasks at .
2013-03-08T21:57:42+01:00 DEBUG: [20519] Initializing state for
collection: @Calendar@, synckey: {513a4f7c-a99c-4526-8fdb-50230a001802}5
2013-03-08T21:57:42+01:00 DEBUG: [20519] Loading state for synckey
{513a4f7c-a99c-4526-8fdb-50230a001802}5
2013-03-08T21:57:42+01:00 DEBUG: [20519] Initializing message diff
engine for @Calendar@
2013-03-08T21:57:42+01:00 DEBUG: [20519]
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362775956,
1362776262, 1361566662, 1)
2013-03-08T21:57:42+01:00 DEBUG: [20519] Found 0 message changes in
@Calendar at .

I get this messages even if the phone if off.

Is that anything of interest or which need to be fixed?

Thank you for your help, your hints lead me to my solution.

Andreas

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 4478 bytes
Desc: S/MIME Kryptografische Unterschrift
URL: <http://lists.horde.org/archives/horde/attachments/20130308/c4b0c725/attachment-0001.bin>


More information about the horde mailing list