From nobody Fri Sep 30 02:14:44 2022 X-Original-To: freebsd-uboot@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 4Mdv2741Mgz4dgFt for ; Fri, 30 Sep 2022 02:14:55 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic307-8.consmr.mail.gq1.yahoo.com (sonic307-8.consmr.mail.gq1.yahoo.com [98.137.64.32]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4Mdv260S2Dz3k6D for ; Fri, 30 Sep 2022 02:14:53 +0000 (UTC) (envelope-from marklmi@yahoo.com) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1664504092; bh=6ZW1K5/4lrYw2F2j8ngpat6GonTqgpZYPVarFyzd/LM=; h=Subject:From:In-Reply-To:Date:Cc:References:To:From:Subject:Reply-To; b=CVb1bzgm62bPvxq/KbubqfLhq3G2tUua4RpHg1aV9zB8vMpbZos5ooovMo8YB2v9x6szq0AzaaNchjNHztGBYxaBXUZ46+UrfO5ieV03tgzWA6a48aQmyu7hHPOvWwObgWyzXrL8JOOEtfn1+zBIpklZvL6EGZtMHavcehvROJ9VAkw7mDOBbMgyuHyE7mzw+viM9SSB6vT7WD5U0j+f0naG+19fa/fujmkxgLkeL2gbk7n8blaf4H0rGiNt9HaevcIacRJxckxEvxpnsmorFvmiRGmddu58safEhQ1r2RrD1rA9X4vvaNaRNEb/mpFyKuKdDLHuBC3zUHEnavzt7Q== X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1664504092; bh=p2c6wzRel1nL9Y5/YXWdZt3MCKa7fvMgdTi2fIT2erU=; h=X-Sonic-MF:Subject:From:Date:To:From:Subject; b=pi8Y6DXcGHUjPNBvxl+A54skXC2rxGOhep6fcC8xdyaTbVq4FF4mshRTZxnNG7tBMPn7W0qbggNVjbFPP83/H1osmQSOZfjgmDQGJH99jbDrkEPsOUW6aF9Rw44I7o+Sl/X2FbnZykhln183WnEDcHEgzFXYPe8yNOx9F0YOztKAAjySDpKZ/GRd5RGVGCIqMlG4CVYnqIOwrTw7Qboa5Ep9dJyWvg6nEAVOMEPdCCxyX8IDFqss1qHM+fBT+l3aFqJDpBShQoAFCVWZM23U9yOK65jrOQD8nRXC0DZRGvqO4nG1HMn3c6Odbbh3aa8LtB7trRgmNpLqtVwwhKfvSg== X-YMail-OSG: fjWfIsYVM1nITSgtXvU_x6CVNkbTKsiyS98eCUWNaCyExeg4cldW6UAKRuR1lKs Nt.e16A_W4L3rhhE2PrMC9a8SE7LPLb0dJhHUT.p2nqK9wsszxNV8RmoEDnVA.4twtQvYw1h2nHD vmVYjtHpCRvqPF5VoDhp1pxWD5fv7o5IhIcYdCawOPsBlFJzyM1D1dD12oUEgHu5ULjIl2xMlay2 ArosUdlNOLZkNEne.Uw91lP1KlHSzeuxMMSds5g_rsKNQGmhPEFURFZLwJUeThDiOeOdeyvVYPbK tdc.6ff0EXMs_Ha_zzgTiQoz.KM7VmUPE0uDd5u3NN8mzVeRPovxTAjbXaZRThvGN_BhvfTDTZCI KXk.RNT5bCNBm9szlOqOkOpCHH9BY8xkTaZETaqQO1NkL4QDJta6VXTAo01Bx5VDo5jZwLLg9BBg vXxvOBtjqhhFogOtooKmuJLak9KbtbXY4FVEFIaDyWN2baj6YtkcBAsMyTZY4omLelyvqI9u2yl4 pDXzyJ4FE426D1DS8s9lVoPo4KzzCeWtpDyKHusL1QtcStIln8o65zejnhKT0gJIyMBwFYlVRjUL r3E9rpJjJ3ZsyWSuDsx93fI2.PMMTS3dUNYp8oiNZWFzLU7.ij9Jx.UKvQNbXRcSoT5ryCYYSAvy CjGgzAgIx8PdsTLVAmcHGlIpfSdPf5VJKDqE2CgyaRMLvpgtmjIEZMsZdIiK9Ral2BqTP3VL0sUY lebpxLPyVcfmtzApBYHuizgtdWL6RG_BycoHbFWNpzXmRul.cHn8Gl3r6.zYvD84uzoJ1lGjbKun 2dGNXR31TvbCAsPaK0ulT.x6uLKfuYjNNCYjF1hdfUX0aXaExhI8HdQfKR__UQgzN.R3STKL_UeC LrtFGBetank.tPRC0ocYJgfuVu_cHa73tVLBufw10S8hU5SQOsp7VUiysufdkBSveUjd3fyGQmlb 9at5L_AlohcbmfS1tfzQhWjQ9zfGX3Efs2wN2.x6I3R7CPXrOSAuK1g.P.FwSw4dy8WI7wAE3w5T gsGtaEPtrxnjm56bxpOzvgt_SlkMb0vGhL1sRTwHGy4Z7AQSfWA4QUnlAo.8wPBlVrkPev4nB4DV ZrMCW_xjf6lQkErF5FThgnELU61rpXcnBXjbXerbVB1FObAkAGBgXHQkXgGBcqY8LPaGquaG_bzg HBxXJPy9bYomxNnR7NOHznh0aeg37QxBs24BwWS6_W_AFv.fX3b9pgfFvoE.gIJTTJiT3bzczuRU pd.u6T8oHDnyV50ZRHTngbLbYvawy5Pk4mjYhcUw.x7I0q1CHfEVJKAujzF_KEhiEbrN4KWaud5n hIlag94a8T5o6sK_ESD5HnRB.8C6FbVN66fbdsJmJbwdCC7Mf.W9lLQS45WDaUVkV6nklm5sFWP7 oHn9VW0_PAMfTElkjSG9GBjAmMAxtpzP2XWwGJ8f0kGS9jT5UIOQ0LYLQMbjeScYyOkLRzuI0b0. Qqeaeluwk1Oo.sUgObEn8W_D1PAzwNJy_gKbn82Tbo2Hajp4Ndb5VFX.14zLgpnbhNnRqEYCiypr PmE6Tjg_h.tN8pE6ICsDKgM6XQTKw7Dvp_bz5tkNIPfWG16NBb9Qr3emliQROyH6BSfPKL6JCLIh UH7QvTouTOrVya0d_COOaMFVDcJHP1YvuXZX46atTKO7RoGNiwOmq.gaxJwG.FnLbqX5zCmbNe0A edjFOQTl8ROPB4jTsKmbQupdX6iniUs.1SiTm0IV6tVywlc0POeCs_qzNnISZobCv5G7_UAjo0Id nEZHMKPi.Mbe90DDx2Gix1GRgt9p4prX8i2yFeVI0qtp_L.crKaAv2hs.egqRFNkD1gjaEyhC.cL rlWrqcRGN4LdursS9A8MVQNsXTqFKIhfqI9HuGE0_U1Jw1m7fFzMBZKC78.XEgQSRT7krOYf_0K6 EWd2Jug1D5NuQf4ntGCYWVx06agaw45C3aNjE0DNqTKeqED7qduLxO1Iil0d2wp6wg7D6O5DmuJR cAht3O62nhXAmNpnA7KzWRYUBbGBPSkjDzFs9Hw0Egj_K8WI0XaexKabTVQwRN8R4SpmMwxHApfd kDYuZcQUZwt905SWpTpMCWvtYAJzaFqg6YqWbV8HdKpEkFcpWsp9vIIzR_NBZOTupAwpsTctSF1X nWQ9GAWVGuxII66VsPb70dg.FEuEz1Kd2R1iu4nCk5JvW1qz6Ksz74rzhBucRWV0._9UCoZ_G3NV g4H1wpM2cmKS0oh_crsL7ICw_tKfqUVZfUae535nXVRgbmLfBPfpQo33hXl2fBgl11p2BpsBJBij f676jtRtIag-- X-Sonic-MF: Received: from sonic.gate.mail.ne1.yahoo.com by sonic307.consmr.mail.gq1.yahoo.com with HTTP; Fri, 30 Sep 2022 02:14:52 +0000 Received: by hermes--production-bf1-5fb9f4c8b8-vstzd (Yahoo Inc. Hermes SMTP Server) with ESMTPA ID 3f3831060bf4f328a6b33aef608e58cb; Fri, 30 Sep 2022 02:14:46 +0000 (UTC) Content-Type: text/plain; charset=us-ascii List-Id: Discussions List-Archive: https://lists.freebsd.org/archives/freebsd-uboot List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-uboot@freebsd.org X-BeenThere: freebsd-uboot@freebsd.org Mime-Version: 1.0 (Mac OS X Mail 16.0 \(3696.120.41.1.1\)) Subject: Re: u-boot debug, was: Re: U-boot on RPI3, sees disk but won't boot it From: Mark Millard In-Reply-To: <20220930002742.GA81169@www.zefox.net> Date: Thu, 29 Sep 2022 19:14:44 -0700 Cc: freebsd-arm , freebsd-uboot@freebsd.org Content-Transfer-Encoding: quoted-printable Message-Id: References: <6AA65AE6-41F1-405F-A592-7D641EA4C9CF@yahoo.com> <20220929054120.GA77803@www.zefox.net> <20220929151926.GA80020@www.zefox.net> <20220929170927.GB80020@www.zefox.net> <6C5019EC-B4A8-448F-9A85-4A98BC46F7DD@yahoo.com> <20220930002742.GA81169@www.zefox.net> To: bob prohaska X-Mailer: Apple Mail (2.3696.120.41.1.1) X-Rspamd-Queue-Id: 4Mdv260S2Dz3k6D X-Spamd-Bar: --- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=yahoo.com header.s=s2048 header.b=CVb1bzgm; dmarc=pass (policy=reject) header.from=yahoo.com; spf=pass (mx1.freebsd.org: domain of marklmi@yahoo.com designates 98.137.64.32 as permitted sender) smtp.mailfrom=marklmi@yahoo.com X-Spamd-Result: default: False [-3.50 / 15.00]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_SHORT(-1.00)[-1.000]; MV_CASE(0.50)[]; DMARC_POLICY_ALLOW(-0.50)[yahoo.com,reject]; R_SPF_ALLOW(-0.20)[+ptr:yahoo.com]; R_DKIM_ALLOW(-0.20)[yahoo.com:s=s2048]; MIME_GOOD(-0.10)[text/plain]; FROM_HAS_DN(0.00)[]; RCPT_COUNT_THREE(0.00)[3]; RCVD_VIA_SMTP_AUTH(0.00)[]; TO_MATCH_ENVRCPT_SOME(0.00)[]; ARC_NA(0.00)[]; RCVD_IN_DNSWL_NONE(0.00)[98.137.64.32:from]; DWL_DNSWL_NONE(0.00)[yahoo.com:dkim]; RCVD_TLS_LAST(0.00)[]; MLMMJ_DEST(0.00)[freebsd-uboot@freebsd.org]; RCVD_COUNT_THREE(0.00)[3]; FREEMAIL_FROM(0.00)[yahoo.com]; TO_DN_SOME(0.00)[]; MID_RHS_MATCH_FROM(0.00)[]; DKIM_TRACE(0.00)[yahoo.com:+]; MIME_TRACE(0.00)[0:+]; FROM_EQ_ENVFROM(0.00)[]; ASN(0.00)[asn:36647, ipnet:98.137.64.0/20, country:US]; FREEMAIL_ENVFROM(0.00)[yahoo.com]; RWL_MAILSPIKE_POSSIBLE(0.00)[98.137.64.32:from] X-ThisMailContainsUnwantedMimeParts: N On 2022-Sep-29, at 17:27, bob prohaska wrote: > On Thu, Sep 29, 2022 at 12:55:00PM -0700, Mark Millard wrote: >> On 2022-Sep-29, at 10:09, bob prohaska wrote: >>=20 >>> . . . >>=20 >> In part I was going by your indication to avoid "bloat", >> which I had guessed was a reference to the logging output >> instead of the size of u-boot.bin : >>=20 >> QUOTE >> The maximum logging level was 4 out of 7, fearing bloat. >> END QUOTE >=20 > No, actually I was then worried about getting a u-boot binary > too large to let me keep a few usable versions in /boot/msdos. > I had at the time absolutely no concept of output volume. Ahh, okay. It turns out your capture of an automatic reset needed the read activity details. It has: . . . 6 USB Device(s) found scanning usb for storage devices... 1 Storage Device(s) found U-Boot> run bootcmd_usb0 Device 0:=20 usb_read: udev 0 usb_read: dev 0 startblk 0, blccnt 1 buffer 3af42c00 read10: start 0 blocks 1 COMMAND phase DATA phase usb_bulk_msg error status 0 BBB_reset usb_control_msg: request: 0xFF, requesttype: 0x21, value 0x0 index 0x0 = length 0x0 BBB_reset result -110: status 0 reset usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x81 = length 0x0 BBB_reset result -22: status 0 clearing IN endpoint usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x2 = length 0x0 BBB_reset result -22: status 0 clearing OUT endpoint BBB_reset done Read ERROR COMMAND phase DATA phase Raspberry Pi Bootcode Read File: config.txt, 265 Read File: start.elf, 2952960 (bytes) Read File: fixup.dat, 7314 (bytes) MESS:00:00:21.193325:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:21.197789:0: brfs: File read: 265 bytes . . . So, apparently, the RPi3B (not just USB) reset during a phase of a Read's activity over the USB bus. It never got as far as reporting the STATUS phase of the read. I've no clue if it is some form of watchdog based reset or a power based reset. But one of the two seem likely. I'm not familiar with the result codes, endpoint clearing, or the like. But at some point I'll try to figure out what -110 and -22 have for names. That might give a clue. >> . . . >>=20 >=20 > There might be another reason for making changes. Apart from the > failure captured last night and posted, every graceful shutdown -r > has succeeded. The count is now 22. It's understood that debugging > code can alter the behavior of bugs, but I didn't expect it to > _fix_ an apparent bug. It's up to 22 successful reboots in a row.=20 Serial console output takes signficant time and can significantly change the timing of what is before vs. after the output request in the code. The extra time can make various type of problems either more or less likely to be observed. > Ah, until now. The 23rd reboot got stuck at the outset, with > Syncing disks, vnodes remaining... Waiting (max 60 seconds) for system = process `syncer' to stop... 2 1 0 0 done > All buffers synced. > Uptime: 1m16s > Resetting system ... > and then nothing. Plug-pulling time. > Came up just fine. >=20 > Is it possible the append a change to patch file > names, like "no.verbose.patch-common_usb__storage.c" as > a way to de-activate them with minimal typing? If it > won't fail to detect the disk some kind of incremental > backout of the diagnostics looks necessary, or at least > useful. =20 One way to deactivate patch files that are not explicit in the Makefile is to move them one level up into ../ ( so out of files/ ), as I understand. Another way is to change names so they do not start with: patch- as I understand. >>=20 >> On a different issue . . . >>=20 >> I'm also hoping that you will happen to also capture >> examples of automatic reset/start-over sequences. It >> may be that those requiring getting to the U-Boot prompt >> and typing commands. (Has it ever happened otherwise?) >>=20 > Are you referring to cases where "assisted" boots fail? >=20 > There have been quite a few cases where on reboot u-boot > finds zero storage devices, but usb reset finds one device. > Typing run bootcmd_usb0 then results in a pause, a re-run > of u-boot and a successful boot. The explicit evidence so far is that "a re-run of u-boot" is better described as "the RPi3B rebooting", starting with execution of the RPi3B firmware and later again getting to the stage of u-boot.bin being loaded and started. > Sometimes the machine > silently hangs with the Device 0: message. Sometimes it > boots.=20 >=20 > I just captured an example now. Because of the file's > size it's at=20 > http://nemesis.zefox.com/~fbsd/=20 > in a file named=20 >=20 > pelorus_console.txt >=20 > By my count the interesting part will be in the last 10% of the =20 > ~9 MB file.=20 >=20 > For some reason the file is littered with non-ascii characters. So far it looks like a binary capture that has every byte sent out in it, including escape characters (ASCII 27 decimal) that start escape sequences for controlling a display. Also, every Carriage Return (ASCII 13 decimal) and every line feed is explicit. There is some text at the beginning (after the first "login:" that looks to be junk so all the following bytes up to the "Password:" after the junk should probably be replaced by one newline or by nothing. There is a sequence (using ESC to indicate an escape character): ESC[?25h that occurs 73225 times in the file. In my normal binary captures of one boot sequence I get somewhat over 4000 of them as I remember. There is interesting text between the sequences, commonly one letter of some overall text. I delete all instances of the escape sequence to read the text with the letters next to each other. The delete is via a find-and-replace-all that replaces them with an empty string. There are 522 more escape characters that were not the beginning of that specific escape sequence. I've not analyzed all the sequences so deleting the 522 ESC might leave some not-normally-displayed text around. The Carriage Returns, 344121 of them, can be similarly removed. There are some ASCII 8 (decimal) characters in the file as well, 1348 of them. ASCII 9 (decimal), 377 of them. I think that is all the characters that are less than a space in the ASCII encoding. But I use some text editors that are good at dealing with such content (but I do not normally deal with such via the headless or plain console FreeBSD machines). > It can be viewed and searched with more, but the chrome browser > is only willing to download it. Attempts to view it fail with > "invalid byte sequence in conversion input". I'm posting it=20 > anyway because it's a rare event. If you've got any ideas for > cleaning it up so it'll display in a browser please say so. > Script seemed to work fine for the first capture, maybe the > huge size is the issue. Perhaps split would help, but I hope > there's something better. =3D=3D=3D Mark Millard marklmi at yahoo.com