Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

scp giving EOF and exit status 1 #8592

Closed
zellyn opened this issue Jul 12, 2023 · 12 comments · Fixed by #8670
Closed

scp giving EOF and exit status 1 #8592

zellyn opened this issue Jul 12, 2023 · 12 comments · Fixed by #8670

Comments

@zellyn
Copy link

zellyn commented Jul 12, 2023

What is the issue?

When using scp, files are transferring correctly, but I'm seeing "EOF" printed, and the exit status is 1.

This seems to be a similar issue to #6054, but I'm using a version of tailscale that should include that fix.

Steps to reproduce

# check versions of stuff
~ ssh zellyn@100.76.94.91 'tailscale --version'
1.44.0
  tailscale commit: 5d008cd8350247adebabd966933e23fe334e9d74
  other commit: 6dac82fa03e9212fb13ce7252dac41745629356a
  go version: go1.20.5-ts40dc4d8
~ ssh zellyn@100.76.94.91 'uname -a'            
Linux lenovo 6.2.0-24-generic #24-Ubuntu SMP PREEMPT_DYNAMIC Fri Jun 16 12:03:50 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
~ ssh zellyn@100.76.94.91 'lsb_release -a'
Distributor ID:	Ubuntu
Description:	Ubuntu 23.04
Release:	23.04
Codename:	lunar

# scp a file: note the "EOF"
~ echo 'hello' > tmp.txt
~ scp tmp.txt zellyn@100.76.94.91:; echo $?
tmp.txt                                                                                                                                                                                                            100%    6     0.5KB/s   00:00    
EOF
1
# Show that it actually transferred
~ ssh zellyn@100.76.94.91 'cat tmp.txt'        
hello
~ ssh zellyn@100.76.94.91 'rm tmp.txt'     

