Sign in to follow this  
CDProp

Strange exception (C++, VS2008)

Recommended Posts

CDProp    1451
Hi. I'm getting an exception, but I can't really figure out what the problem is, and I'm hoping someone can help. A little background info first. The exception is occurring in code that is defined in a DLL. I compiled the DLL myself. The problem is, the exception only happens when the DLL is compiled in Release mode. Therefore, when the exception occurs, it doesn't allow me to actually see the line of code that caused the exception. Instead, it just breaks on whatever line of code originally called the DLL method, and I can't step into it. Thanks to help from Sneftel on FB, I was able to compile the DLL in release mode, with debugging info, without optimizations. Now, when the exception occurs, it takes me to the line of code that caused the exception. The only problem is, I can't see why it is causing an exception. Usually I'm looking for a dereferenced null pointer, or something like that. But that's not what I have here. I'm curious to know if anyone can tell what my problem is by the information I provide. First, some pseudo-code (which will be easier to illustrate what I'm doing; I'll provide the full source at the end of this post).
class QTimer
{
	std::string name;
public:
	QTimer(std::string _name);
	~QTimer();

	void Start();
	void Stop();

	friend class Profiler;
};

typedef std::list<QTimer*> TimerList;

class Profiler
{
	TimerList timers;

	QTimer* findTimer(std::string name)
	{
		TimerList::iterator itr = timers.begin(), end = timers.end();

		while(itr != end)
		{
			if((*itr)->name == name)
				return (*itr);
		}

		return NULL;
	}

public:
	Profiler();
	~Profiler();

	void BeginTimer(std::string name);
	void EndTimer(std::string name)
	{
		QTimer *t = findTimer(name);
		t->Stop(); // exception occurs here!
	}
};





Ok, so this is more or less C++ code, but the classes are greatly simplified. So, I've highlighted where the exception occurs, and I can see that, if t were NULL, I'd get a crash. I should be checking for that (and I do now, as you'll see in the source code that follows). But that's not what is happening here. When I step into findTimer(): - I can see the timers list, and can verify that the timer it is looking for is in that list. - I can see that it's iterating through the timers, and doing the string comparison (which entails dereferencing the pointer). - I can see that the comparison passes, and that the function returns the pointer, not NULL But then, of course, the findTimer method returns, the return value is assigned to t, t is dereferenced, and the exception occurs:
Unhandled exception at 0x0046f9c8 (myDll.dll) in MyProgram.exe: 0xC0000005: Access violation reading location 0x7587c1ac
I've tried stepping through the disassembly, but it's incomprehensible to me. I can step through the source code, but I can't really watch any of the variables (so I can't, for instance, verify that t has the same value that is returned by findTimer). Here is my full source code, as it currently stands:
#ifndef _PROFILE_H_
#define _PROFILE_H_

#include <list>
#include <string>
#include <fstream>
#include <windows.h>
#include <assert.h>
#include <osgViewer/Export>

inline void Profile_Get_Ticks(_int64 * ticks)
{
      __asm
      {
            push edx;
            push ecx;
            mov ecx,ticks;
            _emit 0Fh
            _emit 31h
            mov [ecx],eax;
            mov [ecx+4],edx;
            pop ecx;
            pop edx;
      }
}

class OSGVIEWER_EXPORT QTimer
{
	std::string		name;
	__int64			frequency, start_time;
	double			total_seconds, avg_fps, avg_mspf;
	int				num_frames;
	bool			counting;

public:
	QTimer(std::string _name)
		:	name(_name),
			num_frames(0),
			avg_fps(0.0),
			avg_mspf(0.0),
			total_seconds(0.0)
	{
		QueryPerformanceFrequency((LARGE_INTEGER*)&frequency);
	}

	void Start()
	{
		Profile_Get_Ticks(&start_time);
	}

	void Stop()
	{
		__int64 stop_time;
		Profile_Get_Ticks(&stop_time);

		double delta_seconds = ((double)stop_time - (double)start_time) / (double)frequency;
		total_seconds += delta_seconds;

		++num_frames;

		avg_fps = (double)num_frames / total_seconds;
		avg_mspf = 1000.0 / avg_fps;
	}

	void outputTXT(std::ofstream &file)
	{
		file << name << "[ frames: " << num_frames << ", avg_mspf: " << avg_mspf << ", avg_fps: " << avg_fps << ", total_seconds: " << total_seconds << " ]" << std::endl;
	}

	void outputCSV(std::ofstream &file)
	{
		file << name << "," << num_frames << "," << avg_mspf << "," << avg_fps << "," << total_seconds << std::endl;
	}

