Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

cmd/go: add option to output timestamps along with command tracing #22526

Closed
pmenglund opened this issue Nov 1, 2017 · 7 comments
Closed

cmd/go: add option to output timestamps along with command tracing #22526

pmenglund opened this issue Nov 1, 2017 · 7 comments
Labels
FeatureRequest FrozenDueToAge NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made.
Milestone
Unplanned

Comments

@pmenglund
Copy link

What version of Go are you using (go version)?

go version go1.8 darwin/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/englund/go"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/c4/81xwbyks1c55pm5dxsz2j73xhj07qj/T/go-build552947938=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

When you use the -x flag to build, it wold be useful to be able to pass in -t too, to see the start time of each command to get a rough estimate on where the time is spent. On one server I was working on, a path was NFS mounted, and timestamps would have let me track down the slowdown quicker.

What did you expect to see?

$ go build -x -t
[2017-11-01 09:09:15.653] WORK=/var/folders/c4/81xwbyks1c55pm5dxsz2j73xhj07qj/T/go-build902893394
[2017-11-01 09:09:15.853] mkdir -p $WORK/_/Users/englund/src/go/test/_obj/
[2017-11-01 09:09:16.142] mkdir -p $WORK/_/Users/englund/src/go/test/_obj/exe/
[2017-11-01 09:09:16.653] cd /Users/englund/src/go/test
[2017-11-01 09:09:17.532] /usr/local/go/pkg/tool/darwin_amd64/compile -o $WORK/_/Users/englund/src/go/test.a -trimpath $WORK -p main -complete -buildid 3e52baceee0a3c34b32debe006b809686bc2906c -D _/Users/englund/src/go/test -I $WORK -pack ./main.go
[2017-11-01 09:09:17.653] cd .
[2017-11-01 09:09:18.653] /usr/local/go/pkg/tool/darwin_amd64/link -o $WORK/_/Users/englund/src/go/test/_obj/exe/a.out -L $WORK -extld=clang -buildmode=exe -buildid=3e52baceee0a3c34b32debe006b809686bc2906c $WORK/_/Users/englund/src/go/test.a
[2017-11-01 09:09:19.653] mv $WORK/_/Users/englund/src/go/test/_obj/exe/a.out test

What did you see instead?

$ go build -x
WORK=/var/folders/c4/81xwbyks1c55pm5dxsz2j73xhj07qj/T/go-build902893394
mkdir -p $WORK/_/Users/englund/src/go/test/_obj/
mkdir -p $WORK/_/Users/englund/src/go/test/_obj/exe/
cd /Users/englund/src/go/test
/usr/local/go/pkg/tool/darwin_amd64/compile -o $WORK/_/Users/englund/src/go/test.a -trimpath $WORK -p main -complete -buildid 3e52baceee0a3c34b32debe006b809686bc2906c -D _/Users/englund/src/go/test -I $WORK -pack ./main.go
cd .
/usr/local/go/pkg/tool/darwin_amd64/link -o $WORK/_/Users/englund/src/go/test/_obj/exe/a.out -L $WORK -extld=clang -buildmode=exe -buildid=3e52baceee0a3c34b32debe006b809686bc2906c $WORK/_/Users/englund/src/go/test.a
mv $WORK/_/Users/englund/src/go/test/_obj/exe/a.out test
@ianlancetaylor ianlancetaylor changed the title Request for enhancement: add option to output timestamps along with command tracing cmd/go: add option to output timestamps along with command tracing Nov 1, 2017
@ianlancetaylor ianlancetaylor added this to the Go1.11 milestone Nov 1, 2017
@ianlancetaylor ianlancetaylor added the NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made. label Nov 1, 2017
@rsc
Copy link
Contributor

rsc commented Nov 6, 2017 •
edited

Note that you can do

go build -x 2>&1 | while read x; do echo "$(date) $x"; done

@pmenglund
Copy link
Author

Right, but that primes the cache, which might mask some issues.

@pmenglund
Copy link
Author

And I'm willing to take on implementing this feature, once it is deemed as worthwhile to have.

@rsc
Copy link
Contributor

rsc commented Nov 10, 2017

What do you mean "that primes the cache"? My point is that if you want to add timestamps to output you can do that by piping it through a timestamp-adding program (or script).

@pmenglund
Copy link
Author

I meant it runs the commands and thus the files end up in the file system cache, which affects the following execution.

@ianlancetaylor ianlancetaylor modified the milestones: Go1.11, Unplanned Jul 3, 2018
@bcmills
Copy link
Contributor

bcmills commented Jan 18, 2019 •
edited

The more work we do in parallel, the less useful timestamps will be, and as @rsc notes you can already pipe the output of go build -x through some other process that can annotate each line with (approximate) timestamps.

I don't think timestamps alone would are worth the complexity (particularly in terms of documentation). I'd be open to a general trace of the build (including both start and stop times, and produced in some standard structured form), but that's a matter for a separate proposal.

@bcmills bcmills closed this as completed Jan 18, 2019
@josharian
Copy link
Contributor

I built a pretty decent (if I say so myself) tracer for cmd/go, demo'd in #15736. Perhaps someone would like to revive that?

Note that at the end of that thread, Russ indicated he'd just as soon instead add timing information. So it seems like the two of you are headed in opposite directions.

@golang golang locked and limited conversation to collaborators Jan 18, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FeatureRequest FrozenDueToAge NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made.
Projects
None yet
Milestone
Unplanned
Development

No branches or pull requests
6 participants
@pmenglund @josharian @rsc @ianlancetaylor @bcmills @gopherbot