关于tuxedo进程服务自增长后报错问题分析

问题描述：
当tuxedo的进程自动增长后，应用会持续报错：
Connection does not exist (err11)

问题分析：
报错信息来源于操作Altibase时。咨询了altibase厂家认为数据库没问题，所以推测是操作altibase的变量失效了所致。

变量代码：
AltibaseIntf * abdb::AltibaseIntf::getInstance()
{
    static AltibaseIntf dbi;
    return & dbi;
}

static string curTimeStamp("");
由于dbi变量是static，dbi在连接数据库时判断是否连接的变量时间戳也是static，根据我上次的实验证明，static的在linux上替换动态库是会清空内存的，推测tuxedo线程增长的机制与动态库替换相似。（后面经过验证，是第二个static变量导致）

报错代码：
    if (SQL_ERROR == SQLAllocStmt(m_dbc, &m_stmt))
    {
         if (m_dbc == NULL)
            LOG_TRACE(logger, "error-altibase m_dbc is null!");
   
         throwError("SQLAllocStmt出错：");
    }
SQLAllocStmt函数报错。这个函数报错，很有可能就是m_dbc失去了连接，失去连接的原因很有可能就是dbi变量内存清空了。

整体流程：
void QueryRealBillFromMemDB(CFmlBuf &inBuf, CFmlBuf &outBuf)
{
// 使用单例
DetailbillMgrHolder::getInstance().getRealBillFromMemDB(inBuf,outBuf);
// 调用函数
int DetailbillMgr::getRealBillFromMemDB…
// 取得数据库连接（是static）
abdb::AltibaseIntf * abdbi = abdb::AltibaseIntf::getInstance();
// 如果未连接则进行连接，已连接则直接返回，判断是否连接的变量也为static
abdbi =  abdb::connectAltibase(abdbi);
// 这句报错
abdbi->setSql(sql);
}

1 构建环境
先修改tuxedo的ubb文件，比如开发机上的ubb_tp02文件，使得min与max不一致：

tamcbs1l1server SRVGRP="GRPAMCBS1" SRVID=5360 RQADDR="tamcbs1l1" MIN=1 MAX=2 REPLYQ=Y CLOPT="-A -r -e tp02_s
imp -p 1,30:2,30 -- -T"

默认先启动一个进程，然后模拟并发调用，使其自动增长为两个进程。

2 模拟并发调用
调用前只有一个进程：
[builder@crmint-tp02 ~]$
[builder@crmint-tp02 ~]$ps -ef|grep tamcbs1l1server|grep tuxapp|grep 540
tuxapp   60746     1  0 14:31 pts/10   00:00:00 tamcbs1l1server -C dom=ngbss -g 540 -i 5360 -u crmint-tp02 -U /ngbss/tuxapp/log/ulog -m 0 -A -r -e tp02_simp -p 1,30:2,30 -- -T
[builder@crmint-tp02 ~]$

打开2~3个窗口，进程循环调用：
/tuxapp/preloader]$amcbs.sh

调用后几秒钟，自动增长为两个进程，16点30分的就是新的进程：
[builder@crmint-tp02 ~]$
[builder@crmint-tp02 ~]$ps -ef|grep tamcbs1l1server|grep tuxapp|grep 540
tuxapp   60746     1  0 14:31 pts/10   00:00:25 tamcbs1l1server -C dom=ngbss -g 540 -i 5360 -u crmint-tp02 -U /ngbss/tuxapp/log/ulog -m 0 -A -r -e tp02_simp -p 1,30:2,30 -- -T
tuxapp   72538     1 28 16:30 pts/10   00:00:01 tamcbs1l1server -C dom=ngbss -g 540 -i 5361 -u crmint-tp02 -U /ngbss/tuxapp/log/ulog -m 0 -D -A -r -e tp02_simp -p 1,30:2,30 -- -T
[builder@crmint-tp02 ~]$

1,30:2,30的解释：
CLOPT="-A -p 1,30:2,30 -- -T"
为服务器指定命令行参数，这个参数被两个连续减号分成前后 两个 部分
-A：初始化并公告服务进程 中所有的服务
-p：这个参数通常用于MSSQ服务进程，它告诉Tuxedo在什么条件下启动一个新进程，在什么条件下杀死一个新进程。
-p参数可以以队列长度为条件，如”-p 5,6:15,3”，表示在3秒内，如果服务器队列长度超过15则创建一个新的进程实例，在6秒内，如果服务器队列长度小于5，则杀死一个已经存在 的进程实例
-p也可以以服务器负载 为条件，如”-p 500”表示当服务器负载大于500时，就创建一个新的进程 实例，当服务器负载小于500时就杀死一个已经存在 的进程实例 

日志也开始报错：
tpcall [task:1][4]  QAM_OWEFEE_QUERY@TAM_CBS1_L1SVC return: X_RESULTCODE:-1 X_RESULTINFO:QAM_OWEFEE_QUERY执行异常:
调用函数QueryRealBillFromMemDB发生错误:[INDETERMINATE]AltibaseIntf.cpp:76,17AltibaseException--1: SQLAllocStmt出错：[47175921111094]:,Connection does not exist (err11) X_RECORDNUM:1

    lcuName: [task:1]  QAM_OWEFEE_QUERY [call ok:4]     max:212843ms,min:59105ms,average:0.135758s

一段时间不调用后，进程恢复为1个：（注意，把30改为10会更容易恢复到1个进程）
crmint-tp02:[/ngbss/tuxapp/etc]$
crmint-tp02:[/ngbss/tuxapp/etc]$ps -ef|grep tamcbs1l1server|grep tuxapp|grep 540
tuxapp   77356     1 10 16:54 pts/2    00:00:17 tamcbs1l1server -C dom=ngbss -g 540 -i 5360 -u crmint-tp02 -U /ngbss/tuxapp/log/ulog -m 0 -A -p 1,30:2,10 -- -T
crmint-tp02:[/ngbss/tuxapp/etc]$

3 修改代码
static AltibaseIntf dbi;

static string curTimeStamp("");

把dbi的static去掉，报错依旧。
把curTimeStamp的static去掉，报错去除。
证明是curTimeStamp引起。

经过试验证明，去掉static后，报错不再有。即使tuxedo进程增长了，没有报错；进程降下来了，没有报错；然后进程又再升上去，还是没有报错。

4 错误原因分析
把curTimeStamp和timeStamp打印出来观察
第一次调用时：
curTimeStamp:,timeStamp:2009-02-07 00:00:00

第二次调用时：
curTimeStamp:2009-02-07 00:00:00,timeStamp:2009-02-07 00:00:00

因为cur变量用了static，所以第二次会保持不变，数据库重新连接的条件是cur必须小于time，因此，在这种情况下会沿用原来的dbi连接，但是dbi变量已经可能被清空了，所以报错。
if(curTimeStamp < timeStamp)
{
数据库连接
}

5 另外发现的问题
重新发布libAltibaseIntf.so后，不重启会卡死。
原因待续。

6 解决方案
待续

评论

1 楼 ouyida3 2013-08-22  

这篇和解决方案那篇加起来领导HaiB看了说不错