| Message ID | 160552129733.22861.2033930860605615947.stgit@pasha-ThinkPad-X280 |
|---|---|
| State | New |
| Headers | show |
| Series | tests/acceptance: fix timeout for vm.wait | expand |
Cc'ing John. On Mon, Nov 16, 2020 at 11:08 AM Pavel Dovgalyuk <pavel.dovgalyuk@ispras.ru> wrote: > > This patch adds timeout parameter to vm.wait() calls, because the default > value is just 30 seconds, and tests may last for more time. > > Signed-off-by: Pavel Dovgalyuk <pavel.dovgalyuk@ispras.ru> > --- > tests/acceptance/boot_linux_console.py | 8 ++++---- > tests/acceptance/replay_kernel.py | 2 +- > 2 files changed, 5 insertions(+), 5 deletions(-) > > diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py > index cb6086ca6f..1cb8cb7a2a 100644 > --- a/tests/acceptance/boot_linux_console.py > +++ b/tests/acceptance/boot_linux_console.py > @@ -208,7 +208,7 @@ class BootLinuxConsole(LinuxKernelTest): > exec_command_and_wait_for_pattern(self, 'reboot', > 'reboot: Restarting system') > # Wait for VM to shut down gracefully > - self.vm.wait() > + self.vm.wait(None) > > @skipUnless(os.getenv('AVOCADO_ALLOW_UNTRUSTED_CODE'), 'untrusted code') > def test_mips64el_malta_5KEc_cpio(self): > @@ -250,7 +250,7 @@ class BootLinuxConsole(LinuxKernelTest): > exec_command_and_wait_for_pattern(self, 'reboot', > 'reboot: Restarting system') > # Wait for VM to shut down gracefully > - self.vm.wait() > + self.vm.wait(None) > > def do_test_mips_malta32el_nanomips(self, kernel_url, kernel_hash): > kernel_path_xz = self.fetch_asset(kernel_url, asset_hash=kernel_hash) > @@ -725,7 +725,7 @@ class BootLinuxConsole(LinuxKernelTest): > exec_command_and_wait_for_pattern(self, 'reboot', > 'reboot: Restarting system') > # Wait for VM to shut down gracefully > - self.vm.wait() > + self.vm.wait(None) > > @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), > 'Test artifacts fetched from unreliable apt.armbian.com') > @@ -778,7 +778,7 @@ class BootLinuxConsole(LinuxKernelTest): > exec_command_and_wait_for_pattern(self, 'reboot', > 'reboot: Restarting system') > # Wait for VM to shut down gracefully > - self.vm.wait() > + self.vm.wait(None) > > @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), > 'Test artifacts fetched from unreliable dl.armbian.com') > diff --git a/tests/acceptance/replay_kernel.py b/tests/acceptance/replay_kernel.py > index c8b043ac31..02a52b1d72 100644 > --- a/tests/acceptance/replay_kernel.py > +++ b/tests/acceptance/replay_kernel.py > @@ -60,7 +60,7 @@ class ReplayKernelBase(LinuxKernelTest): > logger.info('finished the recording with log size %s bytes' > % os.path.getsize(replay_path)) > else: > - vm.wait() > + vm.wait(None) > logger.info('successfully finished the replay') > elapsed = time.time() - start_time > logger.info('elapsed time %.2f sec' % elapsed) >
On 11/16/20 6:13 AM, Philippe Mathieu-Daudé wrote: > Cc'ing John. > > On Mon, Nov 16, 2020 at 11:08 AM Pavel Dovgalyuk > <pavel.dovgalyuk@ispras.ru> wrote: >> >> This patch adds timeout parameter to vm.wait() calls, because the default >> value is just 30 seconds, and tests may last for more time. >> This doesn't sound right -- the timeout isn't meant to be for the entire duration of the test, the timeout is from the time of issuing a shutdown command until the time the VM actually shuts down. Ideally, that should not take a particularly long time in a well-behaved test. Why is it lasting longer than 30 seconds? How long is it actually taking, do we know? And, are you SURE you want to have *no* timeout for all of these calls? (Will something else kill them if they take too long? Ideally before gitlab itself kills the job for running too long?) Cleber? >> Signed-off-by: Pavel Dovgalyuk <pavel.dovgalyuk@ispras.ru> >> --- >> tests/acceptance/boot_linux_console.py | 8 ++++---- >> tests/acceptance/replay_kernel.py | 2 +- >> 2 files changed, 5 insertions(+), 5 deletions(-) >> >> diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py >> index cb6086ca6f..1cb8cb7a2a 100644 >> --- a/tests/acceptance/boot_linux_console.py >> +++ b/tests/acceptance/boot_linux_console.py >> @@ -208,7 +208,7 @@ class BootLinuxConsole(LinuxKernelTest): >> exec_command_and_wait_for_pattern(self, 'reboot', >> 'reboot: Restarting system') >> # Wait for VM to shut down gracefully >> - self.vm.wait() >> + self.vm.wait(None) >> >> @skipUnless(os.getenv('AVOCADO_ALLOW_UNTRUSTED_CODE'), 'untrusted code') >> def test_mips64el_malta_5KEc_cpio(self): >> @@ -250,7 +250,7 @@ class BootLinuxConsole(LinuxKernelTest): >> exec_command_and_wait_for_pattern(self, 'reboot', >> 'reboot: Restarting system') >> # Wait for VM to shut down gracefully >> - self.vm.wait() >> + self.vm.wait(None) >> >> def do_test_mips_malta32el_nanomips(self, kernel_url, kernel_hash): >> kernel_path_xz = self.fetch_asset(kernel_url, asset_hash=kernel_hash) >> @@ -725,7 +725,7 @@ class BootLinuxConsole(LinuxKernelTest): >> exec_command_and_wait_for_pattern(self, 'reboot', >> 'reboot: Restarting system') >> # Wait for VM to shut down gracefully >> - self.vm.wait() >> + self.vm.wait(None) >> >> @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), >> 'Test artifacts fetched from unreliable apt.armbian.com') >> @@ -778,7 +778,7 @@ class BootLinuxConsole(LinuxKernelTest): >> exec_command_and_wait_for_pattern(self, 'reboot', >> 'reboot: Restarting system') >> # Wait for VM to shut down gracefully >> - self.vm.wait() >> + self.vm.wait(None) >> >> @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), >> 'Test artifacts fetched from unreliable dl.armbian.com') >> diff --git a/tests/acceptance/replay_kernel.py b/tests/acceptance/replay_kernel.py >> index c8b043ac31..02a52b1d72 100644 >> --- a/tests/acceptance/replay_kernel.py >> +++ b/tests/acceptance/replay_kernel.py >> @@ -60,7 +60,7 @@ class ReplayKernelBase(LinuxKernelTest): >> logger.info('finished the recording with log size %s bytes' >> % os.path.getsize(replay_path)) >> else: >> - vm.wait() >> + vm.wait(None) >> logger.info('successfully finished the replay') >> elapsed = time.time() - start_time >> logger.info('elapsed time %.2f sec' % elapsed) >> >
On 01.12.2020 22:15, John Snow wrote: > On 11/16/20 6:13 AM, Philippe Mathieu-Daudé wrote: >> Cc'ing John. >> >> On Mon, Nov 16, 2020 at 11:08 AM Pavel Dovgalyuk >> <pavel.dovgalyuk@ispras.ru> wrote: >>> >>> This patch adds timeout parameter to vm.wait() calls, because the >>> default >>> value is just 30 seconds, and tests may last for more time. >>> > > This doesn't sound right -- the timeout isn't meant to be for the entire > duration of the test, the timeout is from the time of issuing a shutdown > command until the time the VM actually shuts down. Ideally, that should > not take a particularly long time in a well-behaved test. > > Why is it lasting longer than 30 seconds? These are complex Linux boot&execution tests. Such loading process could take more than 30 seconds. E.g., BootLinux tests have timeout of 900 seconds. > How long is it actually taking, do we know? > > And, are you SURE you want to have *no* timeout for all of these calls? > (Will something else kill them if they take too long? Ideally before > gitlab itself kills the job for running too long?) > > Cleber? > >>> Signed-off-by: Pavel Dovgalyuk <pavel.dovgalyuk@ispras.ru> >>> --- >>> tests/acceptance/boot_linux_console.py | 8 ++++---- >>> tests/acceptance/replay_kernel.py | 2 +- >>> 2 files changed, 5 insertions(+), 5 deletions(-) >>> >>> diff --git a/tests/acceptance/boot_linux_console.py >>> b/tests/acceptance/boot_linux_console.py >>> index cb6086ca6f..1cb8cb7a2a 100644 >>> --- a/tests/acceptance/boot_linux_console.py >>> +++ b/tests/acceptance/boot_linux_console.py >>> @@ -208,7 +208,7 @@ class BootLinuxConsole(LinuxKernelTest): >>> exec_command_and_wait_for_pattern(self, 'reboot', >>> 'reboot: Restarting >>> system') >>> # Wait for VM to shut down gracefully >>> - self.vm.wait() >>> + self.vm.wait(None) >>> >>> @skipUnless(os.getenv('AVOCADO_ALLOW_UNTRUSTED_CODE'), >>> 'untrusted code') >>> def test_mips64el_malta_5KEc_cpio(self): >>> @@ -250,7 +250,7 @@ class BootLinuxConsole(LinuxKernelTest): >>> exec_command_and_wait_for_pattern(self, 'reboot', >>> 'reboot: Restarting >>> system') >>> # Wait for VM to shut down gracefully >>> - self.vm.wait() >>> + self.vm.wait(None) >>> >>> def do_test_mips_malta32el_nanomips(self, kernel_url, >>> kernel_hash): >>> kernel_path_xz = self.fetch_asset(kernel_url, >>> asset_hash=kernel_hash) >>> @@ -725,7 +725,7 @@ class BootLinuxConsole(LinuxKernelTest): >>> exec_command_and_wait_for_pattern(self, 'reboot', >>> 'reboot: Restarting >>> system') >>> # Wait for VM to shut down gracefully >>> - self.vm.wait() >>> + self.vm.wait(None) >>> >>> @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), >>> 'Test artifacts fetched from unreliable >>> apt.armbian.com') >>> @@ -778,7 +778,7 @@ class BootLinuxConsole(LinuxKernelTest): >>> exec_command_and_wait_for_pattern(self, 'reboot', >>> 'reboot: Restarting >>> system') >>> # Wait for VM to shut down gracefully >>> - self.vm.wait() >>> + self.vm.wait(None) >>> >>> @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), >>> 'Test artifacts fetched from unreliable >>> dl.armbian.com') >>> diff --git a/tests/acceptance/replay_kernel.py >>> b/tests/acceptance/replay_kernel.py >>> index c8b043ac31..02a52b1d72 100644 >>> --- a/tests/acceptance/replay_kernel.py >>> +++ b/tests/acceptance/replay_kernel.py >>> @@ -60,7 +60,7 @@ class ReplayKernelBase(LinuxKernelTest): >>> logger.info('finished the recording with log size %s >>> bytes' >>> % os.path.getsize(replay_path)) >>> else: >>> - vm.wait() >>> + vm.wait(None) >>> logger.info('successfully finished the replay') >>> elapsed = time.time() - start_time >>> logger.info('elapsed time %.2f sec' % elapsed) >>> >> >
On 12/2/20 1:31 AM, Pavel Dovgalyuk wrote: >>>> >>>> This patch adds timeout parameter to vm.wait() calls, because the >>>> default >>>> value is just 30 seconds, and tests may last for more time. >>>> >> >> This doesn't sound right -- the timeout isn't meant to be for the >> entire duration of the test, the timeout is from the time of issuing a >> shutdown command until the time the VM actually shuts down. Ideally, >> that should not take a particularly long time in a well-behaved test. >> >> Why is it lasting longer than 30 seconds? > > These are complex Linux boot&execution tests. > Such loading process could take more than 30 seconds. > E.g., BootLinux tests have timeout of 900 seconds. This timeout should only count towards the time spent *shutting down*, not the time to run the entire test. 30 seconds used to be enough time for this to happen on gitlab, if it's taking longer than that I am worried that something has gone wrong. Where were the failures observed, and on what tests? Are there logs I can review? --js
On 02.12.2020 18:22, John Snow wrote: > On 12/2/20 1:31 AM, Pavel Dovgalyuk wrote: >>>>> >>>>> This patch adds timeout parameter to vm.wait() calls, because the >>>>> default >>>>> value is just 30 seconds, and tests may last for more time. >>>>> >>> >>> This doesn't sound right -- the timeout isn't meant to be for the >>> entire duration of the test, the timeout is from the time of issuing >>> a shutdown command until the time the VM actually shuts down. >>> Ideally, that should not take a particularly long time in a >>> well-behaved test. >>> >>> Why is it lasting longer than 30 seconds? >> >> These are complex Linux boot&execution tests. >> Such loading process could take more than 30 seconds. >> E.g., BootLinux tests have timeout of 900 seconds. > > This timeout should only count towards the time spent *shutting down*, > not the time to run the entire test. 30 seconds used to be enough time > for this to happen on gitlab, if it's taking longer than that I am > worried that something has gone wrong. > > Where were the failures observed, and on what tests? Are there logs I > can review? I've got your point. You were right. The problem was with new long-lasting record/replay tests: if record: cloudinit.wait_for_phone_home(('0.0.0.0', self.phone_home_port), self.name) vm.shutdown() logger.info('finished the recording with log size %s bytes' % os.path.getsize(replay_path)) else: vm.wait(None) logger.info('successfully fihished the replay') Replay phase here waits for shutdown for the whole period of Linux boot and execution. We don't check any VM output and just wait for finishing the replay. Smaller RR tests include "self.wait_for_console_pattern" during replay and therefore can't have problems with this timeout. Pavel Dovgalyuk
On Thu, Dec 03, 2020 at 09:29:10AM +0300, Pavel Dovgalyuk wrote: > On 02.12.2020 18:22, John Snow wrote: > > On 12/2/20 1:31 AM, Pavel Dovgalyuk wrote: > > > > > > > > > > > > This patch adds timeout parameter to vm.wait() calls, > > > > > > because the default > > > > > > value is just 30 seconds, and tests may last for more time. > > > > > > > > > > > > > > This doesn't sound right -- the timeout isn't meant to be for > > > > the entire duration of the test, the timeout is from the time of > > > > issuing a shutdown command until the time the VM actually shuts > > > > down. Ideally, that should not take a particularly long time in > > > > a well-behaved test. > > > > > > > > Why is it lasting longer than 30 seconds? > > > > > > These are complex Linux boot&execution tests. > > > Such loading process could take more than 30 seconds. > > > E.g., BootLinux tests have timeout of 900 seconds. > > > > This timeout should only count towards the time spent *shutting down*, > > not the time to run the entire test. 30 seconds used to be enough time > > for this to happen on gitlab, if it's taking longer than that I am > > worried that something has gone wrong. > > > > Where were the failures observed, and on what tests? Are there logs I > > can review? > > I've got your point. You were right. > The problem was with new long-lasting record/replay tests: > Hi Pavel, You mean a new test you're writing based on "boot_linux.py"? > if record: > cloudinit.wait_for_phone_home(('0.0.0.0', self.phone_home_port), > self.name) > vm.shutdown() > logger.info('finished the recording with log size %s bytes' > % os.path.getsize(replay_path)) > else: > vm.wait(None) > logger.info('successfully fihished the replay') > > > Replay phase here waits for shutdown for the whole period of Linux boot and > execution. We don't check any VM output and just wait for finishing > the replay. > I'm missing why a replay be different when it comes to waiting for a successfull "I'm finished booting" from the guest? Wouldn't the guest during the replay act just the same? > Smaller RR tests include "self.wait_for_console_pattern" during replay and > therefore can't have problems with this timeout. > > Pavel Dovgalyuk > Right. Thanks, - Cleber.
On 03.12.2020 19:56, Cleber Rosa wrote: > On Thu, Dec 03, 2020 at 09:29:10AM +0300, Pavel Dovgalyuk wrote: >> On 02.12.2020 18:22, John Snow wrote: >>> On 12/2/20 1:31 AM, Pavel Dovgalyuk wrote: >>>>>>> >>>>>>> This patch adds timeout parameter to vm.wait() calls, >>>>>>> because the default >>>>>>> value is just 30 seconds, and tests may last for more time. >>>>>>> >>>>> >>>>> This doesn't sound right -- the timeout isn't meant to be for >>>>> the entire duration of the test, the timeout is from the time of >>>>> issuing a shutdown command until the time the VM actually shuts >>>>> down. Ideally, that should not take a particularly long time in >>>>> a well-behaved test. >>>>> >>>>> Why is it lasting longer than 30 seconds? >>>> >>>> These are complex Linux boot&execution tests. >>>> Such loading process could take more than 30 seconds. >>>> E.g., BootLinux tests have timeout of 900 seconds. >>> >>> This timeout should only count towards the time spent *shutting down*, >>> not the time to run the entire test. 30 seconds used to be enough time >>> for this to happen on gitlab, if it's taking longer than that I am >>> worried that something has gone wrong. >>> >>> Where were the failures observed, and on what tests? Are there logs I >>> can review? >> >> I've got your point. You were right. >> The problem was with new long-lasting record/replay tests: >> > > Hi Pavel, > > You mean a new test you're writing based on "boot_linux.py"? Right. > >> if record: >> cloudinit.wait_for_phone_home(('0.0.0.0', self.phone_home_port), >> self.name) >> vm.shutdown() >> logger.info('finished the recording with log size %s bytes' >> % os.path.getsize(replay_path)) >> else: >> vm.wait(None) >> logger.info('successfully fihished the replay') >> >> >> Replay phase here waits for shutdown for the whole period of Linux boot and >> execution. We don't check any VM output and just wait for finishing >> the replay. >> > > I'm missing why a replay be different when it comes to waiting for a > successfull "I'm finished booting" from the guest? Wouldn't the guest > during the replay act just the same? Yes, it will act the same. There is no need in checking the output (because record does not check console patterns too), because replay shutdowns automatically after the execution ends. Pavel Dovgalyuk
diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py index cb6086ca6f..1cb8cb7a2a 100644 --- a/tests/acceptance/boot_linux_console.py +++ b/tests/acceptance/boot_linux_console.py @@ -208,7 +208,7 @@ class BootLinuxConsole(LinuxKernelTest): exec_command_and_wait_for_pattern(self, 'reboot', 'reboot: Restarting system') # Wait for VM to shut down gracefully - self.vm.wait() + self.vm.wait(None) @skipUnless(os.getenv('AVOCADO_ALLOW_UNTRUSTED_CODE'), 'untrusted code') def test_mips64el_malta_5KEc_cpio(self): @@ -250,7 +250,7 @@ class BootLinuxConsole(LinuxKernelTest): exec_command_and_wait_for_pattern(self, 'reboot', 'reboot: Restarting system') # Wait for VM to shut down gracefully - self.vm.wait() + self.vm.wait(None) def do_test_mips_malta32el_nanomips(self, kernel_url, kernel_hash): kernel_path_xz = self.fetch_asset(kernel_url, asset_hash=kernel_hash) @@ -725,7 +725,7 @@ class BootLinuxConsole(LinuxKernelTest): exec_command_and_wait_for_pattern(self, 'reboot', 'reboot: Restarting system') # Wait for VM to shut down gracefully - self.vm.wait() + self.vm.wait(None) @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), 'Test artifacts fetched from unreliable apt.armbian.com') @@ -778,7 +778,7 @@ class BootLinuxConsole(LinuxKernelTest): exec_command_and_wait_for_pattern(self, 'reboot', 'reboot: Restarting system') # Wait for VM to shut down gracefully - self.vm.wait() + self.vm.wait(None) @skipUnless(os.getenv('ARMBIAN_ARTIFACTS_CACHED'), 'Test artifacts fetched from unreliable dl.armbian.com') diff --git a/tests/acceptance/replay_kernel.py b/tests/acceptance/replay_kernel.py index c8b043ac31..02a52b1d72 100644 --- a/tests/acceptance/replay_kernel.py +++ b/tests/acceptance/replay_kernel.py @@ -60,7 +60,7 @@ class ReplayKernelBase(LinuxKernelTest): logger.info('finished the recording with log size %s bytes' % os.path.getsize(replay_path)) else: - vm.wait() + vm.wait(None) logger.info('successfully finished the replay') elapsed = time.time() - start_time logger.info('elapsed time %.2f sec' % elapsed)
This patch adds timeout parameter to vm.wait() calls, because the default value is just 30 seconds, and tests may last for more time. Signed-off-by: Pavel Dovgalyuk <pavel.dovgalyuk@ispras.ru> --- tests/acceptance/boot_linux_console.py | 8 ++++---- tests/acceptance/replay_kernel.py | 2 +- 2 files changed, 5 insertions(+), 5 deletions(-)