VirtualMachineExtension metadata error handling response from create_or_update: KeyError "Use twice the key"

[jeking3]

• Package Name: azure-mgmt-compute
• Package Version: 12.0.0
• Operating System: Debian 10
• Python Version: 3.7.3

Describe the bug

After calling VirtualMachineExtension.create_or_update, the response coming back from the server cannot go through a deserialize/serialize cycle, likely due to something with the metadata handling (there are two fields with the key "type" in the structure, but at different levels):

Calling create_or_update with:

('confab-test-virtual-machine-extension-rg',
 'confab-test-virtual-machine-extension-vm',
 'confab-test-virtual-machine-extension',
 {'auto_upgrade_minor_version': True,
  'location': 'eastus',
  'protected_settings': {'commandToExecute': 'powershell.exe -ExecutionPolicy '
                                             'Unrestricted -File '
                                             'appgatewayurl.ps1'},
  'publisher': 'Microsoft.Compute',
  'settings': {'fileUris': ['https://raw.githubusercontent.com/Azure/azure-docs-powershell-samples/master/application-gateway/iis/appgatewayurl.ps1']},
  'tags': {'_tuono_version': 'v0.1.2+unittest'},
  'type_handler_version': '1.10',
  'virtual_machine_extension_type': 'CustomScriptExtension'})

Note there is no "type" property; the server fills that in on the response:

(Pdb) pp result._result
<azure.mgmt.compute.v2019_12_01.models._models_py3.VirtualMachineExtension object at 0x7ff6952fdfd0>
(Pdb) pp result._result.as_dict()
{'auto_upgrade_minor_version': True,
 'id': '/subscriptions/.../resourceGroups/confab-test-virtual-machine-extension-rg/providers/Microsoft.Compute/virtualMachines/confab-test-virtual-machine-extension-vm/extensions/confab-test-virtual-machine-extension',
 'location': 'eastus',
 'name': 'confab-test-virtual-machine-extension',
 'provisioning_state': 'Succeeded',
 'publisher': 'Microsoft.Compute',
 'settings': {'fileUris': ['https://raw.githubusercontent.com/Azure/azure-docs-powershell-samples/master/application-gateway/iis/appgatewayurl.ps1']},
 'tags': {'_tuono_version': 'v0.1.2+unittest'},
 'type': 'Microsoft.Compute/virtualMachines/extensions',
 'type_handler_version': '1.10',
 'virtual_machine_extension_type': 'CustomScriptExtension'}

Now if you attempt to deserialize this result it will fail with the error:

(Pdb) from azure.mgmt.compute.models import VirtualMachineExtension
(Pdb) pp VirtualMachineExtension.from_dict(result._result.as_dict())

*** msrest.exceptions.DeserializationError: Unable to deserialize to object: type, KeyError: 'Use twice the key: "virtual_machine_extension_type"'

When I get the error indicating "Use twice the key", which is a KeyError ,I added a breakpoint so I could investigate:

> /home/jking/confab/confab-cloud/.tox/debug/lib/python3.7/site-packages/msrest/serialization.py(1358)_deserialize()
-> raise KeyError('Use twice the key: "{}"'.format(attr))
(Pdb) l
1353                    for key_extractor in self.key_extractors:
1354                        found_value = key_extractor(attr, attr_desc, data)
1355                        if found_value is not None:
1356                            if raw_value is not None and raw_value != found_value:
1357                                breakpoint()
1358 ->                             raise KeyError('Use twice the key: "{}"'.format(attr))
1359                            raw_value = found_value
1360
1361                    value = self.deserialize_data(raw_value, attr_desc['type'])
1362                    d_attrs[attr] = value
1363            except (AttributeError, TypeError, KeyError) as err:

(Pdb) pp data
{'auto_upgrade_minor_version': True,
 'id': '/subscriptions/.../resourceGroups/confab-test-virtual-machine-extension-rg/providers/Microsoft.Compute/virtualMachines/confab-test-virtual-machine-extension-vm/extensions/confab-test-virtual-machine-extension',
 'location': 'eastus',
 'name': 'confab-test-virtual-machine-extension',
 'provisioning_state': 'Succeeded',
 'publisher': 'Microsoft.Compute',
 'settings': {'fileUris': ['https://raw.githubusercontent.com/Azure/azure-docs-powershell-samples/master/application-gateway/iis/appgatewayurl.ps1']},
 'tags': {'_tuono_version': 'v0.1.2+unittest'},
 'type': 'Microsoft.Compute/virtualMachines/extensions',
 'type_handler_version': '1.10',
 'virtual_machine_extension_type': 'CustomScriptExtension'}

(Pdb) pp attr
'virtual_machine_extension_type'
(Pdb) pp attr_desc
{'key': 'properties.type', 'type': 'str'}

(Pdb) pp found_value
'Microsoft.Compute/virtualMachines/extensions'
(Pdb) pp key_extractor
<function last_rest_key_case_insensitive_extractor at 0x7f9a2fab1048>

