On Fri, Aug 12, 2016 at 1:01 AM, Jaehoon Chung <[email protected]> wrote: > On 08/12/2016 04:13 PM, John Stultz wrote: >> On Thu, Aug 4, 2016 at 9:52 PM, John Stultz <[email protected]> wrote: >>> Hey Ulf, >>> Since moving my HiKey branch to pre-v4.8-rc1 (linus's HEAD), I've >>> been seeing the following warning occasionally. Usually after seeing >>> it, the system will refuse to reboot (system does the "Emergency >>> remount complete" but then just sits there, and if I ctrl-c I can use >>> the shell fine but many commands will get me stuck). >>> >>> Anyway, if you have any ideas... >>> >>> thanks >>> -john >>> >>> [ 24.154245] ------------[ cut here ]------------ >>> [ 24.158903] WARNING: CPU: 2 PID: 1273 at >>> drivers/mmc/core/core.c:991 mmc_release_host+0xa0/0xa8 >>> [ 24.167605] >>> [ 24.169104] CPU: 2 PID: 1273 Comm: mmcqd/0 Not tainted >>> 4.7.0-11945-gb30f1d6-dirty #706 >>> [ 24.177024] Hardware name: HiKey Development Board (DT) >>> [ 24.182253] task: ffffffc0793d8c80 task.stack: ffffffc078c48000 >>> [ 24.188178] PC is at mmc_release_host+0xa0/0xa8 >>> [ 24.192725] LR is at mmc_put_card+0x18/0x3c >>> [ 24.196917] pc : [<ffffff80086c2550>] lr : [<ffffff80086c31f4>] >>> pstate: 80000145 >>> [ 24.204317] sp : ffffffc078c4bd20 >>> [ 24.207636] x29: ffffffc078c4bd20 x28: 0000000000000000 >>> [ 24.212975] x27: 0000000000000000 x26: ffffffc077903420 >>> [ 24.216220] x25: ffffffc078788028 x24: ffffffc0787e8800 >>> [ 24.216232] x23: ffffffc078788000 x22: 0000000000000000 >>> [ 24.216243] x21: 0000000000000000 x20: ffffffc078788018 >>> [ 24.216254] x19: ffffffc0787e8800 x18: 0000000000000000 >>> [ 24.216265] x17: 0000000000000000 x16: 0000000000000000 >>> [ 24.216276] x15: 0000000000000000 x14: ffffffc078789430 >>> [ 24.216288] x13: 000000000000002f x12: 000000000000b853 >>> [ 24.216299] x11: ffffffc077903420 x10: 0000000000000860 >>> [ 24.216310] x9 : ffffffc078c48000 x8 : ffffffc0793d9540 >>> [ 24.216322] x7 : 0000000000d3f8c7 x6 : 0000000000002bd0 >>> [ 24.216333] x5 : 00000000021458fa x4 : 00ffffffffffffff >>> [ 24.216344] x3 : 00000000d0555555 x2 : ffffffc078c4bd5c >>> [ 24.216355] x1 : 0000000000000000 x0 : 0000000000000000 >>> [ 24.216366] >>> [ 24.216372] ---[ end trace 74dade4766b71d8d ]--- >>> [ 24.216377] Call trace: >>> [ 24.216386] Exception stack(0xffffffc078c4bb50 to 0xffffffc078c4bc80) >>> [ 24.216394] bb40: >>> ffffffc0787e8800 0000008000000000 >>> [ 24.216403] bb60: ffffffc078c4bd20 ffffff80086c2550 >>> ffffff8008ca6000 ffffffc0784fb200 >>> [ 24.216411] bb80: ffffffc07bf4b7e8 0000000000000008 >>> ffffffc0793d8d00 ffffff8008c82780 >>> [ 24.216420] bba0: ffffffc078c4bbe0 ffffff800843576c >>> ffffffc078c4bbf0 ffffff800843576c >>> [ 24.216429] bbc0: ffffffc078c4bcc0 ffffffc078c4bc78 >>> ffffffc078c4bc10 ffffff800843576c >>> [ 24.216437] bbe0: ffffffc078c4bce0 ffffffc078c4bc98 >>> 0000000000000000 0000000000000000 >>> [ 24.216445] bc00: ffffffc078c4bd5c 00000000d0555555 >>> 00ffffffffffffff 00000000021458fa >>> [ 24.216452] bc20: 0000000000002bd0 0000000000d3f8c7 >>> ffffffc0793d9540 ffffffc078c48000 >>> [ 24.216460] bc40: 0000000000000860 ffffffc077903420 >>> 000000000000b853 000000000000002f >>> [ 24.216467] bc60: ffffffc078789430 0000000000000000 >>> 0000000000000000 0000000000000000 >>> [ 24.216479] [<ffffff80086c2550>] mmc_release_host+0xa0/0xa8 >>> [ 24.216486] [<ffffff80086c31f4>] mmc_put_card+0x18/0x3c >>> [ 24.216497] [<ffffff80086d30e4>] mmc_blk_issue_rq+0x11c/0x4a4 >>> [ 24.216506] [<ffffff80086d3e44>] mmc_queue_thread+0x98/0x158 >>> [ 24.216517] [<ffffff80080cfd7c>] kthread+0xd0/0xe4 >>> [ 24.216527] [<ffffff8008082e90>] ret_from_fork+0x10/0x40 >> >> >> Hey Ulf, >> I *think* I've narrowed this down to >> 6024e16654c1e1a2475e848d735963d05a12dba9 ("mmc: dw_mmc: set to >> MMC_CAP_ERASE by default"). Its fairly sporadic so I may be seeing >> this as a false positive, but after reverting that patch I've >> seemingly stopped seeing the issue. > > Hmm, i don't think so. I *guess* it's not related with commit 6024e16654.
Well, with that patch reverted I've not seen the issue, but with it I can trigger it fairly quickly. > Before calling mmc_put_card(), is it issued the discard request? > > if ((!req && !(mq->flags & MMC_QUEUE_NEW_REQUEST)) || > (cmd_flags & MMC_REQ_SPECIAL_MASK)) > > Which condition hit? So I'm seeing those conditions hit quite a lot: [ 45.056827] JDB: !req: 0 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 1 [ 45.066299] JDB: !req: 1 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 0 [ 45.135398] JDB: !req: 1 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 0 [ 45.143085] JDB: !req: 1 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 0 [ 45.152183] JDB: !req: 1 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 0 [ 45.161129] JDB: !req: 1 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 0 But right before I saw a warning: [ 51.210393] JDB: !req: 0 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 1 [ 51.218085] ------------[ cut here ]------------ [ 51.222800] WARNING: CPU: 0 PID: 1273 at drivers/mmc/core/core.c:264 mmc_start_request+0x100/0x108 [ 51.231805] [ 51.233356] CPU: 0 PID: 1273 Comm: mmcqd/0 Not tainted 4.8.0-rc1-00056-gf1f4a8e-dirty #791 [ 51.241667] Hardware name: HiKey Development Board (DT) [ 51.246940] task: ffffffc078c0b200 task.stack: ffffffc0786b4000 [ 51.252913] PC is at mmc_start_request+0x100/0x108 [ 51.257756] LR is at mmc_start_request+0x18/0x108 [ 51.262508] pc : [<ffffff80086c3090>] lr : [<ffffff80086c2fa8>] pstate: 00000145 [ 51.269947] sp : ffffffc0786b7bf0 [ 51.273308] x29: ffffffc0786b7bf0 x28: 0000000000000000 [ 51.278743] x27: ffffffc078613018 x26: 0000000000000001 [ 51.284172] x25: 0000000000000000 x24: ffffffc0786b7d5c [ 51.289602] x23: 0000000000000000 x22: ffffffc078613068 [ 51.295033] x21: ffffffc0786131e8 x20: ffffffc078611800 [ 51.300464] x19: ffffffc078613068 x18: 0000000000000000 [ 51.305891] x17: 0000000000000000 x16: 0000000000000000 [ 51.311320] x15: 00000000000011b1 x14: ffffff8008087f08 [ 51.316749] x13: ffffffc0786b002f x12: ffffff8008087f5c [ 51.322179] x11: ffffffc0786b7d20 x10: 0000000000000000 [ 51.327607] x9 : 0000000000000000 x8 : 0000000000001000 [ 51.333036] x7 : ffffffc077392180 x6 : 000000001fde3fff [ 51.338464] x5 : 0000000000000000 x4 : 000000001fde3000 [ 51.343892] x3 : 000000000000003f x2 : 0000000000000020 [ 51.349319] x1 : 0000000000000001 x0 : 0000000000000020 [ 51.354743] [ 51.356279] ---[ end trace 2c3d9b4e1f4fc435 ]--- [ 51.360940] Call trace: [ 51.363440] Exception stack(0xffffffc0786b7a20 to 0xffffffc0786b7b50) [ 51.369942] 7a20: ffffffc078613068 0000008000000000 ffffffc0786b7bf0 ffffff80086c3090 [ 51.377830] 7a40: 0000000000000040 000000000000003f 000000004c7bd000 0000000000000000 [ 51.385719] 7a60: 000000001fde3fff ffffffc077392180 0000000000001000 0000000000000000 [ 51.393609] 7a80: 0000000000000000 ffffffc0786b7d20 ffffff8008087f5c ffffffc0786b002f [ 51.401496] 7aa0: ffffff8008087f08 00000000000011b1 0000000000000000 0000000000000000 [ 51.409383] 7ac0: 0000000000000020 0000000000000001 0000000000000020 000000000000003f [ 51.417271] 7ae0: 000000001fde3000 0000000000000000 000000001fde3fff ffffffc077392180 [ 51.425158] 7b00: 0000000000001000 0000000000000000 0000000000000000 ffffffc0786b7d20 [ 51.433046] 7b20: ffffff8008087f5c ffffffc0786b002f ffffff8008087f08 00000000000011b1 [ 51.440928] 7b40: 0000000000000000 0000000000000000 [ 51.445863] [<ffffff80086c3090>] mmc_start_request+0x100/0x108 [ 51.451754] [<ffffff80086c3fe8>] mmc_start_req+0x280/0x3c8 [ 51.457305] [<ffffff80086d364c>] mmc_blk_issue_rw_rq+0xac/0x9b0 [ 51.463285] [<ffffff80086d3fec>] mmc_blk_issue_rq+0x9c/0x4d8 [ 51.469004] [<ffffff80086d4e00>] mmc_queue_thread+0x98/0x158 [ 51.474725] [<ffffff80080d04dc>] kthread+0xd0/0xe4 [ 51.479577] [<ffffff8008082e90>] ret_from_fork+0x10/0x40 [ 51.488484] ------------[ cut here ]------------ [ 51.774524] ------------[ cut here ]------------ [ 51.779150] WARNING: CPU: 0 PID: 1273 at drivers/mmc/core/core.c:264 mmc_start_request+0x100/0x108 [ 51.788107] [ 51.789599] CPU: 0 PID: 1273 Comm: mmcqd/0 Tainted: G W 4.8.0-rc1-00056-gf1f4a8e-dirty #791 [ 51.799078] Hardware name: HiKey Development Board (DT) [ 51.804302] task: ffffffc078c0b200 task.stack: ffffffc0786b4000 [ 51.810222] PC is at mmc_start_request+0x100/0x108 [ 51.815012] LR is at mmc_start_request+0x18/0x108 [ 51.819715] pc : [<ffffff80086c3090>] lr : [<ffffff80086c2fa8>] pstate: 40000145 [ 51.827109] sp : ffffffc0786b79b0 [ 51.830422] x29: ffffffc0786b79b0 x28: ffffffc0786b7bc8 [ 51.835749] x27: ffffff8008bcd5f0 x26: ffffff8008a7f430 [ 51.841075] x25: 0000000000000001 x24: ffffffc077a3f200 [ 51.846401] x23: 0000000000000000 x22: 000000010001573e [ 51.851727] x21: ffffffc0786b7a40 x20: ffffffc078611800 [ 51.857053] x19: ffffffc0786b7a20 x18: 0000000000000000 [ 51.862378] x17: 0000000000000000 x16: 0000000000000000 [ 51.867704] x15: 0000000000000002 x14: 0000000000000000 [ 51.873030] x13: 0000000000000000 x12: 0000000000000002 [ 51.878355] x11: ffffff80089df458 x10: 0000000000000860 [ 51.883681] x9 : ffffffc0786b4000 x8 : ffffffc078c0bac0 [ 51.889006] x7 : ffffffc07bf257a0 x6 : 0000000000000000 [ 51.894333] x5 : 000000000000000d x4 : 0000000040000543 [ 51.899658] x3 : 0000000000000195 x2 : ffffff8008d666d8 [ 51.904983] x1 : 0000000000000002 x0 : 0000000000000000 [ 51.910308] [ 51.911797] ---[ end trace 2c3d9b4e1f4fc437 ]--- [ 51.916412] Call trace: [ 51.918858] Exception stack(0xffffffc0786b77e0 to 0xffffffc0786b7910) [ 51.925300] 77e0: ffffffc0786b7a20 0000008000000000 ffffffc0786b79b0 ffffff80086c3090 [ 51.933131] 7800: ffffffc0786b7850 ffffff80089b8b88 ffffffc07bf25780 0000000000000000 [ 51.940962] 7820: ffffffc078c0b200 ffffffc0387e1900 ffffffc077bdd400 ffffff80089b921c [ 51.948793] 7840: 0000000000000001 ffffffc07bf1f090 ffffffc0786b78b0 ffffff80089b921c [ 51.956625] 7860: ffffffc0786b4000 0000008000000000 ffffffc0786b7a00 ffffff80086c37ec [ 51.964456] 7880: 0000000000000000 0000000000000002 ffffff8008d666d8 0000000000000195 [ 51.972287] 78a0: 0000000040000543 000000000000000d 0000000000000000 ffffffc07bf257a0 [ 51.980118] 78c0: ffffffc078c0bac0 ffffffc0786b4000 0000000000000860 ffffff80089df458 [ 51.987949] 78e0: 0000000000000002 0000000000000000 0000000000000000 0000000000000002 [ 51.995778] 7900: 0000000000000000 0000000000000000 [ 52.000656] [<ffffff80086c3090>] mmc_start_request+0x100/0x108 [ 52.006490] [<ffffff80086c30e8>] __mmc_start_req+0x50/0x7c [ 52.011976] [<ffffff80086c37cc>] mmc_wait_for_cmd+0x50/0x74 [ 52.017550] [<ffffff80086d2db8>] get_card_status.isra.30+0x50/0x68 [ 52.023731] [<ffffff80086d2e44>] card_busy_detect.isra.31+0x74/0x150 [ 52.030086] [<ffffff80086d2ff4>] mmc_blk_err_check+0xd4/0x544 [ 52.035833] [<ffffff80086c3e44>] mmc_start_req+0xdc/0x3c8 [ 52.041233] [<ffffff80086d364c>] mmc_blk_issue_rw_rq+0xac/0x9b0 [ 52.047153] [<ffffff80086d4188>] mmc_blk_issue_rq+0x238/0x4d8 [ 52.052901] [<ffffff80086d4e00>] mmc_queue_thread+0x98/0x158 [ 52.058562] [<ffffff80080d04dc>] kthread+0xd0/0xe4 [ 52.063355] [<ffffff8008082e90>] ret_from_fork+0x10/0x40 [ 52.068862] JDB: !req: 1 !flags&MMC_QUEUE_NEW_REQUEST: 1 is_special(req): 0 [ 52.076168] ------------[ cut here ]------------ [ 52.080791] WARNING: CPU: 0 PID: 1273 at drivers/mmc/core/core.c:991 mmc_release_host+0xa0/0xa8 [ 52.089488] [ 52.090979] CPU: 0 PID: 1273 Comm: mmcqd/0 Tainted: G W 4.8.0-rc1-00056-gf1f4a8e-dirty #791 [ 52.100458] Hardware name: HiKey Development Board (DT) [ 52.105682] task: ffffffc078c0b200 task.stack: ffffffc0786b4000 [ 52.111601] PC is at mmc_release_host+0xa0/0xa8 [ 52.116131] LR is at mmc_put_card+0x18/0x3c [ 52.120312] pc : [<ffffff80086c34d8>] lr : [<ffffff80086c417c>] pstate: 80000145 [ 52.127707] sp : ffffffc0786b7d20 [ 52.131019] x29: ffffffc0786b7d20 x28: 0000000000000000 [ 52.136346] x27: ffffffc078613018 x26: ffffffc077a3f140 [ 52.141672] x25: ffffffc078613028 x24: ffffffc0786b4000 [ 52.146998] x23: ffffffc078611800 x22: ffffffc078613000 [ 52.152323] x21: 0000000000000001 x20: ffffffc078612800 [ 52.157648] x19: ffffffc078611800 x18: 0000000000000000 [ 52.162973] x17: 0000000000000000 x16: 0000000000000000 [ 52.168298] x15: 0000000000001244 x14: 69202031203a5453 [ 52.173623] x13: 45555145525f5745 x12: 4e5f45554555515f [ 52.178948] x11: 434d4d267367616c x10: 662120202031203a [ 52.184274] x9 : 71657221203a4244 x8 : 203a29716572286c [ 52.189598] x7 : 0000000000001245 x6 : ffffff8008f5a90b [ 52.194924] x5 : 0000000000000000 x4 : 0000000000000000 [ 52.200249] x3 : 0000000000000002 x2 : 0000000000000001 [ 52.205574] x1 : 0000000000000000 x0 : 0000000000000000 [ 52.210899] [ 52.212387] ---[ end trace 2c3d9b4e1f4fc438 ]--- [ 52.217002] Call trace: [ 52.219448] Exception stack(0xffffffc0786b7b50 to 0xffffffc0786b7c80) [ 52.225889] 7b40: ffffffc078611800 0000008000000000 [ 52.233719] 7b60: ffffffc0786b7d20 ffffff80086c34d8 ffffff8008cc39b8 0000000000000000 [ 52.241551] 7b80: 0000000000000000 0000000000000042 0000000000000140 ffffffc0786b7c90 [ 52.249382] 7ba0: ffffff8008d39000 0000000000000042 0000000000000000 ffffff8008b5a270 [ 52.257214] 7bc0: 0000000100000004 ffffff8008cc39f8 ffffffc0786b7c80 ffffff80080f7e3c [ 52.265045] 7be0: ffffffc078611cc8 ffffffc078612800 0000000000000000 0000000000000000 [ 52.272876] 7c00: 0000000000000001 0000000000000002 0000000000000000 0000000000000000 [ 52.280707] 7c20: ffffff8008f5a90b 0000000000001245 203a29716572286c 71657221203a4244 [ 52.288538] 7c40: 662120202031203a 434d4d267367616c 4e5f45554555515f 45555145525f5745 [ 52.296369] 7c60: 69202031203a5453 0000000000001244 0000000000000000 0000000000000000 [ 52.304199] [<ffffff80086c34d8>] mmc_release_host+0xa0/0xa8 [ 52.309772] [<ffffff80086c417c>] mmc_put_card+0x18/0x3c [ 52.315000] [<ffffff80086d4094>] mmc_blk_issue_rq+0x144/0x4d8 [ 52.320748] [<ffffff80086d4e00>] mmc_queue_thread+0x98/0x158 [ 52.326409] [<ffffff80080d04dc>] kthread+0xd0/0xe4 [ 52.331201] [<ffffff8008082e90>] ret_from_fork+0x10/0x40 >> Anyway, I'll do some further testing tomorrow w/ that removed. Usually >> I see the issue 1-2 times an hour, so if I go the day w/o a problem >> I'll let you know. >> >> Zhangfei/Guodong: Any ideas as to why ERASE might cause trouble on HiKey? > > Did you try to send the Erase command directly? e,g fstrim or other things? Android's vold might be, but I'm not. > Is it occurred on every booting time? Unfortunately no. Sometimes it happens shortly after bootup, sometimes I've seen it after suspend/resume cycle. Sometimes it triggers after a while leaving the board idle. I've not sorted out the pattern. thanks -john
