aboutsummaryrefslogtreecommitdiff
path: root/src/runtime/trace
AgeCommit message (Collapse)Author
2023-02-08runtime: correct typosOleksandr Redko
- Fix typo in throw error message for arena. - Correct typos in assembly and Go comments. - Fix log message in TestTraceCPUProfile. Change-Id: I874c9e8cd46394448b6717bc6021aa3ecf319d16 GitHub-Last-Rev: d27fad4d3cea81cc7a4ca6917985bcf5fa49b0e0 GitHub-Pull-Request: golang/go#58375 Reviewed-on: https://go-review.googlesource.com/c/go/+/465975 Reviewed-by: David Chase <drchase@google.com> Reviewed-by: Ian Lance Taylor <iant@google.com> Run-TryBot: Ian Lance Taylor <iant@google.com> Auto-Submit: Ian Lance Taylor <iant@google.com> TryBot-Result: Gopher Robot <gobot@golang.org>
2022-09-14all: remove unnecessary allocations from w.WriteString(fmt.Sprint*(...)) by ↵Emmanuel T Odeke
fmt.Fprint*(w, ...) Noticed in a manual audit from a customer codebase that the pattern w.WriteString(fmt.Sprint*(args...)) was less efficient and in most cases we can just invoke: fmt.Fprint*(w, args...) and from the simple benchmarks we can see quick wins in all dimensions: $ benchstat before.txt after.txt name old time/op new time/op delta DetailString-8 5.48µs ±23% 4.40µs ±11% -19.79% (p=0.000 n=20+17) name old alloc/op new alloc/op delta DetailString-8 2.63kB ± 0% 2.11kB ± 0% -19.76% (p=0.000 n=20+20) name old allocs/op new allocs/op delta DetailString-8 63.0 ± 0% 50.0 ± 0% -20.63% (p=0.000 n=20+20) Change-Id: I47a2827cd34d6b92644900b1bd5f4c0a3287bdb1 Reviewed-on: https://go-review.googlesource.com/c/go/+/429861 Reviewed-by: Robert Findley <rfindley@google.com> Reviewed-by: hopehook <hopehook@golangcn.org> Reviewed-by: Ian Lance Taylor <iant@google.com> Run-TryBot: Emmanuel Odeke <emmanuel@orijtech.com> TryBot-Result: Gopher Robot <gobot@golang.org> Reviewed-by: Daniel Martí <mvdan@mvdan.cc>
2022-08-17runtime/trace: convert tracing.enabled to atomic typeCuong Manh Le
Updates #53821 Change-Id: I8a063ae94568cd2ea65c2e891618069a96139891 Reviewed-on: https://go-review.googlesource.com/c/go/+/423884 Run-TryBot: Cuong Manh Le <cuong.manhle.vn@gmail.com> TryBot-Result: Gopher Robot <gobot@golang.org> Reviewed-by: Michael Pratt <mpratt@google.com> Reviewed-by: Keith Randall <khr@google.com> Auto-Submit: Cuong Manh Le <cuong.manhle.vn@gmail.com>
2022-06-21runtime/trace: ignore fallback stacks in testRhys Hiltner
When runtime.sigprof encounters a stack that gentraceback is unable to process, it synthesizes a call stack with a sentinel function (such as runtime._System) at the leaf. The test to confirm that runtime/trace and runtime/pprof have similar views of CPU profile samples has trouble with those stacks. The test confirms that the samples match by confirming that their symbolized forms match, and the symbolization procedure is very different for the two packages. Skip the samples that the CPU profiler's view symbolizes to include one of runtime.sigprof's sentinel functions at the leaf. (The test design expects the CPU profiler to under-report samples relative to the execution tracer.) Fixes #53378 Change-Id: I60c27de4c69b454057d28a3b6e12d70369de4c4f Reviewed-on: https://go-review.googlesource.com/c/go/+/413457 Reviewed-by: Bryan Mills <bcmills@google.com> Run-TryBot: Rhys Hiltner <rhys@justin.tv> TryBot-Result: Gopher Robot <gobot@golang.org> Reviewed-by: Michael Pratt <mpratt@google.com>
2022-05-05runtime: prefer curg for execution trace profileRhys Hiltner
The CPU profiler adds goroutine labels to its samples based on getg().m.curg. That allows the profile to correctly attribute work that the runtime does on behalf of that goroutine on the M's g0 stack via systemstack calls, such as using runtime.Callers to record the call stack. Those labels also cover work on the g0 stack via mcall. When the active goroutine calls runtime.Gosched, it will receive attribution of its share of the scheduler work necessary to find the next runnable goroutine. The execution tracer's attribution of CPU samples to specific goroutines should match. When curg is set, attribute the CPU samples to that goroutine's ID. Fixes #52693 Change-Id: Ic9af92e153abd8477559e48bc8ebaf3739527b94 Reviewed-on: https://go-review.googlesource.com/c/go/+/404055 Reviewed-by: Michael Knyszek <mknyszek@google.com> Reviewed-by: Bryan Mills <bcmills@google.com> Run-TryBot: Rhys Hiltner <rhys@justin.tv> TryBot-Result: Gopher Robot <gobot@golang.org>
2022-05-03runtime: add CPU samples to execution traceRhys Hiltner
When the CPU profiler and execution tracer are both active, report the CPU profile samples in the execution trace data stream. Include only samples that arrive on the threads known to the runtime, but include them even when running g0 (such as near the scheduler) or if there's no P (such as near syscalls). Render them in "go tool trace" as instantaneous events. For #16895 Change-Id: I0aa501a7b450c971e510961c0290838729033f7f Reviewed-on: https://go-review.googlesource.com/c/go/+/400795 Reviewed-by: Michael Knyszek <mknyszek@google.com> Run-TryBot: Rhys Hiltner <rhys@justin.tv> Reviewed-by: David Chase <drchase@google.com> TryBot-Result: Gopher Robot <gobot@golang.org>
2022-04-11all: gofmt main repoRuss Cox
[This CL is part of a sequence implementing the proposal #51082. The design doc is at https://go.dev/s/godocfmt-design.] Run the updated gofmt, which reformats doc comments, on the main repository. Vendored files are excluded. For #51082. Change-Id: I7332f099b60f716295fb34719c98c04eb1a85407 Reviewed-on: https://go-review.googlesource.com/c/go/+/384268 Reviewed-by: Jonathan Amsterdam <jba@google.com> Reviewed-by: Ian Lance Taylor <iant@golang.org>
2022-04-01all: remove trailing blank doc comment linesRuss Cox
A future change to gofmt will rewrite // Doc comment. // func f() to // Doc comment. func f() Apply that change preemptively to all doc comments. For #51082. Change-Id: I4023e16cfb0729b64a8590f071cd92f17343081d Reviewed-on: https://go-review.googlesource.com/c/go/+/384259 Trust: Russ Cox <rsc@golang.org> Run-TryBot: Russ Cox <rsc@golang.org> Reviewed-by: Ian Lance Taylor <iant@golang.org> TryBot-Result: Gopher Robot <gobot@golang.org>
2021-12-13all: gofmt -w -r 'interface{} -> any' srcRuss Cox
And then revert the bootstrap cmd directories and certain testdata. And adjust tests as needed. Not reverting the changes in std that are bootstrapped, because some of those changes would appear in API docs, and we want to use any consistently. Instead, rewrite 'any' to 'interface{}' in cmd/dist for those directories when preparing the bootstrap copy. A few files changed as a result of running gofmt -w not because of interface{} -> any but because they hadn't been updated for the new //go:build lines. Fixes #49884. Change-Id: Ie8045cba995f65bd79c694ec77a1b3d1fe01bb09 Reviewed-on: https://go-review.googlesource.com/c/go/+/368254 Trust: Russ Cox <rsc@golang.org> Run-TryBot: Russ Cox <rsc@golang.org> Reviewed-by: Robert Griesemer <gri@golang.org> TryBot-Result: Gopher Robot <gobot@golang.org>
2020-12-09all: update to use os.ReadFile, os.WriteFile, os.CreateTemp, os.MkdirTempRuss Cox
As part of #42026, these helpers from io/ioutil were moved to os. (ioutil.TempFile and TempDir became os.CreateTemp and MkdirTemp.) Update the Go tree to use the preferred names. As usual, code compiled with the Go 1.4 bootstrap toolchain and code vendored from other sources is excluded. ReadDir changes are in a separate CL, because they are not a simple search and replace. For #42026. Change-Id: If318df0216d57e95ea0c4093b89f65e5b0ababb3 Reviewed-on: https://go-review.googlesource.com/c/go/+/266365 Trust: Russ Cox <rsc@golang.org> Run-TryBot: Russ Cox <rsc@golang.org> TryBot-Result: Go Bot <gobot@golang.org> Reviewed-by: Ian Lance Taylor <iant@golang.org>
2020-09-02runtime: add file copyright header declarationHeisenberg
Some files have no copyright notice. The copyright time is the earliest modification record of the file. Change-Id: I5698bae16b6b73543e074415877a03348f792951 Reviewed-on: https://go-review.googlesource.com/c/go/+/246378 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Emmanuel Odeke <emm.odeke@gmail.com>
2020-08-19os, internal/poll: loop on EINTR for all file syscallsIan Lance Taylor
When using a FUSE file system, any system call that touches the file system can return EINTR. Fixes #40846 Change-Id: I25d32da22cec08dea81ab297291a85ad72db2df7 Reviewed-on: https://go-review.googlesource.com/c/go/+/249178 Run-TryBot: Ian Lance Taylor <iant@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Bryan C. Mills <bcmills@google.com>
2020-06-19runtime/trace: fix file name in exampleRodolfo Carvalho
The preceding paragraph suggests the test run will produce a file called trace.out. The same name, trace.out, is used in the output from go help testflag, thus we change the go test line instead of changing the preceding paragraph. Change-Id: Ib1fa7e49e540853e263a2399b16040ea6f41b703 GitHub-Last-Rev: 3535e62bf8dd02dd9955a28e7fa9cca98de89efd GitHub-Pull-Request: golang/go#39709 Reviewed-on: https://go-review.googlesource.com/c/go/+/238997 Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
2020-05-11internal/poll, os: loop on EINTRIan Lance Taylor
Historically we've assumed that we can install all signal handlers with the SA_RESTART flag set, and let the system restart slow functions if a signal is received. Therefore, we don't have to worry about EINTR. This is only partially true, and we've added EINTR checks already for connect, and open/read on Darwin, and sendfile on Solaris. Other cases have turned up in #36644, #38033, and #38836. Also, #20400 points out that when Go code is included in a C program, the C program may install its own signal handlers without SA_RESTART. In that case, Go code will see EINTR no matter what it does. So, go ahead and check for EINTR. We don't check in the syscall package; people using syscalls directly may want to check for EINTR themselves. But we do check for EINTR in the higher level APIs in os and net, and retry the system call if we see it. This change looks safe, but of course we may be missing some cases where we need to check for EINTR. As such cases turn up, we can add tests to runtime/testdata/testprogcgo/eintr.go, and fix the code. If there are any such cases, their handling after this change will be no worse than it is today. For #22838 Fixes #20400 Fixes #36644 Fixes #38033 Fixes #38836 Change-Id: I7e46ca8cafed0429c7a2386cc9edc9d9d47a6896 Reviewed-on: https://go-review.googlesource.com/c/go/+/232862 Run-TryBot: Ian Lance Taylor <iant@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Bryan C. Mills <bcmills@google.com>
2020-03-18runtime: don't hold worldsema across mark phaseMichael Anthony Knyszek
This change makes it so that worldsema isn't held across the mark phase. This means that various operations like ReadMemStats may now stop the world during the mark phase, reducing latency on such operations. Only three such operations are still no longer allowed to occur during marking: GOMAXPROCS, StartTrace, and StopTrace. For the former it's because any change to GOMAXPROCS impacts GC mark background worker scheduling and the details there are tricky. For the latter two it's because tracing needs to observe consistent GC start and GC end events, and if StartTrace or StopTrace may stop the world during marking, then it's possible for it to see a GC end event without a start or GC start event without an end, respectively. To ensure that GOMAXPROCS and StartTrace/StopTrace cannot proceed until marking is complete, the runtime now holds a new semaphore, gcsema, across the mark phase just like it used to with worldsema. This change is being landed once more after being reverted in the Go 1.14 release cycle, since CL 215157 allows it to have a positive effect on system performance. For the benchmark BenchmarkReadMemStatsLatency in the runtime, which measures ReadMemStats latencies while the GC is exercised, the tail of these latencies reduced dramatically on an 8-core machine: name old 50%tile-ns new 50%tile-ns delta ReadMemStatsLatency-8 4.40M ±74% 0.12M ± 2% -97.35% (p=0.008 n=5+5) name old 90%tile-ns new 90%tile-ns delta ReadMemStatsLatency-8 102M ± 6% 0M ±14% -99.79% (p=0.008 n=5+5) name old 99%tile-ns new 99%tile-ns delta ReadMemStatsLatency-8 147M ±18% 4M ±57% -97.43% (p=0.008 n=5+5) Fixes #19812. Change-Id: If66c3c97d171524ae29f0e7af4bd33509d9fd0bb Reviewed-on: https://go-review.googlesource.com/c/go/+/216557 Run-TryBot: Michael Knyszek <mknyszek@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Cherry Zhang <cherryyz@google.com>
2020-01-24Revert "runtime: don't hold worldsema across mark phase"Michael Knyszek
This reverts commit 7b294cdd8df0a9523010f6ffc80c59e64578f34b, CL 182657. Reason for revert: This change may be causing latency problems for applications which call ReadMemStats, because it may cause all goroutines to stop until the GC completes. https://golang.org/cl/215157 fixes this problem, but it's too late in the cycle to land that. Updates #19812. Change-Id: Iaa26f4dec9b06b9db2a771a44e45f58d0aa8f26d Reviewed-on: https://go-review.googlesource.com/c/go/+/216358 Run-TryBot: Michael Knyszek <mknyszek@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Cherry Zhang <cherryyz@google.com>
2019-09-04runtime: don't hold worldsema across mark phaseMichael Anthony Knyszek
This change makes it so that worldsema isn't held across the mark phase. This means that various operations like ReadMemStats may now stop the world during the mark phase, reducing latency on such operations. Only three such operations are still no longer allowed to occur during marking: GOMAXPROCS, StartTrace, and StopTrace. For the former it's because any change to GOMAXPROCS impacts GC mark background worker scheduling and the details there are tricky. For the latter two it's because tracing needs to observe consistent GC start and GC end events, and if StartTrace or StopTrace may stop the world during marking, then it's possible for it to see a GC end event without a start or GC start event without an end, respectively. To ensure that GOMAXPROCS and StartTrace/StopTrace cannot proceed until marking is complete, the runtime now holds a new semaphore, gcsema, across the mark phase just like it used to with worldsema. Fixes #19812. Change-Id: I15d43ed184f711b3d104e8f267fb86e335f86bf9 Reviewed-on: https://go-review.googlesource.com/c/go/+/182657 Run-TryBot: Michael Knyszek <mknyszek@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Keith Randall <khr@golang.org> Reviewed-by: Cherry Zhang <cherryyz@google.com>
2019-05-22all: shorten some testsRuss Cox
Shorten some of the longest tests that run during all.bash. Removes 7r 50u 21s from all.bash. After this change, all.bash is under 5 minutes again on my laptop. For #26473. Change-Id: Ie0460aa935808d65460408feaed210fbaa1d5d79 Reviewed-on: https://go-review.googlesource.com/c/go/+/177559 Run-TryBot: Russ Cox <rsc@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Lance Taylor <iant@golang.org>
2019-04-18runtime/trace: also treat plan9 as a low memory systemBrad Fitzpatrick
Fixes #31554 Updates #12032 (also originally about plan9, but later openbsd/arm) Change-Id: Ib9f35d27a2304f38bf271c38c0b9153d210d8f95 Reviewed-on: https://go-review.googlesource.com/c/go/+/172837 Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org> Reviewed-by: David du Colombier <0intro@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2018-12-02all: use "reports whether" consistently instead of "returns whether"Tobias Klauser
Follow-up for CL 147037 and after Brad noticed the "returns whether" pattern during the review of CL 150621. Go documentation style for boolean funcs is to say: // Foo reports whether ... func Foo() bool (rather than "returns whether") Created with: $ perl -i -npe 's/returns whether/reports whether/' $(git grep -l "returns whether" | grep -v vendor) Change-Id: I15fe9ff99180ad97750cd05a10eceafdb12dc0b4 Reviewed-on: https://go-review.googlesource.com/c/150918 Run-TryBot: Tobias Klauser <tobias.klauser@gmail.com> Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
2018-09-03runtime/trace: fix syntax errors in NewTask doc exampleCharles Kenney
Fixes #27406 Change-Id: I9c6f5bac5b26558fa7628233c74a62faf676e811 GitHub-Last-Rev: 29d19f719316b486224a15a50556465811985edf GitHub-Pull-Request: golang/go#27437 Reviewed-on: https://go-review.googlesource.com/132775 Reviewed-by: Emmanuel Odeke <emm.odeke@gmail.com> Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2018-07-10runtime/trace: comment newlines to restore correct doc summaryAlberto Donizetti
Fixes #26309 Change-Id: I0e0b61b885817e514aa46e299b00833f16e98b2a Reviewed-on: https://go-review.googlesource.com/122898 Reviewed-by: Айнар Гарипов <gugl.zadolbal@gmail.com> Reviewed-by: Ian Lance Taylor <iant@golang.org>
2018-06-25runtime/trace: reword the trace package summaryJeremy Jackins
Reword the package summary to be a little easier to read. Change-Id: I84a9301a02e228b46165410a429548b3774762d5 GitHub-Last-Rev: 1342c7219f0ed06144d3bca9acd77790707e4b77 GitHub-Pull-Request: golang/go#26052 Reviewed-on: https://go-review.googlesource.com/120795 Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
2018-06-01runtime/trace: remove remaining NewContext referenceHana Kim
This is a documentation error. Change-Id: I083021f151f7e80a0b9083b98452ae1f5920640d Reviewed-on: https://go-review.googlesource.com/115598 Reviewed-by: Peter Weinberger <pjw@google.com>
2018-06-01os: add js/wasm architectureRichard Musiol
This commit adds the js/wasm architecture to the os package. Access to the actual file system is supported through Node.js. Updates #18892 Change-Id: I6fa642fb294ca020b2c545649d4324d981aa0408 Reviewed-on: https://go-review.googlesource.com/109977 Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org> Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org>
2018-05-09runtime/trace: delete functions replaced by cl/108296Hana Kim
Change-Id: I9bd4e13aafce14f76606b0f96496f621232c9e37 Reviewed-on: https://go-review.googlesource.com/112198 Reviewed-by: Peter Weinberger <pjw@google.com> Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2018-04-24runtime/trace: add simple benchmarks for user annotationHana Kim
Also, avoid Region creation when tracing is disabled. Unfortunate side-effect of this change is that we no longer trace pre-existing regions in tracing, but we can add the feature in the future when we find it useful and justifiable. Until then, let's avoid the overhead from this low-level api use as much as possible. goos: linux goarch: amd64 pkg: runtime/trace // Trace disabled BenchmarkStartRegion-12 2000000000 0.66 ns/op 0 B/op 0 allocs/op BenchmarkNewTask-12 30000000 40.4 ns/op 56 B/op 2 allocs/op // Trace enabled, -trace=/dev/null BenchmarkStartRegion-12 5000000 287 ns/op 32 B/op 1 allocs/op BenchmarkNewTask-12 5000000 283 ns/op 56 B/op 2 allocs/op Also, skip other tests if tracing is already enabled. Change-Id: Id3028d60b5642fcab4b09a74fd7d79361a3861e5 Reviewed-on: https://go-review.googlesource.com/109115 Reviewed-by: Peter Weinberger <pjw@google.com>
2018-04-24runtime/trace: rename "Span" with "Region"Hana Kim
"Span" is a commonly used term in many distributed tracing systems (Dapper, OpenCensus, OpenTracing, ...). They use it to refer to a period of time, not necessarily tied into execution of underlying processor, thread, or goroutine, unlike the "Span" of runtime/trace package. Since distributed tracing and go runtime execution tracing are already similar enough to cause confusion, this CL attempts to avoid using the same word if possible. "Region" is being used in a certain tracing system to refer to a code region which is pretty close to what runtime/trace.Span currently refers to. So, replace that. https://software.intel.com/en-us/itc-user-and-reference-guide-defining-and-recording-functions-or-regions This CL also tweaks APIs a bit based on jbd and heschi's comments: NewContext -> NewTask and it now returns a Task object that exports End method. StartSpan -> StartRegion and it now returns a Region object that exports End method. Also, changed WithSpan to WithRegion and it now takes func() with no context. Another thought is to get rid of WithRegion. It is a nice concept but in practice, it seems problematic (a lot of code churn, and polluting stack trace). Already, the tracing concept is very low level, and we hope this API to be used with great care. Recommended usage will be defer trace.StartRegion(ctx, "someRegion").End() Left old APIs untouched in this CL. Once the usage of them are cleaned up, they will be removed in a separate CL. Change-Id: I73880635e437f3aad51314331a035dd1459b9f3a Reviewed-on: https://go-review.googlesource.com/108296 Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: JBD <jbd@google.com>
2018-03-05internal/trace: remove backlinks from span/task end to startHana Kim
This is an updated version of golang.org/cl/96395, with the fix to TestUserSpan. This reverts commit 7b6f6267e90a8e4eab37a3f2164ba882e6222adb. Change-Id: I31eec8ba0997f9178dffef8dac608e731ab70872 Reviewed-on: https://go-review.googlesource.com/98236 Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Heschi Kreinick <heschi@google.com>
2018-03-01runtime/trace: skip TestUserTaskSpan upon timestamp errorHana Kim
Change-Id: I030baaa0a0abf1e43449faaf676d389a28a868a3 Reviewed-on: https://go-review.googlesource.com/97857 Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com> Reviewed-by: Peter Weinberger <pjw@google.com>
2018-02-18all: remove "the" duplicationsKunpei Sakai
Change-Id: I1f25b11fb9b7cd3c09968ed99913dc85db2025ef Reviewed-on: https://go-review.googlesource.com/94976 Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
2018-02-15internal/trace: link user span start and end eventsHana Kim
Also add testdata for version 1.11 including UserTaskSpan test trace. Change-Id: I673fb29bb3aee96a14fadc0ab860d4f5832143f5 Reviewed-on: https://go-review.googlesource.com/93795 Reviewed-by: Heschi Kreinick <heschi@google.com>
2018-02-15runtime/trace: implement annotation APIHana Kim
This implements the annotation API proposed in golang.org/cl/63274. traceString is updated to protect the string map with trace.stringsLock because the assumption that traceString is called by a single goroutine (either at the beginning of tracing and at the end of tracing when dumping all the symbols and function names) is no longer true. traceString is used by the annotation apis (NewContext, StartSpan, Log) to register frequently appearing strings (task and span names, and log keys) after this change. NewContext -> one or two records (EvString, EvUserTaskCreate) end function -> one record (EvUserTaskEnd) StartSpan -> one or two records (EvString, EvUserSpan) span end function -> one or two records (EvString, EvUserSpan) Log -> one or two records (EvString, EvUserLog) EvUserLog record is of the typical record format written by traceEvent except that it is followed by bytes that represents the value string. In addition to runtime/trace change, this change includes corresponding changes in internal/trace to parse the new record types. Future work to improve efficiency: More efficient unique task id generation instead of atomic. (per-P counter). Instead of a centralized trace.stringsLock, consider using per-P string cache or something more efficient. R=go1.11 Change-Id: Iec9276c6c51e5be441ccd52dec270f1e3b153970 Reviewed-on: https://go-review.googlesource.com/71690 Reviewed-by: Austin Clements <austin@google.com>
2018-02-15runtime/trace: user annotation APIHana Kim
This CL presents the proposed user annotation API skeleton. This CL bumps up the trace version to 1.11. Design doc https://goo.gl/iqJfJ3 Implementation CLs are followed. The API introduces three basic building blocks. Log, Span, and Task. Log is for basic logging. When called, the message will be recorded to the trace along with timestamp, goroutine id, and stack info. trace.Log(ctx, messageType message) Span can be thought as an extension of log to record interesting time interval during a goroutine's execution. A span is local to a goroutine by definition. trace.WithSpan(ctx, "doVeryExpensiveOp", func(ctx context) { /* do something very expensive */ }) Task is higher-level concept that aids tracing of complex operations that encompass multiple goroutines or are asynchronous. For example, an RPC request, a HTTP request, a file write, or a batch job can be traced with a Task. Note we chose to design the API around context.Context so it allows easier integration with other tracing tools, often designed around context.Context as well. Log and WithSpan APIs recognize the task information embedded in the context and record it in the trace as well. That allows the Go execution tracer to associate and group the spans and log messages based on the task information. In order to create a Task, ctx, end := trace.NewContext(ctx, "myTask") defer end() The Go execution tracer measures the time between the task created and the task ended for the task latency. More discussion history in golang.org/cl/59572. Update #16619 R=go1.11 Change-Id: I59a937048294dafd23a75cf1723c6db461b193cd Reviewed-on: https://go-review.googlesource.com/63274 Reviewed-by: Austin Clements <austin@google.com>
2018-02-13runtime/trace: fix TestTraceSymbolize when GOMAXPROCS=1David du Colombier
CL 92916 added the GOMAXPROCS test in TestTraceSymbolize. This test only succeeds when the value of GOMAXPROCS changes. Since the test calls runtime.GOMAXPROCS(1), it will fails on machines where GOMAXPROCS=1. This change fixes the test by calling runtime.GOMAXPROCS(oldGoMaxProcs+1). Fixes #23816. Change-Id: I1183dbbd7db6077cbd7fa0754032ff32793b2195 Reviewed-on: https://go-review.googlesource.com/93735 Run-TryBot: David du Colombier <0intro@gmail.com> Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2018-02-13runtime/trace: add stack tests for GOMAXPROCSHana Kim
and reorganize test log messages for stack dumps for easier debugging. The error log will be formatted like the following: trace_stack_test.go:282: Did not match event GoCreate with stack runtime/trace_test.TestTraceSymbolize :39 testing.tRunner :0 Seen 30 events of the type Offset 1890 runtime/trace_test.TestTraceSymbolize /go/src/runtime/trace/trace_stack_test.go:30 testing.tRunner /go/src/testing/testing.go:777 Offset 1899 runtime/trace_test.TestTraceSymbolize /go/src/runtime/trace/trace_stack_test.go:30 testing.tRunner /go/src/testing/testing.go:777 ... Change-Id: I0468de04507d6ae38ba84d99d13f7bf592e8d115 Reviewed-on: https://go-review.googlesource.com/92916 Reviewed-by: Heschi Kreinick <heschi@google.com> Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
2017-12-20cmd/trace: init goroutine info entries with GoCreate eventHana Kim
golang.org/cl/81315 attempted to distinguish system goroutines by examining the function name in the goroutine stack. It assumes that the information would be available when GoSysBlock or GoInSyscall events are processed, but it turned out the stack information is set too late (when the goroutine gets a chance to run). This change initializes the goroutine information entry when processing GoCreate event which should be one of the very first events for the every goroutine in trace. Fixes #22574 Change-Id: I1ed37087ce2e78ed27c9b419b7d942eb4140cc69 Reviewed-on: https://go-review.googlesource.com/83595 Reviewed-by: Austin Clements <austin@google.com> Run-TryBot: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2017-11-15runtime/trace: fix a typo in docHana Kim
Change-Id: I63f3d2edb09801c99957a1f744639523fb6d0b62 Reviewed-on: https://go-review.googlesource.com/60331 Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
2017-10-31runtime/trace: fix corrupted trace during StartTraceHana (Hyang-Ah) Kim
Since Go1.8, different types of GC mark workers were annotated and the annotation strings were recorded during StartTrace. This change fixes two issues around the use of traceString from StartTrace here. 1) "failed to parse trace: no consistent ordering of events possible" This issue is a result of a missing 'batch' event entry. For efficient tracing, tracer maintains system allocated buffers and once a buffer is full, it is Flushed out for writing. Moreover, tracing assumes all the records in the same buffer (batch) are already ordered and implements more optimization in encoding and defers the completing order reconstruction till the trace parsing time. Thus, when a Flush happens and a new buffer is used, the new buffer should contain an event to indicate the start of a new batch. Before this CL, the batch entry was written only by traceEvent only when the buffer position is 0 and wasn't written when flush occurs during traceString. This CL fixes it by moving the batch entry write to the traceFlush. 2) crash during tracing due to invalid memory access, or during parsing due to duplicate string entries This issue is a result of memory allocation during traceString calls. Execution tracer traces some memory allocation activities. Before this CL, traceString took the buffer address (*traceBuf) and mutated the buffer. If memory tracing occurs in the meantime from the same P, the allocation tracing (traceEvent) will take the same buffer address through the pointer to the buffer address (**traceBuf), and mutate the buffer. As a result, one of the followings can happen: - the allocation record is overwritten by the following trace string record (data loss) - if buffer flush occurs during the allocation tracing, traceString will attempt to write the string record to the old buffer and eventually causes invalid memory access crash. - or flush on the same buffer can occur twice (once from the memory allocation, and once from the string record write), and in this case the trace can contain the same data twice and the parse will complain about duplicate string record entries. This CL fixes the second issue by making the traceString take **traceBuf (*traceBufPtr). Change-Id: I24f629758625b38e1916fbfc7d7be6ea210586af Reviewed-on: https://go-review.googlesource.com/50873 Run-TryBot: Austin Clements <austin@google.com> Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Austin Clements <austin@google.com>
2017-08-29runtime/trace: improve package docHana Kim
Explaining how to enable tracing. Change-Id: Ic8391cb290742b4dc1efab15deba85853e182b4d Reviewed-on: https://go-review.googlesource.com/59612 Reviewed-by: Heschi Kreinick <heschi@google.com>
2017-08-29runtime/trace: add example about trace.Start/StopAndré Carvalho
This commit adds an example to the runtime/trace package on how to use the trace.Start and trace.Stop functions to trace the execution of a Go program and write its trace output to a file. Change-Id: Idf920398f1c3b9d185af9df5ce9293f2361db022 Reviewed-on: https://go-review.googlesource.com/51170 Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
2017-04-14runtime/trace: better output when test failsDavid Lazar
Change-Id: I108d15eb4cd25904bb76de4ed7548c039c69d1a3 Reviewed-on: https://go-review.googlesource.com/40590 Run-TryBot: David Lazar <lazard@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Austin Clements <austin@google.com>
2017-02-15os: use poller for file I/OIan Lance Taylor
This changes the os package to use the runtime poller for file I/O where possible. When a system call blocks on a pollable descriptor, the goroutine will be blocked on the poller but the thread will be released to run other goroutines. When using a non-pollable descriptor, the os package will continue to use thread-blocking system calls as before. For example, on GNU/Linux, the runtime poller uses epoll. epoll does not support ordinary disk files, so they will continue to use blocking I/O as before. The poller will be used for pipes. Since this means that the poller is used for many more programs, this modifies the runtime to only block waiting for the poller if there is some goroutine that is waiting on the poller. Otherwise, there is no point, as the poller will never make any goroutine ready. This preserves the runtime's current simple deadlock detection. This seems to crash FreeBSD systems, so it is disabled on FreeBSD. This is issue 19093. Using the poller on Windows requires opening the file with FILE_FLAG_OVERLAPPED. We should only do that if we can remove that flag if the program calls the Fd method. This is issue 19098. Update #6817. Update #7903. Update #15021. Update #18507. Update #19093. Update #19098. Change-Id: Ia5197dcefa7c6fbcca97d19a6f8621b2abcbb1fe Reviewed-on: https://go-review.googlesource.com/36800 Run-TryBot: Ian Lance Taylor <iant@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Russ Cox <rsc@golang.org>
2017-02-13net: refactor poller into new internal/poll packageIan Lance Taylor
This will make it possible to use the poller with the os package. This is a lot of code movement but the behavior is intended to be unchanged. Update #6817. Update #7903. Update #15021. Update #18507. Change-Id: I1413685928017c32df5654ded73a2643820977ae Reviewed-on: https://go-review.googlesource.com/36799 Run-TryBot: Ian Lance Taylor <iant@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: David Crawshaw <crawshaw@golang.org> Reviewed-by: Russ Cox <rsc@golang.org>
2017-02-10cmd/compile/internal/syntax: removed gcCompat code needed to pass orig. testsRobert Griesemer
The gcCompat mode was introduced to match the new parser's node position setup exactly with the positions used by the original parser. Some of the gcCompat adjustments were required to satisfy syntax error test cases, and the rest were required to make toolstash cmp pass. This change removes the former gcCompat adjustments and instead adjusts the respective test cases as necessary. In some cases this makes the error lines consistent with the ones reported by gccgo. Where it has changed, the position associated with a given syntactic construct is the position (line/col number) of the left-most token belonging to the construct. Change-Id: I5b60c00c5999a895c4d6d6e9b383c6405ccf725c Reviewed-on: https://go-review.googlesource.com/36695 Run-TryBot: Robert Griesemer <gri@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Matthew Dempsky <mdempsky@google.com>
2016-11-15all: don't call t.Fatal from a goroutineIan Lance Taylor
Fixes #17900. Change-Id: I42cda6ac9cf48ed739d3a015a90b3cb15edf8ddf Reviewed-on: https://go-review.googlesource.com/33243 Run-TryBot: Ian Lance Taylor <iant@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
2016-10-28runtime/trace: deflake TestTraceSymbolizeRuss Cox
Waiting 2ms for all the kicked-off goroutines to run and block seems a little optimistic. No harm done by waiting for 200ms instead. Fixes #17238. Change-Id: I827532ea2f5f1f3ed04179f8957dd2c563946ed0 Reviewed-on: https://go-review.googlesource.com/32103 Run-TryBot: Russ Cox <rsc@golang.org> Reviewed-by: Ian Lance Taylor <iant@golang.org>
2016-10-28runtime/trace, internal/trace: script to collect canned tracesAustin Clements
This adds support to the runtime/trace test for saving traces collected by its tests to disk and a script in internal/trace that uses this to collect canned traces for the trace test suite. This can be used to add to the test suite when we introduce a new trace format version. Change-Id: Id9ac1ff312235bf02f982fdfff8a827f54035758 Reviewed-on: https://go-review.googlesource.com/32290 Run-TryBot: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Dmitry Vyukov <dvyukov@google.com>
2016-04-24runtime/trace: test detection of broken timestampsDmitry Vyukov
On some processors cputicks (used to generate trace timestamps) produce non-monotonic timestamps. It is important that the parser distinguishes logically inconsistent traces (e.g. missing, excessive or misordered events) from broken timestamps. The former is a bug in tracer, the latter is a machine issue. Test that (1) parser does not return a logical error in case of broken timestamps and (2) broken timestamps are eventually detected and reported. Change-Id: Ib4b1eb43ce128b268e754400ed8b5e8def04bd78 Reviewed-on: https://go-review.googlesource.com/21608 Reviewed-by: Austin Clements <austin@google.com>
2016-04-11internal/trace: support parsing of 1.5 tracesDmitry Vyukov
1. Parse out version from trace header. 2. Restore handling of 1.5 traces. 3. Restore optional symbolization of traces. 4. Add some canned 1.5 traces for regression testing (http benchmark trace, runtime/trace stress traces, plus one with broken timestamps). Change-Id: Idb18a001d03ded8e13c2730eeeb37c5836e31256 Reviewed-on: https://go-review.googlesource.com/21803 Run-TryBot: Dmitry Vyukov <dvyukov@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Austin Clements <austin@google.com>