Shared printing broken

My iMac is connected to two printers (Canon Pixma iP5000 via USB, HP LaserJet via ethernet) and shares the printers with 2 other computers (MacBook running OS 10.5.7 and G4 running OS 10.4.11) via local network.

Even after 10.5.7 update, everything was working fine. But then two days ago printing went haywire. Hitting command-P caused whatever applications I was trying to print from to hang, as well as Printer Proxy, Print&Fax prefs, and Sharing prefs. Restart did not help. Repair permissions did not help. Verified hard disk. Did Archive and Install of Mac OS X 10.5 and ran software updates. Was able to print from this computer (USB connection direct to printer) UNTIL someone tried to print from the G4 via the local shared network, causing his application to hang and hanging Printer Proxy and the System Prefs on this computer again.

Since then, steps taken: --
Ran the following in Terminal: sudo cp /private/etc/cups/cupsd.conf.default /private/etc/cups/cupsd.conf
This gave me access once again to the Print&Fax prefs. I was able to then reset the printing system. Added the printers successfully. By "default" they were set for sharing, but sharing was turned off. So I opened Sharing prefs, and enabled Printer Sharing. Closed System Prefs. Tested printing from TextWrangler and got the spinning beachball. After about 20 secs of that, I forced quit. Printer Proxy was not responding, so forced it to quit also. Tried to open Print&Fax prefs, but it would not respond. Sharing prefs also would not respond.

Next I downloaded Print Therapy and ran each of the utilities without a hitch, except that on repairing permissions, Print Therapy reported the following file was missing: /usr/libexec/cups/notifier/testnotify

On restart, opened Print&Fax prefs, added the printers, and this time disabled sharing. Printing locally (direct USB connection to printer) was successful.

But as soon as I enabled sharing, same problem all over again.

Then I reinstalled the 10.5.7 combo update. Afterwards enabled sharing printers, opened a text doc in TextWrangler, hit command-P and held my breath. It took about 10 seconds, but then the print dialog window opened, and I was able to print okay. Then I went over to the G4 and tried to print, using the shared printer. It was no good. Back to the iMac. Printing was broken again.

Re-ran Print Therapy. Opened Print&Fax, added the printers back, again tried enabling sharing, but the Print&Fax prefs became nonresponsive, and Sharing prefs also.

Opened Console, took a look at var/log/cups/error log, but I'm no techie, so I don't know what to look for. One thing that did stand out repeatedly is this:
"(org.cups.cupsd [3884]) Unknown Key: SHAuthorizationRight"

Finally, I have disabled sharing printers for the time being, and am able to print directly from the iMac. But this is not at all satisfactory. Someone please help!

iMac Intel Core 2 Duo 2GB, 320GB, MacBook Intel Core 2 Duo 2GB, 80GB, Mac OS X (10.5.7), G4 Gigabit Ethernet, 1.7GHZ, 704MB, 160GB, Mac OSX 10.4.11

Posted on Jun 7, 2009 7:07 PM

Reply
15 replies

Jun 7, 2009 9:33 PM in response to Das Chan

Looking at the cups error log entry, it does appear that something to do with authentication is not quite right on your Mac.

Have a look at this kb article, as it may be worth trying.

http://support.apple.com/kb/HT3511

Also, don't be concerned about the Print Therapy message about the testnotify file missing. I just checked the notifier folder and this file is not present on several of my machines.

PaHu

Jun 8, 2009 12:10 AM in response to PAHU

Hi Pahou, thanks for your reply. Looking at the kb article, I don't really see how it is relevant to the situation... Adding and deleting printers is not a problem, but sharing is. The other users are not adding or deleting printers, but merely trying to access the printers that are set up to be shared from my computer. The printers were showing up in their systems, but not responding. Now that I've disabled Printer Sharing, of course the printers do not show up.

If there is an authentication problem, then even after Archive & Install and then reinstallation of the 10.5.7 combo update, that should have been fixed, no?

Unless something else is corrupting it?? Is it possible that the DSL modem I'm using is somehow or other messing up the printing system? Have been experiencing difficulties getting online and keeping DSL connection - could be a modem issue, but then there is no difficulty to share files between the computers via the modem.

Anybody know how to read console error logs?

Jun 8, 2009 12:40 AM in response to Das Chan

Das Chan wrote:
Hi Pahou, thanks for your reply. Looking at the kb article, I don't really see how it is relevant to the situation... Adding and deleting printers is not a problem, but sharing is.

You need to think outside the square with problem solving. You have performed an update and now the problem is occurring. And you are getting authentication errors in the cups error log, so while the article doesn't detail your symptom exactly, the .7 update introduced a security change with CUPS and it sounds like this is what you are having.

If there is an authentication problem, then even after Archive & Install and then reinstallation of the 10.5.7 combo update, that should have been fixed, no?

Not if the .7 update has caused this...

Is it possible that the DSL modem I'm using is somehow or other messing up the printing system?

Possible but not likely. If the router is providing NAT correctly, then your local network should be isolated from the ISP's network.

Anybody know how to read console error logs?

You referring to the cups error log or a different log? If you mean cups then you can post the relevant section showing the error back here.

Just one other thing. I would go to the other Mac's and delete the printer queues to the iMac shares. If they are still trying to connect while you have been doing all these changes then they may be contributing to the symptom.

Jun 8, 2009 6:49 AM in response to PAHU

Sorry, Pahu, looking back over my post I see first of all that I misspelled your name, and then too I wrote carelessly asking if anybody knows how to read console error logs - of course many people here do - I'm the one who doesn't. What I meant to ask was help to make sense out of the log. Unfortunately, I don't know enough to really pin down the errors, and the log is long. But I'll post below a sampling of the log from yesterday. So I'll copy from where I had just successfully printed (after disabling sharing), and then I tried enabling sharing again. Cannot remember step for step what I was doing, but I guess the log will tell it all.


