mth服务器dxi_change_log僵死问题

最新推荐文章于 2024-04-27 09:48:25 发布

wherwh

最新推荐文章于 2024-04-27 09:48:25 发布

阅读量801

点赞数

分类专栏：问题处理

本文链接：https://blog.csdn.net/wherwh/article/details/40189599

版权

问题处理专栏收录该内容

18 篇文章 0 订阅

订阅专栏

僵死的任务对应的规则：规则8,规则111705。任务号(task_id):2.

1.分析

扫描线程为：9668
[2014-10-13 20:26:13:556][线程9668][2][20][0][]DeamonTask[CDxkChangeLog::ChangeLogScanProc::2,线程数:1]:正在执行...

处理线程为：25672
[2014-10-13 18:50:46:284][线程25672][1][20][0][]HandleLogRecord正在处理:sheet_type=88,rule_id=111705,app_pk=C_ID=C[1-146-1132]...

目前分析得到的信息有：
(1)曾出现MySQL,Oracle连接不上的情况，但最终能恢复，所以不是数据库不可用的问题
(2) 从现象看是扫描线程阻塞.
任务扫描线程最后执行的时间为：
[2014-10-13 20:26:13:556][线程9668][2][20][0][]DeamonTask[CDxkChangeLog::ChangeLogScanProc::2,线程数:1]:正在执行...
且没有表示结束的类似下面的日志信息：
[2014-10-13 20:18:41:016][线程9668][2][20][0][]DeamonTask[CDxkChangeLog::ChangeLogScanProc::2,线程数:1]:执行完毕,返回码=0.
这说明ChangeLogScanProc没有执行结束,阻塞在某处了。
由于扫描线程没有结束，没有新的记录要处理，所以处理线程就再也没有执行了。
从ChangeLogScanProc代码分析,加上sql日志显示没有执行到update修改tb_change_log处理状态的命令.也就没有执行任务的处理线程队列的入队操作(ti->handler_.putq(mb)),不可能是队列阻塞造成的。
如此一来,扫描线程决无可能阻塞。
另外的可能是，ChangeLogScanProc产生了异常,导致线程函数没有机会再次运行（产生异常的线程处于什么状态？windows是如何对待产生异常的线程的?）。
但执行线程函数的ACE_THR_FUNC_RETURN exec_task_func(void *arg)有异常处理，而且还有bugreport守侯.
看来都漏掉了，有这种逻辑吗？

ACE_THR_FUNC_RETURN exec_task_func(void *arg) {
	DeamonThreadArg *t_arg = ACE_reinterpret_cast(DeamonThreadArg*,arg);
	DeamonTask *task = t_arg->task_;
	ACE_THR_FUNC_RETURN status = 0;
	HTX_TSS::instance()->SetDeamon(true);
	do{
		DWORD dwResult = WaitForSingleObject(task->signal_cond_var_,INFINITE);
//		HTX_TSS::instance()->ClearThreadInfo();
		if( task->state_ == 9 )
			break;
		if( dwResult == WAIT_OBJECT_0 || dwResult == WAIT_TIMEOUT ){
			//task->state_ = 2;
			HTX_LOGGER::instance()->log(LO_STDOUT|LO_FILE,SEVERITY_INFO,"DeamonTask[%s]:正在执行...\n",task->name_.c_str());
			try {
				status = (*task->func_)(task->arg_);
				if (status&&HTX_DEAMON_MGR::instance()->error_handle_) { ///< 仅处理错误时才调用错误处理函数
					(*HTX_DEAMON_MGR::instance()->error_handle_)(task,HTX_DEAMON_MGR::instance()->error_handle_arg_);
				}
				HTX_LOGGER::instance()->log(LO_STDOUT|LO_FILE,SEVERITY_INFO,"DeamonTask[%s]:执行完毕,返回码=%d.\n",task->name_.c_str(),status);
			} catch(...) {
				HTX_LOGGER::instance()->log(LO_STDOUT|LO_FILE,SEVERITY_ERROR,"DeamonTask[%s]异常.\n",task->name_.c_str());
				continue;
			}
			//task->state_ = 3;
		}
		if (status==0) {
			if( task->sche_strategy_ ) 
				task->sche_strategy_->adjust();
			if (task->done_cb_) {
				(*task->done_cb_)(task->done_cb_arg_,task->sche_strategy_ ? task->sche_strategy_->get_last_task_time_tag() : 0); ///< @note 回调失败不会导致事务回滚,回调一般用于永久性记录最后任务时间.失败可能导致任务重复执行.(进程重新启动后)
			}
		}

		if (task->get_active_flag()==0) ///< 测试线程是否活动
			task->set_active_flag(1);
		
		ResetEvent(task->signal_cond_var_); /// 设置为non-signal状态. (否则对于每日执行的任务,可能在上次执行过程中,task->signal_cond_var_在下一次定时到期时被设置为signal状态.导致执行多次)
	}while(true);

	delete t_arg;

	return 0;
}

处理线程在当天日志中最后的记录为：（从日志和代码看应该是正常结束了）
[2014-10-13 20:11:10:814][线程25672][1][20][0][]HandleLogRecord正在处理:sheet_type=8,rule_id=8,app_pk=C_ID=C[Q11527-223-000111]...
[2014-10-13 20:11:10:814][线程25672][1][20][0][]正在处理数据抽取(规则:8,单据类型:100121050)...
[2014-10-13 20:11:10:830][线程25672][2][20][0][]数据抽取(规则:8,单据类型:100121050)开始处理...
[2014-10-13 20:11:10:846][线程25672][2][20][0][]数据抽取(规则:8,单据类型:100121050)时,明细记录数为1.主键:Q11527-223-000111,生成文件名:data\retail\autosend/se_imp_10012_100121050_1050_20141013_37308_1.xml
[2014-10-13 20:11:10:846][线程25672][2][20][0][]数据抽取(规则:8,单据类型:100121050)处理了1条记录,扫描记录数:1.
[2014-10-13 20:11:10:846][线程25672][1][20][0][]数据抽取(规则:8,单据类型:100121050)处理完毕,返回值:0
处理线程最早记录为：
[2014-10-13 06:29:26:878][线程25672][1][20][0][]HandleLogRecord正在处理:sheet_type=8,rule_id=8,app_pk=C_ID=C[1-228-004663]...

(3)失败重做线程15436始终在运行,有失败重做的活动。
[2014-10-13 20:27:43:565][线程15436][2][20][0][]DeamonTask[CRedoar::OnRedoProc]:正在执行...

2.处理

目前没有准确定位问题,以下的处理并不直接作用于此问题。

此问题需要继续分析和跟踪。

(1)增加ChangeLogScanProc日志信息,在函数出入口,并输出扫描记录数,有效记录数,处理任务当前队列元素个数.
为以后的问题诊断提供更多的信息.
已提交，未安排升级。

(2)检查失败重做队列表.如果存在反复执行始终无法成功的记录，则需要人工处理(如果是程序缺陷则需要修正完善)
线程15436是失败重做线程。
大量的重做项可能消耗了MySQL的资源.
需要分析下面2种应用的逻辑，分别是insert,update操作。
失败重做保存的是由于外部环境暂时失效，导致无法成功，但系统环境恢复后可以完成的任务。
检查失败重做队列表中的错误是否符合这个条件，表中不应该有永远不会成功的记录。

重做错误1：

[2014-10-13 23:58:49:793][线程15436][4][20][0][]接收到2800[,,,,100122137,QR-02681-000194,30234]
[2014-10-13 23:58:49:793][线程15436][1][20][0][]正在处理机构30234的单据QR-02681-000194...
[2014-10-13 23:58:49:839][线程15436][5][20][0][]CDbAccessor2::Execute insert into tb_o_in(c_id,c_provider,c_status,c_at_should,c_a_should,c_tax_should,c_at_fact,c_a_fact,c_tax_fact,c_settle_region,c_mk_store_id,c_mk_userno,c_get_dt,c_at_pass_in,c_a_pass_in,c_tax_pass_in) values('QR-02681-000194','02681','尚未审核',10432.04,9083.66,1348.38,10432.04,9098.98,1333.06,'A0113','1','供应宝',NULL,'0.00','0.00','0.00')产生异常(Error
Code = 80040e14
Code meaning = IDispatch error #3092
Source = Microsoft OLE DB Provider for ODBC Drivers
Description =[Oracle][ODBC][Ora]ORA-00001: 违反唯一约束条件 (MIS_USER.TB_O_IN_PK)

([1]Number:0X80040E14 Description:[Oracle][ODBC][Ora]ORA-00001: 违反唯一约束条件 (MIS_USER.TB_O_IN_PK)
SQLState:23000 NativeError:1)).
[2014-10-13 23:58:49:855][线程15436][4][20][0][]LoadFromMsg返回值：-6.
[2014-10-13 23:58:49:902][线程15436][2][20][0][]DeamonTask[CRedoar::OnRedoProc]:执行完毕,返回码=0.

重做错误2：
[2014-10-13 02:14:16:956][线程15436][1][20][0][]正在处理机构10012的单据Q1116-147-000346...
[2014-10-13 02:14:17:206][线程15436][5][20][0][]CDbAccessor2::Execute update tb_o_i set c_booking_dt=to_date('2014-10-08 13:00:00','yyyy-MM-dd HH24:mi:ss') where c_id='Q1116-147-000346' and c_rec_status='尚未收货'产生异常(Error
Code = 80040e14
Code meaning = IDispatch error #3092
Source = Microsoft OLE DB Provider for ODBC Drivers
Description =[Oracle][ODBC][Ora]ORA-00001: 违反唯一约束条件 (DCSDBA.INTERFACE_PRE_HEADER_TIME_PK)
ORA-06512: 在 "MIS_USER.TR_RPWMS_PRE_ADVICE_TIME", line 17
ORA-04088: 触发器 'MIS_USER.TR_RPWMS_PRE_ADVICE_TIME' 执行过程中出错

([1]Number:0X80040E14 Description:[Oracle][ODBC][Ora]ORA-00001: 违反唯一约束条件 (DCSDBA.INTERFACE_PRE_HEADER_TIME_PK)
ORA-06512: 在 "MIS_USER.TR_RPWMS_PRE_ADVICE_TIME", line 17
ORA-04088: 触发器 'MIS_USER.TR_RPWMS_PRE_ADVICE_TIME' 执行过程中出错
SQLState:23000 NativeError:1)).

[2014-10-13 02:14:17:206][线程15436][4][20][0][]LoadFromMsg返回值：-1.