2007-11-03 20:27:05,483 INFO engine.syncengine.SyncEngine : Synchronize: manual sync triggered
2007-11-03 20:27:05,483 INFO engine.syncengine.SyncEngine : Synchronize: starting manual sync with partnership P1: id=0xb59dd90, guid="{D2C4C363-4D47-F380-5C7E-59F0CE6F10DF}", hostname="earth", name="Linux Desktop", sync_items=[ Calendar, Tasks, Contacts ]
2007-11-03 20:27:05,483 INFO engine.partnerships.Partnership : loading itemDB for item 0
2007-11-03 20:27:05,484 INFO engine.partnerships.Partnership : loading itemDB for item 1
2007-11-03 20:27:05,484 INFO engine.partnerships.Partnership : loading itemDB for item 7
2007-11-03 20:27:05,484 INFO engine.syncengine.SyncEngine : Synchronize: itemDB loaded
2007-11-03 20:27:05,485 INFO engine.syncengine.SyncEngine : Synchronize: leaving method
2007-11-03 20:27:05,486 DEBUG engine.synchandler.SyncHandler : run: sending request to device
<sync type="Interactive" xmlns="http://schemas.microsoft.com/as/2004/core">
        <partner id="{D2C4C363-4D47-F380-5C7E-59F0CE6F10DF}"/>
</sync>

2007-11-03 20:27:05,625 DEBUG engine.synchandler.SyncHandler : run: performing synchronization
2007-11-03 20:27:05,649 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-11-03 20:27:05,650 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is
<?xml version="1.0" ?>
<SyncStatus>
        <SyncBegin Datatype="" Partner=""/>
</SyncStatus>

2007-11-03 20:27:05,650 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-11-03 20:27:05,650 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-11-03 20:27:05,651 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-11-03 20:27:05,853 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-11-03 20:27:05,854 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is
<?xml version="1.0" ?>
<SyncStatus>
        <SyncBegin Datatype="" Partner="{D2C4C363-4D47-F380-5C7E-59F0CE6F10DF}"/>
</SyncStatus>

2007-11-03 20:27:05,854 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-11-03 20:27:05,854 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-11-03 20:27:05,855 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-11-03 20:27:06,317 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-11-03 20:27:06,318 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is
<?xml version="1.0" ?>
<SyncStatus>
        <Status Partner="{D2C4C363-4D47-F380-5C7E-59F0CE6F10DF}">
                <Progress value="0"/>
        </Status>
        <Status Partner="{D2C4C363-4D47-F380-5C7E-59F0CE6F10DF}">
                <Total value="100"/>
        </Status>
        <Status Partner="{D2C4C363-4D47-F380-5C7E-59F0CE6F10DF}">
                <StatusString type="Status" value="Nach Änderungen suchen"/>
        </Status>
</SyncStatus>

2007-11-03 20:27:06,319 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-11-03 20:27:06,319 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-11-03 20:27:06,320 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-11-03 20:27:06,479 INFO engine.airsync.AirsyncServer : do_POST: received GetItemEstimate command
2007-11-03 20:27:06,479 DEBUG engine.airsync.AirsyncServer : _read_xml_request: converting request from wbxml
2007-11-03 20:27:06,482 DEBUG engine.airsync.AirsyncServer : _handle_get_item_estimate: request document is
<?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<GetItemEstimate xmlns="http://synce.org/formats/airsync_wm5/getitemestimate">
        <Collections>
                <Collection>
                        <Class>
                                Contacts
                        </Class>
                        <CollectionId>
                                {B5B1DD79-8AA4-2441-8CE4-0CB405731D73}
                        </CollectionId>
                        <FilterType xmlns="http://synce.org/formats/airsync_wm5/airsync">
                                0
                        </FilterType>
                        <SyncKey xmlns="http://synce.org/formats/airsync_wm5/airsync">
                                {B5B1DD79-8AA4-2441-8CE4-0CB405731D73}2
                        </SyncKey>
                </Collection>
                <Collection>
                        <Class>
                                Calendar
                        </Class>
                        <CollectionId>
                                {99841D8E-662C-B182-EC2F-19B88AEFB71C}
                        </CollectionId>
                        <FilterType xmlns="http://synce.org/formats/airsync_wm5/airsync">
                                4
                        </FilterType>
                        <SyncKey xmlns="http://synce.org/formats/airsync_wm5/airsync">
                                {99841D8E-662C-B182-EC2F-19B88AEFB71C}3
                        </SyncKey>
                </Collection>
                <Collection>
                        <Class>
                                Tasks
                        </Class>
                        <CollectionId>
                                {0B695426-31CD-8B0B-F9E8-6422C7801B40}
                        </CollectionId>
                        <FilterType xmlns="http://synce.org/formats/airsync_wm5/airsync">
                                0
                        </FilterType>
                        <SyncKey xmlns="http://synce.org/formats/airsync_wm5/airsync">
                                {0B695426-31CD-8B0B-F9E8-6422C7801B40}2
                        </SyncKey>
                </Collection>
        </Collections>
