Nova instances with ephemeral disks on NFS fail with `Error writing to /var/lib/nova/instances/_base/<UUID>.part: [Errno 22] Invalid argument: IOError: [Errno 22] Invalid argument` in Red Hat OpenStack Platform 13

Issue

Nova instances with ephemeral disks on NFS fail with Error writing to /var/lib/nova/instances/_base/4c52c7914d8c60fc85ddb94078f443fb2ad4c376.part: [Errno 22] Invalid argument: IOError: [Errno 22] Invalid argument:

nova-compute.log.1:2019-08-26 20:59:49.021 1 ERROR nova.image.glance [req-3afc783e-2a33-441e-b364-cfe276d43741 d285a7fb8eec4a51871cfa296971728a 8c97d230a53048dbb9908e24ddaccbe6 - default default] Error writing to /var/lib/nova/instances/_base/4c52c7914d8c60fc85ddb94078f443fb2ad4c376.part: [Errno 22] Invalid argument: IOError: [Errno 22] Invalid argument
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [req-3afc783e-2a33-441e-b364-cfe276d43741 d285a7fb8eec4a51871cfa296971728a 8c97d230a53048dbb9908e24ddaccbe6 - default default] [instance: 0de784d1-8c03-4744-9e36-106da465b0b0] Instance failed to spawn: OSError: [Errno 22] Invalid argument
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0] Traceback (most recent call last):
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2273, in _build_resources
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     yield resources
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2053, in _build_and_run_instance
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     block_device_info=block_device_info)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3099, in spawn
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     block_device_info=block_device_info)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3477, in _create_image
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     fallback_from_host)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3568, in _create_and_inject_local_root
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     instance, size, fallback_from_host)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7663, in _try_fetch_image_cache
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     size=size)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py", line 243, in cache
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     *args, **kwargs)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py", line 597, in create_image
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     prepare_template(target=base, *args, **kwargs)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 274, in inner
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     return f(*args, **kwargs)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py", line 239, in fetch_func_sync
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     fetch_func(target=target, *args, **kwargs)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/utils.py", line 381, in fetch_image
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     images.fetch_to_raw(context, image_id, target)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/images.py", line 160, in fetch_to_raw
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     fetch(context, image_href, path_tmp)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/virt/images.py", line 151, in fetch
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     IMAGE_API.download(context, image_href, dest_path=path)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/image/api.py", line 194, in download
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     dst_path=dest_path)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/image/glance.py", line 408, in download
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     self._safe_fsync(data)
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]   File "/usr/lib/python2.7/site-packages/nova/image/glance.py", line 298, in _safe_fsync
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0]     mode = os.fstat(fileno).st_mode
nova-compute.log.1:2019-08-26 20:59:49.023 1 ERROR nova.compute.manager [instance: 0de784d1-8c03-4744-9e36-106da465b0b0] OSError: [Errno 22] Invalid argument

Upon closer analysis, this issue seems to be on the NFS level as it can be reproduced manually with dd, occasionally with touch but listing the directory works without issues:

Sometimes, writing is very slow:

[root@openstack-compute1 nova]# ll /var/lib/nova/instances/
total 12
drwxr-xr-x. 2 42436 42436 4096 Aug 29 18:12 5fd5d1a3-859b-402b-b17b-0ce0a8c0d22e_del
drwxr-xr-x. 2 42436 42436 4096 Aug 30 15:32 _base
-rw-r--r--. 1 42436 42436    0 Aug 30 15:18 compute_nodes
drwxr-xr-x. 2 42436 42436 4096 Aug 29 18:09 locks
-rw-r--r--. 1 42436 42436    0 Aug 29 19:16 me
[root@openstack-compute1 nova]# ll /var/lib/nova/instances/_base/
total 4
-rw-r--r--. 1 nobody nobody 2048 Aug 30 15:32 0a36c2b0699ba5c4b565268a20091b465f51d5ce.part
-rw-r--r--. 1  42436  42436    0 Aug 27 14:35 e020d86d1547e8c2b15af68eaef9c05a163648e5.part
[root@openstack-compute1 nova]# dd if=/dev/zero of=/var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part bs=1K count=10000
^C7+0 records in
7+0 records out
7168 bytes (7.2 kB) copied, 21.0444 s, 0.3 kB/s

Sometimes, it fails:

[root@openstack-compute1 nova]# dd if=/dev/zero of=/var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part bs=1K count=10000
dd: error writing \u2018/var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part\u2019: Invalid argument
dd: closing output file \u2018/var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part\u2019: Invalid argument
[root@openstack-compute1 nova]# touch /var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part
touch: failed to close \u2018/var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part\u2019: Invalid argument
[root@openstack-compute1 nova]# ll /var/lib/nova/instances/_base/
ls: cannot access /var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part: Invalid argument
total 0
-?????????? ? ?     ?     ?            ? 0a36c2b0699ba5c4b565268a20091b465f51d5ce.part
-rw-r--r--. 1 42436 42436 0 Aug 27 14:35 e020d86d1547e8c2b15af68eaef9c05a163648e5.part
[root@openstack-compute1 nova]# rm -f /var/lib/nova/instances/_base/0a36c2b0699ba5c4b565268a20091b465f51d5ce.part