[SOLVED] Unable to install Mattermost

Hi,

I am trying to install Mattermost from the App Center. Unfortunately I am getting following error message.

Der Docker Container konnte nicht gestartet werden! Wir entschuldigen uns für die Unannehmlichkeiten. Bitte helfen Sie uns, das App Center und die Apps zu verbessern, indem Sie uns die unten stehenden Informationen senden.
The container for 4.2/mattermost=4.9.0 could not be started! docker logs 8f8845c218b00a33ede2ed090098433e001b9d4fa73c495389382bd7e463d12d: => Start MySQL * Starting MySQL database server mysqld ...done. => Start Mattermost dockerd logs: -- Logs begin at Thu 2018-04-19 18:36:54 CEST, end at Fri 2018-04-20 08:59:59 CEST. -- Apr 20 07:26:45 mail dockerd[2274]: time="2018-04-20T07:26:45.956109349+02:00" level=error msg="Handler for POST /v1.26/containers/ebc54ffac1c80d266b2aae7fc180fd60b11eab648cb58209af1505ad7e143b3b/stop returned error: Container ebc54ffac1c80d266b2aae7fc180fd60b11eab648cb58209af1505ad7e143b3b is already stopped" docker inspect: {u'Status': u'exited', u'Pid': 0, u'OOMKilled': False, u'Dead': False, u'Paused': False, u'Running': False, u'FinishedAt': u'2018-04-20T06:59:58.82009949Z', u'Restarting': False, u'Error': u'', u'StartedAt': u'2018-04-20T06:59:56.222696566Z', u'ExitCode': 100} {u'Data': {u'MergedDir': u'/var/lib/docker/overlay/55aeb58dae70c135646829a40dbb0da98ae8d785969dbf92590a76235928c18f/merged', u'WorkDir': u'/var/lib/docker/overlay/55aeb58dae70c135646829a40dbb0da98ae8d785969dbf92590a76235928c18f/work', u'LowerDir': u'/var/lib/docker/overlay/41a31cbd68b16a628073ddc9585761dcaa01ea042c9143ad5a8fb2cd46bc8aa1/root', u'UpperDir': u'/var/lib/docker/overlay/55aeb58dae70c135646829a40dbb0da98ae8d785969dbf92590a76235928c18f/upper'}, u'Name': u'overlay'}

Would be cool if anybody ould have an idea what could be the reason for that.

Best regards!

Andy

That feels like an error in the Univention appcenter API, as there are no obvious errors in the posted logs.

I’d just retry.

If that also fails the full docker logs output could be interesting: https://documentation.kopano.io/kopano_mattermost_manual/univention.html#logs-troubleshooting

I tried to install mattermost several times and the error stayed. After showing this error Mattermost is marked as installed in UCS but unfortunately no container has been created. So I had to rununivention-app remove mattermost --do-not-backup to get it uninstalled. Then I removed the image with docker rmi and tried an installation again. But the error stays. Docker itself is running, I already have Onlyoffice and Nextcloud running without any problems.

Docker ps only shows onlyoffice and nextcloud containers running. In the registry there are no variables vor Mattermost under appcenter/apps/. The only Mattermost variables are following:
image

What I could recognize is, that the MergedDir, WorkDir and UpperDir do not exist. The LowerDir is existing.

Andy

Thats strange. @dwiesent any idea why these variables are not created?

@raceface2nd anything in the logs I have requested in the previous post? The appcenter.log of Univention could be of interest as well.

Sorry, forgot to mention the logs. Please find below the output when I run univention-app install mattermost:

Downloading app image docker.software-univention.de/mattermost:4.9.0
Flag --email has been deprecated, will be removed in 1.14.
Login Succeeded
4.9.0: Pulling from mattermost
23a6960fe4a9: Already exists
e9e104b0e69d: Already exists
cd33d2ea7970: Already exists
534ff7b7d120: Already exists
7d352ac0c7f5: Already exists
384a37925448: Already exists
7837c9eeaac3: Already exists
ae4cf7f1e29b: Already exists
ac8a868deb56: Already exists
ab17d1239a6a: Already exists
fe69c67f8e36: Already exists
cafa764b6d91: Already exists
9870a47d5833: Already exists
Digest: sha256:94d30645c7320e919ef8e633364ddbae4c88e8838bde86a1c314352f9b00a488
Status: Image is up to date for docker.software-univention.de/mattermost:4.9.0
Initializing app image
Module: kopano-cfg
Preconfiguring container e7a8893f59919771d612cfcc0e994a2373c680003998ed16fa4500d4f6ea175a
Starting docker-app-mattermost (via systemctl): docker-app-mattermost.service.
Calling ['journalctl', '-n', '20', '-o', 'short', '/usr/bin/dockerd']
-- Logs begin at Thu 2018-04-19 18:36:54 CEST, end at Tue 2018-04-24 18:48:48 CEST. --
Apr 23 08:10:17 mail dockerd[2116]: time="2018-04-23T08:10:17.390217115+02:00" level=error msg="Error during layer Store.Cleanup(): device or resource busy"
Apr 23 08:10:17 mail dockerd[2116]: time="2018-04-23T08:10:17.391226601+02:00" level=info msg="stopping containerd after receiving terminated"
-- Reboot --
Apr 23 08:14:12 mail dockerd[2448]: time="2018-04-23T08:14:12.014668521+02:00" level=info msg="libcontainerd: new containerd process, pid: 2608"
Calling ['docker', 'logs', 'e7a8893f59919771d612cfcc0e994a2373c680003998ed16fa4500d4f6ea175a']
=> Start MySQL
 * Starting MySQL database server mysqld
   ...done.
