features/support/hooks.rb

   1 require 'fileutils'
   2 require 'rb-inotify'
   3 require 'time'
   4 require 'tmpdir'
   5 require "#{GIT_DIR}/features/support/monkeypatches/extra_hooks.rb"
   6
   7 # Run once, before any feature
   8 AfterConfiguration do |config|
   9   puts("Cucumber tags: #{config.tag_expressions}")
  10
  11   # We'll need access to cucumber's options in some places where
  12   # @__cucumber_runtime (which has a reference to it) is awkward to
  13   # access, so we make a global reference to them for those
  14   # situations.
  15   # Note that we use `instance_variable_get` to work around this
  16   # warning:
  17   #
  18   #     Deprecated: Configuration#options will be removed from the
  19   #     next release of Cucumber. Please use the configuration object
  20   #     directly instead.
  21   #
  22   # We'll revisit what to do then.
  23   $cucumber_options = config.instance_variable_get('@options')
  24
  25   # Reorder the execution of some features. As we progress through a
  26   # run we accumulate more and more snapshots and hence use more and
  27   # more disk space, but some features will leave nothing behind
  28   # and/or possibly use large amounts of disk space temporarily for
  29   # various reasons. By running these first we minimize the amount of
  30   # disk space needed.
  31   prioritized_features = [
  32     # Features not using snapshots but using large amounts of scratch
  33     # space for other reasons:
  34     'features/untrusted_partitions.feature',
  35     # Features using temporary snapshots:
  36     'features/root_access_control.feature',
  37     'features/time_syncing.feature',
  38     'features/tor_bridges.feature',
  39     # Features using large amounts of scratch space for other reasons:
  40     'features/erase_memory.feature',
  41     # This feature needs the almost biggest snapshot (USB install,
  42     # excluding persistence) and will create yet another disk and
  43     # install Tails on it. This should be the peak of disk usage.
  44     'features/usb_install.feature',
  45     # This feature uses a few temporary snapshots, a network-enabled
  46     # snapshot, and a large disk.
  47     'features/additional_software_packages.feature',
  48     # This feature needs a copy of the ISO and creates a new disk.
  49     'features/usb_upgrade.feature',
  50     # This feature needs a very big snapshot (USB install with persistence)
  51     # and another, network-enabled snapshot.
  52     'features/emergency_shutdown.feature',
  53   ]
  54   feature_files = config.feature_files
  55   # The &-intersection is specified to keep the element ordering of
  56   # the *left* operand.
  57   intersection = prioritized_features & feature_files
  58   unless intersection.empty?
  59     feature_files -= intersection
  60     feature_files = intersection + feature_files
  61     config.define_singleton_method(:feature_files) { feature_files }
  62   end
  63
  64   # Used to keep track of when we start our first @product feature, when
  65   # we'll do some special things.
  66   $started_first_product_feature = false
  67
  68   if File.exist?($config['TMPDIR'])
  69     unless File.directory?($config['TMPDIR'])
  70       raise "Temporary directory '#{$config['TMPDIR']}' exists but is not a " \
  71             'directory'
  72     end
  73     unless File.owned?($config['TMPDIR'])
  74       raise "Temporary directory '#{$config['TMPDIR']}' must be owned by the " \
  75             'current user'
  76     end
  77     FileUtils.chmod(0o755, $config['TMPDIR'])
  78   else
  79     begin
  80       FileUtils.mkdir_p($config['TMPDIR'])
  81     rescue Errno::EACCES => e
  82       raise "Cannot create temporary directory: #{e}"
  83     end
  84   end
  85
  86   if config_bool('INTERACTIVE_DEBUGGING')
  87     # This module extends exceptions so they contain the stack of
  88     # bindings for all callers from the point that it was raised,
  89     # which we use to restore the context of the failure when
  90     # --interactive-debugging is enabled.
  91     # BTW, upstream renamed the module to skiptrace five years ago but
  92     # hasn't done any release since then.
  93     require 'bindex'
  94   end
  95 end
  96
  97 # Common
  98 ########
  99
 100 After do
 101   @after_scenario_hooks&.each(&:call)
 102   @after_scenario_hooks = []
 103 end
 104
 105 BeforeFeature('@product', '@source') do |feature|
 106   raise "Feature #{feature.file} is tagged both @product and @source, " \
 107         'which is an impossible combination'
 108 end
 109
 110 at_exit do
 111   $vm&.destroy_and_undefine
 112   if $virt
 113     unless KEEP_SNAPSHOTS
 114       VM.remove_all_snapshots
 115       $vmstorage&.clear_pool
 116     end
 117     $vmnet&.destroy_and_undefine
 118     $virt.close
 119   end
 120   # The artifacts directory is empty (and useless) if it contains
 121   # nothing but the mandatory . and ..
 122   FileUtils.rmdir(ARTIFACTS_DIR) if Dir.entries(ARTIFACTS_DIR).size <= 2
 123 end
 124
 125 # For @product tests
 126 ####################
 127
 128 def add_after_scenario_hook(&block)
 129   @after_scenario_hooks ||= []
 130   @after_scenario_hooks << block
 131 end
 132
 133 def save_failure_artifact(desc, path, suffix: nil)
 134   suffix ||= File.extname(path)
 135   $failure_artifacts << [desc, path, suffix]
 136 end
 137
 138 def record_scenario_skipped(scenario)
 139   destfile = "#{ARTIFACTS_DIR}/skipped.txt"
 140   File.open(destfile, 'a') { |f| f.write("#{scenario.location}\n") }
 141 end
 142
 143 def _save_vm_file_content(file:, destfile:, suffix:, desc:)
 144   destfile = "#{$config['TMPDIR']}/#{destfile}"
 145   File.open(destfile, 'w') { |f| f.write($vm.file_content(file)) }
 146   save_failure_artifact(desc, destfile, suffix:)
 147 rescue StandardError => e
 148   info_log("Exception thrown while trying to save #{destfile}: " \
 149            "#{e.class.name}: #{e}")
 150 end
 151
 152 def save_vm_command_output(command:, id:, suffix: nil, desc: nil) # rubocop:disable Naming/MethodParameterName
 153   suffix ||= ".cmd_output_#{id}"
 154   basename = "artifact#{suffix}"
 155   $vm.execute("#{command} > /tmp/#{basename} 2>&1")
 156   _save_vm_file_content(
 157     file:     "/tmp/#{basename}",
 158     destfile: basename,
 159     suffix:,
 160     desc:     desc || "Output of #{command}"
 161   )
 162 end
 163
 164 def save_journal
 165   save_failure_artifact(
 166     'systemd Journal',
 167     JournalDumper.instance.path,
 168     suffix: '.journal'
 169   )
 170 end
 171
 172 def save_vm_file_content(file, desc: nil, suffix: nil)
 173   suffix ||= ".file_content_#{file.gsub('/', '_').sub(/^_/, '')}"
 174   _save_vm_file_content(
 175     file:,
 176     destfile: "artifact#{suffix}",
 177     suffix:,
 178     desc:     desc || "Content of #{file}"
 179   )
 180 end
 181
 182 def save_boot_log
 183   save_vm_file_content('/var/log/boot.log', desc: 'Boot log')
 184 end
 185
 186 # Due to Tails' Tor enforcement, we only allow contacting hosts that
 187 # are Tor nodes, located on the LAN, or allowed for some operational reason.
 188 # However, when we try to verify that only such hosts are contacted we have
 189 # a problem -- we run all Tor nodes (via Chutney) *and* LAN hosts (used on
 190 # some tests) on the same host, the one running the test suite. Hence we
 191 # need to always explicitly track which nodes are allowed or not.
 192 #
 193 # Warning: when a host is added via this function, it is only added
 194 # for the current scenario. As such, if this is done before saving a
 195 # snapshot, it will not remain after the snapshot is loaded.
 196 def add_extra_allowed_host(ipaddr, port)
 197   @extra_allowed_hosts ||= []
 198   @extra_allowed_hosts << { address: ipaddr, port: }
 199 end
 200
 201 def add_dns_to_extra_allowed_host
 202   # Allow connections to the local DNS resolver
 203   add_extra_allowed_host($vmnet.bridge_ip_addr, 53)
 204 end
 205
 206 BeforeFeature('@product') do
 207   images = { 'ISO' => TAILS_ISO, 'IMG' => TAILS_IMG }
 208   images.each do |type, path|
 209     if path.nil?
 210       raise "No Tails #{type} image specified, and none could be found " \
 211             'in the current directory'
 212     end
 213
 214     unless File.exist?(path)
 215       raise "The specified Tails #{type} image '#{path}' does not exist"
 216     end
 217
 218     if File.directory?(path)
 219       raise "The specified Tails #{type} image '#{path}' is a directory"
 220     end
 221
 222     # Workaround: when libvirt takes ownership of the ISO/IMG image it may
 223     # become unreadable for the live user inside the guest in the
 224     # host-to-guest share used for some tests.
 225
 226     unless File.world_readable?(path)
 227       if File.owned?(path)
 228         File.chmod(0o644, path)
 229       else
 230         raise "warning: the Tails #{type} image must be world readable " \
 231               'or be owned by the current user to be available inside ' \
 232               'the guest VM via host-to-guest shares, which is required ' \
 233               'by some tests'
 234       end
 235     end
 236   end
 237   unless File.exist?(OLD_TAILS_ISO)
 238     raise "The specified old Tails ISO image '#{OLD_TAILS_ISO}' does not exist"
 239   end
 240   unless File.exist?(OLD_TAILS_IMG)
 241     raise "The specified old Tails IMG image '#{OLD_TAILS_IMG}' does not exist"
 242   end
 243
 244   unless $started_first_product_feature
 245     $virt = Libvirt.open('qemu:///system')
 246     VM.remove_all_snapshots unless KEEP_SNAPSHOTS
 247     $vmnet = VMNet.new($virt, VM_XML_PATH)
 248     $vmstorage = VMStorage.new($virt, VM_XML_PATH)
 249     $started_first_product_feature = true
 250   end
 251   initialize_chutney unless config_bool('DISABLE_CHUTNEY')
 252 end
 253
 254 AfterFeature('@product') do
 255   unless KEEP_SNAPSHOTS
 256     CHECKPOINTS
 257       .select   { |name, vals| vals[:temporary] && VM.snapshot_exists?(name) }
 258       .each_key { |name| VM.remove_snapshot(name) }
 259   end
 260   $vmstorage
 261     .list_volumes
 262     .reject { |vol_name| vol_name == '__internal' }
 263     .each   { |vol_name| $vmstorage.delete_volume(vol_name) }
 264 end
 265
 266 # Cucumber Before hooks are executed in the order they are listed, and
 267 # we want this hook to always run first, so it must always be the
 268 # *first* Before hook matching @product listed in this file.
 269 Before('@product') do |scenario|
 270   $failure_artifacts = []
 271   if config_bool('CAPTURE')
 272     video_name = sanitize_filename("#{scenario.name}.mkv")
 273     @video_path = "#{ARTIFACTS_DIR}/#{video_name}"
 274     debug_log("Starting video capture of '#{@video_path}'")
 275     capture = IO.popen(['ffmpeg',
 276                         '-f', 'x11grab',
 277                         '-s', '1024x768',
 278                         '-r', '15',
 279                         '-i', "#{$config['DISPLAY']}.0",
 280                         '-an',
 281                         '-c:v', 'libx264',
 282                         '-y',
 283                         @video_path,
 284                         { err: ['/dev/null', 'w'] },])
 285     @video_capture_pid = capture.pid
 286   end
 287   @screen = if config_bool('IMAGE_BUMPING_MODE')
 288               ImageBumpingScreen.new
 289             else
 290               Screen.new
 291             end
 292   # English will be assumed if this is not overridden
 293   $language = ''
 294   $lang_code = ''
 295   @os_loader = 'MBR'
 296   # Passwords includes shell-special chars (space, "!")
 297   # as a regression test for #17792
 298   @sudo_password = 'asdf !'
 299   @persistence_password = 'asdf !'
 300   @changed_persistence_password = 'foo123'
 301   @has_been_reset = false
 302   # See comment for add_extra_allowed_host() above.
 303   @extra_allowed_hosts ||= []
 304
 305   @user_wants_pluggable_transports = false
 306   @tor_network_is_blocked = false
 307 end
 308
 309 # Cucumber After hooks are executed in the *reverse* order they are
 310 # listed, and we want this hook to always run second last, so it must always
 311 # be the *second* After hook matching @product listed in this file --
 312 # hooks added dynamically via add_after_scenario_hook() are supposed to
 313 # truly be last.
 314 # rubocop:disable Metrics/BlockNesting
 315 After('@product') do |scenario|
 316   # we want this to always exist, even if it's empty
 317   FileUtils.touch("#{ARTIFACTS_DIR}/skipped.txt")
 318
 319   if @video_capture_pid
 320     # We can be incredibly fast at detecting errors sometimes, so the
 321     # screen barely "settles" when we end up here and kill the video
 322     # capture. Let's wait a few seconds more to make it easier to see
 323     # what the error was.
 324     sleep 3 if scenario.failed?
 325     debug_log("Stopping video capture of '#{@video_path}'")
 326     Process.kill('INT', @video_capture_pid)
 327     Process.wait(@video_capture_pid)
 328     save_failure_artifact('Video', @video_path)
 329   end
 330   if scenario.failed?
 331     time_of_fail = Time.now - TIME_AT_START
 332     secs = format('%<secs>02d', secs: time_of_fail % 60)
 333     mins = format('%<mins>02d', mins: (time_of_fail / 60) % 60)
 334     hrs  = format('%<hrs>02d',  hrs: time_of_fail / (60 * 60))
 335     elapsed = "#{hrs}:#{mins}:#{secs}"
 336     info_log("SCENARIO FAILED: '#{scenario.name}' (at time #{elapsed})")
 337     save_journal
 338     unless $vm.display.nil?
 339       screenshot_path = sanitize_filename("#{scenario.name}.png")
 340       $vm.display.screenshot(screenshot_path)
 341       save_failure_artifact('Screenshot', screenshot_path)
 342     end
 343     if scenario.exception.is_a?(FirewallAssertionFailedError)
 344       Dir.glob("#{$config['TMPDIR']}/*.pcap").each do |pcap_file|
 345         save_failure_artifact('Network capture', pcap_file)
 346       end
 347     elsif scenario.exception.is_a?(TestSuiteRuntimeError)
 348       info_log("Scenario must be retried: #{scenario.name}")
 349       record_scenario_skipped(scenario)
 350     elsif [TorBootstrapFailure, TimeSyncingError].any? \
 351           { |c| scenario.exception.is_a?(c) }
 352       if File.exist?("#{$config['TMPDIR']}/chutney-data")
 353         chutney_logs = sanitize_filename(
 354           "#{elapsed}_#{scenario.name}_chutney-data"
 355         )
 356         FileUtils.mkdir("#{ARTIFACTS_DIR}/#{chutney_logs}")
 357         FileUtils.rm(Dir.glob("#{$config['TMPDIR']}/chutney-data/**/control"))
 358         begin
 359           FileUtils.copy_entry(
 360             "#{$config['TMPDIR']}/chutney-data",
 361             "#{ARTIFACTS_DIR}/#{chutney_logs}"
 362           )
 363         rescue StandardError => e
 364           info_log("Failed to copy Chutney data: #{e}")
 365         end
 366         info_log
 367         info_log_artifact_location(
 368           'Chutney logs',
 369           "#{ARTIFACTS_DIR}/#{chutney_logs}"
 370         )
 371       else
 372         info_log('Found no Chutney data')
 373       end
 374
 375       if $vm&.remote_shell_is_up?
 376         save_tor_journal
 377         save_failure_artifact('Tor logs', "#{$config['TMPDIR']}/log.tor")
 378         if $vm.file_exist?('/var/lib/tor/pt_state/obfs4proxy.log')
 379           File.open("#{$config['TMPDIR']}/log.obfs4proxy", 'w') do |f|
 380             f.write($vm.file_content('/var/lib/tor/pt_state/obfs4proxy.log'))
 381           end
 382           save_failure_artifact('obfs4proxy logs',
 383                                 "#{$config['TMPDIR']}/log.obfs4proxy")
 384         end
 385
 386         if scenario.exception.instance_of?(HtpdateError)
 387           content = if $vm.file_exist?('/var/log/htpdate.log')
 388                       $vm.file_content('/var/log/htpdate.log')
 389                     else
 390                       "The htpdate logs did not exist\n"
 391                     end
 392           File.write("#{$config['TMPDIR']}/log.htpdate", content)
 393           save_failure_artifact('Htpdate logs', "#{$config['TMPDIR']}/log.htpdate")
 394         end
 395       end
 396     end
 397     # Note that the remote shell isn't necessarily running at all
 398     # times a scenario can fail (and a scenario failure could very
 399     # well cause the remote shell to not respond any more, e.g. when
 400     # we cause a system crash), so let's collect everything depending
 401     # on the remote shell here:
 402     if $vm&.remote_shell_is_up?
 403       save_boot_log
 404       if scenario.feature.file \
 405          == 'features/additional_software_packages.feature'
 406         save_vm_command_output(
 407           command: 'ls -lAR --full-time /var/cache/apt',
 408           id:      'var_cache_apt'
 409         )
 410         save_vm_command_output(
 411           command: 'ls -lAR --full-time /var/lib/apt',
 412           id:      'var_lib_apt'
 413         )
 414         save_vm_command_output(
 415           command: 'mount',
 416           id:      'mount'
 417         )
 418         # When removing the logging below, also revert commit
 419         # c8429eecf23570274b0bb2134a87ae1fcf72ce07
 420         save_vm_command_output(
 421           command: 'ls -lA --full-time /live/persistence/TailsData_unlocked',
 422           id:      'persistent_volume'
 423         )
 424         save_vm_file_content('/run/live-additional-software/log')
 425       end
 426     end
 427     # We give JournalDumper a little time to receive the journal
 428     # entries for any remote shell interactions above before stopping
 429     # it and saving the journal.
 430     sleep 1
 431     JournalDumper.instance.stop
 432     $failure_artifacts.sort!
 433     $failure_artifacts.each do |desc, file, suffix|
 434       artifact_name = sanitize_filename(
 435         "#{elapsed}_#{scenario.name}#{suffix}"
 436       )
 437       artifact_path = "#{ARTIFACTS_DIR}/#{artifact_name}"
 438       assert(File.exist?(file))
 439       FileUtils.mv(file, artifact_path)
 440       info_log
 441       info_log_artifact_location(desc, artifact_path)
 442     end
 443     if config_bool('INTERACTIVE_DEBUGGING')
 444       pause(
 445         "Scenario failed: #{scenario.name}. " \
 446         "The error was: #{scenario.exception.class.name}: #{scenario.exception}",
 447         exception: scenario.exception
 448       )
 449     end
 450   elsif @video_path && File.exist?(@video_path) && !config_bool('CAPTURE_ALL')
 451     FileUtils.rm(@video_path)
 452   end
 453 ensure
 454   # If there are uncaught exceptions during the After hook (which
 455   # happens sometimes, e.g. if the remote shell crashes) we still want
 456   # to ensure that we do the things necessary to prevent leftovers
 457   # from this scenario to interfere with the next scenario. Here we
 458   # take extra care to prevent uncaught exceptions so as many of these
 459   # are run as possible.
 460
 461   begin
 462     # We don't want a stray JournalDumper thread from a previous
 463     # scenario interfering with a new thread it starts for a
 464     # subsequent scenario.
 465     JournalDumper.instance.stop
 466   rescue StandardError
 467     # At least we tried!
 468   end
 469
 470   begin
 471     if $vm&.remote_shell_is_up?
 472       # We gracefully stop tor in order to make the bridges/guards not
 473       # keep sending packets that has a potential to bleed into the
 474       # next scenario. It has been observed that this can cause the
 475       # system under testing to send a TCP RST to the bridge/guard,
 476       # which then may break the check that we only contact the
 477       # expected bridges/guards.
 478       $vm.execute('systemctl stop tor@default')
 479     end
 480   rescue StandardError
 481     # At least we tried!
 482   end
 483
 484   begin
 485     # If we don't shut down the system under testing it will continue to
 486     # run during the next scenario's Before hooks, which we have seen
 487     # causing trouble (for instance, packets from the previous scenario
 488     # have failed scenarios tagged @check_tor_leaks).
 489     $vm&.power_off
 490   rescue StandardError
 491     # At least we tried!
 492   end
 493 end
 494 # rubocop:enable Metrics/BlockNesting
 495
 496 Before('@product', '@check_tor_leaks') do |scenario|
 497   @tor_leaks_sniffer = Sniffer.new(sanitize_filename(scenario.name), $vmnet)
 498   @tor_leaks_sniffer.capture
 499   add_after_scenario_hook do
 500     @tor_leaks_sniffer.clear
 501   end
 502 end
 503
 504 After('@product', '@check_tor_leaks') do |scenario|
 505   @tor_leaks_sniffer.stop
 506   if scenario.passed?
 507     @allowed_dns_queries ||= []
 508
 509     allowed_nodes = @bridge_hosts || allowed_hosts_under_tor_enforcement
 510     allowed_nodes += @extra_allowed_hosts
 511     debug_log("[check_tor_leaks] Allowed hosts: #{allowed_nodes}")
 512     debug_log("[check_tor_leaks] Allowed DNS queries: #{@allowed_dns_queries}")
 513     assert_no_leaks(@tor_leaks_sniffer.pcap_file, allowed_nodes, @allowed_dns_queries)
 514   end
 515 end
 516
 517 # For @source tests
 518 ###################
 519
 520 # BeforeScenario
 521 Before('@source') do
 522   @orig_pwd = Dir.pwd
 523   @git_clone = Dir.mktmpdir 'tails-apt-tests'
 524   Dir.chdir @git_clone
 525 end
 526
 527 # AfterScenario
 528 After('@source') do |scenario|
 529   Dir.chdir @orig_pwd
 530   FileUtils.remove_entry_secure @git_clone
 531   if scenario.failed? && config_bool('INTERACTIVE_DEBUGGING')
 532     pause(
 533       "Scenario failed: #{scenario.name}. " \
 534       "The error was: #{scenario.exception.class.name}: #{scenario.exception}",
 535       exception: scenario.exception
 536     )
 537   end
 538 end