Empecé a perfilar parte de mi código Go1.2 y el elemento superior siempre es algo llamado 'etext'. He buscado pero no pude encontrar mucha información al respecto aparte de la que podría estar relacionada con la profundidad de llamadas en las rutinas de Go. Sin embargo, no estoy usando ninguna rutina de Go y 'etext' todavía ocupa el 75% o más del tiempo total de ejecución.
(pprof) top20 Total: 171 samples 128 74.9% 74.9% 128 74.9% etext¿Alguien puede explicar qué es esto y si hay alguna forma de reducir el impacto?
Me encontré con el mismo problema y luego encontré esto: pprof roto en go 1.2? . Para verificar que realmente es un error 1.2, escribí el siguiente programa "hola mundo":
package main import ( "fmt" "testing" ) func BenchmarkPrintln( t *testing.B ){ TestPrintln( nil ) } func TestPrintln( t *testing.T ){ for i := 0; i < 10000; i++ { fmt.Println("hello " + " world!") } }Como puede ver, solo llama a fmt.Println.
Puede compilar esto con "ir a prueba -c". Ejecute con “./test.test -test.bench. -test.cpuprofile=test.prof” Vea el resultado con “go tool pprof test.test test.prof”
(pprof) top10 Total: 36 samples 18 50.0% 50.0% 18 50.0% syscall.Syscall 8 22.2% 72.2% 8 22.2% etext 4 11.1% 83.3% 4 11.1% runtime.usleep 3 8.3% 91.7% 3 8.3% runtime.futex 1 2.8% 94.4% 1 2.8% MHeap_AllocLocked 1 2.8% 97.2% 1 2.8% fmt.(*fmt).padString 1 2.8% 100.0% 1 2.8% os.epipecheck 0 0.0% 100.0% 1 2.8% MCentral_Grow 0 0.0% 100.0% 33 91.7% System 0 0.0% 100.0% 3 8.3% _/home/xxiao/work/test.BenchmarkPrintlnEl resultado anterior se obtuvo usando go 1.2.1 Luego hice lo mismo usando go 1.1.1 y obtuve el siguiente resultado:
(pprof) top10 Total: 10 samples 2 20.0% 20.0% 2 20.0% scanblock 1 10.0% 30.0% 1 10.0% fmt.(*pp).free 1 10.0% 40.0% 1 10.0% fmt.(*pp).printField 1 10.0% 50.0% 2 20.0% fmt.newPrinter 1 10.0% 60.0% 2 20.0% os.(*File).Write 1 10.0% 70.0% 1 10.0% runtime.MCache_Alloc 1 10.0% 80.0% 1 10.0% runtime.exitsyscall 1 10.0% 90.0% 1 10.0% sweepspan 1 10.0% 100.0% 1 10.0% sync.(*Mutex).Lock 0 0.0% 100.0% 6 60.0% _/home/xxiao/work/test.BenchmarkPrintlnPuede ver que el resultado 1.2.1 no tiene mucho sentido. Syscall y etext ocupan la mayor parte del tiempo. Y el resultado 1.1.1 parece correcto.
Así que estoy convencido de que es realmente un error 1.2.1. Y cambié a usar go 1.1.1 en mi proyecto real y ahora estoy satisfecho con el resultado de la creación de perfiles.
Creo que Mathias Urlichs tiene razón con respecto a la falta de símbolos de depuración en su código cgo. Vale la pena señalar que algunos paquetes estándar como net y syscall utilizan cgo.
Si se desplaza hacia abajo hasta la parte inferior de este documento a la sección llamada Advertencias, puede ver que la tercera viñeta dice...
Si el programa se vinculó en una biblioteca que no se compiló con suficiente información simbólica, todas las muestras asociadas con la biblioteca se pueden cargar al último símbolo encontrado en el programa antes de la biblioteca. Esto inflará artificialmente el recuento de ese símbolo.
No estoy 100% seguro de que esto sea lo que está sucediendo, pero apuesto a que es por eso que etext parece estar tan ocupado (en otras palabras, etext es una colección de varias funciones que no tiene suficiente información para que pprof lo analice correctamente). ).