Variable Achievement Lights - Figured It Out!

[Doug Spata]

I don't have a question, I just want to share that I figured out a function on my game all on my own and I'm feeling pretty proud.

My game starts with a menu mode, where the player can select from a number of objectives and play them one at a time. When each objective is complete, the machine goes into "objective complete" mode, which directs the player to lock the ball in a saucer, at which point the menu returns and they can select a different game.

There are three red inserts on my playfield and I wanted to have one go on each time an objective is completed - three completed objectives will take the player into a timed bonus round (this is sort of inspired by Bally's Spectrum). The issue is that the modes can be played in any order and eventually there will be more than three of them, so assigning a specific light to each objective won't work. Instead, I created a new mode and set up a counter. It starts when the menu (carousel) starts, counts up each time "objective complete" mode ends, and lights a successive light on the playfield. I also worked it out so the lights stay on after a ball drain.  Here's the code:

#config_version=4

mode:
    start_events: mode_carousel_starting
    stop_events: game_ending
    stop_on_ball_end: false

logic_blocks:
    counters:
        achievement1:
            count_events: mode_objective_stopping
            starting_count: 0
            count_complete_value: 1
            direction: up
            events_when_complete: achievement2_start, achievement1_stop
        achievement2:
            count_events: mode_objective_stopping
            starting_count: 0
            count_complete_value: 2
            direction: up
            events_when_complete: achievement3_start, achievement2_stop
        achievement3:
            count_events: mode_objective_stopping
            starting_count: 0
            count_complete_value: 3
            direction: up
            events_when_complete: achievement4_start, achievement3_stop

light_player:
    achievement1_start:
        l_light29: 0
        l_light28: 0
        l_light27: 0
    achievement2_start:
        l_light29: ff
        l_light28: 0
        l_light27: 0
    achievement3_start:
        l_light29: ff
        l_light28: ff
        l_light27: 0
    achievement4_start:
        l_light29: ff
        l_light28: ff
        l_light27: ff

[Doug Spata]

My game is expanding to include a longer string of game and Wizard modes, so I've had to expand my Achievements mode as well. But weird things are happening.  Before I get into too much detail, let me ask a simple question. In this setup...

logic_blocks:
    counters:
        achievement1:
            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete

            starting_count: 0
            count_complete_value: 1
            direction: up
            events_when_complete: achievement2_start, achievement1_stop

            persist_state: true
        achievement2:
            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete

            starting_count: 0
            count_complete_value: 2
            direction: up
            events_when_complete: achievement3_start, achievement2_stop

            persist_state: true
        achievement3:
            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete

            starting_count: 0
            count_complete_value: 3
            direction: up
            events_when_complete: achievement4_start, achievement3_stop

            persist_state: true

... my understanding is that the count_events: for each step will stop the current step and move on to the next step. For example, if we start in achievement 1 and dsmn_default_lit_complete posts, achievement2 starts and achievement1 stops. Then if dsmn_default_lit_complete posts again, achievement3 starts and achievement2 stops. Is this correct?

[jabdoa]

Yes that should work that way.

Jan

[Doug Spata]

Thought so. Here's my code, followed by a description of what's happening:

mode:
    start_events: ball_starting{current_player.ball==1}
    stop_events: mode_attract_starting, game_ending

    stop_on_ball_end: false

logic_blocks:
    counters:
        achievement1:

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up
            events_when_complete: achievement2_start, achievement1_stop
            persist_state: true
        achievement2:
            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 2
            direction: up
            events_when_complete: achievement3_start, achievement2_stop
            persist_state: true
        achievement3:
            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 3
            direction: up
            events_when_complete: achievement4_start, achievement3_stop
            persist_state: true

        achievement4:

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0

            count_complete_value: 4
            direction: up
            events_when_complete: achievement5_start, achievement4_stop
            persist_state: true
        achievement5:
            count_events: mode_objective_stopping
            starting_count: 0
            count_complete_value: 5
            direction: up
            events_when_complete: achievement6_start, achievement5_stop
            persist_state: true
        achievement6:

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0

            count_complete_value: 6
            direction: up
            events_when_complete: achievement7_start, achievement6_stop
            persist_state: true
        achievement7:

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0

            count_complete_value: 7
            direction: up
            events_when_complete: achievement8_start, achievement7_stop
            persist_state: true
        achievement8:

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0

            count_complete_value: 8
            direction: up
            events_when_complete: achievement9_start, achievement8_stop
            persist_state: true
        achievement9:

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0

            count_complete_value: 9
            direction: up
            events_when_complete: achievement10_start, achievement9_stop
            persist_state: true
        achievement10:
            count_events: mode_objective_stopping
            starting_count: 0
            count_complete_value: 10
            direction: up
            events_when_complete: achievement10_complete
            persist_state: true

light_player:
    achievement1_start:
        l_light29: 0
        l_light28: 0
        l_light27: 0
    achievement2_start:
        l_light29: ff
        l_light28: 0
        l_light27: 0
    achievement3_start:
        l_light29: ff
        l_light28: ff
        l_light27: 0
    achievement4_start:
        l_light29: ff
        l_light28: ff
        l_light27: ff

        l_light1: 0
    achievement5_start:
        l_light29: 0
        l_light28: ff
        l_light27: ff
        l_light1: 0
    achievement6_start:

        l_light29: 0
        l_light28: 0
        l_light27: 0

        l_light1: ff
    achievement7_start:
        l_light29: 0
        l_light28: ff
        l_light27: 0
        l_light1: ff
    achievement8_start:

        l_light29: ff
        l_light28: 0
        l_light27: 0

        l_light1: ff
    achievement9_start:

        l_light29: ff
        l_light28: ff
        l_light27: 0

        l_light1: ff
    achievement10_start:

        l_light29: ff
        l_light28: ff
        l_light27: ff

        l_light1: ff

The mode starts with the game.
Completing the first game mode moves the counter to achievement2.
Completing the 2nd game mode moves the counter to achievement3.
Completing the 3rd game mode moves the counter to achievement4.
Locking the ball (and therefore stopping Objective mode) moves the counter to achievement5, which starts Wizardintro1 mode, which leads to Wizard1 and then Wizardoutro1 mode.
Coming out of the Wizard mode sequence, we're in achievement6
Completing the 4th game mode moves the counter back to achievement5 (?)
Completing the 5th game mode keeps the counter at achievement5 (??)
Completing the 6th game mode moves the counter to achievement7 (???)
From there, subsiquent completions lead to achievement 8, 9 and 10

What is happening after Wizard mode to make it do this? I'm thinking of ending the counter when Wizardintro1 starts and starting a new counter when Wizardoutro1 completes, but if possible, I'd rather keep it simple and do it all with one mode.

[jabdoa]

Hi Doug,

I would just have all those counters only count from 0 to 1 and use a start event to start them after the previous one. Like this:

        achievement1:

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement2_start, achievement1_stop, start_achievement2
            persist_state: true
        achievement2:

            start_events: start_achievement2

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement3_start, achievement2_stop, start_achievement3
            persist_state: true

This way you can have achievement 5 start after wizard and then go on after that with your other achievements. 

You could even reduce the number of counters to use one which counts up to three for the wizard mode and then another one which continues afterwards. But I would suggest you do that in a second separate step.

Jan

[Doug Spata]

Looks like start_events: isn't a valid command in counters. And when I set this up in every step...

starting_count: 0
count_complete_value: 1

... it jumped right to achievement7 after competing the first game mode.

[Dan H.]

I'm thinking you need an enable_events: in there instead of the start_events:

[jabdoa]

Yep right. Thanks for jumping in Dan!

Jan

[Doug Spata]

Yes! That works perfectly. Thanks Jan & Dan! I was also able to copy and modify the configs and shows to create a 2nd wizard mode after the 6th game objective is complete.

Now on to other mysteries: Why don't the trough and pop bumper coils work after the first Wizard mode?

Here's the new working code:

logic_blocks:
    counters:

        achievement1:
            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up
            events_when_complete: achievement2_start, achievement1_stop, start_achievement2
            persist_state: true
        achievement2:

            enable_events: start_achievement2

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up
            events_when_complete: achievement3_start, achievement2_stop, start_achievement3
            persist_state: true

        achievement3:
            enable_events: start_achievement3

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement4_start, achievement3_stop, start_achievement4
            persist_state: true
        achievement4:
            enable_events: start_achievement4
            count_events: mode_objective_stopping
            count_complete_value: 1
            direction: up
            events_when_complete: achievement5_start, achievement4_stop, start_achievement5
            persist_state: true
        achievement5:
            enable_events: start_achievement5
            count_events: mode_carousel_starting
            count_complete_value: 1
            direction: up
            events_when_complete: achievement6_start, achievement5_stop, start_achievement6
            persist_state: true
        achievement6:
            enable_events: start_achievement6

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement7_start, achievement6_stop, start_achievement7
            persist_state: true
        achievement7:
            enable_events: start_achievement7

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement8_start, achievement7_stop, start_achievement8
            persist_state: true
        achievement8:
            enable_events: start_achievement8

            count_events: dsmn_default_lit_complete, aobtd3_shots_complete, fatbottom_complete, bicycle_complete, crazy_complete, pressure_complete, killer_complete, rockyou_complete
            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement9_start, achievement8_stop, start_achievement9
            persist_state: true
        achievement9:
            enable_events: start_achievement9
            count_events: mode_objective_stopping

            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement10_start, achievement9_stop, start_achievement10
            persist_state: true
        achievement10:
            enable_events: start_achievement10
            count_events: mode_carousel_starting

            starting_count: 0
            count_complete_value: 1
            direction: up

            events_when_complete: achievement10_complete
            persist_state: true

show_player:
    achievement2_start:
        objectivecomplete2:
            loops: 5
            speed: 2
    achievement3_start:
        objectivecomplete2:
            loops: 5
            speed: 2
    achievement4_start:
        objectivecomplete2:
            loops: 5
            speed: 2
    achievement7_start:
        objectivecomplete2:
            loops: 5
            speed: 2
    achievement8_start:
        objectivecomplete2:
            loops: 5
            speed: 2
    achievement9_start:
        objectivecomplete2:
            loops: 5
            speed: 2

sound_player:
    achievement2_start:
        modecomplete1:
            action: play
            priority: 900
    achievement3_start:
        modecomplete2:
            action: play
            priority: 900
    achievement4_start:
        modecomplete3:
            action: play
            priority: 900
    achievement7_start:
        modecomplete4:
            action: play
            priority: 900
    achievement8_start:
        modecomplete1:
            action: play
            priority: 900
    achievement9_start:
        modecomplete2:
            action: play
            priority: 900

        l_light29: ff
        l_light28: 0
        l_light27: 0
        l_light1: ff

    achievement8_start:

        l_light29: ff
        l_light28: ff
        l_light27: 0
        l_light1: ff
    achievement9_start:
        l_light29: ff
        l_light28: ff

        l_light27: ff

        l_light1: ff
    achievement10_start:
        l_light29: ff
        l_light28: ff
        l_light27: ff
        l_light1: ff

[jabdoa]

The ball drains after the wizard mode, right? I guess that would end your game or at least the current ball. This could be prevented using a ball_save for example. Not sure if I understood that right.

Jan

[Doug Spata]

During Wizardoutro mode, activating the trough switch (i.e. draining the ball) starts Carousel mode, which simultaneously causes the trough to act as a ball lock and stops Wizardoutro mode. Making a Carousel selection ends Carousel mode.

After making a selection, the ball kicks out without the drop targets re-setting (like they normally would at the start of a new ball), suggesting that neither the game nor the current ball has ended.

The pop switches and the trough switch still work - they trigger noises and light shows - but their coils don't fire. The drop targets and kickout hole work normally. I'm going to try adding some enable_events: settings to the main config file and see what happens.
 

Here's the part of the Carousel code that controls the ball locks:

ball_locks:
    kickout:
        balls_to_lock: 1
        lock_devices: bd_kickout
        enable_events: s_switch12_active
        request_new_balls_to_pf: false
        release_one_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected
        reset_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected
    trough:
        balls_to_lock: 1
        lock_devices: bd_trough
        enable_events: mode_wizardoutro1_stopping
        disable_events: mode_dsmn_starting, mode_aobtd1_starting, mode_fatbottom_starting, mode_bicycle_starting, mode_crazy_starting, mode_pressure_starting, mode_kikker_starting, mode_rockyou_starting
        request_new_balls_to_pf: false
        release_one_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected
        reset_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected

[jabdoa]

Yeah i get that. But I'm not so sure if the lock prevents the drain (and thereby game end). You could try to add a ball_save as well. That should prevent the drain and the lock will delay the eject.

Jan

[Doug Spata]

I added a ball_saver: to the wizardoutro modes that looks like this:

mode:
    start_events: mode_wizard1_complete
    stop_events: mode_carousel_starting

ball_saves:
  wizardsave1:
    active_time: 0
    enable_events: mode_wizard1_started
    disable_events: mode_wizardoutro1_stopping
    timer_start_events: mode_wizardoutro1_started
    balls_to_save: -1
    debug: yes

event_player:
    s_switch4_active: mode_wizardoutro1_complete

And now it works MOST of the time.  Nothing is consistent, but I'll try to describe what it's doing.  I can play fine up to the first wizard mode - the ball drains and re-sets as it should and the game ends on ball 3. After Wizard mode, it goes into Carousel and ejects a ball after I've made a game selection. But after that, the trough coil doesn't fire. The game keeps going, the rest of the playfield is active and the trough switch still triggers light shows and sounds, but the coil won't fire and it doesn't progress to a new ball or back to attract mode. If the ball saver were still in effect, it would kick out a ball. The trough ball lock should have been disabled and reset when a selection was made (here's the ball_lock code:)

 trough:
        balls_to_lock: 1
        lock_devices: bd_trough
        enable_events: mode_wizardoutro1_stopping

        disable_events: mode_dsmn_starting, mode_aobtd1_starting, mode_fatbottom_starting, mode_bicycle_starting, mode_crazy_starting, mode_pressure_starting, mode_killer_starting, mode_rockyou_starting, mode_somebody_starting
        request_new_balls_to_pf: false
        release_one_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected
        reset_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected

Also, some weird stuff is happening intermittently:

1. OCCASIONALLY, a mode will mysteriously double-stop or double-start, causing two iterations of the same mode to run at the same time. When a start or stop command is triggered, it causes the whole program to shut down.

2. Also occasionally, Achievements mode will start AFTER a selection has been made, causing the drop targets to re-set and causing the trough to think it needs a ball. The trough coil will than fire every few seconds until it gets a ball to kick out.

3. A have sound files attached to the final ticks in the Wizard mode timer counting down and about half the time it says FOUR... THREE... ONE... TWO... before the timer runs out. Weird in itself, but that's usually a harbinger that more weirdness is about to follow.


I thought there might be an issue with how the trough is set up in the main config but everything looks normal to me:

ball_devices:
    bd_trough:
        ball_switches: s_switch4
        entrance_count_delay: 1s
        eject_coil: c_trough
        tags: trough, home, drain, ball_add_live
        debug: yes
    bd_kickout:
        ball_switches: s_switch12
        eject_coil: c_kickout
        eject_timeouts: 1s
        tags: home

Let me know if you see anything out of place that could explain some of the weirdness.

[jabdoa]

Hi Doug,

That looks weird. Is there a way for me to run your machine? Can you give me a sequence of switches to press on the keyboard when using the virtual platform?

I think this is an interesting case and i would like to debug that case on my site.

Jan

[jabdoa]

Got another question: Why does your trough only have one switch? Is that really a one ball trough or is that maybe an entrance_switch like on older gottlieb troughs?

[Doug Spata]

It's a re-themed Williams Flash, so only one ball, one trough switch and no shooter lane switch.

I never set up a virtual platform for this game. What would I need to do?

[jabdoa]

Just run it with mpf both -X. Then add some keyboard mappings for your switches: http://docs.missionpinball.org/en/latest/examples/keyboard/index.html

Jan

[Doug Spata]

I think I got it set up - what's the best way to get the files to you?

[jabdoa]

Hi Doug,

whatever you like. A dropbox link or a git repository would work for example. You could also mail me a zip file (if it is not too large).


Jan

[Doug Spata]

Is your email address on the MPF website? I can't seem to find it.

[jabdoa]

Hi Doug,

i downloaded the machine. How do i reproduce your issue? Which switches do i have to press?

Jan

[Doug Spata]

I've found that the easiest way to test things is through "Crazy" mode, since it ends with just one switch.

1. Start a game. It should go right into Carousel mode.
2. Hit the right flipper (m) until Crazy is selected. Hit the left flipper (z) to select Crazy mode.
3. Hitting rollover #3 (3) will end Crazy mode and start Objective mode.
4. The kickout saucer (j) will end objective mode and take you back to Carousel.
5. Repeat 1 through 4 two more times. The third time objective mode stops, the game will go into Wizardintro1 mode and an audio clip will play. Then, Wizard1 mode will start. When the timer runs out, Wizard1 will end and Wizardoutro1 will start.
6. Hit the trough switch (v) to end Wizardoutro1 and start Carousel mode again.
7. Selecting a mode with the flippers (as described in step 2) will start a game mode and kick out the ball.

At this point, the trough switch (switch 4, key v) won't end a ball and won't cause the trough coil to kick the ball back into the shooter lane.

Also, listen when the Wizard timer ends and let me know if the voice countdown is out of order (which happens occasionally).

[jabdoa]

Hi Doug,

that does not seem to work for me. I can repeat step 2-5 for unlimited times. Never reaches wizard mode. Tried on latest 0.32 release. Started with "mpf both -X" (which means smart_virtual). What is going wrong here?

Minor: modes/superspinner/shows/spinner_show.yaml produced an error on load (but i fixed that).

In wizardoutro1 are you sure that your ball_save is actually started? I would try something like this (1):

ball_saves:
  wizardsave1:
    active_time: 0
    enable_events: mode_wizardoutro1_started         # this was mode_wizard1_started which will probably posted before this mode
    disable_events: mode_wizardoutro1_stopping
    balls_to_save: -1
    debug: yes

(2) I would use the ball_save_(name)_saving_ball event in the event_player to make this a bit more clean.
(3) The ball_lock in the carousel mode will not work when you start the carousel from the trough switch (or via the event above). Therefore, you got two options:
 3a) Move the ball_lock into wizardoutro1
 3b) Start the carousel in wizardoutro1


Jan



Jan

[Doug Spata]

After a night of testing, some issues are clearer and some new ones have popped up.  Here's the complete revised wizardoutro1 code:

mode:
    start_events: mode_wizard1_complete
    stop_events: mode_carousel_starting

    use_wait_queue: true

ball_saves:
  wizardsave1:
    active_time: 0
    enable_events: mode_wizardoutro1_started

    disable_events: mode_carousel_starting

    balls_to_save: -1
    debug: yes

event_player:

    ball_save_wizardsave1_saving_ball: mode_wizardoutro1_complete

ball_locks:
    trough1:
        balls_to_lock: 1
        lock_devices: bd_trough
        enable_events: mode_wizardoutro1_starting
        disable_events: mode_wizardoutro1_complete
        reset_events: mode_wizardoutro1_complete

The ball locks were moved into the wizardoutro modes and the ball_locks part of the Carousel code now looks like this:

ball_locks:
    kickout:
        balls_to_lock: 1
        lock_devices: bd_kickout
        enable_events: s_switch12_active

        request_new_balls_to_pf: false
        release_one_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected
        reset_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected

What's happening now is that Wizard1 mode ends, Wizardoutro1 begins, the ball drains, Carousel mode starts and stays on, and a ball is kicked out into the shooter lane.  I can then select a new mode and resume playing. This is all perfect, except that I want the ball to kick out only when a carousel selection has been made.

As for the trough issues, I've discovered that I can drain ball 1 at any time and ball 2 will start (drop targets re-set and the new ball kicks out). but problems arise when ball2 drains. It doesn't go to ball 3, it just sits in the trough.  Can you see anything in the code that would be causing this?

[jabdoa]

1. Can you check why the switch sequence from your previous post did not work for me?

2. I think a lock is the wrong thing on the trough because the mechanism is different. Ball drains and a new one is requested (either by the game or in your case by the ball_save). This works different in your VuK because it does not want to keep it normally. You really want to only delay the eject. I guess the simplest way would be to extend the ball_save a bit to account for this case. Alternatively you could block it with a mode or a queue_relay_player.

3. Remove the use_wait_queue from your mode. That does not make much sense here.

[Doug Spata]

1. Are you not hearing Bohemian Rhapsody at all? I just ran through it using mpf both -X and got all the way to the 3rd wizard mode. The kickout hole and trough switches are both set up with ignore_window_ms: 200 in the main config. Maybe if you hold down their respective keys for a couple of seconds?

2 & 3. In order to prevent the ball from kicking out at the very start of the game, I had set up a Blocker mode, which uses a use_wait_queue. Blocker mode ends when the 1st Carousel stops and then the ball kicks out. So what I need is another Blocker mode after Wizard1 is complete - and that can be a function of Wizardoutro1.  Here's a new wizardoutro1:

mode:
    start_events: mode_wizard1_complete
    stop_events: mode_carousel_stopping, carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected
    use_wait_queue: true

event_player:
    s_switch4_active: mode_wizardoutro1_complete

No ball saves, no ball locks. Now, Wizard1 ends, Wizardoutro1 starts, Carousel starts when the ball hits the trough switch, and the ball is held. I can select and start a game mode from Carousel. Wizardoutro1 and Carousel both end together when a selection is made... but the ball doesn't kick out. So I went into the main config file to the ball_devices section and added eject_events: mode_wizardoutro1_stopping, mode_wizardoutro2_stopping to the bd_trough.

So far, it's working pretty consistently, but the ball ending/trough issues remain and I suspect that the culprit is the ball saver in the Wizard modes.  If they're not ending when the Wizard modes stop, they could be messing everything up.  I've tried revising the stop events, but it's not working. Is there something different I should use?

ball_saves:
    wizard1save:
        disable_events: timer_wizard1_timer_tick{ticks==2}, game_ending, ball_ending, mode_wizardoutro1_starting, mode_wizard1_stopping
        enable_events: ball_starting, mode_wizard1_starting, timer_wizard1_timer_starting
        balls_to_save: -1
        active_time: 0

[Doug Spata]

Correction: the Wizard1 ball saver should look like this:

ball_saves:
    wizard1save:
        disable_events: timer_wizard1_timer_tick{ticks==2}, game_ending, ball_ending

        enable_events: ball_starting, mode_wizard1_starting, timer_wizard1_timer_starting
        balls_to_save: -1
        active_time: 0

Adding mode_carousel_stopping and mode_wizardoutro1_stopping as disable events messes everything up - it looks like this ball saver is continuing on after Wizard1 mode has ended which is a) preventing Carousel mode from stopping immediately after it re-starts b) preventing the ball from kicking out before a selection is made and c) preventing any future drains from registering.

[Doug Spata]

Still playing around a bit with the trough switch.  I've discovered that I can drain ball 1 at any time - including after the 1st Wizard mode - and Ball 2 will start (drops re-set and a ball kicks out). But trying to drain ball 2 results in this error message:

