apply: RemoteException() in item.fix() does not show the command that's caused it

[Kunsi]

The actual failed command (zpool create -o ashift=12 -o autotrim=on video raidz2 ...) is not shown, instead we get an empty line.

[vain]

Am confuse, where’s the empty line you’re referring to? 🤔 It shows the zpool command at the bottom of the screenshot.

[fkusei]

@vain it's below all the other listed commands, but before the printed exception.

[vain]

I dug a little.

Item.run() runs the command, then appends the result to the list. The exception gets thrown by self.node.run(), we never get to the point where it’s added to the list.

The whole thing is run from a worker pool in apply_items(). The pool catches the exception by calling handle_exception(), which then proceeds to call handle_apply_result() and that’s the function that prints the executed commands so far.

Now, IIUC, the problem you’re describing is: In handle_apply_result() the list item._command_results does not contain the command that’s currently being executed – because this list only ever contains commands (and their results) that finished as expected (e.g., exit code 1 is fine if it’s called with may_fail=True).

I guess what you ideally want to see is something like this (this is a made-up example):

✘ mynode  mybundle  zfs_pool:tank  failed
│
├─ zpool list tank (return code: 1; no output)
│
├─ lsblk -rndo fstype /dev/sda (RemoteException)
│
│   File "/home/user/git/bundlewrap/bundlewrap/concurrency.py", line 133, in run
│     result = self._get_result()
│   File "/home/user/git/bundlewrap/bundlewrap/concurrency.py", line 73, in _get_result
│     raise exception
│   File "/usr/lib/python3.13/concurrent/futures/thread.py", line 59, in run
│     result = self.fn(*self.args, **self.kwargs)
│   File "/home/user/git/bundlewrap/bundlewrap/items/__init__.py", line 645, in apply
│     self.fix(status_before)
│     ~~~~~~~~^^^^^^^^^^^^^^^
│   File "/home/user/git/bundlewrap/bundlewrap/items/zfs_pool.py", line 60, in fix
│     res = self.run("lsblk -rndo fstype {}".format(quote(device)))
│   File "/home/user/git/bundlewrap/bundlewrap/items/__init__.py", line 679, in run
│     result = self.node.run(command, **kwargs)
│   File "/home/user/git/bundlewrap/bundlewrap/node.py", line 935, in run
│     return operations.run(
│            ~~~~~~~~~~~~~~^
│         self.hostname,
│         ^^^^^^^^^^^^^^
│     ...<8 lines>...
│         user=user,
│         ^^^^^^^^^^
│     )
│     ^
│   File "/home/user/git/bundlewrap/bundlewrap/operations.py", line 366, in run
│     raise RemoteException(error_msg)
│ RemoteException("Non-zero return code (32) running 'lsblk -rndo fstype /dev/sda' on '1.2.3.4':\n\nlsblk: /dev/sda: not a block device\n\n\n")
╵

The line lsblk -rndo fstype /dev/sda (RemoteException) is currently not included in the output. Instead, we print a ╵ which terminates the list of successfully run commands. (This might look like an empty line.)

First idea: We would need more bookkeeping to implement this. Something like “the command currently being run is …”. This could be tricky, because we’re talking about a generic exception handler here – there might not be any command being currently run.

Next idea: Instead, it might be better to handle the RemoteException directly in Node.run(), record the failure there, then re-throw the exception (to signal to the rest of bw that it has failed). And then figure out how to suppress printing this exception in handle_apply_result() to avoid duplicating the output – but show other not-yet-printed exceptions. Ugh.

Next idea: How about printing this instead:

✘ mynode  mybundle  zfs_pool:tank  failed
│
├─ zpool list tank (return code: 1; no output)
╵
Exception after the commands above have been run:
╷
│   File "/home/user/git/bundlewrap/bundlewrap/concurrency.py", line 133, in run
│     result = self._get_result()
│   File "/home/user/git/bundlewrap/bundlewrap/concurrency.py", line 73, in _get_result
│     raise exception
│   File "/usr/lib/python3.13/concurrent/futures/thread.py", line 59, in run
│     result = self.fn(*self.args, **self.kwargs)
│   File "/home/user/git/bundlewrap/bundlewrap/items/__init__.py", line 645, in apply
│     self.fix(status_before)
│     ~~~~~~~~^^^^^^^^^^^^^^^
│   File "/home/user/git/bundlewrap/bundlewrap/items/zfs_pool.py", line 60, in fix
│     res = self.run("lsblk -rndo fstype {}".format(quote(device)))
│   File "/home/user/git/bundlewrap/bundlewrap/items/__init__.py", line 679, in run
│     result = self.node.run(command, **kwargs)
│   File "/home/user/git/bundlewrap/bundlewrap/node.py", line 935, in run
│     return operations.run(
│            ~~~~~~~~~~~~~~^
│         self.hostname,
│         ^^^^^^^^^^^^^^
│     ...<8 lines>...
│         user=user,
│         ^^^^^^^^^^
│     )
│     ^
│   File "/home/user/git/bundlewrap/bundlewrap/operations.py", line 366, in run
│     raise RemoteException(error_msg)
│ RemoteException("Non-zero return code (32) running 'lsblk -rndo fstype /dev/sda' on '1.2.3.4':\n\nlsblk: /dev/sda: not a block device\n\n\n")
╵

Would this be better?

[Kunsi]

I'd really like to have the former, because i think that's where users expect to see the command that has been run. I'd imagine the latter leading to reports like "zpool list failed with this exception: ..."

The latter would definitely be an improvement over the current situation, but it's definitely not what i would want.