From 6d08fac5e16b03f4e198a79663d10e7be40434e5 Mon Sep 17 00:00:00 2001 From: Ken Zangelin Date: Wed, 30 Aug 2023 09:59:20 +0200 Subject: [PATCH 1/2] Added extensive traces for downloading of contexts --- src/lib/logMsg/traceLevels.h | 1 + .../orionld/context/orionldContextFromUrl.cpp | 68 ++++++++++++++++++- 2 files changed, 67 insertions(+), 2 deletions(-) diff --git a/src/lib/logMsg/traceLevels.h b/src/lib/logMsg/traceLevels.h index d59b6d9cb7..d772ecd717 100644 --- a/src/lib/logMsg/traceLevels.h +++ b/src/lib/logMsg/traceLevels.h @@ -89,6 +89,7 @@ typedef enum TraceLevels LmtContexts = 80, // Contexts LmtContextTree, // Context Tree LmtContextCache, // Context Cache + LmtContextDownload, // Context Download LmtCoreContext, // Core Context // GeoJSON diff --git a/src/lib/orionld/context/orionldContextFromUrl.cpp b/src/lib/orionld/context/orionldContextFromUrl.cpp index a8275e95c0..54dd470417 100644 --- a/src/lib/orionld/context/orionldContextFromUrl.cpp +++ b/src/lib/orionld/context/orionldContextFromUrl.cpp @@ -74,19 +74,44 @@ bool contextDownloadListLookup(const char* url) { StringListItem* itemP = contextDownloadList; + LM_T(LmtContextDownload, ("Looking for context URL '%s'", url)); while (itemP != NULL) { + LM_T(LmtContextDownload, ("Comparing existing '%s' to wanted '%s'", itemP->name, url)); if (strcmp(itemP->name, url) == 0) + { + LM_T(LmtContextDownload, ("Found a match: '%s'", url)); return true; + } itemP = itemP->next; } + LM_T(LmtContextDownload, ("Found no match for '%s'", url)); return false; } +// ----------------------------------------------------------------------------- +// +// contextDownloadListDebug - +// +static void contextDownloadListDebug(const char* what) +{ + LM_T(LmtContextDownload, ("contextDownloadList (%s)", what)); + LM_T(LmtContextDownload, ("----------------------------------------------------")); + + for (StringListItem* iterP = contextDownloadList; iterP != NULL; iterP = iterP->next) + { + LM_T(LmtContextDownload, (" o %s", iterP->name)); + } + + LM_T(LmtContextDownload, ("----------------------------------------------------")); +} + + + // ----------------------------------------------------------------------------- // // contextDownloadListAdd - add a URL to the list @@ -95,9 +120,11 @@ void contextDownloadListAdd(const char* url) { StringListItem* itemP = (StringListItem*) malloc(sizeof(StringListItem)); + LM_T(LmtContextDownload, ("Adding '%s' to contextDownloadList", url)); strncpy(itemP->name, url, sizeof(itemP->name) - 1); itemP->next = contextDownloadList; contextDownloadList = itemP; + contextDownloadListDebug("after item added"); } @@ -112,6 +139,8 @@ void contextDownloadListRemove(const char* url) StringListItem* prevP = NULL; StringListItem* itemP = NULL; + LM_T(LmtContextDownload, ("Removing '%s' from contextDownloadList", url)); + while (iterP != NULL) { if (strcmp(iterP->name, url) == 0) @@ -125,23 +154,31 @@ void contextDownloadListRemove(const char* url) } if (itemP == NULL) // Not found! + { + LM_T(LmtContextDownload, ("Cannot find '%s' in contextDownloadList", url)); return; + } if (prevP == NULL) // Found as the first item of the list { + LM_T(LmtContextDownload, ("Removing '%s' as first item in contextDownloadList", url)); contextDownloadList = itemP->next; free(itemP); } else if (itemP->next == NULL) // Found as the last item of the list { + LM_T(LmtContextDownload, ("Removing '%s' as last item in contextDownloadList", url)); prevP->next = NULL; free(itemP); } else // Found in the middle of the list { + LM_T(LmtContextDownload, ("Removing '%s' as middle item in contextDownloadList", url)); prevP->next = itemP->next; free(itemP); } + + contextDownloadListDebug("after item removal"); } @@ -178,16 +215,24 @@ static OrionldContext* contextCacheWait(char* url) int sleepTime = 0; OrionldContext* contextP; + LM_T(LmtContextDownload, ("Awaiting a context download by other (URL: %s)", url)); + while (sleepTime < 3000000) // 3 secs - 3 million microsecs ... CLI param? { usleep(20000); // sleep 20 millisecs ... CLI param? + LM_T(LmtContextDownload, ("Awaiting context download: looking up context '%s'", url)); contextP = orionldContextCacheLookup(url); if (contextP != NULL) + { + LM_T(LmtContextDownload, ("Got it! (%s)", url)); return contextP; + } + LM_T(LmtContextDownload, ("Still not there (%s)", url)); sleepTime += 20000; } + LM_T(LmtContextDownload, ("Timeout during download of an @context (%s)", url)); - // The wait timed out - assuming the URL is invalid, this a "400 Bad Request" + // The wait timed out orionldError(OrionldInternalError, "Timeout during download of an @context", url, 504); return NULL; } @@ -200,10 +245,15 @@ static OrionldContext* contextCacheWait(char* url) // OrionldContext* orionldContextFromUrl(char* url, char* id) { + LM_T(LmtContextDownload, ("Downloading a context URL: '%s'", url)); + OrionldContext* contextP = orionldContextCacheLookup(url); if (contextP != NULL) + { + LM_T(LmtContextDownload, ("Found already downloaded URL '%s'", url)); return contextP; + } // // Make sure the context isn't already being downloaded @@ -228,7 +278,9 @@ OrionldContext* orionldContextFromUrl(char* url, char* id) // Not there, so, we'll download it // First take the 'download semaphore' // + LM_T(LmtContextDownload, ("The context '%s' is not downloading, getting the downloadList semaphore", url)); sem_wait(&contextDownloadListSem); + LM_T(LmtContextDownload, ("Got the downloadList semaphore for '%s'", url)); // // OK - got the semaphore - but, did I have to wait? @@ -237,25 +289,37 @@ OrionldContext* orionldContextFromUrl(char* url, char* id) // If the URL is in 'contextDownloadList' then somebody else took the semaphore before me // and started downloading. // + LM_T(LmtContextDownload, ("Looking up '%s' again, in case I got the semaphore late", url)); urlDownloading = contextDownloadListLookup(url); if (urlDownloading == false) + { + LM_T(LmtContextDownload, ("The context '%s' is not downloading by other - will be downloaded here", url)); contextDownloadListAdd(url); // CASE 1: Mark the URL as being downloading + } + LM_T(LmtContextDownload, ("Giving back the downloadList semaphore for '%s'", url)); sem_post(&contextDownloadListSem); if (urlDownloading == true) // If somebody has taken the semaphore before me and is downloading the context - I'll have to wait + { + LM_T(LmtContextDownload, ("The context '%s' is downloading by other - I wait until it's done", url)); return contextCacheWait(url); // CASE 2 - another thread has downloaded the context + } // CASE 1 - the context will be downloaded } else + { + LM_T(LmtContextDownload, ("The context '%s' is downloading by other - I wait until it's done", url)); return contextCacheWait(url); // CASE 3 - another thread has downloaded the context + } + LM_T(LmtContextDownload, ("Downloading the context '%s' and adding it to the context cache", url)); char* buffer = orionldContextDownload(url); // orionldContextDownload fills in ProblemDetails if (buffer == NULL) return NULL; - LM_T(LmtCoreContext, ("Downloaded the conext '%s'", url)); + LM_T(LmtCoreContext, ("Downloaded the context '%s'", url)); contextP = orionldContextFromBuffer(url, OrionldContextDownloaded, id, buffer); if (contextP == NULL) { From 70d1bad3a5b0e1a35dcee9aad6ad52a7f9cfd2e9 Mon Sep 17 00:00:00 2001 From: Ken Zangelin Date: Wed, 30 Aug 2023 13:15:22 +0200 Subject: [PATCH 2/2] Hopefully fixed issue #1419 --- CHANGES_NEXT_RELEASE | 2 ++ src/lib/orionld/common/orionldRequestSend.cpp | 2 ++ .../orionld/context/orionldContextFromUrl.cpp | 34 ++++++++----------- 3 files changed, 19 insertions(+), 19 deletions(-) diff --git a/CHANGES_NEXT_RELEASE b/CHANGES_NEXT_RELEASE index 2a71a1dae4..39765eb16c 100644 --- a/CHANGES_NEXT_RELEASE +++ b/CHANGES_NEXT_RELEASE @@ -1 +1,3 @@ Fixed issues: + * #1419 - Fixed a bug in the cleanup of the "URL being downloaded list" - not being cleaned up in case of an error + * #280 - Added extensive logging for downloading of contexts diff --git a/src/lib/orionld/common/orionldRequestSend.cpp b/src/lib/orionld/common/orionldRequestSend.cpp index 460595deb6..e58aefe997 100644 --- a/src/lib/orionld/common/orionldRequestSend.cpp +++ b/src/lib/orionld/common/orionldRequestSend.cpp @@ -44,6 +44,8 @@ static size_t writeCallback(void* contents, size_t size, size_t members, void* u OrionldResponseBuffer* rBufP = (OrionldResponseBuffer*) userP; int xtraBytes = 512; + LM_T(LmtCurl, ("CURL: got %d bytes of payload body: %s", bytesToCopy, contents)); + if (bytesToCopy + rBufP->used >= rBufP->size) { if (rBufP->buf == rBufP->internalBuffer) diff --git a/src/lib/orionld/context/orionldContextFromUrl.cpp b/src/lib/orionld/context/orionldContextFromUrl.cpp index 54dd470417..aacf978f01 100644 --- a/src/lib/orionld/context/orionldContextFromUrl.cpp +++ b/src/lib/orionld/context/orionldContextFromUrl.cpp @@ -316,34 +316,30 @@ OrionldContext* orionldContextFromUrl(char* url, char* id) LM_T(LmtContextDownload, ("Downloading the context '%s' and adding it to the context cache", url)); char* buffer = orionldContextDownload(url); // orionldContextDownload fills in ProblemDetails - if (buffer == NULL) - return NULL; - LM_T(LmtCoreContext, ("Downloaded the context '%s'", url)); - contextP = orionldContextFromBuffer(url, OrionldContextDownloaded, id, buffer); - if (contextP == NULL) + if (buffer != NULL) // All OK { - // - // Uncomfortable problem here ... - // The downloaded @context is erroneous and cannot be used. - // The response to the request indicates this fact, but, if the client - // insists on trying to use the context (without fixing it), the broker will download it over and over again. - // Still, I believe this is the best solution. - // - LM_E(("Context Error (%s: %s)", orionldState.pd.title, orionldState.pd.detail)); - contextDownloadListRemove(url); - return NULL; // Parse Error? + LM_T(LmtCoreContext, ("Downloaded the context '%s'", url)); + contextP = orionldContextFromBuffer(url, OrionldContextDownloaded, id, buffer); + if (contextP == NULL) + LM_E(("Context Error (%s: %s)", orionldState.pd.title, orionldState.pd.detail)); } + else + LM_E(("Context Error (%s: %s)", orionldState.pd.title, orionldState.pd.detail)); - contextP->origin = OrionldContextDownloaded; - contextP->createdAt = orionldState.requestTime; - contextP->usedAt = orionldState.requestTime; + if (contextP != NULL) + { + contextP->origin = OrionldContextDownloaded; + contextP->createdAt = orionldState.requestTime; + contextP->usedAt = orionldState.requestTime; + + orionldContextCachePersist(contextP); + } // Remove the 'url' from the contextDownloadList and persist it to DB sem_wait(&contextDownloadListSem); contextDownloadListRemove(url); sem_post(&contextDownloadListSem); - orionldContextCachePersist(contextP); return contextP; }