Issues associated with this PR

2396

Solutions

You should show your solutions about the issues in your PR, including the overall solutions, details and the changes. At this time, Chinese is allowed to describe these.

UT result

测试场景：interval 配置 1s timeout 配置 1s 使用 iptables 切断数据: sudo iptables -t filter -A OUTPUT -p tcp --sport 8080 -d 30.230.84.109 -j DROP 使用 example 中的 sofa 测试日志如下

2024-05-29 16:23:30,203 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 25
2024-05-29 16:23:30,219 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 receive response, requestId = 25
2024-05-29 16:23:30,219 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request success 25
2024-05-29 16:23:30,219 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 5 local addr: 30.230.84.109:55470, remote addr: 100.88.107.243:8080
2024-05-29 16:23:31,204 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 26
2024-05-29 16:23:31,204 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 26
2024-05-29 16:23:31,204 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 26
2024-05-29 16:23:31,211 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 receive response, requestId = 26
2024-05-29 16:23:31,211 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request success 26
2024-05-29 16:23:31,211 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 5 local addr: 30.230.84.109:55470, remote addr: 100.88.107.243:8080
2024-05-29 16:23:32,206 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 27
2024-05-29 16:23:32,206 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 27
2024-05-29 16:23:32,207 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 27
2024-05-29 16:23:32,215 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 receive response, requestId = 27
2024-05-29 16:23:32,215 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request success 27
2024-05-29 16:23:32,215 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 5 local addr: 30.230.84.109:55470, remote addr: 100.88.107.243:8080
2024-05-29 16:23:33,208 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 28
2024-05-29 16:23:33,208 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 28
2024-05-29 16:23:33,208 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 28
2024-05-29 16:23:33,217 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 receive response, requestId = 28
2024-05-29 16:23:33,217 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request success 28
2024-05-29 16:23:33,217 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 5 local addr: 30.230.84.109:55470, remote addr: 100.88.107.243:8080
2024-05-29 16:23:34,209 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 29
2024-05-29 16:23:34,209 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 29
2024-05-29 16:23:34,210 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 29
2024-05-29 16:23:34,218 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 receive response, requestId = 29
2024-05-29 16:23:34,218 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request success 29
2024-05-29 16:23:34,218 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 5 local addr: 30.230.84.109:55470, remote addr: 100.88.107.243:8080
2024-05-29 16:23:35,210 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 30
2024-05-29 16:23:35,210 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 30
2024-05-29 16:23:35,211 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 30
2024-05-29 16:23:35,218 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 receive response, requestId = 30
2024-05-29 16:23:35,218 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request success 30
2024-05-29 16:23:35,218 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 5 local addr: 30.230.84.109:55470, remote addr: 100.88.107.243:8080
2024-05-29 16:23:36,212 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 31
2024-05-29 16:23:36,212 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 31
2024-05-29 16:23:36,213 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 31
2024-05-29 16:23:36,223 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 receive response, requestId = 31
2024-05-29 16:23:36,223 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request success 31
2024-05-29 16:23:36,223 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 5 local addr: 30.230.84.109:55470, remote addr: 100.88.107.243:8080
2024-05-29 16:23:37,214 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 32
2024-05-29 16:23:37,214 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 32
2024-05-29 16:23:37,214 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 32
2024-05-29 16:23:38,214 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 33
2024-05-29 16:23:38,214 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 33
2024-05-29 16:23:38,214 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request timeout 32
2024-05-29 16:23:38,214 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 33
2024-05-29 16:23:39,215 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 34
2024-05-29 16:23:39,215 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 34
2024-05-29 16:23:39,215 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request timeout 33
2024-05-29 16:23:39,215 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 34
2024-05-29 16:23:40,216 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request timeout 34
2024-05-29 16:23:40,216 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 35
2024-05-29 16:23:40,216 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 35
2024-05-29 16:23:40,216 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 35
2024-05-29 16:23:41,217 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 36
2024-05-29 16:23:41,217 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request timeout 35
2024-05-29 16:23:41,217 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 36
2024-05-29 16:23:41,217 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 36
2024-05-29 16:23:42,218 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 37
2024-05-29 16:23:42,218 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 37
2024-05-29 16:23:42,219 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request timeout 36
2024-05-29 16:23:42,219 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 37
2024-05-29 16:23:43,218 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request timeout 37
2024-05-29 16:23:43,219 [DEBUG] [network] [close connection] Close TCP Conn, Remote Address is = 100.88.107.243:8080, eventType is = LocalClose
2024-05-29 16:23:43,219 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 38
2024-05-29 16:23:43,219 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 38
2024-05-29 16:23:43,219 [ERROR] [-,-,-] [stream] [xprotocol] endStream, requestId = 38, error = connection has closed
2024-05-29 16:23:43,219 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 38
2024-05-29 16:23:43,219 [DEBUG] [network] [read loop] Error on read. Connection = 5, Local Address = 30.230.84.109:55470, Remote Address = 100.88.107.243:8080, err = read tcp 30.230.84.109:55470->100.88.107.243:8080: use of closed network connection
2024-05-29 16:23:43,220 [DEBUG] [network] [close connection] Close connection 5, event LocalClose, type NoFlush
2024-05-29 16:23:43,220 [DEBUG] [network] receive new connection event LocalClose, try to handle
2024-05-29 16:23:43,220 [DEBUG] client OnEvent LocalClose, connected true
2024-05-29 16:23:48,455 [INFO] [stream] [xprotocol] [keepalive] connection 5 stopped keepalive
2024-05-29 16:23:48,455 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 receive a request timeout 38
2024-05-29 16:23:48,455 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 39
2024-05-29 16:23:48,455 [DEBUG] [-,-,-] [stream] [xprotocol] connection 5 endStream, direction = 0, requestId = 39
2024-05-29 16:23:48,455 [ERROR] [-,-,-] [stream] [xprotocol] endStream, requestId = 39, error = connection has closed
2024-05-29 16:23:48,455 [DEBUG] [stream] [xprotocol] [keepalive] connection 5 send a keepalive request, id = 39

