lorenzodonini / ocpp-go

Open Charge Point Protocol implementation in Go
MIT License
277 stars 126 forks source link

panic: interface conversion: interface {} is float64, not string #173

Closed sc-atompower closed 1 year ago

sc-atompower commented 1 year ago

Curious if anyone has some across this before. Have 2 separate partners who occasionally crash our system by encountering an error on their end and sending through the websocket pipe to ocpp-go

This causes ocpp-go to panic thus restarting our container. Below is a full Grafana snapshot of what occurs.

image

Really comes down to

parse message: [4 2552633546 3 An internal server error has occurred. map[associatedException:map[ClassName:System.Exception Data:<nil> ExceptionMethod:<nil> HResult:-2.146233088e+09 HelpURL:<nil> InnerException:<nil> Message:An error has occurred, please see details. RemoteStackIndex:0 RemoteStackTraceString:<nil> Source:<nil> StackTraceString:<nil> WatsonBuckets:<nil>] occurenceDateTime:2023-02-23T16:43:41.3998122Z]]

Leading to:


2023-02-23 11:43:41 | dev.azure.com/atompower/cobblestone/_git/ocpp.git/ocppj.(*Endpoint).ParseMessage(0xc0032f4c00, {0xc00377a540, 0x5, 0x449e92}, {0xbac178, 0xc0030aa280}) |  
-- | -- | --
  |   | 2023-02-23 11:43:41 | goroutine 1226 [running]: |  
  |   | 2023-02-23 11:43:41 |   |  
  |   | 2023-02-23 11:43:41 | panic: interface conversion: interface {} is float64, not string
lorenzodonini commented 1 year ago

Hey @sc-atompower and thanks for submitting the issue.

To make sure this isn't an issue in the library I would need a more detailed log message, which allows seeing the raw incoming message. To enable debug logs you can:

ocppj.SetLogger(log.WithField("logger", "ocppj"))
ws.SetLogger(log.WithField("logger", "websocket"))

The logger can be be anything, as long as it conforms to the interface specified in logging.go/Logger (which should be fine with logrus and zap at least, otherwise you'll need to write a tiny adapter).

sc-atompower commented 1 year ago

I'll have more data shortly.

sc-atompower commented 1 year ago

@lorenzodonini

I attached the logger to the ws client and set the log level to debug. We received no new data to explain the crash. This did not allow us to see the raw incoming message.

{"level":"debug","ts":1681532159.2912889,"msg":"enqueued CALL [2114071548, StopTransaction]"}
{"level":"debug","ts":1681532159.2913153,"msg":"queuing data for server","logger":"websocket"}
{"level":"debug","ts":1681532159.2913272,"msg":"sending data","logger":"websocket"}
{"level":"debug","ts":1681532159.2914004,"msg":"written 222 bytes","logger":"websocket"}
{"level":"debug","ts":1681532159.3255785,"msg":"ping sent","logger":"websocket"}
{"level":"debug","ts":1681532159.4100168,"msg":"ping sent","logger":"websocket"}
{"level":"debug","ts":1681532159.412674,"msg":"pong received","logger":"websocket"}
{"level":"debug","ts":1681532159.4139264,"msg":"ping sent","logger":"websocket"}
{"level":"debug","ts":1681532159.493899,"msg":"pong received","logger":"websocket"}
{"level":"debug","ts":1681532159.497917,"msg":"pong received","logger":"websocket"}
{"level":"debug","ts":1681532159.5719092,"msg":"received 426 bytes","logger":"websocket"}
panic: interface conversion: interface {} is float64, not string

goroutine 290118 [running]:
github.com/lorenzodonini/ocpp-go/ocppj.(*Endpoint).ParseMessage(0xc0012ece00, {0xc00020b9e0, 0x5, 0xc0012de918}, {0xbb1498, 0xc00054f810})
    /go/pkg/mod/github.com/lorenzodonini/ocpp-go@v0.16.0/ocppj/ocppj.go:423 +0x10f3
github.com/lorenzodonini/ocpp-go/ocppj.(*Client).ocppMessageHandler(0xc0002b0780, {0xc0012ece00, 0x0, 0x0})
    /go/pkg/mod/github.com/lorenzodonini/ocpp-go@v0.16.0/ocppj/client.go:207 +0xfa
github.com/lorenzodonini/ocpp-go/ws.(*Client).readPump(0xc00051c9a0)
    /go/pkg/mod/github.com/lorenzodonini/ocpp-go@v0.16.0/ws/websocket.go:886 +0x1e2
created by github.com/lorenzodonini/ocpp-go/ws.(*Client).Start
    /go/pkg/mod/github.com/lorenzodonini/ocpp-go@v0.16.0/ws/websocket.go:1005 +0x705