Прилетела ко мне задача померять минимальное, максимальное и среднее время исполнения запросов. Делал, делал и не мог понять, почему на 48 ядерной машине, запросы исполняются за 100мс при нагрузке в 50к/сек.

В итоге я выяснил причину и не могу понять. Толи лыжи не едут, толи реально баг в Go cо снятием времени.

Короче к телу

func TestSingle(t *testing.T) {
	count := 100000

	at := time.Now()
  
	for n := 0; n < count; n++ {
		for i := 0; i < 1000; i++ {
		}
	}

	durAll := time.Since(at)
	durOne := durAll / time.Duration(count)

	log.Println("Single: all ", durAll, " one ", durOne.String())
}

func TestParallel(t *testing.T) {
	count := 100000

	wg := sync.WaitGroup{}
	wg.Add(count)

	dura := atomic.Int64{}

	for n := 0; n < count; n++ {
		go func() {
			wg.Done()
          
			at := time.Now()
          
			for i := 0; i < 1000; i++ {
			}

			dura.Add(int64(time.Since(at)))
		}()
	}

	wg.Wait()

	durAll := time.Duration(dura.Load())
	durOne := durAll / time.Duration(count)

	log.Println("Parallel: all ", durAll, " one ", durOne.String())
}

Итог:

=== RUN   TestSingle
2024/10/30 23:13:12 Single: all  15.8768ms  one  158ns
--- PASS: TestSingle (0.02s)
=== RUN   TestParallel
2024/10/30 23:13:12 Parallel: all  48.1575ms  one  481ns
--- PASS: TestParallel (0.02s)
PASS

Это версия 2. Первая была не корректна и уважаемый @runetfreedom в личку сообщил инфу о погрешности часов. Я это учел (хоть и забыл) и решил переделать тесты. Да и тесты в первой были не корректные.
К нашим баранам. В переписке было сказано, что часы имеют погрешность и не всегда из-за БЫСТРОГО исполнения можно точно узнать время ТОЧНО. Ок. Подумал я и решил увеличить счетчик i с 1000 до 1000 0000 что бы эту погрешность уменьшить.

Итог

=== RUN   TestSingle
2024/10/30 23:14:49 Single: all  12.4822524s  one  124.822µs
--- PASS: TestSingle (12.48s)
=== RUN   TestParallel
2024/10/30 23:14:52 Parallel: all  1m5.7762707s  one  657.762µs
--- PASS: TestParallel (2.77s)
PASS

Кто знает тонкости Go, расскажите в чем подвох со снятием времени в рутинах? Сталкивались ли вы с таким багом?

go version go1.23.1 windows/amd64
goos: windows
goarch: amd64
pkg: ad-dmp/app/rest/route/audience
cpu: 12th Gen Intel(R) Core(TM) i7-1255U