diff mbox series

[v3,net-next,2/2] net: dsa: qca: ar9331: export stats64

Message ID 20201202140904.24748-3-o.rempel@pengutronix.de (mailing list archive)
State Superseded
Delegated to: Netdev Maintainers
Headers show
Series net: dsa: add stats64 support | expand

Checks

Context Check Description
netdev/cover_letter success Link
netdev/fixes_present success Link
netdev/patch_count success Link
netdev/tree_selection success Clearly marked for net-next
netdev/subject_prefix success Link
netdev/source_inline success Was 0 now: 0
netdev/verify_signedoff success Link
netdev/module_param success Was 0 now: 0
netdev/build_32bit success Errors and warnings before: 0 this patch: 0
netdev/kdoc success Errors and warnings before: 0 this patch: 0
netdev/verify_fixes success Link
netdev/checkpatch warning CHECK: Macro argument '_port' may be better as '(_port)' to avoid precedence issues CHECK: Macro argument '_reg' may be better as '(_reg)' to avoid precedence issues WARNING: line length of 82 exceeds 80 columns
netdev/build_allmodconfig_warn success Errors and warnings before: 0 this patch: 0
netdev/header_inline success Link
netdev/stable success Stable not CCed

Commit Message

Oleksij Rempel Dec. 2, 2020, 2:09 p.m. UTC
Add stats support for the ar9331 switch.

Signed-off-by: Oleksij Rempel <o.rempel@pengutronix.de>
---
 drivers/net/dsa/qca/ar9331.c | 248 ++++++++++++++++++++++++++++++++++-
 1 file changed, 247 insertions(+), 1 deletion(-)

Comments

Florian Fainelli Dec. 2, 2020, 5:20 p.m. UTC | #1
On 12/2/2020 6:09 AM, Oleksij Rempel wrote:
> Add stats support for the ar9331 switch.
> 
> Signed-off-by: Oleksij Rempel <o.rempel@pengutronix.de>


Reviewed-by: Florian Fainelli <f.fainelli@gmail.com>
Jakub Kicinski Dec. 2, 2020, 6:42 p.m. UTC | #2
On Wed,  2 Dec 2020 15:09:04 +0100 Oleksij Rempel wrote:
> Add stats support for the ar9331 switch.
> 
> Signed-off-by: Oleksij Rempel <o.rempel@pengutronix.de>

Ah, I missed the v3 (like most reviewers it seems :)).
The sleeping in ndo_get_stats64 question applies.
Oleksij Rempel Dec. 3, 2020, 8:50 a.m. UTC | #3
Hello Jakub and Andrew,

> Ah, I missed the v3 (like most reviewers it seems :)).

No problem, I moved your replies from v2 tread to this mail.

On Wed, Dec 02, 2020 at 10:42:07AM -0800, Jakub Kicinski wrote:
> On Wed,  2 Dec 2020 15:09:04 +0100 Oleksij Rempel wrote:
> > Add stats support for the ar9331 switch.
> > 
> > Signed-off-by: Oleksij Rempel <o.rempel@pengutronix.de>

I added dump_stack() to the stats64 function, so we can see how it is
used.

@Andrew

> You could update the stats here, after the interface is down. You then
> know the stats are actually up to date and correct!

stats are automatically read on __dev_notify_flags(), for example here:

[   11.049289] [<80069ce0>] show_stack+0x9c/0x140
[   11.053651] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   11.058820] [<80526584>] dev_get_stats+0x58/0xfc
[   11.063385] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   11.068293] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   11.073274] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[   11.078799] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[   11.083782] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[   11.088378] [<80534380>] __dev_notify_flags+0x50/0xd8
[   11.093365] [<80534ca0>] dev_change_flags+0x60/0x80
[   11.098273] [<80c13fa4>] ic_close_devs+0xcc/0xdc
[   11.102810] [<80c15200>] ip_auto_config+0x1144/0x11e4
[   11.107847] [<80060f14>] do_one_initcall+0x110/0x2b4
[   11.112871] [<80bf31bc>] kernel_init_freeable+0x220/0x258
[   11.118248] [<80739a2c>] kernel_init+0x24/0x11c
[   11.122707] [<8006306c>] ret_from_kernel_thread+0x14/0x1c

Do we really need an extra read within the ar9331 driver?

@Jakub,

> You can't take sleeping locks from .ndo_get_stats64.
> 
> Also regmap may sleep?
> 
> +	ret = regmap_read(priv->regmap, reg, &val);

Yes. And underling layer is mdio bus which is by default sleeping as
well.

> Am I missing something?

In this log, the  ar9331_get_stats64() was never called from atomic or
irq context. Why it should not be sleeping?

[    0.000000] Linux version 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty (ptxdist@ptxdist) (mips-softfloat-linux-gnu-gcc (OSELAS.Toolchain-2020.08.0 10-20200822) 10.2.1 20200822, GNU ld (GNU Binutils) 2.35) #28 PREEMPT 2020-12-03T08:20:00+00:00
[    0.000000] printk: bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
[    0.000000] MIPS: machine is DPTechnics DPT-Module
[    0.000000] SoC: Atheros AR9330 rev 1
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x000000001fffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000003ffffff]
[    0.000000]   node   0: [mem 0x0000000080000000-0x0000000083ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000083ffffff]
[    0.000000] On node 0 totalpages: 16384
[    0.000000]   Normal zone: 1024 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 16384 pages, LIFO batch:3
[    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: 15360
[    0.000000] Kernel command line: ip=dhcp root=/dev/nfs nfsroot=192.168.1.100:/home/none/nfsroot/som9331-board,v3,tcp
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 41424K/65536K available (7045K kernel code, 2555K rwdata, 2240K rodata, 1336K init, 6706K bss, 24112K reserved, 0K cma-reserved)
[    0.000000] random: get_random_u32 called from cache_random_seq_create+0xa0/0x198 with crng_init=0
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] ftrace: allocating 22486 entries in 44 pages
[    0.000000] ftrace: allocated 44 pages with 3 groups
[    0.000000] Running RCU self tests
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu: 	RCU lockdep checking is enabled.
[    0.000000] 	Trampoline variant of Tasks RCU enabled.
[    0.000000] 	Rude variant of Tasks RCU enabled.
[    0.000000] 	Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 51
[    0.000000] CPU clock: 400.000 MHz
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302233 ns
[    0.000021] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 10737418237ns
[    0.008709] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    0.015475] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.019645] ... MAX_LOCK_DEPTH:          48
[    0.023728] ... MAX_LOCKDEP_KEYS:        8192
[    0.028071] ... CLASSHASH_SIZE:          4096
[    0.032476] ... MAX_LOCKDEP_ENTRIES:     32768
[    0.036846] ... MAX_LOCKDEP_CHAINS:      65536
[    0.041276] ... CHAINHASH_SIZE:          32768
[    0.045767]  memory used by lock dependency info: 4317 kB
[    0.051092]  memory used for stack traces: 2112 kB
[    0.055932]  per task-struct memory footprint: 2304 bytes
[    0.061438] Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
[    0.141175] pid_max: default: 32768 minimum: 301
[    0.147302] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.153243] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.186518] rcu: Hierarchical SRCU implementation.
[    0.201252] devtmpfs: initialized
[    0.257151] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.267232] futex hash table entries: 256 (order: 1, 14336 bytes, linear)
[    0.274830] pinctrl core: initialized pinctrl subsystem
[    0.316846] NET: Registered protocol family 16
[    0.344984] cpuidle: using governor ladder
[    1.008106] clocksource: Switched to clocksource MIPS
[    2.794282] random: fast init done
[    5.314857] NET: Registered protocol family 2
[    5.322775] tcp_listen_portaddr_hash hash table entries: 128 (order: 0, 6656 bytes, linear)
[    5.330472] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    5.337413] TCP bind hash table entries: 1024 (order: 3, 49152 bytes, linear)
[    5.345354] TCP: Hash tables configured (established 1024 bind 1024)
[    5.351554] UDP hash table entries: 256 (order: 2, 28672 bytes, linear)
[    5.357671] UDP-Lite hash table entries: 256 (order: 2, 28672 bytes, linear)
[    5.365883] NET: Registered protocol family 1
[    5.371317] RPC: Registered named UNIX socket transport module.
[    5.375822] RPC: Registered udp transport module.
[    5.380882] RPC: Registered tcp transport module.
[    5.385200] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    5.400983] workingset: timestamp_bits=30 max_order=14 bucket_order=0
[    5.450863] NFS: Registering the id_resolver key type
[    5.454601] Key type id_resolver registered
[    5.459780] Key type id_legacy registered
[    5.463358] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    5.472412] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[    5.480267] io scheduler mq-deadline registered
[    5.483378] io scheduler kyber registered
[    5.505480] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[    5.519609] 18020000.serial: ttyATH0 at MMIO 0x18020000 (irq = 9, base_baud = 1562500) is a AR933X UART
[    5.532099] printk: console [ttyATH0] enabled
[    5.539649] printk: bootconsole [early0] disabled
[    5.558790] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
[    5.565214] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
[    5.589324] libphy: Fixed MDIO Bus: probed
[    6.373379] libphy: ag71xx_mdio: probed
[    6.377959] ag71xx 19000000.ethernet eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:mii
[    6.391117] ag71xx 1a000000.ethernet (unnamed net_device) (uninitialized): invalid MAC address, using random address
[    7.082076] libphy: ag71xx_mdio: probed
[    7.093837] ag71xx 1a000000.ethernet eth1: Atheros AG71xx at 0xba000000, irq 5, mode:gmii
[    7.113705] NET: Registered protocol family 10
[    7.125014] Segment Routing with IPv6
[    7.127562] NET: Registered protocol family 17
[    7.133333] 8021q: 802.1Q VLAN Support v1.8
[    7.136246] Key type dns_resolver registered
[    7.143108] batman_adv: B.A.T.M.A.N. advanced 2020.4 (compatibility version 15) loaded
[    7.182826] libphy: switch@10: probed
[    7.203983] ar9331_switch ethernet.1:10: configuring for fixed/gmii link mode
[    7.213026] ar9331_switch ethernet.1:10: Link is Up - 1Gbps/Full - flow control rx/tx
[    7.288774] ar9331_switch ethernet.1:10 lan0 (uninitialized): PHY [!ahb!ethernet@1a000000!mdio!switch@10:00] driver [Qualcomm Atheros AR9331 built-in PHY] (irq=13)
[    7.306788] CPU: 0 PID: 18 Comm: kworker/0:1 Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[    7.316618] Workqueue: events deferred_probe_work_func
[    7.320606] Stack : 80980000 80980000 8089ffb0 80bd0000 00000000 80bc6e20 00000cc0 00000000
[    7.328877]         00000000 800d1268 00000000 ffffffde 00000017 804eea2c 81943908 365b91c5
[    7.337032]         00000000 00000000 8089ffb0 00000000 81943fe0 00000000 00000000 00000000
[    7.345539]         819439b4 809879b0 fffffffd 66657272 80980000 00000000 8092d5e8 80bd0000
[    7.353774]         00000000 80bc6e20 00000cc0 00000000 8097ca9c 365b91c5 00000000 80d40000
[    7.362098]         ...
[    7.364486] Call Trace:
[    7.366940] [<80069ce0>] show_stack+0x9c/0x140
[    7.371432] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[    7.376488] [<80526584>] dev_get_stats+0x58/0xfc
[    7.381173] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[    7.385961] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[    7.391055] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[    7.396468] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[    7.401562] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[    7.406024] [<80536548>] register_netdevice+0x510/0x538
[    7.411302] [<806c1bd4>] dsa_slave_create+0x4c0/0x578
[    7.416296] [<806bc56c>] dsa_register_switch+0x934/0xa20
[    7.421634] [<804ef638>] ar9331_sw_probe+0x364/0x37c
[    7.426524] [<804eb48c>] mdio_probe+0x44/0x70
[    7.430932] [<8049e3b4>] really_probe+0x30c/0x4f4
[    7.435564] [<8049ea10>] driver_probe_device+0x264/0x26c
[    7.440915] [<8049bc10>] bus_for_each_drv+0xb4/0xd8
[    7.445725] [<8049e684>] __device_attach+0xe8/0x18c
[    7.450647] [<8049ce58>] bus_probe_device+0x48/0xc4
[    7.455455] [<8049db70>] deferred_probe_work_func+0xdc/0xf8
[    7.461093] [<8009ff64>] process_one_work+0x2e4/0x4a0
[    7.466059] [<800a0770>] worker_thread+0x2a8/0x354
[    7.470900] [<800a774c>] kthread+0x16c/0x174
[    7.475094] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[    7.480523] 
[    7.558770] ar9331_switch ethernet.1:10 lan1 (uninitialized): PHY [!ahb!ethernet@1a000000!mdio!switch@10:02] driver [Qualcomm Atheros AR9331 built-in PHY] (irq=13)
[    7.578331] CPU: 0 PID: 18 Comm: kworker/0:1 Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[    7.586440] Workqueue: events deferred_probe_work_func
[    7.593196] Stack : 80980000 80980000 8089ffb0 80bd0000 00000000 80bc6e20 00000cc0 00000000
[    7.600535]         00000000 800d1268 00000000 ffffffde 00000017 804eea2c 81943908 365b91c5
[    7.608806]         00000000 00000000 8089ffb0 00000000 81943fe0 00000000 00000000 00000000
[    7.616961]         819439b4 809879b0 fffffffd 00000005 80980000 00000000 8092d5e8 80bd0000
[    7.625466]         00000000 80bc6e20 00000cc0 00000000 8097ca9c 365b91c5 00000000 80d40000
[    7.633703]         ...
[    7.636075] Call Trace:
[    7.638582] [<80069ce0>] show_stack+0x9c/0x140
[    7.642965] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[    7.648134] [<80526584>] dev_get_stats+0x58/0xfc
[    7.652705] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[    7.657549] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[    7.662644] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[    7.668113] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[    7.673095] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[    7.677612] [<80536548>] register_netdevice+0x510/0x538
[    7.682891] [<806c1bd4>] dsa_slave_create+0x4c0/0x578
[    7.687886] [<806bc56c>] dsa_register_switch+0x934/0xa20
[    7.693223] [<804ef638>] ar9331_sw_probe+0x364/0x37c
[    7.698169] [<804eb48c>] mdio_probe+0x44/0x70
[    7.702469] [<8049e3b4>] really_probe+0x30c/0x4f4
[    7.707152] [<8049ea10>] driver_probe_device+0x264/0x26c
[    7.712505] [<8049bc10>] bus_for_each_drv+0xb4/0xd8
[    7.717314] [<8049e684>] __device_attach+0xe8/0x18c
[    7.722234] [<8049ce58>] bus_probe_device+0x48/0xc4
[    7.727044] [<8049db70>] deferred_probe_work_func+0xdc/0xf8
[    7.732682] [<8009ff64>] process_one_work+0x2e4/0x4a0
[    7.737646] [<800a0770>] worker_thread+0x2a8/0x354
[    7.742488] [<800a774c>] kthread+0x16c/0x174
[    7.746683] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[    7.752112] 
[    7.755552] DSA: tree 0 setup
[    7.762387] ag71xx 1a000000.ethernet eth1: configuring for fixed/gmii link mode
[    7.772511] ag71xx 1a000000.ethernet eth1: Link is Up - 1Gbps/Full - flow control rx/tx
[    7.858775] ag71xx 19000000.ethernet eth0: PHY [!ahb!ethernet@1a000000!mdio!switch@10:04] driver [Qualcomm Atheros AR9331 built-in PHY] (irq=13)
[    7.871990] ag71xx 19000000.ethernet eth0: configuring for phy/mii link mode
[    7.881779] ar9331_switch ethernet.1:10 lan0: configuring for phy/internal link mode
[    7.890327] CPU: 0 PID: 1 Comm: swapper Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[    7.897953] Stack : 808f0000 80885ffc 818bdaf4 00000000 00000000 9b06e2c0 80980000 818c55c8
[    7.906288]         80980ca7 80d43358 00000000 80bc6e20 00000a20 804eea2c 818bdaa0 9b06e2c0
[    7.914674]         00000000 00000000 8089ffb0 818bd918 ffffffea 00000000 00000000 00000000
[    7.923014]         818bdb4c 0000004c 00000033 72393333 80980000 00000000 8092d5e8 80bd0000
[    7.931354]         00000000 80bc6e20 00000a20 00000000 00000000 804ee9f4 00000000 80d40000
[    7.939693]         ...
[    7.942082] Call Trace:
[    7.944538] [<80069ce0>] show_stack+0x9c/0x140
[    7.949028] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[    7.954083] [<80526584>] dev_get_stats+0x58/0xfc
[    7.958768] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[    7.963557] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[    7.968650] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[    7.974064] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[    7.979158] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[    7.983642] [<80534380>] __dev_notify_flags+0x50/0xd8
[    7.988714] [<80534ca0>] dev_change_flags+0x60/0x80
[    7.993541] [<80c143c8>] ip_auto_config+0x30c/0x11e4
[    7.998532] [<80060f14>] do_one_initcall+0x110/0x2b4
[    8.003447] [<80bf31bc>] kernel_init_freeable+0x220/0x258
[    8.008878] [<80739a2c>] kernel_init+0x24/0x11c
[    8.013335] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[    8.018764] 
[    8.021475] ar9331_switch ethernet.1:10 lan1: configuring for phy/internal link mode
[    8.031453] CPU: 0 PID: 1 Comm: swapper Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[    8.039179] Stack : 808f0000 80885ffc 818bdaf4 00000000 00000000 9b06e2c0 80980000 818c55c8
[    8.047412]         80980ca7 80d43358 00000000 80bc6e20 00000a20 804eea2c 818bdaa0 9b06e2c0
[    8.055798]         00000000 00000000 8089ffb0 818bd918 ffffffea 00000000 00000000 00000000
[    8.064139]         818bdb4c 0000004c 00000033 72393333 80980000 00000000 8092d5e8 80bd0000
[    8.072477]         00000000 80bc6e20 00000a20 00000000 00000000 804ee9f4 00000000 80d40000
[    8.080940]         ...
[    8.083205] Call Trace:
[    8.085659] [<80069ce0>] show_stack+0x9c/0x140
[    8.090182] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[    8.095206] [<80526584>] dev_get_stats+0x58/0xfc
[    8.099886] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[    8.104679] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[    8.109774] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[    8.115188] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[    8.120281] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[    8.124762] [<80534380>] __dev_notify_flags+0x50/0xd8
[    8.129838] [<80534ca0>] dev_change_flags+0x60/0x80
[    8.134662] [<80c143c8>] ip_auto_config+0x30c/0x11e4
[    8.139655] [<80060f14>] do_one_initcall+0x110/0x2b4
[    8.144567] [<80bf31bc>] kernel_init_freeable+0x220/0x258
[    8.150000] [<80739a2c>] kernel_init+0x24/0x11c
[    8.154458] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[    8.159888] 
[    8.188460] Sending DHCP requests .
[    8.965250] ar9331_switch ethernet.1:10 lan1: Link is Up - 100Mbps/Full - flow control rx/tx
[    8.978440] IPv6: ADDRCONF(NETDEV_CHANGE): lan1: link becomes ready
[    8.983872] CPU: 0 PID: 18 Comm: kworker/0:1 Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[    8.992995] Workqueue: events linkwatch_event
[    8.997091] Stack : 80980000 80980000 8089ffb0 80bd0000 00000000 80bc6e20 00000cc0 00000000
[    9.005495]         00000000 800d1268 00000000 ffffffde 00000017 804eea2c 81943b30 365b91c5
[    9.013877]         00000000 00000000 8089ffb0 81943990 ffffffea 00000000 00000000 00000000
[    9.022184]         81943bdc ffffffff 00000000 6e6b7761 80980000 00000000 8092d5e8 80bd0000
[    9.030558]         00000000 80bc6e20 00000cc0 00000000 00000000 365b91c5 00000000 80d40000
[    9.038853]         ...
[    9.041224] Call Trace:
[    9.043674] [<80069ce0>] show_stack+0x9c/0x140
[    9.048233] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[    9.053225] [<80526584>] dev_get_stats+0x58/0xfc
[    9.057850] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[    9.062764] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[    9.067734] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[    9.073324] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[    9.078602] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[    9.082769] [<80529d38>] netdev_state_change+0x70/0x98
[    9.087887] [<8054b688>] linkwatch_do_dev+0x7c/0xb8
[    9.093020] [<8054b890>] __linkwatch_run_queue+0xd4/0x20c
[    9.098368] [<8054ba04>] linkwatch_event+0x3c/0x48
[    9.102940] [<8009ff64>] process_one_work+0x2e4/0x4a0
[    9.107959] [<800a0770>] worker_thread+0x2a8/0x354
[    9.112937] [<800a774c>] kthread+0x16c/0x174
[    9.116996] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[    9.122445] 
[    9.285927] ag71xx 19000000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx
[    9.294386] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   10.768065] ., OK
[   10.808789] IP-Config: Got DHCP answer from 192.168.1.100, my address is 192.168.1.87
[   10.816457] IP-Config: Complete:
[   10.820388]      device=eth0, hwaddr=00:03:7f:be:f4:57, ipaddr=192.168.1.87, mask=255.255.255.0, gw=192.168.1.100
[   10.830141]      host=192.168.1.87, domain=example.org, nis-domain=(none)
[   10.836703]      bootserver=192.168.1.100, rootserver=192.168.1.100, rootpath=
[   10.836724]      nameserver0=192.168.1.100
[   10.850094] CPU: 0 PID: 1 Comm: swapper Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   10.857725] Stack : 808f0000 80885ffc 818bdac4 00000000 00000000 9b06e2c0 80980000 818c55c8
[   10.866295]         80980ca7 80d43358 00000000 80bc6e20 00000a20 804eea2c 818bda70 9b06e2c0
[   10.874551]         00000000 00000000 8089ffb0 818bd8e8 ffffffea 00000000 00000000 00000000
[   10.882873]         818bdb1c 80987858 fffffffd 72393333 80980000 00000000 8092d5e8 80bd0000
[   10.891131]         00000000 80bc6e20 00000a20 00000000 00000000 804ee9f4 00000000 80d40000
[   10.899461]         ...
[   10.901850] Call Trace:
[   10.904306] [<80069ce0>] show_stack+0x9c/0x140
[   10.908798] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   10.913852] [<80526584>] dev_get_stats+0x58/0xfc
[   10.918646] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   10.923326] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   10.928437] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[   10.933833] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[   10.938926] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[   10.943410] [<80534380>] __dev_notify_flags+0x50/0xd8
[   10.948484] [<80534ca0>] dev_change_flags+0x60/0x80
[   10.953309] [<80c13fa4>] ic_close_devs+0xcc/0xdc
[   10.957899] [<80c15200>] ip_auto_config+0x1144/0x11e4
[   10.962995] [<80060f14>] do_one_initcall+0x110/0x2b4
[   10.967906] [<80bf31bc>] kernel_init_freeable+0x220/0x258
[   10.973337] [<80739a2c>] kernel_init+0x24/0x11c
[   10.977796] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[   10.983225] 
[   10.987029] ar9331_switch ethernet.1:10 lan1: Link is Down
[   10.995008] CPU: 0 PID: 1 Comm: swapper Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   11.002737] Stack : 808f0000 80885ffc 818bdac4 00000000 00000000 9b06e2c0 80980000 818c55c8
[   11.011134]         80980ca7 80d43358 00000000 80bc6e20 00000a20 804eea2c 818bda70 9b06e2c0
[   11.019481]         00000000 00000000 8089ffb0 818bd8e8 ffffffea 00000000 00000000 00000000
[   11.027648]         818bdb1c 80987858 fffffffd 72393333 80980000 00000000 8092d5e8 80bd0000
[   11.036141]         00000000 80bc6e20 00000a20 00000000 00000000 804ee9f4 00000000 80d40000
[   11.044520]         ...
[   11.046762] Call Trace:
[   11.049289] [<80069ce0>] show_stack+0x9c/0x140
[   11.053651] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   11.058820] [<80526584>] dev_get_stats+0x58/0xfc
[   11.063385] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   11.068293] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   11.073274] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[   11.078799] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[   11.083782] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[   11.088378] [<80534380>] __dev_notify_flags+0x50/0xd8
[   11.093365] [<80534ca0>] dev_change_flags+0x60/0x80
[   11.098273] [<80c13fa4>] ic_close_devs+0xcc/0xdc
[   11.102810] [<80c15200>] ip_auto_config+0x1144/0x11e4
[   11.107847] [<80060f14>] do_one_initcall+0x110/0x2b4
[   11.112871] [<80bf31bc>] kernel_init_freeable+0x220/0x258
[   11.118248] [<80739a2c>] kernel_init+0x24/0x11c
[   11.122707] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[   11.128150] 
[   11.163593] VFS: Mounted root (nfs filesystem) readonly on device 0:11.
[   11.172370] devtmpfs: mounted
[   11.223234] Freeing unused kernel memory: 1336K
[   11.226348] This architecture does not have kernel memory protection.
[   11.232897] Run /sbin/init as init process
[   11.236859]   with arguments:
[   11.239863]     /sbin/init
[   11.242501]   with environment:
[   11.245630]     HOME=/
[   11.247974]     TERM=linux
[   12.999446] systemd[1]: System time before build time, advancing clock.
[   13.458800] systemd[1]: systemd 246.3 running in system mode. (-PAM -AUDIT -SELINUX -IMA -APPARMOR -SMACK -SYSVINIT -UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS -ACL -XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=unified)
[   13.481353] systemd[1]: Detected architecture mips.
[   13.564447] systemd[1]: Set hostname to <AccessBox>.
[   15.915796] systemd[1]: Queued start job for default target multi-user.target.
[   15.935214] random: systemd: uninitialized urandom read (16 bytes read)
[   15.950998] systemd[1]: Created slice system-serial\x2dgetty.slice.
[   15.965076] random: systemd: uninitialized urandom read (16 bytes read)
[   15.970916] systemd[1]: Reached target paths.target.
[   16.039242] random: systemd: uninitialized urandom read (16 bytes read)
[   16.044713] systemd[1]: Reached target remote-fs.target.
[   16.109136] systemd[1]: Reached target slices.target.
[   16.179490] systemd[1]: Reached target swap.target.
[   16.296748] systemd[1]: Listening on systemd-coredump.socket.
[   16.399675] systemd[1]: Condition check resulted in systemd-journald-audit.socket being skipped.
[   16.414345] systemd[1]: Listening on systemd-journald-dev-log.socket.
[   16.482298] systemd[1]: Listening on systemd-journald.socket.
[   16.554415] systemd[1]: Listening on systemd-networkd.socket.
[   16.625357] systemd[1]: Listening on systemd-udevd-control.socket.
[   16.691077] systemd[1]: Listening on systemd-udevd-kernel.socket.
[   16.761941] systemd[1]: Condition check resulted in dev-hugepages.mount being skipped.
[   16.771550] systemd[1]: Condition check resulted in dev-mqueue.mount being skipped.
[   16.789492] systemd[1]: Mounting sys-kernel-debug.mount...
[   16.881382] systemd[1]: Mounting sys-kernel-tracing.mount...
[   16.974520] systemd[1]: Starting kmod-static-nodes.service...
[   17.076169] systemd[1]: Starting systemd-journald.service...
[   17.160586] systemd[1]: Condition check resulted in systemd-modules-load.service being skipped.
[   17.181747] systemd[1]: Condition check resulted in sys-fs-fuse-connections.mount being skipped.
[   17.201014] systemd[1]: Condition check resulted in sys-kernel-config.mount being skipped.
[   17.250839] systemd[1]: Starting systemd-remount-fs.service...
[   17.370692] systemd[1]: Starting systemd-sysctl.service...
[   17.496266] systemd[1]: Starting systemd-udev-trigger.service...
[   17.715202] systemd[1]: Mounted sys-kernel-debug.mount.
[   17.852047] systemd[1]: Mounted sys-kernel-tracing.mount.
[   18.006398] systemd[1]: Finished kmod-static-nodes.service.
[   18.170651] systemd[1]: Starting systemd-tmpfiles-setup-dev.service...
[   18.290900] systemd[1]: Finished systemd-remount-fs.service.
[   18.408573] systemd[1]: Finished systemd-sysctl.service.
[   18.898580] systemd[1]: Finished systemd-tmpfiles-setup-dev.service.
[   18.981444] systemd[1]: Reached target local-fs-pre.target.
[   19.094770] systemd[1]: Mounting tmp.mount...
[   19.199189] systemd[1]: var.mount: Directory /var to mount over is not empty, mounting anyway.
[   19.225148] systemd[1]: Mounting var.mount...
[   19.461304] systemd[1]: Starting systemd-udevd.service...
[   19.736222] systemd[1]: Mounted tmp.mount.
[   20.501277] systemd[1]: Mounting run-varoverlayfs.mount...
[   20.686990] systemd[1]: Mounted run-varoverlayfs.mount.
[   21.760832] systemd[1]: Unmounting run-varoverlayfs.mount...
[   21.988694] systemd[1]: Started systemd-journald.service.
[   25.103434] CPU: 0 PID: 558 Comm: systemd-udevd Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   25.238275] Stack : 808f0000 80885ffc 821c7a0c 00000000 00000000 92cedeab 80980000 81b193c8
[   25.245369]         80980ca7 80d43358 00000000 821b3000 ffffffff 804eea2c 821c79b8 92cedeab
[   25.408200]         00000000 00000000 8089ffb0 00000000 821c7fe0 00000000 00000000 00000000
[   25.415282]         821c7a64 00000007 00000005 00000000 80980000 80000000 8092d5e8 80bd0000
[   25.574160]         00000000 821b3000 ffffffff 00000000 8097ca9c 92cedeab 00000000 80d40000
[   25.648289]         ...
[   25.649354] Call Trace:
[   25.651810] [<80069ce0>] show_stack+0x9c/0x140
[   25.656244] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   25.788333] [<80526584>] dev_get_stats+0x58/0xfc
[   25.791569] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   25.796411] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   25.891720] [<805498f4>] rtnl_getlink+0x2ac/0x36c
[   25.895018] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   25.951801] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   25.956011] [<80591190>] netlink_unicast+0x154/0x200
[   26.013389] [<80591578>] netlink_sendmsg+0x33c/0x374
[   26.017707] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   26.071923] [<80509038>] __sys_sendto+0xdc/0x128
[   26.075157] [<80071aa4>] syscall_common+0x34/0x58
[   26.118366] 
[   26.122380] CPU: 0 PID: 559 Comm: systemd-udevd Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   26.158313] Stack : 808f0000 80885ffc 82323a0c 00000000 00000000 accd16e0 80980000 81b18348
[   26.165407]         80980ca7 80d43358 00000000 821b3cc0 ffffffff 804eea2c 823239b8 accd16e0
[   26.228272]         00000000 00000000 8089ffb0 00000000 82323fe0 00000000 00000000 00000000
[   26.235355]         82323a64 9777010b 00000001 00000000 80980000 80000000 8092d5e8 80bd0000
[   26.288310]         00000000 821b3cc0 ffffffff 00000000 8097ca9c accd16e0 00000000 80d40000
[   26.295401]         ...
[   26.297834] Call Trace:
[   26.348262] [<80069ce0>] show_stack+0x9c/0x140
[   26.351311] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   26.356419] [<80526584>] dev_get_stats+0x58/0xfc
[   26.398351] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   26.401826] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   26.406857] [<805498f4>] rtnl_getlink+0x2ac/0x36c
[   26.448346] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   26.452093] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   26.456940] [<80591190>] netlink_unicast+0x154/0x200
[   26.518265] [<80591578>] netlink_sendmsg+0x33c/0x374
[   26.521836] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   26.526867] [<80509038>] __sys_sendto+0xdc/0x128
[   26.558261] [<80071aa4>] syscall_common+0x34/0x58
[   26.561563] 
[   26.572134] CPU: 0 PID: 558 Comm: systemd-udevd Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   26.618463] Stack : 808f0000 80885ffc 821c7a0c 00000000 00000000 92cedeab 80980000 81b193c8
[   26.625550]         80980ca7 80d43358 00000000 821b3540 ffffffff 804eea2c 821c79b8 92cedeab
[   26.678342]         00000000 00000000 8089ffb0 00000000 821c7fe0 00000000 00000000 00000000
[   26.685431]         821c7a64 808e457c 00000007 00000000 80980000 80000000 8092d5e8 80bd0000
[   26.718203]         00000000 821b3540 ffffffff 00000000 8097ca9c 92cedeab 00000000 80d40000
[   26.725288]         ...
[   26.727722] Call Trace:
[   26.758292] [<80069ce0>] show_stack+0x9c/0x140
[   26.761350] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   26.766456] [<80526584>] dev_get_stats+0x58/0xfc
[   26.808277] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   26.811760] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   26.816790] [<805498f4>] rtnl_getlink+0x2ac/0x36c
[   26.848285] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   26.852035] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   26.856881] [<80591190>] netlink_unicast+0x154/0x200
[   26.888297] [<80591578>] netlink_sendmsg+0x33c/0x374
[   26.891870] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   26.896900] [<80509038>] __sys_sendto+0xdc/0x128
[   26.938270] [<80071aa4>] syscall_common+0x34/0x58
[   26.941566] 
[   26.953297] CPU: 0 PID: 559 Comm: systemd-udevd Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   27.010784] Stack : 808f0000 80885ffc 82323a0c 00000000 00000000 accd16e0 80980000 81b18348
[   27.017874]         80980ca7 80d43358 00000000 821b3000 ffffffff 804eea2c 823239b8 accd16e0
[   27.045205]         00000000 00000000 8089ffb0 00000000 82323fe0 00000000 00000000 00000000
[   27.090415]         82323a64 77b11dc0 00000000 77e739a0 80980000 80000000 8092d5e8 80bd0000
[   27.105401]         00000000 821b3000 ffffffff 00000000 8097ca9c accd16e0 00084a1f 00000001
[   27.170328]         ...
[   27.171923] Call Trace:
[   27.173854] [<80069ce0>] show_stack+0x9c/0x140
[   27.218222] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   27.221956] [<80526584>] dev_get_stats+0x58/0xfc
[   27.226577] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   27.268363] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   27.272011] [<805498f4>] rtnl_getlink+0x2ac/0x36c
[   27.276699] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   27.318350] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   27.321826] [<80591190>] netlink_unicast+0x154/0x200
[   27.326773] [<80591578>] netlink_sendmsg+0x33c/0x374
[   27.378217] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   27.381866] [<80509038>] __sys_sendto+0xdc/0x128
[   27.386476] [<80071aa4>] syscall_common+0x34/0x58
[   27.441718] 
[   28.638918] CPU: 0 PID: 556 Comm: systemd-network Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   28.658222] Stack : 808f0000 80885ffc 82195994 00000000 00000000 dad083d8 80980000 81b1e648
[   28.665309]         80980ca7 80d43358 00000000 82218200 00000000 804eea2c 82195940 dad083d8
[   28.698176]         00000000 00000000 8089ffb0 00000000 82195fe0 00000000 00000000 00000000
[   28.705262]         821959ec 80987858 fffffffd 77ad30bc 80980000 80000000 8092d5e8 80bd0000
[   28.728221]         00000000 82218200 00000000 00000000 8097ca9c dad083d8 00000000 80d40000
[   28.735310]         ...
[   28.737744] Call Trace:
[   28.758277] [<80069ce0>] show_stack+0x9c/0x140
[   28.761326] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   28.766433] [<80526584>] dev_get_stats+0x58/0xfc
[   28.786022] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   28.790931] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   28.794575] [<80547b88>] rtnl_dump_ifinfo+0x3a8/0x498
[   28.808338] [<8058f418>] netlink_dump+0x188/0x338
[   28.811640] [<8058f7b8>] netlink_recvmsg+0x1f0/0x354
[   28.816595] [<80506ad0>] ____sys_recvmsg+0x8c/0x128
[   28.838276] [<805098c8>] ___sys_recvmsg+0x84/0xc8
[   28.841577] [<8050a0a4>] __sys_recvmsg+0x64/0xa4
[   28.846191] [<80071aa4>] syscall_common+0x34/0x58
[   28.868233] 
[   28.870809] CPU: 0 PID: 556 Comm: systemd-network Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   28.898220] Stack : 808f0000 80885ffc 82195994 00000000 00000000 dad083d8 80980000 81b1e648
[   28.905310]         80980ca7 80d43358 00000000 82218200 00000000 804eea2c 82195940 dad083d8
[   28.928217]         00000000 00000000 8089ffb0 00000000 82195fe0 00000000 00000000 00000000
[   28.935298]         821959ec 00000007 00000000 00000000 80980000 80000000 8092d5e8 80bd0000
[   28.962561]         00000000 82218200 00000000 00000000 8097ca9c dad083d8 00000000 80d40000
[   28.988264]         ...
[   28.989326] Call Trace:
[   28.991783] [<80069ce0>] show_stack+0x9c/0x140
[   28.996217] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   29.018881] [<80526584>] dev_get_stats+0x58/0xfc
[   29.022111] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   29.026958] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   29.048236] [<80547b88>] rtnl_dump_ifinfo+0x3a8/0x498
[   29.051897] [<8058f418>] netlink_dump+0x188/0x338
[   29.056571] [<8058f7b8>] netlink_recvmsg+0x1f0/0x354
[   29.078267] [<80506ad0>] ____sys_recvmsg+0x8c/0x128
[   29.081749] [<805098c8>] ___sys_recvmsg+0x84/0xc8
[   29.086430] [<8050a0a4>] __sys_recvmsg+0x64/0xa4
[   29.098305] [<80071aa4>] syscall_common+0x34/0x58
[   29.101600] 
[   29.104383] CPU: 0 PID: 556 Comm: systemd-network Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   29.138125] Stack : 808f0000 80885ffc 82195994 00000000 00000000 dad083d8 80980000 81b1e648
[   29.145217]         80980ca7 80d43358 00000000 82218200 00000000 804eea2c 82195940 dad083d8
[   29.168214]         00000000 00000000 8089ffb0 00000000 82195fe0 00000000 00000000 00000000
[   29.175299]         821959ec 00000007 00000000 00000000 80980000 80000000 8092d5e8 80bd0000
[   29.208158]         00000000 82218200 00000000 00000000 8097ca9c dad083d8 00000000 80d40000
[   29.215243]         ...
[   29.217678] Call Trace:
[   29.228269] [<80069ce0>] show_stack+0x9c/0x140
[   29.231323] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   29.236430] [<80526584>] dev_get_stats+0x58/0xfc
[   29.258373] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   29.261850] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   29.266878] [<80547b88>] rtnl_dump_ifinfo+0x3a8/0x498
[   29.277702] [<8058f418>] netlink_dump+0x188/0x338
[   29.285232] [<8058f7b8>] netlink_recvmsg+0x1f0/0x354
[   29.291673] [<80506ad0>] ____sys_recvmsg+0x8c/0x128
[   29.296643] [<805098c8>] ___sys_recvmsg+0x84/0xc8
[   29.309710] [<8050a0a4>] __sys_recvmsg+0x64/0xa4
[   29.319552] [<80071aa4>] syscall_common+0x34/0x58
[   29.322846] 
[   29.396059] CPU: 0 PID: 556 Comm: systemd-network Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   29.407030] Stack : 808f0000 80885ffc 82195a0c 00000000 00000000 dad083d8 80980000 81b1e648
[   29.430248]         80980ca7 80d43358 00000000 819bcc00 ffffffff 804eea2c 821959b8 dad083d8
[   29.443605]         00000000 00000000 8089ffb0 00000000 82195fe0 00000000 00000000 00000000
[   29.457756]         82195a64 000d5102 00000000 00000000 80980000 80000000 8092d5e8 80bd0000
[   29.469324]         00000000 819bcc00 ffffffff 00000000 8097ca9c dad083d8 00000000 80d40000
[   29.481601]         ...
[   29.485120] Call Trace:
[   29.487370] [<80069ce0>] show_stack+0x9c/0x140
[   29.496608] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   29.503160] [<80526584>] dev_get_stats+0x58/0xfc
[   29.510455] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   29.517564] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   29.538385] [<805498f4>] rtnl_getlink+0x2ac/0x36c
[   29.541687] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   29.546818] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   29.568620] [<80591190>] netlink_unicast+0x154/0x200
[   29.572179] [<80591578>] netlink_sendmsg+0x33c/0x374
[   29.577134] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   29.598241] [<80509038>] __sys_sendto+0xdc/0x128
[   29.601468] [<80071aa4>] syscall_common+0x34/0x58
[   29.607616] 
[   29.625134] CPU: 0 PID: 556 Comm: systemd-network Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   29.658330] Stack : 808f0000 80885ffc 82195a0c 00000000 00000000 dad083d8 80980000 81b1e648
[   29.665423]         80980ca7 80d43358 00000000 819bcd80 ffffffff 804eea2c 821959b8 dad083d8
[   29.682160]         00000000 00000000 8089ffb0 00000000 82195fe0 00000000 00000000 00000000
[   29.699257]         82195a64 7d3d3ae5 74e00000 00000000 80980000 80000000 8092d5e8 80bd0000
[   29.720074]         00000000 819bcd80 ffffffff 00000000 8097ca9c dad083d8 00000000 80d40000
[   29.732223]         ...
[   29.733282] Call Trace:
[   29.735738] [<80069ce0>] show_stack+0x9c/0x140
[   29.743452] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   29.747182] [<80526584>] dev_get_stats+0x58/0xfc
[   29.754403] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   29.757880] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   29.765705] [<805498f4>] rtnl_getlink+0x2ac/0x36c
[   29.770336] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   29.774142] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   29.781229] [<80591190>] netlink_unicast+0x154/0x200
[   29.784790] [<80591578>] netlink_sendmsg+0x33c/0x374
[   29.797947] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   29.803937] [<80509038>] __sys_sendto+0xdc/0x128
[   29.807947] [<80071aa4>] syscall_common+0x34/0x58
[   29.819952] 
[   30.027065] ar9331_switch ethernet.1:10 lan1: configuring for phy/internal link mode
[   30.047116] CPU: 0 PID: 556 Comm: systemd-network Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   30.055929] Stack : 808f0000 80885ffc 82195884 00000000 00000000 dad083d8 80980000 81b1e648
[   30.066504]         80980ca7 80d43358 00000000 80bc6e20 00000a20 804eea2c 82195830 dad083d8
[   30.074972]         00000000 00000000 8089ffb0 00000000 82195fe0 00000000 00000000 00000000
[   30.083455]         821958dc 0000004c 00000033 6262372d 80980000 80000000 8092d5e8 80bd0000
[   30.094397]         00000000 80bc6e20 00000a20 00000000 8097ca9c dad083d8 00000000 80d40000
[   30.106987]         ...
[   30.120557] Call Trace:
[   30.122764] [<80069ce0>] show_stack+0x9c/0x140
[   30.127194] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   30.136087] [<80526584>] dev_get_stats+0x58/0xfc
[   30.141248] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   30.145433] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   30.152730] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[   30.156809] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[   30.164125] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[   30.167274] [<80534380>] __dev_notify_flags+0x50/0xd8
[   30.174629] [<80534ca0>] dev_change_flags+0x60/0x80
[   30.179482] [<80546710>] do_setlink+0x540/0x924
[   30.182618] [<80548e84>] rtnl_setlink+0xe8/0x158
[   30.187220] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   30.195546] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   30.204900] [<80591190>] netlink_unicast+0x154/0x200
[   30.211884] [<80591578>] netlink_sendmsg+0x33c/0x374
[   30.228391] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   30.232047] [<80509038>] __sys_sendto+0xdc/0x128
[   30.236657] [<80071aa4>] syscall_common+0x34/0x58
[   30.248792] 
[   30.257851] ar9331_switch ethernet.1:10 lan0: configuring for phy/internal link mode
[   30.288020] CPU: 0 PID: 556 Comm: systemd-network Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   30.299406] Stack : 808f0000 80885ffc 82195884 00000000 00000000 dad083d8 80980000 81b1e648
[   30.307244]         80980ca7 80d43358 00000000 80bc6e20 00000a20 804eea2c 82195830 dad083d8
[   30.317863]         00000000 00000000 8089ffb0 00000000 82195fe0 00000000 00000000 00000000
[   30.325293]         821958dc 0000004c 00000033 6262372d 80980000 80000000 8092d5e8 80bd0000
[   30.335871]         00000000 80bc6e20 00000a20 00000000 8097ca9c dad083d8 00000000 80d40000
[   30.344360]         ...
[   30.345418] Call Trace:
[   30.347874] [<80069ce0>] show_stack+0x9c/0x140
[   30.361686] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   30.366528] [<80526584>] dev_get_stats+0x58/0xfc
[   30.375877] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   30.381540] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   30.385190] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[   30.392930] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[   30.396574] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[   30.403442] [<80534380>] __dev_notify_flags+0x50/0xd8
[   30.407088] [<80534ca0>] dev_change_flags+0x60/0x80
[   30.414301] [<80546710>] do_setlink+0x540/0x924
[   30.417423] [<80548e84>] rtnl_setlink+0xe8/0x158
[   30.424427] [<805484c8>] rtnetlink_rcv_msg+0x2d8/0x338
[   30.434132] [<805919bc>] netlink_rcv_skb+0xc4/0x148
[   30.438008] [<80591190>] netlink_unicast+0x154/0x200
[   30.444398] [<80591578>] netlink_sendmsg+0x33c/0x374
[   30.450850] [<805067fc>] sock_sendmsg_nosec+0x1c/0x40
[   30.455473] [<80509038>] __sys_sendto+0xdc/0x128
[   30.462351] [<80071aa4>] syscall_common+0x34/0x58
[   30.465648] 
[   31.547591] ar9331_switch ethernet.1:10 lan1: Link is Up - 100Mbps/Full - flow control rx/tx
[   31.590784] IPv6: ADDRCONF(NETDEV_CHANGE): lan1: link becomes ready
[   31.633871] CPU: 0 PID: 335 Comm: kworker/0:2 Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   31.668169] Workqueue: events linkwatch_event
[   31.671131] Stack : 80980000 80980000 8089ffb0 80bd0000 00000000 80bc6e20 00000cc0 00000000
[   31.698212]         00000000 800d1268 00000000 ffffffde 00000017 804eea2c 81b4db30 be8417ff
[   31.705304]         00000000 00000000 8089ffb0 81b4d990 ffffffea 00000000 00000000 00000000
[   31.768311]         81b4dbdc 000017c4 0000001d 6e6b7761 80980000 00000000 8092d5e8 80bd0000
[   31.775399]         00000000 80bc6e20 00000cc0 00000000 00000000 be8417ff 00000000 80d40000
[   31.814234]         ...
[   31.815504] Call Trace:
[   31.817961] [<80069ce0>] show_stack+0x9c/0x140
[   31.839487] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   31.860041] [<80526584>] dev_get_stats+0x58/0xfc
[   31.865785] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   31.891483] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   31.895133] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
[   31.919685] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
[   31.929505] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
[   31.932644] [<80529d38>] netdev_state_change+0x70/0x98
[   31.937757] [<8054b688>] linkwatch_do_dev+0x7c/0xb8
[   31.968371] [<8054b890>] __linkwatch_run_queue+0xd4/0x20c
[   31.972368] [<8054ba04>] linkwatch_event+0x3c/0x48
[   31.977171] [<8009ff64>] process_one_work+0x2e4/0x4a0
[   31.998383] [<800a0770>] worker_thread+0x2a8/0x354
[   32.001781] [<800a774c>] kthread+0x16c/0x174
[   32.006027] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
[   32.028330] 
[   34.423264] random: crng init done
[   34.426731] random: 7 urandom warning(s) missed due to ratelimiting
[   34.827026] CPU: 0 PID: 574 Comm: systemd-resolve Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   34.835835] Stack : 808f0000 80885ffc 8237f994 00000000 00000000 dbbe505e 80980000 82304548
[   34.846348]         80980ca7 80d43358 00000000 82218800 00000000 804eea2c 8237f940 dbbe505e
[   34.855271]         00000000 00000000 8089ffb0 00000000 8237ffe0 00000000 00000000 00000000
[   34.863654]         8237f9ec 77ad5030 00000000 6262372d 80980000 80000000 8092d5e8 80bd0000
[   34.872116]         00000000 82218800 00000000 00000000 8097ca9c dbbe505e 00000000 80d40000
[   34.880567]         ...
[   34.881628] Call Trace:
[   34.884085] [<80069ce0>] show_stack+0x9c/0x140
[   34.891666] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   34.895398] [<80526584>] dev_get_stats+0x58/0xfc
[   34.902311] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   34.905784] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   34.913108] [<80547b88>] rtnl_dump_ifinfo+0x3a8/0x498
[   34.916764] [<8058f418>] netlink_dump+0x188/0x338
[   34.928396] [<8058f7b8>] netlink_recvmsg+0x1f0/0x354
[   34.931961] [<80506ad0>] ____sys_recvmsg+0x8c/0x128
[   34.936819] [<805098c8>] ___sys_recvmsg+0x84/0xc8
[   34.949532] [<8050a0a4>] __sys_recvmsg+0x64/0xa4
[   34.952756] [<80071aa4>] syscall_common+0x34/0x58
[   34.957427] 
[   34.962234] CPU: 0 PID: 574 Comm: systemd-resolve Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   34.972517] Stack : 808f0000 80885ffc 8237f994 00000000 00000000 dbbe505e 80980000 82304548
[   34.983372]         80980ca7 80d43358 00000000 82218800 00000000 804eea2c 8237f940 dbbe505e
[   34.991832]         00000000 00000000 8089ffb0 00000000 8237ffe0 00000000 00000000 00000000
[   35.000212]         8237f9ec 08000000 03bd0000 6262372d 80980000 80000000 8092d5e8 80bd0000
[   35.007297]         00000000 82218800 00000000 00000000 8097ca9c dbbe505e 00000000 80d40000
[   35.017904]         ...
[   35.020298] Call Trace:
[   35.021426] [<80069ce0>] show_stack+0x9c/0x140
[   35.025855] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   35.034126] [<80526584>] dev_get_stats+0x58/0xfc
[   35.037358] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   35.044712] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   35.049734] [<80547b88>] rtnl_dump_ifinfo+0x3a8/0x498
[   35.053403] [<8058f418>] netlink_dump+0x188/0x338
[   35.060232] [<8058f7b8>] netlink_recvmsg+0x1f0/0x354
[   35.063799] [<80506ad0>] ____sys_recvmsg+0x8c/0x128
[   35.070851] [<805098c8>] ___sys_recvmsg+0x84/0xc8
[   35.074149] [<8050a0a4>] __sys_recvmsg+0x64/0xa4
[   35.081067] [<80071aa4>] syscall_common+0x34/0x58
[   35.084360] 
[   35.087198] CPU: 0 PID: 574 Comm: systemd-resolve Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[   35.100389] Stack : 808f0000 80885ffc 8237f994 00000000 00000000 dbbe505e 80980000 82304548
[   35.107477]         80980ca7 80d43358 00000000 82218800 00000000 804eea2c 8237f940 dbbe505e
[   35.117978]         00000000 00000000 8089ffb0 00000000 8237ffe0 00000000 00000000 00000000
[   35.125354]         8237f9ec 77bbfdc0 56c32450 77e859a0 80980000 80000000 8092d5e8 80bd0000
[   35.135694]         00000000 82218800 00000000 00000000 8097ca9c dbbe505e 000859df 00000001
[   35.144054]         ...
[   35.145208] Call Trace:
[   35.147664] [<80069ce0>] show_stack+0x9c/0x140
[   35.155190] [<804eea2c>] ar9331_get_stats64+0x38/0x394
[   35.160297] [<80526584>] dev_get_stats+0x58/0xfc
[   35.163550] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
[   35.170840] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
[   35.174482] [<80547b88>] rtnl_dump_ifinfo+0x3a8/0x498
[   35.182042] [<8058f418>] netlink_dump+0x188/0x338
[   35.185345] [<8058f7b8>] netlink_recvmsg+0x1f0/0x354
[   35.192736] [<80506ad0>] ____sys_recvmsg+0x8c/0x128
[   35.196216] [<805098c8>] ___sys_recvmsg+0x84/0xc8
[   35.203120] [<8050a0a4>] __sys_recvmsg+0x64/0xa4
[   35.206346] [<80071aa4>] syscall_common+0x34/0x58
 
Regards,
Oleksij
Andrew Lunn Dec. 3, 2020, 2:22 p.m. UTC | #4
> @Andrew
> 
> > You could update the stats here, after the interface is down. You then
> > know the stats are actually up to date and correct!
> 
> stats are automatically read on __dev_notify_flags(), for example here:
> 
> [   11.049289] [<80069ce0>] show_stack+0x9c/0x140
> [   11.053651] [<804eea2c>] ar9331_get_stats64+0x38/0x394
> [   11.058820] [<80526584>] dev_get_stats+0x58/0xfc
> [   11.063385] [<805428c8>] rtnl_fill_stats+0x6c/0x14c
> [   11.068293] [<8054703c>] rtnl_fill_ifinfo+0x548/0xcec
> [   11.073274] [<8054a4d4>] rtmsg_ifinfo_build_skb+0xbc/0x134
> [   11.078799] [<8054a5d4>] rtmsg_ifinfo_event+0x4c/0x84
> [   11.083782] [<8054a6c8>] rtmsg_ifinfo+0x2c/0x38
> [   11.088378] [<80534380>] __dev_notify_flags+0x50/0xd8
> [   11.093365] [<80534ca0>] dev_change_flags+0x60/0x80
> [   11.098273] [<80c13fa4>] ic_close_devs+0xcc/0xdc
> [   11.102810] [<80c15200>] ip_auto_config+0x1144/0x11e4
> [   11.107847] [<80060f14>] do_one_initcall+0x110/0x2b4
> [   11.112871] [<80bf31bc>] kernel_init_freeable+0x220/0x258
> [   11.118248] [<80739a2c>] kernel_init+0x24/0x11c
> [   11.122707] [<8006306c>] ret_from_kernel_thread+0x14/0x1c
> 
> Do we really need an extra read within the ar9331 driver?

