Logging

[redshiftzero]

We should make sure we have logging for audit and debugging purposes. It's quite common that admins will encounter an issue with their SecureDrop servers and we ask them to ship us their logs so we can figure out what is going wrong. Having robust logging on the workstations will help them and us debug.

Examples of kinds of events we should log:

• Failures in provisioning
• Successful provisioning
• Reprovisioning of particular VMs after an update
• Failures in decryption

As a rule of thumb, whenever we are creating notifications via notify-send, we should also log them.

Given that we have multiple VMs, I think a reasonable zeroth order approach for 3.2 would be to have logs stored in each persistent VM and dom0.

[redshiftzero]

In the design described in #88, maybe it would make sense to have two logs, one in dom0 for SecureDrop provisioning issues (related: #51) - this action would be something done by the Administrator - and one in the primary UI VM sd-svs:

I think it makes sense for feedback from submission processing to get passed up to sd-svs (instead of sd-journalist since sd-svs is where the UI will be) and then users if they encounter issues can send logs to their Admin, FPF or community support (perhaps there could be something in the UI that does precisely this).

[redshiftzero]

See also this Qubes GSoC idea: LogVMs

[redshiftzero]

a first step here is trying out the qubes.AppendLog service and seeing if it suffices for our centralized logging needs: QubesOS/qubes-issues#2023

[eloquence]

During the 10/23-11/6 sprint, @kushaldas will investigate the AppendLog functionality and report findings here.

[kushaldas]

The qubes.AppendLog service is not implemented yet. After reading through all the logs, I think nearest things we can do:

1st way

• Have our own internal queue in each vm to send loglines to another vm via a new qrexec system

2nd way

• Have our client tool + proxy + any required tool to write to journald (I have Python example ready)
• Have a secondary service to monitor journald and then send out qrexec based calls and loglines to a vm.

Option 1 should be easier I think (to maintain).

[redshiftzero]

did you see this (QubesOS/qubes-builder@58c8c0f#diff-ff568c8fe1b2773b0eed83aae8180c7d is what closed the above qubes.AppendLog ticket I linked to): https://github.com/QubesOS/qubes-builder/blob/master/rpc-services/qubesbuilder.BuildLog ?

[kushaldas]

did you see this (QubesOS/qubes-builder@58c8c0f#diff-ff568c8fe1b2773b0eed83aae8180c7d is what closed the above qubes.AppendLog ticket I linked to): https://github.com/QubesOS/qubes-builder/blob/master/rpc-services/qubesbuilder.BuildLog ?

Yes, and that is a workaround to move logs from one vm to dom0 for build system. The actual AppendLog was never implemented (which was supposed to be done as part of GSoC effort).

If this way to bring in temporary log is good enough for our usecase, we can do similar thing.

[marmarek]

More info about qubesbuilder.BuildLog: https://github.com/QubesOS/qubes-infrastructure/ (see README)

[kushaldas]

oqubeslogging provides a PoC Python logging handler, which can be used by our Python client to send logs to a logging vm (or dom0 if we want). Example code is in README and also in the repo.

We can also have a Python (adding the example to the same repo later tonight) code based systemd service to log journalctl entries into the logging vm.

I will be discussing more during our Engineering meeting today.

[eloquence]

During the 11/6-11/20 sprint, @redshiftzero will review Kushal's proof-of-concept and offer a technical proposal for how to proceed; this work is time-boxed to 4 hours.

[redshiftzero]

@kushaldas great work! some questions/thoughts on the implementation:

1. we should make the Singleton class thread safe since we're going to use it in a multi-threaded application (securedrop-client)
2. I was looking at the logging.StreamHandler implementation, and in its emit method there's exception handling, any reason not to add to OQubesLog.emit also?
3. this is kind of an edge case (at least for us since we're logging to a single VM): I suspect it's going to be surprising to devs that once the OQubesLog instance is created with e.g. args name1 and logvmname1, if a developer calls OQubesLog with different args (i.e. name2 and logvmname2), they’ll get the instance corresponding to the first name1 and logvmname1 from when OQubesLog was created - I thought I’d mention it in case you considered this / have any ideas (maybe raise an exception if the dev tries to instantiate with different args?)
4. nit: we can snip out any python 2 logic (I realize this is from qubesbuilder.BuildLog)

some immediate next steps is in the PR #340 which adds a log VM for using this service, check it out and let me know your thoughts

[kushaldas]

@redshiftzero I will go through #340 and reply. This was a PoC and I will address all 4 questions above in the updated implementation.

[eloquence]

For the 11/20-12/4 sprint, we've agreed that Kushal will address Jen's comments above:
#19 (comment)
in the existing implementation. Once that is done, we've committed to attempting to package this implementation, and to finish the WIP PR that integrates it using a centralized logging VM:

#340

[kushaldas]

@kushaldas great work! some questions/thoughts on the implementation:

I tried to solve 2,3,4. Code is in master.

I was trying a few ways to check for threading related issues. Because in our particular case, all the threads will be Qt threads (not normal Python threads), we can just mark all of those logging calls from the threads as signals which will go to a central slot, where we will do the actual logging.

Or we can continue with the current design and see the actual errors (if any).

[redshiftzero]

excellent, your changes lgtm - what do you think about kushaldas/oqubeslogging#1 for handling issue 1?