尧图网站设计 尧图网站设计YAOTU DESIGN
ARTICLE DETAIL

资讯详情

深耕网站设计与一线实操的经验洞察。

PostgreSQL发送IO错误排查:sending to backend解析

PostgreSQL发送IO错误排查:sending to backend解析 用PostgreSQL做开发或者维护的人多半在日志里撞见过“An IO error occurred while sending to the backend”。我第一次和它打交道是在维护一个Java批量同步任务的时候任务跑到一半日志里突然冒出一行PSQLException整个批处理直接中断。当时第一反应是去翻数据库日志结果服务端干干净净连个warning都没有。后来从应用配置、连接池、网络设备一层层查下去才把真正原因找出来。这篇就把这个异常在什么场景下出现、底层是怎么回事、怎么一步步定位、最后怎么处理完整拆开讲一遍。不管你是写业务的开发还是管库的DBA只要你的应用走TCP长连接连PostgreSQL都可能用得上。1. 这个报错到底在说什么1.1 报错发生的典型场景我梳理了一下自己遇到、以及帮别人排查过的案例这个报错出现频率最高的场景有三个基本覆盖了九成以上的线上问题。第一是应用侧的连接池长期空闲后第一次发起查询。比如晚上系统没人用第二天早上第一个请求打过来直接报错。我前同事负责的一个系统就是这样每天早上一上班第一批请求里总有几条报这个错。业务方第一个电话打给DBADBA查了一圈说数据库没毛病最后问题落到了连接池的maxLifetime上。这种情况其实不是数据库挂了而是连接中间某个环节已经被断掉客户端自己却不知道。第二是长时间执行或大数据量交互的任务。批量导数据、报表聚合、大事务提交这类跑很久的操作在中途报“sending to the backend”失败往往意味着服务端或网络侧中途把连接关了。我之前跑一个千万级数据的报表导出跑了大概40分钟眼看快结束了客户端突然报这个错误。后来定位是数据库在做主从切换旧连接被服务端重置应用没有及时感知。第三是在云数据库或远程访问场景下公网、NAT网关这类链路经常出现。连接保持一段时间后中间的网关设备会静默回收空闲连接客户端完全无感知等下一次发数据才发现写不进去。云厂商的SLB、NAT网关对空闲TCP连接的老化时间各不相同短的可能只有一两分钟长的有十分钟如果应用和数据库之间隔了这类设备这个坑几乎必踩。和MySQL对比一下会更直观MySQL的JDBC驱动遇到类似问题常见报错是“Communications link failure”或“The last packet successfully received from the server was … milliseconds ago”而PostgreSQL的JDBC驱动则直接告诉你是“sending to the backend”阶段出了问题。两者底层原因有交集但PG的连接模型和参数体系不太一样排查路径也略有区别。1.2 从协议和连接机制看根因要真正理解这个报错得先明白PostgreSQL的通信模型。PG使用的是基于TCP的明文协议客户端与服务端之间是一个持久化的TCP连接。正常情况下应用每次查询都复用这个连接而不是重新建连接。连接一旦建立两边都不会主动发额外的心跳包除非你显式开启了TCP keepalive。所谓的“an IO error occurred while sending to the backend”拆开看就是客户端正在向服务端写数据但在socket写入时发生了IO错误。底层的Java异常通常还能看到“Broken pipe”或者“Connection reset by peer”之类的caused by。Broken pipe的意思是客户端往一个已经被对端关闭的socket里写数据Connection reset则是对端直接回了RST包。这里有个很多新手容易忽略的细节socket写入失败不一定发生在“发出去”的那一瞬间。TCP是有发送缓冲区的客户端调用write的时候数据可能先进了本地内核缓冲区内核后续尝试发送时才发现连接已经断了然后才给应用返回错误。所以这个报错出现的时间点跟你上一次成功通信之间可能已经隔了很久。这也解释了为什么很多报错出现在“空闲后第一次使用”而不是“正在频繁读写时”。从协议上还有一个视角如果在事务中服务端主动断连客户端通常要等到下一次与服务器交互发送查询或提交事务时才会感知到错误。如果是网络设备静默丢包客户端甚至要等TCP超时重传失败以后才报错。connectTimeout、socketTimeout这些参数决定的就是客户端在什么时间点放弃等待这个后面会单独讲。2. 最常踩的四个坑2.1 连接池里的“僵尸连接”这是出现频率最高的一类。应用普遍会引入连接池HikariCP、Druid、dbcp2连接池为了性能会缓存一批空闲连接。但连接池只知道它把连接给了应用、应用又还回来了它并不知道数据库那边是不是还认这条连接。数据库、操作系统、网络设备并不会无限期维护一条空闲连接。比如Linux系统默认的TCP keepalive时间通常要7200秒2小时才首次探活一些云厂商的SLB/NAT网关对空闲连接的回收时间可能只有300秒左右。如果连接池里的连接空闲超过这个时间中间设备可能直接丢弃这条连接而数据库和客户端两边都没有立刻收到通知。连接池继续把这根“已经死了”的连接返给应用应用一写数据就报IO error。解决思路也很明确让连接池在把连接交给应用之前先确认连接可用同时让连接池里的连接生命周期短于外部设备的回收周期。具体参数我放到第3节讲这里只强调一个理念——连接池不是万能的它默认不检测“远端是否还活着”是需要你显式配置的。很多人以为开启了连接池就一劳永逸实际上连接池只负责复用连接不负责连接的健康管理。2.2 数据库参数提前断开了会话除了外部设备断开连接PostgreSQL本身也可能主动切断连接。两个最容易被踩中的参数是statement_timeout和idle_in_transaction_session_timeout。statement_timeout设置的是单条SQL的最长执行时间超过就取消SQL。这个报错通常伴随“canceling statement due to statement timeout”应用会看到SQL exception但不会直接看到IO error。这个参数往往不是莫名其妙的更多是业务SQL写得太烂或者没有走索引导致的全表扫描把数据库卡死了。更隐蔽的是idle_in_transaction_session_timeout。它的意思是如果客户端打开了一个事务但又不在执行任何SQL处于“事务中空闲”状态超过设定秒数之后服务端直接断开连接。很多应用在连接池里开启了自动提交但也有的框架比如某些ORM会手动begin事务然后因为业务逻辑慢或者等待外部接口事务一直挂着。等它终于想提交时发现连接早被服务端关了。这种断开是服务端主动发起的客户端拿到的是“connection already closed”或者“An IO error”。数据库日志里也会记录“terminating connection due to idle-in-transaction timeout”。如果你在数据库里查不到这类日志只看到IO error那基本可以排除这个参数。顺带说一句很多团队为了防僵尸事务把这个参数设置得很激进比如30秒或60秒结果业务稍微慢一点就中招设置前得想清楚业务特征。2.3 中间网络设备悄悄回收了连接云环境里最常见的坑。数据库可能放在云RDS应用在自己的服务器上两边要走公网或经过SLB/NAT网关。这些网络中间设备出于资源考虑通常会对空闲的TCP连接做老化回收。有的设备回收时会给对端发送FIN或RST但也有的设备就是静默丢包什么都不发。静默丢包最难受因为TCP两端都还认为连接活着实际上链路早就断了。我们团队踩过的例子一个定时任务每5分钟跑一次白天一直正常但每天早上第一次跑的时候必现这个IO error。分析下来夜间没有任务连接空闲了几个小时云网关那边的空闲连接老化时间早就到了。任务一启动连接池取出空闲连接往服务端发SQLsocket写失败任务就崩了。判断这类问题有一个技巧如果你把应用和数据库放在同一内网、同一个VPC绕开公网和负载均衡同一套代码就不再报错那基本可以肯定是中间链路的问题。另外抓包时如果发现只有最后一个数据包之后就没了动静既没有FIN也没有RST等到超时才报错也是网络设备静默丢弃的典型特征。我遇到过最夸张的一个案例问题出在客户公司自己的防火墙策略上安全团队为了防扫描设置了空闲连接回收结果业务侧遭殃还不自知。2.4 数据库进程异常退出连接是服务端和客户端共同维护的如果服务端进程异常退出所有连接也会全部断开。这类原因在日志里会有明显特征比如“server process (pid 12345) was terminated by signal 9: Killed”或“terminating connection because of crash of another server process”。最常见的诱因是内存不足OOM Killer把postgres进程杀了或者数据库未正常关闭直接重启极端情况下也可能和checkpointer等后台进程异常有关系。这个问题和业务代码基本无关但应用侧的表现同样是IO error而且常常是大量连接同时报错不像前几种情况往往是零散几条。排查时不要只盯应用记得看看数据库服务器上的dmesg有没有大量Out of memory的记录以及数据库日志最后几行的状态。如果确认是OOM那不是改连接池能解决的得去查内存分配、shared_buffers设置、系统可用内存甚至要考虑是不是其他进程把内存吃光了。3. 实操排查路径全记录3.1 先查数据库侧的证据遇到这类报错第一步不是去改代码而是先确认数据库当时在干什么。PostgreSQL提供了pg_stat_activity视图可以查看当前所有连接的状态。如果你能把报错时间点对应上就能看到报错前这个连接是什么状态。SELECT datname, usename, application_name, client_addr, state, backend_start, state_change, xact_start, query FROM pg_stat_activity WHERE datname your_database;state字段是关键。如果是idle说明这个连接当时没有在跑查询只是静静地挂在池子里IO error大概率是连接复用时的失效问题。如果是active说明服务端正在执行某条SQL那要去看查询本身有没有问题、有没有长时间执行触发超时。xact_start字段也值得看如果它显示一个很早的时间说明事务挂了很久就要怀疑idle_in_transaction_session_timeout这类参数。数据库日志也很重要。检查log_connections和log_disconnections这两个参数有没有开启开了的话服务端每次收到和断开连接都会写日志。报错时间点如果只有connection received却没有对应的disconnection日志说明服务端进程认为连接还活着但客户端已经写不进去了。这个时候问题多半在网络链路或客户端侧而不是数据库。另外顺带确认一下相关参数当前的值。很多生产库的statement_timeout和idle_in_transaction_session_timeout可能是被之前的人调过的直接SHOW出来看又快又准SHOW statement_timeout; SHOW idle_in_transaction_session_timeout; SHOW tcp_keepalives_idle; SHOW tcp_keepalives_interval; SHOW tcp_keepalives_count;tcp_keepalives三个参数默认都是0意思是沿用操作系统默认值。如果数据库部署在云上或者连接要穿越多层网络强烈建议把这几个参数显式调小下面会给具体值。这一套查下来至少能排除掉一半的原因。3.2 用抓包定位“谁先断开”如果数据库日志里看不到端倪下一步就是用tcpdump抓包搞清楚连接到底是谁断开的。抓包位置最好同时覆盖客户端和服务端两端如果条件不允许至少抓数据库这一侧的包。tcpdump -i eth0 host 数据库IP and port 5432 -w pg_cli.pcap抓一段时间后用Wireshark打开过滤出对应的TCP流重点看挥手阶段。关键判断规则如下如果看到服务端先发FIN客户端随后响应FIN/ACK说明是服务端主动关闭。此时去查服务端日志和参数。如果看到RST包说明对端认为连接异常直接重置。常见于服务端进程崩溃或中间防火墙主动拒绝。如果TCP流里最后一个包之后什么也没有直到客户端重传超时能看到TCP Retransmission说明是中间链路静默丢包。这时要重点检查NAT、SLB、防火墙的老化配置。我见过很多人一上来就怀疑数据库其实抓包一次就能把锅甩给正确的方向。花10分钟抓包比盲目的在代码里加日志强得多。抓包的时候别忘了一点确认应用当时真的在用这个连接别抓到的是其他客户端的无关流量那会干扰判断。3.3 连接池参数核对清单如果确认是连接空闲失效或复用失效那就轮到连接池背锅了。这里针对最常用的三个池子各说一套推荐配置。HikariCP是目前Spring Boot的默认连接池配置参数如下maximumPoolSize: 20 minimumIdle: 5 maxLifetime: 1500000 idleTimeout: 600000 keepaliveTime: 60000 connectionTestQuery: SELECT 1注意几个关键点。maxLifetime一定要小于数据库和网络链路可能断开连接的时间。如果外部设备回收时间是300秒那maxLifetime最多设240秒左右留出余量。keepaliveTime是HikariCP 4.x新增的参数目的是让连接池里的空闲连接每隔一段时间就发一个探测请求防止中间设备回收。connectionTestQuery在某些JDBC驱动版本里可以省略因为可以用JDBC4的Connection.isValid()方法做探测但显式写出来更稳妥。Druid是阿里开源的连接池比较典型的配置minIdle: 5 maxActive: 20 initialSize: 5 testWhileIdle: true testOnBorrow: true timeBetweenEvictionRunsMillis: 60000 minEvictableIdleTimeMillis: 300000 keepAlive: true validationQuery: SELECT 1testOnBorrow每次从池里取连接都会执行一次探测性能有损耗但查错方便。网上很多配置只开testWhileIdle实际效果是空闲连接定期检查如果你需要更严格地把关testOnBorrow可以临时开起来做排查确认问题后可以关掉。Druid的keepAlive参数是告诉连接池保持最小空闲连接同时主动检测无效连接并移除对这类问题很有用不要漏配。Python用户如果用psycopg2/SQLAlchemy其实也有对应的开关。SQLAlchemy的create_engine里有一个叫pool_pre_ping的参数它会在每次从连接池取连接前用SELECT 1检测连接有效性。很多人以为这是给数据库连不上时用的其实它最初的定位就是解决这类空闲连接失效问题engine create_engine( postgresqlpsycopg2://user:passhost:5432/dbname, pool_pre_pingTrue, )如果直接用psycopg2也可以在连接参数里开启libpq的keepalive能力conn psycopg2.connect( hostdbhost, port5432, dbnamemydb, keepalives1, keepalives_idle60, keepalives_interval10, keepalives_count6, )3.4 参数调整与代码改造示例确认原因并针对连接池做了配置后我还有一套配套的调整方案按优先级从高到低排列。第一JDBC URL里显式开启TCP keepalive并设置socketTimeout。对于PostgreSQL JDBC驱动URL可以这样写jdbc:postgresql://dbhost:5432/mydb?tcpKeepAlivetruesocketTimeout600connectTimeout10tcpKeepAlive对应到操作系统层面的TCP keepalive让内核定时探测连接是否真的活着。socketTimeout是socket读超时默认是0表示无限等待。请注意socketTimeout不是连接超时而是建立连接之后的每次读操作超时。对于批量大查询建议给一个合理较大的值比如600秒避免长查询因为读超时被中断同时又不至于让应用无限等下去。第二在数据库侧调整tcp keepalive参数。如果你有权限改数据库配置建议至少在集群级别设置ALTER SYSTEM SET tcp_keepalives_idle 60; ALTER SYSTEM SET tcp_keepalives_interval 10; ALTER SYSTEM SET tcp_keepalives_count 6;上面的含义是连接空闲60秒后开始发keepalive探测包每10秒发一次连续6次没响应就判定连接失效。这样一个连接最长120秒左右就能感知到对端死掉比系统默认的2小时快得多。改完要reload或重启生效可以用SHOW确认。注意这个参数是让连接更快发现异常并不会主动断开健康的连接所以调小不会带来副作用。第三Linux系统层面也可以修改全局的TCP keepalive参数。操作数据库所在机器或客户端所在机器时在/etc/sysctl.conf中设置net.ipv4.tcp_keepalive_time 60 net.ipv4.tcp_keepalive_intvl 10 net.ipv4.tcp_keepalive_probes 6然后执行sysctl -p生效。注意这个改动影响机器上所有TCP连接建议在测试环境验证之后再上生产。如果团队规范不允许动系统参数那就在PostgreSQL里设置tcp_keepalives_*效果是等价的。第四应用层给IO错误加一次重试。毕竟无论怎么调偶发的网络抖动还是存在业务代码里对这类可重试错误做兜底很重要。比如Spring里可以用Retryable对DataAccessException做一次重试Python的SQLAlchemy里可以通过自定义重试装饰器实现。需要注意重试只适合那些幂等的操作写操作能不能安全重试要自己评估。另外重试次数别太多一两次就够加个短暂的退避时间避免雪崩。4. 常见问题速查与避坑经验4.1 典型问题对照表我把排查过程中最常见的五种情况整理成一张表方便直接对照。这张表里的前两行覆盖了八成的线上场景剩下三行属于冷门但致命的情况。现象可能原因优先检查项处理手段每天第一次请求报IO error连接池空闲连接被网络设备回收连接池maxLifetime、网络设备老化时间调短连接池生命周期开启keepalive批量任务跑到一半报错statement_timeout或网络中断pg_stat_activity、服务端日志调大statement_timeout或拆分任务空闲一段时间后事务提交时报错idle_in_transaction_session_timeout数据库日志、参数调大该参数或缩短事务空闲时间偶发IO error频率不固定网络抖动或中间防火墙RSTtcpdump抓包应用层重试网络链路整改数据库服务器重启后应用全挂连接已被服务端重置数据库日志、dmesg连接池自动重连机制启动检查连接4.2 三个最容易踩的坑第一个坑是乱调socketTimeout。有人为了“让应用不超时”把socketTimeout设成0或者极大值。这样做表面上一时不出错但连接如果在中间被静默断掉应用会一直挂起等待直到系统内核TCP超时可能几分钟甚至十几分钟才返回错误。反而是设置一个合理的读超时让应用快速失败再重试体验更好。第二个坑是只改应用不改数据库。如果你把HikariCP的maxLifetime调成30分钟但数据库侧还是有idle_in_transaction_session_timeout在5分钟就断开空闲事务那连接照样会挂掉。这种问题要靠两端协作解决应用管连接池数据库管会话参数系统管TCP参数三边都对了才能稳定。我见过一个项目运维把数据库参数调得很激进应用怎么改都无效最后两边对线才对齐。第三个坑是测试环境一切正常、生产才出问题。这通常不是代码的锅而是环境差异。测试环境没有公网NAT、没有防火墙老化生产环境全有。我在帮人排查时一定会问一句同一个应用连内网数据库报不报错如果内网正常、公网必现优先查网络设备。这种环境差异性问题代码改不出结果得靠基础设施配合。4.3 我的最终建议如果你正在被这个报错折磨我建议按这个顺序来先把pg_stat_activity和数据库日志拉出来确认报错时数据库侧有没有异常再开抓包确认断链方向然后按第3节的清单检查连接池参数和tcp keepalive配置最后在应用层为这类错误加一次安全重试。大多数情况下做完前三步问题就已经解决了第四步是为了兜底偶发情况属于保险措施。我个人实际操作中的体会是这个报错本身不可怕可怕的是把它当成偶发现象忽略掉。很多线上事故其实在早期日志里就有蛛丝马迹只是没有追下去。现在每当我接到这类问题都会先问一句“你数据库日志和抓包看了吗”而不是急着改代码。TCP这条链路上任何一环出了问题最终都会以IO error的形式暴露到应用层所以排查时一定要有链路思维。如果你按这篇文章的步骤走一遍还没定位到问题大概率是抓包时长不够或者环境里有其他应用在共用连接把包抓全、时间拉长答案总会浮出来。
返回列表