Bug 26996 - irq-driven printing stalls
irq-driven printing stalls
Status: CLOSED RAWHIDE
Product: Red Hat Linux
Classification: Retired
Component: kernel (Show other bugs)
7.1
i386 Linux
medium Severity medium
: ---
: ---
Assigned To: Tim Waugh
David Lawrence
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2001-02-10 17:55 EST by Daniel Hammer
Modified: 2007-04-18 12:31 EDT (History)
1 user (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2001-02-27 10:08:42 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
linux-sema.patch (1001 bytes, patch)
2001-03-01 04:24 EST, Tim Waugh
no flags Details | Diff

  None (edit)
Description Daniel Hammer 2001-02-10 17:55:10 EST
Reproducible: Always

Me again: 
1st: formating for A4 paper does not work for me (HP LaserJet 1100)
2nd: when printing out from within ghostscript it prints 3-5 pages
     and then it falls asleep and lpq gives the following:

Printer: printer@bienchen
 Queue: 2 printable jobs
 Server: pid 1286 active
 Unspooler: pid 1287 active
 Status: waiting for subserver to exit at 22:39:09.250
 Rank   Owner/ID                  Class Job Files                 Size Time
stalled(343sec) hombre@bienchen+285 A   285 /home/hombre/gv_3a8 150161
22:37:35
etc.
Comment 1 Glen Foster 2001-02-12 18:02:42 EST
We (Red Hat) should really try to resolve this before next release.
Comment 2 Tim Waugh 2001-02-13 10:14:39 EST
Regarding the stall problem, are there any interesting messages if you type
'dmesg'?
Comment 3 Crutcher Dunnavant 2001-02-15 00:04:29 EST
works for me, I just printed ~30 pages through ghostscript to test.
Reopen if you figure out how to reproduce.
Comment 4 Daniel Hammer 2001-02-18 08:39:58 EST
> Regarding the stall problem, are there any interesting messages if you type
> 'dmesg'?
no, nothing

Seems to me that this is a kernel problem; let me explain:

1.) with RH-7 and RH-7 stock kernel my printer works perfect, he 
    is correctly recognized and the driver works fine; 
    dmesg gives: 
         parport0: PC-style at 0x378 (0x778) [SPP,ECP,ECPEPP,ECPPS2]
         parport0: detected irq 7; use procfs to enable
interrupt-driven                            operation.
         parport_probe: succeeded
         parport0: Printer, Hewlett-Packard HP LaserJet 1100
         lp0: using parport0 (polling).

 2.) Even if I run with RH-7 with a rawhide kernel like 2.4.0-0.99.11
     everything works fine.

 3.) With RH "fisher" and stock kernel nothing works anymore
     (a) when booting, my lpd-deamon does not start properly
         (first /etc/rc.d/init.d/lpd restart gives a "failed" for
          "shutting down"
     (b) Installing a driver for the printer via printtool works now
         (surprisingly, since the very first time I couldn't even
          start the lpd)
         I could not print at all; when running "lpq" after "lpr something"
         I get a message like this:
           Printer: printer@bienchen 'printer'
           Queue: no printable jobs in queue
           Status: job 'cfK063bienchen.cybercable.tm.fr' removed at 19:03:27.302
     (c) under the new RH (stock) kernel "dmesg" looks as follows
          Winbond Super-IO detection, now testing ports 3F0,370,250,4E,2E ...
          Winbond chip at EFER=0x3f0 key=0x87 devid=97 devrev=73 oldid=ff
          Winbond chip type 83977TF / SMSC 97w33x/97w34x
          Winbond LPT Config: cr_30=01 60,61=0378 70=07 74=03, f0=3b
          Winbond LPT Config: active=yes, io=0x0378 irq=7, dma=3
          Winbond LPT Config: irqtype=pulsed low, high-Z, ECP fifo threshold=7
          Winbond LPT Config: Port mode=ECP and EPP-1.9
          SMSC Super-IO detection, now testing Ports 2F0, 370 ...
          0x378: FIFO is 16 bytes
          0x378: writeIntrThreshold is 9
          0x378: readIntrThreshold is 9
          0x378: PWord is 8 bits
          0x378: Interrupts are ISA-Pulses
          0x378: ECP port cfgA=0x10 cfgB=0x48
          0x378: ECP settings irq=7 dma=<none or set by other means>
          parport0: PC-style at 0x378 (0x778) [PCSPP,TRISTATE,COMPAT,EPP,ECP]
          parport0: irq 7 detected
          parport0: cpp_daisy: aa5500ff(98)
          parport0: assign_addrs: aa5500ff(98)
          parport0: faking semi-colon
          parport0: Printer, Hewlett-Packard HP
          lp0: using parport0 (polling).
          lp0: console ready

 4.) With RH "fisher" with a new kernel which I compiled with my own
     config file (made changes to default kernel-2.4.0-i686.config file)
     printing works.
     But this time I have a strange behavior like this: the printer prints
     a few pages and the hangs.
     dmesg in relevant places looks like this:
     Winbond Super-IO detection, now testing ports 3F0,370,250,4E,2E ...
     Winbond chip at EFER=0x3f0 key=0x87 devid=97 devrev=73 oldid=ff
     Winbond chip type 83977TF / SMSC 97w33x/97w34x
     Winbond LPT Config: cr_30=01 60,61=0378 70=07 74=03, f0=3b
     Winbond LPT Config: active=yes, io=0x0378 irq=7, dma=3
     Winbond LPT Config: irqtype=pulsed low, high-Z, ECP fifo threshold=7
     Winbond LPT Config: Port mode=ECP and EPP-1.9
     SMSC Super-IO detection, now testing Ports 2F0, 370 ...
     0x378: FIFO is 16 bytes
     0x378: writeIntrThreshold is 9
     0x378: readIntrThreshold is 9
     0x378: PWord is 8 bits
     0x378: Interrupts are ISA-Pulses
     0x378: ECP port cfgA=0x10 cfgB=0x48
     0x378: ECP settings irq=7 dma=<none or set by other means>
     parport0: PC-style at 0x378 (0x778) [PCSPP,TRISTATE,COMPAT,EPP,ECP]
     parport0: irq 7 detected
     parport0: cpp_daisy: aa5500ff(98)
     parport0: assign_addrs: aa5500ff(98)
     parport0: faking semi-colon
     parport0: Printer, Hewlett-Packard HP
     lp0: using parport0 (polling).
     lp0: console ready

Reported this problem partly to bug 26441. 
I even installed the whole System completely new, but it's always the same
and nothing is still solved.
Any ideas???
Comment 5 Tim Waugh 2001-02-18 11:31:44 EST
What was the configuration change that you made in order to be able to print
anything at all (i.e. the difference between (3) and (4) above)?

Could you try building a kernel with CONFIG_PARPORT_PC_SUPERIO=n please, for
comparison?
Comment 6 Daniel Hammer 2001-02-19 02:31:57 EST
> Could you try building a kernel with CONFIG_PARPORT_PC_SUPERIO=n please, for
> comparison?
O.k., built the same kernel where CONFIG_PARPORT_PC_SUPERIO is unset. 
The result is the same: after exacly 4 pages the printer hangs
  Printer: lp@localhost
   Queue: 1 printable job
   Server: pid 1154 active
   Unspooler: pid 1155 active
   Status: IF filter 'mf_wrapper' filter msg - 'gs  PID pid2=1162'
           at    07:04:06.941
   Rank   Owner/ID        Class Job Files     Size Time
   stalled(245sec) hombre@localhost+153 A  153 /home/hombre/gv_3a90 58416
         07:04:06
I went out for an hour and found then the pages in the printer. So printing
generally works, but as before odd/even side margins are very (too) big.
Have no idea, maybe the new driver does not work well(??) 'don't know.
Printed this night an a4 page which I generated from "Rusty" Russels kernel
poster tool - don't know much about the time it took but it was printed out.

If it is of interest, I could mail the kernel config file in a seperate mail.
Just drop a line to kernel@linux-sapiens.com.
Comment 7 Tim Waugh 2001-02-19 15:13:19 EST
>The result is the same: after exacly 4 pages the printer hangs

And at _that_ point, there aren't any messages like 'lp0 out of paper' in the
output from 'dmesg'?

The margins is a completely separate issue; this bug is about the stalling that
you're seeing, which seems to be entirely a kernel problem.

See if you can repeat the problem by writing directly to /dev/lp0, like:

# cat file.ps > /dev/lp0

(if the 1100 is a PostScript printer, or else you'll need to use ghostscript
first.)
Comment 8 Daniel Hammer 2001-02-20 14:25:28 EST
> at _that_ point, there aren't any messages like 'lp0 out of paper' in the
> output from 'dmesg'?
no, nothing new in 'dmesg'

> See if you can repeat the problem by writing directly to /dev/lp0, like:
> # cat file.ps > /dev/lp0
created a postscript file from a 19 line ascii test and sent it as root directly
to /dev/lp0 as shown above ... as result 5 empty sheets of paper were printed
out (they just run through the printer) ... no new 'dmesg' ... 'n nothing else
unusual (nothing new in /var/log/messages etc.)
Comment 9 Tim Waugh 2001-02-21 05:23:11 EST
So that's a different problem? (Or perhaps the printer isn't a PostScript one?)

Let's try some different parport_pc settings.  For each of the following, please
put the option line in your /etc/modules.conf, reboot, and try printing
something that normally stalls (and take the line out afterwards).

Interrupt-driven printing:
options parport_pc io=0x378 irq=7 dma=nofifo

PIO printing:
options parport_pc io=0x378 irq=7 dma=none

DMA printing:
options parport_pc io=0x378 irq=7 dma=3
Comment 10 Tim Waugh 2001-02-21 12:26:52 EST
I have more questions. :-)

I would really like to see the output of 'strace -fp nnn' where nnn is the PID
of lpd _before_ you send a print job that eventually stalls.  The whole output
will probably be huge, so just the last few hundred lines would be great.

Also I would like to see the output of 'ls -l /proc/nnn/fd' for each PID nnn
that is mentioned in the last few hundred lines of that strace output, in order
to see which file descriptor is which.

Have you tried a kernel with CONFIG_LP_CONSOLE unset?  CONFIG_LP_CONSOLE
suppresses useful debugging information for bugs like this.

Also, what does 'ps axlwww' say once the print job has stalled?

Lastly, if you do 'while :; do cat
/proc/sys/dev/parport/parport0/devices/active; done', does it ever say anything
but 'none'?

Thanks in advance for your feedback on this.  I can't reproduce this problem
here, but I've heard another report like it too.
Comment 11 Daniel Hammer 2001-02-21 14:46:00 EST
O.k., now to you last two postings:

################################################
# printing: DOES NOT WORK
#           printing stalled again after the first page
# no options in /etc/modules.conf, i.e., just
# alias parport_lowlevel parport_pc
################################################
0.) lpq after it stalled gives:
 Printer: lp@bienchen
 Queue: no printable jobs in queue
 Status: subserver pid 1022 exit status 'JFAIL' at 19:59:58.143

1.)
[root@bienchen hombre]# strace -fp 703
select(7, [5 6], NULL, NULL, {553, 150000}

2.)
[root@bienchen hombre]# ls -l /proc/703/fd
insgesamt 0
lr-x------    1 root     root           64 Feb 21 19:56 0 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:56 1 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:56 2 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:56 21 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:56 3 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:56 4 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:56 5 -> socket:[1513]
lr-x------    1 root     root           64 Feb 21 19:56 6 -> pipe:[1517]
lr-x------    1 root     root           64 Feb 21 19:56 7 -> pipe:[1509]
l-wx------    1 root     root           64 Feb 21 19:56 8 -> pipe:[1509]
l-wx------    1 root     root           64 Feb 21 19:56 9 -> pipe:[1517]

3.) from 'dmesg':
Winbond Super-IO detection, now testing ports 3F0,370,250,4E,2E ...
Winbond chip at EFER=0x3f0 key=0x87 devid=97 devrev=73 oldid=ff
Winbond chip type 83977TF / SMSC 97w33x/97w34x
Winbond LPT Config: cr_30=01 60,61=0378 70=07 74=03, f0=3b
Winbond LPT Config: active=yes, io=0x0378 irq=7, dma=3
Winbond LPT Config: irqtype=pulsed low, high-Z, ECP fifo threshold=7
Winbond LPT Config: Port mode=ECP and EPP-1.9
SMSC Super-IO detection, now testing Ports 2F0, 370 ...
0x378: FIFO is 16 bytes
0x378: writeIntrThreshold is 9
0x378: readIntrThreshold is 9
0x378: PWord is 8 bits
0x378: Interrupts are ISA-Pulses
0x378: ECP port cfgA=0x10 cfgB=0x48
0x378: ECP settings irq=7 dma=<none or set by other means>
parport0: PC-style at 0x378 (0x778) [PCSPP,TRISTATE,COMPAT,EPP,ECP]
parport0: irq 7 detected
parport0: cpp_daisy: aa5500ff(98)
parport0: assign_addrs: aa5500ff(98)
parport0: faking semi-colon
parport0: Printer, Hewlett-Packard HP
lp0: using parport0 (polling).
lp0: console ready

