void m1()
{
Message::Args args;
args.add("hello");
args.add("world");
args.add(123);
args.add(1234.55);
Message m(100);
m.fMsg = "%1% %2% %3% %4%";
m.format(args);
//CPPUNIT_ASSERT(m.msg() == "hello world 123 1234.55");
m.reset();
m.fMsg = "%1% %2% %3% %4%";
args.reset();
m.format(args);
//CPPUNIT_ASSERT(m.msg() == " ");
LoggingID lid(7);
MessageLog ml(lid);
m.reset();
args.add("hello");
args.add("world");
args.add(123);
args.add(1234.55);
m.format(args);
ml.logDebugMessage(m);
args.reset();
args.add("begin CEP generation");
m.reset();
m.format(args);
ml.logInfoMessage(m);
args.reset();
args.add("end CEP generation");
m.reset();
m.format(args);
ml.logInfoMessage(m);
args.reset();
args.add("something took too long");
m.reset();
m.format(args);
ml.logWarningMessage(m);
args.reset();
args.add("something seriously took too long");
m.reset();
m.format(args);
ml.logSeriousMessage(m);
ml.logErrorMessage(m);
args.reset();
args.add("something critical took too long");
m.reset();
m.format(args);
ml.logCriticalMessage(m);
LoggingID lid1;
MessageLog ml1(lid1);
args.reset();
m.reset();
args.add("subsystem 0 = erydb test");
m.format(args);
ml1.logDebugMessage(m);
LoggingID lid2(1000);
MessageLog ml2(lid2);
args.reset();
m.reset();
args.add("subsystem above MAX = erydb test");
m.format(args);
ml2.logDebugMessage(m);
LoggingID lid3(7);
MessageLog ml3(lid3);
args.reset();
m.reset();
args.add("subsystem 7 = eryadmin test");
m.format(args);
ml3.logDebugMessage(m);
Config::deleteInstanceMap();
}
//------------------------------------------------------------------------------
// This method is intended to test the messages used to profile db performance.
// The method also provides an example on how to use these log messages.
// Test can be verified by viewing /var/log/erydb/debug.log.
//
// Message types are:
//
// 26 Start Transaction
// 27 End Transaction
// 28 Start Statement
// 29 End Statement
// 30 Start Step
// 31 End Step
// 32 I/O Reads
//
// The messages should be logged in the following way:
//
// 1. The application should log a StartTransaction message at the beginning
// of a database transaction.
// 2. When the application begins processing a statement, the StartStatement
// message should be logged.
// 3. As each primitive step is executed, it's start time should be recorded
// by logging a StartStep message.
// 4. During the execution of a step, 1 or more I/O Read messages should be
// logged to record the I/O block count used in accessing each object. If
// necessary, more than 1 message can be logged for the same object and
// step. In these cases, the script that post-processes the syslog will
// add up the block counts for the same object and step.
// 5. Upon completion of each primitive step, an EndStep message should be
// logged. If multiple steps are executing in parallel, the EndStep msg
// should be logged as each step completes. After all these stpes are
// completed and logged, if needed, a new set of StartStep messages can
// be logged (for the same statement), for a new set of parallel steps.
// 6. Upon completion of each statement, an EndStatement msg should be logged.
// 7. Upon completion of each transaction, an EndTransaction msg should
// be logged.
//
// Some possible enhancements to simplify this profile logging for the
// application programmer:
//
// 1. Define enum or const ints in a common header file to represent the
// list of valid subSystem ids.
//
// 2. Add set of helper methods to MessageLog class to reduce the
// amount of work for the application. For example a method like:
//
// void logStartStatement ( int statement, int ver, string SQL );
//
// would allow the application to log a StartStatement by simply doing;
//
// Message msgStartStatement ( M0028 );
// int statementId = 11;
// int versionId = 22;
// string sql ("SELECT column1, column2 FROM table1 WHERE ...
// msgStartStatement.logStartStatement ( statementId, versionId, sql);
//
// 3. Could also do something similar to #2 except instead of adding helper
// methods to MessageLog, we could add specialized classes that derive
// from MessageLog or contain a MessageLog. One advantage of doing it
// this way is that a derived class like MessageLogStatement "could" be
// implemented to log the StartStatement, and its desctructor could then
// log the EndStatement automatically, on behalf of the application.
//
//------------------------------------------------------------------------------
void m5()
{
int subSystem = 5; // joblist subSystem
int session = 100;
int transaction = 1;
int thread = 0;
LoggingID lid1 ( subSystem, session, transaction, thread );
MessageLog msgLog ( lid1 );
Message::Args args;
// Log the start time of a transaction
Message msgStartTrans ( M0026 );
msgStartTrans.format ( args );
msgLog.logDebugMessage ( msgStartTrans );
// Log the start of execution time for a SQL statement
Message msgStartStatement ( M0028 );
int statementId = 11;
int versionId = 22;
string sql ("SELECT column1, column2 FROM table1 WHERE column1 = 345");
args.reset ( );
args.add ( statementId );
args.add ( versionId );
args.add ( sql );
msgStartStatement.format ( args );
msgLog.logDebugMessage ( msgStartStatement );
const string stepNames[] = { "steponeA", "steptwoA" ,"stepthreeA",
"stepfourB","stepfiveB","stepsixB" };
// To process this SQL statement, simulate executing 2 job steps,
// with each job step consisting of of 3 parallel primitive steps
for (int jobStep=0; jobStep<2; jobStep++)
{
int primStep1 = jobStep * 3;
// Log 3 parallel steps starting to execute
for (int i=primStep1; i<(primStep1+3); i++)
{
Message msgStartStep ( M0030 ); // Start Step
int stepId = i+1;
string stepName = stepNames[i];
args.reset ( );
args.add ( statementId );
args.add ( stepId );
args.add ( stepName );
msgStartStep.format ( args );
msgLog.logDebugMessage ( msgStartStep );
}
// Record I/O block count for 0 or more objects per step;
// for this example we just record I/O for 1 object per step.
// Then log the completion of each step.
for (int i=primStep1; i<(primStep1+3); i++)
{
Message msgBlockCount ( M0032 ); // I/O block count
int stepId = i+1;
int objectId = stepId * 20;
int phyCount = stepId * 30;
int logCount = phyCount + 5;
args.reset ( );
args.add ( statementId );
args.add ( stepId );
args.add ( objectId );
args.add ( phyCount );
args.add ( logCount );
msgBlockCount.format ( args );
msgLog.logDebugMessage ( msgBlockCount );
Message msgEndStep ( M0031 ); // End Step
args.reset ( );
args.add ( statementId );
args.add ( stepId );
msgEndStep.format ( args );
msgLog.logDebugMessage ( msgEndStep );
}
}
// Log the completion time of the SQL statement
Message msgEndStatement ( M0029 );
args.reset ( );
args.add ( statementId );
msgEndStatement.format ( args );
msgLog.logDebugMessage ( msgEndStatement );
// Log the completion time of the transaction
Message msgEndTrans ( M0027 );
args.reset ( );
args.add ( string("COMMIT") );
msgEndTrans.format ( args );
msgLog.logDebugMessage ( msgEndTrans );
Config::deleteInstanceMap();
}
