xpra icon
Bug tracker and wiki

Opened 3 months ago

Closed 3 months ago

#2821 closed defect (fixed)

cups printing from html client not working

Reported by: Dušan Vejnovič Owned by: Dušan Vejnovič
Priority: major Milestone: 4.1
Component: printing Version: 3.0.x
Keywords: Cc:

Description

I want to print documnt from Libreoffice Writer. When from printers select HTML5-client and print the document, I cannot get PDF file.
I'm running Debian 10 with Xpra 3.0.10 (server and client).

My locale settings (with command 'locale -a'):

C
C.UTF-8
POSIX
sl_SI.utf8

With command 'sudo journalctl -f -t xpraforwarder' I got:

-- Logs begin at Sat 2020-06-27 16:34:25 CEST. --
jun 27 17:17:59 demo2 xpraforwarder[7627]: '/usr/lib/cups/backend/xpraforwarder' '89' 'dusan' 'Neimenovano 1' '1' 'PageSize=A4 job-uuid=urn:uuid:0139ff4e-e72d-3c65-6500-65ce038c6ccc job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593271079 time-at-processing=1593271079 document-name-supplied=Iiz6EA'
jun 27 17:17:59 demo2 xpraforwarder[7627]: version 3.0.10, username: dusan, title: Neimenovano 1, filename: -, job_id: 89
jun 27 17:17:59 demo2 xpraforwarder[7627]: uid=(0, 0, 0), gid=(7, 7, 7)
jun 27 17:17:59 demo2 xpraforwarder[7627]: DEVICE_URI=xpraforwarder:/tmp?display=%3A51255&source=99e56d0f77ab41b581e1316f30b3b465&socket-path=%2Frun%2Fxpra%2Fdemo2-51255&remote-printer=HTML5-client&remote-device-uri=None&mimetype=application%2Fpdf
jun 27 17:17:59 demo2 xpraforwarder[7627]: parsed attributes={'mimetype': ['application/pdf'], 'socket-path': ['/run/xpra/demo2-51255'], 'remote-printer': ['HTML5-client'], 'remote-device-uri': ['None'], 'source': ['99e56d0f77ab41b581e1316f30b3b465'], 'display': [':51255']}
jun 27 17:17:59 demo2 xpraforwarder[7627]: xpra display: :51255, socket-path: /run/xpra/demo2-51255
jun 27 17:17:59 demo2 xpraforwarder[7627]: running: ['xpra', 'print', 'socket:/run/xpra/demo2-51255', '-', 'application/pdf', '99e56d0f77ab41b581e1316f30b3b465', 'Neimenovano 1', 'HTML5-client', '1', 'PageSize=A4 job-uuid=urn:uuid:0139ff4e-e72d-3c65-6500-65ce038c6ccc job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593271079 time-at-processing=1593271079 document-name-supplied=Iiz6EA']
jun 27 17:17:59 demo2 xpraforwarder[7627]: returncode=1
jun 27 17:17:59 demo2 xpraforwarder[7627]: stdout=
jun 27 17:17:59 demo2 xpraforwarder[7627]: stderr=xpra main error:
                                           Traceback (most recent call last):
                                             File "/usr/lib/python3/dist-packages/xpra/scripts/main.py", line 121, in main
                                               return run_mode(script_file, err, options, args, mode, defaults)
                                             File "/usr/lib/python3/dist-packages/xpra/scripts/main.py", line 462, in run_mode
                                               return run_client(error_cb, options, args, mode)
                                             File "/usr/lib/python3/dist-packages/xpra/scripts/main.py", line 1526, in run_client
                                               app = get_client_app(error_cb, opts, extra_args, mode)
                                             File "/usr/lib/python3/dist-packages/xpra/scripts/main.py", line 1589, in get_client_app
                                               app.set_command_args(args)
                                             File "/usr/lib/python3/dist-packages/xpra/client/gobject_client_base.py", line 430, in set_command_args
                                               self.file_data = sys.stdin.read()
                                             File "/usr/lib/python3.7/codecs.py", line 322, in decode
                                               (result, consumed) = self._buffer_decode(data, self.errors, final)
                                           UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbf in position 410: invalid start byte

Change History (10)

comment:1 Changed 3 months ago by Antoine Martin

Owner: changed from Antoine Martin to Dušan Vejnovič

Please try r26827. (trivial change which you can apply by hand to your installation)

The solution was found here: How to prevent “UnicodeDecodeError” when reading piped input from sys.stdin?

Last edited 3 months ago by Antoine Martin (previous) (diff)

comment:2 Changed 3 months ago by Dušan Vejnovič

Not working, nothing happend.

comment:3 Changed 3 months ago by Antoine Martin

Not working, nothing happend.

What about the logs?
FYI: with the html5 client, the file is supposed to open for printing - you may have to accept the event.

comment:4 Changed 3 months ago by Dušan Vejnovič

I'm select HTML5-client printer for printing and print the document. After printing there is no window for saving the printed document.

Command 'sudo journalctl -f -t xpraforwarder' show:

jun 28 08:44:12 test xpraforwarder[5896]: '/usr/lib/cups/backend/xpraforwarder' '17' 'root' 'Untitled 1' '1' 'PageSize=A4 job-uuid=urn:uuid:1f44b6d0-4cb3-34db-5c99-78d24158134c job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593326652 time-at-processing=1593326652 document-name-supplied=afwtO8'
jun 28 08:44:12 test xpraforwarder[5896]: version 3.0.10, username: root, title: Untitled 1, filename: -, job_id: 17
jun 28 08:44:12 test xpraforwarder[5896]: uid=(0, 0, 0), gid=(7, 7, 7)
jun 28 08:44:12 test xpraforwarder[5896]: DEVICE_URI=xpraforwarder:/tmp?source=324125a9-8de4-93a2-cf59-2003fe522a1b&remote-device-uri=None&display=%3A10000&remote-printer=HTML5+client&mimetype=application%2Fpdf&socket-path=%2Frun%2Fuser%2F0%2Fxpra%2Ftest-10000
jun 28 08:44:12 test xpraforwarder[5896]: parsed attributes={'mimetype': ['application/pdf'], 'socket-path': ['/run/user/0/xpra/test-10000'], 'remote-printer': ['HTML5 client'], 'remote-device-uri': ['None'], 'source': ['324125a9-8de4-93a2-cf59-2003fe522a1b'], 'display': [':10000']}
jun 28 08:44:12 test xpraforwarder[5896]: xpra display: :10000, socket-path: /run/user/0/xpra/test-10000
jun 28 08:44:12 test xpraforwarder[5896]: running: ['xpra', 'print', 'socket:/run/user/0/xpra/test-10000', '-', 'application/pdf', '324125a9-8de4-93a2-cf59-2003fe522a1b', 'Untitled 1', 'HTML5 client', '1', 'PageSize=A4 job-uuid=urn:uuid:1f44b6d0-4cb3-34db-5c99-78d24158134c job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593326652 time-at-processing=1593326652 document-name-supplied=afwtO8']
jun 28 08:44:12 test xpraforwarder[5896]: returncode=0
jun 28 08:44:40 test xpraforwarder[5922]: '/usr/lib/cups/backend/xpraforwarder' '16' 'root' 'Untitled 1' '1' 'Duplex=None PageSize=A4 job-uuid=urn:uuid:a3375aba-895f-3367-4cf5-cf53cf2f1bbc job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593326377 time-at-processing=1593326679 document-name-supplied=QwJ18F'
jun 28 08:44:40 test xpraforwarder[5922]: version 3.0.10, username: root, title: Untitled 1, filename: -, job_id: 16
jun 28 08:44:40 test xpraforwarder[5922]: uid=(0, 0, 0), gid=(7, 7, 7)
jun 28 08:44:40 test xpraforwarder[5922]: DEVICE_URI=xpraforwarder:/tmp?source=324125a9-8de4-93a2-cf59-2003fe522a1b&remote-device-uri=None&display=%3A10000&remote-printer=HTML5+client&mimetype=application%2Fpdf&socket-path=%2Frun%2Fuser%2F0%2Fxpra%2Ftest-10000
jun 28 08:44:40 test xpraforwarder[5922]: parsed attributes={'mimetype': ['application/pdf'], 'socket-path': ['/run/user/0/xpra/test-10000'], 'remote-printer': ['HTML5 client'], 'remote-device-uri': ['None'], 'source': ['324125a9-8de4-93a2-cf59-2003fe522a1b'], 'display': [':10000']}
jun 28 08:44:40 test xpraforwarder[5922]: xpra display: :10000, socket-path: /run/user/0/xpra/test-10000
jun 28 08:44:40 test xpraforwarder[5922]: running: ['xpra', 'print', 'socket:/run/user/0/xpra/test-10000', '-', 'application/pdf', '324125a9-8de4-93a2-cf59-2003fe522a1b', 'Untitled 1', 'HTML5 client', '1', 'Duplex=None PageSize=A4 job-uuid=urn:uuid:a3375aba-895f-3367-4cf5-cf53cf2f1bbc job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593326377 time-at-processing=1593326679 document-name-supplied=QwJ18F']
jun 28 08:44:40 test xpraforwarder[5922]: returncode=0

Cups access_log:

localhost - - [28/Jun/2020:08:44:12 +0200] "POST /printers/HTML5-client HTTP/1.1" 200 196 Create-Job successful-ok
localhost - - [28/Jun/2020:08:44:12 +0200] "POST /printers/HTML5-client HTTP/1.1" 200 7178 Send-Document successful-ok

Cups error_log:

