/* * * Copyright 2019 gRPC authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. * */ package profiling import ( "fmt" "strconv" "sync" "testing" "time" "google.golang.org/grpc/internal/grpctest" "google.golang.org/grpc/internal/profiling/buffer" ) type s struct { grpctest.Tester } func Test(t *testing.T) { grpctest.RunSubTests(t, s{}) } func (s) TestProfiling(t *testing.T) { cb, err := buffer.NewCircularBuffer(128) if err != nil { t.Fatalf("error creating circular buffer: %v", err) } stat := NewStat("foo") cb.Push(stat) bar := func(n int) { if n%2 == 0 { defer stat.NewTimer(strconv.Itoa(n)).Egress() } else { timer := NewTimer(strconv.Itoa(n)) stat.AppendTimer(timer) defer timer.Egress() } time.Sleep(1 * time.Microsecond) } numTimers := int(8 * defaultStatAllocatedTimers) for i := 0; i < numTimers; i++ { bar(i) } results := cb.Drain() if len(results) != 1 { t.Fatalf("len(results) = %d; want 1", len(results)) } statReturned := results[0].(*Stat) if stat.Tags != "foo" { t.Fatalf("stat.Tags = %s; want foo", stat.Tags) } if len(stat.Timers) != numTimers { t.Fatalf("len(stat.Timers) = %d; want %d", len(stat.Timers), numTimers) } lastIdx := 0 for i, timer := range statReturned.Timers { // Check that they're in the order of append. if n, err := strconv.Atoi(timer.Tags); err != nil && n != lastIdx { t.Fatalf("stat.Timers[%d].Tags = %s; wanted %d", i, timer.Tags, lastIdx) } // Check that the timestamps are consistent. if diff := timer.End.Sub(timer.Begin); diff.Nanoseconds() < 1000 { t.Fatalf("stat.Timers[%d].End - stat.Timers[%d].Begin = %v; want >= 1000ns", i, i, diff) } lastIdx++ } } func (s) TestProfilingRace(t *testing.T) { stat := NewStat("foo") var wg sync.WaitGroup numTimers := int(8 * defaultStatAllocatedTimers) // also tests the slice growth code path wg.Add(numTimers) for i := 0; i < numTimers; i++ { go func(n int) { defer wg.Done() if n%2 == 0 { defer stat.NewTimer(strconv.Itoa(n)).Egress() } else { timer := NewTimer(strconv.Itoa(n)) stat.AppendTimer(timer) defer timer.Egress() } }(i) } wg.Wait() if len(stat.Timers) != numTimers { t.Fatalf("len(stat.Timers) = %d; want %d", len(stat.Timers), numTimers) } // The timers need not be ordered, so we can't expect them to be consecutive // like above. seen := make(map[int]bool) for i, timer := range stat.Timers { n, err := strconv.Atoi(timer.Tags) if err != nil { t.Fatalf("stat.Timers[%d].Tags = %s; wanted integer", i, timer.Tags) } seen[n] = true } for i := 0; i < numTimers; i++ { if _, ok := seen[i]; !ok { t.Fatalf("seen[%d] = false or does not exist; want it to be true", i) } } } func BenchmarkProfiling(b *testing.B) { for routines := 1; routines <= 1<<8; routines <<= 1 { b.Run(fmt.Sprintf("goroutines:%d", routines), func(b *testing.B) { perRoutine := b.N / routines stat := NewStat("foo") var wg sync.WaitGroup wg.Add(routines) for r := 0; r < routines; r++ { go func() { for i := 0; i < perRoutine; i++ { stat.NewTimer("bar").Egress() } wg.Done() }() } wg.Wait() }) } }