Ceph

Same here, only after upgrading clients (OSDs still running 0.94.5).
Full traceback here: http://pastebin.com/HXfVKKFB

I guess it's due to the new --no-verify option: https://github.com/ceph/ceph/commit/a619b621b0a7c670eeaf163d9e2b742d13c9f517

Here's some strange behaviour when I use seq and --no-verify:

[11:07][root@cephmond0 (production:ceph/dwight/mon*1) ~]# rados bench -p test 5 seq -b 4096 -t 1 --no-verify
sec Cur ops started finished avg MB/s cur MB/s last lat avg lat
0 0 0 0 0 0 - 0
benchmark_data_p01001532077488.cern.ch_257739_object0 is not correct!
benchmark_data_p01001532077488.cern.ch_257739_object1 is not correct!
benchmark_data_p01001532077488.cern.ch_257739_object2 is not correct!
benchmark_data_p01001532077488.cern.ch_257739_object3 is not correct!
benchmark_data_p01001532077488.cern.ch_257739_object4 is not correct!
benchmark_data_p01001532077488.cern.ch_257739_object5 is not correct!
...

Full log: http://pastebin.com/2uePDDnp

Fix (not tested yet): https://github.com/ceph/ceph/pull/7817

The fix is incomplete, there are more locking errors. I'll keep digging.

The revised patch (https://github.com/ceph/ceph/pull/7817) fixes the problem.

Hi Alexey! Is this bug not present in master? (The usual process is to fix in master first and then backport.)

Nathan and Alexey, probably we should backport https://github.com/ceph/ceph/pull/5853 also?

Nathan,

Is this bug not present in master?

No. The bug is caused by a patch (mis)cherry-picked from master to Hammer.

The bug is caused by a patch (mis)cherry-picked from master to Hammer.

For the record the patch in question is https://github.com/ceph/ceph/commit/a619b621b0a7c670eeaf163d9e2b742d13c9f517

The faulty cherry pick comes from https://github.com/ceph/ceph/pull/6791

--- /dev/fd/63    2016-03-03 13:41:37.476976784 +0700
+++ /dev/fd/62    2016-03-03 13:41:37.476976784 +0700
@@ -47,17 +47,22 @@
     Note the decreased latencies, increased bandwidth and more reads performed.

     Signed-off-by: Piotr Dałek <piotr.dalek@ts.fujitsu.com>
+    (cherry picked from commit ca6abca63de813c83a6960f83624be8e1a86a1f8)
+    
+    Conflicts:
+        src/common/obj_bencher.cc
+        src/common/obj_bencher.h

 diff --git a/src/common/obj_bencher.cc b/src/common/obj_bencher.cc
-index 128a544..8fd963b 100644
+index fbc9e34..2ed0c52 100644
 --- a/src/common/obj_bencher.cc
 +++ b/src/common/obj_bencher.cc
-@@ -169,7 +169,7 @@ void *ObjBencher::status_printer(void *_bencher) {
- 
+@@ -154,7 +154,7 @@ void *ObjBencher::status_printer(void *_bencher) {
  int ObjBencher::aio_bench(
    int operation, int secondsToRun,
--  int concurrentios, int object_size, bool cleanup, const char* run_name) {
-+  int concurrentios, int object_size, bool cleanup, const char* run_name, bool no_verify) {
+   int maxObjectsToCreate,
+-  int concurrentios, int op_size, bool cleanup, const char* run_name) {
++  int concurrentios, int op_size, bool cleanup, const char* run_name, bool no_verify) {

    if (concurrentios <= 0) 
      return -EINVAL;
@@ -101,7 +106,7 @@
 +        ++errors;
 +      }
 +    } else {
-+        lock.Unlock();
++      lock.Unlock();
      }
 +
      name[slot] = newName;
@@ -124,7 +129,7 @@
 +        ++errors;
 +      }
 +    } else {
-+        lock.Unlock();
++      lock.Unlock();
      }
      delete contents[slot];
    }
@@ -167,6 +172,7 @@
 -    if (memcmp(data.object_contents, contents[slot]->c_str(), data.object_size) != 0) {
 -      cerr << name[slot] << " is not correct!" << std::endl;
 -      ++errors;
++
 +    if (!no_verify) {
 +      snprintf(data.object_contents, data.object_size, "I'm the %16dth object!", index[slot]);
 +      lock.Unlock();
@@ -175,22 +181,24 @@
 +        ++errors;
 +      }
 +    } else {
-+        lock.Unlock();
++      lock.Unlock();
      }
++
      delete contents[slot];
    }
+ 
 diff --git a/src/common/obj_bencher.h b/src/common/obj_bencher.h
-index c67d429..e1d5e9d 100644
+index 4d89f41..52b3157 100644
 --- a/src/common/obj_bencher.h
 +++ b/src/common/obj_bencher.h
-@@ -67,8 +67,8 @@ protected:
+@@ -65,8 +65,8 @@ protected:
    int fetch_bench_metadata(const std::string& metadata_file, int* object_size, int* num_objects, int* prevPid);

-   int write_bench(int secondsToRun, int concurrentios, const string& run_name_meta);
+   int write_bench(int secondsToRun, int maxObjects, int concurrentios, const string& run_name_meta);
 -  int seq_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid);
 -  int rand_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid);
-+  int seq_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify=false);
-+  int rand_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify=false);
++  int seq_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify);
++  int rand_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify);

    int clean_up(int num_objects, int prevPid, int concurrentios);
    int clean_up_slow(const std::string& prefix, int concurrentios);
@@ -228,6 +236,7 @@
    if (i != opts.end()) {
      nspace = i->second;
    }
+-
 +  i = opts.find("no-verify");
 +  if (i != opts.end()) {
 +    no_verify = true;

This conflict resolution has one notable difference. The original patch had

-+  int seq_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify=false);
-+  int rand_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify=false);

++  int seq_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify);
++  int rand_read_bench(int secondsToRun, int num_objects, int concurrentios, int writePid, bool no_verify);

The other resolution are trivial (space change and protypte change).

--- /dev/fd/63    2016-03-03 14:09:51.354329129 +0700
+++ /dev/fd/62    2016-03-03 14:09:51.358329122 +0700
@@ -76,20 +79,18 @@
      ++data.in_flight;
 -    if (!no_verify) {
 -      snprintf(data.object_contents, data.object_size, "I'm the %16dth object!", current_index);
--      lock.Unlock();
+       lock.Unlock();
 -      if (memcmp(data.object_contents, cur_contents->c_str(), data.object_size) != 0) {
 -        cerr << name[slot] << " is not correct!" << std::endl;
 -        ++errors;
 -      }
--    } else {
--        lock.Unlock();
--    }
--
-+    lock.Unlock();
-     name[slot] = newName;
-   }
- 
-@@ -789,11 +791,14 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
++    if (memcmp(data.object_contents, cur_contents->c_str(), data.object_size) != 0) {
++      cerr << name[slot] << " is not correct!" << std::endl;
++      ++errors;
+     } else {
+       lock.Unlock();
+     }
+@@ -776,11 +785,14 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
        }
        lc.cond.Wait(lock);
      }

The conflict has been resolved incorrectly and added a code block if (memcmp instead of removing the intended code block. For some reason lock.Unlock(); was not removed and creates a double unlock problem.

Loic, can we do the backport through #14958 which I have properly staged for backport to infernalis and hammer?

In other words, we could close this as a duplicate of #14961

Nevermind! I see now that's a totally different double-something issue.