Tests: preserving unit.log when run without restart.

Introducing "unit.log.Log" class for "unit.log" file management.
Moving "findall()" function into TestApplicationProto.
Using "os.kill()" to send signals.

9 files changed, 94 insertions, 96 deletions

diff --git a/test/conftest.py b/test/conftest.py
index 38e1138e..b9f5c60b 100644
--- a/test/conftest.py
+++ b/test/conftest.py
@@ -22,6 +22,7 @@ from unit.check.regex import check_regex
 from unit.check.tls import check_openssl
 from unit.http import TestHTTP
 from unit.option import option
+from unit.log import Log
 from unit.utils import public_dir
 from unit.utils import waitforfiles
 
@@ -71,7 +72,6 @@ def pytest_addoption(parser):
 
 
 unit_instance = {}
-unit_log_copy = "unit.log.copy"
 _processes = []
 _fds_check = {
     'main': {'fds': 0, 'skip': False},
@@ -165,12 +165,11 @@ def pytest_sessionstart(session):
     option.available = {'modules': {}, 'features': {}}
 
     unit = unit_run()
-    option.temp_dir = unit['temp_dir']
 
     # read unit.log
 
     for i in range(50):
-        with open(unit['temp_dir'] + '/unit.log', 'r') as f:
+        with open(Log.get_path(), 'r') as f:
             log = f.read()
             m = re.search('controller started', log)
 
@@ -216,9 +215,6 @@ def pytest_sessionstart(session):
     if option.restart:
         shutil.rmtree(unit_instance['temp_dir'])
 
-    elif option.save_log:
-        open(unit_instance['temp_dir'] + '/' + unit_log_copy, 'w').close()
-
 
 @pytest.hookimpl(tryfirst=True, hookwrapper=True)
 def pytest_runtest_makereport(item, call):
@@ -269,7 +265,6 @@ def check_prerequisites(request):
 @pytest.fixture(autouse=True)
 def run(request):
     unit = unit_run()
-    option.temp_dir = unit['temp_dir']
 
     option.skip_alerts = [
         r'read signalfd\(4\) failed',
@@ -291,34 +286,25 @@ def run(request):
 
     # prepare log
 
-    with open(
-        unit_instance['log'], 'r', encoding='utf-8', errors='ignore'
-    ) as f:
+    with Log.open(encoding='utf-8') as f:
         log = f.read()
-
-    if not option.restart and option.save_log:
-        with open(unit_instance['temp_dir'] + '/' + unit_log_copy, 'a') as f:
-            f.write(log)
-
-    # remove unit.log
+        Log.set_pos(f.tell())
 
     if not option.save_log and option.restart:
         shutil.rmtree(unit['temp_dir'])
+        Log.set_pos(0)
 
     # clean temp_dir before the next test
 
     if not option.restart:
         _clear_conf(unit['temp_dir'] + '/control.unit.sock', log)
 
-        open(unit['log'], 'w').close()
-
         for item in os.listdir(unit['temp_dir']):
             if item not in [
                 'control.unit.sock',
                 'state',
                 'unit.pid',
                 'unit.log',
-                unit_log_copy,
             ]:
                 path = os.path.join(unit['temp_dir'], item)
 
@@ -439,10 +425,12 @@ def unit_run():
         exit('Could not start unit')
 
     unit_instance['temp_dir'] = temp_dir
-    unit_instance['log'] = temp_dir + '/unit.log'
     unit_instance['control_sock'] = temp_dir + '/control.unit.sock'
     unit_instance['unitd'] = unitd
 
+    option.temp_dir = temp_dir
+    Log.temp_dir = temp_dir
+
     with open(temp_dir + '/unit.pid', 'r') as f:
         unit_instance['pid'] = f.read().rstrip()
 
@@ -489,12 +477,9 @@ def unit_stop():
         return 'Could not terminate unit'
 
 
-def _check_alerts(path=None, log=None):
-    if path is None:
-        path = unit_instance['log']
-
+def _check_alerts(log=None):
     if log is None:
-        with open(path, 'r', encoding='utf-8', errors='ignore') as f:
+        with Log.open(encoding='utf-8') as f:
             log = f.read()
 
     found = False
@@ -526,7 +511,7 @@ def _check_alerts(path=None, log=None):
 
 
 def _print_log(data=None):
-    path = unit_instance['log']
+    path = Log.get_path()
 
     print('Path to unit.log:\n' + path + '\n')
 
@@ -679,7 +664,7 @@ def unit_pid(request):
 
 def pytest_sessionfinish(session):
     if not option.restart and option.save_log:
-        print('Path to unit.log:\n' + unit_instance['log'] + '\n')
+        print('Path to unit.log:\n' + Log.get_path() + '\n')
 
     option.restart = True
 
diff --git a/test/test_access_log.py b/test/test_access_log.py
index 72a78c33..ba254c5e 100644
--- a/test/test_access_log.py
+++ b/test/test_access_log.py
@@ -249,7 +249,7 @@ Connection: close
 
         assert self.search_in_log(r'/delete', 'access.log') is None, 'delete'
 
-    def test_access_log_change(self, temp_dir):
+    def test_access_log_change(self):
         self.load('empty')
 
         self.get()
diff --git a/test/test_asgi_application.py b/test/test_asgi_application.py
index 70b2e4c3..f503fa82 100644
--- a/test/test_asgi_application.py
+++ b/test/test_asgi_application.py
@@ -14,10 +14,6 @@ class TestASGIApplication(TestApplicationPython):
     }
     load_module = 'asgi'
 
-    def findall(self, pattern):
-        with open(option.temp_dir + '/unit.log', 'r', errors='ignore') as f:
-            return re.findall(pattern, f.read())
-
     def test_asgi_application_variables(self):
         self.load('variables')
 
diff --git a/test/test_php_application.py b/test/test_php_application.py
index de3da939..350ac0d0 100644
--- a/test/test_php_application.py
+++ b/test/test_php_application.py
@@ -1,8 +1,8 @@
 import os
 import re
 import shutil
+import signal
 import time
-from subprocess import call
 
 import pytest
 
@@ -95,37 +95,29 @@ class TestPHPApplication(TestApplicationPHP):
         assert resp['status'] == 200, 'query string empty status'
         assert resp['headers']['Query-String'] == '', 'query string empty'
 
-    def test_php_application_fastcgi_finish_request(self, temp_dir):
+    def test_php_application_fastcgi_finish_request(self, unit_pid):
         self.load('fastcgi_finish_request')
 
         assert self.get()['body'] == '0123'
 
-        with open(temp_dir + '/unit.pid', 'r') as f:
-            pid = f.read().rstrip()
+        os.kill(unit_pid, signal.SIGUSR1);
 
-        call(['kill', '-s', 'USR1', pid])
+        errs = self.findall(r'Error in fastcgi_finish_request')
 
-        with open(temp_dir + '/unit.log', 'r', errors='ignore') as f:
-            errs = re.findall(r'Error in fastcgi_finish_request', f.read())
+        assert len(errs) == 0, 'no error'
 
-            assert len(errs) == 0, 'no error'
-
-    def test_php_application_fastcgi_finish_request_2(self, temp_dir):
+    def test_php_application_fastcgi_finish_request_2(self, unit_pid):
         self.load('fastcgi_finish_request')
 
         resp = self.get(url='/?skip')
         assert resp['status'] == 200
         assert resp['body'] == ''
 
-        with open(temp_dir + '/unit.pid', 'r') as f:
-            pid = f.read().rstrip()
-
-        call(['kill', '-s', 'USR1', pid])
+        os.kill(unit_pid, signal.SIGUSR1);
 
-        with open(temp_dir + '/unit.log', 'r', errors='ignore') as f:
-            errs = re.findall(r'Error in fastcgi_finish_request', f.read())
+        errs = self.findall(r'Error in fastcgi_finish_request')
 
-            assert len(errs) == 0, 'no error'
+        assert len(errs) == 0, 'no error'
 
     def test_php_application_query_string_absent(self):
         self.load('query_string')
@@ -538,7 +530,7 @@ class TestPHPApplication(TestApplicationPHP):
             r'012345', self.get()['body']
         ), 'disable_classes before'
 
