pmem / issues

Old issues repo for PMDK.
http://pmem.io
13 stars 7 forks source link

test: obj_realloc/TEST0: SETUP (all/pmem/debug/helgrind) #743

Closed mramotowski closed 6 years ago

mramotowski commented 6 years ago

Commit: 76752eecac9f2bf1c6fa7f7414492a8356d1d1b2

obj_realloc/TEST0: SETUP (all/pmem/debug/helgrind) obj_realloc/TEST0 failed with Valgrind. See helgrind0.log. First 20 lines below. obj_realloc/TEST0 helgrind0.log ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) obj_realloc/TEST0 helgrind0.log ==10719== by 0x10F6C5: bucket_new (bucket.c:62) obj_realloc/TEST0 helgrind0.log ==10719== by 0x1175E2: heap_buckets_init (heap.c:1178) obj_realloc/TEST0 helgrind0.log ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) obj_realloc/TEST0 helgrind0.log ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) obj_realloc/TEST0 helgrind0.log ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) obj_realloc/TEST0 helgrind0.log ==10719== by 0x123437: obj_boot (obj.c:729) obj_realloc/TEST0 helgrind0.log ==10719== by 0x124901: obj_runtime_init (obj.c:1090) obj_realloc/TEST0 helgrind0.log ==10719== by 0x125D8F: obj_open_common (obj.c:1615) obj_realloc/TEST0 helgrind0.log ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) obj_realloc/TEST0 helgrind0.log ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) obj_realloc/TEST0 helgrind0.log ==10719== by 0x10DB93: main (obj_realloc.c:242) obj_realloc/TEST0 helgrind0.log ==10719== Block was alloc'd by thread #1 obj_realloc/TEST0 helgrind0.log ==10719== obj_realloc/TEST0 helgrind0.log ==10719== obj_realloc/TEST0 helgrind0.log ==10719== obj_realloc/TEST0 helgrind0.log ==10719== For counts of detected and suppressed errors, rerun with: -v obj_realloc/TEST0 helgrind0.log ==10719== Use --history-level=approx or =none to gain increased speed, at obj_realloc/TEST0 helgrind0.log ==10719== the cost of reduced accuracy of conflicting-access information obj_realloc/TEST0 helgrind0.log ==10719== ERROR SUMMARY: 1372 errors from 4 contexts (suppressed: 0 from 0) RUNTESTS: stopping: obj_realloc//TEST0 failed, TEST=all FS=any BUILD=debug

helgrind0.log

==10719== Helgrind, a thread error detector ==10719== Copyright (C) 2007-2015, and GNU GPL'd, by OpenWorks LLP et al. ==10719== Using Valgrind-3.12.0 and LibVEX; rerun with -h for copyright info ==10719== Command: ./obj_realloc /mnt/pmem/LoremipsumdolorsitametconsecteturadipiscingelitVivamuslacinianibhattortordictumsollicitudinNullamvariusvestibulumligulaetegestaselitsemperidMaurisultriciesligulaeuipsumtinciduntluctusMorbimaximusvariusdolorid/LoremipsumdolorsitametconsecteturadipiscingelitVivamuslacinianibhattortordictumsollicitudinNullamvariusvestibulumligulaetegestaselitsemperidMaurisultriciesligulaeuipsumtinciduntluctusMorbimaximusvariusdolorid/LoremipsumdolorsitametconsecteturadipiscingelitVivamuslacinianibhattortordictumsollicitudinNullamvariusvestibulumligulaetegestaselitsemperidMaurisultriciesligulaeuipsumtinciduntluctusMorbimaximusvariusdolorid/LoremipsumdolorsitametconsecteturadipiscingelitVivamuslacinianibhattortordictumsollicitudinNullamvariusvestibulumligulaetegestaselitsemperidMaurisultriciesligulaeuipsumtinciduntluctusMorbimaximusvariusdolorid/LoremipsumdolorsitametconsecteturadipiscingelitVivamuslacinianibhattortordictumsollicitudinNullamvariusvestibulumligulaetegestaselitsemperidMaurisultriciesligulaeuipsumtinciduntluctusMorbimaximusvariusdolorid/test_obj_realloc0😘⠝⠧⠍⠇ɗNVMLӜ⥺🙋/testfile1 ==10719== Parent PID: 10694 ==10719== ==10719== ---Thread-Announcement------------------------------------------ ==10719== ==10719== Thread #1 is the program's root thread ==10719== ==10719== ---------------------------------------------------------------- ==10719== ==10719== Thread #1: lock order "0x26213888 before 0x262DEBF0" violated ==10719== ==10719== Observed (incorrect) order is: acquisition of lock at 0x262DEBF0 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x114050: util_mutex_lock (sys_util.h:82) ==10719== by 0x11435E: heap_bucket_acquire_by_id (heap.c:216) ==10719== by 0x1165BC: heap_ensure_run_bucket_filled (heap.c:851) ==10719== by 0x116CD2: heap_get_bestfit_block (heap.c:987) ==10719== by 0x129C2D: palloc_reservation_create (palloc.c:194) ==10719== by 0x12A57F: palloc_operation (palloc.c:520) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x126B3D: obj_alloc_construct (obj.c:2025) ==10719== by 0x126C58: pmemobj_alloc (obj.c:2056) ==10719== ==10719== followed by a later acquisition of lock at 0x26213888 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x12D6DF: recycler_calc_score (recycler.c:158) ==10719== by 0x115CD0: heap_reclaim_run (heap.c:633) ==10719== by 0x116669: heap_ensure_run_bucket_filled (heap.c:864) ==10719== by 0x116CD2: heap_get_bestfit_block (heap.c:987) ==10719== by 0x129C2D: palloc_reservation_create (palloc.c:194) ==10719== by 0x12A57F: palloc_operation (palloc.c:520) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x126B3D: obj_alloc_construct (obj.c:2025) ==10719== by 0x126C58: pmemobj_alloc (obj.c:2056) ==10719== ==10719== Required order was established by acquisition of lock at 0x26213888 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x129636: util_mutex_lock (sys_util.h:82) ==10719== by 0x12A17E: palloc_exec_actions (palloc.c:394) ==10719== by 0x12A9A0: palloc_operation (palloc.c:566) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== by 0x12775C: pmemobj_realloc (obj.c:2271) ==10719== by 0x10D67D: test_realloc (obj_realloc.c:159) ==10719== by 0x10DA54: test_realloc_sizes (obj_realloc.c:212) ==10719== by 0x10DC2B: main (obj_realloc.c:256) ==10719== ==10719== followed by a later acquisition of lock at 0x262DEBF0 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x114050: util_mutex_lock (sys_util.h:82) ==10719== by 0x11435E: heap_bucket_acquire_by_id (heap.c:216) ==10719== by 0x129EC1: palloc_restore_free_chunk_state (palloc.c:273) ==10719== by 0x12A034: palloc_finalize_heap_action (palloc.c:304) ==10719== by 0x12A231: palloc_exec_actions (palloc.c:408) ==10719== by 0x12A9A0: palloc_operation (palloc.c:566) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== by 0x12775C: pmemobj_realloc (obj.c:2271) ==10719== ==10719== Lock at 0x26213888 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x113FA6: util_mutex_init (sys_util.h:52) ==10719== by 0x117B48: heap_boot (heap.c:1314) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== Address 0x26213888 is 2,120 bytes inside a block of size 51,288 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x117A38: heap_boot (heap.c:1289) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== by 0x10DB93: main (obj_realloc.c:242) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== Lock at 0x262DEBF0 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x10F601: util_mutex_init (sys_util.h:52) ==10719== by 0x10F701: bucket_new (bucket.c:69) ==10719== by 0x1175E2: heap_buckets_init (heap.c:1178) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== Address 0x262debf0 is 0 bytes inside a block of size 88 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x10F6C5: bucket_new (bucket.c:62) ==10719== by 0x1175E2: heap_buckets_init (heap.c:1178) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== by 0x10DB93: main (obj_realloc.c:242) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== ==10719== ---------------------------------------------------------------- ==10719== ==10719== Thread #1: lock order "0x26213888 before 0x262DEBF0" violated ==10719== ==10719== Observed (incorrect) order is: acquisition of lock at 0x262DEBF0 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x114050: util_mutex_lock (sys_util.h:82) ==10719== by 0x11435E: heap_bucket_acquire_by_id (heap.c:216) ==10719== by 0x1165BC: heap_ensure_run_bucket_filled (heap.c:851) ==10719== by 0x116CD2: heap_get_bestfit_block (heap.c:987) ==10719== by 0x129C2D: palloc_reservation_create (palloc.c:194) ==10719== by 0x12A57F: palloc_operation (palloc.c:520) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x126B3D: obj_alloc_construct (obj.c:2025) ==10719== by 0x126C58: pmemobj_alloc (obj.c:2056) ==10719== ==10719== followed by a later acquisition of lock at 0x26213888 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x114050: util_mutex_lock (sys_util.h:82) ==10719== by 0x1164AD: heap_reuse_from_recycler (heap.c:828) ==10719== by 0x1166AC: heap_ensure_run_bucket_filled (heap.c:871) ==10719== by 0x116CD2: heap_get_bestfit_block (heap.c:987) ==10719== by 0x129C2D: palloc_reservation_create (palloc.c:194) ==10719== by 0x12A57F: palloc_operation (palloc.c:520) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x126B3D: obj_alloc_construct (obj.c:2025) ==10719== by 0x126C58: pmemobj_alloc (obj.c:2056) ==10719== ==10719== Required order was established by acquisition of lock at 0x26213888 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x129636: util_mutex_lock (sys_util.h:82) ==10719== by 0x12A17E: palloc_exec_actions (palloc.c:394) ==10719== by 0x12A9A0: palloc_operation (palloc.c:566) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== by 0x12775C: pmemobj_realloc (obj.c:2271) ==10719== by 0x10D67D: test_realloc (obj_realloc.c:159) ==10719== by 0x10DA54: test_realloc_sizes (obj_realloc.c:212) ==10719== by 0x10DC2B: main (obj_realloc.c:256) ==10719== ==10719== followed by a later acquisition of lock at 0x262DEBF0 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x114050: util_mutex_lock (sys_util.h:82) ==10719== by 0x11435E: heap_bucket_acquire_by_id (heap.c:216) ==10719== by 0x129EC1: palloc_restore_free_chunk_state (palloc.c:273) ==10719== by 0x12A034: palloc_finalize_heap_action (palloc.c:304) ==10719== by 0x12A231: palloc_exec_actions (palloc.c:408) ==10719== by 0x12A9A0: palloc_operation (palloc.c:566) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== by 0x12775C: pmemobj_realloc (obj.c:2271) ==10719== ==10719== Lock at 0x26213888 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x113FA6: util_mutex_init (sys_util.h:52) ==10719== by 0x117B48: heap_boot (heap.c:1314) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== Address 0x26213888 is 2,120 bytes inside a block of size 51,288 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x117A38: heap_boot (heap.c:1289) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== by 0x10DB93: main (obj_realloc.c:242) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== Lock at 0x262DEBF0 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x10F601: util_mutex_init (sys_util.h:52) ==10719== by 0x10F701: bucket_new (bucket.c:69) ==10719== by 0x1175E2: heap_buckets_init (heap.c:1178) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== Address 0x262debf0 is 0 bytes inside a block of size 88 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x10F6C5: bucket_new (bucket.c:62) ==10719== by 0x1175E2: heap_buckets_init (heap.c:1178) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== by 0x10DB93: main (obj_realloc.c:242) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== ==10719== ---------------------------------------------------------------- ==10719== ==10719== Thread #1: lock order "0x26213C18 before 0x26213888" violated ==10719== ==10719== Observed (incorrect) order is: acquisition of lock at 0x26213888 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x129636: util_mutex_lock (sys_util.h:82) ==10719== by 0x12A17E: palloc_exec_actions (palloc.c:394) ==10719== by 0x12A9A0: palloc_operation (palloc.c:566) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== by 0x12775C: pmemobj_realloc (obj.c:2271) ==10719== by 0x10D67D: test_realloc (obj_realloc.c:159) ==10719== by 0x10DAD3: test_realloc_sizes (obj_realloc.c:224) ==10719== by 0x10DC2B: main (obj_realloc.c:256) ==10719== ==10719== followed by a later acquisition of lock at 0x26213C18 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x129636: util_mutex_lock (sys_util.h:82) ==10719== by 0x12A17E: palloc_exec_actions (palloc.c:394) ==10719== by 0x12A9A0: palloc_operation (palloc.c:566) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== by 0x12775C: pmemobj_realloc (obj.c:2271) ==10719== by 0x10D67D: test_realloc (obj_realloc.c:159) ==10719== by 0x10DAD3: test_realloc_sizes (obj_realloc.c:224) ==10719== by 0x10DC2B: main (obj_realloc.c:256) ==10719== ==10719== Lock at 0x26213C18 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x113FA6: util_mutex_init (sys_util.h:52) ==10719== by 0x117B48: heap_boot (heap.c:1314) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== Address 0x26213c18 is 3,032 bytes inside a block of size 51,288 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x117A38: heap_boot (heap.c:1289) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== by 0x10DB93: main (obj_realloc.c:242) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== Lock at 0x26213888 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x113FA6: util_mutex_init (sys_util.h:52) ==10719== by 0x117B48: heap_boot (heap.c:1314) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== Address 0x26213888 is 2,120 bytes inside a block of size 51,288 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x117A38: heap_boot (heap.c:1289) ==10719== by 0x12AE03: palloc_boot (palloc.c:682) ==10719== by 0x12BB7B: pmalloc_boot (pmalloc.c:277) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== by 0x10DB93: main (obj_realloc.c:242) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== ==10719== ---------------------------------------------------------------- ==10719== ==10719== Thread #1: lock order "0x262AF200 before 0x262DEBF0" violated ==10719== ==10719== Observed (incorrect) order is: acquisition of lock at 0x262DEBF0 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x114050: util_mutex_lock (sys_util.h:82) ==10719== by 0x11435E: heap_bucket_acquire_by_id (heap.c:216) ==10719== by 0x1165BC: heap_ensure_run_bucket_filled (heap.c:851) ==10719== by 0x116CD2: heap_get_bestfit_block (heap.c:987) ==10719== by 0x129C2D: palloc_reservation_create (palloc.c:194) ==10719== by 0x12A57F: palloc_operation (palloc.c:520) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== by 0x12787F: pmemobj_zrealloc (obj.c:2290) ==10719== ==10719== followed by a later acquisition of lock at 0x262AF200 ==10719== at 0x4C33E7D: mutex_lock_WRK (hg_intercepts.c:901) ==10719== by 0x4C37CE1: pthread_mutex_lock (hg_intercepts.c:917) ==10719== by 0x13D58B: os_mutex_lock (os_thread_linux.c:119) ==10719== by 0x12D44F: util_mutex_lock (sys_util.h:82) ==10719== by 0x12D9EC: recycler_get (recycler.c:261) ==10719== by 0x116484: heap_reuse_from_recycler (heap.c:825) ==10719== by 0x1166AC: heap_ensure_run_bucket_filled (heap.c:871) ==10719== by 0x116CD2: heap_get_bestfit_block (heap.c:987) ==10719== by 0x129C2D: palloc_reservation_create (palloc.c:194) ==10719== by 0x12A57F: palloc_operation (palloc.c:520) ==10719== by 0x12B52E: pmalloc_operation (pmalloc.c:118) ==10719== by 0x127382: obj_realloc_common (obj.c:2221) ==10719== ==10719== Lock at 0x262AF200 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x12D5C7: recycler_new (recycler.c:114) ==10719== by 0x117416: heap_create_alloc_class_buckets (heap.c:1135) ==10719== by 0x1175A6: heap_buckets_init (heap.c:1173) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== Address 0x262af200 is 96 bytes inside a block of size 144 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x12D502: recycler_new (recycler.c:98) ==10719== by 0x117416: heap_create_alloc_class_buckets (heap.c:1135) ==10719== by 0x1175A6: heap_buckets_init (heap.c:1173) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== Lock at 0x262DEBF0 was first observed ==10719== at 0x4C37CBE: pthread_mutex_init (hg_intercepts.c:779) ==10719== by 0x13D557: os_mutex_init (os_thread_linux.c:101) ==10719== by 0x10F601: util_mutex_init (sys_util.h:52) ==10719== by 0x10F701: bucket_new (bucket.c:69) ==10719== by 0x1175E2: heap_buckets_init (heap.c:1178) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== Address 0x262debf0 is 0 bytes inside a block of size 88 alloc'd ==10719== at 0x4C30FAD: malloc (vg_replace_malloc.c:299) ==10719== by 0x10F6C5: bucket_new (bucket.c:62) ==10719== by 0x1175E2: heap_buckets_init (heap.c:1178) ==10719== by 0x12AE21: palloc_buckets_init (palloc.c:692) ==10719== by 0x12BBCE: pmalloc_boot (pmalloc.c:289) ==10719== by 0x11A5E5: lane_recover_and_section_boot (lane.c:314) ==10719== by 0x123437: obj_boot (obj.c:729) ==10719== by 0x124901: obj_runtime_init (obj.c:1090) ==10719== by 0x125D8F: obj_open_common (obj.c:1615) ==10719== by 0x125EAD: pmemobj_openU (obj.c:1652) ==10719== by 0x125ED2: pmemobj_open (obj.c:1662) ==10719== by 0x10DB93: main (obj_realloc.c:242) ==10719== Block was alloc'd by thread #1 ==10719== ==10719== ==10719== ==10719== For counts of detected and suppressed errors, rerun with: -v ==10719== Use --history-level=approx or =none to gain increased speed, at ==10719== the cost of reduced accuracy of conflicting-access information ==10719== ERROR SUMMARY: 1372 errors from 4 contexts (suppressed: 0 from 0)

mramotowski commented 6 years ago

Verified on 45bc3820efb5815c116e31138139d26b242ab744