Auteur: Alessandro Vesely Datum: Aan: Devuan users Onderwerp: [DNG] Boot hangs with new kernel
Hi all,
today the new Linux version (6.1.0-27-amd64) froze twice. The following are three snippets from kern.log. Two failed, the third one succeeded. The line with "tomoyo" seems to mark the beginning of the shutdown , issued via ctrl-alt-del.
The "random key value" thing is coming from the wifi access point, and doesn't happen on the second boot.
hpasmxld is an obsolete module by HP. It allows me to access some data (using hpasmcli).
How can I find what is going wrong? I have a crashkernel= directive on the grub command line. Actually two of them, an ancient one on /etc/default/grub (now removed) and another one added by /etc/default/grub.d/kdump-tools.cfg. However, I'm not clear what data could be retrieved from it.
Other logs have data related to the time interval before the freeze, but they are successful loading or shutting down notices.
The only not-so-good stuff I see are the iptables blocked packets. I don't think incoming packets can hang the boot, albeit at early stages. Yet, the boot hangs there...?
I also found an exception, which didn't interrupt the boot process, which I paste after the three snippet. Where should I send it?
Best
Ale
Nov 10 14:11:14 6 north kernel: [ 25.005503] IPv6: ADDRCONF(NETDEV_CHANGE): eth0r: link becomes ready
Nov 10 14:11:14 4 north kernel: [ 25.005505] , receive & transmit flow control ON
Nov 10 14:11:16 6 north kernel: [ 26.661131] PPP BSD Compression module registered
Nov 10 14:11:16 6 north kernel: [ 26.667067] PPP Deflate Compression module registered
Nov 10 14:11:18 6 north kernel: [ 29.068581] 8021q: adding VLAN 0 to HW filter on device eth1r
Nov 10 14:11:18 6 north kernel: [ 29.324552] 8021q: adding VLAN 0 to HW filter on device eth2r
Nov 10 14:11:20 6 north kernel: [ 30.773145] e1000e 0000:11:00.1 eth1r: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Nov 10 14:11:20 6 north kernel: [ 30.773313] IPv6: ADDRCONF(NETDEV_CHANGE): eth1r: link becomes ready
Nov 10 14:11:20 6 north kernel: [ 31.405140] e1000e 0000:11:00.0 eth2r: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Nov 10 14:11:20 6 north kernel: [ 31.405278] IPv6: ADDRCONF(NETDEV_CHANGE): eth2r: link becomes ready
Nov 10 14:11:42 7 north kernel: [ 53.456616] ipset drop:IN=ppp0 OUT= MAC= SRC=95.214.27.33 DST=94.198.96.78 LEN=40 TOS=0x00 PREC=0x00 TTL=241 ID=54321 PROTO=TCP SPT=60367 DPT=8081 WINDOW=65535 RES=0x00 SYN URGP=0
Nov 10 14:12:17 7 north kernel: [ 88.309706] ipset drop:IN=ppp0 OUT= MAC= SRC=95.214.27.33 DST=94.198.96.73 LEN=40 TOS=0x00 PREC=0x00 TTL=246 ID=54321 PROTO=TCP SPT=42393 DPT=8081 WINDOW=65535 RES=0x00 SYN URGP=0
Nov 10 14:13:47 4 172.25.197.110 kernel: wl0: random key value: 3FD54515923936E1C30D7D0BC29BE3ED695C4F1CFBCC048A0FF1F275A9C4C1EC
Nov 10 14:14:17 6 north kernel: [ 207.500969] Not activating Mandatory Access Control as /sbin/tomoyo-init does not exist.
Nov 10 14:14:21 6 north kernel: [ 211.596609] device eth0r left promiscuous mode
Nov 10 14:14:21 6 north kernel: [ 211.768749] e1000e 0000:11:00.1 eth1r: NIC Link is Down
Nov 10 14:14:21 6 north kernel: [ 211.932750] e1000e 0000:11:00.0 eth2r: NIC Link is Down
Nov 10 14:16:30 4 north kernel: [ 33.492479] , receive & transmit flow control ON
Nov 10 14:16:30 6 north kernel: [ 33.492485] IPv6: ADDRCONF(NETDEV_CHANGE): eth0r: link becomes ready
Nov 10 14:16:40 6 north kernel: [ 43.522825] PPP BSD Compression module registered
Nov 10 14:16:40 6 north kernel: [ 43.528935] PPP Deflate Compression module registered
Nov 10 14:16:43 6 north kernel: [ 45.900469] 8021q: adding VLAN 0 to HW filter on device eth1r
Nov 10 14:16:43 6 north kernel: [ 46.156483] 8021q: adding VLAN 0 to HW filter on device eth2r
Nov 10 14:16:44 6 north kernel: [ 47.565084] e1000e 0000:11:00.1 eth1r: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Nov 10 14:16:44 6 north kernel: [ 47.565235] IPv6: ADDRCONF(NETDEV_CHANGE): eth1r: link becomes ready
Nov 10 14:16:45 6 north kernel: [ 48.285081] e1000e 0000:11:00.0 eth2r: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Nov 10 14:16:45 6 north kernel: [ 48.285217] IPv6: ADDRCONF(NETDEV_CHANGE): eth2r: link becomes ready
Nov 10 14:17:17 7 north kernel: [ 80.181277] ipset drop:IN=ppp0 OUT= MAC= SRC=80.66.75.207 DST=94.198.96.73 LEN=40 TOS=0x08 PREC=0x20 TTL=239 ID=646 PROTO=TCP SPT=64136 DPT=32775 WINDOW=1024 RES=0x00 SYN URGP=0
Nov 10 14:17:40 6 north kernel: [ 103.556175] Not activating Mandatory Access Control as /sbin/tomoyo-init does not exist.
Nov 10 14:17:45 6 north kernel: [ 108.664504] device eth0r left promiscuous mode
Nov 10 14:17:46 6 north kernel: [ 108.832686] e1000e 0000:11:00.1 eth1r: NIC Link is Down
Nov 10 14:17:46 6 north kernel: [ 108.996699] e1000e 0000:11:00.0 eth2r: NIC Link is Down
Nov 10 14:17:52 6 north kernel: [ 115.125672] x86/PAT: hpasmxld:1488 freeing invalid memtype [mem 0xfff7f000-0xfff82fff]
Nov 10 14:21:47 6 north kernel: [ 24.832743] IPv6: ADDRCONF(NETDEV_CHANGE): eth0r: link becomes ready
Nov 10 14:21:47 4 north kernel: [ 24.832747] , receive & transmit flow control ON
Nov 10 14:21:49 6 north kernel: [ 26.517887] PPP BSD Compression module registered
Nov 10 14:21:49 6 north kernel: [ 26.524028] PPP Deflate Compression module registered
Nov 10 14:21:51 6 north kernel: [ 28.984756] 8021q: adding VLAN 0 to HW filter on device eth1r
Nov 10 14:21:52 6 north kernel: [ 29.240455] 8021q: adding VLAN 0 to HW filter on device eth2r
Nov 10 14:21:53 6 north kernel: [ 30.625065] e1000e 0000:11:00.1 eth1r: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Nov 10 14:21:53 6 north kernel: [ 30.625223] IPv6: ADDRCONF(NETDEV_CHANGE): eth1r: link becomes ready
Nov 10 14:21:54 6 north kernel: [ 31.325349] e1000e 0000:11:00.0 eth2r: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Nov 10 14:21:54 6 north kernel: [ 31.325486] IPv6: ADDRCONF(NETDEV_CHANGE): eth2r: link becomes ready
Nov 10 14:22:16 7 north kernel: [ 53.544823] ipset drop:IN=eth1r OUT= MAC=00:26:55:e0:d0:e8:c0:06:c3:e9:d3:4e:08:00 SRC=85.209.11.73 DST=192.168.1.254 LEN=44 TOS=0x00 PREC=0x00 TTL=247 ID=57915 PROTO=TCP SPT=50491 DPT=33092 WINDOW=1024 RES=0x00 SYN URGP=0
Nov 10 14:22:40 7 north kernel: [ 77.506441] ipset drop:IN=ppp0 OUT= MAC= SRC=95.214.27.38 DST=94.198.96.75 LEN=49 TOS=0x08 PREC=0x20 TTL=241 ID=54321 PROTO=UDP SPT=43348 DPT=5683 LEN=29
Nov 10 14:22:41 6 north kernel: [ 78.181249] perf: interrupt took too long (2521 > 2500), lowering kernel.perf_event_max_sample_rate
Nov 10 14:55:58 4 north kernel: [ 2075.240903] ------------[ cut here ]------------
Nov 10 14:55:58 4 north kernel: [ 2075.240912] Can't enable IRQ/MSI because no handler is installed
Nov 10 14:55:58 4 north kernel: [ 2075.240972] WARNING: CPU: 5 PID: 3136 at drivers/gpu/drm/radeon/r100.c:727 r100_irq_set+0x93/0xb0 [
radeon]
Nov 10 14:55:58 4 north kernel: [ 2075.241058] Modules linked in: fuse nf_conntrack_netlink nfnetlink_queue xt_nat xt_mark xt_NFQUEUE xt_hashlimit xt_tcpudp nft_compat xt_set nf_nat_ftp xt_addrtype xt_LOG nf_log_syslog ipt_REJECT nf_reject_ipv4 xt_multiport xt_state xt_limit xt_conntrack nf_conntrack_ftp ppp_deflate bsd_comp ppp_async pppoe pppox ppp_generic slhc 8021q garp stp mrp llc ip_set_hash_net ip_set iptable_raw iptable_mangle iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 iptable_filter ip_tables x_tables cpufreq_userspace cpufreq_powersave cpufreq_ondemand cpufreq_conservative nf_tables libcrc32c nfnetlink loop parport_pc ppdev lp parport amdgpu gpu_sched drm_buddy radeon video wmi drm_display_helper cec rc_core drm_ttm_helper ttm ipmi_ssif drm_kms_helper coretemp sha512_ssse3 sha512_generic drm cdc_acm sha256_ssse3 sha1_ssse3 i2c_algo_bit evdev iTCO_wdt serio_raw pcspkr intel_pmc_bxt hpwdt iTCO_vendor_support i5000_edac hpilo watchdog acpi_ipmi button i5k_amb ipmi_si ipmi_devintf ipmi_msghandler
Nov 10 14:55:58 4 north kernel: [ 2075.241158] ext4 crc16 mbcache jbd2 crc32c_generic hid_generic usbhid hid sd_mod t10_pi crc64_rocksoft crc64 sr_mod crc_t10dif cdrom crct10dif_generic sg crct10dif_common ata_generic ata_piix uhci_hcd ehci_pci hpsa ehci_hcd libata psmouse scsi_transport_sas usbcore scsi_mod lpc_ich e1000e bnx2 usb_common scsi_common floppy
Nov 10 14:55:58 4 north kernel: [ 2075.241199] CPU: 5 PID: 3136 Comm: Xorg Not tainted 6.1.0-27-amd64 #1 Debian 6.1.115-1
Nov 10 14:55:58 4 north kernel: [ 2075.241204] Hardware name: HP ProLiant ML350 G5, BIOS D21 05/02/2011
Nov 10 14:55:58 4 north kernel: [ 2075.241206] RIP: 0010:r100_irq_set+0x93/0xb0 [radeon]
Nov 10 14:55:58 4 north kernel: [ 2075.241264] Code: 5b c3 cc cc cc cc 8b 93 34 1c 00 00 85 d2 74 c2 eb bd 8b 97 30 1c 00 00 85 d2 74 aa eb a5 48 c7 c7 58 8f bf c0 e8 ed d7 38 ce <0f> 0b 31 d2 48 8b 83 f0 01 00 00 89 50 40 b8 ea ff ff ff 5b c3 cc
Nov 10 14:55:58 4 north kernel: [ 2075.241268] RSP: 0018:ffffb53941abb9f0 EFLAGS: 00010086
Nov 10 14:55:58 4 north kernel: [ 2075.241271] RAX: 0000000000000000 RBX: ffff956c50d40000 RCX: 0000000000000027
Nov 10 14:55:58 4 north kernel: [ 2075.241274] RDX: ffff956d18d603a8 RSI: 0000000000000001 RDI: ffff956d18d603a0
Nov 10 14:55:58 4 north kernel: [ 2075.241276] RBP: 0000000000000000 R08: 0000000000000000 R09: ffffb53941abb868
Nov 10 14:55:58 4 north kernel: [ 2075.241278] R10: 0000000000000003 R11: ffffffff908d4488 R12: 0000000000000097
Nov 10 14:55:58 4 north kernel: [ 2075.241280] R13: ffff956c50d41c04 R14: ffff956c583e8144 R15: 0000000000000000
Nov 10 14:55:58 4 north kernel: [ 2075.241283] FS: 00007f30589eaac0(0000) GS:ffff956d18d40000(0000) knlGS:0000000000000000
Nov 10 14:55:58 4 north kernel: [ 2075.241286] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Nov 10 14:55:58 4 north kernel: [ 2075.241289] CR2: 00007f30595390a0 CR3: 00000001092d8000 CR4: 00000000000006e0
Nov 10 14:55:58 4 north kernel: [ 2075.241292] Call Trace:
Nov 10 14:55:58 4 north kernel: [ 2075.241297] <TASK>
Nov 10 14:55:58 4 north kernel: [ 2075.241301] ? __warn+0x7d/0xc0
Nov 10 14:55:58 4 north kernel: [ 2075.241308] ? r100_irq_set+0x93/0xb0 [radeon]
Nov 10 14:55:58 4 north kernel: [ 2075.241363] ? report_bug+0xe2/0x150
Nov 10 14:55:58 4 north kernel: [ 2075.241368] ? handle_bug+0x41/0x70
Nov 10 14:55:58 4 north kernel: [ 2075.241374] ? exc_invalid_op+0x13/0x60
Nov 10 14:55:58 4 north kernel: [ 2075.241377] ? asm_exc_invalid_op+0x16/0x20
Nov 10 14:55:58 4 north kernel: [ 2075.241383] ? r100_irq_set+0x93/0xb0 [radeon]
Nov 10 14:55:58 4 north kernel: [ 2075.241438] radeon_enable_vblank_kms+0x50/0x80 [radeon]
Nov 10 14:55:58 4 north kernel: [ 2075.241485] drm_vblank_enable+0xdd/0x180 [drm]
Nov 10 14:55:58 4 north kernel: [ 2075.241567] drm_vblank_get+0x96/0xe0 [drm]
Nov 10 14:55:58 4 north kernel: [ 2075.241618] drm_wait_vblank_ioctl+0xf1/0x710 [drm]
Nov 10 14:55:58 4 north kernel: [ 2075.241668] ? avc_has_extended_perms+0x24c/0x550
Nov 10 14:55:58 4 north kernel: [ 2075.241672] ? tomoyo_init_request_info+0x95/0xc0
Nov 10 14:55:58 4 north kernel: [ 2075.241676] ? tomoyo_path_number_perm+0x88/0x200
Nov 10 14:55:58 4 north kernel: [ 2075.241682] ? drm_legacy_modeset_ctl_ioctl+0x110/0x110 [drm]
Nov 10 14:55:58 4 north kernel: [ 2075.241731] drm_ioctl_kernel+0xc9/0x170 [drm]
Nov 10 14:55:58 4 north kernel: [ 2075.241778] drm_ioctl+0x22f/0x410 [drm]
Nov 10 14:55:58 4 north kernel: [ 2075.241823] ? drm_legacy_modeset_ctl_ioctl+0x110/0x110 [drm]
Nov 10 14:55:58 4 north kernel: [ 2075.241874] radeon_drm_ioctl+0x49/0x80 [radeon]
Nov 10 14:55:58 4 north kernel: [ 2075.241919] __x64_sys_ioctl+0x90/0xd0
Nov 10 14:55:58 4 north kernel: [ 2075.241925] do_syscall_64+0x55/0xb0
Nov 10 14:55:58 4 north kernel: [ 2075.241929] ? do_syscall_64+0x61/0xb0
Nov 10 14:55:58 4 north kernel: [ 2075.241933] ? __fget_light+0x9d/0x100
Nov 10 14:55:58 4 north kernel: [ 2075.241938] ? ksys_write+0xd4/0xf0
Nov 10 14:55:58 4 north kernel: [ 2075.241943] ? exit_to_user_mode_prepare+0x40/0x1e0
Nov 10 14:55:58 4 north kernel: [ 2075.241948] ? syscall_exit_to_user_mode+0x1e/0x40
Nov 10 14:55:58 4 north kernel: [ 2075.241953] ? do_syscall_64+0x61/0xb0
Nov 10 14:55:58 4 north kernel: [ 2075.241957] ? ptep_set_access_flags+0x2e/0x40
Nov 10 14:55:58 4 north kernel: [ 2075.241961] ? wp_page_reuse+0x60/0x70
Nov 10 14:55:58 4 north kernel: [ 2075.241966] ? do_wp_page+0x1e3/0x380
Nov 10 14:55:58 4 north kernel: [ 2075.241970] ? do_iter_write+0x81/0x1d0
Nov 10 14:55:58 4 north kernel: [ 2075.241974] ? ktime_get_ts64+0x46/0xe0
Nov 10 14:55:58 4 north kernel: [ 2075.241980] ? _copy_to_user+0x21/0x30
Nov 10 14:55:58 4 north kernel: [ 2075.241983] ? put_timespec64+0x3a/0x60
Nov 10 14:55:58 4 north kernel: [ 2075.241987] ? exit_to_user_mode_prepare+0x40/0x1e0
Nov 10 14:55:58 4 north kernel: [ 2075.241991] ? syscall_exit_to_user_mode+0x1e/0x40
Nov 10 14:55:58 4 north kernel: [ 2075.241996] ? do_syscall_64+0x61/0xb0
Nov 10 14:55:58 4 north kernel: [ 2075.242000] ? handle_mm_fault+0xdb/0x2d0
Nov 10 14:55:58 4 north kernel: [ 2075.242005] ? do_user_addr_fault+0x1b0/0x550
Nov 10 14:55:58 4 north kernel: [ 2075.242009] ? exit_to_user_mode_prepare+0x40/0x1e0
Nov 10 14:55:58 4 north kernel: [ 2075.242013] entry_SYSCALL_64_after_hwframe+0x6e/0xd8
Nov 10 14:55:58 4 north kernel: [ 2075.242017] RIP: 0033:0x7f3058d1ccdb
Nov 10 14:55:58 4 north kernel: [ 2075.242020] Code: 00 48 89 44 24 18 31 c0 48 8d 44 24 60 c7 04 24 10 00 00 00 48 89 44 24 08 48 8d 44 24 20 48 89 44 24 10 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 1c 48 8b 44 24 18 64 48 2b 04 25 28 00 00
Nov 10 14:55:58 4 north kernel: [ 2075.242023] RSP: 002b:00007ffd482f0990 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Nov 10 14:55:58 4 north kernel: [ 2075.242027] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f3058d1ccdb
Nov 10 14:55:58 4 north kernel: [ 2075.242029] RDX: 00007ffd482f0a50 RSI: 00000000c018643a RDI: 000000000000000d
Nov 10 14:55:58 4 north kernel: [ 2075.242032] RBP: 00007ffd482f0abc R08: 00007ffd482f0ac0 R09: 00007ffd482f0abc
Nov 10 14:55:58 4 north kernel: [ 2075.242034] R10: 00007ffd48374080 R11: 0000000000000246 R12: 00007ffd482f0a50
Nov 10 14:55:58 4 north kernel: [ 2075.242036] R13: 000000000000000d R14: 00000000c018643a R15: 0000000000000000
Nov 10 14:55:58 4 north kernel: [ 2075.242040] </TASK>
Nov 10 14:55:58 4 north kernel: [ 2075.242041] ---[ end trace 0000000000000000 ]---