From owner-freebsd-arm@freebsd.org Thu Nov 21 02:12:05 2019 Return-Path: Delivered-To: freebsd-arm@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id 04B0A1A9ADE for ; Thu, 21 Nov 2019 02:12:05 +0000 (UTC) (envelope-from fbsd@www.zefox.net) Received: from www.zefox.net (www.zefox.net [50.1.20.27]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "www.zefox.org", Issuer "www.zefox.org" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id 47JNNg4jrwz3Chw for ; Thu, 21 Nov 2019 02:12:03 +0000 (UTC) (envelope-from fbsd@www.zefox.net) Received: from www.zefox.net (localhost [127.0.0.1]) by www.zefox.net (8.15.2/8.15.2) with ESMTPS id xAL2C3wF001939 (version=TLSv1.2 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO); Wed, 20 Nov 2019 18:12:04 -0800 (PST) (envelope-from fbsd@www.zefox.net) Received: (from fbsd@localhost) by www.zefox.net (8.15.2/8.15.2/Submit) id xAL2C3eK001938; Wed, 20 Nov 2019 18:12:03 -0800 (PST) (envelope-from fbsd) Date: Wed, 20 Nov 2019 18:12:03 -0800 From: bob prohaska To: freebsd-arm@freebsd.org Subject: rpi3 panic: data pending interrupt pushed through SDHCI framework Message-ID: <20191121021203.GA1837@www.zefox.net> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.5.24 (2015-08-30) X-Rspamd-Queue-Id: 47JNNg4jrwz3Chw X-Spamd-Bar: ++ Authentication-Results: mx1.freebsd.org; dkim=none; dmarc=none; spf=none (mx1.freebsd.org: domain of fbsd@www.zefox.net has no SPF policy when checking 50.1.20.27) smtp.mailfrom=fbsd@www.zefox.net X-Spamd-Result: default: False [2.35 / 15.00]; ARC_NA(0.00)[]; WWW_DOT_DOMAIN(0.50)[]; RCVD_TLS_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; TO_DN_SOME(0.00)[]; IP_SCORE(0.07)[ip: (0.30), ipnet: 50.1.16.0/20(0.15), asn: 7065(-0.04), country: US(-0.05)]; MIME_GOOD(-0.10)[text/plain]; DMARC_NA(0.00)[zefox.net]; AUTH_NA(1.00)[]; NEURAL_SPAM_MEDIUM(0.13)[0.131,0]; TO_MATCH_ENVRCPT_SOME(0.00)[]; RCPT_COUNT_TWO(0.00)[2]; NEURAL_SPAM_LONG(0.25)[0.248,0]; R_SPF_NA(0.00)[]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; MIME_TRACE(0.00)[0:+]; ASN(0.00)[asn:7065, ipnet:50.1.16.0/20, country:US]; MID_RHS_MATCH_FROM(0.00)[]; MID_RHS_WWW(0.50)[]; RCVD_COUNT_TWO(0.00)[2] X-BeenThere: freebsd-arm@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: "Porting FreeBSD to ARM processors." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 21 Nov 2019 02:12:05 -0000 While trying to compile www/chromium on a Pi3 running r354909 the system reported a panic which is new, at least to me: panic: data pending interrupt pushed through SDHCI framework cpuid = 3 time = 1574299870 KDB: stack backtrace: db_trace_self() at db_trace_self_wrapper+0x28 pc = 0xffff00000072978c lr = 0xffff000000106548 sp = 0xffff00004026b4c0 fp = 0xffff00004026b6d0 db_trace_self_wrapper() at vpanic+0x18c pc = 0xffff000000106548 lr = 0xffff000000400c58 sp = 0xffff00004026b6e0 fp = 0xffff00004026b790 vpanic() at panic+0x44 pc = 0xffff000000400c58 lr = 0xffff000000400a08 sp = 0xffff00004026b7a0 fp = 0xffff00004026b820 panic() at bcm_sdhci_will_handle_transfer+0x64 pc = 0xffff000000400a08 lr = 0xffff00000071a48c sp = 0xffff00004026b830 fp = 0xffff00004026b840 bcm_sdhci_will_handle_transfer() at sdhci_generic_intr+0x69c pc = 0xffff00000071a48c lr = 0xffff00000022f44c sp = 0xffff00004026b850 fp = 0xffff00004026b8b0 sdhci_generic_intr() at ithread_loop+0x1e8 pc = 0xffff00000022f44c lr = 0xffff0000003c44e8 sp = 0xffff00004026b8c0 fp = 0xffff00004026b940 ithread_loop() at fork_exit+0x7c pc = 0xffff0000003c44e8 lr = 0xffff0000003c0fac sp = 0xffff00004026b950 fp = 0xffff00004026b980 fork_exit() at fork_trampoline+0x10 pc = 0xffff0000003c0fac lr = 0xffff000000746994 sp = 0xffff00004026b990 fp = 0x0000000000000000 KDB: enter: panic [ thread pid 12 tid 100051 ] Stopped at 0 db> bt Tracing pid 12 tid 100051 td 0xfffffd0000b9d000 db_trace_self() at db_stack_trace+0xf8 pc = 0xffff00000072978c lr = 0xffff00000010398c sp = 0xffff00004026b090 fp = 0xffff00004026b0c0 db_stack_trace() at db_command+0x228 pc = 0xffff00000010398c lr = 0xffff000000103604 sp = 0xffff00004026b0d0 fp = 0xffff00004026b1b0 db_command() at db_command_loop+0x58 pc = 0xffff000000103604 lr = 0xffff0000001033ac sp = 0xffff00004026b1c0 fp = 0xffff00004026b1e0 db_command_loop() at db_trap+0xf4 pc = 0xffff0000001033ac lr = 0xffff0000001066b0 sp = 0xffff00004026b1f0 fp = 0xffff00004026b410 db_trap() at kdb_trap+0x1d8 pc = 0xffff0000001066b0 lr = 0xffff0000004491f0 sp = 0xffff00004026b420 fp = 0xffff00004026b4d0 kdb_trap() at do_el1h_sync+0xf4 pc = 0xffff0000004491f0 lr = 0xffff000000746c08 sp = 0xffff00004026b4e0 fp = 0xffff00004026b510 do_el1h_sync() at handle_el1h_sync+0x78 pc = 0xffff000000746c08 lr = 0xffff00000072c078 sp = 0xffff00004026b520 fp = 0xffff00004026b630 handle_el1h_sync() at kdb_enter+0x34 pc = 0xffff00000072c078 lr = 0xffff00000044883c sp = 0xffff00004026b640 fp = 0xffff00004026b6d0 kdb_enter() at vpanic+0x1a8 pc = 0xffff00000044883c lr = 0xffff000000400c74 sp = 0xffff00004026b6e0 fp = 0xffff00004026b790 vpanic() at panic+0x44 pc = 0xffff000000400c74 lr = 0xffff000000400a08 sp = 0xffff00004026b7a0 fp = 0xffff00004026b820 panic() at bcm_sdhci_will_handle_transfer+0x64 pc = 0xffff000000400a08 lr = 0xffff00000071a48c sp = 0xffff00004026b830 fp = 0xffff00004026b840 bcm_sdhci_will_handle_transfer() at sdhci_generic_intr+0x69c pc = 0xffff00000071a48c lr = 0xffff00000022f44c sp = 0xffff00004026b850 fp = 0xffff00004026b8b0 sdhci_generic_intr() at ithread_loop+0x1e8 pc = 0xffff00000022f44c lr = 0xffff0000003c44e8 sp = 0xffff00004026b8c0 fp = 0xffff00004026b940 ithread_loop() at fork_exit+0x7c pc = 0xffff0000003c44e8 lr = 0xffff0000003c0fac sp = 0xffff00004026b950 fp = 0xffff00004026b980 fork_exit() at fork_trampoline+0x10 pc = 0xffff0000003c0fac lr = 0xffff000000746994 sp = 0xffff00004026b990 fp = 0x0000000000000000 db> The last top window contains last pid: 45350; load averages: 1.98, 2.87, 4.04 up 0+02:41:58 17:31:08 45 processes: 2 running, 43 sleeping CPU: 13.0% user, 0.0% nice, 7.3% system, 9.0% interrupt, 70.7% idle Mem: 417M Active, 72M Inact, 220M Laundry, 170M Wired, 97M Buf, 20M Free Swap: 7194M Total, 410M Used, 6784M Free, 5% Inuse, 12M In, 18M Out PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND 45134 root 1 47 0 320M 36M CPU0 0 0:19 47.44% c++ 45136 root 1 21 0 308M 28M swread 2 0:12 3.15% c++ 45135 root 1 21 0 304M 27M swread 2 0:11 3.34% c++ 45148 root 1 21 0 308M 26M swread 3 0:12 3.32% c++ 45350 bob 1 52 0 12M 2392K nanslp 3 0:00 0.00% gstat 1049 bob 1 20 0 19M 2020K select 1 0:03 0.03% sshd 1554 bob 1 20 0 13M 1912K CPU1 1 0:25 0.23% top 1058 bob 1 20 0 19M 1900K select 2 0:00 0.00% sshd 1059 bob 1 20 0 13M 1816K ttyin 0 0:01 0.00% tcsh 958 root 1 20 0 16M 1804K select 1 0:01 0.02% sendmail 1055 root 1 21 0 19M 1796K select 2 0:00 0.00% sshd 1046 root 1 24 0 19M 1788K select 2 0:00 0.00% sshd 1028 bob 1 20 0 19M 1744K select 2 0:00 0.00% sshd 1066 bob 1 20 0 19M 1744K select 1 0:00 0.00% sshd The last of the I/O activity log contains procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 1 0 12 1410224 5316 902 2 1 0 1176 638 0 0 14925 2704 6210 21 7 72 dT: 1.050s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 0 91 3 65 328.1 89 6459 33.6 0 0 0.0 88.3 mmcsd0 0 91 3 65 328.2 89 6459 33.7 0 0 0.0 88.3 mmcsd0s2 0 2 2 61 484.6 0 0 0.0 0 0 0.0 92.3 mmcsd0s2a 0 90 1 4 15.5 89 6459 33.7 0 0 0.0 88.2 mmcsd0s2b 0 2 2 61 484.6 0 0 0.0 0 0 0.0 92.3 ufs/rootfs 7 126 0 0 0.0 126 6021 3.8 0 0 0.0 30.1 da0 5 83 0 0 0.0 83 6021 4.0 0 0 0.0 30.4 da0p6 Wed Nov 20 17:30:44 PST 2019 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 138100 4266152 3% /dev/da0p6 5242880 139496 5103384 3% Total 9647132 277596 9369536 3% Nov 20 17:27:25 www sshd[44294]: error: PAM: Authentication error for illegal user support from 103.133.104.114 Nov 20 17:27:26 www sshd[44294]: error: Received disconnect from 103.133.104.114 port 52227:14: No more user authentication methods available. [preauth] procs memory page suggesting the panic happened while vmstat was writing to the log. For the moment I'll update /usr/src and rebuild. Please indicate if more useful observations can be gathered. Thanks for reading, bob prohaska