Tails

#4 Updated by segfault 2020-04-12 19:45:13

Ah I think this line explains why the packets are being dropped:

W: Download is performed unsandboxed as root as file '/var/lib/apt/lists/partial/ftp.us.debian.org_debian_dists_buster_InRelease' couldn't be accessed by user '_apt'. - pkgAcquire::Run (13: Permission denied)

The download is performed as root and not as _apt, and root is not on the white-list of users allowed to connect to 9050. Now we have to figure out why the file /var/lib/apt/lists/partial/ftp.us.debian.org_debian_dists_buster_InRelease exists and is owned by root.

#5 Updated by segfault 2020-04-12 19:56:57

> Now we have to figure out why the file /var/lib/apt/lists/partial/ftp.us.debian.org_debian_dists_buster_InRelease exists and is owned by root.

I suspect that during one of the previous scenarios which use persistence an apt update was not completed and left these partial lists there. I don’t know why they are owned by root and not by _apt when apt apparently expects them to be owned by _apt.

One way to solve this issue would be to allow root to connect to the Tor SOCKS port.

#9 Updated by intrigeri 2020-05-13 06:40:39

> Next step: in save_old_apt_lists, I’ll try replacing shutil.copytree with cp --archive.

I’ve done this on the bugfix/17278-fix-additional-software-intrigeri branch.

Here’s an analysis of test suite runs 3-16 (13 runs):

• 10 runs out of 13 passed, which in itself is already better than what I see on other branches.
• run 16
  • “Scenario I set up Additional Software when installing a package without persistent partition and the package is installed next time I start Tails” fails on first reboot after setting up Additional Software. apt-get install fails with “E: Unable to parse package file /var/lib/apt/lists/ftp.us.debian.org_debian_dists_bullseye_main_i18n_Translation-en (1)”. The Journal does not include “Found a copy of old APT lists, restoring it”, which means we did not go through the code path I’ve modified during this boot. My hypotheses are:
    • Something else than our Additional Software code messed up with the lists during the previous or during this boot.
    • tails-synchronize-data-to-new-persistent-volume-on-shutdown.service did not do its job correctly before we rebooted last time
  • ACTION: set APT::Periodic::Enable "0"; to ensure apt-daily-upgrade.service is not messing with us (we’ve disabled apt-daily.service but apparently we missed apt-daily-upgrade.service when it was introduced)
  • ACTION: To debug this, on test failure I’d like to see:
    • the output of ls -lAR /var/lib/apt (I’m interested both in the lists and the periodic sub-directories)
    • the output of mount, to make sure the 2 persistent APT directories are mounted
    • the content of /var/log/live-persist, to give us more info in case one persistent APT directory was not mounted
    • Have tails-synchronize-data-to-new-persistent-volume-on-shutdown.service create a flag file in the persistent volume after completion, so during next boot we can tell whether it did its job.
  • The next scenarios fail in the exact same way, for the exact same reason.
• run 13
  • “Scenario I am warned I can not use Additional Software when I start Tails from a DVD and install a package” fails to sync the clock, before it even reached steps related to Additional Software. The htpdate log suggests that lizard had networking issues at the time, which happens regularly since a few weeks.
  • The following scenarios fail in the same way as run 16, modulo the error message is “E: Unable to parse package file /var/lib/apt/lists/ftp.us.debian.org_debian_dists_sid_main_binary-amd64_Packages (1)”.
• run 12
  • “Scenario The Additional Software dpkg hook notices when persistence is locked down while installing a package” fails at step “the Additional Software dpkg hook has been run for package ”makepp" and notices the persistence is locked".
    • The debug log confirms that makepp was successfully installed. It took 35 seconds to install it though, which is very long for a small package that won’t pull in any new dependency.
    • /run/live-additional-software/log is not empty, but 2 minutes later the expected “New packages manually installed” log line has not appeared in that file. In the Journal I see no trace that apt_hook_pre or apt_hook_post have run, so I’m a little confused.
    • ACTION: on test failure, save the content of /run/live-additional-software/log

To sum up:

• The most common failure mode, that I’ve investigated yesterday, did not happen in 13 runs, and I could find no other failure that looks related to the tentative fix I’ve applied. This suggests I’ve fixed the worse failure mode.
• The corrupted APT packages list failure mode happened 2 times in 13 runs. That’s not great. It needs further investigation. See “ACTION” above for what I’d like to try next.
• The dpkg hook failure mode happened 1 time in 13 runs. I’m pretty sure this is an old problem, that happened before we filed this issue. I’m inclined to handle it separately, on a dedicated issue, if the single idea I have so far to investigate it does not hint us in the right direction.

#10 Updated by intrigeri 2020-05-13 09:03:24

> To sum up:
>
> * The most common failure mode, that I’ve investigated yesterday, did not happen in 13 runs, and I could find no other failure that looks related to the tentative fix I’ve applied. This suggests I’ve fixed the worse failure mode.

Before I ask a review’n’merge, I’ll wait for a few more test runs, which I’ll want to do anyway to debug the other 2 failure modes I’ve spotted:

> * The corrupted APT packages list failure mode happened 2 times in 13 runs. That’s not great. It needs further investigation. See “ACTION” above for what I’d like to try next.

I’ve implemented all these action items on my bugfix/17278-fix-additional-software-intrigeri branch.

> * The dpkg hook failure mode happened 1 time in 13 runs. I’m pretty sure this is an old problem, that happened before we filed this issue. I’m inclined to handle it separately, on a dedicated issue, if the single idea I have so far to investigate it does not hint us in the right direction.

My updated branch saves the content of /run/live-additional-software/log on failure, which might help investigating this one.

#11 Updated by intrigeri 2020-05-14 08:21:06

>> * The most common failure mode, that I’ve investigated yesterday, did not happen in 13 runs, and I could find no other failure that looks related to the tentative fix I’ve applied. This suggests I’ve fixed the worse failure mode.
>
> Before I ask a review’n’merge, I’ll wait for a few more test runs, which I’ll want to do anyway to debug the other 2 failure modes I’ve spotted:

This problem (“Download is performed unsandboxed as root”) happened again in test suite run 19.

I still think that commit:1b94f25ce5778d18b2370caa1161a771e44f305b fixes a real bug that can cause these symptoms, but thanks to the extra debugging info saved by the test suite on failure on my branch, I’ve found at least another bug that causes these symptoms. I now have evidence that tails-synchronize-data-to-new-persistent-volume-on-shutdown.service did not complete successfully:

• The apt_sync_started flag file exists but the apt_sync_completed one does not:
  • https://jenkins.tails.boum.org/job/test_Tails_ISO_bugfix-17278-fix-additional-software-intrigeri/19/artifact/build-artifacts/00%3A38%3A18_My_Additional_Software_list_is_configurable_through_a_GUI_or_through_notifications_when_I_install_or_remove_packages_with_APT_or_Synaptic.cmd_output_persistent_volume/*view*/
  • https://jenkins.tails.boum.org/job/test_Tails_ISO_bugfix-17278-fix-additional-software-intrigeri/22/artifact/build-artifacts/01%3A53%3A39_I_set_up_Additional_Software_when_installing_a_package_without_persistent_partition_and_the_package_is_installed_next_time_I_start_Tails.cmd_output_persistent_volume/*view*/
• The persistent /var/lib/apt/lists has mode 0700, while it should have mode 0755 (I suspect cp would set the permissions later, once it has finished copying the files into that directory):
  • https://jenkins.tails.boum.org/job/test_Tails_ISO_bugfix-17278-fix-additional-software-intrigeri/19/artifact/build-artifacts/00%3A38%3A18_My_Additional_Software_list_is_configurable_through_a_GUI_or_through_notifications_when_I_install_or_remove_packages_with_APT_or_Synaptic.cmd_output_var_lib_apt/*view*/
  • https://jenkins.tails.boum.org/job/test_Tails_ISO_bugfix-17278-fix-additional-software-intrigeri/22/artifact/build-artifacts/01%3A53%3A39_I_set_up_Additional_Software_when_installing_a_package_without_persistent_partition_and_the_package_is_installed_next_time_I_start_Tails.cmd_output_var_lib_apt/*view*/
• Some packages list files are smaller than expected (this does not cause “Download is performed unsandboxed as root” but instead “Package sslh is not available”):
  • https://jenkins.tails.boum.org/job/test_Tails_ISO_bugfix-17278-fix-additional-software-intrigeri/22/artifact/build-artifacts/01%3A53%3A39_I_set_up_Additional_Software_when_installing_a_package_without_persistent_partition_and_the_package_is_installed_next_time_I_start_Tails.cmd_output_var_lib_apt/*view*/ → the size of ftp.us.debian.org_debian_dists_buster_main_binary-amd64_Packages is 32MB while it should be 44MB

>> * The corrupted APT packages list failure mode happened 2 times in 13 runs. That’s not great. It needs further investigation. See “ACTION” above for what I’d like to try next.

I’m now convinced that these problems (“Unable to parse package file”) happen because indeed, we feed APT incomplete files. Sometimes these incomplete files still have a valid format and we see errors like “Package sslh is not available”, sometimes they’re simply invalid and we instead see errors like “Unable to parse package file”.