Ah, did not know that. Nice, Somebody solved this for all drivers at
once.

   Andrew
Jakub Kicinski Dec. 3, 2020, 4:35 p.m. UTC | #5
On Thu, 3 Dec 2020 09:50:11 +0100 Oleksij Rempel wrote:
> @Jakub,
> 
> > You can't take sleeping locks from .ndo_get_stats64.
> > 
> > Also regmap may sleep?
> > 
> > +	ret = regmap_read(priv->regmap, reg, &val);  
> 
> Yes. And underling layer is mdio bus which is by default sleeping as
> well.
> 
> > Am I missing something?  
> 
> In this log, the  ar9331_get_stats64() was never called from atomic or
> irq context. Why it should not be sleeping?

You missed some long discussions about this within last week on netdev.
Also Documentation/networking/statistics.rst.

To answer your direct question - try:

# cat /proc/net/dev

procfs iterates over devices while holding only an RCU read lock.
Oleksij Rempel Dec. 3, 2020, 5:53 p.m. UTC | #6
On Thu, Dec 03, 2020 at 08:35:17AM -0800, Jakub Kicinski wrote:
> On Thu, 3 Dec 2020 09:50:11 +0100 Oleksij Rempel wrote:
> > @Jakub,
> > 
> > > You can't take sleeping locks from .ndo_get_stats64.
> > > 
> > > Also regmap may sleep?
> > > 
> > > +	ret = regmap_read(priv->regmap, reg, &val);  
> > 
> > Yes. And underling layer is mdio bus which is by default sleeping as
> > well.
> > 
> > > Am I missing something?  
> > 
> > In this log, the  ar9331_get_stats64() was never called from atomic or
> > irq context. Why it should not be sleeping?
> 
> You missed some long discussions about this within last week on netdev.
> Also Documentation/networking/statistics.rst.
> 
> To answer your direct question - try:
> 
> # cat /proc/net/dev
> 
> procfs iterates over devices while holding only an RCU read lock.

