crash reports while running IO on raid0 btrfs

crash reports while running IO on raid0 btrfs

[Srinivasa Chamarthy]

Received the following crash reports:

fio: pid=2847, got signal=6
Jobs: 3 (f=101), CR=1200MB/0B KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.1%
done] [0KB/118.1MB/0KB /s] [0/1814/0 iopJobs: 3 (f=97), CR=1200MB/0B
KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.2% done] [0KB/40312KB/0KB /s]
[0/583/0 iops]*** Error in `fio':
double free or corruption (!prev): 0x000000000114d7b0 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x730bf)[0x7fcf25c7e0bf]
/lib64/libc.so.6(+0x7892e)[0x7fcf25c8392e]
/lib64/libc.so.6(+0x79636)[0x7fcf25c84636]
fio(free_io_mem+0x97)[0x42c3e7]
fio[0x44dc73]
fio[0x450fd9]
fio(fio_backend+0xfb)[0x45144b]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7fcf25c2cb05]
fio[0x40d3ec]

# fio -v
fio-2.2.7-9-g4da2

# fio --output=file_io.out ./fio_jobs/fio_file.fio

# cat ./fio_jobs/fio_file.fio
[fileio]
ioengine=libaio
rw=write
directory=/mnt/btr1:/mnt/btr2:/mnt/btr3
filesize=1m-40m
file_append=1
nrfiles=256
openfiles=50
fsync_on_close=1
rwmixread=40
file_service_type=random:64
random_generator=tausworthe
rate=,400m
bs=8k
numjobs=6
iodepth=8
blocksize_range=8k-124k
loops=1
fill_device=1
fsync=1024

# btrfs filesystem show
Label: none  uuid: ed55f47f-bf72-4c13-a130-cde927f49fd8
        Total devices 4 FS bytes used 4.12MiB
        devid    1 size 10.00GiB used 3.01GiB path /dev/sdb
        devid    2 size 10.00GiB used 3.00GiB path /dev/sdc
        devid    3 size 10.00GiB used 3.00GiB path /dev/sdd
        devid    4 size 10.00GiB used 3.00GiB path /dev/sde

Label: none  uuid: 60428549-a0b5-41f7-bf7f-6a6607b08925
        Total devices 4 FS bytes used 4.12MiB
        devid    1 size 10.00GiB used 2.01GiB path /dev/sdf
        devid    2 size 10.00GiB used 2.00GiB path /dev/sdg
        devid    3 size 10.00GiB used 2.00GiB path /dev/sdh
        devid    4 size 10.00GiB used 2.00GiB path /dev/sdi

Label: none  uuid: 6c9672ad-8940-42ed-a1d4-fa1c6b6d20e8
        Total devices 4 FS bytes used 4.12MiB
        devid    1 size 10.00GiB used 3.01GiB path /dev/sdj
        devid    2 size 10.00GiB used 3.00GiB path /dev/sdk
        devid    3 size 10.00GiB used 3.00GiB path /dev/sdl
        devid    4 size 10.00GiB used 3.00GiB path /dev/sdm

Btrfs v3.16+20140829

 # lsb_release -a
LSB Version:    n/a
Distributor ID: SUSE LINUX
Description:    SUSE Linux Enterprise Server 12
Release:        12
Codename:       12

# uname -r
3.12.39-47-default

I am running the workload again to get the core dumps.

-- 
Srinivasa R Chamarthy

Re: crash reports while running IO on raid0 btrfs

[Srinivasa Chamarthy]

Here is the stack trace from core:

# gdb $(which fio) ./core
GNU gdb (GDB; SUSE Linux Enterprise 12) 7.7
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-suse-linux".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://bugs.opensuse.org/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...

warning: /etc/gdbinit.d/gdb-heap.py: No such file or directory
Reading symbols from /usr/local/bin/fio...done.
[New LWP 4630]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `fio --output=file_io.out ./fio_jobs/fio_file.fio'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007fad1e27b187 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: zypper install
glibc-debuginfo-2.19-17.72.emc4975661.4975661.x86_64
libaio1-debuginfo-0.3.109-17.15.x86_64
libgcc_s1-debuginfo-4.8.3+r212056-11.2.8142.0.PTF.919274.x86_64
libnuma1-debuginfo-2.0.9-4.8.x86_64 libz1-debuginfo-1.2.8-5.1.x86_64
(gdb) bt
#0  0x00007fad1e27b187 in raise () from /lib64/libc.so.6
#1  0x00007fad1e27c538 in abort () from /lib64/libc.so.6
#2  0x00007fad1e2b90c4 in __libc_message () from /lib64/libc.so.6
#3  0x00007fad1e2be92e in malloc_printerr () from /lib64/libc.so.6
#4  0x00007fad1e2bf636 in _int_free () from /lib64/libc.so.6
#5  0x000000000042c3e7 in free_mem_malloc (td=0x7fad04ad5c40) at memory.c:205
#6  free_io_mem (td=td@entry=0x7fad04ad5c40) at memory.c:256
#7  0x000000000044dc73 in cleanup_io_u (td=0x7fad04ad5c40) at backend.c:1010
#8  thread_main (data=data@entry=0x7fad04ad5c40) at backend.c:1627
#9  0x0000000000450fd9 in fork_main (offset=4, shmid=<optimized out>)
at backend.c:1684
#10 run_threads () at backend.c:2039
#11 0x000000000045144b in fio_backend () at backend.c:2240
#12 0x00007fad1e267b05 in __libc_start_main () from /lib64/libc.so.6
#13 0x000000000040d3ec in _start () at ../sysdeps/x86_64/start.S:122

