bootstrap fails with failure to execute queries before end of atomic block

Bug #1387262 reported by Larry Michel on 2014-10-29
16
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MAAS
Critical
Julian Edwards
1.7
Critical
Julian Edwards

Bug Description

We're hitting 500 INTERNAL SEVER ERROR during boostrap. There were no additional juju debug log error since this failed before instance was launched. We saw this with one pipeline deploy build:

Launching instance
WARNING picked arbitrary tools &{1.20.11-precise-amd64 https://streams.canonical.com/juju/tools/releases/juju-1.20.11-precise-amd64.tgz 196a1348755f3ce869ce1319995d2d6b672809e165d87987dc5c12828c228de8 8112417}
ERROR bootstrap failed: cannot start bootstrap instance: gomaasapi: got error back from server: 500 INTERNAL SERVER ERROR (An error occurred in the current transaction. You can't execute queries until the end of the 'atomic' block.)
Bootstrap failed, destroying environment
ERROR cannot start bootstrap instance: gomaasapi: got error back from server: 500 INTERNAL SERVER ERROR (An error occurred in the current transaction. You can't execute queries until the end of the 'atomic' block.)
2014-10-29 15:12:51,033 [ERROR] oil_ci.juju.client: Calling "juju bootstrap" failed!
2014-10-29 15:12:51,034 [ERROR] oil_ci.cli: Deployment failed:
+ rc=1
+ echo 'Deployment returned: 1'
Deployment returned: 1
+ [[ 1 == 0 ]]

Related branches

Gavin Panella (allenap) wrote :

Larry, are you able to attach the logs from MAAS? /var/log/maas/*.log and /var/log/apache2/error.log are the most useful.

Changed in juju-core:
status: New → Incomplete
Larry Michel (lmic) wrote :

Here are the logs from maas server.

Larry Michel (lmic) wrote :

Also, maas version:

ubuntu@maas-trusty-back-may22:~$ dpkg -l|grep maas
ii maas 1.7.0~beta8+bzr3281-0ubuntu1~trusty1 all MAAS server all-in-one metapackage

Changed in juju-core:
status: Incomplete → New
John George (jog) on 2014-10-30
tags: added: bootstrap maas-provider
John George (jog) on 2014-10-30
Changed in juju-core:
status: New → Triaged
importance: Undecided → Critical
Curtis Hovey (sinzui) on 2014-10-31
Changed in juju-core:
importance: Critical → High
milestone: none → 1.21-alpha3
Christian Reis (kiko) on 2014-10-31
Changed in maas:
milestone: none → 1.7.1
Curtis Hovey (sinzui) on 2014-11-04
Changed in juju-core:
milestone: 1.21-alpha3 → 1.21-beta1
Larry Michel (lmic) wrote :

We have been hitting this quite a lot lately. We are seeing this on the bootstrap nodes and non-bootstrap nodes. We had one deployment on which we saw this on multiple systems, 3 or 4, including the juju boostrap node.

Julian Edwards (julian-edwards) wrote :
Download full text (3.6 KiB)

I've looked at the logs. Here's the relevant bits from maas-django.log and maas.log:

maas-django.log:
ERROR 2014-10-28 15:40:35,954 maasserver ################################ Exception: An error occurred in the current transaction. You can't execute queries until the end of the 'atomic' block. ################################
ERROR 2014-10-28 15:40:35,979 maasserver Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/django/core/handlers/base.py", line 112, in get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/usr/lib/python2.7/dist-packages/django/views/decorators/vary.py", line 19, in inner_func
    response = func(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/piston/resource.py", line 167, in __call__
    result = self.error_handler(e, request, meth, em_format)
  File "/usr/lib/python2.7/dist-packages/piston/resource.py", line 165, in __call__
    result = meth(request, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/maasserver/api/support.py", line 189, in dispatch
    return function(self, request, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/maasserver/api/nodes.py", line 312, in start
    [system_id], request.user, user_data=user_data)
  File "/usr/lib/python2.7/dist-packages/maasserver/models/node.py", line 416, in start_nodes
    claims = node.claim_static_ip_addresses()
  File "/usr/lib/python2.7/dist-packages/maasserver/models/node.py", line 1506, in claim_static_ip_addresses
    static_ips = mac.claim_static_ips()
  File "/usr/lib/python2.7/dist-packages/maasserver/models/macaddress.py", line 302, in claim_static_ips
    interface, alloc_type, requested_address)
  File "/usr/lib/python2.7/dist-packages/maasserver/models/macaddress.py", line 222, in _allocate_static_address
    alloc_type, requested_address=requested_address)
  File "/usr/lib/python2.7/dist-packages/maasserver/models/staticipaddress.py", line 169, in allocate_new
    requested_address, alloc_type, user)
  File "/usr/lib/python2.7/dist-packages/maasserver/models/staticipaddress.py", line 103, in _attempt_allocation
    ipaddress.save()
  File "/usr/lib/python2.7/dist-packages/maasserver/models/cleansave.py", line 38, in save
    return super(CleanSave, self).save(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/maasserver/models/timestampedmodel.py", line 51, in save
    current_time = now()
  File "/usr/lib/python2.7/dist-packages/maasserver/models/timestampedmodel.py", line 31, in now
    cursor.execute("select now()")
  File "/usr/lib/python2.7/dist-packages/django/db/backends/util.py", line 47, in execute
    self.db.validate_no_broken_transaction()
  File "/usr/lib/python2.7/dist-packages/django/db/backends/__init__.py", line 365, in validate_no_broken_transaction
    "An error occurred in the current transaction. You can't "
TransactionManagementError: An error occurred in the current transaction. You can't execute queries until the end of the 'atomic' block.

maas.log:
Oct 28 15:40:32 maas-trusty-back-may22 maas.node: [INFO] hayward-42 allocated to user oil-slave-3
Oct 28 15:40:35 maas-trusty-back-may22 maas.node: [INFO] anahuac.oil: Starting ...

Read more...

Changed in maas:
status: New → Triaged
importance: Undecided → Critical
Julian Edwards (julian-edwards) wrote :

In the postgres log I see:

2014-10-28 15:40:35 UTC ERROR: duplicate key value violates unique constraint "maasserver_staticipaddress_ip_key"
2014-10-28 15:40:35 UTC DETAIL: Key (ip)=(10.245.0.201) already exists.
2014-10-28 15:40:35 UTC STATEMENT: INSERT INTO "maasserver_staticipaddress" ("created", "updated", "ip", "alloc_type", "user_id") VALUES ('2014-10-28 15:40:32.431728', '2014-10-28 15:40:32.431728', '10.245.0.201', 0, NULL) RETURNING "maasserver_staticipaddress"."id"

Julian Edwards (julian-edwards) wrote :

This looks like a race when allocating IP addresses at deployment, and the failure is not handled properly.

Changed in maas:
assignee: nobody → Julian Edwards (julian-edwards)
status: Triaged → In Progress
Changed in maas:
status: In Progress → Fix Committed
Andres Rodriguez (andreserl) wrote :

I think this is critical enough that this needs to be backported ASAP. This is affecting OIL deployments.

Thanks

Changed in maas:
milestone: 1.7.1 → none
Ian Booth (wallyworld) on 2014-11-06
no longer affects: juju-core
Changed in maas:
status: Fix Committed → Fix Released

Hello Larry, or anyone else affected,

Accepted maas into utopic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/maas/1.7.5+bzr3369-0ubuntu1~14.10.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

tags: added: verification-needed
Andres Rodriguez (andreserl) wrote :

This issue has been verified to work both on upgrade and fresh install, and has been QA'd. Marking verification-done.

tags: added: verification-done
removed: verification-needed
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers