Hi,
Some months ago I struggled with a memory leak I had in my image when
doing suspend/resume. After a break, now I started debugging this
again.
My system is a Samsung S3C2410 with CE 5.0.
First, when not having usb host controller in the image, there is no
leak. Now, I think I might be on to something about the leak related
to when ohci2 unloads/loads the usb client drivers after resume. It
seems ohci2 can't close some of the pipes, and free related memory
(see >>>>>>> in the debug output below).
The platform have a USB hub (tusb2046b). When resuming I get the
following debug output related to the usb unload/load (I have a USB
mouse connected):
1895168 PID:5fa369a TID:e5df876a 0x85deb400: +CHub(Root tier
0)::HandleDetach
1895170 PID:5fa369a TID:e5df876a 0x85deb400: CHub(Root tier
0)::HandleDetach - status change thread closed in 2 ms
1895170 PID:5fa369a TID:e5df876a 0x85deb400: +CHub(External tier
1)::HandleDetach
1895174 PID:5fa369a TID:85e09666 0x85d9b690: ndisMResetCompleteStage2:
Internal reset
1895177 PID:5fa369a TID:a5d9bf5e 0x85d68940: SDMemory:
+SlotEventCallBack - 1
1895177 PID:5fa369a TID:a5d9bf5e 0x85d68940: SDMemory: -
SlotEventCallBack
1895180 PID:5fa369a TID:a5d9bf5e 0x85d68940: SDMemory: +SMC_Deinit
1895183 PID:5fa369a TID:e5df876a 0x85deb400: CHub(External tier
1)::HandleDetach - status change thread closed in 12 ms
1895183 PID:5fa369a TID:e5df876a 0x85deb400:
+CQueuedPipe(Control)::ClosePipe
>>>>>>> 1895198 PID:5fa369a TID:e5df876a 0x85deb400: !CQueuedPipe(Control)::ClosePipe 00289e20 doesn't exist!
1895198 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 83488 bytes; TotalSize = 94208 bytes
1895199 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE6C20, VA = 0x00289C20, Size = 512, Desc = IssueTransfer TDs
1895199 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 84000 bytes; TotalSize = 94208 bytes
1895199 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 84000 bytes; TotalSize = 94208 bytes
1895200 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE6420, VA = 0x00289420, Size = 2048, Desc = IssueTransfer TDs
1895200 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 86048 bytes; TotalSize = 94208 bytes
1895201 PID:5fa369a TID:e5df876a 0x85deb400: -
CQueuedPipe(Control)::ClosePipe
1895201 PID:5fa369a TID:e5df876a 0x85deb400:
+CQueuedPipe(Interrupt)::ClosePipe
1895205 PID:5fa369a TID:c5b3dc56 0x85b11c60: +IPNotifyClientsIPEvent
1895206 PID:5fa369a TID:c5b3dc56 0x85b11c60: IPNotifyClientsIPEvent:
replumb stack
1895211 PID:5fa369a TID:e5e99bb6 0x85e68aac: +OpenIFConfig(Comm
\VMINI1\Parms\TCPIP Handle 0x621FD90)
1895213 PID:5fa369a TID:e5e99bb6 0x85e68aac: Opened registry info for
Comm\VMINI1\Parms\TCPIP
1895213 PID:5fa369a TID:e5e99bb6 0x85e68aac: -OpenIFConfig(Comm
\VMINI1\Parms\TCPIP *Handle 0x621FD90, BOOL Ret: 1)
1895214 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 86048 bytes; TotalSize = 94208 bytes
1895215 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE7680, VA = 0x0028A680, Size = 32, Desc = OpenPipe ED
1895215 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 86080 bytes; TotalSize = 94208 bytes
1895215 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 86080 bytes; TotalSize = 94208 bytes
1895216 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE7640, VA = 0x0028A640, Size = 64, Desc = IssueTransfer TDs
1895216 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 86144 bytes; TotalSize = 94208 bytes
1895217 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 86144 bytes; TotalSize = 94208 bytes
1895217 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE6E40, VA = 0x00289E40, Size = 2048, Desc = IssueTransfer TDs
1895217 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 88192 bytes; TotalSize = 94208 bytes
1895218 PID:5fa369a TID:e5df876a 0x85deb400: -
CQueuedPipe(Interrupt)::ClosePipe
1895218 PID:5fa369a TID:e5df876a 0x85deb400: +CFunction(tier
2)::HandleDetach
1895218 PID:5fa369a TID:e5df876a 0x85deb400:
+CQueuedPipe(Control)::ClosePipe
1895223 PID:5fa369a TID:e5e99bb6 0x85e68aac:
+GetGeneralIFConfig(ConfigInfo 0x621FD24 Handle 0xC92A0)
1895225 PID:5fa369a TID:e5e99bb6 0x85e68aac:
GetGeneralIFConfig:Unable to read DefaultGateway value!
1895226 PID:5fa369a TID:e5e99bb6 0x85e68aac:
GetGeneralIFConfig:Unable to read DNS value!
1895227 PID:5fa369a TID:e5e99bb6 0x85e68aac:
GetGeneralIFConfig:Unable to read WINS value!
1895228 PID:5fa369a TID:e5e99bb6 0x85e68aac:
GetGeneralIFConfig:Unable to read UseZeroBroadcast value!
All-nets broadcasts will be addressed to 255.255.255.255
1895230 PID:5fa369a TID:e5e99bb6 0x85e68aac: -
GetGeneralIFConfig(ConfigInfo 0x621FD24 Handle 0xC92A0 Ret: TRUE)
1895230 PID:5fa369a TID:e5e99bb6 0x85e68aac: +GetIFAddrList(NumAddr*
0x621FD98 Handle 0xC92A0)
1895231 PID:5fa369a TID:e5e99bb6 0x85e68aac: *CloseIFConfig(Handle
0xC92A0)
>>>>>>> 1895232 PID:5fa369a TID:e5df876a 0x85deb400: !CQueuedPipe(Control)::ClosePipe 0028b0a0 doesn't exist!
1895233 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 88192 bytes; TotalSize = 94208 bytes
1895233 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE7EA0, VA = 0x0028AEA0, Size = 512, Desc = IssueTransfer TDs
1895233 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 88704 bytes; TotalSize = 94208 bytes
1895234 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 88704 bytes; TotalSize = 94208 bytes
1895234 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE76A0, VA = 0x0028A6A0, Size = 2048, Desc = IssueTransfer TDs
1895234 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 90752 bytes; TotalSize = 94208 bytes
1895235 PID:5fa369a TID:e5df876a 0x85deb400: -
CQueuedPipe(Control)::ClosePipe
1895235 PID:5fa369a TID:e5df876a 0x85deb400:
+CQueuedPipe(Interrupt)::ClosePipe
1895238 PID:5fa369a TID:c5b3dc56 0x85b11c60: IPNotifyClientsIPEvent:
PendingIPGetIPEventRequest 2caae0
1895238 PID:5fa369a TID:c5b3dc56 0x85b11c60: IPNotifyClientsIPEvent:
SetEvent
1895238 PID:5fa369a TID:c5b3dc56 0x85b11c60: IPNotifyClientsIPEvent:
remove old
1895240 PID:5fa369a TID:c5b3dc56 0x85b11c60: IPNotifyClientsIPEvent:
remove old
1895245 PID:5fa369a TID:c5b3dc56 0x85b11c60: +OpenIFConfig(Comm
\VMINI1\Parms\TCPIP Handle 0xC0FDEF0)
1895247 PID:5fa369a TID:c5b3dc56 0x85b11c60: Opened registry info for
Comm\VMINI1\Parms\TCPIP
1895247 PID:5fa369a TID:c5b3dc56 0x85b11c60: -OpenIFConfig(Comm
\VMINI1\Parms\TCPIP *Handle 0xC0FDEF0, BOOL Ret: 1)
1895249 PID:5fa369a TID:c5b3dc56 0x85b11c60: *CloseIFConfig(Handle
0xC92A0)
1895259 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 90752 bytes; TotalSize = 94208 bytes
1895259 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE89C0, VA = 0x0028B9C0, Size = 32, Desc = OpenPipe ED
1895260 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 90784 bytes; TotalSize = 94208 bytes
1895260 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 90784 bytes; TotalSize = 94208 bytes
1895261 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE88C0, VA = 0x0028B8C0, Size = 256, Desc = IssueTransfer TDs
1895261 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 91040 bytes; TotalSize = 94208 bytes
1895261 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 91040 bytes; TotalSize = 94208 bytes
1895262 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem FreeMemory : PA
= 0x31CE80C0, VA = 0x0028B0C0, Size = 2048, Desc = IssueTransfer TDs
1895262 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 93088 bytes; TotalSize = 94208 bytes
1895262 PID:5fa369a TID:e5df876a 0x85deb400: -
CQueuedPipe(Interrupt)::ClosePipe
1895263 PID:5fa369a TID:e5df876a 0x85deb400: +USBD:ClosePipe, hPipe:
0x2BB840
1895263 PID:5fa369a TID:e5df876a 0x85deb400: -USBD:ClosePipe
1895263 PID:5fa369a TID:e5df876a 0x85deb400: +USBD:ClosePipe, hPipe:
0x2B82B0
1895264 PID:5fa369a TID:e5df876a 0x85deb400: -USBD:ClosePipe
1895284 PID:5fa369a TID:e5df876a 0x85deb400: <<< Unloading module
mouhid.dll at address 0x033F0000-0x033F7000 (RW data at
0x01F5A000-0x01F5A4A8)
Unloaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\MOUHID.DLL'
1895311 PID:5fa369a TID:45eed6aa 0x85e00af0: StartInterruptTransfer:
IssueInterruptTransfer failed
1895318 PID:5fa369a TID:e5df876a 0x85deb400: <<< Unloading module
usbhid.dll at address 0x034D0000-0x034E6000 (RW data at
0x01F6E000-0x01F6E540)
Unloaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\USBHID.DLL'
1895319 PID:5fa369a TID:e5df876a 0x85deb400: <<< Unloading module
hidparse.dll at address 0x03420000-0x03435000 (RW data at
0x01F60000-0x01F60474)
Unloaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\HIDPARSE.DLL'
1895322 PID:5fa369a TID:e5df876a 0x85deb400: -CFunction(tier
2)::HandleDetach
1895323 PID:5fa369a TID:e5df876a 0x85deb400: -CHub(External tier
1)::HandleDetach
1895323 PID:5fa369a TID:e5df876a 0x85deb400: -CHub(Root tier
0)::HandleDetach
1895324 PID:5fa369a TID:e5df876a 0x85deb400: +CDevice::DeInitialize
1895325 PID:5fa369a TID:e5df876a 0x85deb400: <<< Unloading module
usbd.dll at address 0x034F0000-0x03501000 (RW data at
0x01F70000-0x01F705D0)
Unloaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\USBD.DLL'
1895327 PID:5fa369a TID:e5df876a 0x85deb400: -CDevice::DeInitialize
1895329 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 94208 bytes; TotalSize = 94208 bytes
1895329 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 32768 bytes; TotalSize = 32768 bytes
1895330 PID:5fa369a TID:e5df876a 0x85deb400: +COhcd::Initialize. Entry
1895330 PID:5fa369a TID:e5df876a 0x85deb400:
+CDeviceGlobal::Initialize
1895348 PID:5fa369a TID:e5df876a 0x85deb400: >>> Loading module
usbd.dll at address 0x034F0000-0x03501000 (RW data at
0x01F70000-0x01F705D0)
Loaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\USBD.DLL'
1895414 PID:5fa369a TID:e5df876a 0x85deb400: USBD: DLL attach
1895415 PID:5fa369a TID:e5df876a 0x85deb400: +USBD:HcdAttach, hcd:
0x5DC80
1895415 PID:5fa369a TID:e5df876a 0x85deb400: -CDevice::Initialize,
success!
1895415 PID:5fa369a TID:e5df876a 0x85deb400: +CHW::Initialize
base=0x270000, intr=0x11
1895416 PID:5fa369a TID:e5df876a 0x85deb400: -CHW::Initialize,
success!
1895416 PID:5fa369a TID:e5df876a 0x85deb400: +CPipe::Initialize
1895417 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 94208 bytes; TotalSize = 94208 bytes
1895417 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem AllocateMemory :
PA = 0x31CE6000, VA = 0x00289000, Size = 1056, Desc = Permanent EDs
1895417 PID:5fa369a TID:e5df876a 0x85deb400: CPhysMem ValidateHeaps :
FreeSize = 93152 bytes; TotalSize = 94208 bytes
1895419 PID:5fa369a TID:e5df876a 0x85deb400: -CPipe::Initialize.
Success!
1895420 PID:5fa369a TID:e5df876a 0x85deb400:
+CHW::EnterOperationalState
1895420 PID:5fa369a TID:e5df876a 0x85deb400: -
CHW::EnterOperationalState
1895420 PID:5fa369a TID:e5df876a 0x85deb400: -COhcd::Initialize.
Success!!
1895444 PID:25d4c06e TID:c5b3dc56 0x85b11c60: Back from
PowerOffSystem.
1895479 PID:e5c10402 TID:e5d9355e 0x85dadd30: [NOTIFY]
HandleSystemEvent 9 none
1895484 PID:e5c10402 TID:25f94db6 0x85f94570: [NOTIFY]
HandleSystemEvent 7 /REMOVE DSK2:
1895488 PID:e5c10402 TID:25f94db6 0x85f94570: [NOTIFY]
HandleSystemEvent 7 /REMOVE HID1:
1895500 PID:5fa369a TID:a5d9bf5e 0x85d68940: SDMemory: -SMC_Deinit
1895501 PID:5fa369a TID:a5d9bf5e 0x85d68940: <<< Unloading module
sdmemory.dll at address 0x03510000-0x03524000 (RW data at
0x01F72000-0x01F72594)
Unloaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\SDMEMORY.DLL'
1895505 PID:5fa369a TID:a5d9bf5e 0x85d68940: SDGetClientFunctions:
+Init
1895505 PID:5fa369a TID:a5d9bf5e 0x85d68940: SDGetClientFunctions: -
Init
1895508 PID:5fa369a TID:a5dabfae 0x85da8000: ************DHCP MEDIA
STATUS************
1895508 PID:5fa369a TID:a5dabfae 0x85da8000: SeqNo: 3
1895508 PID:5fa369a TID:a5dabfae 0x85da8000: MediaStatus: 11024
1895509 PID:5fa369a TID:a5dabfae 0x85da8000: Context: 2 - 3
1895509 PID:5fa369a TID:a5dabfae 0x85da8000: AdapterName: VMINI1
1895510 PID:5fa369a TID:a5dabfae 0x85da8000: Media Status is:
IP_MEDIA_CONNECT
1895514 PID:5fa369a TID:a5dabfae 0x85da8000: IPDispatchDeviceControl
returned Status 103
1895524 PID:e5c10402 TID:45befde2 0x85befba0: [NOTIFY]
HandleSystemEvent 11 none
1895530 PID:5fa369a TID:e5e99bb6 0x85e68aac: VMini:: Detected DHCP
[REQUEST]
1895531 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::HubStatusChangeThread - port 1, change = 0x0001, status = 0x0101
1895537 PID:5fa369a TID:e5e99bb6 0x85e68aac: SetDhcpConfig: set
IPAddr 280D15AC
1895542 PID:5fa369a TID:e5e99bb6 0x85e68aac: SetDhcpConfig: set
LeaseObtained 1bd179c 5256d000
1895545 PID:5fa369a TID:e5e99bb6 0x85e68aac: SetDhcpConfig: T1 34bc0
T2 5c490 Lease 69780
1895550 PID:5fa369a TID:e5e99bb6 0x85e68aac: DHCP:EventMediaConnect:
Successful renewal
1895632 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::HubStatusChangeThread - device attached on port 1
1895632 PID:5fa369a TID:45e37242 0x85ac26e8: +CHub(Root tier
0)::AttachDevice - port = 1, fIsLowSpeed = 0
1895632 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_OPENING_ENDPOINT0_PIPE, failures = 0
1895633 PID:5fa369a TID:45e37242 0x85ac26e8: +CControlPipe::OpenPipe
1895633 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 93152 bytes; TotalSize = 94208 bytes
1895634 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem AllocateMemory :
PA = 0x31CE6420, VA = 0x00289420, Size = 2048, Desc = IssueTransfer
TDs
1895634 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 91104 bytes; TotalSize = 94208 bytes
1895635 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 91104 bytes; TotalSize = 94208 bytes
1895635 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem AllocateMemory :
PA = 0x31CE6C20, VA = 0x00289C20, Size = 512, Desc = IssueTransfer TDs
1895635 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 90592 bytes; TotalSize = 94208 bytes
1895636 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 90592 bytes; TotalSize = 94208 bytes
1895636 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem AllocateMemory :
PA = 0x31CE6E20, VA = 0x00289E20, Size = 32, Desc = OpenPipe ED
1895637 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 90560 bytes; TotalSize = 94208 bytes
1895637 PID:5fa369a TID:45e37242 0x85ac26e8: -CControlPipe::OpenPipe
1895637 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status = DEVICE_CONFIG_STATUS_USING_ADDRESS0,
failures = 0
1895638 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_RESET_AND_ENABLE_PORT, failures = 0
1895705 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_DEVICE_DESCRIPTOR_TEST, failures =
0
1895707 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_SET_ADDRESS, failures = 0
1895709 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status = DEVICE_CONFIG_STATUS_LEAVE_ADDRESS0,
failures = 0
1895720 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_INITIAL_DEVICE_DESCRIPTOR,
failures = 0
1895722 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_DEVICE_DESCRIPTOR, failures = 0
1895724 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SETUP_CONFIGURATION_DESCRIPTOR_ARRAY, failures =
0
1895725 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_INITIAL_CONFIG_DESCRIPTOR,
failures = 0
1895727 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_CONFIG_DESCRIPTOR, failures = 0
1895729 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_DETERMINE_CONFIG_TO_CHOOSE, failures = 0
1895730 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - Select Configuration 0 on
DEVICE_CONFIG_STATUS_DETERMINE_CONFIG_TO_CHOOSE step
1895730 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_SET_CONFIG, failures = 0
1895732 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_INITIAL_HUB_DESCRIPTOR, failures =
0
1895734 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status = DEVICE_CONFIG_STATUS_CREATE_NEW_HUB,
failures = 0
1895735 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_INSERT_NEW_DEVICE_INTO_UPSTREAM_HUB_PORT_ARRAY,
failures = 0
1895735 PID:5fa369a TID:45e37242 0x85ac26e8: CHub(Root tier
0)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SIGNAL_NEW_DEVICE_ENTER_OPERATIONAL_STATE,
failures = 0
1895736 PID:5fa369a TID:45e37242 0x85ac26e8: +CInterruptPipe::OpenPipe
1895736 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 90560 bytes; TotalSize = 94208 bytes
1895737 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem AllocateMemory :
PA = 0x31CE6E40, VA = 0x00289E40, Size = 2048, Desc = IssueTransfer
TDs
1895737 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 88512 bytes; TotalSize = 94208 bytes
1895737 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 88512 bytes; TotalSize = 94208 bytes
1895738 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem AllocateMemory :
PA = 0x31CE7640, VA = 0x0028A640, Size = 64, Desc = IssueTransfer TDs
1895738 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 88448 bytes; TotalSize = 94208 bytes
1895739 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 88448 bytes; TotalSize = 94208 bytes
1895739 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem AllocateMemory :
PA = 0x31CE7680, VA = 0x0028A680, Size = 32, Desc = OpenPipe ED
1895740 PID:5fa369a TID:45e37242 0x85ac26e8: CPhysMem ValidateHeaps :
FreeSize = 88416 bytes; TotalSize = 94208 bytes
1895740 PID:5fa369a TID:45e37242 0x85ac26e8: CInterruptPipe::OpenPipe
- setting the poll interval to 32 ms instead of 255 ms
1895740 PID:5fa369a TID:45e37242 0x85ac26e8: -
CInterruptPipe::OpenPipe, returning HCD_REQUEST_STATUS 0
1895741 PID:5fa369a TID:45e37242 0x85ac26e8: -CHub(Root tier
0)::AttachDevice - port = 1, fIsLowSpeed = 0, address = 1
1895745 PID:5fa369a TID:25df8fa2 0x85df8b8c:
CExternalHub::SetOrClearFeature - port = 1, set/clear = 0x3, feature =
0x16, FAILED
1895748 PID:5fa369a TID:25df8fa2 0x85df8b8c:
CExternalHub::SetOrClearFeature - port = 2, set/clear = 0x3, feature =
0x16, FAILED
1895751 PID:5fa369a TID:25df8fa2 0x85df8b8c:
CExternalHub::SetOrClearFeature - port = 3, set/clear = 0x3, feature =
0x16, FAILED
1895754 PID:5fa369a TID:25df8fa2 0x85df8b8c:
CExternalHub::SetOrClearFeature - port = 4, set/clear = 0x3, feature =
0x16, FAILED
1895960 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::HubStatusChangeThread - port 1, change = 0x0001, status = 0x0301
1896062 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::HubStatusChangeThread - device attached on port 1
1896062 PID:5fa369a TID:25df8fa2 0x85df8b8c: +CHub(External tier
1)::AttachDevice - port = 1, fIsLowSpeed = 1
1896062 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_OPENING_ENDPOINT0_PIPE, failures = 0
1896063 PID:5fa369a TID:25df8fa2 0x85df8b8c: +CControlPipe::OpenPipe
1896063 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 88416 bytes; TotalSize = 94208 bytes
1896064 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem AllocateMemory :
PA = 0x31CE76A0, VA = 0x0028A6A0, Size = 2048, Desc = IssueTransfer
TDs
1896064 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 86368 bytes; TotalSize = 94208 bytes
1896065 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 86368 bytes; TotalSize = 94208 bytes
1896065 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem AllocateMemory :
PA = 0x31CE7EA0, VA = 0x0028AEA0, Size = 512, Desc = IssueTransfer TDs
1896065 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 85856 bytes; TotalSize = 94208 bytes
1896066 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 85856 bytes; TotalSize = 94208 bytes
1896066 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem AllocateMemory :
PA = 0x31CE80A0, VA = 0x0028B0A0, Size = 32, Desc = OpenPipe ED
1896067 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 85824 bytes; TotalSize = 94208 bytes
1896067 PID:5fa369a TID:25df8fa2 0x85df8b8c: -CControlPipe::OpenPipe
1896067 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status = DEVICE_CONFIG_STATUS_USING_ADDRESS0,
failures = 0
1896068 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_RESET_AND_ENABLE_PORT, failures = 0
1896139 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_DEVICE_DESCRIPTOR_TEST, failures =
0
1896141 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_SET_ADDRESS, failures = 0
1896143 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status = DEVICE_CONFIG_STATUS_LEAVE_ADDRESS0,
failures = 0
1896154 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_INITIAL_DEVICE_DESCRIPTOR,
failures = 0
1896156 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_DEVICE_DESCRIPTOR, failures = 0
1896158 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SETUP_CONFIGURATION_DESCRIPTOR_ARRAY, failures =
0
1896158 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_INITIAL_CONFIG_DESCRIPTOR,
failures = 0
1896161 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_GET_CONFIG_DESCRIPTOR, failures = 0
1896164 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_DETERMINE_CONFIG_TO_CHOOSE, failures = 0
1896164 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - Select Configuration 0 on
DEVICE_CONFIG_STATUS_DETERMINE_CONFIG_TO_CHOOSE step
1896165 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SCHEDULING_SET_CONFIG, failures = 0
1896167 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status = DEVICE_CONFIG_STATUS_CREATE_NEW_FUNCTION,
failures = 0
1896167 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_INSERT_NEW_DEVICE_INTO_UPSTREAM_HUB_PORT_ARRAY,
failures = 0
1896168 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_SIGNAL_NEW_DEVICE_ENTER_OPERATIONAL_STATE,
failures = 0
1896236 PID:5fa369a TID:25df8fa2 0x85df8b8c: >>> Loading module
hidparse.dll at address 0x03420000-0x03435000 (RW data at
0x01F60000-0x01F60474)
Loaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\HIDPARSE.DLL'
1896237 PID:5fa369a TID:25df8fa2 0x85df8b8c: >>> Loading module
usbhid.dll at address 0x034D0000-0x034E6000 (RW data at
0x01F6E000-0x01F6E540)
Loaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\USBHID.DLL'
1896423 PID:5fa369a TID:25df8fa2 0x85df8b8c: DEVICE!
RegReadActivationValues RegQueryValueEx(Drivers\USB\ClientDrivers\Hid
\Instance\Prefix) returned 2
1896424 PID:5fa369a TID:25df8fa2 0x85df8b8c: DEVICE!
RegReadActivationValues RegQueryValueEx(Drivers\USB\ClientDrivers\Hid
\Instance\BusPrefix) returned 2
1896428 PID:5fa369a TID:25df8fa2 0x85df8b8c: DEVICE!
RegReadActivationValues RegQueryValueEx(Drivers\USB\ClientDrivers\Hid
\Hid_Class\BusPrefix) returned 2
1896439 PID:5fa369a TID:25df8fa2 0x85df8b8c: +USBD:OpenPipe, EP: 0x81,
MaxPkt: 4, Type: Interrupt
1896440 PID:5fa369a TID:25df8fa2 0x85df8b8c: +CInterruptPipe::OpenPipe
1896440 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 85824 bytes; TotalSize = 94208 bytes
1896440 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem AllocateMemory :
PA = 0x31CE80C0, VA = 0x0028B0C0, Size = 2048, Desc = IssueTransfer
TDs
1896441 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 83776 bytes; TotalSize = 94208 bytes
1896441 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 83776 bytes; TotalSize = 94208 bytes
1896442 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem AllocateMemory :
PA = 0x31CE88C0, VA = 0x0028B8C0, Size = 256, Desc = IssueTransfer TDs
1896442 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 83520 bytes; TotalSize = 94208 bytes
1896443 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 83520 bytes; TotalSize = 94208 bytes
1896443 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem AllocateMemory :
PA = 0x31CE89C0, VA = 0x0028B9C0, Size = 32, Desc = OpenPipe ED
1896443 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 83488 bytes; TotalSize = 94208 bytes
1896445 PID:5fa369a TID:25df8fa2 0x85df8b8c: CInterruptPipe::OpenPipe
- setting the poll interval to 8 ms instead of 10 ms
1896445 PID:5fa369a TID:25df8fa2 0x85df8b8c: -
CInterruptPipe::OpenPipe, returning HCD_REQUEST_STATUS 0
1896445 PID:5fa369a TID:25df8fa2 0x85df8b8c: -USBD:OpenPipe success,
hPipe = 2BB4A0
1896453 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Preparing to
Allocate memory
1896454 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Top Level
Collection 1 found
1896455 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Enter Link
Collection
1896455 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Exit Link
Collection
1896456 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Collection 1
exit
1896457 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Starting
Parsing Pass
1896457 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Parse
Collection 1
1896458 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Main Offset:8
1896458 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Main Offset:b
1896459 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'Main Offset:
10
1896460 PID:5fa369a TID:25df8fa2 0x85df8b8c: HidParse: 'X Parse
Collection 1
1896479 PID:5fa369a TID:25df8fa2 0x85df8b8c: >>> Loading module
mouhid.dll at address 0x033F0000-0x033F7000 (RW data at
0x01F5A000-0x01F5A4A8)
Loaded symbols for 'C:\WINCE500\PLATFORM\CDS\CALE_CDS\RELDIR
\CDS_ARMV4I_DEBUG\MOUHID.DLL'
1896483 PID:e5c10402 TID:25f94db6 0x85f94570: [NOTIFY]
HandleSystemEvent 7 /ADD HID1:
1897079 PID:5fa369a TID:25df8fa2 0x85df8b8c: -CHub(External tier
1)::AttachDevice - port = 1, fIsLowSpeed = 1, address = 2
When connecting/disconnecting the USB mouse I get the following debug
output related to opening/closing pipes (ohci2 manages to close all
previously opened pipes):
******* connecting mouse *******
2547047 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::HubStatusChangeThread - port 1, change = 0x0001, status = 0x0301
2547150 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::HubStatusChangeThread - device attached on port 1
2547151 PID:5fa369a TID:25df8fa2 0x85df8b8c: +CHub(External tier
1)::AttachDevice - port = 1, fIsLowSpeed = 1
2547151 PID:5fa369a TID:25df8fa2 0x85df8b8c: CHub(External tier
1)::AttachDevice - status =
DEVICE_CONFIG_STATUS_OPENING_ENDPOINT0_PIPE, failures = 0
2547152 PID:5fa369a TID:25df8fa2 0x85df8b8c: +CControlPipe::OpenPipe
2547152 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 88416 bytes; TotalSize = 94208 bytes
2547152 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem AllocateMemory :
PA = 0x31CE76A0, VA = 0x0028A6A0, Size = 2048, Desc = IssueTransfer
TDs
2547153 PID:5fa369a TID:25df8fa2 0x85df8b8c: CPhysMem ValidateHeaps :
FreeSize = 86368 bytes; Tota