Aaron Wishnick
05/10/2021, 9:26 PMAssembled and processed 7990100 records from 17 columns in 121766 ms: 65.618484 rec/ms, 1115.5142 cell/ms
time spent so far 0% reading (237 ms) and 99% processing (121766 ms)
at row 7990100. reading next block
block read in memory in 44 ms. row count = 1418384
Finished building StatsCollector!
Collected stats for 9408484 documents
Created dictionary for INT column: ...
...
RecordReader initialized will read a total of 9408484 records.
at row 0. reading next block
Got brand-new decompressor [.gz]
block read in memory in 133 ms. row count = 7990100
Start building IndexCreator!
Assembled and processed 7990100 records from 17 columns in 127060 ms: 62.884464 rec/ms, 1069.0359 cell/ms
time spent so far 0% reading (133 ms) and 99% processing (127060 ms)
at row 7990100. reading next block
block read in memory in 26 ms. row count = 1418384
Finished records indexing in IndexCreator!
Finished segment seal!
...
Generated 25884 star-tree records from 9408484 segment records
Finished constructing star-tree, got 1228 tree nodes and 2058 records under star-node
Finished creating aggregated documents, got 1227 aggregated records
Finished building star-tree in 276631ms
Starting building star-tree with config: StarTreeV2BuilderConfig[...]
Generated 9408484 star-tree records from 9408484 segment records
It's been stuck at that last line for a long time but still seems to be doing something. All the time measurements only add up to a few minutes. Any idea where it's spending time?Ken Krugler
05/10/2021, 10:32 PMXiang Fu
Aaron Wishnick
05/11/2021, 1:12 PM-Xms4G
Ken Krugler
05/11/2021, 4:32 PMbin/pinot-admin.sh
, I changed one line to:
ALL_JAVA_OPTS="-Xms15G -Xmx15G -Dlog4j2.configurationFile=conf/pinot-admin-log4j2.xml"
Aaron Wishnick
05/11/2021, 4:45 PM2021-05-11T20:38:54.205+0000: [Full GC (Ergonomics) [PSYoungGen: 3348480K->2829207K(4470272K)] [ParOldGen: 11184779K->11184779K(11185152K)] 14533259K->14013987K(15655424K), [Metaspace: 55133K->55133K(1099776K)], <tel:546.0819375|546.0819375> secs] [Times: user=31738.44 sys=70.66, real=546.08 secs]
2021-05-11T20:48:00.653+0000: [Full GC (Ergonomics) [PSYoungGen: 3348480K->2829208K(4470272K)] [ParOldGen: 11184779K->11184779K(11185152K)] 14533259K->14013987K(15655424K), [Metaspace: 55133K->55133K(1099776K)], <tel:522.6226807|522.6226807> secs] [Times: user=28270.29 sys=112.95, real=522.62 secs]
2021-05-11T20:56:43.693+0000: [Full GC (Ergonomics) [PSYoungGen: 3348480K->2829208K(4470272K)] [ParOldGen: 11184779K->11184779K(11185152K)] 14533259K->14013987K(15655424K), [Metaspace: 55133K->55133K(1099776K)], <tel:563.4447500|563.4447500> secs] [Times: user=35688.72 sys=23.60, real=563.44 secs]
Ken Krugler
05/11/2021, 9:43 PMAaron Wishnick
05/12/2021, 4:08 PMKen Krugler
05/12/2021, 4:10 PMsegmentCreationJobParallelism
Aaron Wishnick
05/12/2021, 4:11 PMKen Krugler
05/12/2021, 4:12 PMAaron Wishnick
05/12/2021, 4:14 PMKen Krugler
05/12/2021, 4:14 PMAaron Wishnick
05/12/2021, 4:14 PMKen Krugler
05/12/2021, 4:15 PMAaron Wishnick
05/12/2021, 4:15 PMKen Krugler
05/12/2021, 4:19 PMAaron Wishnick
05/12/2021, 4:25 PM2021-05-12T16:25:48.464+0000: [Full GC (Ergonomics) [PSYoungGen: 499972K->0K(4527104K)] [ParOldGen: 10669128K->11093033K(11185152K)] 11169101K->11093033K(15712256K), [Metaspace: 55592K->55592K(1099776K)], 36.2899382 secs] [Times: user=962.56 sys=0.69, real=36.29 secs]
2021-05-12T16:26:28.268+0000: [Full GC (Ergonomics) [PSYoungGen: 3428864K->228298K(4527104K)] [ParOldGen: 11093033K->11170454K(11185152K)] 14521897K->11398752K(15712256K), [Metaspace: 55592K->55592K(1099776K)], 51.5969673 secs] [Times: user=1290.02 sys=9.49, real=51.60 secs]
2021-05-12T16:27:27.406+0000: [Full GC (Ergonomics) [PSYoungGen: 3428864K->496053K(4527104K)] [ParOldGen: 11170454K->11170454K(11185152K)] 14599318K->11666507K(15712256K), [Metaspace: 55592K->55592K(1099776K)], 43.8830724 secs] [Times: user=936.58 sys=13.11, real=43.88 secs]
Ken Krugler
05/12/2021, 7:54 PMAaron Wishnick
05/12/2021, 7:57 PMKen Krugler
05/12/2021, 7:57 PMXiang Fu
Generated 25884 star-tree records from 9408484 segment records
Finished constructing star-tree, got 1228 tree nodes and 2058 records under star-node
Finished creating aggregated documents, got 1227 aggregated records
Finished building star-tree in 276631ms
Starting building star-tree with config: StarTreeV2BuilderConfig[...]
Generated 9408484 star-tree records from 9408484 segment records
Ken Krugler
05/12/2021, 9:23 PMGenerated 9408484 star-tree records from 9408484 segment records
seems odd - maybe trying to use a column in the star-tree definition which is unique per row? If so, that won’t help your queries.Aaron Wishnick
05/13/2021, 2:17 PMenableDefaultStarTree
set to true, so it was generating a second star tree across all dimensions, and yes, one of those dimensions could have been uniqueGenerated 25884 star-tree records from 9408484 segment records