lpd backend stops with status 1 >> all working now!
ariovist at lowa.r.shuttle.de
ariovist at lowa.r.shuttle.de
Thu Oct 7 12:14:36 PDT 2004
Hi,
I thank you very much!
Following your advice, all is working now!
Helge Blischke wrote:
> As SuSE modified its CUPS setup (starting with 9.0, I think) to match
> somewhat
> paranoic (in my opinion) security constraints, I'd suggest the
> following:
> (1) Delete the RunAsUser directive from cupsd.conf (follow the hints
> from
>
> http://portal.suse.com/sdb/en/2003/09/jsmeix_print-einrichten-90.html)
> (2) Append "?reserve=yes" (without the quotes) to your device URI.
>
> Why?
> I suspect your lpd print server requires the source port to be a
> reserved port
> (below 1024). The lpd backend does this only with the said option (from
> 1.1.18 on,
> I think, but I'm not sure), and to aquire reserved ports, the process
> must be
> running as root (at this time at least).
>
> Helge
>
>
>
> ariovist at r.lowa.shuttle.de wrote:
> >
> > Hi Folks!
> >
> > After updating to SuSE 9.1, CUPS(1.1.20-103) cannot print to remote lpd server.
> > I extracted a debug2 -sequence which shows the CUPS server start and one try to connect to the remote lpd-raw queue (no lines dropped). The lpd-daemon refuses the cups-backend request with lpd-error 47 and the backend stops with status 1. All previous steps seem to be O.K.
> >
> > A TCP-dump of this connect-sequence shows returned data from lpd containing a string "Malformed." where I suppose CUPS does not speak lpd-protocol correctly. I tried several configurations with compatible printer models, but the behaviour is always the same.
> >
> > Thanks in advance for your Help
> >
> > I [27/Sep/2004:21:38:36 +0200] Listening to 0:631
> > D [27/Sep/2004:21:38:36 +0200] AddLocation: added location 'CUPS_INTERNAL_BROWSE_ACL'
> > D [27/Sep/2004:21:38:36 +0200] AllowHost: CUPS_INTERNAL_BROWSE_ACL allow @LOCAL
> > D [27/Sep/2004:21:38:36 +0200] DenyIP: CUPS_INTERNAL_BROWSE_ACL deny 00000000/00000000
> > D [27/Sep/2004:21:38:36 +0200] AddLocation: added location '/'
> > D [27/Sep/2004:21:38:36 +0200] DenyIP: / deny 00000000/00000000
> > D [27/Sep/2004:21:38:36 +0200] AllowIP: / allow 7f000001/ffffffff
> > D [27/Sep/2004:21:38:36 +0200] AllowIP: / allow 7f000002/ffffffff
> > D [27/Sep/2004:21:38:36 +0200] AllowHost: / allow @LOCAL
> > D [27/Sep/2004:21:38:36 +0200] AddLocation: added location '/admin'
> > D [27/Sep/2004:21:38:36 +0200] DenyIP: /admin deny 00000000/00000000
> > D [27/Sep/2004:21:38:36 +0200] AllowIP: /admin allow 7f000001/ffffffff
> > I [27/Sep/2004:21:38:36 +0200] Loaded configuration file "/etc/cups/cupsd.conf"
> > I [27/Sep/2004:21:38:36 +0200] Configured for up to 100 clients.
> > I [27/Sep/2004:21:38:36 +0200] Allowing up to 100 client connections per host.
> > I [27/Sep/2004:21:38:36 +0200] Full reload is required.
> > D [27/Sep/2004:21:38:36 +0200] LoadAllPrinters: Loading printer lp0...
> > d [27/Sep/2004:21:38:36 +0200] AddPrinter("lp0")
> > d [27/Sep/2004:21:38:36 +0200] Adding filter application/vnd.cups-raw printer/lp0 0 -
> > d [27/Sep/2004:21:38:36 +0200] FindBest: uri = "/printers/lp0"...
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:38:36 +0200] FindBest: best = "/"
> > d [27/Sep/2004:21:38:36 +0200] Adding filter application/vnd.cups-postscript printer/lp0 0 foomatic-rip
> > D [27/Sep/2004:21:38:36 +0200] LoadAllPrinters: Loading printer lp1...
> > d [27/Sep/2004:21:38:36 +0200] AddPrinter("lp1")
> > d [27/Sep/2004:21:38:36 +0200] Adding filter application/vnd.cups-raw printer/lp1 0 -
> > d [27/Sep/2004:21:38:36 +0200] FindBest: uri = "/printers/lp1"...
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:38:36 +0200] FindBest: best = "/"
> > d [27/Sep/2004:21:38:36 +0200] Adding filter application/vnd.cups-postscript printer/lp1 0 foomatic-rip
> > D [27/Sep/2004:21:38:36 +0200] LoadAllPrinters: Loading printer lpdj...
> > d [27/Sep/2004:21:38:36 +0200] AddPrinter("lpdj")
> > d [27/Sep/2004:21:38:36 +0200] Adding filter application/vnd.cups-raw printer/lpdj 0 -
> > d [27/Sep/2004:21:38:36 +0200] FindBest: uri = "/printers/lpdj"...
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:38:36 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:38:36 +0200] FindBest: best = "/"
> > d [27/Sep/2004:21:38:36 +0200] Adding filter application/vnd.cups-raster printer/lpdj 100 rastertoprinter
> > D [27/Sep/2004:21:38:36 +0200] LoadDevices: Added device "parallel:/dev/lp0"...
> > D [27/Sep/2004:21:38:36 +0200] LoadDevices: Added device "http"...
> > D [27/Sep/2004:21:38:36 +0200] LoadDevices: Added device "ipp"...
> > D [27/Sep/2004:21:38:36 +0200] LoadDevices: Added device "lpd"...
> > D [27/Sep/2004:21:38:36 +0200] LoadDevices: Added device "novell"...
> > D [27/Sep/2004:21:38:36 +0200] LoadDevices: Added device "pipe"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "scsi"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "smb"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS0?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS1?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS2?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS3?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS4?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS5?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS6?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS7?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS8?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS9?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS10?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS11?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS12?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS13?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS14?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS15?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS16?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS17?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS18?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS19?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS20?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS21?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS22?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "serial:/dev/ttyS23?baud=115200"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "socket"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp0"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp1"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp2"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp3"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp4"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp5"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp6"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp7"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp8"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp9"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp10"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp11"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp12"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp13"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp14"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "usb:/dev/usb/lp15"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "canon:/dev/lp0"...
> > D [27/Sep/2004:21:38:37 +0200] LoadDevices: Added device "epson:/dev/lp0"...
> > I [27/Sep/2004:21:38:37 +0200] LoadPPDs: Read "/etc/cups/ppds.dat", 3593 PPDs...
> > I [27/Sep/2004:21:38:37 +0200] LoadPPDs: No new or changed PPDs...
> > D [27/Sep/2004:21:38:37 +0200] LoadAllJobs: Scanning /var/spool/cups...
> > D [27/Sep/2004:21:38:37 +0200] LoadAllJobs: Loading attributes for job 1...
> > D [27/Sep/2004:21:38:37 +0200] LoadAllJobs: Loading attributes for job 4...
> > D [27/Sep/2004:21:38:37 +0200] LoadAllJobs: Loading attributes for job 2...
> > D [27/Sep/2004:21:38:37 +0200] LoadAllJobs: Auto-typing document file d00004-001...
> > I [27/Sep/2004:21:38:37 +0200] Full reload complete.
> > D [27/Sep/2004:21:38:37 +0200] StartListening: NumListeners=1
> > D [27/Sep/2004:21:38:37 +0200] StartListening: address=00000000 port=631
> > D [27/Sep/2004:21:38:37 +0200] ResumeListening: setting input bits...
> > d [27/Sep/2004:21:38:37 +0200] ResumeListening: Adding fd 0 to InputSet...
> > d [27/Sep/2004:21:38:37 +0200] StartBrowsing: Adding fd 2 to InputSet...
> > d [27/Sep/2004:21:38:37 +0200] StartServer: Adding fd 3 to InputSet...
> > d [27/Sep/2004:21:38:37 +0200] AddCert: adding certificate for pid 0
> > d [27/Sep/2004:21:39:59 +0200] AcceptClient(lis=0x808b770) 0 NumClients = 0
> > D [27/Sep/2004:21:39:59 +0200] AcceptClient: 9 from localhost:631.
> > d [27/Sep/2004:21:39:59 +0200] AcceptClient: Adding fd 9 to InputSet...
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 9, used=0, file=-1
> > D [27/Sep/2004:21:39:59 +0200] ReadClient() 9 GET /printers HTTP/1.1
> > d [27/Sep/2004:21:39:59 +0200] decode_auth(0x4038c008): Authorization string = "Basic cm9vdDpDaGlsZGVyaWNoMQ=="
> > d [27/Sep/2004:21:39:59 +0200] decode_auth() 9 username="root"
> > d [27/Sep/2004:21:39:59 +0200] IsAuthorized: con->uri = "/printers"
> > d [27/Sep/2004:21:39:59 +0200] FindBest: uri = "/printers"...
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:39:59 +0200] FindBest: best = "/"
> > d [27/Sep/2004:21:39:59 +0200] IsAuthorized: auth = 0, satisfy=0...
> > d [27/Sep/2004:21:39:59 +0200] argv[0] = "printers.cgi"
> > d [27/Sep/2004:21:39:59 +0200] envp[0] = "PATH=/bin:/usr/bin"
> > d [27/Sep/2004:21:39:59 +0200] envp[1] = "SERVER_SOFTWARE=CUPS/1.1"
> > d [27/Sep/2004:21:39:59 +0200] envp[2] = "GATEWAY_INTERFACE=CGI/1.1"
> > d [27/Sep/2004:21:39:59 +0200] envp[3] = "SERVER_PROTOCOL=HTTP/1.1"
> > d [27/Sep/2004:21:39:59 +0200] envp[4] = "REDIRECT_STATUS=1"
> > d [27/Sep/2004:21:39:59 +0200] envp[5] = "CUPS_SERVER=localhost"
> > d [27/Sep/2004:21:39:59 +0200] envp[6] = "IPP_PORT=631"
> > d [27/Sep/2004:21:39:59 +0200] envp[7] = "SERVER_NAME=localhost"
> > d [27/Sep/2004:21:39:59 +0200] envp[8] = "SERVER_PORT=631"
> > d [27/Sep/2004:21:39:59 +0200] envp[9] = "REMOTE_ADDR=127.0.0.1"
> > d [27/Sep/2004:21:39:59 +0200] envp[10] = "REMOTE_HOST=localhost"
> > d [27/Sep/2004:21:39:59 +0200] envp[11] = "REMOTE_USER=root"
> > d [27/Sep/2004:21:39:59 +0200] envp[12] = "LANG=de.UTF-8"
> > d [27/Sep/2004:21:39:59 +0200] envp[13] = ""
> > d [27/Sep/2004:21:39:59 +0200] envp[14] = "TMPDIR=/var/spool/cups/tmp"
> > d [27/Sep/2004:21:39:59 +0200] envp[15] = "CUPS_DATADIR=/usr/share/cups"
> > d [27/Sep/2004:21:39:59 +0200] envp[16] = "CUPS_SERVERROOT=/etc/cups"
> > d [27/Sep/2004:21:39:59 +0200] envp[17] = "HTTP_USER_AGENT=Mozilla/5.0 (compatible; Konqueror/3.2; Linux) (KHTML, like Gecko)"
> > d [27/Sep/2004:21:39:59 +0200] envp[18] = "SCRIPT_NAME=/printers"
> > d [27/Sep/2004:21:39:59 +0200] envp[19] = "REQUEST_METHOD=GET"
> > d [27/Sep/2004:21:39:59 +0200] AddCert: adding certificate for pid 5953
> > D [27/Sep/2004:21:39:59 +0200] CGI /usr/lib/cups/cgi-bin/printers.cgi started - PID = 5953
> > I [27/Sep/2004:21:39:59 +0200] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=5953)
> > D [27/Sep/2004:21:39:59 +0200] SendCommand: 9 file=11
> > d [27/Sep/2004:21:39:59 +0200] SendCommand: Adding fd 11 to InputSet...
> > d [27/Sep/2004:21:39:59 +0200] SendCommand: Adding fd 9 to OutputSet...
> > d [27/Sep/2004:21:39:59 +0200] AcceptClient(lis=0x808b770) 0 NumClients = 1
> > D [27/Sep/2004:21:39:59 +0200] AcceptClient: 14 from localhost:631.
> > d [27/Sep/2004:21:39:59 +0200] AcceptClient: Adding fd 14 to InputSet...
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: 9 Content-Type: text/html;charset=utf-8
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: 9
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: 9 1174 bytes
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14, used=0, file=-1
> > D [27/Sep/2004:21:39:59 +0200] ReadClient() 14 POST / HTTP/1.1
> > d [27/Sep/2004:21:39:59 +0200] decode_auth(0x4038ec3c): Authorization string = ""
> > d [27/Sep/2004:21:39:59 +0200] decode_auth() 14 username=""
> > d [27/Sep/2004:21:39:59 +0200] IsAuthorized: con->uri = "/"
> > d [27/Sep/2004:21:39:59 +0200] FindBest: uri = "/"...
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:39:59 +0200] FindBest: best = "/"
> > d [27/Sep/2004:21:39:59 +0200] IsAuthorized: auth = 0, satisfy=0...
> > d [27/Sep/2004:21:39:59 +0200] POST /
> > d [27/Sep/2004:21:39:59 +0200] CONTENT_TYPE = application/ipp
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14 con->data_encoding = length, con->data_remaining = 135, con->file = -1
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14, used=0, file=-1
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14 con->data_encoding = length, con->data_remaining = 127, con->file = -1
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14, used=98, file=-1
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14 con->data_encoding = length, con->data_remaining = 98, con->file = -1
> > d [27/Sep/2004:21:39:59 +0200] ProcessIPPRequest(0x4038ec3c[14]): operation_id = 4001
> > d [27/Sep/2004:21:39:59 +0200] get_default(0x4038ec3c[14])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216c10, 0x80955c8, 0x8216b28, 0)
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216c10, 0x80955f0[printer-uri-supported,4,45])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216c10, 0x8095728[printer-name,4,42])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216c10, 0x80950d0, 0x8216b28, 0)
> > D [27/Sep/2004:21:39:59 +0200] ProcessIPPRequest: 14 status_code=1
> > d [27/Sep/2004:21:39:59 +0200] ProcessIPPRequest: Adding fd 14 to OutputSet...
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: Removing fd 14 from OutputSet...
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14, used=0, file=-1
> > D [27/Sep/2004:21:39:59 +0200] ReadClient() 14 POST / HTTP/1.1
> > d [27/Sep/2004:21:39:59 +0200] decode_auth(0x4038ec3c): Authorization string = ""
> > d [27/Sep/2004:21:39:59 +0200] decode_auth() 14 username=""
> > d [27/Sep/2004:21:39:59 +0200] IsAuthorized: con->uri = "/"
> > d [27/Sep/2004:21:39:59 +0200] FindBest: uri = "/"...
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:39:59 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:39:59 +0200] FindBest: best = "/"
> > d [27/Sep/2004:21:39:59 +0200] IsAuthorized: auth = 0, satisfy=0...
> > d [27/Sep/2004:21:39:59 +0200] POST /
> > d [27/Sep/2004:21:39:59 +0200] CONTENT_TYPE = application/ipp
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14 con->data_encoding = length, con->data_remaining = 811, con->file = -1
> > d [27/Sep/2004:21:39:59 +0200] ProcessIPPRequest(0x4038ec3c[14]): operation_id = 4002
> > d [27/Sep/2004:21:39:59 +0200] get_printers(0x4038ec3c[14], 0)
> > d [27/Sep/2004:21:39:59 +0200] add_printer_state_reasons(0x4038ec3c[14], 0x8097c88[lp0])
> > d [27/Sep/2004:21:39:59 +0200] add_queued_job_count(0x4038ec3c[14], 0x8097c88[lp0])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216d50, 0x80955c8, 0x8217070, 0)
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80955f0[printer-uri-supported,4,45])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x8095728[printer-name,4,42])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x8095778[printer-location,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80957c8[printer-info,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80959a0[device-uri,4,45])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80a79b8[printer-make-and-model,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216d50, 0x80950d0, 0x8217070, 0)
> > d [27/Sep/2004:21:39:59 +0200] add_printer_state_reasons(0x4038ec3c[14], 0x80a5dd8[lp1])
> > d [27/Sep/2004:21:39:59 +0200] add_queued_job_count(0x4038ec3c[14], 0x80a5dd8[lp1])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216d50, 0x809bae8, 0x8217070, 0)
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x809bb10[printer-uri-supported,4,45])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x809bce0[printer-name,4,42])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x8095b68[printer-location,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x8095ba0[printer-info,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80a7608[device-uri,4,45])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80a8b78[printer-make-and-model,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216d50, 0x80950d0, 0x8217070, 0)
> > d [27/Sep/2004:21:39:59 +0200] add_printer_state_reasons(0x4038ec3c[14], 0x80a62a8[lpdj])
> > d [27/Sep/2004:21:39:59 +0200] add_queued_job_count(0x4038ec3c[14], 0x80a62a8[lpdj])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216d50, 0x808c838, 0x8217070, 0)
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80975c0[printer-uri-supported,4,45])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80a6ad8[printer-name,4,42])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80a6b28[printer-location,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x8097a78[printer-info,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80a3348[device-uri,4,45])
> > d [27/Sep/2004:21:39:59 +0200] copy_attribute(0x8216d50, 0x80a1a38[printer-make-and-model,4,41])
> > d [27/Sep/2004:21:39:59 +0200] copy_attrs(0x8216d50, 0x80950d0, 0x8217070, 0)
> > D [27/Sep/2004:21:39:59 +0200] ProcessIPPRequest: 14 status_code=1
> > d [27/Sep/2004:21:39:59 +0200] ProcessIPPRequest: Adding fd 14 to OutputSet...
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: Removing fd 14 from OutputSet...
> > d [27/Sep/2004:21:39:59 +0200] PID 5953 exited with no errors.
> > d [27/Sep/2004:21:39:59 +0200] DeleteCert: removing certificate for pid 5953
> > d [27/Sep/2004:21:39:59 +0200] ReadClient() 14, used=0, file=-1
> > d [27/Sep/2004:21:39:59 +0200] ReadClient: httpGets returned EOF...
> > D [27/Sep/2004:21:39:59 +0200] CloseClient() 14
> > d [27/Sep/2004:21:39:59 +0200] CloseClient: Removing fd 14 from InputSet and OutputSet...
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: Removing fd 9 from OutputSet...
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: Removing fd 11 from InputSet...
> > d [27/Sep/2004:21:39:59 +0200] WriteClient: 9 Closing data file 11.
> > d [27/Sep/2004:21:40:04 +0200] ReadClient() 9, used=0, file=-1
> > d [27/Sep/2004:21:40:04 +0200] ReadClient: httpGets returned EOF...
> > D [27/Sep/2004:21:40:04 +0200] CloseClient() 9
> > d [27/Sep/2004:21:40:04 +0200] CloseClient: Removing fd 9 from InputSet and OutputSet...
> > d [27/Sep/2004:21:40:04 +0200] AcceptClient(lis=0x808b770) 0 NumClients = 0
> > D [27/Sep/2004:21:40:04 +0200] AcceptClient: 9 from localhost:631.
> > d [27/Sep/2004:21:40:04 +0200] AcceptClient: Adding fd 9 to InputSet...
> > d [27/Sep/2004:21:40:04 +0200] ReadClient() 9, used=0, file=-1
> > D [27/Sep/2004:21:40:04 +0200] ReadClient() 9 GET /admin/?op=start-printer&printer_name=lp1 HTTP/1.1
> > d [27/Sep/2004:21:40:04 +0200] decode_auth(0x4038c008): Authorization string = "Basic cm9vdDpDaGlsZGVyaWNoMQ=="
> > d [27/Sep/2004:21:40:04 +0200] decode_auth() 9 username="root"
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: con->uri = "/admin/?op=start-printer&printer_name=lp1"
> > d [27/Sep/2004:21:40:04 +0200] FindBest: uri = "/admin/?op=start-printer&printer_name=lp1"...
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: best = "/admin"
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: auth = 0, satisfy=0...
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: username = "root" password = 11 chars
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: Checking "root", address = 7f000001, hostname = "localhost"
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: num_names = 1
> > d [27/Sep/2004:21:40:04 +0200] GetMD5Passwd(username="root", group="sys", passwd=0xbfff02f0)
> > d [27/Sep/2004:21:40:04 +0200] Found MD5 user root, group sys...
> > d [27/Sep/2004:21:40:04 +0200] argv[0] = ""
> > d [27/Sep/2004:21:40:04 +0200] envp[0] = "PATH=/bin:/usr/bin"
> > d [27/Sep/2004:21:40:04 +0200] envp[1] = "SERVER_SOFTWARE=CUPS/1.1"
> > d [27/Sep/2004:21:40:04 +0200] envp[2] = "GATEWAY_INTERFACE=CGI/1.1"
> > d [27/Sep/2004:21:40:04 +0200] envp[3] = "SERVER_PROTOCOL=HTTP/1.1"
> > d [27/Sep/2004:21:40:04 +0200] envp[4] = "REDIRECT_STATUS=1"
> > d [27/Sep/2004:21:40:04 +0200] envp[5] = "CUPS_SERVER=localhost"
> > d [27/Sep/2004:21:40:04 +0200] envp[6] = "IPP_PORT=631"
> > d [27/Sep/2004:21:40:04 +0200] envp[7] = "SERVER_NAME=localhost"
> > d [27/Sep/2004:21:40:04 +0200] envp[8] = "SERVER_PORT=631"
> > d [27/Sep/2004:21:40:04 +0200] envp[9] = "REMOTE_ADDR=127.0.0.1"
> > d [27/Sep/2004:21:40:04 +0200] envp[10] = "REMOTE_HOST=localhost"
> > d [27/Sep/2004:21:40:04 +0200] envp[11] = "REMOTE_USER=root"
> > d [27/Sep/2004:21:40:04 +0200] envp[12] = "LANG=de.UTF-8"
> > d [27/Sep/2004:21:40:04 +0200] envp[13] = ""
> > d [27/Sep/2004:21:40:04 +0200] envp[14] = "TMPDIR=/var/spool/cups/tmp"
> > d [27/Sep/2004:21:40:04 +0200] envp[15] = "CUPS_DATADIR=/usr/share/cups"
> > d [27/Sep/2004:21:40:04 +0200] envp[16] = "CUPS_SERVERROOT=/etc/cups"
> > d [27/Sep/2004:21:40:04 +0200] envp[17] = "HTTP_USER_AGENT=Mozilla/5.0 (compatible; Konqueror/3.2; Linux) (KHTML, like Gecko)"
> > d [27/Sep/2004:21:40:04 +0200] envp[18] = "SCRIPT_NAME=/admin/"
> > d [27/Sep/2004:21:40:04 +0200] envp[19] = "REQUEST_METHOD=GET"
> > d [27/Sep/2004:21:40:04 +0200] envp[20] = "QUERY_STRING=op=start-printer&printer_name=lp1"
> > d [27/Sep/2004:21:40:04 +0200] AddCert: adding certificate for pid 5954
> > D [27/Sep/2004:21:40:04 +0200] CGI /usr/lib/cups/cgi-bin/admin.cgi started - PID = 5954
> > I [27/Sep/2004:21:40:04 +0200] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=5954)
> > D [27/Sep/2004:21:40:04 +0200] SendCommand: 9 file=14
> > d [27/Sep/2004:21:40:04 +0200] SendCommand: Adding fd 14 to InputSet...
> > d [27/Sep/2004:21:40:04 +0200] SendCommand: Adding fd 9 to OutputSet...
> > d [27/Sep/2004:21:40:04 +0200] WriteClient: 9 Content-Type: text/html;charset=utf-8
> > d [27/Sep/2004:21:40:04 +0200] WriteClient: 9
> > d [27/Sep/2004:21:40:04 +0200] WriteClient: 9 1170 bytes
> > d [27/Sep/2004:21:40:04 +0200] AcceptClient(lis=0x808b770) 0 NumClients = 1
> > D [27/Sep/2004:21:40:04 +0200] AcceptClient: 11 from localhost:631.
> > d [27/Sep/2004:21:40:04 +0200] AcceptClient: Adding fd 11 to InputSet...
> > d [27/Sep/2004:21:40:04 +0200] ReadClient() 11, used=0, file=-1
> > D [27/Sep/2004:21:40:04 +0200] ReadClient() 11 POST /admin/ HTTP/1.1
> > d [27/Sep/2004:21:40:04 +0200] decode_auth(0x4038ec3c): Authorization string = ""
> > d [27/Sep/2004:21:40:04 +0200] decode_auth() 11 username=""
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: con->uri = "/admin/"
> > d [27/Sep/2004:21:40:04 +0200] FindBest: uri = "/admin/"...
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: best = "/admin"
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: auth = 0, satisfy=0...
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: username = "" password = 0 chars
> > d [27/Sep/2004:21:40:04 +0200] ReadClient: Unauthorized request for /admin/...
> > D [27/Sep/2004:21:40:04 +0200] SendError() 11 code=401 (Unauthorized)
> > d [27/Sep/2004:21:40:04 +0200] FindBest: uri = "/admin/"...
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: best = "/admin"
> > D [27/Sep/2004:21:40:04 +0200] CloseClient() 11
> > d [27/Sep/2004:21:40:04 +0200] CloseClient: Removing fd 11 from InputSet and OutputSet...
> > d [27/Sep/2004:21:40:04 +0200] AcceptClient(lis=0x808b770) 0 NumClients = 1
> > D [27/Sep/2004:21:40:04 +0200] AcceptClient: 11 from localhost:631.
> > d [27/Sep/2004:21:40:04 +0200] AcceptClient: Adding fd 11 to InputSet...
> > d [27/Sep/2004:21:40:04 +0200] ReadClient() 11, used=0, file=-1
> > D [27/Sep/2004:21:40:04 +0200] ReadClient() 11 POST /admin/ HTTP/1.1
> > d [27/Sep/2004:21:40:04 +0200] decode_auth(0x4038ec3c): Authorization string = "Local EA2A908A3B6E63CCD99CD45A27728707"
> > d [27/Sep/2004:21:40:04 +0200] decode_auth() 11 username="root"
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: con->uri = "/admin/"
> > d [27/Sep/2004:21:40:04 +0200] FindBest: uri = "/admin/"...
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location / Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: Location /admin Limit 7f
> > d [27/Sep/2004:21:40:04 +0200] FindBest: best = "/admin"
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: auth = 0, satisfy=0...
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: username = "root" password = 0 chars
> > d [27/Sep/2004:21:40:04 +0200] IsAuthorized: Checking "root", address = 7f000001, hostname = "localhost"
> > d [27/Sep/2004:21:40:04 +0200] POST /admin/
> > d [27/Sep/2004:21:40:04 +0200] CONTENT_TYPE = application/ipp
> > d [27/Sep/2004:21:40:04 +0200] ReadClient() 11 con->data_encoding = length, con->data_remaining = 116, con->file = -1
> > d [27/Sep/2004:21:40:04 +0200] ProcessIPPRequest(0x4038ec3c[11]): operation_id = 0011
> > d [27/Sep/2004:21:40:04 +0200] start_printer(0x4038ec3c[11], ipp://localhost/printers/lp1)
> > I [27/Sep/2004:21:40:04 +0200] Saving printers.conf...
> > I [27/Sep/2004:21:40:04 +0200] Printer 'lp1' started by 'root'.
> > D [27/Sep/2004:21:40:04 +0200] StartJob(4, 0x80a5dd8)
> > D [27/Sep/2004:21:40:04 +0200] StartJob() id = 4, file = 0/1
> > D [27/Sep/2004:21:40:04 +0200] job-sheets=none,none
> > D [27/Sep/2004:21:40:04 +0200] banner_page = 0
> > D [27/Sep/2004:21:40:04 +0200] StartJob: argv = "lp1","4","root","Test Page","1","","/var/spool/cups/d00004-001"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[2]="USER=root"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[3]="CHARSET=utf-8"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[4]="LANG=de"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[5]="PPD=/etc/cups/ppd/lp1.ppd"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[7]="RIP_MAX_CACHE=8m"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[9]="CONTENT_TYPE=application/postscript"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[10]="DEVICE_URI=lpd://lowa/raw"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[11]="PRINTER=lp1"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[14]="CUPS_SERVER=localhost"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: envp[15]="IPP_PORT=631"
> > d [27/Sep/2004:21:40:04 +0200] StartJob: Allocating status buffer...
> > D [27/Sep/2004:21:40:04 +0200] StartJob: statusfds = [ 15 16 ]
> > D [27/Sep/2004:21:40:04 +0200] StartJob: filterfds[1] = [ 17 -1 ]
> > D [27/Sep/2004:21:40:04 +0200] StartJob: filter = "/usr/lib/cups/filter/pstops"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: filterfds[0] = [ 18 19 ]
> > D [27/Sep/2004:21:40:04 +0200] start_process("/usr/lib/cups/filter/pstops", 0xbffed180, 0xbffec4f0, 17, 19, 16)
> > I [27/Sep/2004:21:40:04 +0200] Started filter /usr/lib/cups/filter/pstops (PID 5955) for job 4.
> > D [27/Sep/2004:21:40:04 +0200] StartJob: filter = "/usr/lib/cups/filter/foomatic-rip"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: filterfds[1] = [ 17 20 ]
> > D [27/Sep/2004:21:40:04 +0200] start_process("/usr/lib/cups/filter/foomatic-rip", 0xbffed180, 0xbffec4f0, 18, 20, 16)
> > I [27/Sep/2004:21:40:04 +0200] Started filter /usr/lib/cups/filter/foomatic-rip (PID 5956) for job 4.
> > D [27/Sep/2004:21:40:04 +0200] StartJob: backend = "/usr/lib/cups/backend/lpd"
> > D [27/Sep/2004:21:40:04 +0200] StartJob: filterfds[0] = [ -1 18 ]
> > D [27/Sep/2004:21:40:04 +0200] start_process("/usr/lib/cups/backend/lpd", 0xbffed180, 0xbffec4f0, 17, 18, 16)
> > I [27/Sep/2004:21:40:04 +0200] Started backend /usr/lib/cups/backend/lpd (PID 5957) for job 4.
> > d [27/Sep/2004:21:40:04 +0200] StartJob: Adding fd 15 to InputSet...
> > D [27/Sep/2004:21:40:04 +0200] ProcessIPPRequest: 11 status_code=0
> > d [27/Sep/2004:21:40:04 +0200] ProcessIPPRequest: Adding fd 11 to OutputSet...
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] Page = 595x842; 24,48 to 571,818
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] slowcollate=0, slowduplex=0, sloworder=0
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%BoundingBox: 0 0 612 792
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%Pages: 1
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%LanguageLevel: 1
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%DocumentData: Clean7Bit
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%DocumentSuppliedResources: procset testprint/1.0
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%DocumentNeededResources: font Helvetica Helvetica-Bold Times-Roman
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%Creator: Michael Sweet, Easy Software Products
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%CreationDate: May 11, 1999
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%Title: Test Page
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%EndComments
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%BeginProlog
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%BeginResource procset testprint 1.1 0
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%EndResource
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%EndProlog
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%Page: 1 1
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] 0 %%Page: 1 1
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] pw = 547.0, pl = 770.0
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] PageLeft = 24.0, PageRight = 571.0
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] PageTop = 818.0, PageBottom = 48.0
> > D [27/Sep/2004:21:40:04 +0200] [Job 4] PageWidth = 595.0, PageLength = 842.0
> > d [27/Sep/2004:21:40:04 +0200] WriteClient: Removing fd 11 from OutputSet...
> > d [27/Sep/2004:21:40:04 +0200] ReadClient() 11, used=0, file=-1
> > d [27/Sep/2004:21:40:04 +0200] ReadClient: httpGets returned EOF...
> > D [27/Sep/2004:21:40:04 +0200] CloseClient() 11
> > d [27/Sep/2004:21:40:04 +0200] CloseClient: Removing fd 11 from InputSet and OutputSet...
> > d [27/Sep/2004:21:40:04 +0200] PID 5954 exited with no errors.
> > d [27/Sep/2004:21:40:04 +0200] DeleteCert: removing certificate for pid 5954
> > d [27/Sep/2004:21:40:04 +0200] WriteClient: Removing fd 9 from OutputSet...
> > d [27/Sep/2004:21:40:04 +0200] WriteClient: Removing fd 14 from InputSet...
> > d [27/Sep/2004:21:40:04 +0200] WriteClient: 9 Closing data file 14.
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] foomatic-rip version $Revision: 3.43.2.2 $ running...
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Parsing PPD file ...
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option ColorSpace
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option PageSize
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option PageRegion
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option ImageableArea
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option PaperDimension
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option ColorMode
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option BlackCorrect
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option Depletion
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option Passes
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Added option Font
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Parameter Summary
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] -----------------
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Spooler: cups
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Printer: lp1
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] PPD file: /etc/cups/ppd/lp1.ppd
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Printer model: Olivetti JP350S Foomatic/cdj500
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Job title: Test Page
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] File(s) to be printed:
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] <STDIN>
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] ================================================
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] File: <STDIN>
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] ================================================
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Reading PostScript input ...
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] --> This document is DSC-conforming!
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] -----------
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%BeginProlog
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] 0 %%EOF
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Saw EOF!
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%EndProlog
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] -----------
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%BeginSetup
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Inserting PostScript code for CUPS' page accounting
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%BeginFeature: *ColorMode NormalColor
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: ColorMode=NormalColor --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %% FoomaticRIPOptionSetting: ColorMode=NormalColor
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: ColorMode=NormalColor --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%BeginFeature: *PageSize A4
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: PageSize=A4 --> Option will be set by PostScript interpreter
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%BeginFeature: *BlackCorrect 4
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: BlackCorrect=4 --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %% FoomaticRIPOptionSetting: BlackCorrect=4
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: BlackCorrect=4 --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%BeginFeature: *Depletion Default
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: Depletion=Default --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %% FoomaticRIPOptionSetting: Depletion=Default
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: Depletion=Default --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%BeginFeature: *Passes Default
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: Passes=Default --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %% FoomaticRIPOptionSetting: Passes=Default
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Option: Passes=Default --> Setting option
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found: %%EndSetup
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] -----------
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] New page: 1 1
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Inserting option code into "PageSetup" section.
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] No page header or page header not DSC-conforming
> > d [27/Sep/2004:21:40:05 +0200] PID 5955 exited with no errors.
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Stopping search for page header options
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Found:
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] pageHeight sub % Move down...
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] --> Output goes directly to the renderer now.
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] Starting renderer
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] JCL: <job data>
> > D [27/Sep/2004:21:40:05 +0200] [Job 4]
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] renderer PID kid4=5959
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] renderer command: gs -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -r300x300 -sDEVICE=cdj500 -dBitsPerPixel=3 -dBlackCorrect=4 -sOutputFile=- -
> > D [27/Sep/2004:21:40:05 +0200] [Job 4] foomatic-gswrapper: gs '-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-r300x300' '-sDEVICE=cdj500' '-dBitsPerPixel=3' '-dBlackCorrect=4' '-sOutputFile=| cat >&3' '/dev/fd/0' 3>&1 1>&2
> > D [27/Sep/2004:21:40:06 +0200] [Job 4]
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] Closing renderer
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] tail process done writing data to STDOUT
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] KID4 finished
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] KID3 exited with status 0
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] KID4 exited with status 0
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] Renderer exit stat: 0
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] KID3 finished
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] Renderer process finished
> > D [27/Sep/2004:21:40:06 +0200] [Job 4]
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] Closing foomatic-rip.
> > d [27/Sep/2004:21:40:06 +0200] PID 5956 exited with no errors.
> > I [27/Sep/2004:21:40:06 +0200] [Job 4] Attempting to connect to host lowa for printer raw
> > I [27/Sep/2004:21:40:06 +0200] [Job 4] Connected to lowa...
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] Connected on ports 515 (local 0)...
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] lpd_command 02 raw
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] Sending command string (5 bytes)...
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] Reading command status...
> > D [27/Sep/2004:21:40:06 +0200] [Job 4] lpd_command returning 47
> > E [27/Sep/2004:21:40:06 +0200] PID 5957 stopped with status 1!
> > D [27/Sep/2004:21:40:06 +0200] UpdateJob: job 4, file 0 is complete.
> > d [27/Sep/2004:21:40:06 +0200] UpdateJob: Removing fd 15 from InputSet...
> > D [27/Sep/2004:21:40:06 +0200] StopJob: id = 4, force = 0
> > I [27/Sep/2004:21:40:06 +0200] Saving printers.conf...
> > D [27/Sep/2004:21:40:06 +0200] StopJob: printer state is 5
> > d [27/Sep/2004:21:40:06 +0200] StopJob: Freeing status buffer...
> > d [27/Sep/2004:21:40:06 +0200] SaveJob: Closing file 14...
> > d [27/Sep/2004:21:41:05 +0200] ReadClient() 9, used=0, file=-1
> > d [27/Sep/2004:21:41:05 +0200] ReadClient: httpGets returned EOF...
> > D [27/Sep/2004:21:41:05 +0200] CloseClient() 9
> > d [27/Sep/2004:21:41:05 +0200] CloseClient: Removing fd 9 from InputSet and OutputSet...
> > d [27/Sep/2004:21:43:37 +0200] DeleteCert: removing certificate for pid 0
> > d [27/Sep/2004:21:43:37 +0200] AddCert: adding certificate for pid 0
> >
> > ########## TCP-DUMP ##############################################
> >
> > baldur:/home/ariovist # tcpdump -i eth0 -X tcp
> > tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
> > listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
> > 21:40:06.649789 IP baldur.lowa.r.shuttle.de.32962 > lowa.lowa.r.shuttle.de.printer: S 2249915913:2249915913(0) win 5840 <mss 1460,sackOK,timestamp 2857273 0,nop,wscale 0>
> > 0x0000 4500 003c 6730 4000 4006 5038 c0a8 0101 E..<g0 at .@.P8....
> > 0x0010 c0a8 0102 80c2 0203 861a fe09 0000 0000 ................
> > 0x0020 a002 16d0 0d95 0000 0204 05b4 0402 080a ................
> > 0x0030 002b 9939 0000 0000 0103 0300 .+.9........
> > 21:40:06.661227 IP lowa.lowa.r.shuttle.de.printer > baldur.lowa.r.shuttle.de.32962: S 1803924147:1803924147(0) ack 2249915914 win 32120 <mss 1460,sackOK,timestamp 280807 2857273,nop,wscale 0>
> > 0x0000 4500 003c 14c2 4000 4006 a2a6 c0a8 0102 E..<.. at .@.......
> > 0x0010 c0a8 0101 0203 80c2 6b85 b2b3 861a fe0a ........k.......
> > 0x0020 a012 7d78 3fb7 0000 0204 05b4 0402 080a ..}x?...........
> > 0x0030 0004 48e7 002b 9939 0103 0300 ..H..+.9....
> > 21:40:06.661391 IP baldur.lowa.r.shuttle.de.32962 > lowa.lowa.r.shuttle.de.printer: . ack 1 win 5840 <nop,nop,timestamp 2857285 280807>
> > 0x0000 4500 0034 6731 4000 4006 503f c0a8 0101 E..4g1 at .@.P?....
> > 0x0010 c0a8 0102 80c2 0203 861a fe0a 6b85 b2b4 ............k...
> > 0x0020 8010 16d0 d518 0000 0101 080a 002b 9945 .............+.E
> > 0x0030 0004 48e7 ..H.
> > 21:40:06.661684 IP baldur.lowa.r.shuttle.de.32962 > lowa.lowa.r.shuttle.de.printer: P 1:6(5) ack 1 win 5840 <nop,nop,timestamp 2857285 280807>
> > 0x0000 4500 0039 6732 4000 4006 5039 c0a8 0101 E..9g2 at .@.P9....
> > 0x0010 c0a8 0102 80c2 0203 861a fe0a 6b85 b2b4 ............k...
> > 0x0020 8018 16d0 6722 0000 0101 080a 002b 9945 ....g".......+.E
> > 0x0030 0004 48e7 0272 6177 0a ..H..raw.
> > 21:40:06.663445 IP lowa.lowa.r.shuttle.de.printer > baldur.lowa.r.shuttle.de.32962: . ack 6 win 32120 <nop,nop,timestamp 280807 2857285>
> > 0x0000 4500 0034 14c3 4000 4006 a2ad c0a8 0102 E..4.. at .@.......
> > 0x0010 c0a8 0101 0203 80c2 6b85 b2b4 861a fe0f ........k.......
> > 0x0020 8010 7d78 6e6b 0000 0101 080a 0004 48e7 ..}xnk........H.
> > 0x0030 002b 9945 .+.E
> > 21:40:06.680799 IP lowa.lowa.r.shuttle.de.printer > baldur.lowa.r.shuttle.de.32962: P 1:44(43) ack 6 win 32120 <nop,nop,timestamp 280809 2857285>
> > 0x0000 4500 005f 14c4 4000 4006 a281 c0a8 0102 E.._.. at .@.......
> > 0x0010 c0a8 0101 0203 80c2 6b85 b2b4 861a fe0f ........k.......
> > 0x0020 8018 7d78 f94f 0000 0101 080a 0004 48e9 ..}x.O........H.
> > 0x0030 002b 9945 2f75 7372 2f73 6269 6e2f 6c70 .+.E/usr/sbin/lp
> > 0x0040 643a 2072 6177 3a20 4d61 6c66 6f72 6d65 d:.raw:.Malforme
> > 0x0050 6420 d.
> > 21:40:06.681190 IP baldur.lowa.r.shuttle.de.32962 > lowa.lowa.r.shuttle.de.printer: . ack 44 win 5840 <nop,nop,timestamp 2857304 280809>
> > 0x0000 4500 0034 6733 4000 4006 503d c0a8 0101 E..4g3 at .@.P=....
> > 0x0010 c0a8 0102 80c2 0203 861a fe0f 6b85 b2df ............k...
> > 0x0020 8010 16d0 d4d3 0000 0101 080a 002b 9958 .............+.X
> > 0x0030 0004 48e9 ..H.
> > 21:40:06.681909 IP baldur.lowa.r.shuttle.de.32962 > lowa.lowa.r.shuttle.de.printer: R 6:6(0) ack 44 win 5840 <nop,nop,timestamp 2857305 280809>
> > 0x0000 4500 0034 6734 4000 4006 503c c0a8 0101 E..4g4 at .@.P<....
> > 0x0010 c0a8 0102 80c2 0203 861a fe0f 6b85 b2df ............k...
> > 0x0020 8014 16d0 d4ce 0000 0101 080a 002b 9959 .............+.Y
> > 0x0030 0004 48e9 ..H.
> > 21:40:06.685734 IP lowa.lowa.r.shuttle.de.printer > baldur.lowa.r.shuttle.de.32962: R 44:44(0) ack 6 win 32120 <nop,nop,timestamp 280809 2857305>
> > 0x0000 4500 0034 14c5 4000 4006 a2ab c0a8 0102 E..4.. at .@.......
> > 0x0010 c0a8 0101 0203 80c2 6b85 b2df 861a fe0f ........k.......
> > 0x0020 8014 7d78 6e26 0000 0101 080a 0004 48e9 ..}xn&........H.
> > 0x0030 002b 9959 .+.Y
>
> --
> Helge Blischke
> Softwareentwicklung
> SRZ Berlin | Firmengruppe besscom
> http://www.srz.de
> tel: +49 30 75301-360
>
>
> H.Blischke at srz-berlin.de
> H.Blischke at srz-berlin.com
> H.Blischke at acm.org
More information about the cups
mailing list