Ticket #143: error_log-2017-12-08-TempDir-PS

File error_log-2017-12-08-TempDir-PS, 78.8 KB (added by Lewis Rosenthal, 7 years ago)

TempDir uncommented in cups-files.conf. PS fails (filter error).

Line 
1D [08/Dec/2017:11:39:00 +0500] [Client 12] POST /printers/HP_Color_LaserJet_3800_PS HTTP/1.1
2D [08/Dec/2017:11:39:00 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
3D [08/Dec/2017:11:39:00 +0500] [Client 12] Read: status=200
4D [08/Dec/2017:11:39:00 +0500] [Client 12] No authentication data provided.
5D [08/Dec/2017:11:39:00 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
6D [08/Dec/2017:11:39:00 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
7D [08/Dec/2017:11:39:00 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
8D [08/Dec/2017:11:39:00 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
9D [08/Dec/2017:11:39:00 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
10D [08/Dec/2017:11:39:00 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
11D [08/Dec/2017:11:39:00 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
12D [08/Dec/2017:11:39:00 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
13D [08/Dec/2017:11:39:00 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
14D [08/Dec/2017:11:39:00 +0500] [CGI] envp[8] = "HOME=/@unixroot/var/spool/cups/tmp"
15D [08/Dec/2017:11:39:00 +0500] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
16D [08/Dec/2017:11:39:00 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
17D [08/Dec/2017:11:39:00 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@bluelion"
18D [08/Dec/2017:11:39:00 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
19D [08/Dec/2017:11:39:00 +0500] [CGI] envp[13] = "TMPDIR=/@unixroot/var/spool/cups/tmp"
20D [08/Dec/2017:11:39:00 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
21D [08/Dec/2017:11:39:00 +0500] [CGI] envp[15] = "USER=root"
22D [08/Dec/2017:11:39:00 +0500] [CGI] envp[16] = "UNIXROOT=C:"
23D [08/Dec/2017:11:39:00 +0500] [CGI] envp[17] = "ETC=C:\\MPTN\\ETC"
24D [08/Dec/2017:11:39:00 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
25D [08/Dec/2017:11:39:00 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
26D [08/Dec/2017:11:39:00 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
27D [08/Dec/2017:11:39:00 +0500] [CGI] envp[21] = "IPP_PORT=631"
28D [08/Dec/2017:11:39:00 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
29D [08/Dec/2017:11:39:00 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
30D [08/Dec/2017:11:39:00 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
31D [08/Dec/2017:11:39:00 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
32D [08/Dec/2017:11:39:00 +0500] [CGI] envp[26] = "SERVER_PORT=631"
33D [08/Dec/2017:11:39:00 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
34D [08/Dec/2017:11:39:00 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
35D [08/Dec/2017:11:39:00 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800_PS"
36D [08/Dec/2017:11:39:00 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800_PS"
37D [08/Dec/2017:11:39:00 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_LaserJet_3800_PS"
38D [08/Dec/2017:11:39:00 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
39D [08/Dec/2017:11:39:00 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=41f45aede00677dfbe5c986711944887"
40D [08/Dec/2017:11:39:00 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
41D [08/Dec/2017:11:39:00 +0500] [CGI] envp[35] = "HTTP_REFERER=http://localhost:631/printers/HP_Color_LaserJet_3800_PS"
42D [08/Dec/2017:11:39:00 +0500] [CGI] envp[36] = "REQUEST_METHOD=POST"
43D [08/Dec/2017:11:39:00 +0500] [CGI] envp[37] = "CONTENT_LENGTH=64"
44D [08/Dec/2017:11:39:00 +0500] [CGI] envp[38] = "CONTENT_TYPE=application/x-www-form-urlencoded"
45D [08/Dec/2017:11:39:00 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 151)
46I [08/Dec/2017:11:39:00 +0500] [Client 12] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=151, file=16)
47D [08/Dec/2017:11:39:00 +0500] [Client 12] Waiting for CGI data.
48D [08/Dec/2017:11:39:00 +0500] [Client 15] Accepted from localhost (Domain)
49D [08/Dec/2017:11:39:00 +0500] [Client 15] Waiting for request.
50D [08/Dec/2017:11:39:00 +0500] [CGI] org.cups.sid cookie is \"41f45aede00677dfbe5c986711944887\"
51D [08/Dec/2017:11:39:00 +0500] [CGI] cgiSetVariable: org.cups.sid=\"41f45aede00677dfbe5c986711944887\"
52D [08/Dec/2017:11:39:00 +0500] [CGI] cgiSetVariable: OP=\"print-test-page\"
53D [08/Dec/2017:11:39:00 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
54D [08/Dec/2017:11:39:00 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
55D [08/Dec/2017:11:39:00 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800_PS\"
56D [08/Dec/2017:11:39:00 +0500] [Client 15] POST /printers/HP_Color_LaserJet_3800_PS HTTP/1.1
57D [08/Dec/2017:11:39:00 +0500] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
58D [08/Dec/2017:11:39:00 +0500] [Client 15] Read: status=200
59D [08/Dec/2017:11:39:00 +0500] [Client 15] No authentication data provided.
60D [08/Dec/2017:11:39:00 +0500] [Client 15] 2.0 Print-Job 1
61D [08/Dec/2017:11:39:00 +0500] Print-Job ipp://localhost:631/printers/HP_Color_LaserJet_3800_PS
62D [08/Dec/2017:11:39:00 +0500] [Job ???] Auto-typing file...
63I [08/Dec/2017:11:39:00 +0500] [Job ???] Request file type is application/vnd.cups-pdf-banner.
64D [08/Dec/2017:11:39:00 +0500] cupsdMarkDirty(---J-)
65D [08/Dec/2017:11:39:00 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
66D [08/Dec/2017:11:39:00 +0500] Adding default job-sheets values "none,none"...
67I [08/Dec/2017:11:39:00 +0500] [Job 11] Adding start banner page "none".
68D [08/Dec/2017:11:39:00 +0500] Discarding unused job-created event...
69D [08/Dec/2017:11:39:00 +0500] cupsdMarkDirty(---J-)
70D [08/Dec/2017:11:39:00 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
71I [08/Dec/2017:11:39:00 +0500] [Job 11] Adding end banner page "none".
72I [08/Dec/2017:11:39:00 +0500] [Job 11] File of type application/vnd.cups-pdf-banner queued by "anonymous".
73D [08/Dec/2017:11:39:00 +0500] [Job 11] hold_until=0
74I [08/Dec/2017:11:39:00 +0500] [Job 11] Queued on "HP_Color_LaserJet_3800_PS" by "anonymous".
75D [08/Dec/2017:11:39:00 +0500] [Job 11] time-at-processing=1512751140
76D [08/Dec/2017:11:39:00 +0500] cupsdMarkDirty(---J-)
77D [08/Dec/2017:11:39:00 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
78D [08/Dec/2017:11:39:00 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
79D [08/Dec/2017:11:39:00 +0500] Discarding unused printer-state-changed event...
80D [08/Dec/2017:11:39:00 +0500] [Job 11] 4 filters for job:
81D [08/Dec/2017:11:39:00 +0500] [Job 11] bannertopdf.exe (application/vnd.cups-pdf-banner to application/pdf, cost 32)
82D [08/Dec/2017:11:39:00 +0500] [Job 11] pdftopdf.exe (application/pdf to application/vnd.cups-pdf, cost 66)
83D [08/Dec/2017:11:39:00 +0500] [Job 11] pdftops.exe (application/vnd.cups-pdf to application/vnd.cups-postscript, cost 100)
84D [08/Dec/2017:11:39:00 +0500] [Job 11] hpps (application/vnd.cups-postscript to printer/HP_Color_LaserJet_3800_PS, cost 0)
85D [08/Dec/2017:11:39:00 +0500] [Job 11] job-sheets=none,none
86D [08/Dec/2017:11:39:00 +0500] [Job 11] argv[0]="HP_Color_LaserJet_3800_PS"
87D [08/Dec/2017:11:39:00 +0500] [Job 11] argv[1]="11"
88D [08/Dec/2017:11:39:00 +0500] [Job 11] argv[2]="anonymous"
89D [08/Dec/2017:11:39:00 +0500] [Job 11] argv[3]="Test Page"
90D [08/Dec/2017:11:39:00 +0500] [Job 11] argv[4]="1"
91D [08/Dec/2017:11:39:00 +0500] [Job 11] argv[5]="job-uuid=urn:uuid:54995884-4ee9-3966-674b-3fd6da49a4af job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1512751140 time-at-processing=1512751140"
92D [08/Dec/2017:11:39:00 +0500] [Job 11] argv[6]="/@unixroot/var/spool/cups/d00011-001"
93D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[0]="CUPS_CACHEDIR=/@unixroot/var/cache/cups"
94D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[1]="CUPS_DATADIR=/@unixroot/usr/share/cups"
95D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[2]="CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
96D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[3]="CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
97D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[4]="CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
98D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[5]="CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
99D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[6]="CUPS_SERVERROOT=/@unixroot/etc/cups"
100D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[7]="CUPS_STATEDIR=/@unixroot/var/run/cups"
101D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[8]="HOME=/@unixroot/var/spool/cups/tmp"
102D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[9]="NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
103D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[10]="PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
104D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[11]="SERVER_ADMIN=root@bluelion"
105D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[12]="SOFTWARE=CUPS/2.1.3"
106D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[13]="TMPDIR=/@unixroot/var/spool/cups/tmp"
107D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[14]="TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
108D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[15]="USER=root"
109D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[16]="UNIXROOT=C:"
110D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[17]="ETC=C:\\MPTN\\ETC"
111D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[18]="CUPS_MAX_MESSAGE=2047"
112D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[19]="CUPS_SERVER=\\socket\\cups.sock"
113D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[20]="CUPS_ENCRYPTION=IfRequested"
114D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[21]="IPP_PORT=631"
115D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[22]="CHARSET=utf-8"
116D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[23]="LANG=en_US.UTF-8"
117D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[24]="PPD=/@unixroot/etc/cups/ppd/HP_Color_LaserJet_3800_PS.ppd"
118D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[25]="RIP_MAX_CACHE=128m"
119D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[26]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
120D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[27]="DEVICE_URI=socket://192.168.100.16"
121D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[28]="PRINTER_INFO=HP Color LaserJet 3800 PS"
122D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[29]="PRINTER_LOCATION=office"
123D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[30]="PRINTER=HP_Color_LaserJet_3800_PS"
124D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[31]="PRINTER_STATE_REASONS=none"
125D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[32]="CUPS_FILETYPE=document"
126D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[33]="FINAL_CONTENT_TYPE=application/vnd.cups-postscript"
127D [08/Dec/2017:11:39:00 +0500] [Job 11] envp[34]="AUTH_I****"
128I [08/Dec/2017:11:39:01 +0500] [Job 11] Started filter /@unixroot/usr/lib/cups/filter/bannertopdf.exe (PID 153)
129I [08/Dec/2017:11:39:01 +0500] [Job 11] Started filter /@unixroot/usr/lib/cups/filter/pdftopdf.exe (PID 155)
130I [08/Dec/2017:11:39:01 +0500] [Job 11] Started filter /@unixroot/usr/lib/cups/filter/pdftops.exe (PID 157)
131I [08/Dec/2017:11:39:01 +0500] [Job 11] Started filter /@unixroot/usr/lib/cups/filter/hpps (PID 158)
132I [08/Dec/2017:11:39:01 +0500] [Job 11] Started backend /@unixroot/usr/lib/cups/backend/socket.exe (PID 160)
133D [08/Dec/2017:11:39:01 +0500] Discarding unused job-state-changed event...
134D [08/Dec/2017:11:39:01 +0500] [Client 15] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HP_Color_LaserJet_3800_PS) from localhost
135D [08/Dec/2017:11:39:01 +0500] [Client 15] Content-Length: 192
136D [08/Dec/2017:11:39:01 +0500] [Client 15] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
137D [08/Dec/2017:11:39:01 +0500] [Job 11] PID 153 (/@unixroot/usr/lib/cups/filter/bannertopdf.exe) exited with no errors.
138D [08/Dec/2017:11:39:01 +0500] [Client 15] con->http=0x201ff2c0
139D [08/Dec/2017:11:39:01 +0500] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=192, response=0x2005c760(IPP_STATE_IDLE), pipe_pid=0, file=-1
140D [08/Dec/2017:11:39:01 +0500] [Client 15] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
141D [08/Dec/2017:11:39:01 +0500] [Client 15] bytes=0, http_state=0, data_remaining=192
142D [08/Dec/2017:11:39:01 +0500] [Client 15] Flushing write buffer.
143D [08/Dec/2017:11:39:01 +0500] [Client 15] New state is HTTP_STATE_WAITING
144D [08/Dec/2017:11:39:01 +0500] [Client 15] Waiting for request.
145D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
146D [08/Dec/2017:11:39:01 +0500] [Job 11] pdftopdf: Last filter determined by the PPD: hpps; FINAL_CONTENT_TYPE: application/vnd.cups-postscript => pdftopdf will log pages in page_log.
147D [08/Dec/2017:11:39:01 +0500] [Job 11] PDF template file doesn\'t have form. It\'s okay.
148D [08/Dec/2017:11:39:01 +0500] [Job 11] PAGE: 1 1
149D [08/Dec/2017:11:39:01 +0500] cupsdMarkDirty(---J-)
150D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
151D [08/Dec/2017:11:39:01 +0500] cupsdMarkDirty(---J-)
152D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
153D [08/Dec/2017:11:39:01 +0500] Discarding unused job-progress event...
154D [08/Dec/2017:11:39:01 +0500] [Job 11] pdftops - copying to temp print file \"/@unixroot/var/spool/cups/tmp/0009f5a2e5ded\"
155D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: +connecting-to-device
156D [08/Dec/2017:11:39:01 +0500] cupsdMarkDirty(---J-)
157D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients, printing jobs, and dirty files"
158D [08/Dec/2017:11:39:01 +0500] [Job 11] Looking up \"192.168.100.16\"...
159D [08/Dec/2017:11:39:01 +0500] Discarding unused printer-state-changed event...
160D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
161D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
162D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
163D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
164W [08/Dec/2017:11:39:01 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
165D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetArray: job_uri[0]=\"/jobs/11\"
166D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetArray: job_id[0]=\"11\"
167D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetArray: job_state[0]=\"3\"
168D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetArray: job_state_message[0]=\"\"
169D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetArray: job_state_reasons[0]=\"none\"
170D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: refresh_page=\"2;URL=/printers/HP_Color_LaserJet_3800_PS\"
171D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: TITLE=\"Print Test Page\"
172D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
173D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
174D [08/Dec/2017:11:39:01 +0500] [Client 15] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
175D [08/Dec/2017:11:39:01 +0500] [Client 15] Closing connection.
176D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
177D [08/Dec/2017:11:39:01 +0500] [Client 12] CGI data ready to be sent.
178D [08/Dec/2017:11:39:01 +0500] [Job 11] Printer make and model: HP Hewlett-Packard HP Color LaserJet 3800
179D [08/Dec/2017:11:39:01 +0500] [Job 11] Running command line for pstops: pstops 11 anonymous \'Test Page\' 1 \'job-uuid=urn:uuid:54995884-4ee9-3966-674b-3fd6da49a4af job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1512751140 time-at-processing=1512751140\'
180D [08/Dec/2017:11:39:01 +0500] [Job 11] Using image rendering resolution 600 dpi
181D [08/Dec/2017:11:39:01 +0500] [Job 11] Running command line for pdftops: pdftops -level2 -origpagesizes -nocenter -r 600 /@unixroot/var/spool/cups/tmp/0009f5a2e5ded -
182D [08/Dec/2017:11:39:01 +0500] [Job 11] Started filter pdftops (PID 163)
183D [08/Dec/2017:11:39:01 +0500] [Job 11] ATTR: marker-colors=#000000,#00FFFF,#FF00FF,#FFFF00
184D [08/Dec/2017:11:39:01 +0500] cupsdMarkDirty(P----)
185D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
186D [08/Dec/2017:11:39:01 +0500] [Job 11] ATTR: marker-names=\'\"Black Cartridge HP Q6470A\"\',\'\"Cyan Cartridge HP Q7581A\"\',\'\"Magenta Cartridge HP Q7583A\"\',\'\"Yellow Cartridge HP Q7582A\"\'
187D [08/Dec/2017:11:39:01 +0500] cupsdMarkDirty(P----)
188D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
189D [08/Dec/2017:11:39:01 +0500] [Job 11] ATTR: marker-types=toner-cartridge,toner-cartridge,toner-cartridge,toner-cartridge
190D [08/Dec/2017:11:39:01 +0500] cupsdMarkDirty(P----)
191D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
192D [08/Dec/2017:11:39:01 +0500] [Job 11] ATTR: marker-levels=11,66,66,13
193D [08/Dec/2017:11:39:01 +0500] cupsdMarkDirty(P----)
194D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
195D [08/Dec/2017:11:39:01 +0500] [Job 11] new_supply_state=0, change_state=ffff
196D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -developer-low-report
197D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -developer-empty-warning
198D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -marker-supply-low-report
199D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -marker-supply-empty-warning
200D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -opc-near-eol-report
201D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -opc-life-over-warning
202D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -toner-low-report
203D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -toner-empty-warning
204D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -waste-receptacle-almost-full-report
205D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -waste-receptacle-full-warning
206D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -cleaner-life-almost-over-report
207D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -cleaner-life-over-warning
208D [08/Dec/2017:11:39:01 +0500] [Job 11] new_state=2000, change_state=ffff
209D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -media-empty-warning
210D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -door-open-report
211D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -media-jam-warning
212D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -input-tray-missing-warning
213D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -output-tray-missing-warning
214D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -marker-supply-missing-warning
215D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -output-area-almost-full-report
216D [08/Dec/2017:11:39:01 +0500] [Job 11] STATE: -output-area-full-warning
217D [08/Dec/2017:11:39:01 +0500] [Job 11] Started filter pstops (PID 165)
218D [08/Dec/2017:11:39:01 +0500] Discarding unused printer-state-changed event...
219D [08/Dec/2017:11:39:01 +0500] [Job 11] PID 155 (/@unixroot/usr/lib/cups/filter/pdftopdf.exe) exited with no errors.
220D [08/Dec/2017:11:39:01 +0500] PID 151 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
221D [08/Dec/2017:11:39:01 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800_PS\"
222D [08/Dec/2017:11:39:01 +0500] [Client 12] con->http=0x201f7140
223D [08/Dec/2017:11:39:01 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=151, file=16
224D [08/Dec/2017:11:39:01 +0500] [Client 12] Waiting for CGI data.
225D [08/Dec/2017:11:39:01 +0500] [Client 12] Script header: Content-Type: text/html;charset=utf-8
226D [08/Dec/2017:11:39:01 +0500] [Client 12] Script header:
227D [08/Dec/2017:11:39:01 +0500] [Client 12] Sending status 200 for CGI.
228D [08/Dec/2017:11:39:01 +0500] [Client 12] cupsdSendHeader: code=200, type="(null)", auth_type=0
229D [08/Dec/2017:11:39:01 +0500] [Client 12] con->http=0x201f7140
230D [08/Dec/2017:11:39:01 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=151, file=16
231D [08/Dec/2017:11:39:01 +0500] [Client 12] Waiting for CGI data.
232D [08/Dec/2017:11:39:01 +0500] [Client 12] CGI data ready to be sent.
233D [08/Dec/2017:11:39:01 +0500] [Client 12] con->http=0x201f7140
234D [08/Dec/2017:11:39:01 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=151, file=16
235D [08/Dec/2017:11:39:01 +0500] [Client 12] Waiting for CGI data.
236D [08/Dec/2017:11:39:01 +0500] [Client 12] Sending 0-length chunk.
237D [08/Dec/2017:11:39:01 +0500] [Client 12] Flushing write buffer.
238D [08/Dec/2017:11:39:01 +0500] [Client 12] New state is HTTP_STATE_WAITING
239D [08/Dec/2017:11:39:01 +0500] [Client 12] Waiting for request.
240D [08/Dec/2017:11:39:01 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
241D [08/Dec/2017:11:39:01 +0500] [Job 11] backendWaitLoop(snmp_fd=5, addr=0x20037e04, side_cb=0x110f0)
242D [08/Dec/2017:11:39:01 +0500] [Job 11] Page = 612x792; 12,12 to 600,780
243D [08/Dec/2017:11:39:01 +0500] [Job 11] slow_collate=0, slow_duplex=0, slow_order=0
244D [08/Dec/2017:11:39:01 +0500] [Job 11] Before copy_comments - %!PS-Adobe-3.0
245D [08/Dec/2017:11:39:01 +0500] [Job 11] %!PS-Adobe-3.0
246D [08/Dec/2017:11:39:01 +0500] [Job 11] %Produced by poppler pdftops version: 0.52.0 (http://poppler.freedesktop.org)
247D [08/Dec/2017:11:39:01 +0500] [Job 11] %%Creator: cairo 1.10.2 (http://cairographics.org)
248D [08/Dec/2017:11:39:01 +0500] [Job 11] %%LanguageLevel: 2
249D [08/Dec/2017:11:39:01 +0500] [Job 11] %%DocumentSuppliedResources: (atend)
250D [08/Dec/2017:11:39:01 +0500] [Job 11] %%DocumentMedia: Letter 612 792 0 () ()
251D [08/Dec/2017:11:39:01 +0500] [Job 11] %%BoundingBox: 0 0 612 792
252D [08/Dec/2017:11:39:01 +0500] [Job 11] %%Pages: 1
253D [08/Dec/2017:11:39:01 +0500] [Job 11] %%EndComments
254D [08/Dec/2017:11:39:01 +0500] [Job 11] Before copy_prolog - %%BeginProlog
255D [08/Dec/2017:11:39:02 +0500] [Job 11] Before copy_setup - %%BeginSetup
256D [08/Dec/2017:11:39:03 +0500] [Client 12] GET /printers/HP_Color_LaserJet_3800_PS HTTP/1.1
257D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
258D [08/Dec/2017:11:39:03 +0500] [Client 12] Read: status=200
259D [08/Dec/2017:11:39:03 +0500] [Client 12] No authentication data provided.
260D [08/Dec/2017:11:39:03 +0500] [Client 12] Processing GET /printers/HP_Color_LaserJet_3800_PS
261D [08/Dec/2017:11:39:03 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
262D [08/Dec/2017:11:39:03 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
263D [08/Dec/2017:11:39:03 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
264D [08/Dec/2017:11:39:03 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
265D [08/Dec/2017:11:39:03 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
266D [08/Dec/2017:11:39:03 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
267D [08/Dec/2017:11:39:03 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
268D [08/Dec/2017:11:39:03 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
269D [08/Dec/2017:11:39:03 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
270D [08/Dec/2017:11:39:03 +0500] [CGI] envp[8] = "HOME=/@unixroot/var/spool/cups/tmp"
271D [08/Dec/2017:11:39:03 +0500] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
272D [08/Dec/2017:11:39:03 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
273D [08/Dec/2017:11:39:03 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@bluelion"
274D [08/Dec/2017:11:39:03 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
275D [08/Dec/2017:11:39:03 +0500] [CGI] envp[13] = "TMPDIR=/@unixroot/var/spool/cups/tmp"
276D [08/Dec/2017:11:39:03 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
277D [08/Dec/2017:11:39:03 +0500] [CGI] envp[15] = "USER=root"
278D [08/Dec/2017:11:39:03 +0500] [CGI] envp[16] = "UNIXROOT=C:"
279D [08/Dec/2017:11:39:03 +0500] [CGI] envp[17] = "ETC=C:\\MPTN\\ETC"
280D [08/Dec/2017:11:39:03 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
281D [08/Dec/2017:11:39:03 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
282D [08/Dec/2017:11:39:03 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
283D [08/Dec/2017:11:39:03 +0500] [CGI] envp[21] = "IPP_PORT=631"
284D [08/Dec/2017:11:39:03 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
285D [08/Dec/2017:11:39:03 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
286D [08/Dec/2017:11:39:03 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
287D [08/Dec/2017:11:39:03 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
288D [08/Dec/2017:11:39:03 +0500] [CGI] envp[26] = "SERVER_PORT=631"
289D [08/Dec/2017:11:39:03 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
290D [08/Dec/2017:11:39:03 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
291D [08/Dec/2017:11:39:03 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800_PS"
292D [08/Dec/2017:11:39:03 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800_PS"
293D [08/Dec/2017:11:39:03 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_LaserJet_3800_PS"
294D [08/Dec/2017:11:39:03 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
295D [08/Dec/2017:11:39:03 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=41f45aede00677dfbe5c986711944887"
296D [08/Dec/2017:11:39:03 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
297D [08/Dec/2017:11:39:03 +0500] [CGI] envp[35] = "REQUEST_METHOD=GET"
298D [08/Dec/2017:11:39:03 +0500] [CGI] envp[36] = "QUERY_STRING="
299D [08/Dec/2017:11:39:03 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 169)
300I [08/Dec/2017:11:39:03 +0500] [Client 12] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=169, file=15)
301D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
302D [08/Dec/2017:11:39:03 +0500] [Client 16] Accepted from localhost (Domain)
303D [08/Dec/2017:11:39:03 +0500] [Client 16] Waiting for request.
304D [08/Dec/2017:11:39:03 +0500] [CGI] org.cups.sid cookie is \"41f45aede00677dfbe5c986711944887\"
305D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
306D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
307D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800_PS\"
308D [08/Dec/2017:11:39:03 +0500] [Client 16] POST / HTTP/1.1
309D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
310D [08/Dec/2017:11:39:03 +0500] [Client 16] Read: status=200
311D [08/Dec/2017:11:39:03 +0500] [Client 16] No authentication data provided.
312D [08/Dec/2017:11:39:03 +0500] [Client 16] 2.0 CUPS-Get-Default 1
313D [08/Dec/2017:11:39:03 +0500] CUPS-Get-Default
314D [08/Dec/2017:11:39:03 +0500] CUPS-Get-Default client-error-not-found: No default printer.
315D [08/Dec/2017:11:39:03 +0500] [Client 16] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
316D [08/Dec/2017:11:39:03 +0500] [Client 16] Content-Length: 113
317D [08/Dec/2017:11:39:03 +0500] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
318D [08/Dec/2017:11:39:03 +0500] [Client 16] con->http=0x201ff2c0
319D [08/Dec/2017:11:39:03 +0500] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x2011efa0(IPP_STATE_DATA), pipe_pid=0, file=-1
320D [08/Dec/2017:11:39:03 +0500] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
321D [08/Dec/2017:11:39:03 +0500] [Client 16] bytes=0, http_state=0, data_remaining=113
322D [08/Dec/2017:11:39:03 +0500] [Client 16] Flushing write buffer.
323D [08/Dec/2017:11:39:03 +0500] [Client 16] New state is HTTP_STATE_WAITING
324D [08/Dec/2017:11:39:03 +0500] [Client 16] Waiting for request.
325D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
326D [08/Dec/2017:11:39:03 +0500] [CGI] show_printer(http=0x2003c3c0, printer=\"HP_Color_LaserJet_3800_PS\")
327D [08/Dec/2017:11:39:03 +0500] [Client 16] POST / HTTP/1.1
328D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
329D [08/Dec/2017:11:39:03 +0500] [Client 16] Read: status=200
330D [08/Dec/2017:11:39:03 +0500] [Client 16] No authentication data provided.
331D [08/Dec/2017:11:39:03 +0500] [Client 16] 2.0 Get-Printer-Attributes 2
332D [08/Dec/2017:11:39:03 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800_PS
333D [08/Dec/2017:11:39:03 +0500] [Client 16] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800_PS) from localhost
334D [08/Dec/2017:11:39:03 +0500] [Client 16] Content-Length: 698
335D [08/Dec/2017:11:39:03 +0500] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
336D [08/Dec/2017:11:39:03 +0500] [Client 16] con->http=0x201ff2c0
337D [08/Dec/2017:11:39:03 +0500] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=698, response=0x201fe200(IPP_STATE_DATA), pipe_pid=0, file=-1
338D [08/Dec/2017:11:39:03 +0500] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
339D [08/Dec/2017:11:39:03 +0500] [Client 16] bytes=0, http_state=0, data_remaining=698
340D [08/Dec/2017:11:39:03 +0500] [Client 16] Flushing write buffer.
341D [08/Dec/2017:11:39:03 +0500] [Client 16] New state is HTTP_STATE_WAITING
342D [08/Dec/2017:11:39:03 +0500] [Client 16] Waiting for request.
343D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
344D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
345D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
346D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
347D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
348D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
349D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"1\"
350D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_state[0]=\"4\"
351D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
352D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800_PS\"
353D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800_PS\"
354D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_location[0]=\"office\"
355D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800 PS\"
356D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
357D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: device_uri[0]=\"socket://192.168.100.16\"
358D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
359D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 Postscript (recommended)\"
360D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
361D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided\"
362D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
363D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
364D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
365D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: refresh_page=\"10;URL=/printers/HP_Color_LaserJet_3800_PS\"
366D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_LaserJet_3800_PS\"
367D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
368D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
369D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
370D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
371D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=169, file=15
372D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
373D [08/Dec/2017:11:39:03 +0500] [Client 12] Script header: Content-Type: text/html;charset=utf-8
374D [08/Dec/2017:11:39:03 +0500] [Client 12] Script header:
375D [08/Dec/2017:11:39:03 +0500] [Client 12] Sending status 200 for CGI.
376D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdSendHeader: code=200, type="(null)", auth_type=0
377D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
378D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
379D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
380D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
381D [08/Dec/2017:11:39:03 +0500] [Client 16] POST / HTTP/1.1
382D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
383D [08/Dec/2017:11:39:03 +0500] [Client 16] Read: status=200
384D [08/Dec/2017:11:39:03 +0500] [Client 16] No authentication data provided.
385D [08/Dec/2017:11:39:03 +0500] [Client 16] 2.0 Get-Jobs 3
386D [08/Dec/2017:11:39:03 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_LaserJet_3800_PS
387D [08/Dec/2017:11:39:03 +0500] [Client 16] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_LaserJet_3800_PS) from localhost
388D [08/Dec/2017:11:39:03 +0500] [Client 16] Content-Length: 757
389D [08/Dec/2017:11:39:03 +0500] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
390D [08/Dec/2017:11:39:03 +0500] [CGI] Regular expression \".*Clean.*\"
391D [08/Dec/2017:11:39:03 +0500] [CGI] matches[0].rm_so=0
392D [08/Dec/2017:11:39:03 +0500] [CGI] matches[1].rm_so=-1
393D [08/Dec/2017:11:39:03 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
394D [08/Dec/2017:11:39:03 +0500] [CGI] matches[0].rm_so=0
395D [08/Dec/2017:11:39:03 +0500] [CGI] matches[1].rm_so=-1
396D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
397D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
398D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
399D [08/Dec/2017:11:39:03 +0500] [Client 16] con->http=0x201ff2c0
400D [08/Dec/2017:11:39:03 +0500] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=757, response=0x201fe1c0(IPP_STATE_DATA), pipe_pid=0, file=-1
401D [08/Dec/2017:11:39:03 +0500] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
402D [08/Dec/2017:11:39:03 +0500] [Client 16] bytes=0, http_state=0, data_remaining=757
403D [08/Dec/2017:11:39:03 +0500] [Client 16] Flushing write buffer.
404D [08/Dec/2017:11:39:03 +0500] [Client 16] New state is HTTP_STATE_WAITING
405D [08/Dec/2017:11:39:03 +0500] [Client 16] Waiting for request.
406D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
407D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
408D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
409D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
410D [08/Dec/2017:11:39:03 +0500] [CGI] cgiClearVariables called.
411D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
412D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
413D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: TOTAL=\"2\"
414D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
415D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
416D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_preserved[0]=\"1\"
417D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_printer_name[0]=\"HP_Color_LaserJet_3800_PS\"
418D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_Color_LaserJet_3800_PS\"
419D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
420D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
421D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
422D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: time_at_creation[0]=\"Thu Dec 7 11:55:05 EST 2017\"
423D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: time_at_processing[0]=\"Thu Dec 7 11:55:05 EST 2017\"
424D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_id[0]=\"8\"
425D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_state[0]=\"6\"
426D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"1\"
427D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
428D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
429D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
430D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
431D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_printer_name[1]=\"HP_Color_LaserJet_3800_PS\"
432D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_printer_uri[1]=\"/printers/HP_Color_LaserJet_3800_PS\"
433D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_name[1]=\"Test Page\"
434D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_originating_user_name[1]=\"anonymous\"
435D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
436D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: time_at_completed[1]=\"novalue\"
437D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: time_at_creation[1]=\"Fri Dec 8 11:39:00 EST 2017\"
438D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: time_at_processing[1]=\"Fri Dec 8 11:39:00 EST 2017\"
439D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_id[1]=\"11\"
440D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_state[1]=\"5\"
441D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_media_sheets_completed[1]=\"1\"
442D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_k_octets[1]=\"1\"
443D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetArray: job_printer_state_message[1]=\"\"
444D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800_PS\"
445D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_LaserJet_3800_PS\"
446D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_LaserJet_3800_PS\"
447D [08/Dec/2017:11:39:03 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_LaserJet_3800_PS\"
448D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
449D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
450D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
451D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
452D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
453D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
454D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
455D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
456D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
457D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
458D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
459D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
460D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
461D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
462D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
463D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
464D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
465D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
466D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
467D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
468D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
469D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
470D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
471D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
472D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
473D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
474D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
475D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
476D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
477D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
478D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
479D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
480D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
481D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
482D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
483D [08/Dec/2017:11:39:03 +0500] [Client 16] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
484D [08/Dec/2017:11:39:03 +0500] [Client 16] Closing connection.
485D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
486D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
487D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
488D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
489D [08/Dec/2017:11:39:03 +0500] PID 169 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
490D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
491D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
492D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
493D [08/Dec/2017:11:39:03 +0500] [Client 12] CGI data ready to be sent.
494D [08/Dec/2017:11:39:03 +0500] [Client 12] con->http=0x201f7140
495D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=169, file=15
496D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for CGI data.
497D [08/Dec/2017:11:39:03 +0500] [Client 12] Sending 0-length chunk.
498D [08/Dec/2017:11:39:03 +0500] [Client 12] Flushing write buffer.
499D [08/Dec/2017:11:39:03 +0500] [Client 12] New state is HTTP_STATE_WAITING
500D [08/Dec/2017:11:39:03 +0500] [Client 12] Waiting for request.
501D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
502D [08/Dec/2017:11:39:03 +0500] [Client 12] GET /cups.css HTTP/1.1
503D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
504D [08/Dec/2017:11:39:03 +0500] [Client 12] Read: status=200
505D [08/Dec/2017:11:39:03 +0500] [Client 12] No authentication data provided.
506D [08/Dec/2017:11:39:03 +0500] [Client 12] Processing GET /cups.css
507D [08/Dec/2017:11:39:03 +0500] [Client 12] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
508D [08/Dec/2017:11:39:03 +0500] [Client 12] cupsdSendHeader: code=304, type="(null)", auth_type=0
509D [08/Dec/2017:11:39:03 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
510D [08/Dec/2017:11:39:05 +0500] [Job 11] Traceback (most recent call last):
511D [08/Dec/2017:11:39:05 +0500] [Job 11] File \"C:/usr/lib/cups/filter/hpps\", line 84, in <module>
512D [08/Dec/2017:11:39:05 +0500] [Job 11] from base.g import *
513D [08/Dec/2017:11:39:05 +0500] [Job 11] File \"/@unixroot/usr/share/hplip/base/g.py\", line 270, in <module>
514D [08/Dec/2017:11:39:05 +0500] [Job 11] prop.username = pwd.getpwuid(os.getuid())[0]
515D [08/Dec/2017:11:39:05 +0500] [Job 11] KeyError: \'getpwuid(): uid not found: 65534\'
516D [08/Dec/2017:11:39:05 +0500] [Job 11] Before page loop - %%Page: 1 1
517D [08/Dec/2017:11:39:05 +0500] [Job 11] Copying page 1...
518D [08/Dec/2017:11:39:05 +0500] [Job 11] pagew = 587.9, pagel = 767.9
519D [08/Dec/2017:11:39:05 +0500] [Job 11] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792
520D [08/Dec/2017:11:39:05 +0500] [Job 11] PageLeft = 12.0, PageRight = 599.9
521D [08/Dec/2017:11:39:05 +0500] [Job 11] PageTop = 780.0, PageBottom = 12.1
522D [08/Dec/2017:11:39:05 +0500] [Job 11] PageWidth = 612.0, PageLength = 792.0
523W [08/Dec/2017:11:39:05 +0500] cupsdDoSelect: select() returned -1... pause and retry select()
524D [08/Dec/2017:11:39:06 +0500] [Job 11] PID 160 (/@unixroot/usr/lib/cups/backend/socket.exe) exited with no errors.
525D [08/Dec/2017:11:39:06 +0500] [Job 11] PID 158 (/@unixroot/usr/lib/cups/filter/hpps) stopped with status 1.
526D [08/Dec/2017:11:39:06 +0500] [Job 11] Wrote 1 pages...
527D [08/Dec/2017:11:39:06 +0500] [Job 11] PID 163 (pdftops) exited with no errors.
528D [08/Dec/2017:11:39:06 +0500] [Job 11] PID 165 (pstops) exited with no errors.
529D [08/Dec/2017:11:39:06 +0500] [Job 11] PID 157 (/@unixroot/usr/lib/cups/filter/pdftops.exe) exited with no errors.
530D [08/Dec/2017:11:39:06 +0500] Discarding unused job-state-changed event...
531E [08/Dec/2017:11:39:06 +0500] [Job 11] Job stopped due to filter errors; please consult the error_log file for details.
532D [08/Dec/2017:11:39:06 +0500] cupsdMarkDirty(---J-)
533D [08/Dec/2017:11:39:06 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
534D [08/Dec/2017:11:39:06 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
535D [08/Dec/2017:11:39:06 +0500] Discarding unused printer-state-changed event...
536D [08/Dec/2017:11:39:06 +0500] cupsdMarkDirty(---J-)
537D [08/Dec/2017:11:39:06 +0500] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
538D [08/Dec/2017:11:39:06 +0500] [Job 11] The following messages were recorded from 11:39:01 am to 11:39:01 am
539D [08/Dec/2017:11:39:06 +0500] [Job 11] hrDeviceDesc=\"HP Color LaserJet 3800\"
540D [08/Dec/2017:11:39:06 +0500] [Job 11] prtMarkerColorantValue.1.1 = \"black\"
541D [08/Dec/2017:11:39:06 +0500] [Job 11] prtMarkerColorantValue.1.2 = \"cyan\"
542D [08/Dec/2017:11:39:06 +0500] [Job 11] prtMarkerColorantValue.1.3 = \"magenta\"
543D [08/Dec/2017:11:39:06 +0500] [Job 11] prtMarkerColorantValue.1.4 = \"yellow\"
544D [08/Dec/2017:11:39:06 +0500] [Job 11] End of messages
545D [08/Dec/2017:11:39:06 +0500] [Job 11] printer-state=3(idle)
546D [08/Dec/2017:11:39:06 +0500] [Job 11] printer-state-message="Filter failed"
547D [08/Dec/2017:11:39:06 +0500] [Job 11] printer-state-reasons=none
548D [08/Dec/2017:11:39:07 +0500] [Job 11] Unloading...
549D [08/Dec/2017:11:39:13 +0500] [Client 12] POST /jobs/ HTTP/1.1
550D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
551D [08/Dec/2017:11:39:13 +0500] [Client 12] Read: status=200
552D [08/Dec/2017:11:39:13 +0500] [Client 12] No authentication data provided.
553D [08/Dec/2017:11:39:13 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi"
554D [08/Dec/2017:11:39:13 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
555D [08/Dec/2017:11:39:13 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
556D [08/Dec/2017:11:39:13 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
557D [08/Dec/2017:11:39:13 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
558D [08/Dec/2017:11:39:13 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
559D [08/Dec/2017:11:39:13 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
560D [08/Dec/2017:11:39:13 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
561D [08/Dec/2017:11:39:13 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
562D [08/Dec/2017:11:39:13 +0500] [CGI] envp[8] = "HOME=/@unixroot/var/spool/cups/tmp"
563D [08/Dec/2017:11:39:13 +0500] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
564D [08/Dec/2017:11:39:13 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
565D [08/Dec/2017:11:39:13 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@bluelion"
566D [08/Dec/2017:11:39:13 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
567D [08/Dec/2017:11:39:13 +0500] [CGI] envp[13] = "TMPDIR=/@unixroot/var/spool/cups/tmp"
568D [08/Dec/2017:11:39:13 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
569D [08/Dec/2017:11:39:13 +0500] [CGI] envp[15] = "USER=root"
570D [08/Dec/2017:11:39:13 +0500] [CGI] envp[16] = "UNIXROOT=C:"
571D [08/Dec/2017:11:39:13 +0500] [CGI] envp[17] = "ETC=C:\\MPTN\\ETC"
572D [08/Dec/2017:11:39:13 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
573D [08/Dec/2017:11:39:13 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
574D [08/Dec/2017:11:39:13 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
575D [08/Dec/2017:11:39:13 +0500] [CGI] envp[21] = "IPP_PORT=631"
576D [08/Dec/2017:11:39:13 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
577D [08/Dec/2017:11:39:13 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
578D [08/Dec/2017:11:39:13 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
579D [08/Dec/2017:11:39:13 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
580D [08/Dec/2017:11:39:13 +0500] [CGI] envp[26] = "SERVER_PORT=631"
581D [08/Dec/2017:11:39:13 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
582D [08/Dec/2017:11:39:13 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
583D [08/Dec/2017:11:39:13 +0500] [CGI] envp[29] = "SCRIPT_NAME=/jobs/"
584D [08/Dec/2017:11:39:13 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/jobs/"
585D [08/Dec/2017:11:39:13 +0500] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
586D [08/Dec/2017:11:39:13 +0500] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=41f45aede00677dfbe5c986711944887"
587D [08/Dec/2017:11:39:13 +0500] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
588D [08/Dec/2017:11:39:13 +0500] [CGI] envp[34] = "HTTP_REFERER=http://localhost:631/printers/HP_Color_LaserJet_3800_PS"
589D [08/Dec/2017:11:39:13 +0500] [CGI] envp[35] = "REQUEST_METHOD=POST"
590D [08/Dec/2017:11:39:13 +0500] [CGI] envp[36] = "CONTENT_LENGTH=124"
591D [08/Dec/2017:11:39:13 +0500] [CGI] envp[37] = "CONTENT_TYPE=application/x-www-form-urlencoded"
592D [08/Dec/2017:11:39:13 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/jobs.cgi (PID 171)
593I [08/Dec/2017:11:39:13 +0500] [Client 12] Started "/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi" (pid=171, file=16)
594D [08/Dec/2017:11:39:13 +0500] [Client 12] Waiting for CGI data.
595D [08/Dec/2017:11:39:13 +0500] [Client 17] Accepted from localhost (Domain)
596D [08/Dec/2017:11:39:13 +0500] [Client 17] Waiting for request.
597D [08/Dec/2017:11:39:13 +0500] [CGI] org.cups.sid cookie is \"41f45aede00677dfbe5c986711944887\"
598D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: org.cups.sid=\"41f45aede00677dfbe5c986711944887\"
599D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: OP=\"cancel-job\"
600D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: job_id=\"8\"
601D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: job_printer_uri=\"/printers/HP_Color_LaserJet_3800_PS\"
602D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: SECTION=\"jobs\"
603D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
604D [08/Dec/2017:11:39:13 +0500] [Client 17] POST /jobs HTTP/1.1
605D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
606D [08/Dec/2017:11:39:13 +0500] [Client 17] Read: status=200
607D [08/Dec/2017:11:39:13 +0500] [Client 17] No authentication data provided.
608D [08/Dec/2017:11:39:13 +0500] [Client 17] 2.0 Cancel-Job 1
609D [08/Dec/2017:11:39:13 +0500] Cancel-Job ipp://localhost/jobs/8
610D [08/Dec/2017:11:39:13 +0500] cupsdIsAuthorized: requesting-user-name="guest"
611D [08/Dec/2017:11:39:13 +0500] [Client 17] Returning HTTP Unauthorized for Cancel-Job (ipp://localhost/jobs/8) from localhost
612D [08/Dec/2017:11:39:13 +0500] [Client 17] cupsdSendHeader: code=401, type="text/html", auth_type=0
613D [08/Dec/2017:11:39:13 +0500] [Client 17] WWW-Authenticate: Basic realm=\"CUPS\", trc=\"y\"
614D [08/Dec/2017:11:39:13 +0500] [Client 18] Accepted from localhost (Domain)
615D [08/Dec/2017:11:39:13 +0500] [Client 18] Waiting for request.
616D [08/Dec/2017:11:39:13 +0500] [Client 17] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
617D [08/Dec/2017:11:39:13 +0500] [Client 17] Closing connection.
618D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
619D [08/Dec/2017:11:39:13 +0500] [Client 19] Accepted from localhost (Domain)
620D [08/Dec/2017:11:39:13 +0500] [Client 19] Waiting for request.
621D [08/Dec/2017:11:39:13 +0500] [Client 18] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
622D [08/Dec/2017:11:39:13 +0500] [Client 18] Closing connection.
623D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
624D [08/Dec/2017:11:39:13 +0500] [Client 20] Accepted from localhost (Domain)
625D [08/Dec/2017:11:39:13 +0500] [Client 20] Waiting for request.
626D [08/Dec/2017:11:39:13 +0500] [Client 19] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
627D [08/Dec/2017:11:39:13 +0500] [Client 19] Closing connection.
628D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
629D [08/Dec/2017:11:39:13 +0500] [Client 20] POST /jobs HTTP/1.1
630D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
631D [08/Dec/2017:11:39:13 +0500] [Client 20] Read: status=200
632D [08/Dec/2017:11:39:13 +0500] [Client 20] Authorized as root using Local.
633D [08/Dec/2017:11:39:13 +0500] [Client 20] 2.0 Cancel-Job 1
634D [08/Dec/2017:11:39:13 +0500] Cancel-Job ipp://localhost/jobs/8
635D [08/Dec/2017:11:39:13 +0500] cupsdIsAuthorized: username="root"
636D [08/Dec/2017:11:39:13 +0500] [Job 8] time-at-completed=1512751153
637D [08/Dec/2017:11:39:13 +0500] Discarding unused job-completed event...
638I [08/Dec/2017:11:39:13 +0500] [Job 8] Job canceled by \"root\"
639I [08/Dec/2017:11:39:13 +0500] Expiring subscriptions...
640D [08/Dec/2017:11:39:13 +0500] cupsdMarkDirty(---J-)
641D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
642D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
643I [08/Dec/2017:11:39:13 +0500] [Job 8] Canceled by "root".
644D [08/Dec/2017:11:39:13 +0500] [Client 20] Returning IPP successful-ok for Cancel-Job (ipp://localhost/jobs/8) from localhost
645D [08/Dec/2017:11:39:13 +0500] [Client 20] Content-Length: 75
646D [08/Dec/2017:11:39:13 +0500] [Client 20] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
647D [08/Dec/2017:11:39:13 +0500] [Job 8] Removing document files.
648D [08/Dec/2017:11:39:13 +0500] cupsdMarkDirty(---J-)
649D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
650D [08/Dec/2017:11:39:13 +0500] [Client 20] con->http=0x20202320
651D [08/Dec/2017:11:39:13 +0500] [Client 20] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x2011f340(IPP_STATE_DATA), pipe_pid=0, file=-1
652D [08/Dec/2017:11:39:13 +0500] [Client 20] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
653D [08/Dec/2017:11:39:13 +0500] [Client 20] bytes=0, http_state=0, data_remaining=75
654D [08/Dec/2017:11:39:13 +0500] [Client 20] Flushing write buffer.
655D [08/Dec/2017:11:39:13 +0500] [Client 20] New state is HTTP_STATE_WAITING
656D [08/Dec/2017:11:39:13 +0500] [Client 20] Waiting for request.
657D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
658D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: refresh_page=\"5;URL=http://localhost:631/printers/HP_Color_LaserJet_3800_PS\"
659D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: TITLE=\"Jobs\"
660D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
661D [08/Dec/2017:11:39:13 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
662D [08/Dec/2017:11:39:13 +0500] [Client 12] CGI data ready to be sent.
663D [08/Dec/2017:11:39:13 +0500] [Client 20] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
664D [08/Dec/2017:11:39:13 +0500] [Client 20] Closing connection.
665D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
666D [08/Dec/2017:11:39:13 +0500] [Client 12] con->http=0x201f7140
667D [08/Dec/2017:11:39:13 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=171, file=16
668D [08/Dec/2017:11:39:13 +0500] [Client 12] Waiting for CGI data.
669D [08/Dec/2017:11:39:13 +0500] [Client 12] Script header: Content-Type: text/html;charset=utf-8
670D [08/Dec/2017:11:39:13 +0500] [Client 12] Script header:
671D [08/Dec/2017:11:39:13 +0500] [Client 12] Sending status 200 for CGI.
672D [08/Dec/2017:11:39:13 +0500] [Client 12] cupsdSendHeader: code=200, type="(null)", auth_type=0
673D [08/Dec/2017:11:39:13 +0500] [Client 12] con->http=0x201f7140
674D [08/Dec/2017:11:39:13 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=171, file=16
675D [08/Dec/2017:11:39:13 +0500] [Client 12] Waiting for CGI data.
676D [08/Dec/2017:11:39:13 +0500] [Client 12] CGI data ready to be sent.
677D [08/Dec/2017:11:39:13 +0500] [Client 12] con->http=0x201f7140
678D [08/Dec/2017:11:39:13 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=171, file=16
679D [08/Dec/2017:11:39:13 +0500] [Client 12] Waiting for CGI data.
680D [08/Dec/2017:11:39:13 +0500] [Client 12] Sending 0-length chunk.
681D [08/Dec/2017:11:39:13 +0500] [Client 12] Flushing write buffer.
682D [08/Dec/2017:11:39:13 +0500] [Client 12] New state is HTTP_STATE_WAITING
683D [08/Dec/2017:11:39:13 +0500] [Client 12] Waiting for request.
684D [08/Dec/2017:11:39:13 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
685D [08/Dec/2017:11:39:13 +0500] PID 171 (/@unixroot/usr/lib/cups/cgi-bin/jobs.cgi) exited with no errors.
686D [08/Dec/2017:11:39:18 +0500] [Client 21] Accepted from localhost:56550 (IPv4)
687D [08/Dec/2017:11:39:18 +0500] [Client 21] Waiting for request.
688D [08/Dec/2017:11:39:18 +0500] [Client 12] GET /printers/HP_Color_LaserJet_3800_PS HTTP/1.1
689D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
690D [08/Dec/2017:11:39:18 +0500] [Client 12] Read: status=200
691D [08/Dec/2017:11:39:18 +0500] [Client 12] No authentication data provided.
692D [08/Dec/2017:11:39:18 +0500] [Client 12] Processing GET /printers/HP_Color_LaserJet_3800_PS
693D [08/Dec/2017:11:39:18 +0500] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
694D [08/Dec/2017:11:39:18 +0500] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
695D [08/Dec/2017:11:39:18 +0500] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
696D [08/Dec/2017:11:39:18 +0500] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
697D [08/Dec/2017:11:39:18 +0500] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
698D [08/Dec/2017:11:39:18 +0500] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
699D [08/Dec/2017:11:39:18 +0500] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
700D [08/Dec/2017:11:39:18 +0500] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
701D [08/Dec/2017:11:39:18 +0500] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
702D [08/Dec/2017:11:39:18 +0500] [CGI] envp[8] = "HOME=/@unixroot/var/spool/cups/tmp"
703D [08/Dec/2017:11:39:18 +0500] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
704D [08/Dec/2017:11:39:18 +0500] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
705D [08/Dec/2017:11:39:18 +0500] [CGI] envp[11] = "SERVER_ADMIN=root@bluelion"
706D [08/Dec/2017:11:39:18 +0500] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
707D [08/Dec/2017:11:39:18 +0500] [CGI] envp[13] = "TMPDIR=/@unixroot/var/spool/cups/tmp"
708D [08/Dec/2017:11:39:18 +0500] [CGI] envp[14] = "TZ=EST5EDT,3,2,0,7200,11,1,0,7200,3600"
709D [08/Dec/2017:11:39:18 +0500] [CGI] envp[15] = "USER=root"
710D [08/Dec/2017:11:39:18 +0500] [CGI] envp[16] = "UNIXROOT=C:"
711D [08/Dec/2017:11:39:18 +0500] [CGI] envp[17] = "ETC=C:\\MPTN\\ETC"
712D [08/Dec/2017:11:39:18 +0500] [CGI] envp[18] = "CUPS_MAX_MESSAGE=2047"
713D [08/Dec/2017:11:39:18 +0500] [CGI] envp[19] = "CUPS_SERVER=\\socket\\cups.sock"
714D [08/Dec/2017:11:39:18 +0500] [CGI] envp[20] = "CUPS_ENCRYPTION=IfRequested"
715D [08/Dec/2017:11:39:18 +0500] [CGI] envp[21] = "IPP_PORT=631"
716D [08/Dec/2017:11:39:18 +0500] [CGI] envp[22] = "LANG=en_US.UTF8"
717D [08/Dec/2017:11:39:18 +0500] [CGI] envp[23] = "REDIRECT_STATUS=1"
718D [08/Dec/2017:11:39:18 +0500] [CGI] envp[24] = "GATEWAY_INTERFACE=CGI/1.1"
719D [08/Dec/2017:11:39:18 +0500] [CGI] envp[25] = "SERVER_NAME=localhost"
720D [08/Dec/2017:11:39:18 +0500] [CGI] envp[26] = "SERVER_PORT=631"
721D [08/Dec/2017:11:39:18 +0500] [CGI] envp[27] = "REMOTE_ADDR=127.0.0.1"
722D [08/Dec/2017:11:39:18 +0500] [CGI] envp[28] = "REMOTE_HOST=localhost"
723D [08/Dec/2017:11:39:18 +0500] [CGI] envp[29] = "SCRIPT_NAME=/printers/HP_Color_LaserJet_3800_PS"
724D [08/Dec/2017:11:39:18 +0500] [CGI] envp[30] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HP_Color_LaserJet_3800_PS"
725D [08/Dec/2017:11:39:18 +0500] [CGI] envp[31] = "PATH_INFO=/HP_Color_LaserJet_3800_PS"
726D [08/Dec/2017:11:39:18 +0500] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
727D [08/Dec/2017:11:39:18 +0500] [CGI] envp[33] = "HTTP_COOKIE=org.cups.sid=41f45aede00677dfbe5c986711944887"
728D [08/Dec/2017:11:39:18 +0500] [CGI] envp[34] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
729D [08/Dec/2017:11:39:18 +0500] [CGI] envp[35] = "REQUEST_METHOD=GET"
730D [08/Dec/2017:11:39:18 +0500] [CGI] envp[36] = "QUERY_STRING="
731D [08/Dec/2017:11:39:18 +0500] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 173)
732I [08/Dec/2017:11:39:18 +0500] [Client 12] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=173, file=16)
733D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
734D [08/Dec/2017:11:39:18 +0500] [CGI] org.cups.sid cookie is \"41f45aede00677dfbe5c986711944887\"
735D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
736D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
737D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800_PS\"
738D [08/Dec/2017:11:39:18 +0500] [Client 22] Accepted from localhost (Domain)
739D [08/Dec/2017:11:39:18 +0500] [Client 22] Waiting for request.
740D [08/Dec/2017:11:39:18 +0500] [Client 22] POST / HTTP/1.1
741D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
742D [08/Dec/2017:11:39:18 +0500] [Client 22] Read: status=200
743D [08/Dec/2017:11:39:18 +0500] [Client 22] No authentication data provided.
744D [08/Dec/2017:11:39:18 +0500] [Client 22] 2.0 CUPS-Get-Default 1
745D [08/Dec/2017:11:39:18 +0500] CUPS-Get-Default
746D [08/Dec/2017:11:39:18 +0500] CUPS-Get-Default client-error-not-found: No default printer.
747D [08/Dec/2017:11:39:18 +0500] [Client 22] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
748D [08/Dec/2017:11:39:18 +0500] [Client 22] Content-Length: 113
749D [08/Dec/2017:11:39:18 +0500] [Client 22] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
750D [08/Dec/2017:11:39:18 +0500] [Client 22] con->http=0x20202320
751D [08/Dec/2017:11:39:18 +0500] [Client 22] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x2011f380(IPP_STATE_DATA), pipe_pid=0, file=-1
752D [08/Dec/2017:11:39:18 +0500] [Client 22] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
753D [08/Dec/2017:11:39:18 +0500] [Client 22] bytes=0, http_state=0, data_remaining=113
754D [08/Dec/2017:11:39:18 +0500] [Client 22] Flushing write buffer.
755D [08/Dec/2017:11:39:18 +0500] [Client 22] New state is HTTP_STATE_WAITING
756D [08/Dec/2017:11:39:18 +0500] [Client 22] Waiting for request.
757D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
758D [08/Dec/2017:11:39:18 +0500] [CGI] show_printer(http=0x2003c3c0, printer=\"HP_Color_LaserJet_3800_PS\")
759D [08/Dec/2017:11:39:18 +0500] [Client 22] POST / HTTP/1.1
760D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
761D [08/Dec/2017:11:39:18 +0500] [Client 22] Read: status=200
762D [08/Dec/2017:11:39:18 +0500] [Client 22] No authentication data provided.
763D [08/Dec/2017:11:39:18 +0500] [Client 22] 2.0 Get-Printer-Attributes 2
764D [08/Dec/2017:11:39:18 +0500] Get-Printer-Attributes ipp://localhost/printers/HP_Color_LaserJet_3800_PS
765D [08/Dec/2017:11:39:18 +0500] [Client 22] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Color_LaserJet_3800_PS) from localhost
766D [08/Dec/2017:11:39:18 +0500] [Client 22] Content-Length: 698
767D [08/Dec/2017:11:39:18 +0500] [Client 22] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
768D [08/Dec/2017:11:39:18 +0500] [Client 22] con->http=0x20202320
769D [08/Dec/2017:11:39:18 +0500] [Client 22] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=698, response=0x2005c760(IPP_STATE_DATA), pipe_pid=0, file=-1
770D [08/Dec/2017:11:39:18 +0500] [Client 22] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
771D [08/Dec/2017:11:39:18 +0500] [Client 22] bytes=0, http_state=0, data_remaining=698
772D [08/Dec/2017:11:39:18 +0500] [Client 22] Flushing write buffer.
773D [08/Dec/2017:11:39:18 +0500] [Client 22] New state is HTTP_STATE_WAITING
774D [08/Dec/2017:11:39:18 +0500] [Client 22] Waiting for request.
775D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
776D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
777D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
778D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
779D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
780D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
781D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_is_shared[0]=\"1\"
782D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_state[0]=\"3\"
783D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
784D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HP_Color_LaserJet_3800_PS\"
785D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_name[0]=\"HP_Color_LaserJet_3800_PS\"
786D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_location[0]=\"office\"
787D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_info[0]=\"HP Color LaserJet 3800 PS\"
788D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
789D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: device_uri[0]=\"socket://192.168.100.16\"
790D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: color_supported[0]=\"1\"
791D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP Color LaserJet 3800 Postscript (recommended)\"
792D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
793D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: sides_supported[0]=\"one-sided\"
794D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
795D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
796D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
797D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: TITLE=\"HP_Color_LaserJet_3800_PS\"
798D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
799D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
800D [08/Dec/2017:11:39:18 +0500] [Client 12] CGI data ready to be sent.
801D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
802D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=173, file=16
803D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
804D [08/Dec/2017:11:39:18 +0500] [Client 12] Script header: Content-Type: text/html;charset=utf-8
805D [08/Dec/2017:11:39:18 +0500] [Client 12] Script header:
806D [08/Dec/2017:11:39:18 +0500] [Client 12] Sending status 200 for CGI.
807D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdSendHeader: code=200, type="(null)", auth_type=0
808D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
809D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
810D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
811D [08/Dec/2017:11:39:18 +0500] [Client 12] CGI data ready to be sent.
812D [08/Dec/2017:11:39:18 +0500] [Client 22] POST / HTTP/1.1
813D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
814D [08/Dec/2017:11:39:18 +0500] [Client 22] Read: status=200
815D [08/Dec/2017:11:39:18 +0500] [Client 22] No authentication data provided.
816D [08/Dec/2017:11:39:18 +0500] [Client 22] 2.0 Get-Jobs 3
817D [08/Dec/2017:11:39:18 +0500] Get-Jobs ipp://localhost:631/printers/HP_Color_LaserJet_3800_PS
818D [08/Dec/2017:11:39:18 +0500] [Job 11] Loading attributes...
819D [08/Dec/2017:11:39:18 +0500] [Client 22] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HP_Color_LaserJet_3800_PS) from localhost
820D [08/Dec/2017:11:39:18 +0500] [Client 22] Content-Length: 432
821D [08/Dec/2017:11:39:18 +0500] [Client 22] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
822D [08/Dec/2017:11:39:18 +0500] [CGI] Regular expression \".*Clean.*\"
823D [08/Dec/2017:11:39:18 +0500] [CGI] matches[0].rm_so=0
824D [08/Dec/2017:11:39:18 +0500] [CGI] matches[1].rm_so=-1
825D [08/Dec/2017:11:39:18 +0500] [CGI] Regular expression \".*PrintSelfTestPage.*\"
826D [08/Dec/2017:11:39:18 +0500] [CGI] matches[0].rm_so=0
827D [08/Dec/2017:11:39:18 +0500] [CGI] matches[1].rm_so=-1
828D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
829D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
830D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
831D [08/Dec/2017:11:39:18 +0500] [Client 22] con->http=0x20202320
832D [08/Dec/2017:11:39:18 +0500] [Client 22] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=432, response=0x201fecc0(IPP_STATE_DATA), pipe_pid=0, file=-1
833D [08/Dec/2017:11:39:18 +0500] [Client 22] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
834D [08/Dec/2017:11:39:18 +0500] [Client 22] bytes=0, http_state=0, data_remaining=432
835D [08/Dec/2017:11:39:18 +0500] [Client 22] Flushing write buffer.
836D [08/Dec/2017:11:39:18 +0500] [Client 22] New state is HTTP_STATE_WAITING
837D [08/Dec/2017:11:39:18 +0500] [Client 22] Waiting for request.
838D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
839D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
840D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
841D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
842D [08/Dec/2017:11:39:18 +0500] [CGI] cgiClearVariables called.
843D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: ORDER=\"asc\"
844D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: SECTION=\"printers\"
845D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: TOTAL=\"1\"
846D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
847D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
848D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_preserved[0]=\"1\"
849D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_printer_name[0]=\"HP_Color_LaserJet_3800_PS\"
850D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HP_Color_LaserJet_3800_PS\"
851D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_name[0]=\"Test Page\"
852D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_originating_user_name[0]=\"anonymous\"
853D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
854D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: time_at_creation[0]=\"Fri Dec 8 11:39:00 EST 2017\"
855D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: time_at_processing[0]=\"Fri Dec 8 11:39:00 EST 2017\"
856D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_id[0]=\"11\"
857D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_state[0]=\"6\"
858D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"1\"
859D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
860D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetArray: job_printer_state_message[0]=\"Filter failed\"
861D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: PRINTER_NAME=\"HP_Color_LaserJet_3800_PS\"
862D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HP_Color_LaserJet_3800_PS\"
863D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: THISURL=\"/printers/HP_Color_LaserJet_3800_PS\"
864D [08/Dec/2017:11:39:18 +0500] [CGI] cgiSetVariable: SEARCH_DEST=\"HP_Color_LaserJet_3800_PS\"
865D [08/Dec/2017:11:39:18 +0500] [Client 12] CGI data ready to be sent.
866D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
867D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
868D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
869D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
870D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
871D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
872D [08/Dec/2017:11:39:18 +0500] [Client 12] CGI data ready to be sent.
873D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
874D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
875D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
876D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
877D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
878D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
879D [08/Dec/2017:11:39:18 +0500] [Client 12] CGI data ready to be sent.
880D [08/Dec/2017:11:39:18 +0500] [Client 22] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
881D [08/Dec/2017:11:39:18 +0500] [Client 22] Closing connection.
882D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
883D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
884D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
885D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
886D [08/Dec/2017:11:39:18 +0500] PID 173 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
887D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
888D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
889D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
890D [08/Dec/2017:11:39:18 +0500] [Client 12] CGI data ready to be sent.
891D [08/Dec/2017:11:39:18 +0500] [Client 12] con->http=0x201f7140
892D [08/Dec/2017:11:39:18 +0500] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=173, file=16
893D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for CGI data.
894D [08/Dec/2017:11:39:18 +0500] [Client 12] Sending 0-length chunk.
895D [08/Dec/2017:11:39:18 +0500] [Client 12] Flushing write buffer.
896D [08/Dec/2017:11:39:18 +0500] [Client 12] New state is HTTP_STATE_WAITING
897D [08/Dec/2017:11:39:18 +0500] [Client 12] Waiting for request.
898D [08/Dec/2017:11:39:18 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
899D [08/Dec/2017:11:39:24 +0500] [Client 21] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
900D [08/Dec/2017:11:39:24 +0500] [Client 21] Closing connection.
901D [08/Dec/2017:11:39:24 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
902D [08/Dec/2017:11:39:29 +0500] [Client 12] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
903D [08/Dec/2017:11:39:29 +0500] [Client 12] Closing connection.
904D [08/Dec/2017:11:39:29 +0500] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
905I [08/Dec/2017:11:39:30 +0500] Saving printers.conf...
906I [08/Dec/2017:11:39:30 +0500] Saving job.cache...
907D [08/Dec/2017:11:39:30 +0500] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"