Bug 847874 - logging messages every 30 seconds
Summary: logging messages every 30 seconds
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: upower
Version: 18
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Richard Hughes
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-08-13 21:25 UTC by Dave Jones
Modified: 2015-01-04 22:31 UTC (History)
13 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-02-05 22:46:55 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 863524 0 unspecified CLOSED upowerd goes crazy when bluetooth keyboard is connected 2021-02-22 00:41:40 UTC

Internal Links: 863524

Description Dave Jones 2012-08-13 21:25:40 UTC
every 30 seconds, upower is logging this..

upowerd[803]: (upowerd:803): UPower-Linux-WARNING **: no voltage values, using 10V as approximation

There's also a few of these in the logs..

upowerd[829]: (upowerd:829): GLib-CRITICAL **: g_ascii_strcasecmp: assertion `s1 != NULL' failed

Comment 1 Tom Horsley 2012-10-06 21:25:29 UTC
Yea, I'm getting messages every 30 seconds as well. The ones I see are:

Oct  6 17:21:30 zooty upowerd[1903]: (upowerd:1903): GLib-CRITICAL **: g_ascii_strcasecmp: assertion `s1 != NULL' failed
Oct  6 17:21:30 zooty upowerd[1903]: (upowerd:1903): UPower-Linux-WARNING **: unknown status string:

Apparently this all started here:

Oct  5 20:48:41 zooty bluetoothd[665]: bluetoothd[665]: Endpoint registered: sender=:1.513 path=/MediaEndpoint/HFPAG
Oct  5 20:48:41 zooty bluetoothd[665]: Endpoint registered: sender=:1.513 path=/MediaEndpoint/HFPAG
Oct  5 20:48:41 zooty bluetoothd[665]: Endpoint registered: sender=:1.513 path=/MediaEndpoint/A2DPSource
Oct  5 20:48:41 zooty bluetoothd[665]: bluetoothd[665]: Endpoint registered: sender=:1.513 path=/MediaEndpoint/A2DPSource
Oct  5 21:06:17 zooty bluetoothd[665]: bluetoothd[665]: Endpoint unregistered: sender=:1.513 path=/MediaEndpoint/HFPAG
Oct  5 21:06:17 zooty bluetoothd[665]: Endpoint unregistered: sender=:1.513 path=/MediaEndpoint/HFPAG
Oct  5 21:06:17 zooty bluetoothd[665]: Endpoint unregistered: sender=:1.513 path=/MediaEndpoint/A2DPSource
Oct  5 21:06:17 zooty bluetoothd[665]: bluetoothd[665]: Endpoint unregistered: sender=:1.513 path=/MediaEndpoint/A2DPSource
Oct  5 21:28:25 zooty kernel: [91636.872631] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
Oct  5 21:28:25 zooty kernel: [91636.873116] hid-generic 0005:046D:B30C.0005: >unknown main item tag 0x0
Oct  5 21:28:25 zooty kernel: [91636.925539] input: Logitech diNovo Mini as /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.7/2-1.7:1.0/bluetooth/hci0/hci0:42/input16
Oct  5 21:28:25 zooty kernel: [91636.925759] hid-generic 0005:046D:B30C.0005: >input,hidraw4: BLUETOOTH HID v0.40 Mouse [Logitech diNovo Mini] on 00:1C:F0:6C:4A:8E
Oct  5 21:28:25 zooty upowerd[1903]: (upowerd:1903): UPower-Linux-WARNING **: no voltage values, using 10V as approximation
Oct  5 21:28:25 zooty upowerd[1903]: (upowerd:1903): UPower-Linux-WARNING **: no voltage values, using 10V as approximation
Oct  5 21:28:25 zooty upowerd[1903]: (upowerd:1903): UPower-Linux-WARNING **: no voltage values, using 10V as approximation

I got a gazillion of the warnings after connecting a bluetooth keyboard, and
then after disconnecting the keyboard the other messages have been going off every 30 seconds.

Comment 2 Tom Horsley 2012-10-06 21:32:07 UTC
Fortunately, rebooting the system seems to have made the infinite message spew stop (presumably until I connect a bluetooth keyboard again).

Comment 3 John Schmitt 2012-10-13 14:32:48 UTC
I get this behaviour when I connect an Appple Magic Trackpad with a USB Bluetooth dongle.  Given https://bugzilla.redhat.com/show_bug.cgi?id=863524 I doubt you need special bluetooth hardware to reproduce this.

I will occasionally get this, at which point I have to re-do the settings for my trackpad:
Oct 13 07:04:22 badboy kernel: [43918.913666] power_supply hid-7C:C3:A1:4A:69:AD-battery: driver failed to report `capacity' property: -5
Oct 13 07:04:30 badboy kernel: [43926.908545] power_supply hid-7C:C3:A1:4A:69:AD-battery: driver failed to report `capacity' property: -5
Oct 13 07:04:30 badboy kernel: [43926.930194] magicmouse 0005:05AC:030E.0007: unknown main item tag 0x0
Oct 13 07:04:30 badboy kernel: [43926.980183] power_supply hid-7C:C3:A1:4A:69:AD-battery: driver failed to report `capacity' property: -5
Oct 13 07:04:30 badboy kernel: [43926.980283] input: Apple Wireless Trackpad as /devices/pci0000:00/0000:00:1d.2/usb8/8-1/8-1:1.0/bluetooth/hci0/hci0:45/input21
Oct 13 07:04:30 badboy kernel: [43926.981065] magicmouse 0005:05AC:030E.0007: input,hidraw5: BLUETOOTH HID v1.60 Mouse [Apple Wireless Trackpad] on 00:15:83:3D:0A:57
Oct 13 07:04:30 badboy kernel: [43926.982157] power_supply hid-7C:C3:A1:4A:69:AD-battery: driver failed to report `capacity' property: -5

Comment 4 Fedora End Of Life 2013-07-03 22:42:28 UTC
This message is a reminder that Fedora 17 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 17. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '17'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 17's end of life.

Bug Reporter:  Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 17 is end of life. If you 
would still like  to see this bug fixed and are able to reproduce it 
against a later version  of Fedora, you are encouraged  change the 
'version' to a later Fedora version prior to Fedora 17's end of life.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 5 John Schmitt 2013-07-03 23:14:40 UTC
Still happens:
...
Jul  3 16:08:27 badboy upowerd[28651]: (upowerd:28651): UPower-Linux-WARNING **: no voltage values, using 10V as approximation
Jul  3 16:08:58 badboy upowerd[28651]: (upowerd:28651): UPower-Linux-WARNING **: no voltage values, using 10V as approximation
Jul  3 16:09:29 badboy upowerd[28651]: (upowerd:28651): UPower-Linux-WARNING **: no voltage values, using 10V as approximation
...
$ cat /etc/redhat-release
Fedora release 18 (Spherical Cow)
$ uname -a
Linux badboy.xxxxxx.net 3.9.6-200.fc18.x86_64 #1 SMP Thu Jun 13 18:56:55 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

