Skip to contentSkip to conversation

repair: realloc(): invalid next size

DISCUSSION Arkadiusz Miśkiewicz 2 participants 6 messages Oct 8, 2018 – Oct 12, 2018

lore
Share & tools
lore
#0 lore raw

Big fs, ton of small files, repair takes 36h until this happens:

rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f980, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
realloc(): invalid next size
Aborted

Fails somewhere in 0x41f9db <xfs_dir2_sf_verify+603>

Complete log at
https://ixion.pld-linux.org/~arekm/xfs-1/repair.txt

Test was done with xfs_repair 4.17.0 and 4.18.0 with the same result.

kernel 4.18.5

Running under gdb now.

Any ideas?

Signature · 1 line
Arkadiusz Miśkiewicz, arekm / ( maven.pl | pld-linux.org )
#1 lore raw
Quoted 29 lines · Arkadiusz Miśkiewicz

Big fs, ton of small files, repair takes 36h until this happens:

rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f980, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
realloc(): invalid next size
Aborted

Fails somewhere in 0x41f9db <xfs_dir2_sf_verify+603>

Complete log at
https://ixion.pld-linux.org/~arekm/xfs-1/repair.txt

Quoted 7 lines

Test was done with xfs_repair 4.17.0 and 4.18.0 with the same result.

kernel 4.18.5

Running under gdb now.

Any ideas?

With such a big fs it's tough to share a metadump for a reproducer, I assume.

The earlier write verifiers failing for xfs_repair writes are troubling...

I'm not certain why it's rebuilding so many dir inodes; there are several cases where that happens, but unfortunately repair doesn't always say which one or why.

Anyway, you eventually get to this inode (it's the same in decimal & hex below):

rebuilding directory inode 360732305
Metadata corruption detected at 0x41f9db, inode 0x15805691 data fork
xfs_repair: warning - iflush_int failed (-117)

with lots of corruption during the writes, and this happens for a couple other inodes, until finally:

rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork

and this one ends up aborting in glibc's realloc():

realloc(): invalid next size

I /think/ that this indicates that memory has been corrupted during the repair run. :/ Running under valgrind would probably lead to a 72hr runtime or more :)

I wonder if it would save time in the long run to make a metadump and remove all directory trees other than this inode (360732305) from it, and see if the same failure occurs when running on the reduced fs image?

Out of curiosity, what happened to this filesystem to leave it in bad shape?

-Eric

#2 lore raw
Quoted 62 lines · Eric Sandeen
Quoted 29 lines · Arkadiusz Miśkiewicz

Big fs, ton of small files, repair takes 36h until this happens:

rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f980, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
realloc(): invalid next size
Aborted

Fails somewhere in 0x41f9db <xfs_dir2_sf_verify+603>

Complete log at
https://ixion.pld-linux.org/~arekm/xfs-1/repair.txt

Quoted 7 lines

Test was done with xfs_repair 4.17.0 and 4.18.0 with the same result.

kernel 4.18.5

Running under gdb now.

Any ideas?

With such a big fs it's tough to share a metadump for a reproducer, I assume.

The earlier write verifiers failing for xfs_repair writes are troubling...

I'm not certain why it's rebuilding so many dir inodes; there are several cases where that happens, but unfortunately repair doesn't always say which one or why.

Anyway, you eventually get to this inode (it's the same in decimal & hex below):

rebuilding directory inode 360732305
Metadata corruption detected at 0x41f9db, inode 0x15805691 data fork
xfs_repair: warning - iflush_int failed (-117)

with lots of corruption during the writes, and this happens for a couple other inodes, until finally:

rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork

and this one ends up aborting in glibc's realloc():

Quoted 8 lines

realloc(): invalid next size

I /think/ that this indicates that memory has been corrupted during the repair run. :/ Running under valgrind would probably lead to a 72hr runtime or more :)

I wonder if it would save time in the long run to make a metadump and remove all directory trees other than this inode (360732305) from it, and see if the same failure occurs when running on the reduced fs image?

Actually if you try that, also leaving the directory trees in place for the other inodes that reported issues would make sense.

