Files @ r27888:73e8956ac824
Branch filter:

Location: cpp/openttd-patchpack/source/src/newgrf_profiling.cpp

Michael Lutz
Feature: [NewGRF] Related Act2 objects for airports and airport tiles.

Airports are similar two stations and industries, both of which have the town as related object.
Airport tiles are similar to industry tiles, which have the industry as related object.
This seems a sensible structure, so let's make it Airport Tile -> Airport -> Town.
/*
 * This file is part of OpenTTD.
 * OpenTTD is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by the Free Software Foundation, version 2.
 * OpenTTD is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
 * See the GNU General Public License for more details. You should have received a copy of the GNU General Public License along with OpenTTD. If not, see <http://www.gnu.org/licenses/>.
 */

 /** @file newgrf_profiling.cpp Profiling of NewGRF action 2 handling. */

#include "newgrf_profiling.h"
#include "fileio_func.h"
#include "string_func.h"
#include "console_func.h"
#include "spritecache.h"
#include "3rdparty/fmt/chrono.h"
#include "timer/timer.h"
#include "timer/timer_game_tick.h"

#include <chrono>


std::vector<NewGRFProfiler> _newgrf_profilers;


/**
 * Create profiler object and begin profiling session.
 * @param grffile   The GRF file to collect profiling data on
 * @param end_date  Game date to end profiling on
 */
NewGRFProfiler::NewGRFProfiler(const GRFFile *grffile) : grffile{ grffile }, active{ false }, cur_call{}
{
}

/**
 * Complete profiling session and write data to file
 */
NewGRFProfiler::~NewGRFProfiler()
{
}

/**
 * Capture the start of a sprite group resolution.
 * @param resolver  Data about sprite group being resolved
 */
void NewGRFProfiler::BeginResolve(const ResolverObject &resolver)
{
	using namespace std::chrono;
	this->cur_call.root_sprite = resolver.root_spritegroup->nfo_line;
	this->cur_call.subs = 0;
	this->cur_call.time = (uint32_t)time_point_cast<microseconds>(high_resolution_clock::now()).time_since_epoch().count();
	this->cur_call.tick = TimerGameTick::counter;
	this->cur_call.cb = resolver.callback;
	this->cur_call.feat = resolver.GetFeature();
	this->cur_call.item = resolver.GetDebugID();
}

/**
 * Capture the completion of a sprite group resolution.
 */
void NewGRFProfiler::EndResolve(const SpriteGroup *result)
{
	using namespace std::chrono;
	this->cur_call.time = (uint32_t)time_point_cast<microseconds>(high_resolution_clock::now()).time_since_epoch().count() - this->cur_call.time;

	if (result == nullptr) {
		this->cur_call.result = 0;
	} else if (result->type == SGT_CALLBACK) {
		this->cur_call.result = static_cast<const CallbackResultSpriteGroup *>(result)->result;
	} else if (result->type == SGT_RESULT) {
		this->cur_call.result = GetSpriteLocalID(static_cast<const ResultSpriteGroup *>(result)->sprite);
	} else {
		this->cur_call.result = result->nfo_line;
	}

	this->calls.push_back(this->cur_call);
}

/**
 * Capture a recursive sprite group resolution.
 */
void NewGRFProfiler::RecursiveResolve()
{
	this->cur_call.subs += 1;
}

void NewGRFProfiler::Start()
{
	this->Abort();
	this->active = true;
	this->start_tick = TimerGameTick::counter;
}

uint32_t NewGRFProfiler::Finish()
{
	if (!this->active) return 0;

	if (this->calls.empty()) {
		IConsolePrint(CC_DEBUG, "Finished profile of NewGRF [{:08X}], no events collected, not writing a file.", BSWAP32(this->grffile->grfid));

		this->Abort();
		return 0;
	}

	std::string filename = this->GetOutputFilename();
	IConsolePrint(CC_DEBUG, "Finished profile of NewGRF [{:08X}], writing {} events to '{}'.", BSWAP32(this->grffile->grfid), this->calls.size(), filename);

	FILE *f = FioFOpenFile(filename, "wt", Subdirectory::NO_DIRECTORY);
	FileCloser fcloser(f);

	uint32_t total_microseconds = 0;

	fmt::print(f, "Tick,Sprite,Feature,Item,CallbackID,Microseconds,Depth,Result\n");
	for (const Call &c : this->calls) {
		fmt::print(f, "{},{},{:#X},{},{:#X},{},{},{}\n", c.tick, c.root_sprite, c.feat, c.item, (uint)c.cb, c.time, c.subs, c.result);
		total_microseconds += c.time;
	}

	this->Abort();
	return total_microseconds;
}

void NewGRFProfiler::Abort()
{
	this->active = false;
	this->calls.clear();
}

/**
 * Get name of the file that will be written.
 * @return File name of profiling output file.
 */
std::string NewGRFProfiler::GetOutputFilename() const
{
	return fmt::format("{}grfprofile-{%Y%m%d-%H%M}-{:08X}.csv", FiosGetScreenshotDir(), fmt::localtime(time(nullptr)), BSWAP32(this->grffile->grfid));
}

/* static */ uint32_t NewGRFProfiler::FinishAll()
{
	NewGRFProfiler::AbortTimer();

	uint64_t max_ticks = 0;
	uint32_t total_microseconds = 0;
	for (NewGRFProfiler &pr : _newgrf_profilers) {
		if (pr.active) {
			total_microseconds += pr.Finish();
			max_ticks = std::max(max_ticks, TimerGameTick::counter - pr.start_tick);
		}
	}

	if (total_microseconds > 0 && max_ticks > 0) {
		IConsolePrint(CC_DEBUG, "Total NewGRF callback processing: {} microseconds over {} ticks.", total_microseconds, max_ticks);
	}

	return total_microseconds;
}

/**
 * Check whether profiling is active and should be finished.
 */
static TimeoutTimer<TimerGameTick> _profiling_finish_timeout(0, []()
{
	NewGRFProfiler::FinishAll();
});

/**
 * Start the timeout timer that will finish all profiling sessions.
 */
/* static */ void NewGRFProfiler::StartTimer(uint64_t ticks)
{
	_profiling_finish_timeout.Reset(ticks);
}

/**
 * Abort the timeout timer, so the timer callback is never called.
 */
/* static */ void NewGRFProfiler::AbortTimer()
{
	_profiling_finish_timeout.Abort();
}