2017-02-09 10:20:46 |
Robert Whitton |
description |
Nemo version: nemo 2.2.4.
Running under debian jessie release 8.7.
Copying nearly a million (small) files from local disk to a USB2 attached hard disk (not a memory stick). A total copy of 8.7GiB, really not very large. The copy started quickly but become slower and slower. After nearly a day the rate of copying had dropped to a pathetic ~100KiB/s.
"top" shows that one of the CPU cores is ~100% busy.
I took a profile of nemo (using perf) and it shows:
# To display the perf.data header info, please use --header/--header-only options.
#
# Samples: 12K of event 'cycles'
# Event count (approx.): 11388387380
#
# Overhead Command Shared Object Symbol
# ........ ....... ............................. ................................................
#
98.76% pool libglib-2.0.so.0.4200.1 [.] g_list_last
0.07% nemo libglib-2.0.so.0.4200.1 [.] g_slice_alloc
0.07% nemo libc-2.19.so [.] _int_malloc
0.04% nemo libpango-1.0.so.0.3600.8 [.] pango_find_paragraph_boundary
0.03% nemo libglib-2.0.so.0.4200.1 [.] g_hash_table_lookup
0.03% nemo libgobject-2.0.so.0.4200.1 [.] g_type_value_table_peek
0.03% pool libc-2.19.so [.] malloc
0.03% nemo libglib-2.0.so.0.4200.1 [.] g_slice_free_chain_with_offset
0.03% gmain libc-2.19.so [.] _IO_no_init
0.02% pool libglib-2.0.so.0.4200.1 [.] g_slice_alloc
0.02% nemo [kernel.kallsyms] [k] msecs_to_jiffies
0.02% nemo libc-2.19.so [.] strlen
0.02% nemo libcairo.so.2.11400.0 [.] 0x00000000000461f3
0.02% nemo libdbus-1.so.3.8.14 [.] dbus_connection_get_dispatch_status
0.02% nemo libharfbuzz.so.0.935.0 [.] 0x00000000000189cd
0.02% nemo libpangocairo-1.0.so.0.3600.8 [.] 0x00000000000065c8
0.02% nemo libgobject-2.0.so.0.4200.1 [.] g_type_check_instance_is_a
0.02% nemo libgdk-3.so.0.1400.5 [.] 0x000000000005b2b2
0.02% nemo libc-2.19.so [.] malloc
0.02% nemo libglib-2.0.so.0.4200.1 [.] g_pointer_bit_lock
0.02% pool libglib-2.0.so.0.4200.1 [.] g_hash_table_lookup_extended
< SNIPPED THE REMAINING INSIGNIFICANT ENTRIES, FILE ATTACHED FOR FULL OUTPUT >
98.76% of the time we are in g_list_last? That doesn't sound good. If I had to guess I would suggest the we have some computation here that's O(N^X) where X is > 0 and N is the number of files already copied. So it gets slower and slower as the copy progresses. |
Nemo version: nemo 2.2.4.
Running under debian jessie release 8.7.
Copying nearly a million (small) files from local disk to a USB2 attached hard disk (not a memory stick). A total copy of 8.7GiB, really not very large. The copy started quickly but become slower and slower. After nearly a day the rate of copying had dropped to a pathetic ~100KiB/s.
"top" shows that one of the CPU cores is ~100% busy.
I took a profile of nemo (using perf) and it shows:
# To display the perf.data header info, please use --header/--header-only options.
#
# Samples: 12K of event 'cycles'
# Event count (approx.): 11388387380
#
# Overhead Command Shared Object Symbol
# ........ ....... ............................. ................................................
#
98.76% pool libglib-2.0.so.0.4200.1 [.] g_list_last
0.07% nemo libglib-2.0.so.0.4200.1 [.] g_slice_alloc
0.07% nemo libc-2.19.so [.] _int_malloc
0.04% nemo libpango-1.0.so.0.3600.8 [.] pango_find_paragraph_boundary
0.03% nemo libglib-2.0.so.0.4200.1 [.] g_hash_table_lookup
0.03% nemo libgobject-2.0.so.0.4200.1 [.] g_type_value_table_peek
0.03% pool libc-2.19.so [.] malloc
0.03% nemo libglib-2.0.so.0.4200.1 [.] g_slice_free_chain_with_offset
0.03% gmain libc-2.19.so [.] _IO_no_init
0.02% pool libglib-2.0.so.0.4200.1 [.] g_slice_alloc
0.02% nemo [kernel.kallsyms] [k] msecs_to_jiffies
0.02% nemo libc-2.19.so [.] strlen
0.02% nemo libcairo.so.2.11400.0 [.] 0x00000000000461f3
0.02% nemo libdbus-1.so.3.8.14 [.] dbus_connection_get_dispatch_status
0.02% nemo libharfbuzz.so.0.935.0 [.] 0x00000000000189cd
0.02% nemo libpangocairo-1.0.so.0.3600.8 [.] 0x00000000000065c8
0.02% nemo libgobject-2.0.so.0.4200.1 [.] g_type_check_instance_is_a
0.02% nemo libgdk-3.so.0.1400.5 [.] 0x000000000005b2b2
0.02% nemo libc-2.19.so [.] malloc
0.02% nemo libglib-2.0.so.0.4200.1 [.] g_pointer_bit_lock
0.02% pool libglib-2.0.so.0.4200.1 [.] g_hash_table_lookup_extended
< SNIPPED THE REMAINING INSIGNIFICANT ENTRIES, FILE ATTACHED FOR FULL OUTPUT >
98.76% of the time we are in g_list_last? That doesn't sound good. If I had to guess I would suggest the we have some computation here that's O(N^X) where X is > 0 and N is the number of files already copied. So it gets slower and slower as the copy progresses.
Let's look at the implementation of libglib... The implementation of g_list_last is truly appalling as the list gets longer...
{
if (list)
{
while (list->next)
list = list->next;
}
return list;
}
i.e. it appears to walk the list from the head until it encounters the last element.
I'd strongly suggest that nemo avoids direct or indirect use of g_list_last since this is likely to offer very poor performance when the list becomes long. |
|