Ceph

Run: http://pulpito.ceph.com/teuthology-2015-03-23_17:13:01-upgrade:firefly-x-hammer-distro-basic-multi/
Job: 818729
Logs: http://qa-proxy.ceph.com/teuthology/teuthology-2015-03-23_17:13:01-upgrade:firefly-x-hammer-distro-basic-multi/818729/

2015-03-25T01:14:15.156 INFO:teuthology.orchestra.run.plana85:Running: 'sudo ceph-objectstore-tool --data-path /var/lib/ceph/osd/ceph-11 --journal-path /var/lib/ceph/osd/ceph-11/journal --log-file=/var/log/ceph/objectstore_tool.\\$pid.log --op import --file /home/ubuntu/cephtest/data/exp.19.26.11'
2015-03-25T01:14:15.792 INFO:teuthology.orchestra.run.plana85.stdout:Importing pgid 19.26
2015-03-25T01:14:16.114 INFO:teuthology.orchestra.run.plana85.stdout:Import successful
2015-03-25T01:14:16.321 INFO:teuthology.orchestra.run.plana85.stderr:*** Caught signal (Segmentation fault) **
2015-03-25T01:14:16.321 INFO:teuthology.orchestra.run.plana85.stderr: in thread 7f7f401d4780
2015-03-25T01:14:21.374 INFO:tasks.ceph.osd.6.plana22.stderr:2015-03-25 01:14:21.371053 7f6070c8c700 -1 osd.6 1335 heartbeat_check: no reply from osd.9 since back 2015-03-25 01:14:01.015247 front 2015-03-25 01:14:01.015247 (cutoff 2015-03-25 01:14:01.371052)
2015-03-25T01:14:22.374 INFO:tasks.ceph.osd.6.plana22.stderr:2015-03-25 01:14:22.371240 7f6070c8c700 -1 osd.6 1335 heartbeat_check: no reply from osd.9 since back 2015-03-25 01:14:01.015247 front 2015-03-25 01:14:01.015247 (cutoff 2015-03-25 01:14:02.371238)
2015-03-25T01:14:22.821 INFO:tasks.ceph.osd.6.plana22.stderr:2015-03-25 01:14:22.818380 7f6059314700 -1 osd.6 1335 heartbeat_check: no reply from osd.9 since back 2015-03-25 01:14:01.015247 front 2015-03-25 01:14:01.015247 (cutoff 2015-03-25 01:14:02.818379)
2015-03-25T01:14:23.374 INFO:tasks.ceph.osd.6.plana22.stderr:2015-03-25 01:14:23.371424 7f6070c8c700 -1 osd.6 1335 heartbeat_check: no reply from osd.9 since back 2015-03-25 01:14:01.015247 front 2015-03-25 01:14:01.015247 (cutoff 2015-03-25 01:14:03.371422)
.........
.........
2015-03-25T04:01:37.018 INFO:tasks.ceph.mon.a.plana22.stderr:2015-03-25 04:01:37.017279 7f3809ffc700 -1 mon.a@0(leader).mds e5 Missing health data for MDS 4107
2015-03-25T04:02:37.018 INFO:tasks.ceph.mon.a.plana22.stderr:2015-03-25 04:02:37.017636 7f3809ffc700 -1 mon.a@0(leader).mds e5 Missing health data for MDS 4107
2015-03-25T04:03:37.018 INFO:tasks.ceph.mon.a.plana22.stderr:2015-03-25 04:03:37.017978 7f3809ffc700 -1 mon.a@0(leader).mds e5 Missing health data for MDS 4107
2015-03-25T04:04:37.019 INFO:tasks.ceph.mon.a.plana22.stderr:2015-03-25 04:04:37.018318 7f3809ffc700 -1 mon.a@0(leader).mds e5 Missing health data for MDS 4107
2015-03-25T04:04:42.123 INFO:tasks.workunit.client.0.plana75.stderr:test_rbd.TestImage.test_remove_with_snap ...
2015-03-25T04:04:42.123 INFO:tasks.workunit:Stopping ['rbd/test_librbd_python.sh'] on client.0...
2015-03-25T04:04:42.123 INFO:teuthology.orchestra.run.plana75:Running: 'rm -rf -- /home/ubuntu/cephtest/workunits.list.client.0 /home/ubuntu/cephtest/workunit.client.0'
2015-03-25T04:04:42.134 ERROR:teuthology.parallel:Exception in parallel execution
Traceback (most recent call last):
  File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 82, in __exit__
    for result in self:
  File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 101, in next
    resurrect_traceback(result)
  File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 19, in capture_traceback
    return func(*args, **kwargs)
  File "/var/lib/teuthworker/src/ceph-qa-suite_hammer/tasks/workunit.py", line 361, in _run_tests
    label="workunit test {workunit}".format(workunit=workunit)
  File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/remote.py", line 137, in run
    r = self._runner(client=self.ssh, name=self.shortname, **kwargs)
  File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/run.py", line 378, in run
    r.wait()
  File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/run.py", line 114, in wait
    label=self.label)
CommandFailedError: Command failed (workunit test rbd/test_librbd_python.sh) on plana75 with status 124: 'mkdir -p -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && cd -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && CEPH_CLI_TEST_DUP_COMMAND=1 CEPH_REF=firefly TESTDIR="/home/ubuntu/cephtest" CEPH_ID="0" PATH=$PATH:/usr/sbin adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 3h /home/ubuntu/cephtest/workunit.client.0/rbd/test_librbd_python.sh'
2015-03-25T04:04:42.160 ERROR:teuthology.run_tasks:Saw exception from tasks.
Traceback (most recent call last):
  File "/home/teuthworker/src/teuthology_master/teuthology/run_tasks.py", line 53, in run_tasks
    manager = run_one_task(taskname, ctx=ctx, config=config)
  File "/home/teuthworker/src/teuthology_master/teuthology/run_tasks.py", line 41, in run_one_task
    return fn(**kwargs)
  File "/var/lib/teuthworker/src/ceph-qa-suite_hammer/tasks/workunit.py", line 105, in task
    config.get('env'), timeout=timeout)
  File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 82, in __exit__
    for result in self:
  File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 101, in next
    resurrect_traceback(result)
  File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 19, in capture_traceback
    return func(*args, **kwargs)
  File "/var/lib/teuthworker/src/ceph-qa-suite_hammer/tasks/workunit.py", line 361, in _run_tests
    label="workunit test {workunit}".format(workunit=workunit)
  File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/remote.py", line 137, in run
    r = self._runner(client=self.ssh, name=self.shortname, **kwargs)
  File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/run.py", line 378, in run
    r.wait()
  File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/run.py", line 114, in wait
    label=self.label)
CommandFailedError: Command failed (workunit test rbd/test_librbd_python.sh) on plana75 with status 124: 'mkdir -p -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && cd -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && CEPH_CLI_TEST_DUP_COMMAND=1 CEPH_REF=firefly TESTDIR="/home/ubuntu/cephtest" CEPH_ID="0" PATH=$PATH:/usr/sbin adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 3h /home/ubuntu/cephtest/workunit.client.0/rbd/test_librbd_python.sh'
2015-03-25T04:04:42.202 ERROR:teuthology.run_tasks: Sentry event: http://sentry.ceph.com/sepia/teuthology/search?q=a5d08917476e4b91889c0aedf62b4292
CommandFailedError: Command failed (workunit test rbd/test_librbd_python.sh) on plana75 with status 124: 'mkdir -p -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && cd -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && CEPH_CLI_TEST_DUP_COMMAND=1 CEPH_REF=firefly TESTDIR="/home/ubuntu/cephtest" CEPH_ID="0" PATH=$PATH:/usr/sbin adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 3h /home/ubuntu/cephtest/workunit.client.0/rbd/test_librbd_python.sh

