Ocpp: add detailed test logging (#16099)

charger/ocpp/const.go

@@ -2,9 +2,9 @@ package ocpp
 
 import "time"
 
-const (
-	Timeout = 30 * time.Second // default request / response timeout on protocol level
+var Timeout = 30 * time.Second // default request / response timeout on protocol level
 
+const (
 	// Core profile keys
 	KeyMeterValueSampleInterval        = "MeterValueSampleInterval"
 	KeyMeterValuesSampledData          = "MeterValuesSampledData"

charger/ocpp_test.go

@@ -12,6 +12,7 @@ import (
 	"github.com/lorenzodonini/ocpp-go/ocpp1.6/core"
 	"github.com/lorenzodonini/ocpp-go/ocpp1.6/remotetrigger"
 	"github.com/lorenzodonini/ocpp-go/ocpp1.6/types"
+	"github.com/lorenzodonini/ocpp-go/ocppj"
 	"github.com/stretchr/testify/suite"
 )
 
@@ -30,6 +31,12 @@ type ocppTestSuite struct {
 }
 
 func (suite *ocppTestSuite) SetupSuite() {
+	// setup cs so we can overwrite logger afterwards
+	_ = ocpp.Instance()
+	ocppj.SetLogger(&ocppLogger{suite.T()})
+
+	ocpp.Timeout = 5 * time.Second
+
 	suite.clock = clock.NewMock()
 	suite.NotNil(ocpp.Instance())
 }
@@ -59,24 +66,20 @@ func (suite *ocppTestSuite) startChargePoint(id string, connectorId int) ocpp16.
 func (suite *ocppTestSuite) handleTrigger(cp ocpp16.ChargePoint, connectorId int, msg remotetrigger.MessageTrigger) {
 	switch msg {
 	case core.BootNotificationFeatureName:
-		if res, err := cp.BootNotification("model", "vendor"); err != nil {
+		if _, err := cp.BootNotification("model", "vendor"); err != nil {
 			suite.T().Log("BootNotification:", err)
-		} else {
-			suite.T().Log("BootNotification:", res)
 		}
 
 	case core.ChangeAvailabilityFeatureName:
 		fallthrough
 
 	case core.StatusNotificationFeatureName:
-		if res, err := cp.StatusNotification(connectorId, core.NoError, core.ChargePointStatusCharging); err != nil {
+		if _, err := cp.StatusNotification(connectorId, core.NoError, core.ChargePointStatusCharging); err != nil {
 			suite.T().Log("StatusNotification:", err)
-		} else {
-			suite.T().Log("StatusNotification:", res)
 		}
 
 	case core.MeterValuesFeatureName:
-		if res, err := cp.MeterValues(connectorId, []types.MeterValue{
+		if _, err := cp.MeterValues(connectorId, []types.MeterValue{
 			{
 				Timestamp: types.NewDateTime(suite.clock.Now()),
 				SampledValue: []types.SampledValue{
@@ -86,12 +89,7 @@ func (suite *ocppTestSuite) handleTrigger(cp ocpp16.ChargePoint, connectorId int
 			},
 		}); err != nil {
 			suite.T().Log("MeterValues:", err)
-		} else {
-			suite.T().Log("MeterValues:", res)
 		}
-
-	default:
-		suite.T().Log(msg)
 	}
 }
 

charger/ocpp_test_handler.go

@@ -1,8 +1,6 @@
 package charger
 
 import (
-	"fmt"
-
 	"github.com/lorenzodonini/ocpp-go/ocpp1.6/core"
 	"github.com/lorenzodonini/ocpp-go/ocpp1.6/remotetrigger"
 	"github.com/lorenzodonini/ocpp-go/ocpp1.6/smartcharging"
@@ -17,27 +15,22 @@ type ChargePointHandler struct {
 
 func (handler *ChargePointHandler) OnChangeAvailability(request *core.ChangeAvailabilityRequest) (confirmation *core.ChangeAvailabilityConfirmation, err error) {
 	defer func() { handler.triggerC <- core.ChangeAvailabilityFeatureName }()
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewChangeAvailabilityConfirmation(core.AvailabilityStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnChangeConfiguration(request *core.ChangeConfigurationRequest) (confirmation *core.ChangeConfigurationConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewChangeConfigurationConfirmation(core.ConfigurationStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnClearCache(request *core.ClearCacheRequest) (confirmation *core.ClearCacheConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewClearCacheConfirmation(core.ClearCacheStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnDataTransfer(request *core.DataTransferRequest) (confirmation *core.DataTransferConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewDataTransferConfirmation(core.DataTransferStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnGetConfiguration(request *core.GetConfigurationRequest) (confirmation *core.GetConfigurationConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	one := "1"
 	meter := "Power.Active.Import,Energy.Active.Import.Register"
 	return core.NewGetConfigurationConfirmation([]core.ConfigurationKey{
@@ -52,44 +45,36 @@ func (handler *ChargePointHandler) OnGetConfiguration(request *core.GetConfigura
 }
 
 func (handler *ChargePointHandler) OnRemoteStartTransaction(request *core.RemoteStartTransactionRequest) (confirmation *core.RemoteStartTransactionConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewRemoteStartTransactionConfirmation(types.RemoteStartStopStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnRemoteStopTransaction(request *core.RemoteStopTransactionRequest) (confirmation *core.RemoteStopTransactionConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewRemoteStopTransactionConfirmation(types.RemoteStartStopStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnReset(request *core.ResetRequest) (confirmation *core.ResetConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewResetConfirmation(core.ResetStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnUnlockConnector(request *core.UnlockConnectorRequest) (confirmation *core.UnlockConnectorConfirmation, err error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return core.NewUnlockConnectorConfirmation(core.UnlockStatusUnlocked), nil
 }
 
 func (handler *ChargePointHandler) OnTriggerMessage(request *remotetrigger.TriggerMessageRequest) (confirmation *remotetrigger.TriggerMessageConfirmation, err error) {
 	defer func() { handler.triggerC <- request.RequestedMessage }()
-	fmt.Printf("%T %+v\n", request, request)
 	return remotetrigger.NewTriggerMessageConfirmation(remotetrigger.TriggerMessageStatusAccepted), nil
 }
 
 // smart charging
 
 func (handler *ChargePointHandler) OnSetChargingProfile(request *smartcharging.SetChargingProfileRequest) (*smartcharging.SetChargingProfileConfirmation, error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return smartcharging.NewSetChargingProfileConfirmation(smartcharging.ChargingProfileStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnClearChargingProfile(request *smartcharging.ClearChargingProfileRequest) (*smartcharging.ClearChargingProfileConfirmation, error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return smartcharging.NewClearChargingProfileConfirmation(smartcharging.ClearChargingProfileStatusAccepted), nil
 }
 
 func (handler *ChargePointHandler) OnGetCompositeSchedule(request *smartcharging.GetCompositeScheduleRequest) (*smartcharging.GetCompositeScheduleConfirmation, error) {
-	fmt.Printf("%T %+v\n", request, request)
 	return smartcharging.NewGetCompositeScheduleConfirmation(smartcharging.GetCompositeScheduleStatusAccepted), nil
 }

charger/ocpp_test_logger.go

@@ -0,0 +1,38 @@
+package charger
+
+import (
+	"fmt"
+	"strings"
+	"testing"
+)
+
+type ocppLogger struct {
+	t *testing.T
+}
+
+func print(t *testing.T, s string) {
+	var ok bool
+	if s, ok = strings.CutPrefix(s, "sent JSON message to"); ok {
+		s = "send" + s
+	} else if s, ok = strings.CutPrefix(s, "received JSON message from"); ok {
+		s = "recv" + s
+	} else {
+		ok = true
+	}
+	if ok {
+		t.Log(s)
+	}
+}
+
+func (l *ocppLogger) Debug(args ...interface{}) { print(l.t, fmt.Sprint(args...)) }
+func (l *ocppLogger) Debugf(format string, args ...interface{}) {
+	print(l.t, fmt.Sprintf(format, args...))
+}
+func (l *ocppLogger) Info(args ...interface{}) { print(l.t, fmt.Sprint(args...)) }
+func (l *ocppLogger) Infof(format string, args ...interface{}) {
+	print(l.t, fmt.Sprintf(format, args...))
+}
+func (l *ocppLogger) Error(args ...interface{}) { print(l.t, fmt.Sprint(args...)) }
+func (l *ocppLogger) Errorf(format string, args ...interface{}) {
+	print(l.t, fmt.Sprintf(format, args...))
+}