Comment 6 Richard Hughes 2013-08-12 14:18:44 UTC
(In reply to John Schmitt from comment #5)
> Jul  3 16:08:27 badboy upowerd[28651]: (upowerd:28651): UPower-Linux-WARNING
> **: no voltage values, using 10V as approximation

Can you attach the output of "upower --dump" please. Thanks.

Comment 7 John Schmitt 2013-08-12 15:27:57 UTC
upower --dump
Device: /org/freedesktop/UPower/devices/battery_hid_7coc3oa1o4ao69oad_battery
  native-path:          /sys/devices/pci0000:00/0000:00:1d.2/usb8/8-1/8-1:1.0/bluetooth/hci0/hci0:21/0005:05AC:030E.0006/power_supply/hid-7c:c3:a1:4a:69:ad-battery
  model:                Apple Wireless Trackpad
  power supply:         no
  updated:              Mon Aug 12 08:26:11 2013 (2 seconds ago)
  has history:          yes
  has statistics:       yes
  battery
    present:             yes
    rechargeable:        yes
    state:               discharging
    energy:              0 Wh
    energy-empty:        0 Wh
    energy-full:         0 Wh
    energy-full-design:  0 Wh
    energy-rate:         0 W
    percentage:          64%
    capacity:            100%

Daemon:
  daemon-version:  0.9.19
  can-suspend:     yes
  can-hibernate:   yes
  on-battery:      no
  on-low-battery:  no
  lid-is-closed:   no
  lid-is-present:  no
  is-docked:       no

Comment 8 Richard Hughes 2013-08-13 08:13:20 UTC
Thanks for that -- what's the output of:

cat "/sys/devices/pci0000:00/0000:00:1d.2/usb8/8-1/8-1:1.0/bluetooth/hci0/hci0:21/0005:05AC:030E.0006/power_supply/hid-7c:c3:a1:4a:69:ad-battery/type"

(or similar path) -- Thanks!

Richard.

Comment 9 John Schmitt 2013-08-13 16:01:34 UTC
$ find /sys/devices/pci0000\:00/0000\:00\:1d.2/usb8/8-1/8-1\:1.0/bluetooth/hci0/ -name type
/sys/devices/pci0000:00/0000:00:1d.2/usb8/8-1/8-1:1.0/bluetooth/hci0/type
/sys/devices/pci0000:00/0000:00:1d.2/usb8/8-1/8-1:1.0/bluetooth/hci0/rfkill1/type
$ cat /sys/devices/pci0000:00/0000:00:1d.2/usb8/8-1/8-1:1.0/bluetooth/hci0/type
BR/EDR
$ cat /sys/devices/pci0000:00/0000:00:1d.2/usb8/8-1/8-1:1.0/bluetooth/hci0/rfkill1/type
bluetooth

If it's any help, when I plug it in, I see this in /var/log/messages (is it worthy of a different bug?):

Aug 13 08:48:30 badboy kernel: [37836.562639] usb 8-1: new full-speed USB device number 4 using uhci_hcd
Aug 13 08:48:30 badboy kernel: [37836.701389] usb 8-1: New USB device found, idVendor=0cf3, idProduct=3000
Aug 13 08:48:30 badboy kernel: [37836.701396] usb 8-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Aug 13 08:48:31 badboy kernel: [37836.958108] usb 8-1: USB disconnect, device number 4
Aug 13 08:48:32 badboy kernel: [37838.583589] usb 8-1: new full-speed USB device number 5 using uhci_hcd
Aug 13 08:48:32 badboy kernel: [37838.721804] usb 8-1: New USB device found, idVendor=0cf3, idProduct=3005
Aug 13 08:48:32 badboy kernel: [37838.721810] usb 8-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Aug 13 08:48:32 badboy systemd[1]: Starting Bluetooth.
Aug 13 08:48:32 badboy systemd[1]: Reached target Bluetooth.
Aug 13 08:48:33 badboy bluetoothd[628]: bluetoothd[628]: Parsing /etc/bluetooth/serial.conf failed: No such file or directory
Aug 13 08:48:33 badboy bluetoothd[628]: Parsing /etc/bluetooth/serial.conf failed: No such file or directory
Aug 13 08:48:33 badboy bluetoothd[628]: bluetoothd[628]: Unknown command complete for opcode 19
Aug 13 08:48:33 badboy bluetoothd[628]: Unknown command complete for opcode 19
Aug 13 08:48:33 badboy bluetoothd[628]: bluetoothd[628]: Adapter /org/bluez/628/hci0 has been enabled
Aug 13 08:48:33 badboy bluetoothd[628]: Adapter /org/bluez/628/hci0 has been enabled
Aug 13 08:49:12 badboy bluetoothd[628]: bluetoothd[628]: Agent replied with an error: org.freedesktop.DBus.Python.glib.GError, Traceback (most recent call last):
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
Aug 13 08:49:12 badboy bluetoothd[628]: retval = candidate_method(self, *args, **keywords)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/main/applet/BluezAgent.py", line 245, in Authorize
Aug 13 08:49:12 badboy bluetoothd[628]: pixbuf=get_icon("blueman", 48), status_icon=self.status_icon)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 187, in __new__
Aug 13 08:49:12 badboy bluetoothd[628]: return NotificationDialog(summary, message, timeout, actions, actions_cb, pixbuf, status_icon)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 41, in __init__
Aug 13 08:49:12 badboy bluetoothd[628]: self.bubble = NotificationBubble(summary, message, pixbuf=pixbuf)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 173, in __init__
Aug 13 08:49:12 badboy bluetoothd[628]: self.show()
Aug 13 08:49:12 badboy bluetoothd[628]: GError: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Notifications was not provided by any .service files
Aug 13 08:49:12 badboy bluetoothd[628]: bluetoothd[628]: Access denied: Traceback (most recent call last):
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
Aug 13 08:49:12 badboy bluetoothd[628]: retval = candidate_method(self, *args, **keywords)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/main/applet/BluezAgent.py", line 245, in Authorize
Aug 13 08:49:12 badboy bluetoothd[628]: pixbuf=get_icon("blueman", 48), status_icon=self.status_icon)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 187, in __new__
Aug 13 08:49:12 badboy bluetoothd[628]: return NotificationDialog(summary, message, timeout, actions, actions_cb, pixbuf, status_icon)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 41, in __init__
Aug 13 08:49:12 badboy bluetoothd[628]: self.bubble = NotificationBubble(summary, message, pixbuf=pixbuf)
Aug 13 08:49:12 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 173, in __init__
Aug 13 08:49:12 badboy bluetoothd[628]: self.show()
Aug 13 08:49:12 badboy bluetoothd[628]: GError: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Notifications was not provided by any .service files
Aug 13 08:49:12 badboy bluetoothd[628]: Agent replied with an error: org.freedesktop.DBus.Python.glib.GError, Traceback (most recent call last):
Aug 13 08:49:12 badboy bluetoothd[628]: Access denied: Traceback (most recent call last):
Aug 13 08:49:16 badboy bluetoothd[628]: bluetoothd[628]: Agent replied with an error: org.freedesktop.DBus.Python.glib.GError, Traceback (most recent call last):
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
Aug 13 08:49:16 badboy bluetoothd[628]: retval = candidate_method(self, *args, **keywords)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/main/applet/BluezAgent.py", line 245, in Authorize
Aug 13 08:49:16 badboy bluetoothd[628]: pixbuf=get_icon("blueman", 48), status_icon=self.status_icon)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 187, in __new__
Aug 13 08:49:16 badboy bluetoothd[628]: return NotificationDialog(summary, message, timeout, actions, actions_cb, pixbuf, status_icon)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 41, in __init__
Aug 13 08:49:16 badboy bluetoothd[628]: self.bubble = NotificationBubble(summary, message, pixbuf=pixbuf)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 173, in __init__
Aug 13 08:49:16 badboy bluetoothd[628]: self.show()
Aug 13 08:49:16 badboy bluetoothd[628]: GError: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Notifications was not provided by any .service files
Aug 13 08:49:16 badboy bluetoothd[628]: bluetoothd[628]: Access denied: Traceback (most recent call last):
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
Aug 13 08:49:16 badboy bluetoothd[628]: retval = candidate_method(self, *args, **keywords)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/main/applet/BluezAgent.py", line 245, in Authorize
Aug 13 08:49:16 badboy bluetoothd[628]: pixbuf=get_icon("blueman", 48), status_icon=self.status_icon)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 187, in __new__
Aug 13 08:49:16 badboy bluetoothd[628]: return NotificationDialog(summary, message, timeout, actions, actions_cb, pixbuf, status_icon)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 41, in __init__
Aug 13 08:49:16 badboy bluetoothd[628]: self.bubble = NotificationBubble(summary, message, pixbuf=pixbuf)
Aug 13 08:49:16 badboy bluetoothd[628]: File "/usr/lib/python2.7/site-packages/blueman/gui/Notification.py", line 173, in __init__
Aug 13 08:49:16 badboy bluetoothd[628]: self.show()
Aug 13 08:49:16 badboy bluetoothd[628]: GError: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Notifications was not provided by any .service files
Aug 13 08:49:16 badboy bluetoothd[628]: Agent replied with an error: org.freedesktop.DBus.Python.glib.GError, Traceback (most recent call last):
Aug 13 08:49:16 badboy bluetoothd[628]: Access denied: Traceback (most recent call last):

Comment 10 Fedora End Of Life 2013-12-21 15:04:21 UTC
This message is a reminder that Fedora 18 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 18. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '18'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 18's end of life.

Thank you for reporting this issue and we are sorry that we may not be 
able to fix it before Fedora 18 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior to Fedora 18's end of life.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 11 Timothée Ravier 2013-12-21 15:50:06 UTC
I sent out patches a while back to upower thus this is "fixed" in upower 0.9.22.

http://cgit.freedesktop.org/upower/commit/?id=12f6f4014502d41d343dcfaf39a65a3ae504ce04
http://cgit.freedesktop.org/upower/commit/?id=6d3a68d7d4a737b2d79fb93547707b7c715aae2d

This does not fix the real underlying problem, but contains the logging to something sane. This may be set to FIXED.

Comment 12 Fedora End Of Life 2014-02-05 22:46:55 UTC
Fedora 18 changed to end-of-life (EOL) status on 2014-01-14. Fedora 18 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.