Bug 510854

Summary: g-p-m handles broken laptop battery badly
Product: [Fedora] Fedora Reporter: Patrick <rh_bugzilla>
Component: gnome-power-managerAssignee: Richard Hughes <richard>
Status: CLOSED WORKSFORME QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 11CC: rhughes, richard
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-08-20 12:07:24 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Patrick 2009-07-11 16:16:39 UTC
Description of problem:
g-p-m handles a broken laptop battery badly causing delays when logging in through gdm and logging out/shutting down via System -> Shut Down

Version-Release number of selected component (if applicable):
2.26.2-1.fc11

How reproducible:
Boot and login or select shut down from the Gnome desktop

Steps to Reproduce:
1. boot and wait for GDM Greeter
2. click on name to use for login in gdm
3. wait and wait and wait until you get the password prompt
  
Actual results:
Wait and wait and wait until you get the password prompt

Expected results:
Password prompt is shown immediately after the username is selected

Additional info:

The battery in my Acer TM6465 laptop is broken. It no longer holds a decent amount of juice and can no longer be charged to any reasonable charge. Look at the "Last full capacity" value below. 

# acpitool -B
  Battery #1     : present
    Remaining capacity : 1581 mAh, 3.02%
    Design capacity    : 4300 mAh
    Last full capacity : 52384 mAh
    Present rate       : 0 mA
    Charging state     : charging
    Battery type       : rechargeable, Li-ion
    Model number       : LIP8216IVPC
    Serial number      : 5309
  Battery #2     : slot empty


# lshal | grep battery
udi = '/org/freedesktop/Hal/devices/computer_power_supply_battery_BAT0'
  battery.charge_level.current = 23398  (0x5b66)  (int)
  battery.charge_level.design = 63640  (0xf898)  (int)
  battery.charge_level.last_full = 775283  (0xbd473)  (int)
  battery.charge_level.percentage = 3  (0x3)  (int)
  battery.charge_level.rate = 0  (0x0)  (int)
  battery.is_rechargeable = true  (bool)
  battery.model = 'LIP8216IVPC'  (string)
  battery.present = true  (bool)
  battery.rechargeable.is_charging = true  (bool)
  battery.rechargeable.is_discharging = false  (bool)
  battery.reporting.current = 1581  (0x62d)  (int)
  battery.reporting.design = 4300  (0x10cc)  (int)
  battery.reporting.last_full = 52384  (0xcca0)  (int)
  battery.reporting.rate = 0  (0x0)  (int)
  battery.reporting.technology = 'Li-ion'  (string)
  battery.reporting.unit = 'mAh'  (string)
  battery.serial = '5309'  (string)
  battery.technology = 'lithium-ion'  (string)
  battery.type = 'primary'  (string)
  battery.vendor = ''  (string)
  battery.voltage.current = 16243  (0x3f73)  (int)
  battery.voltage.design = 14800  (0x39d0)  (int)
  battery.voltage.unit = 'mV'  (string)
  info.capabilities = {'battery'} (string list)
  info.category = 'battery'  (string)
  info.udi = '/org/freedesktop/Hal/devices/computer_power_supply_battery_BAT0'  (string)
  input.keymap.data = {'e025:help', 'e026:setup', 'e027:battery', 'e029:switchvideomode', 'e033:euro', 'e034:dollar', 'e04e:brightnessup', 'e054:bluetooth', 'e055:wlan', 'e056:wlan', 'e057:bluetooth', 'e058:bluetooth', 'e059:brightnessup', 'e06e:brightnessup', 'e06f:brightnessdown', 'e071:f22', 'e072:f22', 'e073:prog2', 'e074:prog1', 'e075:presentation', 'e078:fn', 'e079:f23'} (string list)


Output when I run the command below and unplug the AC:

# udevmonitor --kernel --udev
the program '/bin/bash' called 'udevmonitor', it should use 'udevadm monitor <options>', this will stop working in a future release
monitor will print the received events for:
UDEV - the event which udev sends out after rule processing
KERNEL - the kernel uevent
...

KERNEL[1247328309.731848] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
UDEV  [1247328309.734168] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
KERNEL[1247328309.764539] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
UDEV  [1247328309.767850] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
KERNEL[1247328309.825232] change   /devices/LNXSYSTM:00/device:00/ACPI0003:00/power_supply/ADP0 (power_supply)
UDEV  [1247328309.828504] change   /devices/LNXSYSTM:00/device:00/ACPI0003:00/power_supply/ADP0 (power_supply)
KERNEL[1247328309.839586] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-7/1-7:1.0/usb_endpoint/usbdev1.107_ep81 (usb_endpoint)
KERNEL[1247328309.839719] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-7/1-7:1.0/usb_endpoint/usbdev1.107_ep82 (usb_endpoint)
KERNEL[1247328309.840124] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-7/usb_endpoint/usbdev1.107_ep00 (usb_endpoint)
KERNEL[1247328309.840343] remove   /devices/pci0000:00/0000:00:1d.7/usb1/1-7/1-7:1.0/usb_endpoint/usbdev1.107_ep81 (usb_endpoint)
KERNEL[1247328309.840465] remove   /devices/pci0000:00/0000:00:1d.7/usb1/1-7/1-7:1.0/usb_endpoint/usbdev1.107_ep82 (usb_endpoint)
KERNEL[1247328309.840628] remove   /devices/pci0000:00/0000:00:1d.7/usb1/1-7/1-7:1.0 (usb)
KERNEL[1247328309.840791] remove   /devices/pci0000:00/0000:00:1d.7/usb1/1-7/usb_endpoint/usbdev1.107_ep00 (usb_endpoint)
KERNEL[1247328309.841036] remove   /devices/pci0000:00/0000:00:1d.7/usb1/1-7 (usb)
KERNEL[1247328309.847662] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
UDEV  [1247328309.851493] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-7/1-7:1.0/usb_endpoint/usbdev1.107_ep81 (usb_endpoint)
UDEV  [1247328309.861533] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-7/usb_endpoint/usbdev1.107_ep00 (usb_endpoint)
UDEV  [1247328309.863463] remove   /devices/pci0000:00/0000:00:1d.7/usb1/1-7/1-7:1.0/usb_endpoint/usbdev1.107_ep81 (usb_endpoint)
UDEV  [1247328309.864922] remove   /devices/pci0000:00/0000:00:1d.7/usb1/1-7/usb_endpoint/usbdev1.107_ep00 (usb_endpoint)
UDEV  [1247328309.866573] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
KERNEL[1247328309.870315] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
UDEV  [1247328309.871639] change   /devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0 (power_supply)
...


Here's what's in /var/log/gdm/:0-greeter.log:

** (gnome-power-manager:2368): WARNING **: Error invoking GetAll() to get properties: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
gdm-simple-greeter[2367]: WARNING: Could not ask power manager if user can suspend: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.

So when I get the GDM Greeter screen after booting up I click on the username I want to use for login and instead of the password prompt appearing immediately I have to wait and wait and wait before I finally get the password prompt. 

The same applies to selecting System -> Shut Down in the Desktop menu. It seems to just hang there for quite a while without doing anything. Sometimes I get an empty dialog window and when I click that away it will continue. Sometimes it will finally show the Shut Down dialog window.

Comment 1 Patrick 2009-07-11 16:21:39 UTC
# devkit-power --dump:

(devkit-power:9083): devkit-power-gobject-WARNING **: Couldn't enumerate devices: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
Daemon:

(devkit-power:9083): devkit-power-gobject-WARNING **: Error invoking GetAll() to get properties: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
  daemon-version:  (null)

(devkit-power:9083): devkit-power-gobject-WARNING **: Error invoking GetAll() to get properties: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
  can-suspend:     no

(devkit-power:9083): devkit-power-gobject-WARNING **: Error invoking GetAll() to get properties: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
  can-hibernate    no

(devkit-power:9083): devkit-power-gobject-WARNING **: Error invoking GetAll() to get properties: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
  on-battery:      no

(devkit-power:9083): devkit-power-gobject-WARNING **: Error invoking GetAll() to get properties: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
  lid-is-closed:   no

