Report of Native Avahi support

[Hiroshi TAKENAKA]

Dear Tim-san,

> > E [21/Jan/2011:20:45:55 +0900] Returning IPP client-error-document-format=
> -
> > not-supported for Print-Job (ipp://localhost:631/printers/Canon_MG6100_se=
> ries)
> > from localhost
>
> This looks like the problem, and not the avahi support.
>
> The document is being sent in a different format than the printer
> accepts.  That suggests the wrong PPD is being used.
>
> Tim.
> */

I was advised in gimp-print devel forum that I had forgot to build
Ghostscript in /usr/local directories, resulting in no pstoraster
which works with cups.

I've built it and the CUPS seems successfully to print. Indeed, priter
received data from the Linux machine and CUPS reports data is sent to
printer successfully.

However, after receiving the data, the printer would not print any documents.
The error log is as follws.
Through printer sharing on Mac OSX, I can print any documents form the Linux
machine.

Best regards,
Hiroshi Takenaka

I [25/Jan/2011:22:50:12 +0900] [Job 38] Printing page 1, 15%
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:12 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:12 +0900] [Job 38] ATTR: job-media-progress=15
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:12 +0900] [Job 38] Printing page 1, 16%
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:12 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:12 +0900] [Job 38] ATTR: job-media-progress=16
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:12 +0900] [Job 38] Printing page 1, 17%
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:12 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:12 +0900] [Job 38] ATTR: job-media-progress=17
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:12 +0900] [Job 38] Printing page 1, 18%
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:12 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:12 +0900] [Job 38] ATTR: job-media-progress=18
D [25/Jan/2011:22:50:12 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] [Job 38] prtGeneralCurrentLocalization type is 0, expected 2!
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 8192 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 8192 bytes of print data...
I [25/Jan/2011:22:50:13 +0900] [Job 38] Printing page 1, 19%
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:13 +0900] [Job 38] ATTR: job-media-progress=19
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:13 +0900] [Job 38] Printing page 1, 20%
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:13 +0900] [Job 38] ATTR: job-media-progress=20
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:13 +0900] [Job 38] Printing page 1, 21%
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:13 +0900] [Job 38] ATTR: job-media-progress=21
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:13 +0900] [Job 38] Printing page 1, 22%
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:13 +0900] [Job 38] ATTR: job-media-progress=22
D [25/Jan/2011:22:50:13 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:13 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:14 +0900] [Job 38] Printing page 1, 23%
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:14 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:14 +0900] [Job 38] ATTR: job-media-progress=23
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:14 +0900] [Job 38] Printing page 1, 24%
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:14 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:14 +0900] [Job 38] ATTR: job-media-progress=24
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:14 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:14 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:14 +0900] [Job 38] Printing page 1, 25%
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:14 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:14 +0900] [Job 38] ATTR: job-media-progress=25
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:14 +0900] [Job 38] Printing page 1, 26%
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:14 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:14 +0900] [Job 38] ATTR: job-media-progress=26
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:14 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:14 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:14 +0900] [Job 38] Printing page 1, 27%
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:14 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:14 +0900] [Job 38] ATTR: job-media-progress=27
D [25/Jan/2011:22:50:14 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:15 +0900] [Job 38] Printing page 1, 28%
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:15 +0900] [Job 38] ATTR: job-media-progress=28
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:15 +0900] [Job 38] Printing page 1, 29%
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:15 +0900] [Job 38] ATTR: job-media-progress=29
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:15 +0900] [Job 38] Printing page 1, 30%
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:15 +0900] [Job 38] ATTR: job-media-progress=30
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:15 +0900] [Job 38] Printing page 1, 31%
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:15 +0900] [Job 38] ATTR: job-media-progress=31
D [25/Jan/2011:22:50:15 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:15 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:16 +0900] [Job 38] Printing page 1, 32%
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:16 +0900] [Job 38] ATTR: job-media-progress=32
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:16 +0900] [Job 38] Printing page 1, 33%
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:16 +0900] [Job 38] ATTR: job-media-progress=33
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:16 +0900] [Job 38] Printing page 1, 34%
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:16 +0900] [Job 38] ATTR: job-media-progress=34
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:16 +0900] [Job 38] Printing page 1, 35%
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:16 +0900] [Job 38] ATTR: job-media-progress=35
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:16 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:16 +0900] [Job 38] Printing page 1, 36%
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:16 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:16 +0900] [Job 38] ATTR: job-media-progress=36
D [25/Jan/2011:22:50:16 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:17 +0900] [Job 38] Printing page 1, 37%
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:17 +0900] [Job 38] ATTR: job-media-progress=37
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:17 +0900] [Job 38] Printing page 1, 38%
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:17 +0900] [Job 38] ATTR: job-media-progress=38
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:17 +0900] [Job 38] Printing page 1, 39%
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:17 +0900] [Job 38] ATTR: job-media-progress=39
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:17 +0900] [Job 38] Printing page 1, 40%
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:17 +0900] [Job 38] ATTR: job-media-progress=40
D [25/Jan/2011:22:50:17 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:17 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:18 +0900] [Job 38] Printing page 1, 41%
D [25/Jan/2011:22:50:18 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:18 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:18 +0900] [Job 38] ATTR: job-media-progress=41
D [25/Jan/2011:22:50:18 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:18 +0900] [Job 38] Printing page 1, 42%
D [25/Jan/2011:22:50:18 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:18 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:18 +0900] [Job 38] ATTR: job-media-progress=42
D [25/Jan/2011:22:50:18 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 13 GET /printers/Canon_MG6100_series HTTP/1.1
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:18 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:18 +0900] [CGI] argv[0] = "/usr/local/lib/cups/cgi-bin/printers.cgi"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/usr/local/var/cache/cups"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/local/share/cups"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/local/share/doc/cups"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/local/share/cups/fonts"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/usr/local/var/spool/cups"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/local/lib/cups"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/usr/local/etc/cups"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/usr/local/var/run/cups"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[8] = "HOME=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[9] = "PATH=/usr/local/lib/cups/filter:/usr/local/bin:/usr/local/sbin:/bin:/usr/bin"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[10] = "SERVER_ADMIN=root at vine5-imacg4.local"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.6"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[12] = "TMPDIR=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[13] = "TZ=Asia/Tokyo"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[14] = "USER=root"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[15] = "CUPS_SERVER=/usr/local/var/run/cups/cups.sock"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[17] = "IPP_PORT=631"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[19] = "LANG=ja.UTF8"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[22] = "SERVER_NAME=localhost"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[23] = "SERVER_PORT=631"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[26] = "SCRIPT_NAME=/printers/Canon_MG6100_series"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/local/share/doc/cups/printers/Canon_MG6100_series"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[28] = "PATH_INFO=/Canon_MG6100_series"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[29] = "REMOTE_USER=root"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; U; Linux ppc; ja; rv:1.9.1.15) Gecko/20101031 Vine/3.5.15-1vl5 Firefox/3.5.15"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [25/Jan/2011:22:50:18 +0900] [CGI] envp[34] = "QUERY_STRING="
D [25/Jan/2011:22:50:18 +0900] [CGI] Started /usr/local/lib/cups/cgi-bin/printers.cgi (PID 9141)
I [25/Jan/2011:22:50:18 +0900] Started "/usr/local/lib/cups/cgi-bin/printers.cgi" (pid=9141)
D [25/Jan/2011:22:50:18 +0900] cupsdSendCommand: 13 file=16
D [25/Jan/2011:22:50:18 +0900] [CGI] org.cups.sid cookie is "dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:18 +0900] cupsdAcceptClient: 18 from localhost (Domain)
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:18 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 18 1.1 CUPS-Get-Default 1
D [25/Jan/2011:22:50:18 +0900] CUPS-Get-Default
D [25/Jan/2011:22:50:18 +0900] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [25/Jan/2011:22:50:18 +0900] [CGI] show_printer(http=0x200208c0, printer="Canon_MG6100_series")
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:18 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 18 1.1 Get-Printer-Attributes 1
D [25/Jan/2011:22:50:18 +0900] Get-Printer-Attributes ipp://localhost/printers/Canon_MG6100_series
D [25/Jan/2011:22:50:18 +0900] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MG6100_series) from localhost
D [25/Jan/2011:22:50:18 +0900] Script header: Content-Type: text/html;charset=utf-8
D [25/Jan/2011:22:50:18 +0900] Script header:
D [25/Jan/2011:22:50:18 +0900] [CGI] Regular expression ".*Clean.*"
D [25/Jan/2011:22:50:18 +0900] [CGI] Regular expression ".*PrintSelfTestPage.*"
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:18 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 18 1.1 Get-Jobs 1
D [25/Jan/2011:22:50:18 +0900] Get-Jobs ipp://localhost:631/printers/Canon_MG6100_series
D [25/Jan/2011:22:50:18 +0900] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_MG6100_series) from localhost
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 18 WAITING Closing on EOF
D [25/Jan/2011:22:50:18 +0900] cupsdCloseClient: 18
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:18 +0900] PID 9141 (/usr/local/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 13 GET /cups.css HTTP/1.1
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:18 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Printing jobs and dirty files
I [25/Jan/2011:22:50:18 +0900] [Job 38] Printing page 1, 43%
D [25/Jan/2011:22:50:18 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:18 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:18 +0900] [Job 38] ATTR: job-media-progress=43
D [25/Jan/2011:22:50:18 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 13 GET /images/left.gif HTTP/1.1
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:18 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:18 +0900] cupsdReadClient: 13 GET /images/right.gif HTTP/1.1
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:18 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:18 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:18 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:18 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] cupsdReadClient: 13 GET /images/unsel.gif HTTP/1.1
D [25/Jan/2011:22:50:19 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:19 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:19 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:19 +0900] cupsdReadClient: 13 GET /images/sel.gif HTTP/1.1
D [25/Jan/2011:22:50:19 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:19 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:19 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:19 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:19 +0900] [Job 38] Printing page 1, 44%
D [25/Jan/2011:22:50:19 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:19 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:19 +0900] [Job 38] ATTR: job-media-progress=44
D [25/Jan/2011:22:50:19 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:19 +0900] [Job 38] Printing page 1, 45%
D [25/Jan/2011:22:50:19 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:19 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:19 +0900] [Job 38] ATTR: job-media-progress=45
D [25/Jan/2011:22:50:19 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:19 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:20 +0900] [Job 38] Printing page 1, 46%
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:20 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:20 +0900] [Job 38] ATTR: job-media-progress=46
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:20 +0900] [Job 38] Printing page 1, 47%
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:20 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:20 +0900] [Job 38] ATTR: job-media-progress=47
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:20 +0900] [Job 38] Printing page 1, 48%
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:20 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:20 +0900] [Job 38] ATTR: job-media-progress=48
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:20 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:20 +0900] [Job 38] Printing page 1, 49%
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:20 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:20 +0900] [Job 38] ATTR: job-media-progress=49
D [25/Jan/2011:22:50:20 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:21 +0900] [Job 38] Printing page 1, 50%
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:21 +0900] [Job 38] ATTR: job-media-progress=50
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:21 +0900] [Job 38] Printing page 1, 51%
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:21 +0900] [Job 38] ATTR: job-media-progress=51
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] process_browse_data: Canon_MG6100_series__0635B5C6A06D at 10.0.1.9 not found...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:21 +0900] [Job 38] Printing page 1, 52%
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:21 +0900] [Job 38] ATTR: job-media-progress=52
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:21 +0900] [Job 38] Printing page 1, 53%
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:21 +0900] [Job 38] ATTR: job-media-progress=53
D [25/Jan/2011:22:50:21 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:21 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:22 +0900] [Job 38] Printing page 1, 54%
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:22 +0900] [Job 38] ATTR: job-media-progress=54
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:22 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:22 +0900] [Job 38] Printing page 1, 55%
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:22 +0900] [Job 38] ATTR: job-media-progress=55
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:22 +0900] [Job 38] Printing page 1, 56%
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:22 +0900] [Job 38] ATTR: job-media-progress=56
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:22 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:22 +0900] [Job 38] Printing page 1, 57%
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:22 +0900] [Job 38] ATTR: job-media-progress=57
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:22 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:22 +0900] [Job 38] Printing page 1, 58%
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:22 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:22 +0900] [Job 38] ATTR: job-media-progress=58
D [25/Jan/2011:22:50:22 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:23 +0900] [Job 38] Printing page 1, 59%
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:23 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:23 +0900] [Job 38] ATTR: job-media-progress=59
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:23 +0900] [Job 38] Printing page 1, 60%
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:23 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:23 +0900] [Job 38] ATTR: job-media-progress=60
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:23 +0900] [Job 38] Printing page 1, 61%
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:23 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:23 +0900] [Job 38] ATTR: job-media-progress=61
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:23 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:23 +0900] [Job 38] Printing page 1, 62%
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:23 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:23 +0900] [Job 38] ATTR: job-media-progress=62
D [25/Jan/2011:22:50:23 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:24 +0900] [Job 38] Printing page 1, 63%
D [25/Jan/2011:22:50:24 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:24 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:24 +0900] [Job 38] ATTR: job-media-progress=63
D [25/Jan/2011:22:50:24 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:24 +0900] [Job 38] Printing page 1, 64%
D [25/Jan/2011:22:50:24 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:24 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:24 +0900] [Job 38] ATTR: job-media-progress=64
D [25/Jan/2011:22:50:24 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:24 +0900] [Job 38] Printing page 1, 65%
D [25/Jan/2011:22:50:24 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:24 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:24 +0900] [Job 38] ATTR: job-media-progress=65
D [25/Jan/2011:22:50:24 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:24 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:25 +0900] [Job 38] Printing page 1, 66%
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:25 +0900] [Job 38] ATTR: job-media-progress=66
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:25 +0900] [Job 38] Printing page 1, 67%
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:25 +0900] [Job 38] ATTR: job-media-progress=67
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:25 +0900] [Job 38] Printing page 1, 68%
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:25 +0900] [Job 38] ATTR: job-media-progress=68
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:25 +0900] [Job 38] Printing page 1, 69%
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:25 +0900] [Job 38] ATTR: job-media-progress=69
D [25/Jan/2011:22:50:25 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:25 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:26 +0900] [Job 38] Printing page 1, 70%
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:26 +0900] [Job 38] ATTR: job-media-progress=70
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:26 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:26 +0900] [Job 38] Printing page 1, 71%
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:26 +0900] [Job 38] ATTR: job-media-progress=71
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:26 +0900] [Job 38] Printing page 1, 72%
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:26 +0900] [Job 38] ATTR: job-media-progress=72
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:26 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:26 +0900] [Job 38] Printing page 1, 73%
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:26 +0900] [Job 38] ATTR: job-media-progress=73
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:26 +0900] [Job 38] Printing page 1, 74%
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:26 +0900] [Job 38] ATTR: job-media-progress=74
D [25/Jan/2011:22:50:26 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:26 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:26 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:27 +0900] [Job 38] Printing page 1, 75%
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:27 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:27 +0900] [Job 38] ATTR: job-media-progress=75
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:27 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:27 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:27 +0900] [Job 38] Printing page 1, 76%
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:27 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:27 +0900] [Job 38] ATTR: job-media-progress=76
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:27 +0900] [Job 38] Printing page 1, 77%
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:27 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:27 +0900] [Job 38] ATTR: job-media-progress=77
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:27 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:27 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:27 +0900] [Job 38] Printing page 1, 78%
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:27 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:27 +0900] [Job 38] ATTR: job-media-progress=78
D [25/Jan/2011:22:50:27 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:28 +0900] [Job 38] Printing page 1, 79%
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:28 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:28 +0900] [Job 38] ATTR: job-media-progress=79
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:28 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:28 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:28 +0900] [Job 38] Printing page 1, 80%
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:28 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:28 +0900] [Job 38] ATTR: job-media-progress=80
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:28 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:28 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:28 +0900] [Job 38] Printing page 1, 81%
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:28 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:28 +0900] [Job 38] ATTR: job-media-progress=81
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:28 +0900] [Job 38] Printing page 1, 82%
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:28 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:28 +0900] [Job 38] ATTR: job-media-progress=82
D [25/Jan/2011:22:50:28 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:28 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:28 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:29 +0900] [Job 38] Printing page 1, 83%
D [25/Jan/2011:22:50:29 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:29 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:29 +0900] [Job 38] ATTR: job-media-progress=83
D [25/Jan/2011:22:50:29 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:29 +0900] [Job 38] Printing page 1, 84%
D [25/Jan/2011:22:50:29 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:29 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:29 +0900] [Job 38] ATTR: job-media-progress=84
D [25/Jan/2011:22:50:29 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:29 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:29 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 13 GET /printers/Canon_MG6100_series HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:29 +0900] [CGI] argv[0] = "/usr/local/lib/cups/cgi-bin/printers.cgi"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/usr/local/var/cache/cups"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/local/share/cups"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/local/share/doc/cups"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/local/share/cups/fonts"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/usr/local/var/spool/cups"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/local/lib/cups"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/usr/local/etc/cups"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/usr/local/var/run/cups"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[8] = "HOME=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[9] = "PATH=/usr/local/lib/cups/filter:/usr/local/bin:/usr/local/sbin:/bin:/usr/bin"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[10] = "SERVER_ADMIN=root at vine5-imacg4.local"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.6"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[12] = "TMPDIR=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[13] = "TZ=Asia/Tokyo"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[14] = "USER=root"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[15] = "CUPS_SERVER=/usr/local/var/run/cups/cups.sock"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[17] = "IPP_PORT=631"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[19] = "LANG=ja.UTF8"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[22] = "SERVER_NAME=localhost"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[23] = "SERVER_PORT=631"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[26] = "SCRIPT_NAME=/printers/Canon_MG6100_series"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/local/share/doc/cups/printers/Canon_MG6100_series"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[28] = "PATH_INFO=/Canon_MG6100_series"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[29] = "REMOTE_USER=root"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; U; Linux ppc; ja; rv:1.9.1.15) Gecko/20101031 Vine/3.5.15-1vl5 Firefox/3.5.15"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [25/Jan/2011:22:50:29 +0900] [CGI] envp[34] = "QUERY_STRING="
D [25/Jan/2011:22:50:29 +0900] [CGI] Started /usr/local/lib/cups/cgi-bin/printers.cgi (PID 9143)
I [25/Jan/2011:22:50:29 +0900] Started "/usr/local/lib/cups/cgi-bin/printers.cgi" (pid=9143)
D [25/Jan/2011:22:50:29 +0900] cupsdSendCommand: 13 file=16
D [25/Jan/2011:22:50:29 +0900] [CGI] org.cups.sid cookie is "dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:29 +0900] cupsdAcceptClient: 18 from localhost (Domain)
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 18 1.1 CUPS-Get-Default 1
D [25/Jan/2011:22:50:29 +0900] CUPS-Get-Default
D [25/Jan/2011:22:50:29 +0900] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [25/Jan/2011:22:50:29 +0900] [CGI] show_printer(http=0x200208c0, printer="Canon_MG6100_series")
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 18 1.1 Get-Printer-Attributes 1
D [25/Jan/2011:22:50:29 +0900] Get-Printer-Attributes ipp://localhost/printers/Canon_MG6100_series
D [25/Jan/2011:22:50:29 +0900] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MG6100_series) from localhost
D [25/Jan/2011:22:50:29 +0900] Script header: Content-Type: text/html;charset=utf-8
D [25/Jan/2011:22:50:29 +0900] Script header:
D [25/Jan/2011:22:50:29 +0900] [CGI] Regular expression ".*Clean.*"
D [25/Jan/2011:22:50:29 +0900] [CGI] Regular expression ".*PrintSelfTestPage.*"
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 18 1.1 Get-Jobs 1
D [25/Jan/2011:22:50:29 +0900] Get-Jobs ipp://localhost:631/printers/Canon_MG6100_series
D [25/Jan/2011:22:50:29 +0900] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_MG6100_series) from localhost
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 18 WAITING Closing on EOF
D [25/Jan/2011:22:50:29 +0900] cupsdCloseClient: 18
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:29 +0900] PID 9143 (/usr/local/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 13 GET /cups.css HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 13 GET /images/left.gif HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 13 GET /images/right.gif HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Printing jobs and dirty files
I [25/Jan/2011:22:50:29 +0900] [Job 38] Printing page 1, 85%
D [25/Jan/2011:22:50:29 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:29 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:29 +0900] [Job 38] ATTR: job-media-progress=85
D [25/Jan/2011:22:50:29 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 13 GET /images/unsel.gif HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdReadClient: 13 GET /images/sel.gif HTTP/1.1
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [25/Jan/2011:22:50:29 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:29 +0900] cupsdSetBusyState: Printing jobs and dirty files
D [25/Jan/2011:22:50:30 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:30 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:30 +0900] [Job 38] Printing page 1, 86%
D [25/Jan/2011:22:50:30 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:30 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:30 +0900] [Job 38] ATTR: job-media-progress=86
D [25/Jan/2011:22:50:30 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:30 +0900] [Job 38] Printing page 1, 87%
D [25/Jan/2011:22:50:30 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:30 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:30 +0900] [Job 38] ATTR: job-media-progress=87
D [25/Jan/2011:22:50:30 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:30 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:30 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:30 +0900] [Job 38] Printing page 1, 88%
D [25/Jan/2011:22:50:30 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:30 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:30 +0900] [Job 38] ATTR: job-media-progress=88
D [25/Jan/2011:22:50:30 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:31 +0900] [Job 38] Printing page 1, 89%
D [25/Jan/2011:22:50:31 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:31 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:31 +0900] [Job 38] ATTR: job-media-progress=89
D [25/Jan/2011:22:50:31 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:31 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:31 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:31 +0900] [Job 38] Printing page 1, 90%
D [25/Jan/2011:22:50:31 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:31 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:31 +0900] [Job 38] ATTR: job-media-progress=90
D [25/Jan/2011:22:50:31 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:31 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:31 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:31 +0900] [Job 38] Printing page 1, 91%
D [25/Jan/2011:22:50:31 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:31 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:31 +0900] [Job 38] ATTR: job-media-progress=91
D [25/Jan/2011:22:50:31 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:32 +0900] [Job 38] Printing page 1, 92%
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:32 +0900] [Job 38] ATTR: job-media-progress=92
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:32 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:32 +0900] [Job 38] Printing page 1, 93%
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:32 +0900] [Job 38] ATTR: job-media-progress=93
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:32 +0900] [Job 38] Printing page 1, 94%
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:32 +0900] [Job 38] ATTR: job-media-progress=94
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:32 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:32 +0900] [Job 38] Printing page 1, 95%
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:32 +0900] [Job 38] ATTR: job-media-progress=95
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:32 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:32 +0900] [Job 38] Printing page 1, 96%
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:32 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:32 +0900] [Job 38] ATTR: job-media-progress=96
D [25/Jan/2011:22:50:32 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:33 +0900] [Job 38] Printing page 1, 97%
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] [Job 38] ATTR: job-media-progress=97
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:33 +0900] [Job 38] Printing page 1, 98%
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] [Job 38] ATTR: job-media-progress=98
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 4096 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 4096 bytes of print data...
I [25/Jan/2011:22:50:33 +0900] [Job 38] Printing page 1, 99%
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] [Job 38] ATTR: job-media-progress=99
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
I [25/Jan/2011:22:50:33 +0900] [Job 38] Processing page 2...
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:33 +0900] [Job 38] Finished page 1...
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 2519 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 2519 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Gutenprint: Purging 1 rows
D [25/Jan/2011:22:50:33 +0900] [Job 38] Gutenprint: Done printing page 1
I [25/Jan/2011:22:50:33 +0900] [Job 38] Rendering completed
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] [Job 38] Gutenprint: Ending job
D [25/Jan/2011:22:50:33 +0900] [Job 38] Read 265 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Wrote 265 bytes of print data...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Gutenprint: Printed total 1014496 bytes
D [25/Jan/2011:22:50:33 +0900] [Job 38] Gutenprint: Used 19.800 seconds user, 0.820 seconds system, 28.604 seconds elapsed
D [25/Jan/2011:22:50:33 +0900] [Job 38] STATE: +connecting-to-device
D [25/Jan/2011:22:50:33 +0900] [Job 38] Looking up "10.0.1.4"...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Connecting to 10.0.1.4:515 for printer auto
I [25/Jan/2011:22:50:33 +0900] [Job 38] プリンターに接続中...
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] PID 9134 (/usr/local/lib/cups/filter/rastertogutenprint.5.2) exited with no errors.
D [25/Jan/2011:22:50:33 +0900] [Job 38] STATE: -connecting-to-device
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:33 +0900] [Job 38] プリンターに接続しました...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Connected to 10.0.1.4:515 (IPv4) (local port 1023)...
D [25/Jan/2011:22:50:33 +0900] [Job 38] lpd_command 02 auto
D [25/Jan/2011:22:50:33 +0900] [Job 38] Sending command string (6 bytes)...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Reading command status...
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] PID 9133 (/usr/local/lib/cups/filter/pstoraster) exited with no errors.
D [25/Jan/2011:22:50:33 +0900] [Job 38] lpd_command returning 0
D [25/Jan/2011:22:50:33 +0900] [Job 38] Control file is:
D [25/Jan/2011:22:50:33 +0900] [Job 38] Hvine5-imacg4.local
D [25/Jan/2011:22:50:33 +0900] [Job 38] Proot
D [25/Jan/2011:22:50:33 +0900] [Job 38] JTest Page
D [25/Jan/2011:22:50:33 +0900] [Job 38] ldfA136vine5-imacg4.lo
D [25/Jan/2011:22:50:33 +0900] [Job 38] UdfA136vine5-imacg4.lo
D [25/Jan/2011:22:50:33 +0900] [Job 38] NTest Page
D [25/Jan/2011:22:50:33 +0900] [Job 38] lpd_command 02 94 cfA136vine5-imacg4.lo
D [25/Jan/2011:22:50:33 +0900] [Job 38] Sending command string (26 bytes)...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Reading command status...
D [25/Jan/2011:22:50:33 +0900] [Job 38] lpd_command returning 0
I [25/Jan/2011:22:50:33 +0900] [Job 38] コントロールファイルを送信中 (94 バイト)
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:33 +0900] [Job 38] コントロールファイルが正常に送信されました
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:33 +0900] [Job 38] lpd_command 03 1014496 dfA136vine5-imacg4.lo
D [25/Jan/2011:22:50:33 +0900] [Job 38] Sending command string (31 bytes)...
D [25/Jan/2011:22:50:33 +0900] [Job 38] Reading command status...
D [25/Jan/2011:22:50:33 +0900] [Job 38] lpd_command returning 0
I [25/Jan/2011:22:50:33 +0900] [Job 38] データファイルを送信中 (1014496 バイト)
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:33 +0900] [Job 38] LPR ジョブをスプール中、0% 完了しました...
D [25/Jan/2011:22:50:33 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:33 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、3% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] Saving job cache file "/usr/local/var/cache/cups/job.cache"...
I [25/Jan/2011:22:50:34 +0900] Saving subscriptions.conf...
D [25/Jan/2011:22:50:34 +0900] cupsdSetBusyState: Printing jobs
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、6% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:34 +0900] cupsdSetBusyState: Printing jobs and dirty files
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、10% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、13% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、16% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、19% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、23% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、26% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、29% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、32% 完了しました...
D [25/Jan/2011:22:50:34 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:34 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:34 +0900] [Job 38] LPR ジョブをスプール中、36% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、39% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、42% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、45% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、48% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、52% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、55% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、58% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、61% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、65% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、68% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、71% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、74% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:35 +0900] [Job 38] LPR ジョブをスプール中、78% 完了しました...
D [25/Jan/2011:22:50:35 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:35 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] LPR ジョブをスプール中、81% 完了しました...
D [25/Jan/2011:22:50:36 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] LPR ジョブをスプール中、84% 完了しました...
D [25/Jan/2011:22:50:36 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] LPR ジョブをスプール中、87% 完了しました...
D [25/Jan/2011:22:50:36 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] LPR ジョブをスプール中、90% 完了しました...
D [25/Jan/2011:22:50:36 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] LPR ジョブをスプール中、94% 完了しました...
D [25/Jan/2011:22:50:36 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] LPR ジョブをスプール中、97% 完了しました...
D [25/Jan/2011:22:50:36 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] データファイルが正常に送信されました
D [25/Jan/2011:22:50:36 +0900] Discarding unused job-progress event...
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:36 +0900] PID 9136 (/usr/local/lib/cups/backend/dnssd) exited with no errors.
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
I [25/Jan/2011:22:50:36 +0900] [Job 38] Job completed.
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(----J-)
D [25/Jan/2011:22:50:36 +0900] cupsdMarkDirty(-----S)
D [25/Jan/2011:22:50:37 +0900] [Job 38] Unloading...
D [25/Jan/2011:22:50:37 +0900] Report: clients=1
D [25/Jan/2011:22:50:37 +0900] Report: jobs=23
D [25/Jan/2011:22:50:37 +0900] Report: jobs-active=0
D [25/Jan/2011:22:50:37 +0900] Report: printers=3
D [25/Jan/2011:22:50:37 +0900] Report: printers-implicit=0
D [25/Jan/2011:22:50:37 +0900] Report: stringpool-string-count=121027
D [25/Jan/2011:22:50:37 +0900] Report: stringpool-alloc-bytes=14936
D [25/Jan/2011:22:50:37 +0900] Report: stringpool-total-bytes=2272864
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 13 GET /printers/Canon_MG6100_series HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:40 +0900] [CGI] argv[0] = "/usr/local/lib/cups/cgi-bin/printers.cgi"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/usr/local/var/cache/cups"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/local/share/cups"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/local/share/doc/cups"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/local/share/cups/fonts"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/usr/local/var/spool/cups"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/local/lib/cups"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/usr/local/etc/cups"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/usr/local/var/run/cups"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[8] = "HOME=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[9] = "PATH=/usr/local/lib/cups/filter:/usr/local/bin:/usr/local/sbin:/bin:/usr/bin"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[10] = "SERVER_ADMIN=root at vine5-imacg4.local"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.6"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[12] = "TMPDIR=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[13] = "TZ=Asia/Tokyo"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[14] = "USER=root"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[15] = "CUPS_SERVER=/usr/local/var/run/cups/cups.sock"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[17] = "IPP_PORT=631"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[19] = "LANG=ja.UTF8"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[22] = "SERVER_NAME=localhost"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[23] = "SERVER_PORT=631"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[26] = "SCRIPT_NAME=/printers/Canon_MG6100_series"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/local/share/doc/cups/printers/Canon_MG6100_series"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[28] = "PATH_INFO=/Canon_MG6100_series"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[29] = "REMOTE_USER=root"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; U; Linux ppc; ja; rv:1.9.1.15) Gecko/20101031 Vine/3.5.15-1vl5 Firefox/3.5.15"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [25/Jan/2011:22:50:40 +0900] [CGI] envp[34] = "QUERY_STRING="
D [25/Jan/2011:22:50:40 +0900] [CGI] Started /usr/local/lib/cups/cgi-bin/printers.cgi (PID 9146)
I [25/Jan/2011:22:50:40 +0900] Started "/usr/local/lib/cups/cgi-bin/printers.cgi" (pid=9146)
D [25/Jan/2011:22:50:40 +0900] cupsdSendCommand: 13 file=16
D [25/Jan/2011:22:50:40 +0900] [CGI] org.cups.sid cookie is "dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:40 +0900] cupsdAcceptClient: 18 from localhost (Domain)
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 18 1.1 CUPS-Get-Default 1
D [25/Jan/2011:22:50:40 +0900] CUPS-Get-Default
D [25/Jan/2011:22:50:40 +0900] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [25/Jan/2011:22:50:40 +0900] [CGI] show_printer(http=0x200208c0, printer="Canon_MG6100_series")
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 18 1.1 Get-Printer-Attributes 1
D [25/Jan/2011:22:50:40 +0900] Get-Printer-Attributes ipp://localhost/printers/Canon_MG6100_series
D [25/Jan/2011:22:50:40 +0900] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MG6100_series) from localhost
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:40 +0900] Script header: Content-Type: text/html;charset=utf-8
D [25/Jan/2011:22:50:40 +0900] Script header:
D [25/Jan/2011:22:50:40 +0900] [CGI] Regular expression ".*Clean.*"
D [25/Jan/2011:22:50:40 +0900] [CGI] Regular expression ".*PrintSelfTestPage.*"
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 18 1.1 Get-Jobs 1
D [25/Jan/2011:22:50:40 +0900] Get-Jobs ipp://localhost:631/printers/Canon_MG6100_series
D [25/Jan/2011:22:50:40 +0900] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_MG6100_series) from localhost
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 18 WAITING Closing on EOF
D [25/Jan/2011:22:50:40 +0900] cupsdCloseClient: 18
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Dirty files
D [25/Jan/2011:22:50:40 +0900] PID 9146 (/usr/local/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 13 GET /cups.css HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 13 GET /images/left.gif HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 13 GET /images/right.gif HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 13 GET /images/unsel.gif HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdReadClient: 13 GET /images/sel.gif HTTP/1.1
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:40 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:40 +0900] cupsdSetBusyState: Dirty files
D [25/Jan/2011:22:50:52 +0900] cupsdNetIFUpdate: "lo" = localhost:631
D [25/Jan/2011:22:50:52 +0900] cupsdNetIFUpdate: "wlan0" = 10.0.1.3:0
D [25/Jan/2011:22:50:52 +0900] cupsdNetIFUpdate: "lo" = localhost:631
D [25/Jan/2011:22:50:52 +0900] cupsdNetIFUpdate: "wlan0" = fe80::211:24ff:fea7:d86e%wlan0:0
D [25/Jan/2011:22:50:52 +0900] process_browse_data: Canon_MG6100_series__0635B5C6A06D at 10.0.1.9 not found...
D [25/Jan/2011:22:50:55 +0900] cupsdReadClient: 13 GET /admin HTTP/1.1
D [25/Jan/2011:22:50:55 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:55 +0900] cupsdAuthorize: Authorized as root using Basic
D [25/Jan/2011:22:50:55 +0900] [CGI] argv[0] = "/usr/local/lib/cups/cgi-bin/admin.cgi"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[0] = "CUPS_CACHEDIR=/usr/local/var/cache/cups"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[1] = "CUPS_DATADIR=/usr/local/share/cups"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[2] = "CUPS_DOCROOT=/usr/local/share/doc/cups"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[3] = "CUPS_FONTPATH=/usr/local/share/cups/fonts"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[4] = "CUPS_REQUESTROOT=/usr/local/var/spool/cups"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/local/lib/cups"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[6] = "CUPS_SERVERROOT=/usr/local/etc/cups"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[7] = "CUPS_STATEDIR=/usr/local/var/run/cups"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[8] = "HOME=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[9] = "PATH=/usr/local/lib/cups/filter:/usr/local/bin:/usr/local/sbin:/bin:/usr/bin"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[10] = "SERVER_ADMIN=root at vine5-imacg4.local"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.6"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[12] = "TMPDIR=/usr/local/var/spool/cups/tmp"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[13] = "TZ=Asia/Tokyo"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[14] = "USER=root"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[15] = "CUPS_SERVER=/usr/local/var/run/cups/cups.sock"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[17] = "IPP_PORT=631"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[19] = "LANG=ja.UTF8"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[22] = "SERVER_NAME=localhost"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[23] = "SERVER_PORT=631"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[24] = "REMOTE_ADDR=127.0.0.1"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[26] = "SCRIPT_NAME=/admin"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/local/share/doc/cups/admin"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[28] = "REMOTE_USER=root"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[30] = "HTTP_COOKIE=org.cups.sid=dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; U; Linux ppc; ja; rv:1.9.1.15) Gecko/20101031 Vine/3.5.15-1vl5 Firefox/3.5.15"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[32] = "HTTP_REFERER=http://localhost:631/printers/Canon_MG6100_series"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [25/Jan/2011:22:50:55 +0900] [CGI] envp[34] = "QUERY_STRING="
D [25/Jan/2011:22:50:55 +0900] [CGI] Started /usr/local/lib/cups/cgi-bin/admin.cgi (PID 9147)
I [25/Jan/2011:22:50:55 +0900] Started "/usr/local/lib/cups/cgi-bin/admin.cgi" (pid=9147)
D [25/Jan/2011:22:50:55 +0900] cupsdSendCommand: 13 file=16
D [25/Jan/2011:22:50:55 +0900] [CGI] admin.cgi started...
D [25/Jan/2011:22:50:55 +0900] cupsdAcceptClient: 18 from localhost (Domain)
D [25/Jan/2011:22:50:55 +0900] [CGI] http=0x2002a918
D [25/Jan/2011:22:50:55 +0900] [CGI] org.cups.sid cookie is "dd1df8493e4af048de3dd7d5cc0df761"
D [25/Jan/2011:22:50:55 +0900] [CGI] No form data, showing main menu...
D [25/Jan/2011:22:50:55 +0900] [CGI] /usr/local/share/cups/drivers/pscript5.dll: No such file or directory
D [25/Jan/2011:22:50:55 +0900] cupsdReadClient: 18 POST / HTTP/1.1
D [25/Jan/2011:22:50:55 +0900] cupsdAuthorize: No authentication data provided.
D [25/Jan/2011:22:50:55 +0900] cupsdReadClient: 18 1.1 Get-Subscriptions 1
D [25/Jan/2011:22:50:55 +0900] Get-Subscriptions ipp://localhost/
D [25/Jan/2011:22:50:55 +0900] Returning IPP successful-ok for Get-Subscriptions (ipp://localhost/) from localhost
D [25/Jan/2011:22:50:55 +0900] Script header: Content-Type: text/html;charset=utf-8
D [25/Jan/2011:22:50:55 +0900] Script header:
D [25/Jan/2011:22:50:56 +0900] cupsdReadClient: 18 WAITING Closing on EOF
D [25/Jan/2011:22:50:56 +0900] cupsdCloseClient: 18
D [25/Jan/2011:22:50:56 +0900] cupsdSetBusyState: Dirty files
D [25/Jan/2011:22:50:56 +0900] PID 9147 (/usr/local/lib/cups/cgi-bin/admin.cgi) exited with no errors.
D [25/Jan/2011:22:50:59 +0900] cupsdReadClient: 13 GET /admin/log/error_log HTTP/1.1
D [25/Jan/2011:22:50:59 +0900] cupsdSetBusyState: Active clients and dirty files
D [25/Jan/2011:22:50:59 +0900] cupsdAuthorize: Authorized as root using Basic