Open Stack

On 09/24/2015 10:54 AM, Chris Friesen wrote:

> I took another look at the code and realized that the file *should* get rebuilt
> on restart after a power outage--if the file already exists it will print a
> warning message in the logs but it should still overwrite the contents of the
> file with the desired contents.  However, that didn't happen in my case.
>
> That made me confused about how I ever ended up with an empty persistence file.
>   I went back to my logs and found this:
>
> File "./usr/lib64/python2.7/site-packages/cinder/volume/manager.py", line 334,
> in init_host
> File "/usr/lib64/python2.7/site-packages/osprofiler/profiler.py", line 105, in
> wrapper
> File "./usr/lib64/python2.7/site-packages/cinder/volume/drivers/lvm.py", line
> 603, in ensure_export
> File "./usr/lib64/python2.7/site-packages/cinder/volume/targets/iscsi.py", line
> 296, in ensure_export
> File "./usr/lib64/python2.7/site-packages/cinder/volume/targets/tgt.py", line
> 185, in create_iscsi_target
> TypeError: not enough arguments for format string
>
>
> So it seems like we might have a bug in the handling of an empty file.

And I think I know how we got the empty file in the first place, and it wasn't 
the original file creation but rather the file re-creation.

I have logs from shortly before the above logs showing cinder-volume receiving a 
SIGTERM while it was processing the volume in question:


2015-09-21 19:23:59.123 12429 WARNING cinder.volume.targets.tgt 
[req-7d092503-198a-4f59-97e9-d4d520d38379 - - - - -] Persistence file already 
exists for volume, found file at: 
/opt/cgcs/cinder/data/volumes/volume-76c5f285-a15e-474e-b59e-fd609a624090
2015-09-21 19:24:01.252 12429 WARNING cinder.volume.targets.tgt 
[req-7d092503-198a-4f59-97e9-d4d520d38379 - - - - -] Persistence file already 
exists for volume, found file at: 
/opt/cgcs/cinder/data/volumes/volume-993c94b2-e256-4baf-ab55-805a8e28f547
2015-09-21 19:24:01.951 8201 INFO cinder.openstack.common.service 
[req-904f88a8-8e6f-425e-8df7-5cbb9baae0c5 - - - - -] Caught SIGTERM, stopping 
children


I think what happened is that we took the SIGTERM after the open() call in 
create_iscsi_target(), but before writing anything to the file.

         f = open(volume_path, 'w+')
         f.write(volume_conf)
         f.close()

The 'w+' causes the file to be immediately truncated on opening, leading to an 
empty file.

To work around this, I think we need to do the classic "write to a temporary 
file and then rename it to the desired filename" trick.  The atomicity of the 
rename ensures that either the old contents or the new contents are present.

Chris