severach
commented
6 years ago apple/cups#5396
Closed pezcurrel closed 6 years ago
severach
commented
6 years ago apple/cups#5396
zdohnal
commented
6 years ago @tillkamppeter I see similar thing in Fedora 29: Packages: cups-2.2.8 cups-filters-1.20.3 glibc-2.28
When I install printer (Canon, with ppd foomatic:Canon-imageRunner_C5185i-Postscript.ppd from foomatic) as ipp printer (by "lpadmin -p test -v ipp://hostname:631/printers/printer -m foomatic:Canon-imageRunner_C5185i-Postscript.ppd -E" or when I add it by gnome-control-center) and then send the job to it, it never prints and stays as pending-held until canceling the job. And the printer prints out following text after cancelling:
ERROR: undefined OFFENDING COMMAND: curr STACK: /InitialExtGState
Here are logs for the job (after canceling): https://paste.fedoraproject.org/paste/vknps-YyBB~IEsc~n-p1SQ
I think what connects @severach, @pezcurrel and my issues is foomatic-rip filter - it is used in all cases and symptoms are similar for our issues. And this issue started with glibc-2.28 - I'm currently trying to find actual glibc commit after which the issue began. IMHO a change in glibc influenced something in foomatic-rip filter, which causes the issue.
zdohnal
commented
6 years ago And when I print with -oraw (lp -d test -oraw test-file), file is printed - that makes me think it is really filter problem.
zdohnal
commented
6 years ago Here is the file which goes to the printer, after filtering: https://paste.fedoraproject.org/paste/eX6KaC-wBsX0KBiYGgOrjA
tillkamppeter
commented
6 years ago As the printer is receiving PostScript and not able to print it I would guess that it is some PS interpreter bug in the printer. See the README file of cups-filters for how to force the pdftops filter to use Poppler or MuPDF for generating PostScript. Does the printer print this way?
Another possibility is to use another language which the printer understands, like PCL or driverless printing (uses PDF, PWG Raster, Apple Raster, or PCLm). Do you get it to work this way?
Note that the PS file you have pasted is incomplete. Did you copy and paste it from an editor? The buffer for copy and paste can perhaps be too small.
If you rename the file to have a .txt extension (mv file.ps file.ps.txt) you can directly attach it to this bug report, without need of Pastebin.
zdohnal
commented
6 years ago File is postscript and its opening ends with: GPL Ghostscript 9.23 (2018-03-21) Copyright (C) 2018 Artifex Software, Inc. All rights reserved. This software comes with NO WARRANTY: see the file PUBLIC for details. %%[ Error handled by opdfread.ps : undefined; OffendingCommand: cur ]%%
showpage, press
to continue<<
tillkamppeter
commented
6 years ago This error is due to the case that the file is incomplete.
zdohnal
commented
6 years ago @tillkamppeter I redirected cat to fpaste, which creates pastebin. $ cat printout | fpaste
zdohnal
commented
6 years ago @tillkamppeter Isn't it incomplete because the printing didn't end? Because the job stays in pending-held state (according network traffic and logs)?
tillkamppeter
commented
6 years ago How did you extract this Postscript file?
zdohnal
commented
6 years ago @tillkamppeter I can reproduce this behavior even with file device printer (with ppd mentioned above), so when you have glibc-2.28, you can see the issue too.
zdohnal
commented
6 years ago @tillkamppeter The same way as described in https://wiki.ubuntu.com/DebuggingPrintingProblems - Getting the data which would go to the printer
tillkamppeter
commented
6 years ago OK, I will try it.
zdohnal
commented
6 years ago zdohnal
commented
6 years ago zdohnal
commented
6 years ago I told Chris Liddell about the issue and I uploaded file from /var/spool/cups/tmp/foomatic* upon his request.
severach
commented
6 years ago I think what connects @severach, @pezcurrel and my issues is foomatic-rip filter
HP LaserJet 4100 and Lexmark are printing fine with the foomatic-rip filter. The difference is that their FoomaticRIPCommandLine only contains gs which makes cups run different filters. Any printer model can be broken by changing "gs" to "/usr/bin/gs".
zdohnal
commented
6 years ago I bisected glibc commits and found out in glibc upstream commits:
2cc7bad0ae0a412e75270b - [BZ 1190] Make EOF sticky in stdio.
is the best candidate (filters work with files too, so there can be a usage of EOF).
zdohnal
commented
6 years ago severach
commented
6 years ago filters work with files too
Cups moves everything around in pipes. I think it's pipes, not files.
zdohnal
commented
6 years ago @severach yup, you're right, sorry - they're working with pipes.
tillkamppeter
commented
6 years ago But note that many filters (AFAIK also foomatic-rip) suck the whole stdin into a file before they actually start to work. And PDF (which is foomatic-rip's input format in our example) usually requires to get read completely to get processed due to the fact that the XREF table is at the end of the file.
severach
commented
6 years ago So a slight change in EOF logic makes the EOF not show up as expected and the rip doesn't go on to the next step. The Canon UFR II driver breaks like this quite often.
0xjmz
commented
6 years ago I think I also track the problem to the recent glibc update. If I execute the following code
#include <stdio.h>
#include <unistd.h>
void main(void)
{
FILE *f;
int c;
f = fopen("/etc/issue","r");
dup2(fileno(f),fileno(stdin));
while( (c=fgetc(stdin)) != EOF)
printf("%c",c);
fclose(f);
f = fopen("/etc/issue","r");
dup2(fileno(f),fileno(stdin));
while( (c=fgetc(stdin)) != EOF)
printf("%c",c);
fclose(f);
}Then in glibc 2.28 a get only one line output on old Debian box as expected two lines. The problem is the combine code of 'standard library' and 'syscalls'. The workaround which solve the problem for me at least is the following patch
diff -Naur a/filter/foomatic-rip/foomaticrip.c b/filter/foomatic-rip/foomaticrip.c
--- a/filter/foomatic-rip/foomaticrip.c 2018-08-20 22:48:20.000000000 +0200
+++ b/filter/foomatic-rip/foomaticrip.c 2018-09-11 20:08:09.542690450 +0200
@@ -585,7 +585,7 @@
jobhasjcl = 1;
write_output(buf, startpos);
}*/
- if (file != stdin)
+ /*if (file != stdin)*/
rewind(file);
if (convert) pdfconvertedtops = 0;That rewinds the 'stdin' handle (descriptor). However I think the real solution should be to get rid of the ugly combination of dup2 and stdio.
I also post this workaround on Arch forum: https://bbs.archlinux.org/viewtopic.php?id=240247
Maybe someone has a more time to prepare more comprehensive patch. Right now this workaround should works.
wifiprintguy
commented
6 years ago I'm fairly certain these printers do not support PostScript...
rickrich
commented
6 years ago I compiled the 0xjmz one line patch of foomatic-rip against a VirtualBox instance of Linux Mint 19 targeting a networked LaserJet Pro P1102W. Same thing, it does not work.
But an un-patched VirtualBox instance of Ubuntu 18.04 targeting a networked LaserJet Pro P1102W does work.
severach
commented
6 years ago The P1102 printer doesn't see any postscript. Cups generates postscript. ghostscript renders it to graphics. foo2 encodes it as ZjStream. The P1102 is caught in the quagmire because it uses a command other than gs in FoomaticRIPCommandLine.
libio/fileops.c
libio/oldfileops.c
libio/wfileops.cI trimmed the glibc diff to just these 3 files, reversed the patch, and compiled. Ricoh and Savin print fine.
https://sourceware.org/bugzilla/show_bug.cgi?id=23636
I don't think patching the filter is right. Changing pipe behavior is going to break a lot more than just printers. I see 3 glibc 2.28 bug reports on the Arch Bug Tracker. This needs to be reverted until more test cases help determine how it should be done.
rickrich
commented
6 years ago If I compile 0xjmz test program on Ubuntu 18.04, I get two lines.
If I compile 0xjmz test program on Linux Mint 18.3, I get two lines.
If I compile 0xjmz test program on Linux Mint 19, I get two lines.
If I compile 0xjmz test program on fresh Arch Linux, I get one line.
Ubuntu 18.04 and HP LaserJet Pro P1102 works. Linux Mint 18.3 and HP LaserJet Pro P1102 works. Linux Mint 19 and HP LaserJet Pro P1102 doesn't work. Arch Linux and HP LaserJet Pro P1102 doesn't work.
So, there are two problems.
0xjmz
commented
6 years ago Well, Rickrich probably your printer is using different path. If I grep -Ri dup2.*stdin source code it looks like there are more places to change. I tested the following patch
diff -Naur a/filter/foomatic-rip/foomaticrip.c b/filter/foomatic-rip/foomaticrip.c
--- a/filter/foomatic-rip/foomaticrip.c 2018-08-20 22:48:20.000000000 +0200
+++ b/filter/foomatic-rip/foomaticrip.c 2018-09-12 07:27:39.192764560 +0200
@@ -585,8 +585,7 @@
jobhasjcl = 1;
write_output(buf, startpos);
}*/
- if (file != stdin)
- rewind(file);
+ rewind(file);
if (convert) pdfconvertedtops = 0;
@@ -659,6 +658,7 @@
renderer_pid = start_system_process("pdf-to-ps", pdf2ps_cmd, &in, &out);
+ rewind(stdin);
if (dup2(fileno(out), fileno(stdin)) < 0)
rip_die(EXIT_PRNERR_NORETRY_BAD_SETTINGS,
"Couldn't dup stdout of pdf-to-ps\n");
diff -Naur a/filter/foomatic-rip/renderer.c b/filter/foomatic-rip/renderer.c
--- a/filter/foomatic-rip/renderer.c 2018-02-07 23:08:41.000000000 +0100
+++ b/filter/foomatic-rip/renderer.c 2018-09-12 07:26:38.631973662 +0200
@@ -420,6 +420,7 @@
return EXIT_PRNERR_NORETRY_BAD_SETTINGS;
}
+ rewind(stdin);
if (in && dup2(fileno(in), fileno(stdin)) < 0) {
_log("kid3: Could not dup stdin\n");
fclose(kid4in);against my printer (LaserJet P1006) and it still works. However, I agree with severach glibc should not break the userspace in such a way. The sticky EOF in stdin will break much more applications and in the worst way - silently.
severach
commented
6 years ago /etc/issue on my Arch has one text line and one blank line. That might look line one line if you're not counting carefully. /etc/issue on Manjaro has 1 text line and 2 blank lines.
Paging @barthalion
rickrich
commented
6 years ago I compiled your three line patch on Linux Mint 19, and it still didn't work. Note: Linux Mint 19 has libc6 2.27, not 2.28.
So, there are two problems.
0xjmz
commented
6 years ago Ok. In this case unfortunately you have a different problem. This patch is against glibc 2.28 and its sticky EOF commit. And as I see you get two lines (the same output twice) in above C code.
fweimer
commented
6 years ago I think I also track the problem to the recent glibc update. If I execute the following code
Is this an attempt at reimplementing freopen? I don't think this is valid; you cannot replace the underlying descriptor in this way.
0xjmz
commented
6 years ago As you can see in the patch the C code is a reimplementation what cups-filters are doing with stdin. And I think that it shouldn't combine standard library with syscalls in this way as well.
zdohnal
commented
6 years ago @0xjmz I tested the first patch on our Canon printers and it works, thanks! But as you said, other printers can take other processing path, so it can help only for some printers.
0xjmz
commented
6 years ago I'm glad to help. My guess is that the second patch make all necessary changes if the problem is with glibc that it should work on all printers. In other words if the printer worked and after upgrade to glibc 2.28 it doesn't the patch should help.
atsampson
commented
6 years ago The FreeBSD port of cups-filters has included a patch that does clearerr(stdin); after the dup2 since 2015.
0xjmz
commented
6 years ago Nice work. I hope that at this point upstream will fix that bug. On the other hand since FreeBSD has its own libc implementation the bug could appear sooner.
fweimer
commented
6 years ago FYI: glibc has declined to revert the bug fix which changed behavior:
tillkamppeter
commented
6 years ago Can someone test whether everything works again when I apply the patch from @atsampson of the BSD port?
zdohnal
commented
6 years ago @tillkamppeter I can test it for our Canon ImageRunner printers and file devices. If you request more testing, please tell me and specify what I should test.
tillkamppeter
commented
6 years ago @zdohnal I think your test on the Canon ImageRunner printers would be great. I do not know about any other specific tests needed now. Everyone else reading here and having this problem, please also test the patch with your printer(s).
0xjmz
commented
6 years ago I can confirm that it works on my printer HP LaserJet. By the way it is exactly the first patch that I sent in this thread, so it should work for people that my patch worked. The BSD guys are using 'clearerr(stdin)' instead I reused 'rewind' that is already in the code.
tillkamppeter
commented
6 years ago @0xjmz, in your last patch you add the rewind() call at three points whereas the BSD patch adds the clearerr() call only at one point. Is a rewind() or clearerr() actually needed at the given 3 points or is it enough at the one place where the BSD guys have put it? @0xjmz and @zdohnal, which patch did you actually test?
zdohnal
commented
6 years ago @tillkamppeter I tested the patch on printer with ppd from foomatic Canon ImageRunner C5185i and on file device, both works. @0xjmz IMO your patch clears EOF on file every time when processing goes into print_file(), BSD guys clear it only when file is PDF. I'm not sure if it can cause troubles for f.e. postscript file...
zdohnal
commented
6 years ago @tillkamppeter I tested both - @0xjmz's first patch and patch from BSD, both works for me.
zdohnal
commented
6 years ago @tillkamppeter I didn't test it with @0xjmz second patch.
0xjmz
commented
6 years ago Well, if you take a look at the source code (filter/foomatic-rip/foomaticrip.c) then you notice that 'clearerr' is inserted in the place where function print_file is executed recursively. Thus, STDIN will be used again. However, at the beginning of the function print_file all file descriptors are rewound except STDIN. My first patch simply removed this restriction (STDIN is rewound as well). Therefore, the clearerr(stdin) is not necessary. By the way the function clearerr is only used to clear EOF flag (rewind). The second patch however, is a clear overshoot. I just grep dup2 occurrences and added rewind just in case. So, I think that it will suffice either BSD or my first patch to make this bug go away.
tillkamppeter
commented
6 years ago Fixed in commit 64ca9c2fb5 Thank you for the bug report and the patches.
valpackett
commented
4 years ago If anyone finds this thread as the only google hit for "Read 58 bytes of back-channel data..." and if your printer has worked the last time you tried and now doesn't: the same symptom (usb backend process hanging after logging that message) can happen when something is "stuck" inside the printer's firmware or whatever.
In my case, unplugging the printer from a FreeBSD box into a Windows one also resulted in print jobs getting stuck, so turns out it's the printer and I've had to unplug it from power and plug it back in.
Hi, I'm running an up-to-date Arch Linux box with...
kernel 4.18.5 cups 2.2.8 libcups 2.2.8 cups-filters 1.21.1 ghostscript 9.23 poppler 0.67.0
...and latest foo2zjs (2018-05-19) from http://foo2zjs.rkkda.com (not the AUR - but I get the same problem with foo2zjs-nightly from the AUR). The printer no longer works since about second half of august (2018); I tried downgrading all the above packages (but the kernel) to versions which got installed before, but to no avail.
When I send a job, this is what cups is stuck doing ("ps -AF --forest")...
...until I cancel the job (I waited as long as half an hour, at most). While the job is still active cups web interface says "processing - sending data to the printer" for the job; nothing gets printed, but the green led on the printer blinks as it does when printing (so it seems it's receiving something).
As long as the job is running I have a temp file in "/var/spool/cups/tmp", in the case above it's "foomatic-kqwNwc" (see the "gs" command), which is a complete and well-formed pdf; in order to do some tests, I copied it to "/tmp" before canceling the job; then, on the terminal, piping together the above "gs" command, the "foo2zjs-wrapper" command from "/var/log/cups/error_log" (log level debug, see at the end of post), and the "/usr/lib/cups/backend/usb" command, I managed to print, ie the printer just works flawlessly...
Note that in order for this to work, the temp file one can copy from "/var/spool/cups/tmp" to "/tmp" must be set readable for the user who will run the command, then any job on the queue must be canceled, and then the printer has to be turned off and then on. Then, the command above works even subsequent times, ie it works every time until another job is queued from some applications to cups. The command works even when cups is not running (obviously).
Here comes the relevant part of "/var/log/cups/error_log"...