__step=000081 __cmd_run=LD_PRELOAD=../../setbench/lib/libjemalloc.so timeout 60 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_ext_chromatic_lf.debra -nwork 48 -nprefill 48 -prefill-hybrid -prefill-hybrid-min-ms 1000 -prefill-hybrid-max-ms 5000 -insdel 0.5 0.5 -k 20000000 -t 10000 -pin 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 __file_data=data000081.txt __path_data=data/data000081.txt __hostname=jax REALTIME_MAIN_START_PERF_FORMAT=6979763.216132478 binary=./brown_ext_chromatic_lf.debra parsed custom binding: 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 DS_TYPENAME=brown_ext_chromatic_lf 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=0.5 DEL_FRAC=0.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=0.5 0.5 PREFILL_TYPE=PREFILL_HYBRID PREFILL_HYBRID_MIN_MS=1000 PREFILL_HYBRID_MAX_MS=5000 sizes: node=56 descriptor=128 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 Info: prefilling using hybrid approach; mixed then insert-only if needed. prefilling initialization took 0.004s prefilling_size=5124959 prefilling_elapsed_millis=1.001s prefilling_size=5410682 prefilling_elapsed_millis=1.101s prefilling_size=5677614 prefilling_elapsed_millis=1.201s prefilling_size=5924666 prefilling_elapsed_millis=1.301s prefilling_size=6156652 prefilling_elapsed_millis=1.402s prefilling_size=6375841 prefilling_elapsed_millis=1.502s prefilling_size=6577450 prefilling_elapsed_millis=1.602s prefilling_size=6767259 prefilling_elapsed_millis=1.702s prefilling_size=6947722 prefilling_elapsed_millis=1.802s prefilling_size=7116198 prefilling_elapsed_millis=1.902s prefilling_size=7274288 prefilling_elapsed_millis=2.003s prefilling_size=7422552 prefilling_elapsed_millis=2.103s prefilling_size=7561849 prefilling_elapsed_millis=2.203s prefilling_size=7693898 prefilling_elapsed_millis=2.303s prefilling_size=7816971 prefilling_elapsed_millis=2.404s prefilling_size=7934557 prefilling_elapsed_millis=2.504s prefilling_size=8044804 prefilling_elapsed_millis=2.604s prefilling_size=8148273 prefilling_elapsed_millis=2.704s prefilling_size=8246468 prefilling_elapsed_millis=2.804s prefilling_size=8340745 prefilling_elapsed_millis=2.905s prefilling_size=8427997 prefilling_elapsed_millis=3.005s prefilling_size=8509792 prefilling_elapsed_millis=3.105s prefilling_size=8586550 prefilling_elapsed_millis=3.205s prefilling_size=8660149 prefilling_elapsed_millis=3.305s prefilling_size=8729999 prefilling_elapsed_millis=3.406s prefilling_size=8796199 prefilling_elapsed_millis=3.506s prefilling_size=8856949 prefilling_elapsed_millis=3.606s prefilling_size=8914949 prefilling_elapsed_millis=3.706s prefilling_size=8971641 prefilling_elapsed_millis=3.806s prefilling_size=9025507 prefilling_elapsed_millis=3.907s prefilling_size=9076123 prefilling_elapsed_millis=4.007s prefilling_size=9121508 prefilling_elapsed_millis=4.107s prefilling_size=9166563 prefilling_elapsed_millis=4.207s prefilling_size=9209762 prefilling_elapsed_millis=4.307s prefilling_size=9249397 prefilling_elapsed_millis=4.408s prefilling_size=9288079 prefilling_elapsed_millis=4.508s prefilling_size=9324815 prefilling_elapsed_millis=4.608s prefilling_size=9357702 prefilling_elapsed_millis=4.708s prefilling_size=9389468 prefilling_elapsed_millis=4.808s prefilling_size=9421749 prefilling_elapsed_millis=4.909s prefilling_size=9451702 prefilling_elapsed_millis=5.009s Info: prefilling requires an additional insert phase to complete. Info: prefilling using INSERTION ONLY. timing_start inserting 548272 keys with 48 threads... tid=0 thread_prefill_amount=204134 percent_done_estimate=1787.1 elapsed_s=5 est_remaining_s=-11 / -6 tid=0 thread_prefill_amount=208300 percent_done_estimate=1823.6 elapsed_s=5 est_remaining_s=-11 / -6 tid=0 thread_prefill_amount=212466 percent_done_estimate=1860.1 elapsed_s=5 est_remaining_s=-11 / -6 timing_elapsed 0.0943831s prefilling_size=10000000 prefilling_elapsed_millis=0.094s finished prefilling to size 10000000 for expected size 10000000 keysum=100003916985142, performing 59250583 updates; total_prefilling_elapsed_ms=94 ms) pref_size=10000000 pref_millis=94 prefill_elapsed_ms=94 4NodeIxPvE_object_size=56 4NodeIxPvE_allocated_count=0 4NodeIxPvE_allocated_size=0MB 4NodeIxPvE_get_from_pool=0 4NodeIxPvE_deallocated=0 4NodeIxPvE_limbo_count=27931 4NodeIxPvE_limbo_details=8441 8659 10831 global_epoch_counter=2994 9SCXRecordIxPvE_object_size=128 9SCXRecordIxPvE_allocated_count=0 9SCXRecordIxPvE_allocated_size=0MB 9SCXRecordIxPvE_get_from_pool=0 9SCXRecordIxPvE_deallocated=0 9SCXRecordIxPvE_limbo_count=12800 9SCXRecordIxPvE_limbo_details=3891 3965 4944 global_epoch_counter=0 main thread: starting timer... ############################################################################### ################################ BEGIN RUNNING ################################ ############################################################################### REALTIME_START_PERF_FORMAT=6979768.596155274 REALTIME_END_PERF_FORMAT=6979778.596231167 ############################################################################### ################################## 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.087s tree_stats_numInternalsAtDepth=1 2 4 8 16 32 64 128 256 512 1024 2048 4096 8192 16384 32768 65507 130422 255092 474690 804897 1197524 1527354 1648476 1498063 1130021 694534 340014 126842 34340 6149 716 64 4 0 tree_stats_numLeavesAtDepth=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 29 592 5752 35494 144483 412270 867694 1406232 1798889 1866105 1565508 1049054 553186 219344 62531 11582 1368 124 8 tree_stats_numNodesAtDepth=1 2 4 8 16 32 64 128 256 512 1024 2048 4096 8192 16384 32768 65536 131014 260844 510184 949380 1609794 2395048 3054708 3296952 2996126 2260042 1389068 680028 253684 68680 12298 1432 128 8 tree_stats_numKeysAtDepth=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 29 592 5752 35494 144483 412270 867694 1406232 1798889 1866105 1565508 1049054 553186 219344 62531 11582 1368 124 8 tree_stats_avgDegreeAtDepth=2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 1.99956 1.99548 1.97795 1.93043 1.84781 1.7439 1.63771 1.53965 1.45438 1.37716 1.30731 1.24478 1.18652 1.13537 1.08953 1.05822 1.04469 1.03125 1 tree_stats_height=35 tree_stats_numInternals=10000244 tree_stats_numLeaves=10000245 tree_stats_numNodes=20000489 tree_stats_numKeys=10000245 tree_stats_avgDegreeInternal=2 tree_stats_avgDegreeLeaves=1 tree_stats_avgDegree=1.5 tree_stats_avgKeyDepth=24.6749 tree_stats_bytesAtDepth=56 112 224 448 896 1792 3584 7168 14336 28672 57344 114688 229376 458752 917504 1835008 3670016 7336784 14607264 28570304 53165280 90148464 134122688 171063648 184629312 167783056 126562352 77787808 38081568 14206304 3846080 688688 80192 7168 448 tree_stats_sizeInBytes=1120027384 4NodeIxPvE_object_size=56 4NodeIxPvE_allocated_count=0 4NodeIxPvE_allocated_size=0MB 4NodeIxPvE_get_from_pool=0 4NodeIxPvE_deallocated=0 4NodeIxPvE_limbo_count=0 4NodeIxPvE_limbo_details=0 0 0 global_epoch_counter=11722 9SCXRecordIxPvE_object_size=128 9SCXRecordIxPvE_allocated_count=0 9SCXRecordIxPvE_allocated_size=0MB 9SCXRecordIxPvE_get_from_pool=0 9SCXRecordIxPvE_deallocated=0 9SCXRecordIxPvE_limbo_count=0 9SCXRecordIxPvE_limbo_details=0 0 0 global_epoch_counter=0 log_histogram_of_none_limbo_reclamation_event_size_full_data=1:82071 2:131999 4:146765 8:48234 16:1737 32:21 64:126 128:116 256:3 [2^00, 2^01]: 82071 (2^01, 2^02]: 131999 (2^02, 2^03]: 146765 (2^03, 2^04]: 48234 (2^04, 2^05]: 1737 (2^05, 2^06]: 21 (2^06, 2^07]: 126 (2^07, 2^08]: 116 (2^08, 2^09]: 3 sum_limbo_reclamation_event_size_total=1719910 count_limbo_reclamation_event_size_by_thread=8569 8528 8631 8546 8570 8498 8548 8538 8597 8504 8616 8526 8579 8571 8529 8598 8572 8504 8522 8643 8502 8590 8598 8519 8580 8627 8570 8666 8624 8546 8516 8589 8565 8562 8556 8544 8586 8581 8513 8589 8551 8516 8479 8579 8662 8561 8559 8553 count_limbo_reclamation_event_size_total=411072 sum_limbo_reclamation_event_count_total=837952 first_thread_announced_epoch_by_thread=23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 23444 sum_num_inserts_by_thread=19912 20117 20242 20402 19953 19623 20121 19968 20188 20380 20300 19935 20252 20319 20393 20190 20096 20255 20009 20385 20187 20246 20144 20135 20107 20157 20298 20081 20337 19884 20067 20263 20351 20215 20240 20007 19968 20236 20236 20271 20395 19928 20010 19926 20266 20353 20266 20137 sum_num_inserts_total=967751 sum_num_deletes_by_thread=20082 20223 20314 20262 20045 20098 19871 20037 20507 20252 20142 20058 20269 20218 20218 20381 20312 20007 19955 20275 20033 20276 19923 19899 19783 20130 20400 20425 20427 19939 19996 19960 20474 20232 20305 19973 19929 19861 20431 20183 20060 20083 19750 20198 20317 20351 19974 19879 sum_num_deletes_total=966717 sum_num_searches_by_thread=3955380 3979108 4012151 4009688 3988283 3948232 3965293 3987774 4032966 4033894 3980036 3960638 3975071 3998285 4027483 4025147 3998606 3969766 3941991 3968034 3998640 4020373 3969609 3935816 3958696 3978091 4012901 4008773 3994645 3948442 3969187 3985518 4031450 4036448 3983417 3961090 3976797 4000712 4028255 4018312 3997745 3968987 3942583 3969144 3990311 4017471 3967390 3935947 sum_num_searches_total=191364576 sum_num_rq_by_thread= sum_num_rq_total= sum_num_operations_by_thread=3995374 4019448 4052707 4050352 4028281 3987953 4005285 4027779 4073661 4074526 4020478 4000631 4015592 4038822 4068094 4065718 4039014 4010028 3981955 4008694 4038860 4060895 4009676 3975850 3998586 4018378 4053599 4049279 4035409 3988265 4009250 4025741 4072275 4076895 4023962 4001070 4016694 4040809 4068922 4058766 4038200 4008998 3982343 4009268 4030894 4058175 4007630 3975963 average_num_operations_total=4027063 stdev_num_operations_total=4195 sum_num_operations_total=193299044 min_num_operations_total=3975850 max_num_operations_total=4076895 first_time_thread_terminate_by_thread=10000121 10000077 10000076 10000075 10000075 10000076 10000075 10000075 10000075 10000075 10000075 10000076 10000076 10000076 10000075 10000076 10000075 10000075 10000075 10000076 10000076 10000076 10000076 10000075 10000075 10000075 10000076 10000075 10000075 10000076 10000075 10000075 10000076 10000075 10000075 10000097 10000075 10000075 10000076 10000075 10000075 10000075 10000075 10000076 10000076 10000076 10000076 10000075 min_time_thread_terminate_total=10000075 max_time_thread_terminate_total=10000121 first_time_thread_start_by_thread=10 5 5 5 5 5 6 5 6 6 5 5 5 5 5 5 5 6 5 5 6 5 6 5 5 5 5 5 5 5 6 5 6 6 5 5 5 5 5 5 5 6 5 5 6 5 6 5 min_time_thread_start_total=5 max_time_thread_start_total=10 sum_duration_all_ops_total= threads_final_keysum=100003590071256 threads_final_size=10000245 final_keysum=100003590071256 final_size=10000245 validate_result=success Validation OK. Structural validation OK. total_find=191364576 total_rq=0 total_inserts=967751 total_deletes=966717 total_updates=1934468 total_queries=191364576 total_ops=193299044 find_throughput=19136457 rq_throughput=0 update_throughput=193446 query_throughput=19136457 total_throughput=19329904 total find : 191364576 total rq : 0 total inserts : 967751 total deletes : 966717 total updates : 1934468 total queries : 191364576 total ops : 193299044 find throughput : 19136457 rq throughput : 0 update throughput : 193446 query throughput : 19136457 total throughput : 19329904 elapsed milliseconds : 10000 napping milliseconds overtime : 100 PAPI_L2_TCM=33.9509 PAPI_L3_TCM=11.5675 PAPI_TOT_CYC=6925.28 PAPI_TOT_INS=359.355 garbage=957312193805413 total_execution_walltime=15.635s REALTIME_MAIN_END_PERF_FORMAT=6979778.852462883 [time_cmd_output] time_elapsed_sec=15.92, faults_major=0, faults_minor=590158, mem_maxresident_kb=2361812, user_cputime=738.41, sys_cputime=4.90, percent_cpu=4668% timeout=false algorithm=brown_ext_chromatic_lf.debra thread_pinning=-pin 0-23,96-119,24-47,120-143,48-71,144-167,72-95,168-191 millis=10000 __trials=1