__step=000417 __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 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=data000417.txt __path_data=data/data000417.txt __hostname=jax REALTIME_MAIN_START_PERF_FORMAT=6983888.496699075 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=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=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.007s prefilling_size=5104422 prefilling_elapsed_millis=1.001s prefilling_size=5390441 prefilling_elapsed_millis=1.101s prefilling_size=5655984 prefilling_elapsed_millis=1.201s prefilling_size=5903647 prefilling_elapsed_millis=1.301s prefilling_size=6135074 prefilling_elapsed_millis=1.402s prefilling_size=6351868 prefilling_elapsed_millis=1.502s prefilling_size=6553842 prefilling_elapsed_millis=1.602s prefilling_size=6743886 prefilling_elapsed_millis=1.702s prefilling_size=6922325 prefilling_elapsed_millis=1.803s prefilling_size=7087971 prefilling_elapsed_millis=1.903s prefilling_size=7243401 prefilling_elapsed_millis=2.003s prefilling_size=7389901 prefilling_elapsed_millis=2.103s prefilling_size=7529314 prefilling_elapsed_millis=2.203s prefilling_size=7661389 prefilling_elapsed_millis=2.304s prefilling_size=7783725 prefilling_elapsed_millis=2.404s prefilling_size=7899635 prefilling_elapsed_millis=2.504s prefilling_size=8010744 prefilling_elapsed_millis=2.604s prefilling_size=8115100 prefilling_elapsed_millis=2.704s prefilling_size=8214857 prefilling_elapsed_millis=2.805s prefilling_size=8305556 prefilling_elapsed_millis=2.905s prefilling_size=8394008 prefilling_elapsed_millis=3.005s prefilling_size=8476759 prefilling_elapsed_millis=3.105s prefilling_size=8554526 prefilling_elapsed_millis=3.205s prefilling_size=8628135 prefilling_elapsed_millis=3.306s prefilling_size=8698257 prefilling_elapsed_millis=3.406s prefilling_size=8763122 prefilling_elapsed_millis=3.506s prefilling_size=8825100 prefilling_elapsed_millis=3.606s prefilling_size=8883526 prefilling_elapsed_millis=3.707s prefilling_size=8939553 prefilling_elapsed_millis=3.807s prefilling_size=8991856 prefilling_elapsed_millis=3.907s prefilling_size=9042471 prefilling_elapsed_millis=4.007s prefilling_size=9090612 prefilling_elapsed_millis=4.107s prefilling_size=9135134 prefilling_elapsed_millis=4.208s prefilling_size=9178065 prefilling_elapsed_millis=4.308s prefilling_size=9218680 prefilling_elapsed_millis=4.408s prefilling_size=9256356 prefilling_elapsed_millis=4.508s prefilling_size=9293183 prefilling_elapsed_millis=4.608s prefilling_size=9328914 prefilling_elapsed_millis=4.709s prefilling_size=9361421 prefilling_elapsed_millis=4.809s prefilling_size=9391839 prefilling_elapsed_millis=4.909s prefilling_size=9421743 prefilling_elapsed_millis=5.009s Info: prefilling requires an additional insert phase to complete. Info: prefilling using INSERTION ONLY. timing_start inserting 578259 keys with 48 threads... tid=0 thread_prefill_amount=220798 percent_done_estimate=1832.8 elapsed_s=5 est_remaining_s=-11 / -6 tid=0 thread_prefill_amount=224964 percent_done_estimate=1867.4 elapsed_s=5 est_remaining_s=-11 / -6 tid=0 thread_prefill_amount=229130 percent_done_estimate=1902.0 elapsed_s=5 est_remaining_s=-11 / -6 timing_elapsed 0.101257s prefilling_size=10000000 prefilling_elapsed_millis=0.101s finished prefilling to size 10000000 for expected size 10000000 keysum=100022185391728, performing 59300204 updates; total_prefilling_elapsed_ms=101 ms) pref_size=10000000 pref_millis=101 prefill_elapsed_ms=101 4NodeIxPvE_object_size=56 4NodeIxPvE_allocated_count=0 4NodeIxPvE_allocated_size=0MB 4NodeIxPvE_get_from_pool=0 4NodeIxPvE_deallocated=0 4NodeIxPvE_limbo_count=28697 4NodeIxPvE_limbo_details=9800 8524 10373 global_epoch_counter=2995 9SCXRecordIxPvE_object_size=128 9SCXRecordIxPvE_allocated_count=0 9SCXRecordIxPvE_allocated_size=0MB 9SCXRecordIxPvE_get_from_pool=0 9SCXRecordIxPvE_deallocated=0 9SCXRecordIxPvE_limbo_count=13226 9SCXRecordIxPvE_limbo_details=4527 3959 4740 global_epoch_counter=0 main thread: starting timer... ############################################################################### ################################ BEGIN RUNNING ################################ ############################################################################### REALTIME_START_PERF_FORMAT=6983893.884157234 REALTIME_END_PERF_FORMAT=6983903.884238559 ############################################################################### ################################## 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.089s tree_stats_numInternalsAtDepth=1 2 4 8 16 32 64 128 256 512 1024 2048 4096 8192 16384 32768 65531 130795 257544 485415 834031 1251913 1595949 1703781 1504089 1082765 622699 278785 93687 22348 3436 320 20 0 tree_stats_numLeavesAtDepth=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 5 267 4046 29673 136799 416149 907877 1488117 1903473 1925413 1542831 966613 463883 165026 41260 6552 620 40 tree_stats_numNodesAtDepth=1 2 4 8 16 32 64 128 256 512 1024 2048 4096 8192 16384 32768 65536 131062 261590 515088 970830 1668062 2503826 3191898 3407562 3008178 2165530 1245398 557570 187374 44696 6872 640 40 tree_stats_numKeysAtDepth=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 5 267 4046 29673 136799 416149 907877 1488117 1903473 1925413 1542831 966613 463883 165026 41260 6552 620 40 tree_stats_avgDegreeAtDepth=2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 1.99992 1.99796 1.98453 1.94239 1.85909 1.75052 1.6374 1.53378 1.4414 1.35994 1.28755 1.22385 1.16803 1.11927 1.07687 1.04657 1.03125 1 tree_stats_height=34 tree_stats_numInternals=9998643 tree_stats_numLeaves=9998644 tree_stats_numNodes=19997287 tree_stats_numKeys=9998644 tree_stats_avgDegreeInternal=2 tree_stats_avgDegreeLeaves=1 tree_stats_avgDegree=1.5 tree_stats_avgKeyDepth=24.5617 tree_stats_bytesAtDepth=56 112 224 448 896 1792 3584 7168 14336 28672 57344 114688 229376 458752 917504 1835008 3670016 7339472 14649040 28844928 54366480 93411472 140214256 178746288 190823472 168457968 121269680 69742288 31223920 10492944 2502976 384832 35840 2240 tree_stats_sizeInBytes=1119848072 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=11397 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:2 2:6 4:308 8:24429 16:210644 32:228502 64:15980 128:127 256:2 [2^00, 2^01]: 2 (2^01, 2^02]: 6 (2^02, 2^03]: 308 (2^03, 2^04]: 24429 (2^04, 2^05]: 210644 (2^05, 2^06]: 228502 (2^06, 2^07]: 15980 (2^07, 2^08]: 127 (2^08, 2^09]: 2 sum_limbo_reclamation_event_size_total=16794139 count_limbo_reclamation_event_size_by_thread=10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 10000 count_limbo_reclamation_event_size_total=480000 sum_limbo_reclamation_event_count_total=806682 first_thread_announced_epoch_by_thread=22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 22794 sum_num_inserts_by_thread=191597 193208 195284 194784 193606 190458 192276 193381 195256 195168 193281 192731 192938 193709 194971 195508 194066 192122 191526 192336 194751 193762 192108 190789 192358 192065 194886 195724 192892 191522 192127 193421 195338 195268 193754 192262 192211 193790 194654 194859 193789 191650 190727 193024 193285 194754 192125 191329 sum_num_inserts_total=9277430 sum_num_deletes_by_thread=191312 192288 194829 194216 193291 191142 191862 192743 195605 195064 192973 191741 192811 194070 195333 194769 193505 192909 191119 192721 193795 194339 192571 191401 192155 193479 194251 194934 192939 191072 192108 193043 195519 196121 193005 192895 192532 193212 195018 195056 193716 191994 191360 193111 193751 194936 192785 191259 sum_num_deletes_total=9276660 sum_num_searches_by_thread=3453683 3478455 3505201 3498109 3482045 3445844 3458948 3476808 3521840 3520301 3482587 3455933 3477736 3487935 3517557 3511681 3489001 3469271 3449721 3469544 3493821 3500549 3463396 3441319 3454181 3477280 3507420 3504616 3485367 3452643 3461851 3475680 3515396 3525457 3481574 3462646 3468976 3494620 3511519 3511834 3494103 3466086 3441844 3466339 3489254 3503117 3468643 3435300 sum_num_searches_total=167107031 sum_num_rq_by_thread= sum_num_rq_total= sum_num_operations_by_thread=3836592 3863951 3895314 3887109 3868942 3827444 3843086 3862932 3912701 3910533 3868841 3840405 3863485 3875714 3907861 3901958 3876572 3854302 3832366 3854601 3882367 3888650 3848075 3823509 3838694 3862824 3896557 3895274 3871198 3835237 3846086 3862144 3906253 3916846 3868333 3847803 3853719 3881622 3901191 3901749 3881608 3849730 3823931 3852474 3876290 3892807 3853553 3817888 average_num_operations_total=3867940 stdev_num_operations_total=3897 sum_num_operations_total=185661121 min_num_operations_total=3817888 max_num_operations_total=3916846 first_time_thread_terminate_by_thread=10000139 10000081 10000081 10000081 10000082 10000081 10000081 10000081 10000082 10000081 10000081 10000081 10000081 10000081 10000083 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000082 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000081 10000082 10000081 10000081 10000082 10000082 10000081 min_time_thread_terminate_total=10000081 max_time_thread_terminate_total=10000139 first_time_thread_start_by_thread=10 5 6 5 6 6 6 6 6 6 6 6 5 6 5 6 6 6 5 5 5 5 5 5 5 5 6 5 6 6 6 6 6 6 6 6 5 6 5 6 6 6 5 5 5 5 5 5 min_time_thread_start_total=5 max_time_thread_start_total=10 sum_duration_all_ops_total= threads_final_keysum=100003779916293 threads_final_size=9998644 final_keysum=100003779916293 final_size=9998644 validate_result=success Validation OK. Structural validation OK. total_find=167107031 total_rq=0 total_inserts=9277430 total_deletes=9276660 total_updates=18554090 total_queries=167107031 total_ops=185661121 find_throughput=16710703 rq_throughput=0 update_throughput=1855409 query_throughput=16710703 total_throughput=18566112 total find : 167107031 total rq : 0 total inserts : 9277430 total deletes : 9276660 total updates : 18554090 total queries : 167107031 total ops : 185661121 find throughput : 16710703 rq throughput : 0 update throughput : 1855409 query throughput : 16710703 total throughput : 18566112 elapsed milliseconds : 10000 napping milliseconds overtime : 100 PAPI_L2_TCM=35.9629 PAPI_L3_TCM=12.5172 PAPI_TOT_CYC=7208.1 PAPI_TOT_INS=435.076 garbage=835968782226330 total_execution_walltime=15.644s REALTIME_MAIN_END_PERF_FORMAT=6983904.142170345 [time_cmd_output] time_elapsed_sec=15.91, faults_major=0, faults_minor=607290, mem_maxresident_kb=2430216, user_cputime=738.65, sys_cputime=4.10, percent_cpu=4667% 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