INFO : SwitchController : <<<<< switch: s_switch4, State:1 >>>>>
INFO : Machine : Shutting down...
INFO : Machine : Shutting down...
ERROR : asyncio : Exception in callback SwitchController._process_active_timed_switches(None)()
handle: <TimerHandle when=13132.488713553 SwitchController._process_active_timed_switches(None)()>
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/events.py", line 125, in _run
    self._callback(*self._args)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/switch_controller.py", line 710, in _process_active_timed_switches
    self.machine.events.process_event_queue()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 575, in process_event_queue
    **event[3])
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 543, in _process_event
    result = self._run_handlers(event, ev_type, kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 500, in _run_handlers
    result = handler.callback(**merged_kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/devices/ball_lock.py", line 125, in _wait_for_drain
    self._release_lock.clear()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 612, in clear
    raise AssertionError("Not locked")
AssertionError: Not locked
Shutdown because of an exception:
ERROR : root : Not locked
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/commands/game.py", line 139, in __init__
    MachineController(mpf_path, machine_path, vars(args)).run()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/machine.py", line 574, in run
    self._run_loop()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/machine.py", line 615, in _run_loop
    raise self._exception['exception']
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/events.py", line 125, in _run
    self._callback(*self._args)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/switch_controller.py", line 710, in _process_active_timed_switches
    self.machine.events.process_event_queue()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 575, in process_event_queue
    **event[3])
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 543, in _process_event
    result = self._run_handlers(event, ev_type, kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 500, in _run_handlers
    result = handler.callback(**merged_kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/devices/ball_lock.py", line 125, in _wait_for_drain
    self._release_lock.clear()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 612, in clear
    raise AssertionError("Not locked")
AssertionError: Not locked
INFO : mpfmc : Stopping...
INFO : MPF-MC BCP Server : Stopping BCP sending thread
INFO : mpfmc : Loop rate 33.22 Hz
INFO : kivy : Base: Leaving application in progress...
INFO : mpfmc : Stopping...
INFO : mpfmc : Loop rate 33.22 Hz
INFO : kivy : MC run loop ended.
INFO : kivy : Stopping child threads... (1 remaining)
INFO : kivy : All child threads stopped.

What, in simple terms, is this telling us?

[jabdoa]

Hi Doug,

that is a bug which is actually fixed in dev. However, as I told you earlier, a ball_lock will not work on the trough.

What I did is to extend the ball_save to allow unlimited delays which is what you need: https://github.com/missionpinball/mpf/pull/863/. See an example here: https://github.com/missionpinball/mpf/pull/863/files#diff-e82c6c6c90697a8e0454a42ec4de0e95R72

That will be in dev soon (or in 0.33 when it is released). In 0.32, can use queue_relay_player to block the eject (http://docs.missionpinball.org/en/latest/config/queue_relay_player.html). This would look like this:

queue_relay_player:
   bd_trough_ejecting:
      post: start_carousel
      wait_for: carousel_xxx_selected

Alternatively, you can use dev with the ball_save. That would probably be the easiest way.

Jan

[Doug Spata]

Thanks, Jan

Please see my posts above - I've worked out all the issues with the ball kicking out.  The only problem left is that draining ball 2 shuts down the program.
In this case, I've progressed through Wizard1, started a new game mode and drained the ball. Ball 2 started as it should. I completed the game mode, selected another game mode through Carousel, drained ball 2 and the program shuts down with this error message:

INFO : SwitchController : <<<<< switch: s_switch4, State:1 >>>>>
INFO : Machine : Shutting down...
INFO : Machine : Shutting down...
ERROR : asyncio : Exception in callback SwitchController._process_active_timed_switches(None)()

handle: <TimerHandle when=1814.002346403 SwitchController._process_active_timed_switches(None)()>

INFO : mpfmc : Loop rate 33.27 Hz

INFO : kivy : Base: Leaving application in progress...
INFO : mpfmc : Stopping...

INFO : mpfmc : Loop rate 33.27 Hz

INFO : kivy : MC run loop ended.
INFO : kivy : Stopping child threads... (1 remaining)

INFO : MPF-MC BCP Server : Stopping BCP sending thread

INFO : kivy : All child threads stopped.

I don't know what this means. Does "Exception in callback SwitchController._process_active_timed_switches(None)()" mean that a timer is still going and causing an error?

[jabdoa]

Hi Doug,

As i wrote in the last post. That is a bug which is fixed in 0.33. However, i still see no way that this will work reliably with a ball_lock.

Jan

[jabdoa]

Hi Doug,

you can give 0.33 a try. Everything should work there. You can use a ball_save like this: https://github.com/missionpinball/mpf/blob/dev/mpf/tests/machine_files/ball_save/config/config.yaml#L72. That should solve your problems.

Jan

[Doug Spata]

I've upgraded to .33, but can't run a game. Looks like the new MPF doesn't support Carousel mode? Or it doesn't recognize my ball trough? What does this say?

Dougs-iMac:queen dougspata$ mpf both
Machine : Mission Pinball Framework Core Engine v0.33.2
Machine : Command line arguments: {'create_config_cache': True, 'mc_file_name': None, 'pause': False, 'configfile': ['config'], 'bcp': True, 'no_load_cache': False, 'mpfconfigfile': '/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/mpfconfig.yaml', 'loglevel': 11, 'force_assets_load': False, 'consoleloglevel': 20, 'force_platform': None, 'logfile': 'logs/2017-04-15-00-18-58-mpf-Dougs-iMac.local.log'}
Machine : MPF path: /Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf
Machine : Machine path: /Users/dougspata/Desktop/pinball/queen
Machine : Platform: darwin
Machine : Python executable location: /Library/Frameworks/Python.framework/Versions/3.5/bin/python3.5
Machine : Python version: 3.5.2 (64-bit)
Machine : Loading cached config: /var/folders/_x/chccz0d51tqgm2zhcfyq4jgw0000gn/T/6463df955ee5f11b10ece29f52159459config
Flushing Read Buffer: 0 bytes trashed
FPGA Chip ID: 0xfeedbeef
FPGA Chip Version/Rev: 1.22
P-ROC : Connecting to P-ROC
P-ROC : Successfully connected to P-ROC/P3-ROC. Revision: 22. Version: 1
SwitchController : Loading the SwitchController
EventManager : Event: ======'machine_var_player1_score'====== Args={'prev_value': 3000, 'change': 0, 'value': 3000}
EventManager : Event: ======'machine_var_mpf_version'====== Args={'prev_value': 'MPF v0.33.2', 'change': False, 'value': 'MPF v0.33.2'}
EventManager : Event: ======'machine_var_mpf_extended_version'====== Args={'prev_value': 'MPF v0.33.2, Config version:4, Show version: 4, BCP version:1.1', 'change': False, 'value': 'MPF v0.33.2, Config version:4, Show version: 4, BCP version:1.1'}
EventManager : Event: ======'machine_var_python_version'====== Args={'prev_value': '3.5.2', 'change': False, 'value': '3.5.2'}
EventManager : Event: ======'machine_var_platform'====== Args={'prev_value': 'Darwin-16.0.0-x86_64-i386-64bit', 'change': False, 'value': 'Darwin-16.0.0-x86_64-i386-64bit'}
EventManager : Event: ======'machine_var_platform_system'====== Args={'prev_value': 'Darwin', 'change': False, 'value': 'Darwin'}
EventManager : Event: ======'machine_var_platform_release'====== Args={'prev_value': '16.0.0', 'change': False, 'value': '16.0.0'}
EventManager : Event: ======'machine_var_platform_version'====== Args={'prev_value': 'Darwin Kernel Version 16.0.0: Mon Aug 29 17:56:20 PDT 2016; root:xnu-3789.1.32~3/RELEASE_X86_64', 'change': False, 'value': 'Darwin Kernel Version 16.0.0: Mon Aug 29 17:56:20 PDT 2016; root:xnu-3789.1.32~3/RELEASE_X86_64'}
EventManager : Event: ======'machine_var_platform_machine'====== Args={'prev_value': 'x86_64', 'change': False, 'value': 'x86_64'}
EventManager : Event: ======'init_phase_1'====== Args={}
ball_device.bd_trough : Platform Driver: None
ball_device.bd_trough : Configuring device with settings: '{'mechanical_eject': False, 'ball_capacity': None, 'jam_switch': None, 'confirm_eject_event': None, 'ball_search_order': 200, 'retries_before_increasing_pulse': 4, 'hold_coil': None, 'entrance_count_delay': 1000, 'confirm_eject_type': 'target', 'console_log': 'full', 'captures_from': <playfield.playfield>, 'ball_switches': [<switch.s_switch4>], 'file_log': 'full', 'hold_coil_release_time': 1000, 'eject_timeouts': [], 'exit_count_delay': 500, 'target_on_unexpected_ball': None, 'auto_fire_on_unexpected_ball': True, 'tags': ['trough', 'home', 'drain', 'ball_add_live'], 'eject_coil_retry_pulse': None, 'entrance_switch_full_timeout': 0, 'eject_coil_jam_pulse': None, 'entrance_switch': None, 'ball_missing_target': <playfield.playfield>, 'eject_targets': [<playfield.playfield>], 'max_eject_attempts': 0, 'entrance_events': {}, 'hold_switches': [], 'hold_events': {}, 'debug': True, 'ball_missing_timeouts': [], 'eject_events': {}, 'confirm_eject_switch': None, 'request_ball_events': [], 'eject_coil': <coil.c_trough>, 'eject_all_events': {}, 'label': '%', 'player_controlled_eject_event': None}'
EventManager : Event: ======'drop_target_bank_five_drop_reset_lower_up'====== Args={}
EventManager : Event: ======'drop_target_bank_five_drop_reset_upper_up'====== Args={}
EventManager : Event: ======'drop_target_bank_three_drop_reset_up'====== Args={}
EventManager : Event: ======'init_phase_2'====== Args={}
kivy: Factory: 179 symbols loaded
kivy: Image: Providers: img_tex, img_imageio, img_dds, img_gif, img_sdl2 (img_pil, img_ffpyplayer ignored)
kivy: VideoGstplayer: Using Gstreamer 1.10.2.0
kivy: Video: Provider: gstplayer
kivy: Loading MPF-MC controller
mpfmc: Mission Pinball Framework Media Controller v0.33.0
mpfmc: Mission Pinball Framework Game Engine v0.33.2
mpfmc: Machine path: /Users/dougspata/Desktop/pinball/queen
mpfmc: Starting clock at 30.0Hz
kivy: Text: Provider: sdl2
kivy: OSC: using <multiprocessing> for socket
kivy: Window: Provider: sdl2
Machine : Shutting down...
EventManager : Event: ======'shutdown'====== Args={}
ball_device.bd_trough : Stopping ball device
kivy: GL: OpenGL version <b'2.1 ATI-1.44.68'>
kivy: GL: OpenGL vendor <b'ATI Technologies Inc.'>
kivy: GL: OpenGL renderer <b'ATI Radeon HD 6750M OpenGL Engine'>
kivy: GL: OpenGL parsed version: 2, 1
kivy: GL: Shading version <b'1.20'>
kivy: GL: Texture max size <16384>
kivy: GL: Texture max units <16>
asyncio : Exception in callback EventManager._done(<Task finishe...l.Carousel',)>)
handle: <Handle EventManager._done(<Task finishe...l.Carousel',)>)>

Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/events.py", line 125, in _run
    self._callback(*self._args)

  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 572, in _done
    future.result()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/events.py", line 507, in _run_handlers_sequential
    handler.callback(queue=queue, **merged_kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/mode_controller.py", line 91, in _load_modes
    self.machine.modes[mode] = self._load_mode(mode.lower())
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/mode_controller.py", line 232, in _load_mode
    mode_class = self._load_mode_code(mode_string, config['mode']['code'])
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/mode_controller.py", line 207, in _load_mode_code
    raise AssertionError("Could not load code for mode {} from {}".format(mode_string, code_path))
AssertionError: Could not load code for mode carousel from carousel.Carousel
root : Event loop stopped before Future completed.

Traceback (most recent call last):

  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/commands/game.py", line 165, in __init__
    MachineController(mpf_path, machine_path, vars(args)).run()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/mpf/core/machine.py", line 134, in __init__
    self.clock.loop.run_until_complete(self._run_init_phases())
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 385, in run_until_complete
    raise RuntimeError('Event loop stopped before Future completed.')
RuntimeError: Event loop stopped before Future completed.
kivy: Window: auto add sdl2 input provider
kivy: Window: virtual keyboard not allowed, single mode, not docked
AudioInterface: Initialized 0.33.0-dev.03
kivy: Base: Start application main loop
MPF-MC BCP Server: Starting up on localhost port 5050
MPF-MC BCP Server: Waiting for a connection...

[jabdoa]

Hi Doug,

We changed the "code:" entry. http://docs.missionpinball.org/en/latest/examples/carousel/index.html#id2. Jusz change that and you should be fine. If not just push your code into dropbox and i will have a look.

Jan

[Doug Spata]

Got it! The game is running again.

Now I just need help working out some of the logic behind the ball saves.  Here's what I have in Wizard1 mode:

mode:
    start_events: mode_wizardintro1_complete
    stop_events: mode_wizardoutro1_complete
    priority: 500

ball_saves:
    unlimited_delay:
        enable_events: mode_wizard1_starting
        delayed_eject_events: mode_wizardoutro1_complete

And this is in Wizardoutro1 mode:

mode:
    start_events: mode_wizard1_complete
    stop_events: mode_carousel_stopping, carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected
    use_wait_queue: true

ball_saves:
    unlimited_delay2:
        enable_events: mode_wizardoutro1_starting
        delayed_eject_events: carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected


So here's the sequence of events:

1. Wizard1 starts and ball saver unlimited_delay: is activated.

2. Wizard1 timer ends, which posts mode_wizard1_complete. This starts Wizardoutro1 mode and starts the ball save unlimited_delay2.

3. The ball hits the trough switch, which posts mode_wizardoutro1_complete. This stops Wizard1 mode and the  unlimited_delay: ball saver. It also starts Carousel mode. Wizardoutro1 mode and unlimited_delay2 ball saver are still running.

4. Player can now select a new game mode in Carousel. Starting a new game mode stops Carousel, stops Wizardoutro1 and (in theory)  it stops ball saver unlimited_delay2.

5. mode_wizardoutro1_stopping triggers an eject_event in the main config, which fires the ball into the shooter lane.

All is going well up to this point, but once I shoot the ball and any switch is hit (thus activating the playfield), drop targets re-set, indicating that a new ball has started.  Is there a start/stop sequence I can adjust to keep the ball count from advancing?

[jabdoa]

Hi Doug,

two ball saves for one drain will not work. This should be much simpler. Let us pretend you are starting the "wizardoutro" mode when the wizard timer completed. Then something like this should work:

mode:
    start_events: mode_wizardintro1_complete # this should happen on wizard end
    stop_events: carousel_dontstopmenow_

selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected    # same as below or maybe on carousel end

    priority: 500

ball_saves:
    unlimited_delay:
        enable_events: mode_wizardoutro_started
        delayed_eject_events: carousel_dontstopmenow_

selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected

Jan

[Doug Spata]

Nope.

I'm getting the exact same result when I take out the Wizard1 ball saver. After Wizardoutro1 mode is done, the ball drains, Carousel starts, I can select a new game mode, the ball kicks out and as soon as I hit any switch (activating the playfield) the drop targets re-set and the ball count advances. When I drain the ball during play, it just sits there. No advancing, no kicking out.

I've removed the eject event from the main config and Wizardoutro1 mode now looks like this:

mode:
    start_events: mode_wizard1_complete
    stop_events: mode_carousel_stopping, carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected
    priority: 500

ball_saves:
    unlimited_delay:
        enable_events: mode_wizardoutro1_started
        delayed_eject_events: mode_wizardoutro1_stopping, mode_wizardoutro1_stopped, mode_carousel_stopping, carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected

event_player:
    s_switch4_active: mode_wizardoutro1_complete

You can see that I threw every possible event into the delayed_eject_events: string in hopes that one of them would get it to work. If I take out the first three (mode_wizardoutro1_stopping, mode_wizardoutro1_stopped, mode_carousel_stopping) it works much better, but not perfectly. The ball drains after Wizardoutro1, Carousel starts, I select a new game mode, the ball kicks out and I can shoot it without the ball count advancing. But now when I drain, the ball just sits there and doesn't kick out.

Could the ball saver still be going somehow, waiting for another mode to start before kicking out the ball?

[jabdoa]

Is mode_wizardoutro1_started posted after this mode started? Is the mode started before the ball drains? Please check the event order with the monitor. If you advance to the next ball the ball_save is not enabled. A log may be useful. I'm not seeing that we get this fixed this way. Try a minimal example.

Jan

[Doug Spata]

I copied the readout from the monitor during the end of Wizard mode. The sequence of events we're seeing is:

1. The Wizard timer stops
2. Wizardoutro1 starts
3. ball_save_unlimited_delay is enabled
4. The trough switch (switch 4) is activated.
5. Then a weird Switch Event happens, which I've emboldened.
6. Carousel starts
7. The Wizard countdown timer stops
8. Wizard1 stops.
9. The trough registers one new ball,
10. unlimited_delay saves the ball and then seems to immediately disable (also emboldened).
11. After that, I scroll through Carousel and select Crazy mode.
12. Carousel stops and Wizardoutro1 stops.
13. The ball then ejects with some difficulty - see the four emboldened SwitchController entries.

What do those bold SwitchEvent entries mean? Why do you think the ball saver ends immediately instead of staying on until the ball is ejected?


EventManager : Event: ======'timer_wizard1_timer_tick'====== Args={'ticks_remaining': 1, 'ticks': 2}
EventManager : Event: ======'mode_wizard1_complete'====== Args={'priority': 0}
Timer.wizard1_timer : Stopping Timer
EventManager : Event: ======'timer_wizard1_timer_stopped'====== Args={'ticks_remaining': 1, 'ticks': 2}
EventManager : Event: ======'mode_wizardoutro1_starting'====== Args={}
Mode.wizardoutro1 : Started. Priority: 500
EventManager : Event: ======'mode_wizardoutro1_started'====== Args={}
EventManager : Event: ======'ball_save_unlimited_delay_enabled'====== Args={}
SwitchController : <<<<<<< 's_switch4' active >>>>>>>

SwitchController : Found timed switch handler for k/v 392.102532982 / {'switch_action': 's_switch4-1', 'ms': 1000, 'state': 1, 'callback_kwargs': {}, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x1046c3278>>, 'return_info': False, 'switch_name': 's_switch4', 'removed': False}
EventManager : Event: ======'s_switch4_active'====== Args={}

EventManager : Event: ======'mode_wizardoutro1_complete'====== Args={'priority': 0}
EventManager : Event: ======'mode_carousel_starting'====== Args={}
Timer.wizard1_timer : Stopping Timer
EventManager : Event: ======'timer_wizard1_timer_stopped'====== Args={'ticks_remaining': 1, 'ticks': 2}
EventManager : Event: ======'mode_wizard1_stopping'====== Args={}
Mode.carousel : Started. Priority: 999
EventManager : Event: ======'mode_carousel_started'====== Args={}
Mode.wizard1 : Stopped.
EventManager : Event: ======'mode_wizard1_stopped'====== Args={}

EventManager : Event: ======'clear'====== Args={'key': 'wizard1'}
EventManager : Event: ======'carousel_dontstopmenow_highlighted'====== Args={}
SwitchController : Processing timed switch handler. Switch: s_switch4  State: 1, ms: 1000

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Counting idle
ball_device.bd_trough : BCH: Found 1 new balls
ball_device.bd_trough : Received unexpected ball
EventManager : Event: ======'balldevice_captured_from_playfield'====== Args={'balls': 1}
EventManager : Event: ======'sw_playfield_active'====== Args={'balls': 1}
EventManager : Event: ======'playfield_ball_count_change'====== Args={'balls': 0, 'change': -1}
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Processing new ball
EventManager : Event: ======'balldevice_bd_trough_ball_enter'====== Args={'device': <ball_device.bd_trough>, 'unclaimed_balls': 1, 'new_balls': 1}
EventManager : Event: ======'ball_drain'====== Args={'device': <ball_device.bd_trough>, 'balls': 1}
EventManager : Event: ======'ball_save_unlimited_delay_saving_ball'====== Args={'balls': 1, 'early_save': False}
EventManager : Event: ======'ball_save_unlimited_delay_disabled'====== Args={}
ball_device.bd_trough : Adding ball
EventManager : Event: ======'balldevice_balls_available'====== Args={}
EventManager : Event: ======'balldevice_bd_trough_ball_entered'====== Args={'device': <ball_device.bd_trough>, 'new_balls': 1}
SwitchController : <<<<<<< 's_right_flipper' active >>>>>>>

EventManager : Event: ======'s_right_flipper_active'====== Args={}
EventManager : Event: ======'carousel_aobtd1_highlighted'====== Args={}
SwitchController : <<<<<<< 's_right_flipper' inactive >>>>>>>
EventManager : Event: ======'s_right_flipper_inactive'====== Args={}
SwitchController : <<<<<<< 's_right_flipper' active >>>>>>>
EventManager : Event: ======'s_right_flipper_active'====== Args={}
EventManager : Event: ======'carousel_fatbottom_highlighted'====== Args={}
SwitchController : <<<<<<< 's_right_flipper' inactive >>>>>>>
EventManager : Event: ======'s_right_flipper_inactive'====== Args={}
SwitchController : <<<<<<< 's_right_flipper' active >>>>>>>
EventManager : Event: ======'s_right_flipper_active'====== Args={}
EventManager : Event: ======'carousel_bicycle_highlighted'====== Args={}
SwitchController : <<<<<<< 's_right_flipper' inactive >>>>>>>
EventManager : Event: ======'s_right_flipper_inactive'====== Args={}
SwitchController : <<<<<<< 's_right_flipper' active >>>>>>>
EventManager : Event: ======'s_right_flipper_active'====== Args={}
EventManager : Event: ======'carousel_crazy_highlighted'====== Args={}
SwitchController : <<<<<<< 's_right_flipper' inactive >>>>>>>
EventManager : Event: ======'s_right_flipper_inactive'====== Args={}
SwitchController : <<<<<<< 's_left_flipper' active >>>>>>>
EventManager : Event: ======'s_left_flipper_active'====== Args={}

EventManager : Event: ======'carousel_crazy_selected'====== Args={}
EventManager : Event: ======'carousel_item_selected'====== Args={}
EventManager : Event: ======'mode_carousel_stopping'====== Args={}
ball_device.bd_trough : Adding 1 ball(s) to the eject_queue with target <playfield.playfield>.
ball_device.bd_trough : Adding eject chain
EventManager : Event: ======'balldevice_balls_available'====== Args={}
EventManager : Event: ======'mode_wizardoutro1_stopping'====== Args={}
SwitchController : Registering switch handler: s_switch39, <bound method Shot.hit of <shot.crazy4>>, state: 1, ms: 0, info: False, cb_kwargs: {}
SwitchController : Registering switch handler: s_switch1, <bound method Shot.hit of <shot.crazy6>>, state: 1, ms: 0, info: False, cb_kwargs: {}
SwitchController : Registering switch handler: s_switch37, <bound method Shot.hit of <shot.crazy2>>, state: 1, ms: 0, info: False, cb_kwargs: {}
SwitchController : Registering switch handler: s_switch8, <bound method Shot.hit of <shot.crazy9>>, state: 1, ms: 0, info: False, cb_kwargs: {}
SwitchController : Registering switch handler: s_switch2, <bound method Shot.hit of <shot.crazy7>>, state: 1, ms: 0, info: False, cb_kwargs: {}
SwitchController : Registering switch handler: s_switch7, <bound method Shot.hit of <shot.crazy8>>, state: 1, ms: 0, info: False, cb_kwargs: {}
SwitchController : Registering switch handler: s_switch36, <bound method Shot.hit of <shot.crazy1>>, state: 1, ms: 0, info: False, cb_kwargs: {}
SwitchController : Registering switch handler: s_switch38, <bound method Shot.hit of <shot.crazy3>>, state: 1, ms: 0, info: False, cb_kwargs: {}
EventManager : Event: ======'mode_crazy_starting'====== Args={}
Mode.crazy : Started. Priority: 260
EventManager : Event: ======'mode_crazy_started'====== Args={}
Mode.wizardoutro1 : Stopped.
EventManager : Event: ======'mode_wizardoutro1_stopped'====== Args={}
EventManager : Event: ======'clear'====== Args={'key': 'wizardoutro1'}
Mode.carousel : Stopped.
EventManager : Event: ======'mode_carousel_stopped'====== Args={}
EventManager : Event: ======'clear'====== Args={'key': 'carousel'}

ball_device.bd_trough : Got eject request
EventManager : Event: ======'balldevice_bd_trough_ball_eject_attempt'====== Args={'balls': 1, 'target': <playfield.playfield>, 'num_attempts': 0, 'mechanical_eject': False, 'source': <ball_device.bd_trough>}
ball_device.bd_trough : Ejecting ball to <playfield.playfield>
EventManager : Event: ======'balldevice_bd_trough_ejecting_ball'====== Args={'balls': 1, 'target': <playfield.playfield>, 'num_attempts': 0, 'mechanical_eject': False, 'source': <ball_device.bd_trough>}
ball_device.bd_trough : Entered eject mode.
SwitchController : Registering switch handler: s_switch4, functools.partial(<function SwitchController._wait_handler at 0x103accd90>, switch_name='s_switch4', ms=0, _future=<Future pending cb=[SwitchController._future_done([])()]>), state: 0, ms: 0, info: False, cb_kwargs: {}
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Waiting for eject to end
ball_device.bd_trough : Wait for ball to leave device
ball_device.bd_trough : Firing eject coil. Current balls: 1.
SwitchController : <<<<<<< 's_switch4' inactive >>>>>>>

SwitchController : Found timed switch handler for k/v 402.260405349 / {'switch_action': 's_switch4-0', 'ms': 500, 'state': 0, 'callback_kwargs': {}, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x1046c3278>>, 'return_info': False, 'switch_name': 's_switch4', 'removed': False}

EventManager : Event: ======'s_switch4_inactive'====== Args={}
SwitchController : Removing switch handler. Switch: s_switch4, State: 0, ms: 0
SwitchController : <<<<<<< 's_switch4' active >>>>>>>

SwitchController : Found timed switch handler for k/v 402.766169429 / {'switch_action': 's_switch4-1', 'ms': 1000, 'state': 1, 'callback_kwargs': {}, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x1046c3278>>, 'return_info': False, 'switch_name': 's_switch4', 'removed': False}

EventManager : Event: ======'s_switch4_active'====== Args={}
ball_device.bd_trough : Got ball left during eject
ball_device.bd_trough : Switch 's_switch4' changed too recently. Aborting count!
ball_device.bd_trough : Ball left
ball_device.bd_trough : Wait for confirm with timeout 10.0
SwitchController : <<<<<<< 's_switch4' inactive >>>>>>>

SwitchController : Found timed switch handler for k/v 402.288851816 / {'switch_action': 's_switch4-0', 'ms': 500, 'state': 0, 'callback_kwargs': {}, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x1046c3278>>, 'return_info': False, 'switch_name': 's_switch4', 'removed': False}

EventManager : Event: ======'s_switch4_inactive'====== Args={}
SwitchController : <<<<<<< 's_left_flipper' inactive >>>>>>>
EventManager : Event: ======'s_left_flipper_inactive'====== Args={}
SwitchController : Processing switch. Name: s_switch4, state: 1, logical: False,
SwitchController : <<<<<<< 's_switch4' active >>>>>>>

SwitchController : Found timed switch handler for k/v 402.970340082 / {'switch_action': 's_switch4-1', 'ms': 1000, 'state': 1, 'callback_kwargs': {}, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x1046c3278>>, 'return_info': False, 'switch_name': 's_switch4', 'removed': False}

EventManager : Event: ======'s_switch4_active'====== Args={}
SwitchController : Processing timed switch handler. Switch: s_switch4  State: 1, ms: 1000
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Got 1 unknown ball during eject
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
SwitchController : <<<<<<< 's_switch38' active >>>>>>>
EventManager : Event: ======'crazy3_hit'====== Args={'profile': 'crazy_profile1', 'state': 'lit'}
EventManager : Event: ======'crazy3_crazy_profile1_hit'====== Args={'profile': 'crazy_profile1', 'state': 'lit'}
EventManager : Event: ======'crazy3_crazy_profile1_lit_hit'====== Args={'profile': 'crazy_profile1', 'state': 'lit'}
EventManager : Event: ======'crazy3_lit_hit'====== Args={'profile': 'crazy_profile1', 'state': 'lit'}
EventManager : Event: ======'s_switch38_active'====== Args={}
EventManager : Event: ======'sw_playfield_active'====== Args={}
EventManager : Event: ======'sw_playfield_active_active'====== Args={}
EventManager : Event: ======'crazy_complete'====== Args={'priority': 0}
EventManager : Event: ======'playfield_active'====== Args={}
EventManager : Event: ======'mode_objective_starting'====== Args={}
EventManager : Event: ======'mode_crazy_stopping'====== Args={}

[jabdoa]

Hi Doug,

the ball_save looks good to me from the log. By default it only saves one ball. You can change set with the "balls_to_save" setting (set it to -1 for unlimited). You can also set "only_last_ball" if you want to save only the last ball.

The eject is scheduled correctly here. Don't worry about the timed switch handlers. They are used by the ball device to wait until the switches are stable. Dunno why the ball does not make it out of the trough. Do you have a launcher switch? Otherwise, it will just wait for 10s (default eject_timeout) until it considers the ball as confirmed and ejected. However, in this case it looks like the ball returned. Hard to tell from the log.


Jan

[Doug Spata]

Good to see the log shows everything normal! The problem now is that after the whole Wizard sequence is complete and the ball kicks out, the trough still thinks it should be holding a ball and it fires every few seconds while the ball is in play. Is it possible that if the playfield isn't activated quickly enough after the ball ejects, the trough thinks something went wrong and tries to re-eject the ball?

Here's the log, starting after the Wizard sequence has ended and "Crazy" mode has started (I emboldened some suspicious-looking lines):

EventManager : Event: ======'mode_crazy_starting'====== Args={}
Mode.crazy : Started. Priority: 260
EventManager : Event: ======'mode_crazy_started'====== Args={}

EventManager : Event: ======'mode_wizardoutro1_stopping'====== Args={}

Mode.carousel : Stopped.
EventManager : Event: ======'mode_carousel_stopped'====== Args={}
EventManager : Event: ======'clear'====== Args={'key': 'carousel'}

ball_device.bd_trough : Adding 1 ball(s) to the eject_queue with target <playfield.playfield>.
ball_device.bd_trough : Adding eject chain
EventManager : Event: ======'balldevice_balls_available'====== Args={}

Mode.wizardoutro1 : Stopped.
EventManager : Event: ======'mode_wizardoutro1_stopped'====== Args={}
EventManager : Event: ======'clear'====== Args={'key': 'wizardoutro1'}

ball_device.bd_trough : Got eject request
EventManager : Event: ======'balldevice_bd_trough_ball_eject_attempt'====== Args={'source': <ball_device.bd_trough>, 'mechanical_eject': False, 'num_attempts': 0, 'balls': 1, 'target': <playfield.playfield>}

ball_device.bd_trough : Ejecting ball to <playfield.playfield>

EventManager : Event: ======'balldevice_bd_trough_ejecting_ball'====== Args={'source': <ball_device.bd_trough>, 'mechanical_eject': False, 'num_attempts': 0, 'balls': 1, 'target': <playfield.playfield>}
ball_device.bd_trough : Entered eject mode.
SwitchController : Registering switch handler: s_switch4, functools.partial(<function SwitchController._wait_handler at 0x10428dea0>, switch_name='s_switch4', _future=<Future pending cb=[SwitchController._future_done([])()]>, ms=0), state: 0, ms: 0, info: False, cb_kwargs: {}

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Waiting for eject to end
ball_device.bd_trough : Wait for ball to leave device
ball_device.bd_trough : Firing eject coil. Current balls: 1.
SwitchController : <<<<<<< 's_switch4' inactive >>>>>>>

SwitchController : Found timed switch handler for k/v 11081.263499733 / {'callback_kwargs': {}, 'return_info': False, 'removed': False, 'state': 0, 'switch_name': 's_switch4', 'ms': 500, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x10469da58>>, 'switch_action': 's_switch4-0'}

EventManager : Event: ======'s_switch4_inactive'====== Args={}
SwitchController : Removing switch handler. Switch: s_switch4, State: 0, ms: 0

SwitchController : <<<<<<< 's_switch4' active >>>>>>>

SwitchController : Found timed switch handler for k/v 11081.769048488 / {'callback_kwargs': {}, 'return_info': False, 'removed': False, 'state': 1, 'switch_name': 's_switch4', 'ms': 1000, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x10469da58>>, 'switch_action': 's_switch4-1'}

EventManager : Event: ======'s_switch4_active'====== Args={}
ball_device.bd_trough : Got ball left during eject
ball_device.bd_trough : Switch 's_switch4' changed too recently. Aborting count!
ball_device.bd_trough : Ball left
ball_device.bd_trough : Wait for confirm with timeout 10.0

SwitchController : <<<<<<< 's_left_flipper' inactive >>>>>>>
EventManager : Event: ======'s_left_flipper_inactive'====== Args={}

SwitchController : <<<<<<< 's_switch4' inactive >>>>>>>
SwitchController : Found timed switch handler for k/v 11081.297023608 / {'callback_kwargs': {}, 'return_info': False, 'removed': False, 'state': 0, 'switch_name': 's_switch4', 'ms': 500, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x10469da58>>, 'switch_action': 's_switch4-0'}

EventManager : Event: ======'s_switch4_inactive'====== Args={}

SwitchController : Processing switch. Name: s_switch4, state: 1, logical: False,
SwitchController : <<<<<<< 's_switch4' active >>>>>>>

SwitchController : Found timed switch handler for k/v 11081.973287102 / {'callback_kwargs': {}, 'return_info': False, 'removed': False, 'state': 1, 'switch_name': 's_switch4', 'ms': 1000, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x10469da58>>, 'switch_action': 's_switch4-1'}

EventManager : Event: ======'s_switch4_active'====== Args={}
SwitchController : Processing timed switch handler. Switch: s_switch4  State: 1, ms: 1000
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']

ball_device.bd_trough : Got 1 unknown ball during eject
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']

ball_device.bd_trough : Got timeout before confirm
ball_device.bd_trough : Got unknown balls. Assuming a ball returned.
ball_device.bd_trough : Received eject failed. Ball returned.
ball_device.bd_trough : Exited eject mode.
EventManager : Event: ======'balldevice_bd_trough_ball_eject_failed'====== Args={'retry': True, 'balls': 1, 'num_attempts': 1, 'target': <playfield.playfield>}

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']

ball_device.bd_trough : Eject ended

ball_device.bd_trough : Counting idle
EventManager : Event: ======'balldevice_bd_trough_ball_eject_attempt'====== Args={'source': <ball_device.bd_trough>, 'mechanical_eject': False, 'num_attempts': 1, 'balls': 1, 'target': <playfield.playfield>}

ball_device.bd_trough : Ejecting ball to <playfield.playfield>

EventManager : Event: ======'balldevice_bd_trough_ejecting_ball'====== Args={'source': <ball_device.bd_trough>, 'mechanical_eject': False, 'num_attempts': 1, 'balls': 1, 'target': <playfield.playfield>}
ball_device.bd_trough : Entered eject mode.
SwitchController : Registering switch handler: s_switch4, functools.partial(<function SwitchController._wait_handler at 0x10428dea0>, switch_name='s_switch4', _future=<Future pending cb=[SwitchController._future_done([])()]>, ms=0), state: 0, ms: 0, info: False, cb_kwargs: {}

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Waiting for eject to end
ball_device.bd_trough : Wait for ball to leave device
ball_device.bd_trough : Firing eject coil. Current balls: 1.

[jabdoa]

Hi Doug,

did the ball drain (again) within 10s? The switch is active so it believes that the ball came back. Didn't it? Maybe a bad switch? You can try to reduce "eject_timeouts" to 2-4s if it actually was ejected and drained again. Any playfield switch hit will also confirm the eject but that does not happen here.

I saw in your machine config that you also set "ignore_window_ms: 200" on your trough switch s_switch4. Remove that! The ball device already handles this.


Jan

[Doug Spata]

We're getting there! I pumped up the eject_timeouts: and ball_missing_timeouts: times and haven't had an issue with the trough trying to kick when the ball is already in play.

The next thing to address is that when the ball drains after completing the Wizard sequence, the ball doesn't advance and a new ball doesn't kick out.  I highlighted the differences between pre-Wizard and Post-Wizard drains and discovered that "ball_ending" posts but not "ball_ended" and "player_turn_stop" fails to post at all (which leads to a whole long "new ball" sequence). What could be preventing that and how do I adjust for it?

Here's what a pre-wizard drain looks like:

SwitchController : <<<<<<< 's_switch4' active >>>>>>>
SwitchController : Found timed switch handler for k/v 2256.916988549 / {'return_info': False, 'ms': 2000, 'removed': False, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x104718be0>>, 'switch_action': 's_switch4-1', 'state': 1, 'callback_kwargs': {}, 'switch_name': 's_switch4'}

EventManager : Event: ======'s_switch4_active'====== Args={}

SwitchController : WARNING: Received duplicate switch state, which means this switch had some non-debounced state changes. This could be nothing, but if it happens a lot it could indicate noise or interference on the line. Switch: s_switch4
SwitchController : Processing timed switch handler. Switch: s_switch4  State: 1, ms: 2000

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']

ball_device.bd_trough : Counting idle
ball_device.bd_trough : BCH: Found 1 new balls
ball_device.bd_trough : Received unexpected ball
EventManager : Event: ======'balldevice_captured_from_playfield'====== Args={'balls': 1}
EventManager : Event: ======'sw_playfield_active'====== Args={'balls': 1}

EventManager : Event: ======'playfield_ball_count_change'====== Args={'change': -1, 'balls': 0}

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']

ball_device.bd_trough : Processing new ball
EventManager : Event: ======'balldevice_bd_trough_ball_enter'====== Args={'device': <ball_device.bd_trough>, 'unclaimed_balls': 1, 'new_balls': 1}
EventManager : Event: ======'ball_drain'====== Args={'device': <ball_device.bd_trough>, 'balls': 1}

EventManager : Event: ======'ball_will_end'====== Args={}
EventManager : Event: ======'ball_ending'====== Args={}
EventManager : Event: ======'ball_ended'====== Args={}
ball_device.bd_trough : Adding ball

EventManager : Event: ======'balldevice_balls_available'====== Args={}

EventManager : Event: ======'balldevice_bd_trough_ball_entered'====== Args={'device': <ball_device.bd_trough>, 'new_balls': 1}

EventManager : Event: ======'player_turn_stop'====== Args={'player': <Player 1>, 'number': 1}
EventManager : Event: ======'player_turn_start'====== Args={'player': <Player 1>, 'number': 1}
EventManager : Event: ======'player_turn_starting'====== Args={'player': <Player 1>, 'number': 1}
EventManager : Event: ======'player_ball'====== Args={'change': 1, 'player_num': 1, 'value': 2, 'prev_value': 1}
EventManager : Event: ======'player_turn_started'====== Args={'player': <Player 1>, 'number': 1}
EventManager : Event: ======'ball_starting'====== Args={'is_extra_ball': False, 'balls_remaining': 1}
EventManager : Event: ======'balls_in_play'====== Args={'balls': 1}
EventManager : Event: ======'ball_started'====== Args={'player': 1, 'ball': 2}
EventManager : Event: ======'single_player_ball_started'====== Args={}
ball_device.bd_trough : Setting up player-controlled eject. Balls: 1, Target: <playfield.playfield>, player_controlled_eject_event: None

ball_device.bd_trough : Adding 1 ball(s) to the eject_queue with target <playfield.playfield>.
ball_device.bd_trough : Adding eject chain
EventManager : Event: ======'balldevice_balls_available'====== Args={}

ball_device.bd_trough : Got eject request
EventManager : Event: ======'balldevice_bd_trough_ball_eject_attempt'====== Args={'mechanical_eject': False, 'num_attempts': 0, 'target': <playfield.playfield>, 'source': <ball_device.bd_trough>, 'balls': 1}

ball_device.bd_trough : Ejecting ball to <playfield.playfield>

EventManager : Event: ======'balldevice_bd_trough_ejecting_ball'====== Args={'mechanical_eject': False, 'num_attempts': 0, 'target': <playfield.playfield>, 'source': <ball_device.bd_trough>, 'balls': 1}
ball_device.bd_trough : Entered eject mode.
SwitchController : Registering switch handler: s_switch4, functools.partial(<function SwitchController._wait_handler at 0x10399aea0>, ms=0, _future=<Future pending cb=[SwitchController._future_done([])()]>, switch_name='s_switch4'), state: 0, ms: 0, info: False, cb_kwargs: {}

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Waiting for eject to end
ball_device.bd_trough : Wait for ball to leave device
ball_device.bd_trough : Firing eject coil. Current balls: 1.
SwitchController : <<<<<<< 's_switch4' inactive >>>>>>>

SwitchController : Found timed switch handler for k/v 2257.509407724 / {'return_info': False, 'ms': 500, 'removed': False, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x104718be0>>, 'switch_action': 's_switch4-0', 'state': 0, 'callback_kwargs': {}, 'switch_name': 's_switch4'}

EventManager : Event: ======'s_switch4_inactive'====== Args={}
SwitchController : Removing switch handler. Switch: s_switch4, State: 0, ms: 0

ball_device.bd_trough : Got ball left during eject
ball_device.bd_trough : Switch 's_switch4' changed too recently. Aborting count!
ball_device.bd_trough : Ball left

ball_device.bd_trough : Wait for confirm with timeout 29.0
SwitchController : Processing timed switch handler. Switch: s_switch4  State: 0, ms: 500
ball_device.bd_trough : Counted 0 balls. Active switches: []
EventManager : Event: ======'restore'====== Args={}
EventManager : Event: ======'drop_target_bank_five_drop_reset_lower_up'====== Args={}
EventManager : Event: ======'restore'====== Args={}
EventManager : Event: ======'drop_target_bank_five_drop_reset_upper_up'====== Args={}
EventManager : Event: ======'restore'====== Args={}
EventManager : Event: ======'drop_target_bank_three_drop_reset_up'====== Args={}

and here's what a post-Wizard drain looks like:

SwitchController : <<<<<<< 's_switch4' active >>>>>>>
SwitchController : Found timed switch handler for k/v 1930.042713698 / {'switch_action': 's_switch4-1', 'removed': False, 'switch_name': 's_switch4', 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x104712e80>>, 'ms': 2000, 'state': 1, 'callback_kwargs': {}, 'return_info': False}

EventManager : Event: ======'s_switch4_active'====== Args={}

SwitchController : WARNING: Received duplicate switch state, which means this switch had some non-debounced state changes. This could be nothing, but if it happens a lot it could indicate noise or interference on the line. Switch: s_switch4
SwitchController : WARNING: Received duplicate switch state, which means this switch had some non-debounced state changes. This could be nothing, but if it happens a lot it could indicate noise or interference on the line. Switch: s_switch4
SwitchController : Processing timed switch handler. Switch: s_switch4  State: 1, ms: 2000

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']

ball_device.bd_trough : Counting idle
ball_device.bd_trough : BCH: Found 1 new balls
ball_device.bd_trough : Received unexpected ball
EventManager : Event: ======'balldevice_captured_from_playfield'====== Args={'balls': 1}
EventManager : Event: ======'sw_playfield_active'====== Args={'balls': 1}
EventManager : Event: ======'playfield_ball_count_change'====== Args={'balls': 0, 'change': -1}

ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']

ball_device.bd_trough : Processing new ball
EventManager : Event: ======'balldevice_bd_trough_ball_enter'====== Args={'new_balls': 1, 'device': <ball_device.bd_trough>, 'unclaimed_balls': 1}
EventManager : Event: ======'ball_drain'====== Args={'balls': 1, 'device': <ball_device.bd_trough>}
EventManager : Event: ======'ball_will_end'====== Args={}
EventManager : Event: ======'ball_ending'====== Args={}
ball_device.bd_trough : Adding ball

EventManager : Event: ======'balldevice_balls_available'====== Args={}

EventManager : Event: ======'balldevice_bd_trough_ball_entered'====== Args={'new_balls': 1, 'device': <ball_device.bd_trough>}

[jabdoa]

Do you have a ball_save active in one of them? In that case there will be no player turn change.

Jan

[Doug Spata]

The unlimited_delay in Wizardoutro1 should have ended when Carousel started and the ball kicked out. There are no other timers running (except the new trough timeout) and I've removed all other ball saves.

If the unlimited_delay were still going, I feel like the ball would kick out. But If we try using ball_saves_unlimited_delay_ball_ejected as a stop command on the unlimited_delay, would that be a valid command?

[jabdoa]

What are you trying to achieve? Should the ball end after wizard mode? I still do not fully understand how you want your stuff to work.

Jan

[Doug Spata]

To complete the wizard mode sequence, the ball should drain, it should let me choose a new game mode, and then eject a ball without advancing the ball count. It does all this successfully.

But as I keep playing game modes (and advancing toward the next wizard mode), if I happen to lose the ball, it should advance the ball count and eject a new ball. If I lose ball 3, it should go into attract mode. It doesn't do any of that - the game mode keeps going, the ball count doesn't advance and the ball sits in the trough.

The ball advance and kick out work fine before I get to wizard mode. If I drain during a game mode after wizard has ended, it sits in the though. Something is happening during the wizard mode sequence that is preventing future drains from registering.

[jabdoa]

Can you check with the monitor if the ball_lock stays active after the wizard mode ended? My guess would be that it causes this.

Jan

[Doug Spata]

I've tried some adjustments with limited success, but I can't make it behave how I want it to twice in a row. With no changes to the code, every odd numbered attempt works and every even numbered attempt fails.  Here's what's happening:

The Wizard timer ends, Wizardoutro1 starts and the unlimited_delay is enabled:

EventManager : Event: ======'timer_wizard1_timer_tick'====== Args={'ticks': 4, 'ticks_remaining': 3}
EventManager : Event: ======'oneplay'====== Args={'priority': 0}
EventManager : Event: ======'player_wizard1_wizard1_timer_tick'====== Args={'player_num': 1, 'change': -1, 'value': 3, 'prev_value': 4}
EventManager : Event: ======'timer_wizard1_timer_tick'====== Args={'ticks': 3, 'ticks_remaining': 2}
EventManager : Event: ======'player_wizard1_wizard1_timer_tick'====== Args={'player_num': 1, 'change': -1, 'value': 2, 'prev_value': 3}
EventManager : Event: ======'timer_wizard1_timer_tick'====== Args={'ticks': 2, 'ticks_remaining': 1}

EventManager : Event: ======'mode_wizard1_complete'====== Args={'priority': 0}
Timer.wizard1_timer : Stopping Timer

EventManager : Event: ======'timer_wizard1_timer_stopped'====== Args={'ticks': 2, 'ticks_remaining': 1}

EventManager : Event: ======'mode_wizardoutro1_starting'====== Args={}
Mode.wizardoutro1 : Started. Priority: 500

EventManager : Event: ======'mode_wizardoutro1_started'====== Args={}
EventManager : Event: ======'ball_save_unlimited_delay_enabled'====== Args={}

The flippers go dead, the ball drains (switch 4), stopping Wizard1 mode and starting Carousel. unlimited_delay registers a ball save and immediately disables:

SwitchController : <<<<<<< 's_switch4' active >>>>>>>
SwitchController : Found timed switch handler for k/v 3868.906046593 / {'switch_action': 's_switch4-1', 'switch_name': 's_switch4', 'removed': False, 'state': 1, 'ms': 2000, 'return_info': False, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x104906358>>, 'callback_kwargs': {}}

EventManager : Event: ======'s_switch4_active'====== Args={}

EventManager : Event: ======'mode_wizardoutro1_complete'====== Args={'priority': 0}
EventManager : Event: ======'mode_carousel_starting'====== Args={}
Timer.wizard1_timer : Stopping Timer

EventManager : Event: ======'timer_wizard1_timer_stopped'====== Args={'ticks': 2, 'ticks_remaining': 1}

EventManager : Event: ======'mode_wizard1_stopping'====== Args={}
Mode.carousel : Started. Priority: 999
EventManager : Event: ======'mode_carousel_started'====== Args={}
Mode.wizard1 : Stopped.
EventManager : Event: ======'mode_wizard1_stopped'====== Args={}
EventManager : Event: ======'clear'====== Args={'key': 'wizard1'}
EventManager : Event: ======'carousel_dontstopmenow_highlighted'====== Args={}

SwitchController : Processing timed switch handler. Switch: s_switch4  State: 1, ms: 2000
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Counting idle
ball_device.bd_trough : BCH: Found 1 new balls
ball_device.bd_trough : Received unexpected ball
EventManager : Event: ======'balldevice_captured_from_playfield'====== Args={'balls': 1}
EventManager : Event: ======'sw_playfield_active'====== Args={'balls': 1}
EventManager : Event: ======'playfield_ball_count_change'====== Args={'balls': 0, 'change': -1}
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Processing new ball

EventManager : Event: ======'balldevice_bd_trough_ball_enter'====== Args={'new_balls': 1, 'unclaimed_balls': 1, 'device': <ball_device.bd_trough>}

EventManager : Event: ======'ball_drain'====== Args={'balls': 1, 'device': <ball_device.bd_trough>}

EventManager : Event: ======'ball_save_unlimited_delay_saving_ball'====== Args={'balls': 1, 'early_save': False}

EventManager : Event: ======'ball_save_unlimited_delay_disabled'====== Args={}

ball_device.bd_trough : Adding ball
EventManager : Event: ======'balldevice_balls_available'====== Args={}
EventManager : Event: ======'balldevice_bd_trough_ball_entered'====== Args={'new_balls': 1, 'device': <ball_device.bd_trough>}

... and that's the last mention of unlimited_delay in the logs. Whether it's re-ejected as a new ball or just sits in the trough, when the ball drains again during regular play, there's never mention of the ball being saved. It always recognizes that a ball device has the ball and it looks like it's logging a "ball_ending" event, but half the time, the trough becomes paralyzed before ejecting a new ball.

SwitchController : <<<<<<< 's_switch4' active >>>>>>>
SwitchController : Found timed switch handler for k/v 3918.8889838 / {'switch_action': 's_switch4-1', 'switch_name': 's_switch4', 'removed': False, 'state': 1, 'ms': 2000, 'return_info': False, 'callback': <bound method SwitchCounter._switch_changed of <mpf.devices.ball_device.switch_counter.SwitchCounter object at 0x104906358>>, 'callback_kwargs': {}}

EventManager : Event: ======'s_switch4_active'====== Args={}
SwitchController : WARNING: Received duplicate switch state, which means this switch had some non-debounced state changes. This could be nothing, but if it happens a lot it could indicate noise or interference on the line. Switch: s_switch4
SwitchController : Processing timed switch handler. Switch: s_switch4  State: 1, ms: 2000
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Counting idle
ball_device.bd_trough : BCH: Found 1 new balls
ball_device.bd_trough : Received unexpected ball
EventManager : Event: ======'balldevice_captured_from_playfield'====== Args={'balls': 1}
EventManager : Event: ======'sw_playfield_active'====== Args={'balls': 1}

EventManager : Event: ======'playfield_ball_count_change'====== Args={'balls': 0, 'change': -1}
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Processing new ball

EventManager : Event: ======'balldevice_bd_trough_ball_enter'====== Args={'new_balls': 1, 'unclaimed_balls': 1, 'device': <ball_device.bd_trough>}

EventManager : Event: ======'ball_drain'====== Args={'balls': 1, 'device': <ball_device.bd_trough>}
EventManager : Event: ======'ball_will_end'====== Args={}
EventManager : Event: ======'ball_ending'====== Args={}
ball_device.bd_trough : Adding ball
EventManager : Event: ======'balldevice_balls_available'====== Args={}
EventManager : Event: ======'balldevice_bd_trough_ball_entered'====== Args={'new_balls': 1, 'device': <ball_device.bd_trough>}

Comparing the logs of when it worked and when it didn't, I did find one very subtle difference, highlighted in red. Compare with the same line above (which didn't work). Could this make a difference?

ball_device.bd_trough : Received unexpected ball
EventManager : Event: ======'balldevice_captured_from_playfield'====== Args={'balls': 1}
EventManager : Event: ======'sw_playfield_active'====== Args={'balls': 1}
EventManager : Event: ======'playfield_ball_count_change'====== Args={'change': -1, 'balls': 0}
ball_device.bd_trough : Counted 1 balls. Active switches: ['s_switch4']
ball_device.bd_trough : Processing new ball

[Doug Spata]

Addendum to my last post: Wizardoutro1 mode now looks like this:

mode:
    start_events: mode_wizard1_complete
    stop_events: mode_carousel_stopping, carousel_dontstopmenow_selected, carousel_aobtd1_selected, carousel_fatbottom_selected, carousel_bicycle_selected, carousel_crazy_selected, carousel_pressure_selected, carousel_killer_selected, carousel_rockyou_selected, carousel_somebody_selected
    priority: 500

ball_saves:
    unlimited_delay:
        enable_events: mode_wizardoutro1_started
        delayed_eject_events: mode_wizardoutro1_stopping

        balls_to_save: 1
        disable_events: mode_carousel_stopping

event_player:
    s_switch4_active: mode_wizardoutro1_complete

[jabdoa]

Hi Doug,

Does that work? Do you see the mode stopped? Is there a specific reason you are using mode_carousel_stopped for the ball_save but the _selected events to stop the mode? I guess the latter will be posted first and the other one might not hit the ball save all before unloading.

Jan

[Doug Spata]

Whew!  After a few hours of studying the logs and testing out every possible variation and combination of start and stop events, I came across this combination:

mode:
    start_events: mode_wizard1_complete
    stop_events: mode_dontstopmenow_started, mode_aobtd1_started, mode_fatbottom_started, mode_bicycle_started, mode_crazy_started, mode_pressure_started, mode_killer_started, mode_rockyou_started, mode_somebody_started

ball_saves:
    unlimited_delay:
        enable_events: mode_wizardoutro1_started
        delayed_eject_events: mode_carousel_stopping
        balls_to_save: 1
        disable_events: mode_dontstopmenow_starting, mode_aobtd1_starting, mode_fatbottom_starting, mode_bicycle_starting, mode_crazy_starting, mode_pressure_starting, mode_killer_starting, mode_rockyou_starting, mode_somebody_starting

event_player:
    s_switch4_active: mode_wizardoutro1_complete


This seems to be the correct alchemy - I've tested it successfully four times in a row. If I shut it down and re-start it and it doesn't work, I'm sure you'll hear the screams.

[jabdoa]

Hi Doug,

glad that you got it fixed. I just reviewed our conversation. It looks like part of your problem was that the mode with the ball_save stopped and the ball_save would never eject the ball when that happened before "delayed_eject_events". Therefore, I created Issue https://github.com/missionpinball/mpf/issues/894 and PR https://github.com/missionpinball/mpf/pull/895 to fix this. Basically, the ball_save will eject all delayed balls when the mode ends. Let me know if we should backport it to 0.33. I guess your machine is working now and you do not want to change it.

Jan

[Doug Spata]

True - it seems to be working now, so I'm apprehensive about changing anything. Thanks for your patience on this!