From mboxrd@z Thu Jan 1 00:00:00 1970 From: Tony Asleson Date: Thu, 20 Jun 2013 18:18:14 -0500 Subject: Internal error: Pool read_vg crc mismatch only when running in test environment Message-ID: <51C38DB6.7070507@redhat.com> List-Id: To: lvm-devel@redhat.com MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Writing some new unit test cases for my latest liblvm patch set and at the moment I am running into a case where I can run the unit test case against real disk and it works, but if I run it in the test environment with loop back devices I am getting an abort with: "Internal error: Pool read_vg crc mismatch." Any ideas why this error isn't occurring on both? Thanks, Tony Snippet from output. VERBOSE= \ cluster_LVM_TEST_LOCKING=3 \ lvmetad_LVM_TEST_LVMETAD=1 \ ./lib/harness normal:api/pytest.sh \ cluster:api/pytest.sh \ lvmetad:api/pytest.sh Running normal:api/pytest.sh ... FAILED. -- FAILED normal:api/pytest.sh ------------------------------------ #If you change this change the unit test case too. aux prepare_pvs 3 #pytest.sh:17+ aux prepare_pvs 3 ## preparing loop device....ok (/dev/loop0) ## preparing 3 devices...ok Physical volume "@TESTDIR@/dev/mapper/@PREFIX at pv1" successfully created Physical volume "@TESTDIR@/dev/mapper/@PREFIX at pv2" successfully created Physical volume "@TESTDIR@/dev/mapper/@PREFIX at pv3" successfully created #Locate the python binding library to use. python_lib=`find $abs_top_builddir -name lvm.so` find $abs_top_builddir -name lvm.so ##pytest.sh:20+ find /home/tasleson/lvm2 -name lvm.so #pytest.sh:20+ python_lib=/home/tasleson/lvm2/python/build/lib.linux-x86_64-2.7/lvm.so if [ "$python_lib" != "" ] then export PYTHONPATH=`dirname $python_lib`:$PYTHONPATH python_lvm_unit.py -v else echo "Unable to test python bindings as library not available" fi #pytest.sh:21+ '[' /home/tasleson/lvm2/python/build/lib.linux-x86_64-2.7/lvm.so '!=' '' ']' dirname $python_lib ##pytest.sh:23+ dirname /home/tasleson/lvm2/python/build/lib.linux-x86_64-2.7/lvm.so #pytest.sh:23+ export PYTHONPATH=/home/tasleson/lvm2/python/build/lib.linux-x86_64-2.7: #pytest.sh:23+ PYTHONPATH=/home/tasleson/lvm2/python/build/lib.linux-x86_64-2.7: #pytest.sh:24+ python_lvm_unit.py -v testConfigFindBool (__main__.TestLvm) ... ok testConfigReload (__main__.TestLvm) ... ok testConfig_override (__main__.TestLvm) ... ok testDupeLvCreate (__main__.TestLvm) ... ok testLvActiveInactive (__main__.TestLvm) ... ok testLvMisc (__main__.TestLvm) ... FAIL testLvProperty (__main__.TestLvm) ... ok testLvRename (__main__.TestLvm) ... ok testLvResize (__main__.TestLvm) ... ok testLvSeg (__main__.TestLvm) ... ok testLvSize (__main__.TestLvm) ... ok testLvSuspend (__main__.TestLvm) ... ok testLvTags (__main__.TestLvm) ... ok testOpenClose (__main__.TestLvm) ... ok testPercentToFloat (__main__.TestLvm) ... ok testPvGetters (__main__.TestLvm) ... Internal error: Pool read_vg crc mismatch. api/pytest.sh: line 27: 14608 Aborted (core dumped) python_lvm_unit.py -v set +vx; STACKTRACE; set -vx ##pytest.sh:24+ set +vx ## - api/pytest.sh:24 ## 0 STACKTRACE() called from lib/utils:24 [New LWP 14608] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". Core was generated by `python /home/tasleson/lvm2/test/api/python_lvm_unit.py -v'. Program terminated with signal 6, Aborted. #0 0x0000003055035ba5 in raise () from /lib64/libc.so.6 #0 0x0000003055035ba5 in raise () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003055037358 in abort () from /lib64/libc.so.6 No symbol table info available. #2 0x00007fb6d2249b3b in print_log (level=2, file=0x7fb6d1ffb073 "mm/pool.c", line=178, dm_errno_or_class=-1, format=0x7fb6d1ffb158 "Internal error: Pool %s crc mismatch.") at log/log.c:375 ap = {{gp_offset = 48, fp_offset = 48, overflow_arg_area = 0x7fff895beef0, reg_save_area = 0x7fff895bee30}} buf = " \331\374\000\000\000\000\000\240l\aU0\000\000\000 \331\374\000\000\000\000\000\353\265\006U0\000\000\000\n\212\024\001\000\000\000\000\305\232$\322\266\177\000\000\063\370\000\000\000\000\000\000\210M\000\001\000\000\000\000\353\267+\322\266\177\000\000uG\aU\b\000\000\000\235\266+\322\266\177\000\000`\001\000\000\a\000\000\000 \\\003U0\000\000\000\002", '\000' , "811", '\000' "\360, \030\bW0\000\000\000\b:;W0\000\000\000B\246D\324\266\177\000\000x\230\v\001\000\000\000\000\240>8W0\000\000\000\300\000\\\211\377\177\000\000\207\r\005U0", '\000' , "0\000\000\000\060\000\000\000\200\353[\211\377\177\000\000\300\352[\211\377\177\000\000@;*\322\266\177\000\000\000\000\000\024\000\000\000\000\365\240*\322\266\177\000\000+\003\000\000\000\000\000\000\357"... locn = "\000nternal error: Pool read_vg crc mismatch.\000\000\a\000\000\000 \331\374\000\000\000\000\000\353\265\006U0\000\000\000PI\000\001\000\000\000\000\305\232$\322\266\177\000\000?q\030\001\000\000\000\000Fx\027\001\000\000\000\000\330\240*\322\266\177\000\000\000\000\000\000@\000\000\000\365\240*\322\266\177\000\000\217\000\000\000\a", '\000' , "\027\001", '\000' "\377, \377", '\000' , "\002", '\000' "\260, \332[\211\377\177\000\000\000\000\000\000\000\000\000\000\377\377\377\377\000\000\000\000\000\360\025\001\000\000\000\000\377\377\377\377\377\177\000\000\000\004;U0", '\000' , "\004;U0", '\000' "\360"... bufused = 0 n = 42 message = 0x7fff895bd9d0 "" trformat = 0x7fb6d1ffb158 "Internal error: Pool %s crc mismatch." newbuf = 0x8965c3e
use_stderr = 0 log_once = 0 fatal_internal_error = 1 msglen = 42 #3 0x00007fb6d1feb838 in dm_pool_unlock (p=0x1159460, crc=1) at mm/pool.c:178 No locals. #4 0x00007fb6d221db10 in lvmcache_vginfo_holders_dec_and_test_for_zero (vginfo=0x1082010) at cache/lvmcache.c:821 No locals. #5 0x00007fb6d22804cd in release_vg (vg=0x1173150) at metadata/vg.c:87 No locals. #6 0x00007fb6d221c39f in _free_cached_vgmetadata (vginfo=0x1082010) at cache/lvmcache.c:145 No locals. #7 0x00007fb6d221c77d in _drop_metadata (vgname=0x7fff895c0090 "thin_vg", drop_precommitted=0) at cache/lvmcache.c:258 vginfo = 0x1082010 info = 0x1082020 #8 0x00007fb6d221c897 in lvmcache_drop_metadata (vgname=0x7fff895c0090 "thin_vg", drop_precommitted=0) at cache/lvmcache.c:295 No locals. #9 0x00007fb6d22a4366 in _file_lock_resource (cmd=0x1044b60, resource=0x7fff895c0090 "thin_vg", flags=33, lv=0x0) at locking/file_locking.c:267 lockfile = '\000' "\220, \371[\211\377\177\000\000\200\371[\211\377\177\000\000M\241+\322\266\177\000\000\020\373[\211\377\177\000\000J\241+\322\266\177\000\000\063k\004U0", '\000' "\356, \223\004U0\000\000\000\320\371[\211\377\177\000\000\300\371[\211\377\177\000\000M\241+\322\266\177\000\000P\373[\211\377\177\000\000J\241+\322\266\177\000\000\063k\004U0", '\000' "\356, \223\004U0\000\000\000\002\000\000\000\000\000\000\000\001", '\000' "\377, \377\377\377\000\000\000\000\000\000\000\000>\217\aU0", '\000' , "\n\000\000\000\316\b+\322\266\177", '\000' "\377, \377\377\377\377\377\377\377\000\000\000\000\000\000\000\000\356\223\004U0", '\000' , "\n\000\000\000\377\377\377\377\377\377\377\377\000\000\000\000\000\000\000\000\207\371[\211\377\177", '\000' "\372"... origin_only = 0 revert = 0 #10 0x00007fb6d2247dcc in _lock_vol (cmd=0x1044b60, resource=0x7fff895c0090 "thin_vg", flags=33, lv_op=LV_NOOP, lv=0x0) at locking/locking.c:382 lck_type = 1 lck_scope = 0 ret = 0 __PRETTY_FUNCTION__ = "_lock_vol" #11 0x00007fb6d22480cb in lock_vol (cmd=0x1044b60, vol=0xfbbfb4 "thin_vg", flags=33, lv=0x0) at locking/locking.c:460 resource = "thin_vg", '\000' lv_op = LV_NOOP lck_type = 1 #12 0x00007fb6d226a98c in _vg_lock_and_read (cmd=0x1044b60, vg_name=0xfbbfb4 "thin_vg", vgid=0x0, lock_flags=33, status_flags=0, misc_flags=0) at metadata/metadata.c:4060 vg = 0x0 consistent = 0 consistent_in = 32767 failure = 0 already_locked = 0 #13 0x00007fb6d226ad89 in vg_read (cmd=0x1044b60, vg_name=0xfbbfb4 "thin_vg", vgid=0x0, flags=0) at metadata/metadata.c:4175 status = 0 lock_flags = 33 #14 0x00007fb6d22167cb in lvm_vg_open (libh=0x1044b60, vgname=0xfbbfb4 "thin_vg", mode=0x7fb6d452e4dc "r", flags=0) at lvm_vg.c:197 internal_flags = 0 vg = 0xfff260 #15 0x00007fb6d24fadc0 in liblvm_lvm_vg_open (self=0x0, args=('thin_vg', 'r')) at liblvm_python.c:465 vgname = 0xfbbfb4 "thin_vg" mode = 0x7fb6d452e4dc "r" vgobj = 0x7fb6d44e9150 #16 0x00000030570dd281 in call_function (oparg=, pp_stack=0x7fff895c0488) at /usr/src/debug/Python-2.7.3/Python/ceval.c:4098 callargs = ('thin_vg', 'r') flags = tstate = func = w = na = nk = n = pfunc = 0x115af20 x = #17 PyEval_EvalFrameEx (f=f at entry=Frame 0x115ad70, for file /home/tasleson/lvm2/test/api/python_lvm_unit.py, line 97, in _get_pv_test (self=, dots=False, skipped=[], _mirrorOutput=False, stream=<_WritelnDecorator(stream=) at remote 0x1006dd0>, testsRun=16, buffer=None, _original_stderr=, showAll=True, _stdout_buffer=None, _stderr_buffer=None, _moduleSetUpFailed=False, expectedFailures=[], errors=[], descriptions=True, _previousTestClass=, unexpectedSuccesses=[], failures=[(, _type_equality_funcs={: 'assertSetEqual', : 'assertListEqual', : 'assertMultiLineEqual', : 'assertTupleEqual', : 'assertSetEqual', : 'assertDictEqual'}, _testMethodDoc=None, _testMethodNa...(truncated), throwflag=throwflag at entry=0) at /usr/src/debug/Python-2.7.3/Python/ceval.c:2740 sp = 0x115af28 stack_pointer = next_instr = 0x7fb6d4462964 "}\004" opcode = oparg = why = 1 err = 0 x = v = w = u = t = stream = 0x0 fastlocals = 0x115aee8 freevars = 0x115af18 retval = 0x0 tstate = co = 0x7fb6d444eeb0 instr_ub = -1 instr_lb = 0 instr_prev = -1 first_instr = 0x7fb6d446293c "t" names = ('lvm', 'listVgNames', 'vgOpen', 'listPVs', 'len', 'None') consts = (None, 0)