Arch Linux

SpaghettiToastBook

Member

Registered: 2018-08-18

Posts: 3

HP Color LaserJet 1600 gets stuck processing

Whenever I attempt to print anything, it gets stuck in this state. The CUPS Web interface says "Processing — sending data to printer".

The printer itself functions just fine; when I use the buttons on the actual, physical printer to print a demo page, that has no problems. The last time I used the printer from my computer, which was about about a month ago, everything worked.

I'm using foo2hp (from the AUR package foo2zjs-nightly) to drive the printer.

The printer is connected via USB.

Here's a part of /var/log/cups/error_log. During that time I tried to print a test page from CUPS's Web interface.

Please let me know if you have any idea what's going on. Thanks!

Last edited by SpaghettiToastBook (2018-08-18 08:20:57)

zaxdan69

Member

Registered: 2016-06-04

Posts: 296

Re: HP Color LaserJet 1600 gets stuck processing

Probably is the same problem, as many other have and caused from hplip package update.
Try to downgrade hplip to 3.18.6.2 version. There is a thread about it here:
https://bbs.archlinux.org/viewtopic.php?id=239363

progandy

Member

Registered: 2012-05-17

Posts: 5,259

Re: HP Color LaserJet 1600 gets stuck processing

Did you do an update between now and the last time it worked? Was there an update for e.g. cups*, foomatic*, ghostscript, or foo2zsj-nightly?

---

| alias CUTF='LANG=en_XX.UTF-8@POSIX ' |

SpaghettiToastBook

Member

Registered: 2018-08-18

Posts: 3

Re: HP Color LaserJet 1600 gets stuck processing

Probably is the same problem, as many other have and caused from hplip package update.
Try to downgrade hplip to 3.18.6.2 version. There is a thread about it here:
https://bbs.archlinux.org/viewtopic.php?id=239363

I'm not using hplip.

Did you do an update between now and the last time it worked? Was there an update for e.g. cups*, foomatic*, ghostscript, or foo2zsj-nightly?

The last time it worked appears to be August 7. Only ghostscript had an update since then; I tried downgrading ghostscript and nothing changed.

pezcurrel

Member

Registered: 2012-06-21

Posts: 26

Re: HP Color LaserJet 1600 gets stuck processing

Same here, HP LaserJet P1102.
For now I had to resort to hplip and hplip-plugin (3.18.6, since 3.18.7 is broken, see https://bbs.archlinux.org/viewtopic.php?id=239363 ).

seth

Member

Registered: 2012-09-03

Posts: 58,687

Re: HP Color LaserJet 1600 gets stuck processing

*Only* ghostscript? At all? Please post the pacman log for the relevant time.

---

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

SpaghettiToastBook

Member

Registered: 2018-08-18

Posts: 3

Re: HP Color LaserJet 1600 gets stuck processing

Pacman log

To be clear, I only meant that ghostscript was the only package updated among those listed.

dront78

Member

From: Moscow

Registered: 2010-11-24

Posts: 47

Re: HP Color LaserJet 1600 gets stuck processing

Same here for lj1102 pro and foo2zjs
Ghostscript downgrade not helps.
Cups error log file is quite similar with no significant information

Last edited by dront78 (2018-08-30 06:32:36)

seth

Member

Registered: 2012-09-03

Posts: 58,687

Re: HP Color LaserJet 1600 gets stuck processing

Sorry, got no mail for post #7

The most likely contender is of course

[2018-08-15 23:59] [PACMAN] Running 'pacman -U --noconfirm --config /etc/pacman.conf -- /home/stb/.cache/yay/foo2zjs-nightly/foo2zjs-nightly-20180519-1-x86_64.pkg.tar.xz'
[2018-08-15 23:59] [ALPM] transaction started
[2018-08-15 23:59] [ALPM] reinstalled foo2zjs-nightly (20180519-1)

@dront78, did you also update the foo2zjs driver?

Since I also have an 1102, I'm gonna try myself as well tonight ;-)

---

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

denixx

Member

Registered: 2017-11-16

Posts: 7

Re: HP Color LaserJet 1600 gets stuck processing

Hi!
Copypasting here my problem with HP LJ P1005 from a comments page of an AUR of foo2zjs-nightly:

-= part of original message from https://aur.archlinux.org/packages/foo2 … htly/#news =-

Having issue with foo2zjs-nightly and HP LaserJet P1005.
I was using for a long time scheme like this: Raspberry Pi 3, CUPS of raspbian, connected HP LaserJet P1005 via USB.
After some mangling driver was set to "Local Raw Printer (grayscale)". This means every user which sends a job should HAVE printer driver installed and connect and send jobs to a printer using that driver locally to build print job.
So, a second part is a PC with arch which is connected to that remote printer and using foo2xqx recommended driver from this package via ipps protocol.
This scheme was working well until (as I can remember) I've posted in comments for AUR package at 2018-04-27 about getweb script and problems with proxies. 2018-07-10 I've returned to this problem, and managed to install updated foo2zjs-nightly, and some time (days or maybe weeks) after that I've tried to check if printing still works because of I needed to print smth, and figured out that I can't even print a test page via CUPS's local web-interface...
I will try to say what is looks like: I'm choosing printer in a local web-interface of CUPS (v. 2.2.8 for now). Choosing "Maintenance" - "Print Test Page" (not a "Print Self Test Page" because of a nature of a Raw driver this one is not working). The job starts, and stays in state:

pages: 3 //should be 1 page, I think
state: processing since /timestamp here/ "Connected to printer."

And after that I could see this job in a web-interfase of a CUPS (v. 1.7.5) on a Pi with this info:

state: held since /timestamp here/

At the same time a colleague with Ubuntu 17.10 is still printing without much issues (except broken printing from a Google Chrome, maybe he should do an upgrade for his OS, but that's not my problem.).
I mean he have no troubles of printing a test page using his computer.

Last edited by denixx (2018-08-30 07:08:08)

dront78

Member

From: Moscow

Registered: 2010-11-24

Posts: 47

Re: HP Color LaserJet 1600 gets stuck processing

@seth foo2zjs last release date is the middle of the May. It was working for me on July, but became broken now. I'm using my printer not very often so I can't say the exact date when it stopped printing.
In my configuration printer is attached to the router with lede/openwrt firmware and available using socket:// protocol. I can print from the my android phone using printbot app for example, but can't from ArchLinux desktop.

PS. Hplip doesn't allow me to use network printing, so it's not an option.

Last edited by dront78 (2018-08-30 08:07:25)

denixx

Member

Registered: 2017-11-16

Posts: 7

Re: HP Color LaserJet 1600 gets stuck processing

Some additional info:

/colleague_ip/ - - [30/Aug/2018:12:15:37 +0300] "POST /printers/OurPrinterName HTTP/1.1" 200 358 Validate-Job successful-ok
/colleague_ip/ - - [30/Aug/2018:12:15:37 +0300] "POST /printers/OurPrinterName HTTP/1.1" 200 314 Create-Job successful-ok
/colleague_ip/ - - [30/Aug/2018:12:15:37 +0300] "POST /printers/OurPrinterName HTTP/1.1" 200 159511 Send-Document successful-ok

This is a part of access_log of a successfully printed test page.

/my_ip/ - - [30/Aug/2018:12:27:31 +0300] "POST /printers/OurPrinterName HTTP/1.1" 200 361 Validate-Job successful-ok
/my_ip/ - - [30/Aug/2018:12:27:31 +0300] "POST /printers/OurPrinterName HTTP/1.1" 200 317 Create-Job successful-ok

without third line with "Send-Document successful-ok"

also there is a

OurPrinterName aUsername 1113 [30/Aug/2018:12:15:37 +0300] 1 1 - 10.1.196.207 /Test page/ - -

in page_log - one page of a test page of a colleague print job logged ok.

Also, there just now appeared a line in error_log:

E [30/Aug/2018:12:32:34 +0300] [Job 1114] Aborting job because it has no files.

Looks like that's mine one has aborted after 5 minutes of inactivity.

Last edited by denixx (2018-08-30 10:36:44)

denixx

Member

Registered: 2017-11-16

Posts: 7

Re: HP Color LaserJet 1600 gets stuck processing

A part of (maybe) relevant log from journalctl of arch system

aug 30 12:27:05 myhostname systemsettings5[18351]: libkcups: CUPS-Get-Printers last error: 0 successful-ok
aug 30 12:27:05 myhostname systemsettings5[18351]: libkcups: CUPS-Get-Printers last error: 0 successful-ok
aug 30 12:27:05 myhostname systemsettings5[18351]: libkcups: -1 last error: 0 successful-ok
aug 30 12:27:05 myhostname systemsettings5[18351]: libkcups: Create-Printer-Subscriptions last error: 0 successful-ok
aug 30 12:27:05 myhostname systemsettings5[18351]: libkcups: 3 "OurPrinterName"
aug 30 12:27:05 myhostname systemsettings5[18351]: libkcups: 3 "OurPrinterName"
aug 30 12:27:08 myhostname systemsettings5[18351]: KActivitiesStats( 0x5637678cfc30 ) ResultModelPrivate::onResultScoreUpdated  result added: "kcm:kcm_printer_manager.desktop" score: 6.97333 last: 1535621225 first: 1509350158
aug 30 12:27:11 myhostname systemsettings5[18351]: libkcups: CUPS-Set-Default last error: 0 successful-ok
aug 30 12:27:11 myhostname plasmashell[1475]: libkcups: "OurPrinterName is now the default printer." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 3 "none" true
aug 30 12:27:11 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:11 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:11 myhostname plasmashell[1475]: libkcups: 3 "OurPrinterName"
aug 30 12:27:11 myhostname plasmashell[1475]: libkcups: 3 "OurPrinterName"
aug 30 12:27:11 myhostname systemsettings5[18351]: libkcups: "OurPrinterName is now the default printer." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 3 "none" true
aug 30 12:27:11 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:11 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:11 myhostname systemsettings5[18351]: libkcups: 3 "OurPrinterName"
aug 30 12:27:11 myhostname systemsettings5[18351]: libkcups: 3 "OurPrinterName"
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: Creating Helper
aug 30 12:27:16 myhostname configure-printer[18366]: libkcups: CUPS-Get-Printers last error: 0 successful-ok
aug 30 12:27:16 myhostname configure-printer[18366]: void ConfigureDialog::enableButtonApply(bool) false QObject(0x0)
aug 30 12:27:16 myhostname configure-printer[18366]: kf5.kwidgetsaddons: Invalid pixmap specified.
aug 30 12:27:16 myhostname configure-printer[18366]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: CUPS_PRINTER_BW
aug 30 12:27:16 myhostname configure-printer[18366]: libkcups: CUPS-Get-Printers last error: 0 successful-ok
aug 30 12:27:16 myhostname configure-printer[18366]: kf5.kwidgetsaddons: No frame loaded
aug 30 12:27:16 myhostname configure-printer[18366]: kf5.kwidgetsaddons: No frame loaded
aug 30 12:27:16 myhostname configure-printer[18366]: kf5.kwidgetsaddons: No frame loaded
aug 30 12:27:16 myhostname configure-printer[18366]: libkcups: /tmp/5b87b87460600
aug 30 12:27:16 myhostname configure-printer[18366]: libkcups: "/tmp/5b87b87460600"
aug 30 12:27:16 myhostname configure-printer[18366]: libkcups: CUPS-Get-PPD last error: 0 successful-ok
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent true PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) 1 PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent true PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) 2 PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:16 myhostname configure-printer[18366]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x5583ebd5c1c0, name="PrinterBehavior")
aug 30 12:27:20 myhostname kwin_x11[1465]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 18737, resource id: 195035152, major code: 18 (ChangeProperty), minor code: 0
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: Creating Helper
aug 30 12:27:21 myhostname configure-printer[18377]: libkcups: CUPS-Get-Printers last error: 0 successful-ok
aug 30 12:27:21 myhostname configure-printer[18377]: void ConfigureDialog::enableButtonApply(bool) false QObject(0x0)
aug 30 12:27:21 myhostname configure-printer[18377]: kf5.kwidgetsaddons: Invalid pixmap specified.
aug 30 12:27:21 myhostname configure-printer[18377]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: CUPS_PRINTER_BW
aug 30 12:27:21 myhostname configure-printer[18377]: libkcups: CUPS-Get-Printers last error: 0 successful-ok
aug 30 12:27:21 myhostname configure-printer[18377]: kf5.kwidgetsaddons: No frame loaded
aug 30 12:27:21 myhostname configure-printer[18377]: kf5.kwidgetsaddons: No frame loaded
aug 30 12:27:21 myhostname configure-printer[18377]: kf5.kwidgetsaddons: No frame loaded
aug 30 12:27:21 myhostname configure-printer[18377]: libkcups: /tmp/5b87b879eabd3
aug 30 12:27:21 myhostname configure-printer[18377]: libkcups: "/tmp/5b87b879eabd3"
aug 30 12:27:21 myhostname configure-printer[18377]: libkcups: CUPS-Get-PPD last error: 0 successful-ok
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent true PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) 1 PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent true PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) 2 PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:21 myhostname configure-printer[18377]: pm.configure.printer: void PrinterBehavior::currentIndexChangedCB(int) isDifferent false PrinterBehavior(0x561400985890, name="PrinterBehavior")
aug 30 12:27:24 myhostname kwin_x11[1465]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 20223, resource id: 195035152, major code: 18 (ChangeProperty), minor code: 0
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: Print-Job last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: "Printer \"OurPrinterName\" state changed to processing." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: "Printer \"OurPrinterName\" state changed to processing." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "connecting-to-device" true
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "connecting-to-device" true
aug 30 12:27:27 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:27 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:29 myhostname foo2xqx-wrapper[18404]: foo2xqx-wrapper -r1200x600 -p1 -T3 -m1 -s7 -d1 -n1
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:29 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:29 myhostname foo2xqx-wrapper[18418]: gs -sPAPERSIZE=letter -g10200x6600 -r1200x600 -sDEVICE=pbmraw -dCOLORSCREEN -dMaxBitmap=500000000
aug 30 12:27:29 myhostname foo2xqx-wrapper[18419]: foo2xqx -r1200x600 -g10200x6600 -p1 -m1 -n1 -d1 -s7  -u 177x84 -l 177x84   -T3
aug 30 12:27:29 myhostname kde-print-queue[18420]: void PrintQueue::showQueue(const QString&) "OurPrinterName"
aug 30 12:27:29 myhostname kde-print-queue[18420]: libkcups: CUPS-Get-Printers last error: 0 successful-ok
aug 30 12:27:30 myhostname kde-print-queue[18420]: libkcups: Create-Printer-Subscriptions last error: 0 successful-ok
aug 30 12:27:30 myhostname kde-print-queue[18420]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:30 myhostname kde-print-queue[18420]: "OurPrinterName" "OurPrinterName"
aug 30 12:27:30 myhostname kde-print-queue[18420]: libkcups: Cancel-Subscription last error: 0 successful-ok
aug 30 12:27:30 myhostname kde-print-queue[18420]: libkcups: Create-Printer-Subscriptions last error: 0 successful-ok
aug 30 12:27:30 myhostname kde-print-queue[18420]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:30 myhostname kde-print-queue[18420]: libkcups: 1
aug 30 12:27:30 myhostname kde-print-queue[18420]: false false
aug 30 12:27:30 myhostname kde-print-queue[18420]: 4 ""
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "none"
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: 1
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: false false
aug 30 12:27:31 myhostname kde-print-queue[18420]: 4 "Подключение к принтеру"
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: false false
aug 30 12:27:31 myhostname kde-print-queue[18420]: 4 "Подключение к принтеру"
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "none"
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "OurPrinterName"
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname kde-print-queue[18420]: false false
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: 4 "Подключен к принтеру."
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: 1
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname kde-print-queue[18420]: false false
aug 30 12:27:31 myhostname kde-print-queue[18420]: 4 "Подключен к принтеру."
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: "Printer \"OurPrinterName\" state changed." "ipp://myhostname/printers/OurPrinterName" "OurPrinterName" 4 "none" true
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "none"
aug 30 12:27:31 myhostname kde-print-queue[18420]: "OurPrinterName" "OurPrinterName"
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 1
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Jobs last error: 0 successful-ok
aug 30 12:27:31 myhostname plasmashell[1475]: libkcups: 4 "OurPrinterName"
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: Get-Printer-Attributes last error: 0 successful-ok
aug 30 12:27:31 myhostname kde-print-queue[18420]: false false
aug 30 12:27:31 myhostname kde-print-queue[18420]: 4 "ready to print"
aug 30 12:27:31 myhostname kde-print-queue[18420]: libkcups: 1
aug 30 12:27:31 myhostname kde-print-queue[18420]: false false
aug 30 12:27:31 myhostname kde-print-queue[18420]: 4 "ready to print"
aug 30 12:27:31 myhostname systemsettings5[18351]: libkcups: 4 "OurPrinterName"

