Archived

This topic is now archived and is closed to further replies.

half-destroyed io streams dilemma

This topic is 5611 days old which is more than the 365 day threshold we allow for new replies. Please post a new topic.

If you intended to correct an error in the post then please contact us.

Recommended Posts

EDIT: i ran in a more serious problem involving atexit(), please take a look at it here (it's just a link to a post on this page) yesterday i ran into quite a problem when implementing a CLog class for my engine. i wanted my log class to log his own creation and destruction (log started/finished successfully), so i was hoping this would do the trick.
    
	CLog::CLog(const String &sLogName, LoggingLevel oLoggingLevel, bool bDebugOutput)
	{
		m_oLog.open(sLogName.c_str());
		m_oLoggingLevel = oLoggingLevel;
		m_bDebugOutput = bDebugOutput;

		// log the log creation

		LogMessage(LML_HIGH, "log (name - '%s', logging level - %i) created", sLogName.c_str(), static_cast<int>(oLoggingLevel));
	}

	CLog::~CLog()
	{
		// log the log destruction

		LogMessage(LML_HIGH, "log successfully finished");

		m_oLog.close();
	}
  

for now, i still have a console window (for easy log access) open, and this class outputs the log message to the log and to the console window. here's some code for that.
      
void CLog::LogMessage(const String& sMessage, LogMessageLevel oLMLevel)
	{
		if (oLMLevel + m_oLoggingLevel >= 4)
		{
			tm		*pFormattedTime;
			time_t	oRawTime;
			char	szBuffer[3];

			// figure out time

			time(&oRawTime);
			pFormattedTime = localtime(&oRawTime);

			// display the message on the debugging screen, if asked to

			if (m_bDebugOutput)
				printf("%s (%i:%i:%i) %s\n", MessagePriorityIndicator(oLMLevel), pFormattedTime->tm_hour, pFormattedTime->tm_min, pFormattedTime->tm_sec, sMessage.c_str());

			// log the message

			m_oLog << MessagePriorityIndicator(oLMLevel) << " (" << pFormattedTime->tm_hour << ":" << pFormattedTime->tm_min << ":" << pFormattedTime->tm_sec << ") " << sMessage << "\n";

			// to make sure the file is written to, instead of the buffer

			m_oLog.flush();
		}
	}
  

MessagePriorityIndicator(oLMLevel) just returns a pointer to a string of 3 characters representing the message priority ("  *", " **" or "***").

everything worked fine, at first. the log logged his own destruction on the debuffing screen (the console window). note that printf() was used, not cout (which is stream based).

but when i opened the log file, it only contained a part of the last destruction message. more precisely, it was "*** (", meaning everything   before 1st access to pFormattedTime->tm_hour got printed, and anything after that did not.

i modified that piece of code to something like this:
      
			// log the message

			m_oLog << MessagePriorityIndicator(oLMLevel) << " (" << 5 /* to make sure that pFormattedTime had nothing to with this */ << ":" << 6 << ":" << 7 << ") " << sMessage << "\n";
			m_oLog << "just another string to make sure that everything after 1st integer doesn't get printed to log";
  

the output did not change at all.

then i decided to convert each integer to a std::string. i used this function.
      
	// convert int to string

	String itos(int iInt)
	{
		std::stringstream	oStringStream;
		oStringStream << iInt;
		return oStringStream.str();
	}
  

so now the code looked like this.
      
			// log the message

			m_oLog << MessagePriorityIndicator(oLMLevel) << " (" << itos(pFormattedTime->tm_hour).c_str() << ":" << itos(pFormattedTime->tm_min).c_str() << ":" << itos(pFormattedTime->tm_sec).c_str() << ") " << sMessage << "\n";
  

now the output was the following (no spaces between the bracket and colons, i added them because otherwise it would turn in a smiley):
"*** ( : : ) log successfully finished"

this time everything got printed, except that converting an int to a std::string resulted in an empty string.

it's also very important to note that all of the code above resulted in each test message logged correctly, except for the last one. only the last one was strange, everything else was working.

i solved this problem using itoa() and converted each int to an array of chars. it looked like this.
      
			char	szBuffer[3];  // because i know all those ints are never more than 2 characters long (ie. 0 - 59 max)


			// log the message

			m_oLog << MessagePriorityIndicator(oLMLevel) << " (";
			itoa(pFormattedTime->tm_hour, szBuffer, 10);
			m_oLog << szBuffer << ":";
			itoa(pFormattedTime->tm_min, szBuffer, 10);
			m_oLog << szBuffer << ":";
			itoa(pFormattedTime->tm_sec, szBuffer, 10);
			m_oLog << szBuffer << ") " << sMessage << "\n";
    
i wouldn't call that a nice solution, because it's more of a hack to get the last message working. the only reason it wasn't iis because it was called from CLog's deconstructor, but that doesn't make sense to me. so i tried (yes... again) to replace m_oLog << ... ; with cout << ... ; that resulted in last message not being outputted at all ! the CLog's deconstructor is called when the program exits, so i'm assumging that at that time the io streams get half-destroyed or something, and don't function normally anymore. if anyone has a better explanation, or a better solution, please share it with me. thanks for reading such a long post... ps. the reason that calls to LogMessage and the function itself don't have the same parameter list is because LogMessage is overloaded w/ this function which takes multiple params and sends them all to the other LogMessage version - void CLog::LogMessage(LogMessageLevel oLMLevel, const char *szMessage, ...)) [edited by - shurcool on July 31, 2002 3:13:13 PM]

Share this post


Link to post
Share on other sites
Guest Anonymous Poster
You can''t pick which order global objects are constructed across source file boundaries. cout and cin need to be constructed too, maybe they get constructed after your log class is and so don''t function correctly.
That''s why you shouldn''t use cout in constructors/destructors of global objects anyhow.
Fixing problems like that is a pain, the best thing to do is not have any global objects at all, allocate them with new so you know exactly when they are being constructed.

Share this post


Link to post
Share on other sites
actually, CLog does get allocated using new and deleted using delete. but that happens inside the constructor/destructor of another class (CRoot, the main class, which is a singleton)... i guess i will put it elsewhere, and see what happens.

thanks for the idea!

---
shurcool
wwdev


[edited by - shurcool on July 30, 2002 12:44:07 PM]

Share this post


Link to post
Share on other sites
ok, i added a Destroy() function to CRoot and it basically does this. it clears the smart singleton destructor by settings the singleton pointer to NULL. then it deletes itself.

  
void CRoot::Destroy()
{
if (m_pSingleton) {
m_oSingletonCleaner.SetSingleton(NULL);

delete m_pSingleton;
}
}


the smart singleton cleaner class works like this (i got the idea from this nice article about destroying singletons). it has a pointer to a class (oh, it's a template, so it can accept any class), in this case the CRoot class (it's declared like this: static CSingletonCleaner m_oSingletonCleaner; ) creates as a static var. and C++ promises to delete any static vars on class deconstruction. in CSingletonCleaner's deconstructor it checks if the pointer to a class it has isn't NULL, and deletes it - thus deleting the CRoot singleton class.

so if a stupid engine user forgets to call CRoot::GetSingletonPtr()->Destroy();, the class will still be destroyed without any memory leaks. only the log output will be messed up.

oh well, i don't think it can be any better than that.

do you?

---
shurcool
wwdev


[edited by - shurcool on July 30, 2002 3:16:04 PM]

Share this post


Link to post
Share on other sites
... or you could register a static deconstruction function under atexit(), so it will be called even for pple being casted by ''Forgetfulness'' spell.

Share this post


Link to post
Share on other sites
quote:
Original post by DerekSaw
... or you could register a static deconstruction function under atexit(), so it will be called even for pple being casted by 'Forgetfulness' spell.


thanks, that's a great idea (if only it worked!).

ok, it returns 0, meaning success, and it DOES call the function, MUCH earlier than it would if you called it manually before the return 0; in main().

how do i know that? every class has a constructor and a destructor, inside those i have printf("CLog created.\n") or such, so i know how everything went. and when using atexit() the Destroy function - the one i registered with atexit(&Destroy), gets called earlier than it does if i call it manually - right before return 0 in main().

but, it DOESN'T output the last log message correctly (only a part of "*** ( " instead of the correct message - "*** (12.12.12) log successfully finished ", as if the io streams are half-way destroyed already).

how can that be? i mean how can io streams be already destroyed, if it's CALLED EARLIER

so it calls it (the Destroy() - a public static member function) earlier (or so it seems, because it's called before any destructor gets called, unlike when you call it manually) but the results suggest otherwise... or some other weird reson? why? can anyone please help?!

thank you very much for any help!

---
shurcool
wwdev


[edited by - shurcool on July 31, 2002 3:08:39 PM]

Share this post


Link to post
Share on other sites
I think this is the problem with MSVC6... i''m not sure about VS.Net. Even the following code doesn''t work:

#include <iostream>
class Universe
{
public:
Universe() { std::cout << "Universe created." << std::endl; }
~Universe() { std::cout << "Universe destroyed." << std::endl; }
};
Universe theUniverse;
int main()
{
return 0;
}

"Universe destroyed." is not on the screen!

Share this post


Link to post
Share on other sites
No, that''s just because you can''t rely on the construction and deconstruction of global variables in terms of when they happen. If you allocated the memory dynamically within the program and then free it, it works.

Share this post


Link to post
Share on other sites
quote:
Original post by Zipster
No, that''s just because you can''t rely on the construction and deconstruction of global variables in terms of when they happen. If you allocated the memory dynamically within the program and then free it, it works.

Yes, it has something to do with those global thingie, but it shouldn''t affect cin/cout. I believe the Standards say cout/cin shouldn''t behave this way... ask Dinkumware.... Try it on VS.Net, GCC, Borland or others

Share this post


Link to post
Share on other sites
DerekSaw,
try this code, and see what happens (it will prove that atexit() is not a solution).

#include <iostream>
#include <stdlib.h>

class Universe
{
public:
Universe() { std::cout << "Universe created." << std::endl; }
~Universe() { std::cout << "Universe destroyed." << std::endl; }
};

Universe *theUniversePtr;

void Destroy()
{
delete theUniversePtr;
}

int main()
{
theUniversePtr = new Universe();

atexit(&Destroy);

return 0;
}


i wrote the code off the top of my head, so it might contain some stupid mistakes.

the result, idealy, should be that it prints both statements (Universe is created/destroyed). but in reality, that does not happen (that is what happens in my CLog case).

so i guess the user will manually have to destroy the CLog class(es) (by calling a function, of course) before it reaches return 0; in main(), or what? can't use atexit(), can i?

---
shurcool
wwdev


[edited by - shurcool on July 31, 2002 10:42:22 PM]

Share this post


Link to post
Share on other sites
cout in VC++ is implemented using the Meyer''s singleton (which is a static variable inside a function). That is prone to the destruction order problem. (See article "Singleton:The One" on gamedev)

I would consider this a flawed implementation of cout, but there is little we can do about it. In your case of the logging library, use the Nifty Counter technique (Again, see article)

Share this post


Link to post
Share on other sites
quote:
Original post by shurcool
...
so i guess the user will manually have to destroy the CLog class(es) (by calling a function, of course) before it reaches return 0; in main(), or what? can't use atexit(), can i?


Yep... your code does work. You are qualify to be a human compiler. ... using atexit() shouldn't have any problem.
Do you have your CLog .h and .cpp available for download?
... hmm... I'm in office... I'll look into it later... if not my boss willl munch me.



P/S: How is String class? You crafted it yourself?

[EDIT] Are you still using on your static cleaner?

[edited by - DerekSaw on July 31, 2002 11:03:16 PM]

Share this post


Link to post
Share on other sites
Actually, it (that simplified example 3 posts up) works fine printing to screen using cout. Replace it with an fstream, and only "Universe created" goes in the file. "Universe Destroyed" doesn't. That's what we're wondering about.

If it really is something to do with VC++, I guess we can't do much about it.

The static 'smart' cleaner does the same thing as atexit(), destroys the object when the program exits if it wasn't already. However, this also results in the log file being incomplete.

[edited by - JohnPC on July 31, 2002 11:39:19 PM]

Share this post


Link to post
Share on other sites
quote:
In your case of the logging library, use the Nifty Counter technique (Again, see article)



thanks, i will take a look. hopefully you''re right and it will work.

quote:
... using atexit() shouldn''t have any problem.



as JohnPC already said, it does (with std::ofstream anyway).

quote:
Do you have your CLog .h and .cpp available for download?



get it here.

quote:
P/S: How is String class? You crafted it yourself?



typedef std::string String; // i might make my own class wrapper later

quote:
Are you still using on your static cleaner?



yes, i am (just in case, but usually it''s not needed, since the Destroy function is called), JohnPC also covered this (i know he posted after you, so i''m just saying ).

once again, thanks to all for their help!

---
shurcool
wwdev

Share this post


Link to post
Share on other sites
i read the article about singletons that Void suggested. i compiled the src for the nifty counter, and here''s the ouput i got:

Main INIT
MyClass CTOR
Method called
Main EXIT
Method called
Press any key to continue

and yes, i''m SURE that it''s not breakmeyer.zip, but niftycounter.zip! the project is also called nifty counter, and in has a file called niftycounter.cpp or something. so i''m 100% positive.

anyway, i don''t see the MyClass dtor being called. :-\ that''s really weird... i mean, if the nifty counter allows mem leaks, then what good is it?

---
shurcool
wwdev

Share this post


Link to post
Share on other sites
ok, i tried setting some breakpoints and found out that the dtor actually does get called. the reason i didn''t know is because when it''s called, the cout stream is already destroyed! so if i replace all cout''s w/ printf''s, the ouput is fine, and i see the "MyClass DTOR" message.

that proves that even this method is not working, so i guess the only solution is to manually call the Destroy() function of the CRoot class, which will destroy everything in the right order. not everything can be automatic, or so it seems.

once again, if anyone comes up w/ a better solution, please test it first (try using cout and std::ofstream in the dtor of your test class). because i''m pretty postive that there''s isn''t a better way, and i don''t want my time wasted on trying to get something to work if it''s not going to (not that i don''t appreciate the suggestions you guys offered).

thanks.

---
shurcool
wwdev

Share this post


Link to post
Share on other sites
quote:
Original post by shurcool
i read the article about singletons that Void suggested. i compiled the src for the nifty counter, and here''s the ouput i got:

snip

and yes, i''m SURE that it''s not breakmeyer.zip, but niftycounter.zip! the project is also called nifty counter, and in has a file called niftycounter.cpp or something. so i''m 100% positive.

anyway, i don''t see the MyClass dtor being called. :-\ that''s really weird... i mean, if the nifty counter allows mem leaks, then what good is it?


This is what I get from nifty counter.


Main INIT
MyClass CTOR
Method called
Main EXIT
Method called
MyClass DTOR
Press any key to continue


The nifty counter doesn''t leak. If so, that would be a waste of time. As I said, the problem is with VC++6 implementation of cout. I know why it works for me and not for you. I''m using STL library from www.dinkumware.com.

Share this post


Link to post
Share on other sites