[Core] fix logging file fd leaking

src/azure-cli-core/azure/cli/core/azlogging.py

@@ -29,6 +29,7 @@
 
 from azure.cli.core.commands.events import EVENT_INVOKER_PRE_CMD_TBL_TRUNCATE
 
+from knack.events import EVENT_CLI_POST_EXECUTE
 from knack.log import CLILogging, get_logger
 from knack.util import ensure_dir
 
@@ -46,6 +47,7 @@ def __init__(self, name, cli_ctx=None):
         self.command_logger_handler = None
         self.command_metadata_logger = None
         self.cli_ctx.register_event(EVENT_INVOKER_PRE_CMD_TBL_TRUNCATE, AzCliLogging.init_command_file_logging)
+        self.cli_ctx.register_event(EVENT_CLI_POST_EXECUTE, AzCliLogging.deinit_cmd_metadata_logging)
 
     def get_command_log_dir(self):
         return self.command_log_dir
@@ -173,13 +175,18 @@ def log_cmd_metadata_extension_info(self, extension_name, extension_version):
             self.command_metadata_logger.info("extension name: %s", extension_name)
             self.command_metadata_logger.info("extension version: %s", extension_version)
 
-    def end_cmd_metadata_logging(self, exit_code):
+    @staticmethod
+    def deinit_cmd_metadata_logging(cli_ctx):
+        cli_ctx.logging.end_cmd_metadata_logging(cli_ctx.result.exit_code if cli_ctx.result else 128)
+
+    def end_cmd_metadata_logging(self, exit_code):  # leave it non '-' prefix to not to break user
         if self.command_metadata_logger:
             self.command_metadata_logger.info("exit code: %s", exit_code)
 
             # We have finished metadata logging, remove handler and set command_metadata_handler to None.
             # crucial to remove handler as in python logger objects are shared which can affect testing of this logger
             # we do not want duplicate handlers to be added in subsequent calls of _init_command_logfile_handlers
+            self.command_logger_handler.close()
             self.command_metadata_logger.removeHandler(self.command_logger_handler)
             self.command_metadata_logger = None
 

src/azure-cli-core/setup.py

@@ -56,7 +56,7 @@
     'colorama>=0.3.9',
     'humanfriendly>=4.7,<9.0',
     'jmespath',
-    'knack==0.7.0rc3',
+    'knack==0.7.0rc4',
     'msrest>=0.4.4',
     'msrestazure>=0.6.3',
     'paramiko>=2.0.8,<3.0.0',

src/azure-cli/azure/cli/__main__.py

@@ -47,7 +47,6 @@ def cli_main(cli, args):
 
     elapsed_time = timeit.default_timer() - start_time
 
-    az_cli.logging.end_cmd_metadata_logging(exit_code)
     sys.exit(exit_code)
 
 except KeyboardInterrupt:
@@ -61,7 +60,6 @@ def cli_main(cli, args):
     except NameError:
         pass
 
-    az_cli.logging.end_cmd_metadata_logging(exit_code)
     raise ex
 
 finally:

src/azure-cli/azure/cli/command_modules/feedback/tests/latest/test_feedback.py

@@ -9,6 +9,8 @@
 import time
 import unittest
 
+from knack.events import EVENT_CLI_POST_EXECUTE
+
 from azure.cli.core.azlogging import CommandLoggerContext
 from azure.cli.core.extension.operations import get_extensions, add_extension, remove_extension, WheelExtension
 from azure.cli.command_modules.feedback.custom import (_get_command_log_files, _build_issue_info_tup,
@@ -190,14 +192,20 @@ def _run_cmd(self, command, checks=None, expect_failure=False):
         cli_ctx = get_dummy_cli()
         cli_ctx.logging.command_log_dir = self.temp_command_log_dir
 
-        result = execute(cli_ctx, command, expect_failure=expect_failure).assert_with_checks(checks)
+        # hotfix here for untouch feedback's code to avoid introducing possible break change.
+        # unregister the event for auto closing CLI's file logging after execute() is done
+        cli_ctx.unregister_event(EVENT_CLI_POST_EXECUTE, cli_ctx.logging.deinit_cmd_metadata_logging)
 
         # manually handle error logging as azure.cli.core.util's handle_exception function is mocked out in testsdk / patches
         # this logged error tests that we can properly parse errors from command log file.
         with CommandLoggerContext(logger):
+            result = execute(cli_ctx, command, expect_failure=expect_failure).assert_with_checks(checks)
+
             if result.exit_code != 0:
                 logger.error("There was an error during execution.")
 
+        # close it manually because we unregister the deinit_cmd_metadata_logging
+        # callback from EVENT_CLI_POST_EXECUTE event
         cli_ctx.logging.end_cmd_metadata_logging(result.exit_code)
 
         return result

src/azure-cli/requirements.py3.Darwin.txt

@@ -100,7 +100,7 @@ isodate==0.6.0
 Jinja2==2.10.1
 jmespath==0.9.4
 jsmin==2.2.2
-knack==0.7.0rc3
+knack==0.7.0rc4
 MarkupSafe==1.1.1
 mock==4.0.2
 msrestazure==0.6.3

src/azure-cli/requirements.py3.Linux.txt

@@ -100,7 +100,7 @@ isodate==0.6.0
 Jinja2==2.10.1
 jmespath==0.9.4
 jsmin==2.2.2
-knack==0.7.0rc3
+knack==0.7.0rc4
 MarkupSafe==1.1.1
 mock==4.0.2
 msrest==0.6.9

src/azure-cli/requirements.py3.windows.txt

@@ -98,7 +98,7 @@ isodate==0.6.0
 Jinja2==2.10.1
 jmespath==0.9.4
 jsmin==2.2.2
-knack==0.7.0rc3
+knack==0.7.0rc4
 MarkupSafe==1.1.1
 mock==4.0.2
 msrest==0.6.9

src/azure-cli/setup.py

@@ -131,7 +131,7 @@
     'cryptography>=2.3.1,<3.0.0',
     'fabric~=2.4',
     'jsmin~=2.2.2',
-    'knack==0.7.0rc3',
+    'knack==0.7.0rc4',
     'mock~=4.0',
     'paramiko>=2.0.8,<3.0.0',
     'pyOpenSSL>=17.1.0',