1332253 – [RH Ceph 2.0] test_rbd.py /log/SubsystemMap.h: In function 'bool ceph::log::SubsystemMap::should_gather(unsigned int, int)' thread 7fcb88b2c740 time 2016-05-01 09:12:25.029376

Bug 1332253 - [RH Ceph 2.0] test_rbd.py /log/SubsystemMap.h: In function 'bool ceph::log::SubsystemMap::should_gather(unsigned int, int)' thread 7fcb88b2c740 time 2016-05-01 09:12:25.029376

Summary: [RH Ceph 2.0] test_rbd.py /log/SubsystemMap.h: In function 'bool ceph::log::S...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Ceph Storage
Classification:	Red Hat
Component:	RBD
Sub Component:
Version:	2.0
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	rc
Target Release:	2.0
Assignee:	Jason Dillaman
QA Contact:	Vasu Kulkarni
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2016-05-02 15:58 UTC by Vasu Kulkarni
Modified:	2017-07-30 15:30 UTC (History)
CC List:	4 users (show)
Fixed In Version:	RHEL: ceph-10.2.1-1.el7cp Ubuntu: ceph_10.2.1-2redhat1xenial
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2016-08-23 19:37:28 UTC
Target Upstream Version:
Dependent Products:

Attachments	(Terms of Use)
Add an attachment (proposed patch, testcase, etc.)

Links
System	ID	Priority	Status	Summary	Last Updated
Ceph Project Bug Tracker	15685	None	None	None	2016-05-02 17:19:33 UTC
Red Hat Product Errata	RHBA-2016:1755	normal	SHIPPED_LIVE	Red Hat Ceph Storage 2.0 bug fix and enhancement update	2016-08-23 23:23:52 UTC

Description Vasu Kulkarni 2016-05-02 15:58:56 UTC

Description of problem:

I am seeing following assert during test_rbd.py, not sure if those tests are supported in this build yet.

