Ticket #155: Job2_error_log

File Job2_error_log, 140.7 KB (added by losepete, 8 years ago)

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

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