Bug 232733

Summary: /usr/libexec/hal_lpadmin gets a backtrace
Product: [Fedora] Fedora Reporter: Michal Jaegermann <michal>
Component: hal-cups-utilsAssignee: Tim Waugh <twaugh>
Status: CLOSED RAWHIDE QA Contact:
Severity: medium Docs Contact:
Priority: medium    
Version: 6   
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 0.6.6-1.fc7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2007-04-04 14:21:46 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:
Bug Depends On:    
Bug Blocks: 150225    

Description Michal Jaegermann 2007-03-16 21:29:38 UTC
Description of problem:

After replugging a printer connected on USB link the following
showed up in /var/log/messages:

kernel: drivers/usb/class/usblp.c: usblp0: removed
kernel: usb 1-1: new full speed USB device using ohci_hcd and address 4
kernel: usb 1-1: configuration #1 chosen from 1 choice
kernel: drivers/usb/class/usblp.c: usblp0: USB Bidirectional printer dev 4 if 0
alt 0 proto 2 vid 0x043D pid 0x000C
hal_lpadmin: File "/usr/libexec/hal_lpadmin", line 198, in main h = HalLpAdmin()
hal_lpadmin: File "/usr/libexec/hal_lpadmin", line 172, in __init__    
self.addPrinter()
hal_lpadmin: File "/usr/libexec/hal_lpadmin", line 185, in addPrinter    
printer.add()
hal_lpadmin: File "/usr/libexec/hal_lpadmin", line 82, in add     printers =
cupshelpers.getPrinters(self.cups_connection)
hal_lpadmin: File "/usr/share/system-config-printer/cupshelpers.py", line 234,
in getPrinters     printers_conf = PrintersConf(connection)
hal_lpadmin: File "/usr/share/system-config-printer/cupshelpers.py", line 325,
in __init__  self.parse(self.fetch('/admin/conf/printers.conf'), 'Printer')
hal_lpadmin: File "/usr/share/system-config-printer/cupshelpers.py", line 332,
in fetch     self.connection.getFile(file, filename)
hal_lpadmin: AttributeError: 'NoneType' object has no attribute 'getFile'

The most unfortunate is that after that a printer stopped working
and getting it back into service turned out be not so simple.
Anything short of reconfiguration was not helping.

Version-Release number of selected component (if applicable):
hal-cups-utils-0.6.5-1.fc6

How reproducible:
No way I can try.  This printer and machine are not local.

Comment 1 Tim Waugh 2007-03-17 10:27:12 UTC
hal-cups-utils does not remove printers -- it only adds them.  So whatever was
causing your printer queue to need reconfiguring was unlikely to have been as a
result of this traceback.  More likely the traceback is a symptom of another
problem.

The reason the error occurred is that CUPS was not running, or at least
hal_lpadmin could not connect to CUPS.  I will add some code to
hal-cups-utils/system-config-printer to handle that case (and do nothing).


Comment 2 Michal Jaegermann 2007-03-17 16:38:56 UTC
> The reason the error occurred is that CUPS was not running

AFAIK cups was running all the time.  I was not there but from
what was described to me this was an effect of taking out
an USB cable out of printer, which used to print, and plugging
in another cable instead with the other end in a different socket
on the same host.

What I know for sure, as at that moment I was already logged in,
that cups then was running (and a user would have problems to
know how to stop and start it) but in a deep funk.  It was reporting
a printer present but disabled and no amount of restarting cups or
that printer, or running cupsenable, could persuade it otherwise.
Only reconfiguring a printer with a help of system-config-printer
made it to print again.

Comment 3 Tim Waugh 2007-03-17 17:37:01 UTC
Any messages in /var/log/cups/error_log* that correlate to that moment?

Comment 4 Michal Jaegermann 2007-03-17 18:01:03 UTC
That backtrace showed up yesterday at 10:49:11.  Corresponding
fragment in /var/log/cups/error_log looks like follows:

I [16/Mar/2007:10:47:57 -0600] Full reload complete.
I [16/Mar/2007:10:47:57 -0600] Listening to 127.0.0.1:631 on fd 3...
I [16/Mar/2007:10:47:57 -0600] Listening to /var/run/cups/cups.sock on fd 4...
I [16/Mar/2007:10:48:54 -0600] Scheduler shutting down normally.
I [16/Mar/2007:10:48:54 -0600] Saving remote.cache...
I [16/Mar/2007:10:48:54 -0600] Saving job cache file "/var/cache/cups/job.cache"...
I [16/Mar/2007:10:49:45 -0600] Listening to 127.0.0.1:631 (IPv4)
I [16/Mar/2007:10:49:45 -0600] Listening to /var/run/cups/cups.sock (Domain)
I [16/Mar/2007:10:49:45 -0600] Loaded configuration file "/etc/cups/cupsd.conf"
I [16/Mar/2007:10:49:45 -0600] Using default TempDir of /var/spool/cups/tmp...
I [16/Mar/2007:10:49:45 -0600] Cleaning out old temporary files in
"/var/spool/cups/tmp"...
I [16/Mar/2007:10:49:45 -0600] Configured for up to 100 clients.
I [16/Mar/2007:10:49:45 -0600] Allowing up to 100 client connections per host.
I [16/Mar/2007:10:49:45 -0600] Using policy "default" as the default!
I [16/Mar/2007:10:49:45 -0600] Full reload is required.
I [16/Mar/2007:10:49:45 -0600] Loaded MIME database from '/etc/cups': 34 types,
38 filters...
I [16/Mar/2007:10:49:45 -0600] Loading job cache file "/var/cache/cups/job.cache"...
I [16/Mar/2007:10:49:45 -0600] Full reload complete.
I [16/Mar/2007:10:49:45 -0600] Listening to 127.0.0.1:631 on fd 3...
I [16/Mar/2007:10:49:45 -0600] Listening to /var/run/cups/cups.sock on fd 4...

In 'access_log' I have there

localhost - - [16/Mar/2007:10:47:34 -0600] "POST / HTTP/1.1" 200 196
CUPS-Get-Printers successful-ok
localhost - - [16/Mar/2007:10:49:53 -0600] "POST / HTTP/1.1" 200 196
CUPS-Get-Printers successful-ok


Comment 5 Tim Waugh 2007-03-17 18:07:40 UTC
So it had been shut down, then the cable had been re-inserted, and then it had
been started up.  I've added some code to just log a message about it if
hal_lpadmin can't connect to CUPS.

Comment 6 Michal Jaegermann 2007-03-17 18:13:00 UTC
> So it had been shut down
If that is the case then I have no idea by what it was shut down.  Definitely
not by a person who was switching that cable.

Comment 7 Fedora Update System 2007-05-21 22:43:09 UTC
Fix in update: hal-cups-utils-0.6.9-1.fc6