D [12/Aug/2010:17:15:34 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:34 +0900] Report: clients=1
D [12/Aug/2010:17:15:34 +0900] Report: jobs=5
D [12/Aug/2010:17:15:34 +0900] Report: jobs-active=0
D [12/Aug/2010:17:15:34 +0900] Report: printers=1
D [12/Aug/2010:17:15:34 +0900] Report: printers-implicit=0
D [12/Aug/2010:17:15:34 +0900] Report: stringpool-string-count=544
D [12/Aug/2010:17:15:34 +0900] Report: stringpool-alloc-bytes=8064
D [12/Aug/2010:17:15:34 +0900] Report: stringpool-total-bytes=11872
D [12/Aug/2010:17:15:34 +0900] cupsdReadClient: 13 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:34 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:34 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:15:34 +0900] cupsdReadClient: 13 1.1 CUPS-Delete-Printer 1
D [12/Aug/2010:17:15:34 +0900] CUPS-Delete-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:34 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:15:34 +0900] Returning HTTP Unauthorized for CUPS-Delete-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:34 +0900] cupsdSendHeader: 13 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:15:34 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:34 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:34 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:34 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:34 +0900] cupsdAcceptClient: 14 from localhost (Domain)
D [12/Aug/2010:17:15:34 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:34 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:34 +0900] cupsdReadClient: 14 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:34 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:34 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:34 +0900] cupsdReadClient: 14 1.1 CUPS-Delete-Printer 1
D [12/Aug/2010:17:15:34 +0900] CUPS-Delete-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:34 +0900] cupsdIsAuthorized: username="root"
D [12/Aug/2010:17:15:34 +0900] [Job 16] Loading attributes...
D [12/Aug/2010:17:15:34 +0900] Discarding unused job-completed event...
I [12/Aug/2010:17:15:34 +0900] [Job 16] Job purged by user.
D [12/Aug/2010:17:15:34 +0900] [Job 16] Unloading...
D [12/Aug/2010:17:15:34 +0900] [Job 17] Loading attributes...
D [12/Aug/2010:17:15:34 +0900] Discarding unused job-completed event...
I [12/Aug/2010:17:15:34 +0900] [Job 17] Job purged by user.
D [12/Aug/2010:17:15:34 +0900] [Job 17] Unloading...
D [12/Aug/2010:17:15:34 +0900] [Job 18] Loading attributes...
D [12/Aug/2010:17:15:34 +0900] Discarding unused job-completed event...
I [12/Aug/2010:17:15:34 +0900] [Job 18] Job purged by user.
D [12/Aug/2010:17:15:34 +0900] [Job 18] Unloading...
D [12/Aug/2010:17:15:34 +0900] Discarding unused printer-deleted event...
I [12/Aug/2010:17:15:34 +0900] Printer "MFC695CDN" deleted by "root".
D [12/Aug/2010:17:15:34 +0900] Discarding unused printer-stopped event...
D [12/Aug/2010:17:15:34 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:34 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:15:34 +0900] cupsdDeregisterPrinter(p=0x7fa6f1b7e290(MFC695CDN), removeit=1)
D [12/Aug/2010:17:15:34 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:34 +0900] cupsdMarkDirty(---p--)
D [12/Aug/2010:17:15:34 +0900] Returning IPP successful-ok for CUPS-Delete-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:34 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:15:34 +0900] cupsdReadClient: 14 WAITING Closing on EOF
D [12/Aug/2010:17:15:34 +0900] cupsdCloseClient: 14
I [12/Aug/2010:17:15:34 +0900] Scheduler shutting down normally.
D [12/Aug/2010:17:15:34 +0900] Discarding unused server-stopped event...
I [12/Aug/2010:17:15:34 +0900] Saving printers.conf...
I [12/Aug/2010:17:15:34 +0900] Generating printcap /etc/printcap...
D [12/Aug/2010:17:15:34 +0900] cupsdSetBusyState: Not busy
I [12/Aug/2010:17:15:34 +0900] Saving job cache file "/var/cache/cups/job.cache"...
I [12/Aug/2010:17:15:34 +0900] Listening to ::1:631 (IPv6)
I [12/Aug/2010:17:15:34 +0900] Listening to 127.0.0.1:631 (IPv4)
I [12/Aug/2010:17:15:34 +0900] Listening to /var/run/cups/cups.sock (Domain)
I [12/Aug/2010:17:15:34 +0900] Remote access is disabled.
D [12/Aug/2010:17:15:34 +0900] Added auto ServerAlias nemesis
I [12/Aug/2010:17:15:34 +0900] Loaded configuration file "/etc/cups/cupsd.conf"
I [12/Aug/2010:17:15:34 +0900] Using default TempDir of /var/spool/cups/tmp...
I [12/Aug/2010:17:15:34 +0900] Configured for up to 100 clients.
I [12/Aug/2010:17:15:34 +0900] Allowing up to 100 client connections per host.
I [12/Aug/2010:17:15:34 +0900] Full reload is required.
I [12/Aug/2010:17:15:34 +0900] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 35 types, 45 filters...
I [12/Aug/2010:17:15:34 +0900] Loading job cache file "/var/cache/cups/job.cache"...
D [12/Aug/2010:17:15:34 +0900] [Job 2] Loading from cache...
D [12/Aug/2010:17:15:34 +0900] [Job 3] Loading from cache...
I [12/Aug/2010:17:15:34 +0900] Full reload complete.
D [12/Aug/2010:17:15:34 +0900] cupsd_clean_files(path="/var/spool/cups/tmp", pattern="(null)")
I [12/Aug/2010:17:15:34 +0900] Cleaning out old files in "/var/spool/cups/tmp"...
D [12/Aug/2010:17:15:34 +0900] Removed "/var/spool/cups/tmp/gs_eJzxwf"...
D [12/Aug/2010:17:15:34 +0900] Removed "/var/spool/cups/tmp/gs_20zkK0"...
D [12/Aug/2010:17:15:34 +0900] Removed "/var/spool/cups/tmp/gs_tV0omd"...
D [12/Aug/2010:17:15:34 +0900] Removed "/var/spool/cups/tmp/gs_lw2OUU"...
D [12/Aug/2010:17:15:34 +0900] Removed "/var/spool/cups/tmp/gs_XdI7Fg"...
D [12/Aug/2010:17:15:34 +0900] Removed "/var/spool/cups/tmp/gs_DugvU9"...
D [12/Aug/2010:17:15:34 +0900] cupsd_clean_files(path="/var/cache/cups", pattern="*.ipp")
I [12/Aug/2010:17:15:34 +0900] Cleaning out old files in "/var/cache/cups"...
I [12/Aug/2010:17:15:34 +0900] Listening to ::1:631 on fd 4...
I [12/Aug/2010:17:15:34 +0900] Listening to 127.0.0.1:631 on fd 6...
I [12/Aug/2010:17:15:34 +0900] Listening to /var/run/cups/cups.sock on fd 7...
I [12/Aug/2010:17:15:34 +0900] Resuming new connection processing...
D [12/Aug/2010:17:15:34 +0900] Discarding unused server-started event...
I [12/Aug/2010:17:15:34 +0900] Scheduler shutting down normally.
D [12/Aug/2010:17:15:34 +0900] Discarding unused server-stopped event...
I [12/Aug/2010:17:15:34 +0900] Saving job cache file "/var/cache/cups/job.cache"...
I [12/Aug/2010:17:15:34 +0900] Listening to ::1:631 (IPv6)
I [12/Aug/2010:17:15:34 +0900] Listening to 127.0.0.1:631 (IPv4)
I [12/Aug/2010:17:15:34 +0900] Listening to /var/run/cups/cups.sock (Domain)
I [12/Aug/2010:17:15:34 +0900] Remote access is disabled.
D [12/Aug/2010:17:15:34 +0900] Added auto ServerAlias nemesis
I [12/Aug/2010:17:15:34 +0900] Loaded configuration file "/etc/cups/cupsd.conf"
I [12/Aug/2010:17:15:34 +0900] Using default TempDir of /var/spool/cups/tmp...
I [12/Aug/2010:17:15:34 +0900] Configured for up to 100 clients.
I [12/Aug/2010:17:15:34 +0900] Allowing up to 100 client connections per host.
I [12/Aug/2010:17:15:34 +0900] Full reload is required.
I [12/Aug/2010:17:15:34 +0900] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 35 types, 45 filters...
I [12/Aug/2010:17:15:34 +0900] Loading job cache file "/var/cache/cups/job.cache"...
D [12/Aug/2010:17:15:34 +0900] [Job 2] Loading from cache...
D [12/Aug/2010:17:15:34 +0900] [Job 3] Loading from cache...
I [12/Aug/2010:17:15:34 +0900] Full reload complete.
D [12/Aug/2010:17:15:34 +0900] cupsd_clean_files(path="/var/spool/cups/tmp", pattern="(null)")
I [12/Aug/2010:17:15:34 +0900] Cleaning out old files in "/var/spool/cups/tmp"...
D [12/Aug/2010:17:15:34 +0900] cupsd_clean_files(path="/var/cache/cups", pattern="*.ipp")
I [12/Aug/2010:17:15:34 +0900] Cleaning out old files in "/var/cache/cups"...
I [12/Aug/2010:17:15:34 +0900] Listening to ::1:631 on fd 4...
I [12/Aug/2010:17:15:34 +0900] Listening to 127.0.0.1:631 on fd 6...
I [12/Aug/2010:17:15:34 +0900] Listening to /var/run/cups/cups.sock on fd 7...
I [12/Aug/2010:17:15:34 +0900] Resuming new connection processing...
D [12/Aug/2010:17:15:34 +0900] Discarding unused server-started event...
D [12/Aug/2010:17:15:35 +0900] Report: clients=0
D [12/Aug/2010:17:15:35 +0900] Report: jobs=2
D [12/Aug/2010:17:15:35 +0900] Report: jobs-active=0
D [12/Aug/2010:17:15:35 +0900] Report: printers=0
D [12/Aug/2010:17:15:35 +0900] Report: printers-implicit=0
D [12/Aug/2010:17:15:35 +0900] Report: stringpool-string-count=129
D [12/Aug/2010:17:15:35 +0900] Report: stringpool-alloc-bytes=4064
D [12/Aug/2010:17:15:35 +0900] Report: stringpool-total-bytes=3096
I [12/Aug/2010:17:15:50 +0900] Scheduler shutting down normally.
D [12/Aug/2010:17:15:50 +0900] Discarding unused server-stopped event...
I [12/Aug/2010:17:15:50 +0900] Saving job cache file "/var/cache/cups/job.cache"...
I [12/Aug/2010:17:15:50 +0900] Listening to ::1:631 (IPv6)
I [12/Aug/2010:17:15:50 +0900] Listening to 127.0.0.1:631 (IPv4)
I [12/Aug/2010:17:15:50 +0900] Listening to /var/run/cups/cups.sock (Domain)
I [12/Aug/2010:17:15:50 +0900] Remote access is disabled.
D [12/Aug/2010:17:15:50 +0900] Added auto ServerAlias nemesis
I [12/Aug/2010:17:15:50 +0900] Loaded configuration file "/etc/cups/cupsd.conf"
I [12/Aug/2010:17:15:50 +0900] Using default TempDir of /var/spool/cups/tmp...
I [12/Aug/2010:17:15:50 +0900] Configured for up to 100 clients.
I [12/Aug/2010:17:15:50 +0900] Allowing up to 100 client connections per host.
I [12/Aug/2010:17:15:50 +0900] Full reload is required.
I [12/Aug/2010:17:15:50 +0900] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 35 types, 45 filters...
I [12/Aug/2010:17:15:50 +0900] Loading job cache file "/var/cache/cups/job.cache"...
D [12/Aug/2010:17:15:50 +0900] [Job 2] Loading from cache...
D [12/Aug/2010:17:15:50 +0900] [Job 3] Loading from cache...
I [12/Aug/2010:17:15:50 +0900] Full reload complete.
D [12/Aug/2010:17:15:50 +0900] cupsd_clean_files(path="/var/spool/cups/tmp", pattern="(null)")
I [12/Aug/2010:17:15:50 +0900] Cleaning out old files in "/var/spool/cups/tmp"...
D [12/Aug/2010:17:15:50 +0900] cupsd_clean_files(path="/var/cache/cups", pattern="*.ipp")
I [12/Aug/2010:17:15:50 +0900] Cleaning out old files in "/var/cache/cups"...
I [12/Aug/2010:17:15:50 +0900] Listening to ::1:631 on fd 4...
I [12/Aug/2010:17:15:50 +0900] Listening to 127.0.0.1:631 on fd 6...
I [12/Aug/2010:17:15:50 +0900] Listening to /var/run/cups/cups.sock on fd 7...
I [12/Aug/2010:17:15:50 +0900] Resuming new connection processing...
D [12/Aug/2010:17:15:50 +0900] Discarding unused server-started event...
I [12/Aug/2010:17:15:50 +0900] Scheduler shutting down normally.
D [12/Aug/2010:17:15:50 +0900] Discarding unused server-stopped event...
I [12/Aug/2010:17:15:50 +0900] Saving job cache file "/var/cache/cups/job.cache"...
I [12/Aug/2010:17:15:50 +0900] Listening to ::1:631 (IPv6)
I [12/Aug/2010:17:15:50 +0900] Listening to 127.0.0.1:631 (IPv4)
I [12/Aug/2010:17:15:50 +0900] Listening to /var/run/cups/cups.sock (Domain)
I [12/Aug/2010:17:15:50 +0900] Remote access is disabled.
D [12/Aug/2010:17:15:50 +0900] Added auto ServerAlias nemesis
I [12/Aug/2010:17:15:50 +0900] Loaded configuration file "/etc/cups/cupsd.conf"
I [12/Aug/2010:17:15:50 +0900] Using default TempDir of /var/spool/cups/tmp...
I [12/Aug/2010:17:15:50 +0900] Configured for up to 100 clients.
I [12/Aug/2010:17:15:50 +0900] Allowing up to 100 client connections per host.
I [12/Aug/2010:17:15:50 +0900] Full reload is required.
I [12/Aug/2010:17:15:50 +0900] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 35 types, 45 filters...
I [12/Aug/2010:17:15:50 +0900] Loading job cache file "/var/cache/cups/job.cache"...
D [12/Aug/2010:17:15:50 +0900] [Job 2] Loading from cache...
D [12/Aug/2010:17:15:50 +0900] [Job 3] Loading from cache...
I [12/Aug/2010:17:15:50 +0900] Full reload complete.
D [12/Aug/2010:17:15:50 +0900] cupsd_clean_files(path="/var/spool/cups/tmp", pattern="(null)")
I [12/Aug/2010:17:15:50 +0900] Cleaning out old files in "/var/spool/cups/tmp"...
D [12/Aug/2010:17:15:50 +0900] cupsd_clean_files(path="/var/cache/cups", pattern="*.ipp")
I [12/Aug/2010:17:15:50 +0900] Cleaning out old files in "/var/cache/cups"...
I [12/Aug/2010:17:15:50 +0900] Listening to ::1:631 on fd 4...
I [12/Aug/2010:17:15:50 +0900] Listening to 127.0.0.1:631 on fd 6...
I [12/Aug/2010:17:15:50 +0900] Listening to /var/run/cups/cups.sock on fd 7...
I [12/Aug/2010:17:15:50 +0900] Resuming new connection processing...
D [12/Aug/2010:17:15:50 +0900] Discarding unused server-started event...
D [12/Aug/2010:17:15:51 +0900] Report: clients=0
D [12/Aug/2010:17:15:51 +0900] Report: jobs=2
D [12/Aug/2010:17:15:51 +0900] Report: jobs-active=0
D [12/Aug/2010:17:15:51 +0900] Report: printers=0
D [12/Aug/2010:17:15:51 +0900] Report: printers-implicit=0
D [12/Aug/2010:17:15:51 +0900] Report: stringpool-string-count=129
D [12/Aug/2010:17:15:51 +0900] Report: stringpool-alloc-bytes=4064
D [12/Aug/2010:17:15:51 +0900] Report: stringpool-total-bytes=3096
D [12/Aug/2010:17:15:52 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:52 +0900] cupsdReadClient: 11 POST / HTTP/1.1
D [12/Aug/2010:17:15:52 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:52 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:15:52 +0900] cupsdReadClient: 11 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:15:52 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:15:52 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:15:52 +0900] Returning HTTP Unauthorized for CUPS-Get-Devices (no URI) from localhost
D [12/Aug/2010:17:15:52 +0900] cupsdSendHeader: 11 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:15:52 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:52 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:52 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:52 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:52 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:52 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:52 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:52 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:15:52 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:52 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:52 +0900] cupsdReadClient: 13 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:15:52 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:15:52 +0900] cupsdIsAuthorized: username="root"
D [12/Aug/2010:17:15:52 +0900] [CGI] argv[0] = "/usr/lib/cups/daemon/cups-deviced"
D [12/Aug/2010:17:15:52 +0900] [CGI] argv[1] = "1"
D [12/Aug/2010:17:15:52 +0900] [CGI] argv[2] = "0"
D [12/Aug/2010:17:15:52 +0900] [CGI] argv[3] = "15"
D [12/Aug/2010:17:15:52 +0900] [CGI] argv[4] = "4"
D [12/Aug/2010:17:15:52 +0900] [CGI] argv[5] = "requested-attributes=all"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/webcontent"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[10] = "SERVER_ADMIN=root@nemesis"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.4"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[13] = "USER=root"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[14] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[15] = "CUPS_ENCRYPTION=IfRequested"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[16] = "IPP_PORT=631"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[17] = "CUPSD_AUTH_TYPE=PeerCred"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[18] = "LANG=ja_JP.UTF8"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[19] = "REDIRECT_STATUS=1"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[20] = "GATEWAY_INTERFACE=CGI/1.1"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[21] = "SERVER_NAME=localhost"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[22] = "SERVER_PORT=631"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[23] = "REMOTE_ADDR="
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[24] = "REMOTE_HOST=localhost"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[25] = "SCRIPT_NAME=/"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[26] = "SCRIPT_FILENAME=/usr/share/cups/webcontent/"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[27] = "REMOTE_USER=root"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[28] = "SERVER_PROTOCOL=HTTP/1.1"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[29] = "HTTP_USER_AGENT=CUPS/1.4.4"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[30] = "REQUEST_METHOD=POST"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[31] = "CONTENT_LENGTH=75"
D [12/Aug/2010:17:15:52 +0900] [CGI] envp[32] = "CONTENT_TYPE=application/ipp"
D [12/Aug/2010:17:15:52 +0900] [CGI] Started /usr/lib/cups/daemon/cups-deviced (PID 16220)
I [12/Aug/2010:17:15:52 +0900] Started "/usr/lib/cups/daemon/cups-deviced" (pid=16220)
D [12/Aug/2010:17:15:52 +0900] cupsdSendCommand: 13 file=11
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/beh (PID 16221)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 16222)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 16223)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 16224)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 16225)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/scsi (PID 16226)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 16227)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 16228)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 16229)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 16230)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hp (PID 16231)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 16232)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hpfax (PID 16233)
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16223 (ipp) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16224 (lpd) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16225 (parallel) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16229 (socket) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16230 (usb) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Found device "ipp"...
D [12/Aug/2010:17:15:52 +0900] Script header: Content-Type: application/ipp
D [12/Aug/2010:17:15:52 +0900] Script header: 
D [12/Aug/2010:17:15:52 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Found device "lpd"...
D [12/Aug/2010:17:15:52 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Found device "socket"...
D [12/Aug/2010:17:15:52 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Found device "http"...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16222 (http) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16227 (serial) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Found device "beh"...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16221 (beh) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Found device "scsi"...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16226 (scsi) exited with no errors.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/001: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/002: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/003: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/004: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/005: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/001: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/002: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/003: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/004: Permission denied.
D [12/Aug/2010:17:15:52 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:52 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] Found device "hp"...
D [12/Aug/2010:17:15:52 +0900] [cups-deviced] PID 16231 (hp) exited with no errors.
D [12/Aug/2010:17:15:53 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:53 +0900] [cups-deviced] Found device "smb"...
D [12/Aug/2010:17:15:53 +0900] [cups-deviced] PID 16232 (smb) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "hpfax"...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16233 (hpfax) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16228 (snmp) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] PID 16220 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:54 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:54 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:54 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:54 +0900] cupsdReadClient: 11 POST / HTTP/1.1
D [12/Aug/2010:17:15:54 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:54 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:15:54 +0900] cupsdReadClient: 11 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:15:54 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:15:54 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:15:54 +0900] Returning HTTP Unauthorized for CUPS-Get-Devices (no URI) from localhost
D [12/Aug/2010:17:15:54 +0900] cupsdSendHeader: 11 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:15:54 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:54 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:54 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:54 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:54 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:54 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:54 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:54 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:15:54 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:54 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:54 +0900] cupsdReadClient: 13 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:15:54 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:15:54 +0900] cupsdIsAuthorized: username="root"
D [12/Aug/2010:17:15:54 +0900] [CGI] argv[0] = "/usr/lib/cups/daemon/cups-deviced"
D [12/Aug/2010:17:15:54 +0900] [CGI] argv[1] = "1"
D [12/Aug/2010:17:15:54 +0900] [CGI] argv[2] = "0"
D [12/Aug/2010:17:15:54 +0900] [CGI] argv[3] = "15"
D [12/Aug/2010:17:15:54 +0900] [CGI] argv[4] = "4"
D [12/Aug/2010:17:15:54 +0900] [CGI] argv[5] = "requested-attributes=all"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/webcontent"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[10] = "SERVER_ADMIN=root@nemesis"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.4"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[13] = "USER=root"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[14] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[15] = "CUPS_ENCRYPTION=IfRequested"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[16] = "IPP_PORT=631"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[17] = "CUPSD_AUTH_TYPE=PeerCred"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[18] = "LANG=ja_JP.UTF8"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[19] = "REDIRECT_STATUS=1"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[20] = "GATEWAY_INTERFACE=CGI/1.1"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[21] = "SERVER_NAME=localhost"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[22] = "SERVER_PORT=631"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[23] = "REMOTE_ADDR="
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[24] = "REMOTE_HOST=localhost"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[25] = "SCRIPT_NAME=/"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[26] = "SCRIPT_FILENAME=/usr/share/cups/webcontent/"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[27] = "REMOTE_USER=root"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[28] = "SERVER_PROTOCOL=HTTP/1.1"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[29] = "HTTP_USER_AGENT=CUPS/1.4.4"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[30] = "REQUEST_METHOD=POST"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[31] = "CONTENT_LENGTH=75"
D [12/Aug/2010:17:15:54 +0900] [CGI] envp[32] = "CONTENT_TYPE=application/ipp"
D [12/Aug/2010:17:15:54 +0900] [CGI] Started /usr/lib/cups/daemon/cups-deviced (PID 16238)
I [12/Aug/2010:17:15:54 +0900] Started "/usr/lib/cups/daemon/cups-deviced" (pid=16238)
D [12/Aug/2010:17:15:54 +0900] cupsdSendCommand: 13 file=11
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/beh (PID 16239)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 16240)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 16241)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 16242)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 16243)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/scsi (PID 16244)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 16245)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 16246)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 16247)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 16248)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hp (PID 16249)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 16250)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hpfax (PID 16251)
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16243 (parallel) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "beh"...
D [12/Aug/2010:17:15:54 +0900] Script header: Content-Type: application/ipp
D [12/Aug/2010:17:15:54 +0900] Script header: 
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16239 (beh) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16248 (usb) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "http"...
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "ipp"...
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "lpd"...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16241 (ipp) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16240 (http) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16242 (lpd) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "smb"...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16250 (smb) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16245 (serial) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "scsi"...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16244 (scsi) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/001: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/002: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/003: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/004: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/005: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/001: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/002: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/003: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/004: Permission denied.
D [12/Aug/2010:17:15:54 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "hp"...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16249 (hp) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "socket"...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16247 (socket) exited with no errors.
D [12/Aug/2010:17:15:54 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] Found device "hpfax"...
D [12/Aug/2010:17:15:54 +0900] [cups-deviced] PID 16251 (hpfax) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16246 (snmp) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] PID 16238 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:56 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:56 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:56 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:56 +0900] cupsdReadClient: 11 POST / HTTP/1.1
D [12/Aug/2010:17:15:56 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:56 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:15:56 +0900] cupsdReadClient: 11 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:15:56 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:15:56 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:15:56 +0900] Returning HTTP Unauthorized for CUPS-Get-Devices (no URI) from localhost
D [12/Aug/2010:17:15:56 +0900] cupsdSendHeader: 11 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:15:56 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:56 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:56 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:56 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:56 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:56 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:56 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:56 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:15:56 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:56 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:56 +0900] cupsdReadClient: 13 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:15:56 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:15:56 +0900] cupsdIsAuthorized: username="root"
D [12/Aug/2010:17:15:56 +0900] [CGI] argv[0] = "/usr/lib/cups/daemon/cups-deviced"
D [12/Aug/2010:17:15:56 +0900] [CGI] argv[1] = "1"
D [12/Aug/2010:17:15:56 +0900] [CGI] argv[2] = "0"
D [12/Aug/2010:17:15:56 +0900] [CGI] argv[3] = "15"
D [12/Aug/2010:17:15:56 +0900] [CGI] argv[4] = "4"
D [12/Aug/2010:17:15:56 +0900] [CGI] argv[5] = "requested-attributes=all"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/webcontent"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[10] = "SERVER_ADMIN=root@nemesis"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.4"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[13] = "USER=root"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[14] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[15] = "CUPS_ENCRYPTION=IfRequested"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[16] = "IPP_PORT=631"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[17] = "CUPSD_AUTH_TYPE=PeerCred"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[18] = "LANG=ja_JP.UTF8"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[19] = "REDIRECT_STATUS=1"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[20] = "GATEWAY_INTERFACE=CGI/1.1"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[21] = "SERVER_NAME=localhost"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[22] = "SERVER_PORT=631"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[23] = "REMOTE_ADDR="
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[24] = "REMOTE_HOST=localhost"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[25] = "SCRIPT_NAME=/"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[26] = "SCRIPT_FILENAME=/usr/share/cups/webcontent/"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[27] = "REMOTE_USER=root"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[28] = "SERVER_PROTOCOL=HTTP/1.1"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[29] = "HTTP_USER_AGENT=CUPS/1.4.4"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[30] = "REQUEST_METHOD=POST"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[31] = "CONTENT_LENGTH=75"
D [12/Aug/2010:17:15:56 +0900] [CGI] envp[32] = "CONTENT_TYPE=application/ipp"
D [12/Aug/2010:17:15:56 +0900] [CGI] Started /usr/lib/cups/daemon/cups-deviced (PID 16258)
I [12/Aug/2010:17:15:56 +0900] Started "/usr/lib/cups/daemon/cups-deviced" (pid=16258)
D [12/Aug/2010:17:15:56 +0900] cupsdSendCommand: 13 file=11
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/beh (PID 16259)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 16260)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 16261)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 16262)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 16263)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/scsi (PID 16264)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 16265)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 16266)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 16267)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 16268)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hp (PID 16269)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 16270)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hpfax (PID 16271)
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16263 (parallel) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "beh"...
D [12/Aug/2010:17:15:56 +0900] Script header: Content-Type: application/ipp
D [12/Aug/2010:17:15:56 +0900] Script header: 
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16259 (beh) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16268 (usb) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "http"...
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "ipp"...
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "lpd"...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16260 (http) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16261 (ipp) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16262 (lpd) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "scsi"...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16264 (scsi) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "smb"...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16270 (smb) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16265 (serial) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/001: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/002: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/003: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/004: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/005: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/001: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/002: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/003: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/004: Permission denied.
D [12/Aug/2010:17:15:56 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "hp"...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16269 (hp) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "socket"...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16267 (socket) exited with no errors.
D [12/Aug/2010:17:15:56 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] Found device "hpfax"...
D [12/Aug/2010:17:15:56 +0900] [cups-deviced] PID 16271 (hpfax) exited with no errors.
D [12/Aug/2010:17:15:58 +0900] [cups-deviced] PID 16266 (snmp) exited with no errors.
D [12/Aug/2010:17:15:58 +0900] PID 16258 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:58 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:58 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 11 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:58 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 11 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:15:58 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:58 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:15:58 +0900] Returning HTTP Unauthorized for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:58 +0900] cupsdSendHeader: 11 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:58 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:15:58 +0900] cupsdAcceptClient: 11 from localhost (Domain)
D [12/Aug/2010:17:15:58 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 11 WAITING Closing on EOF
D [12/Aug/2010:17:15:58 +0900] cupsdCloseClient: 11
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:15:58 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:15:58 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:58 +0900] cupsdIsAuthorized: username="root"
I [12/Aug/2010:17:15:58 +0900] Setting MFC695CDN printer-is-accepting-jobs to 1 (was 0.)
D [12/Aug/2010:17:15:58 +0900] Discarding unused printer-state-changed event...
I [12/Aug/2010:17:15:58 +0900] Setting MFC695CDN printer-state to 3 (was 5.)
D [12/Aug/2010:17:15:58 +0900] Discarding unused printer-state-changed event...
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:15:58 +0900] load_ppd: Loading /etc/cups/ppd/MFC695CDN.ppd...
D [12/Aug/2010:17:15:58 +0900] cupsdRegisterPrinter(p=0x7f388fc78290(MFC695CDN))
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(---p--)
D [12/Aug/2010:17:15:58 +0900] Discarding unused (null) event...
I [12/Aug/2010:17:15:58 +0900] New printer "MFC695CDN" added by "root".
D [12/Aug/2010:17:15:58 +0900] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:15:58 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:58 +0900] cupsdIsAuthorized: username="root"
I [12/Aug/2010:17:15:58 +0900] Setting MFC695CDN device-uri to "usb:/dev/usb/lp0" (was "file:///dev/null".)
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:58 +0900] load_ppd: Loading /etc/cups/ppd/MFC695CDN.ppd...
D [12/Aug/2010:17:15:58 +0900] cupsdRegisterPrinter(p=0x7f388fc78290(MFC695CDN))
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(---p--)
D [12/Aug/2010:17:15:58 +0900] Discarding unused (null) event...
I [12/Aug/2010:17:15:58 +0900] Printer "MFC695CDN" modified by "root".
D [12/Aug/2010:17:15:58 +0900] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:15:58 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:58 +0900] cupsdIsAuthorized: username="root"
D [12/Aug/2010:17:15:58 +0900] Copied PPD file successfully!
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:58 +0900] load_ppd: Loading /etc/cups/ppd/MFC695CDN.ppd...
D [12/Aug/2010:17:15:58 +0900] load_ppd: Saving /var/cache/cups/MFC695CDN.ipp2...
D [12/Aug/2010:17:15:58 +0900] cupsdRegisterPrinter(p=0x7f388fc78290(MFC695CDN))
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(---p--)
D [12/Aug/2010:17:15:58 +0900] Discarding unused (null) event...
I [12/Aug/2010:17:15:58 +0900] Printer "MFC695CDN" modified by "root".
D [12/Aug/2010:17:15:58 +0900] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:58 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:58 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:15:58 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:58 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:15:58 +0900] Returning HTTP Unauthorized for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:58 +0900] cupsdSendHeader: 13 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:58 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:15:58 +0900] cupsdAcceptClient: 14 from localhost (Domain)
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:15:58 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 14 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 14 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:15:58 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:15:58 +0900] cupsdIsAuthorized: username="root"
I [12/Aug/2010:17:15:58 +0900] Setting MFC695CDN printer-state to 3 (was 3.)
D [12/Aug/2010:17:15:58 +0900] load_ppd: Loading /var/cache/cups/MFC695CDN.ipp2...
D [12/Aug/2010:17:15:58 +0900] cupsdRegisterPrinter(p=0x7f388fc78290(MFC695CDN))
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:15:58 +0900] cupsdMarkDirty(---p--)
D [12/Aug/2010:17:15:58 +0900] Discarding unused (null) event...
I [12/Aug/2010:17:15:58 +0900] Printer "MFC695CDN" modified by "root".
D [12/Aug/2010:17:15:58 +0900] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:15:58 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:15:58 +0900] cupsdReadClient: 14 WAITING Closing on EOF
D [12/Aug/2010:17:15:58 +0900] cupsdCloseClient: 14
D [12/Aug/2010:17:16:01 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:16:01 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:16:01 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:01 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:01 +0900] cupsdReadClient: 13 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:16:01 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:16:01 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:16:01 +0900] Returning HTTP Unauthorized for CUPS-Get-Devices (no URI) from localhost
D [12/Aug/2010:17:16:01 +0900] cupsdSendHeader: 13 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:16:01 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:16:01 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:16:01 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:01 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:16:01 +0900] cupsdAcceptClient: 14 from localhost (Domain)
D [12/Aug/2010:17:16:01 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:16:01 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:16:01 +0900] cupsdReadClient: 14 POST / HTTP/1.1
D [12/Aug/2010:17:16:01 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:01 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:16:01 +0900] cupsdReadClient: 14 1.1 CUPS-Get-Devices 1
D [12/Aug/2010:17:16:01 +0900] CUPS-Get-Devices
D [12/Aug/2010:17:16:01 +0900] cupsdIsAuthorized: username="root"
D [12/Aug/2010:17:16:01 +0900] [CGI] argv[0] = "/usr/lib/cups/daemon/cups-deviced"
D [12/Aug/2010:17:16:01 +0900] [CGI] argv[1] = "1"
D [12/Aug/2010:17:16:01 +0900] [CGI] argv[2] = "0"
D [12/Aug/2010:17:16:01 +0900] [CGI] argv[3] = "15"
D [12/Aug/2010:17:16:01 +0900] [CGI] argv[4] = "4"
D [12/Aug/2010:17:16:01 +0900] [CGI] argv[5] = "requested-attributes=all"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/webcontent"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[10] = "SERVER_ADMIN=root@nemesis"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.4"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[13] = "USER=root"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[14] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[15] = "CUPS_ENCRYPTION=IfRequested"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[16] = "IPP_PORT=631"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[17] = "CUPSD_AUTH_TYPE=PeerCred"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[18] = "LANG=ja_JP.UTF8"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[19] = "REDIRECT_STATUS=1"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[20] = "GATEWAY_INTERFACE=CGI/1.1"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[21] = "SERVER_NAME=localhost"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[22] = "SERVER_PORT=631"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[23] = "REMOTE_ADDR="
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[24] = "REMOTE_HOST=localhost"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[25] = "SCRIPT_NAME=/"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[26] = "SCRIPT_FILENAME=/usr/share/cups/webcontent/"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[27] = "REMOTE_USER=root"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[28] = "SERVER_PROTOCOL=HTTP/1.1"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[29] = "HTTP_USER_AGENT=CUPS/1.4.4"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[30] = "REQUEST_METHOD=POST"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[31] = "CONTENT_LENGTH=75"
D [12/Aug/2010:17:16:01 +0900] [CGI] envp[32] = "CONTENT_TYPE=application/ipp"
D [12/Aug/2010:17:16:01 +0900] [CGI] Started /usr/lib/cups/daemon/cups-deviced (PID 16304)
I [12/Aug/2010:17:16:01 +0900] Started "/usr/lib/cups/daemon/cups-deviced" (pid=16304)
D [12/Aug/2010:17:16:01 +0900] cupsdSendCommand: 14 file=13
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/beh (PID 16305)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 16306)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 16307)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 16308)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 16309)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/scsi (PID 16310)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 16311)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 16312)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 16313)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 16314)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hp (PID 16315)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 16316)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Started backend /usr/lib/cups/backend/hpfax (PID 16317)
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16309 (parallel) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "beh"...
D [12/Aug/2010:17:16:01 +0900] Script header: Content-Type: application/ipp
D [12/Aug/2010:17:16:01 +0900] Script header: 
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16305 (beh) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16314 (usb) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "http"...
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "ipp"...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16306 (http) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16307 (ipp) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "lpd"...
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "scsi"...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16310 (scsi) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16308 (lpd) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "smb"...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16316 (smb) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16311 (serial) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/001: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/002: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/003: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/004: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/001/005: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "socket"...
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/001: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/002: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/003: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb couldn't open USB device /dev/bus/usb/002/004: Permission denied.
D [12/Aug/2010:17:16:01 +0900] [CGI] libusb requires write access to USB device nodes.
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16313 (socket) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "hp"...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16315 (hp) exited with no errors.
D [12/Aug/2010:17:16:01 +0900] [CGI] Flushed attributes...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] Found device "hpfax"...
D [12/Aug/2010:17:16:01 +0900] [cups-deviced] PID 16317 (hpfax) exited with no errors.
D [12/Aug/2010:17:16:03 +0900] [cups-deviced] PID 16312 (snmp) exited with no errors.
D [12/Aug/2010:17:16:03 +0900] PID 16304 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [12/Aug/2010:17:16:03 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:03 +0900] cupsdReadClient: 14 WAITING Closing on EOF
D [12/Aug/2010:17:16:03 +0900] cupsdCloseClient: 14
D [12/Aug/2010:17:16:09 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 13 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:16:09 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:09 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 13 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:16:09 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:16:09 +0900] cupsdIsAuthorized: username=""
D [12/Aug/2010:17:16:09 +0900] Returning HTTP Unauthorized for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:09 +0900] cupsdSendHeader: 13 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:16:09 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:16:09 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:09 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:16:09 +0900] cupsdAcceptClient: 14 from localhost (Domain)
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:16:09 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 14 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:16:09 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:09 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 14 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:16:09 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:16:09 +0900] cupsdIsAuthorized: username="root"
I [12/Aug/2010:17:16:09 +0900] Setting MFC695CDN device-uri to "socket://192.168.11.50" (was "usb:/dev/usb/lp0".)
D [12/Aug/2010:17:16:09 +0900] load_ppd: Loading /var/cache/cups/MFC695CDN.ipp2...
D [12/Aug/2010:17:16:09 +0900] cupsdRegisterPrinter(p=0x7f388fc78290(MFC695CDN))
D [12/Aug/2010:17:16:09 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:16:09 +0900] cupsdMarkDirty(---p--)
D [12/Aug/2010:17:16:09 +0900] Discarding unused (null) event...
I [12/Aug/2010:17:16:09 +0900] Printer "MFC695CDN" modified by "root".
D [12/Aug/2010:17:16:09 +0900] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:09 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 14 POST /admin/ HTTP/1.1
D [12/Aug/2010:17:16:09 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:09 +0900] cupsdAuthorize: Authorized as root using PeerCred
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 14 1.1 CUPS-Add-Modify-Printer 1
D [12/Aug/2010:17:16:09 +0900] CUPS-Add-Modify-Printer ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:16:09 +0900] cupsdIsAuthorized: username="root"
I [12/Aug/2010:17:16:09 +0900] Setting MFC695CDN printer-state to 3 (was 3.)
D [12/Aug/2010:17:16:09 +0900] load_ppd: Loading /var/cache/cups/MFC695CDN.ipp2...
D [12/Aug/2010:17:16:09 +0900] cupsdRegisterPrinter(p=0x7f388fc78290(MFC695CDN))
D [12/Aug/2010:17:16:09 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:16:09 +0900] cupsdMarkDirty(---p--)
D [12/Aug/2010:17:16:09 +0900] Discarding unused (null) event...
I [12/Aug/2010:17:16:09 +0900] Printer "MFC695CDN" modified by "root".
D [12/Aug/2010:17:16:09 +0900] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:09 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:09 +0900] cupsdReadClient: 14 WAITING Closing on EOF
D [12/Aug/2010:17:16:09 +0900] cupsdCloseClient: 14
D [12/Aug/2010:17:16:17 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:16:17 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:16:17 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:17 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:17 +0900] cupsdReadClient: 13 1.1 Get-Printer-Attributes 1
D [12/Aug/2010:17:16:17 +0900] Get-Printer-Attributes ipp://localhost:631/printers/MFC695CDN
D [12/Aug/2010:17:16:17 +0900] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:17 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:17 +0900] cupsdReadClient: 13 POST /printers/MFC695CDN HTTP/1.1
D [12/Aug/2010:17:16:17 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:17 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:17 +0900] cupsdReadClient: 13 1.1 Create-Job 1
D [12/Aug/2010:17:16:17 +0900] Create-Job ipp://localhost:631/printers/MFC695CDN
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(----J-)
D [12/Aug/2010:17:16:17 +0900] add_job: requesting-user-name="root"
I [12/Aug/2010:17:16:17 +0900] [Job 19] Adding start banner page "none".
D [12/Aug/2010:17:16:17 +0900] Discarding unused job-created event...
I [12/Aug/2010:17:16:17 +0900] [Job 19] Queued on "MFC695CDN" by "root".
D [12/Aug/2010:17:16:17 +0900] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:17 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:17 +0900] cupsdReadClient: 13 POST /printers/MFC695CDN HTTP/1.1
D [12/Aug/2010:17:16:17 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:17 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:17 +0900] cupsdReadClient: 13 1.1 Send-Document 1
D [12/Aug/2010:17:16:17 +0900] Send-Document ipp://localhost:631/printers/MFC695CDN
D [12/Aug/2010:17:16:17 +0900] cupsdIsAuthorized: requesting-user-name="root"
D [12/Aug/2010:17:16:17 +0900] [Job 19] Auto-typing file...
D [12/Aug/2010:17:16:17 +0900] [Job 19] Request file type is application/vnd.cups-banner.
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(----J-)
I [12/Aug/2010:17:16:17 +0900] [Job 19] File of type application/vnd.cups-banner queued by "root".
I [12/Aug/2010:17:16:17 +0900] [Job 19] Adding end banner page "none".
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(----J-)
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(----J-)
D [12/Aug/2010:17:16:17 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [12/Aug/2010:17:16:17 +0900] Discarding unused printer-state-changed event...
D [12/Aug/2010:17:16:17 +0900] [Job 19] job-sheets=none,none
D [12/Aug/2010:17:16:17 +0900] [Job 19] argv[0]="MFC695CDN"
D [12/Aug/2010:17:16:17 +0900] [Job 19] argv[1]="19"
D [12/Aug/2010:17:16:17 +0900] [Job 19] argv[2]="root"
D [12/Aug/2010:17:16:17 +0900] [Job 19] argv[3]="testprint"
D [12/Aug/2010:17:16:17 +0900] [Job 19] argv[4]="1"
D [12/Aug/2010:17:16:17 +0900] [Job 19] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:6d2178ea-26d9-36fa-7487-19f5e77fee80 job-originating-host-name=localhost"
D [12/Aug/2010:17:16:17 +0900] [Job 19] argv[6]="/var/spool/cups/d00019-001"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[2]="CUPS_DOCROOT=/usr/share/cups/webcontent"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[8]="HOME=/var/spool/cups/tmp"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[10]="SERVER_ADMIN=root@nemesis"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[11]="SOFTWARE=CUPS/1.4.4"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[13]="USER=root"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[16]="IPP_PORT=631"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[17]="CHARSET=utf-8"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[18]="LANG=ja_JP.UTF-8"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[19]="PPD=/etc/cups/ppd/MFC695CDN.ppd"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[20]="RIP_MAX_CACHE=8m"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[21]="CONTENT_TYPE=application/vnd.cups-banner"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[22]="DEVICE_URI=socket://192.168.11.50"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[23]="PRINTER_INFO=MFC695CDN"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[24]="PRINTER_LOCATION="
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[25]="PRINTER=MFC695CDN"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[26]="CUPS_FILETYPE=document"
D [12/Aug/2010:17:16:17 +0900] [Job 19] envp[27]="FINAL_CONTENT_TYPE=printer/MFC695CDN"
I [12/Aug/2010:17:16:17 +0900] [Job 19] Started filter /usr/lib/cups/filter/bannertops (PID 16332)
I [12/Aug/2010:17:16:17 +0900] [Job 19] Started filter /usr/lib/cups/filter/pstops (PID 16333)
I [12/Aug/2010:17:16:17 +0900] [Job 19] Started filter /usr/lib/cups/filter/brlpdwrappermfc695cdn (PID 16334)
I [12/Aug/2010:17:16:17 +0900] [Job 19] Started backend /usr/lib/cups/backend/socket (PID 16335)
D [12/Aug/2010:17:16:17 +0900] Discarding unused job-state-changed event...
D [12/Aug/2010:17:16:17 +0900] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:17 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [12/Aug/2010:17:16:17 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:16:17 +0900] cupsdCloseClient: 13
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: +connecting-to-device
D [12/Aug/2010:17:16:17 +0900] Discarding unused printer-state-changed event...
D [12/Aug/2010:17:16:17 +0900] [Job 19] Looking up "192.168.11.50"...
D [12/Aug/2010:17:16:17 +0900] [Job 19] Connecting to 192.168.11.50:9100
I [12/Aug/2010:17:16:17 +0900] [Job 19] ���������������������������...
D [12/Aug/2010:17:16:17 +0900] Discarding unused job-progress event...
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -connecting-to-device
D [12/Aug/2010:17:16:17 +0900] Discarding unused printer-state-changed event...
I [12/Aug/2010:17:16:17 +0900] [Job 19] ������������������������������������...
D [12/Aug/2010:17:16:17 +0900] [Job 19] Connected to 192.168.11.50:9100 (IPv4)...
D [12/Aug/2010:17:16:17 +0900] Discarding unused job-progress event...
D [12/Aug/2010:17:16:17 +0900] [Job 19] load_banner(filename="/var/spool/cups/d00019-001")
D [12/Aug/2010:17:16:17 +0900] [Job 19] Page = 612x792; 9,9 to 603,783
D [12/Aug/2010:17:16:17 +0900] [Job 19] Unable to open font file "/usr/share/cups/fonts/Monospace" - No such file or directory
D [12/Aug/2010:17:16:17 +0900] [Job 19] Unable to open font file "/usr/share/cups/fonts/Monospace-Bold" - No such file or directory
D [12/Aug/2010:17:16:17 +0900] [Job 19] Unable to open font file "/usr/share/cups/fonts/Monospace-BoldOblique" - No such file or directory
D [12/Aug/2010:17:16:17 +0900] [Job 19] Unable to open font file "/usr/share/cups/fonts/Monospace-Oblique" - No such file or directory
D [12/Aug/2010:17:16:17 +0900] [Job 19] PNG image: 128x128x8, color_type=6 (RGB+ALPHA)
D [12/Aug/2010:17:16:17 +0900] [Job 19] ATTR: marker-colors=#000000,#FFFF00,#00FFFF,#FF00FF
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:16:17 +0900] [Job 19] ATTR: marker-names="Black Ink Cartridge","Yellow Ink Cartridge","Cyan Ink Cartridge","Magenta Ink Cartridge"
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:16:17 +0900] [Job 19] ATTR: marker-types=inkCartridge,inkCartridge,inkCartridge,inkCartridge
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:16:17 +0900] Discarding unused printer-state-changed event...
D [12/Aug/2010:17:16:17 +0900] [Job 19] ATTR: marker-levels=0,0,0,0
D [12/Aug/2010:17:16:17 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:16:17 +0900] Discarding unused printer-state-changed event...
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -media-low-report
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -media-empty-warning
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -toner-low-report
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -toner-empty-warning
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -door-open-report
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -media-jam-warning
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -input-tray-missing-warning
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -output-tray-missing-warning
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -marker-supply-missing-warning
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -output-area-almost-full-report
D [12/Aug/2010:17:16:17 +0900] [Job 19] STATE: -output-area-full-warning
D [12/Aug/2010:17:16:17 +0900] [Job 19] backendRunLoop(print_fd=0, device_fd=5, snmp_fd=6, addr=0x7feb2e6b8928, use_bc=1, side_cb=0x7feb2e4adf20)
D [12/Aug/2010:17:16:17 +0900] [Job 19] Page = 612x792; 9,9 to 603,783
D [12/Aug/2010:17:16:17 +0900] [Job 19] slow_collate=0, slow_duplex=0, slow_order=0
D [12/Aug/2010:17:16:17 +0900] [Job 19] Before copy_comments - %!PS-Adobe-3.0
D [12/Aug/2010:17:16:17 +0900] [Job 19] %!PS-Adobe-3.0
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%BoundingBox: 9 9 603 783
D [12/Aug/2010:17:16:17 +0900] [Job 19] %cupsRotation: 0
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%Creator: bannertops/CUPS v1.4.4
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%CreationDate: 2010���08���12��� 17���16���17���
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%LanguageLevel: 2
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%DocumentData: Clean7Bit
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%Title: (testprint)
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%For: (root)
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%Pages: 1
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%DocumentSuppliedResources: font Monospace
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%+ font Monospace-Bold
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%+ font Monospace-BoldOblique
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%+ font Monospace-Oblique
D [12/Aug/2010:17:16:17 +0900] [Job 19] %%EndComments
D [12/Aug/2010:17:16:17 +0900] [Job 19] Before copy_prolog - %%BeginProlog
D [12/Aug/2010:17:16:17 +0900] [Job 19] PNG image: 192x128x8, color_type=2 (RGB)
D [12/Aug/2010:17:16:17 +0900] [Job 19] Before copy_setup - %%Page: coverpage 1
D [12/Aug/2010:17:16:17 +0900] [Job 19] Before page loop - %%Page: coverpage 1
D [12/Aug/2010:17:16:17 +0900] [Job 19] Copying page 1...
D [12/Aug/2010:17:16:17 +0900] [Job 19] pagew = 594.0, pagel = 774.0
D [12/Aug/2010:17:16:17 +0900] [Job 19] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792
D [12/Aug/2010:17:16:17 +0900] [Job 19] PageLeft = 9.0, PageRight = 603.0
D [12/Aug/2010:17:16:17 +0900] [Job 19] PageTop = 783.0, PageBottom = 9.0
D [12/Aug/2010:17:16:17 +0900] [Job 19] PageWidth = 612.0, PageLength = 792.0
D [12/Aug/2010:17:16:17 +0900] [Job 19] Wrote 1 pages...
D [12/Aug/2010:17:16:17 +0900] PID 16332 (/usr/lib/cups/filter/bannertops) exited with no errors.
D [12/Aug/2010:17:16:17 +0900] PID 16333 (/usr/lib/cups/filter/pstops) exited with no errors.
D [12/Aug/2010:17:16:18 +0900] [Job 19] Error: error occurred at print phase !!
E [12/Aug/2010:17:16:18 +0900] [Job 19] No pages found!
D [12/Aug/2010:17:16:18 +0900] [Job 19] Set job-printer-state-message to "No pages found!", current level=ERROR
D [12/Aug/2010:17:16:18 +0900] Discarding unused job-progress event...
D [12/Aug/2010:17:16:19 +0900] PID 16334 (/usr/lib/cups/filter/brlpdwrappermfc695cdn) exited with no errors.
I [12/Aug/2010:17:16:19 +0900] [Job 19] ������������������������������������������������������������������������������������������������������...
D [12/Aug/2010:17:16:19 +0900] Discarding unused job-progress event...
D [12/Aug/2010:17:16:19 +0900] [Job 19] ATTR: marker-levels=0,0,0,0
D [12/Aug/2010:17:16:19 +0900] cupsdMarkDirty(P-----)
D [12/Aug/2010:17:16:19 +0900] Discarding unused printer-state-changed event...
I [12/Aug/2010:17:16:19 +0900] [Job 19] ������������������������������������������
D [12/Aug/2010:17:16:19 +0900] Discarding unused job-progress event...
D [12/Aug/2010:17:16:19 +0900] PID 16335 (/usr/lib/cups/backend/socket) exited with no errors.
D [12/Aug/2010:17:16:19 +0900] Discarding unused job-completed event...
I [12/Aug/2010:17:16:19 +0900] [Job 19] Job completed.
D [12/Aug/2010:17:16:19 +0900] cupsdMarkDirty(----J-)
D [12/Aug/2010:17:16:19 +0900] Discarding unused printer-state-changed event...
D [12/Aug/2010:17:16:20 +0900] [Job 19] Unloading...
D [12/Aug/2010:17:16:26 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [12/Aug/2010:17:16:26 +0900] CUPS-Get-Printers
D [12/Aug/2010:17:16:26 +0900] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 1.1 CUPS-Get-Default 1
D [12/Aug/2010:17:16:26 +0900] CUPS-Get-Default
D [12/Aug/2010:17:16:26 +0900] CUPS-Get-Default client-error-not-found: No default printer
D [12/Aug/2010:17:16:26 +0900] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 1.1 Get-Printer-Attributes 1
D [12/Aug/2010:17:16:26 +0900] Get-Printer-Attributes ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:16:26 +0900] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Active clients and dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 1.1 Get-Jobs 1
D [12/Aug/2010:17:16:26 +0900] Get-Jobs ipp://localhost/printers/MFC695CDN
D [12/Aug/2010:17:16:26 +0900] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/MFC695CDN) from localhost
D [12/Aug/2010:17:16:26 +0900] cupsdSetBusyState: Dirty files
D [12/Aug/2010:17:16:26 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:16:26 +0900] cupsdCloseClient: 13
I [12/Aug/2010:17:16:29 +0900] Saving printers.conf...
I [12/Aug/2010:17:16:29 +0900] Generating printcap /etc/printcap...
I [12/Aug/2010:17:16:29 +0900] Saving job cache file "/var/cache/cups/job.cache"...
D [12/Aug/2010:17:16:29 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:16:30 +0900] cupsdAcceptClient: 13 from localhost (Domain)
D [12/Aug/2010:17:16:32 +0900] cupsdReadClient: 13 POST / HTTP/1.1
D [12/Aug/2010:17:16:32 +0900] cupsdSetBusyState: Active clients
D [12/Aug/2010:17:16:32 +0900] cupsdAuthorize: No authentication data provided.
D [12/Aug/2010:17:16:32 +0900] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [12/Aug/2010:17:16:32 +0900] CUPS-Get-Printers
D [12/Aug/2010:17:16:32 +0900] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [12/Aug/2010:17:16:32 +0900] cupsdSetBusyState: Not busy
D [12/Aug/2010:17:16:36 +0900] cupsdReadClient: 13 WAITING Closing on EOF
D [12/Aug/2010:17:16:36 +0900] cupsdCloseClient: 13