Orenh: /* Logging Activity */

2014-03-25T08:25:32Z

‎Logging Activity

Orenh at 07:30, 25 March 2014

2014-03-25T07:30:35Z

Orenh at 07:28, 25 March 2014

2014-03-25T07:28:19Z

Orenh: Created page with "*=Overview= A lot of the work in OpenSim is done in tasks that are run on a general-purpose threadpool. This threadpool is managed in Util.cs. Tasks are added to the threadp..."

2014-03-25T07:25:56Z

Created page with "*=Overview= A lot of the work in OpenSim is done in tasks that are run on a general-purpose threadpool. This threadpool is managed in Util.cs. Tasks are added to the threadp..."

New page

*=Overview=

A lot of the work in OpenSim is done in tasks that are run on a general-purpose threadpool. This threadpool is managed in Util.cs.

Tasks are added to the threadpool by calling <code>Util.FireAndForget(function)</code>.

=Logging Activity=

There's a console command that enables logging of the tasks in the threadpool. When this option is enabled, the following events are logged:

* Task queued (added to the threadpool)
* Task started running
* Task finished running
* Task timed-out and was terminated

Each time these events are logged, we also log the number of Queued and Running tasks. This shows how busy OpenSim is.

To enable or disable logging, run from the console:

debug threadpool level <num>

There are 4 logging levels:

'''0 = no logging (default)''' <br/>
Turns off logging.

'''1 = only first line of stack trace; don't log common threads''' <br/>
Short logging. Instead of logging the full stack trace where the task was queued, this only logs the first line of the stack trace. This doesn't log common tasks such as BeginFireQueueEmpty, since they tend to fill up the log quickly.

'''2 = full stack trace; don't log common threads''' <br/>
Logs the full stack trace where the task was queued. Still doesn't log common tasks.

'''3 = full stack trace, including common threads''' <br/>
Logs everything.

== Sample Logging Output ==

'''Level 1'''

<pre style="white-space: pre-wrap; word-wrap: break-word;">
2014-03-25 08:50:39,403 DEBUG - OpenSim.Framework.Util Queue threadfunc 32 (Queued 1, Running 0) at OpenSim.Region.ClientStack.LindenUDP.LLClientView.SendWindData(Vector2[] windSpeeds) in c:\opensim\OpenSim\Region\ClientStack\Linden\UDP\LLClientView.cs:line 1292
2014-03-25 08:50:39,406 DEBUG - OpenSim.Framework.Util Run threadfunc 32 (Queued 0, Running 1)
2014-03-25 08:50:39,409 DEBUG - OpenSim.Framework.Util Exit threadfunc 32 (0 ms)
</pre>

'''Levels 2-3'''

<pre style="white-space: pre-wrap; word-wrap: break-word;">
2014-03-25 08:50:52,118 DEBUG - OpenSim.Framework.Util Queue threadfunc 33 (Queued 1, Running 0) at OpenSim.Region.Framework.Scenes.ScenePresence.SendScriptEventToAttachments(String eventName, Object[] args) in c:\opensim\OpenSim\Region\Framework\Scenes\ScenePresence.cs:line 4283
at OpenSim.Region.Framework.Scenes.Animation.ScenePresenceAnimator.TrySetMovementAnimation(String anim) in c:\opensim\OpenSim\Region\Framework\Scenes\Animation\ScenePresenceAnimator.cs:line 190
at OpenSim.Region.Framework.Scenes.Animation.ScenePresenceAnimator.UpdateMovementAnimations() in c:\opensim\OpenSim\Region\Framework\Scenes\Animation\ScenePresenceAnimator.cs:line 461
at OpenSim.Region.Framework.Scenes.ScenePresence.AddNewMovement(Vector3 vec, Single thisAddSpeedModifier) in c:\opensim\OpenSim\Region\Framework\Scenes\ScenePresence.cs:line 3060
at OpenSim.Region.Framework.Scenes.ScenePresence.HandleAgentUpdate(IClientAPI remoteClient, AgentUpdateArgs agentData) in c:\opensim\OpenSim\Region\Framework\Scenes\ScenePresence.cs:line 2154
at OpenSim.Region.ClientStack.LindenUDP.LLClientView.HandleAgentUpdate(IClientAPI sener, Packet packet) in c:\opensim\OpenSim\Region\ClientStack\Linden\UDP\LLClientView.cs:line 5778
at OpenSim.Region.ClientStack.LindenUDP.LLClientView.ProcessPacketMethod(Packet packet) in c:\opensim\OpenSim\Region\ClientStack\Linden\UDP\LLClientView.cs:line 707
at OpenSim.Region.ClientStack.LindenUDP.LLClientView.ProcessInPacket(Packet packet) in c:\opensim\OpenSim\Region\ClientStack\Linden\UDP\LLClientView.cs:line 12372
at OpenSim.Region.ClientStack.LindenUDP.LLUDPServer.ProcessInPacket(IncomingPacket incomingPacket) in c:\opensim\OpenSim\Region\ClientStack\Linden\UDP\LLUDPServer.cs:line 2265
at OpenSim.Region.ClientStack.LindenUDP.LLUDPServer.IncomingPacketHandler() in c:\opensim\OpenSim\Region\ClientStack\Linden\UDP\LLUDPServer.cs:line 1990
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Threading.ThreadHelper.ThreadStart()
2014-03-25 08:50:52,126 DEBUG - OpenSim.Framework.Util Run threadfunc 33 (Queued 0, Running 1)
2014-03-25 08:50:52,129 DEBUG - OpenSim.Framework.Util Exit threadfunc 33 (0 ms)
</pre>

← Older revision		Revision as of 08:25, 25 March 2014
Line 19:		Line 19:
	To enable or disable logging, run from the console:		To enable or disable logging, run from the console:

−	debug threadpool level <~~num~~>	+	debug threadpool level <level>

@@ Line 35: / Line 35: @@
 '''3 = full stack trace, including common threads''' <br/>
 Logs everything.
 == Sample Logging Output ==

@@ Line 1: / Line 1: @@
-*=Overview=
+=Overview=
 A lot of the work in OpenSim is done in tasks that are run on a general-purpose threadpool. This threadpool is managed in Util.cs.
@@ Line 66: / Line 66: @@
 -03-25 08:50:52,129 DEBUG - OpenSim.Framework.Util Exit threadfunc 33 (0 ms)
 </pre>

General-Purpose Threadpool - Revision history

Orenh: /* Logging Activity */

Orenh at 07:30, 25 March 2014

Orenh at 07:28, 25 March 2014

Orenh: Created page with "*=Overview= A lot of the work in OpenSim is done in tasks that are run on a general-purpose threadpool. This threadpool is managed in Util.cs. Tasks are added to the threadp..."