emersion / go-imap

📥 An IMAP library for clients and servers
MIT License
2.02k stars 288 forks source link

v1: connection hangs forever in "handleGreetAndStartReading" #611

Open Simerax opened 2 months ago

Simerax commented 2 months ago

Go-Imap 1.2.1 seems to hang forever in some cases even though we set a Timeout (and Deadline) in net.Dialer.

The IMAP-Server we are connecting to (imap.office365.com) seems to just let us "hang" sometimes (I don't know why - it happens randomly).

This would not really be a problem if the client could just hang up on its own after a certain timeout. The settings in net.Dialer don't seem to do anything.

Does the IMAP Library not honor the Timeout/Deadline Setting in net.Dialer here or are we doing something wrong?

We are unable to give you anymore debugging because we cannot call .SetDebug(w) since this problem occurs within DialWithDialerTLS before we even have a handle to the client.

Ps. we are cross compiling from windows/amd64 to linux/amd64 thats probably why the stack trace paths begin with C:\... but the functions are unix/linux like (poll/fd_unix.go)

// ...
tlsConfig := &tls.Config{}

dialer := &net.Dialer{
    Timeout:  time.Second * 10,
    Deadline: time.Now().Add(time.Second * 20),
}

c, err := client.DialWithDialerTLS(dialer, url, tlsConfig)
// ...
goroutine 2943848 [IO wait, 586 minutes]:
internal/poll.runtime_pollWait(0x7f849015d940, 0x72)
    C:/Program Files/Go/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc0034ec680?, 0xc000530a00?, 0x0)
    C:/Program Files/Go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
    C:/Program Files/Go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0034ec680, {0xc000530a00, 0x1500, 0x1500})
    C:/Program Files/Go/src/internal/poll/fd_unix.go:164 +0x27a
net.(*netFD).Read(0xc0034ec680, {0xc000530a00?, 0xc035daf4a0?, 0xc01387e838?})
    C:/Program Files/Go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc007ad00e0, {0xc000530a00?, 0x0?, 0xc01387e880?})
    C:/Program Files/Go/src/net/net.go:179 +0x45
crypto/tls.(*atLeastReader).Read(0xc0005ee858, {0xc000530a00?, 0xc0005ee858?, 0x0?})
    C:/Program Files/Go/src/crypto/tls/conn.go:805 +0x3b
bytes.(*Buffer).ReadFrom(0xc003d349a8, {0x33cdde0, 0xc0005ee858})
    C:/Program Files/Go/src/bytes/buffer.go:211 +0x98
crypto/tls.(*Conn).readFromUntil(0xc003d34700, {0x33cd6c0?, 0xc007ad00e0}, 0x410425?)
    C:/Program Files/Go/src/crypto/tls/conn.go:827 +0xde
crypto/tls.(*Conn).readRecordOrCCS(0xc003d34700, 0x0)
    C:/Program Files/Go/src/crypto/tls/conn.go:625 +0x250
crypto/tls.(*Conn).readRecord(...)
    C:/Program Files/Go/src/crypto/tls/conn.go:587
crypto/tls.(*Conn).Read(0xc003d34700, {0xc00236b000, 0x1000, 0x2?})
    C:/Program Files/Go/src/crypto/tls/conn.go:1369 +0x158
bufio.(*Reader).fill(0xc064da5020)
    C:/Program Files/Go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).ReadRune(0xc064da5020)
    C:/Program Files/Go/src/bufio/bufio.go:307 +0x1e
github.com/emersion/go-imap.(*Reader).ReadAtom(0xc000500900)
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/read.go:186 +0x6c
github.com/emersion/go-imap.ReadResp(0xc000500900)
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/response.go:15 +0x27
github.com/emersion/go-imap/client.(*Client).readOnce(0xc001c203c0)
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/client.go:150 +0x3b
github.com/emersion/go-imap/client.(*Client).reader(0xc001c203c0)
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/client.go:135 +0x59
created by github.com/emersion/go-imap/client.(*Client).handleGreetAndStartReading in goroutine 2943785
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/client.go:517 +0x145

goroutine 2943785 [select, 586 minutes]:
github.com/emersion/go-imap/client.(*Client).execute(0xc001c203c0, {0x33ce420?, 0x42a3c80?}, {0x0?, 0x0})
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/client.go:276 +0x48d
github.com/emersion/go-imap/client.(*Client).Capability(0xc001c203c0)
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/cmd_any.go:23 +0x2e
github.com/emersion/go-imap/client.(*Client).Support(0xc001c203c0, {0x1807a16, 0x8})
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/cmd_any.go:44 +0xc6
github.com/emersion/go-imap/client.New({0x33e0558?, 0xc003d34700})
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/client.go:596 +0x2a6
github.com/emersion/go-imap/client.DialWithDialerTLS({0x33c97e0, 0xc00384ca80}, {0xc008127060, 0x19}, 0xc003e7a000)
    /pkg/mod/github.com/emersion/go-imap@v1.2.1/client/client.go:681 +0x22d
doganpoyraz commented 2 months ago

We encountered this issue several times and prepared a fix proposal #615. The implementation honors the timeout value in the dialer, but during the construction of a new client, there are 2 consequent requests. The first one runs with a deadline value and times out correctly. However, at the beginning of each command, the connection deadline is set to zero if there is no timeout value defined on the client. At this point, the client object is not returned to the user yet and timeout is always zero.