2007-03-25 22:57:21,132 DEBUG syncengine : creating SyncEngine object
2007-03-25 22:57:21,168 INFO engine.syncengine.SyncEngine : __init__: connected device found
2007-03-25 22:57:21,178 DEBUG engine.syncengine.SyncEngine : sessions_start: setting up RAPI session
2007-03-25 22:57:21,205 DEBUG engine.syncengine.SyncEngine : sessions_start: initializing partnerships
2007-03-25 22:57:21,206 DEBUG engine.partnerships.Partnerships : _read_device: reading partnerships from device registry
2007-03-25 22:57:21,249 DEBUG engine.partnerships.Partnerships : _read_device: read partnership ID = 34093711, Hostname = unholycathedral
2007-03-25 22:57:21,249 DEBUG engine.partnerships.Partnerships : _read_device: Adding entry
2007-03-25 22:57:21,276 DEBUG engine.partnerships.Partnerships : _read_device: read partnership ID = 0, Hostname = 
2007-03-25 22:57:21,284 DEBUG engine.partnerships.Partnerships : _read_device: querying synchronization source information from device
2007-03-25 22:57:21,286 DEBUG engine.xmlutil : _config_query: CeProcessConfig request is 
<wap-provisioningdoc>
	<characteristic type="Sync">
		<characteristic-query recursive="false" type="Sources"/>
	</characteristic>
</wap-provisioningdoc>

2007-03-25 22:57:21,550 DEBUG engine.xmlutil : _config_query: CeProcessConfig response is 
<wap-provisioningdoc>
	<characteristic type="Sync">
		<characteristic recursive="false" type="Sources">
			<characteristic type="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
		</characteristic>
	</characteristic>
</wap-provisioningdoc>

2007-03-25 22:57:21,551 DEBUG engine.xmlutil : _config_query: CeProcessConfig request is 
<wap-provisioningdoc>
	<characteristic type="Sync">
		<characteristic type="Sources">
			<characteristic-query type="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
		</characteristic>
	</characteristic>
</wap-provisioningdoc>

2007-03-25 22:57:22,644 DEBUG engine.xmlutil : _config_query: CeProcessConfig response is 
<wap-provisioningdoc>
	<characteristic type="Sync">
		<characteristic type="Sources">
			<characteristic type="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
				<characteristic type="Engines">
					<characteristic type="{176F4FFD-F20C-4BD4-BDD7-01D0726C567B}">
						<characteristic type="CarrierConnectorList"/>
						<characteristic type="Providers">
							<characteristic type="{7E29B5F7-C686-4B0C-9892-FD8BAD8E0D08}">
								<parm name="Enabled" value="0"/>
								<parm name="Name" value="Favorites"/>
								<parm name="ReadOnly" value="1"/>
							</characteristic>
							<characteristic type="{0DD8685C-E272-4FCB-9ECF-2EAD7EA2497B}">
								<parm name="Enabled" value="1"/>
								<parm name="Name" value="Contacts"/>
								<parm name="ReadOnly" value="0"/>
							</characteristic>
							<characteristic type="{C6D47067-6E92-480E-B0FC-4BA82182FAC7}">
								<parm name="Enabled" value="0"/>
								<parm name="Name" value="E-mail"/>
								<parm name="ReadOnly" value="0"/>
							</characteristic>
							<characteristic type="{8E98CB51-85A4-4777-8DEB-A0298DF8899F}">
								<parm name="Enabled" value="0"/>
								<parm name="Name" value="Notes"/>
								<parm name="ReadOnly" value="1"/>
							</characteristic>
							<characteristic type="{783AE4F6-4C12-4423-8270-66361260D4F1}">
								<parm name="Enabled" value="1"/>
								<parm name="Name" value="Tasks"/>
								<parm name="ReadOnly" value="0"/>
							</characteristic>
							<characteristic type="{A38DEEBF-C535-D8E2-AE24-8AE61845CF82}">
								<parm name="Enabled" value="0"/>
								<parm name="Name" value="Media"/>
								<parm name="ReadOnly" value="1"/>
							</characteristic>
							<characteristic type="{4A5D9FE0-F139-4A63-A5A4-4F31CEEA02AD}">
								<parm name="Enabled" value="1"/>
								<parm name="Name" value="Calendar"/>
								<parm name="ReadOnly" value="0"/>
							</characteristic>
							<characteristic type="{B7B6ACB2-AF1D-43F5-BF9A-586111B263EF}">
								<parm name="Enabled" value="0"/>
								<parm name="Name" value="Files"/>
								<parm name="ReadOnly" value="0"/>
							</characteristic>
						</characteristic>
						<characteristic type="Settings">
							<parm name="CarrierConnector" value=""/>
							<parm name="ClientNegotiated" value="0"/>
							<parm name="ClientProtocolVersion" value=""/>
							<parm name="ConflictResolution" value="1"/>
							<parm name="DeviceAddressingMethod" value="0"/>
							<parm name="DevicePhoneNumber" value=""/>
							<parm name="DeviceSMSAddress" value=""/>
							<parm name="Domain" value="DEFAULT"/>
							<parm name="EmailAddress" value=""/>
							<parm name="Logging" value="0"/>
							<parm name="NotificationsSupported" value="0"/>
							<parm name="RefreshCertAuthXml" value="0"/>
							<parm name="SavePassword" value="1"/>
							<parm name="ServerAutdSupport" value="0"/>
							<parm name="ServerCertAuthRequired" value="0"/>
							<parm name="URI" value="Microsoft-Server-ActiveSync"/>
							<parm name="UseSSL" value="0"/>
							<parm name="User" value="DEFAULT"/>
						</characteristic>
					</characteristic>
				</characteristic>
				<parm name="Name" value="Linux Desktop"/>
				<parm name="Server" value="unholycathedral"/>
				<parm name="StoreType" value="2"/>
			</characteristic>
		</characteristic>
	</characteristic>
