feat(plc4go): improve logging for subscription

plc4go/internal/cbus/Connection.go

@@ -222,8 +222,11 @@ func (c *Connection) setupConnection(ctx context.Context, ch chan plc4go.PlcConn
 		c.log.Trace().Msg("Set interface options 1 failed")
 		return
 	}
+	c.log.Trace().Msg("Connection setup done")
 	c.fireConnected(ch)
+	c.log.Trace().Msg("Connect fired")
 	c.startSubscriptionHandler()
+	c.log.Trace().Msg("subscription handler started")
 }
 
 func (c *Connection) startSubscriptionHandler() {
@@ -240,7 +243,7 @@ func (c *Connection) startSubscriptionHandler() {
 				handled := false
 				for _, subscriber := range c.subscribers {
 					if ok := subscriber.handleMonitoredSAL(monitoredSal); ok {
-						c.log.Debug().Msgf("%v handled\n%s", subscriber, monitoredSal)
+						c.log.Debug().Msgf("\n%v handled\n%s", subscriber, monitoredSal)
 						handled = true
 					}
 				}
@@ -264,7 +267,7 @@ func (c *Connection) startSubscriptionHandler() {
 				handled := false
 				for _, subscriber := range c.subscribers {
 					if ok := subscriber.handleMonitoredMMI(calReply); ok {
-						c.log.Debug().Msgf("%v handled\n%s", subscriber, calReply)
+						c.log.Debug().Msgf("\n%v handled\n%s", subscriber, calReply)
 						handled = true
 					}
 				}

plc4go/internal/cbus/Driver.go

@@ -79,7 +79,7 @@ func (m *Driver) GetConnectionWithContext(ctx context.Context, transportUrl url.
 	}
 
 	codec := NewMessageCodec(transportInstance, options.WithCustomLogger(m.log))
-	m.log.Debug().Msgf("working with codec %#v", codec)
+	m.log.Debug().Msgf("working with codec:\n%s", codec)
 
 	driverContext := NewDriverContext(configuration)
 	driverContext.awaitSetupComplete = m.awaitSetupComplete

plc4go/internal/cbus/Subscriber.go

@@ -102,6 +102,7 @@ func (s *Subscriber) Unsubscribe(ctx context.Context, unsubscriptionRequest apiM
 }
 
 func (s *Subscriber) handleMonitoredMMI(calReply readWriteModel.CALReply) bool {
+	s.log.Debug().Msgf("handling:\n%s", calReply)
 	var unitAddressString string
 	switch calReply := calReply.(type) {
 	case readWriteModel.CALReplyLongExactly:
@@ -118,13 +119,19 @@ func (s *Subscriber) handleMonitoredMMI(calReply readWriteModel.CALReply) bool {
 	default:
 		unitAddressString = "u0" // On short form it should be always unit 0 TODO: double check that
 	}
+	s.log.Debug().Msgf("Unit address string: %s", unitAddressString)
 	calData := calReply.GetCalData()
 	handled := false
 	for registration, consumer := range s.consumers {
+		s.log.Debug().Msgf("Checking with registration\n%s\nand consumer set %t", registration, consumer != nil)
 		for _, subscriptionHandle := range registration.GetSubscriptionHandles() {
-			handled = handled || s.offerMMI(unitAddressString, calData, subscriptionHandle.(*SubscriptionHandle), consumer)
+			s.log.Debug().Msgf("offering to\n%s", subscriptionHandle)
+			handleHandled := s.offerMMI(unitAddressString, calData, subscriptionHandle.(*SubscriptionHandle), consumer)
+			s.log.Debug().Msgf("handle handled: %t", handleHandled)
+			handled = handled || handleHandled
 		}
 	}
+	s.log.Debug().Msgf("final handled: %t", handled)
 	return handled
 }