// Copyright (c) 2005-2009 Nokia Corporation and/or its subsidiary(-ies).

// All rights reserved.

// This component and the accompanying materials are made available

// under the terms of the License "Eclipse Public License v1.0"

// which accompanies this distribution, and is available

// at the URL "http://www.eclipse.org/legal/epl-v10.html".

//

// Initial Contributors:

// Nokia Corporation - initial contribution.

//

// Contributors:

//

// Description:

// Kernel Performance Logger test

// Uses helper LDD for performing actual logging from the kernel side.

// See 

// 

//

/**

 @file

*/

#include <e32std.h>

#include <e32std_private.h>

#include <e32cons.h>

#include <e32test.h>

#include <e32math.h>

#include "t_perflogger.h"

#include "t_perflogger_drv.h"

//-------------------------------------------------------------------------------------

//-- logging subcategoty test tags

const TUint8    KLogSubCat_UserThread   = 0x11;

const TUint8    KLogSubCat_KernelThread = 0x12;

const TUint8    KLogSubCat_ISR          = 0x13;

const TUint8    KLogSubCat_IDFC         = 0x14;

//-------------------------------------------------------------------------------------

RTest   test(_L("T_PerfLogger"));

TInt64  rndSeed;

//-------------------------------------------------------------------------------------

/**

Print out the logging record.

@param aTraceLayout unrolled trace record structure

*/

void  PrintTraceRecord(const TTraceLayout& aTraceLayout)

	{

    TBuf<256> printBuf;

    printBuf.Format(_L("Record: Size:%d, Flags:0x%02x, Cat:%d, SubCat:%d "), aTraceLayout.iSize, aTraceLayout.iFlags, aTraceLayout.iCategory, aTraceLayout.iSubCategory);

    TUint flags = aTraceLayout.iFlags;

    if(flags&(BTrace::EHeader2Present))

        printBuf.AppendFormat(_L("Header2:0x%08x "), aTraceLayout.iHeader2);

    if(flags & (BTrace::ETimestampPresent))

        printBuf.AppendFormat(_L("Timestamp:0x%x "), aTraceLayout.iTimestamp);

    if(flags & (BTrace::ETimestamp2Present))

        printBuf.AppendFormat(_L("Timestamp2:0x%x "), aTraceLayout.iTimestamp2);

    if(flags & (BTrace::EContextIdPresent))

        printBuf.AppendFormat(_L("Context:0x%08x "), aTraceLayout.iContext);

    if(flags & (BTrace::EPcPresent))

        printBuf.AppendFormat(_L("PC: 0x%08x "),  aTraceLayout.iPC);

    if(flags & (BTrace::EExtraPresent))

        printBuf.AppendFormat(_L("Extra: 0x%08x "),  aTraceLayout.iExtra);

    printBuf.Append(_L("| "));

    for(TInt i=0; i< aTraceLayout.iDataWords; ++i)

		{

        printBuf.AppendFormat(_L(" 0x%08x"), aTraceLayout.ipData[i]);    

		}

    printBuf.Append(_L("\n"));

    test.Printf(printBuf);

	}

//-------------------------------------------------------------------------------------

/**

	Get logging trace from the kernel trace engine and optionally check if it corresponds to the 

	TTestLogCtrl structure fields. Actually, the logging trace in our case shall be the result of the 

	test helper LDD worr, that in turn, is controlled by the data in TTestLogCtrl structure.

  @param  aTrace          ref. to the kernel trace engine LDD.

  @param  apControlStruct if not NULL obtained trace fields checked against fields of this structure.

*/

