Improve the error handling of whatsapp

ref DEV-2416

pkg/api/apierrors/skip_logging.go

@@ -84,5 +84,12 @@ func IgnoreError(err error) (ignore bool) {
 		}
 	}
 
+	var skippable log.LoggingSkippable
+	if errors.As(err, &skippable) {
+		if skippable.SkipLogging() {
+			ignore = true
+		}
+	}
+
 	return
 }

pkg/lib/infra/whatsapp/errors.go

@@ -1,9 +1,13 @@
 package whatsapp
 
 import (
+	"encoding/json"
 	"errors"
+	"fmt"
 
 	"github.com/authgear/authgear-server/pkg/api/apierrors"
+	"github.com/authgear/authgear-server/pkg/lib/config"
+	"github.com/authgear/authgear-server/pkg/util/log"
 )
 
 var ErrInvalidWhatsappUser = apierrors.BadRequest.
@@ -16,3 +20,37 @@ var ErrNoAvailableWhatsappClient = apierrors.BadRequest.
 var ErrUnauthorized = errors.New("whatsapp: unauthorized")
 var ErrBadRequest = errors.New("whatsapp: bad request")
 var ErrUnexpectedLoginResponse = errors.New("whatsapp: unexpected login response body")
+
+type WhatsappAPIError struct {
+	APIType        config.WhatsappAPIType    `json:"api_type,omitempty"`
+	HTTPStatusCode int                       `json:"http_status_code,omitempty"`
+	DumpedResponse []byte                    `json:"dumped_response,omitempty"`
+	ParsedResponse *WhatsappAPIErrorResponse `json:"-"`
+}
+
+var _ error = &WhatsappAPIError{}
+
+func (e *WhatsappAPIError) Error() string {
+	jsonText, _ := json.Marshal(e)
+	return fmt.Sprintf("whatsapp api error: %s", string(jsonText))
+}
+
+var _ log.LoggingSkippable = &WhatsappAPIError{}
+
+func (e *WhatsappAPIError) SkipLogging() bool {
+	switch e.HTTPStatusCode {
+	case 401:
+		return true
+	default:
+		if e.ParsedResponse != nil {
+			if firstErrorCode, ok := e.ParsedResponse.FirstErrorCode(); ok {
+				switch firstErrorCode {
+				case errorCodeInvalidUser:
+					return true
+				}
+			}
+		}
+
+	}
+	return false
+}

pkg/lib/infra/whatsapp/models.go

@@ -128,12 +128,23 @@ func (j LoginResponseUserExpiresTime) MarshalText() ([]byte, error) {
 	return []byte(time.Time(j).Format(LoginResponseUserExpiresTimeLayout)), nil
 }
 
-type SendTemplateErrorResponse struct {
-	Errors *[]SendTemplateError `json:"errors,omitempty"`
+type WhatsappAPIErrorResponse struct {
+	Errors []WhatsappAPIErrorDetail `json:"errors,omitempty"`
 }
 
-type SendTemplateError struct {
+func (r *WhatsappAPIErrorResponse) FirstErrorCode() (int, bool) {
+	if r.Errors != nil && len(r.Errors) > 0 {
+		return (r.Errors)[0].Code, true
+	}
+	return -1, false
+}
+
+type WhatsappAPIErrorDetail struct {
 	Code    int    `json:"code"`
 	Title   string `json:"title"`
 	Details string `json:"details"`
 }
+
+const (
+	errorCodeInvalidUser = 1013
+)

pkg/lib/infra/whatsapp/on_premises.go

@@ -11,8 +11,11 @@ import (
 	"net/url"
 	"time"
 
+	nethttputil "net/http/httputil"
+
 	"github.com/authgear/authgear-server/pkg/lib/config"
 	"github.com/authgear/authgear-server/pkg/util/httputil"
+	"github.com/authgear/authgear-server/pkg/util/log"
 )
 
 type HTTPClient struct {
@@ -25,14 +28,22 @@ func NewHTTPClient() HTTPClient {
 	}
 }
 
+type WhatsappOnPremisesClientLogger struct{ *log.Logger }
+
+func NewWhatsappOnPremisesClientLogger(lf *log.Factory) WhatsappOnPremisesClientLogger {
+	return WhatsappOnPremisesClientLogger{lf.New("whatsapp-on-premises-client")}
+}
+
 type OnPremisesClient struct {
+	Logger      WhatsappOnPremisesClientLogger
 	HTTPClient  HTTPClient
 	Endpoint    *url.URL
 	Credentials *config.WhatsappOnPremisesCredentials
 	TokenStore  *TokenStore
 }
 
 func NewWhatsappOnPremisesClient(
+	lf *log.Factory,
 	cfg *config.WhatsappConfig,
 	credentials *config.WhatsappOnPremisesCredentials,
 	tokenStore *TokenStore,
@@ -46,6 +57,7 @@ func NewWhatsappOnPremisesClient(
 		panic(err)
 	}
 	return &OnPremisesClient{
+		Logger:      WhatsappOnPremisesClientLogger{lf.New("whatsapp-on-premises-client")},
 		HTTPClient:  httpClient,
 		Endpoint:    endpoint,
 		Credentials: credentials,
@@ -142,32 +154,64 @@ func (c *OnPremisesClient) sendTemplate(
 	}
 	defer resp.Body.Close()
 
-	if resp.StatusCode == 401 {
-		return ErrUnauthorized
+	if resp.StatusCode >= 200 && resp.StatusCode < 300 {
+		// 2xx means success
+		// https://developers.facebook.com/docs/whatsapp/on-premises/errors#http
+		return nil
 	}
 
-	if resp.StatusCode == 400 {
-		return c.parseBadRequestError(resp)
+	whatsappAPIErr := &WhatsappAPIError{
+		APIType:        config.WhatsappAPITypeOnPremises,
+		HTTPStatusCode: resp.StatusCode,
 	}
 
-	if resp.StatusCode < 200 || resp.StatusCode >= 300 {
-		return fmt.Errorf("whatsapp: unexpected response status %d", resp.StatusCode)
+	dumpedResponse, dumpResponseErr := nethttputil.DumpResponse(resp, true)
+	if dumpResponseErr != nil {
+		c.Logger.WithError(dumpResponseErr).Warn("failed to dump response")
+	} else {
+		whatsappAPIErr.DumpedResponse = dumpedResponse
 	}
+	// The dump error is not part of the api error, ignore it
 
-	return nil
-}
+	errResp, err := c.tryParseErrorResponse(resp)
+	if err != nil {
+		return errors.Join(err, whatsappAPIErr)
+	} else {
+		whatsappAPIErr.ParsedResponse = errResp
+	}
 
-func (c *OnPremisesClient) parseBadRequestError(resp *http.Response) error {
-	var errResp SendTemplateErrorResponse
-	if err := json.NewDecoder(resp.Body).Decode(&errResp); err == nil {
-		if errResp.Errors != nil && len(*errResp.Errors) > 0 {
-			switch (*errResp.Errors)[0].Code {
-			case 1013:
-				return ErrInvalidWhatsappUser
+	if resp.StatusCode == 401 {
+		return errors.Join(ErrUnauthorized, whatsappAPIErr)
+	}
+
+	if errResp != nil {
+		if firstErrorCode, ok := errResp.FirstErrorCode(); ok {
+			switch firstErrorCode {
+			case errorCodeInvalidUser:
+				return errors.Join(ErrInvalidWhatsappUser, whatsappAPIErr)
 			}
 		}
 	}
-	return ErrBadRequest
+
+	return whatsappAPIErr
+}
+
+func (c *OnPremisesClient) tryParseErrorResponse(resp *http.Response) (*WhatsappAPIErrorResponse, error) {
+	respBody, err := io.ReadAll(resp.Body)
+	if err != nil {
+		// If we failed to read the response body, it is an error
+		return nil, err
+	}
+
+	var errResp WhatsappAPIErrorResponse
+	parseErr := json.Unmarshal(respBody, &errResp)
+	// The api could return other errors in format we don't understand, so non-nil parseErr is expected.
+	// Just return nil in this case.
+	if parseErr != nil {
+		c.Logger.WithError(parseErr).Warn("failed to parse error response")
+		return nil, nil
+	}
+	return &errResp, nil
 }
 
 func (c *OnPremisesClient) login(ctx context.Context) (*UserToken, error) {
@@ -178,29 +222,46 @@ func (c *OnPremisesClient) login(ctx context.Context) (*UserToken, error) {
 	}
 	req.SetBasicAuth(c.Credentials.Username, c.Credentials.Password)
 
+	whatsappAPIErr := &WhatsappAPIError{
+		APIType: config.WhatsappAPITypeOnPremises,
+	}
+
 	resp, err := c.HTTPClient.Do(req)
 	if err != nil {
-		return nil, err
+		return nil, errors.Join(err, whatsappAPIErr)
 	}
 	defer resp.Body.Close()
+	whatsappAPIErr.HTTPStatusCode = resp.StatusCode
+
+	dumpedResponse, err := nethttputil.DumpResponse(resp, true)
+	if err != nil {
+		return nil, errors.Join(err, whatsappAPIErr)
+	}
+	whatsappAPIErr.DumpedResponse = dumpedResponse
 
 	if resp.StatusCode < 200 || resp.StatusCode >= 300 {
-		return nil, fmt.Errorf("whatsapp: unexpected response status %d", resp.StatusCode)
+		// It was observed that when status code is 401, the body is empty.
+		// Thus parse error should be ignored.
+		errResp, parseErr := c.tryParseErrorResponse(resp)
+		if parseErr == nil {
+			whatsappAPIErr.ParsedResponse = errResp
+		}
+		return nil, whatsappAPIErr
 	}
 
 	loginHTTPResponseBytes, err := io.ReadAll(resp.Body)
 	if err != nil {
-		return nil, err
+		return nil, errors.Join(err, whatsappAPIErr)
 	}
 
 	var loginResponse LoginResponse
 	err = json.Unmarshal(loginHTTPResponseBytes, &loginResponse)
 	if err != nil {
-		return nil, err
+		return nil, errors.Join(err, whatsappAPIErr)
 	}
 
 	if len(loginResponse.Users) < 1 {
-		return nil, ErrUnexpectedLoginResponse
+		return nil, errors.Join(ErrUnexpectedLoginResponse, whatsappAPIErr)
 	}
 
 	return &UserToken{

pkg/lib/messaging/sender.go

@@ -298,26 +298,29 @@ func (s *Sender) SendWhatsappImmediately(ctx context.Context, msgType translatio
 	// Send immediately.
 	err = s.sendWhatsapp(ctx, opts)
 	if err != nil {
-		isInvalidWhatsappUserErr := errors.Is(err, whatsapp.ErrInvalidWhatsappUser)
-		status := otelauthgear.WithStatusError()
-		if isInvalidWhatsappUserErr {
-			status = otelauthgear.WithStatusInvalidWhatsappUser()
+
+		metricOptions := []otelauthgear.MetricOption{otelauthgear.WithStatusError()}
+		var apiErr *whatsapp.WhatsappAPIError
+		if ok := errors.As(err, &apiErr); ok {
+			metricOptions = append(metricOptions, otelauthgear.WithWhatsappAPIType(apiErr.APIType))
+			metricOptions = append(metricOptions, otelauthgear.WithHTTPStatusCode(apiErr.HTTPStatusCode))
+			if apiErr.ParsedResponse != nil {
+				firstErr, ok := apiErr.ParsedResponse.FirstErrorCode()
+				if ok {
+					metricOptions = append(metricOptions, otelauthgear.WithWhatsappAPIErrorCode(firstErr))
+				}
+			}
 		}
+
 		otelauthgear.IntCounterAddOne(
 			ctx,
 			otelauthgear.CounterWhatsappRequestCount,
-			status,
+			metricOptions...,
 		)
 
-		if !isInvalidWhatsappUserErr {
-			s.Logger.WithError(err).WithFields(logrus.Fields{
-				"phone": phone.Mask(opts.To),
-			}).Error("failed to send Whatsapp")
-		} else {
-			s.Logger.WithError(err).WithFields(logrus.Fields{
-				"phone": phone.Mask(opts.To),
-			}).Warn("failed to send Whatsapp")
-		}
+		s.Logger.WithError(err).WithFields(logrus.Fields{
+			"phone": phone.Mask(opts.To),
+		}).Error("failed to send Whatsapp")
 
 		logErr := s.Events.DispatchEventImmediately(ctx, &nonblocking.WhatsappErrorEventPayload{
 			Description: s.errorToDescription(err),

pkg/lib/otelauthgear/metric.go

@@ -2,10 +2,14 @@ package otelauthgear
 
 import (
 	"context"
+	"fmt"
 
 	"go.opentelemetry.io/otel"
 	"go.opentelemetry.io/otel/attribute"
 	"go.opentelemetry.io/otel/metric"
+	"go.opentelemetry.io/otel/semconv/v1.27.0"
+
+	"github.com/authgear/authgear-server/pkg/lib/config"
 )
 
 // Suppose you have a task to add a new metric, what should you do?
@@ -70,15 +74,18 @@ var AttributeKeyClientID = attribute.Key("authgear.client_id")
 // AttributeKeyStatus defines the attribute.
 var AttributeKeyStatus = attribute.Key("status")
 
+// AttributeKeyWhatsappAPIType defines the attribute.
+var AttributeKeyWhatsappAPIType = attribute.Key("whatsapp_api_type")
+
+// AttributeKeyWhatsappAPIErrorCode defines the attribute.
+var AttributeKeyWhatsappAPIErrorCode = attribute.Key("whatsapp_api_error_code")
+
 // AttributeStatusOK is "status=ok".
 var AttributeStatusOK = AttributeKeyStatus.String("ok")
 
 // AttributeStatusError is "status=error".
 var AttributeStatusError = AttributeKeyStatus.String("error")
 
-// AttributeStatusInvalidWhatsappUser is "status=invalid_whatsapp_user".
-var AttributeStatusInvalidWhatsappUser = AttributeKeyStatus.String("invalid_whatsapp_user")
-
 var CounterOAuthSessionCreationCount = mustInt64Counter(
 	"authgear.oauth_session.creation.count",
 	metric.WithDescription("The number of creation of OAuth session"),
@@ -185,8 +192,16 @@ func WithStatusError() MetricOption {
 	return metricOptionAttributeKeyValue{AttributeStatusError}
 }
 
-func WithStatusInvalidWhatsappUser() MetricOption {
-	return metricOptionAttributeKeyValue{AttributeStatusInvalidWhatsappUser}
+func WithWhatsappAPIType(apiType config.WhatsappAPIType) MetricOption {
+	return metricOptionAttributeKeyValue{AttributeKeyWhatsappAPIType.String(string(apiType))}
+}
+
+func WithWhatsappAPIErrorCode(code int) MetricOption {
+	return metricOptionAttributeKeyValue{AttributeKeyWhatsappAPIErrorCode.String(fmt.Sprint(code))}
+}
+
+func WithHTTPStatusCode(code int) MetricOption {
+	return metricOptionAttributeKeyValue{semconv.HTTPResponseStatusCodeKey.Int(code)}
 }
 
 // IntCounterAddOne prepares necessary attributes and calls Add with incr=1.