2016-05-01T05:01:50.968 INFO:tasks.workunit.client.0.magna049.stderr:+ nosetests -v test_rbd
2016-05-01T05:01:58.135 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_flatten_basic ... ERROR
2016-05-01T05:01:59.276 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_flatten_drops_cache ... ERROR
2016-05-01T05:02:00.659 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_flatten_errors ... ERROR
2016-05-01T05:02:01.910 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_flatten_larger_order ... ERROR
2016-05-01T05:02:03.428 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_flatten_multi_level ... ERROR
2016-05-01T05:02:04.677 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_flatten_smaller_order ... ERROR
2016-05-01T05:02:05.906 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_list_children ... ERROR
2016-05-01T05:02:07.214 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_read ... ERROR
2016-05-01T05:02:08.523 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_resize_flatten_multi_level ... ERROR
2016-05-01T05:02:09.773 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_resize_io ... ERROR
2016-05-01T05:02:11.081 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_resize_stat ... ERROR
2016-05-01T05:02:12.406 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_stat ... ERROR
2016-05-01T05:02:13.677 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_unprotect_with_children ... ERROR
2016-05-01T05:02:15.060 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_unprotected ... ERROR
2016-05-01T05:02:16.277 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_with_params ... ERROR
2016-05-01T05:02:17.619 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestClone.test_write ... ERROR
2016-05-01T05:02:17.620 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_follower_discard ... SKIP
2016-05-01T05:02:17.621 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_follower_flatten ... SKIP
2016-05-01T05:02:17.622 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_follower_resize ... SKIP
2016-05-01T05:02:17.623 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_follower_snap_create ... SKIP
2016-05-01T05:02:17.624 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_follower_snap_rollback ... SKIP
2016-05-01T05:02:17.625 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_follower_write ... SKIP
2016-05-01T05:02:17.626 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_ownership ... SKIP
2016-05-01T05:02:17.627 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_read_only_leadership ... SKIP
2016-05-01T05:02:17.628 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestExclusiveLock.test_snapshot_leadership ... SKIP
2016-05-01T05:02:18.880 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_copy ... ok
2016-05-01T05:02:19.942 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_copy2 ... ok
2016-05-01T05:02:20.128 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_copy3 ... SKIP
2016-05-01T05:02:22.673 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_create_snap ... ok
2016-05-01T05:02:23.061 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_create_with_params ... SKIP
2016-05-01T05:02:29.009 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_diff_iterate ... ok
2016-05-01T05:02:29.409 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_flags ... ok
2016-05-01T05:02:29.843 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_image_auto_close ... ok
2016-05-01T05:02:30.318 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_invalidate_cache ... ok
2016-05-01T05:02:30.727 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_large_read ... ok
2016-05-01T05:02:32.152 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_large_write ... ok
2016-05-01T05:02:33.565 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_list_lockers ... ok
2016-05-01T05:02:38.862 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_list_snaps ... ok
2016-05-01T05:02:41.371 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_list_snaps_iterator_auto_close ... ok
2016-05-01T05:02:41.862 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_lock_unlock ... ok
2016-05-01T05:11:22.135 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_many_snaps ... ok
2016-05-01T05:11:24.916 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_protect_snap ... ok
2016-05-01T05:11:25.365 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_read ... ok
2016-05-01T05:11:25.976 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_read_bad_offset ... ok
2016-05-01T05:11:26.390 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_read_with_fadvise_flags ... ok
2016-05-01T05:11:29.489 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_remove_snap ... ok
2016-05-01T05:11:29.784 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_remove_with_exclusive_lock ... SKIP
2016-05-01T05:11:33.177 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_remove_with_snap ... ok
2016-05-01T05:11:33.715 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_remove_with_watcher ... ok
2016-05-01T05:11:37.044 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_rename_snap ... ok
2016-05-01T05:11:37.461 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_resize ... ok
2016-05-01T05:11:38.094 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_resize_bytes ... ok
2016-05-01T05:11:38.615 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_resize_down ... ok
2016-05-01T05:11:41.765 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_rollback_to_snap ... ok
2016-05-01T05:11:44.228 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_rollback_to_snap_sparse ... ok
2016-05-01T05:11:49.524 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_rollback_with_resize ... ok
2016-05-01T05:11:52.333 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_set_no_snap ... ok
2016-05-01T05:11:55.022 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_set_snap ... ok
2016-05-01T05:11:57.522 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_set_snap_deleted ... ok
2016-05-01T05:12:03.039 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_set_snap_recreated ... ok
2016-05-01T05:12:05.601 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_set_snap_sparse ... ok
2016-05-01T05:12:10.823 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_size ... ok
2016-05-01T05:12:11.368 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_stat ... ok
2016-05-01T05:12:12.057 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_update_features ... ok
2016-05-01T05:12:12.535 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_write ... ok
2016-05-01T05:12:13.010 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_write_read ... ok
2016-05-01T05:12:13.516 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.TestImage.test_write_with_fadvise_flags ... ok
2016-05-01T05:12:13.518 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_version ... ok
2016-05-01T05:12:13.852 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_create ... ok
2016-05-01T05:12:19.701 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_create_defaults ... ok
2016-05-01T05:12:20.068 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_context_manager ... ok
2016-05-01T05:12:22.977 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_open_read_only ... ok
2016-05-01T05:12:23.284 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_open_dne ... ok
2016-05-01T05:12:23.535 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_open_readonly_dne ... ok
2016-05-01T05:12:23.541 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_remove_dne ... ok
2016-05-01T05:12:23.543 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_list_empty ... FAIL
2016-05-01T05:12:23.725 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_list ... FAIL
2016-05-01T05:12:24.232 INFO:tasks.workunit.client.0.magna049.stderr:test_rbd.test_rename ... FAIL
2016-05-01T05:12:24.239 INFO:tasks.workunit.client.0.magna049.stderr:ERROR
2016-05-01T05:12:25.036 INFO:tasks.workunit.client.0.magna049.stderr:
2016-05-01T05:12:25.037 INFO:tasks.workunit.client.0.magna049.stderr:======================================================================
2016-05-01T05:12:25.038 INFO:tasks.workunit.client.0.magna049.stderr:ERROR: test_rbd.TestClone.test_flatten_basic
2016-05-01T05:12:25.039 INFO:tasks.workunit.client.0.magna049.stderr:----------------------------------------------------------------------
2016-05-01T05:12:25.040 INFO:tasks.workunit.client.0.magna049.stderr:Traceback (most recent call last):
2016-05-01T05:12:25.041 INFO:tasks.workunit.client.0.magna049.stderr:  File "/usr/lib/python2.7/site-packages/nose/case.py", line 381, in setUp
2016-05-01T05:12:25.041 INFO:tasks.workunit.client.0.magna049.stderr:    try_run(self.inst, ('setup', 'setUp'))
2016-05-01T05:12:25.042 INFO:tasks.workunit.client.0.magna049.stderr:  File "/usr/lib/python2.7/site-packages/nose/util.py", line 469, in try_run
2016-05-01T05:12:25.043 INFO:tasks.workunit.client.0.magna049.stderr:    return func()
2016-05-01T05:12:25.044 INFO:tasks.workunit.client.0.magna049.stderr:  File "/home/ubuntu/cephtest/mnt.0/client.0/tmp/test_rbd.py", line 92, in _require_features
2016-05-01T05:12:25.045 INFO:tasks.workunit.client.0.magna049.stderr:    return fn(*args, **kwargs)
2016-05-01T05:12:25.085 INFO:tasks.workunit.client.0.magna049.stderr:  File "/home/ubuntu/cephtest/mnt.0/client.0/tmp/test_rbd.py", line 741, in setUp
2016-05-01T05:12:25.086 INFO:tasks.workunit.client.0.magna049.stderr:    features)
2016-05-01T05:12:25.087 INFO:tasks.workunit.client.0.magna049.stderr:  File "rbd.pyx", line 492, in rbd.RBD.clone (rbd.c:3497)
2016-05-01T05:12:25.088 INFO:tasks.workunit.client.0.magna049.stderr:InvalidArgument: error creating clone
2016-05-01T05:12:25.089 INFO:tasks.workunit.client.0.magna049.stderr:

2016-05-01T05:12:25.887 INFO:tasks.workunit.client.0.magna049.stderr:FAILED (SKIP=12, errors=17, failures=3)
2016-05-01T05:12:25.890 INFO:tasks.workunit.client.0.magna049.stderr:./log/SubsystemMap.h: In function 'bool ceph::log::SubsystemMap::should_gather(unsigned int, int)' thread 7fcb88b2c740 time 2016-05-01 09:12:25.029376
2016-05-01T05:12:25.891 INFO:tasks.workunit.client.0.magna049.stderr:./log/SubsystemMap.h: 62: FAILED assert(sub < m_subsys.size())
2016-05-01T05:12:25.892 INFO:tasks.workunit.client.0.magna049.stderr: ceph version 10.2.0-1.el7cp (3a9fba20ec743699b69bd0181dd6c54dc01c64b9)
2016-05-01T05:12:25.893 INFO:tasks.workunit.client.0.magna049.stderr: 1: (()+0x2765b5) [0x7fcb65a565b5]
2016-05-01T05:12:25.894 INFO:tasks.workunit.client.0.magna049.stderr: 2: (()+0x4f092) [0x7fcb6582f092]
2016-05-01T05:12:25.894 INFO:tasks.workunit.client.0.magna049.stderr: 3: (()+0xa7e40) [0x7fcb65887e40]
2016-05-01T05:12:25.895 INFO:tasks.workunit.client.0.magna049.stderr: 4: (()+0xa7f92) [0x7fcb65887f92]
2016-05-01T05:12:25.896 INFO:tasks.workunit.client.0.magna049.stderr: 5: (rbd_close()+0x32) [0x7fcb65842202]
2016-05-01T05:12:25.897 INFO:tasks.workunit.client.0.magna049.stderr: 6: (()+0x13c38) [0x7fcb6f115c38]
2016-05-01T05:12:25.898 INFO:tasks.workunit.client.0.magna049.stderr: 7: (PyObject_Call()+0x43) [0x7fcb885a20c3]
2016-05-01T05:12:25.898 INFO:tasks.workunit.client.0.magna049.stderr: 8: (()+0xa7a5) [0x7fcb6f10c7a5]
2016-05-01T05:12:25.899 INFO:tasks.workunit.client.0.magna049.stderr: 9: (()+0x7f8ff) [0x7fcb885d78ff]
2016-05-01T05:12:25.900 INFO:tasks.workunit.client.0.magna049.stderr: 10: (()+0x9c344) [0x7fcb885f4344]
2016-05-01T05:12:25.900 INFO:tasks.workunit.client.0.magna049.stderr: 11: (()+0x550ab) [0x7fcb885ad0ab]
2016-05-01T05:12:25.901 INFO:tasks.workunit.client.0.magna049.stderr: 12: (()+0x7f8ff) [0x7fcb885d78ff]
2016-05-01T05:12:25.902 INFO:tasks.workunit.client.0.magna049.stderr: 13: (()+0x9bbb2) [0x7fcb885f3bb2]
2016-05-01T05:12:25.903 INFO:tasks.workunit.client.0.magna049.stderr: 14: (()+0x10fa6a) [0x7fcb88667a6a]
2016-05-01T05:12:25.903 INFO:tasks.workunit.client.0.magna049.stderr: 15: (PyGC_Collect()+0x28) [0x7fcb886681e8]
2016-05-01T05:12:25.904 INFO:tasks.workunit.client.0.magna049.stderr: 16: (Py_Finalize()+0xf9) [0x7fcb88655379]
2016-05-01T05:12:25.905 INFO:tasks.workunit.client.0.magna049.stderr: 17: (Py_Exit()+0x8) [0x7fcb88654c78]
2016-05-01T05:12:25.905 INFO:tasks.workunit.client.0.magna049.stderr: 18: (()+0xfcdb7) [0x7fcb88654db7]
2016-05-01T05:12:25.906 INFO:tasks.workunit.client.0.magna049.stderr: 19: (PyErr_PrintEx()+0x1dd) [0x7fcb8865507d]
2016-05-01T05:12:25.906 INFO:tasks.workunit.client.0.magna049.stderr: 20: (PyRun_SimpleFileExFlags()+0x20e) [0x7fcb88655c9e]
2016-05-01T05:12:25.907 INFO:tasks.workunit.client.0.magna049.stderr: 21: (Py_Main()+0xc9f) [0x7fcb88666caf]
2016-05-01T05:12:25.908 INFO:tasks.workunit.client.0.magna049.stderr: 22: (__libc_start_main()+0xf5) [0x7fcb87893b15]
2016-05-01T05:12:25.908 INFO:tasks.workunit.client.0.magna049.stderr: 23: /usr/bin/python() [0x400721]
2016-05-01T05:12:25.909 INFO:tasks.workunit.client.0.magna049.stderr: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2016-05-01T05:12:25.910 INFO:tasks.workunit.client.0.magna049.stderr:/home/ubuntu/cephtest/workunit.client.0/rbd/test_librbd_python.sh: line 13: 17516 Aborted                 (core dumped) nosetests -v test_rbd

