Kernal Oops near `_rtw_open_pktfile`

[nisargjhaveri]

syslog gives,

Jan 16 23:33:45 raspberrypi kernel: [27574.739924] Unable to handle kernel NULL pointer dereference at virtual address 000000ac
Jan 16 23:33:45 raspberrypi kernel: [27574.760203] pgd = c0004000
Jan 16 23:33:45 raspberrypi kernel: [27574.774195] [000000ac] *pgd=00000000
Jan 16 23:33:45 raspberrypi kernel: [27574.785640] Internal error: Oops: 17 [#1] ARM
Jan 16 23:33:45 raspberrypi kernel: [27574.792441] Modules linked in: cfg80211 rfkill bridge stp llc asix 8188eu(O) libphy ip6table_filter ip6_tables ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_filter ip_tables x_tables snd_bcm2835 snd_pcm snd_timer snd bcm2835_gpiomem bcm2835_wdt uio_pdrv_genirq uio ipv6
Jan 16 23:33:45 raspberrypi kernel: [27574.836362] CPU: 0 PID: 425 Comm: RTW_CMD_THREAD Tainted: G           O    4.4.38+ #938
Jan 16 23:33:45 raspberrypi kernel: [27574.849833] Hardware name: BCM2708
Jan 16 23:33:45 raspberrypi kernel: [27574.855995] task: d8ce8da0 ti: d8ef6000 task.ti: d8ef6000
Jan 16 23:33:45 raspberrypi kernel: [27574.865078] PC is at _rtw_open_pktfile+0x18/0x40 [8188eu]
Jan 16 23:33:45 raspberrypi kernel: [27574.874122] LR is at rtw_xmitframe_coalesce+0x110/0xe6c [8188eu]
Jan 16 23:33:45 raspberrypi kernel: [27574.883101] pc : [<bf1e113c>]    lr : [<bf1a1b40>]    psr: 20000013
Jan 16 23:33:45 raspberrypi kernel: [27574.883101] sp : d8ef7df0  ip : d8ef7e00  fp : d8ef7dfc
Jan 16 23:33:45 raspberrypi kernel: [27574.900425] r10: 00000000  r9 : dcf60894  r8 : dcf60958
Jan 16 23:33:45 raspberrypi kernel: [27574.908589] r7 : 000000ff  r6 : dcf47af0  r5 : 00000000  r4 : 00000001
Jan 16 23:33:45 raspberrypi kernel: [27574.918097] r3 : 00000001  r2 : 00000c17  r1 : d8ef7e78  r0 : 00000000
Jan 16 23:33:45 raspberrypi kernel: [27574.927504] Flags: nzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment kernel
Jan 16 23:33:45 raspberrypi kernel: [27574.937702] Control: 00c5387d  Table: 18cc0008  DAC: 00000055
Jan 16 23:33:45 raspberrypi kernel: [27574.946392] Process RTW_CMD_THREAD (pid: 425, stack limit = 0xd8ef6188)
Jan 16 23:33:45 raspberrypi kernel: [27574.956039] Stack: (0xd8ef7df0 to 0xd8ef8000)
Jan 16 23:33:45 raspberrypi kernel: [27574.963438] 7de0:                                     d8ef7ebc d8ef7e00 bf1a1b40 bf1e1130
Jan 16 23:33:45 raspberrypi kernel: [27574.977537] 7e00: 00000000 60000013 60000013 bf1c70c4 d8ef7e3c d8ef7e20 dcf47b48 dcdfb6c0
Jan 16 23:33:45 raspberrypi kernel: [27574.991578] 7e20: dcdfa000 c088dc3c bf1c70c4 0000004b 00000020 d8ed0020 c00254d8 00000001
Jan 16 23:33:45 raspberrypi kernel: [27575.005648] 7e40: d8ef7e6c d8ef7e50 00000000 00208040 00299dfa 0000000a bf18de60 60000093
Jan 16 23:33:45 raspberrypi kernel: [27575.019883] 7e60: bf1c70c4 60000093 bf1c70c4 dcdfb468 dcf510f0 dcf60958 00000000 d8ef7e88
Jan 16 23:33:45 raspberrypi kernel: [27575.034410] 7e80: 00000200 bf1c70c4 dcdfb468 dcf510f0 d8ef7ebc dcdfa000 dcf47af0 dcdfb468
Jan 16 23:33:45 raspberrypi kernel: [27575.049173] 7ea0: dcf510f0 dcf60958 00000011 00000000 d8ef7edc d8ef7ec0 bf1c70f0 bf1a1a3c
Jan 16 23:33:45 raspberrypi kernel: [27575.064192] 7ec0: dcf47af0 dcf4d644 dcf60894 00000001 d8ef7eec d8ef7ee0 bf1b0fe8 bf1c706c
Jan 16 23:33:45 raspberrypi kernel: [27575.079547] 7ee0: d8ef7f24 d8ef7ef0 bf18de78 bf1b0fcc 60000013 dcdfa000 dcdfb3a0 d8d09820
Jan 16 23:33:45 raspberrypi kernel: [27575.095055] 7f00: dcdfa000 dcdfb3a0 bf1e1bb0 bf207f18 d8dd9200 bf1e6c38 d8ef7f64 d8ef7f28
Jan 16 23:33:45 raspberrypi kernel: [27575.110693] 7f20: bf16db20 bf18dd7c d8d4c020 dcdfa000 bf16d95c dcdfb3ac 00000000 00000000
Jan 16 23:33:45 raspberrypi kernel: [27575.126503] 7f40: d8d4c020 dcdfa000 bf16d95c 00000000 00000000 00000000 d8ef7fac d8ef7f68
Jan 16 23:33:45 raspberrypi kernel: [27575.142399] 7f60: c003d2e8 bf16d968 d8ef6000 00000000 d8d4c020 dcdfa000 00000000 d8ef7f7c
Jan 16 23:33:45 raspberrypi kernel: [27575.158296] 7f80: d8ef7f7c 00000000 d8ef7f88 d8ef7f88 d8d4c020 c003d20c 00000000 00000000
Jan 16 23:33:45 raspberrypi kernel: [27575.174195] 7fa0: 00000000 d8ef7fb0 c000f8a8 c003d218 00000000 00000000 00000000 00000000
Jan 16 23:33:45 raspberrypi kernel: [27575.190090] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Jan 16 23:33:45 raspberrypi kernel: [27575.205985] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000 e59420d4 e59d3014
Jan 16 23:33:45 raspberrypi kernel: [27575.223245] [<bf1e113c>] (_rtw_open_pktfile [8188eu]) from [<bf1a1b40>] (rtw_xmitframe_coalesce+0x110/0xe6c [8188eu])
Jan 16 23:33:45 raspberrypi kernel: [27575.243044] [<bf1a1b40>] (rtw_xmitframe_coalesce [8188eu]) from [<bf1c70f0>] (rtl8188eu_hal_xmit+0x90/0x1a4 [8188eu])
Jan 16 23:33:45 raspberrypi kernel: [27575.262842] [<bf1c70f0>] (rtl8188eu_hal_xmit [8188eu]) from [<bf1b0fe8>] (rtw_hal_xmit+0x28/0x34 [8188eu])
Jan 16 23:33:45 raspberrypi kernel: [27575.281662] [<bf1b0fe8>] (rtw_hal_xmit [8188eu]) from [<bf18de78>] (tx_beacon_hdl+0x108/0x170 [8188eu])
Jan 16 23:33:45 raspberrypi kernel: [27575.300194] [<bf18de78>] (tx_beacon_hdl [8188eu]) from [<bf16db20>] (rtw_cmd_thread+0x1c4/0x30c [8188eu])
Jan 16 23:33:45 raspberrypi kernel: [27575.318340] [<bf16db20>] (rtw_cmd_thread [8188eu]) from [<c003d2e8>] (kthread+0xdc/0xf8)
Jan 16 23:33:45 raspberrypi kernel: [27575.334285] [<c003d2e8>] (kthread) from [<c000f8a8>] (ret_from_fork+0x14/0x2c)
Jan 16 23:33:45 raspberrypi kernel: [27575.345495] Code: e24cb004 e52de004 e8bd4000 e5810000 (e59030ac) 
Jan 16 23:33:45 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Mon Jan 16 23:35:15 2017 [try http://www.rsyslog.com/e/2007 ]
Jan 16 23:33:45 raspberrypi kernel: [27575.449695] ---[ end trace b0684affe5c245a8 ]---

I'm using master branch of this repo.

$ uname -a
Linux raspberrypi 4.4.38+ #938 Thu Dec 15 15:17:54 GMT 2016 armv6l GNU/Linux

[lwfinger]

I just pushed some changes that will guard against NULL pointers in that routine.

Please run with the new code, and report what message is actually reported. A proper fix will require adding a return value to _rtw_open_pktfile, or fixing the code to avoid calling the routine when something is wrong. Knowing which one is wrong will help.

[nisargjhaveri]

Sure. I'll try the new code and report if I find anything. Unfortunately, the problem is that I can't figure out how to reproduce this. This happened a couple of times, and today I was able to grab the logs. Any ideas on how can I reproduce this?

[lwfinger]

I have looked at rtw_xmitframe_coalesce() which is the routine that is calling _rtw_open_pktfile() when the crash happens. I now know how to guard against that problem, but I do not know what causes it.

I just pushed an additional change that will prevent this crash. Try it and report any other problems.