Date: Sun, 21 Jul 2013 17:38:49 GMT From: Petar Bogdanovic <petar@smokva.net> To: freebsd-gnats-submit@FreeBSD.org Subject: kern/180724: occasional file corruption when using cp(1) Message-ID: <201307211738.r6LHcnKY071830@oldred.freebsd.org> Resent-Message-ID: <201307211740.r6LHe0Af008442@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
>Number: 180724
>Category: kern
>Synopsis: occasional file corruption when using cp(1)
>Confidential: no
>Severity: non-critical
>Priority: low
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Sun Jul 21 17:40:00 UTC 2013
>Closed-Date:
>Last-Modified:
>Originator: Petar Bogdanovic
>Release: 10.0-CURRENT (Jul 13/14)
>Organization:
>Environment:
FreeBSD pipit 10.0-CURRENT FreeBSD 10.0-CURRENT #0: Sat Jul 13 23:58:56 UTC 2013
root@snap.freebsd.org:/usr/obj/usr/src/sys/GENERIC i386
>Description:
After upgrading an old 8.1-RC2 release to 10-CURRENT in a VirtualBox VM,
strip(1) failed to strip libpkg.so.1 during installation of ports-mgmt/pkg:
----
strip: /usr/local/lib/libpkg.so.1: File format not recognized
----
the source file seemed ok:
----
# file /usr/ports/ports-mgmt/pkg/work/pkg-1.1.4/libpkg/libpkg.so.1
(...)/libpkg.so.1: ELF 32-bit LSB shared object, Intel 80386, version 1 (FreeBSD), dynamically linked, not stripped
----
but not when copied:
----
# cp /usr/ports/ports-mgmt/pkg/work/pkg-1.1.4/libpkg/libpkg.so.1 /tmp
# file /tmp/libpkg.so.1
/tmp/libpkg.so.1: data
----
When running cp through truss, a successful copy happend at least once
but it was not easy to reproduce.
Around the same time, this appeared in messages:
----
Jul 21 21:05:13 kernel: Trying to mount root from ufs:/dev/ada2s1a [rw]...
Jul 21 21:10:40 kernel: lock order reversal:
Jul 21 21:10:40 kernel: 1st 0xe12fd158 bufwait (bufwait) @ /usr/src/sys/kern/vfs_bio.c:3061
Jul 21 21:10:40 kernel: 2nd 0xc7025200 dirhash (dirhash) @ /usr/src/sys/ufs/ufs/ufs_dirhash.c:284
Jul 21 21:10:40 kernel: KDB: stack backtrace:
Jul 21 21:10:40 kernel: db_trace_self_wrapper(c116d81c,e12fd158,4,c117793e,3ea,...) at db_trace_self_wrapper+0x2d/frame 0xf006e950
Jul 21 21:10:40 kernel: kdb_backtrace(c117136b,c7025200,c11a31fe,c6184f90,c11a2e49,...) at kdb_backtrace+0x30/frame 0xf006e9b4
Jul 21 21:10:40 kernel: witness_checkorder(c7025200,9,c11a2e49,11c,0,...) at witness_checkorder+0xccc/frame 0xf006ea04
Jul 21 21:10:40 kernel: _sx_xlock(c7025200,0,c11a2e49,11c,e12fd100,...) at _sx_xlock+0x77/frame 0xf006ea34
Jul 21 21:10:40 kernel: ufsdirhash_remove(c79fa0e8,e3890018,18,f006ea88,f006ea84,...) at ufsdirhash_remove+0x37/frame 0xf006ea5c
Jul 21 21:10:40 kernel: ufs_dirremove(c79fb238,c79fa414,400800c,0,8,...) at ufs_dirremove+0x123/frame 0xf006ea98
Jul 21 21:10:40 kernel: ufs_remove(f006ec00,a87,c79fb238,f006ebfc,c6791930,...) at ufs_remove+0x71/frame 0xf006eadc
Jul 21 21:10:40 kernel: VOP_REMOVE_APV(c129f5b8,f006ec00,c79fb9fc,f006ebd4,c1bc2d00,...) at VOP_REMOVE_APV+0xfd/frame 0xf006eb08
Jul 21 21:10:40 kernel: kern_unlinkat(c6791930,ffffff9c,2881ea38,0,0) at kern_unlinkat+0x27a/frame 0xf006ec24
Jul 21 21:10:40 kernel: sys_unlink(c6791930,f006ecc8,c11c3586,d6,7b3,...) at sys_unlink+0x32/frame 0xf006ec40
Jul 21 21:10:40 kernel: syscall(f006ed08) at syscall+0x2de/frame 0xf006ecfc
Jul 21 21:10:40 kernel: Xint0x80_syscall() at Xint0x80_syscall+0x21/frame 0xf006ecfc
Jul 21 21:10:40 kernel: --- syscall (10, FreeBSD ELF32, sys_unlink), eip = 0x28174e07, esp = 0xbfbfd84c, ebp = 0xbfbfd8e4 ---
----
And just in case, truss cp /usr/ports/(...)/libpkg.so.1 /tmp/test/foobar.so:
----
mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 671494144 (0x28063000)
issetugid(0x28062500,0xbfbfefc8,0x20,0x0,0x0,0x0) = 0 (0x0)
lstat("/etc",{ mode=drwxr-xr-x ,inode=2001920,size=2048,blksize=16384 }) = 0 (0x0)
lstat("/etc/libmap.conf",0xbfbfc670) ERR#2 'No such file or directory'
open("/var/run/ld-elf.so.hints",O_CLOEXEC,00) = 3 (0x3)
read(3,"Ehnt\^A\0\0\0\M^@\0\0\0\^^\0\0\0"...,128) = 128 (0x80)
lseek(3,0x80,SEEK_SET) = 128 (0x80)
read(3,"/lib:/usr/lib:/usr/lib/compat\0",30) = 30 (0x1e)
close(3) = 0 (0x0)
access("/lib/libc.so.7",0) = 0 (0x0)
open("/lib/libc.so.7",O_CLOEXEC,027757746570) = 3 (0x3)
fstat(3,{ mode=-r--r--r-- ,inode=1083438,size=1332088,blksize=16384 }) = 0 (0x0)
mmap(0x0,4096,PROT_READ,MAP_PRIVATE|0x40000,3,0x0) = 671526912 (0x2806b000)
mmap(0x0,1363968,PROT_NONE,MAP_PRIVATE|MAP_ANON|MAP_NOCORE,-1,0x0) = 671531008 (0x2806c000)
mmap(0x2806c000,1253376,PROT_READ|PROT_EXEC,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE|0x40000,3,0x0) = 671531008 (0x2806c000)
mmap(0x2819e000,28672,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|0x40000,3,0x131000) = 672784384 (0x2819e000)
mmap(0x281a5000,81920,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_ANON,-1,0x0) = 672813056 (0x281a5000)
munmap(0x2806b000,4096) = 0 (0x0)
close(3) = 0 (0x0)
mmap(0x0,36864,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 672894976 (0x281b9000)
munmap(0x281bb000,28672) = 0 (0x0)
mmap(0x0,69632,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 672903168 (0x281bb000)
sysarch(0xa,0xbfbfd374,0x280653d8,0x280622b4,0xbfbfd398,0x2804d7b3) = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
readlink("/etc/malloc.conf",0xbfbfcb0f,1024) ERR#2 'No such file or directory'
issetugid(0x28194e6b,0xbfbfcb0f,0x400,0x0,0x0,0x6d62696c) = 0 (0x0)
mmap(0x0,4194304,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 672972800 (0x281cc000)
munmap(0x281cc000,4194304) = 0 (0x0)
mmap(0x0,8384512,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 672972800 (0x281cc000)
munmap(0x281cc000,2310144) = 0 (0x0)
munmap(0x28800000,1880064) = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
sigaction(SIGINFO,{ 0x8049ee0 SA_RESTART ss_t },{ SIG_DFL 0x0 ss_t }) = 0 (0x0)
stat("/tmp/test/foobar.so",{ mode=-rwxr-xr-x ,inode=95129,size=1118522,blksize=16384 }) = 0 (0x0)
umask(0x1ff,0xbfbfdbf0,0x400,0x28066200,0x0,0x7) = 18 (0x12)
umask(0x12,0xbfbfdbf0,0x400,0x28066200,0x0,0x7) = 511 (0x1ff)
mmap(0x0,4194304,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 679477248 (0x28800000)
stat("/usr/ports/ports-mgmt/pkg/work/pkg-1.1.4/libpkg/libpkg.so.1",{ mode=-rwxr-xr-x ,inode=1444593,size=1118522,blksize=16384 }) = 0 (0x0)
stat("/tmp/test/foobar.so",{ mode=-rwxr-xr-x ,inode=95129,size=1118522,blksize=16384 }) = 0 (0x0)
open("/usr/ports/ports-mgmt/pkg/work/pkg-1.1.4/libpkg/libpkg.so.1",O_RDONLY,00) = 3 (0x3)
open("/tmp/test/foobar.so",O_WRONLY|O_TRUNC,00) = 4 (0x4)
mmap(0x0,1118522,PROT_READ,MAP_SHARED,3,0x0) = 672972800 (0x281cc000)
write(4,"\^?ELF\^A\^A\^A\t\0\0\0\0\0\0\0"...,1118522) = 1118522 (0x11113a)
munmap(0x281cc000,1118522) = 0 (0x0)
close(4) = 0 (0x0)
close(3) = 0 (0x0)
madvise(0x2880b000,0x1000,0x5,0x281a107c,0xbfbfd9ac,0x280f18a7) = 0 (0x0)
madvise(0x2881b000,0x1000,0x5,0x281a107c,0xbfbfd9ac,0x280f18a7) = 0 (0x0)
madvise(0x2881e000,0x1000,0x5,0x281a107c,0xbfbfd9ac,0x280f18a7) = 0 (0x0)
madvise(0x28803000,0x1000,0x5,0x281a107c,0xbfbfd9ac,0x280f18a7) = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
process exit, rval = 0
----
This VM has been running 8.1-RC2 for years and there was no change in
environment in the mean time.
Thanks,
Petar Bogdanovic
>How-To-Repeat:
see above
>Fix:
none
>Release-Note:
>Audit-Trail:
>Unformatted:
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201307211738.r6LHcnKY071830>