Skip to content

Commit

Permalink
Preserve original error messages in URLDownloader and update tests
Browse files Browse the repository at this point in the history
  • Loading branch information
@levkropp
levkropp committed Nov 22, 2024
1 parent ad458a5 commit e11c6be
Show file tree
Hide file tree
Showing 3 changed files with 76 additions and 28 deletions.
1 change: 1 addition & 0 deletions src/network/CMakeLists.txt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,5 +27,6 @@ add_library(ip_address STATIC
target_link_libraries(network
fmt
logger
utils
Qt6::Core
Qt6::Network)
42 changes: 26 additions & 16 deletions src/network/url_downloader.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@
#include <multipass/format.h>
#include <multipass/logging/log.h>
#include <multipass/platform.h>
#include <multipass/utils.h>
#include <multipass/version.h>

#include <QDir>
Expand Down Expand Up @@ -108,35 +109,29 @@ download(QNetworkAccessManager* manager, const Time& timeout, QUrl const& url, P
// Log the original error message at debug level
mpl::log(mpl::Level::debug,
category,
fmt::format("Qt error {}: {}", static_cast<int>(error_code), error_string));
fmt::format("Qt error {}: {}", mp::utils::qenum_to_string(error_code), error_string));

const auto msg = (error_code == QNetworkReply::TimeoutError) ? "Network timeout" : error_string;

if (error_code == QNetworkReply::TimeoutError)
if (download_timeout.isActive())
{
// Log a debug message to verify our assumption about download_timeout
if (download_timeout.isActive())
{
mpl::log(mpl::Level::debug, category, "Timeout error detected but download_timeout is still active");
}
mpl::log(mpl::Level::warning, category, "download_timeout is still active");
}

if (reply->error() == QNetworkReply::ProxyAuthenticationRequiredError || abort_download)
{
on_error();
throw mp::AbortedDownloadException{msg};
throw mp::AbortedDownloadException{error_string};
}
if (cache_load_control == QNetworkRequest::CacheLoadControl::AlwaysCache)
{
on_error();
// Log at error level since we are giving up
mpl::log(mpl::Level::error, category, fmt::format("Failed to get {}: {}", url.toString(), msg));
throw mp::DownloadException{url.toString().toStdString(), msg};
mpl::log(mpl::Level::error, category, fmt::format("Failed to get {}: {}", url.toString(), error_string));
throw mp::DownloadException{url.toString().toStdString(), error_string};
}
// Log at warning level when we are going to retry
mpl::log(mpl::Level::warning,
category,
fmt::format("Failed to get {}: {} - trying cache.", url.toString(), msg));
fmt::format("Failed to get {}: {} - trying cache.", url.toString(), error_string));
return ::download(manager, timeout, url, on_progress, on_download, on_error, abort_download,
QNetworkRequest::CacheLoadControl::AlwaysCache);
}
Expand All @@ -163,15 +158,30 @@ auto get_header(QNetworkAccessManager* manager, const QUrl& url, const QNetworkR

if (reply->error() != QNetworkReply::NoError)
{
const auto msg = download_timeout.isActive() ? reply->errorString().toStdString() : "Network timeout";
const auto error_code = reply->error();
const auto error_string = reply->errorString().toStdString();

// Log the original error message at debug level
mpl::log(mpl::Level::debug,
category,
fmt::format("Qt error {}: {}", mp::utils::qenum_to_string(error_code), error_string));

mpl::log(mpl::Level::warning, category, fmt::format("Cannot retrieve headers for {}: {}", url.toString(), msg));
if (download_timeout.isActive())
{
mpl::log(mpl::Level::warning, category, "download_timeout is still active");
}

throw mp::DownloadException{url.toString().toStdString(), reply->errorString().toStdString()};
// Log at error level when we give up on getting headers
mpl::log(mpl::Level::error,
category,
fmt::format("Cannot retrieve headers for {}: {}", url.toString(), error_string));

throw mp::DownloadException{url.toString().toStdString(), error_string};
}

return reply->header(header);
}

} // namespace

mp::NetworkManagerFactory::NetworkManagerFactory(const Singleton<NetworkManagerFactory>::PrivatePass& pass) noexcept
Expand Down
61 changes: 49 additions & 12 deletions tests/test_url_downloader.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -113,11 +113,17 @@ TEST_F(URLDownloader, simpleDownloadNetworkTimeoutTriesCache)
return mock_reply_cache;
});

logger_scope.mock_logger->screen_logs(mpl::Level::trace);
logger_scope.mock_logger->screen_logs(mpl::Level::error);

// Add expectations for the new debug log and the warning log
EXPECT_CALL(*logger_scope.mock_logger,
log(mpl::Level::debug, _, Property(&multipass::logging::CString::c_str, StartsWith("Qt error"))));

logger_scope.mock_logger->expect_log(
mpl::Level::warning,
fmt::format("Failed to get {}: Operation canceled - trying cache.", fake_url.toString()));
logger_scope.mock_logger->expect_log(mpl::Level::trace,
fmt::format("Found {} in cache: true", fake_url.toString()));
logger_scope.mock_logger->expect_log(
mpl::Level::warning, fmt::format("Error getting {}: Network timeout - trying cache.", fake_url.toString()));

mp::URLDownloader downloader(cache_dir.path(), 10ms);

Expand Down Expand Up @@ -248,11 +254,15 @@ TEST_F(URLDownloader, fileDownloadErrorTriesCache)

auto progress_monitor = [](auto...) { return true; };

logger_scope.mock_logger->screen_logs(mpl::Level::trace);
logger_scope.mock_logger->screen_logs(mpl::Level::error);
logger_scope.mock_logger->expect_log(mpl::Level::trace,
fmt::format("Found {} in cache: true", fake_url.toString()));
logger_scope.mock_logger->expect_log(
mpl::Level::warning, fmt::format("Error getting {}: Network timeout - trying cache.", fake_url.toString()));
mpl::Level::warning,
fmt::format("Failed to get {}: Operation canceled - trying cache.", fake_url.toString()));

EXPECT_CALL(*logger_scope.mock_logger,
log(mpl::Level::debug, _, Property(&multipass::logging::CString::c_str, StartsWith("Qt error"))));

mp::URLDownloader downloader(cache_dir.path(), 10ms);

Expand Down Expand Up @@ -417,9 +427,27 @@ TEST_F(URLDownloader, fileDownloadTimeoutDoesNotWriteFile)

auto progress_monitor = [](auto...) { return true; };

logger_scope.mock_logger->screen_logs(mpl::Level::warning);
logger_scope.mock_logger->expect_log(
mpl::Level::warning, fmt::format("Error getting {}: Network timeout - trying cache.", fake_url.toString()));
logger_scope.mock_logger->screen_logs(mpl::Level::error);

// Expect warning log for the first failed attempt
EXPECT_CALL(*logger_scope.mock_logger,
log(mpl::Level::warning,
_,
Property(&multipass::logging::CString::c_str,
HasSubstr(fmt::format("Failed to get {}: Operation canceled - trying cache.",
fake_url.toString())))));

// Expect error log for the second failed attempt
EXPECT_CALL(*logger_scope.mock_logger,
log(mpl::Level::error,
_,
Property(&multipass::logging::CString::c_str,
HasSubstr(fmt::format("Failed to get {}: Operation canceled", fake_url.toString())))));

// Expect two debug logs for each failure
EXPECT_CALL(*logger_scope.mock_logger,
log(mpl::Level::debug, _, Property(&multipass::logging::CString::c_str, StartsWith("Qt error"))))
.Times(2);

mp::URLDownloader downloader(cache_dir.path(), 10ms);

Expand Down Expand Up @@ -499,10 +527,14 @@ TEST_F(URLDownloader, lastModifiedHeaderTimeoutThrows)

EXPECT_CALL(*mock_network_access_manager, createRequest(_, _, _)).WillOnce(Return(mock_reply));

logger_scope.mock_logger->screen_logs(mpl::Level::warning);
logger_scope.mock_logger->screen_logs(mpl::Level::error);
logger_scope.mock_logger->expect_log(
mpl::Level::warning, fmt::format("Cannot retrieve headers for {}: Network timeout", fake_url.toString()));
mpl::Level::error,
fmt::format("Cannot retrieve headers for {}: Operation canceled", fake_url.toString()));

// Expectation for debug log
EXPECT_CALL(*logger_scope.mock_logger,
log(mpl::Level::debug, _, Property(&multipass::logging::CString::c_str, StartsWith("Qt error"))));
mp::URLDownloader downloader(cache_dir.path(), 10ms);

EXPECT_THROW(downloader.last_modified(fake_url), mp::DownloadException);
Expand All @@ -521,9 +553,14 @@ TEST_F(URLDownloader, lastModifiedHeaderErrorThrows)
return mock_reply;
});

logger_scope.mock_logger->screen_logs(mpl::Level::warning);
logger_scope.mock_logger->screen_logs(mpl::Level::error);
logger_scope.mock_logger->expect_log(
mpl::Level::warning, fmt::format("Cannot retrieve headers for {}: {}", fake_url.toString(), error_msg));
mpl::Level::error,
fmt::format("Cannot retrieve headers for {}: {}", fake_url.toString(), error_msg));

// Expectation for debug log
EXPECT_CALL(*logger_scope.mock_logger,
log(mpl::Level::debug, _, Property(&multipass::logging::CString::c_str, StartsWith("Qt error"))));

mp::URLDownloader downloader(cache_dir.path(), 1s);

Expand Down

0 comments on commit e11c6be

Please sign in to comment.