Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

log all QNetworkReply error messages at debug level #3732

Merged
merged 2 commits into from
Nov 23, 2024
Merged

log all QNetworkReply error messages at debug level #3732

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
a824f37
log all QNetworkReply error messages at debug level
levkropp Oct 15, 2024
cc8d248
Preserve original error messages in URLDownloader and update tests
levkropp Nov 21, 2024
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
1 change: 1 addition & 0 deletions src/network/CMakeLists.txt
View file
Open in desktop
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)
46 changes: 37 additions & 9 deletions src/network/url_downloader.cpp
View file
Open in desktop
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 @@ -114,20 +115,36 @@ download(QNetworkAccessManager* manager, const Time& timeout, QUrl const& url, P

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::debug,
category,
fmt::format("download_timeout is {}active", download_timeout.isActive() ? "" : "in"));

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();
throw mp::DownloadException{adjusted_url.toString().toStdString(), msg};
// Log at error level since we are giving up
mpl::log(mpl::Level::error,
category,
fmt::format("Failed to get {}: {}", adjusted_url.toString(), error_string));
throw mp::DownloadException{adjusted_url.toString().toStdString(), error_string};
}
mpl::log(mpl::Level::warning, category,
fmt::format("Error getting {}: {} - trying cache.", url.toString(), msg));
// Log at warning level when we are going to retry
mpl::log(mpl::Level::warning,
category,
fmt::format("Failed to get {}: {} - trying cache.", adjusted_url.toString(), error_string));
return ::download(manager,
timeout,
adjusted_url,
Expand Down Expand Up @@ -161,13 +178,24 @@ 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();

mpl::log(mpl::Level::warning,
// 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::debug,
category,
fmt::format("download_timeout is {}active", download_timeout.isActive() ? "" : "in"));

// Log at error level when we give up on getting headers
mpl::log(mpl::Level::error,
category,
fmt::format("Cannot retrieve headers for {}: {}", adjusted_url.toString(), msg));
fmt::format("Cannot retrieve headers for {}: {}", adjusted_url.toString(), error_string));

throw mp::DownloadException{adjusted_url.toString().toStdString(), reply->errorString().toStdString()};
throw mp::DownloadException{adjusted_url.toString().toStdString(), error_string};
}

return reply->header(header);
Expand Down
61 changes: 49 additions & 12 deletions tests/test_url_downloader.cpp
View file
Open in desktop
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
Loading