</wap-provisioningdoc>

2007-03-25 22:57:22,647 DEBUG engine.partnerships.Partnerships : _read_device: read source GUID = {02AC3DF2-5962-9645-3441-9E04D09EFC3C}, Hostname = unholycathedral, Description = Linux Desktop
2007-03-25 22:57:22,648 DEBUG engine.partnerships.Partnerships : _read_device: source matches partnerhip from registry.  Initializing partnership
2007-03-25 22:57:22,649 DEBUG engine.airsync.AirsyncThread : run: listening for Airsync requests
2007-03-25 22:57:22,661 INFO engine.partnerships.Partnership : load_state: loaded state with 3 items
2007-03-25 22:57:22,662 DEBUG engine.partnerships.Partnerships : _read_device: querying partnerhip synchronization items (providers)
2007-03-25 22:57:22,662 DEBUG engine.partnerships.Partnerships : _read_device: found provider Files
2007-03-25 22:57:22,662 DEBUG engine.partnerships.Partnerships : _read_device: found provider Calendar
2007-03-25 22:57:22,663 DEBUG engine.partnerships.Partnerships : _read_device: provider is enabled
2007-03-25 22:57:22,663 DEBUG engine.partnerships.Partnerships : _read_device: provider ID is 0
2007-03-25 22:57:22,663 DEBUG engine.partnerships.Partnerships : _read_device: found provider Media
2007-03-25 22:57:22,664 DEBUG engine.partnerships.Partnerships : _read_device: found provider Tasks
2007-03-25 22:57:22,664 DEBUG engine.partnerships.Partnerships : _read_device: provider is enabled
2007-03-25 22:57:22,664 DEBUG engine.partnerships.Partnerships : _read_device: provider ID is 7
2007-03-25 22:57:22,664 DEBUG engine.partnerships.Partnerships : _read_device: found provider Notes
2007-03-25 22:57:22,665 DEBUG engine.partnerships.Partnerships : _read_device: found provider E-mail
2007-03-25 22:57:22,665 DEBUG engine.partnerships.Partnerships : _read_device: found provider Contacts
2007-03-25 22:57:22,665 DEBUG engine.partnerships.Partnerships : _read_device: provider is enabled
2007-03-25 22:57:22,666 DEBUG engine.partnerships.Partnerships : _read_device: provider ID is 1
2007-03-25 22:57:22,666 DEBUG engine.partnerships.Partnerships : _read_device: found provider Favorites
2007-03-25 22:57:22,666 INFO engine.partnerships.Partnerships : Attempting to load last used partnership
2007-03-25 22:57:22,669 INFO engine.config.Config : Loading current partnership
2007-03-25 22:57:22,670 INFO engine.partnerships.Partnerships : Last partnership: id=0x2083a8f, guid="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}", hostname="unholycathedral", name="Linux Desktop"
2007-03-25 22:57:22,670 DEBUG engine.partnerships.Partnerships : Checking against: id=0x2083a8f, guid="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}", hostname="unholycathedral", name="Linux Desktop"
2007-03-25 22:57:22,670 INFO engine.partnerships.Partnerships : Match with last used partnership found - slot
2007-03-25 22:57:22,828 DEBUG engine.partnerships.Partnerships : set_current: partnership found in slot 1
2007-03-25 22:57:22,943 INFO engine.partnerships.Partnerships : Saving current partnership info
2007-03-25 22:57:22,945 INFO engine.config.Config : saving partnership file
2007-03-25 22:57:22,947 DEBUG engine.syncengine.SyncEngine : Connecting RRA session
2007-03-25 22:57:23,399 DEBUG RRAThread : have 4 object types
object id 10000 type Ink
object id 10001 type Favorite
object id 10002 type Media
object id 10003 type File
File-sync config: 
   local path           /home/sukko/PDAFiles 
   disable?             0 
   LocalUpdateFreq      10 
   ExtraDeleteDelay     0 
