Unclean shutdown for r273852 -> r273899 transition

From: David Wolfskill <david_at_catwhisker.org>
Date: Fri, 31 Oct 2014 06:59:12 -0700
I thought it a bit odd when I rebooted after the "make installworld"
completed and found that fsck(8) was checking teh file systems on my
laptop.

When it also happened for my build machine, I suspected it might not
merely be a one-off oddity... and I was able to make use of the serial
console on the build machine.

THe laptop started out running:

FreeBSD g1-252.catwhisker.org 11.0-CURRENT FreeBSD 11.0-CURRENT #1412  r273852M/273852:1100040: Thu Oct 30 05:25:51 PDT 2014     root_at_g1-252.catwhisker.org:/common/S4/obj/usr/src/sys/CANARY  i386

this morning; I performed an in-place source upgrade to:

FreeBSD g1-252.catwhisker.org 11.0-CURRENT FreeBSD 11.0-CURRENT #1413  r273899M/273900:1100041: Fri Oct 31 06:01:13 PDT 2014     root_at_g1-252.catwhisker.org:/common/S4/obj/usr/src/sys/CANARY  i386


Here's what things looked like on the cosnole for the build machine (which
had been built from sources at the same revisions):

Oct 31 06:40:09 freebeast shutdown: reboot by david: 
Stopping cron.
Waiting for PIDS: 723.
Stopping sshd.
Waiting for PIDS: 713.
Stopping rsyncd.
Waiting for PIDS: 686.
Stopping powerd.
Waiting for PIDS: 671.
Stopping ntpd.
Waiting for PIDS: 668.
Stopping lpd.
Waiting for PIDS: 647.
Stopping lockd.
Waiting for PIDS: 630.
Stopping statd.
Waiting for PIDS: 627.
Stopping nfsd.
Waiting for PIDS: 623 624.
Stopping mountd.
Waiting for PIDS: 617.
Stopping casperd.
Waiting for PIDS: 595.
Stopping amd.
Waiting for PIDS: 587.
Stopping ypbind.
Waiting for PIDS: 582.
Stopping rpcbind.
Waiting for PIDS: 491.
Stopping devd.
Waiting for PIDS: 407.
Writing entropy file:.
.
TermiOct 31 06:40:14 freebeast syslogd: exiting on signal 15
Waiting (max 60 seconds) for system process `vnlru' to stop...done
Waiting (max 60 seconds) for system process `syncer' to stop...
Syncing disks, vnodes remaining...5 6 6 6 6 4 4 4 4 4 3 1 1 1 1 1 1 1 1 0 0 0 0 0 0 done
Waiting (max 60 seconds) for system process `bufdaemon' to stop...done
All buffers synced.
lock order reversal:
 1st 0xc7925388 ufs (ufs) _at_ /usr/src/sys/kern/vfs_mount.c:1223
 2nd 0xc7a7a7f8 devfs (devfs) _at_ /usr/src/sys/ufs/ffs/ffs_vfsops.c:1375
KDB: stack backtrace:
db_trace_self_wrapper(c11ac524,c6da28c8,c156af90,c156afa4,e1fb9890,...) at db_trace_self_wrapper+0x2d/frame 0xe1fb9828
kdb_backtrace(c11b00a9,c7a7a7f8,c11a2e94,c6daa3e0,c11e2149,...) at kdb_backtrace+0x30/frame 0xe1fb9890
witness_checkorder(c7a7a7f8,9,c11e2149,55f,0,...) at witness_checkorder+0xd0c/frame 0xe1fb98e0
__lockmgr_args(c7a7a7f8,80400,c7a7a818,0,0,0,c11e2149,55f) at __lockmgr_args+0x8f3/frame 0xe1fb99bc
vop_stdlock(e1fb9a30,c11e2149,63d,1244,c7a7a838,...) at vop_stdlock+0x4d/frame 0xe1fb99ec
VOP_LOCK1_APV(c140ddac,e1fb9a30,0,0,c145ac60,...) at VOP_LOCK1_APV+0x10a/frame 0  ______               ____   _____ _____  
 |  ____|             |  _ \ / ____|  __ \ 
 | |___ _ __ ___  ___ | |_) | (___ | |  | |
 |  ___| '__/ _ \/ _ \|  _ < \___ \| |  | |
 | |   | | |  __/  __/| |_) |____) | |__| |
 | |   | | |    |    ||     |      |      |
 |_|   |_|  \___|\___||____/|_____/|_____/    ```                        `
                                             s` `.....---.......--.```   -/
