gistfile1.txt

2025-01-13 17:29:02,884 - handlers.py[DEBUG]: start: modules-final/config-write_files_deferred: running config-write_files_deferred with frequency once-per-instance
2025-01-13 17:29:02,884 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_write_files_deferred - wb: [644] 25 bytes
2025-01-13 17:29:02,885 - helpers.py[DEBUG]: Running config-write_files_deferred using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_write_files_deferred'>)
2025-01-13 17:29:02,885 - cc_write_files_deferred.py[DEBUG]: Skipping module named write_files_deferred, no deferred file defined in configuration
2025-01-13 17:29:02,885 - handlers.py[DEBUG]: finish: modules-final/config-write_files_deferred: SUCCESS: config-write_files_deferred ran successfully
2025-01-13 17:29:02,885 - modules.py[DEBUG]: Running module reset_rmc (<module 'cloudinit.config.cc_reset_rmc' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_reset_rmc.py'>) with frequency once-per-instance
2025-01-13 17:29:02,885 - handlers.py[DEBUG]: start: modules-final/config-reset_rmc: running config-reset_rmc with frequency once-per-instance
2025-01-13 17:29:02,885 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_reset_rmc - wb: [644] 25 bytes
2025-01-13 17:29:02,885 - helpers.py[DEBUG]: Running config-reset_rmc using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_reset_rmc'>)
2025-01-13 17:29:02,886 - cc_reset_rmc.py[DEBUG]: module disabled, RSCT_PATH not present
2025-01-13 17:29:02,886 - handlers.py[DEBUG]: finish: modules-final/config-reset_rmc: SUCCESS: config-reset_rmc ran successfully
2025-01-13 17:29:02,886 - modules.py[DEBUG]: Running module scripts_vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_vendor.py'>) with frequency once-per-instance
2025-01-13 17:29:02,886 - handlers.py[DEBUG]: start: modules-final/config-scripts_vendor: running config-scripts_vendor with frequency once-per-instance
2025-01-13 17:29:02,886 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_scripts_vendor - wb: [644] 25 bytes
2025-01-13 17:29:02,886 - helpers.py[DEBUG]: Running config-scripts_vendor using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_scripts_vendor'>)
2025-01-13 17:29:02,886 - handlers.py[DEBUG]: finish: modules-final/config-scripts_vendor: SUCCESS: config-scripts_vendor ran successfully
2025-01-13 17:29:02,887 - modules.py[DEBUG]: Running module scripts_per_once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once
2025-01-13 17:29:02,887 - handlers.py[DEBUG]: start: modules-final/config-scripts_per_once: running config-scripts_per_once with frequency once
2025-01-13 17:29:02,887 - util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [644] 25 bytes
2025-01-13 17:29:02,887 - helpers.py[DEBUG]: Running config-scripts_per_once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>)
2025-01-13 17:29:02,887 - handlers.py[DEBUG]: finish: modules-final/config-scripts_per_once: SUCCESS: config-scripts_per_once ran successfully
2025-01-13 17:29:02,887 - modules.py[DEBUG]: Running module scripts_per_boot (<module 'cloudinit.config.cc_scripts_per_boot' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_per_boot.py'>) with frequency always
2025-01-13 17:29:02,887 - handlers.py[DEBUG]: start: modules-final/config-scripts_per_boot: running config-scripts_per_boot with frequency always
2025-01-13 17:29:02,887 - helpers.py[DEBUG]: Running config-scripts_per_boot using lock (<cloudinit.helpers.DummyLock object at 0x7fd852ada7d0>)
2025-01-13 17:29:02,888 - handlers.py[DEBUG]: finish: modules-final/config-scripts_per_boot: SUCCESS: config-scripts_per_boot ran successfully
2025-01-13 17:29:02,888 - modules.py[DEBUG]: Running module scripts_per_instance (<module 'cloudinit.config.cc_scripts_per_instance' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_per_instance.py'>) with frequency once-per-instance
2025-01-13 17:29:02,888 - handlers.py[DEBUG]: start: modules-final/config-scripts_per_instance: running config-scripts_per_instance with frequency once-per-instance
2025-01-13 17:29:02,888 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_scripts_per_instance - wb: [644] 24 bytes
2025-01-13 17:29:02,888 - helpers.py[DEBUG]: Running config-scripts_per_instance using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_scripts_per_instance'>)
2025-01-13 17:29:02,888 - handlers.py[DEBUG]: finish: modules-final/config-scripts_per_instance: SUCCESS: config-scripts_per_instance ran successfully
2025-01-13 17:29:02,888 - modules.py[DEBUG]: Running module scripts_user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance
2025-01-13 17:29:02,889 - handlers.py[DEBUG]: start: modules-final/config-scripts_user: running config-scripts_user with frequency once-per-instance
2025-01-13 17:29:02,889 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_scripts_user - wb: [644] 25 bytes
2025-01-13 17:29:02,889 - helpers.py[DEBUG]: Running config-scripts_user using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_scripts_user'>)
2025-01-13 17:29:02,889 - subp.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts/runcmd'] with allowed return codes [0] (shell=False, capture=False)
2025-01-13 17:29:37,269 - subp.py[DEBUG]: command ['/var/lib/cloud/instance/scripts/runcmd'] took 34.s to run
2025-01-13 17:29:37,269 - subp.py[DEBUG]: Unexpected error while running command.
Command: ['/var/lib/cloud/instance/scripts/runcmd']
Exit code: 1
Reason: -
Stdout: -
Stderr: -
2025-01-13 17:29:37,269 - cc_scripts_user.py[WARNING]: Failed to run module scripts_user (scripts in /var/lib/cloud/instance/scripts)
2025-01-13 17:29:37,269 - handlers.py[DEBUG]: finish: modules-final/config-scripts_user: FAIL: running config-scripts_user with frequency once-per-instance
2025-01-13 17:29:37,269 - util.py[WARNING]: Running module scripts_user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py'>) failed
2025-01-13 17:29:37,269 - util.py[DEBUG]: Running module scripts_user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py'>) failed
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/cloudinit/config/modules.py", line 286, in _run_modules
    ran, _r = cc.run(
  File "/usr/lib/python3/dist-packages/cloudinit/cloud.py", line 60, in run
    return self._runners.run(name, functor, args, freq, clear_on_fail)
  File "/usr/lib/python3/dist-packages/cloudinit/helpers.py", line 156, in run
    results = functor(**args)
  File "/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py", line 53, in handle
    subp.runparts(runparts_path)
  File "/usr/lib/python3/dist-packages/cloudinit/subp.py", line 393, in runparts
    raise RuntimeError(
RuntimeError: Runparts: 1 failures (runcmd) in 1 attempted commands
2025-01-13 17:29:37,271 - modules.py[DEBUG]: Running module ssh_authkey_fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequency once-per-instance
2025-01-13 17:29:37,271 - handlers.py[DEBUG]: start: modules-final/config-ssh_authkey_fingerprints: running config-ssh_authkey_fingerprints with frequency once-per-instance
2025-01-13 17:29:37,271 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_ssh_authkey_fingerprints - wb: [644] 25 bytes
2025-01-13 17:29:37,271 - helpers.py[DEBUG]: Running config-ssh_authkey_fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_ssh_authkey_fingerprints'>)
2025-01-13 17:29:37,272 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2025-01-13 17:29:37,272 - util.py[DEBUG]: Read 3239 bytes from /etc/ssh/sshd_config
2025-01-13 17:29:37,273 - util.py[DEBUG]: Reading from /home/ubuntu/.ssh/authorized_keys (quiet=False)
2025-01-13 17:29:37,273 - util.py[DEBUG]: Read 398 bytes from /home/ubuntu/.ssh/authorized_keys
2025-01-13 17:29:37,275 - handlers.py[DEBUG]: finish: modules-final/config-ssh_authkey_fingerprints: SUCCESS: config-ssh_authkey_fingerprints ran successfully
2025-01-13 17:29:37,275 - modules.py[DEBUG]: Running module keys_to_console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance
2025-01-13 17:29:37,275 - handlers.py[DEBUG]: start: modules-final/config-keys_to_console: running config-keys_to_console with frequency once-per-instance
2025-01-13 17:29:37,275 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_keys_to_console - wb: [644] 25 bytes
2025-01-13 17:29:37,276 - helpers.py[DEBUG]: Running config-keys_to_console using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_keys_to_console'>)
2025-01-13 17:29:37,276 - subp.py[DEBUG]: Running command ['/usr/lib/cloud-init/write-ssh-key-fingerprints', '', ''] with allowed return codes [0] (shell=False, capture=True)
2025-01-13 17:29:37,299 - handlers.py[DEBUG]: finish: modules-final/config-keys_to_console: SUCCESS: config-keys_to_console ran successfully
2025-01-13 17:29:37,299 - modules.py[DEBUG]: Running module install_hotplug (<module 'cloudinit.config.cc_install_hotplug' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_install_hotplug.py'>) with frequency once-per-instance
2025-01-13 17:29:37,300 - handlers.py[DEBUG]: start: modules-final/config-install_hotplug: running config-install_hotplug with frequency once-per-instance
2025-01-13 17:29:37,300 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_install_hotplug - wb: [644] 24 bytes
2025-01-13 17:29:37,300 - helpers.py[DEBUG]: Running config-install_hotplug using lock (<FileLock using file '/var/lib/cloud/instances/democluster-tucker-test-demo/sem/config_install_hotplug'>)
2025-01-13 17:29:37,300 - util.py[DEBUG]: Reading from /var/lib/cloud/hotplug.enabled (quiet=False)
2025-01-13 17:29:37,300 - util.py[DEBUG]: File not found: /var/lib/cloud/hotplug.enabled
2025-01-13 17:29:37,300 - stages.py[DEBUG]: Allowed events: {<EventScope.NETWORK: 'network'>: {<EventType.BOOT_NEW_INSTANCE: 'boot-new-instance'>}}
2025-01-13 17:29:37,300 - stages.py[DEBUG]: Event Denied: scopes=['network'] EventType=hotplug
2025-01-13 17:29:37,300 - cc_install_hotplug.py[DEBUG]: Skipping hotplug install, not enabled
2025-01-13 17:29:37,301 - handlers.py[DEBUG]: finish: modules-final/config-install_hotplug: SUCCESS: config-install_hotplug ran successfully
2025-01-13 17:29:37,301 - modules.py[DEBUG]: Running module final_message (<module 'cloudinit.config.cc_final_message' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_final_message.py'>) with frequency always
2025-01-13 17:29:37,301 - handlers.py[DEBUG]: start: modules-final/config-final_message: running config-final_message with frequency always
2025-01-13 17:29:37,301 - helpers.py[DEBUG]: Running config-final_message using lock (<cloudinit.helpers.DummyLock object at 0x7fd852adb580>)
2025-01-13 17:29:37,301 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2025-01-13 17:29:37,301 - util.py[DEBUG]: Read 13 bytes from /proc/uptime
2025-01-13 17:29:37,308 - util.py[DEBUG]: Cloud-init v. 24.1.3-0ubuntu1~22.04.1 finished at Mon, 13 Jan 2025 17:29:37 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net].  Up 58.20 seconds
2025-01-13 17:29:37,308 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 69 bytes
2025-01-13 17:29:37,308 - handlers.py[DEBUG]: finish: modules-final/config-final_message: SUCCESS: config-final_message ran successfully
2025-01-13 17:29:37,309 - main.py[DEBUG]: Ran 12 modules with 1 failures
2025-01-13 17:29:37,309 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp2s3odges) - w: [644] 1008 bytes/chars
2025-01-13 17:29:37,309 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmp1c9ckr7p) - w: [644] 192 bytes/chars
2025-01-13 17:29:37,309 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
2025-01-13 17:29:37,309 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2025-01-13 17:29:37,309 - util.py[DEBUG]: Read 13 bytes from /proc/uptime
2025-01-13 17:29:37,309 - util.py[DEBUG]: cloud-init mode 'modules' took 44.175 seconds (44.18)
2025-01-13 17:29:37,310 - handlers.py[DEBUG]: finish: modules-final: FAIL: running modules for final