2007-03-25 22:57:23,402 DEBUG RRASyncManager : No RRA type subscriptions: not starting RRA thread
2007-03-25 22:57:23,402 DEBUG engine.syncengine.SyncEngine : sessions_start: calling RAPI start_replication
2007-03-25 22:57:23,406 DEBUG engine.syncengine.SyncEngine : sessions_start: calling RAPI sync_resume
2007-03-25 22:57:23,456 DEBUG syncengine : installing signal handlers
2007-03-25 22:57:23,456 DEBUG syncengine : running main loop
2007-03-25 22:57:30,755 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:30,757 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:57:30,758 INFO engine.syncengine.SyncEngine : _sync_begin_cb: monitoring auto sync with partnership P1: id=0x2083a8f, guid="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}", hostname="unholycathedral", name="Linux Desktop", sync_items=[ Calendar, Tasks, Contacts ]
2007-03-25 22:57:30,759 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:30,760 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:30,761 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:30,762 DEBUG engine.synchandler.SyncHandler : run: performing synchronization
2007-03-25 22:57:31,084 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:31,086 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:57:31,088 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:31,088 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:31,089 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:31,277 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:31,277 DEBUG engine.airsync.AirsyncServer : HTTP Request: "OPTIONS /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC HTTP/1.1" 200 -
2007-03-25 22:57:31,278 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:32,001 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:32,002 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Progress value="0"/>
	</Status>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Total value="100"/>
	</Status>
</SyncStatus>

2007-03-25 22:57:32,003 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:32,003 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:32,004 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:33,991 INFO engine.airsync.AirsyncServer : do_POST: received FolderSync command
2007-03-25 22:57:33,992 DEBUG engine.airsync.AirsyncServer : _read_xml_request: converting request from wbxml
2007-03-25 22:57:33,993 DEBUG engine.airsync.AirsyncServer : _handle_foldersync: request document is
 <?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="http://synce.org/formats/airsync_wm5/folderhierarchy">
	<SyncKey>
		0
	</SyncKey>
</FolderSync>

2007-03-25 22:57:34,004 DEBUG engine.airsync.AirsyncServer : handle_foldersync: response document is 
<?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="FolderHierarchy:">
	<Status>
		1
	</Status>
	<SyncKey>
		{00000000-0000-0000-0000-000000000000}1
	</SyncKey>
	<Changes>
		<Count>
			11
		</Count>
		<Add>
			<ServerId>
				{9E0204F3-6186-163A-273D-094FAEFDEFAC}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Sent Items
			</DisplayName>
			<Type>
				5
			</Type>
		</Add>
		<Add>
			<ServerId>
				{737658FE-FC4A-A1EB-9695-8D46EDC91240}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Outbox
			</DisplayName>
			<Type>
				6
			</Type>
		</Add>
		<Add>
			<ServerId>
				{C8363F64-168C-75AA-7BDA-19F72DA381FE}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Calendar
			</DisplayName>
			<Type>
				8
			</Type>
		</Add>
		<Add>
			<ServerId>
				{8C1B41AD-A628-2572-7832-C9A577CBA4ED}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Tasks
			</DisplayName>
			<Type>
				7
			</Type>
		</Add>
		<Add>
			<ServerId>
				{33396C3F-CC8B-0317-9865-EBD439789BBA}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Notes
			</DisplayName>
			<Type>
				10
			</Type>
		</Add>
		<Add>
			<ServerId>
				{FD792329-BEE3-A346-CB50-7264B3601FB5}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Contacts
			</DisplayName>
			<Type>
				9
			</Type>
		</Add>
		<Add>
			<ServerId>
				{32F5B768-0A62-31E9-E0C9-16C9812FC1B1}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Deleted Items
			</DisplayName>
			<Type>
				4
			</Type>
		</Add>
		<Add>
			<ServerId>
				{AD1CEA07-14AC-4C57-E565-3A1D7A6D9E67}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Inbox
			</DisplayName>
			<Type>
				2
			</Type>
		</Add>
		<Add>
			<ServerId>
				{385BD80C-5E78-488A-E671-8DDC26764DB2}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Drafts
			</DisplayName>
			<Type>
				3
			</Type>
		</Add>
		<Add>
			<ServerId>
				{9CB41DA5-FCCD-149E-6C51-37FE0E79D4C9}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Junk E-mail
			</DisplayName>
			<Type>
				12
			</Type>
		</Add>
		<Add>
			<ServerId>
				{12166AD5-6B3F-933A-F851-5B16C665700A}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Journal
			</DisplayName>
			<Type>
				11
			</Type>
		</Add>
	</Changes>
</FolderSync>

2007-03-25 22:57:34,011 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting response 200 code to client
2007-03-25 22:57:34,011 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC&Cmd=FolderSync HTTP/1.1" 200 -
2007-03-25 22:57:34,012 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting response 200 code to client
2007-03-25 22:57:34,013 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting wbxml (length = 859)
2007-03-25 22:57:34,014 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting wbxml
2007-03-25 22:57:34,062 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:34,064 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Error Body="Synchronization could not be completed. If this condition persists, try deleting and then re-creating the device's sync relationships." Code="80004005" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}" Title="Attention required"/>
</SyncStatus>

