Open ubuntu-server-builder opened 1 year ago
Launchpad user Haitao Chen(haidaocht) wrote on 2021-06-05T08:01:29.862826+00:00
Launchpad attachments: cloud-init.log
Launchpad user Haitao Chen(haidaocht) wrote on 2021-06-05T16:38:28.975527+00:00
/cloudinit/analyze/show.py
if event_type(event) == 'start':
if event.get('name') in stages_seen:
if a event name is repeated (start and finish multiple times).
and it's not finished right away(child event will break this condition), finish the event right away won't push the event to stages_seen.
then its considered as new boot record.
Launchpad user Chad Smith(chad.smith) wrote on 2021-06-06T20:19:50.169359+00:00
Haitao Chen (haidaocht), thank you for the bug and contributing to cloud-init to make it better. Do you happen to have a system available to attach the sudo cloud-init analyze show
output as well?
Much thanks.
Launchpad user Chad Smith(chad.smith) wrote on 2021-06-06T20:37:10.495500+00:00
Nevermind, just grabbed it on a Xenial instance I had available: This does feel like a general bug that needs to be better handled by analyze show output for certain event types on Azure.
-- Boot Record 01 -- The total time elapsed since completing an event is printed after the "@" character. The time the event takes is printed after the "+" character.
Starting stage: init-local
|->no cache found @00.00400s +00.00100s Starting stage: init-local/search-Azure Starting stage: azure-ds/_get_data |
->found azure asset tag @00.03100s +00.00100s
|->get_boot_telemetry @00.03200s +00.01200s |
->get_system_info @00.04500s +00.00000s
Starting stage: azure-ds/crawl_metadata
|->list_possible_azure_ds_devs @00.04500s +00.33100s |
->load_azure_ds_dir @00.37700s +00.00000s
Starting stage: azure-ds/load_azure_ds_dir
Starting stage: azure-ds/read_azure_ovf
|->load_azure_ovf_pubkeys @00.38300s +00.00000s Starting stage: azure-ds/_get_preprovisioning_cfgs |
->_get_preprovisionedvm_cfg_value @00.38300s +00.00100s
|`->_get_preprovisionedvmtype_cfg_value @00.38400s +00.00000s
Finished stage: (azure-ds/_get_preprovisioning_cfgs) 00.00100 seconds
Finished stage: (azure-ds/read_azure_ovf) 00.00600 seconds
Finished stage: (azure-ds/load_azure_ds_dir) 00.00700 seconds
Starting stage: azure-ds/get_imds_data_with_api_fallback
Starting stage: azure-ds/get_metadata_from_imds
|->obtain dhcp lease @00.39400s +00.08700s |
->_get_metadata_from_imds @00.48200s +00.01400s
Finished stage: (azure-ds/get_metadata_from_imds) 00.12800 seconds
Finished stage: (azure-ds/get_imds_data_with_api_fallback) 00.12900 seconds
|`->_get_random_seed @00.52200s +00.00000s Finished stage: (azure-ds/crawl_metadata) 00.47700 seconds
|`->write_files @00.52300s +00.00300s Finished stage: (azure-ds/_get_data) 00.49500 seconds
|`->get_public_ssh_keys @00.52700s +00.00000s Finished stage: (init-local/search-Azure) 00.50200 seconds
Starting stage: azure-ds/parse_network_config |`->_generate_network_config_from_fallback_config @00.59400s +00.00600s Finished stage: (azure-ds/parse_network_config) 00.00600 seconds
Finished stage: (init-local) 00.61900 seconds
Starting stage: init-network |`->restored from cache with run check: DataSourceAzure [seed=/var/lib/waagent] @01.56200s +00.02200s Total Time: 2.37000 seconds
-- Boot Record 02 -- The total time elapsed since completing an event is printed after the "@" character. The time the event takes is printed after the "+" character.
Starting stage: azure-ds/parse_network_config |`->_generate_network_config_from_fallback_config @00.00000s +00.00500s Finished stage: (azure-ds/parse_network_config) 00.00500 seconds
Starting stage: init-network/setup-datasource Starting stage: azure-ds/setup Starting stage: azure-ds/_negotiate Starting stage: azure-ds/bounce_network_with_azure_hostname |`->temporary_hostname @00.01500s +00.00100s Finished stage: (azure-ds/bounce_network_with_azure_hostname) 00.00300 seconds
Starting stage: azure-ds/get_metadata_from_fabric
Starting stage: azure-ds/register_with_azure_and_fetch_data
|->generate_certificate @00.01900s +01.48600s Starting stage: azure-ds/_fetch_goal_state_from_azure Starting stage: azure-ds/_get_raw_goal_state_xml_from_azure Starting stage: azure-ds/find_endpoint |
->_networkd_get_value_from_leases @01.50500s +00.00100s
|->_load_dhclient_json @01.50600s +00.03100s |
->_get_value_from_dhcpoptions @01.53700s +00.00000s
Finished stage: (azure-ds/find_endpoint) 00.03200 seconds
Starting stage: azure-ds/goalstate-retrieval |`->http_with_retries @01.53800s +00.00800s Finished stage: (azure-ds/goalstate-retrieval) 00.00800 seconds
Finished stage: (azure-ds/_get_raw_goal_state_xml_from_azure) 00.04100 seconds
Starting stage: azure-ds/_parse_raw_goal_state_xml Starting stage: azure-ds/get-certificates-xml |`->http_with_retries @01.54700s +00.01400s Finished stage: (azure-ds/get-certificates-xml) 00.01400 seconds
Finished stage: (azure-ds/_parse_raw_goal_state_xml) 00.01500 seconds
Finished stage: (azure-ds/_fetch_goal_state_from_azure) 00.05700 seconds
Starting stage: azure-ds/_get_user_pubkeys
Starting stage: azure-ds/parse_certificates
|->_decrypt_certs_from_xml @01.56200s +00.02800s Starting stage: azure-ds/_get_ssh_key_from_cert |
->_run_x509_action @01.59100s +00.02000s
Finished stage: (azure-ds/_get_ssh_key_from_cert) 00.04100 seconds
Starting stage: azure-ds/_get_fingerprint_from_cert |`->_run_x509_action @01.63100s +00.02100s Finished stage: (azure-ds/_get_fingerprint_from_cert) 00.02200 seconds
Finished stage: (azure-ds/parse_certificates) 00.09100 seconds
Finished stage: (azure-ds/_get_user_pubkeys) 00.09100 seconds
Starting stage: azure-ds/send_ready_signal Starting stage: azure-ds/_post_health_report Starting stage: azure-ds/push_log_to_kvp |`->get_last_log_byte_pushed_to_kvp_index @01.65400s +00.00000s Finished stage: (azure-ds/push_log_to_kvp) 00.01200 seconds
|`->http_with_retries @01.66700s +00.00700s Finished stage: (azure-ds/_post_health_report) 00.02000 seconds
Finished stage: (azure-ds/send_ready_signal) 00.02100 seconds
Finished stage: (azure-ds/register_with_azure_and_fetch_data) 01.65500 seconds
Finished stage: (azure-ds/get_metadata_from_fabric) 01.65600 seconds
Finished stage: (azure-ds/_negotiate) 01.66000 seconds
Finished stage: (azure-ds/setup) 01.66100 seconds
Finished stage: (init-network/setup-datasource) 01.66100 seconds
|->reading and applying user-data @01.68400s +00.00300s |
->reading and applying vendor-data @01.68700s +00.00100s
|->reading and applying vendor-data2 @01.68800s +00.00000s Starting stage: init-network/activate-datasource Starting stage: azure-ds/activate Starting stage: azure-ds/address_ephemeral_resize Starting stage: azure-ds/can_dev_be_reformatted |
->_has_ntfs_filesystem @01.71900s +00.18200s
Finished stage: (azure-ds/can_dev_be_reformatted) 00.18300 seconds
Finished stage: (azure-ds/address_ephemeral_resize) 00.18300 seconds
Total Time: 9.13200 seconds
-- Boot Record 03 -- The total time elapsed since completing an event is printed after the "@" character. The time the event takes is printed after the "+" character.
Starting stage: azure-ds/push_log_to_kvp |`->get_last_log_byte_pushed_to_kvp_index @00.00000s +00.00100s Finished stage: (azure-ds/push_log_to_kvp) 00.01200 seconds
Finished stage: (azure-ds/activate) 00.19500 seconds
Finished stage: (init-network/activate-datasource) 00.19900 seconds
|->config-migrator ran successfully @00.03300s +00.00100s |
->config-seed_random ran successfully @00.03400s +00.00200s
|->config-bootcmd ran successfully @00.03600s +00.00100s |
->config-write-files ran successfully @00.03700s +00.00100s
|->config-growpart ran successfully @00.03900s +00.03900s |
->config-resizefs ran successfully @00.07900s +00.00500s
|->config-disk_setup ran successfully @00.08500s +00.08500s |
->config-mounts ran successfully @00.17100s +00.09400s
|->config-set_hostname ran successfully @00.26600s +00.00200s |
->config-update_hostname ran successfully @00.26900s +00.00200s
|->config-update_etc_hosts ran successfully @00.27200s +00.00000s |
->config-ca-certs ran successfully @00.27200s +00.00200s
|->config-rsyslog ran successfully @00.27400s +00.00100s Starting stage: init-network/config-users-groups |
->get_public_ssh_keys @00.27700s +00.00000s
Finished stage: (init-network/config-users-groups) 00.04700 seconds
Starting stage: init-network/config-ssh |`->get_public_ssh_keys @01.00100s +00.00000s Finished stage: (init-network/config-ssh) 00.68300 seconds
Finished stage: (init-network) 02.99900 seconds
Starting stage: modules-config
|->config-emit_upstart ran successfully @04.61400s +00.00000s |
->config-snap ran successfully @04.61400s +00.00200s
|->config-ssh-import-id ran successfully @04.61600s +00.00200s |
->config-locale ran successfully @04.61800s +00.00200s
|->config-set-passwords ran successfully @04.62000s +00.00200s |
->config-grub-dpkg ran successfully @04.62200s +00.24200s
|->config-apt-pipelining ran successfully @04.86500s +00.00200s |
->config-apt-configure ran successfully @04.86700s +00.10600s
|->config-ubuntu-advantage ran successfully @04.97400s +00.00100s |
->config-ntp ran successfully @04.97500s +00.00100s
|->config-timezone ran successfully @04.97700s +00.00100s |
->config-disable-ec2-metadata ran successfully @04.97800s +00.00100s
|->config-runcmd ran successfully @04.97900s +00.00100s |
->config-byobu ran successfully @04.98000s +00.00200s
Finished stage: (modules-config) 00.38500 seconds
Starting stage: modules-final
|->config-package-update-upgrade-install ran successfully @05.47500s +00.00100s |
->config-fan ran successfully @05.47700s +00.00100s
|->config-landscape ran successfully @05.47800s +00.00100s |
->config-lxd ran successfully @05.48000s +00.00100s
|->config-ubuntu-drivers ran successfully @05.48100s +00.00200s |
->config-puppet ran successfully @05.48300s +00.00100s
|->config-chef ran successfully @05.48400s +00.00000s |
->config-mcollective ran successfully @05.48500s +00.00100s
|->config-salt-minion ran successfully @05.48700s +00.00100s |
->config-reset_rmc ran successfully @05.48800s +00.00100s
|->config-refresh_rmc_and_interface ran successfully @05.48900s +00.00100s |
->config-rightscale_userdata ran successfully @05.49000s +00.00100s
|->config-scripts-vendor ran successfully @05.49200s +00.00100s |
->config-scripts-per-once ran successfully @05.49300s +00.00100s
|->config-scripts-per-boot ran successfully @05.49500s +00.00000s |
->config-scripts-per-instance ran successfully @05.49500s +00.00200s
|->config-scripts-user ran successfully @05.49700s +00.00100s |
->config-ssh-authkey-fingerprints ran successfully @05.49800s +00.07400s
|->config-keys-to-console ran successfully @05.57300s +00.14500s |
->config-phone-home ran successfully @05.71900s +00.00200s
|->config-final-message ran successfully @05.72200s +00.00500s |
->config-power-state-change ran successfully @05.72700s +00.00100s
Finished stage: (modules-final) 00.27300 seconds
Total Time: 4.79300 seconds
3 boot records analyzed
This bug was originally filed in Launchpad as LP: #1930956
Launchpad details
Launchpad user Haitao Chen(haidaocht) wrote on 2021-06-05T08:01:29.862826+00:00
cloud-init analyze show return me multiple boot records, while I just have 1.