Comments (7)
Log output showing the error:
Configuring network interfaces... [ 6.557104] net eth0: initializing cpsw version 1.12 (0)
[ 6.565215] net eth0: phy found : id is : 0x7c0f1
[ 6.570314] libphy: PHY 4a101000.mdio:01 not found
[ 6.575342] net eth0: phy 4a101000.mdio:01 not found on slave 1
[ 6.587466] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
udhcpc (v1.23.2) started
Sending discover...
Sending discover...
Sending discover...
No lease, forking to background
[ 15.831436] c_can_platform 481cc000.can can0: setting BTR=1c05 BRPE=0000
done.
Starting system message bus: Setting up watches.
Watches established.
/var/run/dbus/ CREATE system_bus_socket
Starting syslogd/klogd: done
Starting php-fpm done
Starting Connection Manager
Starting Hiawatha Web Server: hiawatha.
Starting crond: OK
Starting simple-upnpd
dbus[880]: [system] Activating service name='fi.w1.wpa_supplicant1' (using servicehelper)
dbus[880]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
[ 24.279456] ieee80211 phy0: rt2x00lib_request_firmware: Info - Loading firmware file 'rt2870.bin'
[ 24.393464] ieee80211 phy0: rt2x00lib_request_firmware: Info - Firmware detected - version: 0.29
beaglebone login: [ 24.656378] random: nonblocking pool is initialized
[ 25.206929] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 26.730822] wlan0: authenticate with 98:fc:11:ae:b5:04
[ 26.831685] wlan0: send auth to 98:fc:11:ae:b5:04 (try 1/3)
[ 26.843218] wlan0: authenticated
[ 26.881219] wlan0: associate with 98:fc:11:ae:b5:04 (try 1/3)
[ 26.899338] wlan0: RX AssocResp from 98:fc:11:ae:b5:04 (capab=0x431 status=0 aid=4)
[ 26.959517] wlan0: associated
[ 26.963460] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 34.681228] c_can_platform 481cc000.can can0: setting BTR=1c05 BRPE=0000
[ 34.688347]
[ 34.689907] =================================
[ 34.694470] [ INFO: inconsistent lock state ]
[ 34.699038] 4.1.15-venus #1 Not tainted
[ 34.703054] ---------------------------------
[ 34.707619] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
[ 34.713915] vrmlogger.py/956 [HC0[0]:SC1[1]:HE1:SE0] takes:
[ 34.719756] (pinctrl_list_mutex){+.?...}, at: [<c02586d4>] pinctrl_get+0x2c/0x458
[ 34.727732] {SOFTIRQ-ON-W} state was registered at:
[ 34.732843] [<c04be4a8>] mutex_lock_nested+0x44/0x34c
[ 34.738334] [<c02586d4>] pinctrl_get+0x2c/0x458
[ 34.743268] [<c0258b2c>] devm_pinctrl_get+0x2c/0x68
[ 34.748566] [<c02c1b58>] pinctrl_bind_pins+0x2c/0xf8
[ 34.753960] [<c02a9708>] driver_probe_device+0x60/0x2b8
[ 34.759632] [<c02a9a38>] __driver_attach+0x94/0x98
[ 34.764840] [<c02a7e54>] bus_for_each_dev+0x68/0x9c
[ 34.770140] [<c02a8f90>] bus_add_driver+0x14c/0x1f4
[ 34.775439] [<c02aa1cc>] driver_register+0x78/0xf8
[ 34.780647] [<c06c2a3c>] regulator_dummy_init+0x64/0x88
[ 34.786318] [<c06c277c>] regulator_init+0x90/0xa8
[ 34.791435] [<c0009638>] do_one_initcall+0x8c/0x1d8
[ 34.796736] [<c069ed30>] kernel_init_freeable+0x120/0x1c0
[ 34.802585] [<c04b93dc>] kernel_init+0x8/0xe8
[ 34.807347] [<c000f238>] ret_from_fork+0x14/0x3c
[ 34.812378] irq event stamp: 174360
[ 34.816031] hardirqs last enabled at (174360): [<c0071778>] vprintk_emit+0x220/0x588
[ 34.824256] hardirqs last disabled at (174359): [<c00715a8>] vprintk_emit+0x50/0x588
[ 34.832379] softirqs last enabled at (174246): [<c0035aa4>] __do_softirq+0x2d4/0x364
[ 34.840604] softirqs last disabled at (174253): [<c0035e68>] irq_exit+0xfc/0x130
[ 34.848362]
[ 34.848362] other info that might help us debug this:
[ 34.855204] Possible unsafe locking scenario:
[ 34.855204]
[ 34.861408] CPU0
[ 34.863966] ----
[ 34.866524] lock(pinctrl_list_mutex);
[ 34.870549] <Interrupt>
[ 34.873289] lock(pinctrl_list_mutex);
[ 34.877495]
[ 34.877495] *** DEADLOCK ***
[ 34.877495]
[ 34.883702] 1 lock held by vrmlogger.py/956:
[ 34.888173] #0: (((&priv->restart_timer))){+.-...}, at: [<c007c620>] call_timer_fn+0x0/0x194
[ 34.897231]
[ 34.897231] stack backtrace:
[ 34.901801] CPU: 0 PID: 956 Comm: vrmlogger.py Not tainted 4.1.15-venus #1
[ 34.909007] Hardware name: Generic AM33XX (Flattened Device Tree)
[ 34.915411] [<c00147c4>] (unwind_backtrace) from [<c0012914>] (show_stack+0x10/0x14)
[ 34.923536] [<c0012914>] (show_stack) from [<c04bb8bc>] (print_usage_bug.part.12+0x290/0x29c)
[ 34.932480] [<c04bb8bc>] (print_usage_bug.part.12) from [<c0066484>] (mark_lock+0x68c/0x770)
[ 34.941331] [<c0066484>] (mark_lock) from [<c0067158>] (__lock_acquire+0x6cc/0x1da0)
[ 34.949452] [<c0067158>] (__lock_acquire) from [<c006912c>] (lock_acquire+0xac/0x12c)
[ 34.957666] [<c006912c>] (lock_acquire) from [<c04be4a8>] (mutex_lock_nested+0x44/0x34c)
[ 34.966154] [<c04be4a8>] (mutex_lock_nested) from [<c02586d4>] (pinctrl_get+0x2c/0x458)
[ 34.974560] [<c02586d4>] (pinctrl_get) from [<c02d91c8>] (c_can_start+0x200/0x2c8)
[ 34.982502] [<c02d91c8>] (c_can_start) from [<c02d92a4>] (c_can_set_mode+0x14/0x68)
[ 34.990535] [<c02d92a4>] (c_can_set_mode) from [<c02d7a00>] (can_restart+0x94/0xc8)
[ 34.998567] [<c02d7a00>] (can_restart) from [<c007c6b4>] (call_timer_fn+0x94/0x194)
[ 35.006597] [<c007c6b4>] (call_timer_fn) from [<c007ca88>] (run_timer_softirq+0x1ec/0x2cc)
[ 35.015266] [<c007ca88>] (run_timer_softirq) from [<c00358d4>] (__do_softirq+0x104/0x364)
[ 35.023844] [<c00358d4>] (__do_softirq) from [<c0035e68>] (irq_exit+0xfc/0x130)
[ 35.031513] [<c0035e68>] (irq_exit) from [<c00729cc>] (__handle_domain_irq+0x58/0xa8)
[ 35.039727] [<c00729cc>] (__handle_domain_irq) from [<c0009458>] (omap_intc_handle_irq+0xc8/0xd0)
[ 35.049038] [<c0009458>] (omap_intc_handle_irq) from [<c04c25e4>] (__irq_usr+0x44/0x60)
[ 35.057428] Exception stack(0xdd40bfb0 to 0xdd40bff8)
[ 35.062726] bfa0: 000aec48 4f40fc94 0b8c8eab 44da029b
[ 35.071302] bfc0: 00000009 b6dc8cb4 b6dc62d4 b6dc6274 b6dc62a4 b6cf837c 00000000 b66e7a50
[ 35.079877] bfe0: b6cf8424 bef21538 b6cd4570 4f4fd72c 20000010 ffffffff
[ 35.087080] c_can_platform 481cc000.can: obtain a copy of previously claimed pinctrl
[ 35.110134] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
from venus.
I had a hunch, that since vrmlogger.py crashed above, it might be related to vrmlogger.py actually calling both connman (over D-Bus) as well as executing ifconfig as a subprocess. But that is ruled out now. Disabling vrmlogger entirely still gives a deadlock after boot.
And also rebooting multiple times gives multiple different deadlocks. Like this one, which does not mention vrmlogger.py:
dbus[926]: [system] Activating service name='fi.w1.wpa_supplicant1' (using servicehelper)
dbus[926]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
[ 29.313413] random: nonblocking pool is initialized
[ 32.735320] c_can_platform 481cc000.can can0: setting BTR=1c05 BRPE=0000
[ 32.742396]
[ 32.743957] =================================
[ 32.748519] [ INFO: inconsistent lock state ]
[ 32.753087] 4.1.15-venus #1 Not tainted
[ 32.757103] ---------------------------------
[ 32.761667] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
[ 32.767963] swapper/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
[ 32.773165] (pinctrl_list_mutex){+.?...}, at: [<c02586d4>] pinctrl_get+0x2c/0x458
[ 32.781142] {SOFTIRQ-ON-W} state was registered at:
[ 32.786253] [<c04be978>] mutex_lock_nested+0x44/0x34c
[ 32.791743] [<c02586d4>] pinctrl_get+0x2c/0x458
[ 32.796677] [<c0258b2c>] devm_pinctrl_get+0x2c/0x68
[ 32.801976] [<c02c1b58>] pinctrl_bind_pins+0x2c/0xf8
[ 32.807368] [<c02a9708>] driver_probe_device+0x60/0x2b8
[ 32.813039] [<c02a9a38>] __driver_attach+0x94/0x98
[ 32.818247] [<c02a7e54>] bus_for_each_dev+0x68/0x9c
[ 32.823545] [<c02a8f90>] bus_add_driver+0x14c/0x1f4
[ 32.828844] [<c02aa1cc>] driver_register+0x78/0xf8
[ 32.834051] [<c06c4a3c>] regulator_dummy_init+0x64/0x88
[ 32.839724] [<c06c477c>] regulator_init+0x90/0xa8
[ 32.844840] [<c0009638>] do_one_initcall+0x8c/0x1d8
[ 32.850140] [<c06a0d30>] kernel_init_freeable+0x120/0x1c0
[ 32.855988] [<c04b98ac>] kernel_init+0x8/0xe8
[ 32.860750] [<c000f238>] ret_from_fork+0x14/0x3c
[ 32.865781] irq event stamp: 38572
[ 32.869341] hardirqs last enabled at (38572): [<c0071778>] vprintk_emit+0x220/0x588
[ 32.877474] hardirqs last disabled at (38571): [<c00715a8>] vprintk_emit+0x50/0x588
[ 32.885507] softirqs last enabled at (38554): [<c0035d50>] irq_enter+0x68/0x84
[ 32.893184] softirqs last disabled at (38555): [<c0035e68>] irq_exit+0xfc/0x130
[ 32.900851]
[ 32.900851] other info that might help us debug this:
[ 32.907693] Possible unsafe locking scenario:
[ 32.907693]
[ 32.913897] CPU0
[ 32.916455] ----
[ 32.919012] lock(pinctrl_list_mutex);
[ 32.923037] <Interrupt>
[ 32.925777] lock(pinctrl_list_mutex);
[ 32.929984]
[ 32.929984] *** DEADLOCK ***
[ 32.929984]
[ 32.936191] 1 lock held by swapper/0:
[ 32.940025] #0: (((&priv->restart_timer))){+.-...}, at: [<c007c620>] call_timer_fn+0x0/0x194
[ 32.949080]
[ 32.949080] stack backtrace:
[ 32.953650] CPU: 0 PID: 0 Comm: swapper Not tainted 4.1.15-venus #1
[ 32.960218] Hardware name: Generic AM33XX (Flattened Device Tree)
[ 32.966621] [<c00147c4>] (unwind_backtrace) from [<c0012914>] (show_stack+0x10/0x14)
[ 32.974745] [<c0012914>] (show_stack) from [<c04bbd8c>] (print_usage_bug.part.12+0x290/0x29c)
[ 32.983688] [<c04bbd8c>] (print_usage_bug.part.12) from [<c0066484>] (mark_lock+0x68c/0x770)
[ 32.992537] [<c0066484>] (mark_lock) from [<c0067158>] (__lock_acquire+0x6cc/0x1da0)
[ 33.000658] [<c0067158>] (__lock_acquire) from [<c006912c>] (lock_acquire+0xac/0x12c)
[ 33.008869] [<c006912c>] (lock_acquire) from [<c04be978>] (mutex_lock_nested+0x44/0x34c)
[ 33.017356] [<c04be978>] (mutex_lock_nested) from [<c02586d4>] (pinctrl_get+0x2c/0x458)
[ 33.025762] [<c02586d4>] (pinctrl_get) from [<c02d91c8>] (c_can_start+0x200/0x2c8)
[ 33.033702] [<c02d91c8>] (c_can_start) from [<c02d92a4>] (c_can_set_mode+0x14/0x68)
[ 33.041734] [<c02d92a4>] (c_can_set_mode) from [<c02d7a00>] (can_restart+0x94/0xc8)
[ 33.049764] [<c02d7a00>] (can_restart) from [<c007c6b4>] (call_timer_fn+0x94/0x194)
[ 33.057794] [<c007c6b4>] (call_timer_fn) from [<c007ca88>] (run_timer_softirq+0x1ec/0x2cc)
[ 33.066462] [<c007ca88>] (run_timer_softirq) from [<c00358d4>] (__do_softirq+0x104/0x364)
[ 33.075039] [<c00358d4>] (__do_softirq) from [<c0035e68>] (irq_exit+0xfc/0x130)
[ 33.082707] [<c0035e68>] (irq_exit) from [<c00729cc>] (__handle_domain_irq+0x58/0xa8)
[ 33.090921] [<c00729cc>] (__handle_domain_irq) from [<c0009458>] (omap_intc_handle_irq+0xc8/0xd0)
[ 33.100230] [<c0009458>] (omap_intc_handle_irq) from [<c04c2804>] (__irq_svc+0x44/0x5c)
[ 33.108621] Exception stack(0xc06e3f50 to 0xc06e3f98)
[ 33.113917] 3f40: 00000001 00000001 00000000 c06e75f8
[ 33.122492] 3f60: c06e2000 c06e4120 00000000 c073112c 00000000 00000001 c07219b8 c06e4128
[ 33.131066] 3f80: 00000000 c06e3f98 c006674c c000faf0 200e0013 ffffffff
[ 33.138004] [<c04c2804>] (__irq_svc) from [<c000faf0>] (arch_cpu_idle+0x24/0x3c)
[ 33.145771] [<c000faf0>] (arch_cpu_idle) from [<c005e8c8>] (cpu_startup_entry+0x250/0x2d0)
[ 33.154439] [<c005e8c8>] (cpu_startup_entry) from [<c06a0c04>] (start_kernel+0x338/0x344)
[ 33.163146] c_can_platform 481cc000.can: obtain a copy of previously claimed pinctrl
[ 33.174538] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
from venus.
assigned to Denx
from venus.
Reply from Denx:
The reason is clear (there is a race condition at the start-up when pinmux is set), and the small patch below solves the issue. Patch applies to branch bbb_b4.1.15.
It was not solved upstream yet, so will be posted soon.
diff --git a/drivers/net/can/dev.c b/drivers/net/can/dev.c
index 141c2a4..2c582cd 100644
--- a/drivers/net/can/dev.c
+++ b/drivers/net/can/dev.c
@@ -21,6 +21,7 @@
#include <linux/slab.h>
#include <linux/netdevice.h>
#include <linux/if_arp.h>
+#include <linux/workqueue.h>
#include <linux/can.h>
#include <linux/can/dev.h>
#include <linux/can/skb.h>
@@ -471,9 +472,8 @@ EXPORT_SYMBOL_GPL(can_free_echo_skb);
/*
* CAN device restart for bus-off recovery
*/
-static void can_restart(unsigned long data)
+static void can_restart(struct net_device *dev)
{
- struct net_device *dev = (struct net_device *)data;
struct can_priv *priv = netdev_priv(dev);
struct net_device_stats *stats = &dev->stats;
struct sk_buff *skb;
@@ -513,6 +513,14 @@ restart:
netdev_err(dev, "Error %d during restart", err);
}
+static void can_restart_work(struct work_struct *work)
+{
+ struct delayed_work *dwork = to_delayed_work(work);
+ struct can_priv *priv = container_of(dwork, struct can_priv, restart_work);
+
+ can_restart(priv->dev);
+}
+
int can_restart_now(struct net_device *dev)
{
struct can_priv *priv = netdev_priv(dev);
@@ -526,8 +534,8 @@ int can_restart_now(struct net_device *dev)
if (priv->state != CAN_STATE_BUS_OFF)
return -EBUSY;
- /* Runs as soon as possible in the timer context */
- mod_timer(&priv->restart_timer, jiffies);
+ cancel_delayed_work_sync(&priv->restart_work);
+ can_restart(dev);
return 0;
}
@@ -548,8 +556,8 @@ void can_bus_off(struct net_device *dev)
netif_carrier_off(dev);
if (priv->restart_ms)
- mod_timer(&priv->restart_timer,
- jiffies + (priv->restart_ms * HZ) / 1000);
+ schedule_delayed_work(&priv->restart_work,
+ msecs_to_jiffies(priv->restart_ms));
}
EXPORT_SYMBOL_GPL(can_bus_off);
@@ -658,6 +666,7 @@ struct net_device *alloc_candev(int sizeof_priv, unsigned int echo_skb_max)
return NULL;
priv = netdev_priv(dev);
+ priv->dev = dev;
if (echo_skb_max) {
priv->echo_skb_max = echo_skb_max;
@@ -667,7 +676,7 @@ struct net_device *alloc_candev(int sizeof_priv, unsigned int echo_skb_max)
priv->state = CAN_STATE_STOPPED;
- init_timer(&priv->restart_timer);
+ INIT_DELAYED_WORK(&priv->restart_work, can_restart_work);
return dev;
}
@@ -742,8 +751,6 @@ int open_candev(struct net_device *dev)
if (!netif_carrier_ok(dev))
netif_carrier_on(dev);
- setup_timer(&priv->restart_timer, can_restart, (unsigned long)dev);
-
return 0;
}
EXPORT_SYMBOL_GPL(open_candev);
@@ -758,7 +765,7 @@ void close_candev(struct net_device *dev)
{
struct can_priv *priv = netdev_priv(dev);
- del_timer_sync(&priv->restart_timer);
+ cancel_delayed_work_sync(&priv->restart_work);
can_flush_echo_skb(dev);
}
EXPORT_SYMBOL_GPL(close_candev);
diff --git a/include/linux/can/dev.h b/include/linux/can/dev.h
index c3a9c8f..4f0590c 100644
--- a/include/linux/can/dev.h
+++ b/include/linux/can/dev.h
@@ -31,6 +31,7 @@ enum can_mode {
* CAN common private data
*/
struct can_priv {
+ struct net_device *dev;
struct can_device_stats can_stats;
struct can_bittiming bittiming, data_bittiming;
@@ -43,7 +44,7 @@ struct can_priv {
u32 ctrlmode_supported;
int restart_ms;
- struct timer_list restart_timer;
+ struct delayed_work restart_work;
int (*do_set_bittiming)(struct net_device *dev);
int (*do_set_data_bittiming)(struct net_device *dev);
from venus.
tested, the patch fixes the issue.
applied
victronenergy/linux@0f6681e
from venus.
Patch was submitted to upstream, and applied to can:
http://marc.info/?l=linux-can&m=147453139610015&w=2
from venus.
and applied to net:
https://www.mail-archive.com/[email protected]/msg130014.html
So next step is linux (?)
from venus.
Related Issues (20)
- Add a QML page to interact with Node-Red HOT 6
- ESS: SoC minimum setup interval 1%, not 5% HOT 1
- systemcalc: DVCC User charge current limit is ignored in systems with a VE.Bus BMS
- can-bus-bms: detect WeCo battery
- SignalK: update signalk-n2kais-0183 to latest version HOT 1
- can-bus-bms: Remove hardcoded DeviceInstance 512, allocate dynamically
- AC Loads calculation wrong when feeding to grid HOT 4
- Support Mopeka universal tank sensors HOT 1
- Generator start/stop: handle generators with their own stop delay HOT 20
- Save names
- Add support for Sunspec protocol to Cerbo GX/Venus OS
- Does this work on old MultiPlus Compact? HOT 1
- hub4control: Make pv inverter offset configurable HOT 2
- Battery menu qml: donβt show history item in the menu if there is no history
- Fronius: Improve detection of 3-phase inverters using SolarApi HOT 3
- systemcalc additions
- localsettings: ClassAndVrmInstance becomes None HOT 1
- Vebus: Energy counter readout disabled on systems with many VE.Bus errors HOT 3
- mk2-dbus & modbus: add boost factor & inverter output voltage settings HOT 2
- Make temperature calibration menu parameters user & installer instead of superuser
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
π Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. πππ
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google β€οΈ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from venus.