From c3fce0af243b70b30f664f8be76986226d5d9a02 Mon Sep 17 00:00:00 2001 From: rejoe2 Date: Thu, 16 Mar 2023 16:51:28 +0100 Subject: [PATCH] MI - optimize debug output and resending logic --- src/hm/miPayload.h | 89 +++++++++++++++++++++++++++------------------- 1 file changed, 52 insertions(+), 37 deletions(-) diff --git a/src/hm/miPayload.h b/src/hm/miPayload.h index 931c9657..7e32ea92 100644 --- a/src/hm/miPayload.h +++ b/src/hm/miPayload.h @@ -92,11 +92,11 @@ class MiPayload { iv->setQueuedCmdFinished(); // command failed if (mSerialDebug) - DPRINTLN(DBG_INFO, F("enqueued cmd failed/timeout")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("enqueued cmd failed/timeout")); if (mSerialDebug) { - DPRINT(DBG_INFO, F("(#")); - DBGPRINT(String(iv->id)); - DBGPRINT(F(") no Payload received! (retransmits: ")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINT(F("no Payload received! (retransmits: ")); DBGPRINT(String(mPayload[iv->id].retransmits)); DBGPRINTLN(F(")")); } @@ -109,17 +109,15 @@ class MiPayload { yield(); if (mSerialDebug){ - DPRINT(DBG_INFO, F("(#")); - DBGPRINT(String(iv->id)); - DBGPRINT(F(") Requesting Inv SN ")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINT(F("Requesting Inv SN ")); DBGPRINTLN(String(iv->config->serial.u64, HEX)); } if (iv->getDevControlRequest()) { if (mSerialDebug) { - DPRINT(DBG_INFO, F("(#")); - DBGPRINT(String(iv->id)); - DBGPRINT(F(") Devcontrol request 0x")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINT(F("Devcontrol request 0x")); DBGPRINT(String(iv->devControlCmd, HEX)); DBGPRINT(F(" power limit ")); DBGPRINTLN(String(iv->powerLimit[0])); @@ -130,9 +128,8 @@ class MiPayload { //iv->enqueCommand(SystemConfigPara); // read back power limit } else { uint8_t cmd = iv->getQueuedCmd(); - DPRINT(DBG_INFO, F("(#")); - DBGPRINT(String(iv->id)); - DBGPRINT(F(") prepareDevInformCmd 0x")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINT(F("prepareDevInformCmd 0x")); DBGPRINTLN(String(cmd, HEX)); uint8_t cmd2 = cmd; if (cmd == 0x1 ) { //0x1 @@ -225,10 +222,12 @@ const byteAssign_t InfoAssignment[] = { mStat->rxSuccess++; mSys->Radio.sendCmdPacket(iv->radioId.u64, 0x0f, 0x01, false);*/ } else if ( p->packet[9] == 0x01 ) {//second frame - DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") got 2nd frame (hw info)")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("got 2nd frame (hw info)")); //mSys->Radio.sendCmdPacket(iv->radioId.u64, 0x0f, 0x12, false); } else if ( p->packet[9] == 0x12 ) {//3rd frame - DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") got 3rd frame (hw info)")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("got 3rd frame (hw info)")); iv->setQueuedCmdFinished(); mStat->rxSuccess++; } @@ -262,7 +261,8 @@ const byteAssign_t InfoAssignment[] = { } } */ } else if (p->packet[0] == (TX_REQ_DEVCONTROL + ALL_FRAMES)) { // response from dev control command - DPRINTLN(DBG_DEBUG, F("Response from devcontrol request received")); + miDPRINTHead(DBG_DEBUG, iv->id); + DBGPRINTLN(F("Response from devcontrol request received")); mPayload[iv->id].txId = p->packet[0]; iv->clearDevControlRequest(); @@ -273,7 +273,10 @@ const byteAssign_t InfoAssignment[] = { mApp->setMqttPowerLimitAck(iv); else msg = "NOT "; - DPRINTLN(DBG_INFO, F("Inverter ") + String(iv->id) + F(" has ") + msg + F("accepted power limit set point ") + String(iv->powerLimit[0]) + F(" with PowerLimitControl ") + String(iv->powerLimit[1])); + //DPRINTLN(DBG_INFO, F("Inverter ") + String(iv->id) + F(" has ") + msg + F("accepted power limit set point ") + String(iv->powerLimit[0]) + F(" with PowerLimitControl ") + String(iv->powerLimit[1])); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("has ") + msg + F("accepted power limit set point ") + String(iv->powerLimit[0]) + F(" with PowerLimitControl ") + String(iv->powerLimit[1])); + iv->clearCmdQueue(); iv->enqueCommand(SystemConfigPara); // read back power limit } @@ -376,21 +379,20 @@ const byteAssign_t InfoAssignment[] = { if ((mPayload[iv->id].requested) && (retransmit)) { if (iv->devControlCmd == Restart || iv->devControlCmd == CleanState_LockAndAlarm) { // This is required to prevent retransmissions without answer. - DPRINTLN(DBG_INFO, F("Prevent retransmit on Restart / CleanState_LockAndAlarm...")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("Prevent retransmit on Restart / CleanState_LockAndAlarm...")); mPayload[iv->id].retransmits = mMaxRetrans; } else if(iv->devControlCmd == ActivePowerContr) { - DPRINT(DBG_INFO, F("(#")); - DBGPRINT(String(iv->id)); - DBGPRINTLN(F(") retransmit power limit")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("retransmit power limit")); mSys->Radio.sendControlPacket(iv->radioId.u64, iv->devControlCmd, iv->powerLimit, true); } else { uint8_t cmd = mPayload[iv->id].txCmd; if (mPayload[iv->id].retransmits < mMaxRetrans) { mPayload[iv->id].retransmits++; if( !mPayload[iv->id].gotFragment ) { - DPRINT(DBG_INFO, F("(#")); - DBGPRINT(String(iv->id)); - DBGPRINTLN(F(") nothing received")); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("nothing received")); mPayload[iv->id].retransmits = mMaxRetrans; } else if ( cmd == 0x0f ) { //hard/firmware request @@ -404,23 +406,23 @@ const byteAssign_t InfoAssignment[] = { change = true; } else if ( cmd == 0x09 ) {//MI single or dual channel device if ( mPayload[iv->id].dataAB[CH1] && iv->type == INV_TYPE_2CH ) { - if (!mPayload[iv->id].stsAB[CH2] || !mPayload[iv->id].dataAB[CH2] ) { + if (!mPayload[iv->id].stsAB[CH1] && mPayload[iv->id].retransmits<2) {} + //first try to get missing sts for first channel a second time + else if (!mPayload[iv->id].stsAB[CH2] || !mPayload[iv->id].dataAB[CH2] ) { cmd = 0x11; change = true; mPayload[iv->id].retransmits = 0; //reset counter } } } else if ( cmd == 0x11) { - if ( mPayload[iv->id].dataAB[CH2] ) { // data is there, but no status - if (!mPayload[iv->id].stsAB[CH1] || !mPayload[iv->id].dataAB[CH1] ) { + if ( mPayload[iv->id].dataAB[CH2] ) { // data + status ch2 are there? + if (mPayload[iv->id].stsAB[CH2] && (!mPayload[iv->id].stsAB[CH1] || !mPayload[iv->id].dataAB[CH1])) { cmd = 0x09; change = true; } } } - DPRINT(DBG_INFO, F("(#")); - DBGPRINT(String(iv->id)); - DBGPRINT(F(") ")); + miDPRINTHead(DBG_INFO, iv->id); if (change) { DBGPRINT(F("next request is 0x")); } else { @@ -438,9 +440,12 @@ const byteAssign_t InfoAssignment[] = { } else if(!crcPass && pyldComplete) { // crc error on complete Payload if (mPayload[iv->id].retransmits < mMaxRetrans) { mPayload[iv->id].retransmits++; - DPRINTLN(DBG_WARN, F("CRC Error: Request Complete Retransmit")); + miDPRINTHead(DBG_WARN, iv->id); + DBGPRINTLN(F("CRC Error: Request Complete Retransmit")); mPayload[iv->id].txCmd = iv->getQueuedCmd(); - DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") prepareDevInformCmd 0x") + String(mPayload[iv->id].txCmd, HEX)); + miDPRINTHead(DBG_INFO, iv->id); + + DBGPRINTLN(F("prepareDevInformCmd 0x") + String(mPayload[iv->id].txCmd, HEX)); mSys->Radio.prepareDevInformCmd(iv->radioId.u64, mPayload[iv->id].txCmd, mPayload[iv->id].ts, iv->alarmMesIndex, true); } } @@ -516,7 +521,7 @@ const byteAssign_t InfoAssignment[] = { } void miStsDecode(Inverter<> *iv, packet_t *p, uint8_t stschan = CH1) { - DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") status msg 0x") + String(p->packet[0], HEX)); + //DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") status msg 0x") + String(p->packet[0], HEX)); record_t<> *rec = iv->getRecordStruct(RealTimeRunData_Debug); // choose the record structure rec->ts = mPayload[iv->id].ts; mPayload[iv->id].gotFragment = true; @@ -537,7 +542,8 @@ const byteAssign_t InfoAssignment[] = { if (iv->alarmMesIndex < rec->record[iv->getPosByChFld(0, FLD_EVT, rec)]){ iv->alarmMesIndex = rec->record[iv->getPosByChFld(0, FLD_EVT, rec)]; // seems there's no status per channel in 3rd gen. models?!? - DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") alarm ID incremented to ") + String(iv->alarmMesIndex)); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("alarm ID incremented to ") + String(iv->alarmMesIndex)); iv->enqueCommand(AlarmData); } //mPayload[iv->id].skipfirstrepeat = 1; @@ -555,7 +561,7 @@ const byteAssign_t InfoAssignment[] = { ( p->packet[0] == 0x91 || p->packet[0] == (0x37 + ALL_FRAMES) ) ? CH2 : p->packet[0] == (0x38 + ALL_FRAMES) ? CH3 : CH4; - DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") data msg 0x") + String(p->packet[0], HEX) + F(" channel ") + datachan); + //DPRINTLN(DBG_INFO, F("(#") + String(iv->id) + F(") data msg 0x") + String(p->packet[0], HEX) + F(" channel ") + datachan); // count in RF_communication_protocol.xlsx is with offset = -1 iv->setValue(iv->getPosByChFld(datachan, FLD_UDC, rec), rec, (float)((p->packet[9] << 8) + p->packet[10])/10); yield(); @@ -613,7 +619,8 @@ const byteAssign_t InfoAssignment[] = { if (iv->alarmMesIndex < rec->record[iv->getPosByChFld(0, FLD_EVT, rec)]){ iv->alarmMesIndex = rec->record[iv->getPosByChFld(0, FLD_EVT, rec)]; - DPRINTLN(DBG_INFO, F("alarm ID incremented to ") + String(iv->alarmMesIndex)); + miDPRINTHead(DBG_INFO, iv->id); + DBGPRINTLN(F("alarm ID incremented to ") + String(iv->alarmMesIndex)); //iv->enqueCommand(AlarmData); } @@ -699,8 +706,16 @@ const byteAssign_t InfoAssignment[] = { return true; } + void miDPRINTHead(uint8_t lvl, uint8_t id) { + DPRINT(lvl, F("(#")); + DBGPRINT(String(id)); + DBGPRINT(F(") ")); + } + void reset(uint8_t id) { - DPRINTLN(DBG_INFO, F("resetPayload: id: ") + String(id)); + //DPRINTLN(DBG_INFO, F("resetPayload: id: ") + String(id)); + miDPRINTHead(DBG_INFO, id); + DBGPRINTLN(F("resetPayload")); memset(mPayload[id].len, 0, MAX_PAYLOAD_ENTRIES); mPayload[id].gotFragment = false; /*mPayload[id].maxPackId = MAX_PAYLOAD_ENTRIES;