"hyperglass start" fails during an async call within util.build_frontend

[linuxgemini]

On a valid configuration set, you can run hyperglass build-ui without issues. Regardless of the UI build state with the same configuration set however, you cannot run hyperglass start. You can run hyperglass with the --direct flag: hyperglass start -d

Bug Description

https://github.com/checktheroads/hyperglass/blob/ee87c34ff162693b7a039027c12211930b409c44/hyperglass/util.py#L637-L647
The code block pointed above fails to the user with an empty RuntimeError:

unhandled exception during asyncio.run() shutdown
task: <Task finished coro=<build_ui() done, defined at /usr/local/lib/python3.6/dist-packages/hyperglass/main.py:59> exception=RuntimeError('',)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/main.py", line 70, in build_ui
    app_path=CONFIG_PATH,
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/util.py", line 696, in build_frontend
    raise RuntimeError(str(e)) from None
RuntimeError
❌

However, the error is not empty. You have to dig deeper (aka adding a try/except block on the linked code above) to get the error: <class 'concurrent.futures._base.CancelledError'>

Expected behavior

hyperglass starting up. (and building the UI/frontend if not done before)

Steps to Reproduce

• Install hyperglass manually with pip3 (or with python3 -m pip)
• Run hyperglass setup and choose /etc/hyperglass as configuration base folder
• Setup a sample config that is connected to a BIRD instance, see "runnable" example config linked below (this should've been easier if the documentation and the example wasn't out of sync, see: Online Documentation for "Adding Devices" is out of date/incomplete #55)
• run hyperglass start

Local Configurations

commands.yaml: empty
devices.yaml: https://files.linuxgemini.space/hyperglass/devices-clearpass.yaml
hyperglass.yaml: https://files.linuxgemini.space/hyperglass/hyperglass.yaml

hyperglass-agent/config.yaml: https://files.linuxgemini.space/hyperglass/agent/config.yaml

Logs

root@hell:~# hyperglass start
[INFO] 20200716 01:08:30 | hyperglass.configuration:43 | <module> → Configuration directory: /etc/hyperglass
[INFO] 20200716 01:08:31 | hyperglass.main:101 | on_starting → Python 3.6.9 detected (3.6 required)
unhandled exception during asyncio.run() shutdown
task: <Task finished coro=<build_ui() done, defined at /usr/local/lib/python3.6/dist-packages/hyperglass/main.py:59> exception=RuntimeError('',)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/main.py", line 70, in build_ui
    app_path=CONFIG_PATH,
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/util.py", line 696, in build_frontend
    raise RuntimeError(str(e)) from None
RuntimeError
❌
root@hell:~#

Possible Solution

Sadly, I am not really sure. I haven't messed with async in Python much; or Python in general.

Environment

Server

• OS: Ubuntu 18.04.4 LTS: Kernel 4.15.0-99-generic
• Python Version: 3.6.9
• hyperglass Version: 1.0.0-beta.51

Route Server

• OS: Ubuntu 18.04.4 LTS: Kernel 4.15.0-106-generic
• Python Version: 3.6.9
• hyperglass-agent Version: 0.1.0
• BIRD Version: 2.0.7

Client

not applicable

Smartphone Details (if applicable)

not applicable

[thatmattlove]

This is a really odd one. Your environment is almost identical to what I run my org’s production hyperglass on, with the exception of BIRD, but I test that via local VM pretty regularly (and should in no way be relevant to the UI build). And, your configs appear largely generic. Can you set debug to ‘true` and run this again? It may help narrow down where exactly the hangup is.

[linuxgemini]

The "Bug Description" part is written when I had debug: true and as I phrased there, without you adding an explicit try/except inside the linked code block you will always get the same RuntimeError('',).

And with that try/except, I've only captured the error <class 'concurrent.futures._base.CancelledError'>. Because I am unfamiliar with Python's async, I can't give you an assumption on what is happening.

I can try adding additional debug loggers etc. If you want me to.

[linuxgemini]

(I have done a minor edit on the primary issue post, I forgot that the first error log posted contained my extra debug log lines so it made the callstack line higher than it supposed to be)

[linuxgemini]

This issue is still persistent on hyperglass-1.0.0b53:

[DEBUG] 20200724 18:46:35 | hyperglass.util:611 | build_frontend → node_modules is already initialized
[DEBUG] 20200724 18:46:35 | hyperglass.util:632 | build_frontend → Previous Build ID: 08f070e680b47bdbf14b4bf78be5e082928b1ec1d68b3516a2cd095f1434b426
[INFO] 20200724 18:46:35 | hyperglass.util:647 | build_frontend → Starting UI build...
[DEBUG] 20200724 18:46:35 | hyperglass.util:649 | build_frontend → Created temporary UI config file: '/tmp/hyperglass_un6uk4hq.json' for build 7ea674e0dd1dd1fc92104b230dd9b8f32c7925a5685a1c293cb7bb449f86bb74
[ERROR] 20200724 18:46:35 | hyperglass.util:686 | build_frontend →
unhandled exception during asyncio.run() shutdown
task: <Task finished coro=<build_ui() done, defined at /usr/local/lib/python3.6/dist-packages/hyperglass/main.py:59> exception=RuntimeError('',)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/main.py", line 70, in build_ui
    app_path=CONFIG_PATH,
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/util/__init__.py", line 687, in build_frontend
    raise RuntimeError(str(err)) from None
RuntimeError
❌

What's interesting is that hyperglass -v reports back 1.0.0-beta.52

[linuxgemini]

Hmm, after a clean-up I now get this:

[DEBUG] 20200724 18:50:09 | hyperglass.util:637 | build_frontend → UI parameters unchanged since last build, skipping UI build...
❌

[thatmattlove]

I just figured out on my own system why it's showing the old version - I forgot to update the version in hyperglass/constants.py. This is mostly cosmetic, with the notable exception that that's one of the key factors that hyperglass uses on startup to determine if a UI build is needed. So, if you did not run hyperglass build-ui manually after upgrading (you don't normally need to), please run it manually and see if it's any different for you. Also, I think you may have shared it in Telegram or another issue, but can you also share the output of hyperglass system-info?

[linuxgemini]

Okay so after doing python3 -m pip install --upgrade hyperglass and then doing hyperglass start gave me #56 (comment)

Realizing that shouldn't really happen, I went ahead and did:

• python3 -m pip uninstall hyperglass
• python3 -m pip install hyperglass
• hyperglass build-ui
• hyperglass start

Which gave me #56 (comment)

System Info

Metric	Value
hyperglass Version	1.0.0-beta.52
hyperglass Path	/etc/hyperglass
Python Version	3.6.9
Platform Info	Linux-4.15.0-99-generic-x86_64-with-Ubuntu-18.04-bionic
CPU Info	AMD EPYC Processor (with IBPB)
Logical Cores	2
Physical Cores	2
Processor Speed	2.4953119999999998GHz
Total Memory	2.04 GB
Memory Utilization	29.0%
Total Disk Space	40.26 GB
Disk Utilization	26.0%

[thatmattlove]

Once 1.0.0-beta.55 finishes CI and is published, can you give it a whirl? The favicons is now live. In my testing, the favicon build process took about 1 second, vs the JS library's nearly full minute, so I'm hopeful this issue will be solved!

[thatmattlove]

The CI build failed, but I've since fixed it. 1.0.0-beta.55 is available via PyPI now.

[linuxgemini]

Unfortunately I got the same exit :(

[DEBUG] 20200727 22:02:10 | hyperglass.util:615 | build_frontend → node_modules is already initialized
[DEBUG] 20200727 22:02:11 | hyperglass.util:637 | build_frontend → Generated 21 favicons
[DEBUG] 20200727 22:02:11 | hyperglass.util:653 | build_frontend → Previous Build ID: 0e049d8ec70fe9afe06bc046ae2a1e9c48150e5e9391469eb47a49bfc5a7c318
[INFO] 20200727 22:02:11 | hyperglass.util:669 | build_frontend → Starting UI build...
[DEBUG] 20200727 22:02:11 | hyperglass.util:671 | build_frontend → Created temporary UI config file: '/tmp/hyperglass_lgu38wva.json' for build 853d3e342408b3640b37d9d08140c53fb4997f268c1a4188bb3da34306cf1327
[ERROR] 20200727 22:02:11 | hyperglass.util:708 | build_frontend →
unhandled exception during asyncio.run() shutdown
task: <Task finished coro=<build_ui() done, defined at /usr/local/lib/python3.6/dist-packages/hyperglass/main.py:59> exception=RuntimeError('',)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/main.py", line 70, in build_ui
    app_path=CONFIG_PATH,
  File "/usr/local/lib/python3.6/dist-packages/hyperglass/util/__init__.py", line 709, in build_frontend
    raise RuntimeError(str(err)) from None
RuntimeError
❌

Already ran build-ui and it was much faster.

[linuxgemini]

To see if Python was at fault, I also installed python3.8 but the end result is the same.

root@hell:~# hyperglass start
[INFO] 20200727 22:24:45 | hyperglass.configuration:45 | <module> → Configuration directory: /etc/hyperglass
[INFO] 20200727 22:24:45 | hyperglass.main:101 | on_starting → Python 3.8.0 detected (3.6 required)
An open stream object is being garbage collected; call "stream.close()" explicitly.
[INFO] 20200727 22:24:46 | hyperglass.util:669 | build_frontend → Starting UI build...
❌
root@hell:~#

With the debug flag set:

[DEBUG] 20200727 22:26:42 | hyperglass.util:615 | build_frontend → node_modules is already initialized
[DEBUG] 20200727 22:26:42 | hyperglass.util:637 | build_frontend → Generated 21 favicons
[DEBUG] 20200727 22:26:42 | hyperglass.util:653 | build_frontend → Previous Build ID: 8e1240ff79e1c8dd4994e5f0229ff414afed265c6f0de8b5aefa930a3ae915b1
[INFO] 20200727 22:26:42 | hyperglass.util:669 | build_frontend → Starting UI build...
[DEBUG] 20200727 22:26:42 | hyperglass.util:670 | build_frontend → Created temporary UI config file: '/tmp/hyperglass_q31epaa9.json' for build a1d00f60824625db36b31ed1eb4a284ba1961170ca3d629c86ac0c032226a015
❌

System Info (though its the same)

Metric	Value
hyperglass Version	1.0.0-beta.55
hyperglass Path	/etc/hyperglass
Python Version	3.8.0
Platform Info	Linux-4.15.0-99-generic-x86_64-with-glibc2.27
CPU Info	AMD EPYC Processor (with IBPB)
Logical Cores	2
Physical Cores	2
Processor Speed	2.4953119999999998GHz
Total Memory	2.04 GB
Memory Utilization	28.3%
Total Disk Space	40.26 GB
Disk Utilization	27.4%