void GetParseRecordData(RBTrace& aTrace, const TTestLogCtrl* apControlStruct = NULL)

	{

    TUint8*         record;

    TTraceLayout    traceLayout;

	for(TInt i=0; ;++i)

		{

        //-- get raw trace record

        TInt dataSize = aTrace.GetData(record);

        if(i != 0 && !dataSize)

            break; //-- no more data

        //-- check if we get log data at all at the very beginning

        if(i == 0 && !dataSize)

			{

			if(!apControlStruct)

				{//-- it's ok, no check

                break;

				}

            else

				{//-- panic if there is no log data, but we are required to get some.

                if(apControlStruct->iLogsNum > 0)

					{

                    test.Printf(_L("GetParseRecordData() No trace data found!\n"));

                    test(0);

					}

				}

			}

        TUint8* end = record+dataSize;

        TUint8* currPos = record;

		TUint nBytes = 0;

        //-- parser the record, print out fields and optionally check the correspondence to the fields of the control structure.

        for(; currPos<end; currPos+=nBytes)

			{

            nBytes = ParseTraceRecord(currPos ,traceLayout);

            test(nBytes >0 );

            //-- skip possible loggings that we didn't make

            if(traceLayout.iCategory != BTrace::EKernPerfLog)

                continue;

            ++nRecords;

            //-- print the record out

            PrintTraceRecord(traceLayout);

			//-- check the obtained record structure

			if(apControlStruct)

				{

				test(traceLayout.iCategory    == apControlStruct->iCategory);

				test(traceLayout.iSubCategory == apControlStruct->iSubCategory);

				if(traceLayout.iDataWords > 1)  //-- we have at least 1 word of user data (1 is for TickCount)

					test(traceLayout.ipData[0] == apControlStruct->iUserData);

				if(traceLayout.iDataWords > 2)  //-- we have 2 words of user data (1 is for TickCount)

					test(traceLayout.ipData[1] == apControlStruct->iUserData2);

				}

			}

		}

	}

//---------------------------------------------------------------------------------

/**

	Parse logging record, converting it from the raw representation to the unrolled data 

	structure.

	@param  apRecord     points to the buffer with the raw trace record

	@param  aTraceLayout here parsed record will bre returned

    @return sise of the record, bytes

*/

TUint  ParseTraceRecord(const TUint8* apRecord, TTraceLayout& aTraceLayout)

	{

    aTraceLayout.iSize          = apRecord[BTrace::ESizeIndex];    

    aTraceLayout.iFlags         = apRecord[BTrace::EFlagsIndex];

    aTraceLayout.iCategory      = apRecord[BTrace::ECategoryIndex];

    aTraceLayout.iSubCategory   = apRecord[BTrace::ESubCategoryIndex];

    const TUint flags= aTraceLayout.iFlags;   

	TInt size = aTraceLayout.iSize;

    const TUint32* pData = (const TUint32*)(apRecord+4);

    size -= 4; //-- count header

    //-- process header flags and appropriate fields of the record

    if(flags&(BTrace::EHeader2Present))

		{

        aTraceLayout.iHeader2 = *pData++;   

        size -= sizeof(TUint32);

        test(size >= 0);

		}

    if(flags & (BTrace::ETimestampPresent))

		{

        aTraceLayout.iTimestamp = *pData++;

        size -= sizeof(TUint32);

        test(size >= 0);

		}

    if(flags & (BTrace::ETimestamp2Present))

		{

        aTraceLayout.iTimestamp2 = *pData++;

        size -= sizeof(TUint32);

        test(size >= 0);

		}   

	if(flags & (BTrace::EContextIdPresent))

		{

		aTraceLayout.iContext = *pData++;

		size -= sizeof(TUint32);

        test(size >= 0);

		}

	if(flags & (BTrace::EPcPresent))

		{

		aTraceLayout.iPC = *pData++;	

		size -= sizeof(TUint32);

        test(size >= 0);

		}

	if(flags & (BTrace::EExtraPresent))

		{

		aTraceLayout.iExtra = *pData++;	

		size -= sizeof(TUint32);

        test(size >= 0);

		}

    //-- process user data if present

    test(size >= 0);

    test(size % sizeof(TUint32) == 0);

    aTraceLayout.iDataWords = size / sizeof(TUint32);

    aTraceLayout.ipData = (aTraceLayout.iDataWords!=0) ? pData : NULL;

    return aTraceLayout.iSize;

	}

//---------------------------------------------------------------------------------

//! @SYMTestCaseID          KBASE-T_PERFLOGGER-0055

//! @SYMTestType            UT

//! @SYMPREQ                PREQ1030

//! @SYMTestCaseDesc        Tests logging from different contexts: user thread, ISR, Kernel thread and IDFC. 

//!                         The main functionality is performed by test heller LDD, "d_perflogger_test" that acually calls the logging function from different contexts 

//!                         following the commands from user application.

//!

//! @SYMTestActions         0   setup the data structures that specify the logging parameters.

//!                         1   call RKPLoggerTestHelper::MakeLogFromUserThread() this is a synchronous operation. Performs logging from the user thread context.

//!                         1.1 Parse the log record data and ensure that the logged information matches the data we passed to the helper LDD.

//!

//!                         2   call RKPLoggerTestHelper::MakeLogFromISR() this is asynchronous operation. Performs logging from the ISR context.

//!                         2.1 Wait for operation to complete, validate the completion status.

//!                         2.2 Parse the log record data and ensure that the logged information matches the data we passed to the helper LDD.

//!

//!

//!                         3   call RKPLoggerTestHelper::MakeLogFromDFC() this is asynchronous operation. Performs logging from the Kernel thread context (DFC).

//!                         3.1 Wait for operation to complete, validate the completion status.

//!                         3.2 Parse the log record data and ensure that the logged information matches the data we passed to the helper LDD.

//!

//!                         4   call RKPLoggerTestHelper::MakeLogFromIDFC() this is asynchronous operation. Performs logging from the IDFC.

//!                         4.1 Wait for operation to complete, validate the completion status.

//!                         4.2 Parse the log record data and ensure that the logged information matches the data we passed to the helper LDD.

//!

//!                         5.  Make scattered overlapped logging from ISR, DFC & IDFC simultaneously, ensure that this work.

//!

//! @SYMTestExpectedResults return if the performace logger behaves as expected, panic otherwise

//! @SYMTestPriority        High

//! @SYMTestStatus          Implemented

//---------------------------------------------------------------------------------