测试符合预期，可以在切断流量的第六次心跳失败后，断开连接

单元测试日志如下：

go test -run=TestKeepAliveSchedule -gcflags="all=-l -N" -v  ./pkg/stream/xprotocol/
2024-05-29 16:30:21,875 [INFO] [network] [ register pool factory] register protocol: bolt factory
2024-05-29 16:30:21,875 [INFO] [network] [ register pool factory] register protocol: dubbo factory
=== RUN   TestKeepAliveSchedule
2024-05-29 16:30:21,876 [DEBUG] new idlechecker: maxIdleCount:0, conn:2
2024-05-29 16:30:21,877 [DEBUG] [network] [client connection connect] connect raw tcp, remote address = 127.0.0.1:55791 ,event = ConnectedFlag, error = <nil>
2024-05-29 16:30:21,877 [DEBUG] [stream] [xprotocol] [keepalive] [start schedule] conn id:[2], interval: 200ms
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 1
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 endStream, direction = 0, requestId = 1
2024-05-29 16:30:21,877 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 send a keepalive request, id = 1
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 2
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 endStream, direction = 0, requestId = 2
2024-05-29 16:30:21,877 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 send a keepalive request, id = 2
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 3
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 endStream, direction = 0, requestId = 3
2024-05-29 16:30:21,877 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 send a keepalive request, id = 3
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 4
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 endStream, direction = 0, requestId = 4
2024-05-29 16:30:21,877 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 send a keepalive request, id = 4
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 5
2024-05-29 16:30:21,877 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 endStream, direction = 0, requestId = 5
2024-05-29 16:30:21,877 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 send a keepalive request, id = 5
2024-05-29 16:30:21,897 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 receive a request timeout 2
2024-05-29 16:30:21,897 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 receive a request timeout 1
2024-05-29 16:30:21,897 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 receive a request timeout 5
2024-05-29 16:30:21,897 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 receive a request timeout 3
2024-05-29 16:30:21,897 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 receive a request timeout 4
2024-05-29 16:30:22,28 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 receive response, requestId = 5
2024-05-29 16:30:22,28 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 receive response, requestId = 2
2024-05-29 16:30:22,28 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 receive response, requestId = 1
2024-05-29 16:30:22,28 [DEBUG] [stream] [xprotocol] [Dispatch] continue read data connection 2 local addr: 127.0.0.1:55792, remote addr: 127.0.0.1:55791
2024-05-29 16:30:22,28 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 receive response, requestId = 3
2024-05-29 16:30:22,28 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 receive response, requestId = 4
2024-05-29 16:30:22,28 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 2 local addr: 127.0.0.1:55792, remote addr: 127.0.0.1:55791
2024-05-29 16:30:22,178 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 6
2024-05-29 16:30:22,178 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 endStream, direction = 0, requestId = 6
2024-05-29 16:30:22,178 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 send a keepalive request, id = 6
2024-05-29 16:30:22,179 [DEBUG] [-,-,-] [stream] [xprotocol] connection 2 receive response, requestId = 6
2024-05-29 16:30:22,179 [DEBUG] [stream] [xprotocol] [keepalive] connection 2 receive a request success 6
2024-05-29 16:30:22,179 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 2 local addr: 127.0.0.1:55792, remote addr: 127.0.0.1:55791
2024-05-29 16:30:22,200 [INFO] [stream] [xprotocol] [keepalive] connection 2 stopped keepalive
--- PASS: TestKeepAliveSchedule (0.32s)
PASS
ok      mosn.io/mosn/pkg/stream/xprotocol       0.930s

