[cups] CUPS & PAM

[Дмитрий Воронин]

Hello,

I use CUPS 2.1.3 with PAM authentication on Debian 8.
I have those rows in /etc/pam.d/cups:

@include common-auth
@include common-account
@include common-session

(it's default settings for CUPS service)

I make some IPP request to CUPS, CUPS ask me a password for user. If I entered incorrect password, faillog on this user increses on 2. Why?

The next possible question is: Why CUPS create 2 clients to handle 1 IPP request (in error_log on Debug mode 'debug'):

D [13/Oct/2016:13:24:30 +0300] [Client 9] Accepted from 192.168.32.227:35090 (IPv4)
D [13/Oct/2016:13:24:30 +0300] [Client 9] Waiting for request.
D [13/Oct/2016:13:24:30 +0300] [Client 8] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [13/Oct/2016:13:24:30 +0300] [Client 8] Closing connection.
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 9] OPTIONS * HTTP/1.1
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 9] Read: status=200
D [13/Oct/2016:13:24:30 +0300] [Client 9] No authentication data provided.
D [13/Oct/2016:13:24:30 +0300] [Client 9] cupsdSendHeader: code=101, type="(null)", auth_type=0
D [13/Oct/2016:13:24:30 +0300] [Client 9] Connection now encrypted.
D [13/Oct/2016:13:24:30 +0300] [Client 9] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 9] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [13/Oct/2016:13:24:30 +0300] [Client 9] Closing connection.
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 9] Waiting for socket close.
D [13/Oct/2016:13:24:30 +0300] [Client 9] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [13/Oct/2016:13:24:30 +0300] [Client 9] Closing connection.
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 10] Accepted from 192.168.32.227:35092 (IPv4)
D [13/Oct/2016:13:24:30 +0300] [Client 10] Waiting for request.
D [13/Oct/2016:13:24:30 +0300] [Client 10] OPTIONS * HTTP/1.1
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 10] Read: status=200
D [13/Oct/2016:13:24:30 +0300] [Client 10] No authentication data provided.
D [13/Oct/2016:13:24:30 +0300] [Client 10] cupsdSendHeader: code=101, type="(null)", auth_type=0
D [13/Oct/2016:13:24:30 +0300] [Client 10] Connection now encrypted.
D [13/Oct/2016:13:24:30 +0300] [Client 10] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 10] POST / HTTP/1.1
D [13/Oct/2016:13:24:30 +0300] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [13/Oct/2016:13:24:30 +0300] [Client 10] Read: status=200
E [13/Oct/2016:13:24:32 +0300] [Client 10] pam_authenticate() returned 7 (Authentication failure)
D [13/Oct/2016:13:24:32 +0300] [Client 10] 2.0 Get-Printer-Attributes 5
D [13/Oct/2016:13:24:32 +0300] Get-Printer-Attributes ipp://localhost/printers/printer
D [13/Oct/2016:13:24:32 +0300] cupsdIsAuthorized: username=""
D [13/Oct/2016:13:24:32 +0300] [Client 10] Returning HTTP permission denined for Get-Printer-Attributes (ipp://localhost/printers/printer) from 192.168.32.227
D [13/Oct/2016:13:24:32 +0300] [Client 10] cupsdSendHeader: code=401, type="text/html", auth_type=1
D [13/Oct/2016:13:24:32 +0300] [Client 10] WWW-Authenticate: Basic realm=\"CUPS\"

-- 
Best regards, Dmitry Voronin