2007-03-25 22:57:34,064 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:34,065 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:34,065 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:34,235 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:34,236 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:57:34,237 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:34,237 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:34,238 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:34,526 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:34,527 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:57:34,528 INFO engine.synchandler.SyncHandler : _sync_end_cb: Called
2007-03-25 22:57:34,528 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:34,528 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:34,529 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:34,762 DEBUG engine.synchandler.SyncHandler : run: calling RAPI sync_pause and sync_resume
2007-03-25 22:57:34,816 DEBUG engine.synchandler.SyncHandler : run: saving partnership state
2007-03-25 22:57:34,819 INFO engine.synchandler.SyncHandler : run: finished synchronization
2007-03-25 22:57:34,820 INFO engine.syncengine.SyncEngine : Synchronized: Emitting Synchronized signal
2007-03-25 22:57:46,471 INFO engine.syncengine.SyncEngine : Synchronize: starting manual sync with partnership P1: id=0x2083a8f, guid="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}", hostname="unholycathedral", name="Linux Desktop", sync_items=[ Calendar, Tasks, Contacts ]
2007-03-25 22:57:46,483 DEBUG engine.synchandler.SyncHandler : run: sending request to device 
<sync type="Interactive" xmlns="http://schemas.microsoft.com/as/2004/core">
	<partner id="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</sync>

2007-03-25 22:57:46,589 DEBUG engine.synchandler.SyncHandler : run: performing synchronization
2007-03-25 22:57:46,615 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:46,616 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:57:46,618 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:46,618 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:46,619 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:46,943 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:46,944 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:57:46,946 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:46,946 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:46,947 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:47,138 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:47,140 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Progress value="0"/>
	</Status>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Total value="100"/>
	</Status>
</SyncStatus>

2007-03-25 22:57:47,143 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:47,143 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:47,144 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:47,146 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:47,147 DEBUG engine.airsync.AirsyncServer : HTTP Request: "OPTIONS /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC HTTP/1.1" 200 -
2007-03-25 22:57:47,148 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:47,416 INFO engine.airsync.AirsyncServer : do_POST: received FolderSync command
2007-03-25 22:57:47,416 DEBUG engine.airsync.AirsyncServer : _read_xml_request: converting request from wbxml
2007-03-25 22:57:47,418 DEBUG engine.airsync.AirsyncServer : _handle_foldersync: request document is
 <?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="http://synce.org/formats/airsync_wm5/folderhierarchy">
	<SyncKey>
		0
	</SyncKey>
</FolderSync>

2007-03-25 22:57:47,431 DEBUG engine.airsync.AirsyncServer : handle_foldersync: response document is 
<?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="FolderHierarchy:">
	<Status>
		1
	</Status>
	<SyncKey>
		{00000000-0000-0000-0000-000000000000}1
	</SyncKey>
	<Changes>
		<Count>
			11
		</Count>
		<Add>
			<ServerId>
				{9E0204F3-6186-163A-273D-094FAEFDEFAC}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Sent Items
			</DisplayName>
			<Type>
				5
			</Type>
		</Add>
		<Add>
			<ServerId>
				{737658FE-FC4A-A1EB-9695-8D46EDC91240}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Outbox
			</DisplayName>
			<Type>
				6
			</Type>
		</Add>
		<Add>
			<ServerId>
				{C8363F64-168C-75AA-7BDA-19F72DA381FE}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Calendar
			</DisplayName>
			<Type>
				8
			</Type>
		</Add>
		<Add>
			<ServerId>
				{8C1B41AD-A628-2572-7832-C9A577CBA4ED}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Tasks
			</DisplayName>
			<Type>
				7
			</Type>
		</Add>
		<Add>
			<ServerId>
				{33396C3F-CC8B-0317-9865-EBD439789BBA}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Notes
			</DisplayName>
			<Type>
				10
			</Type>
		</Add>
		<Add>
			<ServerId>
				{FD792329-BEE3-A346-CB50-7264B3601FB5}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Contacts
			</DisplayName>
			<Type>
				9
			</Type>
		</Add>
		<Add>
			<ServerId>
				{32F5B768-0A62-31E9-E0C9-16C9812FC1B1}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Deleted Items
			</DisplayName>
			<Type>
				4
			</Type>
		</Add>
		<Add>
			<ServerId>
				{AD1CEA07-14AC-4C57-E565-3A1D7A6D9E67}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Inbox
			</DisplayName>
			<Type>
				2
			</Type>
		</Add>
		<Add>
			<ServerId>
				{385BD80C-5E78-488A-E671-8DDC26764DB2}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Drafts
			</DisplayName>
			<Type>
				3
			</Type>
		</Add>
		<Add>
			<ServerId>
				{9CB41DA5-FCCD-149E-6C51-37FE0E79D4C9}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Junk E-mail
			</DisplayName>
			<Type>
				12
			</Type>
		</Add>
		<Add>
			<ServerId>
				{12166AD5-6B3F-933A-F851-5B16C665700A}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Journal
			</DisplayName>
			<Type>
				11
			</Type>
		</Add>
	</Changes>
</FolderSync>