	bool operator< (QTimer &rhs)
	{
		return (this->name.compare(rhs.name) < 0);
	}

	friend class Profiler;
};

typedef std::list<QTimer*> TimerList;
typedef std::list<std::string> StackTrace;

class OSGVIEWER_EXPORT Profiler
{
	TimerList	timers;
	StackTrace	stack;
	std::string outputFileName;

	std::string getFullName(std::string name)
	{
		std::string full_name = "";

		StackTrace::iterator si = stack.begin(), se = stack.end();

		while(si != se)
		{
			full_name += *si;
			full_name += "=>";
			++si;
		}

		full_name += name;

		return full_name;
	}

	QTimer* findTimer(std::string full_name)
	{
		TimerList::iterator ti = timers.begin(), te = timers.end();

		while(ti != te)
		{
			if((*ti)->name == full_name)
				return *ti;

			++ti;
		}

		return NULL;
	}

	void OutputFile(std::string filename)
	{
		timers.sort();

		std::string txtFileName = filename + ".txt";
		std::string csvFileName = filename + ".csv";

		std::ofstream txtFile(txtFileName.c_str());
		std::ofstream csvFile(csvFileName.c_str());

		csvFile << "function name,num_frames,avg_mspf,avg_fps,total_seconds" << std::endl;

		TimerList::iterator itr = timers.begin(), end = timers.end();
		while(itr != end)
		{
			(*itr)->outputCSV(csvFile);
			(*itr)->outputTXT(txtFile);
			++itr;
		}

		txtFile.close();
		csvFile.close();
	}

public:

	Profiler(std::string _outputFileName) : outputFileName(_outputFileName) {}

	~Profiler()
	{
		OutputFile(outputFileName);

		TimerList::iterator itr = timers.begin(), end = timers.end();

		while(itr != end)
		{
			delete (*itr);
			++itr;
		}

		timers.clear();
		stack.clear();
	}

	void BeginTimer(std::string _name)
	{
		std::string full_name = getFullName(_name);
		QTimer *t = findTimer(full_name);

		if(t == NULL)
		{
			t = new QTimer(getFullName(_name));
			timers.push_back(t);
		}

		t->Start();
		stack.push_back(_name);
	}

	void EndTimer(std::string _name)
	{
		assert(stack.back() == _name);

		stack.pop_back();

		std::string full_name = getFullName(_name);
		QTimer *t = findTimer(full_name);

		if(t)
			t->Stop(); // EXCEPTION!!
	}
};

extern OSGVIEWER_EXPORT Profiler g_Profiler;

#endif





