Lag in Vallone sim, in a very regular way

[animats]

I've been seeing lag every 10 seconds or so in Vallone sim for weeks. Today, though, while doing some timing tests on vehicle steering, a pattern appeared:

[11:22]  SIM LAGGING. Delay: 1.422260  Since previous lag: 1.598988
[11:22]  SIM LAGGING. Delay: 0.197685  Since previous lag: 8.414715
[11:22]  SIM LAGGING. Delay: 1.387371  Since previous lag: 1.562363
[11:23]  SIM LAGGING. Delay: 0.200169  Since previous lag: 8.438240
[11:23]  SIM LAGGING. Delay: 1.406193  Since previous lag: 1.650105
[11:23]  SIM LAGGING. Delay: 0.203171  Since previous lag: 8.358871
[11:23]  SIM LAGGING. Delay: 1.488628  Since previous lag: 1.662804
[11:23]  SIM LAGGING. Delay: 0.187752  Since previous lag: 8.320145
[11:23]  SIM LAGGING. Delay: 1.254395  Since previous lag: 1.454010
[11:23]  SIM LAGGING. Delay: 0.195648  Since previous lag: 8.566086
[11:23]  SIM LAGGING. Delay: 1.320679  Since previous lag: 1.542542
[11:23]  SIM LAGGING. Delay: 0.189110  Since previous lag: 8.450493
[11:23]  SIM LAGGING. Delay: 1.368523  Since previous lag: 1.543747
[11:23]  SIM LAGGING. Delay: 0.192764  Since previous lag: 8.460548
[11:23]  SIM LAGGING. Delay: 1.355927  Since previous lag: 1.489693
[11:24]  SIM LAGGING. Delay: 0.186714  Since previous lag: 8.500282
[11:24]  SIM LAGGING. Delay: 1.381752  Since previous lag: 1.628365
[11:24]  SIM LAGGING. Delay: 0.194176  Since previous lag: 8.395630
[11:24]  SIM LAGGING. Delay: 1.375374  Since previous lag: 1.532898
[11:24]  SIM LAGGING. Delay: 0.177559  Since previous lag: 8.456879
[11:24]  SIM LAGGING. Delay: 1.491974  Since previous lag: 1.670341
[11:24]  SIM LAGGING. Delay: 0.191803  Since previous lag: 8.303307
[11:24]  SIM LAGGING. Delay: 1.344498  Since previous lag: 1.539261
[11:24]  SIM LAGGING. Delay: 0.187225  Since previous lag: 8.477051
[11:24]  SIM LAGGING. Delay: 1.310120  Since previous lag: 1.510239
[11:24]  SIM LAGGING. Delay: 0.169800  Since previous lag: 8.477112
[11:24]  SIM LAGGING. Delay: 1.456055  Since previous lag: 1.637375
[11:25]  SIM LAGGING. Delay: 0.188034  Since previous lag: 8.366394
[11:25]  SIM LAGGING. Delay: 1.357407  Since previous lag: 1.515808
[11:25]  SIM LAGGING. Delay: 0.182831  Since previous lag: 8.472702
[11:25]  SIM LAGGING. Delay: 1.335922  Since previous lag: 1.518051
[11:25]  SIM LAGGING. Delay: 0.167603  Since previous lag: 8.497147
[11:25]  SIM LAGGING. Delay: 1.560043  Since previous lag: 1.758499

There's a very regular 10 second cycle.  There's a big lag of 1.5 seconds, and a smaller lag of about 150ms.  (The code timing this has a resolution of 25ms; it's from logging "control" events, which update every 25ms when a key is down, so all numbers have 25ms jitter.) Somebody in Vallone sim has a script that uses a lot of resources on a 10 second cycle. Any guesses as to what?

Support has tried to fix this several times. They can't find it. Restarting the sim doesn't help. This apparently doesn't show in "scripts using a lot of time" because it is not continuous.

[animats]

I packaged up the tester for this as a little bronze pyramid. It's here, and copyable, if you want one. It runs as long as it is rezzed, and whispers SIM LAGGING reports to anyone nearby. Don't leave these running permanently; it's a debug tool.

[Qie Niangao]

1 hour ago, animats said:

There's a very regular 10 second cycle.  There's a big lag of 1.5 seconds, and a smaller lag of about 150ms.  (The code timing this has a resolution of 25ms; it's from logging "control" events, which update every 25ms when a key is down, so all numbers have 25ms jitter.) Somebody in Vallone sim has a script that uses a lot of resources on a 10 second cycle. Any guesses as to what?

Support has tried to fix this several times. They can't find it. Restarting the sim doesn't help. This apparently doesn't show in "scripts using a lot of time" because it is not continuous.

That's a very compelling pattern. But I don't think it implicates an active script or scripts. As in other threads where this has been discussed, when I watch the sim statistics, it's as if the script demand is constant throughout, but something triggers the simulator to extend the execution frame (scripts can't do that themselves) which it's reporting in the "Pump IO" category of time accounting (whatever that actually means).

I suppose it's possible that some script is triggering a chain of causality that leads to extending the frame with all that idle "Spare Time" every 10 seconds, but... it sure would be nice to know what the Lindens did to try to track it down. I'd love to see the sim restarted with scripts turned off altogether at first, to see if the lag is still there -- and if not, whether it returns when scripts are turned back on after that.

[animats]

Avatar presence triggers it. Zero avatars in the sim, no lag. One avatar in sim, the pattern shown above. Two avatars in sim, a more complex pattern which settles down into the original pattern in about a minute.

I'm thinking badly coded security orb.

[animats]

I've been trying this tool in a few other places. In nearby sims in Kama City, it reports a short lag once in a while. In a big sandbox, it's mostly quiet. But crossing a sim boundary (entering, not exiting) with an avatar can cause a brief, measurable script lag, of about 150ms or so.  No worse with a vehicle. Less with the simple n00b avatars. Nothing like the 1.5 seconds lag every 10 seconds I see in Vallone, although Charlesville has something happening every 30 seconds.

If others want to try this, I have one outside my workshop in Vallone which anyone can copy. I also put it on Marketplace for L$10 as "Sim Lag Reporter".

[Ron Khondji]

The one in Vallone is not set to be copyable by anyone. 
Or was I looking at the wrong one?  
 

[animats]

Try now. Thanks.

[animats]

After filing a ticket, and much effort by LL support, the problem seems to have been found.

[11:16] Sim Lag Reporter v1.1: Turned on.  Reporting lags longer than 0.200000s
[11:17] Sim Lag Reporter v1.1: Vallone: NO LAG for 60.000000s.
[11:18] Sim Lag Reporter v1.1: Vallone: NO LAG for 120.015600s.
[11:19] Sim Lag Reporter v1.1: Vallone: NO LAG for 180.031300s.
[11:20] Sim Lag Reporter v1.1: Vallone: SIM LAGGING. Delay: 0.203125  Since previous lag: 230.046900
[11:20] Sim Lag Reporter v1.1: Vallone: SIM LAGGING. Delay: 1.140625  Since previous lag: 11.390630
[11:21] Sim Lag Reporter v1.1: Vallone: NO LAG for 60.031250s.
[11:22] Sim Lag Reporter v1.1: Vallone: NO LAG for 120.062500s.
[11:23] Sim Lag Reporter v1.1: Vallone: NO LAG for 180.093800s.
[11:24] Sim Lag Reporter v1.1: Vallone: NO LAG for 240.109400s.
[11:25] Sim Lag Reporter v1.1: Vallone: NO LAG for 300.125000s.
[11:26] Sim Lag Reporter v1.1: Vallone: NO LAG for 360.125000s.
[11:26] Sim Lag Reporter v1.1: Vallone: SIM LAGGING. Delay: 1.171875  Since previous lag: 367.656300
[11:27] Sim Lag Reporter v1.1: Vallone: NO LAG for 60.000000s.
[11:27] Sim Lag Reporter v1.1: Vallone: SIM LAGGING. Delay: 0.296875  Since previous lag: 76.968750
[11:28] Sim Lag Reporter v1.1: Vallone: NO LAG for 60.015630s.
[11:29] Sim Lag Reporter v1.1: Vallone: SIM LAGGING. Delay: 0.937500  Since previous lag: 85.109380
[11:29] Sim Lag Reporter v1.1: Vallone: SIM LAGGING. Delay: 1.078125  Since previous lag: 21.718750
[11:30] Sim Lag Reporter v1.1: Vallone: NO LAG for 60.015630s.

Every 5 minutes or so, there's lag, instead of regularly every 10 seconds. I can rez a bike and drive it around the block without those moments of 1.5 seconds when the rider has no control and velocity interpolation makes the position go crazy. The bike doesn't trigger a lag report, nor do normal on-sim activities. Much better.