golang 做linux服务每天挂一次

背景

我在做的一个内网穿透项目,目前在线上运行。每间隔1天就掉线几次,基本上发生在运行6个小时的时候,使用长连接的用户就给我反馈掉线了。有时候是半夜告诉我,我TM都睡觉了叫我起来修bug。

好在linux上部署了服务自动启动,如果服务crach了,会自动重启。

也就是这些问题困扰了我很久一直没有解决,今天终于有时间搞分析了。由于crash的时候日志这块输出得不完整导致软件日志不能正常看到错误信息。

于是我使用了一个命令顺利找到了问题点

journalctl  -u ngrokd.service  --since="2022-09-23 06:50:00" 

上面这段命令主要是查询ngrokd服务指定时间点的日志上下文。

ngrok协议攻击

这个可以说我是发现了它的问题,一些ngrokd通道的管理者或许经常遇到ngrokd莫名的掉线,所以才有frp的流行,ngrok不太主流的原因。

ngrok协议攻击原理:

ngrok协议 前面8个字节 是int64 类型 描述后续的内容长度。

如果前面8个字节发送了很大的数字,那么在创建缓冲区的时候他没有校验数据范围。直接

var sz int64 = 0 // 给个初始值
err = binary.Read(c, binary.LittleEndian, &sz)
if err != nil {
    return
}
 // sz的值足够大的化,ngrok直接内存溢出毫无疑问的。
buffer = make([]byte, sz)

线上通道服务日志

Sep 23 06:50:22 cloud-service ngrokd[5136]: [06:50:22 CST 2022/09/23] [INFO] (bullet/ngrok/log.(*PrefixLogger).Info:103) [tun:16597eb0]  failed with error runtime error: makeslice: len out of range: goroutine 8
Sep 23 06:50:22 cloud-service ngrokd[5136]: runtime/debug.Stack()
Sep 23 06:50:22 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/debug/stack.go:24 +0x65
Sep 23 06:50:22 cloud-service ngrokd[5136]: bullet/ngrok/server.tunnelListener.func1.1.1()
Sep 23 06:50:22 cloud-service ngrokd[5136]: /opt/build/ngrok/ngrok/server/main.go:89 +0x58
Sep 23 06:50:22 cloud-service ngrokd[5136]: panic({0x6f3b60, 0x7b1bd0})
Sep 23 06:50:22 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/panic.go:1038 +0x215
Sep 23 06:50:22 cloud-service ngrokd[5136]: bullet/ngrok/msg.readMsgShared({0x7c3d90, 0xc0001b6300})
Sep 23 06:50:22 cloud-service ngrokd[5136]: /opt/build/ngrok/ngrok/msg/conn.go:24 +0x285
Sep 23 06:50:22 cloud-service ngrokd[5136]: bullet/ngrok/msg.ReadMsg({0x7c3d90, 0xc0001b6300})
Sep 23 06:50:22 cloud-service ngrokd[5136]: /opt/build/ngrok/ngrok/msg/conn.go:41 +0x25
Sep 23 06:50:22 cloud-service ngrokd[5136]: bullet/ngrok/server.tunnelListener.func1.1({0x7c3d90, 0xc0001b6300})
Sep 23 06:50:22 cloud-service ngrokd[5136]: /opt/build/ngrok/ngrok/server/main.go:96 +0x85
Sep 23 06:50:22 cloud-service ngrokd[5136]: created by bullet/ngrok/server.tunnelListener.func1
Sep 23 06:50:22 cloud-service ngrokd[5136]: /opt/build/ngrok/ngrok/server/main.go:85 +0x4f
Sep 23 06:50:31 cloud-service ngrokd[5136]: [06:50:31 CST 2022/09/23] [INFO] (bullet/ngrok/conn.Listen.func1:113) New conn[tun:7b44c949]->tuns from 117.187.173.91:35116
Sep 23 06:50:39 cloud-service ngrokd[5136]: [06:50:39 CST 2022/09/23] [WARN] (bullet/ngrok/log.(*PrefixLogger).Warn:107) [tun:7b44c949] Failed to read message: unexpected EOF
Sep 23 06:50:41 cloud-service ngrokd[5136]: [06:50:41 CST 2022/09/23] [INFO] (bullet/ngrok/conn.Listen.func1:113) New conn[tun:14ad9641]->tuns from 117.187.173.91:35510
Sep 23 06:50:41 cloud-service ngrokd[5136]: fatal error: runtime: out of memory
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime stack:
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.throw({0x749c74, 0x1ee00400000})
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/panic.go:1198 +0x71
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.sysMap(0xc002000000, 0x42aba0, 0x7f156b86ad58)
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/mem_linux.go:169 +0x96
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.(*mheap).grow(0x9db060, 0xf700009)
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/mheap.go:1393 +0x225
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.(*mheap).allocSpan(0x9db060, 0xf700009, 0x0, 0x1)
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/mheap.go:1179 +0x165
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.(*mheap).alloc.func1()
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/mheap.go:913 +0x69
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.systemstack()
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/asm_amd64.s:383 +0x49
Sep 23 06:50:41 cloud-service ngrokd[5136]: goroutine 89382 [running]:
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.systemstack_switch()
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/asm_amd64.s:350 fp=0xc0000f1cd0 sp=0xc0000f1cc8 pc=0x464480
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.(*mheap).alloc(0xc00011e380, 0x7bc000, 0x28, 0x0)
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/mheap.go:907 +0x73 fp=0xc0000f1d20 sp=0xc0000f1cd0 pc=0x426ed3
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.(*mcache).allocLarge(0x0, 0x1ee00010316, 0x0, 0x1)
Sep 23 06:50:41 cloud-service ngrokd[5136]: /opt/sdk/go/src/runtime/mcache.go:227 +0x89 fp=0xc0000f1d80 sp=0xc0000f1d20 pc=0x417da9
Sep 23 06:50:41 cloud-service ngrokd[5136]: runtime.mallocgc(0x1ee00010316, 0x6e1b20, 0x1)


报错的核心:

fatal error: runtime: out of memory

TMD java的内存溢出,我在golang复现了。。。
开个玩笑,考虑到成本服务器的内存2G,跑了mysql、redis 还有个java程序。因此内存还是比较吃紧的。

详细分析发现在下面这个函数里面,读取8083端口请求的ngrok协议方式有点端倪。

func readMsgShared(c conn.Conn) (buffer []byte, err error) {}

服务器端没有校验数据 包的大小,因此ngrok 通道端口的前面8个字节我写一个max值过去,必然导致ngrokd服务中断。

服务掉线问题已经困扰我很久了。。。

修复方法

conn/conn.go文件寻找readMsgShared函数


var msgMaxSize = int64(1024 * 10) // 最大的消息数据包 func readMsgShared(c conn.Conn) (buffer []byte, err error) { c.GetLogger().Fine("Waiting to read message") var sz int64 = 0 // 给个初始值 err = binary.Read(c, binary.LittleEndian, &sz) if err != nil { return } if sz <= 0 { // 有些服务器发送的【垃圾包】,读取出来是负数,导致异常,这里做个判断,最好还是增加个大包判断,屏蔽掉 c.GetLogger().Warn("Reading message with length: %d", sz) return nil, errors.New("[msg.read] makeslice: len out of range buffer[" + string(sz) + "]") } // 判断数据包超过额定大小, if sz > msgMaxSize { c.GetLogger().Warn("Reading message with length: %d", sz) return nil, errors.New("[msg.read] makeslice: len out of Max range buffer[" + string(sz) + "]") } c.GetLogger().Fine("Reading message with length: %d", sz) buffer = make([]byte, sz) n, err := c.Read(buffer) c.GetLogger().Fine("Read message %s", buffer) if err != nil { return } if int64(n) != sz { err = errors.New(fmt.Sprintf("Expected to read %d bytes, but only read %d", sz, n)) return } return }

结束语

分析问题还是需要根据日志啦啊,虽然在前期的时候已经怀疑是协议攻击了。但是我没有最大包处理,选择了保守疗法。因为我不知道最大的数据包大小应该如何 定义。

目前也初步定义长度为1024 * 10

超过这个大小,直接报错。

来源: 雨林博客(www.yl-blog.com)