2007-03-25 22:57:47,450 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting response 200 code to client
2007-03-25 22:57:47,450 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC&Cmd=FolderSync HTTP/1.1" 200 -
2007-03-25 22:57:47,451 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting response 200 code to client
2007-03-25 22:57:47,452 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting wbxml (length = 859)
2007-03-25 22:57:47,452 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting wbxml
2007-03-25 22:57:47,498 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:47,499 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Error Body="Synchronization could not be completed. If this condition persists, try deleting and then re-creating the device's sync relationships." Code="80004005" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}" Title="Attention required"/>
</SyncStatus>

2007-03-25 22:57:47,500 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:47,500 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:47,500 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:47,676 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:47,677 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:57:47,677 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:47,677 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:47,678 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:47,941 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:47,943 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:57:47,944 INFO engine.synchandler.SyncHandler : _sync_end_cb: Called
2007-03-25 22:57:47,945 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:47,946 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:47,946 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:48,591 DEBUG engine.synchandler.SyncHandler : run: calling RAPI sync_pause and sync_resume
2007-03-25 22:57:48,645 DEBUG engine.synchandler.SyncHandler : run: saving partnership state
2007-03-25 22:57:48,651 INFO engine.synchandler.SyncHandler : run: finished synchronization
2007-03-25 22:57:48,651 INFO engine.syncengine.SyncEngine : Synchronized: Emitting Synchronized signal
2007-03-25 22:57:49,485 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 0
2007-03-25 22:57:49,485 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 1
2007-03-25 22:57:49,485 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 7
2007-03-25 22:57:49,567 INFO engine.syncengine.SyncEngine : Synchronize: starting manual sync with partnership P1: id=0x2083a8f, guid="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}", hostname="unholycathedral", name="Linux Desktop", sync_items=[ Calendar, Tasks, Contacts ]
2007-03-25 22:57:49,699 DEBUG engine.synchandler.SyncHandler : run: sending request to device 
<sync type="Interactive" xmlns="http://schemas.microsoft.com/as/2004/core">
	<partner id="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</sync>

2007-03-25 22:57:49,758 DEBUG engine.synchandler.SyncHandler : run: performing synchronization
2007-03-25 22:57:49,775 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:49,776 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:57:49,777 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:49,777 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:49,778 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:50,010 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:50,011 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:57:50,011 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:50,012 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:50,012 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:50,165 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:50,166 DEBUG engine.airsync.AirsyncServer : HTTP Request: "OPTIONS /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC HTTP/1.1" 200 -
2007-03-25 22:57:50,166 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:50,277 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:50,279 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Progress value="0"/>
	</Status>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Total value="100"/>
	</Status>
</SyncStatus>

2007-03-25 22:57:50,279 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:50,280 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:50,280 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:50,418 INFO engine.airsync.AirsyncServer : do_POST: received FolderSync command
2007-03-25 22:57:50,419 DEBUG engine.airsync.AirsyncServer : _read_xml_request: converting request from wbxml
2007-03-25 22:57:50,420 DEBUG engine.airsync.AirsyncServer : _handle_foldersync: request document is
 <?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="http://synce.org/formats/airsync_wm5/folderhierarchy">
	<SyncKey>
		0
	</SyncKey>
</FolderSync>

2007-03-25 22:57:50,431 DEBUG engine.airsync.AirsyncServer : handle_foldersync: response document is 
<?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="FolderHierarchy:">
	<Status>
		1
	</Status>
	<SyncKey>
		{00000000-0000-0000-0000-000000000000}1
	</SyncKey>
	<Changes>
		<Count>
			11
		</Count>
		<Add>
			<ServerId>
				{9E0204F3-6186-163A-273D-094FAEFDEFAC}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Sent Items
			</DisplayName>
			<Type>
				5
			</Type>
		</Add>
		<Add>
			<ServerId>
				{737658FE-FC4A-A1EB-9695-8D46EDC91240}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Outbox
			</DisplayName>
			<Type>
				6
			</Type>
		</Add>
		<Add>
			<ServerId>
				{C8363F64-168C-75AA-7BDA-19F72DA381FE}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Calendar
			</DisplayName>
			<Type>
				8
			</Type>
		</Add>
		<Add>
			<ServerId>
				{8C1B41AD-A628-2572-7832-C9A577CBA4ED}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Tasks
			</DisplayName>
			<Type>
				7
			</Type>
		</Add>
		<Add>
			<ServerId>
				{33396C3F-CC8B-0317-9865-EBD439789BBA}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Notes
			</DisplayName>
			<Type>
				10
			</Type>
		</Add>
		<Add>
			<ServerId>
				{FD792329-BEE3-A346-CB50-7264B3601FB5}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Contacts
			</DisplayName>
			<Type>
				9
			</Type>
		</Add>
		<Add>
			<ServerId>
				{32F5B768-0A62-31E9-E0C9-16C9812FC1B1}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Deleted Items
			</DisplayName>
			<Type>
				4
			</Type>
		</Add>
		<Add>
			<ServerId>
				{AD1CEA07-14AC-4C57-E565-3A1D7A6D9E67}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Inbox
			</DisplayName>
			<Type>
				2
			</Type>
		</Add>
		<Add>
			<ServerId>
				{385BD80C-5E78-488A-E671-8DDC26764DB2}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Drafts
			</DisplayName>
			<Type>
				3
			</Type>
		</Add>
		<Add>
			<ServerId>
				{9CB41DA5-FCCD-149E-6C51-37FE0E79D4C9}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Junk E-mail
			</DisplayName>
			<Type>
				12
			</Type>
		</Add>
		<Add>
			<ServerId>
				{12166AD5-6B3F-933A-F851-5B16C665700A}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Journal
			</DisplayName>
			<Type>
				11
			</Type>
		</Add>
	</Changes>
