Click here to Skip to main content
11,412,516 members (72,829 online)
Click here to Skip to main content

A Simple C++ Function Call Stack Trace Utility

, 10 Feb 2006 CPOL
Rate this:
Please Sign up or sign in to vote.
How to record your function call stack for debug purposes

Introduction

Under UNIX/Linux platform, program coredump generates a core file, we can analyze the core file and determine what's wrong in our program. The core file records the function call stack (e.g. under gdb you can use bt command to see backtrace), that is mostly information for us to troubleshooting.

When I debug my program, I try to record the function call stack in program debug log to help me diagnose the program's defect. Fortunately, C++ gives us a simple way to implement this.

Rational

Just use C++ constructor/destructor semantic, we can make our own trace class. At the function entrance, we declare a local variable, it will invoke the constructor immediately, when leaving the function, the local variable will be destroyed and call destructor. That's all. what we need to do is implement a class's constructor and destructor. This rational is simple enough, but this way sometimes can help us a lot.

The complete code is as follows:

// trace.hpp
#include <stdio.h>
#include <stdlib.h>
#include <time.h>
#include <stdarg.h>
#include <string>

#define CM_TRACE_FILE(trace_file)	cm::Trace::LogToFile(trace_file)

#define CM_TRACE_FUNC(func_name)    cm::Trace __CM_TRACE__(func_name, "()")
#define CM_TRACE_FUNC_ARG1(func_name, argfmt, arg)   \
            cm::Trace __CM_TRACE__(func_name, argfmt, arg)
#define CM_TRACE_FUNC_ARG2(func_name, argfmt, arg1, arg2)   \
            cm::Trace __CM_TRACE__(func_name, argfmt, arg1, arg2)
// more macros define....

namespace	cm
{
    class	Trace
    {
    public:
    	explicit Trace(char *func_name, const char* argsfmt, ...)
    	{
            char fmt[256] ={0};
            sprintf(fmt, "%s%s", func_name, argsfmt);
    	    va_list arglist;
    	    va_start(arglist, argsfmt);
    		LogMsg(depth_, depth_ * 2, fmt,  arglist);
    		va_end(arglist);
    		++depth_;
    	}

    	~Trace()
    	{
    		--depth_;
    	}

    	/// special the global log file.
    	void static LogToFile(const char *trace_file)
    	{
    		trace_file_ = trace_file;
    	}

    private:
    	void LogMsg(int depth, int align, const char *fmt, va_list args)
    	{
    		FILE	*fp = fopen(trace_file_.c_str(), "a+");
    		if (fp == NULL)
    		{
    			return;
    		}


    		time_t		curTime;
    		time(&curTime);

    		char	timeStamp[32] = { 0 };
    		strftime(timeStamp, sizeof(timeStamp), 
				"%Y%m%d.%H%M%S", localtime(&curTime));

    		// only log the timestamp when the time changes
    		unsigned int len = fprintf( fp, "%s %*.*s> (%d)",
    				(last_invoke_time_ != curTime) ? 
				timeStamp : "               ",
    				2 * depth,
    				2 * depth,
    				nest_,
    				depth);
    		last_invoke_time_ = curTime;
    		len += vfprintf(fp, fmt, args);
    		len += fwrite("\n", 1, 1, fp);
    		fflush(fp);
    		fclose(fp);
    	}

    private:
    	// the debug trace filename
    	static std::string	trace_file_;

    	// function call stack depth
    	static int			depth_;
    	static const char*  nest_;
    	static time_t       last_invoke_time_;
    };

    std::string Trace::trace_file_  = "";
    int         Trace::depth_       = 0;

    // arbitrarily support nesting 34 deep for no particular reason
    const char* Trace::nest_        = 
	"| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | ";
    time_t      Trace::last_invoke_time_ = 0;
}	// end namespace cm
#endif // CM_TRACE_20060209_HPP

Using the Code

First you need to call CM_TRACE_FILE() to special debug log filename, then at function entrance, call CM_TRACE(). Here is an example.

#include "cm/trace.hpp"

void foo()
{
	CM_TRACE_FUNC("foo");
}

void bar(int x)
{
	CM_TRACE_FUNC_ARG1("bar", "(%d)", x);
	foo();
}

void foobar(int x, const char* s)
{
    CM_TRACE_FUNC_ARG2("foobar", "(%d, %s)", x, s);
    bar(789);
}

void foobar3(int x, int y, double z)
{
    CM_TRACE_FUNC_ARG3("foobar3", "(%d, %d, %f)", x, y, z);
    foobar(123, "4546");
}

int main()
{
    CM_TRACE_FILE("./trace.log");
    CM_TRACE_FUNC("main");
    foo();
    bar(23);
    foobar(33, "char");
    foobar3(12, 23, 34.45);
    return 0;
}

Then open `trace.log', use your favourite editor. At the end of file, you will see the following:

20060211.132431 > (0)main()
                | > (1)foo()
                | > (1)bar(23)
                | | > (2)foo()
                | > (1)foobar(33, char)
                | | > (2)bar(789)
                | | | > (3)foo()
                | > (1)foobar3(12, 23, 34.450000)
                | | > (2)foobar(123, 4546)
                | | | > (3)bar(789)
                | | | | > (4)foo()

Conclusion

The rational in this article is simple, but we can write simple code do useful things.

Revision History

  • v1.00 Feb 4, 2005. Mockey
    • Original article
  • v1.01 Feb 11 2005. Mockey
    • Change fstream to FILE*
    • Change string to sprintf for more efficiency. Thanks Jon Wold's comment
    • Rename CM_TRACE to CM_TRACE_FUN and add CM_TRACE_FUN_ARGx macros.
    • Add feature to log the function call arguments.

License

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

Share

About the Author

Mockey Chen

China China
Mockey is a C++ programmer, experienced with C/C++ program under UNIX platform, his primarily research field is communication program for telecom. He works for one of china's biggest telecom equipment supplier until Dec 2006.

He's current interest is Linux kernel programming, especial in networking hack.

Mockey lives in Chengdu, China. To contact Mockey, email at mockey.chen@gmail.com

Comments and Discussions

 
Questioncan any one explain me what is that __CM_TRACE__ Pin
online@ilovec.in at 22-Jan-13 20:51
memberonline@ilovec.in22-Jan-13 20:51 
AnswerRe: can any one explain me what is that __CM_TRACE__ Pin
Member 11124629 at 10-Mar-15 10:00
memberMember 1112462910-Mar-15 10:00 
Generalany idea for win32 C dll trace log. Pin
fredguo at 1-Mar-09 7:33
memberfredguo1-Mar-09 7:33 
Generalbug.. Pin
dheerajkhajuria at 8-Jul-07 7:17
memberdheerajkhajuria8-Jul-07 7:17 
GeneralRe: bug.. Pin
Mockey Chen at 8-Jul-07 16:29
memberMockey Chen8-Jul-07 16:29 
GeneralCM_TRACE_FUNC_ARG3("foobar3", "(%d, %d, %s)", x, y, 100); Pin
Pham Thanh Toan at 3-Jan-07 7:57
memberPham Thanh Toan3-Jan-07 7:57 
GeneralRe: CM_TRACE_FUNC_ARG3("foobar3", "(%d, %d, %s)", x, y, 100); Pin
Mockey Chen at 6-Jan-07 1:48
memberMockey Chen6-Jan-07 1:48 
Generalsprintf is declared as deprecated Pin
DevianT (rus) at 21-Feb-06 14:27
memberDevianT (rus)21-Feb-06 14:27 
GeneralRe: sprintf is declared as deprecated Pin
Nemanja Trifunovic at 21-Feb-06 14:46
memberNemanja Trifunovic21-Feb-06 14:46 
GeneralRe: sprintf is declared as deprecated Pin
DevianT (rus) at 21-Feb-06 21:21
memberDevianT (rus)21-Feb-06 21:21 
Generalsome advice Pin
thog at 14-Feb-06 17:27
memberthog14-Feb-06 17:27 
GeneralRe: some advice Pin
Gavriloaie Andrei at 26-Oct-07 23:54
memberGavriloaie Andrei26-Oct-07 23:54 
Generalscope logger Pin
Paulius Maruška at 14-Feb-06 15:17
memberPaulius Maruška14-Feb-06 15:17 
GeneralNot a stack trace Pin
Scope at 12-Feb-06 17:08
memberScope12-Feb-06 17:08 
Generalminor comments ... Pin
Jon Wold at 7-Feb-06 6:44
memberJon Wold7-Feb-06 6:44 
GeneralRe: minor comments ... Pin
Mockey Chen at 10-Feb-06 19:53
memberMockey Chen10-Feb-06 19:53 
GeneralAnd throwing in a couple of VC++ macros... Pin
eTurtle at 7-Feb-06 1:19
membereTurtle7-Feb-06 1:19 
GeneralRe: And throwing in a couple of VC++ macros... Pin
Mockey Chen at 7-Feb-06 5:32
memberMockey Chen7-Feb-06 5:32 
GeneralRe: And throwing in a couple of VC++ macros... Pin
Pavel Vozenilek at 13-Feb-06 19:54
memberPavel Vozenilek13-Feb-06 19:54 
GeneralCool Pin
FocusedWolf at 6-Feb-06 13:46
memberFocusedWolf6-Feb-06 13:46 
GeneralRe: Cool Pin
Mockey Chen at 7-Feb-06 13:18
memberMockey Chen7-Feb-06 13:18 

General General    News News    Suggestion Suggestion    Question Question    Bug Bug    Answer Answer    Joke Joke    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.150427.1 | Last Updated 11 Feb 2006
Article Copyright 2006 by Mockey Chen
Everything else Copyright © CodeProject, 1999-2015
Layout: fixed | fluid