CUPS
"Vennekötter, Matthias"
matthias.vennekoetter at bielefeld.goldbeckbau.com
Fri Dec 6 14:39:02 CET 2002
> Das ist ja auch nicht falsch. ...aber was macht der CUPS-Server zu dem
> Zeitpunkt, wenn der Client noch auf eine Antwort wartet? Das sieht man,
> wenn strace von beiden macht...
>
> MfG, JBG
anbei die Ausgabe gekürzt mit den relevanten Stellen, die ich sehe:
open("/var/spool/cups/c72855", O_WRONLY|O_CREAT|O_TRUNC, 0600)
fchmod(6, 0600) = 0
ipc_subcall(0x6, 0x4, 0x3, 0x3) = 0
write(6, "\1\1\0\2\0\0\0\1", 8) = 8
write(6, "\1G\0\22attributes-charset\0\niso-8859"..., 34) = 34
write(6, "H\0\33attributes-natural-language\0\5"..., 37) = 37
write(6, "E\0\vprinter-uri\0#ipp://boli5:631/"..., 51) = 51
write(6, "\2B\0\31job-originating-user-name\0\10b"..., 39) = 39
write(6, "\1B\0\10job-name\0\vdruckjob_12", 25) = 25
write(6, "I\0\17document-format\0\30application/"..., 44) = 44
write(6, "\2B\0\njob-sheets\0\4noneB\0\0\0\4none", 29) = 29
write(6, "!\0\fjob-priority\0\4\0\0\0002", 21) = 21
write(6, "B\0\16job-hold-until\0\7no-hold", 26) = 26
write(6, "!\0\6copies\0\4\0\0\0\1", 15) = 15
write(6, "B\0\31job-originating-host-name\0\v10"..., 41) = 41
write(6, "!\0\6job-id\0\4\0\1\34\227", 15) = 15
write(6, "#\0\tjob-state\0\4\0\0\0\3", 18) = 18
write(6, "!\0\32job-media-sheets-completed\0\4\0"..., 35) = 35
write(6, "E\0\17job-printer-uri\0$http://boli5"..., 56) = 56
write(6, "B\0\10job-name\0\vdruckjob_12", 24) = 24
write(6, "!\0\fjob-k-octets\0\4\0\0\0\264", 21) = 21
write(6, "!\0\20time-at-creation\0\4=\360P|", 25) = 25
write(6, "\23\0\22time-at-processing\0\0", 23) = 23
write(6, "\23\0\21time-at-completed\0\0", 22) = 22
write(6, "\3", 1) = 1
close(6) = 0
pipe([6, 8]) = 0
open("/dev/null", O_RDONLY) = 9
open("/dev/null", O_WRONLY) = 10
fork() = 6061
close(9) = 0
close(-1) = -1 EBADF (Bad file
descriptor)
close(-1) = -1 EBADF (Bad file
descriptor)
close(10) = 0
close(8) = 0
send(4, "HTTP/1.1 200 OK\r\n", 17, 0) = 17
send(4, "Date: Fri, 06 Dec 2002 07:23:41 "..., 37, 0) = 37
send(4, "Server: CUPS/1.1\r\n", 18, 0) = 18
send(4, "Connection: Keep-Alive\r\n", 24, 0) = 24
send(4, "Keep-Alive: timeout=60\r\n", 24, 0) = 24
send(4, "Content-Language: C\r\n", 21, 0) = 21
send(4, "Content-Type: application/ipp; c"..., 51, 0) = 51
send(4, "Content-Length: 187\r\n\r\n", 23, 0) = 23
.
.
.
send(4, "D\0\21job-state-reasons\0\fjob-printi"..., 34, 0) = 34
send(4, "\3", 1, 0) = 1
_llseek(3, 0, [445223], SEEK_CUR) = 0
write(3, "100.20.0.36 - - [06/Dec/2002:08:"..., 93) = 93
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {0,
990000})
read(6, "DEBUG: lpd_command returning 0\nD"..., 1023) = 238
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "DEBUG: lpd_command returning 0\nI"..., 1023) = 224
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "DEBUG: lpd_command returning 0\nI"..., 1023) = 148
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 8% compl"..., 1023) = 39
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 13% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {0,
990000})
read(6, "INFO: Spooling LPR job, 17% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 22% comp"..., 1023) = 80
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 31% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [4], left {1,
0})
.
.
.
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 57% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 62% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 66% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 71% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 75% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 80% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 84% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 89% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 93% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "INFO: Spooling LPR job, 98% comp"..., 1023) = 40
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
--- SIGCHLD (Child exited) ---
wait4(-1, [WIFEXITED(s) && WEXITSTATUS(s) == 0], WNOHANG, NULL) =
6061
wait4(-1, 0xbfffb818, WNOHANG, NULL) = -1 ECHILD (No child
processes)
sigreturn() = ? (mask now [])
read(6, "INFO: Data file sent successfull"..., 1023) = 44
_llseek(7, 0, [65042], SEEK_CUR) = 0
write(7, "bilj5si1a4 blabusch 72855 [06/De"..., 60) = 60
select(1024, [0 1 2 4 6], [], NULL, {1, 0}) = 1 (in [6], left {1,
0})
read(6, "", 1023) = 0
close(6) = 0
open("/var/spool/cups/c72855", O_WRONLY|O_CREAT|O_TRUNC, 0600) = 6
fchmod(6, 0600) = 0
ipc_subcall(0x6, 0x4, 0x3, 0x3) = 0
write(6, "\1\1\0\2\0\0\0\1", 8) = 8
write(6, "\1G\0\22attributes-charset\0\niso-8859"..., 34) = 34
write(6, "H\0\33attributes-natural-language\0\5"..., 37) = 37
write(6, "E\0\vprinter-uri\0#ipp://boli5:631/"..., 51) = 51
write(6, "\2B\0\31job-originating-user-name\0\10b"..., 39) = 39
write(6, "\1B\0\10job-name\0\vdruckjob_12", 25) = 25
write(6, "I\0\17document-format\0\30application/"..., 44) = 44
write(6, "\2B\0\njob-sheets\0\4noneB\0\0\0\4none", 29) = 29
write(6, "!\0\fjob-priority\0\4\0\0\0002", 21) = 21
write(6, "B\0\16job-hold-until\0\7no-hold", 26) = 26
write(6, "!\0\6copies\0\4\0\0\0\1", 15) = 15
write(6, "B\0\31job-originating-host-name\0\v10"..., 41) = 41
write(6, "!\0\6job-id\0\4\0\1\34\227", 15) = 15
write(6, "#\0\tjob-state\0\4\0\0\0\7", 18) = 18
write(6, "!\0\32job-media-sheets-completed\0\4\0"..., 35) = 35
write(6, "E\0\17job-printer-uri\0$http://boli5"..., 56) = 56
write(6, "B\0\10job-name\0\vdruckjob_12", 24) = 24
write(6, "!\0\fjob-k-octets\0\4\0\0\0\264", 21) = 21
write(6, "!\0\20time-at-creation\0\4=\360P|", 25) = 25
write(6, "!\0\22time-at-processing\0\4=\360P}", 27) = 27
write(6, "!\0\21time-at-completed\0\4=\360P}", 26) = 26
write(6, "\3", 1) = 1
close(6) = 0
open("/var/spool/cups/c72855", O_WRONLY|O_CREAT|O_TRUNC, 0600) = 6
fchmod(6, 0600) = 0
ipc_subcall(0x6, 0x4, 0x3, 0x3) = 0
write(6, "\1\1\0\2\0\0\0\1", 8) = 8
write(6, "\1G\0\22attributes-charset\0\niso-8859"..., 34) = 34
write(6, "H\0\33attributes-natural-language\0\5"..., 37) = 37
write(6, "E\0\vprinter-uri\0#ipp://boli5:631/"..., 51) = 51
write(6, "\2B\0\31job-originating-user-name\0\10b"..., 39) = 39
write(6, "\1B\0\10job-name\0\vdruckjob_12", 25) = 25
write(6, "I\0\17document-format\0\30application/"..., 44) = 44
write(6, "\2B\0\njob-sheets\0\4noneB\0\0\0\4none", 29) = 29
write(6, "!\0\fjob-priority\0\4\0\0\0002", 21) = 21
write(6, "B\0\16job-hold-until\0\7no-hold", 26) = 26
write(6, "!\0\6copies\0\4\0\0\0\1", 15) = 15
write(6, "B\0\31job-originating-host-name\0\v10"..., 41) = 41
write(6, "!\0\6job-id\0\4\0\1\34\227", 15) = 15
write(6, "#\0\tjob-state\0\4\0\0\0\t", 18) = 18
write(6, "!\0\32job-media-sheets-completed\0\4\0"..., 35) = 35
write(6, "E\0\17job-printer-uri\0$http://boli5"..., 56) = 56
write(6, "B\0\10job-name\0\vdruckjob_12", 24) = 24
write(6, "!\0\fjob-k-octets\0\4\0\0\0\264", 21) = 21
write(6, "!\0\20time-at-creation\0\4=\360P|", 25) = 25
write(6, "!\0\22time-at-processing\0\4=\360P}", 27) = 27
write(6, "!\0\21time-at-completed\0\4=\360P}", 26) = 26
write(6, "\3", 1) = 1
close(6) = 0
Interpretation:
Job meldet sich mit Nr. 72855 und wird gespoolt
"DEBUG: lpd_command returning 0\nD"..., 1023) = 238
Was passiert hier, antwortet das lp-Kommando des Clients nicht,
warum?
Dann wird nach und nach gespoolt, beim normalen Job taucht nur
einmal eine % Angabe auf,
hier gleich mehrmals, irgendwann ist er dann fertig
mfg
Matthias Vennekötter
More information about the Linux
mailing list