featurebase icon indicating copy to clipboard operation
featurebase copied to clipboard

viewByTimeUnit inefficient

Open tgruben opened this issue 5 years ago • 1 comments

Based on the following profile taken during a time frame import a large portion of time is being spent in the function viewByTimeUnit

(pprof) top40 Showing nodes accounting for 27.84s, 78.67% of 35.39s total Dropped 271 nodes (cum <= 0.18s) Showing top 40 nodes out of 120 flat flat% sum% cum cum% 2.82s 7.97% 7.97% 8.26s 23.34% runtime.mallocgc 2.27s 6.41% 14.38% 2.27s 6.41% runtime.aeshashbody 2.19s 6.19% 20.57% 2.19s 6.19% runtime.memmove 1.51s 4.27% 24.84% 1.59s 4.49% runtime.heapBitsSetType 1.31s 3.70% 28.54% 3.95s 11.16% time.Time.AppendFormat 1.26s 3.56% 32.10% 1.31s 3.70% syscall.Syscall 1.03s 2.91% 35.01% 1.03s 2.91% runtime.memclrNoHeapPointers 1.03s 2.91% 37.92% 1.03s 2.91% runtime.nextFreeFast (inline) 0.90s 2.54% 40.46% 1.21s 3.42% time.appendInt 0.84s 2.37% 42.84% 33.59s 94.91% github.com/pilosa/pilosa.(*Field).Import 0.78s 2.20% 45.04% 0.87s 2.46% time.absDate 0.76s 2.15% 47.19% 3.08s 8.70% runtime.memhash 0.74s 2.09% 49.28% 3.53s 9.97% runtime.mapassign 0.70s 1.98% 51.26% 3.27s 9.24% fmt.(*pp).doPrintf 0.66s 1.86% 53.12% 3.10s 8.76% runtime.mapaccess1 0.64s 1.81% 54.93% 2.28s 6.44% fmt.(*pp).printArg 0.63s 1.78% 56.71% 0.72s 2.03% github.com/pilosa/pilosa/internal.(*ImportRequest).Unmarshal 0.55s 1.55% 58.27% 0.55s 1.55% hash/fnv.(*sum32a).Write 0.50s 1.41% 59.68% 3.98s 11.25% type..hash.github.com/pilosa/pilosa.importKey 0.43s 1.22% 60.89% 15.35s 43.37% github.com/pilosa/pilosa.viewByTimeUnit 0.42s 1.19% 62.08% 0.42s 1.19% runtime.acquirem (inline) 0.40s 1.13% 63.21% 1.81s 5.11% runtime.strhash 0.39s 1.10% 64.31% 0.97s 2.74% fmt.(*buffer).WriteString (inline) 0.39s 1.10% 65.41% 0.81s 2.29% sync.(*Pool).Put 0.39s 1.10% 66.52% 0.79s 2.23% type..eq.github.com/pilosa/pilosa.importKey 0.37s 1.05% 67.56% 3.10s 8.76% runtime.convT2Estring 0.36s 1.02% 68.58% 5.40s 15.26% time.Time.Format 0.34s 0.96% 69.54% 0.71s 2.01% sync.(*Pool).pin 0.33s 0.93% 70.47% 1.64s 4.63% fmt.(*pp).fmtString 0.33s 0.93% 71.40% 0.33s 0.93% github.com/pilosa/pilosa/roaring.search64 0.32s 0.9% 72.31% 16.68s 47.13% github.com/pilosa/pilosa.viewsByTime 0.32s 0.9% 73.21% 0.32s 0.9% time.nextStdChunk 0.28s 0.79% 74.00% 0.28s 0.79% runtime.memeqbody 0.26s 0.73% 74.74% 6.43s 18.17% fmt.Sprintf 0.24s 0.68% 75.42% 0.24s 0.68% github.com/pilosa/pilosa/roaring.search32 0.24s 0.68% 76.09% 2.29s 6.47% runtime.growslice 0.23s 0.65% 76.74% 1.04s 2.94% fmt.(*pp).free 0.23s 0.65% 77.39% 0.23s 0.65% github.com/pilosa/pilosa/roaring.(*sliceIterator).Next 0.23s 0.65% 78.04% 2.16s 6.10% runtime.slicebytetostring 0.22s 0.62% 78.67% 0.22s 0.62% github.com/pilosa/pilosa/roaring.(*Container).arrayCountRuns

I belive alternative methods/caching could improve this performance

tgruben avatar Mar 01 '19 16:03 tgruben

using import-roaring works around this, so it's a bit lower priority.

jaffee avatar Apr 09 '19 16:04 jaffee