Day 8 in the #vDM30in30
When you’re beginning with Puppet, it can be difficult to troubleshoot and debug issues with Puppet code.
What many people don’t know is that there are a bunch of useful cache files that can be used to help with this debugging.
I’ve got a box I’ve classified as a graphite and grafana machine with Puppet, and I want to find out whats going on.
Most of them can be found in the statedir:
[root@graphiteagent ~]# tree $(puppet agent --configprint statedir)
/opt/puppetlabs/puppet/cache/state
├── classes.txt
├── graphs
│ ├── expanded_relationships.dot
│ ├── relationships.dot
│ └── resources.dot
├── last_run_report.yaml
├── last_run_summary.yaml
├── resources.txt
├── state.yaml
└── transactionstore.yaml
1 directory, 9 files
Lets go through them and explain them a bit…
classes.txt
This is a simple text file that lists all classes applied during the last run.
[root@graphiteagent ~]# cat $(puppet agent --configprint classfile)
cat $(puppet agent --configprint classfile)
profiles::grafana
profiles::graphite
settings
default
profiles::grafana
grafana::params
grafana
grafana::install
grafana::config
grafana::service
profiles::graphite
graphite::params
graphite
graphite::install
graphite::config
graphite::config_apache
With a bit of grepping, you can find out if a certain class was present:
[root@graphiteagent ~]# grep graphite $(puppet agent --configprint classfile)
profiles::graphite
profiles::graphite
graphite::params
graphite
graphite::install
graphite::config
graphite::config_apache
resources.txt
Similar to classes.txt, but this lists all resource titles enforced during the last run:
[root@graphiteagent ~]# cat $(puppet agent --configprint resourcefile)
package[fontconfig]
package[grafana]
file[/etc/grafana/grafana.ini]
service[grafana-server]
grafana_datasource[Graphite]
grafana_dashboard[CollectD Stats from Graphite]
file[/usr/bin/pip-python]
package[mysql-python]
package[pyopenssl]
package[python-ldap]
package[python-memcached]
package[python-psycopg2]
...
Again, with a bit of grepping, you can look for a specific resource. Remember however: you can only look by resource title, so if someone’s given a unique title for say, a file, you won’t be able to search for a path.
[root@graphiteagent ~]# grep '/opt/graphite/' $(puppet agent --configprint resourcefile)
file[/opt/graphite/storage]
file[/opt/graphite/storage/rrd]
file[/opt/graphite/storage/lists]
file[/opt/graphite/storage/log]
file[/opt/graphite/bin]
file[/opt/graphite/storage/whisper]
file[/opt/graphite/storage/log/carbon-cache]
file[/opt/graphite/storage/graphite.db]
file[/opt/graphite/webapp/graphite/local_settings.py]
file[/opt/graphite/conf/graphite_wsgi.py]
file[/opt/graphite/webapp/graphite/graphite_wsgi.py]
file[/opt/graphite/conf/storage-schemas.conf]
file[/opt/graphite/conf/carbon.conf]
file[/opt/graphite/conf/storage-aggregation.conf]
file[/opt/graphite/conf/whitelist.conf]
file[/opt/graphite/conf/blacklist.conf]
file[/opt/graphite/bin/carbon-logrotate.sh]
Graph folder
Depending on which version of Puppet you have an how it’s configured, you may have to enable this first.
tree $(puppet agent --configprint statedir)
/opt/puppetlabs/puppet/cache/state
├── classes.txt
├── graphs
├── last_run_report.yaml
├── last_run_summary.yaml
├── resources.txt
├── state.yaml
└── transactionstore.yaml
1 directory, 6 files
As you can see, there’s no files in the graph folder.
So you just set graph to be true:
[root@graphiteagent ~]# puppet config set graph true --section=agent
After that you should see graphs next time you have a Puppet run:
[root@graphiteagent ~]# cat $(puppet agent --configprint statedir)/graphs/relationships.dot
digraph Relationships {
label = "Relationships"
"Stage[main]" [
fontsize = 8,
label = "Stage[main]"
]
"Class[Settings]" [
fontsize = 8,
label = "Class[Settings]"
]
"Class[Main]" [
fontsize = 8,
label = "Class[Main]"
]
"Node[default]" [
fontsize = 8,
label = "Node[default]"
]
"Class[Puppet_enterprise::Params]" [
fontsize = 8,
label = "Class[Puppet_enterprise::Params]"
]
"Class[Puppet_enterprise]" [
fontsize = 8,
label = "Class[Puppet_enterprise]"
]
"Class[Profiles::Grafana]" [
fontsize = 8,
label = "Class[Profiles::Grafana]"
]
"Class[Profiles::Graphite]" [
fontsize = 8,
label = "Class[Profiles::Graphite]"
]
You can then put this into a graph that can visualise .dot files such as Graphviz. There’s a web version of it that you can use in a pinch:
A Puppet relationship graph made from http://www.webgraphviz.com/
Cached Agent Catalog
A newish feature of Puppet is the cached catalog. The master sends the compiled catalog to the agent to be applied. In the event the agent cannot reach the master, it will continue to enforce the last catalog it received (the cached catalog).
This is so that when the master is unavailable, there can still be ongoing Puppet management of systems.
However, we can also use it for debugging by reading the data file for it.
This is in a slightly different location than the other files: $(puppet agent --configprint client_datadir)
[root@graphiteagent ~]# tree $(puppet agent --configprint client_datadir)
/opt/puppetlabs/puppet/cache/client_data
└── catalog
└── graphiteagent.puppetdebug.vlan.json
1 directory, 1 file
Since this is a minified JSON file, grepping it is a little harder as it’s all bunched up and harder to read:
{"tags":["profiles::grafana","profiles","grafana","profiles::graphite","graphite","puppet_enterprise","puppet_enterprise::profile::agent","profile","agent","puppet_enterprise::profile::mcollective::agent","mcollective","settings","default","puppet_enterprise::params","params","grafana::params","grafana::install","install","grafana::config","config","grafana::service","service","graphite::params","graphite::install","graphite::config","graphite::config_apache","config_apache","puppet_enterprise::symlinks","symlinks","puppet_enterprise::pxp_agent","pxp_agent","puppet_enterprise::pxp_agent::service","puppet_enterprise::mcollective::server","server","puppet_enterprise::mcollective::server::plugins","plugins","puppet_enterprise::mcollective::service","puppet_enterprise::mcollective::server::logs","logs","puppet_enterprise::mcollective::server::certs","certs","puppet_enterprise::mcollective::server::facter","facter","puppet_enterprise::mcollective::cleanup","cleanup","node","class"],"name":"pe-201640-agent-1.puppetdebug.vlan","version":1479152216,"code_id":null,"catalog_uuid":"d2f5c1ae-9b01-4be8-8eee-8e756940cae0","catalog_format":1,"environment":"production","resources":[{"type":"Stage","title":"main","tags"
But with jq or python we can read it a little better:
[root@graphiteagent catalog]# python -m json.tool $(puppet agent --configprint client_datadir)/catalog/graphiteagent.puppetdebug.vlan.json
{
"catalog_format": 1,
"catalog_uuid": "d2f5c1ae-9b01-4be8-8eee-8e756940cae0",
"classes": [
"profiles::grafana",
"profiles::graphite",
"settings",
"default",
"profiles::grafana",
"grafana::params",
"grafana",
"grafana::install",
"grafana::config",
"grafana::service",
"profiles::graphite",
"graphite::params",
"graphite",
"graphite::install",
"graphite::config",
As you can see, this is the complete catalog: so it’s all the information, which classes, which resources, tags, parameters, relationships are being created.
There’s a powerful jq tool which as the website says:
jq is like sed for JSON data - you can use it to slice and filter and map and transform structured data with the same ease that sed, awk, grep and friends let you play with text.
https://stedolan.github.io/jq/
So for example, if we want to see all the parameters for a certain class from the json:
[root@graphiteagent ~]# jq '.resources[] | select(.type == "Class" and .title == "Graphite").parameters' $(puppet agent --configprint client_datadir)/catalog/graphiteagent.puppetdebug.vlan.json
{
"gr_rendering_hosts_timeout": "1.0",
"gr_carbonlink_hosts_timeout": "1.0",
"gr_disable_webapp_cache": false,
"gr_manage_python_packages": true,
"gr_pip_install": true,
"gr_django_provider": "pip",
"gr_django_ver": "1.5",
"gr_django_pkg": "Django",
"gr_aggregator_udp_receiver_port": 2023,
"gr_aggregator_udp_receiver_interface": "0.0.0.0",
"gr_aggregator_enable_udp_listener": "False",
"gr_aggregator_line_port": 2023,
"gr_aggregator_line_interface": "0.0.0.0",
last_run_report.yaml
Lastly, this is a basic yaml file giving the last report run on a machine:
[root@graphiteagent ~]# cat $(puppet agent --configprint lastrunreport)
--- !ruby/object:Puppet::Transaction::Report
metrics:
resources: !ruby/object:Puppet::Util::Metric
name: resources
label: Resources
values:
- - total
- Total
- 235
- - skipped
- Skipped
- 0
- - failed
- Failed
- 0
- - failed_to_restart
- Failed to restart
- 0
- - restarted
- Restarted
With some simple grepping, you can get simple information from the report. For example, finding changed resources:
[root@graphiteagent ~]# grep -c 'changed: true' $(puppet agent --configprint lastrunreport)
7
There’s a really cool report reading script written by R.I called report-print.
report-print
report-print is a simple Ruby script that parses the last run yaml file script. The output is pretty awesome summary of indicators of what took the longest time in the catalog and other metrics.
[root@graphiteagent state] git clone https://github.com/ripienaar/puppet-reportprint /opt/report-print
We can actually use the Ruby that comes with the new AIO agent to avoid issues with Ruby incompatibility:
[root@graphiteagent state] /opt/puppetlabs/puppet/bin/ruby /opt/report-print/report_print.rb
Report for pe-201640-agent-1.puppetdebug.vlan in environment production at 2016-11-14 20:13:05 +0000
Report File: /opt/puppetlabs/puppet/cache/state/last_run_report.yaml
Report Kind: apply
Puppet Version: 4.7.0
Report Format: 6
Configuration Version: 1479154386
UUID: dc84cc4b-22c2-4a3a-b793-1cee7ff5bb67
Log Lines: 8 (show with --log)
Report Metrics:
Changes:
Total: 1
Events:
Total: 1
Success: 1
Failure: 0
Resources:
Total: 235
Out of sync: 1
Changed: 1
Corrective change: 1
Failed to restart: 0
Skipped: 0
Failed: 0
Restarted: 0
Scheduled: 0
Time:
Total: 3.891074847
Config retrieval: 3.135387682
File: 0.318029754
Service: 0.17787715599999998
Grafana dashboard: 0.15070201
Grafana datasource: 0.09668277
Package: 0.009231408999999998
Cron: 0.001372621
Exec: 0.000852301
Schedule: 0.000385452
Anchor: 0.00031026999999999997
Filebucket: 0.00015099
Pe anchor: 9.2432e-05
Resources by resource type:
187 File
26 Package
6 Schedule
5 Service
3 Exec
2 Cron
2 Anchor
1 Grafana_dashboard
1 Grafana_datasource
1 Filebucket
1 Pe_anchor
Slowest 20 resources by evaluation time:
0.15 Grafana_dashboard[CollectD Stats from Graphite]
0.10 Grafana_datasource[Graphite]
0.07 File[/tmp/fix-graphite-race-condition.py]
0.04 Service[mcollective]
0.04 Service[httpd]
0.04 Service[grafana-server]
0.03 Service[carbon-cache]
0.03 Service[pxp-agent]
0.02 File[/etc/init.d/carbon-cache]
0.01 File[/opt/puppetlabs/mcollective/plugins/mcollective/validator]
0.01 File[/opt/puppetlabs/mcollective/plugins/mcollective/agent/puppet.ddl]
0.00 File[/etc/puppetlabs/mcollective/ssl/ca.cert.pem]
0.00 File[/usr/bin/pip-python]
0.00 File[/opt/graphite/conf/storage-schemas.conf]
0.00 File[/opt/puppetlabs/mcollective/plugins/mcollective/agent/puppet.rb]
0.00 File[/etc/puppetlabs/mcollective/ssl/pe-201640-agent-1.puppetdebug.vlan.private_key.pem]
0.00 File[/opt/puppetlabs/mcollective/plugins/mcollective/validator/puppet_resource_validator.ddl]
0.00 File[/etc/grafana/grafana.ini]
0.00 File[/etc/puppetlabs/mcollective/ssl/pe-201640-agent-1.puppetdebug.vlan.cert.pem]
0.00 File[carbon_hack]
20 largest managed files (only those with full path as resource name that are readable)
68.00 KB /opt/graphite/storage/graphite.db
16.77 KB /opt/graphite/conf/carbon.conf
15.35 KB /opt/puppetlabs/mcollective/plugins/mcollective/util/puppet_agent_mgr.rb
15.15 KB /opt/puppetlabs/mcollective/plugins/mcollective/security/sshkey.rb
11.48 KB /opt/puppetlabs/mcollective/plugins/mcollective/application/puppet.rb
10.53 KB /opt/puppetlabs/mcollective/plugins/mcollective/agent/puppet.rb
8.97 KB /opt/puppetlabs/mcollective/plugins/mcollective/agent/puppet.ddl
8.92 KB /opt/graphite/webapp/graphite/local_settings.py
8.12 KB /opt/puppetlabs/mcollective/plugins/mcollective/util/puppetrunner.rb
6.06 KB /opt/puppetlabs/mcollective/plugins/mcollective/util/package/base.rb
5.73 KB /opt/puppetlabs/mcollective/plugins/mcollective/agent/package.ddl
5.56 KB /opt/puppetlabs/mcollective/plugins/mcollective/util/actionpolicy.rb
5.25 KB /etc/init.d/carbon-cache
4.87 KB /opt/puppetlabs/mcollective/plugins/mcollective/util/package/packagehelpers.rb
4.46 KB /opt/puppetlabs/mcollective/plugins/mcollective/util/package/yumHelper.py
4.41 KB /opt/puppetlabs/mcollective/plugins/mcollective/agent/package.rb
3.57 KB /opt/puppetlabs/mcollective/plugins/mcollective/application/package.rb
3.25 KB /opt/puppetlabs/mcollective/plugins/mcollective/application/service.rb
3.17 KB /etc/puppetlabs/mcollective/ssl/mcollective-private.pem
3.17 KB /etc/puppetlabs/mcollective/ssl/pe-201640-agent-1.puppetdebug.vlan.private_key.pem
20 most time consuming containment
0.76 Stage[main]
0.25 Profiles::Grafana
0.15 Grafana_dashboard[CollectD Stats from Graphite]
0.12 Puppet_enterprise::Mcollective::Server::Plugins
0.11 Graphite::Config_apache
0.10 Grafana_datasource[Graphite]
0.09 Graphite::Config
0.07 File[/tmp/fix-graphite-race-condition.py]
0.04 Puppet_enterprise::Mcollective::Service
0.04 Service[mcollective]
0.04 Service[httpd]
0.04 Grafana::Service
0.04 Service[grafana-server]
0.03 Service[carbon-cache]
0.03 Puppet_enterprise::Pxp_agent::Service
0.03 Service[pxp-agent]
0.02 File[/etc/init.d/carbon-cache]
0.02 Puppet_enterprise::Mcollective::Cleanup
0.02 Puppet_enterprise::Mcollective::Server::Certs
0.01 Graphite::Install
As you can see, we can see what resources took up the most time, the largest resources in the catalog and how long each step of the Puppet run took: compilation, enforcement and reporting.
