RPi-zero-w: Iterating previous commands using up/down arrow keys has become very slow and unresponsive

[maartenlangeveld]

RPi-zero-w
Linux M-STREAMER 5.4.51+ #1327 Thu Jul 23 10:53:06 BST 2020 armv6l GNU/Linux

Iterating previous commands in terminal window (xterm, UTF-8) using up/down arrow keys has become very slow and unresponsive since latest firmware updates. It's hardly usable anymore. Would be pleased if fixed.

[popcornmix]

Are you directly connected with a wired keyboard and hdmi display?
If not describe your set up

[maartenlangeveld]

Connected through Wi-Fi. Using Bitvise SSH client on my Win 10 PC to connect to RPi (headless config). Has always worked fine. Have to press arrow key longer before iterating starts which makes harder/impossible to control since a normal press does (most of the time) nothing.

Dropbear SSH server on RPi-zero-w

[popcornmix]

Does iwconfig wlan0 power off make a difference?

[maartenlangeveld]

it is already off... :-)

[MichaIng]

Please check if you're effected by #1431 .

[maartenlangeveld]

@MichaIng

My apologies but I do not understand what you are suggesting. What has my issue to do with #1453 ? What do I need to do to check if I am effected to #1453 ?

[MichaIng]

Whoopsie, hitting return has altered the linked issue, I edited it above: #1431

[maartenlangeveld]

@MichaIng

Indeed I was effected by #1431 as I reported (MichaIng/DietPi#3690) :-)

your suggestion helped:
sed -i 's/^arm_freq_min/#arm_freq_min/' /boot/config.txt

But still wondering what this (might) have to do with stuttering iteration on command line. Curious ...

[MichaIng]

Ah lol sorry, blindly overseen that you were the OP it the issue 🤣. The shuttering/unresponsive behaviour was at least what I recognised as symptom of the (broken) frequency scaling, before the RPi hang completely.

So you're facing this now even after reverting min frequency to defaults 🤔.

Did you try to set scaling governor to performance, so that the RPi runs at full clock and does not scale at all? Change it via dietpi-config > Performance Options > CPU Governor. Alternatively arm_freq_min can be set to maximum clock or force_turbo=1 can be added to /boot/config.txt, the latter only without any overclocking profile i.e. no raised voltage to not void warranty.

But probably we're looking into the wrong direction and it has nothing to do with frequency scaling. Generally observing CPU and RAM usage (htop) and dmesg for kernel errors is a good thing to debug. As well stopping all background services that you don't urgently rely on (temporarily), on DietPi most are handed by dietpi-services stop and recheck SSH/console behaviour.

And of course try to rule out anything related to the SSH client/connection, e.g. using a different client machine+software and e.g. connecting it via cable. I know the Zero W has WiFi only, I man the client.

[maartenlangeveld]

@MichaIng

mesg output= reveals some 'failed', warnings and errors

Do I have to worry or take action to prevent these failures, errors and warning?

root@M-STREAMER:~# dmesg

...
'failed':
[ 2.053299] [vc_sm_connected_init]: start
[ 2.056329] vc_vchi_sm_init: failed to open VCHI service (-1)
[ 2.056343] [vc_sm_connected_init]: failed to initialize shared memory service
[ 2.057190] [vc_sm_connected_init]: end - returning -1
...
[ 10.106245] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[ 10.108602] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[ 10.108625] [vc_sm_connected_init]: start
[ 10.110185] vc_sm_cma_vchi_init: failed to open VCHI service (-1)
[ 10.110199] [vc_sm_connected_init]: failed to initialize shared memory service
[ 10.135147] mc: Linux media interface: v0.10
[ 10.325292] videodev: Linux video capture interface: v2.00
[ 10.443408] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[ 10.466326] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[ 10.573900] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
[ 11.364213] snd-rpi-wm8804 soc: sound: ASoC: failed to init link JustBoom Digi: -517
[ 11.765718] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[ 12.065863] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 12.376273] snd-rpi-wm8804 soc: sound: ASoC: failed to init link JustBoom Digi: -517
[ 12.379895] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
[ 12.413197] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
[ 12.413569] usbcore: registered new interface driver brcmfmac
[ 12.414618] snd-rpi-wm8804 soc: sound: ASoC: failed to init link JustBoom Digi: -517
[ 12.438054] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43430-sdio.raspberrypi,model-zero-w.txt failed with error -2
[ 12.662408] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
[ 12.662574] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
[ 12.663592] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Oct 22 2019 01:59:28 version 7.45.98.94 (r723000 CY) FWID 01-3b33decd
[ 14.633767] wm8804 1-003b: revision E
[ 14.638124] snd-rpi-wm8804 soc: sound: wm8804-spdif <-> 20203000.i2s mapping ok

