Re: After unlinking a large file on ext4, the process stalls for a long time

[Mason <mpeg.blue@free.fr>]

On 17/07/2014 18:07, Mason wrote:

> Theodore Ts'o wrote:
> 
>> Mason wrote:
>>
>>> unlink("/mnt/hdd/xxx")                  = 0 <111.479283>
>>>
>>> 0.01user 111.48system 1:51.99elapsed 99%CPU (0avgtext+0avgdata 772maxresident)k
>>> 0inputs+0outputs (0major+434minor)pagefaults 0swaps
>>
>> ... and we're CPU bound inside the kernel.
>>
>> Can you run perf so we can see exactly where we're spending the CPU?
>> You're not using a journal, so I'm pretty sure what you will find is
>> that we're spending all of our time in mb_free_blocks(), when it is
>> updating the internal mballoc buddy bitmaps.
>>
>> With a journal, this work done by mb_free_blocks() is hidden in the
>> kjournal thread, and happens after the commit is completed, so it
>> won't block other file system operations (other than burning some
>> extra CPU on one of the multiple cores available on a typical x86
>> CPU).
>>
>> Also, I suspect the CPU overhead is *much* less on an x86 CPU, which
>> has native bit test/set/clear instructions, whereas the MIPS
>> architecture was designed by Prof. Hennessy at Stanford, who was a
>> doctrinaire RISC fanatic, so there would be no bitop instructions.
>>
>> Even though I'm pretty sure what we'll find, knowing exactly *where*
>> in mb_free_blocks() or the function it calls would be helpful in
>> knowing what we need to optimize.  So if you could try using perf
>> (assuming that the perf is supported MIPS; not sure if it does) that
>> would be really helpful.
> 
> Is perf "better" than oprofile? (For some metric)
> 
> I have enabled:
> 
> CONFIG_PERF_EVENTS=y
> CONFIG_PROFILING=y
> CONFIG_TRACEPOINTS=y
> CONFIG_OPROFILE=y
> CONFIG_HAVE_OPROFILE=y
> CONFIG_KPROBES=y
> CONFIG_KRETPROBES=y
> 
> What command-line do you suggest I run to get the output you expect?
> (I'll try to get it done, but I might have to wait two weeks before
> I can run these tests.)

So much for oprofile...

  CC      arch/mips/oprofile/../../../drivers/oprofile/oprof.o
arch/mips/oprofile/../../../drivers/oprofile/oprof.c: In function 'oprofile_init':
arch/mips/oprofile/../../../drivers/oprofile/oprof.c:316: error: 'timer' undeclared (first use in this function)
arch/mips/oprofile/../../../drivers/oprofile/oprof.c:316: error: (Each undeclared identifier is reported only once
arch/mips/oprofile/../../../drivers/oprofile/oprof.c:316: error: for each function it appears in.)
arch/mips/oprofile/../../../drivers/oprofile/oprof.c: In function '__check_timer':
arch/mips/oprofile/../../../drivers/oprofile/oprof.c:373: error: 'timer' undeclared (first use in this function)
arch/mips/oprofile/../../../drivers/oprofile/oprof.c: At top level:
arch/mips/oprofile/../../../drivers/oprofile/oprof.c:373: error: 'timer' undeclared here (not in a function)
cc1: warnings being treated as errors
arch/mips/oprofile/../../../drivers/oprofile/oprof.c:373: error: type defaults to 'int' in declaration of 'type name'
make[1]: *** [arch/mips/oprofile/../../../drivers/oprofile/oprof.o] Error 1
make: *** [arch/mips/oprofile] Error 2

Dunno if this happens on vanilla kernels, or if the ODM messed
something up (again).

$ ll tools/perf/arch/
drwxrwxr-x 4 bob bob 4096 Mar 27 17:12 arm/
drwxrwxr-x 4 bob bob 4096 Mar 27 17:12 powerpc/
drwxrwxr-x 4 bob bob 4096 Mar 27 17:12 s390/
drwxrwxr-x 4 bob bob 4096 Mar 27 17:12 sh/
drwxrwxr-x 4 bob bob 4096 Mar 27 17:12 sparc/
drwxrwxr-x 4 bob bob 4096 Mar 27 17:12 x86/

I'm not sure perf supports MIPS...

Or maybe it does

$ g -rni mips .
./Makefile:45:				  -e s/ppc.*/powerpc/ -e s/mips.*/mips/ \
Binary file ./.Makefile.swp matches
./perf.h:76:#ifdef __mips__
./perf.h:77:#include "../../arch/mips/include/asm/unistd.h"
./perf.h:79:				".set	mips2\n\t"			\
./perf.h:81:				".set	mips0"				\


-- 
Regards.