... 

(The stack bactrace is obviously truncated.)

...
Booting...
GDB: no debug ports present
KDB: debugger backends: ddb
KDB: current backend: ddb
Copyright (c) 1992-2014 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
        The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 11.0-CURRENT #1651  r273899M/273900:1100041: Fri Oct 31 06:31:31 PDT 2014
    root_at_freebeast.catwhisker.org:/common/S4/obj/usr/src/sys/GENERIC i386
FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) 20140512
WARNING: WITNESS option enabled, expect reduced performance.
CPU: Intel(R) Xeon(TM) CPU 3.60GHz (3600.20-MHz 686-class CPU)
  Origin="GenuineIntel"  Id=0xf41  Family=0xf  Model=0x4  Stepping=1
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
  Features2=0x659d<SSE3,DTES64,MON,DS_CPL,EST,TM2,CNXT-ID,CX16,xTPR>
  AMD Features=0x20100000<NX,LM>
  TSC: P-state invariant
real memory  = 2147483648 (2048 MB)
avail memory = 2077032448 (1980 MB)
Event timer "LAPIC" quality 400
ACPI APIC Table: <PTLTD          APIC  >
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
FreeBSD/SMP: 2 package(s) x 1 core(s)
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  6
random device not loaded/active; using insecure pseudo-random number generator
ioapic0 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
ioapic2 <Version 2.0> irqs 48-71 on motherboard
random: entropy device infrastructure driver
random: selecting highest priority adaptor <Dummy>
kbd1 at kbdmux0
random: SOFT: yarrow init()
random: selecting highest priority adaptor <Yarrow>
...
SMP: AP CPU #1 Launched!
Timecounter "TSC-low" frequency 1800099747 Hz quality 1000
WARNING: WITNESS option enabled, expect reduced performance.
Trying to mount root from ufs:/dev/aacd0s4a [rw]...
Setting hostuuid: 80f1e964-dc63-0010-89d5-0030482d326a.
Setting hostid: 0xc74551dd.
cp: /var/log/utx.lastlogin: No such file or directory
chmod: /var/log/utx.lastlogin: No such file or directory
cp: /var/log/utx.log: No such file or directory
chmod: /var/log/utx.log: No such file or directory
Starting file system checks:
/dev/aacd0s4a: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s4a: clean, 234181 free (1941 frags, 29030 blocks, 0.5% fragmentation)
/dev/aacd0s1a: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s1a: clean, 144421 free (1565 frags, 17857 blocks, 0.4% fragmentation)
/dev/aacd1s1e: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd1s1e: clean, 2589387 free (211371 frags, 297252 blocks, 1.6% fragmentation)
/dev/aacd0s1d: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s1d: clean, 275828 free (3876 frags, 33994 blocks, 0.4% fragmentation)
/dev/aacd0s2a: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s2a: clean, 149425 free (97 frags, 18666 blocks, 0.0% fragmentation)
/dev/aacd0s2d: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s2d: clean, 311378 free (218 frags, 38895 blocks, 0.0% fragmentation)
/dev/aacd0s3a: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s3a: clean, 144465 free (1473 frags, 17874 blocks, 0.4% fragmentation)
/dev/aacd0s3d: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s3d: clean, 279024 free (41032 frags, 29749 blocks, 4.6% fragmentation)
/dev/aacd0s4d: NO WRITE ACCESS
/dev/aacd0s4d: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
/dev/aacd0s4f: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/aacd0s4f: clean, 2090552 free (592 frags, 261245 blocks, 0.0% fragmentation)
THE FOLLOWING FILE SYSTEM HAD AN UNEXPECTED INCONSISTENCY:
        ufs: /dev/aacd0s4d (/usr)
