From 3e93eb55ae9c4f4f49c6a05051733619005c1b8a Mon Sep 17 00:00:00 2001 From: Manuel Pietschmann Date: Wed, 29 May 2024 12:30:07 +0200 Subject: [PATCH] DDF loader improve logging; load DDFs where mfname constant is unknown (#7796) - Reduce noise in `--dbg-ddf` log output - More error logging while loading DDFs - Load raw JSON DDFs where manufacturer name constant can't be resolved This is for ongoing investigation of https://github.com/dresden-elektronik/deconz-rest-plugin/issues/7783 --- device_ddf_init.cpp | 10 ++++++-- device_descriptions.cpp | 51 +++++++++++++++++++++++++++++++++++------ 2 files changed, 52 insertions(+), 9 deletions(-) diff --git a/device_ddf_init.cpp b/device_ddf_init.cpp index 7e63870fdb..2346f04450 100644 --- a/device_ddf_init.cpp +++ b/device_ddf_init.cpp @@ -74,11 +74,17 @@ static ResourceItem *DEV_InitDeviceDescriptionItem(const DeviceDescription::Item if (item) { - DBG_Printf(DBG_DDF, "sub-device: %s, has item: %s\n", uniqueId, ddfItem.descriptor.suffix); + if (DBG_IsEnabled(DBG_INFO_L2)) + { + DBG_Printf(DBG_DDF, "sub-device: %s, has item: %s\n", uniqueId, ddfItem.descriptor.suffix); + } } else { - DBG_Printf(DBG_DDF, "sub-device: %s, create item: %s\n", uniqueId, ddfItem.descriptor.suffix); + if (DBG_IsEnabled(DBG_INFO_L2)) + { + DBG_Printf(DBG_DDF, "sub-device: %s, create item: %s\n", uniqueId, ddfItem.descriptor.suffix); + } item = rsub->addItem(ddfItem.descriptor.type, ddfItem.descriptor.suffix); DBG_Assert(item); diff --git a/device_descriptions.cpp b/device_descriptions.cpp index 50a0462c81..47a5a2415a 100644 --- a/device_descriptions.cpp +++ b/device_descriptions.cpp @@ -1995,6 +1995,8 @@ void DeviceDescriptions::readAllRawJson() return; } + DBG_Printf(DBG_DDF, "DDF try to find raw JSON DDFs for %u identifier pairs\n", (unsigned)d->ddfLoadRecords.size()); + DDF_ParseContext *pctx = new(ctx_mem)DDF_ParseContext; // placement new into scratch memory, no further cleanup needed U_ASSERT(pctx); pctx->extChunks = nullptr; @@ -2027,11 +2029,17 @@ void DeviceDescriptions::readAllRawJson() { if (DDF_ReadConstantsJson(pctx, d->constants2)) { + DBG_Printf(DBG_DDF, "DDF loaded %d string constants from %s\n", (int)d->constants2.size(), pctx->filePath); hasConstants = true; } } } + if (d->constants2.empty() || !hasConstants) // should not happen + { + DBG_Printf(DBG_DDF, "DDF failed to load string constants\n"); + } + U_ASSERT(hasConstants); for (size_t dit = 0; dit < locations.size(); dit++) @@ -2110,7 +2118,10 @@ void DeviceDescriptions::readAllRawJson() if (result.isValid()) { result.storageLocation = locations[dit]; - U_Sha256(pctx->fileData, pctx->fileDataSize, (unsigned char*)&result.sha256Hash[0]); + if (U_Sha256(pctx->fileData, pctx->fileDataSize, (unsigned char*)&result.sha256Hash[0]) == 0) + { + DBG_Printf(DBG_DDF, "DDF failed to create SHA-256 hash of DDF\n"); + } unsigned j = 0; unsigned k = 0; @@ -2152,6 +2163,9 @@ void DeviceDescriptions::readAllRawJson() AT_AtomIndex mfnameIndex; AT_AtomIndex modelidIndex; + mfnameIndex.index = 0; + modelidIndex.index = 0; + /* * Try to get atoms for the mfname/modelid pair. * Note: If they don't exist, this isn't the pair we are looking for! @@ -2162,7 +2176,15 @@ void DeviceDescriptions::readAllRawJson() const QByteArray m = constantToString(result.manufacturerNames[j]).toUtf8(); if (AT_GetAtomIndex(m.constData(), (unsigned)m.size(), &mfnameIndex) != 1) { - continue; + if (m.startsWith('$')) + { + DBG_Printf(DBG_DDF, "DDF failed to resolve constant %s\n", m.data()); + // continue here anyway as long as modelid matches + } + else + { + continue; + } } } @@ -2176,10 +2198,17 @@ void DeviceDescriptions::readAllRawJson() for (k = 0; k < d->ddfLoadRecords.size(); k++) { - if (mfnameIndex.index == d->ddfLoadRecords[k].mfname.index && - modelidIndex.index == d->ddfLoadRecords[k].modelid.index) + if (modelidIndex.index == d->ddfLoadRecords[k].modelid.index) { - //d->ddfLoadRecords[k].loadState = DDF_LoadStateLoadedRawJson; + if (mfnameIndex.index == 0) + { + // ignore for now, in worst case we load a DDF to memory which isn't used + U_ASSERT(0); + } + else if (mfnameIndex.index != d->ddfLoadRecords[k].mfname.index) + { + continue; + } scheduled = true; break; } @@ -2191,6 +2220,10 @@ void DeviceDescriptions::readAllRawJson() } } } + else + { + DBG_Printf(DBG_DDF, "DDF ignore %s due unequal manufacturername/modelid array sizes\n", pctx->filePath); + } if (scheduled) { @@ -2219,6 +2252,7 @@ void DeviceDescriptions::readAllRawJson() } } + DBG_Printf(DBG_DDF, "DDF cache raw JSON DDF %s\n", pctx->filePath); d->descriptions.push_back(std::move(result)); } } @@ -2248,7 +2282,7 @@ void DeviceDescriptions::readAllRawJson() ddf = DDF_LoadScripts(ddf); } - DBG_Printf(DBG_DDF, "loaded %d DDFs\n", (int)d->descriptions.size()); + DBG_Printf(DBG_DDF, "DDF loaded %d raw JSON DDFs\n", (int)d->descriptions.size()); } DBG_MEASURE_END(DDF_ReadRawJson); @@ -3272,7 +3306,10 @@ static DeviceDescription::Item DDF_ParseItem(DDF_ParseContext *pctx, const QJson } } - DBG_Printf(DBG_DDF, "DDF loaded resource item descriptor: %s, public: %u\n", result.descriptor.suffix, (result.isPublic ? 1 : 0)); + if (DBG_IsEnabled(DBG_INFO_L2)) + { + DBG_Printf(DBG_DDF, "DDF loaded resource item descriptor: %s, public: %u\n", result.descriptor.suffix, (result.isPublic ? 1 : 0)); + } } else {