Logging DNS queries

johnpoz

@Octopuss ok - have to do a some changes, add an interface to my vm that I can then stop from coming up.. to try and simulate an interface not coming up that unbound wants to bind too..

But what I did notice on a reboot of my vm, to see if gave warning if my wan dhcp didn't work

You are showing 1.18.0 for your unbound on 2.7.2, and I am showing 1.19.1

[2.7.2-RELEASE][admin@test.mydomain.tld]/root: unbound-control -c /var/unbound/unbound.conf status
version: 1.19.1
verbosity: 1
threads: 1
modules: 1 [ iterator ]
uptime: 141 seconds
options: control(ssl)
unbound (pid 83956) is running...
[2.7.2-RELEASE][admin@test.mydomain.tld]/root:

You posted

[2.7.2-RELEASE][admin@rozcestnik.lan]/root: unbound-control -c /var/unbound/unbound.conf status
version: 1.18.0

That seems odd??? Why would be on different version?

Could you run a pkg upgrade, and see if that updates your unbound.. I just ran it and have some things it will update on mine

[2.7.2-RELEASE][admin@test.mydomain.tld]/root: pkg upgrade
Updating pfSense-core repository catalogue...
Fetching meta.conf:   0%
Fetching packagesite.pkg:   0%
pfSense-core repository is up to date.
Updating pfSense repository catalogue...
Fetching meta.conf:   0%
Fetching packagesite.pkg:   0%
pfSense repository is up to date.
All repositories are up to date.
Checking for upgrades (3 candidates): 100%      3 B   0.0kB/s    00:01    
Processing candidates (3 candidates): 100%      3 B   0.0kB/s    00:01    
The following 2 package(s) will be affected (of 0 checked):

Installed packages to be UPGRADED:
        pfSense-pkg-pfBlockerNG-devel: 3.2.0_8 -> 3.2.0_20 [pfSense]
        rsync: 3.2.7 -> 3.4.0 [pfSense]

Number of packages to be upgraded: 2

The operation will free 1 MiB.
2 MiB to be downloaded.

Proceed with this action? [y/N]:

I am wondering if at some point I had ran that back awhile ago where there were some issues with unbound? I thought at one point they had made an upgrade to unbound kind of behind the scenes.. I would have to dig through forum to find those discussions. But I do recall something about 18.0 to 18.1 or or 19 or something..

edit: ok there was an update from 18 to 19, here is one thread that was talking about it because of CVE

https://forum.netgate.com/topic/186145/unbound-cve-2023-50387-and-cve-2023-50868?_=1738403211860

I would be curious if you ran pkg upgrade if you would update to 1.19.1, maybe you won't see the problem then when selecting specific interfaces?

Octopuss

@johnpoz Unfortunately no difference after an update.

Gertjan

@Octopuss said in Logging DNS queries:

difference after an update.

And system or at least unbound restart ?

unbound-control -c /var/unbound/unbound.conf status

Does it show 1.19.1 now ?

Octopuss

@Gertjan Of course, I rebooted to see whether the update made any difference.

So yes and yes.

johnpoz

@Octopuss My only theory is for whatever reason it takes a bit for your interfaces to come up, and unbound having a problem binding when you don't select all.

Why that is, not sure..

I have never seen it personally on any of my gear.. But again I rarely reboot pfsense.. Just no reason to. Maybe my system does it too? or could.. But sure not seeing it on my test VMs..

I want to try and duplicate like disabling the interface in my VM host, but not quite sure if I can without actually removing the interface from pfsense, ie it won't even see the interface which is different than say pulling the wire on it, or connection to switch takes a while because it's not set to portfast or something.

So where exactly do your lan and wifi interfaces go? Some AP for your wifi ones, Are they just vlans on your lan that is plugged into a switch and then your AP(s) plugged into that switch.. What switch?

So on one hand - yes like to understand why when you boot you only see bind to localhost if you do not select all.. On the other hand just leaving it on all you don't see the problem. So all is the default, it works - we could call it a day.

Octopuss

@johnpoz The cable from the AP goes directly inthe pfSense box, and the LAN port is connected to a managed switch (TP-Link T1700G-28TQ).

The Wifi interface on pfSense is just a VLAN where all the wifi devices go, and their APs.

johnpoz

@Octopuss well the only thing that makes any sense at all is when unbound goes to start one of your lan side interfaces is not up and so it has a problem binding to that IP.. Only theory I have that would explain the symptoms.

Maybe if you could watch is boot from console or something.. And maybe spot something..

Octopuss

@johnpoz Is the boot process being logged? There's so much going on and it scrolls so fast I don't think I could see anything even if I was staring at it.

johnpoz

@Octopuss there is boot log yes, under

Octopuss

@johnpoz
Great, I can't post the log, it is getting flagged as spam.
This forum software...

johnpoz

@Octopuss I bumped your rep to 5 points, try it now.

Octopuss

@johnpoz Thanks!

TSC: P-state invariant, performance statistics
VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID,VID,PostIntr
IA32_ARCH_CAPS=0x180fd6b<RDCL_NO,IBRS_ALL,SKIP_L1DFL_VME,MDS_NO,TAA_NO>
XSAVE Features=0xf<XSAVEOPT,XSAVEC,XINUSE,XSAVES>
Structured Extended Features3=0xfc184410<FSRM,MD_CLEAR,IBT,IBPB,STIBP,L1DFL,ARCH_CAP,CORE_CAP,SSBD>
Structured Extended Features2=0x98c007bc<UMIP,PKU,OSPKE,WAITPKG,GFNI,VAES,VPCLMULQDQ,RDPID,MOVDIRI,MOVDIR64B>
Structured Extended Features=0x239ca7eb<FSGSBASE,TSCADJ,BMI1,AVX2,FDPEXC,SMEP,BMI2,ERMS,INVPCID,NFPUSG,PQE,RDSEED,ADX,SMAP,CLFLUSHOPT,CLWB,PROCTRACE,SHA>
AMD Features2=0x121<LAHF,ABM,Prefetch>
AMD Features=0x2c100800<SYSCALL,NX,Page1GB,RDTSCP,LM>
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>
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>
Origin="GenuineIntel" Id=0xb06e0 Family=0x6 Model=0xbe Stepping=0
CPU: Intel(R) N100 (806.40-MHz K8-class CPU)
nda0: 244198MB (500118192 512 byte sectors)
nda0: nvme version 1.2
nda0: Serial Number 891PC7LTPZXP
nda0: <KBG30ZMV256G TOSHIBA ADHA0102 891PC7LTPZXP>
nda0 at nvme0 bus 0 scbus0 target 0 lun 1
Root mount waiting for: CAM
Root mount waiting for: CAM
Root mount waiting for: CAM
Root mount waiting for: CAM
Root mount waiting for: CAM
Root mount waiting for: CAM
Root mount waiting for: CAM
Root mount waiting for: CAM
uhub1: 16 ports with 16 removable, self powered
uhub0: 3 ports with 3 removable, self powered
Trying to mount root from zfs:pfSense/ROOT/default []...
nvme0: Allocated 38MB host memory buffer
mmc0: No compatible cards found on bus
uhub1: <Intel XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus1
uhub1 on usbus1
ugen1.1: <Intel XHCI root HUB> at usbus1
uhub0: <Intel XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
uhub0 on usbus0
ugen0.1: <Intel XHCI root HUB> at usbus0
ZFS storage pool version: features support (5000)
ZFS filesystem version: 5
Timecounters tick every 1.000 msec
Timecounter "TSC" frequency 806401223 Hz quality 1000
hwpstate_intel3: <Intel Speed Shift> on cpu3
hwpstate_intel2: <Intel Speed Shift> on cpu2
hwpstate_intel1: <Intel Speed Shift> on cpu1
hwpstate_intel0: <Intel Speed Shift> on cpu0
atrtc0: Can't map interrupt.
atrtc0: registered as a time-of-day clock, resolution 1.000000s
atrtc0: Warning: Couldn't map I/O.
atrtc0: <AT realtime clock> at port 0x70 irq 8 on isa0
atkbd0: [GIANT-LOCKED]
kbd0 at atkbd0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
acpi_syscontainer1: <System Container> on acpi0
acpi_syscontainer0: <System Container> on acpi0
acpi_tz0: <Thermal Zone> on acpi0
acpi_button1: <Power Button> on acpi0
cpu0: <ACPI CPU> on acpi0
acpi_button0: <Sleep Button> on acpi0
pci0: <serial bus> at device 31.5 (no driver attached)
isa0: <ISA bus> on isab0
isab0: <PCI-ISA bridge> at device 31.0 on pci0
igc1: netmap queues/slots: TX 4/1024, RX 4/1024
igc1: Ethernet address: a8:b8:e0:02:87:16
igc1: Using MSI-X interrupts with 5 vectors
igc1: Using 4 RX queues 4 TX queues
igc1: Using 1024 TX descriptors and 1024 RX descriptors
igc1: <Intel(R) Ethernet Controller I226-V> mem 0x80400000-0x804fffff,0x80500000-0x80503fff at device 0.0 on pci3
pci3: <ACPI PCI bus> on pcib3
pcib3: <ACPI PCI-PCI bridge> at device 29.1 on pci0
igc0: netmap queues/slots: TX 4/1024, RX 4/1024
igc0: Ethernet address: a8:b8:e0:02:87:15
igc0: Using MSI-X interrupts with 5 vectors
igc0: Using 4 RX queues 4 TX queues
igc0: Using 1024 TX descriptors and 1024 RX descriptors
igc0: <Intel(R) Ethernet Controller I226-V> mem 0x80600000-0x806fffff,0x80700000-0x80703fff at device 0.0 on pci2
pci2: <ACPI PCI bus> on pcib2
pcib2: <ACPI PCI-PCI bridge> at device 29.0 on pci0
nvme0: <Generic NVMe Device> mem 0x80800000-0x80803fff at device 0.0 on pci1
pci1: <ACPI PCI bus> on pcib1
pcib1: <ACPI PCI-PCI bridge> at device 28.0 on pci0
mmc0: <MMC/SD bus> on sdhci_pci0
sdhci_pci0: 1 slot(s) allocated
sdhci_pci0: <Generic SD HCI> mem 0x6001025000-0x6001025fff at device 26.0 on pci0
pci0: <simple comms> at device 22.0 (no driver attached)
pci0: <memory, RAM> at device 20.2 (no driver attached)
usbus1: 5.0Gbps Super Speed USB v3.0
usbus1 on xhci1
xhci1: 32 bytes context size, 64-bit DMA
xhci1: <XHCI (generic) USB 3.0 controller> mem 0x6001000000-0x600100ffff at device 20.0 on pci0
usbus0: 5.0Gbps Super Speed USB v3.0
usbus0 on xhci0
xhci0: 32 bytes context size, 64-bit DMA
xhci0: <XHCI (generic) USB 3.0 controller> mem 0x6001010000-0x600101ffff at device 13.0 on pci0
vgapci0: Boot video device
vgapci0: <VGA-compatible display> port 0x3000-0x303f mem 0x6000000000-0x6000ffffff,0x4000000000-0x400fffffff at device 2.0 on pci0
pci0: <ACPI PCI bus> on pcib0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1808-0x180b on acpi0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
Event timer "i8254" frequency 1193182 Hz quality 100
Timecounter "i8254" frequency 1193182 Hz quality 0
attimer0: <AT timer> port 0x40-0x43,0x50-0x53 irq 0 on acpi0
Event timer "RTC" frequency 32768 Hz quality 0
atrtc1: registered as a time-of-day clock, resolution 1.000000s
atrtc1: Warning: Couldn't map I/O.
atrtc1: <AT realtime clock> on acpi0
Event timer "HPET4" frequency 19200000 Hz quality 440
Event timer "HPET3" frequency 19200000 Hz quality 440
Event timer "HPET2" frequency 19200000 Hz quality 440
Event timer "HPET1" frequency 19200000 Hz quality 440
Event timer "HPET" frequency 19200000 Hz quality 550
Timecounter "HPET" frequency 19200000 Hz quality 950
hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
acpi0: Power Button (fixed)
acpi0: <ALASKA A M I >
smbios0: Version: 3.6, BCD Revision: 3.6
smbios0: <System Management BIOS> at iomem 0x75bb0000-0x75bb001e
efirtc0: registered as a time-of-day clock, resolution 1.000000s
efirtc0: <EFI Realtime Clock>
netgate0: <unknown hardware>
WARNING: Device "spkr" is Giant locked and may be deleted before FreeBSD 14.0.
kbd1 at kbdmux0
random: entropy device external interface
module_register_init: MOD_LOAD (iwi_monitor_fw, 0xffffffff807652e0, 0) error 1
iwi_monitor: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf.
iwi_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE.
module_register_init: MOD_LOAD (iwi_ibss_fw, 0xffffffff80765230, 0) error 1
iwi_ibss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf.
iwi_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE.
module_register_init: MOD_LOAD (iwi_bss_fw, 0xffffffff80765180, 0) error 1
iwi_bss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf.
iwi_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE.
module_register_init: MOD_LOAD (ipw_monitor_fw, 0xffffffff80747700, 0) error 1
ipw_monitor: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
ipw_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE.
module_register_init: MOD_LOAD (ipw_ibss_fw, 0xffffffff80747650, 0) error 1
ipw_ibss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
ipw_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE.
module_register_init: MOD_LOAD (ipw_bss_fw, 0xffffffff807475a0, 0) error 1
ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE.
wlan: mac acl policy registered
TCP_ratelimit: Is now initialized
Launching APs: 2 3 1
ioapic0 <Version 2.0> irqs 0-119
random: unblocking device.
random: fast provider: "Intel Secure Key RNG"
random: registering fast source Intel Secure Key RNG
FreeBSD/SMP: 1 package(s) x 4 core(s)
FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs
WARNING: L3 data cache covers more APIC IDs than a package (7 > 3)
ACPI APIC Table: <ALASKA A M I >
Event timer "LAPIC" quality 600
avail memory = 7982657536 (7612 MB)
real memory = 8589934592 (8192 MB)
TSC: P-state invariant, performance statistics
VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID,VID,PostIntr
IA32_ARCH_CAPS=0x180fd6b<RDCL_NO,IBRS_ALL,SKIP_L1DFL_VME,MDS_NO,TAA_NO>
XSAVE Features=0xf<XSAVEOPT,XSAVEC,XINUSE,XSAVES>
Structured Extended Features3=0xfc184410<FSRM,MD_CLEAR,IBT,IBPB,STIBP,L1DFL,ARCH_CAP,CORE_CAP,SSBD>
Structured Extended Features2=0x98c007bc<UMIP,PKU,OSPKE,WAITPKG,GFNI,VAES,VPCLMULQDQ,RDPID,MOVDIRI,MOVDIR64B>
Structured Extended Features=0x239ca7eb<FSGSBASE,TSCADJ,BMI1,AVX2,FDPEXC,SMEP,BMI2,ERMS,INVPCID,NFPUSG,PQE,RDSEED,ADX,SMAP,CLFLUSHOPT,CLWB,PROCTRACE,SHA>
AMD Features2=0x121<LAHF,ABM,Prefetch>
AMD Features=0x2c100800<SYSCALL,NX,Page1GB,RDTSCP,LM>
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>
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>
Origin="GenuineIntel" Id=0xb06e0 Family=0x6 Model=0xbe Stepping=0
CPU: Intel(R) N100 (806.40-MHz K8-class CPU)
VT(vga): resolution 640x480
FreeBSD clang version 16.0.6 (https://github.com/llvm/llvm-project.git llvmorg-16.0.6-0-g7cbf1a259152)
root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_2-main/obj/amd64/StdASW5b/var/jenkins/workspace/pfSense-CE-snapshots-2_7_2-main/sources/FreeBSD-src-RELENG_2_7_2/amd64.amd64/sys/pfSense amd64
FreeBSD 14.0-CURRENT amd64 1400094 #1 RELENG_2_7_2-n255948-8d2b56da39c: Wed Dec 6 20:45:47 UTC 2023
FreeBSD is a registered trademark of The FreeBSD Foundation.
The Regents of the University of California. All rights reserved.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Copyright (c) 1992-2023 The FreeBSD Project.

johnpoz

@Octopuss so your running wireless on pfsense?

These jumped out at me

iwi_monitor: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf.

You can get rid of those with setting entry in your loader.conf file

https://forum.netgate.com/topic/78681/error-dmesg-module_register_init-mod_load

From your previous, seemed like you had other APs for your wifi..

just a VLAN where all the wifi devices go, and their APs.

Octopuss

@johnpoz said in Logging DNS queries:

so your running wireless on pfsense?

What do you mean?

@johnpoz said in Logging DNS queries:

From your previous, seemed like you had other APs for your wifi..

Yes. I don't understand the question.

johnpoz

@Octopuss this looks like some wifi on pfsense

module_register_init: MOD_LOAD (ipw_bss_fw, 0xffffffff807475a0, 0) error 1
ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE.
wlan: mac acl policy registered
TCP_ratelimit: Is now initialized
Launching APs: 2 3 1

Oh never mind, I don't see those on mine because I had set in loader.conf

[24.11-RELEASE][admin@sg4860.home.arpa]/boot: cat loader.conf.local 
hint.ichsmb.0.disabled=1
legal.intel_ipw.license_ack=1
legal.intel_iwi.license_ack=1
[24.11-RELEASE][admin@sg4860.home.arpa]/boot:

Never mind - my bad..

Octopuss

@johnpoz Yes, we have wifi in the house, two APs. And the internet connection is wifi as well, but I already wrote that - I literally wrote we have an AP on the roof.

johnpoz

@Octopuss yeah my bad, those lines jumped out at me that maybe some wifi was actually running on pfsense - and yeah I knew you had said you were running your own AP.

But that is common thing if you hadn't set in loader.conf - my pfsense has zero wifi card even and was seeing those until I set the loader.conf so I didn't see that warning.

Forget I brought it up..

The only thing that comes to mind that not able to listen on a specific interface and its IP is delay in the IP/interface being available when unbound goes to start when you boot. And then when you restart it they are available.

Thought maybe if there was local wifi trying to come up it could delay the availability of the IP when unbound started on boot when you called out specific interfaces to use vs all.

Its a grasping at straws idea.. but you could remove those errors on your boot by adding those entries in your loader.conf.local file

legal.intel_ipw.license_ack=1
legal.intel_iwi.license_ack=1

It is normally good idea to clear up any sort of such errors, because they are really a sort of log spam that can make it harder to spot a specific issue.. I don't see how that could cause the problem - but it would clean up your boot log a bit ;)

Octopuss

@johnpoz So if I only leave LAN and localhost in network interfaces, it works after boot. If I add the wifi interfaces, it's kaput.
Why is that I have no idea.

Octopuss

@Octopuss said in Logging DNS queries:

@johnpoz So if I only leave LAN and localhost in network interfaces, it works after boot. If I add the wifi interfaces, it's kaput.
Why is that I have no idea.

Ok, no, I was wrong. This forum refreshed but other websites didn't work either.
Nothing makes sense. I either run with DNSSEC enabled or I have to keep in mind to restart the DNS service after every reboot, which I will certainly forget about and when I reboot the thing in several weeks, I will spend several hours trying to troubleshoot why is there no internet.

johnpoz

@Octopuss so hmmm.. those are vlan only right.. They are vlans on your lan interface.. So possible delay in those coming up causing the problem.

But I would think if you said bind to lan, wifi and there was a delay in vlan being available it would still bind to the lan IP.. But maybe the vlans is causing a delay and nothing is available when unbound starts other than localhost.

Do you have interfaces where you could bring those up as native on an interface vs being vlan on lan?

If you have more physical interfaces on your pfsense, and your switch you could run those on their own physical nic and uplink from your switch vs being vlans on the lan interface.

I have multiple uplinks from my switch to pfsense, but I also have some vlans on an interface - those vlans don't ever talk to each other anyway.

I could try adding some vlans to my VM and see if I can then duplicate the problem.

edit:

. I either run with DNSSEC enabled

I thought you said if you select all with dnssec disabled it worked?