void TestPerfLogger(RBTrace &aTrace)

	{

    TInt    nRes;

    const TUint32   KLogUserData  = 0xBAAABEEF; //-- just for testing

    const TUint32   KLogUserData2 = 0x11FFDDCC; //-- just for testing

    test.Next(_L("testing kernel performance logger functionality\n"));

    RKPLoggerTestHelper testHelperLDD;  //-- helper test driver

    CleanupClosePushL(testHelperLDD);

    nRes = testHelperLDD.Open(TVersion(1,0,1)); //-- open test helper ldd for a logger

    test(nRes == KErrNone);

    //---

    TTestLogCtrl   logCtrl_UserThread;

    TTestLogCtrl   logCtrl_ISR;

    TTestLogCtrl   logCtrl_DFC;

    TTestLogCtrl   logCtrl_IDFC;

    TRequestStatus rqStatLogFromISR;

    TRequestStatus rqStatLogFromDFC;

    TRequestStatus rqStatLogFromIDFC;

    //-- setup log control structures

    logCtrl_UserThread.iLogsNum     = 3;

    logCtrl_UserThread.iCategory    = BTrace::EKernPerfLog;

    logCtrl_UserThread.iSubCategory = KLogSubCat_UserThread;

    logCtrl_UserThread.iUserData    = KLogUserData;

    logCtrl_UserThread.iUserData2   = KLogUserData2;

    logCtrl_ISR.iLogsNum        = 3;

    logCtrl_ISR.iCategory       = BTrace::EKernPerfLog;

    logCtrl_ISR.iSubCategory    = KLogSubCat_ISR;

    logCtrl_ISR.iUserData       = KLogUserData;

    logCtrl_ISR.iUserData2      = KLogUserData2;

    logCtrl_DFC.iLogsNum        = 3;

    logCtrl_DFC.iCategory       = BTrace::EKernPerfLog;

    logCtrl_DFC.iSubCategory    = KLogSubCat_KernelThread;

    logCtrl_DFC.iUserData       = KLogUserData;

    logCtrl_DFC.iUserData2      = KLogUserData2;

    logCtrl_IDFC.iLogsNum       = 3;

    logCtrl_IDFC.iCategory      = BTrace::EKernPerfLog;

    logCtrl_IDFC.iSubCategory   = KLogSubCat_IDFC;

    logCtrl_IDFC.iUserData      = KLogUserData;

    logCtrl_IDFC.iUserData2     = KLogUserData2;

    test.Printf(_L("Testing logging from user thread\n"));

    //============================================================

    //-- 1. make logging from user thread, this is a synchronous operation

    nRes = testHelperLDD.MakeLogFromUserThread(logCtrl_UserThread);

    test(nRes == KErrNone);

    //-- 1.1 check the results

    GetParseRecordData(aTrace, &logCtrl_UserThread);

    test.Printf(_L("Testing logging from ISR\n"));

    //============================================================

    //-- 2. make logging from ISR, this is asynchronous operation

    testHelperLDD.MakeLogFromISR(rqStatLogFromISR, logCtrl_ISR);

    User::WaitForRequest(rqStatLogFromISR);

    test(rqStatLogFromISR.Int() == KErrNone);

    //-- 2.1 check the results

    GetParseRecordData(aTrace, &logCtrl_ISR);

    test.Printf(_L("Testing logging from DFC\n"));

    //============================================================

    //-- 3. make logging from DFC kennel thread, this is asynchronous operation

    testHelperLDD.MakeLogFromDFC(rqStatLogFromDFC, logCtrl_DFC);

    User::WaitForRequest(rqStatLogFromDFC);

    test(rqStatLogFromDFC.Int() == KErrNone);

    //-- 3.1 check the results

    GetParseRecordData(aTrace, &logCtrl_DFC);

    test.Printf(_L("Testing logging from IDFC\n"));

    //============================================================

    //-- 4. make logging from IDFC, this is asynchronous operation

    testHelperLDD.MakeLogFromIDFC(rqStatLogFromIDFC, logCtrl_IDFC);

    User::WaitForRequest(rqStatLogFromIDFC);

    test(rqStatLogFromIDFC.Int() == KErrNone);

    //-- 4.1 check the results

    GetParseRecordData(aTrace, &logCtrl_IDFC);

    test.Printf(_L("Testing overlapped logging from ISR, DFC & IDFC\n"));

    //============================================================

    //-- 5. make logging from ISR, DFC and IDFC simultaneously

    //-- use random numbers for number and period of loggings  

    logCtrl_ISR.iLogsNum        = URnd(16)+1;

    logCtrl_ISR.iLogPeriodTick  = URnd(20)+1;

    logCtrl_DFC.iLogsNum        = URnd(16)+1;

    logCtrl_DFC.iLogPeriodTick  = URnd(20)+1;

    logCtrl_IDFC.iLogsNum       = URnd(16)+1;

    logCtrl_IDFC.iLogPeriodTick = URnd(20)+1;

    //-- start logging

    testHelperLDD.MakeLogFromISR(rqStatLogFromISR, logCtrl_ISR);

    testHelperLDD.MakeLogFromDFC(rqStatLogFromDFC, logCtrl_DFC);

    testHelperLDD.MakeLogFromIDFC(rqStatLogFromIDFC, logCtrl_IDFC);

    //-- wait for logging to finish

    User::WaitForRequest(rqStatLogFromISR);

    User::WaitForRequest(rqStatLogFromDFC);

    User::WaitForRequest(rqStatLogFromIDFC);

    GetParseRecordData(aTrace);

    CleanupStack::PopAndDestroy(1); //-- testHelperLDD

}

