Bug 245864
| Summary: | 3.14.1 fails to read usb apc information from device | ||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Jay Goodman <redhat-bugzilla> | ||||||||
| Component: | apcupsd | Assignee: | Orion Poplawski <orion> | ||||||||
| Status: | CLOSED ERRATA | QA Contact: | Fedora Extras Quality Assurance <extras-qa> | ||||||||
| Severity: | low | Docs Contact: | |||||||||
| Priority: | low | ||||||||||
| Version: | 7 | CC: | akropel1 | ||||||||
| Target Milestone: | --- | ||||||||||
| Target Release: | --- | ||||||||||
| Hardware: | x86_64 | ||||||||||
| OS: | Linux | ||||||||||
| Whiteboard: | |||||||||||
| Fixed In Version: | 3.14.1-2.fc7 | Doc Type: | Bug Fix | ||||||||
| Doc Text: | Story Points: | --- | |||||||||
| Clone Of: | Environment: | ||||||||||
| Last Closed: | 2007-07-03 16:25:25 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: | |||||||||||
| Attachments: |
|
||||||||||
|
Description
Jay Goodman
2007-06-27 03:54:07 UTC
What's the actual output from apcaccess? I have the same UPS connected to a F7 box without trouble. Here's both first 3.14.0, second 3.14.1 After updating to 3.14.0, I stopped the apcupsd daemon restarted the daemon rmmod ohci and ehci and uhci modprobed them all to force the udev triggers (the hard way) Got the wall message that usb UPS communications were restored this time So it seems that the ups talks. However, it cannot pull the information needed to function correctly. I have the apcupsd configured to shut down at 5% battery remaining, but since it cannot get the battery level, the machine just stays up until full battery exhaution and then loses power without shutdown being called. Side note: starting apcupsd 3.14.1 takes about 15 seconds compared to the 1 second with 3.14.0 root@linbox [~]$ cat 1 APC : 001,036,0912 DATE : Wed Jun 27 12:18:08 EDT 2007 HOSTNAME : linbox.buffett.lan RELEASE : 3.14.0 VERSION : 3.14.0 (9 February 2007) redhat UPSNAME : linbox.buffett.lan CABLE : USB Cable MODEL : Back-UPS ES 500 UPSMODE : Stand Alone STARTTIME: Tue Jun 26 14:01:22 EDT 2007 STATUS : ONLINE LINEV : 120.0 Volts LOADPCT : 0.0 Percent Load Capacity BCHARGE : 100.0 Percent TIMELEFT : 83.6 Minutes MBATTCHG : 4 Percent MINTIMEL : 2 Minutes MAXTIME : 0 Seconds SENSE : Medium LOTRANS : 088.0 Volts HITRANS : 138.0 Volts ALARMDEL : Always BATTV : 13.5 Volts LASTXFER : No transfers since turnon NUMXFERS : 0 TONBATT : 0 seconds CUMONBATT: 0 seconds XOFFBATT : N/A STATFLAG : 0x07000008 Status Flag MANDATE : 2003-10-29 SERIALNO : JB0344028794 BATTDATE : 2000-00-00 NOMINV : 120 NOMBATTV : 12.0 FIRMWARE : 801.e5.D USB FW:e5 APCMODEL : Back-UPS ES 500 END APC : Wed Jun 27 12:18:41 EDT 2007 root@linbox [~]$ cat 2 APC : 001,019,0486 DATE : Wed Jun 27 12:26:30 EDT 2007 HOSTNAME : linbox.buffett.lan RELEASE : 3.14.1 VERSION : 3.14.1 (04 May 2007) redhat UPSNAME : linbox.buffett.lan CABLE : USB Cable MODEL : USB UPS Driver UPSMODE : Stand Alone STARTTIME: Wed Jun 27 12:25:35 EDT 2007 STATUS : MBATTCHG : 4 Percent MINTIMEL : 2 Minutes MAXTIME : 0 Seconds NUMXFERS : 0 TONBATT : 0 seconds CUMONBATT: 0 seconds XOFFBATT : N/A STATFLAG : 0x07000000 Status Flag END APC : Wed Jun 27 12:27:11 EDT 2007 Can you attach your /etc/apcupsd/apcupsd.conf file? Also the output (/tmp/apcupsd, gzipped) of (with apcupsd stopped): strace -f -o /tmp/apcupsd /usr/sbin/apcupsd -f /etc/apcupsd/apcupsd.conf run apcaccess, then kill the apcupsd process and then collect the /tmp/apcupsd file. Any avc denials in /var/log/messages or /var/log/audit/audit.log? Created attachment 158037 [details]
requested apcupsd.conf
requested apcupsd.conf
Created attachment 158041 [details]
strace of apcupd: start, apcaccess, kill
strace out
> Any avc denials in /var/log/messages or /var/log/audit/audit.log?
selinux is disabled on this system
Okay, how about a /var/log/apcupsd.trace from: apcupsd -d1000 -T -f /etc/apcupsd/apcupsd.conf Created attachment 158060 [details]
apcupsd -d1000 -T -f /etc/apcupsd/apcupsd.conf
start, apcaccess, kill
Are there any other hid devices on your system? ls -l /dev/hiddev* Yep: crw------- 1 root root 180, 96 2007-06-27 14:37 /dev/hiddev0 crw------- 1 root root 180, 97 2007-06-27 14:37 /dev/hiddev1 crw------- 1 root root 180, 98 2007-06-27 14:37 /dev/hiddev2 the ups is on minor 97 (hiddev1) according to dmesg. Looks like apcupsd is trying to ask my keyboard for the battery info according to the trace. :) input,hiddev96: USB HID v1.10 Device [CHICONY USB Keyboard] on usb-0000:00:02.0-2 hiddev97: USB HID v1.10 Device [APC Back-UPS ES 500 FW:801.e5.D USB FW:e5] on usb-0000:00:02.0-3 input,hiddev98: USB HID v1.10 Keyboard [Acer IR Receiver] on usb-0000:00:02.0-9 Thanks for getting me started in the right path Orion. I got the src.rpm and
debuginfo and went to town. I just posted this bug on the apcupsd-users list
since they don't have a formal bug reporting system
======================================================
There seems some pretty sketchy logic in the USB auto detection routines in
linux-usb.c in the latest 3.14.1 release. This version 1.26.6.1 of the file
tagged Release-3_14_1
I've got three hid devices
Keyboard, APC UPS, and IR
# ls /dev/hiddev*
crw------- 1 root root 180, 96 2007-06-27 14:37 /dev/hiddev0
crw------- 1 root root 180, 97 2007-06-27 14:37 /dev/hiddev1
crw------- 1 root root 180, 98 2007-06-27 14:37 /dev/hiddev2
dmesg shows the apc upsd on minor 97 which is hiddev1
# dmesg | grep hiddev
input,hiddev96: USB HID v1.10 Device [CHICONY USB Keyboard] on usb-0000:00:02.0-2
hiddev97: USB HID v1.10 Device [APC Back-UPS ES 500 FW:801.e5.D USB FW:e5] on
usb-0000:00:02.0-3
input,hiddev98: USB HID v1.10 Keyboard [Acer IR Receiver] on usb-0000:00:02.0-9
So in my case, open_device( ) is called for /dev/hiddev0 (the keyboard in my case)
Line 116 loops
i ret ret&ffff000 UPS_USAGE&ffff0000 ==
0 0x10080 0x10000 0x840000 (nope)
1 0xc0001 0xc0000 0x840000 (nope)
2 negative (jump line 121)
Line 121 oops , this should probably read
if (ret >= 0)
but since it doesn't apcupsd thinks it found the apc device and happily, but
unsuccessfully, probes my keyboard for battery status :)
Also, I'm not familiar with the HIDIOAPPLICATION ioctl, but ioctl in general
allows 0 for successful return value as well positive ints. That would change
the comparator in in the for loop in line 116 as well
113 fd = open(dev, O_RDWR | O_NOCTTY);
114 if (fd >= 0) {
115 /* Check for the UPS application HID usage */
116 for (i = 0; (ret = ioctl(fd, HIDIOCAPPLICATION, i)) > 0; i++) {
117 if ((ret & 0xffff000) == (UPS_USAGE & 0xffff0000))
118 break;
119 }
120 /* If we found the UPS application usage, we're good to go */
121 if (ret) {
122 /* Request full uref reporting from read() */
123 if (FORCE_COMPAT24 || ioctl(fd, HIDIOCSFLAG, &flaguref)) {
124 Dmsg0(100, "HIDIOCSFLAG failed; enabling linux-2.4 "
125 "compatibility mode\n");
126 my_data->compat24 = true;
127 }
128 /* Successfully opened the device */
129 Dmsg1(200, "Successfully opened \"%s\"\n", dev);
130 return fd;
131 }
132 close(fd);
133 }
134
135 /* Failed to open the device */
136 return -1;
Analysis looks correct. I introduced that bug in the 3.14.1 device locating rewrite. Line 121 should use a >0 check. HIDIOCAPPLICATION ioctl returns the usage word (non-zero) or a negative error code. I'll fix it up in CVS ASAP. Fixed in apcupsd CVS, linux-usb.c rev 1.26.6.2 on Branch-3_14. Would appreciate test by submitter. Build with release_3_14_1 tag with an updated linux-usb.c to rev 1.26.6.2 is now working with multiple hid devices (with the ups not being hiddev0) Thanks Adam. apcupsd-3.14.1-2.fc7 has been pushed to the Fedora 7 stable repository. If problems still persist, please make note of it in this bug report. |