Bug 210385

Summary: evince doesn't allow printing
Product: [Fedora] Fedora Reporter: Horst H. von Brand <vonbrand>
Component: hplipAssignee: Tim Waugh <twaugh>
Status: CLOSED CURRENTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: medium    
Version: rawhideCC: twaugh
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: i386   
OS: Linux   
Whiteboard:
Fixed In Version: F-8 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2008-01-10 08:29:54 EST Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
Bug Depends On:    
Bug Blocks: 235704    
Attachments:
Description Flags
Output of "lpoptions -p printer@quelen -l", printer is HP LaserJet 1320
none
Output of "strace -o /tmp/log -econnect,send,recv,close evince /tmp/spim.pdf"
none
Output of "lpstat -t -o"
none
Output of "lpstat -h quelen -p printer -o"
none
laptop13:/var/log/cups/error_log
none
quelen:/var/log/cups/error_log none

Description Horst H. von Brand 2006-10-11 15:33:55 EDT
Description of problem:
Opening evince on a file shows it, but the Print menu leads to a menu that has
the actual print button grayed out. On the terminal it was started from it shows:

  ** (evince:31298): WARNING **: Error result: HTTP Error in GET Success
  
  ** (evince:31298): WARNING **: Error result: HTTP Error in GET Success


Version-Release number of selected component (if applicable):
evince-0.6.0-3.fc6

How reproducible:


Steps to Reproduce:
1. evince somefile.pdf
2. Try to print
3.
  
Actual results:
Menu with grayed out print button

Expected results:
Being able to print

Additional info:
Up to date rawhide, CUPS, printer attached to another machine (it shows up and
can be selected fine from the printer list).
Comment 1 Tim Waugh 2006-12-08 06:26:03 EST
Do you still get this?  I think there was a GTK+ fix (gtk2-2.10.4-6.fc6) which
might have addressed this.
Comment 2 Horst H. von Brand 2006-12-28 12:33:12 EST
Now (evince-0.7.0-1.fc7, gtk2-2.10.6-9.fc7) I get the print dialog just fine,
but asking the file to be printed does nothing. 

My setup is this machine (notebook) hooked up to the net, and the printer is on
an x86_64 (also rawhide) machine, both cups-1.2.7-6.fc7. Printing via e.g.
lpr(1) works fine, on my Gnome desktop a printer icon shows up. With evince not
even that.
Comment 3 Horst H. von Brand 2007-01-15 10:11:40 EST
Still the same (evince-0.7.1-1.fc7, gtk2-2.10.7-2.fc7, cups-1.2.7-7.fc7).
Comment 4 Tim Waugh 2007-01-15 10:14:50 EST
The printer you want to print to, is it a raw queue?  Or, alternatively, is
there a PPD for that printer?

If you aren't sure, you can find out like this:

lpoptions -p theprinter -l

(substituting 'theprinter' with your actual destination name)
Comment 5 Horst H. von Brand 2007-01-15 11:21:52 EST
Created attachment 145582 [details]
Output of "lpoptions -p printer@quelen -l", printer is HP LaserJet 1320
Comment 6 Tim Waugh 2007-01-15 11:36:24 EST
Please try running evince under 'strace', like this:

strace -o log -econnect,send,recv,close evince

and try to print.  Once you've seen that the Print button is greyed out when it
should not be, close the print dialog, and Evince, and attach the 'log' file
here.  Thanks.
Comment 7 Horst H. von Brand 2007-01-15 12:00:15 EST
Created attachment 145586 [details]
Output of "strace -o /tmp/log -econnect,send,recv,close evince /tmp/spim.pdf"

The Print button doesn't get grayed out, it looks normal. Pressing it makes
that dialog go away, but nothing is ever sent to the printer(or even the local
CUPS, AFAICS).
Comment 8 Tim Waugh 2007-01-15 12:11:08 EST
What does 'lpstat -t -o' say?
Comment 9 Horst H. von Brand 2007-01-15 12:15:10 EST
Created attachment 145587 [details]
Output of "lpstat -t -o"
Comment 10 Tim Waugh 2007-01-15 12:28:30 EST
Your print queue has been disabled (for some reason), and that's why no jobs are
getting processed.

printer printer disabled since Fri 21 Jul 2006 01:15:33 PM CLT -
	reason unknown
printer-7               vonbrand          3072   Wed 02 Aug 2006 04:46:10 PM CLT
printer-22              vonbrand         62464   Wed 23 Aug 2006 10:17:18 AM CLT
printer-25              vonbrand        103424   Wed 23 Aug 2006 10:23:44 AM CLT
printer-26              vonbrand        103424   Wed 23 Aug 2006 10:28:38 AM CLT
printer-543             vonbrand         13312   Wed 06 Dec 2006 01:15:28 PM CLST
printer-544             vonbrand         13312   Wed 06 Dec 2006 01:15:56 PM CLST
printer-7               vonbrand          3072   Wed 02 Aug 2006 04:46:10 PM CLT
printer-22              vonbrand         62464   Wed 23 Aug 2006 10:17:18 AM CLT
printer-25              vonbrand        103424   Wed 23 Aug 2006 10:23:44 AM CLT
printer-26              vonbrand        103424   Wed 23 Aug 2006 10:28:38 AM CLT
printer-543             vonbrand         13312   Wed 06 Dec 2006 01:15:28 PM CLST
printer-544             vonbrand         13312   Wed 06 Dec 2006 01:15:56 PM CLST
Comment 11 Horst H. von Brand 2007-01-15 12:53:55 EST
That is printer, the printer in question is printer@quelen. It works just fine,
I can print via lpr(1), xpdf, OOo, print OK. And in the print dialog
printer@quelen is the selected printer.

