Traceback: ValueError: Invalid Homeserver

[roughnecks]

-- Journal begins at Mon 2022-08-01 19:39:35 CEST, ends at Wed 2022-08-03 14:41:19 CEST. --
Aug 03 13:56:05 "redacted" systemd[1]: Stopping Matrix registration bot...
Aug 03 13:56:06 "redacted" matrix-bot-matrix-registration-bot[2694077]: matrix-bot-matrix-registration-bot
Aug 03 13:56:06 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Main process exited, code=exited, status=137/n/a
Aug 03 13:56:06 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Failed with result 'exit-code'.
Aug 03 13:56:06 "redacted" systemd[1]: Stopped Matrix registration bot.
Aug 03 13:56:06 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Consumed 10.113s CPU time.
Aug 03 13:56:06 "redacted" systemd[1]: Starting Matrix registration bot...
Aug 03 13:56:06 "redacted" systemd[1]: Started Matrix registration bot.
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,541 INFO:Tying to load bot configuration from /config/config.yml
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,550 DEBUG:BOT_SERVER not set in environment
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,550 DEBUG:BOT_USERNAME not set in environment
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,551 DEBUG:BOT_PASSWORD not set in environment
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,551 DEBUG:BOT_ACCESS_TOKEN not set in environment
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,553 DEBUG:API_BASE_URL not set in environment
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,553 DEBUG:API_TOKEN not set in environment
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,554 DEBUG:LOGGING_LEVEL not set in environment
Aug 03 13:56:11 "redacted" matrix-bot-matrix-registration-bot[2694139]: 2022-08-03 11:56:11,813 INFO:Loaded the simple-matrix-bot config file config.toml
Aug 03 14:04:17 "redacted" systemd[1]: Stopping Matrix registration bot...
Aug 03 14:04:18 "redacted" matrix-bot-matrix-registration-bot[2700551]: matrix-bot-matrix-registration-bot
Aug 03 14:04:19 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Main process exited, code=exited, status=137/n/a
Aug 03 14:04:19 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Failed with result 'exit-code'.
Aug 03 14:04:19 "redacted" systemd[1]: Stopped Matrix registration bot.
Aug 03 14:04:56 "redacted" systemd[1]: Starting Matrix registration bot...
Aug 03 14:04:57 "redacted" systemd[1]: Started Matrix registration bot.
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,221 INFO:Tying to load bot configuration from /config/config.yml
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,241 DEBUG:BOT_SERVER not set in environment
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,243 DEBUG:BOT_USERNAME not set in environment
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,245 DEBUG:BOT_PASSWORD not set in environment
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,246 DEBUG:BOT_ACCESS_TOKEN not set in environment
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,247 DEBUG:API_BASE_URL not set in environment
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,250 DEBUG:API_TOKEN not set in environment
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,251 DEBUG:LOGGING_LEVEL not set in environment
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: 2022-08-03 12:05:19,795 INFO:Loaded the simple-matrix-bot config file config.toml
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]: Traceback (most recent call last):
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:   File "/opt/venv/bin/matrix-registration-bot", line 8, in <module>
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:     sys.exit(run_bot())
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:   File "/opt/venv/lib/python3.10/site-packages/matrix_registration_bot/bot.py", line 195, in run_bot
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:     bot.run()
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:   File "/opt/venv/lib/python3.10/site-packages/simplematrixbotlib/bot.py", line 84, in run
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:     asyncio.run(self.main())
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:   File "/usr/local/lib/python3.10/asyncio/runners.py", line 44, in run
Aug 03 14:05:19 "redacted" matrix-bot-matrix-registration-bot[2703366]:     return loop.run_until_complete(main)
Aug 03 14:05:20 "redacted" matrix-bot-matrix-registration-bot[2703366]:   File "/usr/local/lib/python3.10/asyncio/base_events.py", line 646, in run_until_complete
Aug 03 14:05:20 "redacted" matrix-bot-matrix-registration-bot[2703366]:     return future.result()
Aug 03 14:05:20 "redacted" matrix-bot-matrix-registration-bot[2703366]:   File "/opt/venv/lib/python3.10/site-packages/simplematrixbotlib/bot.py", line 46, in main
Aug 03 14:05:20 "redacted" matrix-bot-matrix-registration-bot[2703366]:     raise ValueError("Invalid Homeserver")
Aug 03 14:05:20 "redacted" matrix-bot-matrix-registration-bot[2703366]: ValueError: Invalid Homeserver
Aug 03 14:05:21 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Main process exited, code=exited, status=1/FAILURE
Aug 03 14:05:21 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Failed with result 'exit-code'.
Aug 03 14:05:51 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Scheduled restart job, restart counter is at 1.
Aug 03 14:05:51 "redacted" systemd[1]: Stopped Matrix registration bot.
Aug 03 14:05:51 "redacted" systemd[1]: Starting Matrix registration bot...
Aug 03 14:05:51 "redacted" systemd[1]: Started Matrix registration bot.
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,190 INFO:Tying to load bot configuration from /config/config.yml
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,195 DEBUG:BOT_SERVER not set in environment
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,196 DEBUG:BOT_USERNAME not set in environment
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,197 DEBUG:BOT_PASSWORD not set in environment
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,197 DEBUG:BOT_ACCESS_TOKEN not set in environment
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,198 DEBUG:API_BASE_URL not set in environment
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,199 DEBUG:API_TOKEN not set in environment
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,199 DEBUG:LOGGING_LEVEL not set in environment
Aug 03 14:05:55 "redacted" matrix-bot-matrix-registration-bot[2704822]: 2022-08-03 12:05:55,357 INFO:Loaded the simple-matrix-bot config file config.toml
Aug 03 14:12:01 "redacted" systemd[1]: Stopping Matrix registration bot...
Aug 03 14:12:03 "redacted" matrix-bot-matrix-registration-bot[2709254]: matrix-bot-matrix-registration-bot
Aug 03 14:12:03 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Main process exited, code=exited, status=137/n/a
Aug 03 14:12:03 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Failed with result 'exit-code'.
Aug 03 14:12:03 "redacted" systemd[1]: Stopped Matrix registration bot.
Aug 03 14:13:11 "redacted" systemd[1]: Starting Matrix registration bot...
Aug 03 14:13:12 "redacted" systemd[1]: Started Matrix registration bot.
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,778 INFO:Tying to load bot configuration from /config/config.yml
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,791 DEBUG:BOT_SERVER not set in environment
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,794 DEBUG:BOT_USERNAME not set in environment
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,795 DEBUG:BOT_PASSWORD not set in environment
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,797 DEBUG:BOT_ACCESS_TOKEN not set in environment
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,798 DEBUG:API_BASE_URL not set in environment
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,800 DEBUG:API_TOKEN not set in environment
Aug 03 14:13:36 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:36,800 DEBUG:LOGGING_LEVEL not set in environment
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]: 2022-08-03 12:13:37,306 INFO:Loaded the simple-matrix-bot config file config.toml
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]: Traceback (most recent call last):
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:   File "/opt/venv/bin/matrix-registration-bot", line 8, in <module>
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:     sys.exit(run_bot())
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:   File "/opt/venv/lib/python3.10/site-packages/matrix_registration_bot/bot.py", line 195, in run_bot
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:     bot.run()
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:   File "/opt/venv/lib/python3.10/site-packages/simplematrixbotlib/bot.py", line 84, in run
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:     asyncio.run(self.main())
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:   File "/usr/local/lib/python3.10/asyncio/runners.py", line 44, in run
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:     return loop.run_until_complete(main)
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:   File "/usr/local/lib/python3.10/asyncio/base_events.py", line 646, in run_until_complete
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:     return future.result()
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:   File "/opt/venv/lib/python3.10/site-packages/simplematrixbotlib/bot.py", line 46, in main
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]:     raise ValueError("Invalid Homeserver")
Aug 03 14:13:37 "redacted" matrix-bot-matrix-registration-bot[2712691]: ValueError: Invalid Homeserver
Aug 03 14:13:38 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Main process exited, code=exited, status=1/FAILURE
Aug 03 14:13:38 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Failed with result 'exit-code'.
Aug 03 14:14:08 "redacted" systemd[1]: matrix-bot-matrix-registration-bot.service: Scheduled restart job, restart counter is at 1.
Aug 03 14:14:08 "redacted" systemd[1]: Stopped Matrix registration bot.
Aug 03 14:14:08 "redacted" systemd[1]: Starting Matrix registration bot...
Aug 03 14:14:08 "redacted" systemd[1]: Started Matrix registration bot.
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,349 INFO:Tying to load bot configuration from /config/config.yml
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,354 DEBUG:BOT_SERVER not set in environment
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,355 DEBUG:BOT_USERNAME not set in environment
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,356 DEBUG:BOT_PASSWORD not set in environment
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,357 DEBUG:BOT_ACCESS_TOKEN not set in environment
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,357 DEBUG:API_BASE_URL not set in environment
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,358 DEBUG:API_TOKEN not set in environment
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,358 DEBUG:LOGGING_LEVEL not set in environment
Aug 03 14:14:12 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:14:12,501 INFO:Loaded the simple-matrix-bot config file config.toml
Aug 03 14:39:05 "redacted" matrix-bot-matrix-registration-bot[2714121]: 2022-08-03 12:39:05,105 INFO:@roughnecks:"redacted" listed all tokens

It works after the error, so this is happening only when restarting the Ansible playbook.

[ccapitalK]

I've encountered this issue as well, I had to bump the service startup timeout in the ansible playbooks up to 60 seconds to get it working.

[roughnecks]

I've encountered this issue as well, I had to bump the service startup timeout in the ansible playbooks up to 60 seconds to get it working.

I have a similar issue with heisenbridge, fixed by using a timeout of 30 seconds; also heisenbridge's devel said it's an easy fix, but I'm not sure is the same exact issue.

[moan0s]

So IIUC the problem is that when using matrix-docker-ansible-deploy and use ansible-playbook -i inventory/hosts setup.yml --tags=start the bot throws the error you've shown above?

[roughnecks]

yep!

[moan0s]

So I guess what happens is:

• Synapse get's started by the playbook
• synapse process is up but the server not yet reachable
• MRB starts and tries to connect to the server -> fails as synapse is not yet reachable

[Jonny1797]

Kind of an old issue, but I'd like to add: your guess @moan0s seems to be right. I'm also using the bot with matrix-docker-ansible-deploy. At first, it threw a few times the same error as happened to @roughnecks, but after a while (probably depending on the speed of the server) - meaning several restarts / retries - it's up, running and functioning.

[spantaleev]

For matrix-docker-ansible-deploy, the problem is likely that the installation instructions for the service were a bit inaccurate, telling people to run the setup-all,start tags for the playbook.

However, this is not enough. Without the ensure-matrix-users-created tag, the bot's user account won't get created.

I've updated the installation instructions here. Running install-all or setup-all via just, actually invokes all the necessary tags (install-all,ensure-matrix-users-created,start or setup-all,ensure-matrix-users-created,start, respectively).

I believe with this, the bot's account will be prepared before the playbook tries to start the service.. and it would be able to then start successfully.