Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss
Bug#887495: cups-browsed: 'No destination host name supplied by cups-browsed for printer "name", is cups-browsed running?' for all queues
213 views
Skip to first unread message
Jens Holzkämper
Jan 17, 2018, 7:50:02 AM1/17/18
to
Package: cups-browsed
Version: 1.11.6-3
Severity: normal
We have a central cups print server (and one client offering a queue for a not network-connected printer) and about 50 identically configured clients running a current stable using it to print. On one specific client sometimes all printer queues stop working, giving the error message 'No destination host name supplied by cups-browsed for printer "name of the queue", is cups-browsed running?'.
Restarting the cups and cups-browsed services does not fix the behaviour; most of the times a reboot does, but not always.
Comparing the two browsed debug logs of the affected and and unaffected client I notice after printing (or trying to print) a test page, that the affected one is missing the lines, showing that the cups server contacted it. I'll attach the excerpt of the cups debug log showing the last connection attempts (of forty before cups gives up) below.
Changes to queues on the server get communicated through to cups by cups-browsed so communication in that direction seems to be working.
Both cups and cups-browsed on the client are currently running with the debug logs enabled, so if you need any more info I'll hopefully be able to provide it.
Probably just a coincidence but I'll mention it: The user of the affected client is the only one of ours that's running KDE as desktop.
-- System Information:
Debian Release: 9.3
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 4.9.0-5-amd64 (SMP w/4 CPU cores)
Locale: LANG=de_DE.UTF-8, LC_CTYPE=de_DE.UTF-8 (charmap=UTF-8), LANGUAGE=en_US:en (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages cups-browsed depends on:
ii cups-daemon 2.2.1-8
ii init-system-helpers 1.48
ii libavahi-client3 0.6.32-2
ii libavahi-common3 0.6.32-2
ii libavahi-glib1 0.6.32-2
ii libc6 2.24-11+deb9u1
ii libcups2 2.2.1-8
ii libglib2.0-0 2.50.3-2
ii libldap-2.4-2 2.4.44+dfsg-5+deb9u1
ii lsb-base 9.20161125
Versions of packages cups-browsed recommends:
ii avahi-daemon 0.6.32-2
cups-browsed suggests no packages.
-- Configuration Files:
/etc/cups/cups-browsed.conf changed:
LogDir /var/log/cups
DebugLogging file
BrowseRemoteProtocols cups
BrowseAllow 141.66.176.24
BrowseAllow cups.zblmath.fiz-karlsruhe.de
BrowsePoll 141.66.176.24
BrowsePoll cups.zblmath.fiz-karlsruhe.de
-- debconf-show failed
/var/log/cups/error_log:
D [17/Jan/2018:12:56:41 +0100] [Client 52] Closing connection.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=21)
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=-1)
I [17/Jan/2018:12:56:41 +0100] Expiring subscriptions...
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] cupsdAcceptClient(lis=0x559574abed90(3)) Clients=4
D [17/Jan/2018:12:56:41 +0100] [Client 53] Server address is "/var/run/cups/cups.sock".
D [17/Jan/2018:12:56:41 +0100] [Client 53] Accepted from localhost (Domain)
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Waiting for request.
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 53] POST / HTTP/1.1
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:41 +0100] [Client 53] Read: status=200
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: uri="/", limit=10...
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin(6) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /(1) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: best=/
d [17/Jan/2018:12:56:41 +0100] [Client 53] con->uri="/", con->best=0x559574abe120(/)
D [17/Jan/2018:12:56:41 +0100] [Client 53] No authentication data provided.
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574abe120(/)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [17/Jan/2018:12:56:41 +0100] [Client 53] 2.0 Get-Printer-Attributes 39
d [17/Jan/2018:12:56:41 +0100] cupsdProcessIPPRequest(0x5595753122a0[53]): operation_id = 000b
D [17/Jan/2018:12:56:41 +0100] Get-Printer-Attributes ipp://localhost:631/printers/copier
d [17/Jan/2018:12:56:41 +0100] get_printer_attrs(0x5595753122a0[53], ipp://localhost:631/printers/copier)
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp(p=0x559574abf450, op=b(Get-Printer-Attributes))
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp: Found wildcard match...
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574ac2d70((null))
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: op=0(0x0000)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b803a0, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b80650, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574ae2130, ra=0x55957530cc10, group=0, quickcopy=-2147483648)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/copier) from localhost
D [17/Jan/2018:12:56:41 +0100] [Client 53] Content-Length: 680
D [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=0x55957473ba50, data=0x5595753122a0)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Client 53] con->http=0x55957531d170
D [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=680, response=0x55957530cef0(IPP_STATE_DATA),
pipe_pid=0, file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 53] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [17/Jan/2018:12:56:41 +0100] [Client 53] bytes=0, http_state=0, data_remaining=680
D [17/Jan/2018:12:56:41 +0100] [Client 53] Flushing write buffer.
D [17/Jan/2018:12:56:41 +0100] [Client 53] New state is HTTP_STATE_WAITING
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Waiting for request.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Job 578] Read cups-browsed-dest-printer option: (null)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 53] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Closing connection.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=21)
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=-1)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] cupsdAcceptClient(lis=0x559574abed90(3)) Clients=4
D [17/Jan/2018:12:56:41 +0100] [Client 54] Server address is "/var/run/cups/cups.sock".
D [17/Jan/2018:12:56:41 +0100] [Client 54] Accepted from localhost (Domain)
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 54] Waiting for request.
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] [Client 54] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 54] POST / HTTP/1.1
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:41 +0100] [Client 54] Read: status=200
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: uri="/", limit=10...
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin(6) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /(1) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: best=/
d [17/Jan/2018:12:56:41 +0100] [Client 54] con->uri="/", con->best=0x559574abe120(/)
D [17/Jan/2018:12:56:41 +0100] [Client 54] No authentication data provided.
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574abe120(/)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [17/Jan/2018:12:56:41 +0100] [Client 54] 2.0 Get-Printer-Attributes 40
d [17/Jan/2018:12:56:41 +0100] cupsdProcessIPPRequest(0x5595753122a0[54]): operation_id = 000b
D [17/Jan/2018:12:56:41 +0100] Get-Printer-Attributes ipp://localhost:631/printers/copier
d [17/Jan/2018:12:56:41 +0100] get_printer_attrs(0x5595753122a0[54], ipp://localhost:631/printers/copier)
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp(p=0x559574abf450, op=b(Get-Printer-Attributes))
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp: Found wildcard match...
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574ac2d70((null))
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: op=0(0x0000)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b803a0, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b80650, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574ae2130, ra=0x55957530cc10, group=0, quickcopy=-2147483648)
D [17/Jan/2018:12:56:41 +0100] [Client 54] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/copier) from localhost
D [17/Jan/2018:12:56:41 +0100] [Client 54] Content-Length: 680
D [17/Jan/2018:12:56:41 +0100] [Client 54] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=0x55957473ba50, data=0x5595753122a0)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Client 54] con->http=0x55957531d170
D [17/Jan/2018:12:56:41 +0100] [Client 54] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=680, response=0x55957530cef0(IPP_STATE_DATA),
pipe_pid=0, file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 54] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [17/Jan/2018:12:56:41 +0100] [Client 54] bytes=0, http_state=0, data_remaining=680
D [17/Jan/2018:12:56:41 +0100] [Client 54] Flushing write buffer.
D [17/Jan/2018:12:56:41 +0100] [Client 54] New state is HTTP_STATE_WAITING
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 54] Waiting for request.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Job 578] Read cups-browsed-dest-printer option: (null)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
E [17/Jan/2018:12:56:42 +0100] [Job 578] No destination host name supplied by cups-browsed for printer \"copier\", is cups-browsed running?
D [17/Jan/2018:12:56:42 +0100] cupsdMarkDirty(---J-)
D [17/Jan/2018:12:56:42 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:42 +0100] cupsdMarkDirty(---J-)
D [17/Jan/2018:12:56:42 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:42 +0100] [Job 578] Set job-printer-state-message to "No destination host name supplied by cups-browsed for printer \"copier\", is cups-browsed running?", current level=ERROR
d [17/Jan/2018:12:56:42 +0100] cupsdAddEvent(event=job-progress, dest=0x559574af7eb0(copier), job=0x55957530d5b0(578), text="%s", ...)
d [17/Jan/2018:12:56:42 +0100] cupsd_send_notification(sub=0x559574ace620(183), event=0x559575300740(job-progress))
d [17/Jan/2018:12:56:42 +0100] sub->pipe=16
--
FIZ Karlsruhe - Leibniz-Institut für Informationsinfrastruktur GmbH.
Sitz der Gesellschaft: Eggenstein-Leopoldshafen, Amtsgericht Mannheim, HRB 101892.
Geschäftsführerin: Sabine Brünger-Weilandt.
Vorsitzender des Aufsichtsrats: MinDirig Dr. Stefan Luther.
Version: 1.11.6-3
Severity: normal
We have a central cups print server (and one client offering a queue for a not network-connected printer) and about 50 identically configured clients running a current stable using it to print. On one specific client sometimes all printer queues stop working, giving the error message 'No destination host name supplied by cups-browsed for printer "name of the queue", is cups-browsed running?'.
Restarting the cups and cups-browsed services does not fix the behaviour; most of the times a reboot does, but not always.
Comparing the two browsed debug logs of the affected and and unaffected client I notice after printing (or trying to print) a test page, that the affected one is missing the lines, showing that the cups server contacted it. I'll attach the excerpt of the cups debug log showing the last connection attempts (of forty before cups gives up) below.
Changes to queues on the server get communicated through to cups by cups-browsed so communication in that direction seems to be working.
Both cups and cups-browsed on the client are currently running with the debug logs enabled, so if you need any more info I'll hopefully be able to provide it.
Probably just a coincidence but I'll mention it: The user of the affected client is the only one of ours that's running KDE as desktop.
-- System Information:
Debian Release: 9.3
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 4.9.0-5-amd64 (SMP w/4 CPU cores)
Locale: LANG=de_DE.UTF-8, LC_CTYPE=de_DE.UTF-8 (charmap=UTF-8), LANGUAGE=en_US:en (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages cups-browsed depends on:
ii cups-daemon 2.2.1-8
ii init-system-helpers 1.48
ii libavahi-client3 0.6.32-2
ii libavahi-common3 0.6.32-2
ii libavahi-glib1 0.6.32-2
ii libc6 2.24-11+deb9u1
ii libcups2 2.2.1-8
ii libglib2.0-0 2.50.3-2
ii libldap-2.4-2 2.4.44+dfsg-5+deb9u1
ii lsb-base 9.20161125
Versions of packages cups-browsed recommends:
ii avahi-daemon 0.6.32-2
cups-browsed suggests no packages.
-- Configuration Files:
/etc/cups/cups-browsed.conf changed:
LogDir /var/log/cups
DebugLogging file
BrowseRemoteProtocols cups
BrowseAllow 141.66.176.24
BrowseAllow cups.zblmath.fiz-karlsruhe.de
BrowsePoll 141.66.176.24
BrowsePoll cups.zblmath.fiz-karlsruhe.de
-- debconf-show failed
/var/log/cups/error_log:
D [17/Jan/2018:12:56:41 +0100] [Client 52] Closing connection.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=21)
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=-1)
I [17/Jan/2018:12:56:41 +0100] Expiring subscriptions...
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] cupsdAcceptClient(lis=0x559574abed90(3)) Clients=4
D [17/Jan/2018:12:56:41 +0100] [Client 53] Server address is "/var/run/cups/cups.sock".
D [17/Jan/2018:12:56:41 +0100] [Client 53] Accepted from localhost (Domain)
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Waiting for request.
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 53] POST / HTTP/1.1
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:41 +0100] [Client 53] Read: status=200
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: uri="/", limit=10...
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin(6) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /(1) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: best=/
d [17/Jan/2018:12:56:41 +0100] [Client 53] con->uri="/", con->best=0x559574abe120(/)
D [17/Jan/2018:12:56:41 +0100] [Client 53] No authentication data provided.
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574abe120(/)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [17/Jan/2018:12:56:41 +0100] [Client 53] 2.0 Get-Printer-Attributes 39
d [17/Jan/2018:12:56:41 +0100] cupsdProcessIPPRequest(0x5595753122a0[53]): operation_id = 000b
D [17/Jan/2018:12:56:41 +0100] Get-Printer-Attributes ipp://localhost:631/printers/copier
d [17/Jan/2018:12:56:41 +0100] get_printer_attrs(0x5595753122a0[53], ipp://localhost:631/printers/copier)
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp(p=0x559574abf450, op=b(Get-Printer-Attributes))
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp: Found wildcard match...
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574ac2d70((null))
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: op=0(0x0000)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b803a0, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b80650, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574ae2130, ra=0x55957530cc10, group=0, quickcopy=-2147483648)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/copier) from localhost
D [17/Jan/2018:12:56:41 +0100] [Client 53] Content-Length: 680
D [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=0x55957473ba50, data=0x5595753122a0)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Client 53] con->http=0x55957531d170
D [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=680, response=0x55957530cef0(IPP_STATE_DATA),
pipe_pid=0, file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 53] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [17/Jan/2018:12:56:41 +0100] [Client 53] bytes=0, http_state=0, data_remaining=680
D [17/Jan/2018:12:56:41 +0100] [Client 53] Flushing write buffer.
D [17/Jan/2018:12:56:41 +0100] [Client 53] New state is HTTP_STATE_WAITING
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Waiting for request.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Job 578] Read cups-browsed-dest-printer option: (null)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] [Client 53] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 53] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [17/Jan/2018:12:56:41 +0100] [Client 53] Closing connection.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=21)
d [17/Jan/2018:12:56:41 +0100] cupsdRemoveSelect(fd=-1)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] cupsdAcceptClient(lis=0x559574abed90(3)) Clients=4
D [17/Jan/2018:12:56:41 +0100] [Client 54] Server address is "/var/run/cups/cups.sock".
D [17/Jan/2018:12:56:41 +0100] [Client 54] Accepted from localhost (Domain)
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 54] Waiting for request.
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
d [17/Jan/2018:12:56:41 +0100] [Client 54] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 54] POST / HTTP/1.1
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:41 +0100] [Client 54] Read: status=200
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: uri="/", limit=10...
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /admin(6) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: Location /(1) Limit 7f
d [17/Jan/2018:12:56:41 +0100] cupsdFindBest: best=/
d [17/Jan/2018:12:56:41 +0100] [Client 54] con->uri="/", con->best=0x559574abe120(/)
D [17/Jan/2018:12:56:41 +0100] [Client 54] No authentication data provided.
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574abe120(/)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [17/Jan/2018:12:56:41 +0100] [Client 54] 2.0 Get-Printer-Attributes 40
d [17/Jan/2018:12:56:41 +0100] cupsdProcessIPPRequest(0x5595753122a0[54]): operation_id = 000b
D [17/Jan/2018:12:56:41 +0100] Get-Printer-Attributes ipp://localhost:631/printers/copier
d [17/Jan/2018:12:56:41 +0100] get_printer_attrs(0x5595753122a0[54], ipp://localhost:631/printers/copier)
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp(p=0x559574abf450, op=b(Get-Printer-Attributes))
d [17/Jan/2018:12:56:41 +0100] cupsdFindPolicyOp: Found wildcard match...
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x559574ac2d70((null))
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: op=0(0x0000)
d [17/Jan/2018:12:56:41 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b803a0, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574b80650, ra=0x55957530cc10, group=0, quickcopy=0)
d [17/Jan/2018:12:56:41 +0100] copy_attrs(to=0x55957530cef0, from=0x559574ae2130, ra=0x55957530cc10, group=0, quickcopy=-2147483648)
D [17/Jan/2018:12:56:41 +0100] [Client 54] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/copier) from localhost
D [17/Jan/2018:12:56:41 +0100] [Client 54] Content-Length: 680
D [17/Jan/2018:12:56:41 +0100] [Client 54] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=0x55957473ba50, data=0x5595753122a0)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Client 54] con->http=0x55957531d170
D [17/Jan/2018:12:56:41 +0100] [Client 54] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=680, response=0x55957530cef0(IPP_STATE_DATA),
pipe_pid=0, file=-1
D [17/Jan/2018:12:56:41 +0100] [Client 54] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [17/Jan/2018:12:56:41 +0100] [Client 54] bytes=0, http_state=0, data_remaining=680
D [17/Jan/2018:12:56:41 +0100] [Client 54] Flushing write buffer.
D [17/Jan/2018:12:56:41 +0100] [Client 54] New state is HTTP_STATE_WAITING
d [17/Jan/2018:12:56:41 +0100] cupsdAddSelect(fd=21, read_cb=0x55957473c370, write_cb=(nil), data=0x5595753122a0)
D [17/Jan/2018:12:56:41 +0100] [Client 54] Waiting for request.
D [17/Jan/2018:12:56:41 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
D [17/Jan/2018:12:56:41 +0100] [Job 578] Read cups-browsed-dest-printer option: (null)
d [17/Jan/2018:12:56:41 +0100] select_timeout: JobHistoryUpdate=0
E [17/Jan/2018:12:56:42 +0100] [Job 578] No destination host name supplied by cups-browsed for printer \"copier\", is cups-browsed running?
D [17/Jan/2018:12:56:42 +0100] cupsdMarkDirty(---J-)
D [17/Jan/2018:12:56:42 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:42 +0100] cupsdMarkDirty(---J-)
D [17/Jan/2018:12:56:42 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [17/Jan/2018:12:56:42 +0100] [Job 578] Set job-printer-state-message to "No destination host name supplied by cups-browsed for printer \"copier\", is cups-browsed running?", current level=ERROR
d [17/Jan/2018:12:56:42 +0100] cupsdAddEvent(event=job-progress, dest=0x559574af7eb0(copier), job=0x55957530d5b0(578), text="%s", ...)
d [17/Jan/2018:12:56:42 +0100] cupsd_send_notification(sub=0x559574ace620(183), event=0x559575300740(job-progress))
d [17/Jan/2018:12:56:42 +0100] sub->pipe=16
--
FIZ Karlsruhe - Leibniz-Institut für Informationsinfrastruktur GmbH.
Sitz der Gesellschaft: Eggenstein-Leopoldshafen, Amtsgericht Mannheim, HRB 101892.
Geschäftsführerin: Sabine Brünger-Weilandt.
Vorsitzender des Aufsichtsrats: MinDirig Dr. Stefan Luther.
Christoph Pleger
Mar 26, 2018, 8:00:03 AM3/26/18
to
Hello,
I discovered the same problem on my computer today and found out that it
is NO coincidence that the problem occurs on the KDE desktop.
After several unsuccessful attempts of getting it to work under KDE by
stopping cups and cups-browsed, editing configuration files, deleting
all files from /var/cache/cups and starting daemons again, I read your
post, then logged out of KDE, re-logged in with MATE, did the same as
before, except from editing configuration, and then, printing was
successful. I logged out from MATE, re-logged in under KDE and then,
printing did also work with KDE. Another daemon restart after deleting
cache files, error occurred again. Logged out, in again with KDE,
printing worked.
Beside the fact that printing worked immediately with another desktop
environment, but only with problems in KDE, I noticed another
difference: In MATE, files
/var/cache/cups/cups-browsed-options-´<printer> were created soon after
the printer information broadcast messages had been received, while in
KDE these files were created not before cups-browsed was stopped.
Regards
Christoph
I discovered the same problem on my computer today and found out that it
is NO coincidence that the problem occurs on the KDE desktop.
After several unsuccessful attempts of getting it to work under KDE by
stopping cups and cups-browsed, editing configuration files, deleting
all files from /var/cache/cups and starting daemons again, I read your
post, then logged out of KDE, re-logged in with MATE, did the same as
before, except from editing configuration, and then, printing was
successful. I logged out from MATE, re-logged in under KDE and then,
printing did also work with KDE. Another daemon restart after deleting
cache files, error occurred again. Logged out, in again with KDE,
printing worked.
Beside the fact that printing worked immediately with another desktop
environment, but only with problems in KDE, I noticed another
difference: In MATE, files
/var/cache/cups/cups-browsed-options-´<printer> were created soon after
the printer information broadcast messages had been received, while in
KDE these files were created not before cups-browsed was stopped.
Regards
Christoph
Marc Haber
Oct 11, 2018, 7:30:03 AM10/11/18
to
On Mon, Mar 26, 2018 at 01:43:00PM +0200, Christoph Pleger wrote:
> I discovered the same problem on my computer today and found out that it is
> NO coincidence that the problem occurs on the KDE desktop.
Half a year later without maintainer response on this bug, I stumbled
> I discovered the same problem on my computer today and found out that it is
> NO coincidence that the problem occurs on the KDE desktop.
about this issue and had the same issue on my system. I would NEVER have
come to the conclusion that the desktop environment in use plays a role
in this issue which presents itself as rooted deeply between system
daemons and network issues.
The absolutely inadequate debug logging of the software in question has
not made it any easier to debug this issue.
That being said, my system prints again.
What did not help:
Activate KDE screen saver, start additional session, log in with the
same account with lxqt, try printing from there (didn't work, same
error).
What helped:
Log out of KDE, start new session with same account with lxqt, try
printing from there (worked), log out of lxqrt, log into KDE with the
smae account (worked).
This is one of the most mysterious and astonishing issuest hat I have
encountered in my lifetime. Kudos for nailing this down to KDE.
Greetings
Marc
Brian Potkin
Oct 13, 2018, 12:40:03 PM10/13/18
to
Thank you for your reports, Jens, christoph and Marc. For the avoidance
of doubt - I am not a cups-browsed maintainer.
On Thu 11 Oct 2018 at 13:16:13 +0200, Marc Haber wrote:
> On Mon, Mar 26, 2018 at 01:43:00PM +0200, Christoph Pleger wrote:
> > I discovered the same problem on my computer today and found out that it is
> > NO coincidence that the problem occurs on the KDE desktop.
>
> Half a year later without maintainer response on this bug, I stumbled
> about this issue and had the same issue on my system. I would NEVER have
> come to the conclusion that the desktop environment in use plays a role
> in this issue which presents itself as rooted deeply between system
> daemons and network issues.
It is unlikely to be a DE issue. I came across the behaviour today while
working in a non-KDE environment and printing from LibreOffice and with
lp.
Only Jens provides the cups version being used and modifications to
cups-browsed.conf made. For me, its cups v2.2.8 and having "driverless"
for the CreateIPPPrinterQueues directive as the only change. On the
surface, we are using different printing systems. I am only inclined to
conduct tests on unstable. "BrowseRemoteProtocols cups" doesn't motivate
me.
> The absolutely inadequate debug logging of the software in question has
> not made it any easier to debug this issue.
Has anyone managed consistently to reproduce the reported behaviour? I
haven't yet formulated a plan of attack to do so.
> That being said, my system prints again.
>
> What did not help:
> Activate KDE screen saver, start additional session, log in with the
> same account with lxqt, try printing from there (didn't work, same
> error).
>
> What helped:
> Log out of KDE, start new session with same account with lxqt, try
> printing from there (worked), log out of lxqrt, log into KDE with the
> smae account (worked).
>
> This is one of the most mysterious and astonishing issuest hat I have
> encountered in my lifetime. Kudos for nailing this down to KDE.
KDE? Maybe, maybe not. Perhaps the "No destination host name supplied..."
message has three different causes?
Regards,
Brian.
of doubt - I am not a cups-browsed maintainer.
On Thu 11 Oct 2018 at 13:16:13 +0200, Marc Haber wrote:
> On Mon, Mar 26, 2018 at 01:43:00PM +0200, Christoph Pleger wrote:
> > I discovered the same problem on my computer today and found out that it is
> > NO coincidence that the problem occurs on the KDE desktop.
>
> Half a year later without maintainer response on this bug, I stumbled
> about this issue and had the same issue on my system. I would NEVER have
> come to the conclusion that the desktop environment in use plays a role
> in this issue which presents itself as rooted deeply between system
> daemons and network issues.
working in a non-KDE environment and printing from LibreOffice and with
lp.
Only Jens provides the cups version being used and modifications to
cups-browsed.conf made. For me, its cups v2.2.8 and having "driverless"
for the CreateIPPPrinterQueues directive as the only change. On the
surface, we are using different printing systems. I am only inclined to
conduct tests on unstable. "BrowseRemoteProtocols cups" doesn't motivate
me.
> The absolutely inadequate debug logging of the software in question has
> not made it any easier to debug this issue.
haven't yet formulated a plan of attack to do so.
> That being said, my system prints again.
>
> What did not help:
> Activate KDE screen saver, start additional session, log in with the
> same account with lxqt, try printing from there (didn't work, same
> error).
>
> What helped:
> Log out of KDE, start new session with same account with lxqt, try
> printing from there (worked), log out of lxqrt, log into KDE with the
> smae account (worked).
>
> This is one of the most mysterious and astonishing issuest hat I have
> encountered in my lifetime. Kudos for nailing this down to KDE.
message has three different causes?
Regards,
Brian.
Brian Potkin
Oct 14, 2018, 2:40:02 AM10/14/18
to
On Sat 13 Oct 2018 at 17:27:18 +0100, Brian Potkin wrote:
> KDE? Maybe, maybe not. Perhaps the "No destination host name supplied..."
> message has three different causes?
Should have said four. I brought my problem on myself by forgetting I
> KDE? Maybe, maybe not. Perhaps the "No destination host name supplied..."
> message has three different causes?
had disabled the queue I was printing to. :(
--
Brian.
0 new messages