search

LekKit / RVVM

The RISC-V Virtual Machine
GNU General Public License v3.0
876 stars 61 forks source link

Strange temporary `Cannot find device "enp0s1"` in RVVM with `-smp 2` #136

Closed fish4terrisa-MSDSM closed 2 months ago

fish4terrisa-MSDSM commented 2 months ago

Environment

Android 10, in Termux, the newest commit of RVVM(both the headless one and the x11 one), with Archlinux riscv as the guest

Strange behavior

The headless RVVM (in my archriscv-term) worked with network enabled by dhclient while boot. However, when I'm using RVVM with x11 in termux(not with proot or vnc, but with the app X Server in google play), I got the following failure log of dhclient while booting:

× dhclient@enp0s1.service - dhclient on enp0s1
     Loaded: loaded (/usr/lib/systemd/system/dhclient@.service; enabled; preset: disabled)
     Active: failed (Result: exit-code) since Sat 2024-06-29 10:55:13 CST; 1min 33s ago
   Duration: 2.451s
 Invocation: 2db6b1bf604249e6bed6af6ab17a741d
    Process: 249 ExecStart=/usr/bin/dhclient -pf /run/dhclient@enp0s1/dhclient.pid -d enp0s1 (code=exited, status=1/FAILURE)
   Main PID: 249 (code=exited, status=1/FAILURE)

6月 29 10:55:11 Archlinux-riscv64 systemd[1]: Started dhclient on enp0s1.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: Internet Systems Consortium DHCP Client 4.4.3-P1
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: Internet Systems Consortium DHCP Client 4.4.3-P1
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: Copyright 2004-2022 Internet Systems Consortium.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: All rights reserved.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: For info, please visit https://www.isc.org/software/dhcp/
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: Copyright 2004-2022 Internet Systems Consortium.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: All rights reserved.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: For info, please visit https://www.isc.org/software/dhcp/
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]:
6月 29 10:55:12 Archlinux-riscv64 dhclient[256]: Cannot find device "enp0s1"
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: Failed to get interface index: No such device
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: Failed to get interface index: No such device
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: If you think you have received this message due to a bug rather
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: than a configuration issue please read the section on submitting
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: bugs on either our web page at www.isc.org or in the README file
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: before submitting a bug.  These pages explain the proper
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: process and the information we find helpful for debugging.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: exiting.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]:
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: If you think you have received this message due to a bug rather
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: than a configuration issue please read the section on submitting
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: bugs on either our web page at www.isc.org or in the README file
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: before submitting a bug.  These pages explain the proper
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: process and the information we find helpful for debugging.
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]:
6月 29 10:55:12 Archlinux-riscv64 dhclient[249]: exiting.
6月 29 10:55:13 Archlinux-riscv64 systemd[1]: dhclient@enp0s1.service: Main process exited, code=exited, status=1/FAILURE
6月 29 10:55:13 Archlinux-riscv64 systemd[1]: dhclient@enp0s1.service: Failed with result 'exit-code'.

However, when I restarted dhclient manually (sudo systemctl restart dhclient@enp0s1), It simply worked fine. It seems that it took the system much longer time to detect and register the network card when running on RVVM with x11 support. And, the dmesg log in the guest in RVVM x11:

[    0.000000] Linux version 6.9.4-arch1-1 (linux@archlinux) (gcc (GCC) 14.1.1 20240522, GNU ld (GNU Binutils) 2.42.0) #1 SMP PREEMPT_DYNAMIC Fri, 14 Jun 2024 16:24:32 +0000
[    0.000000] random: crng init done
[    0.000000] Machine model: RVVM v0.7-dcd391a-dirty
[    0.000000] SBI specification v1.0 detected
[    0.000000] SBI implementation ID=0x1 Version=0x10002
[    0.000000] SBI TIME extension detected
[    0.000000] SBI IPI extension detected
[    0.000000] SBI RFENCE extension detected
[    0.000000] SBI SRST extension detected
[    0.000000] efi: UEFI not found.
[    0.000000] OF: reserved mem: 0x0000000080000000..0x000000008003ffff (256 KiB) nomap non-reusable mmode_resv0@80000000
[    0.000000] NUMA: No NUMA configuration found
[    0.000000] NUMA: Faking a node at [mem 0x0000000080000000-0x00000000ffffffff]
[    0.000000] NUMA: NODE_DATA [mem 0xffdf2740-0xffdf4fff]
[    0.000000] Zone ranges:
[    0.000000]   DMA32    [mem 0x0000000080000000-0x00000000ffffffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000080000000-0x000000008003ffff]
[    0.000000]   node   0: [mem 0x0000000080040000-0x00000000ffffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x00000000ffffffff]
[    0.000000] SBI HSM extension detected
[    0.000000] Falling back to deprecated "riscv,isa"
[    0.000000] riscv: base ISA extensions acdfim
[    0.000000] riscv: ELF capabilities acdfim
[    0.000000] percpu: Embedded 32 pages/cpu s93096 r8192 d29784 u131072
[    0.000000] pcpu-alloc: s93096 r8192 d29784 u131072 alloc=32*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1
[    0.000000] Kernel command line: earlyprintk rw root=/dev/nvme0n1p1  rootwait rootfstype=ext4 LANG=en_US.UTF-8 console=ttyS0
[    0.000000] Unknown kernel command line parameters "earlyprintk LANG=en_US.UTF-8", will be passed to user space.
[    0.000000] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    0.000000] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.000000] Fallback order for Node 0: 0
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 516096
[    0.000000] Policy zone: DMA32
[    0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
[    0.000000] Memory: 1842560K/2097152K available (11065K kernel code, 8131K rwdata, 10240K rodata, 6638K init, 655K bss, 254592K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] trace event string verifier disabled
[    0.000000] Dynamic Preempt: full
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=320 to nr_cpu_ids=2.
[    0.000000] rcu:     RCU priority boosting: priority 1 delay 500 ms.
[    0.000000]  Trampoline variant of Tasks RCU enabled.
[    0.000000]  Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 30 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.000000] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1.
[    0.000000] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1.
[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[    0.000000] riscv-intc: 64 local interrupts mapped
[    0.000000] riscv: providing IPIs using SBI IPI extension
[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    0.000000] clocksource: riscv_clocksource: mask: 0xffffffffffffffff max_cycles: 0x24e6a1710, max_idle_ns: 440795202120 ns
[    0.000018] sched_clock: 64 bits at 10MHz, resolution 100ns, wraps every 4398046511100ns
[    0.008151] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
[    0.011619] Console: colour dummy device 80x25
[    0.012504] Calibrating delay loop (skipped), value calculated using timer frequency.. 20.83 BogoMIPS (lpj=33333)
[    0.012596] pid_max: default: 32768 minimum: 301
[    0.013573] LSM: initializing lsm=capability,landlock,lockdown,yama,bpf
[    0.013998] landlock: Up and running.
[    0.014043] Yama: becoming mindful.
[    0.014205] LSM support for eBPF active
[    0.015058] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    0.015144] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    0.044149] riscv: ELF compat mode supported
[    0.044308] ASID allocator disabled (0 bits)
[    0.047532] rcu: Hierarchical SRCU implementation.
[    0.047603] rcu:     Max phase no-delay instances is 1000.
[    0.053533] EFI services will not be available.
[    0.057005] smp: Bringing up secondary CPUs ...
[    0.068160] smp: Brought up 1 node, 2 CPUs
[    0.079821] devtmpfs: initialized
[    0.093897] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6370867519511994 ns
[    0.094104] futex hash table entries: 512 (order: 3, 32768 bytes, linear)
[    0.096143] pinctrl core: initialized pinctrl subsystem
[    0.118733] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.121838] DMA: preallocated 256 KiB GFP_KERNEL pool for atomic allocations
[    0.122480] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    0.122928] audit: initializing netlink subsys (disabled)
[    0.125135] audit: type=2000 audit(0.019:1): state=initialized audit_enabled=0 res=1
[    0.129034] thermal_sys: Registered thermal governor 'fair_share'
[    0.129094] thermal_sys: Registered thermal governor 'bang_bang'
[    0.129132] thermal_sys: Registered thermal governor 'step_wise'
[    0.129159] thermal_sys: Registered thermal governor 'user_space'
[    0.129179] thermal_sys: Registered thermal governor 'power_allocator'
[    0.130843] cpuidle: using governor ladder
[    0.131194] cpuidle: using governor menu
[    0.496056] cpu1: Ratio of byte access time to unaligned word access is 0.22, unaligned accesses are slow
[    0.742804] cpu0: Ratio of byte access time to unaligned word access is 0.22, unaligned accesses are slow
[    0.830792] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
[    0.830922] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
[    0.830994] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
[    0.831031] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
[    0.838409] Demotion targets for Node 0: null
[    0.857040] ACPI: Interpreter disabled.
[    0.860666] iommu: Default domain type: Translated
[    0.860797] iommu: DMA domain TLB invalidation policy: lazy mode
[    0.875202] SCSI subsystem initialized
[    0.878261] libata version 3.00 loaded.
[    0.879552] usbcore: registered new interface driver usbfs
[    0.879935] usbcore: registered new interface driver hub
[    0.880289] usbcore: registered new device driver usb
[    0.881536] EDAC MC: Ver: 3.0.0
[    0.897447] NetLabel: Initializing
[    0.897538] NetLabel:  domain hash size = 128
[    0.897583] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.898555] NetLabel:  unlabeled traffic allowed by default
[    0.898792] mctp: management component transport protocol core
[    0.898843] NET: Registered PF_MCTP protocol family
[    0.902447] vgaarb: loaded
[    0.906964] clocksource: Switched to clocksource riscv_clocksource
[    0.913308] VFS: Disk quotas dquot_6.6.0
[    0.913729] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.916410] pnp: PnP ACPI: disabled
[    1.074898] NET: Registered PF_INET protocol family
[    1.077495] IP idents hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    1.186471] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)
[    1.186774] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    1.187004] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    1.187480] TCP bind hash table entries: 16384 (order: 7, 524288 bytes, linear)
[    1.187966] TCP: Hash tables configured (established 16384 bind 16384)
[    1.190307] MPTCP token hash table entries: 2048 (order: 3, 49152 bytes, linear)
[    1.190901] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)
[    1.192280] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)
[    1.193839] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    1.194192] NET: Registered PF_XDP protocol family
[    1.195209] PCI: CLS 0 bytes, default 64
[    1.198589] Trying to unpack rootfs image as initramfs...
[    1.213676] Initialise system trusted keyrings
[    1.214853] Key type blacklist registered
[    1.217697] workingset: timestamp_bits=41 max_order=19 bucket_order=0
[    1.218479] zbud: loaded
[    1.225409] fuse: init (API version 7.40)
[    1.230336] integrity: Platform Keyring initialized
[    1.230766] integrity: Machine keyring initialized
[    1.352679] Key type asymmetric registered
[    1.352820] Asymmetric key parser 'x509' registered
[    1.353758] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246)
[    1.356000] io scheduler mq-deadline registered
[    1.356108] io scheduler kyber registered
[    1.356386] io scheduler bfq registered
[    1.366182] riscv-plic c000000.plic: mapped 63 interrupts with 2 handlers for 4 contexts.
[    1.371208] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[    1.376749] SBI CPPC extension NOT detected!!
[    1.383608] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[    1.445723] printk: legacy console [ttyS0] disabled
[    1.448241] 10000000.uart: ttyS0 at MMIO 0x10000000 (irq = 12, base_baud = 2500000) is a 16550A
[    1.448737] printk: legacy console [ttyS0] enabled
[    1.458521] [drm] Initialized simpledrm 1.0.0 20200625 for 28000000.framebuffer on minor 0
[    1.462473] fbcon: Deferring console take-over
[    1.462591] simple-framebuffer 28000000.framebuffer: [drm] fb0: simpledrmdrmfb frame buffer device
[    1.468507] usbcore: registered new interface driver usbserial_generic
[    1.468725] usbserial: USB Serial support registered for generic
[    1.471220] goldfish_rtc 101000.rtc: registered as rtc0
[    1.471516] goldfish_rtc 101000.rtc: setting system clock to 2024-06-29T02:54:17 UTC (1719629657)
[    1.476409] EDAC DEVICE0: Giving out device to module Sifive ECC Manager controller sifive_edac.0: DEV sifive_edac.0 (INTERRUPT)
[    1.478309] ledtrig-cpu: registered to indicate activity on CPUs
[    1.479095] hid: raw HID events driver (C) Jiri Kosina
[    1.480644] riscv-pmu-sbi: SBI PMU extension is available
[    1.480914] riscv-pmu-sbi: 16 firmware and 2 hardware counters
[    1.480985] riscv-pmu-sbi: Perf sampling/filtering is not supported as sscof extension is not available
[    1.484238] drop_monitor: Initializing network drop monitor service
[    1.485396] NET: Registered PF_INET6 protocol family
[   27.345951] Freeing initrd memory: 160520K
[   27.587000] Segment Routing with IPv6
[   27.587628] RPL Segment Routing with IPv6
[   27.589506] In-situ OAM (IOAM) with IPv6
[   27.591243] NET: Registered PF_PACKET protocol family
[   27.688043] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level
[   27.690530] registered taskstats version 1
[   27.702572] Loading compiled-in X.509 certificates
[   27.730627] Loaded X.509 cert 'Build time autogenerated kernel key: 06ebd565c2af728cbdaae276281f1f112cef9039'
[   27.822162] zswap: loaded using pool zstd/zsmalloc
[   27.839031] Key type .fscrypt registered
[   27.839183] Key type fscrypt-provisioning registered
[   27.929613] clk: Disabling unused clocks
[   27.929859] PM: genpd: Disabling unused power domains
[   27.937765] Freeing unused kernel image (initmem) memory: 6636K
[   27.942532] Checked W+X mappings: passed, no W+X pages found
[   27.942720] rodata_test: all tests were successful
[   27.942895] Run /init as init process
[   27.942959]   with arguments:
[   27.943004]     /init
[   27.943034]     earlyprintk
[   27.943060]   with environment:
[   27.943084]     HOME=/
[   27.943108]     TERM=linux
[   27.943130]     LANG=en_US.UTF-8
[   30.635891] pci-host-generic 30000000.pci: host bridge /soc/pci@30000000 ranges:
[   30.636267] pci-host-generic 30000000.pci:       IO 0x0003000000..0x000300ffff -> 0x0000000000
[   30.636493] pci-host-generic 30000000.pci:      MEM 0x0040000000..0x007fffffff -> 0x0040000000
[   30.637284] pci-host-generic 30000000.pci: ECAM at [mem 0x30000000-0x3fffffff] for [bus 00-ff]
[   30.638450] pci-host-generic 30000000.pci: PCI host bridge to bus 0000:00
[   30.638572] pci_bus 0000:00: root bus resource [bus 00-ff]
[   30.638665] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
[   30.638720] pci_bus 0000:00: root bus resource [mem 0x40000000-0x7fffffff]
[   30.639151] pci 0000:00:00.0: [f15e:0000] type 00 class 0x060000 conventional PCI endpoint
[   30.640782] pci 0000:00:01.0: [10ec:8169] type 00 class 0x020000 conventional PCI endpoint
[   30.640948] pci 0000:00:01.0: BAR 1 [mem 0x40000000-0x400000ff]
[   30.641810] pci 0000:00:02.0: [144d:a809] type 00 class 0x010802 conventional PCI endpoint
[   30.641902] pci 0000:00:02.0: BAR 0 [mem 0x40004000-0x40007fff]
[   30.643414] pci 0000:00:02.0: BAR 0 [mem 0x40000000-0x40003fff]: assigned
[   30.643557] pci 0000:00:01.0: BAR 1 [mem 0x40004000-0x400040ff]: assigned
[   31.063565] nvme nvme0: pci function 0000:00:02.0
[   31.070250] nvme nvme0: Failed to read smart log (error 1)
[   31.084929] nvme nvme0: 1/0/0 default/read/poll queues
[   31.098270]  nvme0n1: p1
[   32.627795] EXT4-fs (nvme0n1p1): mounted filesystem 37bdb737-1cb0-45a4-a002-8893a2c63a1d r/w with ordered data mode. Quota mode: none.
[   33.821390] systemd[1]: systemd 256.1-1-arch-g34ba18b^ running in system mode (+PAM +AUDIT -SELINUX -APPARMOR -IMA +SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK +XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE)
[   33.821680] systemd[1]: Detected architecture riscv64.
[   33.841451] systemd[1]: Hostname set to <Archlinux-riscv64>.
[   35.457925] systemd[1]: bpf-restrict-fs: Failed to link program; assuming BPF LSM is not available.
[   38.836157] systemd[1]: Queued start job for default target Graphical Interface.
[   39.068388] systemd[1]: Created slice Slice /system/dhclient.
[   39.089432] systemd[1]: Created slice Slice /system/dirmngr.
[   39.123571] systemd[1]: Created slice Slice /system/getty.
[   39.155652] systemd[1]: Created slice Slice /system/gpg-agent.
[   39.173766] systemd[1]: Created slice Slice /system/gpg-agent-browser.
[   39.189804] systemd[1]: Created slice Slice /system/gpg-agent-extra.
[   39.207376] systemd[1]: Created slice Slice /system/gpg-agent-ssh.
[   39.221935] systemd[1]: Created slice Slice /system/keyboxd.
[   39.236810] systemd[1]: Created slice Slice /system/modprobe.
[   39.251443] systemd[1]: Created slice Slice /system/serial-getty.
[   39.264680] systemd[1]: Created slice User and Session Slice.
[   39.270080] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[   39.274615] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[   39.285228] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[   39.288548] systemd[1]: Expecting device /dev/ttyS0...
[   39.290693] systemd[1]: Expecting device /dev/ttyS1...
[   39.292714] systemd[1]: Expecting device /dev/ttyS2...
[   39.294818] systemd[1]: Expecting device /dev/ttyS3...
[   39.297170] systemd[1]: Reached target Local Encrypted Volumes.
[   39.299792] systemd[1]: Reached target Local Integrity Protected Volumes.
[   39.302631] systemd[1]: Reached target Path Units.
[   39.305194] systemd[1]: Reached target Remote Encrypted Volumes.
[   39.307599] systemd[1]: Reached target Remote File Systems.
[   39.309992] systemd[1]: Reached target Slice Units.
[   39.312446] systemd[1]: Reached target Swaps.
[   39.315054] systemd[1]: Reached target Local Verity Protected Volumes.
[   39.320672] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[   39.331203] systemd[1]: Listening on LVM2 poll daemon socket.
[   39.357252] systemd[1]: Listening on Process Core Dump Socket.
[   39.374539] systemd[1]: Listening on Credential Encryption/Decryption.
[   39.381136] systemd[1]: Listening on Journal Socket (/dev/log).
[   39.386966] systemd[1]: Listening on Journal Sockets.
[   39.392770] systemd[1]: Listening on Network Service Netlink Socket.
[   39.395649] systemd[1]: TPM PCR Measurements was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
[   39.396182] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
[   39.400052] systemd[1]: Listening on udev Control Socket.
[   39.404670] systemd[1]: Listening on udev Kernel Socket.
[   39.409684] systemd[1]: Listening on User Database Manager Socket.
[   39.512514] systemd[1]: Mounting Huge Pages File System...
[   39.594918] systemd[1]: Mounting POSIX Message Queue File System...
[   39.724159] systemd[1]: Mounting Kernel Debug File System...
[   39.753145] systemd[1]: Mounting Kernel Trace File System...
[   39.817236] systemd[1]: Mounting Temporary Directory /tmp...
[   39.874311] systemd[1]: Starting Create List of Static Device Nodes...
[   39.940109] systemd[1]: Starting Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling...
[   39.979443] systemd[1]: Starting Load Kernel Module configfs...
[   40.083599] systemd[1]: Starting Load Kernel Module dm_mod...
[   40.115246] systemd[1]: Starting Load Kernel Module drm...
[   40.225992] systemd[1]: Starting Load Kernel Module efi_pstore...
[   40.328109] systemd[1]: Starting Load Kernel Module fuse...
[   40.357822] device-mapper: uevent: version 1.0.3
[   40.361333] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
[   40.489141] systemd[1]: Starting Load Kernel Module loop...
[   40.492576] systemd[1]: Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67).
[   40.557603] systemd[1]: Starting Journal Service...
[   40.630784] loop: module loaded
[   40.645978] systemd[1]: Starting Load Kernel Modules...
[   40.691277] systemd[1]: Starting Generate network units from Kernel command line...
[   40.727364] systemd[1]: TPM PCR Machine ID Measurement was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
[   40.780268] systemd[1]: Starting Remount Root and Kernel File Systems...
[   40.802129] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
[   40.904821] systemd[1]: Starting Load udev Rules from Credentials...
[   40.968646] systemd-journald[153]: Collecting audit messages is disabled.
[   41.091942] systemd[1]: Starting Coldplug All udev Devices...
[   41.289541] systemd[1]: Mounted Huge Pages File System.
[   41.303206] systemd[1]: Mounted POSIX Message Queue File System.
[   41.346454] systemd[1]: Mounted Kernel Debug File System.
[   41.355941] systemd[1]: Mounted Kernel Trace File System.
[   41.362439] systemd[1]: Mounted Temporary Directory /tmp.
[   41.374355] systemd[1]: Finished Create List of Static Device Nodes.
[   41.388397] systemd[1]: Finished Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling.
[   41.403402] systemd[1]: modprobe@configfs.service: Deactivated successfully.
[   41.410463] systemd[1]: Finished Load Kernel Module configfs.
[   41.423017] systemd[1]: modprobe@dm_mod.service: Deactivated successfully.
[   41.429568] systemd[1]: Finished Load Kernel Module dm_mod.
[   41.441986] systemd[1]: modprobe@drm.service: Deactivated successfully.
[   41.448401] systemd[1]: Finished Load Kernel Module drm.
[   41.467183] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
[   41.473865] systemd[1]: Finished Load Kernel Module efi_pstore.
[   41.485544] systemd[1]: modprobe@fuse.service: Deactivated successfully.
[   41.491944] systemd[1]: Finished Load Kernel Module fuse.
[   41.503705] systemd[1]: modprobe@loop.service: Deactivated successfully.
[   41.510076] systemd[1]: Finished Load Kernel Module loop.
[   41.531287] systemd[1]: Finished Load Kernel Modules.
[   41.542466] systemd[1]: Finished Generate network units from Kernel command line.
[   41.553492] systemd[1]: Finished Remount Root and Kernel File Systems.
[   41.558679] systemd[1]: Started Journal Service.
[   42.526493] systemd-journald[153]: Received client request to flush runtime journal.
[   51.051374] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[   51.111026] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[   51.112197] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
[   51.132001] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[   51.132252] cfg80211: failed to load regulatory.db
[   57.909868] i2c_hid_of 0-0009: supply vdd not found, using dummy regulator
[   57.911140] i2c_hid_of 0-0008: supply vdd not found, using dummy regulator
[   57.913101] i2c_hid_of 0-000a: supply vdd not found, using dummy regulator
[   57.914016] i2c_hid_of 0-000a: supply vddl not found, using dummy regulator
[   57.916044] i2c_hid_of 0-0008: supply vddl not found, using dummy regulator
[   57.917335] i2c_hid_of 0-0009: supply vddl not found, using dummy regulator
[   58.154281] input: hid-over-i2c 0001:0001 as /devices/platform/soc/10030000.i2c/i2c-0/0-0009/0018:0001:0001.0001/input/input0
[   58.160106] hid-generic 0018:0001:0001.0001: input,hidraw0: I2C HID v1.00 Mouse [hid-over-i2c 0001:0001] on 0-0009
[   58.164975] input: hid-over-i2c 0001:0001 as /devices/platform/soc/10030000.i2c/i2c-0/0-000a/0018:0001:0001.0002/input/input1
[   58.166998] hid-generic 0018:0001:0001.0002: input,hidraw1: I2C HID v1.00 Mouse [hid-over-i2c 0001:0001] on 0-000a
[   58.171951] input: hid-over-i2c 0001:0001 as /devices/platform/soc/10030000.i2c/i2c-0/0-0008/0018:0001:0001.0003/input/input2
[   58.200385] hid-generic 0018:0001:0001.0003: input,hidraw2: I2C HID v1.00 Keyboard [hid-over-i2c 0001:0001] on 0-0008
[   58.547102] r8169 0000:00:01.0 eth0: RTL8169s, 06:f5:7a:80:47:8f, XID 008, IRQ 19
[   58.547276] r8169 0000:00:01.0 eth0: jumbo features [frames: 7146 bytes, tx checksumming: ok]
[   59.030877] mousedev: PS/2 mouse device common for all mice
[   59.124384] r8169 0000:00:01.0 enp0s1: renamed from eth0
[   62.499452] fbcon: Taking over console
[   62.508467] Console: switching to colour frame buffer device 80x30

Also, I'm using the same image in headless RVVM and x11 RVVM, so it seems not to be the problem of image or dhclient(?)

Expected behavior

The guest can detect and enable network while booting in RVVM with x11.

fish4terrisa-MSDSM commented 2 months ago

Found Out: That seems to be a bug of termux or android. The headless rvvm also didn't worked in termux. (Also Stange. I'm using the same binary in termux and archriscv-term, but got different result in the same device...... The difference is that RVVM in termux lost the log in dmesg of 

[   51.975145] Generic FE-GE Realtek PHY r8169-0-8:00: attached PHY driver (mii_bus:phy_addr=r8169-0-8:00, irq=MAC)
[   52.100125] r8169 0000:00:01.0 enp0s1: Link is Up - 10Gbps/Full - flow control off
[   52.100576] r8169 0000:00:01.0 enp0s1: No phy led trigger registered for speed(10000)

But that's not the problem of RVVM, sorry for bothering)

fish4terrisa-MSDSM commented 2 months ago

is that due to the slight difference of termux and android environment? If so, then it seems to be a bug of incompatibility of RVVM on termux. However, although I cleared the LD_PRELOAD, the problem still existed.

fish4terrisa-MSDSM commented 2 months ago

Got the result: I used -smp 2 in termux and -smp 4 in archriscv-term, and that's the flag affected the detect of r8169 and dhclient. However, there seems nearly no performance difference between -smp 2 guest and -smp 4 guest (not enough to even make enabling network fail) I can't get the reason of it.

Way to reproduce

I'm not sure about whether it's possible to reproduce it in your environment, as it seems to be a problem only happen in quite-limit-resource devices.

LekKit commented 2 months ago 
[   51.975145] Generic FE-GE Realtek PHY r8169-0-8:00: attached PHY driver (mii_bus:phy_addr=r8169-0-8:00, irq=MAC)
[   52.100125] r8169 0000:00:01.0 enp0s1: Link is Up - 10Gbps/Full - flow control off
[   52.100576] r8169 0000:00:01.0 enp0s1: No phy led trigger registered for speed(10000)

According to this log, r8169 driver is loaded very late in the boot process (Later than dhclient starts). See this: 

[   39.068388] systemd[1]: Created slice Slice /system/dhclient.

Systemd starts the dhclient service earlier than the NIC driver loads. This may be due to r8169 driver not being included in initramfs. The fact that it reproduces under different circumstances and not under others affects this, but seems not to be the cause as I see it.

Try running mkinitcpio -P under root and see if it resolves the issue. Additionally, I use systemd-networkd and never saw such issues there so maybe it's caused by dhclient.

fish4terrisa-MSDSM commented 2 months ago

Find out that adding r8169 in the MODULES line in /etc/mkinitcpio.conf fix ed this problem, i can even get network in the initramfs now. The strange behavior may be caused by the smp racing problem, which made r8169 loaded after dhclient started. (However, after running mkinitcpio,my initramfs cannot find the nvme disk now,as what i posted in the Arch Linux on RISC-V channel. And removing the r8169 in /etc/mkinitcpio.conf didn't worked, so it isnt cause by r8169 module. Hoping for your help. Much thanks)