Level 3

714 points

CUPS Printer Error Log

Hi,

I was checking the Logs section in System Profiler and the following log caught my attention. The log is related to CUPS which is (as I understand) the printer manager in OSX. The log looks like this on screen:

*+Note: I had to put parenthesis instead of brackets because the date would otherwise be crossed out. In other words ( )=[ ] in the report.+*

error_log:
*Description: Printer Error Log*
*Size: 681 bytes*
*Location: /var/log/cups/error_log*

*Recent Comments: W(19/Nov/2010:22:34:23-0500) No limit for Validate-Job defined in policy authenticated using Print-Job's policy.* This same error repeats 4 more times and is the only error mentioned in the report. What I would like to know is what is this error about?, Is there a way to correct this?

An additional detail is that I haven't installed any printers on this computer since I reinstalled OSX in my machine a 2 weeks ago.

Thank you for any assistance in this matter.

2.53GHz Core i5 MacBook Pro 15" (Mid-2010), Mac OS X (10.6.4), 500GB HDD @ 7200rpm, 4GB 1067MHz DDR3 RAM, Intel HD + Nvidia 330m with 256MB

Posted on Nov 27, 2010 4:21 PM

37 replies

vea1083 Author

Level 3

714 points

Nov 28, 2010 7:25 PM in response to PAHU

PAHU wrote:
Just installed build 10H531 and the entries are not appearing in the cups error log. At this stage I have created one network printer queue using the Generic Postscript PPD. Will leave it for a couple of hours to see if the references appear and if not I will enable printer sharing to see if that starts the entries.

How's testing going so far? No more CUPS error entries after the last post? Will you then upgrade back to 10.6.5 to confirm if the update is causing this bug?

Thank You for your assistance!, and Good Luck!

PAHU

Level 6

16,723 points

Nov 28, 2010 11:58 PM in response to vea1083

No entries appearing in the cups error log after several hours. Enabling printer sharing also did not make the validation message appear. Within minutes of installing build 10H574 the message started to appear in the log. This was without any printer queue and therefore no printer sharing was enabled. So there does appear to be a 'glitch' in 10.6.5, although as I said previously the message is just a warning and appears to be causing no detrimental affect to CUPS.

I will post the question about the entries to the Mac developer forum tonight.

To be continued...

vea1083 Author

Level 3

714 points

Nov 29, 2010 6:32 AM in response to PAHU

PAHU,

Please post back as soon as you get a developer response in the Mac Developer forum. How long should it take before we hear from a developer after you post the question?

Now in a earlier post you noted something about CUPS was upgraded to a new version once 10.6.5 came by. Is it possible that this CUPS update and not OSX to be the culprit of the problem or just OSX?

Thank You very much for your assistance PAHU.

vea1083 Author

Level 3

714 points

Nov 29, 2010 8:26 PM in response to vea1083

PAHU,

Did you were able to post the problem in the Apple Developer Forum?

Thank you for any status update you can provide.

PAHU

Level 6

16,723 points

Nov 29, 2010 10:52 PM in response to vea1083

Okay, got the following reply from Michael Sweet, Senior Printing System Engineer - PWG Chair.

The recent update of 10.6.5 (10H574) and subsequent update of CUPS to 1.4.5 has >generated two new warning message in the cups error log that repeat.

W - No limit for Validate-Job defined in policy >authenticated - using Print-Job's policy
W - No limit for Validate-Job defined in policy >kerberos - using Print-Job's policy

This is expected behavior, although perhaps we could just make these "info" messages so they don't show up at the default log level. Basically we were not handling the Validate-Job operation (basically a way to preflight a job before printing it) the same as the Print-Job operation (which actually prints something), and so it was not possible for a client/application to know whether a print request would need authentication.

I was not able to find any reference to this message in the CUPS guide nor have >I been able to find a relevant setting to disable it in the CUPS admin page so >I was hoping for an explanation and possible procedure to stop this from >occurring.

The simplest fix would be to run "cupsctl LogLevel=error" from a Terminal window. You can also reset the printing system (which copies the baseline cupsd.conf file over but also removes all printers from the system) or edit the cupsd.conf file and add "Validate-Job" after any reference to "Print-Job"

PAHU

