Re: Progress on 'guix deploy'

[Jakob L. Kreuze]

address@hidden (Jakob L. Kreuze) writes:

> Very unusal. I'm wondering if it's caused by my use of
> 'call-with-connected-session/auth' from (gnu tests ssh) rather than
> 'open-ssh-session' in (guix ssh). That's the main difference between
> the test suite and 'guix deploy' in terms of how they communicate with
> the guest.

The "[w]e need lightweight compression when exchanging full archives"
comment in (guix ssh) gave me a little bit of hope that the issue could
be solved by addressing the difference in how SSH sessions were being
opened, but I've ensured that they're opened with the same parameters
and still run into this seemingly nondeterministic behavior. Well, I
suppose it's deterministic in the sense that it always fails when run
from the test suite, and always works when run from 'guix deploy' ;)

Running both with `#:log-verbosity 'protocol` yields essentially the
same output, aside from the authentication method.

#+BEGIN_SRC
diff -u /home/jakob/ssh-clean-2 /home/jakob/ssh-clean-1
--- /home/jakob/ssh-clean-2     2019-06-12 12:25:33.856336431 -0400
+++ /home/jakob/ssh-clean-1     2019-06-12 12:25:03.056337396 -0400
@@ -1,5 +1,9 @@
+1] ssh_config_parse_line: Unsupported option: IdentitiesOnly, line: 4
+1] ssh_config_parse_line: Unsupported option: IdentitiesOnly, line: 9
+1] ssh_config_parse_line: Unsupported option: IdentitiesOnly, line: 14
+1] ssh_config_parse_line: Unsupported option: IdentitiesOnly, line: 19
 2] ssh_connect: libssh 0.8.7 (c) 2003-2018 Aris Adamantiadis, Andreas 
Schneider and libssh contributors. Distributed under the LGPL, please refer to 
COPYING file for information about your rights, using threading threads_pthread
-2] ssh_socket_connect: Nonblocking connection socket: 11
+2] ssh_socket_connect: Nonblocking connection socket: 16
 2] ssh_connect: Socket connecting, now waiting for the callbacks to work
 1] socket_callback_connected: Socket connection callback: 1 (0)
 1] ssh_client_connection_callback: SSH server banner: SSH-2.0-OpenSSH_8.0
@@ -11,16 +15,34 @@
 2] ssh_client_curve25519_reply: SSH_MSG_NEWKEYS sent
 2] ssh_packet_newkeys: Received SSH_MSG_NEWKEYS
 2] ssh_packet_newkeys: Signature verified and valid
+2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false
+2] ssh_pki_openssh_import: Opening OpenSSH private key: ciphername: none, kdf: 
none, nkeys: 1
+2] ssh_userauth_publickey_auto: Successfully authenticated using 
/home/jakob/.ssh/guixsd_slave
 2] channel_open: Creating a channel 43 with 64000 window and 32768 max packet
 2] ssh_packet_global_request: Received SSH_MSG_GLOBAL_REQUEST packet
 2] ssh_packet_global_request: UNKNOWN SSH_MSG_GLOBAL_REQUEST address@hidden 0
 1] ssh_packet_process: Couldn't do anything with packet type 80
+2] ssh_packet_ignore_callback: Received SSH_MSG_DEBUG packet
+2] ssh_packet_ignore_callback: Received SSH_MSG_DEBUG packet
 2] ssh_packet_channel_open_conf: Received a CHANNEL_OPEN_CONFIRMATION for 
channel 43:0
 2] ssh_packet_channel_open_conf: Remote window : 0, maxpacket : 32768
 2] channel_rcv_change_window: Adding 2097152 bytes to channel (43:0) (from 0 
bytes)
 2] channel_request: Channel request exec success
 2] grow_window: growing window (channel 43:0) to 1280000 bytes
 2] channel_open: Creating a channel 44 with 64000 window and 32768 max packet
-1] ssh_socket_exception_callback: Socket exception callback: 2 (-1)
-1] ssh_socket_exception_callback: Socket error: Unknown error -1
-0] channel-open-session: [GSSH ERROR] Socket error: Unknown error -1: 
#<input-output: channel (closed) 6c024c0>
+2] ssh_packet_channel_open_conf: Received a CHANNEL_OPEN_CONFIRMATION for 
channel 44:1
+2] ssh_packet_channel_open_conf: Remote window : 0, maxpacket : 32768
+2] channel_rcv_change_window: Adding 2097152 bytes to channel (44:1) (from 0 
bytes)
+2] channel_request: Channel request exec success
+2] grow_window: growing window (channel 44:1) to 1280000 bytes
+2] channel_rcv_change_window: Adding 112751 bytes to channel (44:1) (from 
1939345 bytes)
+2] channel_rcv_change_window: Adding 96256 bytes to channel (44:1) (from 
1961984 bytes)
+2] channel_rcv_change_window: Adding 4096 bytes to channel (44:1) (from 
1913495 bytes)
+2] channel_rcv_change_window: Adding 65536 bytes to channel (44:1) (from 
1917591 bytes)
+2] channel_rcv_change_window: Adding 65536 bytes to channel (44:1) (from 
1983127 bytes)
+2] channel_open: Creating a channel 45 with 64000 window and 32768 max packet
+2] ssh_packet_channel_open_conf: Received a CHANNEL_OPEN_CONFIRMATION for 
channel 45:1
+2] ssh_packet_channel_open_conf: Remote window : 0, maxpacket : 32768
+2] channel_rcv_change_window: Adding 2097152 bytes to channel (45:1) (from 0 
bytes)
+2] channel_request: Channel request exec success
+2] channel_rcv_change_window: Adding 129520 bytes to channel (45:1) (from 
1902096 bytes)

...

Diff finished.  Wed Jun 12 12:25:42 2019
#+END_SRC

signature.asc
Description: PGP signature