D [08/Aug/2005:10:46:42 +0100] AddLocation: added location '/'
D [08/Aug/2005:10:46:42 +0100] DenyIP: / deny 00000000/00000000
D [08/Aug/2005:10:46:42 +0100] AllowIP: / allow 7f000001/ffffffff
D [08/Aug/2005:10:46:42 +0100] AddLocation: added location '/admin'
D [08/Aug/2005:10:46:42 +0100] DenyIP: /admin deny 00000000/00000000
D [08/Aug/2005:10:46:42 +0100] AllowIP: /admin allow 7f000001/ffffffff
D [08/Aug/2005:10:46:42 +0100] AddLocation: added location 'CUPS_INTERNAL_BROWSE_ACL'
D [08/Aug/2005:10:46:42 +0100] AllowHost: CUPS_INTERNAL_BROWSE_ACL allow @LOCAL
I [08/Aug/2005:10:46:42 +0100] Listening to 7f000001:631
I [08/Aug/2005:10:46:42 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
I [08/Aug/2005:10:46:42 +0100] Configured for up to 100 clients.
I [08/Aug/2005:10:46:42 +0100] Allowing up to 100 client connections per host.
I [08/Aug/2005:10:46:42 +0100] Full reload is required.
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "ipp"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "socket"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "smb"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "hal"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp0"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp1"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp2"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp3"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp4"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp5"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp6"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp7"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp8"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp9"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp10"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp11"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp12"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp13"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp14"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "usb:/dev/usb/lp15"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "lpd"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS0?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS1?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS2?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS3?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS4?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS5?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS6?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "serial:/dev/ttyS7?baud=115200"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "http"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "parallel:/dev/lp0"...
D [08/Aug/2005:10:46:42 +0100] LoadDevices: Added device "scsi"...
I [08/Aug/2005:10:46:42 +0100] LoadPPDs: Read "/etc/cups/ppds.dat", 15 PPDs...
I [08/Aug/2005:10:46:42 +0100] LoadPPDs: No new or changed PPDs...
D [08/Aug/2005:10:46:42 +0100] LoadAllJobs: Scanning /var/spool/cups...
I [08/Aug/2005:10:46:42 +0100] Full reload complete.
D [08/Aug/2005:10:46:42 +0100] StartListening: NumListeners=1
D [08/Aug/2005:10:46:42 +0100] StartListening: address=7f000001 port=631
D [08/Aug/2005:10:46:42 +0100] ResumeListening: setting input bits...
I [08/Aug/2005:10:46:55 +0100] Added remote printer "hp2"...
I [08/Aug/2005:10:46:57 +0100] Added remote printer "hp1"...
D [08/Aug/2005:10:47:03 +0100] AcceptClient: 6 from localhost:631.
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=0
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:03 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:03 +0100] CloseClient: 6
I [08/Aug/2005:10:47:05 +0100] Added remote printer "hpcol"...
D [08/Aug/2005:10:47:05 +0100] AcceptClient: 6 from localhost:631.
D [08/Aug/2005:10:47:05 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:05 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:05 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:05 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:05 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:05 +0100] ProcessIPPRequest: 6 status_code=0
D [08/Aug/2005:10:47:06 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:06 +0100] ProcessIPPRequest: 6 status_code=1
I [08/Aug/2005:10:47:06 +0100] Added remote printer "Xerox"...
D [08/Aug/2005:10:47:06 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:06 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:06 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:06 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:06 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:06 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:06 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:06 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:06 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:06 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:06 +0100] CloseClient: 6
D [08/Aug/2005:10:47:23 +0100] AcceptClient: 6 from localhost:631.
D [08/Aug/2005:10:47:23 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:23 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:23 +0100] ReadClient: 6 POST / HTTP/1.1
D [08/Aug/2005:10:47:23 +0100] ProcessIPPRequest: 6 status_code=1
D [08/Aug/2005:10:47:23 +0100] CloseClient: 6
D [08/Aug/2005:10:47:23 +0100] AcceptClient: 6 from localhost:631.
D [08/Aug/2005:10:47:23 +0100] ReadClient: 6 POST /printers/hp2 HTTP/1.1
D [08/Aug/2005:10:47:23 +0100] check_quotas: requesting-user-name = 'mn'
D [08/Aug/2005:10:47:23 +0100] create_job: requesting-user-name = 'mn'
I [08/Aug/2005:10:47:23 +0100] Job 5 created on 'hp2' by 'mn'.
D [08/Aug/2005:10:47:23 +0100] ProcessIPPRequest: 6 status_code=0
D [08/Aug/2005:10:47:23 +0100] ReadClient: 6 POST /printers/hp2 HTTP/1.1
D [08/Aug/2005:10:47:24 +0100] send_document: auto-typing file...
D [08/Aug/2005:10:47:24 +0100] send_document: request file type is text/plain.
I [08/Aug/2005:10:47:24 +0100] File of type text/plain queued in job #5 by 'mn'.
D [08/Aug/2005:10:47:24 +0100] ProcessIPPRequest: 6 status_code=0
D [08/Aug/2005:10:47:24 +0100] ReadClient: 6 POST /printers/hp2 HTTP/1.1
D [08/Aug/2005:10:47:24 +0100] send_document: auto-typing file...
D [08/Aug/2005:10:47:24 +0100] send_document: request file type is text/plain.
I [08/Aug/2005:10:47:24 +0100] File of type text/plain queued in job #5 by 'mn'.
D [08/Aug/2005:10:47:24 +0100] StartJob(5, 0x96ab2a0)
D [08/Aug/2005:10:47:24 +0100] StartJob() id = 5, file = 0/2
D [08/Aug/2005:10:47:24 +0100] StartJob: Sending job to queue tagged as raw...
D [08/Aug/2005:10:47:24 +0100] No job-sheets attribute.
D [08/Aug/2005:10:47:24 +0100] banner_page = 0
D [08/Aug/2005:10:47:24 +0100] StartJob: argv = "hp2","5","mn","long_term_tasks.txt","1","job-priority=50 job-hold-until=no-hold","/var/spool/cups/d00005-001"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[2]="USER=root"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[3]="CHARSET=utf-8"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[4]="LANG=en_GB"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[5]="PPD=/etc/cups/ppd/hp2.ppd"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[9]="CONTENT_TYPE=text/plain"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[10]="DEVICE_URI=ipp://s7.phyip3.dur.ac.uk:631/printers/hp2"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[11]="PRINTER=hp2"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[14]="CUPS_SERVER=localhost"
D [08/Aug/2005:10:47:24 +0100] StartJob: envp[15]="IPP_PORT=631"
D [08/Aug/2005:10:47:24 +0100] StartJob: statusfds = [ 8 9 ]
D [08/Aug/2005:10:47:24 +0100] StartJob: filterfds[1] = [ 10 -1 ]
D [08/Aug/2005:10:47:24 +0100] StartJob: backend = "/usr/lib/cups/backend/ipp"
D [08/Aug/2005:10:47:24 +0100] StartJob: filterfds[0] = [ -1 11 ]
D [08/Aug/2005:10:47:24 +0100] start_process("/usr/lib/cups/backend/ipp", 0xbff46130, 0xbff454a0, 10, 11, 9)
I [08/Aug/2005:10:47:24 +0100] Started backend /usr/lib/cups/backend/ipp (PID 23737) for job 5.
D [08/Aug/2005:10:47:24 +0100] ProcessIPPRequest: 6 status_code=0
D [08/Aug/2005:10:47:24 +0100] [Job 5] Getting supported attributes...
D [08/Aug/2005:10:47:24 +0100] [Job 5] document-format-supported (29 values)
D [08/Aug/2005:10:47:24 +0100] [Job 5] [0] = "application/pdf"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [1] = "application/postscript"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [2] = "application/vnd.cups-command"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [3] = "application/vnd.cups-form"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [4] = "application/vnd.cups-postscript"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [5] = "application/vnd.cups-raster"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [6] = "application/vnd.cups-raw"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [7] = "application/vnd.hp-hpgl"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [8] = "application/x-cshell"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [9] = "application/x-perl"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [10] = "application/x-shell"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [11] = "image/gif"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [12] = "image/jpeg"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [13] = "image/png"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [14] = "image/tiff"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [15] = "image/x-alias"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [16] = "image/x-bitmap"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [17] = "image/x-photocd"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [18] = "image/x-portable-anymap"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [19] = "image/x-portable-bitmap"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [20] = "image/x-portable-graymap"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [21] = "image/x-portable-pixmap"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [22] = "image/x-sgi-rgb"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [23] = "image/x-sun-raster"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [24] = "image/x-xbitmap"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [25] = "image/x-xpixmap"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [26] = "text/html"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [27] = "text/plain"
D [08/Aug/2005:10:47:24 +0100] [Job 5] [28] = "application/octet-stream"
D [08/Aug/2005:10:47:24 +0100] [Job 5] printer-uri = "ipp://s7.phyip3.dur.ac.uk:631/printers/hp2"
D [08/Aug/2005:10:47:24 +0100] [Job 5] requesting-user-name = "mn"
D [08/Aug/2005:10:47:24 +0100] [Job 5] job-name = "long_term_tasks.txt"
D [08/Aug/2005:10:47:24 +0100] CloseClient: 6
D [08/Aug/2005:10:47:29 +0100] AcceptClient: 9 from localhost:631.
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=0
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:29 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:29 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:29 +0100] CloseClient: 9
D [08/Aug/2005:10:47:31 +0100] AcceptClient: 9 from localhost:631.
D [08/Aug/2005:10:47:31 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:31 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:31 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:31 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:31 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:31 +0100] ProcessIPPRequest: 9 status_code=0
D [08/Aug/2005:10:47:31 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:31 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:32 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:32 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:32 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:32 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:32 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:32 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:32 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:32 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:32 +0100] CloseClient: 9
D [08/Aug/2005:10:47:34 +0100] AcceptClient: 9 from localhost:631.
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=0
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:34 +0100] UpdateJob: job 5, file 0 is complete.
D [08/Aug/2005:10:47:34 +0100] StartJob(5, 0x96ab2a0)
D [08/Aug/2005:10:47:34 +0100] StartJob() id = 5, file = 1/2
D [08/Aug/2005:10:47:34 +0100] StartJob: Sending job to queue tagged as raw...
D [08/Aug/2005:10:47:34 +0100] No job-sheets attribute.
D [08/Aug/2005:10:47:34 +0100] banner_page = 0
D [08/Aug/2005:10:47:34 +0100] StartJob: argv = "hp2","5","mn","long_term_tasks.txt","1","job-priority=50 job-hold-until=no-hold","/var/spool/cups/d00005-002"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[2]="USER=root"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[3]="CHARSET=utf-8"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[4]="LANG=en_GB"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[5]="PPD=/etc/cups/ppd/hp2.ppd"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[9]="CONTENT_TYPE=text/plain"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[10]="DEVICE_URI=ipp://s7.phyip3.dur.ac.uk:631/printers/hp2"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[11]="PRINTER=hp2"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[14]="CUPS_SERVER=localhost"
D [08/Aug/2005:10:47:34 +0100] StartJob: envp[15]="IPP_PORT=631"
D [08/Aug/2005:10:47:34 +0100] StartJob: statusfds = [ 8 10 ]
D [08/Aug/2005:10:47:34 +0100] StartJob: filterfds[1] = [ 11 -1 ]
D [08/Aug/2005:10:47:34 +0100] StartJob: backend = "/usr/lib/cups/backend/ipp"
D [08/Aug/2005:10:47:34 +0100] StartJob: filterfds[0] = [ -1 12 ]
D [08/Aug/2005:10:47:34 +0100] start_process("/usr/lib/cups/backend/ipp", 0xbff54820, 0xbff53b90, 11, 12, 10)
I [08/Aug/2005:10:47:34 +0100] Started backend /usr/lib/cups/backend/ipp (PID 23742) for job 5.
D [08/Aug/2005:10:47:34 +0100] [Job 5] Getting supported attributes...
D [08/Aug/2005:10:47:34 +0100] [Job 5] document-format-supported (29 values)
D [08/Aug/2005:10:47:34 +0100] [Job 5] [0] = "application/pdf"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [1] = "application/postscript"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [2] = "application/vnd.cups-command"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [3] = "application/vnd.cups-form"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [4] = "application/vnd.cups-postscript"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [5] = "application/vnd.cups-raster"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [6] = "application/vnd.cups-raw"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [7] = "application/vnd.hp-hpgl"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [8] = "application/x-cshell"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [9] = "application/x-perl"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [10] = "application/x-shell"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [11] = "image/gif"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [12] = "image/jpeg"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [13] = "image/png"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [14] = "image/tiff"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [15] = "image/x-alias"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [16] = "image/x-bitmap"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [17] = "image/x-photocd"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [18] = "image/x-portable-anymap"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [19] = "image/x-portable-bitmap"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [20] = "image/x-portable-graymap"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [21] = "image/x-portable-pixmap"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [22] = "image/x-sgi-rgb"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [23] = "image/x-sun-raster"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [24] = "image/x-xbitmap"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [25] = "image/x-xpixmap"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [26] = "text/html"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [27] = "text/plain"
D [08/Aug/2005:10:47:34 +0100] [Job 5] [28] = "application/octet-stream"
D [08/Aug/2005:10:47:34 +0100] [Job 5] printer-uri = "ipp://s7.phyip3.dur.ac.uk:631/printers/hp2"
D [08/Aug/2005:10:47:34 +0100] [Job 5] requesting-user-name = "mn"
D [08/Aug/2005:10:47:34 +0100] [Job 5] job-name = "long_term_tasks.txt"
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=1
E [08/Aug/2005:10:47:34 +0100] [Job 5] Unable to get job 769 attributes (client-error-bad-request)!
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
E [08/Aug/2005:10:47:34 +0100] PID 23742 stopped with status 1!
D [08/Aug/2005:10:47:34 +0100] UpdateJob: job 5, file 1 is complete.
D [08/Aug/2005:10:47:34 +0100] StopJob: id = 5, force = 0
D [08/Aug/2005:10:47:34 +0100] StopJob: printer state is 3
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:34 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:34 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:34 +0100] CloseClient: 9
D [08/Aug/2005:10:47:40 +0100] AcceptClient: 8 from localhost:631.
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=0
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:40 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:40 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:40 +0100] CloseClient: 8
D [08/Aug/2005:10:47:42 +0100] AcceptClient: 8 from localhost:631.
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=0
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:42 +0100] ReadClient: 8 POST / HTTP/1.1
D [08/Aug/2005:10:47:42 +0100] ProcessIPPRequest: 8 status_code=1
D [08/Aug/2005:10:47:42 +0100] CloseClient: 8
D [08/Aug/2005:10:47:43 +0100] StartJob(5, 0x96ab2a0)
D [08/Aug/2005:10:47:43 +0100] StartJob() id = 5, file = 1/2
D [08/Aug/2005:10:47:43 +0100] StartJob: Sending job to queue tagged as raw...
D [08/Aug/2005:10:47:43 +0100] No job-sheets attribute.
D [08/Aug/2005:10:47:43 +0100] banner_page = 0
D [08/Aug/2005:10:47:43 +0100] StartJob: argv = "hp2","5","mn","long_term_tasks.txt","1","job-priority=50 job-hold-until=no-hold","/var/spool/cups/d00005-002"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[2]="USER=root"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[3]="CHARSET=utf-8"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[4]="LANG=en_GB"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[5]="PPD=/etc/cups/ppd/hp2.ppd"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[9]="CONTENT_TYPE=text/plain"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[10]="DEVICE_URI=ipp://s7.phyip3.dur.ac.uk:631/printers/hp2"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[11]="PRINTER=hp2"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[14]="CUPS_SERVER=localhost"
D [08/Aug/2005:10:47:43 +0100] StartJob: envp[15]="IPP_PORT=631"
D [08/Aug/2005:10:47:43 +0100] StartJob: statusfds = [ 8 9 ]
D [08/Aug/2005:10:47:43 +0100] StartJob: filterfds[1] = [ 10 -1 ]
D [08/Aug/2005:10:47:43 +0100] StartJob: backend = "/usr/lib/cups/backend/ipp"
D [08/Aug/2005:10:47:43 +0100] StartJob: filterfds[0] = [ -1 11 ]
D [08/Aug/2005:10:47:43 +0100] start_process("/usr/lib/cups/backend/ipp", 0xbff548b0, 0xbff53c20, 10, 11, 9)
I [08/Aug/2005:10:47:43 +0100] Started backend /usr/lib/cups/backend/ipp (PID 23748) for job 5.
D [08/Aug/2005:10:47:43 +0100] [Job 5] Getting supported attributes...
D [08/Aug/2005:10:47:43 +0100] [Job 5] document-format-supported (29 values)
D [08/Aug/2005:10:47:43 +0100] [Job 5] [0] = "application/pdf"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [1] = "application/postscript"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [2] = "application/vnd.cups-command"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [3] = "application/vnd.cups-form"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [4] = "application/vnd.cups-postscript"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [5] = "application/vnd.cups-raster"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [6] = "application/vnd.cups-raw"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [7] = "application/vnd.hp-hpgl"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [8] = "application/x-cshell"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [9] = "application/x-perl"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [10] = "application/x-shell"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [11] = "image/gif"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [12] = "image/jpeg"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [13] = "image/png"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [14] = "image/tiff"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [15] = "image/x-alias"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [16] = "image/x-bitmap"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [17] = "image/x-photocd"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [18] = "image/x-portable-anymap"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [19] = "image/x-portable-bitmap"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [20] = "image/x-portable-graymap"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [21] = "image/x-portable-pixmap"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [22] = "image/x-sgi-rgb"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [23] = "image/x-sun-raster"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [24] = "image/x-xbitmap"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [25] = "image/x-xpixmap"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [26] = "text/html"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [27] = "text/plain"
D [08/Aug/2005:10:47:43 +0100] [Job 5] [28] = "application/octet-stream"
D [08/Aug/2005:10:47:43 +0100] [Job 5] printer-uri = "ipp://s7.phyip3.dur.ac.uk:631/printers/hp2"
D [08/Aug/2005:10:47:43 +0100] [Job 5] requesting-user-name = "mn"
D [08/Aug/2005:10:47:43 +0100] [Job 5] job-name = "long_term_tasks.txt"
D [08/Aug/2005:10:47:44 +0100] AcceptClient: 9 from localhost:631.
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=0
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:44 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:44 +0100] CloseClient: 9
D [08/Aug/2005:10:47:45 +0100] AcceptClient: 9 from localhost:631.
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=0
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] ReadClient: 9 POST / HTTP/1.1
D [08/Aug/2005:10:47:45 +0100] ProcessIPPRequest: 9 status_code=1
D [08/Aug/2005:10:47:45 +0100] CloseClient: 9
D [08/Aug/2005:10:47:54 +0100] UpdateJob: job 5, file 1 is complete.
D [08/Aug/2005:10:47:54 +0100] CancelJob: id = 5
D [08/Aug/2005:10:47:54 +0100] StopJob: id = 5, force = 0
D [08/Aug/2005:10:47:54 +0100] StopJob: printer state is 3