Deployment fails with Error running provisioning: Failed to execute hook in astute.log

[Stanislaw Bogatkin]

http://jenkins-product.srt.mirantis.net:8080/job/6.1.ubuntu.bvt_2/226/

VERSION:
  feature_groups:
    - mirantis
  production: "docker"
  release: "6.1"
  api: "1.0"
  build_number: "231"
  build_id: "2015-03-26_09-08-29"
  nailgun_sha: "7f0e0af1f54db840230745ee4f7aec6824dac9b9"
  python-fuelclient_sha: "e5e8389d8d481561a4d7107a99daae07c6ec5177"
  astute_sha: "631f96d5a09cc48bfbddcbf056b946c8a80438f0"
  fuellib_sha: "345a98b34dd0cd450a45d405ac47a6a9fa48b6d8"
  ostf_sha: "a4cf5f218c6aea98105b10c97a4aed8115c15867"
  fuelmain_sha: "320b5f46fc1b2798f9e86ed7df51d3bda1686c10"

In astute.log:

stderr:
exit code: 1
2015-03-26T10:52:20 warning: [686] Problem while performing cmd. Try to repeat: 0 attempt
2015-03-26T10:52:21 info: [686] Casting message to Nailgun: {"method"=>"provision_resp", "args"=>{"task_uuid"=>"2672a689-e251-4f7f-8055-7c9dfc1b547c", "nodes"=>[{"uid"=>"master", "status"=>"error", "error_type"=>"provision", "role"=>"hook", "hook"=>nil}]}}
2015-03-26T10:52:21 err: [686] Error running provisioning: Failed to execute hook .