</FolderSync>

2007-03-25 22:57:50,437 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting response 200 code to client
2007-03-25 22:57:50,437 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC&Cmd=FolderSync HTTP/1.1" 200 -
2007-03-25 22:57:50,437 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting response 200 code to client
2007-03-25 22:57:50,439 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting wbxml (length = 859)
2007-03-25 22:57:50,439 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting wbxml
2007-03-25 22:57:50,479 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:50,480 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Error Body="Synchronization could not be completed. If this condition persists, try deleting and then re-creating the device's sync relationships." Code="80004005" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}" Title="Attention required"/>
</SyncStatus>

2007-03-25 22:57:50,481 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:50,481 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:50,482 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:50,640 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:50,641 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:57:50,642 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:50,642 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:50,642 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:50,898 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:57:50,899 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:57:50,900 INFO engine.synchandler.SyncHandler : _sync_end_cb: Called
2007-03-25 22:57:50,900 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:57:50,901 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:57:50,901 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:57:51,758 DEBUG engine.synchandler.SyncHandler : run: calling RAPI sync_pause and sync_resume
2007-03-25 22:57:51,813 DEBUG engine.synchandler.SyncHandler : run: saving partnership state
2007-03-25 22:57:51,819 INFO engine.synchandler.SyncHandler : run: finished synchronization
2007-03-25 22:57:51,819 INFO engine.syncengine.SyncEngine : Synchronized: Emitting Synchronized signal
2007-03-25 22:58:02,646 INFO engine.syncengine.SyncEngine : Synchronize: starting manual sync with partnership P1: id=0x2083a8f, guid="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}", hostname="unholycathedral", name="Linux Desktop", sync_items=[ Calendar, Tasks, Contacts ]
2007-03-25 22:58:02,650 DEBUG engine.synchandler.SyncHandler : run: sending request to device 
<sync type="Interactive" xmlns="http://schemas.microsoft.com/as/2004/core">
	<partner id="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</sync>

2007-03-25 22:58:02,744 DEBUG engine.synchandler.SyncHandler : run: performing synchronization
2007-03-25 22:58:02,767 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:02,767 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:58:02,768 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:02,768 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:02,768 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:03,083 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:03,084 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:58:03,084 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:03,085 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:03,085 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:03,269 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:03,269 DEBUG engine.airsync.AirsyncServer : HTTP Request: "OPTIONS /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC HTTP/1.1" 200 -
2007-03-25 22:58:03,269 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:03,432 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:03,433 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Progress value="0"/>
	</Status>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<Total value="100"/>
	</Status>
	<Status Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}">
		<StatusString type="Status" value="Synchronizing folders"/>
	</Status>
</SyncStatus>

2007-03-25 22:58:03,433 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:03,433 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:03,433 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:03,553 INFO engine.airsync.AirsyncServer : do_POST: received FolderSync command
2007-03-25 22:58:03,553 DEBUG engine.airsync.AirsyncServer : _read_xml_request: converting request from wbxml
2007-03-25 22:58:03,554 DEBUG engine.airsync.AirsyncServer : _handle_foldersync: request document is
 <?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="http://synce.org/formats/airsync_wm5/folderhierarchy">
	<SyncKey>
		0
	</SyncKey>
</FolderSync>

