Merge ~ltrager/maas:remote-script-runner-reliability into maas:master

[Lee Trager]

LP: #1710092 - Use a monotonic clock instead of relative time.

Previously MAAS was using datetime.now() to calculate timeout. datetime.now()
may change use to NTP running or under high system load. time.monotonic()
gives a consistent incrementing time rate.

Mike started this branch[1] to fix some issues he was seeing. On my system this does make the stress-ng tests more reliable. However the test system does lock up if I run all tests including stress-ng-cpu-long and stress-ng-memory-long.

[1] https://code.launchpad.net/~mpontillo/maas/+git/maas/+merge/331030

[Andres Rodriguez (andreserl)]

Let’s not revert the padding of time. Regardless of the improvements I
still think we should have better padding time!

On Sun, Oct 8, 2017 at 9:28 PM Lee Trager <email address hidden> wrote:

> The proposal to merge ~ltrager/maas:remote-script-runner-reliability into
> maas:master has been updated.
>
> Description changed to:
>
> Mike started this branch[1] to fix some issues he was seeing. On my system
> after switching to a monotonic clock the stress-ng tests no longer time
> out. I've reverted the 5 minutes padding back to 60 seconds as the cause
> seems to be the clock not the timeout.
>
> [1] https://code.launchpad.net/~mpontillo/maas/+git/maas/+merge/331030
>
> For more details, see:
> https://code.launchpad.net/~ltrager/maas/+git/maas/+merge/331995
> --
> Your team MAAS Committers is subscribed to branch maas:master.
>
--
Andres Rodriguez
Engineering Manager, MAAS
Canonical USA, Inc.

[Andres Rodriguez (andreserl)]

Please don’t revert the 5 min padding!

review: Needs Fixing

[Andres Rodriguez (andreserl)]

lgtm!

review: Approve

[MAAS Lander (maas-lander)]

LANDING
-b remote-script-runner-reliability lp:~ltrager/maas into -b master lp:~maas-committers/maas

STATUS: FAILED BUILD
LOG: http://maas-ci-jenkins.internal:8080/job/maas/job/branch-tester/455/consoleText

[MAAS Lander (maas-lander)]

LANDING
-b remote-script-runner-reliability lp:~ltrager/maas into -b master lp:~maas-committers/maas

STATUS: FAILED BUILD
LOG: http://maas-ci-jenkins.internal:8080/job/maas/job/branch-tester/456/consoleText

c9a6de6... by Lee Trager on 2017-10-10

Fix failing test

