Hello!

I think the issue is related to paunch, and should be corrected already, at least upstream: https://review.opendev.org/#/c/696589/

Would you be able to apply it in your env and confirm it's correcting your issue? I'll check if it's already downstream...

Thank you!

Cheers,

C.

*** Bug 1779308 has been marked as a duplicate of this bug. ***

Hi,

So I'm investigating that error as well as I have it in the update CI[1].  I was about to set up the job to test when I notice that the puddle RHOS_TRUNK-16.0-RHEL-8-20191202.n.1[2] has already that patch in, as it has python3-paunch-5.3.1-0.20191202200345.8b47eb2.el8ost.noarch.rpm which has that review in.  See the changelog there[3].

So it looks like that patch didn't solve the issue.  Moving this back to assignee.


[1] https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/DFG/view/upgrades/view/update/job/DFG-upgrades-updates-16-from-passed_phase1-HA-ipv4/16/
[2] http://rhos-qe-mirror-tlv.usersys.redhat.com/rcm-guest/puddles/OpenStack/16.0-RHEL-8/RHOS_TRUNK-16.0-RHEL-8-20191202.n.1/compose/OpenStack/x86_64/os/Packages/
[3] https://brewweb.engineering.redhat.com/brew/buildinfo?buildID=1025918

FYI, We also checked that https://review.opendev.org/#/c/695929/ was also is the puddle and it is as the downstream patch is 184ae87 and the package is 0.4.1-0.20191202200351.184ae87.el8ost

I can confirm tripleo-ansible-0.4.1-0.20191202200351.184ae87.el8ost.noarch.rpm in that puddle also contains https://review.opendev.org/696673 . So we need to figure out which cause remains unaddressed.

@Sofer, the job [1] https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/DFG/view/upgrades/view/update/job/DFG-upgrades-updates-16-from-passed_phase1-HA-ipv4/16/ paunch.log shows:

2019-12-03 14:38:43.580 47869 WARNING paunch [  ] Did not find container with "['podman', 'ps', '-a', '--filter', 'label=container_name=ironic_pxe_http', '--filter', "label=config_id=['tripleo_step4']", '--format', '{{.Names}}']" - retrying without config_id

That means that https://review.opendev.org/695921 was **not** applied (yet?) to tripleo-ansible. Then paunch executes the "bad" code (old one that seems is missing update, yet?) and still hits the config_id=['foo'] problem, which is expected to be closed by https://review.opendev.org/695921. I'm unsure why that happens. I'd expect the tripleo-ansible lib to before updated from RPM on hosts before doing any paunch executions while minor updates application is in progress.

Maybe I'm wrong, and the events logged around 2019-12-03 14:38:43 are actually expected, as represent an installation of the unpatched environment. While update starts later, at 17:09:30.

I discovered that f.e. the original keepelived container (deployed before the minor update had been started) has "config_id": "['tripleo_step1']"

That's why the updated from RPMs code cannot filter it by the fixed config_id=tripleo_step1 label!

So we need to provide a fallback here as well, as the "bad" code gets fixed by an rpm update, but not the bad state.

The fixes are being tested here: https://review.opendev.org/#/c/695242 All the patches are merged upstream.

Hi,

@ccamacho as I said all the patches are in the puddle but the error still persist.  Now what Bogdan says in https://review.opendev.org/697280 is that it's failing because the container wasn't deployed with the fix of RHOS_TRUNK-16.0-RHEL-8-20191202.n.1. which is true as it was deployed with RHOS_TRUNK-16.0-RHEL-8-20191126.n.2, to be able to run an update.

If we are seeing this only because we're starting with a puddle that will never see the light of GA and that starting with 26.n.2 it's fine, then I think that https://review.opendev.org/#/c/695242 is not stricly required for downstream (but still required for upstream)  I'll try to deploy 26.n.2 with only paunch taken from 02.n.1 to test that hypothesis.

I think we can close this as testing only issue then. The upstream bug will be kept in progress and backported for Train

So before closing it, I'll test #12, and when it's working I'll give the workaround for all downstream ci until we get a new puddle.

Hi, so first test failed.

In this one I deployed 02.n.1 with all the above patch but the last one.  Then update it to 02.n.1 This has the right version of paunch and should have prevented the issue altogether.  It should have been an easy test even not conclusive as nothing should have happened as we updating to the same version.

So something happened :)  It failed during "Run container-puppet tasks (generate config) during step 1" from the common_tasks with "You have to remove that container to be able to reuse that name.: that name is already in use"

It was on container-puppet-cinder at that time.

Full logs are there https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/DFG/view/upgrades/view/update/job/DFG-upgrades-updates-16-from-passed_phase1-HA-ipv4/17/

So, now we have two issues:
 - the name already in use still persist even with the latest paunch
 - Why run container-puppet isn't skipped when there is obviously nothing to change.

So, I confirm that the job running update from RHOS_TRUNK-16.0-RHEL-8-20191202.n.1 to RHOS_TRUNK-16.0-RHEL-8-20191202.n.1 fails during controller update in the common_step during puppet configuration:


2019-12-05 01:31:40 |         "2019-12-05 01:30:41,272 WARNING: 13199 -- Retrying running container: cinder",
2019-12-05 01:31:40 |         "2019-12-05 01:30:44,395 ERROR: 13199 -- ['/usr/bin/podman', 'run', '--user', '0', '--name', 'container-puppet-cinder', '--env', 'PUPPET_TAGS=file,file_line,concat,augeas,cron,cinder_
config,cinder_type,file,concat,file_line,cinder_config,file,concat,file_line,cinder_config,file,concat,file_line,cinder_config,file,concat,file_line', '--env', 'NAME=cinder', '--env', 'HOSTNAME=controller-2', '--e
nv', 'NO_ARCHIVE=', '--env', 'STEP=6', '--env', 'NET_HOST=true', '--env', 'DEBUG=False', '--volume', '/etc/localtime:/etc/localtime:ro', '--volume', '/tmp/tmprzcc2b6j:/etc/config.pp:ro', '--volume', '/etc/puppet/:
/tmp/puppet-etc/:ro', '--volume', '/etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro', '--volume', '/etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro', '--volume', '/etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro', '--volume', '/etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro', '--volume', '/var/lib/config-data:/var/lib/config-data/:rw', '--volume', '/var/lib/container-puppet/puppetlabs/facter.conf:/etc/puppetlabs/facter/facter.conf:ro', '--volume', '/var/lib/container-puppet/puppetlabs/:/opt/puppetlabs/:ro', '--volume', '/dev/log:/dev/log:rw', '--rm', '--log-driver', 'k8s-file', '--log-opt', 'path=/var/log/containers/stdouts/container-puppet-cinder.log', '--security-opt', 'label=disable', '--volume', '/usr/share/openstack-puppet/modules/:/usr/share/openstack-puppet/modules/:ro', '--entrypoint', '/var/lib/container-puppet/container-puppet.sh', '--net', 'host', '--volume', '/etc/hosts:/etc/hosts:ro', '--volume', '/var/lib/container-puppet/container-puppet.sh:/var/lib/container-puppet/container-puppet.sh:ro', 'undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp16-openstack-cinder-api:20191202.1'] run failed after Error: error creating container storage: the container name \"container-puppet-cinder\" is already in use by \"81838cad0d3b57e72d09ad6df8d4c494d1c5112a8984741e36f9e09890895e58\". You have to remove that container to be able to reuse that name.: that name is already in use",
2019-12-05 01:31:40 |         " attempt(s): 3",
2019-12-05 01:31:40 |         "2019-12-05 01:30:44,395 WARNING: 13199 -- Retrying running container: cinder",
2019-12-05 01:31:40 |         "2019-12-05 01:30:44,395 ERROR: 13199 -- Failed running container for cinder",
2019-12-05 01:31:40 |         "2019-12-05 01:30:44,395 INFO: 13199 -- Finished processing puppet configs for cinder",


2019-12-05 01:31:40 |         "2019-12-05 01:31:13,009 ERROR: 13205 -- ['/usr/bin/podman', 'run', '--user', '0', '--name', 'container-puppet-neutron', '--env', 'PUPPET_TAGS=file,file_line,concat,augeas,cron,neutro
n_config,neutron_api_config,neutron_plugin_ml2', '--env', 'NAME=neutron', '--env', 'HOSTNAME=controller-2', '--env', 'NO_ARCHIVE=', '--env', 'STEP=6', '--env', 'NET_HOST=true', '--env', 'DEBUG=False', '--volume', 
'/etc/localtime:/etc/localtime:ro', '--volume', '/tmp/tmpycgmu4lr:/etc/config.pp:ro', '--volume', '/etc/puppet/:/tmp/puppet-etc/:ro', '--volume', '/etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro', '--vo
lume', '/etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro', '--volume', '/etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro', '--volume', '/etc/pki/tls/cert.pem:/et
c/pki/tls/cert.pem:ro', '--volume', '/var/lib/config-data:/var/lib/config-data/:rw', '--volume', '/var/lib/container-puppet/puppetlabs/facter.conf:/etc/puppetlabs/facter/facter.conf:ro', '--volume', '/var/lib/cont
ainer-puppet/puppetlabs/:/opt/puppetlabs/:ro', '--volume', '/dev/log:/dev/log:rw', '--rm', '--log-driver', 'k8s-file', '--log-opt', 'path=/var/log/containers/stdouts/container-puppet-neutron.log', '--security-opt'
, 'label=disable', '--volume', '/usr/share/openstack-puppet/modules/:/usr/share/openstack-puppet/modules/:ro', '--entrypoint', '/var/lib/container-puppet/container-puppet.sh', '--net', 'host', '--volume', '/etc/ho
sts:/etc/hosts:ro', '--volume', '/var/lib/container-puppet/container-puppet.sh:/var/lib/container-puppet/container-puppet.sh:ro', 'undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp16-openstack-neutron-server-o
vn:20191202.1'] run failed after Error: error creating container storage: the container name \"container-puppet-neutron\" is already in use by \"34afb03989a595129c10986722bbc62650cfce2d26fbb5250adcb5eb4bccf6a0\". 
You have to remove that container to be able to reuse that name.: that name is already in use",
2019-12-05 01:31:40 |         "2019-12-05 01:31:13,009 WARNING: 13205 -- Retrying running container: neutron",
2019-12-05 01:31:40 |         "2019-12-05 01:31:13,009 ERROR: 13205 -- Failed running container for neutron",


which end up in:

2019-12-05 01:31:40 |         "2019-12-05 01:31:38,648 ERROR: 13198 -- ERROR configuring cinder",
2019-12-05 01:31:40 |         "2019-12-05 01:31:38,648 ERROR: 13198 -- ERROR configuring neutron"

This is in the artifact: undercloud.tar.gz in undercloud-0/home/stack/overcloud_update_run_Controller.log

Oki, I think I've found the real cause:

 "time=\"2019-12-04T21:55:51Z\" level=error msg=\"Error removing container 81838cad0d3b57e72d09ad6df8d4c494d1c5112a8984741e36f9e09890895e58: error removing container 81838cad0d3b57e72d09ad6df8d4c494d1c5112a8984741e36f9e09890895e58 root filesystem: unlinkat /var/lib/containers/storage/overlay/c5b17e5ef5e37441917b557a5359997ee70c043f943c14209a77c8d59a5c6e06/merged: device or resource busy\" "

in undercloud-0/var/lib/mistral/qe-Cloud-0/ansible.log in the undercloud.  So it seems we fails to remove the container, hence paunch fails later on.

Hi Bogdan, did you have a chance to look at the logs of the update from 02.n.1 to 02.n.1 puddle.  Those have errors while removing container (puppet config related container) and thus cannot be re-created during update.  You have a example log in https://bugzilla.redhat.com/show_bug.cgi?id=1779165#c15 

Thanks,

Hi,

some news, so either the latest puddle has some fixes that help with that issue or that issue doesn't happen all the time:

https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/DFG/view/upgrades/view/update/job/DFG-upgrades-updates-16-from-passed_phase1-HA-ipv4/ job 20 (RHOS_TRUNK-16.0-RHEL-8-20191206.n.1-> to itself), 19 (RHOS_TRUNK-16.0-RHEL-8-20191202.n.1 -> RHOS_TRUNK-16.0-RHEL-8-20191206.n.1)

So currently we can lower the priority of this one, and wait for a few more run to call it closed.

I had another instance of that issue during undercloud deployment at task: Run container-puppet tasks (generate config) during step 1

(while the podman run says we run STEP=6, it's a little confusing)

First:

2019-12-10 13:20:34.177 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         "2019-12-10 18:20:04,631 ERROR: 28609 -- ['/usr/bin/podman', 'run', '--user', '0', '--name', 'container-puppet-mysql', '--env', 'PUPPET_TAGS=file,file_line,concat,augeas,cron,file', '--env', 'NAME=mysql', '--env', 'HOSTNAME=undercloud-0', '--env', 'NO_ARCHIVE=', '--env', 'STEP=6', '--env', 'NET_HOST=true', '--env', 'DEBUG=False', '--volume', '/etc/localtime:/etc/localtime:ro', '--volume', '/tmp/tmpwwj184iz:/etc/config.pp:ro', '--volume', '/etc/puppet/:/tmp/puppet-etc/:ro', '--volume', '/etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro', '--volume', '/etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro', '--volume', '/etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro', '--volume', '/etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro', '--volume', '/var/lib/config-data:/var/lib/config-data/:rw', '--volume', '/var/lib/container-puppet/puppetlabs/facter.conf:/etc/puppetlabs/facter/facter.conf:ro', '--volume', '/var/lib/container-puppet/puppetlabs/:/opt/puppetlabs/:ro', '--volume', '/dev/log:/dev/log:rw', '--rm', '--log-driver', 'k8s-file', '--log-opt', 'path=/var/log/containers/stdouts/container-puppet-mysql.log', '--security-opt', 'label=disable', '--volume', '/usr/share/openstack-puppet/modules/:/usr/share/openstack-puppet/modules/:ro', '--entrypoint', '/var/lib/container-puppet/container-puppet.sh', '--net', 'host', '--volume', '/etc/hosts:/etc/hosts:ro', '--volume', '/var/lib/container-puppet/container-puppet.sh:/var/lib/container-puppet/container-puppet.sh:ro', 'undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp16-openstack-mariadb:20191202.1'] run failed after standard_init_linux.go:211: exec user process caused \"no such file or directory\"",

2019-12-10 13:20:34.177 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         "time=\"2019-12-10T18:20:01Z\" level=error msg=\"Error removing container bf0cdbdc0bc76ad5753962fa351574f6f5d1bfa443d677f2b
2839e4ccc2a0986: error removing container bf0cdbdc0bc76ad5753962fa351574f6f5d1bfa443d677f2b2839e4ccc2a0986 root filesystem: unlinkat /var/lib/containers/storage/overlay/7831a0135e378847e876b09c64769a6cbec5d5dc7aee
6d2f39accbdcdddd6df6/merged: device or resource busy\" ",
2019-12-10 13:20:34.177 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         " attempt(s): 1",
2019-12-10 13:20:34.177 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         "2019-12-10 18:20:04,631 WARNING: 28609 -- Retrying running container: mysql",
2019-12-10 13:20:34.177 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         "2019-12-10 18:20:13,083 WARNING: 28610 -- + mkdir -p /etc/puppet",
2019-12-10 13:20:34.177 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         "+ '[' -n file,file_line,concat,augeas,cron,mistral_config,mistral_config,mistral_config,mistral_config,user,group ']'",
2019-12-10 13:20:34.178 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         "+ TAGS='--tags \"file,file_line,concat,augeas,cron,mistral_config,mistral_config,mistral_config,mistral_config,user,group\
"'",

then:

2019-12-10 13:20:34.188 16627 WARNING tripleoclient.v1.tripleo_deploy.Deploy [  ]         "2019-12-10 18:20:16,118 ERROR: 28609 -- ['/usr/bin/podman', 'run', '--user', '0', '--name', 'container-puppet-mysql', '--env', 'PUPPET_TAGS=file,file_line,concat,augeas,cron,file', '--env', 'NAME=mysql', '--env', 'HOSTNAME=undercloud-0', '--env', 'NO_ARCHIVE=', '--env', 'STEP=6', '--env', 'NET_HOST=true', '--env', 'DEBUG=False', '--volume', '/etc/localtime:/etc/localtime:ro', '--volume', '/tmp/tmpwwj184iz:/etc/config.pp:ro', '--volume', '/etc/puppet/:/tmp/puppet-etc/:ro', '--volume', '/etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro', '--volume', '/etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro', '--volume', '/etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro', '--volume', '/etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro', '--volume', '/var/lib/config-data:/var/lib/config-data/:rw', '--volume', '/var/lib/container-puppet/puppetlabs/facter.conf:/etc/puppetlabs/facter/facter.conf:ro', '--volume', '/var/lib/container-puppet/puppetlabs/:/opt/puppetlabs/:ro', '--volume', '/dev/log:/dev/log:rw', '--rm', '--log-driver', 'k8s-file', '--log-opt', 'path=/var/log/containers/stdouts/container-puppet-mysql.log', '--security-opt', 'label=disable', '--volume', '/usr/share/openstack-puppet/modules/:/usr/share/openstack-puppet/modules/:ro', '--entrypoint', '/var/lib/container-puppet/container-puppet.sh', '--net', 'host', '--volume', '/etc/hosts:/etc/hosts:ro', '--volume', '/var/lib/container-puppet/container-puppet.sh:/var/lib/container-puppet/container-puppet.sh:ro', 'undercloud-0.ctlplane.redhat.local:8787/rh-osbs/rhosp16-openstack-mariadb:20191202.1'] run failed after Error: error creating container storage: the container name \"container-puppet-mysql\" is already in use by \"bf0cdbdc0bc76ad5753962fa351574f6f5d1bfa443d677f2b2839e4ccc2a0986\". You have to remove that container to be able to reuse that name.: that name is already in use",

So it seems we are retrying but as the container wasn't properly removed we are failing

Full log there https://rhos-ci-staging-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/job/DFG-upgrades-updates-16-from-passed_phase1-composable-ipv6-scale-up/11/

Note the first error "run failed after standard_init_linux.go:211: exec user process caused \"no such file or directory\"" is symptomatic of a call to a binary that's not there (search internet for it, it appears all the time)

We were able to find a temporary workaround.

1. Log into the Overcloud node(s) where the container failed to be created.
2. Modify the "/var/lib/containers/storage/overlay-containers/containers.json" file and remove the dictionary with information about the related "container-puppet-*" container. In my case, I had to do this for container-puppet-neutron and container-puppet-iscsid.
3. Delete any existing containers that relate to the service: `sudo podman ps -a | grep neutron; sudo podman rm $CONTAINER_NAME`
4. Re-run the `openstack overcloud deploy` command.

Regarding 2, here is an example dictionary that we removed:

{"id":"ec32b6dc3c8bc65dc5d39efc140e95efc8a49c3d09b46110b9721aca6303540c","names":["container-puppet-iscsid"],"image":"add324c23e9e73a0e0c8cef414a3285f9b3fcc93c6bdbe69bb0d5364f7d5c2d1","layer":"c3555bca24533c899509e4caf880c5a714faef220b241411e7e5c7fa474eddc9","metadata":"{\"image-name\":\"lshort-1.ctlplane.localdomain:8787/rh-osbs/rhosp16-openstack-iscsid:20191126.1\",\"image-id\":\"add324c23e9e73a0e0c8cef414a3285f9b3fcc93c6bdbe69bb0d5364f7d5c2d1\",\"name\":\"container-puppet-iscsid\",\"created-at\":1575419988}","created":"2019-12-04T00:39:48.21833944Z","flags":{"MountLabel":"system_u:object_r:container_file_t:s0:c105,c634","ProcessLabel":""}}

*** Bug 1788276 has been marked as a duplicate of this bug. ***

GA blocker since this BZ is dependent on podman 1.6

The fix is in the compose, Can we get blocker ack to add it to errata.

The job DFG-df-splitstack-16-virsh-3cont_3comp_3ceph-blacklist-1compute-1control-update failed due to this BZ. It is now passing:

https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/DFG/view/df/view/splitstack/job/DFG-df-splitstack-16-virsh-3cont_3comp_3ceph-blacklist-1compute-1control-update/12/

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, 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/RHEA-2020:0283

*** Bug 1791110 has been marked as a duplicate of this bug. ***