diff --git a/common/log.cc b/common/log.cc index ded833df..74fc4dc6 100644 --- a/common/log.cc +++ b/common/log.cc @@ -113,6 +113,10 @@ void percent(uint64_t count, uint64_t max, bool displayElapsed) { bool expected = false; + if (!(logging::mask & flag::CLOCK_ELAPSED)) { + displayElapsed = false; + } + if (count == max) { while (!locked.compare_exchange_weak(expected, true)) ; // wait until everybody else is done } else { @@ -158,7 +162,7 @@ void percent(uint64_t count, uint64_t max, bool displayElapsed) " . ", " ." }; - last_count = (last_count + 1) > 3 ? 0 : (last_count + 1); + last_count = (last_count + 1) >= std::size(spinners) ? 0 : (last_count + 1); print(flag::PERCENT, "[{}]\r", spinners[last_count]); last_indeterminate_time = t; } @@ -169,11 +173,17 @@ void percent(uint64_t count, uint64_t max, bool displayElapsed) locked = false; } -percent_clock::~percent_clock() +void percent_clock::print() { + if (!ready) { + return; + } + + ready = false; + if (max != indeterminate) { - if (count != max - 1) { - print("ERROR TO FIX LATER: clock counter ended too early\n"); + if (count != max) { + logging::print("ERROR TO FIX LATER: clock counter ended too early\n"); } } diff --git a/common/settings.cc b/common/settings.cc index 10428e68..544cab52 100644 --- a/common/settings.cc +++ b/common/settings.cc @@ -175,7 +175,7 @@ void common_settings::postinitialize(int argc, const char **argv) } if (nopercent.value()) { - logging::mask &= ~bitflags(logging::flag::PERCENT); + logging::mask &= ~(bitflags(logging::flag::PERCENT) | logging::flag::CLOCK_ELAPSED); } if (nostat.value()) { diff --git a/include/common/log.hh b/include/common/log.hh index 21acd2e2..e060eb24 100644 --- a/include/common/log.hh +++ b/include/common/log.hh @@ -49,6 +49,7 @@ enum class flag : uint8_t PROGRESS = nth_bit(2), // prints only to stdout PERCENT = nth_bit(3), // prints everywhere, if enabled STAT = nth_bit(4), // prints everywhere, if enabled + CLOCK_ELAPSED = nth_bit(5), // overrides displayElapsed if disabled ALL = 0xFF }; @@ -125,19 +126,52 @@ constexpr uint64_t indeterminate = std::numeric_limits::max(); #include -// simple wrapper to percent() to use it in an object-oriented manner. +// simple wrapper to percent() to use it in an object-oriented manner. you can +// call print() to explicitly end the clock, or allow it to run out of scope. struct percent_clock { - std::atomic max = indeterminate; + std::atomic max; bool displayElapsed = true; std::atomic count = 0; + bool ready = true; - inline void increase() + // runs a tick immediately to show up on stdout + // unless max is zero + inline percent_clock(uint64_t max = indeterminate) : + max(max) { - percent(count++, max, displayElapsed); + if (max != 0) { + percent(0, max, displayElapsed); + } } - ~percent_clock(); + // increase count by 1 + inline void increase() + { + if (count == max) { + logging::print("ERROR TO FIX LATER: clock counter increased to end, but not finished yet\n"); + } + + percent(count++, max, displayElapsed); + } + + // increase count by 1 + inline void operator()() + { + increase(); + } + + // increase count by 1 + inline void operator++(int) + { + increase(); + } + + // prints & ends the clock; class is invalid after this call. + void print(); + + // implicitly calls print() + inline ~percent_clock() { print(); } }; #include diff --git a/qbsp/brush.cc b/qbsp/brush.cc index 5766e1a6..c25b5122 100644 --- a/qbsp/brush.cc +++ b/qbsp/brush.cc @@ -350,13 +350,15 @@ std::optional LoadBrush(const mapentity_t *src, mapbrush_t *mapbrush //============================================================================= -static void Brush_LoadEntity(mapentity_t *dst, mapentity_t *src, const int hullnum, content_stats_base_t &stats, bspbrush_t::container &brushes) +static void Brush_LoadEntity(mapentity_t *dst, mapentity_t *src, const int hullnum, content_stats_base_t &stats, bspbrush_t::container &brushes, logging::percent_clock &clock) { // _omitbrushes 1 just discards all brushes in the entity. // could be useful for geometry guides, selective compilation, etc. if (src->epairs.get_int("_omitbrushes")) { return; } + + clock.max += src->mapbrushes.size(); bool all_detail, all_detail_fence, all_detail_illusionary; @@ -398,7 +400,8 @@ static void Brush_LoadEntity(mapentity_t *dst, mapentity_t *src, const int hulln auto it = src->mapbrushes.begin(); for (size_t i = 0; i < src->mapbrushes.size(); i++, it++) { - logging::percent(i, src->mapbrushes.size()); + clock(); + auto &mapbrush = *it; contentflags_t contents = mapbrush.contents; @@ -506,8 +509,6 @@ static void Brush_LoadEntity(mapentity_t *dst, mapentity_t *src, const int hulln dst->bounds += brush->bounds; brushes.push_back(bspbrush_t::make_ptr(std::move(*brush))); } - - logging::percent(src->mapbrushes.size(), src->mapbrushes.size(), src == map.world_entity()); } /* @@ -523,8 +524,10 @@ void Brush_LoadEntity(mapentity_t *entity, const int hullnum, bspbrush_t::contai logging::funcheader(); auto stats = qbsp_options.target_game->create_content_stats(); + logging::percent_clock clock(0); + clock.displayElapsed = (entity == map.world_entity()); - Brush_LoadEntity(entity, entity, hullnum, *stats, brushes); + Brush_LoadEntity(entity, entity, hullnum, *stats, brushes, clock); /* * If this is the world entity, find all func_group and func_detail @@ -544,11 +547,13 @@ void Brush_LoadEntity(mapentity_t *entity, const int hullnum, bspbrush_t::contai ProcessAreaPortal(source); if (IsWorldBrushEntity(source) || IsNonRemoveWorldBrushEntity(source)) { - Brush_LoadEntity(entity, source, hullnum, *stats, brushes); + Brush_LoadEntity(entity, source, hullnum, *stats, brushes, clock); } } } + clock.print(); + logging::header("CountBrushes"); qbsp_options.target_game->print_content_stats(*stats, "brushes"); diff --git a/qbsp/brushbsp.cc b/qbsp/brushbsp.cc index 9cc548fb..066b44f2 100644 --- a/qbsp/brushbsp.cc +++ b/qbsp/brushbsp.cc @@ -992,7 +992,7 @@ static void BuildTree_r(tree_t *tree, node_t *node, bspbrush_t::container brushe if (!bestplane) { // this is a leaf node - clock.increase(); + clock(); node->is_leaf = true; @@ -1002,7 +1002,7 @@ static void BuildTree_r(tree_t *tree, node_t *node, bspbrush_t::container brushe return; } - clock.increase(); + clock(); // this is a splitplane node stats.c_nodes++; @@ -1266,100 +1266,98 @@ void ChopBrushes(bspbrush_t::container &brushes) // clear original list brushes.clear(); - { - logging::percent_clock clock; + logging::percent_clock clock(list.size()); + chopstats_t stats; - chopstats_t stats; + decltype(list)::iterator b1_it = list.begin(); - decltype(list)::iterator b1_it = list.begin(); +newlist: - newlist: - - if (!list.size()) { - // clear output since this is kind of an error... - brushes.clear(); - return; - } - - decltype(list)::iterator next; - - for (; b1_it != list.end(); b1_it = next) - { - clock.max = list.size(); - next = std::next(b1_it); - - auto &b1 = *b1_it; - - for (auto b2_it = next; b2_it != list.end(); b2_it++) - { - auto &b2 = *b2_it; - - if (BrushesDisjoint(*b1, *b2)) { - continue; - } - - bspbrush_t::list sub, sub2; - size_t c1 = std::numeric_limits::max(), c2 = c1; - - if (BrushGE(*b2, *b1)) { - sub = SubtractBrush(b1, b2); - if (sub.size() == 1 && sub.front() == b1) { - continue; // didn't really intersect - } - - if (sub.empty()) { // b1 is swallowed by b2 - b1_it = list.erase(b1_it); // continue after b1_it - stats.c_swallowed++; - goto newlist; - } - c1 = sub.size(); - } - - if (BrushGE (*b1, *b2)) { - sub2 = SubtractBrush (b2, b1); - if (sub2.size() == 1 && sub2.front() == b2) { - continue; // didn't really intersect - } - if (sub2.empty()) { // b2 is swallowed by b1 - list.erase(b2_it); - // continue where b1_it was - stats.c_swallowed++; - goto newlist; - } - c2 = sub2.size(); - } - - if (sub.empty() && sub2.empty()) { - continue; // neither one can bite - } - - // only accept if it didn't fragment - // (commenting this out allows full fragmentation) - if (c1 > 1 && c2 > 1) { - continue; - } - - if (c1 < c2) { - stats.c_from_split += sub.size(); - list.splice(list.end(), sub); - b1_it = list.erase(b1_it); // start from after b1_it - goto newlist; - } else { - stats.c_from_split += sub2.size(); - list.splice(list.end(), sub2); - list.erase(b2_it); - // start from where b1_it left off - goto newlist; - } - } - - clock.increase(); - } - - // since chopbrushes can remove stuff, exact counts are hard... - clock.count = clock.max - 1; + if (!list.size()) { + // clear output since this is kind of an error... + brushes.clear(); + return; } + decltype(list)::iterator next; + + for (; b1_it != list.end(); b1_it = next) + { + clock.max = list.size(); + next = std::next(b1_it); + + auto &b1 = *b1_it; + + for (auto b2_it = next; b2_it != list.end(); b2_it++) + { + auto &b2 = *b2_it; + + if (BrushesDisjoint(*b1, *b2)) { + continue; + } + + bspbrush_t::list sub, sub2; + size_t c1 = std::numeric_limits::max(), c2 = c1; + + if (BrushGE(*b2, *b1)) { + sub = SubtractBrush(b1, b2); + if (sub.size() == 1 && sub.front() == b1) { + continue; // didn't really intersect + } + + if (sub.empty()) { // b1 is swallowed by b2 + b1_it = list.erase(b1_it); // continue after b1_it + stats.c_swallowed++; + goto newlist; + } + c1 = sub.size(); + } + + if (BrushGE (*b1, *b2)) { + sub2 = SubtractBrush (b2, b1); + if (sub2.size() == 1 && sub2.front() == b2) { + continue; // didn't really intersect + } + if (sub2.empty()) { // b2 is swallowed by b1 + list.erase(b2_it); + // continue where b1_it was + stats.c_swallowed++; + goto newlist; + } + c2 = sub2.size(); + } + + if (sub.empty() && sub2.empty()) { + continue; // neither one can bite + } + + // only accept if it didn't fragment + // (commenting this out allows full fragmentation) + if (c1 > 1 && c2 > 1) { + continue; + } + + if (c1 < c2) { + stats.c_from_split += sub.size(); + list.splice(list.end(), sub); + b1_it = list.erase(b1_it); // start from after b1_it + goto newlist; + } else { + stats.c_from_split += sub2.size(); + list.splice(list.end(), sub2); + list.erase(b2_it); + // start from where b1_it left off + goto newlist; + } + } + + clock(); + } + + // since chopbrushes can remove stuff, exact counts are hard... + clock.max = list.size(); + clock.print(); + brushes.insert(brushes.begin(), std::make_move_iterator(list.begin()), std::make_move_iterator(list.end())); logging::print(logging::flag::STAT, "chopped {} brushes into {}\n", original_count, brushes.size()); diff --git a/qbsp/map.cc b/qbsp/map.cc index 19d9c2e5..117454ff 100644 --- a/qbsp/map.cc +++ b/qbsp/map.cc @@ -2262,9 +2262,11 @@ void ProcessMapBrushes() map.total_brushes = 0; size_t num_faces = 0, num_bevels = 0, num_removed = 0, num_offset = 0; + logging::percent_clock clock(map.entities.size()); // calculate brush extents and brush bevels for (auto &entity : map.entities) { + clock(); /* Origin brush support */ entity.rotation = rotation_t::none; @@ -2393,6 +2395,7 @@ void ProcessMapBrushes() } #endif } + clock.print(); logging::print(logging::flag::STAT, " {:8} brushes\n", map.total_brushes); logging::print(logging::flag::STAT, " {:8} faces\n", num_faces); diff --git a/qbsp/outside.cc b/qbsp/outside.cc index 18307466..68925cc1 100644 --- a/qbsp/outside.cc +++ b/qbsp/outside.cc @@ -589,6 +589,7 @@ bool FillOutside(mapentity_t *entity, tree_t *tree, const int hullnum, bspbrush_ node_t *node = tree->headnode; logging::funcheader(); + logging::percent_clock clock; /* Clear the outside filling state on all nodes */ ClearOccupied_r(node); diff --git a/qbsp/portals.cc b/qbsp/portals.cc index 2c5480a7..20c6835d 100644 --- a/qbsp/portals.cc +++ b/qbsp/portals.cc @@ -399,14 +399,15 @@ void CalcNodeBounds(node_t *node) } } -static void CalcTreeBounds_r(tree_t *tree, node_t *node) +static void CalcTreeBounds_r(tree_t *tree, node_t *node, logging::percent_clock &clock) { if (node->is_leaf) { + clock(); CalcNodeBounds(node); } else { tbb::task_group g; - g.run([&]() { CalcTreeBounds_r(tree, node->children[0]); }); - g.run([&]() { CalcTreeBounds_r(tree, node->children[1]); }); + g.run([&]() { CalcTreeBounds_r(tree, node->children[0], clock); }); + g.run([&]() { CalcTreeBounds_r(tree, node->children[1], clock); }); g.wait(); node->bounds = node->children[0]->bounds + node->children[1]->bounds; @@ -467,7 +468,7 @@ Given the list of portals bounding `node`, returns the portal list for a fully-p */ std::list> MakeTreePortals_r(tree_t *tree, node_t *node, portaltype_t type, std::list> boundary_portals, portalstats_t &stats, logging::percent_clock &clock) { - clock.increase(); + clock(); if (node->is_leaf || (type == portaltype_t::VIS && node->detail_separator)) { return boundary_portals; @@ -526,8 +527,7 @@ void MakeTreePortals(tree_t *tree) auto headnodeportals = MakeHeadnodePortals(tree); { - logging::percent_clock clock; - clock.max = tree->nodes.size() + 1; + logging::percent_clock clock(tree->nodes.size()); portalstats_t stats{}; @@ -538,7 +538,9 @@ void MakeTreePortals(tree_t *tree) logging::header("CalcTreeBounds"); - CalcTreeBounds_r(tree, tree->headnode); + logging::percent_clock clock; + CalcTreeBounds_r(tree, tree->headnode, clock); + clock.print(); logging::print(logging::flag::STAT, " {:8} tree portals\n", tree->portals.size()); } @@ -778,7 +780,7 @@ FindPortalSide Finds a brush side to use for texturing the given portal ============ */ -static void FindPortalSide(portal_t *p) +static void FindPortalSide(portal_t *p, size_t &num_sides_not_found) { // decide which content change is strongest // solid > lava > water, etc @@ -860,8 +862,9 @@ static void FindPortalSide(portal_t *p) } } - if (!bestside[0] && !bestside[1]) - logging::print("WARNING: side not found for portal\n"); + if (!bestside[0] && !bestside[1]) { + num_sides_not_found++; + } p->sidefound = true; @@ -876,11 +879,11 @@ MarkVisibleSides_r =============== */ -static void MarkVisibleSides_r(node_t *node) +static void MarkVisibleSides_r(node_t *node, size_t &num_sides_not_found) { if (!node->is_leaf) { - MarkVisibleSides_r(node->children[0]); - MarkVisibleSides_r(node->children[1]); + MarkVisibleSides_r(node->children[0], num_sides_not_found); + MarkVisibleSides_r(node->children[1], num_sides_not_found); return; } @@ -894,8 +897,9 @@ static void MarkVisibleSides_r(node_t *node) s = (p->nodes[0] == node); if (!p->onnode) continue; // edge of world - if (!p->sidefound) - FindPortalSide(p); + if (!p->sidefound) { + FindPortalSide(p, num_sides_not_found); + } for (int i = 0; i < 2; ++i) { if (p->sides[i] && p->sides[i]->source) { p->sides[i]->source->visible = true; @@ -923,6 +927,12 @@ void MarkVisibleSides(tree_t *tree, mapentity_t *entity, bspbrush_t::container & } } + size_t num_sides_not_found = 0; + // set visible flags on the sides that are used by portals - MarkVisibleSides_r(tree->headnode); + MarkVisibleSides_r(tree->headnode, num_sides_not_found); + + if (num_sides_not_found) { + logging::print("WARNING: sides not found for {} portals\n", num_sides_not_found); + } } diff --git a/qbsp/qbsp.cc b/qbsp/qbsp.cc index 1ee471fa..f0460a83 100644 --- a/qbsp/qbsp.cc +++ b/qbsp/qbsp.cc @@ -629,7 +629,7 @@ static void UpdateEntLump(void) if (!qbsp_options.fAllverbose) { qbsp_options.fVerbose = false; logging::mask &= - ~(bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT); + ~(bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::CLOCK_ELAPSED); } } @@ -784,7 +784,7 @@ static void CreateSingleHull(const int hullnum) if (!qbsp_options.fAllverbose) { qbsp_options.fVerbose = false; // don't print rest of entities logging::mask &= - ~(bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT); + ~(bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::CLOCK_ELAPSED); } } } @@ -800,7 +800,7 @@ static void CreateHulls(void) if (!qbsp_options.fNoverbose) { qbsp_options.fVerbose = true; logging::mask |= - (bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT); + (bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::CLOCK_ELAPSED); } auto &hulls = qbsp_options.target_game->get_hull_sizes(); @@ -941,7 +941,7 @@ void ProcessFile() if (!qbsp_options.fAllverbose) { qbsp_options.fVerbose = false; logging::mask &= - ~(bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT); + ~(bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::CLOCK_ELAPSED); } // create hulls! @@ -951,7 +951,7 @@ void ProcessFile() if (!qbsp_options.fNoverbose) { qbsp_options.fVerbose = true; logging::mask |= - (bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT); + (bitflags(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::CLOCK_ELAPSED); } WriteEntitiesToString();