Unable to start demo

Hello Mender!

Today I wanted to try the demo on premise. After following the instructions available on your site (https://docs.mender.io/2.3/getting-started/on-premise-installation/create-a-test-environment) I encoutered errors during the launch of docker containers.

[root@mender-test integration-2.3.0]# ./demo up
ERROR: Service 'mender-deployments' depends on service 'storage-proxy' which is undefined.
Starting the Mender demo environment...
Creating network "integration230_mender" with the default driver
Creating integration230_mender-elasticsearch_1 ... done
Creating integration230_mender-mongo_1         ... done
Creating integration230_mender-redis_1                  ... done
Creating integration230_minio_1                         ... done
Creating integration230_mender-gui_1                    ... done
Creating integration230_mender-useradm_1                ... done
Creating integration230_mender-inventory_1              ... done
Creating integration230_mender-create-artifact-worker_1 ... done
Creating integration230_mender-workflows-server_1       ... done
Creating integration230_mender-conductor_1              ... done
Creating integration230_mender-device-auth_1            ... done
Creating integration230_storage-proxy_1                 ... done
Creating integration230_mender-deployments_1            ... done
Creating integration230_mender-api-gateway_1            ... done
Creating a new user...
docker exec error:  137

The first ERROR doesn’t seem to be blocking. But as you can see the script hangs up trying creating a user.

After looking at the logs it seems like the containers can’t connect to the mongodb container:

mender-useradm_1                 | time="2020-04-02T17:05:55Z" level=info msg="User Administration Service, version unknown starting up" file=entry.go func="logrus.(*Entry).Logf" line=313
mender-useradm_1                 | failed to connect to db: context deadline exceeded

This is just an example but every container throws the same error.

I edited my /etc/hosts to contain the 2 records (s3.docker.mender.io and docker.mender.io IIRC). I put both 127.0.0.1 and then my VM IP. Both didn’t work.

My setup : Centos 7 hypervisor (host), Centos 8 (vm). Fresh install, only docker installed. Already tried downgrading docker-compose (after seeing an issue affecting the script).

I also tried to docker exec into a container and ping the mongodb container: it works! Oh and yeah the mongodb IS running.

One thing I saw is that some containers restart every 10 or 20 seconds.

Thanks for you help !

EDIT: Pressed enter way too soon aha.

@imkwx you can ignore the ERROR about ‘store-proxy’, it is not the root cause of your issue.
The error message you pasted from useradm means that the connection to mongodb times out.

Does your mender-mongo_1 container start correctly?
Can you please check its logs, and eventually post them here?
Can you enter the container, and connect to mongo using the mongo CLI?

@tranchitella
Hello ! Thanks for your answer.

Yes the mongo container starts correctly and the logs doesn’t show any errors, it actually says that it’s listening for connections (see below) :
mongo:3.6 "docker-entrypoint.s…" 14 hours ago Up 14 hours 27017/tcp integration230_mender-mongo_1

2020-04-02T16:56:57.750+0000 I CONTROL  [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db 64-bit host=ce61800c0594
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten] db version v3.6.17
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten] git version: 3d6953c361213c5bfab23e51ab274ce592edafe6
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten] modules: none
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten] build environment:
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten]     distmod: ubuntu1604
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten]     distarch: x86_64
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2020-04-02T16:56:57.751+0000 I CONTROL  [initandlisten] options: { net: { bindIpAll: true } }
2020-04-02T16:56:57.770+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3394M,cache_overflow=(file_max=0M),session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),compatibility=(release="3.0",require_max="3.0"),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),
2020-04-02T16:56:59.307+0000 I STORAGE  [initandlisten] WiredTiger message [1585846619:307539][1:0x7f9258103a40], txn-recover: Set global recovery timestamp: 0
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
2020-04-02T16:56:59.357+0000 I STORAGE  [initandlisten] createCollection: admin.system.version with provided UUID: 3339d964-179b-4d30-9fbf-c28c9d3cede7
2020-04-02T16:56:59.383+0000 I COMMAND  [initandlisten] setting featureCompatibilityVersion to 3.6
2020-04-02T16:56:59.383+0000 I STORAGE  [initandlisten] createCollection: local.startup_log with generated UUID: f9628fe3-aeff-4f30-8221-5f1d03aede8f
2020-04-02T16:56:59.414+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
2020-04-02T16:56:59.415+0000 I NETWORK  [initandlisten] listening via socket bound to 0.0.0.0
2020-04-02T16:56:59.415+0000 I NETWORK  [initandlisten] listening via socket bound to /tmp/mongodb-27017.sock
2020-04-02T16:56:59.415+0000 I NETWORK  [initandlisten] waiting for connections on port 27017
2020-04-02T16:56:59.415+0000 I STORAGE  [LogicalSessionCacheRefresh] createCollection: config.system.sessions with generated UUID: 6effc01e-58a3-4f45-8bd7-af427c147c25
2020-04-02T16:56:59.466+0000 I INDEX    [LogicalSessionCacheRefresh] build index on: config.system.sessions properties: { v: 2, key: { lastUse: 1 }, name: "lsidTTLIndex", ns: "config.system.sessions", expireAfterSeconds: 1800 }
2020-04-02T16:56:59.466+0000 I INDEX    [LogicalSessionCacheRefresh] 	 building index using bulk method; build may temporarily use up to 500 megabytes of RAM
2020-04-02T16:56:59.470+0000 I INDEX    [LogicalSessionCacheRefresh] build index done.  scanned 0 total records. 0 secs

Tried to connect to mongo:

root@ce61800c0594:/# mongo
MongoDB shell version v3.6.17
connecting to: mongodb://127.0.0.1:27017/?gssapiServiceName=mongodb
MongoDB server version: 3.6.17
Welcome to the MongoDB shell.
For interactive help, type "help".
For more comprehensive documentation, see
	http://docs.mongodb.org/
Questions? Try the support group
	http://groups.google.com/group/mongodb-user
Server has startup warnings:
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2020-04-02T16:56:59.356+0000 I CONTROL  [initandlisten]
>

It seems like it is working ? also checked if port was really listening or not.

EDITs: Formatting

I really appreciate the fact you’re taking time to help me out! :smiley:

@imkwx

I confirm your mongodb is healty, according to the logs. Can you please enter the useradm container (I hope you have enough time between the restarts) and check the value of the USERADM_MONGO env variable, verify you can ping the host specified in the value and, optionally, connect to the mongodb port (27017)? Ideally, you can use apk to install the mongo client, but a telnet to the port is enough to verify you have proper communication.

Hmmm. I think the error comes from this container (useradm)

After entering it I got the following result:

[root@mender-test ~]# docker exec -it integration230_mender-useradm_1 sh
/ # echo $USERADM_MONGO

Is it because I try with sh? But yeah it seems like the envvar is not set. That might be the root cause, but I can’t understand why it wouldn’t !

@imkwx
Just run “set”, so you get all the ENV variables, and see if you have USERADM_SOMETHING related to mongo.

@tranchitella

Nope ! It’s practically empty.

/ # set
HISTFILE='/root/.ash_history'
HOME='/root'
HOSTNAME='b02ac3357ff3'
IFS='
'
LINENO=''
OPTIND='1'
PATH='/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin'
PPID='0'
PS1='\w \$ '
PS2='> '
PS4='+ '
PWD='/'
SHLVL='1'
TERM='xterm'

@imkwx this is your issue, then; can you please confirm me the env is free in all the other containers as well? Can you please provide me your docker and docker-compose version?

@tranchitella Sure!

Here’s the versions:

[root@mender-test ~]# docker --version
Docker version 19.03.8, build afacb8b
[root@mender-test ~]# docker-compose --version
docker-compose version 1.23.2, build 1110ad01

Example for the GUI container:

/var/www/mender-gui/dist # set
DEMO='true'
GATEWAY_IP='10.4.41.1'
GIT_COMMIT='3c74e1d39'
GIT_REF='2.3.0'
HISTFILE='/root/.ash_history'
HOME='/root'
HOSTNAME='6bd4d2237f53'
IFS='
'
INTEGRATION_VERSION='2.3.0'
LINENO=''
MENDER_ARTIFACT_VERSION='3.3.0'
MENDER_DEB_PACKAGE_VERSION='2.2.0'
MENDER_VERSION='2.2.0'
NGINX_VERSION='1.17.8'
NJS_VERSION='0.3.8'
OPTIND='1'
PATH='/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin'
PKG_RELEASE='1'
PPID='0'
PS1='\w \$ '
PS2='> '
PS4='+ '
PWD='/var/www/mender-gui/dist'
SHLVL='1'
TERM='xterm'
_='set'

For the API gateway container, it’s the same : no specific envvars for mender.

@imkwx let’s try a different approach, though; If you don’t have the env variables set, defaults from the config file applies. In useradm, you have /etc/useradm/config.yaml with the default values, which is mongo-useradm.

It means you should be able to ping mongo-useradm from the container and connect to its 27017 TCP port. The name mongo-useradm is a network alias, defined here:

Can you please try to ping/telnet/access using the Mongo client your mongodb instance from the useradm container?

@tranchitella

Okay !

The alias seems to work when I try to ping (and the ping is successfull) but it can’t connect to the DB on port 27017, netcat throws an error “bad address” or host unreachable (after a few try). See below:

/ # ping mongo-useradm
PING mongo-useradm (172.22.0.2): 56 data bytes
64 bytes from 172.22.0.2: seq=0 ttl=64 time=0.069 ms
64 bytes from 172.22.0.2: seq=1 ttl=64 time=0.101 ms
^C
--- mongo-useradm ping statistics ---
2 packets transmitted, 2 packets received, 0% packet loss
round-trip min/avg/max = 0.069/0.085/0.101 ms
/ # nc -v mongu-useradm 27017
nc: bad address 'mongu-useradm' 

[root@mender-test integration-2.3.0]# docker exec -it integration230_mender-useradm_1 nc -v mongo-useradm 27017
nc: mongo-useradm (172.23.0.6:27017): Host is unreachable

Also just so you know SELinux is set to Permissive in case this changes anything

EDIT: Saw my typo error “mongu” that’s why I get the bad address. But I still get host is unreachable, when I don’t put gloves when I type !

EDIT 2: So, after thinking about this, like the mongo service runs and listen on the socket but it doesn’t seems te reply from other containers I thought it might be a firewall related issue. So I took a look to firewalld logs and here’s what I found: some of the iptables rules are failing when I launch ./demo up.

I will reinstall my VM and try again. I’ll keep in touch.

@imkwx good, looks like we are on the right track, keep me posted!

@tranchitella
Ok, I’m back. Soooo, went for a reinstall, used CENTOS 7 instead of CENTOS 8. Minimal install, then only docker + compose and jq.

ran ./demo up (and changing /etc/hosts)

Everything went fine ! Still have errors in firewalld though (when installing docker; not mender related.)

So I guess it’s solved? Maybe it’s because of Centos 8 ? I don’t know. Now that I have acces to a demo I will test mender and when I’ll have time i’ll test with Centos 8 again.

Anyway, thanks for helping me out !
Have a good day and take care.

@imkwx I’m happy we solved your issue!

Hello,

I am seeing a similar issue on Ubuntu 18.

When I run the demo-server the entire demo exits when I press “enter”

Running the following also seems to fail

barrett@barrett-strausser-bitbake-0:/datadrive/integration-2.3.0$ sudo docker-compose ps
ERROR: Service ‘mender-deployments’ depends on service ‘storage-proxy’ which is undefined.

@bearrito you should use the demo script instead of invoking docker-compose directly. For example, to list the containers running, use:

$ ./demo ps

From the output you posted, it seems the demo environment successfully started up, and you just had to log in to Mender using your browser and opening https://localhost

The error you report, when pressing enter to get the elogs, is an error in the demo script.