ball didn't end in MR even though all balls drained.

[GabeKnuth]

I started it with a keystroke, so it might have been confused.
Archive 12.zip

[GabeKnuth]

I drained so many so fast that I think the drain thought an eject failed when a new ball came in. Odd thing is that ball search started when both s_drain and s_trough were closed, and that can only happen if the drain/trough combo is full...the game kept acting like there was 2 balls out there.

I changed the drain eject_timeouts to 500ms (was 1500ms). Will test again.

@jabdoa2 i added you to this hoping you could verify that is what's happening.

[GabeKnuth]

Archive 15.zip

This time two balls sat in the drain and didn't go anywhere. Ball search fired, but drain must not be in it. When I moved the ball, ball search turned off, but the mode kept running and the ball didn't end even though all balls were in the drain.

[GabeKnuth]

Here's the ball device config for the game:

ball_devices:
  bd_drain:
    tags: drain
    ball_switches: s_drain
    eject_coil: c_draineject
    eject_targets: bd_trough
    eject_timeouts: 500ms # was 1500ms. changed because fast multiball drains confused it into thinking an eject failed
    debug: true
    target_on_unexpected_ball: bd_trough
    console_log: Full
    eject_coil_retry_pulse: 140
    retries_before_increasing_pulse: 1
  bd_trough:
    tags: trough, home
    entrance_switch: s_trough_enter
    entrance_switch_full_timeout: 500ms
    eject_coil: c_Trougheject
    ball_capacity: 3
    eject_targets: bd_plunger
    eject_timeouts: 3s
    exit_count_delay: 1.5s
    console_log: Full
    debug: true

[jabdoa2]

The problem appears to be a bouncing entry switch in your trough when the third ball is released:

2017-03-27 17:14:13,444 : ball_device.bd_drain : Counted 1 balls. Active switches: ['s_drain']
2017-03-27 17:14:13,447 : ball_device.bd_drain : Wait for ball to leave device
2017-03-27 17:14:13,448 : ball_device.bd_drain : Firing eject coil. Current balls: 1.
2017-03-27 17:14:13,559 : ball_device.bd_drain : Got ball left during eject
2017-03-27 17:14:13,561 : ball_device.bd_drain : Switch 's_drain' changed too recently. Aborting count!
2017-03-27 17:14:13,563 : ball_device.bd_drain : Ball left
2017-03-27 17:14:13,563 : ball_device.bd_trough : Adding incoming ball from <ball_device.bd_drain>
2017-03-27 17:14:13,564 : ball_device.bd_drain : Wait for confirm with timeout 1.5
2017-03-27 17:14:13,677 : ball_device.bd_trough : Entrance switch hit
2017-03-27 17:14:13,682 : ball_device.bd_trough : Counting idle
2017-03-27 17:14:13,682 : ball_device.bd_trough : BCH: Found 1 new balls
2017-03-27 17:14:13,682 : ball_device.bd_trough : Received ball from <ball_device.bd_drain>
2017-03-27 17:14:13,683 : ball_device.bd_trough : Removing incoming ball from <ball_device.bd_drain>
2017-03-27 17:14:13,683 : ball_device.bd_trough : Processing new ball
2017-03-27 17:14:13,683 : EventManager : Event: ======'balldevice_bd_trough_ball_enter'====== Args={'new_balls': 1, 'device': <ball_device.bd_trough>, 'unclaimed_balls': 0}
2017-03-27 17:14:13,689 : ball_device.bd_drain : Got eject confirm
2017-03-27 17:14:13,689 : ball_device.bd_drain : Eject successful
2017-03-27 17:14:13,689 : ball_device.bd_drain : Received eject success.
2017-03-27 17:14:13,690 : EventManager : Event: ======'balldevice_bd_drain_ball_eject_success'====== Args={'balls': 1, 'target': <ball_device.bd_trough>}
2017-03-27 17:14:13,694 : ball_device.bd_drain : Exited eject mode.
2017-03-27 17:14:13,695 : ball_device.bd_drain : Waiting for eject request.
2017-03-27 17:14:13,697 : ball_device.bd_drain : Switch 's_drain' changed too recently. Aborting count!
2017-03-27 17:14:14,043 : ball_device.bd_drain : Counted 0 balls. Active switches: []
2017-03-27 17:14:14,043 : ball_device.bd_drain : Eject ended
2017-03-27 17:14:14,043 : ball_device.bd_drain : Counting idle
2017-03-27 17:14:14,046 : ball_device.bd_drain : Counted 0 balls. Active switches: []
2017-03-27 17:14:17,570 : ball_device.bd_trough : Adding eject chain
2017-03-27 17:14:17,581 : ball_device.bd_trough : Got eject request
2017-03-27 17:14:17,581 : ball_device.bd_trough : Entered eject mode.
2017-03-27 17:14:17,582 : EventManager : Event: ======'balldevice_bd_trough_ball_eject_attempt'====== Args={'source': <ball_device.bd_trough>, 'balls': 1, 'mechanical_eject': False, 'target': <ball_device.bd_plunger>, 'num_attempts': 0}
2017-03-27 17:14:17,589 : ball_device.bd_plunger : Ready to receive from <ball_device.bd_trough>. Free space 1 (Capacity: 1, Balls: 0), incoming_balls: 0
2017-03-27 17:14:17,590 : ball_device.bd_trough : Ejecting ball to <ball_device.bd_plunger>
2017-03-27 17:14:17,590 : EventManager : Event: ======'balldevice_bd_trough_ejecting_ball'====== Args={'source': <ball_device.bd_trough>, 'balls': 1, 'mechanical_eject': False, 'target': <ball_device.bd_plunger>, 'num_attempts': 0}
2017-03-27 17:14:17,593 : ball_device.bd_trough : Waiting for eject to end
2017-03-27 17:14:17,600 : ball_device.bd_trough : Wait for ball to leave device
2017-03-27 17:14:17,602 : ball_device.bd_trough : Firing eject coil. Current balls: 3.
2017-03-27 17:14:17,607 : ball_device.bd_trough : Got ball left during eject
2017-03-27 17:14:17,607 : ball_device.bd_trough : Device ejected a ball. Reducing ball count by one.
2017-03-27 17:14:17,610 : ball_device.bd_trough : Ball left
2017-03-27 17:14:17,610 : ball_device.bd_plunger : Adding incoming ball from <ball_device.bd_trough>
2017-03-27 17:14:17,611 : ball_device.bd_trough : Wait for confirm with timeout 3.0
2017-03-27 17:14:17,693 : ball_device.bd_trough : Entrance switch hit
2017-03-27 17:14:17,697 : ball_device.bd_trough : Got ball entrance during eject
2017-03-27 17:14:17,697 : ball_device.bd_trough : Received unexpected ball
2017-03-27 17:14:17,703 : ball_device.bd_drain : Counted 0 balls. Active switches: []
2017-03-27 17:14:17,705 : ball_device.bd_trough : Processing new ball
2017-03-27 17:14:17,705 : EventManager : Event: ======'balldevice_bd_trough_ball_enter'====== Args={'new_balls': 1, 'device': <ball_device.bd_trough>, 'unclaimed_balls': 1}
2017-03-27 17:14:17,710 : ball_device.bd_trough : Adding ball
2017-03-27 17:14:19,178 : ball_device.bd_drain : Counted 1 balls. Active switches: ['s_drain']
2017-03-27 17:14:19,181 : ball_device.bd_drain : Counting idle
2017-03-27 17:14:19,181 : ball_device.bd_drain : BCH: Found 1 new balls
2017-03-27 17:14:19,182 : ball_device.bd_drain : Received unexpected ball
2017-03-27 17:14:19,189 : ball_device.bd_drain : Processing new ball
2017-03-27 17:14:19,189 : EventManager : Event: ======'balldevice_bd_drain_ball_enter'====== Args={'new_balls': 1, 'device': <ball_device.bd_drain>, 'unclaimed_balls': 1}
2017-03-27 17:14:19,192 : EventManager : Event: ======'ball_drain'====== Args={'device': <ball_device.bd_drain>, 'balls': 1}
2017-03-27 17:14:19,195 : ball_device.bd_drain : Adding ball
2017-03-27 17:14:19,195 : ball_device.bd_drain : Adding eject chain
2017-03-27 17:14:19,200 : ball_device.bd_drain : Counted 1 balls. Active switches: ['s_drain']
2017-03-27 17:14:19,202 : ball_device.bd_drain : Got eject request
2017-03-27 17:14:19,202 : ball_device.bd_drain : Entered eject mode.
2017-03-27 17:14:19,203 : EventManager : Event: ======'balldevice_bd_drain_ball_eject_attempt'====== Args={'source': <ball_device.bd_drain>, 'balls': 1, 'mechanical_eject': False, 'target': <ball_device.bd_trough>, 'num_attempts': 0}
2017-03-27 17:14:19,206 : ball_device.bd_trough : Not ready to receive from <ball_device.bd_drain>. Free space -1 (Capacity: 3, Balls: 4), incoming_balls: 0

We should ignore this when the device is at capacity. I created missionpinball/mpf#844.

Maybe you can tune debounce_closed here? This should prevent this short switch hits.