Z991239-6282 #comment 精简优化日志记录

Module/mod_pinpad/PinPadFSM.cpp

@@ -61,7 +61,7 @@ void CPinPadFSM::s0_on_entry()
 	LOG_FUNCTION();
 	FSMEvent *e = new FSMEvent(USER_EVT_INIT);
 	PostEventFIFO(e);
-	m_ullConnectCost = SP::Module::Comm::RVCGetTickCount();
+	m_ullEntityStart = SP::Module::Comm::RVCGetTickCount();
 }
 void CPinPadFSM::s0_on_exit()
 {
@@ -274,7 +274,7 @@ void CPinPadFSM::s6_on_exit()
 }
 unsigned int CPinPadFSM::s6_on_event(FSMEvent* pEvt)
 {
-	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM)("s6 evt %d", pEvt->iEvt);
+	DbgWithLink(LOG_LEVEL_DEBUG, LOG_TYPE_SYSTEM)("s6 evt %d", pEvt->iEvt);
 	switch (pEvt->iEvt)
 	{
 	default:
@@ -301,8 +301,7 @@ int CPinPadFSM::Initial()
 	eErrDev = pEntity->LoadVendorLibName();
 	if (eErrDev != Error_Succeed)
 	{
-		DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM)("LoadVendorLibName(%d) failed.", eErrDev);
-		LogWarn(Severity_Middle, eErrDev, PinPad_UserErrorCode_Get_DevAdapter_Path_Failed, "Initial:LoadVendorLibName");
+		LogWarn(Severity_Middle, eErrDev, PinPad_UserErrorCode_Get_DevAdapter_Path_Failed, CSimpleStringA::Format("LoadVendorLibName failed,error:%d", eErrDev));
 		m_bOpening = false;
 		return Error_DevLoadFileFailed;
 	}
@@ -314,7 +313,7 @@ int CPinPadFSM::Initial()
 	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
 	eErrDev = LoadUpAdapterLibrary();
 	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
-	LogWarn(Severity_Low, Error_Unexpect, PinPad_UserErrorCode_LoadAdapterCost, CSimpleStringA::Format("%d", m_ullEndTime - m_ullBeginTime));
+	m_ullAdpFileLoadCost = m_ullEndTime - m_ullBeginTime;
 
 	if (!IS_SUCCEED(eErrDev))
 	{
@@ -334,14 +333,33 @@ int CPinPadFSM::Initial()
 
 		if (eErr == Error_Succeed)
 		{
+			//oiltmp@20240521 add for redundancy to check
+			CSmartPointer<IConfigInfo> spConfigCen;
+			int iTmp = 0;
+			GetEntityBase()->GetFunction()->OpenConfig(Config_CenterSetting, spConfigCen);
+			if (spConfigCen->ReadConfigValueInt(GetEntityBase()->GetEntityName(), "UseBackupSN", iTmp) == Error_Succeed)
+			{
+				if (iTmp == 1)
+					m_bUseBackupSN = true;
+				else if (iTmp > 1)//to except default value 0
+					m_bUseBackupSN = false;
+			}
+			iTmp = 0;
+			if (spConfigCen->ReadConfigValueInt(GetEntityBase()->GetEntityName(), "SetParamOnce", iTmp) == Error_Succeed)
+			{
+				if (iTmp == 1)
+					m_bSetParamOnce = true;
+				else if (iTmp > 1)//to except default value 0
+					m_bSetParamOnce = false;
+			}
 			DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::DevOpen").setCostTime(m_ullEndTime - m_ullBeginTime)();
 			initTries = 0;
 			ErrorCodeEnum errCode3, errCode4;
 			m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-			//errCode1 = m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD,EPP_ALGO_METHOD_3DES);
-			//errCode2 = m_hDevHelper->SetParam(EPP_PT_SET_MAC_ALGORITH,EPP_MAC_ALGO_ASNIX99);
 			errCode3 = m_hDevHelper->SetParam(EPP_PT_SET_PIN_ALGORITH, EPP_PIN_ALGO_SM4);
-			errCode4 = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_3DEC_CBC);
+			errCode4 = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_3DEC_CBC);//oilyang@20250616 only add comment:for old adapter
+			if (m_bSetParamOnce)
+				errCode4 = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC);
 			m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
 
 			if (errCode3 != Error_Succeed || errCode4 != Error_Succeed)
@@ -366,18 +384,9 @@ int CPinPadFSM::Initial()
 	} while (initTries < PINPAD_INIT_TRIES);
 	m_bOpening = false;
 	if (initTries != 0)
-	{
-		LogEvent(Severity_Middle, LOG_EVT_PINPAD_OPEN_FAIL, "Open pinpad failed.");
-		DbgWithLink(LOG_LEVEL_ERROR, LOG_TYPE_SYSTEM)("Open pinpad failed.");
 		return 1;
-	}
 	SetDevInitFlag();
-	//oiltmp comment the following 20160406
-	//update with the version 1.7.1
-	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-	m_encryptkey = m_hDevHelper->GetEncryptFunc();
-	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
-	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::GetEncryptFunc").setCostTime(m_ullEndTime - m_ullBeginTime)("Error_Succeed");
+
 	CSmartPointer<IConfigInfo> spConfig;
 	eErrDev = GetEntityBase()->GetFunction()->OpenConfig(Config_Run, spConfig);
 	if (eErrDev != Error_Succeed)
@@ -396,7 +405,10 @@ int CPinPadFSM::Initial()
 		spConfig->ReadConfigValue("Load", "SN_SM", m_keySNSM);
 		spConfig->ReadConfigValue("Load", "ckckck", m_lastCheckCode);
 	}
-	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM)("encrypt key :%d,load key :%d", m_encryptkey, m_bSMLoaded);
+	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
+	m_encryptkey = m_hDevHelper->GetEncryptFunc();
+	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
+	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::GetEncryptFunc").setCostTime(m_ullEndTime - m_ullBeginTime)("encrypt key :%d,loaded key :%d,m_keySNSM:%s", m_encryptkey, m_bSMLoaded, m_keySNSM.GetData());
 	DevCategoryInfo devInfo;
 	ZeroMemory(devInfo.szModel, MAX_DEV_MODEL_LEN);
 	ZeroMemory(devInfo.szType, MAX_DEV_TYPE_LEN);
@@ -418,26 +430,23 @@ int CPinPadFSM::Initial()
 		SetErrorAndLog(eErrDev, MEC_DEVAPI_EPP_GetDevCategory, "DevAdapter::GetDevCategory", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime);
 
 	CSimpleStringA xTmpStr = CSimpleStringA::Format("(hw support):%d,load key :%d,SMSN:%s", m_encryptkey, m_bSMLoaded, m_keySNSM.GetData());
-	LogWarn(Severity_Low, Error_Unexpect, PinPad_UserErrorCode_DevConnect_CostTime, CSimpleStringA::Format("%d", SP::Module::Comm::RVCGetTickCount() - m_ullConnectCost));
+	ULLINT tmpAllCost = SP::Module::Comm::RVCGetTickCount() - m_ullEntityStart;
+	std::map<std::string, std::string> devConnInfo;
+	devConnInfo["AllCost"] = CSimpleStringA::Format("%d", tmpAllCost);
+	devConnInfo["AdpFileLoadCost"] = CSimpleStringA::Format("%d",m_ullAdpFileLoadCost);
+	devConnInfo["DevConnectCost"] = CSimpleStringA::Format("%d", tmpAllCost - m_ullAdpFileLoadCost);
+	std::pair<bool, std::string> strResult;
+	strResult = generateJsonStr(devConnInfo);
+
+	LogWarn(Severity_Low, Error_Unexpect, PinPad_UserErrorCode_DevConnect_CostTime, CSimpleStringA::Format("%s", strResult.second.c_str()));
 	LogWarn(Severity_Low, Error_Unexpect, PinPad_UserErrorCode_PinPad_InfoAboutKey_Onboot, xTmpStr.GetData());
 	LogEvent(Severity_Middle, LOG_EVT_PINPAD_OPEN_SUC, "Open pinpad suc.");
 
