[Midnight Commander] #4287: Quadratic(?) slowdown on file moves across filesystems
Ticket System
-------------------------------+--------------------------------
Reporter: slyfox | Owner:
Type: defect | Status: new
Priority: major | Milestone: Future Releases
Component: mc-core | Version: master
Keywords: | Blocked By:
Blocking: | Branch state: no branch
Votes for changeset: |
-------------------------------+--------------------------------
Tried to move firefox build tree from one btrfs subvolume to another on
NVMe device. It contained ~2M files. Normally it should take under a
minute to relink a few gigabytes. But mc did not not succeed in 1 hour.
Looks like there is a quadratic behavior in file moves related to single
list traversal.
Here is the reproducer:
1. create 1M files in a firectory structure (we will create 1000 dirs 1000
files each)
2. put them all in one directory 'd'
3. move this 'd' from one tmpfs to another
Expected behavior: operation should take seconds (rougly the same time it
takes to create the directory tree).
Actual behaviour: it takes tens of minutes to move the dir.
Script to build a directory:
{{{#!sh
#!/usr/bin/env bash
# fail on first problem
set -e
echo "prepating two new tmpfs filesystems: /tmp/tmpfs-src and /tmp/tmpfs-
dst"
mkdir /tmp/tmpfs-src
mkdir /tmp/tmpfs-dst
sudo mount -t tmpfs tmpfs /tmp/tmpfs-src
sudo mount -t tmpfs tmpfs /tmp/tmpfs-dst
# allow current user to fiddle with it
sudo chown ${USER} /tmp/tmpfs-src /tmp/tmpfs-dst
echo "creating 1M files"
# create 1 million empty files
mkdir /tmp/tmpfs-src/d
for d in {1..1000}; do
mkdir /tmp/tmpfs-src/d/$d
touch /tmp/tmpfs-src/d/$d/{1..1000}
done
echo "don't forget cleanup: 'sudo umount /tmp/tmpfs-src; sudo umount /tmp
/tmpfs-dst'"
echo "Now you can run 'mc /tmp/tmpfs-src /tmp/tmpfs-dst' and try to move
'd' directory with F6."
}}}
Run as:
1. Run '$ prepare_environment.bash'
2. Run 'mc /tmp/tmpfs-src /tmp/tmpfs-dst'
3. Start moving with 'F6' on 'd' dir.
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287>
Midnight Commander <https://midnight-commander.org>
Midnight Development Center
Ticket System
Reporter: slyfox | Owner:
Type: defect | Status: new
Priority: major | Milestone: Future Releases
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: no branch | Votes for changeset:
Comment (by slyfox):
'perf record / perf report' renders the following:
{{{
96.41% mc libglib-2.0.so.0.6800.3 [.] g_slist_last
0.83% mc libslang.so.2.3.2 [.]
_pSLstring_hash.localalias
0.16% mc libslang.so.2.3.2 [.] SLtt_smart_puts
0.15% mc libc-2.33.so [.] __memcmp_avx2_movbe
0.14% mc mc [.]
str_utf8_make_make_term_form
0.11% mc libglib-2.0.so.0.6800.3 [.] g_unichar_type
0.07% mc libc-2.33.so [.] __strlen_avx2
0.07% mc libc-2.33.so [.] __dcigettext
0.07% mc libglib-2.0.so.0.6800.3 [.] g_unichar_isprint
}}}
GDB's backtrace for possible location:
{{{
(gdb) bt
#0 0x00007fecf24dfe77 in g_slist_last ()
from /nix/store/94iv84rv2d1cl0fk1l1mkmmbnxg7fyzz-
glib-2.68.3/lib/libglib-2.0.so.0
#1 0x00007fecf24dfeaf in g_slist_append ()
from /nix/store/94iv84rv2d1cl0fk1l1mkmmbnxg7fyzz-
glib-2.68.3/lib/libglib-2.0.so.0
#2 0x000000000046d2dd in copy_dir_dir (tctx=0xc27ff0, ctx=0xc27f50,
s=0xc24f00 "/tmp/tmpfs-src/d/591", d=<optimized out>,
toplevel=<optimized out>,
move_over=<optimized out>, do_delete=1, parent_dirs=0xa6c9ab0) at
file.c:2989
#3 0x000000000046d162 in copy_dir_dir (tctx=tctx@entry=0xc27ff0,
ctx=ctx@entry=0xc27f50,
s=s@entry=0xc2d490 "/tmp/tmpfs-src/d", d=<optimized out>,
d@entry=0xc0b490 "/tmp/tmpfs-dst/d",
toplevel=toplevel@entry=0, move_over=move_over@entry=0, do_delete=1,
parent_dirs=0xb54cc0)
at file.c:2967
#4 0x000000000046d7fa in do_move_dir_dir (panel=0x7ffc76c9e490,
tctx=0xc27ff0, ctx=0xc27f50,
s=0xc2d490 "/tmp/tmpfs-src/d", d=0xc0b490 "/tmp/tmpfs-dst/d") at
file.c:1674
#5 0x000000000046ed11 in operate_single_file (dialog_type=<optimized
out>, dest=<optimized out>,
src_stat=0x7ffc76c9e740, src=<optimized out>, ctx=0xc27f50,
tctx=0xc27ff0, operation=OP_MOVE,
panel=0xc19000) at file.c:2050
#6 panel_operate (source_panel=source_panel@entry=0xc19000,
operation=operation@entry=OP_MOVE,
force_single=force_single@entry=0) at file.c:3334
#7 0x0000000000465f18 in rename_cmd (panel=0xc19000) at cmd.c:795
#8 0x0000000000418bf0 in midnight_execute_cmd (sender=0xc17c00,
command=23) at filemanager.c:1355
#9 0x000000000049db59 in buttonbar_callback (w=0xc17c00,
sender=<optimized out>,
msg=<optimized out>, parm=1006, data=<optimized out>) at
buttonbar.c:171
#10 0x00000000004a07f0 in send_message (data=0x0, parm=1006,
msg=MSG_HOTKEY, sender=0x0,
w=<optimized out>) at ../../lib/widget/widget-common.h:254
#11 group_handle_hotkey (key=1006, g=0xc04580) at group.c:567
#12 group_default_callback (w=0xc04580, sender=<optimized out>,
msg=<optimized out>,
parm=<optimized out>, data=<optimized out>) at group.c:643
#13 0x00000000004a0680 in send_message (data=0x0, parm=1006,
msg=MSG_HOTKEY, sender=0x0, w=0xc04580)
at ../../lib/widget/widget-common.h:254
#14 group_handle_key (key=1006, g=0xc04580) at group.c:504
#15 group_default_callback (w=0xc04580, sender=<optimized out>,
msg=<optimized out>, parm=1006,
data=<optimized out>) at group.c:640
#16 0x000000000049f06d in dlg_key_event (d_key=1006, h=0xc04580) at
dialog.c:251
#17 dlg_process_event (h=0xc04580, key=1006, event=<optimized out>) at
dialog.c:566
#18 0x000000000049f346 in frontend_dlg_run (h=0xc04580) at dialog.c:320
#19 dlg_run (h=0xc04580) at dialog.c:600
#20 0x000000000041a07c in do_nc () at filemanager.c:1838
#21 0x000000000040b0a5 in main (argc=<optimized out>, argv=<optimized
out>) at main.c:455
}}}
https://people.gnome.org/~ryanl/glib-docs/glib-Singly-Linked-Lists.html
warns about 'g_slist_append':
{{{
Note that g_slist_append() has to traverse the entire list to find the
end,
which is inefficient when adding multiple elements. A common idiom to
avoid
the inefficiency is to prepend the elements and reverse the list when all
elements have been added.
}}}
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:1>
Ticket System
Reporter: slyfox | Owner:
Type: defect | Status: new
Priority: major | Milestone: Future Releases
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: no branch | Votes for changeset:
Comment (by andrew_b):
Replying to [comment:1 slyfox]:
> {{{
> 96.41% mc libglib-2.0.so.0.6800.3 [.] g_slist_last
> }}}
>
> [...]
>
> {{{
> #2 0x000000000046d2dd in copy_dir_dir (tctx=0xc27ff0, ctx=0xc27f50,
> s=0xc24f00 "/tmp/tmpfs-src/d/591", d=<optimized out>,
toplevel=<optimized out>,
> move_over=<optimized out>, do_delete=1, parent_dirs=0xa6c9ab0) at
file.c:2989
> }}}
I can propose to replace g_list_append() with g_list_prepend() if order of
erase_list items is no matter or reimplement erase_list using GQueue
otherwise.
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:2>
Ticket System
Reporter: slyfox | Owner: andrew_b
Type: defect | Status: accepted
Priority: major | Milestone: 4.8.28
Component: mc-core | Version: master
Resolution: | Keywords:
Blocked By: | Blocking:
Branch state: on review | Votes for changeset:
--------------------------+--------------------------------
Changes (by andrew_b):
* status: new => accepted
* owner: => andrew_b
* branch_state: no branch => on review
* milestone: Future Releases => 4.8.28
Comment:
Branch: 4287_slow_move
changeset:1b39025049322bd311654a4ddaaaeafc1cb39164
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:3>
Ticket System
Reporter: slyfox | Owner: andrew_b
Type: defect | Status: accepted
Priority: major | Milestone: 4.8.28
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: on review | Votes for changeset:
--------------------------+--------------------------------
Comment (by slyfox):
The patch works for me: 1M files move in ~30 seconds.
Thank you!
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:4>
Ticket System
Reporter: slyfox | Owner: andrew_b
Type: defect | Status: testing
Priority: major | Milestone: 4.8.28
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: merged | Votes for changeset: committed-master
------------------------+----------------------------------------
Changes (by andrew_b):
* status: accepted => testing
* votes: slyfox andrew_b => committed-master
* resolution: => fixed
* branch_state: approved => merged
Comment:
Merged to master: [130e50ec89be9a2d5fd0025dbab5a5d22e575db0].
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:6>
Ticket System
Reporter: slyfox | Owner: andrew_b
Type: defect | Status: accepted
Priority: major | Milestone: 4.8.28
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: approved | Votes for changeset: slyfox andrew_b
-------------------------+---------------------------------------
Changes (by andrew_b):
* votes: => slyfox andrew_b
* branch_state: on review => approved
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:5>
Ticket System
Reporter: slyfox | Owner: andrew_b
Type: defect | Status: closed
Priority: major | Milestone: 4.8.28
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: merged | Votes for changeset: committed-master
------------------------+----------------------------------------
Changes (by andrew_b):
* status: testing => closed
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:7>
Ticket System
Reporter: slyfox | Owner: andrew_b
Type: defect | Status: closed
Priority: major | Milestone: 4.8.28
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: merged | Votes for changeset: committed-master
------------------------+----------------------------------------
Comment (by Axanar):
I believe, that I triggered an issue with the last merged patch as you can
see in the attachment.
When moving single files or a list of files, then the move went fine. As
soon as you move a directory with no, one or many files then this critical
assertion pops up all the time.
May I ask to have a review of the last merged patch ? This issue won't
happen with the last official release but happens with mc git.
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:8>
Ticket System
Reporter: slyfox | Owner: andrew_b
Type: defect | Status: closed
Priority: major | Milestone: 4.8.28
Component: mc-core | Version: master
Blocked By: | Blocking:
Branch state: merged | Votes for changeset: committed-master
------------------------+----------------------------------------
Comment (by andrew_b):
Thanks for the comment!
Fixed: [8b79bfe32d776f0f0299b77b422211b14be29f51].
--
Ticket URL: <http://www.midnight-commander.org/ticket/4287#comment:9>