增加日志

This commit is contained in:
chenjiangqun
2026-06-29 10:50:43 +08:00
parent 39fbf5570c
commit 6d31ffc78d

View File

@@ -1654,14 +1654,15 @@ namespace WinISP
DDC_SetToolFlag(true); DDC_SetToolFlag(true);
if (_binFilePath == String.Empty) if (_binFilePath == String.Empty)
{ {
frmISP.WriteLog("binFilePath is NULL", "debug"); frmISP.WriteLog("binFilePath is NULL", "error");
return; return;
} }
bool suppressSendFileFail = _suppressSendFileFailMessage; bool suppressSendFileFail = _suppressSendFileFailMessage;
_suppressSendFileFailMessage = false; _suppressSendFileFailMessage = false;
if (suppressSendFileFail) if (suppressSendFileFail)
SetStatusMsg("Ready"); SetStatusMsg("Ready");
frmISP.WriteLog("Start ISP", "debug"); frmISP.WriteLog("===== Start ISP =====", "info");
frmISP.WriteLog("binFilePath = " + _binFilePath + ", simI2cCtrl = " + _simI2cCtrl, "info");
//int totalFailCnt1 = 0; //int totalFailCnt1 = 0;
int failCnt = 0; int failCnt = 0;
int checkSumFailCnt = 0; int checkSumFailCnt = 0;
@@ -1675,6 +1676,7 @@ namespace WinISP
int rdCheckSum = 0, rdPktCnt = 0; int rdCheckSum = 0, rdPktCnt = 0;
int checkSum = 0, sentLen = 0, pktLen = 0; int checkSum = 0, sentLen = 0, pktLen = 0;
int totalBytes = bin.Length; int totalBytes = bin.Length;
frmISP.WriteLog("Bin loaded. totalBytes = " + totalBytes + " (" + (totalBytes / 1024) + " KB)", "info");
int start = GetTickCount(); int start = GetTickCount();
int end = 0; int end = 0;
@@ -1694,12 +1696,14 @@ namespace WinISP
sector.CheckEmpty(); sector.CheckEmpty();
flashSectorInfo.Add(sector); flashSectorInfo.Add(sector);
} }
frmISP.WriteLog("flashSectorInfo built. sectorCount = " + flashSectorInfo.Count + ", sectorSize = " + _flashSectorSize, "debug");
} }
// QueryConnectedMonitorInfo(); // QueryConnectedMonitorInfo();
string checkErr; string checkErr;
if (!ValidateMonitorVsBin(out checkErr)) if (!ValidateMonitorVsBin(out checkErr))
{ {
frmISP.WriteLog("[Validate-PreConnect] ValidateMonitorVsBin FAIL: " + checkErr, "error");
SetStatusMsg(checkErr, true); SetStatusMsg(checkErr, true);
btnAuto.Enabled = false; btnAuto.Enabled = false;
return; return;
@@ -1709,6 +1713,7 @@ namespace WinISP
int imgNum = 0; int imgNum = 0;
retryCnt = 0; retryCnt = 0;
DDC_GetISPImgNum(ref imgNum); DDC_GetISPImgNum(ref imgNum);
frmISP.WriteLog("DDC_GetISPImgNum -> imgNum = " + imgNum, "debug");
if (imgNum == 1) if (imgNum == 1)
{ {
MessageBox.Show(this, "Update firmware will continue without reboot at startup. Display will reboot after update success.", this.Text); MessageBox.Show(this, "Update firmware will continue without reboot at startup. Display will reboot after update success.", this.Text);
@@ -1718,26 +1723,34 @@ namespace WinISP
Byte chipType = 0; Byte chipType = 0;
while ((IsConnect == false) && (retryCnt++ < MaxRetryCnt)) while ((IsConnect == false) && (retryCnt++ < MaxRetryCnt))
{ {
IsConnect = DDC_CheckMTKDevice(ref chipType); bool rMtk = DDC_CheckMTKDevice(ref chipType);
IsConnect = rMtk;
if (IsConnect) if (IsConnect)
{ {
frmISP.WriteLog("[Connect] try#" + retryCnt + " hit by DDC_CheckMTKDevice, chipType=" + chipType, "info");
break; break;
} }
IsConnect = DDC_CheckClientInfo(ref chipType); bool rClient = DDC_CheckClientInfo(ref chipType);
IsConnect = rClient;
if (IsConnect) if (IsConnect)
{ {
frmISP.WriteLog("[Connect] try#" + retryCnt + " hit by DDC_CheckClientInfo, chipType=" + chipType, "info");
break; break;
} }
IsConnect = DDC_CheckPanelInfo(ref chipType); bool rPanel = DDC_CheckPanelInfo(ref chipType);
IsConnect = rPanel;
if (IsConnect) if (IsConnect)
{ {
frmISP.WriteLog("[Connect] try#" + retryCnt + " hit by DDC_CheckPanelInfo, chipType=" + chipType, "info");
break; break;
} }
frmISP.WriteLog("[Connect] try#" + retryCnt + " ALL FAIL. MTK=" + rMtk + " Client=" + rClient + " Panel=" + rPanel + " chipType=" + chipType, "debug");
WinIOLib.DelayMs(1000); WinIOLib.DelayMs(1000);
} }
if (IsConnect == false) if (IsConnect == false)
{ {
frmISP.WriteLog("[Connect] FAIL after " + (retryCnt - 1) + " retries. chipType=" + chipType, "error");
SetStatusMsg("Initialize ISP connection fail."); SetStatusMsg("Initialize ISP connection fail.");
SetISPStatus(false, "Initialize ISP connection fail."); SetISPStatus(false, "Initialize ISP connection fail.");
return; return;
@@ -1746,13 +1759,14 @@ namespace WinISP
_chipType = chipType; _chipType = chipType;
switch (chipType) switch (chipType)
{ {
case 0: { frmISP.WriteLog("MTKChipType=Not Defined", "debug"); } break; case 0: { frmISP.WriteLog("MTKChipType=Not Defined", "warn"); } break;
case 1: { frmISP.WriteLog("MTKChipType=TSUM", "debug"); } break; case 1: { frmISP.WriteLog("MTKChipType=TSUM", "info"); } break;
case 2: { frmISP.WriteLog("MTKChipType=MST9U", "debug"); } break; case 2: { frmISP.WriteLog("MTKChipType=MST9U", "info"); } break;
} }
string verifyErr; string verifyErr;
if (!ValidateMonitorVsBin(out verifyErr)) if (!ValidateMonitorVsBin(out verifyErr))
{ {
frmISP.WriteLog("[Validate-PostConnect] ValidateMonitorVsBin FAIL: " + verifyErr, "error");
SetStatusMsg(verifyErr, true); SetStatusMsg(verifyErr, true);
SetISPStatus(false); SetISPStatus(false);
btnAuto.Enabled = false; btnAuto.Enabled = false;
@@ -1770,14 +1784,17 @@ namespace WinISP
DDC_GetRecvInfo(ref rdSize); DDC_GetRecvInfo(ref rdSize);
if (rdSize == bin.Length) if (rdSize == bin.Length)
break; break;
frmISP.WriteLog("[InitFileInfo] try#" + retryCnt + " mismatch. expect=" + bin.Length + " rdSize=" + rdSize, "debug");
} }
if (rdSize != bin.Length) if (rdSize != bin.Length)
{ {
frmISP.WriteLog("[InitFileInfo] FAIL after retries. expect=" + bin.Length + " rdSize=" + rdSize, "error");
SetStatusMsg("Initialize file Information fail."); SetStatusMsg("Initialize file Information fail.");
SetISPStatus(false, "Initialize file Information fail."); SetISPStatus(false, "Initialize file Information fail.");
return; return;
} }
frmISP.WriteLog("[InitFileInfo] OK. rdSize=" + rdSize, "info");
///////Compare ISP////////////////// ///////Compare ISP//////////////////
List<FlashSectorInfo> rootFlash = new List<FlashSectorInfo>(); List<FlashSectorInfo> rootFlash = new List<FlashSectorInfo>();
@@ -1787,6 +1804,7 @@ namespace WinISP
path += "\\rootimage.bin"; path += "\\rootimage.bin";
if (System.IO.File.Exists(path)) if (System.IO.File.Exists(path))
{ {
frmISP.WriteLog("[CompareISP] rootimage.bin found, building rootFlash...", "info");
Byte[] rootBin = InitBinaryFile(path); Byte[] rootBin = InitBinaryFile(path);
for (int idx = 0; idx < rootBin.Length; idx += _flashSectorSize) for (int idx = 0; idx < rootBin.Length; idx += _flashSectorSize)
{ {
@@ -1806,7 +1824,6 @@ namespace WinISP
rootFlash.Add(sector); rootFlash.Add(sector);
} }
UInt32 crc = 0, rdCrc = 0; UInt32 crc = 0, rdCrc = 0;
int rdImgOneCheckSum = 0; int rdImgOneCheckSum = 0;
for (int idx = 0; idx < 21; idx++) for (int idx = 0; idx < 21; idx++)
@@ -1822,7 +1839,9 @@ namespace WinISP
canExecuteCompareISP = true; canExecuteCompareISP = true;
break; break;
} }
frmISP.WriteLog("[CompareISP] CRC mismatch retry#" + retry + " expCRC=" + crc.ToString("X8") + " rdCRC=" + rdCrc.ToString("X8"), "debug");
} }
frmISP.WriteLog("[CompareISP] CRC check result canExecuteCompareISP=" + canExecuteCompareISP + " expCRC=" + crc.ToString("X8") + " rdCRC=" + rdCrc.ToString("X8"), "info");
if (canExecuteCompareISP) if (canExecuteCompareISP)
{ {
@@ -1840,20 +1859,29 @@ namespace WinISP
else else
{ {
canExecuteCompareISP = false; canExecuteCompareISP = false;
frmISP.WriteLog("[CompareISP] ImgOneCheckSum mismatch retry#" + retry + " expCS=" + imgCheckSum.ToString("X4") + " rdCS=" + rdImgOneCheckSum.ToString("X4"), "debug");
WinIOLib.DelayMs(1000); WinIOLib.DelayMs(1000);
} }
} }
frmISP.WriteLog("[CompareISP] FastISP shadow result canExecuteCompareISP=" + canExecuteCompareISP + " imgCheckSum=" + imgCheckSum.ToString("X4"), "info");
} }
} }
else
{
frmISP.WriteLog("[CompareISP] rootimage.bin NOT found, full write mode.", "info");
}
// SetStatusMsg("Transfer Parameter adjusting ..."); // SetStatusMsg("Transfer Parameter adjusting ...");
int maxPktLen = 0, pktDelayTime = 0; int maxPktLen = 0, pktDelayTime = 0;
int maxDelayHint = Math.Max(Convert.ToInt32(_pktDelayTimeText) * 3, 300); int maxDelayHint = Math.Max(Convert.ToInt32(_pktDelayTimeText) * 3, 300);
AdjustPacketParam(defaultPktLen, ref maxPktLen, maxDelayHint, ref pktDelayTime); AdjustPacketParam(defaultPktLen, ref maxPktLen, maxDelayHint, ref pktDelayTime);
frmISP.WriteLog("maxPktLen = " + Convert.ToString(maxPktLen) + ", pktDelayTime = " + Convert.ToString(pktDelayTime) + "", "debug"); frmISP.WriteLog("maxPktLen = " + Convert.ToString(maxPktLen) + ", pktDelayTime = " + Convert.ToString(pktDelayTime) + "", "info");
#if DEBUG #if DEBUG
if (Convert.ToInt32(_pktDelayTimeText) > 0) if (Convert.ToInt32(_pktDelayTimeText) > 0)
{
pktDelayTime = Convert.ToInt32(_pktDelayTimeText); pktDelayTime = Convert.ToInt32(_pktDelayTimeText);
frmISP.WriteLog("[DEBUG] pktDelayTime overridden by _pktDelayTimeText = " + pktDelayTime, "debug");
}
#endif #endif
retryCnt = 0; retryCnt = 0;
while (retryCnt++ < MaxRetryCnt) while (retryCnt++ < MaxRetryCnt)
@@ -1863,6 +1891,7 @@ namespace WinISP
DDC_GetRecvInfo(ref rdSize); DDC_GetRecvInfo(ref rdSize);
if (rdSize == bin.Length) if (rdSize == bin.Length)
break; break;
frmISP.WriteLog("[ReInitFileInfo] try#" + retryCnt + " mismatch. expect=" + bin.Length + " rdSize=" + rdSize, "debug");
} }
//Send data //Send data
FlashSectorInfo si; FlashSectorInfo si;
@@ -1871,6 +1900,7 @@ namespace WinISP
start = GetTickCount(); start = GetTickCount();
int wroteSectorCnt = 0; int wroteSectorCnt = 0;
retryCnt = 0; retryCnt = 0;
frmISP.WriteLog("===== Begin transfer. totalSector=" + flashSectorInfo.Count + " fastISP=" + canExecuteCompareISP + " =====", "info");
for (int cnt = 0; cnt < flashSectorInfo.Count; cnt++) for (int cnt = 0; cnt < flashSectorInfo.Count; cnt++)
{ {
IsDiffSector = false; IsDiffSector = false;
@@ -1899,6 +1929,7 @@ namespace WinISP
//bypass empty sector //bypass empty sector
if (SetSentInfo(sentLen + _flashSectorSize) == false) if (SetSentInfo(sentLen + _flashSectorSize) == false)
{ {
frmISP.WriteLog("[Transfer] SetSentInfo(bypass-diff) FAIL at sector " + cnt + " sentLen=" + sentLen, "error");
if (!suppressSendFileFail) if (!suppressSendFileFail)
{ {
SetStatusMsg("Send file fail."); SetStatusMsg("Send file fail.");
@@ -1922,6 +1953,7 @@ namespace WinISP
//bypass empty sector //bypass empty sector
if (SetSentInfo(sentLen + _flashSectorSize) == false) if (SetSentInfo(sentLen + _flashSectorSize) == false)
{ {
frmISP.WriteLog("[Transfer] SetSentInfo(bypass-empty) FAIL at sector " + cnt + " sentLen=" + sentLen, "error");
if (!suppressSendFileFail) if (!suppressSendFileFail)
{ {
SetStatusMsg("Send file fail."); SetStatusMsg("Send file fail.");
@@ -1968,6 +2000,12 @@ namespace WinISP
} }
if ((sentLen != rdPktCnt) || (checkSum != rdCheckSum)) if ((sentLen != rdPktCnt) || (checkSum != rdCheckSum))
{ {
// 仅在 mismatch 时打印诊断三元组,避免高频日志拖垮 UI 线程
frmISP.WriteLog("[Transfer] MISMATCH sector=" + cnt
+ " expLen=" + sentLen + " rdLen=" + rdPktCnt
+ " expCS=" + checkSum.ToString("X4") + " rdCS=" + rdCheckSum.ToString("X4")
+ " retry=" + retryCnt + " failCnt=" + failCnt, "warn");
retryCnt++; retryCnt++;
failCnt++; failCnt++;
sentLen -= _flashSectorSize; sentLen -= _flashSectorSize;
@@ -1982,6 +2020,7 @@ namespace WinISP
//reset sent info //reset sent info
if (SetSentInfo(sentLen) == false) if (SetSentInfo(sentLen) == false)
{ {
frmISP.WriteLog("[Transfer] SetSentInfo(reset) FAIL. sentLen=" + sentLen + " sector=" + cnt, "error");
if (!suppressSendFileFail) if (!suppressSendFileFail)
{ {
SetStatusMsg("Send file fail."); SetStatusMsg("Send file fail.");
@@ -1997,6 +2036,8 @@ namespace WinISP
if (retryCnt > MaxRetryCnt) if (retryCnt > MaxRetryCnt)
{ {
frmISP.WriteLog("[Transfer] FAIL: retryCnt(" + retryCnt + ") > MaxRetryCnt(" + MaxRetryCnt + ")."
+ " lenFail=" + lenFailCnt + " csFail=" + checkSumFailCnt + " failCnt=" + failCnt, "error");
if (!suppressSendFileFail) if (!suppressSendFileFail)
{ {
SetStatusMsg("Send file fail."); SetStatusMsg("Send file fail.");
@@ -2024,9 +2065,9 @@ namespace WinISP
if (sentLen >= bin.Length) if (sentLen >= bin.Length)
sentLen = bin.Length; sentLen = bin.Length;
if ((cnt == 0) && (end > 4000)) //terminate ISP when 4K bytes per sec large than 4 sec if ((cnt == 0) && (end > 4000)) //terminate ISP when 4K bytes per sec large than 4 sec
{ {
frmISP.WriteLog("[Transfer] first sector slow: end=" + end + "ms (threshold 4000ms). NOT terminated (commented out).", "warn");
//SetStatusMsg("Procedure is terminated, because data transfer speed is abnormal."); //SetStatusMsg("Procedure is terminated, because data transfer speed is abnormal.");
//btnUploadFlash.Enabled = true; //btnUploadFlash.Enabled = true;
//SetISPStatus(false); //SetISPStatus(false);
@@ -2038,7 +2079,8 @@ namespace WinISP
} }
UInt16 fileCheckSum = 0; UInt16 fileCheckSum = 0;
frmISP.WriteLog("TransferTime = " + end.ToString(), "debug"); frmISP.WriteLog("TransferTime = " + end.ToString() + " ms, wroteSector=" + wroteSectorCnt + "/" + flashSectorInfo.Count
+ " lenFail=" + lenFailCnt + " csFail=" + checkSumFailCnt + " failCnt=" + failCnt, "info");
#if AUTO_SEARCH #if AUTO_SEARCH
Transfer_Time = end; Transfer_Time = end;
Total_Transfer_Time += (ulong)end; Total_Transfer_Time += (ulong)end;
@@ -2047,10 +2089,11 @@ namespace WinISP
{ {
fileCheckSum += bin[idx]; fileCheckSum += bin[idx];
} }
frmISP.WriteLog("fileCheckSum = " + fileCheckSum.ToString("X4"), "debug");
//Execute ISP //Execute ISP
DDC_RunISP(fileCheckSum); DDC_RunISP(fileCheckSum);
frmISP.WriteLog("DDC_RunISP issued. fileCheckSum=" + fileCheckSum.ToString("X4"), "info");
WinIOLib.DelayMs(1000); WinIOLib.DelayMs(1000);
prbProgress.Value = flashSectorInfo.Count; prbProgress.Value = flashSectorInfo.Count;
@@ -2083,6 +2126,7 @@ namespace WinISP
{ {
waitUpdateFWCnt = 960; waitUpdateFWCnt = 960;
} }
frmISP.WriteLog("[WaitUpdate] binLen=" + binLen + "KB, waitUpdateFWCnt=" + waitUpdateFWCnt + "s", "info");
while (retryCnt++ < waitUpdateFWCnt) while (retryCnt++ < waitUpdateFWCnt)
{ {
@@ -2097,13 +2141,17 @@ namespace WinISP
//DDC_GetSentInfo(ref rdCheckSum, ref rdPktCnt); //DDC_GetSentInfo(ref rdCheckSum, ref rdPktCnt);
DDC_GetISPStatus(ref status/*, pktDelayTime*/); DDC_GetISPStatus(ref status/*, pktDelayTime*/);
if ((status == 2) || (status == 1))//0:Init, 1: fail, 2: success if ((status == 2) || (status == 1))//0:Init, 1: fail, 2: success
{
frmISP.WriteLog("[WaitUpdate] break at try#" + retryCnt + " status=" + status, "info");
break; break;
} }
}
//how to check fw is update success? //how to check fw is update success?
end = GetTickCount() - start; end = GetTickCount() - start;
if (status == 2) if (status == 2)
{ {
frmISP.WriteLog("===== ISP SUCCESS. status=" + status + " totalTime=" + end + "ms =====", "info");
// Do NOT call Connect() here: the monitor firmware is rebooting and DDC is // Do NOT call Connect() here: the monitor firmware is rebooting and DDC is
// not ready yet, which would cause a spurious "not compatible" error message. // not ready yet, which would cause a spurious "not compatible" error message.
SetStatusMsg("Update firmware success. Please reset the power of display."); SetStatusMsg("Update firmware success. Please reset the power of display.");
@@ -2111,6 +2159,8 @@ namespace WinISP
} }
else else
{ {
frmISP.WriteLog("===== ISP FAIL. status=" + status + " totalTime=" + end + "ms"
+ " lenFail=" + lenFailCnt + " csFail=" + checkSumFailCnt + " failCnt=" + failCnt + " =====", "error");
SetStatusMsg("Update firmware fail, " + "Elapsed Time : " + (end / 1000).ToString() + " s", true); SetStatusMsg("Update firmware fail, " + "Elapsed Time : " + (end / 1000).ToString() + " s", true);
} }