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

Michael J Rubinsky mrubinsk at horde.org
Fri Mar 8 22:13:46 UTC 2013


Quoting Mauser Info <andreas at mauser.info>>
> #############################################
> Am 08.03.2013 22:34, schrieb Michael J Rubinsky:
>>
>> S/MIME vs Mailman again...
>>
>> ----- Forwarded message from Michael J Rubinsky <mrubinsk at horde.org>
>> -----
>>     Date: Fri, 08 Mar 2013 16:18:09 -0500
>>     From: Michael J Rubinsky <mrubinsk at horde.org>
>> Reply-To: mrubinsk at horde.org
>>  Subject: Re: [horde] Fwd: Ungültige Serveradresse oder nicht
>> unterstützte Protokollversion
>>       To: Mauser Info <andreas at mauser.info>
>>       Cc: horde at lists.horde.org
>>
>> Quoting Mauser Info <andreas at mauser.info>:
>>
>>> 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?
>>
>> This is the currently running PING (or looping SYNC depending on the
>> client). Once the heartbeat interval has passed and the PING
>> completes, they will stop.
>>
>>
>>
> I hope it will stop because its running now for about half an hour.. :)
>
>
IIRC, this can be as long as 59 minutes (the maximum heartbeat  
interval per the specs).

mike
Sent from mobile

Mauser Info <andreas at mauser.info> wrote:





More information about the horde mailing list