Ticket #157: New_error_log

File New_error_log, 140.9 KB (added by losepete, 9 years ago)

USB error_log: "filter failed" "gstoraster stopped with status 11

Line 
1I [28/Apr/2017:17:00:19 +0000] Listening to 127.0.0.1:631 (IPv4)
2I [28/Apr/2017:17:00:19 +0000] Remote access is disabled.
3D [28/Apr/2017:17:00:19 +0000] Added auto ServerAlias TM5320
4I [28/Apr/2017:17:00:19 +0000] Loaded configuration file "/@unixroot/etc/cups/cupsd.conf"
5I [28/Apr/2017:17:00:19 +0000] Configured for up to 100 clients.
6I [28/Apr/2017:17:00:19 +0000] Allowing up to 100 client connections per host.
7I [28/Apr/2017:17:00:19 +0000] Using policy "default" as the default.
8I [28/Apr/2017:17:00:19 +0000] Full reload is required.
9I [28/Apr/2017:17:00:19 +0000] Loaded MIME database from "/@unixroot/usr/share/cups/mime" and "/@unixroot/etc/cups": 44 types, 52 filters...
10D [28/Apr/2017:17:00:19 +0000] Loading printer Canon_MG7500_USB...
11D [28/Apr/2017:17:00:19 +0000] load_ppd: Loading /@unixroot/var/cache/cups/Canon_MG7500_USB.data...
12D [28/Apr/2017:17:00:19 +0000] cupsdRegisterPrinter(p=0x20058780(Canon_MG7500_USB))
13D [28/Apr/2017:17:00:19 +0000] Loading printer MG7550...
14D [28/Apr/2017:17:00:19 +0000] load_ppd: Loading /@unixroot/var/cache/cups/MG7550.data...
15D [28/Apr/2017:17:00:19 +0000] cupsdRegisterPrinter(p=0x20061200(MG7550))
16D [28/Apr/2017:17:00:19 +0000] load_ppd: Loading /@unixroot/var/cache/cups/MG7550.data...
17D [28/Apr/2017:17:00:19 +0000] cupsdRegisterPrinter(p=0x20061200(MG7550))
18D [28/Apr/2017:17:00:19 +0000] Scanning /@unixroot/var/spool/cups for jobs...
19I [28/Apr/2017:17:00:19 +0000] Full reload complete.
20D [28/Apr/2017:17:00:19 +0000] cupsdCleanFiles(path="/@unixroot/var/cache/cups", pattern="*.ipp")
21I [28/Apr/2017:17:00:19 +0000] Cleaning out old files in "/@unixroot/var/cache/cups".
22I [28/Apr/2017:17:00:19 +0000] Listening to 127.0.0.1:631 on fd 6...
23I [28/Apr/2017:17:00:19 +0000] Resuming new connection processing...
24D [28/Apr/2017:17:00:19 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
25D [28/Apr/2017:17:00:19 +0000] cupsdAddCert: Adding certificate for PID 0
26D [28/Apr/2017:17:00:19 +0000] Discarding unused server-started event...
27D [28/Apr/2017:17:00:20 +0000] Report: clients=0
28D [28/Apr/2017:17:00:20 +0000] Report: jobs=0
29D [28/Apr/2017:17:00:20 +0000] Report: jobs-active=0
30D [28/Apr/2017:17:00:20 +0000] Report: printers=2
31D [28/Apr/2017:17:00:20 +0000] Report: stringpool-string-count=37374
32D [28/Apr/2017:17:00:20 +0000] Report: stringpool-alloc-bytes=11112
33D [28/Apr/2017:17:00:20 +0000] Report: stringpool-total-bytes=690872
34D [28/Apr/2017:17:00:48 +0000] [Client 1] Accepted from localhost:55536 (IPv4)
35D [28/Apr/2017:17:00:48 +0000] [Client 1] Waiting for request.
36D [28/Apr/2017:17:00:53 +0000] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
37D [28/Apr/2017:17:00:53 +0000] [Client 1] Closing connection.
38D [28/Apr/2017:17:00:53 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
39D [28/Apr/2017:17:00:53 +0000] [Client 2] Accepted from localhost:55538 (IPv4)
40D [28/Apr/2017:17:00:53 +0000] [Client 2] Waiting for request.
41D [28/Apr/2017:17:00:53 +0000] [Client 2] GET /printers/ HTTP/1.1
42D [28/Apr/2017:17:00:53 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
43D [28/Apr/2017:17:00:53 +0000] [Client 2] Read: status=200
44D [28/Apr/2017:17:00:53 +0000] [Client 2] No authentication data provided.
45D [28/Apr/2017:17:00:53 +0000] [Client 2] Processing GET /printers/
46D [28/Apr/2017:17:00:53 +0000] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
47D [28/Apr/2017:17:00:53 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
48D [28/Apr/2017:17:00:53 +0000] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
49D [28/Apr/2017:17:00:53 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
50D [28/Apr/2017:17:00:53 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
51D [28/Apr/2017:17:00:53 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
52D [28/Apr/2017:17:00:53 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
53D [28/Apr/2017:17:00:53 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
54D [28/Apr/2017:17:00:53 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
55D [28/Apr/2017:17:00:53 +0000] [CGI] envp[8] = "HOME=I:\\TEMP"
56D [28/Apr/2017:17:00:53 +0000] [CGI] envp[9] = "NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
57D [28/Apr/2017:17:00:53 +0000] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
58D [28/Apr/2017:17:00:53 +0000] [CGI] envp[11] = "SERVER_ADMIN=root@TM5320"
59D [28/Apr/2017:17:00:53 +0000] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
60D [28/Apr/2017:17:00:53 +0000] [CGI] envp[13] = "TMPDIR=I:\\TEMP"
61D [28/Apr/2017:17:00:53 +0000] [CGI] envp[14] = "TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
62D [28/Apr/2017:17:00:53 +0000] [CGI] envp[15] = "USER=root"
63D [28/Apr/2017:17:00:53 +0000] [CGI] envp[16] = "UNIXROOT=I:"
64D [28/Apr/2017:17:00:53 +0000] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
65D [28/Apr/2017:17:00:53 +0000] [CGI] envp[18] = "CUPS_SERVER=localhost"
66D [28/Apr/2017:17:00:53 +0000] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
67D [28/Apr/2017:17:00:53 +0000] [CGI] envp[20] = "IPP_PORT=631"
68D [28/Apr/2017:17:00:53 +0000] [CGI] envp[21] = "LANG=en_US.UTF8"
69D [28/Apr/2017:17:00:53 +0000] [CGI] envp[22] = "REDIRECT_STATUS=1"
70D [28/Apr/2017:17:00:53 +0000] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
71D [28/Apr/2017:17:00:53 +0000] [CGI] envp[24] = "SERVER_NAME=localhost"
72D [28/Apr/2017:17:00:53 +0000] [CGI] envp[25] = "SERVER_PORT=631"
73D [28/Apr/2017:17:00:53 +0000] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
74D [28/Apr/2017:17:00:53 +0000] [CGI] envp[27] = "REMOTE_HOST=localhost"
75D [28/Apr/2017:17:00:53 +0000] [CGI] envp[28] = "SCRIPT_NAME=/printers/"
76D [28/Apr/2017:17:00:53 +0000] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/"
77D [28/Apr/2017:17:00:53 +0000] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
78D [28/Apr/2017:17:00:53 +0000] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0 SeaMonkey/2.35"
79D [28/Apr/2017:17:00:53 +0000] [CGI] envp[32] = "HTTP_REFERER=http://localhost:631/"
80D [28/Apr/2017:17:00:53 +0000] [CGI] envp[33] = "REQUEST_METHOD=GET"
81D [28/Apr/2017:17:00:53 +0000] [CGI] envp[34] = "QUERY_STRING="
82D [28/Apr/2017:17:00:54 +0000] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 119)
83I [28/Apr/2017:17:00:54 +0000] [Client 2] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=119, file=10)
84D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
85D [28/Apr/2017:17:00:54 +0000] [CGI] org.cups.sid cookie not found, initializing!
86D [28/Apr/2017:17:00:54 +0000] [CGI] org.cups.sid cookie is \"76832da10be696dc76bac386d11f13bc\"
87D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
88D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
89D [28/Apr/2017:17:00:54 +0000] [Client 3] Accepted from localhost:55539 (IPv4)
90D [28/Apr/2017:17:00:54 +0000] [Client 3] Waiting for request.
91D [28/Apr/2017:17:00:54 +0000] [Client 3] POST / HTTP/1.1
92D [28/Apr/2017:17:00:54 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
93D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=200
94D [28/Apr/2017:17:00:54 +0000] [Client 3] No authentication data provided.
95D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=100
96D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=100
97D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=100
98D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=100
99D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=100
100D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=100
101D [28/Apr/2017:17:00:54 +0000] [Client 3] 2.0 CUPS-Get-Default 1
102D [28/Apr/2017:17:00:54 +0000] CUPS-Get-Default
103D [28/Apr/2017:17:00:54 +0000] CUPS-Get-Default client-error-not-found: No default printer.
104D [28/Apr/2017:17:00:54 +0000] [Client 3] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
105D [28/Apr/2017:17:00:54 +0000] [Client 3] Content-Length: 113
106D [28/Apr/2017:17:00:54 +0000] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
107D [28/Apr/2017:17:00:54 +0000] [Client 3] con->http=0x202eeea0
108D [28/Apr/2017:17:00:54 +0000] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x201e2c40(IPP_STATE_DATA), pipe_pid=0, file=-1
109D [28/Apr/2017:17:00:54 +0000] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
110D [28/Apr/2017:17:00:54 +0000] [Client 3] bytes=0, http_state=0, data_remaining=113
111D [28/Apr/2017:17:00:54 +0000] [Client 3] Flushing write buffer.
112D [28/Apr/2017:17:00:54 +0000] [Client 3] New state is HTTP_STATE_WAITING
113D [28/Apr/2017:17:00:54 +0000] [Client 3] Waiting for request.
114D [28/Apr/2017:17:00:54 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
115D [28/Apr/2017:17:00:54 +0000] [CGI] show_all_printers(http=0x2003c300, user=\"(null)\")
116D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: TITLE=\"Printers\"
117D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
118D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
119D [28/Apr/2017:17:00:54 +0000] [Client 2] CGI data ready to be sent.
120D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
121D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=119, file=10
122D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
123D [28/Apr/2017:17:00:54 +0000] [Client 2] Script header: Set-Cookie: org.cups.sid=76832da10be696dc76bac386d11f13bc; path=/; httponly;
124D [28/Apr/2017:17:00:54 +0000] [Client 2] Script header: Content-Type: text/html;charset=utf-8
125D [28/Apr/2017:17:00:54 +0000] [Client 2] Script header:
126D [28/Apr/2017:17:00:54 +0000] [Client 2] Sending status 200 for CGI.
127D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdSendHeader: code=200, type="(null)", auth_type=0
128D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
129D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
130D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
131D [28/Apr/2017:17:00:54 +0000] [Client 3] POST / HTTP/1.1
132D [28/Apr/2017:17:00:54 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
133D [28/Apr/2017:17:00:54 +0000] [Client 3] Read: status=200
134D [28/Apr/2017:17:00:54 +0000] [Client 3] No authentication data provided.
135D [28/Apr/2017:17:00:54 +0000] [Client 3] 2.0 CUPS-Get-Printers 2
136D [28/Apr/2017:17:00:54 +0000] CUPS-Get-Printers
137D [28/Apr/2017:17:00:54 +0000] [Client 3] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
138D [28/Apr/2017:17:00:54 +0000] [Client 3] Content-Length: 672
139D [28/Apr/2017:17:00:54 +0000] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
140D [28/Apr/2017:17:00:54 +0000] [Client 3] con->http=0x202eeea0
141D [28/Apr/2017:17:00:54 +0000] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=672, response=0x201e3000(IPP_STATE_DATA), pipe_pid=0, file=-1
142D [28/Apr/2017:17:00:54 +0000] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
143D [28/Apr/2017:17:00:54 +0000] [Client 3] bytes=0, http_state=0, data_remaining=672
144D [28/Apr/2017:17:00:54 +0000] [Client 3] Flushing write buffer.
145D [28/Apr/2017:17:00:54 +0000] [Client 3] New state is HTTP_STATE_WAITING
146D [28/Apr/2017:17:00:54 +0000] [Client 3] Waiting for request.
147D [28/Apr/2017:17:00:54 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
148D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: TOTAL=\"2\"
149D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
150D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
151D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_state[0]=\"3\"
152D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_state_message[0]=\"\"
153D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
154D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/Canon_MG7500_USB\"
155D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_name[0]=\"Canon_MG7500_USB\"
156D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_location[0]=\"Local Printer\"
157D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_info[0]=\"Canon MG7500 series\"
158D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_make_and_model[0]=\"Canon PIXMA MG7550 - CUPS+Gutenprint v5.2.11 Simplified\"
159D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
160D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
161D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_state[1]=\"3\"
162D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_state_message[1]=\"\"
163D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: admin_uri[1]=\"/admin/\"
164D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_uri_supported[1]=\"/printers/MG7550\"
165D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_name[1]=\"MG7550\"
166D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_location[1]=\"office\"
167D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_info[1]=\"Canon PIXMA colour inkjet printer\"
168D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetArray: printer_make_and_model[1]=\"Canon PIXMA MG7750 - CUPS+Gutenprint v5.2.11 Simplified\"
169D [28/Apr/2017:17:00:54 +0000] [CGI] cgiSetVariable: THISURL=\"/printers/\"
170D [28/Apr/2017:17:00:54 +0000] [Client 2] CGI data ready to be sent.
171D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
172D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
173D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
174D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
175D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
176D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
177D [28/Apr/2017:17:00:54 +0000] [Client 2] CGI data ready to be sent.
178D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
179D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
180D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
181D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
182D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
183D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
184D [28/Apr/2017:17:00:54 +0000] [Client 4] Accepted from localhost:55540 (IPv4)
185D [28/Apr/2017:17:00:54 +0000] [Client 4] Waiting for request.
186D [28/Apr/2017:17:00:54 +0000] [Client 2] CGI data ready to be sent.
187D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
188D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
189D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
190D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
191D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
192D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
193D [28/Apr/2017:17:00:54 +0000] [Client 2] CGI data ready to be sent.
194D [28/Apr/2017:17:00:54 +0000] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
195D [28/Apr/2017:17:00:54 +0000] [Client 3] Closing connection.
196D [28/Apr/2017:17:00:54 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
197D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
198D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
199D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
200D [28/Apr/2017:17:00:54 +0000] PID 119 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
201D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
202D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
203D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
204D [28/Apr/2017:17:00:54 +0000] [Client 2] CGI data ready to be sent.
205D [28/Apr/2017:17:00:54 +0000] [Client 2] con->http=0x202eacc0
206D [28/Apr/2017:17:00:54 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=119, file=10
207D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for CGI data.
208D [28/Apr/2017:17:00:54 +0000] [Client 2] Sending 0-length chunk.
209D [28/Apr/2017:17:00:54 +0000] [Client 2] Flushing write buffer.
210D [28/Apr/2017:17:00:54 +0000] [Client 2] New state is HTTP_STATE_WAITING
211D [28/Apr/2017:17:00:54 +0000] [Client 2] Waiting for request.
212D [28/Apr/2017:17:00:54 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
213D [28/Apr/2017:17:00:56 +0000] [Client 2] GET /printers/Canon_MG7500_USB HTTP/1.1
214D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
215D [28/Apr/2017:17:00:56 +0000] [Client 2] Read: status=200
216D [28/Apr/2017:17:00:56 +0000] [Client 2] No authentication data provided.
217D [28/Apr/2017:17:00:56 +0000] [Client 2] Processing GET /printers/Canon_MG7500_USB
218D [28/Apr/2017:17:00:56 +0000] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
219D [28/Apr/2017:17:00:56 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
220D [28/Apr/2017:17:00:56 +0000] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
221D [28/Apr/2017:17:00:56 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
222D [28/Apr/2017:17:00:56 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
223D [28/Apr/2017:17:00:56 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
224D [28/Apr/2017:17:00:56 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
225D [28/Apr/2017:17:00:56 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
226D [28/Apr/2017:17:00:56 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
227D [28/Apr/2017:17:00:56 +0000] [CGI] envp[8] = "HOME=I:\\TEMP"
228D [28/Apr/2017:17:00:56 +0000] [CGI] envp[9] = "NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
229D [28/Apr/2017:17:00:56 +0000] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
230D [28/Apr/2017:17:00:56 +0000] [CGI] envp[11] = "SERVER_ADMIN=root@TM5320"
231D [28/Apr/2017:17:00:56 +0000] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
232D [28/Apr/2017:17:00:56 +0000] [CGI] envp[13] = "TMPDIR=I:\\TEMP"
233D [28/Apr/2017:17:00:56 +0000] [CGI] envp[14] = "TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
234D [28/Apr/2017:17:00:56 +0000] [CGI] envp[15] = "USER=root"
235D [28/Apr/2017:17:00:56 +0000] [CGI] envp[16] = "UNIXROOT=I:"
236D [28/Apr/2017:17:00:56 +0000] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
237D [28/Apr/2017:17:00:56 +0000] [CGI] envp[18] = "CUPS_SERVER=localhost"
238D [28/Apr/2017:17:00:56 +0000] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
239D [28/Apr/2017:17:00:56 +0000] [CGI] envp[20] = "IPP_PORT=631"
240D [28/Apr/2017:17:00:56 +0000] [CGI] envp[21] = "LANG=en_US.UTF8"
241D [28/Apr/2017:17:00:56 +0000] [CGI] envp[22] = "REDIRECT_STATUS=1"
242D [28/Apr/2017:17:00:56 +0000] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
243D [28/Apr/2017:17:00:56 +0000] [CGI] envp[24] = "SERVER_NAME=localhost"
244D [28/Apr/2017:17:00:56 +0000] [CGI] envp[25] = "SERVER_PORT=631"
245D [28/Apr/2017:17:00:56 +0000] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
246D [28/Apr/2017:17:00:56 +0000] [CGI] envp[27] = "REMOTE_HOST=localhost"
247D [28/Apr/2017:17:00:56 +0000] [CGI] envp[28] = "SCRIPT_NAME=/printers/Canon_MG7500_USB"
248D [28/Apr/2017:17:00:56 +0000] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/Canon_MG7500_USB"
249D [28/Apr/2017:17:00:56 +0000] [CGI] envp[30] = "PATH_INFO=/Canon_MG7500_USB"
250D [28/Apr/2017:17:00:56 +0000] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
251D [28/Apr/2017:17:00:56 +0000] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=76832da10be696dc76bac386d11f13bc"
252D [28/Apr/2017:17:00:56 +0000] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0 SeaMonkey/2.35"
253D [28/Apr/2017:17:00:56 +0000] [CGI] envp[34] = "HTTP_REFERER=http://localhost:631/printers/"
254D [28/Apr/2017:17:00:56 +0000] [CGI] envp[35] = "REQUEST_METHOD=GET"
255D [28/Apr/2017:17:00:56 +0000] [CGI] envp[36] = "QUERY_STRING="
256D [28/Apr/2017:17:00:56 +0000] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 121)
257I [28/Apr/2017:17:00:56 +0000] [Client 2] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=121, file=10)
258D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
259D [28/Apr/2017:17:00:56 +0000] [Client 5] Accepted from localhost:55541 (IPv4)
260D [28/Apr/2017:17:00:56 +0000] [Client 5] Waiting for request.
261D [28/Apr/2017:17:00:56 +0000] [CGI] org.cups.sid cookie is \"76832da10be696dc76bac386d11f13bc\"
262D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
263D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
264D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
265D [28/Apr/2017:17:00:56 +0000] [Client 5] POST / HTTP/1.1
266D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
267D [28/Apr/2017:17:00:56 +0000] [Client 5] Read: status=200
268D [28/Apr/2017:17:00:56 +0000] [Client 5] No authentication data provided.
269D [28/Apr/2017:17:00:56 +0000] [Client 5] 2.0 CUPS-Get-Default 1
270D [28/Apr/2017:17:00:56 +0000] CUPS-Get-Default
271D [28/Apr/2017:17:00:56 +0000] CUPS-Get-Default client-error-not-found: No default printer.
272D [28/Apr/2017:17:00:56 +0000] [Client 5] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
273D [28/Apr/2017:17:00:56 +0000] [Client 5] Content-Length: 113
274D [28/Apr/2017:17:00:56 +0000] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
275D [28/Apr/2017:17:00:56 +0000] [Client 5] con->http=0x202edd20
276D [28/Apr/2017:17:00:56 +0000] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x202e6000(IPP_STATE_DATA), pipe_pid=0, file=-1
277D [28/Apr/2017:17:00:56 +0000] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
278D [28/Apr/2017:17:00:56 +0000] [Client 5] bytes=0, http_state=0, data_remaining=113
279D [28/Apr/2017:17:00:56 +0000] [Client 5] Flushing write buffer.
280D [28/Apr/2017:17:00:56 +0000] [Client 5] New state is HTTP_STATE_WAITING
281D [28/Apr/2017:17:00:56 +0000] [Client 5] Waiting for request.
282D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
283D [28/Apr/2017:17:00:56 +0000] [CGI] show_printer(http=0x2003c360, printer=\"Canon_MG7500_USB\")
284D [28/Apr/2017:17:00:56 +0000] [Client 5] POST / HTTP/1.1
285D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
286D [28/Apr/2017:17:00:56 +0000] [Client 5] Read: status=200
287D [28/Apr/2017:17:00:56 +0000] [Client 5] No authentication data provided.
288D [28/Apr/2017:17:00:56 +0000] [Client 5] 2.0 Get-Printer-Attributes 2
289D [28/Apr/2017:17:00:56 +0000] Get-Printer-Attributes ipp://localhost/printers/Canon_MG7500_USB
290D [28/Apr/2017:17:00:56 +0000] [Client 5] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MG7500_USB) from localhost
291D [28/Apr/2017:17:00:56 +0000] [Client 5] Content-Length: 729
292D [28/Apr/2017:17:00:56 +0000] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
293D [28/Apr/2017:17:00:56 +0000] [Client 5] con->http=0x202edd20
294D [28/Apr/2017:17:00:56 +0000] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=729, response=0x202e6040(IPP_STATE_DATA), pipe_pid=0, file=-1
295D [28/Apr/2017:17:00:56 +0000] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
296D [28/Apr/2017:17:00:56 +0000] [Client 5] bytes=0, http_state=0, data_remaining=729
297D [28/Apr/2017:17:00:56 +0000] [Client 5] Flushing write buffer.
298D [28/Apr/2017:17:00:56 +0000] [Client 5] New state is HTTP_STATE_WAITING
299D [28/Apr/2017:17:00:56 +0000] [Client 5] Waiting for request.
300D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
301D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
302D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
303D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
304D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
305D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
306D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
307D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_state[0]=\"3\"
308D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
309D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/Canon_MG7500_USB\"
310D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_name[0]=\"Canon_MG7500_USB\"
311D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_location[0]=\"Local Printer\"
312D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_info[0]=\"Canon MG7500 series\"
313D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
314D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: device_uri[0]=\"usb://Canon/MG7500%20series?serial=117758&interface=1\"
315D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: color_supported[0]=\"1\"
316D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_make_and_model[0]=\"Canon PIXMA MG7550 - CUPS+Gutenprint v5.2.11 Simplified\"
317D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
318D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
319D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
320D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: printer_commands[0]=\"none\"
321D [28/Apr/2017:17:00:56 +0000] [Client 2] CGI data ready to be sent.
322D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
323D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: TITLE=\"Canon_MG7500_USB\"
324D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
325D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
326D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
327D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=121, file=10
328D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
329D [28/Apr/2017:17:00:56 +0000] [Client 2] Script header: Content-Type: text/html;charset=utf-8
330D [28/Apr/2017:17:00:56 +0000] [Client 2] Script header:
331D [28/Apr/2017:17:00:56 +0000] [Client 2] Sending status 200 for CGI.
332D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdSendHeader: code=200, type="(null)", auth_type=0
333D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
334D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
335D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
336D [28/Apr/2017:17:00:56 +0000] [CGI] Regular expression \".*Clean.*\"
337D [28/Apr/2017:17:00:56 +0000] [CGI] Regular expression \".*PrintSelfTestPage.*\"
338D [28/Apr/2017:17:00:56 +0000] [Client 2] CGI data ready to be sent.
339D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
340D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
341D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
342D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
343D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
344D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
345D [28/Apr/2017:17:00:56 +0000] [Client 2] CGI data ready to be sent.
346D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
347D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
348D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
349D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
350D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
351D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
352D [28/Apr/2017:17:00:56 +0000] [Client 5] POST / HTTP/1.1
353D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
354D [28/Apr/2017:17:00:56 +0000] [Client 5] Read: status=200
355D [28/Apr/2017:17:00:56 +0000] [Client 5] No authentication data provided.
356D [28/Apr/2017:17:00:56 +0000] [Client 5] 2.0 Get-Jobs 3
357D [28/Apr/2017:17:00:56 +0000] Get-Jobs ipp://localhost:631/printers/Canon_MG7500_USB
358D [28/Apr/2017:17:00:56 +0000] [Client 5] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_MG7500_USB) from localhost
359D [28/Apr/2017:17:00:56 +0000] [Client 5] Content-Length: 75
360D [28/Apr/2017:17:00:56 +0000] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
361D [28/Apr/2017:17:00:56 +0000] [Client 5] con->http=0x202edd20
362D [28/Apr/2017:17:00:56 +0000] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x202e6240(IPP_STATE_DATA), pipe_pid=0, file=-1
363D [28/Apr/2017:17:00:56 +0000] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
364D [28/Apr/2017:17:00:56 +0000] [Client 5] bytes=0, http_state=0, data_remaining=75
365D [28/Apr/2017:17:00:56 +0000] [Client 5] Flushing write buffer.
366D [28/Apr/2017:17:00:56 +0000] [Client 5] New state is HTTP_STATE_WAITING
367D [28/Apr/2017:17:00:56 +0000] [Client 5] Waiting for request.
368D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
369D [28/Apr/2017:17:00:56 +0000] [CGI] cgiClearVariables called.
370D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: ORDER=\"asc\"
371D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
372D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: TOTAL=\"0\"
373D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
374D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/Canon_MG7500_USB\"
375D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: THISURL=\"/printers/Canon_MG7500_USB\"
376D [28/Apr/2017:17:00:56 +0000] [CGI] cgiSetVariable: SEARCH_DEST=\"Canon_MG7500_USB\"
377D [28/Apr/2017:17:00:56 +0000] [Client 2] CGI data ready to be sent.
378D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
379D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
380D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
381D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
382D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
383D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
384D [28/Apr/2017:17:00:56 +0000] [Client 2] CGI data ready to be sent.
385D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
386D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
387D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
388D [28/Apr/2017:17:00:56 +0000] PID 121 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
389D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
390D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
391D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
392D [28/Apr/2017:17:00:56 +0000] [Client 2] CGI data ready to be sent.
393D [28/Apr/2017:17:00:56 +0000] [Client 5] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
394D [28/Apr/2017:17:00:56 +0000] [Client 5] Closing connection.
395D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
396D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
397D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
398D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
399D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
400D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
401D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
402D [28/Apr/2017:17:00:56 +0000] [Client 2] CGI data ready to be sent.
403D [28/Apr/2017:17:00:56 +0000] [Client 2] con->http=0x202eacc0
404D [28/Apr/2017:17:00:56 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=121, file=10
405D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for CGI data.
406D [28/Apr/2017:17:00:56 +0000] [Client 2] Sending 0-length chunk.
407D [28/Apr/2017:17:00:56 +0000] [Client 2] Flushing write buffer.
408D [28/Apr/2017:17:00:56 +0000] [Client 2] New state is HTTP_STATE_WAITING
409D [28/Apr/2017:17:00:56 +0000] [Client 2] Waiting for request.
410D [28/Apr/2017:17:00:56 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
411D [28/Apr/2017:17:00:59 +0000] [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
412D [28/Apr/2017:17:00:59 +0000] [Client 4] Closing connection.
413D [28/Apr/2017:17:00:59 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
414D [28/Apr/2017:17:01:03 +0000] [Client 2] POST /printers/Canon_MG7500_USB HTTP/1.1
415D [28/Apr/2017:17:01:03 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
416D [28/Apr/2017:17:01:03 +0000] [Client 2] Read: status=200
417D [28/Apr/2017:17:01:03 +0000] [Client 2] No authentication data provided.
418D [28/Apr/2017:17:01:03 +0000] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
419D [28/Apr/2017:17:01:03 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
420D [28/Apr/2017:17:01:03 +0000] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
421D [28/Apr/2017:17:01:03 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
422D [28/Apr/2017:17:01:03 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
423D [28/Apr/2017:17:01:03 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
424D [28/Apr/2017:17:01:03 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
425D [28/Apr/2017:17:01:03 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
426D [28/Apr/2017:17:01:03 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
427D [28/Apr/2017:17:01:03 +0000] [CGI] envp[8] = "HOME=I:\\TEMP"
428D [28/Apr/2017:17:01:03 +0000] [CGI] envp[9] = "NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
429D [28/Apr/2017:17:01:03 +0000] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
430D [28/Apr/2017:17:01:03 +0000] [CGI] envp[11] = "SERVER_ADMIN=root@TM5320"
431D [28/Apr/2017:17:01:03 +0000] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
432D [28/Apr/2017:17:01:03 +0000] [CGI] envp[13] = "TMPDIR=I:\\TEMP"
433D [28/Apr/2017:17:01:03 +0000] [CGI] envp[14] = "TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
434D [28/Apr/2017:17:01:03 +0000] [CGI] envp[15] = "USER=root"
435D [28/Apr/2017:17:01:03 +0000] [CGI] envp[16] = "UNIXROOT=I:"
436D [28/Apr/2017:17:01:03 +0000] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
437D [28/Apr/2017:17:01:03 +0000] [CGI] envp[18] = "CUPS_SERVER=localhost"
438D [28/Apr/2017:17:01:03 +0000] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
439D [28/Apr/2017:17:01:03 +0000] [CGI] envp[20] = "IPP_PORT=631"
440D [28/Apr/2017:17:01:03 +0000] [CGI] envp[21] = "LANG=en_US.UTF8"
441D [28/Apr/2017:17:01:03 +0000] [CGI] envp[22] = "REDIRECT_STATUS=1"
442D [28/Apr/2017:17:01:03 +0000] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
443D [28/Apr/2017:17:01:03 +0000] [CGI] envp[24] = "SERVER_NAME=localhost"
444D [28/Apr/2017:17:01:03 +0000] [CGI] envp[25] = "SERVER_PORT=631"
445D [28/Apr/2017:17:01:03 +0000] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
446D [28/Apr/2017:17:01:03 +0000] [CGI] envp[27] = "REMOTE_HOST=localhost"
447D [28/Apr/2017:17:01:03 +0000] [CGI] envp[28] = "SCRIPT_NAME=/printers/Canon_MG7500_USB"
448D [28/Apr/2017:17:01:03 +0000] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/Canon_MG7500_USB"
449D [28/Apr/2017:17:01:03 +0000] [CGI] envp[30] = "PATH_INFO=/Canon_MG7500_USB"
450D [28/Apr/2017:17:01:03 +0000] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
451D [28/Apr/2017:17:01:03 +0000] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=76832da10be696dc76bac386d11f13bc"
452D [28/Apr/2017:17:01:03 +0000] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0 SeaMonkey/2.35"
453D [28/Apr/2017:17:01:03 +0000] [CGI] envp[34] = "HTTP_REFERER=http://localhost:631/printers/Canon_MG7500_USB"
454D [28/Apr/2017:17:01:03 +0000] [CGI] envp[35] = "REQUEST_METHOD=POST"
455D [28/Apr/2017:17:01:03 +0000] [CGI] envp[36] = "CONTENT_LENGTH=64"
456D [28/Apr/2017:17:01:03 +0000] [CGI] envp[37] = "CONTENT_TYPE=application/x-www-form-urlencoded"
457D [28/Apr/2017:17:01:03 +0000] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 123)
458I [28/Apr/2017:17:01:03 +0000] [Client 2] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=123, file=11)
459D [28/Apr/2017:17:01:03 +0000] [Client 2] Waiting for CGI data.
460D [28/Apr/2017:17:01:03 +0000] [Client 6] Accepted from localhost:55542 (IPv4)
461D [28/Apr/2017:17:01:03 +0000] [Client 6] Waiting for request.
462D [28/Apr/2017:17:01:03 +0000] [CGI] org.cups.sid cookie is \"76832da10be696dc76bac386d11f13bc\"
463D [28/Apr/2017:17:01:03 +0000] [CGI] cgiSetVariable: org.cups.sid=\"76832da10be696dc76bac386d11f13bc\"
464D [28/Apr/2017:17:01:03 +0000] [CGI] cgiSetVariable: OP=\"print-test-page\"
465D [28/Apr/2017:17:01:03 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
466D [28/Apr/2017:17:01:03 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
467D [28/Apr/2017:17:01:03 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
468D [28/Apr/2017:17:01:03 +0000] [Client 6] POST /printers/Canon_MG7500_USB HTTP/1.1
469D [28/Apr/2017:17:01:03 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
470D [28/Apr/2017:17:01:03 +0000] [Client 6] Read: status=200
471D [28/Apr/2017:17:01:03 +0000] [Client 6] No authentication data provided.
472D [28/Apr/2017:17:01:03 +0000] [Client 6] 2.0 Print-Job 1
473D [28/Apr/2017:17:01:03 +0000] Print-Job ipp://localhost:631/printers/Canon_MG7500_USB
474D [28/Apr/2017:17:01:03 +0000] [Job ???] Auto-typing file...
475I [28/Apr/2017:17:01:03 +0000] [Job ???] Request file type is application/vnd.cups-pdf-banner.
476D [28/Apr/2017:17:01:03 +0000] cupsdMarkDirty(---J-)
477D [28/Apr/2017:17:01:03 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
478D [28/Apr/2017:17:01:03 +0000] Adding default job-sheets values "none,none"...
479I [28/Apr/2017:17:01:03 +0000] [Job 1] Adding start banner page "none".
480D [28/Apr/2017:17:01:03 +0000] Discarding unused job-created event...
481D [28/Apr/2017:17:01:03 +0000] cupsdMarkDirty(---J-)
482D [28/Apr/2017:17:01:03 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
483I [28/Apr/2017:17:01:03 +0000] [Job 1] Adding end banner page "none".
484I [28/Apr/2017:17:01:03 +0000] [Job 1] File of type application/vnd.cups-pdf-banner queued by "anonymous".
485D [28/Apr/2017:17:01:03 +0000] [Job 1] hold_until=0
486I [28/Apr/2017:17:01:03 +0000] [Job 1] Queued on "Canon_MG7500_USB" by "anonymous".
487D [28/Apr/2017:17:01:03 +0000] [Job 1] time-at-processing=1493395263
488D [28/Apr/2017:17:01:03 +0000] cupsdMarkDirty(---J-)
489D [28/Apr/2017:17:01:03 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
490D [28/Apr/2017:17:01:03 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
491D [28/Apr/2017:17:01:03 +0000] Discarding unused printer-state-changed event...
492D [28/Apr/2017:17:01:03 +0000] [Job 1] 4 filters for job:
493D [28/Apr/2017:17:01:03 +0000] [Job 1] bannertopdf.exe (application/vnd.cups-pdf-banner to application/pdf, cost 32)
494D [28/Apr/2017:17:01:03 +0000] [Job 1] pdftopdf.exe (application/pdf to application/vnd.cups-pdf, cost 66)
495D [28/Apr/2017:17:01:03 +0000] [Job 1] gstoraster.exe (application/vnd.cups-pdf to application/vnd.cups-raster, cost 99)
496D [28/Apr/2017:17:01:03 +0000] [Job 1] rastertogutenprint.5.2 (application/vnd.cups-raster to printer/Canon_MG7500_USB, cost 100)
497D [28/Apr/2017:17:01:03 +0000] [Job 1] job-sheets=none,none
498D [28/Apr/2017:17:01:03 +0000] [Job 1] argv[0]="Canon_MG7500_USB"
499D [28/Apr/2017:17:01:03 +0000] [Job 1] argv[1]="1"
500D [28/Apr/2017:17:01:03 +0000] [Job 1] argv[2]="anonymous"
501D [28/Apr/2017:17:01:03 +0000] [Job 1] argv[3]="Test Page"
502D [28/Apr/2017:17:01:03 +0000] [Job 1] argv[4]="1"
503D [28/Apr/2017:17:01:03 +0000] [Job 1] argv[5]="job-uuid=urn:uuid:98225ce9-8309-3a47-62fb-e422312df770 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1493395263 time-at-processing=1493395263"
504D [28/Apr/2017:17:01:03 +0000] [Job 1] argv[6]="/@unixroot/var/spool/cups/d00001-001"
505D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[0]="CUPS_CACHEDIR=/@unixroot/var/cache/cups"
506D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[1]="CUPS_DATADIR=/@unixroot/usr/share/cups"
507D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[2]="CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
508D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[3]="CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
509D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[4]="CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
510D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[5]="CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
511D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[6]="CUPS_SERVERROOT=/@unixroot/etc/cups"
512D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[7]="CUPS_STATEDIR=/@unixroot/var/run/cups"
513D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[8]="HOME=I:\\TEMP"
514D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[9]="NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
515D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[10]="PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
516D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[11]="SERVER_ADMIN=root@TM5320"
517D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[12]="SOFTWARE=CUPS/2.1.3"
518D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[13]="TMPDIR=I:\\TEMP"
519D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[14]="TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
520D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[15]="USER=root"
521D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[16]="UNIXROOT=I:"
522D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[17]="CUPS_MAX_MESSAGE=2047"
523D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[18]="CUPS_SERVER=localhost"
524D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[19]="CUPS_ENCRYPTION=IfRequested"
525D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[20]="IPP_PORT=631"
526D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[21]="CHARSET=utf-8"
527D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[22]="LANG=en_US.UTF-8"
528D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[23]="PPD=/@unixroot/etc/cups/ppd/Canon_MG7500_USB.ppd"
529D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[24]="RIP_MAX_CACHE=128m"
530D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[25]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
531D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[26]="DEVICE_URI=usb://Canon/MG7500%20series?serial=117758&interface=1"
532D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[27]="PRINTER_INFO=Canon MG7500 series"
533D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[28]="PRINTER_LOCATION=Local Printer"
534D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[29]="PRINTER=Canon_MG7500_USB"
535D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[30]="PRINTER_STATE_REASONS=none"
536D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[31]="CUPS_FILETYPE=document"
537D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[32]="FINAL_CONTENT_TYPE=application/vnd.cups-raster"
538D [28/Apr/2017:17:01:03 +0000] [Job 1] envp[33]="AUTH_I****"
539I [28/Apr/2017:17:01:03 +0000] [Job 1] Started filter /@unixroot/usr/lib/cups/filter/bannertopdf.exe (PID 125)
540I [28/Apr/2017:17:01:03 +0000] [Job 1] Started filter /@unixroot/usr/lib/cups/filter/pdftopdf.exe (PID 126)
541I [28/Apr/2017:17:01:04 +0000] [Job 1] Started filter /@unixroot/usr/lib/cups/filter/gstoraster.exe (PID 129)
542I [28/Apr/2017:17:01:04 +0000] [Job 1] Started filter /@unixroot/usr/lib/cups/filter/rastertogutenprint.5.2.exe (PID 130)
543I [28/Apr/2017:17:01:04 +0000] [Job 1] Started backend /@unixroot/usr/lib/cups/backend/usb.exe (PID 133)
544D [28/Apr/2017:17:01:04 +0000] Discarding unused job-state-changed event...
545D [28/Apr/2017:17:01:04 +0000] [Client 6] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/Canon_MG7500_USB) from localhost
546D [28/Apr/2017:17:01:04 +0000] [Client 6] Content-Length: 195
547D [28/Apr/2017:17:01:04 +0000] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
548D [28/Apr/2017:17:01:04 +0000] [Client 6] con->http=0x202edd20
549D [28/Apr/2017:17:01:04 +0000] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=195, response=0x201e2e60(IPP_STATE_IDLE), pipe_pid=0, file=-1
550D [28/Apr/2017:17:01:04 +0000] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
551D [28/Apr/2017:17:01:04 +0000] [Client 6] bytes=0, http_state=0, data_remaining=195
552D [28/Apr/2017:17:01:04 +0000] [Client 6] Flushing write buffer.
553D [28/Apr/2017:17:01:04 +0000] [Client 6] New state is HTTP_STATE_WAITING
554D [28/Apr/2017:17:01:04 +0000] [Client 6] Waiting for request.
555D [28/Apr/2017:17:01:04 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
556D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
557D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
558D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
559D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
560D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetArray: job_uri[0]=\"/jobs/1\"
561D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetArray: job_id[0]=\"1\"
562D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetArray: job_state[0]=\"3\"
563D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetArray: job_state_message[0]=\"\"
564D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetArray: job_state_reasons[0]=\"none\"
565D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: refresh_page=\"2;URL=/printers/Canon_MG7500_USB\"
566D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: TITLE=\"Print Test Page\"
567D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
568D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
569D [28/Apr/2017:17:01:04 +0000] [Client 2] CGI data ready to be sent.
570D [28/Apr/2017:17:01:04 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
571D [28/Apr/2017:17:01:04 +0000] [Client 2] con->http=0x202eacc0
572D [28/Apr/2017:17:01:04 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=123, file=11
573D [28/Apr/2017:17:01:04 +0000] [Client 2] Waiting for CGI data.
574D [28/Apr/2017:17:01:04 +0000] [Client 2] Script header: Content-Type: text/html;charset=utf-8
575D [28/Apr/2017:17:01:04 +0000] [Client 2] Script header:
576D [28/Apr/2017:17:01:04 +0000] [Client 2] Sending status 200 for CGI.
577D [28/Apr/2017:17:01:04 +0000] [Client 2] cupsdSendHeader: code=200, type="(null)", auth_type=0
578D [28/Apr/2017:17:01:04 +0000] [Client 7] Accepted from localhost:55543 (IPv4)
579D [28/Apr/2017:17:01:04 +0000] [Client 7] Waiting for request.
580D [28/Apr/2017:17:01:04 +0000] [Client 2] con->http=0x202eacc0
581D [28/Apr/2017:17:01:04 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=123, file=11
582D [28/Apr/2017:17:01:04 +0000] [Client 2] Waiting for CGI data.
583D [28/Apr/2017:17:01:04 +0000] [Client 2] CGI data ready to be sent.
584D [28/Apr/2017:17:01:04 +0000] [Client 2] con->http=0x202eacc0
585D [28/Apr/2017:17:01:04 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=123, file=11
586D [28/Apr/2017:17:01:04 +0000] [Client 2] Waiting for CGI data.
587D [28/Apr/2017:17:01:04 +0000] [Client 2] con->http=0x202eacc0
588D [28/Apr/2017:17:01:04 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=123, file=11
589D [28/Apr/2017:17:01:04 +0000] [Client 2] Waiting for CGI data.
590D [28/Apr/2017:17:01:04 +0000] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
591D [28/Apr/2017:17:01:04 +0000] [Client 6] Closing connection.
592D [28/Apr/2017:17:01:04 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
593D [28/Apr/2017:17:01:04 +0000] [Client 2] CGI data ready to be sent.
594D [28/Apr/2017:17:01:04 +0000] [Client 2] con->http=0x202eacc0
595D [28/Apr/2017:17:01:04 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=123, file=11
596D [28/Apr/2017:17:01:04 +0000] [Client 2] Waiting for CGI data.
597D [28/Apr/2017:17:01:04 +0000] [Client 2] Sending 0-length chunk.
598D [28/Apr/2017:17:01:04 +0000] [Client 2] Flushing write buffer.
599D [28/Apr/2017:17:01:04 +0000] [Client 2] New state is HTTP_STATE_WAITING
600D [28/Apr/2017:17:01:04 +0000] [Client 2] Waiting for request.
601D [28/Apr/2017:17:01:04 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
602D [28/Apr/2017:17:01:04 +0000] PID 123 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
603D [28/Apr/2017:17:01:04 +0000] [Job 1] Loading USB quirks from \"/@unixroot/usr/share/cups/usb\".
604D [28/Apr/2017:17:01:04 +0000] [Job 1] Loaded 129 quirks.
605D [28/Apr/2017:17:01:04 +0000] [Job 1] Printing on printer with URI: usb://Canon/MG7500%20series?serial=117758&interface=1
606D [28/Apr/2017:17:01:04 +0000] [Job 1] libusb_get_device_list=2
607D [28/Apr/2017:17:01:04 +0000] [Job 1] STATE: +connecting-to-device
608D [28/Apr/2017:17:01:04 +0000] cupsdMarkDirty(---J-)
609D [28/Apr/2017:17:01:04 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
610D [28/Apr/2017:17:01:04 +0000] Discarding unused printer-state-changed event...
611D [28/Apr/2017:17:01:04 +0000] [Job 1] STATE: -connecting-to-device
612D [28/Apr/2017:17:01:04 +0000] cupsdMarkDirty(---J-)
613D [28/Apr/2017:17:01:04 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
614D [28/Apr/2017:17:01:04 +0000] Discarding unused printer-state-changed event...
615D [28/Apr/2017:17:01:04 +0000] [Job 1] Device protocol: 2
616I [28/Apr/2017:17:01:04 +0000] [Job 1] Sending data to printer.
617D [28/Apr/2017:17:01:04 +0000] cupsdMarkDirty(---J-)
618D [28/Apr/2017:17:01:04 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
619D [28/Apr/2017:17:01:04 +0000] [Job 1] Set job-printer-state-message to "Sending data to printer.", current level=INFO
620D [28/Apr/2017:17:01:04 +0000] Discarding unused job-progress event...
621D [28/Apr/2017:17:01:04 +0000] Discarding unused printer-state-changed event...
622D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 512 bytes of back-channel data...
623D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 512 bytes of back-channel data...
624D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 421 bytes of back-channel data...
625D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 512 bytes of back-channel data...
626D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 512 bytes of back-channel data...
627D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 421 bytes of back-channel data...
628D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 512 bytes of back-channel data...
629D [28/Apr/2017:17:01:04 +0000] [Job 1] Read 512 bytes of back-channel data...
630D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: ============================================================
631D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: VVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVV
632D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: 5.2.11 Starting
633D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: command line: Canon_MG7500_USB \'1\' \'anonymous\' \'Test Page\' \'1\' <args>
634D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: using PPD file /@unixroot/etc/cups/ppd/Canon_MG7500_USB.ppd
635D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: CUPS option count is 6 (196 bytes)
636D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: CUPS option 0 date-time-at-creation =
637D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: CUPS option 1 date-time-at-processing =
638D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: CUPS option 2 job-originating-host-name = localhost
639D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: CUPS option 3 job-uuid = urn:uuid:98225ce9-8309-3a47-62fb-e422312df770
640D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: CUPS option 4 time-at-creation = 1493395263
641D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: CUPS option 5 time-at-processing = 1493395263
642D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Driver Canon PIXMA MG7550
643D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Using fd 0
644D [28/Apr/2017:17:01:05 +0000] [Job 1] PDF template file doesn\'t have form. It\'s okay.
645D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set options:
646D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting DitherAlgorithm to (null)
647D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting PageSize to (null)
648D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting MediaType to (null)
649D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting InputSlot to (null)
650D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set string CassetteTray to Default
651D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set special string CassetteTray to Default
652D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set string CDInnerRadius to None
653D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set special string CDInnerRadius to None
654D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CDOuterDiameter to (null)
655D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CDInnerDiameter to (null)
656D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CDXAdjustment to (null)
657D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CDYAdjustment to (null)
658D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting Resolution to (null)
659D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set string InkType to CMYK
660D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set special string InkType to CMYK
661D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting InkChannels to (null)
662D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting PrintingMode to (null)
663D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set string InkSet to None
664D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set special string InkSet to None
665D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set bool FullBleed to False (0)
666D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting Duplex to (null)
667D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set string Quality to Standard
668D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set special string Quality to Standard
669D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set string ColorCorrection to None
670D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set special string ColorCorrection to None
671D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting ChannelBitDepth to (null)
672D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting InputImageType to (null)
673D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting STPIOutputType to (null)
674D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting STPIRawChannels to (null)
675D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting SimpleGamma to (null)
676D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting LinearContrast to (null)
677D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting LUTDumpFile to (null)
678D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CyanCurve to (null)
679D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting MagentaCurve to (null)
680D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting YellowCurve to (null)
681D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting BlackCurve to (null)
682D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting RedCurve to (null)
683D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting GreenCurve to (null)
684D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting BlueCurve to (null)
685D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting WhiteCurve to (null)
686D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting HueMap to (null)
687D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting SatMap to (null)
688D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting LumMap to (null)
689D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting GCRCurve to (null)
690D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh0 to (null)
691D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh1 to (null)
692D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh2 to (null)
693D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh3 to (null)
694D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh4 to (null)
695D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh5 to (null)
696D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh6 to (null)
697D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh7 to (null)
698D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh8 to (null)
699D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh9 to (null)
700D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh10 to (null)
701D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh11 to (null)
702D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh12 to (null)
703D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh13 to (null)
704D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh14 to (null)
705D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh15 to (null)
706D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh16 to (null)
707D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh17 to (null)
708D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh18 to (null)
709D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh19 to (null)
710D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh20 to (null)
711D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh21 to (null)
712D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh22 to (null)
713D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh23 to (null)
714D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh24 to (null)
715D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh25 to (null)
716D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh26 to (null)
717D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh27 to (null)
718D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh28 to (null)
719D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh29 to (null)
720D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh30 to (null)
721D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh31 to (null)
722D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh32 to (null)
723D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh33 to (null)
724D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh34 to (null)
725D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh35 to (null)
726D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh36 to (null)
727D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh37 to (null)
728D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh38 to (null)
729D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh39 to (null)
730D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh40 to (null)
731D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh41 to (null)
732D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh42 to (null)
733D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh43 to (null)
734D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh44 to (null)
735D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh45 to (null)
736D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh46 to (null)
737D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh47 to (null)
738D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh48 to (null)
739D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh49 to (null)
740D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh50 to (null)
741D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh51 to (null)
742D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh52 to (null)
743D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh53 to (null)
744D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh54 to (null)
745D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh55 to (null)
746D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh56 to (null)
747D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh57 to (null)
748D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh58 to (null)
749D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh59 to (null)
750D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh60 to (null)
751D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh61 to (null)
752D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh62 to (null)
753D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting CurveCh63 to (null)
754D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set string ImageType to TextGraphics
755D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Set special string ImageType to TextGraphics
756D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting JobMode to (null)
757D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: Not setting PageNumber to (null)
758D [28/Apr/2017:17:01:05 +0000] [Job 1] Gutenprint: End options
759W [28/Apr/2017:17:01:05 +0000] cupsdDoSelect: select() returned -1... pause and retry select()
760D [28/Apr/2017:17:01:05 +0000] [Job 1] Color Manager: Calibration Mode/Off
761D [28/Apr/2017:17:01:05 +0000] [Job 1] WARN: not compiled with DBus support
762D [28/Apr/2017:17:01:05 +0000] [Job 1] WARN: not compiled with DBus support
763I [28/Apr/2017:17:01:05 +0000] [Job 1] Color Manager: no profiles specified in PPD
764D [28/Apr/2017:17:01:05 +0000] cupsdMarkDirty(---J-)
765D [28/Apr/2017:17:01:05 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
766D [28/Apr/2017:17:01:05 +0000] [Job 1] Set job-printer-state-message to "Color Manager: no profiles specified in PPD", current level=INFO
767D [28/Apr/2017:17:01:05 +0000] [Job 1] Color Manager: ICC Profile: None
768D [28/Apr/2017:17:01:05 +0000] [Job 1] Ghostscript command line: /@unixroot/usr/bin/gs.exe -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -sDEVICE=cups -sstdout=%stderr -sOutputFile=%stdout -sMediaClass=Cassette -sMediaType=Plain -r600x600 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=1 -dcupsRowFeed=2 -scupsPageSizeName=A4 -I/@unixroot/usr/share/cups/fonts -c \'<</.HWMargins[0.000000 0.000000 0.000000 0.000000] /Margins[0 0]>>setpagedevice\' -f -_
769D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[0]=\"CUPS_CACHEDIR=/@unixroot/var/cache/cups\"
770D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[1]=\"CUPS_DATADIR=/@unixroot/usr/share/cups\"
771D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[2]=\"CUPS_DOCROOT=/@unixroot/usr/share/doc/cups\"
772D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[3]=\"CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts\"
773D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[4]=\"CUPS_REQUESTROOT=/@unixroot/var/spool/cups\"
774D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[5]=\"CUPS_SERVERBIN=/@unixroot/usr/lib/cups\"
775D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[6]=\"CUPS_SERVERROOT=/@unixroot/etc/cups\"
776D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[7]=\"CUPS_STATEDIR=/@unixroot/var/run/cups\"
777D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[8]=\"HOME=I:\\TEMP\"
778D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[9]=\"NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;\"
779D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[10]=\"PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin\"
780D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[11]=\"SERVER_ADMIN=root@TM5320\"
781D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[12]=\"SOFTWARE=CUPS/2.1.3\"
782D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[13]=\"TMPDIR=I:\\TEMP\"
783D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[14]=\"TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600\"
784D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[15]=\"USER=root\"
785D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[16]=\"UNIXROOT=I:\"
786D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[17]=\"CUPS_MAX_MESSAGE=2047\"
787D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[18]=\"CUPS_SERVER=localhost\"
788D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[19]=\"CUPS_ENCRYPTION=IfRequested\"
789D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[20]=\"IPP_PORT=631\"
790D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[21]=\"CHARSET=utf-8\"
791D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[22]=\"LANG=en_US.UTF-8\"
792D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[23]=\"PPD=/@unixroot/etc/cups/ppd/Canon_MG7500_USB.ppd\"
793D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[24]=\"RIP_MAX_CACHE=128m\"
794D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[25]=\"CONTENT_TYPE=application/vnd.cups-pdf-banner\"
795D [28/Apr/2017:17:01:05 +0000] Discarding unused job-progress event...
796D [28/Apr/2017:17:01:05 +0000] Discarding unused printer-state-changed event...
797D [28/Apr/2017:17:01:05 +0000] [Job 1] PID 125 (/@unixroot/usr/lib/cups/filter/bannertopdf.exe) exited with no errors.
798D [28/Apr/2017:17:01:05 +0000] [Job 1] PID 126 (/@unixroot/usr/lib/cups/filter/pdftopdf.exe) exited with no errors.
799D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[26]=\"DEVICE_URI=usb://Canon/MG7500%20series?serial=117758&interface=1\"
800D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[27]=\"PRINTER_INFO=Canon MG7500 series\"
801D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[28]=\"PRINTER_LOCATION=Local Printer\"
802D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[29]=\"PRINTER=Canon_MG7500_USB\"
803D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[30]=\"PRINTER_STATE_REASONS=none\"
804D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[31]=\"CUPS_FILETYPE=document\"
805D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[32]=\"FINAL_CONTENT_TYPE=application/vnd.cups-raster\"
806D [28/Apr/2017:17:01:05 +0000] [Job 1] envp[33]=\"AUTH_INFO_REQUIRED=none\"
807D [28/Apr/2017:17:01:05 +0000] [Job 1] Read 421 bytes of back-channel data...
808D [28/Apr/2017:17:01:06 +0000] [Client 2] GET /printers/Canon_MG7500_USB HTTP/1.1
809D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
810D [28/Apr/2017:17:01:06 +0000] [Client 2] Read: status=200
811D [28/Apr/2017:17:01:06 +0000] [Client 2] No authentication data provided.
812D [28/Apr/2017:17:01:06 +0000] [Client 2] Processing GET /printers/Canon_MG7500_USB
813D [28/Apr/2017:17:01:06 +0000] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
814D [28/Apr/2017:17:01:06 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
815D [28/Apr/2017:17:01:06 +0000] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
816D [28/Apr/2017:17:01:06 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
817D [28/Apr/2017:17:01:06 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
818D [28/Apr/2017:17:01:06 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
819D [28/Apr/2017:17:01:06 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
820D [28/Apr/2017:17:01:06 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
821D [28/Apr/2017:17:01:06 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
822D [28/Apr/2017:17:01:06 +0000] [CGI] envp[8] = "HOME=I:\\TEMP"
823D [28/Apr/2017:17:01:06 +0000] [CGI] envp[9] = "NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
824D [28/Apr/2017:17:01:06 +0000] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
825D [28/Apr/2017:17:01:06 +0000] [CGI] envp[11] = "SERVER_ADMIN=root@TM5320"
826D [28/Apr/2017:17:01:06 +0000] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
827D [28/Apr/2017:17:01:06 +0000] [CGI] envp[13] = "TMPDIR=I:\\TEMP"
828D [28/Apr/2017:17:01:06 +0000] [CGI] envp[14] = "TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
829D [28/Apr/2017:17:01:06 +0000] [CGI] envp[15] = "USER=root"
830D [28/Apr/2017:17:01:06 +0000] [CGI] envp[16] = "UNIXROOT=I:"
831D [28/Apr/2017:17:01:06 +0000] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
832D [28/Apr/2017:17:01:06 +0000] [CGI] envp[18] = "CUPS_SERVER=localhost"
833D [28/Apr/2017:17:01:06 +0000] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
834D [28/Apr/2017:17:01:06 +0000] [CGI] envp[20] = "IPP_PORT=631"
835D [28/Apr/2017:17:01:06 +0000] [CGI] envp[21] = "LANG=en_US.UTF8"
836D [28/Apr/2017:17:01:06 +0000] [CGI] envp[22] = "REDIRECT_STATUS=1"
837D [28/Apr/2017:17:01:06 +0000] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
838D [28/Apr/2017:17:01:06 +0000] [CGI] envp[24] = "SERVER_NAME=localhost"
839D [28/Apr/2017:17:01:06 +0000] [CGI] envp[25] = "SERVER_PORT=631"
840D [28/Apr/2017:17:01:06 +0000] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
841D [28/Apr/2017:17:01:06 +0000] [CGI] envp[27] = "REMOTE_HOST=localhost"
842D [28/Apr/2017:17:01:06 +0000] [CGI] envp[28] = "SCRIPT_NAME=/printers/Canon_MG7500_USB"
843D [28/Apr/2017:17:01:06 +0000] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/Canon_MG7500_USB"
844D [28/Apr/2017:17:01:06 +0000] [CGI] envp[30] = "PATH_INFO=/Canon_MG7500_USB"
845D [28/Apr/2017:17:01:06 +0000] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
846D [28/Apr/2017:17:01:06 +0000] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=76832da10be696dc76bac386d11f13bc"
847D [28/Apr/2017:17:01:06 +0000] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0 SeaMonkey/2.35"
848D [28/Apr/2017:17:01:06 +0000] [CGI] envp[34] = "REQUEST_METHOD=GET"
849D [28/Apr/2017:17:01:06 +0000] [CGI] envp[35] = "QUERY_STRING="
850D [28/Apr/2017:17:01:06 +0000] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 137)
851I [28/Apr/2017:17:01:06 +0000] [Client 2] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=137, file=10)
852D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
853D [28/Apr/2017:17:01:06 +0000] [Client 8] Accepted from localhost:55544 (IPv4)
854D [28/Apr/2017:17:01:06 +0000] [Client 8] Waiting for request.
855D [28/Apr/2017:17:01:06 +0000] [CGI] org.cups.sid cookie is \"76832da10be696dc76bac386d11f13bc\"
856D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
857D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
858D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
859D [28/Apr/2017:17:01:06 +0000] [Client 8] POST / HTTP/1.1
860D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
861D [28/Apr/2017:17:01:06 +0000] [Client 8] Read: status=200
862D [28/Apr/2017:17:01:06 +0000] [Client 8] No authentication data provided.
863D [28/Apr/2017:17:01:06 +0000] [Client 8] 2.0 CUPS-Get-Default 1
864D [28/Apr/2017:17:01:06 +0000] CUPS-Get-Default
865D [28/Apr/2017:17:01:06 +0000] CUPS-Get-Default client-error-not-found: No default printer.
866D [28/Apr/2017:17:01:06 +0000] [Client 8] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
867D [28/Apr/2017:17:01:06 +0000] [Client 8] Content-Length: 113
868D [28/Apr/2017:17:01:06 +0000] [Client 8] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
869D [28/Apr/2017:17:01:06 +0000] [Client 8] con->http=0x202edd20
870D [28/Apr/2017:17:01:06 +0000] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x202e65c0(IPP_STATE_DATA), pipe_pid=0, file=-1
871D [28/Apr/2017:17:01:06 +0000] [Client 8] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
872D [28/Apr/2017:17:01:06 +0000] [Client 8] bytes=0, http_state=0, data_remaining=113
873D [28/Apr/2017:17:01:06 +0000] [Client 8] Flushing write buffer.
874D [28/Apr/2017:17:01:06 +0000] [Client 8] New state is HTTP_STATE_WAITING
875D [28/Apr/2017:17:01:06 +0000] [Client 8] Waiting for request.
876D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
877D [28/Apr/2017:17:01:06 +0000] [CGI] show_printer(http=0x2003c340, printer=\"Canon_MG7500_USB\")
878D [28/Apr/2017:17:01:06 +0000] [Client 8] POST / HTTP/1.1
879D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
880D [28/Apr/2017:17:01:06 +0000] [Client 8] Read: status=200
881D [28/Apr/2017:17:01:06 +0000] [Client 8] No authentication data provided.
882D [28/Apr/2017:17:01:06 +0000] [Client 8] 2.0 Get-Printer-Attributes 2
883D [28/Apr/2017:17:01:06 +0000] Get-Printer-Attributes ipp://localhost/printers/Canon_MG7500_USB
884D [28/Apr/2017:17:01:06 +0000] [Client 8] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MG7500_USB) from localhost
885D [28/Apr/2017:17:01:06 +0000] [Client 8] Content-Length: 729
886D [28/Apr/2017:17:01:06 +0000] [Client 8] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
887D [28/Apr/2017:17:01:06 +0000] [Client 8] con->http=0x202edd20
888D [28/Apr/2017:17:01:06 +0000] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=729, response=0x202e6600(IPP_STATE_DATA), pipe_pid=0, file=-1
889D [28/Apr/2017:17:01:06 +0000] [Client 8] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
890D [28/Apr/2017:17:01:06 +0000] [Client 8] bytes=0, http_state=0, data_remaining=729
891D [28/Apr/2017:17:01:06 +0000] [Client 8] Flushing write buffer.
892D [28/Apr/2017:17:01:06 +0000] [Client 8] New state is HTTP_STATE_WAITING
893D [28/Apr/2017:17:01:06 +0000] [Client 8] Waiting for request.
894D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
895D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
896D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
897D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
898D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
899D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
900D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
901D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_state[0]=\"4\"
902D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
903D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/Canon_MG7500_USB\"
904D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_name[0]=\"Canon_MG7500_USB\"
905D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_location[0]=\"Local Printer\"
906D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_info[0]=\"Canon MG7500 series\"
907D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
908D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: device_uri[0]=\"usb://Canon/MG7500%20series?serial=117758&interface=1\"
909D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: color_supported[0]=\"1\"
910D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_make_and_model[0]=\"Canon PIXMA MG7550 - CUPS+Gutenprint v5.2.11 Simplified\"
911D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
912D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
913D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
914D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: printer_commands[0]=\"none\"
915D [28/Apr/2017:17:01:06 +0000] [Client 2] CGI data ready to be sent.
916D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
917D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: refresh_page=\"10;URL=/printers/Canon_MG7500_USB\"
918D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: TITLE=\"Canon_MG7500_USB\"
919D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
920D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
921D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
922D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=137, file=10
923D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
924D [28/Apr/2017:17:01:06 +0000] [Client 2] Script header: Content-Type: text/html;charset=utf-8
925D [28/Apr/2017:17:01:06 +0000] [Client 2] Script header:
926D [28/Apr/2017:17:01:06 +0000] [Client 2] Sending status 200 for CGI.
927D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdSendHeader: code=200, type="(null)", auth_type=0
928D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
929D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
930D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
931D [28/Apr/2017:17:01:06 +0000] [Client 2] CGI data ready to be sent.
932D [28/Apr/2017:17:01:06 +0000] [Client 8] POST / HTTP/1.1
933D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
934D [28/Apr/2017:17:01:06 +0000] [Client 8] Read: status=200
935D [28/Apr/2017:17:01:06 +0000] [Client 8] No authentication data provided.
936D [28/Apr/2017:17:01:06 +0000] [Client 8] 2.0 Get-Jobs 3
937D [28/Apr/2017:17:01:06 +0000] Get-Jobs ipp://localhost:631/printers/Canon_MG7500_USB
938D [28/Apr/2017:17:01:06 +0000] [Client 8] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_MG7500_USB) from localhost
939D [28/Apr/2017:17:01:06 +0000] [Client 8] Content-Length: 438
940D [28/Apr/2017:17:01:06 +0000] [Client 8] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
941D [28/Apr/2017:17:01:06 +0000] [CGI] Regular expression \".*Clean.*\"
942D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
943D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
944D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
945D [28/Apr/2017:17:01:06 +0000] [Client 8] con->http=0x202edd20
946D [28/Apr/2017:17:01:06 +0000] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=438, response=0x202e6840(IPP_STATE_DATA), pipe_pid=0, file=-1
947D [28/Apr/2017:17:01:06 +0000] [Client 8] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
948D [28/Apr/2017:17:01:06 +0000] [Client 8] bytes=0, http_state=0, data_remaining=438
949D [28/Apr/2017:17:01:06 +0000] [Client 8] Flushing write buffer.
950D [28/Apr/2017:17:01:06 +0000] [Client 8] New state is HTTP_STATE_WAITING
951D [28/Apr/2017:17:01:06 +0000] [Client 8] Waiting for request.
952D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
953D [28/Apr/2017:17:01:06 +0000] [CGI] Regular expression \".*PrintSelfTestPage.*\"
954D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
955D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
956D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
957D [28/Apr/2017:17:01:06 +0000] [CGI] cgiClearVariables called.
958D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: ORDER=\"asc\"
959D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
960D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: TOTAL=\"1\"
961D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
962D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
963D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_printer_name[0]=\"Canon_MG7500_USB\"
964D [28/Apr/2017:17:01:06 +0000] [Client 2] CGI data ready to be sent.
965D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/Canon_MG7500_USB\"
966D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
967D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
968D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
969D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: time_at_creation[0]=\"Fri Apr 28 17:01:03 BST 2017\"
970D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: time_at_processing[0]=\"Fri Apr 28 17:01:03 BST 2017\"
971D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_id[0]=\"1\"
972D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_state[0]=\"5\"
973D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"0\"
974D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
975D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetArray: job_printer_state_message[0]=\"Color Manager: no profiles specified in PPD\"
976D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
977D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/Canon_MG7500_USB\"
978D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: THISURL=\"/printers/Canon_MG7500_USB\"
979D [28/Apr/2017:17:01:06 +0000] [CGI] cgiSetVariable: SEARCH_DEST=\"Canon_MG7500_USB\"
980D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
981D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
982D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
983D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
984D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
985D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
986D [28/Apr/2017:17:01:06 +0000] [Client 2] CGI data ready to be sent.
987D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
988D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
989D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
990D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
991D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
992D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
993D [28/Apr/2017:17:01:06 +0000] [Client 2] CGI data ready to be sent.
994D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
995D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
996D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
997D [28/Apr/2017:17:01:06 +0000] PID 137 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
998D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
999D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
1000D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
1001D [28/Apr/2017:17:01:06 +0000] [Client 2] CGI data ready to be sent.
1002D [28/Apr/2017:17:01:06 +0000] [Client 8] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1003D [28/Apr/2017:17:01:06 +0000] [Client 8] Closing connection.
1004D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
1005D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
1006D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
1007D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
1008D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
1009D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
1010D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
1011D [28/Apr/2017:17:01:06 +0000] [Client 2] CGI data ready to be sent.
1012D [28/Apr/2017:17:01:06 +0000] [Client 2] con->http=0x202eacc0
1013D [28/Apr/2017:17:01:06 +0000] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=137, file=10
1014D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for CGI data.
1015D [28/Apr/2017:17:01:06 +0000] [Client 2] Sending 0-length chunk.
1016D [28/Apr/2017:17:01:06 +0000] [Client 2] Flushing write buffer.
1017D [28/Apr/2017:17:01:06 +0000] [Client 2] New state is HTTP_STATE_WAITING
1018D [28/Apr/2017:17:01:06 +0000] [Client 2] Waiting for request.
1019D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
1020D [28/Apr/2017:17:01:06 +0000] [Client 2] GET /cups.css HTTP/1.1
1021D [28/Apr/2017:17:01:06 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
1022D [28/Apr/2017:17:01:06 +0000] [Client 2] Read: status=200
1023D [28/Apr/2017:17:01:06 +0000] [Client 2] No authentication data provided.
1024D [28/Apr/2017:17:01:06 +0000] [Client 2] Processing GET /cups.css
1025D [28/Apr/2017:17:01:07 +0000] [Client 2] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
1026D [28/Apr/2017:17:01:07 +0000] [Client 2] cupsdSendHeader: code=304, type="(null)", auth_type=0
1027D [28/Apr/2017:17:01:07 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
1028D [28/Apr/2017:17:01:07 +0000] [Job 1] Read 512 bytes of back-channel data...
1029I [28/Apr/2017:17:01:07 +0000] [Job 1] Start rendering...
1030D [28/Apr/2017:17:01:07 +0000] cupsdMarkDirty(---J-)
1031D [28/Apr/2017:17:01:07 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
1032D [28/Apr/2017:17:01:07 +0000] [Job 1] Set job-printer-state-message to "Start rendering...", current level=INFO
1033I [28/Apr/2017:17:01:07 +0000] [Job 1] Processing page 1...
1034D [28/Apr/2017:17:01:07 +0000] cupsdMarkDirty(---J-)
1035D [28/Apr/2017:17:01:07 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
1036D [28/Apr/2017:17:01:07 +0000] [Job 1] Set job-printer-state-message to "Processing page 1...", current level=INFO
1037D [28/Apr/2017:17:01:07 +0000] Discarding unused job-progress event...
1038D [28/Apr/2017:17:01:07 +0000] Discarding unused printer-state-changed event...
1039D [28/Apr/2017:17:01:07 +0000] [Job 1] Gutenprint: About to start printing loop.
1040D [28/Apr/2017:17:01:07 +0000] [Job 1] Gutenprint: stats 0B, 3.420u, 0.000s, 3.312el
1041D [28/Apr/2017:17:01:07 +0000] [Job 1] Gutenprint: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
1042D [28/Apr/2017:17:01:07 +0000] [Job 1] Gutenprint: ============================================================
1043D [28/Apr/2017:17:01:07 +0000] [Job 1] Sent 0 bytes...
1044D [28/Apr/2017:17:01:07 +0000] [Job 1] Waiting for read thread to exit...
1045D [28/Apr/2017:17:01:07 +0000] [Job 1] PID 129 (/@unixroot/usr/lib/cups/filter/gstoraster.exe) stopped with status 11.
1046W [28/Apr/2017:17:01:07 +0000] cupsdDoSelect: select() returned -1... pause and retry select()
1047D [28/Apr/2017:17:01:07 +0000] [Job 1] Read 512 bytes of back-channel data...
1048D [28/Apr/2017:17:01:07 +0000] [Job 1] PID 130 (/@unixroot/usr/lib/cups/filter/rastertogutenprint.5.2.exe) exited with no errors.
1049D [28/Apr/2017:17:01:07 +0000] [Job 1] PID 133 (/@unixroot/usr/lib/cups/backend/usb.exe) exited with no errors.
1050D [28/Apr/2017:17:01:07 +0000] Discarding unused job-state-changed event...
1051E [28/Apr/2017:17:01:07 +0000] [Job 1] Job stopped due to filter errors; please consult the error_log file for details.
1052D [28/Apr/2017:17:01:07 +0000] cupsdMarkDirty(---J-)
1053D [28/Apr/2017:17:01:07 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
1054D [28/Apr/2017:17:01:07 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
1055D [28/Apr/2017:17:01:07 +0000] Discarding unused printer-state-changed event...
1056D [28/Apr/2017:17:01:07 +0000] [Job 1] The following messages were recorded from 17:01:04 to 17:01:04
1057D [28/Apr/2017:17:01:07 +0000] [Job 1] Printer found with device ID: MFG:Canon;CMD:BJL,BJRaster3,BSCCe,NCCe,IVEC,IVECPLI;SOJ:BJNP2,BJNPe;MDL:MG7500 series;CLS:PRINTER;DES:Canon MG7500 series;VER:4.000;STA:10;FSI:03;HRI:D;MSI:AOFF,B240,DAT,E3,H2FSF,JOFF,K21000700;PDR:4;PSE:ADPJ03574;CID:CA_IVEC1TYPE4_IJP; Device URI: usb://Canon/MG7500%20series?serial=117758&interface=1
1058D [28/Apr/2017:17:01:07 +0000] [Job 1] End of messages
1059D [28/Apr/2017:17:01:07 +0000] [Job 1] printer-state=3(idle)
1060D [28/Apr/2017:17:01:07 +0000] [Job 1] printer-state-message="Filter failed"
1061D [28/Apr/2017:17:01:07 +0000] [Job 1] printer-state-reasons=none
1062D [28/Apr/2017:17:01:08 +0000] [Job 1] Unloading...
1063D [28/Apr/2017:17:01:09 +0000] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1064D [28/Apr/2017:17:01:09 +0000] [Client 7] Closing connection.
1065D [28/Apr/2017:17:01:09 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
1066D [28/Apr/2017:17:01:17 +0000] [Client 9] Accepted from localhost:55545 (IPv4)
1067D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for request.
1068D [28/Apr/2017:17:01:17 +0000] [Client 2] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1069D [28/Apr/2017:17:01:17 +0000] [Client 2] Closing connection.
1070D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
1071D [28/Apr/2017:17:01:17 +0000] [Client 9] GET /printers/Canon_MG7500_USB HTTP/1.1
1072D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
1073D [28/Apr/2017:17:01:17 +0000] [Client 9] Read: status=200
1074D [28/Apr/2017:17:01:17 +0000] [Client 9] No authentication data provided.
1075D [28/Apr/2017:17:01:17 +0000] [Client 9] Processing GET /printers/Canon_MG7500_USB
1076D [28/Apr/2017:17:01:17 +0000] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
1077D [28/Apr/2017:17:01:17 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
1078D [28/Apr/2017:17:01:17 +0000] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
1079D [28/Apr/2017:17:01:17 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
1080D [28/Apr/2017:17:01:17 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
1081D [28/Apr/2017:17:01:17 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
1082D [28/Apr/2017:17:01:17 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
1083D [28/Apr/2017:17:01:17 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
1084D [28/Apr/2017:17:01:17 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
1085D [28/Apr/2017:17:01:17 +0000] [CGI] envp[8] = "HOME=I:\\TEMP"
1086D [28/Apr/2017:17:01:17 +0000] [CGI] envp[9] = "NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
1087D [28/Apr/2017:17:01:17 +0000] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
1088D [28/Apr/2017:17:01:17 +0000] [CGI] envp[11] = "SERVER_ADMIN=root@TM5320"
1089D [28/Apr/2017:17:01:17 +0000] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
1090D [28/Apr/2017:17:01:17 +0000] [CGI] envp[13] = "TMPDIR=I:\\TEMP"
1091D [28/Apr/2017:17:01:17 +0000] [CGI] envp[14] = "TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
1092D [28/Apr/2017:17:01:17 +0000] [CGI] envp[15] = "USER=root"
1093D [28/Apr/2017:17:01:17 +0000] [CGI] envp[16] = "UNIXROOT=I:"
1094D [28/Apr/2017:17:01:17 +0000] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
1095D [28/Apr/2017:17:01:17 +0000] [CGI] envp[18] = "CUPS_SERVER=localhost"
1096D [28/Apr/2017:17:01:17 +0000] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
1097D [28/Apr/2017:17:01:17 +0000] [CGI] envp[20] = "IPP_PORT=631"
1098D [28/Apr/2017:17:01:17 +0000] [CGI] envp[21] = "LANG=en_US.UTF8"
1099D [28/Apr/2017:17:01:17 +0000] [CGI] envp[22] = "REDIRECT_STATUS=1"
1100D [28/Apr/2017:17:01:17 +0000] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
1101D [28/Apr/2017:17:01:17 +0000] [CGI] envp[24] = "SERVER_NAME=localhost"
1102D [28/Apr/2017:17:01:17 +0000] [CGI] envp[25] = "SERVER_PORT=631"
1103D [28/Apr/2017:17:01:17 +0000] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
1104D [28/Apr/2017:17:01:17 +0000] [CGI] envp[27] = "REMOTE_HOST=localhost"
1105D [28/Apr/2017:17:01:17 +0000] [CGI] envp[28] = "SCRIPT_NAME=/printers/Canon_MG7500_USB"
1106D [28/Apr/2017:17:01:17 +0000] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/Canon_MG7500_USB"
1107D [28/Apr/2017:17:01:17 +0000] [CGI] envp[30] = "PATH_INFO=/Canon_MG7500_USB"
1108D [28/Apr/2017:17:01:17 +0000] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
1109D [28/Apr/2017:17:01:17 +0000] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=76832da10be696dc76bac386d11f13bc"
1110D [28/Apr/2017:17:01:17 +0000] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0 SeaMonkey/2.35"
1111D [28/Apr/2017:17:01:17 +0000] [CGI] envp[34] = "REQUEST_METHOD=GET"
1112D [28/Apr/2017:17:01:17 +0000] [CGI] envp[35] = "QUERY_STRING="
1113D [28/Apr/2017:17:01:17 +0000] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 139)
1114I [28/Apr/2017:17:01:17 +0000] [Client 9] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=139, file=9)
1115D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1116D [28/Apr/2017:17:01:17 +0000] [Client 10] Accepted from localhost:55546 (IPv4)
1117D [28/Apr/2017:17:01:17 +0000] [Client 10] Waiting for request.
1118D [28/Apr/2017:17:01:17 +0000] [CGI] org.cups.sid cookie is \"76832da10be696dc76bac386d11f13bc\"
1119D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
1120D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
1121D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
1122D [28/Apr/2017:17:01:17 +0000] [Client 10] POST / HTTP/1.1
1123D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1124D [28/Apr/2017:17:01:17 +0000] [Client 10] Read: status=200
1125D [28/Apr/2017:17:01:17 +0000] [Client 10] No authentication data provided.
1126D [28/Apr/2017:17:01:17 +0000] [Client 10] 2.0 CUPS-Get-Default 1
1127D [28/Apr/2017:17:01:17 +0000] CUPS-Get-Default
1128D [28/Apr/2017:17:01:17 +0000] CUPS-Get-Default client-error-not-found: No default printer.
1129D [28/Apr/2017:17:01:17 +0000] [Client 10] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
1130D [28/Apr/2017:17:01:17 +0000] [Client 10] Content-Length: 113
1131D [28/Apr/2017:17:01:17 +0000] [Client 10] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1132D [28/Apr/2017:17:01:17 +0000] [Client 10] con->http=0x202eacc0
1133D [28/Apr/2017:17:01:17 +0000] [Client 10] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x201e2fe0(IPP_STATE_DATA), pipe_pid=0, file=-1
1134D [28/Apr/2017:17:01:17 +0000] [Client 10] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1135D [28/Apr/2017:17:01:17 +0000] [Client 10] bytes=0, http_state=0, data_remaining=113
1136D [28/Apr/2017:17:01:17 +0000] [Client 10] Flushing write buffer.
1137D [28/Apr/2017:17:01:17 +0000] [Client 10] New state is HTTP_STATE_WAITING
1138D [28/Apr/2017:17:01:17 +0000] [Client 10] Waiting for request.
1139D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1140D [28/Apr/2017:17:01:17 +0000] [CGI] show_printer(http=0x2003c340, printer=\"Canon_MG7500_USB\")
1141D [28/Apr/2017:17:01:17 +0000] [Client 10] POST / HTTP/1.1
1142D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1143D [28/Apr/2017:17:01:17 +0000] [Client 10] Read: status=200
1144D [28/Apr/2017:17:01:17 +0000] [Client 10] No authentication data provided.
1145D [28/Apr/2017:17:01:17 +0000] [Client 10] 2.0 Get-Printer-Attributes 2
1146D [28/Apr/2017:17:01:17 +0000] Get-Printer-Attributes ipp://localhost/printers/Canon_MG7500_USB
1147D [28/Apr/2017:17:01:17 +0000] [Client 10] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MG7500_USB) from localhost
1148D [28/Apr/2017:17:01:17 +0000] [Client 10] Content-Length: 729
1149D [28/Apr/2017:17:01:17 +0000] [Client 10] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1150D [28/Apr/2017:17:01:17 +0000] [Client 10] con->http=0x202eacc0
1151D [28/Apr/2017:17:01:17 +0000] [Client 10] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=729, response=0x2005e920(IPP_STATE_DATA), pipe_pid=0, file=-1
1152D [28/Apr/2017:17:01:17 +0000] [Client 10] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1153D [28/Apr/2017:17:01:17 +0000] [Client 10] bytes=0, http_state=0, data_remaining=729
1154D [28/Apr/2017:17:01:17 +0000] [Client 10] Flushing write buffer.
1155D [28/Apr/2017:17:01:17 +0000] [Client 10] New state is HTTP_STATE_WAITING
1156D [28/Apr/2017:17:01:17 +0000] [Client 10] Waiting for request.
1157D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1158D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1159D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1160D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1161D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1162D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
1163D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
1164D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_state[0]=\"3\"
1165D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
1166D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/Canon_MG7500_USB\"
1167D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_name[0]=\"Canon_MG7500_USB\"
1168D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_location[0]=\"Local Printer\"
1169D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_info[0]=\"Canon MG7500 series\"
1170D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
1171D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: device_uri[0]=\"usb://Canon/MG7500%20series?serial=117758&interface=1\"
1172D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: color_supported[0]=\"1\"
1173D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_make_and_model[0]=\"Canon PIXMA MG7550 - CUPS+Gutenprint v5.2.11 Simplified\"
1174D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
1175D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
1176D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
1177D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: printer_commands[0]=\"none\"
1178D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1179D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
1180D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: TITLE=\"Canon_MG7500_USB\"
1181D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1182D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1183D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1184D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=139, file=9
1185D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1186D [28/Apr/2017:17:01:17 +0000] [Client 9] Script header: Content-Type: text/html;charset=utf-8
1187D [28/Apr/2017:17:01:17 +0000] [Client 9] Script header:
1188D [28/Apr/2017:17:01:17 +0000] [Client 9] Sending status 200 for CGI.
1189D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdSendHeader: code=200, type="(null)", auth_type=0
1190D [28/Apr/2017:17:01:17 +0000] [Client 11] Accepted from localhost:55547 (IPv4)
1191D [28/Apr/2017:17:01:17 +0000] [Client 11] Waiting for request.
1192D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1193D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1194D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1195D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1196D [28/Apr/2017:17:01:17 +0000] [Client 10] POST / HTTP/1.1
1197D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1198D [28/Apr/2017:17:01:17 +0000] [Client 10] Read: status=200
1199D [28/Apr/2017:17:01:17 +0000] [Client 10] No authentication data provided.
1200D [28/Apr/2017:17:01:17 +0000] [Client 10] 2.0 Get-Jobs 3
1201D [28/Apr/2017:17:01:17 +0000] Get-Jobs ipp://localhost:631/printers/Canon_MG7500_USB
1202D [28/Apr/2017:17:01:17 +0000] [Job 1] Loading attributes...
1203D [28/Apr/2017:17:01:17 +0000] [Client 10] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_MG7500_USB) from localhost
1204D [28/Apr/2017:17:01:17 +0000] [Client 10] Content-Length: 427
1205D [28/Apr/2017:17:01:17 +0000] [Client 10] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1206D [28/Apr/2017:17:01:17 +0000] [CGI] Regular expression \".*Clean.*\"
1207D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1208D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1209D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1210D [28/Apr/2017:17:01:17 +0000] [Client 10] con->http=0x202eacc0
1211D [28/Apr/2017:17:01:17 +0000] [Client 10] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=427, response=0x202e4ec0(IPP_STATE_DATA), pipe_pid=0, file=-1
1212D [28/Apr/2017:17:01:17 +0000] [Client 10] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1213D [28/Apr/2017:17:01:17 +0000] [Client 10] bytes=0, http_state=0, data_remaining=427
1214D [28/Apr/2017:17:01:17 +0000] [Client 10] Flushing write buffer.
1215D [28/Apr/2017:17:01:17 +0000] [Client 10] New state is HTTP_STATE_WAITING
1216D [28/Apr/2017:17:01:17 +0000] [Client 10] Waiting for request.
1217D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1218D [28/Apr/2017:17:01:17 +0000] [Client 11] GET /cups.css HTTP/1.1
1219D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1220D [28/Apr/2017:17:01:17 +0000] [Client 11] Read: status=200
1221D [28/Apr/2017:17:01:17 +0000] [Client 11] No authentication data provided.
1222D [28/Apr/2017:17:01:17 +0000] [Client 11] Processing GET /cups.css
1223D [28/Apr/2017:17:01:17 +0000] [Client 11] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
1224D [28/Apr/2017:17:01:17 +0000] [Client 11] cupsdSendHeader: code=304, type="(null)", auth_type=0
1225D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1226D [28/Apr/2017:17:01:17 +0000] [CGI] Regular expression \".*PrintSelfTestPage.*\"
1227D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1228D [28/Apr/2017:17:01:17 +0000] [CGI] cgiClearVariables called.
1229D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: ORDER=\"asc\"
1230D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
1231D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: TOTAL=\"1\"
1232D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1233D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1234D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_preserved[0]=\"1\"
1235D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1236D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1237D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1238D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_printer_name[0]=\"Canon_MG7500_USB\"
1239D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/Canon_MG7500_USB\"
1240D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
1241D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
1242D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
1243D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: time_at_creation[0]=\"Fri Apr 28 17:01:03 BST 2017\"
1244D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: time_at_processing[0]=\"Fri Apr 28 17:01:03 BST 2017\"
1245D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_id[0]=\"1\"
1246D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_state[0]=\"6\"
1247D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"0\"
1248D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
1249D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
1250D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
1251D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/Canon_MG7500_USB\"
1252D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: THISURL=\"/printers/Canon_MG7500_USB\"
1253D [28/Apr/2017:17:01:17 +0000] [CGI] cgiSetVariable: SEARCH_DEST=\"Canon_MG7500_USB\"
1254D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1255D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1256D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1257D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1258D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1259D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1260D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1261D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1262D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1263D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1264D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1265D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1266D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1267D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1268D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1269D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1270D [28/Apr/2017:17:01:17 +0000] PID 139 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
1271D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1272D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1273D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1274D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1275D [28/Apr/2017:17:01:17 +0000] [Client 10] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1276D [28/Apr/2017:17:01:17 +0000] [Client 10] Closing connection.
1277D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1278D [28/Apr/2017:17:01:17 +0000] [Client 9] CGI data ready to be sent.
1279D [28/Apr/2017:17:01:17 +0000] [Client 9] con->http=0x202edd20
1280D [28/Apr/2017:17:01:17 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=139, file=9
1281D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for CGI data.
1282D [28/Apr/2017:17:01:17 +0000] [Client 9] Sending 0-length chunk.
1283D [28/Apr/2017:17:01:17 +0000] [Client 9] Flushing write buffer.
1284D [28/Apr/2017:17:01:17 +0000] [Client 9] New state is HTTP_STATE_WAITING
1285D [28/Apr/2017:17:01:17 +0000] [Client 9] Waiting for request.
1286D [28/Apr/2017:17:01:17 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
1287D [28/Apr/2017:17:01:27 +0000] [Client 9] POST /jobs/ HTTP/1.1
1288D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
1289D [28/Apr/2017:17:01:27 +0000] [Client 9] Read: status=200
1290D [28/Apr/2017:17:01:27 +0000] [Client 9] No authentication data provided.
1291D [28/Apr/2017:17:01:27 +0000] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi"
1292D [28/Apr/2017:17:01:27 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
1293D [28/Apr/2017:17:01:27 +0000] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
1294D [28/Apr/2017:17:01:27 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
1295D [28/Apr/2017:17:01:27 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
1296D [28/Apr/2017:17:01:27 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
1297D [28/Apr/2017:17:01:27 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
1298D [28/Apr/2017:17:01:27 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
1299D [28/Apr/2017:17:01:27 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
1300D [28/Apr/2017:17:01:27 +0000] [CGI] envp[8] = "HOME=I:\\TEMP"
1301D [28/Apr/2017:17:01:27 +0000] [CGI] envp[9] = "NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
1302D [28/Apr/2017:17:01:27 +0000] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
1303D [28/Apr/2017:17:01:27 +0000] [CGI] envp[11] = "SERVER_ADMIN=root@TM5320"
1304D [28/Apr/2017:17:01:27 +0000] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
1305D [28/Apr/2017:17:01:27 +0000] [CGI] envp[13] = "TMPDIR=I:\\TEMP"
1306D [28/Apr/2017:17:01:27 +0000] [CGI] envp[14] = "TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
1307D [28/Apr/2017:17:01:27 +0000] [CGI] envp[15] = "USER=root"
1308D [28/Apr/2017:17:01:27 +0000] [CGI] envp[16] = "UNIXROOT=I:"
1309D [28/Apr/2017:17:01:27 +0000] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
1310D [28/Apr/2017:17:01:27 +0000] [CGI] envp[18] = "CUPS_SERVER=localhost"
1311D [28/Apr/2017:17:01:27 +0000] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
1312D [28/Apr/2017:17:01:27 +0000] [CGI] envp[20] = "IPP_PORT=631"
1313D [28/Apr/2017:17:01:27 +0000] [CGI] envp[21] = "LANG=en_US.UTF8"
1314D [28/Apr/2017:17:01:27 +0000] [CGI] envp[22] = "REDIRECT_STATUS=1"
1315D [28/Apr/2017:17:01:27 +0000] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
1316D [28/Apr/2017:17:01:27 +0000] [CGI] envp[24] = "SERVER_NAME=localhost"
1317D [28/Apr/2017:17:01:27 +0000] [CGI] envp[25] = "SERVER_PORT=631"
1318D [28/Apr/2017:17:01:27 +0000] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
1319D [28/Apr/2017:17:01:27 +0000] [CGI] envp[27] = "REMOTE_HOST=localhost"
1320D [28/Apr/2017:17:01:27 +0000] [CGI] envp[28] = "SCRIPT_NAME=/jobs/"
1321D [28/Apr/2017:17:01:27 +0000] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/jobs/"
1322D [28/Apr/2017:17:01:27 +0000] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
1323D [28/Apr/2017:17:01:27 +0000] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=76832da10be696dc76bac386d11f13bc"
1324D [28/Apr/2017:17:01:27 +0000] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0 SeaMonkey/2.35"
1325D [28/Apr/2017:17:01:27 +0000] [CGI] envp[33] = "HTTP_REFERER=http://localhost:631/printers/Canon_MG7500_USB"
1326D [28/Apr/2017:17:01:27 +0000] [CGI] envp[34] = "REQUEST_METHOD=POST"
1327D [28/Apr/2017:17:01:27 +0000] [CGI] envp[35] = "CONTENT_LENGTH=115"
1328D [28/Apr/2017:17:01:27 +0000] [CGI] envp[36] = "CONTENT_TYPE=application/x-www-form-urlencoded"
1329D [28/Apr/2017:17:01:27 +0000] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/jobs.cgi (PID 141)
1330I [28/Apr/2017:17:01:27 +0000] [Client 9] Started "/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi" (pid=141, file=11)
1331D [28/Apr/2017:17:01:27 +0000] [Client 9] Waiting for CGI data.
1332D [28/Apr/2017:17:01:27 +0000] Report: clients=2
1333D [28/Apr/2017:17:01:27 +0000] Report: jobs=1
1334D [28/Apr/2017:17:01:27 +0000] Report: jobs-active=1
1335D [28/Apr/2017:17:01:27 +0000] Report: printers=2
1336D [28/Apr/2017:17:01:27 +0000] Report: stringpool-string-count=37420
1337D [28/Apr/2017:17:01:27 +0000] Report: stringpool-alloc-bytes=12376
1338D [28/Apr/2017:17:01:27 +0000] Report: stringpool-total-bytes=691912
1339D [28/Apr/2017:17:01:27 +0000] [Client 12] Accepted from localhost:55548 (IPv4)
1340D [28/Apr/2017:17:01:27 +0000] [Client 12] Waiting for request.
1341D [28/Apr/2017:17:01:27 +0000] [CGI] org.cups.sid cookie is \"76832da10be696dc76bac386d11f13bc\"
1342D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: org.cups.sid=\"76832da10be696dc76bac386d11f13bc\"
1343D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: OP=\"cancel-job\"
1344D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: job_id=\"1\"
1345D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: job_printer_uri=\"/printers/Canon_MG7500_USB\"
1346D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: SECTION=\"jobs\"
1347D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
1348D [28/Apr/2017:17:01:27 +0000] [Client 12] POST /jobs HTTP/1.1
1349D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1350D [28/Apr/2017:17:01:27 +0000] [Client 12] Read: status=200
1351D [28/Apr/2017:17:01:27 +0000] [Client 12] No authentication data provided.
1352D [28/Apr/2017:17:01:27 +0000] [Client 12] 2.0 Cancel-Job 1
1353D [28/Apr/2017:17:01:27 +0000] Cancel-Job ipp://localhost/jobs/1
1354D [28/Apr/2017:17:01:27 +0000] cupsdIsAuthorized: requesting-user-name="guest"
1355D [28/Apr/2017:17:01:27 +0000] [Client 12] Returning HTTP Unauthorized for Cancel-Job (ipp://localhost/jobs/1) from localhost
1356D [28/Apr/2017:17:01:27 +0000] [Client 12] cupsdSendHeader: code=401, type="text/html", auth_type=0
1357D [28/Apr/2017:17:01:27 +0000] [Client 12] WWW-Authenticate: Basic realm=\"CUPS\", trc=\"y\"
1358D [28/Apr/2017:17:01:27 +0000] [Client 13] Accepted from localhost:55549 (IPv4)
1359D [28/Apr/2017:17:01:27 +0000] [Client 13] Waiting for request.
1360D [28/Apr/2017:17:01:27 +0000] [Client 12] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1361D [28/Apr/2017:17:01:27 +0000] [Client 12] Closing connection.
1362D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1363D [28/Apr/2017:17:01:27 +0000] [Client 14] Accepted from localhost:55550 (IPv4)
1364D [28/Apr/2017:17:01:27 +0000] [Client 14] Waiting for request.
1365D [28/Apr/2017:17:01:27 +0000] [Client 13] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1366D [28/Apr/2017:17:01:27 +0000] [Client 13] Closing connection.
1367D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1368D [28/Apr/2017:17:01:27 +0000] [Client 15] Accepted from localhost:55551 (IPv4)
1369D [28/Apr/2017:17:01:27 +0000] [Client 15] Waiting for request.
1370D [28/Apr/2017:17:01:27 +0000] [Client 14] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1371D [28/Apr/2017:17:01:27 +0000] [Client 14] Closing connection.
1372D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1373D [28/Apr/2017:17:01:27 +0000] [Client 15] POST /jobs HTTP/1.1
1374D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1375D [28/Apr/2017:17:01:27 +0000] [Client 15] Read: status=200
1376D [28/Apr/2017:17:01:27 +0000] [Client 15] Authorized as root using Local.
1377D [28/Apr/2017:17:01:27 +0000] [Client 15] 2.0 Cancel-Job 1
1378D [28/Apr/2017:17:01:27 +0000] Cancel-Job ipp://localhost/jobs/1
1379D [28/Apr/2017:17:01:27 +0000] cupsdIsAuthorized: username="root"
1380D [28/Apr/2017:17:01:27 +0000] [Job 1] time-at-completed=1493395287
1381D [28/Apr/2017:17:01:27 +0000] Discarding unused job-completed event...
1382I [28/Apr/2017:17:01:27 +0000] [Job 1] Job canceled by \"root\"
1383I [28/Apr/2017:17:01:27 +0000] Expiring subscriptions...
1384D [28/Apr/2017:17:01:27 +0000] cupsdMarkDirty(---J-)
1385D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1386D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1387I [28/Apr/2017:17:01:27 +0000] [Job 1] Canceled by "root".
1388D [28/Apr/2017:17:01:27 +0000] [Client 15] Returning IPP successful-ok for Cancel-Job (ipp://localhost/jobs/1) from localhost
1389D [28/Apr/2017:17:01:27 +0000] [Client 15] Content-Length: 75
1390D [28/Apr/2017:17:01:27 +0000] [Client 15] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1391D [28/Apr/2017:17:01:27 +0000] [Job 1] Removing document files.
1392D [28/Apr/2017:17:01:27 +0000] cupsdMarkDirty(---J-)
1393D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1394D [28/Apr/2017:17:01:27 +0000] [Client 15] con->http=0x202f60e0
1395D [28/Apr/2017:17:01:27 +0000] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x2005fd00(IPP_STATE_DATA), pipe_pid=0, file=-1
1396D [28/Apr/2017:17:01:27 +0000] [Client 15] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1397D [28/Apr/2017:17:01:27 +0000] [Client 15] bytes=0, http_state=0, data_remaining=75
1398D [28/Apr/2017:17:01:27 +0000] [Client 15] Flushing write buffer.
1399D [28/Apr/2017:17:01:27 +0000] [Client 15] New state is HTTP_STATE_WAITING
1400D [28/Apr/2017:17:01:27 +0000] [Client 15] Waiting for request.
1401D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1402D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: refresh_page=\"5;URL=http://localhost:631/printers/Canon_MG7500_USB\"
1403D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: TITLE=\"Jobs\"
1404D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1405D [28/Apr/2017:17:01:27 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1406D [28/Apr/2017:17:01:27 +0000] [Client 9] CGI data ready to be sent.
1407D [28/Apr/2017:17:01:27 +0000] [Client 9] con->http=0x202edd20
1408D [28/Apr/2017:17:01:27 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=141, file=11
1409D [28/Apr/2017:17:01:27 +0000] [Client 9] Waiting for CGI data.
1410D [28/Apr/2017:17:01:27 +0000] [Client 9] Script header: Content-Type: text/html;charset=utf-8
1411D [28/Apr/2017:17:01:27 +0000] [Client 9] Script header:
1412D [28/Apr/2017:17:01:27 +0000] [Client 9] Sending status 200 for CGI.
1413D [28/Apr/2017:17:01:27 +0000] [Client 9] cupsdSendHeader: code=200, type="(null)", auth_type=0
1414D [28/Apr/2017:17:01:27 +0000] [Client 9] con->http=0x202edd20
1415D [28/Apr/2017:17:01:27 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=141, file=11
1416D [28/Apr/2017:17:01:27 +0000] [Client 9] Waiting for CGI data.
1417D [28/Apr/2017:17:01:27 +0000] [Client 9] CGI data ready to be sent.
1418D [28/Apr/2017:17:01:27 +0000] [Client 15] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1419D [28/Apr/2017:17:01:27 +0000] [Client 15] Closing connection.
1420D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1421D [28/Apr/2017:17:01:27 +0000] [Client 9] con->http=0x202edd20
1422D [28/Apr/2017:17:01:27 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=141, file=11
1423D [28/Apr/2017:17:01:27 +0000] [Client 9] Waiting for CGI data.
1424D [28/Apr/2017:17:01:27 +0000] PID 141 (/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi) exited with no errors.
1425D [28/Apr/2017:17:01:27 +0000] [Client 9] con->http=0x202edd20
1426D [28/Apr/2017:17:01:27 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=141, file=11
1427D [28/Apr/2017:17:01:27 +0000] [Client 9] Waiting for CGI data.
1428D [28/Apr/2017:17:01:27 +0000] [Client 9] CGI data ready to be sent.
1429D [28/Apr/2017:17:01:27 +0000] [Client 9] con->http=0x202edd20
1430D [28/Apr/2017:17:01:27 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=141, file=11
1431D [28/Apr/2017:17:01:27 +0000] [Client 9] Waiting for CGI data.
1432D [28/Apr/2017:17:01:27 +0000] [Client 9] Sending 0-length chunk.
1433D [28/Apr/2017:17:01:27 +0000] [Client 9] Flushing write buffer.
1434D [28/Apr/2017:17:01:27 +0000] [Client 9] New state is HTTP_STATE_WAITING
1435D [28/Apr/2017:17:01:27 +0000] [Client 9] Waiting for request.
1436D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
1437D [28/Apr/2017:17:01:27 +0000] [Client 11] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1438D [28/Apr/2017:17:01:27 +0000] [Client 11] Closing connection.
1439D [28/Apr/2017:17:01:27 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
1440D [28/Apr/2017:17:01:32 +0000] [Client 9] GET /printers/Canon_MG7500_USB HTTP/1.1
1441D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
1442D [28/Apr/2017:17:01:32 +0000] [Client 9] Read: status=200
1443D [28/Apr/2017:17:01:32 +0000] [Client 9] No authentication data provided.
1444D [28/Apr/2017:17:01:32 +0000] [Client 9] Processing GET /printers/Canon_MG7500_USB
1445D [28/Apr/2017:17:01:32 +0000] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
1446D [28/Apr/2017:17:01:32 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
1447D [28/Apr/2017:17:01:32 +0000] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
1448D [28/Apr/2017:17:01:32 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
1449D [28/Apr/2017:17:01:32 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
1450D [28/Apr/2017:17:01:32 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
1451D [28/Apr/2017:17:01:32 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
1452D [28/Apr/2017:17:01:32 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
1453D [28/Apr/2017:17:01:32 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
1454D [28/Apr/2017:17:01:32 +0000] [CGI] envp[8] = "HOME=I:\\TEMP"
1455D [28/Apr/2017:17:01:32 +0000] [CGI] envp[9] = "NLSPATH=F:\\MPTN\\MSG\\NLS\\%N;F:\\TCPIP\\msg\\ENUS850\\%N;"
1456D [28/Apr/2017:17:01:32 +0000] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
1457D [28/Apr/2017:17:01:32 +0000] [CGI] envp[11] = "SERVER_ADMIN=root@TM5320"
1458D [28/Apr/2017:17:01:32 +0000] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
1459D [28/Apr/2017:17:01:32 +0000] [CGI] envp[13] = "TMPDIR=I:\\TEMP"
1460D [28/Apr/2017:17:01:32 +0000] [CGI] envp[14] = "TZ=GMT0BST,3,-1,0,3600,10,-1,0,7200,3600"
1461D [28/Apr/2017:17:01:32 +0000] [CGI] envp[15] = "USER=root"
1462D [28/Apr/2017:17:01:32 +0000] [CGI] envp[16] = "UNIXROOT=I:"
1463D [28/Apr/2017:17:01:32 +0000] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
1464D [28/Apr/2017:17:01:32 +0000] [CGI] envp[18] = "CUPS_SERVER=localhost"
1465D [28/Apr/2017:17:01:32 +0000] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
1466D [28/Apr/2017:17:01:32 +0000] [CGI] envp[20] = "IPP_PORT=631"
1467D [28/Apr/2017:17:01:32 +0000] [CGI] envp[21] = "LANG=en_US.UTF8"
1468D [28/Apr/2017:17:01:32 +0000] [CGI] envp[22] = "REDIRECT_STATUS=1"
1469D [28/Apr/2017:17:01:32 +0000] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
1470D [28/Apr/2017:17:01:32 +0000] [CGI] envp[24] = "SERVER_NAME=localhost"
1471D [28/Apr/2017:17:01:32 +0000] [CGI] envp[25] = "SERVER_PORT=631"
1472D [28/Apr/2017:17:01:32 +0000] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
1473D [28/Apr/2017:17:01:32 +0000] [CGI] envp[27] = "REMOTE_HOST=localhost"
1474D [28/Apr/2017:17:01:32 +0000] [CGI] envp[28] = "SCRIPT_NAME=/printers/Canon_MG7500_USB"
1475D [28/Apr/2017:17:01:32 +0000] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/Canon_MG7500_USB"
1476D [28/Apr/2017:17:01:32 +0000] [CGI] envp[30] = "PATH_INFO=/Canon_MG7500_USB"
1477D [28/Apr/2017:17:01:32 +0000] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
1478D [28/Apr/2017:17:01:32 +0000] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=76832da10be696dc76bac386d11f13bc"
1479D [28/Apr/2017:17:01:32 +0000] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0 SeaMonkey/2.35"
1480D [28/Apr/2017:17:01:32 +0000] [CGI] envp[34] = "REQUEST_METHOD=GET"
1481D [28/Apr/2017:17:01:32 +0000] [CGI] envp[35] = "QUERY_STRING="
1482D [28/Apr/2017:17:01:32 +0000] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 143)
1483I [28/Apr/2017:17:01:32 +0000] [Client 9] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=143, file=9)
1484D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1485D [28/Apr/2017:17:01:32 +0000] [Client 16] Accepted from localhost:55552 (IPv4)
1486D [28/Apr/2017:17:01:32 +0000] [Client 16] Waiting for request.
1487D [28/Apr/2017:17:01:32 +0000] [CGI] org.cups.sid cookie is \"76832da10be696dc76bac386d11f13bc\"
1488D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
1489D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
1490D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
1491D [28/Apr/2017:17:01:32 +0000] [Client 16] POST / HTTP/1.1
1492D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1493D [28/Apr/2017:17:01:32 +0000] [Client 16] Read: status=200
1494D [28/Apr/2017:17:01:32 +0000] [Client 16] No authentication data provided.
1495D [28/Apr/2017:17:01:32 +0000] [Client 16] 2.0 CUPS-Get-Default 1
1496D [28/Apr/2017:17:01:32 +0000] CUPS-Get-Default
1497D [28/Apr/2017:17:01:32 +0000] CUPS-Get-Default client-error-not-found: No default printer.
1498D [28/Apr/2017:17:01:32 +0000] [Client 16] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
1499D [28/Apr/2017:17:01:32 +0000] [Client 16] Content-Length: 113
1500D [28/Apr/2017:17:01:32 +0000] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1501D [28/Apr/2017:17:01:32 +0000] [Client 16] con->http=0x202eacc0
1502D [28/Apr/2017:17:01:32 +0000] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x2005e960(IPP_STATE_DATA), pipe_pid=0, file=-1
1503D [28/Apr/2017:17:01:32 +0000] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1504D [28/Apr/2017:17:01:32 +0000] [Client 16] bytes=0, http_state=0, data_remaining=113
1505D [28/Apr/2017:17:01:32 +0000] [Client 16] Flushing write buffer.
1506D [28/Apr/2017:17:01:32 +0000] [Client 16] New state is HTTP_STATE_WAITING
1507D [28/Apr/2017:17:01:32 +0000] [Client 16] Waiting for request.
1508D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1509D [28/Apr/2017:17:01:32 +0000] [CGI] show_printer(http=0x2003c340, printer=\"Canon_MG7500_USB\")
1510D [28/Apr/2017:17:01:32 +0000] [Client 16] POST / HTTP/1.1
1511D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1512D [28/Apr/2017:17:01:32 +0000] [Client 16] Read: status=200
1513D [28/Apr/2017:17:01:32 +0000] [Client 16] No authentication data provided.
1514D [28/Apr/2017:17:01:32 +0000] [Client 16] 2.0 Get-Printer-Attributes 2
1515D [28/Apr/2017:17:01:32 +0000] Get-Printer-Attributes ipp://localhost/printers/Canon_MG7500_USB
1516D [28/Apr/2017:17:01:32 +0000] [Client 16] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MG7500_USB) from localhost
1517D [28/Apr/2017:17:01:32 +0000] [Client 16] Content-Length: 729
1518D [28/Apr/2017:17:01:32 +0000] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1519D [28/Apr/2017:17:01:32 +0000] [Client 16] con->http=0x202eacc0
1520D [28/Apr/2017:17:01:32 +0000] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=729, response=0x202e4f40(IPP_STATE_DATA), pipe_pid=0, file=-1
1521D [28/Apr/2017:17:01:32 +0000] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1522D [28/Apr/2017:17:01:32 +0000] [Client 16] bytes=0, http_state=0, data_remaining=729
1523D [28/Apr/2017:17:01:32 +0000] [Client 16] Flushing write buffer.
1524D [28/Apr/2017:17:01:32 +0000] [Client 16] New state is HTTP_STATE_WAITING
1525D [28/Apr/2017:17:01:32 +0000] [Client 16] Waiting for request.
1526D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1527D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1528D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1529D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1530D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1531D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
1532D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
1533D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_state[0]=\"3\"
1534D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
1535D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/Canon_MG7500_USB\"
1536D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_name[0]=\"Canon_MG7500_USB\"
1537D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_location[0]=\"Local Printer\"
1538D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_info[0]=\"Canon MG7500 series\"
1539D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
1540D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: device_uri[0]=\"usb://Canon/MG7500%20series?serial=117758&interface=1\"
1541D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: color_supported[0]=\"1\"
1542D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_make_and_model[0]=\"Canon PIXMA MG7550 - CUPS+Gutenprint v5.2.11 Simplified\"
1543D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
1544D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
1545D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
1546D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: printer_commands[0]=\"none\"
1547D [28/Apr/2017:17:01:32 +0000] [Client 9] CGI data ready to be sent.
1548D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
1549D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: TITLE=\"Canon_MG7500_USB\"
1550D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1551D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1552D [28/Apr/2017:17:01:32 +0000] [Client 9] con->http=0x202edd20
1553D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=143, file=9
1554D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1555D [28/Apr/2017:17:01:32 +0000] [Client 9] Script header: Content-Type: text/html;charset=utf-8
1556D [28/Apr/2017:17:01:32 +0000] [Client 9] Script header:
1557D [28/Apr/2017:17:01:32 +0000] [Client 9] Sending status 200 for CGI.
1558D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdSendHeader: code=200, type="(null)", auth_type=0
1559D [28/Apr/2017:17:01:32 +0000] [Client 17] Accepted from localhost:55553 (IPv4)
1560D [28/Apr/2017:17:01:32 +0000] [Client 17] Waiting for request.
1561D [28/Apr/2017:17:01:32 +0000] [Client 9] CGI data ready to be sent.
1562D [28/Apr/2017:17:01:32 +0000] [Client 9] con->http=0x202edd20
1563D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=143, file=9
1564D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1565D [28/Apr/2017:17:01:32 +0000] [Client 16] POST / HTTP/1.1
1566D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1567D [28/Apr/2017:17:01:32 +0000] [Client 16] Read: status=200
1568D [28/Apr/2017:17:01:32 +0000] [Client 16] No authentication data provided.
1569D [28/Apr/2017:17:01:32 +0000] [Client 16] 2.0 Get-Jobs 3
1570D [28/Apr/2017:17:01:32 +0000] Get-Jobs ipp://localhost:631/printers/Canon_MG7500_USB
1571D [28/Apr/2017:17:01:32 +0000] [Client 16] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_MG7500_USB) from localhost
1572D [28/Apr/2017:17:01:32 +0000] [Client 16] Content-Length: 75
1573D [28/Apr/2017:17:01:32 +0000] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1574D [28/Apr/2017:17:01:32 +0000] [CGI] Regular expression \".*Clean.*\"
1575D [28/Apr/2017:17:01:32 +0000] [Client 9] con->http=0x202edd20
1576D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=143, file=9
1577D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1578D [28/Apr/2017:17:01:32 +0000] [Client 16] con->http=0x202eacc0
1579D [28/Apr/2017:17:01:32 +0000] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x201e34c0(IPP_STATE_DATA), pipe_pid=0, file=-1
1580D [28/Apr/2017:17:01:32 +0000] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1581D [28/Apr/2017:17:01:32 +0000] [Client 16] bytes=0, http_state=0, data_remaining=75
1582D [28/Apr/2017:17:01:32 +0000] [Client 16] Flushing write buffer.
1583D [28/Apr/2017:17:01:32 +0000] [Client 16] New state is HTTP_STATE_WAITING
1584D [28/Apr/2017:17:01:32 +0000] [Client 16] Waiting for request.
1585D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1586D [28/Apr/2017:17:01:32 +0000] [CGI] Regular expression \".*PrintSelfTestPage.*\"
1587D [28/Apr/2017:17:01:32 +0000] [CGI] cgiClearVariables called.
1588D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: ORDER=\"asc\"
1589D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
1590D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: TOTAL=\"0\"
1591D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_MG7500_USB\"
1592D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/Canon_MG7500_USB\"
1593D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: THISURL=\"/printers/Canon_MG7500_USB\"
1594D [28/Apr/2017:17:01:32 +0000] [CGI] cgiSetVariable: SEARCH_DEST=\"Canon_MG7500_USB\"
1595D [28/Apr/2017:17:01:32 +0000] [Client 9] CGI data ready to be sent.
1596D [28/Apr/2017:17:01:32 +0000] [Client 9] con->http=0x202edd20
1597D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=143, file=9
1598D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1599D [28/Apr/2017:17:01:32 +0000] [Client 9] con->http=0x202edd20
1600D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=143, file=9
1601D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1602D [28/Apr/2017:17:01:32 +0000] [Client 9] CGI data ready to be sent.
1603D [28/Apr/2017:17:01:32 +0000] [Client 16] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1604D [28/Apr/2017:17:01:32 +0000] [Client 16] Closing connection.
1605D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1606D [28/Apr/2017:17:01:32 +0000] [Client 9] con->http=0x202edd20
1607D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=143, file=9
1608D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1609D [28/Apr/2017:17:01:32 +0000] PID 143 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
1610D [28/Apr/2017:17:01:32 +0000] [Client 9] CGI data ready to be sent.
1611D [28/Apr/2017:17:01:32 +0000] [Client 9] con->http=0x202edd20
1612D [28/Apr/2017:17:01:32 +0000] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=143, file=9
1613D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for CGI data.
1614D [28/Apr/2017:17:01:32 +0000] [Client 9] Sending 0-length chunk.
1615D [28/Apr/2017:17:01:32 +0000] [Client 9] Flushing write buffer.
1616D [28/Apr/2017:17:01:32 +0000] [Client 9] New state is HTTP_STATE_WAITING
1617D [28/Apr/2017:17:01:32 +0000] [Client 9] Waiting for request.
1618D [28/Apr/2017:17:01:32 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
1619I [28/Apr/2017:17:01:33 +0000] Saving job.cache...
1620D [28/Apr/2017:17:01:33 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
1621D [28/Apr/2017:17:01:36 +0000] [Client 9] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1622D [28/Apr/2017:17:01:36 +0000] [Client 9] Closing connection.
1623D [28/Apr/2017:17:01:36 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
1624D [28/Apr/2017:17:01:36 +0000] [Client 17] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1625D [28/Apr/2017:17:01:36 +0000] [Client 17] Closing connection.
1626D [28/Apr/2017:17:01:36 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
1627W [28/Apr/2017:17:01:40 +0000] cupsdDoSelect: select() returned -1... pause and retry select()
1628W [28/Apr/2017:17:01:42 +0000] cupsdDoSelect: select() returned -1 (2nd failure)... pause and setting socket to non-blocking mode
1629W [28/Apr/2017:17:01:43 +0000] cupsdDoSelect: select() returned -1 (3rd failure)... pause and retry select()
1630I [28/Apr/2017:17:01:46 +0000] Scheduler shutting down normally.
1631D [28/Apr/2017:17:01:46 +0000] Discarding unused server-stopped event...
1632I [28/Apr/2017:17:01:46 +0000] Saving job.cache...
1633D [28/Apr/2017:17:01:46 +0000] [Job 1] Unloading...
1634D [28/Apr/2017:17:01:46 +0000] cupsdStopSelect()