5062 2013-08-28 09:24:26 +0000 ssh doesn't work in sato (dropbear) images 2013-10-07 08:25:19 +0000 1 1 11 Runtime General Runtime General Runtime 1.5 x86 Multiple VERIFIED FIXED High major 1.5 M4 1 sstncr sgw bruce.ashfield dvhart ionutx.chisanovici richard.purdie tom.zanussi --- Regression (Used to work) No (bug/feature does not impact docs) oldest_to_newest 35980 0 sstncr 2013-08-28 09:24:26 +0000 poky commit: 4fd453ef7cd2e7e2b1d72284440dac574603ed27 I can't connect over ssh, either because ssh daemon is not running in the target, or the connection just times out. First image: - qemux86-64 core-image-sato, IMAGE_INSTALL_append = " strace" and the rest is the default local.conf Boot log shows: Starting Dropbear SSH server: Will output 1024 bit rsa secret key to '/etc/dropbear/dropbear_rsa_host_key' Generating key, this may take a while... nf_conntrack version 0.5.0 (911 buckets, 3644 max) Public key portion is: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAAAgnB+54jSGqJIg0Jq04Sk1VuD1Yxwjkl41u5c6/WijQhckTUAB39GUgweksI2H+n7izhBPVeXce+wxH3plP74ZwdkaoWQ0FCXs8luSkfZHSyWYWHcEGV/8BccPYTcOQdy7JOUkhHikBf2Xj8gdMwa8OqE9pZR3VtHTKwtvf7o8Ph2giE= root@qemux86-64 Fingerprint: md5 80:8e:c7:9a:85:4e:d5:69:e3:59:2f:ab:e3:bf:90:9f root@qemux86-64:~# ps | grep [d]ropbear 606 root 10924 S /usr/sbin/dropbear -r /etc/dropbear/dropbear_rsa_hos root@qemux86-64:~# netstat -ant Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State tcp 0 0 0.0.0.0:111 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:3632 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:6000 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:37717 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:53 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:52567 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:58078 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:4224 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:2049 0.0.0.0:* LISTEN tcp 0 0 :::49670 :::* LISTEN tcp 0 0 :::111 :::* LISTEN tcp 0 0 :::6000 :::* LISTEN tcp 0 0 ::1:53 :::* LISTEN tcp 0 0 :::22 :::* LISTEN root@qemux86-64:~# On host: [stefans@firebird build2]$ ssh -vvv -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -l root 192.168.7.4 OpenSSH_6.2p2, OpenSSL 1.0.1e-fips 11 Feb 2013 debug1: Reading configuration data /etc/ssh/ssh_config debug1: /etc/ssh/ssh_config line 50: Applying options for * debug2: ssh_connect: needpriv 0 debug1: Connecting to 192.168.7.4 [192.168.7.4] port 22. debug1: Connection established. debug3: Incorrect RSA1 identifier debug3: Could not load "/home/stefans/.ssh/id_rsa" as a RSA1 public key debug1: identity file /home/stefans/.ssh/id_rsa type 1 debug1: identity file /home/stefans/.ssh/id_rsa-cert type -1 debug1: identity file /home/stefans/.ssh/id_dsa type -1 debug1: identity file /home/stefans/.ssh/id_dsa-cert type -1 debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_6.2 And there it hangs. On target: root@qemux86-64:~# netstat -ant Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State tcp 0 0 0.0.0.0:111 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:3632 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:6000 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:37717 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:53 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:52567 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:58078 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:4224 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:2049 0.0.0.0:* LISTEN tcp 21 0 192.168.7.4:22 192.168.7.3:55532 ESTABLISHED tcp 0 0 :::49670 :::* LISTEN tcp 0 0 :::111 :::* LISTEN tcp 0 0 :::6000 :::* LISTEN tcp 0 0 ::1:53 :::* LISTEN tcp 0 0 :::22 :::* LISTEN Hmm, many years ago I've got bitten by entropy, it does look a bit small: root@qemux86-64:~# cat /proc/sys/kernel/random/entropy_avail 135 (pressing random keys, mosuse in X): root@qemux86-64:~# cat /proc/sys/kernel/random/entropy_avail 402 (ssh still doesn't work) Host: [stefans@firebird build2]$ ps -ef | grep ssh root 1125 1 0 Aug23 ? 00:00:00 /usr/sbin/sshd -D stefans 1621 5606 0 12:20 pts/8 00:00:00 ssh -vvv -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -l root 192.168.7.4 stefans 1718 1624 0 12:21 pts/5 00:00:00 grep --color=auto ssh [stefans@firebird build2]$ strace -p 1621 Process 1621 attached read(3, (an that's all) Target: root@qemux86-64:~# ps | grep [d]ropbear 606 root 10924 R /usr/sbin/dropbear -r /etc/dropbear/dropbear_rsa_hos root@qemux86-64:~# strace -p 606 Process 606 attached select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999984}) read(6, ":\n #0: <ffff880007c0d440>, tick_"..., 2048) = 2048 select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999990}) read(6, "921402 nsecs\n .idle_waketime :"..., 2048) = 2048 select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999987}) read(6, "ime: ktime_get_clocktai\n .off"..., 2048) = 2048 select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999991}) read(6, "230 to 3493761005230 nsecs]\n clo"..., 2048) = 2048 select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999989}) read(6, " hrtimer_start_range_ns, gconfd-"..., 2048) = 2048 select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999991}) read(6, "54 nsecs [in 242192663278 to 242"..., 2048) = 2048 select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999991}) read(6, "\n\ncpu: 0\n clock 0:\n .base: "..., 2048) = 2048 select(7, [6], NULL, NULL, {2, 0}) = 1 (in [6], left {1, 999991}) and it goes on. 35981 1 sstncr 2013-08-28 09:36:44 +0000 Second image: - qemux86-64, core-image-sato, added in local.conf: DISTRO_FEATURES_append = " systemd" VIRTUAL-RUNTIME_init_manager = "systemd" DISTRO_FEATURES_BACKFILL_CONSIDERED = "sysvinit" " root@qemux86-64:~# ps | grep [d]ropbear 136 root 13616 S {dropbear} /bin/sh /etc/init.d/dropbear start 189 root 10924 R dropbearkey -t rsa -f /etc/dropbear/dropbear_rsa_hos root@qemux86-64:~# netstat -ant Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State tcp 0 0 0.0.0.0:6000 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:3632 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:53 0.0.0.0:* LISTEN tcp 0 0 :::6000 :::* LISTEN tcp 0 0 ::1:53 :::* LISTEN So in systemd images it doesn't event generate the key... About 5 minutes later it's still running but systemd probably killed the start script: root@qemux86-64:~# ps | grep [d]ropbear 189 root 10924 R dropbearkey -t rsa -f /etc/dropbear/dropbear_rsa_hos root@qemux86-64:~# systemctl status dropbear.service dropbear.service - LSB: Dropbear Secure Shell server Loaded: loaded (/etc/init.d/dropbear) Active: failed (Result: timeout) since Wed 2013-08-28 09:30:19 UTC; 4min 55s ago Process: 136 ExecStart=/etc/init.d/dropbear start (code=killed, signal=TERM) CGroup: /system.slice/dropbear.service └─189 dropbearkey -t rsa -f /etc/dropbear/dropbear_rsa_host_key Aug 28 09:25:19 qemux86-64 systemd[1]: Starting LSB: Dropbear Secure Shell ..... Aug 28 09:25:49 qemux86-64 dropbear[136]: Starting Dropbear SSH server: Will...' Aug 28 09:25:49 qemux86-64 dropbear[136]: Generating key, this may take a wh.... Aug 28 09:30:19 qemux86-64 systemd[1]: dropbear.service operation timed out...g. Aug 28 09:30:19 qemux86-64 systemd[1]: Failed to start LSB: Dropbear Secure...r. Aug 28 09:30:19 qemux86-64 systemd[1]: Unit dropbear.service entered failed...e. Running manually: root@qemux86-64:~# dropbearkey -t rsa -f test1 Will output 1024 bit rsa secret key to 'test1' Generating key, this may take a while... And it just hangs there... I don't know if the systemd key generation problem is related to the earlier not connecting problem in a sysvinit image. 35982 2 sstncr 2013-08-28 09:40:37 +0000 Important stuff for the first image (one where dropbear started, but connection didn't work): root@qemux86-64:~# ls -l /etc/dropbear/dropbear_rsa_host_key -rw------- 1 root root 427 Aug 28 09:31 /etc/dropbear/dropbear_rsa_host_key root@qemux86-64:~# cat /etc/dropbear/dropbear_rsa_host_key ssh-rsa���ImK[��Ђh"�;��7π1��F+�� ;u8��S���{Hs�,�`CZuZ J��Q0����],8�b���Nm8�7��n6�)1Nm�斾}��_&�b��t ��z��Qz�y \(�y��S�D�L b �yށ$��_ Z��*Z�Z� ����;4 V�X�J�PS���#���F����|�@���j� ���M�?����A���Ss�q�l����77f"�IB��k7��K&@3�QӱB����H&�=J/�6c���B����+@�ӥ�1���� �ke�4�n�C����_�����ڻ�'_�root@qemux86-64:~# 35983 3 sstncr 2013-08-28 10:25:35 +0000 Last known good commit is 44c3f72684c5c920ce8af1da54a2268047342589 Ah, and my earlier comment with the weird chars in /etc/dropbear/dropbear_rsa_host_key, it seems that file looks weird on this good commit too. 35985 4 sstncr 2013-08-28 11:17:34 +0000 Reverting commit 36fc237ad7aaf7097698caaa2a19e49731eb1a21 "meta-yocto: change default kernel to 3.10" fixes the problem for the first image at least. 35986 5 richard.purdie 2013-08-28 12:25:17 +0000 I've added some kernel people to the cc:. This is a release blocker bug :(. So it could be that the 3.10 kernel somehow reduced the available entropy and this is meaning we see these hangs with qemu and ssh as there isn't enough random data for their needs? Kernel people: Was there a change in 3.10 which might have resulted in this behaviour? What can we do? 35987 6 bruce.ashfield 2013-08-28 12:41:55 +0000 Hmmm. There are always a few random/entropy changes in each new kernel release, but nothing that I know of that would cause this. I have all my builds around and will run some tests. 35990 7 tom.zanussi 2013-08-28 13:31:10 +0000 My Fedora host only has entropy of 139 with a 3.3.4 kernel. [root@empanada ~]# uname -a Linux empanada 3.3.4-5.fc17.x86_64 #1 SMP Mon May 7 17:29:34 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux [root@empanada ~]# cat /proc/sys/kernel/random/entropy_avail 139 If you think it's too low entropy, can you try artificially increasing it using rng-tools e.g. HRNGDEVICE=/dev/urandom Run /etc/init.d/rng-tools start 35992 8 sstncr 2013-08-28 14:03:45 +0000 Just adding some more info: - qemux86 core-image-sato doesn't work (just as in the first comment) - qemuarm core-image-sato works just fine - qemux86-64 core-image-sato-sdk (which has openssh instead of dropbear) works (though I still suspect something is weird there when I let it run for some time running a bunch of tests but at least first boot is okay) - qemux86-64 and qemux86 core-image-minimal with IMAGE_FEATURES_append = " ssh-server-dropbear" work just fine - something tells me qemuppc sato has the same issue, based on: http://autobuilder.yoctoproject.org:8011/builders/nightly-ppc/builds/273/steps/Running%20Sanity%20Tests/logs/stdio 35993 9 tom.zanussi 2013-08-28 14:11:09 +0000 Waiting for my x86-64 build to finish, I built and tried 'dropbearkey -t rsa -f test1' on my Fedora 17 box with 3.3.4 kernel and that returned immediately and apparently worked fine. Moving to my Ubuntu 12.04 box with 3.3.2 kernel, same thing, worked fine, but I also had a 3.11-rc7 kernel available there and in that case, dropbearkey also hung as in this report - will try to see if I can narrow it down further, may have to bisect. 36001 10 tom.zanussi 2013-08-28 16:21:36 +0000 (11:18:58 AM) tomz: qemu-x86_64 here uses the 3.10.9 kernel and dropbearkey hangs there too, as does ubuntu 3.10 (11:19:40 AM) tomz: narrowed it down to seedrandom() in genrsa.c of dropbear-2013.58 (11:19:59 AM) tomz: trying 3.9 kernel next 36007 11 tom.zanussi 2013-08-28 19:09:08 +0000 Reverting the following commits fix the problem on x86_64: http://git.yoctoproject.org/cgit/cgit.cgi/linux-yocto-contrib/log/?h=tzanussi/proc_timer_list-revert I'll be looking into a proper fix, but for now the above commits can be reverted to deal with the problem. 36008 12 tom.zanussi 2013-08-28 19:41:19 +0000 This change also fixed the problem seen on Ubuntu with a 3.10 kernel (problem not seen with a 3.9 kernel on the same machine). So the patchset to revert this was sent to linux-yocto - Bruce will probably want to apply the reverts to all branches until it's fixed upstream. 36050 13 dvhart 2013-08-29 14:58:59 +0000 Resolved in master: 8b36aa4 linux-yocto/3.10: fix ssh login and restore CC_OPTIMIZE_FOR_SIZE 37661 14 ionutx.chisanovici 2013-10-07 08:25:19 +0000 Verified on master:56ea7aca3e6b4a0db3f699cc0d775d267b36e164.