search

pkg / sftp

SFTP support for the go.crypto/ssh package
BSD 2-Clause "Simplified" License
1.52k stars 380 forks source link

UseConcurrentWrites copies 0 bytes on windows when using io.Copy #433

Closed lespea closed 3 years ago

lespea commented 3 years ago

So this is a strange one and I'm not sure what to do next to help debug... but here's what I've found so far:

Disabling useConcurrentWrites and all methods work as expected. No errors are ever returned during any copy.

Tested using 32bit go 1.16.3 and go 1.15.8, and 64 bit 1.16.3

drakkan commented 3 years ago

Hi,

can you please share a small program to reproduce the issue? thank you

lespea commented 3 years ago

Okay here is a sample program that demonstrates the issue. I tried for a while to get a server setup but ran into issues so you'll just have to fill out the Dest/User (optional KeyPass) with values to a real ssh server that the key has access to.

package main

import (
    "bufio"
    "github.com/pkg/sftp"
    "golang.org/x/crypto/ssh"
    "io"
    "io/ioutil"
    "log"
    "net"
    "os"
)

const (
    Dest     = ""
    User     = ""
    KeyPass  = ""
    KeyPath  = "testKey"
    TestFile = "main.go"
    NoPanics = true
)

type ReadType uint8

const (
    CopyFile ReadType = iota
    CopyBuf
    RawWrite
)

func (rt ReadType) String() string {
    switch rt {
    case CopyFile:
        return "CopyFile"
    case CopyBuf:
        return "CopyBuf"
    case RawWrite:
        return "RawWrite"
    default:
        log.Panicf("Invalid ReadType: %d", rt)
    }
    return ""
}

func cez64(n int64, err error) {
    ce(err)
    if n <= 0 {
        log.Panic("got 0 bytes but expected > 0")
    }
}

func cez(n int, err error) {
    ce(err)
    if n <= 0 {
        log.Panic("got 0 bytes but expected > 0")
    }
}

func ce(err error) {
    if err != nil {
        panic(err)
    }
}

func cef(f func() error) {
    ce(f())
}

func getConf() *ssh.ClientConfig {
    keyBytes, err := ioutil.ReadFile(KeyPath)
    ce(err)

    var signer ssh.Signer
    if KeyPass != "" {
        if signer, err = ssh.ParsePrivateKeyWithPassphrase(keyBytes, []byte(KeyPass)); err != nil {
            panic(err)
        }
    } else {
        if signer, err = ssh.ParsePrivateKey(keyBytes); err != nil {
            panic(err)
        }
    }

    return &ssh.ClientConfig{
        User: User,
        Auth: []ssh.AuthMethod{ssh.PublicKeys(signer)},
        HostKeyCallback: func(hostname string, remote net.Addr, key ssh.PublicKey) error {
            return nil
        },
    }
}

func getClient() *ssh.Client {
    if client, err := ssh.Dial(
        "tcp",
        Dest,
        getConf(),
    ); err != nil {
        panic(err)
    } else {
        return client
    }
}

func send(conn *ssh.Client, useConcurrent bool, bufWrites bool, readType ReadType) {
    if NoPanics {
        defer func() {
            if r := recover(); r != nil {
                log.Printf("RECOVERY: %+v", r)
            }
        }()
    }

    log.Printf("Testing conc=%v; bufWrite=%v; readType=%s", useConcurrent, bufWrites, readType.String())

    client, err := sftp.NewClient(conn, sftp.UseConcurrentWrites(useConcurrent))
    ce(err)
    defer cef(client.Close)

    if f, err := client.Create(TestFile); err != nil {
        panic(err)
    } else {
        defer cef(f.Close)

        var fw io.Writer
        if bufWrites {
            b := bufio.NewWriter(f)
            defer cef(b.Flush)
            fw = b
        } else {
            fw = f
        }

        switch readType {
        case CopyFile:
            in, err := os.Open(TestFile)
            ce(err)
            cez64(io.Copy(fw, in))

        case CopyBuf:
            in, err := os.Open(TestFile)
            ce(err)
            cez64(io.Copy(fw, bufio.NewReader(in)))

        case RawWrite:
            b, err := ioutil.ReadFile(TestFile)
            ce(err)
            cez(fw.Write(b))

        default:
            panic("Bad read type given")
        }
    }
}