Now i can reproduce it :)

[33683.199864] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:935
[33683.210737] in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 593, name: cat
[33683.216796] INFO: lockdep is turned off.
[33683.222972] CPU: 0 PID: 593 Comm: cat Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
[33683.231743] Stack : 808f0000 80885ffc 820eba5c 00000000 00000000 d4a19200 80980000 819a93c8
[33683.240093]         80980ca7 80d43358 804ee1f4 80980000 00000002 800afe08 820eba08 d4a19200
[33683.247181]         00000000 00000000 8089ffb0 00000000 820ebfe0 00000000 00000000 00000000
[33683.257767]         820ebab4 77bbfdc0 00fae587 77e859a0 80980000 80000000 00000000 80990000
[33683.266107]         804ee1f4 80980000 00000002 8200f750 8097ca9c d4a19200 000859df 00000001
[33683.274529]         ...
[33683.275626] Call Trace:
[33683.280156] [<80069ce0>] show_stack+0x9c/0x140
[33683.283200] [<800afe08>] ___might_sleep+0x220/0x244
[33683.290441] [<8073c030>] __mutex_lock+0x70/0x374
[33683.293651] [<8073c360>] mutex_lock_nested+0x2c/0x38
[33683.300793] [<804ee1f4>] ar9331_read_stats+0x34/0x834
[33683.304441] [<804eea34>] ar9331_get_stats64+0x40/0x394
[33683.311797] [<80526584>] dev_get_stats+0x58/0xfc
[33683.315013] [<805657bc>] dev_seq_printf_stats+0x44/0x228
[33683.322476] [<805659e8>] dev_seq_show+0x48/0x50
[33683.325601] [<8021dd28>] seq_read_iter+0x3d8/0x4d0
[33683.332585] [<8021df60>] seq_read+0x140/0x198
[33683.335532] [<8026f950>] proc_reg_read+0xe4/0xf8
[33683.342397] [<801f0840>] vfs_read+0xc8/0x1a8
[33683.345260] [<801f0b7c>] ksys_read+0x9c/0xfc
[33683.352056] [<80071aa4>] syscall_common+0x34/0x58

