Merge branch 'dev' into lights_platform

mpf/_version.py

@@ -10,7 +10,7 @@
 
 """
 
-__version__ = '0.33.0-dev.10'
+__version__ = '0.33.0-dev.11'
 __short_version__ = '0.33'
 __bcp_version__ = '1.0'
 __config_version__ = '4'

mpf/core/ball_controller.py

@@ -283,9 +283,9 @@ def collect_balls(self, target='home, trough'):
                     source_devices.add(device)
                     balls_to_collect = True
 
-        self.debug_log("Ejecting all balls from: %s", source_devices)
-
         if balls_to_collect:
+            self.debug_log("Ejecting all balls from: %s", source_devices)
+
             self.machine.events.post('collecting_balls')
             '''event: collecting_balls
 

mpf/core/device.py

@@ -25,7 +25,6 @@ def __init__(self, machine: MachineController, name: str):
         self.name = name.lower()
         self.tags = []
         self.label = None
-        self.debug = False
         self.platform = None
         self.config = dict()
 
@@ -73,6 +72,11 @@ def validate_and_parse_config(self, config: dict, is_mode_config: bool) -> dict:
         return config
 
     def _configure_device_logging(self, config):
+
+        if config['debug']:
+            config['console_log'] = 'full'
+            config['file_log'] = 'full'
+
         self.configure_logging(self.class_label + '.' + self.name,
                                config['console_log'],
                                config['file_log'])

mpf/core/mode_timer.py

@@ -50,7 +50,7 @@ def __init__(self, machine, mode, name, config):
 
         if self.config['debug']:
             self.configure_logging('ModeTimer.' + name,
-                                   'basic', 'full')
+                                   'full', 'full')
         else:
             self.configure_logging('ModeTimer.' + name,
                                    self.config['console_log'],

mpf/devices/ball_device/ball_count_handler.py

@@ -163,10 +163,15 @@ def initialise(self):
         self.ball_device.counted_balls = self._ball_count
         yield from super().initialise()
 
+    @property
+    def has_ball(self):
+        """Return true if the device has at least one ball."""
+        return self._ball_count > 0
+
     @asyncio.coroutine
     def wait_for_ball(self):
         """Wait until the device has a ball."""
-        if self._ball_count > 0:
+        if self.has_ball:
             self.debug_log("We have %s balls.", self._ball_count)
             return
 
@@ -199,6 +204,8 @@ def wait_for_ready_to_receive(self, source):
                 self.debug_log("Ready to receive from %s. Free space %s (Capacity: %s, Balls: %s), incoming_balls: %s",
                                source, free_space, self.ball_device.config['ball_capacity'], self._ball_count,
                                incoming_balls)
+                # wait for the counter to be ready
+                yield from self.ball_device.counter.wait_for_ready_to_receive()
                 return True
 
             self.debug_log("Not ready to receive from %s. Free space %s (Capacity: %s, Balls: %s), incoming_balls: %s",

mpf/devices/ball_device/ball_device_ball_counter.py

@@ -40,6 +40,10 @@ def wait_for_ball_activity(self):
         """Wait for ball activity."""
         raise NotImplementedError()
 
+    def wait_for_ready_to_receive(self):
+        """Wait until the counter is ready to count an incoming ball."""
+        raise NotImplementedError()
+
     def received_entrance_event(self):
         """Handle entrance event."""
         pass

mpf/devices/ball_device/entrance_switch_counter.py

@@ -84,14 +84,15 @@ def count_balls(self):
 
     def _wait_for_ball_to_leave(self):
         """Wait for a ball to leave."""
-        if self.machine.switch_controller.is_active(self.config['entrance_switch'].name):
-            return self.machine.switch_controller.wait_for_switch(
-                switch_name=self.config['entrance_switch'].name,
-                state=0)
-        else:
-            # wait 10ms
-            done_future = asyncio.sleep(0.01, loop=self.machine.clock.loop)
-            return Util.ensure_future(done_future, loop=self.machine.clock.loop)
+        # wait 10ms
+        done_future = asyncio.sleep(0.01, loop=self.machine.clock.loop)
+        return Util.ensure_future(done_future, loop=self.machine.clock.loop)
+
+    def wait_for_ready_to_receive(self):
+        """Wait until the entrance switch is inactive."""
+        return self.machine.switch_controller.wait_for_switch(
+            switch_name=self.config['entrance_switch'].name,
+            state=0, only_on_change=False)
 
     def wait_for_ball_activity(self):
         """Wait for ball count changes."""

mpf/devices/ball_device/hold_coil_ejector.py

@@ -53,9 +53,8 @@ def hold(self, **kwargs):
 
     def _enable_hold_coil(self):
         self.ball_device.config['hold_coil'].enable()
-        if self.ball_device.debug:
-            self.ball_device.log.debug("Enabling hold coil. New "
-                                       "balls: %s.", self.ball_device.balls)
+        self.ball_device.debug_log("Enabling hold coil. New "
+                                   "balls: %s.", self.ball_device.balls)
 
     def _hold_release_done(self):
         self.hold_release_in_progress = False

mpf/devices/ball_device/incoming_balls_handler.py

@@ -1,5 +1,6 @@
 """Handles incoming balls."""
 import asyncio
+from functools import partial
 
 from mpf.core.utility_functions import Util
 from mpf.devices.ball_device.ball_device_state_handler import BallDeviceStateHandler
@@ -13,6 +14,7 @@ def __init__(self, source, target):
         """Initialise incoming ball."""
         self._timeout_future = asyncio.Future(loop=source.machine.clock.loop)
         self._confirm_future = asyncio.Future(loop=source.machine.clock.loop)
+        self._can_skip_future = asyncio.Future(loop=source.machine.clock.loop)
         self._source = source
         self._target = target
         self._external_confirm_future = None
@@ -22,6 +24,14 @@ def __init__(self, source, target):
         # 3. arrived
         # 4. lost (timeouted)
 
+    def set_can_skip(self):
+        """Tell other devices that this ball may have """
+        self._can_skip_future.set_result(True)
+
+    def wait_for_can_skip(self):
+        """Wait until this future can skip."""
+        return asyncio.shield(self._can_skip_future, loop=self._source.machine.clock.loop)
+
     @property
     def can_arrive(self):
         """Return true if ball can arrive."""
@@ -115,6 +125,9 @@ def get_num_incoming_balls(self):
     def _run(self):
         """Handle timeouts."""
         while True:
+            if not self._incoming_balls:
+                self._has_incoming_balls.clear()
+
             # sleep until we have incoming balls
             yield from self._has_incoming_balls.wait()
 
@@ -130,9 +143,6 @@ def _run(self):
                 self.ball_device.log.warning("Incoming ball from %s timeouted.", incoming_ball.source)
                 self._incoming_balls.remove(incoming_ball)
 
-            if not self._incoming_balls:
-                self._has_incoming_balls.clear()
-
             for incoming_ball in timeouts:
                 yield from self.ball_device.lost_incoming_ball(source=incoming_ball.source)
 
@@ -143,26 +153,30 @@ def add_incoming_ball(self, incoming_ball: IncomingBall):
         self._has_incoming_balls.set()
 
         if self.ball_device.config['mechanical_eject']:
+            incoming_ball.wait_for_can_skip().add_done_callback(
+                partial(self._add_incoming_ball_which_may_skip_cb, incoming_ball))
+
+    def _add_incoming_ball_which_may_skip_cb(self, incoming_ball, future):
+        if not future.cancelled():
             self.ball_device.outgoing_balls_handler.add_incoming_ball_which_may_skip(incoming_ball)
 
     def remove_incoming_ball(self, incoming_ball: IncomingBall):
         """Remove incoming ball."""
         self.debug_log("Removing incoming ball from %s", incoming_ball.source)
         self._incoming_balls.remove(incoming_ball)
-        if self.ball_device.config['mechanical_eject']:
-            self.ball_device.outgoing_balls_handler.remove_incoming_ball_which_may_skip()
+        if self.ball_device.config['mechanical_eject'] and incoming_ball.wait_for_can_skip().done():
+            self.ball_device.outgoing_balls_handler.remove_incoming_ball_which_may_skip(incoming_ball)
 
     @asyncio.coroutine
     def ball_arrived(self):
         """Handle one ball which arrived in the device."""
-        if self.ball_device.config['mechanical_eject']:
-            self.ball_device.outgoing_balls_handler.remove_incoming_ball_which_may_skip()
         for incoming_ball in self._incoming_balls:
             if not incoming_ball.can_arrive:
                 continue
 
             # handle incoming ball
             self.debug_log("Received ball from %s", incoming_ball.source)
+
             # confirm eject
             incoming_ball.ball_arrived()
 

mpf/devices/ball_device/outgoing_balls_handler.py

@@ -31,24 +31,27 @@ def __init__(self, ball_device):
         self._current_target = None
         self._cancel_future = None
         self._incoming_ball_which_may_skip = asyncio.Event(loop=self.machine.clock.loop)
+        self._incoming_ball_which_may_skip.clear()
         self._no_incoming_ball_which_may_skip = asyncio.Event(loop=self.machine.clock.loop)
-        self._incoming_ball_which_may_skip_obj = None
+        self._no_incoming_ball_which_may_skip.set()
+        self._incoming_ball_which_may_skip_obj = []
 
     def add_eject_to_queue(self, eject: OutgoingBall):
         """Add an eject request to queue."""
         self._eject_queue.put_nowait(eject)
 
     def add_incoming_ball_which_may_skip(self, incoming_ball):
         """Add incoming ball which may skip the device."""
-        self._incoming_ball_which_may_skip_obj = incoming_ball
+        self._incoming_ball_which_may_skip_obj.append(incoming_ball)
         self._no_incoming_ball_which_may_skip.clear()
         self._incoming_ball_which_may_skip.set()
 
-    def remove_incoming_ball_which_may_skip(self):
+    def remove_incoming_ball_which_may_skip(self, incoming_ball):
         """Remove incoming ball which may skip the device."""
-        self._incoming_ball_which_may_skip.clear()
-        self._no_incoming_ball_which_may_skip.set()
-        self._incoming_ball_which_may_skip_obj = None
+        self._incoming_ball_which_may_skip_obj.remove(incoming_ball)
+        if not self._incoming_ball_which_may_skip_obj:
+            self._incoming_ball_which_may_skip.clear()
+            self._no_incoming_ball_which_may_skip.set()
 
     @asyncio.coroutine
     def _run(self):
@@ -83,19 +86,20 @@ def _run(self):
 
     @asyncio.coroutine
     def _skipping_ball(self, target, add_ball_to_target):
+        incoming_skipping_ball = self._incoming_ball_which_may_skip_obj[0]
         self.debug_log("Expecting incoming ball which may skip the device.")
         eject_request = OutgoingBall(target)
         yield from self._post_ejecting_event(eject_request, 1)
         incoming_ball_at_target = self._add_incoming_ball_to_target(eject_request.target)
-        confirm_future = incoming_ball_at_target.wait_for_confirm()
-        ball_future = self.ball_device.ball_count_handler.wait_for_ball()
-        futures = [confirm_future, self._no_incoming_ball_which_may_skip.wait(), ball_future]
+        confirm_future = Util.ensure_future(incoming_ball_at_target.wait_for_confirm(), self.machine.clock.loop)
+        ball_future = Util.ensure_future(self.ball_device.ball_count_handler.wait_for_ball(), self.machine.clock.loop)
+        no_incoming_future = Util.ensure_future(self._no_incoming_ball_which_may_skip.wait(), self.machine.clock.loop)
+        futures = [confirm_future, no_incoming_future, ball_future]
         if self._cancel_future:
             futures.append(self._cancel_future)
 
         if target.is_playfield():
-            timeout = self.ball_device.config['eject_timeouts'][target] / 1000 + \
-                self._incoming_ball_which_may_skip_obj.source.config['eject_timeouts'][self.ball_device] / 1000
+            timeout = self.ball_device.config['eject_timeouts'][target] / 1000
         else:
             timeout = None
 
@@ -108,10 +112,7 @@ def _skipping_ball(self, target, add_ball_to_target):
         if event == confirm_future:
             self.debug_log("Got confirm for skipping ball.")
             yield from self._handle_eject_success(None, eject_request)
-            self._incoming_ball_which_may_skip_obj.ball_arrived()
-            self._incoming_ball_which_may_skip.clear()
-            self._incoming_ball_which_may_skip_obj = None
-            self._no_incoming_ball_which_may_skip.set()
+            incoming_skipping_ball.ball_arrived()
             if add_ball_to_target:
                 target.available_balls += 1
             return True
@@ -183,31 +184,39 @@ def cancel_path_if_target_is(self, start, target) -> bool:
     @asyncio.coroutine
     def _ejecting(self, eject_request: OutgoingBall):
         """Perform main eject loop."""
-        # TODO: handle unexpected mechanical eject
         eject_try = 0
         while True:
             self._current_target = eject_request.target
-            self._cancel_future = asyncio.Future(loop=self.machine.clock.loop)
-            ball_future = self.ball_device.ball_count_handler.wait_for_ball()
-            skipping_ball_future = Util.ensure_future(self._incoming_ball_which_may_skip.wait(),
-                                                      loop=self.machine.clock.loop)
-            # wait until we have a ball (might be instant)
-            self.ball_device.set_eject_state("waiting_for_ball")
-            yield from Util.first([self._cancel_future, ball_future, skipping_ball_future],
-                                  loop=self.machine.clock.loop)
-
-            if skipping_ball_future.done() and not skipping_ball_future.cancelled():
+
+            if not self.ball_device.ball_count_handler.has_ball:
+                # wait until we have a ball
                 self._cancel_future = asyncio.Future(loop=self.machine.clock.loop)
-                result = yield from self._skipping_ball(self._current_target, False)
-                if result or self._cancel_future.done() and not self._cancel_future.cancelled():
+                ball_future = Util.ensure_future(self.ball_device.ball_count_handler.wait_for_ball(),
+                                                 loop=self.machine.clock.loop)
+                skipping_ball_future = Util.ensure_future(self._incoming_ball_which_may_skip.wait(),
+                                                          loop=self.machine.clock.loop)
+
+                self.ball_device.set_eject_state("waiting_for_ball")
+                result = yield from Util.first([self._cancel_future, ball_future, skipping_ball_future],
+                                               loop=self.machine.clock.loop)
+
+                if result == skipping_ball_future:
+                    self._cancel_future = asyncio.Future(loop=self.machine.clock.loop)
+                    result = yield from self._skipping_ball(self._current_target, False)
+                    if result or self._cancel_future.done() and not self._cancel_future.cancelled():
+                        self._cancel_future = None
+                        return True
+                    else:
+                        self._cancel_future = None
+                        continue
+
+                if self._cancel_future.done() and not self._cancel_future.cancelled():
+                    # eject cancelled
+                    self._cancel_future = None
                     return True
-                else:
-                    continue
+                self._cancel_future = None
 
-            if self._cancel_future.done() and not self._cancel_future.cancelled():
-                # eject cancelled
-                return True
-            self._cancel_future = None
+            self.ball_device.set_eject_state("waiting_for_target_ready")
 
             # inform targets about the eject (can delay the eject)
             yield from self._prepare_eject(eject_request, eject_try)
@@ -398,6 +407,9 @@ def _handle_late_confirm_or_missing(self, eject_request: OutgoingBall, ball_ejec
         eject_success_future = incoming_ball_at_target.wait_for_confirm()
         timeout = self.ball_device.config['ball_missing_timeouts'][eject_request.target] / 1000
 
+        # assume that the ball may have skipped the target device by now
+        incoming_ball_at_target.set_can_skip()
+
         # TODO: remove hack when moving code below
         yield from asyncio.sleep(0.1, loop=self.machine.clock.loop)
 

mpf/devices/ball_device/pulse_coil_ejector.py

@@ -20,8 +20,8 @@ def eject_one_ball(self, is_jammed, eject_try):
         else:
             self.ball_device.config['eject_coil'].pulse()
 
-        if self.ball_device.debug:
-            self.ball_device.log.debug("Firing eject coil. Current balls: %s.", self.ball_device.balls)
+        self.ball_device.debug_log("Firing eject coil. Current balls: %s.",
+                                   self.ball_device.balls)
 
     def eject_all_balls(self):
         """Cannot eject all balls."""

mpf/devices/ball_device/switch_counter.py

@@ -91,11 +91,15 @@ def is_jammed(self):
         return self.config['jam_switch'] and self.machine.switch_controller.is_active(
             self.config['jam_switch'].name, ms=self.config['entrance_count_delay'])
 
+    def wait_for_ready_to_receive(self):
+        """Wait until there is at least on inactive switch."""
+        # future returns when ball_count != number of switches
+        return self.wait_for_ball_count_changes(len(self.config['ball_switches']))
+
     @asyncio.coroutine
     def track_eject(self, eject_tracker: EjectTracker, already_left):
         """Return eject_process dict."""
         # count active switches
-        active_switches = []
         while True:
             waiter = self.wait_for_ball_activity()
             try: