Use readable time stamps on log messages.
On long running tests, the time might wrap:
[LOG] 72.15087 JUJU state: opening state; zookeeper addresses: ["ec2-23-20-157-185.compute-1.amazonaws.com:2181"]
[LOG] 78.46405 JUJU state: waiting for state to be initialized
destroy env
[LOG] 13.73135 JUJU environs/ec2: destroying environment "sample-6326978ae3647455"
This CL makes the time stamp format as a duration since
the start of the test in the format agreed before:
[LOG] 0:00.568 DEBUG juju.environs.tools reading v1.* tools
[LOG] 0:00.569 INFO juju environs/testing: uploading FAKE tools 1.17.3-trusty-amd64
[LOG] 0:00.570 INFO juju environs/testing: uploading FAKE tools 1.17.3-precise-amd64
[LOG] 0:00.571 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any
R=
CC=
https://codereview.appspot.com/5874049
diff --git a/benchmark_test.go b/benchmark_test.go
index 7e96ae7..336243f 100644
--- a/benchmark_test.go
+++ b/benchmark_test.go
@@ -40,10 +40,10 @@
helper := FixtureHelper{sleep: 100000}
output := String{}
runConf := RunConf{
- Output: &output,
- Benchmark: true,
+ Output: &output,
+ Benchmark: true,
BenchmarkTime: 10000000,
- Filter: "Benchmark1",
+ Filter: "Benchmark1",
}
Run(&helper, &runConf)
c.Check(helper.calls[0], Equals, "SetUpSuite")
@@ -63,10 +63,10 @@
helper := FixtureHelper{sleep: 100000}
output := String{}
runConf := RunConf{
- Output: &output,
- Benchmark: true,
+ Output: &output,
+ Benchmark: true,
BenchmarkTime: 10000000,
- Filter: "Benchmark2",
+ Filter: "Benchmark2",
}
Run(&helper, &runConf)
diff --git a/bootstrap_test.go b/bootstrap_test.go
index e50d9ea..a3bc28c 100644
--- a/bootstrap_test.go
+++ b/bootstrap_test.go
@@ -1,7 +1,7 @@
// These initial tests are for bootstrapping. They verify that we can
// basically use the testing infrastructure itself to check if the test
// system is working.
-//
+//
// These tests use will break down the test runner badly in case of
// errors because if they simply fail, we can't be sure the developer
// will ever see anything (because failing means the failing system
diff --git a/foundation_test.go b/foundation_test.go
index 9f89150..12dfd36 100644
--- a/foundation_test.go
+++ b/foundation_test.go
@@ -301,14 +301,9 @@
logger = log.New(os.Stderr, "", 0)
logger = c
logger.Output(0, "Hello there")
- expected := "\\[LOG\\] [.0-9]+ Hello there\n"
+ expected := `\[LOG\] [0-9]+:[0-9][0-9]\.[0-9][0-9][0-9] +Hello there\n`
output := c.GetTestLog()
- matched, err := regexp.MatchString(expected, output)
- if err != nil {
- c.Error("Bad expression: ", expected)
- } else if !matched {
- c.Error("Output() didn't log properly:\n", output)
- }
+ c.Assert(output, gocheck.Matches, expected)
}
// -----------------------------------------------------------------------
diff --git a/gocheck.go b/gocheck.go
index 50af42e..780594f 100644
--- a/gocheck.go
+++ b/gocheck.go
@@ -62,7 +62,7 @@
}
func (method *methodType) String() string {
- return method.suiteName()+"."+method.Info.Name
+ return method.suiteName() + "." + method.Info.Name
}
func (method *methodType) matches(re *regexp.Regexp) bool {
@@ -81,6 +81,7 @@
reason string
mustFail bool
tempDir *tempDir
+ startTime time.Time
timer
}
@@ -613,13 +614,14 @@
logb = new(logger)
}
c := &C{
- method: method,
- kind: kind,
- logb: logb,
- logw: logw,
- tempDir: runner.tempDir,
- done: make(chan *C, 1),
- timer: timer{benchTime: runner.benchTime},
+ method: method,
+ kind: kind,
+ logb: logb,
+ logw: logw,
+ tempDir: runner.tempDir,
+ done: make(chan *C, 1),
+ timer: timer{benchTime: runner.benchTime},
+ startTime: time.Now(),
}
runner.tracker.expectCall(c)
go (func() {
@@ -913,4 +915,3 @@
return fmt.Sprintf("%s%s: %s: %s%s", prefix, label, niceFuncPath(pc),
niceFuncName(pc), suffix)
}
-
diff --git a/gocheck_test.go b/gocheck_test.go
index 7575df4..e4acda9 100644
--- a/gocheck_test.go
+++ b/gocheck_test.go
@@ -94,13 +94,13 @@
// Helper suite for testing ordering and behavior of fixture.
type FixtureHelper struct {
- calls []string
- panicOn string
- skip bool
- skipOnN int
- sleepOn string
- sleep time.Duration
- bytes int64
+ calls []string
+ panicOn string
+ skip bool
+ skipOnN int
+ sleepOn string
+ sleep time.Duration
+ bytes int64
}
func (s *FixtureHelper) trace(name string, c *gocheck.C) {
diff --git a/helpers.go b/helpers.go
index fe4ca51..5b8b3fd 100644
--- a/helpers.go
+++ b/helpers.go
@@ -92,9 +92,12 @@
// Output enables *C to be used as a logger in functions that require only
// the minimum interface of *log.Logger.
func (c *C) Output(calldepth int, s string) error {
- ns := time.Now().Sub(time.Time{}).Nanoseconds()
- t := float64(ns%100e9) / 1e9
- c.Logf("[LOG] %.05f %s", t, s)
+ d := time.Now().Sub(c.startTime)
+ msec := d / time.Millisecond
+ sec := d / time.Second
+ min := d / time.Minute
+
+ c.Logf("[LOG] %d:%02d.%03d %s", min, sec%60, msec%1000, s)
return nil
}
diff --git a/run.go b/run.go
index dc75d77..8400355 100644
--- a/run.go
+++ b/run.go
@@ -30,7 +30,7 @@
verboseFlag = flag.Bool("gocheck.v", false, "Verbose mode")
streamFlag = flag.Bool("gocheck.vv", false, "Super verbose mode (disables output caching)")
benchFlag = flag.Bool("gocheck.b", false, "Run benchmarks")
- benchTime = flag.Duration("gocheck.btime", 1 * time.Second, "approximate run time for each benchmark")
+ benchTime = flag.Duration("gocheck.btime", 1*time.Second, "approximate run time for each benchmark")
listFlag = flag.Bool("gocheck.list", false, "List the names of all tests that will be run")
)
@@ -39,10 +39,10 @@
// module.
func TestingT(testingT *testing.T) {
conf := &RunConf{
- Filter: *filterFlag,
- Verbose: *verboseFlag,
- Stream: *streamFlag,
- Benchmark: *benchFlag,
+ Filter: *filterFlag,
+ Verbose: *verboseFlag,
+ Stream: *streamFlag,
+ Benchmark: *benchFlag,
BenchmarkTime: *benchTime,
}
if *listFlag {
diff --git a/run_test.go b/run_test.go
index 6793e4c..cdcddc0 100644
--- a/run_test.go
+++ b/run_test.go
@@ -2,7 +2,6 @@
package gocheck_test
-
import (
"errors"
. "launchpad.net/gocheck"
@@ -299,7 +298,7 @@
}
// -----------------------------------------------------------------------
-// Verify that verbose mode prints tests which pass as well.
+// Verify that verbose mode prints tests which pass as well.
func (s *RunS) TestVerboseMode(c *C) {
helper := FixtureHelper{}