2007-03-25 22:58:03,559 DEBUG engine.airsync.AirsyncServer : handle_foldersync: response document is 
<?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="FolderHierarchy:">
	<Status>
		1
	</Status>
	<SyncKey>
		{00000000-0000-0000-0000-000000000000}1
	</SyncKey>
	<Changes>
		<Count>
			11
		</Count>
		<Add>
			<ServerId>
				{9E0204F3-6186-163A-273D-094FAEFDEFAC}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Sent Items
			</DisplayName>
			<Type>
				5
			</Type>
		</Add>
		<Add>
			<ServerId>
				{737658FE-FC4A-A1EB-9695-8D46EDC91240}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Outbox
			</DisplayName>
			<Type>
				6
			</Type>
		</Add>
		<Add>
			<ServerId>
				{C8363F64-168C-75AA-7BDA-19F72DA381FE}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Calendar
			</DisplayName>
			<Type>
				8
			</Type>
		</Add>
		<Add>
			<ServerId>
				{8C1B41AD-A628-2572-7832-C9A577CBA4ED}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Tasks
			</DisplayName>
			<Type>
				7
			</Type>
		</Add>
		<Add>
			<ServerId>
				{33396C3F-CC8B-0317-9865-EBD439789BBA}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Notes
			</DisplayName>
			<Type>
				10
			</Type>
		</Add>
		<Add>
			<ServerId>
				{FD792329-BEE3-A346-CB50-7264B3601FB5}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Contacts
			</DisplayName>
			<Type>
				9
			</Type>
		</Add>
		<Add>
			<ServerId>
				{32F5B768-0A62-31E9-E0C9-16C9812FC1B1}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Deleted Items
			</DisplayName>
			<Type>
				4
			</Type>
		</Add>
		<Add>
			<ServerId>
				{AD1CEA07-14AC-4C57-E565-3A1D7A6D9E67}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Inbox
			</DisplayName>
			<Type>
				2
			</Type>
		</Add>
		<Add>
			<ServerId>
				{385BD80C-5E78-488A-E671-8DDC26764DB2}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Drafts
			</DisplayName>
			<Type>
				3
			</Type>
		</Add>
		<Add>
			<ServerId>
				{9CB41DA5-FCCD-149E-6C51-37FE0E79D4C9}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Junk E-mail
			</DisplayName>
			<Type>
				12
			</Type>
		</Add>
		<Add>
			<ServerId>
				{12166AD5-6B3F-933A-F851-5B16C665700A}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Journal
			</DisplayName>
			<Type>
				11
			</Type>
		</Add>
	</Changes>
</FolderSync>

2007-03-25 22:58:03,562 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting response 200 code to client
2007-03-25 22:58:03,562 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC&Cmd=FolderSync HTTP/1.1" 200 -
2007-03-25 22:58:03,562 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting response 200 code to client
2007-03-25 22:58:03,563 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting wbxml (length = 859)
2007-03-25 22:58:03,563 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting wbxml
2007-03-25 22:58:03,605 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:03,606 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Error Body="Synchronization could not be completed. If this condition persists, try deleting and then re-creating the device's sync relationships." Code="80004005" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}" Title="Attention required"/>
</SyncStatus>

2007-03-25 22:58:03,606 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:03,607 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:03,607 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:03,776 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:03,777 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:58:03,777 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:03,778 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:03,778 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:04,016 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:04,017 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:58:04,017 INFO engine.synchandler.SyncHandler : _sync_end_cb: Called
2007-03-25 22:58:04,018 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:04,018 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:04,019 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:04,744 DEBUG engine.synchandler.SyncHandler : run: calling RAPI sync_pause and sync_resume
2007-03-25 22:58:04,798 DEBUG engine.synchandler.SyncHandler : run: saving partnership state
2007-03-25 22:58:04,802 INFO engine.synchandler.SyncHandler : run: finished synchronization
2007-03-25 22:58:04,803 INFO engine.syncengine.SyncEngine : Synchronized: Emitting Synchronized signal
2007-03-25 22:58:05,652 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 0
2007-03-25 22:58:05,652 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 1
2007-03-25 22:58:05,652 DEBUG engine.syncengine.SyncEngine : GetRemoteChanges: getting changes for items of type 7
2007-03-25 22:58:05,694 INFO engine.syncengine.SyncEngine : Synchronize: starting manual sync with partnership P1: id=0x2083a8f, guid="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}", hostname="unholycathedral", name="Linux Desktop", sync_items=[ Calendar, Tasks, Contacts ]
2007-03-25 22:58:05,703 DEBUG engine.synchandler.SyncHandler : run: sending request to device 
<sync type="Interactive" xmlns="http://schemas.microsoft.com/as/2004/core">
	<partner id="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</sync>

2007-03-25 22:58:05,770 DEBUG engine.synchandler.SyncHandler : run: performing synchronization
2007-03-25 22:58:05,787 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:05,789 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:58:05,789 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:05,789 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:05,790 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:06,019 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:06,020 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncBegin Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:58:06,021 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:06,021 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:06,022 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:06,167 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:06,168 DEBUG engine.airsync.AirsyncServer : HTTP Request: "OPTIONS /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC HTTP/1.1" 200 -
2007-03-25 22:58:06,168 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:06,291 INFO engine.airsync.AirsyncServer : do_POST: received FolderSync command
2007-03-25 22:58:06,291 DEBUG engine.airsync.AirsyncServer : _read_xml_request: converting request from wbxml
2007-03-25 22:58:06,292 DEBUG engine.airsync.AirsyncServer : _handle_foldersync: request document is
 <?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="http://synce.org/formats/airsync_wm5/folderhierarchy">
	<SyncKey>
		0
	</SyncKey>
</FolderSync>

2007-03-25 22:58:06,302 DEBUG engine.airsync.AirsyncServer : handle_foldersync: response document is 
<?xml version="1.0" ?>
<!DOCTYPE AirSync
  PUBLIC '-//AIRSYNC//DTD AirSync//EN'
  'http://www.microsoft.com/'>