-    def test_php_application_error_log(self, temp_dir):
+    def test_php_application_error_log(self):
         self.load('error_log')
 
         assert self.get()['status'] == 200, 'status'
@@ -551,14 +543,13 @@ class TestPHPApplication(TestApplicationPHP):
 
         assert self.wait_for_record(pattern) is not None, 'errors print'
 
-        with open(temp_dir + '/unit.log', 'r', errors='ignore') as f:
-            errs = re.findall(pattern, f.read())
+        errs = self.findall(pattern)
 
-            assert len(errs) == 2, 'error_log count'
+        assert len(errs) == 2, 'error_log count'
 
-            date = errs[0].split('[')[0]
-            date2 = errs[1].split('[')[0]
-            assert date != date2, 'date diff'
+        date = errs[0].split('[')[0]
+        date2 = errs[1].split('[')[0]
+        assert date != date2, 'date diff'
 
     def test_php_application_script(self):
         assert 'success' in self.conf(
diff --git a/test/test_python_application.py b/test/test_python_application.py
index fd99a3af..48c3d603 100644
--- a/test/test_python_application.py
+++ b/test/test_python_application.py
@@ -7,16 +7,11 @@ import time
 import pytest
 
 from unit.applications.lang.python import TestApplicationPython
-from unit.option import option
 
 
 class TestPythonApplication(TestApplicationPython):
     prerequisites = {'modules': {'python': 'all'}}
 
-    def findall(self, pattern):
-        with open(option.temp_dir + '/unit.log', 'r', errors='ignore') as f:
-            return re.findall(pattern, f.read())
-
     def test_python_application_variables(self):
         self.load('variables')
 
diff --git a/test/test_tls.py b/test/test_tls.py
index 63422dfb..abdca167 100644
--- a/test/test_tls.py
+++ b/test/test_tls.py
@@ -6,16 +6,11 @@ import subprocess
 import pytest
 
 from unit.applications.tls import TestApplicationTLS
-from unit.option import option
 
 
 class TestTLS(TestApplicationTLS):
     prerequisites = {'modules': {'python': 'any', 'openssl': 'any'}}
 
-    def findall(self, pattern):
-        with open(option.temp_dir + '/unit.log', 'r', errors='ignore') as f:
-            return re.findall(pattern, f.read())
-
     def openssl_date_to_sec_epoch(self, date):
         return self.date_to_sec_epoch(date, '%b %d %H:%M:%S %Y %Z')
 
diff --git a/test/test_usr1.py b/test/test_usr1.py
index dbb5265c..9a12b747 100644
--- a/test/test_usr1.py
+++ b/test/test_usr1.py
@@ -1,14 +1,15 @@
 import os
-from subprocess import call
+import signal
 
 from unit.applications.lang.python import TestApplicationPython
+from unit.log import Log
 from unit.utils import waitforfiles
 
 
 class TestUSR1(TestApplicationPython):
     prerequisites = {'modules': {'python': 'any'}}
 
-    def test_usr1_access_log(self, temp_dir):
+    def test_usr1_access_log(self, temp_dir, unit_pid):
         self.load('empty')
 
         log = 'access.log'
@@ -31,10 +32,7 @@ class TestUSR1(TestApplicationPython):
         ), 'rename new'
         assert not os.path.isfile(log_path), 'rename old'
 