diff --git a/src/metadataserver/user_data/templates/snippets/maas_run_remote_scripts.py b/src/metadataserver/user_data/templates/snippets/maas_run_remote_scripts.py
index 9dc5c24..5ff7ced 100644
--- a/src/metadataserver/user_data/templates/snippets/maas_run_remote_scripts.py
+++ b/src/metadataserver/user_data/templates/snippets/maas_run_remote_scripts.py
@@ -29,6 +29,7 @@ import re
 import shlex
 from subprocess import (
     check_output,
+    DEVNULL,
     PIPE,
     Popen,
     TimeoutExpired,
@@ -91,7 +92,7 @@ def download_and_extract_tar(url, creds, scripts_dir):
 def run_and_check(
         cmd, combined_path, stdout_path, stderr_path, script_name, args,
         ignore_error=False):
-    proc = Popen(cmd, stdout=PIPE, stderr=PIPE)
+    proc = Popen(cmd, stdin=DEVNULL, stdout=PIPE, stderr=PIPE)
     capture_script_output(proc, combined_path, stdout_path, stderr_path)
     if proc.returncode != 0 and not ignore_error:
         args['exit_status'] = proc.returncode
diff --git a/src/provisioningserver/refresh/__init__.py b/src/provisioningserver/refresh/__init__.py
index bf05f10..cd52816 100644
--- a/src/provisioningserver/refresh/__init__.py
+++ b/src/provisioningserver/refresh/__init__.py
@@ -7,6 +7,7 @@ import os
 import socket
 import stat
 from subprocess import (
+    DEVNULL,
     PIPE,
     Popen,
     TimeoutExpired,
@@ -164,7 +165,7 @@ def runscripts(scripts, url, creds, tmpdir):
             timeout_seconds = timeout.seconds
 
         try:
-            proc = Popen(script_path, stdout=PIPE, stderr=PIPE)
+            proc = Popen(script_path, stdin=DEVNULL, stdout=PIPE, stderr=PIPE)
             capture_script_output(
                 proc, combined_path, stdout_path, stderr_path, timeout_seconds)
         except OSError as e:
diff --git a/src/provisioningserver/refresh/maas_api_helper.py b/src/provisioningserver/refresh/maas_api_helper.py
index ab80934..e2826f6 100644
--- a/src/provisioningserver/refresh/maas_api_helper.py
+++ b/src/provisioningserver/refresh/maas_api_helper.py
@@ -10,10 +10,6 @@ __all__ = [
     ]
 
 from collections import OrderedDict
-from datetime import (
-    datetime,
-    timedelta,
-)
 from email.utils import parsedate
 import json
 import mimetypes
@@ -295,8 +291,7 @@ def capture_script_output(
         timeout = None
     else:
         # Pad the timeout by 5 minutes to allow for cleanup.
-        timeout = datetime.now() + timedelta(
-            minutes=5, seconds=timeout_seconds)
+        timeout = time.monotonic() + timeout_seconds + (60 * 5)
 
     # Create the file and then open it in read write mode for terminal
     # emulation.
@@ -310,14 +305,14 @@ def capture_script_output(
                 while selector.get_map() and proc.poll() is None:
                     # Select with a short timeout so that we don't tight loop.
                     _select_script_output(selector, combined, 0.1)
-                    if timeout is not None and datetime.now() > timeout:
+                    if timeout is not None and time.monotonic() > timeout:
                         break
                 else:
                     # Process has finished or has closed stdout and stderr.
                     # Process anything still sitting in the latter's buffers.
                     _select_script_output(selector, combined, 0.0)
 
-    now = datetime.now()
+    now = time.monotonic()
     # Wait for the process to finish.
     if timeout is None:
         # No timeout just wait until the process finishes.
@@ -330,7 +325,7 @@ def capture_script_output(
         # stdout and stderr have been closed but the timeout has not been
         # exceeded. Run with the remaining amount of time.
         try:
-            return proc.wait(timeout=(timeout - now).seconds)
+            return proc.wait(timeout=(timeout - now))
         except TimeoutExpired:
             # Make sure the process was killed
             proc.kill()
diff --git a/src/provisioningserver/refresh/tests/test_maas_api_helper.py b/src/provisioningserver/refresh/tests/test_maas_api_helper.py
index 3bf9b83..72f6341 100644
--- a/src/provisioningserver/refresh/tests/test_maas_api_helper.py
+++ b/src/provisioningserver/refresh/tests/test_maas_api_helper.py
@@ -6,7 +6,6 @@
 __all__ = []
 
 from collections import OrderedDict
-from datetime import timedelta
 from email.utils import formatdate
 from io import StringIO
 import json
@@ -615,11 +614,9 @@ class TestCaptureScriptOutput(MAASTestCase):
             )))
 
     def test__timeout(self):
-        # The timeout is padded by 60 seconds, override it so the test can
-        # run quickly.
-        self.patch(maas_api_helper, 'timedelta').return_value = timedelta(
-            microseconds=1)
+        self.patch(maas_api_helper.time, 'monotonic').side_effect = (
+            0, 60 * 6, 60 * 6, 60 * 6)
         proc = Popen(
             'echo "test"', stdout=PIPE, stderr=PIPE, shell=True)
         self.assertRaises(
-            TimeoutExpired, self.capture, proc, random.randint(1, 500))
+            TimeoutExpired, self.capture, proc, random.randint(1, 5))
diff --git a/src/provisioningserver/refresh/tests/test_refresh.py b/src/provisioningserver/refresh/tests/test_refresh.py
index d03cac1..2c5273a 100644
--- a/src/provisioningserver/refresh/tests/test_refresh.py
+++ b/src/provisioningserver/refresh/tests/test_refresh.py
@@ -341,8 +341,8 @@ class TestRefresh(MAASTestCase):
         script_name = factory.make_name('script_name')
         timeout = timedelta(seconds=random.randint(1, 500))
         self.patch_scripts_failure(script_name, timeout)
-        self.patch(refresh.maas_api_helper, 'timedelta').return_value = (
-            timedelta(microseconds=1))
+        self.patch(refresh.maas_api_helper.time, 'monotonic').side_effect = (
+            0, timeout.seconds + (60 * 6), timeout.seconds + (60 * 6))
 
         system_id = factory.make_name('system_id')
         consumer_key = factory.make_name('consumer_key')