No logs are written and fatal php error on start

[athilopi]

Hi,

I am running the opnsense bare metal with 25.1.12. Since I hab problems installing 25.1 (the clients didn't get a connection to the internet, the firewall itself indeed), I installed 24.7 (and imported my old configuration via installation) and updated to 25.1.

Everything is working now, but two things are strange. First there's is no log written, beside the boot.log. I tried everything killed the syslog processes and cleaned the var/log/ direction. But there has never been a file called system.log in the /var/log folder. I rebooted and started the service several time.
I don't know if the problem has something to do with the error on boot. Here's the output of the crash reporter:

Code Select Expand

[24-Jul-2025 21:03:30 Europe/Berlin] PHP Fatal error:  Uncaught Error: Call to a member function setAttributeValue() on null in /usr/local/opnsense/mvc/app/models/OPNsense/Unbound/Migrations/M1_0_0.php:55
Stack trace:
#0 /usr/local/opnsense/mvc/app/models/OPNsense/Base/BaseModel.php(806): OPNsense\Unbound\Migrations\M1_0_0->run(Object(OPNsense\Unbound\Unbound))
#1 /usr/local/opnsense/mvc/script/run_migrations.php(54): OPNsense\Base\BaseModel->runMigrations()
#2 {main}
  thrown in /usr/local/opnsense/mvc/app/models/OPNsense/Unbound/Migrations/M1_0_0.php on line 55
[24-Jul-2025 21:12:09 Europe/Berlin] PHP Fatal error:  Uncaught Error: Call to a member function setAttributeValue() on null in /usr/local/opnsense/mvc/app/models/OPNsense/Unbound/Migrations/M1_0_0.php:55
Stack trace:
#0 /usr/local/opnsense/mvc/app/models/OPNsense/Base/BaseModel.php(806): OPNsense\Unbound\Migrations\M1_0_0->run(Object(OPNsense\Unbound\Unbound))
#1 /usr/local/opnsense/mvc/script/run_migrations.php(54): OPNsense\Base\BaseModel->runMigrations()
#2 {main}
  thrown in /usr/local/opnsense/mvc/app/models/OPNsense/Unbound/Migrations/M1_0_0.php on line 55

Here is the dmesg.boot

Code Select Expand

---<<BOOT>>---
Copyright (c) 1992-2023 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 14.2-RELEASE-p4 stable/25.1-n269832-6addeda7db20 SMP amd64
FreeBSD clang version 18.1.6 (https://github.com/llvm/llvm-project.git llvmorg-18.1.6-0-g1118c2e05e67)
VT(efifb): resolution 800x600
CPU: Intel(R) Core(TM) i7-7500U CPU @ 2.70GHz (2900.00-MHz K8-class CPU)
  Origin="GenuineIntel"  Id=0x806e9  Family=0x6  Model=0x8e  Stepping=9
  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=0x7ffafbbf<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,SDBG,FMA,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,TSCDLT,AESNI,XSAVE,OSXSAVE,AVX,F16C,RDRAND>
  AMD Features=0x2c100800<SYSCALL,NX,Page1GB,RDTSCP,LM>
  AMD Features2=0x121<LAHF,ABM,Prefetch>
  Structured Extended Features=0x29c67af<FSGSBASE,TSCADJ,SGX,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,NFPUSG,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PROCTRACE>
  Structured Extended Features3=0xc000000<IBPB,STIBP>
  XSAVE Features=0xf<XSAVEOPT,XSAVEC,XINUSE,XSAVES>
  VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID
  TSC: P-state invariant, performance statistics
real memory  = 17179869184 (16384 MB)
avail memory = 16513617920 (15748 MB)
Event timer "LAPIC" quality 600
ACPI APIC Table: <ALASKA A M I >
FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs
FreeBSD/SMP: 1 package(s) x 2 core(s) x 2 hardware threads
random: registering fast source Intel Secure Key RNG
random: fast provider: "Intel Secure Key RNG"
random: unblocking device.
ioapic0 <Version 2.0> irqs 0-119
Launching APs: 1 3 2
random: entropy device external interface
wlan: mac acl policy registered
kbd0 at kbdmux0
WARNING: Device "spkr" is Giant locked and may be deleted before FreeBSD 15.0.
efirtc0: <EFI Realtime Clock>
efirtc0: registered as a time-of-day clock, resolution 1.000000s
smbios0: <System Management BIOS> at iomem 0x8ce24000-0x8ce2401e
smbios0: Version: 2.8, BCD Revision: 2.8
aesni0: <AES-CBC,AES-CCM,AES-GCM,AES-ICM,AES-XTS>
acpi0: <ALASKA A M I >
acpi0: Power Button (fixed)
cpu0: <ACPI CPU> on acpi0
hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
Timecounter "HPET" frequency 24000000 Hz quality 950
Event timer "HPET" frequency 24000000 Hz quality 550
Event timer "HPET1" frequency 24000000 Hz quality 440
Event timer "HPET2" frequency 24000000 Hz quality 440
Event timer "HPET3" frequency 24000000 Hz quality 440
Event timer "HPET4" frequency 24000000 Hz quality 440
atrtc0: <AT realtime clock> port 0x70-0x77 irq 8 on acpi0
atrtc0: Warning: Couldn't map I/O.
atrtc0: registered as a time-of-day clock, resolution 1.000000s
Event timer "RTC" frequency 32768 Hz quality 0
attimer0: <AT timer> port 0x40-0x43,0x50-0x53 irq 0 on acpi0
Timecounter "i8254" frequency 1193182 Hz quality 0
Event timer "i8254" frequency 1193182 Hz quality 100
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1808-0x180b on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
vgapci0: <VGA-compatible display> port 0xf000-0xf03f mem 0xde000000-0xdeffffff,0xc0000000-0xcfffffff irq 16 at device 2.0 on pci0
vgapci0: Boot video device
xhci0: <Intel Sunrise Point-LP USB 3.0 controller> mem 0xdf610000-0xdf61ffff irq 16 at device 20.0 on pci0
xhci0: 32 bytes context size, 64-bit DMA
usbus0 on xhci0
usbus0: 5.0Gbps Super Speed USB v3.0
pci0: <simple comms> at device 22.0 (no driver attached)
ahci0: <Intel Sunrise Point-LP AHCI SATA controller> port 0xf090-0xf097,0xf080-0xf083,0xf060-0xf07f mem 0xdf628000-0xdf629fff,0xdf62d000-0xdf62d0ff,0xdf62c000-0xdf62c7ff irq 16 at device 23.0 on pci0
ahci0: AHCI v1.31 with 3 6Gbps ports, Port Multiplier not supported
ahcich0: <AHCI channel> at channel 0 on ahci0
ahcich1: <AHCI channel> at channel 1 on ahci0
ahcich2: <AHCI channel> at channel 2 on ahci0
pcib1: <ACPI PCI-PCI bridge> irq 16 at device 28.0 on pci0
pci1: <ACPI PCI bus> on pcib1
igb0: <Intel(R) I211 (Copper)> port 0xe000-0xe01f mem 0xdf500000-0xdf51ffff,0xdf520000-0xdf523fff irq 16 at device 0.0 on pci1
igb0: NVM V0.6 imgtype1
igb0: Using 1024 TX descriptors and 1024 RX descriptors
igb0: Using 2 RX queues 2 TX queues
igb0: Using MSI-X interrupts with 3 vectors
igb0: Ethernet address: 40:62:31:0b:51:bf
igb0: netmap queues/slots: TX 2/1024, RX 2/1024
pcib2: <ACPI PCI-PCI bridge> irq 17 at device 28.1 on pci0
pci2: <ACPI PCI bus> on pcib2
igb1: <Intel(R) I211 (Copper)> port 0xd000-0xd01f mem 0xdf400000-0xdf41ffff,0xdf420000-0xdf423fff irq 17 at device 0.0 on pci2
igb1: NVM V0.6 imgtype1
igb1: Using 1024 TX descriptors and 1024 RX descriptors
igb1: Using 2 RX queues 2 TX queues
igb1: Using MSI-X interrupts with 3 vectors
igb1: Ethernet address: 40:62:31:0b:51:c0
igb1: netmap queues/slots: TX 2/1024, RX 2/1024
pcib3: <ACPI PCI-PCI bridge> irq 18 at device 28.2 on pci0
pci3: <ACPI PCI bus> on pcib3
igb2: <Intel(R) I211 (Copper)> port 0xc000-0xc01f mem 0xdf300000-0xdf31ffff,0xdf320000-0xdf323fff irq 18 at device 0.0 on pci3
igb2: NVM V0.6 imgtype1
igb2: Using 1024 TX descriptors and 1024 RX descriptors
igb2: Using 2 RX queues 2 TX queues
igb2: Using MSI-X interrupts with 3 vectors
igb2: Ethernet address: 40:62:31:0b:51:c1
igb2: netmap queues/slots: TX 2/1024, RX 2/1024
pcib4: <ACPI PCI-PCI bridge> irq 19 at device 28.3 on pci0
pci4: <ACPI PCI bus> on pcib4
igb3: <Intel(R) I211 (Copper)> port 0xb000-0xb01f mem 0xdf200000-0xdf21ffff,0xdf220000-0xdf223fff irq 19 at device 0.0 on pci4
igb3: NVM V0.6 imgtype1
igb3: Using 1024 TX descriptors and 1024 RX descriptors
igb3: Using 2 RX queues 2 TX queues
igb3: Using MSI-X interrupts with 3 vectors
igb3: Ethernet address: 40:62:31:0b:51:c2
igb3: netmap queues/slots: TX 2/1024, RX 2/1024
pcib5: <ACPI PCI-PCI bridge> irq 16 at device 28.4 on pci0
pci5: <ACPI PCI bus> on pcib5
igb4: <Intel(R) I211 (Copper)> port 0xa000-0xa01f mem 0xdf100000-0xdf11ffff,0xdf120000-0xdf123fff irq 16 at device 0.0 on pci5
igb4: NVM V0.6 imgtype1
igb4: Using 1024 TX descriptors and 1024 RX descriptors
igb4: Using 2 RX queues 2 TX queues
igb4: Using MSI-X interrupts with 3 vectors
igb4: Ethernet address: 40:62:31:0b:51:c3
igb4: netmap queues/slots: TX 2/1024, RX 2/1024
pcib6: <ACPI PCI-PCI bridge> irq 17 at device 28.5 on pci0
pci6: <ACPI PCI bus> on pcib6
igb5: <Intel(R) I211 (Copper)> port 0x9000-0x901f mem 0xdf000000-0xdf01ffff,0xdf020000-0xdf023fff irq 17 at device 0.0 on pci6
igb5: NVM V0.6 imgtype1
igb5: Using 1024 TX descriptors and 1024 RX descriptors
igb5: Using 2 RX queues 2 TX queues
igb5: Using MSI-X interrupts with 3 vectors
igb5: Ethernet address: 40:62:31:0b:51:c4
igb5: netmap queues/slots: TX 2/1024, RX 2/1024
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
pci0: <memory> at device 31.2 (no driver attached)
hdac0: <Intel Kaby Lake-LP HDA Controller> mem 0xdf620000-0xdf623fff,0xdf600000-0xdf60ffff irq 16 at device 31.3 on pci0
acpi_button0: <Sleep Button> on acpi0
acpi_button1: <Power Button> on acpi0
acpi_tz0: <Thermal Zone> on acpi0
acpi_tz1: <Thermal Zone> on acpi0
ns8250: UART FCR is broken
ns8250: UART FCR is broken
uart0: <16950 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
ns8250: UART FCR is broken
ns8250: UART FCR is broken
uart1: <16950 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
orm0: <ISA Option ROM> at iomem 0xc0000-0xcffff pnpid ORM0000 on isa0
hwpstate_intel0: <Intel Speed Shift> on cpu0
hwpstate_intel1: <Intel Speed Shift> on cpu1
hwpstate_intel2: <Intel Speed Shift> on cpu2
hwpstate_intel3: <Intel Speed Shift> on cpu3
Timecounter "TSC-low" frequency 1452000130 Hz quality 1000
Timecounters tick every 1.000 msec
ugen0.1: <Intel XHCI root HUB> at usbus0
uhub0 on usbus0
uhub0: <Intel XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
ZFS filesystem version: 5
ZFS storage pool version: features support (5000)
hdacc0: <Intel Kaby Lake HDA CODEC> at cad 2 on hdac0
hdaa0: <Intel Kaby Lake Audio Function Group> at nid 1 on hdacc0
pcm0: <Intel Kaby Lake (HDMI/DP 8ch)> at nid 3 on hdaa0
Trying to mount root from zfs:zroot/ROOT/25.7.11 []...
ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
ada0: <CT240BX500SSD1 M6CR041> ACS-3 ATA SATA 3.x device
ada0: Serial Number 2104E4ECAEB0
ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 512bytes)
ada0: Command Queueing enabled
ada0: 228936MB (468862128 512 byte sectors)
ada1 at ahcich1 bus 0 scbus1 target 0 lun 0
ada1: <TS128GMSA230S 02J0S86A> ACS-2 ATA SATA 3.x device
ada1: Serial Number F758600913
ada1: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 1024bytes)
ada1: Command Queueing enabled
ada1: 122104MB (250069680 512 byte sectors)
uhub0: 18 ports with 18 removable, self powered
Everytime I restart the firewall the same crash message is shown.

[patient0]

but two things are strange. First there's is no log written, beside the boot.log. I tried everything killed the syslog processes and cleaned the var/log/ direction.

Manually cleaning (deleting?) log files does not sound like something you want to do. Does it show logs in the GUI, e.g System: Firmware: Log File?

And there is no /var/log/system.log file but there is a /var/log/system folder, with 'system_<date>.log' files in it and a file 'latest.log' which is a link to 'system_<current day>.log'


What files and directories does /var/log contain on your OPNsense installation? Below is mine, on a test installation:

Code Select Expand

# ls /var/log/
audit                   flowd.log.000002        routing
boot.log                installer.log           setuid.today
configd                 lighttpd                setuid.yesterday
dhcpd                   mount.today             suricata
dmesg.today             ntp                     system
dmesg.yesterday         ntpd                    userlog
elasticsearch           pf.today                utx.lastlogin
filter                  pf.yesterday            utx.log
firewall                pkg                     wireguard
flowd.log               qemu-ga.log
flowd.log.000001        resolver

[athilopi]

Hi,

thx for your answer. No there's no entry in System/Firmware/Log Files in the web gui.

Here are the files and dirs in the /var/log Folder:

Code Select Expand

dmesg.today
nginx
pf.today
suricata
utx.lastlogin
mount.today
ntp
setuid.today
userlog
utx.log

[franco]

The PHP error is a bit odd but we discussed a fix:

# opnsense-patch https://github.com/opnsense/core/commit/ec54a1d78fd
# /usr/local/opnsense/mvc/script/run_migrations.php

This should allow Unbound config to migrate to the latest. If it fixes the logging I'm entirely unsure as the error has nothing to do with logging.


Cheers,
Franco

[patient0]

thx for your answer. No there's no entry in System/Firmware/Log Files in the web gui.

Was it ok back when you where on 24.7?

If I delete e.g. the /var/log/system folder it gets recreated, I wonder if the migration from 24.7 went through 100%?

[athilopi]

The PHP error is a bit odd but we discussed a fix:

# opnsense-patch https://github.com/opnsense/core/commit/ec54a1d78fd
# /usr/local/opnsense/mvc/script/run_migrations.php

This should allow Unbound config to migrate to the latest. If it fixes the logging I'm entirely unsure as the error has nothing to do with logging.


Cheers,
Franco

I changed the line in /usr/local/opnsense/mvc/app/models/OPNsense/Unbound/Migrations/M1_0_0.php line 54 as github says. Because in /usr/local/opnsense/mvc/script/run_migrations.php there's no if (!empty($mdlNode->$strip)).
But changing the line in /usr/local/opnsense/mvc/app/models/OPNsense/Unbound/Migrations/M1_0_0.php didn't help.

[athilopi]

thx for your answer. No there's no entry in System/Firmware/Log Files in the web gui.

Was it ok back when you where on 24.7?

If I delete e.g. the /var/log/system folder it gets recreated, I wonder if the migration from 24.7 went through 100%?

That's a good question. I don't know if it was ok. The strange thin was, that the Update from 24.7 to 25.1 took very long.