Ticket #143: error_log-2017-12-12

File error_log-2017-12-12, 57.3 KB (added by Lewis Rosenthal, 8 years ago)

new foomatic-rip.exe and installed g.py patched per previous attachment

Line 
1D [12/Dec/2017:00:02:00 +0500] [Client 34] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
2D [12/Dec/2017:00:02:00 +0500] [Client 34] Closing connection.
3D [12/Dec/2017:00:02:00 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
4D [12/Dec/2017:00:02:06 +0500] [Client 28] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
5D [12/Dec/2017:00:02:06 +0500] [Client 28] Closing connection.
6D [12/Dec/2017:00:02:06 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
7D [12/Dec/2017:00:02:06 +0500] [Client 36] Accepted from localhost:64940 (IPv4)
8D [12/Dec/2017:00:02:06 +0500] [Client 36] Waiting for request.
9D [12/Dec/2017:00:02:06 +0500] [Client 36] POST /printers/HP_Color_Laserjet_3800_hpijs HTTP/1.1
10D [12/Dec/2017:00:02:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
11D [12/Dec/2017:00:02:06 +0500] [Client 36] Read: status=200
12D [12/Dec/2017:00:02:06 +0500] [Client 36] No authentication data provided.
13D [12/Dec/2017:00:02:06 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
14D [12/Dec/2017:00:02:06 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
15D [12/Dec/2017:00:02:06 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
16D [12/Dec/2017:00:02:06 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
17D [12/Dec/2017:00:02:06 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
18D [12/Dec/2017:00:02:06 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
19D [12/Dec/2017:00:02:06 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
20D [12/Dec/2017:00:02:06 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
21D [12/Dec/2017:00:02:06 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
22D [12/Dec/2017:00:02:06 +0500] [CGI] envp[8] = "HOME=C:\\var\\temp"
23D [12/Dec/2017:00:02:06 +0500] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
24D [12/Dec/2017:00:02:06 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
25D [12/Dec/2017:00:02:06 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@bluelion"
26D [12/Dec/2017:00:02:06 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
27D [12/Dec/2017:00:02:06 +0500] [CGI] envp[13] = "TMPDIR=C:\\var\\temp"
28D [12/Dec/2017:00:02:06 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
29D [12/Dec/2017:00:02:06 +0500] [CGI] envp[15] = "USER=root"
30D [12/Dec/2017:00:02:06 +0500] [CGI] envp[16] = "UNIXROOT=C:"
31D [12/Dec/2017:00:02:06 +0500] [CGI] envp[17] = "ETC=C:\\MPTN\\ETC"
32D [12/Dec/2017:00:02:06 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
33D [12/Dec/2017:00:02:06 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
34D [12/Dec/2017:00:02:06 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
35D [12/Dec/2017:00:02:06 +0500] [CGI] envp[21] = "IPP_PORT=631"
36D [12/Dec/2017:00:02:06 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
37D [12/Dec/2017:00:02:06 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
38D [12/Dec/2017:00:02:06 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
39D [12/Dec/2017:00:02:06 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
40D [12/Dec/2017:00:02:06 +0500] [CGI] envp[26] = "SERVER_PORT=631"
41D [12/Dec/2017:00:02:06 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
42D [12/Dec/2017:00:02:06 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
43D [12/Dec/2017:00:02:06 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_Laserjet_3800_hpijs"
44D [12/Dec/2017:00:02:06 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_Laserjet_3800_hpijs"
45D [12/Dec/2017:00:02:06 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_Laserjet_3800_hpijs"
46D [12/Dec/2017:00:02:06 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
47D [12/Dec/2017:00:02:06 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=53f2efb08fa70698b63f646e39907fa4"
48D [12/Dec/2017:00:02:06 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0"
49D [12/Dec/2017:00:02:06 +0500] [CGI] envp[35] = "HTTP_REFERER=http://localhost:631/printers/HP_Color_Laserjet_3800_hpijs"
50D [12/Dec/2017:00:02:06 +0500] [CGI] envp[36] = "REQUEST_METHOD=POST"
51D [12/Dec/2017:00:02:06 +0500] [CGI] envp[37] = "CONTENT_LENGTH=64"
52D [12/Dec/2017:00:02:06 +0500] [CGI] envp[38] = "CONTENT_TYPE=application/x-www-form-urlencoded"
53D [12/Dec/2017:00:02:06 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 250)
54I [12/Dec/2017:00:02:06 +0500] [Client 36] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=250, file=12)
55D [12/Dec/2017:00:02:06 +0500] [Client 36] Waiting for CGI data.
56D [12/Dec/2017:00:02:06 +0500] [Client 37] Accepted from localhost (Domain)
57D [12/Dec/2017:00:02:06 +0500] [Client 37] Waiting for request.
58D [12/Dec/2017:00:02:06 +0500] [CGI] org.cups.sid cookie is \"53f2efb08fa70698b63f646e39907fa4\"
59D [12/Dec/2017:00:02:06 +0500] [CGI] cgiSetVariable: org.cups.sid=\"53f2efb08fa70698b63f646e39907fa4\"
60D [12/Dec/2017:00:02:06 +0500] [CGI] cgiSetVariable: OP=\"print-test-page\"
61D [12/Dec/2017:00:02:06 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
62D [12/Dec/2017:00:02:06 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
63D [12/Dec/2017:00:02:06 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_Laserjet_3800_hpijs\"
64D [12/Dec/2017:00:02:06 +0500] [Client 37] POST /printers/HP_Color_Laserjet_3800_hpijs HTTP/1.1
65D [12/Dec/2017:00:02:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
66D [12/Dec/2017:00:02:06 +0500] [Client 37] Read: status=200
67D [12/Dec/2017:00:02:06 +0500] [Client 37] No authentication data provided.
68D [12/Dec/2017:00:02:06 +0500] [Client 37] 2.0 Print-Job 1
69D [12/Dec/2017:00:02:06 +0500] Print-Job ipp://localhost:631/printers/HP_Color_Laserjet_3800_hpijs
70D [12/Dec/2017:00:02:06 +0500] [Job ???] Auto-typing file...
71I [12/Dec/2017:00:02:06 +0500] [Job ???] Request file type is application/vnd.cups-pdf-banner.
72D [12/Dec/2017:00:02:06 +0500] cupsdMarkDirty(---J-)
73D [12/Dec/2017:00:02:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
74D [12/Dec/2017:00:02:06 +0500] Adding default job-sheets values "none,none"...
75I [12/Dec/2017:00:02:06 +0500] [Job 18] Adding start banner page "none".
76D [12/Dec/2017:00:02:06 +0500] Discarding unused job-created event...
77D [12/Dec/2017:00:02:06 +0500] cupsdMarkDirty(---J-)
78D [12/Dec/2017:00:02:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
79I [12/Dec/2017:00:02:06 +0500] [Job 18] Adding end banner page "none".
80I [12/Dec/2017:00:02:06 +0500] [Job 18] File of type application/vnd.cups-pdf-banner queued by "anonymous".
81D [12/Dec/2017:00:02:06 +0500] [Job 18] hold_until=0
82I [12/Dec/2017:00:02:06 +0500] [Job 18] Queued on "HP_Color_Laserjet_3800_hpijs" by "anonymous".
83D [12/Dec/2017:00:02:06 +0500] [Job 18] time-at-processing=1513054926
84D [12/Dec/2017:00:02:06 +0500] cupsdMarkDirty(---J-)
85D [12/Dec/2017:00:02:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
86D [12/Dec/2017:00:02:06 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
87D [12/Dec/2017:00:02:06 +0500] Discarding unused printer-state-changed event...
88D [12/Dec/2017:00:02:07 +0500] [Job 18] 3 filters for job:
89D [12/Dec/2017:00:02:07 +0500] [Job 18] bannertopdf.exe (application/vnd.cups-pdf-banner to application/pdf, cost 32)
90D [12/Dec/2017:00:02:07 +0500] [Job 18] pdftopdf.exe (application/pdf to application/vnd.cups-pdf, cost 66)
91D [12/Dec/2017:00:02:07 +0500] [Job 18] foomatic-rip (application/vnd.cups-pdf to printer/HP_Color_Laserjet_3800_hpijs, cost 0)
92D [12/Dec/2017:00:02:07 +0500] [Job 18] job-sheets=none,none
93D [12/Dec/2017:00:02:07 +0500] [Job 18] argv[0]="HP_Color_Laserjet_3800_hpijs"
94D [12/Dec/2017:00:02:07 +0500] [Job 18] argv[1]="18"
95D [12/Dec/2017:00:02:07 +0500] [Job 18] argv[2]="anonymous"
96D [12/Dec/2017:00:02:07 +0500] [Job 18] argv[3]="Test Page"
97D [12/Dec/2017:00:02:07 +0500] [Job 18] argv[4]="1"
98D [12/Dec/2017:00:02:07 +0500] [Job 18] argv[5]="job-uuid=urn:uuid:bd568d03-ed9a-3d24-6537-e86aee94712e job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1513054926 time-at-processing=1513054926"
99D [12/Dec/2017:00:02:07 +0500] [Job 18] argv[6]="/@unixroot/var/spool/cups/d00018-001"
100D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[0]="CUPS_CACHEDIR=/@unixroot/var/cache/cups"
101D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[1]="CUPS_DATADIR=/@unixroot/usr/share/cups"
102D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[2]="CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
103D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[3]="CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
104D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[4]="CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
105D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[5]="CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
106D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[6]="CUPS_SERVERROOT=/@unixroot/etc/cups"
107D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[7]="CUPS_STATEDIR=/@unixroot/var/run/cups"
108D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[8]="HOME=C:\\var\\temp"
109D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[9]="NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
110D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[10]="PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
111D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[11]="SERVER_ADMIN=root@bluelion"
112D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[12]="SOFTWARE=CUPS/2.1.3"
113D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[13]="TMPDIR=C:\\var\\temp"
114D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[14]="TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
115D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[15]="USER=root"
116D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[16]="UNIXROOT=C:"
117D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[17]="ETC=C:\\MPTN\\ETC"
118D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[18]="CUPS_MAX_MESSAGE=2047"
119D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[19]="CUPS_SERVER=\\socket\\cups.sock"
120D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[20]="CUPS_ENCRYPTION=IfRequested"
121D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[21]="IPP_PORT=631"
122D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[22]="CHARSET=utf-8"
123D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[23]="LANG=en_US.UTF-8"
124D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[24]="PPD=/@unixroot/etc/cups/ppd/HP_Color_Laserjet_3800_hpijs.ppd"
125D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[25]="RIP_MAX_CACHE=128m"
126D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[26]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
127D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[27]="DEVICE_URI=socket://192.168.100.16"
128D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[28]="PRINTER_INFO=HP Color LaserJet 3800 hpijs pcl3"
129D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[29]="PRINTER_LOCATION=office"
130D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[30]="PRINTER=HP_Color_Laserjet_3800_hpijs"
131D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[31]="PRINTER_STATE_REASONS=none"
132D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[32]="CUPS_FILETYPE=document"
133D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[33]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
134D [12/Dec/2017:00:02:07 +0500] [Job 18] envp[34]="AUTH_I****"
135I [12/Dec/2017:00:02:07 +0500] [Job 18] Started filter /@unixroot/usr/lib/cups/filter/bannertopdf.exe (PID 252)
136I [12/Dec/2017:00:02:07 +0500] [Job 18] Started filter /@unixroot/usr/lib/cups/filter/pdftopdf.exe (PID 254)
137I [12/Dec/2017:00:02:07 +0500] [Job 18] Started filter /@unixroot/usr/lib/cups/filter/foomatic-rip.exe (PID 256)
138I [12/Dec/2017:00:02:07 +0500] [Job 18] Started backend /@unixroot/usr/lib/cups/backend/socket.exe (PID 258)
139D [12/Dec/2017:00:02:07 +0500] Discarding unused job-state-changed event...
140D [12/Dec/2017:00:02:07 +0500] [Client 37] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HP_Color_Laserjet_3800_hpijs) from localhost
141D [12/Dec/2017:00:02:07 +0500] [Client 37] Content-Length: 192
142D [12/Dec/2017:00:02:07 +0500] [Client 37] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
143D [12/Dec/2017:00:02:07 +0500] [Job 18] PID 252 (/@unixroot/usr/lib/cups/filter/bannertopdf.exe) exited with no errors.
144D [12/Dec/2017:00:02:07 +0500] [Client 38] Accepted from localhost (Domain)
145D [12/Dec/2017:00:02:07 +0500] [Client 38] Waiting for request.
146D [12/Dec/2017:00:02:07 +0500] [Client 37] con->http=0x20207220
147D [12/Dec/2017:00:02:07 +0500] [Client 37] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=192, response=0x201283e0(IPP_STATE_IDLE), pipe_pid=0, file=-1
148D [12/Dec/2017:00:02:07 +0500] [Client 37] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
149D [12/Dec/2017:00:02:07 +0500] [Client 37] bytes=0, http_state=0, data_remaining=192
150D [12/Dec/2017:00:02:07 +0500] [Client 37] Flushing write buffer.
151D [12/Dec/2017:00:02:07 +0500] [Client 37] New state is HTTP_STATE_WAITING
152D [12/Dec/2017:00:02:07 +0500] [Client 37] Waiting for request.
153D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
154D [12/Dec/2017:00:02:07 +0500] [Job 18] PDF template file doesn\'t have form. It\'s okay.
155D [12/Dec/2017:00:02:07 +0500] [Job 18] pdftopdf: Last filter determined by the PPD: foomatic-rip; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
156D [12/Dec/2017:00:02:07 +0500] [Job 18] WARN: not compiled with DBus support
157D [12/Dec/2017:00:02:07 +0500] [Job 18] \'CM Color Calibration\' Mode in SPOOLER-LESS: Off
158D [12/Dec/2017:00:02:07 +0500] [Job 18] Getting input from file
159D [12/Dec/2017:00:02:07 +0500] [Job 18] foomatic-rip version 1.17.2 running...
160D [12/Dec/2017:00:02:07 +0500] [Client 38] POST /printers/HP_Color_Laserjet_3800_hpijs HTTP/1.1
161D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
162D [12/Dec/2017:00:02:07 +0500] [Client 38] Read: status=200
163D [12/Dec/2017:00:02:07 +0500] [Client 38] No authentication data provided.
164D [12/Dec/2017:00:02:07 +0500] [Client 38] 2.0 Get-Printer-Attributes 1
165D [12/Dec/2017:00:02:07 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_Laserjet_3800_hpijs
166D [12/Dec/2017:00:02:07 +0500] [Client 38] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_Laserjet_3800_hpijs) from localhost
167D [12/Dec/2017:00:02:07 +0500] [Client 38] Content-Length: 214
168D [12/Dec/2017:00:02:07 +0500] [Client 38] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
169D [12/Dec/2017:00:02:07 +0500] [Client 38] con->http=0x2020b400
170D [12/Dec/2017:00:02:07 +0500] [Client 38] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=214, response=0x20205720(IPP_STATE_DATA), pipe_pid=0, file=-1
171D [12/Dec/2017:00:02:07 +0500] [Client 38] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
172D [12/Dec/2017:00:02:07 +0500] [Client 38] bytes=0, http_state=0, data_remaining=214
173D [12/Dec/2017:00:02:07 +0500] [Client 38] Flushing write buffer.
174D [12/Dec/2017:00:02:07 +0500] [Client 38] New state is HTTP_STATE_WAITING
175D [12/Dec/2017:00:02:07 +0500] [Client 38] Waiting for request.
176D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
177D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
178D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
179D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
180D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
181D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: +connecting-to-device
182D [12/Dec/2017:00:02:07 +0500] cupsdMarkDirty(---J-)
183D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients, printing jobs, and dirty files"
184D [12/Dec/2017:00:02:07 +0500] [Job 18] Looking up \"192.168.100.16\"...
185D [12/Dec/2017:00:02:07 +0500] Discarding unused printer-state-changed event...
186D [12/Dec/2017:00:02:07 +0500] [Client 39] Accepted from localhost:64941 (IPv4)
187D [12/Dec/2017:00:02:07 +0500] [Client 39] Waiting for request.
188D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetArray: job_uri[0]=\"/jobs/18\"
189D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetArray: job_id[0]=\"18\"
190D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetArray: job_state[0]=\"3\"
191D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetArray: job_state_message[0]=\"\"
192D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetArray: job_state_reasons[0]=\"none\"
193D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: refresh_page=\"2;URL=/printers/HP_Color_Laserjet_3800_hpijs\"
194D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: TITLE=\"Print Test Page\"
195D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
196D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
197D [12/Dec/2017:00:02:07 +0500] [Client 37] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
198D [12/Dec/2017:00:02:07 +0500] [Client 37] Closing connection.
199D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
200D [12/Dec/2017:00:02:07 +0500] [Client 36] CGI data ready to be sent.
201D [12/Dec/2017:00:02:07 +0500] [Job 18] ATTR: marker-colors=#000000,#00FFFF,#FF00FF,#FFFF00
202D [12/Dec/2017:00:02:07 +0500] cupsdMarkDirty(P----)
203D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
204D [12/Dec/2017:00:02:07 +0500] [Job 18] ATTR: marker-names=\'\"Black Cartridge HP Q6470A\"\',\'\"Cyan Cartridge HP Q7581A\"\',\'\"Magenta Cartridge HP Q7583A\"\',\'\"Yellow Cartridge HP Q7582A\"\'
205D [12/Dec/2017:00:02:07 +0500] cupsdMarkDirty(P----)
206D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
207D [12/Dec/2017:00:02:07 +0500] [Job 18] ATTR: marker-types=toner-cartridge,toner-cartridge,toner-cartridge,toner-cartridge
208D [12/Dec/2017:00:02:07 +0500] cupsdMarkDirty(P----)
209D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
210D [12/Dec/2017:00:02:07 +0500] [Job 18] ATTR: marker-levels=11,66,66,13
211D [12/Dec/2017:00:02:07 +0500] cupsdMarkDirty(P----)
212D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
213D [12/Dec/2017:00:02:07 +0500] [Job 18] new_supply_state=0, change_state=ffff
214D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -developer-low-report
215D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -developer-empty-warning
216D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -marker-supply-low-report
217D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -marker-supply-empty-warning
218D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -opc-near-eol-report
219D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -opc-life-over-warning
220D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -toner-low-report
221D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -toner-empty-warning
222D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -waste-receptacle-almost-full-report
223D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -waste-receptacle-full-warning
224D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -cleaner-life-almost-over-report
225D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -cleaner-life-over-warning
226D [12/Dec/2017:00:02:07 +0500] [Job 18] PAGE: 1 1
227D [12/Dec/2017:00:02:07 +0500] cupsdMarkDirty(---J-)
228D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
229D [12/Dec/2017:00:02:07 +0500] cupsdMarkDirty(---J-)
230D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
231D [12/Dec/2017:00:02:07 +0500] Discarding unused job-progress event...
232D [12/Dec/2017:00:02:07 +0500] Discarding unused printer-state-changed event...
233D [12/Dec/2017:00:02:07 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_Laserjet_3800_hpijs\"
234D [12/Dec/2017:00:02:07 +0500] [Client 36] con->http=0x202004e0
235D [12/Dec/2017:00:02:07 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=250, file=12
236D [12/Dec/2017:00:02:07 +0500] [Client 36] Waiting for CGI data.
237D [12/Dec/2017:00:02:07 +0500] [Client 36] Script header: Content-Type: text/html;charset=utf-8
238D [12/Dec/2017:00:02:07 +0500] [Client 36] Script header:
239D [12/Dec/2017:00:02:07 +0500] [Client 36] Sending status 200 for CGI.
240D [12/Dec/2017:00:02:07 +0500] [Client 36] cupsdSendHeader: code=200, type="(null)", auth_type=0
241D [12/Dec/2017:00:02:07 +0500] PID 250 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
242D [12/Dec/2017:00:02:07 +0500] [Client 36] con->http=0x202004e0
243D [12/Dec/2017:00:02:07 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=250, file=12
244D [12/Dec/2017:00:02:07 +0500] [Client 36] Waiting for CGI data.
245D [12/Dec/2017:00:02:07 +0500] [Client 36] CGI data ready to be sent.
246D [12/Dec/2017:00:02:07 +0500] [Job 18] new_state=2000, change_state=ffff
247D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -media-empty-warning
248D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -door-open-report
249D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -media-jam-warning
250D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -input-tray-missing-warning
251D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -output-tray-missing-warning
252D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -marker-supply-missing-warning
253D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -output-area-almost-full-report
254D [12/Dec/2017:00:02:07 +0500] [Job 18] STATE: -output-area-full-warning
255D [12/Dec/2017:00:02:07 +0500] [Job 18] backendWaitLoop(snmp_fd=5, addr=0x20037e04, side_cb=0x110f0)
256D [12/Dec/2017:00:02:07 +0500] [Client 39] GET /printers/HP_Color_Laserjet_3800_hpijs.ppd HTTP/1.1
257D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
258D [12/Dec/2017:00:02:07 +0500] [Client 39] Read: status=200
259D [12/Dec/2017:00:02:07 +0500] [Client 39] No authentication data provided.
260D [12/Dec/2017:00:02:07 +0500] [Client 39] Processing GET /printers/HP_Color_Laserjet_3800_hpijs.ppd
261D [12/Dec/2017:00:02:07 +0500] [Client 39] filename="/@unixroot/etc/cups/ppd/HP_Color_Laserjet_3800_hpijs.ppd", type=application/vnd.cups-ppd
262D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdSendHeader: code=200, type="application/vnd.cups-ppd", auth_type=0
263D [12/Dec/2017:00:02:07 +0500] [Client 39] Sending file.
264D [12/Dec/2017:00:02:07 +0500] [Client 36] con->http=0x202004e0
265D [12/Dec/2017:00:02:07 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=250, file=12
266D [12/Dec/2017:00:02:07 +0500] [Client 36] Waiting for CGI data.
267D [12/Dec/2017:00:02:07 +0500] [Client 36] Sending 0-length chunk.
268D [12/Dec/2017:00:02:07 +0500] [Client 36] Flushing write buffer.
269D [12/Dec/2017:00:02:07 +0500] [Client 36] New state is HTTP_STATE_WAITING
270D [12/Dec/2017:00:02:07 +0500] [Client 36] Waiting for request.
271D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
272D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
273D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
274D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
275D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
276D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
277D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
278D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
279D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
280D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
281D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
282D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
283D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
284D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
285D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
286D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
287D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
288D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
289D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
290D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
291D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
292D [12/Dec/2017:00:02:07 +0500] [Client 39] con->http=0x202115c0
293D [12/Dec/2017:00:02:07 +0500] [Client 39] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=20785, response=0(), pipe_pid=0, file=11
294D [12/Dec/2017:00:02:07 +0500] [Client 39] Flushing write buffer.
295D [12/Dec/2017:00:02:07 +0500] [Client 39] New state is HTTP_STATE_WAITING
296D [12/Dec/2017:00:02:07 +0500] [Client 39] Waiting for request.
297D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
298D [12/Dec/2017:00:02:07 +0500] [Client 39] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
299D [12/Dec/2017:00:02:07 +0500] [Client 39] Closing connection.
300D [12/Dec/2017:00:02:07 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
301D [12/Dec/2017:00:02:07 +0500] [Job 18] Parsing PPD file ...
302D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option ColorSpace
303D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option Resolution
304D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option PageSize
305D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option Model
306D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option PrintoutMode
307D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option InputSlot
308D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option Duplex
309D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option Quality
310D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option ImageableArea
311D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option PaperDimension
312D [12/Dec/2017:00:02:07 +0500] [Job 18] Added option Font
313D [12/Dec/2017:00:02:07 +0500] [Job 18] Parameter Summary
314D [12/Dec/2017:00:02:07 +0500] [Job 18] -----------------
315D [12/Dec/2017:00:02:07 +0500] [Job 18] Spooler: cups
316D [12/Dec/2017:00:02:07 +0500] [Job 18] Printer: HP_Color_Laserjet_3800_hpijs
317D [12/Dec/2017:00:02:07 +0500] [Job 18] Shell: /@unixroot/usr/bin/sh
318D [12/Dec/2017:00:02:07 +0500] [Job 18] PPD file: /@unixroot/etc/cups/ppd/HP_Color_Laserjet_3800_hpijs.ppd
319D [12/Dec/2017:00:02:07 +0500] [Job 18] ATTR file:
320D [12/Dec/2017:00:02:07 +0500] [Job 18] Printer model: HP Color LaserJet 3800 hpijs pcl3, 3.16.11
321D [12/Dec/2017:00:02:07 +0500] [Job 18] Job title: Test Page
322D [12/Dec/2017:00:02:07 +0500] [Job 18] File(s) to be printed:
323D [12/Dec/2017:00:02:07 +0500] [Job 18] <STDIN>
324D [12/Dec/2017:00:02:07 +0500] [Job 18] Ghostscript extra search path (\'GS_LIB\'): /@unixroot/usr/share/cups/fonts
325D [12/Dec/2017:00:02:07 +0500] [Job 18] Printing system options:
326D [12/Dec/2017:00:02:07 +0500] [Job 18] Pondering option \'job-uuid=urn:uuid:bd568d03-ed9a-3d24-6537-e86aee94712e\'
327D [12/Dec/2017:00:02:07 +0500] [Job 18] Unknown option job-uuid=urn:uuid:bd568d03-ed9a-3d24-6537-e86aee94712e.
328D [12/Dec/2017:00:02:07 +0500] [Job 18] Pondering option \'job-originating-host-name=localhost\'
329D [12/Dec/2017:00:02:07 +0500] [Job 18] Unknown option job-originating-host-name=localhost.
330D [12/Dec/2017:00:02:07 +0500] [Job 18] Pondering option \'date-time-at-creation=\'
331D [12/Dec/2017:00:02:07 +0500] [Job 18] Unknown option date-time-at-creation=.
332D [12/Dec/2017:00:02:07 +0500] [Job 18] Pondering option \'date-time-at-processing=\'
333D [12/Dec/2017:00:02:07 +0500] [Job 18] Unknown option date-time-at-processing=.
334D [12/Dec/2017:00:02:07 +0500] [Job 18] Pondering option \'time-at-creation=1513054926\'
335D [12/Dec/2017:00:02:07 +0500] [Job 18] Unknown option time-at-creation=1513054926.
336D [12/Dec/2017:00:02:07 +0500] [Job 18] Pondering option \'time-at-processing=1513054926\'
337D [12/Dec/2017:00:02:07 +0500] [Job 18] Unknown option time-at-processing=1513054926.
338D [12/Dec/2017:00:02:07 +0500] [Job 18] CM Color Calibration Mode in CUPS: Off
339D [12/Dec/2017:00:02:07 +0500] [Job 18] Options from the PPD file:
340D [12/Dec/2017:00:02:07 +0500] [Job 18] ================================================
341D [12/Dec/2017:00:02:07 +0500] [Job 18] File: <STDIN>
342D [12/Dec/2017:00:02:07 +0500] [Job 18] ================================================
343D [12/Dec/2017:00:02:07 +0500] [Job 18] Filetype: PDF
344D [12/Dec/2017:00:02:07 +0500] [Job 18] Storing temporary files in C:/var/temp
345W [12/Dec/2017:00:02:07 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
346D [12/Dec/2017:00:02:08 +0500] [Job 18] File contains 1 pages
347D [12/Dec/2017:00:02:08 +0500] [Job 18] Starting renderer with command: gs -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 -sDeviceManufacturer=\"HEWLETT-PACKARD\" -sDeviceModel=\"hp color LaserJet\" -dDuplex=false -r300 -sIjsParams=Quality:Quality=0,Quality:ColorMode=2,Quality:MediaType=0,Quality:PenSet=2,PS:MediaPosition=7 -dIjsUseOutputFD -sOutputFile=- C:/var/temp/foomatic-N53hzf
348D [12/Dec/2017:00:02:08 +0500] [Job 18] Starting process \"kid3\" (generation 1)
349D [12/Dec/2017:00:02:08 +0500] [Job 18] Starting process \"kid4\" (generation 2)
350D [12/Dec/2017:00:02:08 +0500] [Job 18] JCL: \033%-12345X@PJL
351D [12/Dec/2017:00:02:08 +0500] [Job 18] <job data>
352D [12/Dec/2017:00:02:08 +0500] [Job 18] Starting process \"renderer\" (generation 2)
353D [12/Dec/2017:00:02:08 +0500] [Job 18] GPL Ghostscript 9.18: Can\'t start ijs server \"hpijs\"
354D [12/Dec/2017:00:02:08 +0500] [Job 18] renderer exited with status 1
355D [12/Dec/2017:00:02:08 +0500] [Job 18] Possible error on renderer command line or PostScript error. Check options.DEBUG: Connecting to 192.168.100.16:9100
356D [12/Dec/2017:00:02:08 +0500] [Job 18] Kid3 exit status: 3
357I [12/Dec/2017:00:02:08 +0500] [Job 18] Connecting to printer.
358D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(---J-)
359D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
360D [12/Dec/2017:00:02:08 +0500] [Job 18] Set job-printer-state-message to "Connecting to printer.", current level=INFO
361D [12/Dec/2017:00:02:08 +0500] [Job 18] STATE: -connecting-to-device
362D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(---J-)
363D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
364I [12/Dec/2017:00:02:08 +0500] [Job 18] Connected to printer.
365D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(---J-)
366D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
367D [12/Dec/2017:00:02:08 +0500] [Job 18] Set job-printer-state-message to "Connected to printer.", current level=INFO
368D [12/Dec/2017:00:02:08 +0500] [Job 18] Connected to 192.168.100.16:9100...
369D [12/Dec/2017:00:02:08 +0500] [Job 18] backendRunLoop(print_fd=0, device_fd=6, snmp_fd=5, addr=0x20037e04, use_bc=1, side_cb=0x110f0)
370D [12/Dec/2017:00:02:08 +0500] [Job 18] STATE: +cups-waiting-for-job-completed
371D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(P----)
372D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
373D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(---J-)
374D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
375I [12/Dec/2017:00:02:08 +0500] [Job 18] Waiting for printer to finish.
376D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(---J-)
377D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
378D [12/Dec/2017:00:02:08 +0500] [Job 18] Set job-printer-state-message to "Waiting for printer to finish.", current level=INFO
379D [12/Dec/2017:00:02:08 +0500] Discarding unused job-progress event...
380D [12/Dec/2017:00:02:08 +0500] Discarding unused printer-state-changed event...
381D [12/Dec/2017:00:02:08 +0500] [Client 38] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
382D [12/Dec/2017:00:02:08 +0500] [Client 38] Closing connection.
383D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
384D [12/Dec/2017:00:02:08 +0500] [Job 18] PID 254 (/@unixroot/usr/lib/cups/filter/pdftopdf.exe) exited with no errors.
385D [12/Dec/2017:00:02:08 +0500] [Job 18] PID 256 (/@unixroot/usr/lib/cups/filter/foomatic-rip.exe) stopped with status 9.
386D [12/Dec/2017:00:02:08 +0500] [Job 18] ATTR: marker-levels=11,65,65,13
387D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(P----)
388D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
389D [12/Dec/2017:00:02:08 +0500] [Job 18] new_supply_state=0, change_state=0
390D [12/Dec/2017:00:02:08 +0500] Discarding unused printer-state-changed event...
391D [12/Dec/2017:00:02:08 +0500] [Job 18] new_state=2000, change_state=0
392D [12/Dec/2017:00:02:08 +0500] [Job 18] PID 258 (/@unixroot/usr/lib/cups/backend/socket.exe) exited with no errors.
393D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(P----)
394D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
395D [12/Dec/2017:00:02:08 +0500] Discarding unused job-state-changed event...
396E [12/Dec/2017:00:02:08 +0500] [Job 18] Job stopped due to filter errors; please consult the error_log file for details.
397D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(---J-)
398D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
399D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
400D [12/Dec/2017:00:02:08 +0500] Discarding unused printer-state-changed event...
401D [12/Dec/2017:00:02:08 +0500] cupsdMarkDirty(---J-)
402D [12/Dec/2017:00:02:08 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
403D [12/Dec/2017:00:02:08 +0500] [Job 18] The following messages were recorded from 12:02:07 am to 12:02:08 am
404D [12/Dec/2017:00:02:08 +0500] [Job 18] hrDeviceDesc=\"HP Color LaserJet 3800\"
405D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerColorantValue.1.1 = \"black\"
406D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerColorantValue.1.2 = \"cyan\"
407D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerColorantValue.1.3 = \"magenta\"
408D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerColorantValue.1.4 = \"yellow\"
409D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerSuppliesLevel.1.1 = 660
410D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerSuppliesLevel.1.2 = 3900
411D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerSuppliesLevel.1.3 = 3900
412D [12/Dec/2017:00:02:08 +0500] [Job 18] prtMarkerSuppliesLevel.1.4 = 780
413D [12/Dec/2017:00:02:08 +0500] [Job 18] End of messages
414D [12/Dec/2017:00:02:08 +0500] [Job 18] printer-state=3(idle)
415D [12/Dec/2017:00:02:08 +0500] [Job 18] printer-state-message="Filter failed"
416D [12/Dec/2017:00:02:08 +0500] [Job 18] printer-state-reasons=none
417D [12/Dec/2017:00:02:09 +0500] [Job 18] Unloading...
418D [12/Dec/2017:00:02:10 +0500] [Client 36] GET /printers/HP_Color_Laserjet_3800_hpijs HTTP/1.1
419D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
420D [12/Dec/2017:00:02:10 +0500] [Client 36] Read: status=200
421D [12/Dec/2017:00:02:10 +0500] [Client 36] No authentication data provided.
422D [12/Dec/2017:00:02:10 +0500] [Client 36] Processing GET /printers/HP_Color_Laserjet_3800_hpijs
423D [12/Dec/2017:00:02:10 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
424D [12/Dec/2017:00:02:10 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
425D [12/Dec/2017:00:02:10 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
426D [12/Dec/2017:00:02:10 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
427D [12/Dec/2017:00:02:10 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
428D [12/Dec/2017:00:02:10 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
429D [12/Dec/2017:00:02:10 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
430D [12/Dec/2017:00:02:10 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
431D [12/Dec/2017:00:02:10 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
432D [12/Dec/2017:00:02:10 +0500] [CGI] envp[8] = "HOME=C:\\var\\temp"
433D [12/Dec/2017:00:02:10 +0500] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
434D [12/Dec/2017:00:02:10 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
435D [12/Dec/2017:00:02:10 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@bluelion"
436D [12/Dec/2017:00:02:10 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
437D [12/Dec/2017:00:02:10 +0500] [CGI] envp[13] = "TMPDIR=C:\\var\\temp"
438D [12/Dec/2017:00:02:10 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
439D [12/Dec/2017:00:02:10 +0500] [CGI] envp[15] = "USER=root"
440D [12/Dec/2017:00:02:10 +0500] [CGI] envp[16] = "UNIXROOT=C:"
441D [12/Dec/2017:00:02:10 +0500] [CGI] envp[17] = "ETC=C:\\MPTN\\ETC"
442D [12/Dec/2017:00:02:10 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
443D [12/Dec/2017:00:02:10 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
444D [12/Dec/2017:00:02:10 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
445D [12/Dec/2017:00:02:10 +0500] [CGI] envp[21] = "IPP_PORT=631"
446D [12/Dec/2017:00:02:10 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
447D [12/Dec/2017:00:02:10 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
448D [12/Dec/2017:00:02:10 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
449D [12/Dec/2017:00:02:10 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
450D [12/Dec/2017:00:02:10 +0500] [CGI] envp[26] = "SERVER_PORT=631"
451D [12/Dec/2017:00:02:10 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
452D [12/Dec/2017:00:02:10 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
453D [12/Dec/2017:00:02:10 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_Laserjet_3800_hpijs"
454D [12/Dec/2017:00:02:10 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_Laserjet_3800_hpijs"
455D [12/Dec/2017:00:02:10 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_Laserjet_3800_hpijs"
456D [12/Dec/2017:00:02:10 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
457D [12/Dec/2017:00:02:10 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=53f2efb08fa70698b63f646e39907fa4"
458D [12/Dec/2017:00:02:10 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:38.0) Gecko/20100101 Firefox/38.0"
459D [12/Dec/2017:00:02:10 +0500] [CGI] envp[35] = "REQUEST_METHOD=GET"
460D [12/Dec/2017:00:02:10 +0500] [CGI] envp[36] = "QUERY_STRING="
461D [12/Dec/2017:00:02:10 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 268)
462I [12/Dec/2017:00:02:10 +0500] [Client 36] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=268, file=11)
463D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
464D [12/Dec/2017:00:02:10 +0500] [Client 40] Accepted from localhost (Domain)
465D [12/Dec/2017:00:02:10 +0500] [Client 40] Waiting for request.
466D [12/Dec/2017:00:02:10 +0500] [CGI] org.cups.sid cookie is \"53f2efb08fa70698b63f646e39907fa4\"
467D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
468D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
469D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_Laserjet_3800_hpijs\"
470D [12/Dec/2017:00:02:10 +0500] [Client 40] POST / HTTP/1.1
471D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
472D [12/Dec/2017:00:02:10 +0500] [Client 40] Read: status=200
473D [12/Dec/2017:00:02:10 +0500] [Client 40] No authentication data provided.
474D [12/Dec/2017:00:02:10 +0500] [Client 40] 2.0 CUPS-Get-Default 1
475D [12/Dec/2017:00:02:10 +0500] CUPS-Get-Default
476D [12/Dec/2017:00:02:10 +0500] CUPS-Get-Default client-error-not-found: No default printer.
477D [12/Dec/2017:00:02:10 +0500] [Client 40] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
478D [12/Dec/2017:00:02:10 +0500] [Client 40] Content-Length: 113
479D [12/Dec/2017:00:02:10 +0500] [Client 40] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
480D [12/Dec/2017:00:02:10 +0500] [Client 40] con->http=0x20207220
481D [12/Dec/2017:00:02:10 +0500] [Client 40] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x20205500(IPP_STATE_DATA), pipe_pid=0, file=-1
482D [12/Dec/2017:00:02:10 +0500] [Client 40] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
483D [12/Dec/2017:00:02:10 +0500] [Client 40] bytes=0, http_state=0, data_remaining=113
484D [12/Dec/2017:00:02:10 +0500] [Client 40] Flushing write buffer.
485D [12/Dec/2017:00:02:10 +0500] [Client 40] New state is HTTP_STATE_WAITING
486D [12/Dec/2017:00:02:10 +0500] [Client 40] Waiting for request.
487D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
488D [12/Dec/2017:00:02:10 +0500] [CGI] show_printer(http=0x2003c3c0, printer=\"HP_Color_Laserjet_3800_hpijs\")
489D [12/Dec/2017:00:02:10 +0500] [Client 40] POST / HTTP/1.1
490D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
491D [12/Dec/2017:00:02:10 +0500] [Client 40] Read: status=200
492D [12/Dec/2017:00:02:10 +0500] [Client 40] No authentication data provided.
493D [12/Dec/2017:00:02:10 +0500] [Client 40] 2.0 Get-Printer-Attributes 2
494D [12/Dec/2017:00:02:10 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_Laserjet_3800_hpijs
495D [12/Dec/2017:00:02:10 +0500] [Client 40] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_Laserjet_3800_hpijs) from localhost
496D [12/Dec/2017:00:02:10 +0500] [Client 40] Content-Length: 756
497D [12/Dec/2017:00:02:10 +0500] [Client 40] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
498D [12/Dec/2017:00:02:10 +0500] [Client 40] con->http=0x20207220
499D [12/Dec/2017:00:02:10 +0500] [Client 40] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=756, response=0x20127b00(IPP_STATE_DATA), pipe_pid=0, file=-1
500D [12/Dec/2017:00:02:10 +0500] [Client 40] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
501D [12/Dec/2017:00:02:10 +0500] [Client 40] bytes=0, http_state=0, data_remaining=756
502D [12/Dec/2017:00:02:10 +0500] [Client 40] Flushing write buffer.
503D [12/Dec/2017:00:02:10 +0500] [Client 40] New state is HTTP_STATE_WAITING
504D [12/Dec/2017:00:02:10 +0500] [Client 40] Waiting for request.
505D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
506D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
507D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
508D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
509D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
510D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
511D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"1\"
512D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
513D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
514D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_Laserjet_3800_hpijs\"
515D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_Laserjet_3800_hpijs\"
516D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_location[0]=\"office\"
517D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800 hpijs pcl3\"
518D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
519D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: device_uri[0]=\"socket://192.168.100.16\"
520D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
521D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 hpijs pcl3, 3.16.11\"
522D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
523D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
524D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
525D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
526D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
527D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_Laserjet_3800_hpijs\"
528D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
529D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
530D [12/Dec/2017:00:02:10 +0500] [Client 36] CGI data ready to be sent.
531D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
532D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=268, file=11
533D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
534D [12/Dec/2017:00:02:10 +0500] [Client 36] Script header: Content-Type: text/html;charset=utf-8
535D [12/Dec/2017:00:02:10 +0500] [Client 36] Script header:
536D [12/Dec/2017:00:02:10 +0500] [Client 36] Sending status 200 for CGI.
537D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdSendHeader: code=200, type="(null)", auth_type=0
538D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
539D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
540D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
541D [12/Dec/2017:00:02:10 +0500] [Client 36] CGI data ready to be sent.
542D [12/Dec/2017:00:02:10 +0500] [Client 40] POST / HTTP/1.1
543D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
544D [12/Dec/2017:00:02:10 +0500] [Client 40] Read: status=200
545D [12/Dec/2017:00:02:10 +0500] [Client 40] No authentication data provided.
546D [12/Dec/2017:00:02:10 +0500] [Client 40] 2.0 Get-Jobs 3
547D [12/Dec/2017:00:02:10 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_Laserjet_3800_hpijs
548D [12/Dec/2017:00:02:10 +0500] [Job 18] Loading attributes...
549D [12/Dec/2017:00:02:10 +0500] [Client 40] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_Laserjet_3800_hpijs) from localhost
550D [12/Dec/2017:00:02:10 +0500] [Client 40] Content-Length: 435
551D [12/Dec/2017:00:02:10 +0500] [Client 40] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
552D [12/Dec/2017:00:02:10 +0500] [CGI] Regular expression \".*Clean.*\"
553D [12/Dec/2017:00:02:10 +0500] [CGI] matches[0].rm_so=0
554D [12/Dec/2017:00:02:10 +0500] [CGI] matches[1].rm_so=-1
555D [12/Dec/2017:00:02:10 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
556D [12/Dec/2017:00:02:10 +0500] [CGI] matches[0].rm_so=0
557D [12/Dec/2017:00:02:10 +0500] [CGI] matches[1].rm_so=-1
558D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
559D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
560D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
561D [12/Dec/2017:00:02:10 +0500] [Client 40] con->http=0x20207220
562D [12/Dec/2017:00:02:10 +0500] [Client 40] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=435, response=0x20127c40(IPP_STATE_DATA), pipe_pid=0, file=-1
563D [12/Dec/2017:00:02:10 +0500] [Client 40] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
564D [12/Dec/2017:00:02:10 +0500] [Client 40] bytes=0, http_state=0, data_remaining=435
565D [12/Dec/2017:00:02:10 +0500] [Client 40] Flushing write buffer.
566D [12/Dec/2017:00:02:10 +0500] [Client 40] New state is HTTP_STATE_WAITING
567D [12/Dec/2017:00:02:10 +0500] [Client 40] Waiting for request.
568D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
569D [12/Dec/2017:00:02:10 +0500] [Client 41] Accepted from localhost:64943 (IPv4)
570D [12/Dec/2017:00:02:10 +0500] [Client 41] Waiting for request.
571D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
572D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
573D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
574D [12/Dec/2017:00:02:10 +0500] [Client 41] GET /cups.css HTTP/1.1
575D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
576D [12/Dec/2017:00:02:10 +0500] [Client 41] Read: status=200
577D [12/Dec/2017:00:02:10 +0500] [Client 41] No authentication data provided.
578D [12/Dec/2017:00:02:10 +0500] [Client 41] Processing GET /cups.css
579D [12/Dec/2017:00:02:10 +0500] [Client 41] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
580D [12/Dec/2017:00:02:10 +0500] [Client 41] cupsdSendHeader: code=304, type="(null)", auth_type=0
581D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
582D [12/Dec/2017:00:02:10 +0500] [CGI] cgiClearVariables called.
583D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
584D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
585D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: TOTAL=\"1\"
586D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
587D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
588D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_preserved[0]=\"1\"
589D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_printer_name[0]=\"HP_Color_Laserjet_3800_hpijs\"
590D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_Color_Laserjet_3800_hpijs\"
591D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
592D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
593D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
594D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: time_at_creation[0]=\"Tue Dec 12 00:02:06 EST 2017\"
595D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: time_at_processing[0]=\"Tue Dec 12 00:02:06 EST 2017\"
596D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_id[0]=\"18\"
597D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_state[0]=\"6\"
598D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"1\"
599D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
600D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
601D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_Laserjet_3800_hpijs\"
602D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_Laserjet_3800_hpijs\"
603D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_Laserjet_3800_hpijs\"
604D [12/Dec/2017:00:02:10 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_Laserjet_3800_hpijs\"
605D [12/Dec/2017:00:02:10 +0500] [Client 36] CGI data ready to be sent.
606D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
607D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
608D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
609D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
610D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
611D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
612D [12/Dec/2017:00:02:10 +0500] [Client 36] CGI data ready to be sent.
613D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
614D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
615D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
616D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
617D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
618D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
619D [12/Dec/2017:00:02:10 +0500] [Client 36] CGI data ready to be sent.
620D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
621D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
622D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
623D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
624D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
625D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
626D [12/Dec/2017:00:02:10 +0500] [Client 36] CGI data ready to be sent.
627D [12/Dec/2017:00:02:10 +0500] [Client 40] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
628D [12/Dec/2017:00:02:10 +0500] [Client 40] Closing connection.
629D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
630D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
631D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
632D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
633D [12/Dec/2017:00:02:10 +0500] PID 268 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
634D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
635D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
636D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
637D [12/Dec/2017:00:02:10 +0500] [Client 36] CGI data ready to be sent.
638D [12/Dec/2017:00:02:10 +0500] [Client 36] con->http=0x202004e0
639D [12/Dec/2017:00:02:10 +0500] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=268, file=11
640D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for CGI data.
641D [12/Dec/2017:00:02:10 +0500] [Client 36] Sending 0-length chunk.
642D [12/Dec/2017:00:02:10 +0500] [Client 36] Flushing write buffer.
643D [12/Dec/2017:00:02:10 +0500] [Client 36] New state is HTTP_STATE_WAITING
644D [12/Dec/2017:00:02:10 +0500] [Client 36] Waiting for request.
645D [12/Dec/2017:00:02:10 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
646I [12/Dec/2017:00:02:20 +0500] Saving printers.conf...
647I [12/Dec/2017:00:02:20 +0500] Saving job.cache...
648D [12/Dec/2017:00:02:20 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
649D [12/Dec/2017:00:02:20 +0500] [Client 36] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
650D [12/Dec/2017:00:02:20 +0500] [Client 36] Closing connection.
651D [12/Dec/2017:00:02:20 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
652D [12/Dec/2017:00:02:20 +0500] [Client 41] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
653D [12/Dec/2017:00:02:20 +0500] [Client 41] Closing connection.
654D [12/Dec/2017:00:02:20 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"