[schilytools] star hangs randomly during copy from ZFS to ZFS
Lasse Kliemann
lasse at lassekliemann.de
Sat Nov 9 12:20:45 CET 2024
Nico Sonack on Thu 2024-11(Nov)-07 at 17:42 wrote:
> This is most definitely a fifo hang.
>
> The source code in star/fifo.c says:
>
> * If you ever see a hang in the fifo code, you need to report a stack
> * trace for both processes (including the line number of the hanging call
> * to swait()) and the relevant state of struct m_head.
>
> You can do this by sending a SIGABRT using kill -ABRT <pid> to the
> processes and then sliding aside the core files.
>
> Then you can throw a debugger at them,
>
> e.g. lldb -c <corefile> $(which star)
>
> and look at the stack traces.
Thanks for looking into this. I compiled from latest source in GIT
(commit e835e64f). I had to censor the file name in the first trace, it
was there in place of "PATH/TO/FILE.EXT".
==> Process 1:
((lldb) bt
* thread #1, name = 'star', stop reason = signal SIGABRT
* frame #0: 0x000000082580956a libc.so.7`__sys_read + 10
frame #1: 0x000000000024db30 star`swait(f=5, chan=3) at fifo.c:688:9
frame #2: 0x000000000024da91 star`fifo_iwait(amount=512) at fifo.c:840:3
frame #3: 0x000000000024397d star`buf_wait(amount=<unavailable>) at buffer.c:1522:6 [artificial]
frame #4: 0x0000000000235ffa star`cr_file(info=0x0000000820846078, func=(star`_fileread at create.c:421), arg=0x0000000820845a2c, amt=8396800, text="") at create.c:1367:12
frame #5: 0x0000000000235f20 star`put_file(fp=<unavailable>, info=<unavailable>) at create.c:0:6 [artificial]
frame #6: 0x000000000023496d star`createi(sname="PATH/TO/FILE.EXT", name="PATH/TO/FILE.EXT", namlen=71, info=0x0000000820846078, pathp=0x0000000820848cb8, last=0x0000000820846220) at create.c:0:4
frame #7: 0x0000000000234ff9 star`createi [inlined] put_dir(sname=<unavailable>, dname=<unavailable>, namlen=<unavailable>, info=0x00000008208468f8, ptb=0x0000000826752e00, pathp=0x0000000820848cb8, last=<unavailable>) at create.c:1748:4
frame #8: 0x000000000023499e star`createi(sname="PATH/TO/FILE.EXT", name="PATH/TO/FILE.EXT", namlen=<unavailable>, info=0x00000008208468f8, pathp=0x0000000820848cb8, last=0x0000000820846aa0) at create.c:603:4
frame #9: 0x0000000000234ff9 star`createi [inlined] put_dir(sname=<unavailable>, dname=<unavailable>, namlen=<unavailable>, info=0x0000000820847178, ptb=0x00000008265da000, pathp=0x0000000820848cb8, last=<unavailable>) at create.c:1748:4
frame #10: 0x000000000023499e star`createi(sname="PATH/TO/FILE.EXT", name="PATH/TO/FILE.EXT", namlen=<unavailable>, info=0x0000000820847178, pathp=0x0000000820848cb8, last=0x0000000820847320) at create.c:603:4
frame #11: 0x0000000000234ff9 star`createi [inlined] put_dir(sname=<unavailable>, dname=<unavailable>, namlen=<unavailable>, info=0x00000008208479f8, ptb=0x0000000826099600, pathp=0x0000000820848cb8, last=<unavailable>) at create.c:1748:4
frame #12: 0x000000000023499e star`createi(sname="PATH/TO/FILE.EXT", name="PATH/TO/FILE.EXT", namlen=<unavailable>, info=0x00000008208479f8, pathp=0x0000000820848cb8, last=0x0000000820847ba0) at create.c:603:4
frame #13: 0x0000000000234ff9 star`createi [inlined] put_dir(sname=<unavailable>, dname=<unavailable>, namlen=<unavailable>, info=0x0000000820848278, ptb=0x0000000826099000, pathp=0x0000000820848cb8, last=<unavailable>) at create.c:1748:4
frame #14: 0x000000000023499e star`createi(sname="PATH/TO/FILE.EXT", name="PATH/TO/FILE.EXT", namlen=<unavailable>, info=0x0000000820848278, pathp=0x0000000820848cb8, last=0x0000000820848420) at create.c:603:4
frame #15: 0x0000000000234ff9 star`createi [inlined] put_dir(sname=<unavailable>, dname=<unavailable>, namlen=<unavailable>, info=0x0000000820848af8, ptb=0x0000000826098a00, pathp=0x0000000820848cb8, last=<unavailable>) at create.c:1748:4
frame #16: 0x000000000023499e star`createi(sname="PATH/TO/FILE.EXT", name="PATH/TO/FILE.EXT", namlen=<unavailable>, info=0x0000000820848af8, pathp=0x0000000820848cb8, last=0x0000000820848ca0) at create.c:603:4
frame #17: 0x0000000000234ff9 star`createi [inlined] put_dir(sname=<unavailable>, dname=<unavailable>, namlen=<unavailable>, info=0x0000000820848d70, ptb=0x0000000826098000, pathp=0x0000000820848cb8, last=<unavailable>) at create.c:1748:4
frame #18: 0x000000000023499e star`createi(sname=".", name=".", namlen=<unavailable>, info=0x0000000820848d70, pathp=0x0000000000000000, last=0x0000000000000000) at create.c:603:4
frame #19: 0x0000000000234127 star`create(name=".", Hflag=<unavailable>, forceadd=0) at create.c:488:2
frame #20: 0x000000000021f5d6 star`star_create(ac=1, av=0x0000000820849688) at star_fat.c:908:4
frame #21: 0x000000000021f7f2 star`copy_create(ac=10, av=0x0000000820849640) at star_fat.c:989:2
frame #22: 0x000000000024d2ee star`runfifo(ac=11, av=0x0000000820849640) at fifo.c:467:4
frame #23: 0x000000000021bf47 star`main(ac=<unavailable>, av=<unavailable>) at star_fat.c:562:3
frame #24: 0x0000000825755a6a libc.so.7`__libc_start1 + 298
frame #25: 0x000000000021b520 star`_start at crt1_s.S:83
((lldb) p *mp
(m_head) {
putptr = 0x0000000826098000 "\xb0QB\xc7b\ba\U00000002\xfc\xe4Ý\x98\xf9\xa1¯X\xa7\xf1\xc0\x80\xf8\xbb\U0000000euz\xb7\xf2/\xf0\x83\U00000018務\xdbe\xfa>w]\xc0\x95/\U0000001b\xf55X\xd3q\t\xa1\U00000005σ\v[SXt\x85\xb5Q\x97\xc8pއ6\xa5\xb6S\U00000005\xec5\xc5܋\xe1s\xdf\xc9\xcb?\x81\U00000001\xe7|e\xbc`\xc5*\U0000000e6\xbdv\xe8~\a\xb7\U0000001e\xad̓#S\xae\U000000151\U00000012\x88 '9\xca_\U0000001f\xea\U00000017\x86\xa1\xef\xa4\xfc\x88\xaf/\xe14bf\U00000012F:sk\xfeX4\U0000001b@\x987\xb9I-\U000000129u\xad\x99\U00000006=\x896C\U0000001a\t\U00000014(\xae\xde*7\x82\x856\a\xac\xed\xa23Cgm\U00000013·\xa7\xfc\xb6+\xda"
getptr = 0x0000000826098000 "\xb0QB\xc7b\ba\U00000002\xfc\xe4Ý\x98\xf9\xa1¯X\xa7\xf1\xc0\x80\xf8\xbb\U0000000euz\xb7\xf2/\xf0\x83\U00000018務\xdbe\xfa>w]\xc0\x95/\U0000001b\xf55X\xd3q\t\xa1\U00000005σ\v[SXt\x85\xb5Q\x97\xc8pއ6\xa5\xb6S\U00000005\xec5\xc5܋\xe1s\xdf\xc9\xcb?\x81\U00000001\xe7|e\xbc`\xc5*\U0000000e6\xbdv\xe8~\a\xb7\U0000001e\xad̓#S\xae\U000000151\U00000012\x88 '9\xca_\U0000001f\xea\U00000017\x86\xa1\xef\xa4\xfc\x88\xaf/\xe14bf\U00000012F:sk\xfeX4\U0000001b@\x987\xb9I-\U000000129u\xad\x99\U00000006=\x896C\U0000001a\t\U00000014(\xae\xde*7\x82\x856\a\xac\xed\xa23Cgm\U00000013·\xa7\xfc\xb6+\xda"
base = 0x0000000826098000 "\xb0QB\xc7b\ba\U00000002\xfc\xe4Ý\x98\xf9\xa1¯X\xa7\xf1\xc0\x80\xf8\xbb\U0000000euz\xb7\xf2/\xf0\x83\U00000018務\xdbe\xfa>w]\xc0\x95/\U0000001b\xf55X\xd3q\t\xa1\U00000005σ\v[SXt\x85\xb5Q\x97\xc8pއ6\xa5\xb6S\U00000005\xec5\xc5܋\xe1s\xdf\xc9\xcb?\x81\U00000001\xe7|e\xbc`\xc5*\U0000000e6\xbdv\xe8~\a\xb7\U0000001e\xad̓#S\xae\U000000151\U00000012\x88 '9\xca_\U0000001f\xea\U00000017\x86\xa1\xef\xa4\xfc\x88\xaf/\xe14bf\U00000012F:sk\xfeX4\U0000001b@\x987\xb9I-\U000000129u\xad\x99\U00000006=\x896C\U0000001a\t\U00000014(\xae\xde*7\x82\x856\a\xac\xed\xa23Cgm\U00000013·\xa7\xfc\xb6+\xda"
end = 0x000000082689a000 "UUUUUUUUUU"
size = 8396800
ibs = 8396800
obs = 8396800
rsize = 1608
icnt = 265229721600
ocnt = 265229721600
iblocked = '\x01'
oblocked = '\x01'
mayoblock = '\0'
m1 = '\0'
m2 = '\0'
chreel = '\0'
reelwait = '\0'
eflags = '\0'
pflags = '\0'
gflags = '\0'
ferrno = 0
hiw = 5597866
low = 2798933
gp = ([0] = 3, [1] = 4)
pp = ([0] = 5, [1] = 6)
puts = 130747
gets = 130006
empty = 35592
full = 19813
maxfill = 8396800
moves = 34
mbytes = 219136
stats = {
reading = 0
swapflg = -1
hdrtype = 9
volno = 1
nblocks = 20
blocksize = 10240
lastsize = 0
eofblock = 0
blocks = 0
parts = 265229721600
Tblocks = 0
Tparts = 0
cur_size = 1453981787
cur_off = 654223872
old_size = 0
old_off = 0
}
bmap = 0x0000000000000000
bmlast = 0
ginfo = {
label = 0x0000000000000000
hostname = 0x0000000000000000
filesys = 0x0000000000000000
cwd = 0x0000000000000000
device = 0x0000000000000000
release = 0x00000008260951b8 "star 1.7.0 (amd64-unknown-freebsd14.1) 2023/01/11"
archtype = 9
dumptype = 0
dumplevel = 0
reflevel = 0
dumpdate = (tv_sec = 1731146591, tv_nsec = 832151168)
refdate = (tv_sec = 0, tv_nsec = 0)
volno = 1
tapesize = 0
blockoff = 0
blocksize = 20
gflags = 805327968
}
}
==> Process 2:
((lldb) bt
* thread #1, name = 'star', stop reason = signal SIGABRT
* frame #0: 0x000000082580956a libc.so.7`__sys_read + 10
frame #1: 0x000000000024db30 star`swait(f=3, chan=5) at fifo.c:688:9
frame #2: 0x000000000024de9b star`fifo_owait(amount=512) at fifo.c:1019:8
frame #3: 0x00000000002435c8 star`buf_rwait(amount=512) at buffer.c:1574:9
frame #4: 0x0000000000233082 star`xt_file(info=0x0000000820849168, func=(star`symbol stub for: ffilewrite), arg=0x00000008258bbc80, amt=8396800, text="") at extract.c:2119:13
frame #5: 0x00000000002324f2 star`get_file [inlined] get_ofile(f=0x00000008258bbc80, info=0x0000000820849168) at extract.c:1984:9
frame #6: 0x0000000000232472 star`get_file(info=0x0000000820849168) at extract.c:1938:7
frame #7: 0x0000000000231757 star`extracti(info=0x0000000820849168, imp=0x0000000000000000) at extract.c:0
frame #8: 0x0000000000230e8e star`extract(vhname=0x0000000000000000) at extract.c:322:7
frame #9: 0x000000000021c127 star`main(ac=<unavailable>, av=<unavailable>) at star_fat.c:615:5
frame #10: 0x0000000825755a6a libc.so.7`__libc_start1 + 298
frame #11: 0x000000000021b520 star`_start at crt1_s.S:83
((lldb) p *mp
(m_head) {
putptr = 0x0000000826098000 "\xb0QB\xc7b\ba\U00000002\xfc\xe4Ý\x98\xf9\xa1¯X\xa7\xf1\xc0\x80\xf8\xbb\U0000000euz\xb7\xf2/\xf0\x83\U00000018務\xdbe\xfa>w]\xc0\x95/\U0000001b\xf55X\xd3q\t\xa1\U00000005σ\v[SXt\x85\xb5Q\x97\xc8pއ6\xa5\xb6S\U00000005\xec5\xc5܋\xe1s\xdf\xc9\xcb?\x81\U00000001\xe7|e\xbc`\xc5*\U0000000e6\xbdv\xe8~\a\xb7\U0000001e\xad̓#S\xae\U000000151\U00000012\x88 '9\xca_\U0000001f\xea\U00000017\x86\xa1\xef\xa4\xfc\x88\xaf/\xe14bf\U00000012F:sk\xfeX4\U0000001b@\x987\xb9I-\U000000129u\xad\x99\U00000006=\x896C\U0000001a\t\U00000014(\xae\xde*7\x82\x856\a\xac\xed\xa23Cgm\U00000013·\xa7\xfc\xb6+\xda"
getptr = 0x0000000826098000 "\xb0QB\xc7b\ba\U00000002\xfc\xe4Ý\x98\xf9\xa1¯X\xa7\xf1\xc0\x80\xf8\xbb\U0000000euz\xb7\xf2/\xf0\x83\U00000018務\xdbe\xfa>w]\xc0\x95/\U0000001b\xf55X\xd3q\t\xa1\U00000005σ\v[SXt\x85\xb5Q\x97\xc8pއ6\xa5\xb6S\U00000005\xec5\xc5܋\xe1s\xdf\xc9\xcb?\x81\U00000001\xe7|e\xbc`\xc5*\U0000000e6\xbdv\xe8~\a\xb7\U0000001e\xad̓#S\xae\U000000151\U00000012\x88 '9\xca_\U0000001f\xea\U00000017\x86\xa1\xef\xa4\xfc\x88\xaf/\xe14bf\U00000012F:sk\xfeX4\U0000001b@\x987\xb9I-\U000000129u\xad\x99\U00000006=\x896C\U0000001a\t\U00000014(\xae\xde*7\x82\x856\a\xac\xed\xa23Cgm\U00000013·\xa7\xfc\xb6+\xda"
base = 0x0000000826098000 "\xb0QB\xc7b\ba\U00000002\xfc\xe4Ý\x98\xf9\xa1¯X\xa7\xf1\xc0\x80\xf8\xbb\U0000000euz\xb7\xf2/\xf0\x83\U00000018務\xdbe\xfa>w]\xc0\x95/\U0000001b\xf55X\xd3q\t\xa1\U00000005σ\v[SXt\x85\xb5Q\x97\xc8pއ6\xa5\xb6S\U00000005\xec5\xc5܋\xe1s\xdf\xc9\xcb?\x81\U00000001\xe7|e\xbc`\xc5*\U0000000e6\xbdv\xe8~\a\xb7\U0000001e\xad̓#S\xae\U000000151\U00000012\x88 '9\xca_\U0000001f\xea\U00000017\x86\xa1\xef\xa4\xfc\x88\xaf/\xe14bf\U00000012F:sk\xfeX4\U0000001b@\x987\xb9I-\U000000129u\xad\x99\U00000006=\x896C\U0000001a\t\U00000014(\xae\xde*7\x82\x856\a\xac\xed\xa23Cgm\U00000013·\xa7\xfc\xb6+\xda"
end = 0x000000082689a000 "UUUUUUUUUU"
size = 8396800
ibs = 8396800
obs = 8396800
rsize = 1608
icnt = 265229721600
ocnt = 265229721600
iblocked = '\x01'
oblocked = '\x01'
mayoblock = '\0'
m1 = '\0'
m2 = '\0'
chreel = '\0'
reelwait = '\0'
eflags = '\0'
pflags = '\0'
gflags = '\0'
ferrno = 0
hiw = 5597866
low = 2798933
gp = ([0] = 3, [1] = 4)
pp = ([0] = 5, [1] = 6)
puts = 130747
gets = 130006
empty = 35592
full = 19813
maxfill = 8396800
moves = 34
mbytes = 219136
stats = {
reading = 0
swapflg = -1
hdrtype = 9
volno = 1
nblocks = 20
blocksize = 10240
lastsize = 0
eofblock = 0
blocks = 0
parts = 265229721600
Tblocks = 0
Tparts = 0
cur_size = 1453981787
cur_off = 654223872
old_size = 0
old_off = 0
}
bmap = 0x0000000000000000
bmlast = 0
ginfo = {
label = 0x0000000000000000
hostname = 0x0000000000000000
filesys = 0x0000000000000000
cwd = 0x0000000000000000
device = 0x0000000000000000
release = 0x00000008260951b8 "star 1.7.0 (amd64-unknown-freebsd14.1) 2023/01/11"
archtype = 9
dumptype = 0
dumplevel = 0
reflevel = 0
dumpdate = (tv_sec = 1731146591, tv_nsec = 832151168)
refdate = (tv_sec = 0, tv_nsec = 0)
volno = 1
tapesize = 0
blockoff = 0
blocksize = 20
gflags = 805327968
}
}
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 259 bytes
Desc: not available
URL: <https://mlists.in-berlin.de/pipermail/schilytools-mlists.in-berlin.de/attachments/20241109/6f796286/attachment.sig>
More information about the schilytools
mailing list