PostgreSQL和Oracle中的一条错误消息分析

PostgreSQL服务端的日志里有时会残留一些这样的消息。意思是说客户端的socket意外终止了。

LOG: could not receive data from client: Connection reset by peer.
或中文的
LOG:无法从客户端获得数据:

出现这样的消息有2个可能的原因
1）客户端进程意外结束了
2）客户端进程没有关闭连接就退出了

其中第2点有时比较隐蔽。比如下面的.NET程序。

String connectionString = ...;
NpgsqlConnection con = new NpgsqlConnection(connectionString);
con.Open();
con.Close();

由于Npgsql使用了连接池，上面的con.Close()不会实际关闭物理连接而是将物理连接放入到连接池中以备下次重用。所以这个程序结束时也可能在服务端引发一条错误消息。

为什么说“可能”呢？
因为Npgsql通过重载NpgsqlNetworkStream类的Dispose()方法，实现了对未关闭连接的释放（*1）。所以一般情况下不会有问题。但测试发现以下几种情况下Dispose()方法不会被调用，因而会导致socket异常关闭，服务端报错。
1）由未捕获的异常导致的程序终了。
2）SSL方式的连接
3）未关闭连接太多或MinPoolSize设的比较大时（*2）

*1）其实这是一个相当危险并应当禁止的行为。因为它在GC的过程中调用了其它对象发送消息，如果其它对象可能正在或已经被回收了，可能会导致不可预知的结果。我们在做别的项目时曾经遇到一个非常极端的情况。在大量并发的情况下，通过.NET的Dispose()对未回收的连接中发一个终了消息，结果
偶尔这个终了消息被误发给了其它连接，导致服务端接受到了错误数据而宕机。
*2）有时调Dispose（）有时不调，有一定随机性

 

引申：Oracle的行为
作为对比调查了Oracle。发现Oracle有类似现象。
同样用.NET程序做测试(没试SSL)，只要同时存在的连接数大于2(或MIN POOL SIZE大于2)，程序退出时，服务端就会出现错误日志。

测试程序:

String connectionString = ...;
OracleConnection con1 = new OracleConnection(connectionString);
OracleConnection con2 = new OracleConnection(connectionString);
con1.Open();
con2.Open();
con1.Close();
con2.Close();

trace/alert_XXXX.log:
***********************************************************************

Fatal NI connect error 12547, connecting to:
(LOCAL=NO)

  VERSION INFORMATION:
              TNS for Linux: Version 11.2.0.1.0 - Production
              Oracle Bequeath NT Protocol Adapter for Linux: Version 11.2.0.1.0 - Production
              TCP/IP NT Protocol Adapter for Linux: Version 11.2.0.1.0 - Production
 Time: 04-SEP-2013 14:51:31
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12547
   
TNS-12547: TNS:lost contact
    ns secondary err code: 12560
    nt main err code: 0
    nt secondary err code: 0
    nt OS err code: 0
opiodr aborting process unknown ospid (3574) as a result of ORA-609

 

总结
对使用连接池的场景，出现这个错误消息很多时候不是问题。但好像没有特别好的方法能让这种场景下不报错。