Last edited by denixx (2018-08-30 10:33:27)

V1del

Forum Moderator

Registered: 2012-10-16

Posts: 23,196

Re: HP Color LaserJet 1600 gets stuck processing

Please use [ code ] tags for pasting command output

denixx

Member

Registered: 2017-11-16

Posts: 7

Re: HP Color LaserJet 1600 gets stuck processing

Additional information:
If I send a job from arch, and then use "Maintenance" - "Pause printer", and after that I'm resuming it with "Resume Printer", the number of pages grows by three in a manner "+1+2".
First it grows by one page, and after some time it adds 2 pages more. So, every "pause"-"resume" adds 3 pages to held job at arch system.

denixx

Member

Registered: 2017-11-16

Posts: 7

Re: HP Color LaserJet 1600 gets stuck processing

Please use [ code ] tags for pasting command output

Sorry for that, I tried to search something like [ spoiler ].
Fixed my longpost, thanks.

seth

Member

Registered: 2012-09-03

Posts: 58,687

Re: HP Color LaserJet 1600 gets stuck processing

Printing still works, ghostscript 9.23-2 (and system generally up-to-date) but dead old foo2zjs-nightly 20171202-1 (what is about the last time I printed something ;-)
So it's most likely there - I'd suggest to try to revert the latest commit in foo2zjs-nightly, rebuild and retry again (or wait whether I find something else to print… next year or so

---

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

dront78

Member

From: Moscow

Registered: 2010-11-24

Posts: 47

Re: HP Color LaserJet 1600 gets stuck processing

any link to foo2zjs-nightly 20171202?

seth

Member

Registered: 2012-09-03

Posts: 58,687

Re: HP Color LaserJet 1600 gets stuck processing

Just keep reverting commits in the AUR git until you reach the desired version (or checkout fd5cad0a9189835f47042c1fa14cbc5ab0b28a08 which is the 20171202 commit)

---

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

pezcurrel

Member

Registered: 2012-06-21

Posts: 26

Re: HP Color LaserJet 1600 gets stuck processing

Just keep reverting commits in the AUR git until you reach the desired version (or checkout fd5cad0a9189835f47042c1fa14cbc5ab0b28a08 which is the 20171202 commit)

I tried, but the PKGBUILD always downloads the latest version

pkgver() {
   local date=$(curl -s 'http://foo2zjs.rkkda.com' | sed -nre 's|.*Tarball last modified: <i>(.+)</i>.*|\1|p')
   if ! [[ "$date" ]]; then
      error "Could not extract package last modification date '$date', please report this to the maintainer"
      return 1
   fi

   date +%Y%m%d -u -d "$date"
}

# `source` is evaluated before `pkgver()`, so a lazy downloader will not re-download the existing source file even if version changes.
# Hence, manually include `pkgver()` in the source file name so that it will be re-downloaded if version changes.
source=(
   "foo2zjs-$(pkgver).tar.gz::http://foo2zjs.rkkda.com/foo2zjs.tar.gz"
   '0001-Makefile-DESTDIR-support.patch'
   '0002-Makefile-general-fixes.patch'
   '0003-Rework-firmware-loading.patch'
   '0004-Makefile-fix-generating-.ppd-in-place.patch'
   '0005-Makefile-leverage-default-rules-as-much-as-possible-.patch'
   '0006-Makefile-do-not-blacklist-usblp-seems-unnecessary-co.patch'
)

I also want to share some tests which led me to manage to print a pdf (as prepared by cups) from the terminal; maybe this can be of interest to further understand the problem.
When I send a job, this is what cups is stuck doing ("ps -AF --forest")...

root       442     1  0 38059 10544   3 05:27 ?        00:00:00 /usr/bin/cupsd -l
cups      1487   442  0 22029 15884   3 05:38 ?        00:00:00  \_ HP_LaserJet_Professional_P1102_su_Gargantua 552 anonymous Test Page 1 job-uuid=urn:uuid:ac02187b-453e-392d-5c5a-054616f19a67 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1535859507 time-at-processing=1535859507
cups      1493  1487  0 14975  6212   0 05:38 ?        00:00:00  |   \_ pdftops 552 anonymous Test Page 1  job-uuid=urn:uuid:ac02187b-453e-392d-5c5a-054616f19a67 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1535859507 time-at-processing=1535859507 /var/spool/cups/tmp/foomatic-kqwNwc
cups      1494  1493  0 51206 27368   0 05:38 ?        00:00:00  |       \_ gs -q -dNOPAUSE -dBATCH -dSAFER -dNOMEDIAATTRS -sDEVICE=ps2write -dShowAcroForm -sOUTPUTFILE=%stdout -dLanguageLevel=3 -r300 -dCompressFonts=false -dNoT3CCITT -dNOINTERPOLATE -c save pop -f /var/spool/cups/tmp/foomatic-kqwNwc
cups      1495  1493  0 15197  6308   0 05:38 ?        00:00:00  |       \_ pdftops 552 anonymous Test Page 1  job-uuid=urn:uuid:ac02187b-453e-392d-5c5a-054616f19a67 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1535859507 time-at-processing=1535859507
cups      1488   442  0 38166  6372   3 05:38 ?        00:00:00  \_ usb://HP/LaserJet%20Professional%20P1102?serial=000000000Q87FWBPPR1a 552 anonymous Test Page 1 job-uuid=urn:uuid:ac02187b-453e-392d-5c5a-054616f19a67 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1535859507 time-at-processing=1535859507

...until I cancel the job (I waited as long as half an hour, at most). While the job is still active, as stated by others, cups web interface says "sending data" for the job; nothing gets printed, but the green led on my hp laserjet p1102 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...

gs -q -dNOPAUSE -dBATCH -dSAFER -dNOMEDIAATTRS -sDEVICE=ps2write -dShowAcroForm -sOUTPUTFILE=%stdout -dLanguageLevel=3 -r300 -dCompressFonts=false -dNoT3CCITT -dNOINTERPOLATE -c 'save pop' -f /tmp/foomatic-kqwNwc | foo2zjs-wrapper -z2 -P -L0 -r1200x600 -p9 -T3 -m1 -s7 -n1 | DEVICE_URI="usb://HP/LaserJet%20Professional%20P1102?serial=000000000Q87FWBPPR1a"  /usr/lib/cups/backend/usb 552 anonymous Test 1 fakeoption

Note that in order for this to work, the temp file you 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"...

D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/Sep/2018:06:44:08 +0200] [Client 1] Server address is "/run/cups/cups.sock".
D [02/Sep/2018:06:44:08 +0200] [Client 1] Accepted from localhost (Domain)
D [02/Sep/2018:06:44:08 +0200] [Client 1] Waiting for request.
D [02/Sep/2018:06:44:08 +0200] [Client 1] POST / HTTP/1.1
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [02/Sep/2018:06:44:08 +0200] [Client 1] Read: status=200, state=6
D [02/Sep/2018:06:44:08 +0200] [Client 1] No authentication data provided.
D [02/Sep/2018:06:44:08 +0200] [Client 1] 2.0 Get-Printer-Attributes 8
D [02/Sep/2018:06:44:08 +0200] Get-Printer-Attributes ipp://localhost:631/printers/HP_LaserJet_Professional_P1102_su_Gargantua
D [02/Sep/2018:06:44:08 +0200] [Client 1] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/HP_LaserJet_Professional_P1102_su_Gargantua) from localhost.
D [02/Sep/2018:06:44:08 +0200] [Client 1] Content-Length: 1435
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] con->http=0x555ab3182c80
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1435, response=0x555ab316abb0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [02/Sep/2018:06:44:08 +0200] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] bytes=0, http_state=0, data_remaining=1435
D [02/Sep/2018:06:44:08 +0200] [Client 1] Flushing write buffer.
D [02/Sep/2018:06:44:08 +0200] [Client 1] New state is HTTP_STATE_WAITING
D [02/Sep/2018:06:44:08 +0200] [Client 1] Waiting for request.
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/Sep/2018:06:44:08 +0200] [Client 1] POST /printers/HP_LaserJet_Professional_P1102_su_Gargantua HTTP/1.1
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/Sep/2018:06:44:08 +0200] [Client 1] Read: status=200, state=6
D [02/Sep/2018:06:44:08 +0200] [Client 1] No authentication data provided.
D [02/Sep/2018:06:44:08 +0200] [Client 1] 2.0 Get-Printer-Attributes 9
D [02/Sep/2018:06:44:08 +0200] Get-Printer-Attributes ipp://localhost/printers/HP_LaserJet_Professional_P1102_su_Gargantua
D [02/Sep/2018:06:44:08 +0200] [Client 1] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_LaserJet_Professional_P1102_su_Gargantua) from localhost.
D [02/Sep/2018:06:44:08 +0200] [Client 1] Content-Length: 421992
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] con->http=0x555ab3182c80
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=421992, response=0x555ab316a2f0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [02/Sep/2018:06:44:08 +0200] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] bytes=0, http_state=0, data_remaining=421992
D [02/Sep/2018:06:44:08 +0200] [Client 1] Flushing write buffer.
D [02/Sep/2018:06:44:08 +0200] [Client 1] New state is HTTP_STATE_WAITING
D [02/Sep/2018:06:44:08 +0200] [Client 1] Waiting for request.
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/Sep/2018:06:44:08 +0200] [Client 1] POST /printers/HP_LaserJet_Professional_P1102_su_Gargantua HTTP/1.1
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/Sep/2018:06:44:08 +0200] [Client 1] Read: status=200, state=6
D [02/Sep/2018:06:44:08 +0200] [Client 1] No authentication data provided.
D [02/Sep/2018:06:44:08 +0200] [Client 1] 2.0 Create-Job 10
D [02/Sep/2018:06:44:08 +0200] Create-Job ipp://localhost/printers/HP_LaserJet_Professional_P1102_su_Gargantua
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [02/Sep/2018:06:44:08 +0200] [Job 554] Applying default options...
D [02/Sep/2018:06:44:08 +0200] add_job: requesting-user-name="gnucco"
D [02/Sep/2018:06:44:08 +0200] Adding default job-sheets values "none,none"...
I [02/Sep/2018:06:44:08 +0200] [Job 554] Adding start banner page "none".
D [02/Sep/2018:06:44:08 +0200] Discarding unused job-created event...
I [02/Sep/2018:06:44:08 +0200] [Job 554] Queued on "HP_LaserJet_Professional_P1102_su_Gargantua" by "gnucco".
D [02/Sep/2018:06:44:08 +0200] [Client 1] Returning IPP successful-ok for Create-Job (ipp://localhost/printers/HP_LaserJet_Professional_P1102_su_Gargantua) from localhost.
D [02/Sep/2018:06:44:08 +0200] [Client 1] Content-Length: 201
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] con->http=0x555ab3182c80
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=201, response=0x555ab31782e0(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [02/Sep/2018:06:44:08 +0200] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] bytes=0, http_state=0, data_remaining=201
D [02/Sep/2018:06:44:08 +0200] [Client 1] Flushing write buffer.
D [02/Sep/2018:06:44:08 +0200] [Client 1] New state is HTTP_STATE_WAITING
D [02/Sep/2018:06:44:08 +0200] [Client 1] Waiting for request.
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/Sep/2018:06:44:08 +0200] [Client 1] POST /printers/HP_LaserJet_Professional_P1102_su_Gargantua HTTP/1.1
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/Sep/2018:06:44:08 +0200] [Client 1] Read: status=200, state=6
D [02/Sep/2018:06:44:08 +0200] [Client 1] No authentication data provided.
D [02/Sep/2018:06:44:08 +0200] [Client 1] 2.0 Send-Document 11
D [02/Sep/2018:06:44:08 +0200] [Client 1] Read: status=100, state=6
D [02/Sep/2018:06:44:08 +0200] [Client 1] Read: status=100, state=6
D [02/Sep/2018:06:44:08 +0200] Send-Document ipp://localhost:631/printers/HP_LaserJet_Professional_P1102_su_Gargantua
D [02/Sep/2018:06:44:08 +0200] cupsdIsAuthorized: requesting-user-name="gnucco"
D [02/Sep/2018:06:44:08 +0200] [Job 554] Auto-typing file...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Request file type is application/pdf.
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [02/Sep/2018:06:44:08 +0200] [Job 554] File of type application/pdf queued by "gnucco".
I [02/Sep/2018:06:44:08 +0200] [Job 554] Adding end banner page "none".
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/Sep/2018:06:44:08 +0200] [Job 554] time-at-processing=1535863448
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/Sep/2018:06:44:08 +0200] Discarding unused printer-state-changed event...
D [02/Sep/2018:06:44:08 +0200] [Job 554] 2 filters for job:
D [02/Sep/2018:06:44:08 +0200] [Job 554] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [02/Sep/2018:06:44:08 +0200] [Job 554] foomatic-rip (application/vnd.cups-pdf to printer/HP_LaserJet_Professional_P1102_su_Gargantua, cost 0)
D [02/Sep/2018:06:44:08 +0200] [Job 554] job-sheets=none,none
D [02/Sep/2018:06:44:08 +0200] [Job 554] argv[0]="HP_LaserJet_Professional_P1102_su_Gargantua"
D [02/Sep/2018:06:44:08 +0200] [Job 554] argv[1]="554"
D [02/Sep/2018:06:44:08 +0200] [Job 554] argv[2]="gnucco"
D [02/Sep/2018:06:44:08 +0200] [Job 554] argv[3]="provastampa.odt"
D [02/Sep/2018:06:44:08 +0200] [Job 554] argv[4]="1"
D [02/Sep/2018:06:44:08 +0200] [Job 554] argv[5]="InputSlot=Auto PageSize=Letter job-uuid=urn:uuid:d6e5565b-6600-3187-7334-81a19301f117 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1535863448 time-at-processing=1535863448 document-name-supplied=DhRNfu"
D [02/Sep/2018:06:44:08 +0200] [Job 554] argv[6]="/var/spool/cups/d00554-001"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[7]="CUPS_STATEDIR=/run/cups"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[8]="HOME=/var/spool/cups/tmp"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[10]="SERVER_ADMIN=root@gargantua.manuelito.lan"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[11]="SOFTWARE=CUPS/2.2.8"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[13]="USER=root"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[14]="CUPS_MAX_MESSAGE=2047"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[17]="IPP_PORT=631"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[18]="CHARSET=utf-8"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[19]="LANG=it_IT.UTF-8"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[20]="PPD=/etc/cups/ppd/HP_LaserJet_Professional_P1102_su_Gargantua.ppd"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[21]="RIP_MAX_CACHE=128m"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[22]="CONTENT_TYPE=application/pdf"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[23]="DEVICE_URI=usb://HP/LaserJet%20Professional%20P1102?serial=000000000Q87FWBPPR1a"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[24]="PRINTER_INFO=HP LaserJet Professional P1102"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[25]="PRINTER_LOCATION=Gargantua"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[26]="PRINTER=HP_LaserJet_Professional_P1102_su_Gargantua"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[27]="PRINTER_STATE_REASONS=none"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[28]="CUPS_FILETYPE=document"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [02/Sep/2018:06:44:08 +0200] [Job 554] envp[30]="AUTH_I****"
I [02/Sep/2018:06:44:08 +0200] [Job 554] Started filter /usr/lib/cups/filter/pdftopdf (PID 2253)
I [02/Sep/2018:06:44:08 +0200] [Job 554] Started filter /usr/lib/cups/filter/foomatic-rip (PID 2254)
I [02/Sep/2018:06:44:08 +0200] [Job 554] Started backend /usr/lib/cups/backend/usb (PID 2255)
D [02/Sep/2018:06:44:08 +0200] Discarding unused job-state-changed event...
D [02/Sep/2018:06:44:08 +0200] [Client 1] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/HP_LaserJet_Professional_P1102_su_Gargantua) from localhost.
D [02/Sep/2018:06:44:08 +0200] [Client 1] Content-Length: 171
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] con->http=0x555ab3182c80
D [02/Sep/2018:06:44:08 +0200] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=171, response=0x555ab316abb0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [02/Sep/2018:06:44:08 +0200] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [02/Sep/2018:06:44:08 +0200] [Client 1] bytes=0, http_state=0, data_remaining=171
D [02/Sep/2018:06:44:08 +0200] [Client 1] Flushing write buffer.
D [02/Sep/2018:06:44:08 +0200] [Client 1] New state is HTTP_STATE_WAITING
D [02/Sep/2018:06:44:08 +0200] [Client 1] Waiting for request.
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients and dirty files"
D [02/Sep/2018:06:44:08 +0200] [Job 554] pdftopdf: Last filter determined by the PPD: foomatic-rip; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Calling FindDeviceById(cups-HP_LaserJet_Professional_P1102_su_Gargantua)
D [02/Sep/2018:06:44:08 +0200] [Job 554] PAGE: 1 1
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/Sep/2018:06:44:08 +0200] Discarding unused job-progress event...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Found device /org/freedesktop/ColorManager/devices/cups_HP_LaserJet_Professional_P1102_su_Gargantua
D [02/Sep/2018:06:44:08 +0200] [Job 554] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [02/Sep/2018:06:44:08 +0200] [Job 554] \'CM Color Calibration\' Mode in SPOOLER-LESS: Off
D [02/Sep/2018:06:44:08 +0200] [Job 554] Getting input from file 
D [02/Sep/2018:06:44:08 +0200] [Job 554] foomatic-rip version 1.21.1 running...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Parsing PPD file ...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option ColorSpace
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option PageSize
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option Quality
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option Resolution
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option ImageableArea
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option PaperDimension
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option InputSlot
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option MediaType
D [02/Sep/2018:06:44:08 +0200] [Job 554] PID 2253 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option Density
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option Copies
D [02/Sep/2018:06:44:08 +0200] [Job 554] Loading USB quirks from \"/usr/share/cups/usb\".
D [02/Sep/2018:06:44:08 +0200] [Job 554] Loaded 89 quirks.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Printing on printer with URI: usb://HP/LaserJet%20Professional%20P1102?serial=000000000Q87FWBPPR1a
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option halftone
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option NupOrient
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option NupPages
D [02/Sep/2018:06:44:08 +0200] [Job 554] Added option Font
D [02/Sep/2018:06:44:08 +0200] [Job 554] Parameter Summary
D [02/Sep/2018:06:44:08 +0200] [Job 554] -----------------
D [02/Sep/2018:06:44:08 +0200] [Job 554] Spooler: cups
D [02/Sep/2018:06:44:08 +0200] [Job 554] Printer: HP_LaserJet_Professional_P1102_su_Gargantua
D [02/Sep/2018:06:44:08 +0200] [Job 554] Shell: /bin/bash
D [02/Sep/2018:06:44:08 +0200] [Job 554] PPD file: /etc/cups/ppd/HP_LaserJet_Professional_P1102_su_Gargantua.ppd
D [02/Sep/2018:06:44:08 +0200] [Job 554] ATTR file: 
D [02/Sep/2018:06:44:08 +0200] [Job 554] Printer model: HP LaserJet Pro P1102 Foomatic/foo2zjs-z2 (recommended)
D [02/Sep/2018:06:44:08 +0200] [Job 554] Job title: provastampa.odt
D [02/Sep/2018:06:44:08 +0200] [Job 554] File(s) to be printed:
D [02/Sep/2018:06:44:08 +0200] [Job 554] <STDIN>
D [02/Sep/2018:06:44:08 +0200] [Job 554] Ghostscript extra search path (\'GS_LIB\'): /usr/share/cups/fonts
D [02/Sep/2018:06:44:08 +0200] [Job 554] Printing system options:
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'job-uuid=urn:uuid:d6e5565b-6600-3187-7334-81a19301f117\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Unknown option job-uuid=urn:uuid:d6e5565b-6600-3187-7334-81a19301f117.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'job-originating-host-name=localhost\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Unknown option job-originating-host-name=localhost.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'date-time-at-creation=\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Unknown option date-time-at-creation=.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'date-time-at-processing=\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Unknown option date-time-at-processing=.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'time-at-creation=1535863448\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Unknown option time-at-creation=1535863448.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'time-at-processing=1535863448\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Unknown option time-at-processing=1535863448.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'document-name-supplied=DhRNfu\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Unknown option document-name-supplied=DhRNfu.
D [02/Sep/2018:06:44:08 +0200] [Job 554] CM Color Calibration Mode in CUPS: Off
D [02/Sep/2018:06:44:08 +0200] [Job 554] Options from the PPD file:
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'InputSlot=Auto\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] Pondering option \'PageSize=Letter\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] ================================================
D [02/Sep/2018:06:44:08 +0200] [Job 554] File: <STDIN>
D [02/Sep/2018:06:44:08 +0200] [Job 554] ================================================
D [02/Sep/2018:06:44:08 +0200] [Job 554] Filetype: PDF
D [02/Sep/2018:06:44:08 +0200] [Job 554] Neither PDF renderer command line nor Ghostscript-based renderer command line found
D [02/Sep/2018:06:44:08 +0200] [Job 554] Driver does not understand PDF input, converting to PostScript
D [02/Sep/2018:06:44:08 +0200] [Job 554] Storing temporary files in /var/spool/cups/tmp
D [02/Sep/2018:06:44:08 +0200] [Job 554] libusb_get_device_list=6
D [02/Sep/2018:06:44:08 +0200] [Job 554] Starting process \"pdf-to-ps\" (generation 1)
D [02/Sep/2018:06:44:08 +0200] [Job 554] STATE: +connecting-to-device
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/Sep/2018:06:44:08 +0200] Discarding unused printer-state-changed event...
D [02/Sep/2018:06:44:08 +0200] [Job 554] STATE: -connecting-to-device
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/Sep/2018:06:44:08 +0200] Discarding unused printer-state-changed event...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Device protocol: 2
D [02/Sep/2018:06:44:08 +0200] [Job 554] Printer does not like usblp kernel module to be re-attached after job
D [02/Sep/2018:06:44:08 +0200] [Job 554] Invio dei dati alla stampante.
D [02/Sep/2018:06:44:08 +0200] cupsdMarkDirty(---J-)
D [02/Sep/2018:06:44:08 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/Sep/2018:06:44:08 +0200] [Job 554] Set job-printer-state-message to "Invio dei dati alla stampante.", current level=INFO
D [02/Sep/2018:06:44:08 +0200] Discarding unused job-progress event...
D [02/Sep/2018:06:44:08 +0200] Discarding unused printer-state-changed event...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Printer make and model: HP HP LaserJet Professional P1102
D [02/Sep/2018:06:44:08 +0200] [Job 554] Running command line for pstops: pstops 554 gnucco provastampa.odt 1 \' InputSlot=Auto PageSize=Letter job-uuid=urn:uuid:d6e5565b-6600-3187-7334-81a19301f117 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1535863448 time-at-processing=1535863448 document-name-supplied=DhRNfu\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] No resolution information found in the PPD file.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Using image rendering resolution 300 dpi
D [02/Sep/2018:06:44:08 +0200] [Job 554] Running command line for gs: gs -q -dNOPAUSE -dBATCH -dSAFER -dNOMEDIAATTRS -sDEVICE=ps2write -dShowAcroForm -sOUTPUTFILE=%stdout -dLanguageLevel=3 -r300 -dCompressFonts=false -dNoT3CCITT -dNOINTERPOLATE -c \'save pop\' -f /var/spool/cups/tmp/foomatic-kqwNwc
D [02/Sep/2018:06:44:08 +0200] [Job 554] Started filter gs (PID 2261)
D [02/Sep/2018:06:44:08 +0200] [Job 554] Started filter pstops (PID 2262)
D [02/Sep/2018:06:44:08 +0200] [Job 554] Page = 612x792; 11,11 to 601,781
D [02/Sep/2018:06:44:08 +0200] [Job 554] slow_collate=0, slow_duplex=0, slow_order=0
D [02/Sep/2018:06:44:08 +0200] [Job 554] Before copy_comments - %!PS-Adobe-3.0
D [02/Sep/2018:06:44:08 +0200] [Job 554] %!PS-Adobe-3.0
D [02/Sep/2018:06:44:08 +0200] [Job 554] %%BoundingBox: 0 0 612 792
D [02/Sep/2018:06:44:08 +0200] [Job 554] %%HiResBoundingBox: 0 0 612.00 792.00
D [02/Sep/2018:06:44:08 +0200] [Job 554] %%Creator: GPL Ghostscript 923 (ps2write)
D [02/Sep/2018:06:44:08 +0200] [Job 554] %%LanguageLevel: 2
D [02/Sep/2018:06:44:08 +0200] [Job 554] %%CreationDate: D:20180902064408+02\'00\'
D [02/Sep/2018:06:44:08 +0200] [Job 554] %%Pages: 1
D [02/Sep/2018:06:44:08 +0200] [Job 554] %%EndComments
D [02/Sep/2018:06:44:08 +0200] [Job 554] Before copy_prolog - %%BeginProlog
D [02/Sep/2018:06:44:08 +0200] [Job 554] Filetype: PostScript
D [02/Sep/2018:06:44:08 +0200] [Job 554] Reading PostScript input ...
D [02/Sep/2018:06:44:08 +0200] [Job 554] --> This document is DSC-conforming!
D [02/Sep/2018:06:44:08 +0200] [Job 554] Found %RBINumCopies: 1
D [02/Sep/2018:06:44:08 +0200] [Job 554] -----------
D [02/Sep/2018:06:44:08 +0200] [Job 554] Found: %%BeginProlog
D [02/Sep/2018:06:44:08 +0200] [Job 554] Inserting option code into \"Prolog\" section.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Flushing FIFO.
D [02/Sep/2018:06:44:08 +0200] [Job 554] \"Prolog\" section is missing, inserting it.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Inserting option code into \"Prolog\" section.
D [02/Sep/2018:06:44:08 +0200] [Job 554] Starting renderer with command: \"foo2zjs-wrapper -z2 -P -L0     -r1200x600 -p1 -T3 -m1 -s7   -n1 \"
D [02/Sep/2018:06:44:08 +0200] [Job 554] Starting process \"kid3\" (generation 1)
D [02/Sep/2018:06:44:08 +0200] [Job 554] Closing renderer
D [02/Sep/2018:06:44:08 +0200] [Job 554] Starting process \"kid4\" (generation 2)
D [02/Sep/2018:06:44:08 +0200] [Job 554] Starting process \"renderer\" (generation 2)
D [02/Sep/2018:06:44:08 +0200] [Job 554] JCL: \033%-12345X@PJL
D [02/Sep/2018:06:44:08 +0200] [Job 554] <job data> 
D [02/Sep/2018:06:44:08 +0200] [Job 554] Not a pbm file!
D [02/Sep/2018:06:44:08 +0200] [Job 554] renderer exited with status 0
D [02/Sep/2018:06:44:08 +0200] [Job 554] Read 312 bytes of print data...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Wrote 312 bytes of print data...
D [02/Sep/2018:06:44:08 +0200] [Job 554] kid4 exited with status 0
D [02/Sep/2018:06:44:08 +0200] [Job 554] kid3 finished
D [02/Sep/2018:06:44:08 +0200] [Job 554] kid3 exited with status 0
D [02/Sep/2018:06:44:08 +0200] [Job 554] Read 56 bytes of back-channel data...
D [02/Sep/2018:06:44:08 +0200] [Job 554] Read 59 bytes of back-channel data...
D [02/Sep/2018:06:44:38 +0200] [Job 554] Read 58 bytes of back-channel data...
I [02/Sep/2018:06:44:38 +0200] Saving job.cache...
D [02/Sep/2018:06:44:38 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/Sep/2018:06:44:38 +0200] Report: clients=1
D [02/Sep/2018:06:44:38 +0200] Report: jobs=16
D [02/Sep/2018:06:44:38 +0200] Report: jobs-active=1
D [02/Sep/2018:06:44:38 +0200] Report: printers=1
D [02/Sep/2018:06:44:38 +0200] Report: stringpool-string-count=17621
D [02/Sep/2018:06:44:38 +0200] Report: stringpool-alloc-bytes=11496
D [02/Sep/2018:06:44:38 +0200] Report: stringpool-total-bytes=319600
D [02/Sep/2018:06:45:08 +0200] [Job 554] Read 58 bytes of back-channel data...

