Partial #635 - also directs logging to stdout

utils/test/Configuration.py

@@ -37,13 +37,15 @@
 ==================================================
 '''
 
+import logging
 import os
 import sys
 
 DEBUG = True # this guy is a flag for extra messaging while debugging tests
 
-#NOTE: Logger and Platform are initialized in TestRunner's main()
+#NOTE: Logger and Platform are initialized in TestRunner's main() or Configuration.GetLogger/Platform
 Logger = None
+LoggerFile = None
 
 Platform = None
 
@@ -150,7 +152,7 @@ def detect_encoding(readline):
     ## END WORKAROUND
     #################################################
 
-def GetLogger() :
+def GetLogger(logLevel = logging.DEBUG) :
 
     global Logger
 
@@ -159,7 +161,7 @@ def GetLogger() :
         import UnitTestUtilities
 
         logName = UnitTestUtilities.getLoggerName()
-        Logger = UnitTestUtilities.initializeLogger(logName)
+        Logger = UnitTestUtilities.initializeLogger(logName, logLevel)
 
     return Logger
 

utils/test/TestRunner.py

@@ -54,20 +54,22 @@
 
 def main():
     ''' main test logic '''
+    print("TestRunner.py - main")
+
     if Configuration.DEBUG == True:
-        print("TestRunner.py - main")
+        print("Debug messaging is ON")
+        logLevel = logging.DEBUG
     else:
         print("Debug messaging is OFF")
+        logLevel = logging.INFO
 
     # setup logger
-    logName = None
     if not logFileFromBAT == None:
-        logName = logFileFromBAT
-        Configuration.Logger = UnitTestUtilities.initializeLogger(logFileFromBAT)
+        Configuration.Logger = UnitTestUtilities.initializeLogger(logFileFromBAT, logLevel)
     else:
-        logName = UnitTestUtilities.getLoggerName()
-        Configuration.Logger = UnitTestUtilities.initializeLogger(logName)
-    print("Logging results to: " + str(logName))
+        Configuration.GetLogger(logLevel)
+
+    print("Logging results to: " + str(Configuration.LoggerFile))
     UnitTestUtilities.setUpLogFileHeader()
 
     result = runTestSuite()
@@ -79,18 +81,15 @@ def main():
 def logTestResults(result):
     ''' Write the log file '''
     resultHead = resultsHeader(result)
-    print(resultHead)
     Configuration.Logger.info(resultHead)
 
     errorLogLines = getErrorResultsAsList(result)
     for errorLogLine in errorLogLines :
         # strip unicode chars so they don't mess up print/log file
         line = errorLogLine.encode('ascii','ignore').decode('ascii')
-        print(line)
         Configuration.Logger.error(line)
 
     endOfTestMsg = "END OF TEST ========================================="
-    print(endOfTestMsg)
     Configuration.Logger.info(endOfTestMsg)
 
     return
@@ -147,7 +146,7 @@ def runTestSuite():
 
     #What Platform are we running on?
     Configuration.GetPlatform()
-    Configuration.Logger.info(Configuration.Platform + " =======================================")
+    Configuration.Logger.info('Running on Platform: ' + Configuration.Platform)
 
     testSuite.addTests(addClearingOperationsSuite())
     testSuite.addTests(addGeoNamesSuite())
@@ -162,63 +161,64 @@ def runTestSuite():
     #TODO: MAoT Test Suite
     #TODO: MAoW Test Suite
 
-    print("running " + str(testSuite.countTestCases()) + " tests...")
+    Configuration.Logger.info("running " + str(testSuite.countTestCases()) + " tests...")
 
     # Run all of the tests added above
     testSuite.run(result)
 
-    print("Test success: {0}".format(str(result.wasSuccessful())))
+    Configuration.Logger.info("Test success: {0}".format(str(result.wasSuccessful())))
 
     return result
 
 def addClearingOperationsSuite():
     '''Add all Clearing operations Tests'''
-    if Configuration.DEBUG == True: print("TestRunner.py - addClearingOperationsSuite")
+    Configuration.Logger.debug("TestRunner.py - addClearingOperationsSuite")
     from clearing_operations_tests import ClearingOperationsTestSuite
     suite = ClearingOperationsTestSuite.getTestSuite()
     return suite
 
 def addIncidentAnalysisSuite():
     ''' Add all IncidentAnalysis tests  '''
-    if Configuration.DEBUG == True: print("TestRunner.py - addIncidentAnalysisSuite")
+    Configuration.Logger.debug("TestRunner.py - addIncidentAnalysisSuite")
     from incident_analysis_tests import IncidentAnalysisToolsTestSuite
     suite = IncidentAnalysisToolsTestSuite.getTestSuite()
     return suite
 
 def addSunPositionAnalysisSuite():
     ''' Add all SunPositionAnalysis tests '''
-    if Configuration.DEBUG == True: print("TestRunner.py - addSunPositionAnalysisSuite")
+    Configuration.Logger.debug("TestRunner.py - addSunPositionAnalysisSuite")
     from sun_position_analysis_tests import SunPositionAnalysisToolsTestSuite
     suite = SunPositionAnalysisToolsTestSuite.getTestSuite()
     return suite
 
 def addGeoNamesSuite():
     ''' Add all GeoNames tests '''
-    if Configuration.DEBUG == True: print("TestRunner.py - addGeoNamesSuite")
+    Configuration.Logger.debug("TestRunner.py - addGeoNamesSuite")
     from geonames_tests import GeoNamesToolsTestSuite
     suite = GeoNamesToolsTestSuite.getTestSuite()
     return suite
 
 def addDistanceToAssetsSuite():
     ''' Add all DistanceToAssets tests '''
-    if Configuration.DEBUG == True: print("TestRunner.py - addDistanceToAssetsSuite")
+    Configuration.Logger.debug("TestRunner.py - addDistanceToAssetsSuite")
     from distance_to_assets_tests import DistanceToAssetsTestSuite
     suite = DistanceToAssetsTestSuite.getTestSuite()
     return suite
 
 def addMilitaryFeaturesSuite():
     ''' Add all MilitaryFeatures tests '''
-    if Configuration.DEBUG == True: print("TestRunner.py - addMilitaryFeaturesSuite")
+    Configuration.Logger.debug("TestRunner.py - addMilitaryFeaturesSuite")
     from military_features_tests import MilitaryFeaturesToolsTestSuite
     suite = MilitaryFeaturesToolsTestSuite.getTestSuite()
     return suite
 
 # MAIN =============================================
 if __name__ == "__main__":
     if Configuration.DEBUG == True:
-        print("TestRunner.py")
-    exitAsCode = main()
-    if exitAsCode:
-        sys.exit(0)
-    else:
-        sys.exit(1)
+        print("Starting TestRunner.py")
+
+    exitAsBoolean = main()
+
+    exitAsCode = 0 if exitAsBoolean else 1
+
+    sys.exit(exitAsCode)

utils/test/UnitTestUtilities.py

@@ -87,7 +87,7 @@ def makeFolderFromPath(folderPath):
             print("Can't make the folder for some reason.")
     return folderPath
 
-def initializeLogger(name):
+def initializeLogger(name, logLevel = logging.DEBUG):
     ''' get and return named logger '''
     if Configuration.DEBUG == True:
         print("UnitTestUtilities - initializeLogger")
@@ -101,33 +101,45 @@ def initializeLogger(name):
         name = getLoggerName()
 
     logFile = os.path.join(Configuration.logPath, name)
+    Configuration.LoggerFile = logFile
 
     # if the log file does NOT exist, create it
     if not os.path.exists(logFile):
         logFile = makeFileFromPath(logFile)
 
-    logging.basicConfig(format='%(levelname)s: %(asctime)s %(message)s', filename=logFile, level=logging.DEBUG)
     logger = logging.getLogger(name)
+    logger.setLevel(logLevel)
+
+    logFormatter = logging.Formatter('%(levelname)s: %(asctime)s %(message)s')
+
+    fileHandler = logging.FileHandler(logFile)
+    fileHandler.setFormatter(logFormatter)
+    logger.addHandler(fileHandler)
+
+    consoleHandler = logging.StreamHandler(sys.stdout)
+    consoleHandler.setFormatter(logFormatter)
+    logger.addHandler(consoleHandler)
+
     return logger
 
 def setUpLogFileHeader():
-    ''' Add a header to log file when initalized '''
-    if Configuration.DEBUG == True:
-        print("UnitTestUtilities - setUpLogFileHeader")
-    Configuration.Logger.info("------------ Begin Test ------------------")
+    ''' Add a header to log file when initialized '''
+    Configuration.Logger.debug("UnitTestUtilities - setUpLogFileHeader")
+    Configuration.Logger.info("------------ Begin Tests ------------------")
     Configuration.Logger.info("Platform: {0}".format(platform.platform()))
     Configuration.Logger.info("Python Version {0}".format(sys.version))
-    d = arcpy.GetInstallInfo()
-    Configuration.Logger.info("{0} Version {1}, installed on {2}.".format(d['ProductName'], d['Version'], d['InstallDate']))
-    Configuration.Logger.info("----------------------------------------")
+    agsInstallInfo = arcpy.GetInstallInfo()
+    Configuration.Logger.info("Product: {0}, Version: {1}, Installed on: {2}, Build: {3}.".format(agsInstallInfo['ProductName'], \
+       agsInstallInfo['Version'], agsInstallInfo['InstallDate'], agsInstallInfo['BuildNumber']))
+    Configuration.Logger.info("-------------------------------------------")
 
 def checkArcPy():
     ''' sanity check that ArcPy is working '''
     if Configuration.DEBUG == True: print("UnitTestUtilities - checkArcPy")
     arcpy.AddMessage("ArcPy works")
 
 def checkExists(p):
-    ''' Python check for existance '''
+    ''' Python check for existence '''
     if Configuration.DEBUG == True: print("UnitTestUtilities - checkExists")
     return os.path.exists(p)