{"action":"created","issue":{"url":"https://api.github.com/repos/golang/go/issues/24929","repository_url":"https://api.github.com/repos/golang/go","labels_url":"https://api.github.com/repos/golang/go/issues/24929/labels{/name}","comments_url":"https://api.github.com/repos/golang/go/issues/24929/comments","events_url":"https://api.github.com/repos/golang/go/issues/24929/events","html_url":"https://github.com/golang/go/issues/24929","id":315568389,"node_id":"MDU6SXNzdWUzMTU1NjgzODk=","number":24929,"title":"testing: stream t.Log output as it happens","user":{"login":"brikis98","id":711908,"node_id":"MDQ6VXNlcjcxMTkwOA==","avatar_url":"https://avatars1.githubusercontent.com/u/711908?v=4","gravatar_id":"","url":"https://api.github.com/users/brikis98","html_url":"https://github.com/brikis98","followers_url":"https://api.github.com/users/brikis98/followers","following_url":"https://api.github.com/users/brikis98/following{/other_user}","gists_url":"https://api.github.com/users/brikis98/gists{/gist_id}","starred_url":"https://api.github.com/users/brikis98/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/brikis98/subscriptions","organizations_url":"https://api.github.com/users/brikis98/orgs","repos_url":"https://api.github.com/users/brikis98/repos","events_url":"https://api.github.com/users/brikis98/events{/privacy}","received_events_url":"https://api.github.com/users/brikis98/received_events","type":"User","site_admin":false},"labels":[{"id":236419512,"node_id":"MDU6TGFiZWwyMzY0MTk1MTI=","url":"https://api.github.com/repos/golang/go/labels/Proposal","name":"Proposal","color":"ededed","default":false},{"id":246350233,"node_id":"MDU6TGFiZWwyNDYzNTAyMzM=","url":"https://api.github.com/repos/golang/go/labels/Proposal-Accepted","name":"Proposal-Accepted","color":"009800","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":{"url":"https://api.github.com/repos/golang/go/milestones/65","html_url":"https://github.com/golang/go/milestone/65","labels_url":"https://api.github.com/repos/golang/go/milestones/65/labels","id":3072996,"node_id":"MDk6TWlsZXN0b25lMzA3Mjk5Ng==","number":65,"title":"Go1.12","description":"","creator":{"login":"rsc","id":104030,"node_id":"MDQ6VXNlcjEwNDAzMA==","avatar_url":"https://avatars1.githubusercontent.com/u/104030?v=4","gravatar_id":"","url":"https://api.github.com/users/rsc","html_url":"https://github.com/rsc","followers_url":"https://api.github.com/users/rsc/followers","following_url":"https://api.github.com/users/rsc/following{/other_user}","gists_url":"https://api.github.com/users/rsc/gists{/gist_id}","starred_url":"https://api.github.com/users/rsc/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/rsc/subscriptions","organizations_url":"https://api.github.com/users/rsc/orgs","repos_url":"https://api.github.com/users/rsc/repos","events_url":"https://api.github.com/users/rsc/events{/privacy}","received_events_url":"https://api.github.com/users/rsc/received_events","type":"User","site_admin":false},"open_issues":701,"closed_issues":384,"state":"open","created_at":"2018-01-29T21:17:52Z","updated_at":"2018-11-05T14:44:56Z","due_on":"2019-01-31T08:00:00Z","closed_at":null},"comments":15,"created_at":"2018-04-18T17:14:49Z","updated_at":"2018-11-05T15:46:25Z","closed_at":null,"author_association":"NONE","body":"As suggested in https://github.com/golang/go/issues/23213#issuecomment-382194330, I'm filing a new issue with a proposal for how to improve `t.Log` and `t.Logf`.\r\n\r\n### What version of Go are you using (`go version`)?\r\n\r\ngo version go1.9.2\r\n\r\n### Does this issue reproduce with the latest release?\r\n\r\nYes\r\n\r\n### What operating system and processor architecture are you using (`go env`)?\r\n\r\nI'm on Darwin, amd64, but this affects all systems/architectures.\r\n\r\n### Motivation\r\n\r\nConsider the following (silly) automated tests:\r\n\r\n```go\r\nfunc TestFoo(t *testing.T) {\r\n\tt.Parallel()\r\n\r\n\tfor i := 0; i < 15; i++ {\r\n\t\tt.Logf(\"%d\", i)\r\n\t\ttime.Sleep(3 * time.Second)\r\n\t}\r\n}\r\n\r\nfunc TestBar(t *testing.T) {\r\n\tt.Parallel()\r\n\r\n\tfor i := 0; i < 15; i++ {\r\n\t\tt.Logf(\"%d\", i)\r\n\t\ttime.Sleep(2 * time.Second)\r\n\t}\r\n}\r\n\r\nfunc TestBaz(t *testing.T) {\r\n\tt.Parallel()\r\n\r\n\tfor i := 0; i < 15; i++ {\r\n\t\tt.Logf(\"%d\", i)\r\n\t\ttime.Sleep(1 * time.Second)\r\n\t}\r\n}\r\n```\r\n\r\nIf I run `go test -v`, I get no log output until all of `TestFoo` is done, then no output until all of `TestBar` is done, and again no more output until all of `TestBaz` is done. This is fine if the tests are working, but if there is some sort of bug, there are a few cases where buffering log output is problematic:\r\n\r\n* When iterating locally, I want to be able to make a change, run my tests, see what's happening in the logs _immediately_ to understand what's going on, hit CTRL+C to shut the test down early if necessary, make another change, re-run the tests, and so on. If `TestFoo` is slow (e.g., it's an integration test), I get no log output until the very end of the test. This significantly slows down iteration.\r\n* If `TestFoo` has a bug that causes it to hang and never complete, I'd get no log output whatsoever. In these cases, `t.Log` and `t.Logf` are of no use at all. This makes debugging very difficult.\r\n* Moreover, not only do I get no log output, but if the test hangs too long, either the Go test timeout kills the test after 10 minutes, or if I increase that timeout, many CI servers will also kill off tests if there is no log output after a certain amount of time (e.g., 10 minutes in CircleCI). So now my tests are killed and I have _nothing_ in the logs to tell me what happened.\r\n\r\n### Current workarounds\r\n\r\nThe main workaround is to replace all `t.Logf` calls with either `fmt.Printf` or a custom logger. Since we often want to iterate quickly on tests, and since debugging is such an important use case, in practice, that means we never use `t.Logf` at all.\r\n\r\nThis seems like a missed opportunity. Go has a lot of powerful testing tools built in, and we usually pass the `t` variable around to many test methods so they can call `t.Fatal()`, `t.Name()`, etc. It would be great if `t` had a logger built in that we could actually use. Honestly, the only thing it's really missing is some way to configure the logger to write to `stdout` immediately, rather than buffering.\r\n\r\n### Possible solutions\r\n\r\nProbably the easiest way to improve `t.Log` and `t.Logf` is to add a `-test.streamlogs` option to the `go test` command. When this option is set, `t.Log` and `t.Logf` write to `stdout` immediately, instead of buffering. \r\n\r\nThis means the output format with this option set wouldn't be backwards compatible, but the expectation is that this option would only be used for local debugging, and not something used in your CI system."},"comment":{"url":"https://api.github.com/repos/golang/go/issues/comments/435923262","html_url":"https://github.com/golang/go/issues/24929#issuecomment-435923262","issue_url":"https://api.github.com/repos/golang/go/issues/24929","id":435923262,"node_id":"MDEyOklzc3VlQ29tbWVudDQzNTkyMzI2Mg==","user":{"login":"jadekler","id":3584893,"node_id":"MDQ6VXNlcjM1ODQ4OTM=","avatar_url":"https://avatars3.githubusercontent.com/u/3584893?v=4","gravatar_id":"","url":"https://api.github.com/users/jadekler","html_url":"https://github.com/jadekler","followers_url":"https://api.github.com/users/jadekler/followers","following_url":"https://api.github.com/users/jadekler/following{/other_user}","gists_url":"https://api.github.com/users/jadekler/gists{/gist_id}","starred_url":"https://api.github.com/users/jadekler/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jadekler/subscriptions","organizations_url":"https://api.github.com/users/jadekler/orgs","repos_url":"https://api.github.com/users/jadekler/repos","events_url":"https://api.github.com/users/jadekler/events{/privacy}","received_events_url":"https://api.github.com/users/jadekler/received_events","type":"User","site_admin":false},"created_at":"2018-11-05T15:46:25Z","updated_at":"2018-11-05T15:46:25Z","author_association":"CONTRIBUTOR","body":"@mvdan Replied to your question in gerrit. (tldr: it changes it slightly)"}}
{"actor":{"display_login":"jadekler"}}