Bug 1706090 - Cannot print to SMB printer
Summary: Cannot print to SMB printer
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: samba
Version: 30
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Guenther Deschner
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-05-03 14:21 UTC by Stephen So
Modified: 2019-07-31 23:25 UTC (History)
17 users (show)

Fixed In Version: samba-4.10.5-1.fc30
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-07-06 04:08:56 UTC
Type: Bug


Attachments (Terms of Use)
Requested cups_whole_log file (178.41 KB, text/plain)
2019-05-15 00:02 UTC, Stephen So
no flags Details
Requested cups_job_log (28.20 KB, text/plain)
2019-05-15 00:02 UTC, Stephen So
no flags Details
cups_whole_log (after installing samba upstream) (142.22 KB, text/plain)
2019-05-15 07:17 UTC, Stephen So
no flags Details
cups_job_log (after installing samba upstream) (27.70 KB, text/plain)
2019-05-15 07:18 UTC, Stephen So
no flags Details
cups_log (after installing samba-4.10.5-1.fc30) (84.83 KB, text/plain)
2019-06-21 01:20 UTC, Stephen So
no flags Details

Description Stephen So 2019-05-03 14:21:21 UTC
Description of problem:

Since the upgrade to F30, printing to a network SMB printer has stopped working.  Worked previous in F29 but after upgrade (and reinstalling printer config), it comes up with "Unable to connect to CIFS host, will retry in 60 seconds".

I've managed to use 

smbclient -U user //printer_address/Find-Me-Print -c "print README"  

to connect to the printer server and manually print from command line sucessfully, so it doesn't seem to be an account or password issue.

Looking at journalctl -xe, I see the following messsages

May 04 00:12:55 corei5 cupsd[6354]: REQUEST localhost - - "POST /printers/Ricoh-Aficio-MP-C4502 HTTP/1.1" 200 422 Print-Job successful-ok
May 04 00:12:55 corei5 cupsd[6354]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 04 00:12:55 corei5 cupsd[6354]: Session setup failed: NT_STATUS_INVALID_PARAMETER
May 04 00:12:55 corei5 cupsd[6354]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 04 00:12:55 corei5 cupsd[6354]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 04 00:12:55 corei5 cupsd[6354]: Unable to connect to CIFS host, will retry in 60 seconds...

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

cups-2.2.11-2.fc30.x86_64

How reproducible:

always

Steps to Reproduce:
1.  Open up system-config-printer
2.  Go to properties of printer
3.  Press "Print Test Page"

Actual results:

Doesn't print.  Comes up "Unable to connect to CIFS host, will retry in 60 seconds..." in Printer State field

Expected results:

It should print normally.

Additional info:

Comment 1 Stephen So 2019-05-07 01:47:55 UTC
Printing using smbspool also works fine, i.e.

smbspool smb://user:password@printer_address/Find-Me-Print 1 1 0 1 1 file.ps

Comment 2 J.Jansen 2019-05-08 11:50:32 UTC
Got a simmilar problem, also after the upgrade to F30.

In my case it keeps telling me that I need "credentials" to print, although they are hard-coded in the printers.conf file.

A complete "fresh" installation of F30 gave the same problem. I reinstalled F29 and the problem was gone.

I'm going to create an installation of F30 in vbox, so that I can do some experiments.

                   Jouk

Comment 3 Zdenek Dohnal 2019-05-13 10:01:19 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 4 Andreas Schneider 2019-05-13 10:26:10 UTC
My guess would be that this is fixed with https://bugzilla.samba.org/show_bug.cgi?id=13939

Comment 5 Andreas Schneider 2019-05-13 15:16:42 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 6 Stephen So 2019-05-14 01:00:10 UTC
Here is the debug log after I printed a test page from system-config-printer



