Log messages with json hide errors

[yellowpattern]

Any errors with the SSL request to the FreeNAS server result in a JSON exception being thrown:

INFO cinder.volume.drivers.ixsystems.iscsi [req-9ec315ec-40bb-4445-8865-57525c88cbe7 - - - - -] iXsystems Do Setup INFO cinder.volume.drivers.ixsystems.iscsi [req-9ec315ec-40bb-4445-8865-57525c88cbe7 - - - - -] iXSystems: Check For Setup Error INFO cinder.volume.drivers.ixsystems.iscsi [req-9ec315ec-40bb-4445-8865-57525c88cbe7 - - - - -] iXSystems: Check For Setup Error INFO cinder.volume.drivers.ixsystems.iscsi [req-9ec315ec-40bb-4445-8865-57525c88cbe7 - - - - -] iXsystems Get Volume Status ... ERROR oslo_service.service [req-9ec315ec-40bb-4445-8865-57525c88cbe7 - - - - -] Error starting thread.: JSONDecodeError: Extra data: line 1 column 4 - line 1 column 17 (char 3 - 16) ERROR oslo_service.service Traceback (most recent call last): ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/oslo_service/service.py", line 810, in run_service ERROR oslo_service.service service.start() ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/cinder/service.py", line 229, in start ERROR oslo_service.service service_id=Service.service_id) ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 445, in init_host ERROR oslo_service.service self._init_host(added_to_cluster, **kwargs) ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 479, in _init_host ERROR oslo_service.service self.driver.init_capabilities() ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 746, in init_capabilities ERROR oslo_service.service stats = self.get_volume_stats(True) ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 198, in get_volume_stats ERROR oslo_service.service self.stats = self.common._update_volume_stats() ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/common.py", line 355, in _update_volume_stats ERROR oslo_service.service respid = json.loads(ret['response']) ERROR oslo_service.service File "/usr/lib64/python2.7/site-packages/simplejson/init.py", line 516, in loads ERROR oslo_service.service return _default_decoder.decode(s) ERROR oslo_service.service File "/usr/lib64/python2.7/site-packages/simplejson/decoder.py", line 380, in decode ERROR oslo_service.service raise JSONDecodeError("Extra data", s, end, len(s)) ERROR oslo_service.service JSONDecodeError: Extra data: line 1 column 4 - line 1 column 17 (char 3 - 16)

This hides the real error which is not discoverable without hacking the python.

[dmcgrandle]

You can also set the logging to DEBUG, which outputs a lot more information including the REST API information being attempted. But I've found the best way to get at this info is to take a wireshark capture - that shows exactly what was sent to the server and exactly what the response was.

[yellowpattern]

Using wireshark on an SSL destination requires more effort (need to load on the certificate & key) and I sometimes prefer not to have to use wireshark for everything.

I was hoping that there would be an easier way to discover the errors.

[dmcgrandle]

Yeah, about SSL - I also needed to load a valid cert on the FreeNAS box to get the driver working initially. However, after getting it working, I then removed the cert and just used unencrypted http and it continued to work. My cinder.conf now just uses the IP address again and no cert on the server. I didn't get a packet capture of the original issue though, and would have to re-install either my storage node and/or FreeNAS system again to recreate in order to capture more data and troubleshoot. I likely won't go to that much effort until I'm setting up OpenStack again.

[dmcgrandle]

@yellowpattern - You may be interested to know that now (since the latest pull request was merged) this driver also exposes the error message from the HTTP body JSON that is returned from the server in the case of an HTTP error, and logs it at INFO level back to the logging system, so this should show up in /var/log/cinder/cinder-volume.log now to help with troubleshooting.