livie
/
phoenix-firestorm
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

DRTVWR-559: Replace debugLoggingEnabled() function with LL_DEBUGS(). 

The trouble with debugLoggingEnabled() is that it locked mutexes and searched
maps every time that call was reached. LL_DEBUGS() has the same functionality
(albeit with idiosyncratic syntax) but performs expensive lookups only once
per session, caching the result in a local static variable.
master
Nat Goodspeed 2023-05-03 09:55:31 -04:00
parent 2994833e7c
commit 2a10bd406c
10 changed files with 127 additions and 164 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
indra/cmake/FMODSTUDIO.cmake
View File

@ -2,7 +2,7 @@
include_guard()
# FMODSTUDIO can be set when launching the make using the argument -DFMODSTUDIO:BOOL=ON
# FMODSTUDIO can be set when launching the make using the argument -DUSE_FMODSTUDIO:BOOL=ON
# When building using proprietary binaries though (i.e. having access to LL private servers),
# we always build with FMODSTUDIO.
if (INSTALL_PROPRIETARY)

12
indra/llcommon/llcallstack.h
View File

@ -79,9 +79,9 @@ struct LLContextStatus
LL_COMMON_API std::ostream& operator<<(std::ostream& s, const LLContextStatus& context_status);
#define dumpStack(tag) \
if (debugLoggingEnabled(tag)) \
{ \
LLCallStack cs; \
LL_DEBUGS(tag) << "STACK:\n" << "====================\n" << cs << "====================" << LL_ENDL; \
}
#define dumpStack(tag) \
LL_DEBUGS(tag) << "STACK:\n" \
<< "====================\n" \
<< LLCallStack() \
<< "====================" \
<< LL_ENDL;

14
indra/llcommon/llerror.cpp
View File

@ -1609,19 +1609,5 @@ namespace LLError
}
}
bool debugLoggingEnabled(const std::string& tag)
{
LLMutexTrylock lock(getMutex<LOG_MUTEX>(), 5);
if (!lock.isLocked())
{
return false;
}
SettingsConfigPtr s = Globals::getInstance()->getSettingsConfig();
LLError::ELevel level = LLError::LEVEL_DEBUG;
bool res = checkLevelMap(s->mTagLevelMap, tag, level);
return res;
}

24
indra/llcommon/llerror.h
View File

@ -467,7 +467,29 @@ typedef LLError::NoClassInfo _LL_CLASS_TO_LOG;
LLError::CallSite& _site(_sites[which]); \
lllog_test_()
// Check at run-time whether logging is enabled, without generating output
/*
// Check at run-time whether logging is enabled, without generating output.
Resist the temptation to add a function like this because it incurs the
expense of locking and map-searching every time control reaches it.
bool debugLoggingEnabled(const std::string& tag);
Instead of:
if debugLoggingEnabled("SomeTag")
{
// ... presumably expensive operation ...
LL_DEBUGS("SomeTag") << ... << LL_ENDL;
}
Use this:
LL_DEBUGS("SomeTag");
// ... presumably expensive operation ...
LL_CONT << ...;
LL_ENDL;
LL_DEBUGS("SomeTag") performs the locking and map-searching ONCE, then caches
the result in a static variable.
*/
#endif // LL_LLERROR_H

122
indra/llwindow/llwindowwin32.cpp
View File

@ -2308,8 +2308,6 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
LLWindowWin32* window_imp = (LLWindowWin32*)GetWindowLongPtr(h_wnd, GWLP_USERDATA);
bool debug_window_proc = false; // gDebugWindowProc || debugLoggingEnabled("Window");
if (NULL != window_imp)
{
// Juggle to make sure we can get negative positions for when
@ -2336,11 +2334,8 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_DEVICECHANGE:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_DEVICECHANGE");
if (debug_window_proc)
{
LL_INFOS("Window") << " WM_DEVICECHANGE: wParam=" << w_param
<< "; lParam=" << l_param << LL_ENDL;
}
LL_INFOS("Window") << " WM_DEVICECHANGE: wParam=" << w_param
<< "; lParam=" << l_param << LL_ENDL;
if (w_param == DBT_DEVNODES_CHANGED || w_param == DBT_DEVICEARRIVAL)
{
WINDOW_IMP_POST(window_imp->mCallbacks->handleDeviceChange(window_imp));
@ -2404,14 +2399,11 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
BOOL activating = (BOOL)w_param;
BOOL minimized = window_imp->getMinimized();
if (debug_window_proc)
{
LL_INFOS("Window") << "WINDOWPROC ActivateApp "
<< " activating " << S32(activating)
<< " minimized " << S32(minimized)
<< " fullscreen " << S32(window_imp->mFullscreen)
<< LL_ENDL;
}
LL_INFOS("Window") << "WINDOWPROC ActivateApp "
<< " activating " << S32(activating)
<< " minimized " << S32(minimized)
<< " fullscreen " << S32(window_imp->mFullscreen)
<< LL_ENDL;
if (window_imp->mFullscreen)
{
@ -2456,13 +2448,10 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
// JC - I'm not sure why, but if we don't report that we handled the
// WM_ACTIVATE message, the WM_ACTIVATEAPP messages don't work
// properly when we run fullscreen.
if (debug_window_proc)
{
LL_INFOS("Window") << "WINDOWPROC Activate "
<< " activating " << S32(activating)
<< " minimized " << S32(minimized)
<< LL_ENDL;
}
LL_INFOS("Window") << "WINDOWPROC Activate "
<< " activating " << S32(activating)
<< " minimized " << S32(minimized)
<< LL_ENDL;
});
break;
@ -2541,12 +2530,9 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
window_imp->mRawLParam = l_param;
{
if (debug_window_proc)
{
LL_INFOS("Window") << "Debug WindowProc WM_KEYDOWN "
<< " key " << S32(w_param)
<< LL_ENDL;
}
LL_INFOS("Window") << "Debug WindowProc WM_KEYDOWN "
<< " key " << S32(w_param)
<< LL_ENDL;
gKeyboard->handleKeyDown(w_param, mask);
}
@ -2571,12 +2557,9 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
{
LL_RECORD_BLOCK_TIME(FTM_KEYHANDLER);
if (debug_window_proc)
{
LL_INFOS("Window") << "Debug WindowProc WM_KEYUP "
<< " key " << S32(w_param)
<< LL_ENDL;
}
LL_INFOS("Window") << "Debug WindowProc WM_KEYUP "
<< " key " << S32(w_param)
<< LL_ENDL;
gKeyboard->handleKeyUp(w_param, mask);
}
});
@ -2586,10 +2569,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_IME_SETCONTEXT:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_IME_SETCONTEXT");
if (debug_window_proc)
{
LL_INFOS("Window") << "WM_IME_SETCONTEXT" << LL_ENDL;
}
LL_INFOS("Window") << "WM_IME_SETCONTEXT" << LL_ENDL;
if (LLWinImm::isAvailable() && window_imp->mPreeditor)
{
l_param &= ~ISC_SHOWUICOMPOSITIONWINDOW;
@ -2600,10 +2580,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_IME_STARTCOMPOSITION:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_IME_STARTCOMPOSITION");
if (debug_window_proc)
{
LL_INFOS() << "WM_IME_STARTCOMPOSITION" << LL_ENDL;
}
LL_INFOS("Window") << "WM_IME_STARTCOMPOSITION" << LL_ENDL;
if (LLWinImm::isAvailable() && window_imp->mPreeditor)
{
WINDOW_IMP_POST(window_imp->handleStartCompositionMessage());
@ -2614,10 +2591,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_IME_ENDCOMPOSITION:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_IME_ENDCOMPOSITION");
if (debug_window_proc)
{
LL_INFOS() << "WM_IME_ENDCOMPOSITION" << LL_ENDL;
}
LL_INFOS("Window") << "WM_IME_ENDCOMPOSITION" << LL_ENDL;
if (LLWinImm::isAvailable() && window_imp->mPreeditor)
{
return 0;
@ -2627,10 +2601,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_IME_COMPOSITION:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_IME_COMPOSITION");
if (debug_window_proc)
{
LL_INFOS() << "WM_IME_COMPOSITION" << LL_ENDL;
}
LL_INFOS("Window") << "WM_IME_COMPOSITION" << LL_ENDL;
if (LLWinImm::isAvailable() && window_imp->mPreeditor)
{
WINDOW_IMP_POST(window_imp->handleCompositionMessage(l_param));
@ -2641,10 +2612,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_IME_REQUEST:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_IME_REQUEST");
if (debug_window_proc)
{
LL_INFOS() << "WM_IME_REQUEST" << LL_ENDL;
}
LL_INFOS("Window") << "WM_IME_REQUEST" << LL_ENDL;
if (LLWinImm::isAvailable() && window_imp->mPreeditor)
{
LRESULT result;
@ -2673,12 +2641,9 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
// it is worth trying. The good old WM_CHAR works just fine even for supplementary
// characters. We just need to take care of surrogate pairs sent as two WM_CHAR's
// by ourselves. It is not that tough. -- Alissa Sabre @ SL
if (debug_window_proc)
{
LL_INFOS("Window") << "Debug WindowProc WM_CHAR "
<< " key " << S32(w_param)
<< LL_ENDL;
}
LL_INFOS("Window") << "Debug WindowProc WM_CHAR "
<< " key " << S32(w_param)
<< LL_ENDL;
// Even if LLWindowCallbacks::handleUnicodeChar(llwchar, BOOL) returned FALSE,
// we *did* processed the event, so I believe we should not pass it to DefWindowProc...
window_imp->handleUnicodeUTF16((U16)w_param, gKeyboard->currentMask(FALSE));
@ -3006,19 +2971,17 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
S32 height = S32(HIWORD(l_param));
if (debug_window_proc)
{
BOOL maximized = (w_param == SIZE_MAXIMIZED);
BOOL restored = (w_param == SIZE_RESTORED);
BOOL minimized = (w_param == SIZE_MINIMIZED);
LL_INFOS("Window");
BOOL maximized = (w_param == SIZE_MAXIMIZED);
BOOL restored = (w_param == SIZE_RESTORED);
BOOL minimized = (w_param == SIZE_MINIMIZED);
LL_INFOS("Window") << "WINDOWPROC Size "
<< width << "x" << height
<< " max " << S32(maximized)
<< " min " << S32(minimized)
<< " rest " << S32(restored)
<< LL_ENDL;
}
LL_CONT << "WINDOWPROC Size "
<< width << "x" << height
<< " max " << S32(maximized)
<< " min " << S32(minimized)
<< " rest " << S32(restored);
LL_ENDL;
// There's an odd behavior with WM_SIZE that I would call a bug. If
// the window is maximized, and you call MoveWindow() with a size smaller
@ -3084,10 +3047,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_SETFOCUS:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_SETFOCUS");
if (debug_window_proc)
{
LL_INFOS("Window") << "WINDOWPROC SetFocus" << LL_ENDL;
}
LL_INFOS("Window") << "WINDOWPROC SetFocus" << LL_ENDL;
WINDOW_IMP_POST(window_imp->mCallbacks->handleFocus(window_imp));
return 0;
}
@ -3095,10 +3055,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
case WM_KILLFOCUS:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - WM_KILLFOCUS");
if (debug_window_proc)
{
LL_INFOS("Window") << "WINDOWPROC KillFocus" << LL_ENDL;
}
LL_INFOS("Window") << "WINDOWPROC KillFocus" << LL_ENDL;
WINDOW_IMP_POST(window_imp->mCallbacks->handleFocusLost(window_imp));
return 0;
}
@ -3219,10 +3176,7 @@ LRESULT CALLBACK LLWindowWin32::mainWindowProc(HWND h_wnd, UINT u_msg, WPARAM w_
default:
{
LL_PROFILE_ZONE_NAMED_CATEGORY_WIN32("mwp - default");
if (debug_window_proc)
{
LL_INFOS("Window") << "Unhandled windows message code: 0x" << std::hex << U32(u_msg) << LL_ENDL;
}
LL_INFOS("Window") << "Unhandled windows message code: 0x" << std::hex << U32(u_msg) << LL_ENDL;
}
break;
}

34
indra/newview/llappviewerwin32.cpp
View File

@ -656,16 +656,18 @@ bool LLAppViewerWin32::init()
LL_VIEWER_VERSION_PATCH << '.' <<
LL_VIEWER_VERSION_BUILD));
DWORD dwFlags = MDSF_NONINTERACTIVE | // automatically submit report without prompting
MDSF_PREVENTHIJACKING; // disallow swiping Exception filter
DWORD dwFlags = MDSF_NONINTERACTIVE | // automatically submit report without prompting
MDSF_PREVENTHIJACKING; // disallow swiping Exception filter
bool needs_log_file = !isSecondInstance() && debugLoggingEnabled("BUGSPLAT");
if (needs_log_file)
{
// Startup only!
LL_INFOS("BUGSPLAT") << "Engaged BugSplat logging to bugsplat.log" << LL_ENDL;
dwFlags |= MDSF_LOGFILE | MDSF_LOG_VERBOSE;
}
bool needs_log_file = !isSecondInstance();
LL_DEBUGS("BUGSPLAT");
if (needs_log_file)
{
// Startup only!
LL_INFOS("BUGSPLAT") << "Engaged BugSplat logging to bugsplat.log" << LL_ENDL;
dwFlags |= MDSF_LOGFILE | MDSF_LOG_VERBOSE;
}
LL_ENDL;
// have to convert normal wide strings to strings of __wchar_t
sBugSplatSender = new MiniDmpSender(
@ -676,12 +678,14 @@ bool LLAppViewerWin32::init()
dwFlags);
sBugSplatSender->setCallback(bugsplatSendLog);
if (needs_log_file)
{
// Log file will be created in %TEMP%, but it will be moved into logs folder in case of crash
std::string log_file = gDirUtilp->getExpandedFilename(LL_PATH_LOGS, "bugsplat.log");
sBugSplatSender->setLogFilePath(WCSTR(log_file));
}
LL_DEBUGS("BUGSPLAT");
if (needs_log_file)
{
// Log file will be created in %TEMP%, but it will be moved into logs folder in case of crash
std::string log_file = gDirUtilp->getExpandedFilename(LL_PATH_LOGS, "bugsplat.log");
sBugSplatSender->setLogFilePath(WCSTR(log_file));
}
LL_ENDL;
// engage stringize() overload that converts from wstring
LL_INFOS("BUGSPLAT") << "Engaged BugSplat(" << LL_TO_STRING(LL_VIEWER_CHANNEL)

11
indra/newview/llviewerstats.cpp
View File

@ -829,12 +829,11 @@ void send_viewer_stats(bool include_preferences)
LL_INFOS("LogViewerStatsPacket") << "Sending viewer statistics: " << body << LL_ENDL;
if (debugLoggingEnabled("LogViewerStatsPacket"))
{
std::string filename("viewer_stats_packet.xml");
llofstream of(filename.c_str());
LLSDSerialize::toPrettyXML(body,of);
}
LL_DEBUGS("LogViewerStatsPacket");
std::string filename("viewer_stats_packet.xml");
llofstream of(filename.c_str());
LLSDSerialize::toPrettyXML(body,of);
LL_ENDL;
// The session ID token must never appear in logs
body["session_id"] = gAgentSessionID;

12
indra/newview/llvoavatar.cpp
View File

@ -11070,8 +11070,9 @@ void LLVOAvatar::calculateUpdateRenderComplexity()
// Diagnostic output to identify all avatar-related textures.
// Does not affect rendering cost calculation.
if (isSelf() && debugLoggingEnabled("ARCdetail"))
if (isSelf())
{
LL_DEBUGS("ARCdetail");
// print any attachment textures we didn't already know about.
for (LLVOVolume::texture_cost_t::iterator it = textures.begin(); it != textures.end(); ++it)
{
@ -11080,17 +11081,17 @@ void LLVOAvatar::calculateUpdateRenderComplexity()
&& (all_textures.find(image_id) == all_textures.end()))
{
// attachment texture not previously seen.
LL_DEBUGS("ARCdetail") << "attachment_texture: " << image_id.asString() << LL_ENDL;
LL_CONT << "attachment_texture: " << image_id.asString() << '\n';
all_textures.insert(image_id);
}
}
// print any avatar textures we didn't already know about
for (LLAvatarAppearanceDictionary::Textures::const_iterator iter = LLAvatarAppearance::getDictionary()->getTextures().begin();
for (LLAvatarAppearanceDictionary::Textures::const_iterator iter = LLAvatarAppearance::getDictionary()->getTextures().begin();
iter != LLAvatarAppearance::getDictionary()->getTextures().end();
++iter)
{
const LLAvatarAppearanceDictionary::TextureEntry *texture_dict = iter->second;
const LLAvatarAppearanceDictionary::TextureEntry *texture_dict = iter->second;
// TODO: MULTI-WEARABLE: handle multiple textures for self
const LLViewerTexture* te_image = getImage(iter->first,0);
if (!te_image)
@ -11100,10 +11101,11 @@ void LLVOAvatar::calculateUpdateRenderComplexity()
continue;
if (all_textures.find(image_id) == all_textures.end())
{
LL_DEBUGS("ARCdetail") << "local_texture: " << texture_dict->mName << ": " << image_id << LL_ENDL;
LL_CONT << "local_texture: " << texture_dict->mName << ": " << image_id << '\n';
all_textures.insert(image_id);
}
}
LL_ENDL;
}
if ( cost != mVisualComplexity )

43
indra/newview/llvovolume.cpp
View File

@ -1617,15 +1617,14 @@ BOOL LLVOVolume::updateLOD()
if (lod_changed)
{
if (debugLoggingEnabled("AnimatedObjectsLinkset"))
{
if (isAnimatedObject() && isRiggedMesh())
{
std::string vobj_name = llformat("Vol%p", this);
F32 est_tris = getEstTrianglesMax();
LL_DEBUGS("AnimatedObjectsLinkset") << vobj_name << " updateLOD to " << getLOD() << ", tris " << est_tris << LL_ENDL;
}
}
LL_DEBUGS("AnimatedObjectsLinkset");
if (isAnimatedObject() && isRiggedMesh())
{
std::string vobj_name = llformat("Vol%p", this);
F32 est_tris = getEstTrianglesMax();
LL_CONT << vobj_name << " updateLOD to " << getLOD() << ", tris " << est_tris;
}
LL_ENDL;
gPipeline.markRebuild(mDrawable, LLDrawable::REBUILD_VOLUME, FALSE);
mLODChanged = TRUE;
@ -4532,15 +4531,14 @@ const LLMatrix4& LLVOVolume::getWorldMatrix(LLXformMatrix* xform) const
void LLVOVolume::markForUpdate(BOOL priority)
{
if (debugLoggingEnabled("AnimatedObjectsLinkset"))
LL_DEBUGS("AnimatedObjectsLinkset");
if (isAnimatedObject() && isRiggedMesh())
{
if (isAnimatedObject() && isRiggedMesh())
{
std::string vobj_name = llformat("Vol%p", this);
F32 est_tris = getEstTrianglesMax();
LL_DEBUGS("AnimatedObjectsLinkset") << vobj_name << " markForUpdate, tris " << est_tris << LL_ENDL;
}
std::string vobj_name = llformat("Vol%p", this);
F32 est_tris = getEstTrianglesMax();
LL_CONT << vobj_name << " markForUpdate, tris " << est_tris;
}
LL_ENDL;
if (mDrawable)
{
@ -6098,15 +6096,14 @@ void LLVolumeGeometryManager::rebuildMesh(LLSpatialGroup* group)
if (!vobj) continue;
if (debugLoggingEnabled("AnimatedObjectsLinkset"))
LL_DEBUGS("AnimatedObjectsLinkset");
if (vobj->isAnimatedObject() && vobj->isRiggedMesh())
{
if (vobj->isAnimatedObject() && vobj->isRiggedMesh())
{
std::string vobj_name = llformat("Vol%p", vobj);
F32 est_tris = vobj->getEstTrianglesMax();
LL_DEBUGS("AnimatedObjectsLinkset") << vobj_name << " rebuildMesh, tris " << est_tris << LL_ENDL;
}
std::string vobj_name = llformat("Vol%p", vobj);
F32 est_tris = vobj->getEstTrianglesMax();
LL_CONT << vobj_name << " rebuildMesh, tris " << est_tris;
}
LL_ENDL;
if (vobj->isNoLOD()) continue;
vobj->preRebuild();

17
indra/newview/pipeline.cpp
View File

@ -3016,17 +3016,16 @@ void LLPipeline::markRebuild(LLDrawable *drawablep, LLDrawable::EDrawableFlags f
{
if (drawablep && !drawablep->isDead() && assertInitialized())
{
if (debugLoggingEnabled("AnimatedObjectsLinkset"))
LL_DEBUGS("AnimatedObjectsLinkset");
LLVOVolume *vol_obj = drawablep->getVOVolume();
if (vol_obj && vol_obj->isAnimatedObject() && vol_obj->isRiggedMesh())
{
LLVOVolume *vol_obj = drawablep->getVOVolume();
if (vol_obj && vol_obj->isAnimatedObject() && vol_obj->isRiggedMesh())
{
std::string vobj_name = llformat("Vol%p", vol_obj);
F32 est_tris = vol_obj->getEstTrianglesMax();
LL_DEBUGS("AnimatedObjectsLinkset") << vobj_name << " markRebuild, tris " << est_tris
<< " priority " << (S32) priority << " flag " << std::hex << flag << LL_ENDL;
}
std::string vobj_name = llformat("Vol%p", vol_obj);
F32 est_tris = vol_obj->getEstTrianglesMax();
LL_CONT << vobj_name << " markRebuild, tris " << est_tris
<< " priority " << (S32) priority << " flag " << std::hex << flag;
}
LL_ENDL;
if (!drawablep->isState(LLDrawable::BUILT))
{