Add GLOB_MEASURE_TIME configuration option to profile the runtime of the postprocessing steps.

Start new documentation page for Performance/Profiling questions.
Migrate existing notes on multithreading to a new doc page, add more details.

git-svn-id: https://assimp.svn.sourceforge.net/svnroot/assimp/trunk@772 67173fc5-114c-0410-ac8e-9d2fd5bffc1f
This commit is contained in:
aramis_acg
2010-07-08 22:44:44 +00:00
parent 7f2f5e7555
commit aae8637666
10 changed files with 403 additions and 44 deletions

View File

@@ -0,0 +1,72 @@
// boost timer.hpp header file ---------------------------------------------//
// Copyright Beman Dawes 1994-99. Distributed under the Boost
// Software License, Version 1.0. (See accompanying file
// LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt)
// See http://www.boost.org/libs/timer for documentation.
// Revision History
// 01 Apr 01 Modified to use new <boost/limits.hpp> header. (JMaddock)
// 12 Jan 01 Change to inline implementation to allow use without library
// builds. See docs for more rationale. (Beman Dawes)
// 25 Sep 99 elapsed_max() and elapsed_min() added (John Maddock)
// 16 Jul 99 Second beta
// 6 Jul 99 Initial boost version
#ifndef BOOST_TIMER_HPP
#define BOOST_TIMER_HPP
//#include <boost/config.hpp>
#include <ctime>
//#include <boost/limits.hpp>
# ifdef BOOST_NO_STDC_NAMESPACE
namespace std { using ::clock_t; using ::clock; }
# endif
namespace boost {
// timer -------------------------------------------------------------------//
// A timer object measures elapsed time.
// It is recommended that implementations measure wall clock rather than CPU
// time since the intended use is performance measurement on systems where
// total elapsed time is more important than just process or CPU time.
// Warnings: The maximum measurable elapsed time may well be only 596.5+ hours
// due to implementation limitations. The accuracy of timings depends on the
// accuracy of timing information provided by the underlying platform, and
// this varies a great deal from platform to platform.
class timer
{
public:
timer() { _start_time = std::clock(); } // postcondition: elapsed()==0
// timer( const timer& src ); // post: elapsed()==src.elapsed()
// ~timer(){}
// timer& operator=( const timer& src ); // post: elapsed()==src.elapsed()
void restart() { _start_time = std::clock(); } // post: elapsed()==0
double elapsed() const // return elapsed time in seconds
{ return double(std::clock() - _start_time) / CLOCKS_PER_SEC; }
double elapsed_max() const // return estimated maximum value for elapsed()
// Portability warning: elapsed_max() may return too high a value on systems
// where std::clock_t overflows or resets at surprising values.
{
return (double((std::numeric_limits<std::clock_t>::max)())
- double(_start_time)) / double(CLOCKS_PER_SEC);
}
double elapsed_min() const // return minimum value for elapsed()
{ return double(1)/double(CLOCKS_PER_SEC); }
private:
std::clock_t _start_time;
}; // timer
} // namespace boost
#endif // BOOST_TIMER_HPP

View File

