Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 2240163

Summary: 17.0/17.1 jobs container image prepare fails with Error: readObjectStart: expect { or n, but found \u0000, error found in #0 byte of ...||..., bigger context ...||...\n"
Product: Red Hat OpenStack Reporter: Yatin Karel <ykarel>
Component: openstack-tripleo-commonAssignee: Rabi Mishra <ramishra>
Status: CLOSED ERRATA QA Contact: David Rosenfeld <drosenfe>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 17.1 (Wallaby)CC: alisci, ariveral, bshephar, dhill, fhubik, fpantano, fyanac, hbrock, ipanova, jbadiapa, jbeaudoi, jmarti, jslagle, mariel, mburns, mitr, pgodwin, pweeks, ramishra, rdiazcam, slinaber
Target Milestone: asyncKeywords: Triaged
Target Release: 17.1Flags: ramishra: needinfo-
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: openstack-tripleo-common-15.4.1-1.20230518205258.el8ost openstack-tripleo-common-15.4.1-1.20230518211056.el9ost Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 2240629 (view as bug list) Environment:
Last Closed: 2023-09-26 15:01:37 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:
Bug Depends On:    
Bug Blocks: 2240629    

Description Yatin Karel 2023-09-22 07:26:41 UTC
Description of problem:
17.0/17.1 jobs recently started to fail with below error during undercloud install:-
"changed": false, "msg": "Failed to run ['/bin/podman', 'inspect', '48959ec71f6ff5e9e5addcd0f9ecb10dc3f131da5c2f587aebbbacfa5c1a4bad', '--format', 'json'] ['inspect', '48959ec71f6ff5e9e5addcd0f9ecb10dc3f131da5c2f587aebbbacfa5c1a4bad', '--format', 'json']: Error: readObjectStart: expect { or n, but found \u0000, error found in #0 byte of ...||..., bigger context ...||...\n", "prefetch_image": "undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp17-openstack-ironic-pxe:17.1_20230905.1"}
2023-09-21 16:53:51.513256 | 52540070-56a8-88cc-09c9-000000001a00 |     TIMING | Pre-fetch all the containers | undercloud-0 | 0:17:22.755747 | 529.56s
2023-09-21 16:53:53.470641 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 5 retries left
2023-09-21 16:53:59.732325 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 4 retries left
2023-09-21 16:54:05.971684 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 3 retries left
2023-09-21 16:54:12.211632 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 2 retries left
2023-09-21 16:54:18.457079 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 1 retries left
2023-09-21 16:54:24.694630 | 52540070-56a8-88cc-09c9-000000001a00 |      FATAL | Pre-fetch all the containers | undercloud-0 | item=undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp17-openstack-cron:17.1_20230905.1 | error={"ansible_loop_var": "prefetch_image", "attempts": 5, "changed": false, "msg": "Failed to run ['/bin/podman', 'inspect', '1b957baada0a8d706994308733bd6aa98dfd92929435b813a8e89c6f909a4092', '--format', 'json'] ['inspect', '1b957baada0a8d706994308733bd6aa98dfd92929435b813a8e89c6f909a4092', '--format', 'json']: Error: readObjectStart: expect { or n, but found \u0000, error found in #0 byte of ...||..., bigger context ...||...\n", "prefetch_image": "undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp17-openstack-cron:17.1_20230905.1"}
2023-09-21 16:54:24.697441 | 52540070-56a8-88cc-09c9-000000001a00 |     TIMING | Pre-fetch all the containers | undercloud-0 | 0:17:55.939945 | 562.74s
2023-09-21 16:54:27.179871 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 5 retries left
2023-09-21 16:54:33.541386 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 4 retries left
2023-09-21 16:54:39.939537 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 3 retries left
2023-09-21 16:54:46.252543 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 2 retries left
2023-09-21 16:54:52.605058 | 52540070-56a8-88cc-09c9-000000001a00 |      RETRY | Pre-fetch all the containers | undercloud-0 | 1 retries left
2023-09-21 16:54:59.010095 | 52540070-56a8-88cc-09c9-000000001a00 |      FATAL | Pre-fetch all the containers | undercloud-0 | item=undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp17-openstack-neutron-openvswitch-agent:17.1_20230905.1 | error={"ansible_loop_var": "prefetch_image", "attempts": 5, "changed": false, "msg": "Failed to run ['/bin/podman', 'inspect', '9b24840749ec689fffe94ffdf9f6f2c240756fbb3b82395e41a0f2a3aebdf2ed', '--format', 'json'] ['inspect', '9b24840749ec689fffe94ffdf9f6f2c240756fbb3b82395e41a0f2a3aebdf2ed', '--format', 'json']: Error: readObjectStart: expect { or n, but found \u0000, error found in #0 byte of ...||..., bigger context ...||...\n", "prefetch_image": "undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp17-openstack-neutron-openvswitch-agent:17.1_20230905.1"}
2023-09-21 16:54:59.013326 | 52540070-56a8-88cc-09c9-000000001a00 |     TIMING | Pre-fetch all the containers | undercloud-0 | 0:18:30.255831 | 597.06s
2023-09-21 16:54:59.033553 | 52540070-56a8-88cc-09c9-000000001a00 |     TIMING | Pre-fetch all the containers | undercloud-0 | 0:18:30.276054 | 597.08s