-Eric

#3 lore raw
In reply to Arkadiusz Miśkiewicz
Quoted 24 lines · Arkadiusz Miśkiewicz

Big fs, ton of small files, repair takes 36h until this happens:

rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f980, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
realloc(): invalid next size
Aborted

Quoted 1 line

Fails somewhere in 0x41f9db <xfs_dir2_sf_verify+603>

Not much progress, traceback but without line numbers:
[New Thread 0x7ffff4588700 (LWP 16783)]
rebuilding directory inode 30299650439
rebuilding directory inode 30300818030
rebuilding directory inode 30317087573
rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x486261, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x486261, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
and segfault

warning: Loadable section ".note.gnu.property" outside of ELF segments
Core was generated by `/sbin/xfs_repair -vvvv /dev/sdc1'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:525
525 VMOVU -VEC_SIZE(%rcx), %VEC(1)
[Current thread is 1 (Thread 0x7ffff797d300 (LWP 31979))]
(gdb) bt

#0  __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:525
#1  0x0000000000485e1e in xfs_dir2_sf_addname_hard ()
#2  0x000000000048599b in xfs_dir2_sf_addname ()
#3  0x00000000004773c2 in libxfs_dir_createname ()
#4  0x00000000004279f3 in longform_dir2_rebuild ()
#5  0x000000000042a61a in longform_dir2_entry_check ()
#6  0x000000000042b697 in process_dir_inode ()
#7  0x000000000042c3ca in traverse_function ()
#8  0x00000000004304a1 in prefetch_ag_range ()
#9  0x000000000043061f in do_inode_prefetch ()

#10 0x000000000042c49c in traverse_ags ()
#11 0x000000000042c752 in phase6 ()
#12 0x000000000043ea38 in main ()

gdb doesn't like my binary, not sure why yet

/sbin/xfs_repair: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2, for GNU/Linux 3.2.0, BuildID[sha1]=710d79304cb58f8e415302572cc718e38f0f1aa4, with debug_info, not stripped

Quoted 12 lines

Complete log at
https://ixion.pld-linux.org/~arekm/xfs-1/repair.txt

Test was done with xfs_repair 4.17.0 and 4.18.0 with the same result.

kernel 4.18.5

Running under gdb now.

Any ideas?

#4 lore raw
Quoted 69 lines · Arkadiusz Miśkiewicz
Quoted 24 lines · Arkadiusz Miśkiewicz

Big fs, ton of small files, repair takes 36h until this happens:

rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f980, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
realloc(): invalid next size
Aborted

Quoted 1 line

Fails somewhere in 0x41f9db <xfs_dir2_sf_verify+603>

Not much progress, traceback but without line numbers:
[New Thread 0x7ffff4588700 (LWP 16783)]
rebuilding directory inode 30299650439
rebuilding directory inode 30300818030
rebuilding directory inode 30317087573
rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x486261, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x486261, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
and segfault

warning: Loadable section ".note.gnu.property" outside of ELF segments
Core was generated by `/sbin/xfs_repair -vvvv /dev/sdc1'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:525 525        VMOVU    -VEC_SIZE(%rcx), %VEC(1)
[Current thread is 1 (Thread 0x7ffff797d300 (LWP 31979))]
(gdb) bt
#0  __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:525 #1  0x0000000000485e1e in xfs_dir2_sf_addname_hard ()
#2  0x000000000048599b in xfs_dir2_sf_addname ()
#3  0x00000000004773c2 in libxfs_dir_createname ()
#4  0x00000000004279f3 in longform_dir2_rebuild ()
#5  0x000000000042a61a in longform_dir2_entry_check ()
#6  0x000000000042b697 in process_dir_inode ()
#7  0x000000000042c3ca in traverse_function ()
#8  0x00000000004304a1 in prefetch_ag_range ()
#9  0x000000000043061f in do_inode_prefetch ()
#10 0x000000000042c49c in traverse_ags ()
#11 0x000000000042c752 in phase6 ()
#12 0x000000000043ea38 in main ()

Quoted 1 line

