Core: Nabu Casa error - Remote UI unreachable

[rschuiling]

Home Assistant release with the issue:
0.103.6

Last working Home Assistant release (if known):
0.103.5

Operating environment (Hass.io/Docker/Windows/etc.):
Hass.io on Ubuntu host

Integration:

Description of problem:
After upgrading to 0.103.6 (from .5) the GUI in unreachable from its Nabu Casa URL. It is still reachable on its DuckDNS url.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

Traceback (if applicable):
Errors in log, persising after Docker restarts:

2020-01-07 19:12:41 ERROR (MainThread) [hass_nabucasa.remote] Can't handle request-connection without backend
2020-01-07 19:12:41 ERROR (MainThread) [hass_nabucasa.iot] Error handling message
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot.py", line 90, in _async_handle_handler_message
    result = await handler(self.cloud, message["payload"])
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot.py", line 143, in async_handle_remote_sni
    await cloud.remote.handle_connection_requests(caller_ip)
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/remote.py", line 216, in handle_connection_requests
    raise RemoteNotConnected()
hass_nabucasa.remote.RemoteNotConnected

Additional information:
Edit: downgrading to 0.103.5 immediately fixed this issue. Definitely seems to be related to 0.103.6 then.
Edit2: seems it's not related to 0.103.6 after all. Now on 0.103.5, after most HA restarts the remote UI is unreachable for me. Logs are below in the comments.

[probot-home-assistant[bot]]

Hey there @home-assistant/cloud, mind taking a look at this issue as its been labeled with a integration (cloud) you are listed as a codeowner for? Thanks!

[balloob]

103.6 only made changes to the cloud integration related to Google (https://github.com/home-assistant/home-assistant/pull/30525/files). Do you have any other errors in your logs ?

[fillwe]

I have had issues since 103 with remote ui sometimes being unavailable. It comes back at random intervals. Google working fine though. Have started using my own domain for now to see if it solves itself, but seen a couple of people in discord and the forums reporting this

[rschuiling]

@balloob No, this is a full copy-paste of the log after the last restart. The restart before that had some standard warnings about the 'dangers' of custom components (spotcast, afvalwijzer).

Forum topic where some more people are reporting this issue: https://community.home-assistant.io/t/nabu-casa-remote-ui-connection-not-always-available/140300/11

[pvizeli]

I need the full log of startup with debug logging. Otherwise I can't say why the backend was not setup.

[rschuiling]

My issue has changed somewhat: I do not see the nabucasa errors I mentioned in the description. But my front end is unreachable after 50% of the restarts. So I have to restart twice to get into the front-end. Edit: this is not consistent behaviour; right now I can't get the front-end to load through the nabu casa URL at all, not even after 3 restarts. The frontend is reachable through the duckdns URL though.

home-assistant.log

@pvizeli Is this debug log sufficient for you to see what is causing the remote UI not to connect?

[rschuiling]

Is there anything else I can do to help this along?

[pvizeli]

What I see in your log is, that the code is never called like they will not exists. Can you remove the dept folder inside config?

[rschuiling]

I don't see a dept folder. Do you mean the deps folder? This one is present and empty. Do you want me to remove it? Presently, the remote UI is functioning just fine.

[pvizeli]

Okay. I close the issue and we can try to debug it again if you see the issue 👍

[rschuiling]

@pvizeli Right now; after every restart the Remote UI is unreachable (whereas the .duckdns-URL is reachable at the same time). If I simply wait for a long time (30-60 minutes is my feeling), eventually the remote-UI starts functioning. I am running a trace log right now, waiting for the Remote UI to come up. Would you prefer a new issue or should we continue with this one?

Edit: I have waited for almost two hours this time, the remote UI is still not reachable for me. I can't upload the log here unfortunately, it's too big (50+MB). Do you have any suggestions to pinpoint the issue here?

Edit2: Here are 2 log files:
1) log where remote UI was unreachable for 2+ hours after restart https://www.dropbox.com/s/2n8i9h2wn7w338j/home-assistant_no_remote_ui_after_2hrs.log?dl=0

2) log where remote UI was available right after restart
https://www.dropbox.com/s/gvbno273m8b7tuw/home-assistant_remote_ui_up%20after%20restart.log?dl=0

Can you see a difference? What is the cause that my remote UI URL often is unreachable after restarting?

[jorismocka]

Hi @pvizeli
I have exactly the Same issue @rschuiling is describing.

There are Logs like this:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot.py", line 90, in _async_handle_handler_message
result = await handler(self.cloud, message["payload"])
File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot.py", line 143, in async_handle_remote_sni
await cloud.remote.handle_connection_requests(caller_ip)
File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/remote.py", line 216, in handle_connection_requests
raise RemoteNotConnected()
hass_nabucasa.remote.RemoteNotConnected

Any Help is appreciated and thanks a Lot for your work! Joris

[jorismocka]

Here another Log:

Unexpected error processing request for /api/cloud/login
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/cloud/http_api.py", line 129, in error_handler
result = await handler(view, request, args, *kwargs)
File "/usr/src/homeassistant/homeassistant/components/http/data_validator.py", line 48, in wrapper
result = await method(view, request, args, *kwargs)
File "/usr/src/homeassistant/homeassistant/components/cloud/http_api.py", line 196, in post
await cloud.login(data["email"], data["password"])
File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/__init__.py", line 182, in login
await self.start()
File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/__init__.py", line 240, in start
await self.client.logged_in()
File "/usr/src/homeassistant/homeassistant/components/cloud/client.py", line 121, in logged_in
gconf.async_enable_local_sdk()
File "/usr/src/homeassistant/homeassistant/components/google_assistant/helpers.py", line 205, in async_enable_local_sdk
self.hass, DOMAIN, "Local Support", webhook_id, self._handle_local_webhook,
File "/usr/src/homeassistant/homeassistant/components/webhook/__init__.py", line 33, in async_register
raise ValueError("Handler is already defined!")
ValueError: Handler is already defined!

[balloob]

@jorismocka HA version?

[jorismocka]

0.103.6 is it.
Thank you

All the best
Joris

Paulus Schoutsen [e-mail] schrieb am Sa., 25. Jan. 2020,
01:14:

@jorismocka https://github.com/jorismocka HA version?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/home-assistant/home-assistant/issues/30555?email_source=notifications&email_token=AOHNZ5WPB3UI2HIDYICEACDQ7OAABA5CNFSM4KD5HY62YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEJ4PAEY#issuecomment-578351123,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AOHNZ5TYIZTKQR6KCNPXITTQ7OAABANCNFSM4KD5HY6Q
.

[rschuiling]

This really is an issue for me: after most restarts I am unable to use the Remote UI. Can this get some attention? Should I open a new issue for this?

[pvizeli]

hass_nabucasa.remote.RemoteNotConnected means they was not loaded. The error why is not loaded is in that case the question they we search and should be in the log after start.

@jorismocka yes, the issue with async_enable_local_sdk stop to process the connection and the reason why it not is loaded after start.

[pvizeli]

@rschuiling if the remote does not work, the code was never executed what I can see in your logs. Do you have any kind of custom component running or other modifications? The log output looks like an old version of hass-nabucasa python library.

[jorismocka]

hass_nabucasa.remote.RemoteNotConnected means they was not loaded. The error why is not loaded is in that case the question they we search and should be in the log after start.

@jorismocka yes, the issue with async_enable_local_sdk stop to process the connection and the reason why it not is loaded after start.

@pvizeli thank you for reopening this issue. It really prevents me from restarting my hass.io because I'm afraid to loose my remote access. What is async_enable_local_sdk part of? Code of the Remote UI? Or a third party tool? Thanks a lot.

[rschuiling]

@pvizeli I am running Hass.io on Ubuntu, HA 0.103.5 with Hass.io supervisor v195. My custom components are HACS (0.20.8 = latest), Spotcast (2.6.1 = latest), Afvalwijzer (3.0.12 = not latest).

The remote UI issue occurs in 0.103.6 and 0.103.5. How can I upgrade to the newest version of hass-nabucasa python library? Upgrading HA?

[fillwe]

As i mentioned earlier i am having the same issues. I am also running Hass.io on Ubuntu, HA 0.104.3 with Hass.io supervisor v195. My custom components are HACS (0.20.9 = latest), Amazon Rekognition 103, Krisinformation 95fe9d2, Unifi Gateway v0.2.3. Have tried uninstalling them all as well as Custom header and card tools. The remote UI problems started for me after 102. Should i provide som logs as well?

[pvizeli]

If you said after restart. Do you means after restart the core or the full device?

@fillwe yes but I need only the log (debug) from hass_nabucasa. all other is not needed. So I can verify if it is the same issue as @rschuiling. Please provide also the ouput of hassio info.

[jorismocka]

If I perform an "hassio ha restart" on CLI - not if I'm restarting the whole device.
In the mean time I upgraded to 0.104.3 and the error did not occur until now!

[rschuiling]

I also mean a restart of core HA. I also restarted the device (Ubuntu) once, but that didn't make any difference for the issue.

[MichielvanBeers]

Hi,

I'm experiencing the same issue: after reboot the whole system the remote connection is unreachable for quite some time. I've also contacted support about this, but thusfar we haven't been able to solve it.
In my configuration Nabu Casa starts working again when I disable _Amazon Polly TTS_. Are more people here using that integration?

I'm on Hass 0.104.1 BTW.

[rschuiling]

I am indeed using Amazon Polly. Will try if disabling it soon.

[jorismocka]

I'm not using Amazon Polly TTS just builtin Google TTS.

[balloob]

For people chiming in on this issue that they also experience this, we need logs or we can't determine the issue.

[MichielvanBeers]

Ah of course, my apologies.

Home Assistant release with the issue:: 0.103.5 & 0.104.3

Operating environment (Hass.io/Docker/Windows/etc.): Hass.io on Raspberry Pi 3

I'm in touch with the Nabu Casa support team. They recommended to match my AWS server option with the Nabu Casa one, changing it from eu-west-3 to eu-central-1. This made the connection sometimes work as normal, but most of the time it was still unable to connect.

Log file when remote UI is not available

ps Sorry for the crappy lay-out. I've copy pasted this from the e-mail conversation with the Nabu Casa support, since I don't have the most recent logs at hand anymore.

Error handling message
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot.py", line 90, in _async_handle_handler_message
    result = await handler(self.cloud, message["payload"])
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot.py", line 143, in async_handle_remote_sni
    await cloud.remote.handle_connection_requests(caller_ip)
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/remote.py", line 216, in handle_connection_requests
    raise RemoteNotConnected()
hass_nabucasa.remote.RemoteNotConnected

Can't handle request-connection without backend

Log when remote UI _is_ available

Unexpected error
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot_base.py", line 108, in connect
    await self._handle_connection()
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/iot_base.py", line 147, in _handle_connection
    await self.cloud.auth.async_check_token()
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/auth.py", line 145, in async_check_token
    await self.cloud.run_executor(self._check_token)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/auth.py", line 160, in _check_token
    access_token=self.cloud.access_token, refresh_token=self.cloud.refresh_token
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/auth.py", line 217, in _cognito
    **kwargs,
  File "/usr/local/lib/python3.7/site-packages/warrant/__init__.py", line 172, in __init__
    self.client = boto3.client('cognito-idp', **boto3_client_kwargs)
  File "/usr/local/lib/python3.7/site-packages/boto3/__init__.py", line 91, in client
    return _get_default_session().client(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/boto3/session.py", line 263, in client
    aws_session_token=aws_session_token, config=config)
  File "/usr/local/lib/python3.7/site-packages/botocore/session.py", line 827, in create_client
    credentials = self.get_credentials()
  File "/usr/local/lib/python3.7/site-packages/botocore/session.py", line 426, in get_credentials
    'credential_provider').load_credentials()
  File "/usr/local/lib/python3.7/site-packages/botocore/session.py", line 907, in get_component
    del self._deferred[name]
KeyError: 'credential_provider'

[cogneato]

@MichielvanBeers

Can you (and anyone else) change the logger: integration as shown here?

logger:
  default: info
  logs:
    hass_nabucasa: debug
    snitun: debug
    homeassistant.components.cloud: debug
    homeassistant.components.cloud.iot: debug

[MichielvanBeers]

@cogneato

I already had my logger set to that configuration. So the logs you see above, is the info that was logged when I changed my settings to yours. Let me know if I can do anything else.

[Larry0ua]

Also experience the connection problem to Remote UI. Though that that is a limitation of trial period, but looks like there is some issue.
Yesterday and day before yesterday there were power failures in my place, and after device running HA was online again it never appeared connected via nabu.casa URL. Actually when I tried to open the remote UI from HASS application on Android it suggested me to open my profile on nabu.casa and click "Connect" for Remote UI. After this the Remote UI is back online.

From my understanding it means that nabu.casa somehow knows where my local instance is running but it is not linked to nabu.casa URL after restart and should be manually re-connected.

[fillwe]

Moved my installation from Docker on Ubuntu to a vm in proxmox, have not had any issues since moving. Starting to think this is a Ubuntu host related issue

[rschuiling]

@MichielvanBeers Amazon Polly doesn't seem to be the culprit. I did several tests where Polly was disabled and enabled. Here are two logs, in both cases Amazon Polly was enabled in configuration.yaml:

home-assistant1.log - Remote UI was unreachable after restart
home-assistant2.log - Remote UI was available after restart, straight away

@cogneato These logs are with your recommended logging options. Anything I can try to help find this issue?

[codylv7]

I am experiencing this issue as well, working on getting logs..

[codylv7]

Here's a log for you https://pastebin.com/DmLDuxML

Let me know what else I can provide

If I set ssl_profile: intermediate the error does not occur, so something SSL related

[balloob]

Traced it down to https://github.com/boto/boto3/issues/1592 . It seems like it's related to having other threads also use the AWS SDK. Looks like https://github.com/boto/boto3/issues/1592#issuecomment-540825115 might be a solution.

[MichielvanBeers]

Thanks for the update @balloob! I'm not completely sure how I can implement this fix myself though.. Could you maybe give me a pointer on if and how I can implement this fix?

[balloob]

We need to implement the fix in the code.

[codylv7]

Awesome, thank you for working on a fix!

[ryanm7780]

Awesome. This has been plaguing me. I'm really looking forward to the fix being released. Thanks @balloob !

[MichielvanBeers]

That is great news! Very happy to hear that there is a fix :) thanks a lot!

[josedeone]

hello guys
i been having the same issue after a reboot nabu kasa SSL goes down. Is there a fix for this coming soon?? ill be posting log later tonight

[balloob]

Please create a new issue. This issue has been resolved.