-        with open(temp_dir + '/unit.pid', 'r') as f:
-            pid = f.read().rstrip()
-
-        call(['kill', '-s', 'USR1', pid])
+        os.kill(unit_pid, signal.SIGUSR1)
 
         assert waitforfiles(log_path), 'reopen'
 
@@ -46,7 +44,7 @@ class TestUSR1(TestApplicationPython):
         ), 'reopen 2'
         assert self.search_in_log(r'/usr1', log_new) is None, 'rename new 2'
 
-    def test_usr1_unit_log(self, temp_dir):
+    def test_usr1_unit_log(self, temp_dir, unit_pid):
         self.load('log_body')
 
         log_new = 'new.log'
@@ -55,28 +53,37 @@ class TestUSR1(TestApplicationPython):
 
         os.rename(log_path, log_path_new)
 
-        body = 'body_for_a_log_new'
-        assert self.post(body=body)['status'] == 200
+        Log.swap(log_new)
 
-        assert self.wait_for_record(body, log_new) is not None, 'rename new'
-        assert not os.path.isfile(log_path), 'rename old'
+        try:
+            body = 'body_for_a_log_new\n'
+            assert self.post(body=body)['status'] == 200
 
-        with open(temp_dir + '/unit.pid', 'r') as f:
-            pid = f.read().rstrip()
+            assert (
+                self.wait_for_record(body, log_new) is not None
+            ), 'rename new'
+            assert not os.path.isfile(log_path), 'rename old'
 
