From 2dfee2a32297148cc6b7b2020b5fe45cb19aebf5 Mon Sep 17 00:00:00 2001 From: maj00r Date: Tue, 19 May 2026 19:04:46 +0200 Subject: [PATCH] loading time fix --- application/application.cpp | 126 +++- scene/scenenode.cpp | 314 +++++--- simulation/simulationstateserializer.cpp | 14 + simulation/simulationstateserializer.h | 4 + utilities/Globals.cpp | 30 +- utilities/Globals.h | 6 +- utilities/Logs.cpp | 140 +++- utilities/parser.cpp | 923 ++++++++++++++++++++++- utilities/parser.h | 53 ++ utilities/utilities.cpp | 253 ++++++- utilities/utilities.h | 16 + 11 files changed, 1722 insertions(+), 157 deletions(-) diff --git a/application/application.cpp b/application/application.cpp index ba09bde9..314f12dc 100644 --- a/application/application.cpp +++ b/application/application.cpp @@ -1084,12 +1084,8 @@ void eu07_application::init_files() { #ifdef _WIN32 - DeleteFile("log.txt"); - DeleteFile("errors.txt"); CreateDirectory("logs", NULL); #elif __unix__ - unlink("log.txt"); - unlink("errors.txt"); mkdir("logs", 0755); #endif } @@ -1127,6 +1123,22 @@ int eu07_application::init_settings(int Argc, char *Argv[]) { std::string token{Argv[i]}; + auto parse_bool_argument = + [](std::string Value, bool &Output) + { + Value = ToLower(Value); + if ((Value == "on") || (Value == "yes") || (Value == "true") || (Value == "1")) + { + Output = true; + return true; + } + if ((Value == "off") || (Value == "no") || (Value == "false") || (Value == "0")) + { + Output = false; + return true; + } + return false; + }; if (token == "-s") { @@ -1142,10 +1154,114 @@ int eu07_application::init_settings(int Argc, char *Argv[]) Global.local_start_vehicle = ToLower(Argv[++i]); } } + else if (token == "--no-scenario-fileexists-cache") + { + Global.ScenarioFileExistsCache = false; + } + else if (token == "--no-scenario-parser-file-cache") + { + Global.ScenarioParserFileCache = false; + } + else if (token == "--no-scenario-parser-fast-geometry") + { + Global.ScenarioParserFastGeometry = false; + } + else if (token == "--no-scenario-parser-fast-skip") + { + Global.ScenarioParserFastSkip = false; + } + else if (token == "--scenario-fileexists-cache") + { + if ((i + 1 < Argc) && parse_bool_argument(Argv[++i], Global.ScenarioFileExistsCache)) + { + continue; + } + + std::cout << "invalid value for --scenario-fileexists-cache" << std::endl; + return -1; + } + else if (token == "--scenario-parser-file-cache") + { + if ((i + 1 < Argc) && parse_bool_argument(Argv[++i], Global.ScenarioParserFileCache)) + { + continue; + } + + std::cout << "invalid value for --scenario-parser-file-cache" << std::endl; + return -1; + } + else if (token == "--scenario-parser-fast-geometry") + { + if ((i + 1 < Argc) && parse_bool_argument(Argv[++i], Global.ScenarioParserFastGeometry)) + { + continue; + } + + std::cout << "invalid value for --scenario-parser-fast-geometry" << std::endl; + return -1; + } + else if (token == "--scenario-parser-fast-skip") + { + if ((i + 1 < Argc) && parse_bool_argument(Argv[++i], Global.ScenarioParserFastSkip)) + { + continue; + } + + std::cout << "invalid value for --scenario-parser-fast-skip" << std::endl; + return -1; + } + else if (token.starts_with("--scenario-fileexists-cache=")) + { + if (parse_bool_argument(token.substr(std::string("--scenario-fileexists-cache=").size()), Global.ScenarioFileExistsCache)) + { + continue; + } + + std::cout << "invalid value for --scenario-fileexists-cache" << std::endl; + return -1; + } + else if (token.starts_with("--scenario-parser-file-cache=")) + { + if (parse_bool_argument(token.substr(std::string("--scenario-parser-file-cache=").size()), Global.ScenarioParserFileCache)) + { + continue; + } + + std::cout << "invalid value for --scenario-parser-file-cache" << std::endl; + return -1; + } + else if (token.starts_with("--scenario-parser-fast-geometry=")) + { + if (parse_bool_argument(token.substr(std::string("--scenario-parser-fast-geometry=").size()), Global.ScenarioParserFastGeometry)) + { + continue; + } + + std::cout << "invalid value for --scenario-parser-fast-geometry" << std::endl; + return -1; + } + else if (token.starts_with("--scenario-parser-fast-skip=")) + { + if (parse_bool_argument(token.substr(std::string("--scenario-parser-fast-skip=").size()), Global.ScenarioParserFastSkip)) + { + continue; + } + + std::cout << "invalid value for --scenario-parser-fast-skip" << std::endl; + return -1; + } else { std::cout << "usage: " << std::string(Argv[0]) << " [-s sceneryfilepath]" - << " [-v vehiclename]" << std::endl; + << " [-v vehiclename]" + << " [--scenario-fileexists-cache on|off]" + << " [--no-scenario-fileexists-cache]" + << " [--scenario-parser-file-cache on|off]" + << " [--no-scenario-parser-file-cache]" + << " [--scenario-parser-fast-geometry on|off]" + << " [--no-scenario-parser-fast-geometry]" + << " [--scenario-parser-fast-skip on|off]" + << " [--no-scenario-parser-fast-skip]" << std::endl; return -1; } } diff --git a/scene/scenenode.cpp b/scene/scenenode.cpp index 784fb14f..35f1b1f7 100644 --- a/scene/scenenode.cpp +++ b/scene/scenenode.cpp @@ -13,9 +13,161 @@ http://mozilla.org/MPL/2.0/. #include "model/Model3d.h" #include "rendering/renderer.h" #include "utilities/parser.h" +#include "utilities/Globals.h" #include "utilities/Logs.h" #include "scene/sn_utils.h" +namespace +{ +constexpr char const *geometry_token_break = "\n\r\t ;"; + +enum class shape_import_subtype +{ + triangles, + triangle_strip, + triangle_fan +}; + +bool read_shape_vertex_fast(cParser &Input, world_vertex &vertex) +{ + return Input.readTokenDouble(vertex.position.x, false, geometry_token_break) + && Input.readTokenDouble(vertex.position.y, false, geometry_token_break) + && Input.readTokenDouble(vertex.position.z, false, geometry_token_break) + && Input.readTokenFloat(vertex.normal.x, false, geometry_token_break) + && Input.readTokenFloat(vertex.normal.y, false, geometry_token_break) + && Input.readTokenFloat(vertex.normal.z, false, geometry_token_break) + && Input.readTokenFloat(vertex.texture.s, false, geometry_token_break) + && Input.readTokenFloat(vertex.texture.t, false, geometry_token_break); +} + +void process_shape_imported_vertex(scene::shape_node::shapenode_data &data, + shape_import_subtype const nodetype, + world_vertex &vertex, + world_vertex &vertex1, + world_vertex &vertex2, + std::size_t &vertexcount, + bool const clamps, + bool const clampt, + std::string const &node_name) +{ + if (true == clamps) + { + vertex.texture.s = std::clamp(vertex.texture.s, 0.001f, 0.999f); + } + if (true == clampt) + { + vertex.texture.t = std::clamp(vertex.texture.t, 0.001f, 0.999f); + } + + switch (nodetype) + { + case shape_import_subtype::triangles: + { + if (vertexcount == 0) + { + vertex1 = vertex; + } + else if (vertexcount == 1) + { + vertex2 = vertex; + } + else if (vertexcount >= 2) + { + if (false == degenerate(vertex1.position, vertex2.position, vertex.position)) + { + data.vertices.emplace_back(vertex1); + data.vertices.emplace_back(vertex2); + data.vertices.emplace_back(vertex); + } + else + { + ErrorLog( + "Bad geometry: degenerate triangle encountered" + + (node_name != "" ? " in node \"" + node_name + "\"" : "") + + " (vertices: " + to_string(vertex1.position) + " + " + to_string(vertex2.position) + " + " + to_string(vertex.position) + ")"); + } + } + ++vertexcount; + if (vertexcount > 2) + { + vertexcount = 0; + } + break; + } + case shape_import_subtype::triangle_fan: + { + if (vertexcount == 0) + { + vertex1 = vertex; + } + else if (vertexcount == 1) + { + vertex2 = vertex; + } + else if (vertexcount >= 2) + { + if (false == degenerate(vertex1.position, vertex2.position, vertex.position)) + { + data.vertices.emplace_back(vertex1); + data.vertices.emplace_back(vertex2); + data.vertices.emplace_back(vertex); + vertex2 = vertex; + } + else + { + ErrorLog( + "Bad geometry: degenerate triangle encountered" + + (node_name != "" ? " in node \"" + node_name + "\"" : "") + + " (vertices: " + to_string(vertex1.position) + " + " + to_string(vertex2.position) + " + " + to_string(vertex.position) + ")"); + } + } + ++vertexcount; + break; + } + case shape_import_subtype::triangle_strip: + { + if (vertexcount == 0) + { + vertex1 = vertex; + } + else if (vertexcount == 1) + { + vertex2 = vertex; + } + else if (vertexcount >= 2) + { + if (false == degenerate(vertex1.position, vertex2.position, vertex.position)) + { + if (vertexcount % 2 == 0) + { + data.vertices.emplace_back(vertex1); + data.vertices.emplace_back(vertex2); + } + else + { + data.vertices.emplace_back(vertex2); + data.vertices.emplace_back(vertex1); + } + data.vertices.emplace_back(vertex); + + vertex1 = vertex2; + vertex2 = vertex; + } + else + { + ErrorLog( + "Bad geometry: degenerate triangle encountered" + + (node_name != "" ? " in node \"" + node_name + "\"" : "") + + " (vertices: " + to_string(vertex1.position) + " + " + to_string(vertex2.position) + " + " + to_string(vertex.position) + ")"); + } + } + ++vertexcount; + break; + } + } +} +} // namespace + // stores content of the struct in provided output stream void lighting_data::serialize( std::ostream &Output ) const { @@ -231,111 +383,35 @@ shape_node::import( cParser &Input, scene::node_data const &Nodedata ) { } // geometry - enum subtype { - triangles, - triangle_strip, - triangle_fan - }; - - subtype const nodetype = ( - Nodedata.type == "triangles" ? triangles : - Nodedata.type == "triangle_strip" ? triangle_strip : - triangle_fan ); + shape_import_subtype const nodetype = ( + Nodedata.type == "triangles" ? shape_import_subtype::triangles : + Nodedata.type == "triangle_strip" ? shape_import_subtype::triangle_strip : + shape_import_subtype::triangle_fan ); std::size_t vertexcount{ 0 }; world_vertex vertex, vertex1, vertex2; - do { - Input.getTokens( 8, false ); - Input - >> vertex.position.x - >> vertex.position.y - >> vertex.position.z - >> vertex.normal.x - >> vertex.normal.y - >> vertex.normal.z - >> vertex.texture.s - >> vertex.texture.t; - // clamp texture coordinates if texture wrapping is off - if( true == clamps ) { vertex.texture.s = std::clamp( vertex.texture.s, 0.001f, 0.999f ); } - if( true == clampt ) { vertex.texture.t = std::clamp( vertex.texture.t, 0.001f, 0.999f ); } - // convert all data to gl_triangles to allow data merge for matching nodes - switch( nodetype ) { - case triangles: { - if( vertexcount == 0 ) { vertex1 = vertex; } - else if( vertexcount == 1 ) { vertex2 = vertex; } - else if( vertexcount >= 2 ) { - if( false == degenerate( vertex1.position, vertex2.position, vertex.position ) ) { - m_data.vertices.emplace_back( vertex1 ); - m_data.vertices.emplace_back( vertex2 ); - m_data.vertices.emplace_back( vertex ); - } - else { - ErrorLog( - "Bad geometry: degenerate triangle encountered" - + ( m_name != "" ? " in node \"" + m_name + "\"" : "" ) - + " (vertices: " + to_string( vertex1.position ) + " + " + to_string( vertex2.position ) + " + " + to_string( vertex.position ) + ")" ); - } - } - ++vertexcount; - if( vertexcount > 2 ) { vertexcount = 0; } // start new triangle if needed + if (Global.ScenarioParserFastGeometry) + { + do + { + if (false == read_shape_vertex_fast(Input, vertex)) + { break; } - case triangle_fan: { - - if( vertexcount == 0 ) { vertex1 = vertex; } - else if( vertexcount == 1 ) { vertex2 = vertex; } - else if( vertexcount >= 2 ) { - if( false == degenerate( vertex1.position, vertex2.position, vertex.position ) ) { - m_data.vertices.emplace_back( vertex1 ); - m_data.vertices.emplace_back( vertex2 ); - m_data.vertices.emplace_back( vertex ); - vertex2 = vertex; - } - else { - ErrorLog( - "Bad geometry: degenerate triangle encountered" - + ( m_name != "" ? " in node \"" + m_name + "\"" : "" ) - + " (vertices: " + to_string( vertex1.position ) + " + " + to_string( vertex2.position ) + " + " + to_string( vertex.position ) + ")" ); - } - } - ++vertexcount; - break; - } - case triangle_strip: { - - if( vertexcount == 0 ) { vertex1 = vertex; } - else if( vertexcount == 1 ) { vertex2 = vertex; } - else if( vertexcount >= 2 ) { - if( false == degenerate( vertex1.position, vertex2.position, vertex.position ) ) { - // swap order every other triangle, to maintain consistent winding - if( vertexcount % 2 == 0 ) { - m_data.vertices.emplace_back( vertex1 ); - m_data.vertices.emplace_back( vertex2 ); - } - else { - m_data.vertices.emplace_back( vertex2 ); - m_data.vertices.emplace_back( vertex1 ); - } - m_data.vertices.emplace_back( vertex ); - - vertex1 = vertex2; - vertex2 = vertex; - } - else { - ErrorLog( - "Bad geometry: degenerate triangle encountered" - + ( m_name != "" ? " in node \"" + m_name + "\"" : "" ) - + " (vertices: " + to_string( vertex1.position ) + " + " + to_string( vertex2.position ) + " + " + to_string( vertex.position ) + ")" ); - } - } - ++vertexcount; - break; - } - default: { break; } - } - token = Input.getToken(); - - } while( token != "endtri" ); + process_shape_imported_vertex(m_data, nodetype, vertex, vertex1, vertex2, vertexcount, clamps, clampt, m_name); + Input.readNextToken(token, false, geometry_token_break); + } while (token != "endtri"); + } + else + { + do + { + Input.getTokens(8, false); + Input >> vertex.position.x >> vertex.position.y >> vertex.position.z >> vertex.normal.x >> vertex.normal.y >> vertex.normal.z >> vertex.texture.s >> vertex.texture.t; + process_shape_imported_vertex(m_data, nodetype, vertex, vertex1, vertex2, vertexcount, clamps, clampt, m_name); + token = Input.getToken(); + } while (token != "endtri"); + } return *this; } @@ -595,12 +671,9 @@ lines_node::import( cParser &Input, scene::node_data const &Nodedata ) { std::size_t vertexcount { 0 }; world_vertex vertex, vertex0, vertex1; std::string token = Input.getToken(); - do { - vertex.position.x = std::atof( token.c_str() ); - Input.getTokens( 2, false ); - Input - >> vertex.position.y - >> vertex.position.z; + + auto process_line_vertex = [&]() + { // convert all data to gl_lines to allow data merge for matching nodes switch( nodetype ) { case lines: { @@ -631,9 +704,34 @@ lines_node::import( cParser &Input, scene::node_data const &Nodedata ) { } default: { break; } } - token = Input.getToken(); + }; - } while( token != "endline" ); + if (Global.ScenarioParserFastGeometry) + { + do + { + char *end = nullptr; + vertex.position.x = std::strtod(token.c_str(), &end); + if (false == Input.readTokenDouble(vertex.position.y, false, geometry_token_break) + || false == Input.readTokenDouble(vertex.position.z, false, geometry_token_break)) + { + break; + } + process_line_vertex(); + Input.readNextToken(token, false, geometry_token_break); + } while (token != "endline"); + } + else + { + do + { + vertex.position.x = std::atof(token.c_str()); + Input.getTokens(2, false); + Input >> vertex.position.y >> vertex.position.z; + process_line_vertex(); + token = Input.getToken(); + } while (token != "endline"); + } // add closing line for the loop if( ( nodetype == line_loop ) && ( vertexcount > 2 ) ) { diff --git a/simulation/simulationstateserializer.cpp b/simulation/simulationstateserializer.cpp index 7277e338..3289ffa9 100644 --- a/simulation/simulationstateserializer.cpp +++ b/simulation/simulationstateserializer.cpp @@ -65,6 +65,11 @@ state_serializer::deserialize_begin( std::string const &Scenariofile ) { Global.file_binary_terrain_state = false; WriteLog("Default SBT absent"); } + + WriteLog( + std::string("Scenario parser: fast_geometry=") + (Global.ScenarioParserFastGeometry ? "on" : "off") + + ", fast_skip=" + (Global.ScenarioParserFastSkip ? "on" : "off") + + ", text_triangles=" + (state->scratchpad.binary.terrain ? "skipped_via_sbt" : "parsed")); scene::Groups.create(); if( false == state->input.ok() ) @@ -160,6 +165,9 @@ state_serializer::deserialize_continue(std::shared_ptr state Region->serialize( state->scenariofile ); } + state->parser_metrics_scope.end(); + state->parser_file_cache_scope.end(); + state->fileexists_cache_scope.end(); return false; } @@ -1128,6 +1136,12 @@ state_serializer::deserialize_sound( cParser &Input, scene::scratch_data &Scratc void state_serializer::skip_until( cParser &Input, std::string const &Token ) { + if (Global.ScenarioParserFastSkip) + { + Input.skipUntilKeyword(Token); + return; + } + std::string token { Input.getToken() }; while( ( false == token.empty() ) && ( token != Token ) ) { diff --git a/simulation/simulationstateserializer.h b/simulation/simulationstateserializer.h index dea1e20e..36abe8c4 100644 --- a/simulation/simulationstateserializer.h +++ b/simulation/simulationstateserializer.h @@ -10,12 +10,16 @@ http://mozilla.org/MPL/2.0/. #pragma once #include "utilities/parser.h" +#include "utilities/utilities.h" #include "scene/scene.h" namespace simulation { struct deserializer_state { std::string scenariofile; + FileExistsCacheScope fileexists_cache_scope; + ParserFileCacheScope parser_file_cache_scope; + ParserMetricsScope parser_metrics_scope; cParser input; scene::scratch_data scratchpad; using deserializefunctionbind = std::function; diff --git a/utilities/Globals.cpp b/utilities/Globals.cpp index 23cf9ab9..f0ca51fb 100644 --- a/utilities/Globals.cpp +++ b/utilities/Globals.cpp @@ -625,7 +625,31 @@ bool global_settings::ConfigParseSimulation(cParser& Parser, const std::string& if (token == "file.binary.terrain") { - ParseOne(Parser, file_binary_terrain, 1, false); + // ParseOne(Parser, file_binary_terrain, 1, false); + return true; + } + + if (token == "scenario.fileexists.cache") + { + ParseOne(Parser, ScenarioFileExistsCache, 1, false); + return true; + } + + if (token == "scenario.parser.filecache") + { + ParseOne(Parser, ScenarioParserFileCache, 1, false); + return true; + } + + if (token == "scenario.parser.fastgeometry") + { + ParseOne(Parser, ScenarioParserFastGeometry, 1, false); + return true; + } + + if (token == "scenario.parser.fastskip") + { + ParseOne(Parser, ScenarioParserFastSkip, 1, false); return true; } @@ -1578,6 +1602,10 @@ global_settings::export_as_text( std::ostream &Output ) const { export_as_text( Output, "latitude", fLatitudeDeg ); export_as_text( Output, "convertmodels", iConvertModels ); export_as_text( Output, "file.binary.terrain", file_binary_terrain ); + export_as_text( Output, "scenario.fileexists.cache", ScenarioFileExistsCache ); + export_as_text( Output, "scenario.parser.filecache", ScenarioParserFileCache ); + export_as_text( Output, "scenario.parser.fastgeometry", ScenarioParserFastGeometry ); + export_as_text( Output, "scenario.parser.fastskip", ScenarioParserFastSkip ); export_as_text( Output, "inactivepause", bInactivePause ); export_as_text( Output, "slowmotion", iSlowMotionMask ); export_as_text( Output, "hideconsole", bHideConsole ); diff --git a/utilities/Globals.h b/utilities/Globals.h index be79e42e..7e4706b9 100644 --- a/utilities/Globals.h +++ b/utilities/Globals.h @@ -80,8 +80,12 @@ struct global_settings { std::string local_start_vehicle{ "EU07-424" }; int iConvertModels{ 0 }; // tworzenie plików binarnych int iConvertIndexRange{ 1000 }; // range of duplicate vertex scan - bool file_binary_terrain{ true }; // enable binary terrain (de)serialization + bool file_binary_terrain{ false }; // enable binary terrain (de)serialization bool file_binary_terrain_state{true}; + bool ScenarioFileExistsCache{ true }; // cache FileExists calls during scenario loading + bool ScenarioParserFileCache{ false }; // cache parser input file bytes during scenario loading + bool ScenarioParserFastGeometry{ false }; // fast float reads for triangles/lines import + bool ScenarioParserFastSkip{ false }; // fast skip_until for endtri/endline blocks // logs bool priorityLoadText3D{false}; // ladowanie T3D priorytetowo int iWriteLogEnabled{ 3 }; // maska bitowa: 1-zapis do pliku, 2-okienko, 4-nazwy torów diff --git a/utilities/Logs.cpp b/utilities/Logs.cpp index 48d74317..ca4d161e 100644 --- a/utilities/Logs.cpp +++ b/utilities/Logs.cpp @@ -25,50 +25,116 @@ char endstring[10] = "\n"; std::deque log_scrollback; -std::string filename_date() { - ::SYSTEMTIME st; +namespace +{ +std::string sanitize_filename_component(std::string value) +{ + for (auto &character : value) + { + switch (character) + { + case '\\': + case '/': + case ':': + case '*': + case '?': + case '\"': + case '<': + case '>': + case '|': + character = '_'; + break; + default: + break; + } + } + return value; +} + +std::string filename_session_timestamp() +{ + ::SYSTEMTIME st {}; #ifdef __unix__ - timespec ts; - clock_gettime(CLOCK_REALTIME, &ts); - tm *tms = localtime(&ts.tv_sec); - st.wYear = tms->tm_year; - st.wMonth = tms->tm_mon; - st.wDayOfWeek = tms->tm_wday; - st.wDay = tms->tm_mday; - st.wHour = tms->tm_hour; - st.wMinute = tms->tm_min; - st.wSecond = tms->tm_sec; - st.wMilliseconds = ts.tv_nsec / 1000000; + timespec ts {}; + clock_gettime(CLOCK_REALTIME, &ts); + tm *tms = localtime(&ts.tv_sec); + if (tms != nullptr) + { + st.wYear = static_cast(tms->tm_year + 1900); + st.wMonth = static_cast(tms->tm_mon + 1); + st.wDay = static_cast(tms->tm_mday); + st.wHour = static_cast(tms->tm_hour); + st.wMinute = static_cast(tms->tm_min); + st.wSecond = static_cast(tms->tm_sec); + st.wMilliseconds = static_cast(ts.tv_nsec / 1000000); + } #elif _WIN32 - ::GetLocalTime( &st ); + ::GetLocalTime(&st); #endif - std::snprintf( - logbuffer, - sizeof(logbuffer), - "%d%02d%02d_%02d%02d%03d", - st.wYear, - st.wMonth, - st.wDay, - st.wHour, - st.wMinute, - st.wMilliseconds); + std::snprintf( + logbuffer, + sizeof(logbuffer), + "%04u%02u%02u_%02u%02u%02u_%03u", + static_cast(st.wYear), + static_cast(st.wMonth), + static_cast(st.wDay), + static_cast(st.wHour), + static_cast(st.wMinute), + static_cast(st.wSecond), + static_cast(st.wMilliseconds)); - return std::string( logbuffer ); + return std::string(logbuffer); } -std::string filename_scenery() { - - auto extension = Global.SceneryFile.rfind( '.' ); - if( extension != std::string::npos ) { - return Global.SceneryFile.substr( 0, extension ); - } - else { - return Global.SceneryFile; - } +std::string const &log_session_id() +{ + static std::string const session_id = []() + { + std::string session = filename_session_timestamp(); +#ifdef _WIN32 + char pid_suffix[32]; + std::snprintf(pid_suffix, sizeof(pid_suffix), "_%lu", static_cast(::GetCurrentProcessId())); + session += pid_suffix; +#endif + return session; + }(); + return session_id; } +std::string filename_scenery() +{ + auto extension = Global.SceneryFile.rfind('.'); + if (extension != std::string::npos) + { + return sanitize_filename_component(Global.SceneryFile.substr(0, extension)); + } + + return sanitize_filename_component(Global.SceneryFile); +} + +std::string log_output_filename() +{ + if (Global.MultipleLogs && false == Global.SceneryFile.empty()) + { + return "logs/log (" + filename_scenery() + ") " + log_session_id() + ".txt"; + } + + return "logs/log_" + log_session_id() + ".txt"; +} + +std::string log_errors_filename() +{ + if (Global.MultipleLogs && false == Global.SceneryFile.empty()) + { + return "logs/errors (" + filename_scenery() + ") " + log_session_id() + ".txt"; + } + + return "logs/errors_" + log_session_id() + ".txt"; +} +} // namespace + // log service stacks std::deque < std::pair> InfoStack; std::deque ErrorStack; @@ -108,8 +174,7 @@ void LogService() { if (!output.is_open()) { - std::string filename = (Global.MultipleLogs ? "logs/log (" + filename_scenery() + ") " + filename_date() + ".txt" : "log.txt"); - output.open(filename, std::ios::trunc); + output.open(log_output_filename(), std::ios::trunc); } output << msg << "\n"; output.flush(); @@ -143,8 +208,7 @@ void LogService() if (!errors.is_open()) { - std::string filename = (Global.MultipleLogs ? "logs/errors (" + filename_scenery() + ") " + filename_date() + ".txt" : "errors.txt"); - errors.open(filename, std::ios::trunc); + errors.open(log_errors_filename(), std::ios::trunc); errors << "EU07.EXE " + Global.asVersion << "\n"; } diff --git a/utilities/parser.cpp b/utilities/parser.cpp index 68656c5d..4ca67ceb 100644 --- a/utilities/parser.cpp +++ b/utilities/parser.cpp @@ -9,6 +9,7 @@ http://mozilla.org/MPL/2.0/. #include "stdafx.h" #include "utilities/parser.h" +#include "utilities/Globals.h" #include "utilities/Logs.h" #include "scene/scenenodegroups.h" @@ -46,12 +47,666 @@ inline bool startsWithBOM(const std::string &s) && static_cast(s[1]) == 0xBB && static_cast(s[2]) == 0xBF; } + +std::atomic g_parser_file_cache_depth { 0 }; +bool g_parser_file_cache_enabled { false }; +std::mutex g_parser_file_cache_mutex; +std::unordered_map> g_parser_file_cache; + +struct parser_file_cache_metrics +{ + std::uint64_t open_attempts { 0 }; + std::uint64_t disk_reads { 0 }; + std::uint64_t cache_hits { 0 }; + std::uint64_t cache_misses { 0 }; + std::uint64_t failed_opens { 0 }; + std::uint64_t bytes_read { 0 }; + std::uint64_t untracked_path_calls { 0 }; + std::uint64_t zero_copy_opens { 0 }; + std::chrono::steady_clock::duration open_read_time {}; + std::unordered_map path_counts; + + void reset() + { + *this = {}; + } +}; + +parser_file_cache_metrics g_parser_file_cache_metrics; + +class parser_memory_streambuf final : public std::streambuf +{ +public: + explicit parser_memory_streambuf(std::shared_ptr data) + : data_(std::move(data)) + { + } + +protected: + int underflow() override + { + if (!data_ || pos_ >= data_->size()) + { + return traits_type::eof(); + } + return static_cast((*data_)[pos_]); + } + + int uflow() override + { + if (!data_ || pos_ >= data_->size()) + { + return traits_type::eof(); + } + return static_cast((*data_)[pos_++]); + } + + std::streampos seekoff(std::streamoff off, std::ios_base::seekdir dir, std::ios_base::openmode which) override + { + if (!data_ || ((which & std::ios_base::in) == 0)) + { + return std::streampos(std::streamoff(-1)); + } + + auto const size = static_cast(data_->size()); + std::streamoff newpos = 0; + switch (dir) + { + case std::ios_base::beg: + newpos = off; + break; + case std::ios_base::cur: + newpos = static_cast(pos_) + off; + break; + case std::ios_base::end: + newpos = size + off; + break; + default: + return std::streampos(std::streamoff(-1)); + } + + if (newpos < 0) + { + newpos = 0; + } + if (newpos > size) + { + newpos = size; + } + pos_ = static_cast(newpos); + return std::streampos(newpos); + } + + std::streampos seekpos(std::streampos pos, std::ios_base::openmode which) override + { + return seekoff(std::streamoff(pos), std::ios_base::beg, which); + } + +private: + std::shared_ptr data_; + std::size_t pos_ { 0 }; +}; + +class parser_memory_istream final : public std::istream +{ +public: + explicit parser_memory_istream(std::shared_ptr data) + : std::istream(nullptr) + , buffer_(std::move(data)) + { + rdbuf(&buffer_); + } + +private: + parser_memory_streambuf buffer_; +}; + +std::shared_ptr ParserFileCacheMakeMemoryStream(std::shared_ptr const &Content) +{ + return std::make_shared(Content); +} + +std::string ParserFileCacheKey(std::string const &Filename) +{ + if (Filename.empty()) + { + return Filename; + } + + try + { + auto path = std::filesystem::path(Filename); + if (path.is_relative()) + { + path = std::filesystem::absolute(path); + } + + auto key = path.lexically_normal().generic_string(); +#ifdef _WIN32 + for (auto &character : key) + { + auto const value = static_cast(character); + if (value < 128) + { + character = static_cast(std::tolower(value)); + } + } +#endif + return key; + } + catch (std::filesystem::filesystem_error const &) + { + auto key = Filename; + std::replace(key.begin(), key.end(), '\\', '/'); + return key; + } +} + +double ParserFileCacheDurationMilliseconds(std::chrono::steady_clock::duration const Duration) +{ + return std::chrono::duration(Duration).count(); +} + +std::string ParserFileCacheFormatMilliseconds(std::chrono::steady_clock::duration const Duration) +{ + std::ostringstream output; + output << std::fixed << std::setprecision(3) << ParserFileCacheDurationMilliseconds(Duration); + return output.str(); +} + +void ParserFileCacheTrackPath(std::string const &Key) +{ + if (auto lookup = g_parser_file_cache_metrics.path_counts.find(Key); lookup != g_parser_file_cache_metrics.path_counts.end()) + { + ++lookup->second; + } + else if (g_parser_file_cache_metrics.path_counts.size() < 4096) + { + g_parser_file_cache_metrics.path_counts.emplace(Key, 1); + } + else + { + ++g_parser_file_cache_metrics.untracked_path_calls; + } +} + +std::vector ParserFileCacheReport() +{ + std::vector report; + report.emplace_back( + std::string("Parser file scope: mode=") + (g_parser_file_cache_enabled ? "cached" : "direct") + + ", opens=" + std::to_string(g_parser_file_cache_metrics.open_attempts) + + ", disk_reads=" + std::to_string(g_parser_file_cache_metrics.disk_reads) + + ", hits=" + std::to_string(g_parser_file_cache_metrics.cache_hits) + + ", misses=" + std::to_string(g_parser_file_cache_metrics.cache_misses) + + ", failed=" + std::to_string(g_parser_file_cache_metrics.failed_opens) + + ", bytes_read=" + std::to_string(g_parser_file_cache_metrics.bytes_read) + + ", open_read_ms=" + ParserFileCacheFormatMilliseconds(g_parser_file_cache_metrics.open_read_time) + + ", zero_copy_opens=" + std::to_string(g_parser_file_cache_metrics.zero_copy_opens) + + ", untracked_paths=" + std::to_string(g_parser_file_cache_metrics.untracked_path_calls) + + ", cached_files=" + std::to_string(g_parser_file_cache.size())); + + std::vector> top_paths; + top_paths.reserve(g_parser_file_cache_metrics.path_counts.size()); + for (auto const &entry : g_parser_file_cache_metrics.path_counts) + { + if (entry.second > 1) + { + top_paths.emplace_back(entry); + } + } + + constexpr std::size_t top_path_limit = 5; + auto const top_count = std::min(top_path_limit, top_paths.size()); + std::partial_sort( + top_paths.begin(), + top_paths.begin() + top_count, + top_paths.end(), + [](auto const &Left, auto const &Right) + { + if (Left.second != Right.second) + { + return Left.second > Right.second; + } + return Left.first < Right.first; + }); + + for (std::size_t index = 0; index < top_count; ++index) + { + report.emplace_back(" " + std::to_string(top_paths[index].second) + "x " + top_paths[index].first); + } + + return report; +} + +void ParserFileCacheLogReport(std::vector const &Report) +{ + for (auto const &line : Report) + { + WriteLog(line); + } +} + +std::shared_ptr ParserFileCacheOpenDirect(std::string const &Path, std::string const &Key) +{ + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.open_attempts; + ParserFileCacheTrackPath(Key); + } + + auto const timestart = std::chrono::steady_clock::now(); + auto stream = std::make_shared(Path, std::ios_base::binary); + if (stream->fail()) + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.failed_opens; + g_parser_file_cache_metrics.open_read_time += std::chrono::steady_clock::now() - timestart; + return stream; + } + + std::error_code error; + auto const size = std::filesystem::file_size(Path, error); + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.disk_reads; + if (!error) + { + g_parser_file_cache_metrics.bytes_read += size; + } + g_parser_file_cache_metrics.open_read_time += std::chrono::steady_clock::now() - timestart; + } + + return stream; +} + +std::shared_ptr ParserFileCacheOpenCached(std::string const &Path, std::string const &Key) +{ + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.open_attempts; + ParserFileCacheTrackPath(Key); + if (auto lookup = g_parser_file_cache.find(Key); lookup != g_parser_file_cache.end()) + { + ++g_parser_file_cache_metrics.cache_hits; + ++g_parser_file_cache_metrics.zero_copy_opens; + return ParserFileCacheMakeMemoryStream(lookup->second); + } + ++g_parser_file_cache_metrics.cache_misses; + } + + auto const timestart = std::chrono::steady_clock::now(); + auto file = std::ifstream(Path, std::ios_base::binary); + if (file.fail()) + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.failed_opens; + g_parser_file_cache_metrics.open_read_time += std::chrono::steady_clock::now() - timestart; + return std::make_shared(std::move(file)); + } + + file.seekg(0, std::ios_base::end); + auto const size = file.tellg(); + file.seekg(0, std::ios_base::beg); + if (size < 0) + { + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.failed_opens; + g_parser_file_cache_metrics.open_read_time += std::chrono::steady_clock::now() - timestart; + } + WriteLog("Parser file cache: falling back to direct read for \"" + Path + "\""); + return std::make_shared(Path, std::ios_base::binary); + } + + auto content = std::make_shared(); + if (size > 0) + { + content->resize(static_cast(size)); + file.read(content->data(), static_cast(size)); + } + if (file.bad() || ((size > 0) && (file.gcount() != static_cast(size)))) + { + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.failed_opens; + g_parser_file_cache_metrics.open_read_time += std::chrono::steady_clock::now() - timestart; + } + WriteLog("Parser file cache: falling back to direct read for \"" + Path + "\""); + return std::make_shared(Path, std::ios_base::binary); + } + + { + std::lock_guard lock(g_parser_file_cache_mutex); + ++g_parser_file_cache_metrics.disk_reads; + g_parser_file_cache_metrics.bytes_read += static_cast(content->size()); + g_parser_file_cache_metrics.open_read_time += std::chrono::steady_clock::now() - timestart; + g_parser_file_cache.emplace(Key, content); + } + + return ParserFileCacheMakeMemoryStream(content); +} + +std::shared_ptr ParserFileCacheOpen(std::string const &Path) +{ + if (g_parser_file_cache_depth.load(std::memory_order_acquire) == 0) + { + return std::make_shared(Path, std::ios_base::binary); + } + + bool cache_enabled = false; + std::string key; + { + std::lock_guard lock(g_parser_file_cache_mutex); + if (g_parser_file_cache_depth.load(std::memory_order_relaxed) == 0) + { + return std::make_shared(Path, std::ios_base::binary); + } + cache_enabled = g_parser_file_cache_enabled; + key = cache_enabled ? ParserFileCacheKey(Path) : Path; + } + + if (cache_enabled) + { + return ParserFileCacheOpenCached(Path, key); + } + + return ParserFileCacheOpenDirect(Path, key); +} + +std::atomic g_parser_metrics_depth { 0 }; + +struct parser_cpu_metrics +{ + std::atomic read_token_calls { 0 }; + std::atomic tokens_read { 0 }; + std::atomic get_tokens_calls { 0 }; + std::atomic includes_opened { 0 }; + std::atomic parsers_file_buffer { 0 }; + std::atomic parsers_text_buffer { 0 }; + std::atomic tokenize_ns { 0 }; + std::atomic read_token_ns { 0 }; + std::atomic convert_ns { 0 }; + std::atomic get_tokens_ns { 0 }; + std::atomic include_ns { 0 }; + std::atomic fp_parse_calls { 0 }; + std::atomic skip_until_calls { 0 }; + std::atomic fast_skip_tokens { 0 }; + std::atomic skip_until_ns { 0 }; + + void reset() + { + read_token_calls.store(0, std::memory_order_relaxed); + tokens_read.store(0, std::memory_order_relaxed); + get_tokens_calls.store(0, std::memory_order_relaxed); + includes_opened.store(0, std::memory_order_relaxed); + parsers_file_buffer.store(0, std::memory_order_relaxed); + parsers_text_buffer.store(0, std::memory_order_relaxed); + tokenize_ns.store(0, std::memory_order_relaxed); + read_token_ns.store(0, std::memory_order_relaxed); + convert_ns.store(0, std::memory_order_relaxed); + get_tokens_ns.store(0, std::memory_order_relaxed); + include_ns.store(0, std::memory_order_relaxed); + fp_parse_calls.store(0, std::memory_order_relaxed); + skip_until_calls.store(0, std::memory_order_relaxed); + fast_skip_tokens.store(0, std::memory_order_relaxed); + skip_until_ns.store(0, std::memory_order_relaxed); + } +}; + +namespace +{ +bool parse_token_as_float(std::string const &Token, float &Value) +{ + if (Token.empty()) + { + return false; + } + + char *end = nullptr; + Value = std::strtof(Token.c_str(), &end); + return end != Token.c_str(); +} + +bool parse_token_as_double(std::string const &Token, double &Value) +{ + if (Token.empty()) + { + return false; + } + + char *end = nullptr; + Value = std::strtod(Token.c_str(), &end); + return end != Token.c_str(); +} } // namespace +parser_cpu_metrics g_parser_cpu_metrics; +std::mutex g_parser_metrics_mutex; + +bool ParserMetricsActive() +{ + return g_parser_metrics_depth.load(std::memory_order_acquire) > 0; +} + +void ParserMetricsAddNs(std::atomic &Counter, std::chrono::steady_clock::duration const Duration) +{ + Counter.fetch_add( + static_cast(std::chrono::duration_cast(Duration).count()), + std::memory_order_relaxed); +} + +class ParserMetricsReadTokenTimer +{ +public: + explicit ParserMetricsReadTokenTimer(bool const Enabled) + : m_enabled(Enabled) + { + if (m_enabled) + { + g_parser_cpu_metrics.read_token_calls.fetch_add(1, std::memory_order_relaxed); + m_start = std::chrono::steady_clock::now(); + } + } + + ~ParserMetricsReadTokenTimer() + { + if (m_enabled) + { + ParserMetricsAddNs(g_parser_cpu_metrics.read_token_ns, std::chrono::steady_clock::now() - m_start); + } + } + +private: + bool const m_enabled; + std::chrono::steady_clock::time_point m_start {}; +}; + +class ParserMetricsTokenizeTimer +{ +public: + explicit ParserMetricsTokenizeTimer(bool const Enabled) + : m_enabled(Enabled) + { + if (m_enabled) + { + m_start = std::chrono::steady_clock::now(); + } + } + + ~ParserMetricsTokenizeTimer() + { + if (m_enabled) + { + ParserMetricsAddNs(g_parser_cpu_metrics.tokenize_ns, std::chrono::steady_clock::now() - m_start); + } + } + +private: + bool const m_enabled; + std::chrono::steady_clock::time_point m_start {}; +}; + +class ParserMetricsGetTokensTimer +{ +public: + explicit ParserMetricsGetTokensTimer(bool const Enabled) + : m_enabled(Enabled) + { + if (m_enabled) + { + g_parser_cpu_metrics.get_tokens_calls.fetch_add(1, std::memory_order_relaxed); + m_start = std::chrono::steady_clock::now(); + } + } + + ~ParserMetricsGetTokensTimer() + { + if (m_enabled) + { + ParserMetricsAddNs(g_parser_cpu_metrics.get_tokens_ns, std::chrono::steady_clock::now() - m_start); + } + } + +private: + bool const m_enabled; + std::chrono::steady_clock::time_point m_start {}; +}; + +class ParserMetricsIncludeTimer +{ +public: + explicit ParserMetricsIncludeTimer(bool const Enabled) + : m_enabled(Enabled) + { + if (m_enabled) + { + m_start = std::chrono::steady_clock::now(); + } + } + + ~ParserMetricsIncludeTimer() + { + if (m_enabled) + { + ParserMetricsAddNs(g_parser_cpu_metrics.include_ns, std::chrono::steady_clock::now() - m_start); + } + } + +private: + bool const m_enabled; + std::chrono::steady_clock::time_point m_start {}; +}; + +double ParserMetricsNanosecondsToMilliseconds(std::uint64_t const Nanoseconds) +{ + return static_cast(Nanoseconds) / 1'000'000.0; +} + +std::string ParserMetricsFormatMilliseconds(std::uint64_t const Nanoseconds) +{ + std::ostringstream output; + output << std::fixed << std::setprecision(3) << ParserMetricsNanosecondsToMilliseconds(Nanoseconds); + return output.str(); +} + +std::vector ParserMetricsReport() +{ + auto const read_token_calls = g_parser_cpu_metrics.read_token_calls.load(std::memory_order_relaxed); + auto const tokens_read = g_parser_cpu_metrics.tokens_read.load(std::memory_order_relaxed); + auto const get_tokens_calls = g_parser_cpu_metrics.get_tokens_calls.load(std::memory_order_relaxed); + auto const includes_opened = g_parser_cpu_metrics.includes_opened.load(std::memory_order_relaxed); + auto const parsers_file_buffer = g_parser_cpu_metrics.parsers_file_buffer.load(std::memory_order_relaxed); + auto const parsers_text_buffer = g_parser_cpu_metrics.parsers_text_buffer.load(std::memory_order_relaxed); + auto const tokenize_ns = g_parser_cpu_metrics.tokenize_ns.load(std::memory_order_relaxed); + auto const read_token_ns = g_parser_cpu_metrics.read_token_ns.load(std::memory_order_relaxed); + auto const convert_ns = g_parser_cpu_metrics.convert_ns.load(std::memory_order_relaxed); + auto const get_tokens_ns = g_parser_cpu_metrics.get_tokens_ns.load(std::memory_order_relaxed); + auto const include_ns = g_parser_cpu_metrics.include_ns.load(std::memory_order_relaxed); + auto const fp_parse_calls = g_parser_cpu_metrics.fp_parse_calls.load(std::memory_order_relaxed); + auto const skip_until_calls = g_parser_cpu_metrics.skip_until_calls.load(std::memory_order_relaxed); + auto const fast_skip_tokens = g_parser_cpu_metrics.fast_skip_tokens.load(std::memory_order_relaxed); + auto const skip_until_ns = g_parser_cpu_metrics.skip_until_ns.load(std::memory_order_relaxed); + + auto const cpu_total_ns = tokenize_ns + convert_ns + include_ns; + std::string tokens_per_sec = "n/a"; + if (cpu_total_ns > 0 && tokens_read > 0) + { + auto const rate = static_cast(tokens_read) / (static_cast(cpu_total_ns) / 1'000'000'000.0); + tokens_per_sec = to_string(rate, 0); + } + + std::vector report; + report.emplace_back( + std::string("Parser CPU scope: read_token=") + std::to_string(read_token_calls) + + ", tokens=" + std::to_string(tokens_read) + + ", get_tokens=" + std::to_string(get_tokens_calls) + + ", includes=" + std::to_string(includes_opened) + + ", parsers_file=" + std::to_string(parsers_file_buffer) + + ", parsers_text=" + std::to_string(parsers_text_buffer) + + ", tokenize_ms=" + ParserMetricsFormatMilliseconds(tokenize_ns) + + ", read_token_ms=" + ParserMetricsFormatMilliseconds(read_token_ns) + + ", convert_ms=" + ParserMetricsFormatMilliseconds(convert_ns) + + ", get_tokens_ms=" + ParserMetricsFormatMilliseconds(get_tokens_ns) + + ", include_ms=" + ParserMetricsFormatMilliseconds(include_ns) + + ", fp_parse=" + std::to_string(fp_parse_calls) + + ", skip_until=" + std::to_string(skip_until_calls) + + ", fast_skip_tokens=" + std::to_string(fast_skip_tokens) + + ", skip_until_ms=" + ParserMetricsFormatMilliseconds(skip_until_ns) + + ", tokens_per_sec=" + tokens_per_sec); + return report; +} + +void ParserMetricsLogReport(std::vector const &Report) +{ + for (auto const &line : Report) + { + WriteLog(line); + } +} +} // namespace + +namespace parser_metrics +{ +bool active() +{ + return ParserMetricsActive(); +} + +convert_timer::convert_timer() +{ + enabled = active(); + if (enabled) + { + start = std::chrono::steady_clock::now(); + } +} + +convert_timer::~convert_timer() +{ + if (enabled) + { + ParserMetricsAddNs(g_parser_cpu_metrics.convert_ns, std::chrono::steady_clock::now() - start); + } +} +} // namespace parser_metrics + // constructors cParser::cParser(std::string const &Stream, buffertype const Type, std::string Path, bool const Loadtraction, std::vector Parameters, bool allowRandom) : allowRandomIncludes(allowRandom), LoadTraction(Loadtraction), mPath(Path) { + if (ParserMetricsActive()) + { + if (Type == buffertype::buffer_FILE) + { + g_parser_cpu_metrics.parsers_file_buffer.fetch_add(1, std::memory_order_relaxed); + } + else + { + g_parser_cpu_metrics.parsers_text_buffer.fetch_add(1, std::memory_order_relaxed); + } + } + // store to calculate sub-sequent includes from relative path if (Type == buffertype::buffer_FILE) { @@ -63,7 +718,7 @@ cParser::cParser(std::string const &Stream, buffertype const Type, std::string P case buffer_FILE: { Path.append(Stream); - mStream = std::make_shared(Path, std::ios_base::binary); + mStream = ParserFileCacheOpen(Path); // content of *.inc files is potentially grouped together if ((Stream.size() >= 4) && (ToLower(Stream.substr(Stream.size() - 4)) == ".inc")) { @@ -114,6 +769,94 @@ cParser::~cParser() } } +ParserFileCacheScope::ParserFileCacheScope() +{ + std::lock_guard lock(g_parser_file_cache_mutex); + if (g_parser_file_cache_depth.load(std::memory_order_relaxed) == 0) + { + g_parser_file_cache.clear(); + g_parser_file_cache_enabled = Global.ScenarioParserFileCache; + g_parser_file_cache_metrics.reset(); + } + g_parser_file_cache_depth.fetch_add(1, std::memory_order_release); +} + +ParserFileCacheScope::~ParserFileCacheScope() +{ + end(); +} + +void ParserFileCacheScope::end() +{ + if (false == m_active) + { + return; + } + + std::vector report; + { + std::lock_guard lock(g_parser_file_cache_mutex); + auto const depth = g_parser_file_cache_depth.load(std::memory_order_relaxed); + if (depth <= 1) + { + report = ParserFileCacheReport(); + g_parser_file_cache_depth.store(0, std::memory_order_release); + g_parser_file_cache.clear(); + g_parser_file_cache_enabled = false; + g_parser_file_cache_metrics.reset(); + } + else + { + g_parser_file_cache_depth.store(depth - 1, std::memory_order_release); + } + m_active = false; + } + + ParserFileCacheLogReport(report); +} + +ParserMetricsScope::ParserMetricsScope() +{ + std::lock_guard lock(g_parser_metrics_mutex); + if (g_parser_metrics_depth.load(std::memory_order_relaxed) == 0) + { + g_parser_cpu_metrics.reset(); + } + g_parser_metrics_depth.fetch_add(1, std::memory_order_release); +} + +ParserMetricsScope::~ParserMetricsScope() +{ + end(); +} + +void ParserMetricsScope::end() +{ + if (false == m_active) + { + return; + } + + std::vector report; + { + std::lock_guard lock(g_parser_metrics_mutex); + auto const depth = g_parser_metrics_depth.load(std::memory_order_relaxed); + if (depth <= 1) + { + report = ParserMetricsReport(); + g_parser_metrics_depth.store(0, std::memory_order_release); + g_parser_cpu_metrics.reset(); + } + else + { + g_parser_metrics_depth.store(depth - 1, std::memory_order_release); + } + m_active = false; + } + + ParserMetricsLogReport(report); +} + template <> glm::vec3 cParser::getToken(bool const ToLower, char const *Break) { // NOTE: this specialization ignores default arguments @@ -131,6 +874,7 @@ template <> cParser &cParser::operator>>(std::string &Right) return *this; } + parser_metrics::convert_timer timer; Right = this->tokens.front(); this->tokens.pop_front(); @@ -145,6 +889,7 @@ template <> cParser &cParser::operator>>(bool &Right) return *this; } + parser_metrics::convert_timer timer; Right = ((this->tokens.front() == "true") || (this->tokens.front() == "yes") || (this->tokens.front() == "1")); this->tokens.pop_front(); @@ -173,6 +918,9 @@ cParser &cParser::autoclear(bool const Autoclear) bool cParser::getTokens(unsigned int Count, bool ToLower, const char *Break) { + auto const metrics_active = ParserMetricsActive(); + ParserMetricsGetTokensTimer const get_tokens_timer(metrics_active); + if (true == m_autoclear) { // legacy parser behaviour @@ -218,8 +966,48 @@ bool cParser::getTokens(unsigned int Count, bool ToLower, const char *Break) return true; } +bool cParser::readTokenFloat(float &Value, bool ToLower, const char *Break) +{ + std::string token; + readToken(token, ToLower, Break); + if (false == parse_token_as_float(token, Value)) + { + return false; + } + + if (ParserMetricsActive()) + { + g_parser_cpu_metrics.fp_parse_calls.fetch_add(1, std::memory_order_relaxed); + } + return true; +} + +bool cParser::readTokenDouble(double &Value, bool ToLower, const char *Break) +{ + std::string token; + readToken(token, ToLower, Break); + if (false == parse_token_as_double(token, Value)) + { + return false; + } + + if (ParserMetricsActive()) + { + g_parser_cpu_metrics.fp_parse_calls.fetch_add(1, std::memory_order_relaxed); + } + return true; +} + +void cParser::readNextToken(std::string &Token, bool ToLower, const char *Break) +{ + readToken(Token, ToLower, Break); +} + std::string cParser::readTokenFromStream(bool ToLower, const char *Break) { + auto const metrics_active = ParserMetricsActive(); + ParserMetricsTokenizeTimer const tokenize_timer(metrics_active); + std::string token; token.reserve(64); @@ -257,6 +1045,123 @@ std::string cParser::readTokenFromStream(bool ToLower, const char *Break) return token; } +std::string cParser::readTokenFromStreamFast(bool ToLower, const char *Break) +{ + std::string token; + token.reserve(32); + + const auto breakTable = makeBreakTable(Break); + char c = 0; + + while (token.empty() && mStream->peek() != EOF) + { + while (mStream->peek() != EOF) + { + c = static_cast(mStream->get()); + if (c == '\n') + { + ++mLine; + } + + const unsigned char uc = static_cast(c); + if (breakTable[uc]) + { + if (!token.empty()) + { + break; + } + continue; + } + + if (ToLower) + { + c = toLowerChar(c); + } + token.push_back(c); + + if (token.find('\"') != std::string::npos && findQuotes(token)) + { + continue; + } + if (token.find('/') != std::string::npos && skipComments && trimComments(token)) + { + break; + } + } + } + + return token; +} + +void cParser::readTokenForSkip(std::string &out, bool ToLower, const char *Break) +{ + if (mIncludeParser) + { + mIncludeParser->readTokenForSkip(out, ToLower, Break); + if (out.empty()) + { + mIncludeParser = nullptr; + readTokenForSkip(out, ToLower, Break); + } + return; + } + + out = readTokenFromStreamFast(ToLower, Break); + + stripFirstTokenBOM(out, ToLower, Break); + + if (out.find('(') != std::string::npos) + { + substituteParameters(out, ToLower); + } + + if (handleIncludeIfPresent(out, ToLower, Break)) + { + if (ParserMetricsActive()) + { + g_parser_cpu_metrics.fast_skip_tokens.fetch_add(1, std::memory_order_relaxed); + } + return; + } + + if (ParserMetricsActive() && false == out.empty()) + { + g_parser_cpu_metrics.fast_skip_tokens.fetch_add(1, std::memory_order_relaxed); + } +} + +void cParser::skipUntilKeyword(std::string const &Keyword, bool ToLower, const char *Break) +{ + auto const metrics_active = ParserMetricsActive(); + auto const timestart = metrics_active ? std::chrono::steady_clock::now() : std::chrono::steady_clock::time_point {}; + + if (metrics_active) + { + g_parser_cpu_metrics.skip_until_calls.fetch_add(1, std::memory_order_relaxed); + } + + std::string token; + std::string keyword_match = Keyword; + if (ToLower) + { + keyword_match = ::ToLower(keyword_match); + } + + for (;;) + { + readTokenForSkip(token, ToLower, Break); + if (token.empty() || token == keyword_match) + { + break; + } + } + + if (metrics_active) + { + ParserMetricsAddNs(g_parser_cpu_metrics.skip_until_ns, std::chrono::steady_clock::now() - timestart); + } +} + void cParser::stripFirstTokenBOM(std::string& token, bool ToLower, const char* Break) { if (!mFirstToken) return; mFirstToken = false; @@ -314,6 +1219,9 @@ void cParser::skipIncludeBlock() { } void cParser::startIncludeFromParser(cParser& srcParser, bool ToLower, std::string includefile) { + auto const metrics_active = ParserMetricsActive(); + ParserMetricsIncludeTimer const include_timer(metrics_active); + replace_slashes(includefile); const bool allowTraction = @@ -340,6 +1248,11 @@ void cParser::startIncludeFromParser(cParser& srcParser, bool ToLower, std::stri } } + if (metrics_active) + { + g_parser_cpu_metrics.includes_opened.fetch_add(1, std::memory_order_relaxed); + } + mIncludeParser = std::make_shared( includefile, /*buffer_FILE*/ static_cast(/*buffer_FILE*/ 0), mPath, LoadTraction, readParameters(srcParser) ); @@ -387,6 +1300,9 @@ bool cParser::handleIncludeIfPresent(std::string& token, bool ToLower, const cha void cParser::readToken(std::string &out, bool ToLower, const char *Break) { + auto const metrics_active = ParserMetricsActive(); + ParserMetricsReadTokenTimer const read_token_timer(metrics_active); + if (mIncludeParser) { mIncludeParser->readToken(out, ToLower, Break); @@ -406,6 +1322,11 @@ void cParser::readToken(std::string &out, bool ToLower, const char *Break) substituteParameters(out, ToLower); handleIncludeIfPresent(out, ToLower, Break); + + if (metrics_active && false == out.empty()) + { + g_parser_cpu_metrics.tokens_read.fetch_add(1, std::memory_order_relaxed); + } } std::vector cParser::readParameters(cParser &Input) diff --git a/utilities/parser.h b/utilities/parser.h index 6bac77e7..15237a03 100644 --- a/utilities/parser.h +++ b/utilities/parser.h @@ -9,6 +9,7 @@ http://mozilla.org/MPL/2.0/. #pragma once +#include #include #include #include @@ -69,6 +70,11 @@ class cParser //: public std::stringstream return m_autoclear; } bool getTokens( unsigned int Count = 1, bool ToLower = true, char const *Break = "\n\r\t ;" ); + // read one token and parse as number without using the tokens deque / stringstream + bool readTokenFloat( float &Value, bool ToLower = true, char const *Break = "\n\r\t ;" ); + bool readTokenDouble( double &Value, bool ToLower = true, char const *Break = "\n\r\t ;" ); + void readNextToken( std::string &Token, bool ToLower = true, char const *Break = "\n\r\t ;" ); + void skipUntilKeyword( std::string const &Keyword, bool ToLower = true, char const *Break = "\n\r\t ;" ); std::string readTokenFromStream(bool ToLower, const char *Break); void stripFirstTokenBOM(std::string &token, bool ToLower, const char *Break); void substituteParameters(std::string &token, bool ToLower); @@ -106,6 +112,8 @@ class cParser //: public std::stringstream bool handleIncludeIfPresent(std::string &token, bool ToLower, const char *Break); // methods: void readToken(std::string& out, bool ToLower = true, const char *Break = "\n\r\t ;"); + void readTokenForSkip(std::string &out, bool ToLower = true, const char *Break = "\n\r\t ;"); + std::string readTokenFromStreamFast(bool ToLower, const char *Break); static std::vector readParameters( cParser &Input ); std::string readQuotes( char const Quote = '\"' ); void skipComment( std::string const &Endmark ); @@ -131,6 +139,50 @@ class cParser //: public std::stringstream std::deque tokens; }; +class ParserFileCacheScope +{ +public: + ParserFileCacheScope(); + ~ParserFileCacheScope(); + + ParserFileCacheScope(ParserFileCacheScope const &) = delete; + ParserFileCacheScope &operator=(ParserFileCacheScope const &) = delete; + + void end(); + +private: + bool m_active { true }; +}; + +class ParserMetricsScope +{ +public: + ParserMetricsScope(); + ~ParserMetricsScope(); + + ParserMetricsScope(ParserMetricsScope const &) = delete; + ParserMetricsScope &operator=(ParserMetricsScope const &) = delete; + + void end(); + +private: + bool m_active { true }; +}; + +namespace parser_metrics +{ +bool active(); + +struct convert_timer +{ + std::chrono::steady_clock::time_point start {}; + bool enabled { false }; + + convert_timer(); + ~convert_timer(); +}; +} // namespace parser_metrics + template <> glm::vec3 @@ -143,6 +195,7 @@ cParser::operator>>( Type_ &Right ) { if( true == this->tokens.empty() ) { return *this; } + parser_metrics::convert_timer timer; std::stringstream converter( this->tokens.front() ); converter >> Right; this->tokens.pop_front(); diff --git a/utilities/utilities.cpp b/utilities/utilities.cpp index fc1d7a53..2b2d3a76 100644 --- a/utilities/utilities.cpp +++ b/utilities/utilities.cpp @@ -15,7 +15,12 @@ Copyright (C) 2007-2014 Maciej Cierniak // //#include //#include +#include +#include +#include #include +#include +#include //#ifndef WIN32 //#include //#endif @@ -26,10 +31,9 @@ Copyright (C) 2007-2014 Maciej Cierniak #include "utilities/utilities.h" #include "utilities/Globals.h" +#include "utilities/Logs.h" #include "utilities/parser.h" -//#include "utilities/Logs.h" - // TODO: This shouldn't be in Globals? bool DebugModeFlag = false; bool FreeFlyModeFlag = false; @@ -37,6 +41,136 @@ bool EditorModeFlag = false; bool DebugCameraFlag = false; bool DebugTractionFlag = false; +namespace +{ +std::atomic g_fileexists_cache_depth { 0 }; +bool g_fileexists_cache_enabled { false }; +std::mutex g_fileexists_cache_mutex; +std::unordered_map g_fileexists_cache; + +struct fileexists_cache_metrics +{ + std::uint64_t total_calls { 0 }; + std::uint64_t cache_hits { 0 }; + std::uint64_t cache_misses { 0 }; + std::uint64_t filesystem_exists_calls { 0 }; + std::uint64_t positive_results { 0 }; + std::uint64_t negative_results { 0 }; + std::uint64_t untracked_path_calls { 0 }; + std::chrono::steady_clock::duration filesystem_exists_time {}; + std::unordered_map path_counts; + + void reset() + { + *this = {}; + } +}; + +fileexists_cache_metrics g_fileexists_cache_metrics; + +std::string FileExistsCacheKey(std::string const &Filename) +{ + if (Filename.empty()) + { + return Filename; + } + + try + { + auto path = std::filesystem::path(Filename); + if (path.is_relative()) + { + path = std::filesystem::absolute(path); + } + + auto key = path.lexically_normal().generic_string(); +#ifdef _WIN32 + for (auto &character : key) + { + auto const value = static_cast(character); + if (value < 128) + { + character = static_cast(std::tolower(value)); + } + } +#endif + return key; + } + catch (std::filesystem::filesystem_error const &) + { + auto key = Filename; + std::replace(key.begin(), key.end(), '\\', '/'); + return key; + } +} + +double FileExistsDurationMilliseconds(std::chrono::steady_clock::duration const Duration) +{ + return std::chrono::duration(Duration).count(); +} + +std::string FileExistsFormatPathCount(std::pair const &Entry) +{ + return " " + std::to_string(Entry.second) + "x " + Entry.first; +} + +std::vector FileExistsCacheReport() +{ + std::vector report; + report.emplace_back( + std::string("FileExists scope: mode=") + (g_fileexists_cache_enabled ? "cached" : "direct") + + ", calls=" + std::to_string(g_fileexists_cache_metrics.total_calls) + + ", hits=" + std::to_string(g_fileexists_cache_metrics.cache_hits) + + ", misses=" + std::to_string(g_fileexists_cache_metrics.cache_misses) + + ", fs_exists=" + std::to_string(g_fileexists_cache_metrics.filesystem_exists_calls) + + ", found=" + std::to_string(g_fileexists_cache_metrics.positive_results) + + ", missing=" + std::to_string(g_fileexists_cache_metrics.negative_results) + + ", fs_time_ms=" + to_string(FileExistsDurationMilliseconds(g_fileexists_cache_metrics.filesystem_exists_time), 3) + + ", untracked_paths=" + std::to_string(g_fileexists_cache_metrics.untracked_path_calls) + + ", cached_paths=" + std::to_string(g_fileexists_cache.size())); + + std::vector> top_paths; + top_paths.reserve(g_fileexists_cache_metrics.path_counts.size()); + for (auto const &entry : g_fileexists_cache_metrics.path_counts) + { + if (entry.second > 1) + { + top_paths.emplace_back(entry); + } + } + + constexpr std::size_t top_path_limit = 5; + auto const top_count = std::min(top_path_limit, top_paths.size()); + std::partial_sort( + top_paths.begin(), + top_paths.begin() + top_count, + top_paths.end(), + [](auto const &Left, auto const &Right) + { + if (Left.second != Right.second) + { + return Left.second > Right.second; + } + return Left.first < Right.first; + }); + + for (std::size_t index = 0; index < top_count; ++index) + { + report.emplace_back(FileExistsFormatPathCount(top_paths[index])); + } + + return report; +} + +void FileExistsCacheLogReport(std::vector const &Report) +{ + for (auto const &line : Report) + { + WriteLog(line); + } +} +} // namespace + std::string Now() { auto now = std::chrono::system_clock::now(); @@ -328,7 +462,62 @@ template <> bool extract_value(bool &Variable, std::string const &Key, std::stri bool FileExists(std::string const &Filename) { - return std::filesystem::exists(Filename); + if (g_fileexists_cache_depth.load(std::memory_order_acquire) == 0) + { + return std::filesystem::exists(Filename); + } + + std::lock_guard lock(g_fileexists_cache_mutex); + if (g_fileexists_cache_depth.load(std::memory_order_relaxed) == 0) + { + return std::filesystem::exists(Filename); + } + + auto const cache_enabled = g_fileexists_cache_enabled; + auto const key = cache_enabled ? FileExistsCacheKey(Filename) : Filename; + ++g_fileexists_cache_metrics.total_calls; + if (auto lookup = g_fileexists_cache_metrics.path_counts.find(key); lookup != g_fileexists_cache_metrics.path_counts.end()) + { + ++lookup->second; + } + else if (g_fileexists_cache_metrics.path_counts.size() < 4096) + { + g_fileexists_cache_metrics.path_counts.emplace(key, 1); + } + else + { + ++g_fileexists_cache_metrics.untracked_path_calls; + } + + if (cache_enabled) + { + auto const lookup = g_fileexists_cache.find(key); + if (lookup != g_fileexists_cache.end()) + { + ++g_fileexists_cache_metrics.cache_hits; + return lookup->second; + } + + ++g_fileexists_cache_metrics.cache_misses; + } + + ++g_fileexists_cache_metrics.filesystem_exists_calls; + auto const timestart = std::chrono::steady_clock::now(); + auto const exists = std::filesystem::exists(Filename); + g_fileexists_cache_metrics.filesystem_exists_time += std::chrono::steady_clock::now() - timestart; + if (exists) + { + ++g_fileexists_cache_metrics.positive_results; + } + else + { + ++g_fileexists_cache_metrics.negative_results; + } + if (cache_enabled) + { + g_fileexists_cache.emplace(key, exists); + } + return exists; } std::pair FileExists(std::vector const &Names, std::vector const &Extensions) @@ -348,6 +537,64 @@ std::pair FileExists(std::vector const &N return {{}, {}}; } +FileExistsCacheScope::FileExistsCacheScope() +{ + std::lock_guard lock(g_fileexists_cache_mutex); + if (g_fileexists_cache_depth.load(std::memory_order_relaxed) == 0) + { + g_fileexists_cache.clear(); + g_fileexists_cache_enabled = Global.ScenarioFileExistsCache; + g_fileexists_cache_metrics.reset(); + } + g_fileexists_cache_depth.fetch_add(1, std::memory_order_release); +} + +FileExistsCacheScope::~FileExistsCacheScope() +{ + end(); +} + +void FileExistsCacheScope::clear() +{ + std::vector report; + { + std::lock_guard lock(g_fileexists_cache_mutex); + report = FileExistsCacheReport(); + g_fileexists_cache.clear(); + g_fileexists_cache_metrics.reset(); + } + FileExistsCacheLogReport(report); +} + +void FileExistsCacheScope::end() +{ + if (false == m_active) + { + return; + } + + std::vector report; + { + std::lock_guard lock(g_fileexists_cache_mutex); + auto const depth = g_fileexists_cache_depth.load(std::memory_order_relaxed); + if (depth <= 1) + { + report = FileExistsCacheReport(); + g_fileexists_cache_depth.store(0, std::memory_order_release); + g_fileexists_cache.clear(); + g_fileexists_cache_enabled = false; + g_fileexists_cache_metrics.reset(); + } + else + { + g_fileexists_cache_depth.store(depth - 1, std::memory_order_release); + } + m_active = false; + } + + FileExistsCacheLogReport(report); +} + // returns time of last modification for specified file std::time_t last_modified(std::string const &Filename) { diff --git a/utilities/utilities.h b/utilities/utilities.h index 5097173f..a20e21a8 100644 --- a/utilities/utilities.h +++ b/utilities/utilities.h @@ -201,6 +201,22 @@ bool FileExists(std::string const &Filename); std::pair FileExists(std::vector const &Names, std::vector const &Extensions); +class FileExistsCacheScope +{ +public: + FileExistsCacheScope(); + ~FileExistsCacheScope(); + + FileExistsCacheScope(FileExistsCacheScope const &) = delete; + FileExistsCacheScope &operator=(FileExistsCacheScope const &) = delete; + + void clear(); + void end(); + +private: + bool m_active { true }; +}; + // returns time of last modification for specified file std::time_t last_modified(std::string const &Filename);