Anonymous | Login | Signup for a new account | 2021-01-15 22:23 PST | ![]() |
Main | My View | View Issues | Change Log | Roadmap | Summary | My Account |
View Issue Details [ Jump to Notes ] | [ Issue History ] [ Print ] | |||||||||
ID | Project | Category | View Status | Date Submitted | Last Update | |||||
0008127 | opensim | [REGION] Script Functions | public | 2017-02-06 21:32 | 2017-05-17 21:11 | |||||
Reporter | Kayaker Magic | |||||||||
Assigned To | ||||||||||
Priority | high | Severity | major | Reproducibility | always | |||||
Status | new | Resolution | open | |||||||
Platform | Various | Operating System | Microsoft .NET | Operating System Version | 0.8 and up | |||||
Product Version | 0.9.0 | |||||||||
Target Version | Fixed in Version | |||||||||
Summary | 0008127: List fetching functions (eg llList2Vector) are dog slow on Microsoft servers | |||||||||
Description | This Mantis has been extensively edited. The test script has been simplified to a list of float and statistics are calculated now. The basic problem is that one would expect the following three lines in a script to run very fast: llResetTime(); r=llList2Float(test,(integer)llFrand(500.0)); //random fetch float time = llGetTime(); //how long did that take? And on some servers it does, but on others it is 1,000 to 10,000 times slower In my experience, the slow results have always been when running OpenSim on a Microsoft Server. Going back to older and older versions of OpenSim I see the problem has been around a while. Here are some recent (May 17, 2017) timing results: Operating System, OpenSim Version, List fetch time Windows 10, 0.8 post fixes, 0.0035 Windows 10, 0.8.2.1 release, 0.0028 Windows 7, 0.8 post fixes, 0.0036 Windows Server, 0.9.1.0, 0.0055 Amazon Linux, 0.8.2.1 Kitely, 0.000011 Suse Linux, 0.9.1.0 Dev, 0.000000 The last test was on the server in my barn running the very latest version fetched from git: commit c28430d52771ed6950e8482095a72ee8ef0c168d I assume a time of zero means things are so fast that it is below the resolution of llGetTime. I tested other things and verified that llGetTime does work correctly on that system. | |||||||||
Steps To Reproduce | The following test program times how fast fetches are. Put the script in a prim, it will construct a list, then time how long it takes to do random fetches from it. The results in seconds are displayed as floating text above the prim. | |||||||||
Additional Information | //llListFetch timing test //Rev 2.0: simple list, mean and variance of results //Note: timer is only used to generate a bunch of test results //there is no dependency on the accuracy of timer events //only llGetTime is used to measure the time to perform a fetch float sum=0.0; float sum2=0.0; float n=0; list test=[]; default { state_entry() { integer i; for (i=0;i<500;i++) //create a mixed list test += [llFrand(500.0)]; llSetTimerEvent(0.5); } on_rez(integer param) { llResetScript(); } timer() { float r; llResetTime(); r=llList2Float(test,(integer)llFrand(500.0)); //random fetch float time = llGetTime(); //how long did that take? sum += time; sum2 += time*time; n += 1.0; llSetText("last="+(string)time+" n="+(string)((integer)n)+"\nmean="+(string)(sum/n)+" var="+(string)(sum2/n-sum*sum/n/n),<0,1,0>,1.0); //display results } } | |||||||||
Tags | No tags attached. | |||||||||
Git Revision or version number | c28430d52771ed6950e8482095a72ee8ef0c168d | |||||||||
Run Mode | Grid (Multiple Regions per Sim) | |||||||||
Physics Engine | ubODE | |||||||||
Script Engine | ||||||||||
Environment | .NET / Windows64 | |||||||||
Mono Version | 3.6 | |||||||||
Viewer | FireStorm | |||||||||
Attached Files | ||||||||||
![]() |
|
(0031593) BillBlight (developer) 2017-02-06 23:42 edited on: 2017-02-06 23:59 |
Are lists not limited to 255 lines(entries) just like other line items ? I changed your test from 500 to 255 and the timing is more like .006 .. UPDATE: Tried this with a list length of 255 and of 128 .. @255 [23:51] Object: 0.006000 [23:51] Object: 0.007000 [23:51] Object: 0.006000 [23:51] Object: 0.006000 [23:51] Object: 0.007000 @128 [23:55] Object: 0.003000 [23:55] Object: 0.003000 [23:55] Object: 0.003000 [23:55] Object: 0.003000 [23:55] Object: 0.003000 It seems like it could grow exponential depending on list length. |
(0031598) Mata Hari (reporter) 2017-02-10 07:11 |
I have also found all list functions MUCH slower under 0.9x than they were under 0.8.x although that may have also coincided with a .NET update I did so it would be worth comparing an identical run under 0.8.2.1 in your mono setup and seeing if there's any difference. |
(0031600) Total Sorbet (reporter) 2017-02-13 12:49 |
@Kayaker I ran your code and im getting a time of 0.000000 However you are using a list containing vectors and integers yet are attempting to fetch value into a vector in each instance. "v=llList2Vector(test,1|(integer)llFrand(500.0)); //random fetch" I tried the following code: list test=[]; default { state_entry() { llSay(0,"Script running"); integer i=500; while(i--){test+=[1,"a string",PI,ZERO_VECTOR];} llSetTimerEvent(0.5); } timer() { list v; integer r; integer len=llGetListLength(test); integer i=10000; llResetTime(); while(i--){r=(integer)llFrand(len);v=llList2List(test,r,r);} llSetText((string)llGetTime(),<0,1,0>,1.0); } } Ive found it can do 10,000 "fetches" in 10 to 20ms under 0.9.x |
(0031625) Kayaker Magic (reporter) 2017-03-14 09:45 edited on: 2017-03-14 09:47 |
Watcher64: No, there is no limit on the size of a list, although I do recall there is a limit on how many items you can initialize a list with when you declare it. TotalSorbet: No, my code is only fetching the vectors. (Hint: 1 inclusive or'ed with any number is always odd). HOWEVER, your observation that fetching a sub-list from a list is fast is very interesting. It suggests a work-around to the problem: Fetch the item(s) you want from a big list into a smaller one where fetching the individual items is faster. I have since discovered that if you have a simple list (all the same type of items such as floats), fetching items is fast. While my original program that fetched one type from a mixed list of integers and vectors is still slow. But it turns out that fetching from a simple list is fast on some servers, and slow on others. An inadequate sampling of servers indicates that fetching from a simple list on a Linux based system is fast, while fetching from simple list on a Microsoft server based system is slow. This suggests there is a difference in the way Mono and .NET are implementing lists! Run the script below on Linux and Microsoft based regions. So far the Linux servers get a typical fetch time of 0.000004 seconds or lower, the Microsoft servers get a time that averages around 0.010000. //timing test for fetching from a list of just floats list rans=[]; default { state_entry() { integer i; for (i=0;i<1024;i++) rans += [llFrand(1.0)]; llSetTimerEvent(0.5); } timer() { llResetTime(); float ran=llList2Float(rans,(integer)llFrand(1024.0)); llSetText((string)llGetTime(),<1,0,0>,1.0); } } |
(0031641) Total Sorbet (reporter) 2017-03-18 14:39 |
ah.. a sneaky 1|.. got me :p |
(0031675) Kayaker Magic (reporter) 2017-04-02 15:12 |
I went back an did some more timing tests on Linux vs Microsoft servers and discovered that my initial test works blindingly fast on Linux servers! At first I was not paying attention to which server I was running the tests on. The whole problem turns out to be how .NET implements the lists! Then I went back to the Microsoft server and tried to work around the issue by fetching sub-lists first, then fetching the values I wanted out of the smaller list. This did not help, the fetches were still dog slow on the Microsoft server. |
(0031676) UbitUmarov (administrator) 2017-04-02 19:10 |
this scripts timing sounds to me more a GetTime() issue. on Linux it has a resolution of about 1ms, on windows something btw 10 to 20ms. try this on master. I did increase GetTime() resolution a few months ago. on 0.9 Lists I expect ADD heavy and slow, not fetch. |
(0031677) UbitUmarov (administrator) 2017-04-02 19:15 |
for reasons i don't remember i do round getime to 3 digits, so 1ms resolution. |
(0031861) Kayaker Magic (reporter) 2017-05-17 08:50 |
This mantis has been extensively edited. When I first submitted this Mantis I did not know why I sometimes got fast list fetches, other times slow. I thought it might be one thing or another until I realized I was working on several grids, some that had Linux servers others Microsoft. In my experience the list fetches on Microsoft servers were 3 to 4 orders of magnitude slower than the fetches on the Linux servers. |
(0031862) UbitUmarov (administrator) 2017-05-17 09:24 |
your last script, at the time I type gives 0, on my win7 box, with master, debug version and and running in VS debugger. (region is not doing anything else) with the change.. ... integer i; for(i = 0 ; i<10000 ;i++) r=llList2Float(test,(integer)llFrand(500.0)); //random fetch float time = llGetTime(); //how long did that take? ... I get 0.009s time with i<100000 I get from 0,088 to 0.092s I repeat what I said on last meeting. llGetTime() has low resolution on windows with older opensim versions that was changed SHA-1: d07f48605f90a0f0485d0ac11ec5641bbb88a28a * change llGetTime() source clock 2016-11-06 SHA-1: 6f1080368d23d8e3952b5ffd3c3cc05f540d6402 * reduce the resolution of llGetTime and llGetAndResetTime, to 1ms 2016-11-25 this higher resolution may not be available on all machines, either bc of no hardware support or bc its disable (High performance counters) try the loop, but remember that the script event is killed in about 0.3s so keep the loop time lower than that. |
(0031863) Kayaker Magic (reporter) 2017-05-17 11:11 |
I'm confused: If llGetTime has lower resolution, I would expect it to return 0 in my test without your change. That is the result that you get. However, when I run the test on my Win 7 or Win 10 systems I get higher numbers from llGetTime, as if it has resolution similar to Linux and llList2Float is slow. If my Windows systems have higher resolution in llGetTime, I would expect making your change would give exactly the same results (if correcting n for the loop). I did that test on several systems with the following results: OpSys, OpenSim Version, test result Win 10, 0.8 post fix, 0.0031 Win 10, 0.8.2.1 release, 0.0033 Win 7, 0.8 post fix, 0.0015 Win 7, 0.8.2.1 release, 0.0023 I cannot re-run the test on the Windows Server based grid because that grid was brought down by the Ransomewear virus. But these results are similar to my last numbers, I assume the 0.9.0.0 Dev numbers will be similar when I can test there again. All 4 of these tests were done with Sim On A Stick moved between two computers. I tried to run it on a Windows XP system, but it failed to find the right version of .net on that system. |
(0031864) Kayaker Magic (reporter) 2017-05-17 11:14 |
I also had to change the loop on i to only 1000 because if I used 10000 the timer event ran for over 30 seconds before exiting! This is because llList2Float takes soooo long to execute that I cannot call it many times in a single event. Wait, that is the ORIGINAL PROBLEM that this mantis is all about. Here is the test I am using now: //llListFetch timing test //Rev 2.1 Put in loop to catch llGetTime resolution issue //Rev 2.0: simple list, mean and variance of results //Note: timer is only used to generate a bunch of test results //there is no dependancy on the accuracy of timer events //only llGetTime is used to measure the time to perform a fetch float sum=0.0; float sum2=0.0; float n=0; list test=[]; default { state_entry() { integer i; for (i=0;i<500;i++) //create a mixed list test += [llFrand(500.0)]; llSetTimerEvent(0.5); } on_rez(integer param) { llResetScript(); } timer() { float r; integer i; llResetTime(); for (i=0;i<1000;i++) r=llList2Float(test,(integer)llFrand(500.0)); //random fetch float time = llGetTime(); //how long did that take? sum += time; sum2 += time*time; n += 1000.0; llSetText("last="+(string)time+" n="+(string)((integer)n)+"\nmean="+(string)(sum/n)+" var="+(string)(sum2/n-sum*sum/n/n),<0,1,0>,1.0); //display results } } |
(0031865) UbitUmarov (administrator) 2017-05-17 12:00 |
well don't know :( I do need to use a loop of 10000 to see ms numbers on my now old 3.5GHz I7 ( also running viewer etc etc) |
(0031866) Kayaker Magic (reporter) 2017-05-17 12:01 |
Ubit: Are you running OpenSim with mono on your Win 7 system? I am using the native .NET . Yours is the first Windows system I have seen that does not show this problem, but I have not tried many. There are lots of OpenSim systems on OSGrid that are run on Windows systems and they all may have this problem, it is worth tracking down. I have another 'test' where I first noticed this issue: I have a script that does many list fetches in the course of a run. I tun this script on my Linux server while watching the clock on the wall. The script takes 2 minutes to complete. Then I run the same script unchanged on a MycroftSoft system while watching the clock on the wall and the script takes 20 hours to complete. I comment out most of the list fetches and run again on the MycroftSoft system and it takes orders of magnitude less time according to the clock on the wall. (I can't comment out all llList2Floats without compromising the functioning of the script). I have no issues with the resolution of the clock on the wall. I just repeated this test on my SOAS installation on my Windows 7 system with a shorter data-set so I didn't have to wait 20 hours: System, OpenSim version, timing test SUSE Linux, 0.9.2.0 Latest git, 0minutes 6seconds Win 7, 0.8.2.1 release, 11min 17sec Win 7, 0.8.2.1 release, 2min 29sec (some llList2Foat's commented out) It is difficult for me to set up 0.9.2.0 to run in SOAS but I will try to do that next. |
(0031867) UbitUmarov (administrator) 2017-05-17 12:13 |
its hard for anyone to setup 0.9.2. we are still at 0.9.1 well I think ;) Running native .net and inside the vs2015 debugger aapdomain = false |
(0031868) UbitUmarov (administrator) 2017-05-17 12:41 |
it is AppDomainLoading = true with it my timings sky up to 1.4ms PER LOOP |
(0031869) UbitUmarov (administrator) 2017-05-17 12:59 |
my numbers now running from console ( outside the debugger) bin compiled in Debug mode: AppDomainLoading = true -> 1.4ms per LOOP AppDomainLoading = false -> 66ms per 100 000 LOOPS bin compiled in Release mode: AppDomainLoading = true -> 1.4ms per LOOP AppDomainLoading = false -> 44ms per 100 000 LOOPS so yeah.. Domain crossings are killers. |
(0031870) Kayaker Magic (reporter) 2017-05-17 15:16 |
SOAS will not work with OpenSim 0.9.2.0, at least not for me. The Windows Server system is still down from the ransomware virus. So I installed the latest download from OSGrid on my Win 7 system with the intent to upgrade it to the latest from the git hub. When I finally got it working (before upgrading to the latest from git), the result is that list fetches now take 0.000002 seconds average. THE PROBLEM APPEARS TO BE FIXED in 0.9.1.0 Dev, git hash 8bdd4c3ed9cef20bcee931b287c9c4124b409186 from May 12, the one that OSGrid is distributing. Have there been any fixes in the last few months that had a beneficial effect on how lists are handled? It was apparently not fixed in the version on the Windows server I first saw this problem on. That server is still down and I am trying to see if someone can tell me what the got hash was for the OpenSim that they were running. |
(0031871) UbitUmarov (administrator) 2017-05-17 16:27 |
did you read above about AppDomainLoading setting? did you checked it? |
(0031872) Kayaker Magic (reporter) 2017-05-17 21:11 edited on: 2017-05-17 21:43 |
The value of AppDomainLoading in the SOAS kit is the default true. I tried setting it to false with the following results in Win7/.NET OpenSim 0.8 Post Fix: AppDomainLoading=true, llList2Float takes 0.0031 seconds AppDomainLoading=false, llList2Float takes 0.0026 seconds It does not seem to have much effect on this older version. The value of AppDomainLoading in the latest OSGrid OpenSim.ini file is false. I tried setting it to true with results similar to what Ubit reported above: (Both test below done on OSgrid 0.9.1.0 (Dev) 8bdd4c3: 2017-05-12 (Win/.NET)) AppDomainLoading=false, llList2Float takes 0.000002 seconds AppDomainLoading=true, llList2Float takes 0.0022 seconds AppDomainLoading=true makes my scripts run 1000 times slower! The script is in a cube sitting on the ground, it is not moving it is not crossing SIM borders, I would not have expected this. |
![]() |
|||
Date Modified | Username | Field | Change |
2017-02-06 21:32 | Kayaker Magic | New Issue | |
2017-02-06 23:42 | BillBlight | Note Added: 0031593 | |
2017-02-06 23:45 | BillBlight | Note Edited: 0031593 | View Revisions |
2017-02-06 23:59 | BillBlight | Note Edited: 0031593 | View Revisions |
2017-02-10 07:11 | Mata Hari | Note Added: 0031598 | |
2017-02-13 12:49 | Total Sorbet | Note Added: 0031600 | |
2017-03-14 09:45 | Kayaker Magic | Note Added: 0031625 | |
2017-03-14 09:47 | Kayaker Magic | Note Edited: 0031625 | View Revisions |
2017-03-18 14:39 | Total Sorbet | Note Added: 0031641 | |
2017-04-02 15:12 | Kayaker Magic | Note Added: 0031675 | |
2017-04-02 19:10 | UbitUmarov | Note Added: 0031676 | |
2017-04-02 19:15 | UbitUmarov | Note Added: 0031677 | |
2017-05-09 11:53 | Kayaker Magic | Environment | Mono / Linux64 => .NET / Windows64 |
2017-05-09 11:53 | Kayaker Magic | Summary | List fetching functions (eg llList2Vector) are dog slow => List fetching functions (eg llList2Vector) are dog slow on Microsoft servers |
2017-05-09 11:53 | Kayaker Magic | Description Updated | View Revisions |
2017-05-09 12:06 | Kayaker Magic | Operating System | Linux Mono => Microsoft .NET |
2017-05-17 08:50 | Kayaker Magic | Git Revision or version number | => c28430d52771ed6950e8482095a72ee8ef0c168d |
2017-05-17 08:50 | Kayaker Magic | Note Added: 0031861 | |
2017-05-17 08:50 | Kayaker Magic | Operating System Version | 0.9.0 => 0.8 and up |
2017-05-17 08:50 | Kayaker Magic | Platform | Open Simulator 0.9 => Various |
2017-05-17 08:50 | Kayaker Magic | Description Updated | View Revisions |
2017-05-17 08:50 | Kayaker Magic | Steps to Reproduce Updated | View Revisions |
2017-05-17 08:50 | Kayaker Magic | Additional Information Updated | View Revisions |
2017-05-17 09:24 | UbitUmarov | Note Added: 0031862 | |
2017-05-17 11:11 | Kayaker Magic | Note Added: 0031863 | |
2017-05-17 11:14 | Kayaker Magic | Note Added: 0031864 | |
2017-05-17 12:00 | UbitUmarov | Note Added: 0031865 | |
2017-05-17 12:01 | Kayaker Magic | Note Added: 0031866 | |
2017-05-17 12:13 | UbitUmarov | Note Added: 0031867 | |
2017-05-17 12:41 | UbitUmarov | Note Added: 0031868 | |
2017-05-17 12:59 | UbitUmarov | Note Added: 0031869 | |
2017-05-17 15:16 | Kayaker Magic | Note Added: 0031870 | |
2017-05-17 16:27 | UbitUmarov | Note Added: 0031871 | |
2017-05-17 21:11 | Kayaker Magic | Note Added: 0031872 | |
2017-05-17 21:43 | Kayaker Magic | Note Edited: 0031872 | View Revisions |
Copyright © 2000 - 2012 MantisBT Group |