Multiple changes to the test framework. Interim commit
to avoid losing code if my VM crashes

Change-Id: I5f03db81851dba1fb0c944c8e5f3a845ddbec2c8
diff --git a/tests/afrouter/suites/test1.json b/tests/afrouter/suites/test1.json
index a6791a0..9e749ac 100644
--- a/tests/afrouter/suites/test1.json
+++ b/tests/afrouter/suites/test1.json
@@ -60,7 +60,8 @@
 				"method":"CreateDevice",
 				"param":"{Type:\"simulated_olt\"}",
 				"expect":"{Id:\"abcd1234\",Type:\"simulated_olt\"}",
-				"_meta":""
+				"_meta":"",
+				"_expectMeta":""
 			},
 			"servers": [
 				{
@@ -90,7 +91,8 @@
 				"method":"GetDevice",
 				"param":"{Id:\"abcd1234\"}",
 				"expect":"{Id:\"abcd1234\",Type:\"simulated_olt\"}",
-				"_meta":""
+				"_meta":"",
+				"_expectMeta":""
 			},
 			"servers": [
 				{
@@ -98,7 +100,7 @@
 					"meta": [
 						{
 							"key":"voltha_serial_number",
-							"value":"0"
+							"value":"1"
 						}
 					]
 				},
@@ -107,7 +109,43 @@
 					"meta": [
 						{
 							"key":"voltha_serial_number",
-							"value":"0"
+							"value":"1"
+						}
+					]
+				}
+			]
+		},
+		{
+			"name":"Test Subscribe",
+			"send": {
+				"client":"client",
+				"method":"Subscribe",
+				"param":"{OfagentId:\"Agent007\"}",
+				"meta": [
+					{
+						"key":"voltha_backend_name",
+						"value":""
+					}
+				],
+				"expect":"{OfagentId:\"Agent007\",VolthaId:\"core11\"}",
+				"expectMeta": [
+					{
+						"key":"voltha_backend_name",
+						"value":"vcore1"
+					}
+				]
+			},
+			"servers": [
+				{
+					"name":"core11",
+					"meta": [
+						{
+							"key":"voltha_serial_number",
+							"value":"2"
+						},
+						{
+							"key":"voltha_backend_name",
+							"value":""
 						}
 					]
 				}
diff --git a/tests/afrouter/suites/test2.json b/tests/afrouter/suites/test2.json
index 2d3d7ad..bdecd95 100644
--- a/tests/afrouter/suites/test2.json
+++ b/tests/afrouter/suites/test2.json
@@ -54,32 +54,98 @@
 	},
 	"tests":[
 		{
+			"name":"Test CreateDevice",
 			"send": {
 				"client":"client",
 				"method":"CreateDevice",
-				"param":"json struct",
+				"param":"{Type:\"simulated_olt\"}",
+				"expect":"{Id:\"abcd1234\",Type:\"simulated_olt\"}",
 				"_meta":""
 			},
 			"servers": [
 				{
-					"name":"server11",
+					"name":"core11",
 					"meta": [
 						{
 							"key":"voltha_serial_number",
-							"value":"1"
+							"value":"0"
 						}
-					],
-					"param":"mirror_client"
+					]
 				},
 				{
-					"name":"server12",
+					"name":"core12",
+					"meta": [
+						{
+							"key":"voltha_serial_number",
+							"value":"0"
+						}
+					]
+				}
+			]
+		},
+		{
+			"name":"Test GetDevice",
+			"send": {
+				"client":"client",
+				"method":"GetDevice",
+				"param":"{Id:\"abcd1234\"}",
+				"expect":"{Id:\"abcd1234\",Type:\"simulated_olt\"}",
+				"_meta":""
+			},
+			"servers": [
+				{
+					"name":"core11",
 					"meta": [
 						{
 							"key":"voltha_serial_number",
 							"value":"1"
 						}
-					],
-					"param":"mirror_client"
+					]
+				},
+				{
+					"name":"core12",
+					"meta": [
+						{
+							"key":"voltha_serial_number",
+							"value":"1"
+						}
+					]
+				}
+			]
+		},
+		{
+			"name":"Test Subscribe",
+			"send": {
+				"client":"client",
+				"method":"Subscribe",
+				"param":"{OfagentId:\"Agent007\"}",
+				"meta": [
+					{
+						"key":"voltha_backend_name",
+						"value":""
+					}
+				],
+				"expect":"{OfagentId:\"Agent007\",VolthaId:\"core11\"}",
+				"expectMeta": [
+					{
+						"key":"voltha_backend_name",
+						"value":"core11"
+					}
+				]
+			},
+			"servers": [
+				{
+					"name":"core11",
+					"meta": [
+						{
+							"key":"voltha_serial_number",
+							"value":"2"
+						},
+						{
+							"key":"voltha_backend_name",
+							"value":"a"
+						}
+					]
 				}
 			]
 		}
diff --git a/tests/afrouter/templates/client.go b/tests/afrouter/templates/client.go
index d384baf..8cd3330 100644
--- a/tests/afrouter/templates/client.go
+++ b/tests/afrouter/templates/client.go
@@ -22,6 +22,7 @@
 	"encoding/json"
 	"google.golang.org/grpc"
 	"golang.org/x/net/context"
+	"google.golang.org/grpc/metadata"
 	"github.com/opencord/voltha-go/common/log"
 	// Values generated by the go template
 	{{range .Imports}}
@@ -35,7 +36,7 @@
 
 {{if .Ct}}{{else}}
 type clientCtl struct {
-	send func(string, interface{}, string) error
+	send func(string, context.Context, interface{}, string, metadata.MD) error
 	cncl  context.CancelFunc
 	ctx context.Context
 }
@@ -74,19 +75,23 @@
 // parameter and validate that the response matches the expected
 // value provided. It will return nil if successful or an error
 // if not.
-func {{.Name}}Send(mthd string, param interface{}, expect string) error {
+func {{.Name}}Send(mthd string, ctx context.Context, param interface{},
+					expect string, expectMeta metadata.MD) error {
 	switch mthd {
 	{{range .Methods}}
-		case "{{.Name}}":
+	case "{{.Name}}":
+		var hdr metadata.MD
 		switch t := param.(type) {
-			case *{{.Param}}:
+		case *{{.Param}}:
 	{{if .Ss}}
 			_=t
+			_=hdr
 	{{else if .Cs}}
 			_=t
+			_=hdr
 	{{else}}
 			client := {{.Pkg}}.New{{.Svc}}Client({{$.Name}}Client.conn)
-			res, err := client.{{.Name}}(context.Background(), t)
+			res, err := client.{{.Name}}(ctx, t, grpc.Header(&hdr))
 			if err != nil {
 				return errors.New("Error sending method {{.Name}}")
 			}
@@ -94,13 +99,27 @@
 			// value.
 			if resS,err := json.Marshal(res); err == nil {
 				if string(resS) != expect {
+					resFile.testLog("Unexpected result returned\n")
 					return errors.New("Unexpected result on method {{.Name}}")
 				}
 			} else {
 				return errors.New("Error Marshaling the reply for method {{.Name}}")
 			}
-			default:
-					return errors.New("Invalid parameter type for method {{.Name}}")
+			// Now validate the metadata in the response
+			for k,v := range expectMeta {
+				if rv,ok := hdr[k]; ok == true {
+					if rv[0] != v[0] {
+						resFile.testLog("Mismatch on returned metadata for key '%s' expected '%s' and got '%s'\n", k, v, rv)
+						err = errors.New("Failure on returned metadata")
+					}
+				} else {
+					resFile.testLog("Returned metadata missing key '%s'; expected value '%s' at that key\n", k, v)
+					err = errors.New("Failure on returned metadata")
+				}
+			}
+			return err
+		default:
+			return errors.New("Invalid parameter type for method {{.Name}}")
 	{{end}}
 		}
 	{{end}}
diff --git a/tests/afrouter/templates/main.go b/tests/afrouter/templates/main.go
index 5c094d9..f539a02 100644
--- a/tests/afrouter/templates/main.go
+++ b/tests/afrouter/templates/main.go
@@ -21,6 +21,7 @@
 
 import (
 	"os"
+	"fmt"
 	"time"
 	"os/exec"
 	"strings"
@@ -28,9 +29,48 @@
 	"github.com/opencord/voltha-go/common/log"
 )
 
-var resFile *os.File
+var resFile *tstLog
+type tstLog struct {
+	fp * os.File
+	fn string
+}
 
-func startSut(cmdStr string) (context.CancelFunc, error) {
+func (tr * tstLog) testLog(format string, a ...interface{}) {
+	var err error
+	if tr.fp == nil {
+		if tr.fp, err = os.OpenFile(tr.fn, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644); err != nil {
+			log.Errorf("Could not append to the results file")
+			tr.fp = nil
+		}
+	}
+	if tr.fp != nil {
+		tr.fp.Write([]byte(fmt.Sprintf(format, a...)))
+	}
+}
+
+func (tr * tstLog) testLogOnce(format string, a ...interface{}) {
+	var err error
+	if tr.fp == nil {
+		if tr.fp, err = os.OpenFile(tr.fn, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644); err != nil {
+			log.Errorf("Could not append to the results file")
+			tr.fp = nil
+		}
+	}
+	if tr.fp != nil {
+		tr.fp.Write([]byte(fmt.Sprintf(format, a...)))
+	}
+	tr.fp.Close()
+	tr.fp = nil
+}
+
+func (tr * tstLog) close() {
+	if tr.fp != nil {
+		tr.fp.Close()
+	}
+}
+
+
+func startSut(cmdStr string) (*exec.Cmd, context.CancelFunc, error) {
 	var err error = nil
 
 	cmdAry := strings.Fields(cmdStr)
@@ -45,13 +85,14 @@
 		log.Errorf("Failed to run the affinity router: %s %v", cmdStr,err)
 	}
 	time.Sleep(1 * time.Second) // Give the command time to get started
-	return cncl, err
+	return cmd, cncl, err
 }
 
-func cleanUp(cncl context.CancelFunc) {
+func cleanUp(cmd *exec.Cmd, cncl context.CancelFunc) {
 	cncl()
+	cmd.Wait() // This seems to hang
 	// Give the child processes time to terminate
-	time.Sleep(1 * time.Second)
+	//time.Sleep(1 * time.Second)
 }
 
 func main() {
@@ -64,12 +105,9 @@
 
 	defer log.CleanUp()
 
-	// Open the results file to write the results to
-	if resFile, err = os.OpenFile(os.Args[1], os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644); err != nil {
-		log.Errorf("Could not append to the results file")
-	}
+	resFile = &tstLog{fn:os.Args[1]}
+	defer resFile.close()
 
-	defer resFile.Close()
 
 	// Initialize the servers
 	if err := serverInit(); err != nil {
@@ -78,8 +116,8 @@
 	}
 
 	// Start the sofware under test
-	cnclFunc, err := startSut("./{{.Command}}");
-	defer cleanUp(cnclFunc)
+	cmd, cnclFunc, err := startSut("./{{.Command}}");
+	defer cleanUp(cmd, cnclFunc)
 	if  err != nil {
 		return
 	}
@@ -94,7 +132,6 @@
 
 	// Run all the test cases now
 	log.Infof("Executing tests")
-	resFile.Write([]byte("Executing tests\n"))
 	runTests()
 
 }
diff --git a/tests/afrouter/templates/runAll.go b/tests/afrouter/templates/runAll.go
index b85e4c7..b4079d1 100644
--- a/tests/afrouter/templates/runAll.go
+++ b/tests/afrouter/templates/runAll.go
@@ -28,6 +28,45 @@
 	"github.com/opencord/voltha-go/common/log"
 )
 
+type tstLog struct {
+	fp * os.File
+	fn string
+}
+
+func (tr * tstLog) testLog(format string, a ...interface{}) {
+	var err error
+	if tr.fp == nil {
+		if tr.fp, err = os.OpenFile(tr.fn, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644); err != nil {
+			log.Errorf("Could not append to the results file")
+			tr.fp = nil
+		}
+	}
+	if tr.fp != nil {
+		tr.fp.Write([]byte(fmt.Sprintf(format, a...)))
+	}
+}
+
+func (tr * tstLog) testLogOnce(format string, a ...interface{}) {
+	var err error
+	if tr.fp == nil {
+		if tr.fp, err = os.OpenFile(tr.fn, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644); err != nil {
+			log.Errorf("Could not append to the results file")
+			tr.fp = nil
+		}
+	}
+	if tr.fp != nil {
+		tr.fp.Write([]byte(fmt.Sprintf(format, a...)))
+	}
+	tr.fp.Close()
+	tr.fp = nil
+}
+
+func (tr * tstLog) close() {
+	if tr.fp != nil {
+		tr.fp.Close()
+	}
+}
+
 func main() {
 	var cmd *exec.Cmd
 	var cmdStr string
@@ -39,12 +78,15 @@
 	defer log.CleanUp()
 
 	log.Info("Running tests")
-	{{range .}}
 	if err:= os.Chdir(os.Args[1]); err != nil {
 		log.Error("Could not change directory to %s: %v", os.Args[1], err)
 	}
+	tl := &tstLog{fn:"results.txt"}
+	{{range .}}
 	cmdStr =  "./"+"{{.}}"[:len("{{.}}")-5]
-	log.Infof("Running test %s",cmdStr)
+	tl.testLogOnce("Running test suite '%s'\n", cmdStr[2:])
+
+	log.Infof("Running test suite %s",cmdStr)
 	cmd = exec.Command(cmdStr, "results.txt")
 	cmd.Stdin = os.Stdin
 	cmd.Stdout = os.Stdout
diff --git a/tests/afrouter/templates/runTests.go b/tests/afrouter/templates/runTests.go
index 3b0f6d4..2c65f09 100644
--- a/tests/afrouter/templates/runTests.go
+++ b/tests/afrouter/templates/runTests.go
@@ -18,10 +18,10 @@
 package main
 
 import (
-	"fmt"
-	"time"
 	"errors"
 	"encoding/json"
+	"golang.org/x/net/context"
+	"google.golang.org/grpc/metadata"
 	"github.com/opencord/voltha-go/common/log"
 	{{range .Imports}}
 	_ "{{.}}"
@@ -31,22 +31,40 @@
 	{{end}}
 )
 
+func resetChannels() {
+	// Drain all channels of data
+	for _,v := range servers {
+		done := false
+		for {
+			select {
+			case _ = <-v.incmg:
+			case _ = <-v.replyData:
+			default:
+				done = true
+			}
+			if done == true {
+				break
+			}
+		}
+	}
+}
+
 func runTests() {
 	{{range $k,$v := .Tests}}
 	if err := test{{$k}}(); err == nil {
-		resFile.Write([]byte("\tTest Successful\n"))
+		resFile.testLog("\tTest Successful\n")
 	} else {
-		resFile.Write([]byte("\tTest Failed\n"))
+		resFile.testLog("\tTest Failed\n")
 	}
+	resetChannels()
 	{{end}}
-	time.Sleep(5 * time.Second)
 }
 
 {{range $k,$v := .Tests}}
 func test{{$k}}() error {
 	var rtrn error = nil
 	// Announce the test being run
-	resFile.Write([]byte("******************** Running test case: {{$v.Name}}\n"))
+	resFile.testLog("******************** Running test case: {{$v.Name}}\n")
 	// Acquire the client used to run the test
 	cl := clients["{{$v.Send.Client}}"]
 	// Create the server's reply data structure
@@ -54,19 +72,36 @@
 	// Send the reply data structure to each of the servers
 	{{range $s := .Srvr}}
 	if servers["{{$s.Name}}"] == nil {
-		log.Error("Server '{{$s.Name}}' is nil")
-		return errors.New("GAAK")
+		err := errors.New("Server '{{$s.Name}}' is nil")
+		log.Error(err)
+		return err
 	}
-	servers["{{$s.Name}}"].replyData <- repl
+	select {
+	case servers["{{$s.Name}}"].replyData <- repl:
+	default:
+		err := errors.New("Could not provide server {{$s.Name}} with reply data")
+		log.Error(err)
+		return err
+	}
 	{{end}}
 
 	// Now call the RPC with the data provided
 	if expct,err := json.Marshal(repl.repl); err != nil {
 		log.Errorf("Marshaling the reply for test {{$v.Name}}: %v",err)
 	} else {
-		if err := cl.send("{{$v.Send.Method}}",
+		// Create the context for the call
+		ctx := context.Background()
+		{{range $m := $v.Send.MetaData}}
+		ctx = metadata.AppendToOutgoingContext(ctx, "{{$m.Key}}", "{{$m.Val}}")
+		{{end}}
+		var md map[string]string = make(map[string]string)
+		{{range $m := $v.Send.ExpectMeta}}
+			md["{{$m.Key}}"] = "{{$m.Val}}"
+		{{end}}
+		expectMd := metadata.New(md)
+		if err := cl.send("{{$v.Send.Method}}", ctx,
 							&{{$v.Send.ParamType}}{{$v.Send.Param}},
-							string(expct)); err != nil {
+							string(expct), expectMd); err != nil {
 			log.Errorf("Test case {{$v.Name}} failed!: %v", err)
 
 		}
@@ -83,22 +118,27 @@
 	}
 	{{range $s := .Srvr}}
 	s = servers["{{$s.Name}}"]
-	i = <-s.incmg
-	if i.payload != payload {
-		log.Errorf("Mismatched payload for test {{$v.Name}}, %s:%s", i.payload, payload)
-		resFile.Write([]byte(fmt.Sprintf("Mismatched payload expected %s, got %s\n", payload, i.payload)))
-		rtrn = errors.New("Failed")
-	}
-	{{range $m := $s.Meta}}
-	if mv,ok := i.meta["{{$m.Key}}"]; ok == true {
-		if "{{$m.Val}}" != mv[0] {
-			log.Errorf("Mismatched metadata for test {{$v.Name}}, %s:%s", mv[0], "{{$m.Val}}")
-			resFile.Write([]byte(fmt.Sprintf("Mismatched metadata on server %s expected %s, got %s\n", "{{$s.Name}}", "{{$m.Val}}", mv[0])))
+	select {
+	case i = <-s.incmg:
+		if i.payload != payload {
+			log.Errorf("Mismatched payload for test {{$v.Name}}, %s:%s", i.payload, payload)
+			resFile.testLog("Mismatched payload expected '%s', got '%s'\n", payload, i.payload)
 			rtrn = errors.New("Failed")
 		}
+		{{range $m := $s.Meta}}
+		if mv,ok := i.meta["{{$m.Key}}"]; ok == true {
+			if "{{$m.Val}}" != mv[0] {
+				log.Errorf("Mismatched metadata for test {{$v.Name}}, %s:%s", mv[0], "{{$m.Val}}")
+				resFile.testLog("Mismatched metadata on server '%s' expected '%s', got '%s'\n", "{{$s.Name}}", "{{$m.Val}}", mv[0])
+				rtrn = errors.New("Failed")
+			}
+		}
+		{{end}}
+	default:
+		err := errors.New("No response data available for server {{$s.Name}}")
+		log.Error(err)
 	}
 	{{end}}
-	{{end}}
 
 	return rtrn
 }
diff --git a/tests/afrouter/templates/server.go b/tests/afrouter/templates/server.go
index 8461d38..85c3b93 100644
--- a/tests/afrouter/templates/server.go
+++ b/tests/afrouter/templates/server.go
@@ -136,12 +136,16 @@
 	// Send the server information back to the test framework
 	ts.control.incmg <- r
 	// Read the value that needs to be returned from the channel
-	d := <-ts.control.replyData
-	switch r := d.repl.(type) {
-		case *{{.Rtrn}}:
-			return r, nil
-		default:
-			return nil, errors.New("Mismatched type in call to {{.Name}}")
+	select {
+	case d := <-ts.control.replyData:
+		switch r := d.repl.(type) {
+			case *{{.Rtrn}}:
+				return r, nil
+			default:
+				return nil, errors.New("Mismatched type in call to {{.Name}}")
+		}
+	default:
+		return nil, errors.New("Nothing in the reply data channel in call to {{.Name}}, sending nil")
 	}
 	return &{{.Rtrn}}{},nil
 }
diff --git a/tests/afrouter/tester.go b/tests/afrouter/tester.go
index e3d883c..939cc24 100644
--- a/tests/afrouter/tester.go
+++ b/tests/afrouter/tester.go
@@ -74,6 +74,8 @@
 	Method string `json:"method"`
 	Param string `json:"param"`
 	Expect string `json:"expect"`
+	MetaData []MetaD `json:"meta"`
+	ExpectMeta []MetaD `json:"expectMeta"`
 }
 
 type MetaD struct {
@@ -110,6 +112,8 @@
 	ParamType string
 	Expect string
 	ExpectType string
+	MetaData []MetaD
+	ExpectMeta []MetaD
 }
 
 type TestCase struct {
@@ -429,6 +433,12 @@
 		test.Send.ParamType = mthdMap[test.Send.Method].Param
 		test.Send.Expect = v.Send.Expect
 		test.Send.ExpectType = mthdMap[test.Send.Method].Rtrn
+		for _,v1 := range v.Send.MetaData {
+			test.Send.MetaData = append(test.Send.MetaData,v1)
+		}
+		for _,v1 := range v.Send.ExpectMeta {
+			test.Send.ExpectMeta = append(test.Send.ExpectMeta,v1)
+		}
 		for _,v1 := range v.Servers {
 			var srvr Server
 			if serverExists(v1.Name, ts) == false {