__step=000041 __cmd_run=LD_PRELOAD=../../setbench/lib/libjemalloc.so timeout 180 numactl -i all /usr/bin/time -f "[time_cmd_output] time_elapsed_sec=%e, faults_major=%F, faults_minor=%R, mem_maxresident_kb=%M, user_cputime=%U, sys_cputime=%S, percent_cpu=%P" ./brown_sigouin_int_avl_tm_auto.debra.norec -nwork 48 -nprefill 48 -prefill-hybrid -prefill-hybrid-min-ms 1000 -prefill-hybrid-max-ms 5000 -insdel 5.0 5.0 -k 20000000 -t 10000 -pin 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 __file_data=data000041.txt __path_data=data/data000041.txt __hostname=jax REALTIME_MAIN_START_PERF_FORMAT=6992461.709593122 binary=./brown_sigouin_int_avl_tm_auto.debra.norec parsed custom binding: 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 DS_TYPENAME=brown_sigouin_int_avl_tm_auto FIND_FUNC=FIND_FUNC INSERT_FUNC=insertIfAbsent ERASE_FUNC=ERASE_FUNC RQ_FUNC=RQ_FUNC RECLAIM=reclaimer_debra ALLOC=allocator_new POOL=pool_none MAX_THREADS_POW2=512 CPU_FREQ_GHZ=2.1 MILLIS_TO_RUN=10000 INS_FRAC=5 DEL_FRAC=5 RQ=0 RQSIZE=0 MAXKEY=20000000 PREFILL_THREADS=48 DESIRED_PREFILL_SIZE=-1 TOTAL_THREADS=48 WORK_THREADS=48 RQ_THREADS=0 distribution=0 INS_DEL_FRAC=5.0 5.0 PREFILL_TYPE=PREFILL_HYBRID PREFILL_HYBRID_MIN_MS=1000 PREFILL_HYBRID_MAX_MS=5000 sizes: node=48 ACTUAL_THREAD_BINDINGS=0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,96,97,98,99,100,101,102,103,104,105,106,107,108,109,110,111,112,113,114,115,116,117,118,119 noREC system ready Info: prefilling using hybrid approach; mixed then insert-only if needed. prefilling initialization took 0.029s prefilling_size=922249 prefilling_elapsed_millis=1.001s prefilling_size=1010318 prefilling_elapsed_millis=1.101s prefilling_size=1098053 prefilling_elapsed_millis=1.201s prefilling_size=1185214 prefilling_elapsed_millis=1.301s prefilling_size=1270960 prefilling_elapsed_millis=1.402s prefilling_size=1355948 prefilling_elapsed_millis=1.502s prefilling_size=1440771 prefilling_elapsed_millis=1.602s prefilling_size=1524817 prefilling_elapsed_millis=1.702s prefilling_size=1607849 prefilling_elapsed_millis=1.802s prefilling_size=1690411 prefilling_elapsed_millis=1.903s prefilling_size=1771378 prefilling_elapsed_millis=2.003s prefilling_size=1852325 prefilling_elapsed_millis=2.103s prefilling_size=1932572 prefilling_elapsed_millis=2.203s prefilling_size=2012023 prefilling_elapsed_millis=2.303s prefilling_size=2090537 prefilling_elapsed_millis=2.404s prefilling_size=2168155 prefilling_elapsed_millis=2.504s prefilling_size=2245143 prefilling_elapsed_millis=2.604s prefilling_size=2321929 prefilling_elapsed_millis=2.704s prefilling_size=2398055 prefilling_elapsed_millis=2.804s prefilling_size=2473373 prefilling_elapsed_millis=2.905s prefilling_size=2548267 prefilling_elapsed_millis=3.005s prefilling_size=2621869 prefilling_elapsed_millis=3.105s prefilling_size=2694820 prefilling_elapsed_millis=3.205s prefilling_size=2767535 prefilling_elapsed_millis=3.305s prefilling_size=2839292 prefilling_elapsed_millis=3.405s prefilling_size=2910298 prefilling_elapsed_millis=3.506s prefilling_size=2980674 prefilling_elapsed_millis=3.606s prefilling_size=3050612 prefilling_elapsed_millis=3.706s prefilling_size=3119872 prefilling_elapsed_millis=3.806s prefilling_size=3188500 prefilling_elapsed_millis=3.906s prefilling_size=3255704 prefilling_elapsed_millis=4.007s prefilling_size=3322801 prefilling_elapsed_millis=4.107s prefilling_size=3389288 prefilling_elapsed_millis=4.207s prefilling_size=3454931 prefilling_elapsed_millis=4.307s prefilling_size=3520442 prefilling_elapsed_millis=4.407s prefilling_size=3585193 prefilling_elapsed_millis=4.508s prefilling_size=3649304 prefilling_elapsed_millis=4.608s prefilling_size=3713104 prefilling_elapsed_millis=4.708s prefilling_size=3775583 prefilling_elapsed_millis=4.808s prefilling_size=3837665 prefilling_elapsed_millis=4.908s prefilling_size=3898860 prefilling_elapsed_millis=5.009s Info: prefilling requires an additional insert phase to complete. Info: prefilling using INSERTION ONLY. timing_start inserting 6101076 keys with 48 threads... tid=0 thread_prefill_amount=83320 percent_done_estimate=65.6 elapsed_s=5 est_remaining_s=6 / 12 tid=0 thread_prefill_amount=87486 percent_done_estimate=68.8 elapsed_s=6 est_remaining_s=6 / 11 tid=0 thread_prefill_amount=91652 percent_done_estimate=72.1 elapsed_s=6 est_remaining_s=5 / 11 tid=0 thread_prefill_amount=95818 percent_done_estimate=75.4 elapsed_s=6 est_remaining_s=4 / 10 tid=0 thread_prefill_amount=99984 percent_done_estimate=78.7 elapsed_s=6 est_remaining_s=4 / 10 tid=0 thread_prefill_amount=104150 percent_done_estimate=81.9 elapsed_s=6 est_remaining_s=3 / 9 tid=0 thread_prefill_amount=108316 percent_done_estimate=85.2 elapsed_s=7 est_remaining_s=3 / 9 tid=0 thread_prefill_amount=112482 percent_done_estimate=88.5 elapsed_s=7 est_remaining_s=2 / 9 tid=0 thread_prefill_amount=116648 percent_done_estimate=91.8 elapsed_s=7 est_remaining_s=1 / 8 tid=0 thread_prefill_amount=120814 percent_done_estimate=95.0 elapsed_s=7 est_remaining_s=1 / 8 tid=0 thread_prefill_amount=124980 percent_done_estimate=98.3 elapsed_s=7 est_remaining_s=0 / 8 tid=0 thread_prefill_amount=129146 percent_done_estimate=101.6 elapsed_s=8 est_remaining_s=-0 / 7 tid=0 thread_prefill_amount=133312 percent_done_estimate=104.9 elapsed_s=8 est_remaining_s=-1 / 7 tid=0 thread_prefill_amount=137478 percent_done_estimate=108.2 elapsed_s=8 est_remaining_s=-1 / 7 tid=0 thread_prefill_amount=141644 percent_done_estimate=111.4 elapsed_s=8 est_remaining_s=-2 / 6 tid=0 thread_prefill_amount=145810 percent_done_estimate=114.7 elapsed_s=8 est_remaining_s=-2 / 6 tid=0 thread_prefill_amount=149976 percent_done_estimate=118.0 elapsed_s=9 est_remaining_s=-3 / 6 tid=0 thread_prefill_amount=154142 percent_done_estimate=121.3 elapsed_s=9 est_remaining_s=-3 / 5 tid=0 thread_prefill_amount=158308 percent_done_estimate=124.5 elapsed_s=9 est_remaining_s=-4 / 5 tid=0 thread_prefill_amount=162474 percent_done_estimate=127.8 elapsed_s=9 est_remaining_s=-5 / 5 tid=0 thread_prefill_amount=166640 percent_done_estimate=131.1 elapsed_s=9 est_remaining_s=-5 / 4 tid=0 thread_prefill_amount=170806 percent_done_estimate=134.4 elapsed_s=10 est_remaining_s=-6 / 4 tid=0 thread_prefill_amount=174972 percent_done_estimate=137.7 elapsed_s=10 est_remaining_s=-6 / 4 tid=0 thread_prefill_amount=179138 percent_done_estimate=140.9 elapsed_s=10 est_remaining_s=-7 / 3 tid=0 thread_prefill_amount=183304 percent_done_estimate=144.2 elapsed_s=10 est_remaining_s=-7 / 3 tid=0 thread_prefill_amount=187470 percent_done_estimate=147.5 elapsed_s=10 est_remaining_s=-8 / 3 tid=0 thread_prefill_amount=191636 percent_done_estimate=150.8 elapsed_s=11 est_remaining_s=-8 / 3 tid=0 thread_prefill_amount=195802 percent_done_estimate=154.0 elapsed_s=11 est_remaining_s=-9 / 2 tid=0 thread_prefill_amount=199968 percent_done_estimate=157.3 elapsed_s=11 est_remaining_s=-9 / 2 tid=0 thread_prefill_amount=204134 percent_done_estimate=160.6 elapsed_s=11 est_remaining_s=-10 / 2 timing_elapsed 6.26538s prefilling_size=10000000 prefilling_elapsed_millis=6.28s finished prefilling to size 10000000 for expected size 10000000 keysum=100008359709288, performing 19428690 updates; total_prefilling_elapsed_ms=6280 ms) pref_size=10000000 pref_millis=6280 prefill_elapsed_ms=6280 main thread: starting timer... ############################################################################### ################################ BEGIN RUNNING ################################ ############################################################################### REALTIME_START_PERF_FORMAT=6992473.368186971 REALTIME_END_PERF_FORMAT=6992483.368259647 ############################################################################### ################################## TIME IS UP ################################# ############################################################################### joining threads... ############################################################################### ################################# END RUNNING ################################# ############################################################################### 10.1s PRODUCING OUTPUT computing tree_stats in PARALLEL... bounded depth BFS to partition into subtrees for parallel computation (48 threads)... partitioned into 256 subtrees; running parallel for... computing stats for the top of the tree (above the partitions)... tree_stats_computeWalltime=0.045s tree_stats_numInternalsAtDepth=1 2 4 8 16 32 64 128 256 512 1024 2048 4096 8192 16384 32768 65536 131071 261967 518792 963237 1434831 1393818 729856 166923 12140 80 0 tree_stats_numLeavesAtDepth=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 162 4632 64207 403229 1146519 1513754 899707 212709 15270 96 tree_stats_numNodesAtDepth=1 2 4 8 16 32 64 128 256 512 1024 2048 4096 8192 16384 32768 65536 131072 262129 523424 1027444 1838060 2540337 2243610 1066630 224849 15350 96 tree_stats_numKeysAtDepth=1 2 4 8 16 32 64 128 256 512 1024 2048 4096 8192 16384 32768 65536 131072 262129 523424 1027444 1838060 2540337 2243610 1066630 224849 15350 96 tree_stats_avgDegreeAtDepth=2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 1.99989 1.99744 1.97178 1.85146 1.60145 1.33452 1.1501 1.05431 1.01428 1.00104 1 tree_stats_height=28 tree_stats_numInternals=5743786 tree_stats_numLeaves=4260286 tree_stats_numNodes=10004072 tree_stats_numKeys=10004072 tree_stats_avgDegreeInternal=1.74172 tree_stats_avgDegreeLeaves=1 tree_stats_avgDegree=1.42586 tree_stats_avgKeyDepth=21.703 log_histogram_of_none_limbo_reclamation_event_size_full_data=1:0 [2^00, 2^01]: 0 sum_limbo_reclamation_event_size_total= count_limbo_reclamation_event_size_by_thread= count_limbo_reclamation_event_size_total= sum_limbo_reclamation_event_count_total=230351 first_thread_announced_epoch_by_thread=11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 11446 sum_commit_tx_reader_total=101042420 sum_commit_tx_reader_by_thread=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2097390 2106416 2103470 2117739 2111650 2094258 2121501 2105434 2096216 2121639 2128014 2130890 2103935 2133720 2116231 2114002 2110902 2084800 2103563 2098119 2118420 2102635 2106022 2081300 2104274 2082042 2113178 2107784 2101271 2124121 2115703 2099027 2097292 2096145 2096778 2105226 2115848 2096012 2086627 2121603 2083982 2112902 2101828 2097105 2092814 2084546 2109991 2088055 sum_commit_tx_writer_total=5315308 sum_commit_tx_writer_by_thread=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 110263 111022 110171 111859 110702 110423 111482 110895 109667 112285 111729 112018 110326 112268 111377 110690 111242 109308 110259 110826 111294 110815 111004 109787 110850 109584 111036 110846 110067 111496 111734 111055 110691 110429 110069 110795 110922 110466 109362 111860 109351 111517 110447 110959 110192 109849 110459 109560 sum_abort_tx_total=167 sum_abort_tx_by_thread=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 7 4 1 1 1 5 4 7 1 3 2 2 6 5 2 3 3 2 3 4 3 4 1 0 2 5 4 3 6 5 3 2 3 2 2 4 8 1 5 5 4 4 2 4 5 4 2 8 max_ht_capacity_by_thread=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 2048 linear_histogram_of_none_tx_rdset_size_full_data=23.9:5 33.8:65 43.7:2328 53.6:41920 63.5:3110 73.4:478 83.3:72 93.2:18 103.1:2 113:1 [ 14.00, 23.90]: 5 ( 23.90, 33.80]: 65 ( 33.80, 43.70]: 2328 ( 43.70, 53.60]: 41920 ( 53.60, 63.50]: 3110 ( 63.50, 73.40]: 478 ( 73.40, 83.30]: 72 ( 83.30, 93.20]: 18 ( 93.20, 103.10]: 2 ( 103.10, 113.00]: 1 linear_histogram_of_none_tx_wrset_size_full_data=3.8:14443 6.6:3350 9.4:10773 12.2:5651 15:8384 17.8:3839 20.6:522 23.4:947 26.2:82 29:7 [ 1.00, 3.80]: 14443 ( 3.80, 6.60]: 3350 ( 6.60, 9.40]: 10773 ( 9.40, 12.20]: 5651 ( 12.20, 15.00]: 8384 ( 15.00, 17.80]: 3839 ( 17.80, 20.60]: 522 ( 20.60, 23.40]: 947 ( 23.40, 26.20]: 82 ( 26.20, 29.00]: 7 sum_fasthtm_commit_total= sum_fasthtm_abort_total= sum_htmpostfix_commit_total= sum_htmpostfix_abort_total= sum_htmprefix_commit_total= sum_htmprefix_abort_total= sum_htmprefix_abort_explicit_total= sum_htmprefix_abort_conflict_total= sum_htmprefix_abort_capacity_total= sum_htmprefix_abort_nesting_total= sum_htmprefix_abort_illegal_total= sum_htmprefix_abort_zero_total= sum_stmprefix_abort_total= sum_stmprefix_commit_total= sum_slow_commit_total= sum_abtree_insert_repeat_total= sum_abtree_erase_repeat_total= sum_abtree_search_repeat_total= sum_abtree_search_complete_total= sum_abtree_fix_weight_viol_attempt_total= sum_abtree_fix_degree_viol_attempt_total= sum_abtree_rebalancing_kcas_attempt_total= sum_abtree_update_kcas_attempt_total= sum_abtree_internal_complex_search_while_iters_total= sum_abtree_internal_basic_search_while_iters_total= sum_kcas_desc_new_total= sum_num_inserts_by_thread=109963 110761 111652 110379 111150 110050 109864 111646 110177 111908 110902 110063 111380 111239 111544 111799 111137 109315 109438 111059 110404 111577 110443 109441 110644 110645 110746 111124 110334 109296 110261 111232 111252 112206 111195 109881 110781 110699 111644 112022 111375 109635 109406 110535 110945 110964 110147 110236 sum_num_inserts_total=5314496 sum_num_deletes_by_thread=110046 110426 111463 110866 110648 110315 108964 110723 110576 112519 110448 110341 111683 110526 111557 112075 112018 109567 109233 110681 110989 111496 110197 110209 110129 110607 111397 110098 110871 109441 110364 111490 111641 111605 111261 110595 111327 110087 111603 111883 110687 109387 109699 110869 111017 110798 110120 110595 sum_num_deletes_total=5315137 sum_num_searches_by_thread=1982997 1999263 2009868 1995084 1993326 1985518 1974505 2002323 1993069 2021561 1992911 1984277 2006535 1996865 2010362 2010050 2004282 1975226 1977318 1995698 1987552 2001346 1987013 1971976 1987210 1986812 2004627 1992228 1985369 1972350 1986222 1999422 2006821 2019097 2005152 1990862 2002106 1991489 2012370 2015838 1993959 1975373 1978510 1988678 2000390 1995264 1993374 1985647 sum_num_searches_total=95728095 sum_num_rq_by_thread= sum_num_rq_total= sum_num_operations_by_thread=2203006 2220450 2232983 2216329 2215124 2205883 2193333 2224692 2213822 2245988 2214261 2204681 2229598 2218630 2233463 2233924 2227437 2194108 2195989 2217438 2208945 2224419 2207653 2191626 2207983 2208064 2226770 2213450 2206574 2191087 2206847 2222144 2229714 2242908 2227608 2211338 2224214 2212275 2235617 2239743 2216021 2194395 2197615 2210082 2222352 2217026 2213641 2206478 average_num_operations_total=2215786 stdev_num_operations_total=2015 sum_num_operations_total=106357728 min_num_operations_total=2191087 max_num_operations_total=2245988 first_time_thread_terminate_by_thread=10000123 10000074 10000072 10000073 10000073 10000072 10000073 10000072 10000073 10000072 10000072 10000072 10000072 10000072 10000074 10000072 10000074 10000072 10000073 10000072 10000072 10000072 10000072 10000072 10000074 10000072 10000072 10000073 10000073 10000073 10000072 10000072 10000073 10000072 10000072 10000072 10000072 10000073 10000073 10000073 10000072 10000072 10000073 10000072 10000072 10000073 10000073 10000073 min_time_thread_terminate_total=10000072 max_time_thread_terminate_total=10000123 first_time_thread_start_by_thread=9 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 4 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 min_time_thread_start_total=4 max_time_thread_start_total=9 sum_duration_all_ops_total= threads_final_keysum=100042308062340 threads_final_size=10004072 final_keysum=100042308062340 final_size=10004072 validate_result=success Validation OK. Structural validation OK. total_find=95728095 total_rq=0 total_inserts=5314496 total_deletes=5315137 total_updates=10629633 total_queries=95728095 total_ops=106357728 find_throughput=9572809 rq_throughput=0 update_throughput=1062963 query_throughput=9572809 total_throughput=10635772 total find : 95728095 total rq : 0 total inserts : 5314496 total deletes : 5315137 total updates : 10629633 total queries : 95728095 total ops : 106357728 find throughput : 9572809 rq throughput : 0 update throughput : 1062963 query throughput : 9572809 total throughput : 10635772 elapsed milliseconds : 10000 napping milliseconds overtime : 100 PAPI_L2_TCM=21.5431 PAPI_L3_TCM=5.93256 PAPI_TOT_CYC=10974.3 PAPI_TOT_INS=6605.53 garbage=478344449489290 total_execution_walltime=22.007s REALTIME_MAIN_END_PERF_FORMAT=6992483.717809223 noREC system shutdown: [time_cmd_output] time_elapsed_sec=22.17, faults_major=0, faults_minor=232021, mem_maxresident_kb=928352, user_cputime=1009.37, sys_cputime=24.58, percent_cpu=4663% timeout=false algorithm=brown_sigouin_int_avl_tm_auto.debra.norec thread_pinning=-pin 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 millis=10000 __trials=1