不存在并发问题

Benchmark

If your code involves the processing of every request, you should give the Benchmark Result.

Code Style

Make sure Goimports has run
Show Golint result

手动 hack 模拟一下，所有 upstream 响应都超时的情况，该机制是可以断开连接的

pkg/stream/xprotocol/conn.go

func (sc *streamConn) handleResponse(ctx context.Context, frame api.XFrame) {
return // 直接添加 return 来模拟超时
}

2024-05-30 12:15:20,157 [DEBUG] [upstream] [cluster manager] clusterSnapshot.loadbalancer.ChooseHost result is 100.88.107.243:8080, cluster name = serverCluster
2024-05-30 12:15:20,157 [DEBUG] [2,-,-] [proxy] [downstream] timeout info: {GlobalTimeout:-1ms TryTimeout:0s}
2024-05-30 12:15:20,157 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownFilterAfterChooseHost[5], proxyId = 7  
2024-05-30 12:15:20,157 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownRecvHeader[6], proxyId = 7  
2024-05-30 12:15:20,157 [DEBUG] [2,-,-] [proxy] [upstream] append headers
2024-05-30 12:15:20,157 [DEBUG] [2,3,-] [proxy] [upstream] connPool ready, proxyId = 7, host = 100.88.107.243:8080
2024-05-30 12:15:20,157 [DEBUG] [2,3,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 9
2024-05-30 12:15:20,157 [DEBUG] [2,3,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 9
2024-05-30 12:15:20,157 [DEBUG] [2,3,-] [proxy] [downstream] enter phase WaitNotify[11], proxyId = 7  
2024-05-30 12:15:20,157 [DEBUG] [2,3,-] [proxy] [downstream] waitNotify begin 0x14000762000, proxyId = 7
2024-05-30 12:15:20,166 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 3 local addr: 30.230.89.233:64360, remote addr: 100.88.107.243:8080
2024-05-30 12:15:20,934 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 10
2024-05-30 12:15:20,934 [DEBUG] [-,-,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 10
2024-05-30 12:15:20,934 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 receive a request timeout 8
2024-05-30 12:15:20,934 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 send a keepalive request, id = 10
2024-05-30 12:15:20,942 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 3 local addr: 30.230.89.233:64360, remote addr: 100.88.107.243:8080
2024-05-30 12:15:21,658 [DEBUG] [2,-,-] [stream] [xprotocol] new stream detect, requestId = 8
2024-05-30 12:15:21,658 [DEBUG] [2,-,-] [proxy] [downstream] new stream, proxyId = 8 , requestId =8, oneway=false
2024-05-30 12:15:21,658 [DEBUG] [2,-,-] [proxy] [downstream] OnReceive
2024-05-30 12:15:21,658 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 2 local addr: 127.0.0.1:2046, remote addr: 127.0.0.1:64359
2024-05-30 12:15:21,659 [DEBUG] [2,-,-] [proxy] [downstream] enter phase InitPhase[0], proxyId = 8  
2024-05-30 12:15:21,659 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownFilter[1], proxyId = 8  
2024-05-30 12:15:21,659 [DEBUG] [2,-,-] [proxy] [downstream] enter phase MatchRoute[2], proxyId = 8  
2024-05-30 12:15:21,659 [DEBUG] [router] [routers] [MatchRoute] 
2024-05-30 12:15:21,659 [DEBUG] [router] [routers] [findVirtualHost] found default virtual host only
2024-05-30 12:15:21,659 [DEBUG] [2,-,-] [router] [DefaultMakeHandler] [MatchRoute] matched a route: &{0x140002ab600 [0x140003d0780] .*}
2024-05-30 12:15:21,659 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownFilterAfterRoute[3], proxyId = 8  
2024-05-30 12:15:21,659 [DEBUG] [2,-,-] [proxy] [downstream] enter phase ChooseHost[4], proxyId = 8  
2024-05-30 12:15:21,659 [DEBUG] [2,-,-] [proxy] [downstream] route match result:&{RouteRuleImplBase:0x140002ab600 configHeaders:[0x140003d0780] fastmatch:.*}, clusterName=serverCluster
2024-05-30 12:15:21,660 [DEBUG] [upstream] [cluster manager] clusterSnapshot.loadbalancer.ChooseHost result is 100.88.107.243:8080, cluster name = serverCluster
2024-05-30 12:15:21,660 [DEBUG] [2,-,-] [proxy] [downstream] timeout info: {GlobalTimeout:-1ms TryTimeout:0s}
2024-05-30 12:15:21,660 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownFilterAfterChooseHost[5], proxyId = 8  
2024-05-30 12:15:21,660 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownRecvHeader[6], proxyId = 8  
2024-05-30 12:15:21,660 [DEBUG] [2,-,-] [proxy] [upstream] append headers
2024-05-30 12:15:21,660 [DEBUG] [2,3,-] [proxy] [upstream] connPool ready, proxyId = 8, host = 100.88.107.243:8080
2024-05-30 12:15:21,660 [DEBUG] [2,3,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 11
2024-05-30 12:15:21,660 [DEBUG] [2,3,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 11
2024-05-30 12:15:21,661 [DEBUG] [2,3,-] [proxy] [downstream] enter phase WaitNotify[11], proxyId = 8  
2024-05-30 12:15:21,661 [DEBUG] [2,3,-] [proxy] [downstream] waitNotify begin 0x14000640580, proxyId = 8
2024-05-30 12:15:21,670 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 3 local addr: 30.230.89.233:64360, remote addr: 100.88.107.243:8080
2024-05-30 12:15:21,936 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 receive a request timeout 10
2024-05-30 12:15:21,937 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 12
2024-05-30 12:15:21,937 [DEBUG] [-,-,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 12
2024-05-30 12:15:21,937 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 send a keepalive request, id = 12
2024-05-30 12:15:21,946 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 3 local addr: 30.230.89.233:64360, remote addr: 100.88.107.243:8080
2024-05-30 12:15:22,938 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 receive a request timeout 12
2024-05-30 12:15:22,938 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 13
2024-05-30 12:15:22,938 [DEBUG] [-,-,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 13
2024-05-30 12:15:22,938 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 send a keepalive request, id = 13
2024-05-30 12:15:22,946 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 3 local addr: 30.230.89.233:64360, remote addr: 100.88.107.243:8080
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [stream] [xprotocol] new stream detect, requestId = 9
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] new stream, proxyId = 9 , requestId =9, oneway=false
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] OnReceive
2024-05-30 12:15:23,159 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 2 local addr: 127.0.0.1:2046, remote addr: 127.0.0.1:64359
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] enter phase InitPhase[0], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownFilter[1], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] enter phase MatchRoute[2], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [router] [routers] [MatchRoute] 
2024-05-30 12:15:23,159 [DEBUG] [router] [routers] [findVirtualHost] found default virtual host only
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [router] [DefaultMakeHandler] [MatchRoute] matched a route: &{0x140002ab600 [0x140003d0780] .*}
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownFilterAfterRoute[3], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] enter phase ChooseHost[4], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] route match result:&{RouteRuleImplBase:0x140002ab600 configHeaders:[0x140003d0780] fastmatch:.*}, clusterName=serverCluster
2024-05-30 12:15:23,159 [DEBUG] [upstream] [cluster manager] clusterSnapshot.loadbalancer.ChooseHost result is 100.88.107.243:8080, cluster name = serverCluster
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] timeout info: {GlobalTimeout:-1ms TryTimeout:0s}
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownFilterAfterChooseHost[5], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [downstream] enter phase DownRecvHeader[6], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [2,-,-] [proxy] [upstream] append headers
2024-05-30 12:15:23,159 [DEBUG] [2,3,-] [proxy] [upstream] connPool ready, proxyId = 9, host = 100.88.107.243:8080
2024-05-30 12:15:23,159 [DEBUG] [2,3,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 14
2024-05-30 12:15:23,159 [DEBUG] [2,3,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 14
2024-05-30 12:15:23,159 [DEBUG] [2,3,-] [proxy] [downstream] enter phase WaitNotify[11], proxyId = 9  
2024-05-30 12:15:23,159 [DEBUG] [2,3,-] [proxy] [downstream] waitNotify begin 0x140002abb80, proxyId = 9
2024-05-30 12:15:23,167 [DEBUG] [stream] [xprotocol] [Dispatch] buf.Len() == 0, connection 3 local addr: 30.230.89.233:64360, remote addr: 100.88.107.243:8080
2024-05-30 12:15:23,939 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 receive a request timeout 13
2024-05-30 12:15:23,939 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 15
2024-05-30 12:15:23,939 [DEBUG] [-,-,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 15
2024-05-30 12:15:23,939 [DEBUG] [network] [close connection] Close TCP Conn, Remote Address is = 100.88.107.243:8080, eventType is = LocalClose
2024-05-30 12:15:23,939 [DEBUG] [network] [read loop] Error on read. Connection = 3, Local Address = 30.230.89.233:64360, Remote Address = 100.88.107.243:8080, err = EOF
2024-05-30 12:15:23,939 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 send a keepalive request, id = 15
2024-05-30 12:15:23,939 [DEBUG] [network] [close connection] Close connection 3, event LocalClose, type NoFlush
2024-05-30 12:15:23,939 [DEBUG] [network] receive new connection event LocalClose, try to handle
2024-05-30 12:15:23,939 [DEBUG] client OnEvent LocalClose, connected true
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 9, reason: ConnectionTermination
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:23,939 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 9, code = 500, with headers = false
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 6, reason: ConnectionTermination
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 4, reason: ConnectionTermination
2024-05-30 12:15:23,939 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 6, code = 500, with headers = false
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:23,939 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 4, code = 500, with headers = false
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 2, reason: ConnectionTermination
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:23,939 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 5, reason: ConnectionTermination
2024-05-30 12:15:26,181 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 3, reason: ConnectionTermination
2024-05-30 12:15:23,939 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 2, code = 500, with headers = false
2024-05-30 12:15:28,202 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 7, reason: ConnectionTermination
2024-05-30 12:15:28,202 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:23,939 [DEBUG] [2,3,-] [proxy] [downstream] directResponse &{ID:6 proxy:0x140001a4b00 route:0x140003d0750 cluster:0x1400045ac00 element:0x140007822d0 bufferLimit:0 timeout:{GlobalTimeout:-1000000 TryTimeout:0} retryState:<nil> requestInfo:0x140002abac0 responseSender:0x140004167f8 upstreamRequest:0x140002aba48 perRetryTimer:<nil> responseTimer:<nil> downstreamReqHeaders:0x140007843c0 downstreamReqDataBuf:<nil> downstreamReqTrailers:<nil> downstreamRespHeaders:0x140007843c0 downstreamRespDataBuf:<nil> downstreamRespTrailers:<nil> upstreamResponseReceived:0 downstreamResponseStarted:false downstreamRecvDone:true upstreamRequestSent:true upstreamProcessDone:{_:[] v:{_:[] v:0}} directResponse:false oneway:false notify:0x140002e7aa0 downstreamReset:0 downstreamCleaned:0 upstreamReset:0 reuseBuffer:0 resetReason:{_:[] v:{Value:{v:ConnectionTermination} _:[]}} streamFilterChain:{downStream:0x140002ab8c0 DefaultStreamFilterChainImpl:0x1400042ea20} receiverFiltersAgainPhase:0 context:0x1400064a0c0 tracks:0x14000788000 logDone:0 snapshot:0x140003d00c0 phase:11}
2024-05-30 12:15:23,939 [DEBUG] [2,3,-] [proxy] [downstream] directResponse &{ID:9 proxy:0x140001a4b00 route:0x140003d0750 cluster:0x1400045ac00 element:0x14000782ab0 bufferLimit:0 timeout:{GlobalTimeout:-1000000 TryTimeout:0} retryState:<nil> requestInfo:0x140002abd80 responseSender:0x14000416d98 upstreamRequest:0x140002abd08 perRetryTimer:<nil> responseTimer:<nil> downstreamReqHeaders:0x14000784d20 downstreamReqDataBuf:<nil> downstreamReqTrailers:<nil> downstreamRespHeaders:0x14000784d20 downstreamRespDataBuf:<nil> downstreamRespTrailers:<nil> upstreamResponseReceived:0 downstreamResponseStarted:false downstreamRecvDone:true upstreamRequestSent:true upstreamProcessDone:{_:[] v:{_:[] v:0}} directResponse:false oneway:false notify:0x140007a60c0 downstreamReset:0 downstreamCleaned:0 upstreamReset:0 reuseBuffer:0 resetReason:{_:[] v:{Value:{v:ConnectionTermination} _:[]}} streamFilterChain:{downStream:0x140002abb80 DefaultStreamFilterChainImpl:0x1400042eb40} receiverFiltersAgainPhase:0 context:0x1400064a210 tracks:0x14000789c00 logDone:0 snapshot:0x140003d00c0 phase:11}
2024-05-30 12:15:28,202 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 3, code = 500, with headers = false
2024-05-30 12:15:28,202 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:28,202 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 7, code = 500, with headers = false
2024-05-30 12:15:28,202 [INFO] [stream] [xprotocol] [keepalive] connection 3 stopped keepalive
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpFilter[12], proxyId = 9  
2024-05-30 12:15:23,939 [DEBUG] [2,3,-] [proxy] [downstream] directResponse &{ID:4 proxy:0x140001a4b00 route:0x140003d0750 cluster:0x1400045ac00 element:0x14000418ff0 bufferLimit:0 timeout:{GlobalTimeout:-1000000 TryTimeout:0} retryState:<nil> requestInfo:0x140005a2780 responseSender:0x1400059e258 upstreamRequest:0x140005a2708 perRetryTimer:<nil> responseTimer:<nil> downstreamReqHeaders:0x1400059c3c0 downstreamReqDataBuf:<nil> downstreamReqTrailers:<nil> downstreamRespHeaders:0x1400059c3c0 downstreamRespDataBuf:<nil> downstreamRespTrailers:<nil> upstreamResponseReceived:0 downstreamResponseStarted:false downstreamRecvDone:true upstreamRequestSent:true upstreamProcessDone:{_:[] v:{_:[] v:0}} directResponse:false oneway:false notify:0x14000134a20 downstreamReset:0 downstreamCleaned:0 upstreamReset:0 reuseBuffer:0 resetReason:{_:[] v:{Value:{v:ConnectionTermination} _:[]}} streamFilterChain:{downStream:0x140005a2580 DefaultStreamFilterChainImpl:0x140005a4120} receiverFiltersAgainPhase:0 context:0x14000418de0 tracks:0x1400059a700 logDone:0 snapshot:0x140003d00c0 phase:11}
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpRecvHeader[13], proxyId = 9  
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpFilter[12], proxyId = 4  
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpFilter[12], proxyId = 6  
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpRecvHeader[13], proxyId = 6  
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] directResponse &{ID:7 proxy:0x140001a4b00 route:0x140003d0750 cluster:0x1400045ac00 element:0x14000712630 bufferLimit:0 timeout:{GlobalTimeout:-1000000 TryTimeout:0} retryState:<nil> requestInfo:0x14000762200 responseSender:0x1400074e438 upstreamRequest:0x14000762188 perRetryTimer:<nil> responseTimer:<nil> downstreamReqHeaders:0x140007545a0 downstreamReqDataBuf:<nil> downstreamReqTrailers:<nil> downstreamRespHeaders:0x140007545a0 downstreamRespDataBuf:<nil> downstreamRespTrailers:<nil> upstreamResponseReceived:0 downstreamResponseStarted:false downstreamRecvDone:true upstreamRequestSent:true upstreamProcessDone:{_:[] v:{_:[] v:0}} directResponse:false oneway:false notify:0x1400005cd80 downstreamReset:0 downstreamCleaned:0 upstreamReset:0 reuseBuffer:0 resetReason:{_:[] v:{Value:{v:ConnectionTermination} _:[]}} streamFilterChain:{downStream:0x14000762000 DefaultStreamFilterChainImpl:0x14000750090} receiverFiltersAgainPhase:0 context:0x14000782360 tracks:0x14000753180 logDone:0 snapshot:0x140003d00c0 phase:11}
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpRecvHeader[13], proxyId = 4  
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpFilter[12], proxyId = 7  
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpRecvHeader[13], proxyId = 7  
2024-05-30 12:15:28,202 [INFO] [2,3,-] [proxy] [downstream] processError=upstreamReset, proxyId: 8, reason: ConnectionTermination
2024-05-30 12:15:28,202 [DEBUG] [2,-,-] [stream] [xprotocol] new stream detect, requestId = 10
2024-05-30 12:15:28,201 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:28,202 [INFO] [2,3,-] [proxy] [downstream] onUpstreamReset, send hijack, reason ConnectionTermination
2024-05-30 12:15:28,202 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 5, code = 500, with headers = false
2024-05-30 12:15:28,202 [WARN] [2,3,-] [proxy] [downstream] set hijack reply, proxyId = 8, code = 500, with headers = false
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [stream] [xprotocol] appendHeaders, direction = 1, requestId = 9
2024-05-30 12:15:28,202 [DEBUG] [-,-,-] [stream] [xprotocol] appendHeaders, direction = 0, requestId = 16
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] directResponse &{ID:3 proxy:0x140001a4b00 route:0x140003d0750 cluster:0x1400045ac00 element:0x14000418c00 bufferLimit:0 timeout:{GlobalTimeout:-1000000 TryTimeout:0} retryState:<nil> requestInfo:0x140005a24c0 responseSender:0x1400059e168 upstreamRequest:0x140005a2448 perRetryTimer:<nil> responseTimer:<nil> downstreamReqHeaders:0x1400059c1e0 downstreamReqDataBuf:<nil> downstreamReqTrailers:<nil> downstreamRespHeaders:0x1400059c1e0 downstreamRespDataBuf:<nil> downstreamRespTrailers:<nil> upstreamResponseReceived:0 downstreamResponseStarted:false downstreamRecvDone:true upstreamRequestSent:true upstreamProcessDone:{_:[] v:{_:[] v:0}} directResponse:false oneway:false notify:0x14000134780 downstreamReset:0 downstreamCleaned:0 upstreamReset:0 reuseBuffer:0 resetReason:{_:[] v:{Value:{v:ConnectionTermination} _:[]}} streamFilterChain:{downStream:0x140005a22c0 DefaultStreamFilterChainImpl:0x140005a4090} receiverFiltersAgainPhase:0 context:0x14000418a80 tracks:0x1400059a380 logDone:0 snapshot:0x140003d00c0 phase:11}
2024-05-30 12:15:28,202 [DEBUG] [-,-,-] [stream] [xprotocol] connection 3 endStream, direction = 0, requestId = 16
2024-05-30 12:15:28,202 [DEBUG] [2,-,-] [proxy] [downstream] new stream, proxyId = 10 , requestId =10, oneway=false
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [stream] [xprotocol] connection 2 endStream, direction = 1, requestId = 9
2024-05-30 12:15:28,202 [ERROR] [-,-,-] [stream] [xprotocol] endStream, requestId = 16, error = connection has closed
2024-05-30 12:15:28,202 [DEBUG] [stream] [xprotocol] [keepalive] connection 3 send a keepalive request, id = 16
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] directResponse &{ID:5 proxy:0x140001a4b00 route:0x140003d0750 cluster:0x1400045ac00 element:0x1400064a030 bufferLimit:0 timeout:{GlobalTimeout:-1000000 TryTimeout:0} retryState:<nil> requestInfo:0x140006404c0 responseSender:0x1400063e168 upstreamRequest:0x14000640448 perRetryTimer:<nil> responseTimer:<nil> downstreamReqHeaders:0x14000338d20 downstreamReqDataBuf:<nil> downstreamReqTrailers:<nil> downstreamRespHeaders:0x14000338d20 downstreamRespDataBuf:<nil> downstreamRespTrailers:<nil> upstreamResponseReceived:0 downstreamResponseStarted:false downstreamRecvDone:true upstreamRequestSent:true upstreamProcessDone:{_:[] v:{_:[] v:0}} directResponse:false oneway:false notify:0x140003c8960 downstreamReset:0 downstreamCleaned:0 upstreamReset:0 reuseBuffer:0 resetReason:{_:[] v:{Value:{v:ConnectionTermination} _:[]}} streamFilterChain:{downStream:0x140006402c0 DefaultStreamFilterChainImpl:0x140006261b0} receiverFiltersAgainPhase:0 context:0x140004190e0 tracks:0x1400063ce00 logDone:0 snapshot:0x140003d00c0 phase:11}
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] directResponse &{ID:8 proxy:0x140001a4b00 route:0x140003d0750 cluster:0x1400045ac00 element:0x1400064a180 bufferLimit:0 timeout:{GlobalTimeout:-1000000 TryTimeout:0} retryState:<nil> requestInfo:0x14000640780 responseSender:0x1400063e258 upstreamRequest:0x14000640708 perRetryTimer:<nil> responseTimer:<nil> downstreamReqHeaders:0x14000338f00 downstreamReqDataBuf:<nil> downstreamReqTrailers:<nil> downstreamRespHeaders:0x14000338f00 downstreamRespDataBuf:<nil> downstreamRespTrailers:<nil> upstreamResponseReceived:0 downstreamResponseStarted:false downstreamRecvDone:true upstreamRequestSent:true upstreamProcessDone:{_:[] v:{_:[] v:0}} directResponse:false oneway:false notify:0x140003c8a80 downstreamReset:0 downstreamCleaned:0 upstreamReset:0 reuseBuffer:0 resetReason:{_:[] v:{Value:{v:ConnectionTermination} _:[]}} streamFilterChain:{downStream:0x14000640580 DefaultStreamFilterChainImpl:0x14000626240} receiverFiltersAgainPhase:0 context:0x140007126c0 tracks:0x1400063d180 logDone:0 snapshot:0x140003d00c0 phase:11}
2024-05-30 12:15:28,202 [DEBUG] [2,3,-] [proxy] [downstream] enter phase UpFilter[12], proxyId = 5

mosn / mosn

feat: actively sends heartbeat request #2397