cooldown: add 15 second delay for engine to stop

It turns out that some generators takes a long time
to respond to the instruction to switch off. When cooldown is
configured, the Multi is instructed to ignore AC-in while the
generator cools down, and AC-in is un-ignored once the generator
is stopped.

If the generator takes too long to stop, however, AC-in may
be re-engaged before the generator stops. To avoid this,
there is now a 15 second delay to allow the generator
to stop cleanly.

victronenergy/venus#1031

gen_utils.py

@@ -38,6 +38,7 @@ class States(object):
 	RUNNING = 1
 	WARMUP = 2
 	COOLDOWN = 3
+	STOPPING = 4
 	ERROR = 10
 
 	@staticmethod
@@ -46,8 +47,9 @@ def get_description(value):
 			'Stopped',
 			'Running',
 			'Warm-up',
-			'Cool-down'] + \
-		6 * [''] + [
+			'Cool-down',
+			'Stopping'] + \
+		5 * [''] + [
 			'Error']
 		d = ''
 		try:

startstop.py

@@ -47,6 +47,7 @@
 SYSTEM_SERVICE = 'com.victronenergy.system'
 BATTERY_PREFIX = '/Dc/Battery'
 HISTORY_DAYS = 30
+WAIT_FOR_ENGINE_STOP = 15
 
 def safe_max(args):
 	try:
@@ -547,7 +548,7 @@ def _evaluate_startstop_conditions(self):
 		# Update current and accumulated runtime.
 		# By performance reasons, accumulated runtime is only updated
 		# once per 60s. When the generator stops is also updated.
-		if self._dbusservice['/State'] in (States.RUNNING, States.WARMUP, States.COOLDOWN):
+		if self._dbusservice['/State'] in (States.RUNNING, States.WARMUP, States.COOLDOWN, States.STOPPING):
 			mtime = monotonic_time.monotonic_time().to_seconds_double()
 			if (mtime - self._starttime) - self._last_runtime_update >= 60:
 				self._dbusservice['/Runtime'] = int(mtime - self._starttime)
@@ -1068,7 +1069,7 @@ def _start_generator(self, condition):
 
 		# This function will start the generator in the case generator not
 		# already running. When differs, the RunningByCondition is updated
-		running = state in (States.WARMUP, States.COOLDOWN, States.RUNNING)
+		running = state in (States.WARMUP, States.COOLDOWN, States.STOPPING, States.RUNNING)
 		if not (running and remote_running): # STOPPED, ERROR
 			if self._settings['warmuptime'] > 0:
 				# Remove load while warming up
@@ -1083,13 +1084,13 @@ def _start_generator(self, condition):
 			self._update_remote_switch()
 			self._starttime = monotonic_time.monotonic_time().to_seconds_double()
 			self.log_info('Starting generator by %s condition' % condition)
-		else: # WARMUP, COOLDOWN, RUNNING
+		else: # WARMUP, COOLDOWN, RUNNING, STOPPING
 			if state == States.WARMUP:
 				if monotonic_time.monotonic_time().to_seconds_double() - self._starttime > self._settings['warmuptime']:
 					self._set_ignore_ac1(False) # Release load onto Generator
 					self._set_ignore_ac2(False)
 					self._dbusservice['/State'] = States.RUNNING
-			elif state == States.COOLDOWN:
+			elif state in (States.COOLDOWN, States.STOPPING):
 				# Start request during cool-down run, go back to RUNNING
 				self._set_ignore_ac1(False) # Put load back onto Generator
 				self._set_ignore_ac2(False)
@@ -1106,7 +1107,7 @@ def _start_generator(self, condition):
 	def _stop_generator(self):
 		state = self._dbusservice['/State']
 		remote_running = self._get_remote_switch_state()
-		running = state in (States.WARMUP, States.COOLDOWN, States.RUNNING)
+		running = state in (States.WARMUP, States.COOLDOWN, States.STOPPING, States.RUNNING)
 
 		if running or remote_running:
 			if self._settings['cooldowntime'] > 0:
@@ -1127,8 +1128,20 @@ def _stop_generator(self):
 						return # Don't stop engine yet
 
 			# When we arrive here, a stop command was given during warmup, the
-			# cooldown timer expired, no cooldown was configured. Stop
-			# immediately.
+			# cooldown timer expired, or no cooldown was configured. Stop
+			# the engine, but if we're coming from cooldown, delay another
+			# while in the STOPPING state before reactivating AC-in.
+			if state == States.COOLDOWN:
+				self._dbusservice['/State'] = States.STOPPING
+				self._update_remote_switch() # Stop engine
+				return
+			elif state == States.STOPPING:
+				if monotonic_time.monotonic_time().to_seconds_double() - \
+						self._stoptime <= self._settings['cooldowntime'] + WAIT_FOR_ENGINE_STOP:
+					return # Wait for engine stop
+
+			# All other possibilities are handled now. Cooldown is over or not
+			# configured and we waited for the generator to shut down.
 			self._dbusservice['/State'] = States.STOPPED
 			self._update_remote_switch()
 			self._set_ignore_ac1(False)

test/generator_test.py

@@ -23,6 +23,7 @@
 
 # Monkey-patch dbus connection
 startstop.StartStop._create_dbus_service = lambda s: create_service(s)
+startstop.WAIT_FOR_ENGINE_STOP = 1
 
 def create_service(s):
 	serv = MockDbusService('com.victronenergy.generator.startstop{}'.format(s._instance))
@@ -1272,11 +1273,27 @@ def test_warmup_and_cooldown(self):
 		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
 			'/Ac/Control/IgnoreAcIn2'), 0)
 
+		# Wait for engine to stop, AC is ignored
+		sleep(1)
+		self._update_values()
+		self._check_values(0, {
+			'/State': States.STOPPING
+		})
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn1'), 1)
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn2'), 0)
+
+		# Engine has stopped, re-enable AC
 		sleep(1)
 		self._update_values()
 		self._check_values(0, {
 			'/State': States.STOPPED
 		})
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn1'), 0)
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn2'), 0)
 
 	def test_warmup_and_cooldown_ac2(self):
 		self._set_setting('/Settings/Generator0/WarmUpTime', 1)
@@ -1316,11 +1333,27 @@ def test_warmup_and_cooldown_ac2(self):
 		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
 			'/Ac/Control/IgnoreAcIn2'), 1)
 
+		# Wait for engine to stop, AC is ignored
+		sleep(1)
+		self._update_values()
+		self._check_values(0, {
+			'/State': States.STOPPING
+		})
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn1'), 0)
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn2'), 1)
+
+		# Engine has stopped, re-enable AC
 		sleep(1)
 		self._update_values()
 		self._check_values(0, {
 			'/State': States.STOPPED
 		})
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn1'), 0)
+		self.assertEqual(self._monitor.get_value('com.victronenergy.vebus.ttyO1',
+			'/Ac/Control/IgnoreAcIn2'), 0)
 
 	def test_capabilities_no_warmupcooldown(self):
 		self._check_values(0, {'/Capabilities': 0})