Re: [BUG 4.9] New led trigger usbport gets the kernel to panic

From: Rafal Milecki
Date: Mon Nov 28 2016 - 19:50:25 EST


Hi Ralph,

On 11/21/2016 09:40 AM, Ralph Sennhauser wrote:
I tried your new usbport trigger in Linux 4.9 with little luck as can be seen in
the following output of the serial console.

I'm really happy my trigger got some attention. I'm sorry it crashes for you,
I never experienced any crash so far. I also got few ppl using it as part of
LEDE project but no reports from them neither.

Also sorry for the late reply, my private life took all my time previous week.


root@wrt1900acs:/# cd /sys/class/leds/pca963x\:shelby\:white\:usb2/
root@wrt1900acs:/sys/devices/platform/soc/soc:internal-regs/f1011000.i2c/i2c-0/0-0068/leds/pca963x:shelby:white:usb2# echo usbport > trigger
root@wrt1900acs:/sys/devices/platform/soc/soc:internal-regs/f1011000.i2c/i2c-0/0-0068/leds/pca963x:shelby:white:usb2# echo 1 > ports/usb2-port1
[ 1461.761528] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[ 1461.769734] pgd = de33c000
[ 1461.772454] [00000000] *pgd=1cb2a831, *pte=00000000, *ppte=00000000
[ 1461.778791] Internal error: Oops: 80000007 [#1] SMP ARM
[ 1461.784036] Modules linked in: iptable_nat nft_chain_nat_ipv4 nf_tables_inet
nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 ipt_REJECT ipt_MASQUERADE
xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit
xt_conntrack xt_comment xt_TCP MSS xt_REDIRECT xt_LOG xt_CT nft_set_rbtree
nft_set_hash nft_reject_inet nft_reject nft_redir_ipv4 nft_redir nft_nat
nft_meta nft_masq_ipv4 nft_masq nft_log nft_limit nft_hash nft_exthdr nft_ct
nft_counter nft_chain_route_ipv6 nft_chain_route_ipv4 nf_tabl es_ipv6
nf_tables_ipv4 nf_tables nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4
nf_nat nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_netlink
nf_conntrack macvlan libcrc32c iptable_raw iptable_mangle iptable_filter
ip_tables act_skbedit act _mirred em_u32 cls_u32 cls_tcindex cls_flow cls_route
cls_fw sch_hfsc sch_ingress mwlwifi(O) mac80211 cfg80211 ledtrig_netdev(O)
ip_set_list_set ip_set_hash_netiface ip_set_hash_netport ip_set_hash_netnet
ip_set_hash_net ip_set_hash_netportnet ip_set_hash _mac ip_set_hash_ipportnet
ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip
ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set nfnetlink
ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_raw
ip6table_mangle ip6table_filter ip6_tables x_tables ifb sit tunnel4 ip_tunnel
vfat fat nls_utf8 nls_iso8859_1 nls_cp850 nls_cp437 rfkill input_core
sha256_generic seqiv jitterentropy_rng drbg hmac ghash_generic gf128mul gcm ctr
ccm ledtrig_usbport ext4 jbd2 mbcache btrf s xor raid6_pq crc32c_generic ubifs
ubi
[ 1461.922401] CPU: 0 PID: 759 Comm: ash Tainted: G O 4.9.0-rc6 #2
[ 1461.929476] Hardware name: Marvell Armada 380/385 (Device Tree)
[ 1461.935418] task: df621080 task.stack: dee0e000
[ 1461.939966] PC is at 0x0
[ 1461.942510] LR is at usbport_trig_port_store+0x8c/0xd8 [ledtrig_usbport]
[ 1461.949238] pc : [<00000000>] lr : [<bf2281f0>] psr: 60000013
[ 1461.949238] sp : dee0fe50 ip : dee0fe10 fp : dee0fe6c
[ 1461.960761] r10: 00000000 r9 : 00000000 r8 : 00000000
[ 1461.966006] r7 : dcabc7c0 r6 : df4164ec r5 : 00000002 r4 : dcabc040
[ 1461.972558] r3 : 00000000 r2 : 0000001a r1 : 00000000 r0 : df4164ec
[ 1461.979112] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment none
[ 1461.986275] Control: 10c5387d Table: 1e33c04a DAC: 00000051
[ 1461.992043] Process ash (pid: 759, stack limit = 0xdee0e210)
[ 1461.997724] Stack: (0xdee0fe50 to 0xdee10000)
[ 1462.002097] fe40: bf228164 00000002 dee0ff80 dcabc7c0
[ 1462.010309] fe60: dee0fe84 dee0fe70 c023f758 bf228170 c023f738 00000002 dee0fe9c dee0fe88
[ 1462.018520] fe80: c0169310 c023f744 df4a1000 00000002 dee0fedc dee0fea0 c0168ab8 c01692d4
[ 1462.026731] fea0: 00000000 00000000 df747c10 df4a100c d4aca1c9 df727a80 c01689c0 dee0ff80
[ 1462.034943] fec0: 00000002 c000fc24 dee0e000 00000000 dee0ff4c dee0fee0 c0100c78 c01689cc
[ 1462.043153] fee0: 00000000 dee0fee8 dee0ff14 dee0fef8 dee0ff14 dee0ff00 c0060668 c04640a0
[ 1462.051365] ff00: dee0ff50 df621350 dee0ff4c dee0ff18 c00298f8 c0060630 fffffff6 dee0ff68
[ 1462.059576] ff20: c00ff23c 00000007 00000002 df727a80 b6f092d0 dee0ff80 c000fc24 dee0e000
[ 1462.067786] ff40: dee0ff7c dee0ff50 c0101ae4 c0100c50 00000003 00000007 df727a80 df727a80
[ 1462.075997] ff60: b6f092d0 00000002 c000fc24 dee0e000 dee0ffa4 dee0ff80 c01028dc c0101a44
[ 1462.084208] ff80: 00000000 00000000 00000000 00000000 ffffffff 00000004 00000000 dee0ffa8
[ 1462.092419] ffa0: c000fa60 c010289c 00000000 00000000 00000001 b6f092d0 00000002 00000000
[ 1462.100630] ffc0: 00000000 00000000 ffffffff 00000004 b6f092d0 00000020 00059ec0 00059ea0
[ 1462.108841] ffe0: beb744f8 beb744e4 b6ee1904 b6ee0dc8 60000010 00000001 00000000 00000000
[ 1462.117049] Backtrace:
[ 1462.119521] [<bf228164>] (usbport_trig_port_store [ledtrig_usbport]) from [<c023f758>] (dev_attr_store+0x20/0x2c)
[ 1462.129826] r7:dcabc7c0 r6:dee0ff80 r5:00000002 r4:bf228164
[ 1462.135511] [<c023f738>] (dev_attr_store) from [<c0169310>] (sysfs_kf_write+0x48/0x4c)
[ 1462.143459] r5:00000002 r4:c023f738
[ 1462.147049] [<c01692c8>] (sysfs_kf_write) from [<c0168ab8>] (kernfs_fop_write+0xf8/0x1f8)
[ 1462.155258] r5:00000002 r4:df4a1000
[ 1462.158850] [<c01689c0>] (kernfs_fop_write) from [<c0100c78>] (__vfs_write+0x34/0x120)
[ 1462.166800] r10:00000000 r9:dee0e000 r8:c000fc24 r7:00000002 r6:dee0ff80 r5:c01689c0
[ 1462.174660] r4:df727a80
[ 1462.177204] [<c0100c44>] (__vfs_write) from [<c0101ae4>] (vfs_write+0xac/0x170)
[ 1462.184543] r9:dee0e000 r8:c000fc24 r7:dee0ff80 r6:b6f092d0 r5:df727a80 r4:00000002
[ 1462.192319] [<c0101a38>] (vfs_write) from [<c01028dc>] (SyS_write+0x4c/0xa8)
[ 1462.199396] r9:dee0e000 r8:c000fc24 r7:00000002 r6:b6f092d0 r5:df727a80 r4:df727a80
[ 1462.207174] [<c0102890>] (SyS_write) from [<c000fa60>] (ret_fast_syscall+0x0/0x3c)
[ 1462.214774] r7:00000004 r6:ffffffff r5:00000000 r4:00000000
[ 1462.220456] Code: bad PC value
[ 1462.223560] ---[ end trace 676638a3a12c7a56 ]---
[ 1462.228197] Kernel panic - not syncing: Fatal exception
[ 1462.233445] CPU1: stopping
[ 1462.236165] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G D O 4.9.0-rc6 #2
[ 1462.243590] Hardware name: Marvell Armada 380/385 (Device Tree)
[ 1462.249531] Backtrace:
[ 1462.252001] [<c00138a8>] (dump_backtrace) from [<c0013b7c>] (show_stack+0x18/0x1c)
[ 1462.259601] r7:df47ff48 r6:60000193 r5:c07dea44 r4:00000000
[ 1462.265285] [<c0013b64>] (show_stack) from [<c01b4fb8>] (dump_stack+0x94/0xa8)
[ 1462.272538] [<c01b4f24>] (dump_stack) from [<c0016bdc>] (handle_IPI+0x178/0x198)
[ 1462.279963] r7:df47ff48 r6:00000000 r5:00000001 r4:c07f9230
[ 1462.285645] [<c0016a64>] (handle_IPI) from [<c00094e4>] (gic_handle_irq+0x90/0x94)
[ 1462.293245] r7:df47ff48 r6:e080210c r5:c07cfbb8 r4:c07ded00
[ 1462.298927] [<c0009454>] (gic_handle_irq) from [<c00146cc>] (__irq_svc+0x6c/0x90)
[ 1462.306439] Exception stack(0xdf47ff48 to 0xdf47ff90)
[ 1462.311510] ff40: 00000001 00000000 00000000 c0020580 df47e000 c07cf02c
[ 1462.319721] ff60: c07cf07c 00000002 00000000 00000000 c07ca378 df47ffa4 df47ffa8 df47ff98
[ 1462.327932] ff80: c00105ac c00105b0 60000013 ffffffff
[ 1462.333004] r9:df47e000 r8:00000000 r7:df47ff7c r6:ffffffff r5:60000013 r4:c00105b0
[ 1462.340781] [<c0010570>] (arch_cpu_idle) from [<c0463f4c>] (default_idle_call+0x28/0x34)
[ 1462.348908] [<c0463f24>] (default_idle_call) from [<c0061494>] (cpu_startup_entry+0x118/0x1f0)
[ 1462.357557] [<c006137c>] (cpu_startup_entry) from [<c0016808>] (secondary_start_kernel+0x150/0x15c)
[ 1462.366638] r7:c07f9240
[ 1462.369181] [<c00166b8>] (secondary_start_kernel) from [<0000962c>] (0x962c)
[ 1462.376256] r5:00000051 r4:1f46406a
[ 1462.379845] Rebooting in 3 seconds..


Would you happen to have an idea what is going wrong here?

I can't see any obvious bug in the trigger code. Could you apply attached
debugging patch and provide another log, please?


diff --git a/drivers/usb/core/ledtrig-usbport.c b/drivers/usb/core/ledtrig-usbport.c
index 3ed5162..1e30922 100644
--- a/drivers/usb/core/ledtrig-usbport.c
+++ b/drivers/usb/core/ledtrig-usbport.c
@@ -73,7 +73,9 @@ static void usbport_trig_update_count(struct usbport_trig_data *usbport_data)
struct led_classdev *led_cdev = usbport_data->led_cdev;

usbport_data->count = 0;
+ pr_info("[%s] usbport_data->count:%d\n", __func__, usbport_data->count);
usb_for_each_dev(usbport_data, usbport_trig_usb_dev_check);
+ pr_info("[%s] usbport_data->count:%d\n", __func__, usbport_data->count);
led_cdev->brightness_set(led_cdev,
usbport_data->count ? LED_FULL : LED_OFF);
}
@@ -96,9 +98,15 @@ static ssize_t usbport_trig_port_store(struct device *dev,
struct device_attribute *attr,
const char *buf, size_t size)
{
- struct usbport_trig_port *port = container_of(attr,
+ struct usbport_trig_port *port;
+
+ dev_info(dev, "[%s] buf:%s size:%zu\n", __func__, buf, size);
+
+ port = container_of(attr,
struct usbport_trig_port,
attr);
+ dev_info(dev, "[%s] port:%p\n", __func__, port);
+ dev_info(dev, "[%s] port->port_name:%s port->data:%p\n", __func__, port->port_name, port->data);

if (!strcmp(buf, "0") || !strcmp(buf, "0\n"))
port->observed = 0;
@@ -109,6 +117,7 @@ static ssize_t usbport_trig_port_store(struct device *dev,

usbport_trig_update_count(port->data);

+ dev_info(dev, "[%s] size:%zu\n", __func__, size);
return size;
}

@@ -163,6 +172,8 @@ static int usbport_trig_add_port(struct usbport_trig_data *usbport_data,

list_add_tail(&port->list, &usbport_data->ports);

+ dev_info(led_cdev->dev, "[%s] port:%p\n", __func__, port);
+ dev_info(led_cdev->dev, "[%s] port->port_name:%s port->data:%p\n", __func__, port->port_name, port->data);
return 0;

err_free_port_name: