Authentication problem in libcups functions used by pycups

[jpl166]

We have two environments, one which works, one which does not. We're authenticating everything about printing using CUPS 2.2.3 or 2.2.6, and using pycups 1.9.73 to drive. The system works using CUPS 2.2.3 but not 2.2.6.

Digging through the network trace, when we issue a getPrinters in pycups, which calls cupsDoRequest under the covers, I see it pass "Authorization: Basic username:password" (base64 encoded, of course) and the printer list comes back. Then the test script does a printFile, which calls cupsPrintFile2, sending it the same http connection struct, and what goes out on the wire is "Authorization: Basic username:" with no password. This obviously fails hard, since we're requiring valid authentication.

Both servers are FreeBSD 11.1.

We've put in place a bit of a hack workaround by blocking most access to the 2.2.6 server and running without authentication, which works fine. It's not really acceptable in our environment long-term, though.

Our test script:

import cups
cups.setServer("server name")
cups.setEncryption(3)
cups.setPort(631)
def tom(p):
return "password"
cups.setUser("user")
cups.setPasswordCB(tom)
c = cups.Connection()
c.getPrinters()
c.printFile('PRINTER','FILE',"Tom Test",{'document-format':'application/vnd.cups-raw'})

[michaelrsweet]

@jpl166 I'm not aware of any specific changes in this area between 2.2.3 and 2.2.6... Can you reproduce this with a C program and not the pycups API?

[jpl166]

I'm a sysadmin, not a programmer. I wouldn't know where to begin. I know enough about how things work to read the code and make some sense of it, but not enough to functionally write my own, unfortunately.

[jpl166]

I also did open this ticket with the pycups folks as well as here, because it's certainly possible that they're mangling the http_t struct contents between consecutive calls from Python - there's plenty of room in what the Python is doing that I have little or no visibility into. But presuming that they're calling with the same, unaltered contents of that one variable, it seems like something isn't handing the "No, you aren't authorized, gimme a username and password" challenge correctly. And that seems to be in libcups. I think.

I wish I could send you the network trace contents, it's really obvious that the two consecutive IPP calls are different in what they're sending for authentication... but that would involve giving you the base64 encoded username and password functionally in plaintext.

[zdohnal]

Hi Mike,
actually I'm upstream of python-cups :) . I think this is connected to the fact, that user is connecting to remote cups. Because printFile method calls cupsPrintFile2, which calls cupsCreateJob and it calls cupsEnumDests, which isn't using http connection as parameter and thinks only about local cups...
Or maybe #5235 is connected?

[michaelrsweet]

cupsEnumDests uses the cupsServer setting to determine which server to use, so it should just work.

That said, I think we can use a more efficient path (call cupsGetNamedDest instead of cupsEnumDests) for the legacy print APIs - that will use the supplied http_t * and only use cupsEnumDests if the queue does not already exist and the server is local.

[zdohnal]

Hmm... when I find definition cupsEnumDests(), I see it calls internal function cups_enum_dests() with parameter CUPS_HTTP_DEFAULT, which is preproccesor's define set to (http_t *)0.
The path of calls is: python's printFile -> cupsPrintFile2 -> cupsPrintFiles2 -> cupsCreateJob and in cupsCreateJob there are cupsEnumDests and cupsCopyDestInfo. It seems something is returned in _cups_createdata_t data structure in cupsEnumDests, so it doesn't fails right away. Then cupsCopyDestInfo is called on data gathered from local cups, but with http connection for remote cups.
I'll try to write a test program, which simulates behavior of python code.
@jpl166 Can you set cups log to debug and see which messaged are shown when 'c.printFile' line is done?

[michaelrsweet]

@zdohnal That's why I'm suggesting that I change the legacy print APIs to use cupsGetNamedDest so that the http_t * is used.

[michaelrsweet]

Try this change:

[master eb6c87e84] Use cupsGetNamedDest for legacy printing APIs (Issue #5288)
[branch-2.2 821b3cc] Mirror changes to legacy CUPS print APIs from master (Issue #5288)

[jpl166]

I wish I'd kept the copy of the debug logs from when I was nailing this down. These are all production servers on my part, it's going to take a bit of doing.

[michaelrsweet]

Well, I'm going to close this as fixed - please let me know if you find out otherwise...

[zdohnal]

Hi Mike,
I'm so sorry, I haven't got into testing this issue yet... once I got into it, I'll write a note here.

[jsmeix]

FYI:
At SUSE we had the following customer issue
https://www.suse.com/support/kb/doc/?id=000020365
that is fixed by
821b3cc

Excerpts from the customer issue:

with cups 2.2.7, a delay in processing print jobs is observed
if the file /etc/cups/printers.conf contains a high number of printer entries
...
When looking at an strace output of an lpr command,
a high number of recvfrom is seen:
# strace -c lpr -Ppdfprint /etc/hosts
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
99.96    0.613015           1    451790         5 recvfrom
...
The code was changed from using cupsEnumDests
(which called cups_create_cb a very high amount of times
to get the destination of a printer) to cupsGetNamedDest
which reduced the number of calls tremendously.
After installing the fix:
# strace -c lpr -Ppdfprint /etc/hosts
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
95.50    0.008879           1      5580         4 recvfrom

The customer also reported that
with CUPS 1.7.5 one spool job takes 0.017s
but with CUPS 2.2.7 it takes 1.411s
which is 83 times as long as before (with small print job data)
or in other words about 1.4 seconds longer
only for additional IPP protocol things
when there are very many print queues.