Unverified Commit df53dd5d authored by Simon Esposito's avatar Simon Esposito Committed by GitHub
Browse files

Improve IAP validation error logging (#669) 

Fix IAP validation hook registration log messages.
Minor JS runtime IAP result fixes.
parent b0f05439

CHANGELOG.md

+2 −0
Original line number Diff line number Diff line
@@ -11,10 +11,12 @@ The format is based on [keep a changelog](http://keepachangelog.com) and this pr 
- Warn when using deprecated config parameters.

- Improve tournament lookup behaviour.

- Improve email import semantics when linking social accounts.

- Log IAP provider API response payload when non 200 status code is returned.



### Fixed

- Fix log level in Lua runtime log calls which use logger fields.

- Correctly register purchase validation before/after hooks in JavaScript/Lua runtimes.

- Add missing "environment" to JS ValidatedPurchases results.



## [3.5.0] - 2021-08-10

### Added

iap/iap.go

+60 −31
Original line number Diff line number Diff line
@@ -23,7 +23,7 @@ import ( 
	"encoding/pem"

	"errors"

	"fmt"

	"io/ioutil"

	"io"

	"net/http"

	"net/url"

	"strings"
@@ -52,6 +52,15 @@ const ( 


const accessTokenExpiresGracePeriod = 300 // 5 min grace period



type ValidationError struct {

	Err        error

	StatusCode int

	Payload    string

}



func (e *ValidationError) Error() string { return e.Err.Error() }

func (e *ValidationError) Unwrap() error { return e.Err }



var (

	ErrNon200ServiceApple     = errors.New("non-200 response from Apple service")

	ErrNon200ServiceGoogle    = errors.New("non-200 response from Google service")
@@ -135,13 +144,13 @@ func ValidateReceiptAppleWithUrl(ctx context.Context, httpc *http.Client, url, r 
	}

	defer resp.Body.Close()



	switch resp.StatusCode {

	case 200:

		buf, err := ioutil.ReadAll(resp.Body)

	buf, err := io.ReadAll(resp.Body)

	if err != nil {

		return nil, nil, err

	}



	switch resp.StatusCode {

	case 200:

		var out ValidateReceiptAppleResponse

		if err := json.Unmarshal(buf, &out); err != nil {

			return nil, nil, err
@@ -156,7 +165,11 @@ func ValidateReceiptAppleWithUrl(ctx context.Context, httpc *http.Client, url, r 
			return &out, buf, nil

		}

	default:

		return nil, nil, ErrNon200ServiceApple

		return nil, nil, &ValidationError{

			Err:        ErrNon200ServiceApple,

			StatusCode: resp.StatusCode,

			Payload:    string(buf),

		}

	}

}
@@ -287,20 +300,24 @@ func getGoogleAccessToken(ctx context.Context, httpc *http.Client, email string, 
	}

	defer resp.Body.Close()



	switch resp.StatusCode {

	case 200:

		buf, err := ioutil.ReadAll(resp.Body)

	buf, err := io.ReadAll(resp.Body)

	if err != nil {

		return "", err

	}



	switch resp.StatusCode {

	case 200:

		cachedTokenGoogle.fetchedAt = time.Now()

		if err := json.Unmarshal(buf, &cachedTokenGoogle); err != nil {

			return "", err

		}

		return cachedTokenGoogle.AccessToken, nil

	default:

		return "", fmt.Errorf("non-200 response from Google auth: %+v", resp)

		return "", &ValidationError{

			Err:        errors.New("non-200 response from Google auth"),

			StatusCode: resp.StatusCode,

			Payload:    string(buf),

		}

	}

}
@@ -361,13 +378,13 @@ func validateReceiptGoogleWithIDs(ctx context.Context, httpc *http.Client, token 


	defer resp.Body.Close()



	switch resp.StatusCode {

	case 200:

		buf, err := ioutil.ReadAll(resp.Body)

	buf, err := io.ReadAll(resp.Body)

	if err != nil {

		return nil, nil, nil, err

	}



	switch resp.StatusCode {

	case 200:

		out := &ValidateReceiptGoogleResponse{}

		if err := json.Unmarshal(buf, &out); err != nil {

			return nil, nil, nil, err
@@ -375,7 +392,11 @@ func validateReceiptGoogleWithIDs(ctx context.Context, httpc *http.Client, token 


		return out, gr, buf, nil

	default:

		return nil, nil, nil, ErrNon200ServiceGoogle

		return nil, nil, nil, &ValidationError{

			Err:        ErrNon200ServiceGoogle,

			StatusCode: resp.StatusCode,

			Payload:    string(buf),

		}

	}

}
@@ -450,20 +471,24 @@ func getHuaweiAccessToken(ctx context.Context, httpc *http.Client, clientID, cli 
	}

	defer resp.Body.Close()



	switch resp.StatusCode {

	case 200:

		buf, err := ioutil.ReadAll(resp.Body)

	buf, err := io.ReadAll(resp.Body)

	if err != nil {

		return "", err

	}



	switch resp.StatusCode {

	case 200:

		var out accessTokenHuawei

		if err := json.Unmarshal(buf, &out); err != nil {

			return "", err

		}

		return out.AccessToken, nil

	default:

		return "", fmt.Errorf("non-200 response from Huawei auth: %+v", resp)

		return "", &ValidationError{

			Err:        errors.New("non-200 response from Huawei auth"),

			StatusCode: resp.StatusCode,

			Payload:    string(buf),

		}

	}

}
@@ -524,13 +549,13 @@ func ValidateReceiptHuawei(ctx context.Context, httpc *http.Client, pubKey, clie 
		return nil, nil, nil, err

	}



	switch res.StatusCode {

	case 200:

		buf, err := ioutil.ReadAll(res.Body)

	buf, err := io.ReadAll(res.Body)

	if err != nil {

		return nil, data, nil, err

	}



	switch res.StatusCode {

	case 200:

		out := &ValidateReceiptHuaweiResponse{}

		if err := json.Unmarshal(buf, &out); err != nil {

			return nil, data, nil, err
@@ -538,7 +563,11 @@ func ValidateReceiptHuawei(ctx context.Context, httpc *http.Client, pubKey, clie 


		return out, data, buf, nil

	default:

		return nil, nil, nil, ErrNon200ServiceHuawei

		return nil, nil, nil, &ValidationError{

			Err:        ErrNon200ServiceHuawei,

			StatusCode: res.StatusCode,

			Payload:    string(buf),

		}

	}

}

server/core_purchase.go

+21 −3
Original line number Diff line number Diff line
@@ -45,9 +45,15 @@ var httpc = &http.Client{Timeout: 5 * time.Second} 
func ValidatePurchasesApple(ctx context.Context, logger *zap.Logger, db *sql.DB, userID uuid.UUID, password, receipt string) (*api.ValidatePurchaseResponse, error) {

	validation, raw, err := iap.ValidateReceiptApple(ctx, httpc, receipt, password)

	if err != nil {

		var vErr *iap.ValidationError

		if err != context.Canceled {

			if errors.As(err, &vErr) {

				logger.Error("Error validating Apple receipt", zap.Error(vErr.Err), zap.Int("status_code", vErr.StatusCode), zap.String("payload", vErr.Payload))

				return nil, vErr.Err

			} else {

				logger.Error("Error validating Apple receipt", zap.Error(err))

			}

		}

		return nil, err

	}
@@ -112,9 +118,15 @@ func ValidatePurchasesApple(ctx context.Context, logger *zap.Logger, db *sql.DB, 
func ValidatePurchaseGoogle(ctx context.Context, logger *zap.Logger, db *sql.DB, userID uuid.UUID, config *IAPGoogleConfig, receipt string) (*api.ValidatePurchaseResponse, error) {

	_, gReceipt, raw, err := iap.ValidateReceiptGoogle(ctx, httpc, config.ClientEmail, config.PrivateKey, receipt)

	if err != nil {

		var vErr *iap.ValidationError

		if err != context.Canceled {

			if errors.As(err, &vErr) {

				logger.Error("Error validating Google receipt", zap.Error(vErr.Err), zap.Int("status_code", vErr.StatusCode), zap.String("payload", vErr.Payload))

				return nil, vErr.Err

			} else {

				logger.Error("Error validating Google receipt", zap.Error(err))

			}

		}

		return nil, err

	}
@@ -162,9 +174,15 @@ func ValidatePurchaseGoogle(ctx context.Context, logger *zap.Logger, db *sql.DB, 
func ValidatePurchaseHuawei(ctx context.Context, logger *zap.Logger, db *sql.DB, userID uuid.UUID, config *IAPHuaweiConfig, inAppPurchaseData, signature string) (*api.ValidatePurchaseResponse, error) {

	validation, data, raw, err := iap.ValidateReceiptHuawei(ctx, httpc, config.PublicKey, config.ClientID, config.ClientSecret, inAppPurchaseData, signature)

	if err != nil {

		var vErr *iap.ValidationError

		if err != context.Canceled {

			if errors.As(err, &vErr) {

				logger.Error("Error validating Huawei receipt", zap.Error(vErr.Err), zap.Int("status_code", vErr.StatusCode), zap.String("payload", vErr.Payload))

				return nil, vErr.Err

			} else {

				logger.Error("Error validating Huawei receipt", zap.Error(err))

			}

		}

		return nil, err

	}

server/runtime.go

+9 −9
Original line number Diff line number Diff line
@@ -1672,13 +1672,13 @@ func NewRuntime(ctx context.Context, logger, startupLogger *zap.Logger, db *sql. 
		startupLogger.Info("Registered JavaScript runtime After function invocation", zap.String("id", "getusers"))

	}

	if allAfterReqFunctions.afterValidatePurchaseAppleFunction != nil {

		startupLogger.Info("Registered JavaScript runtime Before function invocation", zap.String("id", "validatepurchaseapple"))

		startupLogger.Info("Registered JavaScript runtime After function invocation", zap.String("id", "validatepurchaseapple"))

	}

	if allAfterReqFunctions.afterValidatePurchaseGoogleFunction != nil {

		startupLogger.Info("Registered JavaScript runtime Before function invocation", zap.String("id", "validatepurchasegoogle"))

		startupLogger.Info("Registered JavaScript runtime After function invocation", zap.String("id", "validatepurchasegoogle"))

	}

	if allAfterReqFunctions.afterValidatePurchaseHuaweiFunction != nil {

		startupLogger.Info("Registered JavaScript runtime Before function invocation", zap.String("id", "validatepurchasehuawei"))

		startupLogger.Info("Registered JavaScript runtime After function invocation", zap.String("id", "validatepurchasehuawei"))

	}

	if allAfterReqFunctions.afterEventFunction != nil {

		startupLogger.Info("Registered JavaScript runtime After custom events function invocation")
@@ -1955,15 +1955,15 @@ func NewRuntime(ctx context.Context, logger, startupLogger *zap.Logger, db *sql. 
	}

	if luaAfterReqFunctions.afterValidatePurchaseAppleFunction != nil {

		allAfterReqFunctions.afterValidatePurchaseAppleFunction = luaAfterReqFunctions.afterValidatePurchaseAppleFunction

		startupLogger.Info("Registered Lua runtime Before function invocation", zap.String("id", "validatepurchaseapple"))

		startupLogger.Info("Registered Lua runtime After function invocation", zap.String("id", "validatepurchaseapple"))

	}

	if luaAfterReqFunctions.afterValidatePurchaseGoogleFunction != nil {

		allAfterReqFunctions.afterValidatePurchaseGoogleFunction = luaAfterReqFunctions.afterValidatePurchaseGoogleFunction

		startupLogger.Info("Registered Lua runtime Before function invocation", zap.String("id", "validatepurchasegoogle"))

		startupLogger.Info("Registered Lua runtime After function invocation", zap.String("id", "validatepurchasegoogle"))

	}

	if luaAfterReqFunctions.afterValidatePurchaseHuaweiFunction != nil {

		allAfterReqFunctions.afterValidatePurchaseHuaweiFunction = luaAfterReqFunctions.afterValidatePurchaseHuaweiFunction

		startupLogger.Info("Registered Lua runtime Before function invocation", zap.String("id", "validatepurchasehuawei"))

		startupLogger.Info("Registered Lua runtime After function invocation", zap.String("id", "validatepurchasehuawei"))

	}

	if luaAfterReqFunctions.afterEventFunction != nil {

		allAfterReqFunctions.afterEventFunction = luaAfterReqFunctions.afterEventFunction
@@ -2245,15 +2245,15 @@ func NewRuntime(ctx context.Context, logger, startupLogger *zap.Logger, db *sql. 
	}

	if goAfterReqFunctions.afterValidatePurchaseAppleFunction != nil {

		allAfterReqFunctions.afterValidatePurchaseAppleFunction = goAfterReqFunctions.afterValidatePurchaseAppleFunction

		startupLogger.Info("Registered Go runtime Before function invocation", zap.String("id", "validatepurchaseapple"))

		startupLogger.Info("Registered Go runtime After function invocation", zap.String("id", "validatepurchaseapple"))

	}

	if goAfterReqFunctions.afterValidatePurchaseGoogleFunction != nil {

		allAfterReqFunctions.afterValidatePurchaseGoogleFunction = goAfterReqFunctions.afterValidatePurchaseGoogleFunction

		startupLogger.Info("Registered Go runtime Before function invocation", zap.String("id", "validatepurchasegoogle"))

		startupLogger.Info("Registered Go runtime After function invocation", zap.String("id", "validatepurchasegoogle"))

	}

	if goAfterReqFunctions.afterValidatePurchaseHuaweiFunction != nil {

		allAfterReqFunctions.afterValidatePurchaseHuaweiFunction = goAfterReqFunctions.afterValidatePurchaseHuaweiFunction

		startupLogger.Info("Registered Go runtime Before function invocation", zap.String("id", "validatepurchasehuawei"))

		startupLogger.Info("Registered Go runtime After function invocation", zap.String("id", "validatepurchasehuawei"))

	}

	if goAfterReqFunctions.afterEventFunction != nil {

		allAfterReqFunctions.afterEventFunction = goAfterReqFunctions.afterEventFunction

server/runtime_javascript_nakama.go

+3 −2
Original line number Diff line number Diff line
@@ -6256,14 +6256,15 @@ func getJsValidatedPurchasesData(validation *api.ValidatePurchaseResponse) map[s 
}



func getJsValidatedPurchaseData(purchase *api.ValidatedPurchase) map[string]interface{} {

	validatedPurchaseMap := make(map[string]interface{}, 7)

	validatedPurchaseMap := make(map[string]interface{}, 8)

	validatedPurchaseMap["productId"] = purchase.ProductId

	validatedPurchaseMap["transactionId"] = purchase.TransactionId

	validatedPurchaseMap["store"] = purchase.Store.String()

	validatedPurchaseMap["ProviderResponse"] = purchase.ProviderResponse

	validatedPurchaseMap["providerResponse"] = purchase.ProviderResponse

	validatedPurchaseMap["purchaseTime"] = purchase.PurchaseTime.Seconds

	validatedPurchaseMap["createTime"] = purchase.CreateTime.Seconds

	validatedPurchaseMap["updateTime"] = purchase.UpdateTime.Seconds

	validatedPurchaseMap["environment"] = purchase.Environment.String()



	return validatedPurchaseMap

}