diff -r e26895079d7c -r 7fdc9a71d314 analyzetool/commandlineengine/src/CATParseTraceFile.cpp --- a/analyzetool/commandlineengine/src/CATParseTraceFile.cpp Wed Sep 15 00:19:18 2010 +0300 +++ b/analyzetool/commandlineengine/src/CATParseTraceFile.cpp Wed Sep 15 13:53:27 2010 +0300 @@ -20,28 +20,11 @@ #include "../inc/CATParseTraceFile.h" #include "../inc/catdatasaver.h" #include "../inc/CATDatParser.h" +#include "../inc/CATProcessData.h" #include -#define MAIN_ID "PCSS" -#define ALLOC_ID "ALLOC" // < V.1.6 allocation. -#define ALLOCH_ID "ALLOCH" // Header of multi message allocation. -#define ALLOCF_ID "ALLOCF" // Fragment of multi message allocation. -#define FREE_ID "FREE" -#define FREEH_ID "FREEH" // Header of multi message free. -#define FREEF_ID "FREEF" // Fragment of multi message free. -#define HANDLE_LEAK_ID "HANDLE_LEAK" -const string ERROR_OCCURED = "ERROR_OCCURED"; // Error messages. -const string INCORRECT_ATOOL_VERSION = "INCORRECT_ATOOL_VERSION"; -/** -* Invalid characters in trace file line content. -* These will be filtered out before actuall parsing of line. -10 = LF -13 = CR -124 = | -*/ -const char cINVALID_TRACE_FILE_CHARS[] = { 10, 13, 124 }; // ----------------------------------------------------------------------------- // CATParseTraceFile::CATParseTraceFile @@ -57,12 +40,13 @@ // CATParseTraceFile::StartParse // Main function to start trace parsing. // ----------------------------------------------------------------------------- -bool CATParseTraceFile::StartParse( const char* pFileName, const char* pOutputFileName ) +bool CATParseTraceFile::StartParse( const char* pFileName, const char* pOutputFileName, const char* pCleanedTraceFile ) { LOG_FUNC_ENTRY("CATParseTraceFile::StartParse"); // Return value, will be changed to true if process start found. bool bRet = false; + bool bCreateCleanedTraces = false; // Check pointers if ( pFileName == NULL ) @@ -79,6 +63,24 @@ return bRet; } + ofstream cleanedTraces; + + // check is creation of file needed + if( pCleanedTraceFile != NULL ) + { + // if yes open file for cleaned traces + // ( messages with cleaned timestamps) + bCreateCleanedTraces = true; + + cleanedTraces.open(pCleanedTraceFile); + + if( !cleanedTraces.good() ) + { + printf( "Can not open file: %s\n", pCleanedTraceFile ); + return bRet; + } + } + // Open data file ifstream in( pFileName ); @@ -140,10 +142,17 @@ if( strstr( cLineFromFile, MAIN_ID ) != NULL ) { string sRestOfLine( cLineFromFile ); - string sTemp; + string sTemp(""); + unsigned __int64 iTimeStamp(0); + string sTime(""); + string sLineStart(""); - // Delete all characters before main ID - sRestOfLine.erase( 0, sRestOfLine.find( MAIN_ID ) ); + // Get part of line before main id. This should contain time info + sLineStart = GetStringUntilMainId( sRestOfLine ); + // Get message's time stamp in microseconds + iTimeStamp = ParseTimeStamp( sLineStart ); + // store whole line from MAIN_ID - to be logged to cleaned traces file + string sLineToCleanedFile( sRestOfLine ); // Get main ID sTemp = GetStringUntilNextSpace( sRestOfLine ); @@ -156,7 +165,7 @@ // Get next argument sTemp = GetStringUntilNextSpace( sRestOfLine ); - // This might be process id or error message + // This might be process id, device info message or error message if ( sTemp.compare( ERROR_OCCURED ) == 0 ) { // Api mismatch between s60 side and atool.exe @@ -179,7 +188,31 @@ cout << sRestOfLine << endl; continue; } + + if ( sTemp.compare( LABEL_DEVICE_INFO ) == 0 ) + { + + if( vProcessList[iProcessIDinList].bProcessOnGoing == false ) + continue; + + // get time string from timestamp + sTime = GetTimeFromTimeStamp( iTimeStamp, vProcessList[iProcessIDinList].iTimeSpan ); + + // device info line, log it to cleaned file for carbide + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << LABEL_DEVICE_INFO << " "; //add Message type + cleanedTraces << sRestOfLine << "\n"; //add the rest of the line + } + continue; + } + unsigned long iProcessID = _httoi( sTemp.c_str() ); + // todo to be removed when reallocations are implemented + string sProcessID = sTemp; iProcessIDinList = -1; // Find process from list @@ -221,6 +254,26 @@ bRet = true; // Set return value true we found start. vProcessList[iProcessIDinList].vData.push_back( sWholeTempLine ); vProcessList[iProcessIDinList].bProcessOnGoing = true; + + // remove part + GetStringUntilNextSpace( sRestOfLine ); + GetStringUntilNextSpace( sRestOfLine ); + // get time + sTemp = GetStringUntilNextSpace( sRestOfLine ); + unsigned __int64 iTemp(0); + sscanf_s( sTemp.c_str(), "%016I64x", &iTemp); + //calculate span between PCS time and PCS timestamp + vProcessList[iProcessIDinList].iTimeSpan = iTemp - iTimeStamp; + + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTemp << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + continue; } @@ -228,6 +281,13 @@ if( vProcessList[iProcessIDinList].bProcessOnGoing == false ) continue; + // get time string from timestamp + sTime = GetTimeFromTimeStamp( iTimeStamp, vProcessList[iProcessIDinList].iTimeSpan ); + + // TODO version with reallocation + //cleanedTraces << sTime << " "; //add time + //cleanedTraces << sLineToCleanedFile << "\n"; //add the rest of the line + // "Old style" allocation (< v.1.6) if( ! _stricmp( pCommand, ALLOC_ID ) ) { @@ -248,8 +308,17 @@ } else if ( ! _stricmp( pCommand, ALLOCH_ID ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + // Add alloc - vProcessList[iProcessIDinList].AllocH( sRestOfLine ); + vProcessList[iProcessIDinList].AllocH( sRestOfLine, sTime ); // Subtests running? vector::iterator viSubTestIter = vProcessList[iProcessIDinList].vSubTests.begin(); @@ -258,7 +327,7 @@ if( viSubTestIter->bRunning ) { // Save alloc also to sub test - viSubTestIter->AllocH( sRestOfLine ); + viSubTestIter->AllocH( sRestOfLine, sTime ); } viSubTestIter++; } @@ -266,8 +335,17 @@ // Allocation fragment (call stack). else if ( ! _stricmp( pCommand, ALLOCF_ID ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + // Add alloc fragment - vProcessList[iProcessIDinList].AllocF( sRestOfLine ); + vProcessList[iProcessIDinList].AllocF( sRestOfLine, sTime ); // Subtests running? vector::iterator viSubTestIter = vProcessList[iProcessIDinList].vSubTests.begin(); @@ -276,7 +354,164 @@ if( viSubTestIter->bRunning ) { // Save alloc fragment also to sub test - viSubTestIter->AllocF( sRestOfLine ); + viSubTestIter->AllocF( sRestOfLine, sTime ); + } + viSubTestIter++; + } + } + else if ( ! _stricmp( pCommand, REALLOCH_ID ) ) + { + // Add free + + // get 'free' line from realloc line + string sFreeRestOfLine = sRestOfLine; + string sFreeLine = ""; + sFreeLine.append( GetStringUntilNextSpace( sFreeRestOfLine, true ) ); //append freed memory address + sFreeLine.append( " " ); + // next two strings are for 'alloc' (address and size) - lets remove them + GetStringUntilNextSpace( sFreeRestOfLine, true ); + GetStringUntilNextSpace( sFreeRestOfLine, true ); + // add rest of line to 'free' line + sFreeLine.append( sFreeRestOfLine ); + //add 'free' line + vProcessList[iProcessIDinList].FreeH( sFreeLine, sTime ); + + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + // construct 'free' header trace + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << FREEH_ID << " "; //add FRH + cleanedTraces << sFreeLine << "\n"; //add the rest of the line + } + + // Add alloc + + //get 'alloc' line from realloc line + // only first string is unnecessary, lets remove it + GetStringUntilNextSpace( sRestOfLine ); + // add 'alloc' line + vProcessList[iProcessIDinList].AllocH( sRestOfLine, sTime ); + + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + // construct 'alloc' header trace + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << ALLOCH_ID << " "; //add FRH + cleanedTraces << sRestOfLine << "\n"; //add the rest of the line + } + + // Subtests running? + vector::iterator viSubTestIter = vProcessList[iProcessIDinList].vSubTests.begin(); + while( viSubTestIter != vProcessList[iProcessIDinList].vSubTests.end() ) + { + if( viSubTestIter->bRunning ) + { + // Save realloc also to sub test + // Add free + + // get 'free' line from realloc line + string sFreeRestOfLine = sRestOfLine; + string sFreeLine = ""; + sFreeLine.append( GetStringUntilNextSpace( sFreeRestOfLine, true ) ); //append freed memory address + sFreeLine.append( " " ); + // next two strings are for 'alloc' (address and size) - lets remove them + GetStringUntilNextSpace( sFreeRestOfLine, true ); + GetStringUntilNextSpace( sFreeRestOfLine, true ); + // add rest of line to 'free' line + sFreeLine.append( sFreeRestOfLine ); + //add 'free' line + vProcessList[iProcessIDinList].FreeH( sFreeLine, sTime ); + + // Add alloc + + //get 'alloc' line from realloc line + // only first string is unnecessary, lets remove it + GetStringUntilNextSpace( sRestOfLine ); + // add 'alloc' line + vProcessList[iProcessIDinList].AllocH( sRestOfLine, sTime ); + } + viSubTestIter++; + } + } + // rellocation fragment (call stack). + else if ( ! _stricmp( pCommand, REALLOCF_ID ) ) + { + // Add free fragment + + // get 'free' line from realloc line + string sFreeRestOfLine = sRestOfLine; + string sFreeLine = ""; + sFreeLine.append( GetStringUntilNextSpace( sFreeRestOfLine, true ) ); //append freed memory address + sFreeLine.append( " " ); + // next string is for 'alloc' (address) - lets remove it + GetStringUntilNextSpace( sFreeRestOfLine, true ); + // add rest of line to 'free' line + sFreeLine.append( sFreeRestOfLine ); + //add 'free' line + vProcessList[iProcessIDinList].FreeH( sFreeLine, sTime ); + + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + // construct 'free' fragment trace + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << FREEF_ID << " "; //add FRF + cleanedTraces << sFreeLine << "\n"; //add the rest of the line + } + + // Add alloc fragment + + // first string is for 'free' (address), lets remove it first + GetStringUntilNextSpace( sRestOfLine, true ); + //add 'alloc' line + vProcessList[iProcessIDinList].AllocF( sRestOfLine, sTime ); + + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + // construct 'alloc' fragment trace + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << ALLOCF_ID << " "; //add FRF + cleanedTraces << sRestOfLine << "\n"; //add the rest of the line + } + + // Subtests running? + vector::iterator viSubTestIter = vProcessList[iProcessIDinList].vSubTests.begin(); + while( viSubTestIter != vProcessList[iProcessIDinList].vSubTests.end() ) + { + if( viSubTestIter->bRunning ) + { + // Save alloc fragment also to sub test + // Add free fragment + + // get 'free' line from realloc line + string sFreeRestOfLine = sRestOfLine; + string sFreeLine = ""; + sFreeLine.append( GetStringUntilNextSpace( sFreeRestOfLine, true ) ); //append freed memory address + sFreeLine.append( " " ); + // next string is for 'alloc' (address) - lets remove it + GetStringUntilNextSpace( sFreeRestOfLine, true ); + // add rest of line to 'free' line + sFreeLine.append( sFreeRestOfLine ); + //add 'free' line + vProcessList[iProcessIDinList].FreeH( sFreeLine, sTime ); + + // Add alloc fragment + + // first string is for 'free' (address), lets remove it first + GetStringUntilNextSpace( sRestOfLine, true ); + //add 'alloc' line + vProcessList[iProcessIDinList].AllocF( sRestOfLine, sTime ); } viSubTestIter++; } @@ -302,8 +537,17 @@ // Header free. else if( ! _stricmp( pCommand, FREEH_ID ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + // Send free - vProcessList[iProcessIDinList].FreeH( sRestOfLine ); + vProcessList[iProcessIDinList].FreeH( sRestOfLine, sTime ); // Subtests running? vector::iterator viSubTestIter = vProcessList[iProcessIDinList].vSubTests.begin(); @@ -312,7 +556,7 @@ if( viSubTestIter->bRunning ) { // Send free to subtest - viSubTestIter->FreeH( sRestOfLine ); + viSubTestIter->FreeH( sRestOfLine, sTime ); } viSubTestIter++; } @@ -320,11 +564,34 @@ } else if( ! _stricmp( pCommand, FREEF_ID ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } // Not used currently. } // Command process end else if( ! _stricmp( pCommand, LABEL_PROCESS_END ) ) { + // append processID and time + sWholeTempLine.append(" "); + sWholeTempLine.append( sProcessID ); + sWholeTempLine.append(" "); + sWholeTempLine.append( sTime ); + + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + // Set process has ended. vProcessList[iProcessIDinList].bProcessOnGoing = false; @@ -405,6 +672,15 @@ } else if( ! _stricmp( pCommand, LABEL_HANDLE_LEAK ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + // Make whole line sTemp.append( " " ); sTemp.append( sRestOfLine ); @@ -412,6 +688,19 @@ } else if( ! _stricmp( pCommand, LABEL_DLL_LOAD ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + + // append time to the end of the line + sWholeTempLine.append( " " ); + sWholeTempLine.append( sTime ); + // Add module load to process data. vProcessList[iProcessIDinList].vData.push_back( sWholeTempLine ); // Add module load to subtest data if test running. @@ -425,6 +714,19 @@ } else if( ! _stricmp( pCommand, LABEL_DLL_UNLOAD ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + + // append time to the end of the line + sWholeTempLine.append( " " ); + sWholeTempLine.append( sTime ); + // Add module load to process data. vProcessList[iProcessIDinList].vData.push_back( sWholeTempLine ); // Add module unload to subtest data if test running. @@ -439,10 +741,28 @@ sTemp.find( LABEL_PROCESS_END ) != string::npos || sTemp.find( LABEL_ERROR_OCCURED ) != string::npos || sTemp.find( LABEL_HANDLE_LEAK ) != string::npos ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + vProcessList[iProcessIDinList].vData.push_back( sWholeTempLine ); } else if( ! _stricmp( pCommand, LABEL_TEST_START ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + bRet = true; // Set return value true we found start. // Get sub test time string sSubTestTime = GetStringUntilNextSpace( sRestOfLine ); @@ -461,6 +781,15 @@ } else if( ! _stricmp( pCommand, LABEL_TEST_END ) ) { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + // Get sub test time string sSubTestEnd = GetStringUntilNextSpace( sRestOfLine ); // Get sub test name @@ -481,9 +810,53 @@ viSubTestIter++; } } + else if( ! _stricmp( pCommand, LABEL_THREAD_START ) ) + { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + + //currently not used + } + else if( ! _stricmp( pCommand, LABEL_THREAD_END ) ) + { + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + + //currently not used + } + else + { + // unknown tag, log it to cleaned file for carbide + if( bCreateCleanedTraces ) + { + // add message to cleaned traces file + cleanedTraces << sTime << " "; //add time + cleanedTraces << MAIN_ID << " "; //add MAIN_ID + cleanedTraces << sProcessID << " "; //add process ID + cleanedTraces << sWholeTempLine << "\n"; //add the rest of the line + } + } } } + if( bCreateCleanedTraces ) + { + // close stream + cleanedTraces.close(); + } + // Print all saved data from processes for( unsigned int i = 0 ; i < vProcessList.size() ; i++ ) { @@ -582,4 +955,19 @@ LOG_LOW_FUNC_ENTRY("CATParseTraceFile::GetDataSaver"); return &m_DataSaver; } + + +// ----------------------------------------------------------------------------- +// CATBase::GetTimeFromTimeStamp +// Gets time from timestamp in microseconds as string +// ----------------------------------------------------------------------------- +string CATParseTraceFile::GetTimeFromTimeStamp( unsigned __int64 iTimeStamp, unsigned __int64 iTimeSpan ) +{ + unsigned __int64 iTime = iTimeStamp + iTimeSpan; + stringstream ss; + ss << std::hex << iTime; + + return ss.str(); +} + //EOF