Click here to Skip to main content
12,558,909 members (31,558 online)
Click here to Skip to main content
Add your own
alternative version


26 bookmarked

Logging Class with QueryPerformanceCounter

, 24 May 2006 CPOL
Rate this:
Please Sign up or sign in to vote.
Logging class with high performance timer and background thread Synchronise Sleep


I needed a class to very quickly log lines of text to a file in a multi threaded application. In addition, I needed to record the exact time of the log (accurate to 1 micro second) in the log file.

The recording needs to be very fast so the text to be written is placed on a queue and is written to disc on another worker thread, hence even busy disc performance does not slow the important recording thread. Minimal locks keep the record to queue operation as fast as possible.

DateTime.Now returns a time accurate to only about 20ms. To get better accuracy, this code uses the High Performance Timer and adjusts the tick count to match up with the DateTime. This is done by building a small table recording the HP Ticks and DateTime Ticks after sleep operations, and then using linear interpolation to calculate the DateTime at the record time. The table building and interpolation take place on the non critical worker thread. Recording DateTime after sleep operations gives a DateTime that corresponds to the actual time with minimal inaccuracy (see other articles about accurate clock times in the Windows OS).

This method of calling only QueryPerformanceCounter and then converting this long to an accurate date time string on the non critical thread gives the best possible performance. The times will always be increasing even for small changes in DateTime (e.g. NTP clock adjustments) because any adjustment in the clock is spread out over the sleep time. The HP counter rolls every 90 years or at reboot hence no check for that. 

Performance on my machine - a thread looping continuously can log every 2 micro seconds. This code is fully tested and used in production on my 4 processor box.

using System; 
using System.Threading;
using System.Collections;
using System.IO;
using System.Runtime.InteropServices;
public class FastFileWriter
    private class Item
    { // class for holding data items on the write queues
        public long time=0; // This is the High Performance Timer time
        public string text; // This is the line of text to write to the file
private int qActive; // three write queues for incoming data
private Queue[] q = new Queue[3];
private int timePosition; // an array of HP Timer Tick vs DateTime Ticks at sync points
private int timeSearchBelow, timeSearchAbove; // which we search at file 
                                              // write time in order 
private long[,] timeArray=new long[5,2]; // to assign a DateTime to any given HP time
private StreamWriter outfile; // The file we write to
private Thread thread; // The thread on which we write to the file
[DllImport("kernel32.dll")] // The High Performance Timer System Call
static extern int QueryPerformanceCounter(ref long x);
public FastFileWriter(string filename, bool append)
    // create the outfile, exception on error
    try { outfile = new StreamWriter(filename, append); }
    catch { throw new Exception("Could not open the log file: "+filename); }
    // setup our queues
    q[0]=new Queue();
    q[1]=new Queue();
    q[2]=new Queue();
    // fill in the first point in the timerArray
    // timeArray[0,0] is the HP Timer ticks
    // timeArray[0,1] is the corresponding DateTime ticks
    timeSearchBelow=0; timeSearchAbove=1;
    QueryPerformanceCounter(ref timeArray[timePosition,0]);
    thread = new Thread(new ThreadStart(this.Run));
public void Write(string s) // Fast Write safe for multi threaded calls
    Item item=new Item();
    lock(this) // here we need a lock... 
        QueryPerformanceCounter(ref item.time); //move outside if you run 4 queues
private void Run() // The worker thread which writes to the file
    while (true)
        Thread.Sleep(10000); // Change this to 100 seconds (100000) or as desired
        // sync time
        QueryPerformanceCounter(ref timeArray[timePosition,0]); // read this first 
                                                          //because it changes quickly
        timeArray[timePosition,1]=DateTime.Now.Ticks; // read this seconds because it 
                                                      // only changes slowly
        // write a dummy to the queue so it's never completely empty
        Write(""); // so even if no data arrives for a long time the 
                    // timerArray does not fill up
        // swap incoming messages to the next queue
        lock(this) // here we need a lock... but it's just over one line of code
	   if (++qActive>2) qActive=0; }
	   // flush the oldest queue
	   Queue qOld; if (qActive>=2) qOld=q[0]; else qOld=q[qActive+1];
	   // clean up the timerArray list by deleting old times from the bottom
	   // note time in other queues will all be > the last time read
    private void Flush(Queue qOld)
        while ( qOld.Count > 0 )
            Item item= (Item) qOld.Dequeue();
	   DateTime t=new DateTime( GetDateTime( item.time ) );
	   if (item.text!="") outfile.WriteLine( t.ToString
			("yyyy-MM-dd HH:mm:ss.ffffff") +"|"+item.text );
    private long GetDateTime(long tHP)
        // reads the timeArray to find the DateTime.Ticks at the given HPC time
        // there must always be a higher and lower entry in the timerArray or 
        // this code will crash
        // it's for this reason that we need to maintain three write queues
        while (true)
            if (tHP>=timeArray[timeSearchBelow,0] && tHP<=timeArray[timeSearchAbove,0])
            { // the enquired time is between timeSearchBelow and timeSearchAbove
                double diff_tHP= tHP-timeArray[timeSearchBelow,0];
                double diff_HPHP= timeArray[timeSearchAbove,0]-
                double diff_DTDT= timeArray[timeSearchAbove,1]-
                long offset= Convert.ToInt64(diff_tHP*diff_DTDT/diff_HPHP);
                return offset+timeArray[timeSearchBelow,1];
            { // need to change timeSearchBelow and timeSearchAbove
                if ( tHP>timeArray[timeSearchAbove,0])
                { // move up
                    timeSearchAbove++; // will crash out of bounds if no higher entry
                { // move down
                    timeSearchBelow--; // will crash out of bounds if no lower entry
    private void CleanUpTimeArray()
        while (true)
            if (timeSearchBelow>0)
            { // if timeSearchBelow>0 then shift all the subsequent entries down
                for (int i=1; i<timePosition; i++)
    public void Dispose()
    { // Call to flush all the queues and end the worker thread
        lock (this)
        { // Lock in case someone tries to write after calling dispose
            // sync time
            QueryPerformanceCounter(ref timeArray[timePosition,0]); 
            // Flush all the queues
       // Close File


This article, along with any associated source code and files, is licensed under The Code Project Open License (CPOL)


About the Author

You may also be interested in...

Comments and Discussions

GeneralBetter way... Pin
w.hooper15-Apr-09 22:51
memberw.hooper15-Apr-09 22:51 
GeneralSomething to keep in mind... Pin
Stonie19-Dec-06 15:14
memberStonie19-Dec-06 15:14 
Generalwrite frequency Pin
wwbach13-Jul-06 4:35
memberwwbach13-Jul-06 4:35 
GeneralRe: write frequency Pin
williammorrishooper13-Jul-06 5:07
memberwilliammorrishooper13-Jul-06 5:07 
GeneralMissing ")" Pin
wwbach24-May-06 6:44
memberwwbach24-May-06 6:44 
NewsUnsafe for Multiple or hyperthreaded CPUs Pin
TekCat23-May-06 9:41
memberTekCat23-May-06 9:41 
GeneralRe: Unsafe for Multiple or hyperthreaded CPUs [modified] Pin
williammorrishooper23-May-06 19:20
memberwilliammorrishooper23-May-06 19:20 
GeneralRe: Unsafe for Multiple or hyperthreaded CPUs [modified] Pin
TekCat24-May-06 5:01
memberTekCat24-May-06 5:01 
GeneralRe: Unsafe for Multiple or hyperthreaded CPUs [modified] Pin
williammorrishooper24-May-06 21:32
memberwilliammorrishooper24-May-06 21:32 
GeneralRe: Unsafe for Multiple or hyperthreaded CPUs [modified] Pin
Scope25-May-06 4:10
memberScope25-May-06 4:10 
GeneralRe: Unsafe for Multiple or hyperthreaded CPUs [modified] Pin
TekCat29-May-06 10:25
memberTekCat29-May-06 10:25 
GeneralGreat article Pin
hillgoat19-May-06 8:21
memberhillgoat19-May-06 8:21 

General General    News News    Suggestion Suggestion    Question Question    Bug Bug    Answer Answer    Joke Joke    Praise Praise    Rant Rant    Admin Admin   

Use Ctrl+Left/Right to switch messages, Ctrl+Up/Down to switch threads, Ctrl+Shift+Left/Right to switch pages.

| Advertise | Privacy | Terms of Use | Mobile
Web01 | 2.8.161026.1 | Last Updated 25 May 2006
Article Copyright 2006 by w.hooper
Everything else Copyright © CodeProject, 1999-2016
Layout: fixed | fluid