################################################
# Interrupt-driven printing: WORKS
# options parport_pc io=0x378 irq=7 dma=nofifo
################################################
1.)
[root@bienchen hombre]# strace -fp 703
select(7, [5 6], NULL, NULL, NULL

2.)
[root@bienchen hombre]# ls -l /proc/703/fd
insgesamt 0
lr-x------    1 root     root           64 Feb 21 19:27 0 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:27 1 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:27 2 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:27 21 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:27 3 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:27 4 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:27 5 -> socket:[1510]
lr-x------    1 root     root           64 Feb 21 19:27 6 -> pipe:[1512]
lr-x------    1 root     root           64 Feb 21 19:27 7 -> pipe:[1506]
l-wx------    1 root     root           64 Feb 21 19:27 8 -> pipe:[1506]
l-wx------    1 root     root           64 Feb 21 19:27 9 -> pipe:[1512]

3.) from 'dmesg'
0x378: FIFO is 16 bytes
0x378: writeIntrThreshold is 9
0x378: readIntrThreshold is 9
0x378: PWord is 8 bits
0x378: Interrupts are ISA-Pulses
0x378: ECP port cfgA=0x10 cfgB=0x48
0x378: ECP settings irq=7 dma=<none or set by other means>
parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP,TRISTATE,COMPAT,EPP,ECP]
parport0: cpp_daisy: aa5500ff(98)
parport0: assign_addrs: aa5500ff(98)
parport0: faking semi-colon
parport0: Printer, Hewlett-Packard HP
lp0: using parport0 (interrupt-driven).
lp0: console ready

################################################
# PIO printing: WORKS
# options parport_pc io=0x378 irq=7 dma=none
################################################
1.)
[root@bienchen hombre]# strace -fp 703
select(7, [5 6], NULL, NULL, {410, 310000}

2.)
[root@bienchen hombre]# ls -l /proc/703/fd
insgesamt 0
lr-x------    1 root     root           64 Feb 21 19:36 0 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:36 1 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:36 2 -> /dev/null
l-wx------    1 root     root           64 Feb 21 19:36 21 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:36 3 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:36 4 -> /dev/null
lrwx------    1 root     root           64 Feb 21 19:36 5 -> socket:[1511]
lr-x------    1 root     root           64 Feb 21 19:36 6 -> pipe:[1513]
lr-x------    1 root     root           64 Feb 21 19:36 7 -> pipe:[1507]
l-wx------    1 root     root           64 Feb 21 19:36 8 -> pipe:[1507]
l-wx------    1 root     root           64 Feb 21 19:36 9 -> pipe:[1513]

3.) from 'dmesg'
0x378: FIFO is 16 bytes
0x378: writeIntrThreshold is 9
0x378: readIntrThreshold is 9
0x378: PWord is 8 bits
0x378: Interrupts are ISA-Pulses
0x378: ECP port cfgA=0x10 cfgB=0x48
0x378: ECP settings irq=7 dma=<none or set by other means>
parport0: PC-style at 0x378 (0x778), irq 7, using FIFO
[PCSPP,TRISTATE,COMPAT,EPP,ECP]
parport0: cpp_daisy: aa5500ff(98)
parport0: assign_addrs: aa5500ff(98)
parport0: faking semi-colon
parport0: Printer, Hewlett-Packard HP
lp0: using parport0 (interrupt-driven).
lp0: console ready

