[cups.general] [Q] What might cause Windows to Mac OS Epson printing to just give up?

Maurice Volaski mvolaski at aecom.yu.edu
Thu Jan 3 15:04:15 PST 2008


I am trying to print to an Epson Stylus C88 from Windows XP to a Mac 
running OS 10.4.11. The job never prints. The Mac itself prints fine 
to this printer. The Windows box has printed to this Epson before 
when it was connected directly. All other networking connectivity 
from the Windows box are in working order. The Windows box is using a 
standard Stylus C88 driver. Below is a portion of the cups debug2 
log, starting with its being started. The job is then sent and by the 
end, the XP box seems to think there was a communication error and 
gives up.

I [03/Jan/2008:17:16:33 -0500] Listening to 0:631
I [03/Jan/2008:17:16:33 -0500] Listening to 3010e0:0
D [03/Jan/2008:17:16:33 -0500] AddLocation: added location 
'CUPS_INTERNAL_BROWSE_ACL'
D [03/Jan/2008:17:16:33 -0500] AllowIP: CUPS_INTERNAL_BROWSE_ACL 
allow 7f000001/ffffffff
D [03/Jan/2008:17:16:33 -0500] AllowHost: CUPS_INTERNAL_BROWSE_ACL allow @LOCAL
D [03/Jan/2008:17:16:33 -0500] AllowIP: CUPS_INTERNAL_BROWSE_ACL 
allow 81625aab/ffffffff
D [03/Jan/2008:17:16:33 -0500] DenyIP: CUPS_INTERNAL_BROWSE_ACL deny 
00000000/00000000
D [03/Jan/2008:17:16:33 -0500] AddLocation: added location '/'
D [03/Jan/2008:17:16:33 -0500] DenyIP: / deny 00000000/00000000
D [03/Jan/2008:17:16:33 -0500] AllowIP: / allow 7f000001/ffffffff
D [03/Jan/2008:17:16:33 -0500] AllowHost: / allow @LOCAL
D [03/Jan/2008:17:16:33 -0500] AllowIP: / allow 81625aab/ffffffff
D [03/Jan/2008:17:16:33 -0500] AddLocation: added location '/admin'
D [03/Jan/2008:17:16:33 -0500] DenyIP: /admin deny 00000000/00000000
D [03/Jan/2008:17:16:33 -0500] AllowIP: /admin allow 7f000001/ffffffff
D [03/Jan/2008:17:16:33 -0500] AddLocation: added location '/admin'
D [03/Jan/2008:17:16:33 -0500] AddLocation: added location 
'/admin/conf/cupsd.conf'
D [03/Jan/2008:17:16:33 -0500] DenyIP: /admin/conf/cupsd.conf deny 
00000000/00000000
D [03/Jan/2008:17:16:33 -0500] AllowIP: /admin/conf/cupsd.conf allow 
7f000001/ffffffff
D [03/Jan/2008:17:16:33 -0500] AddLocation: added location 
'/admin/conf/cupsd.conf'
I [03/Jan/2008:17:16:33 -0500] Loaded configuration file 
"/private/etc/cups/cupsd.conf"
D [03/Jan/2008:17:16:33 -0500] Cleaning out old temporary files in 
"/private/var/spool/cups/tmp"...
I [03/Jan/2008:17:16:33 -0500] Configured for up to 100 clients.
I [03/Jan/2008:17:16:33 -0500] Allowing up to 100 client connections per host.
I [03/Jan/2008:17:16:33 -0500] Full reload is required.
D [03/Jan/2008:17:16:33 -0500] LoadAllPrinters: Loading printer Stylus_C88...
d [03/Jan/2008:17:16:33 -0500] AddPrinter("Stylus_C88")
d [03/Jan/2008:17:16:33 -0500] Adding filter application/vnd.cups-raw 
printer/Stylus_C88 0 -
d [03/Jan/2008:17:16:33 -0500] FindBest: uri = "/printers/Stylus_C88"...
d [03/Jan/2008:17:16:33 -0500] FindBest: Location 
CUPS_INTERNAL_BROWSE_ACL Limit 0
d [03/Jan/2008:17:16:33 -0500] FindBest: Location / Limit 7f
d [03/Jan/2008:17:16:33 -0500] FindBest: Location /admin Limit 5d
d [03/Jan/2008:17:16:33 -0500] FindBest: Location /admin Limit 22
d [03/Jan/2008:17:16:33 -0500] FindBest: Location 
/admin/conf/cupsd.conf Limit 5f
d [03/Jan/2008:17:16:33 -0500] FindBest: Location 
/admin/conf/cupsd.conf Limit 20
d [03/Jan/2008:17:16:33 -0500] FindBest: best = "/"
d [03/Jan/2008:17:16:33 -0500] Adding filter application/pdf 
printer/Stylus_C88 0 
/System/Library/Printers/Libraries/PrintJobMgr/Contents/MacOS/PrintJobMgr
D [03/Jan/2008:17:16:33 -0500] dnssdRegisterPrinter(Stylus_C88) new
d [03/Jan/2008:17:16:33 -0500] dnssdRegisterCallback: Adding fd 2 to 
InputSet...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "bluetooth"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "fax"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "firewire"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "http"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "ipp"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "lpd"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "mdns"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "pap"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "pdf"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "smb"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "socket"...
D [03/Jan/2008:17:16:33 -0500] LoadDevices: Compatibility device "usb"...
D [03/Jan/2008:17:16:33 -0500] LoadJobs: Scanning /private/var/spool/cups...
I [03/Jan/2008:17:16:33 -0500] Full reload complete.
D [03/Jan/2008:17:16:34 -0500] StartListening: NumListeners=2
D [03/Jan/2008:17:16:34 -0500] StartListening: address=00000000 port=631
D [03/Jan/2008:17:16:34 -0500] StartListening: domain 
socket=/private/var/run/cupsd
D [03/Jan/2008:17:16:34 -0500] ResumeListening: setting input bits...
d [03/Jan/2008:17:16:34 -0500] ResumeListening: Adding fd 0 to InputSet...
d [03/Jan/2008:17:16:34 -0500] ResumeListening: Adding fd 12 to InputSet...
d [03/Jan/2008:17:16:34 -0500] StartBrowsing: Adding fd 14 to InputSet...
D [03/Jan/2008:17:16:34 -0500] dnssdRegisterPrinter(Stylus_C88) update
d [03/Jan/2008:17:16:34 -0500] StartServer: Adding fd 15 to InputSet...
d [03/Jan/2008:17:16:34 -0500] AddCert: adding certificate for pid 0
d [03/Jan/2008:17:16:34 -0500] StartServer: Adding fd 17 to InputSet...
D [03/Jan/2008:17:16:35 -0500] dnssdRegisterCallback(Stylus C88 @ 
reeber, _ipp._tcp.)
d [03/Jan/2008:17:16:35 -0500] SendBrowseList: (102 bytes to "en0") 
9006 3 ipp://reeber.aecom.yu.edu:631/printers/Stylus_C88 "reeber" 
"Stylus C88" "EPSON C88 Series (1)"
d [03/Jan/2008:17:16:35 -0500] UpdateCUPSBrowse: (102 bytes from 
129.98.91.112) 9006 3 
ipp://reeber.aecom.yu.edu:631/printers/Stylus_C88 "reeber" "Stylus 
C88" "EPSON C88 Series (1)"
d [03/Jan/2008:17:16:36 -0500] select_timeout: 30 seconds to send browse update
d [03/Jan/2008:17:16:36 -0500] AcceptClient(lis=0x301100) 0 NumClients = 0
D [03/Jan/2008:17:16:36 -0500] AcceptClient: 19 from 129.98.90.171:631.
d [03/Jan/2008:17:16:36 -0500] AcceptClient: Adding fd 19 to InputSet...
d [03/Jan/2008:17:16:36 -0500] ReadClient: 19, used=0, file=-1
D [03/Jan/2008:17:16:36 -0500] ReadClient: 19 POST 
/printers/Stylus_C88 HTTP/1.1
d [03/Jan/2008:17:16:36 -0500] decode_auth(0x1817a00): Authorization 
string = ""
d [03/Jan/2008:17:16:36 -0500] decode_auth: 19 username=""
d [03/Jan/2008:17:16:36 -0500] IsAuthorized: con->uri = "/printers/Stylus_C88"
d [03/Jan/2008:17:16:36 -0500] FindBest: uri = "/printers/Stylus_C88"...
d [03/Jan/2008:17:16:36 -0500] FindBest: Location 
CUPS_INTERNAL_BROWSE_ACL Limit 0
d [03/Jan/2008:17:16:36 -0500] FindBest: Location / Limit 7f
d [03/Jan/2008:17:16:36 -0500] FindBest: Location /admin Limit 5d
d [03/Jan/2008:17:16:36 -0500] FindBest: Location /admin Limit 22
d [03/Jan/2008:17:16:36 -0500] FindBest: Location 
/admin/conf/cupsd.conf Limit 5f
d [03/Jan/2008:17:16:36 -0500] FindBest: Location 
/admin/conf/cupsd.conf Limit 20
d [03/Jan/2008:17:16:36 -0500] FindBest: best = "/"
d [03/Jan/2008:17:16:36 -0500] IsAuthorized: auth = 0, satisfy=0...
d [03/Jan/2008:17:16:36 -0500] POST /printers/Stylus_C88
d [03/Jan/2008:17:16:36 -0500] CONTENT_TYPE = application/ipp
d [03/Jan/2008:17:16:36 -0500] ReadClient() 19 con->data_encoding = 
length, con->data_remaining = 141, con->file = -1
d [03/Jan/2008:17:16:36 -0500] ProcessIPPRequest(0x1817a00[19]): 
operation_id = 000b
d [03/Jan/2008:17:16:36 -0500] ProcessIPPRequest: 
URI="http://reeber.aecom.yu.edu:631/printers/Stylus_C88"
d [03/Jan/2008:17:16:36 -0500] get_printer_attrs(0x1817a00[19], 
http://reeber.aecom.yu.edu:631/printers/Stylus_C88)
d [03/Jan/2008:17:16:36 -0500] 
add_printer_state_reasons(0x1817a00[19], 0x1800a00[Stylus_C88])
d [03/Jan/2008:17:16:36 -0500] add_queued_job_count(0x1817a00[19], 
0x1800a00[Stylus_C88])
[various lines removed]
[various ReadClient lines]
d [03/Jan/2008:17:17:11 -0500] ReadClient() 19 Closing data file 22, 
size = 619913.
d [03/Jan/2008:17:17:11 -0500] ProcessIPPRequest(0x1817a00[19]): 
operation_id = 0002
d [03/Jan/2008:17:17:11 -0500] ProcessIPPRequest: 
URI="http://reeber.aecom.yu.edu:631/printers/Stylus_C88"
d [03/Jan/2008:17:17:11 -0500] print_job(0x1817a00[19], 
http://reeber.aecom.yu.edu:631/printers/Stylus_C88)
D [03/Jan/2008:17:17:11 -0500] print_job: auto-typing file...
D [03/Jan/2008:17:17:11 -0500] print_job: request file type is 
application/octet-stream.
d [03/Jan/2008:17:17:11 -0500] check_quotas(0x1817a00[19], 
0x1800a00[Stylus_C88])
D [03/Jan/2008:17:17:11 -0500] check_quotas: requesting-user-name = 
'Arlene Bravo'
D [03/Jan/2008:17:17:11 -0500] print_job: requesting-user-name = 'Arlene Bravo'
D [03/Jan/2008:17:17:11 -0500] Adding default job-sheets values "none,none"...
I [03/Jan/2008:17:17:11 -0500] Adding start banner page "none" to job 11.
d [03/Jan/2008:17:17:11 -0500] copy_banner(0x1817a00[19], 0x314730[11], none)
d [03/Jan/2008:17:17:11 -0500] add_file(con=0x1817a00[19], job=11, 
filetype=application/octet-stream, compression=0)
I [03/Jan/2008:17:17:11 -0500] Adding end banner page "none" to job 11.
d [03/Jan/2008:17:17:11 -0500] copy_banner(0x1817a00[19], 0x314730[11], none)
I [03/Jan/2008:17:17:11 -0500] Job 11 queued on 'Stylus_C88' by 'Arlene Bravo'.
D [03/Jan/2008:17:17:11 -0500] Job 11 hold_until = 0
d [03/Jan/2008:17:17:11 -0500] SaveJob: Closing file 22...
D [03/Jan/2008:17:17:11 -0500] StartJob(11, 0x1800a00)
D [03/Jan/2008:17:17:11 -0500] StartJob() id = 11, file = 0/1
D [03/Jan/2008:17:17:11 -0500] dnssdRegisterPrinter(Stylus_C88) update
D [03/Jan/2008:17:17:11 -0500] job-sheets=none,none
D [03/Jan/2008:17:17:11 -0500] banner_page = 0
D [03/Jan/2008:17:17:11 -0500] StartJob: argv = 
"Stylus_C88","11","Arlene Bravo","Mozilla Firefox Start 
Page","1","","/private/var/spool/cups/d00011-001"
D [03/Jan/2008:17:17:11 -0500] StartJob: 
envp[0]="PATH=/usr/libexec/cups/filter:/bin:/usr/bin"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[2]="USER=root"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[3]="CHARSET=utf-8"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[4]="LANG=en_US"
D [03/Jan/2008:17:17:11 -0500] StartJob: 
envp[5]="PPD=/private/etc/cups/ppd/Stylus_C88.ppd"
D [03/Jan/2008:17:17:11 -0500] StartJob: 
envp[6]="CUPS_SERVERROOT=/private/etc/cups"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [03/Jan/2008:17:17:11 -0500] StartJob: 
envp[8]="TMPDIR=/private/var/spool/cups/tmp"
D [03/Jan/2008:17:17:11 -0500] StartJob: 
envp[9]="CONTENT_TYPE=application/octet-stream"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[10]="DEVICE_URI=file:///dev/null"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[11]="PRINTER=Stylus_C88"
D [03/Jan/2008:17:17:11 -0500] StartJob: 
envp[12]="CUPS_DATADIR=/usr/share/cups"
D [03/Jan/2008:17:17:11 -0500] StartJob: 
envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[14]="CUPS_SERVER=localhost"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[15]="IPP_PORT=631"
D [03/Jan/2008:17:17:11 -0500] StartJob: envp[16]="<CFProcessPath>"
d [03/Jan/2008:17:17:11 -0500] StartJob: Allocating status buffer...
D [03/Jan/2008:17:17:11 -0500] StartJob: statusfds = [ 22 23 ]
D [03/Jan/2008:17:17:11 -0500] StartJob: filterfds[1] = [ 24 -1 ]
d [03/Jan/2008:17:17:11 -0500] StartJob: Adding fd 22 to InputSet...
d [03/Jan/2008:17:17:11 -0500] add_job_state_reasons(0x1817a00[19], 11)
D [03/Jan/2008:17:17:11 -0500] ProcessIPPRequest: 19 status_code=0
d [03/Jan/2008:17:17:12 -0500] ProcessIPPRequest: Adding fd 19 to OutputSet...
d [03/Jan/2008:17:17:12 -0500] SendBrowseList: (102 bytes to "en0") 
9006 4 ipp://reeber.aecom.yu.edu:631/printers/Stylus_C88 "reeber" 
"Stylus C88" "EPSON C88 Series (1)"
D [03/Jan/2008:17:17:12 -0500] UpdateJob: job 11, file 0 is complete.
d [03/Jan/2008:17:17:12 -0500] UpdateJob: Removing fd 22 from InputSet...
D [03/Jan/2008:17:17:12 -0500] CancelJob: id = 11
D [03/Jan/2008:17:17:12 -0500] StopJob: id = 11, force = 0
D [03/Jan/2008:17:17:12 -0500] dnssdRegisterPrinter(Stylus_C88) update
D [03/Jan/2008:17:17:12 -0500] StopJob: printer state is 3
d [03/Jan/2008:17:17:12 -0500] StopJob: Freeing status buffer...
d [03/Jan/2008:17:17:12 -0500] SaveJob: Closing file 22...
d [03/Jan/2008:17:17:12 -0500] SaveJob: Closing file 22...
d [03/Jan/2008:17:17:12 -0500] UpdateCUPSBrowse: (102 bytes from 
129.98.91.112) 9006 4 
ipp://reeber.aecom.yu.edu:631/printers/Stylus_C88 "reeber" "Stylus 
C88" "EPSON C88 Series (1)"
d [03/Jan/2008:17:17:12 -0500] WriteClient: Removing fd 19 from OutputSet...
[some lines removed]
D [03/Jan/2008:17:17:36 -0500] ProcessIPPRequest: 19 status_code=0
d [03/Jan/2008:17:17:36 -0500] ProcessIPPRequest: Adding fd 19 to OutputSet...
d [03/Jan/2008:17:17:36 -0500] WriteClient: Removing fd 19 from OutputSet...
d [03/Jan/2008:17:17:37 -0500] select_timeout: 7 seconds to send browse update
d [03/Jan/2008:17:17:41 -0500] ReadClient: 21, used=0, file=-1
D [03/Jan/2008:17:17:41 -0500] ReadClient: 21 POST 
/printers/Stylus_C88 HTTP/1.1
d [03/Jan/2008:17:17:41 -0500] decode_auth(0x181e000): Authorization 
string = ""
d [03/Jan/2008:17:17:41 -0500] decode_auth: 21 username=""
d [03/Jan/2008:17:17:41 -0500] IsAuthorized: con->uri = "/printers/Stylus_C88"
d [03/Jan/2008:17:17:41 -0500] FindBest: uri = "/printers/Stylus_C88"...
d [03/Jan/2008:17:17:41 -0500] FindBest: Location 
CUPS_INTERNAL_BROWSE_ACL Limit 0
d [03/Jan/2008:17:17:41 -0500] FindBest: Location / Limit 7f
d [03/Jan/2008:17:17:41 -0500] FindBest: Location /admin Limit 5d
d [03/Jan/2008:17:17:41 -0500] FindBest: Location /admin Limit 22
d [03/Jan/2008:17:17:41 -0500] FindBest: Location 
/admin/conf/cupsd.conf Limit 5f
d [03/Jan/2008:17:17:41 -0500] FindBest: Location 
/admin/conf/cupsd.conf Limit 20
d [03/Jan/2008:17:17:41 -0500] FindBest: best = "/"
d [03/Jan/2008:17:17:41 -0500] IsAuthorized: auth = 0, satisfy=0...
d [03/Jan/2008:17:17:41 -0500] POST /printers/Stylus_C88
d [03/Jan/2008:17:17:41 -0500] CONTENT_TYPE = application/ipp
d [03/Jan/2008:17:17:41 -0500] ReadClient() 21 con->data_encoding = 
length, con->data_remaining = 141, con->file = -1
d [03/Jan/2008:17:17:41 -0500] ProcessIPPRequest(0x181e000[21]): 
operation_id = 000b
d [03/Jan/2008:17:17:41 -0500] ProcessIPPRequest: 
URI="http://reeber.aecom.yu.edu:631/printers/Stylus_C88"
d [03/Jan/2008:17:17:41 -0500] get_printer_attrs(0x181e000[21], 
http://reeber.aecom.yu.edu:631/printers/Stylus_C88)
d [03/Jan/2008:17:17:41 -0500] 
add_printer_state_reasons(0x181e000[21], 0x1800a00[Stylus_C88])
d [03/Jan/2008:17:17:41 -0500] add_queued_job_count(0x181e000[21], 
0x1800a00[Stylus_C88])
[some lines removed]
D [03/Jan/2008:17:17:41 -0500] ProcessIPPRequest: 21 status_code=0
d [03/Jan/2008:17:17:41 -0500] ProcessIPPRequest: Adding fd 21 to OutputSet...
d [03/Jan/2008:17:17:41 -0500] WriteClient: Removing fd 21 from OutputSet...
d [03/Jan/2008:17:17:42 -0500] select_timeout: 2 seconds to send browse update
By this point, the Windows XP box has given up.
-----
keywords: no printing, not printing, no output, silence, no response, 
ignores print job, ignores print request, communication error.
-- 

Maurice Volaski, mvolaski at aecom.yu.edu
Computing Support, Rose F. Kennedy Center
Albert Einstein College of Medicine of Yeshiva University





More information about the cups mailing list