Can't log into HomeAssistant API, Samba share not displaying, PuTTY works - Update: Let's Encrypt being weird

Wheezy · January 11, 2018, 6:12am

Hey everybody,

This just started happening a few hours ago. Nothing on my network changed. HASSIO is on a wired connection, local IP is reserved in my router. Router and Modem are working.
I can PuTTY into HASSIO on the Pi. The last thing I did was updated a sensor to use weather underground instead of darksky (I don’t think this is the issue).

My automations were triggered normally when I came home, but the server still wouldn’t let me log in from the API. I also noticed that Samba share won’t announce itself to Windows, even though it is still accessible via \\HASSIO\ via Windows Explorer (I mean the Windows file browser, not the internet browser). I use duckdns, but its IP matches my modem’s current IP and nothing seems out of sorts on the duckdns website.

I softbooted homeassistant a couple times from hassio, then reset the pi, then hard booted the pi, reset the router/modem/pi. Still getting this in my log (viewable from hassio/PuTTY)

Is it possible someone figured out my weak login password and changed it from my homeassistant setup website? (configuration.yaml still shows the correct password under api_password:)

I’m stumped. Any help would be super appreciated. Thank you all in advance

home-assistant.log:

2018-01-10 21:51:17 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=113 from 2018-01-11 04:39:44.727660)
2018-01-10 21:51:33 WARNING (MainThread) [homeassistant.setup] Setup of notify is taking over 10 seconds.
2018-01-10 21:51:35 WARNING (MainThread) [homeassistant.setup] Setup of sensor is taking over 10 seconds.
2018-01-10 21:51:37 WARNING (MainThread) [homeassistant.setup] Setup of media_player is taking over 10 seconds.
2018-01-10 21:51:37 WARNING (MainThread) [homeassistant.setup] Setup of switch is taking over 10 seconds.
2018-01-10 21:51:40 WARNING (MainThread) [homeassistant.setup] Setup of tts is taking over 10 seconds.
2018-01-10 21:51:59 WARNING (MainThread) [homeassistant.components.media_player] Setup of platform cast is taking over 10 seconds.

Log from PuTTY:

core-ssh:~# hassio homeassistant logs
decrypt_verify(): found 294 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 294 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
2018-01-10 21:56:02 INFO (MainThread) [homeassistant.components.media_player.kodi] Unable to connect to Kodi via websocket
2018-01-10 21:56:13 INFO (MainThread) [homeassistant.components.media_player.kodi] Unable to connect to Kodi via websocket
2018-01-10 21:56:24 INFO (MainThread) [homeassistant.components.media_player.kodi] Unable to connect to Kodi via websocket
2018-01-10 21:56:30 INFO (SyncWorker_1) [homeassistant.components.switch.flux] Lights updated to mired:434 brightness:133, 100% of night cycle complete at 2018-01-10 21:56:30.773510-08:00
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sun.sun, old_state=<state sun.sun=below_horizon; next_dawn=2018-01-11T14:59:59+00:00, next_dusk=2018-01-12T01:02:33+00:00, next_midnight=2018-01-11T08:01:36+00:00, next_noon=2018-01-11T20:01:16+00:00, next_rising=2018-01-11T15:33:51+00:00, next_setting=2018-01-12T00:28:41+00:00, elevation=-54.74, azimuth=302.8, friendly_name=Solar angle @ 2018-01-10T21:51:27.385824-08:00>, new_state=<state sun.sun=below_horizon; next_dawn=2018-01-11T14:59:59+00:00, next_dusk=2018-01-12T01:02:33+00:00, next_midnight=2018-01-11T08:01:36+00:00, next_noon=2018-01-11T20:01:16+00:00, next_rising=2018-01-11T15:33:51+00:00, next_setting=2018-01-12T00:28:41+00:00, elevation=-54.89, azimuth=303.11, friendly_name=Solar angle @ 2018-01-10T21:51:27.385824-08:00>>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.livingroom_1, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-110>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.livingroom_2, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-111>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.livingroom_3, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-112>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.livingroom_4, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-113>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.kitchen_1, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-114>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.kitchen_2, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-115>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.kitchen_table_1, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-116>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.kitchen_table_2, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-117>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.hallway, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-118>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.bedroom_1, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-119>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.bedroom_2, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-120>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.bathroom_1, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-121>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.bathroom_2, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-122>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.bathroom_3, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-123>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.bathroom_4, transition=30, brightness=133, color_temp=434, service_call_id=1965478352-124>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-110>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-111>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-112>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-113>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-114>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-115>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-116>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-117>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-118>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-119>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-120>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-121>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-122>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-123>
2018-01-10 21:56:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=1965478352-124>
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 294 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 291 bytes cleartext
decrypt_verify(): found 291 bytes cleartext
decrypt_verify(): found 297 bytes cleartext
decrypt_verify(): found 297 bytes cleartext
decrypt_verify(): found 289 bytes cleartext
decrypt_verify(): found 291 bytes cleartext
decrypt_verify(): found 291 bytes cleartext
decrypt_verify(): found 292 bytes cleartext
decrypt_verify(): found 292 bytes cleartext
decrypt_verify(): found 292 bytes cleartext
decrypt_verify(): found 292 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 294 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 294 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 294 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 294 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
decrypt_verify(): found 8 bytes cleartext
2018-01-10 21:56:35 INFO (MainThread) [homeassistant.components.media_player.kodi] Unable to connect to Kodi via websocket
2018-01-10 21:56:46 INFO (MainThread) [homeassistant.components.media_player.kodi] Unable to connect to Kodi via websocket
2018-01-10 21:56:57 INFO (MainThread) [homeassistant.components.media_player.kodi] Unable to connect to Kodi via websocket

