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
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.
MAAS: 2.6.0 (7802-g59416a86 9-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: /github. com/maas/ maas/blob/ 5fe288985249afe dadf4656b595238 856b13ce4d/ src/maasserver/ forms/pods. py#L726
https:/
Added more logs to the "except" statement and found out two types of errors: OperationalError and TransactionMana gementError. 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): python3/ dist-packages/ django/ db/backends/ utils.py" , line 64, in execute execute( sql, params) extensions. TransactionRoll backError: could not serialize access due to concurrent update
File "/usr/lib/
return self.cursor.
psycopg2.
The above exception was the direct cause of the following exception:
Traceback (most recent call last): python3/ dist-packages/ maasserver/ forms/pods. py", line 745, in compose type=NODE_ CREATION_ TYPE.DYNAMIC) python3/ dist-packages/ maasserver/ forms/pods. py", line 664, in compose and_sync( (requested_ machine, result)) python3/ dist-packages/ maasserver/ forms/pods. py", line 606, in create_and_sync pod.sync_ hints(pod_ hints) python3/ dist-packages/ maasserver/ models/ bmc.py" , line 622, in sync_hints python3/ dist-packages/ maasserver/ models/ cleansave. py", line 252, in save python3/ dist-packages/ django/ db/models/ base.py" , line 808, in save update= force_update, update_ fields= update_ fields) python3/ dist-packages/ django/ db/models/ base.py" , line 838, in save_base table(raw, cls, force_insert, force_update, using, update_fields) python3/ dist-packages/ maasserver/ models/ cleansave. py", line 278, in _save_table fields= update_ fields) python3/ dist-packages/ django/ db/models/ base.py" , line 905, in _save_table python3/ dist-packages/ django/ db/models/ base.py" , line 955, in _do_update _update( values) > 0 python3/ dist-packages/ django/ db/models/ query.py" , line 664, in _update compiler( self.db) .execute_ sql(CURSOR) python3/ dist-packages/ django/ db/models/ sql/compiler. py", line 1204, in execute_sql Compiler, self).execute_ sql(result_ type) python3/ dist-packages/ django/ db/models/ sql/compiler. py", line 899, in execute_sql python3/ dist-packages/ django/ db/models/ sql/compiler. py", line 889, in execute_sql execute( sql, params) python3/ dist-packages/ maasserver/ prometheus/ middleware. py", line 21, in execute .execute( sql, params=params) python3/ dist-packages/ django/ db/backends/ utils.py" , line 64, in execute execute( sql, params) python3/ dist-packages/ django/ db/utils. py", line 94, in __exit__ reraise( dj_exc_ type, dj_exc_value, traceback) python3/ dist-packages/ django/ utils/six. py", line 685, in reraise traceback( tb) python3/ dist-packages/ django/ db/backends/ utils.py" , line 64, in execute execute( sql, params) db.utils. OperationalErro r: could not serialize access due to concurrent update
File "/usr/lib/
creation_
File "/usr/lib/
return create_
File "/usr/lib/
self.
File "/usr/lib/
hints.save()
File "/usr/lib/
return super(CleanSave, self).save(*args, **kwargs)
File "/usr/lib/
force_
File "/usr/lib/
updated = self._save_
File "/usr/lib/
update_
File "/usr/lib/
forced_update)
File "/usr/lib/
return filtered.
File "/usr/lib/
return query.get_
File "/usr/lib/
cursor = super(SQLUpdate
File "/usr/lib/
raise original_exception
File "/usr/lib/
cursor.
File "/usr/lib/
return super()
File "/usr/lib/
return self.cursor.
File "/usr/lib/
six.
File "/usr/lib/
raise value.with_
File "/usr/lib/
return self.cursor.
django.
Full tracestack for TransactionMana gementError (unformatted): 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( "ComposeMachine ForPodsForm 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/boundfiel d.py", line 41, in __str__\n return self.as_widget()\n File "/usr/lib/ python3/ dist-packages/ django/ forms/boundfiel d.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. TransactionMana gementError: 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 forms.pods: [info] ComposeMachineF orPodsForm commit_forms Exception: An error occurred in the current transaction. You can't execute queries until the end of the 'atomic' block.
2019-09-10 20:13:12 maasserver.
2019-09-10 20:13:12 maasserver.