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
32 changes: 20 additions & 12 deletions iocore/cache/CacheHosting.cc
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,14 @@

extern int gndisks;

namespace
{

DbgCtl dbg_ctl_cache_hosting{"cache_hosting"};
DbgCtl dbg_ctl_matcher{"matcher"};

} // end anonymous namespace

/*************************************************************
* Begin class HostMatcher
*************************************************************/
Expand Down Expand Up @@ -169,7 +177,7 @@ CacheHostMatcher::NewEntry(matcher_line *line_info)
memset(static_cast<void *>(cur_d), 0, sizeof(CacheHostRecord));
return;
}
Debug("cache_hosting", "hostname: %s, host record: %p", match_data, cur_d);
Dbg(dbg_ctl_cache_hosting, "hostname: %s, host record: %p", match_data, cur_d);
// Fill in the matching info
host_lookup->NewEntry(match_data, (line_info->type == MATCH_DOMAIN) ? true : false, cur_d);

Expand Down Expand Up @@ -384,7 +392,7 @@ CacheHostTable::BuildTableFromString(const char *config_file_path, char *file_bu

ink_assert(second_pass == numEntries);

if (is_debug_tag_set("matcher")) {
if (is_dbg_ctl_enabled(dbg_ctl_matcher)) {
Print();
}
return numEntries;
Expand Down Expand Up @@ -426,7 +434,7 @@ CacheHostRecord::Init(CacheType typ)
CacheVol *cachep = cp_list.head;
for (; cachep; cachep = cachep->link.next) {
if (cachep->scheme == type) {
Debug("cache_hosting", "Host Record: %p, Volume: %d, size: %" PRId64, this, cachep->vol_number, (int64_t)cachep->size);
Dbg(dbg_ctl_cache_hosting, "Host Record: %p, Volume: %d, size: %" PRId64, this, cachep->vol_number, (int64_t)cachep->size);
cp[num_cachevols] = cachep;
num_cachevols++;
num_vols += cachep->num_vols;
Expand Down Expand Up @@ -517,8 +525,8 @@ CacheHostRecord::Init(matcher_line *line_info, CacheType typ)
if (cachep->vol_number == volume_number) {
is_vol_present = 1;
if (cachep->scheme == type) {
Debug("cache_hosting", "Host Record: %p, Volume: %d, size: %ld", this, volume_number,
(long)(cachep->size * STORE_BLOCK_SIZE));
Dbg(dbg_ctl_cache_hosting, "Host Record: %p, Volume: %d, size: %ld", this, volume_number,
(long)(cachep->size * STORE_BLOCK_SIZE));
cp[num_cachevols] = cachep;
num_cachevols++;
num_vols += cachep->num_vols;
Expand Down Expand Up @@ -780,8 +788,8 @@ ConfigVolumes::BuildListFromString(char *config_file_path, char *file_buf)
} else {
ink_release_assert(!"Unexpected non-HTTP cache volume");
}
Debug("cache_hosting", "added volume=%d, scheme=%d, size=%d percent=%d, ramcache enabled=%d", volume_number, scheme, size,
in_percent, ramcache_enabled);
Dbg(dbg_ctl_cache_hosting, "added volume=%d, scheme=%d, size=%d percent=%d, ramcache enabled=%d", volume_number, scheme, size,
in_percent, ramcache_enabled);
}

tmp = bufTok.iterNext(&i_state);
Expand Down Expand Up @@ -1045,14 +1053,14 @@ execute_and_verify(RegressionTest *t)

for (int i = 0; i < gndisks; i++) {
CacheDisk *d = gdisks[i];
if (is_debug_tag_set("cache_hosting")) {
Debug("cache_hosting", "Disk: %d: Vol Blocks: %u: Free space: %" PRIu64, i, d->header->num_diskvol_blks, d->free_space);
if (is_dbg_ctl_enabled(dbg_ctl_cache_hosting)) {
Dbg(dbg_ctl_cache_hosting, "Disk: %d: Vol Blocks: %u: Free space: %" PRIu64, i, d->header->num_diskvol_blks, d->free_space);
for (int j = 0; j < static_cast<int>(d->header->num_volumes); j++) {
Debug("cache_hosting", "\tVol: %d Size: %" PRIu64, d->disk_vols[j]->vol_number, d->disk_vols[j]->size);
Dbg(dbg_ctl_cache_hosting, "\tVol: %d Size: %" PRIu64, d->disk_vols[j]->vol_number, d->disk_vols[j]->size);
}
for (int j = 0; j < static_cast<int>(d->header->num_diskvol_blks); j++) {
Debug("cache_hosting", "\tBlock No: %d Size: %" PRIu64 " Free: %u", d->header->vol_info[j].number,
d->header->vol_info[j].len, d->header->vol_info[j].free);
Dbg(dbg_ctl_cache_hosting, "\tBlock No: %d Size: %" PRIu64 " Free: %u", d->header->vol_info[j].number,
d->header->vol_info[j].len, d->header->vol_info[j].free);
}
}
}
Expand Down
22 changes: 14 additions & 8 deletions iocore/cache/CachePages.cc
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,12 @@
#include "Show.h"
#include "I_Tasks.h"
#include "CacheControl.h"
namespace
{

DbgCtl dbg_ctl_cache_inspector{"cache_inspector"};

} // end anonymous namespace

struct ShowCache : public ShowCont {
enum scan_type {
Expand Down Expand Up @@ -92,8 +98,8 @@ struct ShowCache : public ShowCont {

query_len = unescapifyStr(query);

Debug("cache_inspector", "query params: '%s' len %d [unescaped]", unescapedQuery, query_len);
Debug("cache_inspector", "query params: '%s' len %d [escaped]", query, query_len);
Dbg(dbg_ctl_cache_inspector, "query params: '%s' len %d [unescaped]", unescapedQuery, query_len);
Dbg(dbg_ctl_cache_inspector, "query params: '%s' len %d [escaped]", query, query_len);

// remove 'C-m' s
unsigned l, m;
Expand Down Expand Up @@ -140,15 +146,15 @@ struct ShowCache : public ShowCont {
}
}

Debug("cache_inspector", "there were %d url(s) passed in", nstrings == 1 ? 1 : nstrings - 1);
Dbg(dbg_ctl_cache_inspector, "there were %d url(s) passed in", nstrings == 1 ? 1 : nstrings - 1);

for (unsigned i = 0; i < nstrings; i++) {
if (show_cache_urlstrs[i][0] == '\0') {
continue;
}
Debug("cache_inspector", "URL %d: '%s'", i + 1, show_cache_urlstrs[i]);
Dbg(dbg_ctl_cache_inspector, "URL %d: '%s'", i + 1, show_cache_urlstrs[i]);
unescapifyStr(show_cache_urlstrs[i]);
Debug("cache_inspector", "URL %d: '%s'", i + 1, show_cache_urlstrs[i]);
Dbg(dbg_ctl_cache_inspector, "URL %d: '%s'", i + 1, show_cache_urlstrs[i]);
}
}

Expand Down Expand Up @@ -617,7 +623,7 @@ ShowCache::handleCacheScanCallback(int event, Event *e)
int erroffset;
pcre *preq = pcre_compile(show_cache_urlstrs[s], 0, &error, &erroffset, nullptr);

Debug("cache_inspector", "matching url '%s' '%s' with regex '%s'", m, xx, show_cache_urlstrs[s]);
Dbg(dbg_ctl_cache_inspector, "matching url '%s' '%s' with regex '%s'", m, xx, show_cache_urlstrs[s]);

if (preq) {
int r = pcre_exec(preq, nullptr, xx, ib, 0, 0, nullptr, 0);
Expand Down Expand Up @@ -662,7 +668,7 @@ ShowCache::handleCacheScanCallback(int event, Event *e)
}
} else {
// TODO: Regex didn't compile, show errors ?
Debug("cache_inspector", "regex '%s' didn't compile", show_cache_urlstrs[s]);
Dbg(dbg_ctl_cache_inspector, "regex '%s' didn't compile", show_cache_urlstrs[s]);
}
}
return res;
Expand All @@ -677,7 +683,7 @@ ShowCache::handleCacheScanCallback(int event, Event *e)
}
}
CHECK_SHOW(show("<H3>Done</H3>\n"));
Debug("cache_inspector", "scan done");
Dbg(dbg_ctl_cache_inspector, "scan done");
complete(event, e);
return EVENT_DONE;
case CACHE_EVENT_SCAN_FAILED:
Expand Down
49 changes: 29 additions & 20 deletions iocore/cache/CacheVol.cc
Original file line number Diff line number Diff line change
Expand Up @@ -26,10 +26,18 @@
#define SCAN_BUF_SIZE RECOVERY_SIZE
#define SCAN_WRITER_LOCK_MAX_RETRY 5

namespace
{

DbgCtl dbg_ctl_cache_scan{"cache_scan"};
DbgCtl dbg_ctl_cache_scan_truss{"cache_scan_truss"};

} // end anonymous namespace

Action *
Cache::scan(Continuation *cont, const char *hostname, int host_len, int KB_per_second)
{
Debug("cache_scan_truss", "inside scan");
Dbg(dbg_ctl_cache_scan_truss, "inside scan");
if (!CacheProcessor::IsCacheReady(CACHE_FRAG_TYPE_HTTP)) {
cont->handleEvent(CACHE_EVENT_SCAN_FAILED, nullptr);
return ACTION_RESULT_DONE;
Expand All @@ -53,7 +61,7 @@ Cache::scan(Continuation *cont, const char *hostname, int host_len, int KB_per_s
int
CacheVC::scanVol(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
{
Debug("cache_scan_truss", "inside %p:scanVol", this);
Dbg(dbg_ctl_cache_scan_truss, "inside %p:scanVol", this);
if (_action.cancelled) {
return free_CacheVC(this);
}
Expand Down Expand Up @@ -164,7 +172,7 @@ make_vol_map(Vol *vol)
int
CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
{
Debug("cache_scan_truss", "inside %p:scanObject", this);
Dbg(dbg_ctl_cache_scan_truss, "inside %p:scanObject", this);

Doc *doc = nullptr;
void *result = nullptr;
Expand All @@ -182,7 +190,7 @@ CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)

CACHE_TRY_LOCK(lock, vol->mutex, mutex->thread_holding);
if (!lock.is_locked()) {
Debug("cache_scan_truss", "delay %p:scanObject", this);
Dbg(dbg_ctl_cache_scan_truss, "delay %p:scanObject", this);
mutex->thread_holding->schedule_in_local(this, HRTIME_MSECONDS(cache_config_mutex_retry_delay));
return EVENT_CONT;
}
Expand All @@ -198,7 +206,7 @@ CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
io.aiocb.aio_buf = buf->data();
io.action = this;
io.thread = AIO_CALLBACK_THREAD_ANY;
Debug("cache_scan_truss", "read %p:scanObject", this);
Dbg(dbg_ctl_cache_scan_truss, "read %p:scanObject", this);
goto Lread;
}

Expand Down Expand Up @@ -227,7 +235,7 @@ CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)

if (doc->magic != DOC_MAGIC) {
next_object_len = CACHE_BLOCK_SIZE;
Debug("cache_scan_truss", "blockskip %p:scanObject", this);
Dbg(dbg_ctl_cache_scan_truss, "blockskip %p:scanObject", this);
continue;
}

Expand Down Expand Up @@ -275,7 +283,7 @@ CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
if (!hostinfo_copied) {
memccpy(hname, vector.get(i)->request_get()->host_get(&hlen), 0, 500);
hname[hlen] = 0;
Debug("cache_scan", "hostname = '%s', hostlen = %d", hname, hlen);
Dbg(dbg_ctl_cache_scan, "hostname = '%s', hostlen = %d", hname, hlen);
hostinfo_copied = true;
}
vector.get(i)->object_key_get(&key);
Expand Down Expand Up @@ -357,9 +365,9 @@ CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
scan_fix_buffer_offset = partial_object_len;
} else { // Normal case, where we ended on a object boundary.
io.aiocb.aio_offset += (reinterpret_cast<char *>(doc) - buf->data()) + next_object_len;
Debug("cache_scan_truss", "next %p:scanObject %" PRId64, this, (int64_t)io.aiocb.aio_offset);
Dbg(dbg_ctl_cache_scan_truss, "next %p:scanObject %" PRId64, this, (int64_t)io.aiocb.aio_offset);
io.aiocb.aio_offset = next_in_map(vol, scan_vol_map, io.aiocb.aio_offset);
Debug("cache_scan_truss", "next_in_map %p:scanObject %" PRId64, this, (int64_t)io.aiocb.aio_offset);
Dbg(dbg_ctl_cache_scan_truss, "next_in_map %p:scanObject %" PRId64, this, (int64_t)io.aiocb.aio_offset);
io.aiocb.aio_nbytes = SCAN_BUF_SIZE;
io.aiocb.aio_buf = buf->data();
scan_fix_buffer_offset = 0;
Expand All @@ -379,11 +387,12 @@ CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
}
offset = 0;
ink_assert(ink_aio_read(&io) >= 0);
Debug("cache_scan_truss", "read %p:scanObject %" PRId64 " %zu", this, (int64_t)io.aiocb.aio_offset, (size_t)io.aiocb.aio_nbytes);
Dbg(dbg_ctl_cache_scan_truss, "read %p:scanObject %" PRId64 " %zu", this, (int64_t)io.aiocb.aio_offset,
(size_t)io.aiocb.aio_nbytes);
return EVENT_CONT;

Ldone:
Debug("cache_scan_truss", "done %p:scanObject", this);
Dbg(dbg_ctl_cache_scan_truss, "done %p:scanObject", this);
_action.continuation->handleEvent(CACHE_EVENT_SCAN_DONE, result);
Lcancel:
return free_CacheVC(this);
Expand All @@ -392,8 +401,8 @@ CacheVC::scanObject(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
int
CacheVC::scanRemoveDone(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
{
Debug("cache_scan_truss", "inside %p:scanRemoveDone", this);
Debug("cache_scan", "remove done.");
Dbg(dbg_ctl_cache_scan_truss, "inside %p:scanRemoveDone", this);
Dbg(dbg_ctl_cache_scan, "remove done.");
alternate.destroy();
SET_HANDLER(&CacheVC::scanObject);
return handleEvent(EVENT_IMMEDIATE, nullptr);
Expand All @@ -402,12 +411,12 @@ CacheVC::scanRemoveDone(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
int
CacheVC::scanOpenWrite(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
{
Debug("cache_scan_truss", "inside %p:scanOpenWrite", this);
Dbg(dbg_ctl_cache_scan_truss, "inside %p:scanOpenWrite", this);
cancel_trigger();
// get volume lock
if (writer_lock_retry > SCAN_WRITER_LOCK_MAX_RETRY) {
int r = _action.continuation->handleEvent(CACHE_EVENT_SCAN_OPERATION_BLOCKED, nullptr);
Debug("cache_scan", "still haven't got the writer lock, asking user..");
Dbg(dbg_ctl_cache_scan, "still haven't got the writer lock, asking user..");
switch (r) {
case CACHE_SCAN_RESULT_RETRY:
writer_lock_retry = 0;
Expand All @@ -421,11 +430,11 @@ CacheVC::scanOpenWrite(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
{
CACHE_TRY_LOCK(lock, vol->mutex, mutex->thread_holding);
if (!lock.is_locked()) {
Debug("cache_scan", "vol->mutex %p:scanOpenWrite", this);
Dbg(dbg_ctl_cache_scan, "vol->mutex %p:scanOpenWrite", this);
VC_SCHED_LOCK_RETRY();
}

Debug("cache_scan", "trying for writer lock");
Dbg(dbg_ctl_cache_scan, "trying for writer lock");
if (vol->open_write(this, false, 1)) {
writer_lock_retry++;
SET_HANDLER(&CacheVC::scanOpenWrite);
Expand All @@ -443,7 +452,7 @@ CacheVC::scanOpenWrite(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
vector.clear(false);
// check that the directory entry was not overwritten
// if so return failure
Debug("cache_scan", "got writer lock");
Dbg(dbg_ctl_cache_scan, "got writer lock");
Dir *l = nullptr;
Dir d;
Doc *doc = reinterpret_cast<Doc *>(buf->data() + offset);
Expand All @@ -467,7 +476,7 @@ CacheVC::scanOpenWrite(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
return handleEvent(EVENT_IMMEDIATE, nullptr);
}
if (memcmp(&dir, &d, SIZEOF_DIR)) {
Debug("cache_scan", "dir entry has changed");
Dbg(dbg_ctl_cache_scan, "dir entry has changed");
continue;
}
break;
Expand All @@ -491,7 +500,7 @@ CacheVC::scanOpenWrite(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
int
CacheVC::scanUpdateDone(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
{
Debug("cache_scan_truss", "inside %p:scanUpdateDone", this);
Dbg(dbg_ctl_cache_scan_truss, "inside %p:scanUpdateDone", this);
cancel_trigger();
// get volume lock
CACHE_TRY_LOCK(lock, vol->mutex, mutex->thread_holding);
Expand Down
24 changes: 16 additions & 8 deletions iocore/cache/Store.cc
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,13 @@
const char Store::VOLUME_KEY[] = "volume";
const char Store::HASH_BASE_STRING_KEY[] = "id";

namespace
{

DbgCtl dbg_ctl_cache_init{"cache_init"};

} // end anonymous namespace

static span_error_t
make_span_error(int error)
{
Expand Down Expand Up @@ -311,7 +318,7 @@ Store::read_config()
ats_scoped_str storage_path(RecConfigReadConfigPath(nullptr, ts::filename::STORAGE));

Note("%s loading ...", ts::filename::STORAGE);
Debug("cache_init", "Store::read_config, fd = -1, \"%s\"", (const char *)storage_path);
Dbg(dbg_ctl_cache_init, "Store::read_config, fd = -1, \"%s\"", (const char *)storage_path);
fd = ::open(storage_path, O_RDONLY);
if (fd < 0) {
Error("%s failed to load", ts::filename::STORAGE);
Expand Down Expand Up @@ -340,7 +347,7 @@ Store::read_config()
}

// parse
Debug("cache_init", "Store::read_config: \"%s\"", path);
Dbg(dbg_ctl_cache_init, "Store::read_config: \"%s\"", path);
++n_disks_in_config;

int64_t size = -1;
Expand Down Expand Up @@ -378,10 +385,10 @@ Store::read_config()
std::string pp = Layout::get()->relative(path);

ns = new Span;
Debug("cache_init", "Store::read_config - ns = new Span; ns->init(\"%s\",%" PRId64 "), forced volume=%d%s%s", pp.c_str(), size,
volume_num, seed ? " id=" : "", seed ? seed : "");
Dbg(dbg_ctl_cache_init, "Store::read_config - ns = new Span; ns->init(\"%s\",%" PRId64 "), forced volume=%d%s%s", pp.c_str(),
size, volume_num, seed ? " id=" : "", seed ? seed : "");
if ((err = ns->init(pp.c_str(), size))) {
Debug("cache_init", "Store::read_config - could not initialize storage \"%s\" [%s]", pp.c_str(), err);
Dbg(dbg_ctl_cache_init, "Store::read_config - could not initialize storage \"%s\" [%s]", pp.c_str(), err);
delete ns;
continue;
}
Expand Down Expand Up @@ -569,9 +576,10 @@ Span::init(const char *path, int64_t size)
this->set_mmapable(ink_file_is_mmappable(S_ISDIR(sbuf.st_mode) ? static_cast<mode_t>(S_IFREG) : sbuf.st_mode));
this->pathname = ats_strdup(path);

Debug("cache_init", "initialized span '%s'", this->pathname.get());
Debug("cache_init", "hw_sector_size=%d, size=%" PRId64 ", blocks=%" PRId64 ", disk_id=%" PRId64 "/%" PRId64 ", file_pathname=%d",
this->hw_sector_size, this->size(), this->blocks, this->disk_id[0], this->disk_id[1], this->file_pathname);
Dbg(dbg_ctl_cache_init, "initialized span '%s'", this->pathname.get());
Dbg(dbg_ctl_cache_init,
"hw_sector_size=%d, size=%" PRId64 ", blocks=%" PRId64 ", disk_id=%" PRId64 "/%" PRId64 ", file_pathname=%d",
this->hw_sector_size, this->size(), this->blocks, this->disk_id[0], this->disk_id[1], this->file_pathname);

return nullptr;

Expand Down
Loading