Error Parsing Time - Githubissues

mhop74 commented 5 years ago

I have, today, installed Kelvin in a Docker container. Everything seems to be working fine, but I will be monitoring to check that transitions configure in the Schedule are working as expected.

I do notice in the logs that there is a message every minute related to parsing the time:

time="2018/21/11 16:53:15" level=info msg="parsing time \"\" as \"15:04\": cannot parse \"\" as \"15\""
time="2018/21/11 16:54:15" level=info msg="parsing time \"\" as \"15:04\": cannot parse \"\" as \"15\""
time="2018/21/11 16:55:15" level=info msg="parsing time \"\" as \"15:04\": cannot parse \"\" as \"15\""
time="2018/21/11 16:56:15" level=info msg="parsing time \"\" as \"15:04\": cannot parse \"\" as \"15\""
time="2018/21/11 16:57:15" level=info msg="parsing time \"\" as \"15:04\": cannot parse \"\" as \"15\""
time="2018/21/11 16:58:15" level=info msg="parsing time \"\" as \"15:04\": cannot parse \"\" as \"15\""
time="2018/21/11 16:59:15" level=info msg="parsing time \"\" as \"15:04\": cannot parse \"\" as \"15\""

Will this cause any problems? Is there a solution? Thanks.

stefanwichmann commented 5 years ago

Hey, this is only an information message and should therefore be no problem.

To be sure and to identify the root cause: Could you start Kelvin with the -debug flag?

Thanks, Stefan

mhop74 commented 5 years ago

Thanks for the reply Stefan. I've changed my installation to have Kelvin run as systemd process rather than as a docker container. It seems a lot easier to know what it going on and has removed the info msg I was receiving.

stefanwichmann commented 5 years ago

Ok but strange... I'll close the issue for now.

sirwolfgang commented 5 years ago

I have been having the parsing error, seemingly off and on(or maybe just me noticing it) since I set it up over a month ago. Here is a loop of the error as seen in the debug log. I am installed via the /opt/kelvin as a service method.

DEBU[2019/18/04 20:48:31] 🎨 Updating scenes...
DEBU[2019/18/04 20:48:31] 🎨 Updating scene "Default (Kelvin)" for schedule "default"...
INFO[2019/18/04 20:48:31] parsing time "" as "15:04": cannot parse "" as "15"
DEBU[2019/18/04 20:48:32] 🎨 Successfully updated scene "Default (Kelvin)"
DEBU[2019/18/04 20:48:32] 💡 HueLight Living, Wall - Setting light state to 2632K and 72% brightness (TargetColorTemperature: 379, CurrentColorTemperature: 375, TargetColor: [0.466 0.412], CurrentColor: [0.464 0.412], TargetBrightness: 182, CurrentBrightness: 185, TransitionTime: 4)
DEBU[2019/18/04 20:48:32] 💡 HueLight Living, Wall - Light was successfully updated (TargetColorTemperature: 379, CurrentColorTemperature: 375, TargetColor: [0.466 0.412], CurrentColor: [0.464 0.412], TargetBrightness: 182, CurrentBrightness: 185, TransitionTime: 4)
INFO[2019/18/04 20:48:32] 💡 Light Living, Wall - Updated light state to 2632K at 72% brightness
DEBU[2019/18/04 20:48:32] 🤖 Light Living, Wall - Updated light state. Awaiting transition...
DEBU[2019/18/04 20:48:33] 💡 HueLight Living, Center - Setting light state to 2632K and 72% brightness (TargetColorTemperature: 379, CurrentColorTemperature: 375, TargetColor: [0.466 0.412], CurrentColor: [0.464 0.412], TargetBrightness: 182, CurrentBrightness: 185, TransitionTime: 4)
DEBU[2019/18/04 20:48:33] 💡 HueLight Living, Center - Light was successfully updated (TargetColorTemperature: 379, CurrentColorTemperature: 375, TargetColor: [0.466 0.412], CurrentColor: [0.464 0.412], TargetBrightness: 182, CurrentBrightness: 185, TransitionTime: 4)
INFO[2019/18/04 20:48:33] 💡 Light Living, Center - Updated light state to 2632K at 72% brightness
DEBU[2019/18/04 20:48:33] 🤖 Light Living, Center - Updated light state. Awaiting transition...
DEBU[2019/18/04 20:48:33] 💡 HueLight Entry - Setting light state to 2632K and 72% brightness (TargetColorTemperature: 379, CurrentColorTemperature: 375, TargetColor: [0.466 0.412], CurrentColor: [0.464 0.412], TargetBrightness: 182, CurrentBrightness: 185, TransitionTime: 4)
DEBU[2019/18/04 20:48:33] 💡 HueLight Entry - Light was successfully updated (TargetColorTemperature: 379, CurrentColorTemperature: 375, TargetColor: [0.466 0.412], CurrentColor: [0.464 0.412], TargetBrightness: 182, CurrentBrightness: 185, TransitionTime: 4)
INFO[2019/18/04 20:48:33] 💡 Light Entry - Updated light state to 2632K at 72% brightness
DEBU[2019/18/04 20:48:33] 🤖 Light Entry - Updated light state. Awaiting transition...
DEBU[2019/18/04 20:49:31] 💡 Light Living, Wall - Updated target light state for the interval 20:00 - 22:00 from {ColorTemperature:2632 Brightness:72} to {ColorTemperature:2616 Brightness:72}
DEBU[2019/18/04 20:49:31] 💡 Light Living, Center - Updated target light state for the interval 20:00 - 22:00 from {ColorTemperature:2632 Brightness:72} to {ColorTemperature:2616 Brightness:72}
DEBU[2019/18/04 20:49:31] 💡 Light Entry - Updated target light state for the interval 20:00 - 22:00 from {ColorTemperature:2632 Brightness:72} to {ColorTemperature:2616 Brightness:72}
DEBU[2019/18/04 20:49:31] 💡 Light Whale - Updated target light state for the interval 20:00 - 22:00 from {ColorTemperature:2632 Brightness:72} to {ColorTemperature:2616 Brightness:72}
DEBU[2019/18/04 20:49:31] 🎨 Updating scenes...
DEBU[2019/18/04 20:49:31] 🎨 Updating scene "Default (Kelvin)" for schedule "default"...
INFO[2019/18/04 20:49:31] parsing time "" as "15:04": cannot parse "" as "15"
DEBU[2019/18/04 20:49:32] 🎨 Successfully updated scene "Default (Kelvin)"