-- Logs begin at Tue 2019-04-23 23:44:00 AEST. --
May 14 10:52:41 corei5 cupsd[13403]: Starting renderer with command: \"printf \"%%!PS-Adobe-3.0
May 14 10:52:41 corei5 cupsd[13403]: %%%%Title: (Test Page)
May 14 10:52:41 corei5 cupsd[13403]: %%
May 14 10:52:41 corei5 cupsd[13403]: %%\\n/lppswd()def\\n/dspswd()def\\n/usrcode()def\\nmark\\n/usrcode where{pop}{/usrcode()def}ifelse\\n(root) usrcode (20`date +%y%m%d%R | sed \'s/://\'`) {setuserinfo} stopped\\ncleartomark\\nmark {\\n<<\\n   /JobType 0\\n   /JobInfo <<\\n      /UserID (root)\\n      /Time (20`date +%y%m%d%R | sed \'s/://\'`)\\n      /HostLoginName (root)\\n      /HostName (corei5)\\n   >>\\n>> /RDeviceProcSet /ProcSet findresource /SetJobType get exec\\n}stopped cleartomark\\n<</OutputType null>>setpagedevice\\nuserdict /RPS_BPdict 2 dict put\\nuserdict /RPS_BPdict get begin /RPS_BP_MEDIAPOSITION null def end\\nuserdict /RPS_BPdict get begin\\n/RPS_BP_MEDIATYPE (Auto) def end\\n<<\\n/BannerPageMode false\\n/MediaPosition null\\n/MediaType null\\n>>\\n/RDeviceProcSet \\n/ProcSet findresource \\n/SetBannerPage get exec\\n\"%%%%; cat;\"
May 14 10:52:41 corei5 cupsd[13403]: Starting process \"kid3\" (generation 1)
May 14 10:52:41 corei5 cupsd[13403]: Starting process \"kid4\" (generation 2)
May 14 10:52:41 corei5 cupsd[13403]: Starting process \"renderer\" (generation 2)
May 14 10:52:41 corei5 cupsd[13403]: JCL: \033%-12345X@PJL
May 14 10:52:41 corei5 cupsd[13403]: <job data>
May 14 10:52:42 corei5 cupsd[13403]: Expiring subscriptions...
May 14 10:53:11 corei5 cupsd[13403]: Saving job.cache...
May 14 10:53:11 corei5 cupsd[13403]: Saving subscriptions.conf...
May 14 10:53:11 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
May 14 10:53:11 corei5 cupsd[13403]: Expiring subscriptions...
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Server address is "/var/run/cups/cups.sock".
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Accepted from localhost (Domain)
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Waiting for request.
May 14 10:53:12 corei5 cupsd[13403]: Expiring subscriptions...
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] POST / HTTP/1.1
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Read: status=200, state=6
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] No authentication data provided.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] 2.0 CUPS-Get-Default 1
May 14 10:53:12 corei5 cupsd[13403]: CUPS-Get-Default
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Content-Length: 1323
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] con->http=0x557dbe990370
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1323, response=0x557dbe913c70(IPP_STATE_DATA), pipe_pid=0, file=-1
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] bytes=0, http_state=0, data_remaining=1323
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Flushing write buffer.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] New state is HTTP_STATE_WAITING
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Waiting for request.
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] POST / HTTP/1.1
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Read: status=200, state=6
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] No authentication data provided.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] 2.0 Get-Printer-Attributes 2
May 14 10:53:12 corei5 cupsd[13403]: Get-Printer-Attributes ipp://localhost:631/printers/-
May 14 10:53:12 corei5 cupsd[13403]: Get-Printer-Attributes client-error-not-found: The printer or class does not exist.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Returning IPP client-error-not-found for Get-Printer-Attributes (ipp://localhost:631/printers/-) from localhost.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Content-Length: 130
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] con->http=0x557dbe990370
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=130, response=0x557dbe960a00(IPP_STATE_DATA), pipe_pid=0, file=-1
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] bytes=0, http_state=0, data_remaining=130
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Flushing write buffer.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] New state is HTTP_STATE_WAITING
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Waiting for request.
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] POST / HTTP/1.1
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Read: status=200, state=6
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] No authentication data provided.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] 2.0 CUPS-Get-Printers 3
May 14 10:53:12 corei5 cupsd[13403]: CUPS-Get-Printers
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Content-Length: 1323
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] con->http=0x557dbe990370
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1323, response=0x557dbe913c70(IPP_STATE_DATA), pipe_pid=0, file=-1
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] bytes=0, http_state=0, data_remaining=1323
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Flushing write buffer.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] New state is HTTP_STATE_WAITING
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Waiting for request.
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] POST / HTTP/1.1
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs"
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Read: status=200, state=6
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] No authentication data provided.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] 2.0 CUPS-Get-Default 4
May 14 10:53:12 corei5 cupsd[13403]: CUPS-Get-Default
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Content-Length: 13916
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] con->http=0x557dbe990370
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=13916, response=0x557dbe960a00(IPP_STATE_DATA), pipe_pid=0, file=-1
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] bytes=0, http_state=0, data_remaining=13916
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Flushing write buffer.
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] New state is HTTP_STATE_WAITING
May 14 10:53:12 corei5 cupsd[13403]: [Client 5] Waiting for request.
May 14 10:53:12 corei5 cupsd[13403]: cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs"

