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

too many common errors are offuscated in ansible, requiring run with --debug #1666

Closed
ssbarnea opened this issue Jan 15, 2019 · 11 comments
Closed
Assignees

Comments

@ssbarnea
Copy link
Member

ssbarnea commented Jan 15, 2019

This is a generic issue with molecule which can really put many users off: a big number of very common execution errors are offuscated by crytic errors and you never find the cause till you run molecule again in debug mode.

One such example: what happens if local docker is stopped. Just try it.

Expected behaviour: get a clear error and not have to run molecule in debug mode in order to find out the cause.

Another issue that make this issue even more problematic is that --debug is extreamly verbose and as far as I know there is nothing in-between normal execution and debug mode. For example I almost never found useful to see the "blue" connection messages, but the other changes in verbosity did prove essential for debugging errors. It may be my lack of knowledge but I wasn't able to find something less verbose.

@decentral1se
Copy link
Contributor

Agree with all points here. We can make improvements.

One such example: what happens if local docker is stopped. Just try it.

One idea is to introduce a validation layer right at the start of the run which asks which driver is being requested, in your example, Docker, and then trys to check if it is up and ready to run. We could bail out with some nice error messages immediately if not.

That might take some work. In the meantime, as suggested on https://etherpad.openstack.org/p/ansible-molecule, we could try and put together a simple 'troubleshooting' guide and output this with any error message.

Another issue that make this issue even more problematic is that --debug is extreamly verbose and as far as I know there is nothing in-between normal execution and debug mode. For example I almost never found useful to see the "blue" connection messages, but the other changes in verbosity did prove essential for debugging errors. It may be my lack of knowledge but I wasn't able to find something less verbose.

AFAIK, a way in between --debug is to set log: true in your molecule.yml.

@asmacdo
Copy link
Contributor

asmacdo commented Feb 20, 2019

Something along the lines of molecule test --debug-failed would be very helpful for running molecule tests with travis.

To clarify, what would be most useful in this situation would be to increase the verbosity only for a failed test. Currently, if a build is broken in travis, we almost always have to run the tests locally (in highly verbose debug mode) to even get an idea of what went wrong.

@ssbarnea
Copy link
Member Author

I am glad to see others feel the same pain. As someone that tries to advocate molecule use to others I find the need to run afain with debug very inconvenient.

We should aim to get meaninful error on normal runs, without asking user to add extra params in order to findout about stuff like:

  • unable to connect to docker
  • docker module was not importable
  • docker build failed....

I am not saying that default execution should be more verbose but I am saying that failed tasks should be verbose.

@decentral1se decentral1se removed this from the v.2.21 milestone Feb 27, 2019
@decentral1se
Copy link
Contributor

To be clear, I'm really +1 on something for this (and I hope I have time soon) to improve the experience with Molecule and debugging failures. It's pretty damn important and without, it can certainly be frustrating.

ssbarnea added a commit that referenced this issue Mar 13, 2019
Improves user experience by displaying the errors that caused key
tasks to fail.

Avoids adding extra verbosity by using no_log on successes.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
@ssbarnea ssbarnea self-assigned this Mar 13, 2019
@ssbarnea ssbarnea added the ux label Mar 13, 2019
@ssbarnea ssbarnea reopened this Mar 13, 2019
@decentral1se
Copy link
Contributor

Following discussion #1828, can we make no_log:False the default and set no_log:True only for tasks that Molecule internally has to handle credentials for? Anyone see issues?

@decentral1se
Copy link
Contributor

decentral1se commented Mar 13, 2019

Hmmmm ... #1289 and basically a lot of https://github.com/ansible/molecule/issues?utf8=%E2%9C%93&q=is%3Aissue+no_log.

Here's the line:

no_log: "{{ not (lookup('env', 'MOLECULE_DEBUG') | bool or molecule_yml.provisioner.log|default(false) | bool) }}"
(but it is in a bunch of other places ...).

Some docs too: https://docs.ansible.com/ansible/latest/reference_appendices/faq.html#how-do-i-keep-secret-data-in-my-playbook.

@decentral1se
Copy link
Contributor

Further debate:

14:43 < decentral1se> zbr: reviwed #1828!
14:48 < decentral1se> can we make no_log:False the default?
14:49 < decentral1se> I can't see issues with this as long as we take care of no_log:True for credentials handling tasks ...
14:49 < decentral1se> am I missing something?
15:10 < zbr> decentral1se: the no_log issue is more complex, because its value is inhered down
15:11 < zbr> while --debug should problably make no_log: false, I do not think that lack of --debug means the opposite.
15:13 < decentral1se> sure but not passing --debug should only no_log:True credential handling tasks, no?
15:14 < decentral1se> I think no_log:True was just a design decision from previous maintainers
15:14 < zbr> decentral1se: what is a credential handling task? afaik all ansible modules are supposed not to expose
credentials by themselves anyway.
15:14 < decentral1se> one of the instance creating tasks. Say, Linode create instance task
15:15 < decentral1se> it typically accepts an api_token or whatever
15:15 < zbr> if i remember well, ansible is censoring these by default, right?
15:15 < decentral1se> right yeah, I think I saw something like that
15:15 < decentral1se> yeah, like, what is the use case for no_log:True ... !?
15:16 < decentral1se> It just is not helping me know what happened when molecule breaks
15:16 < zbr> decentral1se: if you do a shell command with something like --password=xxxx --- you need it.
15:17 < decentral1se> yes but if we control these tasks in our internal play definitions
15:17 < zbr> decentral1se: but, overall, I think we could scrap most of the no_logs.
15:17 < decentral1se> then we should be free to say: "OK, we can log here"
15:17 < decentral1se> cool cool