</GetItemEstimate>

2007-11-03 20:27:06,486 DEBUG engine.airsync.AirsyncServer : _handle_get_item_estimate: response document is
<?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<GetItemEstimate xmlns="http://synce.org/formats/airsync_wm5/getitemestimate">
        <Response>
                <Status>
                        1
                </Status>
                <Collection>
                        <Class>
                                Contacts
                        </Class>
                        <CollectionId>
                                {B5B1DD79-8AA4-2441-8CE4-0CB405731D73}
                        </CollectionId>
                        <Estimate>
                                0
                        </Estimate>
                </Collection>
        </Response>
        <Response>
                <Status>
                        1
                </Status>
                <Collection>
                        <Class>
                                Calendar
                        </Class>
                        <CollectionId>
                                {99841D8E-662C-B182-EC2F-19B88AEFB71C}
                        </CollectionId>
                        <Estimate>
                                0
                        </Estimate>
                </Collection>
        </Response>
        <Response>
                <Status>
                        1
                </Status>
                <Collection>
                        <Class>
                                Tasks
                        </Class>
                        <CollectionId>
                                {0B695426-31CD-8B0B-F9E8-6422C7801B40}
                        </CollectionId>
                        <Estimate>
                                0
                        </Estimate>
                </Collection>
        </Response>
</GetItemEstimate>

2007-11-03 20:27:06,488 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting response 200 code to client
2007-11-03 20:27:06,489 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=4A954D725E48BBB12EE0095B0160F652&DeviceType=PocketPC&Cmd=GetItemEstimate HTTP/1.1" 200 -
2007-11-03 20:27:06,489 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting response 200 code to client
2007-11-03 20:27:06,490 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting wbxml (length = 209)
2007-11-03 20:27:06,490 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting wbxml
2007-11-03 20:27:06,599 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-11-03 20:27:06,599 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is
<?xml version="1.0" ?>
<SyncStatus>
        <SyncEnd Datatype="" Partner="{D2C4C363-4D47-F380-5C7E-59F0CE6F10DF}"/>
</SyncStatus>

2007-11-03 20:27:06,600 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-11-03 20:27:06,600 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-11-03 20:27:06,601 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-11-03 20:27:06,825 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-11-03 20:27:06,825 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is
<?xml version="1.0" ?>
<SyncStatus>
        <SyncEnd Datatype="" Partner=""/>
</SyncStatus>

