Bug 5062 - ssh doesn't work in sato (dropbear) images
Summary: ssh doesn't work in sato (dropbear) images
Status: VERIFIED FIXED
Alias: None
Product: General Runtime
Classification: Runtime
Component: General Runtime (show other bugs)
Version: 1.5
Hardware: x86 Multiple
: High major
Target Milestone: 1.5 M4
Assignee: Saul Wold
QA Contact:
URL:
Whiteboard:
Depends on:
Blocks:
 
Reported: 2013-08-28 09:24 UTC by Stefan Stanacar
Modified: 2013-10-07 08:25 UTC (History)
5 users (show)

See Also:
OS type for building Yocto: ---
Type of Regression: Regression (Used to work)
Verified:
Documentation change: No (bug/feature does not impact docs)


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Stefan Stanacar 2013-08-28 09:24:26 UTC
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.
Comment 1 Stefan Stanacar 2013-08-28 09:36:44 UTC
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.
Comment 2 Stefan Stanacar 2013-08-28 09:40:37 UTC
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:~#
Comment 3 Stefan Stanacar 2013-08-28 10:25:35 UTC
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.
Comment 4 Stefan Stanacar 2013-08-28 11:17:34 UTC
Reverting commit 36fc237ad7aaf7097698caaa2a19e49731eb1a21 "meta-yocto: change default kernel to 3.10" fixes the problem for the first image at least.
Comment 5 Richard Purdie 2013-08-28 12:25:17 UTC
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?
Comment 6 Bruce Ashfield 2013-08-28 12:41:55 UTC
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.
Comment 7 Tom Zanussi 2013-08-28 13:31:10 UTC
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
Comment 8 Stefan Stanacar 2013-08-28 14:03:45 UTC
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
Comment 9 Tom Zanussi 2013-08-28 14:11:09 UTC
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.
Comment 10 Tom Zanussi 2013-08-28 16:21:36 UTC
(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
Comment 11 Tom Zanussi 2013-08-28 19:09:08 UTC
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.
Comment 12 Tom Zanussi 2013-08-28 19:41:19 UTC
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.
Comment 13 Darren Hart 2013-08-29 14:58:59 UTC
Resolved in master:

8b36aa4 linux-yocto/3.10: fix ssh login and restore CC_OPTIMIZE_FOR_SIZE
Comment 14 Ionut Chisanovici 2013-10-07 08:25:19 UTC
Verified on master:56ea7aca3e6b4a0db3f699cc0d775d267b36e164.