Cool VL Viewer forum

View unanswered posts | View active topics It is currently 2024-03-28 15:54:34



Reply to topic  [ 13 posts ]  Go to page 1, 2  Next
Shutdown crash with Debug GL on (was: Slow quit on Windows?) 
Author Message

Joined: 2011-10-07 10:39:20
Posts: 181
Reply with quote
Hello Henri,

not sure if it is a viewer or AMD driver problem, but i noticed extremly slow shutdowns of the viewer recently. Is this a known problem?
A few seconds delay, ok, happens, due to all the destructors cleaning up etc, but minutes seems like something is stuck and waiting for a timeout or so.
Any idea what log settings might help to find out? Maybe i should simply unpack a debugger/profiler and take a closer look.

For example today it took nearly 4 MINUTES to stop the viewer after hitting the "quit" button.

Code:
2022-10-23 11:46:37Z INFO: LLAppViewer::forceQuit: Quitting...
2022-10-23 11:46:37Z INFO: LLApp::setQuitting: Setting app state to QUITTING
2022-10-23 11:46:37Z INFO: LLImageGLThread::run: Shutting down thread 4 with GL context: 10004. Number of operations performed: 43725
2022-10-23 11:46:37Z INFO: LLImageGLThread::run: Shutting down thread 3 with GL context: 10003. Number of operations performed: 43788
2022-10-23 11:46:37Z INFO: LLImageGLThread::run: Shutting down thread 1 with GL context: 10001. Number of operations performed: 43544
2022-10-23 11:46:37Z INFO: LLImageGLThread::run: Shutting down thread 2 with GL context: 10002. Number of operations performed: 43837
2022-10-23 11:46:44Z INFO: LLPluginMessagePipe::pumpInput: Got EOF from plugin socket.
2022-10-23 11:48:28Z INFO: LLAppViewer::forceQuit: Quitting...
2022-10-23 11:48:28Z INFO: LLEventPollImpl::eventPollCoro: Cancelling coroutine for event poll <7> - Region: Aediman Hill
2022-10-23 11:48:28Z INFO: LLEventPollImpl::eventPollCoro: Cancelling coroutine for event poll <8> - Region: Breven
2022-10-23 11:48:28Z INFO: LLEventPollImpl::eventPollCoro: Cancelling coroutine for event poll <9> - Region: Somani
2022-10-23 11:48:28Z INFO: LLEventPollImpl::eventPollCoro: Cancelling coroutine for event poll <6> - Region: 35.90.253.240
2022-10-23 11:48:28Z INFO: LLAppViewer::mainLoop: Exiting main loop.
2022-10-23 11:48:28Z INFO: LLAppViewer::cleanup: Cleaning up...
2022-10-23 11:48:28Z INFO: LLAppViewer::cleanup: LLVOAvatarSelf destroyed
2022-10-23 11:48:28Z INFO: LLVoiceClient::terminate: Terminating voice client...
2022-10-23 11:48:28Z INFO: LLAppViewer::cleanup: LLVoiceClient terminated
2022-10-23 11:48:28Z INFO: LLAppViewer::disconnectViewer: Disconnecting viewer !
2022-10-23 11:48:28Z INFO: LLMemory::logMemoryInfo: System memory information: Max physical memory: 11631028KB - Allocated physical memory: 4871900KB - Available physical memory: 11631028KB - Allocated virtual memory: 9138844KB
2022-10-23 11:48:28Z INFO: LLInventoryModel::saveToFile: Saving cached inventory to file: C:\Users\Me\AppData\Local\CoolVLViewer\726003c3-9d93-4a8c-9f62-7597925d045e_inv.llsd
2022-10-23 11:48:30Z INFO: LLInventoryModel::saveToFile: Saved 70332 items in 8282 categories.
2022-10-23 11:48:30Z INFO: LLInventoryModel::saveToFile: Saving cached inventory to file: C:\Users\Me\AppData\Local\CoolVLViewer\ba2a564a-f0f1-4b82-9c61-b7520bfcd09f_inv.llsd
2022-10-23 11:48:30Z INFO: LLInventoryModel::saveToFile: Saved 3500 items in 286 categories.
2022-10-23 11:48:30Z INFO: LLAppViewer::saveExperienceCache: Saving: C:\Users\Me\AppData\Local\CoolVLViewer\experience_cache.xml
2022-10-23 11:48:30Z INFO: LLWorld::cleanupClass: Shutting down the World class...
2022-10-23 11:48:30Z INFO: LLViewerObjectList::cleanupClass: Destroying all the objects in the list...
2022-10-23 11:48:30Z INFO: LLViewerObjectList::killAllObjects: Marking all objects dead...
2022-10-23 11:48:30Z INFO: LLViewerObjectList::killAllObjects: Cleaning up dead objects...
2022-10-23 11:48:31Z INFO: LLViewerObjectList::cleanupClass: All objects destroyed.
2022-10-23 11:48:31Z INFO: LLWorld::cleanupClass: Removing regions...
2022-10-23 11:48:31Z INFO: LLWorld::removeRegion: Removing region at 464640:305408 (Purdy (bf1ee412-3b9f-46c8-8dfc-4b644d895a84))
2022-10-23 11:48:31Z INFO: LLViewerObjectList::killObjects: Removed 0 objects for region Purdy (bf1ee412-3b9f-46c8-8dfc-4b644d895a84) in 0.0046ms
2022-10-23 11:48:31Z INFO: LLVOCache::writeToCache: Object cache saved for region 'Purdy' in 22.8243ms, to file: C:\Users\Me\AppData\Local\CoolVLViewer\objectcache\objects_1815_1193.slc
2022-10-23 11:48:31Z INFO: LLWorld::removeRegion: Removing region at 464640:305664 (Aediman Hill (66a74fae-6d13-4fd4-bdab-7b87f1d4236b))
2022-10-23 11:48:31Z INFO: LLViewerObjectList::killObjects: Removed 0 objects for region Aediman Hill (66a74fae-6d13-4fd4-bdab-7b87f1d4236b) in 0.0026ms
2022-10-23 11:48:31Z INFO: LLVOCache::writeToCache: Object cache saved for region 'Aediman Hill' in 9.546ms, to file: C:\Users\Me\AppData\Local\CoolVLViewer\objectcache\objects_1815_1194.slc
2022-10-23 11:48:31Z INFO: LLWorld::removeRegion: Removing region at 464384:305408 (Breven (7aebcf66-0812-46ed-8a18-aeaed2d1c731))
2022-10-23 11:48:31Z INFO: LLViewerObjectList::killObjects: Removed 0 objects for region Breven (7aebcf66-0812-46ed-8a18-aeaed2d1c731) in 0.0027ms
2022-10-23 11:48:31Z INFO: LLVOCache::writeToCache: Object cache saved for region 'Breven' in 22.5728ms, to file: C:\Users\Me\AppData\Local\CoolVLViewer\objectcache\objects_1814_1193.slc
2022-10-23 11:48:31Z INFO: LLWorld::removeRegion: Removing region at 464384:305664 (Somani (39c8cba8-e099-42ff-88d3-6e5297954ae3))
2022-10-23 11:48:31Z INFO: LLViewerObjectList::killObjects: Removed 0 objects for region Somani (39c8cba8-e099-42ff-88d3-6e5297954ae3) in 0.0025ms
2022-10-23 11:48:31Z INFO: LLVOCache::writeToCache: Object cache saved for region 'Somani' in 25.6821ms, to file: C:\Users\Me\AppData\Local\CoolVLViewer\objectcache\objects_1814_1194.slc
2022-10-23 11:48:31Z INFO: LLViewerPartSim::cleanupClass: Destroying all particle groups...
2022-10-23 11:48:31Z INFO: LLViewerPartSim::cleanupClass: Destroying all particle sources...
2022-10-23 11:48:31Z INFO: LLViewerPartSim::cleanupClass: Particles destroyed.
2022-10-23 11:48:31Z INFO: LLWorld::cleanupClass: Removing water edges...
2022-10-23 11:48:31Z INFO: LLWorld::cleanupClass: World class shut down.
2022-10-23 11:48:31Z INFO: LLVOCache::~LLVOCache: Objects cache destroyed.
2022-10-23 11:48:31Z INFO: LLAppViewer::disconnectViewer: Firing LLDestroyClassList callbacks...
2022-10-23 11:48:31Z INFO: LLAppViewer::disconnectViewer: Transfer manager destroyed.
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: Viewer disconnected
2022-10-23 11:48:31Z INFO: LLEnvironment::cleanupClass: Cleaning up.
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: Pumping 'mainloop' to let coroutines shut down...
2022-10-23 11:48:31Z INFO: LLExperienceCache::idleCoro: Experience cache idle coroutine exited.
2022-10-23 11:48:31Z INFO: LLCoprocedurePool::coprocedureInvokerCoro: Exiting coroutine for pool: AIS
2022-10-23 11:48:31Z INFO: LLCoprocedurePool::coprocedureInvokerCoro: Exiting coroutine for pool: AssetStorage
2022-10-23 11:48:31Z INFO: LLCoprocedurePool::coprocedureInvokerCoro: Exiting coroutine for pool: AssetStorage (repeated 15 times)
2022-10-23 11:48:31Z INFO: LLCoprocedurePool::coprocedureInvokerCoro: Exiting coroutine for pool: ExpCache
2022-10-23 11:48:31Z INFO: LLCoprocedurePool::coprocedureInvokerCoro: Exiting coroutine for pool: ExpCache (repeated 4 times)
2022-10-23 11:48:31Z INFO: LLCoprocedurePool::coprocedureInvokerCoro: Exiting coroutine for pool: Upload
2022-10-23 11:48:31Z INFO: LLCoros::printActiveCoroutines: No active coroutine
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: LLEventPumps reset
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: LLEventPumps cleared
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: LLMortician::setZealous() called
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: Saving data...
2022-10-23 11:48:31Z INFO: LLControlGroup::saveToFile: Saved to C:\Users\Me\AppData\Roaming\SecondLife\user_settings\settings_coolvlviewer_1300.xml
2022-10-23 11:48:31Z INFO: LLControlGroup::saveToFile: Saved to C:\Users\Me\AppData\Roaming\SecondLife\kathrine_jansma\settings_per_account_coolvlviewer.xml
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: All user settings saved
2022-10-23 11:48:31Z INFO: HBFileSelector::saveDefaultPaths: Saving default selector paths to: C:\Users\Me\AppData\Roaming\SecondLife\user_settings\selector_paths.xml
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: selector_paths.xml saved
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: url_history.xml saved
2022-10-23 11:48:31Z INFO: LLMuteList::saveToFile: Mute list saved to file: C:\Users\Me\AppData\Local\CoolVLViewer\726003c3-9d93-4a8c-9f62-7597925d045e.cached_mute
2022-10-23 11:48:31Z INFO: LLMuteList::savePerAccountMuteList: Saving per-account mute-list...
2022-10-23 11:48:31Z INFO: LLMuteList::saveToFile: Mute list saved to file: C:\Users\Me\AppData\Roaming\SecondLife\kathrine_jansma\mute_list.txt
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: Display cleaned up
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: Stopped logging to fixed buffer
2022-10-23 11:48:31Z INFO: LLMeshRepository::shutdown: Shutting down mesh repository.
2022-10-23 11:48:31Z INFO: LLMeshRepoThread::~LLMeshRepoThread: Small GETs issued: 13765 - Large GETs issued: 7 - Max lock holdoffs: 3 - Total mesh headers stored: 8262
2022-10-23 11:48:31Z INFO: LLMeshRepository::shutdown: Shutting down decomposition system.
2022-10-23 11:48:31Z INFO: LLMeshRepository::shutdown: Clearing 165 cached skin info entries.
2022-10-23 11:48:31Z INFO: LLMeshRepository::shutdown: Clearing 5779 cached cost data entries.
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: Mesh repository shut down
2022-10-23 11:48:31Z INFO: LLAppViewer::cleanup: HUD objects cleaned up
2022-10-23 11:48:31Z INFO: LLKeyframeDataCache::clear: Total cached entries: 1145
2022-10-23 11:48:38Z INFO: LLKeyframeDataCache::clear: Cache cleared.
2022-10-23 11:48:38Z INFO: LLAppViewer::cleanup: HUD manager shut down
2022-10-23 11:48:38Z INFO: LLAppViewer::cleanup: Local bitmaps cleaned up
2022-10-23 11:48:38Z INFO: LLAppViewer::cleanup: Asset storage deleted
2022-10-23 11:48:45Z INFO: LLAppViewer::cleanup: All polymeshes freed
2022-10-23 11:48:45Z INFO: LLAppViewer::cleanup: Name cache cleaned up
2022-10-23 11:48:45Z INFO: LLAppViewer::cleanup: World map images cleared
2022-10-23 11:48:45Z INFO: LLStartUp::shutdownAudioEngine: Deleting existing audio engine instance
2022-10-23 11:48:45Z INFO: LLAudioEngine_FMOD::shutdown: Shutting down the audio engine...
2022-10-23 11:48:45Z INFO: LLAudioEngine_FMOD::shutdown: Closing FMOD Studio
2022-10-23 11:48:45Z INFO: LLAudioEngine_FMOD::shutdown: Done closing FMOD Studio
2022-10-23 11:48:45Z INFO: LLAppViewer::cleanup: Audio engine shut down
2022-10-23 11:48:45Z INFO: LLAppViewer::cleanup: Settings patched up
2022-10-23 11:48:45Z INFO: LLAppViewer::cleanup: Temporary cache files removed
2022-10-23 11:48:45Z INFO: LLViewerWindow::shutdownViews: LLModalDialog shut down.
2022-10-23 11:48:45Z INFO: LLViewerWindow::shutdownViews: Menus destroyed
2022-10-23 11:48:45Z INFO: HBFloaterTeleportHistory::~HBFloaterTeleportHistory: Teleport history instance destroyed.
2022-10-23 11:48:45Z INFO: LLFloaterWorldMap::~LLFloaterWorldMap: World map destroyed
2022-10-23 11:48:45Z INFO: LLFloaterTools::~LLFloaterTools: Floater Tools destroyed
2022-10-23 11:48:45Z INFO: LLHoverView::~LLHoverView: Hover-view destroyed.
2022-10-23 11:50:02Z INFO: LLViewerWindow::shutdownViews: Root view and children destroyed.


2022-10-23 11:57:46
Profile

Joined: 2009-03-17 18:42:51
Posts: 5523
Reply with quote
For me (and for the rare times when I actually "use" the viewer under Windoze, like what happened last week, when verifying that the UI textures corruption got fixed), the shutdown process, while (much) slower than under Linux (where it takes at worst a few seconds and usually under 2 seconds), the viewer definitely does not need minutes to shut down (tested under Win 7 Ultimate + ESU and Win 11 Pro 21H2), but at most 30 seconds or so...

This said, my Windows installations have been the subject of a very stringent diet, with removal of all "accessories" (including Windows Defender, Search, etc).

I would personally suspect Windows Defender (or any other "real time" anti virus) to be the culprit... You could try and exclude the viewer cache directories from Defender and Search, for example...


2022-10-23 15:33:47
Profile WWW

Joined: 2010-03-14 21:12:58
Posts: 86
Reply with quote
I have noticed long shutdown times on Linux when memory is tight and the system has been paging to disc for a while. It can take several minutes to shut down and exit as it resolves all the swapped pages and clears things up. But this is not in any way the viewer's fault. I just need a new computer.


2022-10-23 21:49:12
Profile

Joined: 2011-10-07 10:39:20
Posts: 181
Reply with quote
Sure, when memory is tight, you swap out memory. And that memory needs to be swapped back in to run the destructors of all those objects.