# Let's try that again with a whole lot of v's…
~ scp -vvv tmp.txt zellyn@100.76.94.91:; echo $?
Executing: program /usr/bin/ssh host 100.76.94.91, user zellyn, command sftp
OpenSSH_9.0p1, LibreSSL 3.3.6
debug1: Reading configuration data /Users/zellyn/.ssh/config
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/00-corpnet-consoles depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/00-corpnet-consoles
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/00-general depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/00-general
debug1: /opt/homebrew/opt/square-ssh-config/config.d/00-general line 3: Applying options for *
debug1: /opt/homebrew/opt/square-ssh-config/config.d/00-general line 13: Deprecated option "useroaming"
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-consoles depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-consoles
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-oobfw depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-oobfw
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-ssh depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-ssh
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-vsrx depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/00-neteng-vsrx
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/01-bastions depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/01-bastions
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/03-sjc depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/03-sjc
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/04-builders depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/04-builders
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/05-nrt depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/05-nrt
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/06-iad depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/06-iad
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/07-network-pops depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/07-network-pops
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/08-global depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/08-global
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/09-lab depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/09-lab
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/10-regional depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/10-regional
debug2: checking match for 'host=*.square,*.sqprod.net,*.sjc1,*.sjc1b,*.sjc2b,*.sjc3b,*.iad1,*.iad2b,*.iad3a,*.iad3b,*.nrt1,*.nrt1b,10.*.*.*,*.uswest*.sqcorp.co,*.useast*.sqcorp.co,worker*.ec2.squareup.com,*.hw.oak*.sqcorp.co,*.hw.tor*.sqcorp.co' host 100.76.94.91 originally 100.76.94.91
debug3: /opt/homebrew/opt/square-ssh-config/config.d/10-regional line 9: not matched 'host "100.76.94.91"' 
debug2: match not found
debug2: checking match for 'user "org-49461806" host "github.com"' host 100.76.94.91 originally 100.76.94.91
debug3: /opt/homebrew/opt/square-ssh-config/config.d/10-regional line 13: not matched 'user "zellyn"' 
debug3: /opt/homebrew/opt/square-ssh-config/config.d/10-regional line 13: not matched 'host "100.76.94.91"' 
debug2: match not found
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/11-corp-aws depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/11-corp-aws
debug3: /Users/zellyn/.ssh/config line 2: Including file /opt/homebrew/opt/square-ssh-config/config.d/12-factories depth 0
debug1: Reading configuration data /opt/homebrew/opt/square-ssh-config/config.d/12-factories
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 21: include /etc/ssh/ssh_config.d/* matched no files
debug1: /etc/ssh/ssh_config line 54: Applying options for *
debug1: /etc/ssh/ssh_config line 58: Applying options for *
debug2: resolve_canonicalize: hostname 100.76.94.91 is address
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts' -> '/Users/zellyn/.ssh/known_hosts'
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts2' -> '/Users/zellyn/.ssh/known_hosts2'
debug1: Authenticator provider $SSH_SK_PROVIDER did not resolve; disabling
debug3: ssh_connect_direct: entering
debug1: Connecting to 100.76.94.91 [100.76.94.91] port 22.
debug3: set_sock_tos: set socket 3 IP_TOS 0x48
debug1: Connection established.
debug1: identity file /Users/zellyn/.ssh/id_rsa type -1
debug1: identity file /Users/zellyn/.ssh/id_rsa-cert type -1
debug1: identity file /Users/zellyn/.ssh/id_ecdsa type -1
debug1: identity file /Users/zellyn/.ssh/id_ecdsa-cert type -1
debug1: identity file /Users/zellyn/.ssh/id_ecdsa_sk type -1
debug1: identity file /Users/zellyn/.ssh/id_ecdsa_sk-cert type -1
debug1: identity file /Users/zellyn/.ssh/id_ed25519 type 3
debug1: identity file /Users/zellyn/.ssh/id_ed25519-cert type -1
debug1: identity file /Users/zellyn/.ssh/id_ed25519_sk type -1
debug1: identity file /Users/zellyn/.ssh/id_ed25519_sk-cert type -1
debug1: identity file /Users/zellyn/.ssh/id_xmss type -1
debug1: identity file /Users/zellyn/.ssh/id_xmss-cert type -1
debug1: identity file /Users/zellyn/.ssh/id_dsa type -1
debug1: identity file /Users/zellyn/.ssh/id_dsa-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_9.0
debug1: Remote protocol version 2.0, remote software version Tailscale
debug1: compat_banner: no match: Tailscale
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to 100.76.94.91:22 as 'zellyn'
debug3: record_hostkey: found key type ED25519 in file /Users/zellyn/.ssh/known_hosts:4
debug3: load_hostkeys_file: loaded 1 keys from 100.76.94.91
debug1: load_hostkeys: fopen /Users/zellyn/.ssh/known_hosts2: No such file or directory
debug3: record_hostkey: found ca key type RSA in file /etc/ssh/ssh_known_hosts:2
debug3: record_hostkey: found ca key type RSA in file /etc/ssh/ssh_known_hosts:3
debug3: record_hostkey: found ca key type RSA in file /etc/ssh/ssh_known_hosts:4
debug3: load_hostkeys_file: loaded 3 keys from 100.76.94.91
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug3: order_hostkeyalgs: have matching best-preference key type ssh-ed25519-cert-v01@openssh.com, using HostkeyAlgorithms verbatim
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms: sntrup761x25519-sha512@openssh.com,curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,ext-info-c
debug2: host key algorithms: ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,rsa-sha2-512,rsa-sha2-256
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib@openssh.com,zlib
debug2: compression stoc: none,zlib@openssh.com,zlib
debug2: languages ctos: 
debug2: languages stoc: 
debug2: first_kex_follows 0 
debug2: reserved 0 
debug2: peer server KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1
debug2: host key algorithms: rsa-sha2-256,rsa-sha2-512,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519
debug2: ciphers ctos: aes128-gcm@openssh.com,chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr
debug2: ciphers stoc: aes128-gcm@openssh.com,chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr
debug2: MACs ctos: hmac-sha2-256-etm@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha1-96
debug2: MACs stoc: hmac-sha2-256-etm@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha1-96
debug2: compression ctos: none
debug2: compression stoc: none
debug2: languages ctos: 
debug2: languages stoc: 
debug2: first_kex_follows 0 
debug2: reserved 0 
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: SSH2_MSG_KEX_ECDH_REPLY received
debug1: Server host key: ssh-ed25519 SHA256:VUwK4Qvv/6tPvgraIMn9IsNjpfFuRop4dDwsUI0PR2A
debug3: record_hostkey: found key type ED25519 in file /Users/zellyn/.ssh/known_hosts:4
debug3: load_hostkeys_file: loaded 1 keys from 100.76.94.91
debug1: load_hostkeys: fopen /Users/zellyn/.ssh/known_hosts2: No such file or directory
debug3: record_hostkey: found ca key type RSA in file /etc/ssh/ssh_known_hosts:2
debug3: record_hostkey: found ca key type RSA in file /etc/ssh/ssh_known_hosts:3
debug3: record_hostkey: found ca key type RSA in file /etc/ssh/ssh_known_hosts:4
debug3: load_hostkeys_file: loaded 3 keys from 100.76.94.91
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug1: Host '100.76.94.91' is known and matches the ED25519 host key.
debug1: Found key in /Users/zellyn/.ssh/known_hosts:4
debug3: send packet: type 21
debug2: ssh_set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: receive packet: type 21
debug1: SSH2_MSG_NEWKEYS received
debug2: ssh_set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug1: get_agent_identities: bound agent to hostkey
debug1: get_agent_identities: agent returned 1 keys
debug1: Will attempt key: /Users/zellyn/.ssh/id_ed25519 ED25519 SHA256:W/fnWz0C3r+wg3RNNCiFA8jW+amYSboMW68puvssCmg agent
debug1: Will attempt key: /Users/zellyn/.ssh/id_rsa 
debug1: Will attempt key: /Users/zellyn/.ssh/id_ecdsa 
debug1: Will attempt key: /Users/zellyn/.ssh/id_ecdsa_sk 
debug1: Will attempt key: /Users/zellyn/.ssh/id_ed25519_sk 
debug1: Will attempt key: /Users/zellyn/.ssh/id_xmss 
debug1: Will attempt key: /Users/zellyn/.ssh/id_dsa 
debug2: pubkey_prepare: done
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,rsa-sha2-256,rsa-sha2-512,ssh-rsa,ssh-dss>
debug3: receive packet: type 6
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
debug3: receive packet: type 52
Authenticated to 100.76.94.91 ([100.76.94.91]:22) using "none".
debug2: fd 4 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Entering interactive session.
debug1: pledge: filesystem
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: fd 3 setting TCP_NODELAY
debug3: set_sock_tos: set socket 3 IP_TOS 0x20
debug2: client_session2_setup: id 0
debug1: Sending environment.
debug3: Ignored env TERM_PROGRAM
debug3: Ignored env SHELL
debug3: Ignored env TERM
debug3: Ignored env TMPDIR
debug3: Ignored env TERM_PROGRAM_VERSION
debug3: Ignored env TERM_SESSION_ID
debug3: Ignored env USER
debug3: Ignored env SSH_AUTH_SOCK
debug3: Ignored env PATH
debug3: Ignored env LaunchInstanceID
debug3: Ignored env __CFBundleIdentifier
debug3: Ignored env PWD
debug3: Ignored env XPC_FLAGS
debug3: Ignored env XPC_SERVICE_NAME
debug3: Ignored env SHLVL
debug3: Ignored env HOME
debug3: Ignored env LOGNAME
debug3: Ignored env BEYOND_AUTH_SOCK
debug3: Ignored env SECURITYSESSIONID
debug3: Ignored env BEYOND_CORP_TUNNEL
debug3: Ignored env OLDPWD
debug3: Ignored env HOMEBREW_PREFIX
debug3: Ignored env HOMEBREW_CELLAR
debug3: Ignored env HOMEBREW_REPOSITORY
debug3: Ignored env MANPATH
debug3: Ignored env INFOPATH
debug3: Ignored env SQUARE_HOME
debug3: Ignored env ENVOY_HTTP_EGRESS_SOCKET_PATH
debug3: Ignored env GOPATH
debug3: Ignored env GOPRIVATE
debug3: Ignored env GOFETCH_ALIASES
debug3: Ignored env JAVA_HOME
debug3: Ignored env JRUBY_OPTS
debug3: Ignored env MAVEN_OPTS
debug3: Ignored env NODE_OPTIONS
debug3: Ignored env RANGE_HOST
debug3: Ignored env RANGE_PORT
debug3: Ignored env RANGE_SSL
debug3: Ignored env RUBY_GC_HEAP_INIT_SLOTS
debug3: Ignored env RUBY_GC_MALLOC_LIMIT
debug3: Ignored env HOMEBREW_NO_ANALYTICS
debug3: Ignored env CPATH
debug3: Ignored env LIBRARY_PATH
debug3: Ignored env CLICOLOR
debug3: Ignored env PR_RED
debug3: Ignored env PR_GREEN
debug3: Ignored env PR_YELLOW
debug3: Ignored env PR_BLUE
debug3: Ignored env PR_WHITE
debug3: Ignored env PR_BLACK
debug3: Ignored env PR_MAGENTA
debug3: Ignored env PR_CYAN
debug3: Ignored env PR_BOLD_RED
debug3: Ignored env PR_BOLD_GREEN
debug3: Ignored env PR_BOLD_YELLOW
debug3: Ignored env PR_BOLD_BLUE
debug3: Ignored env PR_BOLD_WHITE
debug3: Ignored env PR_BOLD_BLACK
debug3: Ignored env PR_BOLD_MAGENTA
debug3: Ignored env PR_BOLD_CYAN
debug3: Ignored env LSCOLORS
debug3: Ignored env GREP_OPTIONS
debug3: Ignored env GIT_PS1_SHOWDIRTYSTATE
debug3: Ignored env HISTFILE
debug3: Ignored env HISTSIZE
debug3: Ignored env SAVEHIST
debug3: Ignored env rvm_prefix
debug3: Ignored env rvm_path
debug3: Ignored env rvm_bin_path
debug3: Ignored env rvm_version
debug3: Ignored env GEM_HOME
debug3: Ignored env GEM_PATH
debug3: Ignored env MY_RUBY_HOME
debug3: Ignored env IRBRC
debug3: Ignored env RUBY_VERSION
debug3: Ignored env HOMEBREW_GITHUB_API_TOKEN
debug3: Ignored env EDITOR
debug3: Ignored env HERMIT_BIN_CHANGE
debug3: Ignored env PS1
debug3: Ignored env rvm_alias_expanded
debug3: Ignored env rvm_bin_flag
debug3: Ignored env rvm_docs_type
debug3: Ignored env rvm_gemstone_package_file
debug3: Ignored env rvm_gemstone_url
debug3: Ignored env rvm_niceness
debug3: Ignored env rvm_nightly_flag
debug3: Ignored env rvm_only_path_flag
debug3: Ignored env rvm_pretty_print_flag
debug3: Ignored env rvm_proxy
debug3: Ignored env rvm_quiet_flag
debug3: Ignored env rvm_ruby_bits
debug3: Ignored env rvm_ruby_file
debug3: Ignored env rvm_ruby_make
debug3: Ignored env rvm_ruby_make_install
debug3: Ignored env rvm_ruby_mode
debug3: Ignored env rvm_script_name
debug3: Ignored env rvm_sdk
debug3: Ignored env rvm_silent_flag
debug3: Ignored env rvm_use_flag
debug3: Ignored env rvm_hook
debug1: channel 0: setting env LANG = "en_US.UTF-8"
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env _
debug3: Ignored env __CF_USER_TEXT_ENCODING
debug1: Sending subsystem: sftp
debug2: channel 0: request subsystem confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 2097152 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: subsystem request accepted on channel 0
debug2: channel 0: rcvd adjust 9
scp: debug2: Remote version: 3
scp: debug2: Server supports extension "hardlink@openssh.com" revision 1
scp: debug2: Server supports extension "posix-rename@openssh.com" revision 1
scp: debug2: Server supports extension "statvfs@openssh.com" revision 2
scp: debug2: Sending SSH2_FXP_STAT "."
scp: debug3: Sent message fd 7 T:17 I:1
debug2: channel 0: rcvd adjust 14
scp: debug3: Received stat reply T:105 I:1 F:0x000f M:40755
scp: debug3: source_sftp: copying local tmp.txt to remote ./tmp.txt
scp: debug2: do_upload: upload local "tmp.txt" to remote "./tmp.txt"
scp: debug2: Sending SSH2_FXP_OPEN "./tmp.txt"
scp: debug3: Sent dest message SSH2_FXP_OPEN I:2 P:./tmp.txt M:0x001a
debug2: channel 0: rcvd adjust 34
tmp.txt                                                                                                                                                                                                              0%    0     0.0KB/s   --:-- ETAscp: debug3: Sent message SSH2_FXP_WRITE I:4 O:0 S:6
debug2: channel 0: rcvd adjust 32
scp: debug3: SSH2_FXP_STATUS 0
scp: debug3: In write loop, ack for 4 6 bytes at 0
tmp.txt                                                                                                                                                                                                            100%    6     1.3KB/s   00:00    
scp: debug3: Sent message SSH2_FXP_CLOSE I:3
debug2: channel 0: rcvd adjust 14
scp: debug3: SSH2_FXP_STATUS 0
debug2: channel 0: read failed rfd 4 maxlen 32768: Broken pipe
debug2: channel 0: read failed
debug2: chan_shutdown_read: channel 0: (i0 o0 sock -1 wfd 4 efd 6 [write])
debug2: channel 0: input open -> drain
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug2: channel 0: rcvd ext data 4
EOF
debug2: channel 0: written 4 to efd 6
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: chan_shutdown_write: channel 0: (i3 o1 sock -1 wfd 5 efd 6 [write])
debug2: channel 0: output drain -> closed
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug3: send packet: type 97
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/6 sock -1 cc -1 io 0x00/0x00)

debug3: send packet: type 1
Transferred: sent 1924, received 1628 bytes, in 0.1 seconds
Bytes per second: sent 21210.0, received 17946.9
debug1: Exit status 1
1
~ 

Are there any recent changes that introduced the issue?

No response

OS

Linux, macOS

OS version

MacOS 13.4.1, Ubuntu lunar

Tailscale version

1.44.0

Other software

No response

Bug report

BUG-81de7171c9e0067342e4f496695f36375a66716b746a105ef7adbc1a3cb0677f-20230712125627Z-e136de65bfae2555

@zellyn
Copy link
Author

zellyn commented Jul 12, 2023

Addendum: this is not happening when using scp from another of my linux boxes to the same host:

~ ssh 100.95.60.80
Welcome to Ubuntu 22.04.1 LTS (GNU/Linux 5.15.0-75-generic x86_64)
…snip…
Last login: Wed Jul 12 12:57:39 UTC 2023 from 100.96.52.10 on pts/2
zellyn@hp:~$ echo 'hello' > tmp.txt
zellyn@hp:~$ scp tmp.txt zellyn@100.76.94.91:; echo $?
tmp.txt                                                                                                                                                                                                            100%    6     2.9KB/s   00:00    
0
zellyn@hp:~$ ```

@bradfitz
Copy link
Member

Wasn't this just fixed recently, @maisem @dsnet?

@DentonGentry
Copy link
Contributor

#8405 looks similar and went in after 1.44.0 was released. It would be in the current https://pkgs.tailscale.com/unstable/ build.

@dsnet
Copy link
Member

dsnet commented Jul 12, 2023

Hey @zellyn, thanks for the report! The bug does look awfully suspicious to what's fixed by #8405, which faces a race condition in the non-pty code path (which apparently scp uses).

@creachadair
Copy link
Member

I believe this symptom occurred when scp runs in the "new style" mode (in which it is a wrapper around an sftp session), and I was able to work around it using scp -O to get the "original style" in which it uses the normal pty/tty connection. (Hopefully it shouldn't matter once that fix is released anyway—but it may help in the short term as a workaround)

@zellyn
Copy link
Author

zellyn commented Jul 19, 2023

Unfortunately, this is still broken in 1.44.2 😞

@DentonGentry
Copy link
Contributor

It was not expected to be fixed in 1.44.2, the fix is expected in 1.46.0.

@zellyn
Copy link
Author

zellyn commented Jul 20, 2023

Still broken with 1.46.0 😞

@zellyn
Copy link
Author

zellyn commented Jul 20, 2023

In case it helps…

~ ssh zellyn@100.76.94.91 'tailscale --version'
1.46.0
  tailscale commit: 03b5aa8b4d846b67e5f6e14543f5e8fd25ff259d
  other commit: ea91237a35098bf2e10af36cddde53bb96e7ad3c
  go version: go1.21rc3
~ scp tmp.txt zellyn@100.76.94.91:; echo $?   
tmp.txt                        100%   13     0.4KB/s   00:00    
EOF
1
~ scp -O tmp.txt zellyn@100.76.94.91:; echo $? 
tmp.txt                        100%   13     0.6KB/s   00:00    
0
~ system_profiler SPSoftwareDataType SPHardwareDataType | grep -v ID | grep -v Serial
Software:

    System Software Overview:

      System Version: macOS 13.4.1 (c) (22F770820d)
      Kernel Version: Darwin 22.5.0
      Boot Volume: Macintosh HD
      Boot Mode: Normal
      Computer Name: zellyn-macbookpro
      User Name: Zellyn Hunter (zellyn)
      Secure Virtual Memory: Enabled
      System Integrity Protection: Enabled
      Time since boot: 6 days, 2 hours, 17 minutes

Hardware:

    Hardware Overview:

      Model Name: MacBook Pro
      Model Identifier: MacBookPro18,2
      Model Number: Z14Z0010BLL/A
      Chip: Apple M1 Max
      Total Number of Cores: 10 (8 performance and 2 efficiency)
      Memory: 64 GB
      System Firmware Version: 8422.121.1
      OS Loader Version: 8422.121.1
      Activation Lock Status: Disabled

~ ssh -V
OpenSSH_9.0p1, LibreSSL 3.3.6
~ 

@dsnet
Copy link
Member

dsnet commented Jul 21, 2023

Alright, I'm able to reproduce on v1.46, but I had to do:

scp -s tmp.txt carbonite.digitalstatic.ts.net:/tmp/; echo $?
tmp.txt                                                                     100%    6     7.6KB/s   00:00    
EOF
1

where the -s specifies the use of SFTP. I guess scp variants are inconsistent on which protocol they use by default.

dsnet added a commit that referenced this issue Jul 21, 2023
If the connection provided to sftp.NewServer is closed,
Serve returns the io.EOF error verbatim from io.Reader.Read.
This is an odd error since this is an expected situation,
so we manually ignore io.EOF.
This is somewhat buggy since the sftp package itself
incorrectly reports io.EOF in cases where it should actually
be reporting io.ErrUnexpectedEOF.
See pkg/sftp#554 which patches Serve to
return nil on clean closes and fixes buggy uses of io.ReadFull.

Fixes #8592

Signed-off-by: Joe Tsai <joetsai@digital-static.net>
@creachadair
Copy link
Member

I guess scp variants are inconsistent on which protocol they use by default.

Yes. For OpenSSH specifically (which covers the majority of SSH deployments at this point), there was a switch of the default at some relatively recent version.

bradfitz pushed a commit that referenced this issue Jul 21, 2023
If the connection provided to sftp.NewServer is closed,
Serve returns the io.EOF error verbatim from io.Reader.Read.
This is an odd error since this is an expected situation,
so we manually ignore io.EOF.
This is somewhat buggy since the sftp package itself
incorrectly reports io.EOF in cases where it should actually
be reporting io.ErrUnexpectedEOF.
See pkg/sftp#554 which patches Serve to
return nil on clean closes and fixes buggy uses of io.ReadFull.

Fixes #8592

Signed-off-by: Joe Tsai <joetsai@digital-static.net>
bradfitz pushed a commit that referenced this issue Jul 21, 2023
If the connection provided to sftp.NewServer is closed,
Serve returns the io.EOF error verbatim from io.Reader.Read.
This is an odd error since this is an expected situation,
so we manually ignore io.EOF.
This is somewhat buggy since the sftp package itself
incorrectly reports io.EOF in cases where it should actually
be reporting io.ErrUnexpectedEOF.
See pkg/sftp#554 which patches Serve to
return nil on clean closes and fixes buggy uses of io.ReadFull.

Fixes #8592

Signed-off-by: Joe Tsai <joetsai@digital-static.net>
(cherry picked from commit bb4b35e)
DentonGentry pushed a commit that referenced this issue Jul 22, 2023
If the connection provided to sftp.NewServer is closed,
Serve returns the io.EOF error verbatim from io.Reader.Read.
This is an odd error since this is an expected situation,
so we manually ignore io.EOF.
This is somewhat buggy since the sftp package itself
incorrectly reports io.EOF in cases where it should actually
be reporting io.ErrUnexpectedEOF.
See pkg/sftp#554 which patches Serve to
return nil on clean closes and fixes buggy uses of io.ReadFull.

Fixes #8592

Signed-off-by: Joe Tsai <joetsai@digital-static.net>
(cherry picked from commit bb4b35e)
@zellyn
Copy link
Author

zellyn commented Jul 27, 2023

Confirmed fixed in 1.46.1. Thanks!

alexelisenko pushed a commit to Control-D-Inc/tailscale that referenced this issue Feb 15, 2024
If the connection provided to sftp.NewServer is closed,
Serve returns the io.EOF error verbatim from io.Reader.Read.
This is an odd error since this is an expected situation,
so we manually ignore io.EOF.
This is somewhat buggy since the sftp package itself
incorrectly reports io.EOF in cases where it should actually
be reporting io.ErrUnexpectedEOF.
See pkg/sftp#554 which patches Serve to
return nil on clean closes and fixes buggy uses of io.ReadFull.

Fixes tailscale#8592

Signed-off-by: Joe Tsai <joetsai@digital-static.net>
Signed-off-by: Alex Paguis <alex@windscribe.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants