net: io.CopyN fails to copy from file to net.Conn on Windows

[AndreKR]

What version of Go are you using (go version)?

go version go1.10.2 windows/amd64

Does this issue reproduce with the latest release?

That is the latest (stable) release.

What operating system and processor architecture are you using (go env)?

windows/amd64

What did you do?

• Be on Windows (I tried this on Linux and couldn't reproduce the bug.)
• Build this program:

package main

import (
	"fmt"
	"io"
	"net"
	"os"
	"time"
)

func main() {
	l, err := net.Listen("tcp", ":1234")
	fmt.Println(err)
	for {
		conn, err := l.Accept()
		fmt.Println(err)
		f, err := os.Open("alphabet.txt")
		fmt.Println(err)

		for {
			n, err := io.CopyN(conn, f, 3)
			fmt.Println(n, err)
			if err != nil {
				break
			}
			time.Sleep(1 * time.Second)
		}
		conn.Close()
	}
}

• Create a file alphabet.txt:

abcdefghijklmnopqrstuvwxyz

• Run the program
• Connect to port 1234 with PuTTY or netcat.

What did you expect to see?

abc <pause> def <pause> ghi <pause> jkl ...

What did you see instead?

abc <pause> def <pause> def <pause> def ...

Notes

I could only reproduce this when copying from a file to a network connection. If I for example replace the network connection with os.Stdout or the file with strings.NewReader() the issue doesn't happen.

[bcmills]

CC: @alexbrainman @mikioh @bradfitz

[AndreKR]

The code path used in this case (copying from a file to a network socket) uses Windows' TransmitFile function.

As this might turn out to be a bug in the TransmitFile implementation, it might be relevant that this occurs on Windows 7 Pro Service Pack 1.

[alexbrainman]

@AndreKR

I agree it does sounds like TransmitFile problem. I already fixed something similar in 4aa5dcc . Maybe my change did not account for something. See if you can fix it again. If you don't want to fix this, I will look into this when I have time.

Thank you.

Alex

[AndreKR]

I could reproduce the issue even in C++.

Here's poll.SendFile with a fix:

// SendFile wraps the TransmitFile call.
func SendFile(fd *FD, src syscall.Handle, n int64) (int64, error) {
	ft, err := syscall.GetFileType(src)
	if err != nil {
		return 0, err
	}
	// TransmitFile does not work with pipes
	if ft == syscall.FILE_TYPE_PIPE {
		return 0, syscall.ESPIPE
	}

	if err := fd.writeLock(); err != nil {
		return 0, err
	}
	defer fd.writeUnlock()

	o := &fd.wop
	o.qty = uint32(n)
	o.handle = src

	var done int
	if n != 0 {
		done, err = transmitFileAndFixFilePointer(o)
	} else {
		done, err = transmitFile(o)
	}

	return int64(done), err

}

func transmitFile(o *operation) (int, error) {
	return wsrv.ExecIO(o, func(o *operation) error {
		return syscall.TransmitFile(o.fd.Sysfd, o.handle, o.qty, 0, &o.o, nil, syscall.TF_WRITE_BEHIND)
	})
}

// transmitFileAndFixFilePointer calls TransmitFile and, if it failed to advance the file pointer, advances the file pointer
func transmitFileAndFixFilePointer(o *operation) (int, error) {
	filePointerBefore, err := getFilePointer(o.handle)
	if err != nil {
		return 0, err
	}
	done, err := wsrv.ExecIO(o, func(o *operation) error {
		return syscall.TransmitFile(o.fd.Sysfd, o.handle, o.qty, 0, &o.o, nil, syscall.TF_WRITE_BEHIND)
	})
	if err != nil {
		return done, err
	}
	filePointerAfter, err := getFilePointer(o.handle)
	if err != nil {
		return done, err
	}
	if filePointerAfter != filePointerBefore+int64(o.qty) {
		_, err = syscall.SetFilePointer(o.handle, int32(o.qty), nil, syscall.FILE_CURRENT)
	}
	return done, err
}

func getFilePointer(h syscall.Handle) (int64, error) {
	var highOffset int32
	lowOffset, err := syscall.SetFilePointer(h, 0, &highOffset, syscall.FILE_CURRENT)
	if err != nil {
		return 0, err
	}
	return int64(highOffset)<<32 | int64(lowOffset), nil
}

This makes three syscalls instead of one and I'm not sure how it performs compared to not using TransmitFile at all.

[alexbrainman]

I could reproduce the issue even in C++.

I could not reproduce your problem on my Windows 10.

Here's poll.SendFile with a fix:

Why do you think Go implementation needs a fix? What is wrong with Go implementation?

Alex

[creker]

I could reproduce the issue in C++ on my Windows 10 1803. Both samples on the stackoverflow fix the problem. Looks like a bug in TransmitFile.

[AndreKR]

What is wrong with Go implementation?

It uses TransmitFile in a way that doesn't work. It expects TransmitFile to advance the file pointer, which works only for the first call, not for subsequent calls.

This happens at least on some systems. While it seems to work on your Windows 10 system, the issue has been observed so far by @creker on Windows 10 1803, by Stack Overflow user Remy Lebeau on Windows 7 Home Premium 64bit and by me on Windows 7 Professional 64 bit.

[creker]

Same issue on Windows Server 2016 1607

[gopherbot]

Change https://golang.org/cl/117655 mentions this issue: net: debuggin TestSendfile

[alexbrainman]

@AndreKR and @creker I just modified our existing test https://go-review.googlesource.com/c/go/+/117655 to hopefully tickle this bug. Our try builder did not complain about my changes (I do not know what Windows version it runs). I suspect my changed test will fail on your computers. Can you, please, verify.

I did read https://msdn.microsoft.com/en-us/library/windows/desktop/ms740565(v=vs.85).aspx and it does says:

lpOverlapped
A pointer to an OVERLAPPED structure. If the socket handle has been opened as overlapped, specify this parameter in order to achieve an overlapped (asynchronous) I/O operation. By default, socket handles are opened as overlapped.

You can use the lpOverlapped parameter to specify a 64-bit offset within the file at which to start the file data transfer by setting the Offset and OffsetHigh member of the OVERLAPPED structure.

Perhaps when we wrote this code, we assumed that clearing lpOverlapped will send data starting from current file position (and it does do this for me). But it does not explicitly say that. Perhaps "You can use" confused me.

Anyway, if my CL 117655 is broken for you, maybe we could use Windows SetFilePointer to get current file position and copy it into lpOverlapped before calling TransmitFile. Regardless I will need your help, because we don't have computer where I can verify my changes.

Thank you.

Alex

[creker]

@alexbrainman I think your change doesn't trigger the bug. At least the part about advancing file position. Simple test would be to call CopyN(conn, f, 3) three times in a row and compare the result on the other end with "Produced ". You don't want to seek. This bug will cause the string to be "Producduc" instead.

[alexbrainman]

@alexbrainman I think your change doesn't trigger the bug.

Did you actually try it on your computer?

Simple test would be to call CopyN(conn, f, 3) three times in a row and compare the result on the other end with "Produced ". You don't want to seek. This bug will cause the string to be "Producduc" instead.

I modified my test as you suggested - see patch set 2 of my CL https://go-review.googlesource.com/c/go/+/117655/2 As you can see Windows builder is still OK. Does patch 2 fails on your computer?

Surprisingly freebsd-amd64 builder failed with exact message we are after:

--- FAIL: TestSendfile (0.00s)
sendfile_test.go:74: have="ProProPro", but want="Produced "
FAIL

Alex

[creker]

@alexbrainman no, I read the code first and saw that it doesn't match the issue and uses Seek which should prevent TransmitFile from giving the wrong result. I'm not familiar with Go test suite to easily test changes.

But now that even this change doesn't trigger the bug I will run it and report the results. Will also try previous test just in case.

[creker]

Windows 10 1803

Patch set 2 fails

--- FAIL: TestSendfile (0.00s)
    sendfile_test.go:74: have="Producduc", but want="Produced "

Patch set 1 is ok

[gopherbot]

Change https://golang.org/cl/117775 mentions this issue: net: add TestSendfileParts

[alexbrainman]

@creker I can reproduce this on one of my Windows 10 computers. So I sent a proper test now - I plan to submit it. Thank you very much.

Alex

[gopherbot]

Change https://golang.org/cl/117816 mentions this issue: internal/poll: specify current file position when calling TransmitFile

[alexbrainman]

@AndreKR and @creker I submitted

https://golang.org/cl/117775

with new test that fails on my Windows 10, but none of our 5 builders https://build.golang.org fails the test. Please, try new test on current tip and make sure that it fails on your system.

I also sent a fix for this issue in

https://golang.org/cl/117816

Please, also try CL 117816 to see if it fixes new test on your system, and fixes whatever other problems re this issue. I will wait before submitting CL 117816.

Thank you.

Alex

[AndreKR]

I can confirm that the current master (40fc4bb), which includes CL 117775 fails on my machine with:

--- FAIL: TestSendfileParts (0.00s)
    sendfile_test.go:151: unexpected server reply "Producduc", want "Produced "

I can also confirm that the change from CL 117816 fixes the problem.

By the way, I just realized that this sentence from the TransmitFile documentation:

If lpOverlapped is a NULL pointer, the transmission of data always starts at the current byte offset in the file.

is irrelevant in our case, because we are never passing a NULL pointer. Instead, there seems to be another bug in TransmitFile that causes it to start reading at position 3 when lpOverlapped.Offset is 0.

[creker]

Same on my Windows 10 1803

@AndreKR

there seems to be another bug in TransmitFile

That's starting to sound to me like we don't understand something. Would be cool if someone from MS could comment on that. But if it's a bug they probably wouldn't be able to fix it without breaking backwards compatibility.

[alexbrainman]

I can also confirm that the change from CL 117816 fixes the problem.

Sounds good to me.

Same on my Windows 10 1803

SGTM.

I will wait for CL 117816 to be reviewed and submitted.

Thank you.

Alex

[alexbrainman]

https://go-review.googlesource.com/c/go/+/130855 broke test that is guarding fix for this current issue.

c:\>systeminfo | findstr /B /C:"OS Name" /C:"OS Version"
OS Name:                   Microsoft Windows 10 Enterprise
OS Version:                10.0.17134 N/A Build 17134

c:\>go version
go version devel +e03220a594 Sat Aug 25 02:39:49 2018 +0000 windows/amd64

c:\>go test -short net
--- FAIL: TestSendfileParts (0.00s)
    sendfile_test.go:145: unexpected server reply "Producduc", want "Produced "
FAIL
FAIL    net     6.035s

c:\>

And I think this current issue is broken again. So I am reopening it.

I also suspect that TestSendfileParts will fail pretty much on every recent version of Windows 10. (@mattn does it fail for you? Thank you)

Maybe we should skip TestSendfileParts and copy that change to release-branch.go1.11 ?

/cc @bradfitz

Alex

[ianlancetaylor]

The test does three instances of "copy 3 bytes." It expects to see the first nine characters, which are "Produced ". In the failing test case it is instead getting "Producduc". It's clear that it is getting characters 0-3, then characters 4-6, then characters 4-6 again.

Each "copy 3 bytes" action is done by calling TransmitFile. The code arranges to transmit the file starting at the current file position; that was implemented by your CL 117816, which accidentally set the offset incorrectly and was corrected by CL 130855. When CL 117816 set the offset incorrectly, the TransmitFile call failed, and the code fell back to doing an ordinary Read followed by a Write. Now the TransmitFile succeeds. But, apparently, in some cases, it transmit from the wrong file offset.

My guess is that in some cases TransmitFile does not update the current file position. That is consistent with what has been reported. So my hypothesis is that we can fix this by explicitly updating the file position at the end of SendFile, to move forward by the number of bytes that were transferred.

[ianlancetaylor]

Basically, try changing the end of internal/poll/sendfile_windows.go to look like this:

	done, err := wsrv.ExecIO(o, func(o *operation) error {
		return syscall.TransmitFile(o.fd.Sysfd, o.handle, o.qty, 0, &o.o, nil, syscall.TF_WRITE_BEHIND)
	})

	if err == nil {
		_, err = syscall.Seek(o.handle, int64(done), 1)
	}

	return int64(done), err

[alexbrainman]

Basically, try changing the end of internal/poll/sendfile_windows.go to look like this:

Sure:

c:\Users\Alex\dev\go\src>git rev-parse HEAD
b7d3e14a5296b17c940983aed0d9d6cb54b912b7

c:\Users\Alex\dev\go\src>git diff
diff --git a/src/internal/poll/sendfile_windows.go b/src/internal/poll/sendf
ile_windows.go
index dc93e851d6..ce27a0de8f 100644
--- a/src/internal/poll/sendfile_windows.go
+++ b/src/internal/poll/sendfile_windows.go
@@ -38,5 +38,9 @@ func SendFile(fd *FD, src syscall.Handle, n int64) (int64,
 error) {
        done, err := wsrv.ExecIO(o, func(o *operation) error {
                return syscall.TransmitFile(o.fd.Sysfd, o.handle, o.qty, 0,
&o.o, nil, syscall.TF_WRITE_BEHIND)
        })
+       if err == nil {
+               // TODO: need a comment
+               _, err = syscall.Seek(o.handle, int64(done), 1)
+       }
        return int64(done), err
 }

c:\Users\Alex\dev\go\src>go test -short -run=TestSendfileParts net
--- FAIL: TestSendfileParts (0.00s)
    sendfile_test.go:145: unexpected server reply "Proed by ", want "Produced "
FAIL
FAIL    net     0.143s

c:\Users\Alex\dev\go\src>

Alex

[ianlancetaylor]

Oh yeah, I forgot that it appears that on some systems and in some cases the file position is updated, and in others it is not. I do not understand the logic of what is happening.

Try instead something like syscall.Seek(o.handle, curpos + int64(done), 0).

[alexbrainman]

Try instead something like syscall.Seek(o.handle, curpos + int64(done), 0).

This works (thank you):

c:\Users\Alex\dev\go\src>git diff
diff --git a/src/internal/poll/sendfile_windows.go b/src/internal/poll/sendfile_windows.go
index dc93e851d6..caf56d8ac4 100644
--- a/src/internal/poll/sendfile_windows.go
+++ b/src/internal/poll/sendfile_windows.go
@@ -38,5 +38,9 @@ func SendFile(fd *FD, src syscall.Handle, n int64) (int64, error) {
        done, err := wsrv.ExecIO(o, func(o *operation) error {
                return syscall.TransmitFile(o.fd.Sysfd, o.handle, o.qty, 0, &o.o, nil, syscall.TF_WRITE_BEHIND)
        })
+       if err == nil {
+               // TODO: need a comment
+               _, err = syscall.Seek(o.handle, curpos + int64(done), 0)
+       }
        return int64(done), err
 }

c:\Users\Alex\dev\go\src>

I will send a patch when free. Unless someone beats me to it.

Alex

[bradfitz]

Nice to hear that works.

[gopherbot]

Change https://golang.org/cl/131976 mentions this issue: internal/poll: advance file position in windows sendfile

[alexbrainman]

Nice to hear that works.

Sad we do not have Windows 10 builder that would catch errors like that.

@mattn please try https://go-review.googlesource.com/c/go/+/131976 to see if it fixes broken net.TestSendfileParts on your Windows 10. Thank you.

Alex

[alexbrainman]

Should we push CL 131976 to release-branch.go1.11 branch?

Alex

[rasky]

@gopherbot please consider backporting this issue to Go 1.11

[gopherbot]

Backport issue(s) opened: #27411 (for 1.11).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

[rasky]

@gopherbot please consider back porting this issue to Go 1.10. It's broken on Windows 10 and workarounds are difficult if the CopyN call happens deep into some networking library.

[FiloSottile]

Made backport issue #27419 manually because of #25574. (But also, "back porting" with a space does not trigger gopherbot.)

[gopherbot]

Change https://golang.org/cl/146779 mentions this issue: [release-branch.go1.10] internal/poll: advance file position in windows sendfile

[gopherbot]

Change https://golang.org/cl/146780 mentions this issue: [release-branch.go1.10] internal/poll: specify current file position when calling TransmitFile