From da4c18fbf7b21362eef450d028672a002d4d72f8 Mon Sep 17 00:00:00 2001 From: James Rosewell Date: Fri, 13 Nov 2026 22:44:05 +0000 Subject: [PATCH 1/4] Test that the data update service logs its HTTP failures as the Errors table rows --- .../DataUpdateServiceLoggingTests.java | 126 +++++++++++++----- 1 file changed, 89 insertions(+), 37 deletions(-) diff --git a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java index dcd972ae1..a6c2d6ca1 100644 --- a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java +++ b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java @@ -24,6 +24,7 @@ import ch.qos.logback.classic.Level; import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.IThrowableProxy; import ch.qos.logback.classic.spi.ThrowableProxyUtil; import ch.qos.logback.core.read.ListAppender; import fiftyone.common.wrappers.io.FileWrapperFactoryDefault; @@ -41,6 +42,7 @@ import java.io.ByteArrayInputStream; import java.io.File; import java.io.IOException; +import java.io.InputStream; import java.net.HttpURLConnection; import java.net.URL; import java.util.ArrayList; @@ -51,6 +53,7 @@ import static org.junit.Assert.assertFalse; import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertTrue; +import static org.junit.Assert.fail; import static org.mockito.ArgumentMatchers.any; import static org.mockito.ArgumentMatchers.anyString; import static org.mockito.Mockito.doThrow; @@ -290,20 +293,18 @@ public void FileSystemWatcher_LogsCreatingFileSystemWatcher() { } @Test - public void ConnectFails_Manual_WarnsWithoutRetryText() throws Exception { + public void ConnectFails_Manual_LogsTheAccessError() throws Exception { when(httpClient.connect(any(URL.class))) .thenThrow(new IOException("refused")); newDataFile(false, false, false); dataUpdate.checkForUpdate(engine); - assertLogged(Level.WARN, "An error occurred when connecting to " + - UPDATE_URL + " in order to check for data file updates for " + - engineType + ". Error detail: refused"); + assertCheckFailed(accessFailure(UPDATE_URL), "refused"); } @Test - public void ConnectFails_Automatic_WarnsThatUpdateWillBeTriedAgain() + public void ConnectFails_Automatic_LogsTheAccessError() throws Exception { when(httpClient.connect(any(URL.class))) .thenThrow(new IOException("refused")); @@ -311,14 +312,11 @@ public void ConnectFails_Automatic_WarnsThatUpdateWillBeTriedAgain() dataUpdate.registerDataFile(file); - assertLogged(Level.WARN, "An error occurred when connecting to " + - UPDATE_URL + " in order to check for data file updates for " + - engineType + ". Update will be attempted again later. " + - "Error detail: refused"); + assertCheckFailed(accessFailure(UPDATE_URL), "refused"); } @Test - public void ConnectFails_AutoUpdateOff_DoesNotPromiseAnotherTry() + public void ConnectFails_AutoUpdateOff_LogsTheAccessError() throws Exception { when(httpClient.connect(any(URL.class))) .thenThrow(new IOException("refused")); @@ -326,37 +324,63 @@ public void ConnectFails_AutoUpdateOff_DoesNotPromiseAnotherTry() dataUpdate.registerDataFile(file); - assertLogged(Level.WARN, "An error occurred when connecting to " + - UPDATE_URL + " in order to check for data file updates for " + - engineType + ". Error detail: refused"); + assertCheckFailed(accessFailure(UPDATE_URL), "refused"); } - private void assertStatusWarned(int status, String detail) + /** + * A 200 response whose body ends before all of it has arrived is the + * first row of the Errors table, as a failure to connect is. + */ + @Test + public void DownloadCutShort_LogsTheAccessError() throws Exception { + when(connection.getResponseCode()) + .thenReturn(HttpURLConnection.HTTP_OK); + when(connection.getInputStream()).thenReturn(new InputStream() { + private int sent = 0; + + @Override + public int read() throws IOException { + if (sent < 10) { + sent++; + return 'x'; + } + throw new IOException("Premature EOF"); + } + }); + newDataFile(false, false, false); + + assertEquals(DataUpdateService.AutoUpdateStatus.AUTO_UPDATE_HTTPS_ERR, + dataUpdate.checkForUpdate(engine)); + + assertCheckFailed(accessFailure(UPDATE_URL), "Premature EOF"); + } + + private void assertStatusFailed(int status, String message) throws Exception { when(connection.getResponseCode()).thenReturn(status); newDataFile(true, false, false); dataUpdate.checkForUpdate(engine); - assertLogged(Level.WARN, "An error occurred while downloading a data " + - "file update for " + engineType + " from " + UPDATE_URL + ". " + - "Error detail: " + detail); - assertTrue(logged(Level.ERROR).isEmpty()); + assertCheckFailed(message, null); } @Test - public void TooManyRequests_WarnsAboutTheDownload() throws Exception { - assertStatusWarned(429, "HTTP status code 429 (too many requests)"); + public void TooManyRequests_LogsTheTableRow() throws Exception { + assertStatusFailed(429, "Too many requests to '" + UPDATE_URL + + "' for engine '" + engineType + "'"); } @Test - public void Forbidden_WarnsAboutTheDownload() throws Exception { - assertStatusWarned(403, "HTTP status code 403 (access denied)"); + public void Forbidden_LogsTheTableRow() throws Exception { + assertStatusFailed(403, "Access denied to data update service at '" + + UPDATE_URL + "' for engine '" + engineType + "'"); } @Test - public void OtherStatus_WarnsAboutTheDownload() throws Exception { - assertStatusWarned(500, "HTTP status code 500"); + public void OtherStatus_LogsTheTableRow() throws Exception { + assertStatusFailed(500, "HTTP status code '500' from data update " + + "service at '" + UPDATE_URL + "' for engine '" + engineType + "'"); } /** @@ -440,6 +464,39 @@ private AspectEngineDataFileDefault newKeyedDataFile(boolean inMemory) { * Fails if any log entry, or any throwable logged with one, holds the * license key in full. */ + /** + * An Error row of the specification's Errors table, logged at Error as + * "Error during check for data update" with an error attached that + * carries the row's message, and the cause's message when there is one. + */ + private void assertCheckFailed(String message, String causeMessage) { + List found = new ArrayList<>(); + for (ILoggingEvent event : appender.list) { + if (event.getLevel() == Level.ERROR && + "Error during check for data update".equals( + event.getFormattedMessage()) && + event.getThrowableProxy() != null) { + IThrowableProxy error = event.getThrowableProxy(); + found.add(error.getMessage()); + if (message.equals(error.getMessage())) { + IThrowableProxy cause = error.getCause(); + assertEquals(causeMessage, + cause == null ? null : cause.getMessage()); + assertTrue("A warning was logged as well: " + + logged(Level.WARN), logged(Level.WARN).isEmpty()); + return; + } + } + } + fail("Expected '" + message + "' attached to an Error entry, but " + + "the errors attached were " + found); + } + + private String accessFailure(String url) { + return "Error accessing data update service at '" + url + + "' for engine '" + engineType + "'"; + } + private void assertKeyOnlyMasked() { assertFalse(appender.list.isEmpty()); for (ILoggingEvent event : appender.list) { @@ -498,9 +555,8 @@ public void LicenseKey_ConnectFails_MasksTheUrlAndTheException() dataUpdate.checkForUpdate(engine); - assertLogged(Level.WARN, "An error occurred when connecting to " + - MASKED_URL + " in order to check for data file updates for " + - engineType + ". Error detail: Connection refused: " + MASKED_URL); + assertCheckFailed(accessFailure(MASKED_URL), + "Connection refused: " + MASKED_URL); assertKeyOnlyMasked(); } @@ -515,9 +571,8 @@ public void LicenseKey_DownloadFails_MasksTheUrlAndTheException() dataUpdate.checkForUpdate(engine); - assertLogged(Level.WARN, "An error occurred while downloading a data " + - "file update for " + engineType + " from " + MASKED_URL + ". " + - "Error detail: Premature EOF from " + MASKED_URL); + assertCheckFailed(accessFailure(MASKED_URL), + "Premature EOF from " + MASKED_URL); assertKeyOnlyMasked(); } @@ -529,9 +584,8 @@ public void LicenseKey_Forbidden_LogsTheMaskedUrl() throws Exception { dataUpdate.checkForUpdate(engine); - assertLogged(Level.WARN, "An error occurred while downloading a data " + - "file update for " + engineType + " from " + MASKED_URL + ". " + - "Error detail: HTTP status code 403 (access denied)"); + assertCheckFailed("Access denied to data update service at '" + + MASKED_URL + "' for engine '" + engineType + "'", null); assertKeyOnlyMasked(); } @@ -542,10 +596,8 @@ public void LicenseKey_NoResponse_LogsTheMaskedUrl() throws Exception { dataUpdate.checkForUpdate(engine); - assertLogged(Level.WARN, "An error occurred when connecting to " + - MASKED_URL + " in order to check for data file updates for " + - engineType + ". Error detail: No response from the data update " + - "service"); + assertCheckFailed("No response from data update service at '" + + MASKED_URL + "' for engine '" + engineType + "'", null); assertKeyOnlyMasked(); } } From 3a474d007170ec35959b381f622c03ac6d960863 Mon Sep 17 00:00:00 2001 From: James Rosewell Date: Fri, 13 Nov 2026 22:44:06 +0000 Subject: [PATCH 2/4] Log the data update service's HTTP failures as the Errors table rows A download cut short and a failed connection are the table's first row, the access error, and each HTTP row is logged at Error as 'Error during check for data update' with an error carrying the row's message and the cause. --- .../services/DataUpdateServiceDefault.java | 69 ++++++++++--------- 1 file changed, 35 insertions(+), 34 deletions(-) diff --git a/pipeline/pipeline.engines/src/main/java/fiftyone/pipeline/engines/services/DataUpdateServiceDefault.java b/pipeline/pipeline.engines/src/main/java/fiftyone/pipeline/engines/services/DataUpdateServiceDefault.java index 398bfd9b9..ba4631d33 100644 --- a/pipeline/pipeline.engines/src/main/java/fiftyone/pipeline/engines/services/DataUpdateServiceDefault.java +++ b/pipeline/pipeline.engines/src/main/java/fiftyone/pipeline/engines/services/DataUpdateServiceDefault.java @@ -67,6 +67,13 @@ */ public class DataUpdateServiceDefault implements DataUpdateService { + /** + * The log message of a failed check for a data update, with the error + * that says why attached. + */ + private static final String CHECK_FAILED = + "Error during check for data update"; + /** * The query parameter of a data update URL that holds the license keys, * as the 51Degrees URL formatter writes it. @@ -820,8 +827,8 @@ private AutoUpdateStatus downloadFile( loggedUrl, engineType); HttpURLConnection connection = httpClient.connect(new URI(url.trim()).toURL()); if (connection == null) { - logger.warn(connectFailure(loggedUrl, engineType, automatic, - "No response from the data update service")); + logCheckFailure("No response from data update service at '" + + loggedUrl + "' for engine '" + engineType + "'", null); return AutoUpdateStatus.AUTO_UPDATE_HTTPS_ERR; } try { @@ -842,11 +849,10 @@ private AutoUpdateStatus downloadFile( downloaded = downloadOkResponse( connection, dataFile, tempFile, automatic); } catch (Exception e) { - // An HTTP library's exception often names the - // URL it requested. - logger.warn(downloadFailure(loggedUrl, engineType, - automatic, LicenseKeyMask.maskIn( - e.getMessage(), licenseKeys)), + // A download cut short is the access error, as + // a failure to connect is. An HTTP library's + // exception often names the URL it requested. + logCheckFailure(accessFailure(loggedUrl, engineType), LicenseKeyMask.maskIn(e, licenseKeys)); return AutoUpdateStatus.AUTO_UPDATE_HTTPS_ERR; } @@ -859,8 +865,8 @@ private AutoUpdateStatus downloadFile( // Note: needed because TooManyRequests is not available // in some versions of the HttpStatusCode enum. case (429): - logger.warn(downloadFailure(loggedUrl, engineType, automatic, - "HTTP status code 429 (too many requests)")); + logCheckFailure("Too many requests to '" + loggedUrl + + "' for engine '" + engineType + "'", null); return AutoUpdateStatus.AUTO_UPDATE_ERR_429_TOO_MANY_ATTEMPTS; case HttpURLConnection.HTTP_NOT_MODIFIED: logger.info("No data newer than {} found at '{}' for Engine '{}'", @@ -868,12 +874,15 @@ private AutoUpdateStatus downloadFile( engineType); return AutoUpdateStatus.AUTO_UPDATE_NOT_NEEDED; case HttpURLConnection.HTTP_FORBIDDEN: - logger.warn(downloadFailure(loggedUrl, engineType, automatic, - "HTTP status code 403 (access denied)")); + logCheckFailure("Access denied to data update service " + + "at '" + loggedUrl + "' for engine '" + + engineType + "'", null); return AutoUpdateStatus.AUTO_UPDATE_ERR_403_FORBIDDEN; default: - logger.warn(downloadFailure(loggedUrl, engineType, automatic, - "HTTP status code " + connection.getResponseCode())); + logCheckFailure("HTTP status code '" + + connection.getResponseCode() + "' from data " + + "update service at '" + loggedUrl + + "' for engine '" + engineType + "'", null); return AutoUpdateStatus.AUTO_UPDATE_HTTPS_ERR; } } finally { @@ -881,8 +890,7 @@ private AutoUpdateStatus downloadFile( } } catch (Exception e) { // An HTTP library's exception often names the URL it requested. - logger.warn(connectFailure(loggedUrl, engineType, automatic, - LicenseKeyMask.maskIn(e.getMessage(), licenseKeys)), + logCheckFailure(accessFailure(loggedUrl, engineType), LicenseKeyMask.maskIn(e, licenseKeys)); return AutoUpdateStatus.AUTO_UPDATE_HTTPS_ERR; } @@ -911,31 +919,24 @@ private static String retryNote(boolean automatic) { } /** - * The warning for a failed connection. The URL and the detail are + * The message of the Errors table's row for a failure to connect to the + * data update service, or to download all of its response. The URL is * given with each license key already masked. */ - private static String connectFailure( - String loggedUrl, - String engineType, - boolean automatic, - String detail) { - return "An error occurred when connecting to " + loggedUrl + - " in order to check for data file updates for " + engineType + - "." + retryNote(automatic) + " Error detail: " + detail; + private static String accessFailure(String loggedUrl, String engineType) { + return "Error accessing data update service at '" + loggedUrl + + "' for engine '" + engineType + "'"; } /** - * The warning for a failed download. The URL and the detail are given - * with each license key already masked. + * Log an Error row of the Errors table as the specification asks, at + * Error, reading "Error during check for data update", with an error + * attached that carries the row's message and the cause when there is + * one. The message and the cause are given with each license key + * already masked. */ - private static String downloadFailure( - String loggedUrl, - String engineType, - boolean automatic, - String detail) { - return "An error occurred while downloading a data file update for " + - engineType + " from " + loggedUrl + "." + retryNote(automatic) + - " Error detail: " + detail; + private void logCheckFailure(String message, Throwable cause) { + logger.error(CHECK_FAILED, new IOException(message, cause)); } /** From 2b589ceb934bdfad87416f173af86d9cb4e9285a Mon Sep 17 00:00:00 2001 From: James Rosewell Date: Fri, 13 Nov 2026 23:04:12 +0000 Subject: [PATCH 3/4] Expect the access error and the 429 row at Error in the older data update tests --- .../services/DataUpdateServiceLoggingTests.java | 14 +++++++++++--- .../services/DataUpdateServiceTests.java | 17 +++++++++-------- 2 files changed, 20 insertions(+), 11 deletions(-) diff --git a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java index a6c2d6ca1..408f5e145 100644 --- a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java +++ b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java @@ -52,6 +52,7 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertFalse; import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertNull; import static org.junit.Assert.assertTrue; import static org.junit.Assert.fail; import static org.mockito.ArgumentMatchers.any; @@ -467,7 +468,9 @@ private AspectEngineDataFileDefault newKeyedDataFile(boolean inMemory) { /** * An Error row of the specification's Errors table, logged at Error as * "Error during check for data update" with an error attached that - * carries the row's message, and the cause's message when there is one. + * carries the row's message, and a cause whose message holds the given + * text when there is one. A cause with a License Key masked out of it + * is a copy whose message starts with the original's class name. */ private void assertCheckFailed(String message, String causeMessage) { List found = new ArrayList<>(); @@ -480,8 +483,13 @@ private void assertCheckFailed(String message, String causeMessage) { found.add(error.getMessage()); if (message.equals(error.getMessage())) { IThrowableProxy cause = error.getCause(); - assertEquals(causeMessage, - cause == null ? null : cause.getMessage()); + if (causeMessage == null) { + assertNull(cause); + } else { + assertNotNull(cause); + assertTrue("The cause was " + cause.getMessage(), + cause.getMessage().endsWith(causeMessage)); + } assertTrue("A warning was logged as well: " + logged(Level.WARN), logged(Level.WARN).isEmpty()); return; diff --git a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceTests.java b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceTests.java index b10b06a8a..0d1796004 100644 --- a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceTests.java +++ b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceTests.java @@ -892,12 +892,13 @@ public void call(Object sender, DataUpdateService.DataUpdateCompleteArgs args) { // reconfigured to try again later. verify(futureFactory, atLeast(1)) .schedule(any(Runnable.class), anyLong()); - // We expect one warning to be logged so make sure it's - // ignored in cleanup and verify its presence. - ignoreWranings = 1; - assertEquals(1, logger.warningsLogged.size()); - assertTrue(logger.warningsLogged.get(0).contains(errorText)); - assertEquals(0, logger.errorsLogged.size()); + // The failed connection is the Errors table's access error, + // logged once at Error, so it is ignored in cleanup. + ignoreErrors = 1; + assertEquals(0, logger.warningsLogged.size()); + assertEquals(1, logger.errorsLogged.size()); + assertEquals("Error during check for data update", + logger.errorsLogged.get(0)); assertEquals(AUTO_UPDATE_HTTPS_ERR, completeEventArgs[0].getStatus()); } finally { @@ -1724,8 +1725,8 @@ public void call(Object sender, DataUpdateService.DataUpdateCompleteArgs args) { assertTrue("The 'checkForUpdateComplete' " + "event was never fired", completed); - // Ignore the warning that is logged due to the 429 - ignoreWranings = 1; + // Ignore the error that is logged due to the 429 + ignoreErrors = 1; // Check that the timer has been set to go off again. assertNotNull(file.getFuture()); // Check that the timer has been set to expire in 10 seconds. From 97fdf249153674ee778ed3681a1e1e86a4874d47 Mon Sep 17 00:00:00 2001 From: James Rosewell Date: Sat, 14 Nov 2026 04:50:10 +0000 Subject: [PATCH 4/4] Put the Javadoc of assertKeyOnlyMasked back above it --- .../engines/services/DataUpdateServiceLoggingTests.java | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java index 408f5e145..c93f6369c 100644 --- a/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java +++ b/pipeline/pipeline.engines/src/test/java/fiftyone/pipeline/engines/services/DataUpdateServiceLoggingTests.java @@ -461,10 +461,6 @@ private AspectEngineDataFileDefault newKeyedDataFile(boolean inMemory) { return file; } - /** - * Fails if any log entry, or any throwable logged with one, holds the - * license key in full. - */ /** * An Error row of the specification's Errors table, logged at Error as * "Error during check for data update" with an error attached that @@ -505,6 +501,10 @@ private String accessFailure(String url) { "' for engine '" + engineType + "'"; } + /** + * Fails if any log entry, or any throwable logged with one, holds the + * license key in full. + */ private void assertKeyOnlyMasked() { assertFalse(appender.list.isEmpty()); for (ILoggingEvent event : appender.list) {