breakPatternCounter issues

For test results, bug reports, announcements of new builds etc.

Moderators: winston, another_commander, Getafix

Post Reply
User avatar
Milo
---- E L I T E ----
---- E L I T E ----
Posts: 462
Joined: Mon Sep 17, 2018 5:01 pm

breakPatternCounter issues

Post by Milo »

After a lengthy play session involving flying for 30 minutes or so out past the sun and back, I attempted to auto-dock. The game appeared to freeze with the HUD visible but black screen behind it. However, I didn't want to lose my progress, so I waited... and waited... and I'm still waiting, because it appears the game is still doing stuff. Occasionally, I even see comms activity pop up on the right side of the scanner and in the CommsLog MFD, so I know the game is actually still running and executing scripts. In the Latest.log, which is 385MB (I have too much logging enabled), following the lines indicating that I had begun the docking process, I see many repetitions of spawnShipsWithRole spawning multiples (as low as 3, sometimes over 20 at a time) of 'griffspark' and 'griffwreckage' and 'spinspark' near various ships (often police) followed by calls to 'griff_spawn_sparks 1.0' and 'griff_remove_spark_debris 1.0', and eventually, after quite a while of just that happening, it logged this:
11:37:18.137 [universe.addEntity.failed] -[Universe addEntity:]: ***** Universe cannot addEntity:<ShipEntity 0x56152340>{"Wreckage" position: (14442.6, -81958.7, 355492) scanClass: CLASS_ROCK status: STATUS_IN_FLIGHT} -- Universe is full (2047 entities out of 2048)
It then proceeded to log a lot of universe.objectDump lines, followed by more griff spark removal and adding, which again tripped over the entities limit and triggered another dump of all entities, followed by more griff sparks, etc. etc. etc.

TaskManager shows Oolite is continuing to run at around 9.5% CPU and around 1500 MB of memory. A message from the HOopy Casino just popped up, and this is still ongoing. Meanwhile, my controls in the game don't seem to do anything; I can't pause. The debug console is still hooked up, though, and it seems responsive. I therefore tried:

Code: Select all

z=system.allShips.length; while(z-- > 200) system.allShips[z].remove(); 
This seems to have ended the universe full cycle, however the docking process is still stalled. Any way to save this session?
[PlayerShip "Cobra Mark IV" position: (19903.6, -66525.7, 323765) scanClass: CLASS_PLAYER status: STATUS_DOCKING]
From a bit of code browsing, when the status is STATUS_DOCKING, I think performDockingUpdates() in PlayerEntity.m is supposed to transition to the docked state:

Code: Select all

- (void) performDockingUpdates:(OOTimeDelta)delta_t
{
	if ([UNIVERSE breakPatternOver])
	{
		[self docked];		// bookkeeping for docking
	}
}
In Universe.m:

Code: Select all

- (BOOL) breakPatternOver
{
	return (breakPatternCounter == 0);
}

- (BOOL) breakPatternHide
{
	Entity* player = PLAYER;
	return ((breakPatternCounter > 5)||(!player)||([player status] == STATUS_DOCKING));
}

