Merge pull request #474 from seleniumbase/improve-logging

Improve the Logging System

Author: mdmintz

README.md

@@ -1,6 +1,6 @@
 [<img src="https://cdn2.hubspot.net/hubfs/100006/images/super_logo_sb20.png" title="SeleniumBase" height="48">](https://github.com/seleniumbase/SeleniumBase/blob/master/README.md)
 
-[<img src="https://img.shields.io/github/release/seleniumbase/SeleniumBase.svg" alt=" " />](https://github.com/seleniumbase/SeleniumBase/releases) [<img src="https://img.shields.io/pypi/v/seleniumbase.svg" alt=" " />](https://pypi.python.org/pypi/seleniumbase) [<img src="https://badges.gitter.im/seleniumbase/SeleniumBase.svg" alt=" " />](https://gitter.im/seleniumbase/SeleniumBase) [<img src="https://img.shields.io/travis/seleniumbase/SeleniumBase/master.svg?logo=travis" alt=" " />](https://travis-ci.org/seleniumbase/SeleniumBase) [<img src="https://dev.azure.com/seleniumbase/seleniumbase/_apis/build/status/seleniumbase.SeleniumBase?branchName=master" alt=" " />](https://dev.azure.com/seleniumbase/seleniumbase/_build/latest?definitionId=1&branchName=master) [<img src="https://github.com/seleniumbase/SeleniumBase/workflows/CI%20build/badge.svg">](https://github.com/seleniumbase/SeleniumBase/actions) [<img src="https://img.shields.io/badge/license-MIT-22BBCC.svg" alt=" " />](https://github.com/seleniumbase/SeleniumBase/blob/master/LICENSE) [<img src="https://img.shields.io/github/stars/seleniumbase/seleniumbase.svg" alt=" " />](https://github.com/seleniumbase/SeleniumBase/stargazers)
+[<img src="https://img.shields.io/github/release/seleniumbase/SeleniumBase.svg" alt=" " />](https://github.com/seleniumbase/SeleniumBase/releases) [<img src="https://img.shields.io/pypi/v/seleniumbase.svg" alt=" " />](https://pypi.python.org/pypi/seleniumbase) [<img src="https://badges.gitter.im/seleniumbase/SeleniumBase.svg" alt=" " />](https://gitter.im/seleniumbase/SeleniumBase) [<img src="https://img.shields.io/travis/seleniumbase/SeleniumBase/master.svg?logo=travis" alt=" " />](https://travis-ci.org/seleniumbase/SeleniumBase) [<img src="https://dev.azure.com/seleniumbase/seleniumbase/_apis/build/status/seleniumbase.SeleniumBase?branchName=master" alt=" " />](https://dev.azure.com/seleniumbase/seleniumbase/_build) [<img src="https://github.com/seleniumbase/SeleniumBase/workflows/CI%20build/badge.svg">](https://github.com/seleniumbase/SeleniumBase/actions) [<img src="https://img.shields.io/badge/license-MIT-22BBCC.svg" alt=" " />](https://github.com/seleniumbase/SeleniumBase/blob/master/LICENSE) [<img src="https://img.shields.io/github/stars/seleniumbase/seleniumbase.svg" alt=" " />](https://github.com/seleniumbase/SeleniumBase/stargazers)
 
 Python Framework for End-to-End UI Testing with [Selenium WebDriver](https://selenium.dev) and [pytest](https://pytest.org).
 
@@ -228,7 +228,6 @@ SeleniumBase provides additional Pytest command-line options for tests:
 --headless  # (The option to run tests headlessly. The default on Linux OS.)
 --headed  # (The option to run tests with a GUI on Linux OS.)
 --start-page=URL  # (The starting URL for the web browser when tests begin.)
---log-path=LOG_PATH  # (The directory where log files get saved to.)
 --archive-logs  # (Archive old log files instead of deleting them.)
 --slow  # (The option to slow down the automation.)
 --demo  # (The option to visually see test actions as they occur.)

examples/example_logs/basic_test_info.txt

@@ -1,5 +1,6 @@
-Last_Page: https://xkcd.com/731/
-Browser: firefox 
+Last Page: https://xkcd.com/731/
+  Browser: firefox
+Timestamp: 1540898481
 Traceback: File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/case.py", line 615, in run
     testMethod()
   File "/Users/michael/github/SeleniumBase/examples/test_fail.py", line 12, in test_find_army_of_robots_on_xkcd_desert_island

requirements.txt

@@ -1,5 +1,6 @@
 pip>=19.3.1
-setuptools>=44.0.0
+setuptools>=44.0.0;python_version<"3"
+setuptools>=45.0.0;python_version>="3"
 setuptools-scm>=3.3.3
 wheel>=0.33.6
 six==1.13.0
@@ -34,7 +35,7 @@ pyopenssl==19.1.0
 packaging>=20.0
 pygments==2.5.2
 colorama==0.4.3
-coverage>=5.0.2
+coverage>=5.0.3
 pymysql==0.9.3
 pyotp==2.3.0
 boto==2.49.0

seleniumbase/core/browser_launcher.py

@@ -95,7 +95,7 @@ def _add_chrome_proxy_extension(
     """ Implementation of https://stackoverflow.com/a/35293284 for
         https://stackoverflow.com/questions/12848327/
         (Run Selenium on a proxy server that requires authentication.) """
-    if not "".join(sys.argv) == "-c":
+    if not ("-n" in sys.argv or "".join(sys.argv) == "-c"):
         # Single-threaded
         proxy_helper.create_proxy_zip(proxy_string, proxy_user, proxy_pass)
     else:
@@ -529,7 +529,8 @@ def get_local_driver(
                         logging.debug("\nWarning: Could not make geckodriver"
                                       " executable: %s" % e)
                 elif not is_geckodriver_on_path():
-                    if not "".join(sys.argv) == "-c":  # Skip if multithreaded
+                    if not ("-n" in sys.argv or "".join(sys.argv) == "-c"):
+                        # (Not multithreaded)
                         from seleniumbase.console_scripts import sb_install
                         sys_args = sys.argv  # Save a copy of current sys args
                         print("\nWarning: geckodriver not found!"
@@ -600,7 +601,8 @@ def get_local_driver(
         else:
             return webdriver.Edge()
     elif browser_name == constants.Browser.SAFARI:
-        if "".join(sys.argv) == "-c":  # Skip if multithreaded
+        if ("-n" in sys.argv or "".join(sys.argv) == "-c"):
+            # Skip if multithreaded
             raise Exception("Can't run Safari tests in multi-threaded mode!")
         return webdriver.Safari()
     elif browser_name == constants.Browser.OPERA:
@@ -631,7 +633,8 @@ def get_local_driver(
                     logging.debug("\nWarning: Could not make chromedriver"
                                   " executable: %s" % e)
             elif not is_chromedriver_on_path():
-                if not "".join(sys.argv) == "-c":  # Skip if multithreaded
+                if not ("-n" in sys.argv or "".join(sys.argv) == "-c"):
+                    # (Not multithreaded)
                     from seleniumbase.console_scripts import sb_install
                     sys_args = sys.argv  # Save a copy of current sys args
                     print("\nWarning: chromedriver not found. Installing now:")

seleniumbase/core/download_helper.py

@@ -1,6 +1,5 @@
 import os
 import shutil
-import sys
 import time
 from seleniumbase.config import settings
 from seleniumbase.fixtures import constants
@@ -26,11 +25,7 @@ def reset_downloads_folder():
     if os.path.exists(downloads_path) and not os.listdir(downloads_path) == []:
         archived_downloads_folder = os.path.join(downloads_path, '..',
                                                  ARCHIVE_DIR)
-        if not "".join(sys.argv) == "-c":
-            # Only move files if the test run is not multi-threaded.
-            # (Running tests with "-n NUM" will create threads that only
-            # have "-c" in the sys.argv list. Easy to catch.)
-            reset_downloads_folder_assistant(archived_downloads_folder)
+        reset_downloads_folder_assistant(archived_downloads_folder)
 
 
 def reset_downloads_folder_assistant(archived_downloads_folder):
@@ -43,8 +38,11 @@ def reset_downloads_folder_assistant(archived_downloads_folder):
         archived_downloads_folder, int(time.time()))
     if os.path.exists(downloads_path):
         if not os.listdir(downloads_path) == []:
-            shutil.move(downloads_path, new_archived_downloads_sub_folder)
-            os.makedirs(downloads_path)
+            try:
+                shutil.move(downloads_path, new_archived_downloads_sub_folder)
+                os.makedirs(downloads_path)
+            except Exception:
+                pass
     if not settings.ARCHIVE_EXISTING_DOWNLOADS:
         try:
             shutil.rmtree(new_archived_downloads_sub_folder)

seleniumbase/core/log_helper.py

@@ -31,8 +31,9 @@ def log_test_failure_data(test, test_logpath, driver, browser):
     log_file = codecs.open(basic_file_path, "w+", "utf-8")
     last_page = get_last_page(driver)
     data_to_save = []
-    data_to_save.append("Last_Page: %s" % last_page)
-    data_to_save.append("Browser: %s " % browser)
+    data_to_save.append("Last Page: %s" % last_page)
+    data_to_save.append("  Browser: %s" % browser)
+    data_to_save.append("Timestamp: %s" % int(time.time()))
     if sys.version_info[0] >= 3 and hasattr(test, '_outcome'):
         if test._outcome.errors:
             try:
@@ -104,6 +105,47 @@ def get_html_source_with_base_href(driver, page_source):
     return ''
 
 
+def copytree(src, dst, symlinks=False, ignore=None):
+    if not os.path.exists(dst):
+        os.makedirs(dst)
+    for item in os.listdir(src):
+        s = os.path.join(src, item)
+        d = os.path.join(dst, item)
+        if os.path.isdir(s):
+            copytree(s, d, symlinks, ignore)
+        else:
+            if not os.path.exists(d) or (
+                    os.stat(s).st_mtime - os.stat(d).st_mtime > 1):
+                shutil.copy2(s, d)
+
+
+def archive_logs_if_set(log_path, archive_logs=False):
+    """ Handle Logging """
+    if "-n" in sys.argv or "".join(sys.argv) == "-c":
+        return  # Skip if multithreaded
+    if log_path.endswith("/"):
+        log_path = log_path[:-1]
+    if not os.path.exists(log_path):
+        try:
+            os.makedirs(log_path)
+        except Exception:
+            pass  # Only reachable during multi-threaded runs
+    else:
+        if settings.ARCHIVE_EXISTING_LOGS or archive_logs:
+            if len(os.listdir(log_path)) > 0:
+                archived_folder = "%s/../archived_logs/" % log_path
+                archived_folder = os.path.realpath(archived_folder) + '/'
+                log_path = os.path.realpath(log_path) + '/'
+                if not os.path.exists(archived_folder):
+                    try:
+                        os.makedirs(archived_folder)
+                    except Exception:
+                        pass  # Only reachable during multi-threaded runs
+                time_id = str(int(time.time()))
+                archived_logs = "%slogs_%s" % (archived_folder, time_id)
+                copytree(log_path, archived_logs)
+
+
 def log_folder_setup(log_path, archive_logs=False):
     """ Handle Logging """
     if log_path.endswith("/"):
@@ -115,30 +157,23 @@ def log_folder_setup(log_path, archive_logs=False):
             pass  # Should only be reachable during multi-threaded runs
     else:
         archived_folder = "%s/../archived_logs/" % log_path
+        archived_folder = os.path.realpath(archived_folder) + '/'
         if not os.path.exists(archived_folder):
             try:
                 os.makedirs(archived_folder)
             except Exception:
                 pass  # Should only be reachable during multi-threaded runs
-        if not "".join(sys.argv) == "-c":
-            # Only move log files if the test run is not multi-threaded.
-            # (Running tests with "-n NUM" will create threads that only
-            # have "-c" in the sys.argv list. Easy to catch.)
-            archived_logs = "%slogs_%s" % (
-                archived_folder, int(time.time()))
-            if "_logs" not in log_path:
-                # Don't move files in a custom-named log folder (in case
-                # the user specifed a folder with important files in it)
-                # unless the folder name contains "_logs".
-                # The default name for the log folder is "latest_logs".
-                return
+        archived_logs = "%slogs_%s" % (
+            archived_folder, int(time.time()))
+
+        if len(os.listdir(log_path)) > 0:
             shutil.move(log_path, archived_logs)
             os.makedirs(log_path)
             if not settings.ARCHIVE_EXISTING_LOGS and not archive_logs:
                 shutil.rmtree(archived_logs)
-            elif len(os.listdir(archived_logs)) == 0:
-                # Don't archive an empty directory
-                shutil.rmtree(archived_logs)
             else:
-                # Logs are saved/archived
-                pass
+                if ("-n" in sys.argv or "".join(sys.argv) == "-c"):
+                    # Logs are saved/archived now if tests are multithreaded
+                    pass
+                else:
+                    shutil.rmtree(archived_logs)  # (Archive test run later)

seleniumbase/plugins/base_plugin.py

@@ -1,7 +1,6 @@
 # -*- coding: utf-8 -*-
 """ This is the Nose plugin for setting a test environment and saving logs. """
 
-import os
 import sys
 import time
 from nose.plugins import Plugin
@@ -17,7 +16,6 @@ class Base(Plugin):
     --env=ENV  (Set a test environment. Use "self.env" to use this in tests.)
     --data=DATA  (Extra data to pass to tests. Use "self.data" in tests.)
     --settings-file=FILE  (Overrides SeleniumBase settings.py values.)
-    --log-path=LOG_PATH  (The directory where log files get saved to.)
     --archive-logs  (Archive old log files instead of deleting them.)
     --report  (The option to create a fancy report after tests complete.)
     --show-report   If self.report is turned on, then the report will
@@ -59,7 +57,7 @@ def options(self, parser, env):
             '--log_path', '--log-path',
             dest='log_path',
             default='latest_logs/',
-            help='Where the log files are saved.')
+            help='Where the log files are saved. (No longer editable!)')
         parser.add_option(
             '--archive_logs', '--archive-logs',
             action="store_true",
@@ -102,16 +100,13 @@ def configure(self, options, conf):
         self.page_results_list = []
         self.test_count = 0
         self.import_error = False
-        log_path = options.log_path
+        log_path = 'latest_logs/'
         archive_logs = options.archive_logs
         log_helper.log_folder_setup(log_path, archive_logs)
         if self.report_on:
             report_helper.clear_out_old_report_logs(archive_past_runs=False)
 
     def beforeTest(self, test):
-        test_logpath = self.options.log_path + "/" + test.id()
-        if not os.path.exists(test_logpath):
-            os.makedirs(test_logpath)
         test.test.environment = self.options.environment
         test.test.env = self.options.environment  # Add a shortened version
         test.test.data = self.options.data
@@ -123,6 +118,8 @@ def beforeTest(self, test):
         self.start_time = float(time.time())
 
     def finalize(self, result):
+        log_helper.archive_logs_if_set(
+            self.options.log_path, self.options.archive_logs)
         if self.report_on:
             if not self.import_error:
                 report_helper.add_bad_page_log_file(self.page_results_list)

seleniumbase/plugins/basic_test_info.py

@@ -11,6 +11,7 @@
 
 import os
 import codecs
+import time
 import traceback
 from nose.plugins import Plugin
 from seleniumbase.config import settings
@@ -55,8 +56,9 @@ def addFailure(self, test, err, capt=None, tbinfo=None):
 
     def __log_test_error_data(self, log_file, test, err, type):
         data_to_save = []
-        data_to_save.append("Last_Page: %s" % test.driver.current_url)
-        data_to_save.append("Browser: %s " % self.options.browser)
+        data_to_save.append("Last Page: %s" % test.driver.current_url)
+        data_to_save.append("  Browser: %s" % self.options.browser)
+        data_to_save.append("Timestamp: %s" % int(time.time()))
         data_to_save.append("Server: %s " % self.options.servername)
         data_to_save.append("%s: %s" % (type, err[0]))
         data_to_save.append("Traceback: " + ''.join(

seleniumbase/plugins/pytest_plugin.py

@@ -29,7 +29,6 @@ def pytest_addoption(parser):
     --headless  (The option to run tests headlessly. The default on Linux OS.)
     --headed  (The option to run tests with a GUI on Linux OS.)
     --start-page=URL  (The starting URL for the web browser when tests begin.)
-    --log-path=LOG_PATH  (The directory where log files get saved to.)
     --archive-logs  (Archive old log files instead of deleting them.)
     --slow  (The option to slow down the automation.)
     --demo  (The option to visually see test actions as they occur.)
@@ -113,7 +112,7 @@ def pytest_addoption(parser):
     parser.addoption('--log_path', '--log-path',
                      dest='log_path',
                      default='latest_logs/',
-                     help='Where the log files are saved.')
+                     help='Where log files are saved. (No longer editable!)')
     parser.addoption('--archive_logs', '--archive-logs',
                      action="store_true",
                      dest='archive_logs',
@@ -380,7 +379,7 @@ def pytest_configure(config):
     sb_config.settings_file = config.getoption('settings_file')
     sb_config.user_data_dir = config.getoption('user_data_dir')
     sb_config.database_env = config.getoption('database_env')
-    sb_config.log_path = config.getoption('log_path')
+    sb_config.log_path = 'latest_logs/'  # (No longer editable!)
     sb_config.archive_logs = config.getoption('archive_logs')
     sb_config.slow_mode = config.getoption('slow_mode')
     sb_config.demo_mode = config.getoption('demo_mode')
@@ -402,7 +401,8 @@ def pytest_configure(config):
     sb_config.pytest_html_report = config.getoption('htmlpath')  # --html=FILE
 
     if sb_config.reuse_session:
-        if "".join(sys.argv) == "-c":  # Can't "reuse_session" if multithreaded
+        if "-n" in sys.argv or "".join(sys.argv) == "-c":
+            # Can't "reuse_session" if multithreaded
             sb_config.reuse_session = False
 
     if "linux" in sys.platform and (
@@ -432,6 +432,7 @@ def pytest_unconfigure():
             except Exception:
                 pass
         sb_config.shared_driver = None
+    log_helper.archive_logs_if_set(sb_config.log_path, sb_config.archive_logs)
 
 
 def pytest_runtest_setup():

setup.py

@@ -45,7 +45,7 @@
 
 setup(
     name='seleniumbase',
-    version='1.34.17',
+    version='1.34.18',
     description='Fast, Easy, and Reliable Browser Automation & Testing.',
     long_description=long_description,
     long_description_content_type='text/markdown',
@@ -117,7 +117,7 @@
         'packaging>=20.0',
         'pygments>=2.5.2',
         'colorama==0.4.3',
-        'coverage>=5.0.2',
+        'coverage>=5.0.3',
         'pymysql==0.9.3',
         'pyotp==2.3.0',
         'boto==2.49.0',