On Fri, Apr 17, 2015 at 5:13 PM, Srinivasa Chamarthy
<chamarthy.raju@gmail.com> wrote:
> Received the following crash reports:
>
> fio: pid=2847, got signal=6
> Jobs: 3 (f=101), CR=1200MB/0B KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.1%
> done] [0KB/118.1MB/0KB /s] [0/1814/0 iopJobs: 3 (f=97), CR=1200MB/0B
> KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.2% done] [0KB/40312KB/0KB /s]
> [0/583/0 iops]*** Error in `fio':
> double free or corruption (!prev): 0x000000000114d7b0 ***
> ======= Backtrace: =========
> /lib64/libc.so.6(+0x730bf)[0x7fcf25c7e0bf]
> /lib64/libc.so.6(+0x7892e)[0x7fcf25c8392e]
> /lib64/libc.so.6(+0x79636)[0x7fcf25c84636]
> fio(free_io_mem+0x97)[0x42c3e7]
> fio[0x44dc73]
> fio[0x450fd9]
> fio(fio_backend+0xfb)[0x45144b]
> /lib64/libc.so.6(__libc_start_main+0xf5)[0x7fcf25c2cb05]
> fio[0x40d3ec]
>
> # fio -v
> fio-2.2.7-9-g4da2
>
> # fio --output=file_io.out ./fio_jobs/fio_file.fio
>
> # cat ./fio_jobs/fio_file.fio
> [fileio]
> ioengine=libaio
> rw=write
> directory=/mnt/btr1:/mnt/btr2:/mnt/btr3
> filesize=1m-40m
> file_append=1
> nrfiles=256
> openfiles=50
> fsync_on_close=1
> rwmixread=40
> file_service_type=random:64
> random_generator=tausworthe
> rate=,400m
> bs=8k
> numjobs=6
> iodepth=8
> blocksize_range=8k-124k
> loops=1
> fill_device=1
> fsync=1024
>
> # btrfs filesystem show
> Label: none  uuid: ed55f47f-bf72-4c13-a130-cde927f49fd8
>         Total devices 4 FS bytes used 4.12MiB
>         devid    1 size 10.00GiB used 3.01GiB path /dev/sdb
>         devid    2 size 10.00GiB used 3.00GiB path /dev/sdc
>         devid    3 size 10.00GiB used 3.00GiB path /dev/sdd
>         devid    4 size 10.00GiB used 3.00GiB path /dev/sde
>
> Label: none  uuid: 60428549-a0b5-41f7-bf7f-6a6607b08925
>         Total devices 4 FS bytes used 4.12MiB
>         devid    1 size 10.00GiB used 2.01GiB path /dev/sdf
>         devid    2 size 10.00GiB used 2.00GiB path /dev/sdg
>         devid    3 size 10.00GiB used 2.00GiB path /dev/sdh
>         devid    4 size 10.00GiB used 2.00GiB path /dev/sdi
>
> Label: none  uuid: 6c9672ad-8940-42ed-a1d4-fa1c6b6d20e8
>         Total devices 4 FS bytes used 4.12MiB
>         devid    1 size 10.00GiB used 3.01GiB path /dev/sdj
>         devid    2 size 10.00GiB used 3.00GiB path /dev/sdk
>         devid    3 size 10.00GiB used 3.00GiB path /dev/sdl
>         devid    4 size 10.00GiB used 3.00GiB path /dev/sdm
>
> Btrfs v3.16+20140829
>
>  # lsb_release -a
> LSB Version:    n/a
> Distributor ID: SUSE LINUX
> Description:    SUSE Linux Enterprise Server 12
> Release:        12
> Codename:       12
>
> # uname -r
> 3.12.39-47-default
>
> I am running the workload again to get the core dumps.
>
> --
> Srinivasa R Chamarthy



-- 
Srinivasa R Chamarthy

Re: crash reports while running IO on raid0 btrfs

[Jens Axboe]

On 04/17/2015 03:13 AM, Srinivasa Chamarthy wrote:
> Received the following crash reports:
>
> fio: pid=2847, got signal=6
> Jobs: 3 (f=101), CR=1200MB/0B KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.1%
> done] [0KB/118.1MB/0KB /s] [0/1814/0 iopJobs: 3 (f=97), CR=1200MB/0B
> KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.2% done] [0KB/40312KB/0KB /s]
> [0/583/0 iops]*** Error in `fio':
> double free or corruption (!prev): 0x000000000114d7b0 ***
> ======= Backtrace: =========
> /lib64/libc.so.6(+0x730bf)[0x7fcf25c7e0bf]
> /lib64/libc.so.6(+0x7892e)[0x7fcf25c8392e]
> /lib64/libc.so.6(+0x79636)[0x7fcf25c84636]
> fio(free_io_mem+0x97)[0x42c3e7]
> fio[0x44dc73]
> fio[0x450fd9]
> fio(fio_backend+0xfb)[0x45144b]
> /lib64/libc.so.6(__libc_start_main+0xf5)[0x7fcf25c2cb05]
> fio[0x40d3ec]
>
> # fio -v
> fio-2.2.7-9-g4da2

I can't reproduce this. Could you try a make clean and make again? 
Sometimes fio's build system screws up when you pull in changes, some of 
the dependencies are apparently whacked.

-- 
Jens Axboe

Re: crash reports while running IO on raid0 btrfs

[Jens Axboe]

[-- Attachment #1: Type: text/plain, Size: 1412 bytes --]

On 04/24/2015 10:20 AM, Jens Axboe wrote:
> On 04/17/2015 03:13 AM, Srinivasa Chamarthy wrote:
>> Received the following crash reports:
>>
>> fio: pid=2847, got signal=6
>> Jobs: 3 (f=101), CR=1200MB/0B KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.1%
>> done] [0KB/118.1MB/0KB /s] [0/1814/0 iopJobs: 3 (f=97), CR=1200MB/0B
>> KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.2% done] [0KB/40312KB/0KB /s]
>> [0/583/0 iops]*** Error in `fio':
>> double free or corruption (!prev): 0x000000000114d7b0 ***
>> ======= Backtrace: =========
>> /lib64/libc.so.6(+0x730bf)[0x7fcf25c7e0bf]
>> /lib64/libc.so.6(+0x7892e)[0x7fcf25c8392e]
>> /lib64/libc.so.6(+0x79636)[0x7fcf25c84636]
>> fio(free_io_mem+0x97)[0x42c3e7]
>> fio[0x44dc73]
>> fio[0x450fd9]
>> fio(fio_backend+0xfb)[0x45144b]
>> /lib64/libc.so.6(__libc_start_main+0xf5)[0x7fcf25c2cb05]
>> fio[0x40d3ec]
>>
>> # fio -v
>> fio-2.2.7-9-g4da2
>
> I can't reproduce this. Could you try a make clean and make again?
> Sometimes fio's build system screws up when you pull in changes, some of
> the dependencies are apparently whacked.

Actually, I think I see what it is. It's because your max bs isn't a 
multiple of the min bs, and fio has a bug in where it rounds up the 
blocksize as a multiple of the min bs. So we end up rounding up to 128K, 
where the max should be 124K. This causes us to overwrite allocated 
memory, and madness ensues. Can you test this patch?

-- 
Jens Axboe


[-- Attachment #2: bs-align-down.patch --]
[-- Type: text/x-patch, Size: 409 bytes --]

diff --git a/io_u.c b/io_u.c
index ba3f7ca00fcd..50644850463f 100644
--- a/io_u.c
+++ b/io_u.c
@@ -485,7 +485,7 @@ static unsigned int __get_next_buflen(struct thread_data *td, struct io_u *io_u,
 				~(td->o.verify_interval - 1);
 
 		if (!td->o.bs_unaligned && is_power_of_2(minbs))
-			buflen = (buflen + minbs - 1) & ~(minbs - 1);
+			buflen &= ~(minbs - 1);
 
 	} while (!io_u_fits(td, io_u, buflen));
 

Re: crash reports while running IO on raid0 btrfs

[Srinivasa Chamarthy]

Thanks. :) Oh yeah... i did not see i gave a wrong max bs. typo ...
oops... sometimes doing something wrong wakes up some issues :)

I tried the provided patch and it worked well. I also tried with the
right max bs and it all works well now.

Thanks for the great support.

On Sat, Apr 25, 2015 at 12:39 AM, Jens Axboe <axboe@kernel.dk> wrote:
> On 04/24/2015 10:20 AM, Jens Axboe wrote:
>>
>> On 04/17/2015 03:13 AM, Srinivasa Chamarthy wrote:
>>>
>>> Received the following crash reports:
>>>
>>> fio: pid=2847, got signal=6
>>> Jobs: 3 (f=101), CR=1200MB/0B KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.1%
>>> done] [0KB/118.1MB/0KB /s] [0/1814/0 iopJobs: 3 (f=97), CR=1200MB/0B
>>> KB/s: [K(1),W(1),K(1),W(2),K(1)] [80.2% done] [0KB/40312KB/0KB /s]
>>> [0/583/0 iops]*** Error in `fio':
>>> double free or corruption (!prev): 0x000000000114d7b0 ***
>>> ======= Backtrace: =========
>>> /lib64/libc.so.6(+0x730bf)[0x7fcf25c7e0bf]
>>> /lib64/libc.so.6(+0x7892e)[0x7fcf25c8392e]
>>> /lib64/libc.so.6(+0x79636)[0x7fcf25c84636]
>>> fio(free_io_mem+0x97)[0x42c3e7]
>>> fio[0x44dc73]
>>> fio[0x450fd9]
>>> fio(fio_backend+0xfb)[0x45144b]
>>> /lib64/libc.so.6(__libc_start_main+0xf5)[0x7fcf25c2cb05]
>>> fio[0x40d3ec]
>>>
>>> # fio -v
>>> fio-2.2.7-9-g4da2
>>
>>
>> I can't reproduce this. Could you try a make clean and make again?
>> Sometimes fio's build system screws up when you pull in changes, some of
>> the dependencies are apparently whacked.
>
>
> Actually, I think I see what it is. It's because your max bs isn't a
> multiple of the min bs, and fio has a bug in where it rounds up the
> blocksize as a multiple of the min bs. So we end up rounding up to 128K,
> where the max should be 124K. This causes us to overwrite allocated memory,
> and madness ensues. Can you test this patch?
>
> --
> Jens Axboe
>



-- 
Srinivasa R Chamarthy