################################################
# DMA printing: WORKS
# options parport_pc io=0x378 irq=7 dma=3
################################################
1.)
[root@bienchen hombre]# strace -fp 703
select(7, [5 6], NULL, NULL, {494, 70000}

2.)
[root@bienchen hombre]# ls -l /proc/703/fd
insgesamt 0
lr-x------    1 root     root           64 Feb 21 20:22 0 -> /dev/null
l-wx------    1 root     root           64 Feb 21 20:22 1 -> /dev/null
l-wx------    1 root     root           64 Feb 21 20:22 2 -> /dev/null
l-wx------    1 root     root           64 Feb 21 20:22 21 -> /dev/null
lrwx------    1 root     root           64 Feb 21 20:22 3 -> /dev/null
lrwx------    1 root     root           64 Feb 21 20:22 4 -> /dev/null
lrwx------    1 root     root           64 Feb 21 20:22 5 -> socket:[1510]
lr-x------    1 root     root           64 Feb 21 20:22 6 -> pipe:[1518]
lr-x------    1 root     root           64 Feb 21 20:22 7 -> pipe:[1506]
l-wx------    1 root     root           64 Feb 21 20:22 8 -> pipe:[1506]
l-wx------    1 root     root           64 Feb 21 20:22 9 -> pipe:[1518]

3.)
0x378: FIFO is 16 bytes
0x378: writeIntrThreshold is 9
0x378: readIntrThreshold is 9
0x378: PWord is 8 bits
0x378: Interrupts are ISA-Pulses
0x378: ECP port cfgA=0x10 cfgB=0x48
0x378: ECP settings irq=7 dma=<none or set by other means>
parport0: PC-style at 0x378 (0x778), irq 7, dma 3
[PCSPP,TRISTATE,COMPAT,EPP,ECP,DMA]
parport0: cpp_daisy: aa5500ff(98)
parport0: assign_addrs: aa5500ff(98)
parport0: faking semi-colon
parport0: Printer, Hewlett-Packard HP
lp0: using parport0 (interrupt-driven).
lp0: console ready
Comment 12 Tim Waugh 2001-02-22 08:22:36 EST
Okay, _that_'s weird.  So the only bit that's broken is irq-less, dma-less
printing.  That really ought to be the _most_ reliable, not the _least_!

Could you please try the following test, with options io=0x378 irq=none:

1. locate the PID of lpd
2. Run:
  strace -fp nnn 2>&1 | tee /tmp/lpd-log
    on lpd's PID
3. submit a print job that will stall
4. the strace output should go wild for a bit, and then eventually stop.  When
it stops, ctrl-C it
   and send me (twaugh@redhat.com) the output of:
  tail -500 /tmp/lpd-log

I'm trying to find out what lpd (and its children) is up to when the stall
happens.
Comment 13 Tim Waugh 2001-02-22 11:27:56 EST
Looking at the code some more, here is my best guess at what is going on.  The
fact that printing works for you with interrupts on but not with them off makes
me suspicious of the back-off polling algorithm, which, now that I look at it
again, is all wrong.

Could you please try a small change?  I would like you to comment out a line in
linux/drivers/parport/ieee1284_ops.c, line 113 I think it is:

	/* Wait longer next time. */
	wait *= 2;  <-- this line

Please change it so that it says:

	// wait *= 2;

Recompile and let me know if that changes anything.  Thanks.
Comment 14 Tim Waugh 2001-02-22 11:54:29 EST
(If that doesn't fix it, 'ls /proc/sys/dev/parport/parport0/devices' would be
useful to see.)
Comment 15 Tim Waugh 2001-02-27 10:01:49 EST
I had confirmation from another reporter that it's a down_interruptible bug
(which Andrew Morton knows about).
Comment 16 Tim Waugh 2001-02-27 10:08:33 EST
(And the back-off polling isn't all that wrong, but could use some better
comments.)
Comment 17 Tim Waugh 2001-02-28 12:24:08 EST
Should be fixed in kernel-2.4.2-0.1.7 or later.  Please re-open if not.
Comment 18 Michael K. Johnson 2001-02-28 22:39:57 EST
There is a typo, that should be 2.4.2-0.1.17 or later
Comment 19 Daniel Hammer 2001-03-01 03:53:55 EST
> There is a typo, that should be 2.4.2-0.1.17 or later
... o.k., current rawhide is 2.4.1-0.1.14 & current kernel.org is 2.4.2.
Is there another typo? Why so late?
Comment 20 Tim Waugh 2001-03-01 04:24:05 EST
If you want to just apply the patch, it's here.
Comment 21 Tim Waugh 2001-03-01 04:24:51 EST
Created attachment 11422 [details]
linux-sema.patch

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