RedisShake icon indicating copy to clipboard operation
RedisShake copied to clipboard
verified publisher icon tair-opensource

运行过程中short write退出了，抓包发现工具发了rst。请教这是什么情况呢？

Open holmes1412 opened this issue 2 years ago • 2 comments

问题描述（Issue Description）

使用工具往target迁移，前后三次都出现以下情况（分别跑了20分和40分钟这样）：

运行过程中short write退出了，抓包发现redis-shake在同一时间里：共16个连接，其中11个连接发了rst，5个连接发了fin。

source工具以前有改过并发发送，所以这里是建立多个连接，target是个proxy。

同时，也有其他实例在正常迁移中，target的日志看cost也很短，整体连接数也不高，请求还达不到target的处理瓶颈，因此暂时排除target的问题。

环境信息（Environment）

  • RedisShake 版本（RedisShake Version）： 基于commit: 30a09a8683602ff5d43d2b00576170044a93d544，去年fork过的改动是https://github.com/holmes1412/RedisShake （但目前看和改动的关系不大，没有改过网络相关处理）

日志信息（Logs）

2023-10-11 18:18:18 INF redisWriter succesfully execute
restore timeliness_af2551c1d7cc4499a66775d464034b79
2023-10-11 18:18:18 INF rediswriter succesfully execute : restore c7e94e33d4d39dc4
2023-10-11 18:18:18 INF redisWriter succesfully execute: restore fdd36d3433b2c6ad
2023-10-11 18:18:18 PNC short write
panic: short write
goroutine 77389064 [running]:
github.com/rs/zerolog. (*Logger). Panic. func1 (0xc00045cf50, 0xb)
github.com/rs/[email protected]/log-go:359 +0x4f
github.com/rs/zerolog. (*Event). msg (0xc0003f7800, 0xc00045cf50, 0xb)
github.com/rs/[email protected]/event.go: 156 +0x30c
github.com/rs/zerolog. (*Event) .Msg (sE .)
github.com/rs/[email protected]/event-go:108
github.com/alibaba/RedisShake/internal/log.logFinally(0xc0003f7800, 0x8389c7, 0xb, 0x0, 0x0, 0x0)
github.com/alibaba/RedisShake/internal/log/func.go:71 +0x85
github.com/alibaba/RedisShake/internal/log.Panicf (0x8389c7, 0xb, 0x0, 0x0, 0x0)
github.com/alibaba/RedisShake/internal/log/func.go:27 +0x6d
github.com/alibaba/RedisShake/internal/log.PanicError (0x8b21e0, 0xc00009e040)
github.com/alibaba/RedisShake/internal/log/func.go:31 +0x5a
github.com/alibaba/RedisShake/internal/client. (*Redis). flush (0xc000020600)
github.com/alibaba/RedisShake/internal/client/redis.go:99 +0x5a
github.com/alibaba/RedisShake/internal/client. (*Redis).SendBytes(0xc000020600, 0xc00001600, 0x78, 0x22a8)
github.com/alibaba/RedisShake/internal/client/redis.go:93 +0x6d
github.com/alibaba/RedisShake/internal/writer.(*redisWriter).Write(0xc0000cbaa0, 0xc0003c3b80)
github.com/alibaba/RedisShake/internal/writer/redis.go:54 +0x145
main. main. func2 (0x8b2260, 0xc0000cbaa0, 0xc0003c3b80)
github.com/alibaba/RedisShake/cmd/redis-shake/main.go: 104 +0x3b
created by main.main
github.com/alibaba/RedisShake/cmd/redis-shake/main.go: 103 +0xa25

其他信息（Additional Information）

抓包信息，只抓了rst和fin：

18:18:18.571045 IP REDIS_SHAKE.56674 > TARGET_PROXY: Flags [R.], seq 235610761, ack 1094504067, win 502, options [nop,nop,TS val 1820961107 ecr 396069719], length 0
18:18:18.571060 IP REDIS_SHAKE.56672 > TARGET_PROXY: Flags [R.], seq 1327860178, ack 1820459564, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571074 IP REDIS_SHAKE.56670 > TARGET_PROXY: Flags [R.], seq 2729781562, ack 2709660229, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571077 IP REDIS_SHAKE.56668 > TARGET_PROXY: Flags [F.], seq 4037971275, ack 80903814, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571085 IP REDIS_SHAKE.56666 > TARGET_PROXY: Flags [R.], seq 2720328617, ack 709714997, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571088 IP REDIS_SHAKE.56660 > TARGET_PROXY: Flags [R.], seq 3507311602, ack 1982479562, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571101 IP REDIS_SHAKE.56662 > TARGET_PROXY: Flags [R.], seq 4148086157, ack 420481503, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571101 IP REDIS_SHAKE.56656 > TARGET_PROXY: Flags [F.], seq 1258641333, ack 89228415, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571104 IP REDIS_SHAKE.56664 > TARGET_PROXY: Flags [R.], seq 1708998558, ack 4262801482, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571109 IP REDIS_SHAKE.56658 > TARGET_PROXY: Flags [R.], seq 727608699, ack 3470690562, win 502, options [nop,nop,TS val 1820961107 ecr 396069719], length 0
18:18:18.571126 IP TARGET_PROXY > REDIS_SHAKE.56668: Flags [F.], seq 1, ack 1, win 165, options [nop,nop,TS val 396069723 ecr 1820961107], length 0
18:18:18.571127 IP REDIS_SHAKE.56652 > TARGET_PROXY: Flags [R.], seq 2971647696, ack 4096582380, win 502, options [nop,nop,TS val 1820961107 ecr 396069719], length 0
18:18:18.571131 IP REDIS_SHAKE.56644 > TARGET_PROXY: Flags [F.], seq 1941362022, ack 329866302, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571135 IP REDIS_SHAKE.56648 > TARGET_PROXY: Flags [F.], seq 1538855307, ack 2859857104, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571135 IP REDIS_SHAKE.56650 > TARGET_PROXY: Flags [R.], seq 724963505, ack 3472601846, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571137 IP TARGET_PROXY > REDIS_SHAKE.56656: Flags [F.], seq 1, ack 1, win 165, options [nop,nop,TS val 396069723 ecr 1820961107], length 0
18:18:18.571137 IP REDIS_SHAKE.56654 > TARGET_PROXY: Flags [F.], seq 3017053416, ack 2234812204, win 502, options [nop,nop,TS val 1820961107 ecr 396069718], length 0
18:18:18.571140 IP REDIS_SHAKE.56646 > TARGET_PROXY: Flags [R.], seq 3460886833, ack 91555643, win 502, options [nop,nop,TS val 1820961107 ecr 396069719], length 0
18:18:18.571182 IP TARGET_PROXY > REDIS_SHAKE.56644: Flags [F.], seq 1, ack 1, win 165, options [nop,nop,TS val 396069723 ecr 1820961107], length 0
18:18:18.571187 IP TARGET_PROXY > REDIS_SHAKE.56654: Flags [F.], seq 1, ack 1, win 2186, options [nop,nop,TS val 396069723 ecr 1820961107], length 0
18:18:18.571188 IP TARGET_PROXY > REDIS_SHAKE.56648: Flags [F.], seq 1, ack 1, win 165, options [nop,nop,TS val 396069723 ecr 1820961107], length 0

holmes1412 avatar Oct 11 '23 11:10 holmes1412

可能是 select 的问题：

  1. 是不是用到了 select，之前有个修复 #619，确定你已经移植了。
  2. #619 忘记兼容 pipeline_count_limit 了，试试再附上这样改：
--- a/internal/writer/redis.go
+++ b/internal/writer/redis.go
@@ -56,12 +56,12 @@ func (w *redisWriter) Write(e *entry.Entry) {
 }
 
 func (w *redisWriter) switchDbTo(newDbId int) {
-       w.client.Send("select", strconv.Itoa(newDbId))
        w.DbId = newDbId
        w.chWaitReply <- &entry.Entry{
                Argv:    []string{"select", strconv.Itoa(newDbId)},
                CmdName: "select",
        }
+       w.client.Send("select", strconv.Itoa(newDbId))
 }

suxb201 avatar Oct 12 '23 01:10 suxb201

感谢回复，我们没有select命令，目前还是rdb文件的restore命令遇到的问题～

holmes1412 avatar Oct 12 '23 10:10 holmes1412