From d8bfbbf4fce48cd8b578d2707d20f04c7070fdf5 Mon Sep 17 00:00:00 2001 From: wiechula Date: Sat, 18 Nov 2023 22:09:07 +0100 Subject: [PATCH] Speed up SACs, improved error messages, fix stream alignment * Speed up using custom hex string to int convertion, some orders of magnitude * Add packet position information in error messages * Fix false error message in initial string alignment * Fix wrong error message in packet count check overflowing 16bit boundary --- .../include/TPCCalibration/SACDecoder.h | 2 + Detectors/TPC/calibration/src/SACDecoder.cxx | 71 ++++++++++++++----- 2 files changed, 56 insertions(+), 17 deletions(-) diff --git a/Detectors/TPC/calibration/include/TPCCalibration/SACDecoder.h b/Detectors/TPC/calibration/include/TPCCalibration/SACDecoder.h index d16efc8995e8d..a57d9cafd10ff 100644 --- a/Detectors/TPC/calibration/include/TPCCalibration/SACDecoder.h +++ b/Detectors/TPC/calibration/include/TPCCalibration/SACDecoder.h @@ -233,6 +233,8 @@ class Decoder uint32_t mDebugLevel{0}; ///< Amount of debug information to print + uint32_t decodeTimeStamp(const char* data); + /// \return status message: 1 = good, 0 = data length too short, -1 = decoding error int decodeChannels(DecodedDataFE& sacs, size_t& carry, int feid); void decode(int feid); diff --git a/Detectors/TPC/calibration/src/SACDecoder.cxx b/Detectors/TPC/calibration/src/SACDecoder.cxx index 49cfc81e067d5..0be11eba500ba 100644 --- a/Detectors/TPC/calibration/src/SACDecoder.cxx +++ b/Detectors/TPC/calibration/src/SACDecoder.cxx @@ -60,7 +60,7 @@ bool Decoder::process(const char* data, size_t size) // check packet counters are increasing by one // - if (lastPacketInstance && (packetInstance != (lastPacketInstance + 1))) { + if (lastPacketInstance && (uint16_t(packetInstance) != uint16_t(lastPacketInstance + 1))) { // convert to uint16_t to respect size of sac.header.pktCount LOGP(error, "Packet for instance {} missing, last packet {}, this packet {}", instance, lastPacketInstance, packetInstance); } @@ -137,6 +137,29 @@ int Decoder::decodeChannels(DecodedDataFE& sacs, size_t& carry, int feid) return 1; } +uint32_t Decoder::decodeTimeStamp(const char* data) +{ + int carry = 0; + uint32_t value = 0; + for (int i = 0; i < 8; ++i) { + const auto c = data[carry]; + uint32_t nibble = 0; + if ((c >= '0') && (c <= '9')) { + nibble = c - '0'; + } else if ((c >= 'A') && (c <= 'F')) { + nibble = c - 'A' + 10; + } else { + LOGP(error, "unexpected '{}' in time stamp", data[carry]); + break; + } + value <<= 4; + value |= (nibble & 0xF); + ++carry; + } + + return value; +} + void Decoder::decode(int feid) { const auto startTime = HighResClock::now(); @@ -190,11 +213,7 @@ void Decoder::decode(int feid) const auto streamStart = carry; // time stamp comes after channel data ++carry; - std::string_view vd(&data[carry], 8); - std::stringstream str(vd.data()); - str.flags(std::ios_base::hex); - uint32_t timeStamp; - str >> timeStamp; + uint32_t timeStamp = decodeTimeStamp(&data[carry]); decdata.timeStamp = timeStamp; decAdditional.timeStamp = timeStamp; @@ -226,7 +245,8 @@ void Decoder::decode(int feid) auto& refCount = mTSCountFEs[feid].second; // NOTE: use (refTime > 1) instead of (refTime > 0), since in some cases the packet with TS 0 is missing if ((refCount == 0) && (refTime > 1)) { - LOGP(info, "Skipping initial data packet {} with time stamp {} for FE {}", mTSCountFEs[feid].first, timeStamp, feid); + LOGP(detail, "Skipping initial data packet {} with time stamp {} for FE {}", + mTSCountFEs[feid].first, timeStamp, feid); } else { if (refTime < firstRefTime) { // LOGP(info, "FE {}: {} < {}, adding {} DataPoint(s)", feid, refTime, firstRefTime, firstRefTime - refTime); @@ -240,12 +260,18 @@ void Decoder::decode(int feid) mDecodedData.setData(refTime - firstRefTime, refTime, decdata, feid); if (refCount != refTime) { - LOGP(warning, "Unexpected time stamp in FE {}. Count {} != TS {} ({}), dump: {}", feid, refCount, refTime, timeStamp, std::string_view(&data[streamStart], std::min(size_t(20), dataSize - streamStart - carry))); // NOTE: be graceful in case TS 0 is missing and avoid furhter warnings + if (!((refCount == 0) && (refTime == 1))) { + LOGP(warning, "Unexpected time stamp in FE {}. Count {} != TS {} ({}), dump: {}", feid, refCount, refTime, timeStamp, std::string_view(&data[streamStart], std::min(size_t(20), dataSize - streamStart - carry))); + } if (((refCount == 0) && (refTime == 1)) || ((mReAlignType == ReAlignType::AlignAndFillMissing) && syncLost)) { while (refCount < refTime) { mDecodedData.setData(refCount - firstRefTime, refCount, DecodedDataFE(), feid); - LOGP(warning, "Adding dummy data for FE {}, TS {}", feid, refCount); + if ((refCount == 0) && (refTime == 1)) { + LOGP(info, "Adding dummy data for FE {}, TS {}", feid, refCount); + } else { + LOGP(warning, "Adding dummy data for FE {}, TS {}", feid, refCount); + } ++refCount; } syncLost = false; @@ -293,22 +319,33 @@ void Decoder::decode(int feid) } ++carry; } else if (data[carry] >= 'a' && data[carry] <= 'z') { - if (mReAlignType != ReAlignType::None) { - LOGP(error, "Skipping {} for FE {}, trying to re-align data stream", data[carry], feid); - aligned = false; - syncLost = true; - } else { - LOGP(error, "Skipping {} for FE {}, might lead to decoding problems", data[carry], feid); + if (mTSCountFEs[feid].first == 0) { + // in case we still haven't processed the first packet we simply skip end sequence termination and continue + LOGP(info, "Skipping {} for FE {}, time stamp packet count {}, ref count {}", + data[carry], feid, mTSCountFEs[feid].first, mTSCountFEs[feid].second); ++carry; + } else { + if (mReAlignType != ReAlignType::None) { + LOGP(warning, "Skipping {} for FE {}, trying to re-align data stream, time stamp packet count {}, ref count {}", + data[carry], feid, mTSCountFEs[feid].first, mTSCountFEs[feid].second); + aligned = false; + syncLost = true; + } else { + LOGP(error, "Skipping {} for FE {}, might lead to decoding problems, time stamp packet count {}, ref count {}", + data[carry], feid, mTSCountFEs[feid].first, mTSCountFEs[feid].second); + ++carry; + } } decdata.reset(); } else { if (mReAlignType != ReAlignType::None) { - LOGP(warn, "Can't interpret position for FE {}, {} / {}, {}, trying to re-align data stream\n", feid, carry, dataSize, std::string_view(&data[carry - 8], std::min(size_t(20), dataSize - 8 - carry))); + LOGP(warn, "Can't interpret position for FE {}, {} / {}, {}, trying to re-align data stream, time stamp packet count {}, ref count {}", + feid, carry, dataSize, std::string_view(&data[carry - 8], std::min(size_t(20), dataSize - 8 - carry)), mTSCountFEs[feid].first, mTSCountFEs[feid].second); aligned = false; syncLost = true; } else { - LOGP(error, "Can't interpret position for FE {}, {} / {}, {}, stopping decoding\n", feid, carry, dataSize, std::string_view(&data[carry - 8], std::min(size_t(20), dataSize - 8 - carry))); + LOGP(error, "Can't interpret position for FE {}, {} / {}, {}, stopping decoding, time stamp packet count {}, ref count {}", + feid, carry, dataSize, std::string_view(&data[carry - 8], std::min(size_t(20), dataSize - 8 - carry)), mTSCountFEs[feid].first, mTSCountFEs[feid].second); break; } }