broker crash on database timeout

[Robie Basak]

This could use some investigation. Is the sqlite3 lock timeout retry code buggy somehow?

Associated with this was a broker exit status 1 with no traceback a few days after an automatic restart following this crash.

Apr 16 03:11:31 reber git-ubuntu[78448]: Traceback (most recent call last):
Apr 16 03:11:31 reber git-ubuntu[78448]: File "/snap/git-ubuntu/474/bin/git-ubuntu", line 11, in <module>
Apr 16 03:11:31 reber git-ubuntu[78448]: load_entry_point('gitubuntu==1.0', 'console_scripts', 'git-ubuntu')()
Apr 16 03:11:31 reber git-ubuntu[78448]: File "/snap/git-ubuntu/474/lib/python3.6/site-packages/gitubuntu/__main__.py", line 279, in main
Apr 16 03:11:31 reber git-ubuntu[78448]: sys.exit(args.func(args))
Apr 16 03:11:31 reber git-ubuntu[78448]: File "/snap/git-ubuntu/474/lib/python3.6/site-packages/gitubuntu/importer_service_broker.py", line 165, in cli_main
Apr 16 03:11:31 reber git-ubuntu[78448]: worker_broker_socket_address=args.worker_broker_socket_address,
Apr 16 03:11:31 reber git-ubuntu[78448]: File "/snap/git-ubuntu/474/lib/python3.6/site-packages/gitubuntu/importer_service_broker.py", line 129, in main
Apr 16 03:11:31 reber git-ubuntu[78448]: main_loop(worker_socket, service_state) # never returns
Apr 16 03:11:31 reber git-ubuntu[78448]: File "/snap/git-ubuntu/474/lib/python3.6/site-packages/gitubuntu/importer_service_broker.py", line 109, in main_loop
Apr 16 03:11:31 reber git-ubuntu[78448]: handle_reply(service_state, reply)
Apr 16 03:11:31 reber git-ubuntu[78448]: File "/snap/git-ubuntu/474/lib/python3.6/site-packages/gitubuntu/importer_service_broker.py", line 77, in handle_reply
Apr 16 03:11:31 reber git-ubuntu[78448]: reply.identity,
Apr 16 03:11:31 reber git-ubuntu[78448]: File "/snap/git-ubuntu/474/lib/python3.6/site-packages/gitubuntu/importer_service.py", line 108, in wrapper
Apr 16 03:11:31 reber git-ubuntu[78448]: self.db.execute('ROLLBACK')
Apr 16 03:11:31 reber git-ubuntu[78448]: sqlite3.OperationalError: cannot rollback - no transaction is active

[Bryce Harrington (bryce)]

Just looking cursorily at this I notice a comment:

    # We only update the status of the request if the worker is telling us
    # about the request we have recorded as having given it. It's possible that
    # the worker is reporting work from an old identity and we've already moved
    # on from that, so in that case we just ignore the worker's work and rely
    # on the cleanup done later using service_state.clear_ipc_worker() to get
    # back to a good state.
    package, level, reckoning_time = service_state.lookup_ipc_worker(
        reply.identity,
    )

Might it be possible that this is in fact the documented situation where the worker is reporting on old stuff (or returning after a timeout)? Might be why it ends with a "no transaction is active" result.