@@ -141,6 +141,7 @@ SOURCE_GROUP( Common FILES
Vertex.h
LineSplitter.h
TinyFormatter.h
Profiler.h
)
SOURCE_GROUP( 3DS FILES
@@ -720,6 +721,7 @@ ADD_LIBRARY( assimp SHARED
BlenderIntermediate.h
BlenderModifier.h
BlenderModifier.cpp
Profiler.h
# Necessary to show the headers in the project when using the VC++ generator:
BoostWorkaround/boost/math/common_factor_rt.hpp

View File

@@ -67,6 +67,9 @@ OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
#include "ProcessHelper.h"
#include "ScenePreprocessor.h"
#include "MemoryIOWrapper.h"
#include "Profiler.h"
using namespace Assimp::Profiling;
// ------------------------------------------------------------------------------------------------
// Importers
@@ -837,20 +840,25 @@ const aiScene* Importer::ReadFile( const char* _pFile, unsigned int pFlags)
{
// Check whether this Importer instance has already loaded
// a scene. In this case we need to delete the old one
if (pimpl->mScene)
{
DefaultLogger::get()->debug("Deleting previous scene");
if (pimpl->mScene) {
DefaultLogger::get()->debug("(Deleting previous scene)");
FreeScene();
}
// First check if the file is accessable at all
if( !pimpl->mIOHandler->Exists( pFile))
{
if( !pimpl->mIOHandler->Exists( pFile)) {
pimpl->mErrorString = "Unable to open file \"" + pFile + "\".";
DefaultLogger::get()->error(pimpl->mErrorString);
return NULL;
}
boost::scoped_ptr<Profiler> profiler(GetPropertyInteger(AI_CONFIG_GLOB_MEASURE_TIME,0)?new Profiler():NULL);
if (profiler) {
profiler->BeginRegion("total");
}
// Find an worker class which can handle the file
BaseImporter* imp = NULL;
for( unsigned int a = 0; a < pimpl->mImporter.size(); a++) {
@@ -861,10 +869,9 @@ const aiScene* Importer::ReadFile( const char* _pFile, unsigned int pFlags)
}
}
if (!imp)
{
if (!imp) {
// not so bad yet ... try format auto detection.
std::string::size_type s = pFile.find_last_of('.');
const std::string::size_type s = pFile.find_last_of('.');
if (s != std::string::npos) {
DefaultLogger::get()->info("File extension now known, trying signature-based detection");
for( unsigned int a = 0; a < pimpl->mImporter.size(); a++) {
@@ -885,9 +892,18 @@ const aiScene* Importer::ReadFile( const char* _pFile, unsigned int pFlags)
// Dispatch the reading to the worker class for this format
DefaultLogger::get()->info("Found a matching importer for this file format");
if (profiler) {
profiler->BeginRegion("import");
}
imp->SetupProperties( this );
pimpl->mScene = imp->ReadFile( pFile, pimpl->mIOHandler);
if (profiler) {
profiler->EndRegion("import");
}
// If successful, apply all active post processing steps to the imported data
if( pimpl->mScene) {
@@ -904,9 +920,17 @@ const aiScene* Importer::ReadFile( const char* _pFile, unsigned int pFlags)
#endif // no validation
// Preprocess the scene and prepare it for post-processing
if (profiler) {
profiler->BeginRegion("preprocess");
}
ScenePreprocessor pre(pimpl->mScene);
pre.ProcessScene();
if (profiler) {
profiler->EndRegion("preprocess");
}
// Ensure that the validation process won't be called twice
ApplyPostProcessing(pFlags & (~aiProcess_ValidateDataStructure));
}
@@ -917,6 +941,10 @@ const aiScene* Importer::ReadFile( const char* _pFile, unsigned int pFlags)
// clear any data allocated by post-process steps
pimpl->mPPShared->Clean();
if (profiler) {
profiler->EndRegion("total");
}
}
#ifdef ASSIMP_CATCH_GLOBAL_EXCEPTIONS
catch (std::exception &e)
@@ -979,16 +1007,27 @@ const aiScene* Importer::ApplyPostProcessing(unsigned int pFlags)
pFlags |= aiProcess_ValidateDataStructure;
}
#else
if (pimpl->bExtraVerbose)
if (pimpl->bExtraVerbose) {
DefaultLogger::get()->warn("Not a debug build, ignoring extra verbose setting");
}
#endif // ! DEBUG
boost::scoped_ptr<Profiler> profiler(GetPropertyInteger(AI_CONFIG_GLOB_MEASURE_TIME,0)?new Profiler():NULL);
for( unsigned int a = 0; a < pimpl->mPostProcessingSteps.size(); a++) {
BaseProcess* process = pimpl->mPostProcessingSteps[a];
if( process->IsActive( pFlags)) {
if (profiler) {
profiler->BeginRegion("postprocess");
}
process->SetupProperties( this );
process->ExecuteOnScene ( this );
if (profiler) {
profiler->EndRegion("postprocess");
}
}
if( !pimpl->mScene) {
break;

97
code/Profiler.h Normal file
View File

@@ -0,0 +1,97 @@
/*
Open Asset Import Library (ASSIMP)
----------------------------------------------------------------------
Copyright (c) 2006-2010, ASSIMP Development Team
All rights reserved.
Redistribution and use of this software in source and binary forms,
with or without modification, are permitted provided that the
following conditions are met:
* Redistributions of source code must retain the above
copyright notice, this list of conditions and the
following disclaimer.
* Redistributions in binary form must reproduce the above
copyright notice, this list of conditions and the
following disclaimer in the documentation and/or other
materials provided with the distribution.
* Neither the name of the ASSIMP team, nor the names of its
contributors may be used to endorse or promote products
derived from this software without specific prior
written permission of the ASSIMP Development Team.
THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
"AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
(INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
----------------------------------------------------------------------
*/
/** @file Profiler.h
* @brief Utility to measure the respective runtime of each import step
*/
#ifndef INCLUDED_PROFILER_H
#define INCLUDED_PROFILER_H
#include "boost/timer.hpp"
#include "../include/DefaultLogger.h"
#include "TinyFormatter.h"
namespace Assimp {
namespace Profiling {
using namespace Formatter;
// ------------------------------------------------------------------------------------------------
/** Simple wrapper around boost::timer to simplify reporting. Timings are automatically
* dumped to the log file.
*/
class Profiler
{
public:
Profiler() {}
public:
/** Start a named timer */
void BeginRegion(const std::string& region) {
regions[region] = boost::timer();
DefaultLogger::get()->debug((format("START `"),region,"`"));
}
/** End a specific named timer and write its end time to the log */
void EndRegion(const std::string& region) {
RegionMap::const_iterator it = regions.find(region);
if (it == regions.end()) {
return;
}
DefaultLogger::get()->debug((format("END `"),region,"`, dt= ",(*it).second.elapsed()," s"));
}
private:
typedef std::map<std::string,boost::timer> RegionMap;
RegionMap regions;
};
}
}
#endif