Bug: 3.64 and 3.65 drivers on Mac OS X send spurious jobs to the queue

[macfreek]

Thanks Joe, I really appreciated the continued effort you took to come up with ways forward to solve this.

Unfortunately, I missed your replies until I figured a way forward myself -- I couldn't find a way to get email notifications for new posts (I now see I can enable that with a new post).

As for the 8 minute delay, I suspect that was caused that the queue was filled with status jobs because I opened the print dialog multiple times during testing. I had a hard time to debug this issue, with some hard to reproduce results. But it seems that the root cause is now clear, so I won't pursue this any further.

For the record, I also made a bug report with Apple, as this issue started (for me and my colleagues) with an update of the Xerox print drivers by OS X recently, rdar:24606341.

[Joe Arseneau]

Can you mark your last post as the solution please?

It helps in the future when other people do a search, it will show your resolution in the results.

[macfreek · Accepted solution]

At least I've now found why these status reports are so slow. The reason is indeed a network timeout, because SNMP traffic (UDP port 161) is blocked on the network.

I run two tcpdumps, one from a netwerk where SNMP traffic was blocked, another from a network where SNMP was not blocked. In case where SNMP traffic was not blocked, the printer gave a reply and these status jobs where removed from the queue after 3-5 seconds. In case SNMP traffic was blocked, the request was send to the printer (a couple of times), but the printer did not reply. In this case, the status jobs were closed after 60 seconds, with some overhead, 2 status jobs caused 2 - 2.5 minutes delay.

[Joe Arseneau]

Odd only your location seems afflicted. I support all the USA, and have co-workers across the hall who support all Canada, and work with some guys in Belgium, your issue of 8 minutes for a print is not a thing people are seeing at all.

IPP and LPR are the vast majority of installations, RAW (HP Jet direct) has only ever really been used to combat the OSX issues in 10.6 and some 10.7 installs with the "OPC end of life" message that happened with corrupted upgrades, but still, if jobs were taking 415 times as long as a typical Windows print on OSX I would certainly have come across it immediately.

Would you be able to capture a Wireshark trace of the print between Mac and MFP?

[macfreek]

Hi Joe,

The problem is not that the print driver uses a print job to asks about it's status. The problem is that it takes 8 minutes to complete. I surely hope that is not intentional :)

Anyhow, here is my work-around (you need to be savvy with the command line):

Go to /etc/cups/ppd, and open the .ppd file of the affected printer. Mine is called "Xerox_ColorQube.ppd".

Uncomment the line with the "cupsCommands" by replacing:
     *cupsCommands: "ReportStatus com.xerox.ColorCorrections com.xerox.LDAPQuery"
With:
     *%cupsCommands: "ReportStatus com.xerox.ColorCorrections com.xerox.LDAPQuery"

(The line in your file may be slightly different. E.g., it may contain an ReportLevels entry.)

Then, restart the print services:

    sudo launchctl stop org.cups.cupsd
    sudo launchctl start org.cups.cupsd

After this change, I could print just fine again!

Regards,
Freek Dijkstra

[Joe Arseneau]

An unrelated addition:

You will get better print results via LPD than on Jet direct.

If the 93xx is running on Connectkey firmware, set the DNS timeout to 1 second instead of the default 5 (Connectkey does a DNS lookup of the sender, so the print job gets delayed during submission if the DNS timeout is large.

[Joe Arseneau]

It isn't really a bug, it is intentional....

When printing from newer Mac OS's 10.7 and up, a user will see additional print jobs appear in the Mac queue. This occurs when printing locally from a Mac or when printing from a shared queue.

 The print driver is working to meet new Apple OS design requirements.

As part of ongoing security measures, Apple operating systems starting in 10.6 prevent any application that does not need network access to complete its "work" from having network access. This includes print drivers inside of  applications. All print drivers (Xerox and Competitors) are bound by the same rules and no longer have access to direct network communication. Xerox uses the "Printer Status job" as their way to meet this security requirement and still be able to gather the necessary device information. If the job is titled "Supply Levels" this job is created by the Mac OS and is required to capture Toner Levels.

Not every manufacturer is using the same method, EFI for instance installs a Daemon that runs in the background on its own to do communications to the printer, and because the Daemon is local, it can live update the PPD/driver that is called from within the application.

I'm sure in the future a better method will be used, but for now, it is what it is, you either have a full featured driver that knows the status of the printer and get a few small jobs that cause a tiny delay, or you have a driver that never knows what the status of the printer is.

And before anyone asks, i am not a developer/coder etc etc. This information just came down the line, any inaccuracies are likely mine due to incomplete understanding/ or in trying to bring it down to layman's terms I lost an element.

[macfreek]

On my new laptop, with either Xerox Print drivers 3.64.0 or 3.65.3, I have the following problem.

When opening a Print Dialog, CUPS queues two print jobs of 1024 each. None of them seem actual print jobs, and if they are followed by an actual print job, it takes a time-out of these spurious print job before the actual print job is send to the printer.

Steps to Reproduce:
1. Configure a Xerox printer, e.g. the ColorQube 9302.
2. Open any application, e.g. TextEdit.
3. Open the print dialog using the File > Print menu item. Do nothing else yet.
4. In a terminal, observe with `lpstat -o` that there are two print jobs already in the queue.
5. Optionally, cancel the print dialog.

Expected Results:
I expected that only a "Print" command would send a print job to the printer.

Actual Results:
Even if just a print dialog is opened, two print jobs already populate in the queue. If a document is actually printed, that would be the third job in the queue.

Configuration:

This has been tested with a Xerox ColorCube 9302. The printer is configured to use it's fixed IPv4 address, and using the HP Jetdirect - Socket protocol.

The problem has been reproduced on OS X.10.5 with Xerox printer software 3.64.0, OS X.10.5 with Xerox printer software 4.65.3, and OS X.11.1 with Xerox printer software 3.65.3.

Notes:
I suspect that the actual bug is in the Xerox print driver, and that while opening the Print dialog, it asks for the status of the printer. However, that status request is somehow interpreted as a print job by CUPS. The spurious jobs always have a size of 1024 bytes, regardless of the actual print job (which is typically much larger).

Workaround:
As a work-around, it is each enough to kill the spurious jobs in the terminal using `lprm`. On OS X.10, these two jobs are not shown in the printer GUI dialog. On OS X.11, on another machine, these two jobs are shown in the printer GUI dialog.