Refactor execute to use wrapper for logging

Avoid each implementation of Command to call logging and use
a wrapped to log executions of each subclass.

src/molecule/command/base.py

@@ -37,6 +37,20 @@
 MOLECULE_DEFAULT_SCENARIO_NAME = "default"
 
 
+def section_logger(func: Callable) -> Callable:
+    """Wrap effective execution of a method."""
+
+    def wrapper(*args, **kwargs):
+        # LOG.error("start %s %s", dir(args[0]), kwargs)
+        args[0].print_info()
+        rt = func(*args, **kwargs)
+        # LOG.error("stop")
+        return rt
+
+    # wrapper.inherit_decorator = section_logger
+    return wrapper
+
+
 class Base(object, metaclass=abc.ABCMeta):
     """An abstract base class used to define the command interface."""
 
@@ -50,7 +64,13 @@ def __init__(self, c):
         self._config = c
         self._setup()
 
+    def __init_subclass__(cls) -> None:
+        """Decorate execute from all subclasses."""
+        super().__init_subclass__()
+        setattr(cls, "execute", section_logger(cls.execute))
+
     @abc.abstractmethod
+    @section_logger
     def execute(self):  # pragma: no cover
         pass
 
@@ -141,7 +161,8 @@ def execute_subcommand(config, subcommand):
     # and is also used for reporting in execute_cmdline_scenarios
     config.action = subcommand
 
-    return command(config).execute()
+    result = command(config).execute()
+    return result
 
 
 def execute_scenario(scenario):

src/molecule/command/check.py

@@ -79,7 +79,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         self._config.provisioner.check()
 
 

src/molecule/command/cleanup.py

@@ -73,8 +73,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
-
         if not self._config.provisioner.playbooks.cleanup:
             msg = "Skipping, cleanup playbook not configured."
             LOG.warning(msg)

src/molecule/command/converge.py

@@ -79,7 +79,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         self._config.provisioner.converge()
         self._config.state.change_state("converged", True)
 

src/molecule/command/create.py

@@ -78,7 +78,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         self._config.state.change_state("driver", self._config.driver.name)
 
         if self._config.driver.delegated and not self._config.driver.managed:

src/molecule/command/dependency.py

@@ -70,7 +70,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         self._config.dependency.execute()
 
 

src/molecule/command/destroy.py

@@ -93,8 +93,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
-
         if self._config.command_args.get("destroy") == "never":
             msg = "Skipping, '--destroy=never' requested."
             LOG.warning(msg)

src/molecule/command/idempotence.py

@@ -74,7 +74,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         if not self._config.state.converged:
             msg = "Instances not converged.  Please converge instances first."
             util.sysexit_with_message(msg)

src/molecule/command/lint.py

@@ -80,8 +80,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
-
         # v3 migration code:
         cmd = self._config.lint
         if not cmd:

src/molecule/command/prepare.py

@@ -89,8 +89,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
-
         if self._config.state.prepared and not self._config.command_args.get("force"):
             msg = "Skipping, instances already prepared."
             LOG.warning(msg)

src/molecule/command/side_effect.py

@@ -72,7 +72,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         if not self._config.provisioner.playbooks.side_effect:
             msg = "Skipping, side effect playbook not configured."
             LOG.warning(msg)

src/molecule/command/syntax.py

@@ -69,7 +69,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         self._config.provisioner.syntax()
 
 

src/molecule/command/verify.py

@@ -70,7 +70,6 @@ def execute(self):
 
         :return: None
         """
-        self.print_info()
         self._config.verifier.execute()