Bug #18245 - memory use on chain wormholes

[Capt. Murphy]

Hi,

I've ended up playing with some long range jump code using chained wormholes and have observed the same phenomenon reported by Okti.

The code fires on ship.willExitWitchSpace - spawning an entity directly in front of the player and then using entity.exitSystem(nextdestination) to create a wormhole

The result is that the player never sees the intervening systems in the jump chain - he gets a repeated tunnel effect until arrival in the final system of the chain. However Oolite's memory uses increases with every jump and never goes down, until after the final jump is complete. If there is a fair few OXP's installed with large textures etc, the game will freeze or crash part way through the jump chain.

Logging with script.trace.javaScript = yes; reveals that this.shipExitedWitchSpace never fires in this scenario.

06:40:45.567 [murphy-autojumper]: this.initialJump started with earlyjump flag:true
06:40:45.570 [murphy-autojumper]: this.jumpArray: 7,129,124,154,157,90,44,228,125,212,225,115,100,139,21,230,150,110,145,179,133,4,184,169,34,202,59,142,213,223,238,182,170,117,66 ,this.jumpArray.length: 35
06:40:45.570 [murphy-autojumper]: this.jumpFunction called with earlyjump flag:true
06:40:45.575 [murphy-autojumper]: Jump destination: 129
06:40:45.578 [murphy-autojumper]: Jump success: true
06:40:45.817 [script.trace.javaScript]: Calling [BGS-M].shipWillEnterWitchspace()
06:40:45.817 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipWillEnterWitchspace()
06:40:45.817 [script.trace.javaScript]: Calling [Cabal_Common_OXPStrength].shipWillEnterWitchspace()
06:40:45.817 [script.trace.javaScript]: Calling [Cabal_Common_Comms].shipWillEnterWitchspace()
06:40:45.817 [script.trace.javaScript]: Calling [Cabal_Common_SpecialMarkets].shipWillEnterWitchspace()
06:40:45.817 [script.trace.javaScript]: Calling [oolite-nova].shipWillEnterWitchspace()
06:40:46.221 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.221 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.221 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.221 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.296 [script.trace.javaScript]: Calling [BGS-M].shipWillExitWitchspace()
06:40:46.306 [script.trace.javaScript]: Calling [murphy-autojumper].shipWillExitWitchspace()
06:40:46.306 [murphy-autojumper]: this.jumpFunction called with earlyjump flag:true
06:40:46.307 [murphy-autojumper]: Jump destination: 124
06:40:46.310 [murphy-autojumper]: Jump success: true
06:40:46.310 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipWillExitWitchspace()
06:40:46.310 [script.trace.javaScript]: Calling [oolite-cloaking-device].shipWillExitWitchspace()
06:40:46.310 [script.trace.javaScript]: Calling [Cabal_Common_OXPStrength].shipWillExitWitchspace()
06:40:46.310 [script.trace.javaScript]: Calling [oolite-trumbles].shipWillExitWitchspace()
06:40:46.310 [script.trace.javaScript]: Calling [Cabal_Common_SpecialMarkets].shipWillExitWitchspace()
06:40:46.310 [script.trace.javaScript]: Calling [oolite-nova].shipWillExitWitchspace()
06:40:46.327 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.328 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.328 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.329 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.329 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.329 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.330 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.330 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.330 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:46.330 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.057 [script.trace.javaScript]: Calling [BGS-M].shipWillEnterWitchspace()
06:40:47.057 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipWillEnterWitchspace()
06:40:47.057 [script.trace.javaScript]: Calling [Cabal_Common_OXPStrength].shipWillEnterWitchspace()
06:40:47.057 [script.trace.javaScript]: Calling [Cabal_Common_Comms].shipWillEnterWitchspace()
06:40:47.057 [script.trace.javaScript]: Calling [Cabal_Common_SpecialMarkets].shipWillEnterWitchspace()
06:40:47.057 [script.trace.javaScript]: Calling [oolite-nova].shipWillEnterWitchspace()
06:40:47.448 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.448 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.448 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.448 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.448 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.448 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.478 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.478 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:40:47.522 [script.trace.javaScript]: Calling [BGS-M].shipWillExitWitchspace()
06:40:47.523 [script.trace.javaScript]: Calling [murphy-autojumper].shipWillExitWitchspace()
06:40:47.523 [murphy-autojumper]: this.jumpFunction called with earlyjump flag:true
06:40:47.524 [murphy-autojumper]: Jump destination: 154
06:40:47.526 [murphy-autojumper]: Jump success: true
06:40:47.526 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipWillExitWitchspace()
06:40:47.526 [script.trace.javaScript]: Calling [oolite-cloaking-device].shipWillExitWitchspace()
06:40:47.526 [script.trace.javaScript]: Calling [Cabal_Common_OXPStrength].shipWillExitWitchspace()
06:40:47.526 [script.trace.javaScript]: Calling [oolite-trumbles].shipWillExitWitchspace()
06:40:47.526 [script.trace.javaScript]: Calling [Cabal_Common_SpecialMarkets].shipWillExitWitchspace()
06:40:47.526 [script.trace.javaScript]: Calling [oolite-nova].shipWillExitWitchspace()