⇒ I’ll now focus on making tails-synchronize-data-to-new-persistent-volume-on-shutdown.service run in a robust manner.
I think I already know what’s happening.

>> * The dpkg hook failure mode happened 1 time in 13 runs. I’m pretty sure this is an old problem, that happened before we filed this issue. I’m inclined to handle it separately, on a dedicated issue, if the single idea I have so far to investigate it does not hint us in the right direction.
>
> My updated branch saves the content of /run/live-additional-software/log on failure, which might help investigating this one.

I’ll need more test runs to gather data about this rare problem.

#12 Updated by intrigeri 2020-05-14 09:46:17

> ⇒ I’ll now focus on making tails-synchronize-data-to-new-persistent-volume-on-shutdown.service run in a robust manner.
> I think I already know what’s happening.

I tried something (commit:d17e4c6d2f43e7e0fc50b7e88e4286dab238c048), but I’m wondering if my analysis is correct: even without this commit, I see that shutting down Tails after setting up persistence + Additional Software, i.e. when tails-synchronize-data-to-new-persistent-volume-on-shutdown.service actually does something, takes 30+ seconds, and I did not manage to make it fail on my laptop by rate limiting the virtual USB drive to 5 MB/s with this patch:

--- a/features/domains/disk.xml
+++ b/features/domains/disk.xml
@@ -2,4 +2,8 @@
<driver name='qemu' type=''/>
<source file=''/>
<target dev='' bus=''/>
+  <iotune>
+    <write_bytes_sec>5000000</write_bytes_sec>
+    <write_bytes_sec_max>5000000</write_bytes_sec_max>
+  </iotune>
</disk>

… while I expected this I/O rate limiting to be sufficient to trigger the bug.
So at the face of it, it does not look like DefaultTimeoutStopSec=5s is fully honored for this service, and perhaps something else than this timeout makes its ExecStop= abort early, I don’t know.
I’m a little bit confused. Let’s see how this commit impacts test results.

#13 Updated by intrigeri 2020-05-14 12:44:53

> I tried something (commit:d17e4c6d2f43e7e0fc50b7e88e4286dab238c048), but I’m wondering if my analysis is correct: even without this commit, I see that shutting down Tails after setting up persistence + Additional Software, i.e. when tails-synchronize-data-to-new-persistent-volume-on-shutdown.service actually does something, takes 30+ seconds, and I did not manage to make it fail on my laptop by rate limiting the virtual USB drive to 5 MB/s with this patch:
>
> […]
>
> … while I expected this I/O rate limiting to be sufficient to trigger the bug.
> So at the face of it, it does not look like DefaultTimeoutStopSec=5s is fully honored for this service, and perhaps something else than this timeout makes its ExecStop= abort early, I don’t know.
> I’m a little bit confused.

After running tests locally with and without this commit, passing noplash, with limited I/O write rate, and inspecting what I see on screen during system shutdown, I have a theory that can explain this:

1. Without this patch

• I think tails-synchronize-data-to-new-persistent-volume-on-shutdown.service starts doing stuff and is quickly killed: it does not even show up on screen when I do virsh send-key TailsToaster KEY_LEFTSHIFT KEY_PAGEUP. Depending on how fast the system is, during these 5s cp can have sent part, or all, of the data to the USB stick (or rather, to the kernel disk cache, really).
• Then, the mount unit for /media/tails-persistence-setup/TailsData (which has a much larger timeout) takes a while to stop: it effectively sync’s data to the USB stick, but only data that cp could already send to the kernel disk cache before it got killed. I see this stop job run for several minutes.
• The I/O rate limiting only impacts how much time the mount unit needs to sync’ the data cp had time to send. It does not impact (much?) how much of the data was sent.
• Success/failure rate is a function of the performance of the CPU. This explains why I never can reproduce this problem locally, while lizard regularly exposes it. To confirm this I would need to ask QEMU to make TailsToaster’s CPU slower, but at this point I’m a bit lazy. I may come back to this if actual test results on lizard still fail even with commit:d17e4c6d2f43e7e0fc50b7e88e4286dab238c048.

2. With this patch, I see A stop job is running for Synchronize data to newly created persistent volume on shutdown (Xs / 5min) run for several minutes — yeah!

> Let’s see how this commit impacts test results.

I’m now quite optimistic, but we’ll see.

#18 Updated by intrigeri 2020-05-15 10:02:40

Hi segfault, I’ve renamed your branch to wip/bugfix/17278-fix-additional-software, so it does not eat cycles on Jenkins: I believe we don’t need this workaround now that I’ve identified, and apparently fixed, the root cause of the problem.