从Gitlab CI启动tomcat的坑，到tty与进程组

问题症状

为了做一个Spring MVC的Java Web项目的CI，我写了个编译war包后启动tomcat的脚本。CI脚本很简单：

1
2
3
4
5
6
sit:
   script:
     - cd /root/
     - ./test-publish-xxx-sit.sh
   only:
     - develop

SSH到服务器手工执行脚本一切顺利。但通过gitlab-runner执行脚本，到最后一步执行./startup.sh启动tomcat的时候，遇到了两个很奇怪的现象：

  • 和SSH下执行./startup.sh不同，没有打印环境变量（例如Using CATALINA_BASE:）。只显示了最后一句“Tomcat started.”
  • 虽然打印了“Tomcat started.”，tomcat却没有正常启动。catalina.out里完全没有启动日志信息
    尝试过从权限和执行用户方向排查，都没有找到原因。

解决方法

在gitlab的论坛看到有人回答需要部署为linux的service，或者加个setsid，才能启动。结果证明这两种方式都是可行的解决方案。

问题是解决了。但疑问还是没解决：

  • 为何同样的用户执行，打印的日志不一样？
  • 为何普通脚本可以成功执行，但执行tomcat的启动脚本startup.sh的时候就会出问题？
    前一个问题和tty有关，后一个问题和Linux进程组有关。

引申1：tty

以前在python脚本排查的时候遇到过一个诡异的问题：sudo -i切换root下时可以正常执行的命令，到su - root切换到root下就执行失败了。最终发现问题和PATH环境变量有关。但这次明显不是这个原因，要不然也不会打印“Tomcat started.”的日志。
在翻了tomcat的catalina.sh后，找到了这段：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
# Bugzilla 37848: only output this if we have a TTY
if [ $have_tty -eq 1 ]; then
  echo "Using CATALINA_BASE:   $CATALINA_BASE"
  echo "Using CATALINA_HOME:   $CATALINA_HOME"
  echo "Using CATALINA_TMPDIR: $CATALINA_TMPDIR"
  if [ "$1" = "debug" ] ; then
    echo "Using JAVA_HOME:       $JAVA_HOME"
  else
    echo "Using JRE_HOME:        $JRE_HOME"
  fi
  echo "Using CLASSPATH:       $CLASSPATH"
  if [ ! -z "$CATALINA_PID" ]; then
    echo "Using CATALINA_PID:    $CATALINA_PID"
  fi
fi

而have_tty这个变量是执行tty后的结果：

1
2
3
4
have_tty=0
if [ "`tty`" != "not a tty" ]; then
    have_tty=1
fi

SSH的时候执行tty的结果是/dev/pts/{数字}，而gitlab-runner执行的结果是not a tty。
tty的含义可以参见文末的参考资料，可以简单理解为终端。gitlab与gitlab-runner通信的时候是通过https请求，没有终端。所以按照tomcat启动脚本的逻辑不会输出环境变量。

引申2：进程组

排查时最疑惑的点在于：输出日志里打印了“Tomcat started.”，表示tomcat的启动脚本已经跑完了。但为何tomcat的进程不存在，catalina.out里也完全没有相关日志？
要解释这个问题，需要从进程组开始解释。

当开两个SSH连到Linux服务器上，执行ps auxf命令，可以得到如下结果：

1
2
3
4
5
6
7
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root      1101  0.0  0.1 106084  4136 ?        Ss   Mar20   0:00 /usr/sbin/sshd -D
root     14590  0.0  0.1 145788  5244 ?        Ss   23:00   0:00  \_ sshd: root@pts/0
root     14594  0.0  0.0 115440  2028 pts/0    Ss+  23:00   0:00  |   \_ -bash
root     14631  3.2  0.1 145788  5240 ?        Ss   23:23   0:00  \_ sshd: root@pts/1
root     14635  0.2  0.0 115436  2084 pts/1    Ss   23:23   0:00      \_ -bash
root     14651  0.0  0.0 151244  1928 pts/1    R+   23:23   0:00          \_ ps auxf

这个界面展现了ssh相关的进程和进程间的父子关系。
TTY那一列中的pts/0和pts/1分别对应两个SSH终端。sshd对应下图中的ssh server。 bash是sshd进程创建的子进程。
当在第二个终端上通过bash执行ps auxf命令时，由bash进程创建ps auxf子进程。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
+----------+       +------------+
| Keyboard |------>|            |
+----------+       |  Terminal  |
| Monitor  |<------|            |
+----------+       +------------+
                         |
                         |  ssh protocol
                         |
                         ↓
                   +------------+
                   |            |
                   | ssh server |--------------------------+
                   |            |           fork           |
                   +------------+                          |
                       |   ↑                               |
                       |   |                               |
                 write |   | read                          |
                       |   |                               |
                 +-----|---|-------------------+           |
                 |     |   |                   |           ↓
                 |     ↓   |      +-------+    |       +-------+
                 |   +--------+   | pts/0 |<---------->| shell |
                 |   |        |   +-------+    |       +-------+
                 |   |  ptmx  |<->| pts/1 |<---------->| shell |
                 |   |        |   +-------+    |       +-------+
                 |   +--------+   | pts/2 |<---------->| shell |
                 |                +-------+    |       +-------+
                 |    Kernel                   |
                 +-----------------------------+

状态列STAT中的加号“+”表示前台进程（可以通过man ps命令查看各种状态的详情）。第一个大S表示进程在中断睡眠，大R表示运行中。第二个小s表示是会话的session leader。
每个SSH窗口对应一个session会话。一个会话可以由多个进程组构成。一个进程组成为会话的前台工作(foreground)，而其他的进程组是后台工作(background)。
我们也可以执行命令的时候添加&，使进程组成为后台进程组。

在熟悉了这些知识后，我们来回顾一下我们的gitlab-runner脚本。
我们是通过./test-publish-xxx-sit.sh命令来调用脚本。在我修改之前，脚本是通过调用./startup.sh启动tomcat。
./xxx.sh是fork调用，即从当前进程创建一个子进程来执行脚本。（另外两种是source和exec）
startup.sh fork调用了catalina.sh。而catalina.sh通过

1
java 【省略参数】 org.apache.catalina.startup.Bootstrap start 【省略参数】 &

这条命令启动了tomcat。总结一下，父子关系大致如下：

1
2
3
4
5
6
/usr/lib/gitlab-runner/gitlab-runner run
 \_ /bin/bash
     \_ /bin/sh ./test-publish-xxx-sit.sh
         \_ /bin/sh ./startup.sh
             \_ /bin/sh ./catalina.sh
                 \_ /usr/bin/java org.apache.catalina.startup.Bootstrap start

通过gitlab runner的源代码可以看到，gitlab runner在执行完每条命令，对该命令的进程组执行KillProcessGroup操作。

1
2
3
4
5
6
7
select {
case err = <-waitCh:
	return err

case <-cmd.Context.Done():
	return s.killAndWait(c, waitCh)
}
1
2
3
4
5
6
7
8
9
10
11
func (s *executor) killAndWait(cmd *exec.Cmd, waitCh chan error) error {
	for {
		s.Debugln("Aborting command...")
		helpers.KillProcessGroup(cmd)
		select {
		case <-time.After(time.Second):
		case err := <-waitCh:
			return err
		}
	}
}

所以当gitlab-runner执行完/bin/sh ./test-publish-xxx-sit.sh这个命令，杀掉进程组后，tomcat进程也被跟着一起杀掉了。
这也解释了为什么tomcat部署为服务和setsid命令会起效。
当setsid后，tomcat的启动脚本进程和原父进程脱离关系，成为了孤儿进程。
当部署为服务后，tomcat成为了守护进程，自然也和gitlab-runner的进程没有了关系。

后记

想起来当初刚开始玩Spring Boot的时候，在Linux服务器上用java -jar加上&后台启动应用后，过了两小时后进程被自动杀掉了。一开始还以为是Spring Boot的Bug。。。在总结了发生规律后，才发现是和SSH session有关。改为了nohup+&启动后问题解决。之后又改为优雅一些的注册为系统服务。但对原理的不甚了了，最终还是导致这次栽坑了。
知其然，知其所以然。
不过这次相比之前也有一点改进：总算储备的shell知识积累到有胆子去翻tomcat启动脚本了。这次顺带解答了我之前的一个疑惑：为什么启动tomcat的启动命令./startup.sh时不用后面加&。这是因为启动脚本里已经带了：

1
2
3
4
5
6
7
8
eval \{ $_NOHUP "\"$_RUNJAVA\"" "\"$LOGGING_CONFIG\"" $LOGGING_MANAGER $JAVA_OPTS $CATALINA_OPTS \
  -D$ENDORSED_PROP="\"$JAVA_ENDORSED_DIRS\"" \
  -classpath "\"$CLASSPATH\"" \
  -Dcatalina.base="\"$CATALINA_BASE\"" \
  -Dcatalina.home="\"$CATALINA_HOME\"" \
  -Djava.io.tmpdir="\"$CATALINA_TMPDIR\"" \
  org.apache.catalina.startup.Bootstrap "$@" start \
  2\>\&1 \& echo \$! \>\"$catalina_pid_file\" \; \} $catalina_out_command "&"

但NOHUP参数默认不加，所以还是会被父进程杀掉。

参考资料

Attempting to restart tomcat 8 with gitlab-runner, pid file created, log empty, server not started - Server Fault
感谢作者解决问题后补充的回答。要不然我还钻在Google里，想不到去看tomcat启动脚本和gitlab-runner的源代码。

Linux TTY/PTS概述 - Linux程序员 - SegmentFault 思否
非常生动形象地用ASCII图展现了TTY的原理。

Linux 技巧：让进程在后台可靠运行的几种方法
解释了为什么setsid和disown命令可以起效。

终端断开导致Tomcat进程被kill问题分析 | El Psy Congroo
tomcat的另一种非正常死法，通过进程组实验的方式解释了原理。我没有产生过作者那样的疑问，主要是个人习惯太好了，从来不会做不退出脚本就直接关闭终端的行为（雾

本文永久链接 [ https://galaxyyao.github.io/2019/03/28/Gitlab-CI-pipeline启动tomcat中遇到的坑/ ]