diff --git a/WIN10_WinISP_SrcCode_For_MOKA_20250416_1/WinISP/FormISP_MSI.cs b/WIN10_WinISP_SrcCode_For_MOKA_20250416_1/WinISP/FormISP_MSI.cs index b240c98..768434d 100644 --- a/WIN10_WinISP_SrcCode_For_MOKA_20250416_1/WinISP/FormISP_MSI.cs +++ b/WIN10_WinISP_SrcCode_For_MOKA_20250416_1/WinISP/FormISP_MSI.cs @@ -1654,14 +1654,15 @@ namespace WinISP DDC_SetToolFlag(true); if (_binFilePath == String.Empty) { - frmISP.WriteLog("binFilePath is NULL", "debug"); + frmISP.WriteLog("binFilePath is NULL", "error"); return; } bool suppressSendFileFail = _suppressSendFileFailMessage; _suppressSendFileFailMessage = false; if (suppressSendFileFail) SetStatusMsg("Ready"); - frmISP.WriteLog("Start ISP", "debug"); + frmISP.WriteLog("===== Start ISP =====", "info"); + frmISP.WriteLog("binFilePath = " + _binFilePath + ", simI2cCtrl = " + _simI2cCtrl, "info"); //int totalFailCnt1 = 0; int failCnt = 0; int checkSumFailCnt = 0; @@ -1675,6 +1676,7 @@ namespace WinISP int rdCheckSum = 0, rdPktCnt = 0; int checkSum = 0, sentLen = 0, pktLen = 0; int totalBytes = bin.Length; + frmISP.WriteLog("Bin loaded. totalBytes = " + totalBytes + " (" + (totalBytes / 1024) + " KB)", "info"); int start = GetTickCount(); int end = 0; @@ -1694,21 +1696,24 @@ namespace WinISP sector.CheckEmpty(); flashSectorInfo.Add(sector); } + frmISP.WriteLog("flashSectorInfo built. sectorCount = " + flashSectorInfo.Count + ", sectorSize = " + _flashSectorSize, "debug"); } - // QueryConnectedMonitorInfo(); - string checkErr; - if (!ValidateMonitorVsBin(out checkErr)) - { - SetStatusMsg(checkErr, true); - btnAuto.Enabled = false; - return; - } + // QueryConnectedMonitorInfo(); + string checkErr; + if (!ValidateMonitorVsBin(out checkErr)) + { + frmISP.WriteLog("[Validate-PreConnect] ValidateMonitorVsBin FAIL: " + checkErr, "error"); + SetStatusMsg(checkErr, true); + btnAuto.Enabled = false; + return; + } prbProgress.Maximum = flashSectorInfo.Count; prbProgress.Value = 0; int imgNum = 0; retryCnt = 0; DDC_GetISPImgNum(ref imgNum); + frmISP.WriteLog("DDC_GetISPImgNum -> imgNum = " + imgNum, "debug"); if (imgNum == 1) { 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; while ((IsConnect == false) && (retryCnt++ < MaxRetryCnt)) { - IsConnect = DDC_CheckMTKDevice(ref chipType); + bool rMtk = DDC_CheckMTKDevice(ref chipType); + IsConnect = rMtk; if (IsConnect) { + frmISP.WriteLog("[Connect] try#" + retryCnt + " hit by DDC_CheckMTKDevice, chipType=" + chipType, "info"); break; } - IsConnect = DDC_CheckClientInfo(ref chipType); + bool rClient = DDC_CheckClientInfo(ref chipType); + IsConnect = rClient; if (IsConnect) { + frmISP.WriteLog("[Connect] try#" + retryCnt + " hit by DDC_CheckClientInfo, chipType=" + chipType, "info"); break; } - IsConnect = DDC_CheckPanelInfo(ref chipType); + bool rPanel = DDC_CheckPanelInfo(ref chipType); + IsConnect = rPanel; if (IsConnect) { + frmISP.WriteLog("[Connect] try#" + retryCnt + " hit by DDC_CheckPanelInfo, chipType=" + chipType, "info"); break; } + frmISP.WriteLog("[Connect] try#" + retryCnt + " ALL FAIL. MTK=" + rMtk + " Client=" + rClient + " Panel=" + rPanel + " chipType=" + chipType, "debug"); WinIOLib.DelayMs(1000); } if (IsConnect == false) { + frmISP.WriteLog("[Connect] FAIL after " + (retryCnt - 1) + " retries. chipType=" + chipType, "error"); SetStatusMsg("Initialize ISP connection fail."); SetISPStatus(false, "Initialize ISP connection fail."); return; @@ -1746,13 +1759,14 @@ namespace WinISP _chipType = chipType; switch (chipType) { - case 0: { frmISP.WriteLog("MTKChipType=Not Defined", "debug"); } break; - case 1: { frmISP.WriteLog("MTKChipType=TSUM", "debug"); } break; - case 2: { frmISP.WriteLog("MTKChipType=MST9U", "debug"); } break; + case 0: { frmISP.WriteLog("MTKChipType=Not Defined", "warn"); } break; + case 1: { frmISP.WriteLog("MTKChipType=TSUM", "info"); } break; + case 2: { frmISP.WriteLog("MTKChipType=MST9U", "info"); } break; } string verifyErr; if (!ValidateMonitorVsBin(out verifyErr)) { + frmISP.WriteLog("[Validate-PostConnect] ValidateMonitorVsBin FAIL: " + verifyErr, "error"); SetStatusMsg(verifyErr, true); SetISPStatus(false); btnAuto.Enabled = false; @@ -1770,14 +1784,17 @@ namespace WinISP DDC_GetRecvInfo(ref rdSize); if (rdSize == bin.Length) break; + frmISP.WriteLog("[InitFileInfo] try#" + retryCnt + " mismatch. expect=" + bin.Length + " rdSize=" + rdSize, "debug"); } if (rdSize != bin.Length) { + frmISP.WriteLog("[InitFileInfo] FAIL after retries. expect=" + bin.Length + " rdSize=" + rdSize, "error"); SetStatusMsg("Initialize file Information fail."); SetISPStatus(false, "Initialize file Information fail."); return; } + frmISP.WriteLog("[InitFileInfo] OK. rdSize=" + rdSize, "info"); ///////Compare ISP////////////////// List rootFlash = new List(); @@ -1787,6 +1804,7 @@ namespace WinISP path += "\\rootimage.bin"; if (System.IO.File.Exists(path)) { + frmISP.WriteLog("[CompareISP] rootimage.bin found, building rootFlash...", "info"); Byte[] rootBin = InitBinaryFile(path); for (int idx = 0; idx < rootBin.Length; idx += _flashSectorSize) { @@ -1806,7 +1824,6 @@ namespace WinISP rootFlash.Add(sector); } - UInt32 crc = 0, rdCrc = 0; int rdImgOneCheckSum = 0; for (int idx = 0; idx < 21; idx++) @@ -1822,7 +1839,9 @@ namespace WinISP canExecuteCompareISP = true; 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) { @@ -1840,20 +1859,29 @@ namespace WinISP else { canExecuteCompareISP = false; + frmISP.WriteLog("[CompareISP] ImgOneCheckSum mismatch retry#" + retry + " expCS=" + imgCheckSum.ToString("X4") + " rdCS=" + rdImgOneCheckSum.ToString("X4"), "debug"); 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 ..."); int maxPktLen = 0, pktDelayTime = 0; int maxDelayHint = Math.Max(Convert.ToInt32(_pktDelayTimeText) * 3, 300); 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 (Convert.ToInt32(_pktDelayTimeText) > 0) - pktDelayTime = Convert.ToInt32(_pktDelayTimeText); + if (Convert.ToInt32(_pktDelayTimeText) > 0) + { + pktDelayTime = Convert.ToInt32(_pktDelayTimeText); + frmISP.WriteLog("[DEBUG] pktDelayTime overridden by _pktDelayTimeText = " + pktDelayTime, "debug"); + } #endif retryCnt = 0; while (retryCnt++ < MaxRetryCnt) @@ -1863,6 +1891,7 @@ namespace WinISP DDC_GetRecvInfo(ref rdSize); if (rdSize == bin.Length) break; + frmISP.WriteLog("[ReInitFileInfo] try#" + retryCnt + " mismatch. expect=" + bin.Length + " rdSize=" + rdSize, "debug"); } //Send data FlashSectorInfo si; @@ -1871,6 +1900,7 @@ namespace WinISP start = GetTickCount(); int wroteSectorCnt = 0; retryCnt = 0; + frmISP.WriteLog("===== Begin transfer. totalSector=" + flashSectorInfo.Count + " fastISP=" + canExecuteCompareISP + " =====", "info"); for (int cnt = 0; cnt < flashSectorInfo.Count; cnt++) { IsDiffSector = false; @@ -1899,6 +1929,7 @@ namespace WinISP //bypass empty sector if (SetSentInfo(sentLen + _flashSectorSize) == false) { + frmISP.WriteLog("[Transfer] SetSentInfo(bypass-diff) FAIL at sector " + cnt + " sentLen=" + sentLen, "error"); if (!suppressSendFileFail) { SetStatusMsg("Send file fail."); @@ -1922,6 +1953,7 @@ namespace WinISP //bypass empty sector if (SetSentInfo(sentLen + _flashSectorSize) == false) { + frmISP.WriteLog("[Transfer] SetSentInfo(bypass-empty) FAIL at sector " + cnt + " sentLen=" + sentLen, "error"); if (!suppressSendFileFail) { SetStatusMsg("Send file fail."); @@ -1968,6 +2000,12 @@ namespace WinISP } 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++; failCnt++; sentLen -= _flashSectorSize; @@ -1982,6 +2020,7 @@ namespace WinISP //reset sent info if (SetSentInfo(sentLen) == false) { + frmISP.WriteLog("[Transfer] SetSentInfo(reset) FAIL. sentLen=" + sentLen + " sector=" + cnt, "error"); if (!suppressSendFileFail) { SetStatusMsg("Send file fail."); @@ -1997,6 +2036,8 @@ namespace WinISP if (retryCnt > MaxRetryCnt) { + frmISP.WriteLog("[Transfer] FAIL: retryCnt(" + retryCnt + ") > MaxRetryCnt(" + MaxRetryCnt + ")." + + " lenFail=" + lenFailCnt + " csFail=" + checkSumFailCnt + " failCnt=" + failCnt, "error"); if (!suppressSendFileFail) { SetStatusMsg("Send file fail."); @@ -2024,9 +2065,9 @@ namespace WinISP if (sentLen >= bin.Length) sentLen = bin.Length; - 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."); //btnUploadFlash.Enabled = true; //SetISPStatus(false); @@ -2038,19 +2079,21 @@ namespace WinISP } 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 - Transfer_Time = end; - Total_Transfer_Time += (ulong)end; + Transfer_Time = end; + Total_Transfer_Time += (ulong)end; #endif for (int idx = 0; idx < bin.Length; idx++) { fileCheckSum += bin[idx]; } - + frmISP.WriteLog("fileCheckSum = " + fileCheckSum.ToString("X4"), "debug"); //Execute ISP DDC_RunISP(fileCheckSum); + frmISP.WriteLog("DDC_RunISP issued. fileCheckSum=" + fileCheckSum.ToString("X4"), "info"); WinIOLib.DelayMs(1000); prbProgress.Value = flashSectorInfo.Count; @@ -2083,6 +2126,7 @@ namespace WinISP { waitUpdateFWCnt = 960; } + frmISP.WriteLog("[WaitUpdate] binLen=" + binLen + "KB, waitUpdateFWCnt=" + waitUpdateFWCnt + "s", "info"); while (retryCnt++ < waitUpdateFWCnt) { @@ -2097,13 +2141,17 @@ namespace WinISP //DDC_GetSentInfo(ref rdCheckSum, ref rdPktCnt); DDC_GetISPStatus(ref status/*, pktDelayTime*/); if ((status == 2) || (status == 1))//0:Init, 1: fail, 2: success + { + frmISP.WriteLog("[WaitUpdate] break at try#" + retryCnt + " status=" + status, "info"); break; + } } //how to check fw is update success? end = GetTickCount() - start; 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 // not ready yet, which would cause a spurious "not compatible" error message. SetStatusMsg("Update firmware success. Please reset the power of display."); @@ -2111,6 +2159,8 @@ namespace WinISP } 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); }