gdb doesn't like my binary, not sure why yet

but it looks to be memcpy near the end of function

(gdb) where

#0  __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:525
#1  0x0000000000485e1e in xfs_dir2_sf_addname_hard ()
#2  0x000000000048599b in xfs_dir2_sf_addname ()
#3  0x00000000004773c2 in libxfs_dir_createname ()
#4  0x00000000004279f3 in longform_dir2_rebuild ()
#5  0x000000000042a61a in longform_dir2_entry_check ()
#6  0x000000000042b697 in process_dir_inode ()
#7  0x000000000042c3ca in traverse_function ()
#8  0x00000000004304a1 in prefetch_ag_range ()
#9  0x000000000043061f in do_inode_prefetch ()

#10 0x000000000042c49c in traverse_ags ()
#11 0x000000000042c752 in phase6 ()
#12 0x000000000043ea38 in main ()
(gdb) frame 1
#1 0x0000000000485e1e in xfs_dir2_sf_addname_hard () (gdb) disassemble 0x0000000000485e1e
Dump of assembler code for function xfs_dir2_sf_addname_hard:

   0x0000000000485b32 <+0>:	push   %rbp
   0x0000000000485b33 <+1>:	mov    %rsp,%rbp
   0x0000000000485b36 <+4>:	sub    $0x60,%rsp
   0x0000000000485b3a <+8>:	mov    %rdi,-0x58(%rbp)
   0x0000000000485b3e <+12>:	mov    %esi,-0x5c(%rbp)
   0x0000000000485b41 <+15>:	mov    %edx,-0x60(%rbp)
   0x0000000000485b44 <+18>:	mov    -0x58(%rbp),%rax
   0x0000000000485b48 <+22>:	mov    0x38(%rax),%rax
   0x0000000000485b4c <+26>:	mov    %rax,-0x18(%rbp)
   0x0000000000485b50 <+30>:	mov    -0x18(%rbp),%rax
   0x0000000000485b54 <+34>:	mov    0xb0(%rax),%rax
   0x0000000000485b5b <+41>:	mov    %rax,-0x20(%rbp)
   0x0000000000485b5f <+45>:	mov    -0x18(%rbp),%rax
   0x0000000000485b63 <+49>:	mov    0xe0(%rax),%rax
   0x0000000000485b6a <+56>:	mov    %eax,-0x24(%rbp)
   0x0000000000485b6d <+59>:	mov    -0x24(%rbp),%eax
   0x0000000000485b70 <+62>:	cltq
   0x0000000000485b72 <+64>:	mov    $0x1,%esi
   0x0000000000485b77 <+69>:	mov    %rax,%rdi
   0x0000000000485b7a <+72>:	callq  0x443186 <kmem_alloc>
   0x0000000000485b7f <+77>:	mov    %rax,-0x30(%rbp)
   0x0000000000485b83 <+81>:	mov    -0x30(%rbp),%rax
   0x0000000000485b87 <+85>:	mov    %rax,-0x38(%rbp)
   0x0000000000485b8b <+89>:	mov    -0x24(%rbp),%eax
   0x0000000000485b8e <+92>:	movslq %eax,%rdx
   0x0000000000485b91 <+95>:	mov    -0x20(%rbp),%rcx
   0x0000000000485b95 <+99>:	mov    -0x38(%rbp),%rax
   0x0000000000485b99 <+103>:	mov    %rcx,%rsi
   0x0000000000485b9c <+106>:	mov    %rax,%rdi
   0x0000000000485b9f <+109>:	callq  0x4033c0 <memcpy@plt>
   0x0000000000485ba4 <+114>:	mov    -0x18(%rbp),%rax
   0x0000000000485ba8 <+118>:	mov    0x130(%rax),%rax
   0x0000000000485baf <+125>:	mov    0x70(%rax),%eax
   0x0000000000485bb2 <+128>:	mov    %eax,-0x8(%rbp)
   0x0000000000485bb5 <+131>:	mov    -0x38(%rbp),%rax
   0x0000000000485bb9 <+135>:	mov    %rax,%rdi
   0x0000000000485bbc <+138>:	callq  0x48510e 
