Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down Expand Up @@ -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 {
Expand All @@ -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;
}
Expand All @@ -859,30 +865,32 @@ 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 '{}'",
Instant.ofEpochMilli(ifModifiedSince), loggedUrl,
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 {
connection.disconnect();
}
} 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;
}
Expand Down Expand Up @@ -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));
}

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand All @@ -50,7 +52,9 @@
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;
import static org.mockito.ArgumentMatchers.anyString;
import static org.mockito.Mockito.doThrow;
Expand Down Expand Up @@ -290,73 +294,94 @@ 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"));
AspectEngineDataFileDefault file = newDataFile(false, true, true);

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"));
AspectEngineDataFileDefault file = newDataFile(false, false, true);

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 + "'");
}

/**
Expand Down Expand Up @@ -436,6 +461,46 @@ private AspectEngineDataFileDefault newKeyedDataFile(boolean inMemory) {
return file;
}

/**
* 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 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<String> 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();
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;
}
}
}
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 + "'";
}

/**
* Fails if any log entry, or any throwable logged with one, holds the
* license key in full.
Expand Down Expand Up @@ -498,9 +563,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();
}

Expand All @@ -515,9 +579,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();
}

Expand All @@ -529,9 +592,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();
}

Expand All @@ -542,10 +604,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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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.
Expand Down
Loading