ssbarnea added a commit that referenced this issue Mar 13, 2019
Improves user experience by displaying the errors that caused key
tasks to fail.

Avoids adding extra verbosity by using no_log on successes.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
@decentral1se
Copy link
Contributor

RE #1666 (comment), we could also add a check on DOCKER_HOST to be sure that it is a local docker and not another remote. This could be a dangerous assumption ...

@webknjaz
Copy link
Member

@decentral1se what if Molecule, as a first step, verified accessibility and usability of providers and reported the problem early and loudly following the "fail fast" approach?

@decentral1se
Copy link
Contributor

#1666 (comment)

One idea is to introduce a validation layer right at the start of the run which asks which driver is being requested, in your example, Docker, and then trys to check if it is up and ready to run. We could bail out with some nice error messages immediately if not.

ssbarnea added a commit that referenced this issue Mar 16, 2019
This change makes the default behavior of molecule to enable logging
of its tasks. This may expose credentials if they are defined in
molecule.yml files.

User can override this behaviour by defining MOLECULE_NO_LOG variable
to true of false. When defined that value would override any value
of `provider.log` mentioned inside molecule.yaml.

When variable is not defined, the value from molecule.yml file will be
used.

When none of these are defined, logging will be enabled.

This matches Ansible behavior where environment variables do take
precedence over values defined in playbooks.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
@ssbarnea
Copy link
Member Author

@webknjaz While I do support your idea but is unrelated to this issue. We need to expose errors in molecule tasks because they very often contain problems that we could never catch with pre-run sanity check. My plan is to first adapt the way we run tests to always skip unconfigured providers unless we mention a list of ones we want to test, speeding up testing locally and on CI.

ssbarnea added a commit that referenced this issue Mar 17, 2019
This change makes the default behavior of molecule to enable logging
of its tasks. This may expose credentials if they are defined in
molecule.yml files.

User can override this behaviour by defining MOLECULE_NO_LOG variable
to true of false. When defined that value would override any value
of `provider.log` mentioned inside molecule.yaml.

When variable is not defined, the value from molecule.yml file will be
used.

When none of these are defined, logging will be enabled.

This matches Ansible behavior where environment variables do take
precedence over values defined in playbooks.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
ssbarnea added a commit that referenced this issue Mar 18, 2019
This change makes the default behavior of molecule to enable logging
of its tasks. This may expose credentials if they are defined in
molecule.yml files.

User can override this behaviour by defining MOLECULE_NO_LOG variable
to true of false. When defined that value would override any value
of `provider.log` mentioned inside molecule.yaml.

When variable is not defined, the value from molecule.yml file will be
used.

When none of these are defined, logging will be enabled.

This matches Ansible behavior where environment variables do take
precedence over values defined in playbooks.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
ssbarnea added a commit that referenced this issue Mar 22, 2019
User can override this behaviour by defining MOLECULE_NO_LOG variable
to true of false. When defined that value would override any value
of `provider.log` mentioned inside molecule.yaml.

When variable is not defined, the value from molecule.yml file will be
used.

When none of these are defined, logging will be disabled in order to
keep the behaviour consistent with previous versions. In the future
we may want to change the default value in order to improve the user
experience.

This matches Ansible behavior where environment variables do take
precedence over values defined in playbooks.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
ssbarnea added a commit that referenced this issue Mar 25, 2019
User can override this behaviour by defining MOLECULE_NO_LOG variable
to true of false. When defined that value would override any value
of `provider.log` mentioned inside molecule.yaml.

When variable is not defined, the value from molecule.yml file will be
used.

When none of these are defined, logging will be disabled in order to
keep the behaviour consistent with previous versions. In the future
we may want to change the default value in order to improve the user
experience.

This matches Ansible behavior where environment variables do take
precedence over values defined in playbooks.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
ssbarnea added a commit that referenced this issue Mar 26, 2019
User can override this behaviour by defining MOLECULE_NO_LOG variable
to true of false. When defined that value would override any value
of `provider.log` mentioned inside molecule.yaml.

When variable is not defined, the value from molecule.yml file will be
used.

When none of these are defined, logging will be disabled in order to
keep the behaviour consistent with previous versions. In the future
we may want to change the default value in order to improve the user
experience.

This matches Ansible behavior where environment variables do take
precedence over values defined in playbooks.

Fixes: #1666
Signed-off-by: Sorin Sbarnea <[email protected]>
decentral1se added a commit to decentral1se/molecule that referenced this issue Mar 26, 2019
decentral1se added a commit to decentral1se/molecule that referenced this issue Mar 30, 2019
Something for ansible#1666 (comment).

Signed-off-by: Luke Murphy <[email protected]>
decentral1se added a commit that referenced this issue Apr 9, 2019
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 a pull request may close this issue.

4 participants