Last edited by pezcurrel (2018-09-02 07:04:47)

dront78

Member

From: Moscow

Registered: 2010-11-24

Posts: 47

Re: HP Color LaserJet 1600 gets stuck processing

Does not make any sense to revert the commits, because it always points to the same _name on web site_
Seem no previous versions exist on web.

progandy

Member

Registered: 2012-05-17

Posts: 5,259

Re: HP Color LaserJet 1600 gets stuck processing

Debian has the original sources archived:
https://packages.debian.org/sid/printer-driver-foo2zjs
https://salsa.debian.org/printing-team/foo2zjs
http://cdn-fastly.deb.debian.org/debian … f/foo2zjs/

The largest change with 20180519 is the addition of a pdf cups filter. The older  20171202 only uses postscript.

@@ -33,7 +33,8 @@
 *cupsVersion:  1.0
 *cupsManualCopies: True
 *cupsModelNumber:  2
-*cupsFilter:   "application/vnd.cups-postscript 0 foomatic-rip"
+*cupsFilter:   "application/vnd.cups-postscript 100 foomatic-rip"
+*cupsFilter:   "application/vnd.cups-pdf 0 foomatic-rip"
 *%pprRIP:        foomatic-rip other
 *ModelName:     "HP Color LaserJet 1600"
 *ShortNickName: "HP Color LaserJet 1600 foo2hp"