func main() {
    client := getClient()
    defer cef(client.Close)

    bools := []bool{true, false}
    for _, conc := range bools {
        for _, bufW := range bools {
            for _, rt := range []ReadType{CopyFile, CopyBuf, RawWrite} {
                send(client, conc, bufW, rt)
            }
        }
    }
}

Windows output:

2021/04/22 14:08:16 Testing conc=true; bufWrite=true; readType=CopyFile
2021/04/22 14:08:17 got 0 bytes but expected > 0
2021/04/22 14:08:17 RECOVERY: got 0 bytes but expected > 0

2021/04/22 14:08:17 Testing conc=true; bufWrite=true; readType=CopyBuf
2021/04/22 14:08:17 got 0 bytes but expected > 0
2021/04/22 14:08:18 RECOVERY: got 0 bytes but expected > 0

2021/04/22 14:08:18 Testing conc=true; bufWrite=true; readType=RawWrite

2021/04/22 14:08:18 Testing conc=true; bufWrite=false; readType=CopyFile
2021/04/22 14:08:19 got 0 bytes but expected > 0
2021/04/22 14:08:19 RECOVERY: got 0 bytes but expected > 0

2021/04/22 14:08:19 Testing conc=true; bufWrite=false; readType=CopyBuf
2021/04/22 14:08:19 got 0 bytes but expected > 0
2021/04/22 14:08:20 RECOVERY: got 0 bytes but expected > 0

2021/04/22 14:08:20 Testing conc=true; bufWrite=false; readType=RawWrite
2021/04/22 14:08:20 Testing conc=false; bufWrite=true; readType=CopyFile
2021/04/22 14:08:21 Testing conc=false; bufWrite=true; readType=CopyBuf
2021/04/22 14:08:21 Testing conc=false; bufWrite=true; readType=RawWrite
2021/04/22 14:08:22 Testing conc=false; bufWrite=false; readType=CopyFile
2021/04/22 14:08:23 Testing conc=false; bufWrite=false; readType=CopyBuf
2021/04/22 14:08:24 Testing conc=false; bufWrite=false; readType=RawWrite

Mac Output:

2021/04/22 14:12:47 Testing conc=true; bufWrite=true; readType=CopyFile
2021/04/22 14:12:47 Testing conc=true; bufWrite=true; readType=CopyBuf
2021/04/22 14:12:48 Testing conc=true; bufWrite=true; readType=RawWrite
2021/04/22 14:12:48 Testing conc=true; bufWrite=false; readType=CopyFile
2021/04/22 14:12:48 Testing conc=true; bufWrite=false; readType=CopyBuf
2021/04/22 14:12:49 Testing conc=true; bufWrite=false; readType=RawWrite
2021/04/22 14:12:49 Testing conc=false; bufWrite=true; readType=CopyFile
2021/04/22 14:12:49 Testing conc=false; bufWrite=true; readType=CopyBuf
2021/04/22 14:12:50 Testing conc=false; bufWrite=true; readType=RawWrite
2021/04/22 14:12:50 Testing conc=false; bufWrite=false; readType=CopyFile
2021/04/22 14:12:50 Testing conc=false; bufWrite=false; readType=CopyBuf
2021/04/22 14:12:51 Testing conc=false; bufWrite=false; readType=RawWrite
puellanivis commented 3 years ago 
C:\Users\snowgirl\Work\test>test-windows-zero-byte.exe
2021/04/22 20:14:31 Testing conc=true; bufWrite=true; readType=CopyFile
2021/04/22 20:14:31 Testing conc=true; bufWrite=true; readType=CopyBuf
2021/04/22 20:14:31 Testing conc=true; bufWrite=true; readType=RawWrite
2021/04/22 20:14:31 Testing conc=true; bufWrite=false; readType=CopyFile
2021/04/22 20:14:31 Testing conc=true; bufWrite=false; readType=CopyBuf
2021/04/22 20:14:32 Testing conc=true; bufWrite=false; readType=RawWrite
2021/04/22 20:14:32 Testing conc=false; bufWrite=true; readType=CopyFile
2021/04/22 20:14:32 Testing conc=false; bufWrite=true; readType=CopyBuf
2021/04/22 20:14:32 Testing conc=false; bufWrite=true; readType=RawWrite
2021/04/22 20:14:32 Testing conc=false; bufWrite=false; readType=CopyFile
2021/04/22 20:14:32 Testing conc=false; bufWrite=false; readType=CopyBuf
2021/04/22 20:14:32 Testing conc=false; bufWrite=false; readType=RawWrite
puellanivis commented 3 years ago

What kind of remote ssh/sftp server are you connecting to? Architecture, product, etc.

lespea commented 3 years ago

Okay so new information... I'm not sure what happened when I was testing it last night with different versions of go, but it appears that it only errors for 32bit versions of go. I was trying my sample code on a different machine to see what servers it all failed on... when one of them passed. That machine was using 64bit go. So I uninstalled the 64bit version, cleared out $GOHOME, installed 32bit, and then had the same errors.

For reference, I was testing against a centos 7 machine running openssh, using an ed25519 key.

My go.sum file:

github.com/davecgh/go-spew v1.1.0 h1:ZDRjVQ15GmhC3fiQ8ni8+OwkZQO4DARzQgrnXU1Liz8=
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/kr/fs v0.1.0 h1:Jskdu9ieNAYnjxsi0LbQp1ulIKZV1LAFgK1tWhpZgl8=
github.com/kr/fs v0.1.0/go.mod h1:FFnZGqtBN9Gxj7eW1uZ42v5BccTP0vu6NEaFoC2HwRg=
github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
github.com/pkg/sftp v1.13.0 h1:Riw6pgOKK41foc1I1Uu03CjvbLZDXeGpInycM4shXoI=
github.com/pkg/sftp v1.13.0/go.mod h1:41g+FIPlQUTDCveupEmEA65IoiQFrtgCeDopC4ajGIM=
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/testify v1.6.1 h1:hDPOHmpOpP40lSULcqw7IrRb/u7w6RpDC9399XyoNd0=
github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
golang.org/x/crypto v0.0.0-20201221181555-eec23a3978ad/go.mod h1:jdWPYTVW3xRLrWPugEBEK3UY2ZEsg3UU495nc5E+M+I=
golang.org/x/crypto v0.0.0-20210421170649-83a5a9bb288b h1:7mWr3k41Qtv8XlltBkDkl8LoP3mpSgBW8BUoxtEdbXg=
golang.org/x/crypto v0.0.0-20210421170649-83a5a9bb288b/go.mod h1:T9bdIzuCu7OtxOm1hfPfRQxPLYneinmdGuTeoZ9dtd4=
golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg=
golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4 h1:myAQVi0cGEoqQVR5POX+8RR2mrocKqNN1hmeMqhX27k=
golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/term v0.0.0-20201117132131-f5c789dd3221/go.mod h1:Nr5EML6q2oocZ2LXRh80K7BxOlk5/8JxuGnuhpl+muw=
golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1 h1:v+OssWQX+hTHEmOBgwxdZxK4zHq3yOs8F9J7mk0PY8E=
golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c h1:dUUwHk2QECo/6vqA44rthZ8ie2QXMNeKRTHCNY2nXvo=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
puellanivis commented 3 years ago

Weird…

lespea commented 3 years ago

I'm gonna try to get 32bit go working on linux and see what happens there

lespea commented 3 years ago

Okay tested this with 32bit go on linux and same failure. So it doesn't appear to be OS dependent just the architecture.

puellanivis commented 3 years ago

I have reproduced it on GOOS=windows GOARCH=386

lespea commented 3 years ago

That's good... it isn't just me ;)

puellanivis commented 3 years ago

I’ve isolated the cause, and will be opening a PR to address it.

puellanivis commented 3 years ago

The most recent master should get things almost-always-fixed as it does not default to using MaxInt64 which in part causes the issue.

lespea commented 3 years ago

I tested with the latest master and it indeed worked. Thanks for the quick fix; once your pr gets merged I'll double check that one as well.

drakkan commented 3 years ago

@lespea please check again now that the PR is merged and close this issue if it is fixed, thank you

lespea commented 3 years ago

Looks good, thanks again for the quick fix!