For the second osd.7 one, it's a firefly osd and:

2015-03-25 01:21:49.807405 7f23faaf9700 1 -- 10.214.133.31:6805/11495 <== client.15931 10.214.132.3:0/1010061 2442 ==== osd_op(client.15931.0:3796 rb.0.3e3b.2d1d5ae9.000000000001 [delete] 2.32a45244 snapc 19e=[] ack+ondisk+write e1660) v4 ==== 182+0+0 (2163273376 0 0) 0x4907000 con 0x40926e0
2015-03-25 01:21:49.807420 7f622fcfb700 20 osd.10 1660 scrub_random_backoff lost coin flip, randomly backing off
2015-03-25 01:21:49.807427 7f622fcfb700 10 osd.10 1660 do_waiters -- start
2015-03-25 01:21:49.807429 7f622fcfb700 10 osd.10 1660 do_waiters -- finish
2015-03-25 01:21:49.807430 7fa42c415700 10 osd.13 1660 do_waiters -- start
2015-03-25 01:21:49.807435 7fa42c415700 10 osd.13 1660 do_waiters -- finish
2015-03-25 01:21:49.807438 7fa42c415700 20 osd.13 1660 _dispatch 0x58d5480 osd_op(client.15931.0:3795 rb.0.3e3b.2d1d5ae9.000000000000 [delete] 2.532fd966 snapc 19e=[] ack+ondisk+write e1660) v4
2015-03-25 01:21:49.807443 7f23faaf9700 10 osd.7 1660 do_waiters -- start
2015-03-25 01:21:49.807447 7f23faaf9700 10 osd.7 1660 do_waiters -- finish
2015-03-25 01:21:49.807450 7f23faaf9700 20 osd.7 1660 _dispatch 0x4907000 osd_op(client.15931.0:3796 rb.0.3e3b.2d1d5ae9.000000000001 [delete] 2.32a45244 snapc 19e=[] ack+ondisk+write e1660) v4
2015-03-25 01:21:49.807516 7fa42c415700 15 osd.13 1660 require_same_or_newer_map 1660 (i am 1660) 0x58d5480
2015-03-25 01:21:49.807522 7f23faaf9700 15 osd.7 1660 require_same_or_newer_map 1660 (i am 1660) 0x4907000
2015-03-25 01:21:49.807526 7f23faaf9700 20 osd.7 1660 _share_map_incoming client.15931 10.214.132.3:0/1010061 1660
2015-03-25 01:21:49.807532 7fa42c415700 20 osd.13 1660 _share_map_incoming client.15931 10.214.132.3:0/1010061 1660
2015-03-25 01:21:49.807557 7fa42c415700 15 osd.13 1660 enqueue_op 0xa268690 prio 63 cost 0 latency 0.000307 osd_op(client.15931.0:3795 rb.0.3e3b.2d1d5ae9.000000000000 [delete] 2.532fd966 snapc 19e=[] ack+ondisk+write e1660) v4
2015-03-25 01:21:49.807559 7f23faaf9700 7 osd.7 1660 hit non-existent pg 2.44
2015-03-25 01:21:49.807582 7f23faaf9700 7 osd.7 1660 we are valid target for op, waiting
2015-03-25 01:21:49.807590 7fa42c415700 10 osd.13 1660 do_waiters -- start
2015-03-25 01:21:49.807594 7fa42c415700 10 osd.13 1660 do_waiters -- finish
2015-03-25 01:21:49.807604 7f23faaf9700 10 osd.7 1660 do_waiters -- start
2015-03-25 01:21:49.807607 7f23faaf9700 10 osd.7 1660 do_waiters -- finish

still looking.

Oh, osd 9 stopped for some reason with the only copy of one of the pgs. No backtrace, core. Odd.

Same with the other one, osd.9 stopped without any information. Probably environmental.