Thats fine, in general. Some systems like some games (or Windows with fast shutdown) optimize away those destructors by simply not cleaning up and just doing a controlled crash. Thats technically a memory leak, but the Memory Management Unit or operating system cleans up the mess later. You hide memory leaks in your code that way, so its only a late optimization to do.

In my case memory is plentiful, but probably some parts block each other shutting down. Henri's suggestion about virus scanners is probably a good one, those tend to do that. I'll investigate in that direction.


2022-10-23 22:01:58
Profile

Joined: 2009-03-17 18:42:51
Posts: 5523
Reply with quote
kathrine wrote:
Some systems like some games (or Windows with fast shutdown) optimize away those destructors by simply not cleaning up and just doing a controlled crash.
Well, that's a dirty hack that I had to recourse to for the experimental branch since otherwise, something related with libepoxy (likely a threading issue with probably a deadlock or infinite loop somewhere in Windows or the drivers) causes the viewer process to never exit, so the last thing I am doing (after a proper structures cleanup however) is a call to "TerminateProcess(GetCurrentProcess(), exit_code)", so to suicide the process...

You could try v1.30.1 and see if it exits faster than v1.30.0 for you (it should at least exit immediately after the logged "Goodbye")...


2022-10-24 16:47:33
Profile WWW

Joined: 2011-10-07 10:39:20
Posts: 181
Reply with quote
Some new insights.

I used Windows Performance Recorder (WPR) to capture a trace of the system during the shutdown of the viewer.
It seems the quite sequence causes a bunch of crash recorder WERFault.exe processes to get created, and only after that storm (and memory dumping) subsides, the viewer finally shuts down.

This is a part of it displayed in the Windows Performance Analyzer:
Image

In the lower pane, one notices the CoolVLViewer that has a lot of WERFault subprocesses. Those get spawned when Windows notices an appcrash somewhere. Its just strange to see so many of them.
In the upper pane, it shows the CPU usage, the usage spikes a bit before the WER process gets created, then drops again, until the next process gets created.

I'll try to figure out whats happening there.


2022-10-24 19:52:36
Profile

Joined: 2009-03-17 18:42:51
Posts: 5523
Reply with quote
kathrine wrote:
It seems the quite sequence causes a bunch of crash recorder WERFault.exe processes to get created, and only after that storm (and memory dumping) subsides, the viewer finally shuts down.
Well, that's interesting, and somewhat surprising since the viewer unregisters itself from the Windows Error Reporting (WER) (and reports it in the log via a "Windows error reporting disabled successfully." message), and uses its own crash dump routine (that got an anti-reentrance security check), which should get triggered in case of any crash on exit... :shock:


2022-10-24 21:17:10
Profile WWW

