Error message: System.FormatException: Input string was not in a correct format. about myuplinksmartconnect

[gmeks]

Il look into it.

[gmeks]

Should be fixed in erlingsaeterdal/myuplinksmartconnect:latest

If you check the MQTT stuff it now has 2 new messages it sends, for logs and status

[TheAlpiner]

Hi,

Updated and so far so good :-)

I tried to put in subscription for the new messages but does not receive anything new. I put this in my yaml config:

- state_topic: "heater/LogEntry"
    name: "WaterHeater_MyUplinkSmartConnectLogs"
    unique_id: "WaterHeater_MyUplinkSmartConnectLogs"

- state_topic: "heater/ServiceStatus"
    name: "WaterHeater_MyUplinkSmartConnect status"
    unique_id: "WaterHeater_MyUplinkSmartConnectStatus"

But nothing is received. Am i doing something wrong or is it not updating in the same frequency? :-)

[gmeks]

No those new are only sendt on changes, but startup is considered a "change" and it will send "OK".

It feels like your on the old version, can you do a docker pull erlingsaeterdal/myuplinksmartconnect:latest

[TheAlpiner]

I did with the following response:

kjell@localhost-live myuplink]$ sudo docker pull erlingsaeterdal/myuplinksmartconnect:latest
[sudo] passord for kjell: 
latest: Pulling from erlingsaeterdal/myuplinksmartconnect
Digest: sha256:7ba5620d06908f6f95fd8f6299cf105cfbfc4493f3f7b68730e54327ca441527
Status: Image is up to date for erlingsaeterdal/myuplinksmartconnect:latest
docker.io/erlingsaeterdal/myuplinksmartconnect:latest
[kjell@localhost-live myuplink]$ 

Seems to be updated. I also tried with "heater/BerederVaskerom/LogEntry" just in case you had a typo ;-). But that did not work either. HM! is it me that is stupid and forgot something.... HM!

:-)

[gmeks]

Forgot to press comment yesterday. There is off course a change of typos, but thats why i use copy and paste. So the typos are consistent :)

There is a setting if you just wanna test, MQTTLogLevel that defaults to warning.

The idea is that heater/LogEntry and heater/ServiceStatus are seperate from the heater, incase the house has more then 1.

[TheAlpiner]

Looks like the error is not gone:

Starting myuplink_server_1 ... done
Attaching to myuplink_server_1
server_1  | [15:02:03 INF] Target Schedule change time is 17:17
server_1  | [15:02:03 INF] Starting up service
server_1  | [15:02:03 INF] Reading settings from environmental variables
server_1  | [15:02:03 INF] Reporting to MQTT is: True
server_1  | [15:03:04 INF] Found device with ID: HOIAX_##
server_1  | [15:17:08 ERR] Failed to run heater status job
server_1  | System.FormatException: Input string was not in a correct format.
server_1  |    at System.Number.ThrowOverflowOrFormatException(ParsingStatus status, TypeCode type)
server_1  |    at MyUplinkSmartConnect.ExternalPrice.BasePriceAPI.Parse(String input) in /src/myUplink/ExternalPrice/BasePriceAPI.cs:line 106
server_1  |    at MyUplinkSmartConnect.ExternalPrice.Nordpoolgroup.GetPriceInformation()
server_1  |    at MyUplinkSmartConnect.JobReScheuleheating.GetPriceInformation() in /src/myUplink/JobReScheuleheating.cs:line 26
server_1  |    at MyUplinkSmartConnect.JobReScheuleheating.Work() in /src/myUplink/JobReScheuleheating.cs:line 45
server_1  |    at MyUplinkSmartConnect.BackgroundJobSupervisor.WorkerSchedule() in /src/myUplink/BackgroundJobSupervisor.cs:line 166
server_1  | [15:19:10 INF] Found device with ID: HOIAX_##
server_1  | [15:19:11 INF] Found device with ID: HOIAX_##
server_1  | [15:20:12 INF] Found device with ID: HOIAX_##
server_1  | [15:20:12 ERR] Failed to run heater status job

Very strange, it works for some time and then suddenly it throws an error.

[gmeks]

Thats not from today is it?

The reason im a bit confured about the versions is that the callstack does not match with latest released version. The "Parse" function does not actualy parse, it just prepairs the string.

[TheAlpiner]

HM! Strange it is from yesterday afternoon. After i restarted and verified the latest release. I restarted again today just to see. No faults yet,

[12:42:33 INF] Target Schedule change time is 17:17
[12:42:33 INF] Starting up service
[12:42:33 INF] Reading settings from environmental variables
[12:42:33 INF] Reporting to MQTT is: True
[12:43:34 INF] Found device with ID: HOIAX_##

I also added those two lines:

- MQTTLogLevel=Verbose
- ConsoleLogLevel=Verbose

But I have not noticing any difference in the console outputs so maybe it is just me doing things i should not do. Obsviously something wrong :-)

This is the files from inside the running container. The newest from 21 July. If that is wrong something is really messed up with my docker solution :-)

root@80fc26f3e869:/app# ls -all
total 1344
drwxr-xr-x. 1 root root    960 Jul 21 10:37 .
drwxr-xr-x. 1 root root    158 Aug 16 12:42 ..
-rw-r--r--. 1 root root   6656 Jul 21 10:37 DetermenisticRandom.dll
-rw-r--r--. 1 root root  11208 Jul 21 10:37 DetermenisticRandom.pdb
-rwxr--r--. 1 root root  20480 Oct 13  2019 HashDepot.dll
-rwxr--r--. 1 root root 293376 Jul 12 16:46 MQTTnet.dll
-rwxr--r--. 1 root root  23112 Nov 15  2019 Microsoft.Win32.SystemEvents.dll
-rwxr-xr-x. 1 root root 142840 Jul 21 10:37 MyUplink-smartconnect
-rw-r--r--. 1 root root  19980 Jul 21 10:37 MyUplink-smartconnect.deps.json
-rw-r--r--. 1 root root 100352 Jul 21 10:37 MyUplink-smartconnect.dll
-rw-r--r--. 1 root root  38684 Jul 21 10:37 MyUplink-smartconnect.pdb
-rw-r--r--. 1 root root    242 Jul 21 10:37 MyUplink-smartconnect.runtimeconfig.json
-rwxr--r--. 1 root root 158208 Jun  7 15:41 RestSharp.dll
-rwxr--r--. 1 root root  34304 Nov 19  2021 Serilog.Sinks.Console.dll
-rwxr--r--. 1 root root 128000 Sep 10  2020 Serilog.dll
-rwxr--r--. 1 root root  49256 Nov 15  2019 System.Diagnostics.EventLog.dll
-rwxr--r--. 1 root root  30584 Nov 15  2019 System.ServiceProcess.ServiceController.dll
-rwxr--r--. 1 root root  73728 Dec  6  2020 TopShelf.ServiceInstaller.dll
-rwxr--r--. 1 root root  10752 Dec  6  2020 Topshelf.Serilog.dll
-rwxr--r--. 1 root root 194048 Dec  6  2020 Topshelf.dll
-rwxr-xr-x. 1 root root    398 Jul 18 15:24 appsettings.Development.json
-rwxr-xr-x. 1 root root    369 Jul 18 15:06 appsettings.json
drwxr-xr-x. 1 root root      6 Jul 21 10:37 runtimes
root@80fc26f3e869:/app# 

[gmeks]

Something is odd yea. MyUplink-smartconnect.dll would be the dll that should be very close to todays date.

If this docker host is dedicated this. You can run the following commands, that will reset docker ( all data is lost).

docker stop $(docker ps -a -q)
docker rm $(docker ps -a -q)
docker rmi $(docker images -q)
docker volume rm $(docker volume ls -q)
docker network rm $(docker network ls -q)

Inside my docker, but im running a test version from today:

