Ticket #143: error_log-2017-09-26

File error_log-2017-09-26, 103.2 KB (added by Lewis Rosenthal, 7 years ago)

Fresh error log (SET SHELL=sh in CONFIG.SYS)

Line 
1D [26/Sep/2017:13:56:06 +0500] [Client 1] GET /printers/HP_Color_LaserJet_3800 HTTP/1.1
2D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
3D [26/Sep/2017:13:56:06 +0500] [Client 1] Read: status=200
4D [26/Sep/2017:13:56:06 +0500] [Client 1] No authentication data provided.
5D [26/Sep/2017:13:56:06 +0500] [Client 1] Processing GET /printers/HP_Color_LaserJet_3800
6D [26/Sep/2017:13:56:06 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
7D [26/Sep/2017:13:56:06 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
8D [26/Sep/2017:13:56:06 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
9D [26/Sep/2017:13:56:06 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
10D [26/Sep/2017:13:56:06 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
11D [26/Sep/2017:13:56:06 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
12D [26/Sep/2017:13:56:06 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
13D [26/Sep/2017:13:56:06 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
14D [26/Sep/2017:13:56:06 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
15D [26/Sep/2017:13:56:06 +0500] [CGI] envp[8] = "HOME=H:\\var\\temp"
16D [26/Sep/2017:13:56:06 +0500] [CGI] envp[9] = "NLSPATH=H:\\MPTN\\MSG\\NLS\\%N;H:\\TCPIP\\msg\\ENUS850\\%N;"
17D [26/Sep/2017:13:56:06 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
18D [26/Sep/2017:13:56:06 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
19D [26/Sep/2017:13:56:06 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
20D [26/Sep/2017:13:56:06 +0500] [CGI] envp[13] = "TMPDIR=H:\\var\\temp"
21D [26/Sep/2017:13:56:06 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
22D [26/Sep/2017:13:56:06 +0500] [CGI] envp[15] = "USER=root"
23D [26/Sep/2017:13:56:06 +0500] [CGI] envp[16] = "UNIXROOT=H:"
24D [26/Sep/2017:13:56:06 +0500] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
25D [26/Sep/2017:13:56:06 +0500] [CGI] envp[18] = "CUPS_SERVER=localhost"
26D [26/Sep/2017:13:56:06 +0500] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
27D [26/Sep/2017:13:56:06 +0500] [CGI] envp[20] = "IPP_PORT=631"
28D [26/Sep/2017:13:56:06 +0500] [CGI] envp[21] = "LANG=en_US.UTF8"
29D [26/Sep/2017:13:56:06 +0500] [CGI] envp[22] = "REDIRECT_STATUS=1"
30D [26/Sep/2017:13:56:06 +0500] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
31D [26/Sep/2017:13:56:06 +0500] [CGI] envp[24] = "SERVER_NAME=localhost"
32D [26/Sep/2017:13:56:06 +0500] [CGI] envp[25] = "SERVER_PORT=631"
33D [26/Sep/2017:13:56:06 +0500] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
34D [26/Sep/2017:13:56:06 +0500] [CGI] envp[27] = "REMOTE_HOST=localhost"
35D [26/Sep/2017:13:56:06 +0500] [CGI] envp[28] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800"
36D [26/Sep/2017:13:56:06 +0500] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800"
37D [26/Sep/2017:13:56:06 +0500] [CGI] envp[30] = "PATH_INFO=/HP_Color_LaserJet_3800"
38D [26/Sep/2017:13:56:06 +0500] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
39D [26/Sep/2017:13:56:06 +0500] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=ba119267d82f0c1688613ada42d0a797"
40D [26/Sep/2017:13:56:06 +0500] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
41D [26/Sep/2017:13:56:06 +0500] [CGI] envp[34] = "HTTP_REFERER=http://localhost:631/printers/HP_Color_LaserJet_3800"
42D [26/Sep/2017:13:56:06 +0500] [CGI] envp[35] = "REQUEST_METHOD=GET"
43D [26/Sep/2017:13:56:06 +0500] [CGI] envp[36] = "QUERY_STRING="
44D [26/Sep/2017:13:56:06 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 66)
45I [26/Sep/2017:13:56:06 +0500] [Client 1] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=66, file=10)
46D [26/Sep/2017:13:56:06 +0500] [Client 1] Waiting for CGI data.
47D [26/Sep/2017:13:56:06 +0500] [CGI] org.cups.sid cookie is \"ba119267d82f0c1688613ada42d0a797\"
48D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
49D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
50D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
51D [26/Sep/2017:13:56:06 +0500] [Client 2] Accepted from localhost:49974 (IPv4)
52D [26/Sep/2017:13:56:06 +0500] [Client 2] Waiting for request.
53D [26/Sep/2017:13:56:06 +0500] [Client 2] POST / HTTP/1.1
54D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
55D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=200
56D [26/Sep/2017:13:56:06 +0500] [Client 2] No authentication data provided.
57D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=100
58D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=100
59D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=100
60D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=100
61D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=100
62D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=100
63D [26/Sep/2017:13:56:06 +0500] [Client 2] 2.0 CUPS-Get-Default 1
64D [26/Sep/2017:13:56:06 +0500] CUPS-Get-Default
65D [26/Sep/2017:13:56:06 +0500] CUPS-Get-Default client-error-not-found: No default printer.
66D [26/Sep/2017:13:56:06 +0500] [Client 2] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
67D [26/Sep/2017:13:56:06 +0500] [Client 2] Content-Length: 113
68D [26/Sep/2017:13:56:06 +0500] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
69D [26/Sep/2017:13:56:06 +0500] [Client 2] con->http=0x200f41e0
70D [26/Sep/2017:13:56:06 +0500] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x200af7c0(IPP_STATE_DATA), pipe_pid=0, file=-1
71D [26/Sep/2017:13:56:06 +0500] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
72D [26/Sep/2017:13:56:06 +0500] [Client 2] bytes=0, http_state=0, data_remaining=113
73D [26/Sep/2017:13:56:06 +0500] [Client 2] Flushing write buffer.
74D [26/Sep/2017:13:56:06 +0500] [Client 2] New state is HTTP_STATE_WAITING
75D [26/Sep/2017:13:56:06 +0500] [Client 2] Waiting for request.
76D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
77D [26/Sep/2017:13:56:06 +0500] [CGI] show_printer(http=0x2003c240, printer=\"HP_Color_LaserJet_3800\")
78D [26/Sep/2017:13:56:06 +0500] [Client 2] POST / HTTP/1.1
79D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
80D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=200
81D [26/Sep/2017:13:56:06 +0500] [Client 2] No authentication data provided.
82D [26/Sep/2017:13:56:06 +0500] [Client 2] 2.0 Get-Printer-Attributes 2
83D [26/Sep/2017:13:56:06 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800
84D [26/Sep/2017:13:56:06 +0500] [Client 2] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800) from localhost
85D [26/Sep/2017:13:56:06 +0500] [Client 2] Content-Length: 757
86D [26/Sep/2017:13:56:06 +0500] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
87D [26/Sep/2017:13:56:06 +0500] [Client 2] con->http=0x200f41e0
88D [26/Sep/2017:13:56:06 +0500] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=757, response=0x200af820(IPP_STATE_DATA), pipe_pid=0, file=-1
89D [26/Sep/2017:13:56:06 +0500] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
90D [26/Sep/2017:13:56:06 +0500] [Client 2] bytes=0, http_state=0, data_remaining=757
91D [26/Sep/2017:13:56:06 +0500] [Client 2] Flushing write buffer.
92D [26/Sep/2017:13:56:06 +0500] [Client 2] New state is HTTP_STATE_WAITING
93D [26/Sep/2017:13:56:06 +0500] [Client 2] Waiting for request.
94D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
95D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
96D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
97D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
98D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
99D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
100D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
101D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
102D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
103D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800\"
104D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800\"
105D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_location[0]=\"\"
106D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800\"
107D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
108D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: device_uri[0]=\"usb://HP/Color%20LaserJet%203800?serial=CNDBB03809\"
109D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
110D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 hpijs pcl3, 3.16.5\"
111D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
112D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
113D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
114D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
115D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
116D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_LaserJet_3800\"
117D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
118D [26/Sep/2017:13:56:06 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
119D [26/Sep/2017:13:56:06 +0500] [Client 1] CGI data ready to be sent.
120D [26/Sep/2017:13:56:06 +0500] [Client 1] con->http=0x200f0000
121D [26/Sep/2017:13:56:06 +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=66, file=10
122D [26/Sep/2017:13:56:06 +0500] [Client 1] Waiting for CGI data.
123D [26/Sep/2017:13:56:06 +0500] [Client 1] Script header: Content-Type: text/html;charset=utf-8
124D [26/Sep/2017:13:56:06 +0500] [Client 1] Script header:
125D [26/Sep/2017:13:56:06 +0500] [Client 1] Sending status 200 for CGI.
126D [26/Sep/2017:13:56:06 +0500] [Client 1] cupsdSendHeader: code=200, type="(null)", auth_type=0
127D [26/Sep/2017:13:56:06 +0500] [CGI] Regular expression \".*Clean.*\"
128D [26/Sep/2017:13:56:06 +0500] [Client 1] con->http=0x200f0000
129D [26/Sep/2017:13:56:06 +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=66, file=10
130D [26/Sep/2017:13:56:06 +0500] [Client 1] Waiting for CGI data.
131D [26/Sep/2017:13:56:06 +0500] [CGI] matches[0].rm_so=0
132D [26/Sep/2017:13:56:06 +0500] [CGI] matches[1].rm_so=-1
133D [26/Sep/2017:13:56:06 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
134D [26/Sep/2017:13:56:06 +0500] [CGI] matches[0].rm_so=0
135D [26/Sep/2017:13:56:06 +0500] [CGI] matches[1].rm_so=-1
136D [26/Sep/2017:13:56:06 +0500] [Client 1] CGI data ready to be sent.
137D [26/Sep/2017:13:56:06 +0500] [Client 1] con->http=0x200f0000
138D [26/Sep/2017:13:56:06 +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=66, file=10
139D [26/Sep/2017:13:56:06 +0500] [Client 1] Waiting for CGI data.
140D [26/Sep/2017:13:56:06 +0500] [Client 1] con->http=0x200f0000
141D [26/Sep/2017:13:56:06 +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=66, file=10
142D [26/Sep/2017:13:56:06 +0500] [Client 1] Waiting for CGI data.
143D [26/Sep/2017:13:56:06 +0500] [Client 1] CGI data ready to be sent.
144D [26/Sep/2017:13:56:06 +0500] [Client 1] con->http=0x200f0000
145D [26/Sep/2017:13:56:06 +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=66, file=10
146D [26/Sep/2017:13:56:06 +0500] [Client 1] Waiting for CGI data.
147D [26/Sep/2017:13:56:06 +0500] [Client 1] con->http=0x200f0000
148D [26/Sep/2017:13:56:06 +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=66, file=10
149D [26/Sep/2017:13:56:06 +0500] [Client 1] Waiting for CGI data.
150D [26/Sep/2017:13:56:06 +0500] [Client 2] POST / HTTP/1.1
151D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
152D [26/Sep/2017:13:56:06 +0500] [Client 2] Read: status=200
153D [26/Sep/2017:13:56:06 +0500] [Client 2] No authentication data provided.
154D [26/Sep/2017:13:56:06 +0500] [Client 2] 2.0 Get-Jobs 3
155D [26/Sep/2017:13:56:06 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_LaserJet_3800
156D [26/Sep/2017:13:56:06 +0500] [Job 7] Loading attributes...
157D [26/Sep/2017:13:56:06 +0500] [Client 2] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_LaserJet_3800) from localhost
158D [26/Sep/2017:13:56:06 +0500] [Client 2] Content-Length: 433
159D [26/Sep/2017:13:56:06 +0500] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
160D [26/Sep/2017:13:56:06 +0500] [Client 3] Accepted from localhost:49975 (IPv4)
161D [26/Sep/2017:13:56:06 +0500] [Client 3] Waiting for request.
162D [26/Sep/2017:13:56:06 +0500] [Client 2] con->http=0x200f41e0
163D [26/Sep/2017:13:56:06 +0500] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=433, response=0x200af860(IPP_STATE_DATA), pipe_pid=0, file=-1
164D [26/Sep/2017:13:56:06 +0500] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
165D [26/Sep/2017:13:56:06 +0500] [Client 2] bytes=0, http_state=0, data_remaining=433
166D [26/Sep/2017:13:56:06 +0500] [Client 2] Flushing write buffer.
167D [26/Sep/2017:13:56:06 +0500] [Client 2] New state is HTTP_STATE_WAITING
168D [26/Sep/2017:13:56:06 +0500] [Client 2] Waiting for request.
169D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
170D [26/Sep/2017:13:56:06 +0500] [Client 3] GET /cups.css HTTP/1.1
171D [26/Sep/2017:13:56:06 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
172D [26/Sep/2017:13:56:06 +0500] [Client 3] Read: status=200
173D [26/Sep/2017:13:56:06 +0500] [Client 3] No authentication data provided.
174D [26/Sep/2017:13:56:06 +0500] [Client 3] Processing GET /cups.css
175D [26/Sep/2017:13:56:07 +0500] [Client 3] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
176D [26/Sep/2017:13:56:07 +0500] [Client 3] cupsdSendHeader: code=200, type="text/css", auth_type=0
177D [26/Sep/2017:13:56:07 +0500] [Client 3] Sending file.
178D [26/Sep/2017:13:56:07 +0500] [CGI] cgiClearVariables called.
179D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
180D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
181D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: TOTAL=\"1\"
182D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
183D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
184D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_preserved[0]=\"1\"
185D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_printer_name[0]=\"HP_Color_LaserJet_3800\"
186D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_Color_LaserJet_3800\"
187D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
188D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
189D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
190D [26/Sep/2017:13:56:07 +0500] [Client 3] con->http=0x200fa3e0
191D [26/Sep/2017:13:56:07 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=13
192D [26/Sep/2017:13:56:07 +0500] [Client 3] con->http=0x200fa3e0
193D [26/Sep/2017:13:56:07 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=13
194D [26/Sep/2017:13:56:07 +0500] [Client 3] con->http=0x200fa3e0
195D [26/Sep/2017:13:56:07 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=13
196D [26/Sep/2017:13:56:07 +0500] [Client 3] con->http=0x200fa3e0
197D [26/Sep/2017:13:56:07 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=13
198D [26/Sep/2017:13:56:07 +0500] [Client 3] con->http=0x200fa3e0
199D [26/Sep/2017:13:56:07 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=13
200D [26/Sep/2017:13:56:07 +0500] [Client 3] Flushing write buffer.
201D [26/Sep/2017:13:56:07 +0500] [Client 3] New state is HTTP_STATE_WAITING
202D [26/Sep/2017:13:56:07 +0500] [Client 3] Waiting for request.
203D [26/Sep/2017:13:56:07 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
204D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: time_at_creation[0]=\"Tue Sep 26 13:44:34 EDT 2017\"
205D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: time_at_processing[0]=\"Tue Sep 26 13:44:34 EDT 2017\"
206D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_id[0]=\"7\"
207D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_state[0]=\"6\"
208D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"0\"
209D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
210D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
211D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
212D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_LaserJet_3800\"
213D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_LaserJet_3800\"
214D [26/Sep/2017:13:56:07 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_LaserJet_3800\"
215D [26/Sep/2017:13:56:07 +0500] [Client 1] CGI data ready to be sent.
216D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
217D [26/Sep/2017:13:56:07 +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=66, file=10
218D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
219D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
220D [26/Sep/2017:13:56:07 +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=66, file=10
221D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
222D [26/Sep/2017:13:56:07 +0500] [Client 1] CGI data ready to be sent.
223D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
224D [26/Sep/2017:13:56:07 +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=66, file=10
225D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
226D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
227D [26/Sep/2017:13:56:07 +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=66, file=10
228D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
229D [26/Sep/2017:13:56:07 +0500] [Client 1] CGI data ready to be sent.
230D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
231D [26/Sep/2017:13:56:07 +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=66, file=10
232D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
233D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
234D [26/Sep/2017:13:56:07 +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=66, file=10
235D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
236D [26/Sep/2017:13:56:07 +0500] [Client 1] CGI data ready to be sent.
237D [26/Sep/2017:13:56:07 +0500] [Client 2] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
238D [26/Sep/2017:13:56:07 +0500] [Client 2] Closing connection.
239D [26/Sep/2017:13:56:07 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
240D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
241D [26/Sep/2017:13:56:07 +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=66, file=10
242D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
243D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
244D [26/Sep/2017:13:56:07 +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=66, file=10
245D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
246D [26/Sep/2017:13:56:07 +0500] [Client 1] CGI data ready to be sent.
247D [26/Sep/2017:13:56:07 +0500] [Client 1] con->http=0x200f0000
248D [26/Sep/2017:13:56:07 +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=66, file=10
249D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for CGI data.
250D [26/Sep/2017:13:56:07 +0500] [Client 1] Sending 0-length chunk.
251D [26/Sep/2017:13:56:07 +0500] [Client 1] Flushing write buffer.
252D [26/Sep/2017:13:56:07 +0500] [Client 1] New state is HTTP_STATE_WAITING
253D [26/Sep/2017:13:56:07 +0500] [Client 1] Waiting for request.
254D [26/Sep/2017:13:56:07 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
255W [26/Sep/2017:13:56:07 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
256D [26/Sep/2017:13:56:08 +0500] PID 66 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
257D [26/Sep/2017:13:56:10 +0500] [Client 3] POST /jobs/ HTTP/1.1
258D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
259D [26/Sep/2017:13:56:10 +0500] [Client 3] Read: status=200
260D [26/Sep/2017:13:56:10 +0500] [Client 3] No authentication data provided.
261D [26/Sep/2017:13:56:10 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi"
262D [26/Sep/2017:13:56:10 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
263D [26/Sep/2017:13:56:10 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
264D [26/Sep/2017:13:56:10 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
265D [26/Sep/2017:13:56:10 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
266D [26/Sep/2017:13:56:10 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
267D [26/Sep/2017:13:56:10 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
268D [26/Sep/2017:13:56:10 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
269D [26/Sep/2017:13:56:10 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
270D [26/Sep/2017:13:56:10 +0500] [CGI] envp[8] = "HOME=H:\\var\\temp"
271D [26/Sep/2017:13:56:10 +0500] [CGI] envp[9] = "NLSPATH=H:\\MPTN\\MSG\\NLS\\%N;H:\\TCPIP\\msg\\ENUS850\\%N;"
272D [26/Sep/2017:13:56:10 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
273D [26/Sep/2017:13:56:10 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
274D [26/Sep/2017:13:56:10 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
275D [26/Sep/2017:13:56:10 +0500] [CGI] envp[13] = "TMPDIR=H:\\var\\temp"
276D [26/Sep/2017:13:56:10 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
277D [26/Sep/2017:13:56:10 +0500] [CGI] envp[15] = "USER=root"
278D [26/Sep/2017:13:56:10 +0500] [CGI] envp[16] = "UNIXROOT=H:"
279D [26/Sep/2017:13:56:10 +0500] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
280D [26/Sep/2017:13:56:10 +0500] [CGI] envp[18] = "CUPS_SERVER=localhost"
281D [26/Sep/2017:13:56:10 +0500] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
282D [26/Sep/2017:13:56:10 +0500] [CGI] envp[20] = "IPP_PORT=631"
283D [26/Sep/2017:13:56:10 +0500] [CGI] envp[21] = "LANG=en_US.UTF8"
284D [26/Sep/2017:13:56:10 +0500] [CGI] envp[22] = "REDIRECT_STATUS=1"
285D [26/Sep/2017:13:56:10 +0500] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
286D [26/Sep/2017:13:56:10 +0500] [CGI] envp[24] = "SERVER_NAME=localhost"
287D [26/Sep/2017:13:56:10 +0500] [CGI] envp[25] = "SERVER_PORT=631"
288D [26/Sep/2017:13:56:10 +0500] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
289D [26/Sep/2017:13:56:10 +0500] [CGI] envp[27] = "REMOTE_HOST=localhost"
290D [26/Sep/2017:13:56:10 +0500] [CGI] envp[28] = "SCRIPT_NAME=/jobs/"
291D [26/Sep/2017:13:56:10 +0500] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/jobs/"
292D [26/Sep/2017:13:56:10 +0500] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
293D [26/Sep/2017:13:56:10 +0500] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=ba119267d82f0c1688613ada42d0a797"
294D [26/Sep/2017:13:56:10 +0500] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
295D [26/Sep/2017:13:56:10 +0500] [CGI] envp[33] = "HTTP_REFERER=http://localhost:631/printers/HP_Color_LaserJet_3800"
296D [26/Sep/2017:13:56:10 +0500] [CGI] envp[34] = "REQUEST_METHOD=POST"
297D [26/Sep/2017:13:56:10 +0500] [CGI] envp[35] = "CONTENT_LENGTH=121"
298D [26/Sep/2017:13:56:10 +0500] [CGI] envp[36] = "CONTENT_TYPE=application/x-www-form-urlencoded"
299D [26/Sep/2017:13:56:10 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/jobs.cgi (PID 68)
300I [26/Sep/2017:13:56:10 +0500] [Client 3] Started "/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi" (pid=68, file=11)
301D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for CGI data.
302D [26/Sep/2017:13:56:10 +0500] [Client 4] Accepted from localhost:49976 (IPv4)
303D [26/Sep/2017:13:56:10 +0500] [Client 4] Waiting for request.
304D [26/Sep/2017:13:56:10 +0500] [CGI] org.cups.sid cookie is \"ba119267d82f0c1688613ada42d0a797\"
305D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: org.cups.sid=\"ba119267d82f0c1688613ada42d0a797\"
306D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: OP=\"cancel-job\"
307D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: job_id=\"7\"
308D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: job_printer_uri=\"/printers/HP_Color_LaserJet_3800\"
309D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: SECTION=\"jobs\"
310D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
311D [26/Sep/2017:13:56:10 +0500] [Client 4] POST /jobs HTTP/1.1
312D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
313D [26/Sep/2017:13:56:10 +0500] [Client 4] Read: status=200
314D [26/Sep/2017:13:56:10 +0500] [Client 4] No authentication data provided.
315D [26/Sep/2017:13:56:10 +0500] [Client 4] 2.0 Cancel-Job 1
316D [26/Sep/2017:13:56:10 +0500] Cancel-Job ipp://localhost/jobs/7
317D [26/Sep/2017:13:56:10 +0500] cupsdIsAuthorized: requesting-user-name="guest"
318D [26/Sep/2017:13:56:10 +0500] [Client 4] Returning HTTP Unauthorized for Cancel-Job (ipp://localhost/jobs/7) from localhost
319D [26/Sep/2017:13:56:10 +0500] [Client 4] cupsdSendHeader: code=401, type="text/html", auth_type=0
320D [26/Sep/2017:13:56:10 +0500] [Client 4] WWW-Authenticate: Basic realm=\"CUPS\", trc=\"y\"
321D [26/Sep/2017:13:56:10 +0500] [Client 5] Accepted from localhost:49977 (IPv4)
322D [26/Sep/2017:13:56:10 +0500] [Client 5] Waiting for request.
323D [26/Sep/2017:13:56:10 +0500] [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
324D [26/Sep/2017:13:56:10 +0500] [Client 4] Closing connection.
325D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
326D [26/Sep/2017:13:56:10 +0500] [Client 6] Accepted from localhost:49978 (IPv4)
327D [26/Sep/2017:13:56:10 +0500] [Client 6] Waiting for request.
328D [26/Sep/2017:13:56:10 +0500] [Client 5] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
329D [26/Sep/2017:13:56:10 +0500] [Client 5] Closing connection.
330D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
331D [26/Sep/2017:13:56:10 +0500] [Client 7] Accepted from localhost:49979 (IPv4)
332D [26/Sep/2017:13:56:10 +0500] [Client 7] Waiting for request.
333D [26/Sep/2017:13:56:10 +0500] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
334D [26/Sep/2017:13:56:10 +0500] [Client 6] Closing connection.
335D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
336D [26/Sep/2017:13:56:10 +0500] [Client 7] POST /jobs HTTP/1.1
337D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
338D [26/Sep/2017:13:56:10 +0500] [Client 7] Read: status=200
339D [26/Sep/2017:13:56:10 +0500] [Client 7] Authorized as root using Local.
340D [26/Sep/2017:13:56:10 +0500] [Client 7] 2.0 Cancel-Job 1
341D [26/Sep/2017:13:56:10 +0500] Cancel-Job ipp://localhost/jobs/7
342D [26/Sep/2017:13:56:10 +0500] cupsdIsAuthorized: username="root"
343D [26/Sep/2017:13:56:10 +0500] [Job 7] time-at-completed=1506448570
344D [26/Sep/2017:13:56:10 +0500] Discarding unused job-completed event...
345I [26/Sep/2017:13:56:10 +0500] [Job 7] Job canceled by \"root\"
346I [26/Sep/2017:13:56:10 +0500] Expiring subscriptions...
347D [26/Sep/2017:13:56:10 +0500] cupsdMarkDirty(---J-)
348D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
349D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
350I [26/Sep/2017:13:56:10 +0500] [Job 7] Canceled by "root".
351D [26/Sep/2017:13:56:10 +0500] [Client 7] Returning IPP successful-ok for Cancel-Job (ipp://localhost/jobs/7) from localhost
352D [26/Sep/2017:13:56:10 +0500] [Client 7] Content-Length: 75
353D [26/Sep/2017:13:56:10 +0500] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
354D [26/Sep/2017:13:56:10 +0500] [Job 7] Removing document files.
355D [26/Sep/2017:13:56:10 +0500] cupsdMarkDirty(---J-)
356D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
357D [26/Sep/2017:13:56:10 +0500] [Client 7] con->http=0x200fe5c0
358D [26/Sep/2017:13:56:10 +0500] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x200af4a0(IPP_STATE_DATA), pipe_pid=0, file=-1
359D [26/Sep/2017:13:56:10 +0500] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
360D [26/Sep/2017:13:56:10 +0500] [Client 7] bytes=0, http_state=0, data_remaining=75
361D [26/Sep/2017:13:56:10 +0500] [Client 7] Flushing write buffer.
362D [26/Sep/2017:13:56:10 +0500] [Client 7] New state is HTTP_STATE_WAITING
363D [26/Sep/2017:13:56:10 +0500] [Client 7] Waiting for request.
364D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
365D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: refresh_page=\"5;URL=http://localhost:631/printers/HP_Color_LaserJet_3800\"
366D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: TITLE=\"Jobs\"
367D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
368D [26/Sep/2017:13:56:10 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
369D [26/Sep/2017:13:56:10 +0500] [Client 3] CGI data ready to be sent.
370D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
371D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=68, file=11
372D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for CGI data.
373D [26/Sep/2017:13:56:10 +0500] [Client 3] Script header: Content-Type: text/html;charset=utf-8
374D [26/Sep/2017:13:56:10 +0500] [Client 3] Script header:
375D [26/Sep/2017:13:56:10 +0500] [Client 3] Sending status 200 for CGI.
376D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdSendHeader: code=200, type="(null)", auth_type=0
377D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
378D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=68, file=11
379D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for CGI data.
380D [26/Sep/2017:13:56:10 +0500] [Client 3] CGI data ready to be sent.
381D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
382D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=68, file=11
383D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for CGI data.
384D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
385D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=68, file=11
386D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for CGI data.
387D [26/Sep/2017:13:56:10 +0500] [Client 3] CGI data ready to be sent.
388D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
389D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=68, file=11
390D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for CGI data.
391D [26/Sep/2017:13:56:10 +0500] [Client 3] CGI data ready to be sent.
392D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
393D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=68, file=11
394D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for CGI data.
395D [26/Sep/2017:13:56:10 +0500] [Client 3] Sending 0-length chunk.
396D [26/Sep/2017:13:56:10 +0500] [Client 3] Flushing write buffer.
397D [26/Sep/2017:13:56:10 +0500] [Client 3] New state is HTTP_STATE_WAITING
398D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for request.
399D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
400D [26/Sep/2017:13:56:10 +0500] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
401D [26/Sep/2017:13:56:10 +0500] [Client 7] Closing connection.
402D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
403D [26/Sep/2017:13:56:10 +0500] PID 68 (/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi) exited with no errors.
404D [26/Sep/2017:13:56:10 +0500] [Client 3] GET /cups.css HTTP/1.1
405D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
406D [26/Sep/2017:13:56:10 +0500] [Client 3] Read: status=200
407D [26/Sep/2017:13:56:10 +0500] [Client 3] No authentication data provided.
408D [26/Sep/2017:13:56:10 +0500] [Client 3] Processing GET /cups.css
409D [26/Sep/2017:13:56:10 +0500] [Client 3] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
410D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdSendHeader: code=200, type="text/css", auth_type=0
411D [26/Sep/2017:13:56:10 +0500] [Client 3] Sending file.
412D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
413D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
414D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
415D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
416D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
417D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
418D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
419D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
420D [26/Sep/2017:13:56:10 +0500] [Client 3] con->http=0x200fa3e0
421D [26/Sep/2017:13:56:10 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
422D [26/Sep/2017:13:56:10 +0500] [Client 3] Flushing write buffer.
423D [26/Sep/2017:13:56:10 +0500] [Client 3] New state is HTTP_STATE_WAITING
424D [26/Sep/2017:13:56:10 +0500] [Client 3] Waiting for request.
425D [26/Sep/2017:13:56:10 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
426D [26/Sep/2017:13:56:15 +0500] [Client 3] GET /printers/HP_Color_LaserJet_3800 HTTP/1.1
427D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
428D [26/Sep/2017:13:56:15 +0500] [Client 3] Read: status=200
429D [26/Sep/2017:13:56:15 +0500] [Client 3] No authentication data provided.
430D [26/Sep/2017:13:56:15 +0500] [Client 3] Processing GET /printers/HP_Color_LaserJet_3800
431D [26/Sep/2017:13:56:15 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
432D [26/Sep/2017:13:56:15 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
433D [26/Sep/2017:13:56:15 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
434D [26/Sep/2017:13:56:15 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
435D [26/Sep/2017:13:56:15 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
436D [26/Sep/2017:13:56:15 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
437D [26/Sep/2017:13:56:15 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
438D [26/Sep/2017:13:56:15 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
439D [26/Sep/2017:13:56:15 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
440D [26/Sep/2017:13:56:15 +0500] [CGI] envp[8] = "HOME=H:\\var\\temp"
441D [26/Sep/2017:13:56:15 +0500] [CGI] envp[9] = "NLSPATH=H:\\MPTN\\MSG\\NLS\\%N;H:\\TCPIP\\msg\\ENUS850\\%N;"
442D [26/Sep/2017:13:56:15 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
443D [26/Sep/2017:13:56:15 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
444D [26/Sep/2017:13:56:15 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
445D [26/Sep/2017:13:56:15 +0500] [CGI] envp[13] = "TMPDIR=H:\\var\\temp"
446D [26/Sep/2017:13:56:15 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
447D [26/Sep/2017:13:56:15 +0500] [CGI] envp[15] = "USER=root"
448D [26/Sep/2017:13:56:15 +0500] [CGI] envp[16] = "UNIXROOT=H:"
449D [26/Sep/2017:13:56:15 +0500] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
450D [26/Sep/2017:13:56:15 +0500] [CGI] envp[18] = "CUPS_SERVER=localhost"
451D [26/Sep/2017:13:56:15 +0500] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
452D [26/Sep/2017:13:56:15 +0500] [CGI] envp[20] = "IPP_PORT=631"
453D [26/Sep/2017:13:56:15 +0500] [CGI] envp[21] = "LANG=en_US.UTF8"
454D [26/Sep/2017:13:56:15 +0500] [CGI] envp[22] = "REDIRECT_STATUS=1"
455D [26/Sep/2017:13:56:15 +0500] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
456D [26/Sep/2017:13:56:15 +0500] [CGI] envp[24] = "SERVER_NAME=localhost"
457D [26/Sep/2017:13:56:15 +0500] [CGI] envp[25] = "SERVER_PORT=631"
458D [26/Sep/2017:13:56:15 +0500] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
459D [26/Sep/2017:13:56:15 +0500] [CGI] envp[27] = "REMOTE_HOST=localhost"
460D [26/Sep/2017:13:56:15 +0500] [CGI] envp[28] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800"
461D [26/Sep/2017:13:56:15 +0500] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800"
462D [26/Sep/2017:13:56:15 +0500] [CGI] envp[30] = "PATH_INFO=/HP_Color_LaserJet_3800"
463D [26/Sep/2017:13:56:15 +0500] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
464D [26/Sep/2017:13:56:15 +0500] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=ba119267d82f0c1688613ada42d0a797"
465D [26/Sep/2017:13:56:15 +0500] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
466D [26/Sep/2017:13:56:15 +0500] [CGI] envp[34] = "REQUEST_METHOD=GET"
467D [26/Sep/2017:13:56:15 +0500] [CGI] envp[35] = "QUERY_STRING="
468D [26/Sep/2017:13:56:15 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 70)
469I [26/Sep/2017:13:56:15 +0500] [Client 3] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=70, file=10)
470D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
471D [26/Sep/2017:13:56:15 +0500] [Client 8] Accepted from localhost:49980 (IPv4)
472D [26/Sep/2017:13:56:15 +0500] [Client 8] Waiting for request.
473D [26/Sep/2017:13:56:15 +0500] [CGI] org.cups.sid cookie is \"ba119267d82f0c1688613ada42d0a797\"
474D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
475D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
476D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
477D [26/Sep/2017:13:56:15 +0500] [Client 8] POST / HTTP/1.1
478D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
479D [26/Sep/2017:13:56:15 +0500] [Client 8] Read: status=200
480D [26/Sep/2017:13:56:15 +0500] [Client 8] No authentication data provided.
481D [26/Sep/2017:13:56:15 +0500] [Client 8] 2.0 CUPS-Get-Default 1
482D [26/Sep/2017:13:56:15 +0500] CUPS-Get-Default
483D [26/Sep/2017:13:56:15 +0500] CUPS-Get-Default client-error-not-found: No default printer.
484D [26/Sep/2017:13:56:15 +0500] [Client 8] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
485D [26/Sep/2017:13:56:15 +0500] [Client 8] Content-Length: 113
486D [26/Sep/2017:13:56:15 +0500] [Client 8] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
487D [26/Sep/2017:13:56:15 +0500] [Client 8] con->http=0x200f41e0
488D [26/Sep/2017:13:56:15 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x200af4a0(IPP_STATE_DATA), pipe_pid=0, file=-1
489D [26/Sep/2017:13:56:15 +0500] [Client 8] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
490D [26/Sep/2017:13:56:15 +0500] [Client 8] bytes=0, http_state=0, data_remaining=113
491D [26/Sep/2017:13:56:15 +0500] [Client 8] Flushing write buffer.
492D [26/Sep/2017:13:56:15 +0500] [Client 8] New state is HTTP_STATE_WAITING
493D [26/Sep/2017:13:56:15 +0500] [Client 8] Waiting for request.
494D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
495D [26/Sep/2017:13:56:15 +0500] [CGI] show_printer(http=0x2003c220, printer=\"HP_Color_LaserJet_3800\")
496D [26/Sep/2017:13:56:15 +0500] [Client 8] POST / HTTP/1.1
497D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
498D [26/Sep/2017:13:56:15 +0500] [Client 8] Read: status=200
499D [26/Sep/2017:13:56:15 +0500] [Client 8] No authentication data provided.
500D [26/Sep/2017:13:56:15 +0500] [Client 8] 2.0 Get-Printer-Attributes 2
501D [26/Sep/2017:13:56:15 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800
502D [26/Sep/2017:13:56:15 +0500] [Client 8] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800) from localhost
503D [26/Sep/2017:13:56:15 +0500] [Client 8] Content-Length: 757
504D [26/Sep/2017:13:56:15 +0500] [Client 8] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
505D [26/Sep/2017:13:56:15 +0500] [Client 8] con->http=0x200f41e0
506D [26/Sep/2017:13:56:15 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=757, response=0x200f7500(IPP_STATE_DATA), pipe_pid=0, file=-1
507D [26/Sep/2017:13:56:15 +0500] [Client 8] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
508D [26/Sep/2017:13:56:15 +0500] [Client 8] bytes=0, http_state=0, data_remaining=757
509D [26/Sep/2017:13:56:15 +0500] [Client 8] Flushing write buffer.
510D [26/Sep/2017:13:56:15 +0500] [Client 8] New state is HTTP_STATE_WAITING
511D [26/Sep/2017:13:56:15 +0500] [Client 8] Waiting for request.
512D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
513D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
514D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
515D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
516D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
517D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
518D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
519D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
520D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
521D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800\"
522D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800\"
523D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_location[0]=\"\"
524D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800\"
525D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
526D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: device_uri[0]=\"usb://HP/Color%20LaserJet%203800?serial=CNDBB03809\"
527D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
528D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 hpijs pcl3, 3.16.5\"
529D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
530D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
531D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
532D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
533D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
534D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
535D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_LaserJet_3800\"
536D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
537D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
538D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
539D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=70, file=10
540D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
541D [26/Sep/2017:13:56:15 +0500] [Client 3] Script header: Content-Type: text/html;charset=utf-8
542D [26/Sep/2017:13:56:15 +0500] [Client 3] Script header:
543D [26/Sep/2017:13:56:15 +0500] [Client 3] Sending status 200 for CGI.
544D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdSendHeader: code=200, type="(null)", auth_type=0
545D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
546D [26/Sep/2017:13:56:15 +0500] [Client 8] POST / HTTP/1.1
547D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
548D [26/Sep/2017:13:56:15 +0500] [Client 8] Read: status=200
549D [26/Sep/2017:13:56:15 +0500] [Client 8] No authentication data provided.
550D [26/Sep/2017:13:56:15 +0500] [Client 8] 2.0 Get-Jobs 3
551D [26/Sep/2017:13:56:15 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_LaserJet_3800
552D [26/Sep/2017:13:56:15 +0500] [Client 8] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_LaserJet_3800) from localhost
553D [26/Sep/2017:13:56:15 +0500] [Client 8] Content-Length: 75
554D [26/Sep/2017:13:56:15 +0500] [Client 8] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
555D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
556D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
557D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
558D [26/Sep/2017:13:56:15 +0500] [CGI] Regular expression \".*Clean.*\"
559D [26/Sep/2017:13:56:15 +0500] [CGI] matches[0].rm_so=0
560D [26/Sep/2017:13:56:15 +0500] [CGI] matches[1].rm_so=-1
561D [26/Sep/2017:13:56:15 +0500] [Client 8] con->http=0x200f41e0
562D [26/Sep/2017:13:56:15 +0500] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x200f7600(IPP_STATE_DATA), pipe_pid=0, file=-1
563D [26/Sep/2017:13:56:15 +0500] [Client 8] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
564D [26/Sep/2017:13:56:15 +0500] [Client 8] bytes=0, http_state=0, data_remaining=75
565D [26/Sep/2017:13:56:15 +0500] [Client 8] Flushing write buffer.
566D [26/Sep/2017:13:56:15 +0500] [Client 8] New state is HTTP_STATE_WAITING
567D [26/Sep/2017:13:56:15 +0500] [Client 8] Waiting for request.
568D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
569D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
570D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
571D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
572D [26/Sep/2017:13:56:15 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
573D [26/Sep/2017:13:56:15 +0500] [CGI] matches[0].rm_so=0
574D [26/Sep/2017:13:56:15 +0500] [CGI] matches[1].rm_so=-1
575D [26/Sep/2017:13:56:15 +0500] [CGI] cgiClearVariables called.
576D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
577D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
578D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: TOTAL=\"0\"
579D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
580D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_LaserJet_3800\"
581D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_LaserJet_3800\"
582D [26/Sep/2017:13:56:15 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_LaserJet_3800\"
583D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
584D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
585D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
586D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
587D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
588D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
589D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
590D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
591D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
592D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
593D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
594D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
595D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
596D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
597D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
598D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
599D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
600D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
601D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
602D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
603D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
604D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
605D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
606D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
607D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
608D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
609D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
610D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
611D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
612D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
613D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
614D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
615D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
616D [26/Sep/2017:13:56:15 +0500] [Client 3] CGI data ready to be sent.
617D [26/Sep/2017:13:56:15 +0500] [Client 8] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
618D [26/Sep/2017:13:56:15 +0500] [Client 8] Closing connection.
619D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
620D [26/Sep/2017:13:56:15 +0500] [Client 3] con->http=0x200fa3e0
621D [26/Sep/2017:13:56:15 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=70, file=10
622D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for CGI data.
623D [26/Sep/2017:13:56:15 +0500] [Client 3] Sending 0-length chunk.
624D [26/Sep/2017:13:56:15 +0500] [Client 3] Flushing write buffer.
625D [26/Sep/2017:13:56:15 +0500] [Client 3] New state is HTTP_STATE_WAITING
626D [26/Sep/2017:13:56:15 +0500] [Client 3] Waiting for request.
627D [26/Sep/2017:13:56:15 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
628W [26/Sep/2017:13:56:15 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
629D [26/Sep/2017:13:56:16 +0500] [Client 3] GET /cups.css HTTP/1.1
630D [26/Sep/2017:13:56:16 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
631D [26/Sep/2017:13:56:16 +0500] [Client 3] Read: status=200
632D [26/Sep/2017:13:56:16 +0500] [Client 3] No authentication data provided.
633D [26/Sep/2017:13:56:16 +0500] [Client 3] Processing GET /cups.css
634D [26/Sep/2017:13:56:16 +0500] [Client 3] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
635D [26/Sep/2017:13:56:16 +0500] [Client 3] cupsdSendHeader: code=200, type="text/css", auth_type=0
636D [26/Sep/2017:13:56:16 +0500] [Client 3] Sending file.
637D [26/Sep/2017:13:56:16 +0500] PID 70 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
638D [26/Sep/2017:13:56:16 +0500] [Client 3] con->http=0x200fa3e0
639D [26/Sep/2017:13:56:16 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
640D [26/Sep/2017:13:56:16 +0500] [Client 3] con->http=0x200fa3e0
641D [26/Sep/2017:13:56:16 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
642D [26/Sep/2017:13:56:16 +0500] [Client 3] con->http=0x200fa3e0
643D [26/Sep/2017:13:56:16 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
644D [26/Sep/2017:13:56:16 +0500] [Client 3] con->http=0x200fa3e0
645D [26/Sep/2017:13:56:16 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
646D [26/Sep/2017:13:56:16 +0500] [Client 3] con->http=0x200fa3e0
647D [26/Sep/2017:13:56:16 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=10
648D [26/Sep/2017:13:56:16 +0500] [Client 3] Flushing write buffer.
649D [26/Sep/2017:13:56:16 +0500] [Client 3] New state is HTTP_STATE_WAITING
650D [26/Sep/2017:13:56:16 +0500] [Client 3] Waiting for request.
651D [26/Sep/2017:13:56:16 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
652D [26/Sep/2017:13:56:17 +0500] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
653D [26/Sep/2017:13:56:17 +0500] [Client 1] Closing connection.
654D [26/Sep/2017:13:56:17 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
655D [26/Sep/2017:13:56:18 +0500] [Client 3] POST /printers/HP_Color_LaserJet_3800 HTTP/1.1
656D [26/Sep/2017:13:56:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
657D [26/Sep/2017:13:56:18 +0500] [Client 3] Read: status=200
658D [26/Sep/2017:13:56:18 +0500] [Client 3] No authentication data provided.
659D [26/Sep/2017:13:56:18 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
660D [26/Sep/2017:13:56:18 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
661D [26/Sep/2017:13:56:18 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
662D [26/Sep/2017:13:56:18 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
663D [26/Sep/2017:13:56:18 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
664D [26/Sep/2017:13:56:18 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
665D [26/Sep/2017:13:56:18 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
666D [26/Sep/2017:13:56:18 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
667D [26/Sep/2017:13:56:18 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
668D [26/Sep/2017:13:56:18 +0500] [CGI] envp[8] = "HOME=H:\\var\\temp"
669D [26/Sep/2017:13:56:18 +0500] [CGI] envp[9] = "NLSPATH=H:\\MPTN\\MSG\\NLS\\%N;H:\\TCPIP\\msg\\ENUS850\\%N;"
670D [26/Sep/2017:13:56:18 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
671D [26/Sep/2017:13:56:18 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
672D [26/Sep/2017:13:56:18 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
673D [26/Sep/2017:13:56:18 +0500] [CGI] envp[13] = "TMPDIR=H:\\var\\temp"
674D [26/Sep/2017:13:56:18 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
675D [26/Sep/2017:13:56:18 +0500] [CGI] envp[15] = "USER=root"
676D [26/Sep/2017:13:56:18 +0500] [CGI] envp[16] = "UNIXROOT=H:"
677D [26/Sep/2017:13:56:18 +0500] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
678D [26/Sep/2017:13:56:18 +0500] [CGI] envp[18] = "CUPS_SERVER=localhost"
679D [26/Sep/2017:13:56:18 +0500] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
680D [26/Sep/2017:13:56:18 +0500] [CGI] envp[20] = "IPP_PORT=631"
681D [26/Sep/2017:13:56:18 +0500] [CGI] envp[21] = "LANG=en_US.UTF8"
682D [26/Sep/2017:13:56:18 +0500] [CGI] envp[22] = "REDIRECT_STATUS=1"
683D [26/Sep/2017:13:56:18 +0500] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
684D [26/Sep/2017:13:56:18 +0500] [CGI] envp[24] = "SERVER_NAME=localhost"
685D [26/Sep/2017:13:56:18 +0500] [CGI] envp[25] = "SERVER_PORT=631"
686D [26/Sep/2017:13:56:18 +0500] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
687D [26/Sep/2017:13:56:18 +0500] [CGI] envp[27] = "REMOTE_HOST=localhost"
688D [26/Sep/2017:13:56:18 +0500] [CGI] envp[28] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800"
689D [26/Sep/2017:13:56:18 +0500] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800"
690D [26/Sep/2017:13:56:18 +0500] [CGI] envp[30] = "PATH_INFO=/HP_Color_LaserJet_3800"
691D [26/Sep/2017:13:56:18 +0500] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
692D [26/Sep/2017:13:56:18 +0500] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=ba119267d82f0c1688613ada42d0a797"
693D [26/Sep/2017:13:56:18 +0500] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
694D [26/Sep/2017:13:56:18 +0500] [CGI] envp[34] = "HTTP_REFERER=http://localhost:631/printers/HP_Color_LaserJet_3800"
695D [26/Sep/2017:13:56:18 +0500] [CGI] envp[35] = "REQUEST_METHOD=POST"
696D [26/Sep/2017:13:56:18 +0500] [CGI] envp[36] = "CONTENT_LENGTH=64"
697D [26/Sep/2017:13:56:18 +0500] [CGI] envp[37] = "CONTENT_TYPE=application/x-www-form-urlencoded"
698D [26/Sep/2017:13:56:18 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 72)
699I [26/Sep/2017:13:56:18 +0500] [Client 3] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=72, file=10)
700D [26/Sep/2017:13:56:18 +0500] [Client 3] Waiting for CGI data.
701D [26/Sep/2017:13:56:18 +0500] [Client 9] Accepted from localhost:49983 (IPv4)
702D [26/Sep/2017:13:56:18 +0500] [Client 9] Waiting for request.
703D [26/Sep/2017:13:56:18 +0500] [CGI] org.cups.sid cookie is \"ba119267d82f0c1688613ada42d0a797\"
704D [26/Sep/2017:13:56:18 +0500] [CGI] cgiSetVariable: org.cups.sid=\"ba119267d82f0c1688613ada42d0a797\"
705D [26/Sep/2017:13:56:18 +0500] [CGI] cgiSetVariable: OP=\"print-test-page\"
706D [26/Sep/2017:13:56:18 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
707D [26/Sep/2017:13:56:18 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
708D [26/Sep/2017:13:56:18 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
709D [26/Sep/2017:13:56:18 +0500] [Client 9] POST /printers/HP_Color_LaserJet_3800 HTTP/1.1
710D [26/Sep/2017:13:56:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
711D [26/Sep/2017:13:56:18 +0500] [Client 9] Read: status=200
712D [26/Sep/2017:13:56:18 +0500] [Client 9] No authentication data provided.
713D [26/Sep/2017:13:56:18 +0500] [Client 9] 2.0 Print-Job 1
714D [26/Sep/2017:13:56:18 +0500] [Client 9] Read: status=100
715D [26/Sep/2017:13:56:18 +0500] Print-Job ipp://localhost:631/printers/HP_Color_LaserJet_3800
716D [26/Sep/2017:13:56:18 +0500] [Job ???] Auto-typing file...
717I [26/Sep/2017:13:56:18 +0500] [Job ???] Request file type is application/vnd.cups-pdf-banner.
718D [26/Sep/2017:13:56:19 +0500] cupsdMarkDirty(---J-)
719D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
720D [26/Sep/2017:13:56:19 +0500] Adding default job-sheets values "none,none"...
721I [26/Sep/2017:13:56:19 +0500] [Job 8] Adding start banner page "none".
722D [26/Sep/2017:13:56:19 +0500] Discarding unused job-created event...
723D [26/Sep/2017:13:56:19 +0500] cupsdMarkDirty(---J-)
724D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
725I [26/Sep/2017:13:56:19 +0500] [Job 8] Adding end banner page "none".
726I [26/Sep/2017:13:56:19 +0500] [Job 8] File of type application/vnd.cups-pdf-banner queued by "anonymous".
727D [26/Sep/2017:13:56:19 +0500] [Job 8] hold_until=0
728I [26/Sep/2017:13:56:19 +0500] [Job 8] Queued on "HP_Color_LaserJet_3800" by "anonymous".
729D [26/Sep/2017:13:56:19 +0500] [Job 8] time-at-processing=1506448579
730D [26/Sep/2017:13:56:19 +0500] cupsdMarkDirty(---J-)
731D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
732D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
733D [26/Sep/2017:13:56:19 +0500] Discarding unused printer-state-changed event...
734D [26/Sep/2017:13:56:19 +0500] [Job 8] 3 filters for job:
735D [26/Sep/2017:13:56:19 +0500] [Job 8] bannertopdf.exe (application/vnd.cups-pdf-banner to application/pdf, cost 32)
736D [26/Sep/2017:13:56:19 +0500] [Job 8] pdftopdf.exe (application/pdf to application/vnd.cups-pdf, cost 66)
737D [26/Sep/2017:13:56:19 +0500] [Job 8] foomatic-rip (application/vnd.cups-pdf to printer/HP_Color_LaserJet_3800, cost 0)
738D [26/Sep/2017:13:56:19 +0500] [Job 8] job-sheets=none,none
739D [26/Sep/2017:13:56:19 +0500] [Job 8] argv[0]="HP_Color_LaserJet_3800"
740D [26/Sep/2017:13:56:19 +0500] [Job 8] argv[1]="8"
741D [26/Sep/2017:13:56:19 +0500] [Job 8] argv[2]="anonymous"
742D [26/Sep/2017:13:56:19 +0500] [Job 8] argv[3]="Test Page"
743D [26/Sep/2017:13:56:19 +0500] [Job 8] argv[4]="1"
744D [26/Sep/2017:13:56:19 +0500] [Job 8] argv[5]="job-uuid=urn:uuid:09c275d6-f3fa-3388-4dfe-54b984036d0e job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1506448579 time-at-processing=1506448579"
745D [26/Sep/2017:13:56:19 +0500] [Job 8] argv[6]="/@unixroot/var/spool/cups/d00008-001"
746D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[0]="CUPS_CACHEDIR=/@unixroot/var/cache/cups"
747D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[1]="CUPS_DATADIR=/@unixroot/usr/share/cups"
748D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[2]="CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
749D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[3]="CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
750D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[4]="CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
751D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[5]="CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
752D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[6]="CUPS_SERVERROOT=/@unixroot/etc/cups"
753D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[7]="CUPS_STATEDIR=/@unixroot/var/run/cups"
754D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[8]="HOME=H:\\var\\temp"
755D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[9]="NLSPATH=H:\\MPTN\\MSG\\NLS\\%N;H:\\TCPIP\\msg\\ENUS850\\%N;"
756D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[10]="PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
757D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[11]="SERVER_ADMIN=root@ARCAOS-01D8CC3"
758D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[12]="SOFTWARE=CUPS/2.1.3"
759D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[13]="TMPDIR=H:\\var\\temp"
760D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[14]="TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
761D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[15]="USER=root"
762D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[16]="UNIXROOT=H:"
763D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[17]="CUPS_MAX_MESSAGE=2047"
764D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[18]="CUPS_SERVER=localhost"
765D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[19]="CUPS_ENCRYPTION=IfRequested"
766D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[20]="IPP_PORT=631"
767D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[21]="CHARSET=utf-8"
768D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[22]="LANG=en_US.UTF-8"
769D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[23]="PPD=/@unixroot/etc/cups/ppd/HP_Color_LaserJet_3800.ppd"
770D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[24]="RIP_MAX_CACHE=128m"
771D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[25]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
772D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[26]="DEVICE_URI=usb://HP/Color%20LaserJet%203800?serial=CNDBB03809"
773D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[27]="PRINTER_INFO=HP Color LaserJet 3800"
774D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[28]="PRINTER_LOCATION="
775D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[29]="PRINTER=HP_Color_LaserJet_3800"
776D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[30]="PRINTER_STATE_REASONS=none"
777D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[31]="CUPS_FILETYPE=document"
778D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[32]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
779D [26/Sep/2017:13:56:19 +0500] [Job 8] envp[33]="AUTH_I****"
780I [26/Sep/2017:13:56:19 +0500] [Job 8] Started filter /@unixroot/usr/lib/cups/filter/bannertopdf.exe (PID 74)
781I [26/Sep/2017:13:56:19 +0500] [Job 8] Started filter /@unixroot/usr/lib/cups/filter/pdftopdf.exe (PID 75)
782I [26/Sep/2017:13:56:19 +0500] [Job 8] Started filter /@unixroot/usr/lib/cups/filter/foomatic-rip.exe (PID 76)
783I [26/Sep/2017:13:56:19 +0500] [Job 8] Started backend /@unixroot/usr/lib/cups/backend/usb.exe (PID 80)
784D [26/Sep/2017:13:56:19 +0500] Discarding unused job-state-changed event...
785D [26/Sep/2017:13:56:19 +0500] [Client 9] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HP_Color_LaserJet_3800) from localhost
786D [26/Sep/2017:13:56:19 +0500] [Client 9] Content-Length: 195
787D [26/Sep/2017:13:56:19 +0500] [Client 9] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
788D [26/Sep/2017:13:56:19 +0500] [Client 9] con->http=0x200f0000
789D [26/Sep/2017:13:56:19 +0500] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=195, response=0x200af8a0(IPP_STATE_IDLE), pipe_pid=0, file=-1
790D [26/Sep/2017:13:56:19 +0500] [Client 9] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
791D [26/Sep/2017:13:56:19 +0500] [Client 9] bytes=0, http_state=0, data_remaining=195
792D [26/Sep/2017:13:56:19 +0500] [Client 9] Flushing write buffer.
793D [26/Sep/2017:13:56:19 +0500] [Client 9] New state is HTTP_STATE_WAITING
794D [26/Sep/2017:13:56:19 +0500] [Client 9] Waiting for request.
795D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
796D [26/Sep/2017:13:56:19 +0500] [Job 8] WARN: not compiled with DBus support
797D [26/Sep/2017:13:56:19 +0500] [Job 8] \'CM Color Calibration\' Mode in SPOOLER-LESS: Off
798D [26/Sep/2017:13:56:19 +0500] [Job 8] Getting input from file
799D [26/Sep/2017:13:56:19 +0500] [Job 8] foomatic-rip version 1.8.2 running...
800D [26/Sep/2017:13:56:19 +0500] [Job 8] Parsing PPD file ...
801D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
802D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
803D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
804D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
805D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetArray: job_uri[0]=\"/jobs/8\"
806D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetArray: job_id[0]=\"8\"
807D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetArray: job_state[0]=\"3\"
808D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetArray: job_state_message[0]=\"\"
809D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetArray: job_state_reasons[0]=\"none\"
810D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: refresh_page=\"2;URL=/printers/HP_Color_LaserJet_3800\"
811D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: TITLE=\"Print Test Page\"
812D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
813D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
814D [26/Sep/2017:13:56:19 +0500] [Client 3] CGI data ready to be sent.
815D [26/Sep/2017:13:56:19 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
816D [26/Sep/2017:13:56:19 +0500] [Client 3] con->http=0x200fa3e0
817D [26/Sep/2017:13:56:19 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=72, file=10
818D [26/Sep/2017:13:56:19 +0500] [Client 3] Waiting for CGI data.
819D [26/Sep/2017:13:56:19 +0500] [Client 3] Script header: Content-Type: text/html;charset=utf-8
820D [26/Sep/2017:13:56:19 +0500] [Client 3] Script header:
821D [26/Sep/2017:13:56:19 +0500] [Client 3] Sending status 200 for CGI.
822D [26/Sep/2017:13:56:19 +0500] [Client 3] cupsdSendHeader: code=200, type="(null)", auth_type=0
823D [26/Sep/2017:13:56:19 +0500] [Client 3] con->http=0x200fa3e0
824D [26/Sep/2017:13:56:19 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=72, file=10
825D [26/Sep/2017:13:56:19 +0500] [Client 3] Waiting for CGI data.
826D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option ColorSpace
827D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option Resolution
828D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option PageSize
829D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option Model
830D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option PrintoutMode
831D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option InputSlot
832D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option Duplex
833D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option Quality
834D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option ImageableArea
835D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option PaperDimension
836D [26/Sep/2017:13:56:19 +0500] [Job 8] Added option Font
837D [26/Sep/2017:13:56:19 +0500] [Job 8] Parameter Summary
838D [26/Sep/2017:13:56:19 +0500] [Job 8] -----------------
839D [26/Sep/2017:13:56:19 +0500] [Job 8] Spooler: cups
840D [26/Sep/2017:13:56:19 +0500] [Job 8] Printer: HP_Color_LaserJet_3800
841D [26/Sep/2017:13:56:19 +0500] [Job 8] Shell: /bin/bash
842D [26/Sep/2017:13:56:19 +0500] [Job 8] PPD file: /@unixroot/etc/cups/ppd/HP_Color_LaserJet_3800.ppd
843D [26/Sep/2017:13:56:19 +0500] [Job 8] ATTR file:
844D [26/Sep/2017:13:56:19 +0500] [Job 8] Printer model: HP Color LaserJet 3800 hpijs pcl3, 3.16.5
845D [26/Sep/2017:13:56:19 +0500] [Job 8] Job title: Test Page
846D [26/Sep/2017:13:56:19 +0500] [Job 8] File(s) to be printed:
847D [26/Sep/2017:13:56:19 +0500] [Job 8] <STDIN>
848D [26/Sep/2017:13:56:19 +0500] [Job 8] Ghostscript extra search path (\'GS_LIB\'): /@unixroot/usr/share/cups/fonts
849D [26/Sep/2017:13:56:19 +0500] [Job 8] Printing system options:
850D [26/Sep/2017:13:56:19 +0500] [Job 8] Pondering option \'job-uuid=urn:uuid:09c275d6-f3fa-3388-4dfe-54b984036d0e\'
851D [26/Sep/2017:13:56:19 +0500] [Job 8] Unknown option job-uuid=urn:uuid:09c275d6-f3fa-3388-4dfe-54b984036d0e.
852D [26/Sep/2017:13:56:19 +0500] [Job 8] Pondering option \'job-originating-host-name=localhost\'
853D [26/Sep/2017:13:56:19 +0500] [Job 8] Unknown option job-originating-host-name=localhost.
854D [26/Sep/2017:13:56:19 +0500] [Job 8] Pondering option \'date-time-at-creation=\'
855D [26/Sep/2017:13:56:19 +0500] [Job 8] Unknown option date-time-at-creation=.
856D [26/Sep/2017:13:56:19 +0500] [Job 8] Pondering option \'date-time-at-processing=\'
857D [26/Sep/2017:13:56:19 +0500] [Job 8] Unknown option date-time-at-processing=.
858D [26/Sep/2017:13:56:19 +0500] [Job 8] Pondering option \'time-at-creation=1506448579\'
859D [26/Sep/2017:13:56:19 +0500] [Job 8] Unknown option time-at-creation=1506448579.
860D [26/Sep/2017:13:56:19 +0500] [Job 8] Pondering option \'time-at-processing=1506448579\'
861D [26/Sep/2017:13:56:19 +0500] [Job 8] Unknown option time-at-processing=1506448579.
862D [26/Sep/2017:13:56:19 +0500] [Job 8] CM Color Calibration Mode in CUPS: Off
863D [26/Sep/2017:13:56:19 +0500] [Job 8] Options from the PPD file:
864D [26/Sep/2017:13:56:19 +0500] [Job 8] ================================================
865D [26/Sep/2017:13:56:19 +0500] [Job 8] File: <STDIN>
866D [26/Sep/2017:13:56:19 +0500] [Job 8] ================================================
867D [26/Sep/2017:13:56:19 +0500] [Client 3] CGI data ready to be sent.
868D [26/Sep/2017:13:56:19 +0500] [Client 3] con->http=0x200fa3e0
869D [26/Sep/2017:13:56:19 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=72, file=10
870D [26/Sep/2017:13:56:19 +0500] [Client 3] Waiting for CGI data.
871D [26/Sep/2017:13:56:19 +0500] [Client 3] con->http=0x200fa3e0
872D [26/Sep/2017:13:56:19 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=72, file=10
873D [26/Sep/2017:13:56:19 +0500] [Client 3] Waiting for CGI data.
874D [26/Sep/2017:13:56:19 +0500] [Client 9] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
875D [26/Sep/2017:13:56:19 +0500] [Client 9] Closing connection.
876D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
877D [26/Sep/2017:13:56:19 +0500] [Client 3] CGI data ready to be sent.
878D [26/Sep/2017:13:56:19 +0500] [Client 3] con->http=0x200fa3e0
879D [26/Sep/2017:13:56:19 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=72, file=10
880D [26/Sep/2017:13:56:19 +0500] [Client 3] Waiting for CGI data.
881D [26/Sep/2017:13:56:19 +0500] [Client 3] Sending 0-length chunk.
882D [26/Sep/2017:13:56:19 +0500] [Client 3] Flushing write buffer.
883D [26/Sep/2017:13:56:19 +0500] [Client 3] New state is HTTP_STATE_WAITING
884D [26/Sep/2017:13:56:19 +0500] [Client 3] Waiting for request.
885D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
886D [26/Sep/2017:13:56:19 +0500] PID 72 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
887D [26/Sep/2017:13:56:19 +0500] [Job 8] Loading USB quirks from \"/@unixroot/usr/share/cups/usb\".
888D [26/Sep/2017:13:56:19 +0500] [Job 8] Loaded 129 quirks.
889D [26/Sep/2017:13:56:19 +0500] [Job 8] Printing on printer with URI: usb://HP/Color%20LaserJet%203800?serial=CNDBB03809
890D [26/Sep/2017:13:56:19 +0500] [Job 8] libusb_get_device_list=2
891D [26/Sep/2017:13:56:19 +0500] [Job 8] STATE: +connecting-to-device
892D [26/Sep/2017:13:56:19 +0500] cupsdMarkDirty(---J-)
893D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
894D [26/Sep/2017:13:56:19 +0500] Discarding unused printer-state-changed event...
895D [26/Sep/2017:13:56:19 +0500] [Job 8] STATE: -connecting-to-device
896D [26/Sep/2017:13:56:19 +0500] cupsdMarkDirty(---J-)
897D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
898D [26/Sep/2017:13:56:19 +0500] Discarding unused printer-state-changed event...
899D [26/Sep/2017:13:56:19 +0500] [Job 8] Device protocol: 2
900I [26/Sep/2017:13:56:19 +0500] [Job 8] Sending data to printer.
901D [26/Sep/2017:13:56:19 +0500] cupsdMarkDirty(---J-)
902D [26/Sep/2017:13:56:19 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
903D [26/Sep/2017:13:56:19 +0500] [Job 8] Set job-printer-state-message to "Sending data to printer.", current level=INFO
904D [26/Sep/2017:13:56:19 +0500] Discarding unused job-progress event...
905D [26/Sep/2017:13:56:19 +0500] Discarding unused printer-state-changed event...
906D [26/Sep/2017:13:56:20 +0500] [Job 8] PDF template file doesn\'t have form. It\'s okay.
907W [26/Sep/2017:13:56:20 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
908D [26/Sep/2017:13:56:20 +0500] [Job 8] Filetype: PDF
909D [26/Sep/2017:13:56:20 +0500] [Job 8] Storing temporary files in H:\\var\\temp
910D [26/Sep/2017:13:56:20 +0500] [Job 8] Process is dying with \"Failed to execute ghostscript to determine number of input pages!
911D [26/Sep/2017:13:56:20 +0500] [Job 8] \", exit stat 6
912D [26/Sep/2017:13:56:20 +0500] [Job 8] Cleaning up...
913D [26/Sep/2017:13:56:20 +0500] [Job 8] PID 74 (/@unixroot/usr/lib/cups/filter/bannertopdf.exe) exited with no errors.
914D [26/Sep/2017:13:56:20 +0500] [Job 8] PID 75 (/@unixroot/usr/lib/cups/filter/pdftopdf.exe) exited with no errors.
915D [26/Sep/2017:13:56:20 +0500] [Job 8] Sent 0 bytes...
916D [26/Sep/2017:13:56:20 +0500] [Job 8] Waiting for read thread to exit...
917W [26/Sep/2017:13:56:20 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
918D [26/Sep/2017:13:56:20 +0500] [Client 3] GET /cups.css HTTP/1.1
919D [26/Sep/2017:13:56:20 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
920D [26/Sep/2017:13:56:20 +0500] [Client 3] Read: status=200
921D [26/Sep/2017:13:56:20 +0500] [Client 3] No authentication data provided.
922D [26/Sep/2017:13:56:20 +0500] [Client 3] Processing GET /cups.css
923D [26/Sep/2017:13:56:20 +0500] [Client 3] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
924D [26/Sep/2017:13:56:20 +0500] [Client 3] cupsdSendHeader: code=200, type="text/css", auth_type=0
925D [26/Sep/2017:13:56:20 +0500] [Client 3] Sending file.
926D [26/Sep/2017:13:56:20 +0500] [Job 8] PID 76 (/@unixroot/usr/lib/cups/filter/foomatic-rip.exe) stopped with status 6.
927D [26/Sep/2017:13:56:20 +0500] [Job 8] PID 80 (/@unixroot/usr/lib/cups/backend/usb.exe) exited with no errors.
928D [26/Sep/2017:13:56:20 +0500] Discarding unused job-state-changed event...
929E [26/Sep/2017:13:56:20 +0500] [Job 8] Job stopped due to filter errors; please consult the error_log file for details.
930D [26/Sep/2017:13:56:20 +0500] cupsdMarkDirty(---J-)
931D [26/Sep/2017:13:56:20 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
932D [26/Sep/2017:13:56:20 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
933D [26/Sep/2017:13:56:20 +0500] Discarding unused printer-state-changed event...
934D [26/Sep/2017:13:56:20 +0500] [Job 8] The following messages were recorded from 01:56:19 pm to 01:56:19 pm
935D [26/Sep/2017:13:56:20 +0500] [Job 8] Printer found with device ID: MFG:Hewlett-Packard;CMD:PJL,MLC,BIDI-ECP,PCLXL,PCL,PDF,PJL,POSTSCRIPT;1284.4DL:4d,4e,1;MDL:HP Color LaserJet 3800;CLS:PRINTER;DES:Hewlett-Packard Color LaserJet 3800; Device URI: usb://HP/Color%20LaserJet%203800?serial=CNDBB03809
936D [26/Sep/2017:13:56:20 +0500] [Job 8] End of messages
937D [26/Sep/2017:13:56:20 +0500] [Job 8] printer-state=3(idle)
938D [26/Sep/2017:13:56:20 +0500] [Job 8] printer-state-message="Filter failed"
939D [26/Sep/2017:13:56:20 +0500] [Job 8] printer-state-reasons=none
940D [26/Sep/2017:13:56:20 +0500] [Client 3] con->http=0x200fa3e0
941D [26/Sep/2017:13:56:20 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
942D [26/Sep/2017:13:56:20 +0500] [Client 3] con->http=0x200fa3e0
943D [26/Sep/2017:13:56:20 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
944D [26/Sep/2017:13:56:20 +0500] [Client 3] con->http=0x200fa3e0
945D [26/Sep/2017:13:56:20 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
946D [26/Sep/2017:13:56:20 +0500] [Client 3] con->http=0x200fa3e0
947D [26/Sep/2017:13:56:20 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
948D [26/Sep/2017:13:56:20 +0500] [Client 3] con->http=0x200fa3e0
949D [26/Sep/2017:13:56:20 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
950D [26/Sep/2017:13:56:20 +0500] [Client 3] Flushing write buffer.
951D [26/Sep/2017:13:56:20 +0500] [Client 3] New state is HTTP_STATE_WAITING
952D [26/Sep/2017:13:56:20 +0500] [Client 3] Waiting for request.
953D [26/Sep/2017:13:56:20 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients, printing jobs, and dirty files"
954D [26/Sep/2017:13:56:21 +0500] [Job 8] Unloading...
955D [26/Sep/2017:13:56:22 +0500] [Client 3] GET /printers/HP_Color_LaserJet_3800 HTTP/1.1
956D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
957D [26/Sep/2017:13:56:22 +0500] [Client 3] Read: status=200
958D [26/Sep/2017:13:56:22 +0500] [Client 3] No authentication data provided.
959D [26/Sep/2017:13:56:22 +0500] [Client 3] Processing GET /printers/HP_Color_LaserJet_3800
960D [26/Sep/2017:13:56:22 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
961D [26/Sep/2017:13:56:22 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
962D [26/Sep/2017:13:56:22 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
963D [26/Sep/2017:13:56:22 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
964D [26/Sep/2017:13:56:22 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
965D [26/Sep/2017:13:56:22 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
966D [26/Sep/2017:13:56:22 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
967D [26/Sep/2017:13:56:22 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
968D [26/Sep/2017:13:56:22 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
969D [26/Sep/2017:13:56:22 +0500] [CGI] envp[8] = "HOME=H:\\var\\temp"
970D [26/Sep/2017:13:56:22 +0500] [CGI] envp[9] = "NLSPATH=H:\\MPTN\\MSG\\NLS\\%N;H:\\TCPIP\\msg\\ENUS850\\%N;"
971D [26/Sep/2017:13:56:22 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
972D [26/Sep/2017:13:56:22 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@ARCAOS-01D8CC3"
973D [26/Sep/2017:13:56:22 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
974D [26/Sep/2017:13:56:22 +0500] [CGI] envp[13] = "TMPDIR=H:\\var\\temp"
975D [26/Sep/2017:13:56:22 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
976D [26/Sep/2017:13:56:22 +0500] [CGI] envp[15] = "USER=root"
977D [26/Sep/2017:13:56:22 +0500] [CGI] envp[16] = "UNIXROOT=H:"
978D [26/Sep/2017:13:56:22 +0500] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
979D [26/Sep/2017:13:56:22 +0500] [CGI] envp[18] = "CUPS_SERVER=localhost"
980D [26/Sep/2017:13:56:22 +0500] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
981D [26/Sep/2017:13:56:22 +0500] [CGI] envp[20] = "IPP_PORT=631"
982D [26/Sep/2017:13:56:22 +0500] [CGI] envp[21] = "LANG=en_US.UTF8"
983D [26/Sep/2017:13:56:22 +0500] [CGI] envp[22] = "REDIRECT_STATUS=1"
984D [26/Sep/2017:13:56:22 +0500] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
985D [26/Sep/2017:13:56:22 +0500] [CGI] envp[24] = "SERVER_NAME=localhost"
986D [26/Sep/2017:13:56:22 +0500] [CGI] envp[25] = "SERVER_PORT=631"
987D [26/Sep/2017:13:56:22 +0500] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
988D [26/Sep/2017:13:56:22 +0500] [CGI] envp[27] = "REMOTE_HOST=localhost"
989D [26/Sep/2017:13:56:22 +0500] [CGI] envp[28] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800"
990D [26/Sep/2017:13:56:22 +0500] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800"
991D [26/Sep/2017:13:56:22 +0500] [CGI] envp[30] = "PATH_INFO=/HP_Color_LaserJet_3800"
992D [26/Sep/2017:13:56:22 +0500] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
993D [26/Sep/2017:13:56:22 +0500] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=ba119267d82f0c1688613ada42d0a797"
994D [26/Sep/2017:13:56:22 +0500] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
995D [26/Sep/2017:13:56:22 +0500] [CGI] envp[34] = "REQUEST_METHOD=GET"
996D [26/Sep/2017:13:56:22 +0500] [CGI] envp[35] = "QUERY_STRING="
997D [26/Sep/2017:13:56:22 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 82)
998I [26/Sep/2017:13:56:22 +0500] [Client 3] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=82, file=9)
999D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1000D [26/Sep/2017:13:56:22 +0500] [Client 10] Accepted from localhost:49984 (IPv4)
1001D [26/Sep/2017:13:56:22 +0500] [Client 10] Waiting for request.
1002D [26/Sep/2017:13:56:22 +0500] [CGI] org.cups.sid cookie is \"ba119267d82f0c1688613ada42d0a797\"
1003D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
1004D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
1005D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
1006D [26/Sep/2017:13:56:22 +0500] [Client 10] POST / HTTP/1.1
1007D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1008D [26/Sep/2017:13:56:22 +0500] [Client 10] Read: status=200
1009D [26/Sep/2017:13:56:22 +0500] [Client 10] No authentication data provided.
1010D [26/Sep/2017:13:56:22 +0500] [Client 10] 2.0 CUPS-Get-Default 1
1011D [26/Sep/2017:13:56:22 +0500] CUPS-Get-Default
1012D [26/Sep/2017:13:56:22 +0500] CUPS-Get-Default client-error-not-found: No default printer.
1013D [26/Sep/2017:13:56:22 +0500] [Client 10] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
1014D [26/Sep/2017:13:56:22 +0500] [Client 10] Content-Length: 113
1015D [26/Sep/2017:13:56:22 +0500] [Client 10] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1016D [26/Sep/2017:13:56:22 +0500] [Client 10] con->http=0x200f0000
1017D [26/Sep/2017:13:56:22 +0500] [Client 10] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x200f75c0(IPP_STATE_DATA), pipe_pid=0, file=-1
1018D [26/Sep/2017:13:56:22 +0500] [Client 10] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1019D [26/Sep/2017:13:56:22 +0500] [Client 10] bytes=0, http_state=0, data_remaining=113
1020D [26/Sep/2017:13:56:22 +0500] [Client 10] Flushing write buffer.
1021D [26/Sep/2017:13:56:22 +0500] [Client 10] New state is HTTP_STATE_WAITING
1022D [26/Sep/2017:13:56:22 +0500] [Client 10] Waiting for request.
1023D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1024D [26/Sep/2017:13:56:22 +0500] [CGI] show_printer(http=0x2003c220, printer=\"HP_Color_LaserJet_3800\")
1025D [26/Sep/2017:13:56:22 +0500] [Client 10] POST / HTTP/1.1
1026D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1027D [26/Sep/2017:13:56:22 +0500] [Client 10] Read: status=200
1028D [26/Sep/2017:13:56:22 +0500] [Client 10] No authentication data provided.
1029D [26/Sep/2017:13:56:22 +0500] [Client 10] 2.0 Get-Printer-Attributes 2
1030D [26/Sep/2017:13:56:22 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800
1031D [26/Sep/2017:13:56:22 +0500] [Client 10] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800) from localhost
1032D [26/Sep/2017:13:56:22 +0500] [Client 10] Content-Length: 757
1033D [26/Sep/2017:13:56:22 +0500] [Client 10] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1034D [26/Sep/2017:13:56:22 +0500] [Client 10] con->http=0x200f0000
1035D [26/Sep/2017:13:56:22 +0500] [Client 10] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=757, response=0x2005e860(IPP_STATE_DATA), pipe_pid=0, file=-1
1036D [26/Sep/2017:13:56:22 +0500] [Client 10] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1037D [26/Sep/2017:13:56:22 +0500] [Client 10] bytes=0, http_state=0, data_remaining=757
1038D [26/Sep/2017:13:56:22 +0500] [Client 10] Flushing write buffer.
1039D [26/Sep/2017:13:56:22 +0500] [Client 10] New state is HTTP_STATE_WAITING
1040D [26/Sep/2017:13:56:22 +0500] [Client 10] Waiting for request.
1041D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1042D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1043D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1044D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1045D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1046D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
1047D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
1048D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
1049D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
1050D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800\"
1051D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800\"
1052D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_location[0]=\"\"
1053D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800\"
1054D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
1055D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: device_uri[0]=\"usb://HP/Color%20LaserJet%203800?serial=CNDBB03809\"
1056D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
1057D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 hpijs pcl3, 3.16.5\"
1058D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
1059D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
1060D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
1061D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
1062D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1063D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
1064D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_LaserJet_3800\"
1065D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1066D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1067D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1068D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=82, file=9
1069D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1070D [26/Sep/2017:13:56:22 +0500] [Client 3] Script header: Content-Type: text/html;charset=utf-8
1071D [26/Sep/2017:13:56:22 +0500] [Client 3] Script header:
1072D [26/Sep/2017:13:56:22 +0500] [Client 3] Sending status 200 for CGI.
1073D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdSendHeader: code=200, type="(null)", auth_type=0
1074D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1075D [26/Sep/2017:13:56:22 +0500] [Client 10] POST / HTTP/1.1
1076D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1077D [26/Sep/2017:13:56:22 +0500] [Client 10] Read: status=200
1078D [26/Sep/2017:13:56:22 +0500] [Client 10] No authentication data provided.
1079D [26/Sep/2017:13:56:22 +0500] [Client 10] 2.0 Get-Jobs 3
1080D [26/Sep/2017:13:56:22 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_LaserJet_3800
1081D [26/Sep/2017:13:56:22 +0500] [Job 8] Loading attributes...
1082D [26/Sep/2017:13:56:22 +0500] [Client 10] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_LaserJet_3800) from localhost
1083D [26/Sep/2017:13:56:22 +0500] [Client 10] Content-Length: 433
1084D [26/Sep/2017:13:56:22 +0500] [Client 10] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
1085D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1086D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1087D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1088D [26/Sep/2017:13:56:22 +0500] [CGI] Regular expression \".*Clean.*\"
1089D [26/Sep/2017:13:56:22 +0500] [CGI] matches[0].rm_so=0
1090D [26/Sep/2017:13:56:22 +0500] [CGI] matches[1].rm_so=-1
1091D [26/Sep/2017:13:56:22 +0500] [Client 10] con->http=0x200f0000
1092D [26/Sep/2017:13:56:22 +0500] [Client 10] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=433, response=0x200f75c0(IPP_STATE_DATA), pipe_pid=0, file=-1
1093D [26/Sep/2017:13:56:22 +0500] [Client 10] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
1094D [26/Sep/2017:13:56:22 +0500] [Client 10] bytes=0, http_state=0, data_remaining=433
1095D [26/Sep/2017:13:56:22 +0500] [Client 10] Flushing write buffer.
1096D [26/Sep/2017:13:56:22 +0500] [Client 10] New state is HTTP_STATE_WAITING
1097D [26/Sep/2017:13:56:22 +0500] [Client 10] Waiting for request.
1098D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1099D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1100D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1101D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1102D [26/Sep/2017:13:56:22 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
1103D [26/Sep/2017:13:56:22 +0500] [CGI] matches[0].rm_so=0
1104D [26/Sep/2017:13:56:22 +0500] [CGI] matches[1].rm_so=-1
1105D [26/Sep/2017:13:56:22 +0500] [CGI] cgiClearVariables called.
1106D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
1107D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
1108D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: TOTAL=\"1\"
1109D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
1110D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
1111D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_preserved[0]=\"1\"
1112D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_printer_name[0]=\"HP_Color_LaserJet_3800\"
1113D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_Color_LaserJet_3800\"
1114D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
1115D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
1116D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
1117D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: time_at_creation[0]=\"Tue Sep 26 13:56:19 EDT 2017\"
1118D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: time_at_processing[0]=\"Tue Sep 26 13:56:19 EDT 2017\"
1119D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_id[0]=\"8\"
1120D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_state[0]=\"6\"
1121D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"0\"
1122D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
1123D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
1124D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800\"
1125D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_LaserJet_3800\"
1126D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_LaserJet_3800\"
1127D [26/Sep/2017:13:56:22 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_LaserJet_3800\"
1128D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1129D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1130D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1131D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1132D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1133D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1134D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1135D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1136D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1137D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1138D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1139D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1140D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1141D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1142D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1143D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1144D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1145D [26/Sep/2017:13:56:22 +0500] [Client 10] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1146D [26/Sep/2017:13:56:22 +0500] [Client 10] Closing connection.
1147D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
1148D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1149D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1150D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1151D [26/Sep/2017:13:56:22 +0500] [Client 3] CGI data ready to be sent.
1152D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1153D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=82, file=9
1154D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for CGI data.
1155D [26/Sep/2017:13:56:22 +0500] [Client 3] Sending 0-length chunk.
1156D [26/Sep/2017:13:56:22 +0500] [Client 3] Flushing write buffer.
1157D [26/Sep/2017:13:56:22 +0500] [Client 3] New state is HTTP_STATE_WAITING
1158D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for request.
1159D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
1160D [26/Sep/2017:13:56:22 +0500] PID 82 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
1161D [26/Sep/2017:13:56:22 +0500] [Client 3] GET /cups.css HTTP/1.1
1162D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
1163D [26/Sep/2017:13:56:22 +0500] [Client 3] Read: status=200
1164D [26/Sep/2017:13:56:22 +0500] [Client 3] No authentication data provided.
1165D [26/Sep/2017:13:56:22 +0500] [Client 3] Processing GET /cups.css
1166D [26/Sep/2017:13:56:22 +0500] [Client 3] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
1167D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdSendHeader: code=200, type="text/css", auth_type=0
1168D [26/Sep/2017:13:56:22 +0500] [Client 3] Sending file.
1169D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1170D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
1171D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1172D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
1173D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1174D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
1175D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1176D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
1177D [26/Sep/2017:13:56:22 +0500] [Client 3] con->http=0x200fa3e0
1178D [26/Sep/2017:13:56:22 +0500] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9961, response=0(), pipe_pid=0, file=9
1179D [26/Sep/2017:13:56:22 +0500] [Client 3] Flushing write buffer.
1180D [26/Sep/2017:13:56:22 +0500] [Client 3] New state is HTTP_STATE_WAITING
1181D [26/Sep/2017:13:56:22 +0500] [Client 3] Waiting for request.
1182D [26/Sep/2017:13:56:22 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
1183D [26/Sep/2017:13:56:33 +0500] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
1184D [26/Sep/2017:13:56:33 +0500] [Client 3] Closing connection.
1185D [26/Sep/2017:13:56:33 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
1186I [26/Sep/2017:13:56:41 +0500] Saving job.cache...
1187D [26/Sep/2017:13:56:41 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"