And here is the disassembly window contents, if that helps (sorry about the wall of text, I'm going to try to figure out a way to get this to look better). The exception occurs at (0046F9C8):
	void EndTimer(std::string _name)
	{
0046F8F0  push        0FFFFFFFFh 
0046F8F2  push        offset __ehhandler$?EndTimer@Profiler@@QAEXV?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@Z (48EB52h) 
0046F8F7  mov         eax,dword ptr fs:[00000000h] 
0046F8FD  push        eax  
0046F8FE  sub         esp,2Ch 
0046F901  mov         eax,dword ptr [___security_cookie (4BE7D4h)] 
0046F906  xor         eax,esp 
0046F908  mov         dword ptr [esp+28h],eax 
0046F90C  push        ebx  
0046F90D  push        ebp  
0046F90E  push        esi  
0046F90F  push        edi  
0046F910  mov         eax,dword ptr [___security_cookie (4BE7D4h)] 
0046F915  xor         eax,esp 
0046F917  push        eax  
0046F918  lea         eax,[esp+40h] 
0046F91C  mov         dword ptr fs:[00000000h],eax 
0046F922  mov         edi,ecx 
		assert(stack.back() == _name);

		stack.pop_back();
0046F924  mov         esi,dword ptr [edi+1Ch] 
0046F927  mov         ebx,dword ptr [edi+30h] 
0046F92A  lea         ebp,[edi+1Ch] 
0046F92D  mov         dword ptr [esp+48h],0 
0046F935  test        esi,esi 
0046F937  jne         Profiler::EndTimer+4Fh (46F93Fh) 
0046F939  call        dword ptr [__imp___invalid_parameter_noinfo (491190h)] 
0046F93F  mov         ebx,dword ptr [ebx+4] 
0046F942  test        esi,esi 
0046F944  je          Profiler::EndTimer+5Ah (46F94Ah) 
0046F946  mov         eax,dword ptr [esi] 
0046F948  jmp         Profiler::EndTimer+5Ch (46F94Ch) 
0046F94A  xor         eax,eax 
0046F94C  cmp         ebx,dword ptr [eax+14h] 
0046F94F  jne         Profiler::EndTimer+67h (46F957h) 
0046F951  call        dword ptr [__imp___invalid_parameter_noinfo (491190h)] 
0046F957  push        ebx  
0046F958  push        esi  
0046F959  lea         eax,[esp+20h] 
0046F95D  push        eax  
0046F95E  mov         ecx,ebp 
0046F960  call        std::list&lt;std::basic_string&lt;char,std::char_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt;,std::allocator&lt;std::basic_string&lt;char,std::char_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt; &gt; &gt;::erase (46E460h) 

		std::string full_name = getFullName(_name);
0046F965  sub         esp,1Ch 
0046F968  lea         edx,[esp+6Ch] 
0046F96C  mov         ecx,esp 
0046F96E  mov         dword ptr [esp+30h],esp 
0046F972  push        edx  
0046F973  call        dword ptr [__imp_std::basic_string&lt;char,std::char_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt;::basic_string&lt;char,std::char_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt; (491090h)] 
0046F979  lea         eax,[esp+3Ch] 
0046F97D  push        eax  
0046F97E  mov         ecx,edi 
0046F980  call        Profiler::getFullName (46EA50h) 
		QTimer *t = findTimer(full_name);
0046F985  sub         esp,1Ch 
0046F988  lea         edx,[esp+3Ch] 
0046F98C  mov         ecx,esp 
0046F98E  mov         dword ptr [esp+30h],esp 
0046F992  mov         ebx,1 
0046F997  push        edx  
0046F998  mov         byte ptr [esp+68h],bl 
0046F99C  call        dword ptr [__imp_std::basic_string&lt;char,std::char_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt;::basic_string&lt;char,std::char_traits&lt;char&gt;,std::allocator&lt;char&gt; &gt; (491090h)] 
0046F9A2  mov         ecx,edi 
0046F9A4  call        Profiler::findTimer (46EB50h) 

		if(t)
0046F9A9  test        eax,eax 
0046F9AB  je          Profiler::EndTimer+102h (46F9F2h) 
			t-&gt;Stop();
0046F9AD  lea         ecx,[esp+18h] 
0046F9B1  mov         dword ptr [esp+14h],ecx 
0046F9B5  push        edx  
0046F9B6  push        ecx  
0046F9B7  mov         ecx,dword ptr [esp+1Ch] 
0046F9BB  rdtsc            
0046F9BD  mov         dword ptr [ecx],eax 
0046F9BF  mov         dword ptr [ecx+4],edx 
0046F9C2  pop         ecx  
0046F9C3  pop         edx  
0046F9C4  fild        qword ptr [esp+18h] 
0046F9C8  fild        qword ptr [eax+28h] 
0046F9CB  add         dword ptr [eax+48h],ebx 
0046F9CE  mov         edx,dword ptr [eax+48h] 
0046F9D1  mov         dword ptr [esp+14h],edx 
0046F9D5  fsubp       st(1),st 
0046F9D7  fild        qword ptr [eax+20h] 
0046F9DA  fdivp       st(1),st 
0046F9DC  fadd        qword ptr [eax+30h] 
0046F9DF  fst         qword ptr [eax+30h] 
0046F9E2  fidivr      dword ptr [esp+14h] 
0046F9E6  fst         qword ptr [eax+38h] 
0046F9E9  fdivr       qword ptr [__real@408f400000000000 (493CB8h)] 
0046F9EF  fstp        qword ptr [eax+40h] 

Share this post


Link to post
Share on other sites
mattd    1078
Didn't Sneftel warn against relying on the source code line information in a release build? :)

Your Profile_Get_Ticks and Stop functions are both being inlined on the call to t->Stop(). Hence a problem in either of these will appear to be coming from this line, when in fact this is misleading.

Notice the instruction that is failing, fild qword ptr [eax+28h], refers to the eax register. Also note that the instructions just before that are from Profile_Get_Ticks (having been inlined). You don't store the value of eax across Profile_Get_Ticks, so it is getting trashed by rdtsc storing the timestamp value in it.

You need to push and pop eax as well in your Profile_Get_Ticks assembly.

Not sure why you say that the disassembly output is "incomprehensible to (you)", as you've written inline assembly in Profile_Get_Ticks :)

Share this post


Link to post
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now

Sign in to follow this