Force full screen update shortly before check screen would fail

OpenQA/Benchmark/Stopwatch.pm

@@ -228,7 +228,7 @@ sub as_data ($self) {
 
         $running_total += $lapcopy{time};
         $lapcopy{cumulative} = $running_total;
-        $lapcopy{fraction} = $lapcopy{time} / $data{total_time};
+        $lapcopy{fraction} = $lapcopy{time} / $data{total_time} if $data{total_time};
 
         push @{$data{laps}}, \%lapcopy;
     }

backend/baseclass.pm

@@ -32,6 +32,9 @@ use Time::Seconds;
 use English -no_match_vars;
 use OpenQA::NamedIOSelect;
 
+use constant FULL_SCREEN_SEARCH_FREQUENCY => $ENV{OS_AUTOINST_FULL_SCREEN_SEARCH_FREQUENCY} // 5;
+use constant FULL_UPDATE_REQUEST_FREQUENCY => $ENV{OS_AUTOINST_FULL_UPDATE_REQUEST_FREQUENCY} // 5;
+
 # should be a singleton - and only useful in backend process
 our $backend;
 
@@ -679,8 +682,8 @@ sub load_console_snapshots ($self, $name) {
     }
 }
 
-sub request_screen_update ($self) {
-    return $self->bouncer('request_screen_update', undef);
+sub request_screen_update ($self, $args = undef) {
+    return $self->bouncer('request_screen_update', $args);
 }
 
 sub console ($self, $testapi_console) {
@@ -950,29 +953,23 @@ sub time_remaining_str ($time) {
     return sprintf("%.1fs", $time - 0.05);
 }
 
+sub _reset_asserted_screen_check_variables ($self) {
+    $self->{_final_full_update_requested} = 0;
+    $self->assert_screen_last_check(undef);
+}
+
 sub check_asserted_screen ($self, $args) {
-    my $img = $self->last_image;
-    return unless $img;    # no screenshot yet to search on
+    return unless my $img = $self->last_image;    # no screenshot yet to search on
     my $watch = OpenQA::Benchmark::Stopwatch->new();
     my $timestamp = $self->last_screenshot;
     my $n = $self->_time_to_assert_screen_deadline;
     my $frame = $self->{video_frame_number};
 
-    my $search_ratio = 0.02;
-    $search_ratio = 1 if ($n % 5 == 0);
-
+    # do a full-screen search every FULL_SCREEN_SEARCH_FREQUENCY'th time and at the end
+    my $search_ratio = $n < 0 || $n % FULL_SCREEN_SEARCH_FREQUENCY == 0 ? 1 : 0.02;
     my ($oldimg, $old_search_ratio) = @{$self->assert_screen_last_check || [undef, 0]};
 
-    if ($n < 0) {
-        # one last big search
-        $search_ratio = 1;
-    }
-    else {
-        if ($oldimg && $oldimg eq $img && $old_search_ratio >= $search_ratio) {
-            bmwqemu::diag('no change: ' . time_remaining_str($n));
-            return;
-        }
-    }
+    bmwqemu::diag('no change: ' . time_remaining_str($n)) and return if $n >= 0 && $oldimg && $oldimg eq $img && $old_search_ratio >= $search_ratio;
 
     $watch->start();
     $watch->{debug} = 0;
@@ -981,7 +978,7 @@ sub check_asserted_screen ($self, $args) {
     my ($foundneedle, $failed_candidates) = $img->search(\@registered_needles, 0, $search_ratio, ($watch->{debug} ? $watch : undef));
     $watch->lap("Needle search") unless $watch->{debug};
     if ($foundneedle) {
-        $self->assert_screen_last_check(undef);
+        $self->_reset_asserted_screen_check_variables;
         return {
             image => encode_base64($img->ppm_data),
             found => $foundneedle,
@@ -1010,8 +1007,7 @@ sub check_asserted_screen ($self, $args) {
     bmwqemu::diag($no_match_diag);
 
     if ($n < 0) {
-        # make sure we recheck later
-        $self->assert_screen_last_check(undef);
+        $self->_reset_asserted_screen_check_variables;
 
         if (!$self->assert_screen_check) {
             my @unregistered_needles = grep { $_->{unregistered} } @{$self->assert_screen_needles};
@@ -1030,6 +1026,15 @@ sub check_asserted_screen ($self, $args) {
 
         return $hash;
     }
+    elsif ($n <= $self->screenshot_interval * 2 && !$self->{_final_full_update_requested}) {
+        # try to request a full screen update to workaround possibly destorted VNC screen
+        # as we're nearing the deadline
+        $self->request_screen_update({incremental => 0});
+        $self->{_final_full_update_requested} = 1;
+    }
+    elsif ($n % FULL_UPDATE_REQUEST_FREQUENCY == 0) {
+        $self->request_screen_update({incremental => 0});
+    }
 
     if ($search_ratio == 1) {
         # save only failures where the whole screen has been searched

consoles/VNC.pm

@@ -800,9 +800,7 @@ sub _send_frame_buffer {
 }
 
 # frame buffer update request
-sub send_update_request {
-    my ($self) = @_;
-
+sub send_update_request ($self, $incremental = undef) {
     my $time_after_vnc_is_considered_stalled = $bmwqemu::vars{VNC_STALL_THRESHOLD} // 4;
     # after 2 seconds: send forced update
     # after 4 seconds: turn off screen
@@ -825,9 +823,8 @@ sub send_update_request {
         }
     }
 
-    my $incremental = $self->_framebuffer ? 1 : 0;
     # if we have a black screen, we need a full update
-    $incremental = 0 unless $self->_last_update_received;
+    $incremental = $self->_framebuffer && $self->_last_update_received ? 1 : 0 unless defined $incremental;
     return $self->_send_frame_buffer(
         {
             incremental => $incremental,

consoles/vnc_base.pm

@@ -37,11 +37,11 @@ sub connect_remote ($self, $args) {
     return $self->{vnc};
 }
 
-sub request_screen_update ($self, @) {
+sub request_screen_update ($self, $args = undef) {
     return unless $self->{vnc};
     # drain the VNC socket before polling for a new update
     $self->{vnc}->update_framebuffer();
-    $self->{vnc}->send_update_request();
+    $self->{vnc}->send_update_request($args ? $args->{incremental} : undef);
     return;
 }
 

t/23-baseclass.t

@@ -5,6 +5,7 @@ use Mojo::Base -strict, -signatures;
 use FindBin '$Bin';
 use lib "$Bin/../external/os-autoinst-common/lib";
 use OpenQA::Test::TimeLimit '5';
+use Test::Mock::Time;
 use Test::MockModule;
 use Test::MockObject;
 use Test::Output;
@@ -29,6 +30,17 @@ tzset;
 
 bmwqemu::init_logger;
 
+my $baseclass_mock = Test::MockModule->new('backend::baseclass');
+my @requested_screen_updates;
+$baseclass_mock->redefine(run_capture_loop => sub {
+        sleep 5;    # simulate that time passes (mocked via Test::Mock::Time)
+        $baseclass_mock->original('run_capture_loop')->(@_);
+});
+$baseclass_mock->redefine(request_screen_update => sub ($self, $args) {
+        is $args->{incremental}, 0, 'screen update is always expected to be non-incremental within this test';
+        push @requested_screen_updates, [$args];
+});
+
 my $baseclass = backend::baseclass->new();
 
 subtest 'format_vtt_timestamp' => sub {
@@ -376,6 +388,24 @@ subtest check_select_rate => sub {
     };
 };
 
+subtest 'requesting full screen update' => sub {
+    is scalar @requested_screen_updates, 0, 'no screen update requested so far';
+    $baseclass->last_image(Test::MockObject->new->set_list(search => 0, []));
+    $baseclass->assert_screen_tags(['foo']);
+    $baseclass->assert_screen_needles([{}]);
+    $baseclass_mock->redefine(_time_to_assert_screen_deadline => 41);
+    $baseclass->screenshot_interval(20);
+    $baseclass->check_asserted_screen({});
+    is scalar @requested_screen_updates, 0, 'no screen update requested';
+    $baseclass_mock->redefine(_time_to_assert_screen_deadline => 40);
+    $baseclass->check_asserted_screen({});
+    is scalar @requested_screen_updates, 1, 'screen update requested as deadline nearing end';
+    is scalar @requested_screen_updates, 1, 'no further screen update requested';
+    $baseclass_mock->redefine(_time_to_assert_screen_deadline => 2 * backend::baseclass::FULL_UPDATE_REQUEST_FREQUENCY);
+    $baseclass->check_asserted_screen({});
+    is scalar @requested_screen_updates, 2, 'screen update triggered periodically';
+};
+
 is($baseclass->get_wait_still_screen_on_here_doc_input({}), 0, 'wait_still_screen on here doc is off by default!');
 
 done_testing;