<FolderSync xmlns="FolderHierarchy:">
	<Status>
		1
	</Status>
	<SyncKey>
		{00000000-0000-0000-0000-000000000000}1
	</SyncKey>
	<Changes>
		<Count>
			11
		</Count>
		<Add>
			<ServerId>
				{9E0204F3-6186-163A-273D-094FAEFDEFAC}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Sent Items
			</DisplayName>
			<Type>
				5
			</Type>
		</Add>
		<Add>
			<ServerId>
				{737658FE-FC4A-A1EB-9695-8D46EDC91240}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Outbox
			</DisplayName>
			<Type>
				6
			</Type>
		</Add>
		<Add>
			<ServerId>
				{C8363F64-168C-75AA-7BDA-19F72DA381FE}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Calendar
			</DisplayName>
			<Type>
				8
			</Type>
		</Add>
		<Add>
			<ServerId>
				{8C1B41AD-A628-2572-7832-C9A577CBA4ED}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Tasks
			</DisplayName>
			<Type>
				7
			</Type>
		</Add>
		<Add>
			<ServerId>
				{33396C3F-CC8B-0317-9865-EBD439789BBA}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Notes
			</DisplayName>
			<Type>
				10
			</Type>
		</Add>
		<Add>
			<ServerId>
				{FD792329-BEE3-A346-CB50-7264B3601FB5}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Contacts
			</DisplayName>
			<Type>
				9
			</Type>
		</Add>
		<Add>
			<ServerId>
				{32F5B768-0A62-31E9-E0C9-16C9812FC1B1}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Deleted Items
			</DisplayName>
			<Type>
				4
			</Type>
		</Add>
		<Add>
			<ServerId>
				{AD1CEA07-14AC-4C57-E565-3A1D7A6D9E67}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Inbox
			</DisplayName>
			<Type>
				2
			</Type>
		</Add>
		<Add>
			<ServerId>
				{385BD80C-5E78-488A-E671-8DDC26764DB2}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Drafts
			</DisplayName>
			<Type>
				3
			</Type>
		</Add>
		<Add>
			<ServerId>
				{9CB41DA5-FCCD-149E-6C51-37FE0E79D4C9}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Junk E-mail
			</DisplayName>
			<Type>
				12
			</Type>
		</Add>
		<Add>
			<ServerId>
				{12166AD5-6B3F-933A-F851-5B16C665700A}
			</ServerId>
			<ParentId>
				0
			</ParentId>
			<DisplayName>
				Journal
			</DisplayName>
			<Type>
				11
			</Type>
		</Add>
	</Changes>
</FolderSync>

2007-03-25 22:58:06,307 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting response 200 code to client
2007-03-25 22:58:06,307 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync?User=DEFAULT&DeviceId=A85B5E59B1D31970C8FDCC69E10531EE&DeviceType=PocketPC&Cmd=FolderSync HTTP/1.1" 200 -
2007-03-25 22:58:06,308 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting response 200 code to client
2007-03-25 22:58:06,309 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Emitting wbxml (length = 859)
2007-03-25 22:58:06,309 DEBUG engine.airsync.AirsyncServer : _send_wbxml_response: Finished emitting wbxml
2007-03-25 22:58:06,353 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:06,355 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<Error Body="Synchronization could not be completed. If this condition persists, try deleting and then re-creating the device's sync relationships." Code="80004005" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}" Title="Attention required"/>
</SyncStatus>

2007-03-25 22:58:06,355 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:06,355 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:06,356 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:06,522 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:06,523 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner="{02AC3DF2-5962-9645-3441-9E04D09EFC3C}"/>
</SyncStatus>

2007-03-25 22:58:06,524 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:06,524 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:06,525 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:06,766 INFO engine.airsync.AirsyncServer : do_POST: received Status command
2007-03-25 22:58:06,767 DEBUG engine.airsync.AirsyncServer : _handle_status: request document is 
<?xml version="1.0" ?>
<SyncStatus>
	<SyncEnd Datatype="" Partner=""/>
</SyncStatus>

2007-03-25 22:58:06,768 INFO engine.synchandler.SyncHandler : _sync_end_cb: Called
2007-03-25 22:58:06,768 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Emitting response 200 code to client
2007-03-25 22:58:06,769 DEBUG engine.airsync.AirsyncServer : HTTP Request: "POST /Microsoft-Server-ActiveSync/SyncStat.dll HTTP/1.1" 200 -
2007-03-25 22:58:06,769 DEBUG engine.airsync.AirsyncServer : _send_empty_response: Finished emitting response 200 code to client
2007-03-25 22:58:06,772 DEBUG engine.synchandler.SyncHandler : run: calling RAPI sync_pause and sync_resume
2007-03-25 22:58:06,926 DEBUG engine.synchandler.SyncHandler : run: saving partnership state
2007-03-25 22:58:06,931 INFO engine.synchandler.SyncHandler : run: finished synchronization
2007-03-25 22:58:06,931 INFO engine.syncengine.SyncEngine : Synchronized: Emitting Synchronized signal