2007-11-03 20:27:06,826 INFO engine.synchandler.SyncHandler : _sync_end_cb: Called
2007-11-03 20:27:06,826 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-11-03 20:27:06,826 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-11-03 20:27:06,827 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-11-03 20:27:07,623 DEBUG engine.synchandler.SyncHandler : run: calling RAPI sync_pause and sync_resume
2007-11-03 20:27:07,700 DEBUG engine.synchandler.SyncHandler : run: saving partnership state
2007-11-03 20:27:07,701 DEBUG engine.synchandler.SyncHandler : run: saving itemDB
2007-11-03 20:27:07,701 INFO engine.partnerships.Partnership : saving itemDB for item 0
2007-11-03 20:27:07,702 INFO engine.partnerships.Partnership : saving itemDB for item 1
2007-11-03 20:27:07,702 INFO engine.partnerships.Partnership : saving itemDB for item 7
2007-11-03 20:27:07,703 INFO engine.synchandler.SyncHandler : run: finished synchronization
2007-11-03 20:27:07,703 INFO engine.syncengine.SyncEngine : Synchronized: Emitting Synchronized signal
2007-11-03 20:27:07,705 INFO engine.syncengine.SyncEngine : prefill: slow sync prefill triggered
2007-11-03 20:27:07,706 INFO engine.prefill.PrefillThread : prefill thread entered
2007-11-03 20:27:07,706 INFO engine.prefill.PrefillThread : prefill: prefilling for item type 0
bias             -60
std_name         STD
std_year         0
std_month        10
std_dow          6
std_occurrence   5
std_start_hour   3
std_minute       0
std_second       0
std_millisecs    0
std_bias         0
dst_name                DST
dst_month        3
dst_dow          6
dst_occurrence   5
dst_start_hour   2
dst_minute       0
dst_second       0
dst_millisecs    0
dst_bias         -60
CONFIG - DST OFFSET  1:00:00
bias             -60
std_name         STD
std_year         0
std_month        10
std_dow          6
std_occurrence   5
std_start_hour   3
std_minute       0
std_second       0
std_millisecs    0
std_bias         0
dst_name                DST
dst_month        3
dst_dow          6
dst_occurrence   5
dst_start_hour   2
dst_minute       0
dst_second       0
dst_millisecs    0
dst_bias         -60
CONFIG - DST OFFSET  1:00:00
2007-11-03 20:27:07,742 INFO engine.prefill.PrefillThread : prefill: prefill complete
2007-11-03 20:27:07,743 INFO engine.syncengine.SyncEngine : Prefill complete: Emitting PrefillComplete signal
2007-11-03 20:27:07,745 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 0
2007-11-03 20:27:07,745 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: got change GUID = pas-id-CE118077A86F6F8C, ChangeType = 1, Data = <vcal><Timezone><TimezoneID>/synce.org/DST-030605T020000-STD-100605T030000</TimezoneID><Location>Unknown/Unknown</Location><DaylightSavings><TZOffsetFrom>+0100</TZOffsetFrom><TZOffsetTo>+0200</TZOffsetTo><TimezoneName>DST</TimezoneName><DateStarted>20070325T020000</DateStarted><RecurrenceRule><Rule>FREQ=YEARLY</Rule><Rule>INTERVAL=1</Rule><Rule>BYMONTH=3</Rule><Rule>BYDAY=-1SU</Rule></RecurrenceRule></DaylightSavings><Standard><TZOffsetFrom>+0200</TZOffsetFrom><TZOffsetTo>+0100</TZOffsetTo><TimezoneName>STD</TimezoneName><DateStarted>20071028T030000</DateStarted><RecurrenceRule><Rule>FREQ=YEARLY</Rule><Rule>INTERVAL=1</Rule><Rule>BYMONTH=10</Rule><Rule>BYDAY=-1SU</Rule></RecurrenceRule></Standard></Timezone><Event><Alarm><AlarmTrigger><Content>-PT15M</Content><Value>DURATION</Value><Related>START</Related></AlarmTrigger><AlarmAction>DISPLAY</AlarmAction><AlarmDescription/></Alarm><Transparency><Content>OPAQUE</Content></Transparency><LastModified><Content>20071103T192454Z</Content></LastModified><DateStarted><TimezoneID>/synce.org/DST-030605T020000-STD-100605T030000</TimezoneID><Content>20071104T140000</Content></DateStarted><DateEnd><TimezoneID>/synce.org/DST-030605T020000-STD-100605T030000</TimezoneID><Content>20071104T150000</Content></DateEnd><Location><Content/></Location><Summary><Content>termin</Content></Summary><Description><Content/></Description><Categories/></Event></vcal>
2007-11-03 20:27:07,745 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: got change GUID = pas-id-E9CCC3DD06A0E65D, ChangeType = 1, Data = <vcal><Timezone><TimezoneID>/synce.org/DST-030605T020000-STD-100605T030000</TimezoneID><Location>Unknown/Unknown</Location><DaylightSavings><TZOffsetFrom>+0100</TZOffsetFrom><TZOffsetTo>+0200</TZOffsetTo><TimezoneName>DST</TimezoneName><DateStarted>20080330T020000</DateStarted><RecurrenceRule><Rule>FREQ=YEARLY</Rule><Rule>INTERVAL=1</Rule><Rule>BYMONTH=3</Rule><Rule>BYDAY=-1SU</Rule></RecurrenceRule></DaylightSavings><Standard><TZOffsetFrom>+0200</TZOffsetFrom><TZOffsetTo>+0100</TZOffsetTo><TimezoneName>STD</TimezoneName><DateStarted>20081026T030000</DateStarted><RecurrenceRule><Rule>FREQ=YEARLY</Rule><Rule>INTERVAL=1</Rule><Rule>BYMONTH=10</Rule><Rule>BYDAY=-1SU</Rule></RecurrenceRule></Standard></Timezone><Event><Alarm><AlarmTrigger><Content>-PT15M</Content><Value>DURATION</Value><Related>START</Related></AlarmTrigger><AlarmAction>DISPLAY</AlarmAction><AlarmDescription/></Alarm><Transparency><Content>OPAQUE</Content></Transparency><LastModified><Content>20071103T192454Z</Content></LastModified><DateStarted><TimezoneID>/synce.org/DST-030605T020000-STD-100605T030000</TimezoneID><Content>20080128T080000</Content></DateStarted><DateEnd><TimezoneID>/synce.org/DST-030605T020000-STD-100605T030000</TimezoneID><Content>20080128T180000</Content></DateEnd><Location><Content/></Location><Summary><Content>TLG A Log Of S4</Content></Summary><Description><Content/></Description><Categories/><RecurrenceRule><Rule>INTERVAL=1</Rule><Rule>UNTIL=20080131T230000Z</Rule><Rule>FREQ=DAILY</Rule></RecurrenceRule></Event></vcal>
2007-11-03 20:27:07,746 DEBUG engine.syncengine.SyncEngine : return
2007-11-03 20:27:07,755 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: acking changes for items of type 0
2007-11-03 20:27:07,755 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: acking change for items GUID = pas-id-CE118077A86F6F8C
2007-11-03 20:27:07,755 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: acking change for items GUID = pas-id-E9CCC3DD06A0E65D
2007-11-03 20:27:07,756 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: saving synchronization state and itemDB
2007-11-03 20:27:07,757 INFO engine.partnerships.Partnership : saving itemDB for item 0
2007-11-03 20:27:07,758 INFO engine.partnerships.Partnership : saving itemDB for item 1
2007-11-03 20:27:07,758 INFO engine.partnerships.Partnership : saving itemDB for item 7
2007-11-03 20:27:07,761 INFO engine.syncengine.SyncEngine : prefill: slow sync prefill triggered
2007-11-03 20:27:07,762 INFO engine.prefill.PrefillThread : prefill thread entered
2007-11-03 20:27:07,763 INFO engine.prefill.PrefillThread : prefill: prefilling for item type 1
2007-11-03 20:27:07,768 INFO engine.prefill.PrefillThread : prefill: prefill complete
2007-11-03 20:27:07,768 INFO engine.syncengine.SyncEngine : Prefill complete: Emitting PrefillComplete signal
2007-11-03 20:27:07,770 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 1
2007-11-03 20:27:07,771 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: got change GUID = pas-id-6303A47486E27371, ChangeType = 1, Data = <contact xmlns:AS="http://synce.org/formats/airsync_wm5/airsync"><FileAs><Content>Tewst</Content></FileAs><FormattedName><Content>Tewst</Content></FormattedName><Name><FirstName>Tewst</FirstName><LastName/><Additional/><Suffix/><Prefix/></Name><Nickname><Content/></Nickname><Photo><Content/></Photo><Categories/><Assistant><Content/></Assistant><Manager><Content/></Manager><Organization><Name/><Department/><Unit/></Organization><Spouse><Content/></Spouse><Telephone><Type>Radio</Type><Content>079</Content></Telephone><Title><Content/></Title><Url><Content/></Url><Note><Content/></Note></contact>
2007-11-03 20:27:07,771 DEBUG engine.syncengine.SyncEngine : return
2007-11-03 20:27:07,775 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: acking changes for items of type 1
2007-11-03 20:27:07,775 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: acking change for items GUID = pas-id-6303A47486E27371
2007-11-03 20:27:07,776 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: saving synchronization state and itemDB
2007-11-03 20:27:07,777 INFO engine.partnerships.Partnership : saving itemDB for item 0
2007-11-03 20:27:07,777 INFO engine.partnerships.Partnership : saving itemDB for item 1
2007-11-03 20:27:07,778 INFO engine.partnerships.Partnership : saving itemDB for item 7
2007-11-03 20:27:07,781 INFO engine.syncengine.SyncEngine : prefill: slow sync prefill triggered
2007-11-03 20:27:07,782 INFO engine.prefill.PrefillThread : prefill thread entered
2007-11-03 20:27:07,783 INFO engine.prefill.PrefillThread : prefill: prefilling for item type 7
DATESTRING -  2007-11-14T00:00:00.000Z
DATESTRING -  2007-11-13T23:00:00.000Z
2007-11-03 20:27:07,789 INFO engine.prefill.PrefillThread : prefill: prefill complete
2007-11-03 20:27:07,789 INFO engine.syncengine.SyncEngine : Prefill complete: Emitting PrefillComplete signal
2007-11-03 20:27:07,791 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 7
2007-11-03 20:27:07,792 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: got change GUID = pas-id-8B5A2FBA63D044A9, ChangeType = 1, Data = <vcal xmlns:tz="http://synce.org/tz"><Todo><Summary><Content>Aufgabe</Content></Summary><DateDue><Content>20071113T230000Z</Content></DateDue><Class><Content>0</Content></Class><Categories/><Priority><Content>5</Content></Priority><Description><Content/></Description></Todo></vcal>
2007-11-03 20:27:07,792 DEBUG engine.syncengine.SyncEngine : return
2007-11-03 20:27:07,796 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: acking changes for items of type 7
2007-11-03 20:27:07,797 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: acking change for items GUID = pas-id-8B5A2FBA63D044A9
2007-11-03 20:27:07,797 DEBUG engine.syncengine.SyncEngine : AcknowledgeRemoteChanges: saving synchronization state and itemDB
2007-11-03 20:27:07,798 INFO engine.partnerships.Partnership : saving itemDB for item 0
2007-11-03 20:27:07,799 INFO engine.partnerships.Partnership : saving itemDB for item 1
2007-11-03 20:27:07,800 INFO engine.partnerships.Partnership : saving itemDB for item 7