warning:
[ 16.500879] random: crng init done
[ 16.500902] random: 7 urandom warning(s) missed due to ratelimiting

errors:
[ 5075.515624] bcm2835-i2s 20203000.i2s: I2S SYNC error!
[ 6319.660434] bcm2835-i2s 20203000.i2s: I2S SYNC error!
[ 6421.682871] bcm2835-i2s 20203000.i2s: I2S SYNC error!

[MichaIng]

All the vc_sm errors are expected since you reasonably have gpu_mem set to 16M (<32M) for this headless device. Some GPU features are disabled automatically then (cut-down start_cd.elf) and the video core hence fails to load them. I'm still wondering why the cut down device tree has this even enabled @popcornmix ? It distracts from important errors when reviewing kernel logs.
I use the following device tree overlay to disable vcsm which prevents the errors and I do not see any downside:

2020-08-13 16:05:31 root@micha:/etc# cat /mnt/sda/micha.dts
/dts-v1/;
/plugin/;

/ {
        compatible = "brcm,bcm2835";

        fragment@0 {
                target-path = "/soc/vcsm";
                __overlay__ {
                        status = "disabled";
                };
        };
};

---

You use the JustBoom Digi HAT for sound? First it seems to fail several times, then it finally seems to succeed:

[ 14.638124] snd-rpi-wm8804 soc: sound: wm8804-spdif <-> 20203000.i2s mapping ok

But then much later you get those I2S errors:

[ 5075.515624] bcm2835-i2s 20203000.i2s: I2S SYNC error!

I never used any external sound on my RPi nor do I have experience with I2S, probably it is expected to throw an error by times. However of course you can try to disable the sound card (via dietpi-config or manually remove the dtoverlay from config.txt) and remove the HAT just to be sure it is not related.

---

Then there is something about the onboard WiFi chip:

[ 12.438054] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43430-sdio.raspberrypi,model-zero-w.txt failed with error -2
[ 12.662408] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
[ 12.662574] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
[ 12.663592] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Oct 22 2019 01:59:28 version 7.45.98.94 (r723000 CY) FWID 01-3b33decd

No idea if that is expected either.

[pelwell]

I'm still wondering why the cut down device tree has this even enabled @popcornmix ?

There's no such concept of firmware-variant-specific DTB files. It would be possible to get the firmware to explicitly disable the vchiq node in the loaded DTB, but I would argue that is more confusing in the event that somebody is actually trying to use vchiq.

[pelwell]

[ 5075.515624] bcm2835-i2s 20203000.i2s: I2S SYNC error!

Occasional SYNC errors at the beginning or end of playback are probably nothing to worry about.

[ 12.438054] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43430-sdio.raspberrypi,model-zero-w.txt failed with error -2
[ 12.662408] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
[ 12.662574] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
[ 12.663592] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Oct 22 2019 01:59:28 version 7.45.98.94 (r723000 CY) FWID 01-3b33decd

Those are all to be expected (we don't use board-specific "nvram" .txt files, and the 43438 firmware has a built-in clm_blob.

[MichaIng]

Thanks for clarification. Ah okay I was not sure if those different start(_cd.elf) methods actually (can) manipulate the device tree or not. Disabling vchiq completely is not great since it breaks vcgencmd as well and everything related to it (I played around with this earlier, disabled /soc/mailbox@7e00b840), so I ended up with disabling only the failing part of it.

@maartenlangeveld
Then I suggest you go on with the other steps I mentioned to rule our GPU governor/scheduling completely, installed system services and the SSH client/connection: #1450 (comment)

[maartenlangeveld]

@MichaIng , @pelwell ,

Thanks for your truly great support. I followed the other steps but to no solution so far.

[pelwell]

I'd like to understand exactly what is slow/unresponsive and what isn't. For each of the following, can you describe the responsiveness?

1. Type a sentence.
2. Type a character, wait 10 seconds, type another character.
3. Type a character, holding down the key so that it repeats.
4. Press the "up" cursor key once.
5. Press the "up" cursor key once every second.
6. Press and hold "up" so that it repeats.

For the avoidance of doubt and confusion, the above are all done over SSH via WiFi.

[maartenlangeveld]

I'd like to understand exactly what is slow/unresponsive and what isn't. For each of the following, can you describe the responsiveness?

1. Type a sentence.
   " Just typing some text to see wether the terminal is responsive. And yes it seenms like it is..."

No problems

2. Type a character, wait 10 seconds, type another character.

"A0b;xId" went fine

3. Type a character, holding down the key so that it repeats.

holding down 30s, stutter-free, avg speed almost 30 characters per second (29,3)

4. Press the "up" cursor key once.

no problem, responsive

5. Press the "up" cursor key once every second.

went okay
--> pressing "up" cursor key every 0,5 second: much stuttering: halting for a second or more sometimes to the extent that it won't scroll further

6. Press and hold "up" so that it repeats.

stutters: very 1-3 seconds it pauses for 0,5 to 1 second,

For the avoidance of doubt and confusion, the above are all done over SSH via WiFi.

Yes

[pelwell]

And how is "cat"ing a large text file , e.g. cat /var/log/syslog?

[maartenlangeveld]

I have "cat"a very large text file (> 500 MB), result stutter-free except for very few minor hiccups (< 0,5 second).

[pelwell]

Thanks. I understand the problem better now, but I still have no idea what's going wrong.

[MichaIng]

Hmm, the "up"/"down" button basically query ~/.bash_history, not sure if there is anything else invoked on a different layer.
With the "down" button its the same?
How large is the history file? ls -l ~/.bash_history
And does it change anything when clearing it? mv ~/.bash_history ~/.bash_history_bak or rm ~/.bash_history
Would be still strange since that file for sure is fully loaded into fs memory cache: vmtouch ~/.bash_history

[maartenlangeveld]

"up" and "down" the same

-rw------- 1 root root 24927 Aug 13 20:53 /root/.bash_history

root@M-STREAMER:~# vmtouch ~/.bash_history
           Files: 1
     Directories: 0
  Resident Pages: 7/7  28K/28K  100%
         Elapsed: 0.000787 seconds

rm ~/.bash_history
strange when removed, I can still iterate through my command line history or is a reboot required?

[maartenlangeveld]

after reboot, with very small history:
-rw------- 1 root root 530 Aug 13 21:13 /root/.bash_history

stuttering still occurs.

Seems RPi problem as of lately since no issues with my NanoPi NEO2

[pelwell]

I think it's more likely to be triggered by the pattern of transmits and receives than the fact that you are scrolling through your history.

One option is to capture the network traffic on one or (ideally) both sides. You won't see the data itself because of the encryption, but you should see packet sizes, timing and any retransmission.

$ sudo apt install tshark
# I choose not to enable capture for non-root users
$ sudo tshark -w ssh.pcap port 22 &
# Note - I've not tested this command, but I think it's correct

[maartenlangeveld]

I don't think so since often it won't react to first (since idle time of for example 10 minutes) or following cursur "up" presses whilst typing a character always immediately echoes in terminal.

[maartenlangeveld]

Drives me crazy. It is possible to revert to previous firmware (<5) without reinstalling os and applications ?

[pelwell]

You can revert to the last 4.19 firmware with sudo rpi-update e1050e9. N.B. This is not a recommendation - you use rpi-update at your own risk, and you should make a backup of your SD card before doing so.

[MichaIng]

Since its not pre-installed on DietPi, if you want to test: apt install rpi-update
Generally I'd as well recommend to try going forward instead of backwards, but since no-one has a clue so far, I'd understand.
If you have mood and a SD card left, you could try to flash DietPi freshly and see if the same issue is present and if so, try with the latest Raspberry Pi OS 32-bit image, upgrade APT packages (kernel) and see its present there as well, or the other way round. That way we could narrow it down a bid to either something on your particular system (some software/package/library/corruption/whatever) or something that is wrong with our image.

[maartenlangeveld]

Hi @MichaIng ,

Maybe your suggestion is better way go forward. If I find time I'll will do a fresh install, I'll keep you informed!
Thanks for your great help (as wel as @pelwell ).

[maartenlangeveld]

Hi @MichaIng, @pelwell,

Just finished a complete re-install but stuttering remains. I guess my RPi Zero W is running on its limits.
Again thanks for your great support!

Will close the issue.

[MichaIng]

If it was not an issue pre-5.4, it's probably still reasonable to investigate, e.g. checking if downgrading the kernel solves the issue:

apt install rpi-update
rpi-update e1050e94821a70b2e4c72b318d6c6c968552e9a2

Or we keep it in mind for now in case a similar report is done.

[maartenlangeveld]

When I have time and appetite I will consider to downgrade the kernel on a backup sd card.

Strange is that when in Python3 interpreter, iterating through commands is rather trouble free.

[MichaIng]

Yes of course bash/shell and python are two entirely different applications. Indeed it seems to be related to the way the input/response is transmitted though SSH, testing different clients on different machines is hence another reasonable debug track.