MacOS X cgpdftoxxx filters failing to read their own tmp files???

[Kaelin Colclasure]

I am trying to insert a filter that conditionally makes a copy of the PDF data rendered during the printing process on Mac OS X (10.7.4) so it can do some additional post-processing.

As far as I can tell, my filter (/usr/libexec/cups/filter/prox4pdf) is behaving according to the rules, and indeed it succeeds in creating copies of the PDF data when it should. BUT, when my filter is installed, the system cgpdftoxxx (e.g. cgpdftoraster) filters (which are the next filters in line) fail.

They log that they are "copying to temp print file XXX", then after my filter exits successfully, the cgpdftoxxx filter logs that it "can't open XXX". This happens wether my filter creates its own temp file in /private/var/spool/cups/tmp/ or not. (In either case, my filter dutifully copies the print job file from argv[6] or stdin to stdout unmodified.)

When I examine the tmp dir I see no sign of the temp file XXX logged by the system filter. What am I doing that's derailing the process?

Here are the prox.convs rules I use to insert my filter:
---8<---
application/pdf                 application/prox.pdf            1       prox4pdf

application/prox.pdf            application/postscript          23      cgpdftops
application/prox.pdf            application/vnd.cups-raster     98      cgpdftoraster
--->8---

The costs are chosen to make my rules preferred over the system defaults in apple.convs. I also define the application/prox.pdf type in prox.types.

Finally, here is an example of the debug output logged when I submit a job with my filter in place (in this case just passing the data through, not making a copy):
---8<---
I [29/Aug/2012:16:54:19 -0700] [Job 68] Started filter /usr/libexec/cups/filter/cgtexttopdf (PID 2110)
I [29/Aug/2012:16:54:19 -0700] [Job 68] Started filter /usr/libexec/cups/filter/prox4pdf (PID 2111)
I [29/Aug/2012:16:54:19 -0700] [Job 68] Started filter /usr/libexec/cups/filter/cgpdftoraster (PID 2112)
I [29/Aug/2012:16:54:19 -0700] [Job 68] Started filter /Library/Printers/Samsung/Filters/rastertosec (PID 2113)
I [29/Aug/2012:16:54:19 -0700] [Job 68] Started backend /usr/libexec/cups/backend/usb (PID 2114)
D [29/Aug/2012:16:54:19 -0700] Discarding unused job-state-changed event...
D [29/Aug/2012:16:54:19 -0700] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/Samsung_ML_2160_Series) from localhost
D [29/Aug/2012:16:54:19 -0700] cupsdAcceptClient: 19 from localhost (Domain)
D [29/Aug/2012:16:54:19 -0700] cupsdReadClient: 19 POST / HTTP/1.1
D [29/Aug/2012:16:54:19 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [29/Aug/2012:16:54:19 -0700] cupsdAuthorize: No authentication data provided.
D [29/Aug/2012:16:54:19 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [29/Aug/2012:16:54:19 -0700] cupsdReadClient: 19 1.1 Get-Jobs 1
D [29/Aug/2012:16:54:19 -0700] Get-Jobs ipp://localhost:631/printers/test_81059_local_
D [29/Aug/2012:16:54:19 -0700] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/test_81059_local_) from localhost
D [29/Aug/2012:16:54:19 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [29/Aug/2012:16:54:19 -0700] cupsdReadClient: 19 WAITING Closing on EOF
D [29/Aug/2012:16:54:19 -0700] cupsdCloseClient: 19
D [29/Aug/2012:16:54:19 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Aug/2012:16:54:19 -0700] cupsdReadClient: 17 WAITING Closing on EOF
D [29/Aug/2012:16:54:19 -0700] cupsdCloseClient: 17
D [29/Aug/2012:16:54:19 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Aug/2012:16:54:19 -0700] [Job 68] Page = 612x792; 12,12 to 600,780
D [29/Aug/2012:16:54:19 -0700] [Job 68] usb: AppleLanguages="en-US"
D [29/Aug/2012:16:54:19 -0700] [Job 68] STATE: +connecting-to-device
D [29/Aug/2012:16:54:19 -0700] [Job 68] Looking for 'Samsung ML-2160 Series'
D [29/Aug/2012:16:54:19 -0700] Discarding unused printer-state-changed event...
D [29/Aug/2012:16:54:19 -0700] [Job 68] cgpdftoraster - copying to temp print file "/private/var/spool/cups/tmp/008405047227d"
D [29/Aug/2012:16:54:19 -0700] [Job 68] load_classdriver(/System/Library/Printers/Libraries/USBGenericPrintingClass.plugin) (kr:0x00000000)
D [29/Aug/2012:16:54:19 -0700] [Job 68] load_classdriver(/System/Library/Printers/Libraries/USBGenericPrintingClass.plugin) (kr:0x00000000)
D [29/Aug/2012:16:54:19 -0700] [Job 68] No italic font!
D [29/Aug/2012:16:54:19 -0700] [Job 68] No bold-italic font!
D [29/Aug/2012:16:54:19 -0700] [Job 68] No bold font!
D [29/Aug/2012:16:54:19 -0700] PID 2110 (/usr/libexec/cups/filter/cgtexttopdf) exited with no errors.
D [29/Aug/2012:16:54:19 -0700] PID 2111 (/usr/libexec/cups/filter/prox4pdf) exited with no errors.
E [29/Aug/2012:16:54:19 -0700] [Job 68] can't open `/private/var/spool/cups/tmp/008405047227d'.
D [29/Aug/2012:16:54:19 -0700] [Job 68] Set job-printer-state-message to "can't open `/private/var/spool/cups/tmp/008405047227d'.", current level=ERROR
D [29/Aug/2012:16:54:19 -0700] Discarding unused job-progress event...
D [29/Aug/2012:16:54:19 -0700] Discarding unused printer-state-changed event...
D [29/Aug/2012:16:54:19 -0700] PID 2112 (/usr/libexec/cups/filter/cgpdftoraster) stopped with status 3.
E [29/Aug/2012:16:54:19 -0700] [Job 68] No pages found!
--->8---

Any suggestions?

-- Kaelin