From nobody Thu Dec 28 12:21:23 2023 X-Original-To: freebsd-arm@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4T170V4TpPz55kd8 for ; Thu, 28 Dec 2023 12:21:30 +0000 (UTC) (envelope-from bzeeb-lists@lists.zabbadoz.net) Received: from mx1.sbone.de (mx1.sbone.de [IPv6:2a01:4f8:13b:39f::9f:25]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "mx1.sbone.de", Issuer "SBone.DE Root Certificate Authority" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id 4T170V1Wkvz4NFw; Thu, 28 Dec 2023 12:21:30 +0000 (UTC) (envelope-from bzeeb-lists@lists.zabbadoz.net) Authentication-Results: mx1.freebsd.org; none Received: from mail.sbone.de (mail.sbone.de [IPv6:fde9:577b:c1a9:4902:0:7404:2:1025]) (using TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mx1.sbone.de (Postfix) with ESMTPS id 6A58D8D4A142; Thu, 28 Dec 2023 12:21:27 +0000 (UTC) Received: from content-filter.t4-02.sbone.de (content-filter.t4-02.sbone.de [IPv6:fde9:577b:c1a9:4902:0:7404:2:2742]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by mail.sbone.de (Postfix) with ESMTPS id 895232D029D7; Thu, 28 Dec 2023 12:21:26 +0000 (UTC) X-Virus-Scanned: amavisd-new at sbone.de Received: from mail.sbone.de ([IPv6:fde9:577b:c1a9:4902:0:7404:2:1025]) by content-filter.t4-02.sbone.de (content-filter.t4-02.sbone.de [IPv6:fde9:577b:c1a9:4902:0:7404:2:2742]) (amavisd-new, port 10024) with ESMTP id 6lccgxIDY-W4; Thu, 28 Dec 2023 12:21:24 +0000 (UTC) Received: from strong-iwl0.sbone.de (strong-iwl0.sbone.de [IPv6:fde9:577b:c1a9:4902:b66b:fcff:fef3:e3d2]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by mail.sbone.de (Postfix) with ESMTPSA id A643D2D029D2; Thu, 28 Dec 2023 12:21:24 +0000 (UTC) Date: Thu, 28 Dec 2023 12:21:23 +0000 (UTC) From: "Bjoern A. Zeeb" To: Warner Losh cc: "freebsd-arm@freebsd.org" , Warner Losh Subject: Re: MMCCAM hang In-Reply-To: Message-ID: <6sp3659o-21pr-773q-2s04-7s5n60s60481@yvfgf.mnoonqbm.arg> References: X-OpenPGP-Key-Id: 0x14003F198FEFA3E77207EE8D2B58B8F83CCF1842 List-Id: Porting FreeBSD to ARM processors List-Archive: https://lists.freebsd.org/archives/freebsd-arm List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-arm@freebsd.org MIME-Version: 1.0 Content-Type: multipart/mixed; BOUNDARY="1098556516-150255199-1703765891=:54546" Content-ID: X-Rspamd-Pre-Result: action=no action; module=replies; Message is reply to one we originated X-Spamd-Result: default: False [-4.00 / 15.00]; REPLY(-4.00)[]; ASN(0.00)[asn:24940, ipnet:2a01:4f8::/32, country:DE] X-Spamd-Bar: ---- X-Rspamd-Queue-Id: 4T170V1Wkvz4NFw This message is in MIME format. The first part should be readable text, while the remaining parts are likely unreadable without MIME-aware tools. --1098556516-150255199-1703765891=:54546 Content-Type: text/plain; CHARSET=UTF-8; format=flowed Content-Transfer-Encoding: 8BIT Content-ID: <8934p5r9-2op9-6nq7-3p89-369ons79p08r@mnoonqbm.arg> On Wed, 27 Dec 2023, Warner Losh wrote: > On Wed, Dec 27, 2023, 4:55 PM Bjoern A. Zeeb > wrote: > >> Hi, >> >> sdhci_fsl_fdt0: Desired SD/MMC freq: 50000000, actual: 50000000; base >> 700000000 prescale 1 divisor 14 >> GEOM: new disk sdda0 >> sdda0 at sdhci_slot0 bus 0 scbus0 target 0 lun 0 >> sdda0: Relative addr: 00000002 >> Card features: >> Card random: unblocking device. >> GEOM: new disk sdda0boot0 >> memory OCR: 00ff8080 >> sdda0: Serial Number ....... >> sdda0: MMCHC .................................. by 17 0x0000 >> GEOM: new disk sdda0boot1 >> uhub0: 2 ports with 2 removable, self powered >> >> at which point basically anything hangs. In auto-boot it is >> before/during file-system checks. >> In single user mode camcontrol devlist will show sdda0 >> but >> >> root@:/ # gpart show sdda0 >> load: 6.06 cmd: gpart 24 [g_waitfor_event] 1.28r 0.00u 0.00s 0% 2088k >> {forever} >> >> >> Unclear at which point I broke to debugger and this is where it seems to >> hang: >> >> db> trace 100088 >> Tracing pid 4 tid 100088 td 0xffff0000dc527000 >> ipi_stop() at ipi_stop+0x34 >> arm_gic_v3_intr() at arm_gic_v3_intr+0xe4 >> intr_irq_handler() at intr_irq_handler+0x80 >> handle_el1h_irq() at handle_el1h_irq+0x14 >> --- interrupt >> spinlock_exit() at spinlock_exit+0x44 >> callout_reset_sbt_on() at callout_reset_sbt_on+0x210 >> sdhci_cam_action() at sdhci_cam_action+0x284 >> xpt_run_devq() at xpt_run_devq+0x4c8 >> xpt_action_default() at xpt_action_default+0x470 >> sddastart() at sddastart+0x1bc >> xpt_run_allocq() at xpt_run_allocq+0xa8 >> xpt_done_process() at xpt_done_process+0x610 >> xpt_done_td() at xpt_done_td+0x1a8 >> fork_exit() at fork_exit+0x8c >> fork_trampoline() at fork_trampoline+0x18 >> >> >> Anyone an idea? >> > > > Looks like deadlock with another thread. Anybody else in the time keeping / > callout code? I need to a build a kernel with debugging on... New boot ... so thread 100092 now... which seems to move ... # gpart show load: 9.90 cmd: gpart 20 [g_waitfor_event] 104.65r 0.00u 0.00s 0% 2048k Tracing command kernel pid 0 tid 100011 td 0xffff0000dc2cc2c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 msleep_spin_sbt() at msleep_spin_sbt+0xf4 gtaskqueue_thread_loop() at gtaskqueue_thread_loop+0x160 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 [...] Tracing command kernel pid 0 tid 100027 td 0xffff0000dc4c2900 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 msleep_spin_sbt() at msleep_spin_sbt+0xf4 gtaskqueue_thread_loop() at gtaskqueue_thread_loop+0x160 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command kernel pid 0 tid 100028 td 0xffff0000dc4c22c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 taskqueue_thread_loop() at taskqueue_thread_loop+0x124 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 [...] Tracing command kernel pid 0 tid 100175 td 0xffff0000f16fd900 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 taskqueue_thread_loop() at taskqueue_thread_loop+0x124 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command kernel pid 0 tid 100177 td 0xffff0000f36eb2c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 msleep_spin_sbt() at msleep_spin_sbt+0xf4 taskqueue_thread_loop() at taskqueue_thread_loop+0x160 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 [...] Tracing command kernel pid 0 tid 100181 td 0xffff0000f2116900 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 taskqueue_thread_loop() at taskqueue_thread_loop+0x124 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command init pid 1 tid 100002 td 0xffff0000dc2c5640 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 sleepq_catch_signals() at sleepq_catch_signals+0x424 sleepq_wait_sig() at sleepq_wait_sig+0xc _sleep() at _sleep+0x1d8 kern_wait6() at kern_wait6+0x754 sys_wait4() at sys_wait4+0x84 do_el0_sync() at do_el0_sync+0x634 handle_el0_sync() at handle_el0_sync+0x48 --- exception, esr 0x56000000 Tracing command clock pid 2 tid 100057 td 0xffff0000dc4d82c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 softclock_thread() at softclock_thread+0x104 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command clock pid 2 tid 100058 td 0xffff0000dc4d7c80 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 softclock_thread() at softclock_thread+0x104 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 [...] Tracing command cam pid 4 tid 100088 td 0xffff0000dc527000 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 xpt_done_td() at xpt_done_td+0xfc fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command cam pid 4 tid 100089 td 0xffff0000dc52d000 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 xpt_done_td() at xpt_done_td+0xfc fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command cam pid 4 tid 100090 td 0xffff0000dc52c900 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 xpt_async_td() at xpt_async_td+0xf4 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command cam pid 4 tid 100182 td 0xffff0000f21162c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 xpt_scanner_thread() at xpt_scanner_thread+0xfc fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 [...] Tracing command intr pid 12 tid 100092 td 0xffff0000dc52bc80 (CPU 1) ipi_stop() at ipi_stop+0x34 arm_gic_v3_intr() at arm_gic_v3_intr+0xe4 intr_irq_handler() at intr_irq_handler+0x80 handle_el1h_irq() at handle_el1h_irq+0x14 --- interrupt generic_bs_r_4() at generic_bs_r_4+0xc sdhci_generic_reset() at sdhci_generic_reset+0x140 sdhci_fsl_fdt_reset() at sdhci_fsl_fdt_reset+0x20 sdhci_finish_command() at sdhci_finish_command+0xf4 sdhci_generic_intr() at sdhci_generic_intr+0x388 ithread_loop() at ithread_loop+0x3ac fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 [...] Tracing command geom pid 13 tid 100067 td 0xffff0000dc4da900 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 biowait() at biowait+0xc4 g_read_data() at g_read_data+0x88 g_raid_md_taste_ddf() at g_raid_md_taste_ddf+0x104 g_raid_taste() at g_raid_taste+0x184 g_new_provider_event() at g_new_provider_event+0xac g_run_events() at g_run_events+0x2e4 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command geom pid 13 tid 100068 td 0xffff0000dc4da2c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 g_io_schedule_up() at g_io_schedule_up+0x74 g_up_procbody() at g_up_procbody+0x70 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command geom pid 13 tid 100069 td 0xffff0000dc4d9c80 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 g_io_schedule_down() at g_io_schedule_down+0x7c g_down_procbody() at g_down_procbody+0x70 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 [...] Tracing command gpart pid 20 tid 100206 td 0xffff000042a082c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 g_waitfor_event() at g_waitfor_event+0x118 sysctl_kern_geom_confany() at sysctl_kern_geom_confany+0xd0 sysctl_root_handler_locked() at sysctl_root_handler_locked+0x11c sysctl_root() at sysctl_root+0x21c userland_sysctl() at userland_sysctl+0x190 sys___sysctl() at sys___sysctl+0x6c do_el0_sync() at do_el0_sync+0x634 handle_el0_sync() at handle_el0_sync+0x48 --- exception, esr 0x56000000 db> {out and back in} cpuid = 1 dynamic pcpu = 0x41c17f00 curthread = 0xffff0000dc52bc80: pid 12 tid 100092 critnest 1 "gic0,s28:-_fsl_fdt0" curpcb = 0xffff0000dc64ab20 fpcurthread = none idlethread = 0xffff0000dc2c4900: tid 100004 "idle: cpu1" curvnet = 0 Tracing command intr pid 12 tid 100092 td 0xffff0000dc52bc80 (CPU 1) ipi_stop() at ipi_stop+0x34 arm_gic_v3_intr() at arm_gic_v3_intr+0xe4 intr_irq_handler() at intr_irq_handler+0x80 handle_el1h_irq() at handle_el1h_irq+0x14 --- interrupt spinlock_exit() at spinlock_exit+0x44 wakeup() at wakeup+0x34 xpt_done() at xpt_done+0x164 sdhci_generic_intr() at sdhci_generic_intr+0x388 ithread_loop() at ithread_loop+0x3ac fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command geom pid 13 tid 100067 td 0xffff0000dc4da900 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 biowait() at biowait+0xc4 g_read_data() at g_read_data+0x88 g_raid_md_taste_ddf() at g_raid_md_taste_ddf+0x104 g_raid_taste() at g_raid_taste+0x184 g_new_provider_event() at g_new_provider_event+0xac g_run_events() at g_run_events+0x2e4 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command geom pid 13 tid 100068 td 0xffff0000dc4da2c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 g_io_schedule_up() at g_io_schedule_up+0x74 g_up_procbody() at g_up_procbody+0x70 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command geom pid 13 tid 100069 td 0xffff0000dc4d9c80 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 g_io_schedule_down() at g_io_schedule_down+0x7c g_down_procbody() at g_down_procbody+0x70 fork_exit() at fork_exit+0x8c fork_trampoline() at fork_trampoline+0x18 Tracing command gpart pid 20 tid 100206 td 0xffff000042a082c0 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0x108 _sleep() at _sleep+0x1e4 g_waitfor_event() at g_waitfor_event+0x118 sysctl_kern_geom_confany() at sysctl_kern_geom_confany+0xd0 sysctl_root_handler_locked() at sysctl_root_handler_locked+0x11c sysctl_root() at sysctl_root+0x21c userland_sysctl() at userland_sysctl+0x190 sys___sysctl() at sys___sysctl+0x6c do_el0_sync() at do_el0_sync+0x634 handle_el0_sync() at handle_el0_sync+0x48 --- exception, esr 0x56000000 -- Bjoern A. Zeeb r15:7 --1098556516-150255199-1703765891=:54546--