pgj / freebsd-wifibox

wifibox: Use Linux to drive your wireless card on FreeBSD
BSD 2-Clause "Simplified" License
159 stars 12 forks source link

Broadcom-wl suspend to ram stopped working #59

Closed venoom27 closed 1 year ago

venoom27 commented 1 year ago

Description

When installing the main branch of wifbox-apline with broadcom-wl drive my suspend to ram stops working. When I say stops working it will go to sleep but it will not wake. When I was testing some of the earlier dev branchs and the broadcom-wl driver was not assigned a device wlan0 this was not an issue. It seems to be once the broadcom-wl module got loaded and assigned to wlan0 in the wifibox this became an issue. If wifbox is not installed suspend to ram works.

Host operating system

FreeBSD foo 13.2-RELEASE-p1 FreeBSD 13.2-RELEASE-p1 GENERIC amd64

Wireless NIC

bwn_pci0@pci0:2:0:0:    class=0x028000 rev=0x02 hdr=0x00 vendor=0x14e4 device=0x4331 subvendor=0x106b subdevice=0x00f5
    vendor     = 'Broadcom Inc. and subsidiaries'
    device     = 'BCM4331 802.11a/b/g/n'
    class      = network

Wifibox version

wifibox version 0.11.0

Disk image type and version

The kind of VM image in use, e.g. Wifibox/Alpine, and its version.

Changes to the default configuration files

rc.conf with its relevant wifibox add ons

devmatch_enable="YES"
devmatch_blocklist="if_iwm if_iwlwifi"

wifibox_enable="YES"

PORTS config for Alpine
UDS_PASSTHRU
XX_DRIVER_WL
COMP_XZ
APP_WPA_SUPPLICANT

Logs

Please copy and paste any relevant log output from the following sources:

- /var/log/wifibox.log (with DEBUG logging verbosity)

2023-07-30T18:46:45-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop
2023-07-30T18:46:45-0400 INFO  Begin: wifibox stop
2023-07-30T18:46:45-0400 DEBUG stop=GN
2023-07-30T18:46:45-0400 WARN  Guest is not running, hence not stopped
2023-07-30T18:46:45-0400 INFO  Removing null-modem devices
2023-07-30T18:46:45-0400 INFO  Null-modem devices are removed
2023-07-30T18:46:45-0400 INFO  Destroying bridge interface: wifibox0
2023-07-30T18:46:45-0400 DEBUG [ifconfig] ifconfig: interface wifibox0 does not exist
2023-07-30T18:46:45-0400 WARN  No linked tap inteface found for wifibox0
2023-07-30T18:46:45-0400 INFO  End: wifibox stop
2023-07-30T18:47:35-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-07-30T18:47:35-0400 INFO  Begin: wifibox start
2023-07-30T18:47:35-0400 DEBUG start=GN
2023-07-30T18:47:35-0400 INFO  Creating bridge interface: wifibox0
2023-07-30T18:47:35-0400 DEBUG [ifconfig] wifibox0
2023-07-30T18:47:35-0400 INFO  Linking tap interface to wifibox0: tap0
2023-07-30T18:47:35-0400 DEBUG assert loaded: kmod=vmm, kmod_file=/boot/modules/vmm.ko
2023-07-30T18:47:35-0400 DEBUG Kernel module vmm is not loaded
2023-07-30T18:47:35-0400 DEBUG Kernel module vmm was loaded successfully
2023-07-30T18:47:35-0400 DEBUG assert hardware support present: iommu=1, amdvi=0
2023-07-30T18:47:35-0400 DEBUG Backends reported by bhyve:
2023-07-30T18:47:35-0400 DEBUG [bhyve] ahci
2023-07-30T18:47:35-0400 DEBUG [bhyve] ahci-hd
2023-07-30T18:47:35-0400 DEBUG [bhyve] ahci-cd
2023-07-30T18:47:35-0400 DEBUG [bhyve] e1000
2023-07-30T18:47:35-0400 DEBUG [bhyve] dummy
2023-07-30T18:47:35-0400 DEBUG [bhyve] hda
2023-07-30T18:47:35-0400 DEBUG [bhyve] fbuf
2023-07-30T18:47:35-0400 DEBUG [bhyve] amd_hostbridge
2023-07-30T18:47:35-0400 DEBUG [bhyve] hostbridge
2023-07-30T18:47:35-0400 DEBUG [bhyve] lpc
2023-07-30T18:47:35-0400 DEBUG [bhyve] nvme
2023-07-30T18:47:35-0400 DEBUG [bhyve] passthru
2023-07-30T18:47:35-0400 DEBUG [bhyve] virtio-9p
2023-07-30T18:47:35-0400 DEBUG [bhyve] virtio-blk
2023-07-30T18:47:35-0400 DEBUG [bhyve] virtio-console
2023-07-30T18:47:35-0400 DEBUG [bhyve] virtio-net
2023-07-30T18:47:35-0400 DEBUG [bhyve] virtio-rnd
2023-07-30T18:47:35-0400 DEBUG [bhyve] virtio-scsi
2023-07-30T18:47:35-0400 DEBUG [bhyve] uart
2023-07-30T18:47:35-0400 DEBUG [bhyve] xhci
2023-07-30T18:47:35-0400 INFO  Bringing up null-modem devices for console connection
2023-07-30T18:47:35-0400 DEBUG assert loaded: kmod=nmdm, kmod_file=nmdm
2023-07-30T18:47:35-0400 DEBUG Kernel module nmdm is not loaded
2023-07-30T18:47:35-0400 DEBUG Kernel module nmdm was loaded successfully
2023-07-30T18:47:35-0400 INFO  Null-modem devices are available
2023-07-30T18:47:35-0400 INFO  Waiting for bhyve to start up
2023-07-30T18:47:35-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-07-30T18:47:35-0400 DEBUG assert daemonized: parent=daemon
2023-07-30T18:47:35-0400 INFO  VM manager launched
2023-07-30T18:47:35-0400 INFO  Gathering necessary configuration files for launching the guest
2023-07-30T18:47:35-0400 INFO  Pulling bhyve options from configuration file
2023-07-30T18:47:35-0400 DEBUG cpus=1, memory=128M, passthru=2/0/0, console=yes
2023-07-30T18:47:35-0400 INFO  Guest console is configured to use
2023-07-30T18:47:35-0400 INFO  Passthru device is configured: 2/0/0
2023-07-30T18:47:35-0400 INFO  PPT driver is configured for pci2:0:0 device
2023-07-30T18:47:35-0400 INFO  tap interface is configured: tap0
2023-07-30T18:47:35-0400 INFO  Launching guest wifibox from /usr/local/share/wifibox with grub-bhyve
2023-07-30T18:47:35-0400 INFO  Application config is found at /usr/local/etc/wifibox/wpa_supplicant
2023-07-30T18:47:35-0400 INFO  Application config will be mounted writeable
2023-07-30T18:47:35-0400 DEBUG Devices: virtio-blk,/usr/local/share/wifibox/disk.img virtio-9p,config=/usr/local/etc/wifibox/appliance,ro virtio-9p,var=/var/run/wifibox/appliance virtio-9p,app_config=/usr/local/etc/wifibox/wpa_supplicant
2023-07-30T18:47:35-0400 DEBUG Arguments:  -S -M 128M -r host -c /dev/nmdm-wifibox.1A -d /usr/local/share/wifibox wifibox
2023-07-30T18:47:35-0400 INFO  Launching guest wifibox from /usr/local/share/wifibox with bhyve
2023-07-30T18:47:35-0400 DEBUG Arguments:  -c 1 -m 128M -AHP -u -S -l com1,/dev/nmdm-wifibox.1A -s 0,hostbridge -s 31,lpc -s 4:0,virtio-blk,/usr/local/share/wifibox/disk.img -s 4:1,virtio-9p,config=/usr/local/etc/wifibox/appliance,ro -s 4:2,virtio-9p,var=/var/run/wifibox/appliance -s 4:3,virtio-9p,app_config=/usr/local/etc/wifibox/wpa_supplicant -s 5:0,e1000,tap0 -s 6:0,passthru,2/0/0 wifibox
2023-07-30T18:47:36-0400 DEBUG [bhyve] rdmsr to register 0x140 on vcpu 0
2023-07-30T18:47:36-0400 DEBUG [bhyve] rdmsr to register 0x34 on vcpu 0
2023-07-30T18:47:36-0400 INFO  Guest wifibox has started up
2023-07-30T18:47:36-0400 INFO  Guest is managed by PID 409
2023-07-30T18:47:36-0400 INFO  Bringing up Unix Domain Socket pass-through
2023-07-30T18:47:36-0400 INFO  Found guest IP address: 10.0.0.1
2023-07-30T18:47:36-0400 INFO  Configured sockets: [path=/var/run/wpa_supplicant/wlan0,user=root,group=0,mode=770,port=1200
path=/var/run/wpa_supplicant/p2p-dev-wlan0,user=root,group=0,mode=770,port=1201]
2023-07-30T18:47:36-0400 INFO  Hooking up 10.0.0.1:1200 as /var/run/wpa_supplicant/wlan0 (root:0@770)
2023-07-30T18:47:36-0400 INFO  Hooking up 10.0.0.1:1201 as /var/run/wpa_supplicant/p2p-dev-wlan0 (root:0@770)
2023-07-30T18:47:36-0400 INFO  End: wifibox start
2023-07-30T18:51:35-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: verison
2023-07-30T18:51:50-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: version
2023-07-30T18:51:50-0400 INFO  Begin: wifibox version
2023-07-30T18:51:50-0400 DEBUG version=0.11.0, checksum=8ea7e7a4a252171ae523aeb201282f7439104e9800c522d264b740ab9f346dd7
2023-07-30T18:51:50-0400 INFO  End: wifibox version

- /var/run/wifibox/appliance/log/dmesg

[    0.000000] Linux version 5.15.104-0-lts (pgj@wifibox-dev) (gcc (Alpine 12.2.1_git20220924-r4) 12.2.1 20220924, GNU ld (GNU Binutils) 2.39) #1-Alpine Sun, 26 Mar 2023 00:13:40 +0000
[    0.000000] Command line: console=ttyS0 BOOT_IMAGE=(host)/usr/local/share/wifibox/vmlinuz modules=squashfs root=/dev/vda rootfstype=squashfs clocksource=hpet tsc=unstable
[    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
[    0.000000] signal: max sigframe size: 1360
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x0000000007ffffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 2.6 present.
[    0.000000] DMI: FreeBSD BHYVE/BHYVE, BIOS 13.0 11/10/2020
[    0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000000] last_pfn = 0x8000 max_arch_pfn = 0x400000000
[    0.000000] Disabled
[    0.000000] x86/PAT: MTRRs disabled, skipping PAT initialization too.
[    0.000000] CPU MTRRs all blank - virtualized system.
[    0.000000] x86/PAT: Configuration [0-7]: WB  WT  UC- UC  WB  WT  UC- UC  
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F2400 000024 (v02 BHYVE )
[    0.000000] ACPI: XSDT 0x00000000000F2480 000044 (v01 BHYVE  BVXSDT   00000001 INTL 20201113)
[    0.000000] ACPI: APIC 0x00000000000F2500 00005A (v01 BHYVE  BVMADT   00000001 INTL 20201113)
[    0.000000] ACPI: FACP 0x00000000000F25D2 00010C (v05 BHYVE  BVFACP   00000001 INTL 20201113)
[    0.000000] ACPI: DSDT 0x00000000000F27D2 000A5C (v02 BHYVE  BVDSDT   00000001 INTL 20201113)
[    0.000000] ACPI: FACS 0x00000000000F2792 000040
[    0.000000] ACPI: FACS 0x00000000000F2792 000040
[    0.000000] ACPI: HPET 0x00000000000F2712 000038 (v01 BHYVE  BVHPET   00000001 INTL 20201113)
[    0.000000] ACPI: MCFG 0x00000000000F2752 00003C (v01 BHYVE  BVMCFG   00000001 INTL 20201113)
[    0.000000] ACPI: Reserving APIC table memory at [mem 0xf2500-0xf2559]
[    0.000000] ACPI: Reserving FACP table memory at [mem 0xf25d2-0xf26dd]
[    0.000000] ACPI: Reserving DSDT table memory at [mem 0xf27d2-0xf322d]
[    0.000000] ACPI: Reserving FACS table memory at [mem 0xf2792-0xf27d1]
[    0.000000] ACPI: Reserving FACS table memory at [mem 0xf2792-0xf27d1]
[    0.000000] ACPI: Reserving HPET table memory at [mem 0xf2712-0xf2749]
[    0.000000] ACPI: Reserving MCFG table memory at [mem 0xf2752-0xf278d]
[    0.000000] system APIC only can use physical flat
[    0.000000] Setting APIC routing to physical flat.
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   DMA32    [mem 0x0000000001000000-0x0000000007ffffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.000000]   node   0: [mem 0x0000000000100000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000007ffffff]
[    0.000000] On node 0, zone DMA: 1 pages in unavailable ranges
[    0.000000] On node 0, zone DMA: 96 pages in unavailable ranges
[    0.000000] ACPI: PM-Timer IO Port: 0x408
[    0.000000] system APIC only can use physical flat
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] high edge lint[0x1])
[    0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-31
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 high edge)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 low level)
[    0.000000] ACPI: Using ACPI (MADT) for SMP configuration information
[    0.000000] ACPI: HPET id: 0x80860701 base: 0xfed00000
[    0.000000] [mem 0x08000000-0xffffffff] available for PCI devices
[    0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 32000
[    0.000000] Kernel command line: console=ttyS0 BOOT_IMAGE=(host)/usr/local/share/wifibox/vmlinuz modules=squashfs root=/dev/vda rootfstype=squashfs clocksource=hpet tsc=unstable
[    0.000000] tsc: Marking TSC unstable due to boot parameter
[    0.000000] Unknown kernel command line parameters "BOOT_IMAGE=(host)/usr/local/share/wifibox/vmlinuz modules=squashfs", will be passed to user space.
[    0.000000] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.000000] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 108968K/130684K available (8193K kernel code, 1465K rwdata, 1572K rodata, 724K init, 1768K bss, 21456K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS: 4352, nr_irqs: 256, preallocated irqs: 16
[    0.000000] Console: colour EGA 80x25
[    0.000000] printk: console [ttyS0] enabled
[    0.000000] ACPI: Core revision 20210730
[    0.000000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 113919999973 ns
[    0.000000] APIC: Switch to symmetric I/O mode setup
[    0.001000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.007000] tsc: PIT calibration matches PMTIMER. 1 loops
[    0.008000] tsc: Detected 2492.392 MHz processor
[    0.000005] Calibrating delay loop (skipped), value calculated using timer frequency.. 4984.78 BogoMIPS (lpj=2492392)
[    0.001004] pid_max: default: 32768 minimum: 301
[    0.002016] LSM: Security Framework initializing
[    0.003022] Mount-cache hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.004005] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.005451] Last level iTLB entries: 4KB 512, 2MB 8, 4MB 8
[    0.006006] Last level dTLB entries: 4KB 512, 2MB 32, 4MB 32, 1GB 0
[    0.007012] CPU: Intel(R) Core(TM) i5-3210M CPU @ 2.50GHz (family: 0x6, model: 0x3a, stepping: 0x9)
[    0.008006] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.009006] Spectre V2 : Kernel not compiled with retpoline; no mitigation available!
[    0.009007] Spectre V2 : Vulnerable
[    0.010748] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.011005] Speculative Store Bypass: Vulnerable
[    0.012009] MDS: Mitigation: Clear CPU buffers
[    0.013004] MMIO Stale Data: Unknown: No mitigations
[    0.014005] SRBDS: Unknown: Dependent on hypervisor status
[    0.016020] Performance Events: unsupported p6 CPU model 58 no PMU driver, software events only.
[    0.120003] devtmpfs: initialized
[    0.120003] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.120007] futex hash table entries: 256 (order: 0, 6144 bytes, linear)
[    0.121152] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.122100] thermal_sys: Registered thermal governor 'step_wise'
[    0.122101] thermal_sys: Registered thermal governor 'user_space'
[    0.123012] cpuidle: using governor menu
[    0.124844] ACPI FADT declares the system doesn't support PCIe ASPM, so disable it
[    0.125005] ACPI: bus type PCI registered
[    0.126004] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.127077] PCI: Using configuration type 1 for base access
[    0.129426] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.131128] ACPI: Added _OSI(Module Device)
[    0.132005] ACPI: Added _OSI(Processor Device)
[    0.132939] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.133005] ACPI: Added _OSI(Processor Aggregator Device)
[    0.134005] ACPI: Added _OSI(Linux-Dell-Video)
[    0.134936] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.135007] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[    0.136264] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.138105] ACPI: Interpreter enabled
[    0.138885] ACPI: PM: (supports S0 S5)
[    0.139005] ACPI: Using IOAPIC for interrupt routing
[    0.140022] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.141063] ACPI: Enabled 1 GPEs in block 00 to 07
[    0.143911] ACPI: PCI Root Bridge [PC00] (domain 0000 [bus 00])
[    0.144008] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
[    0.145061] PCI host bridge to bus 0000:00
[    0.146005] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.147005] pci_bus 0000:00: root bus resource [io  0x0d00-0x1fff window]
[    0.148006] pci_bus 0000:00: root bus resource [io  0x2000-0x26bf window]
[    0.149005] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xc01fffff window]
[    0.150005] pci_bus 0000:00: root bus resource [mem 0x800000000-0x81fffffff window]
[    0.151005] pci_bus 0000:00: root bus resource [bus 00]
[    0.153090] pci 0000:00:00.0: [1275:1275] type 00 class 0x060000
[    0.154517] pci 0000:00:00.0: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.155742] pci 0000:00:04.0: [1af4:1001] type 00 class 0x010000
[    0.156213] pci 0000:00:04.0: reg 0x10: [io  0x2600-0x267f]
[    0.157120] pci 0000:00:04.0: reg 0x14: [mem 0xc0034000-0xc0035fff]
[    0.159473] pci 0000:00:04.0: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.161615] pci 0000:00:04.1: [1af4:1009] type 00 class 0x010000
[    0.163068] pci 0000:00:04.1: reg 0x10: [io  0x2000-0x21ff]
[    0.164117] pci 0000:00:04.1: reg 0x14: [mem 0xc0036000-0xc0037fff]
[    0.166213] pci 0000:00:04.1: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.168344] pci 0000:00:04.2: [1af4:1009] type 00 class 0x010000
[    0.169213] pci 0000:00:04.2: reg 0x10: [io  0x2200-0x23ff]
[    0.171069] pci 0000:00:04.2: reg 0x14: [mem 0xc0038000-0xc0039fff]
[    0.172571] pci 0000:00:04.2: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.174052] pci 0000:00:04.3: [1af4:1009] type 00 class 0x010000
[    0.175213] pci 0000:00:04.3: reg 0x10: [io  0x2400-0x25ff]
[    0.176117] pci 0000:00:04.3: reg 0x14: [mem 0xc003a000-0xc003bfff]
[    0.177565] pci 0000:00:04.3: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.179700] pci 0000:00:05.0: [8086:100f] type 00 class 0x020000
[    0.181146] pci 0000:00:05.0: reg 0x10: [mem 0xc0000000-0xc001ffff]
[    0.182115] pci 0000:00:05.0: reg 0x14: [mem 0xc0020000-0xc002ffff]
[    0.183114] pci 0000:00:05.0: reg 0x18: [io  0x2680-0x2687]
[    0.184441] pci 0000:00:05.0: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.186322] pci 0000:00:06.0: [14e4:4331] type 00 class 0x028000
[    0.187315] pci 0000:00:06.0: reg 0x10: [mem 0xc0030000-0xc0033fff 64bit]
[    0.188711] pci 0000:00:06.0: enabling Extended Tags
[    0.190667] pci 0000:00:06.0: supports D1 D2
[    0.191005] pci 0000:00:06.0: PME# supported from D0 D3hot D3cold
[    0.193662] pci 0000:00:1f.0: [8086:7000] type 00 class 0x060100
[    0.195530] pci 0000:00:1f.0: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.197096] pci_bus 0000:00: on NUMA node 0
[    0.197192] ACPI: PCI: Interrupt link LNKA configured for IRQ 5
[    0.198100] ACPI: PCI: Interrupt link LNKB configured for IRQ 6
[    0.199098] ACPI: PCI: Interrupt link LNKC configured for IRQ 7
[    0.200097] ACPI: PCI: Interrupt link LNKD configured for IRQ 10
[    0.201097] ACPI: PCI: Interrupt link LNKE configured for IRQ 11
[    0.202087] ACPI: PCI: Interrupt link LNKF configured for IRQ 0
[    0.203004] ACPI: PCI: Interrupt link LNKF disabled
[    0.204086] ACPI: PCI: Interrupt link LNKG configured for IRQ 0
[    0.205004] ACPI: PCI: Interrupt link LNKG disabled
[    0.206086] ACPI: PCI: Interrupt link LNKH configured for IRQ 0
[    0.207004] ACPI: PCI: Interrupt link LNKH disabled
[    0.208146] vgaarb: loaded
[    0.209023] pps_core: LinuxPPS API ver. 1 registered
[    0.210004] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.211008] PTP clock support registered
[    0.212111] NetLabel: Initializing
[    0.212833] NetLabel:  domain hash size = 128
[    0.213004] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.214019] NetLabel:  unlabeled traffic allowed by default
[    0.215027] PCI: Using ACPI for IRQ routing
[    0.216005] PCI: pci_cache_line_size set to 64 bytes
[    0.216283] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0, 0, 0, 0, 0, 0
[    0.217004] hpet0: 8 comparators, 32-bit 16.777216 MHz counter
[    0.221037] clocksource: Switched to clocksource hpet
[    0.222221] pnp: PnP ACPI init
[    0.223226] system 00:02: [io  0x04d0-0x04d1] has been reserved
[    0.224489] system 00:02: [io  0x0400-0x0407] has been reserved
[    0.225750] system 00:02: [mem 0xe0000000-0xefffffff] has been reserved
[    0.227202] pnp: PnP ACPI: found 8 devices
[    0.233482] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.235342] NET: Registered PF_INET protocol family
[    0.236432] IP idents hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.238089] tcp_listen_portaddr_hash hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.239838] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.241435] TCP established hash table entries: 1024 (order: 1, 8192 bytes, linear)
[    0.243061] TCP bind hash table entries: 1024 (order: 1, 8192 bytes, linear)
[    0.244550] TCP: Hash tables configured (established 1024 bind 1024)
[    0.245907] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.247275] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.248764] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.250198] pci 0000:00:04.0: BAR 6: assigned [mem 0xc003c000-0xc003c7ff pref]
[    0.251722] pci 0000:00:04.1: BAR 6: assigned [mem 0xc003c800-0xc003cfff pref]
[    0.253223] pci 0000:00:04.2: BAR 6: assigned [mem 0xc003d000-0xc003d7ff pref]
[    0.254741] pci 0000:00:04.3: BAR 6: assigned [mem 0xc003d800-0xc003dfff pref]
[    0.256247] pci 0000:00:05.0: BAR 6: assigned [mem 0xc003e000-0xc003e7ff pref]
[    0.257767] pci 0000:00:1f.0: BAR 6: assigned [mem 0xc003e800-0xc003efff pref]
[    0.259263] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
[    0.260575] pci_bus 0000:00: resource 5 [io  0x0d00-0x1fff window]
[    0.261875] pci_bus 0000:00: resource 6 [io  0x2000-0x26bf window]
[    0.263170] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xc01fffff window]
[    0.264625] pci_bus 0000:00: resource 8 [mem 0x800000000-0x81fffffff window]
[    0.266403] pci 0000:00:1f.0: Activating ISA DMA hang workarounds
[    0.267976] PCI: CLS 256 bytes, default 64
[    0.268918] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 163840 ms ovfl timer
[    0.270735] Initialise system trusted keyrings
[    0.272214] workingset: timestamp_bits=62 max_order=15 bucket_order=0
[    0.274979] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.276372] 9p: Installing v9fs 9p2000 file system support
[    0.289885] Key type asymmetric registered
[    0.290784] Asymmetric key parser 'x509' registered
[    0.292142] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    0.293796] ACPI: button: Power Button [PWRF]
[    0.295322] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[    0.297273] virtio-pci 0000:00:04.1: virtio_pci: leaving for legacy driver
[    0.299138] virtio-pci 0000:00:04.2: virtio_pci: leaving for legacy driver
[    0.300933] virtio-pci 0000:00:04.3: virtio_pci: leaving for legacy driver
[    0.302689] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.304318] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    0.306199] 00:04: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    0.308013] 00:05: ttyS2 at I/O 0x3e8 (irq = 4, base_baud = 115200) is a 16550A
[    0.309821] 00:06: ttyS3 at I/O 0x2e8 (irq = 3, base_baud = 115200) is a 16550A
[    0.311811] Non-volatile memory driver v1.3
[    0.313957] loop: module loaded
[    0.315775] virtio_blk virtio0: [vda] 16960 512-byte logical blocks (8.68 MB/8.28 MiB)
[    0.320293] e1000: Intel(R) PRO/1000 Network Driver
[    0.321376] e1000: Copyright (c) 1999-2006 Intel Corporation.
[    0.732765] e1000 0000:00:05.0 eth0: (PCI:33MHz:32-bit) 00:a0:98:8a:05:71
[    0.734328] e1000 0000:00:05.0 eth0: Intel(R) PRO/1000 Network Connection
[    0.736209] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    0.738352] i8042: Warning: Keylock active
[    0.740427] serio: i8042 KBD port at 0x60,0x64 irq 1
[    0.741601] serio: i8042 AUX port at 0x60,0x64 irq 12
[    0.743719] rtc_cmos 00:07: registered as rtc0
[    0.744969] rtc_cmos 00:07: alarms up to one day, y3k, 114 bytes nvram
[    0.746696] Initializing XFRM netlink socket
[    0.747782] NET: Registered PF_INET6 protocol family
[    0.749267] Segment Routing with IPv6
[    0.750181] In-situ OAM (IOAM) with IPv6
[    0.751169] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.752712] NET: Registered PF_PACKET protocol family
[    0.753914] 9pnet: Installing 9P2000 support
[    0.757318] registered taskstats version 1
[    0.758309] Loading compiled-in X.509 certificates
[    0.759653] printk: console [netcon0] enabled
[    0.760693] netconsole: network logging started
[    0.761788] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    0.763928] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    0.765440] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[    0.767898] cfg80211: failed to load regulatory.db
[    0.770665] VFS: Mounted root (squashfs filesystem) readonly on device 254:0.
[    0.772464] devtmpfs: mounted
[    0.773270] Freeing unused kernel image (initmem) memory: 724K
[    0.774522] Write protecting the kernel read-only data: 12288k
[    0.776131] Freeing unused kernel image (text/rodata gap) memory: 2044K
[    0.777605] Freeing unused kernel image (rodata/data gap) memory: 476K
[    0.778966] Run /sbin/init as init process
[    0.779845]   with arguments:
[    0.779846]     /sbin/init
[    0.779846]   with environment:
[    0.779847]     HOME=/
[    0.779847]     TERM=linux
[    0.779848]     BOOT_IMAGE=(host)/usr/local/share/wifibox/vmlinuz
[    0.779849]     modules=squashfs
[    2.662585] wl: loading out-of-tree module taints kernel.
[    2.662593] wl: module license 'MIXED/Proprietary' taints kernel.
[    2.662594] Disabling lock debugging due to kernel taint
[    2.666704] wl 0000:00:06.0: can't derive routing for PCI INT A
[    2.666708] wl 0000:00:06.0: PCI INT A: not connected
[    2.796902] wl 0000:00:06.0: MSI supported: true
[    2.797320] wl 0000:00:06.0: (MSI) allocated 1 IRQ vectors
[    2.797323] wl 0000:00:06.0: (MSI) requesting IRQ: 40
[    2.826170] wlan0: Broadcom BCM4331 802.11 Hybrid Wireless Controller 6.30.223.271 (r587334)
[    2.826173] 

- /var/run/wifibox/appliance/log/messages

Jul 30 22:47:38 wifibox syslog.info syslogd started: BusyBox v1.35.0
Jul 30 22:47:38 wifibox daemon.info supervise-daemon[782]: Supervisor command line: supervise-daemon wpa_supplicant --start --respawn-delay 2 --respawn-max 5 --respawn-period 1800 /sbin/wpa_supplicant -- -iwlan0 -c/etc/wpa_supplicant/wpa_supplicant.conf 
Jul 30 22:47:38 wifibox daemon.info supervise-daemon[786]: Child command line: /sbin/wpa_supplicant -iwlan0 -c/etc/wpa_supplicant/wpa_supplicant.conf 
Jul 30 22:47:44 wifibox daemon.info supervise-daemon[930]: Supervisor command line: supervise-daemon uds_passthru --start --respawn-delay 2 --respawn-max 5 --respawn-period 1800 /sbin/uds_passthru -- 
Jul 30 22:47:44 wifibox daemon.info supervise-daemon[934]: Child command line: /sbin/uds_passthru 
Jul 30 22:47:44 wifibox daemon.info : starting pid 937, tty '': '/sbin/openrc default'
Jul 30 22:47:44 wifibox daemon.debug uds_passthru[934]: Configuration: network=10.0.0.1:255.255.255.0, sockets=[path=/var/run/wpa_supplicant/wlan0,user=root,group=0,mode=770,port=1200 path=/var/run/wpa_supplicant/p2p-dev-wlan0,user=root,group=0,mode=770,port=1201]
Jul 30 22:47:44 wifibox daemon.info uds_passthru[934]: Associating 10.0.0.1:1200 (10.0.0.1:255.255.255.0) with /var/run/wpa_supplicant/wlan0 (/tmp/tmp.hpCGcE/tmp.aFcCeC)
Jul 30 22:47:44 wifibox daemon.warn uds_passthru[934]: /var/run/wpa_supplicant/p2p-dev-wlan0 is not available, skipping.
Jul 30 22:47:44 wifibox daemon.info uds_passthru[934]: Waiting for PID 945 to stop.
Jul 30 22:47:44 wifibox cron.info crond[994]: crond (busybox 1.35.0) started, log level 8
Jul 30 22:47:44 wifibox daemon.info udhcpd[1047]: started, v1.35.0
Jul 30 22:47:44 wifibox daemon.err udhcpd[1047]: can't open '/var/lib/misc/udhcpd.leases': No such file or directory
Jul 30 22:47:45 wifibox daemon.info : starting pid 1054, tty '/dev/ttyS0': '/sbin/getty -L ttyS0 115200 vt100'
Jul 30 22:55:54 wifibox auth.info login[1054]: root login on 'ttyS0'

Additional context

Let me know if you need any other information.

Have you tried to turn it on and off?

pgj commented 1 year ago

Thanks for the report. Just to double check: How did you configure the suspend to RAM for the FreeBSD host? It may happen that you will have to stop wifibox completely before suspending and restart it after resume. The net/wifibox-core port lets you configure the way how suspend/resume situations should be handled, it might be worth trying.

venoom27 commented 1 year ago

I was able to suspend and wake back up by putting the following lines in the /usr/local/etc/devd/wifibox.conf . I got this from https://xyinn.org/md/freebsd/wifibox which is looks like he got from you.

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Suspend";
        action "logger 'Stopping wifibox before suspend' && /usr/local/sbin/wifibox stop && /etc/rc.suspend acpi $notify";
};

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Resume";
        action "/etc/rc.resume acpi $notify && logger 'Starting wifibox after resume and getting IP via DHCP' && /usr/local/sbin/wifibox start && /sbin/dhclient wifibox0";
};

Then I put the system to sleep by issuing acpiconf -s 3

Its takes longer to wake up which I am assuming is the wifibox starting back up. But once it back up the wlan0 within wifibox will not ping google. I can ping the router but when I ping google I get ping: bad address 'www.google.com'

Here is the ifconfig within wifibox console.

wlan0     Link encap:Ethernet  HWaddr A8:BB:CF:22:EA:A6
          inet6 addr: fe80::aabb:cfff:fe22:eaa6/64 Scope:Link
          UP BROADCAST MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:3533
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
          Interrupt:40

I also tried

service netif stop
service wifibox restart
service netif start

Still will not ping google. I then have to reboot the computer to get the wifibox to ping google again.

pgj commented 1 year ago

Using wifibox stop and then wifibox start destroys the wifibox0 networking interface so it should be reconfigured by service netif restart wifibox0 in order to make it work again (there is no need for a complete reboot). But that is why I implemented wifibox stop guest and wifibox start guest extension where the networking interface is left intact and does not require a reconfiguration upon restart. Please try that version.

venoom27 commented 1 year ago

I tried service netif restart after resuming and the wifbox console still comes back with

wifibox:~# ping www.google.com
ping: bad address 'www.google.com'

I added /etc/rc.d/netif restart to /usr/local/etc/devd/wifibox.conf so it looks like this

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Suspend";
        action "logger 'Stopping wifibox before suspend' && /usr/local/sbin/wifibox stop && /etc/rc.suspend acpi $notify";
};

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Resume";
        action "/etc/rc.resume acpi $notify && logger 'Starting wifibox after resume and getting IP via DHCP' && /usr/local/sbin/wifibox start && /etc/rc.d/netif restart && /sbin/dhclient wifibox0";
};

I still get

wifibox:~# ping www.google.com
ping: bad address 'www.google.com'

after resuming and waking up.

pgj commented 1 year ago

The service netif restart wifibox0 command has to be issued on the FreeBSD host. The guest does not have a netif service but networking. Independently of that, if the guest cannot communicate with the Internet after resume, a reason could be that you will have to stop the guest, reload (unload and then load again) the vmm kernel module on host and restart the guest. This is what wifibox restart vmm can do for you while leaving the wifibox0 interface intact. (That is what I have also been using on my notebook.)

pgj commented 1 year ago

Note that if you have configured the net/wifibox-core port properly, that is all you need in /usr/local/etc/devd/wifibox.conf, the rest is handed by the wifibox service:

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Suspend";
        action "/etc/rc.suspend acpi $notify && service wifibox suspend";
};
venoom27 commented 1 year ago

I original had

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Suspend";
        action "/etc/rc.suspend acpi $notify && service wifibox suspend";
};

in my /usr/local/etc/devd/wifibox.conf when I opened the ticket. When I make config the net/wifibox-core I have the RECOVER_SUSPEND_GUEST selected. Should I pick the RECOVER_RESTART_VMM instead?

pgj commented 1 year ago

Yes, please try RECOVER_RESTART_VMM.

venoom27 commented 1 year ago

I complied wifibox-core with the RECOVER_RESTART_VMM flag and change the /usr/local/etc/devd/wifibox.conf to

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Suspend";
        action "/etc/rc.suspend acpi $notify && service wifibox suspend";
};

I then suspended the computer with acpiconf -s 3 which suspended it. Then when I wake it the screen freezes on on console text and I have to force shutdown.

pgj commented 1 year ago

Okay, thanks for testing. Based on what you wrote, I believe the problem is that the kernel crashes on reloading the vmm kernel module. We could try to investigate the details (and validate this theory) in the following way.

It is expected that the whole procedure will not go through. Try to identify in which step the computer crashes and collect logs and data about the details of the crash.

pgj commented 1 year ago

If I recall correctly, this does not matter. The procedure tries to model how RECOVER_RESTART_VMM works and the goal is to walk it through step-by-step and troubleshoot.

venoom27 commented 1 year ago
service wifibox stop
# service wifibox stop
Stopping wifibox.......OK

# wifibox start && service netif restart wifibox0
Starting wifibox.......OK
Stopping Network: wifibox0.
wifibox0: flags=8802<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether 58:9c:fc:00:34:21
        id 00:00:00:00:00:00 priority 32768 hellotime 2 fwddelay 15
        maxage 20 holdcnt 6 proto rstp maxaddr 2000 timeout 1200
        root id 00:00:00:00:00:00 priority 32768 ifcost 0 port 0
        member: tap0 flags=143<LEARNING,DISCOVER,AUTOEDGE,AUTOPTP>
                ifmaxaddr 0 port 4 priority 128 path cost 2000000
        groups: bridge
        nd6 options=9<PERFORMNUD,IFDISABLED>
Starting Network: wifibox0.
wifibox0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether 58:9c:fc:00:34:21
        inet 10.0.0.165 netmask 0xffffff00 broadcast 10.0.0.255
        id 00:00:00:00:00:00 priority 32768 hellotime 2 fwddelay 15
        maxage 20 holdcnt 6 proto rstp maxaddr 2000 timeout 1200
        root id 00:00:00:00:00:00 priority 32768 ifcost 0 port 0
        member: tap0 flags=143<LEARNING,DISCOVER,AUTOEDGE,AUTOPTP>
                ifmaxaddr 0 port 4 priority 128 path cost 2000000
        groups: bridge
        nd6 options=9<PERFORMNUD,IFDISABLED>

#acpiconf -s 3

It freezes on resume and looks like the image below. resume

After hard shutdown

# wifibox stop
Stopping wifibox.......OK

#kldunload vmm

#kldload vmm

# wifibox start && service netif restart wifibox0
Starting wifibox.......OK
Stopping Network: wifibox0.
wifibox0: flags=8802<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether 58:9c:fc:00:34:21
        id 00:00:00:00:00:00 priority 32768 hellotime 2 fwddelay 15
        maxage 20 holdcnt 6 proto rstp maxaddr 2000 timeout 1200
        root id 00:00:00:00:00:00 priority 32768 ifcost 0 port 0
        member: tap0 flags=143<LEARNING,DISCOVER,AUTOEDGE,AUTOPTP>
                ifmaxaddr 0 port 4 priority 128 path cost 2000000
        groups: bridge
        nd6 options=9<PERFORMNUD,IFDISABLED>
