`apt-get`, `dpkg` fails from a bluetooth serial port, but succeed from the physically attached console

Question

On Linux, is there some configuration setting or feature that could explain some commands can work from the system attached console, but not from a serial console?

---

I post here because the remote system is a RaspberryPi, but I don't think the issue is related to that. I suspect it could happen on other Debian (and possibly other Linux) systems.

When I'm logged in to a remote system through Bluetooth serial port, apt-get update, and a couple of package management related commands produce errors:

Raspbian GNU/Linux 9 raspberry pi rfcomm0
raspberrypi login: pi
Password:
Last login: Mon Dec  3 12:31:11 UTC 2018 on rfcomm0
Linux raspberrypi 4.9.59-v7+ #1047 SMP Sun Oct 29 12:19:23 GMT 2017 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
pi@raspberrypi:~$ sudo bash
root@raspberrypi:/home/pi# apt-get update
Hit:1 http://archive.raspbian.org/raspbian stretch InRelease
Err:1 http://archive.raspbian.org/raspbian stretch InRelease
  Waited for apt-key but it wasn't there
Reading package lists... Done
W: An error occurred during the signature verification. The repository is not updated and the previous index files will be used. GPG error: http://archive.raspbian.org/raspbian stretch InRelease: Waited for apt-key but it wasn't there
W: Failed to fetch http://archive.raspbian.org/raspbian/dists/stretch/InRelease  Waited for apt-key but it wasn't there
W: Some index files failed to download. They have been ignored, or old ones used instead.
root@raspberrypi:/home/pi# 

root@raspberrypi:/home/pi# dpkg -i /var/cache/apt/archives/apt-utils_1.4.8_armhf.deb 
dpkg: unrecoverable fatal error, aborting:
 wait for subprocess dpkg-split failed: No child processes

Running the same commands directly on the remote system console produces no error and it works flowlessly. The board is installed with a stock Raspbian system and besides the Bluetooth settings, there was no configuration change.

pi@raspberrypi:~$ who -a
           system boot  1970-01-01 00:00
           run-level 5  2018-12-03 12:29
pi       - tty1         2018-12-03 12:29 00:53         674
pi       - rfcomm0      2018-12-03 13:27   .          1906
pi@raspberrypi:~$ pstree
systemd─┬─avahi-daemon───avahi-daemon
        ├─bluetoothd
        ├─cron
        ├─dbus-daemon
        ├─dhcpcd
        ├─hciattach
        ├─login───bash───sudo───bash   < XXX apt-* works from here
        ├─rfcomm───login───bash        <     but not from here
        ├─rsyslogd─┬─{in:imklog}
        │          ├─{in:imuxsock}
        │          └─{rs:main Q:Reg}
        ├─systemd───(sd-pam)
        ├─systemd-journal
        ├─systemd-logind
        ├─systemd-timesyn───{sd-resolve}
        ├─systemd-udevd
        ├─thd
        └─wpa_supplicant

This is reproducible or other RPi. I didn't had a spare x86 system at hand to test that from a genuine Debian system though.

---

EDIT: This is even crazier: I tried to traceback the issue using strace, but:

# apt-get install -y openssh-server
Reading package lists... Done
Building dependency tree       
Reading state information... Done
The following package was automatically installed and is no longer required:
  libva-wayland1
Use 'apt autoremove' to remove it.
Suggested packages:
  molly-guard monkeysphere rssh ssh-askpass ufw
The following NEW packages will be installed:
  openssh-server
0 upgraded, 1 newly installed, 0 to remove and 114 not upgraded.
Need to get 0 B/301 kB of archives.
After this operation, 833 kB of additional disk space will be used.
E: Waited for /usr/bin/apt-listchanges --apt || test $? -lt 10 but it wasn't there
E: Failure running script /usr/bin/apt-listchanges --apt || test $? -lt 10

# strace apt-get install -y openssh-server
[...]
[long list of system calls]
[...]
munmap(0x74c0d000, 2269184)             = 0
munmap(0x74a56000, 1798144)             = 0
close(3)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

As you can see, running apt-get from strace exits with the status 0 (success) and the package was properly installed. Running "outside" of strace didn't work ?!?

---

The issue defeats all my investigations. I didn't see any clue in /var/log/syslog, /var/log/auth nor in journalctl. I cleaned the APT cache just in case, but the error messages feel spurious and let me think some child processes can't be spawn. I suspect something related to PAM but I can't tell for sure.

Answer 1

I'm using a Raspberry Pi Zero W with Raspbian Stretch. When I do sudo apt-get update while logged in through a Bluetooth serial console, I get those exact same Waited for apt-key but it wasn't there error messages. This was driving me nuts until I found your post above.

