[Issue 423] build logs not saved on build error (#426)

* Fix builder return empty buildlogs when encounters errors

* Append error logs to build logs

* Builder manager updates package with build logs plus error log

* Fix potential nil pointer bug

* Replace numeric status code with built-in const

* Remove no use parameter

* Fix go fmt

builder/builder.go

@@ -21,18 +21,18 @@ import (
 	"encoding/json"
 	"errors"
 	"fmt"
+	"io"
 	"io/ioutil"
 	"log"
 	"net/http"
 	"os"
 	"os/exec"
+	"path"
 	"path/filepath"
 	"strings"
 	"time"
 
 	"github.com/dchest/uniuri"
-	"io"
-	"path"
 )
 
 const (
@@ -70,7 +70,9 @@ func MakeBuilder(sharedVolumePath string) *Builder {
 
 func (builder *Builder) Handler(w http.ResponseWriter, r *http.Request) {
 	if r.Method != "POST" {
-		http.Error(w, "", 405)
+		e := fmt.Sprintf("Method not allowed: %v", r.Method)
+		log.Println(e)
+		builder.reply(w, "", e, http.StatusMethodNotAllowed)
 		return
 	}
 
@@ -83,15 +85,17 @@ func (builder *Builder) Handler(w http.ResponseWriter, r *http.Request) {
 	// parse request
 	body, err := ioutil.ReadAll(r.Body)
 	if err != nil {
-		log.Printf("Error reading request body")
+		e := errors.New(fmt.Sprintf("Error reading request body: %v", err))
-		http.Error(w, err.Error(), 500)
+		log.Println(e.Error())
+		builder.reply(w, "", e.Error(), http.StatusInternalServerError)
 		return
 	}
 	var req PackageBuildRequest
 	err = json.Unmarshal(body, &req)
 	if err != nil {
-		log.Printf("Error parsing json body: %v", err)
+		e := errors.New(fmt.Sprintf("Error parsing json body: %v", err))
-		http.Error(w, err.Error(), 400)
+		log.Println(e.Error())
+		builder.reply(w, "", e.Error(), http.StatusBadRequest)
 		return
 	}
 	log.Printf("Builder received request: %v", req)
@@ -108,25 +112,34 @@ func (builder *Builder) Handler(w http.ResponseWriter, r *http.Request) {
 	buildLogs, err := builder.build(buildCmd, srcPkgPath, deployPkgPath)
 	if err != nil {
 		e := errors.New(fmt.Sprintf("Error building source package: %v", err))
-		http.Error(w, e.Error(), 500)
+		log.Println(e.Error())
+		// append error at the end of build logs
+		buildLogs += fmt.Sprintf("%v\n", e.Error())
+		builder.reply(w, deployPkgFilename, buildLogs, http.StatusInternalServerError)
 		return
 	}
 
+	builder.reply(w, deployPkgFilename, buildLogs, http.StatusOK)
+}
+
+func (builder *Builder) reply(w http.ResponseWriter, pkgFilename string, buildLogs string, statusCode int) {
 	resp := PackageBuildResponse{
-		ArtifactFilename: deployPkgFilename,
+		ArtifactFilename: pkgFilename,
 		BuildLogs:        buildLogs,
 	}
 
 	rBody, err := json.Marshal(resp)
 	if err != nil {
 		e := errors.New(fmt.Sprintf("Error encoding response body: %v", err))
-		http.Error(w, e.Error(), 500)
+		rBody = []byte(fmt.Sprintf(`{"buildLogs": "%v"}`, e.Error()))
-		return
+		statusCode = http.StatusInternalServerError
 	}
 
 	w.Header().Add("Content-Type", "application/json")
+	// should write header before writing the body,
+	// or client will receive HTTP 200 regardless the real status code
+	w.WriteHeader(statusCode)
 	w.Write(rBody)
-	w.WriteHeader(http.StatusOK)
 }
 
 func (builder *Builder) build(command string, srcPkgPath string, deployPkgPath string) (string, error) {
@@ -183,14 +196,14 @@ func (builder *Builder) build(command string, srcPkgPath string, deployPkgPath s
 	if err := scanner.Err(); err != nil {
 		scanErr := errors.New(fmt.Sprintf("Error reading cmd output: %v", err.Error()))
 		fmt.Println(scanErr)
-		return "", scanErr
+		return buildLogs, scanErr
 	}
 
 	err = cmd.Wait()
 	if err != nil {
 		cmdErr := errors.New(fmt.Sprintf("Error waiting for cmd '%v': %v", command, err.Error()))
 		fmt.Println(cmdErr)
-		return "", cmdErr
+		return buildLogs, cmdErr
 	}
 	fmt.Println("==================\n")
 

builder/client/client.go

@@ -20,6 +20,7 @@ import (
 	"bytes"
 	"encoding/json"
 	"io/ioutil"
+	"log"
 	"net/http"
 	"strings"
 
@@ -50,20 +51,18 @@ func (c *Client) Build(req *builder.PackageBuildRequest) (*builder.PackageBuildR
 	}
 	defer resp.Body.Close()
 
-	if resp.StatusCode != 200 {
-		return nil, fission.MakeErrorFromHTTP(resp)
-	}
-
 	rBody, err := ioutil.ReadAll(resp.Body)
 	if err != nil {
+		log.Printf("Error reading resp body: %v", err)
 		return nil, err
 	}
 
 	pkgBuildResp := builder.PackageBuildResponse{}
 	err = json.Unmarshal([]byte(rBody), &pkgBuildResp)
 	if err != nil {
+		log.Printf("Error parsing resp body: %v", err)
 		return nil, err
 	}
 
-	return &pkgBuildResp, nil
+	return &pkgBuildResp, fission.MakeErrorFromHTTP(resp)
 }

buildermgr/api.go

@@ -39,10 +39,9 @@ type (
 	}
 
 	BuilderMgr struct {
-		fissionClient    *crd.FissionClient
+		fissionClient *crd.FissionClient
-		kubernetesClient *kubernetes.Clientset
+		storageSvcUrl string
-		storageSvcUrl    string
+		namespace     string
-		namespace        string
 	}
 )
 
@@ -53,14 +52,13 @@ func MakeBuilderMgr(fissionClient *crd.FissionClient,
 	envWatcher := makeEnvironmentWatcher(fissionClient, kubernetesClient, envBuilderNamespace)
 	go envWatcher.watchEnvironments()
 
-	pkgWatcher := makePackageWatcher(fissionClient, kubernetesClient, envBuilderNamespace, storageSvcUrl)
+	pkgWatcher := makePackageWatcher(fissionClient, envBuilderNamespace, storageSvcUrl)
 	go pkgWatcher.watchPackages()
 
 	return &BuilderMgr{
-		fissionClient:    fissionClient,
+		fissionClient: fissionClient,
-		kubernetesClient: kubernetesClient,
+		storageSvcUrl: storageSvcUrl,
-		storageSvcUrl:    storageSvcUrl,
+		namespace:     envBuilderNamespace,
-		namespace:        envBuilderNamespace,
 	}
 }
 
@@ -76,14 +74,23 @@ func (builderMgr *BuilderMgr) build(w http.ResponseWriter, r *http.Request) {
 	buildReq := BuildRequest{}
 	err = json.Unmarshal([]byte(body), &buildReq)
 	if err != nil {
-		e := fmt.Sprintf("invalid request body: %v", err)
+		e := fmt.Sprintf("Invalid request body: %v", err)
 		log.Println(e)
 		http.Error(w, e, 400)
 		return
 	}
 
-	buildLogs, err := buildPackage(builderMgr.fissionClient, builderMgr.kubernetesClient,
+	pkg, err := builderMgr.fissionClient.
-		builderMgr.namespace, builderMgr.storageSvcUrl, buildReq)
+		Packages(buildReq.Package.Namespace).
+		Get(buildReq.Package.Name)
+	if err != nil {
+		e := fmt.Sprintf("Error getting package CRD info: %v", err)
+		log.Println(e)
+		http.Error(w, e, 500)
+		return
+	}
+
+	buildLogs, err := buildPackage(builderMgr.fissionClient, builderMgr.namespace, builderMgr.storageSvcUrl, pkg)
 	if err != nil {
 		code, e := fission.GetHTTPError(err)
 		http.Error(w, e, code)

buildermgr/common.go

@@ -19,10 +19,10 @@ package buildermgr
 import (
 	"fmt"
 	"log"
+	"net/http"
 	"strings"
 
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
-	"k8s.io/client-go/kubernetes"
 
 	"github.com/dchest/uniuri"
 	"github.com/fission/fission"
@@ -43,24 +43,14 @@ import (
 // 6. Update package status to succeed state
 // 7. Update package resource in package ref of functions that share the same package
 // *. Update package status to failed state,if any one of steps above failed
-func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes.Clientset,
+func buildPackage(fissionClient *crd.FissionClient, builderNamespace string,
-	builderNamespace string, storageSvcUrl string, buildReq BuildRequest) (buildLogs string, err error) {
+	storageSvcUrl string, pkg *crd.Package) (buildLogs string, err error) {
-
-	pkg, err := fissionClient.
-		Packages(buildReq.Package.Namespace).
-		Get(buildReq.Package.Name)
-	if err != nil {
-		e := fmt.Sprintf("Error getting function CRD info: %v", err)
-		log.Println(e)
-		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
-		return e, fission.MakeError(500, e)
-	}
 
 	// Only do build for pending packages
 	if pkg.Status.BuildStatus != fission.BuildStatusPending {
 		e := "package is not in pending state"
 		log.Println(e)
-		return e, fission.MakeError(400, e)
+		return e, fission.MakeError(http.StatusBadRequest, e)
 	}
 
 	// update package status to running state, so that
@@ -77,7 +67,7 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 		e := fmt.Sprintf("Error setting package pending state: %v", err)
 		log.Println(e)
 		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
-		return e, fission.MakeError(500, e)
+		return e, fission.MakeError(http.StatusInternalServerError, e)
 	}
 
 	env, err := fissionClient.Environments(metav1.NamespaceDefault).Get(pkg.Spec.Environment.Name)
@@ -85,7 +75,7 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 		e := fmt.Sprintf("Error getting environment CRD info: %v", err)
 		log.Println(e)
 		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
-		return e, fission.MakeError(500, e)
+		return e, fission.MakeError(http.StatusInternalServerError, e)
 	}
 
 	svcName := fmt.Sprintf("%v-%v.%v", env.Metadata.Name, env.Metadata.ResourceVersion, builderNamespace)
@@ -105,7 +95,7 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 		e := fmt.Sprintf("Error fetching source package: %v", err)
 		log.Println(e)
 		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
-		return e, fission.MakeError(500, e)
+		return e, fission.MakeError(http.StatusInternalServerError, e)
 	}
 
 	buildCmd := pkg.Spec.BuildCommand
@@ -124,8 +114,13 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 	if err != nil {
 		e := fmt.Sprintf("Error building deployment package: %v", err)
 		log.Println(e)
-		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
+		var buildLogs string
-		return e, fission.MakeError(500, e)
+		if buildResp != nil {
+			buildLogs = buildResp.BuildLogs
+		}
+		buildLogs += fmt.Sprintf("%v\n", e)
+		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, buildLogs, nil)
+		return e, fission.MakeError(http.StatusInternalServerError, e)
 	}
 
 	log.Printf("Build succeed, source package: %v, deployment package: %v", srcPkgFilename, buildResp.ArtifactFilename)
@@ -141,8 +136,9 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 	if err != nil {
 		e := fmt.Sprintf("Error uploading deployment package: %v", err)
 		log.Println(e)
-		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
+		buildResp.BuildLogs += fmt.Sprintf("%v\n", e)
-		return e, fission.MakeError(500, e)
+		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, buildResp.BuildLogs, nil)
+		return e, fission.MakeError(http.StatusInternalServerError, e)
 	}
 
 	log.Printf("Start updating info of package: %v", pkg.Metadata.Name)
@@ -153,8 +149,9 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 	if err != nil {
 		e := fmt.Sprintf("Error creating deployment package CRD resource: %v", err)
 		log.Println(e)
-		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
+		buildResp.BuildLogs += fmt.Sprintf("%v\n", e)
-		return e, fission.MakeError(500, e)
+		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, buildResp.BuildLogs, nil)
+		return e, fission.MakeError(http.StatusInternalServerError, e)
 	}
 
 	fnList, err := fissionClient.
@@ -162,8 +159,9 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 	if err != nil {
 		e := fmt.Sprintf("Error getting function list: %v", err)
 		log.Println(e)
-		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
+		buildResp.BuildLogs += fmt.Sprintf("%v\n", e)
-		return e, fission.MakeError(500, e)
+		updatePackage(fissionClient, pkg, fission.BuildStatusFailed, buildResp.BuildLogs, nil)
+		return e, fission.MakeError(http.StatusInternalServerError, e)
 	}
 
 	// A package may be used by multiple functions. Update
@@ -178,8 +176,9 @@ func buildPackage(fissionClient *crd.FissionClient, kubernetesClient *kubernetes
 			if err != nil {
 				e := fmt.Sprintf("Error updating function package resource version: %v", err)
 				log.Println(e)
-				updatePackage(fissionClient, pkg, fission.BuildStatusFailed, e, nil)
+				buildResp.BuildLogs += fmt.Sprintf("%v\n", e)
-				return e, fission.MakeError(500, e)
+				updatePackage(fissionClient, pkg, fission.BuildStatusFailed, buildResp.BuildLogs, nil)
+				return e, fission.MakeError(http.StatusInternalServerError, e)
 			}
 		}
 	}

buildermgr/pkgwatcher.go

@@ -22,7 +22,6 @@ import (
 
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/watch"
-	"k8s.io/client-go/kubernetes"
 
 	"github.com/fission/fission"
 	"github.com/fission/fission/crd"
@@ -31,31 +30,25 @@ import (
 type (
 	packageWatcher struct {
 		fissionClient    *crd.FissionClient
-		kubernetesClient *kubernetes.Clientset
 		builderNamespace string
 		storageSvcUrl    string
 	}
 )
 
 func makePackageWatcher(fissionClient *crd.FissionClient,
-	kubernetesClient *kubernetes.Clientset, builderNamespace string, storageSvcUrl string) *packageWatcher {
+	builderNamespace string, storageSvcUrl string) *packageWatcher {
 	pkgw := &packageWatcher{
 		fissionClient:    fissionClient,
-		kubernetesClient: kubernetesClient,
 		builderNamespace: builderNamespace,
 		storageSvcUrl:    storageSvcUrl,
 	}
 	return pkgw
 }
 
-func (pkgw *packageWatcher) build(pkgMetadata metav1.ObjectMeta) {
+func (pkgw *packageWatcher) build(pkg *crd.Package) {
-	buildReq := BuildRequest{
+	_, err := buildPackage(pkgw.fissionClient, pkgw.builderNamespace, pkgw.storageSvcUrl, pkg)
-		Package: pkgMetadata,
-	}
-	_, err := buildPackage(pkgw.fissionClient,
-		pkgw.kubernetesClient, pkgw.builderNamespace, pkgw.storageSvcUrl, buildReq)
 	if err != nil {
-		log.Printf("Error building package %v: %v", buildReq.Package.Name, err)
+		log.Printf("Error building package %v: %v", pkg.Metadata.Name, err)
 	}
 }
 
@@ -84,7 +77,7 @@ func (pkgw *packageWatcher) watchPackages() {
 
 			// only do build for packages in pending state
 			if pkg.Status.BuildStatus == fission.BuildStatusPending {
-				go pkgw.build(pkg.Metadata)
+				go pkgw.build(pkg)
 			}
 		}
 	}