stefanwichmann commented 5 years ago

Reopening the issue.

Could you post your config.json file? It seems like there is an error in it. Thanks!

sirwolfgang commented 5 years ago

It's almost default, I have basically reset it each time I have upgraded. Edited in place with Nano, or sometimes with the WebGUI. I guessing its the "time": "", before sunrise part? Which is not something I think I personally edited.

{
  "version": 1,
  "bridge": {
    "ip": "10.0.0.41",
    "username": "Xc9fsxooQQyS9Cbuac13YFPA9t6x16bJiU2DVL-5"
  },
  "location": {
    "latitude": 37.7811,
    "longitude": -122.4625
  },
  "webinterface": {
    "enabled": true,
    "port": 8080
  },
  "schedules": [
    {
      "name": "default",
      "associatedDeviceIDs": [
        1,
        2,
        3,
        4
      ],
      "enableWhenLightsAppear": true,
      "defaultColorTemperature": 6500,
      "defaultBrightness": 100,
      "beforeSunrise": [
        {
          "time": "",
          "colorTemperature": 1500,
          "brightness": 60
        }
      ],
      "afterSunset": [
        {
          "time": "20:00",
          "colorTemperature": 3400,
          "brightness": 80
        },
        {
          "time": "22:00",
          "colorTemperature": 1500,
          "brightness": 60
        }
      ]
    }
  ]
}

sirwolfgang commented 5 years ago

I tried looking around, not sure what the issue is. My guess is it could be something about the web form resetting to the default of null, then saving it down. Either way, I think it might be sensible to or set NULL times with midnight.

stefanwichmann commented 5 years ago

The issue is the empty string for the "time" key under "beforeSunrise". In this form the configuration is invalid. You can fix the warning by entering valid timestamp in the format of the others.

The default timestamp for this would be "4:00".

sirwolfgang commented 5 years ago

The first Time input field doesn't look to the initalize right on my web GUI. If I click save schedule while it is in this default state, it then overwrites the "4:00" with "".

stefanwichmann commented 5 years ago

The tab "Schedules" in the webinterface displays the content of the config.json. If you have an empty timestamp in your configuration it will be displayed as seen above in the screenshot.

If you clear this field in the webinterface an empty (and invalid) value will be written to your config.json. After this you will see the warnings in the log...

There is certainly some room for improvement here and the webinterface could to some validation... PRs are welcome!

stefanwichmann / kelvin

Error Parsing Time #49