| Message ID | CANMBJr7PKy-eCcB3HiBajpApHS_BYPa7xfKjTqV4o8Z1hwY99A@mail.gmail.com |
|---|---|
| State | New |
| Headers | show |
On 19 August 2015 at 03:33, Thierry Reding <thierry.reding@gmail.com> wrote: > On Wed, Aug 19, 2015 at 11:48:44AM +0200, Sjoerd Simons wrote: >> On Wed, 2015-08-19 at 11:14 +0200, Thierry Reding wrote: >> > On Tue, Aug 18, 2015 at 03:30:41PM -0700, Tyler Baker wrote: >> > > Hi Theirry, >> > > >> > > >> > > This isn't where the story ends unfortunately. The collabora lab >> > > also >> > > has a jetson-tk1, booted in the same manner, which boots next >> > > -20150818 >> > > fine[4]. The only differences I can spot in the two boot logs is >> > > that >> > > the collabora board is using an older version of u-boot, where as >> > > my >> > > board is using a newer version. U-Boot 2015.01-00231-gab77f24-dirty >> > > (Good) vs U-Boot 2015.07-00130-gb217c89 (Bad). >> >> Our 2015.01-00231-gab77f24-dirty is 2015.01-00231-gab77f24 + changes >> which got merged as 053b86e6d8e50359412e626c33bae3f7bafd74dd in >> upstream u-boot. >> >> Fwiw: >> $ git show 2015.01-00231-gab77f24 >> commit ab77f24119e80257de4ab017b877f92f96980562 >> Merge: d928664 fa58b10 >> Author: Tom Rini <trini@ti.com> >> Date: Thu Jan 15 14:05:31 2015 -0500 >> >> Merge branch 'master' of git://git.denx.de/u-boot-ti >> >> Which is definately a commit you should hae in your upstream u-boot >> tree. > > Yeah, I suck. I was running: > > $ git show gab77f24 > > I didn't know git could parse the full output from git describe. > >> > I don't have either of those commits in any of the U-Boot trees I >> > have. >> > Perhaps whatever tree this comes from has local patches that cause >> > the >> > breakage? The version that I use a recent upstream U-Boot with some >> > local patches, none of which should impact Jetson TK1 in any way. >> > Just >> > to make sure I tried running latest origin/master, which identifies >> > thusly: >> > >> > U-Boot 2015.10-rc2-00040-g0f9258228e2b >> > >> > And that boots next-20150818 fine. >> >> Probably worth for tyler to test that u-boot commit on his jetson to >> see if that solves the issue he's having... > > I've tried reconstructing the version that Tyler is running by checking > out 2015.01-00231-gab77f24 and applying 053b86e6d8e5 ("pci: tegra: Fix > port information parsing") on top, but that also leaves me with a > bootable system, so no way of reproducing. I agree that upgrading to a > more recent U-Boot version sounds like the best way forward because it > has already proven to work on at least two setups. Thanks for looking into this issue guys. I'll upgrade u-boot when I return from Plumbers this week and report back. Cheers, Tyler
Hi Mikko,
On 19 August 2015 at 04:15, Mikko Perttunen <mikko.perttunen@kapsi.fi> wrote:
> Please try disabling TEGRA124_EMC and seeing if that makes any difference.
I disabled CONFIG_TEGRA124_EMC and the problem on my end still exists.
Thanks for the suggestion.
Cheers,
Tyler
Hi Thierry, On 19 August 2015 at 03:33, Thierry Reding <thierry.reding@gmail.com> wrote: > On Wed, Aug 19, 2015 at 11:48:44AM +0200, Sjoerd Simons wrote: >> On Wed, 2015-08-19 at 11:14 +0200, Thierry Reding wrote: >> > On Tue, Aug 18, 2015 at 03:30:41PM -0700, Tyler Baker wrote: >> > > Hi Theirry, >> > > >> > > >> > > This isn't where the story ends unfortunately. The collabora lab >> > > also >> > > has a jetson-tk1, booted in the same manner, which boots next >> > > -20150818 >> > > fine[4]. The only differences I can spot in the two boot logs is >> > > that >> > > the collabora board is using an older version of u-boot, where as >> > > my >> > > board is using a newer version. U-Boot 2015.01-00231-gab77f24-dirty >> > > (Good) vs U-Boot 2015.07-00130-gb217c89 (Bad). >> >> Our 2015.01-00231-gab77f24-dirty is 2015.01-00231-gab77f24 + changes >> which got merged as 053b86e6d8e50359412e626c33bae3f7bafd74dd in >> upstream u-boot. >> >> Fwiw: >> $ git show 2015.01-00231-gab77f24 >> commit ab77f24119e80257de4ab017b877f92f96980562 >> Merge: d928664 fa58b10 >> Author: Tom Rini <trini@ti.com> >> Date: Thu Jan 15 14:05:31 2015 -0500 >> >> Merge branch 'master' of git://git.denx.de/u-boot-ti >> >> Which is definately a commit you should hae in your upstream u-boot >> tree. > > Yeah, I suck. I was running: > > $ git show gab77f24 > > I didn't know git could parse the full output from git describe. > >> > I don't have either of those commits in any of the U-Boot trees I >> > have. >> > Perhaps whatever tree this comes from has local patches that cause >> > the >> > breakage? The version that I use a recent upstream U-Boot with some >> > local patches, none of which should impact Jetson TK1 in any way. >> > Just >> > to make sure I tried running latest origin/master, which identifies >> > thusly: >> > >> > U-Boot 2015.10-rc2-00040-g0f9258228e2b >> > >> > And that boots next-20150818 fine. >> >> Probably worth for tyler to test that u-boot commit on his jetson to >> see if that solves the issue he's having... > > I've tried reconstructing the version that Tyler is running by checking > out 2015.01-00231-gab77f24 and applying 053b86e6d8e5 ("pci: tegra: Fix > port information parsing") on top, but that also leaves me with a > bootable system, so no way of reproducing. I agree that upgrading to a > more recent U-Boot version sounds like the best way forward because it > has already proven to work on at least two setups. Sorry for the delay. I've upgraded u-boot to U-Boot 2015.10-rc2-00439-g03d8714 using the tegra u-boot flashing scripts. FWIW, I did have to revert 620776d734e4 ("tftp: adjust settings to be suitable for 100Mbit ethernet") to get TFTP working again. Anyways, it hangs at the exact same spot[1] with the newer version of u-boot. If remove the modules from the initrd or just disable CONFIG_SND_HDA_TEGRA it boots fine. This weekend I'll try to debug this module manually and see if I draw any conclusions. Cheers, Tyler [1] http://lava.kernelci.org/scheduler/job/180894/log_file
Hi Kevin, On 10/09/15 22:29, Kevin Hilman wrote: [snip] > Since there is no movement on this, and jetson hasn't been boot for > multi_v7_defconfig for a while[1], I think it's time to undo the > option causing this problem[2] so that v4.3 will actually boot on the > jetson. > > Unless I hear a good reason otherwise, I'll be posting a patch to > disable the HDA related options in multi_v7_defconfig. So curiosity got the better of this cat, as to why we are not seeing this ;-) The main difference I see between the tegra_defconfig and multi_v7_defconfig is all the sound drivers are modules (including this one). So trying a quick modprobe of the hda-tegra driver I do see it hang ... / # modprobe snd-hda-tegra [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show the order in which modules are being loaded) ... / # modprobe snd-hda-tegra [ 22.450276] snd_hda_tegra: err = -2 [ 22.484535] soundcore: err = 0 [ 22.488964] snd: err = 0 [ 22.493242] snd_timer: err = 0 [ 22.498380] snd_pcm: err = 0 [ 22.502479] snd_hda_core: err = 0 [ 22.508337] snd_hda_codec: err = 0 [ 22.513386] snd_hda_tegra: err = 0 [ 22.740216] snd_hda_codec_hdmi: err = 0 [hangs here] However, if I do the following, this works ... / # modprobe snd-hda-codec-hdmi / # modprobe snd-hda-tegra So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. Thierry, any thoughts? Jon
On 11/09/15 11:39, Jon Hunter wrote: > Hi Kevin, > > On 10/09/15 22:29, Kevin Hilman wrote: > > [snip] > >> Since there is no movement on this, and jetson hasn't been boot for >> multi_v7_defconfig for a while[1], I think it's time to undo the >> option causing this problem[2] so that v4.3 will actually boot on the >> jetson. >> >> Unless I hear a good reason otherwise, I'll be posting a patch to >> disable the HDA related options in multi_v7_defconfig. > > So curiosity got the better of this cat, as to why we are not seeing > this ;-) > > The main difference I see between the tegra_defconfig and > multi_v7_defconfig is all the sound drivers are modules (including > this one). > > So trying a quick modprobe of the hda-tegra driver I do see it hang ... > > / # modprobe snd-hda-tegra > [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) > [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) > [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) > [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) > [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) > [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) > [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) > [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) > [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) > [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) > [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. > [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 > [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 > [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) > [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) > [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) > [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) > [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) > [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) > [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) > [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) > [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) > [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) > [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) > [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) > [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) > > Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show > the order in which modules are being loaded) ... > > / # modprobe snd-hda-tegra > [ 22.450276] snd_hda_tegra: err = -2 > [ 22.484535] soundcore: err = 0 > [ 22.488964] snd: err = 0 > [ 22.493242] snd_timer: err = 0 > [ 22.498380] snd_pcm: err = 0 > [ 22.502479] snd_hda_core: err = 0 > [ 22.508337] snd_hda_codec: err = 0 > [ 22.513386] snd_hda_tegra: err = 0 > [ 22.740216] snd_hda_codec_hdmi: err = 0 Ftrace shows a similar thing ... / # cat /debug/tracing/trace # tracer: nop # # entries-in-buffer/entries-written: 8/8 #P:4 # # _-----=> irqs-off # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | | modprobe-110 [000] .... 46.095279: module_load: soundcore modprobe-110 [000] .n.. 46.096443: module_load: snd modprobe-110 [000] .n.. 46.097719: module_load: snd_timer modprobe-110 [000] .... 46.099242: module_load: snd_pcm modprobe-110 [000] .... 46.100231: module_load: snd_hda_core modprobe-110 [000] .... 46.102418: module_load: snd_hda_codec modprobe-110 [000] .... 46.102915: module_load: snd_hda_tegra modprobe-122 [000] .... 46.341224: module_load: snd_hda_codec_hdmi However, would imply that snd-hda-codec-hdmi is loaded ok and the hang occurs afterwards as the trace message is printed once the module has been loaded. Jon
On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: > Hi Kevin, > > On 10/09/15 22:29, Kevin Hilman wrote: > > [snip] > > > Since there is no movement on this, and jetson hasn't been boot for > > multi_v7_defconfig for a while[1], I think it's time to undo the > > option causing this problem[2] so that v4.3 will actually boot on the > > jetson. > > > > Unless I hear a good reason otherwise, I'll be posting a patch to > > disable the HDA related options in multi_v7_defconfig. > > So curiosity got the better of this cat, as to why we are not seeing > this ;-) > > The main difference I see between the tegra_defconfig and > multi_v7_defconfig is all the sound drivers are modules (including > this one). > > So trying a quick modprobe of the hda-tegra driver I do see it hang ... > > / # modprobe snd-hda-tegra > [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) > [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) > [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) > [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) > [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) > [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) > [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) > [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) > [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) > [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) > [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. > [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 > [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 > [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) > [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) > [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) > [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) > [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) > [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) > [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) > [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) > [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) > [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) > [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) > [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) > [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) > > Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show > the order in which modules are being loaded) ... > > / # modprobe snd-hda-tegra > [ 22.450276] snd_hda_tegra: err = -2 > [ 22.484535] soundcore: err = 0 > [ 22.488964] snd: err = 0 > [ 22.493242] snd_timer: err = 0 > [ 22.498380] snd_pcm: err = 0 > [ 22.502479] snd_hda_core: err = 0 > [ 22.508337] snd_hda_codec: err = 0 > [ 22.513386] snd_hda_tegra: err = 0 > [ 22.740216] snd_hda_codec_hdmi: err = 0 > > [hangs here] > > However, if I do the following, this works ... > > / # modprobe snd-hda-codec-hdmi > / # modprobe snd-hda-tegra > > So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. > > Thierry, any thoughts? I can't reproduce this. Booting multi_v7_defconfig on my setup works just fine. I don't ever see snd-hda-codec-hdmi being probed, but then probing it manually works fine. No hangs. What I do see is that after a little while network stops working. I noticed primarily because I boot with an NFS root, so the kernel started complaining about the NFS server not responding. Being on an NFS root could be one reason why this works for me, not sure what the kernelci labs are running. I don't see the network issues with tegra_defconfig. I've also tried a tegra_defconfig with all of sound support built as modules and that all works perfectly. I'll investigate the multi_v7_defconfig network issues, perhaps that'll give me some clues, or perhaps even allow me to reproduce the original issue. Thierry
On 11/09/15 13:38, Thierry Reding wrote: > * PGP Signed by an unknown key > > On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: >> Hi Kevin, >> >> On 10/09/15 22:29, Kevin Hilman wrote: >> >> [snip] >> >>> Since there is no movement on this, and jetson hasn't been boot for >>> multi_v7_defconfig for a while[1], I think it's time to undo the >>> option causing this problem[2] so that v4.3 will actually boot on the >>> jetson. >>> >>> Unless I hear a good reason otherwise, I'll be posting a patch to >>> disable the HDA related options in multi_v7_defconfig. >> >> So curiosity got the better of this cat, as to why we are not seeing >> this ;-) >> >> The main difference I see between the tegra_defconfig and >> multi_v7_defconfig is all the sound drivers are modules (including >> this one). >> >> So trying a quick modprobe of the hda-tegra driver I do see it hang ... >> >> / # modprobe snd-hda-tegra >> [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) >> [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) >> [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) >> [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) >> [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) >> [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) >> [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) >> [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) >> [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) >> [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) >> [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. >> [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 >> [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 >> [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) >> [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) >> [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) >> [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) >> [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) >> [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) >> [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) >> [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) >> [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) >> [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) >> [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) >> [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) >> [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) >> >> Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show >> the order in which modules are being loaded) ... >> >> / # modprobe snd-hda-tegra >> [ 22.450276] snd_hda_tegra: err = -2 >> [ 22.484535] soundcore: err = 0 >> [ 22.488964] snd: err = 0 >> [ 22.493242] snd_timer: err = 0 >> [ 22.498380] snd_pcm: err = 0 >> [ 22.502479] snd_hda_core: err = 0 >> [ 22.508337] snd_hda_codec: err = 0 >> [ 22.513386] snd_hda_tegra: err = 0 >> [ 22.740216] snd_hda_codec_hdmi: err = 0 >> >> [hangs here] >> >> However, if I do the following, this works ... >> >> / # modprobe snd-hda-codec-hdmi >> / # modprobe snd-hda-tegra >> >> So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. >> >> Thierry, any thoughts? > > I can't reproduce this. Booting multi_v7_defconfig on my setup works > just fine. I don't ever see snd-hda-codec-hdmi being probed, but then > probing it manually works fine. No hangs. Did you try "modprobe snd-hda-tegra"? Fails for me 100% of the time. > What I do see is that after a little while network stops working. I > noticed primarily because I boot with an NFS root, so the kernel started > complaining about the NFS server not responding. Being on an NFS root > could be one reason why this works for me, not sure what the kernelci > labs are running. I don't see the network issues with tegra_defconfig. > I've also tried a tegra_defconfig with all of sound support built as > modules and that all works perfectly. > > I'll investigate the multi_v7_defconfig network issues, perhaps that'll > give me some clues, or perhaps even allow me to reproduce the original > issue. Well I am not using any networking and booting with a simple ramdisk so I don't think that is the right place to look. Cheers Jon
On 11/09/15 13:38, Thierry Reding wrote: > * PGP Signed by an unknown key > > On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: >> Hi Kevin, >> >> On 10/09/15 22:29, Kevin Hilman wrote: >> >> [snip] >> >>> Since there is no movement on this, and jetson hasn't been boot for >>> multi_v7_defconfig for a while[1], I think it's time to undo the >>> option causing this problem[2] so that v4.3 will actually boot on the >>> jetson. >>> >>> Unless I hear a good reason otherwise, I'll be posting a patch to >>> disable the HDA related options in multi_v7_defconfig. >> >> So curiosity got the better of this cat, as to why we are not seeing >> this ;-) >> >> The main difference I see between the tegra_defconfig and >> multi_v7_defconfig is all the sound drivers are modules (including >> this one). >> >> So trying a quick modprobe of the hda-tegra driver I do see it hang ... >> >> / # modprobe snd-hda-tegra >> [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) >> [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) >> [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) >> [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) >> [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) >> [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) >> [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) >> [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) >> [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) >> [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) >> [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. >> [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 >> [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 >> [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) >> [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) >> [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) >> [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) >> [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) >> [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) >> [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) >> [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) >> [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) >> [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) >> [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) >> [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) >> [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) >> >> Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show >> the order in which modules are being loaded) ... >> >> / # modprobe snd-hda-tegra >> [ 22.450276] snd_hda_tegra: err = -2 >> [ 22.484535] soundcore: err = 0 >> [ 22.488964] snd: err = 0 >> [ 22.493242] snd_timer: err = 0 >> [ 22.498380] snd_pcm: err = 0 >> [ 22.502479] snd_hda_core: err = 0 >> [ 22.508337] snd_hda_codec: err = 0 >> [ 22.513386] snd_hda_tegra: err = 0 >> [ 22.740216] snd_hda_codec_hdmi: err = 0 >> >> [hangs here] >> >> However, if I do the following, this works ... >> >> / # modprobe snd-hda-codec-hdmi >> / # modprobe snd-hda-tegra >> >> So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. >> >> Thierry, any thoughts? > > I can't reproduce this. Booting multi_v7_defconfig on my setup works > just fine. I don't ever see snd-hda-codec-hdmi being probed, but then > probing it manually works fine. No hangs. To be clear, booting multi_v7_defconfig works just fine for me too and has been working fine for months. However, the reason I am not seeing the issue Kevin and Tyler are reporting is because I never attempt to "modprobe snd-hda-tegra" after boot. If I do then I see a hang. So I believe the only reason we don't see this is because their setup is loading modules. Cheers Jon
On Fri, Sep 11, 2015 at 02:15:00PM +0100, Jon Hunter wrote: > > On 11/09/15 13:38, Thierry Reding wrote: > > * PGP Signed by an unknown key > > > > On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: > >> Hi Kevin, > >> > >> On 10/09/15 22:29, Kevin Hilman wrote: > >> > >> [snip] > >> > >>> Since there is no movement on this, and jetson hasn't been boot for > >>> multi_v7_defconfig for a while[1], I think it's time to undo the > >>> option causing this problem[2] so that v4.3 will actually boot on the > >>> jetson. > >>> > >>> Unless I hear a good reason otherwise, I'll be posting a patch to > >>> disable the HDA related options in multi_v7_defconfig. > >> > >> So curiosity got the better of this cat, as to why we are not seeing > >> this ;-) > >> > >> The main difference I see between the tegra_defconfig and > >> multi_v7_defconfig is all the sound drivers are modules (including > >> this one). > >> > >> So trying a quick modprobe of the hda-tegra driver I do see it hang ... > >> > >> / # modprobe snd-hda-tegra > >> [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) > >> [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) > >> [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) > >> [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) > >> [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) > >> [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) > >> [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) > >> [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) > >> [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) > >> [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) > >> [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. > >> [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 > >> [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > >> [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 > >> [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) > >> [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) > >> [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) > >> [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) > >> [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) > >> [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) > >> [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) > >> [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) > >> [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) > >> [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) > >> [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) > >> [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) > >> [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) > >> > >> Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show > >> the order in which modules are being loaded) ... > >> > >> / # modprobe snd-hda-tegra > >> [ 22.450276] snd_hda_tegra: err = -2 > >> [ 22.484535] soundcore: err = 0 > >> [ 22.488964] snd: err = 0 > >> [ 22.493242] snd_timer: err = 0 > >> [ 22.498380] snd_pcm: err = 0 > >> [ 22.502479] snd_hda_core: err = 0 > >> [ 22.508337] snd_hda_codec: err = 0 > >> [ 22.513386] snd_hda_tegra: err = 0 > >> [ 22.740216] snd_hda_codec_hdmi: err = 0 > >> > >> [hangs here] > >> > >> However, if I do the following, this works ... > >> > >> / # modprobe snd-hda-codec-hdmi > >> / # modprobe snd-hda-tegra > >> > >> So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. > >> > >> Thierry, any thoughts? > > > > I can't reproduce this. Booting multi_v7_defconfig on my setup works > > just fine. I don't ever see snd-hda-codec-hdmi being probed, but then > > probing it manually works fine. No hangs. > > To be clear, booting multi_v7_defconfig works just fine for me too and > has been working fine for months. However, the reason I am not seeing > the issue Kevin and Tyler are reporting is because I never attempt to > "modprobe snd-hda-tegra" after boot. If I do then I see a hang. So I > believe the only reason we don't see this is because their setup is > loading modules. snd-hda-tegra is auto-loaded on boot for me as well and I don't see any hangs either. I can also unload and reload the module just fine. I've tested this on next-20150911. Thierry
On Fri, Sep 11, 2015 at 02:10:59PM +0100, Jon Hunter wrote: > > On 11/09/15 13:38, Thierry Reding wrote: > > * PGP Signed by an unknown key > > > > On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: > >> Hi Kevin, > >> > >> On 10/09/15 22:29, Kevin Hilman wrote: > >> > >> [snip] > >> > >>> Since there is no movement on this, and jetson hasn't been boot for > >>> multi_v7_defconfig for a while[1], I think it's time to undo the > >>> option causing this problem[2] so that v4.3 will actually boot on the > >>> jetson. > >>> > >>> Unless I hear a good reason otherwise, I'll be posting a patch to > >>> disable the HDA related options in multi_v7_defconfig. > >> > >> So curiosity got the better of this cat, as to why we are not seeing > >> this ;-) > >> > >> The main difference I see between the tegra_defconfig and > >> multi_v7_defconfig is all the sound drivers are modules (including > >> this one). > >> > >> So trying a quick modprobe of the hda-tegra driver I do see it hang ... > >> > >> / # modprobe snd-hda-tegra > >> [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) > >> [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) > >> [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) > >> [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) > >> [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) > >> [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) > >> [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) > >> [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) > >> [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) > >> [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) > >> [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. > >> [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 > >> [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > >> [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 > >> [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) > >> [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) > >> [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) > >> [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) > >> [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) > >> [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) > >> [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) > >> [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) > >> [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) > >> [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) > >> [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) > >> [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) > >> [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) > >> > >> Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show > >> the order in which modules are being loaded) ... > >> > >> / # modprobe snd-hda-tegra > >> [ 22.450276] snd_hda_tegra: err = -2 > >> [ 22.484535] soundcore: err = 0 > >> [ 22.488964] snd: err = 0 > >> [ 22.493242] snd_timer: err = 0 > >> [ 22.498380] snd_pcm: err = 0 > >> [ 22.502479] snd_hda_core: err = 0 > >> [ 22.508337] snd_hda_codec: err = 0 > >> [ 22.513386] snd_hda_tegra: err = 0 > >> [ 22.740216] snd_hda_codec_hdmi: err = 0 > >> > >> [hangs here] > >> > >> However, if I do the following, this works ... > >> > >> / # modprobe snd-hda-codec-hdmi > >> / # modprobe snd-hda-tegra > >> > >> So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. > >> > >> Thierry, any thoughts? > > > > I can't reproduce this. Booting multi_v7_defconfig on my setup works > > just fine. I don't ever see snd-hda-codec-hdmi being probed, but then > > probing it manually works fine. No hangs. > > Did you try "modprobe snd-hda-tegra"? Fails for me 100% of the time. Works for me 100% of the time. Unloading and reloading isn't a problem either. What revision of the Jetson TK1 do you have? Mine is a C.2 > > What I do see is that after a little while network stops working. I > > noticed primarily because I boot with an NFS root, so the kernel started > > complaining about the NFS server not responding. Being on an NFS root > > could be one reason why this works for me, not sure what the kernelci > > labs are running. I don't see the network issues with tegra_defconfig. > > I've also tried a tegra_defconfig with all of sound support built as > > modules and that all works perfectly. > > > > I'll investigate the multi_v7_defconfig network issues, perhaps that'll > > give me some clues, or perhaps even allow me to reproduce the original > > issue. > > Well I am not using any networking and booting with a simple ramdisk so > I don't think that is the right place to look. Looks like this might have been a transient issue with my networking setup. I can no longer reproduce the NFS hangs. What sort of ramdisk do you use? Can you share the instructions you use to create it? Perhaps I can reproduce that way. Thierry
On 11/09/15 14:21, Thierry Reding wrote: > * PGP Signed by an unknown key > > On Fri, Sep 11, 2015 at 02:15:00PM +0100, Jon Hunter wrote: >> >> On 11/09/15 13:38, Thierry Reding wrote: >>>> Old Signed by an unknown key >>> >>> On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: >>>> Hi Kevin, >>>> >>>> On 10/09/15 22:29, Kevin Hilman wrote: >>>> >>>> [snip] >>>> >>>>> Since there is no movement on this, and jetson hasn't been boot for >>>>> multi_v7_defconfig for a while[1], I think it's time to undo the >>>>> option causing this problem[2] so that v4.3 will actually boot on the >>>>> jetson. >>>>> >>>>> Unless I hear a good reason otherwise, I'll be posting a patch to >>>>> disable the HDA related options in multi_v7_defconfig. >>>> >>>> So curiosity got the better of this cat, as to why we are not seeing >>>> this ;-) >>>> >>>> The main difference I see between the tegra_defconfig and >>>> multi_v7_defconfig is all the sound drivers are modules (including >>>> this one). >>>> >>>> So trying a quick modprobe of the hda-tegra driver I do see it hang ... >>>> >>>> / # modprobe snd-hda-tegra >>>> [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) >>>> [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) >>>> [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) >>>> [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) >>>> [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) >>>> [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) >>>> [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) >>>> [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) >>>> [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) >>>> [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) >>>> [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. >>>> [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 >>>> [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >>>> [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 >>>> [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) >>>> [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) >>>> [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) >>>> [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) >>>> [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) >>>> [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) >>>> [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) >>>> [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) >>>> [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) >>>> [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) >>>> [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) >>>> [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) >>>> [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) >>>> >>>> Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show >>>> the order in which modules are being loaded) ... >>>> >>>> / # modprobe snd-hda-tegra >>>> [ 22.450276] snd_hda_tegra: err = -2 >>>> [ 22.484535] soundcore: err = 0 >>>> [ 22.488964] snd: err = 0 >>>> [ 22.493242] snd_timer: err = 0 >>>> [ 22.498380] snd_pcm: err = 0 >>>> [ 22.502479] snd_hda_core: err = 0 >>>> [ 22.508337] snd_hda_codec: err = 0 >>>> [ 22.513386] snd_hda_tegra: err = 0 >>>> [ 22.740216] snd_hda_codec_hdmi: err = 0 >>>> >>>> [hangs here] >>>> >>>> However, if I do the following, this works ... >>>> >>>> / # modprobe snd-hda-codec-hdmi >>>> / # modprobe snd-hda-tegra >>>> >>>> So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. >>>> >>>> Thierry, any thoughts? >>> >>> I can't reproduce this. Booting multi_v7_defconfig on my setup works >>> just fine. I don't ever see snd-hda-codec-hdmi being probed, but then >>> probing it manually works fine. No hangs. >> >> To be clear, booting multi_v7_defconfig works just fine for me too and >> has been working fine for months. However, the reason I am not seeing >> the issue Kevin and Tyler are reporting is because I never attempt to >> "modprobe snd-hda-tegra" after boot. If I do then I see a hang. So I >> believe the only reason we don't see this is because their setup is >> loading modules. > > snd-hda-tegra is auto-loaded on boot for me as well and I don't see any > hangs either. I can also unload and reload the module just fine. I've > tested this on next-20150911. What else are you auto-loading? For my testing there appears to be a sensitivity to order outside of the depmod order. Can you try unloading all the sound modules and then do a "modprobe snd-hda-tegra"? Cheers Jon
On 11/09/15 14:25, Thierry Reding wrote: > * PGP Signed by an unknown key > > On Fri, Sep 11, 2015 at 02:10:59PM +0100, Jon Hunter wrote: >> >> On 11/09/15 13:38, Thierry Reding wrote: >>>> Old Signed by an unknown key >>> >>> On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: >>>> Hi Kevin, >>>> >>>> On 10/09/15 22:29, Kevin Hilman wrote: >>>> >>>> [snip] >>>> >>>>> Since there is no movement on this, and jetson hasn't been boot for >>>>> multi_v7_defconfig for a while[1], I think it's time to undo the >>>>> option causing this problem[2] so that v4.3 will actually boot on the >>>>> jetson. >>>>> >>>>> Unless I hear a good reason otherwise, I'll be posting a patch to >>>>> disable the HDA related options in multi_v7_defconfig. >>>> >>>> So curiosity got the better of this cat, as to why we are not seeing >>>> this ;-) >>>> >>>> The main difference I see between the tegra_defconfig and >>>> multi_v7_defconfig is all the sound drivers are modules (including >>>> this one). >>>> >>>> So trying a quick modprobe of the hda-tegra driver I do see it hang ... >>>> >>>> / # modprobe snd-hda-tegra >>>> [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) >>>> [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) >>>> [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) >>>> [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) >>>> [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) >>>> [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) >>>> [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) >>>> [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) >>>> [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) >>>> [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) >>>> [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. >>>> [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 >>>> [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >>>> [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 >>>> [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) >>>> [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) >>>> [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) >>>> [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) >>>> [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) >>>> [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) >>>> [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) >>>> [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) >>>> [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) >>>> [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) >>>> [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) >>>> [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) >>>> [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) >>>> >>>> Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show >>>> the order in which modules are being loaded) ... >>>> >>>> / # modprobe snd-hda-tegra >>>> [ 22.450276] snd_hda_tegra: err = -2 >>>> [ 22.484535] soundcore: err = 0 >>>> [ 22.488964] snd: err = 0 >>>> [ 22.493242] snd_timer: err = 0 >>>> [ 22.498380] snd_pcm: err = 0 >>>> [ 22.502479] snd_hda_core: err = 0 >>>> [ 22.508337] snd_hda_codec: err = 0 >>>> [ 22.513386] snd_hda_tegra: err = 0 >>>> [ 22.740216] snd_hda_codec_hdmi: err = 0 >>>> >>>> [hangs here] >>>> >>>> However, if I do the following, this works ... >>>> >>>> / # modprobe snd-hda-codec-hdmi >>>> / # modprobe snd-hda-tegra >>>> >>>> So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. >>>> >>>> Thierry, any thoughts? >>> >>> I can't reproduce this. Booting multi_v7_defconfig on my setup works >>> just fine. I don't ever see snd-hda-codec-hdmi being probed, but then >>> probing it manually works fine. No hangs. >> >> Did you try "modprobe snd-hda-tegra"? Fails for me 100% of the time. > > Works for me 100% of the time. Unloading and reloading isn't a problem > either. What revision of the Jetson TK1 do you have? Mine is a C.2 > >>> What I do see is that after a little while network stops working. I >>> noticed primarily because I boot with an NFS root, so the kernel started >>> complaining about the NFS server not responding. Being on an NFS root >>> could be one reason why this works for me, not sure what the kernelci >>> labs are running. I don't see the network issues with tegra_defconfig. >>> I've also tried a tegra_defconfig with all of sound support built as >>> modules and that all works perfectly. >>> >>> I'll investigate the multi_v7_defconfig network issues, perhaps that'll >>> give me some clues, or perhaps even allow me to reproduce the original >>> issue. >> >> Well I am not using any networking and booting with a simple ramdisk so >> I don't think that is the right place to look. > > Looks like this might have been a transient issue with my networking > setup. I can no longer reproduce the NFS hangs. > > What sort of ramdisk do you use? Can you share the instructions you use > to create it? Perhaps I can reproduce that way. It is just a simple busybox based file-system. I can share it with you. Cheers Jon
On Fri, Sep 11, 2015 at 02:39:33PM +0100, Jon Hunter wrote: > > On 11/09/15 14:21, Thierry Reding wrote: > > * PGP Signed by an unknown key > > > > On Fri, Sep 11, 2015 at 02:15:00PM +0100, Jon Hunter wrote: > >> > >> On 11/09/15 13:38, Thierry Reding wrote: > >>>> Old Signed by an unknown key > >>> > >>> On Fri, Sep 11, 2015 at 11:39:01AM +0100, Jon Hunter wrote: > >>>> Hi Kevin, > >>>> > >>>> On 10/09/15 22:29, Kevin Hilman wrote: > >>>> > >>>> [snip] > >>>> > >>>>> Since there is no movement on this, and jetson hasn't been boot for > >>>>> multi_v7_defconfig for a while[1], I think it's time to undo the > >>>>> option causing this problem[2] so that v4.3 will actually boot on the > >>>>> jetson. > >>>>> > >>>>> Unless I hear a good reason otherwise, I'll be posting a patch to > >>>>> disable the HDA related options in multi_v7_defconfig. > >>>> > >>>> So curiosity got the better of this cat, as to why we are not seeing > >>>> this ;-) > >>>> > >>>> The main difference I see between the tegra_defconfig and > >>>> multi_v7_defconfig is all the sound drivers are modules (including > >>>> this one). > >>>> > >>>> So trying a quick modprobe of the hda-tegra driver I do see it hang ... > >>>> > >>>> / # modprobe snd-hda-tegra > >>>> [ 625.213864] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) > >>>> [ 625.220215] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) > >>>> [ 625.226480] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) > >>>> [ 625.233168] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) > >>>> [ 625.239062] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) > >>>> [ 625.245314] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) > >>>> [ 625.251321] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) > >>>> [ 625.258081] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) > >>>> [ 625.264078] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) > >>>> [ 625.270607] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) > >>>> [ 840.117528] INFO: task modprobe:137 blocked for more than 120 seconds. > >>>> [ 840.124192] Not tainted 4.2.0-next-20150909-40826-gb799053 #1 > >>>> [ 840.130584] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > >>>> [ 840.138540] modprobe D c09ac3a4 0 137 82 0x00000000 > >>>> [ 840.145123] [<c09ac3a4>] (__schedule) from [<c09ac838>] (schedule+0x34/0x98) > >>>> [ 840.152310] [<c09ac838>] (schedule) from [<c09acaac>] (schedule_preempt_disabled+0xc/0x10) > >>>> [ 840.160734] [<c09acaac>] (schedule_preempt_disabled) from [<c09adeec>] (__mutex_lock_slowpath+0x9c/0x150) > >>>> [ 840.170458] [<c09adeec>] (__mutex_lock_slowpath) from [<c09adfec>] (mutex_lock+0x4c/0x50) > >>>> [ 840.178807] [<c09adfec>] (mutex_lock) from [<c062999c>] (__driver_attach+0x44/0x90) > >>>> [ 840.186627] [<c062999c>] (__driver_attach) from [<c0627fcc>] (bus_for_each_dev+0x54/0x88) > >>>> [ 840.194966] [<c0627fcc>] (bus_for_each_dev) from [<c0628f88>] (bus_add_driver+0xe4/0x1f0) > >>>> [ 840.203305] [<c0628f88>] (bus_add_driver) from [<c062a1d0>] (driver_register+0x78/0xf4) > >>>> [ 840.211475] [<c062a1d0>] (driver_register) from [<c020ac04>] (do_one_initcall+0x80/0x1d0) > >>>> [ 840.219818] [<c020ac04>] (do_one_initcall) from [<c02c8abc>] (do_init_module+0x58/0x354) > >>>> [ 840.228081] [<c02c8abc>] (do_init_module) from [<c02afae8>] (load_module+0x17e0/0x1d8c) > >>>> [ 840.236258] [<c02afae8>] (load_module) from [<c02b016c>] (SyS_init_module+0xd8/0x138) > >>>> [ 840.244260] [<c02b016c>] (SyS_init_module) from [<c0210b00>] (ret_fast_syscall+0x0/0x3c) > >>>> > >>>> Adding some debug it appears to hang on snd-hda-codec-hdmi (the following show > >>>> the order in which modules are being loaded) ... > >>>> > >>>> / # modprobe snd-hda-tegra > >>>> [ 22.450276] snd_hda_tegra: err = -2 > >>>> [ 22.484535] soundcore: err = 0 > >>>> [ 22.488964] snd: err = 0 > >>>> [ 22.493242] snd_timer: err = 0 > >>>> [ 22.498380] snd_pcm: err = 0 > >>>> [ 22.502479] snd_hda_core: err = 0 > >>>> [ 22.508337] snd_hda_codec: err = 0 > >>>> [ 22.513386] snd_hda_tegra: err = 0 > >>>> [ 22.740216] snd_hda_codec_hdmi: err = 0 > >>>> > >>>> [hangs here] > >>>> > >>>> However, if I do the following, this works ... > >>>> > >>>> / # modprobe snd-hda-codec-hdmi > >>>> / # modprobe snd-hda-tegra > >>>> > >>>> So it implies that snd-hda-codec-hdmi needs to be loaded first otherwise it hangs. > >>>> > >>>> Thierry, any thoughts? > >>> > >>> I can't reproduce this. Booting multi_v7_defconfig on my setup works > >>> just fine. I don't ever see snd-hda-codec-hdmi being probed, but then > >>> probing it manually works fine. No hangs. > >> > >> To be clear, booting multi_v7_defconfig works just fine for me too and > >> has been working fine for months. However, the reason I am not seeing > >> the issue Kevin and Tyler are reporting is because I never attempt to > >> "modprobe snd-hda-tegra" after boot. If I do then I see a hang. So I > >> believe the only reason we don't see this is because their setup is > >> loading modules. > > > > snd-hda-tegra is auto-loaded on boot for me as well and I don't see any > > hangs either. I can also unload and reload the module just fine. I've > > tested this on next-20150911. > > What else are you auto-loading? For my testing there appears to be a > sensitivity to order outside of the depmod order. > > Can you try unloading all the sound modules and then do a "modprobe > snd-hda-tegra"? Here's the list of loaded modules right after boot: -sh-4.3# lsmod Module Size Used by snd_hda_tegra 4764 0 snd_hda_codec_hdmi 35010 1 snd_soc_tegra30_i2s 5380 2 snd_soc_tegra_pcm 1184 1 snd_soc_tegra30_i2s snd_soc_tegra_rt5640 3960 0 snd_soc_rt5640 56972 1 snd_soc_tegra_utils 2825 1 snd_soc_tegra_rt5640 snd_soc_rl6231 1897 1 snd_soc_rt5640 snd_soc_core 107271 4 snd_soc_tegra_pcm,snd_soc_rt5640,snd_soc_tegra_rt5640,snd_soc_tegra30_i2s snd_hda_codec 75955 2 snd_hda_codec_hdmi,snd_hda_tegra snd_compress 7363 1 snd_soc_core snd_hda_core 26603 3 snd_hda_codec_hdmi,snd_hda_codec,snd_hda_tegra snd_pcm_dmaengine 2943 1 snd_soc_core snd_pcm 69108 7 snd_soc_rt5640,snd_soc_core,snd_hda_codec_hdmi,snd_hda_codec,snd_hda_tegra,snd_pcm_dmaengine,snd_hda_core snd_timer 17264 1 snd_pcm snd_soc_tegra30_ahub 8299 1 snd_soc_tegra30_i2s snd 42248 7 snd_soc_core,snd_timer,snd_hda_codec_hdmi,snd_pcm,snd_hda_codec,snd_hda_tegra,snd_compress nouveau 1302185 0 soundcore 858 1 snd tegra_devfreq 5375 0 ttm 65238 1 nouveau Then I went and unloaded a couple of modules until I was left with this: -sh-4.3# lsmod Module Size Used by nouveau 1302185 0 tegra_devfreq 5375 0 ttm 65238 1 nouveau Then I did the following: -sh-4.3# modprobe snd-hda-tegra [ 2243.786143] hdaudio hdaudioC0D3: Unable to bind the codec -sh-4.3# lsmod Module Size Used by snd_hda_tegra 4764 0 snd_hda_codec 75955 1 snd_hda_tegra snd_hda_core 26603 2 snd_hda_codec,snd_hda_tegra snd_pcm 69108 3 snd_hda_codec,snd_hda_tegra,snd_hda_core snd_timer 17264 1 snd_pcm snd 42248 4 snd_timer,snd_pcm,snd_hda_codec,snd_hda_tegra soundcore 858 1 snd nouveau 1302185 0 tegra_devfreq 5375 0 ttm 65238 1 nouveau -sh-4.3# modprobe snd-hda-codec-hdmi -sh-4.3# modprobe -r snd-hda-tegra -sh-4.3# modprobe snd-hda-tegra [ 2263.934328] input: tegra-hda HDMI/DP,pcm=3 as /devices/soc0/70030000.hda/sound/card0/input4 So all worked just fine. Thierry
On 11/09/15 14:57, Thierry Reding wrote: [snip] > Then I did the following: > > -sh-4.3# modprobe snd-hda-tegra > [ 2243.786143] hdaudio hdaudioC0D3: Unable to bind the codec > -sh-4.3# lsmod > Module Size Used by > snd_hda_tegra 4764 0 > snd_hda_codec 75955 1 snd_hda_tegra > snd_hda_core 26603 2 snd_hda_codec,snd_hda_tegra > snd_pcm 69108 3 snd_hda_codec,snd_hda_tegra,snd_hda_core > snd_timer 17264 1 snd_pcm > snd 42248 4 snd_timer,snd_pcm,snd_hda_codec,snd_hda_tegra > soundcore 858 1 snd > nouveau 1302185 0 > tegra_devfreq 5375 0 > ttm 65238 1 nouveau > -sh-4.3# modprobe snd-hda-codec-hdmi > -sh-4.3# modprobe -r snd-hda-tegra > -sh-4.3# modprobe snd-hda-tegra > [ 2263.934328] input: tegra-hda HDMI/DP,pcm=3 as /devices/soc0/70030000.hda/sound/card0/input4 > > So all worked just fine. That's interesting. For me (as per my earlier email), I did not see the "unable to bind the codec" and modprobe attempted to load snd-hda-codec-hdmi after snd-hda-tega. Puzzled. Jon
On 11/09/15 14:25, Thierry Reding wrote: [snip] > Works for me 100% of the time. Unloading and reloading isn't a problem > either. What revision of the Jetson TK1 do you have? Mine is a C.2 Unfortunately, I am not sure it is whatever is in Paul's automation rig [0]. However, I have also reproduced this on a tegra124 nyan-big in the office. Cheers Jon [0] http://nvtb.github.io/linux-next/
On Fri, Sep 11, 2015 at 04:51:49PM +0100, Jon Hunter wrote: > > On 11/09/15 14:25, Thierry Reding wrote: > > [snip] > > > Works for me 100% of the time. Unloading and reloading isn't a problem > > either. What revision of the Jetson TK1 do you have? Mine is a C.2 > > Unfortunately, I am not sure it is whatever is in Paul's automation rig > [0]. However, I have also reproduced this on a tegra124 nyan-big in the > office. I was able to reproduce this using a busybox initial ramdisk. Just to make sure I built a separate one from git and it exposes the same behaviour. I suspect that this is some sort of weird interaction between mdev and async probing and nobody's noticed so far because async probing isn't very common (at least in the ARM world). I'll be off for the weekend soonish, but I'll try to find some more time next week to track this down. Thierry
On Fri, Sep 11, 2015 at 05:59:48PM +0200, Thierry Reding wrote: > On Fri, Sep 11, 2015 at 04:51:49PM +0100, Jon Hunter wrote: > > > > On 11/09/15 14:25, Thierry Reding wrote: > > > > [snip] > > > > > Works for me 100% of the time. Unloading and reloading isn't a problem > > > either. What revision of the Jetson TK1 do you have? Mine is a C.2 > > > > Unfortunately, I am not sure it is whatever is in Paul's automation rig > > [0]. However, I have also reproduced this on a tegra124 nyan-big in the > > office. > > I was able to reproduce this using a busybox initial ramdisk. Just to > make sure I built a separate one from git and it exposes the same > behaviour. I suspect that this is some sort of weird interaction between > mdev and async probing and nobody's noticed so far because async probing > isn't very common (at least in the ARM world). > > I'll be off for the weekend soonish, but I'll try to find some more time > next week to track this down. Before I head into the weekend, here are my findings: looks like this might be some sort of recursive locking problem. Here's the output with a lot of debug messages: / # modprobe snd-hda-tegra [ 298.765514] snd_hda_tegra: Unknown symbol snd_hdac_bus_enter_link_reset (err 0) [ 298.773024] snd_hda_tegra: Unknown symbol azx_probe_codecs (err 0) [ 298.779332] snd_hda_tegra: Unknown symbol snd_card_register (err 0) [ 298.785834] snd_hda_tegra: Unknown symbol snd_card_free (err 0) [ 298.792015] snd_hda_tegra: Unknown symbol azx_init_streams (err 0) [ 298.798485] snd_hda_tegra: Unknown symbol azx_stop_all_streams (err 0) [ 298.805234] snd_hda_tegra: Unknown symbol snd_dma_free_pages (err 0) [ 298.811816] snd_hda_tegra: Unknown symbol snd_hdac_bus_free_stream_pages (err 0) [ 298.819413] snd_hda_tegra: Unknown symbol snd_hdac_bus_exit (err 0) [ 298.825919] snd_hda_tegra: Unknown symbol snd_card_new (err 0) [ 298.832003] snd_hda_tegra: Unknown symbol snd_pcm_lib_malloc_pages (err 0) [ 298.839080] snd_hda_tegra: Unknown symbol snd_pcm_lib_free_pages (err 0) [ 298.846033] snd_hda_tegra: Unknown symbol azx_bus_init (err 0) [ 298.852070] snd_hda_tegra: Unknown symbol azx_free_streams (err 0) [ 298.858475] snd_hda_tegra: Unknown symbol azx_init_chip (err 0) [ 298.864626] snd_hda_tegra: Unknown symbol snd_device_new (err 0) [ 298.870856] snd_hda_tegra: Unknown symbol snd_hda_set_power_save (err 0) [ 298.877802] snd_hda_tegra: Unknown symbol azx_stop_chip (err 0) [ 298.883953] snd_hda_tegra: Unknown symbol azx_codec_configure (err 0) [ 298.890598] snd_hda_tegra: Unknown symbol snd_dma_alloc_pages (err 0) [ 298.897274] snd_hda_tegra: Unknown symbol snd_hdac_bus_alloc_stream_pages (err 0) [ 298.904975] snd_hda_tegra: Unknown symbol azx_interrupt (err 0) [ 299.024167] device: 'timer': device_add [ 299.031120] > driver_register(drv=bf06dd24) [ 299.035294] finding driver... [ 299.038495] adding driver... [ 299.041605] > __driver_attach(dev=ed805810, data=bf06dd24) [ 299.047115] matching device... [ 299.050352] > __driver_attach(dev=ed983e10, data=bf06dd24) [ 299.055857] matching device... [ 299.059086] > __driver_attach(dev=ed9a2010, data=bf06dd24) [ 299.064606] matching device... [ 299.067872] > __driver_attach(dev=ed9a2210, data=bf06dd24) [ 299.073384] matching device... [ 299.076658] > __driver_attach(dev=ed9a2410, data=bf06dd24) [ 299.082171] matching device... [ 299.085408] > __driver_attach(dev=ed9a2610, data=bf06dd24) [ 299.090912] matching device... [ 299.094141] > __driver_attach(dev=ed9a2810, data=bf06dd24) [ 299.099655] matching device... [ 299.102924] > __driver_attach(dev=ed9a2a10, data=bf06dd24) [ 299.108435] matching device... [ 299.111710] > __driver_attach(dev=ed9a2c10, data=bf06dd24) [ 299.117221] matching device... [ 299.120459] > __driver_attach(dev=ed9a2e10, data=bf06dd24) [ 299.125963] matching device... [ 299.129192] > __driver_attach(dev=ed9a3010, data=bf06dd24) [ 299.134706] matching device... [ 299.137976] > __driver_attach(dev=ed9a3210, data=bf06dd24) [ 299.143487] matching device... [ 299.146762] > __driver_attach(dev=ed9a3410, data=bf06dd24) [ 299.152273] matching device... [ 299.155511] > __driver_attach(dev=ed9a3610, data=bf06dd24) [ 299.161015] matching device... [ 299.164253] > __driver_attach(dev=ed9a3810, data=bf06dd24) [ 299.169752] matching device... [ 299.173016] > __driver_attach(dev=ed9a3a10, data=bf06dd24) [ 299.178527] matching device... [ 299.181802] > __driver_attach(dev=ed9a3c10, data=bf06dd24) [ 299.187325] matching device... [ 299.190560] > __driver_attach(dev=ed9a3e10, data=bf06dd24) [ 299.196062] matching device... [ 299.199301] > __driver_attach(dev=ed9a4010, data=bf06dd24) [ 299.204799] matching device... [ 299.208051] > __driver_attach(dev=ed9a4210, data=bf06dd24) [ 299.213534] matching device... [ 299.216796] > __driver_attach(dev=ed9a4410, data=bf06dd24) [ 299.222307] matching device... [ 299.225545] > __driver_attach(dev=ed9a4610, data=bf06dd24) [ 299.231060] matching device... [ 299.234295] > __driver_attach(dev=ed9a4810, data=bf06dd24) [ 299.239798] matching device... [ 299.243051] > __driver_attach(dev=ed9a4a10, data=bf06dd24) [ 299.248534] matching device... [ 299.251799] > __driver_attach(dev=ed9a4c10, data=bf06dd24) [ 299.257309] matching device... [ 299.260548] > __driver_attach(dev=ed9a4e10, data=bf06dd24) [ 299.266064] matching device... [ 299.269298] > __driver_attach(dev=ed9a5010, data=bf06dd24) [ 299.274801] matching device... [ 299.278054] > __driver_attach(dev=ed9a5210, data=bf06dd24) [ 299.283537] matching device... [ 299.286799] > __driver_attach(dev=ed9a5410, data=bf06dd24) [ 299.292311] matching device... [ 299.295549] > __driver_attach(dev=ed9a5610, data=bf06dd24) [ 299.301064] matching device... [ 299.304296] > __driver_attach(dev=ed9a5810, data=bf06dd24) [ 299.309800] matching device... [ 299.313054] > __driver_attach(dev=ed9a5a10, data=bf06dd24) [ 299.318537] matching device... [ 299.321808] done [ 299.323821] locking parent... [ 299.326991] done [ 299.329007] locking device... [ 299.332191] done [ 299.334201] probing device... [ 299.337372] bus: 'platform': driver_probe_device: matched device 70030000.hda with driver tegra-hda [ 299.346453] bus: 'platform': really_probe: probing driver tegra-hda with device 70030000.hda [ 299.354990] devices_kset: Moving 70030000.hda to end of list [ 299.510965] device: 'hdaudioC0D3': device_add [ 299.590057] > __hda_codec_driver_register(drv=bf0795f0, name=snd_hda_codec_hdmi, owner=bf079680) [ 299.598862] > driver_register(drv=bf0795f0) [ 299.603054] finding driver... [ 299.606206] adding driver... [ 299.609265] > __driver_attach(dev=ede27c00, data=bf0795f0) [ 299.614756] matching device... [ 299.617998] > hda_bus_match(dev=ede27c00, drv=bf0795f0) [ 299.623240] > hda_codec_match(dev=ede27c00, drv=bf0795f0) [ 299.628657] < hda_codec_match() match! [ 299.632429] done [ 299.634443] locking parent... It hangs here, but interestingly I can interrupt it using Ctrl-C: ^C[ 329.774183] > __device_attach_driver(drv=bf0795f0, _data=ecbc3d08) [ 329.780536] matching device... [ 329.783844] > hda_bus_match(dev=ede27c00, drv=bf0795f0) [ 329.789198] > hda_codec_match(dev=ede27c00, drv=bf0795f0) [ 329.794722] < hda_codec_match() match! [ 329.798600] async allowed: 0 [ 329.801790] bus: 'hdaudio': driver_probe_device: matched device hdaudioC0D3 with driver snd_hda_codec_hdmi [ 329.811577] bus: 'hdaudio': really_probe: probing driver snd_hda_codec_hdmi with device hdaudioC0D3 [ 329.820913] devices_kset: Moving hdaudioC0D3 to end of list [ 329.826618] > hda_codec_driver_probe(dev=ede27c00) [ 329.831533] device: hdaudioC0D3 [ 329.835152] > patch_tegra_hdmi(codec=ede27c00) [ 329.916075] < patch_tegra_hdmi() [ 329.920029] ALSA pcmC0D3p,0:HDMI 0: cannot preallocate for size 65536 [ 330.946327] < hda_codec_driver_probe() [ 330.950122] driver: 'snd_hda_codec_hdmi': driver_bound: bound to device 'hdaudioC0D3' [ 330.958115] bus: 'hdaudio': really_probe: bound device hdaudioC0D3 to driver snd_hda_codec_hdmi [ 330.966903] < __device_attach_driver() = 1 [ 330.971179] device: 'card0': device_add [ 330.975432] device: 'controlC0': device_add [ 330.981325] device: 'pcmC0D3p': device_add [ 330.987256] device: 'input1': device_add [ 330.991997] input: tegra-hda HDMI/DP,pcm=3 as /devices/soc0/70030000.hda/sound/card0/input1 [ 331.000477] device: 'event1': device_add [ 331.136299] driver: 'tegra-hda': driver_bound: bound to device '70030000.hda' [ 331.143621] bus: 'platform': really_probe: bound device 70030000.hda to driver tegra-hda [ 331.151804] done [ 331.153845] unlocking device... [ 331.157288] done [ 331.157473] done [ 331.157483] locking device... [ 331.157493] done [ 331.157501] unlocking device... [ 331.157508] done [ 331.157514] unlocking parent... [ 331.157522] done [ 331.157532] < __driver_attach() [ 331.157714] adding groups... [ 331.157722] sending KOBJ_ADD event... [ 331.157772] < driver_register() = 0 [ 331.157784] < __hda_codec_driver_register() = 0 [ 331.196006] unlocking parent... [ 331.199354] done [ 331.201407] < __driver_attach() [ 331.204551] > __driver_attach(dev=ed9a5c10, data=bf06dd24) [ 331.210061] matching device... [ 331.213325] > __driver_attach(dev=ed9a5e10, data=bf06dd24) [ 331.218826] matching device... [ 331.222091] > __driver_attach(dev=ed9a6010, data=bf06dd24) [ 331.227593] matching device... [ 331.230837] > __driver_attach(dev=ed9a6210, data=bf06dd24) [ 331.236341] matching device... [ 331.239578] > __driver_attach(dev=ed9a6410, data=bf06dd24) [ 331.245079] matching device... [ 331.248351] > __driver_attach(dev=ed9a6610, data=bf06dd24) [ 331.253854] matching device... [ 331.257119] > __driver_attach(dev=ed9a6810, data=bf06dd24) [ 331.262623] matching device... [ 331.265901] > __driver_attach(dev=ed9a6a10, data=bf06dd24) [ 331.271407] matching device... [ 331.274645] > __driver_attach(dev=ed9a6c10, data=bf06dd24) [ 331.280146] matching device... [ 331.283411] > __driver_attach(dev=ed9a6e10, data=bf06dd24) [ 331.288913] matching device... [ 331.292178] > __driver_attach(dev=ed9a7010, data=bf06dd24) [ 331.297681] matching device... [ 331.300955] > __driver_attach(dev=ed9a7210, data=bf06dd24) [ 331.306459] matching device... [ 331.309696] > __driver_attach(dev=ed9a7410, data=bf06dd24) [ 331.315197] matching device... [ 331.318461] > __driver_attach(dev=ed9a7610, data=bf06dd24) [ 331.323964] matching device... [ 331.327229] > __driver_attach(dev=ed9a7810, data=bf06dd24) [ 331.332732] matching device... [ 331.335993] > __driver_attach(dev=ed9a7a10, data=bf06dd24) [ 331.341497] matching device... [ 331.344734] > __driver_attach(dev=ed9a7c10, data=bf06dd24) [ 331.350236] matching device... [ 331.353502] > __driver_attach(dev=ed9a7e10, data=bf06dd24) [ 331.359005] matching device... [ 331.362269] > __driver_attach(dev=ed9b0010, data=bf06dd24) [ 331.367772] matching device... [ 331.371032] > __driver_attach(dev=ed9b0210, data=bf06dd24) [ 331.376533] matching device... [ 331.379771] > __driver_attach(dev=ed9b0410, data=bf06dd24) [ 331.385272] matching device... [ 331.388536] > __driver_attach(dev=ed9b0610, data=bf06dd24) [ 331.394039] matching device... [ 331.397312] > __driver_attach(dev=ed9b0810, data=bf06dd24) [ 331.402816] matching device... [ 331.406068] > __driver_attach(dev=ed9b0a10, data=bf06dd24) [ 331.411569] matching device... [ 331.414807] > __driver_attach(dev=ed9b0c10, data=bf06dd24) [ 331.420307] matching device... [ 331.423572] > __driver_attach(dev=ed9b0e10, data=bf06dd24) [ 331.429074] matching device... [ 331.432339] > __driver_attach(dev=ed9b1010, data=bf06dd24) [ 331.437841] matching device... [ 331.441092] > __driver_attach(dev=ed9b1210, data=bf06dd24) [ 331.446600] matching device... [ 331.449836] > __driver_attach(dev=ed9b1410, data=bf06dd24) [ 331.455339] matching device... [ 331.458604] > __driver_attach(dev=edad2410, data=bf06dd24) [ 331.464105] matching device... [ 331.467368] > __driver_attach(dev=edcbb810, data=bf06dd24) [ 331.472870] matching device... [ 331.476120] > __driver_attach(dev=edde4a10, data=bf06dd24) [ 331.481625] matching device... [ 331.484863] > __driver_attach(dev=edde5210, data=bf06dd24) [ 331.490366] matching device... [ 331.493630] > __driver_attach(dev=edde5410, data=bf06dd24) [ 331.499133] matching device... [ 331.502384] > __driver_attach(dev=edde5610, data=bf06dd24) [ 331.507879] matching device... [ 331.511129] > __driver_attach(dev=edde5810, data=bf06dd24) [ 331.516623] matching device... [ 331.519855] > __driver_attach(dev=edde5a10, data=bf06dd24) [ 331.525348] matching device... [ 331.528598] > __driver_attach(dev=ede78810, data=bf06dd24) [ 331.534092] matching device... [ 331.537341] > __driver_attach(dev=edeb5e10, data=bf06dd24) [ 331.542838] matching device... [ 331.546133] adding groups... [ 331.549184] sending KOBJ_ADD event... [ 331.553043] < driver_register() = 0 Thierry
Thierry Reding <thierry.reding@gmail.com> writes: > On Fri, Sep 11, 2015 at 05:59:48PM +0200, Thierry Reding wrote: >> On Fri, Sep 11, 2015 at 04:51:49PM +0100, Jon Hunter wrote: >> > >> > On 11/09/15 14:25, Thierry Reding wrote: >> > >> > [snip] >> > >> > > Works for me 100% of the time. Unloading and reloading isn't a problem >> > > either. What revision of the Jetson TK1 do you have? Mine is a C.2 >> > >> > Unfortunately, I am not sure it is whatever is in Paul's automation rig >> > [0]. However, I have also reproduced this on a tegra124 nyan-big in the >> > office. >> >> I was able to reproduce this using a busybox initial ramdisk. Just to >> make sure I built a separate one from git and it exposes the same >> behaviour. I suspect that this is some sort of weird interaction between >> mdev and async probing and nobody's noticed so far because async probing >> isn't very common (at least in the ARM world). >> >> I'll be off for the weekend soonish, but I'll try to find some more time >> next week to track this down. > > Before I head into the weekend, here are my findings: looks like this > might be some sort of recursive locking problem. Here's the output with > a lot of debug messages: FWIW, in kernelci we use a buildroot initramfs[1] with eudev enabled for module loading. Before booting, modules are injected into the ramdisk so they are loaded during boot by eudev. The source is on github[2] and can be rebuilt using './configs/frags/build armel' Kevin [1] http://storage.kernelci.org/images/rootfs/buildroot/armel/ [2] https://github.com/kernelci/buildroot/tree/kernelci/2015.02
On Fri, Sep 11, 2015 at 10:08:06AM -0700, Kevin Hilman wrote: > Thierry Reding <thierry.reding@gmail.com> writes: > > > On Fri, Sep 11, 2015 at 05:59:48PM +0200, Thierry Reding wrote: > >> On Fri, Sep 11, 2015 at 04:51:49PM +0100, Jon Hunter wrote: > >> > > >> > On 11/09/15 14:25, Thierry Reding wrote: > >> > > >> > [snip] > >> > > >> > > Works for me 100% of the time. Unloading and reloading isn't a problem > >> > > either. What revision of the Jetson TK1 do you have? Mine is a C.2 > >> > > >> > Unfortunately, I am not sure it is whatever is in Paul's automation rig > >> > [0]. However, I have also reproduced this on a tegra124 nyan-big in the > >> > office. > >> > >> I was able to reproduce this using a busybox initial ramdisk. Just to > >> make sure I built a separate one from git and it exposes the same > >> behaviour. I suspect that this is some sort of weird interaction between > >> mdev and async probing and nobody's noticed so far because async probing > >> isn't very common (at least in the ARM world). > >> > >> I'll be off for the weekend soonish, but I'll try to find some more time > >> next week to track this down. > > > > Before I head into the weekend, here are my findings: looks like this > > might be some sort of recursive locking problem. Here's the output with > > a lot of debug messages: > > FWIW, in kernelci we use a buildroot initramfs[1] with eudev enabled for > module loading. Before booting, modules are injected into the ramdisk > so they are loaded during boot by eudev. > > The source is on github[2] and can be rebuilt using './configs/frags/build armel' This turned out to be rather interesting. The reason why I wasn't seeing this on my setup was because request_module() ends up directly calling the /sbin/modprobe userspace helper. On my setup I had these files installed in /usr/bin (because that's the default installation path that kmod uses) and I was missing a symlink from /sbin to /usr/bin, therefore causing request_module() to return with -ENOENT. Unfortunately the HDA core code completely ignores errors from request_module() so didn't give any indication at all. Thanks to Jon Hunter who put me on that trail. After fixing the root filesystem I was seeing the deadlocks as well. But the root cause of this was now clearly the request_module(). It turns out that this causes the driver for the HDA codec to be bound to the HDA codec device immediately, from within the HDA controller's ->probe() callback, hence leading to the deadlock. That's a known problem in HDA land and for Intel this has been worked around rather creatively by deferring HDA codec probing to a work queue that runs asynchronously to the controller's probe. To be fair there seem to be other reasons why this is necessary on Intel (the HDA codec and i915 display drivers interact weirdly). It's possible that a work- around isn't necessary on Intel anymore either because the recursive locking of HDA controller vs. HDA codec is gone and the i915 device should be relatively far removed to not cause any deadlocks. I haven't invested any time in fixing this because I don't have a setup where I could test this. The solution I came up with, and I've sent patches earlier with a couple of people from this thread Cc'ed, is to get rid of the explicit calls to the request_module() function and use existing infrastructure instead. I implemented a uevent callback in the HDA bus that reports the MODALIAS information to the userspace helper, which can then use it to auto-load the proper module. That gets rid of the recursive locking because both devices are now probed from different contexts. This should work just fine with any relatively modern distribution. Both systemd and eudev implementations of udev should support loading modules when they see a MODALIAS environment variable. For busybox this doesn't work out of the box, but you can enable it by adding the following line to /etc/mdev.conf: # support module loading on hotplug $MODALIAS=.* root:root 660 @modprobe "$MODALIAS" Make sure you have /etc/passwd and /etc/group entries for root, or else mdev will fail to parse this file. mdev still doesn't automatically load modules on boot (mdev -s isn't quite the same as udevadm trigger), but that's only a minor inconvenience and maybe even expected when you use mdev. Given that the patches are somewhat invasive and probably need more testing on Intel, I'm not sure if they'll make it into v4.3. If not I suggest we go ahead and remove the problematic Kconfig option for now (or make it built-in) and enable it again when the fixes have landed (if not for v4.3 then hopefully for v4.4). Perhaps give it a week or so to give the sound tree maintainers a chance to look at the patches and evaluate whether or not they should go into v4.3. Does that sound reasonable? Thierry
diff --git a/arch/arm/configs/multi_v7_defconfig b/arch/arm/configs/multi_v7_defconfig index b2facab..a285afe 100644 --- a/arch/arm/configs/multi_v7_defconfig +++ b/arch/arm/configs/multi_v7_defconfig @@ -468,7 +468,6 @@ CONFIG_FRAMEBUFFER_CONSOLE_ROTATION=y CONFIG_SOUND=m CONFIG_SND=m CONFIG_SND_DYNAMIC_MINORS=y -CONFIG_SND_HDA_TEGRA=m CONFIG_SND_HDA_INPUT_BEEP=y CONFIG_SND_HDA_PATCH_LOADER=y CONFIG_SND_HDA_CODEC_REALTEK=m