avatar2: Race condition when using wait/cont on target in combination with hooks

Circumstances

I am using the GDBTarget target to connect to QEMU. I can’t use the built-in QEMU target because QEMU gets spawned from another process. There seems to be an issue with synchronous hooks being async. I have the following testcase to reproduce the issue:

import avatar2
import os
import logging
import sys
import time

from nose.tools import *


def test_race():

    def hook_callback(avatar, *args, **kwargs):
        gdb = avatar.targets['gdbtest']
        pc = gdb.read_register("pc")
        assert pc is not None, f"ILLEGAL STATE {gdb.get_status()}"
        print(pc)

        if pc == 0x1000:
            sys.exit()

    avatar = avatar2.Avatar(arch=avatar2.ARM)
    gdb = avatar.add_target(avatar2.GDBTarget,
                              name='gdbtest',
                              gdb_port=1234,
                              gdb_verbose_mi=True,
                              gdb_executable='/usr/bin/gdb-multiarch'
                            )

    # add breakpoint callback
    avatar.watchmen.add('BreakpointHit', when='after', callback=hook_callback, is_async=False)


    print("Init avatar targets...")
    avatar.init_targets()

    gdb.set_breakpoint(0x4)

    gdb.write_register('pc', 0)
    # Start running
    gdb.cont()

    # wait until we hit a breakpoint, once we hit the breakpoint, continue this python script
    print("waiting until we hit a breakpoint")
    gdb.wait()
    # add two breakpoints
    gdb.set_breakpoint(0x8)
    gdb.set_breakpoint(0xc)

    gdb.set_breakpoint(0x1000)

    # Continue executing from main
    gdb.cont()
    time.sleep(1)
    while True:
        # Wait until we hit a breakpoint
        gdb.wait()
        gdb.cont()


    avatar.shutdown()

if __name__ == '__main__':
    test_race()

This results in this crash:

redacted@5d755f437052:~/avatar_bug$ python3 target_wait.py 
Init avatar targets...
waiting until we hit a breakpoint
4
8
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.8/dist-packages/avatar2/avatar2.py", line 400, in run
    handler(message)
  File "/usr/local/lib/python3.8/dist-packages/avatar2/watchmen.py", line 80, in watchtrigger
    cb_ret = avatar.watchmen.t(watched_type, AFTER, *args, **cb_kwargs)
  File "/usr/local/lib/python3.8/dist-packages/avatar2/watchmen.py", line 185, in trigger
    watchman.react(self._avatar, *args, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/avatar2/watchmen.py", line 126, in react
    ret = self._callback(avatar, *args, **kwargs)
  File "target_wait.py", line 18, in hook_callback
    assert pc is not None, f"ILLEGAL STATE {gdb.get_status()}"
AssertionError: ILLEGAL STATE {'state': <TargetStates.RUNNING: 8>}

See also the following trace with gdb_verbose_mi enabled (around message 15-16):

writing: 13-data-list-register-values x 15
{'message': 'done',
 'payload': {'register-values': [{'number': '15', 'value': '0x8'}]},
 'stream': 'stdout',
 'token': 13,
 'type': 'result'}
8
writing: 14-exec-continue
{'message': 'running',
 'payload': None,
 'stream': 'stdout',
 'token': 14,
 'type': 'result'}
{'message': 'running',
 'payload': {'thread-id': 'all'},
 'stream': 'stdout',
 'token': None,
 'type': 'notify'}
{'message': 'breakpoint-modified',
 'payload': {'bkpt': {'addr': '0x0000000c',
                      'disp': 'keep',
                      'enabled': 'y',
                      'number': '3',
                      'original-location': '*0xc',
                      'thread-groups': ['i1'],
                      'times': '1',
                      'type': 'breakpoint'}},
 'stream': 'stdout',
 'token': None,
 'type': 'notify'}
{'message': None, 'payload': '\\n', 'stream': 'stdout', 'type': 'console'}
{'message': None,
 'payload': 'Breakpoint 3, 0x0000000c in ?? ()\\n',
 'stream': 'stdout',
 'type': 'console'}
{'message': 'stopped',
 'payload': {'bkptno': '3',
             'disp': 'keep',
             'frame': {'addr': '0x0000000c',
                       'arch': 'arm',
                       'args': [],
                       'func': '??'},
             'reason': 'breakpoint-hit',
             'stopped-threads': 'all',
             'thread-id': '1'},
 'stream': 'stdout',
 'token': None,
 'type': 'notify'}
writing: 15-exec-continue
writing: 16-data-list-register-values x 15
{'message': 'running',
 'payload': None,
 'stream': 'stdout',
 'token': 15,
 'type': 'result'}
{'message': 'running',
 'payload': {'thread-id': 'all'},
 'stream': 'stdout',
 'token': None,
 'type': 'notify'}
{'message': 'error',
 'payload': {'msg': 'Selected thread is running.'},
 'stream': 'stdout',
 'token': 16,
 'type': 'result'}
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
{'message': 'breakpoint-modified',
 'payload': {'bkpt': {'addr': '0x00000008',
                      'disp': 'keep',
                      'enabled': 'y',
                      'number': '2',
                      'original-location': '*0x8',
                      'thread-groups': ['i1'],
                      'times': '2',
                      'type': 'breakpoint'}},
 'stream': 'stdout',
 'token': None,
 'type': 'notify'}
    self.run()
  File "/usr/local/lib/python3.8/dist-packages/avatar2/avatar2.py", line 400, in run
{'message': None, 'payload': '\\n', 'stream': 'stdout', 'type': 'console'}
{'message': None,
 'payload': 'Breakpoint 2, 0x00000008 in ?? ()\\n',
 'stream': 'stdout',
 'type': 'console'}
{'message': 'stopped',
 'payload': {'bkptno': '2',
             'disp': 'keep',
             'frame': {'addr': '0x00000008',
                       'arch': 'arm',
                       'args': [],
                       'func': '??'},
             'reason': 'breakpoint-hit',
             'stopped-threads': 'all',
             'thread-id': '1'},
 'stream': 'stdout',
 'token': None,
 'type': 'notify'}
    handler(message)
  File "/usr/local/lib/python3.8/dist-packages/avatar2/watchmen.py", line 80, in watchtrigger
    cb_ret = avatar.watchmen.t(watched_type, AFTER, *args, **cb_kwargs)
  File "/usr/local/lib/python3.8/dist-packages/avatar2/watchmen.py", line 185, in trigger
    watchman.react(self._avatar, *args, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/avatar2/watchmen.py", line 126, in react
    ret = self._callback(avatar, *args, **kwargs)
  File "target_wait.py", line 15, in hook_callback
    assert pc is not None, f"ILLEGAL STATE {gdb.get_status()}"
AssertionError: ILLEGAL STATE {'state': <TargetStates.RUNNING: 8>}

Steps to reproduce this

1. Run qemu-system-arm -machine virt -gdb tcp::1234 -S -nographic -bios qemu_arm_test in a separate terminal. The qemu_arm_test binary is in avatar2/tests/binaries of this repository.
2. Run the Python script, for me it crashes every time (I have 4 CPU cores)

Expected behaviour

Machine state is STOPPED in synchronous hooks

Actual behaviour

Synchronous hooks act like async hooks?