-	//oiltmp@20240521 add for redundancy to check
-	CSmartPointer<IConfigInfo> spConfigCen;
-	int iTmp = 0;
-	GetEntityBase()->GetFunction()->OpenConfig(Config_CenterSetting, spConfigCen);
-	if (spConfigCen->ReadConfigValueInt(GetEntityBase()->GetEntityName(), "UseBackupSN", iTmp) == Error_Succeed)
-	{
-		if (iTmp == 1)
-			m_bUseBackupSN = true;
-		else if (iTmp > 1)//to except default value 0
-			m_bUseBackupSN = false;
-	}
 	CSimpleStringA csRunInfo, csSNBakFile;
 	if ((eErr = GetEntityBase()->GetFunction()->GetPath("RunInfo", csRunInfo)) == Error_Succeed)
 	{
 		csSNBakFile = csRunInfo + SPLIT_SLASH_STR + "runcfg" + SPLIT_SLASH_STR + "snbak.dat";
-		ifstream infile(csSNBakFile, std::ofstream::binary);
+		ifstream infile(csSNBakFile.GetData(), std::ofstream::binary);
 		char* buffer = new char[16];
 		ZeroMemory(buffer, 16);
 		if (infile.is_open())
@@ -478,10 +487,7 @@ unsigned int __stdcall DoWork(void *pData)
 			SpReqAnsContext<PinPadService_GetInputJS_Req, PinPadService_GetInputJS_Ans>::Pointer ctxJS;
 			bool bRet = pFsm->GetJSCtx(ctxJS);
 			if (!bRet)
-			{
-				DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM)("get ctx(JS) failed.doing nothing");
 				continue;
-			}
 			ret = pFsm->GetInputJS(ctxJS);
 			evt = new FSMEvent(USER_EVT_GETINPUT_JS_FINISHED);
 		}
@@ -490,10 +496,7 @@ unsigned int __stdcall DoWork(void *pData)
 			SpReqAnsContext<PinPadService_GetInputSM_Req, PinPadService_GetInputSM_Ans>::Pointer ctxSM;
 			bool bRet = pFsm->GetCtx(ctxSM);
 			if (!bRet)
-			{
-				DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM)("get ctx failed.doing nothing");
 				continue;
-			}
 			ret = pFsm->GetInput(ctxSM);
 			evt = new FSMEvent(USER_EVT_GETINPUT_SM_FINISHED);
 		}
@@ -633,8 +636,6 @@ ErrorCodeEnum CPinPadFSM::GetEncryptText(SpReqAnsContext<PinPadService_GetInputS
 	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
 	if (errCode != Error_Succeed)
 	{
-		DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM)("[sm]set accout(%s)(%s) failed(%d).", (const char*)ctxSM->Req.account, accInfo.account, errCode);
-
 		DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetAccNo, "DevAdapter::SetAccNo", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
 		ctxSM->Answer(Error_DevCommFailed, dwUserCode);
 		return Error_DevCommFailed;
@@ -656,17 +657,20 @@ ErrorCodeEnum CPinPadFSM::GetEncryptText(SpReqAnsContext<PinPadService_GetInputS
 		return Error_DevCommFailed;
 	}
 	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_USER).setAPI("DevAdapter::ActiveWorkingKey").setCostTime(m_ullEndTime - m_ullBeginTime)();
-	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-	errCode = m_hDevHelper->SetParam(EPP_PT_SET_PIN_ALGORITH, EPP_PIN_ALGO_SM4);
-	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
-	
-	if (errCode != Error_Succeed)
+	if (!m_bSetParamOnce)
 	{
-		DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
-		ctxSM->Answer(Error_DevCommFailed, dwUserCode);
-		return Error_DevCommFailed;
+		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
+		errCode = m_hDevHelper->SetParam(EPP_PT_SET_PIN_ALGORITH, EPP_PIN_ALGO_SM4);
+		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
+
+		if (errCode != Error_Succeed)
+		{
+			DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
+			ctxSM->Answer(Error_DevCommFailed, dwUserCode);
+			return Error_DevCommFailed;
+		}
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 	}
-	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
 	errCode = m_hDevHelper->StartPinInput(len);
 	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
@@ -784,7 +788,7 @@ Err:
 		delete[]buf;
 	if (bCancelInput)
 	{
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_USER).setLogCode("QLR040220602")("input cancel(pin)");
+		DbgWithLink(LOG_LEVEL_DEBUG, LOG_TYPE_USER)("input cancel(pin)");
 		ctxSM->Answer(Error_Cancel);
 		return Error_Cancel;
 	}
@@ -827,20 +831,23 @@ Err:
 		memcpy(srcInfo.data, m_devCheckData, m_devCheckData.GetLength());
 		srcInfo.dwSize = m_devCheckData.GetLength();
 		memset(dstInfo.data, 0, MAX_EN_DECRYPT_DATA_SIZE);
-		//set param
-		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-		errCode = m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4);
-		if (errCode == Error_Succeed)
-			errCode = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC);
-		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
-		
-		if (errCode != Error_Succeed)
+		if (!m_bSetParamOnce)
 		{
-			DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
-			ctxSM->Answer(Error_Param, dwUserCode);
-			return Error_Param;
+			//set param
+			m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
+			errCode = m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4);
+			if (errCode == Error_Succeed)
+				errCode = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC);
+			m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
+
+			if (errCode != Error_Succeed)
+			{
+				DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
+				ctxSM->Answer(Error_Param, dwUserCode);
+				return Error_Param;
+			}
+			DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 		}
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
 		errCode = m_hDevHelper->EncryptData(srcInfo, dstInfo);
 		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
@@ -942,7 +949,9 @@ int CPinPadFSM::GetInput(SpReqAnsContext<PinPadService_GetInputSM_Req, PinPadSer
 			.setResultCode(GetEntityBase()->GetFunction()->UserCodeToRTACode(dwUserCode))("OnExit:close pinpad(%d).", SpStrError(errClosePinPad));
 	}
 	else
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::StopInput").setCostTime(m_ullEndTime - m_ullBeginTime)("StopInput cost(%d)ms", m_ullEndTime - m_ullBeginTime);
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::StopInput").setCostTime(m_ullEndTime - m_ullBeginTime)
+		("StopInput cost:%d(ms), req acc.len:%d,confirm:%d,len:%d. ans:ck.len:%d,traceid[%s]", m_ullEndTime - m_ullBeginTime, m_inputSMCtx->Req.account.GetLength(), m_inputSMCtx->Req.confirm
+			, m_inputSMCtx->Req.length, m_inputSMCtx->Ans.checkcode.IsNullOrEmpty() ? 0 : m_inputSMCtx->Ans.checkcode.GetLength(), m_inputSMCtx->link.traceId.GetData());
 
 	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM)
 		("req acc.len:%d,confirm:%d,len:%d. ans:ck.len:%d,traceid[%s]", m_inputSMCtx->Req.account.GetLength(), m_inputSMCtx->Req.confirm
@@ -980,7 +989,7 @@ int CPinPadFSM::LoadKeySM(SpReqAnsContext<PinPadService_LoadKeysSM_Req, PinPadSe
 
 	if (!(ctx->Req.smflag == 1))
 	{
-		DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_USER)("密钥标识不支持，ctx->Req.smflag:%d", ctx->Req.smflag);
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_USER)("密钥标识不支持，ctx->Req.smflag:%d", ctx->Req.smflag);
 		ctx->Answer(Error_Unexpect, PinPad_UserErrorCode_UnknownSMFlag);
 		return 0;
 	}
@@ -1110,22 +1119,24 @@ int CPinPadFSM::EncryptSM(SpReqAnsContext<PinPadService_EncryptDataSM_Req, PinPa
 
 	if (!(ctx->Req.smflag == 1))
 	{
-		DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_USER)("密钥标识不支持，ctx->Req.smflag:%d", ctx->Req.smflag);
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_USER)("密钥标识不支持，ctx->Req.smflag:%d", ctx->Req.smflag);
 		ctx->Answer(Error_Unexpect, PinPad_UserErrorCode_UnknownSMFlag);
 		return 0;
 	}
-	//set param
-	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-	if (m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4) != Error_Succeed
-		|| m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC) != Error_Succeed)
+	if (!m_bSetParamOnce)
 	{
-		DWORD dwUserCode = SetErrorAndLog(Error_Unexpect, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime);
-		ctx->Answer(Error_Unexpect, dwUserCode);
-		m_bEncrypt = false;
-		return 0;
+		//set param
+		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
+		if (m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4) != Error_Succeed
+			|| m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC) != Error_Succeed)
+		{
+			DWORD dwUserCode = SetErrorAndLog(Error_Unexpect, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime);
+			ctx->Answer(Error_Unexpect, dwUserCode);
+			m_bEncrypt = false;
+			return 0;
+		}
+		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
 	}
-	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
-
 	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
 	ErrorCodeEnum eErr = m_hDevHelper->ActiveWorkingKey(1, 1);
 	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
@@ -1179,25 +1190,30 @@ ErrorCodeEnum CPinPadFSM::GetCheckCode(SpReqAnsContext<PinPadService_GetCheckCod
 	for (int i = 0; i < ctx->Req.mSN.GetCount(); i++)
 	{
 		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM)("mSN:%d,wSN:%d,origData[%s]", ctx->Req.mSN[i], ctx->Req.wSN[i], m_devCheckData.GetData());
-		//set param
-		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-		if (ctx->Req.mSN[i] == 1)
-			eErr = m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4);
-		else
+		if (!m_bSetParamOnce)
 		{
-			DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_USER)("mSN:%d", ctx->Req.mSN[i]);
-			ctx->Ans.checkcode[i] = "";
-			ctx->Ans.index[i] = "";
-			continue;
-		}
-		if (eErr == Error_Succeed)
-			eErr = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC);
-		if (eErr != Error_Succeed)
-		{
-			SetErrorAndLog(eErr, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, false, m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetCheckCode);
-			return Error_DevCommFailed;
+			//set param
+			m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
+			if (ctx->Req.mSN[i] == 1)
+			{
+				eErr = m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4);
+			}
+			else
+			{
+				DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_USER)("not sm, mSN:%d", ctx->Req.mSN[i]);
+				ctx->Ans.checkcode[i] = "";
+				ctx->Ans.index[i] = "";
+				continue;
+			}
+			if (eErr == Error_Succeed)
+				eErr = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC);
+			if (eErr != Error_Succeed)
+			{
+				SetErrorAndLog(eErr, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, false, m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetCheckCode);
+				return Error_DevCommFailed;
+			}
+			m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
 		}
-		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
 
 		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
 		eErr = m_hDevHelper->ActiveWorkingKey(ctx->Req.mSN[i], ctx->Req.wSN[i]);
