Bug 2105961

Summary: edge-installer (anaconda) fails if user has ssh-key defined
Product: Red Hat Enterprise Linux 9 Reporter: Rafal Szmigiel <rszmigie>
Component: osbuild-composerAssignee: Image Builder team <osbuilders>
Status: CLOSED ERRATA QA Contact: Xiaofeng Wang <xiaofwan>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 9.0CC: mcattamo, obudai, qzhang, xiaofwan, yih
Target Milestone: rcKeywords: Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: osbuild-composer-57-1.el9 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2022-11-15 09:50:32 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Rafal Szmigiel 2022-07-11 10:56:36 UTC 
Description of problem:
Having this blueprint to build edge-container and edge-installer images:

name = "rafal-test-sshkey"
description = ""
version = "0.0.1"
packages = []
modules = []
groups = []
distro = ""

[customizations]

[[customizations.user]]
name = "xxxxxxxx"
description = "First Last"
password = "********"
groups = ["wheel"]
key = "ssh-rsa ******** root@image-builder"


I cannot perform edge-installer installation as Anaconda fails to add ssh-key to non-existing user which is supposed to be just created:


10:38:18,401 INF core.configuration.product: Loading information about products from /etc/anaconda/product.d.
10:38:18,408 INF core.configuration.product: Found Red Hat Enterprise Linux at /etc/anaconda/product.d/rhel.conf.
10:38:18,409 INF core.configuration.product: Found Fedora-ELN at /etc/anaconda/product.d/fedora-eln.conf.
10:38:18,409 INF core.configuration.product: Found Fedora Workstation at /etc/anaconda/product.d/fedora-workstation.conf.
10:38:18,410 INF core.configuration.product: Found Fedora Server at /etc/anaconda/product.d/fedora-server.conf.
10:38:18,410 INF core.configuration.product: Found oVirt Node Next at /etc/anaconda/product.d/ovirt.conf.
10:38:18,411 INF core.configuration.product: Found Scientific Linux at /etc/anaconda/product.d/scientific-linux.conf.
10:38:18,412 INF core.configuration.product: Found Fedora-IoT IoT at /etc/anaconda/product.d/fedora-iot.conf.
10:38:18,413 INF core.configuration.product: Found RHVH at /etc/anaconda/product.d/rhvh.conf.
10:38:18,414 INF core.configuration.product: Found Fedora at /etc/anaconda/product.d/fedora.conf.
10:38:18,415 INF core.configuration.product: Found CentOS Stream at /etc/anaconda/product.d/centos-stream.conf.
10:38:18,416 INF core.configuration.product: Found Fedora Workstation Live at /etc/anaconda/product.d/fedora-workstation-live.conf.
10:38:18,417 INF core.configuration.product: Found Rocky at /etc/anaconda/product.d/rocky.conf.
10:38:18,418 INF core.configuration.product: Found CentOS Linux at /etc/anaconda/product.d/centos.conf.
10:38:18,418 INF core.configuration.product: Found Fedora Silverblue at /etc/anaconda/product.d/fedora-silverblue.conf.
10:38:18,420 INF core.configuration.product: Found AlmaLinux at /etc/anaconda/product.d/almalinux.conf.
10:38:18,420 WRN core.configuration.product: No support for the product Red Hat Enterprise Linux edge.
10:38:18,420 INF core.configuration.product: The product Red Hat Enterprise Linux is supported.
10:38:18,428 WRN misc: /usr/lib64/python3.9/site-packages/pyanaconda/core/configuration/anaconda.py:74: DeprecationWarning: The kickstart_modules configuration option is deprecated and will be removed in in the future.
  warnings.warn(

10:38:18,430 INF main: /sbin/anaconda 34.25.0.29-1.el9_0
10:38:18,449 INF core.util: Reporting the IPMI event: 7
10:38:20,496 INF isys: 1982052 kB (1935 MB) are available
10:38:20,509 WRN misc: /usr/lib64/python3.9/subprocess.py:941: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)

10:38:20,534 INF startup_utils: check_memory(): total:1935, needed:320, graphical:410
10:38:20,535 DBG startup_utils: Don't set up proxy variables.
10:38:20,548 INF main: anaconda called with cmdline = ['/sbin/anaconda']
10:38:20,548 INF main: Default encoding = utf-8
10:38:20,548 INF misc: Writing a temporary configuration loaded from: ['/etc/anaconda/anaconda.conf', '/etc/anaconda/product.d/rhel.conf', '/etc/anaconda/conf.d/00-do-nothing.conf', '/etc/anaconda/conf.d/01-still-do-nothing.conf', '/etc/anaconda/conf.d/90-osbuild.conf']
10:38:20,592 INF core.dbus: Connecting to the Anaconda bus at unix:abstract=/tmp/dbus-YiXqJ5Istk,guid=c0e95abcf1341a7984fbded862cbfd9c.
10:38:27,106 INF main: Found a kickstart file: /run/install/ks.cfg
10:38:27,224 INF startup_utils: Parsing kickstart: /run/install/ks.cfg
10:38:27,538 WRN kickstart: Command ostreesetup will be parsed in DBus module.
10:38:27,539 WRN kickstart: Command user will be parsed in DBus module.
10:38:27,540 WRN kickstart: Command sshkey will be parsed in DBus module.
10:38:27,540 DBG pwpolicy: Using the password policy from the configuration.
10:38:27,574 DBG localization: setting locale to: en_US.UTF-8
10:38:27,590 DBG network: Initialization started.
10:38:27,599 DBG network: Devices found: ['enp1s0']
10:38:27,605 DBG network: Running task Apply kickstart
10:38:28,613 DBG network: Apply kickstart result: []
10:38:28,636 DBG network: Running task Dump missing config files
10:38:29,649 DBG network: Dump missing config files result: ['enp1s0']
10:38:29,651 DBG network: Creating network configurations.
10:38:29,659 DBG network: Initialization finished.
10:38:29,660 INF threading: Running Thread: AnaWaitForConnectingNMThread (139768713819712)
10:38:29,660 DBG anaconda: setting display mode to GUI
10:38:29,664 WRN stdout: Not asking for VNC because we don't have a network
10:38:29,665 INF anaconda: Display mode is set to 'interactive graphical mode'.
10:38:29,666 INF isys: 1982052 kB (1935 MB) are available
10:38:29,668 WRN misc: /usr/lib64/python3.9/subprocess.py:941: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)

10:38:29,681 INF threading: Thread Done: AnaWaitForConnectingNMThread (139768713819712)
10:38:29,687 INF startup_utils: check_memory(): total:1935, needed:320, graphical:410
10:38:29,687 DBG core.util: Setting timeout 60 seconds for starting X.
10:38:32,785 DBG core.util: X server has signalled a successful start.
10:38:32,990 INF display: Started spice-vdagent.
10:38:34,070 DBG ui.lib.addons: Loading spokes into module path for addon com_redhat_kdump
10:38:34,070 DBG ui.lib.addons: Loading spokes into module path for addon org_fedora_oscap
10:38:34,373 DBG core.storage: LABEL=OEMDRV matches [] for devicetree=None and disks_only=True
10:38:34,389 INF threading: Running Thread: AnaStorageThread (139768713819712)
10:38:34,440 DBG payload.manager: Restarting payload thread
10:38:34,444 INF threading: Running Thread: AnaPayloadRestartThread (139768329827904)
10:38:34,445 INF geoloc: Geolocation is disabled due to automated kickstart based installation.
10:38:34,448 DBG startup_utils: Skip the time synchronization due to disabled module.
10:38:34,456 INF threading: Running Thread: AnaPayloadThread (139768321435200)
10:38:34,456 INF threading: Thread Done: AnaPayloadRestartThread (139768329827904)
10:38:34,461 DBG payload.manager: Updating payload thread state: STARTED
10:38:34,462 DBG payload.manager: Updating payload thread state: WAITING_STORAGE
10:38:34,540 WRN misc: /usr/lib64/python3.9/site-packages/pyanaconda/core/util.py:1218: DeprecationWarning: the imp module is deprecated in favour of importlib; see the module's documentation for alternative uses
  import imp