Also note that the recent documents intended to be printed did never show up on
the queue, and no error messages ("Printer disabled" or such show up for evince:
It just acts as if the file was printed normally.
Comment 12 Tim Waugh 2007-01-15 13:19:32 EST
Ah, now that I take a closer look at the strace output I see I was in error. 
The thing is though, there is no error in submitting the job.  It is submitted
without any problem as far as evince knows:

onnect(23, {sa_family=AF_FILE, path="/var/run/cups/cups.sock"}, 26) = 0
send(23, "POST /printers/printer@quelen HT"..., 137, 0) = 137
send(23, "\1\1\0\2\0\0\0\1\1G\0\22attributes-charset\0\5"..., 631, 0) = 631
send(23, "%!PS-Adobe-3.0\n%%Creator: xpdf/p"..., 8192, 0) = 8192
send(23, "1 add 3 1 roll 2 copy add 0.5 mu"..., 8192, 0) = 8192
send(23, "f/.notdef/.notdef/.notdef/.notde"..., 8192, 0) = 8192
send(23, "FC07CF5EF5\nCF24FE2E5E31F91777206"..., 8192, 0) = 8192
send(23, "9F147832\nEA2BDFE4BAD149D8E504AC3"..., 8192, 0) = 8192
send(23, " /dagger/degree/cent/sterling/se"..., 8192, 0) = 8192
send(23, "647B90790C0BF30AE7\n68925790084D7"..., 8192, 0) = 8192
send(23, "CF69EE17\n45DFF1CAC4F4E97519ADC25"..., 8192, 0) = 8192
send(23, ") 4.765 Tj\n4.9 TJm\n(ulat) 1.537 "..., 8192, 0) = 8192
send(23, "/F6_0 1 Tf\n( ) 0.23 Tj\n[10.505 0"..., 8192, 0) = 8192
send(23, " Td\n/DeviceCMYK {} cs\n[0 0 0 1] "..., 7921, 0) = 7921
recv(23, "HTTP/1.1 200 OK\r\nDate: Mon, 15 J"..., 2048, 0) = 337
close(23)                               = 0

What does 'lpstat -h quelen -p printer -o' say?  Also, what software is running
on that machine?
Comment 13 Horst H. von Brand 2007-01-15 13:26:55 EST
Created attachment 145594 [details]
Output of "lpstat -h quelen -p printer -o"

It is strange that those ancient queue entries show up here...
Comment 14 Horst H. von Brand 2007-01-15 13:28:45 EST
Oops, quelen is x86_64, and runs Fedora rawhide, up to date (just as this
machine here, i686).
Comment 15 Tim Waugh 2007-01-15 13:34:30 EST
Perhaps you could see what effect cancelling or restarting them has? (You can
use the CUPS web interface to do this, or 'cancel -h quelen ...', or 'lp -h
quelen -H restart ...')
Comment 16 Horst H. von Brand 2007-01-15 13:49:17 EST
I tried restarting them, nothing happened. Then I cancelled them on quelen
directly, and now I get:

# lpq -P hp_LaserJet_1320_series
hp_LaserJet_1320_series is not ready
Comment 17 Tim Waugh 2007-01-16 07:11:30 EST
Well, is that queue disabled or something?
Comment 18 Horst H. von Brand 2007-01-17 15:51:11 EST
Yep, disabled. I should just delete it with all the accumulated cruft in CUPS
there...
Comment 19 Tim Waugh 2007-01-18 06:33:02 EST
Working as expected then: closing.
Comment 20 Horst H. von Brand 2007-01-18 07:57:50 EST
Nope, I misunderstood. The queue that is disabled on quelen is
hp_LaserJet_1320_series, not printer. printer works A-OK: I can print from
quelen, I can print (via lpr, from OOo, from xpdf) just fine from laptop13
(remotely). Only evince shows this bizarre behaviour.
Comment 21 Tim Waugh 2007-01-18 08:26:34 EST
What does 'lpstat -W all -h quelen -p printer -o | tail -n5' show (a) before,
and (b) after printing to printer@quelen with evince?
Comment 22 Horst H. von Brand 2007-01-18 09:14:03 EST
Both before and after it just contains:

printer-381             vonbrand        708608   Wed 10 Jan 2007 05:39:37 PM CLS
T
printer-382             vonbrand        985088   Thu 11 Jan 2007 11:49:55 AM CLS
T
printer-383             vonbrand          2048   Mon 15 Jan 2007 01:17:26 PM CLS
T
printer-384             vonbrand          4096   Wed 17 Jan 2007 10:10:23 AM CLS
T
printer-385             vonbrand        707584   Thu 18 Jan 2007 09:51:44 AM CLS
T
Comment 23 Tim Waugh 2007-01-18 09:44:27 EST
Okay, now please try the same test with this command:

lpstat -W all -o | tail -n5

Thanks.
Comment 24 Horst H. von Brand 2007-01-18 09:59:58 EST
Again, no changes:

di-27                   vonbrand         62464   Wed 23 Aug 2006 10:34:55 AM CLT
di-56                   vonbrand        148480   Wed 06 Sep 2006 03:08:27 PM CLT
di-69                   vonbrand         13312   Thu 14 Sep 2006 05:24:41 PM CLT
di-153                  vonbrand       4585472   Fri 13 Oct 2006 10:56:24 AM CLT
di-155                  vonbrand         92160   Fri 13 Oct 2006 02:22:46 PM CLT

But this gives information on another remote printer (an HP connected directly
to the net) that I very rarely use...

I've been updating rawhide since their original installs around may on laptop13,
and since march or so on quelen. Perhaps I should remove and install CUPS et al
again? (No, I'm not looking forward to doing so, it was a royal pain to set up).
Comment 25 Tim Waugh 2007-01-19 08:54:07 EST
I'd rather see if we can get to the bottom of this.

So: let's try starting again.  Make sure on quelen that the printer queue is
empty and enabled.  Then, on *both* quelen and the client machine you're running
evince on, I'd like to enable more debugging output:

1. Edit /etc/cups/cupsd.conf and change the 'LogLevel' line to read:

LogLevel debug2

2. Stop cups:

/sbin/service cups stop

3. Clear out the error_log file:

>/var/log/cups/error_log

4. Start cups again:

/sbin/service cups start

Once you've done that on *both* machines, please run this command on the client
machine laptop13 (the one you're trying evince on):

lp -dprinter@quelen /usr/share/cups/data/testprint.ps

I suppose from comment #20 that this will print correctly -- please verify
whether it does.

Next, please try printing from evince.  Wait for about a minute or so, and when
there is no print output please attach the /var/log/cups/error_log files from
(a) laptop13, and (b) quelen.

Thanks!
Comment 26 Horst H. von Brand 2007-01-19 13:58:23 EST
Created attachment 146021 [details]
laptop13:/var/log/cups/error_log
Comment 27 Horst H. von Brand 2007-01-19 13:58:59 EST
Created attachment 146022 [details]
quelen:/var/log/cups/error_log
Comment 28 Tim Waugh 2007-01-23 07:11:03 EST
The logs show a normal print process.  The data was transferred to the printer.

D [19/Jan/2007:15:51:04 -0300] [Job 386] argv[0]="printer"
D [19/Jan/2007:15:51:04 -0300] [Job 386] argv[1]="386"
D [19/Jan/2007:15:51:04 -0300] [Job 386] argv[2]="remroot"
D [19/Jan/2007:15:51:04 -0300] [Job 386] argv[3]="testprint.ps"
D [19/Jan/2007:15:51:04 -0300] [Job 386] argv[4]="1"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
argv[5]="job-uuid=urn:uuid:bcb7e045-1578-379e-4e2f-a48e51230120 lease-duration=300"
D [19/Jan/2007:15:51:04 -0300] [Job 386] argv[6]="/var/spool/cups/d00386-001"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[2]="CUPS_DOCROOT=/usr/share/doc/cups-1.2.7"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[8]="PATH=/usr/lib/cups/filter:/usr/lib64/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[9]="SERVER_ADMIN=root@quelen.inf.utfsm.cl"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[10]="SOFTWARE=CUPS/1.2.7"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[12]="USER=root"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[15]="IPP_PORT=631"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[16]="CHARSET=utf-8"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[17]="LANG=en_US"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[18]="PPD=/etc/cups/ppd/printer.ppd"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[19]="RIP_MAX_CACHE=8m"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[20]="CONTENT_TYPE=application/postscript"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[21]="DEVICE_URI=hp:/usb/hp_LaserJet_1320_series?serial=00BRGS559G1V"
D [19/Jan/2007:15:51:04 -0300] [Job 386] envp[22]="PRINTER=printer"
D [19/Jan/2007:15:51:04 -0300] [Job 386]
envp[23]="FINAL_CONTENT_TYPE=application/vnd.cups-postscript"
I [19/Jan/2007:15:51:04 -0300] Started filter /usr/lib/cups/filter/pstops (PID
20206) for job 386.
I [19/Jan/2007:15:51:04 -0300] Started backend /usr/lib/cups/backend/hp (PID
20207) for job 386.
D [19/Jan/2007:15:51:04 -0300] [Job 386] Page = 612x792; 12,12 to 600,780
D [19/Jan/2007:15:51:04 -0300] [Job 386] slow_collate=0, slow_duplex=0, slow_order=0
D [19/Jan/2007:15:51:04 -0300] [Job 386] Before copy_comments - %!PS-Adobe-3.0
D [19/Jan/2007:15:51:04 -0300] [Job 386] %!PS-Adobe-3.0
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%BoundingBox: 0 0 612 792
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%Pages: 1
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%LanguageLevel: 1
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%DocumentData: Clean7Bit
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%DocumentSuppliedResources: procset
testprint/1.2
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%DocumentNeededResources: font
Helvetica Helvetica-Bold Times-Roman
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%Creator: Michael Sweet, Easy Software
Products
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%CreationDate: D:20060114093000+0500
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%Title: Test Page
D [19/Jan/2007:15:51:04 -0300] [Job 386] %%EndComments
D [19/Jan/2007:15:51:04 -0300] [Job 386] Before copy_prolog - %%BeginProlog
D [19/Jan/2007:15:51:04 -0300] [Job 386] Before copy_setup - %%Page: 1 1
D [19/Jan/2007:15:51:04 -0300] [Job 386] Before page loop - %%Page: 1 1
D [19/Jan/2007:15:51:04 -0300] [Job 386] Copying page 1...
d [19/Jan/2007:15:51:04 -0300] [Job 386] PAGE: 1 1
D [19/Jan/2007:15:51:05 -0300] [Job 386] pagew = 587.8, pagel = 767.8
D [19/Jan/2007:15:51:05 -0300] [Job 386] bboxw = 612, bboxl = 792
D [19/Jan/2007:15:51:05 -0300] [Job 386] PageLeft = 12.0, PageRight = 599.8
D [19/Jan/2007:15:51:05 -0300] [Job 386] PageTop = 779.8, PageBottom = 12.0
D [19/Jan/2007:15:51:05 -0300] [Job 386] PageWidth = 612.0, PageLength = 792.0
D [19/Jan/2007:15:51:05 -0300] [Job 386] Wrote 1 pages...
D [19/Jan/2007:15:51:05 -0300] PID 20206 (/usr/lib/cups/filter/pstops) exited
with no errors.
I [19/Jan/2007:15:51:15 -0300] [Job 386] ready to print
D [19/Jan/2007:15:51:16 -0300] PID 20207 (/usr/lib/cups/backend/hp) exited with
no errors.
D [19/Jan/2007:15:51:16 -0300] [Job 386] File 0 is complete.

Did the printer do anything at all?  Flash any lights?
Comment 29 Horst H. von Brand 2007-01-23 13:03:27 EST
Nope. The printer shows an amber light when data arrives, nothing of that sort.
AFAICS, the data never even arrives at quelen. I don't see jobs hanging around
there, the last completed job number doesn't increase.
Comment 30 Horst H. von Brand 2007-01-23 13:21:09 EST
OK, just double-checked. I'm printing a document on quelen (here 612, there
389). I sent something to print from evince here. lpstat -t says nothing about
the new job, either on laptop13 or on quelen.
Comment 31 Tim Waugh 2007-01-23 13:29:37 EST
It certainly arrives at quelen -- all of the log quoted in comment #28 comes
from the quelen log file.
Comment 32 Horst H. von Brand 2007-01-26 12:43:48 EST
AFAICS, it doesn't even arrive at the local queue in laptop13. The printer icon
in Gnome (which shows up whenever I print something, by whatever means) doesn't
show up. The job numbers don't increase.

Please note that the successful print job you comment on in #28 is testpage.ps
(which you asked me to print out), not what I tried to print via evince
(spim.pdf, IIRC).
Comment 33 Horst H. von Brand 2007-01-26 15:36:29 EST
Sorry, but I'm leaving for vacations now. I might come by to check things in the
next few weeks, no promises.
Comment 34 Tim Waugh 2007-05-09 12:58:01 EDT
This, from the laptop13 log, shows the point at which laptop13 hands off the job
to quelen:

N [19/Jan/2007:15:51:04 -0300] [Job 609] Print file accepted - job ID 386.
Comment 35 Tim Waugh 2007-06-11 05:58:34 EDT
Do you still see this problem?
Comment 36 Horst H. von Brand 2007-07-17 11:37:08 EDT
Today (evince-0.9.2-1.fc8, cups-1.2.12-1.fc8) I was able to print to a remote
networked printer. Currently printing on quelen is totally busted (see bz 245785).
Comment 37 Tim Waugh 2008-01-10 08:29:54 EST
Horst: what's the current situation with this, now that bug #245785 is closed? 
I think it's all working now, but if not please re-open this bug report.
Comment 38 Horst H. von Brand 2008-01-10 12:21:56 EST
Just tried printing here (after a _long_ time), and it now works fine. Setup is
i686 client, printer on x86_64, both rawhide up to date.

Thanks!