allow explicit calling of percent_clock so it can be simplified a bit

add more timers in a few spots
by default, display percent timers but don't display elapsed for non-verbose stuff (bmodels); this is so it still shows that it's "working" instead of just showing blank for large maps, give user an idea on progress for certain stuff
merge all "side not found"s into a single line
time `FillOutside`
time `ProcessMapBrushes`
time `Brush_LoadEntity`
This commit is contained in:
Jonathan 2022-08-12 01:30:04 -04:00
parent 4bf2ab338c
commit bf162c7a86
9 changed files with 189 additions and 128 deletions

View File

@ -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");
}
}

View File

@ -175,7 +175,7 @@ void common_settings::postinitialize(int argc, const char **argv)
}
if (nopercent.value()) {
logging::mask &= ~bitflags<logging::flag>(logging::flag::PERCENT);
logging::mask &= ~(bitflags<logging::flag>(logging::flag::PERCENT) | logging::flag::CLOCK_ELAPSED);
}
if (nostat.value()) {

View File

@ -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<uint64_t>::max();
#include <atomic>
// 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<uint64_t> max = indeterminate;
std::atomic<uint64_t> max;
bool displayElapsed = true;
std::atomic<uint64_t> count = 0;
bool ready = true;
// runs a tick immediately to show up on stdout
// unless max is zero
inline percent_clock(uint64_t max = indeterminate) :
max(max)
{
if (max != 0) {
percent(0, max, displayElapsed);
}
}
// 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);
}
~percent_clock();
// 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 <list>

View File

@ -350,7 +350,7 @@ std::optional<bspbrush_t> 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.
@ -358,6 +358,8 @@ static void Brush_LoadEntity(mapentity_t *dst, mapentity_t *src, const int hulln
return;
}
clock.max += src->mapbrushes.size();
bool all_detail, all_detail_fence, all_detail_illusionary;
const std::string &classname = src->epairs.get("classname");
@ -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");

View File

@ -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,9 +1266,7 @@ void ChopBrushes(bspbrush_t::container &brushes)
// clear original list
brushes.clear();
{
logging::percent_clock clock;
logging::percent_clock clock(list.size());
chopstats_t stats;
decltype(list)::iterator b1_it = list.begin();
@ -1353,12 +1351,12 @@ void ChopBrushes(bspbrush_t::container &brushes)
}
}
clock.increase();
clock();
}
// since chopbrushes can remove stuff, exact counts are hard...
clock.count = clock.max - 1;
}
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());

View File

@ -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);

View File

@ -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);

View File

@ -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<std::unique_ptr<buildportal_t>> MakeTreePortals_r(tree_t *tree, node_t *node, portaltype_t type, std::list<std::unique_ptr<buildportal_t>> 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);
}
}

View File

@ -629,7 +629,7 @@ static void UpdateEntLump(void)
if (!qbsp_options.fAllverbose) {
qbsp_options.fVerbose = false;
logging::mask &=
~(bitflags<logging::flag>(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT);
~(bitflags<logging::flag>(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>(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT);
~(bitflags<logging::flag>(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>(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT);
(bitflags<logging::flag>(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>(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT);
~(bitflags<logging::flag>(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>(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::PERCENT);
(bitflags<logging::flag>(logging::flag::STAT) | logging::flag::PROGRESS | logging::flag::CLOCK_ELAPSED);
}
WriteEntitiesToString();