<xfs_dir2_sf_firstentry.lto_priv.614>
   0x0000000000485bc1 <+143>:	mov    %rax,-0x10(%rbp)
   0x0000000000485bc5 <+147>:	mov    -0x18(%rbp),%rax
   0x0000000000485bc9 <+151>:	mov    0x130(%rax),%rax
   0x0000000000485bd0 <+158>:	mov    0x40(%rax),%rax
   0x0000000000485bd4 <+162>:	mov    -0x58(%rbp),%rdx
   0x0000000000485bd8 <+166>:	mov    0x10(%rdx),%edx
   0x0000000000485bdb <+169>:	mov    %edx,%edi
   0x0000000000485bdd <+171>:	callq  0x4ac8cb <__x86_indirect_thunk_rax>
   0x0000000000485be2 <+176>:	mov    %eax,-0x3c(%rbp)
   0x0000000000485be5 <+179>:	mov    -0x24(%rbp),%eax
   0x0000000000485be8 <+182>:	movslq %eax,%rdx
   0x0000000000485beb <+185>:	mov    -0x30(%rbp),%rax
   0x0000000000485bef <+189>:	add    %rdx,%rax
   0x0000000000485bf2 <+192>:	cmp    %rax,-0x10(%rbp)
   0x0000000000485bf6 <+196>:	sete   %al

--Type <RET> for more, q to quit, c to continue without paging--
0x0000000000485bf9 <+199>: movzbl %al,%eax
0x0000000000485bfc <+202>: mov %eax,-0x4(%rbp)
0x0000000000485bff <+205>: jmpq 0x485c8a
<xfs_dir2_sf_addname_hard+344>

   0x0000000000485c04 <+210>:	mov    -0x10(%rbp),%rax
   0x0000000000485c08 <+214>:	mov    %rax,%rdi
   0x0000000000485c0b <+217>:	callq  0x4850c4 
<xfs_dir2_sf_get_offset.lto_priv.619>
   0x0000000000485c10 <+222>:	mov    %eax,-0x40(%rbp)
   0x0000000000485c13 <+225>:	mov    -0x3c(%rbp),%edx
   0x0000000000485c16 <+228>:	mov    -0x8(%rbp),%eax
   0x0000000000485c19 <+231>:	add    %edx,%eax
   0x0000000000485c1b <+233>:	cmp    %eax,-0x40(%rbp)
   0x0000000000485c1e <+236>:	jae    0x485c94 
<xfs_dir2_sf_addname_hard+354>
   0x0000000000485c20 <+238>:	mov    -0x18(%rbp),%rax
   0x0000000000485c24 <+242>:	mov    0x130(%rax),%rax
   0x0000000000485c2b <+249>:	mov    0x40(%rax),%rax
   0x0000000000485c2f <+253>:	mov    -0x10(%rbp),%rdx
   0x0000000000485c33 <+257>:	movzbl (%rdx),%edx
   0x0000000000485c36 <+260>:	movzbl %dl,%edx
   0x0000000000485c39 <+263>:	mov    %edx,%edi
   0x0000000000485c3b <+265>:	callq  0x4ac8cb <__x86_indirect_thunk_rax>
   0x0000000000485c40 <+270>:	mov    %eax,%edx
   0x0000000000485c42 <+272>:	mov    -0x40(%rbp),%eax
   0x0000000000485c45 <+275>:	add    %edx,%eax
   0x0000000000485c47 <+277>:	mov    %eax,-0x8(%rbp)
   0x0000000000485c4a <+280>:	mov    -0x18(%rbp),%rax
   0x0000000000485c4e <+284>:	mov    0x130(%rax),%rax
   0x0000000000485c55 <+291>:	mov    0x8(%rax),%rax
   0x0000000000485c59 <+295>:	mov    -0x10(%rbp),%rcx
   0x0000000000485c5d <+299>:	mov    -0x38(%rbp),%rdx
   0x0000000000485c61 <+303>:	mov    %rcx,%rsi
   0x0000000000485c64 <+306>:	mov    %rdx,%rdi
   0x0000000000485c67 <+309>:	callq  0x4ac8cb <__x86_indirect_thunk_rax>
   0x0000000000485c6c <+314>:	mov    %rax,-0x10(%rbp)
   0x0000000000485c70 <+318>:	mov    -0x24(%rbp),%eax
   0x0000000000485c73 <+321>:	movslq %eax,%rdx
   0x0000000000485c76 <+324>:	mov    -0x30(%rbp),%rax
   0x0000000000485c7a <+328>:	add    %rdx,%rax
   0x0000000000485c7d <+331>:	cmp    %rax,-0x10(%rbp)
   0x0000000000485c81 <+335>:	sete   %al
   0x0000000000485c84 <+338>:	movzbl %al,%eax
   0x0000000000485c87 <+341>:	mov    %eax,-0x4(%rbp)
   0x0000000000485c8a <+344>:	cmpl   $0x0,-0x4(%rbp)
   0x0000000000485c8e <+348>:	je     0x485c04 
<xfs_dir2_sf_addname_hard+210>
   0x0000000000485c94 <+354>:	mov    -0x24(%rbp),%eax
   0x0000000000485c97 <+357>:	neg    %eax
   0x0000000000485c99 <+359>:	mov    %eax,%ecx
   0x0000000000485c9b <+361>:	mov    -0x18(%rbp),%rax
   0x0000000000485c9f <+365>:	mov    $0x0,%edx
   0x0000000000485ca4 <+370>:	mov    %ecx,%esi
   0x0000000000485ca6 <+372>:	mov    %rax,%rdi
   0x0000000000485ca9 <+375>:	callq  0x4918ee <libxfs_idata_realloc>
   0x0000000000485cae <+380>:	mov    -0x60(%rbp),%ecx
   0x0000000000485cb1 <+383>:	mov    -0x18(%rbp),%rax
--Type <RET> for more, q to quit, c to continue without paging--
   0x0000000000485cb5 <+387>:	mov    $0x0,%edx
   0x0000000000485cba <+392>:	mov    %ecx,%esi
   0x0000000000485cbc <+394>:	mov    %rax,%rdi
   0x0000000000485cbf <+397>:	callq  0x4918ee <libxfs_idata_realloc>
   0x0000000000485cc4 <+402>:	mov    -0x18(%rbp),%rax
   0x0000000000485cc8 <+406>:	mov    0xb0(%rax),%rax
   0x0000000000485ccf <+413>:	mov    %rax,-0x20(%rbp)
   0x0000000000485cd3 <+417>:	mov    -0x10(%rbp),%rax
   0x0000000000485cd7 <+421>:	sub    -0x38(%rbp),%rax
   0x0000000000485cdb <+425>:	mov    %eax,-0x44(%rbp)
   0x0000000000485cde <+428>:	mov    -0x44(%rbp),%eax
   0x0000000000485ce1 <+431>:	movslq %eax,%rdx
   0x0000000000485ce4 <+434>:	mov    -0x38(%rbp),%rcx
   0x0000000000485ce8 <+438>:	mov    -0x20(%rbp),%rax
   0x0000000000485cec <+442>:	mov    %rcx,%rsi
   0x0000000000485cef <+445>:	mov    %rax,%rdi
   0x0000000000485cf2 <+448>:	callq  0x4033c0 <memcpy@plt>
   0x0000000000485cf7 <+453>:	mov    -0x44(%rbp),%eax
   0x0000000000485cfa <+456>:	movslq %eax,%rdx
   0x0000000000485cfd <+459>:	mov    -0x20(%rbp),%rax
   0x0000000000485d01 <+463>:	add    %rdx,%rax
   0x0000000000485d04 <+466>:	mov    %rax,-0x50(%rbp)
   0x0000000000485d08 <+470>:	mov    -0x58(%rbp),%rax
   0x0000000000485d0c <+474>:	mov    0x10(%rax),%eax
   0x0000000000485d0f <+477>:	mov    %eax,%edx
   0x0000000000485d11 <+479>:	mov    -0x50(%rbp),%rax
   0x0000000000485d15 <+483>:	mov    %dl,(%rax)
   0x0000000000485d17 <+485>:	mov    -0x8(%rbp),%edx
   0x0000000000485d1a <+488>:	mov    -0x50(%rbp),%rax
   0x0000000000485d1e <+492>:	mov    %edx,%esi
   0x0000000000485d20 <+494>:	mov    %rax,%rdi
   0x0000000000485d23 <+497>:	callq  0x4850e5 

