[cups.general] parallel priner on sparc u5 stop working suddenly, parallel process dies
张韡武
zhangweiwu at realss.com
Sat Sep 16 06:02:36 PDT 2006
Printers are really behaving strangely these days. Yesterday my laserjet
3015 (directly connected to computer with parallel port) suddenly
stopped working (send print job, no response, gs eat up 100% CPU
resource, killing gs makes printer printed one page with nothing on it
-- white page). After restart the computer several times, the behavior
become like this:
1) send a test page;
2) nothing happens. No job in the queue.
This happens if I use either PS (ppd file from foomatic) or use PCL
(hpijs and ppd file from foomatic).
Meanwhile:
1) two other inkjet USB printers on the same computer works fine.
2) echo Hello World > /dev/lp0 result correct (printed correctly)
I also tried to decrypt the error_log, these lines looks strange:
I [16/Sep/2006:10:57:28 +0800] Started backend /usr/lib/cups/backend/parallel (PID 1929) for job 1116.
D [16/Sep/2006:10:57:28 +0800] ProcessIPPRequest: 7 status_code=0
E [16/Sep/2006:10:57:28 +0800] PID 1928 stopped with status 22!
D [16/Sep/2006:10:57:28 +0800] CloseClient: 7
My dmesg for experts:
sun ~ # dmesg | grep lp0 | grep --invert-match usb
lp0: using parport0 (interrupt-driven).
lp0: ECP mode
lp0: ECP mode
lp0: ECP mode
sab82532: receive_chars: RFOsab82532: receive_chars: RFOsab82532:
receive_chars: RFO<6>lp0: ECP mode
lp0: ECP mode
lp0: ECP mode
lp0: ECP mode
all the error_log is full of information I cannot understand, thus I
attached the error_log here (only the part since last restart cups):
I [16/Sep/2006:10:56:54 +0800] Listening to 0:631
D [16/Sep/2006:10:56:54 +0800] AddLocation: added location '/'
D [16/Sep/2006:10:56:54 +0800] DenyIP: / deny 00000000/00000000
D [16/Sep/2006:10:56:54 +0800] AllowIP: / allow 00000000/00000000
D [16/Sep/2006:10:56:54 +0800] AddLocation: added location '/admin'
D [16/Sep/2006:10:56:54 +0800] DenyIP: /admin deny 00000000/00000000
D [16/Sep/2006:10:56:54 +0800] AllowIP: /admin allow 00000000/00000000
I [16/Sep/2006:10:56:54 +0800] Loaded configuration file "/etc/cups/cupsd.conf"
I [16/Sep/2006:10:56:54 +0800] Configured for up to 100 clients.
I [16/Sep/2006:10:56:54 +0800] Allowing up to 50 client connections per host.
I [16/Sep/2006:10:56:54 +0800] Full reload is required.
D [16/Sep/2006:10:56:54 +0800] LoadAllPrinters: Loading printer epson_stylus_830...
D [16/Sep/2006:10:56:55 +0800] LoadAllPrinters: Loading printer epson_stylus_r350...
D [16/Sep/2006:10:56:55 +0800] LoadAllPrinters: Loading printer hp_laserjet_3015...
D [16/Sep/2006:10:56:55 +0800] LoadAllPrinters: Loading printer Virtual_PDF....
D [16/Sep/2006:10:56:55 +0800] LoadDevices: Added device "ipp"...
D [16/Sep/2006:10:56:55 +0800] LoadDevices: Added device "lpd"...
D [16/Sep/2006:10:56:55 +0800] LoadDevices: Added device "parallel:/dev/lp0"...
D [16/Sep/2006:10:56:55 +0800] LoadDevices: Added device "scsi"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "serial:/dev/ttyS0?baud=115200"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "serial:/dev/ttyS1?baud=115200"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "socket"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp0"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp1"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp2"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp3"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp4"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp5"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp6"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp7"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp8"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp9"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp10"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp11"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp12"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp13"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp14"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "usb:/dev/usb/lp15"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "http"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "cups-pdf:/"...
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "epson:/dev/lp0"....
D [16/Sep/2006:10:56:57 +0800] LoadDevices: Added device "canon:/dev/lp0"....
I [16/Sep/2006:10:56:57 +0800] LoadPPDs: Read "/etc/cups/ppds.dat", 3488 PPDs...
I [16/Sep/2006:10:56:58 +0800] LoadPPDs: No new or changed PPDs...
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Scanning /var/spool/cups...
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1106....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1107....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1108....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1109....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1110....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1111....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1112....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1113....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1114....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1115....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 1102....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 836....
D [16/Sep/2006:10:56:58 +0800] LoadAllJobs: Loading attributes for job 837....
I [16/Sep/2006:10:56:58 +0800] Full reload complete.
D [16/Sep/2006:10:56:58 +0800] StartListening: NumListeners=1
D [16/Sep/2006:10:56:58 +0800] StartListening: address=00000000 port=631
D [16/Sep/2006:10:56:58 +0800] ResumeListening: setting input bits...
D [16/Sep/2006:10:57:24 +0800] AcceptClient: 5 from 10.0.0.4:631.
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /printers HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] CGI /usr/lib/cups/cgi-bin/printers.cgi started - PID = 1925
I [16/Sep/2006:10:57:24 +0800] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=1925)
D [16/Sep/2006:10:57:24 +0800] SendCommand: 5 file=7
D [16/Sep/2006:10:57:24 +0800] AcceptClient: 8 from localhost:631.
D [16/Sep/2006:10:57:24 +0800] ReadClient: 8 POST / HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] ProcessIPPRequest: 8 status_code=1
D [16/Sep/2006:10:57:24 +0800] ReadClient: 8 POST / HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] ProcessIPPRequest: 8 status_code=1
D [16/Sep/2006:10:57:24 +0800] AcceptClient: 9 from 10.0.0.4:631.
D [16/Sep/2006:10:57:24 +0800] ReadClient: 9 GET /cups.css HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 9 file=10
D [16/Sep/2006:10:57:24 +0800] ReadClient: 9 GET /images/navbar.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 9 file=10
D [16/Sep/2006:10:57:24 +0800] CloseClient: 8
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /images/left.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 5 file=7
D [16/Sep/2006:10:57:24 +0800] ReadClient: 9 GET /images/right.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 9 file=8
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /images/printer-idle.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 5 file=7
D [16/Sep/2006:10:57:24 +0800] ReadClient: 9 GET /images/print-test-page.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 9 file=7
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /images/stop-printer.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 5 file=8
D [16/Sep/2006:10:57:24 +0800] ReadClient: 9 GET /images/reject-jobs.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 9 file=7
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /images/modify-printer.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 5 file=7
D [16/Sep/2006:10:57:24 +0800] ReadClient: 9 GET /images/config-printer.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 9 file=8
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /images/delete-printer.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 5 file=7
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /images/set-as-default.gif HTTP/1.1
D [16/Sep/2006:10:57:24 +0800] SendFile: 5 file=7
D [16/Sep/2006:10:57:24 +0800] ReadClient: 5 GET /images/add-printer.gif HTTP/1.1
D [16/Sep/2006:10:57:25 +0800] SendFile: 5 file=7
D [16/Sep/2006:10:57:28 +0800] ReadClient: 5 GET /printers/hp_laserjet_3015?op=print-test-page HTTP/1.1
D [16/Sep/2006:10:57:28 +0800] CGI /usr/lib/cups/cgi-bin/printers.cgi started - PID = 1926
I [16/Sep/2006:10:57:28 +0800] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=1926)
D [16/Sep/2006:10:57:28 +0800] SendCommand: 5 file=8
D [16/Sep/2006:10:57:28 +0800] AcceptClient: 7 from localhost:631.
D [16/Sep/2006:10:57:28 +0800] ReadClient: 7 POST /printers/hp_laserjet_3015 HTTP/1.1
D [16/Sep/2006:10:57:28 +0800] print_job: request file type is application/postscript.
D [16/Sep/2006:10:57:28 +0800] check_quotas: requesting-user-name = ''
D [16/Sep/2006:10:57:28 +0800] print_job: requesting-user-name = ''
D [16/Sep/2006:10:57:28 +0800] Adding default job-sheets values "none,none"....
I [16/Sep/2006:10:57:28 +0800] Adding start banner page "none" to job 1116.
I [16/Sep/2006:10:57:28 +0800] Adding end banner page "none" to job 1116.
I [16/Sep/2006:10:57:28 +0800] Job 1116 queued on 'hp_laserjet_3015' by ''.
D [16/Sep/2006:10:57:28 +0800] Job 1116 hold_until = 0
D [16/Sep/2006:10:57:28 +0800] StartJob(1116, 0xb7828)
D [16/Sep/2006:10:57:28 +0800] StartJob() id = 1116, file = 0/1
D [16/Sep/2006:10:57:28 +0800] job-sheets=none,none
D [16/Sep/2006:10:57:28 +0800] banner_page = 0
D [16/Sep/2006:10:57:28 +0800] StartJob: argv = "hp_laserjet_3015","1116","","Test Page","1","","/var/spool/cups/d01116-001"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[2]="USER=root"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[3]="CHARSET=utf-8"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[4]="LANG=en"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[5]="PPD=/etc/cups/ppd/hp_laserjet_3015.ppd"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[9]="CONTENT_TYPE=application/postscript"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[10]="DEVICE_URI=parallel:/dev/lp0"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[11]="PRINTER=hp_laserjet_3015"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[14]="CUPS_SERVER=localhost"
D [16/Sep/2006:10:57:28 +0800] StartJob: envp[15]="IPP_PORT=631"
D [16/Sep/2006:10:57:28 +0800] StartJob: statusfds = [ 10 11 ]
D [16/Sep/2006:10:57:28 +0800] StartJob: filterfds[1] = [ 12 -1 ]
D [16/Sep/2006:10:57:28 +0800] StartJob: filter = "/usr/lib/cups/filter/pstops"
D [16/Sep/2006:10:57:28 +0800] StartJob: filterfds[0] = [ 13 14 ]
D [16/Sep/2006:10:57:28 +0800] start_process("/usr/lib/cups/filter/pstops", 0xeffee9a8, 0xeffedd18, 12, 14, 11)
I [16/Sep/2006:10:57:28 +0800] Started filter /usr/lib/cups/filter/pstops (PID 1927) for job 1116.
D [16/Sep/2006:10:57:28 +0800] StartJob: filter = "/usr/lib/cups/filter/foomatic-rip"
D [16/Sep/2006:10:57:28 +0800] StartJob: filterfds[1] = [ 12 15 ]
D [16/Sep/2006:10:57:28 +0800] start_process("/usr/lib/cups/filter/foomatic-rip", 0xeffee9a8, 0xeffedd18, 13, 15, 11)
I [16/Sep/2006:10:57:28 +0800] Started filter /usr/lib/cups/filter/foomatic-rip (PID 1928) for job 1116.
D [16/Sep/2006:10:57:28 +0800] StartJob: backend = "/usr/lib/cups/backend/parallel"
D [16/Sep/2006:10:57:28 +0800] StartJob: filterfds[0] = [ -1 13 ]
D [16/Sep/2006:10:57:28 +0800] start_process("/usr/lib/cups/backend/parallel", 0xeffee9a8, 0xeffedd18, 12, 13, 11)
I [16/Sep/2006:10:57:28 +0800] Started backend /usr/lib/cups/backend/parallel (PID 1929) for job 1116.
D [16/Sep/2006:10:57:28 +0800] ProcessIPPRequest: 7 status_code=0
E [16/Sep/2006:10:57:28 +0800] PID 1928 stopped with status 22!
D [16/Sep/2006:10:57:28 +0800] CloseClient: 7
D [16/Sep/2006:10:57:28 +0800] [Job 1116] /usr/lib/cups/filter/foomatic-rip: No such file or directory
D [16/Sep/2006:10:57:28 +0800] [Job 1116] Page = 612x792; 0,0 to 612,792
D [16/Sep/2006:10:57:28 +0800] [Job 1116] slowcollate=0, slowduplex=0, sloworder=0
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%BoundingBox: 0 0 612 792
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%Pages: 1
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%LanguageLevel: 1
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%DocumentData: Clean7Bit
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%DocumentSuppliedResources: procset testprint/1.1
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%DocumentNeededResources: font Helvetica Helvetica-Bold Times-Roman
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%Creator: Michael Sweet, Easy Software Products
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%CreationDate: May 11, 1999
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%Title: Test Page
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%EndComments
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%BeginProlog
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%BeginResource procset testprint 1.1 0
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%EndResource
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%EndProlog
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%Page: 1 1
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%Page: 1 1
D [16/Sep/2006:10:57:28 +0800] [Job 1116] pw = 612.0, pl = 792.0
D [16/Sep/2006:10:57:28 +0800] [Job 1116] PageLeft = 0.0, PageRight = 612.0
D [16/Sep/2006:10:57:28 +0800] [Job 1116] PageTop = 792.0, PageBottom = 0.0
D [16/Sep/2006:10:57:28 +0800] [Job 1116] PageWidth = 612.0, PageLength = 792.0
D [16/Sep/2006:10:57:28 +0800] [Job 1116] 0 %%EOF
D [16/Sep/2006:10:57:28 +0800] [Job 1116] Saw EOF!
D [16/Sep/2006:10:57:28 +0800] UpdateJob: job 1116, file 0 is complete.
D [16/Sep/2006:10:57:28 +0800] CancelJob: id = 1116
D [16/Sep/2006:10:57:28 +0800] StopJob: id = 1116, force = 0
D [16/Sep/2006:10:57:28 +0800] StopJob: printer state is 3
D [16/Sep/2006:10:57:29 +0800] ReadClient: 9 GET /printers/hp_laserjet_3015 HTTP/1.1
D [16/Sep/2006:10:57:29 +0800] CGI /usr/lib/cups/cgi-bin/printers.cgi started - PID = 1930
I [16/Sep/2006:10:57:29 +0800] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=1930)
D [16/Sep/2006:10:57:29 +0800] SendCommand: 9 file=8
D [16/Sep/2006:10:57:29 +0800] AcceptClient: 7 from localhost:631.
D [16/Sep/2006:10:57:29 +0800] ReadClient: 7 POST / HTTP/1.1
D [16/Sep/2006:10:57:30 +0800] ProcessIPPRequest: 7 status_code=1
D [16/Sep/2006:10:57:30 +0800] ReadClient: 7 POST / HTTP/1.1
D [16/Sep/2006:10:57:30 +0800] ProcessIPPRequest: 7 status_code=1
D [16/Sep/2006:10:57:30 +0800] ReadClient: 7 POST / HTTP/1.1
D [16/Sep/2006:10:57:30 +0800] ProcessIPPRequest: 7 status_code=1
D [16/Sep/2006:10:57:30 +0800] CloseClient: 7
D [16/Sep/2006:10:57:30 +0800] ReadClient: 5 GET /images/show-completed.gif HTTP/1.1
D [16/Sep/2006:10:57:30 +0800] SendFile: 5 file=7
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 189 bytes
Desc: 这是信件的数字签名部分
URL: <https://lists.cups.org/pipermail/cups/attachments/20060916/4e5784c1/attachment.bin>
More information about the cups
mailing list