Subject: Strange Veriexec kernel breakage
To: None <current-users@netbsd.org>
From: Scott Ellis <scotte@warped.com>
List: current-users
Date: 12/26/2006 10:13:48
This is a multi-part message in MIME format.
--------------000700090600060907060002
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

I was wanting to play around with Veriexec this weekend, and so added 
the following two lines to an otherwise working -current (cvs updated 
the morning of Dec 26th) kernel:

pseudo-device 	veriexec 	1
options 	VERIFIED_EXEC_FP_SHA256

Booting this kernel seems to have sysctl_createv() behaving weirdly, as 
the booted kernel prints things like:

sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(securelevel) returned 2
sysctl_createv: sysctl_create(kern) returned 17

...and many of the "normal" mibs aren't present (like kern.maxfiles).

The attached Boot_Breakage.txt shows what a boot looks.  The attached 
INTREPID.AMD64 is the kernel config that runs file (with the two 
veriexec items above commented out).

It seems almost like I'm missing some other kernel option, but I can't 
see what that would be!

In case it matters, I have USE_SSP=yes in mk.conf.

Any clues what is happening here?

	ScottE

--------------000700090600060907060002
Content-Type: text/plain;
 name="Boot_Breakage.txt"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
 filename="Boot_Breakage.txt"

>> NetBSD/amd64 BIOS Boot, Revision 3.3
>> (scotte@intrepid, Fri Apr  7 19:53:08 PDT 2006)
>> Memory: 637/1046784 k
Press return to boot now, any other key for boot menu
booting hd0a:netbsd - starting in 0
2376584+316040+229248 [257064+170792]=0x432e98
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005, 2006
    The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
    The Regents of the University of California.  All rights reserved.

NetBSD 4.99.7 (INTREPID.AMD64) #2: Tue Dec 26 09:42:05 PST 2006
        scotte@intrepid:/nbu/source/netbsd/src/obj.amd64/nbu/source/netbsd/src/sys/arch/amd64/compile/INTREPID.AMD64
