1
0
mirror of https://github.com/Zygo/bees.git synced 2025-05-17 21:35:45 +02:00

bees: drop BEESINFO

Having too many "write a message to the log" primitives is confusing,
and having one that intermittently and silently discards output is even
_more_ confusing.

Replace all BEESINFO with appropriate BEESLOG*s.  Usually DEBUG.
Except for one or two that occur too often.  Just delete those.

Signed-off-by: Zygo Blaxell <bees@furryterror.org>
This commit is contained in:
Zygo Blaxell 2018-01-25 00:07:26 -05:00
parent bd2a15733c
commit f6909dac17
6 changed files with 21 additions and 35 deletions

View File

@ -47,7 +47,7 @@ BeesFdCache::open_root(shared_ptr<BeesContext> ctx, uint64_t root)
// The open FDs prevent snapshots from being deleted. // The open FDs prevent snapshots from being deleted.
// cleaner_kthread just keeps skipping over the open dir and all its children. // cleaner_kthread just keeps skipping over the open dir and all its children.
if (m_root_cache_timer.age() > BEES_COMMIT_INTERVAL) { if (m_root_cache_timer.age() > BEES_COMMIT_INTERVAL) {
BEESINFO("Clearing root FD cache to enable subvol delete"); BEESLOGINFO("Clearing root FD cache to enable subvol delete");
m_root_cache.clear(); m_root_cache.clear();
m_root_cache_timer.reset(); m_root_cache_timer.reset();
BEESCOUNT(root_clear); BEESCOUNT(root_clear);
@ -59,7 +59,7 @@ Fd
BeesFdCache::open_root_ino(shared_ptr<BeesContext> ctx, uint64_t root, uint64_t ino) BeesFdCache::open_root_ino(shared_ptr<BeesContext> ctx, uint64_t root, uint64_t ino)
{ {
if (m_file_cache_timer.age() > BEES_COMMIT_INTERVAL) { if (m_file_cache_timer.age() > BEES_COMMIT_INTERVAL) {
BEESINFO("Clearing open FD cache to enable file delete"); BEESLOGINFO("Clearing open FD cache to enable file delete");
m_file_cache.clear(); m_file_cache.clear();
m_file_cache_timer.reset(); m_file_cache_timer.reset();
BEESCOUNT(open_clear); BEESCOUNT(open_clear);
@ -432,7 +432,7 @@ BeesContext::scan_one_extent(const BeesFileRange &bfr, const Extent &e)
// Hash is toxic // Hash is toxic
if (found_addr.is_toxic()) { if (found_addr.is_toxic()) {
BEESINFO("WORKAROUND: abandoned toxic match for hash " << hash << " addr " << found_addr); BEESLOGWARN("WORKAROUND: abandoned toxic match for hash " << hash << " addr " << found_addr);
// Don't push these back in because we'll never delete them. // Don't push these back in because we'll never delete them.
// Extents may become non-toxic so give them a chance to expire. // Extents may become non-toxic so give them a chance to expire.
// hash_table->push_front_hash_addr(hash, found_addr); // hash_table->push_front_hash_addr(hash, found_addr);
@ -449,7 +449,7 @@ BeesContext::scan_one_extent(const BeesFileRange &bfr, const Extent &e)
BeesResolver resolved(m_ctx, found_addr); BeesResolver resolved(m_ctx, found_addr);
// Toxic extents are really toxic // Toxic extents are really toxic
if (resolved.is_toxic()) { if (resolved.is_toxic()) {
BEESINFO("WORKAROUND: abandoned toxic match at found_addr " << found_addr << " matching bbd " << bbd); BEESLOGWARN("WORKAROUND: abandoned toxic match at found_addr " << found_addr << " matching bbd " << bbd);
BEESCOUNT(scan_toxic_match); BEESCOUNT(scan_toxic_match);
// Make sure we never see this hash again. // Make sure we never see this hash again.
// It has become toxic since it was inserted into the hash table. // It has become toxic since it was inserted into the hash table.
@ -503,7 +503,7 @@ BeesContext::scan_one_extent(const BeesFileRange &bfr, const Extent &e)
if (it_copy.found_hash()) { if (it_copy.found_hash()) {
BEESCOUNT(scan_hash_hit); BEESCOUNT(scan_hash_hit);
} else { } else {
// BEESINFO("erase src hash " << hash << " addr " << it_copy.addr()); // BEESLOGDEBUG("erase src hash " << hash << " addr " << it_copy.addr());
BEESCOUNT(scan_hash_miss); BEESCOUNT(scan_hash_miss);
hash_table->erase_hash_addr(hash, it_copy.addr()); hash_table->erase_hash_addr(hash, it_copy.addr());
} }
@ -706,7 +706,7 @@ BeesContext::scan_forward(const BeesFileRange &bfr)
// No FD? Well, that was quick. // No FD? Well, that was quick.
if (!bfr.fd()) { if (!bfr.fd()) {
BEESINFO("No FD in " << root_path() << " for " << bfr); // BEESLOGINFO("No FD in " << root_path() << " for " << bfr);
BEESCOUNT(scan_no_fd); BEESCOUNT(scan_no_fd);
return bfr; return bfr;
} }

View File

@ -46,7 +46,7 @@ verify_cell_range(BeesHashTable::Cell *p, BeesHashTable::Cell *q, bool clear_bug
for (BeesHashTable::Cell *cell = p; cell < q; ++cell) { for (BeesHashTable::Cell *cell = p; cell < q; ++cell) {
if (cell->e_addr && cell->e_addr < 0x1000) { if (cell->e_addr && cell->e_addr < 0x1000) {
BEESCOUNT(bug_hash_magic_addr); BEESCOUNT(bug_hash_magic_addr);
BEESINFO("Bad hash table address hash " << to_hex(cell->e_hash) << " addr " << to_hex(cell->e_addr)); BEESLOGDEBUG("Bad hash table address hash " << to_hex(cell->e_hash) << " addr " << to_hex(cell->e_addr));
if (clear_bugs) { if (clear_bugs) {
cell->e_addr = 0; cell->e_addr = 0;
cell->e_hash = 0; cell->e_hash = 0;
@ -55,8 +55,8 @@ verify_cell_range(BeesHashTable::Cell *p, BeesHashTable::Cell *q, bool clear_bug
} }
if (cell->e_addr && !seen_it.insert(*cell).second) { if (cell->e_addr && !seen_it.insert(*cell).second) {
BEESCOUNT(bug_hash_duplicate_cell); BEESCOUNT(bug_hash_duplicate_cell);
// BEESLOG("Duplicate hash table entry:\nthis = " << *cell << "\nold = " << *seen_it.find(*cell)); // BEESLOGDEBUG("Duplicate hash table entry:\nthis = " << *cell << "\nold = " << *seen_it.find(*cell));
BEESINFO("Duplicate hash table entry: " << *cell); BEESLOGDEBUG("Duplicate hash table entry: " << *cell);
if (clear_bugs) { if (clear_bugs) {
cell->e_addr = 0; cell->e_addr = 0;
cell->e_hash = 0; cell->e_hash = 0;
@ -439,7 +439,7 @@ BeesHashTable::erase_hash_addr(HashType hash, AddrType addr)
BEESCOUNT(hash_erase); BEESCOUNT(hash_erase);
#if 0 #if 0
if (verify_cell_range(er.first, er.second)) { if (verify_cell_range(er.first, er.second)) {
BEESINFO("while erasing hash " << hash << " addr " << addr); BEESLOGDEBUG("while erasing hash " << hash << " addr " << addr);
} }
#endif #endif
} }
@ -490,7 +490,7 @@ BeesHashTable::push_front_hash_addr(HashType hash, AddrType addr)
} }
#if 0 #if 0
if (verify_cell_range(er.first, er.second)) { if (verify_cell_range(er.first, er.second)) {
BEESINFO("while push_fronting hash " << hash << " addr " << addr); BEESLOGDEBUG("while push_fronting hash " << hash << " addr " << addr);
} }
#endif #endif
return found; return found;

View File

@ -197,7 +197,7 @@ BeesResolver::chase_extent_ref(const BtrfsInodeOffsetRoot &bior, BeesBlockData &
Fd file_fd = m_ctx->roots()->open_root_ino(bior.m_root, bior.m_inum); Fd file_fd = m_ctx->roots()->open_root_ino(bior.m_root, bior.m_inum);
if (!file_fd) { if (!file_fd) {
// Deleted snapshots generate craptons of these // Deleted snapshots generate craptons of these
// BEESINFO("No FD in chase_extent_ref " << bior); // BEESLOGDEBUG("No FD in chase_extent_ref " << bior);
BEESCOUNT(chase_no_fd); BEESCOUNT(chase_no_fd);
return BeesFileRange(); return BeesFileRange();
} }
@ -211,7 +211,7 @@ BeesResolver::chase_extent_ref(const BtrfsInodeOffsetRoot &bior, BeesBlockData &
// ...or are we? // ...or are we?
if (file_addr.is_magic()) { if (file_addr.is_magic()) {
BEESINFO("file_addr is magic: file_addr = " << file_addr << " bior = " << bior << " needle_bbd = " << needle_bbd); BEESLOGDEBUG("file_addr is magic: file_addr = " << file_addr << " bior = " << bior << " needle_bbd = " << needle_bbd);
BEESCOUNT(chase_wrong_magic); BEESCOUNT(chase_wrong_magic);
return BeesFileRange(); return BeesFileRange();
} }
@ -220,7 +220,7 @@ BeesResolver::chase_extent_ref(const BtrfsInodeOffsetRoot &bior, BeesBlockData &
// Did we get the physical block we asked for? The magic bits have to match too, // Did we get the physical block we asked for? The magic bits have to match too,
// but the compressed offset bits do not. // but the compressed offset bits do not.
if (file_addr.get_physical_or_zero() != m_addr.get_physical_or_zero()) { if (file_addr.get_physical_or_zero() != m_addr.get_physical_or_zero()) {
// BEESINFO("found addr " << file_addr << " at " << name_fd(file_fd) << " offset " << to_hex(bior.m_offset) << " but looking for " << m_addr); // BEESLOGDEBUG("found addr " << file_addr << " at " << name_fd(file_fd) << " offset " << to_hex(bior.m_offset) << " but looking for " << m_addr);
// FIEMAP/resolve are working, but the data is old. // FIEMAP/resolve are working, but the data is old.
BEESCOUNT(chase_wrong_addr); BEESCOUNT(chase_wrong_addr);
return BeesFileRange(); return BeesFileRange();

View File

@ -500,11 +500,11 @@ BeesRoots::open_root_nocache(uint64_t rootid)
BEESTRACE("dirid " << dirid << " root " << rootid << " INO_PATH"); BEESTRACE("dirid " << dirid << " root " << rootid << " INO_PATH");
BtrfsIoctlInoPathArgs ino(dirid); BtrfsIoctlInoPathArgs ino(dirid);
if (!ino.do_ioctl_nothrow(parent_fd)) { if (!ino.do_ioctl_nothrow(parent_fd)) {
BEESINFO("dirid " << dirid << " inode path lookup failed in parent_fd " << name_fd(parent_fd)); BEESLOGINFO("dirid " << dirid << " inode path lookup failed in parent_fd " << name_fd(parent_fd));
continue; continue;
} }
if (ino.m_paths.empty()) { if (ino.m_paths.empty()) {
BEESINFO("dirid " << dirid << " inode has no paths in parent_fd " << name_fd(parent_fd)); BEESLOGINFO("dirid " << dirid << " inode has no paths in parent_fd " << name_fd(parent_fd));
continue; continue;
} }
BEESTRACE("dirid " << dirid << " path " << ino.m_paths.at(0)); BEESTRACE("dirid " << dirid << " path " << ino.m_paths.at(0));
@ -528,12 +528,12 @@ BeesRoots::open_root_nocache(uint64_t rootid)
THROW_CHECK2(runtime_error, new_root_id, rootid, new_root_id == rootid); THROW_CHECK2(runtime_error, new_root_id, rootid, new_root_id == rootid);
Stat st(rv); Stat st(rv);
THROW_CHECK1(runtime_error, st.st_ino, st.st_ino == BTRFS_FIRST_FREE_OBJECTID); THROW_CHECK1(runtime_error, st.st_ino, st.st_ino == BTRFS_FIRST_FREE_OBJECTID);
// BEESINFO("open_root_nocache " << rootid << ": " << name_fd(rv)); // BEESLOGDEBUG("open_root_nocache " << rootid << ": " << name_fd(rv));
return rv; return rv;
} }
} }
} }
BEESINFO("No path for rootid " << rootid); BEESLOGDEBUG("No path for rootid " << rootid);
BEESCOUNT(root_notfound); BEESCOUNT(root_notfound);
return Fd(); return Fd();
} }
@ -600,7 +600,7 @@ BeesRoots::open_root_ino_nocache(uint64_t root, uint64_t ino)
BEESTRACE("looking up ino " << ino); BEESTRACE("looking up ino " << ino);
BtrfsIoctlInoPathArgs ipa(ino); BtrfsIoctlInoPathArgs ipa(ino);
if (!ipa.do_ioctl_nothrow(root_fd)) { if (!ipa.do_ioctl_nothrow(root_fd)) {
BEESINFO("Lookup root " << root << " ino " << ino << " failed: " << strerror(errno)); BEESLOGINFO("Lookup root " << root << " ino " << ino << " failed: " << strerror(errno));
return Fd(); return Fd();
} }
@ -832,13 +832,13 @@ BeesCrawl::fetch_extents()
auto type = call_btrfs_get(btrfs_stack_file_extent_type, i.m_data); auto type = call_btrfs_get(btrfs_stack_file_extent_type, i.m_data);
switch (type) { switch (type) {
default: default:
BEESINFO("Unhandled file extent type " << type << " in root " << get_state().m_root << " ino " << i.objectid << " offset " << to_hex(i.offset)); BEESLOGDEBUG("Unhandled file extent type " << type << " in root " << get_state().m_root << " ino " << i.objectid << " offset " << to_hex(i.offset));
++count_unknown; ++count_unknown;
BEESCOUNT(crawl_unknown); BEESCOUNT(crawl_unknown);
break; break;
case BTRFS_FILE_EXTENT_INLINE: case BTRFS_FILE_EXTENT_INLINE:
// Ignore these for now. // Ignore these for now.
// BEESINFO("Ignored file extent type INLINE in root " << get_state().m_root << " ino " << i.objectid << " offset " << to_hex(i.offset)); // BEESLOGDEBUG("Ignored file extent type INLINE in root " << get_state().m_root << " ino " << i.objectid << " offset " << to_hex(i.offset));
++count_inline; ++count_inline;
// TODO: replace with out-of-line dup extents // TODO: replace with out-of-line dup extents
BEESCOUNT(crawl_inline); BEESCOUNT(crawl_inline);

View File

@ -62,8 +62,6 @@ do_cmd_help(char *argv[])
// tracing ---------------------------------------- // tracing ----------------------------------------
RateLimiter bees_info_rate_limit(BEES_INFO_RATE, BEES_INFO_BURST);
thread_local BeesTracer *BeesTracer::tl_next_tracer = nullptr; thread_local BeesTracer *BeesTracer::tl_next_tracer = nullptr;
BeesTracer::~BeesTracer() BeesTracer::~BeesTracer()

View File

@ -97,10 +97,6 @@ const double BEES_TOXIC_DURATION = BEES_COMMIT_INTERVAL;
// How long between hash table histograms // How long between hash table histograms
const double BEES_HASH_TABLE_ANALYZE_INTERVAL = BEES_STATS_INTERVAL; const double BEES_HASH_TABLE_ANALYZE_INTERVAL = BEES_STATS_INTERVAL;
// Rate limiting of informational messages
const double BEES_INFO_RATE = 10.0;
const double BEES_INFO_BURST = 1.0;
// Stop growing the work queue after we have this many tasks queued // Stop growing the work queue after we have this many tasks queued
const size_t BEES_MAX_QUEUE_SIZE = 128; const size_t BEES_MAX_QUEUE_SIZE = 128;
@ -134,13 +130,6 @@ const int FLAGS_OPEN_FANOTIFY = O_RDWR | O_NOATIME | O_CLOEXEC | O_LARGEFILE;
#define BEESTRACE(x) BeesTracer SRSLY_WTF_C(beesTracer_, __LINE__) ([&]() { BEESLOG(LOG_ERR, x); }) #define BEESTRACE(x) BeesTracer SRSLY_WTF_C(beesTracer_, __LINE__) ([&]() { BEESLOG(LOG_ERR, x); })
#define BEESTOOLONG(x) BeesTooLong SRSLY_WTF_C(beesTooLong_, __LINE__) ([&](ostream &_btl_os) { _btl_os << x; }) #define BEESTOOLONG(x) BeesTooLong SRSLY_WTF_C(beesTooLong_, __LINE__) ([&](ostream &_btl_os) { _btl_os << x; })
#define BEESNOTE(x) BeesNote SRSLY_WTF_C(beesNote_, __LINE__) ([&](ostream &_btl_os) { _btl_os << x; }) #define BEESNOTE(x) BeesNote SRSLY_WTF_C(beesNote_, __LINE__) ([&](ostream &_btl_os) { _btl_os << x; })
#define BEESINFO(x) do { \
if (bees_info_rate_limit.is_ready()) { \
bees_info_rate_limit.borrow(1); \
Chatter c(LOG_INFO, BeesNote::get_name()); \
c << x; \
} \
} while (0)
#define BEESLOGERR(x) BEESLOG(LOG_ERR, x) #define BEESLOGERR(x) BEESLOG(LOG_ERR, x)
#define BEESLOGWARN(x) BEESLOG(LOG_WARNING, x) #define BEESLOGWARN(x) BEESLOG(LOG_WARNING, x)
@ -824,7 +813,6 @@ public:
// And now, a giant pile of extern declarations // And now, a giant pile of extern declarations
extern const char *BEES_VERSION; extern const char *BEES_VERSION;
string pretty(double d); string pretty(double d);
extern RateLimiter bees_info_rate_limit;
void bees_sync(int fd); void bees_sync(int fd);
string format_time(time_t t); string format_time(time_t t);