D [27/Aug/2011:14:12:20 +0200] cupsdAcceptClient: 13 from localhost (Domain)
D [27/Aug/2011:14:12:20 +0200] cupsdReadClient: 13 POST / HTTP/1.1
D [27/Aug/2011:14:12:20 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:12:20 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:20 +0200] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [27/Aug/2011:14:12:20 +0200] CUPS-Get-Printers
D [27/Aug/2011:14:12:20 +0200] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [27/Aug/2011:14:12:20 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:12:20 +0200] cupsdReadClient: 13 POST / HTTP/1.1
D [27/Aug/2011:14:12:20 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:12:20 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:20 +0200] cupsdReadClient: 13 1.1 CUPS-Get-Default 1
D [27/Aug/2011:14:12:20 +0200] CUPS-Get-Default
D [27/Aug/2011:14:12:20 +0200] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [27/Aug/2011:14:12:20 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:12:21 +0200] Report: clients=1
D [27/Aug/2011:14:12:21 +0200] Report: jobs=2
D [27/Aug/2011:14:12:21 +0200] Report: jobs-active=1
D [27/Aug/2011:14:12:21 +0200] Report: printers=1
D [27/Aug/2011:14:12:21 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:12:21 +0200] Report: stringpool-string-count=476
D [27/Aug/2011:14:12:21 +0200] Report: stringpool-alloc-bytes=8152
D [27/Aug/2011:14:12:21 +0200] Report: stringpool-total-bytes=10464
D [27/Aug/2011:14:12:23 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:12:23 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:12:23 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:12:23 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:12:38 +0200] cupsdReadClient: 13 POST / HTTP/1.1
D [27/Aug/2011:14:12:38 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:12:38 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:38 +0200] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [27/Aug/2011:14:12:38 +0200] CUPS-Get-Printers
D [27/Aug/2011:14:12:38 +0200] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [27/Aug/2011:14:12:38 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:12:38 +0200] cupsdReadClient: 13 POST / HTTP/1.1
D [27/Aug/2011:14:12:38 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:12:38 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:38 +0200] cupsdReadClient: 13 1.1 CUPS-Get-Default 1
D [27/Aug/2011:14:12:38 +0200] CUPS-Get-Default
D [27/Aug/2011:14:12:38 +0200] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [27/Aug/2011:14:12:38 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:12:40 +0200] cupsdReadClient: 13 POST /printers/BJ-5 HTTP/1.1
D [27/Aug/2011:14:12:40 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:12:40 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:40 +0200] cupsdReadClient: 13 1.1 Create-Job 1
D [27/Aug/2011:14:12:40 +0200] Create-Job ipp://localhost:631/printers/BJ-5
D [27/Aug/2011:14:12:40 +0200] cupsdMarkDirty(----J-)
D [27/Aug/2011:14:12:40 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:40 +0200] add_job: requesting-user-name="per"
D [27/Aug/2011:14:12:40 +0200] Adding default job-sheets values "none,none"...
I [27/Aug/2011:14:12:40 +0200] [Job 96] Adding start banner page "none".
D [27/Aug/2011:14:12:40 +0200] cupsdMarkDirty(-----S)
I [27/Aug/2011:14:12:40 +0200] [Job 96] Queued on "BJ-5" by "per".
D [27/Aug/2011:14:12:40 +0200] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/BJ-5) from localhost
D [27/Aug/2011:14:12:40 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:40 +0200] cupsdReadClient: 13 POST /printers/BJ-5 HTTP/1.1
D [27/Aug/2011:14:12:40 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:40 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:40 +0200] cupsdReadClient: 13 1.1 Send-Document 1
D [27/Aug/2011:14:12:40 +0200] Send-Document ipp://localhost:631/printers/BJ-5
D [27/Aug/2011:14:12:40 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:40 +0200] [Job 96] Auto-typing file...
D [27/Aug/2011:14:12:40 +0200] [Job 96] Request file type is application/postscript.
D [27/Aug/2011:14:12:40 +0200] cupsdMarkDirty(----J-)
I [27/Aug/2011:14:12:40 +0200] [Job 96] File of type application/postscript queued by "per".
I [27/Aug/2011:14:12:40 +0200] [Job 96] Adding end banner page "none".
D [27/Aug/2011:14:12:40 +0200] cupsdMarkDirty(----J-)
D [27/Aug/2011:14:12:40 +0200] cupsdMarkDirty(----J-)
D [27/Aug/2011:14:12:40 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:40 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:40 +0200] [Job 96] job-sheets=none,none
D [27/Aug/2011:14:12:40 +0200] [Job 96] argv[0]="BJ-5"
D [27/Aug/2011:14:12:40 +0200] [Job 96] argv[1]="96"
D [27/Aug/2011:14:12:40 +0200] [Job 96] argv[2]="per"
D [27/Aug/2011:14:12:40 +0200] [Job 96] argv[3]="Navnløs1"
D [27/Aug/2011:14:12:40 +0200] [Job 96] argv[4]="1"
D [27/Aug/2011:14:12:40 +0200] [Job 96] argv[5]="PageSize=A4 job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97 job-originating-host-name=localhost time-at-creation=1314447160 time-at-processing=1314447160 AP_D_InputSlot="
D [27/Aug/2011:14:12:40 +0200] [Job 96] argv[6]="/var/spool/cups/d00096-001"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[8]="HOME=/var/spool/cups/tmp"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[10]="SERVER_ADMIN=root@per-loftstova"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[11]="SOFTWARE=CUPS/1.4.6"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[13]="USER=root"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[16]="IPP_PORT=631"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[17]="CHARSET=utf-8"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[18]="LANG=no_NO.UTF-8"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[19]="PPD=/etc/cups/ppd/BJ-5.ppd"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[20]="RIP_MAX_CACHE=auto"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[21]="CONTENT_TYPE=application/postscript"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[22]="DEVICE_URI=cnijnet:/00-1E-8F-A3-4C-0F"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[23]="PRINTER_INFO=BJ-5"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[24]="PRINTER_LOCATION=per-loftstova"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[25]="PRINTER=BJ-5"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[26]="CUPS_FILETYPE=document"
D [27/Aug/2011:14:12:40 +0200] [Job 96] envp[27]="FINAL_CONTENT_TYPE=printer/BJ-5"
I [27/Aug/2011:14:12:40 +0200] [Job 96] Started filter /usr/lib/cups/filter/pstopdf (PID 30119)
I [27/Aug/2011:14:12:40 +0200] [Job 96] Started filter /usr/lib/cups/filter/pdftopdf (PID 30120)
I [27/Aug/2011:14:12:40 +0200] [Job 96] Started filter /usr/lib/cups/filter/foomatic-rip (PID 30121)
I [27/Aug/2011:14:12:40 +0200] [Job 96] Started backend /usr/lib/cups/backend/cnijnet (PID 30122)
D [27/Aug/2011:14:12:40 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:40 +0200] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/BJ-5) from localhost
D [27/Aug/2011:14:12:40 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:40 +0200] [Job 96] pstopdf 6 args: 96 per Navnløs1 1 PageSize=A4 job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97 job-originating-host-name=localhost time-at-creation=1314447160 time-at-processing=1314447160 AP_D_InputSlot= /var/spool/cups/d00096-001
D [27/Aug/2011:14:12:40 +0200] [Job 96] PPD: /etc/cups/ppd/BJ-5.ppd
D [27/Aug/2011:14:12:40 +0200] [Job 96] Resolution: 360x360
D [27/Aug/2011:14:12:40 +0200] [Job 96] Page size: A4
D [27/Aug/2011:14:12:40 +0200] [Job 96] Width: 595, height: 842, absolute margins: 18, 36, 577, 806
D [27/Aug/2011:14:12:41 +0200] [Job 96] Getting input from file 
D [27/Aug/2011:14:12:41 +0200] [Job 96] foomatic-rip version 4.0.7.235 running...
D [27/Aug/2011:14:12:41 +0200] [Job 96] Parsing PPD file ...
D [27/Aug/2011:14:12:41 +0200] [Job 96] Added option PageSize
D [27/Aug/2011:14:12:41 +0200] [Job 96] Added option ImageableArea
D [27/Aug/2011:14:12:41 +0200] [Job 96] Added option PaperDimension
D [27/Aug/2011:14:12:41 +0200] [Job 96] Added option Resolution
D [27/Aug/2011:14:12:41 +0200] [Job 96] Added option Font
D [27/Aug/2011:14:12:41 +0200] [Job 96] 
D [27/Aug/2011:14:12:41 +0200] [Job 96] Parameter Summary
D [27/Aug/2011:14:12:41 +0200] [Job 96] -----------------
D [27/Aug/2011:14:12:41 +0200] [Job 96] 
D [27/Aug/2011:14:12:41 +0200] [Job 96] Spooler: cups
D [27/Aug/2011:14:12:41 +0200] [Job 96] Printer: BJ-5
D [27/Aug/2011:14:12:41 +0200] [Job 96] Shell: /bin/bash
D [27/Aug/2011:14:12:41 +0200] [Job 96] PPD file: /etc/cups/ppd/BJ-5.ppd
D [27/Aug/2011:14:12:41 +0200] [Job 96] ATTR file: 
D [27/Aug/2011:14:12:41 +0200] [Job 96] Printer model: Canon BJ-5 Foomatic/bj10e (recommended)
D [27/Aug/2011:14:12:41 +0200] [Job 96] Job title: Navnløs1
D [27/Aug/2011:14:12:41 +0200] [Job 96] File(s) to be printed:
D [27/Aug/2011:14:12:41 +0200] [Job 96] <STDIN>
D [27/Aug/2011:14:12:41 +0200] [Job 96] 
D [27/Aug/2011:14:12:41 +0200] [Job 96] Ghostscript extra search path ('GS_LIB'): /usr/share/cups/fonts
D [27/Aug/2011:14:12:41 +0200] [Job 96] Printing system options:
D [27/Aug/2011:14:12:41 +0200] [Job 96] Pondering option 'job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97'
D [27/Aug/2011:14:12:41 +0200] [Job 96] Unknown option job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97.
D [27/Aug/2011:14:12:41 +0200] [Job 96] Pondering option 'job-originating-host-name=localhost'
D [27/Aug/2011:14:12:41 +0200] [Job 96] Unknown option job-originating-host-name=localhost.
D [27/Aug/2011:14:12:41 +0200] [Job 96] Pondering option 'time-at-creation=1314447160'
D [27/Aug/2011:14:12:41 +0200] [Job 96] Unknown option time-at-creation=1314447160.
D [27/Aug/2011:14:12:41 +0200] [Job 96] Pondering option 'time-at-processing=1314447160'
D [27/Aug/2011:14:12:41 +0200] [Job 96] Unknown option time-at-processing=1314447160.
D [27/Aug/2011:14:12:41 +0200] [Job 96] Pondering option 'AP_D_InputSlot='
D [27/Aug/2011:14:12:41 +0200] [Job 96] Unknown option AP_D_InputSlot=.
D [27/Aug/2011:14:12:41 +0200] [Job 96] Options from the PPD file:
D [27/Aug/2011:14:12:41 +0200] [Job 96] Pondering option 'PageSize=A4'
D [27/Aug/2011:14:12:41 +0200] [Job 96] 
D [27/Aug/2011:14:12:41 +0200] [Job 96] ================================================
D [27/Aug/2011:14:12:41 +0200] [Job 96] 
D [27/Aug/2011:14:12:41 +0200] [Job 96] File: <STDIN>
D [27/Aug/2011:14:12:41 +0200] [Job 96] 
D [27/Aug/2011:14:12:41 +0200] [Job 96] ================================================
D [27/Aug/2011:14:12:41 +0200] [Job 96] 
D [27/Aug/2011:14:12:41 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 1.1 Get-Notifications 1
D [27/Aug/2011:14:12:41 +0200] Get-Notifications /
D [27/Aug/2011:14:12:41 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:41 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 1.1 Get-Job-Attributes 1
D [27/Aug/2011:14:12:41 +0200] Get-Job-Attributes ipp://localhost/jobs/96
D [27/Aug/2011:14:12:41 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/96) from localhost
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 17 1.1 Get-Printer-Attributes 1
D [27/Aug/2011:14:12:41 +0200] Get-Printer-Attributes ipp://per-loftstova:631/printers/BJ-5
D [27/Aug/2011:14:12:41 +0200] Returning IPP successful-ok for Get-Printer-Attributes (ipp://per-loftstova:631/printers/BJ-5) from localhost
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 17 WAITING Closing on EOF
D [27/Aug/2011:14:12:41 +0200] cupsdCloseClient: 17
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:12:41 +0200] cupsdCloseClient: 16
D [27/Aug/2011:14:12:41 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 1.1 Get-Notifications 1
D [27/Aug/2011:14:12:41 +0200] Get-Notifications /
D [27/Aug/2011:14:12:41 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:41 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:12:41 +0200] cupsdCloseClient: 16
D [27/Aug/2011:14:12:41 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 1.1 Get-Notifications 1
D [27/Aug/2011:14:12:41 +0200] Get-Notifications /
D [27/Aug/2011:14:12:41 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:41 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:12:41 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:41 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:12:41 +0200] cupsdCloseClient: 16
D [27/Aug/2011:14:12:41 +0200] [Job 96] Relative margins: 18, 36, 18, 36
D [27/Aug/2011:14:12:41 +0200] [Job 96] PPD options: -r360 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842
D [27/Aug/2011:14:12:41 +0200] [Job 96] PostScript to be injected: 
D [27/Aug/2011:14:12:41 +0200] [Job 96] Running cat | /usr/bin/gs -q -dNOPAUSE -dBATCH -sDEVICE=pdfwrite -dCompatibilityLevel=1.3 -dAutoRotatePages=/None -dAutoFilterColorImages=false                -dNOPLATFONTS -dPARANOIDSAFER -sstdout=%stderr -dColorImageFilter=/FlateEncode                 -dPDFSETTINGS=/printer                 -dColorConversionStrategy=/LeaveColorUnchanged -dDoNumCopies -r360 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sOutputFile=-  -c .setpdfwrite -f -
I [27/Aug/2011:14:12:41 +0200] [Job 96] 
I [27/Aug/2011:14:12:42 +0200] [Job 96] 
E [27/Aug/2011:14:12:42 +0200] [Job 96] cannot load library
D [27/Aug/2011:14:12:42 +0200] [Job 96] Set job-printer-state-message to "cannot load library", current level=ERROR
D [27/Aug/2011:14:12:42 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:42 +0200] cupsdMarkDirty(-----S)
I [27/Aug/2011:14:12:42 +0200] [Job 96] 
D [27/Aug/2011:14:12:42 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:42 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:42 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:12:42 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:42 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:42 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:42 +0200] cupsdReadClient: 16 1.1 Get-Notifications 1
D [27/Aug/2011:14:12:42 +0200] Get-Notifications /
D [27/Aug/2011:14:12:42 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:42 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:12:42 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:42 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:12:42 +0200] cupsdCloseClient: 16
D [27/Aug/2011:14:12:42 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:12:42 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:42 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:12:42 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:42 +0200] cupsdReadClient: 16 1.1 Get-Notifications 1
D [27/Aug/2011:14:12:42 +0200] Get-Notifications /
D [27/Aug/2011:14:12:42 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:42 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:12:42 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:12:42 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:12:42 +0200] cupsdCloseClient: 16
D [27/Aug/2011:14:12:42 +0200] PID 30119 (/usr/lib/cups/filter/pstopdf) exited with no errors.
D [27/Aug/2011:14:12:42 +0200] [Job 96] Filetype: PDF
D [27/Aug/2011:14:12:42 +0200] [Job 96] Storing temporary files in /var/spool/cups/tmp
D [27/Aug/2011:14:12:42 +0200] PID 30120 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [27/Aug/2011:14:12:42 +0200] [Job 96] File contains 1 pages
D [27/Aug/2011:14:12:42 +0200] [Job 96] Starting renderer with command: gs -dFirstPage=1  -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=bj10e -r360x360 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sOutputFile=-   /var/spool/cups/tmp/foomatic-jX7fAh 
D [27/Aug/2011:14:12:42 +0200] [Job 96] Starting process "kid3" (generation 1)
D [27/Aug/2011:14:12:42 +0200] [Job 96] Starting process "kid4" (generation 2)
D [27/Aug/2011:14:12:42 +0200] [Job 96] Starting process "renderer" (generation 2)
D [27/Aug/2011:14:12:42 +0200] [Job 96] JCL: %-12345X@PJL
D [27/Aug/2011:14:12:42 +0200] [Job 96] <job data> 
D [27/Aug/2011:14:12:42 +0200] [Job 96] 
D [27/Aug/2011:14:12:42 +0200] [Job 96] renderer exited with status 0
D [27/Aug/2011:14:12:42 +0200] [Job 96] kid4 exited with status 0
D [27/Aug/2011:14:12:42 +0200] [Job 96] kid3 finished
D [27/Aug/2011:14:12:42 +0200] [Job 96] Kid3 exit status: 0
D [27/Aug/2011:14:12:42 +0200] [Job 96] 
D [27/Aug/2011:14:12:42 +0200] [Job 96] Closing foomatic-rip.
D [27/Aug/2011:14:12:42 +0200] PID 30121 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
D [27/Aug/2011:14:12:43 +0200] PID 30122 (/usr/lib/cups/backend/cnijnet) stopped with status 1!
I [27/Aug/2011:14:12:43 +0200] [Job 96] Backend returned status 1 (failed)
D [27/Aug/2011:14:12:43 +0200] set_hold_until: hold_until = 1314447463
D [27/Aug/2011:14:12:43 +0200] cupsdMarkDirty(----J-)
D [27/Aug/2011:14:12:43 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:43 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [27/Aug/2011:14:12:43 +0200] cupsdReadClient: 15 POST / HTTP/1.1
D [27/Aug/2011:14:12:43 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:43 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:43 +0200] cupsdReadClient: 15 1.1 Get-Notifications 1
D [27/Aug/2011:14:12:43 +0200] Get-Notifications /
D [27/Aug/2011:14:12:43 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:43 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:12:43 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:43 +0200] cupsdReadClient: 15 WAITING Closing on EOF
D [27/Aug/2011:14:12:43 +0200] cupsdCloseClient: 15
D [27/Aug/2011:14:12:53 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 15 POST /jobs/ HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 15 1.1 Cancel-Job 1
D [27/Aug/2011:14:12:53 +0200] Cancel-Job ipp://localhost/jobs/95
D [27/Aug/2011:14:12:53 +0200] cupsdMarkDirty(-----S)
I [27/Aug/2011:14:12:53 +0200] [Job 95] Job canceled by "per"
D [27/Aug/2011:14:12:53 +0200] cupsdMarkDirty(----J-)
I [27/Aug/2011:14:12:53 +0200] [Job 95] Canceled by "per".
D [27/Aug/2011:14:12:53 +0200] Returning IPP successful-ok for Cancel-Job (ipp://localhost/jobs/95) from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 1.1 Cancel-Subscription 1
D [27/Aug/2011:14:12:53 +0200] Cancel-Subscription /
D [27/Aug/2011:14:12:53 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:53 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:53 +0200] Returning IPP successful-ok for Cancel-Subscription (/) from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 1.1 Create-Printer-Subscription 1
D [27/Aug/2011:14:12:53 +0200] Create-Printer-Subscription /
D [27/Aug/2011:14:12:53 +0200] cupsdCreateSubscription(con=0x7fd8f886c090(16), uri="/")
D [27/Aug/2011:14:12:53 +0200] pullmethod="ippget"
D [27/Aug/2011:14:12:53 +0200] notify-lease-duration=86400
D [27/Aug/2011:14:12:53 +0200] notify-time-interval=0
D [27/Aug/2011:14:12:53 +0200] cupsdAddSubscription(mask=1798f, dest=(nil)(), job=(nil)(0), uri="(null)")
D [27/Aug/2011:14:12:53 +0200] Added subscription 111 for server
D [27/Aug/2011:14:12:53 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:12:53 +0200] Returning IPP successful-ok for Create-Printer-Subscription (/) from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 1.1 Get-Jobs 1
D [27/Aug/2011:14:12:53 +0200] Get-Jobs ipp://localhost/printers/
D [27/Aug/2011:14:12:53 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 1.1 CUPS-Get-Printers 1
D [27/Aug/2011:14:12:53 +0200] CUPS-Get-Printers
D [27/Aug/2011:14:12:53 +0200] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 1.1 CUPS-Get-Printers 1
D [27/Aug/2011:14:12:53 +0200] CUPS-Get-Printers
D [27/Aug/2011:14:12:53 +0200] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 17 1.1 Get-Printer-Attributes 1
D [27/Aug/2011:14:12:53 +0200] Get-Printer-Attributes 
D [27/Aug/2011:14:12:53 +0200] Get-Printer-Attributes client-error-not-found: The printer or class was not found.
D [27/Aug/2011:14:12:53 +0200] Returning IPP client-error-not-found for Get-Printer-Attributes () from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 18 1.1 Get-Job-Attributes 1
D [27/Aug/2011:14:12:53 +0200] Get-Job-Attributes ipp://localhost/jobs/96
D [27/Aug/2011:14:12:53 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/96) from localhost
D [27/Aug/2011:14:12:53 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 17 WAITING Closing on EOF
D [27/Aug/2011:14:12:53 +0200] cupsdCloseClient: 17
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:12:53 +0200] cupsdCloseClient: 16
D [27/Aug/2011:14:12:53 +0200] cupsdReadClient: 18 WAITING Closing on EOF
D [27/Aug/2011:14:12:53 +0200] cupsdCloseClient: 18
D [27/Aug/2011:14:12:54 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:12:54 +0200] [Job 95] Unloading...
D [27/Aug/2011:14:12:54 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:12:54 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:12:54 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:12:54 +0200] cupsdReadClient: 16 1.1 Get-Notifications 1
D [27/Aug/2011:14:12:54 +0200] Get-Notifications /
D [27/Aug/2011:14:12:54 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:12:54 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:12:54 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:12:54 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:12:54 +0200] cupsdCloseClient: 16
I [27/Aug/2011:14:13:11 +0200] Saving job cache file "/var/cache/cups/job.cache"...
I [27/Aug/2011:14:13:11 +0200] Saving subscriptions.conf...
D [27/Aug/2011:14:13:11 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:13:12 +0200] cupsdAcceptClient: 16 from localhost:631 (IPv4)
D [27/Aug/2011:14:13:12 +0200] cupsdReadClient: 16 GET /printers/ HTTP/1.1
D [27/Aug/2011:14:13:12 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:13:12 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:13:12 +0200] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[10] = "SERVER_ADMIN=root@per-loftstova"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.6"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[13] = "USER=root"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[14] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[15] = "CUPS_ENCRYPTION=IfRequested"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[16] = "IPP_PORT=631"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[17] = "LANG=nb_NO.UTF8"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[18] = "REDIRECT_STATUS=1"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[19] = "GATEWAY_INTERFACE=CGI/1.1"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[20] = "SERVER_NAME=localhost"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[21] = "SERVER_PORT=631"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[22] = "REMOTE_ADDR=127.0.0.1"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[23] = "REMOTE_HOST=localhost"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[24] = "SCRIPT_NAME=/printers/"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[25] = "SCRIPT_FILENAME=/usr/share/cups/doc-root/printers/"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[26] = "SERVER_PROTOCOL=HTTP/1.1"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[27] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:6.0) Gecko/20100101 Firefox/6.0"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[28] = "HTTP_REFERER=http://localhost:631/"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[29] = "REQUEST_METHOD=GET"
D [27/Aug/2011:14:13:12 +0200] [CGI] envp[30] = "QUERY_STRING="
D [27/Aug/2011:14:13:12 +0200] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 30641)
I [27/Aug/2011:14:13:12 +0200] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=30641)
D [27/Aug/2011:14:13:12 +0200] cupsdSendCommand: 16 file=17
D [27/Aug/2011:14:13:12 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [27/Aug/2011:14:13:12 +0200] [CGI] org.cups.sid cookie not found, initializing!
D [27/Aug/2011:14:13:12 +0200] [CGI] org.cups.sid cookie is "1a32e46c8664b71fc4fde6416d10641a"
D [27/Aug/2011:14:13:12 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [27/Aug/2011:14:13:12 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:13:12 +0200] cupsdReadClient: 18 1.1 CUPS-Get-Default 1
D [27/Aug/2011:14:13:12 +0200] CUPS-Get-Default
D [27/Aug/2011:14:13:12 +0200] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [27/Aug/2011:14:13:12 +0200] [CGI] show_all_printers(http=0x7f498b739490, user="(null)")
D [27/Aug/2011:14:13:12 +0200] Script header: Set-Cookie: org.cups.sid=1a32e46c8664b71fc4fde6416d10641a;; path=/;
D [27/Aug/2011:14:13:12 +0200] Script header: Content-Type: text/html;charset=utf-8
D [27/Aug/2011:14:13:12 +0200] Script header: 
D [27/Aug/2011:14:13:12 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [27/Aug/2011:14:13:12 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:13:12 +0200] cupsdReadClient: 18 1.1 CUPS-Get-Printers 1
D [27/Aug/2011:14:13:12 +0200] CUPS-Get-Printers
D [27/Aug/2011:14:13:12 +0200] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [27/Aug/2011:14:13:12 +0200] cupsdReadClient: 18 WAITING Closing on EOF
D [27/Aug/2011:14:13:12 +0200] cupsdCloseClient: 18
D [27/Aug/2011:14:13:12 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:13:12 +0200] PID 30641 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [27/Aug/2011:14:13:16 +0200] cupsdReadClient: 16 GET /jobs/ HTTP/1.1
D [27/Aug/2011:14:13:16 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:13:16 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:13:16 +0200] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/jobs.cgi"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[10] = "SERVER_ADMIN=root@per-loftstova"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[11] = "SOFTWARE=CUPS/1.4.6"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[13] = "USER=root"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[14] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[15] = "CUPS_ENCRYPTION=IfRequested"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[16] = "IPP_PORT=631"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[17] = "LANG=nb_NO.UTF8"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[18] = "REDIRECT_STATUS=1"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[19] = "GATEWAY_INTERFACE=CGI/1.1"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[20] = "SERVER_NAME=localhost"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[21] = "SERVER_PORT=631"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[22] = "REMOTE_ADDR=127.0.0.1"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[23] = "REMOTE_HOST=localhost"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[24] = "SCRIPT_NAME=/jobs/"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[25] = "SCRIPT_FILENAME=/usr/share/cups/doc-root/jobs/"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[26] = "SERVER_PROTOCOL=HTTP/1.1"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[27] = "HTTP_COOKIE=org.cups.sid=1a32e46c8664b71fc4fde6416d10641a"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[28] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:6.0) Gecko/20100101 Firefox/6.0"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[29] = "HTTP_REFERER=http://localhost:631/printers/"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[30] = "REQUEST_METHOD=GET"
D [27/Aug/2011:14:13:16 +0200] [CGI] envp[31] = "QUERY_STRING="
D [27/Aug/2011:14:13:16 +0200] [CGI] Started /usr/lib/cups/cgi-bin/jobs.cgi (PID 30719)
I [27/Aug/2011:14:13:16 +0200] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=30719)
D [27/Aug/2011:14:13:16 +0200] cupsdSendCommand: 16 file=17
D [27/Aug/2011:14:13:16 +0200] [CGI] org.cups.sid cookie is "1a32e46c8664b71fc4fde6416d10641a"
D [27/Aug/2011:14:13:16 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [27/Aug/2011:14:13:16 +0200] Script header: Content-Type: text/html;charset=utf-8
D [27/Aug/2011:14:13:16 +0200] Script header: 
D [27/Aug/2011:14:13:16 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [27/Aug/2011:14:13:16 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:13:16 +0200] cupsdReadClient: 18 1.1 Get-Jobs 1
D [27/Aug/2011:14:13:16 +0200] Get-Jobs ipp://localhost/
D [27/Aug/2011:14:13:16 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost
D [27/Aug/2011:14:13:16 +0200] cupsdReadClient: 18 WAITING Closing on EOF
D [27/Aug/2011:14:13:16 +0200] cupsdCloseClient: 18
D [27/Aug/2011:14:13:16 +0200] PID 30719 (/usr/lib/cups/cgi-bin/jobs.cgi) exited with no errors.
D [27/Aug/2011:14:13:16 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:13:46 +0200] cupsdReadClient: 16 WAITING Closing on EOF
D [27/Aug/2011:14:13:46 +0200] cupsdCloseClient: 16
D [27/Aug/2011:14:13:46 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:13:46 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:13:46 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:13:46 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:13:46 +0200] Report: clients=2
D [27/Aug/2011:14:13:46 +0200] Report: jobs=3
D [27/Aug/2011:14:13:46 +0200] Report: jobs-active=1
D [27/Aug/2011:14:13:46 +0200] Report: printers=1
D [27/Aug/2011:14:13:46 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:13:46 +0200] Report: stringpool-string-count=874
D [27/Aug/2011:14:13:46 +0200] Report: stringpool-alloc-bytes=9024
D [27/Aug/2011:14:13:46 +0200] Report: stringpool-total-bytes=18464
D [27/Aug/2011:14:14:48 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:14:48 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:14:48 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:14:48 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:14:48 +0200] Report: clients=2
D [27/Aug/2011:14:14:48 +0200] Report: jobs=3
D [27/Aug/2011:14:14:48 +0200] Report: jobs-active=1
D [27/Aug/2011:14:14:48 +0200] Report: printers=1
D [27/Aug/2011:14:14:48 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:14:48 +0200] Report: stringpool-string-count=874
D [27/Aug/2011:14:14:48 +0200] Report: stringpool-alloc-bytes=9024
D [27/Aug/2011:14:14:48 +0200] Report: stringpool-total-bytes=18464
D [27/Aug/2011:14:15:50 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:15:50 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:15:50 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:15:50 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:15:50 +0200] Report: clients=2
D [27/Aug/2011:14:15:50 +0200] Report: jobs=3
D [27/Aug/2011:14:15:50 +0200] Report: jobs-active=1
D [27/Aug/2011:14:15:50 +0200] Report: printers=1
D [27/Aug/2011:14:15:50 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:15:50 +0200] Report: stringpool-string-count=874
D [27/Aug/2011:14:15:50 +0200] Report: stringpool-alloc-bytes=9024
D [27/Aug/2011:14:15:50 +0200] Report: stringpool-total-bytes=18464
D [27/Aug/2011:14:16:18 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [27/Aug/2011:14:16:18 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:16:18 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:16:18 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:16:18 +0200] cupsdReadClient: 16 1.1 CUPS-Get-Printers 1
D [27/Aug/2011:14:16:18 +0200] CUPS-Get-Printers
D [27/Aug/2011:14:16:18 +0200] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [27/Aug/2011:14:16:18 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:16:18 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [27/Aug/2011:14:16:18 +0200] cupsdSetBusyState: Active clients
D [27/Aug/2011:14:16:18 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:16:18 +0200] cupsdReadClient: 16 1.1 CUPS-Get-Default 1
D [27/Aug/2011:14:16:18 +0200] CUPS-Get-Default
D [27/Aug/2011:14:16:18 +0200] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [27/Aug/2011:14:16:18 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:16:52 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:16:52 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:16:52 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:16:52 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:16:52 +0200] Report: clients=3
D [27/Aug/2011:14:16:52 +0200] Report: jobs=3
D [27/Aug/2011:14:16:52 +0200] Report: jobs-active=1
D [27/Aug/2011:14:16:52 +0200] Report: printers=1
D [27/Aug/2011:14:16:52 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:16:52 +0200] Report: stringpool-string-count=874
D [27/Aug/2011:14:16:52 +0200] Report: stringpool-alloc-bytes=9024
D [27/Aug/2011:14:16:52 +0200] Report: stringpool-total-bytes=18464
D [27/Aug/2011:14:17:41 +0200] Closing client 13 after 300 seconds of inactivity...
D [27/Aug/2011:14:17:41 +0200] cupsdCloseClient: 13
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Dirty files
I [27/Aug/2011:14:17:51 +0200] [Job 96] Job submission timed out.
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(----J-)
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(----J-)
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:17:51 +0200] [Job 96] job-sheets=none,none
D [27/Aug/2011:14:17:51 +0200] [Job 96] argv[0]="BJ-5"
D [27/Aug/2011:14:17:51 +0200] [Job 96] argv[1]="96"
D [27/Aug/2011:14:17:51 +0200] [Job 96] argv[2]="per"
D [27/Aug/2011:14:17:51 +0200] [Job 96] argv[3]="Navnløs1"
D [27/Aug/2011:14:17:51 +0200] [Job 96] argv[4]="1"
D [27/Aug/2011:14:17:51 +0200] [Job 96] argv[5]="PageSize=A4 job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97 job-originating-host-name=localhost time-at-creation=1314447160 time-at-processing=1314447471 AP_D_InputSlot="
D [27/Aug/2011:14:17:51 +0200] [Job 96] argv[6]="/var/spool/cups/d00096-001"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[8]="HOME=/var/spool/cups/tmp"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[10]="SERVER_ADMIN=root@per-loftstova"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[11]="SOFTWARE=CUPS/1.4.6"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[13]="USER=root"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[16]="IPP_PORT=631"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[17]="CHARSET=utf-8"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[18]="LANG=no_NO.UTF-8"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[19]="PPD=/etc/cups/ppd/BJ-5.ppd"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[20]="RIP_MAX_CACHE=auto"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[21]="CONTENT_TYPE=application/postscript"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[22]="DEVICE_URI=cnijnet:/00-1E-8F-A3-4C-0F"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[23]="PRINTER_INFO=BJ-5"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[24]="PRINTER_LOCATION=per-loftstova"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[25]="PRINTER=BJ-5"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[26]="CUPS_FILETYPE=document"
D [27/Aug/2011:14:17:51 +0200] [Job 96] envp[27]="FINAL_CONTENT_TYPE=printer/BJ-5"
I [27/Aug/2011:14:17:51 +0200] [Job 96] Started filter /usr/lib/cups/filter/pstopdf (PID 2915)
I [27/Aug/2011:14:17:51 +0200] [Job 96] Started filter /usr/lib/cups/filter/pdftopdf (PID 2916)
I [27/Aug/2011:14:17:51 +0200] [Job 96] Started filter /usr/lib/cups/filter/foomatic-rip (PID 2917)
I [27/Aug/2011:14:17:51 +0200] [Job 96] Started backend /usr/lib/cups/backend/cnijnet (PID 2918)
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:17:51 +0200] [Job 96] pstopdf 6 args: 96 per Navnløs1 1 PageSize=A4 job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97 job-originating-host-name=localhost time-at-creation=1314447160 time-at-processing=1314447471 AP_D_InputSlot= /var/spool/cups/d00096-001
D [27/Aug/2011:14:17:51 +0200] [Job 96] PPD: /etc/cups/ppd/BJ-5.ppd
D [27/Aug/2011:14:17:51 +0200] [Job 96] Getting input from file 
D [27/Aug/2011:14:17:51 +0200] [Job 96] foomatic-rip version 4.0.7.235 running...
D [27/Aug/2011:14:17:51 +0200] [Job 96] Parsing PPD file ...
D [27/Aug/2011:14:17:51 +0200] [Job 96] Added option PageSize
D [27/Aug/2011:14:17:51 +0200] [Job 96] Added option ImageableArea
D [27/Aug/2011:14:17:51 +0200] [Job 96] Added option PaperDimension
D [27/Aug/2011:14:17:51 +0200] [Job 96] Added option Resolution
D [27/Aug/2011:14:17:51 +0200] [Job 96] Added option Font
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Parameter Summary
D [27/Aug/2011:14:17:51 +0200] [Job 96] -----------------
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Spooler: cups
D [27/Aug/2011:14:17:51 +0200] [Job 96] Printer: BJ-5
D [27/Aug/2011:14:17:51 +0200] [Job 96] Shell: /bin/bash
D [27/Aug/2011:14:17:51 +0200] [Job 96] PPD file: /etc/cups/ppd/BJ-5.ppd
D [27/Aug/2011:14:17:51 +0200] [Job 96] ATTR file: 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Printer model: Canon BJ-5 Foomatic/bj10e (recommended)
D [27/Aug/2011:14:17:51 +0200] [Job 96] Job title: Navnløs1
D [27/Aug/2011:14:17:51 +0200] [Job 96] File(s) to be printed:
D [27/Aug/2011:14:17:51 +0200] [Job 96] <STDIN>
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Ghostscript extra search path ('GS_LIB'): /usr/share/cups/fonts
D [27/Aug/2011:14:17:51 +0200] [Job 96] Printing system options:
D [27/Aug/2011:14:17:51 +0200] [Job 96] Pondering option 'job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97'
D [27/Aug/2011:14:17:51 +0200] [Job 96] Unknown option job-uuid=urn:uuid:38590236-39ef-35fd-4c1f-d779cb8b9a97.
D [27/Aug/2011:14:17:51 +0200] [Job 96] Pondering option 'job-originating-host-name=localhost'
D [27/Aug/2011:14:17:51 +0200] [Job 96] Unknown option job-originating-host-name=localhost.
D [27/Aug/2011:14:17:51 +0200] [Job 96] Pondering option 'time-at-creation=1314447160'
D [27/Aug/2011:14:17:51 +0200] [Job 96] Unknown option time-at-creation=1314447160.
D [27/Aug/2011:14:17:51 +0200] [Job 96] Pondering option 'time-at-processing=1314447471'
D [27/Aug/2011:14:17:51 +0200] [Job 96] Unknown option time-at-processing=1314447471.
D [27/Aug/2011:14:17:51 +0200] [Job 96] Pondering option 'AP_D_InputSlot='
D [27/Aug/2011:14:17:51 +0200] [Job 96] Unknown option AP_D_InputSlot=.
D [27/Aug/2011:14:17:51 +0200] [Job 96] Options from the PPD file:
D [27/Aug/2011:14:17:51 +0200] [Job 96] Pondering option 'PageSize=A4'
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] ================================================
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] File: <STDIN>
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] ================================================
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
I [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Resolution: 360x360
D [27/Aug/2011:14:17:51 +0200] [Job 96] Page size: A4
I [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Width: 595, height: 842, absolute margins: 18, 36, 577, 806
D [27/Aug/2011:14:17:51 +0200] [Job 96] Relative margins: 18, 36, 18, 36
D [27/Aug/2011:14:17:51 +0200] [Job 96] PPD options: -r360 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842
D [27/Aug/2011:14:17:51 +0200] [Job 96] PostScript to be injected: 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Running cat | /usr/bin/gs -q -dNOPAUSE -dBATCH -sDEVICE=pdfwrite -dCompatibilityLevel=1.3 -dAutoRotatePages=/None -dAutoFilterColorImages=false                -dNOPLATFONTS -dPARANOIDSAFER -sstdout=%stderr -dColorImageFilter=/FlateEncode                 -dPDFSETTINGS=/printer                 -dColorConversionStrategy=/LeaveColorUnchanged -dDoNumCopies -r360 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sOutputFile=-  -c .setpdfwrite -f -
E [27/Aug/2011:14:17:51 +0200] [Job 96] cannot load library
D [27/Aug/2011:14:17:51 +0200] [Job 96] Set job-printer-state-message to "cannot load library", current level=ERROR
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(-----S)
I [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:17:51 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:17:51 +0200] PID 2915 (/usr/lib/cups/filter/pstopdf) exited with no errors.
D [27/Aug/2011:14:17:51 +0200] [Job 96] Filetype: PDF
D [27/Aug/2011:14:17:51 +0200] [Job 96] Storing temporary files in /var/spool/cups/tmp
D [27/Aug/2011:14:17:51 +0200] PID 2916 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [27/Aug/2011:14:17:51 +0200] [Job 96] File contains 1 pages
D [27/Aug/2011:14:17:51 +0200] [Job 96] Starting renderer with command: gs -dFirstPage=1  -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=bj10e -r360x360 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sOutputFile=-   /var/spool/cups/tmp/foomatic-uqOhMI 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Starting process "kid3" (generation 1)
D [27/Aug/2011:14:17:51 +0200] [Job 96] Starting process "kid4" (generation 2)
D [27/Aug/2011:14:17:51 +0200] [Job 96] Starting process "renderer" (generation 2)
D [27/Aug/2011:14:17:51 +0200] [Job 96] JCL: %-12345X@PJL
D [27/Aug/2011:14:17:51 +0200] [Job 96] <job data> 
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 1.1 Get-Notifications 1
D [27/Aug/2011:14:17:51 +0200] Get-Notifications /
D [27/Aug/2011:14:17:51 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:17:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 18 1.1 Get-Printer-Attributes 1
D [27/Aug/2011:14:17:51 +0200] Get-Printer-Attributes ipp://per-loftstova:631/printers/BJ-5
D [27/Aug/2011:14:17:51 +0200] Returning IPP successful-ok for Get-Printer-Attributes (ipp://per-loftstova:631/printers/BJ-5) from localhost
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 18 WAITING Closing on EOF
D [27/Aug/2011:14:17:51 +0200] cupsdCloseClient: 18
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 WAITING Closing on EOF
D [27/Aug/2011:14:17:51 +0200] cupsdCloseClient: 17
D [27/Aug/2011:14:17:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 1.1 Get-Notifications 1
D [27/Aug/2011:14:17:51 +0200] Get-Notifications /
D [27/Aug/2011:14:17:51 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:17:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 WAITING Closing on EOF
D [27/Aug/2011:14:17:51 +0200] cupsdCloseClient: 17
D [27/Aug/2011:14:17:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 1.1 Get-Notifications 1
D [27/Aug/2011:14:17:51 +0200] Get-Notifications /
D [27/Aug/2011:14:17:51 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:17:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 WAITING Closing on EOF
D [27/Aug/2011:14:17:51 +0200] cupsdCloseClient: 17
D [27/Aug/2011:14:17:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 1.1 Get-Notifications 1
D [27/Aug/2011:14:17:51 +0200] Get-Notifications /
D [27/Aug/2011:14:17:51 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:17:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:17:51 +0200] cupsdSetBusyState: Printing jobs and dirty files
D [27/Aug/2011:14:17:51 +0200] cupsdReadClient: 17 WAITING Closing on EOF
D [27/Aug/2011:14:17:51 +0200] cupsdCloseClient: 17
D [27/Aug/2011:14:17:51 +0200] [Job 96] renderer exited with status 0
D [27/Aug/2011:14:17:51 +0200] [Job 96] kid4 exited with status 0
D [27/Aug/2011:14:17:51 +0200] [Job 96] kid3 finished
D [27/Aug/2011:14:17:51 +0200] [Job 96] Kid3 exit status: 0
D [27/Aug/2011:14:17:51 +0200] [Job 96] 
D [27/Aug/2011:14:17:51 +0200] [Job 96] Closing foomatic-rip.
D [27/Aug/2011:14:17:51 +0200] PID 2917 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
D [27/Aug/2011:14:17:52 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:17:52 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:17:52 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:17:52 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:17:52 +0200] Report: clients=2
D [27/Aug/2011:14:17:52 +0200] Report: jobs=3
D [27/Aug/2011:14:17:52 +0200] Report: jobs-active=1
D [27/Aug/2011:14:17:52 +0200] Report: printers=1
D [27/Aug/2011:14:17:52 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:17:52 +0200] Report: stringpool-string-count=1333
D [27/Aug/2011:14:17:52 +0200] Report: stringpool-alloc-bytes=9040
D [27/Aug/2011:14:17:52 +0200] Report: stringpool-total-bytes=27672
D [27/Aug/2011:14:17:52 +0200] PID 2918 (/usr/lib/cups/backend/cnijnet) stopped with status 1!
I [27/Aug/2011:14:17:52 +0200] [Job 96] Backend returned status 1 (failed)
D [27/Aug/2011:14:17:52 +0200] set_hold_until: hold_until = 1314447772
D [27/Aug/2011:14:17:52 +0200] cupsdMarkDirty(----J-)
D [27/Aug/2011:14:17:52 +0200] cupsdMarkDirty(-----S)
D [27/Aug/2011:14:17:52 +0200] cupsdAcceptClient: 13 from localhost (Domain)
D [27/Aug/2011:14:17:52 +0200] cupsdReadClient: 13 POST / HTTP/1.1
D [27/Aug/2011:14:17:52 +0200] cupsdSetBusyState: Active clients and dirty files
D [27/Aug/2011:14:17:52 +0200] cupsdAuthorize: No authentication data provided.
D [27/Aug/2011:14:17:52 +0200] cupsdReadClient: 13 1.1 Get-Notifications 1
D [27/Aug/2011:14:17:52 +0200] Get-Notifications /
D [27/Aug/2011:14:17:52 +0200] cupsdIsAuthorized: requesting-user-name="per"
D [27/Aug/2011:14:17:52 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [27/Aug/2011:14:17:52 +0200] cupsdSetBusyState: Dirty files
D [27/Aug/2011:14:17:52 +0200] cupsdReadClient: 13 WAITING Closing on EOF
D [27/Aug/2011:14:17:52 +0200] cupsdCloseClient: 13
D [27/Aug/2011:14:17:54 +0200] Closing client 15 after 300 seconds of inactivity...
D [27/Aug/2011:14:17:54 +0200] cupsdCloseClient: 15
I [27/Aug/2011:14:18:22 +0200] Saving job cache file "/var/cache/cups/job.cache"...
I [27/Aug/2011:14:18:22 +0200] Saving subscriptions.conf...
D [27/Aug/2011:14:18:22 +0200] cupsdSetBusyState: Not busy
D [27/Aug/2011:14:18:55 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:18:55 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:18:55 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:18:55 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:18:55 +0200] Report: clients=1
D [27/Aug/2011:14:18:55 +0200] Report: jobs=3
D [27/Aug/2011:14:18:55 +0200] Report: jobs-active=1
D [27/Aug/2011:14:18:55 +0200] Report: printers=1
D [27/Aug/2011:14:18:55 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:18:55 +0200] Report: stringpool-string-count=1390
D [27/Aug/2011:14:18:55 +0200] Report: stringpool-alloc-bytes=9064
D [27/Aug/2011:14:18:55 +0200] Report: stringpool-total-bytes=28880
D [27/Aug/2011:14:19:57 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:19:57 +0200] cupsdNetIFUpdate: "eth0" = 10.0.0.3:631
D [27/Aug/2011:14:19:57 +0200] cupsdNetIFUpdate: "lo" = localhost:631
D [27/Aug/2011:14:19:57 +0200] cupsdNetIFUpdate: "eth0" = [v1.fe80::222:15ff:fe95:1916+eth0]:631
D [27/Aug/2011:14:19:57 +0200] Report: clients=1
D [27/Aug/2011:14:19:57 +0200] Report: jobs=3
D [27/Aug/2011:14:19:57 +0200] Report: jobs-active=1
D [27/Aug/2011:14:19:57 +0200] Report: printers=1
D [27/Aug/2011:14:19:57 +0200] Report: printers-implicit=0
D [27/Aug/2011:14:19:57 +0200] Report: stringpool-string-count=1390
D [27/Aug/2011:14:19:57 +0200] Report: stringpool-alloc-bytes=9064
D [27/Aug/2011:14:19:57 +0200] Report: stringpool-total-bytes=28880