<xfs_dir2_sf_put_offset.lto_priv.616>
0x0000000000485d28 <+502>: mov -0x50(%rbp),%rax
0x0000000000485d2c <+506>: movzbl (%rax),%eax
0x0000000000485d2f <+509>: movzbl %al,%edx

   0x0000000000485d32 <+512>:	mov    -0x58(%rbp),%rax
   0x0000000000485d36 <+516>:	mov    0x8(%rax),%rax
   0x0000000000485d3a <+520>:	mov    -0x50(%rbp),%rcx
   0x0000000000485d3e <+524>:	add    $0x3,%rcx
   0x0000000000485d42 <+528>:	mov    %rax,%rsi
   0x0000000000485d45 <+531>:	mov    %rcx,%rdi
   0x0000000000485d48 <+534>:	callq  0x4033c0 <memcpy@plt>
   0x0000000000485d4d <+539>:	mov    -0x18(%rbp),%rax
   0x0000000000485d51 <+543>:	mov    0x130(%rax),%rax
   0x0000000000485d58 <+550>:	mov    0x28(%rax),%rax
   0x0000000000485d5c <+554>:	mov    -0x58(%rbp),%rdx
   0x0000000000485d60 <+558>:	mov    0x30(%rdx),%rdx
   0x0000000000485d64 <+562>:	mov    -0x50(%rbp),%rsi
   0x0000000000485d68 <+566>:	mov    -0x20(%rbp),%rcx
   0x0000000000485d6c <+570>:	mov    %rcx,%rdi
   0x0000000000485d6f <+573>:	callq  0x4ac8cb <__x86_indirect_thunk_rax>
   0x0000000000485d74 <+578>:	mov    -0x18(%rbp),%rax
   0x0000000000485d78 <+582>:	mov    0x130(%rax),%rax

--Type <RET> for more, q to quit, c to continue without paging--
0x0000000000485d7f <+589>: mov 0x18(%rax),%rax
0x0000000000485d83 <+593>: mov -0x58(%rbp),%rdx
0x0000000000485d87 <+597>: movzbl 0x14(%rdx),%edx
0x0000000000485d8b <+601>: movzbl %dl,%ecx

   0x0000000000485d8e <+604>:	mov    -0x50(%rbp),%rdx
   0x0000000000485d92 <+608>:	mov    %ecx,%esi
   0x0000000000485d94 <+610>:	mov    %rdx,%rdi
   0x0000000000485d97 <+613>:	callq  0x4ac8cb <__x86_indirect_thunk_rax>
   0x0000000000485d9c <+618>:	mov    -0x20(%rbp),%rax
   0x0000000000485da0 <+622>:	movzbl (%rax),%eax
   0x0000000000485da3 <+625>:	lea    0x1(%rax),%edx
   0x0000000000485da6 <+628>:	mov    -0x20(%rbp),%rax
   0x0000000000485daa <+632>:	mov    %dl,(%rax)
   0x0000000000485dac <+634>:	mov    -0x58(%rbp),%rax
   0x0000000000485db0 <+638>:	mov    0x30(%rax),%rax
   0x0000000000485db4 <+642>:	mov    $0xffffffff,%edx
   0x0000000000485db9 <+647>:	cmp    %rdx,%rax
   0x0000000000485dbc <+650>:	jbe    0x485dd6 

<xfs_dir2_sf_addname_hard+676>
0x0000000000485dbe <+652>: cmpl $0x0,-0x5c(%rbp)
0x0000000000485dc2 <+656>: jne 0x485dd6
<xfs_dir2_sf_addname_hard+676>
0x0000000000485dc4 <+658>: mov -0x20(%rbp),%rax
0x0000000000485dc8 <+662>: movzbl 0x1(%rax),%eax

   0x0000000000485dcc <+666>:	lea    0x1(%rax),%edx
   0x0000000000485dcf <+669>:	mov    -0x20(%rbp),%rax
   0x0000000000485dd3 <+673>:	mov    %dl,0x1(%rax)
   0x0000000000485dd6 <+676>:	cmpl   $0x0,-0x4(%rbp)
   0x0000000000485dda <+680>:	jne    0x485e1e 
<xfs_dir2_sf_addname_hard+748>
   0x0000000000485ddc <+682>:	mov    -0x18(%rbp),%rax
   0x0000000000485de0 <+686>:	mov    0x130(%rax),%rax
   0x0000000000485de7 <+693>:	mov    0x8(%rax),%rax
   0x0000000000485deb <+697>:	mov    -0x50(%rbp),%rcx
   0x0000000000485def <+701>:	mov    -0x20(%rbp),%rdx
   0x0000000000485df3 <+705>:	mov    %rcx,%rsi
   0x0000000000485df6 <+708>:	mov    %rdx,%rdi
   0x0000000000485df9 <+711>:	callq  0x4ac8cb <__x86_indirect_thunk_rax>
   0x0000000000485dfe <+716>:	mov    %rax,-0x50(%rbp)
   0x0000000000485e02 <+720>:	mov    -0x24(%rbp),%eax
   0x0000000000485e05 <+723>:	sub    -0x44(%rbp),%eax
   0x0000000000485e08 <+726>:	movslq %eax,%rdx
   0x0000000000485e0b <+729>:	mov    -0x10(%rbp),%rcx
   0x0000000000485e0f <+733>:	mov    -0x50(%rbp),%rax
   0x0000000000485e13 <+737>:	mov    %rcx,%rsi
   0x0000000000485e16 <+740>:	mov    %rax,%rdi
   0x0000000000485e19 <+743>:	callq  0x4033c0 <memcpy@plt>
=> 0x0000000000485e1e <+748>:	mov    -0x30(%rbp),%rax
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
   0x0000000000485e22 <+752>:	mov    %rax,%rdi
   0x0000000000485e25 <+755>:	callq  0x484e23 <kmem_free.lto_priv.174>
   0x0000000000485e2a <+760>:	mov    -0x60(%rbp),%eax

0x0000000000485e2d <+763>: movslq %eax,%rdx
0x0000000000485e30 <+766>: mov -0x18(%rbp),%rax
0x0000000000485e34 <+770>: mov %rdx,0xe0(%rax)
0x0000000000485e3b <+777>: leaveq
0x0000000000485e3c <+778>: retq
--Type <RET> for more, q to quit, c to continue without paging-- End of assembler dump.

Quoted 17 lines

/sbin/xfs_repair: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2, for GNU/Linux 3.2.0, BuildID[sha1]=710d79304cb58f8e415302572cc718e38f0f1aa4, with debug_info, not stripped

Quoted 12 lines

Complete log at
https://ixion.pld-linux.org/~arekm/xfs-1/repair.txt

Test was done with xfs_repair 4.17.0 and 4.18.0 with the same result.

kernel 4.18.5

Running under gdb now.

Any ideas?

Signature · 1 line
Arkadiusz Miśkiewicz, arekm / ( maven.pl | pld-linux.org )
#5 lore raw
In reply to Arkadiusz Miśkiewicz
Quoted 26 lines · Arkadiusz Miśkiewicz
Quoted 25 lines · Arkadiusz Miśkiewicz

Big fs, ton of small files, repair takes 36h until this happens:

rebuilding directory inode 30363993060
rebuilding directory inode 30398868604
rebuilding directory inode 30414474627
rebuilding directory inode 30425006954
rebuilding directory inode 30447937553
rebuilding directory inode 30529556616
rebuilding directory inode 30537494728
rebuilding directory inode 30569826838
rebuilding directory inode 31060721895
Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f9db, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
Warning: recursive buffer locking at block 31060721776 detected Metadata corruption detected at 0x41f980, inode 0x73b5d00e7 data fork
xfs_repair: warning - iflush_int failed (-117)
realloc(): invalid next size
Aborted