File system preen failed, trying fsck -y 
** /dev/aacd0s4a
** Last Mounted on /
** Root file system
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
4306 files, 137698 used, 234181 free (1941 frags, 29030 blocks, 0.5% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s1a
** Last Mounted on /S1
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
10354 files, 227458 used, 144421 free (1565 frags, 17857 blocks, 0.4% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s1d
** Last Mounted on /S1/usr
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
146169 files, 619244 used, 275828 free (3876 frags, 33994 blocks, 0.4% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s2a
** Last Mounted on /S2
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
10313 files, 222454 used, 149425 free (97 frags, 18666 blocks, 0.0% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s2d
** Last Mounted on /S2/usr
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
134366 files, 583702 used, 311378 free (218 frags, 38895 blocks, 0.0% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s3a
** Last Mounted on /S3
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
10352 files, 227414 used, 144465 free (1473 frags, 17874 blocks, 0.4% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s3d
** Last Mounted on /S3/usr
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
random: unblocking device.
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
145515 files, 616056 used, 279024 free (41032 frags, 29749 blocks, 4.6% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s4d (NO WRITE)
** Last Mounted on /usr
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
143274 files, 563503 used, 331464 free (18320 frags, 39143 blocks, 2.0% fragmentation)
** /dev/aacd1s1e
** Last Mounted on /common
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
620322 files, 10780289 used, 2589387 free (211371 frags, 297252 blocks, 1.6% fragmentation)

***** FILE SYSTEM IS CLEAN *****
** /dev/aacd0s4f
** Last Mounted on /var
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
575 files, 25776 used, 2090552 free (592 frags, 261245 blocks, 0.0% fragmentation)

***** FILE SYSTEM IS CLEAN *****
lock order reversal:
 1st 0xc79085c0 ufs (ufs) _at_ /usr/src/sys/kern/vfs_mount.c:1223
 2nd 0xc7995c68 devfs (devfs) _at_ /usr/src/sys/ufs/ffs/ffs_vfsops.c:1375
KDB: stack backtrace:
db_trace_self_wrapper(c11aca2c,c6d9f8c8,c1574418,c157441c,f4cbb860,...) at db_trace_self_wrapper+0x2d/frame 0xf4cbb7f8
kdb_backtrace(c11b05b1,c7995c68,c11a339c,c6da7448,c11e2649,...) at kdb_backtrace+0x30/frame 0xf4cbb860
witness_checkorder(c7995c68,9,c11e2649,55f,0,...) at witness_checkorder+0xd0c/frame 0xf4cbb8b0
__lockmgr_args(c7995c68,80400,c7995c88,0,0,0,c11e2649,55f) at __lockmgr_args+0x8f3/frame 0xf4cbb98c
vop_stdlock(f4cbba00,c7937310,c79a32a0,0,c79a32a0,...) at vop_stdlock+0x4d/frame 0xf4cbb9bc
VOP_LOCK1_APV(c140d5a0,f4cbba00,0,0,c145a460,...) at VOP_LOCK1_APV+0x10a/frame 0xf4cbb9e8
_vn_lock(c7995c34,80400,c11e2649,55f,c1574418,...) at _vn_lock+0xa6/frame 0xf4cbba28
ffs_flushfiles(c79a32a0,8,c7937310,1,c7995c34,...) at ffs_flushfiles+0x142/frame 0xf4cbba74
softdep_flushfiles(c79a32a0,0,c7937310,0,0,...) at softdep_flushfiles+0x74/frame 0xf4cbbac8
ffs_unmount(c79a32a0,8000000,c11b92d4,50a,c141db80,...) at ffs_unmount+0x7b/frame 0xf4cbbb10
dounmount(c79a32a0,8000000,c7937310,48c,0,...) at dounmount+0x4de/frame 0xf4cbbb70
sys_unmount(c7937310,f4cbbcc8,8,c11a894c,db,...) at sys_unmount+0x2ca/frame 0xf4cbbc40
syscall(f4cbbd08) at syscall+0x30c/frame 0xf4cbbcfc
Xint0x80_syscall() at Xint0x80_syscall+0x21/frame 0xf4cbbcfc
--- syscall (22, FreeBSD ELF32, sys_unmount), eip = 0x280cc63b, esp = 0xbfbfe464, ebp = 0xbfbfe530 ---
Mounting local file systems:.
Writing entropy file:.
Setting hostname: freebeast.catwhisker.org.
....


After the "smoke test" on head, I rebooted the laptop to today's
stable/10 (FreeBSD 10.1-PRERELEASE #1374  r273898M/273900:1001501: Fri
Oct 31 04:12:05 PDT 2014); the build machine was powered off (until just
before midnight).

I'm not sure exactly how much of a problem this is, but it seems
anomalous, at best.

Peace,
david
-- 
David H. Wolfskill				david_at_catwhisker.org
Taliban: Evil cowards with guns afraid of truth from a 14-year old girl.

See http://www.catwhisker.org/~david/publickey.gpg for my public key.

Received on Fri Oct 31 2014 - 12:59:15 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:53 UTC