lp: Bad Request #5211

swbil · 2018-01-02T13:01:46Z

Server: cups 1.3.7
Client: Kbuntu 17.04 / Fedora 27 (since cups-Version 2.2.4-2.3b1)

Work: Printing from firefox
Don't Work: Printing from LibreOffice, Okular or lp

~> lp -d lama /etc/hosts
lp: Bad Request

debug2-LogLevel

d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: Write on fd 10...
d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: polling 7 fds for 1 seconds...
d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: epoll() returned 1...
d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: Write on fd 10...
d [02/Jan/2018:13:46:14 +0100] cupsdWriteClient: 10 bytes < 0
d [02/Jan/2018:13:46:14 +0100] cupsdAddSelect: fd=10, read_cb=0x40f013, write_cb=(nil), data=0x59de20
d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: polling 7 fds for 1 seconds...
d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: epoll() returned 1...
d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: Read on fd 10...
d [02/Jan/2018:13:46:14 +0100] cupsdReadClient: 10, used=0, file=-1 state=0
D [02/Jan/2018:13:46:14 +0100] cupsdReadClient: 10 POST /printers/lama HTTP/1.1
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: uri = "/printers/lama"...
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /printers/name Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /printers Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /jobs Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /classes/name Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /classes Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /admin/log Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location /admin Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: Location / Limit 7f
d [02/Jan/2018:13:46:14 +0100] cupsdFindBest: best = /printers
d [02/Jan/2018:13:46:14 +0100] cupsdAuthorize: con->uri="/printers/lama", con->best=0x555100(/printers)
d [02/Jan/2018:13:46:14 +0100] cupsdAuthorize: Authorization=""
D [02/Jan/2018:13:46:14 +0100] cupsdAuthorize: No authentication data provided.
d [02/Jan/2018:13:46:14 +0100] cupsdIsAuthorized: con->uri="/printers/lama", con->best=0x555100(/printers)
d [02/Jan/2018:13:46:14 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [02/Jan/2018:13:46:14 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [02/Jan/2018:13:46:14 +0100] POST /printers/lama
d [02/Jan/2018:13:46:14 +0100] CONTENT_TYPE = application/ipp
d [02/Jan/2018:13:46:14 +0100] cupsdReadClient: 10 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=347, con->file=-1
E [02/Jan/2018:13:46:14 +0100] cupsdReadClient: 10 IPP Read Error!
D [02/Jan/2018:13:46:14 +0100] cupsdSendError: 10 code=400 (Bad Request)
D [02/Jan/2018:13:46:14 +0100] cupsdCloseClient: 10
d [02/Jan/2018:13:46:14 +0100] cupsdRemoveSelect: fd=10
d [02/Jan/2018:13:46:14 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [02/Jan/2018:13:46:15 +0100] cupsdDoSelect: epoll() returned 0...
d [02/Jan/2018:13:46:15 +0100] select_timeout(0): 100 seconds to timeout a client connection
d [02/Jan/2018:13:46:15 +0100] cupsdDoSelect: polling 6 fds for 100 seconds...

The text was updated successfully, but these errors were encountered:

jsmeix · 2018-01-03T09:41:33Z

@swbil

Server: cups 1.3.7
Client: cups-Version 2.2.4-2.3b1

CUPS >= 1.6 has major incompatible changes
compared to CUPS up to version 1.5.4
in particular when printing via network:

The IPP protocol default version increased from 1.1 to 2.0.
Older IPP servers like CUPS 1.3.x reject IPP 2.0 requests
with "Bad Request", see
#4231

By adding '/version=1.1' to ServerName in client.conf e.g.
ServerName older.server.example.com/version=1.1
or to the CUPS_SERVER environment variable value
or by adding it to the server name value of the '-h' option e.g.
lpstat -h older.server.example.com/version=1.1 -p
the older IPP protocol version for older servers must be
specified explicitly.

Cf. the section about"CUPS Version Upgrade" in
https://www.suse.com/releasenotes/x86_64/SUSE-SLES/12/

swbil · 2018-01-03T12:02:22Z

@jsmeix: thanks for your Tip, but we already use IPP 1.1 all time. We can print from firefox under Kbuntu 17.04 / Fedora 27.

cat /etc/cups/client.conf
ServerName domainXX.com/version=1.1

lp command works with cups-client from
Ubuntu 16.10 cups-2.1.3
Debian 9.3 cups-2.2.1

Something must be changed (IPP?) from cups 2.2.1 to 2.2.4.

michaelrsweet · 2018-01-08T20:29:33Z

@swbil Can you use Wireshark to capture the traffic between the client and server? Nothing changed between 2.2.1 and 2.2.4 that would cause that kind of issue...

swbil · 2018-01-11T14:57:14Z

Dear @michaelrsweet, you and your Team did/do a great great Job in the last 20 years!! ThankYOU! Without you, we would have had to live with lpsched of SUN or Windows printserver ;-)

Thanks for the hint with wireshark! Kbuntu 17.10, Debian Testing, Fedora 28 make IPP Request (Create-Job) with !! IPP 2.0 !! only. That's why it does not work and we'got "lp: Bad Request"

Is it a cups or linux problem?

### IPP Request with IPP 1.1
74	6.599593048	10.0.2.15	X.X.X.X	IPP	297	IPP Request (Get-Printer-Attributes)

Frame 74: 297 bytes on wire (2376 bits), 297 bytes captured (2376 bits) on interface 0
Ethernet II, Src: PcsCompu_b7:d4:66 (08:00:27:b7:d4:66), Dst: RealtekU_12:35:02 (52:54:00:12:35:02)
Internet Protocol Version 4, Src: 10.0.2.15, Dst: X.X.X.X
Transmission Control Protocol, Src Port: 41348, Dst Port: 631, Seq: 2479, Ack: 28555, Len: 243
[2 Reassembled TCP Segments (493 bytes): #73(250), #74(243)]
Hypertext Transfer Protocol
Internet Printing Protocol
    [Response In: 86]
    version: 1.1
    operation-id: Get-Printer-Attributes (0x000b)
    request-id: 4
    operation-attributes-tag
    end-of-attributes-tag

### IPP Response with IPP 1.1
86	6.607292615	X.X.X.X	10.0.2.15	IPP	1175	IPP Response (successful-ok)

Frame 86: 1175 bytes on wire (9400 bits), 1175 bytes captured (9400 bits) on interface 0
Ethernet II, Src: RealtekU_12:35:02 (52:54:00:12:35:02), Dst: PcsCompu_b7:d4:66 (08:00:27:b7:d4:66)
Internet Protocol Version 4, Src: X.X.X.X, Dst: 10.0.2.15
Transmission Control Protocol, Src Port: 631, Dst Port: 41348, Seq: 32775, Ack: 2722, Len: 1121
[6 Reassembled TCP Segments (5316 bytes): #78(198), #80(1448), #82(591), #83(1448), #85(510), #86(1121)]
Hypertext Transfer Protocol
Internet Printing Protocol
    [Request In: 74]
    [Response Time: 0.007699567 seconds]
    version: 1.1
    status-code: Successful (successful-ok)
    request-id: 4
    operation-attributes-tag
    printer-attributes-tag
    end-of-attributes-tag

### IPP Request (Create-Job) with !! IPP 2.0 !!
### That's why it does not work!! 
89	6.609333682	10.0.2.15	X.X.X.X	IPP	400	IPP Request (Create-Job)

Frame 89: 400 bytes on wire (3200 bits), 400 bytes captured (3200 bits) on interface 0
Ethernet II, Src: PcsCompu_b7:d4:66 (08:00:27:b7:d4:66), Dst: RealtekU_12:35:02 (52:54:00:12:35:02)
Internet Protocol Version 4, Src: 10.0.2.15, Dst: X.X.X.X
Transmission Control Protocol, Src Port: 41348, Dst Port: 631, Seq: 2972, Ack: 33896, Len: 346
[2 Reassembled TCP Segments (596 bytes): #88(250), #89(346)]
Hypertext Transfer Protocol
Internet Printing Protocol
    version: 2.0
    operation-id: Create-Job (0x0005)
    request-id: 5
    operation-attributes-tag
    job-attributes-tag
    end-of-attributes-tag

### Error-Text to client
93	6.614426317	X.X.X.X	10.0.2.15	HTTP	610	HTTP/1.1 400 Bad Request  (text/html)

Frame 93: 610 bytes on wire (4880 bits), 610 bytes captured (4880 bits) on interface 0
Ethernet II, Src: RealtekU_12:35:02 (52:54:00:12:35:02), Dst: PcsCompu_b7:d4:66 (08:00:27:b7:d4:66)
Internet Protocol Version 4, Src: X.X.X.X, Dst: 10.0.2.15
Transmission Control Protocol, Src Port: 631, Dst Port: 41348, Seq: 33921, Ack: 3318, Len: 556
Hypertext Transfer Protocol
Line-based text data: text/html
    <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN" "http:https://www.w3.org/TR/REC-html40/loose.dtd">\n
    <HTML>\n
    <HEAD>\n
    \t<META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=utf-8">\n
    \t<TITLE>400 Bad Request</TITLE>\n
    \t<LINK REL="STYLESHEET" TYPE="text/css" HREF="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/cups.css">\n
    </HEAD>\n
    <BODY>\n
    <H1>400 Bad Request</H1>\n
    <P></P>\n
    </BODY>\n
    </HTML>\n

michaelrsweet · 2018-01-11T15:53:33Z

Hmm, will investigate but the code that sets the default IPP version hasn't changed in a long long time...

michaelrsweet · 2018-01-11T16:11:05Z

OK, I've confirmed that lp is ignoring the server version; investigating...

michaelrsweet · 2018-01-11T16:21:52Z

OK, the issue appears to be that the cupsCreateJob API now redirects to cupsCreateDestJob, which uses the destination information which tells it to use IPP/2.0... And that is because the cupsCopyDestInfo assumes that the initial version is 2.0, not 1.1... :/

Fix coming up...

cups/dest-options.c: - Fix IPP version check in cupsCopyDestInfo.

michaelrsweet · 2018-01-11T16:32:48Z

[master 6a3d63e] Printing to old CUPS servers has been fixed (Issue #5211)

swbil · 2018-01-21T09:21:13Z

Dear @michaelrsweet, thanks for the fix, but the bug (IPP 2.0) moves now to Get-Printer-Attributes
and stop from there. We don't see IPP Request (Create-Job) any more.

Can you check it, pls?

234	12.500032285	X.X.X.X	10.0.2.16	IPP	547	IPP Response (successful-ok)
Internet Printing Protocol
    [Request In: 209]
    [Response Time: 0.003834289 seconds]
    version: 1.1
    status-code: Successful (successful-ok)
    request-id: 3
    operation-attributes-tag
    printer-attributes-tag
...
    printer-attributes-tag
    end-of-attributes-tag

237	12.501271103	10.0.2.16	X.X.X.X	IPP	308	IPP Request (Get-Printer-Attributes)
Frame 237: 308 bytes on wire (2464 bits), 308 bytes captured (2464 bits) on interface 0
Ethernet II, Src: LcfcHefe_7d:a8:3a (28:d2:44:7d:a8:3a), Dst: Cisco_ff:fd:90 (00:08:e3:ff:fd:90)
Internet Protocol Version 4, Src: 10.0.2.16, Dst: X.X.X.X
Transmission Control Protocol, Src Port: 38386, Dst Port: 631, Seq: 2409, Ack: 28555, Len: 242
[2 Reassembled TCP Segments (475 bytes): #236(233), #237(242)]
Hypertext Transfer Protocol
Internet Printing Protocol
    version: 2.0
    operation-id: Get-Printer-Attributes (0x000b)
    request-id: 4
    operation-attributes-tag
    end-of-attributes-tag

239	12.501458646	X.X.X.X	10.0.2.16	HTTP	622	HTTP/1.1 400 Bad Request  (text/html)
Frame 239: 622 bytes on wire (4976 bits), 622 bytes captured (4976 bits) on interface 0
Ethernet II, Src: Cisco_ff:fd:90 (00:08:e3:ff:fd:90), Dst: LcfcHefe_7d:a8:3a (28:d2:44:7d:a8:3a)
Internet Protocol Version 4, Src: X.X.X.X, Dst: 10.0.2.16
Transmission Control Protocol, Src Port: 631, Dst Port: 38386, Seq: 28580, Ack: 2651, Len: 556
Hypertext Transfer Protocol
Line-based text data: text/html
    <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN" "http:https://www.w3.org/TR/REC-html40/loose.dtd">\n
    <HTML>\n
    <HEAD>\n
    \t<META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=utf-8">\n
    \t<TITLE>400 Bad Request</TITLE>\n
    \t<LINK REL="STYLESHEET" TYPE="text/css" HREF="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/cups.css">\n
    </HEAD>\n
    <BODY>\n
    <H1>400 Bad Request</H1>\n
    <P></P>\n
    </BODY>\n
    </HTML>\n

swbil · 2018-01-23T14:49:28Z

Dear @michaelrsweet,

it works if I make a quick and dirty change at line 716 in cups/dest-options.c from cups-2.3b2-source.tar.gz

-  version    = 20;
+  version    = 11;

swbil · 2018-01-31T17:08:18Z

Hi @michaelrsweet, I can't reopen this issue. Can you reopen for me, please?

michaelrsweet · 2018-01-31T18:39:38Z

That change won't work since 1.1 clients don't get collection attributes.

Reopening while I determine why the negotiated version number isn't being used.

michaelrsweet · 2018-02-01T00:32:32Z

[master b969d5a] Fix additional IPP/1.1 issues with cupsCopyDestInfo (Issue #5211)

michaelrsweet · 2018-02-01T01:21:59Z

[master 27551f0] One more fix for _cupsGetDestResource (Issue #5211)

Update ippserver to support maximum version option (-V max-version) Update cupsCopyDestInfo to recognize when we are talking to the CUPS server and when we are talking to the device (so we get the right URI for the printer) Add "--device" option to testdest.

- Fixed a compile issue when PAM is not available (Issue #5253) - Documentation fixes (Issue #5252) - Star Micronics printers need the "unidir" USB quirk rule (Issue #5251) - The scheduler now supports using temporary print queues for older IPP/1.1 print queues like those shared by CUPS 1.3 and earlier (Issue #5241) - The `cupsRasterWritePixels` function did not correctly swap bytes for some formats (Issue #5225) - Added a USB quirk rule for Canon MP280 series printers (Issue #5221) - The `ppdInstallableConflict` tested too many constraints (Issue #5213) - More fixes for printing to old CUPS servers (Issue #5211) - The `cupsCopyDest` function now correctly copies the `is_default` value (Issue #5208) - The scheduler did not work with older versions of uClibc (Issue #5188) - The scheduler now substitutes default values for invalid job attributes when running in "relaxed conformance" mode (Issue #5186) - Fixed PAM module detection and added support for the common PAM definitions (Issue #5185) - Fixed a journald support bug in the scheduler (Issue #5181) - The cups-driverd program incorrectly stopped scanning PPDs as soon as a loop was seen (Issue #5170) - Fixed group validation on OpenBSD (Issue #5166) - Fixed the `ippserver` sample code when threading is disabled or unavailable (Issue #5154) - The `cupsEnumDests` function did not include options from the lpoptions files (Issue #5144) - The `SSLOptions` directive now supports `MinTLS` and `MaxTLS` options to control the minimum and maximum TLS versions that will be allowed, respectively (Issue #5119) - The scheduler did not write out dirty configuration and state files if there were open client connections (Issue #5118) - The `lpadmin` command now provides a better error message when an unsupported System V interface script is used (Issue #5111) - The `lp` and `lpr` commands now provide better error messages when the default printer cannot be found (Issue #5096) - No longer support backslash, question mark, or quotes in printer names (Issue #4966) - The CUPS library now supports the latest HTTP Digest authentication specification including support for SHA-256 (Issue #4862) - The `lpstat` command now reports when new jobs are being held (Issue #4761) - The `lpoptions` command incorrectly saved default options (Issue #4717) - The `ppdLocalizeIPPReason` function incorrectly returned a localized version of "none" (rdar:https://36566269) - TLS connections now properly timeout (rdar:https://34938533) - The IPP backend did not properly detect failed PDF prints (rdar:https://34055474)

michaelrsweet self-assigned this Jan 8, 2018

michaelrsweet added the investigating Investigating the issue label Jan 8, 2018

michaelrsweet added this to the CUPS 2.3.x milestone Jan 11, 2018

michaelrsweet added priority-high and removed investigating Investigating the issue labels Jan 11, 2018

michaelrsweet pushed a commit that referenced this issue Jan 11, 2018

Printing to old CUPS servers has been fixed (Issue #5211)

6a3d63e

cups/dest-options.c: - Fix IPP version check in cupsCopyDestInfo.

michaelrsweet closed this as completed Jan 11, 2018

michaelrsweet reopened this Jan 31, 2018

michaelrsweet closed this as completed Feb 1, 2018

michaelrsweet added a commit that referenced this issue Feb 1, 2018

One more fix for _cupsGetDestResource (Issue #5211)

27551f0

michaelrsweet mentioned this issue Feb 26, 2018

Back port important CUPS 2.3.x changes to 2.2.x #5255

Closed

rcoss mentioned this issue May 28, 2019

Backporting patch for #5211 to 2.2.7 #5587

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

lp: Bad Request #5211

lp: Bad Request #5211

swbil commented Jan 2, 2018 •

edited

jsmeix commented Jan 3, 2018

swbil commented Jan 3, 2018 •

edited

michaelrsweet commented Jan 8, 2018

swbil commented Jan 11, 2018 •

edited

michaelrsweet commented Jan 11, 2018

michaelrsweet commented Jan 11, 2018

michaelrsweet commented Jan 11, 2018

michaelrsweet commented Jan 11, 2018

swbil commented Jan 21, 2018

swbil commented Jan 23, 2018

swbil commented Jan 31, 2018

michaelrsweet commented Jan 31, 2018

michaelrsweet commented Feb 1, 2018

michaelrsweet commented Feb 1, 2018

lp: Bad Request #5211

lp: Bad Request #5211

Comments

swbil commented Jan 2, 2018 • edited

debug2-LogLevel

jsmeix commented Jan 3, 2018

swbil commented Jan 3, 2018 • edited

michaelrsweet commented Jan 8, 2018

swbil commented Jan 11, 2018 • edited

michaelrsweet commented Jan 11, 2018

michaelrsweet commented Jan 11, 2018

michaelrsweet commented Jan 11, 2018

michaelrsweet commented Jan 11, 2018

swbil commented Jan 21, 2018

swbil commented Jan 23, 2018

swbil commented Jan 31, 2018

michaelrsweet commented Jan 31, 2018

michaelrsweet commented Feb 1, 2018

michaelrsweet commented Feb 1, 2018

swbil commented Jan 2, 2018 •

edited

swbil commented Jan 3, 2018 •

edited

swbil commented Jan 11, 2018 •

edited