[Opensim-users] slow GET request for /CAPS

Tue Feb 14 01:56:55 UTC 2012

On 11/02/12 15:36, Akira Sonoda wrote:
> What i found out so far: The message is written into the log when a
> request exceeds a given threshold. Then a request is considered slow.
> Close Encounter is a really nice region to do long time studies,
> because the workload is almost the same over years now: Not much
> building, Not much scripts but each friday evening a big party with up
> to 25 avatars simultaneously on that sim. Here is a graph showing the
> increase of slow GET CAPS:
>
> http://farm8.staticflickr.com/7194/6855984135_5ac407a5ec_b_d.jpg
>
> As you can see we have a huge increase of slow requests since dcember.
> Okie what is the reason for this increase as i mentioned the workload
> is the same over 2 years. Upgrade to mono 2.10.6:
>
> http://farm8.staticflickr.com/7200/6855984237_62ab033d61_b_d.jpg
>
> Possible... I installed the update on the 26. November 2011. Coud be,
> but it's still no evidence.
>
> During the party i did some samples and found out that some of the
> caps producing slow GET requests were:
>
> GetTexture
> FetchInventoryDescendents2
> FetchInventory2
>
> Hmm FetchInventory2.... it immediately came to my mind that i did
> change the OpenSim.ini to:
>
> [ClientStack.LindenCaps]
>      ;; For the long list of capabilities, see OpenSimDefaults.ini
>      ;; Here are the few ones you may want to change. Possible values
>      ;; are:
>      ;;   "" -- empty, capability disabled
>      ;;   "localhost" -- capability enabled and served by the simulator
>      ;;   "<url>" -- capability enabled and served by some other server
>      ;;
>      ; These are enabled by default to localhost. Change if you see fit.
>      Cap_GetTexture = "localhost"
>      Cap_GetMesh = "localhost"
>      ; This is disabled by default. Change if you see fit. Note that
>      ; serving this cap from the simulators may lead to poor performace.
>      Cap_FetchInventoryDescendents2 = "localhost"	
>      Cap_FetchInventory2 = "localhost"
>
> as suggested in one news post in osgrid.org. Reading the comment "Note
> that serving this cap .... poor performance". Well i made the upgrade
> to the newest version only one week ago, but seen the increase of slow
> GET requests since december 2011 then this change is most likely not
> the root cause of this increase.
>
> Other observations i made:
>
> Mostly people using the Singularity viewer were affected by slow GET
> ... CAPS requests. The people using Imprudence had none to just a few
> slow requests. But still those were just a few samples i took and
> certainly not a serious research.
>
> in order to correlate the data from the logs i'd need the following
> information in the logs:
>
> Authentication (or any other) procedure should log the Avatar Name
> (ok), Avatar UUID (ok), Viewer Name (nok), IP (nok)
> the IP address is used to correlate the slow GET Request with the Avatar.
> Then during the registration of the capability with the http server
> the Name and the UUID of the capability should be written into the log
> (LogLevel INFO)
>
> This would allow me to find out if there's a pattern like:
>
> Slow CAPS (Name)<->  user,
> Slow CAPS (Name)<->  viewer,
>
> it is not important when the information is written to the log but it
> is important THAT it will be written into the Log. Preferred Log Level
> INFO, because i do not run this sim in DEBUG mode.

I added IP address and viewer name to the new viewer connection logging.  This was already available to the simulator 
but wasn't being logged.

However, adding a log message for each capability registration is too spammy.  I think that a better approach would be 
to output this on a 'slow' message but this will take non-trivial re-engineering.  I accept that without this knowing 
the other details may not be helpful.

These messages will probably only ever be DEBUG or possibly WARN, they are far too spammy to be INFO.  You can 
selectively output certain log messages at any level by changing the log4net config in OpenSim.exe.config [1].

[1] http://opensimulator.org/wiki/Logging

>
>
>
> Am 11. Februar 2012 03:39 schrieb Justin Clark-Casey<jjustincc at googlemail.com>:
>
>> There are a very large number of possible causes (busy simulator, poor
>> network links, many http requests) not helped by the fact that the debug
>> message doesn't say which cap is responsible.
>>
>> Unfortunately, this means that I can't suggest any particular course of
>> action.
>>
>> In future, this information should be linked and spat out for diagnostic
>> purposes which will help a bit.  In the mean time, it is possible to match
>> the CAPS url with the information output by the "region console" command,
>> though this will generate a flood of info if there's any more than a single
>> avatar.
>>
>> --
>> Justin Clark-Casey (justincc)
>> http://justincc.org/blog
>> http://twitter.com/justincc
>> _______________________________________________
>> Opensim-users mailing list
>> Opensim-users at lists.berlios.de
>> https://lists.berlios.de/mailman/listinfo/opensim-users
> _______________________________________________
> Opensim-users mailing list
> Opensim-users at lists.berlios.de
> https://lists.berlios.de/mailman/listinfo/opensim-users
>

-- 
Justin Clark-Casey (justincc)
http://justincc.org/blog
http://twitter.com/justincc