=> Start Mattermost
[2018/04/24 16:48:44 UTC] [INFO] Using config file at /etc/mattermost/config.json
[2018/04/24 16:48:44 UTC] [INFO] Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'
[2018/04/24 16:48:44 UTC] [INFO] Server is initializing...
Going to remove Mattermost (4.9.0)
Module: kopano-cfg
Configuring 4.2/mattermost=4.9.0
Cannot run command: 4.2/mattermost=4.9.0 is not running in a container
setting default hostname
not setting CSP and x-frame options
using ucr defined certificate
using ucr defined private key
using ucs default ca
using ucr defined chain
Enabling site mattermost.
To activate the new configuration, you need to run:
  systemctl reload apache2
Create ucs/web/overview/entries/admin/mattermost/description
Create ucs/web/overview/entries/admin/mattermost/description/de
Create ucs/web/overview/entries/admin/mattermost/label
Create ucs/web/overview/entries/admin/mattermost/label/de
Create ucs/web/overview/entries/admin/mattermost/link
Create ucs/web/overview/entries/admin/mattermost/priority
Module: create_portal_entries
Module: kopano-cfg
Stopping docker-app-mattermost (via systemctl): docker-app-mattermost.service.
e7a8893f59919771d612cfcc0e994a2373c680003998ed16fa4500d4f6ea175a
e7a8893f59919771d612cfcc0e994a2373c680003998ed16fa4500d4f6ea175a
Removing localhost from LDAP object
Module: create_portal_entries
Don't know how to handle UCR key ucs/web/overview/entries/admin/mattermost/priority
File: /etc/univention/service.info/services/univention-appcenter.cfg
File: /usr/share/univention-portal/apps.json
Module: kopano-cfg
Multifile: /etc/apache2/sites-available/000-default.conf
Multifile: /etc/apache2/sites-available/default-ssl.conf
Multifile: /etc/postgresql/9.6/main/pg_hba.conf
Reloading apache2 configuration (via systemctl): apache2.service.
Installing join script /var/cache/univention-appcenter/appcenter.software-univention.de/4.2/mattermost_20180417113313.uinst
univention-run-join-scripts: runs all join scripts existing on local computer.
copyright (c) 2001-2018 Univention GmbH, Germany

Running 00kopano4ucs-safemode-on.inst skipped (already executed)
Running 01univention-ldap-server-init.inst skipped (already executed)
Running 02univention-directory-notifier.inst skipped (already executed)
Running 03univention-directory-listener.inst skipped (already executed)
Running 04univention-ldap-client.inst skipped (already executed)
Running 05univention-bind.inst skipped (already executed)
Running 08univention-apache.inst skipped (already executed)
Running 10univention-ldap-server.inst skipped (already executed)
Running 11univention-heimdal-init.inst skipped (already executed)
Running 11univention-pam.inst skipped (already executed)
Running 15univention-directory-notifier-post.inst skipped (already executed)
Running 15univention-heimdal-kdc.inst skipped (already executed)
Running 18python-univention-directory-manager.inst skipped (already executed)
Running 20univention-directory-policy.inst skipped (already executed)
Running 20univention-join.inst skipped (already executed)
Running 25univention-dhcp.inst skipped (already executed)
Running 26univention-nagios-common.inst skipped (already executed)
Running 28univention-nagios-server.inst skipped (already executed)
Running 30univention-appcenter.inst skipped (already executed)
Running 30univention-nagios-client.inst skipped (already executed)
Running 31univention-nagios-libvirtd-kvm.inst skipped (already executed)
Running 31univention-nagios-s4-connector.inst skipped (already executed)
Running 31univention-nagios-samba.inst skipped (already executed)
Running 31univention-nagios-uvmmd.inst skipped (already executed)
Running 33univention-portal.inst skipped (already executed)
Running 34univention-management-console-server.inst skipped (already executed)
Running 34univention-self-service.inst skipped (already executed)
Running 35univention-appcenter-docker.inst skipped (already executed)
Running 35univention-management-console-module-appcenter.inst skipped (already executed)
Running 35univention-management-console-module-diagnostic.inst skipped (already executed)
Running 35univention-management-console-module-ipchange.inst skipped (already executed)
Running 35univention-management-console-module-join.inst skipped (already executed)
Running 35univention-management-console-module-lib.inst skipped (already executed)
Running 35univention-management-console-module-mrtg.inst skipped (already executed)
Running 35univention-management-console-module-printers.inst skipped (already executed)
Running 35univention-management-console-module-quota.inst skipped (already executed)
Running 35univention-management-console-module-reboot.inst skipped (already executed)
Running 35univention-management-console-module-services.inst skipped (already executed)
Running 35univention-management-console-module-setup.inst skipped (already executed)
Running 35univention-management-console-module-sysinfo.inst skipped (already executed)
Running 35univention-management-console-module-top.inst skipped (already executed)
Running 35univention-management-console-module-ucr.inst skipped (already executed)
Running 35univention-management-console-module-udm.inst skipped (already executed)
Running 35univention-management-console-module-updater.inst skipped (already executed)
Running 35univention-nagios-cups.inst skipped (already executed)
Running 35univention-nagios-dansguardian.inst skipped (already executed)
Running 35univention-nagios-squid.inst skipped (already executed)
Running 35univention-self-service-passwordreset-umc.inst skipped (already executed)
Running 35univention-server-overview.inst skipped (already executed)
Running 36univention-management-console-module-apps.inst skipped (already executed)
Running 40univention-postgresql.inst skipped (already executed)
Running 40univention-virtual-machine-manager-schema.inst skipped (already executed)
Running 43univention-virtual-machine-manager-node-common.inst skipped (already executed)
Running 44univention-virtual-machine-manager-daemon.inst skipped (already executed)
Running 44univention-virtual-machine-manager-node-kvm.inst skipped (already executed)
Running 45univention-management-console-module-uvmm.inst skipped (already executed)
Running 50dudle.inst skipped (already executed)
Running 50nextcloud.inst skipped (already executed)
Running 50onlyoffice-ds.inst skipped (already executed)
Running 70kopano4ucs-udm.inst skipped (already executed)
Running 70kopano4ucs.inst skipped (already executed)
Running 71kopano4ucs-webapp.inst skipped (already executed)
Running 79univention-printserver.inst skipped (already executed)
Running 81univention-nfs-server.inst skipped (already executed)
Running 90univention-bind-post.inst skipped (already executed)
Running 91univention-saml.inst skipped (already executed)
Running 92univention-management-console-web-server.inst skipped (already executed)
Running 96univention-samba4.inst skipped (already executed)
Running 97univention-s4-connector.inst skipped (already executed)
Running 98univention-pkgdb-tools.inst skipped (already executed)
Running 98univention-samba4-dns.inst skipped (already executed)
Running 98univention-samba4-saml-kerberos.inst skipped (already executed)
Running 99kopano4ucs-safemode-off.inst skipped (already executed)
Running 51mattermost-uninstall.uinst done
Press [ENTER] to continue

