yahoo-eng-team team mailing list archive

[Matt Riedemann <mriedem.os@xxxxxxxxx>]

Public bug reported:

Seen here:

http://logs.openstack.org/43/619143/12/check/nova-
lvm/786180c/logs/screen-n-cpu.txt.gz?level=TRACE#_Dec_12_12_35_39_607002

Dec 12 12:35:39.607002 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [None req-107a6ea1-f573-4c73-b191-2498e9d6d5ea tempest-AutoAllocateNetworkTest-1112737108 tempest-AutoAllocateNetworkTest-1112737108] [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] Instance failed to spawn: ArgsAlreadyParsedError: arguments already parsed
Dec 12 12:35:39.607240 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] Traceback (most recent call last):
Dec 12 12:35:39.607458 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/compute/manager.py", line 2361, in _build_resources
Dec 12 12:35:39.607676 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     yield resources
Dec 12 12:35:39.607886 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/compute/manager.py", line 2125, in _build_and_run_instance
Dec 12 12:35:39.608118 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     block_device_info=block_device_info)
Dec 12 12:35:39.608334 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3063, in spawn
Dec 12 12:35:39.608549 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     block_device_info=block_device_info)
Dec 12 12:35:39.608761 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3441, in _create_image
Dec 12 12:35:39.608975 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     fallback_from_host)
Dec 12 12:35:39.609190 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3532, in _create_and_inject_local_root
Dec 12 12:35:39.609415 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     instance, size, fallback_from_host)
Dec 12 12:35:39.609654 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 7830, in _try_fetch_image_cache
Dec 12 12:35:39.609878 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     trusted_certs=instance.trusted_certs)
Dec 12 12:35:39.610094 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 243, in cache
Dec 12 12:35:39.610310 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     *args, **kwargs)
Dec 12 12:35:39.610524 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 763, in create_image
Dec 12 12:35:39.610758 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     create_lvm_image(base, size)
Dec 12 12:35:39.610973 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 328, in inner
Dec 12 12:35:39.611198 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     return f(*args, **kwargs)
Dec 12 12:35:39.611423 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 731, in create_lvm_image
Dec 12 12:35:39.611639 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     run_as_root=True)
Dec 12 12:35:39.611852 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/images.py", line 117, in convert_image_unsafe
Dec 12 12:35:39.612060 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     _convert_image(source, dest, None, out_format, run_as_root)
Dec 12 12:35:39.612272 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/images.py", line 128, in _convert_image
Dec 12 12:35:39.612506 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     source, dest, in_format, out_format, CONF.instances_path)
Dec 12 12:35:39.612745 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/usr/local/lib/python2.7/dist-packages/oslo_privsep/priv_context.py", line 207, in _wrap
Dec 12 12:35:39.612960 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     return self.channel.remote_call(name, args, kwargs)
Dec 12 12:35:39.613174 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/usr/local/lib/python2.7/dist-packages/oslo_privsep/daemon.py", line 202, in remote_call
Dec 12 12:35:39.613393 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     raise exc_type(*result[2])
Dec 12 12:35:39.613616 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] ArgsAlreadyParsedError: arguments already parsed
Dec 12 12:35:39.613830 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] 

The nova-lvm job is currently non-voting which is why no one probably
noticed the regression.

https://github.com/openstack/nova/blob/c72dafad8011198b78fd906f2fc7d1126e3f79f3/.zuul.yaml#L115

** Affects: nova
     Importance: Medium
         Status: Confirmed


** Tags: libvirt lvm privsep

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1808247

Title:
  nova-lvm job failing with ArgsAlreadyParsedError (privsep)

Status in OpenStack Compute (nova):
  Confirmed

Bug description:
  Seen here:

  http://logs.openstack.org/43/619143/12/check/nova-
  lvm/786180c/logs/screen-n-cpu.txt.gz?level=TRACE#_Dec_12_12_35_39_607002

  Dec 12 12:35:39.607002 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [None req-107a6ea1-f573-4c73-b191-2498e9d6d5ea tempest-AutoAllocateNetworkTest-1112737108 tempest-AutoAllocateNetworkTest-1112737108] [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] Instance failed to spawn: ArgsAlreadyParsedError: arguments already parsed
  Dec 12 12:35:39.607240 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] Traceback (most recent call last):
  Dec 12 12:35:39.607458 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/compute/manager.py", line 2361, in _build_resources
  Dec 12 12:35:39.607676 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     yield resources
  Dec 12 12:35:39.607886 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/compute/manager.py", line 2125, in _build_and_run_instance
  Dec 12 12:35:39.608118 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     block_device_info=block_device_info)
  Dec 12 12:35:39.608334 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3063, in spawn
  Dec 12 12:35:39.608549 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     block_device_info=block_device_info)
  Dec 12 12:35:39.608761 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3441, in _create_image
  Dec 12 12:35:39.608975 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     fallback_from_host)
  Dec 12 12:35:39.609190 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3532, in _create_and_inject_local_root
  Dec 12 12:35:39.609415 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     instance, size, fallback_from_host)
  Dec 12 12:35:39.609654 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 7830, in _try_fetch_image_cache
  Dec 12 12:35:39.609878 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     trusted_certs=instance.trusted_certs)
  Dec 12 12:35:39.610094 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 243, in cache
  Dec 12 12:35:39.610310 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     *args, **kwargs)
  Dec 12 12:35:39.610524 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 763, in create_image
  Dec 12 12:35:39.610758 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     create_lvm_image(base, size)
  Dec 12 12:35:39.610973 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 328, in inner
  Dec 12 12:35:39.611198 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     return f(*args, **kwargs)
  Dec 12 12:35:39.611423 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 731, in create_lvm_image
  Dec 12 12:35:39.611639 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     run_as_root=True)
  Dec 12 12:35:39.611852 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/images.py", line 117, in convert_image_unsafe
  Dec 12 12:35:39.612060 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     _convert_image(source, dest, None, out_format, run_as_root)
  Dec 12 12:35:39.612272 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/opt/stack/new/nova/nova/virt/images.py", line 128, in _convert_image
  Dec 12 12:35:39.612506 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     source, dest, in_format, out_format, CONF.instances_path)
  Dec 12 12:35:39.612745 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/usr/local/lib/python2.7/dist-packages/oslo_privsep/priv_context.py", line 207, in _wrap
  Dec 12 12:35:39.612960 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     return self.channel.remote_call(name, args, kwargs)
  Dec 12 12:35:39.613174 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]   File "/usr/local/lib/python2.7/dist-packages/oslo_privsep/daemon.py", line 202, in remote_call
  Dec 12 12:35:39.613393 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68]     raise exc_type(*result[2])
  Dec 12 12:35:39.613616 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] ArgsAlreadyParsedError: arguments already parsed
  Dec 12 12:35:39.613830 ubuntu-xenial-rax-iad-0001148680 nova-compute[29772]: ERROR nova.compute.manager [instance: d0a6774a-7b73-431b-8768-706e4e4fcc68] 

  The nova-lvm job is currently non-voting which is why no one probably
  noticed the regression.

  https://github.com/openstack/nova/blob/c72dafad8011198b78fd906f2fc7d1126e3f79f3/.zuul.yaml#L115

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1808247/+subscriptions