Split-gpg2: NotImplementedError

Euwiiwueir · July 11, 2024, 1:18am

I’m setting up split-gpg2 and seemingly have it working in that a client VM can run gpg --list-secret-keys and it will return my key.

Great! However, in my server VM I see this pop out of journalctl -f each time I run gpg --list-secret-keys in a client:

servervm qubes.Gpg2+-clientvm[1120]: Traceback (most recent call last):
servervm qubes.Gpg2+-clientvm[1120]:   File "<frozen runpy>", line 198, in _run_module_as_main
servervm qubes.Gpg2+-clientvm[1120]:   File "<frozen runpy>", line 88, in _run_code
servervm qubes.Gpg2+-clientvm[1120]:   File "/usr/lib/python3/dist-packages/splitgpg2/__main__.py", line 3, in <module>
servervm qubes.Gpg2+-clientvm[1120]:     main()
servervm qubes.Gpg2+-clientvm[1120]:   File "/usr/lib/python3/dist-packages/splitgpg2/__init__.py", line 1457, in main
servervm qubes.Gpg2+-clientvm[1120]:     loop.run_until_complete(server.run())
servervm qubes.Gpg2+-clientvm[1120]:   File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete
servervm qubes.Gpg2+-clientvm[1120]:     return future.result()
servervm qubes.Gpg2+-clientvm[1120]:            ^^^^^^^^^^^^^^^
servervm qubes.Gpg2+-clientvm[1120]:   File "/usr/lib/python3/dist-packages/splitgpg2/__init__.py", line 426, in run
servervm qubes.Gpg2+-clientvm[1120]:     await self.client_writer.wait_closed()
servervm qubes.Gpg2+-clientvm[1120]:   File "/usr/lib/python3.11/asyncio/streams.py", line 350, in wait_closed
servervm qubes.Gpg2+-clientvm[1120]:     await self._protocol._get_close_waiter(self)
servervm qubes.Gpg2+-clientvm[1120]:           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
servervm qubes.Gpg2+-clientvm[1120]:   File "/usr/lib/python3.11/asyncio/streams.py", line 178, in _get_close_waiter
servervm qubes.Gpg2+-clientvm[1120]:     raise NotImplementedError
servervm qubes.Gpg2+-clientvm[1120]: NotImplementedError

If you are using split-gpg2, do you see this in your server VM journal also?

Euwiiwueir · August 5, 2024, 6:24pm

For posterity: I opened an issue for this:

github.com/QubesOS/qubes-issues

`split-gpg2`: `NotImplementedError` in logs

opened 06:21PM - 05 Aug 24 UTC

Euwiiwueir

T: bug P: default

[How to file a helpful issue](https://www.qubes-os.org/doc/issue-tracking/) #…## Qubes OS release 4.2 Debian 12 templates ### Brief summary In attempting to set up `split-gpg2` I noticed this pattern logged in `journalctl`: ``` servervm qubes.Gpg2+-clientvm[1120]: Traceback (most recent call last): servervm qubes.Gpg2+-clientvm[1120]: File "<frozen runpy>", line 198, in _run_module_as_main servervm qubes.Gpg2+-clientvm[1120]: File "<frozen runpy>", line 88, in _run_code servervm qubes.Gpg2+-clientvm[1120]: File "/usr/lib/python3/dist-packages/splitgpg2/__main__.py", line 3, in <module> servervm qubes.Gpg2+-clientvm[1120]: main() servervm qubes.Gpg2+-clientvm[1120]: File "/usr/lib/python3/dist-packages/splitgpg2/__init__.py", line 1457, in main servervm qubes.Gpg2+-clientvm[1120]: loop.run_until_complete(server.run()) servervm qubes.Gpg2+-clientvm[1120]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete servervm qubes.Gpg2+-clientvm[1120]: return future.result() servervm qubes.Gpg2+-clientvm[1120]: ^^^^^^^^^^^^^^^ servervm qubes.Gpg2+-clientvm[1120]: File "/usr/lib/python3/dist-packages/splitgpg2/__init__.py", line 426, in run servervm qubes.Gpg2+-clientvm[1120]: await self.client_writer.wait_closed() servervm qubes.Gpg2+-clientvm[1120]: File "/usr/lib/python3.11/asyncio/streams.py", line 350, in wait_closed servervm qubes.Gpg2+-clientvm[1120]: await self._protocol._get_close_waiter(self) servervm qubes.Gpg2+-clientvm[1120]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ servervm qubes.Gpg2+-clientvm[1120]: File "/usr/lib/python3.11/asyncio/streams.py", line 178, in _get_close_waiter servervm qubes.Gpg2+-clientvm[1120]: raise NotImplementedError servervm qubes.Gpg2+-clientvm[1120]: NotImplementedError ``` (The logging above comes from the server VM journal but it's also logged in the client VM under the `split-gpg2-client.service` unit.) Having stepped through the code, I think it's probably innocuous, as it occurs during cleanup. But it is alarming logging coming from security-related software so it should probably be fixed. The cause seems to be: * `asyncio.streams.FlowControlMixin` protocol [instantiated here](https://github.com/QubesOS/qubes-app-linux-split-gpg2/blob/f121711039c8ba0c9dd54b4bf1a7b09d9c741912/splitgpg2/__init__.py#L1408) * Later, the writer owning the protocol is instructed to close [here](https://github.com/QubesOS/qubes-app-linux-split-gpg2/blob/f121711039c8ba0c9dd54b4bf1a7b09d9c741912/splitgpg2/__init__.py#L426) * This initiates a call on the protocol to an internal `_get_close_waiter()` function which is "implemented" on `asyncio.streams.FlowControlMixin` like so: ``` def _get_close_waiter(self, stream): raise NotImplementedError ``` At least, this is my best understanding. I [posted about this on the forum](https://forum.qubes-os.org/t/split-gpg2-notimplementederror/27558) but got no other reports, therefore I'm not super confident it shows up for other users. ### Steps to reproduce Install and set up `split-gpg2` on a server and client, attempt to sign something on the client, then check the logs. ### Expected behavior No logging ### Actual behavior Scary logging

boreas · August 6, 2024, 6:43am

I tested it with qubes-gpg-client --list-secret-keys and it works fine for me. Also no scary log message… strange…

Euwiiwueir · August 6, 2024, 3:02pm

Thanks, that is interesting. If you don’t mind sharing, what base template do you use for the vault?

solene · August 8, 2024, 8:19am

nothing either, I’m using a fedora-39 for both the gpg client and the gpg vault

Euwiiwueir · August 8, 2024, 3:13pm

Thanks. It’ll be a little while before I can look into this again but next I’ll try to reproduce the logging w/ a Fedora template.

boreas · August 9, 2024, 8:45pm

my template is debian 12, also for both