Update: Updating HASS to the latest version via PuTTY\HASSIO doesn’t help :[

ih8gates · January 11, 2018, 2:52pm

I bet that the login challenge you’re seeing is cached. If you clear cache and reload that URL, you won’t connect. I don’t think it’s a password issue - it’s acting like HA hasn’t started for some reason or is inaccessible.

When you putty in, what happens if you issue: hassio ha check to check your config. A hassio ha info might be informative, too.

If it’s not an issue with HA starting up, you might have a network config issue. Check port forwarding (if applicable) and the settings for http: in your config yaml. Could also be a LetsEncrypt issue.

NotoriousBDG · January 11, 2018, 3:02pm

It might be an issue with NAT loopback on your router. Try adding your duckdns IP with your private IP to your hosts file to see if that makes it work.

Wheezy · January 11, 2018, 3:41pm

Thanks for the lead on the cache! I have access again. Although now I can’t figure out what went wrong with Let’sEncrypt

The problem threw me since both iPhone and Chrome both stopped being able to log in. I tried logging in with Internet Explorer (which I never use, so it doesn’t have any cached files):

Internet Explorer:

After clearing my Chrome cache:

Let’s Encrypt appeared to have disabled itself after not being able to renew my security certificate:

I found this in the Let’sEncrypt log:

starting version 3.2.2
Saving debug log to /var/log/letsencrypt/letsencrypt.log
-------------------------------------------------------------------------------
Processing /data/letsencrypt/renewal/xxxxxxxx.duckdns.org.conf
-------------------------------------------------------------------------------
Cert is due for renewal, auto-renewing...
Renewing an existing certificate
Performing the following challenges:
Client with the currently selected authenticator does not support any combination of challenges that will satisfy the CA.
Attempting to renew cert from /data/letsencrypt/renewal/xxxxxxxx.duckdns.org.conf produced an unexpected error: Client with the currently selected authenticator does not support any combination of challenges that will satisfy the CA.. Skipping.
All renewal attempts failed. The following certs could not be renewed:
  /data/letsencrypt/live/xxxxxxxx.duckdns.org/fullchain.pem (failure)
1 renew failure(s), 0 parse failure(s)

I restarted Let’sEncrypt and got the same error log messages, then noticed that Let’sEncrypt shut itself off again.

I searched the Let’sEncrypt error and noticed DavidFW1960 had fixed Let’s Encrypt after having a similar problem just yesterday (same time as me). He changed the challenge in Let’sEncrypt Options from https to http. Worked for me too.

starting version 3.2.2
Saving debug log to /var/log/letsencrypt/letsencrypt.log
-------------------------------------------------------------------------------
Processing /data/letsencrypt/renewal/xxxxx.duckdns.org.conf
-------------------------------------------------------------------------------
Cert is due for renewal, auto-renewing...
Renewing an existing certificate
Performing the following challenges:
http-01 challenge for xxxxx.duckdns.org
Waiting for verification...
Cleaning up challenges
-------------------------------------------------------------------------------
new certificate deployed without reload, fullchain is
/data/letsencrypt/live/xxxxx.duckdns.org/fullchain.pem
-------------------------------------------------------------------------------
Congratulations, all renewals succeeded. The following certs have been renewed:
  /data/letsencrypt/live/xxxxx.duckdns.org/fullchain.pem (success)

So, I can log in fine now, and my cert is supposedly renewed, but Chrome browser still says my cert is expired as of yesterday even though I updated the cert in Let’s Encrypt. ¯_(ツ)_/¯

It’s working at least.

ih8gates · January 11, 2018, 3:59pm

Glad you got that sorted.

I recently moved from AIO to Hassio. Haven’t had it set up long enough for my cert to update.

With the challenge set to HTTP, are you leaving port 80 permanently forwarded to your HASS?
How do you switch the challenge to HTTP? I see the network settings for the addon - mine are set to 80/443.

Incidentally, the addon says “state: stopped”, but I’m getting SSL.

ih8gates · January 11, 2018, 4:01pm

Answering my own qestion. Didn’t realize that setting was in the options JSON.

github.com

home-assistant/addons/blob/master/letsencrypt/README.md

# Home Assistant Add-on: Letsencrypt

Let's Encrypt is a certificate authority that provides free X.509 certificates for Transport Layer Security encryption via an automated process designed to eliminate the hitherto complex process of manual creation, validation, signing, installation, and renewal of certificates for secure websites.

![Supports aarch64 Architecture][aarch64-shield] ![Supports amd64 Architecture][amd64-shield] ![Supports armhf Architecture][armhf-shield] ![Supports armv7 Architecture][armv7-shield] ![Supports i386 Architecture][i386-shield]

Setting up Letsencrypt allows you to use validated certificates for your webpages and web-interfaces.
It requires you to own the domain you are requesting the certificate for.

The generated certificate can be used within others addons. By default the path and file for the certificates within other addons will refer to the files generated within this addon.

[discord]: https://discord.gg/c5DvZ4e
[forum]: https://community.home-assistant.io
[issue]: https://github.com/home-assistant/hassio-addons/issues
[certbot]: https://certbot.eff.org
[reddit]: https://reddit.com/r/homeassistant

[aarch64-shield]: https://img.shields.io/badge/aarch64-yes-green.svg
[amd64-shield]: https://img.shields.io/badge/amd64-yes-green.svg
[armhf-shield]: https://img.shields.io/badge/armhf-yes-green.svg

This file has been truncated. show original

Wheezy · January 11, 2018, 4:05pm

Hey, ih8gates, thanks again for the reply that got me on the right track.
I didn’t post my Options area before, but it looks like this now.

I also forgot to mention I’m running the latest HASS 0.60.1.

Update: After restarting HASS and waiting about and hour(?) everything is working perfectly again. Ignore the below text

The problem isn’t actually fixed, since Let’s Encrypt and http certificates are still acting strange, but at least I can log in and have control of my home again.

Pictured: Security cert still out of date after updating cert with http challenge (instead of https challenge) and deleting my Chrome browser cache.