'st2ctl register' fails to register rules on a fresh DB

[arm4b]

Previous PR #429 removed all sleep occurencies from the installer and fixed some deep issues with the st2 services startup, handling better st2api, st2auth, st2stream to report correct status only when respective service is listening on the network port.

But not all bugs were caught. Under Ubuntu Xenial after initial st2 install running

sudo st2ctl start && st2ctl reload --register-all

fails to register the rules.

Reproduce

Run xenial installer (with removed sleep):

curl -sSL https://raw.githubusercontent.com/StackStorm/st2-packages/27ec5a09d87c3bc2bcfd0e01adf3ff4daa294551/scripts/st2bootstrap-deb.sh | bash -s -- --user=st2admin --password=st2admin --unstable --staging

Happens only during the first boot.

Error

Registering content...[flags = --config-file /etc/st2/st2.conf --register-all]
2017-03-14 17:58:48,626 INFO [-] Connecting to database "st2" @ "0.0.0.0:27017" as user "stackstorm".
2017-03-14 17:58:50,440 INFO [-] =========================================================
2017-03-14 17:58:50,440 INFO [-] ############## Registering triggers #####################
2017-03-14 17:58:50,440 INFO [-] =========================================================
2017-03-14 17:58:50,550 INFO [-] Registered 0 triggers.
2017-03-14 17:58:50,550 INFO [-] =========================================================
2017-03-14 17:58:50,550 INFO [-] ############## Registering sensors ######################
2017-03-14 17:58:50,551 INFO [-] =========================================================
2017-03-14 17:58:50,618 INFO [-] Registered 1 sensors.
2017-03-14 17:58:50,619 INFO [-] =========================================================
2017-03-14 17:58:50,619 INFO [-] ############## Registering runners ######################
2017-03-14 17:58:50,619 INFO [-] =========================================================
2017-03-14 17:58:51,204 INFO [-] Registered 13 runners.
2017-03-14 17:58:51,204 INFO [-] =========================================================
2017-03-14 17:58:51,204 INFO [-] ############## Registering actions ######################
2017-03-14 17:58:51,204 INFO [-] =========================================================
2017-03-14 17:58:53,184 INFO [-] Registered 46 actions.
2017-03-14 17:58:53,185 INFO [-] =========================================================
2017-03-14 17:58:53,185 INFO [-] ############## Registering rules ########################
2017-03-14 17:58:53,185 INFO [-] =========================================================
2017-03-14 17:58:53,286 WARNING [-] Failed to register rules: Failed to register rule "/opt/stackstorm/packs/chatops/rules/notify_hubot.yaml" from pack "chatops": A simple trigger should have been created when registering triggertype. Cannot create trigger: {'type': 'core.st2.generic.notifytrigger', 'parameters': {}, 'pack': 'core'}.
Traceback (most recent call last):
  File "/usr/bin/st2-register-content", line 22, in <module>
    sys.exit(content_loader.main(sys.argv[1:]))
  File "/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2common/content/bootstrap.py", line 387, in main
    register_content()
  File "/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2common/content/bootstrap.py", line 339, in register_content
    register_rules()
  File "/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2common/content/bootstrap.py", line 248, in register_rules
    raise e
ValueError: Failed to register rule "/opt/stackstorm/packs/chatops/rules/notify_hubot.yaml" from pack "chatops": A simple trigger should have been created when registering triggertype. Cannot create trigger: {'type': 'core.st2.generic.notifytrigger', 'parameters': {}, 'pack': 'core'}.

---

This time the problem could be related to st2 core itself. Needs more investigation and proper fix.

[arm4b]

After further debugging, here is the script to easily reproduce an error on Ubuntu16 (works on Vagrant too):

#!/bin/bash

set -o xtrace

# disable mongo auth to run dropDatabase() from cli
if grep -q 'authorization: enabled' /etc/mongod.conf; then
  sudo sed -i 's/authorization: enabled/authorization: disabled/' /etc/mongod.conf
  sudo service mongod restart
fi

# emulate fresh & clean start
sudo st2ctl stop
mongo st2 --eval 'db.dropDatabase();'
sudo st2ctl start

# Failed to register rules: Failed to register rule "/opt/stackstorm/packs/chatops/rules/notify_hubot.yaml"
st2ctl reload --register-all

Seems at early point st2 is busy bootstrapping DB schema in mongo (?) and for some reason can't register a rule (some db resource is not yet available ?) when saving it for the first time.

---

So from the packaging point of view, I can't do anything here.

@Kami @lakshmi-kannan @m4dcoder Can you help with debugging this case in StackStorm itself?

[estee-tew]

https://stackstorm.slack.com/archives/community/p1492461999780716

[estee-tew]

https://stackstorm.slack.com/archives/community/p1492633077162687

[csillab]

I have the same issue with newly installed vagrant ubuntu 16.06.

[Mierdin]

I looked into this a bit tonight, and haven't figured out why this is happening, but it does seem to be a delay in what's being written to MongoDB, and the availability of that resource to be read, since I have been able to fix this by simply inserting a 5 second sleep before the query. Still looking.

[Kami]

Yeah, it seems related to MongoDB configuration and read after write (or perhaps mongoengine, but less likely).

One option might be to experiment with write concern for trigger writes on rule register (https://docs.mongodb.com/manual/reference/write-concern/#standalone).

In the worst case, we might need to add some sleep in the code for now as a work-around.

[arm4b]

So as we figured out, the re-appeared regression mentioned in previous 2 messages was caused by the updated mongoengine pip package: StackStorm/st2#3402 Now the st2 CI is passing and we don't need to increase any sleep timeouts in curl|bash installer again.

But as said before, ideally is to find the root cause/investigate the proper fix for this issue and remove sleep 5 from our installer:

st2-packages/scripts/st2bootstrap-deb.sh

Lines 331 to 336 in ffe4f7b

	sudo st2ctl start
	# TODO: Fix https://github.com/StackStorm/st2-packages/issues/445 (under xenial register content fails on first boot)
	if [[ "$SUBTYPE" == 'xenial' ]]; then
	sleep 5
	fi
	sudo st2ctl reload --register-all

completely, because with these sleep timeouts added to curl|bash installer or CI we just swipe the dirt under the rug.

The bug still remains the bug while users installing st2 manually via packages or via configuration management tools.
To conclude, the issue is still unresolved.

[estee-tew]

https://stackstorm.slack.com/archives/community/p1495207857780815

[pvanheus]

+1 Happens for me too. My environment is a Ubuntu 16.04 virtual machine, upgraded from 14.04 recently. 2 GB RAM, 1 virtual CPU, ~ 10 GB disk available. The result is a system left in an inconsistent state. If I try and re-do the install I get:

root@mon:~# curl -sSL https://stackstorm.com/packages/install.sh | bash -s -- --user=st2admin --password=PASSWORD
*** Detected Distro is Ubuntu ***
*** Detected flavor xenial ***
Downloading deployment script from: https://raw.githubusercontent.com/StackStorm/st2-packages/v2.2/scripts/st2bootstrap-deb.sh...
Running deployment script for st2 ...
OS specific script cmd: bash st2bootstrap-deb.sh  --stable  --user=st2admin --password=PASSWORD

########################################################
          Installing StackStorm stable               
########################################################

Not all required TCP ports are available. ST2 and related services will fail to start.

The following ports are in use by the specified pid/process and need to be stopped:
 127.0.0.1:9100 1/init
 127.0.0.1:9101 1/init
 127.0.0.1:9102 1/init

############### ERROR ###############
# Failed on step - Check TCP ports and MongoDB storage requirements #
#####################################

If I am able to somehow get back to a "clean" state to continue the installation, where should a pause in the install routine be placed?

[Kami]

I dug in a little and it looks like the issue is most likely related to register content running before st2api or other services fully start.

On st2api and some other services startup internal trigger types are registered so if this internal registration doesn't happen before register content is ran, the script will fail with that error.

Having said that, at the moment I still can't tie this issue to the mongoengine change yet. This behavior was always like that, but it's possible there is something else going on, still.

On a related note, afaik, if st2ctl start would correctly wait on st2api and other services to start before returning / existing this shouldn't happen.

[arm4b]

@Kami I could further isolate it.
Register-content script can work without any st2 services, it just needs Mongo DB.

#!/bin/bash

set -o xtrace

# disable mongo auth to run dropDatabase() from cli
if grep -q 'authorization: enabled' /etc/mongod.conf; then
  sudo sed -i 's/authorization: enabled/authorization: disabled/' /etc/mongod.conf
  sudo service mongod restart
fi

# emulate fresh & clean start
sudo st2ctl stop
mongo st2 --eval 'db.dropDatabase();'

# Failed to register rules: Failed to register rule "/opt/stackstorm/packs/chatops/rules/notify_hubot.yaml"
st2ctl reload --register-all

So we don't even start st2, just emulate register-content script on a fresh DB.
Could reproduce it even on Ubuntu14. So it's not Xenial-related.

[arm4b]

This race is fixed in st2 core via StackStorm/st2#3542 a long time ago.