search

ghollingworth / overlayfs

Apache License 2.0
112 stars 14 forks source link

[Bug]: CUPS printing service doesn't work #10

Open Ashish7237 opened 2 years ago

Ashish7237 commented 2 years ago

Contact Details

ashish.patel7237@gmail.com

What happened?

A bug happened! I have installed HP Deskjet 1212 printer on my raspi zero. It is working fine and am able to print pdfs perfectly. However, after enabling overlayFS (making the SD card readonly) printing doesn't work. Again when I disable overlayFS (make the SD read/write) it works fine as earlier. All functions of raspi work fine when overlayFS is enabled except for printing. Enabling overlayFS is crucial for the deployment of my application. What I see in /var/log/cups/error_log is a 'filter-failed' error. I'm sure it's not the real problem as filter is working fine when overlayFS is disabled. Any help would be appreciated.

Version

1.0.2 (Default)

What browsers are you seeing the problem on?

No response

Relevant log output

E [16/Feb/2022:17:22:36 +0530] [Job 202] Job stopped due to filter errors; please consult the /var/log/cups/error_log file for details.
D [16/Feb/2022:17:22:36 +0530] [Job 202] The following messages were recorded from 05:22:31 IST to 05:22:36 IST
D [16/Feb/2022:17:22:36 +0530] [Job 202] Applying default options...
D [16/Feb/2022:17:22:36 +0530] [Job 202] Adding start banner page "none".
D [16/Feb/2022:17:22:36 +0530] [Job 202] Queued on "HP_DeskJet_1200_series" by "pi".
D [16/Feb/2022:17:22:36 +0530] [Job 202] Auto-typing file...
D [16/Feb/2022:17:22:36 +0530] [Job 202] Request file type is application/pdf.
D [16/Feb/2022:17:22:36 +0530] [Job 202] File of type application/pdf queued by "pi".
D [16/Feb/2022:17:22:36 +0530] [Job 202] Adding end banner page "none".
D [16/Feb/2022:17:22:36 +0530] [Job 202] time-at-processing=1645012351
D [16/Feb/2022:17:22:36 +0530] [Job 202] 3 filters for job:
D [16/Feb/2022:17:22:36 +0530] [Job 202] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [16/Feb/2022:17:22:36 +0530] [Job 202] gstoraster (application/vnd.cups-pdf to application/vnd.cups-raster, cost 99)
D [16/Feb/2022:17:22:36 +0530] [Job 202] hpcups (application/vnd.cups-raster to printer/HP_DeskJet_1200_series, cost 0)
D [16/Feb/2022:17:22:36 +0530] [Job 202] job-sheets=none,none
D [16/Feb/2022:17:22:36 +0530] [Job 202] argv[0]="HP_DeskJet_1200_series"
D [16/Feb/2022:17:22:36 +0530] [Job 202] argv[1]="202"
D [16/Feb/2022:17:22:36 +0530] [Job 202] argv[2]="pi"
D [16/Feb/2022:17:22:36 +0530] [Job 202] argv[3]=""
D [16/Feb/2022:17:22:36 +0530] [Job 202] argv[4]="1"
D [16/Feb/2022:17:22:36 +0530] [Job 202] argv[5]="job-uuid=urn:uuid:06ba67c7-1c7f-3fb0-5407-ca146ba9f11d job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1645012351 time-at-processing=1645012351 document-name-supplied=report.pdf"
D [16/Feb/2022:17:22:36 +0530] [Job 202] argv[6]="/var/spool/cups/d00202-001"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[7]="CUPS_STATEDIR=/run/cups"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[8]="HOME=/var/spool/cups/tmp"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[10]="SERVER_ADMIN=root@raspberrypi"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[11]="SOFTWARE=CUPS/2.2.10"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[13]="USER=root"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[14]="CUPS_MAX_MESSAGE=2047"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[17]="IPP_PORT=631"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[18]="CHARSET=utf-8"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[19]="LANG=en_IN.UTF-8"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[20]="PPD=/etc/cups/ppd/HP_DeskJet_1200_series.ppd"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[21]="RIP_MAX_CACHE=128m"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[22]="CONTENT_TYPE=application/pdf"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[23]="DEVICE_URI=usb://HP/DeskJet%201200%20series?serial=CN09K220BJ"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[24]="PRINTER_INFO=HP DeskJet 1200 series"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[25]="PRINTER_LOCATION="
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[26]="PRINTER=HP_DeskJet_1200_series"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[27]="PRINTER_STATE_REASONS=none"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[28]="CUPS_FILETYPE=document"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-raster"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[30]="AUTH_I****"
D [16/Feb/2022:17:22:36 +0530] [Job 202] Started filter /usr/lib/cups/filter/pdftopdf (PID 1488)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Started filter /usr/lib/cups/filter/gstoraster (PID 1489)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Started filter /usr/lib/cups/filter/hpcups (PID 1490)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Started backend /usr/lib/cups/backend/usb (PID 1491)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Loading USB quirks from \"/usr/share/cups/usb\".
D [16/Feb/2022:17:22:36 +0530] [Job 202] OUTFORMAT=\"(null)\", so output format will be CUPS/PWG Raster
D [16/Feb/2022:17:22:36 +0530] [Job 202] Loaded 172 quirks.
D [16/Feb/2022:17:22:36 +0530] [Job 202] Printing on printer with URI: usb://HP/DeskJet%201200%20series?serial=CN09K220BJ
D [16/Feb/2022:17:22:36 +0530] [Job 202] pdftopdf: Last filter determined by the PPD: hpcups; FINAL_CONTENT_TYPE: application/vnd.cups-raster => pdftopdf will not log pages in page_log.
D [16/Feb/2022:17:22:36 +0530] [Job 202] libusb_get_device_list=5
D [16/Feb/2022:17:22:36 +0530] [Job 202] STATE: +connecting-to-device
D [16/Feb/2022:17:22:36 +0530] [Job 202] STATE: -connecting-to-device
D [16/Feb/2022:17:22:36 +0530] [Job 202] Printer found with device ID: MFG:HP;MDL:DeskJet 1200 series;CMD:PCL3GUI,PJL,Automatic,DW-PCL,DESKJET,DYN;CLS:PRINTER;DES:7WN07D;CID:HPDeskjet_P976D;LEDMDIS:USB#07#01#02,USB#FF#04#01;SN:CN09K220BJ;S:038000C484a00001002c240003cc14001fe;Z:05000009000001,12000,17000000000000,181; Device URI: usb://HP/DeskJet%201200%20series?serial=CN09K220BJ
D [16/Feb/2022:17:22:36 +0530] [Job 202] Device protocol: 2
D [16/Feb/2022:17:22:36 +0530] [Job 202] Sending data to printer.
D [16/Feb/2022:17:22:36 +0530] [Job 202] Set job-printer-state-message to "Sending data to printer.", current level=INFO
D [16/Feb/2022:17:22:36 +0530] [Job 202] Color Manager: Calibration Mode/Off
D [16/Feb/2022:17:22:36 +0530] [Job 202] PID 1488 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [16/Feb/2022:17:22:36 +0530] [Job 202] Calling FindDeviceById(cups-HP_DeskJet_1200_series)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Found device /org/freedesktop/ColorManager/devices/cups_HP_DeskJet_1200_series
D [16/Feb/2022:17:22:36 +0530] [Job 202] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Calling FindDeviceById(cups-HP_DeskJet_1200_series)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Found device /org/freedesktop/ColorManager/devices/cups_HP_DeskJet_1200_series
D [16/Feb/2022:17:22:36 +0530] [Job 202] Calling GetProfileForQualifiers(RGB.Plain....)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Found profile /org/freedesktop/ColorManager/profiles/HP_DeskJet_1200_series_RGB__
D [16/Feb/2022:17:22:36 +0530] [Job 202] Calling org.freedesktop.ColorManager.Profile.Get(Filename)
D [16/Feb/2022:17:22:36 +0530] [Job 202] Use profile filename: \'\'
D [16/Feb/2022:17:22:36 +0530] [Job 202] Color Manager: ICC Profile:
D [16/Feb/2022:17:22:36 +0530] [Job 202] Ghostscript using Any-Part-of-Pixel method to fill paths.
D [16/Feb/2022:17:22:36 +0530] [Job 202] Ghostscript command line: gs -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dShowAcroForm -sstdout=%stderr -sOutputFile=%stdout -sDEVICE=cups -sOutputType=0 -r600x600 -dMediaPosition=1 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=841 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=17 -dcupsInteger0=26 -scupsPageSizeName=A4 -I/usr/share/cups/fonts -c \'<</.HWMargins[8.400000 41.040001 8.400024 8.400024] /Margins[0 0]>>setpagedevice\' -f -_
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[0]=\"CUPS_CACHEDIR=/var/cache/cups\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[1]=\"CUPS_DATADIR=/usr/share/cups\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[2]=\"CUPS_DOCROOT=/usr/share/cups/doc-root\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[3]=\"CUPS_FONTPATH=/usr/share/cups/fonts\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[4]=\"CUPS_REQUESTROOT=/var/spool/cups\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[5]=\"CUPS_SERVERBIN=/usr/lib/cups\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[6]=\"CUPS_SERVERROOT=/etc/cups\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[7]=\"CUPS_STATEDIR=/run/cups\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[8]=\"HOME=/var/spool/cups/tmp\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[9]=\"PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[10]=\"SERVER_ADMIN=root@raspberrypi\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[11]=\"SOFTWARE=CUPS/2.2.10\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[12]=\"TMPDIR=/var/spool/cups/tmp\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[13]=\"USER=root\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[14]=\"CUPS_MAX_MESSAGE=2047\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[15]=\"CUPS_SERVER=/run/cups/cups.sock\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[16]=\"CUPS_ENCRYPTION=IfRequested\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[17]=\"IPP_PORT=631\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[18]=\"CHARSET=utf-8\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[19]=\"LANG=en_IN.UTF-8\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[20]=\"PPD=/etc/cups/ppd/HP_DeskJet_1200_series.ppd\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[21]=\"RIP_MAX_CACHE=128m\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[22]=\"CONTENT_TYPE=application/pdf\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[23]=\"DEVICE_URI=usb://HP/DeskJet%201200%20series?serial=CN09K220BJ\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[24]=\"PRINTER_INFO=HP DeskJet 1200 series\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[25]=\"PRINTER_LOCATION=\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[26]=\"PRINTER=HP_DeskJet_1200_series\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[27]=\"PRINTER_STATE_REASONS=none\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[28]=\"CUPS_FILETYPE=document\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[29]=\"FINAL_CONTENT_TYPE=application/vnd.cups-raster\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] envp[30]=\"AUTH_INFO_REQUIRED=none\"
D [16/Feb/2022:17:22:36 +0530] [Job 202] Start rendering...
D [16/Feb/2022:17:22:36 +0530] [Job 202] Set job-printer-state-message to "Start rendering...", current level=INFO
D [16/Feb/2022:17:22:36 +0530] [Job 202] Processing page 1...
D [16/Feb/2022:17:22:36 +0530] [Job 202] Set job-printer-state-message to "Processing page 1...", current level=INFO
D [16/Feb/2022:17:22:36 +0530] [Job 202] PID 1489 (/usr/lib/cups/filter/gstoraster) stopped with status 1.
D [16/Feb/2022:17:22:36 +0530] [Job 202] Hint: Try setting the LogLevel to "debug" to find out more.
D [16/Feb/2022:17:22:36 +0530] [Job 202] prnt/hpcups/HPCupsFilter.cpp 568: cupsRasterOpen failed, fd = 0
D [16/Feb/2022:17:22:36 +0530] [Job 202] Sent 0 bytes...
D [16/Feb/2022:17:22:36 +0530] [Job 202] Waiting for read thread to exit...
D [16/Feb/2022:17:22:36 +0530] [Job 202] PID 1490 (/usr/lib/cups/filter/hpcups) stopped with status 1.
D [16/Feb/2022:17:22:36 +0530] [Job 202] Hint: Try setting the LogLevel to "debug" to find out more.
D [16/Feb/2022:17:22:36 +0530] [Job 202] PID 1491 (/usr/lib/cups/backend/usb) exited with no errors.
D [16/Feb/2022:17:22:36 +0530] [Job 202] End of messages
D [16/Feb/2022:17:22:36 +0530] [Job 202] printer-state=3(idle)
D [16/Feb/2022:17:22:36 +0530] [Job 202] printer-state-message="Filter failed"
D [16/Feb/2022:17:22:36 +0530] [Job 202] printer-state-reasons=none

Code of Conduct

ghgeiger commented 2 years ago

I would just like to comment that I have a setup nearly identical to OP's, Raspberry Pi zero W + HP 1012 connected through a usb otg cable. After reading about your bug, I was expecting to run into the same problem after running the overlay script through raspi-config, but everything worked fine from the start.

Let me know if there is any information I can provide that may help explain why mine works and yours doesn't.

I installed from a vanilla Raspberrypi OS - 32 bit - Lite install, apt update/full upgrade, installed cupsd & avahi (for airprint support), setup my printer in cups, and then enabled overlay through raspi-config & permitted the script to enable write protection on /boot.