Bug #48119: JSONDecodeErrors break OSD deploy - Orchestrator - Ceph

Actions

Copy link

Bug #48119

closed

JSONDecodeErrors break OSD deploy

Added by Michael Fritch over 3 years ago. Updated over 3 years ago.

Status:

Resolved

Priority:

Normal

Assignee:

Michael Fritch

Category:

cephadm

Target version:

% Done:

Source:

Tags:

Backport:

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

37952

Crash signature (v1):

Crash signature (v2):

Description

a/teuthology/mgfritch-2020-11-03_14:22:58-rados:cephadm-wip-mgfritch-testing-2020-11-02-1045-distro-basic-smithi/5586893/teuthology.log

2020-11-03T21:47:43.136 INFO:teuthology.orchestra.run.smithi190:> sudo cephadm --image quay.ceph.io/ceph-ci/ceph:9b3ad64c4a7e93bad1c734ad3f5c1c259af6157d shell -c /etc/ceph/ceph.conf -k /etc/ceph/ceph.client.admin.keyring --fsid c3b7212c-1e1d-11eb-a2ae-001a4aab830c -- ceph-volume lvm zap /dev/vg_nvme/lv_4
2020-11-03T21:47:44.869 INFO:teuthology.orchestra.run.smithi190.stderr:--> Zapping: /dev/vg_nvme/lv_4
2020-11-03T21:47:44.870 INFO:teuthology.orchestra.run.smithi190.stderr:Running command: /usr/bin/dd if=/dev/zero of=/dev/vg_nvme/lv_4 bs=1M count=10 conv=fsync
2020-11-03T21:47:44.870 INFO:teuthology.orchestra.run.smithi190.stderr: stderr: 10+0 records in
2020-11-03T21:47:44.870 INFO:teuthology.orchestra.run.smithi190.stderr:10+0 records out
2020-11-03T21:47:44.870 INFO:teuthology.orchestra.run.smithi190.stderr:10485760 bytes (10 MB, 10 MiB) copied, 0.0109102 s, 961 MB/s
2020-11-03T21:47:44.870 INFO:teuthology.orchestra.run.smithi190.stderr: stderr:
2020-11-03T21:47:44.870 INFO:teuthology.orchestra.run.smithi190.stderr:--> Zapping successful for: <LV: /dev/vg_nvme/lv_4>
2020-11-03T21:47:45.362 INFO:teuthology.orchestra.run.smithi190:> sudo cephadm --image quay.ceph.io/ceph-ci/ceph:9b3ad64c4a7e93bad1c734ad3f5c1c259af6157d shell -c /etc/ceph/ceph.conf -k /etc/ceph/ceph.client.admin.keyring --fsid c3b7212c-1e1d-11eb-a2ae-001a4aab830c -- ceph orch daemon add osd smithi190:vg_nvme/lv_4
2020-11-03T21:47:54.577 INFO:teuthology.orchestra.run.smithi190.stderr:Error EINVAL: Traceback (most recent call last):
2020-11-03T21:47:54.577 INFO:teuthology.orchestra.run.smithi190.stderr:  File "/usr/share/ceph/mgr/mgr_module.py", line 1195, in _handle_command
2020-11-03T21:47:54.578 INFO:teuthology.orchestra.run.smithi190.stderr:    return self.handle_command(inbuf, cmd)
2020-11-03T21:47:54.578 INFO:teuthology.orchestra.run.smithi190.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 141, in handle_command
2020-11-03T21:47:54.578 INFO:teuthology.orchestra.run.smithi190.stderr:    return dispatch[cmd['prefix']].call(self, cmd, inbuf)
2020-11-03T21:47:54.578 INFO:teuthology.orchestra.run.smithi190.stderr:  File "/usr/share/ceph/mgr/mgr_module.py", line 332, in call
2020-11-03T21:47:54.578 INFO:teuthology.orchestra.run.smithi190.stderr:    return self.func(mgr, **kwargs)
2020-11-03T21:47:54.579 INFO:teuthology.orchestra.run.smithi190.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 103, in <lambda>
2020-11-03T21:47:54.579 INFO:teuthology.orchestra.run.smithi190.stderr:    wrapper_copy = lambda *l_args, **l_kwargs: wrapper(*l_args, **l_kwargs)
2020-11-03T21:47:54.579 INFO:teuthology.orchestra.run.smithi190.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 92, in wrapper
2020-11-03T21:47:54.579 INFO:teuthology.orchestra.run.smithi190.stderr:    return func(*args, **kwargs)
2020-11-03T21:47:54.579 INFO:teuthology.orchestra.run.smithi190.stderr:  File "/usr/share/ceph/mgr/orchestrator/module.py", line 753, in _daemon_add_osd
2020-11-03T21:47:54.579 INFO:teuthology.orchestra.run.smithi190.stderr:    raise_if_exception(completion)
2020-11-03T21:47:54.580 INFO:teuthology.orchestra.run.smithi190.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 643, in raise_if_exception
2020-11-03T21:47:54.580 INFO:teuthology.orchestra.run.smithi190.stderr:    raise e
2020-11-03T21:47:54.580 INFO:teuthology.orchestra.run.smithi190.stderr:json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2020-11-03T21:47:54.580 INFO:teuthology.orchestra.run.smithi190.stderr:
2020-11-03T21:47:54.999 DEBUG:teuthology.orchestra.run:got remote process result: 22

Actions

Copy link

Updated by Michael Fritch over 3 years ago

a/teuthology/mgfritch-2020-11-03_14:22:58-rados:cephadm-wip-mgfritch-testing-2020-11-02-1045-distro-basic-smithi/5586920/teuthology.log

2020-11-03T22:15:05.260 INFO:teuthology.orchestra.run.smithi145.stderr:Error EINVAL: Traceback (most recent call last):
2020-11-03T22:15:05.261 INFO:teuthology.orchestra.run.smithi145.stderr:  File "/usr/share/ceph/mgr/mgr_module.py", line 1195, in _handle_command
2020-11-03T22:15:05.261 INFO:teuthology.orchestra.run.smithi145.stderr:    return self.handle_command(inbuf, cmd)
2020-11-03T22:15:05.261 INFO:teuthology.orchestra.run.smithi145.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 141, in handle_command
2020-11-03T22:15:05.261 INFO:teuthology.orchestra.run.smithi145.stderr:    return dispatch[cmd['prefix']].call(self, cmd, inbuf)
2020-11-03T22:15:05.261 INFO:teuthology.orchestra.run.smithi145.stderr:  File "/usr/share/ceph/mgr/mgr_module.py", line 332, in call
2020-11-03T22:15:05.261 INFO:teuthology.orchestra.run.smithi145.stderr:    return self.func(mgr, **kwargs)
2020-11-03T22:15:05.262 INFO:teuthology.orchestra.run.smithi145.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 103, in <lambda>
2020-11-03T22:15:05.262 INFO:teuthology.orchestra.run.smithi145.stderr:    wrapper_copy = lambda *l_args, **l_kwargs: wrapper(*l_args, **l_kwargs)
2020-11-03T22:15:05.262 INFO:teuthology.orchestra.run.smithi145.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 92, in wrapper
2020-11-03T22:15:05.262 INFO:teuthology.orchestra.run.smithi145.stderr:    return func(*args, **kwargs)
2020-11-03T22:15:05.262 INFO:teuthology.orchestra.run.smithi145.stderr:  File "/usr/share/ceph/mgr/orchestrator/module.py", line 753, in _daemon_add_osd
2020-11-03T22:15:05.262 INFO:teuthology.orchestra.run.smithi145.stderr:    raise_if_exception(completion)
2020-11-03T22:15:05.263 INFO:teuthology.orchestra.run.smithi145.stderr:  File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 643, in raise_if_exception
2020-11-03T22:15:05.263 INFO:teuthology.orchestra.run.smithi145.stderr:    raise e
2020-11-03T22:15:05.263 INFO:teuthology.orchestra.run.smithi145.stderr:json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2020-11-03T22:15:05.263 INFO:teuthology.orchestra.run.smithi145.stderr:
2020-11-03T22:15:05.748 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: debug 2020-11-03T22:15:05.250+0000 7ff557fff700 -1 log_channel(cephadm) log [ERR] : executing create_from_spec_one(([('smithi145', <ceph.deployment.drive_selection.selector.DriveSelection object at 0x7ff53b258278>)],)) failed.
2020-11-03T22:15:05.749 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: Traceback (most recent call last):
2020-11-03T22:15:05.749 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/utils.py", line 62, in do_work
2020-11-03T22:15:05.749 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return f(*arg)
2020-11-03T22:15:05.749 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/services/osd.py", line 43, in create_from_spec_one
2020-11-03T22:15:05.750 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     host, cmd, replace_osd_ids=osd_id_claims.get(host, []), env_vars=env_vars
2020-11-03T22:15:05.750 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/services/osd.py", line 74, in create_single_host
2020-11-03T22:15:05.750 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     osds_elems = json.loads('\n'.join(out))
2020-11-03T22:15:05.750 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/json/__init__.py", line 354, in loads
2020-11-03T22:15:05.750 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return _default_decoder.decode(s)
2020-11-03T22:15:05.750 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/json/decoder.py", line 339, in decode
2020-11-03T22:15:05.750 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     obj, end = self.raw_decode(s, idx=_w(s, 0).end())
2020-11-03T22:15:05.751 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/json/decoder.py", line 357, in raw_decode
2020-11-03T22:15:05.751 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     raise JSONDecodeError("Expecting value", s, err.value) from None
2020-11-03T22:15:05.751 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2020-11-03T22:15:05.751 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: debug 2020-11-03T22:15:05.254+0000 7ff55f55b700 -1 log_channel(cephadm) log [ERR] : _Promise failed
2020-11-03T22:15:05.751 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: Traceback (most recent call last):
2020-11-03T22:15:05.751 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 295, in _finalize
2020-11-03T22:15:05.751 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     next_result = self._on_complete(self._value)
2020-11-03T22:15:05.752 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/module.py", line 108, in <lambda>
2020-11-03T22:15:05.752 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return CephadmCompletion(on_complete=lambda _: f(*args, **kwargs))
2020-11-03T22:15:05.752 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/module.py", line 1650, in create_osds
2020-11-03T22:15:05.752 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return self.osd_service.create_from_spec(drive_group)
2020-11-03T22:15:05.752 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/services/osd.py", line 47, in create_from_spec
2020-11-03T22:15:05.752 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     ret = create_from_spec_one(self.prepare_drivegroup(drive_group))
2020-11-03T22:15:05.752 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/utils.py", line 68, in forall_hosts_wrapper
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return CephadmOrchestrator.instance._worker_pool.map(do_work, vals)
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/multiprocessing/pool.py", line 266, in map
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return self._map_async(func, iterable, mapstar, chunksize).get()
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/multiprocessing/pool.py", line 644, in get
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     raise self._value
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/multiprocessing/pool.py", line 119, in worker
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     result = (True, func(*args, **kwds))
2020-11-03T22:15:05.753 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/multiprocessing/pool.py", line 44, in mapstar
2020-11-03T22:15:05.754 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return list(map(*args))
2020-11-03T22:15:05.754 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/utils.py", line 62, in do_work
2020-11-03T22:15:05.754 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return f(*arg)
2020-11-03T22:15:05.754 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/services/osd.py", line 43, in create_from_spec_one
2020-11-03T22:15:05.754 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     host, cmd, replace_osd_ids=osd_id_claims.get(host, []), env_vars=env_vars
2020-11-03T22:15:05.754 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/cephadm/services/osd.py", line 74, in create_single_host
2020-11-03T22:15:05.755 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     osds_elems = json.loads('\n'.join(out))
2020-11-03T22:15:05.755 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/json/__init__.py", line 354, in loads
2020-11-03T22:15:05.755 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return _default_decoder.decode(s)
2020-11-03T22:15:05.755 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/json/decoder.py", line 339, in decode
2020-11-03T22:15:05.756 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     obj, end = self.raw_decode(s, idx=_w(s, 0).end())
2020-11-03T22:15:05.756 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/lib64/python3.6/json/decoder.py", line 357, in raw_decode
2020-11-03T22:15:05.756 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     raise JSONDecodeError("Expecting value", s, err.value) from None
2020-11-03T22:15:05.756 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2020-11-03T22:15:05.756 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: debug 2020-11-03T22:15:05.254+0000 7ff55f55b700 -1 mgr handle_command module 'orchestrator' command handler threw exception: Expecting value: line 1 column 1 (char 0)
2020-11-03T22:15:05.756 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: debug 2020-11-03T22:15:05.258+0000 7ff55f55b700 -1 mgr.server reply reply (22) Invalid argument Traceback (most recent call last):
2020-11-03T22:15:05.756 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/mgr_module.py", line 1195, in _handle_command
2020-11-03T22:15:05.757 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return self.handle_command(inbuf, cmd)
2020-11-03T22:15:05.757 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 141, in handle_command
2020-11-03T22:15:05.757 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return dispatch[cmd['prefix']].call(self, cmd, inbuf)
2020-11-03T22:15:05.757 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/mgr_module.py", line 332, in call
2020-11-03T22:15:05.757 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return self.func(mgr, **kwargs)
2020-11-03T22:15:05.757 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 103, in <lambda>
2020-11-03T22:15:05.757 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     wrapper_copy = lambda *l_args, **l_kwargs: wrapper(*l_args, **l_kwargs)
2020-11-03T22:15:05.758 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 92, in wrapper
2020-11-03T22:15:05.758 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     return func(*args, **kwargs)
2020-11-03T22:15:05.758 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/orchestrator/module.py", line 753, in _daemon_add_osd
2020-11-03T22:15:05.758 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     raise_if_exception(completion)
2020-11-03T22:15:05.758 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:   File "/usr/share/ceph/mgr/orchestrator/_interface.py", line 643, in raise_if_exception
2020-11-03T22:15:05.758 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]:     raise e
2020-11-03T22:15:05.758 INFO:journalctl@ceph.mgr.y.smithi145.stdout:Nov 03 22:15:05 smithi145 bash[10590]: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

Actions

Copy link