Running it under strace works fine for me, just like you. But running apt-get under strace is very unsatisfactory, since strace is very noisy and makes it impossible to read what apt-get is saying.

Using the Bluetooth serial console, I was able to find my Raspberry Pi's WiFi IP address and then ssh into the Raspberry Pi. I was able to do sudo apt-get update successfully through ssh. This is one possible workaround for the problem. ssh localhost also works if you don't want to go through WiFi.

A second workaround is to log into the Raspberry Pi through the Bluetooth serial console and then simply run screen on the Raspberry Pi. Once under screen, I can run sudo apt-get update just fine through the Bluetooth serial console!

I suspected that there is some sort of problem with the terminal emulation, but I'm not sure. When I initially connected to the Raspberry Pi through Bluetooth serial, I didn't get a green colored command prompt like I do once I get under screen or ssh. Something may be wrong with the way we are setting up the Bluetooth rfcomm serial console in the ExecStart= line below:

/etc/systemd/system/rfcomm.service

[Unit]
Description=RFCOMM service
After=bluetooth.service
Requires=bluetooth.service

[Service]
ExecStart=/usr/bin/rfcomm watch hci0 1 setsid /sbin/agetty -8 --noreset -s -w -L rfcomm0 115200 vt100 -a pi

[Install]
WantedBy=multi-user.target

Changing the ExecStart= line to the following gets me a nice green colored command prompt:

ExecStart=/usr/bin/rfcomm watch hci0 1 setsid /sbin/agetty -8 --noclear -s -w -L rfcomm0 115200 linux -a pi

Note that you MUST reboot after changing that file for it to take effect. Doing sudo systemctl reload rfcomm.service didn't seem to be sufficient.

Unfortunately, even though I've got a nice green colored command prompt now, sudo apt-get update still gives me the dreaded Waited for apt-key but it wasn't there error when not running under strace/screen/ssh!

Answer 2

This has something to do with the SIGCHLD signal and how waitpid works while inside the rfcomm setsid getty context. I don't understand POSIX semantics, controlling terminals, and signal handlers enough to get more specific, but I believe the problem could likely be traced to how either rfcomm or setsid are calling fork() / waitpid() and/or (not) handling SIGCHLD.

I came to this conclusion by experimenting with this small program from the S.O. question No Child Process Error from waitpid() when waiting for process group that shows different behavior when run from inside the bluetooth serial terminal (under [rfcomm setsid getty]) where it "breaks" and then from inside [rfcomm setsid getty screen] where it "works."

// cc -o wp wp.c
#include <errno.h>
#include <signal.h>
#include <stdio.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <unistd.h>

int main(int argc, char **argv)
{
    pid_t pid, wpid;
    int stat;

    if ((pid = fork()))
    {
        printf("PARENT: %d | CHILD: %d\n", getpid(), pid);
        wpid = waitpid(-getpid(), &stat, 0);
        printf("DONE: wpid %d errno %d %m\n", wpid, errno);
    }
    else
    {
        printf("CHILD pid: %d\n", getpid());
        sleep(1);
    }
    return 0;
}

The failing results from various commands:

• wp (waitpid test program above)
  • "DONE: wpid -1 errno 10 No child processes"
• crontab -e
  • On exit gets stuck in a loop printing "crontab: waitpid() failed waiting for PID 20864 from "/usr/bin/sensible-editor": No child processes"
• apt-get update
  • "Waited for apt-key but it wasn't there"
• git clone https://git.savannah.gnu.org/git/screen.git
  • "error: waitpid for index-pack failed: No child processes"
  • Interestingly, git clone git://git.savannah.gnu.org/screen works fine.
  • "It works when run under GNU/screen" led me to try and figure out why from screen's source, but nothing jumped out at me

Notes

• After login, if you invoke /bin/dash, then all the commands work fine, similar to how they work under screen, although running /bin/bash or /bin/bash --login doesn't help.
• The waitpid test works when run with the dash "enable job control" argument -m as in: /bin/dash -m -c "~/src/wp/wp"

I'd like to rule out whether or not a "controlling TTY" is involved, since this affects signals and I see that rfcomm uses the O_NOCTTY flag when open()ing /dev/rfcomm0. Experiments with setsid --ctty showed even worse behavior, and I haven't tried changing rfcomm.c source. I'm (re)reading The TTY demystified by Linus Akkeson to try and understand more.

I realize this isn't an answer and that SE is not a forum, but I hope this is helpful to someone and don't have reputation enough to comment.