i386/159971: panic with soft updates journaling during load testing

Kirk Russell kirk at ba23.org
Sun Aug 21 13:10:05 UTC 2011


>Number:         159971
>Category:       i386
>Synopsis:       panic with soft updates journaling during load testing
>Confidential:   no
>Severity:       non-critical
>Priority:       low
>Responsible:    freebsd-i386
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Sun Aug 21 13:10:04 UTC 2011
>Closed-Date:
>Last-Modified:
>Originator:     Kirk Russell
>Release:        FreeBSD 9.0-BETA1
>Organization:
bstg
>Environment:
FreeBSD kleenex 9.0-BETA1 FreeBSD 9.0-BETA1 #0: Fri Aug 12 21:31:10 IST 2011     root at kleenex:/usr/obj/usr/src/sys/GENERIC  i386
>Description:
I have been testing a scratch filesystem, with soft updates journaling enabled.
I have been seeing one of these two panics:
    panic: ino 0xc5d0f600(0x3C8209) 14147, 7047 != 14098
and
    panic: Bad link elm 0xc4d7cd00 prev->next != elm
If I disable soft updates journaling, I do not see these panics.

Here is the source to the load test:
http://www.ba23.org/bstgbugs/bstg0003.c

Here is the output from /var/crash/core.txt:
http://www.ba23.org/bstgbugs/bstg0003.core.txt.gz

panic: ino 0xc5835000(0x3C8209) 1847043, 2320643 != 1420808

(kgdb) #0  doadump (textdump=0) at pcpu.h:244
#1  0xc04e4683 in db_dump (dummy=-1063023718, dummy2=0, dummy3=-1, 
    dummy4=0xed6de6f8 "") at /usr/src/sys/ddb/db_command.c:537
#2  0xc04e3da1 in db_command (last_cmdp=0xc104fc7c, cmd_table=0x0, dopager=1)
    at /usr/src/sys/ddb/db_command.c:448
#3  0xc04e3efa in db_command_loop () at /usr/src/sys/ddb/db_command.c:501
#4  0xc04e5eed in db_trap (type=3, code=0) at /usr/src/sys/ddb/db_main.c:229
#5  0xc0a38d63 in kdb_trap (type=3, code=0, tf=0xed6de8a8)
    at /usr/src/sys/kern/subr_kdb.c:539
#6  0xc0d347bb in trap (frame=0xed6de8a8) at /usr/src/sys/i386/i386/trap.c:719
#7  0xc0d1d69c in calltrap () at /usr/src/sys/i386/i386/exception.s:168
#8  0xc0a38b9a in kdb_enter (why=0xc0eefcd5 "panic", msg=0xc0eefcd5 "panic")
    at cpufunc.h:71
#9  0xc0a04274 in panic (fmt=0xc0f24586 "ino %p(0x%X) %d, %d != %d")
    at /usr/src/sys/kern/kern_shutdown.c:587
#10 0xc0c35964 in softdep_disk_io_initiation (bp=0xc499e89c)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:9818
#11 0xc0c3d9af in ffs_geom_strategy (bo=0xc5493e7c, bp=0xc499e89c)
    at buf.h:405
#12 0xc0a85e79 in bufwrite (bp=0xc499e89c) at buf.h:398
#13 0xc0c3cfc0 in ffs_bufwrite (bp=0xc499e89c)
    at /usr/src/sys/ufs/ffs/ffs_vfsops.c:2074
#14 0xc0c1b23c in ffs_update (vp=0xc5820220, waitfor=2) at buf.h:386
#15 0xc0c44113 in ffs_syncvnode (vp=0xc5820220, waitfor=2)
    at /usr/src/sys/ufs/ffs/ffs_vnops.c:304
#16 0xc0c3e11f in ffs_sync (mp=0xc5230a20, waitfor=2)
    at /usr/src/sys/ufs/ffs/ffs_vfsops.c:1498
#17 0xc0aa56f0 in sync (td=0xc55082e0, uap=0xed6decec)
    at /usr/src/sys/kern/vfs_syscalls.c:149
#18 0xc0a47663 in syscallenter (td=0xc55082e0, sa=0xed6dece4)
    at /usr/src/sys/kern/subr_trap.c:344
#19 0xc0d34064 in syscall (frame=0xed6ded28)
    at /usr/src/sys/i386/i386/trap.c:1082
#20 0xc0d1d701 in Xint0x80_syscall ()
    at /usr/src/sys/i386/i386/exception.s:266
#21 0x00000033 in ?? ()

>How-To-Repeat:
- as root -- setup the filesystem with soft updates journaling
# newfs -j /dev/ada0p4
/dev/ada0p4: 56320.0MB (115343360 sectors) block size 32768, fragment size 4096
        using 77 cylinder groups of 740.00MB, 23680 blks, 47360 inodes.
        with soft updates
super-block backups (for fsck -b #) at:
 192, 1515712, 3031232, 4546752, 6062272, 7577792, 9093312, 10608832, 12124352,
 13639872, 15155392, 16670912, 18186432, 19701952, 21217472, 22732992,
 24248512, 25764032, 27279552, 28795072, 30310592, 31826112, 33341632,
 34857152, 36372672, 37888192, 39403712, 40919232, 42434752, 43950272,
 45465792, 46981312, 48496832, 50012352, 51527872, 53043392, 54558912,
 56074432, 57589952, 59105472, 60620992, 62136512, 63652032, 65167552,
 66683072, 68198592, 69714112, 71229632, 72745152, 74260672, 75776192,
 77291712, 78807232, 80322752, 81838272, 83353792, 84869312, 86384832,
 87900352, 89415872, 90931392, 92446912, 93962432, 95477952, 96993472,
 98508992, 100024512, 101540032, 103055552, 104571072, 106086592, 107602112,
 109117632, 110633152, 112148672, 113664192, 115179712
Using inode 4 in cg 0 for 33554432 byte journal
newfs: soft updates journaling set
# mount /dev/ada0p4 /mnt
# chmod -R a+wrx /mnt
chmod: /mnt/.sujournal: Operation not permitted

- as a regular user, compile and run the load test
$ cat bstg0003.c
/*
 * Copyright 2011 Kirk J. Russell
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *     http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

#include <unistd.h>
#include <assert.h>
#include <fcntl.h>
#include <signal.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/stat.h>
#include <sys/uio.h>
#include <sys/wait.h>

static char * bstg_pathstore[] = {
    "/mnt/111/z",
    "/mnt/111/aaaa",
    "/mnt/111/bbbbb",
    "/mnt/111/ccccc",
    "/mnt/111/d",
    "/mnt/111/e",
    "/mnt/111/ffffff.fff.f",
    "/mnt/111/gggggggggggg",
    "/mnt/111/hhhh",
    "/mnt/111/iiiii.ii",
    "/mnt/111/jjjj.jj.jjjjjjjj",
    "/mnt/111/kkkk.kkkkkkkk",
    "/mnt/111/lllll",
    "/mnt/222/z",
    "/mnt/222/aaaa",
    "/mnt/222/bbbbb",
    "/mnt/222/ccccc",
    "/mnt/222/d",
    "/mnt/222/e",
    "/mnt/222/ffffff.fff.f",
    "/mnt/222/gggggggggggg",
    "/mnt/222/hhhh",
    "/mnt/222/iiiii.ii",
    "/mnt/222/jjjj.jj.jjjjjjjj",
    "/mnt/222/kkkk.kkkkkkkk",
    "/mnt/222/lllll",
    "/mnt/333/z",
    "/mnt/333/aaaa",
    "/mnt/333/bbbbb",
    "/mnt/333/ccccc",
    "/mnt/333/d",
    "/mnt/333/e",
    "/mnt/333/ffffff.fff.f",
    "/mnt/333/gggggggggggg",
    "/mnt/333/hhhh",
    "/mnt/333/iiiii.ii",
    "/mnt/333/jjjj.jj.jjjjjjjj",
    "/mnt/333/kkkk.kkkkkkkk",
    "/mnt/333/lllll",
    "/mnt/444/z",
    "/mnt/444/aaaa",
    "/mnt/444/bbbbb",
    "/mnt/444/ccccc",
    "/mnt/444/d",
    "/mnt/444/e",
    "/mnt/444/ffffff.fff.f",
    "/mnt/444/gggggggggggg",
    "/mnt/444/hhhh",
    "/mnt/444/iiiii.ii",
    "/mnt/444/jjjj.jj.jjjjjjjj",
    "/mnt/444/kkkk.kkkkkkkk",
    "/mnt/444/lllll",
    "/mnt/555/z",
    "/mnt/555/aaaa",
    "/mnt/555/bbbbb",
    "/mnt/555/ccccc",
    "/mnt/555/d",
    "/mnt/555/e",
    "/mnt/555/ffffff.fff.f",
    "/mnt/555/gggggggggggg",
    "/mnt/555/hhhh",
    "/mnt/555/iiiii.ii",
    "/mnt/555/jjjj.jj.jjjjjjjj",
    "/mnt/555/kkkk.kkkkkkkk",
    "/mnt/555/lllll",
    "/mnt/666/z",
    "/mnt/666/aaaa",
    "/mnt/666/bbbbb",
    "/mnt/666/ccccc",
    "/mnt/666/d",
    "/mnt/666/e",
    "/mnt/666/ffffff.fff.f",
    "/mnt/666/gggggggggggg",
    "/mnt/666/hhhh",
    "/mnt/666/iiiii.ii",
    "/mnt/666/jjjj.jj.jjjjjjjj",
    "/mnt/666/kkkk.kkkkkkkk",
    "/mnt/666/lllll",
    "/mnt/777/z",
    "/mnt/777/aaaa",
    "/mnt/777/bbbbb",
    "/mnt/777/ccccc",
    "/mnt/777/d",
    "/mnt/777/e",
    "/mnt/777/ffffff.fff.f",
    "/mnt/777/gggggggggggg",
    "/mnt/777/hhhh",
    "/mnt/777/iiiii.ii",
    "/mnt/777/jjjj.jj.jjjjjjjj",
    "/mnt/777/kkkk.kkkkkkkk",
    "/mnt/777/lllll",
    "/mnt/888/z",
    "/mnt/888/aaaa",
    "/mnt/888/bbbbb",
    "/mnt/888/ccccc",
    "/mnt/888/d",
    "/mnt/888/e",
    "/mnt/888/ffffff.fff.f",
    "/mnt/888/gggggggggggg",
    "/mnt/888/hhhh",
    "/mnt/888/iiiii.ii",
    "/mnt/888/jjjj.jj.jjjjjjjj",
    "/mnt/888/kkkk.kkkkkkkk",
    "/mnt/888/lllll",
    "/mnt/999/z",
    "/mnt/999/aaaa",
    "/mnt/999/bbbbb",
    "/mnt/999/ccccc",
    "/mnt/999/d",
    "/mnt/999/e",
    "/mnt/999/ffffff.fff.f",
    "/mnt/999/gggggggggggg",
    "/mnt/999/hhhh",
    "/mnt/999/iiiii.ii",
    "/mnt/999/jjjj.jj.jjjjjjjj",
    "/mnt/999/kkkk.kkkkkkkk",
    "/mnt/999/lllll",
    "/mnt/aaa/z",
    "/mnt/aaa/aaaa",
    "/mnt/aaa/bbbbb",
    "/mnt/aaa/ccccc",
    "/mnt/aaa/d",
    "/mnt/aaa/e",
    "/mnt/aaa/ffffff.fff.f",
    "/mnt/aaa/gggggggggggg",
    "/mnt/aaa/hhhh",
    "/mnt/aaa/iiiii.ii",
    "/mnt/aaa/jjjj.jj.jjjjjjjj",
    "/mnt/aaa/kkkk.kkkkkkkk",
    "/mnt/aaa/lllll",
    "/mnt/bbb/z",
    "/mnt/bbb/aaaa",
    "/mnt/bbb/bbbbb",
    "/mnt/bbb/ccccc",
    "/mnt/bbb/d",
    "/mnt/bbb/e",
    "/mnt/bbb/ffffff.fff.f",
    "/mnt/bbb/gggggggggggg",
    "/mnt/bbb/hhhh",
    "/mnt/bbb/iiiii.ii",
    "/mnt/bbb/jjjj.jj.jjjjjjjj",
    "/mnt/bbb/kkkk.kkkkkkkk",
    "/mnt/bbb/lllll",
    "/mnt/ccc/z",
    "/mnt/ccc/aaaa",
    "/mnt/ccc/bbbbb",
    "/mnt/ccc/ccccc",
    "/mnt/ccc/d",
    "/mnt/ccc/e",
    "/mnt/ccc/ffffff.fff.f",
    "/mnt/ccc/gggggggggggg",
    "/mnt/ccc/hhhh",
    "/mnt/ccc/iiiii.ii",
    "/mnt/ccc/jjjj.jj.jjjjjjjj",
    "/mnt/ccc/kkkk.kkkkkkkk",
    "/mnt/ccc/lllll",
    "/mnt/ddd/z",
    "/mnt/ddd/aaaa",
    "/mnt/ddd/bbbbb",
    "/mnt/ddd/ccccc",
    "/mnt/ddd/d",
    "/mnt/ddd/e",
    "/mnt/ddd/ffffff.fff.f",
    "/mnt/ddd/gggggggggggg",
    "/mnt/ddd/hhhh",
    "/mnt/ddd/iiiii.ii",
    "/mnt/ddd/jjjj.jj.jjjjjjjj",
    "/mnt/ddd/kkkk.kkkkkkkk",
    "/mnt/ddd/lllll",
    "/mnt/eee/z",
    "/mnt/eee/aaaa",
    "/mnt/eee/bbbbb",
    "/mnt/eee/ccccc",
    "/mnt/eee/d",
    "/mnt/eee/e",
    "/mnt/eee/ffffff.fff.f",
    "/mnt/eee/gggggggggggg",
    "/mnt/eee/hhhh",
    "/mnt/eee/iiiii.ii",
    "/mnt/eee/jjjj.jj.jjjjjjjj",
    "/mnt/eee/kkkk.kkkkkkkk",
    "/mnt/eee/lllll",
    "/mnt/fff/z",
    "/mnt/fff/aaaa",
    "/mnt/fff/bbbbb",
    "/mnt/fff/ccccc",
    "/mnt/fff/d",
    "/mnt/fff/e",
    "/mnt/fff/ffffff.fff.f",
    "/mnt/fff/gggggggggggg",
    "/mnt/fff/hhhh",
    "/mnt/fff/iiiii.ii",
    "/mnt/fff/jjjj.jj.jjjjjjjj",
    "/mnt/fff/kkkk.kkkkkkkk",
    "/mnt/fff/lllll"
};

char *
bstg_pathstore_get()
{
    return bstg_pathstore[rand() %
        ((sizeof(bstg_pathstore)/sizeof(bstg_pathstore[0])))];
}

void
dogcore()
{
    pid_t sleepchild, gcorechild;
    extern char **environ;

    /* create a child for the gcore target */
    if ((sleepchild = fork()) == 0) {
        sleep(30);
        _exit(1);
    } else if (sleepchild > 0) {
        char *token[] = { NULL, NULL, NULL, NULL, NULL };
        char buf[64];
        int status;

        /* use the first process as the target */
        snprintf(buf, sizeof(buf), "%d", sleepchild);
        token[0] = "gcore";
        token[1] = "-c";
        token[2] = bstg_pathstore_get();
        token[3] = buf;
        assert(token[4] == NULL);

        if ((gcorechild = fork()) > 0) {
            waitpid(gcorechild, &status, 0);
        } else if (gcorechild == 0) {
            execve("/usr/bin/gcore", token, environ);
            _exit(1);
        }

        kill(sleepchild, SIGKILL);
        waitpid(sleepchild, &status, 0);
    }
}

void
dowrite()
{
    struct iovec data[] = {
        { "12", 2 },
        { NULL, 0 },
        { "12345678", 8},
    };
    static int fd = -1;

    if (fd == -1) {
        /* keep existing file open during life of this process */
        fd = open(bstg_pathstore_get(), O_RDWR|O_NONBLOCK|O_NOCTTY);
    }

    data[1].iov_base = bstg_pathstore_get();
    data[1].iov_len = strlen((char*)data[1].iov_base);
    ftruncate(fd, 0);
    pwritev(fd, data, 3, 0);
}

void
dounlink()
{
    unlink(bstg_pathstore_get());
}

void
dolink()
{
    link(bstg_pathstore_get(), bstg_pathstore_get());
}

void
domkdir()
{
    char **pdir;
    static char * bstg_dirs[] = {
        "/mnt/111", "/mnt/222", "/mnt/333", "/mnt/444",
        "/mnt/555", "/mnt/666", "/mnt/777", "/mnt/888",
        "/mnt/999", "/mnt/aaa", "/mnt/bbb", "/mnt/ccc",
        "/mnt/ddd", "/mnt/eee", "/mnt/fff", NULL
    };

    for (pdir = bstg_dirs; *pdir; pdir++) {
        mkdir(*pdir, 0777);
    }
}

void
dosync()
{
    sync();
}

int
main()
{
    unsigned x;
    int status;
    void (*funcs[])() = {
        dogcore,
        dowrite,
        dounlink,
        dolink,
        dowrite,
        dounlink,
        dolink,
        dowrite,
        dosync,
        dowrite,
        dounlink,
        dolink,
        dowrite,
        dounlink,
        dolink,
        dowrite,
    };

    /* we only can domkdir() once at startup */
    domkdir();

    /* create 128 children that loop forever running 4 operations */
    dosync();
    for (x = 0; x < 128; x++) {
        if (fork() == 0) {
            /* give child a new seed for the pathname selection */
            srand(x);

            for (;;) {
                /* each child will start looping at different function */
                (*funcs[x++ % 16]) ();
            }
            /* we never expect this code to run */
            _exit(1);
        }
    }

    /* block forever for all our children */
    while(wait(&status) > 0);
    return 0;
}
$ cc -Wall -O2 bstg0003.c
$ ./a.out
[... takes a few minutes to cause the panic ...]
>Fix:


>Release-Note:
>Audit-Trail:
>Unformatted:


More information about the freebsd-i386 mailing list