diff --git a/.github/workflows/default.yml b/.github/workflows/default.yml index b23b8935..8e4007c5 100644 --- a/.github/workflows/default.yml +++ b/.github/workflows/default.yml @@ -34,6 +34,7 @@ jobs: version: latest skip-pkg-cache: true skip-build-cache: true + args: --timeout=3m --issues-exit-code=0 ./... - name: Test run: go test -race -v -coverprofile=coverage.out -covermode=atomic ./... diff --git a/features/deviceclassification.go b/features/deviceclassification.go index 04143352..5adb1bf6 100644 --- a/features/deviceclassification.go +++ b/features/deviceclassification.go @@ -1,7 +1,6 @@ package features import ( - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -43,7 +42,6 @@ func (d *DeviceClassification) RequestManufacturerDetailsForEntity() (*model.Msg // request DeviceClassificationManufacturer from a remote entity msgCounter, err := d.requestData(model.FunctionTypeDeviceClassificationManufacturerData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/features/deviceconfiguration.go b/features/deviceconfiguration.go index 27b0f48c..5662ee59 100644 --- a/features/deviceconfiguration.go +++ b/features/deviceconfiguration.go @@ -3,7 +3,6 @@ package features import ( "time" - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -42,7 +41,6 @@ func NewDeviceConfiguration(localRole, remoteRole model.RoleType, spineLocalDevi func (d *DeviceConfiguration) Request() error { // request DeviceConfigurationKeyValueDescriptionListData from a remote entity if _, err := d.requestData(model.FunctionTypeDeviceConfigurationKeyValueDescriptionListData, nil, nil); err != nil { - logging.Log.Error(err) return err } @@ -54,7 +52,6 @@ func (d *DeviceConfiguration) RequestKeyValueList() (*model.MsgCounterType, erro // request FunctionTypeDeviceConfigurationKeyValueListData from a remote entity msgCounter, err := d.requestData(model.FunctionTypeDeviceConfigurationKeyValueListData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/features/devicediagnosis.go b/features/devicediagnosis.go index f4952d1f..9a3af5c6 100644 --- a/features/devicediagnosis.go +++ b/features/devicediagnosis.go @@ -1,7 +1,6 @@ package features import ( - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -33,7 +32,6 @@ func (d *DeviceDiagnosis) RequestStateForEntity() (*model.MsgCounterType, error) // request FunctionTypeDeviceDiagnosisStateData from a remote entity msgCounter, err := d.requestData(model.FunctionTypeDeviceDiagnosisStateData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/features/electricalconnection.go b/features/electricalconnection.go index eb8cefee..89bfb78a 100644 --- a/features/electricalconnection.go +++ b/features/electricalconnection.go @@ -1,7 +1,6 @@ package features import ( - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -44,7 +43,6 @@ func NewElectricalConnection(localRole, remoteRole model.RoleType, spineLocalDev // request ElectricalConnectionDescriptionListDataType from a remote entity func (e *ElectricalConnection) RequestDescription() error { if _, err := e.requestData(model.FunctionTypeElectricalConnectionDescriptionListData, nil, nil); err != nil { - logging.Log.Error(err) return err } @@ -54,7 +52,6 @@ func (e *ElectricalConnection) RequestDescription() error { // request FunctionTypeElectricalConnectionParameterDescriptionListData from a remote entity func (e *ElectricalConnection) RequestParameterDescription() error { if _, err := e.requestData(model.FunctionTypeElectricalConnectionParameterDescriptionListData, nil, nil); err != nil { - logging.Log.Error(err) return err } @@ -65,7 +62,6 @@ func (e *ElectricalConnection) RequestParameterDescription() error { func (e *ElectricalConnection) RequestPermittedValueSet() (*model.MsgCounterType, error) { msgCounter, err := e.requestData(model.FunctionTypeElectricalConnectionPermittedValueSetListData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/features/feature.go b/features/feature.go index 2e07561d..08c261b8 100644 --- a/features/feature.go +++ b/features/feature.go @@ -83,7 +83,7 @@ func (f *FeatureImpl) requestData(function model.FunctionType, selectors any, el msgCounter, fErr := f.featureLocal.RequestData(function, selectors, elements, f.featureRemote) if fErr != nil { - logging.Log.Error(fErr.String()) + logging.Log.Debug(fErr.String()) return nil, errors.New(fErr.String()) } diff --git a/features/identification.go b/features/identification.go index 08b6aca3..88f94770 100644 --- a/features/identification.go +++ b/features/identification.go @@ -1,7 +1,6 @@ package features import ( - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -32,7 +31,6 @@ func NewIdentification(localRole, remoteRole model.RoleType, spineLocalDevice *s func (i *Identification) Request() (*model.MsgCounterType, error) { msgCounter, err := i.requestData(model.FunctionTypeIdentificationListData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/features/incentivetable.go b/features/incentivetable.go index af7bf0f3..aee75896 100644 --- a/features/incentivetable.go +++ b/features/incentivetable.go @@ -1,7 +1,6 @@ package features import ( - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -27,7 +26,6 @@ func NewIncentiveTable(localRole, remoteRole model.RoleType, spineLocalDevice *s func (i *IncentiveTable) RequestDescription() error { _, err := i.requestData(model.FunctionTypeIncentiveTableDescriptionData, nil, nil) if err != nil { - logging.Log.Error(err) return err } @@ -38,7 +36,6 @@ func (i *IncentiveTable) RequestDescription() error { func (i *IncentiveTable) RequestConstraints() error { _, err := i.requestData(model.FunctionTypeIncentiveTableConstraintsData, nil, nil) if err != nil { - logging.Log.Error(err) return err } @@ -49,7 +46,6 @@ func (i *IncentiveTable) RequestConstraints() error { func (i *IncentiveTable) RequestValues() error { _, err := i.requestData(model.FunctionTypeIncentiveTableData, nil, nil) if err != nil { - logging.Log.Error(err) return err } diff --git a/features/loadcontrol.go b/features/loadcontrol.go index 001e0eaf..3777d275 100644 --- a/features/loadcontrol.go +++ b/features/loadcontrol.go @@ -1,7 +1,6 @@ package features import ( - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -37,7 +36,6 @@ func NewLoadControl(localRole, remoteRole model.RoleType, spineLocalDevice *spin // request FunctionTypeLoadControlLimitDescriptionListData from a remote device func (l *LoadControl) RequestLimitDescription() error { if _, err := l.requestData(model.FunctionTypeLoadControlLimitDescriptionListData, nil, nil); err != nil { - logging.Log.Error(err) return err } @@ -47,7 +45,6 @@ func (l *LoadControl) RequestLimitDescription() error { // request FunctionTypeLoadControlLimitConstraintsListData from a remote device func (l *LoadControl) RequestLimitConstraints() error { if _, err := l.requestData(model.FunctionTypeLoadControlLimitConstraintsListData, nil, nil); err != nil { - logging.Log.Error(err) return err } @@ -58,7 +55,6 @@ func (l *LoadControl) RequestLimitConstraints() error { func (l *LoadControl) RequestLimits() (*model.MsgCounterType, error) { msgCounter, err := l.requestData(model.FunctionTypeLoadControlLimitListData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/features/measurement.go b/features/measurement.go index 1741fa15..3d5d69a0 100644 --- a/features/measurement.go +++ b/features/measurement.go @@ -3,7 +3,6 @@ package features import ( "time" - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -39,7 +38,6 @@ func NewMeasurement(localRole, remoteRole model.RoleType, spineLocalDevice *spin // request FunctionTypeMeasurementDescriptionListData from a remote device func (m *Measurement) RequestDescription() error { if _, err := m.requestData(model.FunctionTypeMeasurementDescriptionListData, nil, nil); err != nil { - logging.Log.Error(err) return err } @@ -49,7 +47,6 @@ func (m *Measurement) RequestDescription() error { // request FunctionTypeMeasurementConstraintsListData from a remote entity func (m *Measurement) RequestConstraints() error { if _, err := m.requestData(model.FunctionTypeMeasurementConstraintsListData, nil, nil); err != nil { - logging.Log.Error(err) return err } @@ -60,7 +57,6 @@ func (m *Measurement) RequestConstraints() error { func (m *Measurement) Request() (*model.MsgCounterType, error) { msgCounter, err := m.requestData(model.FunctionTypeMeasurementListData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/features/timeseries.go b/features/timeseries.go index 2bf6fdfc..8a1e7b09 100644 --- a/features/timeseries.go +++ b/features/timeseries.go @@ -3,7 +3,6 @@ package features import ( "time" - "github.com/enbility/eebus-go/logging" "github.com/enbility/eebus-go/spine" "github.com/enbility/eebus-go/spine/model" ) @@ -69,7 +68,6 @@ func NewTimeSeries(localRole, remoteRole model.RoleType, spineLocalDevice *spine func (t *TimeSeries) RequestDescription() error { _, err := t.requestData(model.FunctionTypeTimeSeriesDescriptionListData, nil, nil) if err != nil { - logging.Log.Error(err) return err } @@ -80,7 +78,6 @@ func (t *TimeSeries) RequestDescription() error { func (t *TimeSeries) RequestConstraints() error { _, err := t.requestData(model.FunctionTypeTimeSeriesConstraintsListData, nil, nil) if err != nil { - logging.Log.Error(err) return err } @@ -91,7 +88,6 @@ func (t *TimeSeries) RequestConstraints() error { func (t *TimeSeries) Request() (*model.MsgCounterType, error) { msgCounter, err := t.requestData(model.FunctionTypeTimeSeriesListData, nil, nil) if err != nil { - logging.Log.Error(err) return nil, err } diff --git a/service/hub.go b/service/hub.go index 359c3e20..ac111db2 100644 --- a/service/hub.go +++ b/service/hub.go @@ -108,18 +108,18 @@ func (h *connectionsHub) start() { // start mDNS err := h.mdns.SetupMdnsService() if err != nil { - logging.Log.Error("error during mdns setup:", err) + logging.Log.Debug("error during mdns setup:", err) } // start the websocket server go func() { if err := h.startWebsocketServer(); err != nil { - logging.Log.Error("error during websocket server starting:", err) + logging.Log.Debug("error during websocket server starting:", err) } }() if err := h.mdns.AnnounceMdnsEntry(); err != nil { - logging.Log.Error("error registering mDNS Service:", err) + logging.Log.Debug("error registering mDNS Service:", err) } } @@ -297,27 +297,27 @@ func (h *connectionsHub) ServeHTTP(w http.ResponseWriter, r *http.Request) { conn, err := upgrader.Upgrade(w, r, nil) if err != nil { - logging.Log.Error("error during connection upgrading:", err) + logging.Log.Debug("error during connection upgrading:", err) return } // check if the client supports the ship sub protocol if conn.Subprotocol() != shipWebsocketSubProtocol { - logging.Log.Error("client does not support the ship sub protocol") + logging.Log.Debug("client does not support the ship sub protocol") conn.Close() return } // check if the clients certificate provides a SKI if len(r.TLS.PeerCertificates) == 0 { - logging.Log.Error("client does not provide a certificate") + logging.Log.Debug("client does not provide a certificate") conn.Close() return } ski, err := skiFromCertificate(r.TLS.PeerCertificates[0]) if err != nil { - logging.Log.Error(err) + logging.Log.Debug(err) conn.Close() return } @@ -374,7 +374,6 @@ func (h *connectionsHub) connectFoundService(remoteService *ServiceDetails, host address := fmt.Sprintf("wss://%s:%s", host, port) conn, _, err := dialer.Dial(address, nil) if err != nil { - logging.Log.Error(err) return err } @@ -520,6 +519,7 @@ func (h *connectionsHub) UnpairRemoteService(ski string) error { func (h *connectionsHub) ReportMdnsEntries(entries map[string]MdnsEntry) { h.muxMdns.Lock() defer h.muxMdns.Unlock() + for ski, entry := range entries { // check if this ski is already connected if h.isSkiConnected(ski) { diff --git a/service/mdns.go b/service/mdns.go index 6af04af8..24d234b8 100644 --- a/service/mdns.go +++ b/service/mdns.go @@ -282,7 +282,9 @@ func (m *mdns) RegisterMdnsSearch(cb MdnsSearch) { } // may this is already found - go m.searchDelegate.ReportMdnsEntries(m.entries) + mdnsEntries := m.entries + + go m.searchDelegate.ReportMdnsEntries(mdnsEntries) } // Remove a callback for found mDNS entries and stop searching if no callbacks are left @@ -381,7 +383,7 @@ func (m *mdns) stopResolvingEntries() { func (m *mdns) processAvahiService(service avahi.Service, remove bool) { _, ifaceIndexes, err := m.interfaces() if err != nil { - logging.Log.Error("error getting interfaces:", err) + logging.Log.Debug("error getting interfaces:", err) return } @@ -527,6 +529,7 @@ func (m *mdns) processMdnsEntry(elements map[string]string, name, host string, a } if m.searchDelegate != nil { - go m.searchDelegate.ReportMdnsEntries(m.entries) + mdnsEntries := m.entries + go m.searchDelegate.ReportMdnsEntries(mdnsEntries) } } diff --git a/service/service.go b/service/service.go index 3f76f9a3..4dc4914d 100644 --- a/service/service.go +++ b/service/service.go @@ -89,13 +89,11 @@ func (s *EEBUSService) Setup() error { leaf, err := x509.ParseCertificate(sd.certificate.Certificate[0]) if err != nil { - logging.Log.Error(err) return err } ski, err := skiFromCertificate(leaf) if err != nil { - logging.Log.Error(err) return err } diff --git a/ship/connection.go b/ship/connection.go index 08437bc5..2aa46f94 100644 --- a/ship/connection.go +++ b/ship/connection.go @@ -127,7 +127,7 @@ var _ spine.SpineDataConnection = (*ShipConnection)(nil) // SpineDataConnection interface implementation func (c *ShipConnection) WriteSpineMessage(message []byte) { if err := c.sendSpineData(message); err != nil { - logging.Log.Error(c.RemoteSKI, "Error sending spine message: ", err) + logging.Log.Debug(c.RemoteSKI, "Error sending spine message: ", err) return } } @@ -140,13 +140,13 @@ func (c *ShipConnection) shipModelFromMessage(message []byte) (*model.ShipData, // Get the datagram from the message data := model.ShipData{} if err := json.Unmarshal(jsonData, &data); err != nil { - logging.Log.Error(c.RemoteSKI, "error unmarshalling message: ", err) + logging.Log.Debug(c.RemoteSKI, "error unmarshalling message: ", err) return nil, err } if data.Data.Payload == nil { errorMsg := "received no valid payload" - logging.Log.Error(c.RemoteSKI, errorMsg) + logging.Log.Debug(c.RemoteSKI, errorMsg) return nil, errors.New(errorMsg) } diff --git a/ship/websocket.go b/ship/websocket.go index 9f1b09f2..57914ec0 100644 --- a/ship/websocket.go +++ b/ship/websocket.go @@ -26,12 +26,13 @@ type websocketConnection struct { shipWriteChannel chan []byte // internal handling of closed connections - isConnectionClosed bool + connectionClosed bool remoteSki string - mux sync.Mutex - shutdownOnce sync.Once + muxConnClosed sync.Mutex + muxShipWrite sync.Mutex + shutdownOnce sync.Once } // create a new websocket based shipDataProcessing implementation @@ -44,10 +45,18 @@ func NewWebsocketConnection(conn *websocket.Conn, remoteSki string) *websocketCo // check if the websocket connection is closed func (w *websocketConnection) isConnClosed() bool { - w.mux.Lock() - defer w.mux.Unlock() + w.muxConnClosed.Lock() + defer w.muxConnClosed.Unlock() - return w.isConnectionClosed + return w.connectionClosed +} + +// check if the websocket connection is closed +func (w *websocketConnection) setConnClosed() { + w.muxConnClosed.Lock() + defer w.muxConnClosed.Unlock() + + w.connectionClosed = true } func (w *websocketConnection) run() { @@ -157,11 +166,13 @@ func (w *websocketConnection) readWebsocketMessage() ([]byte, error) { // close the current websocket connection func (w *websocketConnection) close() { w.shutdownOnce.Do(func() { - if w.isConnectionClosed { + if w.isConnClosed() { return } - w.mux.Lock() + w.setConnClosed() + + w.muxShipWrite.Lock() if !util.IsChannelClosed(w.closeChannel) { close(w.closeChannel) @@ -173,13 +184,11 @@ func (w *websocketConnection) close() { w.shipWriteChannel = nil } - w.mux.Unlock() - if w.conn != nil { w.conn.Close() } - w.isConnectionClosed = true + w.muxShipWrite.Unlock() }) } @@ -193,8 +202,15 @@ func (w *websocketConnection) InitDataProcessing(dataProcessing ShipDataProcessi // write a message to the websocket connection func (w *websocketConnection) WriteMessageToDataConnection(message []byte) error { - if w.conn == nil { - return errors.New("connection is not initialized") + if w.isConnClosed() { + return errors.New("connection is closed") + } + + w.muxShipWrite.Lock() + defer w.muxShipWrite.Unlock() + + if w.conn == nil || w.shipWriteChannel == nil { + return errors.New("connection is closed") } w.shipWriteChannel <- message diff --git a/spine/device_remote.go b/spine/device_remote.go index e7d7b695..03782f25 100644 --- a/spine/device_remote.go +++ b/spine/device_remote.go @@ -70,7 +70,6 @@ func (d *DeviceRemoteImpl) CloseConnection() { func (d *DeviceRemoteImpl) HandleIncomingSpineMesssage(message []byte) (*model.MsgCounterType, error) { datagram := model.Datagram{} if err := json.Unmarshal([]byte(message), &datagram); err != nil { - logging.Log.Error(err) return nil, err } err := d.localDevice.ProcessCmd(datagram.Datagram, d) diff --git a/spine/feature_local.go b/spine/feature_local.go index 6ed07c23..fa849aac 100644 --- a/spine/feature_local.go +++ b/spine/feature_local.go @@ -356,7 +356,7 @@ func (r *FeatureLocalImpl) processResult(message *Message) *ErrorType { if message.Cmd.ResultData.Description != nil { errorString += fmt.Sprintf(": %s", *message.Cmd.ResultData.Description) } - logging.Log.Error(errorString) + logging.Log.Debug(errorString) } // we don't need to populate this error as requests don't require a pendingRequest entry diff --git a/spine/feature_remote.go b/spine/feature_remote.go index f22b7390..70a11f47 100644 --- a/spine/feature_remote.go +++ b/spine/feature_remote.go @@ -73,7 +73,7 @@ func (r *FeatureRemoteImpl) SetMaxResponseDelay(delay *model.MaxResponseDelayTyp if err != nil { r.maxResponseDelay = util.Ptr(p.DurationApprox()) } else { - logging.Log.Error(err) + logging.Log.Debug(err) } } diff --git a/spine/function_data.go b/spine/function_data.go index 65c48a31..f077e8cc 100644 --- a/spine/function_data.go +++ b/spine/function_data.go @@ -83,6 +83,6 @@ func (r *FunctionDataImpl[T]) DataAny() any { func (r *FunctionDataImpl[T]) UpdateDataAny(newData any, filterPartial *model.FilterType, filterDelete *model.FilterType) { err := r.UpdateData(newData.(*T), filterPartial, filterDelete) if err != nil { - logging.Log.Error(err.String()) + logging.Log.Debug(err.String()) } } diff --git a/spine/heartbeat.go b/spine/heartbeat.go index 0053ef47..b7672d0f 100644 --- a/spine/heartbeat.go +++ b/spine/heartbeat.go @@ -119,7 +119,7 @@ func (c *HeartbeatSender) sendHearbeat(stopC chan struct{}, d time.Duration) { msgCounter, err := c.sender.Notify(c.senderAddr, c.destinationAddr, cmd) if err != nil { - logging.Log.Error("ERROR sending heartbeat: ", err) + logging.Log.Debug("ERROR sending heartbeat: ", err) } if msgCounter != nil { c.msgCounters = append(c.msgCounters, *msgCounter) diff --git a/spine/nodemanagement_usecase.go b/spine/nodemanagement_usecase.go index 2dfb2da3..f5907b5f 100644 --- a/spine/nodemanagement_usecase.go +++ b/spine/nodemanagement_usecase.go @@ -40,7 +40,7 @@ func (r *NodeManagementImpl) processReplyUseCaseData(message *Message, data mode if useCaseInfo.Actor != nil { actor = model.UseCaseActorType(*useCaseInfo.Actor) } else { - logging.Log.Error("actor is missing in useCaseInformation") + logging.Log.Debug("actor is missing in useCaseInformation") break } @@ -51,7 +51,7 @@ func (r *NodeManagementImpl) processReplyUseCaseData(message *Message, data mode if useCaseSupport.UseCaseName != nil { useCaseName = model.UseCaseNameType(*useCaseSupport.UseCaseName) } else { - logging.Log.Error("useCaseName is missing in useCaseSupport") + logging.Log.Debug("useCaseName is missing in useCaseSupport") continue }