- (void) setUpBreakPattern:(HPVector) pos orientation:(Quaternion) q forDocking:(BOOL) forDocking
{
	int						i;
	OOBreakPatternEntity	*ring = nil;
	id						colorDesc = nil;
	OOColor					*color = nil;
	
	[self setViewDirection:VIEW_FORWARD];
	
	q.w = -q.w;		// reverse the quaternion because this is from the player's viewpoint
	
	Vector			v = vector_forward_from_quaternion(q);
	Vector			vel = vector_multiply_scalar(v, -BREAK_PATTERN_RING_SPEED);
	
	// hyperspace colours
	
	OOColor *col1 = [OOColor colorWithRed:1.0 green:0.0 blue:0.0 alpha:0.5];	//standard tunnel colour
	OOColor *col2 = [OOColor colorWithRed:0.0 green:0.0 blue:1.0 alpha:0.25];	//standard tunnel colour
	
	colorDesc = [[self globalSettings] objectForKey:@"hyperspace_tunnel_color_1"];
	if (colorDesc != nil)
	{
		color = [OOColor colorWithDescription:colorDesc];
		if (color != nil)  col1 = color;
		else  OOLogWARN(@"hyperspaceTunnel.fromDict", @"could not interpret \"%@\" as a colour.", colorDesc);
	}

	colorDesc = [[self globalSettings] objectForKey:@"hyperspace_tunnel_color_2"];
	if (colorDesc != nil)
	{
		color = [OOColor colorWithDescription:colorDesc];
		if (color != nil)  col2 = color;
		else  OOLogWARN(@"hyperspaceTunnel.fromDict", @"could not interpret \"%@\" as a colour.", colorDesc);
	}
	
	unsigned	sides = kOOBreakPatternMaxSides;
	GLfloat		startAngle = 0;
	GLfloat		aspectRatio = 1;
	
	if (forDocking)
	{
		NSDictionary *info = [[PLAYER dockedStation] shipInfoDictionary];
		sides = [info oo_unsignedIntForKey:@"tunnel_corners" defaultValue:4];
		startAngle = [info oo_floatForKey:@"tunnel_start_angle" defaultValue:45.0f];
		aspectRatio = [info oo_floatForKey:@"tunnel_aspect_ratio" defaultValue:2.67f];
	}
	
	for (i = 1; i < 11; i++)
	{
		ring = [OOBreakPatternEntity breakPatternWithPolygonSides:sides startAngle:startAngle aspectRatio:aspectRatio];
		if (!forDocking)
		{
			[ring setInnerColor:col1 outerColor:col2];
		}
		
		Vector offset = vector_multiply_scalar(v, i * BREAK_PATTERN_RING_SPACING);
		[ring setPosition:HPvector_add(pos, vectorToHPVector(offset))];  // ahead of the player
		[ring setOrientation:q];
		[ring setVelocity:vel];
		[ring setLifetime:i * BREAK_PATTERN_RING_SPACING];
		
		// FIXME: better would be to have break pattern timing not depend on
		// these ring objects existing in the first place. - CIM
		if (forDocking && ![[PLAYER dockedStation] hasBreakPattern])
		{
			ring->isImmuneToBreakPatternHide = NO;
		}
		else if (!forDocking && ![self witchspaceBreakPattern])
		{
			ring->isImmuneToBreakPatternHide = NO;
		}
		[self addEntity:ring];
		breakPatternCounter++;
	}
}

- (BOOL)doRemoveEntity:(Entity *)entity
{
	// remove reference to entity in linked lists
	if ([entity canCollide])	// filter only collidables disappearing
	{
		doLinkedListMaintenanceThisUpdate = YES;
	}
	
	[entity removeFromLinkedLists];
	
	// moved forward ^^
	// remove from the reference dictionary
	int old_id = [entity universalID];
	entity_for_uid[old_id] = nil;
	[entity setUniversalID:NO_TARGET];
	[entity wasRemovedFromUniverse];
	
	// maintain sorted lists
	int index = entity->zero_index;
	
	int n = 1;
	if (index >= 0)
	{
		if (sortedEntities[index] != entity)
		{
			OOLog(kOOLogInconsistentState, @"DEBUG: Universe removeEntity:%@ ENTITY IS NOT IN THE RIGHT PLACE IN THE ZERO_DISTANCE SORTED LIST -- FIXING...", entity);
			unsigned i;
			index = -1;
			for (i = 0; (i < n_entities)&&(index == -1); i++)
				if (sortedEntities[i] == entity)
					index = i;
			if (index == -1)
				 OOLog(kOOLogInconsistentState, @"DEBUG: Universe removeEntity:%@ ENTITY IS NOT IN THE ZERO_DISTANCE SORTED LIST -- CONTINUING...", entity);
		}
		if (index != -1)
		{
			while ((unsigned)index < n_entities)
			{
				while (((unsigned)index + n < n_entities)&&(sortedEntities[index + n] == entity))
				{
					n++;	// ie there's a duplicate entry for this entity
				}
				
				/*
					BUG: when n_entities == UNIVERSE_MAX_ENTITIES, this read
					off the end of the array and copied (Entity *)n_entities =
					0x800 into the list. The subsequent update of zero_index
					derferenced 0x800 and crashed.
					FIX: add an extra unused slot to sortedEntities, which is
					always nil.
					EFFICIENCY CONCERNS: this could have been an alignment
					issue since UNIVERSE_MAX_ENTITIES == 2048, but it isn't
					really. sortedEntities is part of the object, not malloced,
					it isn't aligned, and the end of it is only live in
					degenerate cases.
					-- Ahruman 2012-07-11
				*/
				sortedEntities[index] = sortedEntities[index + n];	// copy entity[index + n] -> entity[index] (preserves sort order)
				if (sortedEntities[index])
				{
					sortedEntities[index]->zero_index = index;				// give it its correct position
				}
				index++;
			}
			if (n > 1)
				 OOLog(kOOLogInconsistentState, @"DEBUG: Universe removeEntity: REMOVED %d EXTRA COPIES OF %@ FROM THE ZERO_DISTANCE SORTED LIST", n - 1, entity);
			while (n--)
			{
				n_entities--;
				sortedEntities[n_entities] = nil;
			}
		}
		entity->zero_index = -1;	// it's GONE!
	}
	
	// remove from the definitive list
	if ([entities containsObject:entity])
	{
		// FIXME: better approach needed for core break patterns - CIM
		if ([entity isBreakPattern] && ![entity isVisualEffect])
		{
			breakPatternCounter--;
		}
		
		if ([entity isShip])
		{
			ShipEntity *se = (ShipEntity*)entity;
			[self clearBeacon:se];
		}
		if ([entity isWaypoint])
		{
			OOWaypointEntity *wp = (OOWaypointEntity*)entity;
			[self clearBeacon:wp];
		}
		if ([entity isVisualEffect])
		{
			OOVisualEffectEntity *ve = (OOVisualEffectEntity*)entity;
			[self clearBeacon:ve];
		}
		
		if ([entity isWormhole])
		{
			[activeWormholes removeObject:entity];
		}
		else if ([entity isPlanet])
		{
			[allPlanets removeObject:entity];
		}
		
		[entities removeObject:entity];
		return YES;
	}
	
	return NO;
}
So I guessed something went wrong with the break pattern, possibly related to having too many entities (although the universe full warnings seemed to start showing up a bit later than when I initiated docking). I do not think I saw the break pattern visually that first time I tried to dock.

Next I tried 'player.ship.launch()' and it launched me, but the screen behind the HUD was still black and it seemed stuck in STATUS_LAUNCHING:
[PlayerShip "Cobra Mark IV" position: (11683.1, -71661.9, 363744) scanClass: CLASS_PLAYER status: STATUS_LAUNCHING]
In this state, I collided with the nav buoy, and continued for a while, before I tried 'system.mainStation.dockPlayer()' ... which displayed the break pattern this time (maybe I missed it before), but then went back to STATUS_DOCKING. Still stuck.
[PlayerShip "Cobra Mark IV" position: (9830.68, -60274, 370802) scanClass: CLASS_PLAYER status: STATUS_DOCKING]
I was able to regain access to the keyboard controls by engaging the autopilot with player.ship.engageAutopilotToStation(system.mainStation) after launching with player.ship.launch(). I was able to pause, change game options, switch views (though with no visual effect, just the HUD acknowledging the view change), toggle autopilot off (c), and retain control... keyboard still responsive and now my ship status is STATUS_IN_FLIGHT, but the background behind the HUD remains black. External camera (v) makes the HUD disappear, forward view (1) brings it back...

I let the autopilot dock me the slow way, which worked, but still stuck in STATUS_DOCKING after break pattern was displayed.

I suspect that there are some left-over break pattern entities lingering from the very first docking attempt, and therefore breakPatternHide is true, resulting in everything being hidden and my docking attempts unable to complete.

But, system.allVisualEffects contains only 2 effects, both belonging to the compass (datakey === planetaryCompass_moon, planetaryCompass_planet). When I launch/dock, I see bgs_docking effects show up there during the tunnel visual. But I'm not sure how to see if any of the internal "ring" entities still exist.

So... I attached a debugger to the running process and searched for an integer value greater than 5 that increased when I was going through the docking tunnel and then returned to its original value, and I narrowed it down to a single memory address, which contained the value 9. After changing that to zero, I was able to successfully dock.

Perhaps the rings were created but failed to be added to the entities list? Or some rings failed to be created? Either way, breakPatternCounter was still incremented, and since it was > 5, I was unable to complete the docking process (and everything was hidden for the same reason). Anyway, game session saved in the end, I'm happy. But still a bit mystified.
User avatar
phkb
Impressively Grand Sub-Admiral
Impressively Grand Sub-Admiral
Posts: 4830
Joined: Tue Jan 21, 2014 10:37 pm
Location: Writing more OXPs, because the world needs more OXPs.

Re: breakPatternCounter issues

Post by phkb »

Not sure about what happened, but if you can still enter commands,

Code: Select all

system.mainStation.dockPlayer()
will get you inside quickly.
User avatar
Milo
---- E L I T E ----
---- E L I T E ----
Posts: 462
Joined: Mon Sep 17, 2018 5:01 pm

Re: breakPatternCounter issues

Post by Milo »

I could enter that command, but it got stuck in STATUS_DOCKING. The breakPatternCounter property on the Universe object was greater than 5 (it had a value of 9 left over from an earlier docking attempt or attempts: I'm not sure if all 9 were left over from the first time or if my subsequent attempts further increased it). When breakPatternCounter > 5, the breakPatternHide method on the Universe object returns true, preventing almost all entities (other than break patterns themselves) from being rendered. Therefore, I couldn't see anything behind the HUD. And when breakPatternCounter is non-zero, the Universe method breakPatternOver returns false, which blocks the transition from STATUS_DOCKING to STATUS_DOCKED in performDockingUpdate. So, you can't finish docking (it also prevents STATUS_LAUNCHING transitioning to STATUS_IN_FLIGHT, but enabling autopilot gets around that).

Why was the breakPatternCounter out of sync, is the question. The break pattern entities ("rings") are assigned a lifetime value and call RemoveEntity on themselves when it expires, which handles the decrement of breakPatternCounter. On the other hand, the increment of breakPatternCounter is done regardless of whether there is a failure in creating the break pattern entities or whether there is a failure in adding them to the global entities list. I am not sure if it is possible to fail either of those things, but that is my only hypothesis at the moment.
User avatar
Milo
---- E L I T E ----
---- E L I T E ----
Posts: 462
Joined: Mon Sep 17, 2018 5:01 pm

Re: breakPatternCounter issues

Post by Milo »

In my local Oolite build, I've raised max entities to 4096 from 2048. So far, I don't think my entity count has exceeded 2048, however. I also went into the Griff Alloys and Wreckage OXZ and cut the random ranges and AI pause timings in half, more or less (I also noticed that some of the random spawn amounts in that OXZ have comments that didn't match the amount actually produced by the formulas). The visuals still seem fine to me, and they clear up sooner. With this, I'm seeing entities in-system (as shown by shift-F) usually staying under 600, and I was able to play for a long time without any significant issues. One other change I made that might be relevant to the improvement is that I disabled two logging entries in logcontrol.plist that had been responsible for a disproportionate amount of my latest.log, and as a precaution I disabled the third line also:

Code: Select all

	script.debug.replaceVariablesInString	= no;
	script.javaScript.load.success			= no;
	universe.maxEntitiesDump = no;
Post Reply