io.Copy Error for closing tunnel

[eleijonmarck]

I am experiencing a bit of error logs from the tunnel implementation.

	// Start the server in the background. You will need to wait a
	// small amount of time for it to bind to the localhost port
	// before you can start sending connections.
	go tunnel.Start()
	defer func() {
		time.Sleep(5 * time.Second)
		tunnel.Close()
	}()

Even if I wait 5 seconds for the tunnel to get any io.Copys out of the way (and I am not creating anything or so) I still get an error of io.Copy

2020/09/22 16:44:33.035361 accepted connection
2020/09/22 16:44:33.035380 listening for new connections...
2020/09/22 16:44:33.076055 connected to 11.11.11.11:22 (1 of 2)
2020/09/22 16:44:33.078677 connected to 22.22.22.22:22 (2 of 2)
2020/09/22 16:44:39.385185 close signal received, closing...
2020/09/22 16:44:39.385195 closing the netConn (1 of 2)
2020/09/22 16:44:39.385304 io.Copy error: read tcp 127.0.0.1:2000->127.0.0.1:40330: use of closed network connection
2020/09/22 16:44:39.385311 closing the netConn (2 of 2)
2020/09/22 16:44:39.385416 closing the serverConn (1 of 1)
2020/09/22 16:44:39.386128 tunnel closed

This is probably the interval workings of the tunnel implementation and closing before closing io.Copy implementations.

[elliotchance]

Can you provide the complete example?

[eleijonmarck]

@elliotchance
I am unable to setup a tunnel locally. Cannot give you a complete working example.

But maybe you could help out in creating a complete example setup w. docker and stuff as I am unable to create a tunnel and sftp locally.

here is the example I can give you. That should be working

https://github.com/eleijonmarck/go-ssh-tunnel

go code specifically:

package main

import (
	"io/ioutil"
	"log"
	"os"
	"time"

	"github.com/elliotchance/sshtunnel"
	"github.com/pkg/sftp"
	"golang.org/x/crypto/ssh"
)

func main() {
	client, err := startTunnel()
	if err != nil {
		log.Printf("errrrrorrr %s", err)
	}
	sftpclient, err := sftp.NewClient(client)
	if err != nil {
		log.Printf("unable to create sftp client with error: %s", err)
	}
	defer sftpclient.Close()

	// check it's there
	fi, err := sftpclient.Lstat("toSEB")
	if err != nil {
		log.Printf("seb upload test failed to upload a file w. error: %s", err)
	}
	log.Printf("fi %v", fi)
}

func startTunnel() (*ssh.Client, error) {
	portForwarded := "2000"
	sftpHostUser := "root"
	// Connection settings
	sftpHostServer := "localhost:2222"
	sftpRemoteServer := "localhost:3333"
	tunnel := sshtunnel.NewSSHTunnel(
		// User and host of tunnel server, it will default to port 22
		// if not specified.
		sftpHostUser+"@"+sftpHostServer,
		// authentication
		// auth, // 1. private key
		ssh.Password("root"), // 1. private key
		// The destination host and port of the actual server.
		sftpRemoteServer,
		// The local port you want to bind the remote port to.
		// Specifying "0" will lead to a random port.
		portForwarded,
	)

	// You can provide a logger for debugging, or remove this line to
	// make it silent.

	tunnel.Log = log.New(os.Stdout, "", log.Ldate|log.Lmicroseconds)
	// Start the server in the background. You will need to wait a
	// small amount of time for it to bind to the localhost port
	// before you can start sending connections.
	go tunnel.Start()

	// known io.Copy error:
	// even if we wait 5 seconds we still get logs of io.Copy error use of closed connection
	defer func() {
		time.Sleep(5 * time.Second)
		tunnel.Close()
	}()

	time.Sleep(100 * time.Millisecond)
	log.Printf("started tunnel")

	log.Printf("tunnel %+v", tunnel)

	sftpHostUser = "docker"
	keyPath := "./ssh_host_payout_staging_rsa_key"
	buff, err := ioutil.ReadFile(keyPath)
	if err != nil {
		log.Printf("unable to read the privatye key %s, w. error: %s", keyPath, err)
	}
	signer, err := ssh.ParsePrivateKey(buff)
	if err != nil {
		log.Printf("unable to parse key")
	}
	auth := ssh.PublicKeys(signer)

	config := &ssh.ClientConfig{
		User: sftpHostUser,
		Auth: []ssh.AuthMethod{
			auth,
		},
		Timeout:         3 * time.Second,
		HostKeyCallback: ssh.InsecureIgnoreHostKey(),
	}
	hostNetwork := "localhost"
	log.Printf("dialing %s:%s", hostNetwork, portForwarded)
	return ssh.Dial("tcp", hostNetwork+":"+portForwarded, config)
}

[elliotchance]

I suspect it's because ou're closing the sshtunnel in a defer from startTunnel. You will need to close the client in a defer in the parent scope:

func main() {
	client, tunnel, err := startTunnel()
	if err != nil {
		log.Printf("errrrrorrr %s", err)
	}
        defer tunnel.Close()

        // ...
}

func startTunnel() (*ssh.Client, *sshtunnel.SSHTunnel, error) {
        go tunnel.Start()

        client, err := ssh.Dial("tcp", hostNetwork+":"+portForwarded, config)
        if err != nil {
                return nil, nil, err
        }
        return client, tunnel, nil
}

[eleijonmarck]

okay that was maybe not representative of the functino I am calling:

func downloadFiles(s *service) error {
	portForwarded := "3333"
	tunnel, err := getTunnel(portForwarded)
	if err != nil {
		return fmt.Errorf("unable to setup tunnel for files: %w", err)
	}

	// Start the server in the background. You will need to wait a
	// small amount of time for it to bind to the localhost port
	// before you can start sending connections.
	go tunnel.Start()
	defer tunnel.Close()
	time.Sleep(100 * time.Millisecond)
	log.Print("tunnel connected")

	// connect to sftp
	sshClient, err := connectSFTP(portForwarded)
	if err != nil {
		return fmt.Errorf("error happened while connecting to SFTP: %w", err)
	}
	err = lookForFile(s, sshClient)
	if err != nil {
		return fmt.Errorf("error happened while downloading files: %w", err)
	}
	return nil
}

// ideally we would download these files first and then parse for the statuses of the files
func lookForFile(s *service, sshClient *ssh.Client) error {
	client, err := sftp.NewClient(sshClient)
	if err != nil {
		return fmt.Errorf("unable to create sftp client with error: %w", err)
	}
	defer client.Close()
}

I am only using the tunnel inside this scope

[elliotchance]

Sorry, I'm not sure what going on. Perhaps there is something that is closing the connection on the other end?

[eleijonmarck]

@elliotchance I have updated the example with the lookForFile function that I am using.

But it is only closing the sftp client that is using the sshClient that is connected to the tunnel.

Maybe I have to reverse the order in which I am closing the connections.

now the defers are in this order when executing

client.Close()
sshClient.Close()
tunnel.Close()