Starting Network: wifibox0.
wifibox0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether 58:9c:fc:00:34:21
        inet 10.0.0.165 netmask 0xffffff00 broadcast 10.0.0.255
        id 00:00:00:00:00:00 priority 32768 hellotime 2 fwddelay 15
        maxage 20 holdcnt 6 proto rstp maxaddr 2000 timeout 1200
        root id 00:00:00:00:00:00 priority 32768 ifcost 0 port 0
        member: tap0 flags=143<LEARNING,DISCOVER,AUTOEDGE,AUTOPTP>
                ifmaxaddr 0 port 4 priority 128 path cost 2000000
        groups: bridge
        nd6 options=9<PERFORMNUD,IFDISABLED>
pgj commented 1 year ago

Thanks for providing these details. The part after the freeze and the hard shutdown is not relevant. We would like to avoid the freeze so what is important here is to see what we can do before it happens.

If the machine freezes on resume, it might make sense to stop Wifibox before suspending the machine. Even unload the vmm kernel module. That is, the updated procedure to test is now as follows.

  1. Stop the wifibox service so that wifibox will not be tried for resume: service wifibox stop.
  2. Start wifibox manually: wifibox start && service netif restart wifibox0.
  3. Stop wifibox: wifibox stop guest.
  4. Suspend the machine.
  5. Resume the computer and reload vmm: kldunload vmm && kldload vmm.
  6. Restart wifibox: wifibox start guest.

Alternatively, step 3 could be adjusted like this:

3/a. Stop wifibox: wifibox stop guest. 3/b. Unload the vmm kernel module: kldunload vmm.

And step 5 would change accordingly:

  1. Resume the computer and load vmm: kldload vmm.
venoom27 commented 1 year ago
service wifibox stop
Stopping wifibox .......OK
wifibox start && service netif restart wifibox0
Starting wifibox.......OK
Stopping Network: wifibox0
Starting Network wifibox0
wifibox stop guest
Stopping wifibox .......OK
acpiconf -s 3

goes to sleep resume it wakes back up

kldunload vmm && kldload vmm
kldunload vmm && kldload vmm

So now the only issue I am having after those chain of commands is that wifibox console can ping google but the host can't ping google. It says ping: Unknown host.

pgj commented 1 year ago

It would be useful to see the dmesg output from the guest after the resume to understand why the network connection is dead. It is very likely that the card is not accessible for bhyve any more but it would be good to have a confirmation about that.

How does it change if you run kldunload vmm before suspending the computer?

By the way, did you run the combination of the kldunload and kldload commands twice?

venoom27 commented 1 year ago

It seems if I run wifibox stop then kldunload before acpiconf -s 3 and then once it is resumed running kldload vmm then wifibox start it brings it back correctly.

pgj commented 1 year ago

All right. In the dev branch of the freebsd-wifibox-ports repository, I have updated the net/wifibox-core port to support this configuration: please try it by selecting the RECOVER_SUSPEND_VMM option.

venoom27 commented 1 year ago

I downloaded the new update to the dev branch and selected the RECOVER_SUSPEND_VMM flag in wifibox-core and installed it. When I suspend the computer by running acpiconf -s 3 it suspends but when I resume it it freezes on the console display as before.

pgj commented 1 year ago

Could you please include logs from /var/log/wifibox.log? The service wifibox suspend command may not be called on the suspend event. That is because it needs the wifibox.conf under /usr/local/etc/devd. Unfortunately, the FreeBSD base system only supports the resume event for services.

pgj commented 1 year ago

For testing individually, you can also try to simulate the behavior by calling service wifibox suspend before acpiconf -s 3 and then service wifibox resume after resume.

venoom27 commented 1 year ago

Running service wifibox suspend first before running acpiconf -s 3 works. It resumes correctly. I guess I could just write small script that runs those two commands to suspend it. Thanks for your help.

pgj commented 1 year ago

Ideally, you should not have to. The wifibox.conf for devd shall do that for you exactly. Maybe it would be worth to investigate why devd does not call service wifibox suspend? The contents should be like that:

notify 11 {
        match "system"          "ACPI";
        match "subsystem"       "Suspend";
        action "/etc/rc.suspend acpi $notify && service wifibox suspend";
};
venoom27 commented 1 year ago

My wifibox.conf is just like you recommend when I did the test before. Are there any logs you would like me to pull?

pgj commented 1 year ago

The /var/log/wifibox.log could actually show (with DEBUG verbosity level) what commands were (or were not) run on suspend:

grep -F "with arguments" /var/log/wifibox.log

Do you have devd enabled?

service devd status
pgj commented 1 year ago

It is worth to check if /etc/devd.conf has the following lines (uncommented):

options {
        # Each "directory" directive adds a directory to the list of
        # directories that we scan for files.  Files are loaded in the order
        # that they are returned from readdir(3).  The rule-sets are combined
        # to create a DFA that's used to match events to actions.
        directory "/etc/devd";
        directory "/usr/local/etc/devd";
        pid-file "/var/run/devd.pid";
...
}

This default setting assumes that you have the third-party software and its configuration installed under /usr/local but I guess that holds for you.

venoom27 commented 1 year ago

My /etc/devd.conf is just like you posted.

options {
        # Each "directory" directive adds a directory to the list of
        # directories that we scan for files.  Files are loaded in the order
        # that they are returned from readdir(3).  The rule-sets are combined
        # to create a DFA that's used to match events to actions.
        directory "/etc/devd";
        directory "/usr/local/etc/devd";
        pid-file "/var/run/devd.pid";
pgj commented 1 year ago

Could you please answer my other comment above? Without that, I cannot help. Currently, I have no idea why the suspend event is not handled properly on your system.

venoom27 commented 1 year ago

Sorry I didn't see that response. Here is the info. Thanks again for your help.

grep -F "with arguments" /var/log/wifibox.log
# grep -F "with arguments" /var/log/wifibox.log
2023-08-12T21:18:30-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-12T21:18:30-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-12T21:20:28-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop
2023-08-12T21:20:32-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-12T21:20:33-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-12T21:23:09-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-12T21:23:09-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-13T20:45:20-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-13T20:45:20-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-13T20:48:45-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop vmm
2023-08-13T20:49:15-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop vmm
2023-08-13T20:49:15-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start vmm
2023-08-13T20:49:16-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-13T20:49:32-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start vmm
2023-08-13T20:54:16-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop
2023-08-15T19:29:42-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-15T19:29:42-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-15T19:37:34-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop
2023-08-17T21:05:51-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-17T21:05:51-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-17T21:12:27-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop
2023-08-17T21:14:43-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-17T21:14:43-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-19T07:44:23-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-19T07:44:23-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-19T07:53:04-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-19T07:53:04-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
# service devd status
devd is running as pid 1699.
pgj commented 1 year ago

In wifibox.log, I can see stop vmm and start vmm commands although only once and in a very quick succession. They correspond to calling service wifibox suspend and then service wifibox resume so that part seems to be working. But we should align the timestamps with the invocations of acpiconf -s 3 and the subsequent wake-up.

What does the command grep -F "acpi[" /var/log/messages say? It should be displaying the suspend and resume times as handled by the acpi process. I have the following output but this might just be due to some local configuration:

Aug 20 01:18:58 XXX acpi[43580]: suspend at 20230820 01:18:58
Aug 20 01:19:18 XXX acpi[43768]: resumed at 20230820 01:19:18

which have the corresponding matching lines in wifibox.log:

2023-08-20T01:19:13+0200 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: stop vmm
2023-08-20T01:19:18+0200 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start vmm

In your log it appears like stop vmm and start vmm were called twice, kind of a result of some race. Whether does it always happen? Also, for the second start vmm, the _manage_vm (internal) command is not happening which suggests an error.

venoom27 commented 1 year ago

Here is the results of # grep -F "acpi[" /var/log/messages

Aug 12 21:21:39 foo acpi[3824]: suspend at 20230812 21:21:39
Aug 12 21:25:34 foo acpi[2369]: suspend at 20230812 21:25:34
Aug 13 20:48:56 foo acpi[2527]: suspend at 20230813 20:48:56
Aug 13 20:49:15 foo acpi[2623]: resumed at 20230813 20:49:15
Aug 19 07:51:36 foo acpi[2765]: suspend at 20230819 07:51:36

I also ran another acpiconf -s 3 so it would show up in the logs. Here is the new result. It resumed correctly but froze on console and had to be hard shutdown.

grep -F "with arguments" /var/log/wifibox.log

2023-08-19T21:16:53-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-19T21:16:53-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm
2023-08-19T21:26:08-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: start
2023-08-19T21:26:08-0400 DEBUG Program started as /usr/local/sbin/wifibox, with arguments: _manage_vm

# grep -F "acpi[" /var/log/messages

Aug 19 21:23:57 foo acpi[2669]: suspend at 20230819 21:23:57
pgj commented 1 year ago

Based on those logs, even though service wifibox suspend might be called, stop vmm is not issued. What do you have in /usr/local/etc/rc.d/wifibox?

grep -E "(suspend|resume)_cmd" /usr/local/etc/rc.d/wifibox
venoom27 commented 1 year ago
# grep -E "(suspend|resume)_cmd" /usr/local/etc/rc.d/wifibox
suspend_cmd="${command} stop vmm"
resume_cmd="${command} start vmm"
pgj commented 1 year ago

Do you have the wifibox service enabled?

service -e | grep -F wifibox
venoom27 commented 1 year ago
# service -e | grep -F wifibox
/usr/local/etc/rc.d/wifibox
pgj commented 1 year ago

I do not see the reason why the suspend event would not be handled properly. Could you please try all this with a clean install, if possible? I will also do the same to see if my system has any non-standard setting that may influence the results.

venoom27 commented 1 year ago

Unfortunately, I cannot easily do a clean install on this system and I didn't get a snapshot in before I started with wifibox.

pgj commented 1 year ago

For what it is worth, with enough RAM you can just run FreeBSD without having it installed to a hard disk. That is what I usually do to test Wifibox with different versions. The only requirement that it will need a wired connection to download the files from the Internet when the file system in the memory is being populated.

For example, for 13.2-RELEASE, something along these lines:

venoom27 commented 1 year ago

Thanks so much for the info and I will try it out this evening.

venoom27 commented 1 year ago

I started it this evening and was building the wifibox port but my time for my only hardline connect ran out so I will have to try again tomorrow. I will keep you updated.

venoom27 commented 1 year ago

OK I tired again and I was able to install Wifibox/Alpine but when I got through the middle of wifibox-core it errored out saying "kernel: pid 74380 (getty), kid 0, uid 0, was killed: failed to reclaim memory" so I am not able to install it through the live cd.

For the purpose of troubleshooting I will do a fresh install in the next day or two and see if it works. I will let you know my results. Also you wouldn't know a link to how to backup zfs and then restore it would you?

venoom27 commented 1 year ago

Great news I did a clean install and suspend works with wifibox installed. I figured out how to install it on another dataset so I still have the old install. I did not set up any passthru. Please let me know how you want to proceed.

pgj commented 1 year ago

Sorry that I did not respond to your earlier comment, doing it now.

I got through the middle of wifibox-core it errored out saying "kernel: pid 74380 (getty), kid 0, uid 0, was killed: failed to reclaim memory" so I am not able to install it through the live cd.

That is probably because the RAM is not enough to hold all the files and run programs. I have 8 GB in my machine and I have to clean up the file system in memory regularly to avoid similar situations.

you wouldn't know a link to how to backup zfs and then restore it would you?

Unfortunately I do not use ZFS for performance reasons. I deemed that with 8 GB it is not worth the trouble. I do not get in touch with other FreeBSD installations these days so I do not have a working knowledge of these operations. But it is good that you could figure it out!

pgj commented 1 year ago

Great news I did a clean install and suspend works with wifibox installed. I figured out how to install it on another dataset so I still have the old install. I did not set up any passthru. Please let me know how you want to proceed.

Configure SUSPEND_VMM as the recovery method, enable the wifibox service, set up the passthrough. Test if it the wireless connection works and then try it with suspend/resume.

venoom27 commented 1 year ago

I got the passthru up and running and the SUSPEND_VMM flag on and it suspends and wakes the way it should.

pgj commented 1 year ago

That is great news! I can now cut a new release with this fix.

pgj commented 1 year ago

The support for SUSPEND_VMM has been added to main in d5f07d2f. I am now closing the ticket.