Repository: missionpinball/mpf
Issue: Bug in timer control event handling

When trying to use an event with args as a control event in a timer, it screws up the timer. Here's an example config:

```
timers:
    world_tour_timer:
        start_value: 20
        max_value: 20
        tick_interval: 1s
        direction: down
        control_events:
          - event: timer_wt_intro_timer_complete
            action: start
          - event: player_world_tour_world_tour_timer_tick{value == 5} # This is the problem
            action: change_tick_interval
            value: 1.5
          - event: add_time
            action: add
            value: 3
          - event: s_subwayopto_active
            action: stop
```

With this config, I want the timer to change the tick interval to 1.5s for the last 5 seconds. If I put a normal event in there (like a switch that I push to test it), it works, but with the event that's in the above config, it just resets the timer to 0.


Changed files:
mpf/core/timer.py, mpf/core/events.py, mpf/tests/test_Timer.py, mpf/core/logging.py

diff --git a/mpf/core/events.py b/mpf/core/events.py
index cb561a343..a8c07569a 100644
--- a/mpf/core/events.py
+++ b/mpf/core/events.py
@@ -525,8 +525,8 @@ class EventManager(MpfController):
             # in while we were processing previous handlers
 
             # merge the post's kwargs with the registered handler's kwargs
-            # in case of conflict, posts kwargs will win
-            merged_kwargs = dict(list(handler.kwargs.items()) + list(kwargs.items()))
+            # in case of conflict, handlers kwargs will win
+            merged_kwargs = dict(list(kwargs.items()) + list(handler.kwargs.items()))
 
             # if condition exists and is not true skip
             if handler.condition is not None and not handler.condition.evaluate(merged_kwargs):
@@ -568,8 +568,8 @@ class EventManager(MpfController):
             # in while we were processing previous handlers
 
             # merge the post's kwargs with the registered handler's kwargs
-            # in case of conflict, posts kwargs will win
-            merged_kwargs = dict(list(handler.kwargs.items()) + list(kwargs.items()))
+            # in case of conflict, handler kwargs will win
+            merged_kwargs = dict(list(kwargs.items()) + list(handler.kwargs.items()))
 
             # if condition exists and is not true skip
             if handler.condition is not None and not handler.condition.evaluate(merged_kwargs):
diff --git a/mpf/core/logging.py b/mpf/core/logging.py
index 7ac65d9fe..abfcbca41 100644
--- a/mpf/core/logging.py
+++ b/mpf/core/logging.py
@@ -49,7 +49,7 @@ class LogMixin(object):
         if self.unit_test:
             self._info_to_console = True
 
-    def debug_log(self, msg, *args, **kwargs):
+    def debug_log(self, msg: str, *args, **kwargs):
         """Log a message at the debug level.
 
         Note that whether this message shows up in the console or log file is
@@ -63,7 +63,7 @@ class LogMixin(object):
         elif self._debug_to_file:
             self.log.log(11, msg, *args, **kwargs)
 
-    def info_log(self, msg, *args, **kwargs):
+    def info_log(self, msg: str, *args, **kwargs):
         """Log a message at the info level.
 
         Whether this message shows up in the console or log file is controlled
@@ -77,7 +77,7 @@ class LogMixin(object):
         elif self._info_to_file or self._debug_to_file:
             self.log.log(11, msg, *args, **kwargs)
 
-    def warning_log(self, msg, *args, **kwargs):
+    def warning_log(self, msg: str, *args, **kwargs):
         """Log a message at the warning level.
 
         These messages will always be shown in the console and the log file.
diff --git a/mpf/core/timer.py b/mpf/core/timer.py
index 7887cfd0a..a6f727680 100644
--- a/mpf/core/timer.py
+++ b/mpf/core/timer.py
@@ -1,7 +1,15 @@
 """Mode timers."""
+from typing import TYPE_CHECKING, List
+
 from mpf.core.delays import DelayManager
 from mpf.core.logging import LogMixin
 
+if TYPE_CHECKING:
+    from mpf.core.machine import MachineController
+    from mpf.core.mode import Mode
+    from mpf.core.clock import PeriodicTask
+    from mpf.core.events import EventHandlerKey
+
 
 # pylint: disable-msg=too-many-instance-attributes
 class Timer(LogMixin):
@@ -17,7 +25,7 @@ class Timer(LogMixin):
 
     """
 
-    def __init__(self, machine, mode, name, config):
+    def __init__(self, machine: "MachineController", mode: "Mode", name: str, config: dict) -> None:
         """Initialise mode timer."""
         super().__init__()
         self.machine = machine
@@ -40,8 +48,8 @@ class Timer(LogMixin):
         self.max_value = self.config['max_value']
         self.direction = self.config['direction'].lower()
         self.tick_secs = self.config['tick_interval'] / 1000.0
-        self.timer = None
-        self.event_keys = set()
+        self.timer = None               # type: PeriodicTask
+        self.event_keys = list()        # type: List[EventHandlerKey]
         self.delay = DelayManager(self.machine.delayRegistry)
 
         if self.config['debug']:
@@ -97,7 +105,7 @@ class Timer(LogMixin):
     def _setup_control_events(self, event_list):
         self.debug_log("Setting up control events")
 
-        kwargs = None
+        kwargs = {}
         for entry in event_list:
             if entry['action'] in ('add', 'subtract', 'jump', 'pause', 'set_tick_interval'):
                 handler = getattr(self, entry['action'])
@@ -118,12 +126,8 @@ class Timer(LogMixin):
                 raise AssertionError("Invalid control_event action {} in mode".
                                      format(entry['action']), self.name)
 
-            if kwargs:
-                self.event_keys.add(self.machine.events.add_handler(
-                                    entry['event'], handler, **kwargs))
-            else:
-                self.event_keys.add(self.machine.events.add_handler(
-                                    entry['event'], handler))
+            self.event_keys.append(self.machine.events.add_handler(
+                                entry['event'], handler, **kwargs))
 
     def _remove_control_events(self):
         self.debug_log("Removing control events")
diff --git a/mpf/tests/test_Timer.py b/mpf/tests/test_Timer.py
index 83c231c2a..79d0b04da 100644
--- a/mpf/tests/test_Timer.py
+++ b/mpf/tests/test_Timer.py
@@ -230,7 +230,7 @@ class TestTimer(MpfFakeGameTestCase):
         self.assertEqual(1, timer.ticks)
         self.post_event('jump_timer_up')
         self.assertEqual(5, timer.ticks)
-        self.post_event("change_tick_interval_timer_up")
+        self.post_event_with_params("change_tick_interval_timer_up", change=1)
         # 1s * 4 = 4s
         self.advance_time_and_run(1)
         self.assertEqual(5, timer.ticks)