Comment 7 Stephen So 2019-05-14 01:17:42 UTC
When I try to print a test page from the cups web interface, I get the following message

"Session setup failed: NT_STATUS_NOT_SUPPORTED"

So it is a samba issue?

Comment 8 Zdenek Dohnal 2019-05-14 05:34:17 UTC
Stephen,

thank you for providing the log, but unfortunately it is cropped - I do not see the whole job. 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:40 UTC
Until we find out more info, let's stay in cups component.

Comment 10 Andreas Schneider 2019-05-14 08:18:56 UTC
I already have some fixes, but I need logs to understand what CUPS is doing on different hosts as it looks like there are different configurations. So different routes.

Comment 11 Andreas Schneider 2019-05-14 08:59:52 UTC
You can use

cupsctl --debug-logging

to turn on debug logging ...

Comment 12 Stephen So 2019-05-15 00:02:05 UTC
Created attachment 1568723 [details]
Requested cups_whole_log file

Here is the requested cups_whole_log file

Comment 13 Stephen So 2019-05-15 00:02:38 UTC
Created attachment 1568725 [details]
Requested cups_job_log

Comment 14 Zdenek Dohnal 2019-05-15 05:50:31 UTC
Samba connection messages:

May 15 09:57:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:57:14 corei5 cupsd[811]: Set job-printer-state-message to "Session setup failed: NT_STATUS_NOT_SUPPORTED", current level=ERROR
May 15 09:57:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
.
.
.
May 15 09:57:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_INVALID_PARAMETER
May 15 09:57:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_INVALID_PARAMETER [c000000d])
May 15 09:57:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:57:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:57:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:57:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:57:14 corei5 cupsd[811]: Unable to connect to CIFS host, will retry in 60 seconds...
.
.
.
May 15 09:58:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:58:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:58:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_INVALID_PARAMETER
May 15 09:58:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_INVALID_PARAMETER [c000000d])
May 15 09:58:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:58:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:58:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:58:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:58:14 corei5 cupsd[811]: Unable to connect to CIFS host, will retry in 60 seconds...
May 15 09:59:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:59:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:59:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_INVALID_PARAMETER
May 15 09:59:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_INVALID_PARAMETER [c000000d])
May 15 09:59:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:59:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:59:14 corei5 cupsd[811]: Session setup failed: NT_STATUS_NOT_SUPPORTED
May 15 09:59:14 corei5 cupsd[811]: get_exit_code(cli=0x555e4e7b5c20, nt_status=NT_STATUS_NOT_SUPPORTED [c00000bb])
May 15 09:59:14 corei5 cupsd[811]: Unable to connect to CIFS host, will retry in 60 seconds...
May 15 09:59:21 corei5 cupsd[811]: time-at-completed=1557878361
May 15 09:59:21 corei5 cupsd[811]: Job canceled by \"root\"
May 15 09:59:21 corei5 cupsd[811]: PID 1131 (/usr/lib/cups/backend/smb) was terminated normally with signal 15.

According other job log it seems device uri nor environment provide the credentials - I'll create samba scratch build based on Andreas' link to samba upstream. Stephen, would you mind testing it if it helps for you?

Comment 15 Stephen So 2019-05-15 06:04:19 UTC
Yes, I'm more than happy to test it, if you can provide me with the rpms.

Comment 16 Zdenek Dohnal 2019-05-15 06:48:14 UTC
Here are the rpms https://koji.fedoraproject.org/koji/taskinfo?taskID=34866229

Comment 17 Stephen So 2019-05-15 07:17:12 UTC
Created attachment 1568810 [details]
cups_whole_log (after installing samba upstream)

Unfortunately, it still doesn't work.  Here are the logs.

Comment 18 Stephen So 2019-05-15 07:18:07 UTC
Created attachment 1568811 [details]
cups_job_log (after installing samba upstream)

