From 27ca55372aa0bfe923dce495c0280c487e7848c6 Mon Sep 17 00:00:00 2001
From: Diaa Sami <disami@redhat.com>
Date: Wed, 22 Sep 2021 17:39:53 +0200
Subject: [PATCH] cloudapi: Add extra logging & improve existing

Use different logging levels depending on situation
Log HTTP 5xx errors to stdout with internal error details when possible
---
 internal/cloudapi/v2/errors.go | 10 +++++++++-
 internal/cloudapi/v2/v2.go     | 14 ++++++++------
 2 files changed, 17 insertions(+), 7 deletions(-)

diff --git a/internal/cloudapi/v2/errors.go b/internal/cloudapi/v2/errors.go
index 9787fe677..a49af714e 100644
--- a/internal/cloudapi/v2/errors.go
+++ b/internal/cloudapi/v2/errors.go
@@ -219,7 +219,14 @@ func (s *Server) HTTPErrorHandler(echoError error, c echo.Context) {
 			apiErr := APIError(code, sec, c)
 
 			if sec.httpStatus == http.StatusInternalServerError {
-				c.Logger().Errorf("Internal server error. Code: %s, OperationId: %s", apiErr.Code, apiErr.OperationId)
+				internalError, ok := echoError.(*echo.HTTPError)
+				errMsg := fmt.Sprintf("Internal server error. Code: %s, OperationId: %s", apiErr.Code, apiErr.OperationId)
+
+				if ok {
+					errMsg += fmt.Sprintf(", InternalError: %v", internalError)
+				}
+
+				c.Logger().Error(errMsg)
 			}
 
 			if c.Request().Method == http.MethodHead {
@@ -237,6 +244,7 @@ func (s *Server) HTTPErrorHandler(echoError error, c echo.Context) {
 
 	he, ok := echoError.(*echo.HTTPError)
 	if !ok {
+		c.Logger().Errorf("ErrorNotHTTPError %v", echoError)
 		doResponse(ErrorNotHTTPError, c)
 		return
 	}
diff --git a/internal/cloudapi/v2/v2.go b/internal/cloudapi/v2/v2.go
index 2fc618ee4..a395835a1 100644
--- a/internal/cloudapi/v2/v2.go
+++ b/internal/cloudapi/v2/v2.go
@@ -147,7 +147,7 @@ func (h *apiHandlers) PostCompose(ctx echo.Context) error {
 	var bp = blueprint.Blueprint{}
 	err = bp.Initialize()
 	if err != nil {
-		return HTTPError(ErrorFailedToInitializeBlueprint)
+		return HTTPErrorWithInternal(ErrorFailedToInitializeBlueprint, err)
 	}
 	if request.Customizations != nil && request.Customizations.Packages != nil {
 		for _, p := range *request.Customizations.Packages {
@@ -235,7 +235,7 @@ func (h *apiHandlers) PostCompose(ctx echo.Context) error {
 			imageOptions.OSTree.URL = *ostreeOptions.Url
 			parent, err = ostree.ResolveRef(imageOptions.OSTree.URL, imageOptions.OSTree.Ref)
 			if err != nil {
-				return HTTPError(ErrorInvalidOSTreeRepo)
+				return HTTPErrorWithInternal(ErrorInvalidOSTreeRepo, err)
 			}
 			imageOptions.OSTree.Parent = parent
 		}
@@ -266,7 +266,7 @@ func (h *apiHandlers) PostCompose(ctx echo.Context) error {
 
 		manifest, err := imageType.Manifest(blueprintCustoms, imageOptions, repositories, pkgSpecSets, manifestSeed)
 		if err != nil {
-			return HTTPError(ErrorFailedToMakeManifest)
+			return HTTPErrorWithInternal(ErrorFailedToMakeManifest, err)
 		}
 
 		imageRequests[i].manifest = manifest
@@ -411,9 +411,11 @@ func (h *apiHandlers) PostCompose(ctx echo.Context) error {
 		Exports:  ir.exports,
 	})
 	if err != nil {
-		return HTTPError(ErrorEnqueueingJob)
+		return HTTPErrorWithInternal(ErrorEnqueueingJob, err)
 	}
 
+	ctx.Logger().Infof("Job ID %s enqueued for operationID %s", id, ctx.Get("operationID"))
+
 	return ctx.JSON(http.StatusCreated, &ComposeId{
 		ObjectReference: ObjectReference{
 			Href: "/api/composer/v2/compose",
@@ -530,12 +532,12 @@ func (h *apiHandlers) GetComposeMetadata(ctx echo.Context, id string) error {
 	var result worker.OSBuildJobResult
 	status, _, err := h.server.workers.JobStatus(jobId, &result)
 	if err != nil {
-		return HTTPError(ErrorComposeNotFound)
+		return HTTPErrorWithInternal(ErrorComposeNotFound, err)
 	}
 
 	var job worker.OSBuildJob
 	if _, _, _, err = h.server.workers.Job(jobId, &job); err != nil {
-		return HTTPError(ErrorComposeNotFound)
+		return HTTPErrorWithInternal(ErrorComposeNotFound, err)
 	}
 
 	if status.Finished.IsZero() {