I [07/Jun/2009:10:25:03 +0800] [Job 7] Completed successfully.
I [07/Jun/2009:10:38:41 +0800] Scheduler shutting down normally.
I [07/Jun/2009:10:38:41 +0800] Saving job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:10:38:42 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:10:38:42 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:10:38:42 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:10:38:42 +0800] Remote access is disabled.
I [07/Jun/2009:10:38:42 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
E [07/Jun/2009:10:38:42 +0800] TMPDIR (/var/folders/-r/-rNcX2TaH14sqkcu8vJN8U +TI/-Tmp-/) has the wrong permissions!
I [07/Jun/2009:10:38:42 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:10:38:42 +0800] Configured for up to 100 clients.
I [07/Jun/2009:10:38:42 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:10:38:42 +0800] Using policy "default" as the default!
I [07/Jun/2009:10:38:42 +0800] Full reload is required.
I [07/Jun/2009:10:38:42 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:10:38:42 +0800] Loading job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:10:38:42 +0800] Full reload complete.
I [07/Jun/2009:10:38:42 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
E [07/Jun/2009:10:38:42 +0800] Unable to bind socket for address ::1:631 - Address already in use.
E [07/Jun/2009:10:38:42 +0800] Unable to bind socket for address 127.0.0.1:631 - Address already in use.
I [07/Jun/2009:10:38:42 +0800] Listening to /private/var/run/cupsd on fd 1...
I [07/Jun/2009:10:38:42 +0800] Resuming new connection processing...
I [07/Jun/2009:10:38:44 +0800] Scheduler shutting down normally.
I [07/Jun/2009:10:38:44 +0800] Saving job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:10:38:45 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:10:38:45 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:10:38:45 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:10:38:45 +0800] Remote access is disabled.
I [07/Jun/2009:10:38:45 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
E [07/Jun/2009:10:38:45 +0800] TMPDIR (/var/folders/-r/-rNcX2TaH14sqkcu8vJN8U +TI/-Tmp-/) has the wrong permissions!
I [07/Jun/2009:10:38:45 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:10:38:45 +0800] Configured for up to 100 clients.
I [07/Jun/2009:10:38:45 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:10:38:45 +0800] Using policy "default" as the default!
I [07/Jun/2009:10:38:45 +0800] Full reload is required.
I [07/Jun/2009:10:38:45 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:10:38:45 +0800] Loading job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:10:38:45 +0800] Full reload complete.
I [07/Jun/2009:10:38:45 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
E [07/Jun/2009:10:38:45 +0800] Unable to bind socket for address ::1:631 - Address already in use.
E [07/Jun/2009:10:38:45 +0800] Unable to bind socket for address 127.0.0.1:631 - Address already in use.
I [07/Jun/2009:10:38:45 +0800] Listening to /private/var/run/cupsd on fd 1...
I [07/Jun/2009:10:38:45 +0800] Resuming new connection processing...
I [07/Jun/2009:11:03:14 +0800] Scheduler shutting down normally.
I [07/Jun/2009:11:03:14 +0800] Saving job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:09:56 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:11:09:56 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:11:09:56 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:11:09:56 +0800] Remote access is disabled.
I [07/Jun/2009:11:09:56 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [07/Jun/2009:11:09:56 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:11:09:56 +0800] Configured for up to 100 clients.
I [07/Jun/2009:11:09:56 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:11:09:56 +0800] Using policy "default" as the default!
I [07/Jun/2009:11:09:56 +0800] Full reload is required.
I [07/Jun/2009:11:09:56 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:11:09:56 +0800] Loading job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:09:56 +0800] Full reload complete.
I [07/Jun/2009:11:09:56 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
I [07/Jun/2009:11:09:56 +0800] Listening to ::1:631 on fd 4...
I [07/Jun/2009:11:09:56 +0800] Listening to 127.0.0.1:631 on fd 6...
I [07/Jun/2009:11:09:56 +0800] Listening to /private/var/run/cupsd on fd 7...
I [07/Jun/2009:11:09:56 +0800] Resuming new connection processing...
I [07/Jun/2009:11:10:43 +0800] Scheduler shutting down normally.
E [07/Jun/2009:11:10:43 +0800] Unable to save remote.cache - No such file or directory
E [07/Jun/2009:11:10:43 +0800] Unable to create job cache file "/private/var/spool/cups/cache/job.cache" - No such file or directory
I [07/Jun/2009:11:10:44 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:11:10:44 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:11:10:44 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:11:10:44 +0800] Remote access is disabled.
I [07/Jun/2009:11:10:44 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
E [07/Jun/2009:11:10:44 +0800] TMPDIR (/var/folders/-r/-rNcX2TaH14sqkcu8vJN8U +TI/-Tmp-/) has the wrong permissions!
I [07/Jun/2009:11:10:44 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:11:10:44 +0800] Configured for up to 100 clients.
I [07/Jun/2009:11:10:44 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:11:10:44 +0800] Using policy "default" as the default!
I [07/Jun/2009:11:10:44 +0800] Full reload is required.
I [07/Jun/2009:11:10:44 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:11:10:44 +0800] Full reload complete.
I [07/Jun/2009:11:10:44 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
E [07/Jun/2009:11:10:44 +0800] Unable to bind socket for address ::1:631 - Address already in use.
E [07/Jun/2009:11:10:44 +0800] Unable to bind socket for address 127.0.0.1:631 - Address already in use.
I [07/Jun/2009:11:10:44 +0800] Listening to /private/var/run/cupsd on fd 1...
I [07/Jun/2009:11:10:44 +0800] Resuming new connection processing...
I [07/Jun/2009:11:10:54 +0800] Scheduler shutting down normally.
I [07/Jun/2009:11:10:54 +0800] Saving job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:11:24 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:11:11:24 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:11:11:24 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:11:11:24 +0800] Remote access is disabled.
I [07/Jun/2009:11:11:24 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [07/Jun/2009:11:11:24 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:11:11:24 +0800] Configured for up to 100 clients.
I [07/Jun/2009:11:11:24 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:11:11:24 +0800] Using policy "default" as the default!
I [07/Jun/2009:11:11:24 +0800] Full reload is required.
I [07/Jun/2009:11:11:25 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:11:11:27 +0800] Loading job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:11:27 +0800] Full reload complete.
I [07/Jun/2009:11:11:27 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
I [07/Jun/2009:11:11:27 +0800] Listening to ::1:631 on fd 4...
I [07/Jun/2009:11:11:27 +0800] Listening to 127.0.0.1:631 on fd 6...
I [07/Jun/2009:11:11:27 +0800] Listening to /private/var/run/cupsd on fd 7...
I [07/Jun/2009:11:11:27 +0800] Resuming new connection processing...
E [07/Jun/2009:11:13:08 +0800] CUPS-Add-Modify-Printer: Unauthorized
I [07/Jun/2009:11:13:09 +0800] Setting Canon_iP5000 device-uri to "file:///dev/null" (was "file:/dev/null".)
I [07/Jun/2009:11:13:09 +0800] Setting Canon_iP5000 printer-is-accepting-jobs to 1 (was 0.)
I [07/Jun/2009:11:13:09 +0800] Setting Canon_iP5000 printer-state to 3 (was 5.)
I [07/Jun/2009:11:13:09 +0800] Saving printers.conf...
I [07/Jun/2009:11:13:09 +0800] New printer "Canon_iP5000" added by " AUTHREF".
I [07/Jun/2009:11:13:10 +0800] Setting Canon_iP5000 printer-is-shared to 1 (was 1.)
I [07/Jun/2009:11:13:10 +0800] Saving printers.conf...
I [07/Jun/2009:11:13:10 +0800] Printer "Canon_iP5000" modified by " AUTHREF".
I [07/Jun/2009:11:19:22 +0800] Scheduler shutting down normally.
I [07/Jun/2009:11:19:22 +0800] Saving job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:19:24 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:11:19:24 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:11:19:24 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:11:19:24 +0800] Remote access is disabled.
I [07/Jun/2009:11:19:24 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
E [07/Jun/2009:11:19:24 +0800] TMPDIR (/var/folders/-r/-rNcX2TaH14sqkcu8vJN8U +TI/-Tmp-/) has the wrong permissions!
I [07/Jun/2009:11:19:24 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:11:19:24 +0800] Configured for up to 100 clients.
I [07/Jun/2009:11:19:24 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:11:19:24 +0800] Using policy "default" as the default!
I [07/Jun/2009:11:19:24 +0800] Full reload is required.
I [07/Jun/2009:11:19:24 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:11:19:24 +0800] Loading job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:19:24 +0800] Full reload complete.
I [07/Jun/2009:11:19:24 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
E [07/Jun/2009:11:19:24 +0800] Unable to bind socket for address ::1:631 - Address already in use.
E [07/Jun/2009:11:19:24 +0800] Unable to bind socket for address 127.0.0.1:631 - Address already in use.
I [07/Jun/2009:11:19:24 +0800] Listening to /private/var/run/cupsd on fd 1...
I [07/Jun/2009:11:19:24 +0800] Resuming new connection processing...
I [07/Jun/2009:11:19:32 +0800] Scheduler shutting down normally.
I [07/Jun/2009:11:19:32 +0800] Saving job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:21:56 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:11:21:56 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:11:21:56 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:11:21:56 +0800] Remote access is disabled.
I [07/Jun/2009:11:21:56 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [07/Jun/2009:11:21:56 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:11:21:56 +0800] Configured for up to 100 clients.
I [07/Jun/2009:11:21:56 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:11:21:56 +0800] Using policy "default" as the default!
I [07/Jun/2009:11:21:56 +0800] Full reload is required.
I [07/Jun/2009:11:21:56 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:11:21:56 +0800] Loading job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:21:57 +0800] Full reload complete.
I [07/Jun/2009:11:21:57 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
I [07/Jun/2009:11:21:57 +0800] Listening to ::1:631 on fd 4...
I [07/Jun/2009:11:21:57 +0800] Listening to 127.0.0.1:631 on fd 6...
I [07/Jun/2009:11:21:57 +0800] Listening to /private/var/run/cupsd on fd 7...
I [07/Jun/2009:11:21:57 +0800] Resuming new connection processing...
I [07/Jun/2009:11:31:53 +0800] Scheduler shutting down normally.
I [07/Jun/2009:11:31:53 +0800] Saving job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:34:03 +0800] Listening to ::1:631 (IPv6)
I [07/Jun/2009:11:34:03 +0800] Listening to 127.0.0.1:631 (IPv4)
I [07/Jun/2009:11:34:03 +0800] Listening to /private/var/run/cupsd (Domain)
I [07/Jun/2009:11:34:03 +0800] Remote access is disabled.
I [07/Jun/2009:11:34:03 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [07/Jun/2009:11:34:03 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [07/Jun/2009:11:34:03 +0800] Configured for up to 100 clients.
I [07/Jun/2009:11:34:03 +0800] Allowing up to 100 client connections per host.
I [07/Jun/2009:11:34:03 +0800] Using policy "default" as the default!
I [07/Jun/2009:11:34:03 +0800] Full reload is required.
I [07/Jun/2009:11:34:03 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [07/Jun/2009:11:34:03 +0800] Loading job cache file "/private/var/spool/cups/cache/job.cache"...
I [07/Jun/2009:11:34:03 +0800] Full reload complete.
I [07/Jun/2009:11:34:03 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
I [07/Jun/2009:11:34:03 +0800] Listening to ::1:631 on fd 4...
I [07/Jun/2009:11:34:03 +0800] Listening to 127.0.0.1:631 on fd 6...
I [07/Jun/2009:11:34:03 +0800] Listening to /private/var/run/cupsd on fd 7...
I [07/Jun/2009:11:34:03 +0800] Resuming new connection processing...
I [07/Jun/2009:11:34:12 +0800] Started "/usr/libexec/cups/daemon/cups-deviced" (pid=184)
E [07/Jun/2009:11:34:54 +0800] CUPS-Add-Modify-Printer: Unauthorized


and it goes on like this over and over. At one point I was running Print Therapy, repaired permissions, Reset Print System, Replaced cupsd file, etc. I deleted the Canon printer and then added it back, added also the HP. As long as sharing was disabled, they were okay. The second I enabled sharing, the prefs, printer proxy all hung.

One weird thing is that earlier the console showed the error "(org.cups.cupsd 3884) Unknown Key: SHAuthorizationRight", but now I don't see it there at all, not in any of the logs under cups. So where did it come from and where did it go? I don't know. I didn't clear the console, so...

I see from another post in the forums that someone else having shared printer problems found there was an issue with MDNSResponder (Bonjour), and somehow or other disabled it... see http://discussions.apple.com/message.jspa?messageID=9477765#9477765. I'm wondering if that could be the case here also, because now it occurs to me that all this happened right after I ran into a problem launching Parallels Desktop 3 Build 5626. All of a sudden my other apps also became non-responsive. Force quit, repair permissions and restart fixed them, but Parallels Desktop would not launch, so I installed the update (Build 5636). That seemed to do the trick. Parallels Desktop was working fine. But that was when the shared printing broke. Maybe there is some issue with Bonjour? I have not been running Parallels Desktop since then, except just this afternoon. Printing works fine from within Parallels Desktop, as before.

Does any of this make sense to you?

Jun 8, 2009 4:38 PM in response to Das Chan

Thanks for the log. There are several items in here that do not look correct and are possibly a cause.

The first is this error;

E 07/Jun/2009:10:38:42 +0800 TMPDIR (/var/folders/-r/-rNcX2TaH14sqkcu8vJN8U +TI/-Tmp-/) has the wrong permissions!

In comparison to my Mac, the loading of the cupsd.conf is followed by using default TempDir, as shown below.

I [08/Jun/2009:15:54:16 +1000] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [08/Jun/2009:15:54:16 +1000] Using default TempDir of /private/var/spool/cups/tmp...

The /var/folders directory and its subfolders are owned by system, so the fact that there is a reference to the wrong permissions would suggest you need to perform a repair disk permissions, preferably after booting from your Mac OS X disc.

The next entry/s that are of concern are the inability to bind to the CUPS IPP port.

E 07/Jun/2009:10:38:42 +0800 Unable to bind socket for address ::1:631 - Address already in use.
E 07/Jun/2009:10:38:42 +0800 Unable to bind socket for address 127.0.0.1:631 - Address already in use.

Again, by comparison, my Mac shows;

I [08/Jun/2009:15:54:16 +1000] Listening to ::1:631 (IPv6)
I [08/Jun/2009:15:54:16 +1000] Listening to 127.0.0.1:631 (IPv4)

Not sure if this error is due to permissions or some other application. At some point through the log this appears to get resolved. But then the error appears again for some reason. Anyway, it doesn't look correct but I'm not sure how to resolve this. Are you able to open the cups web page, which is http://127.0.0.1:631

The next entry that doesn't look correct is when you add the iP5000.

I 07/Jun/2009:11:13:09 +0800 New printer "Canon_iP5000" added by "AUTHREF".

I don't remember seeing a user of "AUTHREF" previously and will have to do some searching to see what this is. My Mac shows the following for an add printer, which I did yesterday for another posting.

I [08/Jun/2009:15:14:53 +1000] New printer "MP980 series__00_00_85_ec_96_60" added by "pahu".

This may be related to the other error you were getting about the SHAuthorization and it is therefore probably not a bad idea to use the commands in that kb article. I suggest you try the one for the mobile user and replace student with your short name.

As for the issue being related to MDNS/Bonjour, after reading that other posting I believe the firewall was enabled on the Mac, hence the requests to allow certain applications to have access. Do you have the firewall enabled?

Finally, I'm not sure about Parallels being a cause. I use Fusion so I don't know if Parallels has the same option (I assume it would), but with Fusion I can set Windows to use the Mac printers. I don't have this enabled but if you do then try disabling it to see if that helps.

Also, are you able to use the Parallels printer queue when the Mac printer proxy errors?

PaHu

Jun 8, 2009 8:06 PM in response to PAHU

Hi Pahu, I'm back after trying the following: -

1. This morning enabled printer sharing for the Canon, launched TextWrangler, opened a file and hit command-P. RESULT: Printer Proxy & TextWrangler at first were unresponsive. In Firefox, opened url 127.0.0.1:631/, access was successful, and subsequently the document printed successfully (time duration: 08:32.11 - 08.33.29).

2. Launched Parallels Desktop, booted Win XP, opened Notepad, typed a short message and selected print command. (Printer is set to default Mac printer.) RESULT: Parallels Desktop became unresponsive. In Firefox, cleared cache, attempted to again connect to 127.0.0.1:631/, but could not. Forced quit Parallels Desktop. Attempted relaunch, but did not respond. Forced quit again.

3. Quit all apps, restarted with Mac OS X 10.5 Disk 1, repaired permissions, restarted.

4. Relaunched Parallels Desktop, attempted to boot Win XP, did not respond. Launched Firefox, but could not connect to 127.0.0.1:631/. Forced quit Parallels Desktop. Launched TextWrangler, attempted to print, no response. Again attempted to connect to 127.0.0.1:631/, no response.

5. Launched Terminal, typed: sudo cp /private/etc/cups/cupsd.conf.default /private/etc/cups/cupsd.conf, followed by password, quit all apps and restarted.

6. Opened Sharing Prefs, confirmed Shared Printing disabled. Opened Print&Fax prefs, and disabled sharing. Launched Firefox, and at once accessed 127.0.01:631/. Poked around a bit on the website, read a bit about Kerberos and opened the Administration tab, but made no changes from the CUPS webpages.

7. Next launched Parallels Desktop, successfully booted Win XP. Opened Notepad, selected print command and printed successfully. (Of course, using Mac default printer - direct USB connection.)

8. Launched Terminal, typed: dseditgroup -o edit -n /Local/Default -u admin -p -a das -t user lpadmin
Note: "student" replaced with my short name, "das". Then entered password, hit return. Terminal reported: Authentication failed. Tried again, same result. What am I doing wrong?

Here's the log from this morning:

I [09/Jun/2009:08:18:39 +0800] Installing config file "/private/etc/cups/cupsd.conf"...
I [09/Jun/2009:08:18:39 +0800] Listening to :::631 (IPv6)
I [09/Jun/2009:08:18:39 +0800] Listening to 0.0.0.0:631 (IPv4)
I [09/Jun/2009:08:18:39 +0800] Listening to /private/var/run/cupsd (Domain)
I [09/Jun/2009:08:18:39 +0800] Remote access is enabled.
I [09/Jun/2009:08:18:39 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [09/Jun/2009:08:18:39 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [09/Jun/2009:08:18:39 +0800] Configured for up to 100 clients.
I [09/Jun/2009:08:18:39 +0800] Allowing up to 100 client connections per host.
I [09/Jun/2009:08:18:39 +0800] Using policy "default" as the default!
I [09/Jun/2009:08:18:40 +0800] Partial reload complete.
I [09/Jun/2009:08:18:40 +0800] Listening to :::631 on fd 8...
I [09/Jun/2009:08:18:40 +0800] Listening to 0.0.0.0:631 on fd 9...
I [09/Jun/2009:08:18:40 +0800] Listening to /private/var/run/cupsd on fd 7...
I [09/Jun/2009:08:18:40 +0800] Listening to ::1:631 on fd 4...
I [09/Jun/2009:08:18:40 +0800] Listening to 127.0.0.1:631 on fd 6...
I [09/Jun/2009:08:18:40 +0800] Resuming new connection processing...
E [09/Jun/2009:08:18:46 +0800] CUPS-Add-Modify-Printer: Unauthorized
I [09/Jun/2009:08:18:46 +0800] Setting Canon_iP5000 printer-is-shared to 1 (was 0.)
I [09/Jun/2009:08:18:46 +0800] Saving printers.conf...
I [09/Jun/2009:08:18:46 +0800] Printer "Canon_iP5000" modified by "das".
I [09/Jun/2009:08:32:11 +0800] [Job ???] Request file type is application/pdf.
I [09/Jun/2009:08:32:11 +0800] [Job 5] Adding start banner page "none".
I [09/Jun/2009:08:32:11 +0800] [Job 5] Adding end banner page "none".
I [09/Jun/2009:08:32:11 +0800] [Job 5] File of type application/pdf queued by "das".
I [09/Jun/2009:08:32:11 +0800] [Job 5] Queued on "Canon_iP5000" by "das".
I [09/Jun/2009:08:32:11 +0800] [Job 5] Started filter /System/Library/Printers/Libraries/PrintJobMgr/Contents/MacOS/PrintJobMgr (PID 32418)
I [09/Jun/2009:08:33:29 +0800] [Job 5] Completed successfully.
I [09/Jun/2009:09:31:59 +0800] Listening to :::631 (IPv6)
I [09/Jun/2009:09:31:59 +0800] Listening to 0.0.0.0:631 (IPv4)
I [09/Jun/2009:09:31:59 +0800] Listening to /private/var/run/cupsd (Domain)
I [09/Jun/2009:09:31:59 +0800] Remote access is enabled.
I [09/Jun/2009:09:31:59 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [09/Jun/2009:09:31:59 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [09/Jun/2009:09:31:59 +0800] Configured for up to 100 clients.
I [09/Jun/2009:09:31:59 +0800] Allowing up to 100 client connections per host.
I [09/Jun/2009:09:31:59 +0800] Using policy "default" as the default!
I [09/Jun/2009:09:31:59 +0800] Full reload is required.
I [09/Jun/2009:09:31:59 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [09/Jun/2009:09:31:59 +0800] Loading NextJobId from job cache file "/private/var/spool/cups/cache/job.cache"...
I [09/Jun/2009:09:31:59 +0800] Full reload complete.
I [09/Jun/2009:09:31:59 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
I [09/Jun/2009:09:31:59 +0800] Listening to :::631 on fd 9...
I [09/Jun/2009:09:31:59 +0800] Listening to 0.0.0.0:631 on fd 10...
I [09/Jun/2009:09:31:59 +0800] Listening to /private/var/run/cupsd on fd 8...
I [09/Jun/2009:09:31:59 +0800] Listening to ::1:631 on fd 4...
I [09/Jun/2009:09:31:59 +0800] Listening to 127.0.0.1:631 on fd 7...
I [09/Jun/2009:09:31:59 +0800] Resuming new connection processing...
I [09/Jun/2009:09:54:57 +0800] Listening to ::1:631 (IPv6)
I [09/Jun/2009:09:54:57 +0800] Listening to 127.0.0.1:631 (IPv4)
I [09/Jun/2009:09:54:57 +0800] Listening to /private/var/run/cupsd (Domain)
I [09/Jun/2009:09:54:57 +0800] Remote access is disabled.
I [09/Jun/2009:09:54:57 +0800] Loaded configuration file "/private/etc/cups/cupsd.conf"
I [09/Jun/2009:09:54:57 +0800] Using default TempDir of /private/var/spool/cups/tmp...
I [09/Jun/2009:09:54:57 +0800] Configured for up to 100 clients.
I [09/Jun/2009:09:54:57 +0800] Allowing up to 100 client connections per host.
I [09/Jun/2009:09:54:57 +0800] Using policy "default" as the default!
I [09/Jun/2009:09:54:57 +0800] Full reload is required.
I [09/Jun/2009:09:54:58 +0800] Loaded MIME database from '/private/etc/cups': 52 types, 49 filters...
I [09/Jun/2009:09:54:59 +0800] Loading NextJobId from job cache file "/private/var/spool/cups/cache/job.cache"...
I [09/Jun/2009:09:54:59 +0800] Full reload complete.
I [09/Jun/2009:09:54:59 +0800] Cleaning out old temporary files in "/private/var/spool/cups/tmp"...
I [09/Jun/2009:09:54:59 +0800] Listening to ::1:631 on fd 4...
I [09/Jun/2009:09:54:59 +0800] Listening to 127.0.0.1:631 on fd 6...
I [09/Jun/2009:09:54:59 +0800] Listening to /private/var/run/cupsd on fd 7...
I [09/Jun/2009:09:54:59 +0800] Resuming new connection processing...
E [09/Jun/2009:09:55:13 +0800] CUPS-Add-Modify-Printer: Unauthorized
I [09/Jun/2009:09:55:13 +0800] Setting Canon_iP5000 printer-is-shared to 0 (was 1.)
I [09/Jun/2009:09:55:13 +0800] Saving printers.conf...
I [09/Jun/2009:09:55:13 +0800] Printer "Canon_iP5000" modified by "das".
I [09/Jun/2009:10:05:23 +0800] [Job 6] Adding start banner page "none".
I [09/Jun/2009:10:05:23 +0800] [Job 6] Adding end banner page "none".
I [09/Jun/2009:10:05:23 +0800] [Job 6] File of type application/postscript queued by "das".
I [09/Jun/2009:10:05:23 +0800] [Job 6] Queued on "Canon_iP5000" by "das".
I [09/Jun/2009:10:05:23 +0800] [Job 6] Started filter /usr/libexec/cups/filter/pstoappleps (PID 318)
I [09/Jun/2009:10:05:23 +0800] [Job 6] Started filter /usr/libexec/cups/filter/pstopdffilter (PID 319)
I [09/Jun/2009:10:05:23 +0800] [Job 6] Started filter /System/Library/Printers/Libraries/PrintJobMgr/Contents/MacOS/PrintJobMgr (PID 320)
I [09/Jun/2009:10:05:43 +0800] [Job 6] Completed successfully.
I [09/Jun/2009:10:07:04 +0800] [Job 7] Adding start banner page "none".
I [09/Jun/2009:10:07:04 +0800] [Job 7] Adding end banner page "none".
I [09/Jun/2009:10:07:04 +0800] [Job 7] File of type application/postscript queued by "das".
I [09/Jun/2009:10:07:04 +0800] [Job 7] Queued on "Canon_iP5000" by "das".
I [09/Jun/2009:10:07:04 +0800] [Job 7] Started filter /usr/libexec/cups/filter/pstoappleps (PID 347)
I [09/Jun/2009:10:07:04 +0800] [Job 7] Started filter /usr/libexec/cups/filter/pstopdffilter (PID 348)
I [09/Jun/2009:10:07:04 +0800] [Job 7] Started filter /System/Library/Printers/Libraries/PrintJobMgr/Contents/MacOS/PrintJobMgr (PID 349)
I [09/Jun/2009:10:07:16 +0800] [Job 7] Completed successfully.
I [09/Jun/2009:10:16:24 +0800] Started "/usr/libexec/cups/cgi-bin/printers.cgi" (pid=433)
I [09/Jun/2009:10:17:08 +0800] Started "/usr/libexec/cups/cgi-bin/help.cgi" (pid=437)
I [09/Jun/2009:10:17:18 +0800] Started "/usr/libexec/cups/cgi-bin/help.cgi" (pid=438)
I [09/Jun/2009:10:18:41 +0800] Started "/usr/libexec/cups/cgi-bin/help.cgi" (pid=453)
I [09/Jun/2009:10:21:51 +0800] Started "/usr/libexec/cups/cgi-bin/admin.cgi" (pid=482)
I [09/Jun/2009:10:23:03 +0800] [Job ???] Request file type is application/pdf.
I [09/Jun/2009:10:23:03 +0800] [Job 8] Adding start banner page "none".
I [09/Jun/2009:10:23:03 +0800] [Job 8] Adding end banner page "none".
I [09/Jun/2009:10:23:03 +0800] [Job 8] File of type application/pdf queued by "das".
I [09/Jun/2009:10:23:03 +0800] [Job 8] Queued on "Canon_iP5000" by "das".
I [09/Jun/2009:10:23:03 +0800] [Job 8] Started filter /System/Library/Printers/Libraries/PrintJobMgr/Contents/MacOS/PrintJobMgr (PID 498)
I [09/Jun/2009:10:23:21 +0800] [Job 8] Completed successfully.

Jun 9, 2009 4:18 AM in response to Das Chan

This cups error log is looking at lot healthier compared to the previous log, so it seems that you have achieved getting this in order with all that you have done so far. You can see that your name is mentioned for creating the printer - not AUTHREF. Also, with remote access enabled (printer sharing) there is no complaints about access to CUPS or the ownership of temp directories/files. In fact, looking at all the print job entries, I would have said that the Mac is behaving as it should.

At this stage I am not sure what else to suggest. I think I need to sleep on it and get back to you tomorrow. Maybe someone else in the meantime may chip in and offer some thoughts...

PaHu

Jun 9, 2009 7:24 AM in response to PAHU

Thanks for checking in, Pahu. BTW, at one point when Parallels Desktop hung and Printer proxy was not responding, console did not report any activity in the cups logs. The other day I ran Print Therapy. Today I did not. Maybe Print Therapy was responsible for some of those weird cups error messages in the log? Anyway, for the time being, I've disabled printer sharing, until someone can help come up with a solution. 😟

Jun 9, 2009 8:15 AM in response to Das Chan

To add to the confusion, on peering through Console Messages under Log Database Queries, now I see the "com.apple.launchd[1] (org.cups.cupsd) Unknown key: SHAuthorizationRight " error that I reported originally. Anyway, FWIW, here's a snippet of the Console Messages from today (morning): --

6/9/09 8:18:40 AM com.apple.service_helper[32232] bind(): Address already in use
6/9/09 8:18:40 AM com.apple.service_helper[32232] org.cups.cups-lpd: Already loaded
6/9/09 8:18:40 AM com.apple.launchd[1] (org.samba.smbd[248]) Stray process with PGID equal to this dead job: PID 249 PPID 1 smbd
6/9/09 8:18:40 AM com.apple.launchd[1] (org.samba.nmbd[32236]) Exited: Terminated
6/9/09 8:18:40 AM com.apple.launchd[1] (org.samba.nmbd) Throttling respawn: Will start in 10 seconds
6/9/09 8:44:44 AM com.apple.launchd[71] ([0x0-0x7f07f].com.parallels.desktop[16324]) Stray process with PGID equal to this dead job: PID 32311 PPID 1 WinAppHelper
6/9/09 8:44:44 AM com.apple.launchd[71] ([0x0-0x7f07f].com.parallels.desktop[16324]) Stray process with PGID equal to this dead job: PID 16765 PPID 1 vfstool
6/9/09 8:44:44 AM com.apple.launchd[71] ([0x0-0x7f07f].com.parallels.desktop[16324]) Exited: Killed
6/9/09 8:47:09 AM [0x0-0xc20c2].com.parallels.desktop[32563] QFSFileEngine::open: No file name specified
6/9/09 8:52:33 AM com.apple.launchd[71] ([0x0-0xc20c2].com.parallels.desktop[32563]) Exited: Terminated
6/9/09 8:55:07 AM com.apple.launchd[71] ([0x0-0xd00d].com.apple.finder[97]) Stray process with PGID equal to this dead job: PID 32667 PPID 1 smbclient
6/9/09 8:55:07 AM com.apple.launchd[71] ([0x0-0xd00d].com.apple.finder[97]) Stray process with PGID equal to this dead job: PID 32665 PPID 1 smbclient
6/9/09 8:55:07 AM com.apple.launchd[71] ([0x0-0xd00d].com.apple.finder[97]) Stray process with PGID equal to this dead job: PID 32652 PPID 1 smbclient
6/9/09 8:55:12 AM com.apple.loginwindow[35] Shutdown NOW!
6/9/09 8:55:12 AM com.apple.loginwindow[35] System shutdown time has arrived
6/9/09 8:55:12 AM com.apple.SystemStarter[30] /Library/StartupItems/Tablet/Tablet: line 4: /Library/StartupItems/Tablet/TabletDriverRelauncher: No such file or directory
6/9/09 8:55:14 AM com.apple.SystemStarter[30] kextunload: unload kext /System/Library/Extensions/Pvsnet.kext succeeded
6/9/09 8:55:14 AM com.apple.SystemStarter[30] kextunload: unload kext /System/Library/Extensions/ConnectUSB.kext succeeded
6/9/09 8:55:17 AM com.apple.SystemStarter[30] kextunload: unload kext /System/Library/Extensions/vmmain.kext succeeded
6/9/09 8:55:17 AM com.apple.SystemStarter[30] kextunload: unload kext /System/Library/Extensions/hypervisor.kext succeeded
6/9/09 9:30:05 AM com.apple.launchctl.System[2] BootCacheControl: could not open /var/db/BootCache.playlist: No such file or directory
6/9/09 9:30:05 AM com.apple.launchctl.System[2] BootCacheControl: could not unlink playlist /var/db/BootCache.playlist: Unknown error: -1
6/9/09 9:30:06 AM com.apple.launchctl.System[2] launchctl: Please convert the following to launchd: /etc/mach_init.d/dashboardadvisoryd.plist
6/9/09 9:30:06 AM com.apple.launchd[1] (com.adobe.versioncueCS3) Unknown key: ServiceDescription
6/9/09 9:30:06 AM com.apple.launchd[1] (com.apple.usbmuxd) Unknown key for boolean: EnableTransactions
6/9/09 9:30:06 AM com.apple.launchd[1] (org.cups.cups-lpd) Unknown key: SHAuthorizationRight
6/9/09 9:30:06 AM com.apple.launchd[1] (org.cups.cupsd) Unknown key: SHAuthorizationRight
6/9/09 9:30:06 AM com.apple.launchd[1] (org.ntp.ntpd) Unknown key: SHAuthorizationRight
6/9/09 9:30:06 AM com.apple.launchd[1] (org.x.privileged_startx) Unknown key for boolean: EnableTransactions
6/9/09 9:30:18 AM org.ntp.ntpd[28] Error : nodename nor servname provided, or not known
6/9/09 9:30:20 AM com.apple.launchd[1] (com.apple.aslmanager) Throttling respawn: Will start in 5 seconds
6/9/09 9:30:22 AM com.apple.launchd[1] (com.apple.aslmanager) Throttling respawn: Will start in 3 seconds
6/9/09 9:30:22 AM com.apple.launchd[1] (com.apple.aslmanager) Throttling respawn: Will start in 3 seconds
6/9/09 9:30:23 AM com.apple.SystemStarter[32] /Library/StartupItems/Tablet/Tablet: line 4: /Library/StartupItems/Tablet/TabletDriverRelauncher: No such file or directory
6/9/09 9:30:24 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/hypervisor.kext is already loaded
6/9/09 9:30:25 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/vmmain.kext is already loaded
6/9/09 9:30:25 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/ConnectUSB.kext is already loaded
6/9/09 9:30:25 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/Pvsnet.kext is already loaded
6/9/09 9:30:26 AM com.apple.SystemStarter[32] kextload: /Library/StartupItems/Parallels/Pvsvnic.kext loaded successfully
6/9/09 9:30:35 AM [0x0-0x5005].com.wacom.TabletDriver[109] TabletDriver[109]: RunApplication called while eRelaunching
6/9/09 9:30:36 AM com.apple.launchd[1] ([0x0-0x5005].com.wacom.TabletDriver[109]) Exited with exit code: 1
6/9/09 9:30:36 AM com.apple.launchd[1] (com.apple.UserEventAgent-LoginWindow[104]) Exited: Terminated
6/9/09 9:30:36 AM com.apple.launchd[112] (com.apple.AirPortBaseStationAgent) Unknown key for boolean: EnableTransactions
6/9/09 9:30:36 AM com.apple.launchd[112] (org.x.startx) Unknown key for boolean: EnableTransactions
6/9/09 9:30:58 AM com.apple.launchd[112] ([0x0-0x16016].com.linotype.FontExplorerX.Autoload[150]) Exited with exit code: 255
6/9/09 9:31:13 AM quicklookd[143] [QL ERROR] 'Creating thumbnail' timed out for '<QLThumbnailRequest /Users/das/Desktop/[soldats] Monster - 07.avi>'
6/9/09 9:31:58 AM [0x0-0x21021].com.parallels.desktop[182] QFSFileEngine::open: No file name specified
6/9/09 9:43:52 AM [0x0-0x26026].org.mozilla.firefox[276] Debugger() was called!
6/9/09 9:44:02 AM [0x0-0x26026].org.mozilla.firefox[276] [FDLProc] canHandle()
6/9/09 9:44:02 AM [0x0-0x26026].org.mozilla.firefox[276] [FDLProc] canHandle()
6/9/09 9:44:02 AM [0x0-0x26026].org.mozilla.firefox[276] [FDLProc] canHandle()
6/9/09 9:44:02 AM [0x0-0x26026].org.mozilla.firefox[276] [FDLProc] canHandle()
6/9/09 9:44:48 AM [0x0-0x26026].org.mozilla.firefox[276] [FDLProc] canHandle()
6/9/09 9:44:48 AM [0x0-0x26026].org.mozilla.firefox[276] [FDLProc] canHandle()
6/9/09 9:46:52 AM com.apple.launchd[112] ([0x0-0x21021].com.parallels.desktop[182]) Exited: Killed
6/9/09 9:52:23 AM com.apple.launchd[112] ([0x0-0x2c02c].com.barebones.textwrangler[373]) Exited: Terminated
6/9/09 9:53:28 AM com.apple.loginwindow[37] Shutdown NOW!
6/9/09 9:53:28 AM com.apple.loginwindow[37] System shutdown time has arrived
6/9/09 9:53:28 AM com.apple.SystemStarter[32] /Library/StartupItems/Tablet/Tablet: line 4: /Library/StartupItems/Tablet/TabletDriverRelauncher: No such file or directory
6/9/09 9:53:30 AM com.apple.SystemStarter[32] kextunload: unload kext /System/Library/Extensions/Pvsnet.kext succeeded
6/9/09 9:53:30 AM com.apple.SystemStarter[32] kextunload: unload kext /System/Library/Extensions/ConnectUSB.kext succeeded
6/9/09 9:53:33 AM com.apple.SystemStarter[32] kextunload: unload kext /System/Library/Extensions/vmmain.kext succeeded
6/9/09 9:53:33 AM com.apple.SystemStarter[32] kextunload: unload kext /System/Library/Extensions/hypervisor.kext succeeded
6/9/09 9:54:10 AM com.apple.launchctl.System[2] launchctl: Please convert the following to launchd: /etc/mach_init.d/dashboardadvisoryd.plist
6/9/09 9:54:10 AM com.apple.launchd[1] (com.adobe.versioncueCS3) Unknown key: ServiceDescription
6/9/09 9:54:10 AM com.apple.launchd[1] (com.apple.usbmuxd) Unknown key for boolean: EnableTransactions
6/9/09 9:54:10 AM com.apple.launchd[1] (org.cups.cups-lpd) Unknown key: SHAuthorizationRight
6/9/09 9:54:10 AM com.apple.launchd[1] (org.cups.cupsd) Unknown key: SHAuthorizationRight
6/9/09 9:54:10 AM com.apple.launchd[1] (org.ntp.ntpd) Unknown key: SHAuthorizationRight
6/9/09 9:54:10 AM com.apple.launchd[1] (org.x.privileged_startx) Unknown key for boolean: EnableTransactions
6/9/09 9:54:23 AM com.apple.launchd[1] (com.apple.UserEventAgent-LoginWindow[77]) Exited: Terminated
6/9/09 9:54:23 AM com.apple.launchd[72] (com.apple.AirPortBaseStationAgent) Unknown key for boolean: EnableTransactions
6/9/09 9:54:23 AM com.apple.launchd[72] (org.x.startx) Unknown key for boolean: EnableTransactions
6/9/09 9:54:30 AM [0x0-0x5005].com.wacom.TabletDriver[81] TabletDriver[81]: RunApplication called while eStopping
6/9/09 9:54:30 AM com.apple.launchd[1] ([0x0-0x5005].com.wacom.TabletDriver[81]) Exited with exit code: 255
6/9/09 9:54:35 AM com.apple.launchd[72] ([0x0-0x14014].com.linotype.FontExplorerX.Autoload[109]) Exited with exit code: 255
6/9/09 9:54:46 AM quicklookd[98] [QL ERROR] 'Creating thumbnail' timed out for '<QLThumbnailRequest /Users/das/Desktop/[soldats] Monster - 07.avi>'
6/9/09 9:54:56 AM quicklookd[122] [QL ERROR] 'Creating thumbnail' timed out for '<QLThumbnailRequest /Users/das/Desktop/[soldats] Monster - 06.avi>'
6/9/09 9:55:23 AM com.apple.SystemStarter[32] /Library/StartupItems/Tablet/Tablet: line 4: /Library/StartupItems/Tablet/TabletDriverRelauncher: No such file or directory
6/9/09 9:55:23 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/hypervisor.kext is already loaded
6/9/09 9:55:23 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/vmmain.kext is already loaded
6/9/09 9:55:23 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/ConnectUSB.kext is already loaded
6/9/09 9:55:23 AM com.apple.SystemStarter[32] kextload: extension /System/Library/Extensions/Pvsnet.kext is already loaded
6/9/09 9:55:23 AM com.apple.SystemStarter[32] kextload: /Library/StartupItems/Parallels/Pvsvnic.kext loaded successfully


From around this time I replaced the cupsd.conf file and restarted, disabled shared printing and was able to launch Parallels Desktop normally. Since then, I have not enabled shared printing.

Jun 10, 2009 12:52 AM in response to Das Chan

From what I can find on the net, the SHAuthorizationRight entry is not something to be concerned about. I did a clean install of 10.5.7 on my test Mini and found the same reference when the Mac restarted.

10/06/09 5:24:38 PM com.apple.launchd[1] (org.cups.cupsd) Unknown key: SHAuthorizationRight
10/06/09 5:24:38 PM com.apple.launchd[1] (org.ntp.ntpd) Unknown key: SHAuthorizationRight
10/06/09 5:24:38 PM com.apple.launchd[1] (org.x.privileged_startx) Unknown key for boolean: EnableTransactions
10/06/09 5:25:04 PM org.ntp.ntpd[13] Error : nodename nor servname provided, or not known

Could you try doing a Safe Boot. This should stop a number of the services mentioned in console log from starting. If you then enable sharing again and attempt to print to the iP5000, we'll then see if one of these disabled services is the culprit.

PaHu

Jun 12, 2009 12:05 AM in response to PAHU

Hi Pahu, I'm back again. Had to go outstation yesterday, and then last night and this morning there was power outage, and now trouble with internet connection again (I'm in Malaysia).

In the meantime, I removed a number of login items. No improvement. Did the safe boot. Enabled shared printing. Opened a text editor on this computer, and hit command-p. Got the spinning beachball for a while, but then after just over a minute, the printer dialog window did appear, and then did print. This was using the local usb connection to the printer.

Then I went over to the G4, opened a text editor, hit command-p, and the printer dialog window appeared. I pulled down the printer menu to look for the shared printer options, but there was none. No indication whatever of any shared printers. Tried to add printers, but only the option to add appletalk printers appeared. What happened to Bonjour?!

Same story over at the MacBook.

So back to the iMac, opened Network prefs, ran diagnostics, and it made some changes (?) to the prefs, then reported that my connection to the internet seemed to be working. Outa there.

Back to text editor, hit command-p, and got the spinning beachball again. Walked over to the G4, opened the text editor, hit command-p, which launched the printer dialog window, and this time when I pulled down the printer menu, the shared printer showed up. I selected it, and hit return. Guess what? Spinning beachball of eternity.

Forced quit. Went back to the iMac, forced the text editor to quit. Opened sharing prefs, but it would not respond, had to force quit.

Launched Disk Utility, repaired permissions. Restarted. This time not in safe mode.

Opened sharing prefs, but still not responding.

Launched Terminal, again typed "sudo cp /private/etc/cups/cupsd.conf.default /private/etc/cups/cupsd.conf" and restarted. Again, not in safe mode. Launched print&fax prefs, reset printing system. Added back the printers, disabled sharing.

Of course printing is working fine now - with the local usb connection. So I think we can rule out any of those login items that were disabled with the safe boot?

Jun 12, 2009 12:36 AM in response to Das Chan

It's certainly not sounding good. When you are in safe mode, there are going to be a number of services that don't start - wireless is one of them and probably components of the TCP/IP stack, so that would explain why there was no Bonjour.

At this stage, do you know if simply enabling printer sharing is the problem, or does it go bad when you attempt to connect from the other Macs? So,in other words, if you don't have the other Mac's turned on and you enable sharing on the main Mac, are you able to print without any major delays or crashes?

PaHu

Jun 12, 2009 1:26 AM in response to PAHU

Thank you for asking, Pahu.
I shut down the G4.
Made sure printer sharing was enabled in the iMac. Opened a text editor and hit command-p (default set to use local printer, usb connection to this computer). Result: spinning beachball. Forced quit. Opened sharing prefs, tried to disable printer sharing. Result: spinning beachball. Forced quit.

Next, I turned off Airport on the iMac.
Opened a text editor and hit command-p. Result: Immediately printer dialog window appeared, and allowed me to print without any problem. Next, opened sharing prefs: shared printing is disabled. Then, opened print&fax prefs, and was able to disable sharing.

Finally, I turned Airport back on. But not sharing printer.
Opened text editor and hit command-p. Result: printing okay.

Could it be something to do with Airport? Or modem NAT? File sharing is working between the computers. They all three show up in the LAN group on the modem. Is Bonjour working when Airport is turned off? Maybe Bonjour is screwed up?

Jun 12, 2009 4:02 AM in response to Das Chan

Good find! I don't think it is Bonjour. It probably has more to do with your TCP/IP settings, which Bonjour uses as an underlying protocol.

Are you using DHCP or have you set static addresses? Which ever it is, then try the other option. Of course, if you do try setting static addresses, then ensure each Mac has their own network address.

PaHu

Jun 19, 2009 11:45 PM in response to PAHU

Hi Pahu, and everyone else who happens across this thread. Thanks so much for your help. We had narrowed down the trouble to the TCP/IP settings, or so we thought. I could not get back to you until now, because my modem was having trouble connecting online.

Thought that was a fault on the ISP side, because they had a global outage 2 weeks ago, and since then things have been intermittent, BUT finally 2 days ago my modem could no longer connect to DSL. So I went out and bought a new one. Guess what? Shared printing is now working again as before.

So even though NAT appeared to be enabled and working with the old modem - I could see the other computers there, and file sharing was working, something went screwy with negotiating the printing.

So I am happy to report that the problem is solved. Thanks again for helping me to pin it down.

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.

Shared printing broken

Welcome to Apple Support Community
A forum where Apple customers help each other with their products. Get started with your Apple Account.