Use an Asynchronous Event Loop in SbyJob

[cr1901]

Compared to the select event loop, using the event loop provided by asyncio for sby_core offers improvements in portability and reduces the code used for manaual event management, with minimal increase in the lines of code. Unix functionality is (almost completely- see signal handlers) unaffected, while Windows support gains feature-parity with Unix.

Summary of Changes

As part of this PR, taskloop's semantics have changed (task in this context means async def). Instead of waiting on fds, taskloop now waits on SbyTask termination or SbyJob timeout. The following tasks are run:

• maybe_spawn will spawn a subprocess associated with SbyTask if all SbyTasks it depends on is finished.
• The output task will collect lines of stdout. This happens in parallel with waiting for SbyTask termination.
• shutdown_and_notify will do cleanup and then run maybe_spawn on all SbyTasks in self.notify.
• timekeeper handles global timeout of SbyJob.
• Once the task_poller task returns (be it termination, timeout, or completion), the event loop shuts itself down.

Improvements

• Improves Windows support while only using Python's standard library; tasks can now run in parallel without relying on Unix-specific select functionality.
• From my perception, an overall cleanup of taskloop:
  • taskloop will not iterate unless an event occurred (contrast to the timeout parameter of select.
  • There is no longer any need to poll tasks that have not started; process termination is monitored by the asynchronous event loop. Every time a task finishes, taskloop will make sure to attempt to start pending tasks before beginning a new iteration.
  • Timeout and task termination is handled automatically by the asynchronous event loop.
  • Tasks no longer need to be polled regularly for output; this happens transparently.

Disadvantages

• I had to add a workaround for Windows to ensure the Python interpreter actually exits when the event loop completes. I have no idea where in the stack to look (msys2 implementation bug? Python bug?), so I'm looking into creating an MVCE to duplicate the problem and ask for help.

  That said, the code works correctly in my testing on Windows, and better than what is currently there. This is more of a complaint that a workaround is needed at all (the tasks_retired member of SbyTask exists solely for this workaround).

• SbyTasks no longer spawn subprocesses; this is now taskloop's responsbility. Python constructors cannot be asynchronous and the various workarounds I've found require large swaths of SymbiYosys to become async rather than just the taskloop. In my opinion, this is more trouble than it is worth for a few milliseconds less latency in getting tasks running initially. I renamed run() functions to init() to reflect the changes.

• Signal handlers should be async using AbstractEventLoop.add_signal_handler(). At present, there is no way to do this portably. This results in messages like the following when CTRL+C is pressed:

Windows

SBY 23:27:36 [sbysrc\demo3] engine_1: ##   0:00:00  Checking assertions in step 15..
SBY 23:27:36 [sbysrc\demo3] engine_0: ##   0:00:00  Checking assumptions in step 8..
SBY 23:27:36 [sbysrc\demo3] engine_0: ##   0:00:00  Checking assertions in step 8..
Task exception was never retrieved
future: <Task finished coro=<SbyTask.output() done, defined at C:\msys64\mingw64\bin/../share/yosys/python3\sby_core.py:121> exception=RuntimeError("reentrant call inside <_io.BufferedWriter name='<stdout>'>",)>
Traceback (most recent call last):
  File "C:\msys64\mingw64\bin/../share/yosys/python3\sby_core.py", line 132, in output
    self.handle_output(outs)
  File "C:\msys64\mingw64\bin/../share/yosys/python3\sby_core.py", line 90, in handle_output
    self.job.log("%s: %s" % (self.info, line))
  File "C:\msys64\mingw64\bin/../share/yosys/python3\sby_core.py", line 292, in log
    print("SBY %2d:%02d:%02d [%s] %s" % (tm.tm_hour, tm.tm_min, tm.tm_sec, self.workdir, logmessage), flush=True)
  File "C:\msys64\mingw64\bin/../share/yosys/python3\sby_core.py", line 33, in force_shutdown
    print("SBY ---- Keyboard interrupt or external termination signal ----", flush=True)
RuntimeError: reentrant call inside <_io.BufferedWriter name='<stdout>'>
SBY 23:27:36 [sbysrc\demo3] engine_1: ##   0:00:00  Unexpected response from solver: unknown
SBY 23:27:36 [sbysrc\demo3] engine_1: <SIGINT>
SBY 23:27:36 [sbysrc\demo3] engine_0: finished (returncode=1)
SBY 23:27:36 [sbysrc\demo3] ERROR: engine_0: Engine terminated without status.
SBY 23:27:36 [sbysrc\demo3] engine_1: terminating process
SBY 23:27:36 [sbysrc\demo3] DONE (ERROR, rc=16)

Unix

This warning comparatively rare. I've not been able to cause an error on Unix. AbstractEventLoop.add_signal_handler() can solve this, but since signals become events in the event loop, the sys.exit(1) line would need to be moved until after the loop finishes (i.e. task_poller returns). Current behavior is to exit immediately in force_shutdown.

SBY 23:13:05 [sbysrc/demo3] engine_0: ##   0:00:00  Checking assertions in step 15..
SBY 23:13:05 [sbysrc/demo3] engine_1: ##   0:00:00  Checking assumptions in step 35..
^CSBY ---- Keyboard interrupt or external termination signal ----
SBY 23:13:05 [sbysrc/demo3] engine_0: terminating process
SBY 23:13:05 [sbysrc/demo3] engine_1: terminating process
Task was destroyed but it is pending!
source_traceback: Object created at (most recent call last):
  File "/home/william/.local/bin/sby", line 388, in <module>
    retcode |= run_job(t)
  File "/home/william/.local/bin/sby", line 346, in run_job
    job.run(setupmode)
  File "/home/william/.local/bin/../share/yosys/python3/sby_core.py", line 660, in run
    self.taskloop()
  File "/home/william/.local/bin/../share/yosys/python3/sby_core.py", line 242, in taskloop
    loop.run_until_complete(poll_fut)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 375, in run_until_complete
    self.run_forever()
  File "/usr/lib/python3.5/asyncio/base_events.py", line 345, in run_forever
    self._run_once()
  File "/usr/lib/python3.5/asyncio/base_events.py", line 1304, in _run_once
    handle._run()
  File "/usr/lib/python3.5/asyncio/events.py", line 125, in _run
    self._callback(*self._args)
  File "/usr/lib/python3.5/asyncio/tasks.py", line 307, in _wakeup
    self._step()
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "/home/william/.local/bin/../share/yosys/python3/sby_core.py", line 277, in task_poller
    await task.shutdown_and_notify()
  File "/usr/lib/python3.5/asyncio/coroutines.py", line 105, in __next__
    return self.gen.send(None)
  File "/home/william/.local/bin/../share/yosys/python3/sby_core.py", line 181, in shutdown_and_notify
    await next_task.maybe_spawn()
  File "/usr/lib/python3.5/asyncio/coroutines.py", line 105, in __next__
    return self.gen.send(None)
  File "/home/william/.local/bin/../share/yosys/python3/sby_core.py", line 161, in maybe_spawn
    asyncio.ensure_future(self.output())
task: <Task pending coro=<SbyTask.output() running at /home/william/.local/bin/../share/yosys/python3/sby_core.py:124> created at /home/william/.local/bin/../share/yosys/python3/sby_core.py:161>

Testing

I have tested this PR on Windows (MSYS2) and Linux (Ubuntu) using the demo3.sby script with an extra solver: smtbmc z3. I also tested timeout and ^C handling.

cc: @q3k and @whitequark I would also like your feedback.