Updating image metadata fails when value contains newline (\n)

[Steve Gregory]

This is a correct request/response (Via LibCloud) to set metadata (without the newline)

The metadata I am attempting to add is: {"application_description": "10chartest", "application_version":"1"}

# -------- begin 66424056 request ----------
curl -i -X POST -H 'Host: xx.xx.xx.xx:8774' -H 'X-LC-Request-ID: 66424056' -H 'Accept-Encoding: gzip,deflate' -H 'X-Auth-Token: <REMOVED>' -H 'Content-Type: application/json; charset=UTF-8' -H 'Content-Length: 83' -H 'Accept: application/json' -H 'User-Agent: libcloud/0.14.0-beta3 (OpenStack) '
--data-binary '{"metadata": {"application_description": "10chartest", "application_version": "1"}}' --compress http://xx.xx.xx.xx:8774/v2/3db7423c206849749a77c19f347624bc/images/304fbf85-cc3f-4be6-a729-c5c9d190254f/metadata

# -------- begin 66424056:64395816 response ----------
HTTP/1.1 200 OK
Date: Thu, 16 Jan 2014 20:25:36 GMT
Content-Length: 256
Content-Type: application/json
X-Compute-Request-Id: req-99a0df3d-5432-444f-988f-fcd6d2765fe4

{"metadata": {"application_uuid": "d120cbca-1910-5542-b789-8dabc870c613", "application_description": "10chartest", "application_tags": "[\"R\", \"IGV\"]", "application_owner": "test", "application_name": "Visualization", "application_version": "1"}}
# -------- end 66424056:64395816 response ----------

This is the same request with a newline character as part of the value for the key 'application_description'
The metadata I am attempting to add is: {"application_description": "10char\ntest", "application_version":"1"}

# -------- begin 66422544 request ----------
curl -i -X POST -H 'Host: xx.xx.xx.xx:8774' -H 'X-LC-Request-ID: 66422544' -H 'Accept-Encoding: gzip,deflate' -H 'X-Auth-Token: <REMOVED>' -H 'Content-Type: application/json; charset=UTF-8' -H 'Content-Length: 85' -H 'Accept: application/json' -H 'User-Agent: libcloud/0.14.0-beta3 (OpenStack) '
 --data-binary '{"metadata": {"application_description": "10char\ntest", "application_version": "1"}}' --compress http://xx.xx.xx.xx:8774/v2/3db7423c206849749a77c19f347624bc/images/304fbf85-cc3f-4be6-a729-c5c9d190254f/metadata
# -------- begin 66422544:64395816 response ----------
HTTP/1.1 200 OK
Date: Thu, 16 Jan 2014 20:25:46 GMT
Content-Length: 224
Content-Type: application/json
X-Compute-Request-Id: req-00caedb5-dedc-44fe-95e4-b48cf93e64ba

{"metadata": {"application_name": "Visualization", "application_uuid": "d120cbca-1910-5542-b789-8dabc870c613", "application_description": "10char", "application_owner": "test", "application_tags": "[\"R\", \"IGV\"]"}}
# -------- end 66422544:64395816 response ----------

The second request has two errors:

1. All of the characters following the \n have been removed from the metadata
2. The 'application_version' metadata key-value pair has also been deleted from the image's metadata.

Other notes:

In my testing of this error, the application_version metadata item would be deleted even if it previously existed in image metadata and even when application_version was never intended to be set in the request above.

The 'maxImageMeta' is set to 128, so the # of metadata items should not be limited, and the response is returning a 200 OK, even when the output data does not match the input data, and whole metadata items are missing.

[Steve Gregory (steve-gregory)]

I looked into this a little more and I found that the problem occurred because the \n character is not valid json, and that the value should have been \\n.

However, instead of returning an error, the server returned a 200 with the metadata up to the point the error occurred.

No error was detected in nova-api.log

[Maithem (maithem)]

can you past the corresponding log snippet?

[Steve Gregory (steve-gregory)]

Here is the corresponding log snippet. It appears that when nova passes the data to glance the text after the illegal \n character and the application_version tag have already been removed. Both return success

From nova-api.log:
---------------------------
2014-01-21 09:40:28.132 9373 INFO nova.osapi_compute.wsgi.server [req-e787f632-0eaf-4ad6-a9c7-d4487ef4d1d2 d8421a6882fc4613a2d2f878036c7b78 3db7423c206849749a77c19f347624bc] xx.xx.xx.xx "POST /v2/3db7423c206849749a77c19f347624bc/images/071e1289-531c-4e9c-bed2-08af23931f6b/metadata HTTP/1.1" status: 200 len: 355 time: 0.4346108
---------------------------

From glance server's registry.log:
---------------------------
2014-01-21 09:40:27.967 47830 INFO glance.registry.api.v1.members [] Returning member list for image 071e1289-531c-4e9c-bed2-08af23931f6b
2014-01-21 09:40:28.037 47830 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token ... /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:585
2014-01-21 09:40:28.039 47830 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token ... /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:976
2014-01-21 09:40:28.040 47830 DEBUG routes.middleware [-] Matched PUT /images/071e1289-531c-4e9c-bed2-08af23931f6b ...
2014-01-21 09:40:28.040 47830 DEBUG routes.middleware [-] Route path: '/images/{id}', defaults: {'action': u'update', 'controller': <glance.common.wsgi.Resource object at 0x37caf90>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-01-21 09:40:28.041 47830 DEBUG routes.middleware [-] Match dict: {'action': u'update', 'controller': <glance.common.wsgi.Resource object at 0x37caf90>, 'id': u'071e1289-531c-4e9c-bed2-08af23931f6b'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-01-21 09:40:28.042 47830 DEBUG glance.registry.api.v1.images [371b6386-7861-4787-a810-1e3a9cf5e6a2 d8421a6882fc4613a2d2f878036c7b78 3db7423c206849749a77c19f347624bc]

Updating image 071e1289-531c-4e9c-bed2-08af23931f6b with metadata: {u'owner': u'b3ba766fc3124e8c8ddad50dca855dd7', u'container_format': u'ami', u'disk_format': u'ami', u'name': u'Tuxedo Workbench2', u'properties': {u'test_flag': u'"go_flag"', u'application_name': u'Tuxedo Workbench2', u'application_description': u'twoline', u'application_owner': u'atmoadmin', u'how_many': u'"make_it"'}} update /usr/lib/python2.7/dist-packages/glance/registry/api/v1/images.py:436

2014-01-21 09:40:28.104 47830 INFO glance.registry.api.v1.images [371b6386-7861-4787-a810-1e3a9cf5e6a2 d8421a6882fc4613a2d2f878036c7b78 3db7423c206849749a77c19f347624bc] Updating metadata for image 071e1289-531c-4e9c-bed2-08af23931f6b
---------------------------

[Joe Gordon (jogo)]

It looks like this is a glance issue underneath

[Feilong Wang (flwang)]

I haven't try to recreate this issue. But before that, may I know any specific user cases about why we need a \n in image metadata? Thanks.

[Steve Gregory (steve-gregory)]

Hi Fei Long Wang,

Thank you for looking in to this. One of our image metadata keys is 'application_description' and it takes multi-line input from the user. The tag allows users to inform others about what their image contains, when and how it should be launched, etc. and in some cases that description will span many lines.

Thanks,
Steve Gregory

[Feilong Wang (flwang)]

Hi Steve, I just tested it with latest code. if there are \n in the metadata, after create image, the \ will be removed. For example, if you input 'hello\ngood', then you will get 'hellongood'

I'm wondering if Nova is impacting something.

flwang@flwang-ThinkPad-X230:~$ glance image-update 0169b354-0d42-4bc6-9cf1-b2d3a4a60bde --property bbb=hello\ngood
+------------------+--------------------------------------+
| Property | Value |
+------------------+--------------------------------------+
| Property 'aaa' | hello |
| Property 'bbb' | hellongood |
| checksum | None |
| container_format | bare |
| created_at | 2014-02-10T14:19:44 |
| deleted | False |
| deleted_at | None |
| disk_format | raw |
| id | 0169b354-0d42-4bc6-9cf1-b2d3a4a60bde |
| is_public | False |
| min_disk | 0 |
| min_ram | 0 |
| name | havana_location_1 |
| owner | 82d65617aa3244dba88a316234c5fd4e |
| protected | False |
| size | 9761280 |
| status | active |
| updated_at | 2014-02-10T15:50:39 |
+------------------+--------------------------------------+

[Steve Gregory (steve-gregory)]

I belive it may be the combination of nova-to-glance..

In a somewhat-related note I have also noticed metadata inconsistencies when I enter a JSON array into metadata

i.e. {"bbb":["one","two","three"]}

nova returns a failure, so I must convert the array to string on write and back to an array on reads..

Is this working via. glance, or are both problems somehow related to how novaclient is contacting glance?

[Ankit Agrawal (ankitagrawal)]

Hi, I tested this issue with latest code and found following points

1. Call glance api update image using curl command (with metadata 'tesinsg\nisssue')
$ curl -i 'http://10.69.4.178:9292/v1/images/ce33c155-91bc-4b85-b9d0-a8735b35536f' -X PUT -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'User-Agent: python-glanceclient' -H 'x-glance-registry-purge-props: false' -H 'Content-Type: application/octet-stream' -H 'X-Auth-Token: 5552cacaade544ceade9489317b4d446' -H 'x-image-meta-property-test: tesinsg\nisssue'

Result: Status 200. There is no issue and metadata value is saved as it is (with containing '\n').

2. Update image using python-glanceclient
$ glance image-update ce33c155-91bc-4b85-b9d0-a8735b35536f --property testkey=akt\nagrawal

Result: Status 200. '\' is removed from the metadata value and stored value will be testkey=aktnagrawal ('\' is removed).
Analysis: '\' is a special character in python which is escaped by "sys.argv".

The correct ways to add new line using python-glanceclient
a) $ glance image-update ce33c155-91bc-4b85-b9d0-a8735b35536f --property testkey=akt\\nagrawal -- (with '\\n')
b) $ glance image-update ce33c155-91bc-4b85-b9d0-a8735b35536f --property testkey='akt\nagrawal'
c) $ glance image-update ce33c155-91bc-4b85-b9d0-a8735b35536f --property testkey="akt\nagrawal"

3. Call nova api update image using curl command
$ curl -i 'http://10.69.4.178:8774/v2/8327f833d88c42d693d9b38d3400565c/images/ce33c155-91bc-4b85-b9d0-a8735b35536f/metadata' -X POST -H "Accept: application/json" -H "Content-Type: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Project-Id: admin" -H "X-Auth-Token: 5552cacaade544ceade9489317b4d446" -d '{"metadata": {"key1": "firstline\nsecondline", "application_version": "1"}}'

Result: Status 200. All the characters after (including) '\n' is removed from the metadata value.

Data is being lost when calling "self.session.request()" method from "_request" method of python-glanceclient/glanceclient/common/http.py module.
self.session is an object of requests.Session() which is a third party library, so IMO this issue can not be handled from glance or glance-client.

The correct way to add new line in metadata is to send with "\\n".

[Ian Cordasco (icordasc)]

Ankit, as a core-developer of requests I suspect you either missed something that is causing problems with nova using glanceclient's wrapper around a requests Session OR this is something in novaclient. If you're simply passing the data straight through to requests without modifying it yourself and you have no bizarre adapters mounted to the session that could be causing this, then requests is absolutely not responsible for this. We do 0 munging of user data if we're passed a string-y type (bytes or unicode). When I have time, I'll see if I can find what's munging this so thank you for the detailed steps to reproduce but I can say with certainty that this is not a requests bug.

[Ian Cordasco (icordasc)]

I set up a clean instance of devstack today and did the following:

root@ian-devstack-glance:~# nova image-meta 34763240-9a37-4891-ad37-c5861b1edee9 set key=value
root@ian-devstack-glance:~# nova image-show 34763240-9a37-4891-ad37-c5861b1edee9
+----------------------+--------------------------------------+
| Property | Value |
+----------------------+--------------------------------------+
| OS-EXT-IMG-SIZE:size | 4969360 |
| created | 2014-12-26T17:29:45Z |
| id | 34763240-9a37-4891-ad37-c5861b1edee9 |
| metadata key | value |
| minDisk | 0 |
| minRam | 0 |
| name | cirros-0.3.2-x86_64-uec-kernel |
| progress | 100 |
| status | ACTIVE |
| updated | 2014-12-26T21:32:09Z |
+----------------------+--------------------------------------+
root@ian-devstack-glance:~# nova image-meta 34763240-9a37-4891-ad37-c5861b1edee9 set key2='value\nnewline'
root@ian-devstack-glance:~# nova image-show 34763240-9a37-4891-ad37-c5861b1edee9
+----------------------+--------------------------------------+
| Property | Value |
+----------------------+--------------------------------------+
| OS-EXT-IMG-SIZE:size | 4969360 |
| created | 2014-12-26T17:29:45Z |
| id | 34763240-9a37-4891-ad37-c5861b1edee9 |
| metadata key | value |
| metadata key2 | value |
| | newline |
| minDisk | 0 |
| minRam | 0 |
| name | cirros-0.3.2-x86_64-uec-kernel |
| progress | 100 |
| status | ACTIVE |
| updated | 2014-12-26T21:32:35Z |
+----------------------+--------------------------------------+

====

Note that the metadata value for key2 is "value\nnewline" and it both accepts and prints it appropriately. I cannot reproduce this.

[Cyril Roelandt (cyril-roelandt)]

I think this particular API and its associated command (nova image-meta) have been deprecated for a while.

I see no specific Glance issue here; feel free to reopen if you think otherwise.