Project

General

Profile

Bug #25148

Updated by Nathan Cutler over 5 years ago

h3. What?

Apparent race condition in upgrade test

h3. Where?

It happened in the upgrade test @upgrade:luminous-x/parallel/{0-cluster/{openstack.yaml start.yaml} 1-ceph-install/luminous.yaml 2-workload/{blogbench.yaml ec-rados-default.yaml rados_api.yaml rados_loadgenbig.yaml rgw_ragweed_prepare.yaml test_rbd_api.yaml test_rbd_python.yaml} 3-upgrade-sequence/upgrade-all.yaml 4-final-workload/{blogbench.yaml rados-snaps-few-objects.yaml rados_loadgenmix.yaml rados_mon_thrash.yaml rbd_cls.yaml rbd_import_export.yaml rgw.yaml rgw_ragweed_check.yaml rgw_swift.yaml} objectstore/filestore-xfs.yaml supported-all-distro/centos_latest.yaml}@

Logs: http://pulpito.ceph.com/smithfarm-2018-07-27_03:56:15-upgrade:luminous-x-wip-smithfarm-testing-distro-basic-smithi/2823058/

h3. .h3 Analysis (such as it is)

mds.a is stopped:

<pre>2018-07-29T03:37:40.288 INFO:tasks.ceph.mds.a:Stopped
2018-07-29T03:37:40.288 INFO:teuthology.orchestra.run.smithi134:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage daemon-helper kill ceph-mds -f --cluster ceph -i a'
</pre>

The command "ceph --cluster ceph --admin-daemon /var/run/ceph/ceph-mds.a.asok session ls" is run on the stopped mds's asok:

<pre>2018-07-29T03:37:40.290 INFO:teuthology.orchestra.run.smithi134:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 0 ceph --cluster ceph --admin-daemon /var/run/ceph/ceph-mds.a.asok session ls'
2018-07-29T03:37:40.330 INFO:tasks.ceph.mds.a:Started
</pre>

With the result:

<pre>2018-07-29T03:37:40.482 INFO:tasks.ceph.mds.a.smithi134.stdout:starting mds.a at
2018-07-29T03:37:40.530 INFO:teuthology.orchestra.run.smithi134.stdout:"mds_not_active"
2018-07-29T03:37:40.531 INFO:teuthology.orchestra.run.smithi134.stdout:failed
2018-07-29T03:37:40.531 INFO:tasks.cephfs.filesystem:_json_asok output: "mds_not_active"
failed
2018-07-29T03:37:40.531 ERROR:teuthology.run_tasks:Saw exception from tasks.
Traceback (most recent call last):
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 86, in run_tasks
manager = run_one_task(taskname, ctx=ctx, config=config)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task
return task(**kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/parallel.py", line 55, in task
p.spawn(_run_spawned, ctx, confg, taskname)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/parallel.py", line 85, in __exit__
for result in self:
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/parallel.py", line 99, in next
resurrect_traceback(result)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/parallel.py", line 22, in capture_traceback
return func(*args, **kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/parallel.py", line 63, in _run_spawned
mgr = run_tasks.run_one_task(taskname, ctx=ctx, config=config)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task
return task(**kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/full_sequential.py", line 30, in task
mgr = run_tasks.run_one_task(taskname, ctx=ctx, config=confg)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task
return task(**kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/sequential.py", line 48, in task
mgr.__enter__()
File "/usr/lib/python2.7/contextlib.py", line 17, in __enter__
return self.gen.next()
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/ceph_fuse.py", line 136, in task
mount.mount()
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/fuse_mount.py", line 33, in mount
return self._mount(mount_path, mount_fs_name)
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/fuse_mount.py", line 161, in _mount
self.gather_mount_info()
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/fuse_mount.py", line 170, in gather_mount_info
sessions = self.fs.rank_asok(['session', 'ls'])
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/filesystem.py", line 920, in rank_asok
return self.json_asok(command, 'mds', info['name'])
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/filesystem.py", line 180, in json_asok
return json.loads(response_data)
File "/usr/lib/python2.7/json/__init__.py", line 339, in loads
return _default_decoder.decode(s)
File "/usr/lib/python2.7/json/decoder.py", line 367, in decode
raise ValueError(errmsg("Extra data", s, end, len(s)))
ValueError: Extra data: line 2 column 1 - line 2 column 7 (char 17 - 23)
2018-07-29T03:37:40.572 ERROR:teuthology.run_tasks: Sentry event: http://sentry.ceph.com/sepia/teuthology/?q=69a609d9c5cb4f04b2d8d2a04f1ec98d
Traceback (most recent call last):
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 86, in run_tasks
manager = run_one_task(taskname, ctx=ctx, config=config)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task
return task(**kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/parallel.py", line 55, in task
p.spawn(_run_spawned, ctx, confg, taskname)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/parallel.py", line 85, in __exit__
for result in self:
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/parallel.py", line 99, in next
resurrect_traceback(result)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/parallel.py", line 22, in capture_traceback
return func(*args, **kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/parallel.py", line 63, in _run_spawned
mgr = run_tasks.run_one_task(taskname, ctx=ctx, config=config)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task
return task(**kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/full_sequential.py", line 30, in task
mgr = run_tasks.run_one_task(taskname, ctx=ctx, config=confg)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task
return task(**kwargs)
File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/task/sequential.py", line 48, in task
mgr.__enter__()
File "/usr/lib/python2.7/contextlib.py", line 17, in __enter__
return self.gen.next()
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/ceph_fuse.py", line 136, in task
mount.mount()
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/fuse_mount.py", line 33, in mount
return self._mount(mount_path, mount_fs_name)
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/fuse_mount.py", line 161, in _mount
self.gather_mount_info()
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/fuse_mount.py", line 170, in gather_mount_info
sessions = self.fs.rank_asok(['session', 'ls'])
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/filesystem.py", line 920, in rank_asok
return self.json_asok(command, 'mds', info['name'])
File "/home/teuthworker/src/git.ceph.com_ceph-c_wip-smithfarm-testing/qa/tasks/cephfs/filesystem.py", line 180, in json_asok
return json.loads(response_data)
File "/usr/lib/python2.7/json/__init__.py", line 339, in loads
return _default_decoder.decode(s)
File "/usr/lib/python2.7/json/decoder.py", line 367, in decode
raise ValueError(errmsg("Extra data", s, end, len(s)))
ValueError: Extra data: line 2 column 1 - line 2 column 7 (char 17 - 23)
</pre>

Back