cloud-config annotation throws exception, fix it

[holmanb]

Don't throw exceptions for empty cloud config

Warn during boot when an empty config is provided. Likewise,
`cloud-init devel schema --annotate` should not throw exception, return
something meaningful instead.

Additional Context

the following config:

root@me:~# cat test1.yml 
#cloud-config

causes the following exception:

root@me:~# cloud-init devel schema -c test1.yml --annotate
['']
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/cloudinit/config/schema.py", line 239, in validate_cloudconfig_file
    cloudconfig, schema, strict=True)
  File "/usr/lib/python3/dist-packages/cloudinit/config/schema.py", line 121, in validate_cloudconfig_schema
    raise SchemaValidationError(errors)
cloudinit.config.schema.SchemaValidationError: Cloud config schema errors: : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object', : None is not of type 'object'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/cloud-init", line 11, in <module>
    load_entry_point('cloud-init==21.4', 'console_scripts', 'cloud-init')()
  File "/usr/lib/python3/dist-packages/cloudinit/cmd/main.py", line 929, in main
    get_uptime=True, func=functor, args=(name, args))
  File "/usr/lib/python3/dist-packages/cloudinit/util.py", line 2475, in log_time
    ret = func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/cloudinit/config/schema.py", line 470, in handle_schema_args
    args.config_file, full_schema, args.annotate)
  File "/usr/lib/python3/dist-packages/cloudinit/config/schema.py", line 243, in validate_cloudconfig_file
    cloudconfig, content, e.schema_errors))
  File "/usr/lib/python3/dist-packages/cloudinit/config/schema.py", line 159, in annotated_cloudconfig_file
    errors_by_line[schemapaths[path]].append(msg)
KeyError: ''

Test Configs

empty-body.yml:

#cloud-config

invalid-not-empty-config.yml:

#cloud-config
test:
        - arg
                test:
                        #

whilespace-config-has-tabs-spaces.yml:

#cloud-config



        
      

observe new error message:

root@me:~# cloud-init devel schema -c test3.yml --annotate
# Errors: -------------
Empty cloud-config

check that annotation still works for invalid-not-empty-config.yml

Checklist:

• My code follows the process laid out in the documentation
• I have updated or added any unit tests accordingly
• I have updated or added any documentation accordingly

[blackboxsw]

While this "fixes" cloud-init schema, this is invalid cloud-config and our fix should probably also either Warn or hard-error noting Invalid #cloud-config in userdata instead of a confusing traceback.

Providing an empty (non-dict) YAML such as #cloud-config\n results in a Traceback anyway on the booted system

csmith@uptown:~$ cat > invalid_cloudconfig.yaml <<EOF
#cloud-config
EOF
csmith@uptown:~$ lxc launch ubuntu-daily:bionic -c user.user-data="$( cat 3.yaml)"
Creating the instance
Instance name is: firm-starfish
Starting firm-starfish
 csmith@uptown:~$ lxc exec firm-starfish cat /var/log/cloud-init.log | grep -B 5 -A 10 Traceback
2021-12-03 22:11:12,644 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance
2021-12-03 22:11:12,644 - util.py[DEBUG]: Attempting to load yaml from string of length 14 with allowed root types (<class 'dict'>,)
2021-12-03 22:11:12,644 - util.py[DEBUG]: loaded blob returned None, returning default.
2021-12-03 22:11:12,644 - util.py[WARNING]: Failed at merging in cloud config part from part-001
2021-12-03 22:11:12,644 - util.py[DEBUG]: Failed at merging in cloud config part from part-001
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/cloudinit/handlers/cloud_config.py", line 140, in handle_part
    self._merge_part(payload, headers)
  File "/usr/lib/python3/dist-packages/cloudinit/handlers/cloud_config.py", line 116, in _merge_part
    (payload_yaml, my_mergers) = self._extract_mergers(payload, headers)
  File "/usr/lib/python3/dist-packages/cloudinit/handlers/cloud_config.py", line 95, in _extract_mergers
    mergers_yaml = mergers.dict_extract_mergers(payload_yaml)
  File "/usr/lib/python3/dist-packages/cloudinit/mergers/__init__.py", line 79, in dict_extract_mergers
    raw_mergers = config.pop('merge_how', None)
AttributeError: 'NoneType' object has no attribute 'pop'
2021-12-03 22:11:12,645 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance

[holmanb]

Latest update to this PR checks for empty payload and prints something useful:

root@me:~# grep -B2 WARN  /var/log/cloud-init.log 
2021-12-07 14:52:33,473 - util.py[DEBUG]: Attempting to load yaml from string of length 14 with allowed root types (<class 'dict'>,)
2021-12-07 14:52:33,473 - util.py[DEBUG]: loaded blob returned None, returning default.
2021-12-07 14:52:33,473 - cloud_config.py[WARNING]: Failed at merging in cloud config part from file part-001: Empty cloud config
--
2021-12-07 14:52:33,475 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance
2021-12-07 14:52:33,475 - util.py[DEBUG]: Attempting to load yaml from string of length 18 with allowed root types (<class 'dict'>,)
2021-12-07 14:52:33,475 - cloud_config.py[WARNING]: Failed at merging in cloud config part from file part-001: Empty cloud config

Apparently this code path is executed twice during startup, so we get twice the warning. I'm not familiar enough with merging to know why this is run twice, but at least now it is does something arguably more "useful".

[github-actions]

Hello! Thank you for this proposed change to cloud-init. This pull request is now marked as stale as it has not seen any activity in 14 days. If no activity occurs within the next 7 days, this pull request will automatically close.

If you are waiting for code review and you are seeing this message, apologies! Please reply, tagging mitechie, and he will ensure that someone takes a look soon.

(If the pull request is closed and you would like to continue working on it, please do tag mitechie to reopen it.)

[holmanb]

@blackboxsw - I finally got back around to this. The latest iteration drops the following log when an empty cloud config is provided. Assuming tests pass I think this is ready for review.

2022-01-04 18:21:56,381 - cloud_config.py[WARNING]: Failed at merging in empty cloud config

[blackboxsw]

Thanks for the update @holmanb. I'd like to see handle more cases in annotate than just representing "empty" user-data
There is at least one case that still fails.

touch should-error-about-missing-header.yaml
python3 -m cloudinit.cmd.main devel schema -c should-error-about-missing-header.yaml --annotate
# Errors: -------------
Empty cloud-config

An empty user-data file should instead report that it doesn't have a #cloud-config header line.

I also think we could use one or two unittests for this: I've added one in my consolidated diff below if you agree with the suggestions I made inline:

diff --git a/cloudinit/config/schema.py b/cloudinit/config/schema.py
index befad76ca..85cad3bb6 100644
--- a/cloudinit/config/schema.py
+++ b/cloudinit/config/schema.py
@@ -217,21 +217,21 @@ def annotated_cloudconfig_file(cloudconfig, original_content, schema_errors):
     if not schema_errors:
         return original_content
     schemapaths = {}
-    if cloudconfig:
-        schemapaths = _schemapath_for_cloudconfig(
-            cloudconfig, original_content
-        )
     errors_by_line = defaultdict(list)
     error_footer = []
     error_header = "# Errors: -------------\n{0}\n\n"
     annotated_content = []
     lines = original_content.decode().split("\n")
-    cloud_config_body = lines[1:]
-
-    # Return a meaningful message on empty cloud-config
-    if not [line for line in cloud_config_body if line.strip()]:
-        return error_header.format("Empty cloud-config")
-
+    if not isinstance(cloudconfig, dict):
+        # Return a meaningful message on empty cloud-config
+        return "\n".join(
+            lines
+            + [error_header.format("# E1: Cloud-config is not a YAML dict.")]
+        )
+    if cloudconfig:
+        schemapaths = _schemapath_for_cloudconfig(
+            cloudconfig, original_content
+        )
     for path, msg in schema_errors:
         match = re.match(r"format-l(?P<line>\d+)\.c(?P<col>\d+).*", path)
         if match:
diff --git a/cloudinit/handlers/cloud_config.py b/cloudinit/handlers/cloud_config.py
index c6b2c3afb..8070c6cb2 100644
--- a/cloudinit/handlers/cloud_config.py
+++ b/cloudinit/handlers/cloud_config.py
@@ -143,7 +143,11 @@ class CloudConfigPartHandler(handlers.Handler):
                 filename = filename.replace(i, " ")
             self.file_names.append(filename.strip())
         except ValueError as err:
-            LOG.warning("Failed at merging in %s", err)
+            LOG.warning(
+                "Failed at merging in cloud config part from %s: %s",
+                filename,
+                err,
+            )
         except Exception:
             util.logexc(
                 LOG, "Failed at merging in cloud config part from %s", filename
diff --git a/tests/unittests/config/test_schema.py b/tests/unittests/config/test_schema.py
index fb5b891d7..416cc46d5 100644
--- a/tests/unittests/config/test_schema.py
+++ b/tests/unittests/config/test_schema.py
@@ -546,6 +546,31 @@ class AnnotatedCloudconfigFileTest(CiTestCase):
             content, annotated_cloudconfig_file({}, content, schema_errors=[])
         )
 
+    def test_annotated_cloudconfig_file_with_non_dict_cloud_config(self):
+        """Error when empty non-dict cloud-config is provided.
+
+        OurJSON validation when user-data is None type generates a bunch
+        schema validation errors of the format:
+        ('', "None is not of type 'object'"). Ignore those symptoms and
+        report the general problem instead.
+        """
+        content = b"\n\n\n"
+        expected = "\n".join(
+            [
+                content.decode(),
+                "# Errors: -------------",
+                "# E1: Cloud-config is not a YAML dict.\n\n",
+            ]
+        )
+        self.assertEqual(
+            expected,
+            annotated_cloudconfig_file(
+                None,
+                content,
+                schema_errors=[("", "None is not of type 'object'")],
+            ),
+        )
+
     def test_annotated_cloudconfig_file_schema_annotates_and_adds_footer(self):
         """With schema_errors, error lines are annotated and a footer added."""
         content = dedent(

[holmanb]

Thanks @blackboxsw. I agree with all of your suggestions. This better handles the root cause over dealing with symptoms. I have applied your suggested changes. I can add further tests if you think it is warranted, but I haven't thought up other cases worth adding.

[holmanb]

@blackboxsw when you get a chance I think this is ready. I made the changes mentioned yesterday in IRC and also added a test verifying an error message is produced with the incorrect flag combo.

[blackboxsw]

@holmanb This LGTM! Thanks ofr all the related fixes in here.
Let's get this out into Jammy.