---
priority: 100
type: shell
uids:
- master
parameters:
  retries: 1
  cmd: 'fuel-image ''{"image_data": {"/boot": {"container": "gzip", "uri": "http://10.109.0.2:8080/targetimages/env_1_ubuntu_1404_amd64-boot.img.gz",
    "format": "ext2"}, "/": {"container": "gzip", "uri": "http://10.109.0.2:8080/targetimages/env_1_ubuntu_1404_amd64.img.gz",
    "format": "ext4"}}, "output": "/var/www/nailgun/targetimages", "repos": [{"name":
    "ubuntu-0", "section": "main universe multiverse", "uri": "http://mirror-pkgs.vm.mirantis.net/ubuntu-2015-03-26-030045",
    "priority": 1001, "suite": "trusty", "type": "deb"}, {"name": "ubuntu-1", "section":
    "main universe multiverse", "uri": "http://mirror-pkgs.vm.mirantis.net/ubuntu-2015-03-26-030045",
    "priority": 1001, "suite": "trusty-updates", "type": "deb"}, {"name": "ubuntu-2",
    "section": "main universe multiverse", "uri": "http://mirror-pkgs.vm.mirantis.net/ubuntu-2015-03-26-030045",
    "priority": 1001, "suite": "trusty-security", "type": "deb"}, {"name": "mos",
    "section": "main restricted", "uri": "http://10.109.0.2:8080/2014.2-6.1/ubuntu/x86_64",
    "priority": 1050, "suite": "mos6.1", "type": "deb"}, {"name": "mos-updates", "section":
    "main restricted", "uri": "http://mirror.fuel-infra.org/mos/ubuntu/", "priority":
    1050, "suite": "mos6.1-updates", "type": "deb"}, {"name": "mos-security", "section":
    "main restricted", "uri": "http://mirror.fuel-infra.org/mos/ubuntu/", "priority":
    1050, "suite": "mos6.1-security", "type": "deb"}, {"name": "mos-holdback", "section":
    "main restricted", "uri": "http://mirror.fuel-infra.org/mos/ubuntu/", "priority":
    1100, "suite": "mos6.1-holdback", "type": "deb"}], "codename": "trusty"}'''
  cwd: "/"
  timeout: 1200
  interval: 1
, trace:
["/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/nailgun_hooks.rb:54:in `block in process'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/nailgun_hooks.rb:26:in `each'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/nailgun_hooks.rb:26:in `process'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/orchestrator.rb:69:in `provision'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/dispatcher.rb:50:in `provision'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/dispatcher.rb:37:in `image_provision'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/server.rb:142:in `dispatch_message'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/server.rb:103:in `block in dispatch'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/task_queue.rb:64:in `call'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/task_queue.rb:64:in `block in each'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/task_queue.rb:56:in `each'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/task_queue.rb:56:in `each'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/server.rb:101:in `each_with_index'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/server.rb:101:in `dispatch'",
 "/usr/lib64/ruby/gems/2.1.0/gems/astute-6.0.0/lib/astute/server/server.rb:85:in `block in perform_main_job'"]

2015-03-26T10:52:21 debug: [686] Dispatching aborted by image_provision

[Stanislaw Bogatkin (sbogatkin)]

Also reproduced on http://jenkins-product.srt.mirantis.net:8080/job/6.1.ubuntu.smoke_neutron/155/

[Dmitry Pyzhov (dpyzhov)]

This message means that image build failed. We are working hard on rewriting image build to python: https://bugs.launchpad.net/fuel/+bug/1433193
So this issue will be fixed by the end of this week with our new python implementation.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/166774
Committed: https://git.openstack.org/cgit/stackforge/fuel-main/commit/?id=465825cb450236c97adb0a18fa236e7c121f6805
Submitter: Jenkins
Branch: master

commit 465825cb450236c97adb0a18fa236e7c121f6805
Author: Alexander Gordeev <email address hidden>
Date: Mon Mar 23 13:29:28 2015 +0300

    IBP: fix apt pinning in build script

    We have to use `archive` name in APT pinning because `suite` is actually
    an archive name. For instance, the following upstream Ubuntu repo

        deb http://archive.ubuntu.com/ubuntu/ trusty-updates main

    has the following attributes in APT pinning

        a=trusty-updates, n=trusty, c=main

    Obviously, it's wrong to use `n=` (codename) for matching suite.

    Besides this, since now we're generating a few pinnings for the source
    like

        deb http://archive.ubuntu.com/ubuntu/ trusty main restricted

    because the following line

        a=trusty, c=main, c=restricted

    will apply pinning only for the `restricted` section.

    Also, it skips a repo from pinning if its priority isn't set.

    Change-Id: Ibe5c99910f70312ea4e4bd0c642cd8f31ddc526b
    Implements: blueprint consume-external-ubuntu
    Closes-Bug: #1436806

[Anastasia Palkina (apalkina)]

Cannot reproduce on latests ISOs including #314

"build_id": "2015-04-15_23-18-33", "ostf_sha": "90f232a25d10f98db9d5531a3b133319529f57aa", "build_number": "314", "release_versions": {"2014.2-6.1": {"VERSION": {"build_id": "2015-04-15_23-18-33", "ostf_sha": "90f232a25d10f98db9d5531a3b133319529f57aa", "build_number": "314", "api": "1.0", "nailgun_sha": "24b56283fb4caaba6b6414056dad30e503a7c30f", "openstack_version": "2014.2-6.1", "production": "docker", "python-fuelclient_sha": "ff186de358cbda489a320723de47a9e61ae23364", "astute_sha": "36a3d54baf86480326866279778b867086aa4b05", "feature_groups": ["mirantis"], "release": "6.1", "fuelmain_sha": "d3aa72d814c3f18799b566363004a22591161cef", "fuellib_sha": "ab6dbba825a5e54f3183ed8582921a0328b211c7"}}}, "auth_required": true, "api": "1.0", "nailgun_sha": "24b56283fb4caaba6b6414056dad30e503a7c30f", "openstack_version": "2014.2-6.1", "production": "docker", "python-fuelclient_sha": "ff186de358cbda489a320723de47a9e61ae23364", "astute_sha": "36a3d54baf86480326866279778b867086aa4b05", "feature_groups": ["mirantis"], "release": "6.1", "fuelmain_sha": "d3aa72d814c3f18799b566363004a22591161cef", "fuellib_sha": "ab6dbba825a5e54f3183ed8582921a0328b211c7"