(Pdb) pp attributes
{'auto_upgrade_minor_version': {'key': 'properties.autoUpgradeMinorVersion',
                                'type': 'bool'},
 'force_update_tag': {'key': 'properties.forceUpdateTag', 'type': 'str'},
 'id': {'key': 'id', 'type': 'str'},
 'instance_view': {'key': 'properties.instanceView',
                   'type': 'VirtualMachineExtensionInstanceView'},
 'location': {'key': 'location', 'type': 'str'},
 'name': {'key': 'name', 'type': 'str'},
 'protected_settings': {'key': 'properties.protectedSettings',
                        'type': 'object'},
 'provisioning_state': {'key': 'properties.provisioningState', 'type': 'str'},
 'publisher': {'key': 'properties.publisher', 'type': 'str'},
 'settings': {'key': 'properties.settings', 'type': 'object'},
 'tags': {'key': 'tags', 'type': '{str}'},
 'type': {'key': 'type', 'type': 'str'},
 'type_handler_version': {'key': 'properties.typeHandlerVersion',
                          'type': 'str'},
 'virtual_machine_extension_type': {'key': 'properties.type', 'type': 'str'}}

It appears the metadata for "virtual_machine_extension_type" is referencing the "type" field instead of the "virtual_machine_extension_type" field. It extracts the wrong content, and then the code thinks that a key appears twice in the data.

incorrect:
(Pdb) pp key_extractor("virtual_machine_extension_type", {"key": "properties.type", "type": "str"}, data)
'Microsoft.Compute/virtualMachines/extensions'

correct:
(Pdb) pp key_extractor("virtual_machine_extension_type", {"key": "properties.virtual_machine_extension_type", "type": "str"}, data)
'CustomScriptExtension'

To Reproduce Run the following script:

import unittest

from azure.mgmt.compute.models import VirtualMachineExtension

class TestVirtualMachineExtensionSerialization(unittest.TestCase):
    def setUp(self):
        self.raw = {
            'auto_upgrade_minor_version': True,
            'id': (
                '/subscriptions/.../resourceGroups/confab-test-virtual-machine-extension-2-rg'
                '/providers/Microsoft.Compute/virtualMachines/confab-test-virtual-machine-extension-2-vm'
                '/extensions/confab-test-virtual-machine-extension-2'
            ),
            'location': 'eastus',
            'name': 'confab-test-virtual-machine-extension-2',
            'provisioning_state': 'Succeeded',
            'publisher': 'Microsoft.Compute',
            'settings': {
                'fileUris': [
                    (
                        'https://raw.githubusercontent.com/Azure/azure-docs-powershell-samples'
                        '/master/application-gateway/iis/appgatewayurl.ps1'
                    )
                ]
            },
            'tags': {'_tuono_version': 'v0.1.2+unittest'},
            'type': 'Microsoft.Compute/virtualMachines/extensions',
            'type_handler_version': '1.10',
            'virtual_machine_extension_type': 'CustomScriptExtension'
        }

    def test_from_dict(self):
        assert VirtualMachineExtension.from_dict(self.raw).virtual_machine_extension_type == "CustomScriptExtension"

if __name__ == "__main__":
    unittest.main()

Result:

confab@bf0bc13796ae:/data$ python3 /tmp/bug.py
E
======================================================================
ERROR: test_from_dict (__main__.TestVirtualMachineExtensionSerialization)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/msrest/serialization.py", line 1357, in _deserialize
    raise KeyError('Use twice the key: "{}"'.format(attr))
KeyError: 'Use twice the key: "virtual_machine_extension_type"'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/tmp/bug.py", line 34, in test_from_dict
    assert VirtualMachineExtension.from_dict(self.raw).virtual_machine_extension_type == "CustomScriptExtension"
  File "/usr/local/lib/python3.7/site-packages/msrest/serialization.py", line 322, in from_dict
    return deserializer(cls.__name__, data, content_type=content_type)
  File "/usr/local/lib/python3.7/site-packages/msrest/serialization.py", line 1294, in __call__
    return self._deserialize(target_obj, data)
  File "/usr/local/lib/python3.7/site-packages/msrest/serialization.py", line 1364, in _deserialize
    raise_with_traceback(DeserializationError, msg, err)
  File "/usr/local/lib/python3.7/site-packages/msrest/exceptions.py", line 51, in raise_with_traceback
    raise error.with_traceback(exc_traceback)
  File "/usr/local/lib/python3.7/site-packages/msrest/serialization.py", line 1357, in _deserialize
    raise KeyError('Use twice the key: "{}"'.format(attr))
msrest.exceptions.DeserializationError: Unable to deserialize to object: type, KeyError: 'Use twice the key: "virtual_machine_extension_type"'

[jeking3]

This is likely an internal error in the program I was using; I will investigate that and re-open this if necessary.

[jeking3]

Reopened, this is not an issue in my code; it is happening in the library.

[ghost]

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @Drewm3, @avirishuv, @axayjo, @vaibhav-agar.

[lmazuel]

Hi @jeking3 Assigning to myself since it touches the serialization part and not really the Compute specific part. I actually wrote that "double key" detection mechanism :). Your Github report is awesome, all the details I can dream of, I'll try to investigate that asap (can't promise date though I'm sorry).

[jeking3]

Thanks!

My guess is in this case the metadata is wrong, or it is not reversible. i.e. when converting from python to rest you take the virtual_machine_extension_type and stuck it in properties.type, and the same on the way back out. But if you as_dict then from_dict a VirtualMachineExtension object, the content stays in python form, and the lookup is expecting server form:

1146    def last_rest_key_case_insensitive_extractor(attr, attr_desc, data):
1147 ->     key = attr_desc['key']
1148        dict_keys = _FLATTEN.split(key)
1149        return attribute_key_case_insensitive_extractor(dict_keys[-1], None, data)
1150
1151    def attribute_key_extractor(attr, _, data):
1152        return data.get(attr)
(Pdb) n
> /home/jking/confab/confab-cloud/.tox/debug/lib/python3.7/site-packages/msrest/serialization.py(1148)last_rest_key_case_insensitive_extractor()
-> dict_keys = _FLATTEN.split(key)
(Pdb) n
> /home/jking/confab/confab-cloud/.tox/debug/lib/python3.7/site-packages/msrest/serialization.py(1149)last_rest_key_case_insensitive_extractor()
-> return attribute_key_case_insensitive_extractor(dict_keys[-1], None, data)
(Pdb) pp dict_keys
['properties', 'type']

In this case it ignores "attr" completely, and drops "properties." and returns the type field which is wrong.

[jeking3]

I'd like to stress the urgency for a fix on this... Any virtual machine with an extension installed cannot be deserialized by azure-mgmt-compute 12.0 (the current version).

[lmazuel]

@jeking3 could you try downgrading msrest to 0.6.12 or below? I wonder if its a regression introduced in 0.6.13

Edit: tested myself and no difference 0.6.12/0.6.13

[lmazuel]

Hi @jeking3 Something I don't understand, why would you do that:

VirtualMachineExtension.from_dict(result._result.as_dict())

It seems you got result._result as a correct instance of VirtualMachineExtension already from create_or_update, meaning you didn't get an exception from create_or_update (which is what you title made me think).

I don't deny there is a bug somewhere of course, I'm just challenging the title to be misleading a little, since to me the create_or_update operation didn't fail, it's further handling of the received model using as_dict / from_dict that fails, which is not the same thing.

Do you agree?

[lmazuel]

So, this happens because from_string has three extractors by default, you can workaround the issue specifying the one you want to use:

In [12]: from msrest.serialization import attribute_key_extractor

In [14]: v = VirtualMachineExtension.from_dict(raw, key_extractors=[attribute_key_extractor])

In [15]: v.type
Out[15]: 'Microsoft.Compute/virtualMachines/extensions'

In [16]: v.virtual_machine_extension_type
Out[16]: 'CustomScriptExtension'

attribute_key_extractor is the opposite part of as_dict, making it more deterministic.

I'm still unsure what is the best way to fix the issue, since it's deep inside the deserialization logic and any changes could update many MANY packages (there is hundreds, if not thousands if you count all versions, of packages that uses this code).

[lmazuel]

Hi @jeking3 I got a fix in PR, where instead of raise in case of duplicate, I apply extractors in order and precedence is most important. It means that the only change of behavior is when this exception was raised (the rest doesn't change). I added a log still.

In [2]: from azure.mgmt.compute.models import *

In [3]: v = VirtualMachineExtension.from_dict(raw)
Ignoring extracted value 'Microsoft.Compute/virtualMachines/extensions' from <function last_rest_key_case_insensitive_extractor at 0x000002403109FB88> for key 'virtual_machine_extension_type' (duplicate extraction, follow extractors order)

Could you give it a shot? https://github.com/Azure/msrest-for-python/pull/204

Thanks,

[jeking3]

This fixes the issue I was seeing. Seems like a pretty major change to reorder the deserializer preferences?

[lmazuel]

It was not ordered before, we were trying all, and then, we were discarding None, and checking the remaining were all the same values. It's where your problem was, in this last scenario you get in a situation where when we check all the extracted values are consistent, they are not and we raised an exception. The new version will not raise an exception, but instead pick the first one in order and return (while logging a warning). I don't think this exception was bringing any values anyway, so people will see a change from an exception to a warning log, which I think it's fair.

[jeking3]

It fixed a test in the repository that was expecting an error, so I would agree with you.

[lmazuel]

Fixed part of msrest 0.6.14 https://pypi.org/project/msrest/0.6.14/

Could you confirm before I close the issue?

[lmazuel]

Re-opening, since I want manual confirmation and Github closed it

[lmazuel]

Closing the issue after a few days since I strongly believed this is fixed, feel free to create a new issue if necessary. Thanks!