Comment 0 for bug 1843493

Revision history for this message
Pedro GuimarĂ£es (pguimaraes) wrote :

MAAS: 2.6.0 (7802-g59416a869-0ubuntu1~18.04.1)

Whenever I boot multiple VM pods at the same time using "allocate" operation, I get some VMs failing with overall message on Juju as:
3 down pending bionic suitable availability zone for machine 3 not found

Looking into MAAS source code, I can see decision on which pod will receive corresponding VM is done on method:
https://github.com/maas/maas/blob/5fe288985249afedadf4656b595238856b13ce4d/src/maasserver/forms/pods.py#L726

Added more logs to the "except" statement and found out two types of errors: OperationalError and TransactionManagementError. I believe both errors correspond to a resource dispute on database, since error message is generally: "could not serialize access due to concurrent update", which is also documented on Postgres: https://www.postgresql.org/docs/9.1/transaction-iso.html

Full traceback of OperationalError:

Traceback (most recent call last):
   File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 64, in execute
     return self.cursor.execute(sql, params)
 psycopg2.extensions.TransactionRollbackError: could not serialize access due to concurrent update

 The above exception was the direct cause of the following exception:

 Traceback (most recent call last):
   File "/usr/lib/python3/dist-packages/maasserver/forms/pods.py", line 745, in compose
     creation_type=NODE_CREATION_TYPE.DYNAMIC)
   File "/usr/lib/python3/dist-packages/maasserver/forms/pods.py", line 664, in compose
     return create_and_sync((requested_machine, result))
   File "/usr/lib/python3/dist-packages/maasserver/forms/pods.py", line 606, in create_and_sync
     self.pod.sync_hints(pod_hints)
   File "/usr/lib/python3/dist-packages/maasserver/models/bmc.py", line 622, in sync_hints
     hints.save()
   File "/usr/lib/python3/dist-packages/maasserver/models/cleansave.py", line 252, in save
     return super(CleanSave, self).save(*args, **kwargs)
   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 808, in save
     force_update=force_update, update_fields=update_fields)
   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 838, in save_base
     updated = self._save_table(raw, cls, force_insert, force_update, using, update_fields)
   File "/usr/lib/python3/dist-packages/maasserver/models/cleansave.py", line 278, in _save_table
     update_fields=update_fields)
   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 905, in _save_table
     forced_update)
   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 955, in _do_update
     return filtered._update(values) > 0
   File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 664, in _update
     return query.get_compiler(self.db).execute_sql(CURSOR)
   File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 1204, in execute_sql
     cursor = super(SQLUpdateCompiler, self).execute_sql(result_type)
   File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 899, in execute_sql
     raise original_exception
   File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 889, in execute_sql
     cursor.execute(sql, params)
   File "/usr/lib/python3/dist-packages/maasserver/prometheus/middleware.py", line 21, in execute
     return super().execute(sql, params=params)
   File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 64, in execute
     return self.cursor.execute(sql, params)
   File "/usr/lib/python3/dist-packages/django/db/utils.py", line 94, in __exit__
     six.reraise(dj_exc_type, dj_exc_value, traceback)
   File "/usr/lib/python3/dist-packages/django/utils/six.py", line 685, in reraise
     raise value.with_traceback(tb)
   File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 64, in execute
     return self.cursor.execute(sql, params)
 django.db.utils.OperationalError: could not serialize access due to concurrent update

Full tracestack for TransactionManagementError (unformatted):
2019-09-10 20:13:12 maasserver.forms.pods: [info] Unable to format event {'log_logger': <LegacyLogger 'maasserver.forms.pods'>, 'log_level': <LogLevel=info>, 'log_namespace': 'maasserver.forms.pods', 'log_source': None, 'log_format': 'Traceback (most recent call last):\n File "/usr/lib/python3/dist-packages/maasserver/forms/pods.py", line 742, in compose\n log.info("ComposeMachineForPodsForm compose commit_forms: {}".format(form))\n File "/usr/lib/python3/dist-packages/django/utils/html.py", line 394, in <lambda>\n klass.__str__ = lambda self: mark_safe(klass_str(self))\n File "/usr/lib/python3/dist-packages/django/forms/forms.py", line 137, in __str__\n return self.as_table()\n File "/usr/lib/python3/dist-packages/django/forms/forms.py", line 285, in as_table\n errors_on_separate_row=False)\n File "/usr/lib/python3/dist-packages/django/forms/forms.py", line 240, in _html_output\n \'field\': six.text_type(bf),\n File "/usr/lib/python3/dist-packages/django/utils/html.py", line 394, in <lambda>\n klass.__str__ = lambda self: mark_safe(klass_str(self))\n File "/usr/lib/python3/dist-packages/django/forms/boundfield.py", line 41, in __str__\n return self.as_widget()\n File "/usr/lib/python3/dist-packages/django/forms/boundfield.py", line 127, in as_widget\n **kwargs\n File "/usr/lib/python3/dist-packages/django/forms/widgets.py", line 220, in render\n context = self.get_context(name, value, attrs)\n File "/usr/lib/python3/dist-packages/django/forms/widgets.py", line 665, in get_context\n context = super(Select, self).get_context(name, value, attrs)\n File "/usr/lib/python3/dist-packages/django/forms/widgets.py", line 627, in get_context\n context[\'widget\'][\'optgroups\'] = self.optgroups(name, context[\'widget\'][\'value\'], attrs)\n File "/usr/lib/python3/dist-packages/django/forms/widgets.py", line 575, in optgroups\n for index, (option_value, option_label) in enumerate(chain(self.choices)):\n File "/usr/lib/python3/dist-packages/django/forms/models.py", line 1139, in __iter__\n for obj in queryset:\n File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 53, in __iter__\n results = compiler.execute_sql(chunked_fetch=self.chunked_fetch)\n File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 899, in execute_sql\n raise original_exception\n File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 889, in execute_sql\n cursor.execute(sql, params)\n File "/usr/lib/python3/dist-packages/maasserver/prometheus/middleware.py", line 21, in execute\n return super().execute(sql, params=params)\n File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 59, in execute\n self.db.validate_no_broken_transaction()\n File "/usr/lib/python3/dist-packages/django/db/backends/base/base.py", line 448, in validate_no_broken_transaction\n "An error occurred in the current transaction. You can\'t "\ndjango.db.transaction.TransactionManagementError: An error occurred in the current transaction. You can\'t execute queries until the end of the \'atomic\' block.\n', 'log_time': 1568146392.1984248}: tuple index out of range
2019-09-10 20:13:12 maasserver.forms.pods: [info] ComposeMachineForPodsForm commit_forms Exception: An error occurred in the current transaction. You can't execute queries until the end of the 'atomic' block.