Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add debug logs to packager #934

Merged
merged 4 commits into from
Dec 4, 2018
Merged

Conversation

stealthycoin
Copy link
Contributor

Add debug logs to packager

Added log statements to track the state of all packages in between each
step during the packaging process. A function in the CLI layer was added
to enable this logger when the --debug flag is passed.

@codecov-io
Copy link

codecov-io commented Aug 15, 2018

Codecov Report

Merging #934 into master will increase coverage by <.01%.
The diff coverage is 96.15%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master     #934      +/-   ##
==========================================
+ Coverage   95.52%   95.52%   +<.01%     
==========================================
  Files          27       27              
  Lines        4449     4474      +25     
  Branches      558      560       +2     
==========================================
+ Hits         4250     4274      +24     
  Misses        128      128              
- Partials       71       72       +1
Impacted Files Coverage Δ
chalice/cli/factory.py 92.85% <ø> (-0.05%) ⬇️
chalice/deploy/packager.py 95.87% <100%> (+0.15%) ⬆️
chalice/cli/__init__.py 87.4% <91.66%> (+0.2%) ⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update a4f8a79...b84c32c. Read the comment docs.

Copy link
Contributor

@kyleknap kyleknap left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks fine. Just some comments.

@@ -27,6 +28,9 @@
OptStr = Optional[str]
OptBytes = Optional[bytes]

LOGGER_NAME = 'packager'
logger = logging.getLogger(LOGGER_NAME)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can just use __name__ here instead of LOGGER_NAME. This allows the file to get moved around without having to update the string.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah I'm fine with just using __name__ and having this be part of our standard debug logs.

req_file = os.path.join(local_app, 'requirements.txt')
with open(req_file, 'w') as f:
f.write('pip==10.0.0\n')
p = subprocess.Popen(['chalice', '--debug', 'package', 'out'],
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So the coverage is down because it is being ran in a subprocess?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes unless i'm missing something I cant see how to even test top level args with the click test runner.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does just passing the cli function to the click runner not work?

@@ -405,6 +415,7 @@ def _download_dependencies(self, directory, requirements_filename):
# compiler.
compatible_wheels, incompatible_wheels = self._categorize_wheel_files(
directory)
logger.debug("compatible: %s", compatible_wheels)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks like there are a few compatible repeats. It may be good to update it so the statements are unique so it is not ambiguous where the debug line is coming from and worded in a way that I do not have to dive into the code to see at what step the compatible log entry is getting written.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yea so I think this is unavoidable. The logs are only useful if I can see the state of the world between each step.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think Kyle's just asking to add something besides "compatible" so that similar lines (such as line 404) can be distinguished without having to dig through the source code. Maybe something like compatible wheels after second download pass, compatible wheels after categorization, etc.

@@ -363,6 +380,9 @@ def generate_sdk(ctx, sdk_type, stage, outdir):
def package(ctx, single_file, stage, out):
# type: (click.Context, bool, str, str) -> None
factory = ctx.obj['factory'] # type: CLIFactory
debug = ctx.obj['debug'] # type: bool
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder if it makes sense to instantiate this at the cli level so it gets essentially set for all chalice commands? While it is not bad for two commands, I think we should try to avoid having to do this every time to a new command that needs logs displayed when running --debug. We also set it when we create the botocore session. So there is definitely some potential refactoring. Also what was the reasoning behind not setting the logger name to an empty string?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This was more of a POC to facilitate this discussion. Not sure how we want to do logging, nor am I sure how it should be done with click or if there is a better pattern available.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think at least for now, we should have a single place that configures logging. We were previously relying on the set_debug_logger() in the botocore session previously, but now that we're adding our own logging in chalice, we should just do the configuration ourselves and not rely on botocore's configuration.

It might be simplest to just call _configure_logging() in cli() and remove the call to set_debug_logger() in the CLIFactory.

Added log statements to track the state of all packages in between each
step during the packaging process. A function in the CLI layer was added
to enable this logger when the --debug flag is passed.
@jamesls jamesls self-assigned this Nov 29, 2018
@kyleknap kyleknap assigned kyleknap and unassigned jamesls Dec 4, 2018
def test_can_create_botocore_session():
session = factory.create_botocore_session()
assert session.user_agent().startswith('aws-chalice/')
assert session.get_default_client_config() is None


def test_can_create_botocore_session_debug():
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not sure why this was removed. Can you add this back (unless you know why it needs to be removed)?

@kyleknap kyleknap merged commit a6a4f33 into aws:master Dec 4, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants