[Pkg-cups-devel] Bug#489045: cups: infinite loop, 100%CPU use, while trying to print with HPJetDirect

Andreas Mohr andi at lisas.de
Sun Nov 2 15:20:22 UTC 2008


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>, "øX\234¿ìX\234¿\020\002\000\000\000§ú·\210\000\000\0008Y\234¿ð\212ú·\034\002ô·dü¶·\000\000\000\000\000\000\000\000»š\001\000ôOü·@\\\234¿UÕú· Rü· 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>, "øX\234¿ìX\234¿\020\002\000\000\000§ú·\210\000\000\0008Y\234¿ð\212ú·\034\002ô·dü¶·\000\000\000\000\000\000\000\000»š\001\000ôOü·@\\\234¿UÕú· Rü· 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





More information about the Pkg-cups-devel mailing list