Page MenuHomePhabricator

Evaluate options to make puppet errors more visible
Closed, ResolvedPublic

Description

Over the last month I quite frequently found out about puppet errors by looking through /var/log/syslog where output from past runs is sent.

However (except for one isolated case) the vast majority of these did not result in an actual failed puppet run, and thus did not ring any of our bells monitoring this stuff.

Finding out about puppet failures and random regressions two days (or even weeks) after they were introduced – when investigating other more visible failures – is not cool. Some of these errors had quite real impact, just not visible enough for anyone to suspect or notify CI infrastructure.

Intuitively I imagine there ought to be a flag in puppet that triggers behaviour of "Damn it, fail when you fail, don't just continue and pretend everything is fine".

Event Timeline

Krinkle raised the priority of this task from to High.
Krinkle updated the task description. (Show Details)
Krinkle subscribed.

What do you mean by "puppet failures and random regressions" in this case?

What do you mean by "puppet failures and random regressions" in this case?

Integrity errors or quality issues being introduced that did not exist before - specifically those that result in the puppet run logging an error. Sometimes they cause builds to fail when underlying services don't run properly. Or they cause race conditions when things work one some hosts but not others. Errors in puppet output can be the entry point to any of a wide range of actual user-facing problems.

For example: T92482: Remove integration/kss.git

Mar 14 01:56:08 integration-slave1401 puppet-agent[18663]: (/Stage[main]/Contint::Slave-scripts/Git::Clone[jenkins CI kss]/Exec[git_pull_jenkins CI kss]/returns) fatal: remote error: Git repository not found
Mar 14 01:56:08 integration-slave1401 puppet-agent[18663]: /usr/bin/git  pull --recurse-submodules --quiet returned 1 instead of one of [0]
Mar 14 01:56:08 integration-slave1401 puppet-agent[18663]: (/Stage[main]/Contint::Slave-scripts/Git::Clone[jenkins CI kss]/Exec[git_pull_jenkins CI kss]/returns) change from notrun to 0 failed: /usr/bin/git  pull --recurse-submodules --quiet returned 1 instead of one of [0]
Mar 14 01:56:08 integration-slave1401 puppet-agent[18663]: (/Stage[main]/Contint::Slave-scripts/Git::Clone[jenkins CI kss]/Exec[git_submodule_update_jenkins CI kss]) Dependency Exec[git_pull_jenkins CI kss] has failures: true
Mar 14 01:56:08 integration-slave1401 puppet-agent[18663]: (/Stage[main]/Contint::Slave-scripts/Git::Clone[jenkins CI kss]/Exec[git_submodule_update_jenkins CI kss]) Skipping because of failed dependencies

The kss repo was deleted two days ago, and I find out about this error today when I happen to be looking through the logs when investigating a different issue. The puppet role ensures the repo is cloned and pulled to the latest master. This shouldn't be a minor notice in the log, that's an explicit failure to ensure what the manifest declares.

There are two aspects to this:

  1. Whether the Git failure caused Puppet to fail. This seems to have been the case.
  2. Whether the Puppet failure triggered appropriate alarms.

Looking at http://shinken.wmflabs.org/service/integration-slave1402/Puppet%20failure, shinken seems to have noticed the Puppet failure correctly. For the Tools project, I get regular alarms about Puppet failures, and the configuration for the Integration project looks identical. @yuvipanda, could you please check why @Krinkle wasn't notified?

Looking at http://shinken.wmflabs.org/service/integration-slave1402/Puppet%20failure, shinken seems to have noticed the Puppet failure correctly.

Where is the historical data in Shinken? I can't seem to find any failure there.

Anyhow, you're right that Puppet did indeed fail. I thought it only outputted the error in the log and continued to a regular finish. The underlying Diamond collector and Graphite did indeed detect the failed puppet run. And querying the raw Graphite data via Nagf https://tools.wmflabs.org/nagf/?project=integration#h_integration-slave1402_puppetagent shows puppet failed for few days before March 15.

Just a note: instead of looking at /var/log/syslog, you can look at /var/log/puppet.log on the instances. That files comes with ansi colored output with some red color whenever there is a failure.

Puppetmaster should be able to send its log to a logstash system since T62690 , though we don't have a logstash system for CI.

Just making a point here so we avoid future "puppet failed" threads.

Puppet itself did not fail in this specific case. A specific resource failed which does not mean that puppet failed. And we don't want it otherwise (aka the entire puppet run failing if a single resource fails).

In production we do have monitoring for those kind of failures. We get an alert that puppet had X number of failures and we investigate. Some times it is transient errors, sometimes actual ones. The way we do it is parse /var/lib/puppet/state/last_run_summary.yaml and reports the number of failures, if any. We obviously also monitor actual puppet failures (it used to be the "epic puppet fail" message) which means that catalog compilation failed and puppet did not run using the same mechanism.

I do have some ideas about making the check even better like telling you what the actual errors were. That should be doable by parsing the yaml file last_run_report.yaml which can make the puppet failures in the icinga interface very visible. That could provide the degree of insight needed.

Note that this task relates to Labs instances where Icinga can't be used. @yuvipanda had to jump through a lot of hoops to make the existing alerts possible :-).

Note that this task relates to Labs instances where Icinga can't be used. @yuvipanda had to jump through a lot of hoops to make the existing alerts possible :-).

Which is exactly why I started ones of my paragraphs with:

In production,

I am well aware of the alerting approach in labs. It unfortunately does not allow much room for maneuvering, given that arbitrary strings can not be stored into graphite, but it's a sound approach given the requirements.

fgiunchedi lowered the priority of this task from High to Low.Mar 30 2015, 4:44 PM
fgiunchedi subscribed.

looks like everything was working as expected on the alerting side, not sure there's any other action?

As long as the "number of failures" (e.g. a failed resource, not the complete compilation failure) are counted in Graphite and result in Shinken e-mails. Is that the case?

They are counted in graphite, and present in the emails just not particularly clearly.

Krinkle claimed this task.