Version-Release number of selected component (if applicable):
10.2.0-1.el7cp (3a9fba20ec743699b69bd0181dd6c54dc01c64b9)

How reproducible:

Always

Steps to Reproduce:
Run test_librbd

Additional info:

http://magna002.ceph.redhat.com/vasu-2016-04-30_16:09:18-rbd-jewel---basic-magna/230177/teuthology.log

Comment 2 Jason Dillaman 2016-05-02 17:17:16 UTC

The log indicates the following error: "librbd: format 2 or later required for clone".  Looking at the test setup, we see:

ceph:
  conf:
    client:
      rbd clone copy on read: false
      rbd default format: 1

Comment 3 Jason Dillaman 2016-05-02 19:09:54 UTC

Upstream PR: https://github.com/ceph/ceph/pull/8883

Comment 4 Ken Dreyer (Red Hat) 2016-05-10 13:23:47 UTC

This is undergoing review upstream (https://github.com/ceph/ceph/pull/8972) and will be in v10.2.1.

Comment 5 Ken Dreyer (Red Hat) 2016-05-13 23:31:07 UTC

The above PR is in v10.2.1.

Comment 8 Vasu Kulkarni 2016-06-21 23:50:22 UTC

Fix verified in 10.2.2

Comment 10 errata-xmlrpc 2016-08-23 19:37:28 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2016-1755.html

Note You need to log in before you can comment on or make changes to this bug.