root@2ad12d2baf9a:/app# ls -all
total 1364
drwxr-xr-x 1 root root 4096 Aug 16 12:23 .
drwxr-xr-x 1 root root 4096 Aug 16 12:26 ..
-rw-r--r-- 1 root root 6656 Aug 16 12:23 DetermenisticRandom.dll
-rw-r--r-- 1 root root 11208 Aug 16 12:23 DetermenisticRandom.pdb
-rwxr--r-- 1 root root 20480 Oct 13 2019 HashDepot.dll
-rwxr--r-- 1 root root 297472 Aug 3 20:55 MQTTnet.dll
-rwxr--r-- 1 root root 23112 Nov 15 2019 Microsoft.Win32.SystemEvents.dll
-rwxr-xr-x 1 root root 142840 Aug 16 12:23 MyUplink-smartconnect
-rw-r--r-- 1 root root 19980 Aug 16 12:23 MyUplink-smartconnect.deps.json
-rw-r--r-- 1 root root 104960 Aug 16 12:23 MyUplink-smartconnect.dll
-rw-r--r-- 1 root root 40200 Aug 16 12:23 MyUplink-smartconnect.pdb
-rw-r--r-- 1 root root 242 Aug 16 12:23 MyUplink-smartconnect.runtimeconfig.json
-rwxr--r-- 1 root root 158208 Jun 7 15:41 RestSharp.dll
-rwxr--r-- 1 root root 34304 Nov 19 2021 Serilog.Sinks.Console.dll
-rwxr--r-- 1 root root 128000 Sep 10 2020 Serilog.dll
-rwxr--r-- 1 root root 49256 Nov 15 2019 System.Diagnostics.EventLog.dll
-rwxr--r-- 1 root root 30584 Nov 15 2019 System.ServiceProcess.ServiceController.dll
-rwxr--r-- 1 root root 73728 Dec 6 2020 TopShelf.ServiceInstaller.dll
-rwxr--r-- 1 root root 10752 Dec 6 2020 Topshelf.Serilog.dll
-rwxr--r-- 1 root root 194048 Dec 6 2020 Topshelf.dll
-rwxr-xr-x 1 root root 398 Jul 18 15:24 appsettings.Development.json
-rwxr-xr-x 1 root root 369 Jul 18 15:06 appsettings.json
drwxr-xr-x 3 root root 4096 Aug 16 12:23 runtimes

[TheAlpiner]

HM! I am not a docker guru so this might be my lack of knowledge but if i download using ":latest" i will get an older version than if i use ":1.0.0.14" (The latest version i found) :

REPOSITORY                             TAG        IMAGE ID       CREATED         SIZE
erlingsaeterdal/myuplinksmartconnect   1.0.0.14   a29ede861278   2 hours ago     189MB
erlingsaeterdal/myuplinksmartconnect   latest     9a1f2a433be5   3 weeks ago     189MB

So maybe this will do the trick. I do not know how the ":latest" is managed but something strange is going on :-)

Anyway my output changed:

Starting myuplink_server_1 ... done
Attaching to myuplink_server_1
server_1  | [14:36:42 INF] Target Schedule change time is 17:17
server_1  | [14:36:42 INF] Starting up service, detected version is 1.0.0.14
server_1  | [14:36:42 INF] Reading settings from environmental variables
server_1  | [14:36:42 INF] Reporting to MQTT is: True

So maybe something different will happen now :-)

[TheAlpiner]

Lo and behold ... the messages are coming trough hehe...

Should the latest parameter really pull and old image... very strange. Welll seems to work now when i got the latest release. Sorry about this if this one is on me :-)

[gmeks]

Basicly the last part of the image ( latest / 1.0.0.014 ) is just text. So atm latest basicly means .13 . So latest should be from a few days ago.
There is somthing wrong with your setup where the latest tag is not getting updated...

.14 is a "hidden" version thats im testing.

[TheAlpiner]

OK, i changed it to 13 :-)

And i understand that latest is something i probably should not use (https://vsupalov.com/docker-latest-tag/). Have not experienced before that latest is pulling an old version but there is a first time for everything :-)

Status: Downloaded newer image for erlingsaeterdal/myuplinksmartconnect:1.0.0.13
Recreating myuplink_server_1 ... done
Attaching to myuplink_server_1
server_1  | [15:26:20 INF] Target Schedule change time is 17:17
server_1  | [15:26:20 INF] Starting up service
server_1  | [15:26:21 INF] Reading settings from environmental variables
server_1  | [15:26:21 INF] Reporting to MQTT is: True
server_1  | [15:26:24 INF] Found device with ID: HOIAX_##
server_1  | [15:26:26 INF] Changed schedule for HOIAX_## for today and tomorrow

The messages are still coming trough so that is ok. But no extended logging is done. Even with those parameters in the compose.yaml

- MQTTLogLevel=Verbose
- ConsoleLogLevel=Verbose

But that is probably also my fault. So i give that a rest. :-)

[gmeks]

Nope log level was a bug on my side, erlingsaeterdal/myuplinksmartconnect:1.0.0.15 fixes it.

[TheAlpiner]

OK, i will try .15 today. But i experienced som peculiar behaviour with .13. This is the complete log from yesterdays start with .13

[15:26:20 INF] Target Schedule change time is 17:17
[15:26:20 INF] Starting up service
[15:26:21 INF] Reading settings from environmental variables
[15:26:21 INF] Reporting to MQTT is: True
[15:26:24 INF] Found device with ID: HOIAX_someheater
[15:26:26 INF] Changed schedule for HOIAX_someheater for today and tomorrow
[07:43:11 WRN] When doing stats update for water heaters, 0 stats items where sendt
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:00 ERR] Failed to parse double from string -
[15:18:01 WRN] Failed to get price information for tomorrow, will only be able to change todays schedule
[15:18:01 INF] Found device with ID: HOIAX_someheater
[15:18:03 INF] Changed schedule for HOIAX_someheater for today
[15:18:03 INF] Found device with ID: HOIAX_someheater
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 ERR] Failed to parse double from string -
[15:19:04 WRN] Failed to get price information for tomorrow, will only be able to change todays schedule
[15:19:04 INF] Found device with ID: HOIAX_someheater
[15:19:06 INF] Changed schedule for HOIAX_someheater for today
[15:19:06 INF] Found device with ID: HOIAX_someheater
[15:20:08 INF] Found device with ID: HOIAX_someheater
[15:20:10 INF] Changed schedule for HOIAX_someheater for today and tomorrow
[15:20:10 INF] Found device with ID: HOIAX_someheater

If you can make some sense of it. Everything seems to stop after 15:20. I restarted with .15 now at 20:14.

[TheAlpiner]

I think the error is following me. This is with .15. Or is this normal behaviour. Below is the log, i cut the top with the password etc.:

[20:19:42 DBG] Environmental variable mqttloglevel - Verbose
[20:19:42 DBG] Environmental variable consoleloglevel - Verbose
[20:19:42 INF] Reporting to MQTT is: True
[20:19:43 DBG] Environmental variable isinsidedocker - 1
[20:19:43 DBG] Last schedule was 27.045323625861112 hours ago and above minimum hour for schedule start True
[20:19:44 DBG] Failed to get updated price information, from EU API. Checking nordpool
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:45 ERR] Failed to parse double from string -
[20:19:46 WRN] Failed to get price information for tomorrow, will only be able to change todays schedule
[20:19:46 DBG] Login is required, no old bear token found
[20:19:46 DBG] Login via API got new token
[20:19:46 INF] Found device with ID: HOIAX_someheater
[20:19:48 INF] Changed schedule for HOIAX_someheater for today
[20:19:48 DBG] Sending update BerederVaskerom - LastScheduleChangeInHours - 0
[20:19:48 DBG] Schedule is now failed
[20:19:48 DBG] Sending update BerederVaskerom - LastScheduleChangeInHours - 27
[20:19:48 DBG] Updated status for 1 devices
[20:19:48 DBG] Next status update in 0.108578515 should update now False

[gmeks]

You have some odd issue that its not getting the price information. You can leave it running when this happens, it should retry downloading price information untill it works.

Im not sure why that happens for you, but i created erlingsaeterdal/myuplinksmartconnect:1.0.0.16 so it can read price information from VG.

[TheAlpiner]

I think you are right it always updates the schedule but for some reason fails sometimes fetching the prices. I do not think it ever has missed updating the schedule so it works ok in that sense. Was just curious about the error messages. This is the log after yesterdays restart (and i have now removed the verbose log settings). It looks very quiet now.

[10:47:12 INF] Target Schedule change time is 17:17
[10:47:12 INF] Starting up service, detected version is 1.0.0.15
[10:47:12 INF] Reading settings from environmental variables
[10:47:12 INF] MQTTLogLevel cannot be more verbose then console, moving Console log to Information
Setting console log level to Information
[10:47:12 INF] Reporting to MQTT is: True
[10:48:13 INF] Found device with ID: HOIAX_##
[17:17:56 INF] Found device with ID: HOIAX_##
[17:17:58 INF] Changed schedule for HOIAX_##
[17:17:58 INF] Found device with ID: HOIAX_##

I am still very happy with it. Very neat and smart little app :-)

[gmeks]

It should not be critical that it fails to get price information, it will just retry a bit later.

But its importent that people check the logs, if nobody reports issues they will not get fixed. I dont have any analytics.