Bug #1952226 ""Unexpected error while running command.” when dep... : Bugs : curtin

Revision history for this message

Diego Mascialino (dmascialino) wrote on 2021-11-25:

#1

curtin-logs.tar Edit (150.0 KiB, application/x-tar)

Revision history for this message

Sean Feole (sfeole) wrote on 2021-11-29:

#2

curtin.txt Edit (25.4 KiB, text/plain)

Download full text (14.5 KiB)

I have also just experienced this failure today while refreshing maas-images to include the latest uploaded jammy release.

See attached curtin.txt for full log

finish: cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders: FAIL: removing previous storage devices
TIMED BLOCK_META: 1.260
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: FAIL: curtin command block-meta
Traceback (most recent call last):
  File "/curtin/curtin/commands/main.py", line 202, in main
    ret = args.func(args)
  File "/curtin/curtin/log.py", line 97, in wrapper
    return log_time("TIMED %s: " % msg, func, *args, **kwargs)
  File "/curtin/curtin/log.py", line 79, in log_time
    return func(*args, **kwargs)
  File "/curtin/curtin/commands/block_meta.py", line 102, in block_meta
    meta_clear(devices, state.get('report_stack_prefix', ''))
  File "/curtin/curtin/commands/block_meta.py", line 1889, in meta_clear
    clear_holders.clear_holders(devices)
  File "/curtin/curtin/block/clear_holders.py", line 639, in clear_holders
    shutdown_function(dev_info['device'])
  File "/curtin/curtin/block/clear_holders.py", line 244, in wipe_superblock
    if block.is_extended_partition(blockdev):
  File "/curtin/curtin/block/__init__.py", line 1084, in is_extended_partition
    return (get_part_table_type(parent_dev) in ['dos', 'msdos'] and
  File "/curtin/curtin/block/__init__.py", line 1026, in get_part_table_type
    return ('gpt' if check_efi_signature(device) else
  File "/curtin/curtin/block/__init__.py", line 1058, in check_efi_signature
    sector_size = get_blockdev_sector_size(devname)[0]
  File "/curtin/curtin/block/__init__.py", line 785, in get_blockdev_sector_size
    logical = info[parent]['LOG-SEC']
KeyError: 'LOG-SEC'
'LOG-SEC'
curtin: Installation failed with exception: Unexpected error while running command.
Command: ['curtin', 'block-meta', 'custom']
Exit code: 3
Reason: -
Stdout: start: cmd-install/stage-partitioning/builtin/cmd-block-meta: curtin command block-meta
        get_path_to_storage_volume for volume nvme0n1({'grub_device': True, 'id': 'nvme0n1', 'model': 'INTEL SSDPE2KX010T8', 'name': 'nvme0n1', 'ptable': 'gpt', 'serial': 'PHLJ0023005Y1P0FGN', 'type': 'disk', 'wipe': 'superblock'})
        Processing serial PHLJ0023005Y1P0FGN via udev to PHLJ0023005Y1P0FGN
        lookup_disks found: ['nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part1', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part2']
        Running command ['udevadm', 'info', '--query=property', '--export', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device? False
        Running command ['multipath', '-c', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device member? False
        block.lookup_disk() returning path /dev/nvme0n1
        Running command ['partprobe', '/dev/nvme0n1'] with allowed return codes [0, 1] (capture=False)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.092
        devsync happy - path /dev/nvme0n1 now exists
        ...

I have also just experienced this failure today while refreshing maas-images to include the latest uploaded jammy release.

See attached curtin.txt for full log

finish: cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders: FAIL: removing previous storage devices
TIMED BLOCK_META: 1.260
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: FAIL: curtin command block-meta
Traceback (most recent call last):
  File "/curtin/curtin/commands/main.py", line 202, in main
    ret = args.func(args)
  File "/curtin/curtin/log.py", line 97, in wrapper
    return log_time("TIMED %s: " % msg, func, *args, **kwargs)
  File "/curtin/curtin/log.py", line 79, in log_time
    return func(*args, **kwargs)
  File "/curtin/curtin/commands/block_meta.py", line 102, in block_meta
    meta_clear(devices, state.get('report_stack_prefix', ''))
  File "/curtin/curtin/commands/block_meta.py", line 1889, in meta_clear
    clear_holders.clear_holders(devices)
  File "/curtin/curtin/block/clear_holders.py", line 639, in clear_holders
    shutdown_function(dev_info['device'])
  File "/curtin/curtin/block/clear_holders.py", line 244, in wipe_superblock
    if block.is_extended_partition(blockdev):
  File "/curtin/curtin/block/__init__.py", line 1084, in is_extended_partition
    return (get_part_table_type(parent_dev) in ['dos', 'msdos'] and
  File "/curtin/curtin/block/__init__.py", line 1026, in get_part_table_type
    return ('gpt' if check_efi_signature(device) else
  File "/curtin/curtin/block/__init__.py", line 1058, in check_efi_signature
    sector_size = get_blockdev_sector_size(devname)[0]
  File "/curtin/curtin/block/__init__.py", line 785, in get_blockdev_sector_size
    logical = info[parent]['LOG-SEC']
KeyError: 'LOG-SEC'
'LOG-SEC'
curtin: Installation failed with exception: Unexpected error while running command.
Command: ['curtin', 'block-meta', 'custom']
Exit code: 3
Reason: -
Stdout: start: cmd-install/stage-partitioning/builtin/cmd-block-meta: curtin command block-meta
        get_path_to_storage_volume for volume nvme0n1({'grub_device': True, 'id': 'nvme0n1', 'model': 'INTEL SSDPE2KX010T8', 'name': 'nvme0n1', 'ptable': 'gpt', 'serial': 'PHLJ0023005Y1P0FGN', 'type': 'disk', 'wipe': 'superblock'})
        Processing serial PHLJ0023005Y1P0FGN via udev to PHLJ0023005Y1P0FGN
        lookup_disks found: ['nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part1', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part2']
        Running command ['udevadm', 'info', '--query=property', '--export', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device? False
        Running command ['multipath', '-c', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device member? False
        block.lookup_disk() returning path /dev/nvme0n1
        Running command ['partprobe', '/dev/nvme0n1'] with allowed return codes [0, 1] (capture=False)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.092
        devsync happy - path /dev/nvme0n1 now exists
        return volume path /dev/nvme0n1
        get_path_to_storage_volume for volume nvme1n1({'id': 'nvme1n1', 'model': 'INTEL SSDPE2KX010T8', 'name': 'nvme1n1', 'serial': 'PHLJ023200RS1P0FGN', 'type': 'disk', 'wipe': 'superblock'})
        Processing serial PHLJ023200RS1P0FGN via udev to PHLJ023200RS1P0FGN
        lookup_disks found: ['nvme-INTEL_SSDPE2KX010T8_PHLJ023200RS1P0FGN']
        Running command ['udevadm', 'info', '--query=property', '--export', '/dev/nvme1n1'] with allowed return codes [0] (capture=True)
        /dev/nvme1n1 is multipath device? False
        Running command ['multipath', '-c', '/dev/nvme1n1'] with allowed return codes [0] (capture=True)
        /dev/nvme1n1 is multipath device member? False
        block.lookup_disk() returning path /dev/nvme1n1
        Running command ['partprobe', '/dev/nvme1n1'] with allowed return codes [0, 1] (capture=False)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.043
        devsync happy - path /dev/nvme1n1 now exists
        return volume path /dev/nvme1n1
        get_path_to_storage_volume for volume nvme0n1-part1({'device': 'nvme0n1', 'flag': 'boot', 'id': 'nvme0n1-part1', 'name': 'nvme0n1-part1', 'number': 1, 'offset': '4194304B', 'size': '536870912B', 'type': 'partition', 'uuid': 'e1e97045-4a7e-4c6c-becc-79d94cc90ae4', 'wipe': 'superblock'})
        get_path_to_storage_volume for volume nvme0n1({'grub_device': True, 'id': 'nvme0n1', 'model': 'INTEL SSDPE2KX010T8', 'name': 'nvme0n1', 'ptable': 'gpt', 'serial': 'PHLJ0023005Y1P0FGN', 'type': 'disk', 'wipe': 'superblock'})
        Processing serial PHLJ0023005Y1P0FGN via udev to PHLJ0023005Y1P0FGN
        lookup_disks found: ['nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part1', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part2']
        Running command ['udevadm', 'info', '--query=property', '--export', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device? False
        Running command ['multipath', '-c', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device member? False
        block.lookup_disk() returning path /dev/nvme0n1
        Running command ['partprobe', '/dev/nvme0n1'] with allowed return codes [0, 1] (capture=False)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.100
        devsync happy - path /dev/nvme0n1 now exists
        return volume path /dev/nvme0n1
        Running command ['partprobe', '/dev/nvme0n1'] with allowed return codes [0, 1] (capture=False)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.100
        devsync happy - path /dev/nvme0n1 now exists
        return volume path /dev/nvme0n1p1
        get_path_to_storage_volume for volume nvme0n1-part2({'device': 'nvme0n1', 'id': 'nvme0n1-part2', 'name': 'nvme0n1-part2', 'number': 2, 'size': '999662026752B', 'type': 'partition', 'uuid': '190aac66-a231-4097-9609-ac5c67db02b2', 'wipe': 'superblock'})
        get_path_to_storage_volume for volume nvme0n1({'grub_device': True, 'id': 'nvme0n1', 'model': 'INTEL SSDPE2KX010T8', 'name': 'nvme0n1', 'ptable': 'gpt', 'serial': 'PHLJ0023005Y1P0FGN', 'type': 'disk', 'wipe': 'superblock'})
        Processing serial PHLJ0023005Y1P0FGN via udev to PHLJ0023005Y1P0FGN
        lookup_disks found: ['nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part1', 'nvme-INTEL_SSDPE2KX010T8_PHLJ0023005Y1P0FGN-part2']
        Running command ['udevadm', 'info', '--query=property', '--export', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device? False
        Running command ['multipath', '-c', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        /dev/nvme0n1 is multipath device member? False
        block.lookup_disk() returning path /dev/nvme0n1
        Running command ['partprobe', '/dev/nvme0n1'] with allowed return codes [0, 1] (capture=False)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.096
        devsync happy - path /dev/nvme0n1 now exists
        return volume path /dev/nvme0n1
        Running command ['partprobe', '/dev/nvme0n1'] with allowed return codes [0, 1] (capture=False)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.100
        devsync happy - path /dev/nvme0n1 now exists
        return volume path /dev/nvme0n1p2
        block-meta: extracted devices to clear: ['/dev/nvme0n1', '/dev/nvme1n1', '/dev/nvme0n1p1', '/dev/nvme0n1p2']
        Declared block devices: ['/dev/nvme0n1', '/dev/nvme1n1', '/dev/nvme0n1p1', '/dev/nvme0n1p2']
        clearing devices=['/dev/nvme0n1', '/dev/nvme1n1', '/dev/nvme0n1p1', '/dev/nvme0n1p2']
        start: cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders: removing previous storage devices
        Running command ['mdadm', '--assemble', '--scan', '-v'] with allowed return codes [0, 1, 2] (capture=True)
        mdadm assemble scan results:
        
        mdadm: looking for devices for further assembly
        mdadm: cannot open device /dev/sr0: No medium found
        mdadm: no recogniseable superblock on /dev/nvme0n1p2
        mdadm: Cannot assemble mbr metadata on /dev/nvme0n1p1
        mdadm: Cannot assemble mbr metadata on /dev/nvme0n1
        mdadm: no recogniseable superblock on /dev/nvme1n1
        mdadm: no recogniseable superblock on /dev/loop3
        mdadm: no recogniseable superblock on /dev/loop2
        mdadm: no recogniseable superblock on /dev/loop1
        mdadm: no recogniseable superblock on /dev/loop0
        mdadm: No arrays found in config file or automatically
        
        Running command ['mdadm', '--detail', '--scan', '-v'] with allowed return codes [0, 1] (capture=True)
        mdadm detail scan after assemble:
        
        
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.010
        Detected multipath support, reload maps
        Running command ['multipath', '-r'] with allowed return codes [0] (capture=False)
        Verifying /dev/mapper/mpath* files are symlinks
        Running command ['dmsetup', 'ls', '-o', 'blkdevname'] with allowed return codes [0] (capture=True)
        Running command ['pvscan', '--config', 'devices{ filter = [ "a|/dev/mapper/mpath.*|", "r|.*|" ] }'] with allowed return codes [0] (capture=True)
        Running command ['vgscan', '--config', 'devices{ filter = [ "a|/dev/mapper/mpath.*|", "r|.*|" ] }'] with allowed return codes [0] (capture=True)
        Running command ['vgchange', '--activate=y', '--config', 'devices{ filter = [ "a|/dev/mapper/mpath.*|", "r|.*|" ] }'] with allowed return codes [0] (capture=True)
        Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
        TIMED udevadm_settle(): 0.010
        Loading kernel module bcache via modprobe
        Running command ['modprobe', '--use-blacklist', 'bcache'] with allowed return codes [0] (capture=False)
        Generating device storage trees for path(s): ['/dev/nvme0n1', '/dev/nvme1n1', '/dev/nvme0n1p1', '/dev/nvme0n1p2']
        devname '/sys/class/block/nvme0n1' had holders: []
        /dev/nvme0n1 is multipath device partition? False
        /dev/nvme0n1 is multipath device partition? False
        /dev/nvme0n1 is multipath device partition? False
        devname '/sys/class/block/nvme0n1p1' had holders: []
        devname '/sys/class/block/nvme0n1p2' had holders: []
        devname '/sys/class/block/nvme1n1' had holders: []
        /dev/nvme1n1 is multipath device partition? False
        /dev/nvme1n1 is multipath device partition? False
        /dev/nvme1n1 is multipath device partition? False
        devname '/sys/class/block/nvme0n1p1' had holders: []
        devname '/sys/class/block/nvme0n1p2' had holders: []
        Current device storage tree:
        nvme0n1
        |-- nvme0n1p1
        `-- nvme0n1p2
        nvme1n1
        nvme0n1p1
        nvme0n1p2
        Shutdown Plan:
        {'level': 3, 'device': '/sys/class/block/nvme0n1p1', 'dev_type': 'partition'}
        {'level': 3, 'device': '/sys/class/block/nvme0n1p2', 'dev_type': 'partition'}
        {'level': 1, 'device': '/sys/class/block/nvme0n1', 'dev_type': 'disk'}
        {'level': 0, 'device': '/sys/class/block/nvme1n1', 'dev_type': 'disk'}
        shutdown running on holder type: 'partition' syspath: '/sys/class/block/nvme0n1p1'
        Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/nvme0n1'] with allowed return codes [0] (capture=True)
        get_blockdev_sector_size: info:
        {
         "nvme0n1": {
          "ALIGNMENT": "0",
          "DISC_ALN": "0",
          "DISC_GRAN": "512",
          "DISC_MAX": "2199023255040",
          "DISC_ZERO": "0",
          "FSTYPE": "",
          "GROUP": "disk",
          "KNAME": "nvme0n1",
          "LABEL": "",
          "LOG_SEC": "512",
          "MAJ_MIN": "259:1",
          "MIN_IO": "512",
          "MODE": "brw-rw----",
          "MODEL": "INTEL SSDPE2KX010T8",
          "MOUNTPOINT": "",
          "NAME": "nvme0n1",
          "OPT_IO": "0",
          "OWNER": "root",
          "PHY_SEC": "512",
          "RM": "0",
          "RO": "0",
          "ROTA": "0",
          "RQ_SIZE": "1023",
          "SIZE": "1000204886016",
          "STATE": "live",
          "TYPE": "disk",
          "UUID": "",
          "device_path": "/dev/nvme0n1"
         },
         "nvme0n1p1": {
          "ALIGNMENT": "0",
          "DISC_ALN": "0",
          "DISC_GRAN": "512",
          "DISC_MAX": "2199023255040",
          "DISC_ZERO": "0",
          "FSTYPE": "vfat",
          "GROUP": "disk",
          "KNAME": "nvme0n1p1",
          "LABEL": "efi",
          "LOG_SEC": "512",
          "MAJ_MIN": "259:2",
          "MIN_IO": "512",
          "MODE": "brw-rw----",
          "MODEL": "",
          "MOUNTPOINT": "",
          "NAME": "nvme0n1p1",
          "OPT_IO": "0",
          "OWNER": "root",
          "PHY_SEC": "512",
          "RM": "0",
          "RO": "0",
          "ROTA": "0",
          "RQ_SIZE": "1023",
          "SIZE": "536870912",
          "STATE": "",
          "TYPE": "part",
          "UUID": "309D-E10E",
          "device_path": "/dev/nvme0n1p1"
         },
         "nvme0n1p2": {
          "ALIGNMENT": "0",
          "DISC_ALN": "0",
          "DISC_GRAN": "512",
          "DISC_MAX": "2199023255040",
          "DISC_ZERO": "0",
          "FSTYPE": "ext4",
          "GROUP": "disk",
          "KNAME": "nvme0n1p2",
          "LABEL": "root",
          "LOG_SEC": "512",
          "MAJ_MIN": "259:3",
          "MIN_IO": "512",
          "MODE": "brw-rw----",
          "MODEL": "",
          "MOUNTPOINT": "",
          "NAME": "nvme0n1p2",
          "OPT_IO": "0",
          "OWNER": "root",
          "PHY_SEC": "512",
          "RM": "0",
          "RO": "0",
          "ROTA": "0",
          "RQ_SIZE": "1023",
          "SIZE": "999666949632",
          "STATE": "",
          "TYPE": "part",
          "UUID": "fa0d62f1-72f5-4549-b5a7-a3a4c2eb7b22",
          "device_path": "/dev/nvme0n1p2"
         }
        }

Changed in curtin:
status:	New → Confirmed

Revision history for this message

Dan Bungert (dbungert) wrote on 2021-11-29:

#3

Fixed in https://code.launchpad.net/~dbungert/curtin/+git/curtin/+merge/412027

Changed in curtin:
status:	Confirmed → Fix Committed

Revision history for this message

Patricia Domingues (patriciasd) wrote on 2021-12-14:

#4

curtin_ppc64le_P9_tiselius Edit (109.5 KiB, text/plain)

I was checking this on a 2.9.2 MAAS and I can reproduce this issue on a ppc64le (POWER9) server trying to install 22.04. Attaching the curtin log

Revision history for this message

Patricia Domingues (patriciasd) wrote on 2021-12-14:

#5

I can now install and boot 22.04 on the same Power9 server - installing curtin 21.3 from ppa:curtin-dev/daily:

`2021-12-14T15:58:23+00:00 tiselius cloud-init[3091]: curtin: Installation started. (21.3-972-g9ea6be15-0ubuntu1+307~trunk~ubuntu20.04.1)`

```
ii curtin-common 21.3-972-g9ea6be15-0ubuntu1+307~trunk~ubuntu20.04.1 all Library and tools for curtin installer
ii python3-curtin 21.3-972-g9ea6be15-0ubuntu1+307~trunk~ubuntu20.04.1 all Library and tools for curtin installer
```

`Welcome to Ubuntu Jammy Jellyfish (development branch) (GNU/Linux 5.13.0-19-generic ppc64le)`

let me know if I can provide any other test/info

curtin

"Unexpected error while running command." when deploying jammy images with MAAS

Bug Description

Related branches

Other bug subscribers

Bug attachments

Remote bug watches