Bug 9123 - failed to get sysjob for job xxx, tracking as Unix job
Summary: failed to get sysjob for job xxx, tracking as Unix job
Status: CLOSED FIXED
Alias: None
Product: Samba 3.6
Classification: Unclassified
Component: Printing (show other bugs)
Version: 3.6.7
Hardware: x64 Linux
: P5 normal
Target Milestone: ---
Assignee: Karolin Seeger
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-08-28 14:07 UTC by Marc Muehlfeld
Modified: 2012-08-30 06:26 UTC (History)
1 user (show)

See Also:


Attachments
level 10 debug log (546.16 KB, application/x-bzip2)
2012-08-28 14:07 UTC, Marc Muehlfeld
no flags Details
smb.conf (9.09 KB, text/plain)
2012-08-28 14:12 UTC, Marc Muehlfeld
no flags Details
printcap (2.12 KB, text/plain)
2012-08-28 14:13 UTC, Marc Muehlfeld
no flags Details
patch to avoid job filename trucation and increase the log level for warnings. (1.70 KB, patch)
2012-08-28 17:06 UTC, David Disseldorp
asn: review+
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Marc Muehlfeld 2012-08-28 14:07:37 UTC
Created attachment 7842 [details]
level 10 debug log

Everytime a user is printing over samba 3.6.7, the following is logged:

[2012/08/28 15:48:07.795949,  0, pid=6703] printing/print_generic.c:292(generic_job_submit)
  failed to get sysjob for job 3423 (Testseite), tracking as Unix job

For machines that do many printing, this produces a lot of log entries.


We use LPRng-3.8.Arc4 as backend.
Comment 1 David Disseldorp 2012-08-28 14:09:33 UTC
Potentially fallout from bso#8719 changes.
Comment 2 Marc Muehlfeld 2012-08-28 14:12:39 UTC
Created attachment 7843 [details]
smb.conf
Comment 3 Marc Muehlfeld 2012-08-28 14:13:01 UTC
Created attachment 7844 [details]
printcap
Comment 4 David Disseldorp 2012-08-28 14:34:16 UTC
What does lpq provide as output after you've submitted a print job?
i.e. /usr/bin/lpq -P $PRINTER


You may want to run the following manual print test:

for i in `seq 1 10000`; do
echo -n "$i " >> test_print.dat
done

/usr/bin/lpr -P $TEST_PRINTER -r test_print.dat

/usr/bin/lpq -P $TEST_PRINTER
Comment 5 Marc Muehlfeld 2012-08-28 14:53:33 UTC
Just for explanation: Because of a critical printing bug I had to switch our production environment back to 3.5.17. Thats why the following was run on my test environment, where LPD doesn't send the printjobs directly to the printer. There I have to send it first to different LPD server (192.168.10.4) to get the job transfered to the printers, which are in the production network. 




(In reply to comment #4)
> What does lpq provide as output after you've submitted a print job?
> i.e. /usr/bin/lpq -P $PRINTER

# lpq -P SHMX2600-6
Printer: SHMX2600-6@Test_Member (dest SHMX2600-6@192.168.10.4)
 Queue: no printable jobs in queue
 Server: no server active
 Rank   Owner/ID               Pr/Class Job Files                 Size Time
done   root@Test_Member+671         A   671 smbprn.00003425.PiH 109442 16:48:59
Printer: SHMX2600-6@localhost (dest SHMX2600-6@10.1.0.17)
 Queue: no printable jobs in queue
 Server: no server active
 Rank   Owner/ID               Pr/Class Job Files                 Size Time
done   root@Test_Member+671         A   671 smbprn.00003425.PiH 109442 16:49:00
Ready

no entries






> You may want to run the following manual print test:
> 
> for i in `seq 1 10000`; do
> echo -n "$i " >> test_print.dat
> done
> 
> /usr/bin/lpr -P $TEST_PRINTER -r test_print.dat
> 
> /usr/bin/lpq -P $TEST_PRINTER

# lpq -P SHMX2600-6
Printer: SHMX2600-6@Test_Member (dest SHMX2600-6@192.168.10.4)
 Queue: no printable jobs in queue
 Server: no server active
 Rank   Owner/ID               Pr/Class Job Files                 Size Time
done   root@Test_Member+775         A   775 test_print.dat       48894 16:54:22
Printer: SHMX2600-6@localhost (dest SHMX2600-6@10.1.0.17)
 Queue: no printable jobs in queue
 Server: no server active
 Rank   Owner/ID               Pr/Class Job Files                 Size Time
done   root@Test_Member+775         A   775 test_print.dat       48894 16:54:23
Ready

no entries
Comment 6 David Disseldorp 2012-08-28 16:54:00 UTC
The lprng printing back-end is truncating the print job filename in the lpq output.
The job filename is used by samba to obtain the back-end job ID (sysjob) for newly submitted print jobs when the printing back-end does not provide it on submission (CUPS does so).

As this is not a catastrophic failure (samba will track the print job as a unix print job), we can safely increase the log level for the error message.

We can also reduce the length of the job filename such that it is not truncated, the spoolss jobid does not need to be included in the filename.
Comment 7 David Disseldorp 2012-08-28 17:06:18 UTC
Created attachment 7846 [details]
patch to avoid job filename trucation and increase the log level for warnings.
Comment 8 David Disseldorp 2012-08-28 17:07:41 UTC
Marc, please test patch in comment#7.
Comment 9 Marc Muehlfeld 2012-08-29 07:47:21 UTC
I applied the patch. Now when I print, nothing is logged any more at level 1. Thanks.

Is there anything I can test about the job filename trucation?
Comment 10 David Disseldorp 2012-08-29 08:58:12 UTC
(In reply to comment #9)
> I applied the patch. Now when I print, nothing is logged any more at level 1.
> Thanks.

Hmm, that implies that you're still seeing the warning at level 2?

> Is there anything I can test about the job filename trucation?

You should not be seeing the warning at all.
Could you please provide the lpq -P SHMX2600-6 output immediately after Windows client job submission.
Comment 11 Marc Muehlfeld 2012-08-29 09:02:05 UTC
It's also gone on log level 2 (this is the output of a printing on level 2):
http://cpaste.org/1237/




> Could you please provide the lpq -P SHMX2600-6 output immediately after
> Windows client job submission.

# lpq -P SHMX2600-6
Printer: SHMX2600-6@Test_Member (dest SHMX2600-6@192.168.10.4)
 Queue: no printable jobs in queue
 Server: no server active
 Rank   Owner/ID               Pr/Class Job Files                 Size Time
done   root@Test_Member+654         A   654 smbprn.0ZGatG       109441 11:01:26
Printer: SHMX2600-6@localhost (dest SHMX2600-6@10.1.0.17)
 Queue: no printable jobs in queue
 Server: no server active
 Rank   Owner/ID               Pr/Class Job Files                 Size Time
done   root@Test_Member+654         A   654 smbprn.0ZGatG       109441 11:01:27
Ready

no entries
Comment 12 David Disseldorp 2012-08-29 09:07:12 UTC
(In reply to comment #11)
> It's also gone on log level 2 (this is the output of a printing on level 2):
> http://cpaste.org/1237/

Great, that means Samba is correctly finding the job in the print queue after submission.

> > Could you please provide the lpq -P SHMX2600-6 output immediately after
> > Windows client job submission.
> 
> # lpq -P SHMX2600-6
> Printer: SHMX2600-6@Test_Member (dest SHMX2600-6@192.168.10.4)
>  Queue: no printable jobs in queue
>  Server: no server active
>  Rank   Owner/ID               Pr/Class Job Files                 Size Time
> done   root@Test_Member+654         A   654 smbprn.0ZGatG       109441 11:01:26

Looks good.
Comment 13 Andreas Schneider 2012-08-29 10:40:52 UTC
Comment on attachment 7846 [details]
patch to avoid job filename trucation and increase the log level for warnings.

lgtm
Comment 14 Andreas Schneider 2012-08-29 10:41:49 UTC
Karolin, could you please add this to the next 3.6 release? Thanks.

David, please push it to autobuild.
Comment 15 Karolin Seeger 2012-08-30 06:26:08 UTC
Pushed to v3-6-test.
Closing out bug report.

Thanks!