2020-11-09 11:33:36.361 6 DEBUG oslo_service.service [req-7908b3ee-483d-46de-9e36-06d50a320c58 - - - - -] Started child 1953 _start_child /usr/lib/python3/dist-packages/oslo_service/service.py:579
2020-11-09 11:33:36.366 1953 INFO cinder.service [-] Starting cinder-volume node (version 16.2.0)
2020-11-09 11:33:36.387 1953 INFO cinder.volume.manager [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] Starting volume driver FreeNASISCSIDriver (2.0.0)
2020-11-09 11:33:36.388 1953 INFO cinder.volume.drivers.ixsystems.iscsi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] iXsystems Do Setup
2020-11-09 11:33:36.388 1953 INFO cinder.volume.drivers.ixsystems.iscsi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] iXSystems: Check For Setup Error
2020-11-09 11:33:36.389 1953 DEBUG cinder.volume.drivers.ixsystems.common [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] Using iXsystems FREENAS server: os-truenas.martellotech.com _create_handle /usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/common.py:40
2020-11-09 11:33:36.389 1953 INFO cinder.volume.drivers.ixsystems.iscsi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] iXSystems: Check For Setup Error
2020-11-09 11:33:36.389 1953 INFO cinder.volume.drivers.ixsystems.iscsi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] iXsystems Get Volume Status
2020-11-09 11:33:36.390 1953 DEBUG cinder.volume.drivers.ixsystems.common [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] _update_volume_stats request_urn : /storage/volume/HDDs/ _update_volume_stats /usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/common.py:359
2020-11-09 11:33:36.390 1953 DEBUG cinder.volume.drivers.ixsystems.freenasapi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] invoke_command invoke_command /usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/freenasapi.py:184
2020-11-09 11:33:36.390 1953 DEBUG cinder.volume.drivers.ixsystems.freenasapi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] url :
http://os-truenas.martellotech.com/api/v1.0/storage/volume/HDDs/, request: /storage/volume/HDDs/ _create_request /usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/freenasapi.py:129
2020-11-09 11:33:36.390 1953 DEBUG cinder.volume.drivers.ixsystems.freenasapi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] param list : None _create_request /usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/freenasapi.py:130
2020-11-09 11:33:36.407 1953 DEBUG cinder.volume.drivers.ixsystems.freenasapi [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] invoke_command : response for request /storage/volume/HDDs/ : {"status": "ok", "response": [TrueNAS Loading Page HTML] } _update_volume_stats /usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/common.py:362
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service [req-e020089b-5f77-40fd-9015-bf26651c929e - - - - -] Error starting thread.: simplejson.errors.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service Traceback (most recent call last):
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/oslo_service/service.py", line 810, in run_service
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service service.start()
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/cinder/service.py", line 229, in start
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service service_id=Service.service_id)
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 443, in init_host
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service self._init_host(added_to_cluster, **kwargs)
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 477, in _init_host
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service self.driver.init_capabilities()
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/cinder/volume/driver.py", line 770, in init_capabilities
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service stats = self.get_volume_stats(True)
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 199, in get_volume_stats
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service self.stats = self.common._update_volume_stats()
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/cinder/volume/drivers/ixsystems/common.py", line 368, in _update_volume_stats
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service data['total_capacity_gb'] = ix_utils.get_size_in_gb(json.loads(ret['response'])['avail'] + json.loads(ret['response'])['used'])
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/simplejson/__init__.py", line 518, in loads
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service return _default_decoder.decode(s)
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/simplejson/decoder.py", line 370, in decode
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service obj, end = self.raw_decode(s)
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service File "/usr/lib/python3/dist-packages/simplejson/decoder.py", line 400, in raw_decode
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service return self.scan_once(s, idx=_w(s, idx).end())
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service simplejson.errors.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2020-11-09 11:33:36.408 1953 ERROR oslo_service.service
2020-11-09 11:33:36.412 1953 DEBUG oslo_concurrency.lockutils [req-7908b3ee-483d-46de-9e36-06d50a320c58 - - - - -] Acquired lock "singleton_lock" lock /usr/lib/python3/dist-packages/oslo_concurrency/lockutils.py:265
2020-11-09 11:33:36.412 1953 DEBUG oslo_concurrency.lockutils [req-7908b3ee-483d-46de-9e36-06d50a320c58 - - - - -] Releasing lock "singleton_lock" lock /usr/lib/python3/dist-packages/oslo_concurrency/lockutils.py:281
2020-11-09 11:33:36.424 6 INFO oslo_service.service [req-7908b3ee-483d-46de-9e36-06d50a320c58 - - - - -] Child 1953 exited with status 1
2020-11-09 11:33:36.425 6 INFO oslo_service.service [req-7908b3ee-483d-46de-9e36-06d50a320c58 - - - - -] Forking too fast, sleeping