Track debug info into a log file

Cmheidelberg commented 4 years ago

Is your feature request related to a problem? Please describe. It can be difficult to track problems on others machines, and we want to reduce the debug info printed to the terminal. Best solution would be to track debug information into a log file the user can attack to any issues so we can help

Describe the solution you'd like Track any debug information into a log file so we can reproduce issues and fix bugs. Things to track:

basic user system information on start
Which commands are being used
Any error codes
Misc debug items that could be important to fixing an issue

issue-label-bot[bot] commented 4 years ago

Issue-Label Bot is automatically applying the label feature_request to this issue, with a confidence of 0.98. Please mark this comment with :thumbsup: or :thumbsdown: to give our bot feedback!

Links: app homepage, dashboard and code for this bot.

Cmheidelberg commented 4 years ago

@mosoriob what are your thoughts on this logging format

my run:

# mic pkg start
# mic pkg trace a.txt in.txt 14
# mic pkg trace ./addtoarray.sh a.txt in.txt 14
# mic pkg inputs
# mic pkg outputs
# mic pkg parameters --name hello --value 4

mic.log

2020-07-21 15:19:38,392 mic          INFO     Log file created
2020-07-21 15:19:38,392 mic          INFO     OS: {'name': 'Linux', 'data': {'version': '#44-Ubuntu SMP Tue Jun 23 00:01:04 UTC 2020', 'release': '5.4.0-40-generic', 'machine': 'x86_64'}}
2020-07-21 15:19:38,393 mic          INFO     MIC Version: 1.2.0
2020-07-21 15:19:38,393 mic.commands INFO     Command: {'name': 'start', 'inputs': {'name': {'value': 'name', 'type': <class 'str'>}, 'image': {'value': None, 'type': <class 'NoneType'>}}}
2020-07-21 15:20:16,890 mic.commands INFO     Command: {'name': 'trace', 'inputs': {'command': {'value': ('a.txt', 'in.txt', '14'), 'type': <class 'tuple'>}, 'continu': {'value': None, 'type': <class 'NoneType'>}, 'overwrite': {'value': None, 'type': <class 'NoneType'>}}}
2020-07-21 15:20:26,816 mic.commands INFO     Command: {'name': 'trace', 'inputs': {'command': {'value': ('./addtoarray.sh', 'a.txt', 'in.txt', '14'), 'type': <class 'tuple'>}, 'continu': {'value': None, 'type': <class 'NoneType'>}, 'overwrite': {'value': None, 'type': <class 'NoneType'>}}}
2020-07-21 15:20:35,541 mic.commands INFO     Command: {'name': 'add_parameters', 'inputs': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': <class 'str'>}, 'custom_inputs': {'value': (), 'type': <class 'tuple'>}}}
2020-07-21 15:20:46,419 mic.commands INFO     Command: {'name': 'outputs', 'inputs': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': <class 'str'>}, 'custom_outputs': {'value': (), 'type': <class 'tuple'>}}}
2020-07-21 15:21:00,039 mic.commands INFO     Command: {'name': 'add_parameters', 'inputs': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': <class 'str'>}, 'name': {'value': 'hello', 'type': <class 'str'>}, 'value': {'value': 4, 'type': <class 'int'>}, 'overwrite': {'value': False, 'type': <class 'bool'>}, 'description': {'value': None, 'type': <class 'NoneType'>}}}

Using json objects looks a little ugly but it will make it easier to parse the log when looking for something. Also dicts let me dynamically list data. The name (mic and mic.commands) reference what python file the log was made from, which should make tracking down bugs easier (ie mic.commands means the log came from commands.py). I still have to log everything but this is the basic infrastructure I have set up.

Cmheidelberg commented 4 years ago

Here is a more fleshed out example. This is one where I go through all the commands and have a crash on upload: Commands:

# mic pkg start
# mic pkg trace ./addtoarray.sh a.txt in.txt 43
# mic pkg inputs
# mic pkg outputs
# mic pkg parameters
# mic pkg wrapper
# mic pkg run
# mic pkg upload

log:

mic   _utils.py          INFO     Log file created
mic   _utils.py          INFO     OS: {'name': 'Linux', 'data': {'version': '#46-Ubuntu SMP Fri Jul 10 00:24:02 UTC 2020', 'release': '5.4.0-42-generic', 'machine': 'x86_64'}}
mic   _utils.py          INFO     MIC Version: 1.2.0
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'start', 'command_parameters': {'name': {'value': 'test', 'type': 'str'}, 'image': {'value': None, 'type': 'NoneType'}}}
mic   initialization.py  DEBUG    detecting framework(s): []
mic   docker.py          INFO     Downloading and building base docker image
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'name', 'value': 'test'}}
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'docker_image', 'value': 'test:latest'}}
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'framework', 'value': <Framework.GENERIC: ('general', 'mintproject/generic:latest')>}}
mic   commands.py        INFO     start done
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'trace', 'command_parameters': {'invocation_command': {'value': ('./addtoarray.sh', 'a.txt', 'in.txt', '43'), 'type': 'tuple'}, 'continu': {'value': None, 'type': 'NoneType'}, 'overwrite': {'value': None, 'type': 'NoneType'}}}
mic   commands.py        DEBUG    Append mode: None
mic   commands.py        INFO     trace done
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'inputs', 'command_parameters': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': 'str'}, 'custom_inputs': {'value': (), 'type': 'tuple'}}}
mic   commands.py        DEBUG    Inputs found from reprozip: ['/home/chris/Desktop/tests/test_logger/in.txt', '/home/chris/Desktop/tests/test_logger/a.txt', '/home/chris/Desktop/tests/test_logger/addtoarray.sh', '/home/chris/Desktop/tests/test_logger/outputs']
mic   reprozip.py        DEBUG    Adding executable: addtoarray.sh
mic   commands.py        DEBUG    code files found from reprozip: ['/home/chris/Desktop/tests/test_logger/addtoarray.sh']
mic   commands.py        INFO     Input added: in.txt
mic   commands.py        INFO     Input added: a.txt
mic   commands.py        INFO     Ignoring the config as an input: /home/chris/Desktop/tests/test_logger/addtoarray.sh
mic   commands.py        INFO     Skipping: /home/chris/Desktop/tests/test_logger/outputs
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'inputs', 'value': {'in_txt': {'path': 'in.txt', 'format': 'txt'}, 'a_txt': {'path': 'a.txt', 'format': 'txt'}}}}
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'code_files', 'value': {'addtoarray_sh': {'path': 'addtoarray.sh', 'format': 'sh'}}}}
mic   commands.py        INFO     inputs done
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'outputs', 'command_parameters': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': 'str'}, 'custom_outputs': {'value': (), 'type': 'tuple'}}}
mic   commands.py        DEBUG    Outputs found from reprozip: ['/home/chris/Desktop/tests/test_logger/outputs/out.csv']
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'outputs', 'value': {'out_csv': {'path': 'outputs/out.csv', 'format': 'csv'}}}}
mic   commands.py        INFO     outputs done
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'add_parameters', 'command_parameters': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': 'str'}, 'name': {'value': None, 'type': 'NoneType'}, 'value': {'value': None, 'type': 'NoneType'}, 'overwrite': {'value': False, 'type': 'bool'}, 'description': {'value': None, 'type': 'NoneType'}}}
mic   commands.py        INFO     Automatically adding any parameters from trace
mic   reprozip.py        DEBUG    Adding parameter: param_1
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'parameters', 'value': {'param_1': {'name': '', 'default_value': '43', 'type': 'int', 'description': ''}}}}
mic   commands.py        INFO     add_parameters done
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'wrapper', 'command_parameters': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': 'str'}}}
mic   commands.py        INFO     Generating wrapper code
mic   reprozip.py        DEBUG    Pre runner code: ''
mic   reprozip.py        DEBUG    Runner code: '\npushd .\n/bin/sh ./addtoarray.sh ${a_txt} ${in_txt} ${param_1}\npopd'
mic   initialization.py  DEBUG    run file rendered
mic   initialization.py  DEBUG    io file rendered
mic   commands.py        INFO     wrapper done
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'run', 'command_parameters': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': 'str'}}}
mic   commands.py        INFO     run done
mic   _utils.py          INFO     <=================>
mic   _utils.py          INFO     Command: {'name': 'run', 'command_parameters': {'mic_file': {'value': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'type': 'str'}, 'profile': {'value': 'default', 'type': 'str'}, 'model_configuration': {'value': True, 'type': 'bool'}, 'data_transformation': {'value': None, 'type': 'NoneType'}}}
mic   github.py          INFO     Creating the git repository
mic   github.py          INFO     Compressing code
mic   github.py          INFO     Creating a new commit
mic   github.py          DEBUG    No remote server configured. Creating new GitHub repository
mic   github.py          INFO     Selected repository already exists
mic   config_yaml.py     DEBUG    Writing to spec: {'file': '/home/chris/Desktop/tests/test_logger/mic/mic.yaml', 'data': {'key': 'github_repo_url', 'value': 'https://github.com/Cmheidelberg/test.git'}}
mic   github.py          INFO     Creating a new version
mic   github.py          DEBUG    New version: 20.7.1
mic   github.py          INFO     Pushing changes to the server
mic   commands.py        ERROR    Upload failed: 1 uncommitted change would be overwritten by merge
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/mic-1.2.0-py3.8.egg/mic/click_encapsulate/commands.py", line 664, in upload
    push(mic_config_path.parent, mic_config_path, name, profile)
  File "/usr/local/lib/python3.8/dist-packages/mic-1.2.0-py3.8.egg/mic/publisher/github.py", line 44, in push
    git_pull(repo, remote)
  File "/usr/local/lib/python3.8/dist-packages/mic-1.2.0-py3.8.egg/mic/publisher/github.py", line 152, in git_pull
    repo.merge(remote_master_id)
_pygit2.GitError: 1 uncommitted change would be overwritten by merge

mintproject / mic

Track debug info into a log file #262