gistfile1.txt

[2014-01-19 09:55:13,268: WARNING/Worker-7] [2014-01-19T09:55:00-07:00] INFO: Forking chef instance to converge...
[2014-01-19T09:55:00-07:00] INFO: *** Chef 11.6.2 ***
[2014-01-19T09:55:04-07:00] INFO: Run List is [recipe[deis], recipe[deis::runtime], recipe[deis::proxy]]
[2014-01-19T09:55:04-07:00] INFO: Run List expands to [deis, deis::runtime, deis::proxy]
[2014-01-19T09:55:04-07:00] INFO: Starting Chef Run for devvy-runtime-2
[2014-01-19T09:55:04-07:00] INFO: Running start handlers
[2014-01-19T09:55:04-07:00] INFO: Start handlers complete.
[2014-01-19T09:55:07-07:00] INFO: Loading cookbooks [apt, deis, rsyslog, sudo]

================================================================================
Recipe Compile Error in /var/chef/cache/cookbooks/deis/recipes/runtime.rb
================================================================================


NoMethodError
-------------
undefined method `[]' for nil:NilClass


Cookbook Trace:
---------------
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:98:in `block (4 levels) in from_file'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:90:in `each_pair'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:90:in `block (3 levels) in from_file'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:88:in `each_pair'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:88:in `block (2 levels) in from_file'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:51:in `each_pair'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:51:in `block in from_file'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:42:in `each'
  /var/chef/cache/cookbooks/deis/recipes/runtime.rb:42:in `from_file'


Relevant File Content:
----------------------
/var/chef/cache/cookbooks/deis/recipes/runtime.rb:

 91:        
 92:          nodename, port = node_port.split(':')
 93:          
 94:          next if nodename != node.name
 95:  
 96:          # determine build command, if one exists
 97:          if build != {}
 98>>           command = build['procfile'][c_type]
 99:          else
100:            command = nil # assume command baked into docker image
101:          end
102:          name = "#{app_id}.#{c_type}.#{c_num}"
103:          # define the container
104:          container name do
105:            app_name app_id
106:            c_type c_type
107:            c_num c_num



[2014-01-19T09:55:12-07:00] ERROR: Running exception handlers
[2014-01-19T09:55:12-07:00] ERROR: Exception handlers complete
[2014-01-19T09:55:12-07:00] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out
[2014-01-19T09:55:12-07:00] INFO: Sending resource update report (run-id: e9e44ef6-227a-491e-88cf-bf329ff0e7ad)
[2014-01-19T09:55:13-07:00] FATAL: Chef::Exceptions::ChildConvergeError: Chef run process exited unsuccessfully (exit code 1)
[2014-01-19 09:55:13,404: ERROR/MainProcess] Task api.tasks.converge_node[145bcca8-529c-4f31-a271-558bbbed6b48] raised unexpected: RuntimeError(u'Node converge error',)
Traceback (most recent call last):
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/celery/app/trace.py", line 238, in trace_task
    R = retval = fun(*args, **kwargs)
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/celery/app/trace.py", line 416, in __protected_call__
    return self.run(*args, **kwargs)
  File "/vagrant/api/tasks.py", line 85, in converge_node
    output, rc = CM.converge_node(node.flat())
  File "/vagrant/cm/chef.py", line 188, in converge_node
    raise e
RuntimeError: Node converge error
[2014-01-19 09:55:17,516: WARNING/Worker-3] [2014-01-19T09:54:57-07:00] INFO: Forking chef instance to converge...
[2014-01-19T09:54:57-07:00] INFO: *** Chef 11.6.2 ***
[2014-01-19T09:54:59-07:00] INFO: Run List is [recipe[deis], recipe[deis::runtime], recipe[deis::proxy]]
[2014-01-19T09:54:59-07:00] INFO: Run List expands to [deis, deis::runtime, deis::proxy]
[2014-01-19T09:54:59-07:00] INFO: Starting Chef Run for devvy-runtime-1
[2014-01-19T09:54:59-07:00] INFO: Running start handlers
[2014-01-19T09:54:59-07:00] INFO: Start handlers complete.
[2014-01-19T09:55:01-07:00] INFO: Loading cookbooks [apt, deis, rsyslog, sudo]
[2014-01-19T09:55:09-07:00] INFO: Processing user[deis] action create (deis::default line 16)
[2014-01-19T09:55:09-07:00] INFO: Processing directory[/opt/deis] action create (deis::default line 26)
[2014-01-19T09:55:09-07:00] INFO: Processing sudo[deis] action install (deis::default line 32)
[2014-01-19T09:55:09-07:00] INFO: Processing template[/etc/sudoers.d/deis] action create (/var/chef/cache/cookbooks/sudo/providers/default.rb line 80)
[2014-01-19T09:55:09-07:00] INFO: Processing template[/etc/sudoers.d/deis] action nothing (/var/chef/cache/cookbooks/sudo/providers/default.rb line 80)
[2014-01-19T09:55:09-07:00] INFO: Processing directory[/var/log/deis] action create (deis::default line 44)
[2014-01-19T09:55:09-07:00] INFO: Processing bash[force-apt-get-update] action run (deis::default line 51)
[2014-01-19T09:55:09-07:00] INFO: Processing package[fail2ban] action install (deis::default line 58)
[2014-01-19T09:55:09-07:00] INFO: Processing package[python-setuptools] action install (deis::default line 59)
[2014-01-19T09:55:10-07:00] INFO: Processing package[python-pip] action install (deis::default line 60)
[2014-01-19T09:55:10-07:00] INFO: Processing package[debootstrap] action install (deis::default line 61)
[2014-01-19T09:55:10-07:00] INFO: Processing package[git] action install (deis::default line 62)
[2014-01-19T09:55:10-07:00] INFO: Processing package[make] action install (deis::default line 63)
[2014-01-19T09:55:10-07:00] INFO: Processing package[rsyslog] action install (rsyslog::default line 20)
[2014-01-19T09:55:10-07:00] INFO: Processing directory[/etc/rsyslog.d] action create (rsyslog::default line 23)
[2014-01-19T09:55:10-07:00] INFO: Processing directory[/var/spool/rsyslog] action create (rsyslog::default line 29)
[2014-01-19T09:55:10-07:00] INFO: Processing template[/etc/rsyslog.conf] action create (rsyslog::default line 37)
[2014-01-19T09:55:10-07:00] INFO: Processing template[/etc/rsyslog.d/50-default.conf] action create (rsyslog::default line 45)
[2014-01-19T09:55:10-07:00] INFO: Processing service[rsyslog] action enable (rsyslog::default line 82)
[2014-01-19T09:55:10-07:00] INFO: Processing service[rsyslog] action start (rsyslog::default line 82)
[2014-01-19T09:55:10-07:00] INFO: Processing template[/etc/rsyslog.d/49-remote.conf] action create (rsyslog::client line 44)
[2014-01-19T09:55:10-07:00] INFO: Processing file[/etc/rsyslog.d/server.conf] action delete (rsyslog::client line 54)
[2014-01-19T09:55:10-07:00] INFO: Processing execute[apt-get-update] action run (apt::default line 30)
[2014-01-19T09:55:10-07:00] INFO: Processing execute[apt-get update] action nothing (apt::default line 38)
[2014-01-19T09:55:10-07:00] INFO: Processing execute[apt-get autoremove] action nothing (apt::default line 46)
[2014-01-19T09:55:10-07:00] INFO: Processing execute[apt-get autoclean] action nothing (apt::default line 53)
[2014-01-19T09:55:10-07:00] INFO: Processing package[update-notifier-common] action install (apt::default line 60)
[2014-01-19T09:55:10-07:00] INFO: Processing execute[apt-get-update-periodic] action run (apt::default line 65)
[2014-01-19T09:55:10-07:00] INFO: Processing directory[/var/cache/local] action create (apt::default line 76)
[2014-01-19T09:55:10-07:00] INFO: Processing directory[/var/cache/local/preseeding] action create (apt::default line 76)
[2014-01-19T09:55:10-07:00] INFO: Processing apt_repository[dotcloud] action add (deis::docker line 4)
[2014-01-19T09:55:10-07:00] INFO: Processing remote_file[/var/chef/cache/gpg] action create (/var/chef/cache/cookbooks/apt/providers/repository.rb line 59)
[2014-01-19T09:55:12-07:00] INFO: Processing execute[install-key gpg] action run (/var/chef/cache/cookbooks/apt/providers/repository.rb line 73)
[2014-01-19T09:55:12-07:00] INFO: Processing file[/var/lib/apt/periodic/update-success-stamp] action nothing (/var/chef/cache/cookbooks/apt/providers/repository.rb line 106)
[2014-01-19T09:55:12-07:00] INFO: Processing execute[apt-get update] action nothing (/var/chef/cache/cookbooks/apt/providers/repository.rb line 110)
[2014-01-19T09:55:12-07:00] INFO: Processing file[/etc/apt/sources.list.d/dotcloud.list] action create (/var/chef/cache/cookbooks/apt/providers/repository.rb line 123)
[2014-01-19T09:55:12-07:00] INFO: Processing package[lxc-docker-0.7.6] action install (deis::docker line 11)
[2014-01-19T09:55:12-07:00] INFO: Processing service[docker] action enable (deis::docker line 13)
[2014-01-19T09:55:12-07:00] INFO: Processing directory[/opt/deis/runtime] action create (deis::runtime line 4)
[2014-01-19T09:55:12-07:00] INFO: Processing directory[/opt/deis/runtime/slugs] action create (deis::runtime line 10)
[2014-01-19T09:55:12-07:00] INFO: Processing git[/opt/deis/runtime/slugrunner] action sync (deis::runtime line 16)
[2014-01-19T09:55:13-07:00] INFO: Processing bash[create-slugrunner-image] action run (deis::runtime line 24)
[2014-01-19T09:55:13-07:00] INFO: Processing package[curl] action install (deis::runtime line 37)
[2014-01-19T09:55:13-07:00] INFO: Processing bash[download-slug-devvy1-2] action run (deis::runtime line 72)
[2014-01-19T09:55:13-07:00] INFO: Processing apt_repository[nginx-ppa] action add (deis::nginx line 12)
[2014-01-19T09:55:13-07:00] INFO: Processing execute[install-key E5267A6C] action run (/var/chef/cache/cookbooks/apt/providers/repository.rb line 28)
[2014-01-19T09:55:13-07:00] INFO: Processing file[/var/lib/apt/periodic/update-success-stamp] action nothing (/var/chef/cache/cookbooks/apt/providers/repository.rb line 106)
[2014-01-19T09:55:13-07:00] INFO: Processing execute[apt-get update] action nothing (/var/chef/cache/cookbooks/apt/providers/repository.rb line 110)
[2014-01-19T09:55:13-07:00] INFO: Processing file[/etc/apt/sources.list.d/nginx-ppa.list] action create (/var/chef/cache/cookbooks/apt/providers/repository.rb line 123)
[2014-01-19T09:55:13-07:00] INFO: Processing package[nginx] action install (deis::nginx line 20)
[2014-01-19T09:55:13-07:00] INFO: Processing link[/etc/nginx/sites-enabled/default] action delete (deis::nginx line 22)
[2014-01-19T09:55:13-07:00] INFO: Processing template[/etc/nginx/nginx.conf] action create (deis::nginx line 27)
[2014-01-19T09:55:13-07:00] INFO: Processing service[nginx] action enable (deis::nginx line 35)
[2014-01-19T09:55:13-07:00] INFO: Processing template[/etc/nginx/sites-available/deis-devvy1] action create (deis::proxy line 8)
[2014-01-19T09:55:13-07:00] INFO: Processing link[/etc/nginx/sites-enabled/deis-devvy1] action create (deis::proxy line 17)
[2014-01-19T09:55:13-07:00] INFO: Processing template[/etc/nginx/sites-available/deis-devvy2] action create (deis::proxy line 8)
[2014-01-19T09:55:13-07:00] INFO: template[/etc/nginx/sites-available/deis-devvy2] backed up to /var/chef/backup/etc/nginx/sites-available/deis-devvy2.chef-20140119095513
[2014-01-19T09:55:13-07:00] INFO: template[/etc/nginx/sites-available/deis-devvy2] updated file contents /etc/nginx/sites-available/deis-devvy2
[2014-01-19T09:55:13-07:00] INFO: Processing link[/etc/nginx/sites-enabled/deis-devvy2] action create (deis::proxy line 17)
[2014-01-19T09:55:13-07:00] INFO: template[/etc/nginx/sites-available/deis-devvy2] sending restart action to service[nginx] (delayed)
[2014-01-19T09:55:13-07:00] INFO: Processing service[nginx] action restart (deis::nginx line 35)
[2014-01-19T09:55:15-07:00] INFO: service[nginx] restarted
[2014-01-19T09:55:16-07:00] INFO: Chef Run complete in 17.030430808 seconds
[2014-01-19T09:55:16-07:00] INFO: Running report handlers
[2014-01-19T09:55:16-07:00] INFO: Report handlers complete
[2014-01-19T09:55:16-07:00] INFO: Sending resource update report (run-id: b0ac45fb-80f0-4e79-b073-1a305ee7ec6b)
[2014-01-19 09:55:17,524: INFO/MainProcess] Task api.tasks.converge_node[78817f2d-aa2a-43f7-8b42-61680c53b0cd] succeeded in 20.980676075s: ('[2014-01-19T09:54:57-07:00] INFO: Forking chef instance to converge...\n[2014-01-19T09:54:57-07:00] INFO: *** Chef 11.6.2...

==> /var/log/deis/server.log <==
ERROR Internal Server Error: /api/apps/devvy2/scale
Traceback (most recent call last):
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 114, in get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/rest_framework/viewsets.py", line 78, in view
    return self.dispatch(request, *args, **kwargs)
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/django/views/decorators/csrf.py", line 57, in wrapped_view
    return view_func(*args, **kwargs)
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/rest_framework/views.py", line 399, in dispatch
    response = self.handle_exception(exc)
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/rest_framework/views.py", line 396, in dispatch
    response = handler(request, *args, **kwargs)
  File "/opt/deis/controller/api/views.py", line 498, in scale
    databag = app.converge()
  File "/opt/deis/controller/api/models.py", line 499, in converge
    self.formation.converge()
  File "/opt/deis/controller/api/models.py", line 217, in converge
    group(*subtasks).apply_async().join()
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/celery/result.py", line 565, in join
    interval=interval)
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/celery/result.py", line 151, in get
    interval=interval)
  File "/opt/deis/controller/venv/local/lib/python2.7/site-packages/celery/backends/amqp.py", line 158, in wait_for
    raise self.exception_to_python(meta['result'])
RuntimeError: Node converge error

==> /var/log/deis/access.log <==
192.168.61.1 - - [19/Jan/2014:09:55:17] "POST /api/apps/devvy2/scale HTTP/1.0" 500 - "-" "python-requests/2.2.0 CPython/2.7.5 Linux/3.12.5-302.fc20.x86_64"