From b4f6ccaa8873b5560d618fb9cfee79691ef5990a Mon Sep 17 00:00:00 2001 From: Adam Johnson Date: Mon, 7 Jan 2013 00:13:30 -0500 Subject: [PATCH 1/4] Fix the "Crash on Exit" bug We were throwing away the Dispatcher before all the keys (namely, leaked keys) were unloaded. See the comment in plResManager for more details. --- Sources/Plasma/NucleusLib/inc/plgDispatch.h | 2 ++ .../Plasma/NucleusLib/pnDispatch/plDispatch.cpp | 10 ++++++---- Sources/Plasma/NucleusLib/pnDispatch/plDispatch.h | 8 ++++++-- .../Plasma/PubUtilLib/plResMgr/plResManager.cpp | 14 +++++++++----- 4 files changed, 23 insertions(+), 11 deletions(-) diff --git a/Sources/Plasma/NucleusLib/inc/plgDispatch.h b/Sources/Plasma/NucleusLib/inc/plgDispatch.h index c62a2061..344cf1a4 100644 --- a/Sources/Plasma/NucleusLib/inc/plgDispatch.h +++ b/Sources/Plasma/NucleusLib/inc/plgDispatch.h @@ -68,6 +68,8 @@ public: virtual void MsgQueueOnOff(bool) = 0; // Turn on or off Queued Messages, if off, uses MsgSend Immediately (for plugins) virtual bool SetMsgBuffering(bool on) = 0; // On starts deferring msg delivery until buffering is set to off again. + + virtual void BeginShutdown() = 0; }; class plgDispatch diff --git a/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp b/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp index 38297684..16b15897 100644 --- a/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp +++ b/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp @@ -103,12 +103,14 @@ plDispatch::plDispatch() plDispatch::~plDispatch() { - int i; - for( i = 0; i < fRegisteredExactTypes.GetCount(); i++ ) - delete fRegisteredExactTypes[i]; - + hsAssert(fRegisteredExactTypes.GetCount() == 0, "registered type after Dispatch shutdown"); ITrashUndelivered(); +} +void plDispatch::BeginShutdown() +{ + fRegisteredExactTypes.Reset(); + ITrashUndelivered(); } void plDispatch::ITrashUndelivered() diff --git a/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.h b/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.h index 9554673c..a4b31329 100644 --- a/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.h +++ b/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.h @@ -131,6 +131,8 @@ public: virtual bool SetMsgBuffering(bool on); // On starts deferring msg delivery until buffering is set to off again. + virtual void BeginShutdown(); + static void SetMsgRecieveCallback(MsgRecieveCallback callback) { fMsgRecieveCallback = callback; } }; @@ -146,8 +148,10 @@ public: virtual bool MsgSend(plMessage* msg) { return true; } - virtual void MsgQueue(plMessage* msg) {} - virtual void MsgQueueProcess() {} + virtual void MsgQueue(plMessage* msg) {} + virtual void MsgQueueProcess() {} + + virtual void BeginShutdown() {} }; diff --git a/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp b/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp index eda1d7ae..dd159cc2 100644 --- a/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp +++ b/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp @@ -205,10 +205,11 @@ void plResManager::IShutdown() // TimerCallbackMgr is a fixed-keyed object, so needs to shut down before the registry plgTimerCallbackMgr::Shutdown(); - // Destroy the dispatch. Note that we do this before the registry so that any lingering messages - // can free up keys properly - hsRefCnt_SafeUnRef(fDispatch); - fDispatch = nil; + // Formerly, we destroyed the Dispatcher here to clean up keys for leak reporting. + // However, if there are *real* leaked keys, then they will want to unload after this step. + // To unload, plKeyImp needs to dispatcher. SO, we're going to pitch everything currently in the + // Dispatcher and kill it later + fDispatch->BeginShutdown(); // Just before we shut down the registry, page out any keys that still exist. // (They shouldn't... they're baaaaaad.) @@ -224,9 +225,12 @@ void plResManager::IShutdown() fLoadedPages.clear(); IUnlockPages(); - fLastFoundPage = nil; + // Now, kill off the Dispatcher + hsRefCnt_SafeUnRef(fDispatch); + fDispatch = nullptr; + kResMgrLog(1, ILog(1, " ...Shutdown successful!")); fInited = false; From d2815f35bfb257972e7426d844fe41035cab0e7d Mon Sep 17 00:00:00 2001 From: Adam Johnson Date: Mon, 7 Jan 2013 19:09:38 -0500 Subject: [PATCH 2/4] Replace plasmalog with a better debug log Plasmalog.txt is now plasmadbg.log. This allows us to view the log inside the game, flush to the debugger output window, and have the logfile. The plan is to redirect key leak reports to this log in a future commit. --- Sources/Plasma/Apps/plClient/winmain.cpp | 111 ++++++++--------------- Sources/Plasma/CoreLib/hsStream.cpp | 14 +-- 2 files changed, 43 insertions(+), 82 deletions(-) diff --git a/Sources/Plasma/Apps/plClient/winmain.cpp b/Sources/Plasma/Apps/plClient/winmain.cpp index 4108cb8e..5fee20ee 100644 --- a/Sources/Plasma/Apps/plClient/winmain.cpp +++ b/Sources/Plasma/Apps/plClient/winmain.cpp @@ -305,11 +305,6 @@ LRESULT CALLBACK WndProc(HWND hWnd, UINT message, WPARAM wParam, LPARAM lParam) bool active = (LOWORD(wParam) == WA_ACTIVE || LOWORD(wParam) == WA_CLICKACTIVE); bool minimized = (HIWORD(wParam) != 0); - DebugMsgF("Got WM_ACTIVATE, active=%s, minimized=%s, clicked=%s", - active ? "true" : "false", - minimized ? "true" : "false", - (LOWORD(wParam) == WA_CLICKACTIVE) ? "true" : "false"); - if (gClient && !minimized && !gClient->GetDone()) { gClient->WindowActivate(active); @@ -324,7 +319,6 @@ LRESULT CALLBACK WndProc(HWND hWnd, UINT message, WPARAM wParam, LPARAM lParam) // Let go of the mouse if the window is being moved. case WM_ENTERSIZEMOVE: - DebugMsgF("Got WM_ENTERSIZEMOVE%s", gClient ? "" : ", no client, ignoring"); gDragging = true; if( gClient ) gClient->WindowActivate(false); @@ -332,7 +326,6 @@ LRESULT CALLBACK WndProc(HWND hWnd, UINT message, WPARAM wParam, LPARAM lParam) // Redo the mouse capture if the window gets moved case WM_EXITSIZEMOVE: - DebugMsgF("Got WM_EXITSIZEMOVE%s", gClient ? "" : ", no client, ignoring"); gDragging = false; if( gClient ) gClient->WindowActivate(true); @@ -342,12 +335,7 @@ LRESULT CALLBACK WndProc(HWND hWnd, UINT message, WPARAM wParam, LPARAM lParam) // and his cool program that bumps windows out from under the taskbar) case WM_MOVE: if (!gDragging && gClient && gClient->GetInputManager()) - { gClient->GetInputManager()->Activate(true); - DebugMsgF("Got WM_MOVE"); - } - else - DebugMsgF("Got WM_MOVE, but ignoring"); break; /// Resize the window @@ -358,7 +346,6 @@ LRESULT CALLBACK WndProc(HWND hWnd, UINT message, WPARAM wParam, LPARAM lParam) // size, not when the window is minimized or restored) case WM_SIZING: { - DebugMsgF("Got WM_SIZING"); RECT r; ::GetClientRect(hWnd, &r); gClient->GetPipeline()->Resize(r.right - r.left, r.bottom - r.top); @@ -369,14 +356,12 @@ LRESULT CALLBACK WndProc(HWND hWnd, UINT message, WPARAM wParam, LPARAM lParam) // Let go of the mouse if the window is being minimized if (wParam == SIZE_MINIMIZED) { - DebugMsgF("Got WM_SIZE, SIZE_MINIMIZED%s", gClient ? "" : ", but no client, ignoring"); if (gClient) gClient->WindowActivate(false); } // Redo the mouse capture if the window gets restored else if (wParam == SIZE_RESTORED) { - DebugMsgF("Got WM_SIZE, SIZE_RESTORED%s", gClient ? "" : ", but no client, ignoring"); if (gClient) gClient->WindowActivate(true); } @@ -653,32 +638,40 @@ BOOL WinInit(HINSTANCE hInst, int nCmdShow) // // For error logging // -static FILE* gDebugFile=NULL; -void DebugMessageProc(const char* msg) +static plStatusLog* s_DebugLog = nullptr; +static void _DebugMessageProc(const char* msg) { - OutputDebugString(msg); - OutputDebugString("\n"); - if (gDebugFile != NULL) - { - fprintf(gDebugFile, "%s\n", msg); - fflush(gDebugFile); - } +#if defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) + s_DebugLog->AddLine(msg, plStatusLog::kRed); +#endif // defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) } -void DebugMsgF(const char* format, ...) +static void _StatusMessageProc(const char* msg) { -#ifndef PLASMA_EXTERNAL_RELEASE +#if defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) + s_DebugLog->AddLine(msg); +#endif // defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) +} + +static void DebugMsgF(const char* format, ...) +{ +#if defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) va_list args; va_start(args, format); - - char buf[256]; - int numWritten = _vsnprintf(buf, sizeof(buf), format, args); - hsAssert(numWritten > 0, "Buffer too small"); - + s_DebugLog->AddLineV(plStatusLog::kYellow, format, args); va_end(args); +#endif // defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) +} - DebugMessageProc(buf); -#endif +static void DebugInit() +{ +#if defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) + plStatusLogMgr& mgr = plStatusLogMgr::GetInstance(); + s_DebugLog = mgr.CreateStatusLog(30, "plasmadbg.log", plStatusLog::kFilledBackground | + plStatusLog::kDeleteForMe | plStatusLog::kAlignToTop | plStatusLog::kTimestamp); + hsSetDebugMessageProc(_DebugMessageProc); + hsSetStatusMessageProc(_StatusMessageProc); +#endif // defined(HS_DEBUGGING) || !defined(PLASMA_EXTERNAL_RELEASE) } static void AuthFailedStrings (ENetError authError, @@ -1203,6 +1196,7 @@ LONG WINAPI plCustomUnhandledExceptionFilter( struct _EXCEPTION_POINTERS *Except #include "pfConsoleCore/pfConsoleEngine.h" PF_CONSOLE_LINK_ALL() +#include "plResMgr/plVersion.h" int WINAPI WinMain(HINSTANCE hInst, HINSTANCE hPrevInst, LPSTR lpCmdLine, int nCmdShow) { PF_CONSOLE_INIT_ALL() @@ -1398,22 +1392,8 @@ int WINAPI WinMain(HINSTANCE hInst, HINSTANCE hPrevInst, LPSTR lpCmdLine, int nC // // Set up to log errors by using hsDebugMessage // - gDebugFile = NULL; - if ( !plStatusLog::fLoggingOff ) - { - wchar_t fileAndPath[MAX_PATH]; - PathGetLogDirectory(fileAndPath, arrsize(fileAndPath)); - PathAddFilename(fileAndPath, fileAndPath, L"plasmalog.txt", arrsize(fileAndPath)); - gDebugFile = _wfopen(fileAndPath, L"wt"); - hsAssert(gDebugFile != NULL, "Error creating debug file plasmalog.txt"); - hsSetDebugMessageProc(DebugMessageProc); - if (gDebugFile != NULL) - { - fputs(plProduct::ProductString().c_str(), gDebugFile); - fputs("\n", gDebugFile); - fflush(gDebugFile); - } - } + DebugInit(); + DebugMsgF("Plasma 2.0.%i.%i - %s", PLASMA2_MAJOR_VERSION, PLASMA2_MINOR_VERSION, plProduct::ProductString().c_str()); for (;;) { // Create Window @@ -1485,32 +1465,17 @@ int WINAPI WinMain(HINSTANCE hInst, HINSTANCE hPrevInst, LPSTR lpCmdLine, int nC break; } -#ifndef _DEBUG - try - { -#endif - // - // Cleanup - // - if (gClient) - { - gClient->Shutdown(); // shuts down PhysX for us - gClient = nil; - } - hsAssert(hsgResMgr::ResMgr()->RefCnt()==1, "resMgr has too many refs, expect mem leaks"); - hsgResMgr::Shutdown(); // deletes fResMgr - DeInitNetClientComm(); -#ifndef _DEBUG - } catch (...) + // + // Cleanup + // + if (gClient) { - // just catch all the crashes on exit... just to keep GameTap from complaining - if (gDebugFile) - fprintf(gDebugFile, "Crashed on shutdown.\n"); + gClient->Shutdown(); // shuts down PhysX for us + gClient = nil; } -#endif - - if (gDebugFile) - fclose(gDebugFile); + hsAssert(hsgResMgr::ResMgr()->RefCnt()==1, "resMgr has too many refs, expect mem leaks"); + hsgResMgr::Shutdown(); // deletes fResMgr + DeInitNetClientComm(); // Uninstall our unhandled exception filter, if we installed one #ifndef HS_DEBUGGING diff --git a/Sources/Plasma/CoreLib/hsStream.cpp b/Sources/Plasma/CoreLib/hsStream.cpp index ba9610f6..f0fd4caa 100644 --- a/Sources/Plasma/CoreLib/hsStream.cpp +++ b/Sources/Plasma/CoreLib/hsStream.cpp @@ -714,17 +714,13 @@ uint32_t hsUNIXStream::Read(uint32_t bytes, void* buffer) { if (!fRef || !bytes) return 0; - int numItems = ::fread(buffer, 1 /*size*/, bytes /*count*/, fRef); + size_t numItems = ::fread(buffer, 1 /*size*/, bytes /*count*/, fRef); fBytesRead += numItems; fPosition += numItems; - if ((unsigned)numItems < bytes) { - if (feof(fRef)) { - // EOF ocurred - char str[128]; - sprintf(str, "Hit EOF on UNIX Read, only read %d out of requested %d bytes\n", numItems, bytes); - hsDebugMessage(str, 0); - } - else { + if (numItems < bytes) + { + if (!feof(fRef)) + { hsDebugMessage("Error on UNIX Read", ferror(fRef)); } } From bb2146b3a38ed343fc71edb159b21f269e3a0651 Mon Sep 17 00:00:00 2001 From: Adam Johnson Date: Mon, 7 Jan 2013 20:15:04 -0500 Subject: [PATCH 3/4] Remove Cruft --- .../PubUtilLib/plResMgr/plResManager.cpp | 49 +++++-------------- .../Plasma/PubUtilLib/plResMgr/plResManager.h | 1 - Sources/Tools/MaxMain/plPluginResManager.cpp | 3 -- 3 files changed, 11 insertions(+), 42 deletions(-) diff --git a/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp b/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp index dd159cc2..8bb7c0e2 100644 --- a/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp +++ b/Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp @@ -96,7 +96,6 @@ static void ILog(uint8_t level, const char* format, ...) plResManager::plResManager(): fInited(false), - fPageOutHint(0), fDispatch(nil), fReadingObject( false ), fCurCloneID(0), @@ -492,47 +491,21 @@ public: } }; -#if HS_BUILD_FOR_UNIX -static void sLeakReportRedirectFn( const char message[] ) -{ - hsUNIXStream stream; - stream.Open( "resMgrMemLeaks.txt", "at" ); - stream.WriteString( message ); - stream.Close(); -} -static bool sFirstTime = true; -#endif - // Just the scene nodes (and objects referenced by the node... and so on) void plResManager::IPageOutSceneNodes(bool forceAll) { plSynchEnabler ps(false); // disable dirty tracking while paging out -#if HS_BUILD_FOR_UNIX - if (sFirstTime) - { - hsUNIXStream stream; - stream.Open("resMgrMemLeaks.txt", "wt"); - stream.Close(); - sFirstTime = false; - } - hsDebugMessageProc oldProc = hsSetStatusMessageProc(sLeakReportRedirectFn); -#endif - if (forceAll) { hsStatusMessage( "--- plResManager Object Leak Report (BEGIN) ---" ); - plPageOutIterator iter(this, uint16_t(-1)); + plPageOutIterator iter(this, static_cast(-1)); hsStatusMessage( "--- plResManager Object Leak Report (END) ---" ); } else { - plPageOutIterator iter(this, fPageOutHint); + plPageOutIterator iter(this, 0); } - -#if HS_BUILD_FOR_UNIX - hsSetStatusMessageProc( oldProc ); -#endif } //// FindKey ///////////////////////////////////////////////////////////////// @@ -1582,7 +1555,7 @@ static void sIReportLeak(plKeyImp* key, plRegistryPageNode* page) if (!alreadyDone) { // Print out page header - hsStatusMessageF(" Leaks in page %s>%s[%08x]:\n", lastPage->GetPageInfo().GetAge().c_str(), lastPage->GetPageInfo().GetPage().c_str(), lastPage->GetPageInfo().GetLocation().GetSequenceNumber()); + hsStatusMessageF("\tLeaks in page %s>%s[%08x]:\n", lastPage->GetPageInfo().GetAge().c_str(), lastPage->GetPageInfo().GetPage().c_str(), lastPage->GetPageInfo().GetLocation().GetSequenceNumber()); alreadyDone = true; } @@ -1590,14 +1563,14 @@ static void sIReportLeak(plKeyImp* key, plRegistryPageNode* page) if (refsLeft == 0) return; - char tempStr2[128]; - if (key->ObjectIsLoaded() == nil) - sprintf(tempStr2, "(key only, %d refs left)", refsLeft); + plStringStream ss; + ss << "\t\t" << plFactory::GetNameOfClass(key->GetUoid().GetClassType()) << ": "; + ss << key->GetUoid().StringIze() << " "; + if (key->ObjectIsLoaded()) + ss << "- " << key->GetDataLen() << " bytes - " << refsLeft << " refs left"; else - sprintf(tempStr2, "- %d bytes - %d refs left", key->GetDataLen(), refsLeft); - - hsStatusMessageF(" %s: %s %s\n", plFactory::GetNameOfClass(key->GetUoid().GetClassType()), - key->GetUoid().StringIze().c_str(), tempStr2); + ss << "(key only, " << refsLeft << " refs left)"; + hsStatusMessage(ss.GetString().c_str()); } //// UnloadPageObjects /////////////////////////////////////////////////////// @@ -1628,7 +1601,7 @@ void plResManager::UnloadPageObjects(plRegistryPageNode* pageNode, uint16_t clas plUnloadObjectsIterator iterator; - if (classIndexHint != uint16_t(-1)) + if (classIndexHint != static_cast(-1)) pageNode->IterateKeys(&iterator, classIndexHint); else pageNode->IterateKeys(&iterator); diff --git a/Sources/Plasma/PubUtilLib/plResMgr/plResManager.h b/Sources/Plasma/PubUtilLib/plResMgr/plResManager.h index 306ed0c1..8d36e9a5 100644 --- a/Sources/Plasma/PubUtilLib/plResMgr/plResManager.h +++ b/Sources/Plasma/PubUtilLib/plResMgr/plResManager.h @@ -209,7 +209,6 @@ protected: plRegistryPageNode* CreatePage(const plLocation& location, const char* age, const char* page); bool fInited; - uint16_t fPageOutHint; // True if we're reading in an object. We only read one object at a time bool fReadingObject; diff --git a/Sources/Tools/MaxMain/plPluginResManager.cpp b/Sources/Tools/MaxMain/plPluginResManager.cpp index 596ef6e1..12e89fea 100644 --- a/Sources/Tools/MaxMain/plPluginResManager.cpp +++ b/Sources/Tools/MaxMain/plPluginResManager.cpp @@ -60,9 +60,6 @@ You can contact Cyan Worlds, Inc. by email legal@cyan.com plKey plPluginResManager::NameToLoc(const plString& age, const plString& page, int32_t sequenceNumber, bool itinerant) { - // Hack for now--always prefer paging out sceneNodes first - fPageOutHint = plSceneNode::Index(); - // Get or create our page plRegistryPageNode* pageNode = INameToPage(age, page, sequenceNumber, itinerant); hsAssert(pageNode != nil, "No page returned from INameToPage(), shouldn't be possible"); From 795babd6aaa0f8d9075deaf41258baf5848d06de Mon Sep 17 00:00:00 2001 From: Adam Johnson Date: Mon, 7 Jan 2013 22:02:33 -0500 Subject: [PATCH 4/4] Fix issues from review - Delete the TypeFilter pointers --- Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp | 2 ++ 1 file changed, 2 insertions(+) diff --git a/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp b/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp index 16b15897..79401720 100644 --- a/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp +++ b/Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp @@ -109,6 +109,8 @@ plDispatch::~plDispatch() void plDispatch::BeginShutdown() { + for (int i = 0; i < fRegisteredExactTypes.Count(); ++i) + delete fRegisteredExactTypes[i]; fRegisteredExactTypes.Reset(); ITrashUndelivered(); }