fiddle - Add some tracing and increase timeout.

Bug: skia:
Change-Id: Ib6ed48486e23f092510058d617937de203ef8533
Reviewed-on: https://skia-review.googlesource.com/c/181880
Reviewed-by: Joe Gregorio <jcgregorio@google.com>
Commit-Queue: Joe Gregorio <jcgregorio@google.com>
diff --git a/fiddlek/go/fiddle/main.go b/fiddlek/go/fiddle/main.go
index fd96ce8..eedf067 100644
--- a/fiddlek/go/fiddle/main.go
+++ b/fiddlek/go/fiddle/main.go
@@ -360,30 +360,32 @@
 		return resp, fmt.Errorf("Invalid Options: %s", err), "Invalid options."
 	}
 	sklog.Infof("Request: %#v", *req)
+	fiddleHash, err := req.Options.ComputeHash(req.Code)
+	if err != nil {
+		sklog.Infof("Failed to compute hash: %s", err)
+		return resp, fmt.Errorf("Failed to compute hash: %s", err), "Invalid request."
+	}
 
 	// The fast path returns quickly if the fiddle already exists.
 	if req.Fast {
 		sklog.Infof("Trying the fast path.")
-		if fiddleHash, err := req.Options.ComputeHash(req.Code); err == nil {
-			if _, _, err := fiddleStore.GetCode(fiddleHash); err == nil {
-				resp.FiddleHash = fiddleHash
-				if req.Options.TextOnly {
-					if b, _, _, err := fiddleStore.GetMedia(fiddleHash, store.TXT); err != nil {
-						sklog.Infof("Failed to get text: %s", err)
-					} else {
-						resp.Text = string(b)
-						return resp, nil, ""
-					}
+		if _, _, err := fiddleStore.GetCode(fiddleHash); err == nil {
+			resp.FiddleHash = fiddleHash
+			if req.Options.TextOnly {
+				if b, _, _, err := fiddleStore.GetMedia(fiddleHash, store.TXT); err != nil {
+					sklog.Infof("Failed to get text: %s", err)
 				} else {
+					resp.Text = string(b)
 					return resp, nil, ""
 				}
 			} else {
-				sklog.Infof("Failed to match hash: %s", err)
+				return resp, nil, ""
 			}
 		} else {
-			sklog.Infof("Failed to compute hash: %s", err)
+			sklog.Infof("Failed to match hash: %s", err)
 		}
 	}
+	req.Hash = fiddleHash
 
 	res, err := run.Run(*local, req)
 	if err != nil {
@@ -391,7 +393,7 @@
 	}
 	maybeSecViolation := false
 	if res.Execute.Errors != "" {
-		sklog.Infof("Execution errors: %q", res.Execute.Errors)
+		sklog.Infof("%q Execution errors: %q", req.Hash, res.Execute.Errors)
 		maybeSecViolation = true
 		resp.RunTimeError = fmt.Sprintf("Failed to run, possibly violated security container: %q", res.Execute.Errors)
 	}
@@ -418,12 +420,12 @@
 			}
 			line_num, err := strconv.Atoi(match[0][3])
 			if err != nil {
-				sklog.Errorf("Failed to parse compiler output line number: %#v: %s", match, err)
+				sklog.Errorf("%q Failed to parse compiler output line number: %#v: %s", req.Hash, match, err)
 				continue
 			}
 			col_num, err := strconv.Atoi(match[0][4])
 			if err != nil {
-				sklog.Errorf("Failed to parse compiler output column number: %#v: %s", match, err)
+				sklog.Errorf("%q Failed to parse compiler output column number: %#v: %s", req.Hash, match, err)
 				continue
 			}
 			resp.CompileErrors = append(resp.CompileErrors, types.CompileError{
@@ -437,7 +439,7 @@
 	if res.Compile.Errors != "" || res.Execute.Errors != "" {
 		res = nil
 	}
-	fiddleHash := ""
+	fiddleHash = ""
 	// Store the fiddle, but only if we are not in Fast mode and errors occurred.
 	if !(res == nil && req.Fast) {
 		fiddleHash, err = fiddleStore.Put(req.Code, req.Options, res)
diff --git a/fiddlek/go/fiddler/main.go b/fiddlek/go/fiddler/main.go
index fab7a76..8e69494 100644
--- a/fiddlek/go/fiddler/main.go
+++ b/fiddlek/go/fiddler/main.go
@@ -311,7 +311,7 @@
 		InheritEnv:  true,
 		Stdout:      &stdout,
 		Stderr:      &stderr,
-		Timeout:     20 * time.Second,
+		Timeout:     30 * time.Second,
 	}
 	if err := exec.Run(ctx, runCmd); err != nil {
 		sklog.Errorf("Failed to run: %s", err)
diff --git a/fiddlek/go/runner/runner.go b/fiddlek/go/runner/runner.go
index cca141d..7158927 100644
--- a/fiddlek/go/runner/runner.go
+++ b/fiddlek/go/runner/runner.go
@@ -255,7 +255,7 @@
 	reqToSend := *req
 	reqToSend.Code = r.prepCodeToCompile(req.Code, &req.Options)
 	runTotal.Inc(1)
-	sklog.Infof("Sending: %q", reqToSend.Code)
+	sklog.Infof("%q Sending: %q", req.Hash, reqToSend.Code)
 
 	b, err := json.Marshal(reqToSend)
 	if err != nil {
@@ -273,11 +273,11 @@
 			ips := r.randPodIPs()
 			for _, p := range ips {
 				rootURL := fmt.Sprintf("http://%s:8000", p)
-				sklog.Infof("Trying: %q", rootURL)
+				sklog.Infof("%q Trying: %q", req.Hash, rootURL)
 				// Run the fiddle in the open pod.
 				ret, err := r.singleRun(rootURL+"/run", bytes.NewReader(b))
 				if err == alreadyRunningFiddleErr || err == failedToSendErr {
-					sklog.Warningf("Couldn't run on pod: %s", err)
+					sklog.Warningf("%q Couldn't run on pod: %s", req.Hash, err)
 					continue
 				} else {
 					return ret, err
@@ -287,7 +287,7 @@
 			time.Sleep((1 << uint64(tries)) * time.Second)
 		}
 		runExhaustion.Inc(1)
-		return nil, fmt.Errorf("Failed to find an available server to run the fiddle.")
+		return nil, fmt.Errorf("%q Failed to find an available server to run the fiddle.", req.Hash)
 	}
 }