--- 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 <time.h>
-#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
+ // (<AT> 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 <processName> <processID> 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<CSubTestData>::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<CSubTestData>::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<CSubTestData>::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<CSubTestData>::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<CSubTestData>::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