Random yum failures on newrelic install on fresh EC2 instance

[et304383]

This is only happening for the newrelic yum install so I'm not convinced it's a widespread yum race condition issue. I'm using the latest version of this cookbook.

I spun up two fresh EC2 instances today using the same run list and one failed randomly. I've seen this numerous times (from newrelic install) and it's very difficult to debug. Here's the relevant stack trace:

[2015-08-11T11:17:45+00:00] INFO: Processing newrelic_server_monitor[Install] action install (newrelic::server_monitor_agent line 8)
[2015-08-11T11:17:45+00:00] INFO: Processing yum_repository[newrelic] action create (/etc/chef/local-mode-cache/cache/cookbooks/newrelic/libraries/helpers.rb line 29)
[2015-08-11T11:17:45+00:00] INFO: Processing template[/etc/yum.repos.d/newrelic.repo] action create (/etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb line 39)
[2015-08-11T11:17:45+00:00] INFO: template[/etc/yum.repos.d/newrelic.repo] created file /etc/yum.repos.d/newrelic.repo
[2015-08-11T11:17:45+00:00] INFO: template[/etc/yum.repos.d/newrelic.repo] updated file contents /etc/yum.repos.d/newrelic.repo
[2015-08-11T11:17:45+00:00] INFO: template[/etc/yum.repos.d/newrelic.repo] mode changed to 644
[2015-08-11T11:17:45+00:00] INFO: template[/etc/yum.repos.d/newrelic.repo] sending run action to execute[yum clean newrelic] (immediate)
[2015-08-11T11:17:45+00:00] INFO: Processing execute[yum clean newrelic] action run (/etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb line 55)
[2015-08-11T11:17:47+00:00] INFO: execute[yum clean newrelic] ran successfully
[2015-08-11T11:17:47+00:00] INFO: template[/etc/yum.repos.d/newrelic.repo] sending run action to execute[yum-makecache-newrelic] (immediate)
[2015-08-11T11:17:47+00:00] INFO: Processing execute[yum-makecache-newrelic] action run (/etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb line 61)
[0m
================================================================================[0m
[31mError executing action `run` on resource 'execute[yum-makecache-newrelic]'[0m
================================================================================[0m

[0mMixlib::ShellOut::ShellCommandFailed[0m
------------------------------------[0m
Expected process to exit with [0], but received '1'
[0m---- Begin output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
[0mSTDOUT: 
[0mSTDERR: (process:3071): GLib-CRITICAL **: g_timer_stop: assertion `timer != NULL' failed
[0m
[0m(process:3071): GLib-CRITICAL **: g_timer_destroy: assertion `timer != NULL' failed
[0mTraceback (most recent call last):
[0m  File "/usr/bin/yum", line 29, in <module>
[0m    yummain.user_main(sys.argv[1:], exit_code=True)
[0m  File "/usr/share/yum-cli/yummain.py", line 355, in user_main
[0m    errcode = main(args)
[0m  File "/usr/share/yum-cli/yummain.py", line 174, in main
[0m    result, resultmsgs = base.doCommands()
[0m  File "/usr/share/yum-cli/cli.py", line 572, in doCommands
[0m    return self.yum_cli_commands[self.basecmd].doCommand(self, self.basecmd, self.extcmds)
[0m  File "/usr/share/yum-cli/yumcommands.py", line 1389, in doCommand
[0m    base.repos.populateSack(mdtype='all', cacheonly=1)
[0m  File "/usr/lib/python2.7/dist-packages/yum/repos.py", line 383, in populateSack
[0m    sack.populate(repo, mdtype, callback, cacheonly)
[0m  File "/usr/lib/python2.7/dist-packages/yum/yumRepo.py", line 286, in populate
[0m    dobj = repo_cache_function(xml, csum)
[0m  File "/usr/lib64/python2.7/dist-packages/sqlitecachec.py", line 46, in getPrimary
[0m    self.repoid))
[0mTypeError: Can not create files table: disk I/O error
[0m---- End output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
[0mRan yum -q -y makecache --disablerepo=* --enablerepo=newrelic returned 1[0m

[0mResource Declaration:[0m
---------------------[0m
# In /etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb
[0m
[0m 61:   execute "yum-makecache-#{new_resource.repositoryid}" do
[0m 62:     command "yum -q -y makecache --disablerepo=* --enablerepo=#{new_resource.repositoryid}"
[0m 63:     action :nothing
[0m 64:     only_if { new_resource.enabled }
[0m 65:   end
[0m 66: 
[0m
[0mCompiled Resource:[0m
------------------[0m
# Declared in /etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb:61:in `block in class_from_file'
[0m
[0mexecute("yum-makecache-newrelic") do
[0m  action [:nothing]
[0m  retries 0
[0m  retry_delay 2
[0m  default_guard_interpreter :execute
[0m  command "yum -q -y makecache --disablerepo=* --enablerepo=newrelic"
[0m  backup 5
[0m  returns 0
[0m  declared_type :execute
[0m  cookbook_name "newrelic"
[0m  only_if { #code block }
[0mend
[0m
[0m[2015-08-11T11:17:48+00:00] INFO: Running queued delayed notifications before re-raising exception
[0m
================================================================================[0m
[31mError executing action `create` on resource 'yum_repository[newrelic]'[0m
================================================================================[0m

[0mMixlib::ShellOut::ShellCommandFailed[0m
------------------------------------[0m
execute[yum-makecache-newrelic] (/etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb line 61) had an error: Mixlib::ShellOut::ShellCommandFailed: Expected process to exit with [0], but received '1'
[0m---- Begin output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
[0mSTDOUT: 
[0mSTDERR: (process:3071): GLib-CRITICAL **: g_timer_stop: assertion `timer != NULL' failed
[0m
[0m(process:3071): GLib-CRITICAL **: g_timer_destroy: assertion `timer != NULL' failed
[0mTraceback (most recent call last):
[0m  File "/usr/bin/yum", line 29, in <module>
[0m    yummain.user_main(sys.argv[1:], exit_code=True)
[0m  File "/usr/share/yum-cli/yummain.py", line 355, in user_main
[0m    errcode = main(args)
[0m  File "/usr/share/yum-cli/yummain.py", line 174, in main
[0m    result, resultmsgs = base.doCommands()
[0m  File "/usr/share/yum-cli/cli.py", line 572, in doCommands
[0m    return self.yum_cli_commands[self.basecmd].doCommand(self, self.basecmd, self.extcmds)
[0m  File "/usr/share/yum-cli/yumcommands.py", line 1389, in doCommand
[0m    base.repos.populateSack(mdtype='all', cacheonly=1)
[0m  File "/usr/lib/python2.7/dist-packages/yum/repos.py", line 383, in populateSack
[0m    sack.populate(repo, mdtype, callback, cacheonly)
[0m  File "/usr/lib/python2.7/dist-packages/yum/yumRepo.py", line 286, in populate
[0m    dobj = repo_cache_function(xml, csum)
[0m  File "/usr/lib64/python2.7/dist-packages/sqlitecachec.py", line 46, in getPrimary
[0m    self.repoid))
[0mTypeError: Can not create files table: disk I/O error
[0m---- End output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
[0mRan yum -q -y makecache --disablerepo=* --enablerepo=newrelic returned 1[0m

[0mResource Declaration:[0m
---------------------[0m
# In /etc/chef/local-mode-cache/cache/cookbooks/newrelic/libraries/helpers.rb
[0m
[0m 29:       yum_repository 'newrelic' do
[0m 30:         description 'New Relic packages for Enterprise Linux 5 - $basearch'
[0m 31:         baseurl node['newrelic']['repository']['uri']
[0m 32:         gpgkey node['newrelic']['repository']['key']
[0m 33:       end
[0m 34:     end
[0m
[0mCompiled Resource:[0m
------------------[0m
# Declared in /etc/chef/local-mode-cache/cache/cookbooks/newrelic/libraries/helpers.rb:29:in `install_newrelic_repo_rhel'
[0m
[0myum_repository("newrelic") do
[0m  action :create
[0m  updated true
[0m  updated_by_last_action true
[0m  retries 0
[0m  retry_delay 2
[0m  default_guard_interpreter :default
[0m  declared_type :yum_repository
[0m  cookbook_name "newrelic"
[0m  baseurl "http://download.newrelic.com/pub/newrelic/el5/$basearch/"
[0m  description "New Relic packages for Enterprise Linux 5 - $basearch"
[0m  enabled true
[0m  gpgcheck true
[0m  gpgkey "http://download.newrelic.com/548C16BF.gpg"
[0m  repositoryid "newrelic"
[0m  mode "0644"
[0m  make_cache true
[0mend
[0m
[0m[2015-08-11T11:17:48+00:00] INFO: Running queued delayed notifications before re-raising exception
[0m
================================================================================[0m
[31mError executing action `install` on resource 'newrelic_server_monitor[Install]'[0m
================================================================================[0m

[0mMixlib::ShellOut::ShellCommandFailed[0m
------------------------------------[0m
yum_repository[newrelic] (/etc/chef/local-mode-cache/cache/cookbooks/newrelic/libraries/helpers.rb line 29) had an error: Mixlib::ShellOut::ShellCommandFailed: execute[yum-makecache-newrelic] (/etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb line 61) had an error: Mixlib::ShellOut::ShellCommandFailed: Expected process to exit with [0], but received '1'
[0m---- Begin output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
[0mSTDOUT: 
[0mSTDERR: (process:3071): GLib-CRITICAL **: g_timer_stop: assertion `timer != NULL' failed
[0m
[0m(process:3071): GLib-CRITICAL **: g_timer_destroy: assertion `timer != NULL' failed
[0mTraceback (most recent call last):
[0m  File "/usr/bin/yum", line 29, in <module>
[0m    yummain.user_main(sys.argv[1:], exit_code=True)
[0m  File "/usr/share/yum-cli/yummain.py", line 355, in user_main
[0m    errcode = main(args)
[0m  File "/usr/share/yum-cli/yummain.py", line 174, in main
[0m    result, resultmsgs = base.doCommands()
[0m  File "/usr/share/yum-cli/cli.py", line 572, in doCommands
[0m    return self.yum_cli_commands[self.basecmd].doCommand(self, self.basecmd, self.extcmds)
[0m  File "/usr/share/yum-cli/yumcommands.py", line 1389, in doCommand
[0m    base.repos.populateSack(mdtype='all', cacheonly=1)
[0m  File "/usr/lib/python2.7/dist-packages/yum/repos.py", line 383, in populateSack
[0m    sack.populate(repo, mdtype, callback, cacheonly)
[0m  File "/usr/lib/python2.7/dist-packages/yum/yumRepo.py", line 286, in populate
[0m    dobj = repo_cache_function(xml, csum)
[0m  File "/usr/lib64/python2.7/dist-packages/sqlitecachec.py", line 46, in getPrimary
[0m    self.repoid))
[0mTypeError: Can not create files table: disk I/O error
[0m---- End output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
[0mRan yum -q -y makecache --disablerepo=* --enablerepo=newrelic returned 1[0m

[0mResource Declaration:[0m
---------------------[0m
# In /etc/chef/local-mode-cache/cache/cookbooks/newrelic/recipes/server_monitor_agent.rb
[0m
[0m  8: newrelic_server_monitor 'Install' do
[0m  9:   license NewRelic.server_monitoring_license(node)
[0m 10:   logfile node['newrelic']['server_monitoring']['logfile'] unless node['newrelic']['server_monitoring']['logfile'].nil?
[0m 11:   loglevel node['newrelic']['server_monitoring']['loglevel'] unless node['newrelic']['server_monitoring']['loglevel'].nil?
[0m 12:   proxy node['newrelic']['server_monitoring']['proxy'] unless node['newrelic']['server_monitoring']['proxy'].nil?
[0m 13:   ssl NewRelic.to_boolean(node['newrelic']['server_monitoring']['ssl']) unless node['newrelic']['server_monitoring']['ssl'].nil?
[0m 14:   ssl_ca_bundle node['newrelic']['server_monitoring']['ssl_ca_bundle'] unless node['newrelic']['server_monitoring']['ssl_ca_bundle'].nil?
[0m 15:   ssl_ca_path node['newrelic']['server_monitoring']['ssl_ca_path'] unless node['newrelic']['server_monitoring']['ssl_ca_path'].nil?
[0m 16:   hostname node['newrelic']['server_monitoring']['hostname'] unless node['newrelic']['server_monitoring']['hostname'].nil?
[0m 17:   labels node['newrelic']['server_monitoring']['labels'] unless node['newrelic']['server_monitoring']['labels'].nil?
[0m 18:   pidfile node['newrelic']['server_monitoring']['pidfile'] unless node['newrelic']['server_monitoring']['pidfile'].nil?
[0m 19:   collector_host node['newrelic']['server_monitoring']['collector_host'] unless node['newrelic']['server_monitoring']['collector_host'].nil?
[0m 20:   timeout node['newrelic']['server_monitoring']['timeout'] unless node['newrelic']['server_monitoring']['timeout'].nil?
[0m 21:   alert_policy_id node['newrelic']['server_monitoring']['alert_policy_id'] unless node['newrelic']['server_monitoring']['alert_policy_id'].nil?
[0m 22:   config_file_user node['newrelic']['server_monitor_agent']['config_file_user'] unless node['newrelic']['server_monitor_agent']['config_file_user'].nil?
[0m 23:   config_file_group node['newrelic']['server_monitor_agent']['config_file_group'] unless node['newrelic']['server_monitor_agent']['config_file_group'].nil?
[0m 24:   service_notify_action node['newrelic']['server_monitor_agent']['service_notify_action'] unless node['newrelic']['server_monitor_agent']['service_notify_action'].nil?
[0m 25:   service_actions node['newrelic']['server_monitor_agent']['service_actions'] unless node['newrelic']['server_monitor_agent']['service_actions'].nil?
[0m 26:   windows_version node['newrelic']['server_monitor_agent']['windows_version'] unless node['newrelic']['server_monitor_agent']['windows_version'].nil?
[0m 27:   windows32_checksum node['newrelic']['server_monitor_agent']['windows32_checksum'] unless node['newrelic']['server_monitor_agent']['windows32_checksum'].nil?
[0m 28:   windows64_checksum node['newrelic']['server_monitor_agent']['windows64_checksum'] unless node['newrelic']['server_monitor_agent']['windows64_checksum'].nil?
[0m 29:   cookbook node['newrelic']['server_monitor_agent']['template']['cookbook'] unless node['newrelic']['server_monitor_agent']['template']['cookbook'].nil?
[0m 30:   source node['newrelic']['server_monitor_agent']['template']['source'] unless node['newrelic']['server_monitor_agent']['template']['source'].nil?
[0m 31:   service_name node['newrelic']['server_monitor_agent']['service_name'] unless node['newrelic']['server_monitor_agent']['service_name'].nil?
[0m 32:   config_path node['newrelic']['server_monitor_agent']['config_path'] unless node['newrelic']['server_monitor_agent']['config_path'].nil?
[0m 33: end
[0m
[0mCompiled Resource:[0m
------------------[0m
# Declared in /etc/chef/local-mode-cache/cache/cookbooks/newrelic/recipes/server_monitor_agent.rb:8:in `from_file'
[0m
[0mnewrelic_server_monitor("Install") do
[0m  action :install
[0m  updated true
[0m  updated_by_last_action true
[0m  retries 0
[0m  retry_delay 2
[0m  default_guard_interpreter :default
[0m  declared_type :newrelic_server_monitor
[0m  cookbook_name "newrelic"
[0m  recipe_name "server_monitor_agent"
[0m  license "<REMOVED>"
[0m  hostname "<REMOVED>"
[0m  service_name "newrelic-sysmond"
[0m  config_path "/etc/newrelic"
[0m  cookbook "newrelic"
[0m  source "agent/server_monitor/nrsysmond.cfg.erb"
[0m  config_file_user "root"
[0m  config_file_group "newrelic"
[0m  service_notify_action "restart"
[0m  service_actions ["enable", "start"]
[0mend
[0m
[0m[2015-08-11T11:17:48+00:00] INFO: Running queued delayed notifications before re-raising exception
[2015-08-11T11:17:48+00:00] ERROR: Running exception handlers
[2015-08-11T11:17:48+00:00] ERROR: Exception handlers complete
[2015-08-11T11:17:48+00:00] FATAL: Stacktrace dumped to /etc/chef/local-mode-cache/cache/chef-stacktrace.out
[2015-08-11T11:17:48+00:00] ERROR: newrelic_server_monitor[Install] (newrelic::server_monitor_agent line 8) had an error: Mixlib::ShellOut::ShellCommandFailed: yum_repository[newrelic] (/etc/chef/local-mode-cache/cache/cookbooks/newrelic/libraries/helpers.rb line 29) had an error: Mixlib::ShellOut::ShellCommandFailed: execute[yum-makecache-newrelic] (/etc/chef/local-mode-cache/cache/cookbooks/yum/providers/repository.rb line 61) had an error: Mixlib::ShellOut::ShellCommandFailed: Expected process to exit with [0], but received '1'
---- Begin output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
STDOUT: 
STDERR: (process:3071): GLib-CRITICAL **: g_timer_stop: assertion `timer != NULL' failed

(process:3071): GLib-CRITICAL **: g_timer_destroy: assertion `timer != NULL' failed
Traceback (most recent call last):
  File "/usr/bin/yum", line 29, in <module>
    yummain.user_main(sys.argv[1:], exit_code=True)
  File "/usr/share/yum-cli/yummain.py", line 355, in user_main
    errcode = main(args)
  File "/usr/share/yum-cli/yummain.py", line 174, in main
    result, resultmsgs = base.doCommands()
  File "/usr/share/yum-cli/cli.py", line 572, in doCommands
    return self.yum_cli_commands[self.basecmd].doCommand(self, self.basecmd, self.extcmds)
  File "/usr/share/yum-cli/yumcommands.py", line 1389, in doCommand
    base.repos.populateSack(mdtype='all', cacheonly=1)
  File "/usr/lib/python2.7/dist-packages/yum/repos.py", line 383, in populateSack
    sack.populate(repo, mdtype, callback, cacheonly)
  File "/usr/lib/python2.7/dist-packages/yum/yumRepo.py", line 286, in populate
    dobj = repo_cache_function(xml, csum)
  File "/usr/lib64/python2.7/dist-packages/sqlitecachec.py", line 46, in getPrimary
    self.repoid))
TypeError: Can not create files table: disk I/O error
---- End output of yum -q -y makecache --disablerepo=* --enablerepo=newrelic ----
Ran yum -q -y makecache --disablerepo=* --enablerepo=newrelic returned 1
[2015-08-11T11:17:49+00:00] FATAL: Chef::Exceptions::ChildConvergeError: Chef run process exited unsuccessfully (exit code 1)

[et304383]

@djoos everything OK on your end? It's not like you to not respond to issues. No sarcasm: I'm genuinely concerned.

[djoos]

Hi @eric-tucker,

thanks for getting in touch! I'm ok, thanks! Sorry: I've had quite a lot on at work and this one slipped through the net... :-/

Hmmm, I found a related issue here. You mentioned you spun up 2 fresh instances, so the "Can not create files table: disk I/O error" is most likely not down to running out of disk space, right? Any kind of (instance-related and also weird) limits AWS might be enforcing? (even so: it should be less random in that case and probably more clear-cut as to what is causing it)

An interesting one - looking forward to hearing from you!

Kind regards, David

[EDIT: updated the link to the issue on the AWS forum]

[et304383]

I saw that issue as well in my Google travels.

I see this happen still today randomly. We routinely destroy and recreate our test servers daily. Today, an instance failed to provision that yesterday using the same CloudFormation stack and Chef recipes successfully was provisioned (no yum error).

It only seems to happen from the newrelic install though - no other yum installations throw such an error. It could be a coincidence and this have nothing to do with newrelic though.

[djoos]

Ok, so it's also not provider-specific (nor a case of a full disk)... Do you guys use vagrant? If so, ever ran into the issue on a local vm as well? In the meantime, I'll reach out to New Relic support as well...

I'll keep you updated!

Kind regards, David

[et304383]

We do not use Vagrant, sorry. Hopefully something comes up on Newrelic's end!

[djoos]

Hi @eric-tucker,

so I've got a reply from a lead technical support engineer at New Relic...

"Thank you for reaching out. This is not something I have seen before. So I will escalate this to our LSM experts who should have a much better understanding of the issue." (continues below)

However, as we currently have some nodes with a slightly older version of the Linux server monitor - he picked upon this and asked to make sure we've got the latest installed. Would you be able to give me the version of the server monitor you've got installed?

"Is there any additional information you can share about your system which might be relevant? Would you be willing to give us a quick description of your environment?" Well, here is where it would digress from our setup obviously and I'm unable to share more specifics...

Perhaps it might be worth you opening an issue with New Relic? In that case I don't even mind you referencing my ticket number in, just so they can tie things together on their end in Zendesk: 158724. As far as I currently understand it, it is not a newrelic cookbook-related issue, however it obviously manifests itselfs when using the cookbook...

Thanks in advance for your feedback!

Kind regards, David

[et304383]

Well considering it's a fresh install using the latest 2.x newrelic cookbook I'd say I'm installing the latest monitor.

Berksfile:

cookbook "newrelic", "< 3.0.0"

The server is standard Amazon Linux server using the base Amazon AMI for 2015.03 Amazon Linux release.

This might help (a snippet of our recipe doing the yum operations):

if ["amazon", "centos", "redhat"].include?(node[:platform])
  include_recipe "yum-epel"
end

#Fix for non 8 GB root volumes.  Ignore any errors as this is just a convenience call.
execute "resize2fs /dev/xvda1 2>/dev/null"
include_recipe "codedeploy-agent"

#Fix for codedeploy-agent startup script not checking that the PID in the PID file is
#actually a codedeploy agent process
cookbook_file "/opt/codedeploy-agent/bin/codedeploy-agent-pid-fix.sh" do
  mode 0755
end

cron "codedeploy-agent-pid-fix" do
  minute "*/15"
  command "/opt/codedeploy-agent/bin/codedeploy-agent-pid-fix.sh"
end

package "htop"

unless node[:newrelic][:license].nil?
  include_recipe "newrelic::server_monitor_agent"
end

So as far as yum operations it looks like I'm enabling the yum epel, installing htop, then moving to the server monitor recipe.

I could open a ticket with newrelic if you're confident it's not the cookbook causing the issue.

[djoos]

I've got another update through on the ticket...

"The error message shown looks to be a problem specific to the sqlitecachec Python package on the user's systems when attempting to download, cache, and actually install the newrelic package through yum (through Chef). Given that the consistent error in all of these failed Chef command executions is:

TypeError: Can not create files table: disk I/O error I can only imagine that something on the filesystem (or something about the filesystem/database - out of space, bad permissions, inability to access a yum caching database, etc.) is resulting in the issue. In either case, it doesn't look to be anything specific to New Relic or our services.

That being said, we're unable to provide any official support on this use case, but a few cursory things to check might be to ensure that the version of the sqlitecachec package is up to date on the machine image in use, ensuring whichever SQLite database used by yum won't run into any of the issues described above (permissions, etc.), and anything else related to yum interacting with any backing SQLite stores."

[djoos]

Sorry @eric-tucker - didn't want to just close and comment, but was handling this update I literally just got through on my mobile... (fat fingers)

[djoos]

Any further luck troubleshooting this one @eric-tucker?

Kind regards, David

[et304383]

No, but considering it's not related to this cookbook (though it appears as the only place it manifests) you can close this and I'll take into consideration the advice from Newrelic. I'll open a ticket with them if I need further assistance.

[djoos]

Perfect, thanks @eric-tucker!

Kind regards, David

[pkang]

@eric-tucker, I'm hitting the same exact issue with our cookbook and installing New Relic. Did the advice help?

[michaelskiles]

Just came across this same issue. Wasn't able to get to the bottom of it...but it's working again for now.