Level 6

16,723 points

Nov 29, 2010 11:27 PM in response to PAHU

The reset of the printing system does appear to have stopped the messages. Can't believe it was that simple...

So now I am going to compare what changed in cupsd.conf from 10.6.4 to 10.6.5.

PAHU

Level 6

16,723 points

Nov 30, 2010 4:00 AM in response to PAHU

Comparison of the cupsd.conf from v1.4.4 to v1.4.5 does show the addition of the Validate-Job entries, as shown below;

<Policy default>
<Limit Create-Job Print-Job Print-URI Validate-Job>
Order deny,allow
</Limit>

And as Michael suggested, the replacement of the cupsd.conf with the backup (or reset of the printing system) has stopped this message from appearing in the error log. So even though the Validate-Job entries are still present in the new configuration file there was obviously a bad mix of other settings with the new conf which the reset resolved.

vea1083 Author

Level 3

714 points

Nov 30, 2010 9:09 AM in response to PAHU

PAHU wrote:
Okay, got the following reply from Michael Sweet, Senior Printing System Engineer - PWG Chair.

The recent update of 10.6.5 (10H574) and subsequent update of CUPS to 1.4.5 has >generated two new warning message in the cups error log that repeat.

W - No limit for Validate-Job defined in policy >authenticated - using Print-Job's policy
W - No limit for Validate-Job defined in policy >kerberos - using Print-Job's policy

This is expected behavior, although perhaps we could just make these "info" messages so they don't show up at the default log level. Basically we were not handling the Validate-Job operation (basically a way to preflight a job before printing it) the same as the Print-Job operation (which actually prints something), and so it was not possible for a client/application to know whether a print request would need authentication.

I was not able to find any reference to this message in the CUPS guide nor have >I been able to find a relevant setting to disable it in the CUPS admin page so >I was hoping for an explanation and possible procedure to stop this from >occurring.

The simplest fix would be to run "cupsctl LogLevel=error" from a Terminal window. You can also reset the printing system (which copies the baseline cupsd.conf file over but also removes all printers from the system) or edit the cupsd.conf file and add "Validate-Job" after any reference to "Print-Job"

PAHU,

How you were able to reset CUPS? Can you provide a detailed set of intructions so I can do it with my MacBook Pro? Also why did Michael said that the "W" messages are expected behaviors?

Thank You!

PAHU

Level 6

16,723 points

Nov 30, 2010 4:41 PM in response to vea1083

vea1083 wrote:
How you were able to reset CUPS? Can you provide a detailed set of intructions so I can do it with my MacBook Pro?

The easiest way to reset CUPS is as follows.

*How to Reset the Printing System*

1. Open System Preferences > Print & Fax
2. Move your mouse over the Printers list
3. Hold down the Control button and click the mouse
4. Click the "Reset printing system ..." popup
5. Restart your Mac

This will remove your print queues but not your printer drivers. So you will only need to add your printer queues again.

Also why did Michael said that the "W" messages are expected behaviors?

He is saying that they added this validation operation to ensure better functionality of the printing system. This resulted in the messages we were seeing, which I believe was most likely a result of a conflict with the previous setup for OS X 10.6.4 (and CUPS 1.4.4) and running the 10.6.5 update (which also updated CUPS to v1.4.5). By resetting the printing system, the conflict was removed and the messages stopped.

vea1083 Author

Level 3

714 points

Nov 30, 2010 5:32 PM in response to PAHU

PAHU wrote:

vea1083 wrote:
How you were able to reset CUPS? Can you provide a detailed set of intructions so I can do it with my MacBook Pro?

The easiest way to reset CUPS is as follows.

*How to Reset the Printing System*

1. Open System Preferences > Print & Fax
2. Move your mouse over the Printers list
3. Hold down the Control button and click the mouse
4. Click the "Reset printing system ..." popup
5. Restart your Mac

This will remove your print queues but not your printer drivers. So you will only need to add your printer queues again.

Also why did Michael said that the "W" messages are expected behaviors?

He is saying that they added this validation operation to ensure better functionality of the printing system. This resulted in the messages we were seeing, which I believe was most likely a result of a conflict with the previous setup for OS X 10.6.4 (and CUPS 1.4.4) and running the 10.6.5 update (which also updated CUPS to v1.4.5). By resetting the printing system, the conflict was removed and the messages stopped.

PAHU,

Thank You for your response, but I haven't installed any printers on my MacBook Pro yet so will this still work or I should install a printer first? Also have you not experience any more printer log entries after the reset?

I will try this solution and I will post back with the results, also what should I do with the error log? Can I delete it after reseting the system?

I will test out your reset procedure, but it won't be before I get your answer on the question if a Mac without a installed printer affects the outcome of this CUPS resolution procedure. I will be looking forward for your response! 🙂

Again, thank you for your diligence in this situation you have done an outstanding job in finding information with this bug.

PAHU

Level 6

16,723 points

Nov 30, 2010 6:06 PM in response to vea1083

You don't need to have a printer installed to reset the printing system. So follow the steps and then check the logs. So far my cups error log shows none of the Validate messages since the reset last night. Given that they were appearing a few times in an hour then it looks to have worked.

Regarding the log, just leave it. OS X has built-in methods for updating and archiving its logs so it won't cause your Mac any harm.

vea1083 Author

Level 3

714 points

Dec 2, 2010 9:51 AM in response to PAHU

PAHU,

I just reset CUPS and it appears to have worked however, it seems that just before reseting CUPS the log added a new entry, so I won't be able to know if the reset will fix the problem, since the entry was very close from the reset.

Also, after two days has your Mac CUPS log generated new entries? Another thing I can do is to manually erase the log and see if CUPS regenerates it. That might point if CUPS actually repaired itself.

Tell me what you think?

vea1083 Author

Level 3

714 points

Dec 2, 2010 11:42 AM in response to PAHU

PAHU,

After reseting CUPS, a new log was created and is in the same folder as the error log however this one has another name, "access_log". I think this log indicates that the reset was successful. Here is the log content, also I noticed that this access_log mentions the "cupsd.conf" file that you mentioned a few post back. Here are the contents of the "access_log"

access_log

*Description: Printer Access Log*
*Size: 193 bytes*
*Location: /var/log/cups/access_log*
*Recent Comments:*

*localhost -- 02/Dec/2010:12:26:06-0500 "PUT /admin/conf/cupsd.conf HTTP/1.1" 401 0 --*
*localhost - AUTHREF 02/Dec/2010:12:26:06-0500 "PUT /admin/conf/cupsd.conf HTTP/1.1" 201 4490 --*

Do you think this log indicates that I was successful reseting cups?

Now here's today's last entries of the error log before reseting CUPS, as you can see, the time of the last entry was very close to the creation of the access_log

error_log

*Description: Printer error log*
*Size: 908 bytes*
*Modified: Today, 12:25 PM*
*Recent Comments:*

*W 02/Dec/2010:12:25:43 -0500 No limit for Validate-Job defined in policy authenticated - using Print-Job's policy*
*W 25/Nov/2010:12:25:43 -0500 No limit for Validate-Job defined in policy kerberos - using Print-Job's policy*

So far, after one hour from the CUPS reset I still don't have new entries in the error_log. I hope that this error does not repeats but still I need to wait until a few days before I can say if I fixed this error or not.

I am looking forward to your response! 😉

vea1083 Author

Level 3

714 points

Dec 3, 2010 5:08 AM in response to vea1083

Any conclusion from the logs?

vea1083 Author

Level 3

714 points

Dec 3, 2010 6:36 AM in response to vea1083

PAHU,

I don't know if you have has the chance to see the access log that mentions the "cupsd.conf" being put. The log is named "access_log". So far yesterday, I did not received any error log message after resetting CUPS. However, due to the last error_log entry yesterday being so close to the CUPS reset, about 30 seconds of difference it will be hard to tell if the error was solved unless more testing is done. I will mark the message as "solved" in the next few days as I will have more time with my Mac computer. This will give me time if to know if the CUPS reset has worked. First of all, I would like to thank you PAHU for your assistance in this issue.

P.S. After two days, has your error log added more entries since the CUPS reset?

Again, thank you and I expect to hear your response soon.

This thread has been closed by the system or the community team. You may vote for any posts you find helpful, or search the Community for additional answers.

CUPS Printer Error Log