total memory = 1022 MB
avail memory = 979 MB
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(securelevel) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(ostype) returned 2
sysctl_createv: sysctl_locate(osrelease) returned 2
sysctl_createv: sysctl_locate(osrevision) returned 2
sysctl_createv: sysctl_locate(version) returned 2
sysctl_createv: sysctl_locate(maxvnodes) returned 2
sysctl_createv: sysctl_locate(maxproc) returned 2
sysctl_createv: sysctl_locate(maxfiles) returned 2
sysctl_createv: sysctl_locate(argmax) returned 2
sysctl_createv: sysctl_locate(hostname) returned 2
sysctl_createv: sysctl_locate(hostid) returned 2
sysctl_createv: sysctl_locate(clockrate) returned 2
sysctl_createv: sysctl_locate(hardclock_ticks) returned 2
sysctl_createv: sysctl_locate(vnode) returned 2
sysctl_createv: sysctl_locate(file) returned 2
sysctl_createv: sysctl_locate(profiling) returned 2
sysctl_createv: sysctl_locate(posix1version) returned 2
sysctl_createv: sysctl_locate(ngroups) returned 2
sysctl_createv: sysctl_locate(job_control) returned 2
sysctl_createv: sysctl_locate(saved_ids) returned 2
sysctl_createv: sysctl_locate(boottime) returned 2
sysctl_createv: sysctl_locate(domainname) returned 2
sysctl_createv: sysctl_locate(maxpartitions) returned 2
sysctl_createv: sysctl_locate(rawpartition) returned 2
sysctl_createv: sysctl_locate(timex) returned 2
sysctl_createv: sysctl_locate(autonicetime) returned 2
sysctl_createv: sysctl_locate(autoniceval) returned 2
sysctl_createv: sysctl_locate(rtc_offset) returned 2
sysctl_createv: sysctl_locate(root_device) returned 2
sysctl_createv: sysctl_locate(msgbufsize) returned 2
sysctl_createv: sysctl_locate(fsync) returned 2
sysctl_createv: sysctl_locate(ipc) returned 2
sysctl_createv: sysctl_locate(sysvmsg) returned 2
sysctl_createv: sysctl_locate(sysvsem) returned 2
sysctl_createv: sysctl_locate(sysvshm) returned 2
sysctl_createv: sysctl_locate(synchronized_io) returned 2
sysctl_createv: sysctl_locate(iov_max) returned 2
sysctl_createv: sysctl_locate(mapped_files) returned 2
sysctl_createv: sysctl_locate(memlock) returned 2
sysctl_createv: sysctl_locate(memlock_range) returned 2
sysctl_createv: sysctl_locate(memory_protection) returned 2
sysctl_createv: sysctl_locate(login_name_max) returned 2
sysctl_createv: sysctl_locate(defcorename) returned 2
sysctl_createv: sysctl_locate(logsigexit) returned 2
sysctl_createv: sysctl_locate(fscale) returned 2
sysctl_createv: sysctl_locate(ccpu) returned 2
sysctl_createv: sysctl_locate(cp_time) returned 2
sysctl_createv: sysctl_locate(msgbuf) returned 2
sysctl_createv: sysctl_locate(consdev) returned 2
sysctl_createv: sysctl_locate(maxptys) returned 2
sysctl_createv: sysctl_locate(maxphys) returned 2
sysctl_createv: sysctl_locate(sbmax) returned 2
sysctl_createv: sysctl_locate(monotonic_clock) returned 2
sysctl_createv: sysctl_locate(urandom) returned 2
sysctl_createv: sysctl_locate(arandom) returned 2
sysctl_createv: sysctl_locate(labelsector) returned 2
sysctl_createv: sysctl_locate(labeloffset) returned 2
sysctl_createv: sysctl_locate(lwp) returned 2
sysctl_createv: sysctl_locate(forkfsleep) returned 2
sysctl_createv: sysctl_locate(posix_threads) returned 2
sysctl_createv: sysctl_locate(posix_semaphores) returned 2
sysctl_createv: sysctl_locate(posix_barriers) returned 2
sysctl_createv: sysctl_locate(posix_timers) returned 2
sysctl_createv: sysctl_locate(posix_spin_locks) returned 2
sysctl_createv: sysctl_locate(posix_reader_writer_locks) returned 2
sysctl_createv: sysctl_locate(dump_on_panic) returned 2
sysctl_createv: sysctl_locate(root_partition) returned 2
sysctl_createv: sysctl_locate(drivers) returned 2
sysctl_createv: sysctl_locate(file2) returned 2
sysctl_createv: sysctl_locate(cp_id) returned 2
sysctl_createv: sysctl_locate(coredump) returned 2
sysctl_createv: rnode NULL
sysctl_createv: rnode NULL
sysctl_createv: rnode NULL
sysctl_createv: rnode NULL
sysctl_createv: rnode NULL
sysctl_createv: rnode NULL
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(proc) returned 2
sysctl_createv: sysctl_locate(proc2) returned 2
sysctl_createv: sysctl_locate(proc_args) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(ntptime) returned 2
sysctl_createv: sysctl_locate(timecounter) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(bufq) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(pipe) returned 2
sysctl_createv: sysctl_locate(maxkvasz) returned 2
sysctl_createv: sysctl_locate(maxloankvasz) returned 2
sysctl_createv: sysctl_locate(maxbigpipes) returned 2
sysctl_createv: sysctl_locate(nbigpipes) returned 2
sysctl_createv: sysctl_locate(kvasize) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(ipc) returned 2
sysctl_createv: sysctl_locate(sysvipc_info) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(ipc) returned 2
sysctl_createv: sysctl_locate(shmmax) returned 2
sysctl_createv: sysctl_locate(shmmni) returned 2
sysctl_createv: sysctl_locate(shmseg) returned 2
sysctl_createv: sysctl_locate(shmmaxpgs) returned 2
sysctl_createv: sysctl_locate(shm_use_phys) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(tkstat) returned 2
sysctl_createv: sysctl_locate(nin) returned 2
sysctl_createv: sysctl_locate(nout) returned 2
sysctl_createv: sysctl_locate(cancc) returned 2
sysctl_createv: sysctl_locate(rawcc) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(mbuf) returned 2
sysctl_createv: sysctl_locate(msize) returned 2
sysctl_createv: sysctl_locate(mclbytes) returned 2
sysctl_createv: sysctl_locate(nmbclusters) returned 2
sysctl_createv: sysctl_locate(mblowat) returned 2
sysctl_createv: sysctl_locate(mcllowat) returned 2
sysctl_createv: sysctl_locate(stats) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(somaxkva) returned 2
sysctl_createv: sysctl_create(kern) returned 17
sysctl_createv: sysctl_locate(buf) returned 2
timecounter: Timecounters tick every 10.000 msec
timecounter: Timecounter "i8254" frequency 1193182 Hz quality 100
mainbus0 (root)
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: AMD Athlon(tm) 64 Processor 3400+, 2202.93 MHz
cpu0: features: e7dbfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR>
cpu0: features: e7dbfbff<PGE,MCA,CMOV,PAT,PSE36,MPC,NOX,MMXX,MMX>
cpu0: features: e7dbfbff<FXSR,SSE,SSE2,LONG,3DNOW2,3DNOW>
cpu0: AMD Power Management features: f<TTP,VID,FID,TS>
cpu0: AMD Cool`n'Quiet Technology 2200 MHz
cpu0: available frequencies (Mhz): 1000 1800 2000 2200
cpu0: calibrating local timer
cpu0: apic clock running at 200 MHz
cpu0: 16 page colors
ioapic0 at mainbus0 apid 1 (I/O APIC)
ioapic0: pa 0xfec00000, version 3, 24 pins
ioapic0: misconfigured as apic 2
ioapic0: remapped to apic 1
acpi0 at mainbus0: Advanced Configuration and Power Interface
acpi0: fixed-feature power button present
timecounter: Timecounter "ACPI-Fast" frequency 3579545 Hz quality 1000
ACPI-Fast 24-bit timer
ACPI Object Type 'Processor' (0x0c) at acpi0 not configured
PNP0A03 at acpi0 not configured
PNP0000 at acpi0 not configured
PNP0200 at acpi0 not configured
PNP0100 at acpi0 not configured
PNP0B00 at acpi0 not configured
PNP0800 at acpi0 not configured
PNP0C04 at acpi0 not configured
fdc0 at acpi0 (PNP0700)
fdc0: io 0x3f0-0x3f5,0x3f7 irq 6 drq 2
fdc0: expected BUFFER, got 4
lpt0 at acpi0 (PNP0400-1)
lpt0: io 0x378-0x37f irq 7
PNP0C02 at acpi0 not configured
PNP0C02 at acpi0 not configured
com0 at acpi0 (PNP0501-2)
com0: io 0x2f8-0x2ff irq 3
com0: ns16550a, working fifo
com1 at acpi0 (PNP0501-1)
com1: io 0x3f8-0x3ff irq 4
com: ns16550a, working fifo
com1: console
PNP0C01 at acpi0 not configured
acpibut0 at acpi0 (PNP0C0C-170): ACPI Power Button
PNP0C0F at acpi0 not configured
PNP0C0F at acpi0 not configured
PNP0C0F at acpi0 not configured
PNP0C0F at acpi0 not configured
acpibut1 at acpi0 (PNP0C0E): ACPI Sleep Button
pci0 at mainbus0 bus 0: configuration mode 1
pci0: i/o space, memory space enabled, rd/line, rd/mult, wr/inv ok
pchb0 at pci0 dev 0 function 0
pchb0: vendor 0x1106 product 0x3188 (rev. 0x01)
agp at pchb0 not configured
ppb0 at pci0 dev 1 function 0: vendor 0x1106 product 0xb188 (rev. 0x00)
pci1 at ppb0 bus 1
pci1: memory space enabled
skc0 at pci0 dev 10 function 0: ioapic0 pin 17 (irq 11)
skc0: Marvell Yukon Lite Gigabit Ethernet rev. A3(0x7)
sk0 at skc0 port A: Ethernet address 00:11:2f:38:83:e7
makphy0 at sk0 phy 0: Marvell 88E1011 Gigabit PHY, rev. 5
makphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto
ex0 at pci0 dev 11 function 0: 3Com 3c905B-TX 10/100 Ethernet (rev. 0x30)
ex0: interrupting at ioapic0 pin 16 (irq 5)
ex0: MAC address 00:50:04:78:77:9c
exphy0 at ex0 phy 24: 3Com internal media interface
exphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
ex1 at pci0 dev 14 function 0: 3Com 3c905B-TX 10/100 Ethernet (rev. 0x30)
ex1: interrupting at ioapic0 pin 19 (irq 11)
ex1: MAC address 00:10:5a:0f:35:6f
exphy1 at ex1 phy 24: 3Com internal media interface
exphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
viaide0 at pci0 dev 15 function 0
viaide0: VIA Technologies VT8237 SATA Controller (rev. 0x80)
viaide0: bus-master DMA support present
viaide0: primary channel wired to native-PCI mode
viaide0: using ioapic0 pin 20 (irq 11) for native-PCI interrupt
atabus0 at viaide0 channel 0
viaide0: secondary channel wired to native-PCI mode
atabus1 at viaide0 channel 1
viaide1 at pci0 dev 15 function 1
viaide1: VIA Technologies VT8237 ATA133 controller
viaide1: bus-master DMA support present
viaide1: primary channel configured to compatibility mode
viaide1: primary channel interrupting at ioapic0 pin 14 (irq 14)
atabus2 at viaide1 channel 0
viaide1: secondary channel configured to compatibility mode
viaide1: secondary channel interrupting at ioapic0 pin 15 (irq 15)
atabus3 at viaide1 channel 1
uhci0 at pci0 dev 16 function 0: vendor 0x1106 product 0x3038 (rev. 0x81)
uhci0: interrupting at ioapic0 pin 21 (irq 5)
usb0 at uhci0: USB revision 1.0
uhub0 at usb0
uhub0: vendor 0x1106 UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
uhci1 at pci0 dev 16 function 1: vendor 0x1106 product 0x3038 (rev. 0x81)
uhci1: interrupting at ioapic0 pin 21 (irq 5)
usb1 at uhci1: USB revision 1.0
uhub1 at usb1
uhub1: vendor 0x1106 UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhci2 at pci0 dev 16 function 2: vendor 0x1106 product 0x3038 (rev. 0x81)
uhci2: interrupting at ioapic0 pin 21 (irq 11)
usb2 at uhci2: USB revision 1.0
uhub2 at usb2
uhub2: vendor 0x1106 UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
uhci3 at pci0 dev 16 function 3: vendor 0x1106 product 0x3038 (rev. 0x81)
uhci3: interrupting at ioapic0 pin 21 (irq 11)
usb3 at uhci3: USB revision 1.0
uhub3 at usb3
uhub3: vendor 0x1106 UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub3: 2 ports with 2 removable, self powered
ehci0 at pci0 dev 16 function 4: vendor 0x1106 product 0x3104 (rev. 0x86)
ehci0: interrupting at ioapic0 pin 21 (irq 10)
ehci0: BIOS has given up ownership
ehci0: EHCI version 1.0
ehci0: companion controllers, 2 ports each: uhci0 uhci1 uhci2 uhci3
usb4 at ehci0: USB revision 2.0
uhub4 at usb4
uhub4: vendor 0x1106 EHCI root hub, class 9/0, rev 2.00/1.00, addr 1
uhub4: 8 ports with 8 removable, self powered
pcib0 at pci0 dev 17 function 0
pcib0: vendor 0x1106 product 0x3227 (rev. 0x00)
auvia0 at pci0 dev 17 function 5: VIA Technologies VT8237 AC'97 Audio (rev 0x60)
auvia0: interrupting at ioapic0 pin 22 (irq 10)
auvia0: ac97: Analog Devices AD1980 codec; headphone, 20 bit DAC, no 3D stereo
auvia0: ac97: ext id 3c7<AMAP,LDAC,SDAC,CDAC,SPDIF,DRA,VRA>
audio0 at auvia0: full duplex, mmap, independent
pchb1 at pci0 dev 24 function 0
pchb1: vendor 0x1022 product 0x1100 (rev. 0x00)
pchb2 at pci0 dev 24 function 1
pchb2: vendor 0x1022 product 0x1101 (rev. 0x00)
pchb3 at pci0 dev 24 function 2
pchb3: vendor 0x1022 product 0x1102 (rev. 0x00)
pchb4 at pci0 dev 24 function 3
pchb4: vendor 0x1022 product 0x1103 (rev. 0x00)
isa0 at pcib0
lm0 at isa0 port 0x290-0x297: W83697HF
pcppi0 at isa0 port 0x61
sysbeep0 at pcppi0
ioapic0: enabling
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
fd0 at fdc0 drive 0: 1.44MB, 80 cyl, 2 head, 18 sec
Kernelized RAIDframe activated
viaide0 port 0: device present, speed: 1.5Gb/s
viaide0 port 1: device present, speed: 1.5Gb/s
wd0 at atabus0 drive 0: <WDC WD5000YS-01MPB0>
wd0: drive supports 16-sector PIO transfers, LBA48 addressing
wd0: 465 GB, 969021 cyl, 16 head, 63 sec, 512 bytes/sect x 976773168 sectors
wd0: 32-bit data port
wd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133)
wd0(viaide0:0:0): using PIO mode 4, Ultra-DMA mode 6 (Ultra/133) (using DMA)
wd1 at atabus1 drive 0: <WDC WD5000YS-01MPB0>
wd1: drive supports 16-sector PIO transfers, LBA48 addressing
wd1: 465 GB, 969021 cyl, 16 head, 63 sec, 512 bytes/sect x 976773168 sectors
wd1: 32-bit data port
wd1: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133)
wd1(viaide0:1:0): using PIO mode 4, Ultra-DMA mode 6 (Ultra/133) (using DMA)
raid1: RAID Level 1
raid1: Components: /dev/wd1a /dev/wd0a
raid1: Total Sectors: 976772992 (476939 MB)
boot device: raid1
root on raid1a dumps on raid1b
root file system type: ffs
Tue Dec 26 09:44:58 PST 2006
swapctl: adding /dev/raid1b as swap device at priority 0
Checking for botched superblock upgrades: done.
Starting file system checks:
/dev/rraid1a: file system is clean; not checking
/dev/rraid1e: file system is clean; not checkinguplcom0 at uhub1 port 2
uplcom0: vendor 0x067b product 0x2303, rev 1.10/2.02, addr 2

ucom0 at uplcom0
/dev/rraid1f: file system is clean; not checking
/dev/rraid1g: file system is clean; not checking
/dev/rraid1h: file system is clean; not checking
Setting tty flags.
umass0 at uhub3 port 1 configuration 1 interface 0
umass0: USB Solid state disk, rev 1.10/1.00, addr 2
umass0: using SCSI over Bulk-Only
scsibus0 at umass0: 2 targets, 1 lun per target
sd0 at scsibus0 target 0 lun 0: <Mobile, Drive, 1.11> disk removable
sd0: fabricating a geometry
sd0: 64512 KB, 63 cyl, 64 head, 32 sec, 512 bytes/sect x 129024 sectors
pfctl: DIOCADDRULE: Address family not supported by protocol family
Setting sysctl variables:
sysctl: /etc/sysctl.conf#29: second level name 'maxfiles' in 'kern.maxfiles' is invalid
Starting network.
Hostname: Intrepid.warped.com
hostname: sethostname: No such file or directory
Configuring network interfaces: ex0 ex1 sk0.
Adding interface aliases:
Starting dhclient.
Internet Systems Consortium DHCP Client V3.0.3
Copyright 2004-2005 Internet Systems Consortium.
All rights reserved.
For info, please visit http://www.isc.org/products/DHCP

Listening on BPF/ex0/00:50:04:78:77:9c
Sending on   BPF/ex0/00:50:04:78:77:9c
Sending on   Socket/fallback
DHCPREQUEST on ex0 to 255.255.255.255 port 67
DHCPREQUEST on ex0 to 255.255.255.255 port 67
DHCPREQUEST on ex0 to 255.255.255.255 port 67
DHCPACK from 75.80.176.1
hostname: gethostname: No such file or directory
hostname: sethostname: No such file or directory
bound to 75.80.183.211 -- renewal in 36695 seconds.
Enabling pf firewall.
Building databases...
Starting syslogd.
Starting pflogd.
Dec 26 09:45:08 pflogd[474]: [priv]: msg PRIV_OPEN_LOG received
Starting named.
Dec 26 09:45:09  named[508]: none:0: open: /etc/rndc.key: file not found
Dec 26 09:45:09  named[508]: zone hostname.bind/CH: could not find NS and/or SOA records
Dec 26 09:45:09  named[508]: zone hostname.bind/CH: has 0 SOA records
Dec 26 09:45:09  named[508]: zone hostname.bind/CH: has no NS records
Setting date via ntp.
Starting rpcbind.
Mounting all filesystems...
Clearing /tmp.
dmesg: can't get msgbuf: No such file or directory
Checking quotas: done.
sysctl: second level name 'securelevel' in 'kern.securelevel' is invalid
Starting virecover.
Starting dhcpd.
Linking /var/tmp -> /tmp
starting local daemons:estd saslauthd estd: Cannot get CPU status
spamd Starting spamd
exim FreePOP Dec 26 09:45:16 exim[109]: 2006-12-26 09:45:16 Start queue run: pid=109
Dec 26 09:45:16 exim[110]: 2006-12-26 09:45:16 1GxqPC-00025G-RX == powaytm@intrepid.dnsalias.com routing defer (-51): retry time not reached
Dec 26 09:45:16 exim[109]: 2006-12-26 09:45:16 End queue run: pid=109
apache Dec 26 09:45:17 httpd[1173]: [warn] RSA server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
samba Dec 26 09:45:17 httpd[1142]: [warn] RSA server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
ClamAV SlimServer SELCD dovecot Cleaning tmp .
Starting lpd.
Updating motd.
sysctl: second level name 'version' in 'kern.version' is invalid
Starting ntpd.
Starting powerd.
Starting sshd.
Restoring mixer settings: mixer0raidctl: unable to open device file: raid1