Joined: 2011-10-07 10:39:20
Posts: 181
Reply with quote
Indeed, it is pretty strange.

The log shows the mentioned "Windows error reporting disabled successfully."

The WERFault cascade seems to happen in a pause in the log, right after:

Code:
2022-10-24 19:13:49Z INFO: LLApp::setQuitting: Setting app state to QUITTING
2022-10-24 19:13:49Z INFO: LLImageGLThread::run: Shutting down thread 2 with GL context: 10002. Number of operations performed: 1197
2022-10-24 19:13:49Z INFO: LLImageGLThread::run: Shutting down thread 1 with GL context: 10001. Number of operations performed: 1184
2022-10-24 19:13:49Z INFO: LLImageGLThread::run: Shutting down thread 3 with GL context: 10003. Number of operations performed: 1204
2022-10-24 19:13:49Z INFO: LLImageGLThread::run: Shutting down thread 4 with GL context: 10004. Number of operations performed: 1213
----
2022-10-24 19:14:20Z INFO: LLAppViewer::forceQuit: Quitting...


So, maybe its some parts of the LLImageGLThread shutdown that causes WERFault to trigger.


2022-10-24 22:35:16
Profile

Joined: 2009-03-17 18:42:51
Posts: 5523
Reply with quote
kathrine wrote:
So, maybe its some parts of the LLImageGLThread shutdown that causes WERFault to trigger.
Likely in the OpenGL driver then... Not seeing any such problem here.


2022-10-24 22:36:40
Profile WWW

Joined: 2011-10-07 10:39:20
Posts: 181
Reply with quote
I guess i found the issue.

After attaching a debugger i noticed i still had GL debugging activated, so the code entered log_glerror() and promptly crashed there.
Maybe thats new or wasn't tested yet, but glGetError() crashes when no current GL context is around.

So i added a quick check (probably wrong for Linux... like this), and the WERFaults spawn stopped, despite GL debugging being enable.
It also speeds up the shutdown again, so it is quick.

Code:
void log_glerror(const char* file, U32 line, bool crash)
{
   static std::string filename;
        /* Check if we have a GL context to call glGetError(), might not be the case in a thread */
   HGLRC context = wglGetCurrentContext();
   if (!context) {
      return;
   }
   GLenum error = glGetError();
   if (LL_UNLIKELY(error))


Not sure if this is a bug or just bad usage, but i guess the logging should check if a context exists.


2022-10-25 00:01:58
Profile
Display posts from previous:  Sort by  
Reply to topic   [ 13 posts ]  Go to page 1, 2  Next

Who is online

Users browsing this forum: No registered users and 31 guests


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot post attachments in this forum

Search for:
Jump to:  
Powered by phpBB® Forum Software © phpBB Group
Designed by ST Software.