Hm.. There is no way i can guarantee that underlying mdio system is
not using mutexes. So, i can't read stats directly from HW within
ar9331_get_stats64(), only driver internal storage can be used. It is possible
to poll it more frequently, but  it make no reals sense on this low power
devices.

What kind of options do we have?

Regards,
Oleksij
Jakub Kicinski Dec. 3, 2020, 6:01 p.m. UTC | #7
On Thu, 3 Dec 2020 18:53:20 +0100 Oleksij Rempel wrote:
> On Thu, Dec 03, 2020 at 08:35:17AM -0800, Jakub Kicinski wrote:
> > On Thu, 3 Dec 2020 09:50:11 +0100 Oleksij Rempel wrote:  
> > > @Jakub,
> > >   
> > > > You can't take sleeping locks from .ndo_get_stats64.
> > > > 
> > > > Also regmap may sleep?
> > > > 
> > > > +	ret = regmap_read(priv->regmap, reg, &val);    
> > > 
> > > Yes. And underling layer is mdio bus which is by default sleeping as
> > > well.
> > >   
> > > > Am I missing something?    
> > > 
> > > In this log, the  ar9331_get_stats64() was never called from atomic or
> > > irq context. Why it should not be sleeping?  
> > 
> > You missed some long discussions about this within last week on netdev.
> > Also Documentation/networking/statistics.rst.
> > 
> > To answer your direct question - try:
> > 
> > # cat /proc/net/dev
> > 
> > procfs iterates over devices while holding only an RCU read lock.  
> 
> Now i can reproduce it :)
> 
> [33683.199864] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:935
> [33683.210737] in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 593, name: cat
> [33683.216796] INFO: lockdep is turned off.
> [33683.222972] CPU: 0 PID: 593 Comm: cat Not tainted 5.10.0-rc3-ar9331-00733-gff7090915bb7-dirty #28
> [33683.231743] Stack : 808f0000 80885ffc 820eba5c 00000000 00000000 d4a19200 80980000 819a93c8
> [33683.240093]         80980ca7 80d43358 804ee1f4 80980000 00000002 800afe08 820eba08 d4a19200
> [33683.247181]         00000000 00000000 8089ffb0 00000000 820ebfe0 00000000 00000000 00000000
> [33683.257767]         820ebab4 77bbfdc0 00fae587 77e859a0 80980000 80000000 00000000 80990000
> [33683.266107]         804ee1f4 80980000 00000002 8200f750 8097ca9c d4a19200 000859df 00000001
> [33683.274529]         ...
> [33683.275626] Call Trace:
> [33683.280156] [<80069ce0>] show_stack+0x9c/0x140
> [33683.283200] [<800afe08>] ___might_sleep+0x220/0x244
> [33683.290441] [<8073c030>] __mutex_lock+0x70/0x374
> [33683.293651] [<8073c360>] mutex_lock_nested+0x2c/0x38
> [33683.300793] [<804ee1f4>] ar9331_read_stats+0x34/0x834
> [33683.304441] [<804eea34>] ar9331_get_stats64+0x40/0x394
> [33683.311797] [<80526584>] dev_get_stats+0x58/0xfc
> [33683.315013] [<805657bc>] dev_seq_printf_stats+0x44/0x228
> [33683.322476] [<805659e8>] dev_seq_show+0x48/0x50
> [33683.325601] [<8021dd28>] seq_read_iter+0x3d8/0x4d0
> [33683.332585] [<8021df60>] seq_read+0x140/0x198
> [33683.335532] [<8026f950>] proc_reg_read+0xe4/0xf8
> [33683.342397] [<801f0840>] vfs_read+0xc8/0x1a8
> [33683.345260] [<801f0b7c>] ksys_read+0x9c/0xfc
> [33683.352056] [<80071aa4>] syscall_common+0x34/0x58
> 
> Hm.. There is no way i can guarantee that underlying mdio system is
> not using mutexes. So, i can't read stats directly from HW within
> ar9331_get_stats64(), only driver internal storage can be used. It is possible
> to poll it more frequently, but  it make no reals sense on this low power
> devices.
> 
> What kind of options do we have?

