Bug 913564 - Use pyppd in foomatic
Summary: Use pyppd in foomatic
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: foomatic
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Zdenek Dohnal
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-02-21 13:41 UTC by Rick Richardson
Modified: 2021-04-28 04:59 UTC (History)
3 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2021-04-28 04:59:14 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
debug output - hp1020 selected (6.95 KB, text/plain)
2013-02-21 15:34 UTC, Rick Richardson
no flags Details
debug output - uri selected (6.79 KB, text/plain)
2013-02-21 15:35 UTC, Rick Richardson
no flags Details
CUPS error log (9.17 KB, text/plain)
2013-02-21 16:48 UTC, Rick Richardson
no flags Details
CUPS error log with cupsctl --debug-logging (82.48 KB, text/plain)
2013-02-21 18:08 UTC, Rick Richardson
no flags Details
Replacement /usr/share/system-config-printer/asyncipp.py file (24.76 KB, text/plain)
2013-02-22 16:09 UTC, Tim Waugh
no flags Details
debug output - asyncipp.py (7.00 KB, text/plain)
2013-02-22 16:24 UTC, Rick Richardson
no flags Details
Replacement /usr/share/system-config-printer/asyncipp.py file (25.71 KB, text/plain)
2013-03-21 15:05 UTC, Tim Waugh
no flags Details
Replacement /usr/share/system-config-printer/asyncconn.py file (9.61 KB, text/plain)
2013-03-21 15:05 UTC, Tim Waugh
no flags Details
debug output - asyncipp.py, asyncconn.py, python-cups-1.9.63-1 (11.65 KB, text/plain)
2013-03-21 15:34 UTC, Rick Richardson
no flags Details
debug output - system-config-printer-1.3.13 (18.01 KB, text/plain)
2013-04-02 14:22 UTC, Rick Richardson
no flags Details
strace 2>syscalls.txt -tt -s400 python -c 'import cups;cups.Connection().getPPDs2()' (41.75 KB, application/octet-stream)
2013-04-03 12:56 UTC, Rick Richardson
no flags Details
Output from ps axf (9.27 KB, text/plain)
2013-05-03 15:19 UTC, Rick Richardson
no flags Details
Output from /usr/lib/cups/driver/foomatic list > xxx (628.44 KB, text/plain)
2013-05-03 16:09 UTC, Rick Richardson
no flags Details

Description Rick Richardson 2013-02-21 13:41:01 UTC
system-config-printer and HP LaserJet 1020: doesn't add printer.

$ system-config-printer
Enter URI, either by selecting HP LaserJet 1020, or by typing the URI as usb:/dev/usb/lp0.
Then hit "Forward".
Then, it says "Searching", followed by "Querying", followed by "Searching".
But when it stops, "Forward" is not honored!

But the command line works:
# lpadmin -p hp1020 -v usb://HP/LaserJet%201020 -E \
            -P /usr/share/cups/model/HP-LaserJet_1020.ppd.gz

Comment 1 Tim Waugh 2013-02-21 14:05:16 UTC
Please run 'system-config-printer --debug' from a command line, and try to add the printer again.  When it fails in the same manner as described above, please paste in the output it gave.

Comment 2 Rick Richardson 2013-02-21 15:34:19 UTC
Created attachment 700602 [details]
debug output - hp1020 selected

Comment 3 Rick Richardson 2013-02-21 15:35:19 UTC
Created attachment 700603 [details]
debug output - uri selected

Comment 4 Tim Waugh 2013-02-21 16:41:29 UTC
This seems to be the issue:

Call <method 'getPPDs2' of 'cups.Connection' objects>
...failure

Does /var/log/cups/error_log show any error at the time you do that?

Comment 5 Rick Richardson 2013-02-21 16:48:00 UTC
Created attachment 700664 [details]
CUPS error log

Comment 6 Tim Waugh 2013-02-21 17:38:47 UTC
Please run the command 'cupsctl --debug-logging', then try again.  This time there will be much more in the error_log file.

Afterwards, turn off debugging with 'cupsctl --no-debug-logging'.

Comment 7 Rick Richardson 2013-02-21 18:08:56 UTC
Created attachment 700692 [details]
CUPS error log with cupsctl --debug-logging

Comment 8 Tim Waugh 2013-02-22 16:09:37 UTC
Created attachment 701241 [details]
Replacement /usr/share/system-config-printer/asyncipp.py file

Please try this replacement /usr/share/systme-config-printer/asyncipp.py file.  Run 'system-config-printer --debug' again and attach the output.  Hopefully this will give us an idea what's going wrong and why it's being handled badly.

Comment 9 Rick Richardson 2013-02-22 16:24:58 UTC
Created attachment 701254 [details]
debug output - asyncipp.py

Comment 10 Tim Waugh 2013-03-20 13:49:30 UTC
...failure (IPPError(1280, 'server-error-internal-error'))

When I artificially create this failure at the same point, I get an error message in a pop-up dialog:

CUPS server error
There was an error during the CUPS operation: 'server-error-internal-error'.

I would at least expect to see that -- did you see that message?

In any case, server-error-internal-error tells us that something else is going on, but doesn't tell us what. :-(

Are you still seeing this issue?

Comment 11 Rick Richardson 2013-03-20 15:00:31 UTC
did you see that message?
No.

Are you still seeing this issue?
Yes.

Comment 12 Tim Waugh 2013-03-21 15:05:03 UTC
Created attachment 713917 [details]
Replacement /usr/share/system-config-printer/asyncipp.py file

Comment 13 Tim Waugh 2013-03-21 15:05:33 UTC
Created attachment 713918 [details]
Replacement /usr/share/system-config-printer/asyncconn.py file

Comment 14 Tim Waugh 2013-03-21 15:07:55 UTC
Please try the above two replacement files, for asyncipp.py and asyncconn.py.  Additionally, please update python-cups to the one here:
  https://koji.fedoraproject.org/koji/buildinfo?buildID=404342
(download the appropriate python-cups-1.9.63-1.*.rpm file for your architecture and run 'yum localupdate ./python-cups-1.9.63-...' to install it)

These things, together, should provide enough information to diagnose what's going wrong.  Please run 'system-config-printer --debug' as before and attach the output.

Comment 15 Rick Richardson 2013-03-21 15:34:45 UTC
Created attachment 713939 [details]
debug output - asyncipp.py, asyncconn.py, python-cups-1.9.63-1

Comment 16 Tim Waugh 2013-04-02 13:54:28 UTC
Thanks.  I've made some changes in system-config-printer-1.3.13: please try this test update, and run with --debug again to get another run of debug output.

yum --enablerepo=updates-testing update 'system-config-printer*'

Comment 17 Rick Richardson 2013-04-02 14:22:03 UTC
Created attachment 730814 [details]
debug output - system-config-printer-1.3.13

Note: this time I got:

CUPS server error
There was an error during the CUPS operation: 'Success'.

after the "searching..." stuff.

Comment 18 Tim Waugh 2013-04-03 11:15:52 UTC
That's... weird.  I can't see any path in the code that would do that. :-/

Time to look in detail at the system calls to see if I can see what libcups is actually doing.

Please run this (it's all one line):

strace 2>syscalls.txt -tt -s400 python -c 'import cups;cups.Connection().getPPDs2()'

and then run 'gzip syscalls.txt' and attach the resulting syscalls.txt.gz you end up with.

Comment 19 Rick Richardson 2013-04-03 12:56:31 UTC
Created attachment 731140 [details]
strace 2>syscalls.txt -tt -s400 python -c 'import cups;cups.Connection().getPPDs2()'

strace 2>syscalls.txt -tt -s400 python -c 'import cups;cups.Connection().getPPDs2()'

Comment 20 Tim Waugh 2013-04-12 15:45:56 UTC
What's happening is that the libcups library is timing out while waiting for the scheduler to come up with a list of available PPDs.

Comment 21 Tim Waugh 2013-04-30 15:46:42 UTC
What does this say?:

time lpinfo -m >/dev/null
time lpinfo -m >/dev/null

(i.e. run it twice)

Comment 22 Rick Richardson 2013-04-30 15:58:02 UTC
$ time lpinfo -m >/dev/null
lpinfo: Success

real    1m0.698s
user    0m0.004s
sys     0m0.149s
$ time lpinfo -m >/dev/null
lpinfo: Success

real    1m0.450s
user    0m0.005s
sys     0m0.142s

Comment 23 Tim Waugh 2013-05-03 14:54:45 UTC
Another test to run:

1. In one terminal, run 'lpinfo -m'
2. In another terminal, wait for about 30 seconds and then run 'ps axf'

What I'm looking for is the process tree for cupsd: i.e. which programs is it still running?

Comment 24 Rick Richardson 2013-05-03 15:19:08 UTC
Created attachment 743254 [details]
Output from ps axf

Comment 25 Tim Waugh 2013-05-03 15:32:21 UTC
Thanks.  Well, it's foomatic that's taking the time.

What does this say?:

time /usr/lib/cups/driver/foomatic list >/dev/null

Comment 26 Rick Richardson 2013-05-03 15:43:19 UTC
$ time /usr/lib/cups/driver/foomatic list >/dev/null
real    1m14.627s
user    0m4.820s
sys     0m41.701s

Comment 27 Rick Richardson 2013-05-03 15:48:38 UTC
Another time:

real 1m50s

Comment 28 Tim Waugh 2013-05-03 15:56:02 UTC
Thanks.  And this?:

/usr/lib/cups/driver/foomatic list |wc -l

FWIW, 'foomatic list' takes under 2s on this machine the second time (15s the first time).

Comment 29 Rick Richardson 2013-05-03 16:05:03 UTC
3860

Comment 30 Rick Richardson 2013-05-03 16:09:15 UTC
Created attachment 743261 [details]
Output from /usr/lib/cups/driver/foomatic list > xxx

Comment 31 Tim Waugh 2013-05-08 14:12:08 UTC
This seems quite a time to be taking in syscalls:

sys     0m41.701s

That said, foomatic is slow and that's a known issue... but not one that seems to be in bugzilla at the moment.  I'll change the name of this bug to reflect that.

Comment 32 Fedora End Of Life 2013-12-21 11:35:15 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 33 Fedora Admin XMLRPC Client 2016-06-24 10:33:40 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 34 Zdenek Dohnal 2021-04-28 04:59:14 UTC
I tested the command on fully used F33 (all foomatic packages installed, 4411 foomatic drivers available) and it took 50s at the most (clean rawhide took 9s). Time consumption looks better now.

Since the classic drivers will be replaced by printer application in the future, upstream will not introduce new dependency to the project, I'm sorry.


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