So the root cause is that when we run a transaction we do not filter nodes per-graph, but rather per-transaction.
See
4344 2017-03-14 22:11:48.516 INFO [7fa84a51f880] (manager) Start new transaction: cluster=1 graphs=[{u'type': u'net-verification'}, {u'type': u'deletion'}, {u'type': u'prov ision'}, {u'type': u'default'}] dry_run=0 noop_run=False force=0 4345 2017-03-14 22:11:48.535 DEBUG [7fa84a51f880] (task) Mark task as deleted: 52547e48-8e1a-4e4c-84ec-bfddc3d3359b 4346 2017-03-14 22:11:48.536 DEBUG [7fa84a51f880] (task) Updating task: 52547e48-8e1a-4e4c-84ec-bfddc3d3359b 4347 2017-03-14 22:11:48.578 DEBUG [7fa84a51f880] (manager) Transaction 10 starts assembling. 4348 2017-03-14 22:11:48.579 DEBUG [7fa84a51f880] (manager) Transaction 10 finish assembling. 4349 2017-03-14 22:11:48.579 DEBUG [7fa84a51f880] (mule) MULE STARTING for TransactionsManager._execute_async 4350 2017-03-14 22:11:48.585 DEBUG [7fa84a51f880] (manager) Transaction 10 starts assembling. 4351 [pid: 18806|app: 0|req: 91/456] 10.109.0.1 () {40 vars in 601 bytes} [Tue Mar 14 22:11:48 2017] PUT /api/clusters/1/changes/ => generated 276 bytes in 217 msecs (HTTP/ 1.1 202) 4 headers in 191 bytes (2 switches on core 0) 4352 2017-03-14 22:11:48.612 WARNING [7fa84a51f880] (deployment_graph) Graph association with type 'net-verification' was requested for the unappropriated model instance <n ailgun.db.sqlalchemy.models.cluster.Cluster object at 0x7fa82c035c50> with ID=1 4353 2017-03-14 22:11:48.614 DEBUG [7fa84a51f880] (manager) applying nodes filter: $.pending_addition
We filter nodes only once here: for net-verification, but not for other graphs. Thus we run provision graph on already provisioned nodes.
So the root cause is that when we run a transaction we do not filter nodes per-graph, but rather per-transaction.
See
4344 2017-03-14 22:11:48.516 INFO [7fa84a51f880] (manager) Start new transaction: cluster=1 graphs=[{u'type': u'net-verificat ion'}, {u'type': u'deletion'}, {u'type': u'prov ision'}, {u'type': u'default'}] dry_run=0 noop_run=False force=0 8e1a-4e4c- 84ec-bfddc3d335 9b 8e1a-4e4c- 84ec-bfddc3d335 9b ager._execute_ async 1/changes/ => generated 276 bytes in 217 msecs (HTTP/ 1.1 202) 4 headers in 191 bytes (2 switches on core 0) db.sqlalchemy. models. cluster. Cluster object at 0x7fa82c035c50> with ID=1
4345 2017-03-14 22:11:48.535 DEBUG [7fa84a51f880] (task) Mark task as deleted: 52547e48-
4346 2017-03-14 22:11:48.536 DEBUG [7fa84a51f880] (task) Updating task: 52547e48-
4347 2017-03-14 22:11:48.578 DEBUG [7fa84a51f880] (manager) Transaction 10 starts assembling.
4348 2017-03-14 22:11:48.579 DEBUG [7fa84a51f880] (manager) Transaction 10 finish assembling.
4349 2017-03-14 22:11:48.579 DEBUG [7fa84a51f880] (mule) MULE STARTING for TransactionsMan
4350 2017-03-14 22:11:48.585 DEBUG [7fa84a51f880] (manager) Transaction 10 starts assembling.
4351 [pid: 18806|app: 0|req: 91/456] 10.109.0.1 () {40 vars in 601 bytes} [Tue Mar 14 22:11:48 2017] PUT /api/clusters/
4352 2017-03-14 22:11:48.612 WARNING [7fa84a51f880] (deployment_graph) Graph association with type 'net-verification' was requested for the unappropriated model instance <n ailgun.
4353 2017-03-14 22:11:48.614 DEBUG [7fa84a51f880] (manager) applying nodes filter: $.pending_addition
We filter nodes only once here: for net-verification, but not for other graphs. Thus we run provision graph on already provisioned nodes.