[cups] StartOutput output_header_error -- solved, sort-of

Håkon Alstadheim hakon at alstadheim.priv.no
Mon Sep 8 03:40:02 PDT 2014


After lots of digging, I believe I have found a work-around, which I am 
sure can be improved upon.

First, I have moved cups from the main server, since my initial line of 
inquiry was incompatibilities between kernel-hardening and the canon 
drivers. I relaxed the flags on /tmp (chmod o-t /tmp) . No immediate 
success, though there is something fishy about how canon handles 
symlinks in /tmp I think.

More consistent "success" came from moving 
/usr/lib/cups/filter/pstoncapcpca (as per debian directory layout) to 
pstoncapcpca_0, and inserting a shell script in its place, like so (I'll 
leave the stuff needed to figure things out in there, but beware 
printing large files with strace):
------
#!/bin/bash
env > /tmp/pstoncap-env-$$
echo -n "ppid " >> /tmp/pstoncap-env-$$
echo $PPID  >> /tmp/pstoncap-env-$$
ps auxwww | grep $PPID   >> /tmp/pstoncap-env-$$
echo >> /tmp/pstoncap-env-$$
echo "$@"  >> /tmp/pstoncap-env-$$
echo Open files:  >> /tmp/pstoncap-env-$$
lsof -p $$   >> /tmp/pstoncap-env-$$
#exec strace -ff -o /tmp/pstoncap-trace -e open,write 
/usr/lib/cups/filter/pstoncapcpca_0 "$@"
LANG=en_US.UTF-8
exec /usr/lib/cups/filter/pstoncapcpca_0 "$@"
-------

The strace led me to finding som missing dependencies (search for '= -' 
in the output), but I believe the main part is getting rid ov my locale 
settings.


The moral of this story is obviously: Don't buy Canon i-SENSYS LBP 7100 
if all you have is linux machines.


On 06. sep. 2014 21:07, Helge Blischke wrote:
> I tnink the error is caused by the canon specific filter
> libcanon-pdlwrapper
> Without knowing this piece of software in detail, I suspect that this
> filter tries to access some file(s) or dierectorieries the permissions 
> of which does
> not allow non-root users to access.
>
> As all the cups filters pass the job stream by a pipe to one another, 
> in this case the canon filter's
> predecessor, ghostscript, runs into a SIGPIPE error and thus fails.
>
> There are some 40 compaints regarding this filter (mostly in ubuntu 
> forums). One recipe I found is
> http://www.fredposner.com/1648/ubuntu-printing-error-line-514/
> perhaps this might help you as well.
>
> Helge
>
> Am 06.09.2014 um 11:03 schrieb Håkon Alstadheim:
>
>> Hi all, I'm new to the list, apologies if this has been asked and 
>> answered. After intensive googling (few hits from this list) I have 
>> not found an answer.
>>
>> Problem: Only root can print.
>> Gear: networked canon i-sensys lbp7100cn
>>           linux cups server on debian wheezy 32-bit (with some stuff 
>> from backports, amd64 kernel from plain wheezy)
>>           .debs from canon installed
>>           print-client is on then same machine
>> user root can print (see "Successful job" below)
>> user hakon can not (see "Failed job" below)
>> command $ id gives:
>> uid=1001(hakon) gid=1001(hakon) 
>> groups=1001(hakon),0(root),4(adm),7(lp),27(sudo),29(audio),37(operator),44(video),50(staff),123(fuse),131(lpadmin),139(quaggavty),143(wireshark),162(davfs2),1011(realtime)t 
>> print.
>>
>> looking at the various paths from the debug output like qouted below, 
>> seems to indicate that "hakon" has all the required permissions, and 
>> that there is plenty of free space (see "various paths in cups" below).
>>
>> The successful and failed jobs start to diverge (as far as I can see) 
>> at the line where the failure says "StartOutput output_header_error". 
>> That string gives no hits in the ml-archive.
>>
>> I have tried running the cups server under strace with -e open,write, 
>> but the output is a bit staggering, and there are no obvous negative 
>> return values jumping out at me.
>>
>> So, how do I go about debugging this further ? Which settings in 
>> cupsd.conf affect this? I have tried resetting the cupsd.conf to 
>> default from the web-interface, and then removed "Port 631", and put 
>> in "Listen localhost:631" and "Listen 192.168.2.2:631". The box is 
>> directly connected to the internet, and I am a bit leery about 
>> letting cups listen to all interfaces.
>>
>>
>> --------------------------command to examine the various paths in 
>> cups:--------
>> for f in /var/cache/cups /usr/share/cups /usr/share/cups/doc-root 
>> /usr/share/cups/fonts /var/spool/cups /usr/lib/cups /etc/cups 
>> /var/run/cups /var/spool/cups/tmp /usr/lib/cups/filter /usr/bin 
>> /usr/sbin /bin /usr/bin /var/spool/cups/tmp /var/run/cups/cups.sock 
>> /etc/cups/ppd/Canon_LBP7100C_7110C.ppd /usr/lib/cups/filter/pdftopdf 
>> /usr/lib/cups/filter/pdftops /usr/lib/cups/filter/pstoncapcpca 
>> /usr/lib/cups/backend/socket; do if test -d "$f"; then ls -ld $f;echo 
>> -n "df -h $f: "; df -h $f| tail -1; else ls -ld $f;fi;done
>> drwxrwxr-x 3 root lp 4096 2014-09-06 10:34 /var/cache/cups
>> df -h /var/cache/cups: /dev/mapper/system-root  311G  167G  130G 57% /
>> drwxr-xr-x 17 root root 4096 2013-05-13 15:13 /usr/share/cups
>> df -h /usr/share/cups: /dev/mapper/system-root  311G  167G  130G 57% /
>> drwxr-xr-x 14 root root 4096 2014-07-29 21:19 /usr/share/cups/doc-root
>> df -h /usr/share/cups/doc-root: /dev/mapper/system-root  311G 167G 
>> 130G  57% /
>> drwxr-xr-x 2 root root 4096 2014-03-22 12:07 /usr/share/cups/fonts
>> df -h /usr/share/cups/fonts: /dev/mapper/system-root  311G  167G 
>> 130G  57% /
>> drwx--x--- 3 root lp 4096 2014-09-06 10:33 /var/spool/cups
>> df -h /var/spool/cups: /dev/mapper/system-root  311G  167G  130G 57% /
>> drwxr-xr-x 10 root root 4096 2012-06-03 11:31 /usr/lib/cups
>> df -h /usr/lib/cups: /dev/mapper/system-root  311G  167G  130G 57% /
>> drwxr-xr-x 4 root lp 4096 2014-09-06 10:34 /etc/cups
>> df -h /etc/cups: /dev/mapper/system-root  311G  167G  130G  57% /
>> drwxr-xr-x 3 root lp 120 2014-09-06 07:18 /var/run/cups
>> df -h /var/run/cups: tmpfs           369M  6.4M  362M   2% /run
>> drwxrwx--T 2 root lp 4096 2014-09-06 10:33 /var/spool/cups/tmp
>> df -h /var/spool/cups/tmp: /dev/mapper/system-root  311G  167G 130G  
>> 57% /
>> drwxr-xr-x 2 root root 4096 2014-09-05 12:20 /usr/lib/cups/filter
>> df -h /usr/lib/cups/filter: /dev/mapper/system-root  311G  167G 130G  
>> 57% /
>> drwxr-xr-x 3 root root 122880 2014-09-05 12:20 /usr/bin
>> df -h /usr/bin: /dev/mapper/system-root  311G  167G  130G  57% /
>> drwxr-xr-x 2 root root 20480 2014-09-05 12:14 /usr/sbin
>> df -h /usr/sbin: /dev/mapper/system-root  311G  167G  130G  57% /
>> drwxr-xr-x 2 root root 4096 2014-08-06 13:31 /bin
>> df -h /bin: /dev/mapper/system-root  311G  167G  130G  57% /
>> drwxr-xr-x 3 root root 122880 2014-09-05 12:20 /usr/bin
>> df -h /usr/bin: /dev/mapper/system-root  311G  167G  130G  57% /
>> drwxrwx--T 2 root lp 4096 2014-09-06 10:33 /var/spool/cups/tmp
>> df -h /var/spool/cups/tmp: /dev/mapper/system-root  311G  167G 130G  
>> 57% /
>> srwxrwxrwx 1 root root 0 2014-09-06 07:18 /var/run/cups/cups.sock
>> -rw-r--r-- 1 root root 25646 2014-09-05 13:32 
>> /etc/cups/ppd/Canon_LBP7100C_7110C.ppd
>> -rwxr-xr-x 1 root root 156320 2014-03-11 15:30 
>> /usr/lib/cups/filter/pdftopdf
>> -rwxr-xr-x 1 root root 26408 2014-03-11 15:30 
>> /usr/lib/cups/filter/pdftops
>> -rwxr-xr-x 1 root root 31004 2014-03-24 11:53 
>> /usr/lib/cups/filter/pstoncapcpca
>> -r-xr-xr-x 2 root root 30160 2014-07-25 10:13 
>> /usr/lib/cups/backend/socket
>>
>> --- Failed job: -----
>> D [05/Sep/2014:15:51:42 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:51:42 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:51:42 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:51:42 +0200] cupsdReadClient: 17 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:51:42 +0200] cupsdCloseClient: 17
>> D [05/Sep/2014:15:51:42 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:51:44 +0200] cupsdAcceptClient: 16 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:51:44 +0200] cupsdReadClient: 16 POST 
>> /printers/Canon_LBP7100C_7110C HTTP/1.1
>> D [05/Sep/2014:15:51:44 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:51:44 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:51:44 +0200] cupsdReadClient: 16 1.1 Print-Job 1
>> D [05/Sep/2014:15:51:45 +0200] Print-Job 
>> ipp://localhost:631/printers/Canon_LBP7100C_7110C
>> D [05/Sep/2014:15:51:45 +0200] [Job ???] Auto-typing file...
>> I [05/Sep/2014:15:51:45 +0200] [Job ???] Request file type is 
>> application/pdf.
>> D [05/Sep/2014:15:51:45 +0200] cupsdMarkDirty(----J-)
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients"
>> D [05/Sep/2014:15:51:45 +0200] add_job: requesting-user-name="hakon"
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] Adding start banner page 
>> "none".
>> D [05/Sep/2014:15:51:45 +0200] Discarding unused job-created event...
>> D [05/Sep/2014:15:51:45 +0200] cupsdMarkDirty(----J-)
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients and dirty files"
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] Adding end banner page "none".
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] File of type application/pdf 
>> queued by "hakon".
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] hold_until=0
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] Queued on 
>> "Canon_LBP7100C_7110C" by "hakon".
>> D [05/Sep/2014:15:51:45 +0200] cupsdMarkDirty(----J-)
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:51:45 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] job-sheets=none,none
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] argv[0]="Canon_LBP7100C_7110C"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] argv[1]="339"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] argv[2]="hakon"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] argv[3]="Uten navn"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] argv[4]="1"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] argv[5]="InputSlot=Auto 
>> CNColorMode=Auto noCNFeedAFiveHorizontally PageSize=A4 number-up=1 
>> MediaType=Auto CNDraftModeTwo=Off CNBarCodeMode=None 
>> noCNFeedStatementHorizontally CNDetectPaperSize OutputBin=Auto 
>> job-uuid=urn:uuid:3c871046-377d-353a-68f7-c04ac0764728 
>> job-originating-host-name=localhost time-at-creation=1409925105 
>> time-at-processing=1409925105"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> argv[6]="/var/spool/cups/d00339-001"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[0]="CUPS_CACHEDIR=/var/cache/cups"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[1]="CUPS_DATADIR=/usr/share/cups"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[6]="CUPS_SERVERROOT=/etc/cups"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[7]="CUPS_STATEDIR=/var/run/cups"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[8]="HOME=/var/spool/cups/tmp"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[10]="SERVER_ADMIN=root at garbo"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[11]="SOFTWARE=CUPS/1.5.3"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[12]="TMPDIR=/var/spool/cups/tmp"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[13]="TZ=Europe/Oslo"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[14]="USER=root"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[16]="CUPS_ENCRYPTION=IfRequested"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[17]="IPP_PORT=631"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[18]="CHARSET=utf-8"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[19]="LANG=no_NO.UTF-8"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[20]="PPD=/etc/cups/ppd/Canon_LBP7100C_7110C.ppd"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[21]="RIP_MAX_CACHE=128m"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[22]="CONTENT_TYPE=application/pdf"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[23]="DEVICE_URI=socket://192.168.2.202"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[24]="PRINTER_INFO=Canon 
>> LBP7100C/7110C"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[25]="PRINTER_LOCATION=Loftet"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[26]="PRINTER=Canon_LBP7100C_7110C"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[27]="PRINTER_STATE_REASONS=none"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[28]="CUPS_FILETYPE=document"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] 
>> envp[29]="FINAL_CONTENT_TYPE=printer/Canon_LBP7100C_7110C"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] envp[30]="AUTH_I****"
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] Started filter 
>> /usr/lib/cups/filter/pdftopdf (PID 24829)
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] Started filter 
>> /usr/lib/cups/filter/pdftops (PID 24830)
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] Started filter 
>> /usr/lib/cups/filter/pstoncapcpca (PID 24831)
>> I [05/Sep/2014:15:51:45 +0200] [Job 339] Started backend 
>> /usr/lib/cups/backend/socket (PID 24832)
>> D [05/Sep/2014:15:51:45 +0200] Discarding unused job-state-changed 
>> event...
>> D [05/Sep/2014:15:51:45 +0200] Returning IPP successful-ok for 
>> Print-Job (ipp://localhost:631/printers/Canon_LBP7100C_7110C) from 
>> localhost
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] pstoncapcpca start.
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:51:45 +0200] cupsdReadClient: 16 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:51:45 +0200] cupsdCloseClient: 16
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: +connecting-to-device
>> D [05/Sep/2014:15:51:45 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] Looking up "192.168.2.202"...
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] pdftops - copying to temp 
>> print file "/var/spool/cups/tmp/060fe540c7071"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] ATTR: 
>> marker-colors=#000000,#00FFFF,#FF00FF,#FFFF00
>> D [05/Sep/2014:15:51:45 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:51:45 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] ATTR: marker-names='"Canon 
>> CRG731 Black Toner for LBP7100Cn"','"Canon CRG731 Cyan Toner for 
>> LBP7100Cn"','"Canon CRG731 Magenta Toner for LBP7100Cn"','"Canon 
>> CRG731 Yellow Toner for LBP7100Cn"'
>> D [05/Sep/2014:15:51:45 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] ATTR: 
>> marker-types=toner,toner,toner,toner
>> D [05/Sep/2014:15:51:45 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:51:45 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:51:45 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] new_supply_state=0, 
>> change_state=ffff
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -developer-low-report
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -developer-empty-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: 
>> -marker-supply-low-report
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: 
>> -marker-supply-empty-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -opc-near-eol-report
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -opc-life-over-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -toner-low-report
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -toner-empty-warning
>> D [05/Sep/2014:15:51:45 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] new_state=0, change_state=ffff
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -media-low-report
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -media-empty-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -door-open-report
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: -media-jam-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: 
>> -input-tray-missing-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: 
>> -output-tray-missing-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: 
>> -marker-supply-missing-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: 
>> -output-area-almost-full-report
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] STATE: 
>> -output-area-full-warning
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] backendWaitLoop(snmp_fd=5, 
>> addr=0xf97a797c, side_cb=0xf77d67b0)
>> D [05/Sep/2014:15:51:45 +0200] PID 24829 
>> (/usr/lib/cups/filter/pdftopdf) exited with no errors.
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] Using image rendering 
>> resolution 600 dpi
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] Started filter gs (PID 24834)
>> D [05/Sep/2014:15:51:45 +0200] [Job 339] Started filter pstops (PID 
>> 24835)
>> D [05/Sep/2014:15:51:49 +0200] [Job 339] Page = 595x842; 14,14 to 
>> 581,828
>> D [05/Sep/2014:15:51:49 +0200] [Job 339] slow_collate=0, 
>> slow_duplex=0, slow_order=0
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] Before copy_comments - 
>> %!PS-Adobe-3.0
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] %!PS-Adobe-3.0
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] %%BoundingBox: 0 0 595 842
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] %%Creator: GPL Ghostscript 
>> 905 (ps2write)
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] %%LanguageLevel: 2
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] %%CreationDate: 
>> D:20140905155146+02'00'
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] %%Pages: 1
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] %%EndComments
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] Before copy_prolog - 
>> %%BeginProlog
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] Before copy_setup - %%Page: 1 1
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] Before page loop - %%Page: 1 1
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] Copying page 1...
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] pagew = 566.9, pagel = 813.5
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] bboxx = 0, bboxy = 0, bboxw 
>> = 595, bboxl = 842
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] PageLeft = 14.2, PageRight = 
>> 581.1
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] PageTop = 827.8, PageBottom 
>> = 14.3
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] PageWidth = 595.0, 
>> PageLength = 842.0
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] opvpOpenPrinter(463)
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] CStubOpenPrinter(397)
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] opvpOpenPrinter(463)
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] CStubOpenPrinter(397)
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] StartOutput output_header_error
>> E [05/Sep/2014:15:51:50 +0200] [Job 339] src = libcanon_pdlwrapper.c, 
>> line = 633, err = -1¥nDEBUG2: prtMarkerSuppliesLevel.1.1 = 100
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] Set 
>> job-printer-state-message to "src = libcanon_pdlwrapper.c, line = 
>> 633, err = -1¥nDEBUG2: prtMarkerSuppliesLevel.1.1 = 100", current 
>> level=ERROR
>> D [05/Sep/2014:15:51:50 +0200] Discarding unused job-progress event...
>> D [05/Sep/2014:15:51:50 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:51:50 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:51:50 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:51:50 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:51:50 +0200] [Job 339] new_state=0, change_state=0
>> D [05/Sep/2014:15:51:52 +0200] cupsdAcceptClient: 16 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:51:52 +0200] Report: clients=1
>> D [05/Sep/2014:15:51:52 +0200] Report: jobs=62
>> D [05/Sep/2014:15:51:52 +0200] Report: jobs-active=1
>> D [05/Sep/2014:15:51:52 +0200] Report: printers=2
>> D [05/Sep/2014:15:51:52 +0200] Report: printers-implicit=0
>> D [05/Sep/2014:15:51:52 +0200] Report: stringpool-string-count=2999
>> D [05/Sep/2014:15:51:52 +0200] Report: stringpool-alloc-bytes=13520
>> D [05/Sep/2014:15:51:52 +0200] Report: stringpool-total-bytes=55496
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 POST / HTTP/1.1
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:51:52 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:51:52 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 POST / HTTP/1.1
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 1.1 
>> CUPS-Get-Default 1
>> D [05/Sep/2014:15:51:52 +0200] CUPS-Get-Default
>> D [05/Sep/2014:15:51:52 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Default (no URI) from localhost
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 POST / HTTP/1.1
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 1.1 
>> Get-Printer-Attributes 1
>> D [05/Sep/2014:15:51:52 +0200] Get-Printer-Attributes 
>> ipp://localhost/printers/Canon_LBP7100C_7110C
>> D [05/Sep/2014:15:51:52 +0200] Returning IPP successful-ok for 
>> Get-Printer-Attributes 
>> (ipp://localhost/printers/Canon_LBP7100C_7110C) from localhost
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 POST / HTTP/1.1
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 1.1 Get-Jobs 1
>> D [05/Sep/2014:15:51:52 +0200] Get-Jobs 
>> ipp://localhost/printers/Canon_LBP7100C_7110C
>> D [05/Sep/2014:15:51:52 +0200] Returning IPP successful-ok for 
>> Get-Jobs (ipp://localhost/printers/Canon_LBP7100C_7110C) from localhost
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:51:52 +0200] cupsdReadClient: 16 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:51:52 +0200] cupsdCloseClient: 16
>> D [05/Sep/2014:15:51:52 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:51:55 +0200] [Job 339] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:51:55 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:51:55 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:51:55 +0200] [Job 339] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:51:55 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:51:55 +0200] [Job 339] new_state=0, change_state=0
>> D [05/Sep/2014:15:52:00 +0200] [Job 339] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:52:00 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:52:00 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:52:00 +0200] [Job 339] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:52:00 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:52:00 +0200] [Job 339] new_state=0, change_state=0
>> D [05/Sep/2014:15:52:05 +0200] [Job 339] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:52:05 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:52:05 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:52:05 +0200] [Job 339] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:52:05 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:52:05 +0200] [Job 339] new_state=0, change_state=0
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] PID 24834 (gs) exited with 
>> no errors.
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Wrote 1 pages...
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] PID 24835 (pstops) exited 
>> with no errors.
>> D [05/Sep/2014:15:52:08 +0200] PID 24830 
>> (/usr/lib/cups/filter/pdftops) exited with no errors.
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=2, 
>> SeqNo=3,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=5, 
>> SeqNo=4,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=7, 
>> SeqNo=121,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=8, 
>> SeqNo=2599,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=7, 
>> SeqNo=2600,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=8, 
>> SeqNo=2618,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] GPL Ghostscript 9.05: 
>> Unrecoverable error, exit code 1
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=6, 
>> SeqNo=2619,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] [Job 339] Error Response:ReqNo=3, 
>> SeqNo=2620,opvpErrorNo=-2
>> D [05/Sep/2014:15:52:08 +0200] PID 24831 
>> (/usr/lib/cups/filter/pstoncapcpca) exited with no errors.
>> D [05/Sep/2014:15:52:08 +0200] PID 24832 
>> (/usr/lib/cups/backend/socket) exited with no errors.
>> D [05/Sep/2014:15:52:08 +0200] Discarding unused job-completed event...
>> I [05/Sep/2014:15:52:08 +0200] [Job 339] Job completed.
>> D [05/Sep/2014:15:52:08 +0200] cupsdMarkDirty(----J-)
>> D [05/Sep/2014:15:52:08 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Dirty files"
>> D [05/Sep/2014:15:52:08 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:52:08 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:52:09 +0200] [Job 339] Unloading...
>> D [05/Sep/2014:15:52:09 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:52:09 +0200] cupsdNetIFUpdate: "eth2" = 
>> 178.164.66.9:631
>> D [05/Sep/2014:15:52:09 +0200] cupsdNetIFUpdate: "br0" = 192.168.2.2:631
>> D [05/Sep/2014:15:52:09 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:52:09 +0200] cupsdNetIFUpdate: "eth2" = 
>> [v1.fe80::92e2:baff:fe70:df29+eth2]:631
>> D [05/Sep/2014:15:52:09 +0200] cupsdNetIFUpdate: "br0" = 
>> [v1.fe80::21d:92ff:feda:2afb+br0]:631
>> I [05/Sep/2014:15:52:16 +0200] Saving printers.conf...
>> I [05/Sep/2014:15:52:16 +0200] Saving job.cache...
>> D [05/Sep/2014:15:52:16 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Printing jobs and dirty files"
>>
>>
>>
>> ------- Successful job: ------------
>> D [05/Sep/2014:15:52:52 +0200] Report: clients=0
>> D [05/Sep/2014:15:52:52 +0200] Report: jobs=62
>> D [05/Sep/2014:15:52:52 +0200] Report: jobs-active=0
>> D [05/Sep/2014:15:52:52 +0200] Report: printers=2
>> D [05/Sep/2014:15:52:52 +0200] Report: printers-implicit=0
>> D [05/Sep/2014:15:52:52 +0200] Report: stringpool-string-count=2945
>> D [05/Sep/2014:15:52:52 +0200] Report: stringpool-alloc-bytes=12360
>> D [05/Sep/2014:15:52:52 +0200] Report: stringpool-total-bytes=54384
>> D [05/Sep/2014:15:52:55 +0200] cupsdAcceptClient: 16 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:52:55 +0200] cupsdReadClient: 16 POST / HTTP/1.1
>> D [05/Sep/2014:15:52:55 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:52:55 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:52:55 +0200] cupsdReadClient: 16 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:52:55 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:52:55 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:52:55 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:52:57 +0200] cupsdAcceptClient: 17 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 POST / HTTP/1.1
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:52:57 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:52:57 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:52:57 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 POST / HTTP/1.1
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:52:57 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 1.1 
>> CUPS-Get-Default 1
>> D [05/Sep/2014:15:52:57 +0200] CUPS-Get-Default
>> D [05/Sep/2014:15:52:57 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Default (no URI) from localhost
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 POST / HTTP/1.1
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:52:57 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 1.1 
>> Get-Printer-Attributes 1
>> D [05/Sep/2014:15:52:57 +0200] Get-Printer-Attributes 
>> ipp://localhost/printers/Canon_LBP7100C_7110C
>> D [05/Sep/2014:15:52:57 +0200] Returning IPP successful-ok for 
>> Get-Printer-Attributes 
>> (ipp://localhost/printers/Canon_LBP7100C_7110C) from localhost
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 POST / HTTP/1.1
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:52:57 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 1.1 Get-Jobs 1
>> D [05/Sep/2014:15:52:57 +0200] Get-Jobs 
>> ipp://localhost/printers/Canon_LBP7100C_7110C
>> D [05/Sep/2014:15:52:57 +0200] Returning IPP successful-ok for 
>> Get-Jobs (ipp://localhost/printers/Canon_LBP7100C_7110C) from localhost
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:52:57 +0200] cupsdReadClient: 17 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:52:57 +0200] cupsdCloseClient: 17
>> D [05/Sep/2014:15:52:57 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:53:00 +0200] cupsdAcceptClient: 17 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:53:00 +0200] cupsdReadClient: 17 POST / HTTP/1.1
>> D [05/Sep/2014:15:53:00 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:53:00 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:53:00 +0200] cupsdReadClient: 17 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:53:00 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:53:00 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:53:00 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:53:06 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:53:06 +0200] cupsdReadClient: 18 POST / HTTP/1.1
>> D [05/Sep/2014:15:53:06 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:53:06 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:53:06 +0200] cupsdReadClient: 18 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:53:06 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:53:06 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:53:06 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:53:06 +0200] cupsdReadClient: 18 POST / HTTP/1.1
>> D [05/Sep/2014:15:53:06 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:53:06 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:53:06 +0200] cupsdReadClient: 18 1.1 
>> CUPS-Get-Classes 1
>> D [05/Sep/2014:15:53:06 +0200] CUPS-Get-Classes
>> D [05/Sep/2014:15:53:06 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Classes (no URI) from localhost
>> D [05/Sep/2014:15:53:06 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:53:06 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:53:06 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:53:06 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:53:11 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:53:11 +0200] cupsdNetIFUpdate: "eth2" = 
>> 178.164.66.9:631
>> D [05/Sep/2014:15:53:11 +0200] cupsdNetIFUpdate: "br0" = 192.168.2.2:631
>> D [05/Sep/2014:15:53:11 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:53:11 +0200] cupsdNetIFUpdate: "eth2" = 
>> [v1.fe80::92e2:baff:fe70:df29+eth2]:631
>> D [05/Sep/2014:15:53:11 +0200] cupsdNetIFUpdate: "br0" = 
>> [v1.fe80::21d:92ff:feda:2afb+br0]:631
>> D [05/Sep/2014:15:54:14 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:54:14 +0200] cupsdNetIFUpdate: "eth2" = 
>> 178.164.66.9:631
>> D [05/Sep/2014:15:54:14 +0200] cupsdNetIFUpdate: "br0" = 192.168.2.2:631
>> D [05/Sep/2014:15:54:14 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:54:14 +0200] cupsdNetIFUpdate: "eth2" = 
>> [v1.fe80::92e2:baff:fe70:df29+eth2]:631
>> D [05/Sep/2014:15:54:14 +0200] cupsdNetIFUpdate: "br0" = 
>> [v1.fe80::21d:92ff:feda:2afb+br0]:631
>> D [05/Sep/2014:15:54:14 +0200] Report: clients=2
>> D [05/Sep/2014:15:54:14 +0200] Report: jobs=62
>> D [05/Sep/2014:15:54:14 +0200] Report: jobs-active=0
>> D [05/Sep/2014:15:54:14 +0200] Report: printers=2
>> D [05/Sep/2014:15:54:14 +0200] Report: printers-implicit=0
>> D [05/Sep/2014:15:54:14 +0200] Report: stringpool-string-count=2945
>> D [05/Sep/2014:15:54:14 +0200] Report: stringpool-alloc-bytes=12360
>> D [05/Sep/2014:15:54:14 +0200] Report: stringpool-total-bytes=54384
>> D [05/Sep/2014:15:55:16 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:55:16 +0200] cupsdNetIFUpdate: "eth2" = 
>> 178.164.66.9:631
>> D [05/Sep/2014:15:55:16 +0200] cupsdNetIFUpdate: "br0" = 192.168.2.2:631
>> D [05/Sep/2014:15:55:16 +0200] cupsdNetIFUpdate: "lo" = localhost:631
>> D [05/Sep/2014:15:55:16 +0200] cupsdNetIFUpdate: "eth2" = 
>> [v1.fe80::92e2:baff:fe70:df29+eth2]:631
>> D [05/Sep/2014:15:55:16 +0200] cupsdNetIFUpdate: "br0" = 
>> [v1.fe80::21d:92ff:feda:2afb+br0]:631
>> D [05/Sep/2014:15:55:16 +0200] Report: clients=2
>> D [05/Sep/2014:15:55:16 +0200] Report: jobs=62
>> D [05/Sep/2014:15:55:16 +0200] Report: jobs-active=0
>> D [05/Sep/2014:15:55:16 +0200] Report: printers=2
>> D [05/Sep/2014:15:55:16 +0200] Report: printers-implicit=0
>> D [05/Sep/2014:15:55:16 +0200] Report: stringpool-string-count=2945
>> D [05/Sep/2014:15:55:16 +0200] Report: stringpool-alloc-bytes=12360
>> D [05/Sep/2014:15:55:16 +0200] Report: stringpool-total-bytes=54384
>> D [05/Sep/2014:15:56:08 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:08 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:08 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 18 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:08 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 18 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:08 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:08 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:08 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:08 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 19 GET 
>> /printers/Canon_LBP7100C_7110C.ppd HTTP/1.1
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:08 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:08 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:08 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:08 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:08 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:08 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:08 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:08 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:08 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:08 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:08 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:09 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:09 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:09 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:09 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:09 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:09 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:09 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:09 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:09 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:09 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:09 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:09 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:09 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:09 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:10 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:10 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:10 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:10 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:10 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:10 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:10 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:10 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:10 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:10 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:10 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:10 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:10 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:10 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:11 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 18 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 18 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:11 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:11 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:11 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:11 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:11 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:11 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:11 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:11 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:11 +0200] cupsdAcceptClient: 19 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:11 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 19 POST / HTTP/1.1
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:11 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 19 1.1 
>> CUPS-Get-Printers 1
>> D [05/Sep/2014:15:56:11 +0200] CUPS-Get-Printers
>> D [05/Sep/2014:15:56:11 +0200] Returning IPP successful-ok for 
>> CUPS-Get-Printers (no URI) from localhost
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Active clients"
>> D [05/Sep/2014:15:56:11 +0200] cupsdReadClient: 19 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:11 +0200] cupsdCloseClient: 19
>> D [05/Sep/2014:15:56:11 +0200] cupsdSetBusyState: newbusy="Not busy", 
>> busy="Not busy"
>> D [05/Sep/2014:15:56:13 +0200] cupsdAcceptClient: 18 from localhost 
>> (Domain)
>> D [05/Sep/2014:15:56:13 +0200] cupsdReadClient: 18 POST 
>> /printers/Canon_LBP7100C_7110C HTTP/1.1
>> D [05/Sep/2014:15:56:13 +0200] cupsdSetBusyState: newbusy="Active 
>> clients", busy="Not busy"
>> D [05/Sep/2014:15:56:13 +0200] cupsdAuthorize: No authentication data 
>> provided.
>> D [05/Sep/2014:15:56:13 +0200] cupsdReadClient: 18 1.1 Print-Job 1
>> D [05/Sep/2014:15:56:14 +0200] Print-Job 
>> ipp://localhost:631/printers/Canon_LBP7100C_7110C
>> D [05/Sep/2014:15:56:14 +0200] [Job ???] Auto-typing file...
>> I [05/Sep/2014:15:56:14 +0200] [Job ???] Request file type is 
>> application/pdf.
>> D [05/Sep/2014:15:56:14 +0200] cupsdMarkDirty(----J-)
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients"
>> D [05/Sep/2014:15:56:14 +0200] add_job: requesting-user-name="root"
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] Adding start banner page 
>> "none".
>> D [05/Sep/2014:15:56:14 +0200] Discarding unused job-created event...
>> D [05/Sep/2014:15:56:14 +0200] cupsdMarkDirty(----J-)
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients and dirty files"
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] Adding end banner page "none".
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] File of type application/pdf 
>> queued by "root".
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] hold_until=0
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] Queued on 
>> "Canon_LBP7100C_7110C" by "root".
>> D [05/Sep/2014:15:56:14 +0200] cupsdMarkDirty(----J-)
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Active 
>> clients and dirty files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:56:14 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] job-sheets=none,none
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] argv[0]="Canon_LBP7100C_7110C"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] argv[1]="340"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] argv[2]="root"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] argv[3]="Untitled"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] argv[4]="1"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] argv[5]="InputSlot=Auto 
>> CNColorMode=Auto noCNFeedAFiveHorizontally PageSize=A4 number-up=1 
>> MediaType=Auto CNDraftModeTwo=Off CNBarCodeMode=None 
>> noCNFeedStatementHorizontally CNDetectPaperSize OutputBin=Auto 
>> job-uuid=urn:uuid:33d62377-cec8-3aa4-4d0c-75b1a2448c7a 
>> job-originating-host-name=localhost time-at-creation=1409925374 
>> time-at-processing=1409925374"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> argv[6]="/var/spool/cups/d00340-001"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[0]="CUPS_CACHEDIR=/var/cache/cups"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[1]="CUPS_DATADIR=/usr/share/cups"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[6]="CUPS_SERVERROOT=/etc/cups"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[7]="CUPS_STATEDIR=/var/run/cups"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[8]="HOME=/var/spool/cups/tmp"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[10]="SERVER_ADMIN=root at garbo"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[11]="SOFTWARE=CUPS/1.5.3"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[12]="TMPDIR=/var/spool/cups/tmp"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[13]="TZ=Europe/Oslo"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[14]="USER=root"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[16]="CUPS_ENCRYPTION=IfRequested"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[17]="IPP_PORT=631"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[18]="CHARSET=utf-8"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[19]="LANG=en_US.UTF-8"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[20]="PPD=/etc/cups/ppd/Canon_LBP7100C_7110C.ppd"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[21]="RIP_MAX_CACHE=128m"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[22]="CONTENT_TYPE=application/pdf"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[23]="DEVICE_URI=socket://192.168.2.202"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[24]="PRINTER_INFO=Canon 
>> LBP7100C/7110C"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[25]="PRINTER_LOCATION=Loftet"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[26]="PRINTER=Canon_LBP7100C_7110C"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[27]="PRINTER_STATE_REASONS=none"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[28]="CUPS_FILETYPE=document"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] 
>> envp[29]="FINAL_CONTENT_TYPE=printer/Canon_LBP7100C_7110C"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] envp[30]="AUTH_I****"
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] Started filter 
>> /usr/lib/cups/filter/pdftopdf (PID 25911)
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] Started filter 
>> /usr/lib/cups/filter/pdftops (PID 25912)
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] Started filter 
>> /usr/lib/cups/filter/pstoncapcpca (PID 25913)
>> I [05/Sep/2014:15:56:14 +0200] [Job 340] Started backend 
>> /usr/lib/cups/backend/socket (PID 25914)
>> D [05/Sep/2014:15:56:14 +0200] Discarding unused job-state-changed 
>> event...
>> D [05/Sep/2014:15:56:14 +0200] Returning IPP successful-ok for 
>> Print-Job (ipp://localhost:631/printers/Canon_LBP7100C_7110C) from 
>> localhost
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Active clients and dirty files"
>> D [05/Sep/2014:15:56:14 +0200] cupsdReadClient: 18 WAITING Closing on 
>> EOF
>> D [05/Sep/2014:15:56:14 +0200] cupsdCloseClient: 18
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: +connecting-to-device
>> D [05/Sep/2014:15:56:14 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] pstoncapcpca start.
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] pdftops - copying to temp 
>> print file "/var/spool/cups/tmp/06538540c1283"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] Looking up "192.168.2.202"...
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] ATTR: 
>> marker-colors=#000000,#00FFFF,#FF00FF,#FFFF00
>> D [05/Sep/2014:15:56:14 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] ATTR: marker-names='"Canon 
>> CRG731 Black Toner for LBP7100Cn"','"Canon CRG731 Cyan Toner for 
>> LBP7100Cn"','"Canon CRG731 Magenta Toner for LBP7100Cn"','"Canon 
>> CRG731 Yellow Toner for LBP7100Cn"'
>> D [05/Sep/2014:15:56:14 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] ATTR: 
>> marker-types=toner,toner,toner,toner
>> D [05/Sep/2014:15:56:14 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:56:14 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:14 +0200] cupsdSetBusyState: newbusy="Dirty 
>> files", busy="Dirty files"
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] new_supply_state=0, 
>> change_state=ffff
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -developer-low-report
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -developer-empty-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: 
>> -marker-supply-low-report
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: 
>> -marker-supply-empty-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -opc-near-eol-report
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -opc-life-over-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -toner-low-report
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -toner-empty-warning
>> D [05/Sep/2014:15:56:14 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] new_state=0, change_state=ffff
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -media-low-report
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -media-empty-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -door-open-report
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: -media-jam-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: 
>> -input-tray-missing-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: 
>> -output-tray-missing-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: 
>> -marker-supply-missing-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: 
>> -output-area-almost-full-report
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] STATE: 
>> -output-area-full-warning
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] backendWaitLoop(snmp_fd=5, 
>> addr=0xf7acb97c, side_cb=0xf76fe7b0)
>> D [05/Sep/2014:15:56:14 +0200] PID 25911 
>> (/usr/lib/cups/filter/pdftopdf) exited with no errors.
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] Using image rendering 
>> resolution 600 dpi
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] Started filter gs (PID 25915)
>> D [05/Sep/2014:15:56:14 +0200] [Job 340] Started filter pstops (PID 
>> 25916)
>> D [05/Sep/2014:15:56:16 +0200] Report: clients=2
>> D [05/Sep/2014:15:56:16 +0200] Report: jobs=63
>> D [05/Sep/2014:15:56:16 +0200] Report: jobs-active=1
>> D [05/Sep/2014:15:56:16 +0200] Report: printers=2
>> D [05/Sep/2014:15:56:16 +0200] Report: printers-implicit=0
>> D [05/Sep/2014:15:56:16 +0200] Report: stringpool-string-count=3001
>> D [05/Sep/2014:15:56:16 +0200] Report: stringpool-alloc-bytes=13400
>> D [05/Sep/2014:15:56:16 +0200] Report: stringpool-total-bytes=55440
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Page = 595x842; 14,14 to 
>> 581,828
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] slow_collate=0, 
>> slow_duplex=0, slow_order=0
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Before copy_comments - 
>> %!PS-Adobe-3.0
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] %!PS-Adobe-3.0
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] %%BoundingBox: 0 0 595 842
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] %%Creator: GPL Ghostscript 
>> 905 (ps2write)
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] %%LanguageLevel: 2
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] %%CreationDate: 
>> D:20140905155614+02'00'
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] %%Pages: 1
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] %%EndComments
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Before copy_prolog - 
>> %%BeginProlog
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Before copy_setup - %%Page: 1 1
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Before page loop - %%Page: 1 1
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Copying page 1...
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] pagew = 566.9, pagel = 813.5
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] bboxx = 0, bboxy = 0, bboxw 
>> = 595, bboxl = 842
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] PageLeft = 14.2, PageRight = 
>> 581.1
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] PageTop = 827.8, PageBottom 
>> = 14.3
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] PageWidth = 595.0, 
>> PageLength = 842.0
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] opvpOpenPrinter(463)
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] CStubOpenPrinter(397)
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] opvpOpenPrinter(463)
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] CStubOpenPrinter(397)
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Connecting to 
>> 192.168.2.202:9100
>> I [05/Sep/2014:15:56:18 +0200] [Job 340] Connecting to printer.
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Set 
>> job-printer-state-message to "Connecting to printer.", current 
>> level=INFO
>> D [05/Sep/2014:15:56:18 +0200] Discarding unused job-progress event...
>> D [05/Sep/2014:15:56:18 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] STATE: -connecting-to-device
>> D [05/Sep/2014:15:56:18 +0200] Discarding unused 
>> printer-state-changed event...
>> I [05/Sep/2014:15:56:18 +0200] [Job 340] Connected to printer.
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Set 
>> job-printer-state-message to "Connected to printer.", current level=INFO
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Connected to 
>> 192.168.2.202:9100...
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] backendRunLoop(print_fd=0, 
>> device_fd=6, snmp_fd=5, addr=0xf7acb97c, use_bc=1, side_cb=0xf76fe7b0)
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] Read 753 bytes of print data...
>> D [05/Sep/2014:15:56:18 +0200] Discarding unused job-progress event...
>> D [05/Sep/2014:15:56:18 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:56:18 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:18 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Dirty files"
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:56:18 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:18 +0200] [Job 340] new_state=0, change_state=0
>> D [05/Sep/2014:15:56:19 +0200] [Job 340] Wrote 753 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:24 +0200] [Job 340] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:56:24 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:24 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:56:24 +0200] [Job 340] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:56:24 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:24 +0200] [Job 340] new_state=0, change_state=0
>> D [05/Sep/2014:15:56:29 +0200] [Job 340] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:56:29 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:29 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:56:29 +0200] [Job 340] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:56:29 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:29 +0200] [Job 340] new_state=0, change_state=0
>> D [05/Sep/2014:15:56:34 +0200] [Job 340] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:56:34 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:34 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:56:34 +0200] [Job 340] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:56:34 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:34 +0200] [Job 340] new_state=0, change_state=0
>> D [05/Sep/2014:15:56:39 +0200] [Job 340] ATTR: 
>> marker-levels=100,100,100,100
>> D [05/Sep/2014:15:56:39 +0200] cupsdMarkDirty(P-----)
>> D [05/Sep/2014:15:56:39 +0200] cupsdSetBusyState: newbusy="Printing 
>> jobs and dirty files", busy="Printing jobs and dirty files"
>> D [05/Sep/2014:15:56:39 +0200] [Job 340] new_supply_state=0, 
>> change_state=0
>> D [05/Sep/2014:15:56:39 +0200] Discarding unused 
>> printer-state-changed event...
>> D [05/Sep/2014:15:56:39 +0200] [Job 340] new_state=0, change_state=0
>> D [05/Sep/2014:15:56:41 +0200] [Job 340] Wrote 1 pages...
>> D [05/Sep/2014:15:56:41 +0200] [Job 340] PID 25916 (pstops) exited 
>> with no errors.
>> D [05/Sep/2014:15:56:41 +0200] [Job 340] PID 25915 (gs) exited with 
>> no errors.
>> D [05/Sep/2014:15:56:41 +0200] PID 25912 
>> (/usr/lib/cups/filter/pdftops) exited with no errors.
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 38 bytes of print data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 38 bytes of print data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Read 8192 bytes of print 
>> data...
>> D [05/Sep/2014:15:56:42 +0200] [Job 340] Wrote 8192 bytes of print 
>> data...
>> .... And this goes on ....
>> -----------
>>
>> -- 
>> Håkon Alstadheim / N-7510 Skatval / email: hakon at alstadheim.priv.no
>> tlf: 74 82 60 27 mob: 47 35 39 38
>> http://alstadheim.priv.no/hakon/
>>
>>
>> _______________________________________________
>> cups mailing list
>> cups at cups.org
>> https://www.cups.org/mailman/listinfo/cups
>
> _______________________________________________
> cups mailing list
> cups at cups.org
> https://www.cups.org/mailman/listinfo/cups
>


-- 
Håkon Alstadheim / N-7510 Skatval / email: hakon at alstadheim.priv.no
tlf: 74 82 60 27 mob: 47 35 39 38
http://alstadheim.priv.no/hakon/





More information about the cups mailing list