LibHTTP: Place HTTP disk cache log points behind a debug flag

These log points are quite verbose. Before we enable the disk cache by
default, let's place them behind a debug flag.
This commit is contained in:
Timothy Flynn
2025-12-01 15:15:45 -05:00
committed by Andreas Kling
parent adcf5462af
commit aae8574d25
Notes: github-actions[bot] 2025-12-02 11:21:02 +00:00
5 changed files with 26 additions and 18 deletions

View File

@@ -106,6 +106,10 @@
# cmakedefine01 HTML_SCRIPT_DEBUG # cmakedefine01 HTML_SCRIPT_DEBUG
#endif #endif
#ifndef HTTP_DISK_CACHE_DEBUG
# cmakedefine01 HTTP_DISK_CACHE_DEBUG
#endif
#ifndef HTTP_MEMORY_CACHE_DEBUG #ifndef HTTP_MEMORY_CACHE_DEBUG
# cmakedefine01 HTTP_MEMORY_CACHE_DEBUG # cmakedefine01 HTTP_MEMORY_CACHE_DEBUG
#endif #endif

View File

@@ -4,6 +4,7 @@
* SPDX-License-Identifier: BSD-2-Clause * SPDX-License-Identifier: BSD-2-Clause
*/ */
#include <AK/Debug.h>
#include <AK/HashFunctions.h> #include <AK/HashFunctions.h>
#include <AK/ScopeGuard.h> #include <AK/ScopeGuard.h>
#include <LibCore/System.h> #include <LibCore/System.h>
@@ -151,7 +152,7 @@ ErrorOr<void> CacheEntryWriter::write_status_and_reason(u32 status_code, Optiona
}(); }();
if (result.is_error()) { if (result.is_error()) {
dbgln("\033[31;1mUnable to write status/reason to cache entry for\033[0m {}: {}", m_url, result.error()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mUnable to write status/reason to cache entry for\033[0m {}: {}", m_url, result.error());
remove(); remove();
close_and_destroy_cache_entry(); close_and_destroy_cache_entry();
@@ -170,7 +171,7 @@ ErrorOr<void> CacheEntryWriter::write_data(ReadonlyBytes data)
} }
if (auto result = m_file->write_until_depleted(data); result.is_error()) { if (auto result = m_file->write_until_depleted(data); result.is_error()) {
dbgln("\033[31;1mUnable to write data to cache entry for\033[0m {}: {}", m_url, result.error()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mUnable to write data to cache entry for\033[0m {}: {}", m_url, result.error());
remove(); remove();
close_and_destroy_cache_entry(); close_and_destroy_cache_entry();
@@ -192,7 +193,7 @@ ErrorOr<void> CacheEntryWriter::flush(NonnullRefPtr<HeaderList> response_headers
m_cache_footer.header_hash = m_cache_header.hash(); m_cache_footer.header_hash = m_cache_header.hash();
if (auto result = m_file->write_value(m_cache_footer); result.is_error()) { if (auto result = m_file->write_value(m_cache_footer); result.is_error()) {
dbgln("\033[31;1mUnable to flush cache entry for\033[0m {}: {}", m_url, result.error()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mUnable to flush cache entry for\033[0m {}: {}", m_url, result.error());
remove(); remove();
return result.release_error(); return result.release_error();
@@ -200,7 +201,7 @@ ErrorOr<void> CacheEntryWriter::flush(NonnullRefPtr<HeaderList> response_headers
m_index.create_entry(m_cache_key, m_url, move(response_headers), m_cache_footer.data_size, m_request_time, m_response_time); m_index.create_entry(m_cache_key, m_url, move(response_headers), m_cache_footer.data_size, m_request_time, m_response_time);
dbgln("\033[34;1mFinished caching\033[0m {} ({} bytes)", m_url, m_cache_footer.data_size); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[34;1mFinished caching\033[0m {} ({} bytes)", m_url, m_cache_footer.data_size);
return {}; return {};
} }
@@ -265,7 +266,7 @@ CacheEntryReader::CacheEntryReader(DiskCache& disk_cache, CacheIndex& index, u64
void CacheEntryReader::revalidation_succeeded(HeaderList const& response_headers) void CacheEntryReader::revalidation_succeeded(HeaderList const& response_headers)
{ {
dbgln("\033[34;1mCache revalidation succeeded for\033[0m {}", m_url); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[34;1mCache revalidation succeeded for\033[0m {}", m_url);
update_header_fields(m_response_headers, response_headers); update_header_fields(m_response_headers, response_headers);
m_index.update_response_headers(m_cache_key, m_response_headers); m_index.update_response_headers(m_cache_key, m_response_headers);
@@ -273,7 +274,7 @@ void CacheEntryReader::revalidation_succeeded(HeaderList const& response_headers
void CacheEntryReader::revalidation_failed() void CacheEntryReader::revalidation_failed()
{ {
dbgln("\033[33;1mCache revalidation failed for\033[0m {}", m_url); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[33;1mCache revalidation failed for\033[0m {}", m_url);
remove(); remove();
close_and_destroy_cache_entry(); close_and_destroy_cache_entry();
@@ -334,7 +335,7 @@ void CacheEntryReader::pipe_without_blocking()
void CacheEntryReader::pipe_complete() void CacheEntryReader::pipe_complete()
{ {
if (auto result = read_and_validate_footer(); result.is_error()) { if (auto result = read_and_validate_footer(); result.is_error()) {
dbgln("\033[31;1mError validating cache entry for\033[0m {}: {}", m_url, result.error()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mError validating cache entry for\033[0m {}: {}", m_url, result.error());
remove(); remove();
if (m_on_pipe_error) if (m_on_pipe_error)
@@ -351,7 +352,7 @@ void CacheEntryReader::pipe_complete()
void CacheEntryReader::pipe_error(Error error) void CacheEntryReader::pipe_error(Error error)
{ {
dbgln("\033[31;1mError transferring cache to pipe for\033[0m {}: {}", m_url, error); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mError transferring cache to pipe for\033[0m {}: {}", m_url, error);
// FIXME: We may not want to actually remove the cache file for all errors. For now, let's assume the file is not // FIXME: We may not want to actually remove the cache file for all errors. For now, let's assume the file is not
// useable at this point and remove it. // useable at this point and remove it.

View File

@@ -4,6 +4,7 @@
* SPDX-License-Identifier: BSD-2-Clause * SPDX-License-Identifier: BSD-2-Clause
*/ */
#include <AK/Debug.h>
#include <AK/StringBuilder.h> #include <AK/StringBuilder.h>
#include <LibHTTP/Cache/CacheIndex.h> #include <LibHTTP/Cache/CacheIndex.h>
#include <LibHTTP/Cache/Utilities.h> #include <LibHTTP/Cache/Utilities.h>
@@ -68,7 +69,7 @@ ErrorOr<CacheIndex> CacheIndex::create(Database::Database& database)
if (cache_version != CACHE_VERSION) { if (cache_version != CACHE_VERSION) {
if (cache_version != 0) if (cache_version != 0)
dbgln("\033[31;1mDisk cache version mismatch:\033[0m stored version = {}, new version = {}", cache_version, CACHE_VERSION); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mDisk cache version mismatch:\033[0m stored version = {}, new version = {}", cache_version, CACHE_VERSION);
// FIXME: We should more elegantly handle minor changes, i.e. use ALTER TABLE to add fields to CacheIndex. // FIXME: We should more elegantly handle minor changes, i.e. use ALTER TABLE to add fields to CacheIndex.
auto delete_cache_index_table = TRY(database.prepare_statement("DROP TABLE IF EXISTS CacheIndex;"sv)); auto delete_cache_index_table = TRY(database.prepare_statement("DROP TABLE IF EXISTS CacheIndex;"sv));

View File

@@ -4,6 +4,7 @@
* SPDX-License-Identifier: BSD-2-Clause * SPDX-License-Identifier: BSD-2-Clause
*/ */
#include <AK/Debug.h>
#include <LibCore/EventLoop.h> #include <LibCore/EventLoop.h>
#include <LibCore/StandardPaths.h> #include <LibCore/StandardPaths.h>
#include <LibFileSystem/FileSystem.h> #include <LibFileSystem/FileSystem.h>
@@ -64,11 +65,11 @@ Variant<Optional<CacheEntryWriter&>, DiskCache::CacheHasOpenEntry> DiskCache::cr
auto cache_entry = CacheEntryWriter::create(*this, m_index, cache_key, move(serialized_url), request_start_time, current_time_offset_for_testing); auto cache_entry = CacheEntryWriter::create(*this, m_index, cache_key, move(serialized_url), request_start_time, current_time_offset_for_testing);
if (cache_entry.is_error()) { if (cache_entry.is_error()) {
dbgln("\033[31;1mUnable to create cache entry for\033[0m {}: {}", url, cache_entry.error()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mUnable to create cache entry for\033[0m {}: {}", url, cache_entry.error());
return Optional<CacheEntryWriter&> {}; return Optional<CacheEntryWriter&> {};
} }
dbgln("\033[32;1mCreated disk cache entry for\033[0m {}", url); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[32;1mCreated disk cache entry for\033[0m {}", url);
auto* cache_entry_pointer = cache_entry.value().ptr(); auto* cache_entry_pointer = cache_entry.value().ptr();
m_open_cache_entries.ensure(cache_key).append(cache_entry.release_value()); m_open_cache_entries.ensure(cache_key).append(cache_entry.release_value());
@@ -89,13 +90,13 @@ Variant<Optional<CacheEntryReader&>, DiskCache::CacheHasOpenEntry> DiskCache::op
auto index_entry = m_index.find_entry(cache_key); auto index_entry = m_index.find_entry(cache_key);
if (!index_entry.has_value()) { if (!index_entry.has_value()) {
dbgln("\033[35;1mNo disk cache entry for\033[0m {}", url); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[35;1mNo disk cache entry for\033[0m {}", url);
return Optional<CacheEntryReader&> {}; return Optional<CacheEntryReader&> {};
} }
auto cache_entry = CacheEntryReader::create(*this, m_index, cache_key, index_entry->response_headers, index_entry->data_size); auto cache_entry = CacheEntryReader::create(*this, m_index, cache_key, index_entry->response_headers, index_entry->data_size);
if (cache_entry.is_error()) { if (cache_entry.is_error()) {
dbgln("\033[31;1mUnable to open cache entry for\033[0m {}: {}", url, cache_entry.error()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[31;1mUnable to open cache entry for\033[0m {}: {}", url, cache_entry.error());
m_index.remove_entry(cache_key); m_index.remove_entry(cache_key);
return Optional<CacheEntryReader&> {}; return Optional<CacheEntryReader&> {};
@@ -109,11 +110,11 @@ Variant<Optional<CacheEntryReader&>, DiskCache::CacheHasOpenEntry> DiskCache::op
switch (cache_lifetime_status(response_headers, freshness_lifetime, current_age)) { switch (cache_lifetime_status(response_headers, freshness_lifetime, current_age)) {
case CacheLifetimeStatus::Fresh: case CacheLifetimeStatus::Fresh:
dbgln("\033[32;1mOpened disk cache entry for\033[0m {} (lifetime={}s age={}s) ({} bytes)", url, freshness_lifetime.to_seconds(), current_age.to_seconds(), index_entry->data_size); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[32;1mOpened disk cache entry for\033[0m {} (lifetime={}s age={}s) ({} bytes)", url, freshness_lifetime.to_seconds(), current_age.to_seconds(), index_entry->data_size);
break; break;
case CacheLifetimeStatus::Expired: case CacheLifetimeStatus::Expired:
dbgln("\033[33;1mCache entry expired for\033[0m {} (lifetime={}s age={}s)", url, freshness_lifetime.to_seconds(), current_age.to_seconds()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[33;1mCache entry expired for\033[0m {} (lifetime={}s age={}s)", url, freshness_lifetime.to_seconds(), current_age.to_seconds());
cache_entry.value()->remove(); cache_entry.value()->remove();
return Optional<CacheEntryReader&> {}; return Optional<CacheEntryReader&> {};
@@ -123,7 +124,7 @@ Variant<Optional<CacheEntryReader&>, DiskCache::CacheHasOpenEntry> DiskCache::op
if (check_if_cache_has_open_entry(request, cache_key, url, CheckReaderEntries::Yes)) if (check_if_cache_has_open_entry(request, cache_key, url, CheckReaderEntries::Yes))
return Optional<CacheEntryReader&> {}; return Optional<CacheEntryReader&> {};
dbgln("\033[36;1mMust revalidate disk cache entry for\033[0m {} (lifetime={}s age={}s)", url, freshness_lifetime.to_seconds(), current_age.to_seconds()); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[36;1mMust revalidate disk cache entry for\033[0m {} (lifetime={}s age={}s)", url, freshness_lifetime.to_seconds(), current_age.to_seconds());
cache_entry.value()->set_must_revalidate(); cache_entry.value()->set_must_revalidate();
break; break;
} }
@@ -142,7 +143,7 @@ bool DiskCache::check_if_cache_has_open_entry(CacheRequest& request, u64 cache_k
for (auto const& open_entry : *open_entries) { for (auto const& open_entry : *open_entries) {
if (is<CacheEntryWriter>(*open_entry)) { if (is<CacheEntryWriter>(*open_entry)) {
dbgln("\033[36;1mDeferring disk cache entry for\033[0m {} (waiting for existing writer)", url); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[36;1mDeferring disk cache entry for\033[0m {} (waiting for existing writer)", url);
m_requests_waiting_completion.ensure(cache_key).append(request); m_requests_waiting_completion.ensure(cache_key).append(request);
return true; return true;
} }
@@ -150,7 +151,7 @@ bool DiskCache::check_if_cache_has_open_entry(CacheRequest& request, u64 cache_k
// We allow concurrent readers unless another reader is open for revalidation. That reader will issue the network // We allow concurrent readers unless another reader is open for revalidation. That reader will issue the network
// request, which may then result in the cache entry being updated or deleted. // request, which may then result in the cache entry being updated or deleted.
if (check_reader_entries == CheckReaderEntries::Yes || as<CacheEntryReader>(*open_entry).must_revalidate()) { if (check_reader_entries == CheckReaderEntries::Yes || as<CacheEntryReader>(*open_entry).must_revalidate()) {
dbgln("\033[36;1mDeferring disk cache entry for\033[0m {} (waiting for existing reader)", url); dbgln_if(HTTP_DISK_CACHE_DEBUG, "\033[36;1mDeferring disk cache entry for\033[0m {} (waiting for existing reader)", url);
m_requests_waiting_completion.ensure(cache_key).append(request); m_requests_waiting_completion.ensure(cache_key).append(request);
return true; return true;
} }

View File

@@ -22,6 +22,7 @@ set(GIF_DEBUG ON)
set(HEAP_DEBUG ON) set(HEAP_DEBUG ON)
set(HIGHLIGHT_FOCUSED_FRAME_DEBUG ON) set(HIGHLIGHT_FOCUSED_FRAME_DEBUG ON)
set(HTML_SCRIPT_DEBUG ON) set(HTML_SCRIPT_DEBUG ON)
set(HTTP_DISK_CACHE_DEBUG ON)
set(HTTP_MEMORY_CACHE_DEBUG ON) set(HTTP_MEMORY_CACHE_DEBUG ON)
set(HTTPJOB_DEBUG ON) set(HTTPJOB_DEBUG ON)
set(HUNKS_DEBUG ON) set(HUNKS_DEBUG ON)