D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:08:44:12 +0200] [Client 16] Server address is "/var/run/cups/cups.sock".
D [28/Jun/2020:08:44:12 +0200] [Client 16] Accepted from localhost (Domain)
D [28/Jun/2020:08:44:12 +0200] [Client 16] Waiting for request.
I [28/Jun/2020:08:44:12 +0200] Expiring subscriptions...
D [28/Jun/2020:08:44:12 +0200] [Client 16] POST / HTTP/1.1
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=200, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] No authentication data provided.
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] 2.0 Get-Printer-Attributes 7
D [28/Jun/2020:08:44:12 +0200] Get-Printer-Attributes ipp://localhost:631/printers/HTML5-client
D [28/Jun/2020:08:44:12 +0200] [Client 16] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/HTML5-client) from localhost.
D [28/Jun/2020:08:44:12 +0200] [Client 16] Content-Length: 1380
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] con->http=0x560d624f5400
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1380, response=0x560d6250a5f0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:08:44:12 +0200] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] bytes=0, http_state=0, data_remaining=1380
D [28/Jun/2020:08:44:12 +0200] [Client 16] Flushing write buffer.
D [28/Jun/2020:08:44:12 +0200] [Client 16] New state is HTTP_STATE_WAITING
D [28/Jun/2020:08:44:12 +0200] [Client 16] Waiting for request.
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [28/Jun/2020:08:44:12 +0200] [Client 16] POST /printers/HTML5-client HTTP/1.1
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=200, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] No authentication data provided.
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] 2.0 Get-Printer-Attributes 8
D [28/Jun/2020:08:44:12 +0200] Get-Printer-Attributes ipp://localhost/printers/HTML5-client
D [28/Jun/2020:08:44:12 +0200] [Client 16] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HTML5-client) from localhost.
D [28/Jun/2020:08:44:12 +0200] [Client 16] Content-Length: 12253
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] con->http=0x560d624f5400
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12253, response=0x560d6250a680(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:08:44:12 +0200] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] bytes=0, http_state=0, data_remaining=12253
D [28/Jun/2020:08:44:12 +0200] [Client 16] Flushing write buffer.
D [28/Jun/2020:08:44:12 +0200] [Client 16] New state is HTTP_STATE_WAITING
D [28/Jun/2020:08:44:12 +0200] [Client 16] Waiting for request.
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [28/Jun/2020:08:44:12 +0200] [Client 16] POST /printers/HTML5-client HTTP/1.1
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=200, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] No authentication data provided.
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] 2.0 Create-Job 9
D [28/Jun/2020:08:44:12 +0200] Create-Job ipp://localhost/printers/HTML5-client
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [28/Jun/2020:08:44:12 +0200] [Job 17] Applying default options...
D [28/Jun/2020:08:44:12 +0200] add_job: requesting-user-name="root"
D [28/Jun/2020:08:44:12 +0200] Adding default job-sheets values "none,none"...
I [28/Jun/2020:08:44:12 +0200] [Job 17] Adding start banner page "none".
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [28/Jun/2020:08:44:12 +0200] [Job 17] Queued on "HTML5-client" by "root".
D [28/Jun/2020:08:44:12 +0200] [Client 16] Returning IPP successful-ok for Create-Job (ipp://localhost/printers/HTML5-client) from localhost.
D [28/Jun/2020:08:44:12 +0200] [Client 16] Content-Length: 200
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] con->http=0x560d624f5400
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=200, response=0x560d6250a750(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [28/Jun/2020:08:44:12 +0200] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] bytes=0, http_state=0, data_remaining=200
D [28/Jun/2020:08:44:12 +0200] [Client 16] Flushing write buffer.
D [28/Jun/2020:08:44:12 +0200] [Client 16] New state is HTTP_STATE_WAITING
D [28/Jun/2020:08:44:12 +0200] [Client 16] Waiting for request.
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:08:44:12 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:12 +0200] [Notifier] JobCreated
D [28/Jun/2020:08:44:12 +0200] [Client 16] POST /printers/HTML5-client HTTP/1.1
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=200, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] No authentication data provided.
D [28/Jun/2020:08:44:12 +0200] [Client 16] 2.0 Send-Document 10
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] [Client 16] Read: status=100, state=6
D [28/Jun/2020:08:44:12 +0200] Send-Document ipp://localhost:631/printers/HTML5-client
D [28/Jun/2020:08:44:12 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [28/Jun/2020:08:44:12 +0200] [Job 17] Auto-typing file...
D [28/Jun/2020:08:44:12 +0200] [Job 17] Request file type is application/pdf.
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [28/Jun/2020:08:44:12 +0200] [Job 17] File of type application/pdf queued by "root".
I [28/Jun/2020:08:44:12 +0200] [Job 17] Adding end banner page "none".
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:08:44:12 +0200] [Job 17] time-at-processing=1593326652
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:08:44:12 +0200] [Job 17] 2 filters for job:
D [28/Jun/2020:08:44:12 +0200] [Job 17] pdftopdf (application/pdf to printer/HTML5-client/application/vnd.cups-pdf, cost 0)
D [28/Jun/2020:08:44:12 +0200] [Job 17] - (printer/HTML5-client/application/vnd.cups-pdf to printer/HTML5-client, cost 0)
D [28/Jun/2020:08:44:12 +0200] [Job 17] job-sheets=none,none
D [28/Jun/2020:08:44:12 +0200] [Job 17] argv[0]="HTML5-client"
D [28/Jun/2020:08:44:12 +0200] [Job 17] argv[1]="17"
D [28/Jun/2020:08:44:12 +0200] [Job 17] argv[2]="root"
D [28/Jun/2020:08:44:12 +0200] [Job 17] argv[3]="Untitled 1"
D [28/Jun/2020:08:44:12 +0200] [Job 17] argv[4]="1"
D [28/Jun/2020:08:44:12 +0200] [Job 17] argv[5]="PageSize=A4 job-uuid=urn:uuid:1f44b6d0-4cb3-34db-5c99-78d24158134c job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593326652 time-at-processing=1593326652 document-name-supplied=afwtO8"
D [28/Jun/2020:08:44:12 +0200] [Job 17] argv[6]="/var/spool/cups/d00017-001"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[7]="CUPS_STATEDIR=/run/cups"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[8]="HOME=/var/spool/cups/tmp"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[10]="SERVER_ADMIN=root@test"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[11]="SOFTWARE=CUPS/2.2.10"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[13]="USER=root"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[14]="CUPS_MAX_MESSAGE=2047"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[17]="IPP_PORT=631"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[18]="CHARSET=utf-8"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[19]="LANG=sl_SI.UTF-8"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[20]="PPD=/etc/cups/ppd/HTML5-client.ppd"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[21]="RIP_MAX_CACHE=128m"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[22]="CONTENT_TYPE=application/pdf"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[23]="DEVICE_URI=xpraforwarder:/tmp?source=324125a9-8de4-93a2-cf59-2003fe522a1b&remote-device-uri=None&display=%3A10000&remote-printer=HTML5+client&mimetype=application%2Fpdf&socket-path=%2Frun%2Fuser%2F0%2Fxpra%2Ftest-10000"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[24]="PRINTER_INFO=Print to PDF in client browser"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[25]="PRINTER_LOCATION=via xpra"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[26]="PRINTER=HTML5-client"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[27]="PRINTER_STATE_REASONS=none"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[28]="CUPS_FILETYPE=document"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [28/Jun/2020:08:44:12 +0200] [Job 17] envp[30]="AUTH_I****"
I [28/Jun/2020:08:44:12 +0200] [Job 17] Started filter /usr/lib/cups/filter/pdftopdf (PID 5895)
I [28/Jun/2020:08:44:12 +0200] [Job 17] Started backend /usr/lib/cups/backend/xpraforwarder (PID 5896)
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:08:44:12 +0200] [Client 16] Content-Length: 170
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] con->http=0x560d624f5400
D [28/Jun/2020:08:44:12 +0200] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=170, response=0x560d6250a5c0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:08:44:12 +0200] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:08:44:12 +0200] [Client 16] bytes=0, http_state=0, data_remaining=170
D [28/Jun/2020:08:44:12 +0200] [Client 16] Flushing write buffer.
D [28/Jun/2020:08:44:12 +0200] [Client 16] New state is HTTP_STATE_WAITING
D [28/Jun/2020:08:44:12 +0200] [Client 16] Waiting for request.
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [28/Jun/2020:08:44:12 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:12 +0200] [Notifier] PrinterStateChanged
D [28/Jun/2020:08:44:12 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:12 +0200] [Notifier] JobState
D [28/Jun/2020:08:44:12 +0200] [Job 17] pdftopdf: Last filter determined by the PPD: pdftopdf; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
D [28/Jun/2020:08:44:12 +0200] [Job 17] PAGE: 1 1
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:12 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:12 +0200] [Notifier] JobProgress
D [28/Jun/2020:08:44:12 +0200] [Job 17] PID 5895 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [28/Jun/2020:08:44:12 +0200] [Job 17] PID 5896 (/usr/lib/cups/backend/xpraforwarder) exited with no errors.
D [28/Jun/2020:08:44:12 +0200] [Job 17] time-at-completed=1593326652
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [28/Jun/2020:08:44:12 +0200] [Job 17] Job completed.
I [28/Jun/2020:08:44:12 +0200] Expiring subscriptions...
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:12 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:12 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:12 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:12 +0200] [Notifier] JobCompleted
D [28/Jun/2020:08:44:12 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:12 +0200] [Notifier] PrinterStateChanged
I [28/Jun/2020:08:44:13 +0200] Expiring subscriptions...
D [28/Jun/2020:08:44:13 +0200] [Job 17] Unloading...
I [28/Jun/2020:08:44:39 +0200] Expiring subscriptions...
D [28/Jun/2020:08:44:39 +0200] cupsdAddCert: Adding certificate for PID 0
D [28/Jun/2020:08:44:39 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
I [28/Jun/2020:08:44:39 +0200] [Job 16] Job submission timed out.
D [28/Jun/2020:08:44:39 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [28/Jun/2020:08:44:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [28/Jun/2020:08:44:39 +0200] [Job 16] time-at-processing=1593326679
D [28/Jun/2020:08:44:39 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [28/Jun/2020:08:44:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [28/Jun/2020:08:44:39 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [28/Jun/2020:08:44:39 +0200] [Job 16] 2 filters for job:
D [28/Jun/2020:08:44:39 +0200] [Job 16] pdftopdf (application/pdf to printer/HTML5-client/application/vnd.cups-pdf, cost 0)
D [28/Jun/2020:08:44:39 +0200] [Job 16] - (printer/HTML5-client/application/vnd.cups-pdf to printer/HTML5-client, cost 0)
D [28/Jun/2020:08:44:39 +0200] [Job 16] job-sheets=none,none
D [28/Jun/2020:08:44:39 +0200] [Job 16] argv[0]="HTML5-client"
D [28/Jun/2020:08:44:39 +0200] [Job 16] argv[1]="16"
D [28/Jun/2020:08:44:39 +0200] [Job 16] argv[2]="root"
D [28/Jun/2020:08:44:39 +0200] [Job 16] argv[3]="Untitled 1"
D [28/Jun/2020:08:44:39 +0200] [Job 16] argv[4]="1"
D [28/Jun/2020:08:44:39 +0200] [Job 16] argv[5]="Duplex=None PageSize=A4 job-uuid=urn:uuid:a3375aba-895f-3367-4cf5-cf53cf2f1bbc job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593326377 time-at-processing=1593326679 document-name-supplied=QwJ18F"
D [28/Jun/2020:08:44:39 +0200] [Job 16] argv[6]="/var/spool/cups/d00016-001"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[7]="CUPS_STATEDIR=/run/cups"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[8]="HOME=/var/spool/cups/tmp"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[10]="SERVER_ADMIN=root@test"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[11]="SOFTWARE=CUPS/2.2.10"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[13]="USER=root"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[14]="CUPS_MAX_MESSAGE=2047"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[17]="IPP_PORT=631"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[18]="CHARSET=utf-8"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[19]="LANG=sl_SI.UTF-8"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[20]="PPD=/etc/cups/ppd/HTML5-client.ppd"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[21]="RIP_MAX_CACHE=128m"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[22]="CONTENT_TYPE=application/pdf"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[23]="DEVICE_URI=xpraforwarder:/tmp?source=324125a9-8de4-93a2-cf59-2003fe522a1b&remote-device-uri=None&display=%3A10000&remote-printer=HTML5+client&mimetype=application%2Fpdf&socket-path=%2Frun%2Fuser%2F0%2Fxpra%2Ftest-10000"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[24]="PRINTER_INFO=Print to PDF in client browser"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[25]="PRINTER_LOCATION=via xpra"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[26]="PRINTER=HTML5-client"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[27]="PRINTER_STATE_REASONS=none"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[28]="CUPS_FILETYPE=document"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [28/Jun/2020:08:44:39 +0200] [Job 16] envp[30]="AUTH_I****"
I [28/Jun/2020:08:44:39 +0200] [Job 16] Started filter /usr/lib/cups/filter/pdftopdf (PID 5921)
I [28/Jun/2020:08:44:39 +0200] [Job 16] Started backend /usr/lib/cups/backend/xpraforwarder (PID 5922)
D [28/Jun/2020:08:44:39 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [28/Jun/2020:08:44:39 +0200] Report: clients=1
D [28/Jun/2020:08:44:39 +0200] Report: jobs=17
D [28/Jun/2020:08:44:39 +0200] Report: jobs-active=1
D [28/Jun/2020:08:44:39 +0200] Report: printers=2
D [28/Jun/2020:08:44:39 +0200] Report: stringpool-string-count=2563
D [28/Jun/2020:08:44:39 +0200] Report: stringpool-alloc-bytes=13376
D [28/Jun/2020:08:44:39 +0200] Report: stringpool-total-bytes=52408
D [28/Jun/2020:08:44:39 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:39 +0200] [Notifier] JobState
D [28/Jun/2020:08:44:39 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:39 +0200] [Notifier] PrinterStateChanged
D [28/Jun/2020:08:44:39 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:39 +0200] [Notifier] JobState
D [28/Jun/2020:08:44:40 +0200] [Job 16] pdftopdf: Last filter determined by the PPD: pdftopdf; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
D [28/Jun/2020:08:44:40 +0200] [Job 16] PAGE: 1 1
D [28/Jun/2020:08:44:40 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:40 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:40 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:40 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:40 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:40 +0200] [Notifier] JobProgress
D [28/Jun/2020:08:44:40 +0200] [Job 16] PID 5921 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
I [28/Jun/2020:08:44:40 +0200] Expiring subscriptions...
D [28/Jun/2020:08:44:40 +0200] [Job 16] PID 5922 (/usr/lib/cups/backend/xpraforwarder) exited with no errors.
D [28/Jun/2020:08:44:40 +0200] [Job 16] time-at-completed=1593326680
D [28/Jun/2020:08:44:40 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:40 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [28/Jun/2020:08:44:40 +0200] [Job 16] Job completed.
I [28/Jun/2020:08:44:40 +0200] Expiring subscriptions...
D [28/Jun/2020:08:44:40 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:40 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:40 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:40 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:08:44:40 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:40 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:08:44:40 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:08:44:40 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:40 +0200] [Notifier] JobCompleted
D [28/Jun/2020:08:44:40 +0200] [Notifier] state=3
D [28/Jun/2020:08:44:40 +0200] [Notifier] PrinterStateChanged
I [28/Jun/2020:08:44:41 +0200] Expiring subscriptions...
D [28/Jun/2020:08:44:41 +0200] [Job 16] Unloading...
I [28/Jun/2020:08:44:43 +0200] Saving job.cache...
I [28/Jun/2020:08:44:43 +0200] Saving subscriptions.conf...
D [28/Jun/2020:08:44:43 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Printing jobs and dirty files"
I [28/Jun/2020:08:44:43 +0200] Expiring subscriptions...
I [28/Jun/2020:08:49:13 +0200] Expiring subscriptions...
D [28/Jun/2020:08:49:13 +0200] Closing client 16 after 300 seconds of inactivity.
D [28/Jun/2020:08:49:13 +0200] [Client 16] Closing connection.
D [28/Jun/2020:08:49:13 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [28/Jun/2020:08:49:13 +0200] Report: clients=0
D [28/Jun/2020:08:49:13 +0200] Report: jobs=17
D [28/Jun/2020:08:49:13 +0200] Report: jobs-active=0
D [28/Jun/2020:08:49:13 +0200] Report: printers=2
D [28/Jun/2020:08:49:13 +0200] Report: stringpool-string-count=2600
D [28/Jun/2020:08:49:13 +0200] Report: stringpool-alloc-bytes=12344
D [28/Jun/2020:08:49:13 +0200] Report: stringpool-total-bytes=53184

comment:5 Changed 3 months ago by Antoine Martin

The problem must be elsewhere now because the xpra print command worked correctly this time:

running: ['xpra', 'print', 'socket:/run/user/0/xpra/test-10000', '-', 'application/pdf', '324125a9-8de4-93a2-cf59-2003fe522a1b', 'Untitled 1', 'HTML5 client', '1', '...']
xpraforwarder[5922]: returncode=0

Maybe there's a regression in the server or the html5 client.
You could run your xpra server with -d file,printing and post the log. And also keep an eye on the javascript console of your browser.

comment:6 Changed 3 months ago by Dušan Vejnovič

No error messages in the In Firefox Javascipt Console.

File /run/user/0/xpra/:10000.log

2020-06-28 11:23:38,916 Missing property or wrong property type WM_TRANSIENT_FOR (window)
2020-06-28 11:23:38,917  no such window
2020-06-28 11:23:39,222 New unix-domain connection received
2020-06-28 11:23:39,222  on '/run/user/0/xpra/test-10000'
2020-06-28 11:23:39,225 Handshake complete; enabling connection
2020-06-28 11:23:39,226 file transfer: init_attributes('no', 10, 'no', 'no', 'no', None, True)
2020-06-28 11:23:39,226 file transfer attributes={'file-transfer': False, 'file-transfer-ask': False, 'file-size-limit': 10, 'file-chunks': 65536, 'open-files': False, 'open-files-ask': False, 'printing': False, 'printing-ask': False, 'open-url': False, 'open-url-ask': False, 'file-ask-timeout': 3600}
2020-06-28 11:23:39,226 file transfer: init_attributes('no', 10, 'no', 'no', 'no', None, True)
2020-06-28 11:23:39,226 file transfer attributes={'file-transfer': False, 'file-transfer-ask': False, 'file-size-limit': 10, 'file-chunks': 65536, 'open-files': False, 'open-files-ask': False, 'printing': False, 'printing-ask': False, 'open-url': False, 'open-url-ask': False, 'file-ask-timeout': 3600}
2020-06-28 11:23:39,227 file transfer remote caps: file-transfer=False   (ask=True)
2020-06-28 11:23:39,228 file transfer remote caps: printing=False        (ask=False)
2020-06-28 11:23:39,228 file transfer remote caps: open-files=True      (ask=True)
2020-06-28 11:23:39,228 file transfer remote caps: open-url=True        (ask=True)
2020-06-28 11:23:39,228 Python/GObject/Print client version 3.0.10-r26630 64-bit
2020-06-28 11:23:39,228  connected from 'test' as 'root'
2020-06-28 11:23:39,231 Error parsing xdg menu data:
2020-06-28 11:23:39,231  ParsingError in file '/etc/xdg/menus/kde-debian-menu.menu', File not found
2020-06-28 11:23:39,231  this is either a bug in python-xdg,
2020-06-28 11:23:39,231  or an invalid system menu configuration
2020-06-28 11:23:39,235 Error parsing xdg menu data:
2020-06-28 11:23:39,235  ParsingError in file '/etc/xdg/menus/kde-debian-menu.menu', File not found
2020-06-28 11:23:39,235  this is either a bug in python-xdg,
2020-06-28 11:23:39,235  or an invalid system menu configuration
2020-06-28 11:23:39,239 process_print: (b'324125a9-8de4-93a2-cf59-2003fe522a1b', b'application/pdf', '7346 bytes', '324125a9-8de4-93a2-cf59-2003fe522a1b', b'Untitled 1', b'HTML5 client', 1, {'Duplex': 'None', 'PageSize': 'A4', 'job-uuid': 'urn:uuid:721387e7-cb44-3439-6b4b-e97dd5b3970c', 'job-originating-host-name': 'localhost', 'date-time-at-creation': '', 'date-time-at-proce
ssing': '', 'time-at-creation': '1593336218', 'time-at-processing': '1593336218', 'document-name-supplied': 'QvcceM'})
2020-06-28 11:23:39,239 process_print: got 7346 bytes for file b'324125a9-8de4-93a2-cf59-2003fe522a1b'
2020-06-28 11:23:39,239 sha1 digest: da3a380362a27b76ec1d966f5523c6859e404395
2020-06-28 11:23:39,239 parsed printer options: {'printer': b'HTML5 client', 'title': b'Untitled 1', 'copies': 1, 'options': {'Duplex': 'None', 'PageSize': 'A4', 'job-uuid': 'urn:uuid:721387e7-cb44-3439-6b4b-e97dd5b3970c', 'job-originating-host-name': 'localhost', 'date-time-at-creation': '', 'date-time-at-processing': '', 'time-at-creation': '1593336218', 'time-at-processing
': '1593336218', 'document-name-supplied': 'QvcceM'}, 'sha1': 'da3a380362a27b76ec1d966f5523c6859e404395'}
2020-06-28 11:23:39,239 will try to send to 2 clients: (ClientConnection(1 : WebSocket(ws socket: 192.168.0.50:10000 <- 192.168.0.3:54838)), ClientConnection(5 : Protocol(unix-domain socket:/run/user/0/xpra/test-10000)))
2020-06-28 11:23:39,240 not sending to ClientConnection(1 : WebSocket(ws socket: 192.168.0.50:10000 <- 192.168.0.3:54838)) (uuid=33eb35ec-d28b-1db7-d757-eb3ea09e18bd, wanted uuid=324125a9-8de4-93a2-cf59-2003fe522a1b)
2020-06-28 11:23:39,240 not sending to ClientConnection(5 : Protocol(unix-domain socket:/run/user/0/xpra/test-10000)) (uuid=27b6fd3c98e34649d9a26a271cc83eaace4eaf58, wanted uuid=324125a9-8de4-93a2-cf59-2003fe522a1b)
2020-06-28 11:23:39,240 'b'Untitled 1'' (7KB) sent to 0 clients for printing
2020-06-28 11:23:39,240 client Protocol(unix-domain socket:/run/user/0/xpra/test-10000) has requested disconnection: done (detaching)
2020-06-28 11:23:39,240 Disconnecting client /run/user/0/xpra/test-10000:
2020-06-28 11:23:39,240  client request
2020-06-28 11:23:39,243 xpra client 5 disconnected.

Cups access_log:

localhost - - [28/Jun/2020:11:23:38 +0200] "POST /printers/HTML5-client HTTP/1.1" 200 211 Create-Job successful-ok
localhost - - [28/Jun/2020:11:23:38 +0200] "POST /printers/HTML5-client HTTP/1.1" 200 7162 Send-Document successful-ok

Cups error_log

D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:11:23:36 +0200] [Client 25] Server address is "/var/run/cups/cups.sock".
D [28/Jun/2020:11:23:36 +0200] [Client 25] Accepted from localhost (Domain)
D [28/Jun/2020:11:23:36 +0200] [Client 25] Waiting for request.
I [28/Jun/2020:11:23:36 +0200] Expiring subscriptions...
D [28/Jun/2020:11:23:36 +0200] cupsdAddCert: Adding certificate for PID 0
D [28/Jun/2020:11:23:36 +0200] Report: clients=2
D [28/Jun/2020:11:23:36 +0200] Report: jobs=20
D [28/Jun/2020:11:23:36 +0200] Report: jobs-active=0
D [28/Jun/2020:11:23:36 +0200] Report: printers=2
D [28/Jun/2020:11:23:36 +0200] Report: stringpool-string-count=3142
D [28/Jun/2020:11:23:36 +0200] Report: stringpool-alloc-bytes=12504
D [28/Jun/2020:11:23:36 +0200] Report: stringpool-total-bytes=64392
D [28/Jun/2020:11:23:36 +0200] [Client 25] POST / HTTP/1.1
D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=200, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] No authentication data provided.
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] 2.0 CUPS-Get-Printers 25
D [28/Jun/2020:11:23:36 +0200] CUPS-Get-Printers
D [28/Jun/2020:11:23:36 +0200] [Client 25] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [28/Jun/2020:11:23:36 +0200] [Client 25] Content-Length: 2481
D [28/Jun/2020:11:23:36 +0200] [Client 25] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:11:23:36 +0200] [Client 25] con->http=0x560d6251b5e0
D [28/Jun/2020:11:23:36 +0200] [Client 25] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2481, response=0x560d62514850(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:11:23:36 +0200] [Client 25] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:11:23:36 +0200] [Client 25] bytes=0, http_state=0, data_remaining=2481
D [28/Jun/2020:11:23:36 +0200] [Client 25] Flushing write buffer.
D [28/Jun/2020:11:23:36 +0200] [Client 25] New state is HTTP_STATE_WAITING
D [28/Jun/2020:11:23:36 +0200] [Client 25] Waiting for request.
D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [28/Jun/2020:11:23:36 +0200] [Client 25] POST / HTTP/1.1
D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=200, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] No authentication data provided.
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=100, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] 2.0 CUPS-Get-Default 26
D [28/Jun/2020:11:23:36 +0200] CUPS-Get-Default
D [28/Jun/2020:11:23:36 +0200] [Client 25] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [28/Jun/2020:11:23:36 +0200] [Client 25] Content-Length: 13206
D [28/Jun/2020:11:23:36 +0200] [Client 25] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:11:23:36 +0200] [Client 25] con->http=0x560d6251b5e0
D [28/Jun/2020:11:23:36 +0200] [Client 25] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=13206, response=0x560d62512f90(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:11:23:36 +0200] [Client 25] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:11:23:36 +0200] [Client 25] bytes=0, http_state=0, data_remaining=13206
D [28/Jun/2020:11:23:36 +0200] [Client 25] Flushing write buffer.
D [28/Jun/2020:11:23:36 +0200] [Client 25] New state is HTTP_STATE_WAITING
D [28/Jun/2020:11:23:36 +0200] [Client 25] Waiting for request.
D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [28/Jun/2020:11:23:36 +0200] [Client 25] POST / HTTP/1.1
D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:11:23:36 +0200] [Client 25] Read: status=200, state=6
D [28/Jun/2020:11:23:36 +0200] [Client 25] No authentication data provided.
D [28/Jun/2020:11:23:36 +0200] [Client 25] 2.0 CUPS-Get-Default 27
D [28/Jun/2020:11:23:36 +0200] CUPS-Get-Default
D [28/Jun/2020:11:23:36 +0200] [Client 25] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [28/Jun/2020:11:23:36 +0200] [Client 25] Content-Length: 13206
D [28/Jun/2020:11:23:36 +0200] [Client 25] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:11:23:36 +0200] [Client 25] con->http=0x560d6251b5e0
D [28/Jun/2020:11:23:36 +0200] [Client 25] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=13206, response=0x560d6251b540(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:11:23:36 +0200] [Client 25] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:11:23:36 +0200] [Client 25] bytes=0, http_state=0, data_remaining=13206
D [28/Jun/2020:11:23:36 +0200] [Client 25] Flushing write buffer.
D [28/Jun/2020:11:23:36 +0200] [Client 25] New state is HTTP_STATE_WAITING
D [28/Jun/2020:11:23:36 +0200] [Client 25] Waiting for request.
D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [28/Jun/2020:11:23:36 +0200] [Client 25] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [28/Jun/2020:11:23:36 +0200] [Client 25] Closing connection.
D [28/Jun/2020:11:23:36 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
I [28/Jun/2020:11:23:37 +0200] Expiring subscriptions...
D [28/Jun/2020:11:23:38 +0200] [Client 23] POST / HTTP/1.1
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=200, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] No authentication data provided.
D [28/Jun/2020:11:23:38 +0200] [Client 23] 2.0 Get-Printer-Attributes 28
D [28/Jun/2020:11:23:38 +0200] Get-Printer-Attributes ipp://localhost:631/printers/HTML5-client
D [28/Jun/2020:11:23:38 +0200] [Client 23] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/HTML5-client) from localhost.
D [28/Jun/2020:11:23:38 +0200] [Client 23] Content-Length: 1380
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
I [28/Jun/2020:11:23:38 +0200] Expiring subscriptions...
D [28/Jun/2020:11:23:38 +0200] [Client 23] con->http=0x560d624f5400
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1380, response=0x560d62510de0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:11:23:38 +0200] [Client 23] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:11:23:38 +0200] [Client 23] bytes=0, http_state=0, data_remaining=1380
D [28/Jun/2020:11:23:38 +0200] [Client 23] Flushing write buffer.
D [28/Jun/2020:11:23:38 +0200] [Client 23] New state is HTTP_STATE_WAITING
D [28/Jun/2020:11:23:38 +0200] [Client 23] Waiting for request.
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [28/Jun/2020:11:23:38 +0200] [Client 23] POST /printers/HTML5-client HTTP/1.1
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=200, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] No authentication data provided.
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] 2.0 Get-Printer-Attributes 29
D [28/Jun/2020:11:23:38 +0200] Get-Printer-Attributes ipp://localhost/printers/HTML5-client
D [28/Jun/2020:11:23:38 +0200] [Client 23] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HTML5-client) from localhost.
D [28/Jun/2020:11:23:38 +0200] [Client 23] Content-Length: 12253
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:11:23:38 +0200] [Client 23] con->http=0x560d624f5400
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12253, response=0x560d6251b540(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:11:23:38 +0200] [Client 23] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:11:23:38 +0200] [Client 23] bytes=0, http_state=0, data_remaining=12253
D [28/Jun/2020:11:23:38 +0200] [Client 23] Flushing write buffer.
D [28/Jun/2020:11:23:38 +0200] [Client 23] New state is HTTP_STATE_WAITING
D [28/Jun/2020:11:23:38 +0200] [Client 23] Waiting for request.
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [28/Jun/2020:11:23:38 +0200] [Client 23] POST /printers/HTML5-client HTTP/1.1
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=200, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] No authentication data provided.
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] 2.0 Create-Job 30
D [28/Jun/2020:11:23:38 +0200] Create-Job ipp://localhost/printers/HTML5-client
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [28/Jun/2020:11:23:38 +0200] [Job 21] Applying default options...
D [28/Jun/2020:11:23:38 +0200] add_job: requesting-user-name="root"
D [28/Jun/2020:11:23:38 +0200] Adding default job-sheets values "none,none"...
I [28/Jun/2020:11:23:38 +0200] [Job 21] Adding start banner page "none".
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [28/Jun/2020:11:23:38 +0200] [Job 21] Queued on "HTML5-client" by "root".
D [28/Jun/2020:11:23:38 +0200] [Client 23] Returning IPP successful-ok for Create-Job (ipp://localhost/printers/HTML5-client) from localhost.
D [28/Jun/2020:11:23:38 +0200] [Client 23] Content-Length: 200
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:11:23:38 +0200] [Client 23] con->http=0x560d624f5400
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=200, response=0x560d62510de0(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [28/Jun/2020:11:23:38 +0200] [Client 23] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:11:23:38 +0200] [Client 23] bytes=0, http_state=0, data_remaining=200
D [28/Jun/2020:11:23:38 +0200] [Client 23] Flushing write buffer.
D [28/Jun/2020:11:23:38 +0200] [Client 23] New state is HTTP_STATE_WAITING
D [28/Jun/2020:11:23:38 +0200] [Client 23] Waiting for request.
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:11:23:38 +0200] [Notifier] state=3
D [28/Jun/2020:11:23:38 +0200] [Notifier] JobCreated
D [28/Jun/2020:11:23:38 +0200] [Client 23] POST /printers/HTML5-client HTTP/1.1
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=200, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] No authentication data provided.
D [28/Jun/2020:11:23:38 +0200] [Client 23] 2.0 Send-Document 31
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] [Client 23] Read: status=100, state=6
D [28/Jun/2020:11:23:38 +0200] Send-Document ipp://localhost:631/printers/HTML5-client
D [28/Jun/2020:11:23:38 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [28/Jun/2020:11:23:38 +0200] [Job 21] Auto-typing file...
D [28/Jun/2020:11:23:38 +0200] [Job 21] Request file type is application/pdf.
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [28/Jun/2020:11:23:38 +0200] [Job 21] File of type application/pdf queued by "root".
I [28/Jun/2020:11:23:38 +0200] [Job 21] Adding end banner page "none".
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:11:23:38 +0200] [Job 21] time-at-processing=1593336218
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:11:23:38 +0200] [Job 21] 2 filters for job:
D [28/Jun/2020:11:23:38 +0200] [Job 21] pdftopdf (application/pdf to printer/HTML5-client/application/vnd.cups-pdf, cost 0)
D [28/Jun/2020:11:23:38 +0200] [Job 21] - (printer/HTML5-client/application/vnd.cups-pdf to printer/HTML5-client, cost 0)
D [28/Jun/2020:11:23:38 +0200] [Job 21] job-sheets=none,none
D [28/Jun/2020:11:23:38 +0200] [Job 21] argv[0]="HTML5-client"
D [28/Jun/2020:11:23:38 +0200] [Job 21] argv[1]="21"
D [28/Jun/2020:11:23:38 +0200] [Job 21] argv[2]="root"
D [28/Jun/2020:11:23:38 +0200] [Job 21] argv[3]="Untitled 1"
D [28/Jun/2020:11:23:38 +0200] [Job 21] argv[4]="1"
D [28/Jun/2020:11:23:38 +0200] [Job 21] argv[5]="Duplex=None PageSize=A4 job-uuid=urn:uuid:721387e7-cb44-3439-6b4b-e97dd5b3970c job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1593336218 time-at-processing=1593336218 document-name-supplied=QvcceM"
D [28/Jun/2020:11:23:38 +0200] [Job 21] argv[6]="/var/spool/cups/d00021-001"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[7]="CUPS_STATEDIR=/run/cups"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[8]="HOME=/var/spool/cups/tmp"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[10]="SERVER_ADMIN=root@test"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[11]="SOFTWARE=CUPS/2.2.10"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[13]="USER=root"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[14]="CUPS_MAX_MESSAGE=2047"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[17]="IPP_PORT=631"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[18]="CHARSET=utf-8"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[19]="LANG=sl_SI.UTF-8"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[20]="PPD=/etc/cups/ppd/HTML5-client.ppd"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[21]="RIP_MAX_CACHE=128m"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[22]="CONTENT_TYPE=application/pdf"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[23]="DEVICE_URI=xpraforwarder:/tmp?source=324125a9-8de4-93a2-cf59-2003fe522a1b&remote-device-uri=None&display=%3A10000&remote-printer=HTML5+client&mimetype=application%2Fpdf&socket-path=%2Frun%2Fuser%2F0%2Fxpra%2Ftest-10000"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[24]="PRINTER_INFO=Print to PDF in client browser"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[25]="PRINTER_LOCATION=via xpra"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[26]="PRINTER=HTML5-client"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[27]="PRINTER_STATE_REASONS=none"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[28]="CUPS_FILETYPE=document"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [28/Jun/2020:11:23:38 +0200] [Job 21] envp[30]="AUTH_I****"
I [28/Jun/2020:11:23:38 +0200] [Job 21] Started filter /usr/lib/cups/filter/pdftopdf (PID 6612)
I [28/Jun/2020:11:23:38 +0200] [Job 21] Started backend /usr/lib/cups/backend/xpraforwarder (PID 6613)
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [28/Jun/2020:11:23:38 +0200] [Client 23] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/HTML5-client) from localhost.
D [28/Jun/2020:11:23:38 +0200] [Client 23] Content-Length: 170
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [28/Jun/2020:11:23:38 +0200] [Client 23] con->http=0x560d624f5400
D [28/Jun/2020:11:23:38 +0200] [Client 23] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=170, response=0x560d62517880(IPP_STATE_DATA), pipe_pid=0, file=-1
D [28/Jun/2020:11:23:38 +0200] [Client 23] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [28/Jun/2020:11:23:38 +0200] [Client 23] bytes=0, http_state=0, data_remaining=170
D [28/Jun/2020:11:23:38 +0200] [Client 23] Flushing write buffer.
D [28/Jun/2020:11:23:38 +0200] [Client 23] New state is HTTP_STATE_WAITING
D [28/Jun/2020:11:23:38 +0200] [Client 23] Waiting for request.
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [28/Jun/2020:11:23:38 +0200] [Notifier] state=3
D [28/Jun/2020:11:23:38 +0200] [Notifier] PrinterStateChanged
D [28/Jun/2020:11:23:38 +0200] [Notifier] state=3
D [28/Jun/2020:11:23:38 +0200] [Notifier] JobState
D [28/Jun/2020:11:23:38 +0200] [Job 21] pdftopdf: Last filter determined by the PPD: pdftopdf; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
D [28/Jun/2020:11:23:38 +0200] [Job 21] PAGE: 1 1
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:11:23:38 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:38 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:11:23:38 +0200] [Job 21] PID 6612 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [28/Jun/2020:11:23:38 +0200] [Notifier] state=3
D [28/Jun/2020:11:23:38 +0200] [Notifier] JobProgress
I [28/Jun/2020:11:23:39 +0200] Expiring subscriptions...
D [28/Jun/2020:11:23:39 +0200] [Job 21] PID 6613 (/usr/lib/cups/backend/xpraforwarder) exited with no errors.
D [28/Jun/2020:11:23:39 +0200] [Job 21] time-at-completed=1593336219
D [28/Jun/2020:11:23:39 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:11:23:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [28/Jun/2020:11:23:39 +0200] [Job 21] Job completed.
I [28/Jun/2020:11:23:39 +0200] Expiring subscriptions...
D [28/Jun/2020:11:23:39 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:11:23:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:11:23:39 +0200] cupsdMarkDirty(----S)
D [28/Jun/2020:11:23:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:11:23:39 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:11:23:39 +0200] cupsdMarkDirty(---J-)
D [28/Jun/2020:11:23:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Jun/2020:11:23:39 +0200] [Notifier] state=3
D [28/Jun/2020:11:23:39 +0200] [Notifier] JobCompleted
D [28/Jun/2020:11:23:39 +0200] [Notifier] state=3
D [28/Jun/2020:11:23:39 +0200] [Notifier] PrinterStateChanged
I [28/Jun/2020:11:23:40 +0200] Expiring subscriptions...
D [28/Jun/2020:11:23:40 +0200] [Job 21] Unloading...
I [28/Jun/2020:11:24:09 +0200] Saving job.cache...
I [28/Jun/2020:11:24:09 +0200] Saving subscriptions.conf...
D [28/Jun/2020:11:24:09 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Printing jobs and dirty files"
I [28/Jun/2020:11:24:09 +0200] Expiring subscriptions...
I [28/Jun/2020:11:28:39 +0200] Expiring subscriptions...
D [28/Jun/2020:11:28:39 +0200] cupsdAddCert: Adding certificate for PID 0
D [28/Jun/2020:11:28:39 +0200] Closing client 23 after 300 seconds of inactivity.
D [28/Jun/2020:11:28:39 +0200] [Client 23] Closing connection.
D [28/Jun/2020:11:28:39 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [28/Jun/2020:11:28:39 +0200] Report: clients=0
D [28/Jun/2020:11:28:39 +0200] Report: jobs=21
D [28/Jun/2020:11:28:39 +0200] Report: jobs-active=0
D [28/Jun/2020:11:28:39 +0200] Report: printers=2
D [28/Jun/2020:11:28:39 +0200] Report: stringpool-string-count=3320
D [28/Jun/2020:11:28:39 +0200] Report: stringpool-alloc-bytes=12472
D [28/Jun/2020:11:28:39 +0200] Report: stringpool-total-bytes=68064

comment:7 Changed 3 months ago by Antoine Martin

I've managed to reproduce more unicode errors, r26831 fixes those.

This may be why you were seeing these messages in your xpra server log:

not sending to ClientConnection(1 : WebSocket(ws socket: 192.168.0.50:10000 <- 192.168.0.3:54838)) (uuid=33eb35ec-d28b-1db7-d757-eb3ea09e18bd, wanted uuid=324125a9-8de4-93a2-cf59-2003fe522a1b)
not sending to ClientConnection(5 : Protocol(unix-domain socket:/run/user/0/xpra/test-10000)) (uuid=27b6fd3c98e34649d9a26a271cc83eaace4eaf58, wanted uuid=324125a9-8de4-93a2-cf59-2003fe522a1b)
'b'Untitled 1'' (7KB) sent to 0 clients for printing

Though I don't understand why your connection uuid is completely different there.

Printing works for me with Firefox, with chrome I think that the popup gets blocked silently now (this definitely used to work).

FYI: you may also need to disable SELinux if you get AVCs.

comment:8 Changed 3 months ago by Dušan Vejnovič

I was restarting the server, still not working: cannot get window for saving printed document. SELinux is disabled, connection uuid is still different.

comment:9 Changed 3 months ago by Antoine Martin

connection uuid is still different.

It should match.
Maybe the printer you selected was created by a different connection / user / session?
The uuid is stored as source in the DEVICE_URI of the printer.
It is unique per client connection.

comment:10 Changed 3 months ago by Dušan Vejnovič

Resolution: fixed
Status: newclosed

I have manually delete printer from CUPS. Now I can get printed document. Thank you.
I will close this ticket for now.

Note: See TracTickets for help on using tickets.