GNU bug report logs - #36007
double close() of of=file if receiving SIGINT during fdatasync()

Previous Next

Package: coreutils;

Reported by: Hans Henrik Bergan <divinity76 <at> gmail.com>

Date: Thu, 30 May 2019 16:03:02 UTC

Severity: normal

Done: Paul Eggert <eggert <at> cs.ucla.edu>

Bug is archived. No further changes may be made.

Full log

View this message in rfc822 format

From: Hans Henrik Bergan <divinity76 <at> gmail.com>
To: 36007 <at> debbugs.gnu.org
Subject: bug#36007: double close() of of=file if receiving SIGINT during fdatasync()
Date: Thu, 30 May 2019 17:38:16 +0200

[Message part 1 (text/plain, inline)]
i think there is a double-close() bug that causes dd to try to close input
file twice if it receives a SIGINT during fdatasync(),

it seems easy to reproduce on a slow block device (the issue was noticed on
a 5400RPM harddrive), but i have not been able to reproduce it on a SSD
(likely because fdatasync() finishes too fast, i didn't try very hard.
like, i suppose i could have hooked fdatasync and made it slow on purpose,
but i didn't spend that much time/energy on trying),

anyway, the bug seems to boil down to somehow cleanup() is being called
twice

command issued:

time strace dd if=/dev/zero of=/dev/sda4 bs=10M count=10 iflag=fullblock
conv=fdatasync >stdout 2>stderr

dd version:
root <at> 1:/dev# dd --version
dd (coreutils) 8.30
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <
https://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.

Written by Paul Rubin, David MacKenzie, and Stuart Kemp.


script log (corrupted when pasted, strictly speaking, but i don't think
anything of value was lost. if you want an actual 100% intact log, i can
send you a base64 copy if you want, but again i don't think anything of
value was lost)

Script started on 2019-05-30 09:39:45-04:00 [TERM="xterm" TTY="/dev/pts/1"
COLUMNS="194" LINES="41"]
root <at> 1:/dev# exit pastebinit foo.log
[C [C [C [C [C [C [C [C [C [C [C [C [C [5Pscript foo.log [3Prm foo.log
[2 <at> nano [C [C [C [C [C [C [C [C [C [1Pcat [C [C [C [C [C [C [C [C [C script
foo.log ls [K cat stderr out time strace dd if=/dev/zero of=/dev/sda4
bs=10M count=10 iflag=fullblock conv=fdatasync >stdout 2>stderr
execve("/usr/bin/dd", ["dd", "if=/dev/zero", "of=/dev/sda4", "bs=10M",
"count=10", "iflag=fullblock", "conv=fdatasync"], 0x7fffffffe690 /* 18 vars
*/) = 0
brk(NULL)                               = 0x555555568000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or
directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=20223, ...}) = 0
mmap(NULL, 20223, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7ffff7fcb000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3,
"\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260A\2\0\0\0\0\0"..., 832)
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1824496, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7ffff7fc9000
mmap(NULL, 1837056, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7ffff7e08000
mprotect(0x7ffff7e2a000, 1658880, PROT_NONE) = 0
mmap(0x7ffff7e2a000, 1343488, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7ffff7e2a000
mmap(0x7ffff7f72000, 311296, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16a000) = 0x7ffff7f72000
mmap(0x7ffff7fbf000, 24576, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7ffff7fbf000
mmap(0x7ffff7fc5000, 14336, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7ffff7fc5000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7ffff7fca580) = 0
mprotect(0x7ffff7fbf000, 16384, PROT_READ) = 0
mprotect(0x555555566000, 4096, PROT_READ) = 0
mprotect(0x7ffff7ffc000, 4096, PROT_READ) = 0
munmap(0x7ffff7fcb000, 20223)           = 0
rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8)
= 0
rt_sigaction(SIGUSR1, {sa_handler=0x555555558430, sa_mask=[INT USR1],
sa_flags=SA_RESTORER, sa_restorer=0x7ffff7e3f840}, NULL, 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x555555558420, sa_mask=[INT USR1],
sa_flags=SA_RESTORER|SA_NODEFER|SA_RESETHAND, sa_restorer=0x7ffff7e3f840},
NULL, 8) = 0
brk(NULL)                               = 0x555555568000
brk(0x555555589000)                     = 0x555555589000
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=3031616, ...}) = 0
mmap(NULL, 3031616, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7ffff7b23000
close(3)                                = 0
openat(AT_FDCWD, "/dev/zero", O_RDONLY) = 3
dup2(3, 0)                              = 0
close(3)                                = 0
lseek(0, 0, SEEK_CUR)                   = 0
openat(AT_FDCWD, "/dev/sda4", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
dup2(3, 1)                              = 1
close(3)                                = 0
mmap(NULL, 10498048, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x7ffff7120000
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
read(0,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
write(1,
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
10485760) = 10485760
fdatasync(1)                            = 0
--- SIGINT {si_signo=SIGINT, si_code=SI_USER, si_pid=1399, si_uid=0} ---
rt_sigreturn({mask=[]})                 = 0
close(0)                                = 0
close(1)                                = 0
openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 0
fstat(0, {st_mode=S_IFREG|0644, st_size=2995, ...}) = 0
read(0, "# Locale name alias data base.\n#"..., 4096) = 2995
read(0, "", 4096)                       = 0
close(0)                                = 0
openat(AT_FDCWD, "/usr/share/locale/en_CA/LC_MESSAGES/coreutils.mo",
O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en/LC_MESSAGES/coreutils.mo", O_RDONLY)
= -1 ENOENT (No such file or directory)
write(2, "10+0 records in\n10+0 records out"..., 3310+0 records in
10+0 records out
) = 33
write(2, "104857600 bytes (105 MB, 100 MiB"..., 62104857600 bytes (105 MB,
100 MiB) copied, 1.94798 s, 53.8 MB/s) = 62
write(2, "\n", 1
)                       = 1
rt_sigprocmask(SIG_BLOCK, [INT USR1], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
close(0)                                = -1 EBADF (Bad file descriptor)
write(2, "dd: ", 4dd: )                     = 4
write(2, "closing input file '/dev/zero'", 30closing input file
'/dev/zero') = 30
openat(AT_FDCWD, "/usr/share/locale/en_CA/LC_MESSAGES/libc.mo", O_RDONLY) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en/LC_MESSAGES/libc.mo", O_RDONLY) = -1
ENOENT (No such file or directory)
write(2, ": Bad file descriptor", 21: Bad file descriptor)   = 21
write(2, "\n", 1
)                       = 1
close(2)                                = 0
exit_group(1)                           = ?
+++ exited with 1 +++

real 0m1.955s
user 0m0.001s
sys 0m0.201s
root <at> 1:/dev# exit
exit

Script done on 2019-05-30 09:40:05-04:00 [COMMAND_EXIT_CODE="1"]

[Message part 2 (text/html, inline)]
This bug report was last modified 5 years and 360 days ago.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.