Hello everybody,
I would be grateful if anybody could assist me in overcoming this problem:
After I start to communicate with an I2C device, the ActiveSync connection will be closed after a reproducible duration.
I use a PicoCOM2 with a custom-made mainboard, connected to WindowsXP using ActiveSync 4.5.
The I2C driver is activated (with Debug=1 setting), one device (MCP23017 PortExpander) is connected to the bus and works normally.
Serial debug shows:
- Microsoft Windows CE Ethernet Bootloader Common Library Version 1.1 Built Nov 23 2010 11:16:01
- Microsoft Windows CE Bootloader for PICOCOM2 Built Dec 22 2010
- Portions copyright (c) 2007 F&S Elektronik Systeme GmbH
- Boot Loader, Version 1.7
- NBoot, Version C215
- 32 MB Ram
- INFO:OALLogSetZones: dpCurSettings.ulZoneMask: 0xb
- Board Revision: 1.10
- System ready!
- Preparing for download...
- Press >S< to step into monitor...
- AUTO BOOT enabled
- +ReadKernelRegionFromNandFlash
- Image Signature in Flash Memory found (dwSig=0x43454345)
- TOC pointer=0x810385B0
- ROMHDR (cTOC = 0x00f265b0) ---------------------
- DLL First : 0x4001c001
- DLL Last : 0x40a8c0a0
- Physical First : 0x80112000
- Physical Last : 0x8103a494
- Num Modules : 185
- RAM Start : 0x81040000
- RAM Free : 0x81058000
- RAM End : 0x82012000
- Num Copy Entries : 2
- Copy Entries Offset : 0x808f8e88
- Prof Symbol Length : 0x00000000
- Prof Symbol Offset : 0x00000000
- Num Files : 68
- Kernel Flags : 0x00000000
- FileSys RAM Percent : 0x20202020
- Driver Glob Start : 0x00000000
- Driver Glob Length : 0x00000000
- CPU : 0x01c2
- MiscFlags : 0x0002
- Extensions : 0x80113140
- Tracking Mem Start : 0x00000000
- Tracking Mem Length : 0x00000000
- Kernel (15521kB) read from flash disk started finished in 5881 milliseconds
- Kernel read from NAND
- INFO: OEMLaunch: Jumping to Physical Address 0x20113000h (Virtual Address 0x0h)...
- Windows CE Kernel for ARM (Thumb Enabled) Built on Aug 4 2010 at 14:23:58
- PicoCOM2 V1.16 - Firmware Init
- Copyright (c) 2008 F&S Elektronik Systeme GmbH
- Build: Jan 18 2011/09:27:33
- INFO:OALLogSetZones: dpCurSettings.ulZoneMask: 0xb
- INFO:OALLogSetZones: dpCurSettings.ulZoneMask: 0x400b
- OEMInit: SDRAM = 32 MB
- DCache: 128 sets, 4 ways, 32 line size, 16384 size
- ICache: 128 sets, 4 ways, 32 line size, 16384 size
- OEM: Force clean boot.
- OALTimerInit
- OALKitlStart
- Firmware Init Done.
- OEM: Watchdog ENABLED
- Handle Event:0xa00003, sysintr=0x10OEM: Not clearing storage
- OEM: Not cleaning system hive
- OEM: Not cleaning user profiles
- OEM: Not cleaning system hive
- PM-NETDCU: STARTED
- NET: Version V1.5, ActiveKey = Comm\ETHNETA
- USBFN: Version 1.2, ActiveKey = Drivers\Active\07
- ERROR: OALIoCtlHalGetDeviceInfo: Device doesn't support IOCTL_HAL_GET_DEVICE_INFO::SPI_GETUUID
- BCS: Version 1.0, ActiveKey = Drivers\Active\22
- NI2C: Version 1.13, ActiveKey = Drivers\Active\23
- NI2C: Installed ISR handler, Dll = 'pc2_twiisr.dll', Handler = 'ISRHandler', Irq = 13, SysIntr = 0x15
- NI2C: Interrupt service thread ID: 0x03aa0002
- NI2C: TWI_CWGR = 0x00029494
- DIO: Version 3.3, ActiveKey = Drivers\Active\24
- SDHC:Version 1.2, ActiveKey = Drivers\Active\25
- SDHC:Card state change detected!
- DDGPE:Read registry settings from Drivers\Display\LCD
- Display-Mode: 150, Name Glyn G-ET035009DH6
- DDGPE:Width: 320 Height: 240 Bpp: 16
- DDGPE:InitializeDisplayHardware Complete
- EnableTouchscreen PASSED
- NDCUCFG V: 042 started. Platform: PicoCOM2
- CheckAutoStart: Version 1.4, LaunchNum = 100
- CreateFile() failed -> ERROR COM1:
- NET: cable attached
- USBFN:C_USB_DEVICE::ThreadRun: : Attach Detected
ActiveSync is connected (taskbar icon turns into green), these are the ActiveSync log files
- -----------------------------------------------------------------------
- 11:32:35 ActiveSync verbunden (Icon in PC-Taskleiste wird grün)
- -----------------------------------------------------------------------
- WCESCOMM.LOG:
- -----------------------------------------------------------------------
- 03/02/2011 11:32:34.941 - Windows CE Services (4.5.0) Communication Logging.
- 03/02/2011 11:32:34.941 - Logging file auto-purge after a successful device connection.
- 03/02/2011 11:32:34.941 -
- 03/02/2011 11:32:35.066 - CesProxy: Accept on port 990, IsWinsock 1, hResult 0
- 03/02/2011 11:32:35.066 - TCP: ....S., 192.168.55.100(1033) => 192.168.55.101(990) Seq=9385890-9385890 Ack=0 Win=8192 Len=44
- 03/02/2011 11:32:35.082 - TCP: .A..S., 192.168.55.101(990) => 192.168.55.100(1033) Seq=2690367-2690367 Ack=9385891 Win=33580 Len=44
- 03/02/2011 11:32:36.019 - CesProxy: Accept on port 990, IsWinsock 1, hResult 0
- 03/02/2011 11:32:36.019 - TCP: ....S., 192.168.55.100(1034) => 192.168.55.101(990) Seq=9386843-9386843 Ack=0 Win=8192 Len=44
- 03/02/2011 11:32:36.019 - TCP: .A..S., 192.168.55.101(990) => 192.168.55.100(1034) Seq=2954334-2954334 Ack=9386844 Win=33580 Len=44
- 03/02/2011 11:32:36.050 - CesProxy: recv failed on Win socket 990, err = 10054
- 03/02/2011 11:32:36.066 - CesProxy: Close Win socket 990
- 03/02/2011 11:32:36.066 - CesProxy: Close PPP socket 990
- 03/02/2011 11:32:36.066 - TCP: ...R.., 192.168.55.100(1033) => 192.168.55.101(990) Seq=9386081-9386081 Ack=2954355 Win=0 Len=40
- 03/02/2011 11:32:36.082 - CesProxy: recv failed on PPP socket 990, err = 10004
- 03/02/2011 11:32:36.097 - TCP: .A.R.., 192.168.55.101(990) => 192.168.55.100(1034) Seq=2954371-2954371 Ack=9387364 Win=0 Len=40
- 03/02/2011 11:32:36.097 - CesProxy: recv failed on PPP socket 990, err = 10054
- 03/02/2011 11:32:36.097 - CesProxy: Close Win socket 990
- 03/02/2011 11:32:36.113 - CesProxy: recv failed on Win socket 990, err = 10053
- 03/02/2011 11:32:36.113 - CesProxy: Close PPP socket 990
- -----------------------------------------------------------------------
- WCESMgr.log:
- -----------------------------------------------------------------------
- 03/02/2011 11:32:35.457 Creating new partnership for device 0x0 (PicoCOM2, PicoCOM2).
- 03/02/2011 11:32:35.457 Creating a guest connection for device of type 'PicoCOM2'
- 03/02/2011 11:32:35.597 **************** Logging Started ****************
- 03/02/2011 11:32:35.597 Process G:\Programme\Microsoft ActiveSync\WCESMgr.exe p(2616)
- 03/02/2011 11:32:35.597 ActiveSync second instance started, Cmd line: '/onconnect'
- 03/02/2011 11:32:35.597 ActiveSync second instance exiting
- 03/02/2011 11:32:35.597 **************** Logging Stopped ****************
- 03/02/2011 11:32:35.457 p(3300) t(1912) TraceToFile -> ERROR in CPartnerReg::Initialize : hr = 0x8000ffff - syncmgr.cpp(5726)
- 03/02/2011 11:32:35.457 p(3300) t(1912) TraceToFile -> ERROR in CPartnerReg::CreatePartnerReg : hr = 0x8000ffff - syncmgr.cpp(5642)
- 03/02/2011 11:32:35.457 p(3300) t(1912) TraceToFile -> ERROR in CProfiles::SetDeviceDataFolder : hr = 0x80070057 - syncmgr.cpp(5280)
- 03/02/2011 11:32:35.457 p(3300) t(1912) TraceToFile -> ERROR in CDevInfo::CreateGuestProfile : hr = 0x80070057 - partner.cpp(1579)
- 03/02/2011 11:32:35.457 p(3300) t(1696) TraceToFile -> ERROR in AllowMultiHomingIfCapable : hr = 0x80072746 - partner.cpp(1906)
Now I start an application that communicates with the port expander using CreateFile/WriteFile/ReadFile on the I2C driver. Serial debug:
(The "USBFN:C_USB_DEVICE" is a USB flash drive.) Exactly 106 seconds later the ActiveSync connection is closed down, the taskbar icon turns grey.ActiveSync log files show:
- -----------------------------------------------------------------------
- WCESCOMM.LOG:
- -----------------------------------------------------------------------
- 03/02/2011 11:34:44.948 - Device timed out, timeout 100, iret 0, Connected 1, RLSD 1. Error 0
- 03/02/2011 11:34:44.948 - CesProxy: recv failed on Win socket 5679, err = 10054
- 03/02/2011 11:34:44.948 - Connection: Prep for a new socket connection.
- 03/02/2011 11:34:44.948 - CesProxy: Close PPP socket 5679
- 03/02/2011 11:34:45.058 - CesProxy: Close Win socket 5679
- -----------------------------------------------------------------------
- WCESMgr.log:
- -----------------------------------------------------------------------
- 03/02/2011 11:34:45.105 p(3300) t(1912) TraceToFile -> ERROR in CPartnerReg::Initialize : hr = 0x8000ffff - syncmgr.cpp(5726)
- 03/02/2011 11:34:45.105 p(3300) t(1912) TraceToFile -> ERROR in CPartnerReg::CreatePartnerReg : hr = 0x8000ffff - syncmgr.cpp(5642)
- 03/02/2011 11:34:45.105 p(3300) t(1912) TraceToFile -> ERROR in CProfiles::GetDeviceDataFolder : hr = 0x80070057 - syncmgr.cpp(4982)
- 03/02/2011 11:34:45.105 p(3300) t(1912) TraceToFile -> ERROR in CSyncMgrApp::DeleteProfileData2 : hr = 0x80070057 - syncmgr.cpp(3925)
Neither unplugging and replugging the USB cable nor NDCUCFG:Reboot will restore the connection, a cold reboot is required.
--
I tried the same setup with a PicoCOM starter kit and the same PicoCOM module. The only difference is that in this case there is no device connected over I2C.
When I start my application that tries to connect the I2C device, serial debug output is
I observe that the line
is missing, instead
is issued multiple times, probably due to the missing I2C device. (Both setups can't be compared I'm afraid.)
Can you explain this behaviour? The constant time interval of 106 s before ActiveSync is disconnected (tried many times) leads to the assumption a timeout might be expired. But which? of what device or component?
The line containing
QuoteDevice timed out, timeout 100, iret 0, Connected 1, RLSD 1. Error 0
in WCESCOMM.LOG might give a hint. There is no ethernet connection.
Any help I will appreciate as the short ActiveSync life time is very annoying. Debugging an application from VisualStudio is impossible.