[Printing-architecture] Communication between IPP printer and "ipp" CUPS backend

[Printing-architecture] Communication between IPP printer and "ipp" CUPS backend

[Till Kamppeter]

[ Cross-posting because I do not know ehich list is the better for
   this ]

Hi,

I have overtaken maintainership on the ippusbxd IPP-over-USB support 
daemon (hosted now here: https://github.com/tillkamppeter/ippusbxd/).

Now I have done several tests and bug fixes using the HP DeskJet Ink 
Advantage 2540, a USB multi-function device which also does IPP via WiFi 
and via IPP-over-USB.

The printer prints reliably via WiFi, conventional USB (using "hp" 
backend of HPLIP) and when doing IPP-over-USB but printing with ipptool 
and not with the "ipp" CUPS backend. With the "ipp" CUPS backend I can 
print something like 3 or 4 one-page LibreOffice jobs and then the 
printer stops working, whereas with ipptool I do not get it stopping. It 
prints and prints and prints, ...

The difference between the "ipp" backend and ipptool is what 
communication happens between the client and the printer. ipptool sends 
the job without any other communication in parallel until the job is 
completely sent out and the answer (with job URI/ID) is received. The 
"ipp" tool does a lot of conversations in parallel, like checking the 
progress of the job, the ink levels, ... I have already tried to add 
"&waitjob=false" to the device URI for using the "ipp" backend, making 
the backend stop as soon as the job is sent and communicate less this 
way, but I still get the printer stopping in a middle of a job.

By the way, command line of ipptool is

ipptool ipp://localhost:60000/ipp/print -d 
filetype=application/octet-stream -d filename=`pwd`/printout-bashrc.gz 
print-job.test

The file printout-bashrc.gz is the result of printing ~/.bashrc with 
CUPS and HPLIP but capturing the output into a file and "gzip"ping it.

In the "ipp" backend case I use an HPLIP-PPD-based CUPS queue with a 
device URI like

ipp://localhost:60000/ipp/print

or

ipp://localhost:60000/ipp/print&waitjob=false

In both cases ippusbxd is binding to port 60000 on localhost on both 
IPv4 and IPv6, running with the command line

./ippusbxd -d -v 03f0 -m c211 -s BR54BFB02C05XK -P 60000 2>&1 | tee log

The codes after -v, -m, and -s are printer specific, they are USB vendor 
ID, USB product ID, and the serial number. -P is for requesting port 
60000 and -d makes ippusbxd in the foreground with debug output.

I am using my 1.22 release of ippusbxd.

ippusbxd starts in a loop waiting for requests from the client on 
localhost:60000. If a request comes in it starts a thread for it, 
immediately continuing to listen for further requests, allowing several 
requests to be handled in parallel. The request handler thread starts a 
conversation with the printer, passing on the client's request to the 
printer via USB and waiting for the printer's answer on USB, passing it 
on to the client on localhost:60000. It repeats in a loop if the client 
continues the communication sending new packets until the client stops.

One sees in the debug output that printing via the "ipp" backend 
generates something like three or four parallel conversations, one being 
the transfer of the job data. ipptool establishes only one single 
conversation.

If everything is OK (job gets completely printed) every client's request 
receives an answer from the printer and a conversation always ends with 
an answer from the printer. All communication except the upload of the 
print job data into the printer is done vis Content-Length, the data 
upload is done via Chunked. The data transfer is answered with the job 
URI and ID.

If the printer stops, the page (in case of multiple pages the last page) 
is printed only half-way. In the debug info one can see that the full 
job data got uploaded and the closing blob for an HTTP package in 
chunked mode (30 0d 0a 0d 0a, "0\r\n\r\n") is also sent, but the printer 
never answers to this. The thread carrying this conversation is waiting 
until timing out. Parallel conversations still continue to happen. If 
the device URI is without "&waitjob=false" the job does not get 
dequeued. The printer never finishes printing the page and after some 
minutes it times out internally, ejecting the half-printed page.

This kind of stop does only happen with ippusbxd, not when printing via 
WiFi.

Now my question is whether I do everything correctly, especially whether 
the assumption that communication with an IPP printer is actually always 
started by a request from the client which gets answered by the printer 
and then continuing this way until the conversation ends with the answer 
of the printer, allowing several of these conversations in parallel?

Is there no way for example that the printer can start a conversation 
and if I ignore that (have no loop listening on the USB of the printer 
and grabbing the data there) a printer-internal, small buffer fills up 
and the printer blocks? And if I grab data from the printer's USB, do I 
have to answer to prevent the printer from blocking? Can one set the 
printer into a mode not starting such conversations?

Is there a limit of parallel conversations and the "ipp" backend perhaps 
exceeds it? Can I check somehow before starting a conversation whether 
there is still "a slot free"?

Any other idea what can be happening here?

Thanks in advance.

    Till

Re: [Printing-architecture] Communication between IPP printer and "ipp" CUPS backend

[Till Kamppeter]

Hi,

no one has any idea or opinion concerning this?

    Till

On 09/11/2015 02:07 PM, Till Kamppeter wrote:
> [ Cross-posting because I do not know which list is the better for
>    this ]
>
> Hi,
>
> I have overtaken maintainership on the ippusbxd IPP-over-USB support
> daemon (hosted now here: https://github.com/tillkamppeter/ippusbxd/).
>
> Now I have done several tests and bug fixes using the HP DeskJet Ink
> Advantage 2540, a USB multi-function device which also does IPP via WiFi
> and via IPP-over-USB.
>
> The printer prints reliably via WiFi, conventional USB (using "hp"
> backend of HPLIP) and when doing IPP-over-USB but printing with ipptool
> and not with the "ipp" CUPS backend. With the "ipp" CUPS backend I can
> print something like 3 or 4 one-page LibreOffice jobs and then the
> printer stops working, whereas with ipptool I do not get it stopping. It
> prints and prints and prints, ...
>
> The difference between the "ipp" backend and ipptool is what
> communication happens between the client and the printer. ipptool sends
> the job without any other communication in parallel until the job is
> completely sent out and the answer (with job URI/ID) is received. The
> "ipp" tool does a lot of conversations in parallel, like checking the
> progress of the job, the ink levels, ... I have already tried to add
> "&waitjob=false" to the device URI for using the "ipp" backend, making
> the backend stop as soon as the job is sent and communicate less this
> way, but I still get the printer stopping in a middle of a job.
>
> By the way, command line of ipptool is
>
> ipptool ipp://localhost:60000/ipp/print -d
> filetype=application/octet-stream -d filename=`pwd`/printout-bashrc.gz
> print-job.test
>
> The file printout-bashrc.gz is the result of printing ~/.bashrc with
> CUPS and HPLIP but capturing the output into a file and "gzip"ping it.
>
> In the "ipp" backend case I use an HPLIP-PPD-based CUPS queue with a
> device URI like
>
> ipp://localhost:60000/ipp/print
>
> or
>
> ipp://localhost:60000/ipp/print&waitjob=false
>
> In both cases ippusbxd is binding to port 60000 on localhost on both
> IPv4 and IPv6, running with the command line
>
> ./ippusbxd -d -v 03f0 -m c211 -s BR54BFB02C05XK -P 60000 2>&1 | tee log
>
> The codes after -v, -m, and -s are printer specific, they are USB vendor
> ID, USB product ID, and the serial number. -P is for requesting port
> 60000 and -d makes ippusbxd in the foreground with debug output.
>
> I am using my 1.22 release of ippusbxd.
>
> ippusbxd starts in a loop waiting for requests from the client on
> localhost:60000. If a request comes in it starts a thread for it,
> immediately continuing to listen for further requests, allowing several
> requests to be handled in parallel. The request handler thread starts a
> conversation with the printer, passing on the client's request to the
> printer via USB and waiting for the printer's answer on USB, passing it
> on to the client on localhost:60000. It repeats in a loop if the client
> continues the communication sending new packets until the client stops.
>
> One sees in the debug output that printing via the "ipp" backend
> generates something like three or four parallel conversations, one being
> the transfer of the job data. ipptool establishes only one single
> conversation.
>
> If everything is OK (job gets completely printed) every client's request
> receives an answer from the printer and a conversation always ends with
> an answer from the printer. All communication except the upload of the
> print job data into the printer is done vis Content-Length, the data
> upload is done via Chunked. The data transfer is answered with the job
> URI and ID.
>
> If the printer stops, the page (in case of multiple pages the last page)
> is printed only half-way. In the debug info one can see that the full
> job data got uploaded and the closing blob for an HTTP package in
> chunked mode (30 0d 0a 0d 0a, "0\r\n\r\n") is also sent, but the printer
> never answers to this. The thread carrying this conversation is waiting
> until timing out. Parallel conversations still continue to happen. If
> the device URI is without "&waitjob=false" the job does not get
> dequeued. The printer never finishes printing the page and after some
> minutes it times out internally, ejecting the half-printed page.
>
> This kind of stop does only happen with ippusbxd, not when printing via
> WiFi.
>
> Now my question is whether I do everything correctly, especially whether
> the assumption that communication with an IPP printer is actually always
> started by a request from the client which gets answered by the printer
> and then continuing this way until the conversation ends with the answer
> of the printer, allowing several of these conversations in parallel?
>
> Is there no way for example that the printer can start a conversation
> and if I ignore that (have no loop listening on the USB of the printer
> and grabbing the data there) a printer-internal, small buffer fills up
> and the printer blocks? And if I grab data from the printer's USB, do I
> have to answer to prevent the printer from blocking? Can one set the
> printer into a mode not starting such conversations?
>
> Is there a limit of parallel conversations and the "ipp" backend perhaps
> exceeds it? Can I check somehow before starting a conversation whether
> there is still "a slot free"?
>
> Any other idea what can be happening here?
>
> Thanks in advance.
>
>     Till

Re: [Printing-architecture] [cups-devel] Communication between IPP printer and "ipp" CUPS backend

[Till Kamppeter]

[-- Attachment #1: Type: text/plain, Size: 1902 bytes --]

On 09/15/2015 09:32 PM, Kennedy, Smith (Wireless Architect) wrote:
> Hi Till,
>
> Sorry for not replying earlier. Would you have any USB traces from Wireshark or a Beagle protocol analyzer, or logs, and/or the corresponding document files, so that we could try to repro it internally?
>
> Smith

Attached is a tarball with the following files:

"log" files (with hex dumps of all communication content) of the 
following command line for several print jobs:

./ippusbxd -d -v 03f0 -m c211 -s BR54BFB02C05XK -P 60000 2>&1 | tee log

Each job was printing the file "doacao.odt" out of LibreOffice on a CUPS 
queue with the device URI (using HPLIP driver):

ipp://localhost:60000/ipp/print?waitjob=false

The job succeeded in most cases, after each job I have stopped ippusbxd, 
saved the "log" file and started it again. After each failed job I have 
turned off and turned on the printer again.

log10 Succeeded
log11 Succeeded
log12 Succeeded
log13 Succeeded
log14 Failed
log20 Succeeded
log21 Succeeded
log22 Succeeded
log23 Succeeded
log24 Failed
log30 Succeeded
log31 Succeeded
log32 Succeeded
log33 Succeeded
log34 Succeeded
log35 Failed

error_log file (with LogLevel=debug) for all the above print jobs:

error_log

Example files:

bashrc
doacao.odt

Binary data which goes to the printer when printing the above example files:

printout-bashrc
printout-doacao

Script to run ipptool for printing a job:

ipptool-print

I have tested on a Ubuntu Vivid (15.04) system with the following 
software versions (some Wily (15.10) packages installed):

ippusbxd: Current GIT snapshot from 
https://github.com/tillkamppeter/ippusbxd
The GIT snapshot (compared to the 1.22 release) adds hex-dumping 
communication content in log output.

CUPS 2.1rc1
cups-filters 1.0.67
HPLIP 3.15.2
Ghostscript 9.16

Printer is the HP DeskJet Ink Advantage 2546 all-in-One

I hope that this information helps.

    Till



[-- Attachment #2: ippusbxd-problem.tar.xz --]
[-- Type: application/x-xz, Size: 619932 bytes --]

Re: [Printing-architecture] [cups-devel] Communication between IPP printer and "ipp" CUPS backend

[Till Kamppeter]

On 09/15/2015 09:32 PM, Kennedy, Smith (Wireless Architect) wrote:
> Hi Till,
>
> Sorry for not replying earlier. Would you have any USB traces from Wireshark or a Beagle protocol analyzer, or logs, and/or the corresponding document files, so that we could try to repro it internally?
>
> Smith

As the problem always occurs after 4 or 5 successful jobs (all the jobs 
being the same one) after turning on the printer, it seems that some 
data is accumulating in some buffer of the printer which runs full after 
a certain amount of activity making the printer blocking.

Perhaps it is data which the printer tries to send to the client without 
being an answer to a request from the client but sent spontaneously by 
the printer. ippusbxd does not pick up such data from the printer as it 
waits for data from the printer only as an answer to a request which it 
has sent.

    Till

Re: [Printing-architecture] [cups-devel] Communication between IPP printer and "ipp" CUPS backend

[Till Kamppeter]

Smith, did you get my e-mail? Did you already have a look into my files?

    Till

On 09/16/2015 04:34 PM, Till Kamppeter wrote:
> On 09/15/2015 09:32 PM, Kennedy, Smith (Wireless Architect) wrote:
>> Hi Till,
>>
>> Sorry for not replying earlier. Would you have any USB traces from
>> Wireshark or a Beagle protocol analyzer, or logs, and/or the
>> corresponding document files, so that we could try to repro it
>> internally?
>>
>> Smith
>
> As the problem always occurs after 4 or 5 successful jobs (all the jobs
> being the same one) after turning on the printer, it seems that some
> data is accumulating in some buffer of the printer which runs full after
> a certain amount of activity making the printer blocking.
>
> Perhaps it is data which the printer tries to send to the client without
> being an answer to a request from the client but sent spontaneously by
> the printer. ippusbxd does not pick up such data from the printer as it
> waits for data from the printer only as an answer to a request which it
> has sent.
>
>     Till
>
>

Re: [Printing-architecture] [cups-devel] Communication between IPP printer and "ipp" CUPS backend

[Till Kamppeter]

Hi,

did you hear back something of the firmware people? In the meantime I 
have worked on ippusbxd, not being able to solve the problem, but fixing 
and improving several things. See

https://github.com/tillkamppeter/ippusbxd/commits/master

Perhaps these last changes could help the firmware developers.

    Till


On 09/21/2015 06:17 PM, Kennedy, Smith (Wireless Architect) wrote:
> Hi Till,
>
> I've asked some of the firmware folks to take a look at it.  (I don't work in printer firmware.)  When I've heard back I'll let you know.
>
> Thanks for your patience,
> Smith