Merge pull request #534 from kyzentun/song_manager_restructure

Various changes to speed up start up time

src/Actor.cpp

@@ -269,14 +269,7 @@ void Actor::LoadFromNode( const XNode* pNode )
 		// Load Name, if any.
 		const RString &sKeyName = pAttr->first;
 		const XNodeValue *pValue = pAttr->second;
-		if( sKeyName == "Name" )			SetName( pValue->GetValue<RString>() );
+		if( EndsWith(sKeyName,"Command") )
-		else if( sKeyName == "BaseRotationX" )		SetBaseRotationX( pValue->GetValue<float>() );
-		else if( sKeyName == "BaseRotationY" )		SetBaseRotationY( pValue->GetValue<float>() );
-		else if( sKeyName == "BaseRotationZ" )		SetBaseRotationZ( pValue->GetValue<float>() );
-		else if( sKeyName == "BaseZoomX" )		SetBaseZoomX( pValue->GetValue<float>() );
-		else if( sKeyName == "BaseZoomY" )		SetBaseZoomY( pValue->GetValue<float>() );
-		else if( sKeyName == "BaseZoomZ" )		SetBaseZoomZ( pValue->GetValue<float>() );
-		else if( EndsWith(sKeyName,"Command") )
 		{
 			LuaReference *pRef = new LuaReference;
 			pValue->PushValue( L );
@@ -284,6 +277,13 @@ void Actor::LoadFromNode( const XNode* pNode )
 			RString sCmdName = sKeyName.Left( sKeyName.size()-7 );
 			AddCommand( sCmdName, apActorCommands( pRef ) );
 		}
+		else if( sKeyName == "Name" )			SetName( pValue->GetValue<RString>() );
+		else if( sKeyName == "BaseRotationX" )		SetBaseRotationX( pValue->GetValue<float>() );
+		else if( sKeyName == "BaseRotationY" )		SetBaseRotationY( pValue->GetValue<float>() );
+		else if( sKeyName == "BaseRotationZ" )		SetBaseRotationZ( pValue->GetValue<float>() );
+		else if( sKeyName == "BaseZoomX" )		SetBaseZoomX( pValue->GetValue<float>() );
+		else if( sKeyName == "BaseZoomY" )		SetBaseZoomY( pValue->GetValue<float>() );
+		else if( sKeyName == "BaseZoomZ" )		SetBaseZoomZ( pValue->GetValue<float>() );
 	}
 
 	LUA->Release( L );

src/Course.cpp

@@ -440,6 +440,7 @@ bool Course::GetTrailUnsorted( StepsType st, CourseDifficulty cd, Trail &trail )
 	trail.m_StepsType = st;
 	trail.m_CourseType = GetCourseType();
 	trail.m_CourseDifficulty = cd;
+	trail.m_vEntries.reserve(entries.size());
 
 	// Set to true if CourseDifficulty is able to change something.
 	bool bCourseDifficultyIsSignificant = (cd == Difficulty_Medium);

src/RageLog.cpp

@@ -56,9 +56,10 @@ static map<RString, RString> LogMaps;
 
 #define LOG_PATH	"/Logs/log.txt"
 #define INFO_PATH	"/Logs/info.txt"
+#define TIME_PATH	"/Logs/timelog.txt"
 #define USER_PATH	"/Logs/userlog.txt"
 
-static RageFile *g_fileLog, *g_fileInfo, *g_fileUserLog;
+static RageFile *g_fileLog, *g_fileInfo, *g_fileUserLog, *g_fileTimeLog;
 
 /* Mutex writes to the files.  Writing to files is not thread-aware, and this is the
  * only place we write to the same file from multiple threads. */
@@ -75,7 +76,8 @@ enum
 	WRITE_TO_USER_LOG = 0x02,
 
 	/* Whether this line should be loud when written to log.txt (warnings). */
-	WRITE_LOUD = 0x04
+	WRITE_LOUD = 0x04,
+	WRITE_TO_TIME= 0x08
 };
 
 RageLog::RageLog(): m_bLogToDisk(false), m_bInfoToDisk(false),
@@ -84,6 +86,10 @@ m_bUserLogToDisk(false), m_bFlush(false), m_bShowLogOutput(false)
 	g_fileLog = new RageFile;
 	g_fileInfo = new RageFile;
 	g_fileUserLog = new RageFile;
+	g_fileTimeLog = new RageFile;
+
+	if(!g_fileTimeLog->Open(TIME_PATH, RageFile::WRITE|RageFile::STREAMED))
+	{ fprintf(stderr, "Couldn't open %s: %s\n", TIME_PATH, g_fileTimeLog->GetError().c_str()); }
 	
 	g_Mutex = new RageMutex( "Log" );
 }
@@ -105,6 +111,7 @@ RageLog::~RageLog()
 	g_fileLog->Close();
 	g_fileInfo->Close();
 	g_fileUserLog->Close();
+	g_fileTimeLog->Close();
 
 	SAFE_DELETE( g_Mutex );
 	SAFE_DELETE( g_fileLog );
@@ -222,6 +229,16 @@ void RageLog::Warn( const char *fmt, ... )
 	Write( WRITE_TO_INFO | WRITE_LOUD, sBuff );
 }
 
+void RageLog::Time(const char *fmt, ...)
+{
+	va_list	va;
+	va_start(va, fmt);
+	RString sBuff = vssprintf(fmt, va);
+	va_end(va);
+
+	Write(WRITE_TO_TIME, sBuff);
+}
+
 void RageLog::UserLog( const RString &sType, const RString &sElement, const char *fmt, ... )
 {
 	va_list va;
@@ -274,6 +291,9 @@ void RageLog::Write( int where, const RString &sLine )
 		 * and stdout. */
 		sStr.insert( 0, sTimestamp );
 
+		if(where & WRITE_TO_TIME)
+			g_fileTimeLog->PutLine(sStr);
+
 		AddToRecentLogs( sStr );
 		
 		if( m_bLogToDisk && g_fileLog->IsOpen() )
@@ -295,6 +315,7 @@ void RageLog::Flush()
 {
 	g_fileLog->Flush();
 	g_fileInfo->Flush();
+	g_fileTimeLog->Flush();
 	g_fileUserLog->Flush();
 }
 

src/RageLog.h

@@ -12,6 +12,8 @@ public:
 	void Trace( const char *fmt, ... ) PRINTF(2,3);
 	void Warn( const char *fmt, ... ) PRINTF(2,3);
 	void Info( const char *fmt, ... ) PRINTF(2,3);
+	// Time is purely for writing profiling time data to the time log. -Kyz
+	void Time( const char *fmt, ... ) PRINTF(2,3);
 	void UserLog( const RString &sType, const RString &sElement, const char *fmt, ... ) PRINTF(4,5);
 	void Flush();
 

src/RageTimer.h

@@ -54,9 +54,17 @@ extern const RageTimer RageZeroTimer;
 
 // For profiling how long some chunk of code takes. -Kyz
 #define START_TIME(name) uint64_t name##_start_time= RageTimer::GetUsecsSinceStart();
-#define END_TIME(name) uint64_t name##_end_time= RageTimer::GetUsecsSinceStart();  LOG->Warn(#name " time: %zu to %zu = %zu", name##_start_time, name##_end_time, name##_end_time - name##_start_time);
+#define START_TIME_CALL_COUNT(name) START_TIME(name); ++name##_call_count;
+#define END_TIME(name) uint64_t name##_end_time= RageTimer::GetUsecsSinceStart();  LOG->Time(#name " time: %zu to %zu = %zu", name##_start_time, name##_end_time, name##_end_time - name##_start_time);
 #define END_TIME_ADD_TO(name) uint64_t name##_end_time= RageTimer::GetUsecsSinceStart();  name##_total += name##_end_time - name##_start_time;
 
+#define DECL_TOTAL_TIME(name) extern uint64_t name##_total;
+#define DEF_TOTAL_TIME(name) uint64_t name##_total= 0;
+#define PRINT_TOTAL_TIME(name) LOG->Time(#name " total time: %zu", name##_total);
+#define DECL_TOT_CALL_PAIR(name) extern uint64_t name##_total; extern uint64_t name##_call_count;
+#define DEF_TOT_CALL_PAIR(name) uint64_t name##_total= 0; uint64_t name##_call_count= 0;
+#define PRINT_TOT_CALL_PAIR(name) LOG->Time(#name " calls: %zu, time: %zu", name##_call_count, name##_total);
+
 #endif
 
 /*

src/RageUtil.cpp

@@ -667,6 +667,14 @@ RString join( const RString &sDeliminator, const vector<RString> &sSource)
 		return RString();
 
 	RString sTmp;
+	size_t final_size= 0;
+	size_t delim_size= sDeliminator.size();
+	for(size_t n= 0; n < sSource.size()-1; ++n)
+	{
+		final_size+= sSource[n].size() + delim_size;
+	}
+	final_size+= sSource.back().size();
+	sTmp.reserve(final_size);
 
 	for( unsigned iNum = 0; iNum < sSource.size()-1; iNum++ )
 	{
@@ -683,6 +691,18 @@ RString join( const RString &sDelimitor, vector<RString>::const_iterator begin,
 		return RString();
 
 	RString sRet;
+	size_t final_size= 0;
+	size_t delim_size= sDelimitor.size();
+	for(vector<RString>::const_iterator curr= begin; curr != end; ++curr)
+	{
+		final_size+= curr->size();
+		if(curr != end)
+		{
+			final_size+= delim_size;
+		}
+	}
+	sRet.reserve(final_size);
+
 	while( begin != end )
 	{
 		sRet += *begin;

src/Song.cpp

@@ -293,9 +293,9 @@ bool Song::LoadFromSongDir( RString sDir, bool load_autosave )
 
 	if( !DoesFileExist(sCacheFilePath) )
 	{ bUseCache = false; }
-	if(!PREFSMAN->m_bFastLoad && GetHashForDirectory(m_sSongDir) != uCacheHash)
+	else if(!PREFSMAN->m_bFastLoad && GetHashForDirectory(m_sSongDir) != uCacheHash)
 	{ bUseCache = false; } // this cache is out of date
-	if(load_autosave)
+	else if(load_autosave)
 	{ bUseCache= false; }
 
 	if( bUseCache )
@@ -390,6 +390,10 @@ bool Song::LoadFromSongDir( RString sDir, bool load_autosave )
  * Song/Steps objects to reload themselves. -- djpohly */
 bool Song::ReloadFromSongDir( RString sDir )
 {
+	// Remove the cache file to force the song to reload from its dir instead
+	// of loading from the cache. -Kyz
+	FILEMAN->Remove(GetCacheFilePath());
+
 	RemoveAutoGenNotes();
 	vector<Steps*> vOldSteps = m_vpSteps;
 
@@ -2196,6 +2200,11 @@ public:
 		lua_pushboolean( L, p->m_DisplayBPMType == DISPLAY_BPM_RANDOM );
 		return 1;
 	}
+	static int ReloadFromSongDir(T* p, lua_State* L)
+	{
+		p->ReloadFromSongDir();
+		COMMON_RETURN_SELF;
+	}
 
 	LunaSong()
 	{
@@ -2262,6 +2271,7 @@ public:
 		ADD_METHOD( HasPreviewVid );
 		ADD_METHOD( GetPreviewVidPath );
 		ADD_METHOD(GetPreviewMusicPath);
+		ADD_METHOD(ReloadFromSongDir);
 	}   
 };
 

src/Song.h

@@ -90,6 +90,7 @@ public:
 	bool LoadFromSongDir( RString sDir, bool load_autosave= false );
 	// This one takes the effort to reuse Steps pointers as best as it can
 	bool ReloadFromSongDir( RString sDir );
+	bool ReloadFromSongDir() { return ReloadFromSongDir(GetSongDir()); }
 	void LoadEditsFromSongDir(RString dir);
 
 	bool HasAutosaveFile();

src/SongCacheIndex.cpp

@@ -106,13 +106,21 @@ void SongCacheIndex::ReadCacheIndex()
 	FILEMAN->FlushDirCache();
 }
 
+void SongCacheIndex::SaveCacheIndex()
+{
+	CacheIndex.WriteFile(CACHE_INDEX);
+}
+
 void SongCacheIndex::AddCacheIndex(const RString &path, unsigned hash)
 {
 	if( hash == 0 )
 		++hash; /* no 0 hash values */
 	CacheIndex.SetValue( "Cache", "CacheVersion", FILE_CACHE_VERSION );
 	CacheIndex.SetValue( "Cache", MangleName(path), hash );
-	CacheIndex.WriteFile( CACHE_INDEX );
+	if(!delay_save_cache)
+	{
+		CacheIndex.WriteFile(CACHE_INDEX);
+	}
 }
 
 unsigned SongCacheIndex::GetCacheHash( const RString &path ) const

src/SongCacheIndex.h

@@ -15,8 +15,10 @@ public:
 	static RString GetCacheFilePath( const RString &sGroup, const RString &sPath );
 
 	void ReadCacheIndex();
+	void SaveCacheIndex();
 	void AddCacheIndex( const RString &path, unsigned hash );
 	unsigned GetCacheHash( const RString &path ) const;
+	bool delay_save_cache;
 };
 
 extern SongCacheIndex *SONGINDEX;	// global and accessible from anywhere in our program

src/SongManager.cpp

@@ -1,6 +1,7 @@
 #include "global.h"
 #include "SongManager.h"
 #include "arch/LoadingWindow/LoadingWindow.h"
+#include "ActorUtil.h"
 #include "AnnouncerManager.h"
 #include "BackgroundUtil.h"
 #include "BannerCache.h"
@@ -24,6 +25,7 @@
 #include "RageFileManager.h"
 #include "RageLog.h"
 #include "Song.h"
+#include "SongCacheIndex.h"
 #include "SongUtil.h"
 #include "Sprite.h"
 #include "StatsManager.h"
@@ -142,12 +144,18 @@ void SongManager::Reload( bool bAllowFastLoad, LoadingWindow *ld )
 void SongManager::InitSongsFromDisk( LoadingWindow *ld )
 {
 	RageTimer tm;
+	// Tell SONGINDEX to not write the cache index file every time a song adds
+	// an entry. -Kyz
+	SONGINDEX->delay_save_cache= true;
 	LoadStepManiaSongDir( SpecialFiles::SONGS_DIR, ld );
 
 	const bool bOldVal = PREFSMAN->m_bFastLoad;
 	PREFSMAN->m_bFastLoad.Set( PREFSMAN->m_bFastLoadAdditionalSongs );
 	LoadStepManiaSongDir( ADDITIONAL_SONGS_DIR, ld );
 	PREFSMAN->m_bFastLoad.Set( bOldVal );
+	LoadEnabledSongsFromPref();
+	SONGINDEX->SaveCacheIndex();
+	SONGINDEX->delay_save_cache= false;
 
 	LOG->Trace( "Found %d songs in %f seconds.", (int)m_pSongs.size(), tm.GetDeltaTime() );
 }
@@ -157,12 +165,20 @@ void SongManager::SanityCheckGroupDir( RString sDir ) const
 {
 	// Check to see if they put a song directly inside the group folder.
 	vector<RString> arrayFiles;
-	GetDirListing( sDir + "/*.mp3", arrayFiles );
+	GetDirListing( sDir + "/*", arrayFiles );
-	GetDirListing( sDir + "/*.oga", arrayFiles );
+	const vector<RString>& audio_exts= ActorUtil::GetTypeExtensionList(FT_Sound);
-	GetDirListing( sDir + "/*.ogg", arrayFiles );
+	FOREACH(RString, arrayFiles, fname)
-	GetDirListing( sDir + "/*.wav", arrayFiles );
+	{
-	if( !arrayFiles.empty() )
+		const RString ext= GetExtension(*fname);
-		RageException::Throw( FOLDER_CONTAINS_MUSIC_FILES.GetValue(), sDir.c_str() );	
+		FOREACH_CONST(RString, audio_exts, aud)
+		{
+			if(ext == *aud)
+			{
+				RageException::Throw(
+					FOLDER_CONTAINS_MUSIC_FILES.GetValue(), sDir.c_str());
+			}
+		}
+	}
 }
 
 void SongManager::AddGroup( RString sDir, RString sGroupDirName )
@@ -309,14 +325,13 @@ void SongManager::LoadStepManiaSongDir( RString sDir, LoadingWindow *ld )
 				);
 			}
 			Song* pNewSong = new Song;
-			m_pSongs.push_back( pNewSong );
 			if( !pNewSong->LoadFromSongDir( sSongDirName ) )
 			{
 				// The song failed to load.
-				m_pSongs.pop_back();
 				delete pNewSong;
 				continue;
 			}
+			AddSongToList(pNewSong);
 
 			index_entry.push_back( pNewSong );
 			loaded++;
@@ -341,8 +356,6 @@ void SongManager::LoadStepManiaSongDir( RString sDir, LoadingWindow *ld )
 	if( ld ) {
 		ld->SetIndeterminate( true );
 	}
-
-	LoadEnabledSongsFromPref();
 }
 
 // Instead of "symlinks", songs should have membership in multiple groups. -Chris
@@ -375,7 +388,7 @@ void SongManager::LoadGroupSymLinks(RString sDir, RString sGroupFolder)
 
 			pNewSong->m_bIsSymLink = true;	// Very important so we don't double-parse later
 			pNewSong->m_sGroupName = sGroupFolder;
-			m_pSongs.push_back( pNewSong );
+			AddSongToList(pNewSong);
 			index_entry.push_back( pNewSong );
 		}
 	}
@@ -423,6 +436,7 @@ void SongManager::FreeSongs()
 	for( unsigned i=0; i<m_pSongs.size(); i++ )
 		SAFE_DELETE( m_pSongs[i] );
 	m_pSongs.clear();
+	m_SongsByDir.clear();
 
 	// also free the songs that have been deleted from disk
 	for ( unsigned i=0; i<m_pDeletedSongs.size(); ++i ) 
@@ -1124,9 +1138,6 @@ void SongManager::SaveEnabledSongsToPref()
 
 void SongManager::LoadEnabledSongsFromPref()
 {
-	FOREACH( Song *, m_pSongs, s )
-		(*s)->SetEnabled( true );
-
 	vector<RString> asDisabledSongs;
 	split( g_sDisabledSongs, ";", asDisabledSongs, true );
 
@@ -1355,17 +1366,18 @@ Course* SongManager::GetRandomCourse()
 	return NULL;
 }
 
-Song* SongManager::GetSongFromDir( RString sDir ) const
+Song* SongManager::GetSongFromDir(RString dir) const
 {
-	if( sDir.Right(1) != "/" )
+	if(dir.Right(1) != "/")
-		sDir += "/";
+	{ dir += "/"; }
-
-	sDir.Replace( '\\', '/' );
-
-	FOREACH_CONST( Song*, m_pSongs, s )
-		if( sDir.EqualsNoCase((*s)->GetSongDir()) )
-			return *s;
 
+	dir.Replace('\\', '/');
+	dir.MakeLower();
+	map<RString, Song*>::const_iterator entry= m_SongsByDir.find(dir);
+	if(entry != m_SongsByDir.end())
+	{
+		return entry->second;
+	}
 	return NULL;
 }
 
@@ -1849,6 +1861,15 @@ int SongManager::GetNumEditsLoadedFromProfile( ProfileSlot slot ) const
 	return iCount;
 }
 
+void SongManager::AddSongToList(Song* new_song)
+{
+	new_song->SetEnabled(true);
+	m_pSongs.push_back(new_song);
+	RString dir= new_song->GetSongDir();
+	dir.MakeLower();
+	m_SongsByDir.insert(make_pair(dir, new_song));
+}
+
 void SongManager::FreeAllLoadedFromProfile( ProfileSlot slot )
 {
 	// Profile courses may refer to profile steps, so free profile courses first.

src/SongManager.h

@@ -178,8 +178,10 @@ protected:
 	void AddGroup( RString sDir, RString sGroupDirName );
 	int GetNumEditsLoadedFromProfile( ProfileSlot slot ) const;
 
+	void AddSongToList(Song* new_song);
 	/** @brief All of the songs that can be played. */
 	vector<Song*>		m_pSongs;
+	map<RString, Song*> m_SongsByDir;
 	/** @brief Hold pointers to all the songs that have been deleted from disk but must at least be kept temporarily alive for smooth audio transitions. */
 	vector<Song*>       m_pDeletedSongs;
 	/** @brief The most popular songs ranked by number of plays. */