Ticket #143: error_log-2018-02-05

File error_log-2018-02-05, 91.2 KB (added by Lewis Rosenthal, 7 years ago)

Fresh error log, latest exp packages installed

Line 
1I [05/Feb/2018:12:34:48 +0500] Listening to 127.0.0.1:631 (IPv4)
2I [05/Feb/2018:12:34:48 +0500] Listening to localhost (Domain)
3I [05/Feb/2018:12:34:48 +0500] Remote access is disabled.
4D [05/Feb/2018:12:34:48 +0500] Added auto ServerAlias ARCAOS-01D8CC3
5I [05/Feb/2018:12:34:48 +0500] Loaded configuration file "/@unixroot/etc/cups/cupsd.conf"
6I [05/Feb/2018:12:34:48 +0500] Configured for up to 100 clients.
7I [05/Feb/2018:12:34:48 +0500] Allowing up to 100 client connections per host.
8I [05/Feb/2018:12:34:48 +0500] Using policy "default" as the default.
9I [05/Feb/2018:12:34:48 +0500] Full reload is required.
10I [05/Feb/2018:12:34:48 +0500] Loaded MIME database from "/@unixroot/usr/share/cups/mime" and "/@unixroot/etc/cups": 45 types, 53 filters...
11D [05/Feb/2018:12:34:48 +0500] Loading printer HP_Color_LaserJet_3800...
12D [05/Feb/2018:12:34:48 +0500] load_ppd: Loading /@unixroot/var/cache/cups/HP_Color_LaserJet_3800.data...
13D [05/Feb/2018:12:34:48 +0500] cupsdRegisterPrinter(p=0x200588c0(HP_Color_LaserJet_3800))
14D [05/Feb/2018:12:34:48 +0500] load_ppd: Loading /@unixroot/var/cache/cups/HP_Color_LaserJet_3800.data...
15D [05/Feb/2018:12:34:48 +0500] cupsdRegisterPrinter(p=0x200588c0(HP_Color_LaserJet_3800))
16I [05/Feb/2018:12:34:48 +0500] Loading job cache file "/@unixroot/var/cache/cups/job.cache"...
17D [05/Feb/2018:12:34:48 +0500] [Job 1] Loading from cache...
18D [05/Feb/2018:12:34:48 +0500] [Job 2] Loading from cache...
19D [05/Feb/2018:12:34:48 +0500] [Job 2] Loading attributes...
20I [05/Feb/2018:12:34:48 +0500] Full reload complete.
21D [05/Feb/2018:12:34:48 +0500] cupsdCleanFiles(path="/@unixroot/var/cache/cups", pattern="*.ipp")
22I [05/Feb/2018:12:34:48 +0500] Cleaning out old files in "/@unixroot/var/cache/cups".
23I [05/Feb/2018:12:34:48 +0500] Listening to 127.0.0.1:631 on fd 6...
24I [05/Feb/2018:12:34:48 +0500] Listening to localhost on fd 7...
25I [05/Feb/2018:12:34:48 +0500] Resuming new connection processing...
26D [05/Feb/2018:12:34:48 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
27D [05/Feb/2018:12:34:48 +0500] cupsdAddCert: Adding certificate for PID 0
28D [05/Feb/2018:12:34:48 +0500] Discarding unused server-started event...
29D [05/Feb/2018:12:34:49 +0500] Report: clients=0
30D [05/Feb/2018:12:34:49 +0500] Report: jobs=2
31D [05/Feb/2018:12:34:49 +0500] Report: jobs-active=1
32D [05/Feb/2018:12:34:49 +0500] Report: printers=1
33D [05/Feb/2018:12:34:49 +0500] Report: stringpool-string-count=2707
34D [05/Feb/2018:12:34:49 +0500] Report: stringpool-alloc-bytes=9488
35D [05/Feb/2018:12:34:49 +0500] Report: stringpool-total-bytes=51528
36D [05/Feb/2018:12:35:53 +0500] [Client 1] Accepted from localhost:63567 (IPv4)
37D [05/Feb/2018:12:35:53 +0500] [Client 1] Waiting for request.
38D [05/Feb/2018:12:35:53 +0500] [Job 2] Unloading...
39D [05/Feb/2018:12:35:53 +0500] Report: clients=1
40D [05/Feb/2018:12:35:53 +0500] Report: jobs=2
41D [05/Feb/2018:12:35:53 +0500] Report: jobs-active=1
42D [05/Feb/2018:12:35:53 +0500] Report: printers=1
43D [05/Feb/2018:12:35:53 +0500] Report: stringpool-string-count=2664
44D [05/Feb/2018:12:35:53 +0500] Report: stringpool-alloc-bytes=8320
45D [05/Feb/2018:12:35:53 +0500] Report: stringpool-total-bytes=50544
46D [05/Feb/2018:12:35:56 +0500] [Client 1] GET /printers/ HTTP/1.1
47D [05/Feb/2018:12:35:56 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
48D [05/Feb/2018:12:35:56 +0500] [Client 1] Read: status=200
49D [05/Feb/2018:12:35:56 +0500] [Client 1] No authentication data provided.
50D [05/Feb/2018:12:35:56 +0500] [Client 1] Processing GET /printers/
51D [05/Feb/2018:12:35:56 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
52D [05/Feb/2018:12:35:56 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
53D [05/Feb/2018:12:35:56 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
54D [05/Feb/2018:12:35:56 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
55D [05/Feb/2018:12:35:56 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
56D [05/Feb/2018:12:35:56 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
57D [05/Feb/2018:12:35:56 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
58D [05/Feb/2018:12:35:56 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
59D [05/Feb/2018:12:35:56 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
60D [05/Feb/2018:12:35:56 +0500] [CGI] envp[8] = "HOME=M:\\var\\temp"
61D [05/Feb/2018:12:35:56 +0500] [CGI] envp[9] = "NLSPATH=M:\\MPTN\\MSG\\NLS\\%N;M:\\TCPIP\\msg\\ENUS850\\%N;"
62D [05/Feb/2018:12:35:56 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
63D [05/Feb/2018:12:35:56 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
64D [05/Feb/2018:12:35:56 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
65D [05/Feb/2018:12:35:56 +0500] [CGI] envp[13] = "TMPDIR=M:\\var\\temp"
66D [05/Feb/2018:12:35:56 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
67D [05/Feb/2018:12:35:56 +0500] [CGI] envp[15] = "USER=root"
68D [05/Feb/2018:12:35:56 +0500] [CGI] envp[16] = "UNIXROOT=M:"
69D [05/Feb/2018:12:35:56 +0500] [CGI] envp[17] = "ETC=M:\\MPTN\\ETC"
70D [05/Feb/2018:12:35:56 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
71D [05/Feb/2018:12:35:56 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
72D [05/Feb/2018:12:35:56 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
73D [05/Feb/2018:12:35:56 +0500] [CGI] envp[21] = "IPP_PORT=631"
74D [05/Feb/2018:12:35:56 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
75D [05/Feb/2018:12:35:56 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
76D [05/Feb/2018:12:35:56 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
77D [05/Feb/2018:12:35:56 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
78D [05/Feb/2018:12:35:56 +0500] [CGI] envp[26] = "SERVER_PORT=631"
79D [05/Feb/2018:12:35:56 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
80D [05/Feb/2018:12:35:56 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
81D [05/Feb/2018:12:35:56 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/"
82D [05/Feb/2018:12:35:56 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/"
83D [05/Feb/2018:12:35:56 +0500] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
84D [05/Feb/2018:12:35:56 +0500] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0"
85D [05/Feb/2018:12:35:56 +0500] [CGI] envp[33] = "HTTP_REFERER=http://localhost:631/"
86D [05/Feb/2018:12:35:56 +0500] [CGI] envp[34] = "REQUEST_METHOD=GET"
87D [05/Feb/2018:12:35:56 +0500] [CGI] envp[35] = "QUERY_STRING="
88D [05/Feb/2018:12:35:56 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 89)
89I [05/Feb/2018:12:35:56 +0500] [Client 1] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=89, file=11)
90D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
91D [05/Feb/2018:12:35:56 +0500] [CGI] org.cups.sid cookie not found, initializing!
92D [05/Feb/2018:12:35:56 +0500] [CGI] org.cups.sid cookie is \"873e98c1cb8d4b69abd3f3d756f22f63\"
93D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
94D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
95D [05/Feb/2018:12:35:56 +0500] [Client 2] Accepted from localhost (Domain)
96D [05/Feb/2018:12:35:56 +0500] [Client 2] Waiting for request.
97D [05/Feb/2018:12:35:56 +0500] [Client 2] POST / HTTP/1.1
98D [05/Feb/2018:12:35:56 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
99D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=200
100D [05/Feb/2018:12:35:56 +0500] [Client 2] No authentication data provided.
101D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=100
102D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=100
103D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=100
104D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=100
105D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=100
106D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=100
107D [05/Feb/2018:12:35:56 +0500] [Client 2] 2.0 CUPS-Get-Default 1
108D [05/Feb/2018:12:35:56 +0500] CUPS-Get-Default
109D [05/Feb/2018:12:35:56 +0500] CUPS-Get-Default client-error-not-found: No default printer.
110D [05/Feb/2018:12:35:56 +0500] [Client 2] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
111D [05/Feb/2018:12:35:56 +0500] [Client 2] Content-Length: 113
112D [05/Feb/2018:12:35:56 +0500] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
113D [05/Feb/2018:12:35:56 +0500] [Client 2] con->http=0x200bcce0
114D [05/Feb/2018:12:35:56 +0500] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x200bff40(IPP_STATE_DATA), pipe_pid=0, file=-1
115D [05/Feb/2018:12:35:56 +0500] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
116D [05/Feb/2018:12:35:56 +0500] [Client 2] bytes=0, http_state=0, data_remaining=113
117D [05/Feb/2018:12:35:56 +0500] [Client 2] Flushing write buffer.
118D [05/Feb/2018:12:35:56 +0500] [Client 2] New state is HTTP_STATE_WAITING
119D [05/Feb/2018:12:35:56 +0500] [Client 2] Waiting for request.
120D [05/Feb/2018:12:35:56 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
121D [05/Feb/2018:12:35:56 +0500] [CGI] show_all_printers(http=0x2003c1e0, user=\"(null)\")
122D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: TITLE=\"Printers\"
123D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
124D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
125D [05/Feb/2018:12:35:56 +0500] [Client 1] CGI data ready to be sent.
126D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
127D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=89, file=11
128D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
129D [05/Feb/2018:12:35:56 +0500] [Client 1] Script header: Set-Cookie: org.cups.sid=873e98c1cb8d4b69abd3f3d756f22f63; path=/; httponly;
130D [05/Feb/2018:12:35:56 +0500] [Client 1] Script header: Content-Type: text/html;charset=utf-8
131D [05/Feb/2018:12:35:56 +0500] [Client 1] Script header:
132D [05/Feb/2018:12:35:56 +0500] [Client 1] Sending status 200 for CGI.
133D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdSendHeader: code=200, type="(null)", auth_type=0
134D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
135D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
136D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
137D [05/Feb/2018:12:35:56 +0500] [Client 3] Accepted from localhost:63568 (IPv4)
138D [05/Feb/2018:12:35:56 +0500] [Client 3] Waiting for request.
139D [05/Feb/2018:12:35:56 +0500] [Client 2] POST / HTTP/1.1
140D [05/Feb/2018:12:35:56 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
141D [05/Feb/2018:12:35:56 +0500] [Client 2] Read: status=200
142D [05/Feb/2018:12:35:56 +0500] [Client 2] No authentication data provided.
143D [05/Feb/2018:12:35:56 +0500] [Client 2] 2.0 CUPS-Get-Printers 2
144D [05/Feb/2018:12:35:56 +0500] CUPS-Get-Printers
145D [05/Feb/2018:12:35:56 +0500] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
146D [05/Feb/2018:12:35:56 +0500] [Client 2] Content-Length: 371
147D [05/Feb/2018:12:35:56 +0500] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
148D [05/Feb/2018:12:35:56 +0500] [Client 2] con->http=0x200bcce0
149D [05/Feb/2018:12:35:56 +0500] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=371, response=0x200af360(IPP_STATE_DATA), pipe_pid=0, file=-1
150D [05/Feb/2018:12:35:56 +0500] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
151D [05/Feb/2018:12:35:56 +0500] [Client 2] bytes=0, http_state=0, data_remaining=371
152D [05/Feb/2018:12:35:56 +0500] [Client 2] Flushing write buffer.
153D [05/Feb/2018:12:35:56 +0500] [Client 2] New state is HTTP_STATE_WAITING
154D [05/Feb/2018:12:35:56 +0500] [Client 2] Waiting for request.
155D [05/Feb/2018:12:35:56 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
156D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: TOTAL=\"1\"
157D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
158D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
159D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
160D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: printer_state_message[0]=\"\"
161D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
162D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800\"
163D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800\"
164D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: printer_location[0]=\"office\"
165D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800\"
166D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 hpijs pcl3, 3.17.11\"
167D [05/Feb/2018:12:35:56 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/\"
168D [05/Feb/2018:12:35:56 +0500] [Client 1] CGI data ready to be sent.
169D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
170D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
171D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
172D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
173D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
174D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
175D [05/Feb/2018:12:35:56 +0500] [Client 1] CGI data ready to be sent.
176D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
177D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
178D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
179D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
180D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
181D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
182D [05/Feb/2018:12:35:56 +0500] [Client 1] CGI data ready to be sent.
183D [05/Feb/2018:12:35:56 +0500] [Client 2] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
184D [05/Feb/2018:12:35:56 +0500] [Client 2] Closing connection.
185D [05/Feb/2018:12:35:56 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
186D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
187D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
188D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
189D [05/Feb/2018:12:35:56 +0500] PID 89 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
190D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
191D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
192D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
193D [05/Feb/2018:12:35:56 +0500] [Client 1] CGI data ready to be sent.
194D [05/Feb/2018:12:35:56 +0500] [Client 1] con->http=0x200b8b00
195D [05/Feb/2018:12:35:56 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=89, file=11
196D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for CGI data.
197D [05/Feb/2018:12:35:56 +0500] [Client 1] Sending 0-length chunk.
198D [05/Feb/2018:12:35:56 +0500] [Client 1] Flushing write buffer.
199D [05/Feb/2018:12:35:56 +0500] [Client 1] New state is HTTP_STATE_WAITING
200D [05/Feb/2018:12:35:56 +0500] [Client 1] Waiting for request.
201D [05/Feb/2018:12:35:56 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
202D [05/Feb/2018:12:35:57 +0500] [Client 1] GET /printers/HP_Color_LaserJet_3800 HTTP/1.1
203D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
204D [05/Feb/2018:12:35:57 +0500] [Client 1] Read: status=200
205D [05/Feb/2018:12:35:57 +0500] [Client 1] No authentication data provided.
206D [05/Feb/2018:12:35:57 +0500] [Client 1] Processing GET /printers/HP_Color_LaserJet_3800
207D [05/Feb/2018:12:35:57 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
208D [05/Feb/2018:12:35:57 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
209D [05/Feb/2018:12:35:57 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
210D [05/Feb/2018:12:35:57 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
211D [05/Feb/2018:12:35:57 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
212D [05/Feb/2018:12:35:57 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
213D [05/Feb/2018:12:35:57 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
214D [05/Feb/2018:12:35:57 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
215D [05/Feb/2018:12:35:57 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
216D [05/Feb/2018:12:35:57 +0500] [CGI] envp[8] = "HOME=M:\\var\\temp"
217D [05/Feb/2018:12:35:57 +0500] [CGI] envp[9] = "NLSPATH=M:\\MPTN\\MSG\\NLS\\%N;M:\\TCPIP\\msg\\ENUS850\\%N;"
218D [05/Feb/2018:12:35:57 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
219D [05/Feb/2018:12:35:57 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
220D [05/Feb/2018:12:35:57 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
221D [05/Feb/2018:12:35:57 +0500] [CGI] envp[13] = "TMPDIR=M:\\var\\temp"
222D [05/Feb/2018:12:35:57 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
223D [05/Feb/2018:12:35:57 +0500] [CGI] envp[15] = "USER=root"
224D [05/Feb/2018:12:35:57 +0500] [CGI] envp[16] = "UNIXROOT=M:"
225D [05/Feb/2018:12:35:57 +0500] [CGI] envp[17] = "ETC=M:\\MPTN\\ETC"
226D [05/Feb/2018:12:35:57 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
227D [05/Feb/2018:12:35:57 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
228D [05/Feb/2018:12:35:57 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
229D [05/Feb/2018:12:35:57 +0500] [CGI] envp[21] = "IPP_PORT=631"
230D [05/Feb/2018:12:35:57 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
231D [05/Feb/2018:12:35:57 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
232D [05/Feb/2018:12:35:57 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
233D [05/Feb/2018:12:35:57 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
234D [05/Feb/2018:12:35:57 +0500] [CGI] envp[26] = "SERVER_PORT=631"
235D [05/Feb/2018:12:35:57 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
236D [05/Feb/2018:12:35:57 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
237D [05/Feb/2018:12:35:57 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800"
238D [05/Feb/2018:12:35:57 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800"
239D [05/Feb/2018:12:35:57 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_LaserJet_3800"
240D [05/Feb/2018:12:35:57 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
241D [05/Feb/2018:12:35:57 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=873e98c1cb8d4b69abd3f3d756f22f63"
242D [05/Feb/2018:12:35:57 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0"
243D [05/Feb/2018:12:35:57 +0500] [CGI] envp[35] = "HTTP_REFERER=http://localhost:631/printers/"
244D [05/Feb/2018:12:35:57 +0500] [CGI] envp[36] = "REQUEST_METHOD=GET"
245D [05/Feb/2018:12:35:57 +0500] [CGI] envp[37] = "QUERY_STRING="
246D [05/Feb/2018:12:35:57 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 91)
247I [05/Feb/2018:12:35:57 +0500] [Client 1] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=91, file=11)
248D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
249D [05/Feb/2018:12:35:57 +0500] [Client 4] Accepted from localhost (Domain)
250D [05/Feb/2018:12:35:57 +0500] [Client 4] Waiting for request.
251D [05/Feb/2018:12:35:57 +0500] [CGI] org.cups.sid cookie is \"873e98c1cb8d4b69abd3f3d756f22f63\"
252D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
253D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
254D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
255D [05/Feb/2018:12:35:57 +0500] [Client 4] POST / HTTP/1.1
256D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
257D [05/Feb/2018:12:35:57 +0500] [Client 4] Read: status=200
258D [05/Feb/2018:12:35:57 +0500] [Client 4] No authentication data provided.
259D [05/Feb/2018:12:35:57 +0500] [Client 4] 2.0 CUPS-Get-Default 1
260D [05/Feb/2018:12:35:57 +0500] CUPS-Get-Default
261D [05/Feb/2018:12:35:57 +0500] CUPS-Get-Default client-error-not-found: No default printer.
262D [05/Feb/2018:12:35:57 +0500] [Client 4] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
263D [05/Feb/2018:12:35:57 +0500] [Client 4] Content-Length: 113
264D [05/Feb/2018:12:35:57 +0500] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
265D [05/Feb/2018:12:35:57 +0500] [Client 4] con->http=0x200bcce0
266D [05/Feb/2018:12:35:57 +0500] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x200af180(IPP_STATE_DATA), pipe_pid=0, file=-1
267D [05/Feb/2018:12:35:57 +0500] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
268D [05/Feb/2018:12:35:57 +0500] [Client 4] bytes=0, http_state=0, data_remaining=113
269D [05/Feb/2018:12:35:57 +0500] [Client 4] Flushing write buffer.
270D [05/Feb/2018:12:35:57 +0500] [Client 4] New state is HTTP_STATE_WAITING
271D [05/Feb/2018:12:35:57 +0500] [Client 4] Waiting for request.
272D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
273D [05/Feb/2018:12:35:57 +0500] [CGI] show_printer(http=0x2003c240, printer=\"HP_Color_LaserJet_3800\")
274D [05/Feb/2018:12:35:57 +0500] [Client 4] POST / HTTP/1.1
275D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
276D [05/Feb/2018:12:35:57 +0500] [Client 4] Read: status=200
277D [05/Feb/2018:12:35:57 +0500] [Client 4] No authentication data provided.
278D [05/Feb/2018:12:35:57 +0500] [Client 4] 2.0 Get-Printer-Attributes 2
279D [05/Feb/2018:12:35:57 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800
280D [05/Feb/2018:12:35:57 +0500] [Client 4] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800) from localhost
281D [05/Feb/2018:12:35:57 +0500] [Client 4] Content-Length: 733
282D [05/Feb/2018:12:35:57 +0500] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
283D [05/Feb/2018:12:35:57 +0500] [Client 4] con->http=0x200bcce0
284D [05/Feb/2018:12:35:57 +0500] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=733, response=0x200af1e0(IPP_STATE_DATA), pipe_pid=0, file=-1
285D [05/Feb/2018:12:35:57 +0500] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
286D [05/Feb/2018:12:35:57 +0500] [Client 4] bytes=0, http_state=0, data_remaining=733
287D [05/Feb/2018:12:35:57 +0500] [Client 4] Flushing write buffer.
288D [05/Feb/2018:12:35:57 +0500] [Client 4] New state is HTTP_STATE_WAITING
289D [05/Feb/2018:12:35:57 +0500] [Client 4] Waiting for request.
290D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
291D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
292D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
293D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
294D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
295D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
296D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
297D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
298D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
299D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800\"
300D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800\"
301D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_location[0]=\"office\"
302D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800\"
303D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
304D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: device_uri[0]=\"socket://192.168.100.16\"
305D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
306D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 hpijs pcl3, 3.17.11\"
307D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
308D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
309D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
310D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
311D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
312D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_LaserJet_3800\"
313D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
314D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
315D [05/Feb/2018:12:35:57 +0500] [Client 1] CGI data ready to be sent.
316D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
317D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=91, file=11
318D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
319D [05/Feb/2018:12:35:57 +0500] [Client 1] Script header: Content-Type: text/html;charset=utf-8
320D [05/Feb/2018:12:35:57 +0500] [Client 1] Script header:
321D [05/Feb/2018:12:35:57 +0500] [Client 1] Sending status 200 for CGI.
322D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdSendHeader: code=200, type="(null)", auth_type=0
323D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
324D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
325D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
326D [05/Feb/2018:12:35:57 +0500] [CGI] Regular expression \".*Clean.*\"
327D [05/Feb/2018:12:35:57 +0500] [CGI] matches[0].rm_so=0
328D [05/Feb/2018:12:35:57 +0500] [CGI] matches[1].rm_so=-1
329D [05/Feb/2018:12:35:57 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
330D [05/Feb/2018:12:35:57 +0500] [CGI] matches[0].rm_so=0
331D [05/Feb/2018:12:35:57 +0500] [CGI] matches[1].rm_so=-1
332D [05/Feb/2018:12:35:57 +0500] [Client 1] CGI data ready to be sent.
333D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
334D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
335D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
336D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
337D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
338D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
339D [05/Feb/2018:12:35:57 +0500] [Client 1] CGI data ready to be sent.
340D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
341D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
342D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
343D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
344D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
345D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
346D [05/Feb/2018:12:35:57 +0500] [Client 4] POST / HTTP/1.1
347D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
348D [05/Feb/2018:12:35:57 +0500] [Client 4] Read: status=200
349D [05/Feb/2018:12:35:57 +0500] [Client 4] No authentication data provided.
350D [05/Feb/2018:12:35:57 +0500] [Client 4] 2.0 Get-Jobs 3
351D [05/Feb/2018:12:35:57 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_LaserJet_3800
352D [05/Feb/2018:12:35:57 +0500] [Job 2] Loading attributes...
353D [05/Feb/2018:12:35:57 +0500] [Client 4] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_LaserJet_3800) from localhost
354D [05/Feb/2018:12:35:57 +0500] [Client 4] Content-Length: 429
355D [05/Feb/2018:12:35:57 +0500] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
356D [05/Feb/2018:12:35:57 +0500] [Client 4] con->http=0x200bcce0
357D [05/Feb/2018:12:35:57 +0500] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=429, response=0x200af340(IPP_STATE_DATA), pipe_pid=0, file=-1
358D [05/Feb/2018:12:35:57 +0500] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
359D [05/Feb/2018:12:35:57 +0500] [Client 4] bytes=0, http_state=0, data_remaining=429
360D [05/Feb/2018:12:35:57 +0500] [Client 4] Flushing write buffer.
361D [05/Feb/2018:12:35:57 +0500] [Client 4] New state is HTTP_STATE_WAITING
362D [05/Feb/2018:12:35:57 +0500] [Client 4] Waiting for request.
363D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
364D [05/Feb/2018:12:35:57 +0500] [CGI] cgiClearVariables called.
365D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
366D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
367D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: TOTAL=\"1\"
368D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
369D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
370D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_preserved[0]=\"1\"
371D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_printer_name[0]=\"HP_Color_LaserJet_3800\"
372D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_Color_LaserJet_3800\"
373D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
374D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
375D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
376D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: time_at_creation[0]=\"Sat Feb 3 20:12:57 EST 2018\"
377D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: time_at_processing[0]=\"Sat Feb 3 20:12:57 EST 2018\"
378D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_id[0]=\"2\"
379D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_state[0]=\"6\"
380D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"1\"
381D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
382D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
383D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
384D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_LaserJet_3800\"
385D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_LaserJet_3800\"
386D [05/Feb/2018:12:35:57 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_LaserJet_3800\"
387D [05/Feb/2018:12:35:57 +0500] [Client 1] CGI data ready to be sent.
388D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
389D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
390D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
391D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
392D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
393D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
394D [05/Feb/2018:12:35:57 +0500] [Client 1] CGI data ready to be sent.
395D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
396D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
397D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
398D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
399D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
400D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
401D [05/Feb/2018:12:35:57 +0500] [Client 1] CGI data ready to be sent.
402D [05/Feb/2018:12:35:57 +0500] [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
403D [05/Feb/2018:12:35:57 +0500] [Client 4] Closing connection.
404D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
405D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
406D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
407D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
408D [05/Feb/2018:12:35:57 +0500] PID 91 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
409D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
410D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
411D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
412D [05/Feb/2018:12:35:57 +0500] [Client 1] CGI data ready to be sent.
413D [05/Feb/2018:12:35:57 +0500] [Client 1] con->http=0x200b8b00
414D [05/Feb/2018:12:35:57 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=91, file=11
415D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for CGI data.
416D [05/Feb/2018:12:35:57 +0500] [Client 1] Sending 0-length chunk.
417D [05/Feb/2018:12:35:57 +0500] [Client 1] Flushing write buffer.
418D [05/Feb/2018:12:35:57 +0500] [Client 1] New state is HTTP_STATE_WAITING
419D [05/Feb/2018:12:35:57 +0500] [Client 1] Waiting for request.
420D [05/Feb/2018:12:35:57 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
421D [05/Feb/2018:12:36:02 +0500] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
422D [05/Feb/2018:12:36:02 +0500] [Client 3] Closing connection.
423D [05/Feb/2018:12:36:02 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
424D [05/Feb/2018:12:36:06 +0500] [Client 1] POST /printers/HP_Color_LaserJet_3800 HTTP/1.1
425D [05/Feb/2018:12:36:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
426D [05/Feb/2018:12:36:06 +0500] [Client 1] Read: status=200
427D [05/Feb/2018:12:36:06 +0500] [Client 1] No authentication data provided.
428D [05/Feb/2018:12:36:06 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
429D [05/Feb/2018:12:36:06 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
430D [05/Feb/2018:12:36:06 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
431D [05/Feb/2018:12:36:06 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
432D [05/Feb/2018:12:36:06 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
433D [05/Feb/2018:12:36:06 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
434D [05/Feb/2018:12:36:06 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
435D [05/Feb/2018:12:36:06 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
436D [05/Feb/2018:12:36:06 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
437D [05/Feb/2018:12:36:06 +0500] [CGI] envp[8] = "HOME=M:\\var\\temp"
438D [05/Feb/2018:12:36:06 +0500] [CGI] envp[9] = "NLSPATH=M:\\MPTN\\MSG\\NLS\\%N;M:\\TCPIP\\msg\\ENUS850\\%N;"
439D [05/Feb/2018:12:36:06 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
440D [05/Feb/2018:12:36:06 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
441D [05/Feb/2018:12:36:06 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
442D [05/Feb/2018:12:36:06 +0500] [CGI] envp[13] = "TMPDIR=M:\\var\\temp"
443D [05/Feb/2018:12:36:06 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
444D [05/Feb/2018:12:36:06 +0500] [CGI] envp[15] = "USER=root"
445D [05/Feb/2018:12:36:06 +0500] [CGI] envp[16] = "UNIXROOT=M:"
446D [05/Feb/2018:12:36:06 +0500] [CGI] envp[17] = "ETC=M:\\MPTN\\ETC"
447D [05/Feb/2018:12:36:06 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
448D [05/Feb/2018:12:36:06 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
449D [05/Feb/2018:12:36:06 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
450D [05/Feb/2018:12:36:06 +0500] [CGI] envp[21] = "IPP_PORT=631"
451D [05/Feb/2018:12:36:06 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
452D [05/Feb/2018:12:36:06 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
453D [05/Feb/2018:12:36:06 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
454D [05/Feb/2018:12:36:06 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
455D [05/Feb/2018:12:36:06 +0500] [CGI] envp[26] = "SERVER_PORT=631"
456D [05/Feb/2018:12:36:06 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
457D [05/Feb/2018:12:36:06 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
458D [05/Feb/2018:12:36:06 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800"
459D [05/Feb/2018:12:36:06 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800"
460D [05/Feb/2018:12:36:06 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_LaserJet_3800"
461D [05/Feb/2018:12:36:06 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
462D [05/Feb/2018:12:36:06 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=873e98c1cb8d4b69abd3f3d756f22f63"
463D [05/Feb/2018:12:36:06 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0"
464D [05/Feb/2018:12:36:06 +0500] [CGI] envp[35] = "HTTP_REFERER=http://localhost:631/printers/HP_Color_LaserJet_3800"
465D [05/Feb/2018:12:36:06 +0500] [CGI] envp[36] = "REQUEST_METHOD=POST"
466D [05/Feb/2018:12:36:06 +0500] [CGI] envp[37] = "CONTENT_LENGTH=64"
467D [05/Feb/2018:12:36:06 +0500] [CGI] envp[38] = "CONTENT_TYPE=application/x-www-form-urlencoded"
468D [05/Feb/2018:12:36:06 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 93)
469I [05/Feb/2018:12:36:06 +0500] [Client 1] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=93, file=12)
470D [05/Feb/2018:12:36:06 +0500] [Client 1] Waiting for CGI data.
471D [05/Feb/2018:12:36:06 +0500] [Client 5] Accepted from localhost (Domain)
472D [05/Feb/2018:12:36:06 +0500] [Client 5] Waiting for request.
473D [05/Feb/2018:12:36:06 +0500] [CGI] org.cups.sid cookie is \"873e98c1cb8d4b69abd3f3d756f22f63\"
474D [05/Feb/2018:12:36:06 +0500] [CGI] cgiSetVariable: org.cups.sid=\"873e98c1cb8d4b69abd3f3d756f22f63\"
475D [05/Feb/2018:12:36:06 +0500] [CGI] cgiSetVariable: OP=\"print-test-page\"
476D [05/Feb/2018:12:36:06 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
477D [05/Feb/2018:12:36:06 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
478D [05/Feb/2018:12:36:06 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
479D [05/Feb/2018:12:36:06 +0500] [Client 5] POST /printers/HP_Color_LaserJet_3800 HTTP/1.1
480D [05/Feb/2018:12:36:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
481D [05/Feb/2018:12:36:06 +0500] [Client 5] Read: status=200
482D [05/Feb/2018:12:36:06 +0500] [Client 5] No authentication data provided.
483D [05/Feb/2018:12:36:06 +0500] [Client 5] 2.0 Print-Job 1
484D [05/Feb/2018:12:36:06 +0500] Print-Job ipp://localhost:631/printers/HP_Color_LaserJet_3800
485D [05/Feb/2018:12:36:06 +0500] [Job ???] Auto-typing file...
486I [05/Feb/2018:12:36:06 +0500] [Job ???] Request file type is application/vnd.cups-pdf-banner.
487D [05/Feb/2018:12:36:06 +0500] cupsdMarkDirty(---J-)
488D [05/Feb/2018:12:36:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
489D [05/Feb/2018:12:36:06 +0500] Adding default job-sheets values "none,none"...
490I [05/Feb/2018:12:36:06 +0500] [Job 3] Adding start banner page "none".
491D [05/Feb/2018:12:36:06 +0500] Discarding unused job-created event...
492D [05/Feb/2018:12:36:06 +0500] cupsdMarkDirty(---J-)
493D [05/Feb/2018:12:36:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
494I [05/Feb/2018:12:36:06 +0500] [Job 3] Adding end banner page "none".
495I [05/Feb/2018:12:36:06 +0500] [Job 3] File of type application/vnd.cups-pdf-banner queued by "anonymous".
496D [05/Feb/2018:12:36:06 +0500] [Job 3] hold_until=0
497I [05/Feb/2018:12:36:06 +0500] [Job 3] Queued on "HP_Color_LaserJet_3800" by "anonymous".
498D [05/Feb/2018:12:36:06 +0500] [Job 3] time-at-processing=1517852166
499D [05/Feb/2018:12:36:06 +0500] cupsdMarkDirty(---J-)
500D [05/Feb/2018:12:36:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
501D [05/Feb/2018:12:36:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
502D [05/Feb/2018:12:36:06 +0500] Discarding unused printer-state-changed event...
503D [05/Feb/2018:12:36:06 +0500] [Job 3] 3 filters for job:
504D [05/Feb/2018:12:36:06 +0500] [Job 3] bannertopdf.exe (application/vnd.cups-pdf-banner to application/pdf, cost 32)
505D [05/Feb/2018:12:36:06 +0500] [Job 3] pdftopdf.exe (application/pdf to application/vnd.cups-pdf, cost 66)
506D [05/Feb/2018:12:36:06 +0500] [Job 3] foomatic-rip (application/vnd.cups-pdf to printer/HP_Color_LaserJet_3800, cost 0)
507D [05/Feb/2018:12:36:06 +0500] [Job 3] job-sheets=none,none
508D [05/Feb/2018:12:36:06 +0500] [Job 3] argv[0]="HP_Color_LaserJet_3800"
509D [05/Feb/2018:12:36:06 +0500] [Job 3] argv[1]="3"
510D [05/Feb/2018:12:36:06 +0500] [Job 3] argv[2]="anonymous"
511D [05/Feb/2018:12:36:06 +0500] [Job 3] argv[3]="Test Page"
512D [05/Feb/2018:12:36:06 +0500] [Job 3] argv[4]="1"
513D [05/Feb/2018:12:36:06 +0500] [Job 3] argv[5]="job-uuid=urn:uuid:4fae2f72-1ff3-3a53-497f-2b77bcaa1172 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1517852166 time-at-processing=1517852166"
514D [05/Feb/2018:12:36:06 +0500] [Job 3] argv[6]="/@unixroot/var/spool/cups/d00003-001"
515D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[0]="CUPS_CACHEDIR=/@unixroot/var/cache/cups"
516D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[1]="CUPS_DATADIR=/@unixroot/usr/share/cups"
517D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[2]="CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
518D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[3]="CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
519D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[4]="CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
520D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[5]="CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
521D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[6]="CUPS_SERVERROOT=/@unixroot/etc/cups"
522D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[7]="CUPS_STATEDIR=/@unixroot/var/run/cups"
523D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[8]="HOME=M:\\var\\temp"
524D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[9]="NLSPATH=M:\\MPTN\\MSG\\NLS\\%N;M:\\TCPIP\\msg\\ENUS850\\%N;"
525D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[10]="PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
526D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[11]="SERVER_ADMIN=root@ARCAOS-01D8CC3"
527D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[12]="SOFTWARE=CUPS/2.1.3"
528D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[13]="TMPDIR=M:\\var\\temp"
529D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[14]="TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
530D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[15]="USER=root"
531D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[16]="UNIXROOT=M:"
532D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[17]="ETC=M:\\MPTN\\ETC"
533D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[18]="CUPS_MAX_MESSAGE=2047"
534D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[19]="CUPS_SERVER=\\socket\\cups.sock"
535D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[20]="CUPS_ENCRYPTION=IfRequested"
536D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[21]="IPP_PORT=631"
537D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[22]="CHARSET=utf-8"
538D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[23]="LANG=en_US.UTF-8"
539D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[24]="PPD=/@unixroot/etc/cups/ppd/HP_Color_LaserJet_3800.ppd"
540D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[25]="RIP_MAX_CACHE=128m"
541D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[26]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
542D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[27]="DEVICE_URI=socket://192.168.100.16"
543D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[28]="PRINTER_INFO=HP Color LaserJet 3800"
544D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[29]="PRINTER_LOCATION=office"
545D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[30]="PRINTER=HP_Color_LaserJet_3800"
546D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[31]="PRINTER_STATE_REASONS=none"
547D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[32]="CUPS_FILETYPE=document"
548D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[33]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
549D [05/Feb/2018:12:36:06 +0500] [Job 3] envp[34]="AUTH_I****"
550I [05/Feb/2018:12:36:07 +0500] [Job 3] Started filter /@unixroot/usr/lib/cups/filter/bannertopdf.exe (PID 95)
551I [05/Feb/2018:12:36:07 +0500] [Job 3] Started filter /@unixroot/usr/lib/cups/filter/pdftopdf.exe (PID 96)
552I [05/Feb/2018:12:36:07 +0500] [Job 3] Started filter /@unixroot/usr/lib/cups/filter/foomatic-rip.exe (PID 98)
553I [05/Feb/2018:12:36:07 +0500] [Job 3] Started backend /@unixroot/usr/lib/cups/backend/socket.exe (PID 101)
554D [05/Feb/2018:12:36:07 +0500] Discarding unused job-state-changed event...
555D [05/Feb/2018:12:36:07 +0500] [Client 5] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HP_Color_LaserJet_3800) from localhost
556D [05/Feb/2018:12:36:07 +0500] [Client 5] Content-Length: 191
557D [05/Feb/2018:12:36:07 +0500] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
558D [05/Feb/2018:12:36:07 +0500] [Client 6] Accepted from localhost (Domain)
559D [05/Feb/2018:12:36:07 +0500] [Client 6] Waiting for request.
560D [05/Feb/2018:12:36:07 +0500] [Client 5] con->http=0x200bbb60
561D [05/Feb/2018:12:36:07 +0500] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=191, response=0x2005e7c0(IPP_STATE_IDLE), pipe_pid=0, file=-1
562D [05/Feb/2018:12:36:07 +0500] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
563D [05/Feb/2018:12:36:07 +0500] [Client 5] bytes=0, http_state=0, data_remaining=191
564D [05/Feb/2018:12:36:07 +0500] [Client 5] Flushing write buffer.
565D [05/Feb/2018:12:36:07 +0500] [Client 5] New state is HTTP_STATE_WAITING
566D [05/Feb/2018:12:36:07 +0500] [Client 5] Waiting for request.
567D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
568D [05/Feb/2018:12:36:07 +0500] [Job 3] WARN: not compiled with DBus support
569D [05/Feb/2018:12:36:07 +0500] [Job 3] \'CM Color Calibration\' Mode in SPOOLER-LESS: Off
570D [05/Feb/2018:12:36:07 +0500] [Job 3] Getting input from file
571D [05/Feb/2018:12:36:07 +0500] [Job 3] foomatic-rip version 1.17.2 running...
572D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
573D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
574D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
575D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
576D [05/Feb/2018:12:36:07 +0500] [Client 6] POST /printers/HP_Color_LaserJet_3800 HTTP/1.1
577D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
578D [05/Feb/2018:12:36:07 +0500] [Client 6] Read: status=200
579D [05/Feb/2018:12:36:07 +0500] [Client 6] No authentication data provided.
580D [05/Feb/2018:12:36:07 +0500] [Client 6] 2.0 Get-Printer-Attributes 1
581D [05/Feb/2018:12:36:07 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800
582D [05/Feb/2018:12:36:07 +0500] [Client 6] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800) from localhost
583D [05/Feb/2018:12:36:07 +0500] [Client 6] Content-Length: 208
584D [05/Feb/2018:12:36:07 +0500] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
585D [05/Feb/2018:12:36:07 +0500] [Client 6] con->http=0x200c02e0
586D [05/Feb/2018:12:36:07 +0500] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=208, response=0x200bec60(IPP_STATE_DATA), pipe_pid=0, file=-1
587D [05/Feb/2018:12:36:07 +0500] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
588D [05/Feb/2018:12:36:07 +0500] [Client 6] bytes=0, http_state=0, data_remaining=208
589D [05/Feb/2018:12:36:07 +0500] [Client 6] Flushing write buffer.
590D [05/Feb/2018:12:36:07 +0500] [Client 6] New state is HTTP_STATE_WAITING
591D [05/Feb/2018:12:36:07 +0500] [Client 6] Waiting for request.
592D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
593D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetArray: job_uri[0]=\"/jobs/3\"
594D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetArray: job_id[0]=\"3\"
595D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetArray: job_state[0]=\"3\"
596D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetArray: job_state_message[0]=\"\"
597D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetArray: job_state_reasons[0]=\"none\"
598D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: refresh_page=\"2;URL=/printers/HP_Color_LaserJet_3800\"
599D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: TITLE=\"Print Test Page\"
600D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
601D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
602D [05/Feb/2018:12:36:07 +0500] [Client 1] CGI data ready to be sent.
603D [05/Feb/2018:12:36:07 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
604D [05/Feb/2018:12:36:07 +0500] [Client 1] con->http=0x200b8b00
605D [05/Feb/2018:12:36:07 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=93, file=12
606D [05/Feb/2018:12:36:07 +0500] [Client 1] Waiting for CGI data.
607D [05/Feb/2018:12:36:07 +0500] [Client 1] Script header: Content-Type: text/html;charset=utf-8
608D [05/Feb/2018:12:36:07 +0500] [Client 1] Script header:
609D [05/Feb/2018:12:36:07 +0500] [Client 1] Sending status 200 for CGI.
610D [05/Feb/2018:12:36:07 +0500] [Client 1] cupsdSendHeader: code=200, type="(null)", auth_type=0
611D [05/Feb/2018:12:36:07 +0500] [Client 7] Accepted from localhost:63569 (IPv4)
612D [05/Feb/2018:12:36:07 +0500] [Client 7] Waiting for request.
613D [05/Feb/2018:12:36:07 +0500] [Client 1] con->http=0x200b8b00
614D [05/Feb/2018:12:36:07 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=93, file=12
615D [05/Feb/2018:12:36:07 +0500] [Client 1] Waiting for CGI data.
616D [05/Feb/2018:12:36:07 +0500] [Client 5] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
617D [05/Feb/2018:12:36:07 +0500] [Client 5] Closing connection.
618D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
619D [05/Feb/2018:12:36:07 +0500] [Client 1] CGI data ready to be sent.
620D [05/Feb/2018:12:36:07 +0500] PID 93 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
621D [05/Feb/2018:12:36:07 +0500] [Client 8] Accepted from localhost:63570 (IPv4)
622D [05/Feb/2018:12:36:07 +0500] [Client 8] Waiting for request.
623D [05/Feb/2018:12:36:07 +0500] [Client 1] con->http=0x200b8b00
624D [05/Feb/2018:12:36:07 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=93, file=12
625D [05/Feb/2018:12:36:07 +0500] [Client 1] Waiting for CGI data.
626D [05/Feb/2018:12:36:07 +0500] [Client 1] con->http=0x200b8b00
627D [05/Feb/2018:12:36:07 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=93, file=12
628D [05/Feb/2018:12:36:07 +0500] [Client 1] Waiting for CGI data.
629D [05/Feb/2018:12:36:07 +0500] [Client 1] CGI data ready to be sent.
630D [05/Feb/2018:12:36:07 +0500] [Client 1] con->http=0x200b8b00
631D [05/Feb/2018:12:36:07 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=93, file=12
632D [05/Feb/2018:12:36:07 +0500] [Client 1] Waiting for CGI data.
633D [05/Feb/2018:12:36:07 +0500] [Client 1] Sending 0-length chunk.
634D [05/Feb/2018:12:36:07 +0500] [Client 1] Flushing write buffer.
635D [05/Feb/2018:12:36:07 +0500] [Client 1] New state is HTTP_STATE_WAITING
636D [05/Feb/2018:12:36:07 +0500] [Client 1] Waiting for request.
637D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
638D [05/Feb/2018:12:36:07 +0500] [Client 8] GET /printers/HP_Color_LaserJet_3800.ppd HTTP/1.1
639D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
640D [05/Feb/2018:12:36:07 +0500] [Client 8] Read: status=200
641D [05/Feb/2018:12:36:07 +0500] [Client 8] No authentication data provided.
642D [05/Feb/2018:12:36:07 +0500] [Client 8] Processing GET /printers/HP_Color_LaserJet_3800.ppd
643D [05/Feb/2018:12:36:07 +0500] [Client 8] filename="/@unixroot/etc/cups/ppd/HP_Color_LaserJet_3800.ppd", type=application/vnd.cups-ppd
644D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdSendHeader: code=200, type="application/vnd.cups-ppd", auth_type=0
645D [05/Feb/2018:12:36:07 +0500] [Client 8] Sending file.
646D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: +connecting-to-device
647D [05/Feb/2018:12:36:07 +0500] cupsdMarkDirty(---J-)
648D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients, printing jobs, and dirty files"
649D [05/Feb/2018:12:36:07 +0500] [Job 3] Looking up \"192.168.100.16\"...
650D [05/Feb/2018:12:36:07 +0500] [Job 3] pdftopdf: Last filter determined by the PPD: foomatic-rip; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
651D [05/Feb/2018:12:36:07 +0500] Discarding unused printer-state-changed event...
652D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
653D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
654D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
655D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
656D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
657D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
658D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
659D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
660D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
661D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
662D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
663D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
664D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
665D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
666D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
667D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
668D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
669D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
670D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
671D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
672D [05/Feb/2018:12:36:07 +0500] [Client 8] con->http=0x200bbb60
673D [05/Feb/2018:12:36:07 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=12
674D [05/Feb/2018:12:36:07 +0500] [Client 8] Flushing write buffer.
675D [05/Feb/2018:12:36:07 +0500] [Client 8] New state is HTTP_STATE_WAITING
676D [05/Feb/2018:12:36:07 +0500] [Client 8] Waiting for request.
677D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
678D [05/Feb/2018:12:36:07 +0500] [Client 8] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
679D [05/Feb/2018:12:36:07 +0500] [Client 8] Closing connection.
680D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
681D [05/Feb/2018:12:36:07 +0500] [Job 3] Parsing PPD file ...
682D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option ColorSpace
683D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option Resolution
684D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option PageSize
685D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option Model
686D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option PrintoutMode
687D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option InputSlot
688D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option Duplex
689D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option Quality
690D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option ImageableArea
691D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option PaperDimension
692D [05/Feb/2018:12:36:07 +0500] [Job 3] Added option Font
693D [05/Feb/2018:12:36:07 +0500] [Job 3] Parameter Summary
694D [05/Feb/2018:12:36:07 +0500] [Job 3] -----------------
695D [05/Feb/2018:12:36:07 +0500] [Job 3] Spooler: cups
696D [05/Feb/2018:12:36:07 +0500] [Job 3] Printer: HP_Color_LaserJet_3800
697D [05/Feb/2018:12:36:07 +0500] [Job 3] Shell: /@unixroot/usr/bin/sh
698D [05/Feb/2018:12:36:07 +0500] [Job 3] PPD file: /@unixroot/etc/cups/ppd/HP_Color_LaserJet_3800.ppd
699D [05/Feb/2018:12:36:07 +0500] [Job 3] ATTR file:
700D [05/Feb/2018:12:36:07 +0500] [Job 3] Printer model: HP Color LaserJet 3800 hpijs pcl3, 3.17.11
701D [05/Feb/2018:12:36:07 +0500] [Job 3] Job title: Test Page
702D [05/Feb/2018:12:36:07 +0500] [Job 3] File(s) to be printed:
703D [05/Feb/2018:12:36:07 +0500] [Job 3] <STDIN>
704D [05/Feb/2018:12:36:07 +0500] [Job 3] Ghostscript extra search path (\'GS_LIB\'): /@unixroot/usr/share/cups/fonts
705D [05/Feb/2018:12:36:07 +0500] [Job 3] Printing system options:
706D [05/Feb/2018:12:36:07 +0500] [Job 3] Pondering option \'job-uuid=urn:uuid:4fae2f72-1ff3-3a53-497f-2b77bcaa1172\'
707D [05/Feb/2018:12:36:07 +0500] [Job 3] Unknown option job-uuid=urn:uuid:4fae2f72-1ff3-3a53-497f-2b77bcaa1172.
708D [05/Feb/2018:12:36:07 +0500] [Job 3] Pondering option \'job-originating-host-name=localhost\'
709D [05/Feb/2018:12:36:07 +0500] [Job 3] Unknown option job-originating-host-name=localhost.
710D [05/Feb/2018:12:36:07 +0500] [Job 3] Pondering option \'date-time-at-creation=\'
711D [05/Feb/2018:12:36:07 +0500] [Job 3] Unknown option date-time-at-creation=.
712D [05/Feb/2018:12:36:07 +0500] [Job 3] Pondering option \'date-time-at-processing=\'
713D [05/Feb/2018:12:36:07 +0500] [Job 3] Unknown option date-time-at-processing=.
714D [05/Feb/2018:12:36:07 +0500] [Job 3] Pondering option \'time-at-creation=1517852166\'
715D [05/Feb/2018:12:36:07 +0500] [Job 3] Unknown option time-at-creation=1517852166.
716D [05/Feb/2018:12:36:07 +0500] [Job 3] Pondering option \'time-at-processing=1517852166\'
717D [05/Feb/2018:12:36:07 +0500] [Job 3] Unknown option time-at-processing=1517852166.
718D [05/Feb/2018:12:36:07 +0500] [Job 3] CM Color Calibration Mode in CUPS: Off
719D [05/Feb/2018:12:36:07 +0500] [Job 3] Options from the PPD file:
720D [05/Feb/2018:12:36:07 +0500] [Job 3] ================================================
721D [05/Feb/2018:12:36:07 +0500] [Job 3] File: <STDIN>
722D [05/Feb/2018:12:36:07 +0500] [Job 3] ================================================
723D [05/Feb/2018:12:36:07 +0500] [Job 3] ATTR: marker-colors=#000000,#00FFFF,#FF00FF,#FFFF00
724D [05/Feb/2018:12:36:07 +0500] cupsdMarkDirty(P----)
725D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
726D [05/Feb/2018:12:36:07 +0500] [Job 3] ATTR: marker-names=\'\"Black Cartridge HP Q6470A\"\',\'\"Cyan Cartridge HP Q7581A\"\',\'\"Magenta Cartridge HP Q7583A\"\',\'\"Yellow Cartridge HP Q7582A\"\'
727D [05/Feb/2018:12:36:07 +0500] cupsdMarkDirty(P----)
728D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
729D [05/Feb/2018:12:36:07 +0500] [Job 3] ATTR: marker-types=toner-cartridge,toner-cartridge,toner-cartridge,toner-cartridge
730D [05/Feb/2018:12:36:07 +0500] cupsdMarkDirty(P----)
731D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
732D [05/Feb/2018:12:36:07 +0500] [Job 3] ATTR: marker-levels=11,64,64,13
733D [05/Feb/2018:12:36:07 +0500] cupsdMarkDirty(P----)
734D [05/Feb/2018:12:36:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
735D [05/Feb/2018:12:36:07 +0500] [Job 3] new_supply_state=0, change_state=ffff
736D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -developer-low-report
737D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -developer-empty-warning
738D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -marker-supply-low-report
739D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -marker-supply-empty-warning
740D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -opc-near-eol-report
741D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -opc-life-over-warning
742D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -toner-low-report
743D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -toner-empty-warning
744D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -waste-receptacle-almost-full-report
745D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -waste-receptacle-full-warning
746D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -cleaner-life-almost-over-report
747D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -cleaner-life-over-warning
748D [05/Feb/2018:12:36:07 +0500] Discarding unused printer-state-changed event...
749D [05/Feb/2018:12:36:07 +0500] [Job 3] new_state=2000, change_state=ffff
750D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -media-empty-warning
751D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -door-open-report
752D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -media-jam-warning
753D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -input-tray-missing-warning
754D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -output-tray-missing-warning
755D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -marker-supply-missing-warning
756D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -output-area-almost-full-report
757D [05/Feb/2018:12:36:07 +0500] [Job 3] STATE: -output-area-full-warning
758D [05/Feb/2018:12:36:07 +0500] [Job 3] backendWaitLoop(snmp_fd=5, addr=0x20037c84, side_cb=0x110f0)
759D [05/Feb/2018:12:36:07 +0500] [Job 3] PDF template file doesn\'t have form. It\'s okay.
760W [05/Feb/2018:12:36:07 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
761D [05/Feb/2018:12:36:08 +0500] [Job 3] PAGE: 1 1
762D [05/Feb/2018:12:36:08 +0500] cupsdMarkDirty(---J-)
763D [05/Feb/2018:12:36:08 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
764D [05/Feb/2018:12:36:08 +0500] cupsdMarkDirty(---J-)
765D [05/Feb/2018:12:36:08 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
766D [05/Feb/2018:12:36:08 +0500] Discarding unused job-progress event...
767D [05/Feb/2018:12:36:08 +0500] [Job 3] Filetype: PDF
768D [05/Feb/2018:12:36:08 +0500] [Job 3] Storing temporary files in M:/var/temp
769D [05/Feb/2018:12:36:08 +0500] [Job 3] Process is dying with \"Failed to execute ghostscript to determine number of input pages! rc=2 (No such file or directory)
770D [05/Feb/2018:12:36:08 +0500] [Job 3] \", exit stat 6
771D [05/Feb/2018:12:36:08 +0500] [Job 3] Cleaning up...
772D [05/Feb/2018:12:36:08 +0500] [Job 3] PID 95 (/@unixroot/usr/lib/cups/filter/bannertopdf.exe) exited with no errors.
773D [05/Feb/2018:12:36:08 +0500] [Job 3] PID 96 (/@unixroot/usr/lib/cups/filter/pdftopdf.exe) exited with no errors.
774D [05/Feb/2018:12:36:08 +0500] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
775D [05/Feb/2018:12:36:08 +0500] [Client 6] Closing connection.
776D [05/Feb/2018:12:36:08 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
777D [05/Feb/2018:12:36:08 +0500] [Job 3] PID 98 (/@unixroot/usr/lib/cups/filter/foomatic-rip.exe) stopped with status 6.
778D [05/Feb/2018:12:36:08 +0500] [Job 3] PID 101 (/@unixroot/usr/lib/cups/backend/socket.exe) exited with no errors.
779D [05/Feb/2018:12:36:08 +0500] Discarding unused job-state-changed event...
780E [05/Feb/2018:12:36:08 +0500] [Job 3] Job stopped due to filter errors; please consult the error_log file for details.
781D [05/Feb/2018:12:36:08 +0500] cupsdMarkDirty(---J-)
782D [05/Feb/2018:12:36:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
783D [05/Feb/2018:12:36:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
784D [05/Feb/2018:12:36:08 +0500] Discarding unused printer-state-changed event...
785D [05/Feb/2018:12:36:08 +0500] cupsdMarkDirty(---J-)
786D [05/Feb/2018:12:36:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
787D [05/Feb/2018:12:36:08 +0500] [Job 3] The following messages were recorded from 12:36:07 pm to 12:36:07 pm
788D [05/Feb/2018:12:36:08 +0500] [Job 3] hrDeviceDesc=\"HP Color LaserJet 3800\"
789D [05/Feb/2018:12:36:08 +0500] [Job 3] prtMarkerColorantValue.1.1 = \"black\"
790D [05/Feb/2018:12:36:08 +0500] [Job 3] prtMarkerColorantValue.1.2 = \"cyan\"
791D [05/Feb/2018:12:36:08 +0500] [Job 3] prtMarkerColorantValue.1.3 = \"magenta\"
792D [05/Feb/2018:12:36:08 +0500] [Job 3] prtMarkerColorantValue.1.4 = \"yellow\"
793D [05/Feb/2018:12:36:08 +0500] [Job 3] End of messages
794D [05/Feb/2018:12:36:08 +0500] [Job 3] printer-state=3(idle)
795D [05/Feb/2018:12:36:08 +0500] [Job 3] printer-state-message="Filter failed"
796D [05/Feb/2018:12:36:08 +0500] [Job 3] printer-state-reasons=none
797D [05/Feb/2018:12:36:09 +0500] [Job 3] Unloading...
798D [05/Feb/2018:12:36:09 +0500] [Client 1] GET /printers/HP_Color_LaserJet_3800 HTTP/1.1
799D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
800D [05/Feb/2018:12:36:09 +0500] [Client 1] Read: status=200
801D [05/Feb/2018:12:36:09 +0500] [Client 1] No authentication data provided.
802D [05/Feb/2018:12:36:09 +0500] [Client 1] Processing GET /printers/HP_Color_LaserJet_3800
803D [05/Feb/2018:12:36:09 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
804D [05/Feb/2018:12:36:09 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
805D [05/Feb/2018:12:36:09 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
806D [05/Feb/2018:12:36:09 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
807D [05/Feb/2018:12:36:09 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
808D [05/Feb/2018:12:36:09 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
809D [05/Feb/2018:12:36:09 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
810D [05/Feb/2018:12:36:09 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
811D [05/Feb/2018:12:36:09 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
812D [05/Feb/2018:12:36:09 +0500] [CGI] envp[8] = "HOME=M:\\var\\temp"
813D [05/Feb/2018:12:36:09 +0500] [CGI] envp[9] = "NLSPATH=M:\\MPTN\\MSG\\NLS\\%N;M:\\TCPIP\\msg\\ENUS850\\%N;"
814D [05/Feb/2018:12:36:09 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
815D [05/Feb/2018:12:36:09 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
816D [05/Feb/2018:12:36:09 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
817D [05/Feb/2018:12:36:09 +0500] [CGI] envp[13] = "TMPDIR=M:\\var\\temp"
818D [05/Feb/2018:12:36:09 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
819D [05/Feb/2018:12:36:09 +0500] [CGI] envp[15] = "USER=root"
820D [05/Feb/2018:12:36:09 +0500] [CGI] envp[16] = "UNIXROOT=M:"
821D [05/Feb/2018:12:36:09 +0500] [CGI] envp[17] = "ETC=M:\\MPTN\\ETC"
822D [05/Feb/2018:12:36:09 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
823D [05/Feb/2018:12:36:09 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
824D [05/Feb/2018:12:36:09 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
825D [05/Feb/2018:12:36:09 +0500] [CGI] envp[21] = "IPP_PORT=631"
826D [05/Feb/2018:12:36:09 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
827D [05/Feb/2018:12:36:09 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
828D [05/Feb/2018:12:36:09 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
829D [05/Feb/2018:12:36:09 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
830D [05/Feb/2018:12:36:09 +0500] [CGI] envp[26] = "SERVER_PORT=631"
831D [05/Feb/2018:12:36:09 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
832D [05/Feb/2018:12:36:09 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
833D [05/Feb/2018:12:36:09 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800"
834D [05/Feb/2018:12:36:09 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800"
835D [05/Feb/2018:12:36:09 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_LaserJet_3800"
836D [05/Feb/2018:12:36:09 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
837D [05/Feb/2018:12:36:09 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=873e98c1cb8d4b69abd3f3d756f22f63"
838D [05/Feb/2018:12:36:09 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0"
839D [05/Feb/2018:12:36:09 +0500] [CGI] envp[35] = "REQUEST_METHOD=GET"
840D [05/Feb/2018:12:36:09 +0500] [CGI] envp[36] = "QUERY_STRING="
841D [05/Feb/2018:12:36:09 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 103)
842I [05/Feb/2018:12:36:09 +0500] [Client 1] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=103, file=11)
843D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
844D [05/Feb/2018:12:36:09 +0500] [Client 9] Accepted from localhost (Domain)
845D [05/Feb/2018:12:36:09 +0500] [Client 9] Waiting for request.
846D [05/Feb/2018:12:36:09 +0500] [CGI] org.cups.sid cookie is \"873e98c1cb8d4b69abd3f3d756f22f63\"
847D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
848D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
849D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
850D [05/Feb/2018:12:36:09 +0500] [Client 9] POST / HTTP/1.1
851D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
852D [05/Feb/2018:12:36:09 +0500] [Client 9] Read: status=200
853D [05/Feb/2018:12:36:09 +0500] [Client 9] No authentication data provided.
854D [05/Feb/2018:12:36:09 +0500] [Client 9] 2.0 CUPS-Get-Default 1
855D [05/Feb/2018:12:36:09 +0500] CUPS-Get-Default
856D [05/Feb/2018:12:36:09 +0500] CUPS-Get-Default client-error-not-found: No default printer.
857D [05/Feb/2018:12:36:09 +0500] [Client 9] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
858D [05/Feb/2018:12:36:09 +0500] [Client 9] Content-Length: 113
859D [05/Feb/2018:12:36:09 +0500] [Client 9] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
860D [05/Feb/2018:12:36:09 +0500] [Client 9] con->http=0x200bbb60
861D [05/Feb/2018:12:36:09 +0500] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x200af1e0(IPP_STATE_DATA), pipe_pid=0, file=-1
862D [05/Feb/2018:12:36:09 +0500] [Client 9] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
863D [05/Feb/2018:12:36:09 +0500] [Client 9] bytes=0, http_state=0, data_remaining=113
864D [05/Feb/2018:12:36:09 +0500] [Client 9] Flushing write buffer.
865D [05/Feb/2018:12:36:09 +0500] [Client 9] New state is HTTP_STATE_WAITING
866D [05/Feb/2018:12:36:09 +0500] [Client 9] Waiting for request.
867D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
868D [05/Feb/2018:12:36:09 +0500] [CGI] show_printer(http=0x2003c240, printer=\"HP_Color_LaserJet_3800\")
869D [05/Feb/2018:12:36:09 +0500] [Client 9] POST / HTTP/1.1
870D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
871D [05/Feb/2018:12:36:09 +0500] [Client 9] Read: status=200
872D [05/Feb/2018:12:36:09 +0500] [Client 9] No authentication data provided.
873D [05/Feb/2018:12:36:09 +0500] [Client 9] 2.0 Get-Printer-Attributes 2
874D [05/Feb/2018:12:36:09 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800
875D [05/Feb/2018:12:36:09 +0500] [Client 9] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800) from localhost
876D [05/Feb/2018:12:36:09 +0500] [Client 9] Content-Length: 733
877D [05/Feb/2018:12:36:09 +0500] [Client 9] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
878D [05/Feb/2018:12:36:09 +0500] [Client 9] con->http=0x200bbb60
879D [05/Feb/2018:12:36:09 +0500] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=733, response=0x200c56e0(IPP_STATE_DATA), pipe_pid=0, file=-1
880D [05/Feb/2018:12:36:09 +0500] [Client 9] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
881D [05/Feb/2018:12:36:09 +0500] [Client 9] bytes=0, http_state=0, data_remaining=733
882D [05/Feb/2018:12:36:09 +0500] [Client 9] Flushing write buffer.
883D [05/Feb/2018:12:36:09 +0500] [Client 9] New state is HTTP_STATE_WAITING
884D [05/Feb/2018:12:36:09 +0500] [Client 9] Waiting for request.
885D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
886D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
887D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
888D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
889D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
890D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
891D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
892D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
893D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
894D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800\"
895D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800\"
896D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_location[0]=\"office\"
897D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800\"
898D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
899D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: device_uri[0]=\"socket://192.168.100.16\"
900D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
901D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 hpijs pcl3, 3.17.11\"
902D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
903D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
904D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
905D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
906D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
907D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_LaserJet_3800\"
908D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
909D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
910D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
911D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
912D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=103, file=11
913D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
914D [05/Feb/2018:12:36:09 +0500] [Client 1] Script header: Content-Type: text/html;charset=utf-8
915D [05/Feb/2018:12:36:09 +0500] [Client 1] Script header:
916D [05/Feb/2018:12:36:09 +0500] [Client 1] Sending status 200 for CGI.
917D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdSendHeader: code=200, type="(null)", auth_type=0
918D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
919D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
920D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
921D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
922D [05/Feb/2018:12:36:09 +0500] [Client 9] POST / HTTP/1.1
923D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
924D [05/Feb/2018:12:36:09 +0500] [Client 9] Read: status=200
925D [05/Feb/2018:12:36:09 +0500] [Client 9] No authentication data provided.
926D [05/Feb/2018:12:36:09 +0500] [Client 9] 2.0 Get-Jobs 3
927D [05/Feb/2018:12:36:09 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_LaserJet_3800
928D [05/Feb/2018:12:36:09 +0500] [Job 3] Loading attributes...
929D [05/Feb/2018:12:36:09 +0500] [Client 9] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_LaserJet_3800) from localhost
930D [05/Feb/2018:12:36:09 +0500] [Client 9] Content-Length: 783
931D [05/Feb/2018:12:36:09 +0500] [Client 9] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
932D [05/Feb/2018:12:36:09 +0500] [CGI] Regular expression \".*Clean.*\"
933D [05/Feb/2018:12:36:09 +0500] [CGI] matches[0].rm_so=0
934D [05/Feb/2018:12:36:09 +0500] [CGI] matches[1].rm_so=-1
935D [05/Feb/2018:12:36:09 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
936D [05/Feb/2018:12:36:09 +0500] [CGI] matches[0].rm_so=0
937D [05/Feb/2018:12:36:09 +0500] [CGI] matches[1].rm_so=-1
938D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
939D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
940D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
941D [05/Feb/2018:12:36:09 +0500] [Client 9] con->http=0x200bbb60
942D [05/Feb/2018:12:36:09 +0500] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=783, response=0x200bec40(IPP_STATE_DATA), pipe_pid=0, file=-1
943D [05/Feb/2018:12:36:09 +0500] [Client 9] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
944D [05/Feb/2018:12:36:09 +0500] [Client 9] bytes=0, http_state=0, data_remaining=783
945D [05/Feb/2018:12:36:09 +0500] [Client 9] Flushing write buffer.
946D [05/Feb/2018:12:36:09 +0500] [Client 9] New state is HTTP_STATE_WAITING
947D [05/Feb/2018:12:36:09 +0500] [Client 9] Waiting for request.
948D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
949D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
950D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
951D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
952D [05/Feb/2018:12:36:09 +0500] [CGI] cgiClearVariables called.
953D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
954D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
955D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: TOTAL=\"2\"
956D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
957D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
958D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_preserved[0]=\"1\"
959D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_printer_name[0]=\"HP_Color_LaserJet_3800\"
960D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_Color_LaserJet_3800\"
961D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
962D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
963D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
964D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: time_at_creation[0]=\"Sat Feb 3 20:12:57 EST 2018\"
965D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: time_at_processing[0]=\"Sat Feb 3 20:12:57 EST 2018\"
966D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_id[0]=\"2\"
967D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_state[0]=\"6\"
968D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"1\"
969D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
970D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
971D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
972D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
973D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_preserved[1]=\"1\"
974D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_printer_name[1]=\"HP_Color_LaserJet_3800\"
975D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_printer_uri[1]=\"/printers/HP_Color_LaserJet_3800\"
976D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_name[1]=\"Test Page\"
977D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_originating_user_name[1]=\"anonymous\"
978D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: time_at_completed[1]=\"novalue\"
979D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: time_at_creation[1]=\"Mon Feb 5 12:36:06 EST 2018\"
980D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: time_at_processing[1]=\"Mon Feb 5 12:36:06 EST 2018\"
981D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_id[1]=\"3\"
982D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_state[1]=\"6\"
983D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_media_sheets_completed[1]=\"1\"
984D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_k_octets[1]=\"1\"
985D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetArray: job_printer_state_message[1]=\"Filter failed\"
986D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
987D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_LaserJet_3800\"
988D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_LaserJet_3800\"
989D [05/Feb/2018:12:36:09 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_LaserJet_3800\"
990D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
991D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
992D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
993D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
994D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
995D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
996D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
997D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
998D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
999D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1000D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1001D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1002D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1003D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1004D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
1005D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1006D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1007D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1008D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1009D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1010D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1011D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
1012D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1013D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1014D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1015D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1016D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1017D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1018D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
1019D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1020D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1021D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1022D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1023D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1024D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1025D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
1026D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1027D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1028D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1029D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1030D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1031D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1032D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
1033D [05/Feb/2018:12:36:09 +0500] [Client 9] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1034D [05/Feb/2018:12:36:09 +0500] [Client 9] Closing connection.
1035D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1036D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1037D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1038D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1039D [05/Feb/2018:12:36:09 +0500] PID 103 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
1040D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1041D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1042D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1043D [05/Feb/2018:12:36:09 +0500] [Client 1] CGI data ready to be sent.
1044D [05/Feb/2018:12:36:09 +0500] [Client 1] con->http=0x200b8b00
1045D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=103, file=11
1046D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for CGI data.
1047D [05/Feb/2018:12:36:09 +0500] [Client 1] Sending 0-length chunk.
1048D [05/Feb/2018:12:36:09 +0500] [Client 1] Flushing write buffer.
1049D [05/Feb/2018:12:36:09 +0500] [Client 1] New state is HTTP_STATE_WAITING
1050D [05/Feb/2018:12:36:09 +0500] [Client 1] Waiting for request.
1051D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
1052D [05/Feb/2018:12:36:09 +0500] [Client 1] GET /cups.css HTTP/1.1
1053D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
1054D [05/Feb/2018:12:36:09 +0500] [Client 1] Read: status=200
1055D [05/Feb/2018:12:36:09 +0500] [Client 1] No authentication data provided.
1056D [05/Feb/2018:12:36:09 +0500] [Client 1] Processing GET /cups.css
1057D [05/Feb/2018:12:36:09 +0500] [Client 1] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
1058D [05/Feb/2018:12:36:09 +0500] [Client 1] cupsdSendHeader: code=304, type="(null)", auth_type=0
1059D [05/Feb/2018:12:36:09 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
1060D [05/Feb/2018:12:36:12 +0500] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1061D [05/Feb/2018:12:36:12 +0500] [Client 7] Closing connection.
1062D [05/Feb/2018:12:36:12 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
1063D [05/Feb/2018:12:36:15 +0500] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1064D [05/Feb/2018:12:36:15 +0500] [Client 1] Closing connection.
1065D [05/Feb/2018:12:36:15 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
1066I [05/Feb/2018:12:36:38 +0500] Saving printers.conf...
1067I [05/Feb/2018:12:36:38 +0500] Saving job.cache...
1068D [05/Feb/2018:12:36:38 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"