FIX #1120: Logging ignoring level set in setup_logging

Configuration.setup_logging(level, ...):

* Need to reassign new level to self.logging_level
  REASON: config.logging_level is used in
  "behave.log_capture.LoggingCapture" and "behave.log_capture.capture"

CHANGES.rst

@@ -89,6 +89,7 @@ FIXED:
 * FIXED: Some tests related to python3.11
 * FIXED: Some tests related to python3.9
 * FIXED: active-tag logic if multiple tags with same category exists.
+* issue #1120: Logging ignoring level set in setup_logging (submitted by: j7an)
 * issue #1070: Color support detection: Fails for WindowsTerminal (provided by: jenisys)
 * issue #1116: behave erroring in pretty format in pyproject.toml (submitted by: morning-sunn)
 * issue #1061: Scenario should inherit Rule tags (submitted by: testgitdl)

behave/configuration.py

@@ -18,6 +18,7 @@
 import json
 import logging
 from logging.config import fileConfig as logging_config_fileConfig
+from logging import _checkLevel as logging_check_level
 import os
 import re
 import sys
@@ -1117,6 +1118,9 @@ def before_all(context):
         """
         if level is None:
             level = self.logging_level      # pylint: disable=no-member
+        else:
+            # pylint: disable=import-outside-toplevel
+            level = logging_check_level(level)
 
         if configfile:
             logging_config_fileConfig(configfile)
@@ -1127,7 +1131,10 @@ def before_all(context):
             logging.basicConfig(format=format_, datefmt=datefmt, **kwargs)
         # -- ENSURE: Default log level is set
         #    (even if logging subsystem is already configured).
+        # -- HINT: Ressign to self.logging_level
+        #    NEEDED FOR: behave.log_capture.LoggingCapture, capture
         logging.getLogger().setLevel(level)
+        self.logging_level = level  # pylint: disable=W0201
 
     def setup_model(self):
         if self.scenario_outline_annotation_schema:

behave/log_capture.py

@@ -180,9 +180,10 @@ def abandon(self):
 def capture(*args, **kw):
     """Decorator to wrap an *environment file function* in log file capture.
 
-    It configures the logging capture using the *behave* context - the first
-    argument to the function being decorated (so don't use this to decorate
-    something that doesn't have *context* as the first argument.)
+    It configures the logging capture using the *behave* context,
+    the first argument to the function being decorated
+    (so don't use this to decorate something that
+    doesn't have *context* as the first argument).
 
     The basic usage is:
 
@@ -192,9 +193,9 @@ def capture(*args, **kw):
         def after_scenario(context, scenario):
             ...
 
-    The function prints any captured logging (at the level determined by the
-    ``log_level`` configuration setting) directly to stdout, regardless of
-    error conditions.
+    The function prints any captured logging
+    (at the level determined by the ``log_level`` configuration setting)
+    directly to stdout, regardless of error conditions.
 
     It is mostly useful for debugging in situations where you are seeing a
     message like::
@@ -210,8 +211,8 @@ def after_scenario(context, scenario):
         def after_scenario(context, scenario):
             ...
 
-    This would limit the logging captured to just ERROR and above, and thus
-    only display logged events if they are interesting.
+    This would limit the logging captured to just ERROR and above,
+    and thus only display logged events if they are interesting.
     """
     def create_decorator(func, level=None):
         def f(context, *args):

issue.features/issue1120.feature

@@ -0,0 +1,87 @@
+@issue
+Feature: Issue #1120 -- Logging ignoring level set in setup_logging
+
+  . DESCRIPTION OF SYNDROME (OBSERVED BEHAVIOR):
+  .  * I setup logging-level in "before_all()" hook w/ context.config.setup_logging()
+  .  * I use logging in "after_scenario()" hook
+  .  * Even levels below "logging.WARNING" are shown
+
+  Background: Setup
+    Given a new working directory
+    And a file named "features/steps/use_step_library.py" with:
+      """
+      import behave4cmd0.passing_steps
+      import behave4cmd0.failing_steps
+      """
+    And a file named "features/simple.feature" with:
+      """
+      Feature: F1
+        Scenario: S1
+          Given a step passes
+          When another step passes
+      """
+
+  Scenario: Check Syndrome
+    Given a file named "features/environment.py" with:
+      """
+      from __future__ import absolute_import, print_function
+      import logging
+      from behave.log_capture import capture
+
+      def before_all(context):
+          context.config.setup_logging(logging.WARNING)
+
+      @capture
+      def after_scenario(context, scenario):
+          logging.debug("THIS_LOG_MESSAGE::debug")
+          logging.info("THIS_LOG_MESSAGE::info")
+          logging.warning("THIS_LOG_MESSAGE::warning")
+          logging.error("THIS_LOG_MESSAGE::error")
+          logging.critical("THIS_LOG_MESSAGE::critical")
+      """
+    When I run "behave features/simple.feature"
+    Then it should pass with:
+      """
+      1 feature passed, 0 failed, 0 skipped
+      """
+    And the command output should contain "THIS_LOG_MESSAGE::critical"
+    And the command output should contain "THIS_LOG_MESSAGE::error"
+    And the command output should contain "THIS_LOG_MESSAGE::warning"
+    But the command output should not contain "THIS_LOG_MESSAGE::debug"
+    And the command output should not contain "THIS_LOG_MESSAGE::info"
+
+
+  Scenario: Workaround for Syndrome (works without fix)
+    Given a file named "features/environment.py" with:
+      """
+      from __future__ import absolute_import, print_function
+      import logging
+      from behave.log_capture import capture
+
+      def before_all(context):
+          # -- HINT: Use behave.config.logging_level from config-file
+          context.config.setup_logging()
+
+      @capture
+      def after_scenario(context, scenario):
+          logging.debug("THIS_LOG_MESSAGE::debug")
+          logging.info("THIS_LOG_MESSAGE::info")
+          logging.warning("THIS_LOG_MESSAGE::warning")
+          logging.error("THIS_LOG_MESSAGE::error")
+          logging.critical("THIS_LOG_MESSAGE::critical")
+      """
+    And a file named "behave.ini" with:
+      """
+      [behave]
+      logging_level = WARNING
+      """
+    When I run "behave features/simple.feature"
+    Then it should pass with:
+      """
+      1 feature passed, 0 failed, 0 skipped
+      """
+    And the command output should contain "THIS_LOG_MESSAGE::critical"
+    And the command output should contain "THIS_LOG_MESSAGE::error"
+    And the command output should contain "THIS_LOG_MESSAGE::warning"
+    But the command output should not contain "THIS_LOG_MESSAGE::debug"
+    And the command output should not contain "THIS_LOG_MESSAGE::info"