Improves logging and adds support for logging.code() calls

Implements storage account list command.

src/azure/cli/__main__.py

@@ -1,12 +1,13 @@
 import time
 _import_time = time.perf_counter()
 
-import logging
 import sys
 
 import azure.cli.main
+from azure.cli._logging import logging
+
 try:
     sys.exit(azure.cli.main.main(sys.argv[1:]))
 finally:
-    # Note: script time includes idle time
-    logging.info('Script time: %8.3fms', 1000 * (time.perf_counter() - _import_time))
+    # Note: script time includes idle and network time
+    logging.info('Execution time: %8.3fms', 1000 * (time.perf_counter() - _import_time))

src/azure/cli/_argparse.py

@@ -1,9 +1,10 @@
 from __future__ import print_function
 import json
-import logging
 import os
 import sys
 
+from ._logging import logging
+
 # Named arguments are prefixed with one of these strings
 ARG_PREFIXES = sorted(('-', '--', '/'), key=len, reverse=True)
 
@@ -37,6 +38,7 @@ def __getattr__(self, key):
             return self[key]
         except LookupError:
             pass
+        logging.debug('Argument %s is required', key)
         raise IncorrectUsageError(_("Argument {0} is required").format(key))
 
 def _read_arg(string):
@@ -142,7 +144,7 @@ def execute(self, args, show_usage=False, show_completions=False, out=sys.stdout
         if not show_completions:
             show_completions = any(a in self.complete_args for a in args)
 
-        all_global_args = self.help_args | self.complete_args | self.global_args
+        all_global_args = set(a.lstrip('-/') for a in self.help_args | self.complete_args | self.global_args)
         def not_global(a):
             return a.lstrip('-/') not in all_global_args
         it = filter(not_global, args)
@@ -165,6 +167,7 @@ def not_global(a):
             expected_kwargs = m['$kwargs']
             handler = m['$handler']
         except LookupError:
+            logging.debug('Missing data for noun %s', n)
             show_usage = True
 
         if show_completions:
@@ -201,11 +204,15 @@ def not_global(a):
                 parsed.positional.append(n)
             n = next_n
 
+        old_stdout = sys.stdout
         try:
+            sys.stdout = out
             return handler(parsed, others)
         except IncorrectUsageError as ex:
             print(str(ex), file=out)
             return self.display_usage(nouns, m, args, out)
+        finally:
+            sys.stdout = old_stdout
 
     def _display_usage(self, nouns, noun_map, arguments, out=sys.stdout):
         spec = ' '.join(noun_map.get('$spec') or nouns)

src/azure/cli/_logging.py

@@ -1,4 +1,33 @@
-import logging
+import logging as _logging
+import sys
+
+_CODE_LEVEL = _logging.INFO + 1
+
+class Logger(_logging.Logger):
+    def __init__(self, name, level = _logging.NOTSET):
+        super(Logger, self).__init__(name, level)
+
+    def code(self, msg, *args):
+        self._log(_CODE_LEVEL, msg, args)
+
+logging = Logger('az', _logging.WARNING)
+
+class PyFileFormatter(_logging.Formatter):
+    def __init__(self):
+        super(PyFileFormatter, self).__init__('# %(levelname)s: %(message)s')
+        self.info_style = _logging.PercentStyle('%(message)s')
+
+    def format(self, record):
+        assert isinstance(record, _logging.LogRecord)
+        if record.levelno == _CODE_LEVEL:
+            return record.getMessage()
+        return super(PyFileFormatter, self).format(record)
+
+def _arg_name(arg):
+    a = arg.lstrip('-/')
+    if a == arg:
+        return None
+    return a.lower()
 
 def configure_logging(argv, config):
     # TODO: Configure logging handler to log messages to .py file
@@ -8,11 +37,44 @@ def configure_logging(argv, config):
     #   WARNING/ERROR messages as clearly marked comments
 
     # Currently we just use the default format
-    level = logging.WARNING
-    if '-v' in argv or '--verbose' in argv or config.get('verbose'):
-        level = logging.INFO
-
-    if '--debug' in argv or config.get('debug'):
-        level = logging.DEBUG
-
-    logging.basicConfig(level=level)
+    level = _logging.WARNING
+    if config.get('verbose'):
+        level = _logging.INFO
+    if config.get('debug'):
+        level = _logging.DEBUG
+
+    logfile = None
+    i = 0
+    while i < len(argv):
+        arg = _arg_name(argv[i])
+        if arg in ('v', 'verbose'):
+            level = _logging.INFO
+            argv.pop(i)
+        elif arg in ('debug',):
+            level = _logging.DEBUG
+            argv.pop(i)
+        elif arg in ('log',):
+            argv.pop(i)
+            try:
+                logfile = argv.pop(i)
+            except IndexError:
+                pass
+        else:
+            i += 1
+    logging.setLevel(_logging.INFO)
+
+    stderr_handler = _logging.StreamHandler(sys.stderr)
+    stderr_handler.formatter = _logging.Formatter('%(levelname)s: %(message)s')
+    stderr_handler.level = level
+    logging.handlers.append(stderr_handler)
+
+    if logfile and logfile.lower().endswith('.py'):
+        py_handler = _logging.StreamHandler(open(logfile, 'w', encoding='utf-8'))
+        py_handler.formatter = PyFileFormatter()
+        py_handler.level = level if level == _logging.DEBUG else _logging.INFO
+        logging.handlers.append(py_handler)
+    elif logfile:
+        log_handler = _logging.StreamHandler(open(logfile, 'w', encoding='utf-8'))
+        log_handler.formatter = _logging.Formatter('[%(levelname)s:%(asctime)s] %(message)s')
+        log_handler.level = level if level == _logging.DEBUG else _logging.INFO
+        logging.handlers.append(log_handler)

src/azure/cli/_util.py

@@ -1,11 +1,38 @@
-import logging
 import types
 
-try:
-    from importlib import import_module
-except ImportError:
-    def import_module(mod):
-        m = __import__(mod)
-        for b in mod.split('.'):
-            m = gettatr(m, b)
-        return m
+class TableOutput(object):
+    def __enter__(self):
+        self._rows = [{}]
+        self._columns = {}
+        self._column_order = []
+        return self
+
+    def __exit__(self, ex_type, ex_value, ex_tb):
+        if ex_type:
+            return
+        if len(self._rows) == 1:
+            return
+
+        cols = [(c, self._columns[c]) for c in self._column_order]
+        print(' | '.join(c.center(w) for c, w in cols))
+        print('-|-'.join('-' * w for c, w in cols))
+        for r in self._rows[:-1]:
+            print(' | '.join(r[c].ljust(w) for c, w in cols))
+        print()
+
+    @property
+    def any_rows(self):
+        return len(self._rows) > 1
+
+    def cell(self, name, value):
+        n = str(name)
+        v = str(value)
+        max_width = self._columns.get(n)
+        if max_width is None:
+            self._column_order.append(n)
+            max_width = len(n)
+        self._rows[-1][n] = v
+        self._columns[n] = max(max_width, len(v))
+
+    def end_row(self):
+        self._rows.append({})

src/azure/cli/commands/__init__.py

@@ -1,6 +1,5 @@
-import logging
-
 from .._argparse import IncorrectUsageError
+from .._logging import logging
 
 # TODO: Alternatively, simply scan the directory for all modules
 COMMAND_MODULES = [

src/azure/cli/commands/login.py

@@ -1,4 +1,4 @@
-import logging
+from .._logging import logging
 from ..main import CONFIG, SESSION
 from ..commands import command, description, option
 

src/azure/cli/commands/storage.py

@@ -1,26 +1,53 @@
-import logging
 from ..main import CONFIG, SESSION
-from ..commands import command, option
+from .._logging import logging
+from .._util import TableOutput
+from ..commands import command, description, option
 
-@command('storage test')
-@option('<pos>')
-@option('--bool')
-@option('--arg <value>')
-def test(args, unexpected):
-    print('test', args.positional)
-    print('test', args)
+@command('storage account list')
+@description('List storage accounts')
+@option('--resource-group -g <resourceGroup>', _("the resource group name"))
+@option('--subscription -s <id>', _("the subscription id"))
+def list_accounts(args, unexpected):
+    from azure.mgmt.storage import StorageManagementClient, StorageManagementClientConfiguration
+    from azure.mgmt.storage.models import StorageAccount
+    from msrestazure.azure_active_directory import UserPassCredentials
+
+    username = ''   # TODO: get username somehow
+    password = ''   # TODO: get password somehow
+
+    logging.code('''smc = StorageManagementClient(StorageManagementClientConfiguration(
+    credentials=UserPassCredentials(%r, %r),
+    subscription_id=%r
+)''', username, password, args.subscription)
+    smc = StorageManagementClient(StorageManagementClientConfiguration(
+        credentials=UserPassCredentials(username, password),
+        subscription_id=args.subscription,
+    ))
+
+    group = args.get('resource-group')
+    if group:
+        logging.code('accounts = smc.storage_accounts.list_by_resource_group(%r)', group)
+        accounts = smc.storage_accounts.list_by_resource_group(group)
+    else:
+        logging.code('accounts = smc.storage_accounts.list()')
+        accounts = smc.storage_accounts.list()
 
-@command('storage test subtest')
-def subtest(args, unexpected):
-    print('subtest', args.positional)
-    print('subtest', args)
+    with TableOutput() as to:
+        for acc in accounts:
+            assert isinstance(acc, StorageAccount)
+            to.cell('Name', acc.name)
+            to.cell('Type', acc.account_type)
+            to.cell('Location', acc.location)
+            to.end_row()
+        if not to.any_rows:
+            print('No storage accounts defined')
 
 @command('storage account check')
 @option('--account-name <name>')
 def checkname(args, unexpected):
     from azure.mgmt.storage import StorageManagementClient, StorageManagementClientConfiguration
 
-    logging.info('''smc = StorageManagementClient(StorageManagementClientConfiguration())
+    logging.code('''smc = StorageManagementClient(StorageManagementClientConfiguration())
 smc.storage_accounts.check_name_availability({0.account_name!r})
 '''.format(args))
 

src/azure/cli/main.py

@@ -1,13 +1,11 @@
 import gettext
-import logging
 import os
 
 gettext.install("az", os.path.join(os.path.abspath(__file__), '..', 'locale'))
 
 from ._argparse import ArgumentParser
-from ._logging import configure_logging
+from ._logging import configure_logging, logging
 from ._session import Session
-from ._util import import_module
 
 # CONFIG provides external configuration options
 CONFIG = Session()

src/azure/cli/tests/test_argparse.py

@@ -1,7 +1,7 @@
 import unittest
-import logging
 
 from azure.cli._argparse import ArgumentParser, IncorrectUsageError
+from azure.cli._logging import logging
 
 class Test_argparse(unittest.TestCase):
     @classmethod