mksquashfs deadlock on writing stage

[fourdim]

Version: 4.7.2 (2025/08/18)
Command: mksquashfs ${1:-.} ${2:-${1:-out}.squashfs} -comp zstd -Xcompression-level 19 -b 1M
Folder characteristics: many small files
CPU utilization: 0 from htop

GDB attached on released version:
deadlock on

• pthread_cond_wait * n
• pthread_mutex_lock
• sigtimedwait

#3  0x00007f666c10e53e in write () from /usr/lib/libc.so.6
#4  0x00007f666c08eb75 in _IO_file_write () from /usr/lib/libc.so.6
#5  0x00007f666c08c9b6 in ?? () from /usr/lib/libc.so.6
#6  0x00007f666c08edb1 in _IO_file_xsputn () from /usr/lib/libc.so.6

Detailed information with debug symbols will be provided probably next week.

[plougher]

If the program had completely hung you would not see a thread executing write(). If you check the output file you should see it increasing in size.

Mksquashfs is multi-threaded. At the end of the program when everything has been done except to write out the queued compressed data to disk, all the threads will be idle (on pthread_cont_wait). At that stage all you will see is the writer thread executing the write() glibc function and system call.

How long it stays in this state depends on how slow the output media is with respect to how fast compression is, and much data has built up waiting to be written to disk.

To limit the build up of data that can happen with fast compression and a slow output device, you can reduce memory with the -mem option or reduce parallelism with the -processors option.

[fourdim]

You have a good point. The thing is, in the previous version, I didn't experience this slow writing issue when folder size is about 2.9G. Later I add 100M files to this folder and upgrade to the latest version. I'm experiencing much long delay on writing.
I will do an A/B testing later. It could be SSD used up its cache.

[plougher]

OK I think I can understand what has happened. I have noticed a change in timing myself between 4.6.1 and 4.7+, but, not as severe. Obviously I expected the change, but I didn't expect it to be that noticeable to other people. So you may have an unusual use-case which has produced a noticeable change in behaviour.

The big question (for me at any rate) is whether it has produced a real slow-down, or just a perception of slow-down by the viewer, and it is in fact no slower. A wall-clock timing of version 4.6.1 against version 4.7+ would show which is the case here.

OK I'll explain why it can be a perception of slow-down rather than a real slow-down. There are three major changes in 4.7+ which has changed the timing. First is reading small files is much faster than it was before, because reading is now done in parallel. See

squashfs-tools/Documentation/4.7.2/README

Line 149 in 90ab378

3. PARALLEL FILE READING AND OPTIONS

for the speed-up details, for example more than 10 times speed up in small file reading has been seen. The second is a compression stall has been removed. The third is all metadata compression has been moved to after data compression.

Now you know about queues and caches. There is a data cache/queue between the compressor threads and the writer thread in Mksquashfs. There is also a kernel cache/queue between the writer thread write() and the SSD, and the SSD also has its own cache too. The knock on effect of the speed-ups is data is read far faster than before, and which can mean the output queues build up faster at the previously mentioned three points, and become deeper.

The issue is that the progress bar represents the progress at compressing files, but it doesn't represent the progress of writing the files to the output filesystem because it don't know anything about how deep these queues are.

Now imagine in version 4.6.1 it took ten minutes to read and compress the input files, and eight minutes to output the compressed version to the output filesystem. The progress bar will spend 10 minutes getting to 100%, and by the time it has, there are no deep output queues which need to drain because writing was faster. So the program will exit immediately once 100% is reached.

Now imagine in version 4.7.2 due to parallel reading, it now takes four minutes to read and compress the input files, but eight minutes to output the compressed version to the output filesystem. The progress bar will spend four minutes getting to 100%, and at this point it will take another four minutes for the output queues to drain. So the progress bar will be stuck at 100% for four minutes.

So even though Mksquashfs was two minutes faster, the viewer perception is it was slower because it got stuck at 100% for so long.

I think you may be hitting this. You see the progress bar stuck at 100% and think it is slower.

The alternative is you are seeing a genuine slow-down because metadata compression has been moved to after data compression. This can produce a loss of parallelism because metadata compression is single threaded, and moving it to the end means there's no data compression happening at the same time to ensure all CPU cores are occupied. But normally the output queues are so backed up at that point that they're the bottleneck and multi-threaded metadata compression will be pointless.

But, you may have an unusual use-case where moving the single-threaded metadata compression to the end has caused a slow-down, because your use-case is heavily dominated by metadata compression.

A wall-clock timing will give more information as to what is happening here.

[fourdim]

I'm measuring the time between

Unrecognised xattr prefix btrfs.compression
Unrecognised xattr prefix btrfs.compression
Unrecognised xattr prefix btrfs.compression

and done.

This message flushes all my terminal so that I cannot see the progress bar.

My feeling is that, this time period is much longer than what it used to be.

[fourdim]

There should be something wrong. I run it this time and it is not stucking. The time between Unrecognised xattr prefix btrfs.compression and done is now roughly 10 seconds. While when this potential bug happens, it feels taking more than 5 mins.

[plougher]

There should be something wrong. I run it this time and it is not stucking. The time between Unrecognised xattr prefix btrfs.compression and done is now roughly 10 seconds. While when this potential bug happens, it feels taking more than 5 mins.

When Unrecognised xattr prefix is printed. Mksquashfs is compressing the metadata. So something has changed 10 seconds into 5 minutes, which is a major performance reduction. But it is not happening all the time, and so it is possibly dependent on external factors.

I'll try and reproduce this. Firstly I need to know more about what you're compressing and your setup to stand a better chance in reproducing it.

1. How many files are you compressing? At they in the same directory, or across multiple directories?
2. What are the sizes of the files? Is there an average size, e.g. 1K, 100K, 1M etc.
3. How many processors are you using?
4. How much memory is Mksquashfs using? If you're using the default memory size, that can be obtained by running mksquashfs -mem-default.
5. Is the system otherwise idle when running Mksquashfs, or are there other active programs, and are they using memory or doing I/O.
6. The output summary from Mksquashfs would be useful.

Thanks.

[fourdim]

1. roughly 129663 files and 53510 directories, in total around 3G of files. These files are distributed not evenly under at most 5 levels of directory and only 1 directory at the top. The host is using a btrfs filesystem with zstd compression. BTRFS scrub no errors found, usage 153G out of 931G SSD.
2. most around 20K, no more than 1M.
3. 16 logical processors
4. 23057 I have 90G in total
5. idle, no one else is heavily using CPU or memory
6. Output using 2>&1 | awk '{ print strftime("%s: "), $0; fflush(); }' | tee mksquashfs.log

mksquashfs.log

[plougher]

OK, I have done extensive testing on a number of different platforms over the last four days, and I have been unable to reproduce this. But while doing this I have discovered a couple of issues which affect really large filesystems (large 256GB files with 4K blocks) which have been fixed.

The situation as it stands is the amount of files and the filesystem size you have (129663 files, ~ 3G of files) is not exceptional, and this use-case has been extensively tested and there are no known issues here.

So basically I do not have any explanation for what is going on here. As I can't find the cause, this means the cause could be external to Mksquashfs, or there is something in your system which is triggering a bug in Mksquashfs which doesn't happen on my systems. Lastly it may not be external and simply your input files have hit that 1 in a million combination which triggers a bug which hasn't occurred in my testing.

In other words at the moment the cause could be anything and anywhere, akin to looking for a needle in haystack blindfolded.

At this stage, there are only two options to move forward:

1. You need to give me a reproducer, that is a set of input files which reproduce the issue on your hardware. Obviously this should not be anything private, which may mean you have to spend some time creating a set of files which reproduce the problem which you can send me. Obviously if this is a 1 in a million combination if it may be impossible to do so.
2. The other option is a lengthy trial and error process designed to eliminate as much as possible and to isolate the cause.

There are a couple of things you can do now though with your existing files/data-set.

1. Run mksquashfs with the -single-reader option. What effect does this have? This makes Mksquashfs behave like 4.6.1 when reading files.
2. When running 4.7.2 and when it appears to hang, hit ctrl-\ (control key and \ key) twice within a second. This will produce a dump of the caches and queues in Mksquashfs. Then wait about 10 seconds and generate a second dump. Send them to me.
3. If the problem occurs with -single-reader, dumps with the single-reader option would be useful as well.
4. You can eliminate the Btrfs filesystem and the output SSD as the cause by creating a ramdisk (mount -t tmpfs mnt-point) and copying the input files to that, and outputting to the ramdisk.

[fourdim]

1. Unfortunately nothing happened
2. Will do
3. I'm writing to the ramfs in /dev/shm. Because it used to occur in the writing stage. It should not have any issue with reading.

I'm sorry that I didn't preserve the input files and the dump properly and it cannot be reproduced from my end either. Anyway, thank you for your suggestions. I learned a lot.

[plougher]

3. I'm writing to the ramfs in /dev/shm. Because it used to occur in the writing stage. It should not have any issue with reading.

I have a feeling that the original GDB thread dump may have been misleading.

This is your original GDB thread call stack

#3  0x00007f666c10e53e in write () from /usr/lib/libc.so.6
#4  0x00007f666c08eb75 in _IO_file_write () from /usr/lib/libc.so.6
#5  0x00007f666c08c9b6 in ?? () from /usr/lib/libc.so.6
#6  0x00007f666c08edb1 in _IO_file_xsputn () from /usr/lib/libc.so.6

I did some glibc investigation to identify the functions in the call stack.

_IO_file_xsputn () operates on a FILE *, and it is an internal glibc function which things like puts() and putchar() are mapped to.

The point being that the threads that write data to the output filesystem don't use glibc buffered I/O using a FILE *. They directly write to the file using the glibc write() function which is a shim over the write() system call.

In otherwords, that thread isn't writing to the output file. The only thread in Mksquashfs which does use FILE * and putchar() is the progress bar, and that will continue running when all other threads have hung.

So stepping back, it looks likely that everything else has hung in that thread dump, and if so the cause may not be hanging writing to the output file. In a pipeline A->B->C->D, when one part hangs they all will eventually hang. That is the pipeline will hang if D the writer thread hangs, because the threads A/B/C will run out of buffer space to continue because the queues and caches are full. But the pipeline will hang if A the input thread hangs, because this time the threads B/C/D will run of data because their queues and caches are empty. Again if C the compressor threads hang, the pipeline will hang. But in this case threads A/B will have hung because their queues and caches are full, and thread D will have hung because its queue is empty.

So the balance of empty queues/caches and full queues/caches in a pipeline, shows which part of the pipeline hung. Full before it, and empty after it.

Which is why I asked you for the debugging queue/cache dump when it hangs :-)

I'm sorry that I didn't preserve the input files and the dump properly and it cannot be reproduced from my end either. Anyway, thank you for your suggestions. I learned a lot.

No problem. If it happens again we can look into then. In the meantime I'm going to continue to reproduce any issues.