You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@plc4x.apache.org by sr...@apache.org on 2023/06/13 08:53:51 UTC
[plc4x] 02/02: test(plc4go/cbus): add logging to hunt down randomly failing test
This is an automated email from the ASF dual-hosted git repository.
sruehl pushed a commit to branch develop
in repository https://gitbox.apache.org/repos/asf/plc4x.git
commit 30aa44ce2100c5b7451d1f2d33104119d35a3d05
Author: Sebastian Rühl <sr...@apache.org>
AuthorDate: Tue Jun 13 10:53:35 2023 +0200
test(plc4go/cbus): add logging to hunt down randomly failing test
---
plc4go/internal/cbus/Browser.go | 8 +++++
plc4go/internal/cbus/MessageCodec.go | 55 +++++++++++++++++++++----------
plc4go/internal/cbus/MessageCodec_test.go | 2 +-
3 files changed, 46 insertions(+), 19 deletions(-)
diff --git a/plc4go/internal/cbus/Browser.go b/plc4go/internal/cbus/Browser.go
index 89d8f29350..ed23370056 100644
--- a/plc4go/internal/cbus/Browser.go
+++ b/plc4go/internal/cbus/Browser.go
@@ -60,6 +60,7 @@ func (m Browser) BrowseQuery(ctx context.Context, interceptor func(result apiMod
var queryResults []apiModel.PlcBrowseItem
switch query := query.(type) {
case *unitInfoQuery:
+ m.log.Trace().Msg("extract units")
units, allUnits, err := m.extractUnits(ctx, query, m.getInstalledUnitAddressBytes)
if err != nil {
m.log.Error().Err(err).Msg("Error extracting units")
@@ -72,6 +73,7 @@ func (m Browser) BrowseQuery(ctx context.Context, interceptor func(result apiMod
}
unitLoop:
for _, unit := range units {
+ m.log.Trace().Msgf("checking unit:\n%s", unit)
if err := ctx.Err(); err != nil {
m.log.Info().Err(err).Msgf("Aborting scan at unit %s", unit)
return apiModel.PlcResponseCode_INVALID_ADDRESS, nil
@@ -95,12 +97,15 @@ func (m Browser) BrowseQuery(ctx context.Context, interceptor func(result apiMod
} else {
event.Msgf("unit %d: Query %s", unitAddress, attribute)
}
+ m.log.Trace().Msg("Building request")
readTagName := fmt.Sprintf("%s/%d/%s", queryName, unitAddress, attribute)
readRequest, _ := m.connection.ReadRequestBuilder().
AddTag(readTagName, NewCALIdentifyTag(unit, nil /*TODO: add bridge support*/, attribute, 1)).
Build()
timeoutCtx, timeoutCancel := context.WithTimeout(ctx, time.Second*2)
+ m.log.Trace().Msgf("Executing readRequest\n%s\nwith timeout %s", readRequest, timeoutCtx)
requestResult := <-readRequest.ExecuteWithContext(timeoutCtx)
+ m.log.Trace().Msg("got a response")
timeoutCancel()
if err := requestResult.GetErr(); err != nil {
if !allUnits && !allAttributes {
@@ -126,14 +131,17 @@ func (m Browser) BrowseQuery(ctx context.Context, interceptor func(result apiMod
},
)
if interceptor != nil {
+ m.log.Trace().Msg("forwarding query result to interceptor")
interceptor(queryResult)
}
queryResults = append(queryResults, queryResult)
}
}
default:
+ m.log.Warn().Msgf("unsupported query type supplied %T", query)
return apiModel.PlcResponseCode_INVALID_ADDRESS, nil
}
+ m.log.Trace().Msgf("Browse done with \n%s", queryResults)
return apiModel.PlcResponseCode_OK, queryResults
}
diff --git a/plc4go/internal/cbus/MessageCodec.go b/plc4go/internal/cbus/MessageCodec.go
index 2160eee221..1c4c3e3743 100644
--- a/plc4go/internal/cbus/MessageCodec.go
+++ b/plc4go/internal/cbus/MessageCodec.go
@@ -56,7 +56,7 @@ func NewMessageCodec(transportInstance transports.TransportInstance, _options ..
monitoredSALs: make(chan readWriteModel.MonitoredSAL, 100),
log: options.ExtractCustomLogger(_options...),
}
- codec.DefaultCodec = _default.NewDefaultCodec(codec, transportInstance, append(_options, _default.WithCustomMessageHandler(extractMMIAndSAL))...)
+ codec.DefaultCodec = _default.NewDefaultCodec(codec, transportInstance, append(_options, _default.WithCustomMessageHandler(extractMMIAndSAL(codec.log)))...)
return codec
}
@@ -296,6 +296,7 @@ lookingForTheEnd:
requestContext := readWriteModel.NewRequestContext(false)
cBusMessage, secondErr := readWriteModel.CBusMessageParse(sanitizedInput, pciResponse, requestContext, m.cbusOptions)
if secondErr == nil {
+ m.log.Trace().Msgf("Parsed message as SAL:\n%s", cBusMessage)
return cBusMessage, nil
} else {
m.log.Debug().Err(secondErr).Msg("SAL parse failed too")
@@ -306,6 +307,7 @@ lookingForTheEnd:
cbusOptions := readWriteModel.NewCBusOptions(false, false, false, false, false, false, false, false, false)
cBusMessage, secondErr := readWriteModel.CBusMessageParse(sanitizedInput, true, requestContext, cbusOptions)
if secondErr == nil {
+ m.log.Trace().Msgf("Parsed message as MMI:\n%s", cBusMessage)
return cBusMessage, nil
} else {
m.log.Debug().Err(secondErr).Msg("CAL parse failed too")
@@ -315,29 +317,46 @@ lookingForTheEnd:
m.log.Warn().Err(err).Msg("error parsing")
return nil, nil
}
+
+ m.log.Trace().Msgf("Parsed message:\n%s", cBusMessage)
return cBusMessage, nil
}
-func extractMMIAndSAL(codec _default.DefaultCodecRequirements, message spi.Message) bool {
- switch message := message.(type) {
- case readWriteModel.CBusMessageToClientExactly:
- switch reply := message.GetReply().(type) {
- case readWriteModel.ReplyOrConfirmationReplyExactly:
- switch reply := reply.GetReply().(type) {
- case readWriteModel.ReplyEncodedReplyExactly:
- switch encodedReply := reply.GetEncodedReply().(type) {
- case readWriteModel.MonitoredSALReplyExactly:
- codec.(*MessageCodec).monitoredSALs <- encodedReply.GetMonitoredSAL()
- case readWriteModel.EncodedReplyCALReplyExactly:
- calData := encodedReply.GetCalReply().GetCalData()
- switch calData.(type) {
- case readWriteModel.CALDataStatusExactly, readWriteModel.CALDataStatusExtendedExactly:
- codec.(*MessageCodec).monitoredMMIs <- encodedReply.GetCalReply()
+func extractMMIAndSAL(log zerolog.Logger) _default.CustomMessageHandler {
+ return func(codec _default.DefaultCodecRequirements, message spi.Message) bool {
+ log.Trace().Msgf("Custom handling message:\n%s", message)
+ switch message := message.(type) {
+ case readWriteModel.CBusMessageToClientExactly:
+ switch reply := message.GetReply().(type) {
+ case readWriteModel.ReplyOrConfirmationReplyExactly:
+ switch reply := reply.GetReply().(type) {
+ case readWriteModel.ReplyEncodedReplyExactly:
+ switch encodedReply := reply.GetEncodedReply().(type) {
+ case readWriteModel.MonitoredSALReplyExactly:
+ log.Trace().Msg("Feed to monitored SALs")
+ codec.(*MessageCodec).monitoredSALs <- encodedReply.GetMonitoredSAL()
+ case readWriteModel.EncodedReplyCALReplyExactly:
+ calData := encodedReply.GetCalReply().GetCalData()
+ switch calData.(type) {
+ case readWriteModel.CALDataStatusExactly, readWriteModel.CALDataStatusExtendedExactly:
+ log.Trace().Msg("Feed to monitored MMIs")
+ codec.(*MessageCodec).monitoredMMIs <- encodedReply.GetCalReply()
+ default:
+ log.Trace().Msgf("Not a CALDataStatusExactly or CALDataStatusExtendedExactly. Actual type %T", calData)
+ }
+ default:
+ log.Trace().Msgf("Not a MonitoredSALReply or EncodedReplyCALReply. Actual type %T", encodedReply)
}
+ default:
+ log.Trace().Msgf("Not a ReplyEncodedReply. Actual type %T", reply)
}
+ default:
+ log.Trace().Msgf("Not a ReplyOrConfirmationReply. Actual type %T", reply)
}
+ default:
+ log.Trace().Msgf("Not a CBusMessageToClient. Actual type %T", message)
}
+ // We never handle mmi or sal here as we might want to read them in a read-request too
+ return false
}
- // We never handle mmi or sal here as we might want to read them in a read-request too
- return false
}
diff --git a/plc4go/internal/cbus/MessageCodec_test.go b/plc4go/internal/cbus/MessageCodec_test.go
index 9f9e9dcf82..2c11659dfb 100644
--- a/plc4go/internal/cbus/MessageCodec_test.go
+++ b/plc4go/internal/cbus/MessageCodec_test.go
@@ -874,7 +874,7 @@ func Test_extractMMIAndSAL(t *testing.T) {
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
- assert.Equalf(t, tt.want, extractMMIAndSAL(tt.args.codec, tt.args.message), "extractMMIAndSAL(%v, %v)", tt.args.codec, tt.args.message)
+ assert.Equalf(t, tt.want, extractMMIAndSAL(testutils.ProduceTestingLogger(t))(tt.args.codec, tt.args.message), "extractMMIAndSAL(%v, %v)", tt.args.codec, tt.args.message)
})
}
}