sd-log sometimes ingests logs as host

[eloquence]

As reported here and here, logs are sometimes ingested under the host directory instead of the VM's actual name, potentially due to a race condition. This may be limited to the sd-whonix VM.

[eloquence]

(Bumping priority as these test failures have caused significant confusion.)

[eloquence]

I'll take a 4 hour timebox against this issue during the 9/17-10/1 sprint; self-assigning accordingly.

[eloquence]

Started on a timebox today. In my staging env, I found a host dir that was last written to on September 11, but currently sd-whonix correctly logs into its directory on sd-log. Repeatedly restarting so far has not yielded a repro. Could be an issue at provisioning-time where, once correctly provisioned, it works as expected.

[conorsch]

Could be an issue at provisioning-time where, once correctly provisioned, it works as expected.

That's right, it'll be a first-run problem, specific to the Whonix Gateway VM. If you inspect the logs available in sd-log:QubesIncomingLogs/host/*, you should see tor-related messaging. More research required to sort out whether it's whonix-gw-15 (TemplateVM) or sd-whonix (AppVM) that's briefly misconfigured at install time.

[eloquence]

I reprovisioned my staging environment and observed the logs carefully. The host log dir was getting populated with sd-whonix logs during the "Provision all SecureDrop Workstation VMs" stage. However, I see host getting written to after every restart of sd-whonix as well, well after provisioning, regardless of the template boot status. More on that below.

whonix-gw-15 does not get logged at all (running logger in the template does not result in any logs being written in sd-log). It's not tagged with sd-workstation, but our RPC policies require this tag to be set:

https://github.com/freedomofpress/securedrop-workstation/blob/main/dom0/sd-log.sls#L50-L51

I'm assuming that's the desired behavior given that we generally are more interested in AppVM logs than TemplateVM logs. As far as I can tell, it's only the RPC policies that prevent whonix-gw-15 logs from being sent to sd-log, otherwise it would be happily ingesting those logs as host as well.

Regarding the writes to host on VM boot of sd-whonix, that's consistent with what I would expect given the logic here:
https://github.com/freedomofpress/securedrop-workstation/blob/main/dom0/sd-logging-setup.sls#L65-L96

This logic works via rc.local, so it won't have run yet during the earlier runlevels. So it makes sense to me that the VM name would initially still be host in the logs, and only later be populated correctly.

Here, it seems we can decide to either use a different strategy to provision the configuration (I don't fully understand why it's not done in the template), or we could just have sd-log refuse logs with an invalid VM name, which would mean that we miss those early runlevel logs. Does that make sense?

[eloquence]

@conorsch and I just talked this through. There seems to be indeed limited value in aggregating logs from whonix-gw-15, so for now we'd suggest no change to get it to log.

With that in mind, it seems reasonable (the best of multiple not-great options) to set the localvm name for logging purposes to sd-whonix in the template instead of relying on /rw/config, since there's only one sd-workstation tagged AppVM based on that template. Will give that a try. The fallback option would be to add mapping to the logging tool itself, to ensure it always logs host to sd-whonix.