ganquan的博客

# cicscp -v start region vhfsserv StartType=cold

ERZ059004I/0107: Starting RPC daemon.

ERZ059002I/0101: RPC daemon is already running.

ERZ096122I/0264: Processing a 'start region' command

ERZ096158I/0264: The region 'vhfsserv' is starting

ERZ096111I/0224: Processing a start sfs_server command

ERZ096141I/0224: Starting SFS server '/.:/cics/sfs/njffs'

Process with pid_1200320 went down with PROCESS LOCK held. Shutdown all processes and restart SARPCD

ERZ052004I/0602 03/11/07 09:07:36 ywrun : Dump to 'A1580026.dmp' started.

ERZ052013I/0409 03/11/07 09:07:37 ywrun : Dump 0026 - 1 core dump(s) created.

ERZ052007I/0604 03/11/07 09:07:37 ywrun : Dump to 'A1580026.dmp' completed.

ERZ014016E/0036 03/11/07 09:07:37 ywrun : Transaction 'CPMI', Abend 'A158', at '????'.

ERZ057002E/0140 03/11/07 09:07:37 ywrun : CICS internal error: Unsuccessful condition '(tran_TidEqual(ThreadTid, OldTid))' for function 'TasLU_ISyncpoint' on line 968 in file '/cics/PTF9/src/tas/lu/src/taslusyn.c' of module 16

ERZ057005E/0140 03/11/07 09:07:37 ywrun : CICS internal error: Abnormally terminating region with exit code 'U5701'

ERZ010003I/0094 03/11/07 09:07:37 ywrun : CICS is performing region abnormal termination in process 'cicsas'

ERZ052004I/0602 03/11/07 09:07:37 ywrun : Dump to 'SYSA0027.dmp' started.

ERZ052007I/0604 03/11/07 09:07:41 ywrun : Dump to 'SYSA0027.dmp' completed.

ERZ010089E/0367 03/11/07 09:07:41 ywrun : Application Server 108 ended unexpectedly

ERZ010144I/0375 03/11/07 09:07:41 ywrun : Application server 104 started

ERZ010144I/0375 03/11/07 09:07:41 ywrun : Application server 105 started

ERZ014016E/0036 03/11/07 09:07:41 ywrun : Transaction 'CPMI', Abend 'A147', at '????'.

ERZ052004I/0602 03/11/07 10:13:02 ywrun : Dump to 'A1580001.dmp' started.

ERZ052013I/0409 03/11/07 10:13:02 ywrun : Dump 0001 - 1 core dump(s) created.

ERZ052007I/0604 03/11/07 10:13:02 ywrun : Dump to 'A1580001.dmp' completed.

ERZ014016E/0036 03/11/07 10:13:02 ywrun : Transaction 'CPMI', Abend 'A158', at '????'.

ERZ057002E/0140 03/11/07 10:13:02 ywrun : CICS internal error: Unsuccessful condition '(tran_TidEqual(ThreadTid, OldTid))' for function 'TasLU_ISyncpoint' on line 968 in file '/cics/PTF9/src/tas/lu/src/taslusyn.c' of module 16

ERZ057005E/0140 03/11/07 10:13:02 ywrun : CICS internal error: Abnormally terminating region with exit code 'U5701'

ERZ010003I/0094 03/11/07 10:13:02 ywrun : CICS is performing region abnormal termination in process 'cicsas'

ERZ052004I/0602 03/11/07 10:13:02 ywrun : Dump to 'SYSA0002.dmp' started.

ERZ052007I/0604 03/11/07 10:13:04 ywrun : Dump to 'SYSA0002.dmp' completed.

ERZ010012I/0194 03/11/07 10:13:04 ywrun : CICS is performing an immediate shutdown of region 'ywrun'

问题描述:

5/12 17：30左右 大量前台交易不能进行：

但CICS server console日志中没有出现异常,cicsterm—〉CEMT I TA可以运行，并且偶尔有几个交易能做。前台 cics client 状态表现为available，但这时前台的交易不能正常返回。重新启动cics client ，状态则为connecting.

问题解答:

1． 使用showProcInfo工具，获取了cics的所进程信息。发现cicsip的进程信息和正常情况相差很远：

正常：

Waiting to attach to process 49170 ...

Successfully attached to cicsip.

warning: Directory containing cicsip could not be determined.

Apply 'use' command to initialize source path.

Type 'help' for help.

reading symbolic information ...

stopped in evt._pthread_ksleep [/usr/lib/libpthreads.a] at 0xd00e2d4c ($t4)

0xd00e2d4c (_pthread_ksleep+0x9c) 80410014 lwz r2,0x14(r1)

thread state-k wchan state-u k-tid mode held scope function

$t1 wait 0xe60b32bc blocked 733945 k no sys _pthread_ksleep

$t2 wait 0xe60097bc blocked 38679 k no sys _pthread_ksleep

$t3 wait 0x32e7c904 running 91099 k no sys _ptrgl

>$t4 run blocked 743665 k no sys _pthread_ksleep

$t5 wait 0xe601f1bc blocked 127245 k no sys _pthread_ksleep

$t6 wait 0xe6030fbc blocked 200545 k no sys _pthread_ksleep

$t7 wait 0xe60310bc blocked 200893 k no sys _pthread_ksleep

$t8 wait 0xe60b2ebc blocked 732729 k no sys _pthread_ksleep

$t9 wait 0xe60b8fbc blocked 757693 k no sys _pthread_ksleep

$t10 wait 0xe601ccbc blocked 117939 k no sys _pthread_ksleep

$t11 wait 0xe60b67bc blocked 747287 k no sys _pthread_ksleep

$t12 wait 0xe60a7bbc blocked 686919 k no sys _pthread_ksleep

异常：

Waiting to attach to process 49170 ...

Successfully attached to cicsip.

warning: Directory containing cicsip could not be determined.

Apply 'use' command to initialize source path.

Type 'help' for help.

reading symbolic information ...

stopped in evt._pthread_ksleep [/usr/lib/libpthreads.a] at 0xd00e2d4c ($t4)

0xd00e2d4c (_pthread_ksleep+0x9c) 80410014 lwz r2,0x14(r1)

thread state-k wchan state-u k-tid mode held scope function

$t1 wait 0xe60b32bc blocked 733945 k no sys _pthread_ksleep

$t2 wait 0xe60097bc blocked 38679 k no sys _pthread_ksleep

$t3 wait 0x32e7c904 running 91099 k no sys _ptrgl

>$t4 run blocked 743665 k no sys _pthread_ksleep

$t5 wait 0xf04805f4 running 127245 k no sys pthread_mutex_lock

$t6 wait 0xf04805f4 running 200545 k no sys pthread_mutex_lock

$t7 wait 0xf04805f4 running 200893 k no sys pthread_mutex_lock

$t8 wait 0xf04805f4 running 732729 k no sys pthread_mutex_lock

$t9 wait 0xf04805f4 running 757693 k no sys pthread_mutex_lock

$t10 wait 0xf04805f4 running 117939 k no sys pthread_mutex_lock

$t11 wait 0xf04805f4 running 747287 k no sys pthread_mutex_lock

$t12 wait 0xf04805f4 running 686919 k no sys pthread_mutex_lock

通过分析以上信息和现象，发现正常和异常情况的cicsip进程信息区别很大，异常情况下cicsip的很多线程处在pthread_mutex_lock。

2.查看最近的console 日志,从4/29号6138交易连续出现了Abend code 为A57A，导致cicsas异常结束。

例如：

ERZ014016E/0036 05/13/04 05:54:10 BCSSCICS : Transaction '6138', Abend 'A57A', at '????'.

并且在symrecs中出现了相关的异常信息。

SYMPTOMS = PIDS/5697D1720 LVLS/420 PTFS/ RIDS/ComIP_IntRecvBytes LINE/-1 MS/057003 MSN/14 SRC/11 PRCS/2097152 AB/A57A PID/42744 TID/1 TIME/040513055410 TAIST

SECONDARY SYMPTOMS = PostMortem (Error Path is offset x'128' in ComIP_IntRecvBytes<ComIP_IntRecvGDS<ComIP_Receive<ComSU_ReceiveData<ComSU_GetFMHMessage<ComFS_APPCServ<TasTA_Exec<TasTA_Run<main) logging where error occurred

SYMPTOMS = PIDS/5697D1720 LVLS/420 PTFS/@(#)comip, 15:47:27, May 5 2000 RIDS/ComIP_IntRecvBytes LINE/1731 MS/057003 MSN/14 SRC/11 PRCS/99 AB/A57A PID/42744 TID/1 TIME/040513055410 TAIST

SECONDARY SYMPTOMS = * * * Internal inconsistency error * * *

分析：

1. 目前系统的版本如下：

CICS 4.2.0.8，ENCINA 4.2.0.1。

目前cics 4.2的最高补丁如下：

CICS 4.2.0.9，ENCINA 4.2.0.15。

2. 通过和ibm工程师共同分析，如果cicsip的很多线程处在pthread_mutex_lock，这样很可能会导致前台cics client 无法连接到cics server。

3. 如果需要进一步分析导致cicsip的很多线程处在pthread_mutex_lock的原因，则需要寻求IBM 实验室的技术支持。

4. 关于进一步分析A57A的问题，目前对参数进行如下调整：

RD:

SysDump=yes (原值：no)

PCDump=no (原值：yes)

ABDump=no (原值：yes)

TD:

6138:

TransDump=yes （原值：no）

LD:

新增 TCPIPL1定义，其中端口号为1438。

如果再次出现A57A时将产生dump信息，从而通过分析交易的dump信息和应用程序的lis文件，来判断问题的原因。

建议：

1． 基于cicsip的分析建议：

由于目前CICS产品的版本为4.2， IBM 实验室已经不再提供该版本的支持服务，所以建议升级到最新版本V5.1。

2． 针对目前cics的性能优化建议：

（1） 把比较慢且允许等待的交易分成一类交易，从而使得这些交易不对其他执行时间短而且量大交易造成堵塞的现象。

（2） 由于某些前台的程序没有进行交易分类，所以导致后台使用CPMI交易进行执行，所以建议把CPMI的交易也进行分类。

（3） 调整 RD中MaxConsoleSize参数为一个合适的大小。

3． 需要密切关注应用程序中出现的A57A的问题，因为该问题会导致cicsas异常结束。

4． 目前建议网银的前置机使用1438的端口号，然后再继续观察系统。

SERVICE_MESSAGE 12/05/04 12:22:56.115751675 xswork 78202/0001 : Traceback

file '/var/cics_regions/xswork/dumps/dir1/cicsas78202.traceback' for transaction

'' is generated

XA_CLOSE: Turned exception exc_e_illaddr into XAER_RMERR

ERZ080035E/0805 12/05/04 12:22:56.127269406 xswork 78202/0001 : Abnormal

termination U8035. XA_CLOSE returned a Resource Manager error when closing 'Sin

gle Phase Informix' using XA_CLOSE string ''. ' SQLCODE 0, Unknown error messag

e 0.

'

ERZ010003I/0094 12/05/04 12:22:56.127556116 xswork 78202/0001 : CICS is p

erforming region abnormal termination in process 'cicsas'

ERZ052004I/0602 12/05/04 12:22:56.127992717 xswork 78202/0001 : Dump to '

SYSA0001.dmp' started.

#include

$include sqlca;

main( void )

{

$char jshzh[23];

char *CommArea;

EXEC CICS ADDRESS EIB( dfheiptr );

EXEC CICS ADDRESS COMMAREA( CommArea );

memset(jshzh,0,sizeof(jshzh));

strcpy(jshzh,"1234567890123456789012");

jshzh[22]='';

printf("************ zh[%s]n",jshzh);

EXEC SQL declare zh_cur1 cursor for select * from fhdgckfhz

where zh=:jshzh for update;

if (sqlca.sqlcode !=0) {

printf("declare zh_cur1 err zh[%s]n",jshzh);

EXEC CICS SYNCPOINT ROLLBACK;

EXEC CICS RETURN;

}

EXEC SQL open zh_cur1;

if (sqlca.sqlcode !=0) {

printf("open zh_cur1 err sqlca.sqlcode[%s]n",sqlca.sqlcode);

EXEC CICS SYNCPOINT ROLLBACK;

EXEC CICS RETURN;

}

EXEC SQL close zh_cur1;

if (sqlca.sqlcode !=0) {

printf("close zh_cur1 err sqlca.sqlcode[%s]n",sqlca.sqlcode);

EXEC CICS SYNCPOINT ROLLBACK;

EXEC CICS RETURN;

}

EXEC SQL free zh_cur1;

if (sqlca.sqlcode !=0) {

printf("free zh_cur1 err sqlca.sqlcode[%s]n",sqlca.sqlcode);

EXEC CICS SYNCPOINT ROLLBACK;

EXEC CICS RETURN;

}

EXEC CICS RETURN;

}

测试条件

测试结果

1.

一阶段提交;

MinServer=3 ;MaxServer=15;

关键语句：EXEC SQL declare zh_cur1 cursor for select * from fhdgckfhz

where zh=:jshzh for update;

当cicsas个数从Maxserver下降时，会出现cics region 异常终止的现象。

2.

一阶段提交;

MinServer=3 ;MaxServer=15;

关键语句：EXEC SQL declare zh_cur1 cursor for select * from fhdgckfhz

where zh=’12345678901234567890123’ for update;

当cicsas个数从Maxserver下降时，cics region 表现正常。

3.

一阶段提交;

MinServer=15 ;MaxServer=15;

关键语句：EXEC SQL declare zh_cur1 cursor for select * from fhdgckfhz

where zh=:jshzh for update;

当cicsas个数从Maxserver下降时，cics region 表现正常。

4.

两阶段提交;

MinServer=3 ;MaxServer=15;

关键语句：EXEC SQL declare zh_cur1 cursor for select * from fhdgckfhz

where zh=:jshzh for update;

当cicsas个数从Maxserver下降时，cics region 表现正常；当会出现个别交易被hang的现象。

IFX_AUTOFREE=1

EXEC SQL set autofree enabled;

Close cursor

Free cursor

Cics region

1

n

n

y

n

down

2

n

n

y

y

normal

3

n

y

y

n

normal

4

n

y

n

n

down

5

y

n

y

n

normal

With the OPTOFC feature disabled, a static cursor is freed when it is closed. When ESQL/C reaches a CLOSE statement for a static cursor,it actually sends a message to close the cursor and free memory associated with this cursor. However, dynamic cursors are not implicitly freed when they are closed.

另外：

The default value of the OPTOFC environment variable is 0 (zero).

0 This value disables the OPTOFC feature for all threads of the application.