Fails somewhere in 0x41f9db <xfs_dir2_sf_verify+603>

[...]

Quoted 2 lines

gdb doesn't like my binary, not sure why yet

LTO patch that was merged into xfsprogs makes binary undebuggable with gdb (if it gets enabled and it is automatically in my setup).

Now back to main problem:

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff7ba7541 in __GI_abort () at abort.c:79
#2  0x00007ffff7c00458 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7ffff7d0f400 "%s\n") at ../sysdeps/posix/libc_fatal.c:181
#3  0x00007ffff7c06dea in malloc_printerr (str=str@entry=0x7ffff7d0d6ce "realloc(): invalid next size") at malloc.c:5336
#4  0x00007ffff7c0b00c in _int_realloc (av=av@entry=0x7ffff7d46c40 <main_arena>, oldp=oldp@entry=0x61930520, oldsize=oldsize@entry=96, nb=nb@entry=160) at malloc.c:4520
#5  0x00007ffff7c0c28b in __GI___libc_realloc (oldmem=0x61930530, bytes=140) at malloc.c:3214
#6  0x000000000044343a in kmem_realloc (ptr=0x61930530, new_size=140, flags=5) at kmem.c:90
#7  0x0000000000491dd7 in libxfs_idata_realloc (ip=0x50a95cd0, byte_diff=63, whichfork=0) at xfs_inode_fork.c:511
#8  0x0000000000485dc3 in xfs_dir2_sf_addname_easy (args=0x69ac0100, sfep=0x61930546, offset=44, new_isize=137) at xfs_dir2_sf.c:379
#9  0x0000000000485cff in xfs_dir2_sf_addname (args=0x69ac0100) at xfs_dir2_sf.c:339

#10 0x0000000000477705 in libxfs_dir_createname (tp=0x5b60a9d0, dp=0x50a95cd0, name=0x50ad5450, inum=31060721942, first=0x7fffffffdae8, dfops=0x7fffffffdaa0, total=45) at xfs_dir2.c:281
#11 0x0000000000427b1a in longform_dir2_rebuild (mp=0x7fffffffe180, ino=31060721895, ip=0x50a95cd0, irec=0x7fff2016f780, ino_offset=7, hashtab=0x8d9811e0) at phase6.c:1444
#12 0x000000000042a743 in longform_dir2_entry_check (mp=0x7fffffffe180, ino=31060721895, ip=0x50a95cd0, num_illegal=0x7fffffffdccc, need_dot=0x7fffffffdcd4, irec=0x7fff2016f780, ino_offset=7, hashtab=0x8d9811e0) at phase6.c:2481 #13 0x000000000042b7c7 in process_dir_inode (mp=0x7fffffffe180, agno=14, irec=0x7fff2016f780, ino_offset=7) at phase6.c:2983
#14 0x000000000042c4ff in traverse_function (wq=0x7fffffffde50, agno=14, arg=0x62c5ec20) at phase6.c:3254
#15 0x00000000004305fe in prefetch_ag_range (work=0x7fffffffde50, start_ag=0, end_ag=39, dirs_only=true, func=0x42c442 <traverse_function>) at prefetch.c:964
#16 0x000000000043077e in do_inode_prefetch (mp=0x7fffffffe180, stride=0, func=0x42c442 <traverse_function>, check_cache=false, dirs_only=true) at prefetch.c:1027
#17 0x000000000042c5d3 in traverse_ags (mp=0x7fffffffe180) at phase6.c:3284
#18 0x000000000042c88a in phase6 (mp=0x7fffffffe180) at phase6.c:3372
#19 0x000000000043ebd8 in main (argc=3, argv=0x7fffffffe688) at xfs_repair.c:949

more at

https://ixion.pld-linux.org/~arekm/xfs-1/gdb1.txt

Have coredump, so can look for more details.