生产环境 Go 并发问题记录

,

Don’t Panic. ——The Hitchhiker’s Guide to Operating Systems

某生产环境升级文件管理器 2.0 后管道服务异常容器停止。检查容器日志发现停止前有大量文件移动失败操作：

1
2
3
4
2024-02-28 14:26:16.426 [INFO] {1f37db2ad3f2b71786569371f5915da7} CopyAndSet 拷贝文件发生异常 error=map[/share/home/***/******/ultralytics-main/datasets/PCB_DATASET_Contrast1/labels/test(4)_20240228142122/test4/01_missing_hole_02_changed.txt:拷贝文件发生异常，原因:bash: -c: line 0: syntax error near unexpected token `('
bash: -c: line 0: `mv /share/home/***/******/ultralytics-main/datasets/PCB_DATASET_Contrast1/labels/test(4)_20240228142122/test4/01_missing_hole_02_changed.txt '/share/home/***/******/ultralytics-main/datasets/PCB_DATASET_Contrast1/labels/test(4)_20240228142122'' Process exited with status 1 /share/home/***/******/ultralytics-main/datasets/PCB_DATASET_Contrast1/labels/test(4)_20240228142122/test4/01_missing_hole_04_changed.txt:拷贝文件发生异常，原因:bash: -c: line 0: syntax error near unexpected token `('
bash: -c: line 0: `mv /share/home/***/******/ultralytics-main/datasets/PCB_DATASET_Contrast1/labels/test(4)_20240228142122/test4/01_missing_hole_04_changed.txt '/share/home/***/******/ultralytics-main/datasets/PCB_DATASET_Contrast1/labels/test(4)_20240228142122'' Process exited with status 1 /share/home/***/******/ultralytics-main/datasets/PCB_DATASET_Contrast1/labels/test(4)_20240228142122/test4/01_missing_hole_18_changed.txt:拷贝文件发生异常，原因:bash: -c: line 0: syntax error near unexpected token `('
bash: -c: line 0: ...

查阅报错位置代码如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
var wg sync.WaitGroup  
for key, value := range sourceFileMap {  
   wg.Add(1)  
   go func(key string, value int) {  
      defer wg.Done()  
      _, errStr, _, err := ssh.Run(fmt.Sprintf("%s '%s' '%s'", operateType[0], key, filepath.ToSlash(targetPath)))  
  
      if err != nil || errStr != "" {  
         errMap[key] = errors.New(fmt.Sprintf("拷贝文件发生异常，原因:%s %s", errStr, err))  
         return  
      }  
   }(key, value)  
}  
wg.Wait()

初步判断 goroutine 的创建超出了系统的线程限制（实际资源耗尽一般不会导致 panic ）

回忆之前看鸟窝博客有类似场景描述，搜了一下找到原文

10个goroutine并发的写同一个map:…大概率会出现panic:…

例子里的日志包含明显提示： fatal error: concurrent map writes

由于 panic 日志打印在 stderr 一般不会记录到日志文件，尝试了 docker logs --tail=80000 og-apus > temp_apus.log 2>&1 可以导出日志回溯：

1
2
3
4
5
6
7
8
9
2024-02-28 14:28:17.012 [INFO] {88fc6b2ff0f2b717a4569371a71d32e2} start... //v2/files/move POST
fatal error: concurrent map writes
fatal error: concurrent map writes

goroutine 10670081 [running]:
og-apus/utility/fileutility.CopyAndSet.func1({0xc001ec2960, 0x97}, 0xc001656718?)
	/opt/jenkins/workspace/og-apus@2/utility/fileutility/utils.go:158 +0x28b
created by og-apus/utility/fileutility.CopyAndSet
	/opt/jenkins/workspace/og-apus@2/utility/fileutility/utils.go:153 +0x234
  • 查看 /var/lib/docker/containers/<container_id>/<container_id>-json.log Docker 日志驱动程序的位置也可以得到上述内容的类似格式

重新检查代码也可以发现并发执行命令异常导致异常结果次数多的情况就会触发 errMap 的并发写操作。

简单加了个 Mutex 锁，用 demo 测试了下基本解决了导致生产环境 panic 的问题：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
var wg sync.WaitGroup  
var mu sync.Mutex  
for key, value := range sourceFileMap {  
   wg.Add(1)  
   go func(key string, value int) {  
      defer wg.Done()  
      _, errStr, _, err := ssh.Run(fmt.Sprintf("%s '%s' '%s'", operateType[0], key, filepath.ToSlash(targetPath)))  
  
      if err != nil || errStr != "" {  
         mu.Lock()  
         errMap[key] = errors.New(fmt.Sprintf("拷贝文件发生异常，原因:%s %s", errStr, err))  
         mu.Unlock()  
         return  
      } 
   }(key, value)  
}  
wg.Wait()

优化方向：

根据选择文件数量无限制增加 gouroutine 并不合理

最佳的 goroutine 数量取决于工作负载类型。如果工作者执行的工作负载是 I/O 密集型，则该值主要取决于外部系统。相反，如果工作负载受 CPU 限制，则最佳 goroutine 数量接近可用线程的数量。
- 100 Go Mistakes and How to Avoid Them

后续可以考虑通过其他方式获取系统资源建立合适大小的工作池。