Re: exception following PowerOffSystem() call in power manager PDD

From: Andrew Worsley (Andrew.Worsley_at_nospam.4.me)
Date: 12/20/04 

Date: Tue, 21 Dec 2004 09:31:33 +1300

In article <uOVxj5l5EHA.828@TK2MSFTNGP14.phx.gbl>, "David Liao \(MS\)"
<davli@online.microsoft.com> says...
> On Windows CE 4.2, you can't call any API during the power callback(Except
> few like SetInterruptEvent). The message indicate you are calling some API
> during the power callback. Usually, the problem is not the Power Manager
> PDD, it is a driver. Probably, you have a driver which calling some API in
> XXX_PowerDown or XXX_PowerUp handler.
>
> You probably can find out which driver by turn on PNP zone on processor
> device.exe.

Thanks David,

Sorry I replied by email - I meant to reply to the group, but must have
pressed the wrong button.

I was aware of that restriction (drivers can't call APIs during
XXX_PowerDown()), but couldn't find any driver that
breaks the rules. I'll tried turning on the PNP zone, but it didn't give
any more information. In fact, I turned on all the device.exe zones, and
all the pm.dll zones, and this is what I got:

4294844962 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PowerManager: Changing
state from osrunning to osclosing because of Timeout
4294844963 PID:ffc0472 TID:6ff998ae 0x8ff968e0:
+PmSetSystemPowerState_I: name osclosing, hint 0x00000000, options
0x00000000, fInternal 1
4294844966 PID:ffc0472 TID:6ff998ae 0x8ff968e0: ReadSystemPowerState:
state 'osclosing' devices max is D4, flags 0x00200000
4294844967 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 28 bytes
returned 0x00053010 (55 total objects allocated)
4294844969 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 36 bytes
returned 0x00053040 (56 total objects allocated)
4294844971 PID:ffc0472 TID:6ff998ae 0x8ff968e0:
RegReadClassDeviceRestrictions: reading information for class {98c5250d-
c29a-4985-ae5f-afe5367e5006}
4294844973 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 44 bytes
returned 0x00053080 (57 total objects allocated)
4294844975 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 24 bytes
returned 0x000530c0 (58 total objects allocated)
4294844977 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 32 bytes
returned 0x000530f0 (59 total objects allocated)
4294844979 PID:ffc0472 TID:6ff998ae 0x8ff968e0:
RegReadClassDeviceRestrictions: device 'Default' restricted to D0
4294844981 PID:ffc0472 TID:6ff998ae 0x8ff968e0:
RegReadClassDeviceRestrictions: reading information for class {a32942b7-
920c-486b-b0e6-92a702a99b35}
4294844983 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 44 bytes
returned 0x00053130 (60 total objects allocated)
4294844985 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 24 bytes
returned 0x00053170 (61 total objects allocated)
4294844987 PID:ffc0472 TID:6ff998ae 0x8ff968e0: PmAlloc: alloc 32 bytes
returned 0x000531a0 (62 total objects allocated)
4294844989 PID:ffc0472 TID:6ff998ae 0x8ff968e0:
RegReadClassDeviceRestrictions: device 'Default' restricted to D4
4294844991 PID:ffc0472 TID:6ff998ae 0x8ff968e0:
RegReadClassDeviceRestrictions: skipping flags 0x00200000
4294844993 PID:ffc0472 TID:6ff998ae 0x8ff968e0: GenerateNotifications:
sending type 1 notifications (32 bytes)
4294844996 PID:ffc0472 TID:6ff998ae 0x8ff968e0: SendNotification:
sending notification to 0x000519c0 (owner 0x2fe444f6)
4294844997 PID:ffc0472 TID:6ff998ae 0x8ff968e0: GenerateNotifications:
done sending type 1 notifications
4294844999 PID:ffc0472 TID:6ff998ae 0x8ff968e0: NotifyAndPowerOff():
suspending - notifying non-block drivers
4294845000 PID:ffc0472 TID:6ff998ae 0x8ff968e0: DeviceStateAddRef:
refcnt for 0x00037430 set to 3
4294845002 PID:ffc0472 TID:6ff998ae 0x8ff968e0: UpdateDeviceState: new
state for 'nds0:' is 4 (current 0, req 0, set -1, floor 4, ceiling 4,
actual 0)
4294845004 PID:ffc0472 TID:6ff998ae 0x8ff968e0: MapDevicePowerState:
mapping D4 to D0
4294845005 PID:ffc0472 TID:6ff998ae 0x8ff968e0: SetDevicePower: setting
'nds0:' to D4 (mapped to D0), fForceSet is 0
4294845007 PID:ffc0472 TID:6ff998ae 0x8ff968e0: SetDevicePower: device
is already at D0
4294845008 PID:ffc0472 TID:6ff998ae 0x8ff968e0: DeviceStateDecRef:
refcnt for 0x00037430 set to 2
4294845009 PID:ffc0472 TID:6ff998ae 0x8ff968e0: DeviceStateAddRef:
refcnt for 0x00037670 set to 2
4294845011 PID:ffc0472 TID:6ff998ae 0x8ff968e0: UpdateDeviceState: new
state for 'vmini1' is -1 (current 0, req 0, set -1, floor 4, ceiling 0,
actual 0)
4294845013 PID:ffc0472 TID:6ff998ae 0x8ff968e0: DeviceStateDecRef:
refcnt for 0x00037670 set to 1
4294845015 PID:ffc0472 TID:6ff998ae 0x8ff968e0: NotifyAndPowerOff():
calling KernelIoControl(IOCTL_HAL_PRESUSPEND)
4294845016 PID:cffdd59e TID:6ff998ae 0x8ff968e0: FS: Got Power notif
0x00000002
4294845018 PID:cffdd59e TID:6ff998ae 0x8ff968e0: FSREG: Registry flush
unnecessary
4294845020 PID:cffdd59e TID:6ff998ae 0x8ff968e0: FSRAM: Flushing cached
file data
4294845021 PID:ffc0472 TID:6ff998ae 0x8ff968e0: NotifyPowerOff():
suspending - notifying block drivers
4294845023 PID:ffc0472 TID:6ff998ae 0x8ff968e0: DeviceStateAddRef:
refcnt for 0x000524d0 set to 2
4294845025 PID:ffc0472 TID:6ff998ae 0x8ff968e0: UpdateDeviceState: new
state for 'dsk1:' is 4 (current 0, req 0, set -1, floor 4, ceiling 4,
actual 0)
4294845026 PID:ffc0472 TID:6ff998ae 0x8ff968e0: MapDevicePowerState:
mapping D4 to D4
4294845028 PID:ffc0472 TID:6ff998ae 0x8ff968e0: SetDevicePower: setting
'dsk1:' to D4 (mapped to D4), fForceSet is 0
4294845029 PID:ffc0472 TID:6ff998ae 0x8ff968e0: RequestStreamDevice:
calling DeviceIoControl(0x4fee6ce6) w/ request 3280904
('IOCTL_POWER_SET')
4294845031 PID:ffc0472 TID:6ff998ae 0x8ff968e0: ATADISK: Powering off
system: D4 Count=1
4294845033 PID:ffc0472 TID:6ff998ae 0x8ff968e0: DeviceStateDecRef:
refcnt for 0x000524d0 set to 1
4294845035 PID:ffc0472 TID:6ff998ae 0x8ff968e0: NotifyPowerOff():
calling PowerOffSystem()
4294845036 PID:ffc0472 TID:6ff998ae Exception 040 Thread=8ff968e0 Proc=
0ffc0472 'device.exe'
4294845037 PID:ffc0472 TID:6ff998ae AKY=00000009 PC=8c9b2f4e RA=8c9b01f0
TEA=00003b83

As you can see, it is not until AFTER the call to PowerOffSystem() that
the exception occurs.

I thought it was Power Manager PDD that called the XXX_PowerDown()
functions, right?

I can step all the way through the Power Manger PDD code, past the calls
to the UpdateClassDeviceStates() (is this what calls the XXX_PowerDown()
functions?), right up to the call to PowerOffSystem(). Its only after
stepping into that function that the exception occurs.

Does the call to PowerOffStstem() cause other driver functions to be
called? I thought all it did was set a flag, so the kernel calls
OEMPowerOff() on the next reschedule.

It is called like this (same as default driver, with some extra logging
so I can see when it happens:

  FileSystemPowerFunction(FSNOTIFY_POWER_OFF);

  // update block device power states
  DEBUGMSG(ZONE_PLATFORM || ZONE_RESUME, (_T("NotifyPowerOff():
suspending - notifying block drivers\r\n")));
  pdl = GetDeviceListFromClass(&idBlockDevices);
  if(pdl != NULL) {
      UpdateClassDeviceStates(pdl);
  }

  DEBUGMSG(ZONE_PLATFORM || ZONE_RESUME, (_T("NotifyPowerOff(): calling
PowerOffSystem()\r\n")));
  PowerOffSystem(); // Set Flag in the system
  //Sleep(INFINITE); // Run the scheduler and never come back
  Sleep(0); // Run the scheduler and never come back
  DEBUGMSG(ZONE_PLATFORM || ZONE_RESUME, (_T("NotifyPowerOff(): returned
from PowerOffSystem() - shouldn't get here!\r\n")));

Quantcast