GitHub

@@ -0,0 +1,144 @@

1+

// This integration test exercises the behavior of heartbeatconn

2+

// where the server is slow at handling the data received over the connection.

3+

// Note that the server is still sending heartbeats to the client, it's just the

4+

// data handling (usually I/O in case of zrepl endpoint.Receiver) that is slow.

5+

//

6+

// In commit 082335df5d85e1b0b9faa35ff182c71886142d3e and earlier, heartbeatconn would fail

7+

// this benchmark with a writev I/O timeout (here the ss(8) output at the time of failure)

8+

//

9+

// ESTAB 33369 0 127.0.0.1:12345 127.0.0.1:57282 users:(("heartbeatconn_i",pid=25953,fd=5))

10+

// cubic wscale:7,7 rto:203 rtt:2.992/5.849 ato:162 mss:32768 pmtu:65535 rcvmss:32741 advmss:65483 cwnd:10 bytes_sent:48 bytes_acked:48 bytes_received:195401 segs_out:44 segs_in:57 data_segs_out:6 data_segs_in:34 send 876.1Mbps lastsnd:125 lastrcv:9390 lastack:125 pacing_rate 1752.0Mbps delivery_rate 6393.8Mbps delivered:7 app_limited busy:42ms rcv_rtt:1 rcv_space:65483 rcv_ssthresh:65483 minrtt:0.029

11+

// --

12+

// ESTAB 0 3956805 127.0.0.1:57282 127.0.0.1:12345 users:(("heartbeatconn_i",pid=26100,fd=3))

13+

// cubic wscale:7,7 rto:211 backoff:5 rtt:10.38/16.937 ato:40 mss:32768 pmtu:65535 rcvmss:536 advmss:65483 cwnd:10 bytes_sent:195401 bytes_acked:195402 bytes_received:48 segs_out:57 segs_in:45 data_segs_out:34 data_segs_in:6 send 252.5Mbps lastsnd:9390 lastrcv:125 lastack:125 pacing_rate 505.1Mbps delivery_rate 1971.0Mbps delivered:35 busy:30127ms rwnd_limited:30086ms(99.9%) rcv_space:65495 rcv_ssthresh:65495 notsent:3956805 minrtt:0.007

14+

// panic: writev tcp 127.0.0.1:57282->127.0.0.1:12345: i/o timeout

15+

//

16+

// The assumed reason for those writev timeouts is the following:

17+

// - Sporadic server stalls (sever data handling, usually I/O) cause TCP exponential backoff on the client for client->server

18+

// - Go runtime unblocks after the deadline expires, resultin gin writev I/O timeout

19+

// - That is, even though the client observed heartbeats from the server

20+

// -> TCP doesn't assume symmetric connection behavior, but our implementation does.

21+

//

22+

// The fix contained in the commit this message was committed with resets the deadline whenever

23+

// a heartbeat is received from the server.

24+

//

25+

//

26+

// How to run this integration test:

27+

//

28+

//

29+

// Terminal 1:

30+

// $ ZREPL_RPC_DATACONN_HEARTBEATCONN_DEBUG=1 go run heartbeatconn_integration_variablereceiverate.go -mode server -addr 127.0.0.1:12345

31+

// rpc/dataconn/heartbeatconn: send heartbeat

32+

// rpc/dataconn/heartbeatconn: send heartbeat

33+

// ...

34+

//

35+

// Terminal 2:

36+

// $ ZREPL_RPC_DATACONN_HEARTBEATCONN_DEBUG=1 go run heartbeatconn_integration_variablereceiverate.go -mode client -addr 127.0.0.1:12345

37+

// rpc/dataconn/heartbeatconn: received heartbeat, resetting write timeout

38+

// rpc/dataconn/heartbeatconn: renew frameconn write timeout returned errT=<nil> err=%!s(<nil>)

39+

// rpc/dataconn/heartbeatconn: send heartbeat

40+

// rpc/dataconn/heartbeatconn: received heartbeat, resetting write timeout

41+

// rpc/dataconn/heartbeatconn: renew frameconn write timeout returned errT=<nil> err=%!s(<nil>)

42+

// rpc/dataconn/heartbeatconn: received heartbeat, resetting write timeout

43+

// ...

44+

//

45+

// You should observe

46+

package main

47+48+

import (

49+

"bytes"

50+

"flag"

51+

"fmt"

52+

"io"

53+

"log"

54+

"math/rand"

55+

"net"

56+

"os"

57+

"os/exec"

58+

"path"

59+

"time"

60+61+

"github.com/zrepl/zrepl/util/devnoop"

62+63+

"github.com/zrepl/zrepl/rpc/dataconn/heartbeatconn"

64+

)

65+66+

func orDie(err error) {

67+

if err != nil {

68+

grepfield := path.Base(os.Args[0])[:10]

69+

fmt.Fprintf(os.Stderr, "grepping for %s\n", grepfield)

70+

sh := fmt.Sprintf("ss -ntpi | grep -A1 %s", grepfield)

71+

cmd := exec.Command("bash", "-c", sh)

72+

o, _ := cmd.CombinedOutput()

73+

buf := bytes.NewBuffer(o)

74+

_, _ = io.Copy(os.Stderr, buf)

75+

panic(err)

76+

}

77+

}

78+79+

var mode string

80+

var addr string

81+82+

func main() {

83+84+

flag.StringVar(&mode, "mode", "", "server|client")

85+

flag.StringVar(&addr, "addr", "INVALID", "")

86+

flag.Parse()

87+88+

modemap := map[string]func(){

89+

"server": server,

90+

"client": client,

91+

}

92+

modemap[mode]()

93+94+

}

95+96+

func server() {

97+

ln, err := net.Listen("tcp", addr)

98+

orDie(err)

99+

l := ln.(*net.TCPListener)

100+

for {

101+

c, err := l.AcceptTCP()

102+

if err != nil {

103+

log.Printf("accept err: %s", err)

104+

continue

105+

}

106+

hc := heartbeatconn.Wrap(c, 5*time.Second, 10*time.Second)

107+108+

for {

109+

f, err := hc.ReadFrame()

110+

orDie(err)

111+

// _, err = buf.Write(f.Buffer.Bytes())

112+

// orDie(err)

113+

sleep := time.Duration(rand.NormFloat64()*500) * time.Millisecond

114+

time.Sleep(sleep)

115+

f.Buffer.Free()

116+

}

117+118+

}

119+120+

}

121+122+

func client() {

123+

c, err := net.Dial("tcp", addr)

124+

orDie(err)

125+

hc := heartbeatconn.Wrap(c.(*net.TCPConn), 5*time.Second, 10*time.Second)

126+127+

// follow API requirements to always ReadFrame

128+

go func() {

129+

for {

130+

f, err := hc.ReadFrame()

131+

orDie(err)

132+

f.Buffer.Free()

133+

}

134+

}()

135+136+

dn := devnoop.Get()

137+

var buf [1 << 10]byte

138+

for {

139+

n, err := dn.Read(buf[:])

140+

orDie(err)

141+

err = hc.WriteFrame(buf[:n], 23)

142+

orDie(err)

143+

}

144+

}

Read the original on github.com ↗