__step=000089 __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_abtree_tm_auto.debra.hybridnorec -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=data000089.txt __path_data=data/data000089.txt __hostname=jax REALTIME_MAIN_START_PERF_FORMAT=6994320.660130976 binary=./brown_abtree_tm_auto.debra.hybridnorec parsed custom binding: 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 DS_TYPENAME=brown_abtree_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=200 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 Hybrid noREC system ready Info: prefilling using hybrid approach; mixed then insert-only if needed. prefilling initialization took 0.008s prefilling_size=819440 prefilling_elapsed_millis=1.001s prefilling_size=898137 prefilling_elapsed_millis=1.101s prefilling_size=976117 prefilling_elapsed_millis=1.201s prefilling_size=1053238 prefilling_elapsed_millis=1.301s prefilling_size=1130020 prefilling_elapsed_millis=1.402s prefilling_size=1205728 prefilling_elapsed_millis=1.502s prefilling_size=1280655 prefilling_elapsed_millis=1.602s prefilling_size=1355079 prefilling_elapsed_millis=1.702s prefilling_size=1428901 prefilling_elapsed_millis=1.802s prefilling_size=1502131 prefilling_elapsed_millis=1.903s prefilling_size=1574386 prefilling_elapsed_millis=2.003s prefilling_size=1646728 prefilling_elapsed_millis=2.103s prefilling_size=1718184 prefilling_elapsed_millis=2.203s prefilling_size=1788653 prefilling_elapsed_millis=2.303s prefilling_size=1858792 prefilling_elapsed_millis=2.404s prefilling_size=1928405 prefilling_elapsed_millis=2.504s prefilling_size=1997729 prefilling_elapsed_millis=2.604s prefilling_size=2066272 prefilling_elapsed_millis=2.704s prefilling_size=2133561 prefilling_elapsed_millis=2.804s prefilling_size=2200621 prefilling_elapsed_millis=2.904s prefilling_size=2267012 prefilling_elapsed_millis=3.005s prefilling_size=2333132 prefilling_elapsed_millis=3.105s prefilling_size=2398650 prefilling_elapsed_millis=3.205s prefilling_size=2464132 prefilling_elapsed_millis=3.305s prefilling_size=2528635 prefilling_elapsed_millis=3.405s prefilling_size=2592493 prefilling_elapsed_millis=3.506s prefilling_size=2655693 prefilling_elapsed_millis=3.606s prefilling_size=2718476 prefilling_elapsed_millis=3.706s prefilling_size=2780698 prefilling_elapsed_millis=3.806s prefilling_size=2842092 prefilling_elapsed_millis=3.906s prefilling_size=2902938 prefilling_elapsed_millis=4.007s prefilling_size=2963632 prefilling_elapsed_millis=4.107s prefilling_size=3023440 prefilling_elapsed_millis=4.207s prefilling_size=3082899 prefilling_elapsed_millis=4.307s prefilling_size=3141588 prefilling_elapsed_millis=4.407s prefilling_size=3199879 prefilling_elapsed_millis=4.508s prefilling_size=3257516 prefilling_elapsed_millis=4.608s prefilling_size=3314403 prefilling_elapsed_millis=4.708s prefilling_size=3371424 prefilling_elapsed_millis=4.808s prefilling_size=3427538 prefilling_elapsed_millis=4.908s prefilling_size=3483370 prefilling_elapsed_millis=5.009s Info: prefilling requires an additional insert phase to complete. Info: prefilling using INSERTION ONLY. timing_start inserting 6516564 keys with 48 threads... tid=0 thread_prefill_amount=70822 percent_done_estimate=52.2 elapsed_s=5 est_remaining_s=11 / 16 tid=0 thread_prefill_amount=74988 percent_done_estimate=55.2 elapsed_s=5 est_remaining_s=10 / 15 tid=0 thread_prefill_amount=79154 percent_done_estimate=58.3 elapsed_s=6 est_remaining_s=9 / 15 tid=0 thread_prefill_amount=83320 percent_done_estimate=61.4 elapsed_s=6 est_remaining_s=8 / 14 tid=0 thread_prefill_amount=87486 percent_done_estimate=64.4 elapsed_s=6 est_remaining_s=8 / 14 tid=0 thread_prefill_amount=91652 percent_done_estimate=67.5 elapsed_s=6 est_remaining_s=7 / 13 tid=0 thread_prefill_amount=95818 percent_done_estimate=70.6 elapsed_s=7 est_remaining_s=6 / 13 tid=0 thread_prefill_amount=99984 percent_done_estimate=73.6 elapsed_s=7 est_remaining_s=6 / 12 tid=0 thread_prefill_amount=104150 percent_done_estimate=76.7 elapsed_s=7 est_remaining_s=5 / 12 tid=0 thread_prefill_amount=108316 percent_done_estimate=79.8 elapsed_s=7 est_remaining_s=4 / 12 tid=0 thread_prefill_amount=112482 percent_done_estimate=82.9 elapsed_s=8 est_remaining_s=4 / 11 tid=0 thread_prefill_amount=116648 percent_done_estimate=85.9 elapsed_s=8 est_remaining_s=3 / 11 tid=0 thread_prefill_amount=120814 percent_done_estimate=89.0 elapsed_s=8 est_remaining_s=2 / 10 tid=0 thread_prefill_amount=124980 percent_done_estimate=92.1 elapsed_s=8 est_remaining_s=2 / 10 tid=0 thread_prefill_amount=129146 percent_done_estimate=95.1 elapsed_s=9 est_remaining_s=1 / 10 tid=0 thread_prefill_amount=133312 percent_done_estimate=98.2 elapsed_s=9 est_remaining_s=0 / 9 tid=0 thread_prefill_amount=137478 percent_done_estimate=101.3 elapsed_s=9 est_remaining_s=-0 / 9 tid=0 thread_prefill_amount=141644 percent_done_estimate=104.3 elapsed_s=9 est_remaining_s=-1 / 8 tid=0 thread_prefill_amount=145810 percent_done_estimate=107.4 elapsed_s=10 est_remaining_s=-1 / 8 tid=0 thread_prefill_amount=149976 percent_done_estimate=110.5 elapsed_s=10 est_remaining_s=-2 / 8 tid=0 thread_prefill_amount=154142 percent_done_estimate=113.5 elapsed_s=10 est_remaining_s=-3 / 7 tid=0 thread_prefill_amount=158308 percent_done_estimate=116.6 elapsed_s=10 est_remaining_s=-3 / 7 tid=0 thread_prefill_amount=162474 percent_done_estimate=119.7 elapsed_s=11 est_remaining_s=-4 / 7 tid=0 thread_prefill_amount=166640 percent_done_estimate=122.7 elapsed_s=11 est_remaining_s=-5 / 6 tid=0 thread_prefill_amount=170806 percent_done_estimate=125.8 elapsed_s=11 est_remaining_s=-5 / 6 tid=0 thread_prefill_amount=174972 percent_done_estimate=128.9 elapsed_s=11 est_remaining_s=-6 / 6 tid=0 thread_prefill_amount=179138 percent_done_estimate=132.0 elapsed_s=12 est_remaining_s=-6 / 5 tid=0 thread_prefill_amount=183304 percent_done_estimate=135.0 elapsed_s=12 est_remaining_s=-7 / 5 tid=0 thread_prefill_amount=187470 percent_done_estimate=138.1 elapsed_s=12 est_remaining_s=-7 / 5 tid=0 thread_prefill_amount=191636 percent_done_estimate=141.2 elapsed_s=12 est_remaining_s=-8 / 4 tid=0 thread_prefill_amount=195802 percent_done_estimate=144.2 elapsed_s=12 est_remaining_s=-9 / 4 tid=0 thread_prefill_amount=199968 percent_done_estimate=147.3 elapsed_s=13 est_remaining_s=-9 / 3 tid=0 thread_prefill_amount=204134 percent_done_estimate=150.4 elapsed_s=13 est_remaining_s=-10 / 3 timing_elapsed 7.50314s prefilling_size=10000000 prefilling_elapsed_millis=7.521s finished prefilling to size 10000000 for expected size 10000000 keysum=100009789424363, performing 18597523 updates; total_prefilling_elapsed_ms=7521 ms) pref_size=10000000 pref_millis=7521 prefill_elapsed_ms=7521 main thread: starting timer... ############################################################################### ################################ BEGIN RUNNING ################################ ############################################################################### REALTIME_START_PERF_FORMAT=6994333.492172714 REALTIME_END_PERF_FORMAT=6994343.492244371 ############################################################################### ################################## 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 470 subtrees; running parallel for... computing stats for the top of the tree (above the partitions)... tree_stats_computeWalltime=0.015s tree_stats_numInternalsAtDepth=1 1 8 63 470 3408 25681 199840 0 tree_stats_numLeavesAtDepth=0 0 0 0 0 0 0 0 1576246 tree_stats_numNodesAtDepth=1 1 8 63 470 3408 25681 199840 1576246 tree_stats_numKeysAtDepth=0 0 0 0 0 0 0 0 10006395 tree_stats_avgDegreeAtDepth=1 8 7.875 7.46032 7.25106 7.5355 7.78163 7.88754 6.34824 tree_stats_height=9 tree_stats_numInternals=229472 tree_stats_numLeaves=1576246 tree_stats_numNodes=1805718 tree_stats_numKeys=10006395 tree_stats_avgDegreeInternal=7.86901 tree_stats_avgDegreeLeaves=6.34824 tree_stats_avgDegree=6.5415 tree_stats_avgKeyDepth=8 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=681790 first_thread_announced_epoch_by_thread=30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 30416 sum_commit_tx_reader_total= sum_commit_tx_reader_by_thread= sum_commit_tx_writer_total= sum_commit_tx_writer_by_thread= sum_abort_tx_total= sum_abort_tx_by_thread= max_ht_capacity_by_thread= linear_histogram_of_none_tx_rdset_size_full_data= linear_histogram_of_none_tx_wrset_size_full_data= 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=291492 294030 295989 295758 295694 293531 293452 295024 297129 297423 295705 293581 294880 295028 295218 294715 297276 295267 291655 294521 296646 296155 293780 293785 296084 298675 299778 301190 299713 299398 297581 300130 300474 301245 299681 298638 299675 298630 300252 300516 302337 299839 297259 298405 301357 302079 299187 300359 sum_num_inserts_total=14270216 sum_num_deletes_by_thread=291922 294781 294744 294859 296471 292850 293630 294021 297842 297177 295281 294488 294430 295638 295662 295971 297102 294759 292085 295426 296798 296810 295201 295064 295335 298553 300783 300147 299862 298229 298033 299147 301763 301497 299619 299426 299020 299319 300743 301388 300999 300388 296059 298195 300488 302154 299590 298905 sum_num_deletes_total=14272654 sum_num_searches_by_thread=5243093 5295248 5328849 5320527 5329809 5288323 5283492 5300600 5354884 5350115 5322081 5293625 5300788 5308342 5337141 5315873 5332731 5316392 5259119 5288345 5344555 5333313 5303300 5304439 5314980 5371375 5410411 5424779 5394855 5374139 5366684 5403109 5426630 5421352 5396792 5379706 5390525 5389089 5410519 5409436 5424582 5403535 5330934 5365948 5416993 5430823 5388822 5393589 sum_num_searches_total=256894591 sum_num_rq_by_thread= sum_num_rq_total= sum_num_operations_by_thread=5826507 5884059 5919582 5911144 5921974 5874704 5870574 5889645 5949855 5944715 5913067 5881694 5890098 5899008 5928021 5906559 5927109 5906418 5842859 5878292 5937999 5926278 5892281 5893288 5906399 5968603 6010972 6026116 5994430 5971766 5962298 6002386 6028867 6024094 5996092 5977770 5989220 5987038 6011514 6011340 6027918 6003762 5924252 5962548 6018838 6035056 5987599 5992853 average_num_operations_total=5946613 stdev_num_operations_total=8129 sum_num_operations_total=285437461 min_num_operations_total=5826507 max_num_operations_total=6035056 first_time_thread_terminate_by_thread=10000125 10000071 10000071 10000071 10000073 10000071 10000071 10000071 10000073 10000071 10000071 10000071 10000076 10000072 10000071 10000072 10000071 10000071 10000074 10000073 10000071 10000071 10000075 10000072 10000071 10000072 10000071 10000071 10000076 10000071 10000071 10000071 10000071 10000071 10000071 10000071 10000071 10000072 10000071 10000076 10000071 10000071 10000071 10000072 10000071 10000071 10000071 10000071 min_time_thread_terminate_total=10000071 max_time_thread_terminate_total=10000125 first_time_thread_start_by_thread=9 4 4 4 4 5 4 5 5 4 5 4 4 4 5 5 5 5 5 4 4 4 5 5 3 4 4 4 4 5 4 5 5 4 5 4 4 4 5 5 5 5 5 4 4 4 5 5 min_time_thread_start_total=3 max_time_thread_start_total=9 sum_duration_all_ops_total= threads_final_keysum=100067806355821 threads_final_size=10006395 final_keysum=100067806355821 final_size=10006395 validate_result=success Validation OK. Structural validation OK. total_find=256894591 total_rq=0 total_inserts=14270216 total_deletes=14272654 total_updates=28542870 total_queries=256894591 total_ops=285437461 find_throughput=25689459 rq_throughput=0 update_throughput=2854287 query_throughput=25689459 total_throughput=28543746 total find : 256894591 total rq : 0 total inserts : 14270216 total deletes : 14272654 total updates : 28542870 total queries : 256894591 total ops : 285437461 find throughput : 25689459 rq throughput : 0 update throughput : 2854287 query throughput : 25689459 total throughput : 28543746 elapsed milliseconds : 10000 napping milliseconds overtime : 100 PAPI_L2_TCM=18.5049 PAPI_L3_TCM=5.98957 PAPI_TOT_CYC=4677.85 PAPI_TOT_INS=1619.73 garbage=1283916675480203 total_execution_walltime=23.003s REALTIME_MAIN_END_PERF_FORMAT=6994343.664561353 Hybrid noREC system shutdown: HTM_ATTEMPT_THRESH=40 [fast htm] total fast htm commit : 299354528 [slow htm] [fallback] total fallback commit : 4680457 seconds global lock is held : 1.14819 [time_cmd_output] time_elapsed_sec=23.24, faults_major=0, faults_minor=464358, mem_maxresident_kb=1857756, user_cputime=1085.37, sys_cputime=3.86, percent_cpu=4685% timeout=false algorithm=brown_abtree_tm_auto.debra.hybridnorec thread_pinning=-pin 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 millis=10000 __trials=1