search

dlmcpaul / EnphaseCollector

Enphase Solar Metrics Collector
Mozilla Public License 2.0
68 stars 19 forks source link

Unrecognized field "system_id" #64

Closed HuweyII closed 1 year ago

HuweyII commented 1 year ago

I get this error suddenly from the docker container running Enphasecollector. The container still answers with prometheus data the "important to me" solar data is missing. i.e. "solar_meter_production_watts" is not in the collector output then this error is happening.

`2023-09-05T08:51:45.053-07:00 ERROR 7 --- [ scheduling-1] com.hz.services.EnvoyService : Failed to retrieve Solar stats. Exception was Unrecognized field "system_id" (class com.hz.models.envoy.LogInResponse), not marked as ignorable (4 known properties: "is_consumer", "session_id", "message", "manager_token"]) at [Source: (String)"{"message":"success","session_id":"3086e4bae322887a5a1efdc613c20270","manager_token":"eyJhbGciOiJIUzI1NiJ9.eyJkYXRhIjp7InNlc3Npb25faWQiOiIzMDg2ZTRiYWUzMjI4ODdhNWExZWZkYzYxM2MyMDI3MCIsImNvbXBhbnlfaWQiOm51bGwsImVtYWlsX2lkIjoibWlzY0ByZXRsYXcubmV0IiwidXNlcl9pZCI6MjM5MjQ5MCwiY2xpZW50X2FwcCI6Iml0azMiLCJmaXJzdF9uYW1lIjoiSmFtZXMiLCJsYXN0X25hbWUiOiJTdXRoZXJsYW5kIiwibG9naW5fdXNlciI6bnVsbCwiaXNfZGlzdHJpYnV0b3IiOmZhbHNlfSwiZXhwIjoxNjk0NTMzOTA0LCJzdWIiOiJtaXNjQHJldGxhdy5uZXQifQ.aU_flbzO9FodCzfLr8xXcUwVY30r8K"[truncated 54 chars]; line: 1, column: 554] (through reference chain: com.hz.models.envoy.LogInResponse["system_id"])

com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException: Unrecognized field "system_id" (class com.hz.models.envoy.LogInResponse), not marked as ignorable (4 known properties: "is_consumer", "session_id", "message", "manager_token"]) at [Source: (String)"{"message":"success","session_id":"3086e4bae322887a5a1efdc613c20270","manager_token":"eyJhbGciOiJIUzI1NiJ9.eyJkYXRhIjp7InNlc3Npb25faWQiOiIzMDg2ZTRiYWUzMjI4ODdhNWExZWZkYzYxM2MyMDI3MCIsImNvbXBhbnlfaWQiOm51bGwsImVtYWlsX2lkIjoibWlzY0ByZXRsYXcubmV0IiwidXNlcl9pZCI6MjM5MjQ5MCwiY2xpZW50X2FwcCI6Iml0azMiLCJmaXJzdF9uYW1lIjoiSmFtZXMiLCJsYXN0X25hbWUiOiJTdXRoZXJsYW5kIiwibG9naW5fdXNlciI6bnVsbCwiaXNfZGlzdHJpYnV0b3IiOmZhbHNlfSwiZXhwIjoxNjk0NTMzOTA0LCJzdWIiOiJtaXNjQHJldGxhdy5uZXQifQ.aU_flbzO9FodCzfLr8xXcUwVY30r8K"[truncated 54 chars]; line: 1, column: 554] (through reference chain: com.hz.models.envoy.LogInResponse["system_id"]) at com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException.from(UnrecognizedPropertyException.java:61) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.DeserializationContext.handleUnknownProperty(DeserializationContext.java:1132) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.deser.std.StdDeserializer.handleUnknownProperty(StdDeserializer.java:2202) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownProperty(BeanDeserializerBase.java:1705) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownVanilla(BeanDeserializerBase.java:1683) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:320) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:177) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.deser.DefaultDeserializationContext.readRootValue(DefaultDeserializationContext.java:323) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4730) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3677) ~[jackson-databind-2.14.2.jar:2.14.2] at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3645) ~[jackson-databind-2.14.2.jar:2.14.2] at com.hz.utils.EnphaseJWTExtractor.postLogin(EnphaseJWTExtractor.java:79) ~[app/:na] at com.hz.utils.EnphaseJWTExtractor.fetchJWTV2(EnphaseJWTExtractor.java:165) ~[app/:na] at com.hz.services.EnvoyConnectionProxy.getSecureTemplate(EnvoyConnectionProxy.java:145) ~[app/:na] at com.hz.services.EnvoyService.getSystemData(EnvoyService.java:46) ~[app/:na] at com.hz.services.EnvoyService.collectEnphaseData(EnvoyService.java:57) ~[app/:na] at com.hz.services.OutputManager.gather(OutputManager.java:47) ~[app/:na] at jdk.internal.reflect.GeneratedMethodAccessor28.invoke(Unknown Source) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na] at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-6.0.8.jar:6.0.8] at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-6.0.8.jar:6.0.8] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na] at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[na:na] at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na] at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]`

HuweyII commented 1 year ago

Now with better formatting ....

2023-09-05T08:51:45.053-07:00 ERROR 7 --- [   scheduling-1] com.hz.services.EnvoyService             : Failed to retrieve Solar stats. Exception was Unrecognized field "system_id" (class com.hz.models.envoy.LogInResponse), not marked as ignorable (4 known properties: "is_consumer", "session_id", "message", "manager_token"])
 at [Source: (String)"{"message":"success","session_id":"3086e4bae322887a5a1efdc613c20270","manager_token":"eyJhbGciOiJIUzI1NiJ9.eyJkYXRhIjp7InNlc3Npb25faWQiOiIzMDg2ZTRiYWUzMjI4ODdhNWExZWZkYzYxM2MyMDI3MCIsImNvbXBhbnlfaWQiOm51bGwsImVtYWlsX2lkIjoibWlzY0ByZXRsYXcubmV0IiwidXNlcl9pZCI6MjM5MjQ5MCwiY2xpZW50X2FwcCI6Iml0azMiLCJmaXJzdF9uYW1lIjoiSmFtZXMiLCJsYXN0X25hbWUiOiJTdXRoZXJsYW5kIiwibG9naW5fdXNlciI6bnVsbCwiaXNfZGlzdHJpYnV0b3IiOmZhbHNlfSwiZXhwIjoxNjk0NTMzOTA0LCJzdWIiOiJtaXNjQHJldGxhdy5uZXQifQ.aU_flbzO9FodCzfLr8xXcUwVY30r8K"[truncated 54 chars]; line: 1, column: 554] (through reference chain: com.hz.models.envoy.LogInResponse["system_id"])

com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException: Unrecognized field "system_id" (class com.hz.models.envoy.LogInResponse), not marked as ignorable (4 known properties: "is_consumer", "session_id", "message", "manager_token"])
 at [Source: (String)"{"message":"success","session_id":"3086e4bae322887a5a1efdc613c20270","manager_token":"eyJhbGciOiJIUzI1NiJ9.eyJkYXRhIjp7InNlc3Npb25faWQiOiIzMDg2ZTRiYWUzMjI4ODdhNWExZWZkYzYxM2MyMDI3MCIsImNvbXBhbnlfaWQiOm51bGwsImVtYWlsX2lkIjoibWlzY0ByZXRsYXcubmV0IiwidXNlcl9pZCI6MjM5MjQ5MCwiY2xpZW50X2FwcCI6Iml0azMiLCJmaXJzdF9uYW1lIjoiSmFtZXMiLCJsYXN0X25hbWUiOiJTdXRoZXJsYW5kIiwibG9naW5fdXNlciI6bnVsbCwiaXNfZGlzdHJpYnV0b3IiOmZhbHNlfSwiZXhwIjoxNjk0NTMzOTA0LCJzdWIiOiJtaXNjQHJldGxhdy5uZXQifQ.aU_flbzO9FodCzfLr8xXcUwVY30r8K"[truncated 54 chars]; line: 1, column: 554] (through reference chain: com.hz.models.envoy.LogInResponse["system_id"])
        at com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException.from(UnrecognizedPropertyException.java:61) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.DeserializationContext.handleUnknownProperty(DeserializationContext.java:1132) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.deser.std.StdDeserializer.handleUnknownProperty(StdDeserializer.java:2202) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownProperty(BeanDeserializerBase.java:1705) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownVanilla(BeanDeserializerBase.java:1683) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:320) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:177) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.deser.DefaultDeserializationContext.readRootValue(DefaultDeserializationContext.java:323) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4730) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3677) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3645) ~[jackson-databind-2.14.2.jar:2.14.2]
        at com.hz.utils.EnphaseJWTExtractor.postLogin(EnphaseJWTExtractor.java:79) ~[app/:na]
        at com.hz.utils.EnphaseJWTExtractor.fetchJWTV2(EnphaseJWTExtractor.java:165) ~[app/:na]
        at com.hz.services.EnvoyConnectionProxy.getSecureTemplate(EnvoyConnectionProxy.java:145) ~[app/:na]
        at com.hz.services.EnvoyService.getSystemData(EnvoyService.java:46) ~[app/:na]
        at com.hz.services.EnvoyService.collectEnphaseData(EnvoyService.java:57) ~[app/:na]
        at com.hz.services.OutputManager.gather(OutputManager.java:47) ~[app/:na]
        at jdk.internal.reflect.GeneratedMethodAccessor28.invoke(Unknown Source) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
        at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
        at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-6.0.8.jar:6.0.8]
        at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-6.0.8.jar:6.0.8]
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
        at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[na:na]
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[na:na]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
        at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]
dlmcpaul commented 1 year ago

Ok, looks like they have added some fields to the login response. I have pushed a fix.

Do you want me to build a test docker image for you?

dlmcpaul commented 1 year ago

Should be fixed with the 0.28 release

HuweyII commented 1 year ago

Fix works great; thanks for the fast change. Great change too so this kind of thing won't bite again.