Re: Bug#840327: stopped working, no helpful feedback
On 10/10/16 21:22, Brian Potkin wrote:
> On Mon 10 Oct 2016 at 18:15:15 +0200, Daniel Pocock wrote:
>
>> Package: cups
>> Version: 1.7.5-11+deb8u1
>>
>> Printing had been working fine for a long time but about 20 minutes ago
>> I tried to print something and an error popup appeared in GNOME asking
>> if I wanted to diagnose the printer. My document appeared paused in the
>> queue.
>
> Printing "working fine" for a long time must indicate something to you.
> Then it stops working. How is this a bug rather than a matter for
> debian-user? Computer systems don't generally go into meltdown because
> they feel unappreciated.
>
The bug isn't because it stopped working (I got it working again anyway)
I raised a bug because I was hoping we could improve the user experience
for people who don't know how to dig around in the log files. Maybe it
should be a wishlist bug.
>> I looked at /var/log/cups/*log and found nothing about the error
>
> You had debug logging enabled?
>
>> I went to the control panel and also the CUPS web interface on port 631
>> and tried re-enabling the printer and each time I did that it failed again.
>>
>> I looked at /var/log/daemon.log and observed:
>>
>> hpcups[16590]: prnt/hpcups/HPCupsFilter.cpp 707: First raster data plane..
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 1...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 2...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 3...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 4...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 5...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 6...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 7...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 8...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 9...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 10...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 11...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 12...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 13...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 14...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 15...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 16...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 17...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 18...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 19...
>> hp[16592]: io/hpmud/jd.c 820: mdns lookup ABC123DEF.local retry 20...
>> hp[16592]: io/hpmud/jd.c 816: error timeout mdns lookup ABC123DEF.local
>> hp[16592]: io/hpmud/jd.c 93: unable to read device-id
>> hp[16592]: prnt/backend/hp.c 808: ERROR: open device failed stat=12:
>> hp:/net/HP_LaserJet_3055?zc=ABC123DEF
>
> This is a symptom indicating you have done something to the system. It
> never happened before; why should it happen now? Things don't generally
> occur out of the blue.
>
After looking more closely, I believe the root cause was a recent
firewall change that was interfering with mDNS. Tweaking the firewall
makes it work again. This hadn't been obvious because some other
devices had been able to send stuff to the printer and the printer and
the printer's web admin pages were accessible.
>> I killed the cups process and modified /etc/cups/printers.conf to change
>> the URI from:
>>
>> DeviceURI hp:/net/HP_LaserJet_3055?zc=ABC123DEF
>>
>> to something like:
>>
>> DeviceURI hp:/net/HP_LaserJet_3055?ip=192.168.1.234
>>
>>
>> and started cups again and now printing works again.
>>
>> What is really wrong here?
>
> Who knows? Having to do this is a sign of a non-optimal setup in some
> way. You are the one in charge of the system. You've not touched
> anything in the last year (or twenty minutes)?
>
>> Why did the popup not tell me the root cause of the problem? Why did I
>> have to go hunting around in the log files like this? How many
>> non-developers would be comfortable troubleshooting a problem like that
>> without more details?
>
> System administrators should always feel comfortable about trouble
> shooting. Admit it; you really love log files. :)
>
If I love log files, why would I have packaged LogAnalyzer[1] ?
As I mentioned earlier, I opened the bug report to see if there is
anything we can do to make this easier for people who are not sysadmins
or DDs. I had a colleague who saw somebody throw a printer across an
office when it wasn't working, printing outages tend to irritate people
a lot.
> I'd set up the print queue again from scratch. Maybe.
>
Neither rebooting nor recreating the print queue the same way would have
resolved this particular issue. Trying to recreate it in a different
way (using the IP instead of mDNS) may have helped.
I understand cups probably couldn't have worked out exactly what went
wrong in this case. Nonetheless, there are a few things the printing
troubleshooter could do (wishlist items):
- check for syslog messages from any source (e.g. hplip, avahi) that
have a severity >= LOG_WARN between the time the job was sent and the
time the printer went offline and make the user aware of that early on
- check the cups log to see the last time a job was successful for that
queue, check the apt/dpkg logs to see if there has been any upgrading
without a reboot
- ask the user if they added or changed any firewalls or IP settings
recently, maybe run some mDNS test
Regards,
Daniel
1. https://danielpocock.com/pruning-syslog-entries-from-mongodb
Reply to: