今天线上同事找到我说,发现有一个PostgreSQL实例,出现了多个postmaster进程,时不时报出连通性告警,无法连接,这个是怎么一回事呢?什么情况下我们会看到有多个postmaster进程?
首先,postmaster我们很熟悉,是PostgreSQL的总控进程,也是所有进程的父进程,会负责一些初始化、异常处理(实例出现错误的时候,自动完成恢复)、信号处理等等,另外最为熟知的,就是请求来了,postmaster会负责先进行身份验证,然后创建连接。
通常情况下,我们看到的现象一般都是类似下面的情况,即
1.一个postmaster进程,以 -D 标识2.多个后台子进程,如autovacuum、checkpointer等3.多个后台backend process,即服务客户端的进程,比如此例的idle
[postgres@xiongcc ~]$ ps -axjf | grep postgres
1 10799 10799 10799 ? -1 Ss 1000 0:00 /usr/pgsql-14/bin/postgres -D pgdata
10799 10800 10800 10800 ? -1 Ss 1000 0:00 \_ postgres: logger
10799 10802 10802 10802 ? -1 Ss 1000 0:00 \_ postgres: checkpointer
10799 10803 10803 10803 ? -1 Ss 1000 0:00 \_ postgres: background writer
10799 10804 10804 10804 ? -1 Ss 1000 0:00 \_ postgres: walwriter
10799 10805 10805 10805 ? -1 Ss 1000 0:00 \_ postgres: autovacuum launcher
10799 10806 10806 10806 ? -1 Ss 1000 0:00 \_ postgres: stats collector
10799 10807 10807 10807 ? -1 Ss 1000 0:00 \_ postgres: logical replication launcher
10799 10827 10827 10827 ? -1 Ss 1000 0:00 \_ postgres: postgres postgres [local] idle
10799 10958 10958 10958 ? -1 Ss 1000 0:00 \_ postgres: postgres postgres [local] idle
10799 10960 10960 10960 ? -1 Ss 1000 0:00 \_ postgres: postgres postgres [local] idle
但是今天的线上案例情况是,有很多个postmaster进程,我通过本地复现模拟出来了,现象类似如下,存在多个postmaster进程,可以看到,10997这个进程是10799的子进程,这个和我们日常看到的现象大相径庭,那么什么情况会导致这样的现象呢?
[postgres@xiongcc ~]$ ps -axjf | grep postgres
1 10799 10799 10799 ? -1 Ss 1000 0:00 /usr/pgsql-14/bin/postgres -D pgdata
10799 10800 10800 10800 ? -1 Ss 1000 0:00 \_ postgres: logger
10799 10802 10802 10802 ? -1 Ss 1000 0:00 \_ postgres: checkpointer
10799 10803 10803 10803 ? -1 Ss 1000 0:00 \_ postgres: background writer
10799 10804 10804 10804 ? -1 Ss 1000 0:00 \_ postgres: walwriter
10799 10805 10805 10805 ? -1 Ss 1000 0:00 \_ postgres: autovacuum launcher
10799 10806 10806 10806 ? -1 Ss 1000 0:00 \_ postgres: stats collector
10799 10807 10807 10807 ? -1 Ss 1000 0:00 \_ postgres: logical replication launcher
10799 10997 10799 10799 ? -1 t 1000 0:00 \_ /usr/pgsql-14/bin/postgres -D pgdata
[postgres@xiongcc ~]$ ps -ef | grep pgdata
postgres 10799 1 0 12:42 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 10997 10799 0 13:55 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 11034 10051 0 14:01 pts/2 00:00:00 grep --color=auto pgdata
线上这个实例每隔一会,通过ps查看进程,就有大量的postmaster进程,但是过了一会,就没了,想通过pg_stat_activity看也是大量的冗余信息,那么抓一下堆栈信息
#!/bin/bash
for pid in `ps -aux | grep pg5432 | cut -d '' -f 2 | head -n 5`
do
pstack $pid >> pgstack.txt
done
通过脚本,抓一下进程的堆栈信息
#0 0x00007fdd6d34b291 in fork () from /lib64/libc.so.6
#1 0x00000000006ba2e1 in fork_process () at fork_process.c:61
#2 0x000000000047e2ef in BackendStartup (port=0x1c3b690) at postmaster.c:4013
#3 ServerLoop () at postmaster.c:1707
#4 0x00000000006c5809 in PostmasterMain (argc=argc@entry=3,argv=argv@entry=0x1c07f80) at postmaster.c:1380
#5 0x000000000047f24b in main (argc=3,argv=0x1c07f80) at main.c:228
抓了几次堆栈,可以看到,大量这种类似的postmaster进程,堆栈是一样的,最顶层都是fork(),在PostmasterMain()中进入了BackendStartup(),该函数用于创建后台进程
回顾一下,PostgreSQL端口监听然后建立连接的一个过程
main->PostmasterMain->ServerLoop,postmaster进程启动后,然后会进入ServerLoop方法,无限循环等待监听。
PostmasterMain()
|->ServerLoop()
|->initMasks()
|->for(;;)
|->select() <--监听端口
|->ConnCreate() <--创建connection相关的数据结构
|->BackendStartup() <--建立后端进程backend process
|->PostmasterRandom()
|->canAcceptConnections()
|->fork_process()
|->InitPostmasterChild()
|->ClosePostmasterPorts()
|->BackendInitialize()
|->ProcessStartupPacket()
|->BackendRun()
|->PostgresMain()
|->ConnFree() <--释放connection相关的数据结构
PostmasterMain()
|->ServerLoop()
|->for(;;)
|->BackendStartup() <--建立后端进程backend process
|->BackendInitialize()
|->ProcessStartupPacket()
|->processCancelRequest()
|->signal_child(bp->pid, SIGINT)
BackendStartup就是在创建后台进程,看下这个函数里面做了什么,fork_process()里面就是调用了一下操作系统提供的fork()
/*
* BackendStartup -- start backend process
*
* returns: STATUS_ERROR if the fork failed, STATUS_OK otherwise.
*
* Note: if you change this code, also consider StartAutovacuumWorker.
*/
static int
BackendStartup(Port *port)
{
...
...
#ifdef EXEC_BACKEND
pid = backend_forkexec(port);
#else /* !EXEC_BACKEND */
pid = fork_process();
if (pid == 0) /* child */
{
free(bn);
/* Detangle from postmaster */
InitPostmasterChild();
/* Close the postmaster's sockets */
ClosePostmasterPorts(false);
/* Perform additional initialization and collect startup packet */
BackendInitialize(port);
/* And run the backend */
BackendRun(port);
}
#endif /* EXEC_BACKEND */
...
...
}
大致流程如下:
1.当一个backend启动之后,我们就可以脱离postmaster,把后面的一切交给backend自己处理了,backend在子进程中作的第一件事是清理不需要的资源。2.InitPostmasterChild()就是用来初始化backend进程,将IsUnderPostmaster设置为true,也就是postmaster的子进程,初始化一些全局变量,例如MyProcPid(进程id),MyStartTime(进程开始时间),初始化一个进程锁等3.然后调用ClosePostmasterPorts()关闭此时不需要的文件描述符,因为进程是从postmaster复制出来的,所以,postmaster上的一些未关闭的socket需要关闭。然后调用BackendInitialize做进一步的初始化,并处理startup package。4.最后,调用BackendRun()真正的运行这个backend,backendrun函数只是一个外壳,他只是切换了内存上下文到topMemoryContex。
那么这里,我们可以得出一些关键信息了,通过fork_process() -> fork() fork了子进程,但是这一步,还没有做其他的动作,仅仅是操作系统层面fork了一个子进程,那么我们在这里打断点,应该可以看到两个postmaster进程,试一下。
[postgres@xiongcc ~]$ ps -ef | grep pgdata
postgres 11950 1 9 16:38 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 11960 11696 0 16:38 pts/5 00:00:00 grep --color=auto pgdata
postmaster主进程的pid是11950
[postgres@xiongcc ~]$ gdb postgres 11950
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-120.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/pgsql-14/bin/postgres...done.
Attaching to program: /usr/pgsql-14/bin/postgres, process 11950
Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Loaded symbols for /lib64/libpthread.so.0
Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/librt.so.1
Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libdl.so.2
Reading symbols from /lib64/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libm.so.6
Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libc.so.6
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Reading symbols from /usr/pgsql-14/lib/pg_rewrite.so...done.
Loaded symbols for /usr/pgsql-14/lib/pg_rewrite.so
Reading symbols from /usr/pgsql-14/lib/pg_stat_statements.so...done.
Loaded symbols for /usr/pgsql-14/lib/pg_stat_statements.so
Reading symbols from /lib64/libnss_files.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libnss_files.so.2
0x00007fc40c4abbb3 in __select_nocancel () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.17-157.el7_3.5.x86_64
另外,我们是需要给自己打个断点,让它卡在fork()的地方,fork()会涉及到子进程
在2.5.60版Linux内核及以后,GDB对使用fork/vfork创建子进程的程序提供了follow-fork-mode选项来支持多进程调试:
follow-fork-mode的用法为:set follow-fork-mode [parent|child]
1.parent:调试父进程,子进程不受影响2.child:调试子进程,父进程不受影响
我们需要调试子进程,所以在启动GDB后,set follow-fork-mode child
(gdb) set follow-fork-mode child
(gdb) b InitPostmasterChild
Breakpoint 1 at 0xa8b1e7: file miscinit.c, line 95.
(gdb) info b
Num Type Disp Enb Address What
1 breakpoint keep y 0x0000000000a8b1e7 in InitPostmasterChild at miscinit.c:95
新开一个窗口,psql登录会卡住
[postgres@xiongcc ~]$ psql
---此处夯住
继续continue,可以看到,这里就fork了一个新的进程
(gdb) c
Continuing.
[Attaching after process 11967 fork to child process 11967]
[New inferior 2 (process 11967)]
[Detaching after fork from parent process 11950]
[Inferior 1 (process 11950) detached]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
[Switching to Thread 0x7fc40d2b9740 (LWP 11967)]
Breakpoint 1, InitPostmasterChild () at miscinit.c:95
95 IsUnderPostmaster = true; /* we are a postmaster subprocess now */
再次查看进程,果然,出现了两个postmaster进程
[postgres@xiongcc ~]$ ps -ef | grep postgres | egrep -v "su|ps|bash|grep"
postgres 11426 11105 0 15:14 pts/3 00:00:00 gdb postgres 11228
postgres 11950 1 0 16:38 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 11951 11950 0 16:38 ? 00:00:00 postgres: logger
postgres 11953 11950 0 16:38 ? 00:00:00 postgres: checkpointer
postgres 11954 11950 0 16:38 ? 00:00:00 postgres: background writer
postgres 11955 11950 0 16:38 ? 00:00:00 postgres: walwriter
postgres 11956 11950 0 16:38 ? 00:00:00 postgres: autovacuum launcher
postgres 11957 11950 0 16:38 ? 00:00:00 postgres: stats collector
postgres 11958 11950 0 16:38 ? 00:00:00 postgres: logical replication launcher
postgres 11961 11609 0 16:38 pts/0 00:00:00 gdb postgres 11950
postgres 11967 11950 0 16:38 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
[postgres@xiongcc ~]$ ps -ef | grep pgdata
postgres 11950 1 0 16:38 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 11967 11950 0 16:38 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 11975 11696 0 16:40 pts/5 00:00:00 grep --color=auto pgdata
继续continue,就只剩一个postmaster进程了,之前的postmaster变成了我们熟知的形态
(gdb) c
Continuing.
[postgres@xiongcc ~]$ psql
psql (14rc1)
Type "help" for help.
postgres=# select pg_backend_pid();
pg_backend_pid
----------------
11967
(1 row)
[postgres@xiongcc ~]$ ps -ef | grep postgres | egrep -v "su|ps|bash|grep"
postgres 11426 11105 0 15:14 pts/3 00:00:00 gdb postgres 11228
postgres 11950 1 0 16:38 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 11951 11950 0 16:38 ? 00:00:00 postgres: logger
postgres 11953 11950 0 16:38 ? 00:00:00 postgres: checkpointer
postgres 11954 11950 0 16:38 ? 00:00:00 postgres: background writer
postgres 11955 11950 0 16:38 ? 00:00:00 postgres: walwriter
postgres 11956 11950 0 16:38 ? 00:00:00 postgres: autovacuum launcher
postgres 11957 11950 0 16:38 ? 00:00:00 postgres: stats collector
postgres 11958 11950 0 16:38 ? 00:00:00 postgres: logical replication launcher
postgres 11961 11609 0 16:38 pts/0 00:00:00 gdb postgres 11950
postgres 11967 11950 0 16:38 ? 00:00:00 postgres: postgres postgres [local] idle
[postgres@xiongcc ~]$ ps -ef | grep pgdata
postgres 11950 1 0 16:38 ? 00:00:00 /usr/pgsql-14/bin/postgres -D pgdata
postgres 11990 11696 0 16:42 pts/5 00:00:00 grep --color=auto pgdata
小结一下
1.当一个连接请求来了之后,postmaster会fork一个新进程,形态和postmaster一样,不过是父子进程2.然后经过一系列的初始化,脱离了postmaster之后,就变成了我们熟知的形态,即postgres: postgres postgres [local] idle
所以,什么情况下会出现这种多个postmaster呢?当有大量连接的时候,PostgreSQL疲于奔命,大量fork连接,连接还处于一个中间态的时候,即还没有脱离postmaster的时候。
通过排查日志,确实发现该实例有大量的连接不断地在连,同时因为密码错误,不断打印认证失败的信息。这种情况,我们可以通过使用auth_delay参数,该参数可以使PostgreSQL在提示认证失败之前暂停一会,这样就防止对数据库密码的穷举攻击。所以,我们会时不时就看到多个postmaster进程。
对于连接相关的错误,大概有这么几种情况
•server closed the connection unexpectedly•SSL SYSCALL error: EOF detected•unexpected EOF on client connection•could not receive data from client: Connection reset by peer•sorry, too many clients already•incomplete startup packet
其中,incomplete startup packet,通常出现在,和PostgreSQL在建立连接进行握手的通信过程中,使用了一些不正确的协议,比如探活、监控程序等,其他几个错误可以参考之前的文章《TCP Keepalive》。
https://segmentfault.com/a/1190000039195234
https://segmentfault.com/a/1190000039193129
https://postgrespro.com/list/thread-id/2371500
https://serverfault.com/questions/151177/postgresql-spawning-a-ridiculous-number-of-postmaster-processes
https://postgrespro.com/list/thread-id/2371500
https://www.jianshu.com/p/8fc05dbf777e
https://wizardforcel.gitbooks.io/100-gdb-tips/content/set-follow-fork-mode-child.html
https://www.cnblogs.com/flying-tiger/p/8761212.html
原文作者:PostgreSQL学徒;如有侵权,请联系管理员删除。