Mantis Bug Tracker

View Issue Details Jump to Notes ] Issue History ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0006789opensim[REGION] Physics Enginespublic2013-10-02 18:022014-07-27 02:57
ReporterGwyneth Llewelyn 
Assigned ToRobert Adams 
PrioritynormalSeverityminorReproducibilityhave not tried
StatusassignedResolutionopen 
PlatformPCOSUbuntuOS Version12.04.3 LTS
Product Versionmaster (dev code) 
Target VersionFixed in Version 
Summary0006789: BulletSim: Consuming vast amounts of CPU
DescriptionI have been testing BulletSim physics on a separate computer connected to our grid. Finding it stable enough, at least on 0.7.6 Dev (fc4f86a), I've decided to run it on our "main" grid (running Ubuntu 10.04 and Mono 2.10.8.1).

I was astonished at the amount of CPU that this is currently consuming. Usually, I can easily run 6 instances on this old server, each with about 100.000 prims on several regions, and, when idle, CPU consumption is around 2%, peaking to 10% occasionally (e.g. when saving snapshots or doing something), but, of course, when avatars are around, the load increases when the avatar just logs in. The server has 6 GBytes of memory and rarely ever consumes more than 3-4.

When switching to BulletSim, memory consumption went to twice normal (see resolved issue http://opensimulator.org/mantis/view.php?id=6599 [^]) but CPU skyrocketed. Idle instances are routinely consuming 40-60% of all CPU — each. Which, of course, brings the server to its knees, and logging in, while it allows everything to be loaded relatively quickly, avatar movement is next to impossible.

Switching back to ODE restores the server to its usual low CPU consumption.

Now I understand that this might be just related to BulletSim parameters, with which I'm not familiar (yet). Maybe there is a recommended set of parameters to keep CPU consumption as low as under ODE?
Additional InformationMy current BulletSim configuration:

---

[BulletSim]
    ; All the BulletSim parameters can be displayed with the console command
    ; "physics get all" and all are defined in the source file
    ; OpenSim/Regions/Physics/BulletSPlugin/BSParam.cs.

    ; There are two bullet physics libraries, bulletunmanaged is the default and is a
    ; native c++ dll bulletxna is a managed C# dll. They have comparible functionality
    ; but the c++ one is much faster.
    BulletEngine = "bulletunmanaged"
    ; BulletEngine = "bulletxna"

    ; BulletSim can run on its own thread independent of the simulator's heartbeat
    ; thread. Enabling this will nto let the physics engine slow down avatar movement, etc.
    ; UseSeparatePhysicsThread = true

    ; Detailed physics debug logging. Very verbose.
    ;PhysicsLoggingEnabled = true
    ;PhysicsLoggingDir = "/tmp/"
    ;VehicleLoggingEnabled = False

    TerrainMeshMagnification = 1 ; deals with the excessive memory consumption

---

I did experiment setting UseSeparatePhysicsThread to false to see if it reduced CPU consumption, but to no avail.
TagsNo tags attached.
Git Revision or version numberbd7d5f5
Run Mode Grid (Multiple Regions per Sim)
Physics EngineBulletSim
Script Engine
EnvironmentMono / Linux64
Mono Version2.10
ViewerFirestorm-Release
Attached Files

- Relationships

-  Notes
(0024446)
Gwyneth Llewelyn (reporter)
2013-10-11 03:07
edited on: 2013-10-11 03:07

Interestingly, there seems to be no difference in CPU consumption under Mac OS X 10.7.5! Maybe this is related to Ubuntu 12.04.3 LTS?

I could do a few tests on a VPS running Ubuntu 12.10, but, being a VPS, it might not be the best system to test performance issues.

(0024459)
Gwyneth Llewelyn (reporter)
2013-10-12 11:15

Tests on the VPS with Ubuntu 12.10 (compiled with 2.10.8.1) show that there is no performance increase under 12.10.

I also suspected that maybe mono under Ubuntu 12.04.3 was using the "old" Mono 2.0 libraries, but I've reconfirmed that it is using the 4.0 libs, and I've recompiled everything fresh and clean from scratch.

So, somehow, this might be related to either my specific hardware (which would be weird!) *or* Ubuntu 12.04.3. I will need to see how I can upgrade Ubuntu on that server, and see if it makes a difference.
(0024463)
Gwyneth Llewelyn (reporter)
2013-10-12 18:21

An upgrade to Ubuntu 12.10 and a recompile of the whole tree did not solve the problem: BulletSim continues to use massive amounts of CPU.

So I guess that my problem is either with my specific hardware or eventually some configuration conflict (e.g. maybe BulletSim is writing a lot of debugging data, even if debug is turned off), which needs to be checked.
(0024480)
Gwyneth Llewelyn (reporter)
2013-10-16 04:27

Upgraded to Ubuntu 13.04, which however keeps Mono at 2.10.8.1. After a very careful review of my whole configuration, I cannot see any difference to my other "test" environments. CPU load is usually around 54-70% per instance (as opposed to merely 4-6% for ODE), 120-140% if one uses the XNA library (this is a 2-core CPU). Clearly something is going on which is hard to pinpoint, but there are absolutely no errors anywhere. I even suspected that the high CPU load could be due to I/O issues (i.e. CPU waiting for disk operations to complete on a faulty disk?) but there are no reasons to suspect a hardware failure — why would ODE work smoothly but not BulletSim?

Another possibility would have been too much intrinsic, legitimate I/O due to the module itself, i.e. writing to logs, swapping due to lack of resources, etc. I tweaked some settings, increased the amount of available threads to 25 (but only 15 are ever allocated on an "empty" grid), made sure that BulletSim logging was kept off, added UseSeparatePhysicsThread = true, etc. All to no avail. Something is still over-consuming CPU without any reason.

I still have the option to turn on sar and use other utilities like lsof etc. to try to figure out what's going on.
(0024481)
Gwyneth Llewelyn (reporter)
2013-10-16 04:45
edited on: 2013-10-16 04:45

There is one hint I got from reading the to-do list, "two problems: if asset failed to mesh, constantly refetched asset". I do have indeed several assets failing to mesh, on several regions.

In fact, trying out an instance with only two quasi-empty regions, without any assets failing to mesh, seems to keep CPU load as low as under ODE, which is quite encouraging!

I will now try to remove the assets failing to mesh on another instance (which does not have many), and see if CPU consumption drops because of that. It looks like CPU load skyrockets with merely ONE instance, thus alluding to the allegedly corrected bug in the to-do list.

BTW, memory consumption is about twice of ODE, even with TerrainMeshMagnification = 1

(0024482)
Gwyneth Llewelyn (reporter)
2013-10-16 06:07

No luck so far. Removing the object failing to mesh did not have any effect, even when restarting the region (without the object) — CPU consumption for that particular region rose back to 50-60% as before. The difference between the two instances — the one without problems and this other one — is the sheer amount of prims: in the first case, where the two regions were practically empty, BulletSim works fine and does not consume much CPU. In the second case, with over 6000+ prims in one region and a handful of prims on the other, CPU consumption remains extremely high, no matter if no objects failed to mesh.

So apparently the amount of prims does, indeed, make a difference. Note that none of those prims is set to physical.

For the sake of completeness, the "test" environments (one Mac and one VPS) used a region with 8000+ prims or so and a few dozens of active prims. None of the test environments had any CPU issues.
(0024535)
Gwyneth Llewelyn (reporter)
2013-10-18 19:34

Upgraded to Ubuntu 13.10. Mono is still 2.10.8.1, unfortunately. The problem persists.
(0024537)
kenvc (reporter)
2013-10-18 21:24

It is looking like at least a temporary workaround for the massive memory increase with BulletSim issue has been found. In case the memory issue is related to the BulletSim CPU issue, try this fix and leave a note here if it helps:

[BulletSim]
 TerrainImplementation=0

I have tested this change and it does not appear to have any unwanted effects and it seems to actually speed up BulletSim vehicle response on my system.
(0024541)
Gwyneth Llewelyn (reporter)
2013-10-19 10:44

All right, under an instance in HG mode, with two regions and a total of 13000+ prims, latest build from git (with the new unmanaged library), running under Ubuntu 13.10:

Reference: With ODE:

Heap allocated to OpenSim : 145 MB
Last heap allocation rate : 0.375 MB/s
Average heap allocation rate: 0.068 MB/s
Process memory : 261 MB

With BulletSim, TerrainImplementation=0 and TerrainMeshMagnification = 1:

Heap allocated to OpenSim : 198 MB
Last heap allocation rate : 0.064 MB/s
Average heap allocation rate: 0.101 MB/s
Process memory : 345 MB

With BulletSim, TerrainMeshMagnification = 1:

Heap allocated to OpenSim : 199 MB
Last heap allocation rate : 0.069 MB/s
Average heap allocation rate: 0.133 MB/s
Process memory : 390 MB

So memory consumption is now 25% over ODE instead of 33%, which is certainly an improvement over 40% or 100%! (I think that memory consumption under ODE also dropped a bit with the upgrades of both Ubuntu and OpenSimulator)

CPU consumption, unfortunately, remains high and unexplainable.
(0024556)
Gwyneth Llewelyn (reporter)
2013-10-22 06:28
edited on: 2013-10-22 06:45

I see that Robert has added new DLLs for BulletSim on 392841c, so I did a new test. Started with an instance with two empty regions. CPU consumptions was at the expected level, i.e. around 2%.

Then I uploaded an OAR from http://zadaroo.com/?page_id=1640, [^] which has about 6100 prims or so. Many of which, unfortunately, are non-meshable sculpts (i.e. the kind that has transparent textures applied), which gives the usual (and now expected) errors on the console.

CPU consumption rose briefly to occupy the two cores during the upload (which is usual) and then settled back to 20%, slightly less than half of what I get from my other test instance, which has also slighty twice the amount of prims.

Then I launched another instance which has 4 regions and 3780 prims. This gives me 24-25% CPU consumption.

Another instance with 2 regions and 17000 prims gives 72-74%.

So at least in my case there is a correlation between number of prims, number of regions per instance, and CPU consumption:

- No prims (or very few prims): 2% (this is what I usually get with ODE as well)
- 6000 or so prims: 20%
- 3780 prims, 4 regions: 24%
- 13000 or so prims: 53%
- 17000 prims: 74%

ODE, no matter how many prims and regions, will consistently give 2-4% CPU consumption (peaking only when an avatar logs in, a physics object is moved, etc., but, even so, I haven't seen an ODE-based instance goingh much above 14% or so, even with 10-14 avatars online, interacting with each other).

(0024575)
Robert Adams (administrator)
2013-10-26 21:56

I just checked in new BulletSim DLLs and SOs that reduce the CPU overhead in a lot of cases. Does this improve your situation?
(0024577)
Gwyneth Llewelyn (reporter)
2013-10-27 15:45

Ok, I can report a slight improvement — very slight, but noticeable.

I can now launch all 6 instances with 20 or so regions, and have them running on my single 2-core server — if I'm willing to have it at 500-700% load. At this kind of load, however, I still get more than 50 PhysicsFPS (with one or two avatars, I haven't tested with more than that), which means that the grid is barely, just barely, usable.

This is certainly much better than before. Unfortunately, it still means 10x as much server load as ODE (yes, that's right, not a typo) on average, besides the huge memory consumption. As said, I worry far less about memory, since I have plenty to spare for all those instances.

Nevertheless, I think you're on the right track, there was certainly an improvement — previously, CPU load was so high (and, consequently, PhysicsFPS so low) that it was impossible to move the avatars around. It *could* be something related to the way the DLLs are called. Maybe if you can tell me what debugging settings I should turn on/off, I might be able to give you some log of what is actually happening?

(Please note that I might be sometimes slow to respond, as this is a production grid with work being done for some customers, and when the content creators need to work, I have to revert to ODE to make sure they can actually do something productive)
(0024578)
Gwyneth Llewelyn (reporter)
2013-10-27 15:51
edited on: 2013-10-27 15:51

As a comparison: the 13000-prim, two-region instance now consumes merely 19% of CPU, as compared with 53%. The 6000-prim, two-region instance is now merely at 4.6-5.6%, as opposed to 20% (4-5% is very close to ODE's CPU consumption for that region). I'm actually leaving those two on BulletSim (they have mostly "test" regions and serve as backups for old projects), and have all the rest on ODE, since it means acceptably low CPU usage overall.

So, nice work, Robert, you're definitely getting closer to a final solution :-)

(0024579)
Gwyneth Llewelyn (reporter)
2013-10-27 16:04

What is so frustrating is that ODE is getting consistently better and better performance. With the latest build, I don't get 4% CPU consumption on 100,000-prim instances — I just barely get 2%. And memory consumption is not only much lower, it's also better managed (the garbage collector seems to be actually doing something).

I truly wonder if this is not mostly related to lots of prims (most of which might be intersecting each other), and whole "paved" sims, all of which have prims as paving on top of the meshed terrain. It's just that on some test OARs, where the amount of intersecting prims is lower (but also the overall number of prims is around 2000 or lower), BulletSim comes close to ODE in terms of CPU consumption. This is certainly the case on my "test" hardware which runs Mac OS X. However, as regions start having "real" content, as opposed to merely tests of scattered prims and meshes around the place, BulletSim seems to start to struggle. Does any of this make sense to you?

I'm still trying to get a different server to try everything with a clean configuration, but it's still some weeks in the future, at best.
(0024580)
Robert Adams (administrator)
2013-10-28 07:34

It is odd that your ODE measurements are changing since the ODE code and DLL have not changed in nearly a year. I wonder what is being measured.

The last BulletSim changes fixed a specific problem and made my 65K prim test region reduce from 100% CPU to 5%. The fix didn't get everything as I have a 130K prim region that still uses 35% CPU (60% CPU on slower systems) so there is still some per-prim over head happening. ODE has code to manage when objects are checked for changes which is missing from Bullet. I still have some work for high prim count regions.
(0024591)
Gwyneth Llewelyn (reporter)
2013-10-30 17:29

Well, I did make a few changes since my last ODE CPU consumption measurements: lots of Ubuntu upgrades and switching to compiling under Mono 4.0 profiles, to see if that helped. It certainly helped... with ODE.
(0026043)
Gwyneth Llewelyn (reporter)
2014-05-12 04:39
edited on: 2014-05-12 04:39

Just to update this thread...

OpenSim has gone through several upgrades, but, in my case, no matter what is changed, CPU load for BulletSim is consistently 7x the amount of what ODE consumes.

These days I'm running Ubuntu 14.04 LTS, mono 3.2.8 with Mono 4.0 Profiles, MySQL 5.5.37.

Because I usually have no issues with BulletSim elsewhere (namely, on Mac OS X), I seriously suspect it's just something with my hardware. For the sake of completeness in the report, here is /proc/cpuinfo (I have two cores):

processor : 0
vendor_id : GenuineIntel
cpu family : 15
model : 4
model name : Intel(R) Pentium(R) 4 CPU 3.06GHz
stepping : 9
microcode : 0x3
cpu MHz : 3060.089
cache size : 1024 KB
physical id : 0
siblings : 2
core id : 0
cpu cores : 1
apicid : 0
initial apicid : 0
fpu : yes
fpu_exception : yes
cpuid level : 5
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc pebs bts nopl pni dtes64 monitor ds_cpl tm2 cid cx16 xtpr lahf_lm
bogomips : 6120.17
clflush size : 64
cache_alignment : 128
address sizes : 36 bits physical, 48 bits virtual
power management:

processor : 1
vendor_id : GenuineIntel
cpu family : 15
model : 4
model name : Intel(R) Pentium(R) 4 CPU 3.06GHz
stepping : 9
microcode : 0x3
cpu MHz : 3060.089
cache size : 1024 KB
physical id : 0
siblings : 2
core id : 0
cpu cores : 1
apicid : 1
initial apicid : 1
fpu : yes
fpu_exception : yes
cpuid level : 5
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc pebs bts nopl pni dtes64 monitor ds_cpl tm2 cid cx16 xtpr lahf_lm
bogomips : 6120.17
clflush size : 64
cache_alignment : 128
address sizes : 36 bits physical, 48 bits virtual
power management:

Aye, I know it's an old CPU :) But it still runs OpenSim instances with tens of thousands of prims taking just 2% of CPU load, peaking on 4%. BulletSim needs at least 18%-21% for the same kinds of regions.

And here is my BulletSim configuration, extracted from within the console:

[BulletSim]
  BulletEngine = bulletunmanaged
  UseSeparatePhysicsThread = true
  TerrainImplementation = 0
  TerrainMeshMagnification = 2
  AvatarHeightLowFudge = 0
  AvatarHeightMidFudge = 0
  AvatarHeightHighFudge = 0
  LinkImplementation = 1
  LinksetOffsetCenterOfMass = false
  MeshSculptedPrim = true
  ForceSimplePrimMeshing = false
  ShouldRemoveZeroWidthTriangles = true
  ShouldUseAssetHulls = true
  MaxCollisionsPerFrame = 2048
  MaxUpdatesPerFrame = 8192
  PhysicsLoggingEnabled = false
  PhysicsLoggingDir = .
  VehicleLoggingEnabled = False

(0026044)
Robert Adams (administrator)
2014-05-12 06:35

On problem found with the actual Bullet physics engine is that it is very CPU intensive for detailed mesh-to-mesh collisions. For instance, at the OSCC last year, the presentation room chairs were very detailed mesh objects. Several avatars just leaning against the chairs caused excessive CPU usage. The solution, at the time, was to make the chairs phantom. This does not need the detailed meshes to be physical as the collision computation is done for just bumping into things.

You can test this on your region by checking the estate collision report and making the top ones phantom and seeing of that reduces the CPU usage. The ultimate solution is an update to the Bullet physics engine (http://bulletphysics.org [^]).
(0026045)
Gavin Hird (reporter)
2014-05-12 07:10
edited on: 2014-05-12 07:49

With reference to this issue http://opensimulator.org/mantis/view.php?id=7158#c26042, [^] I stated that with the latest updates and mono 3.2.7 my CPU performance hit was in the 3.5x range whereas I before had seen consistently 7x+ with bulletsim over ODE.

However, the joy was kindoff short-lived in that the Mac OS X 10.9.2 kernel killed mono after running for about 5 minutes complaining about excessive wakeup calls per second (over 450) while the kernel only allowed 150 per process. I have seen quite a few complaints over the same in other contexts for the 10.9.2 kernel so it might be that Apple will relax this for the 10.9.3 system that is now in round 11 of the beta cycle (of which I have only tested desktop and not server, so can't tell if makes a difference.)

It might, however, also be a symptom of an inherent problem with the bulletsim engine and how it draws on system resources.

I saw the same behavior on 2 different systems, one running on an i5 processor and the other on an i7. Both systems with 8 GB of system memory. Both systems saw the 3.5x performance hit for bullet over ODE versus 7x+ a couple months back in time.

(0026047)
Gavin Hird (reporter)
2014-05-12 07:48

Another approach, rather than setting the mesh to phantom, would be to make a very simple bounding box (in the general shape of the chair) and upload with the mesh as the physics model.

Unfortunately the viewer does not not give us much help on opensim as it does when uploading to SL, where you can auto generate, tweak and simplify the physics model quite a bit before upload.

So for now, it is either to thrown the full weight of the mesh to bulletsim, or do the extra work of making an efficient collision model by hand. Most of the time I do the later for any mesh that is not a wearable.
(0026049)
Robert Adams (administrator)
2014-05-12 08:37

Does the 'excessive wakeup calls' in MacOS happen with ODE? Architecturally, any physics engine in OpenSimulator is a passive actor. That is, it does not generation any events but the simulator calls the physics engine 11 times a second asking it to simulate the next 11th of a second. That call does cause the physics engine to call back into the simulator with physical changes (position changes, collisions, ...) but the physics engine itself does not create any wakeup or timer events.

It might be possible that BulletSim is creating more updates than ODE, for instance, and is thus tickling some other event mechanism.
(0026050)
Gavin Hird (reporter)
2014-05-12 08:42

To what extent the wakeup calls happens with ODE I am not sure, but if they do, it is under the 150 calls per sec limit that is set in the kernel. I'll restart my standalone with bulletsim and give you the exact syslog message when mono is terminated. I'll also check the mono log to see if there is any clues there.
(0026051)
Gavin Hird (reporter)
2014-05-12 09:56

By monitoring my standalone (which is basically identical to the public osg sims, except it has significantly more mesh and many more scripts running), when ODE is configured the process has steadily around 950 wake-up calls per 5 sec sample period, whereas with bulletsim the number is closer to 1300, with periodic peaks of about 1850 and some lows down to 600. So it seems to be much more transient.

Oddly enough the system did not kill mono this time around, so maybe the kernel auto tuned.
I'll let the standalone run with bulletsim for now and see how it does... If it works, I'll switch the OSG instance over too.
(0026052)
Gavin Hird (reporter)
2014-05-12 10:08

it does report this during startup with bulletsim:

ay 12 18:59:08 u2 kernel[0]: process mono-sgen[98032] caught causing excessive wakeups. Observed wakeups rate (per sec): 529; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45124
May 12 18:59:08 u2.dayturn.com ReportCrash[98293]: Invoking spindump for pid=98032 wakeups_rate=529 duration=86 because of excessive wake ups

despite this, it seems to start up properly
(0026053)
Gavin Hird (reporter)
2014-05-12 10:27
edited on: 2014-05-12 10:27

this time it eventually crashed (maybe because of the previous crash), with the following error message:

ay 12 19:23:11 u2 mono[98032]: mono(98032,0xb0d2d000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
    *** error: can't allocate region securely
    *** set a breakpoint in malloc_error_break to debug
May 12 19:23:11 --- last message repeated 1 time ---
May 12 19:23:11 u2 mono[98032]: mono(98032,0xb2ef1000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
    *** error: can't allocate region securely
    *** set a breakpoint in malloc_error_break to debug
May 12 19:23:11 --- last message repeated 1 time ---
May 12 19:23:11 u2 mono[98032]: mono(98032,0xb0b29000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
    *** error: can't allocate region securely
    *** set a breakpoint in malloc_error_break to debug
May 12 19:23:16 --- last message repeated 1 time ---
May 12 19:23:16 u2.dayturn.com ReportCrash[1242]: Saved crash report for mono-sgen[98032] version ??? to /Library/Logs/DiagnosticReports/mono-sgen_2014-05-12-192316_u2.crash

(0026054)
Gavin Hird (reporter)
2014-05-12 12:03

LOL – for the fun of it I installed mono 3.4 and started the standalone with bulletsim, and this is what happened per the syslog:

May 12 20:44:05 u2 kernel[0]: process mono-sgen[9513] caught causing excessive wakeups. Observed wakeups rate (per sec): 257; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45043
May 12 20:44:21 u2.dayturn.com spindump[9933]: Saved wakeups_resource.spin report for mono version ??? (???) to /Library/Logs/DiagnosticReports/mono_2014-05-12-204420_u2.wakeups_resource.spin
May 12 20:52:12 u2 mono[9513]: mono(9513,0xb5843000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 12 20:52:12 u2 mono[9513]: mono(9513,0xb0721000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 12 20:52:12 u2 mono[9513]: mono(9513,0xc67bd000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 12 20:52:12 u2 mono[9513]: mono(9513,0xb25df000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 12 20:52:18 u2.dayturn.com ReportCrash[11074]: Saved crash report for mono-sgen[9513] version ??? to /Library/Logs/DiagnosticReports/mono-sgen_2014-05-12-205218_u2.crash

The interesting thing is that when starting up with ODE it reports the same behavior, but it does not crash:

May 12 20:54:44 u2 kernel[0]: process mono-sgen[11195] caught causing excessive wakeups. Observed wakeups rate (per sec): 473; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45023

so the sims starts up and can be logged into.

Mono 3.4 has an additional problem that is XEngine fails to save script state, but that is a different can of worms. Reverting back to 3.2.7
(0026057)
Gavin Hird (reporter)
2014-05-13 01:51
edited on: 2014-05-13 02:08

OK, I think I have found a lead to where there is a problem.

The precursor was that I wanted to precompile the bulletsim dll, just to see if the compiler would complain with other optimizations than the JIT runs with. So after some trial and error I managed to get a stable startup and running system with the following modules precompiled:

mono --aot -O=all OpenSim.exe
mono --aot -O=all BulletXNA.dll
mono --aot -O=all OpenSim.Region.ScriptEngine.XEngine.dll
mono --aot -O=all OpenSim.Region.ScriptEngine.XEngine.Api.Runtime.dll

The system then complained with the usual error during startup, but as you can see from the log below it ran stable for about half an hour before malloc-ing. This happened both on the standalone and the public OSG instance, so that is fairly consistent, and the same thing happened over multiple runs (as in always).

Apart from that, when the sims were running, the idle CPU load (single core load) was around 23% with bulletsim enabled, whereas the same with ODE is around 13% for the OSG instance. For the standalone (which has significantly more content and scripts), the numbers are around 40% with bulletsim and around 21% with ODE, which is pretty acceptable.


May 13 09:57:22 u1 kernel[0]: process mono-sgen[91048] caught causing excessive wakeups. Observed wakeups rate (per sec): 350; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45035
May 13 10:31:36 u1 mono[91048]: mono(91048,0xb5127000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 13 10:31:36 u1 mono[91048]: mono(91048,0xb450f000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 13 10:31:36 u1 mono[91048]: mono(91048,0xb2ee3000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 13 10:31:36 u1 mono[91048]: mono(91048,0xb33ed000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 13 10:31:36 u1 mono[91048]: mono(91048,0xb542d000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
May 13 10:31:40 u1.dayturn.com ReportCrash[92151]: Saved crash report for mono-sgen[91048] version ??? to /Library/Logs/DiagnosticReports/mono-sgen_2014-05-13-103140_u1.crash



Stacktrace:

  at <unknown> <0xffffffff>
  at (wrapper managed-to-native) OpenSim.Region.Physics.BulletSPlugin.BSAPIUnman/BSAPICPP.PhysicsStep2 (intptr,single,int,single,int&,int&) <0xffffffff>
  at OpenSim.Region.Physics.BulletSPlugin.BSAPIUnman.PhysicsStep (OpenSim.Region.Physics.BulletSPlugin.BulletWorld,single,int,single,int&,int&) <0x00053>
  at OpenSim.Region.Physics.BulletSPlugin.BSScene.DoPhysicsStep (single) <0x00299>
  at OpenSim.Region.Physics.BulletSPlugin.BSScene.BulletSPluginPhysicsThread () <0x00047>
  at System.Threading.Thread.StartInternal () <0x00057>
  at (wrapper runtime-invoke) object.runtime_invoke_void__this__ (object,intptr,intptr,intptr) <0xffffffff>

Native stacktrace:

mono(91048,0xb542d000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
*** error: can't allocate region securely
*** set a breakpoint in malloc_error_break to debug
mono(91048,0xb542d000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
*** error: can't allocate region securely
*** set a breakpoint in malloc_error_break to debug
libc++abi.dylib: terminating with uncaught exception of type std::bad_alloc: std::bad_alloc
Abort trap: 6


------- THE FOLLOWING LINE --- is from startup with ODE so this problem during startup exist for both physics engines.
May 13 10:40:10 u1 kernel[0]: process mono-sgen[92214] caught causing excessive wakeups. Observed wakeups rate (per sec): 507; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 68498

(0026059)
Gwyneth Llewelyn (reporter)
2014-05-13 04:28

A stupid question, is there a console command for showing the wakeup calls inside OpenSim, or is this all an issue at the OS level?

I've used (on Ubuntu) health-check. Here is the logs for running it for about 10 minutes. It should also have caught some extra work at the end of the region startup, but I see no wakeup calls:

CPU usage (in terms of 1 CPU):
  PID Process USR% SYS% TOTAL% Duration
  2872 mono 20.02 0.73 20.75 600.01 (medium load)

Page Faults:
  PID Process Minor/sec Major/sec Total/sec
  2872 mono 68.16 0.00 68.16

Wakeups:
 No wakeups detected.

Context Switches:
  PID Process Voluntary Involuntary Total
                             Ctxt Sw/Sec Ctxt Sw/Sec Ctxt Sw/Sec
  2872 mono 0.91 0.00 0.91 (very low)

File I/O operations:
  PID Process Count Op Filename
  2872 mono 36 R /etc/mono/4.5/machine.config
  2872 mono 23 W /home/opensim/opensim-0.7.6-dev-source/bin/OpenSim.JeffBush.log
  2872 mono 6 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/03a9b966-0320-41df-bba6-2663a69b36c8.state
  2872 mono 5 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/65088166-0cdc-4d4b-aef6-85d955782707.state
  2872 mono 5 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/85d3e16b-dd09-431c-9e7a-ca96a6532b7b.state
  2872 mono 5 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/cf6ca37f-6cbd-4039-9d70-58a2919f7322.state
  2872 mono 4 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/03a9b966-0320-41df-bba6-2663a69b36c8.state
  2872 mono 4 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/03a9b966-0320-41df-bba6-2663a69b36c8.state
  2872 mono 4 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/65088166-0cdc-4d4b-aef6-85d955782707.state
  2872 mono 4 C /etc/mono/4.5/machine.config
  2872 mono 4 O /etc/mono/4.5/machine.config
  2872 mono 3 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/85d3e16b-dd09-431c-9e7a-ca96a6532b7b.state
  2872 mono 3 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/cf6ca37f-6cbd-4039-9d70-58a2919f7322.state
  2872 mono 3 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/cf6ca37f-6cbd-4039-9d70-58a2919f7322.state
  2872 mono 3 R /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/259/9fe/2599fe55-d492-46bc-851d-98e44e24df93
  2872 mono 3 R /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/cc7/629/cc7629f6-d8de-4774-902f-8dd81705418f
  2872 mono 3 R /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/089/858/0898582a-43ca-40b6-9939-149ded8f2732
  2872 mono 3 W /tmp/62333859/58d30ded.0.cs
  2872 mono 2 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/85d3e16b-dd09-431c-9e7a-ca96a6532b7b.state
  2872 mono 2 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/85d3e16b-dd09-431c-9e7a-ca96a6532b7b.state
  2872 mono 2 R /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/b8d/396/b8d3965a-ad78-bf43-699b-bff8eca6c975
  2872 mono 2 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll
  2872 mono 2 C /home/opensim/opensim-0.7.6-dev-source/bin/OpenSim.exe.config
  2872 mono 2 R /home/opensim/opensim-0.7.6-dev-source/bin/OpenSim.exe.config
  2872 mono 2 O /home/opensim/opensim-0.7.6-dev-source/bin/OpenSim.exe.config
  2872 mono 2 C /home/opensim/opensim-0.7.6-dev-source/bin/addin-db-001/fdb-lock
  2872 mono 2 O /home/opensim/opensim-0.7.6-dev-source/bin/addin-db-001/fdb-lock
  2872 mono 2 OCR /home/opensim/opensim-0.7.6-dev-source/bin/OpenSim.exe.config
  2872 mono 2 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_79310a15-5341-4ac0-8c7d-63f6f7e14146.dll
  2872 mono 2 C /tmp/49256feb
  2872 mono 2 O /tmp/49256feb
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/cf6ca37f-6cbd-4039-9d70-58a2919f7322.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/03a9b966-0320-41df-bba6-2663a69b36c8.state
  2872 mono 1 OCW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/cf6ca37f-6cbd-4039-9d70-58a2919f7322.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/65088166-0cdc-4d4b-aef6-85d955782707.state
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/65088166-0cdc-4d4b-aef6-85d955782707.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/c9f72156-2f21-48a7-b417-075cc784a57e.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/c9f72156-2f21-48a7-b417-075cc784a57e.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/2d8622b9-1fe8-40ae-9908-e91379b47055.state
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/2d8622b9-1fe8-40ae-9908-e91379b47055.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/2d8622b9-1fe8-40ae-9908-e91379b47055.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/d0018045-9c7f-4f30-97b3-ae0e0c5d51c4.state
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/d0018045-9c7f-4f30-97b3-ae0e0c5d51c4.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/d0018045-9c7f-4f30-97b3-ae0e0c5d51c4.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/8b0842f8-502f-42f0-a75a-7734cbb0fd18.state
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/8b0842f8-502f-42f0-a75a-7734cbb0fd18.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/8b0842f8-502f-42f0-a75a-7734cbb0fd18.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/78998619-932a-4e2e-81e8-1632c9ec343c.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/78998619-932a-4e2e-81e8-1632c9ec343c.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/307b6221-8f4c-489e-9829-eb9fcf37d310.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/307b6221-8f4c-489e-9829-eb9fcf37d310.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/b910b24d-8606-443b-b1de-c473346a14bc.state
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/b910b24d-8606-443b-b1de-c473346a14bc.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/b910b24d-8606-443b-b1de-c473346a14bc.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/6dc66dd5-ede6-4164-81d6-f374c97823f5.state
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/6dc66dd5-ede6-4164-81d6-f374c97823f5.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/6dc66dd5-ede6-4164-81d6-f374c97823f5.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/21cb34ad-7557-4fbc-9033-d800cb05f81b.state
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/21cb34ad-7557-4fbc-9033-d800cb05f81b.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/21cb34ad-7557-4fbc-9033-d800cb05f81b.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/e6579efb-8460-4e34-9759-ab79b2cac034.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/e6579efb-8460-4e34-9759-ab79b2cac034.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/dce0b3b6-66a4-4114-b91a-2784b53bebe6.state
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/dce0b3b6-66a4-4114-b91a-2784b53bebe6.state
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/259/9fe/2599fe55-d492-46bc-851d-98e44e24df93
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/259/9fe/2599fe55-d492-46bc-851d-98e44e24df93
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/cc7/629/cc7629f6-d8de-4774-902f-8dd81705418f
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/cc7/629/cc7629f6-d8de-4774-902f-8dd81705418f
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/089/858/0898582a-43ca-40b6-9939-149ded8f2732
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/089/858/0898582a-43ca-40b6-9939-149ded8f2732
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/b8d/396/b8d3965a-ad78-bf43-699b-bff8eca6c975
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/assetcache/b8d/396/b8d3965a-ad78-bf43-699b-bff8eca6c975
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/cf6ca37f-6cbd-4039-9d70-58a2919f7322.state
  2872 mono 1 R /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/cf6ca37f-6cbd-4039-9d70-58a2919f7322.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll.text
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll.text
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll.text
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll
  2872 mono 1 R /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll
  2872 mono 1 OC /tmp/62333859
  2872 mono 1 C /tmp/62333859
  2872 mono 1 O /tmp/62333859
  2872 mono 1 C /etc/gai.conf
  2872 mono 1 R /etc/gai.conf
  2872 mono 1 O /etc/gai.conf
  2872 mono 1 C /usr/bin/mcs
  2872 mono 1 OR /usr/bin/mcs
  2872 mono 1 CW /tmp/62333859/58d30ded.0.cs
  2872 mono 1 O /tmp/62333859/58d30ded.0.cs
  2872 mono 1 CW /tmp/62333859/58d30ded.tmp
  2872 mono 1 O /tmp/62333859/58d30ded.tmp
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll.map
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll.map
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_0a69f559-2ec9-41de-a3df-7cf3daf8b5e3.dll.map
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/03a9b966-0320-41df-bba6-2663a69b36c8.state
  2872 mono 1 R /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/03a9b966-0320-41df-bba6-2663a69b36c8.state
  2872 mono 1 CW /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_79310a15-5341-4ac0-8c7d-63f6f7e14146.dll.text
  2872 mono 1 W /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_79310a15-5341-4ac0-8c7d-63f6f7e14146.dll.text
  2872 mono 1 O /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_79310a15-5341-4ac0-8c7d-63f6f7e14146.dll.text
  2872 mono 1 C /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_79310a15-5341-4ac0-8c7d-63f6f7e14146.dll
  2872 mono 1 R /home/opensim/opensim-0.7.6-dev-source/bin/ScriptEngines/1dba66ba-a66f-40f1-9159-44e2778230a0/CommonCompiler_compiled_79310a15-5341-4ac0-8c7d-63f6f7e14146.dll
 Total 217
 Op: O=Open, R=Read, W=Write, C=Close

File I/O Operations per second:
  PID Process Open Close Read Write
  2872 mono 0.10 0.10 0.09 0.13

System calls traced:
  PID Process Syscall Count Rate/Sec Total ?Secs % Call Time
  2872 mono rt_sigreturn 56 0.0933 5704 0.0010
  2872 mono rt_sigprocmask 56 0.0933 1947 0.0003
  2872 mono futex 49 0.0817 2638 0.0005
  2872 mono read 29 0.0483 568804684 99.7751
  2872 mono rt_sigsuspend 28 0.0467 1271597 0.2231
 Total 218 0.3633 570086570

Filesystem Syncs:
 None.

Inotify watches added:
 None.

Memory:
Per Process Memory (K):
  PID Process Type Size RSS PSS
  2872 mono Stack 96648 7900 7900
  2872 mono Heap 1310556 342468 342468
  2872 mono Mapped 116976 21768 4241

Change in memory (K/second):
  PID Process Type Size RSS PSS
  2872 mono Stack -26.88 -0.23 -0.23 (shrinking moderately fast)
  2872 mono Heap -2.93 -23.48 -23.48 (shrinking moderately fast)
  2872 mono Mapped 0.04 0.16 0.15 (growing slowly)

Heap Change via brk():
 None.

Memory Change via mmap() and munmap():
 None.

Open Network Connections:
  PID Process Proto Send Receive Address
  2872 mono UDP 0.00 B 0.00 B 0.0.0.0:0
  2872 mono TCP 0.00 B 0.00 B 127.0.0.1:3306
  2872 mono TCP 0.00 B 0.00 B 0.0.0.0:0



The thing about interpenetrating objects might be a hint. When I use a 'mostly empty' region to test BulletSim, it shows about the same CPU and memory consumption as ODE. But my test instance has two regions: one which is almost empty but has a handful of meshes. The other is pretty much full, with about 9000 prims and a few sculpties (no meshes). But many of those prims overlap/interlock without being set to phantom. None are set to physical, though. This region has a 7x CPU performance hit compared to running it under ODE.

But I also think the issue is hardware-related. I'm running a rather full region as well on a different Ubuntu server, which has a very-low end CPU:

processor : 0
vendor_id : CentaurHauls
cpu family : 6
model : 15
model name : VIA Nano processor U2250 (1.6GHz Capable)
stepping : 3
cpu MHz : 800.000
cache size : 1024 KB
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat clflush acpi mmx fxsr sse sse2 ss tm pbe syscall nx lm constant_tsc rep_good nopl pni monitor vmx est tm2 ssse3 cx16 xtpr rng rng_en ace ace_en ace2 phe phe_en lahf_lm
bogomips : 3192.00
clflush size : 64
cache_alignment : 128
address sizes : 36 bits physical, 48 bits virtual
power management:

The instance running here has absolutely no problem with BulletSim.

Now, I cannot claim that both Ubuntu servers are configured in 'exactly' the same way, because I'm sure they're not. They are, however, as closely configured as possible.

What comes to my mind is that the delicate balance of CPU/OS configuration/OpenSim instance configuration/prims on the region might trigger this excessive load on BulletSim in some cases, but not in most of the others, so it has been incredibly hard to pinpoint what is causing the problem.
(0026063)
Gavin Hird (reporter)
2014-05-13 05:10

Gwyneth, it might be that the excessive wake-up calls is primarily an issue with the Mac OS X kernel introduced by the "power nap" function in Mac OS X 10.9 (Mavericks) and for some reason compounded by something Apple did in 10.9.2 after which these issues have popped up in their discussion forums.

As per my latest posting you see that these happens during opensim startup regardless of ODE or bulletsim are selected as the physics engine, but it seems like bulletsim invokes more of these calls after startup is complete – perhaps just enough to tip the number over the scale for the system to kill the (offending) process.

Compiling parts of the code seemed to improve the issue and also increased performance by shaving of a few more percents CPU utilization, but it also seemed to identify a memory leak.

On OS X you can monitor the number of wakeup-calls per process in the Activity Monitor app, so you get a pretty good feel for what's going on. Over that you probably have to set up app profiling with the Instruments app that is part of the OS X / iOS developer tools.

I will later today try and set a system setting for power naps and see it that changes the situation (as in not killing a process), and report back.

I suspect, perhaps, the quality of the JIT compiler for your operating system might have something to do with how much performance you can wring out of mono for any given processor configuration. On compiling the code on OS X it invoked clang (which is now the standard compiler) and not gcc.
(0026064)
Gavin Hird (reporter)
2014-05-13 06:53

The suggested method to change the system setting did not make any difference.

What I observe from the startup sequence is that at some point you see a massive spike in CPU load, and opensim starts to log a shitload of console messages as shown below. I have included from the beginning of these messages which starts at timestamp 2014-05-13 15:29:18.

Just a few seconds later, the system kicks out this message on the system log:

May 13 15:29:36 u1 kernel[0]: process mono-sgen[1225] caught causing excessive wakeups. Observed wakeups rate (per sec): 346; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45009
May 13 15:29:37 u1.dayturn.com spindump[1270]: Saved wakeups_resource.spin report for mono version ??? (???) to /Library/Logs/DiagnosticReports/mono_2014-05-13-152937_u1.wakeups_resource.spin

So it looks like this bit of code could be where (some of the problem) is. It also calls OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset() so I guess the same type of call is involved for bulletsim


2014-05-13 15:29:18,299 DEBUG - OpenSim.Framework.Util Threadfunc: enable overload mode (Queued 4, Running 45)
2014-05-13 15:29:18,348 DEBUG - OpenSim.Framework.Util Queue threadfunc 123 (Queued 5, Running 45) at OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset.HGAssetBroker.Get(System.String id, System.Object sender, OpenSim.Services.Interfaces.AssetRetrieved handler)
2014-05-13 15:29:18,348 DEBUG - OpenSim.Framework.Util Queue threadfunc 124 (Queued 6, Running 45) at OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset.HGAssetBroker.Get(System.String id, System.Object sender, OpenSim.Services.Interfaces.AssetRetrieved handler)
2014-05-13 15:29:18,348 DEBUG - OpenSim.Framework.Util Queue threadfunc 122 (Queued 4, Running 45) at OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset.HGAssetBroker.Get(System.String id, System.Object sender, OpenSim.Services.Interfaces.AssetRetrieved handler)
2014-05-13 15:29:18,407 DEBUG - OpenSim.Framework.Util Exit threadfunc 116 (55 ms)
2014-05-13 15:29:18,407 DEBUG - OpenSim.Framework.Util Exit threadfunc 115 (55 ms)
2014-05-13 15:29:18,408 DEBUG - OpenSim.Framework.Util Exit threadfunc 118 (56 ms)
2014-05-13 15:29:18,408 DEBUG - OpenSim.Framework.Util Run threadfunc 119 (Queued 5, Running 43)
2014-05-13 15:29:18,409 DEBUG - OpenSim.Framework.Util Run threadfunc 121 (Queued 3, Running 45)
2014-05-13 15:29:18,409 DEBUG - OpenSim.Framework.Util Run threadfunc 120 (Queued 4, Running 44)
2014-05-13 15:29:18,416 DEBUG - OpenSim.Framework.Util Queue threadfunc 125 (Queued 4, Running 45) at OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset.HGAssetBroker.Get(System.String id, System.Object sender, OpenSim.Services.Interfaces.AssetRetrieved handler)
2014-05-13 15:29:18,416 DEBUG - OpenSim.Framework.Util Exit threadfunc 119 (8 ms)
2014-05-13 15:29:18,416 DEBUG - OpenSim.Framework.Util Run threadfunc 123 (Queued 3, Running 45)
2014-05-13 15:29:18,721 DEBUG - OpenSim.Framework.Util Queue threadfunc 126 (Queued 4, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,721 DEBUG - OpenSim.Framework.Util Queue threadfunc 127 (Queued 5, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,722 DEBUG - OpenSim.Framework.Util Queue threadfunc 128 (Queued 6, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,722 DEBUG - OpenSim.Framework.Util Queue threadfunc 129 (Queued 7, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,723 DEBUG - OpenSim.Framework.Util Queue threadfunc 130 (Queued 8, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,723 DEBUG - OpenSim.Framework.Util Queue threadfunc 131 (Queued 9, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,724 DEBUG - OpenSim.Framework.Util Queue threadfunc 132 (Queued 10, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,724 DEBUG - OpenSim.Framework.Util Queue threadfunc 133 (Queued 11, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,725 DEBUG - OpenSim.Framework.Util Queue threadfunc 135 (Queued 13, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,724 DEBUG - OpenSim.Framework.Util Queue threadfunc 134 (Queued 12, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,725 DEBUG - OpenSim.Framework.Util Queue threadfunc 136 (Queued 14, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,725 DEBUG - OpenSim.Framework.Util Queue threadfunc 137 (Queued 15, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,726 DEBUG - OpenSim.Framework.Util Queue threadfunc 138 (Queued 16, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,726 DEBUG - OpenSim.Framework.Util Queue threadfunc 139 (Queued 17, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,727 DEBUG - OpenSim.Framework.Util Queue threadfunc 140 (Queued 18, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,727 DEBUG - OpenSim.Framework.Util Queue threadfunc 141 (Queued 19, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,727 DEBUG - OpenSim.Framework.Util Queue threadfunc 142 (Queued 20, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,727 DEBUG - OpenSim.Framework.Util Queue threadfunc 143 (Queued 21, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,727 DEBUG - OpenSim.Framework.Util Queue threadfunc 144 (Queued 22, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,728 DEBUG - OpenSim.Framework.Util Queue threadfunc 145 (Queued 23, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,728 DEBUG - OpenSim.Framework.Util Queue threadfunc 146 (Queued 24, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,728 DEBUG - OpenSim.Framework.Util Queue threadfunc 147 (Queued 25, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,728 DEBUG - OpenSim.Framework.Util Queue threadfunc 148 (Queued 26, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,729 DEBUG - OpenSim.Framework.Util Queue threadfunc 149 (Queued 27, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,729 DEBUG - OpenSim.Framework.Util Queue threadfunc 150 (Queued 28, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,729 DEBUG - OpenSim.Framework.Util Queue threadfunc 151 (Queued 29, Running 45) at OpenSim.Region.Physics.OdePlugin.OdePrim.CheckMeshAsset()
2014-05-13 15:29:18,730 DEBUG - OpenSim.Framework.Util Queue threadfunc 152 (Queued 30, Running 45) at
(0026065)
Robert Adams (administrator)
2014-05-13 07:30

ODEPrim.CheckMeshAsset() fires off a thread to do the database/assetserver fetch of the mesh asset. The mechanism is Util.FireAndForget() (a.k.a. BeginInvoke). BulletSim uses roughly the same code pattern. So, for both ODE and BulletSim, when a region starts up and all of the objects in the region are registered with the physics engine, the physics engines try to create a new thread for every object that needs a mesh (all non-simple prims). This pile of work on start-up could be pushing some of the Mono infrastructure over the edge.
(0026068)
Gavin Hird (reporter)
2014-05-13 11:44
edited on: 2014-05-13 12:34

Based on Robert's last comment, I wanted to test if the async_call_method setting in OpenSim.ini had any influence on how well the startup process performed. My observations were as follows (this is on the i7 processor for the standalone with most content and scripts):

With ODE enabled and async_call_method set to Thread, the mono-sgen process peaked at around 390% (sustained) CPU utilization during the phase where it was fetching the mesh assets. With the default setting async_call_method = SmartThreadPool the process peaked out at about 220%.

After everything was loaded it settled for around 12-15% CPU utilization which is about 5-7% lower than with the default setting. All meshes had their physics models generated correctly as far as I could tell.

With bulletsim and async_call_method set to Thread, the mono-sgen process peaked at around 160% (sustained) CPU utilization. Startup time was markedly shorter than for ODE.

After everything was loaded it settled for between 35-42% CPU utilization which is slightly lower than with the default setting. All meshes had their physics models generated correctly as far as I could tell.

For all other settings of the async_call_method the results were unpredictable both for ODE and bulletsim in that mono crashed into the debugger, physics models were not generated or mono malloc-ed.

For bulletsim it eventually malloced in the same manner as before with async_call_method set to Thread

EDIT ----

I did the same (set async_call_method set to Thread) for the public OSG sims (on a server with i5) and it behaved slightly different in that it ended up with about 220 threads allocated for the mono-sgen process while it peaked at close to 800 during the startup process. One marked effect is that sim crossings are markedly smoother and it also feels like texture loading are quite a bit faster. You can check from my andwest sim

... on the i7 (standalone) it has allocated closer to 250 treads and also there it peaked out at close to 800 during startup. – It might be the default thread allocation settings in OpenSim.ini are too low for efficient operation of the sims (when it kicks into overload mode with the default settings)?

(0026131)
Gavin Hird (reporter)
2014-05-20 04:27

Just an update after upgrading to OSgrid 0.8.0 (Dev) 5ec3429: 2014-05-19, and OS X 10.9.3

With bulletsim enabled, the CPU load on the standalone fell by about 5% on idle sims (no logged in avatars) to between 28-35%. However, it still crash after about 40 minutes in the same manner as reported before.

It looks like that for 10.9.3 Apple did changes to the kernel that contributes to the lower CPU load, since the ODE startup before was able to load the system with the mono-sgen up to around 400% and 800 threads, while it now maxed out at 732% CPU and over 1900 running threads (this on the i7). Idle sim ODE runs around 15% CPU load and 245 threads (using async_call_method set to Thread,) which is also a few notches down from before.
(0026199)
AliciaRaven (manager)
2014-05-28 02:00

Hi, i noticed the sudden spew of log events about thread functions today. Its caused by a commit from 25th april. These thread overload messages can be disabled by setting LogOverloads to false in the startup section of OpenSim.ini
(0026226)
Gavin Hird (reporter)
2014-06-01 23:51

Another update after upgrading to OSgrid 0.8.0 (Dev) 0aa0dad: 2014-06-01 (interface version 7)

With bulletsim enabled, the CPU load on the standalone fell by another 5% on idle sims (no logged in avatars) to between 22-27%.

It still terminates with the following messages:

# mono(5412,0xb6f71000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
*** error: can't allocate region securely
*** set a breakpoint in malloc_error_break to debug
mono(5412,0xb6f71000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
*** error: can't allocate region securely
*** set a breakpoint in malloc_error_break to debug
libc++abi.dylib: terminating with uncaught exception of type std::bad_alloc: std::bad_alloc
mono(5412,0xb6f71000) malloc: *** mach_vm_map(size=1048576) failed (error code=3)
*** error: can't allocate region securely
*** set a breakpoint in malloc_error_break to debug
Stacktrace:

--- left out as it did not give any more specifics to where in the code this happened. When it was running it increased process memory by about 1 Mb/sec till it was stopped.
(0026227)
Gavin Hird (reporter)
2014-06-02 00:14
edited on: 2014-06-02 00:14

Also for this update (should possibly be reported somewhere else), with async_call_method set to Thread, it starts generating the following messages, which eventually leads to failure in multiple modules during startup till it will crash ( I can supply the full log).


2014-06-02 08:18:55,442 ERROR - OpenSim.Region.Framework.Scenes.EventManager [EVENT MANAGER]: Delegate for OnRegionReadyStatusChange failed - continuing Object reference not set to an instance of an object - at OpenSim.Region.CoreModules.World.Warp3DMap.Warp3DImageModule.CreateMapTile (OpenSim.Region.CoreModules.World.Warp3DMap.Viewport viewport, Boolean useTextures) [0x00000] in <filename unknown>:0

(0026617)
orenh (administrator)
2014-07-27 02:57
edited on: 2014-07-27 02:59

I also see extremely high CPU usage by BulletSim. It happens when I enable the "Physics" flag on non-trivial objects. There are two separate problems with high CPU in BulletSim:

1. When I change a non-physical object to physical there's a long delay. This happens on the Heartbeat thread, so the entire simulator becomes hung while this happens. I added more detailed logging to BSScene.DoPhysicsStep(), and this is what it shows:

2014-07-27 12:27:26,434 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=265, numTaints=0, simTime=0, substeps=6, updates=0, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:27:26,525 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=266, numTaints=0, simTime=0, substeps=5, updates=0, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:27:26,616 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=267, numTaints=0, simTime=0, substeps=5, updates=0, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:27:26,707 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=268, numTaints=0, simTime=0, substeps=6, updates=0, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:27:26,798 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=269, numTaints=0, simTime=0, substeps=5, updates=0, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:27:32,255 ERROR - OpenSim.OpenSim [WATCHDOG]: Timeout detected for thread "Heartbeat (Edoras)". ThreadState=Running. Last tick was 5460ms ago.
2014-07-27 12:27:46,923 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=270, numTaints=364, simTime=20030, substeps=5, updates=2, colliders=1, objWColl=1, taintTime=18985, physicsStepTime=1045, collisionTime=0, updatePropertiesTime=0, postStepTime=0

Frame 270 is the frame where the slowdown occurred: it took 20 seconds. Nearly the entire time was taken up in the beginning of DoPhysicsStep(), where ProcessTaints() is called (twice).

2. After the initial slowdown is finished, BulletSim is still very slow as long as the physical object is moving. For example, if I lift the object in the air and drop it then I see very slow physics behavior (>100 ms per frame!) until the object finishes settling to the ground. At that point the physics time drops down to 0. For example:

(Before lifting the object in the air)

2014-07-27 12:29:47,266 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1569, numTaints=0, simTime=0, substeps=5, updates=0, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:47,357 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1570, numTaints=0, simTime=0, substeps=5, updates=0, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0

(After lifting the object in the air, and dropping it)

2014-07-27 12:29:49,586 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1571, numTaints=107, simTime=2137, substeps=6, updates=105, colliders=1, objWColl=1, taintTime=0, physicsStepTime=2137, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:50,999 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1572, numTaints=0, simTime=1404, substeps=5, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=1404, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:52,324 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1573, numTaints=0, simTime=1311, substeps=5, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=1311, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:53,699 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1574, numTaints=0, simTime=1358, substeps=6, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=1358, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:54,586 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1575, numTaints=0, simTime=874, substeps=5, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=874, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:55,167 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1576, numTaints=0, simTime=593, substeps=5, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=593, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:55,613 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1577, numTaints=0, simTime=436, substeps=6, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=436, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:29:55,986 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1578, numTaints=0, simTime=375, substeps=5, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=375, collisionTime=0, updatePropertiesTime=0, postStepTime=0

(There are about 30 more frames with high 'physicsStepTime here...)
(Finally, the object settles down)

2014-07-27 12:30:08,624 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1609, numTaints=0, simTime=437, substeps=6, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=437, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:30:08,979 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1610, numTaints=0, simTime=359, substeps=5, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=359, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:30:09,057 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1611, numTaints=26, simTime=78, substeps=5, updates=2, colliders=1, objWColl=1, taintTime=0, physicsStepTime=78, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:30:09,073 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1612, numTaints=11, simTime=0, substeps=6, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0
2014-07-27 12:30:09,169 DEBUG - OpenSim.Region.Physics.BulletSPlugin.BSScene Physics step: frame=1613, numTaints=13, simTime=0, substeps=5, updates=1, colliders=1, objWColl=1, taintTime=0, physicsStepTime=0, collisionTime=0, updatePropertiesTime=0, postStepTime=0

(Back to idle state)

The time called "physicsStepTime" is the call to PE.PhysicsStep(), which ends up calling BSAPICPP.PhysicsStep2().


I've seen this behavior with several objects. One of them was "Dirty Biker Hair", which is an object with about 140 prims. Another was a Campfire object which contains much fewer prims, but some of them are sculpties.

This doesn't happen with trivial objects such as boxes.


- Issue History
Date Modified Username Field Change
2013-10-02 18:02 Gwyneth Llewelyn New Issue
2013-10-11 03:01 Gwyneth Llewelyn Git Revision or version number fc4f86a => bd7d5f5
2013-10-11 03:04 Gwyneth Llewelyn OS Version 10.04 => 12.04.3 LTS
2013-10-11 03:07 Gwyneth Llewelyn Note Added: 0024446
2013-10-11 03:07 Gwyneth Llewelyn Note Edited: 0024446 View Revisions
2013-10-12 11:15 Gwyneth Llewelyn Note Added: 0024459
2013-10-12 18:21 Gwyneth Llewelyn Note Added: 0024463
2013-10-16 04:27 Gwyneth Llewelyn Note Added: 0024480
2013-10-16 04:45 Gwyneth Llewelyn Note Added: 0024481
2013-10-16 04:45 Gwyneth Llewelyn Note Edited: 0024481 View Revisions
2013-10-16 06:07 Gwyneth Llewelyn Note Added: 0024482
2013-10-18 09:25 Robert Adams Assigned To => Robert Adams
2013-10-18 09:25 Robert Adams Status new => assigned
2013-10-18 12:12 aiaustin Summary BulletSim consuming vast amounts of CPU => BulletSim: Consuming vast amounts of CPU
2013-10-18 19:34 Gwyneth Llewelyn Note Added: 0024535
2013-10-18 21:24 kenvc Note Added: 0024537
2013-10-19 10:44 Gwyneth Llewelyn Note Added: 0024541
2013-10-22 06:28 Gwyneth Llewelyn Note Added: 0024556
2013-10-22 06:45 Gwyneth Llewelyn Note Edited: 0024556 View Revisions
2013-10-26 21:56 Robert Adams Note Added: 0024575
2013-10-27 15:45 Gwyneth Llewelyn Note Added: 0024577
2013-10-27 15:51 Gwyneth Llewelyn Note Added: 0024578
2013-10-27 15:51 Gwyneth Llewelyn Note Edited: 0024578 View Revisions
2013-10-27 16:04 Gwyneth Llewelyn Note Added: 0024579
2013-10-28 07:34 Robert Adams Note Added: 0024580
2013-10-30 17:29 Gwyneth Llewelyn Note Added: 0024591
2014-05-12 04:39 Gwyneth Llewelyn Note Added: 0026043
2014-05-12 04:39 Gwyneth Llewelyn Note Edited: 0026043 View Revisions
2014-05-12 06:35 Robert Adams Note Added: 0026044
2014-05-12 07:10 Gavin Hird Note Added: 0026045
2014-05-12 07:48 Gavin Hird Note Added: 0026047
2014-05-12 07:49 Gavin Hird Note Edited: 0026045 View Revisions
2014-05-12 08:37 Robert Adams Note Added: 0026049
2014-05-12 08:42 Gavin Hird Note Added: 0026050
2014-05-12 09:56 Gavin Hird Note Added: 0026051
2014-05-12 10:08 Gavin Hird Note Added: 0026052
2014-05-12 10:27 Gavin Hird Note Added: 0026053
2014-05-12 10:27 Gavin Hird Note Edited: 0026053 View Revisions
2014-05-12 12:03 Gavin Hird Note Added: 0026054
2014-05-13 01:51 Gavin Hird Note Added: 0026057
2014-05-13 01:55 Gavin Hird Note Edited: 0026057 View Revisions
2014-05-13 01:57 Gavin Hird Note Edited: 0026057 View Revisions
2014-05-13 02:08 Gavin Hird Note Edited: 0026057 View Revisions
2014-05-13 04:28 Gwyneth Llewelyn Note Added: 0026059
2014-05-13 05:10 Gavin Hird Note Added: 0026063
2014-05-13 06:53 Gavin Hird Note Added: 0026064
2014-05-13 07:30 Robert Adams Note Added: 0026065
2014-05-13 11:44 Gavin Hird Note Added: 0026068
2014-05-13 12:12 Gavin Hird Note Edited: 0026068 View Revisions
2014-05-13 12:34 Gavin Hird Note Edited: 0026068 View Revisions
2014-05-20 04:27 Gavin Hird Note Added: 0026131
2014-05-28 02:00 AliciaRaven Note Added: 0026199
2014-06-01 23:51 Gavin Hird Note Added: 0026226
2014-06-02 00:14 Gavin Hird Note Added: 0026227
2014-06-02 00:14 Gavin Hird Note Edited: 0026227 View Revisions
2014-07-27 02:57 orenh Note Added: 0026617
2014-07-27 02:58 orenh Note Edited: 0026617 View Revisions
2014-07-27 02:59 orenh Note Edited: 0026617 View Revisions


Copyright © 2000 - 2012 MantisBT Group
Powered by Mantis Bugtracker