As submitter of merged report #502100, I debugged this issue further
(installed cups-dbg), then submitted a job and waited for the 100% CPU
socket backend lockup to occur.
Did a
gdb /usr/lib/cups/backend-available/socket
and then a "bt" (no symbols listed here yet), and then did
"add-symbol-file" with base address parameter as given by
/proc/<PID>/maps, for various libraries involved here.
The result is:
(gdb) bt full
#0 0xb7f4a54e in ?? ()
No symbol table info available.
#1 0xb7fc9ff4 in backendDrainOutput (print_fd=0, device_fd=5) at runloop.c:98
nfds = 1869426291
input = {fds_bits = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1931476992,
0 <repeats 21 times>}}
print_bytes = -1080284600
bytes = -1080284472
print_buffer =
"\034\204à·\020ii\r\b/\234¿È/û·\212!á·öÓŸ·\000\000\000\000ÀÈó·Àú¶·\002\000\234¿H\207û·ÝÓŸ·L\215ú·ôOü·
ý¿·\004\223¿·ÿÿÿÿ\000\000\000\000\2004\234¿|4\234¿", '\0' <repeats 12 times>,
"Œ\033ü·P/\234¿\000\000\000\000\220u\202\r\210\215ú·¬\023l\000\024\000\000\000Œ<à·
+à·", '\0' <repeats 16 times>,
"\001\000\000\000v\004\000\000Àú¶·\210\215ú·þÑŸ·\214Êà·hÇŸ·\001\000\000\000ôOü·\220u\202\ržñ¿·p0\234¿Ï5û·`0\234¿hÇŸ·T0\234¿"...
print_ptr = 0x61680032 <Address 0x61680032 out of bounds>
timeout = {tv_sec = 0, tv_usec = 0}
#2 0xb7fc78aa in backendRunLoop (print_fd=-1208187264, device_fd=-1208193648,
use_bc=-1080271736, side_cb=0) at /usr/include/bits/stdio2.h:98
nfds = 0
input = {fds_bits = {0, 1, 0, 0, 0, -1080281036, -1080281048, 0,
-1080281024, -1080281036, -1080280972, -1208317200, -1208741829,
-1080280960, 0 <repeats 16 times>, -1209095467, 5}}
output = {fds_bits = {86688, -1080281208, -1212821024, -1212821184,
-1080277360, -1080280183, 1, 0, 90, -1080279760, 16777491, 1, 604800, 4,
-1080277380, -1080277568, -1080279670, -1080279748, 1, 0, -1080277568,
-1080277356, -1080273913, -1212220560, 0, -1208199228, 0, 1, -1080277352, 0,
1, -1080279703}}
print_bytes = 0
bc_bytes = 0
total_bytes = 0
bytes = 0
(gdb) bt full
#0 0xb7f4a54e in ?? ()
No symbol table info available.
#1 0xb7fc9ff4 in backendDrainOutput (print_fd=0, device_fd=5) at runloop.c:98
nfds = 1869426291
input = {fds_bits = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1931476992,
0 <repeats 21 times>}}
print_bytes = -1080284600
bytes = -1080284472
print_buffer =
"\034\204à·\020ii\r\b/\234¿È/û·\212!á·öÓŸ·\000\000\000\000ÀÈó·Àú¶·\002\000\234¿H\207û·ÝÓŸ·L\215ú·ôOü·
ý¿·\004\223¿·ÿÿÿÿ\000\000\000\000\2004\234¿|4\234¿", '\0' <repeats 12 times>,
"Œ\033ü·P/\234¿\000\000\000\000\220u\202\r\210\215ú·¬\023l\000\024\000\000\000Œ<à·
+à·", '\0' <repeats 16 times>,
"\001\000\000\000v\004\000\000Àú¶·\210\215ú·þÑŸ·\214Êà·hÇŸ·\001\000\000\000ôOü·\220u\202\ržñ¿·p0\234¿Ï5û·`0\234¿hÇŸ·T0\234¿"...
print_ptr = 0x61680032 <Address 0x61680032 out of bounds>
timeout = {tv_sec = 0, tv_usec = 0}
#2 0xb7fc78aa in backendRunLoop (print_fd=-1208187264, device_fd=-1208193648,
use_bc=-1080271736, side_cb=0) at /usr/include/bits/stdio2.h:98
nfds = 0
input = {fds_bits = {0, 1, 0, 0, 0, -1080281036, -1080281048, 0,
-1080281024, -1080281036, -1080280972, -1208317200, -1208741829,
-1080280960, 0 <repeats 16 times>, -1209095467, 5}}
output = {fds_bits = {86688, -1080281208, -1212821024, -1212821184,
-1080277360, -1080280183, 1, 0, 90, -1080279760, 16777491, 1, 604800, 4,
-1080277380, -1080277568, -1080279670, -1080279748, 1, 0, -1080277568,
-1080277356, -1080273913, -1212220560, 0, -1208199228, 0, 1, -1080277352, 0,
1, -1080279703}}
print_bytes = 0
bc_bytes = 0
total_bytes = 0
bytes = 0
---Type <return> to continue, or q <return> to quit---
paperout = 0
offline = 0
print_buffer = "ŽH\234¿", '\0' <repeats 21 times>,
"\030\000\000\000\000\000\000È£ú· Rü·Àšš\002ÿÿÿÿôOü·0ïó·ð\212ú·\2048\234¿[xû·š\214ú·Pñ¶·\001\000\000\000\001\000\000\000\000\000\000\000;\020ô·
\000\000\000\000\000php0\205O\204ªû·È£ú·ô/õ·\000\000\000\000Ü/õ·P붷H붷`Èó·ô/õ·\000\000\000\000\000\000\000\000ô¿¿·\000\000\000\000\002\000\000\000ü<\234¿å)¿·\000\000\000\000\001\000\000\000\001\000\000\0000=\234¿\000\004\000\000TE\234¿\b\000\004\000¬æ¶·\004",
'\0' <repeats 15 times>...
print_ptr = 0xb7e0787c "ôE"
bc_buffer =
"0.101.0.1\000ü·WÛ\223\034š\214ú·\bY\234¿Ï5û·øX\234¿`ðó·ìX\234¿ÄWü·\000\000\000\000àð¶·\001\000\000\000\000\000\000\000\001\000\000\000Ð涷\031\000\000\000\001",
'\0' <repeats 15 times>, "[EMAIL PROTECTED] Xü·", '\0' <repeats 24 times>,
"Ä\221ú·Ä\221ú·HYü·\200&ô·\004\000\000\020", '\0' <repeats 28 times>,
"Ìsà·\210\215ú·\000"...
action = {__sigaction_handler = {sa_handler = 0, sa_sigaction = 0},
sa_mask = {__val = {4294967295, 3086766068, 3082134176, 3086798488,
3214685904, 3086710875, 3086798928, 3086799328, 1, 1, 0, 3082134782, 14,
3082133504, 20528, 1, 3084941436, 3082153972, 4, 3214689992, 3214687484,
3086734048, 4, 3085379232, 4, 3214689992, 3214687484, 3082137661,
3214689996, 3214687589, 4, 3214687113}}, sa_flags = 255,
sa_restorer = 0xa0cbc62e}
#3 0xb7e16455 in msort_with_tmp (p=0xbf9c5c88, b=0xb7fc6d90, n=3086774688)
at msort.c:142
b1 = 0x2cb86081 <Address 0x2cb86081 out of bounds>
b2 = 0xb7fc8680 "U\211åWVSèüçÿÿ\201Ãi\031"
n1 = 3603444881
n2 = 0
tmp = 0xb7fc6d90 "1í^\211á\203äðPTRè\""
s = 0
cmp = (__compar_fn_t) 0
---Type <return> to continue, or q <return> to quit---
---Type <return> to continue, or q <return> to quit---
paperout = 0
offline = 0
print_buffer = "ŽH\234¿", '\0' <repeats 21 times>,
"\030\000\000\000\000\000\000È£ú· Rü·Àšš\002ÿÿÿÿôOü·0ïó·ð\212ú·\2048\234¿[xû·š\214ú·Pñ¶·\001\000\000\000\001\000\000\000\000\000\000\000;\020ô·
\000\000\000\000\000php0\205O\204ªû·È£ú·ô/õ·\000\000\000\000Ü/õ·P붷H붷`Èó·ô/õ·\000\000\000\000\000\000\000\000ô¿¿·\000\000\000\000\002\000\000\000ü<\234¿å)¿·\000\000\000\000\001\000\000\000\001\000\000\0000=\234¿\000\004\000\000TE\234¿\b\000\004\000¬æ¶·\004",
'\0' <repeats 15 times>...
print_ptr = 0xb7e0787c "ôE"
bc_buffer =
"0.101.0.1\000ü·WÛ\223\034š\214ú·\bY\234¿Ï5û·øX\234¿`ðó·ìX\234¿ÄWü·\000\000\000\000àð¶·\001\000\000\000\000\000\000\000\001\000\000\000Ð涷\031\000\000\000\001",
'\0' <repeats 15 times>, "[EMAIL PROTECTED] Xü·", '\0' <repeats 24 times>,
"Ä\221ú·Ä\221ú·HYü·\200&ô·\004\000\000\020", '\0' <repeats 28 times>,
"Ìsà·\210\215ú·\000"...
action = {__sigaction_handler = {sa_handler = 0, sa_sigaction = 0},
sa_mask = {__val = {4294967295, 3086766068, 3082134176, 3086798488,
3214685904, 3086710875, 3086798928, 3086799328, 1, 1, 0, 3082134782, 14,
3082133504, 20528, 1, 3084941436, 3082153972, 4, 3214689992, 3214687484,
3086734048, 4, 3085379232, 4, 3214689992, 3214687484, 3082137661,
3214689996, 3214687589, 4, 3214687113}}, sa_flags = 255,
sa_restorer = 0xa0cbc62e}
#3 0xb7e16455 in msort_with_tmp (p=0xbf9c5c88, b=0xb7fc6d90, n=3086774688)
at msort.c:142
b1 = 0x2cb86081 <Address 0x2cb86081 out of bounds>
b2 = 0xb7fc8680 "U\211åWVSèüçÿÿ\201Ãi\031"
n1 = 3603444881
n2 = 0
tmp = 0xb7fc6d90 "1í^\211á\203äðPTRè\""
s = 0
cmp = (__compar_fn_t) 0
---Type <return> to continue, or q <return> to quit---
#4 0xb7fc6dc1 in main (argc=-1212155688, argv=Cannot access memory at address
0xfffff32c
) at socket.c:342
method = Cannot access memory at address 0xfffffeed
(gdb)
Not that this output helps a lot, methinks.
frame #0 cannot be decoded since I was unable to load libpthread:
(gdb) add-symbol-file /usr/lib/debug/libpthread-2.7.so 0xb7f3e000
add symbol table from file "/usr/lib/debug/libpthread-2.7.so" at
.text_addr = 0xb7f3e000
(y or n) y
Reading symbols from /usr/lib/debug/libpthread-2.7.so...done.
warning: Cannot initialize thread debugging library: generic error
warning: Cannot initialize thread debugging library: generic error
All in all gdb symbol lookup handling leaves a LOT to be desired.
This issue seems to happen more easily in case of WLAN-based transfers
(on LAN, only larger jobs seem to be able to cause this lockup).
Please give more information as to how to usefully debug a CUPS backend
in-process, the CUPS website doesn't seem to explain much in this area.
Thanks,
Andreas Mohr
--
To UNSUBSCRIBE, email to [EMAIL PROTECTED]
with a subject of "unsubscribe". Trouble? Contact [EMAIL PROTECTED]