Comment 19 Zdenek Dohnal 2019-05-15 07:35:52 UTC
Still the same errors from samba, even by applying https://attachments.samba.org/attachment.cgi?id=15137 . Andreas, I'll move it to samba for more investigation.

Comment 20 Andreas Schneider 2019-05-15 11:41:09 UTC
Zdenek, yeah this is still work in progress, see https://git.samba.org/?p=asn/samba.git;a=shortlog;h=refs/heads/master-smbspool

Comment 21 Norman Gaywood 2019-06-20 00:28:16 UTC
Perhaps a patch for this now?

https://bugzilla.samba.org/show_bug.cgi?id=13939#c22

Comment 22 Fedora Update System 2019-06-20 20:04:51 UTC
FEDORA-2019-8015e5dc40 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-8015e5dc40

Comment 23 Stephen So 2019-06-21 01:20:49 UTC
Created attachment 1582978 [details]
cups_log (after installing samba-4.10.5-1.fc30)

I've updated to the latest samba build from koji - https://koji.fedoraproject.org/koji/buildinfo?buildID=1291125

Getting a different problem now.  After printing the cups test page, I am getting an "Idle - Filter failed" as the printer state.

I've uploaded the cups_log.  There seems to be a "Broken pipe during fwrite" message.

Jun 21 11:13:09 corei5 cupsd[5528]: renderer exited with status 141
Jun 21 11:13:09 corei5 cupsd[5528]: A filter used in addition to the renderer itself may have failed.Process is dying with \"Encountered error Broken pipe during fwrite\", exit stat 1
Jun 21 11:13:09 corei5 cupsd[5528]: Cleaning up...
Jun 21 11:13:09 corei5 cupsd[5528]: Killing kid3
Jun 21 11:13:09 corei5 cupsd[5528]: Process is dying with \"Caught termination signal: Job canceled
Jun 21 11:13:09 corei5 cupsd[5528]: \", exit stat 0
Jun 21 11:13:09 corei5 cupsd[5528]: Cleaning up...
Jun 21 11:13:09 corei5 cupsd[5528]: Killing kid4
Jun 21 11:13:10 corei5 cupsd[5528]: Expiring subscriptions...
Jun 21 11:13:17 corei5 cupsd[5528]: Expiring subscriptions...
Jun 21 11:13:17 corei5 cupsd[5528]: PID 5585 (/usr/lib/cups/filter/foomatic-rip) stopped with status 1.

Comment 24 Andreas Schneider 2019-06-21 11:48:00 UTC
Looks like the filter failed to render the page. smbspool is not involved in this.

Comment 25 Andreas Schneider 2019-06-21 11:51:15 UTC
I only see in the logs:

kerberos_ccache_is_valid: Failed to get default principal from ccache: KCM:


which means the user doesn't have a Kerberos ticket and can't authenticate.

Comment 26 Stephen So 2019-06-21 13:39:53 UTC
(In reply to Andreas Schneider from comment #25)
> I only see in the logs:
> 
> kerberos_ccache_is_valid: Failed to get default principal from ccache: KCM:
> 
> 
> which means the user doesn't have a Kerberos ticket and can't authenticate.

One thing I noticed different is in my /etc/cups/printers.conf file, there is a "AuthInfoRequired none" line, even though the DeviceURI has my username and password.  I tried adding another samba printer and it also has this line in it too.  

When I checked my printers.conf file from the previous Fedora 28, it had "AuthInfoRequired username,password", while in Fedora 29, it didn't even have a "AuthInfoRequired" line.  Could this explain wny the print jobs are always "held for authentication"?

Comment 27 Andreas Schneider 2019-06-21 14:55:25 UTC
Yes, this needs to be set to: AuthInfoRequired username,password

Comment 28 Fedora Update System 2019-06-22 06:04:28 UTC
samba-4.10.5-1.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-8015e5dc40

Comment 29 Fedora Update System 2019-07-06 04:08:56 UTC
samba-4.10.5-1.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.

Comment 30 paul 2019-07-31 23:25:24 UTC
Similar bug in ? 
https://bugzilla.redhat.com/show_bug.cgi?id=1700791

In my case, "Required Credential to print" appears in notification area.


Procedures:
1.  Install F30
2.  Install Printer, searching the local network area, add the printer
3.  Print to the network printer
4.  "Required Credential to print"


F29 has no such problem.


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