uvloop Error in Bonus Mode

[Greg Sealby]

I've installed uvloop on my Ubuntu platform and have noticed that I am getting an issue during bonus mode when players "flipper cancel" during this mode.  Flipper cancel works fine in other parts of the game (eg Carousel at the start of a ball).  When a flipper cancel event is received during the bonus mode, my game crashes unceremoniously.  Here is the log:

2019-09-08 17:03:38,175 : INFO : EventManager : Event: ======'flipper_cancel'====== Args={}
2019-09-08 17:03:38,192 : INFO : EventManager : Event: ======'machine_var_audits_switches_s_flipper_main_right'====== Args={'value': 7819, 'prev_value': 7818, 'change': 1}
2019-09-08 17:03:38,193 : ERROR : asyncio : Exception in callback <bound method EventManager.process_event_queue of <mpf.core.events.EventManager object at 0x7fb46cd4e9c8>>
handle: <Handle EventManager.process_event_queue>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 657, in _run_handlers
    result = handler.callback(**merged_kwargs)
  File "/usr/local/lib/python3.6/dist-packages/mpf/modes/bonus/code/bonus.py", line 69, in hurry_up
    self.delay.run_now('bonus')
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/delays.py", line 198, in run_now
    cb = self.delays[name]._callback
AttributeError: 'uvloop.loop.TimerHandle' object has no attribute '_callback'


The above exception was the direct cause of the following exception:


Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 66, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 738, in process_event_queue
    **event[3])
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 703, in _process_event
    result = self._run_handlers(event, ev_type, kwargs)
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 659, in _run_handlers
    raise Exception("Exception while processing {} for event {}".format(handler, event)) from e
Exception: Exception while processing RegisteredHandler(callback=<bound method Bonus.hurry_up of <Mode.bonus>>, priority=500, kwargs={'mode': <Mode.bonus>}, key=UUID('2b1bc245-ac54-4a78-ace8-dde4ff2c62fe'), condition=None, blocking_facility=None) for event flipper_cancel
2019-09-08 17:03:38,208 : INFO : Machine : Shutting down...
2019-09-08 17:03:38,208 : INFO : EventManager : Event: ======'shutdown'====== Args={}
2019-09-08 17:03:38,208 : INFO : EventManager : Event: ======'mode_service_will_stop'====== Args={}
2019-09-08 17:03:38,208 : INFO : EventManager : Event: ======'mode_service_stopping'====== Args={}
2019-09-08 17:03:38,209 : INFO : Mode.service : Stopped.
2019-09-08 17:03:38,212 : WARNING : BCPClientSocket.local_display : WARNING: Failed to write to bcp since transport is closing. Transport <TCPTransport closed=False reading=False 0x28a0588>
2019-09-08 17:03:38,213 : WARNING : BCPClientSocket.local_display : WARNING: Failed to write to bcp since transport is closing. Transport <TCPTransport closed=False reading=False 0x28a0588>
2019-09-08 17:03:38,214 : WARNING : BCPClientSocket.local_display : WARNING: Failed to write to bcp since transport is closing. Transport <TCPTransport closed=False reading=False 0x28a0588>
2019-09-08 17:03:38,215 : INFO : EventManager : Event: ======'mode_service_stopped'====== Args={}
2019-09-08 17:03:38,216 : INFO : EventManager : Event: ======'clear'====== Args={'key': 'service'}
2019-09-08 17:03:38,227 : ERROR : root : Exception while processing RegisteredHandler(callback=<bound method Bonus.hurry_up of <Mode.bonus>>, priority=500, kwargs={'mode': <Mode.bonus>}, key=UUID('2b1bc245-ac54-4a78-ace8-dde4ff2c62fe'), condition=None, blocking_facility=None) for event flipper_cancel
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 657, in _run_handlers
    result = handler.callback(**merged_kwargs)
  File "/usr/local/lib/python3.6/dist-packages/mpf/modes/bonus/code/bonus.py", line 69, in hurry_up
    self.delay.run_now('bonus')
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/delays.py", line 198, in run_now
    cb = self.delays[name]._callback
AttributeError: 'uvloop.loop.TimerHandle' object has no attribute '_callback'


The above exception was the direct cause of the following exception:


Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/mpf/commands/game.py", line 220, in __init__
    MachineController(mpf_path, machine_path, vars(self.args)).run()
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/machine.py", line 709, in run
    self._run_loop()
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/machine.py", line 769, in _run_loop
    raise self._exception['exception']
  File "uvloop/cbhandles.pyx", line 66, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 738, in process_event_queue
    **event[3])
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 703, in _process_event
    result = self._run_handlers(event, ev_type, kwargs)
  File "/usr/local/lib/python3.6/dist-packages/mpf/core/events.py", line 659, in _run_handlers
    raise Exception("Exception while processing {} for event {}".format(handler, event)) from e
Exception: Exception while processing RegisteredHandler(callback=<bound method Bonus.hurry_up of <Mode.bonus>>, priority=500, kwargs={'mode': <Mode.bonus>}, key=UUID('2b1bc245-ac54-4a78-ace8-dde4ff2c62fe'), condition=None, blocking_facility=None) for event flipper_cancel

Should I just install uvloop?  Or is there a piece of additional config that is required to make Bonus mode work properly?  It looks like it can't jump a timer to zero in the bonus mode due to an issue with uvloop.

[jabdoa]

Hi Greg,

you are already running uvloop. MPF will use it once it is installed. I fixed this in dev a while back: https://github.com/missionpinball/mpf/commit/8bdb7f08234d7a67ef741e08433c69b70bcbb26d. I just backported it to 0.52.6.

Jan

[Greg Sealby]

Thanks Jan, I'll upgrade tomorrow and let you know how it goes.

[Greg Sealby]

Confirmed.  Version 52.6 has resolved this issue.  Thanks Jan.