10:38:36,523 DBG ui.gui: Detected primary monitor: 1024x768 100dpix 100dpiy
10:38:36,822 DBG ui.gui.spokes.network: network standalone spoke (init): completed: True
10:38:36,873 INF lifecycle: Adding controller: SummaryHub
10:38:36,967 INF threading: Running Thread: AnaStorageWatcher (139768216413760)
10:38:36,968 DBG ui.gui.hubs: incomplete spokes: [StorageSpoke]
10:38:36,993 INF lifecycle: Module initialized: CustomPartitioningSpoke
10:38:37,022 INF lifecycle: Module initialized: FilterSpoke
10:38:37,034 WRN misc: /usr/share/anaconda/addons/com_redhat_kdump/gui/spokes/kdump.py:92: PyGTKDeprecationWarning: Using positional arguments with the GObject constructor has been deprecated. Please specify keyword(s) for "value, lower, upper, step_increment, page_increment, page_size" or use a class specific constructor. See: https://wiki.gnome.org/PyGObject/InitializerDeprecations
  adjustment = Gtk.Adjustment(lower, lower, upper, step, step, 0)

10:38:37,067 DBG ui.gui.spokes.network: adding device configuration: NetworkDeviceConfiguration(connection_uuid='072cc6bf-f0ce-4731-9167-498a5fa9df7b', device_name='enp1s0', device_type=1)
10:38:37,071 INF lifecycle: Module initialized: NetworkSpoke
10:38:37,091 INF misc: OSCAP Addon: Defaulting to local content
10:38:37,096 INF threading: Running Thread: OSCAPguiWaitForDataFetchThread (139768224806464)
10:38:37,102 INF misc: OSCAP Addon: started to look at the content
10:38:37,103 WRN misc: /usr/lib64/python3.9/subprocess.py:941: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)

10:38:37,113 INF lifecycle: Module initialized: PasswordSpoke
10:38:37,203 INF lifecycle: Module initialized: UserSpoke
10:38:37,225 INF lifecycle: Initialization of all modules (6) has been started.
10:38:37,230 DBG ui.gui.hubs: Starting event loop for hub SummaryHub
10:38:37,307 DBG ui.common: Entered hub: SummaryHub
10:38:37,308 INF threading: Thread Done: AnaStorageThread (139768713819712)
10:38:37,319 WRN misc: /usr/lib/python3.9/site-packages/gi/overrides/Gdk.py:329: DeprecationWarning: Gdk.Cursor.new is deprecated
  return cls.new(*args, **kwds)