Comment 2 Richard Hughes 2009-07-11 16:27:35 UTC
Hmm, oddball. Can you try:

su -l
killall devkit-power-dameon
/usr/libexec/devkit-power-daemon --verbose

And then post the output. Thanks.

Comment 3 Patrick 2009-07-12 13:32:13 UTC
Thanks for the feedback. Here's the output you asked for.

[patrick@localhost ~]$ su -l
Password: 

[root@localhost ~]# killall devkit-power-dameon
devkit-power-dameon: no process killed

[root@localhost ~]# /usr/libexec/devkit-power-daemon --verbose
TI:15:31:22	TH:0x25b55f0	FI:egg-debug.c	FN:egg_debug_init,306
 - Verbose debugging 1 (on console 1)DKP_VERBOSE
TI:15:31:22	TH:0x25b55f0	FI:dkp-main.c	FN:main_acquire_name_on_proxy,91
 - Failed to acquire org.freedesktop.DeviceKit.Power
TI:15:31:22	TH:0x25b55f0	FI:dkp-main.c	FN:main,162
 - Could not acquire name; bailing out

Comment 4 Richard Hughes 2009-07-12 17:16:45 UTC
Crazy. Can you try removing DeviceKit-power and reinstalling it please?

Comment 5 Patrick 2009-07-14 18:05:47 UTC
Crazy indeed. I just booted my laptop and tried those commands in #2 again. This time it had a ton of output. Here it is:

# /usr/libexec/devkit-power-daemon --verbose
TI:20:02:27	TH:0xdee5f0	FI:egg-debug.c	FN:egg_debug_init,306
 - Verbose debugging 1 (on console 1)DKP_VERBOSE
TI:20:02:27	TH:0xdee5f0	FI:dkp-main.c	FN:main,169
 - Starting devkit-power-daemon version 008
TI:20:02:27	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_register_power_daemon,824
 - registering subsystem : power_supply
TI:20:02:27	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_register_power_daemon,824
 - registering subsystem : usb
TI:20:02:27	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_register_power_daemon,824
 - registering subsystem : tty
TI:20:02:27	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_register_power_daemon,824
 - registering subsystem : input
TI:20:02:28	TH:0xdee5f0	FI:dkp-input.c	FN:dkp_input_coldplug,185
 - not a switch [/sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input0/../capabilities/sw]
TI:20:02:28	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_device_add,595
 - not adding device /sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
TI:20:02:28	TH:0xdee5f0	FI:dkp-input.c	FN:dkp_input_coldplug,200
 - not one bitmask entry for /sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input0/event0
TI:20:02:28	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_device_add,595
 - not adding device /sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input0/event0
TI:20:02:28	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_register_device,811
 - object path = /org/freedesktop/DeviceKit/Power/devices/line_power_ADP0
TI:20:02:28	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_refresh_internal,672
 - added native-path: /sys/devices/LNXSYSTM:00/device:00/ACPI0003:00/power_supply/ADP0

TI:20:02:28	TH:0xdee5f0	FI:dkp-device-list.c	FN:dkp_device_list_insert,85
 - added /sys/devices/LNXSYSTM:00/device:00/ACPI0003:00/power_supply/ADP0
TI:20:02:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,371
 - energy_full (775.283200) is greater than energy_full_design (63.640000)
TI:20:02:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:02:28	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_register_device,811
 - object path = /org/freedesktop/DeviceKit/Power/devices/battery_BAT0
TI:20:02:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:02:28	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_refresh_internal,672
 - added native-path: /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0

TI:20:02:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_set_id,658
 - using id: LIP8216IVPC-63-5309
TI:20:02:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_array_from_file,480
 - loading 382 items of data from /var/lib/DeviceKit-power/history-rate-LIP8216IVPC-63-5309.dat
TI:20:02:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_array_from_file,480
 - loading 42 items of data from /var/lib/DeviceKit-power/history-charge-LIP8216IVPC-63-5309.dat
TI:20:02:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_array_from_file,480
 - loading 18 items of data from /var/lib/DeviceKit-power/history-time-full-LIP8216IVPC-63-5309.dat
TI:20:02:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_array_from_file,480
 - loading 25 items of data from /var/lib/DeviceKit-power/history-time-empty-LIP8216IVPC-63-5309.dat
TI:20:02:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,595
 - saving in 600 seconds
TI:20:02:28	TH:0xdee5f0	FI:dkp-device-list.c	FN:dkp_device_list_insert,85
 - added /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0
TI:20:02:28	TH:0xdee5f0	FI:dkp-input.c	FN:dkp_input_coldplug,185
 - not a switch [/sys/devices/LNXSYSTM:00/device:00/PNP0C0C:00/input/input2/../capabilities/sw]
TI:20:02:28	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_device_add,595
 - not adding device /sys/devices/LNXSYSTM:00/device:00/PNP0C0C:00/input/input2
TI:20:02:28	TH:0xdee5f0	FI:dkp-input.c	FN:dkp_input_coldplug,200
 - not one bitmask entry for /sys/devices/LNXSYSTM:00/device:00/PNP0C0C:00/input/input2/event2
TI:20:02:28	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_device_add,595

... snip tons of tty stuff

TI:20:02:28	TH:0xdee5f0	FI:dkp-daemon.c	FN:gpk_daemon_device_add,595
 - not adding device /sys/devices/virtual/tty/tty9
TI:20:02:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_poll_battery,517
 - No updates on supply /org/freedesktop/DeviceKit/Power/devices/battery_BAT0 for 30 seconds; forcing update
TI:20:02:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:02:58	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:02:58	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:02:58	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_emit_changed,755
 - emitting changed on /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0
TI:20:03:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_poll_battery,517
 - No updates on supply /org/freedesktop/DeviceKit/Power/devices/battery_BAT0 for 30 seconds; forcing update
TI:20:03:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:03:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:03:28	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_emit_changed,755
 - emitting changed on /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0
TI:20:03:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_poll_battery,517
 - No updates on supply /org/freedesktop/DeviceKit/Power/devices/battery_BAT0 for 30 seconds; forcing update
TI:20:03:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:03:58	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:03:58	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_emit_changed,755
 - emitting changed on /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0
TI:20:04:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_poll_battery,517
 - No updates on supply /org/freedesktop/DeviceKit/Power/devices/battery_BAT0 for 30 seconds; forcing update
TI:20:04:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:04:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:04:28	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_emit_changed,755
 - emitting changed on /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0
TI:20:04:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_poll_battery,517
 - No updates on supply /org/freedesktop/DeviceKit/Power/devices/battery_BAT0 for 30 seconds; forcing update
TI:20:04:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:04:58	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:04:58	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_emit_changed,755
 - emitting changed on /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0
TI:20:05:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_poll_battery,517
 - No updates on supply /org/freedesktop/DeviceKit/Power/devices/battery_BAT0 for 30 seconds; forcing update
TI:20:05:28	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:05:28	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:05:28	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_emit_changed,755
 - emitting changed on /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0
TI:20:05:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_poll_battery,517
 - No updates on supply /org/freedesktop/DeviceKit/Power/devices/battery_BAT0 for 30 seconds; forcing update
TI:20:05:58	TH:0xdee5f0	FI:dkp-supply.c	FN:dkp_supply_refresh_battery,416
 - resetting unknown timeout after 0 retries
TI:20:05:58	TH:0xdee5f0	FI:dkp-history.c	FN:dkp_history_schedule_save,590
 - deferring as others queued
TI:20:05:58	TH:0xdee5f0	FI:dkp-device.c	FN:dkp_device_emit_changed,755
 - emitting changed on /sys/devices/LNXSYSTM:00/device:00/PNP0C0A:00/power_supply/BAT0

If you need more info please let me know.

Comment 6 Richard Hughes 2009-07-15 11:14:20 UTC
So after the reboot it now works? Could dbus have not been started? Did other applications fail to work properly also?

Comment 7 Patrick 2009-07-28 16:14:32 UTC
After the last round of updates things work much better. No more delays when logging in and shutting down or suspending. Case can be closed. Thank you for your efforts.