[jwrosewell]

Closes #125.

Problem

DataUpdateServiceDefault.downloadFile logged every failure to reach the data update service at Warning, in wording of its own, on rc at 30e48867.

• A failed connection, at lines 882 to 887, as "An error occurred when connecting to <url> in order to check for data file updates for <engine>. Error detail: ..." with a note that the update will be tried again.
• A 200 response whose body stopped before all of it had arrived, at lines 840 to 852, as "An error occurred while downloading a data file update for <engine> from <url>. Error detail: ...". That is the download cut short which Report a data update download cut short as the specification's access error #125 describes.
• No response, a 429, a 403 and any other failing status, at lines 822 to 826 and 860 to 878, in the same two forms.

The status each returned is the one the specification gives. The level and the message were not.

What the specification says

The Errors section of the data update specification, at 6570727d on the specifications main branch, says the messages "are the messages and levels of the .NET data update service", and "A row at Error level is an error that carries the message shown. Where the service logs it, the entry is at Error, reads Error during check for data update, and has the error attached." Its table gives these rows, each at Error.

Error	Status	Message
Connecting to the data update URL failed	AUTO_UPDATE_HTTPS_ERR	Error accessing data update service at '<url>' for engine '<Engine type name>'
The data update URL gave no response	AUTO_UPDATE_HTTPS_ERR	No response from data update service at '<url>' for engine '<Engine type name>'
A 429 (Too many requests) response	AUTO_UPDATE_ERR_429_TOO_MANY_ATTEMPTS	Too many requests to '<url>' for engine '<Engine type name>'
A 403 (Forbidden) response	AUTO_UPDATE_ERR_403_FORBIDDEN	Access denied to data update service at '<url>' for engine '<Engine type name>'
Any other response that is not a success and not a 304 (Not modified)	AUTO_UPDATE_HTTPS_ERR	HTTP status code '<status code>' from data update service at '<url>' for engine '<Engine type name>'

A download that starts and then ends before the whole file has arrived is the first row, as #125 sets out. .NET reports it that way because HttpClient.SendAsync reads the whole response before it returns, inside the same try as the connection. Which row covers it is raised in specifications#144, and Node.js made the same change in 51degrees-node#94.

What changed

Every failure exit of downloadFile now logs its row of the table through one new private method, logCheckFailure, which logs "Error during check for data update" at Error with an IOException attached that carries the row's message and, for a failed connection or a download cut short, the cause. The URL and the cause are masked as before, so a License Key never appears in full. The two helpers that built the old warnings are removed. The statuses do not change, and nothing public is added or removed.

The integrity check failure is logged by downloadOkResponse, not downloadFile, and is left as it is (see What remains).

Tests

da4c18fb changes the eleven tests in DataUpdateServiceLoggingTests that cover these exits to expect the table's rows, and adds DownloadCutShort_LogsTheAccessError, whose response body gives ten bytes and then throws "Premature EOF". 3a474d00 is the fix.

• Red, run 43521693094 on a throwaway branch holding da4c18f and a temporary workflow that runs every DataUpdateService*Tests class on ubuntu-latest with the runner's Java and Maven. 11 of the 26 logging tests failed, being exactly the eleven changed or added, and DataUpdateServiceTests (132), DataUpdateServiceLicenseKeyTests (7) and DataUpdateServiceWatchedFileTests (9) passed.
• Green, run 43524315858, the same with 2b589ceb, the head. Every test passed, 26 of 26 logging tests, 132 in DataUpdateServiceTests, 7 in DataUpdateServiceLicenseKeyTests and 9 in DataUpdateServiceWatchedFileTests.
• The first green attempt, run 43521706640 on 3a474d0, failed in two older tests, DataUpdateServiceTests.DataUpdateService_Register_TimerSetAfter429 and DataUpdateService_UpdateFromUrl_HttpException, which expected the warning, and in the new check of a masked cause, because a cause with a License Key masked out of it is a copy whose message starts with the original's class name. 2b589ce changes the two tests to expect the one Error entry and the check to accept the masked copy. It changes no main code.
• 97fdf249 moves the Javadoc of assertKeyOnlyMasked back above that method, from above assertCheckFailed where an earlier edit had left it. It changes a test comment only, and rc (6e03a25) was merged in before it at b7e9df1, with a merge commit and no conflict.

Full build

Run 43580725187 built 97fdf24, this head, merged with rc (ceab088) on nine configurations, Ubuntu x64 with Java 8, 11, 17 and 21, Ubuntu arm64 with Java 17, and Windows with Java 8, 11, 17 and 21, and every job passed. Each of its ten Setting 'PullRequestSha' lines names 97fdf24, and its Configure job printed "Left out 6 macOS entries". Windows_Java_11 passed on its third attempt. In the first, GitHub reported "The hosted runner lost communication with the server" after 63 minutes, with no log. In the second, Maven stopped before building anything with "Failed to read artifact descriptor for org.sonatype.central:central-publishing-maven-plugin:jar:0.7.0" in all four trees, while the same job of another draft's build fetched that plugin at about the same time. Neither reached a test. The build of the earlier head, 2b589ce, was run 43526163363, also green.

macOS was left out of this draft's full build under the 9 November decision. The rc head is built with macOS before it merges into main.

Before you upgrade

A failed check for a data update, whether the connection failed, the download stopped part way, or the service answered 429, 403 or another failing status, is now logged at Error as "Error during check for data update", with the reason in the attached error, where it was a warning. An application that alerts on Error entries sees these.

What remains

• The integrity check failure is still a warning with a retry note where the table gives Error, the other Error rows log their message directly rather than as "Error during check for data update", and a programmatic check and the update on start-up log a failure where the specification says they pass it to the caller. Those are the rest of the table, which #150 tracks.
• A body that is not gzip, or is corrupt, fails while it is read, because Java decompresses the body as it reads it (DataUpdateServiceDefault.java line 1003 at 6e03a25f). So with this change it is logged as the access row, "Error accessing data update service", with AUTO_UPDATE_HTTPS_ERR, the status rc already returns. .NET decompresses after the download (DataUpdateService.cs line 1150 at 8b3220b3) and reports the table's "Any other error" row with AUTO_UPDATE_UNKNOWN_ERROR (lines 886 to 888), a status Java does not have yet. The same issue covers it.