10:38:37,331 DBG ui.lib.storage: Selecting all disks by default: vda,vdb
10:38:37,331 INF lifecycle: Module initialized: StorageSpoke
10:38:37,331 INF lifecycle: All modules have been initialized.
10:38:37,331 DBG misc: OSCAP addon: Anaconda init_done signal triggered
10:38:37,332 INF threading: Thread Done: AnaStorageWatcher (139768216413760)
10:38:37,332 DBG payload.manager: Updating payload thread state: WAITING_NETWORK
10:38:37,340 DBG ui.gui.hubs: setting StorageSpoke status to: Probing storage...
10:38:37,341 DBG ui.gui.hubs: setting OSCAPSpoke status to: Fetching content data
10:38:37,347 DBG ui.gui.hubs: spoke is not ready: OSCAPSpoke
10:38:37,357 DBG ui.gui.hubs: spoke is ready: PasswordSpoke
10:38:37,359 DBG ui.gui.hubs: kickstart installation, spoke Root Password is ready
10:38:37,361 DBG ui.gui.hubs: setting StorageSpoke status to: Probing storage...
10:38:37,372 DBG ui.gui.hubs: spoke is ready: StorageSpoke
10:38:37,374 INF ui.gui.helpers: kickstart installation stopped for info: User interaction required on spoke Installation Destination
10:38:37,483 DBG ui.gui.hubs: spoke is not ready: KdumpSpoke
10:38:37,490 DBG ui.gui.hubs: spoke is ready: KdumpSpoke
10:38:37,490 DBG ui.gui.hubs: kickstart installation, spoke KDUMP is ready
10:38:38,348 DBG payload.manager: Updating payload thread state: FINISHED
10:38:38,348 INF threading: Thread Done: AnaPayloadThread (139768321435200)
10:38:38,411 INF misc: OSCAP addon: Identified /usr/share/xml/scap/ssg/content//ssg-rhel9-ds.xml as Source Data Stream
10:38:38,412 INF misc: OSCAP Addon: finished looking at the content
10:38:38,412 INF misc: OSCAP Addon: Opening SCAP content at /usr/share/xml/scap/ssg/content/ssg-rhel9-ds.xml without considering tailoring
10:38:38,980 INF misc: OSCAP Addon: Done with analysis
10:38:38,983 INF threading: Thread Done: OSCAPguiWaitForDataFetchThread (139768224806464)
10:38:38,987 DBG ui.gui.hubs: spoke is ready: OSCAPSpoke
10:38:38,987 DBG ui.gui.hubs: kickstart installation, spoke Security Profile is ready
10:38:38,987 DBG ui.gui.hubs: setting OSCAPSpoke status to: No profile selected
10:38:38,988 DBG ui.gui.hubs: spoke is ready: OSCAPSpoke
10:38:38,988 DBG ui.gui.hubs: kickstart installation, spoke Security Profile is ready
10:38:38,988 DBG ui.gui.hubs: setting OSCAPSpoke status to: No profile selected
10:38:38,989 DBG ui.gui.hubs: spoke is ready: OSCAPSpoke
10:38:38,989 DBG ui.gui.hubs: kickstart installation, spoke Security Profile is ready
10:38:38,990 DBG ui.gui.hubs: setting OSCAPSpoke status to: No profile selected
10:38:39,942 DBG ui.common: Entered spoke: StorageSpoke
10:38:44,114 INF core.storage: Detected 1.89 GiB of memory
10:38:44,115 INF core.storage: Swap attempt of 3.78 GiB
10:38:44,115 DBG ui.gui.spokes.storage: disk free: 20 GiB  fs free: 0 B  sw needs: 476.84 MiB  auto swap: 3.78 GiB
10:38:44,130 DBG ui.gui.spokes.storage: Running the execute method for the AUTOMATIC partitioning method.
10:38:44,131 INF threading: Running Thread: AnaExecuteStorageThread (139768206710336)
10:38:44,131 DBG ui.common: Left spoke: StorageSpoke
10:38:44,137 DBG ui.gui.spokes.storage: Saving storage configuration...
10:38:44,192 DBG ui.gui.hubs: spoke is not ready: StorageSpoke
10:38:44,193 DBG ui.gui.hubs: setting StorageSpoke status to: Saving storage configuration...
10:38:44,295 DBG ui.gui.hubs: spoke is not ready: KdumpSpoke
10:38:44,298 DBG ui.gui.hubs: spoke is ready: KdumpSpoke
10:38:44,298 DBG ui.gui.hubs: kickstart installation, spoke KDUMP is ready
10:38:45,158 DBG ui.gui.spokes.storage: Checking storage configuration...
10:38:45,201 DBG ui.gui.hubs: setting StorageSpoke status to: Checking storage configuration...
10:38:46,213 DBG ui.gui.spokes.storage: Partitioning has been applied: ValidationReport(error_messages=[], warning_messages=[])
10:38:46,213 INF threading: Thread Done: AnaExecuteStorageThread (139768206710336)
10:38:46,278 DBG ui.gui.hubs: spoke is not ready: KdumpSpoke
10:38:46,284 DBG ui.gui.hubs: incomplete spokes: []
10:38:46,287 INF ui.lib.space: fs space: 15.92 GiB  needed: 476.84 MiB
10:38:46,287 INF core.util: Skipping detection of SMT.
10:38:46,287 DBG ui.gui.hubs: spoke is ready: StorageSpoke
10:38:46,289 DBG ui.gui.hubs: kickstart installation, spoke Installation Destination is ready
10:38:46,292 INF ui.lib.space: fs space: 15.92 GiB  needed: 476.84 MiB
10:38:46,293 INF core.util: Skipping detection of SMT.
10:38:46,293 DBG ui.gui.hubs: spoke is ready: KdumpSpoke
10:38:46,293 DBG ui.gui.hubs: kickstart installation, spoke KDUMP is ready
10:38:48,993 DBG ui.common: Entered spoke: NetworkSpoke
10:38:51,362 INF ui.gui.spokes.network: device enp1s0 switched on
10:38:51,538 DBG ui.gui.hubs: setting NetworkSpoke status to: Wired (enp1s0) connected
10:38:51,538 DBG ui.gui.hubs: setting NetworkSpoke status to: Wired (enp1s0) connected
10:38:51,538 DBG ui.gui.hubs: setting NetworkSpoke status to: Wired (enp1s0) connected
10:38:51,539 DBG ui.gui.hubs: setting NetworkSpoke status to: Wired (enp1s0) connected
10:38:51,539 DBG ui.gui.hubs: setting NetworkSpoke status to: Wired (enp1s0) connected
10:38:54,090 DBG ui.gui.spokes.network: network spoke (apply), network configuration changed - skipping restart of payload thread, payload does not need network
10:38:54,090 DBG ui.common: Left spoke: NetworkSpoke
10:38:54,120 INF ui.lib.space: fs space: 15.92 GiB  needed: 476.84 MiB
10:38:54,120 INF core.util: Skipping detection of SMT.
10:39:05,403 INF ui.gui.helpers: kickstart installation stopped for info: User interaction required on standalone spoke ProgressSpoke
10:39:05,409 DBG ui.common: Left hub: SummaryHub
10:39:05,432 INF threading: Running Thread: AnaInstallThread (139768329827904)
10:39:05,432 DBG ui.gui.spokes.installation_progress: The installation has started.
10:39:05,441 DBG ui.common: Entered spoke: ProgressSpoke
10:39:05,558 INF installation: Top-level task queue: Complete installation queue
Number of task queues: 17
Number of tasks: 22
Task & task group listing:
 Task queue: Installation queue
  Task: Save system time to HW clock
  Task queue: Installation environment setup
  Task queue: Early storage configuration
   Task: Create storage layout
   Task: Mount filesystems
  Task queue: Pre-install scripts
   Task: Run %pre-install scripts
  Task queue: Pre install tasks
   Task: Copy resolv.conf to sysroot
   Task: Find additional packages & run pre_install()
  Task queue: Payload installation
   Task: Install the payload
  Task queue: Late storage configuration
   Task: Write the storage configuration
  Task queue: Bootloader installation
   Task: Configure bootloader
   Task: Install bootloader
  Task queue: Post-installation setup tasks
   Task: Run post-installation setup tasks
 Task queue: Configuration queue
  Task queue: Installed system configuration
   Task: Configure firewall
  Task queue: Network configuration
   Task: Network configuration
  Task queue: User creation
   Task: Create groups
   Task: Create users
   Task: Configure root password
   Task: Set SSH keys
   Task: Configure optional root password SSH login
  Task queue: Anaconda addon configuration
   Task: Enable the kdump.service
  Task queue: Initramfs generation
   Task: Generate initramfs
  Task queue: Write configs and kickstarts
   Task: Store kickstarts
  Task queue: Post installation scripts
   Task: Run post installation scripts
10:39:05,558 INF installation: Queue started: Installation queue (1/17)
10:39:05,559 INF installation: Task started: Save system time to HW clock (1/22)
10:39:05,561 INF progress: Save system time to HW clock
10:39:05,561 DBG installation: Task completed: Save system time to HW clock (1/22) (0.0 s)
10:39:05,561 WRN installation_tasks: Attempting to start an empty task queue (Installation environment setup).
10:39:05,561 INF progress: Setting up the installation environment
10:39:05,562 INF installation: Queue started: Installation environment setup (2/17)
10:39:05,562 WRN installation_tasks: The task group Installation environment setup is empty.
10:39:05,562 INF progress: Configuring storage
10:39:05,563 INF installation: Queue started: Early storage configuration (3/17)
10:39:05,563 INF installation: Task started: Create storage layout (2/22)
10:39:05,984 INF progress: Creating disklabel on /dev/vda
10:39:06,600 INF progress: Creating xfs on /dev/vda2
10:39:07,134 INF progress: Creating lvmpv on /dev/vda3
10:39:07,931 INF progress: Creating swap on /dev/mapper/rhel-swap
10:39:08,201 INF progress: Creating xfs on /dev/mapper/rhel-root
10:39:08,275 INF progress: Creating efi on /dev/vda1
10:39:09,590 INF progress: Create storage layout
10:39:09,591 DBG installation: Task completed: Create storage layout (2/22) (4.0 s)
10:39:09,591 INF installation: Task started: Mount filesystems (3/22)
10:39:12,601 INF progress: Mount filesystems
10:39:12,602 DBG installation: Task completed: Mount filesystems (3/22) (3.0 s)
10:39:12,602 INF progress: Running pre-installation scripts
10:39:12,602 INF installation: Queue started: Pre-install scripts (4/17)
10:39:12,603 INF installation: Task started: Run %pre-install scripts (4/22)
10:39:12,603 INF progress: Run %pre-install scripts
10:39:12,603 DBG installation: Task completed: Run %pre-install scripts (4/22) (0.0 s)
10:39:12,603 INF progress: Running pre-installation tasks
10:39:12,603 INF installation: Queue started: Pre install tasks (5/17)
10:39:12,604 INF installation: Task started: Copy resolv.conf to sysroot (5/22)
10:39:12,604 INF progress: Copy resolv.conf to sysroot
10:39:12,605 DBG installation: Task completed: Copy resolv.conf to sysroot (5/22) (0.0 s)
10:39:12,605 INF installation: Task started: Find additional packages & run pre_install() (6/22)
10:39:12,610 INF progress: Find additional packages & run pre_install()
10:39:12,610 DBG installation: Task completed: Find additional packages & run pre_install() (6/22) (0.0 s)
10:39:12,611 INF progress: Installing.
10:39:12,611 INF installation: Queue started: Payload installation (6/17)
10:39:12,611 INF installation: Task started: Install the payload (7/22)
10:39:12,614 INF payload.rpmostreepayload: executing ostreesetup=RPMOSTreeConfigurationData(gpg_verification_enabled=False, osname='rhel', ref='rhel/9/x86_64/edge', remote='rhel', url='file:///run/install/repo/ostree/repo')
10:39:39,913 INF modules.payloads.payload.rpm_ostree.installation: ostree pull: 3060 metadata, 23190 content objects imported; 1.1 GB content written
10:39:40,306 INF modules.payloads.payload.rpm_ostree.installation: ostree admin deploy starting
10:39:44,207 INF modules.payloads.payload.rpm_ostree.installation: ostree admin deploy complete
10:39:44,346 INF modules.payloads.payload.rpm_ostree.installation: Copying bootloader data: efi
10:39:44,397 INF modules.payloads.payload.rpm_ostree.installation: Copying bootloader data: grub2
10:39:44,845 INF progress: Install the payload
10:39:44,845 DBG installation: Task completed: Install the payload (7/22) (32.2 s)
10:39:44,846 INF progress: Configuring storage
10:39:44,846 INF installation: Queue started: Late storage configuration (7/17)
10:39:44,847 INF installation: Task started: Write the storage configuration (8/22)
10:39:45,854 INF progress: Write the storage configuration
10:39:45,855 DBG installation: Task completed: Write the storage configuration (8/22) (1.0 s)
10:39:45,856 INF progress: Installing boot loader
10:39:45,856 INF installation: Queue started: Bootloader installation (8/17)
10:39:45,856 INF installation: Task started: Configure bootloader (9/22)
10:39:46,868 INF progress: Configure bootloader
10:39:46,868 DBG installation: Task completed: Configure bootloader (9/22) (1.0 s)
10:39:46,868 INF installation: Task started: Install bootloader (10/22)
10:39:52,903 INF progress: Install bootloader
10:39:52,905 DBG installation: Task completed: Install bootloader (10/22) (6.0 s)
10:39:52,905 INF progress: Performing post-installation setup tasks
10:39:52,905 INF installation: Queue started: Post-installation setup tasks (9/17)
10:39:52,906 INF installation: Task started: Run post-installation setup tasks (11/22)
10:39:52,921 INF modules.payloads.payload.rpm_ostree.installation: Moving /mnt/sysroot/boot/grub2/grub.cfg -> /mnt/sysroot/boot/loader/grub.cfg
10:39:56,274 INF progress: Run post-installation setup tasks
10:39:56,274 DBG installation: Task completed: Run post-installation setup tasks (11/22) (3.4 s)
10:39:56,274 INF installation: Queue started: Configuration queue (10/17)
10:39:56,275 INF progress: Configuring installed system
10:39:56,275 INF installation: Queue started: Installed system configuration (11/17)
10:39:56,275 INF installation: Task started: Configure firewall (12/22)
10:39:58,283 INF progress: Configure firewall
10:39:58,284 DBG installation: Task completed: Configure firewall (12/22) (2.0 s)
10:39:58,284 INF progress: Writing network configuration
10:39:58,284 INF installation: Queue started: Network configuration (12/17)
10:39:58,285 INF installation: Task started: Network configuration (13/22)
10:39:58,422 DBG ui.gui.spokes.lib.network_secret_agent: SaveSecrets called for /org/freedesktop/NetworkManager/Settings/1
10:40:01,406 INF progress: Network configuration
10:40:01,407 DBG installation: Task completed: Network configuration (13/22) (3.1 s)
10:40:01,407 INF progress: Creating users
10:40:01,408 INF installation: Queue started: User creation (13/17)
10:40:01,408 INF installation: Task started: Create groups (14/22)
10:40:02,413 INF progress: Create groups
10:40:02,414 DBG installation: Task completed: Create groups (14/22) (1.0 s)
10:40:02,414 INF installation: Task started: Create users (15/22)
10:40:03,419 INF progress: Create users
10:40:03,419 DBG installation: Task completed: Create users (15/22) (1.0 s)
10:40:03,420 INF installation: Task started: Configure root password (16/22)
10:40:04,425 INF progress: Configure root password
10:40:04,425 DBG installation: Task completed: Configure root password (16/22) (1.0 s)
10:40:04,426 INF installation: Task started: Set SSH keys (17/22)
10:40:05,439 INF threading: Thread Failed: AnaInstallThread (139768329827904)
10:40:05,440 DBG exception: running handleException
10:40:05,445 CRT exception: Traceback (most recent call last):

  File "/usr/lib64/python3.9/site-packages/pyanaconda/threading.py", line 275, in run
    threading.Thread.run(self)

  File "/usr/lib64/python3.9/threading.py", line 910, in run
    self._target(*self._args, **self._kwargs)

  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation.py", line 396, in run_installation
    queue.start()

  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 311, in start
    item.start()

  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 311, in start
    item.start()

  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 311, in start
    item.start()

  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 496, in start
    self.run_task()

  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 527, in run_task
    sync_run_task(self._task_proxy)

  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/common/task/__init__.py", line 46, in sync_run_task
    task_proxy.Finish()

  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 444, in _call_method
    return self._get_method_reply(

  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply
    return self._handle_method_error(error)

  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error
    raise exception from None

dasbus.error.DBusError: set_user_ssh_key: user xxxxxxxx does not exist

10:40:05,446 DBG exception: Gtk running, queuing exception handler to the main loop
10:40:05,446 INF threading: Thread Done: AnaInstallThread (139768329827904)
10:40:07,244 INF core.util: Running kickstart %%onerror script(s)
10:40:07,244 INF core.util: All kickstart %%onerror script(s) have been run
10:40:07,244 INF kickstart.script: Running kickstart %%traceback script(s)
10:40:07,244 INF kickstart.script: All kickstart %%traceback script(s) have been run
10:40:07,245 INF core.util: Reporting the IPMI event: 10



If I remove ssh-key from the blueprint installation works fine, user is being created as expected with expected password.


Version-Release number of selected component (if applicable):

RHEL8 and RHEL9 are confirmed

How reproducible:

All the time

Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:
Comment 1 Xiaofeng Wang 2022-07-12 14:13:32 UTC 
Hi 
osbuild-composer supports this feature by PR https://github.com/osbuild/osbuild-composer/pull/2375.
This feature is available after v49 of osbuild-composer. But it's not included in RHEL 9.0 release.
Could you please use RHEL 9.1 if you want to try this feature? Thanks.

Xiaofeng
Comment 4 Xiaofeng Wang 2022-08-09 14:13:01 UTC 
Verified on osbuild-63-1.el9.noarch.rpm and osbuild-composer-58-1.el9.x86_64.rpm.
Comment 6 errata-xmlrpc 2022-11-15 09:50:32 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Low: Image Builder security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2022:7950