Vladimir has been looking at solving this, I'll let him answer with his
latest thoughts.
Vladimir Oltean Dec. 3, 2020, 6:01 p.m. UTC | #8
On Thu, Dec 03, 2020 at 06:53:20PM +0100, Oleksij Rempel wrote:
> It is possible to poll it more frequently, but  it make no reals sense
> on this low power devices.

Frankly I thought you understood the implications of periodic polling
and you're ok with them, just wanting to have _something_. But fine,
welcome to my world, happy to have you onboard...

> What kind of options do we have?

https://www.spinics.net/lists/netdev/msg703774.html
https://www.spinics.net/lists/netdev/msg704370.html

Unfortunately I've been absolutely snowed under with work lately. I hope
to be able to come back to that during the weekend or something like that.
Oleksij Rempel Dec. 4, 2020, 1:40 p.m. UTC | #9
On Thu, Dec 03, 2020 at 08:01:40PM +0200, Vladimir Oltean wrote:
> On Thu, Dec 03, 2020 at 06:53:20PM +0100, Oleksij Rempel wrote:
> > It is possible to poll it more frequently, but  it make no reals sense
> > on this low power devices.
> 
> Frankly I thought you understood the implications of periodic polling
> and you're ok with them,

I added polling to read out small counters to avoid overflow.

> just wanting to have _something_.

Having something is good, but making it good is better :D

> But fine,
> welcome to my world, happy to have you onboard...
> 
> > What kind of options do we have?
> 
> https://www.spinics.net/lists/netdev/msg703774.html
> https://www.spinics.net/lists/netdev/msg704370.html
> 
> Unfortunately I've been absolutely snowed under with work lately. I hope
> to be able to come back to that during the weekend or something like that.

Ok, so the strategy is to fix the original issue. Sound good.

For now I'll resend this patches without accessing mdio regs from the
stats64 callback. It will give initial play ground, so we can see what
else should be done for DSA specific use case.

Regards,
Oleksij
diff mbox series

Patch

diff --git a/drivers/net/dsa/qca/ar9331.c b/drivers/net/dsa/qca/ar9331.c
index e24a99031b80..48c81996e807 100644
--- a/drivers/net/dsa/qca/ar9331.c
+++ b/drivers/net/dsa/qca/ar9331.c
@@ -101,6 +101,57 @@ 
 	 AR9331_SW_PORT_STATUS_RX_FLOW_EN | AR9331_SW_PORT_STATUS_TX_FLOW_EN | \
 	 AR9331_SW_PORT_STATUS_SPEED_M)
 
