perfeval.c

Go to the documentation of this file.

/*
 *  This program is free software; you can redistribute it and/or
 *  modify it under the terms of the GNU General Public License
 *  as published by the Free Software Foundation; either version
 *  2 of the License, or (at your option) any later version.
 *
 *  Copyright 2004 Spiro Trikaliotis
 *
 */

#include <wdm.h>

#include "cbm_driver.h"

#include "../libiec/i_iec.h"

#ifdef PERFEVAL

#undef PERFEVAL_DEBUG 

#undef PERFEVAL_WRITE_TO_MEMORY


#ifdef PERFEVAL_DEBUG

    #define DBG_PRINT_REG( _xxx ) DBG_PRINT( _xxx )
    #define DBG_PRINT_FILE( _xxx ) DBG_PRINT( _xxx )

#else /* #ifdef PERFEVAL_DEBUG */

    #define DBG_PRINT_REG( _xxx )
    #define DBG_PRINT_FILE( _xxx )

#endif /* #ifdef PERFEVAL_DEBUG */

#define MAX_PERFORMANCE_EVAL_ENTRIES 0xffff

static PPERFORMANCE_EVAL_ENTRY PerformanceEvalEntries = NULL;

static ULONG CurrentPerformanceEvalEntry = -1;

static ULONG ProcessorFrequency = -1;

#pragma warning(push)
#pragma warning(disable:4035)

__forceinline __int64 RDTSC(void)
{
#ifdef USE_RDTSC
    __asm {
        // RDTSC
        _emit 0x0F
        _emit 0x31
    }
#else
    LARGE_INTEGER li;

    li = KeQueryPerformanceCounter(NULL);

    return li.QuadPart;
#endif
}
#pragma warning(pop)

VOID
PerfInit(VOID)
{
    FUNC_ENTER();

    DBG_ASSERT(PerformanceEvalEntries == NULL);
    DBG_ASSERT(CurrentPerformanceEvalEntry == -1);

    // Allocate memory for the entries

    PerformanceEvalEntries = (PPERFORMANCE_EVAL_ENTRY) ExAllocatePoolWithTag(NonPagedPool, 
        MAX_PERFORMANCE_EVAL_ENTRIES * sizeof(*PerformanceEvalEntries), MTAG_PERFEVAL);

    if (PerformanceEvalEntries)
    {
#ifdef USE_RDTSC

        UNICODE_STRING registryPath;
        NTSTATUS ntStatus;
        HANDLE handleRegistry;

        // Get the processor frequency from the registry. As Windows
        // already tried to calculate the frequency, do not try to
        // calculate it on my own, but rely on this.

        RtlInitUnicodeString(&registryPath, 
            L"\\REGISTRY\\MACHINE\\HARDWARE\\DESCRIPTION\\System\\CentralProcessor\\0");

        DBG_PRINT_REG((DBG_PREFIX "trying to open %wZ", &registryPath));
        ntStatus = cbm_registry_open_for_read(&handleRegistry, &registryPath);
        DBG_PRINT_REG((DBG_PREFIX "cbm_registry_open() returned %s", DebugNtStatus(ntStatus)));

        if (NT_SUCCESS(ntStatus))
        {
            ntStatus = cbm_registry_read_ulong(handleRegistry, L"~MHz", &ProcessorFrequency);
            DBG_PRINT_REG((DBG_PREFIX "cbm_registry_read() returned %s, value = %u", 
                DebugNtStatus(ntStatus), ProcessorFrequency));

            ntStatus = cbm_registry_close(handleRegistry);
            DBG_PRINT_REG((DBG_PREFIX "cbm_registry_close() returned %s", DebugNtStatus(ntStatus)));
        }

#else
        LARGE_INTEGER li;

        KeQueryPerformanceCounter(&li);

        DBG_ASSERT(li.HighPart == 0);
        ProcessorFrequency = li.LowPart;

#endif

        {
            unsigned int waitPeriod = 100;

            DBG_PRINT((DBG_PREFIX "Measuring time:"));
            PERF_EVENT_MEASURE_TIME(0);
            cbmiec_udelay(waitPeriod);
            PERF_EVENT_MEASURE_TIME(waitPeriod);
            DBG_PRINT((DBG_PREFIX "We waited %u us.", waitPeriod));
        }
    }

    FUNC_LEAVE();
}

VOID
PerfEvent(IN ULONG_PTR Event, IN ULONG_PTR Data)
{
    ULONG currentEntry;

    FUNC_ENTER();

    // only try to write if we successfully allocated a buffer!

    if (PerformanceEvalEntries)
    {
        // first of all, increment the entry number of the event
        // This makes sure that we are multiprocessor-safe, as 
        // we only write to the log after we have successfully
        // incremented the value.

        currentEntry = InterlockedIncrement(&CurrentPerformanceEvalEntry);

        if (currentEntry < MAX_PERFORMANCE_EVAL_ENTRIES)
        {
            PerformanceEvalEntries[currentEntry].Timestamp = RDTSC();
            PerformanceEvalEntries[currentEntry].Processor = CbmGetCurrentProcessorNumber();
            PerformanceEvalEntries[currentEntry].PeThread  = PsGetCurrentThread();
            PerformanceEvalEntries[currentEntry].Event = Event;
            PerformanceEvalEntries[currentEntry].Data = Data;
        }
        else
        {
            // If we incremented "out of the buffer", make sure
            // that we decrement the value back to where it was
            // before

            InterlockedDecrement(&CurrentPerformanceEvalEntry);
        }
    }

    FUNC_LEAVE();
}

typedef 
struct PERFEVAL_FILE_HEADER
{
    ULONG FileVersion;

    ULONG ProcessorFrequency;

    ULONG CountEntries;

} PERFEVAL_FILE_HEADER, *PPERFEVAL_FILE_HEADER;

VOID
PerfSynchronize(VOID)
{
    FUNC_ENTER();

    // Make sure to only output the entries if there are some

    DBG_ASSERT(((LONG)CurrentPerformanceEvalEntry) >= 0);

    if (PerformanceEvalEntries)
    {

#ifdef PERFEVAL_WRITE_TO_MEMORY

        __int64 FirstTimestamp;
        __int64 LastTimestamp;
        ULONG i;

        FirstTimestamp = PerformanceEvalEntries[0].Timestamp;
        LastTimestamp = FirstTimestamp;
        
        for (i = 0; i < CurrentPerformanceEvalEntry; i++)
        {
            __int64 tempTimeAbs;
            __int64 tempTimeRel;
            ULONG usTime;
            ULONG msTime;
            ULONG sTime;

            tempTimeAbs = (PerformanceEvalEntries[i].Timestamp - FirstTimestamp) / ProcessorFrequency;
            tempTimeRel = (PerformanceEvalEntries[i].Timestamp - LastTimestamp) / ProcessorFrequency;

            LastTimestamp = PerformanceEvalEntries[i].Timestamp;

            usTime = (ULONG) (tempTimeAbs % 1000);
            msTime = (ULONG) ((tempTimeAbs / 1000) % 1000);
            sTime = (ULONG) ((tempTimeAbs / 1000000) % 1000);

            DBG_PRINT((DBG_PREFIX 
                "%6u - Time: %3u.%03u.%03u us (+%7I64u us) - Event = %08x, Data = %08x"
                " on processur %u in thread %p",
                i,
                sTime, msTime, usTime,
                tempTimeRel,
                PerformanceEvalEntries[i].Event,
                PerformanceEvalEntries[i].Data,
                PerformanceEvalEntries[i].Processor,
                PerformanceEvalEntries[i].PeThread));
        }

        // make sure we start storing the performance values 
        // at the beginning again

        InterlockedExchange(&CurrentPerformanceEvalEntry, -1);

#else /* #ifdef PERFEVAL_WRITE_TO_MEMORY */

        IO_STATUS_BLOCK ioStatusBlock;
        OBJECT_ATTRIBUTES objectAttributes;
        UNICODE_STRING fileName;
        NTSTATUS ntStatus;
        HANDLE fileHandle;

        RtlZeroMemory(&objectAttributes, sizeof(objectAttributes));
        RtlInitUnicodeString(&fileName, L"\\??\\c:\\opencbm\\timing\\timing.dat");

        DBG_IRQL( == PASSIVE_LEVEL);
        InitializeObjectAttributes(&objectAttributes,
            &fileName,
            OBJ_CASE_INSENSITIVE ,
            NULL,
            NULL
        );

        ntStatus = ZwCreateFile(
                &fileHandle,
                FILE_APPEND_DATA | SYNCHRONIZE,
                &objectAttributes,
                &ioStatusBlock,
                NULL,
                FILE_ATTRIBUTE_NORMAL,
                0, 
                FILE_OPEN_IF,
                FILE_NON_DIRECTORY_FILE | FILE_SEQUENTIAL_ONLY | FILE_SYNCHRONOUS_IO_NONALERT,
                NULL,
                0
            );

        DBG_PRINT_FILE((DBG_PREFIX "ZwCreateFile returned %s", DebugNtStatus(ntStatus)));

        if (NT_SUCCESS(ntStatus))
        {
            PERFEVAL_FILE_HEADER fileHeader;

            fileHeader.FileVersion = 2
#ifndef _X86_
            | (1<<31);
#endif /* #ifndef _X86_ */
            ;

            fileHeader.ProcessorFrequency = ProcessorFrequency;
            fileHeader.CountEntries = CurrentPerformanceEvalEntry + 1;

            // the file has been opened; now, we can write to it

            ntStatus = ZwWriteFile(fileHandle, 
                NULL, // event
                NULL, // ApcRoutine
                NULL, // ApcContext
                &ioStatusBlock,
                &fileHeader,
                sizeof(fileHeader),
                NULL,
                NULL);

            DBG_PRINT_FILE((DBG_PREFIX "ZwWriteFile (header) returned %s",
                DebugNtStatus(ntStatus)));

            ntStatus = ZwWriteFile(fileHandle, 
                NULL, // event
                NULL, // ApcRoutine
                NULL, // ApcContext
                &ioStatusBlock,
                PerformanceEvalEntries,
                fileHeader.CountEntries * sizeof(*PerformanceEvalEntries),
                NULL,
                NULL);

            DBG_PRINT_FILE((DBG_PREFIX "ZwWriteFile (data) returned %s",
                DebugNtStatus(ntStatus)));

            ntStatus = ZwClose(fileHandle);

            DBG_PRINT_FILE((DBG_PREFIX "ZwCloseFile returned %s",
                DebugNtStatus(ntStatus)));

            // make sure we start storing the performance values 
            // at the beginning again

            InterlockedExchange(&CurrentPerformanceEvalEntry, -1);
        }

#endif /* #ifdef PERFEVAL_WRITE_TO_MEMORY */

    }

    FUNC_LEAVE();
}

VOID
PerfSave(VOID)
{
    FUNC_ENTER();

    if (PerformanceEvalEntries)
    {
        PVOID buffer;

        // write the event logs to where they should be written

        PerfSynchronize();

        // stop the event logging by writing the default values

        buffer = InterlockedExchangePointer(&PerformanceEvalEntries, NULL);
        InterlockedExchange(&CurrentPerformanceEvalEntry, -1);

        // free the previously allocated buffer.

        ExFreePool(buffer);
    }

    FUNC_LEAVE();
}

#endif /* #ifdef PERFEVAL */

---