Last edited by progandy (2018-09-02 12:54:46)

---

| alias CUTF='LANG=en_XX.UTF-8@POSIX ' |

yellius_

Member

Registered: 2016-08-29

Posts: 4

Re: HP Color LaserJet 1600 gets stuck processing

I had the same problem. That last tip worked for me.
I downloaded from the 3rd link: http://cdn-fastly.deb.debian.org/debian … rig.tar.xz
sudo pacman -R foo2zjs-nightly
extract the archive xz -d
cd dir
make
./getweb XXXX (1600 for my printer)
sudo make install

and it magically worked. I will report to upstream as well.

dront78

Member

From: Moscow

Registered: 2010-11-24

Posts: 47

Re: HP Color LaserJet 1600 gets stuck processing

setting this in the /etc/cups/ppd/HP_LaserJet_Professional_P1102.ppd

+*cupsFilter:   "application/vnd.cups-postscript 0 foomatic-rip"
-*cupsFilter:   "application/vnd.cups-postscript 100 foomatic-rip"
-*cupsFilter:   "application/vnd.cups-pdf 0 foomatic-rip"

and

lpadmin -p HP_LaserJet_Professional_P1102 -o pdftops-renderer-default=pdftops

make my printer working again using debian foo2zjs_20171202dfsg0.orig.tar.xz driver after the cups restart.

Last edited by dront78 (2018-09-08 07:26:30)

pezcurrel

Member

Registered: 2012-06-21

Posts: 26

Re: HP Color LaserJet 1600 gets stuck processing

Recent upgrade to cups-filters 1.21.3-1 solved the issue with my hp laserjet pro p1102 (see https://github.com/OpenPrinting/cups-filters/issues/58)

Last edited by pezcurrel (2018-10-08 20:37:58)