[Bug 722168] Re: mksquashfs hangs

Cody A.W. Somerville cody-somerville at ubuntu.com
Wed Jun 22 01:44:21 UTC 2011


I believe that I'm also running into this bug except in my case
mksquashfs (from squashfs-tools 1:4.0-8) is being invoked by live-helper
(now known as live-build). Occasionally, mksquashfs will hang at
seemingly 100%. I've captured the following debug information:

  `-lh_build,16803 /usr/bin/lh_build
      `-lh_binary,7979 /usr/bin/lh_binary
          `-lh_binary_rootf,9495 /usr/bin/lh_binary_rootfs
              `-mksquashfs,9596 chroot filesystem.squashfs
                  |-{mksquashfs},9598
                  |-{mksquashfs},9599
                  |-{mksquashfs},9600
                  |-{mksquashfs},9601
                  |-{mksquashfs},9602
                  |-{mksquashfs},9603
                  |-{mksquashfs},9604
                  |-{mksquashfs},9605
                  |-{mksquashfs},9606
                  `-{mksquashfs},9607

strace of mksquashfs,9596:
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
....

strace of {mksquashfs},9598;
futex(0x92c6998, FUTEX_WAIT_PRIVATE, 5745, NULL

strace of {mksquashfs},9599:

strace of {mksquashfs},9600:
futex(0x92c6100, FUTEX_WAIT_PRIVATE, 73393, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x92c6100, FUTEX_WAIT_PRIVATE, 73396, NULL

strace of {mksquashfs},9601:
futex(0x92cb368, FUTEX_WAIT_PRIVATE, 852, NULL

strace of {mksquashfs},9602:
futex(0x92c6100, FUTEX_WAIT_PRIVATE, 73396, NULL

strace of {mksquashfs},9603:
futex(0x92cb368, FUTEX_WAIT_PRIVATE, 851, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x92cb368, FUTEX_WAIT_PRIVATE, 852, NULL

strace of {mksquashfs},9604:
futex(0x92c6100, FUTEX_WAIT_PRIVATE, 73394, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x92c6100, FUTEX_WAIT_PRIVATE, 73396, NULL

strace of {mksquashfs},9605:
futex(0x92cb368, FUTEX_WAIT_PRIVATE, 849, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x92cb368, FUTEX_WAIT_PRIVATE, 852, NULL

strace of {mksquashfs},9606:
futex(0x92c6100, FUTEX_WAIT_PRIVATE, 73395, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x92c6100, FUTEX_WAIT_PRIVATE, 73396, NULL

strace of {mksquashfs},9607:
futex(0x92cb368, FUTEX_WAIT_PRIVATE, 850, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x92cb368, FUTEX_WAIT_PRIVATE, 852, NULL

strace of mksquashfs,9596 with -f option (to follow children):
...
[pid 9596] sched_yield() = 0
[pid 9596] sched_yield() = 0
[pid 9596] --- SIGALRM (Alarm clock) @ 0 (0) ---
[pid 9596] sigreturn() = ? (mask now [])
[pid 9596] sched_yield() = 0
[pid 9596] sched_yield() = 0
...
pid 9596] sched_yield() = 0
[pid 9599] <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 9599] gettimeofday({1302110049, 888547}, NULL) = 0
[pid 9599] futex(0x80e17a0, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 9599] clock_gettime(CLOCK_REALTIME, {1302110049, 888637707}) = 0
[pid 9599] futex(0x8363de4, FUTEX_WAIT_PRIVATE, 4655307, {0, 249909293} <unfinished ...>
[pid 9598] <... futex resumed> ) = ? ERESTARTSYS (To be restarted)
[pid 9596] --- SIGALRM (Alarm clock) @ 0 (0) ---
[pid 9598] futex(0x92c6998, FUTEX_WAIT_PRIVATE, 5745, NULL <unfinished ...>
[pid 9596] sigreturn() = ? (mask now [])
[pid 9596] sched_yield() = 0
[pid 9596] sched_yield() = 0
...

(gdb) thread apply all bt full:

Thread 11 (Thread 0xf6ca4b70 (LWP 9598)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92c6970) at mksquashfs.c:457
        data = <value optimized out>
#3 0x080514d1 in writer (arg=0x0) at mksquashfs.c:2314
        file_buffer = 0xe7ef070
        off = 1006143431
        write_error = 0
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 10 (Thread 0xf64a3b70 (LWP 9599)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f9884 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x0804b1f4 in progress_thrd (arg=0x0) at mksquashfs.c:2521
        timeval = {tv_sec = 1302110661, tv_usec = 973737}
        timespec = {tv_sec = 1302110662, tv_nsec = 223737000}
        itimerval = {it_interval = {tv_sec = 0, tv_usec = 250000}, it_value = {tv_sec = 0, tv_usec = 250000}}
        winsize = {ws_row = 0, ws_col = 0, ws_xpixel = 0, ws_ypixel = 0}
#3 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#4 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 9 (Thread 0xf5ca2b70 (LWP 9600)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92c60d8) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051345 in deflator (arg=0x0) at mksquashfs.c:2375
        write_buffer = 0xd98c8e8
        stream = 0xb413a30
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 8 (Thread 0xf54a1b70 (LWP 9601)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92cb340) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051241 in frag_deflator (arg=0x0) at mksquashfs.c:2413
        compressed_size = 15364
        file_buffer = 0x116b6fe0
        write_buffer = 0xe7ef070
        stream = 0xf6b18b8
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 7 (Thread 0xf4ca0b70 (LWP 9602)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92c60d8) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051345 in deflator (arg=0x0) at mksquashfs.c:2375
        write_buffer = 0xead400c8
        stream = 0xb414320
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 6 (Thread 0xf449fb70 (LWP 9603)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92cb340) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051241 in frag_deflator (arg=0x0) at mksquashfs.c:2413
        compressed_size = 13340
        file_buffer = 0xb8c6ed8
        write_buffer = 0xf15c0228
        stream = 0x92d33c8
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 5 (Thread 0xf3c9eb70 (LWP 9604)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92c60d8) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051345 in deflator (arg=0x0) at mksquashfs.c:2375
        write_buffer = 0xda4caf8
        stream = 0xb414360
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 4 (Thread 0xf349db70 (LWP 9605)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92cb340) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051241 in frag_deflator (arg=0x0) at mksquashfs.c:2413
        compressed_size = 8789
        file_buffer = 0xe64ebf8
        write_buffer = 0xf0fa01d0
        stream = 0xb3d18a0
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 3 (Thread 0xf2c9cb70 (LWP 9606)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92c60d8) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051345 in deflator (arg=0x0) at mksquashfs.c:2375
        write_buffer = 0xdb2cd60
        stream = 0xb4143a0
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 2 (Thread 0xf249bb70 (LWP 9607)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76f94dc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
No symbol table info available.
#2 0x08050fd4 in queue_get (queue=0x92cb340) at mksquashfs.c:457
        data = <value optimized out>
#3 0x08051241 in frag_deflator (arg=0x0) at mksquashfs.c:2413
        compressed_size = 20408
        file_buffer = 0xf791b68
        write_buffer = 0xc709608
        stream = 0xf0e204c0
        oldstate = 0
#4 0xf76f4cc9 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#5 0xf763a6ae in clone () from /lib/libc.so.6
No symbol table info available.

Thread 1 (Thread 0xf75696c0 (LWP 9596)):
#0 0xf7723430 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf760f8ec in sched_yield () from /lib/libc.so.6
No symbol table info available.
#2 0x08057a09 in main (argc=3, argv=<value optimized out>) at mksquashfs.c:4779
        buf = {st_dev = 0, __pad1 = 0, __st_ino = 0, st_mode = 0, st_nlink = 0, st_uid = 0, st_gid = 0, st_rdev = 0,
          __pad2 = 0, st_size = 0, st_blksize = 0, st_blocks = 0, st_atim = {tv_sec = 0, tv_nsec = 0}, st_mtim = {
            tv_sec = 0, tv_nsec = 0}, st_ctim = {tv_sec = 0, tv_nsec = 0}, st_ino = 0}
        source_buf = {st_dev = 21, __pad1 = 0, __st_ino = 293859759, st_mode = 16877, st_nlink = 21, st_uid = 0, st_gid = 0,
          st_rdev = 0, __pad2 = 0, st_size = 460, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1301538668,
            tv_nsec = 859741929}, st_mtim = {tv_sec = 1301539108, tv_nsec = 659745930}, st_ctim = {tv_sec = 1301539136,
            tv_nsec = 59747352}, st_ino = 293859759}
        i = <value optimized out>
        sBlk = {s_magic = 1936814952, inodes = 131210, mkfs_time = 1301539226, block_size = 131072, fragments = 5352,
          compression = 0, block_log = 17, flags = 192, no_ids = 0, s_major = 4, s_minor = 0, root_inode = 84226939007,
          bytes_used = 0, id_table_start = 0, xattr_table_start = 0, inode_table_start = 0, directory_table_start = 0,
          fragment_table_start = 0, lookup_table_start = 0}
        b = 0x0
        root_name = 0x0
        nopad = 0
        keep_as_directory = 0
        inode = 84226939007
        readb_mbytes = 64
        writeb_mbytes = 512
        fragmentb_mbytes = 64
        s_minor = 0

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to squashfs-tools in Ubuntu.
https://bugs.launchpad.net/bugs/722168

Title:
  mksquashfs hangs

Status in “squashfs-tools” package in Ubuntu:
  New

Bug description:
  Binary package hint: squashfs-tools

  # lsb_release -rd
  Description:	Ubuntu 10.10
  Release:	10.10

  # apt-cache policy squashfs-tools
  squashfs-tools:
    Installed: 1:4.0-8
    Candidate: 1:4.0-8
    Version table:
   *** 1:4.0-8 0
          500 http://us.archive.ubuntu.com/ubuntu/ maverick/main amd64 Packages
          100 /var/lib/dpkg/status

  I attempted to make a series of squashfs filesystems.  (Many times!).
  I'm using The Transparent Archivist (ftp://ftp.flaterco.com/ta/) to
  organize the making of the filesystems; this tool calls mksquashfs
  repeatedly as it divides a directory-to-be-archived into CD- or DVD-
  sized squashfs filesystems.  I don't think Transparent Archivist is
  implicated in the problem, whatever it is.  As far as mksquashfs is
  concerned, it is being invoked in the usual way as an independent
  subprocess.

  Sometimes -- not very often, maybe once in 30-60 invocations --
  mksquashfs simply hangs.  Having made some of the filesystem it's
  supposed to be making, It stops making the filesystem for no apparent
  reason.  It continues to use a wee bit of processing power after that
  -- very occasionally rising to the top of the "top" display -- but it
  makes no observable progress on the filesystem that it's supposed to
  be making.  Once I left it running for 4 days; no progress, and no
  resumption of work occurred during all that time.

  Reading about mksquashfs's earlier bugs led me to edit the Transparent
  Archivist's source code in such a way as to add '-no-sparse' to the
  invocation parameters of the call to mksquashfs.  This change did not
  fix the problem; the occasional hanging continued just as before.

  I also read Philip Lougher's remarks in Launchpad about problems in
  earlier Ubuntu distros with mixing kernel module versions and
  mksquashfs versions incorrectly, with respect to lzma
  support/defaulting.  One fix for that earlier "bug" was to invoke
  mksquashfs with -no-lzma.  The version of mksquashfs in my 10.10
  distro does not recognize that argument, so there's no way to try that
  fix.

  It's important that you understand that, while I can reliably
  reproduce the error, it often takes many invocations of mksquashfs to
  do so, and the number of invocations cannot be predicted, EVEN FOR
  EXACTLY THE SAME DATA.  When mksquashfs hangs, and I abort it
  manually, I can restart mksquashfs with exactly the source data and
  invocation parameters, and so far it has always worked just fine when
  I do that.

  You're about to ask me, "Is your hardware stable?".  The answer is
  "Yes".  If this is a hardware problem, it is one that appears ONLY
  during mksquashfs processing and at no other time.  No other
  applications are affected by it, and no rebooting is necessary even
  when it does happen.  Everything else works perfectly.

  Realizing that mksquashfs uses all 8 threads of my i7-950 processor, I
  have checked its temperature during maximum mksquashfs-mediated loads,
  and it always stays below 55 C, and usually below 45C.  And all other
  processes continue to work without a hitch.  So I don't think this is
  a hardware problem.

  Could "ionice -c 3" be implicated?  It's something to think about,
  anyway.  I need to use that in order to keep the computer useful for
  small interactive tasks during these giant, days-long archiving jobs.
  However, the hanging problem was occurring before I started using
  ionice.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/squashfs-tools/+bug/722168/+subscriptions




More information about the foundations-bugs mailing list