[SOLVED]nmcli hangs when executed (sometimes)

kocheng · 2022-10-22 03:47:35

Sometimes, when I executed nmcli, it hangs (or maybe actually loading for a long time, I don't know). After nmcli hangs, sudo also hangs, and my laptop shutdown process (executed with shutdown now) also freeze that I need to hold power button down to force shutdown my computer. I only do some basic stuff with nmcli, e.g. checking connection or connecting to wifi. Is there are someone of you who encountered the same problem? Can you explain to me what's happening? And more importantly, how to solve it?

Last edited by kocheng (2022-11-21 09:28:58)

ewaller · 2022-10-22 14:05:00

Don't use nmcli much. Does it ever recover if you just leave it? Are you using the console, or are you using any GUI environment? Can you change to a different console using Ctrl-Alt-F2 (or F3 through F6)?
When it hangs, are the LEDs on your keyboard flashing? That is indicative of a kernel panic.
If you can change consoles, can you log in? Can you check your memory with free in said console?
After reboot, look at the logs of the previous session with journalctl -b-1 and see if there are any clues at the end of the log.

kocheng · 2022-10-23 13:36:09

Hello, today (Oct 23 2022), I think the problem somehow has gone... I don't know how and why. I'll let you know if I encounter this problem again. For now, I will mark this as solved. Thanks for all of your support .

kocheng · 2022-11-11 07:44:54

Hmm, I encountered the same issue again
It seems that the condition for reproducing the problem is kind of random...

Last edited by kocheng (2022-11-11 07:45:37)

kocheng · 2022-11-17 04:14:26

Today I face this problem again, and this is the output of journalctl -b-1

http://ix.io/4gVu

But I don't really know where is the problematic line.

NOTE:
I use nmcli on command line. When it hangs, changing tty works fine. I can login to different tty session. free output also doesn't seems like there is problem in memory...

Last edited by kocheng (2022-11-26 14:28:12)

d.ALT · 2022-11-17 07:47:44

Begin following logs before attempting nmcli connection; start connection via nmcli (another Terminal) and check what's going on while connection attempt.

# journalctl -f

seth · 2022-11-17 08:45:34

Output of

hostnamectl

and in doubt set a static hostname, https://wiki.archlinux.org/title/Networ … e_hostname

kocheng · 2022-11-17 10:30:00

seth wrote:

Output of
hostnamectl
and in doubt set a static hostname, https://wiki.archlinux.org/title/Networ … e_hostname

$ hostnamectl 
 Static hostname: archlinux
       Icon name: computer-laptop
         Chassis: laptop ?
      Machine ID: 6914da91d4684fefa0fc046061910ee1
         Boot ID: bb7889cb9108484f9e7ed611df66be4d
Operating System: Arch Linux                      
          Kernel: Linux 6.0.8-arch1-1
    Architecture: x86-64
 Hardware Vendor: ASUSTeK COMPUTER INC.
  Hardware Model: X302UV
Firmware Version: X302UV.203

kocheng · 2022-11-17 11:21:09

d.ALT wrote:

Begin following logs before attempting nmcli connection; start connection via nmcli (another Terminal) and check what's going on while connection attempt.
# journalctl -f

$ journalctl -f
Nov 17 17:40:18 archlinux NetworkManager[366]: <info>  [1668681618.4020] manager: NetworkManager state is now DISCONNECTED
Nov 17 17:40:18 archlinux NetworkManager[366]: <info>  [1668681618.4063] device (wlp3s0): supplicant interface state: completed -> disconnected
Nov 17 17:40:18 archlinux NetworkManager[366]: <info>  [1668681618.4064] device (p2p-dev-wlp3s0): supplicant management interface state: completed -> disconnected
Nov 17 17:40:18 archlinux NetworkManager[366]: <info>  [1668681618.4070] device (wlp3s0): supplicant interface state: disconnected -> interface_disabled
Nov 17 17:40:18 archlinux NetworkManager[366]: <info>  [1668681618.4071] device (p2p-dev-wlp3s0): supplicant management interface state: disconnected -> interface_disabled
Nov 17 17:40:18 archlinux NetworkManager[366]: <info>  [1668681618.4074] device (wlp3s0): supplicant interface state: interface_disabled -> disconnected
Nov 17 17:40:18 archlinux NetworkManager[366]: <info>  [1668681618.4075] device (p2p-dev-wlp3s0): supplicant management interface state: interface_disabled -> disconnected
Nov 17 17:40:28 archlinux systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Nov 17 17:40:28 archlinux audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 17 17:40:28 archlinux kernel: audit: type=1131 audit(1668681628.008:95): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 17 17:43:02 archlinux NetworkManager[366]: <info>  [1668681782.8334] agent-manager: agent[d60720f45c1dca47,:1.60/nmcli-connect/1000]: agent registered
Nov 17 17:43:02 archlinux kernel: audit: type=1111 audit(1668681782.836:96): pid=366 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="my_wifi_ssid" pid=9700 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 17 17:43:02 archlinux audit[366]: USYS_CONFIG pid=366 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="my_wifi_ssid" pid=9700 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 17 17:43:02 archlinux NetworkManager[366]: <info>  [1668681782.8384] device (wlp3s0): Activation: starting connection 'my_wifi_ssid' (66549a1f-7441-4af6-8019-f26f28527f56)
Nov 17 17:43:02 archlinux NetworkManager[366]: <info>  [1668681782.8385] audit: op="connection-activate" uuid="66549a1f-7441-4af6-8019-f26f28527f56" name="my_wifi_ssid" pid=9700 uid=1000 result="success"
Nov 17 17:43:02 archlinux NetworkManager[366]: <info>  [1668681782.8386] device (wlp3s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 17 17:43:02 archlinux NetworkManager[366]: <info>  [1668681782.8389] manager: NetworkManager state is now CONNECTING

And there's no more...
So I guess NetworkManager is just randomly failed when attempting to connect to my wifi (?)

Oh, and btw, is it good to use pastebin.com? I have read about that from, uhh, seth's signature about how to upload text...

Last edited by kocheng (2022-11-17 13:26:54)

seth · 2022-11-17 15:21:54

pastebin.com is discouraged because it's not accessible across the globe, you can use 0x0.st or ix.io

The journal snippet shows you being disconnected at 17:40 for undisclosed reasons (the journal segment is too short) and then start a connection at 17:43:02 w/ unknown success (the journal segment is too short… )
I had hoped that it's a hostname resolution issue, because "sudo also hangs"

So in your older journal we've

Nov 17 08:09:16 archlinux polkitd[468]: Registered Authentication Agent for unix-process:1063:41448 (system bus name :1.19 [nmcli --ask c up my_wifi_ssid], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Nov 17 08:09:16 archlinux NetworkManager[374]: <info>  [1668647356.2180] agent-manager: agent[0db7b0ad2a5273d4,:1.19/nmcli-connect/1000]: agent registered
Nov 17 08:09:16 archlinux NetworkManager[374]: <info>  [1668647356.2184] policy: auto-activating connection 'my_wifi_ssid' (967ed77e-1237-4398-9698-f10041fb287a)
Nov 17 08:09:16 archlinux NetworkManager[374]: <info>  [1668647356.2200] device (wlp3s0): Activation: starting connection 'my_wifi_ssid' (967ed77e-1237-4398-9698-f10041fb287a)
Nov 17 08:09:16 archlinux NetworkManager[374]: <info>  [1668647356.2210] device (wlp3s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 17 08:09:16 archlinux NetworkManager[374]: <info>  [1668647356.2223] manager: NetworkManager state is now CONNECTING
Nov 17 08:09:41 archlinux polkitd[468]: Unregistered Authentication Agent for unix-process:1063:41448 (system bus name :1.19, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Nov 17 08:10:44 archlinux systemd-logind[357]: The system will reboot now!
Nov 17 08:10:44 archlinux systemd-logind[357]: System is rebooting.
Nov 17 08:10:44 archlinux systemd[1]: Stopping Session 1 of User galih...

What made me wonder whether this was a broken session - and lo and behold:

Nov 17 08:06:41 archlinux audit: PROCTITLE proctitle="/usr/bin/ly"
Nov 17 08:06:41 archlinux ly[384]: pam_unix(ly:session): session opened for user galih(uid=1000) by (uid=0)

Don't use that.
If you reasonably don't want to use a big fat DM, try to log into a console and use startx/xinit (and see the last link below)
"ly" has a trackrecord for trashing your (session) bus (what you can hardly google for because "ly" is conveniantly not a google-able term…)

kocheng · 2022-11-18 14:13:01

Ok, now I only use startx for login. The problem still appear
journalctl -f when testing for the problem shows this:

Nov 18 20:28:01 archlinux NetworkManager[366]: <info>  [1668778081.2328] manager: NetworkManager state is now DISCONNECTED
Nov 18 20:28:01 archlinux NetworkManager[366]: <info>  [1668778081.2376] device (wlp3s0): supplicant interface state: completed -> disconnected
Nov 18 20:28:01 archlinux NetworkManager[366]: <info>  [1668778081.2378] device (p2p-dev-wlp3s0): supplicant management interface state: completed -> disconnected
Nov 18 20:28:01 archlinux NetworkManager[366]: <info>  [1668778081.2384] device (wlp3s0): supplicant interface state: disconnected -> interface_disabled
Nov 18 20:28:01 archlinux NetworkManager[366]: <info>  [1668778081.2385] device (p2p-dev-wlp3s0): supplicant management interface state: disconnected -> interface_disabled
Nov 18 20:28:01 archlinux NetworkManager[366]: <info>  [1668778081.2389] device (wlp3s0): supplicant interface state: interface_disabled -> disconnected
Nov 18 20:28:01 archlinux NetworkManager[366]: <info>  [1668778081.2390] device (p2p-dev-wlp3s0): supplicant management interface state: interface_disabled -> disconnected
Nov 18 20:28:02 archlinux systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Nov 18 20:28:02 archlinux audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 18 20:28:02 archlinux kernel: audit: type=1131 audit(1668778082.251:70): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 18 20:30:46 archlinux polkitd[435]: Registered Authentication Agent for unix-process:495:44746 (system bus name :1.19 [nmcli --ask c up my_wifi_ssid], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Nov 18 20:30:46 archlinux kernel: audit: type=1111 audit(1668778246.518:71): pid=366 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="my_wifi_ssid" pid=495 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 18 20:30:46 archlinux audit[366]: USYS_CONFIG pid=366 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="my_wifi_ssid" pid=495 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 18 20:30:46 archlinux NetworkManager[366]: <info>  [1668778246.5168] agent-manager: agent[105ded0d76e2b0a3,:1.19/nmcli-connect/1000]: agent registered
Nov 18 20:30:46 archlinux NetworkManager[366]: <info>  [1668778246.5216] device (wlp3s0): Activation: starting connection 'my_wifi_ssid' (66549a1f-7441-4af6-8019-f26f28527f56)
Nov 18 20:30:46 archlinux NetworkManager[366]: <info>  [1668778246.5218] audit: op="connection-activate" uuid="66549a1f-7441-4af6-8019-f26f28527f56" name="my_wifi_ssid" pid=495 uid=1000 result="success"
Nov 18 20:30:46 archlinux NetworkManager[366]: <info>  [1668778246.5219] device (wlp3s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 18 20:30:46 archlinux NetworkManager[366]: <info>  [1668778246.5221] manager: NetworkManager state is now CONNECTING
Nov 18 20:32:17 archlinux polkitd[435]: Unregistered Authentication Agent for unix-process:495:44746 (system bus name :1.19, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Nov 18 20:33:33 archlinux kernel: INFO: task NetworkManager:366 blocked for more than 122 seconds.
Nov 18 20:33:33 archlinux kernel:       Tainted: G          I        6.0.8-arch1-1 #1
Nov 18 20:33:33 archlinux kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 18 20:33:33 archlinux kernel: task:NetworkManager  state:D stack:    0 pid:  366 ppid:     1 flags:0x00004002
Nov 18 20:33:33 archlinux kernel: Call Trace:
Nov 18 20:33:33 archlinux kernel:  <TASK>
Nov 18 20:33:33 archlinux kernel:  __schedule+0x343/0x11c0
Nov 18 20:33:33 archlinux kernel:  schedule+0x5e/0xd0
Nov 18 20:33:33 archlinux kernel:  schedule_timeout+0x11c/0x150
Nov 18 20:33:33 archlinux kernel:  wait_for_completion+0x8a/0x160
Nov 18 20:33:33 archlinux kernel:  kthread_stop+0x65/0x170
Nov 18 20:33:33 archlinux kernel:  ? hwrng_unregister+0xf0/0xf0 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  hwrng_manage_rngd+0x31/0x90 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  set_current_rng+0x76/0xd0 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  enable_best_rng+0x7d/0xb0 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  hwrng_unregister+0xce/0xf0 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  ? hwrng_unregister+0xf0/0xf0 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  devres_release+0x28/0x60
Nov 18 20:33:33 archlinux kernel:  ath9k_rng_stop+0x27/0x40 [ath9k 7980fb3b10c9498fe65fb452b5a50b0cc81d4d84]
Nov 18 20:33:33 archlinux kernel:  ath9k_stop+0x40/0x230 [ath9k 7980fb3b10c9498fe65fb452b5a50b0cc81d4d84]
Nov 18 20:33:33 archlinux kernel:  drv_stop+0x34/0x100 [mac80211 3b284e4d4d412e2738c24e4099be64c0340eb88b]
Nov 18 20:33:33 archlinux kernel:  ieee80211_do_stop+0x6a5/0x8b0 [mac80211 3b284e4d4d412e2738c24e4099be64c0340eb88b]
Nov 18 20:33:33 archlinux kernel:  ieee80211_stop+0x41/0x170 [mac80211 3b284e4d4d412e2738c24e4099be64c0340eb88b]
Nov 18 20:33:33 archlinux kernel:  __dev_close_many+0x9b/0x110
Nov 18 20:33:33 archlinux kernel:  __dev_change_flags+0x1aa/0x250
Nov 18 20:33:33 archlinux kernel:  dev_change_flags+0x26/0x60
Nov 18 20:33:33 archlinux kernel:  do_setlink+0x802/0x12b0
Nov 18 20:33:33 archlinux kernel:  ? newidle_balance+0x2f4/0x430
Nov 18 20:33:33 archlinux kernel:  ? update_load_avg+0x7e/0x730
Nov 18 20:33:33 archlinux kernel:  ? __nla_validate_parse+0x5f/0xbc0
Nov 18 20:33:33 archlinux kernel:  ? inode_permission+0x3d/0x1e0
Nov 18 20:33:33 archlinux kernel:  ? security_inode_permission+0x3b/0x60
Nov 18 20:33:33 archlinux kernel:  __rtnl_newlink+0x61d/0x9b0
Nov 18 20:33:33 archlinux kernel:  rtnl_newlink+0x47/0x70
Nov 18 20:33:33 archlinux kernel:  rtnetlink_rcv_msg+0x14f/0x3c0
Nov 18 20:33:33 archlinux kernel:  ? __wake_up_common_lock+0x88/0xc0
Nov 18 20:33:33 archlinux kernel:  ? rtnl_calcit.isra.0+0x140/0x140
Nov 18 20:33:33 archlinux kernel:  netlink_rcv_skb+0x52/0x100
Nov 18 20:33:33 archlinux kernel:  netlink_unicast+0x243/0x390
Nov 18 20:33:33 archlinux kernel:  netlink_sendmsg+0x254/0x4d0
Nov 18 20:33:33 archlinux kernel:  sock_sendmsg+0x60/0x70
Nov 18 20:33:33 archlinux kernel:  ____sys_sendmsg+0x267/0x2b0
Nov 18 20:33:33 archlinux kernel:  ? copy_msghdr_from_user+0x7d/0xc0
Nov 18 20:33:33 archlinux kernel:  ___sys_sendmsg+0x9a/0xe0
Nov 18 20:33:33 archlinux kernel:  __sys_sendmsg+0x7a/0xd0
Nov 18 20:33:33 archlinux kernel:  do_syscall_64+0x5c/0x90
Nov 18 20:33:33 archlinux kernel:  ? syscall_exit_to_user_mode+0x1b/0x40
Nov 18 20:33:33 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 18 20:33:33 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 18 20:33:33 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 18 20:33:33 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 18 20:33:33 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 18 20:33:33 archlinux kernel:  entry_SYSCALL_64_after_hwframe+0x63/0xcd
Nov 18 20:33:33 archlinux kernel: RIP: 0033:0x7f45a019addd
Nov 18 20:33:33 archlinux kernel: RSP: 002b:00007ffff276aad0 EFLAGS: 00000293 ORIG_RAX: 000000000000002e
Nov 18 20:33:33 archlinux kernel: RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f45a019addd
Nov 18 20:33:33 archlinux kernel: RDX: 0000000000000000 RSI: 00007ffff276ab10 RDI: 000000000000000d
Nov 18 20:33:33 archlinux kernel: RBP: 00005645730720d0 R08: 0000000000000000 R09: 0000000000000000
Nov 18 20:33:33 archlinux kernel: R10: 0000000000000000 R11: 0000000000000293 R12: 000000000000005a
Nov 18 20:33:33 archlinux kernel: R13: 00007ffff276ac80 R14: 00007ffff276ac7c R15: 0000000000000000
Nov 18 20:33:33 archlinux kernel:  </TASK>
Nov 18 20:33:33 archlinux kernel: INFO: task hwrng:486 blocked for more than 122 seconds.
Nov 18 20:33:33 archlinux kernel:       Tainted: G          I        6.0.8-arch1-1 #1
Nov 18 20:33:33 archlinux kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 18 20:33:33 archlinux kernel: task:hwrng           state:D stack:    0 pid:  486 ppid:     2 flags:0x00004000
Nov 18 20:33:33 archlinux kernel: Call Trace:
Nov 18 20:33:33 archlinux kernel:  <TASK>
Nov 18 20:33:33 archlinux kernel:  __schedule+0x343/0x11c0
Nov 18 20:33:33 archlinux kernel:  ? __bpf_trace_tick_stop+0x10/0x10
Nov 18 20:33:33 archlinux kernel:  schedule+0x5e/0xd0
Nov 18 20:33:33 archlinux kernel:  schedule_preempt_disabled+0x15/0x30
Nov 18 20:33:33 archlinux kernel:  __mutex_lock.constprop.0+0x399/0x700
Nov 18 20:33:33 archlinux kernel:  ? rng_current_show+0x90/0x90 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  put_rng+0x15/0x80 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  hwrng_fillfn+0x185/0x1e0 [rng_core 39106c472f9e4efe48900783fb0e53909fb53086]
Nov 18 20:33:33 archlinux kernel:  kthread+0xdb/0x110
Nov 18 20:33:33 archlinux kernel:  ? kthread_complete_and_exit+0x20/0x20
Nov 18 20:33:33 archlinux kernel:  ret_from_fork+0x1f/0x30
Nov 18 20:33:33 archlinux kernel:  </TASK>

seth · 2022-11-18 14:56:43

We've a backtrace, try passing "ath9k.nohwcrypt=1" to the kernel commandline, https://wiki.archlinux.org/title/Kernel_parameters

kocheng · 2022-11-19 02:40:38

seth wrote:

We've a backtrace, try passing "ath9k.nohwcrypt=1" to the kernel commandline, https://wiki.archlinux.org/title/Kernel_parameters

I have added the "ath9k.nohwcrypt=1" to /etc/sysctl.d/preventNmcliCrash.conf

$ cat /etc/sysctl.d/preventNmcliCrash.conf 
ath9k.nohwcrypt=1

Then I reboot my system.
Aaand, the problem still appear (when I test for it, of course), heres the log:

$ journalctl -f
Nov 19 08:56:37 archlinux NetworkManager[366]: <info>  [1668822997.2802] manager: NetworkManager state is now DISCONNECTED
Nov 19 08:56:37 archlinux NetworkManager[366]: <info>  [1668822997.2841] device (wlp3s0): supplicant interface state: completed -> disconnected
Nov 19 08:56:37 archlinux NetworkManager[366]: <info>  [1668822997.2842] device (p2p-dev-wlp3s0): supplicant management interface state: completed -> disconnected
Nov 19 08:56:37 archlinux NetworkManager[366]: <info>  [1668822997.2848] device (wlp3s0): supplicant interface state: disconnected -> interface_disabled
Nov 19 08:56:37 archlinux NetworkManager[366]: <info>  [1668822997.2849] device (p2p-dev-wlp3s0): supplicant management interface state: disconnected -> interface_disabled
Nov 19 08:56:37 archlinux NetworkManager[366]: <info>  [1668822997.2853] device (wlp3s0): supplicant interface state: interface_disabled -> disconnected
Nov 19 08:56:37 archlinux NetworkManager[366]: <info>  [1668822997.2853] device (p2p-dev-wlp3s0): supplicant management interface state: interface_disabled -> disconnected
Nov 19 08:56:46 archlinux systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Nov 19 08:56:46 archlinux audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 19 08:56:46 archlinux kernel: audit: type=1131 audit(1668823006.989:68): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 19 08:59:06 archlinux polkitd[502]: Registered Authentication Agent for unix-process:1591:28232 (system bus name :1.21 [nmcli --ask c up Aulia], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Nov 19 08:59:06 archlinux NetworkManager[366]: <info>  [1668823146.3741] agent-manager: agent[f2d31a3e1b96463e,:1.21/nmcli-connect/1000]: agent registered
Nov 19 08:59:06 archlinux NetworkManager[366]: <info>  [1668823146.3788] device (wlp3s0): Activation: starting connection 'Aulia' (66549a1f-7441-4af6-8019-f26f28527f56)
Nov 19 08:59:06 archlinux audit[366]: USYS_CONFIG pid=366 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="Aulia" pid=1591 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 19 08:59:06 archlinux NetworkManager[366]: <info>  [1668823146.3790] audit: op="connection-activate" uuid="66549a1f-7441-4af6-8019-f26f28527f56" name="Aulia" pid=1591 uid=1000 result="success"
Nov 19 08:59:06 archlinux NetworkManager[366]: <info>  [1668823146.3791] device (wlp3s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 19 08:59:06 archlinux NetworkManager[366]: <info>  [1668823146.3794] manager: NetworkManager state is now CONNECTING
Nov 19 08:59:06 archlinux kernel: audit: type=1111 audit(1668823146.377:69): pid=366 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="Aulia" pid=1591 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 19 09:00:37 archlinux polkitd[502]: Unregistered Authentication Agent for unix-process:1591:28232 (system bus name :1.21, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Nov 19 09:02:35 archlinux kernel: INFO: task kworker/2:2:179 blocked for more than 122 seconds.
Nov 19 09:02:35 archlinux kernel:       Tainted: G          I        6.0.9-arch1-1 #1
Nov 19 09:02:35 archlinux kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 19 09:02:35 archlinux kernel: task:kworker/2:2     state:D stack:    0 pid:  179 ppid:     2 flags:0x00004000
Nov 19 09:02:35 archlinux kernel: Workqueue: ipv6_addrconf addrconf_verify_work
Nov 19 09:02:35 archlinux kernel: Call Trace:
Nov 19 09:02:35 archlinux kernel:  <TASK>
Nov 19 09:02:35 archlinux kernel:  __schedule+0x343/0x11c0
Nov 19 09:02:35 archlinux kernel:  schedule+0x5e/0xd0
Nov 19 09:02:35 archlinux kernel:  schedule_preempt_disabled+0x15/0x30
Nov 19 09:02:35 archlinux kernel:  __mutex_lock.constprop.0+0x399/0x700
Nov 19 09:02:35 archlinux kernel:  addrconf_verify_work+0x12/0x30
Nov 19 09:02:35 archlinux kernel:  process_one_work+0x1c4/0x380
Nov 19 09:02:35 archlinux kernel:  worker_thread+0x51/0x390
Nov 19 09:02:35 archlinux kernel:  ? rescuer_thread+0x3b0/0x3b0
Nov 19 09:02:35 archlinux kernel:  kthread+0xdb/0x110
Nov 19 09:02:35 archlinux kernel:  ? kthread_complete_and_exit+0x20/0x20
Nov 19 09:02:35 archlinux kernel:  ret_from_fork+0x1f/0x30
Nov 19 09:02:35 archlinux kernel:  </TASK>
Nov 19 09:02:35 archlinux kernel: INFO: task NetworkManager:366 blocked for more than 122 seconds.
Nov 19 09:02:35 archlinux kernel:       Tainted: G          I        6.0.9-arch1-1 #1
Nov 19 09:02:35 archlinux kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 19 09:02:35 archlinux kernel: task:NetworkManager  state:D stack:    0 pid:  366 ppid:     1 flags:0x00004002
Nov 19 09:02:35 archlinux kernel: Call Trace:
Nov 19 09:02:35 archlinux kernel:  <TASK>
Nov 19 09:02:35 archlinux kernel:  __schedule+0x343/0x11c0
Nov 19 09:02:35 archlinux kernel:  schedule+0x5e/0xd0
Nov 19 09:02:35 archlinux kernel:  schedule_timeout+0x11c/0x150
Nov 19 09:02:35 archlinux kernel:  wait_for_completion+0x8a/0x160
Nov 19 09:02:35 archlinux kernel:  kthread_stop+0x65/0x170
Nov 19 09:02:35 archlinux kernel:  ? hwrng_unregister+0xf0/0xf0 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  hwrng_manage_rngd+0x31/0x90 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  set_current_rng+0x76/0xd0 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  enable_best_rng+0x7d/0xb0 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  hwrng_unregister+0xce/0xf0 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  ? hwrng_unregister+0xf0/0xf0 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  devres_release+0x28/0x60
Nov 19 09:02:35 archlinux kernel:  ath9k_rng_stop+0x27/0x40 [ath9k 4a185322914b4e88bf4f14b38fbe90deddbef00e]
Nov 19 09:02:35 archlinux kernel:  ath9k_stop+0x40/0x230 [ath9k 4a185322914b4e88bf4f14b38fbe90deddbef00e]
Nov 19 09:02:35 archlinux kernel:  drv_stop+0x34/0x100 [mac80211 4ae1ebb4938b08eb2075e2bfb7d05ebe6ba273e0]
Nov 19 09:02:35 archlinux kernel:  ieee80211_do_stop+0x6a5/0x8b0 [mac80211 4ae1ebb4938b08eb2075e2bfb7d05ebe6ba273e0]
Nov 19 09:02:35 archlinux kernel:  ieee80211_stop+0x41/0x170 [mac80211 4ae1ebb4938b08eb2075e2bfb7d05ebe6ba273e0]
Nov 19 09:02:35 archlinux kernel:  __dev_close_many+0x9b/0x110
Nov 19 09:02:35 archlinux kernel:  __dev_change_flags+0x1aa/0x250
Nov 19 09:02:35 archlinux kernel:  dev_change_flags+0x26/0x60
Nov 19 09:02:35 archlinux kernel:  do_setlink+0x802/0x12b0
Nov 19 09:02:35 archlinux kernel:  ? update_load_avg+0x60d/0x730
Nov 19 09:02:35 archlinux kernel:  ? __nla_validate_parse+0x5f/0xbc0
Nov 19 09:02:35 archlinux kernel:  ? update_curr+0x69/0x1e0
Nov 19 09:02:35 archlinux kernel:  ? reweight_entity+0x14d/0x160
Nov 19 09:02:35 archlinux kernel:  __rtnl_newlink+0x61d/0x9b0
Nov 19 09:02:35 archlinux kernel:  ? try_to_wake_up+0x1a1/0x560
Nov 19 09:02:35 archlinux kernel:  rtnl_newlink+0x47/0x70
Nov 19 09:02:35 archlinux kernel:  rtnetlink_rcv_msg+0x14f/0x3c0
Nov 19 09:02:35 archlinux kernel:  ? ep_poll_callback+0x230/0x280
Nov 19 09:02:35 archlinux kernel:  ? rtnl_calcit.isra.0+0x140/0x140
Nov 19 09:02:35 archlinux kernel:  netlink_rcv_skb+0x52/0x100
Nov 19 09:02:35 archlinux kernel:  netlink_unicast+0x243/0x390
Nov 19 09:02:35 archlinux kernel:  netlink_sendmsg+0x254/0x4d0
Nov 19 09:02:35 archlinux kernel:  sock_sendmsg+0x60/0x70
Nov 19 09:02:35 archlinux kernel:  ____sys_sendmsg+0x267/0x2b0
Nov 19 09:02:35 archlinux kernel:  ? copy_msghdr_from_user+0x7d/0xc0
Nov 19 09:02:35 archlinux kernel:  ___sys_sendmsg+0x9a/0xe0
Nov 19 09:02:35 archlinux kernel:  __sys_sendmsg+0x7a/0xd0
Nov 19 09:02:35 archlinux kernel:  do_syscall_64+0x5c/0x90
Nov 19 09:02:35 archlinux kernel:  ? do_futex+0xde/0x1b0
Nov 19 09:02:35 archlinux kernel:  ? __x64_sys_futex+0x92/0x1d0
Nov 19 09:02:35 archlinux kernel:  ? syscall_exit_to_user_mode+0x1b/0x40
Nov 19 09:02:35 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 19 09:02:35 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 19 09:02:35 archlinux kernel:  entry_SYSCALL_64_after_hwframe+0x63/0xcd
Nov 19 09:02:35 archlinux kernel: RIP: 0033:0x7f478eb6bddd
Nov 19 09:02:35 archlinux kernel: RSP: 002b:00007ffdc8736d40 EFLAGS: 00000293 ORIG_RAX: 000000000000002e
Nov 19 09:02:35 archlinux kernel: RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f478eb6bddd
Nov 19 09:02:35 archlinux kernel: RDX: 0000000000000000 RSI: 00007ffdc8736d80 RDI: 000000000000000d
Nov 19 09:02:35 archlinux kernel: RBP: 0000561b6541e0d0 R08: 0000000000000000 R09: 0000000000000000
Nov 19 09:02:35 archlinux kernel: R10: 0000000000000000 R11: 0000000000000293 R12: 000000000000003a
Nov 19 09:02:35 archlinux kernel: R13: 00007ffdc8736ef0 R14: 00007ffdc8736eec R15: 0000000000000000
Nov 19 09:02:35 archlinux kernel:  </TASK>
Nov 19 09:02:35 archlinux kernel: INFO: task hwrng:833 blocked for more than 122 seconds.
Nov 19 09:02:35 archlinux kernel:       Tainted: G          I        6.0.9-arch1-1 #1
Nov 19 09:02:35 archlinux kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 19 09:02:35 archlinux kernel: task:hwrng           state:D stack:    0 pid:  833 ppid:     2 flags:0x00004000
Nov 19 09:02:35 archlinux kernel: Call Trace:
Nov 19 09:02:35 archlinux kernel:  <TASK>
Nov 19 09:02:35 archlinux kernel:  __schedule+0x343/0x11c0
Nov 19 09:02:35 archlinux kernel:  ? __bpf_trace_tick_stop+0x10/0x10
Nov 19 09:02:35 archlinux kernel:  schedule+0x5e/0xd0
Nov 19 09:02:35 archlinux kernel:  schedule_preempt_disabled+0x15/0x30
Nov 19 09:02:35 archlinux kernel:  __mutex_lock.constprop.0+0x399/0x700
Nov 19 09:02:35 archlinux kernel:  ? rng_current_show+0x90/0x90 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  put_rng+0x15/0x80 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  hwrng_fillfn+0x185/0x1e0 [rng_core a018817c23b95c20fa80cb09c0f0275c418fafe9]
Nov 19 09:02:35 archlinux kernel:  kthread+0xdb/0x110
Nov 19 09:02:35 archlinux kernel:  ? kthread_complete_and_exit+0x20/0x20
Nov 19 09:02:35 archlinux kernel:  ret_from_fork+0x1f/0x30
Nov 19 09:02:35 archlinux kernel:  </TASK>
Nov 19 09:02:35 archlinux kernel: INFO: task iwgetid:1611 blocked for more than 122 seconds.
Nov 19 09:02:35 archlinux kernel:       Tainted: G          I        6.0.9-arch1-1 #1
Nov 19 09:02:35 archlinux kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 19 09:02:35 archlinux kernel: task:iwgetid         state:D stack:    0 pid: 1611 ppid:   490 flags:0x00000002
Nov 19 09:02:35 archlinux kernel: Call Trace:
Nov 19 09:02:35 archlinux kernel:  <TASK>
Nov 19 09:02:35 archlinux kernel:  __schedule+0x343/0x11c0
Nov 19 09:02:35 archlinux kernel:  ? memcg_slab_post_alloc_hook+0x17d/0x250
Nov 19 09:02:35 archlinux kernel:  ? __alloc_file+0x23/0xd0
Nov 19 09:02:35 archlinux kernel:  ? kmem_cache_alloc+0x15c/0x320
Nov 19 09:02:35 archlinux kernel:  schedule+0x5e/0xd0
Nov 19 09:02:35 archlinux kernel:  schedule_preempt_disabled+0x15/0x30
Nov 19 09:02:35 archlinux kernel:  __mutex_lock.constprop.0+0x399/0x700
Nov 19 09:02:35 archlinux kernel:  dev_ifconf+0x7c/0x150
Nov 19 09:02:35 archlinux kernel:  sock_ioctl+0x1c7/0x340
Nov 19 09:02:35 archlinux kernel:  ? syscall_exit_to_user_mode+0x1b/0x40
Nov 19 09:02:35 archlinux kernel:  ? do_syscall_64+0x6b/0x90
Nov 19 09:02:35 archlinux kernel:  __x64_sys_ioctl+0x91/0xd0
Nov 19 09:02:35 archlinux kernel:  do_syscall_64+0x5c/0x90
Nov 19 09:02:35 archlinux kernel:  ? do_user_addr_fault+0x1e0/0x6a0
Nov 19 09:02:35 archlinux kernel:  ? exc_page_fault+0x74/0x170
Nov 19 09:02:35 archlinux kernel:  entry_SYSCALL_64_after_hwframe+0x63/0xcd
Nov 19 09:02:35 archlinux kernel: RIP: 0033:0x7facbbaaec0f
Nov 19 09:02:35 archlinux kernel: RSP: 002b:00007fff2a536540 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Nov 19 09:02:35 archlinux kernel: RAX: ffffffffffffffda RBX: 00005608570fa2f8 RCX: 00007facbbaaec0f
Nov 19 09:02:35 archlinux kernel: RDX: 00007fff2a5365a0 RSI: 0000000000008912 RDI: 0000000000000003
Nov 19 09:02:35 archlinux kernel: RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000000
Nov 19 09:02:35 archlinux kernel: R10: 00007fff2a536750 R11: 0000000000000246 R12: 0000000000000002
Nov 19 09:02:35 archlinux kernel: R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000003
Nov 19 09:02:35 archlinux kernel:  </TASK>

PS: When I test for the problem, firstly I disconnect from my wifi with nmcli c down ssid, then I wait several minutes before attempting to connect to my wifi again. If I didn't wait several minutes and just connecting again to my wifi shortly after I disconnected it, usually nmcli will work.

Last edited by kocheng (2022-11-19 02:45:32)

seth · 2022-11-19 07:35:48

cat /etc/sysctl.d/preventNmcliCrash.conf

does nothing. Please pass the parameter to the kernel commandline or as module option, https://wiki.archlinux.org/title/Kernel … le_options
nb. that for the latter you might have to rebuild the initramfs if the module is copied there.

kocheng · 2022-11-19 14:08:16

Doesn't work. The problem still occur . I have set the kernel option, here:

$ cat /etc/modprobe.d/preventNmcliCrash.conf 
options ath9k nohwcrypt=1
# mkinitcpio -P

reboot...

$ systool -v -m ath9k
Module = "ath9k"

  Attributes:
    coresize            = "192512"
    initsize            = "0"
    initstate           = "live"
    refcnt              = "0"
    srcversion          = "6C595B69F60C18CE7861D5E"
    taint               = ""
    uevent              = <store method only>

  Parameters:
    blink               = "0"
    bt_ant_diversity    = "0"
    btcoex_enable       = "0"
    led_active_high     = "-1"
    nohwcrypt           = "1" <-- This one here, right?
    ps_enable           = "0"
    use_chanctx         = "0"
    use_msi             = "0"

  Sections:

Then I disconnect from my wifi, then attempting to connect to my wifi (after waiting several minute), here's the log:

$ journalctl -f
Nov 19 20:45:28 archlinux NetworkManager[364]: <info>  [1668865528.7486] dhcp6 (wlp3s0): state changed no lease
Nov 19 20:45:28 archlinux NetworkManager[364]: <info>  [1668865528.7991] device (wlp3s0): set-hw-addr: set MAC address to 9A:7A:8C:52:E4:15 (scanning)
Nov 19 20:45:28 archlinux NetworkManager[364]: <info>  [1668865528.9327] manager: NetworkManager state is now DISCONNECTED
Nov 19 20:45:28 archlinux NetworkManager[364]: <info>  [1668865528.9364] device (wlp3s0): supplicant interface state: disconnected -> interface_disabled
Nov 19 20:45:28 archlinux NetworkManager[364]: <info>  [1668865528.9365] device (p2p-dev-wlp3s0): supplicant management interface state: disconnected -> interface_disabled
Nov 19 20:45:28 archlinux NetworkManager[364]: <info>  [1668865528.9368] device (wlp3s0): supplicant interface state: interface_disabled -> disconnected
Nov 19 20:45:28 archlinux NetworkManager[364]: <info>  [1668865528.9369] device (p2p-dev-wlp3s0): supplicant management interface state: interface_disabled -> disconnected
Nov 19 20:45:38 archlinux systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Nov 19 20:45:38 archlinux audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 19 20:45:38 archlinux kernel: audit: type=1131 audit(1668865538.559:65): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 19 20:50:33 archlinux polkitd[497]: Registered Authentication Agent for unix-process:2120:37611 (system bus name :1.20 [nmcli --ask c up my_wifi_ssid], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Nov 19 20:50:33 archlinux kernel: audit: type=1111 audit(1668865833.191:66): pid=364 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="my_wifi_ssid" pid=2120 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 19 20:50:33 archlinux audit[364]: USYS_CONFIG pid=364 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="my_wifi_ssid" pid=2120 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 19 20:50:33 archlinux NetworkManager[364]: <info>  [1668865833.1917] agent-manager: agent[ea8337fcd4e6b41f,:1.20/nmcli-connect/1000]: agent registered
Nov 19 20:50:33 archlinux NetworkManager[364]: <info>  [1668865833.1962] device (wlp3s0): Activation: starting connection 'my_wifi_ssid' (66549a1f-7441-4af6-8019-f26f28527f56)
Nov 19 20:50:33 archlinux NetworkManager[364]: <info>  [1668865833.1964] audit: op="connection-activate" uuid="66549a1f-7441-4af6-8019-f26f28527f56" name="my_wifi_ssid" pid=2120 uid=1000 result="success"
Nov 19 20:50:33 archlinux NetworkManager[364]: <info>  [1668865833.1965] device (wlp3s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 19 20:50:33 archlinux NetworkManager[364]: <info>  [1668865833.1967] manager: NetworkManager state is now CONNECTING
Nov 19 20:52:03 archlinux polkitd[497]: Unregistered Authentication Agent for unix-process:2120:37611 (system bus name :1.20, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)

seth · 2022-11-19 20:29:24

Seems hwrng was only a (random) victim of the stall

PS: When I test for the problem, firstly I disconnect from my wifi with nmcli c down ssid, then I wait several minutes before attempting to connect to my wifi again. If I didn't wait several minutes and just connecting again to my wifi shortly after I disconnected it, usually nmcli will work.

    ps_enable           = "0"

Output of

iw dev wlp3s0 get power_save

On a limb, add "pcie_aspm=off" to the kernel parameters.

Sanity check: is there a parallel windows installation?

kocheng · 2022-11-20 02:39:42

Nope, I still can reproduce the problem...

$ cat /etc/modprobe.d/preventNmcliCrash.conf 
options ath9k nohwcrypt=1 
options ath9k ps_enable=1
# mkinitcpio -P
# cat /etc/default/grub | grep pcie
GRUB_CMDLINE_LINUX_DEFAULT="loglevel=3 pcie_aspm=off"
# grub-mkconfig -o /boot/grub/grub.cfg

reboot...

$ systool -v -m ath9k
Module = "ath9k"
    ...
    nohwcrypt           = "1"
    ps_enable           = "1" <-- is this what you want?
    ...

$ iw dev wlp3s0 get power_save
Power save: off

Here's the log:

Nov 20 09:24:42 archlinux audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 20 09:24:42 archlinux kernel: audit: type=1131 audit(1668911082.398:72): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 20 09:25:20 archlinux systemd[1]: Starting Cleanup of Temporary Directories...
Nov 20 09:25:20 archlinux systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully.
Nov 20 09:25:20 archlinux systemd[1]: Finished Cleanup of Temporary Directories.
Nov 20 09:25:20 archlinux kernel: audit: type=1130 audit(1668911120.565:73): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 20 09:25:20 archlinux kernel: audit: type=1131 audit(1668911120.565:74): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 20 09:25:20 archlinux audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 20 09:25:20 archlinux audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nov 20 09:25:20 archlinux systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully.
Nov 20 09:28:06 archlinux polkitd[506]: Registered Authentication Agent for unix-process:6073:107834 (system bus name :1.32 [nmcli --ask c up Aulia], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Nov 20 09:28:06 archlinux NetworkManager[365]: <info>  [1668911286.3993] agent-manager: agent[12825895dc989613,:1.32/nmcli-connect/1000]: agent registered
Nov 20 09:28:06 archlinux NetworkManager[365]: <info>  [1668911286.4036] device (wlp3s0): Activation: starting connection 'Aulia' (66549a1f-7441-4af6-8019-f26f28527f56)
Nov 20 09:28:06 archlinux audit[365]: USYS_CONFIG pid=365 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="Aulia" pid=6073 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 20 09:28:06 archlinux NetworkManager[365]: <info>  [1668911286.4037] audit: op="connection-activate" uuid="66549a1f-7441-4af6-8019-f26f28527f56" name="Aulia" pid=6073 uid=1000 result="success"
Nov 20 09:28:06 archlinux NetworkManager[365]: <info>  [1668911286.4038] device (wlp3s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 20 09:28:06 archlinux NetworkManager[365]: <info>  [1668911286.4041] manager: NetworkManager state is now CONNECTING
Nov 20 09:28:06 archlinux kernel: audit: type=1111 audit(1668911286.401:75): pid=365 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=66549a1f-7441-4af6-8019-f26f28527f56 name="Aulia" pid=6073 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Nov 20 09:29:37 archlinux polkitd[506]: Unregistered Authentication Agent for unix-process:6073:107834 (system bus name :1.32, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)

Yes, I have Windows 10 installed on my system, dual booted with Arch (of course!).

d.ALT · 2022-11-20 07:31:14

kocheng wrote:

Yes, I have Windows 10 installed on my system, dual booted with Arch (of course!).

Make sure Windows' Fast Start is disabled.

kocheng · 2022-11-20 11:16:36

d.ALT wrote:

Make sure Windows' Fast Start is disabled.

Yes, I have disabled that.

seth · 2022-11-20 12:53:09

is this what you want?

No, I was just pointing out that this is disabled (so it's not power saving by the driver) - you should revert the value for now.

Yes, I have disabled that.

When, where and how? Did you make sure it still is?
See the 3rd link below.
The device is no more responding, but there's no indication as to why and we need to rule out this.
Other than that, see whether disabling https://wiki.archlinux.org/title/Networ … domization helps

Finally: disable networkmaanger and see whether you can alter the connection w/ netctl/wifi-menu reliably (NMs scanning habits might get in the way differently - shrug)

kocheng · 2022-11-21 09:28:30

Hello, it seems that the problem has been solved with seth's solution about disabling the MAC address randomization ...
I have reverted the value of ath9k.ps_enable to 0. Windows fast start and hibernate has also been disabled (I'm sure about that).

$ cat /etc/NetworkManager/conf.d/wifi_rand_mac.conf 
[device]
wifi.scan-rand-mac-address=no

restart NetworkManager...

Thanks so much !

Arch Linux

#1 2022-10-22 03:47:35

[SOLVED]nmcli hangs when executed (sometimes)

#2 2022-10-22 14:05:00

Re: [SOLVED]nmcli hangs when executed (sometimes)

#3 2022-10-23 13:36:09

Re: [SOLVED]nmcli hangs when executed (sometimes)

#4 2022-11-11 07:44:54

Re: [SOLVED]nmcli hangs when executed (sometimes)

#5 2022-11-17 04:14:26

Re: [SOLVED]nmcli hangs when executed (sometimes)

#6 2022-11-17 07:47:44

Re: [SOLVED]nmcli hangs when executed (sometimes)

#7 2022-11-17 08:45:34

Re: [SOLVED]nmcli hangs when executed (sometimes)

#8 2022-11-17 10:30:00

Re: [SOLVED]nmcli hangs when executed (sometimes)

#9 2022-11-17 11:21:09

Re: [SOLVED]nmcli hangs when executed (sometimes)

#10 2022-11-17 15:21:54

Re: [SOLVED]nmcli hangs when executed (sometimes)

#11 2022-11-18 14:13:01

Re: [SOLVED]nmcli hangs when executed (sometimes)

#12 2022-11-18 14:56:43

Re: [SOLVED]nmcli hangs when executed (sometimes)

#13 2022-11-19 02:40:38

Re: [SOLVED]nmcli hangs when executed (sometimes)

#14 2022-11-19 07:35:48

Re: [SOLVED]nmcli hangs when executed (sometimes)

#15 2022-11-19 14:08:16

Re: [SOLVED]nmcli hangs when executed (sometimes)

#16 2022-11-19 20:29:24

Re: [SOLVED]nmcli hangs when executed (sometimes)

#17 2022-11-20 02:39:42

Re: [SOLVED]nmcli hangs when executed (sometimes)

#18 2022-11-20 07:31:14

Re: [SOLVED]nmcli hangs when executed (sometimes)

#19 2022-11-20 11:16:36

Re: [SOLVED]nmcli hangs when executed (sometimes)

#20 2022-11-20 12:53:09

Re: [SOLVED]nmcli hangs when executed (sometimes)

#21 2022-11-21 09:28:30

Re: [SOLVED]nmcli hangs when executed (sometimes)

Board footer