The container for 4.2/mattermost=4.9.0 could not be started!

docker logs e7a8893f59919771d612cfcc0e994a2373c680003998ed16fa4500d4f6ea175a:
=> Start MySQL
 * Starting MySQL database server mysqld
   ...done.
=> Start Mattermost
[2018/04/24 16:48:44 UTC] [INFO] Using config file at /etc/mattermost/config.json
[2018/04/24 16:48:44 UTC] [INFO] Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'
[2018/04/24 16:48:44 UTC] [INFO] Server is initializing...

dockerd logs:
-- Logs begin at Thu 2018-04-19 18:36:54 CEST, end at Tue 2018-04-24 18:48:48 CEST. --
Apr 23 08:10:17 mail dockerd[2116]: time="2018-04-23T08:10:17.390217115+02:00" level=error msg="Error during layer Store.Cleanup(): device or resource busy"
Apr 23 08:10:17 mail dockerd[2116]: time="2018-04-23T08:10:17.391226601+02:00" level=info msg="stopping containerd after receiving terminated"
-- Reboot --
Apr 23 08:14:12 mail dockerd[2448]: time="2018-04-23T08:14:12.014668521+02:00" level=info msg="libcontainerd: new containerd process, pid: 2608"

docker inspect:
{u'Status': u'exited', u'Pid': 0, u'OOMKilled': False, u'Dead': False, u'Paused': False, u'Running': False, u'FinishedAt': u'2018-04-24T16:48:46.053111032Z', u'Restarting': False, u'Error': u'', u'StartedAt': u'2018-04-24T16:48:43.48823508Z', u'ExitCode': 100}
{u'Data': {u'MergedDir': u'/var/lib/docker/overlay/9bfd7bdc7c308ee88a3489f06e15bcb6d4b5981998b4270ac641aa4cd0e82394/merged', u'WorkDir': u'/var/lib/docker/overlay/9bfd7bdc7c308ee88a3489f06e15bcb6d4b5981998b4270ac641aa4cd0e82394/work', u'LowerDir': u'/var/lib/docker/overlay/01de8ab01a887f9ff0aa634e1fe2842f4f821664091ca5c2bc2328a044379b15/root', u'UpperDir': u'/var/lib/docker/overlay/9bfd7bdc7c308ee88a3489f06e15bcb6d4b5981998b4270ac641aa4cd0e82394/upper'}, u'Name': u'overlay'}
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/__init__.py", line 226, in call_with_namespace
    result = self.main(namespace)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 73, in main
    return self.do_it(args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install_base.py", line 105, in do_it
    self._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 63, in _do_it
    ret = super(Install, self)._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 90, in _do_it
    if self._install_app(app, args):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 57, in _install_app
    self._start_docker_image(app, hostdn, password, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_base.py", line 249, in _start_docker_image
    raise AppCenterErrorContainerStart(msg)

Andy

This looks like the Container is starting and then the Appcenter decides something went wrong and wants to remove it again.

@dwiesent did you already have time to look into this?

@raceface2nd: Thanks for the logs, this helps. You could also try:
univention-app install mattermost --do-not-revert
which does not remove the App even if there was a problem with the Container. You would need to remove it afterwards with
univention-app remove mattermost --do-not-backup
but in the meantime, you could examine the container further. (Find the container with docker ps -a and then look at docker logs $container)
Is there any obvious “special setup” that could interfere with Docker itself? Do you use a non-standard File System like XFS or Btrfs? Do you have limited RAM? Are you able to run any other Docker based App (e.g., wordpress)?

@fbartels: Everything seems to go fine up to that point. From the output, this may be important:

{u’Status’: u’exited’, u’Pid’: 0, u’OOMKilled’: False, u’Dead’: False, u’Paused’: False, u’Running’: False, u’FinishedAt’: u’2018-04-24T16:48:46.053111032Z’, u’Restarting’: False, u’Error’: u’’, u’StartedAt’: u’2018-04-24T16:48:43.48823508Z’, u’ExitCode’: 100}

So it seems the container indeed stopped. This is not done by the App Center and the App Center does not know “why” it happened. Normally, /start.sh just exited. Maybe the operating system stopped it due to disk space or RAM?

@dwiesent: The filesystem on the server is ext. 2 disks in a hardware raid 1. While installation of UCS I used the option Use entire disk with LVM.

Disk space should not be a problem, neither RAM.

Dateisystem             Größe Benutzt Verf. Verw% Eingehängt auf
udev                      10M       0   10M    0% /dev
tmpfs                    6,3G     16M  6,3G    1% /run
/dev/mapper/vg_ucs-root   29G    9,0G   19G   33% /
tmpfs                     16G     68K   16G    1% /dev/shm
tmpfs                    5,0M       0  5,0M    0% /run/lock
tmpfs                     16G       0   16G    0% /sys/fs/cgroup
/dev/sda1                472M     61M  387M   14% /boot
/dev/mapper/vg_ucs-home 1022G     77M  969G    1% /home
overlay                   29G    9,0G   19G   33% /var/lib/docker/overlay/a815bafb2912f35f026ae9494f4f81e023904babc0a6ace5d8904a900d2b0410/merged
overlay                   29G    9,0G   19G   33% /var/lib/docker/overlay/261d9f5d9bbe46e0c6558772b8c57fa43b9d1f20dbf4dd258d1c8f9be1f1f257/merged
shm                       64M       0   64M    0% /var/lib/docker/containers/8fdd9cc4441c3767fa8440ae9aa52023e47eada97fc92507b39777361457e046/shm
shm                       64M       0   64M    0% /var/lib/docker/containers/f1f1cf841eda2d664cf2275a18039759d277706e915f31691c678f925053cd20/shm
overlay                   29G    9,0G   19G   33% /var/lib/docker/overlay/6dd66e0bc904e7c503db0de24a2930faa4c92bce406a1cf1f51ee9d92133c14c/merged
shm                       64M       0   64M    0% /var/lib/docker/containers/f4b89b483b06b973528e958c8ca90a5872c0b1423863ce4f204fc6f47acb2a40/shm
root@mail:~# free -m
              total        used        free      shared  buff/cache   available
Mem:          32165        2449       25968          71        3747       29188
Swap:         32755           0       32755

There are running several docker based apps (onlyoffice, nextcloud, dudle)

root@mail:~# docker ps
CONTAINER ID        IMAGE                                                  COMMAND                  CREATED             STATUS              PORTS                                           NAMES
f4b89b483b06        docker.software-univention.de/ucs-appbox-amd64:4.1-4   "/sbin/init"             44 hours ago        Up 44 hours         0.0.0.0:40001->80/tcp, 0.0.0.0:40002->443/tcp   cocky_rosalind
8fdd9cc4441c        docker.software-univention.de/nextcloud:12.0.6-0       "/bin/sh -c /usr/s..."   5 days ago          Up 46 hours         0.0.0.0:40000->80/tcp                           xenodochial_feynman
f1f1cf841eda        onlyoffice/documentserver:5.0.6.14                     "/bin/sh -c 'bash ..."   5 days ago          Up 46 hours         80/tcp, 0.0.0.0:5443->443/tcp                   wizardly_thompson

Onlyoffice and nextcloud have been installed before the first try of mattermost and dudle recently.

I tried install of mattermost with univention-app install mattermost --do-not-revert but there is still no container. The installer throws now

Creating data directories for mattermost...
Copying /var/cache/univention-appcenter/appcenter.software-univention.de/4.2/mattermost_20180417113313.schema
Registering UCR for mattermost
Marking 4.2/mattermost=4.9.0 as installed
File: /etc/univention/service.info/services/univention-appcenter.cfg
File: /usr/share/univention-portal/apps.json
Module: kopano-cfg
Multifile: /etc/postgresql/9.6/main/pg_hba.conf
Multifile: /etc/apache2/sites-available/000-default.conf
Multifile: /etc/apache2/sites-available/default-ssl.conf
Module: kopano-cfg
Creating /etc/init.d/docker-app-mattermost
Adding localhost to LDAP object
Setting overview variables
Module: create_portal_entries
Module: kopano-cfg
Reloading apache2 configuration (via systemctl): apache2.service.
Registering schema /usr/share/univention-appcenter/apps/mattermost/mattermost.schema
INFO: No change of core data of object mattermost.
No modification: cn=mattermost,cn=ldapschema,cn=univention,dc removed

WARNING: cannot append mattermost to appidentifier, value exists
No modification: cn=mattermost,cn=ldapschema,cn=univention,dc removed

Waiting for activation of the extension object mattermost: OK
Registering the container host matte-32884959 for mattermost
Module: kopano-cfg
Verifying Docker registry manifest for app image docker.software-univention.de/mattermost:4.9.0
Downloading app image docker.software-univention.de/mattermost:4.9.0
Flag --email has been deprecated, will be removed in 1.14.
Login Succeeded
4.9.0: Pulling from mattermost
23a6960fe4a9: Already exists
e9e104b0e69d: Already exists
cd33d2ea7970: Already exists
534ff7b7d120: Already exists
7d352ac0c7f5: Already exists
384a37925448: Already exists
7837c9eeaac3: Already exists
ae4cf7f1e29b: Already exists
ac8a868deb56: Already exists
ab17d1239a6a: Already exists
fe69c67f8e36: Already exists
cafa764b6d91: Already exists
9870a47d5833: Already exists
Digest: sha256:94d30645c7320e919ef8e633364ddbae4c88e8838bde86a1c314352f9b00a488
Status: Image is up to date for docker.software-univention.de/mattermost:4.9.0
Initializing app image
Module: kopano-cfg
Preconfiguring container 99c025197a06025b67a3d2422334b55d250f9c00fdff6441301f3c3cd1df8369
Starting docker-app-mattermost (via systemctl): docker-app-mattermost.service.
Calling ['journalctl', '-n', '20', '-o', 'short', '/usr/bin/dockerd']
-- Logs begin at Thu 2018-04-19 18:36:54 CEST, end at Wed 2018-04-25 07:14:56 CEST. --
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.474935431+02:00" level=info msg="Graph migration to content-addressability took 0.00 seconds"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475218986+02:00" level=warning msg="Your kernel does not support swap memory limit"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475286872+02:00" level=warning msg="Your kernel does not support cgroup rt period"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475303913+02:00" level=warning msg="Your kernel does not support cgroup rt runtime"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.481031248+02:00" level=info msg="Loading containers: start."
Calling ['docker', 'logs', '99c025197a06025b67a3d2422334b55d250f9c00fdff6441301f3c3cd1df8369']
=> Start MySQL
 * Starting MySQL database server mysqld
   ...done.
=> Start Mattermost
[2018/04/25 05:14:55 UTC] [INFO] Using config file at /etc/mattermost/config.json
[2018/04/25 05:14:55 UTC] [INFO] Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'
File: /usr/share/univention-management-console/modules/apps.xml

Module: kopano-cfg

File: /usr/share/univention-management-console/i18n/de/apps.mo

File: /etc/apt/apt.conf.d/55user_agent

4.2/mattermost=4.9.0: Not running, cannot check further

The container for 4.2/mattermost=4.9.0 could not be started!

docker logs 99c025197a06025b67a3d2422334b55d250f9c00fdff6441301f3c3cd1df8369:
=> Start MySQL
 * Starting MySQL database server mysqld
   ...done.
=> Start Mattermost
[2018/04/25 05:14:55 UTC] [INFO] Using config file at /etc/mattermost/config.json
[2018/04/25 05:14:55 UTC] [INFO] Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'

dockerd logs:
-- Logs begin at Thu 2018-04-19 18:36:54 CEST, end at Wed 2018-04-25 07:14:56 CEST. --
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.474935431+02:00" level=info msg="Graph migration to content-addressability took 0.00 seconds"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475218986+02:00" level=warning msg="Your kernel does not support swap memory limit"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475286872+02:00" level=warning msg="Your kernel does not support cgroup rt period"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475303913+02:00" level=warning msg="Your kernel does not support cgroup rt runtime"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.481031248+02:00" level=info msg="Loading containers: start."

docker inspect:
{u'Status': u'exited', u'Pid': 0, u'OOMKilled': False, u'Dead': False, u'Paused': False, u'Running': False, u'FinishedAt': u'2018-04-25T05:14:56.705533136Z', u'Restarting': False, u'Error': u'', u'StartedAt': u'2018-04-25T05:14:54.121313103Z', u'ExitCode': 100}
{u'Data': {u'MergedDir': u'/var/lib/docker/overlay/6949055667c662384da2ea324192f61bcaf7a703a8c88d55710301159d17c9e9/merged', u'WorkDir': u'/var/lib/docker/overlay/6949055667c662384da2ea324192f61bcaf7a703a8c88d55710301159d17c9e9/work', u'LowerDir': u'/var/lib/docker/overlay/01de8ab01a887f9ff0aa634e1fe2842f4f821664091ca5c2bc2328a044379b15/root', u'UpperDir': u'/var/lib/docker/overlay/6949055667c662384da2ea324192f61bcaf7a703a8c88d55710301159d17c9e9/upper'}, u'Name': u'overlay'}
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/__init__.py", line 226, in call_with_namespace
    result = self.main(namespace)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 73, in main
    return self.do_it(args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install_base.py", line 105, in do_it
    self._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 63, in _do_it
    ret = super(Install, self)._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 90, in _do_it
    if self._install_app(app, args):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 57, in _install_app
    self._start_docker_image(app, hostdn, password, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_base.py", line 249, in _start_docker_image
    raise AppCenterErrorContainerStart(msg)

Andy

Hmm… that’s weird. So the container gets terminated. As @dwiesent suggested can you post the output of docker ps -a ? If the container was stopped a reason should be logged here.

Another idea: could you try one of the previous versions? E.g. univention-app install mattermost=4.8.0?

@dwiesent thanks for looking at the logs.

Ah, now also noticed the {u’Status’: u’exited’, u’Pid’: 0, u’OOMKilled’: message.

Sorry, forgot. Here’s the output of docker ps -a

root@mail:~# docker ps -a
CONTAINER ID        IMAGE                                                  COMMAND                  CREATED             STATUS                     PORTS                                           NAMES
99c025197a06        docker.software-univention.de/mattermost:4.9.0         "/start.sh"              3 hours ago         Exited (100) 3 hours ago                                                   lucid_haibt
f4b89b483b06        docker.software-univention.de/ucs-appbox-amd64:4.1-4   "/sbin/init"             2 days ago          Up 2 days                  0.0.0.0:40001->80/tcp, 0.0.0.0:40002->443/tcp   cocky_rosalind
8fdd9cc4441c        docker.software-univention.de/nextcloud:12.0.6-0       "/bin/sh -c /usr/s..."   5 days ago          Up 2 days                  0.0.0.0:40000->80/tcp                           xenodochial_feynman
f1f1cf841eda        onlyoffice/documentserver:5.0.6.14                     "/bin/sh -c 'bash ..."   5 days ago          Up 2 days                  80/tcp, 0.0.0.0:5443->443/tcp                   wizardly_thompson

Trying to install 4.8.0 does not work either :frowning:

docker logs 4d6d46261507677a3aac4267aa5cfb272b34d35a0b48c45460b719147d4f7b25:
=> Update Mattermost plugin directory
ls: cannot access '/opt/mattermost/plugins.orig': No such file or directory
=> Start MySQL
 * Starting MySQL database server mysqld
   ...done.
=> Start Mattermost
[2018/04/25 08:33:57 UTC] [INFO] Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'

dockerd logs:
-- Logs begin at Thu 2018-04-19 18:36:54 CEST, end at Wed 2018-04-25 10:33:59 CEST. --
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.481031248+02:00" level=info msg="Loading containers: start."
Apr 23 08:14:21 mail dockerd[2448]: time="2018-04-23T08:14:21.238584984+02:00" level=info msg="Firewalld running: false"
Apr 23 08:14:23 mail dockerd[2448]: time="2018-04-23T08:14:23.714802875+02:00" level=info msg="Loading containers: done."
Apr 23 08:14:23 mail dockerd[2448]: time="2018-04-23T08:14:23.831626669+02:00" level=warning msg="failed to retrieve docker-init version: unknown output format: tini version 0.13.0\n"
Apr 23 08:14:23 mail dockerd[2448]: time="2018-04-23T08:14:23.856728115+02:00" level=info msg="Daemon has completed initialization"

docker inspect:
{u'Status': u'exited', u'Pid': 0, u'OOMKilled': False, u'Dead': False, u'Paused': False, u'Running': False, u'FinishedAt': u'2018-04-25T08:33:58.963639379Z', u'Restarting': False, u'Error': u'', u'StartedAt': u'2018-04-25T08:33:56.368963617Z', u'ExitCode': 100}
{u'Data': {u'MergedDir': u'/var/lib/docker/overlay/113339b3aa95b54cced7c525e1270bcc37d87b220f4a4207a9d48883b8fe757c/merged', u'WorkDir': u'/var/lib/docker/overlay/113339b3aa95b54cced7c525e1270bcc37d87b220f4a4207a9d48883b8fe757c/work', u'LowerDir': u'/var/lib/docker/overlay/bed822778d6fdf7e40810b948e9972158601ca8a23486e99b5f31b2b217a7fb7/root', u'UpperDir': u'/var/lib/docker/overlay/113339b3aa95b54cced7c525e1270bcc37d87b220f4a4207a9d48883b8fe757c/upper'}, u'Name': u'overlay'}
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/__init__.py", line 226, in call_with_namespace
    result = self.main(namespace)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 73, in main
    return self.do_it(args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install_base.py", line 105, in do_it
    self._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 63, in _do_it
    ret = super(Install, self)._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 90, in _do_it
    if self._install_app(app, args):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 57, in _install_app
    self._start_docker_image(app, hostdn, password, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_base.py", line 249, in _start_docker_image
    raise AppCenterErrorContainerStart(msg)

Now docker ps -a is NOT showing a container for mattermost.

Andy

Which is quite natural, since you now probably did not include --do-not-revert

While the start.sh script is instructed to stop at errors, I would expect an error to be logged.

I’m out of ideas.

You’re right, that I forgot do not revert.

In one of my earlier posts I found the following log entries

-- Logs begin at Thu 2018-04-19 18:36:54 CEST, end at Wed 2018-04-25 07:14:56 CEST. --
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.474935431+02:00" level=info msg="Graph migration to content-addressability took 0.00 seconds"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475218986+02:00" level=warning msg="Your kernel does not support swap memory limit"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475286872+02:00" level=warning msg="Your kernel does not support cgroup rt period"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.475303913+02:00" level=warning msg="Your kernel does not support cgroup rt runtime"
Apr 23 08:14:20 mail dockerd[2448]: time="2018-04-23T08:14:20.481031248+02:00" level=info msg="Loading containers: start."
Calling ['docker', 'logs', '99c025197a06025b67a3d2422334b55d250f9c00fdff6441301f3c3cd1df8369']

Next days I am travelling but will try to dig deeper into the logs of the container, maybe I will find something of interest I can post.

Andy

In the log file I could figure out following messages. Looks like that there went something wrong with the binds

{"log":"=\u003e Update Mattermost plugin directory\n","stream":"stdout","time":"2018-04-25T17:45:00.732131458Z"}
{"log":"ls: cannot access '/opt/mattermost/plugins.orig': No such file or directory\n","stream":"stderr","time":"2018-04-25T17:45:00.733946983Z"}
{"log":"=\u003e Start MySQL\n","stream":"stdout","time":"2018-04-25T17:45:00.734308202Z"}
{"log":" * Starting MySQL database server mysqld\n","stream":"stdout","time":"2018-04-25T17:45:00.773739613Z"}
{"log":"   ...done.\n","stream":"stdout","time":"2018-04-25T17:45:05.890299128Z"}
{"log":"=\u003e Start Mattermost\n","stream":"stdout","time":"2018-04-25T17:45:05.893525865Z"}
{"log":"[2018/04/25 17:45:06 UTC] [INFO] Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'\n","stream":"stdout","time":"2018-04-25T17:45:06.196264782Z"}
{"log":"[2018/04/25 17:45:06 UTC] [INFO] Server is initializing...\n","stream":"stdout","time":"2018-04-25T17:45:06.196309829Z"}
{"log":"[2018/04/25 17:45:06 UTC] [INFO] Pinging SQL master database\n","stream":"stdout","time":"2018-04-25T17:45:06.201906072Z"}
{"log":"[2018/04/25 17:45:06 UTC] [CRIT] Error creating database tables: Error 1146: Table 'mattermost.Systems' doesn't exist\n","stream":"stdout","time":"2018-04-25T17:45:06.220762869Z"}

Andy

Have you meanwhile activated the test appcenter? While the mount already exists in the 4.9.0 app, the log message you posted is not part of the 4.9.0 app.

One thing that you could also try, is starting the app manually (similar to how its explained in https://documentation.kopano.io/kopano_mattermost_manual/univention.html#restoring-a-mysql-dump-in-the-docker-container) and then manually start start.sh and see what happens.

Edit: ah, found the log line. I apparently did put it in the master branch before pushing the last update. But this should not have any effect on the startup error as he continues past that point.

No, I did not install the test app center. I was using a brand new installation of UCS, no additional users only NC, Onlyoffice and Kopano have been installed before I tried mattermost.

As I am out of office until tomorrow night I will investigate more over the weekend.

Andy

Hello @raceface2nd

FYI: How to activate the Test App Center.

Disclaimer: Please do only use the Test App Center for investigation of your issue. It is not intended to be used for production use, only for development for App Providers.

Best regards,
Nico

My question was not really an invitation to enable the test appcenter, I was merely wondering where the specific log message came from. But if you enable the test appcenter, you’ll find an update that would also include a preview of the new Kopano Web Meetings. (but if 4.8 and 4.9 does not install, I give it low chances that this one will)

Following Felix’ hint to start the app manually brought following log entries in the mysql error.log inside the container.

2018-04-17T09:38:15.682399Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2018-04-17T09:38:16.281499Z 0 [Warning] InnoDB: New log files created, LSN=45790
2018-04-17T09:38:16.409743Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
2018-04-17T09:38:16.487285Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 0e3b8dc4-4223-11$
2018-04-17T09:38:16.498172Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
2018-04-17T09:38:16.499519Z 1 [Warning] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2018-04-27T22:06:44.975076Z mysqld_safe Logging to '/var/log/mysql/error.log'.
2018-04-27T22:06:45.033676Z mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
2018-04-27T22:06:45.229965Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2018-04-27T22:06:45.231539Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.21-0ubuntu0.16.04.1) starting as process 483 ...
2018-04-27T22:06:45.236328Z 0 [Note] InnoDB: PUNCH HOLE support available
2018-04-27T22:06:45.236389Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-04-27T22:06:45.236417Z 0 [Note] InnoDB: Uses event mutexes
2018-04-27T22:06:45.236443Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-04-27T22:06:45.236469Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2018-04-27T22:06:45.236494Z 0 [Note] InnoDB: Using Linux native AIO
2018-04-27T22:06:45.236761Z 0 [Note] InnoDB: Number of pools: 1
2018-04-27T22:06:45.236891Z 0 [Note] InnoDB: Using CPU crc32 instructions
2018-04-27T22:06:45.238781Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2018-04-27T22:06:45.247258Z 0 [Note] InnoDB: Completed initialization of buffer pool
2018-04-27T22:06:45.249655Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2018-04-27T22:06:45.262247Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2018-04-27T22:06:45.277592Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2658979
2018-04-27T22:06:45.277664Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 2658988
2018-04-27T22:06:45.277708Z 0 [Note] InnoDB: Database was not shutdown normally!
2018-04-27T22:06:45.277748Z 0 [Note] InnoDB: Starting crash recovery.
2018-04-27T22:06:45.435074Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2018-04-27T22:06:45.435170Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2018-04-27T22:06:45.435275Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2018-04-27T22:06:45.530902Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2018-04-27T22:06:45.531959Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2018-04-27T22:06:45.531999Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2018-04-27T22:06:45.533090Z 0 [Note] InnoDB: 5.7.21 started; log sequence number 2658988
2018-04-27T22:06:45.533370Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2018-04-27T22:06:45.533691Z 0 [Note] Plugin 'FEDERATED' is disabled.
2018-04-27T22:06:45.536434Z 0 [Note] InnoDB: Buffer pool(s) load completed at 180427 22:06:45
2018-04-27T22:06:45.540280Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
2018-04-27T22:06:45.540346Z 0 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
2018-04-27T22:06:45.540393Z 0 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
2018-04-27T22:06:45.540456Z 0 [Note] Server socket created on IP: '0.0.0.0'.
2018-04-27T22:06:45.573347Z 0 [Note] Event Scheduler: Loaded 0 events
2018-04-27T22:06:45.573743Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.7.21-0ubuntu0.16.04.1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu)
2018-04-27T22:06:45.706136Z 2 [Note] Access denied for user 'debian-sys-maint'@'localhost' (using password: YES)
2018-04-27T22:06:45.726734Z 3 [Note] Access denied for user 'debian-sys-maint'@'localhost' (using password: YES)
2018-04-27T22:06:46.094763Z 4 [Warning] InnoDB: Cannot open table mattermost/Systems from the internal data dictionary of InnoDB though the .frm file for the table exists. Please refer to $
2018-04-27T22:06:47.100068Z 4 [Note] Aborted connection 4 to db: 'mattermost' user: 'mmuser' host: 'localhost' (Got an error reading communication packets)

Andy

So the database files got somehow corrupted?

Will you be able to install mattermost if you “reset” the app by removing the data files of mysql?

That got it running somehow. I deleted everything inside the folder /var/lib/univention-appcenter/apps/mattermost/mysql and started the original container.

After this I recognized, that the apache config for mattermost has not been enabled so I enabled it with a2ensite mattermost and reloaded the apache.

Unfortunately I do not get access to mattermost. As described in the app info I tried with administrator and mattermost but mattermost returns We couldn't find an account matching your login credentials.

Looking into /var/log/mattermost.log I found the following warnings.

[2018/04/29 10:01:53 UTC] [WARN] unable to create user namespace: fork/exec /proc/self/exe: operation not permitted
[2018/04/29 10:01:53 UTC] [WARN] plugin sandboxing is not supported. plugins will run with the same access level as the server. See documentation to learn more: https://developers.mattermost.com/extend/plugins/security/

So I tried to reset the password using the CLI but got following

root@matte-66251310:/opt/mattermost/bin# ./platform user password administrator mattermost
[10:23:31 UTC 2018/04/29] [INFO] (github.com/mattermost/mattermost-server/app.(*App).Shutdown:212) Stopping Server...
[10:23:31 UTC 2018/04/29] [INFO] (github.com/mattermost/mattermost-server/app.(*App).HubStop:114) stopping websocket hub connections
[10:23:31 UTC 2018/04/29] [WARN] (github.com/mattermost/mattermost-server/app.(*App).HubStop:119) We appear to have already sent the stop checking for deadlocks command
[10:23:31 UTC 2018/04/29] [INFO] (github.com/mattermost/mattermost-server/app.(*App).Shutdown:231) Server stopped
panic: LoadConfig: Error opening config file=config.json, err=no config file found,

goroutine 1 [running]:
github.com/mattermost/mattermost-server/cmd.InitDBCommandContextCobra(0x2480a40, 0xc4200a7700, 0xc420544310, 0xc420525cb0)
        /var/lib/jenkins/jobs/msr/jobs/d/jobs/enterprise-release/workspace/src/github.com/mattermost/mattermost-server/cmd/init.go:22 +0xf5
github.com/mattermost/mattermost-server/cmd/commands.resetUserPasswordCmdF(0x2480a40, 0xc4205442c0, 0x2, 0x2, 0x0, 0x0)
        /var/lib/jenkins/jobs/msr/jobs/d/jobs/enterprise-release/workspace/src/github.com/mattermost/mattermost-server/cmd/commands/user.go:380 +0x40
github.com/mattermost/mattermost-server/vendor/github.com/spf13/cobra.(*Command).execute(0x2480a40, 0xc420544200, 0x2, 0x2, 0x2480a40, 0xc420544200)
        /var/lib/jenkins/jobs/msr/jobs/d/jobs/enterprise-release/workspace/src/github.com/mattermost/mattermost-server/vendor/github.com/spf13/cobra/command.go:753 +0x475
github.com/mattermost/mattermost-server/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x24800c0, 0x24ba100, 0xc420525f40, 0x10f863c)
        /var/lib/jenkins/jobs/msr/jobs/d/jobs/enterprise-release/workspace/src/github.com/mattermost/mattermost-server/vendor/github.com/spf13/cobra/command.go:843 +0x334
github.com/mattermost/mattermost-server/vendor/github.com/spf13/cobra.(*Command).Execute(0x24800c0, 0x0, 0xc420525f40)
        /var/lib/jenkins/jobs/msr/jobs/d/jobs/enterprise-release/workspace/src/github.com/mattermost/mattermost-server/vendor/github.com/spf13/cobra/command.go:791 +0x2b
github.com/mattermost/mattermost-server/cmd.Run(0xc420010150, 0x4, 0x4, 0xc420525f70, 0x1109719)
        /var/lib/jenkins/jobs/msr/jobs/d/jobs/enterprise-release/workspace/src/github.com/mattermost/mattermost-server/cmd/cmd.go:14 +0x6d
main.main()
        /var/lib/jenkins/jobs/msr/jobs/d/jobs/enterprise-release/workspace/src/github.com/mattermost/mattermost-server/main.go:33 +0x63

Andy

Mastodon