-        call(['kill', '-s', 'USR1', pid])
+            os.kill(unit_pid, signal.SIGUSR1)
 
-        assert waitforfiles(log_path), 'reopen'
+            assert waitforfiles(log_path), 'reopen'
+
+            body = 'body_for_a_log_unit\n'
+            assert self.post(body=body)['status'] == 200
+
+            assert self.wait_for_record(body) is not None, 'rename new'
+            assert self.search_in_log(body, log_new) is None, 'rename new 2'
 
-        body = 'body_for_a_log_unit'
-        assert self.post(body=body)['status'] == 200
+        finally:
+            # merge two log files into unit.log to check alerts
 
-        assert self.wait_for_record(body) is not None, 'rename new'
-        assert self.search_in_log(body, log_new) is None, 'rename new 2'
+            with open(log_path, 'r', errors='ignore') as unit_log:
+                log = unit_log.read()
 
-        # merge two log files into unit.log to check alerts
+            with open(log_path, 'w') as unit_log, open(
+                log_path_new, 'r', errors='ignore'
+            ) as unit_log_new:
+                unit_log.write(unit_log_new.read())
+                unit_log.write(log)
 
-        with open(log_path, 'w') as unit_log, open(
-            log_path_new, 'r'
-        ) as unit_log_new:
-            unit_log.write(unit_log_new.read())
+            Log.swap(log_new)
diff --git a/test/unit/applications/proto.py b/test/unit/applications/proto.py
index 5c400621..92754c03 100644
--- a/test/unit/applications/proto.py
+++ b/test/unit/applications/proto.py
@@ -4,6 +4,7 @@ import time
 
 from unit.control import TestControl
 from unit.option import option
+from unit.log import Log
 
 
 class TestApplicationProto(TestControl):
@@ -15,18 +16,23 @@ class TestApplicationProto(TestControl):
     def date_to_sec_epoch(self, date, template='%a, %d %b %Y %H:%M:%S %Z'):
         return time.mktime(time.strptime(date, template))
 
+    def findall(self, pattern, name='unit.log'):
+        with Log.open(name) as f:
+            return re.findall(pattern, f.read())
+
     def search_in_log(self, pattern, name='unit.log'):
-        with open(option.temp_dir + '/' + name, 'r', errors='ignore') as f:
+        with Log.open(name) as f:
             return re.search(pattern, f.read())
 
     def wait_for_record(self, pattern, name='unit.log', wait=150):
-        for i in range(wait):
-            found = self.search_in_log(pattern, name)
+        with Log.open(name) as f:
+            for i in range(wait):
+                found = re.search(pattern, f.read())
 
-            if found is not None:
-                break
+                if found is not None:
+                    break
 
-            time.sleep(0.1)
+                time.sleep(0.1)
 
         return found
 
diff --git a/test/unit/log.py b/test/unit/log.py
new file mode 100644
index 00000000..7263443d
--- /dev/null
+++ b/test/unit/log.py
@@ -0,0 +1,23 @@
+UNIT_LOG = 'unit.log'
+
+
+class Log:
+    temp_dir = None
+    pos = {}
+
+    def open(name=UNIT_LOG, encoding=None):
+        f = open(Log.get_path(name), 'r', encoding=encoding, errors='ignore')
+        f.seek(Log.pos.get(name, 0))
+
+        return f
+
+    def set_pos(pos, name=UNIT_LOG):
+        Log.pos[name] = pos
+
+    def swap(name):
+        pos = Log.pos.get(UNIT_LOG, 0)
+        Log.pos[UNIT_LOG] = Log.pos.get(name, 0)
+        Log.pos[name] = pos
+
+    def get_path(name=UNIT_LOG):
+        return Log.temp_dir + '/' + name