Remove polling (#137)

* Change print on logging

* Normalize error

---------

Co-authored-by: vshepard <[email protected]>

Author: demonolock

testgres/config.py

@@ -2,6 +2,8 @@
 
 import atexit
 import copy
+import logging
+import os
 import tempfile
 
 from contextlib import contextmanager
@@ -10,6 +12,10 @@
 from .operations.os_ops import OsOperations
 from .operations.local_ops import LocalOperations
 
+log_level = os.getenv('LOGGING_LEVEL', 'WARNING').upper()
+log_format = os.getenv('LOGGING_FORMAT', '%(asctime)s - %(levelname)s - %(message)s').upper()
+logging.basicConfig(level=log_level, format=log_format)
+
 
 class GlobalConfig(object):
     """

testgres/connection.py

@@ -1,4 +1,5 @@
 # coding: utf-8
+import logging
 
 # we support both pg8000 and psycopg2
 try:
@@ -110,7 +111,7 @@ def execute(self, query, *args):
         except ProgrammingError:
             return None
         except Exception as e:
-            print("Error executing query: {}\n {}".format(repr(e), query))
+            logging.error("Error executing query: {}\n {}".format(repr(e), query))
             return None
 
     def close(self):

testgres/node.py

@@ -1,5 +1,5 @@
 # coding: utf-8
-
+import logging
 import os
 import random
 import signal
@@ -736,11 +736,10 @@ def start(self, params=[], wait=True):
                 if any(len(file) > 1 and 'Is another postmaster already '
                                          'running on port' in file[1].decode() for
                        file in files):
-                    print("Detected an issue with connecting to port {0}. "
-                          "Trying another port after a 5-second sleep...".format(self.port))
+                    logging.warning("Detected an issue with connecting to port {0}. "
+                                    "Trying another port after a 5-second sleep...".format(self.port))
                     self.port = reserve_port()
-                    options = {}
-                    options['port'] = str(self.port)
+                    options = {'port': str(self.port)}
                     self.set_auto_conf(options)
                     startup_retries -= 1
                     time.sleep(5)
@@ -1166,7 +1165,6 @@ def poll_query_until(self,
         assert sleep_time > 0
         attempts = 0
         while max_attempts == 0 or attempts < max_attempts:
-            print(f"Pooling {attempts}")
             try:
                 res = self.execute(dbname=dbname,
                                    query=query,
@@ -1190,6 +1188,7 @@ def poll_query_until(self,
                     return    # done
 
             except tuple(suppress or []):
+                logging.info(f"Trying execute, attempt {attempts + 1}.\nQuery: {query}")
                 pass    # we're suppressing them
 
             time.sleep(sleep_time)

testgres/operations/local_ops.py

@@ -1,4 +1,5 @@
 import getpass
+import logging
 import os
 import shutil
 import stat
@@ -165,9 +166,9 @@ def rmdirs(self, path, ignore_errors=True, retries=3, delay=1):
             except FileNotFoundError:
                 return True
             except Exception as e:
-                print(f"Error: Failed to remove directory {path} on attempt {attempt + 1}: {e}")
+                logging.error(f"Error: Failed to remove directory {path} on attempt {attempt + 1}: {e}")
             time.sleep(delay)
-        print(f"Error: Failed to remove directory {path} after {retries} attempts.")
+        logging.error(f"Error: Failed to remove directory {path} after {retries} attempts.")
         return False
 
     def listdir(self, path):

testgres/operations/remote_ops.py

@@ -93,8 +93,10 @@ def exec_command(self, cmd, wait_exit=False, verbose=False, expect_error=False,
         if not error:
             error_found = 0
         else:
+            error = normalize_error(error)
             error_found = exit_status != 0 or any(
-                marker in error for marker in [b'error', b'Permission denied', b'fatal', b'No such file or directory'])
+                marker in error for marker in ['error', 'Permission denied', 'fatal', 'No such file or directory']
+            )
 
         if error_found:
             if isinstance(error, bytes):
@@ -369,3 +371,9 @@ def db_connect(self, dbname, user, password=None, host="localhost", port=5432):
             password=password,
         )
         return conn
+
+
+def normalize_error(error):
+    if isinstance(error, bytes):
+        return error.decode()
+    return error

testgres/plugins/pg_probackup2/pg_probackup2/app.py

@@ -1,6 +1,7 @@
 import contextlib
 import importlib
 import json
+import logging
 import os
 import re
 import subprocess
@@ -74,7 +75,7 @@ def run(self, command, gdb=False, old_binary=False, return_id=True, env=None,
             command = [command[0], *self.backup_dir.pb_args, *command[1:]]
 
         if not self.probackup_old_path and old_binary:
-            print('PGPROBACKUPBIN_OLD is not set')
+            logging.error('PGPROBACKUPBIN_OLD is not set')
             exit(1)
 
         if old_binary:
@@ -107,12 +108,11 @@ def run(self, command, gdb=False, old_binary=False, return_id=True, env=None,
             return GDBobj(cmdline, self.test_class)
 
         try:
-            result = None
             if type(gdb) is tuple and gdb[0] == 'suspend':
                 # special test flow for manually debug probackup
                 gdb_port = gdb[1]
                 cmdline = ['gdbserver'] + ['localhost:' + str(gdb_port)] + cmdline
-                print("pg_probackup gdb suspended, waiting gdb connection on localhost:{0}".format(gdb_port))
+                logging.warning("pg_probackup gdb suspended, waiting gdb connection on localhost:{0}".format(gdb_port))
 
             start_time = time.time()
             self.test_class.output = subprocess.check_output(
@@ -233,7 +233,7 @@ def backup_node(
         if options is None:
             options = []
         if not node and not data_dir:
-            print('You must provide ether node or data_dir for backup')
+            logging.error('You must provide ether node or data_dir for backup')
             exit(1)
 
         if not datname:
@@ -502,7 +502,7 @@ def show(
                         if i == '':
                             backup_record_split.remove(i)
                     if len(header_split) != len(backup_record_split):
-                        print(warning.format(
+                        logging.error(warning.format(
                             header=header, body=body,
                             header_split=header_split,
                             body_split=backup_record_split)
@@ -581,7 +581,7 @@ def show_archive(
         else:
             show_splitted = self.run(cmd_list + options, old_binary=old_binary,
                                      expect_error=expect_error).splitlines()
-            print(show_splitted)
+            logging.error(show_splitted)
             exit(1)
 
     def validate(
@@ -769,7 +769,7 @@ def load_backup_class(fs_type):
         if fs_type:
             implementation = fs_type
 
-        print("Using ", implementation)
+        logging.info("Using ", implementation)
         module_name, class_name = implementation.rsplit(sep='.', maxsplit=1)
 
         module = importlib.import_module(module_name)

testgres/plugins/pg_probackup2/pg_probackup2/init_helpers.py

@@ -1,3 +1,4 @@
+import logging
 from functools import reduce
 import getpass
 import os
@@ -31,7 +32,7 @@
         cached_initdb_dir=False,
         node_cleanup_full=delete_logs)
 except Exception as e:
-    print("Can't configure testgres: {0}".format(e))
+    logging.warning("Can't configure testgres: {0}".format(e))
 
 
 class Init(object):
@@ -104,7 +105,7 @@ def __init__(self):
 
             if os.path.isfile(probackup_path_tmp):
                 if not os.access(probackup_path_tmp, os.X_OK):
-                    print('{0} is not an executable file'.format(
+                    logging.warning('{0} is not an executable file'.format(
                         probackup_path_tmp))
                 else:
                     self.probackup_path = probackup_path_tmp
@@ -114,13 +115,13 @@ def __init__(self):
 
             if os.path.isfile(probackup_path_tmp):
                 if not os.access(probackup_path_tmp, os.X_OK):
-                    print('{0} is not an executable file'.format(
+                    logging.warning('{0} is not an executable file'.format(
                         probackup_path_tmp))
                 else:
                     self.probackup_path = probackup_path_tmp
 
         if not self.probackup_path:
-            print('pg_probackup binary is not found')
+            logging.error('pg_probackup binary is not found')
             exit(1)
 
         if os.name == 'posix':
@@ -207,7 +208,7 @@ def __init__(self):
         if self.probackup_version.split('.')[0].isdigit():
             self.major_version = int(self.probackup_version.split('.')[0])
         else:
-            print('Can\'t process pg_probackup version \"{}\": the major version is expected to be a number'.format(self.probackup_version))
+            logging.error('Can\'t process pg_probackup version \"{}\": the major version is expected to be a number'.format(self.probackup_version))
             sys.exit(1)
 
     def test_env(self):

testgres/plugins/pg_probackup2/pg_probackup2/tests/basic_test.py

@@ -1,3 +1,4 @@
+import logging
 import os
 import shutil
 import unittest
@@ -14,7 +15,7 @@ def get_module_and_function_name(test_id):
             module_name = test_id.split('.')[-2]
             fname = test_id.split('.')[-1]
         except IndexError:
-            print(f"Couldn't get module name and function name from test_id: `{test_id}`")
+            logging.warning(f"Couldn't get module name and function name from test_id: `{test_id}`")
             module_name, fname = test_id.split('(')[1].split('.')[1], test_id.split('(')[0]
         return module_name, fname
 

testgres/utils.py

@@ -228,7 +228,6 @@ def eprint(*args, **kwargs):
     """
     Print stuff to stderr.
     """
-
     print(*args, file=sys.stderr, **kwargs)