Refactor packages

glide.lock

@@ -1,36 +1,37 @@
 hash: 2951dfcd48b65b112760c6c6a388d881200deed5f4c24a02e93ae0483b024756
-updated: 2016-08-14T23:11:39.087051487+09:00
+updated: 2016-11-05T22:35:17.810086239+09:00
 imports:
 - name: github.com/cpuguy83/go-md2man
-  version: 2724a9c9051aa62e9cca11304e7dd518e9e41599
+  version: a65d4d2de4d5f7c74868dfa9b202a3c8be315aaa
   subpackages:
   - md2man
 - name: github.com/fatih/color
-  version: 87d4004f2ab62d0d255e0a38f1680aa534549fe3
+  version: bf82308e8c8546dc2b945157173eb8a959ae9505
 - name: github.com/inconshreveable/mousetrap
   version: 76626ae9c91c4f2a10f34cad8ce83ea42c93bb75
 - name: github.com/mattn/go-colorable
-  version: ed8eb9e318d7a84ce5915b495b7d35e0cfe7b5a8
+  version: d228849504861217f796da67fae4f6e347643f15
 - name: github.com/mattn/go-isatty
   version: 66b8e73f3f5cda9f96b69efd03dd3d7fc4a5cdb8
 - name: github.com/russross/blackfriday
-  version: 93622da34e54fb6529bfb7c57e710f37a8d9cbd8
+  version: 5f33e7b7878355cd2b7e6b8eefc48a5472c69f70
 - name: github.com/shurcooL/sanitized_anchor_name
-  version: 10ef21a441db47d8b13ebcc5fd2310f636973c77
+  version: 1dba4b3954bc059efc3991ec364f9f9a35f597d2
 - name: github.com/spf13/cobra
   version: 2bd8a730ae1986edcd19ee9ca686431cfe78bf2e
 - name: github.com/spf13/pflag
   version: 08b1a584251b5b62f458943640fc8ebd4d50aaa5
 - name: github.com/spf13/viper
-  version: 346299ea79e446ebdddb834371ceba2e5926b732
+  version: 651d9d916abc3c3d6a91a12549495caba5edffd2
 - name: golang.org/x/net
-  version: 07b51741c1d6423d4a6abab1c49940ec09cb1aaf
+  version: 55a3084c9119aeb9ba2437d595b0a7e9cb635da9
   subpackages:
   - http2
   - http2/hpack
+  - idna
   - lex/httplex
 - name: golang.org/x/sys
-  version: a646d33e2ee3172a661fc09bca23bb4889a41bc8
+  version: c200b10b5d5e122be351b67af224adc6128af5bf
   subpackages:
   - unix
 testImports: []

glide.yaml

@@ -1,6 +1,7 @@
 package: github.com/summerwind/h2spec
 import:
 - package: golang.org/x/net
+  varsion: 55a3084c9119aeb9ba2437d595b0a7e9cb635da9
   subpackages:
   - http2
   - http2/hpack

h2spec.go

@@ -2,14 +2,13 @@ package h2spec
 
 import (
 	"fmt"
-	"io/ioutil"
-	"os"
 	"time"
 
 	"github.com/summerwind/h2spec/config"
+	"github.com/summerwind/h2spec/http2"
+	"github.com/summerwind/h2spec/log"
+	"github.com/summerwind/h2spec/reporter"
 	"github.com/summerwind/h2spec/spec"
-	"github.com/summerwind/h2spec/spec/http2"
-	"github.com/summerwind/h2spec/spec/log"
 )
 
 func Run(c *config.Config) error {
@@ -17,10 +16,9 @@ func Run(c *config.Config) error {
 		http2.Spec(),
 	}
 
-	results := []*spec.TestResult{}
 	start := time.Now()
 	for _, s := range specs {
-		results = append(results, s.Test(c)...)
+		s.Test(c)
 	}
 	end := time.Now()
 	d := end.Sub(start)
@@ -30,42 +28,17 @@ func Run(c *config.Config) error {
 	}
 
 	log.SetIndentLevel(0)
-	log.Info(fmt.Sprintf("Finished in %.4f seconds", d.Seconds()))
+	log.Println(fmt.Sprintf("Finished in %.4f seconds", d.Seconds()))
 
-	s := summary(results)
-	tmp := "%d tests, %d passed, %d skipped, %d failed"
-	log.Info(fmt.Sprintf(tmp, s["total"], s["passed"], s["skipped"], s["failed"]))
+	reporter.Summary(specs)
+	reporter.FailedReport(specs)
 
 	if c.JUnitReport != "" {
-		reporter := NewJUnitReporter()
-		report, err := reporter.Export(results)
+		err := reporter.JUnitReport(specs, c.JUnitReport)
 		if err != nil {
 			return err
 		}
-		ioutil.WriteFile(c.JUnitReport, []byte(report), os.ModePerm)
 	}
 
 	return nil
 }
-
-func summary(results []*spec.TestResult) map[string]int {
-	data := map[string]int{
-		"total":   0,
-		"passed":  0,
-		"failed":  0,
-		"skipped": 0,
-	}
-
-	for _, result := range results {
-		data["total"] += 1
-		if result.Failed() {
-			data["failed"] += 1
-		} else if result.Skipped() {
-			data["skipped"] += 1
-		} else {
-			data["passed"] += 1
-		}
-	}
-
-	return data
-}

log/log.go

@@ -0,0 +1,32 @@
+package log
+
+import (
+	"fmt"
+	"strings"
+)
+
+var (
+	IndentLevel int    = 0
+	Indent      string = ""
+)
+
+func SetIndentLevel(level int) {
+	IndentLevel = level
+	Indent = strings.Repeat("  ", level)
+}
+
+func Print(a ...interface{}) {
+	fmt.Printf("%s%s", Indent, fmt.Sprint(a...))
+}
+
+func Println(a ...interface{}) {
+	fmt.Printf("%s%s", Indent, fmt.Sprintln(a...))
+}
+
+func PrintBlankLine() {
+	fmt.Println("")
+}
+
+func ResetLine() {
+	fmt.Printf("\r")
+}

reporter.go

@@ -1,114 +0,0 @@
-package h2spec
-
-import (
-	"encoding/xml"
-	"fmt"
-	"strings"
-
-	"github.com/summerwind/h2spec/spec"
-)
-
-type JUnitTestReport struct {
-	XMLName    xml.Name          `xml:"testsuites"`
-	TestSuites []*JUnitTestSuite `xml:"testsuite"`
-}
-
-type JUnitTestSuite struct {
-	XMLName   xml.Name         `xml:"testsuite"`
-	Name      string           `xml:"name,attr"`
-	Package   string           `xml:"package,attr"`
-	ID        string           `xml:"id,attr"`
-	Tests     int              `xml:"tests,attr"`
-	Skipped   int              `xml:"skipped,attr"`
-	Failures  int              `xml:"failures,attr"`
-	Errors    int              `xml:"errors,attr"`
-	TestCases []*JUnitTestCase `xml:"testcase"`
-}
-
-type JUnitTestCase struct {
-	XMLName   xml.Name      `xml:"testcase"`
-	Package   string        `xml:"package,attr"`
-	ClassName string        `xml:"classname,attr"`
-	Time      string        `xml:"time,attr"`
-	Failures  int           `xml:"failures,attr"`
-	Failure   *JUnitFailure `xml:"failure"`
-	Skipped   *JUnitSkipped `xml:"skipped"`
-}
-
-type JUnitFailure struct {
-	XMLName xml.Name `xml:"failure"`
-	Content string   `xml:",innerxml"`
-}
-
-type JUnitSkipped struct {
-	XMLName xml.Name `xml:"skipped"`
-	Content string   `xml:",innerxml"`
-}
-
-type JUnitReporter struct{}
-
-func NewJUnitReporter() *JUnitReporter {
-	return &JUnitReporter{}
-}
-
-func (e JUnitReporter) Export(results []*spec.TestResult) (string, error) {
-	if len(results) == 0 {
-		return "", nil
-	}
-
-	report := JUnitTestReport{
-		TestSuites: make([]*JUnitTestSuite, 0, 20),
-	}
-
-	var parent *spec.TestGroup
-	var ts *JUnitTestSuite
-
-	for _, r := range results {
-		if parent != r.TestCase.Parent {
-			parent = r.TestCase.Parent
-
-			ts = &JUnitTestSuite{
-				Package:   parent.ID(),
-				Name:      fmt.Sprintf("%s. %s", parent.Section, parent.Name),
-				ID:        parent.Section,
-				Tests:     0,
-				Skipped:   0,
-				Failures:  0,
-				Errors:    0,
-				TestCases: make([]*JUnitTestCase, 0, 20),
-			}
-			report.TestSuites = append(report.TestSuites, ts)
-		}
-
-		tc := &JUnitTestCase{
-			Package:   r.TestCase.Parent.ID(),
-			ClassName: r.TestCase.Desc,
-			Time:      fmt.Sprintf("%.04f", r.Duration.Seconds()),
-		}
-
-		ts.Tests += 1
-		if r.Skipped() {
-			ts.Skipped += 1
-			tc.Skipped = &JUnitSkipped{}
-		} else if r.Failed() {
-			ts.Failures += 1
-
-			err := r.Error.(*spec.TestError)
-			expected := strings.Join(err.Expected, "\n")
-			actual := err.Actual
-
-			tc.Failure = &JUnitFailure{
-				Content: fmt.Sprintf("Expect:\n%s\nActual:\n%s", expected, actual),
-			}
-		}
-
-		ts.TestCases = append(ts.TestCases, tc)
-	}
-
-	buf, err := xml.MarshalIndent(report, "", "  ")
-	if err != nil {
-		return "", err
-	}
-
-	return fmt.Sprintf("%s%s", xml.Header, buf), nil
-}

reporter/junit_report.go

@@ -0,0 +1,119 @@
+package reporter
+
+import (
+	"encoding/xml"
+	"fmt"
+	"io/ioutil"
+	"os"
+	"strings"
+
+	"github.com/summerwind/h2spec/spec"
+)
+
+type JUnitTestReport struct {
+	XMLName    xml.Name          `xml:"testsuites"`
+	TestSuites []*JUnitTestSuite `xml:"testsuite"`
+}
+
+type JUnitTestSuite struct {
+	XMLName   xml.Name         `xml:"testsuite"`
+	Name      string           `xml:"name,attr"`
+	Package   string           `xml:"package,attr"`
+	ID        string           `xml:"id,attr"`
+	Tests     int              `xml:"tests,attr"`
+	Skipped   int              `xml:"skipped,attr"`
+	Failures  int              `xml:"failures,attr"`
+	Errors    int              `xml:"errors,attr"`
+	TestCases []*JUnitTestCase `xml:"testcase"`
+}
+
+type JUnitTestCase struct {
+	XMLName   xml.Name      `xml:"testcase"`
+	Package   string        `xml:"package,attr"`
+	ClassName string        `xml:"classname,attr"`
+	Time      string        `xml:"time,attr"`
+	Failure   *JUnitFailure `xml:"failure"`
+	Skipped   *JUnitSkipped `xml:"skipped"`
+}
+
+type JUnitFailure struct {
+	XMLName xml.Name `xml:"failure"`
+	Content string   `xml:",innerxml"`
+}
+
+type JUnitSkipped struct {
+	XMLName xml.Name `xml:"skipped"`
+	Content string   `xml:",innerxml"`
+}
+
+func JUnitReport(groups []*spec.TestGroup, filePath string) error {
+	report := JUnitTestReport{
+		TestSuites: convertJUnitReport(groups),
+	}
+
+	buf, err := xml.MarshalIndent(report, "", "  ")
+	if err != nil {
+		return err
+	}
+
+	body := fmt.Sprintf("%s%s", xml.Header, buf)
+	return ioutil.WriteFile(filePath, []byte(body), os.ModePerm)
+}
+
+func convertJUnitReport(groups []*spec.TestGroup) []*JUnitTestSuite {
+	ts := make([]*JUnitTestSuite, 20)
+
+	for _, tg := range groups {
+		tests := append(tg.Tests, tg.StrictTests...)
+		if len(tests) == 0 {
+			ts = append(ts, convertJUnitReport(tg.Groups)...)
+			continue
+		}
+
+		jts := &JUnitTestSuite{
+			Package:   tg.ID(),
+			Name:      fmt.Sprintf("%s. %s", tg.Section, tg.Name),
+			ID:        tg.Section,
+			Tests:     0,
+			Skipped:   0,
+			Failures:  0,
+			Errors:    0,
+			TestCases: make([]*JUnitTestCase, 20),
+		}
+
+		for _, tc := range tests {
+			if tc.Result == nil {
+				continue
+			}
+
+			jtc := &JUnitTestCase{
+				Package:   tg.ID(),
+				ClassName: tc.Desc,
+				Time:      fmt.Sprintf("%.04f", tc.Result.Duration.Seconds()),
+			}
+
+			jts.Tests += 1
+			if tc.Result.Skipped {
+				jts.Skipped += 1
+				jtc.Skipped = &JUnitSkipped{}
+			} else if tc.Result.Failed {
+				jts.Failures += 1
+
+				err := tc.Result.Error.(*spec.TestError)
+				expected := strings.Join(err.Expected, "\n")
+				actual := err.Actual
+
+				jtc.Failure = &JUnitFailure{
+					Content: fmt.Sprintf("Expect:\n%s\nActual:\n%s", expected, actual),
+				}
+			}
+
+			jts.TestCases = append(jts.TestCases, jtc)
+		}
+
+		ts = append(ts, jts)
+		ts = append(ts, convertJUnitReport(tg.Groups)...)
+	}
+
+	return ts
+}

reporter/reporter.go

@@ -0,0 +1,90 @@
+package reporter
+
+import (
+	"fmt"
+
+	"github.com/summerwind/h2spec/log"
+	"github.com/summerwind/h2spec/spec"
+)
+
+func Summary(groups []*spec.TestGroup) {
+	s := aggregateSummary(groups)
+	tmp := "%d tests, %d passed, %d skipped, %d failed"
+	log.Println(fmt.Sprintf(tmp, s["total"], s["passed"], s["skipped"], s["failed"]))
+}
+
+func aggregateSummary(groups []*spec.TestGroup) map[string]int {
+	data := map[string]int{
+		"total":   0,
+		"passed":  0,
+		"failed":  0,
+		"skipped": 0,
+	}
+
+	for _, tg := range groups {
+		tests := append(tg.Tests, tg.StrictTests...)
+		for _, tc := range tests {
+			if tc.Result == nil {
+				continue
+			}
+
+			data["total"] += 1
+			if tc.Result.Failed {
+				data["failed"] += 1
+			} else if tc.Result.Skipped {
+				data["skipped"] += 1
+			} else {
+				data["passed"] += 1
+			}
+		}
+
+		if tg.Groups != nil {
+			d := aggregateSummary(tg.Groups)
+			data["total"] += d["total"]
+			data["failed"] += d["failed"]
+			data["skipped"] += d["skipped"]
+			data["passed"] += d["passed"]
+		}
+	}
+
+	return data
+}
+
+func FailedReport(groups []*spec.TestGroup) {
+	log.Println("\n--------------------\n")
+	log.Println("Failed tests: \n")
+
+	for _, tg := range groups {
+		log.Println(tg.Title())
+		printFailed(tg.Groups)
+	}
+}
+
+func printFailed(groups []*spec.TestGroup) {
+	for _, tg := range groups {
+		failed := false
+
+		tests := append(tg.Tests, tg.StrictTests...)
+		for _, tc := range tests {
+			if tc.Result == nil {
+				continue
+			}
+
+			if tc.Result.Failed {
+				log.SetIndentLevel(1)
+				log.Println(tc.Parent.Title())
+				log.SetIndentLevel(2)
+				tc.Result.Print()
+				failed = true
+			}
+		}
+
+		if failed {
+			log.PrintBlankLine()
+		}
+
+		if tg.Groups != nil {
+			printFailed(tg.Groups)
+		}
+	}
+}

runner.go

@@ -1,28 +0,0 @@
-package h2spec
-
-import (
-	"github.com/summerwind/h2spec/config"
-	"github.com/summerwind/h2spec/spec"
-	"github.com/summerwind/h2spec/spec/http2"
-)
-
-type Runner struct {
-	Specs  []*spec.TestGroup
-	Config *config.Config
-}
-
-func (r *Runner) Run() ([]*spec.TestResult, error) {
-	for _, s := range r.Specs {
-		s.Test(r.Config)
-	}
-	return nil, nil
-}
-
-func NewRunner(c *config.Config) *Runner {
-	return &Runner{
-		Specs: []*spec.TestGroup{
-			http2.Spec(),
-		},
-		Config: c,
-	}
-}

spec/connection.go

@@ -14,7 +14,7 @@ import (
 	"golang.org/x/net/http2/hpack"
 
 	"github.com/summerwind/h2spec/config"
-	"github.com/summerwind/h2spec/spec/log"
+	"github.com/summerwind/h2spec/log"
 )
 
 const DefaultWindowSize = 65535
@@ -33,29 +33,32 @@ type Conn struct {
 	framer     *http2.Framer
 	encoder    *hpack.Encoder
 	encoderBuf *bytes.Buffer
+
+	debugFramer    *http2.Framer
+	debugFramerBuf *bytes.Buffer
 }
 
 func Dial(c *config.Config) (*Conn, error) {
-	var conn net.Conn
+	var baseConn net.Conn
 	var err error
 
 	if c.TLS {
 		dialer := &net.Dialer{}
 		dialer.Timeout = c.Timeout
 
-		tconn, err := tls.DialWithDialer(dialer, "tcp", c.Addr(), c.TLSConfig())
+		tlsConn, err := tls.DialWithDialer(dialer, "tcp", c.Addr(), c.TLSConfig())
 		if err != nil {
 			return nil, err
 		}
 
-		cs := tconn.ConnectionState()
+		cs := tlsConn.ConnectionState()
 		if !cs.NegotiatedProtocolIsMutual {
 			return nil, errors.New("Protocol negotiation failed")
 		}
 
-		conn = tconn
+		baseConn = tlsConn
 	} else {
-		conn, err = net.DialTimeout("tcp", c.Addr(), c.Timeout)
+		baseConn, err = net.DialTimeout("tcp", c.Addr(), c.Timeout)
 		if err != nil {
 			return nil, err
 		}
@@ -63,14 +66,15 @@ func Dial(c *config.Config) (*Conn, error) {
 
 	settings := map[http2.SettingID]uint32{}
 
-	framer := http2.NewFramer(conn, conn)
+	framer := http2.NewFramer(baseConn, baseConn)
 	framer.AllowIllegalWrites = true
+	framer.AllowIllegalReads = true
 
 	var encoderBuf bytes.Buffer
 	encoder := hpack.NewEncoder(&encoderBuf)
 
-	return &Conn{
-		Conn:     conn,
+	conn := Conn{
+		Conn:     baseConn,
 		Settings: settings,
 		Timeout:  c.Timeout,
 		Verbose:  c.Verbose,
@@ -82,7 +86,16 @@ func Dial(c *config.Config) (*Conn, error) {
 		framer:     framer,
 		encoder:    encoder,
 		encoderBuf: &encoderBuf,
-	}, nil
+	}
+
+	if conn.Verbose {
+		conn.debugFramerBuf = new(bytes.Buffer)
+		conn.debugFramer = http2.NewFramer(conn.debugFramerBuf, conn.debugFramerBuf)
+		conn.debugFramer.AllowIllegalWrites = true
+		conn.debugFramer.AllowIllegalReads = true
+	}
+
+	return &conn, nil
 }
 
 func (conn *Conn) Handshake() error {
@@ -98,7 +111,7 @@ func (conn *Conn) Handshake() error {
 			ID:  http2.SettingInitialWindowSize,
 			Val: DefaultWindowSize,
 		}
-		conn.framer.WriteSettings(setting)
+		conn.WriteSettings(setting)
 
 		for !(local && remote) {
 			f, err := conn.framer.ReadFrame()
@@ -107,6 +120,9 @@ func (conn *Conn) Handshake() error {
 				return
 			}
 
+			ev := getEventByFrame(f)
+			conn.vlog(ev, false)
+
 			sf, ok := f.(*http2.SettingsFrame)
 			if !ok {
 				done <- errors.New("handshake failed: unexpeced frame")
@@ -121,7 +137,7 @@ func (conn *Conn) Handshake() error {
 					conn.Settings[setting.ID] = setting.Val
 					return nil
 				})
-				conn.framer.WriteSettingsAck()
+				conn.WriteSettingsAck()
 			}
 		}
 
@@ -165,42 +181,81 @@ func (conn *Conn) EncodeHeaders(headers []hpack.HeaderField) []byte {
 }
 
 func (conn *Conn) Send(payload string) error {
-	_, err := conn.Write([]byte(payload))
+	p := []byte(payload)
+	conn.vlog(EventRawData{p}, true)
+	_, err := conn.Write(p)
 	return err
 }
 
 func (conn *Conn) WriteData(streamID uint32, endStream bool, data []byte) error {
-	conn.vlog(EventDataFrame{}, true)
+	if conn.Verbose {
+		conn.debugFramer.WriteData(streamID, endStream, data)
+		conn.logFrameSend()
+	}
+
 	return conn.framer.WriteData(streamID, endStream, data)
 }
 
 func (conn *Conn) WriteHeaders(p http2.HeadersFrameParam) error {
-	conn.vlog(EventHeadersFrame{}, true)
+	if conn.Verbose {
+		conn.debugFramer.WriteHeaders(p)
+		conn.logFrameSend()
+	}
+
 	return conn.framer.WriteHeaders(p)
 }
 
 func (conn *Conn) WritePriority(streamID uint32, p http2.PriorityParam) error {
-	conn.vlog(EventPriorityFrame{}, true)
+	if conn.Verbose {
+		conn.debugFramer.WritePriority(streamID, p)
+		conn.logFrameSend()
+	}
+
 	return conn.framer.WritePriority(streamID, p)
 }
 
 func (conn *Conn) WriteRSTStream(streamID uint32, code http2.ErrCode) error {
-	conn.vlog(EventRSTStreamFrame{}, true)
+	if conn.Verbose {
+		conn.debugFramer.WriteRSTStream(streamID, code)
+		conn.logFrameSend()
+	}
+
 	return conn.framer.WriteRSTStream(streamID, code)
 }
 
 func (conn *Conn) WriteSettings(settings ...http2.Setting) error {
-	conn.vlog(EventSettingsFrame{}, true)
+	if conn.Verbose {
+		conn.debugFramer.WriteSettings(settings...)
+		conn.logFrameSend()
+	}
+
 	return conn.framer.WriteSettings(settings...)
 }
 
+func (conn *Conn) WriteSettingsAck() error {
+	if conn.Verbose {
+		conn.debugFramer.WriteSettingsAck()
+		conn.logFrameSend()
+	}
+
+	return conn.framer.WriteSettingsAck()
+}
+
 func (conn *Conn) WriteWindowUpdate(streamID, incr uint32) error {
-	conn.vlog(EventWindowUpdateFrame{}, true)
+	if conn.Verbose {
+		conn.debugFramer.WriteWindowUpdate(streamID, incr)
+		conn.logFrameSend()
+	}
+
 	return conn.framer.WriteWindowUpdate(streamID, incr)
 }
 
 func (conn *Conn) WriteContinuation(streamID uint32, endHeaders bool, headerBlockFragment []byte) error {
-	conn.vlog(EventContinuationFrame{}, true)
+	if conn.Verbose {
+		conn.debugFramer.WriteContinuation(streamID, endHeaders, headerBlockFragment)
+		conn.logFrameSend()
+	}
+
 	return conn.framer.WriteContinuation(streamID, endHeaders, headerBlockFragment)
 }
 
@@ -241,32 +296,12 @@ func (conn *Conn) WaitEvent() Event {
 		return ev
 	}
 
-	switch f := f.(type) {
-	case *http2.DataFrame:
-		ev = EventDataFrame{*f}
+	_, ok := f.(*http2.DataFrame)
+	if ok {
 		conn.updateWindowSize(f)
-	case *http2.HeadersFrame:
-		ev = EventHeadersFrame{*f}
-	case *http2.PriorityFrame:
-		ev = EventPriorityFrame{*f}
-	case *http2.RSTStreamFrame:
-		ev = EventRSTStreamFrame{*f}
-	case *http2.SettingsFrame:
-		ev = EventSettingsFrame{*f}
-	case *http2.PushPromiseFrame:
-		ev = EventPushPromiseFrame{*f}
-	case *http2.PingFrame:
-		ev = EventPingFrame{*f}
-	case *http2.GoAwayFrame:
-		ev = EventGoAwayFrame{*f}
-	case *http2.WindowUpdateFrame:
-		ev = EventWindowUpdateFrame{*f}
-	case *http2.ContinuationFrame:
-		ev = EventContinuationFrame{*f}
-		//default:
-		//	ev = EventUnknownFrame(f)
 	}
 
+	ev = getEventByFrame(f)
 	conn.vlog(ev, false)
 
 	return ev
@@ -300,12 +335,55 @@ func (conn *Conn) updateWindowSize(f http2.Frame) {
 	}
 }
 
+func (conn *Conn) logFrameSend() {
+	f, err := conn.debugFramer.ReadFrame()
+	if err != nil {
+		return
+	}
+
+	ev := getEventByFrame(f)
+	conn.vlog(ev, true)
+}
+
 func (conn *Conn) vlog(ev Event, send bool) {
-	if conn.Verbose {
+	if !conn.Verbose {
+		return
+	}
+
 	if send {
-			log.Verbose(fmt.Sprintf("send: %s", ev))
+		log.Println(gray(fmt.Sprintf("     <-- [send] %s", ev)))
 	} else {
-			log.Verbose(fmt.Sprintf("recv: %s", ev))
+		log.Println(gray(fmt.Sprintf("     --> [recv] %s", ev)))
 	}
 }
+
+func getEventByFrame(f http2.Frame) Event {
+	var ev Event
+
+	switch f := f.(type) {
+	case *http2.DataFrame:
+		ev = EventDataFrame{*f}
+	case *http2.HeadersFrame:
+		ev = EventHeadersFrame{*f}
+	case *http2.PriorityFrame:
+		ev = EventPriorityFrame{*f}
+	case *http2.RSTStreamFrame:
+		ev = EventRSTStreamFrame{*f}
+	case *http2.SettingsFrame:
+		ev = EventSettingsFrame{*f}
+	case *http2.PushPromiseFrame:
+		ev = EventPushPromiseFrame{*f}
+	case *http2.PingFrame:
+		ev = EventPingFrame{*f}
+	case *http2.GoAwayFrame:
+		ev = EventGoAwayFrame{*f}
+	case *http2.WindowUpdateFrame:
+		ev = EventWindowUpdateFrame{*f}
+	case *http2.ContinuationFrame:
+		ev = EventContinuationFrame{*f}
+		//default:
+		//	ev = EventUnknownFrame(f)
+	}
+
+	return ev
 }

spec/event.go

@@ -1,6 +1,7 @@
 package spec
 
 import (
+	"fmt"
 	"math"
 
 	"golang.org/x/net/http2"
@@ -36,12 +37,20 @@ func (ev EventTimeout) String() string {
 	return "Timeout"
 }
 
+type EventRawData struct {
+	Payload []byte
+}
+
+func (ev EventRawData) String() string {
+	return fmt.Sprintf("Raw Data (0x%x)", ev.Payload)
+}
+
 type EventDataFrame struct {
 	http2.DataFrame
 }
 
 func (ev EventDataFrame) String() string {
-	return "DATA Frame"
+	return frameString(ev.Header())
 }
 
 type EventHeadersFrame struct {
@@ -49,7 +58,7 @@ type EventHeadersFrame struct {
 }
 
 func (ev EventHeadersFrame) String() string {
-	return "HEADERS Frame"
+	return frameString(ev.Header())
 }
 
 type EventPriorityFrame struct {
@@ -57,7 +66,7 @@ type EventPriorityFrame struct {
 }
 
 func (ev EventPriorityFrame) String() string {
-	return "PRIORITY Frame"
+	return frameString(ev.Header())
 }
 
 type EventRSTStreamFrame struct {
@@ -65,7 +74,7 @@ type EventRSTStreamFrame struct {
 }
 
 func (ev EventRSTStreamFrame) String() string {
-	return "RST_STREAM Frame"
+	return frameString(ev.Header())
 }
 
 type EventSettingsFrame struct {
@@ -73,7 +82,7 @@ type EventSettingsFrame struct {
 }
 
 func (ev EventSettingsFrame) String() string {
-	return "SETTINGS Frame"
+	return frameString(ev.Header())
 }
 
 type EventPushPromiseFrame struct {
@@ -81,7 +90,7 @@ type EventPushPromiseFrame struct {
 }
 
 func (ev EventPushPromiseFrame) String() string {
-	return "PUSH_PROMISE Frame"
+	return frameString(ev.Header())
 }
 
 type EventPingFrame struct {
@@ -89,7 +98,7 @@ type EventPingFrame struct {
 }
 
 func (ev EventPingFrame) String() string {
-	return "PING Frame"
+	return frameString(ev.Header())
 }
 
 type EventGoAwayFrame struct {
@@ -97,7 +106,7 @@ type EventGoAwayFrame struct {
 }
 
 func (ev EventGoAwayFrame) String() string {
-	return "GOAWAY Frame"
+	return frameString(ev.Header())
 }
 
 type EventWindowUpdateFrame struct {
@@ -105,7 +114,7 @@ type EventWindowUpdateFrame struct {
 }
 
 func (ev EventWindowUpdateFrame) String() string {
-	return "WINDOW_UPDATE Frame"
+	return frameString(ev.Header())
 }
 
 type EventContinuationFrame struct {
@@ -113,5 +122,15 @@ type EventContinuationFrame struct {
 }
 
 func (ev EventContinuationFrame) String() string {
-	return "CONTINUATION Frame"
+	return frameString(ev.Header())
+}
+
+func frameString(header http2.FrameHeader) string {
+	return fmt.Sprintf(
+		"%s Frame (length:%d, flags:0x%02x, stream_id:%d)",
+		header.Type,
+		header.Length,
+		header.Flags,
+		header.StreamID,
+	)
 }

spec/log/log.go

@@ -1,101 +0,0 @@
-package log
-
-import (
-	"fmt"
-	"strings"
-
-	"github.com/fatih/color"
-)
-
-var (
-	gray   = color.New(color.FgHiBlack).SprintFunc()
-	green  = color.New(color.FgGreen).SprintFunc()
-	red    = color.New(color.FgRed).SprintFunc()
-	yellow = color.New(color.FgYellow).SprintFunc()
-	cyan   = color.New(color.FgCyan).SprintFunc()
-)
-
-var (
-	currentLevel  int    = 0
-	currentIndent string = ""
-)
-
-func SetIndentLevel(level int) {
-	currentLevel = level
-	currentIndent = strings.Repeat("  ", level)
-}
-
-func Print(a ...interface{}) {
-	fmt.Printf("%s%s", currentIndent, fmt.Sprint(a...))
-}
-
-func Println(a ...interface{}) {
-	fmt.Printf("%s%s", currentIndent, fmt.Sprintln(a...))
-}
-
-func DescDryRun(num int, desc string) {
-	Println(fmt.Sprintf("%s %s", number(num), desc))
-}
-
-func DescRunning(num int, desc string) {
-	Print(fmt.Sprintf("  %s %s", gray(number(num)), gray(desc)))
-}
-
-func DescPassed(num int, desc string) {
-	Println(fmt.Sprintf("%s %s %s", green("✔"), gray(number(num)), gray(desc)))
-}
-
-func DescFailed(num int, desc string, req string, expected []string, actual string) {
-	Println(fmt.Sprintf("%s %s %s", red("×"), red(number(num)), red(desc)))
-
-	level := currentLevel
-	SetIndentLevel(level + 1)
-	defer func() {
-		SetIndentLevel(level)
-	}()
-
-	Println(red(fmt.Sprintf("-> %s", req)))
-
-	label := "Expected: "
-	for i, ex := range expected {
-		if i != 0 {
-			label = strings.Repeat(" ", len(label))
-		}
-		Println(yellow(fmt.Sprintf("   %s%s", label, ex)))
-	}
-
-	Println(green(fmt.Sprintf("     Actual: %s", actual)))
-}
-
-func DescSkipped(num int, desc string) {
-	Println(fmt.Sprintf("%s %s", cyan(number(num)), cyan(desc)))
-}
-
-func DescError(num int, desc string, err error) {
-	Println(fmt.Sprintf("%s %s %s", red("×"), red(number(num)), red(desc)))
-	Error(err)
-}
-
-func Info(msg string) {
-	Println(gray(msg))
-}
-
-func Verbose(msg string) {
-	Println(gray(fmt.Sprintf("   | %s", msg)))
-}
-
-func Error(err error) {
-	Println(red(fmt.Sprintf("Error: %v", err)))
-}
-
-func ResetLine() {
-	fmt.Printf("\r")
-}
-
-func leftPad(str, padStr string, padLen int) string {
-	return strings.Repeat(padStr, padLen-len(str)) + str
-}
-
-func number(num int) string {
-	return fmt.Sprintf("%d:", num)
-}

spec/spec.go

@@ -8,7 +8,7 @@ import (
 	"time"
 
 	"github.com/summerwind/h2spec/config"
-	"github.com/summerwind/h2spec/spec/log"
+	"github.com/summerwind/h2spec/log"
 )
 
 var (
@@ -22,9 +22,13 @@ type TestGroup struct {
 	Name        string
 	Strict      bool
 	Parent      *TestGroup
-	groups      []*TestGroup
-	tests       []*TestCase
-	strictTests []*TestCase
+	Groups      []*TestGroup
+	Tests       []*TestCase
+	StrictTests []*TestCase
+}
+
+func (tg *TestGroup) IsRoot() bool {
+	return tg.Parent == nil
 }
 
 func (tg *TestGroup) ID() string {
@@ -35,22 +39,6 @@ func (tg *TestGroup) ID() string {
 	return fmt.Sprintf("%s/%s", tg.Key, tg.Section)
 }
 
-func (tg *TestGroup) AddTestGroup(stg *TestGroup) {
-	stg.Parent = tg
-	stg.Strict = tg.Strict
-	tg.groups = append(tg.groups, stg)
-}
-
-func (tg *TestGroup) AddTestCase(tc *TestCase) {
-	tc.Parent = tg
-	if tg.Strict {
-		tc.Strict = true
-		tg.strictTests = append(tg.strictTests, tc)
-	} else {
-		tg.tests = append(tg.tests, tc)
-	}
-}
-
 func (tg *TestGroup) IsTarget(targets map[string]bool) bool {
 	if len(targets) == 0 {
 		return true
@@ -81,35 +69,6 @@ func (tg *TestGroup) IsTarget(targets map[string]bool) bool {
 	return false
 }
 
-//func (tg *TestGroup) IsTarget(targets []string) bool {
-//	if len(targets) == 0 {
-//		return true
-//	}
-//
-//	id := tg.ID()
-//	for _, target := range targets {
-//		var base, prefix string
-//
-//		if len(target) > len(id) {
-//			base = target
-//			prefix = id
-//		} else {
-//			base = id
-//			prefix = target
-//		}
-//
-//		if strings.HasPrefix(base, prefix) {
-//			return true
-//		}
-//	}
-//
-//	return false
-//}
-
-func (tg *TestGroup) IsRoot() bool {
-	return tg.Parent == nil
-}
-
 func (tg *TestGroup) Title() string {
 	if tg.IsRoot() {
 		return fmt.Sprintf("%s", tg.Name)
@@ -126,80 +85,58 @@ func (tg *TestGroup) Level() int {
 	return strings.Count(tg.Section, ".") + 1
 }
 
-func (tg *TestGroup) Test(c *config.Config) []*TestResult {
-	results := []*TestResult{}
+func (tg *TestGroup) Test(c *config.Config) {
 	level := tg.Level()
 
 	if tg.Strict && !c.Strict {
-		return nil
+		return
 	}
 
 	if !tg.IsTarget(c.Targets) {
-		return nil
+		return
 	}
 
 	log.SetIndentLevel(level)
 	log.Println(tg.Title())
 	log.SetIndentLevel(level + 1)
 
-	tests := append(tg.tests, tg.strictTests...)
-	tested := 0
+	tests := append(tg.Tests, tg.StrictTests...)
+	tested := false
 
 	for i, tc := range tests {
-		num := i + 1
+		seq := i + 1
 
-		if c.DryRun {
-			log.DescDryRun(num, tc.Desc)
-			tested += 1
-			continue
-		}
-
-		if tc.Strict && !c.Strict {
-			continue
-		}
-
-		if !tc.IsTarget(num, c.Targets) {
-			continue
-		}
-
-		if !c.Verbose {
-			log.DescRunning(num, tc.Desc)
-		}
-
-		r, err := tc.Test(c)
+		err := tc.Test(c, seq)
 		if err != nil {
-			log.ResetLine()
-			log.DescError(num, tc.Desc, err)
 			os.Exit(1)
 		}
 
-		log.ResetLine()
-		if r.Skipped() {
-			log.DescSkipped(num, tc.Desc)
-		} else if r.Failed() {
-			err, ok := r.Error.(*TestError)
-			if ok {
-				log.DescFailed(num, tc.Desc, tc.Requirement, err.Expected, err.Actual)
+		tested = true
+	}
+
+	if tested {
+		log.PrintBlankLine()
+	}
+
+	for _, g := range tg.Groups {
+		g.Test(c)
+	}
+}
+
+func (tg *TestGroup) AddTestGroup(stg *TestGroup) {
+	stg.Parent = tg
+	stg.Strict = tg.Strict
+	tg.Groups = append(tg.Groups, stg)
+}
+
+func (tg *TestGroup) AddTestCase(tc *TestCase) {
+	tc.Parent = tg
+	if tg.Strict {
+		tc.Strict = true
+		tg.StrictTests = append(tg.StrictTests, tc)
 	} else {
-				log.DescError(num, tc.Desc, r.Error)
+		tg.Tests = append(tg.Tests, tc)
 	}
-		} else {
-			log.DescPassed(num, tc.Desc)
-		}
-
-		results = append(results, r)
-		tested += 1
-	}
-
-	if tested > 0 {
-		log.Println("")
-	}
-
-	for _, g := range tg.groups {
-		results = append(results, g.Test(c)...)
-	}
-
-	return results
 }
 
 type TestCase struct {
@@ -207,6 +144,7 @@ type TestCase struct {
 	Requirement string
 	Strict      bool
 	Parent      *TestGroup
+	Result      *TestResult
 	Run         func(c *config.Config, conn *Conn) error
 }
 
@@ -239,10 +177,32 @@ func (tc *TestCase) IsTarget(num int, targets map[string]bool) bool {
 	return false
 }
 
-func (tc *TestCase) Test(c *config.Config) (*TestResult, error) {
+func (tc *TestCase) Test(c *config.Config, seq int) error {
+	if c.DryRun {
+		msg := fmt.Sprintf("%s %s", seqStr(seq), tc.Desc)
+		log.Println(msg)
+		return nil
+	}
+
+	if tc.Strict && !c.Strict {
+		return nil
+	}
+
+	if !tc.IsTarget(seq, c.Targets) {
+		return nil
+	}
+
+	if !c.Verbose {
+		msg := gray(fmt.Sprintf("  %s %s", seqStr(seq), tc.Desc))
+		log.Print(msg)
+	}
+
 	conn, err := Dial(c)
 	if err != nil {
-		return nil, err
+		msg := red(fmt.Sprintf("  %s %s %s", "×", seqStr(seq), tc.Desc))
+		log.ResetLine()
+		log.Println(msg)
+		return err
 	}
 	defer conn.Close()
 
@@ -250,27 +210,13 @@ func (tc *TestCase) Test(c *config.Config) (*TestResult, error) {
 	err = tc.Run(c, conn)
 	end := time.Now()
 
-	d := end.Sub(start)
+	log.ResetLine()
 
-	return &TestResult{
-		TestCase: tc,
-		Error:    err,
-		Duration: d,
-	}, nil
-}
+	tr := NewTestResult(tc, seq, err, end.Sub(start))
+	tr.Print()
+	tc.Result = tr
 
-type TestResult struct {
-	TestCase *TestCase
-	Error    error
-	Duration time.Duration
-}
-
-func (tr *TestResult) Skipped() bool {
-	return tr.Error != nil && tr.Error == ErrSkipped
-}
-
-func (tr *TestResult) Failed() bool {
-	return tr.Error != nil && tr.Error != ErrSkipped
+	return nil
 }
 
 type TestError struct {
@@ -281,3 +227,81 @@ type TestError struct {
 func (e TestError) Error() string {
 	return fmt.Sprintf("%s\n%s", strings.Join(e.Expected, "\n"), e.Actual)
 }
+
+type TestResult struct {
+	TestCase *TestCase
+	Sequence int
+	Error    error
+	Duration time.Duration
+
+	Skipped bool
+	Failed  bool
+}
+
+func NewTestResult(tc *TestCase, seq int, err error, d time.Duration) *TestResult {
+	skipped := false
+	failed := false
+
+	if err != nil {
+		if err == ErrSkipped {
+			skipped = true
+		} else {
+			failed = true
+		}
+	}
+
+	tr := TestResult{
+		TestCase: tc,
+		Sequence: seq,
+		Error:    err,
+		Duration: d,
+		Skipped:  skipped,
+		Failed:   failed,
+	}
+
+	return &tr
+}
+
+func (tr *TestResult) Print() {
+	tc := tr.TestCase
+	desc := tc.Desc
+	seq := seqStr(tr.Sequence)
+
+	if tr.Skipped {
+		log.Println(cyan(fmt.Sprintf("%s %s", seq, desc)))
+		return
+	}
+
+	if !tr.Failed {
+		log.Println(fmt.Sprintf("%s %s %s", green("✔"), gray(seq), gray(desc)))
+		return
+	}
+
+	log.Println(red(fmt.Sprintf("%s %s %s", "×", seq, desc)))
+	err, ok := tr.Error.(*TestError)
+	if ok {
+		level := log.IndentLevel
+		log.SetIndentLevel(level + 1)
+		defer func() {
+			log.SetIndentLevel(level)
+		}()
+
+		log.Println(red(fmt.Sprintf("-> %s", tc.Requirement)))
+		label := "Expected: "
+		for i, ex := range err.Expected {
+			if i != 0 {
+				label = strings.Repeat(" ", len(label))
+			}
+			log.Println(yellow(fmt.Sprintf("   %s%s", label, ex)))
+		}
+		log.Println(green(fmt.Sprintf("     Actual: %s", err.Actual)))
+
+		return
+	}
+
+	log.Println(red(fmt.Sprintf("Error: %v", err)))
+}
+
+func seqStr(seq int) string {
+	return fmt.Sprintf("%d:", seq)
+}

spec/util.go

@@ -4,11 +4,20 @@ import (
 	"bytes"
 	"fmt"
 
+	"github.com/fatih/color"
 	"github.com/summerwind/h2spec/config"
 
 	"golang.org/x/net/http2/hpack"
 )
 
+var (
+	gray   = color.New(color.FgHiBlack).SprintFunc()
+	green  = color.New(color.FgGreen).SprintFunc()
+	red    = color.New(color.FgRed).SprintFunc()
+	yellow = color.New(color.FgYellow).SprintFunc()
+	cyan   = color.New(color.FgCyan).SprintFunc()
+)
+
 func DummyString(len int) string {
 	var buffer bytes.Buffer
 	for i := 0; i < len; i++ {

spec/verifier.go

@@ -18,8 +18,19 @@ func VerifyConnectionClose(conn *Conn) error {
 
 	passed := false
 	for !conn.Closed {
-		actual = conn.WaitEvent()
-		_, passed = actual.(EventConnectionClosed)
+		event := conn.WaitEvent()
+
+		switch ev := event.(type) {
+		case EventConnectionClosed:
+			passed = true
+		case EventTimeout:
+			if actual == nil {
+				actual = ev
+			}
+		default:
+			actual = ev
+		}
+
 		if passed {
 			break
 		}
@@ -40,13 +51,19 @@ func VerifyConnectionError(conn *Conn, codes ...http2.ErrCode) error {
 
 	passed := false
 	for !conn.Closed {
-		actual = conn.WaitEvent()
+		ev := conn.WaitEvent()
 
-		switch ev := actual.(type) {
+		switch event := ev.(type) {
 		case EventConnectionClosed:
 			passed = true
 		case EventGoAwayFrame:
-			passed = VerifyErrorCode(codes, ev.ErrCode)
+			passed = VerifyErrorCode(codes, event.ErrCode)
+		case EventTimeout:
+			if actual == nil {
+				actual = event
+			}
+		default:
+			actual = event
 		}
 
 		if passed {
@@ -75,15 +92,21 @@ func VerifyStreamError(conn *Conn, codes ...http2.ErrCode) error {
 
 	passed := false
 	for !conn.Closed {
-		actual = conn.WaitEvent()
+		ev := conn.WaitEvent()
 
-		switch ev := actual.(type) {
+		switch event := ev.(type) {
 		case EventConnectionClosed:
 			passed = true
 		case EventGoAwayFrame:
-			passed = VerifyErrorCode(codes, ev.ErrCode)
+			passed = VerifyErrorCode(codes, event.ErrCode)
 		case EventRSTStreamFrame:
-			passed = VerifyErrorCode(codes, ev.ErrCode)
+			passed = VerifyErrorCode(codes, event.ErrCode)
+		case EventTimeout:
+			if actual == nil {
+				actual = event
+			}
+		default:
+			actual = event
 		}
 
 		if passed {
@@ -113,17 +136,23 @@ func VerifyStreamClose(conn *Conn) error {
 
 	passed := false
 	for !conn.Closed {
-		actual = conn.WaitEvent()
+		ev := conn.WaitEvent()
 
-		switch ev := actual.(type) {
+		switch event := ev.(type) {
 		case EventDataFrame:
-			if ev.StreamEnded() {
+			if event.StreamEnded() {
 				passed = true
 			}
 		case EventHeadersFrame:
-			if ev.StreamEnded() {
+			if event.StreamEnded() {
 				passed = true
 			}
+		case EventTimeout:
+			if actual == nil {
+				actual = event
+			}
+		default:
+			actual = event
 		}
 
 		if passed {