//---------------------------------------------------------------------------------

//! @SYMTestCaseID          KBASE-T_PERFLOGGER-0056

//! @SYMTestType            UT

//! @SYMPREQ                PREQ1030

//! @SYMTestCaseDesc        Test of PERF_LOG0, PERF_LOG1, PERF_LOG macros performed by helper LDD

//! @SYMTestActions         Calls helper LDD API that in turn implies using PERF_LOG0, PERF_LOG1, PERF_LOG macros by helper LDD

//! @SYMTestExpectedResults return if the performace logger behaves as expected, panic otherwise

//! @SYMTestPriority        High

//! @SYMTestStatus          Implemented

//---------------------------------------------------------------------------------

void TestMacros(RBTrace &aTrace)

	{

    TInt    nRes;

    const TUint32   KLogUserData  = 0xBAAABEEF; //-- just for testing

    const TUint32   KLogUserData2 = 0x11FFDDCC; //-- just for testing

    test.Next(_L("Unit test for different macros\n"));

    RKPLoggerTestHelper testHelperLDD;  //-- helper test driver

    CleanupClosePushL(testHelperLDD);

    nRes = testHelperLDD.Open(TVersion(1,0,1)); //-- open test helper ldd for a logger

    test(nRes == KErrNone);

    //---

    TTestLogCtrl   logCtrl;

    //-- setup log control structures

    logCtrl.iLogsNum     = 1;

    logCtrl.iCategory    = BTrace::EKernPerfLog;

    logCtrl.iSubCategory = KLogSubCat_UserThread;

    logCtrl.iUserData    = KLogUserData;

    logCtrl.iUserData2   = KLogUserData2;

    //-- make logging from user thread using different macros, PERF_LOG0, PERF_LOG1, PERF_LOG 

    //-- see the helper driver

    nRes = testHelperLDD.TestDifferentMacros(logCtrl);

    test(nRes == KErrNone);

    //-- print out the results

    GetParseRecordData(aTrace);

    CleanupStack::PopAndDestroy(1); //-- testHelperLDD

	}

//---------------------------------------------------------------------------------

void MainL(void)

	{

    test.Start(_L("Kern Perf Logger tests"));

    Initialise();

    RBTrace trace;

	TInt error = trace.Open();

    test(error == KErrNone);

	trace.Empty();

	trace.SetFilter(BTrace::EThreadIdentification,0);

    //-- actually, for hardware platforms, the testing category and trace enabling 

    //-- may be set up in appropriate "header.iby" file

    trace.SetMode(RBTrace::EEnable);

    trace.SetFilter(BTrace::EKernPerfLog, ETrue);

    //-- unit-test for PERF_LOG macros

    TestMacros(trace);

    //-- functionality test

    TestPerfLogger(trace); 

    trace.Close();

    Finalise();

	test.End();

	}

//---------------------------------------------------------------------------------

//! @SYMTestCaseID          KBASE-T_PERFLOGGER-0162

//! @SYMTestType            UT

//! @SYMPREQ                PREQ1030

//! @SYMTestCaseDesc        Load test helper LDD and check the result

//! @SYMTestActions         load specified LDD by calling User::LoadLogicalDevice()

//! @SYMTestExpectedResults return if helper LDD is loaded OK, panic otherwise

//! @SYMTestPriority        High

//! @SYMTestStatus          Implemented

//---------------------------------------------------------------------------------

void Initialise()

	{

    rndSeed = Math::Random();

    //-- load device drivers 

    TInt nRes;

    test.Printf(_L("Loading test helper LDD...\n"));

    nRes = User::LoadLogicalDevice(KPLoggerHelperTestDrv);

    test(nRes == KErrNone || nRes == KErrAlreadyExists);

	}