The alternative version spawns the entity on this.shipExitedWitchSpace. The result is the player does see each intervening sytem between jumps, and memory use rises and falls with each jump staying relatively constant overall (there is a slight increase over the course of many jumps, but no where near as dramatic as with the above version.

06:45:52.027 [murphy-autojumper]: this.initialJump started with earlyjump flag:undefined
06:45:52.030 [murphy-autojumper]: this.jumpArray: 67,171,214,219,104,68,211,226,43,101,250,140,48,144,168,249,167,131,62,150,110,145,179,133,4,184,169,34,202,59,142,213,223,238,182,170,117,66 ,this.jumpArray.length: 38
06:45:52.030 [murphy-autojumper]: this.jumpFunction called with earlyjump flag:undefined
06:45:52.032 [murphy-autojumper]: Jump destination: 171
06:45:52.033 [murphy-autojumper]: Jump success: true
06:45:53.017 [script.trace.javaScript]: Calling [BGS-M].shipWillEnterWitchspace()
06:45:53.017 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipWillEnterWitchspace()
06:45:53.017 [script.trace.javaScript]: Calling [Cabal_Common_OXPStrength].shipWillEnterWitchspace()
06:45:53.017 [script.trace.javaScript]: Calling [Cabal_Common_Comms].shipWillEnterWitchspace()
06:45:53.017 [script.trace.javaScript]: Calling [Cabal_Common_SpecialMarkets].shipWillEnterWitchspace()
06:45:53.017 [script.trace.javaScript]: Calling [oolite-nova].shipWillEnterWitchspace()
06:45:53.346 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.346 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.346 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.346 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.346 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.346 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.357 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.357 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.370 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.370 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.393 [script.trace.javaScript]: Calling [BGS-M].shipWillExitWitchspace()
06:45:53.398 [script.trace.javaScript]: Calling [murphy-autojumper].shipWillExitWitchspace()
06:45:53.398 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipWillExitWitchspace()
06:45:53.399 [script.trace.javaScript]: Calling [oolite-cloaking-device].shipWillExitWitchspace()
06:45:53.399 [script.trace.javaScript]: Calling [Cabal_Common_OXPStrength].shipWillExitWitchspace()
06:45:53.399 [script.trace.javaScript]: Calling [oolite-trumbles].shipWillExitWitchspace()
06:45:53.399 [script.trace.javaScript]: Calling [Cabal_Common_SpecialMarkets].shipWillExitWitchspace()
06:45:53.399 [script.trace.javaScript]: Calling [oolite-nova].shipWillExitWitchspace()
06:45:53.423 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.423 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.423 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.423 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.423 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.423 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.424 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.425 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.425 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.425 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.426 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.426 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.426 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.426 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:53.426 [script.trace.javaScript]: Calling [oolite-default-ship-script].coordinatesForEscortPosition()
06:45:55.687 [script.trace.javaScript]: Calling [BGS-M].shipExitedWitchspace()
06:45:55.687 [script.trace.javaScript]: Calling [oolite-constrictor-hunt].shipExitedWitchspace()
06:45:55.687 [script.trace.javaScript]: Calling [murphy-autojumper].shipExitedWitchspace()
06:45:55.687 [murphy-autojumper]: this.jumpFunction called with earlyjump flag:undefined
06:45:55.689 [murphy-autojumper]: Jump destination: 214
06:45:55.690 [murphy-autojumper]: Jump success: true
06:45:55.690 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipExitedWitchspace()
06:45:55.691 [script.trace.javaScript]: Calling [explorer_club.js].shipExitedWitchspace()
06:45:55.691 [script.trace.javaScript]: Calling [oolite-thargoid-plans].shipExitedWitchspace()
06:45:55.691 [script.trace.javaScript]: Calling [oolite-nova].shipExitedWitchspace()
06:45:55.697 [script.trace.javaScript]: Calling [Cabal_Common_Music].alertConditionChanged()
06:45:56.687 [script.trace.javaScript]: Calling [BGS-M].shipWillEnterWitchspace()
06:45:56.687 [script.trace.javaScript]: Calling [Cabal_Common_Music].shipWillEnterWitchspace()
06:45:56.687 [script.trace.javaScript]: Calling [Cabal_Common_OXPStrength].shipWillEnterWitchspace()
06:45:56.687 [script.trace.javaScript]: Calling [Cabal_Common_Comms].shipWillEnterWitchspace()
06:45:56.687 [script.trace.javaScript]: Calling [Cabal_Common_SpecialMarkets].shipWillEnterWitchspace()
06:45:56.687 [script.trace.javaScript]: Calling [oolite-nova].shipWillEnterWitchspace()

So it appears that doing it the first way completely bypasses memory release on exiting a system in the source code. But the gradual overall memory increase in the 2nd version suggests a small ongoing memory leak somewhere.

This test was done with 1.76.....I'll repeat with trunk..... edit to add - results are similar with current nightly build.

[Switeck]

Okti's and my findings here:
https://bb.oolite.space/viewtopic.php?f=3&t=10439

...and associated bug report:
http://developer.berlios.de/bugs/?func= ... up_id=3577

[Eric Walch]

Logging with script.trace.javaScript = yes; reveals that this.shipExitedWitchSpace never fires in this scenario.

Maybe you can go to: ShipEntity.m, line 8357

and change:

Code: Select all

else if ([ent isWormhole])

into

Code: Select all

else if ([ent isWormhole] && [ent status] == STATUS_IN_FLIGHT)

That will make you only can enter the wormhole when in_flight. When the this.shipWillExitWitchSpace fires, the status is different, so you won't jump on that moment but on a next update. The probably gives the code time to do its normal cleanup during a jump and probably gives the this.shipExitedWitchSpace handler time to fire. When that does not fire, some other oxps might get confused.

[Capt. Murphy]

Maybe you can go to: ShipEntity.m, line 8357

and change:

Code: Select all

else if ([ent isWormhole])

into

Code: Select all

else if ([ent isWormhole] && [ent status] == STATUS_IN_FLIGHT)

.

That breaks wormholes entirely....I don't think wormholes are set with a STATUS_IN_FLIGHT flag.

However

Code: Select all

else if ([ent isWormhole] && [self status] == STATUS_IN_FLIGHT)

does have the effect of delaying the jump. Memory is being released as it should, but the overall effect is the same as the 2nd method, with the added problem that sometimes the player misses the wormhole entirely, which isn't quite what I was hoping for.

I'll keep on playing with both the script and the source to see if I can get it doing what I want it to do without crashing and report the results.

Edit to add - I'm looking at this section from PlayerEntity.m

Code: Select all

	// set clock after "playerWillEnterWitchspace" and before  removeAllEntitiesExceptPlayer, to allow escorts time to follow their mother. 
	double distance = distanceBetweenPlanetPositions(sTo.d,sTo.b,galaxy_coordinates.x,galaxy_coordinates.y);
	ship_clock_adjust += distance * distance * (misjump ? 2700.0 : 3600.0);	// LY * LY hrs - misjumps take 3/4 time of the full jump, they're not the same as a jump of half the length!
	
	[UNIVERSE removeAllEntitiesExceptPlayer];

and wondering if because the next jump is kicking in whilst the clock is adjusting that [UNIVERSE removeAllEntitiesExceptPlayer] isn't happening.....which then leads me to wonder if the JS script could remove all entities just before creating the new wormhole.....time to go to work now will investigate more tomorrow....