Example failures:-
http://rhos-ci-logs.lab.eng.tlv2.redhat.com/logs/rcj/DFG-network-neutron-17.1_director-rhel-virthost-3cont_2comp-ipv4-geneve-gate-ovn/528/undercloud-0/home/stack/undercloud_install.log.gz
http://rhos-ci-logs.lab.eng.tlv2.redhat.com/logs/rcj/DFG-compute-nova-17.0_director-rhel-virthost-3cont_2comp-ipv4-geneve-check-job/96/undercloud-0/home/stack/undercloud_install.log.gz
http://rhos-ci-logs.lab.eng.tlv2.redhat.com/logs/rcj/DFG-perfscale-PerfCI-OSP17.1-dynamic-workloads-ovs/87/hosts/undercloud-0.tar.gz/undercloud-0/home/stack/undercloud_install.log
http://rhos-ci-logs.lab.eng.tlv2.redhat.com/logs/rcj/DFG-perfscale-PerfCI-OSP17.1-neutron-ovn/93/hosts/undercloud-0.tar.gz/undercloud-0/home/stack/undercloud_install.log


How reproducible:
Currently happening always in 17.0/17.1 jobs


Actual results:
podman inspect <image id> fails with  Error: readObjectStart: expect { or n, but found \u0000, error found in #0 byte of ...||..., bigger context ...||...\n"

Expected results:
podman inspect should pass

Additional info:

Comment 2 Filip HubĂ­k 2023-09-22 12:27:09 UTC
I compared recent passing and failing CI builds and I see several differenced in minor package number (though the OSP build version is the same, 2 weeks difference). Especially since this seems to be podman related, the version got bumped 2:4.4.1-12.el9_2 -> 2:4.4.1-13.el9_2 . That one got change https://github.com/containers/podman/commit/dd490ff plus seems to be related to https://bugzilla.redhat.com/show_bug.cgi?id=2229749 - might be worth looking at as part of the debugging.

Comment 9 Brendan Shephard 2023-09-25 05:36:06 UTC
*** Bug 2240252 has been marked as a duplicate of this bug. ***

Comment 10 Brendan Shephard 2023-09-25 05:40:27 UTC
*** Bug 2240185 has been marked as a duplicate of this bug. ***

Comment 22 errata-xmlrpc 2023-09-26 15:01:37 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 (Red Hat OpenStack Platform 17.0 & 17.1 Bug Fix Advisory), 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/RHBA-2023:5364

Comment 25 Alberto Rivera Laporte 2023-10-18 14:18:30 UTC
Hello, 

This issue still present with openstack-tripleo-common-15.4.1-1.20230518205258.el8ost.noarch [1] and is currently preventing the upgrade of an Undercloud from 16.2.5 -> 17.1 during this task on the Undercloud upgrade[2],[3]. 




Should this bz be reopened or should I create a new BZ ? 




[1] 
---
[stack@osp-dir ~]$ rpm -qi openstack-tripleo-common-15.4.1-1.20230518205258.el8ost.noarch
Name        : openstack-tripleo-common
Version     : 15.4.1
Release     : 1.20230518205258.el8ost
Architecture: noarch
Install Date: Wed 18 Oct 2023 09:54:25 AM EDT
Group       : Unspecified
Size        : 75426
License     : ASL 2.0
Signature   : RSA/SHA256, Mon 25 Sep 2023 03:00:26 PM EDT, Key ID 199e2f91fd431d51
Source RPM  : openstack-tripleo-common-15.4.1-1.20230518205258.el8ost.src.rpm
Build Date  : Mon 25 Sep 2023 02:42:51 PM EDT
Build Host  : s390-066.build.eng.bos.redhat.com
Relocations : (not relocatable)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
Vendor      : Red Hat, Inc.
URL         : https://github.com/rdo-management/tripleo-common
Summary     : Python library for code used by TripleO projects.
Description :
Python library for code used by TripleO projects.



[2] 
---
2023-10-18 10:06:07.236779 | 52540015-7743-1eb7-458d-000000000952 |       TASK | Clean up redo log by running a transient mysql server
2023-10-18 10:06:07.675856 | 52540015-7743-1eb7-458d-000000000952 |      FATAL | Clean up redo log by running a transient mysql server | osp-dir | error={"changed": true, "cmd": "podman run --rm -u root --net=host -e \"KOLLA_CONFIG_STRATEGY=COPY_ALWAYS\" -v /var/lib/kolla/config_files/mysql.json:/var/lib/kolla/config_files/config.json -v /var/lib/config-data/puppet-generated/mysql:/var/lib/kolla/config_files/src:ro -v /etc/localtime:/etc/localtime:ro -v /etc/hosts:/etc/hosts:ro -v /var/lib/mysql:/var/lib/mysql -v /var/log/containers/mysql:/var/log/mariadb \"osp-dir.ctlplane.voltron.xyz:8787/rhosp-rhel8/openstack-mariadb:16.2.5\" /bin/bash -ecx \"kolla_set_configs; mysqld_safe --user=mysql --skip-networking --log-error=/var/log/mariadb/mariadb-upgrade.log & timeout 180 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'; mysqladmin shutdown\"", "delta": "0:00:00.146240", "end": "2023-10-18 10:06:07.640817", "msg": "non-zero return code", "rc": 125, "start": "2023-10-18 10:06:07.494577", "stderr": "Error: unexpected end of JSON input", "stderr_lines": ["Error: unexpected end of JSON input"], "stdout": "", "stdout_lines": []}
2023-10-18 10:06:07.677828 | 52540015-7743-1eb7-458d-000000000952 |     TIMING | Clean up redo log by running a transient mysql server | osp-dir | 0:05:34.157672 | 0.44s

PLAY RECAP *********************************************************************
localhost                  : ok=1    changed=0    unreachable=0    failed=0    skipped=2    rescued=0    ignored=0
osp-dir                    : ok=245  changed=93   unreachable=0    failed=1    skipped=133  rescued=0    ignored=2



[3]
---
[stack@osp-dir ~]$ sudo podman --log-level=debug image inspect osp-dir.ctlplane.voltron.xyz:8787/rhosp-rhel8/openstack-mariadb:16.2.5
INFO[0000] podman filtering at log level debug
DEBU[0000] Called inspect.PersistentPreRunE(podman --log-level=debug image inspect osp-dir.ctlplane.voltron.xyz:8787/rhosp-rhel8/openstack-mariadb:16.2.5)
DEBU[0000] Merged system config "/usr/share/containers/containers.conf"
DEBU[0000] Merged system config "/etc/containers/containers.conf"
DEBU[0000] Using conmon: "/usr/bin/conmon"
DEBU[0000] Initializing boltdb state at /var/lib/containers/storage/libpod/bolt_state.db
DEBU[0000] Using graph driver overlay
DEBU[0000] Using graph root /var/lib/containers/storage
DEBU[0000] Using run root /run/containers/storage
DEBU[0000] Using static dir /var/lib/containers/storage/libpod
DEBU[0000] Using tmp dir /run/libpod
DEBU[0000] Using volume path /var/lib/containers/storage/volumes
DEBU[0000] Set libpod namespace to ""
DEBU[0000] [graphdriver] trying provided driver "overlay"
DEBU[0000] cached value indicated that overlay is supported
DEBU[0000] cached value indicated that metacopy is being used
DEBU[0000] cached value indicated that native-diff is not being used
INFO[0000] Not using native diff for overlay, this may cause degraded performance for building images: kernel has CONFIG_OVERLAY_FS_REDIRECT_DIR enabled
DEBU[0000] backingFs=xfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=true
DEBU[0000] Initializing event backend journald
DEBU[0000] configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument
DEBU[0000] configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument
DEBU[0000] Using OCI runtime "/usr/bin/runc"
INFO[0000] Found CNI network podman (type=bridge) at /etc/cni/net.d/87-podman-bridge.conflist
DEBU[0000] Default CNI network name podman is unchangeable
INFO[0000] Setting parallel job count to 25
DEBU[0000] Looking up image "osp-dir.ctlplane.voltron.xyz:8787/rhosp-rhel8/openstack-mariadb:16.2.5" in local containers storage
DEBU[0000] Trying "osp-dir.ctlplane.voltron.xyz:8787/rhosp-rhel8/openstack-mariadb:16.2.5" ...
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/run/containers/storage:overlay.mountopt=nodev,metacopy=on]@414957cc322bd69c9e88b9ae66cd01ba07ea13826d47c5b756bd1b8847cba7e2"
DEBU[0000] Found image "osp-dir.ctlplane.voltron.xyz:8787/rhosp-rhel8/openstack-mariadb:16.2.5" as "osp-dir.ctlplane.voltron.xyz:8787/rhosp-rhel8/openstack-mariadb:16.2.5" in local containers storage
DEBU[0000] Inspecting image 414957cc322bd69c9e88b9ae66cd01ba07ea13826d47c5b756bd1b8847cba7e2
Error: unexpected end of JSON input

Comment 26 Leif Madsen 2023-10-18 18:00:05 UTC
(In reply to Alberto Rivera Laporte from comment #25)
> Hello, 
> 
> This issue still present with
> openstack-tripleo-common-15.4.1-1.20230518205258.el8ost.noarch [1] and is
> currently preventing the upgrade of an Undercloud from 16.2.5 -> 17.1 during
> this task on the Undercloud upgrade[2],[3]. 
> 
> 
> 
> 
> Should this bz be reopened or should I create a new BZ ? 

Please open a new issue as this one has already been associated with an errata as part of shipped product, and it will make it difficult to address.

It'd be ideal to have a separate issue with the appropriate information identifying where the problem lies along with a new description in order to avoid having to trawl the entire backlog for cleanliness.

Comment 27 Rabi Mishra 2023-10-19 01:22:27 UTC
> Should this bz be reopened or should I create a new BZ ? 

There is no need to create a new BZ or re-open this one. This BZ does not address related (16.2->17.1)upgrade issues  and that instead has been addressed with https://bugzilla.redhat.com/show_bug.cgi?id=2240185. The issue is during upgrade we try to inspect old 16.2 local images with new podman.

Comment 28 Brendan Shephard 2023-11-09 03:17:45 UTC
*** Bug 2240252 has been marked as a duplicate of this bug. ***