+/* MIB registers */
+#define AR9331_MIB_COUNTER(x)			(0x20000 + ((x) * 0x100))
+
+#define AR9331_PORT_MIB_rxbroad(_port)		(AR9331_MIB_COUNTER(_port) + 0x00)
+#define AR9331_PORT_MIB_rxpause(_port)		(AR9331_MIB_COUNTER(_port) + 0x04)
+#define AR9331_PORT_MIB_rxmulti(_port)		(AR9331_MIB_COUNTER(_port) + 0x08)
+#define AR9331_PORT_MIB_rxfcserr(_port)		(AR9331_MIB_COUNTER(_port) + 0x0c)
+#define AR9331_PORT_MIB_rxalignerr(_port)	(AR9331_MIB_COUNTER(_port) + 0x10)
+#define AR9331_PORT_MIB_rxrunt(_port)		(AR9331_MIB_COUNTER(_port) + 0x14)
+#define AR9331_PORT_MIB_rxfragment(_port)	(AR9331_MIB_COUNTER(_port) + 0x18)
+#define AR9331_PORT_MIB_rx64byte(_port)		(AR9331_MIB_COUNTER(_port) + 0x1c)
+#define AR9331_PORT_MIB_rx128byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x20)
+#define AR9331_PORT_MIB_rx256byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x24)
+#define AR9331_PORT_MIB_rx512byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x28)
+#define AR9331_PORT_MIB_rx1024byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x2c)
+#define AR9331_PORT_MIB_rx1518byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x30)
+#define AR9331_PORT_MIB_rxmaxbyte(_port)	(AR9331_MIB_COUNTER(_port) + 0x34)
+#define AR9331_PORT_MIB_rxtoolong(_port)	(AR9331_MIB_COUNTER(_port) + 0x38)
+
+/* 64 bit counter */
+#define AR9331_PORT_MIB_rxgoodbyte(_port)	(AR9331_MIB_COUNTER(_port) + 0x3c)
+
+/* 64 bit counter */
+#define AR9331_PORT_MIB_rxbadbyte(_port)	(AR9331_MIB_COUNTER(_port) + 0x44)
+
+#define AR9331_PORT_MIB_rxoverflow(_port)	(AR9331_MIB_COUNTER(_port) + 0x4c)
+#define AR9331_PORT_MIB_filtered(_port)		(AR9331_MIB_COUNTER(_port) + 0x50)
+#define AR9331_PORT_MIB_txbroad(_port)		(AR9331_MIB_COUNTER(_port) + 0x54)
+#define AR9331_PORT_MIB_txpause(_port)		(AR9331_MIB_COUNTER(_port) + 0x58)
+#define AR9331_PORT_MIB_txmulti(_port)		(AR9331_MIB_COUNTER(_port) + 0x5c)
+#define AR9331_PORT_MIB_txunderrun(_port)	(AR9331_MIB_COUNTER(_port) + 0x60)
+#define AR9331_PORT_MIB_tx64byte(_port)		(AR9331_MIB_COUNTER(_port) + 0x64)
+#define AR9331_PORT_MIB_tx128byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x68)
+#define AR9331_PORT_MIB_tx256byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x6c)
+#define AR9331_PORT_MIB_tx512byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x70)
+#define AR9331_PORT_MIB_tx1024byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x74)
+#define AR9331_PORT_MIB_tx1518byte(_port)	(AR9331_MIB_COUNTER(_port) + 0x78)
+#define AR9331_PORT_MIB_txmaxbyte(_port)	(AR9331_MIB_COUNTER(_port) + 0x7c)
+#define AR9331_PORT_MIB_txoversize(_port)	(AR9331_MIB_COUNTER(_port) + 0x80)
+
+/* 64 bit counter */
+#define AR9331_PORT_MIB_txbyte(_port)		(AR9331_MIB_COUNTER(_port) + 0x84)
+
+#define AR9331_PORT_MIB_txcollision(_port)	(AR9331_MIB_COUNTER(_port) + 0x8c)
+#define AR9331_PORT_MIB_txabortcol(_port)	(AR9331_MIB_COUNTER(_port) + 0x90)
+#define AR9331_PORT_MIB_txmulticol(_port)	(AR9331_MIB_COUNTER(_port) + 0x94)
+#define AR9331_PORT_MIB_txsinglecol(_port)	(AR9331_MIB_COUNTER(_port) + 0x98)
+#define AR9331_PORT_MIB_txexcdefer(_port)	(AR9331_MIB_COUNTER(_port) + 0x9c)
+#define AR9331_PORT_MIB_txdefer(_port)		(AR9331_MIB_COUNTER(_port) + 0xa0)
+#define AR9331_PORT_MIB_txlatecol(_port)	(AR9331_MIB_COUNTER(_port) + 0xa4)
+
 /* Phy bypass mode
  * ------------------------------------------------------------------------
  * Bit:   | 0 | 1 | 2 | 3 | 4 | 5 | 6 | 7 | 8 | 9 |10 |11 |12 |13 |14 |15 |
@@ -154,6 +205,59 @@ 
 #define AR9331_SW_MDIO_POLL_SLEEP_US		1
 #define AR9331_SW_MDIO_POLL_TIMEOUT_US		20
 
+#define STATS_INTERVAL_JIFFIES			(100 * HZ)
+
+struct ar9331_sw_stats {
+	u64 rxbroad;
+	u64 rxpause;
+	u64 rxmulti;
+	u64 rxfcserr;
+	u64 rxalignerr;
+	u64 rxrunt;
+	u64 rxfragment;
+	u64 rx64byte;
+	u64 rx128byte;
+	u64 rx256byte;
+	u64 rx512byte;
+	u64 rx1024byte;
+	u64 rx1518byte;
+	u64 rxmaxbyte;
+	u64 rxtoolong;
+	u64 rxgoodbyte;
+	u64 rxbadbyte;
+	u64 rxoverflow;
+	u64 filtered;
+	u64 txbroad;
+	u64 txpause;
+	u64 txmulti;
+	u64 txunderrun;
+	u64 tx64byte;
+	u64 tx128byte;
+	u64 tx256byte;
+	u64 tx512byte;
+	u64 tx1024byte;
+	u64 tx1518byte;
+	u64 txmaxbyte;
+	u64 txoversize;
+	u64 txbyte;
+	u64 txcollision;
+	u64 txabortcol;
+	u64 txmulticol;
+	u64 txsinglecol;
+	u64 txexcdefer;
+	u64 txdefer;
+	u64 txlatecol;
+};
+
+struct ar9331_sw_priv;
+struct ar9331_sw_port {
+	int idx;
+	struct ar9331_sw_priv *priv;
+	struct delayed_work mib_read;
+	struct ar9331_sw_stats stats;
+	struct mutex lock;		/* stats access */
+};
+
 struct ar9331_sw_priv {
 	struct device *dev;
 	struct dsa_switch ds;
@@ -163,6 +267,7 @@  struct ar9331_sw_priv {
 	struct mii_bus *sbus; /* mdio slave */
 	struct regmap *regmap;
 	struct reset_control *sw_reset;
+	struct ar9331_sw_port port[AR9331_SW_PORTS];
 };
 
 /* Warning: switch reset will reset last AR9331_SW_MDIO_PHY_MODE_PAGE request
@@ -422,6 +527,7 @@  static void ar9331_sw_phylink_mac_link_down(struct dsa_switch *ds, int port,
 					    phy_interface_t interface)
 {
 	struct ar9331_sw_priv *priv = (struct ar9331_sw_priv *)ds->priv;
+	struct ar9331_sw_port *p = &priv->port[port];
 	struct regmap *regmap = priv->regmap;
 	int ret;
 
@@ -429,6 +535,8 @@  static void ar9331_sw_phylink_mac_link_down(struct dsa_switch *ds, int port,
 				 AR9331_SW_PORT_STATUS_MAC_MASK, 0);
 	if (ret)
 		dev_err_ratelimited(priv->dev, "%s: %i\n", __func__, ret);
+
+	cancel_delayed_work_sync(&p->mib_read);
 }
 
 static void ar9331_sw_phylink_mac_link_up(struct dsa_switch *ds, int port,
@@ -439,10 +547,13 @@  static void ar9331_sw_phylink_mac_link_up(struct dsa_switch *ds, int port,
 					  bool tx_pause, bool rx_pause)
 {
 	struct ar9331_sw_priv *priv = (struct ar9331_sw_priv *)ds->priv;
+	struct ar9331_sw_port *p = &priv->port[port];
 	struct regmap *regmap = priv->regmap;
 	u32 val;
 	int ret;
 
+	schedule_delayed_work(&p->mib_read, 0);
+
 	val = AR9331_SW_PORT_STATUS_MAC_MASK;
 	switch (speed) {
 	case SPEED_1000:
@@ -475,6 +586,124 @@  static void ar9331_sw_phylink_mac_link_up(struct dsa_switch *ds, int port,
 		dev_err_ratelimited(priv->dev, "%s: %i\n", __func__, ret);
 }
 
+static u32 ar9331_stat_get_val(const struct ar9331_sw_priv *priv, u32 reg)
+{
+	u32 val;
+	int ret;
+
+	ret = regmap_read(priv->regmap, reg, &val);
+	if (ret) {
+		dev_err_ratelimited(priv->dev, "%s: %i\n", __func__, ret);
+		return 0;
+	}
+
+	return val;
+}
+
+#define AR9331_READ_STATS(_port, _reg) \
+{ \
+	const struct ar9331_sw_priv *priv = _port->priv; \
+	struct ar9331_sw_stats *s = &_port->stats; \
+	int idx = _port->idx; \
+\
+	s->_reg += ar9331_stat_get_val(priv, AR9331_PORT_MIB_##_reg(idx)); \
+}
+
+static void ar9331_read_stats(struct ar9331_sw_port *port)
+{
+	mutex_lock(&port->lock);
+
+	AR9331_READ_STATS(port, rxbroad);
+	AR9331_READ_STATS(port, rxpause);
+	AR9331_READ_STATS(port, rxmulti);
+	AR9331_READ_STATS(port, rxfcserr);
+	AR9331_READ_STATS(port, rxalignerr);
+	AR9331_READ_STATS(port, rxrunt);
+	AR9331_READ_STATS(port, rxfragment);
+	AR9331_READ_STATS(port, rx64byte);
+	AR9331_READ_STATS(port, rx128byte);
+	AR9331_READ_STATS(port, rx256byte);
+	AR9331_READ_STATS(port, rx512byte);
+	AR9331_READ_STATS(port, rx1024byte);
+	AR9331_READ_STATS(port, rx1518byte);
+	AR9331_READ_STATS(port, rxmaxbyte);
+	AR9331_READ_STATS(port, rxtoolong);
+	AR9331_READ_STATS(port, rxgoodbyte);
+	AR9331_READ_STATS(port, rxbadbyte);
+	AR9331_READ_STATS(port, rxoverflow);
+	AR9331_READ_STATS(port, filtered);
+	AR9331_READ_STATS(port, txbroad);
+	AR9331_READ_STATS(port, txpause);
+	AR9331_READ_STATS(port, txmulti);
+	AR9331_READ_STATS(port, txunderrun);
+	AR9331_READ_STATS(port, tx64byte);
+	AR9331_READ_STATS(port, tx128byte);
+	AR9331_READ_STATS(port, tx256byte);
+	AR9331_READ_STATS(port, tx512byte);
+	AR9331_READ_STATS(port, tx1024byte);
+	AR9331_READ_STATS(port, tx1518byte);
+	AR9331_READ_STATS(port, txmaxbyte);
+	AR9331_READ_STATS(port, txoversize);
+	AR9331_READ_STATS(port, txbyte);
+	AR9331_READ_STATS(port, txcollision);
+	AR9331_READ_STATS(port, txabortcol);
+	AR9331_READ_STATS(port, txmulticol);
+	AR9331_READ_STATS(port, txsinglecol);
+	AR9331_READ_STATS(port, txexcdefer);
+	AR9331_READ_STATS(port, txdefer);
+	AR9331_READ_STATS(port, txlatecol);
+
+	mutex_unlock(&port->lock);
+}
+
+static void ar9331_stats_update(struct ar9331_sw_port *port,
+				struct rtnl_link_stats64 *stats)
+{
+	struct ar9331_sw_stats *s = &port->stats;
+
+	stats->rx_packets = s->rxbroad + s->rxmulti + s->rx64byte +
+		s->rx128byte + s->rx256byte + s->rx512byte + s->rx1024byte +
+		s->rx1518byte + s->rxmaxbyte;
+	stats->tx_packets = s->txbroad + s->txmulti + s->tx64byte +
+		s->tx128byte + s->tx256byte + s->tx512byte + s->tx1024byte +
+		s->tx1518byte + s->txmaxbyte;
+	stats->rx_bytes = s->rxgoodbyte;
+	stats->tx_bytes = s->txbyte;
+	stats->rx_errors = s->rxfcserr + s->rxalignerr + s->rxrunt +
+		s->rxfragment + s->rxoverflow;
+	stats->tx_errors = s->txoversize;
+	stats->multicast = s->rxmulti;
+	stats->collisions = s->txcollision;
+	stats->rx_length_errors = s->rxrunt + s->rxfragment + s->rxtoolong;
+	stats->rx_crc_errors = s->rxfcserr + s->rxalignerr + s->rxfragment;
+	stats->rx_frame_errors = s->rxalignerr;
+	stats->rx_missed_errors = s->rxoverflow;
+	stats->tx_aborted_errors = s->txabortcol;
+	stats->tx_fifo_errors = s->txunderrun;
+	stats->tx_window_errors = s->txlatecol;
+	stats->rx_nohandler = s->filtered;
+}
+
+static void ar9331_do_stats_poll(struct work_struct *work)
+{
+	struct ar9331_sw_port *port = container_of(work, struct ar9331_sw_port,
+						   mib_read.work);
+
+	ar9331_read_stats(port);
+
+	schedule_delayed_work(&port->mib_read, STATS_INTERVAL_JIFFIES);
+}
+
+static void ar9331_get_stats64(struct dsa_switch *ds, int port,
+			       struct rtnl_link_stats64 *s)
+{
+	struct ar9331_sw_priv *priv = (struct ar9331_sw_priv *)ds->priv;
+	struct ar9331_sw_port *p = &priv->port[port];
+
+	ar9331_read_stats(p);
+	ar9331_stats_update(p, s);
+}
+
 static const struct dsa_switch_ops ar9331_sw_ops = {
 	.get_tag_protocol	= ar9331_sw_get_tag_protocol,
 	.setup			= ar9331_sw_setup,
@@ -483,6 +712,7 @@  static const struct dsa_switch_ops ar9331_sw_ops = {
 	.phylink_mac_config	= ar9331_sw_phylink_mac_config,
 	.phylink_mac_link_down	= ar9331_sw_phylink_mac_link_down,
 	.phylink_mac_link_up	= ar9331_sw_phylink_mac_link_up,
+	.get_stats64		= ar9331_get_stats64,
 };
 
 static irqreturn_t ar9331_sw_irq(int irq, void *data)
@@ -781,7 +1011,7 @@  static int ar9331_sw_probe(struct mdio_device *mdiodev)
 {
 	struct ar9331_sw_priv *priv;
 	struct dsa_switch *ds;
-	int ret;
+	int ret, i;
 
 	priv = devm_kzalloc(&mdiodev->dev, sizeof(*priv), GFP_KERNEL);
 	if (!priv)
@@ -816,6 +1046,15 @@  static int ar9331_sw_probe(struct mdio_device *mdiodev)
 	ds->ops = &priv->ops;
 	dev_set_drvdata(&mdiodev->dev, priv);
 
+	for (i = 0; i < ARRAY_SIZE(priv->port); i++) {
+		struct ar9331_sw_port *port = &priv->port[i];
+
+		port->idx = i;
+		port->priv = priv;
+		mutex_init(&port->lock);
+		INIT_DELAYED_WORK(&port->mib_read, ar9331_do_stats_poll);
+	}
+
 	ret = dsa_register_switch(ds);
 	if (ret)
 		goto err_remove_irq;
@@ -831,6 +1070,13 @@  static int ar9331_sw_probe(struct mdio_device *mdiodev)
 static void ar9331_sw_remove(struct mdio_device *mdiodev)
 {
 	struct ar9331_sw_priv *priv = dev_get_drvdata(&mdiodev->dev);
+	unsigned int i;
+
+	for (i = 0; i < ARRAY_SIZE(priv->port); i++) {
+		struct ar9331_sw_port *port = &priv->port[i];
+
+		cancel_delayed_work_sync(&port->mib_read);
+	}
 
 	irq_domain_remove(priv->irqdomain);
 	mdiobus_unregister(priv->mbus);