Bug 1706316 - Fedora Stopped Printing to Samba printer after upgrade
Summary: Fedora Stopped Printing to Samba printer after upgrade
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: samba
Version: 29
Hardware: x86_64
OS: Linux
high
high
Target Milestone: ---
Assignee: Guenther Deschner
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-05-04 09:19 UTC by Mustafa Mahudhawala
Modified: 2019-08-12 08:25 UTC (History)
18 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-08-12 08:25:52 UTC


Attachments (Terms of Use)
Error Dialog (17.99 KB, image/png)
2019-05-04 09:19 UTC, Mustafa Mahudhawala
no flags Details
journalctl -f -u cups > cups_whole_log_debug (6.85 KB, application/x-bzip)
2019-05-14 10:07 UTC, Mustafa Mahudhawala
no flags Details
journalctl -u cups JID=NNN > cups_job_log_debug (3.73 KB, application/x-bzip)
2019-05-14 11:27 UTC, Mustafa Mahudhawala
no flags Details

Description Mustafa Mahudhawala 2019-05-04 09:19:39 UTC
Created attachment 1562998 [details]
Error Dialog

Description of problem:

Printing to Samba shared printer fails with error ..

Authentication required for printing document `test page' (Job 271)
negotiate []

Version-Release number of selected component (if applicable):

Was working fine on Fedora 27, Upgraded to Fedora 28 got the problem, upgraded cups to packages from Fedora 29, still same problem.

How reproducible:
Add Windows share printer, send a test print. It gives this error.

Steps to Reproduce:
See Above

Actual results:


Expected results:


Additional info:

Comment 1 Mustafa Mahudhawala 2019-05-04 09:21:14 UTC
# systemctl status cups
● cups.service - CUPS Scheduler
   Loaded: loaded (/usr/lib/systemd/system/cups.service; disabled; vendor preset: disabled)
   Active: active (running) since Sat 2019-05-04 14:33:06 IST; 51s ago
     Docs: man:cupsd(8)
 Main PID: 5166 (cupsd)
   Status: "Scheduler is running..."
    Tasks: 1 (limit: 4915)
   Memory: 5.1M
   CGroup: /system.slice/cups.service
           └─5166 /usr/sbin/cupsd -l

May 04 14:33:24 redhat.com cupsd[5166]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 04 14:33:24 redhat.com cupsd[5166]: Session setup failed: NT_STATUS_ACCESS_DENIED
May 04 14:33:24 redhat.com cupsd[5166]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 04 14:33:24 redhat.com cupsd[5166]: Tree connect failed (NT_STATUS_ACCESS_DENIED)
May 04 14:33:26 redhat.com cupsd[5166]: REQUEST localhost - - "POST /jobs/ HTTP/1.1" 200 158 CUPS-Authenticate-Job successful-ok
May 04 14:33:26 redhat.com cupsd[5166]: Tree connect failed (NT_STATUS_ACCESS_DENIED)
May 04 14:33:26 redhat.com cupsd[5166]: Session setup failed: NT_STATUS_ACCESS_DENIED
May 04 14:33:27 redhat.com cupsd[5166]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 04 14:33:27 redhat.com cupsd[5166]: Tree connect failed (NT_STATUS_ACCESS_DENIED)
May 04 14:33:50 redhat.com cupsd[5166]: REQUEST localhost - - "POST / HTTP/1.1" 200 156 Cancel-Subscription successful-ok

Comment 3 Mustafa Mahudhawala 2019-05-04 09:25:04 UTC
https://bugs.archlinux.org/task/62521

Looks Similar ^^

Comment 4 Zdenek Dohnal 2019-05-13 10:02:39 UTC
Hi!

thank you for reporting the issue! According CUPS upstream ( https://github.com/apple/cups/issues/5573 ), samba people should take a look on the issue.

Comment 5 J.Jansen 2019-05-13 10:31:13 UTC
(In reply to Zdenek Dohnal from comment #4)
> Hi!
> 
> thank you for reporting the issue! According CUPS upstream (
> https://github.com/apple/cups/issues/5573 ), samba people should take a look
> on the issue.

This link suggests that samba sould be compiled with --with-experimental-mit-ad-dc to get the Kerberos stuff in.

I got the authentication problem when upgrading from F29 to F30

Comment 6 Andreas Schneider 2019-05-13 11:24:50 UTC
Printing is not a Samba AD feature!

Comment 7 Andreas Schneider 2019-05-13 15:16:22 UTC
Please enable *debug* logging of CUPS and then reproduce the issue and provide the cups log.

journalctl -f -u cups.service

should normally give you the log.

Comment 8 Zdenek Dohnal 2019-05-14 05:42:36 UTC
(In reply to Andreas Schneider from comment #7)
> journalctl -f -u cups.service

'-f' will give you the most recent logs and logs after you issue the command - so if you reproduced before that, it can get cropped. Please follow these steps:

1) $ journalctl -f -u cups > cups_whole_log
(in other terminal, your_print_queue_name is the name of printer, which it has in system-config-printer)
2) $ lp -d <your_print_queue_name> /etc/fstab
(you will see a string in the terminal, which will contains string alike your_print_queue_name-NNN, where NNN are numbers. You will need those numbers.)
3) wait until job is finished - you can check it by '$ lpstat -o <your_print_queue_name>' - if it will take too long (f.e. 1 minute), cancel the job by 'cancel <NNN>', where <NNN> are numbers from lp output
4) stop the journalctl command - just press ctrl+c in terminal where it is running.
5) $ journalctl -u cups JID=<NNN> > cups_job_log
6) please attach both files: cups_whole_log, cups_job_log to the bugzilla.

Comment 9 Zdenek Dohnal 2019-05-14 05:43:57 UTC
Until we find out more info, let's stay in cups component.

Comment 10 Mustafa Mahudhawala 2019-05-14 08:36:03 UTC
I get that same pop-up, it did not print and had to cancel the Job. The cups job log file was empty.

$ lp -d Samsung-SCX-4200 /etc/fstab 
request id is Samsung-SCX-4200-274 (1 file(s))

$ cancel Samsung-SCX-4200-274

Had to run journalctl as root, but here is the o/p...

# journalctl -u cups JID=274 > cups_job_log

# cat cups_job_log 
-- Logs begin at Tue 2018-06-26 17:42:45 IST, end at Tue 2019-05-14 13:58:05 IST. --
May 14 13:57:27 test.redhat.com cupsd[13361]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 14 13:57:27 test.redhat.com cupsd[13361]: Session setup failed: NT_STATUS_ACCESS_DENIED
May 14 13:57:27 test.redhat.com cupsd[13361]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 14 13:57:27 test.redhat.com cupsd[13361]: Tree connect failed (NT_STATUS_ACCESS_DENIED)

# cat cups_whole_log 
-- Logs begin at Tue 2018-06-26 17:42:45 IST. --
May 14 13:53:44 test.redhat.com cupsd[13361]: REQUEST localhost - root "POST /admin/ HTTP/1.1" 200 41263 CUPS-Add-Modify-Printer successful-ok
May 14 13:53:44 test.redhat.com cupsd[13361]: [Client 6] Returning IPP client-error-bad-request for CUPS-Add-Modify-Printer (ipp://localhost:631/printers/Sales_office_Canon_C350_Black_cups01) from localhost.
May 14 13:53:44 test.redhat.com cupsd[13361]: REQUEST localhost - root "POST /admin/ HTTP/1.1" 200 234 CUPS-Add-Modify-Printer client-error-bad-request
May 14 13:53:51 test.redhat.com cupsd[13361]: REQUEST localhost - root "POST /admin/ HTTP/1.1" 200 42099 CUPS-Add-Modify-Printer successful-ok
May 14 13:53:51 test.redhat.com cupsd[13361]: [Client 6] Returning IPP client-error-bad-request for CUPS-Add-Modify-Printer (ipp://localhost:631/printers/Sales_office_Canon_C350i_Color_cups01) from localhost.
May 14 13:53:51 test.redhat.com cupsd[13361]: REQUEST localhost - root "POST /admin/ HTTP/1.1" 200 234 CUPS-Add-Modify-Printer client-error-bad-request
May 14 13:53:55 test.redhat.com cupsd[13361]: REQUEST localhost - root "POST /admin/ HTTP/1.1" 200 49102 CUPS-Add-Modify-Printer successful-ok
May 14 13:53:55 test.redhat.com cupsd[13361]: [Client 6] Returning IPP client-error-bad-request for CUPS-Add-Modify-Printer (ipp://localhost:631/printers/Sales_office_Canon_3320_Black_cups01) from localhost.
May 14 13:53:55 test.redhat.com cupsd[13361]: REQUEST localhost - root "POST /admin/ HTTP/1.1" 200 234 CUPS-Add-Modify-Printer client-error-bad-request
May 14 13:54:01 test.redhat.com cupsd[13361]: REQUEST localhost - - "POST /jobs/ HTTP/1.1" 200 144 Cancel-Job successful-ok
May 14 13:57:27 test.redhat.com cupsd[13361]: REQUEST localhost - - "POST /printers/Samsung-SCX-4200 HTTP/1.1" 401 353 Create-Job successful-ok
May 14 13:57:27 test.redhat.com cupsd[13361]: REQUEST localhost - test "POST /printers/Samsung-SCX-4200 HTTP/1.1" 200 353 Create-Job successful-ok
May 14 13:57:27 test.redhat.com cupsd[13361]: REQUEST localhost - test "POST /printers/Samsung-SCX-4200 HTTP/1.1" 200 1142 Send-Document successful-ok
May 14 13:57:27 test.redhat.com cupsd[13361]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 14 13:57:27 test.redhat.com cupsd[13361]: Session setup failed: NT_STATUS_ACCESS_DENIED
May 14 13:57:27 test.redhat.com cupsd[13361]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 14 13:57:27 test.redhat.com cupsd[13361]: Tree connect failed (NT_STATUS_ACCESS_DENIED)
May 14 13:58:05 test.redhat.com cupsd[13361]: REQUEST localhost - - "POST /jobs/ HTTP/1.1" 200 144 Cancel-Job successful-ok

Comment 11 Andreas Schneider 2019-05-14 08:58:24 UTC
You need to turn on debug logs in CUPS.

cupsctl --debug-logging

Comment 13 Mustafa Mahudhawala 2019-05-14 10:07:23 UTC
Created attachment 1568357 [details]
journalctl -f -u cups > cups_whole_log_debug

Comment 14 Mustafa Mahudhawala 2019-05-14 10:13:22 UTC
Attached out puts of ..

# journalctl -f -u cups > cups_whole_log_debug
# journalctl -u cups JID=276 > cups_job_log_debug

After debugging enabled.

Comment 15 Zdenek Dohnal 2019-05-14 10:28:39 UTC
May 14 15:28:59 test.redhat.com cupsd[16658]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 14 15:28:59 test.redhat.com cupsd[16658]: Set job-printer-state-message to "Session setup failed: NT_STATUS_LOGON_FAILURE", current level=ERROR
May 14 15:28:59 test.redhat.com cupsd[16658]: get_exit_code(cli=0x55e06b7ddfa0, nt_status=NT_STATUS_LOGON_FAILURE [c000006d])
May 14 15:28:59 test.redhat.com cupsd[16658]: ATTR: auth-info-required=username,password
May 14 15:28:59 test.redhat.com cupsd[16658]: Kerberos auth with \'test@SAMBA\' (SAMBA\\test) to access \'192.168.3.40\' not possible
May 14 15:28:59 test.redhat.com cupsd[16658]: Session setup failed: NT_STATUS_ACCESS_DENIED
May 14 15:28:59 test.redhat.com cupsd[16658]: get_exit_code(cli=0x55e06b7ddfa0, nt_status=NT_STATUS_ACCESS_DENIED [c0000022])
May 14 15:28:59 test.redhat.com cupsd[16658]: ATTR: auth-info-required=negotiate
May 14 15:28:59 test.redhat.com cupsd[16658]: Session setup failed: NT_STATUS_LOGON_FAILURE
May 14 15:28:59 test.redhat.com cupsd[16658]: get_exit_code(cli=0x55e06b7ddfa0, nt_status=NT_STATUS_LOGON_FAILURE [c000006d])
May 14 15:28:59 test.redhat.com cupsd[16658]: ATTR: auth-info-required=negotiate
May 14 15:28:59 test.redhat.com cupsd[16658]: Tree connect failed (NT_STATUS_ACCESS_DENIED)
May 14 15:28:59 test.redhat.com cupsd[16658]: get_exit_code(cli=0x55e06b7ddfa0, nt_status=NT_STATUS_ACCESS_DENIED [c0000022])
May 14 15:28:59 test.redhat.com cupsd[16658]: ATTR: auth-info-required=negotiate
May 14 15:28:59 test.redhat.com cupsd[16658]: PID 16674 (/usr/lib/cups/backend/smb) stopped with status 2.
.
.
.
May 14 15:28:59 test.redhat.com cupsd[16658]: Backend returned status 2 (authentication required)

It truly looks like something in smb. More info is in the logs.

Comment 16 Mustafa Mahudhawala 2019-05-14 11:15:01 UTC
No configuration changes done either at client or Samba server side, just stopped working popping up the auth box after Fedora upgrade.

That said I can access all my file shares from the same server without issues using the same credentials, just printing stopped working.

Printing locally on the samba server (same printer) works fine, of course that does not go through samba.

Comment 17 Mustafa Mahudhawala 2019-05-14 11:27:15 UTC
Created attachment 1568405 [details]
journalctl -u cups JID=NNN > cups_job_log_debug

Comment 18 J.Jansen 2019-05-14 11:32:13 UTC
Same to me. To me it looks like cups does not supply smb with the username/password.
In my case the username/password is hardcoded in the PrinterURI in the /etc/cups/printers.conf file.

Comment 19 Zdenek Dohnal 2019-05-14 12:00:03 UTC
CUPS is supplying device URI correctly to smb, which should parse credentials from URI, but it uses credentials from environment in some cases.

Comment 20 Andreas Schneider 2019-05-14 12:17:05 UTC
Sorry, but you start confuse me. Is this bug about printing with Kerberos or username/password. If this is about Kerberos then it looks like the package samba-krb5-printing is not installed. Please make sure to explain how you want to print. Also don't mix bugs!

Comment 21 J.Jansen 2019-05-14 12:43:38 UTC
It looks like it fails for both Kerberos and username/password : The journalctl above shows Kerberos. I do not use it, but get the same journalctl but I get a mention of useraname/password. I noticed that the actual username/password are not in the journalctl.

Comment 22 Andreas Schneider 2019-05-14 14:07:17 UTC
This should be fixed in F30 with Samba 4.10

Comment 24 gmassimiani 2019-07-03 15:02:56 UTC
hello in fedora 30 new installation with samba-4.10.4-1.fc30.x86_64 and cups-2.2.11-3.fc30.x86_64 there is the same error

in fedora 29 fresh install (not upgrade) all  works fine

in fedora 29 upgraded to the last packages there is the same error

I I debug with wiresharsk:
fedora 30 show: 
128	938.196396001	source destination SMB2	256	Session Setup Request, NTLMSSP_AUTH, User: \

fedora 29 show : 14	0.038345589	source destinationSMB2	776	Session Setup Request, NTLMSSP_AUTH, User: domain\username

Comment 25 Andreas Schneider 2019-07-03 16:29:51 UTC
What is auth_requried_info set to?

Comment 26 gmassimiani 2019-07-04 09:30:22 UTC
sorry but I don't understand exactly what is auth_requried_info.

if you are referring to the "authentication" option in the smb printer panel, I have tested both options
prompt user if authentication is required
set authentication details now

in both case the result is the same

Fedora 29 new installation works fine
Fedora 29 updated not works 
Fedora 30 not works

Comment 27 Andreas Schneider 2019-07-04 14:41:27 UTC
In /etc/cups/printers.conf

you have:

<Printer ptr>
AuthInfoRequired username/password
...
</Printer>

Normally so that cups authenticates with a username and password. Or you set it to negotiate if you want Kerberos.

Comment 28 gmassimiani 2019-07-05 08:33:33 UTC
hello
I have excuted some tests and in all cases:
fedora 29 new installation : the parameter is never added to printers.con
fedora 30 in all case in the file printers.conf is automatically added the row:
AuthInfoRequired negotiate

I have tried to
stop cups and add manually:
AuthInfoRequired username/password
start cups

configure the printer to store username and password
DeviceURI smb://DOMAIN%5Cusername:password@printerhost/Printername

in both case after restart cups the file printers.conf is automatically modified and the rom 
AuthInfoRequired negotiate
is added to the file

from fedora 30 I have tested the smb login to the printer server without problems

smbclient //printerhost/Printername -U DOMAIN\\username
Enter DOMAIN\\username's password: 
Try "help" to get a list of possible commands.
smb: \>

Comment 29 Andreas Schneider 2019-07-05 12:42:21 UTC
If you use username/password then AuthInfoRequred should be set to username/password and it should stay there. If not you have to figure out why it changes it by turning on debug logging in cups. However this doesn't look like a smbspool issue if AuthInfoRequired is set to the wrong value.

Comment 30 Zdenek Dohnal 2019-07-08 13:14:01 UTC
(In reply to gmassimiani from comment #28)
> I have tried to
> stop cups and add manually:
> AuthInfoRequired username/password
> start cups

The delimiter is ',', not '/'. If you use 'username,password', it should work.

Comment 31 DK 2019-07-17 21:37:30 UTC
(In reply to Zdenek Dohnal from comment #30)
> The delimiter is ',', not '/'. If you use 'username,password', it should work.

I have tried with ','. Result the same. It does not work. 

variants that i tried:

1.
AuthInfoRequired MAIN%5Cdk,pass
DeviceURI smb://MAIN%5Cdk:pass@srv-print/printer-floor-3.tut.com

2.
AuthInfoRequired dk,pass
DeviceURI smb://MAIN%5CBdk:pass@srv-print/printer-floor-3.tut.com


In additionally, i tried with ';' instead of '\', according to smb://[[<domain>;]<username>[:<password>]@]<server>[:<port>][/[<share>[/[<path>]]][?[<param>=<value>[<param2>=<value2>[...]]]]]     

3.
AuthInfoRequired MAIN%3Bdk,pass
DeviceURI smb://MAIN%3Bdk:pass@srv-print/printer-floor-3.tut.com

4.
AuthInfoRequired dk,pass
DeviceURI smb://MAIN%3Bdk:pass@srv-print/printer-floor-3.tut.com

Comment 32 Zdenek Dohnal 2019-07-18 09:53:57 UTC
(In reply to DK from comment #31)
> 1.
> AuthInfoRequired MAIN%5Cdk,pass

It suppose to be username,password as keywords, not your actual username and password.

Comment 33 DK 2019-07-18 10:44:19 UTC
(In reply to Zdenek Dohnal from comment #32)
> (In reply to DK from comment #31)
> > 1.
> > AuthInfoRequired MAIN%5Cdk,pass
> 
> It suppose to be username,password as keywords, not your actual username and
> password.

Thanks i will check

Comment 34 DK 2019-07-18 11:06:58 UTC
(In reply to Zdenek Dohnal from comment #32)
> (In reply to DK from comment #31)
> > 1.
> > AuthInfoRequired MAIN%5Cdk,pass
> 
> It suppose to be username,password as keywords, not your actual username and
> password.

It helped, Thanks once again.

Comment 35 Andreas Schneider 2019-07-18 11:46:01 UTC
So this bug can be closed as fixed?


Note You need to log in before you can comment on or make changes to this bug.