@@ -1328,8 +1344,6 @@ ErrorCodeEnum CPinPadFSM::GetEncryptTextJS(SpReqAnsContext<PinPadService_GetInpu
 	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
 	if (errCode != Error_Succeed)
 	{
-		DbgWithLink(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM)("[sm]set accout(%s)(%s) failed(%d).", (const char*)ctxJS->Req.account, accInfo.account, errCode);
-
 		DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetAccNo, "DevAdapter::SetAccNo", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
 		ctxJS->Answer(Error_DevCommFailed, dwUserCode);
 		return Error_DevCommFailed;
@@ -1351,17 +1365,20 @@ ErrorCodeEnum CPinPadFSM::GetEncryptTextJS(SpReqAnsContext<PinPadService_GetInpu
 		return Error_DevCommFailed;
 	}
 	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_USER).setAPI("DevAdapter::ActiveWorkingKey").setCostTime(m_ullEndTime - m_ullBeginTime)();
-	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-	errCode = m_hDevHelper->SetParam(EPP_PT_SET_PIN_ALGORITH, EPP_PIN_ALGO_SM4);
-	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
-
-	if (errCode != Error_Succeed)
+	if (!m_bSetParamOnce)
 	{
-		DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
-		ctxJS->Answer(Error_DevCommFailed, dwUserCode);
-		return Error_DevCommFailed;
+		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
+		errCode = m_hDevHelper->SetParam(EPP_PT_SET_PIN_ALGORITH, EPP_PIN_ALGO_SM4);
+		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
+
+		if (errCode != Error_Succeed)
+		{
+			DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
+			ctxJS->Answer(Error_DevCommFailed, dwUserCode);
+			return Error_DevCommFailed;
+		}
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 	}
-	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 	m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
 	errCode = m_hDevHelper->StartPinInput(CurrentPasswordLen);
 	m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
@@ -1432,7 +1449,7 @@ Err:
 		delete[]buf;
 	if (bCancelInput)
 	{
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_USER).setLogCode("QLR040220602")("input cancel(pin)");
+		DbgWithLink(LOG_LEVEL_DEBUG, LOG_TYPE_USER)("input cancel(pin)");
 		ctxJS->Answer(Error_Cancel);
 		return Error_Cancel;
 	}
@@ -1475,20 +1492,23 @@ Err:
 		memcpy(srcInfo.data, m_devCheckData, m_devCheckData.GetLength());
 		srcInfo.dwSize = m_devCheckData.GetLength();
 		memset(dstInfo.data, 0, MAX_EN_DECRYPT_DATA_SIZE);
-		//set param
-		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
-		errCode = m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4);
-		if (errCode == Error_Succeed)
-			errCode = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC);
-		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
-
-		if (errCode != Error_Succeed)
+		if (!m_bSetParamOnce)
 		{
-			DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
-			ctxJS->Answer(Error_Param, dwUserCode);
-			return Error_Param;
+			//set param
+			m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
+			errCode = m_hDevHelper->SetParam(EPP_PT_SET_ENCRYPT_METHOD, EPP_ALGO_METHOD_SM4);
+			if (errCode == Error_Succeed)
+				errCode = m_hDevHelper->SetParam(EPP_PT_SET_ECB_CBC_MODE, EPP_ALGO_MODE_CBC);
+			m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
+
+			if (errCode != Error_Succeed)
+			{
+				DWORD dwUserCode = SetErrorAndLog(errCode, MEC_DEVAPI_EPP_SetParam, "DevAdapter::SetParam", __FUNCTION__, IsInBusiness(), m_ullEndTime - m_ullBeginTime, PinPadService_LogCode_GetInputSM);
+				ctxJS->Answer(Error_Param, dwUserCode);
+				return Error_Param;
+			}
+			DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 		}
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::SetParam").setCostTime(m_ullEndTime - m_ullBeginTime)();
 		m_ullBeginTime = SP::Module::Comm::RVCGetTickCount();
 		errCode = m_hDevHelper->EncryptData(srcInfo, dstInfo);
 		m_ullEndTime = SP::Module::Comm::RVCGetTickCount();
@@ -1579,11 +1599,10 @@ int CPinPadFSM::GetInputJS(SpReqAnsContext<PinPadService_GetInputJS_Req, PinPadS
 			.setResultCode(GetEntityBase()->GetFunction()->UserCodeToRTACode(dwUserCode))("OnExit:close pinpad(%d).", SpStrError(errClosePinPad));
 	}
 	else
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::StopInput").setCostTime(m_ullEndTime - m_ullBeginTime)("StopInput cost(%d)ms", m_ullEndTime - m_ullBeginTime);
-
-	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM)
-		("req acc.len:%d,ans.ck.len:%d,traceId:[%s]", m_inputJSCtx->Req.account.GetLength(), m_inputJSCtx->Ans.checkcode.IsNullOrEmpty() ? 0 : m_inputJSCtx->Ans.checkcode.GetLength()
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI("DevAdapter::StopInput").setCostTime(m_ullEndTime - m_ullBeginTime)
+		("StopInput cost:%d(ms), req acc.len:%d,ans.ck.len:%d,traceId:[%s]", m_ullEndTime - m_ullBeginTime, m_inputJSCtx->Req.account.GetLength(), m_inputJSCtx->Ans.checkcode.IsNullOrEmpty() ? 0 : m_inputJSCtx->Ans.checkcode.GetLength()
 			, m_inputJSCtx->link.traceId.GetData());
+		
 	DbgToBeidou(m_inputJSCtx->link, "GetInputJS")();
 	m_bPinInputJS = false;
 	LogEvent(Severity_Middle, LOG_EVT_PINPAD_GREEN_OFF, "PinPad light off.");

Module/mod_pinpad/PinPadFSM.h

@@ -174,7 +174,7 @@ public:
 		, m_dwDevCommFailCount(0), m_dwPinPadRunCount(0), m_encryptkey(1)
 		, m_bSM(false), m_bSMLoaded(false), m_szModel(""), m_szType("")
 		, m_szVendor(""),m_csMachineType(true), m_terminalNo(true)
-		, m_bPinInputJS(false), m_bUseBackupSN(true){
+		, m_bPinInputJS(false), m_bUseBackupSN(true), m_bSetParamOnce(false){
 			HARDWARE_ENTITY_RESET_ENTITYID(m_entCode, 0x206);
 			ZeroMemory(&m_adapterInfo, sizeof(m_adapterInfo));
 	}
@@ -285,8 +285,8 @@ private:
 	SpReqAnsContext<PinPadService_GetInputJS_Req, PinPadService_GetInputJS_Ans>::Pointer m_inputJSCtx;
 	char m_szAccount[MAX_ACCOUNT_LEN];
 	bool m_bFrontCancel,m_bWaitingMore,m_bExit,m_bPlainPin,m_bEntityExit
-		,m_bPinInput,m_bLoadKey,m_bEncrypt,m_bSM,m_bSMLoaded, m_bPinInputJS, m_bUseBackupSN/*if use backup sn*/;
-	ULLINT m_ullBeginTime, m_ullEndTime,m_ullConnectCost;
+		,m_bPinInput,m_bLoadKey,m_bEncrypt,m_bSM,m_bSMLoaded, m_bPinInputJS, m_bUseBackupSN/*if use backup sn*/, m_bSetParamOnce/*call SetParam Only once*/;
+	ULLINT m_ullBeginTime, m_ullEndTime, m_ullAdpFileLoadCost, m_ullEntityStart;
 	CSimpleStringA m_deviceNo, m_devCheckData,m_keySNSM,m_szModel,m_szType,m_szVendor;
 	char m_buf[4];
 	DWORD m_dwDevCommFailCount,m_dwPinPadRunCount;

Module/mod_pinpad/PinPad_UserErrorCode.h

@@ -15,7 +15,7 @@ enum PinPad_UserErrorCode {
 	PinPad_UserErrorCode_KEY_LOST_SM = 0x2060020A,
 	PinPad_UserErrorCode_PINPAD_KEY_LOST = 0x2060020B,
 	PinPad_UserErrorCode_Create_Event_Failed = 0x2060020C,
-	PinPad_UserErrorCode_LoadAdapterCost = 0x2060020d,	//the cost time of load vendor adapter dll/so file
+	//PinPad_UserErrorCode_LoadAdapterCost = 0x2060020d,	//the cost time of load vendor adapter dll/so file
 	PinPad_UserErrorCode_Load_Dll_File_Failed = 0x2060020E,
 	PinPad_UserErrorCode_GET_CDC_ADDR_Failed = 0x2060020F,
 	PinPad_UserErrorCode_GET_RDC_ADDR_Failed = 0x20600210,