[cups] Attempt printing CUPS jobs to ImageWriter II on Mac OS Catalina
St T
stlearn3 at gmail.com
Thu Oct 8 22:36:02 PDT 2020
I appreciate the help this group has provided others and thought I would
try the same.
GOAL:
Use CUPS v2.3.1 on Mac OS Catalina and print jobs to Apple Imagewriter II.
ENVIRONMENT SETUP:
1/ MacBook Operating System: macOS X Catalina 10.15.7
2/ MacOS CUPS Version Number: 2.3.1 (web admin enabled and accessible
localhost:631)
3/ Local Printer Connection Path: macbook usb port to Keyspan serial
adapter to apple printer
MacBook Air USB port --> USB:Serial adapter (Tripp Lite Keyspan USH-19) -->
DE9:DIN8 converter cable --> Apple ImageWriter II DIN-8 port
4/ Installed USB to Serial adapter driver: KeyspanUSADriver v4.0
(installed, loaded, showing up in /Extensions and lpinfo as
usb:/dev/usb/KeySerial1)
5/ installed GhostScript v8.71
6/ installed Linux Foundation foomatic-rip v4.06
7/ PPD file: downloaded from http://www.openprinting.org/driver/iwhi (Apple
ImageWriter II) and copied gz version to
/Extensions/Printers/PPDs/Content/Resources
8/ Backend: CoolTerm app (select usb:/dev/usb/KeySerial1 and Connect
9600:N:8:1)
9/ CUPS printer status:
Name: IW2
Driver: Apple ImageWriter II Foomatic /iwhi (recommended) (color)
Connection: usb: /dev/cu.KeySerial1
Defaults: job-sheets=none, non media=na_letter_8.5x11in sides=one-sided
10/ CUPS updated cupsd.conf to LogLevel debug2 and PreserveJobFiles On
11/ Try and print from Mac OS TextEdit or CUPS web admin interface
PROBLEM:
The print job does not complete. In the CUPS web admin interface the Jobs
status update shows:
"process since Thu Oct 8 22:24:47 2020 "Filter Failed"
For additional information, I looked at the cups log_error output (sorry
for the high number of timestamp log entries) and noticed several EOF
processing errors but I am not certain where I should continue my
investigation.
D [08/Oct/2020:21:34:54 -0700] [Client 16] con->http=0x7fee13013a00
D [08/Oct/2020:21:34:54 -0700] [Client 16] cupsdWriteClient error=0,
used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH,
data_remaining=355, response=0x7fee1251d910(IPP_STATE_DATA), pipe_pid=0,
file=-1
D [08/Oct/2020:21:34:54 -0700] [Client 16] Writing IPP response,
ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [08/Oct/2020:21:34:54 -0700] [Client 16] bytes=0, http_state=0,
data_remaining=355
D [08/Oct/2020:21:34:54 -0700] [Client 16] Flushing write buffer.
D [08/Oct/2020:21:34:54 -0700] [Client 16] New state is HTTP_STATE_WAITING
d [08/Oct/2020:21:34:54 -0700] cupsdAddSelect(fd=15, read_cb=0x10275fcbd,
write_cb=0x0, data=0x7fee1300d800)
D [08/Oct/2020:21:34:54 -0700] [Client 16] Waiting for request.
D [08/Oct/2020:21:34:54 -0700] cupsdSetBusyState: newbusy="Active clients
and dirty files", busy="Active clients and dirty files"
d [08/Oct/2020:21:34:54 -0700] select_timeout: JobHistoryUpdate=2147483647
d [08/Oct/2020:21:34:54 -0700] [Client 17] cupsdReadClient: error=0,
used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH,
data_remaining=0, request=0x0(), file=-1
D [08/Oct/2020:21:34:54 -0700] [Client 17] GET /cups.css HTTP/1.1
D [08/Oct/2020:21:34:54 -0700] cupsdSetBusyState: newbusy="Active clients
and dirty files", busy="Active clients and dirty files"
D [08/Oct/2020:21:34:54 -0700] [Client 17] Read: status=200, state=3
d [08/Oct/2020:21:34:54 -0700] cupsdFindBest: uri="/cups.css", limit=2...
d [08/Oct/2020:21:34:54 -0700] cupsdFindBest: Location /admin/log(10) Limit
7f
d [08/Oct/2020:21:34:54 -0700] cupsdFindBest: Location /admin/conf(11)
Limit 7f
d [08/Oct/2020:21:34:54 -0700] cupsdFindBest: Location /admin(6) Limit 7f
d [08/Oct/2020:21:34:54 -0700] cupsdFindBest: Location /(1) Limit 7f
d [08/Oct/2020:21:34:54 -0700] cupsdFindBest: best=/
d [08/Oct/2020:21:34:54 -0700] [Client 17] con->uri="/cups.css",
con->best=0x7fee125041d0(/)
D [08/Oct/2020:21:34:54 -0700] [Client 17] No authentication data provided.
d [08/Oct/2020:21:34:54 -0700] cupsdIsAuthorized: con->uri="/cups.css",
con->best=0x7fee125041d0(/)
d [08/Oct/2020:21:34:54 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON,
type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [08/Oct/2020:21:34:54 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [08/Oct/2020:21:34:54 -0700] [Client 17] Processing GET /cups.css
d [08/Oct/2020:21:34:54 -0700] [Client 17] get_file:
filestats=0x7ffeed498760, filename=0x7ffeed498b60, len=1024, returning
"/usr/share/doc/cups/cups.css".
D [08/Oct/2020:21:34:54 -0700] [Client 17]
filename="/usr/share/doc/cups/cups.css", type=text/css
d [08/Oct/2020:21:34:54 -0700] [Client 17] is_cgi:
filename="/usr/share/doc/cups/cups.css", filestats=0x7ffeed498760,
type=text/css, returning 0.
d [08/Oct/2020:21:34:54 -0700] [Client 17] check_if_modified:
filestats=0x7ffeed498760(11092, 1569468623)) If-Modified-Since="Thu, 26 Sep
2019 03:30:23 GMT"
d [08/Oct/2020:21:34:54 -0700] [Client 17] cupsdSendError code=304,
auth_type=0
D [08/Oct/2020:21:34:54 -0700] [Client 17] cupsdSendHeader: code=304,
type="(null)", auth_type=0
D [08/Oct/2020:21:34:54 -0700] cupsdSetBusyState: newbusy="Active clients
and dirty files", busy="Active clients and dirty files"
d [08/Oct/2020:21:34:54 -0700] select_timeout: JobHistoryUpdate=2147483647
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiClearVariables called.
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable: SECTION=\"printers\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable: TOTAL=\"1\"
d [08/Oct/2020:21:34:54 -0700] [CGI]
cgiSetIPPObjectVars(obj=0x7fdfc7604440, prefix=\"(null)\", element=0)
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable:
SERVER_NAME=\"localhost\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable: REMOTE_USER=\"st\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS
v2.3.1\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray:
job_printer_name[0]=\"iw2\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray:
job_printer_uri[0]=\"/printers/iw2\"
d [08/Oct/2020:21:34:54 -0700] [CGI] job_printer_uri[0]=\"/printers/iw2\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray:
time_at_completed[0]=\"novalue\"
d [08/Oct/2020:21:34:54 -0700] [CGI] time_at_completed[0]=\"novalue\"
d [08/Oct/2020:21:34:54 -0700] select_timeout: JobHistoryUpdate=2147483647
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray: time_at_creation[0]=\"Thu
Oct 8 21:34:52 2020\"
d [08/Oct/2020:21:34:54 -0700] [CGI] time_at_creation[0]=\"Thu Oct 8
21:34:52 2020\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray:
time_at_processing[0]=\"Thu Oct 8 21:34:52 2020\"
d [08/Oct/2020:21:34:54 -0700] [CGI] time_at_processing[0]=\"Thu Oct 8
21:34:52 2020\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray: job_id[0]=\"11\"
d [08/Oct/2020:21:34:54 -0700] [CGI] job_id[0]=\"11\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray: job_state[0]=\"5\"
d [08/Oct/2020:21:34:54 -0700] [CGI] job_state[0]=\"5\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray:
job_impressions_completed[0]=\"0\"
d [08/Oct/2020:21:34:54 -0700] [CGI] job_impressions_completed[0]=\"0\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
d [08/Oct/2020:21:34:54 -0700] [CGI] job_k_octets[0]=\"1\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray:
job_hold_until[0]=\"no-hold\"
d [08/Oct/2020:21:34:54 -0700] [CGI] job_hold_until[0]=\"no-hold\"
d [08/Oct/2020:21:34:54 -0700] select_timeout: JobHistoryUpdate=2147483647
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetArray:
job_printer_state_message[0]=\"Filter failed\"
d [08/Oct/2020:21:34:54 -0700] [CGI] job_printer_state_message[0]=\"Filter
failed\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable: PRINTER_NAME=\"iw2\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable:
PRINTER_URI_SUPPORTED=\"/printers/iw2\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable:
THISURL=\"/printers/iw2\"
D [08/Oct/2020:21:34:54 -0700] [CGI] cgiSetVariable: SEARCH_DEST=\"iw2\"
d [08/Oct/2020:21:34:54 -0700] [CGI]
cgiCopyTemplateLang(tmpl=\"search.tmpl\")
d [08/Oct/2020:21:34:54 -0700] [CGI] lang=\"en_US.UTF8\",
locale=\"/en_US\"...
d [08/Oct/2020:21:34:54 -0700] [CGI] Template file is
\"/usr/share/cups/templates/search.tmpl\"...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 0...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{SECTION}\" at 24...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{?SEARCH_DEST}\" at 39...
d [08/Oct/2020:21:34:54 -0700] select_timeout: JobHistoryUpdate=2147483647
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{WHICH_JOBS?\" at 67,
result=0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 67...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{WHICH_JOBS}\" at 125...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 128 on
character \':\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Output second part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 128...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 129 on
character \'}\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Finished \"{WHICH_JOBS?\",
out=0x7fff97850e28...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{ORDER?\" at 137,
result=0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 137...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{ORDER}\" at 185...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 188 on
character \':\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Output second part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 188...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 189 on
character \'}\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Finished \"{ORDER?\",
out=0x7fff97850e28...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{SEARCH_DEST?\" at 235,
result=1...
d [08/Oct/2020:21:34:54 -0700] [CGI] Output first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 235...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{SEARCH_DEST}\" at 248...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 249 on
character \':\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip second part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 249...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{SECTION=classes\" at 266,
result=0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 266...
d [08/Oct/2020:21:34:54 -0700] [Client 14] write_pipe: CGI output on fd 14.
d [08/Oct/2020:21:34:54 -0700] cupsdRemoveSelect(fd=14)
d [08/Oct/2020:21:34:54 -0700] cupsdAddSelect(fd=12, read_cb=0x0,
write_cb=0x102764a7a, data=0x7fee1400ea00)
D [08/Oct/2020:21:34:54 -0700] [Client 14] CGI data ready to be sent.
d [08/Oct/2020:21:34:54 -0700] select_timeout: JobHistoryUpdate=2147483647
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 274 on
character \':\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Output second part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 274...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{SECTION=jobs\" at 288,
result=0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 288...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 293 on
character \':\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Output second part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 293...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 302 on
character \'}\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Finished \"{SECTION=jobs\", out=0x0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 303 on
character \'}\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Finished \"{SECTION=classes\",
out=0x0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 304 on
character \'}\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Finished \"{SEARCH_DEST?\",
out=0x7fff97850e28...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{?QUERY}\" at 359...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{SECTION}\" at 415...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 530 on
EOF...
d [08/Oct/2020:21:34:54 -0700] [CGI]
cgiCopyTemplateLang(tmpl=\"jobs-header.tmpl\")
d [08/Oct/2020:21:34:54 -0700] [CGI] lang=\"en_US.UTF8\",
locale=\"/en_US\"...
d [08/Oct/2020:21:34:54 -0700] [CGI] Template file is
\"/usr/share/cups/templates/jobs-header.tmpl\"...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{?which_jobs=\" at 14,
result=1...
d [08/Oct/2020:21:34:54 -0700] [CGI] Output first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 14...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 15 on
character \':\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip second part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 15...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{?printer_name=\" at 45,
result=0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 45...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 51 on
character \':\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Output second part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 51...
d [08/Oct/2020:21:34:54 -0700] [CGI] \"{printer_uri_supported}\" at 74...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 75 on
character \'}\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Finished \"{?printer_name=\",
out=0x0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Returning at file position 144 on
character \'}\'...
d [08/Oct/2020:21:34:54 -0700] [CGI] Finished \"{?which_jobs=\",
out=0x7fff97850e28...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting \"{?which_jobs=completed\" at
168, result=0...
d [08/Oct/2020:21:34:54 -0700] [CGI] Skip first part...
d [08/Oct/2020:21:34:54 -0700] [CGI] Starting at file position 168...
D [08/Oct/2020:21:34:54 -0700] [Client 14] con->http=0x7fee14017a00
D [08/Oct/2020:21:34:54 -0700] [Client 14] cupsdWriteClient error=0,
used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED,
data_remaining=0, response=0x0(), pipe_pid=731, file=14
d [08/Oct/2020:21:34:54 -0700] cupsdAddSelect(fd=14, read_cb=0x10276492a,
write_cb=0x0, data=0x7fee1400ea00)
D [08/Oct/2020:21:34:54 -0700] [Client 14] Waiting for CGI data.
Thank you!
ST
More information about the cups
mailing list