mattermost / mattermost

Mattermost is an open source platform for secure collaboration across the entire software development lifecycle..
https://mattermost.com
Other
30.84k stars 7.4k forks source link

[MM-35029] Improve logging during make run-server #17433

Open hakansa opened 3 years ago

hakansa commented 3 years ago

Summary

I couldn't run mattermost-server on Ubuntu 18.04. I followed the Developer Setup

Steps to reproduce

Detailed information is below;

root@vultr:~/mattermost-server# go version
go version go1.16.3 linux/amd64
root@vultr:~/mattermost-server#
root@vultr:~/mattermost-server# git describe
v5.3.1-3265-g3a13987ee
root@vultr:~/mattermost-server# uname -a
Linux vultr.guest 4.15.0-132-generic #136-Ubuntu SMP Tue Jan 12 14:58:42 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
root@vultr:~/mattermost-server#
root@vultr:~/mattermost-server# docker version
Client: Docker Engine - Community
 Version:           20.10.6
 API version:       1.41
 Go version:        go1.13.15
 Git commit:        370c289
 Built:             Fri Apr  9 22:46:01 2021
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.6
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.13.15
  Git commit:       8728dd2
  Built:            Fri Apr  9 22:44:13 2021
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.4.4
  GitCommit:        05f951a3781f4f2c1911b05e61c160e9c30eaa8e
 runc:
  Version:          1.0.0-rc93
  GitCommit:        12644e614e25b05da6fd08a38ffa0cfe1903fdec
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0
root@vultr:~/mattermost-server#

Expected behavior

Run mattermost server.

Observed behavior (that appears unintentional)

When I run make run-server, I got the following output;

root@vultr:~/mattermost-server# make run-server
Downloading prepackaged binary: https://releases.mattermost.com/mmctl/master
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 21.4M  100 21.4M    0     0  90.6M      0 --:--:-- --:--:-- --:--:-- 90.2M
mmctl
Starting docker containers
go run ./build/docker-compose-generator/main.go mysql postgres inbucket  minio | docker-compose -f docker-compose.makefile.yml -f /dev/stdin run --rm start_dependencies
Creating network "mattermost-server_mm-test" with driver "bridge"
Pulling postgres (postgres:10)...
10: Pulling from library/postgres
62deabe7a6db: Pull complete
24c7b6331486: Pull complete
00b83e6d4b38: Pull complete
0e54c5150202: Pull complete
31dd3ef3701c: Pull complete
a7a29ab258fa: Pull complete
0d30412e41ab: Pull complete
f300ff05c105: Pull complete
a94098507ba9: Pull complete
0138ee4935fb: Pull complete
0178834a4ed0: Pull complete
629b1c12e59a: Pull complete
bc3476ca3abd: Pull complete
b6e0c1fc65f3: Pull complete
Digest: sha256:8558d6a7c1a751e097e52dda3992e09c5de2fc501cb6fc682862940670627578
Status: Downloaded newer image for postgres:10
Pulling mysql (mysql:5.6)...
5.6: Pulling from library/mysql
62deabe7a6db: Already exists
81ba35f9cdf1: Pull complete
5c8f6a545aa1: Pull complete
9ced99c328da: Pull complete
1983b7d65f8f: Pull complete
2fc89d436e20: Pull complete
6cd56cc7fc71: Pull complete
ff26e0e5f66f: Pull complete
cf5586a4456d: Pull complete
53d17e698ea2: Pull complete
b5c84062b3c4: Pull complete
Digest: sha256:5d63153bf35070c230b9d41a754651d99053cbf19a9eec70ebeba926a304761f
Status: Downloaded newer image for mysql:5.6
Pulling minio (minio/minio:RELEASE.2019-10-11T00-38-09Z)...
RELEASE.2019-10-11T00-38-09Z: Pulling from minio/minio
e7c96db7181b: Pull complete
d5e5170863b7: Pull complete
d98aad23d939: Pull complete
Digest: sha256:0d02f16a1662653f9b961211b21ed7de04bf04492f44c2b7594bacbfcc519eb5
Status: Downloaded newer image for minio/minio:RELEASE.2019-10-11T00-38-09Z
Pulling inbucket (jhillyerd/inbucket:release-1.2.0)...
release-1.2.0: Pulling from jhillyerd/inbucket
1160f4abea84: Pull complete
4d49542c61a4: Pull complete
3ee103c86f60: Pull complete
9a56d2eb1eed: Pull complete
67e0ebed9a3b: Pull complete
194910951a14: Pull complete
501db3b40976: Pull complete
c688e5339531: Pull complete
b5af386662eb: Pull complete
Digest: sha256:29b54a03602e286ada491b72a034b81b8528a6cad6b1168713c893c1de24f3db
Status: Downloaded newer image for jhillyerd/inbucket:release-1.2.0
Pulling start_dependencies (mattermost/mattermost-wait-for-dep:latest)...
latest: Pulling from mattermost/mattermost-wait-for-dep
3489d1c4660e: Pull complete
f27e77dfffb8: Pull complete
Digest: sha256:007c49efabfe385b2fff143cf915a115a770eb8339118dab1ddbb17e6a20a9c5
Status: Downloaded newer image for mattermost/mattermost-wait-for-dep:latest
Creating mattermost-mysql    ... done
Creating mattermost-postgres ... done
Creating mattermost-minio    ... done
Creating mattermost-inbucket ... done
Creating mattermost-server_start_dependencies_run ... done
Waiting for mysql to listen on 3306...
sleeping
sleeping
sleeping
sleeping
sleeping
sleeping
Waiting for postgres to listen on 5432...
Waiting for inbucket to listen on 10080...
Waiting for minio to listen on 9000...
Running mattermost for development
mkdir -p ../mattermost-webapp/dist/files
go run  -ldflags '-X "github.com/mattermost/mattermost-server/v5/model.BuildNumber=dev" -X "github.com/mattermost/mattermost-server/v5/model.BuildDate=Sat Apr 17 07:20:20 UTC 2021" -X "github.com/mattermost/mattermost-server/v5/model.BuildHash=3a13987ee17bde55eb6256f8fca962dbf77fd47b" -X "github.com/mattermost/mattermost-server/v5/model.BuildHashEnterprise=none" -X "github.com/mattermost/mattermost-server/v5/model.BuildEnterpriseReady=false"' "./cmd/mattermost/main.go" --disableconfigwatch 2>&1 | \
    go run  -ldflags '-X "github.com/mattermost/mattermost-server/v5/model.BuildNumber=dev" -X "github.com/mattermost/mattermost-server/v5/model.BuildDate=Sat Apr 17 07:20:20 UTC 2021" -X "github.com/mattermost/mattermost-server/v5/model.BuildHash=3a13987ee17bde55eb6256f8fca962dbf77fd47b" -X "github.com/mattermost/mattermost-server/v5/model.BuildHashEnterprise=none" -X "github.com/mattermost/mattermost-server/v5/model.BuildEnterpriseReady=false"' "./cmd/mattermost/main.go" logs --logrus &
root@vultr:~/mattermost-server#

Everyting is OK so far, When I ping the server, I got the following error;

root@vultr:~/mattermost-server# curl http://localhost:8065/api/v4/system/ping
curl: (7) Failed to connect to localhost port 8065: Connection refused

Port 8065 is not listening;

root@vultr:~/mattermost-server# netstat -na |grep *. |grep 8065
root@vultr:~/mattermost-server#
root@vultr:~/mattermost-server# netstat -na | grep 8065
root@vultr:~/mattermost-server#

I think the mattermost-server process is running;

root@vultr:~/mattermost-server# ps ax | grep mattermost

17532 pts/0    Sl     0:07 go run -ldflags -X "github.com/mattermost/mattermost-server/v5/model.BuildNumber=dev" -X "github.com/mattermost/mattermost-server/v5/model.BuildDate=Sat Apr 17 07:20:20 UTC 2021" -X "github.com/mattermost/mattermost-server/v5/model.BuildHash=3a13987ee17bde55eb6256f8fca962dbf77fd47b" -X "github.com/mattermost/mattermost-server/v5/model.BuildHashEnterprise=none" -X "github.com/mattermost/mattermost-server/v5/model.BuildEnterpriseReady=false" ./cmd/mattermost/main.go --disableconfigwatch
17533 pts/0    Sl     0:07 go run -ldflags -X "github.com/mattermost/mattermost-server/v5/model.BuildNumber=dev" -X "github.com/mattermost/mattermost-server/v5/model.BuildDate=Sat Apr 17 07:20:20 UTC 2021" -X "github.com/mattermost/mattermost-server/v5/model.BuildHash=3a13987ee17bde55eb6256f8fca962dbf77fd47b" -X "github.com/mattermost/mattermost-server/v5/model.BuildHashEnterprise=none" -X "github.com/mattermost/mattermost-server/v5/model.BuildEnterpriseReady=false" ./cmd/mattermost/main.go logs --logrus
17865 pts/0    Sl     0:07 go run cmd/mattermost/main.go
26449 pts/0    Sl     0:10 /usr/local/go/pkg/tool/linux_amd64/compile -o /tmp/go-build76632970/b745/_pkg_.a -trimpath /tmp/go-build76632970/b745=> -p github.com/mattermost/mattermost-server/v5/store/sqlstore -lang=go1.15 -complete -buildid iilGoMNvUMSIBO_JV02_/iilGoMNvUMSIBO_JV02_ -goversion go1.16.3 -D  -importcfg /tmp/go-build76632970/b745/importcfg -pack /root/mattermost-server/store/sqlstore/audit_store.go /root/mattermost-server/store/sqlstore/bot_store.go /root/mattermost-server/store/sqlstore/channel_member_history_store.go /root/mattermost-server/store/sqlstore/channel_store.go /root/mattermost-server/store/sqlstore/channel_store_categories.go /root/mattermost-server/store/sqlstore/cluster_discovery_store.go /root/mattermost-server/store/sqlstore/command_store.go /root/mattermost-server/store/sqlstore/command_webhook_store.go /root/mattermost-server/store/sqlstore/compliance_store.go /root/mattermost-server/store/sqlstore/context.go /root/mattermost-server/store/sqlstore/emoji_store.go /root/mattermost-server/store/sqlstore/file_info_store.go /root/mattermost-server/store/sqlstore/group_store.go /root/mattermost-server/store/sqlstore/integrity.go /root/mattermost-server/store/sqlstore/job_store.go /root/mattermost-server/store/sqlstore/license_store.go /root/mattermost-server/store/sqlstore/link_metadata_store.go /root/mattermost-server/store/sqlstore/oauth_store.go /root/mattermost-server/store/sqlstore/plugin_store.go /root/mattermost-server/store/sqlstore/post_store.go /root/mattermost-server/store/sqlstore/preference_store.go /root/mattermost-server/store/sqlstore/product_notices_store.go /root/mattermost-server/store/sqlstore/reaction_store.go /root/mattermost-server/store/sqlstore/remote_cluster_store.go /root/mattermost-server/store/sqlstore/retention_policy_store.go /root/mattermost-server/store/sqlstore/role_store.go /root/mattermost-server/store/sqlstore/scheme_store.go /root/mattermost-server/store/sqlstore/session_store.go /root/mattermost-server/store/sqlstore/shared_channel_store.go /root/mattermost-server/store/sqlstore/status_store.go /root/mattermost-server/store/sqlstore/store.go /root/mattermost-server/store/sqlstore/system_store.go /root/mattermost-server/store/sqlstore/team_store.go /root/mattermost-server/store/sqlstore/terms_of_service_store.go /root/mattermost-server/store/sqlstore/thread_store.go /root/mattermost-server/store/sqlstore/tokens_store.go /root/mattermost-server/store/sqlstore/upgrade.go /root/mattermost-server/store/sqlstore/upload_session_store.go /root/mattermost-server/store/sqlstore/user_access_token_store.go /root/mattermost-server/store/sqlstore/user_store.go /root/mattermost-server/store/sqlstore/user_terms_of_service.go /root/mattermost-server/store/sqlstore/utils.go /root/mattermost-server/store/sqlstore/webhook_store.go
26453 pts/0    Rl     0:09 /usr/local/go/pkg/tool/linux_amd64/compile -o /tmp/go-build2170058020/b745/_pkg_.a -trimpath /tmp/go-build2170058020/b745=> -p github.com/mattermost/mattermost-server/v5/store/sqlstore -lang=go1.15 -complete -buildid iilGoMNvUMSIBO_JV02_/iilGoMNvUMSIBO_JV02_ -goversion go1.16.3 -D  -importcfg /tmp/go-build2170058020/b745/importcfg -pack /root/mattermost-server/store/sqlstore/audit_store.go /root/mattermost-server/store/sqlstore/bot_store.go /root/mattermost-server/store/sqlstore/channel_member_history_store.go /root/mattermost-server/store/sqlstore/channel_store.go /root/mattermost-server/store/sqlstore/channel_store_categories.go /root/mattermost-server/store/sqlstore/cluster_discovery_store.go /root/mattermost-server/store/sqlstore/command_store.go /root/mattermost-server/store/sqlstore/command_webhook_store.go /root/mattermost-server/store/sqlstore/compliance_store.go /root/mattermost-server/store/sqlstore/context.go /root/mattermost-server/store/sqlstore/emoji_store.go /root/mattermost-server/store/sqlstore/file_info_store.go /root/mattermost-server/store/sqlstore/group_store.go /root/mattermost-server/store/sqlstore/integrity.go /root/mattermost-server/store/sqlstore/job_store.go /root/mattermost-server/store/sqlstore/license_store.go /root/mattermost-server/store/sqlstore/link_metadata_store.go /root/mattermost-server/store/sqlstore/oauth_store.go /root/mattermost-server/store/sqlstore/plugin_store.go /root/mattermost-server/store/sqlstore/post_store.go /root/mattermost-server/store/sqlstore/preference_store.go /root/mattermost-server/store/sqlstore/product_notices_store.go /root/mattermost-server/store/sqlstore/reaction_store.go /root/mattermost-server/store/sqlstore/remote_cluster_store.go /root/mattermost-server/store/sqlstore/retention_policy_store.go /root/mattermost-server/store/sqlstore/role_store.go /root/mattermost-server/store/sqlstore/scheme_store.go /root/mattermost-server/store/sqlstore/session_store.go /root/mattermost-server/store/sqlstore/shared_channel_store.go /root/mattermost-server/store/sqlstore/status_store.go /root/mattermost-server/store/sqlstore/store.go /root/mattermost-server/store/sqlstore/system_store.go /root/mattermost-server/store/sqlstore/team_store.go /root/mattermost-server/store/sqlstore/terms_of_service_store.go /root/mattermost-server/store/sqlstore/thread_store.go /root/mattermost-server/store/sqlstore/tokens_store.go /root/mattermost-server/store/sqlstore/upgrade.go /root/mattermost-server/store/sqlstore/upload_session_store.go /root/mattermost-server/store/sqlstore/user_access_token_store.go /root/mattermost-server/store/sqlstore/user_store.go /root/mattermost-server/store/sqlstore/user_terms_of_service.go /root/mattermost-server/store/sqlstore/utils.go /root/mattermost-server/store/sqlstore/webhook_store.go
26454 pts/0    Sl     0:09 /usr/local/go/pkg/tool/linux_amd64/compile -o /tmp/go-build3535300351/b745/_pkg_.a -trimpath /tmp/go-build3535300351/b745=> -p github.com/mattermost/mattermost-server/v5/store/sqlstore -lang=go1.15 -complete -buildid iilGoMNvUMSIBO_JV02_/iilGoMNvUMSIBO_JV02_ -goversion go1.16.3 -D  -importcfg /tmp/go-build3535300351/b745/importcfg -pack /root/mattermost-server/store/sqlstore/audit_store.go /root/mattermost-server/store/sqlstore/bot_store.go /root/mattermost-server/store/sqlstore/channel_member_history_store.go /root/mattermost-server/store/sqlstore/channel_store.go /root/mattermost-server/store/sqlstore/channel_store_categories.go /root/mattermost-server/store/sqlstore/cluster_discovery_store.go /root/mattermost-server/store/sqlstore/command_store.go /root/mattermost-server/store/sqlstore/command_webhook_store.go /root/mattermost-server/store/sqlstore/compliance_store.go /root/mattermost-server/store/sqlstore/context.go /root/mattermost-server/store/sqlstore/emoji_store.go /root/mattermost-server/store/sqlstore/file_info_store.go /root/mattermost-server/store/sqlstore/group_store.go /root/mattermost-server/store/sqlstore/integrity.go /root/mattermost-server/store/sqlstore/job_store.go /root/mattermost-server/store/sqlstore/license_store.go /root/mattermost-server/store/sqlstore/link_metadata_store.go /root/mattermost-server/store/sqlstore/oauth_store.go /root/mattermost-server/store/sqlstore/plugin_store.go /root/mattermost-server/store/sqlstore/post_store.go /root/mattermost-server/store/sqlstore/preference_store.go /root/mattermost-server/store/sqlstore/product_notices_store.go /root/mattermost-server/store/sqlstore/reaction_store.go /root/mattermost-server/store/sqlstore/remote_cluster_store.go /root/mattermost-server/store/sqlstore/retention_policy_store.go /root/mattermost-server/store/sqlstore/role_store.go /root/mattermost-server/store/sqlstore/scheme_store.go /root/mattermost-server/store/sqlstore/session_store.go /root/mattermost-server/store/sqlstore/shared_channel_store.go /root/mattermost-server/store/sqlstore/status_store.go /root/mattermost-server/store/sqlstore/store.go /root/mattermost-server/store/sqlstore/system_store.go /root/mattermost-server/store/sqlstore/team_store.go /root/mattermost-server/store/sqlstore/terms_of_service_store.go /root/mattermost-server/store/sqlstore/thread_store.go /root/mattermost-server/store/sqlstore/tokens_store.go /root/mattermost-server/store/sqlstore/upgrade.go /root/mattermost-server/store/sqlstore/upload_session_store.go /root/mattermost-server/store/sqlstore/user_access_token_store.go /root/mattermost-server/store/sqlstore/user_store.go /root/mattermost-server/store/sqlstore/user_terms_of_service.go /root/mattermost-server/store/sqlstore/utils.go /root/mattermost-server/store/sqlstore/webhook_store.go
26631 pts/0    S+     0:00 grep --color=auto mattermost
root@vultr:~/mattermost-server#

Possible fixes

-

darkLord19 commented 3 years ago

@hakansa It seems compilation is stuck or something so server is not started hence you can't ping. export GOFLAGS=-x and then run make run-server and we can try to figure out why compilation is stuck.

amyblais commented 3 years ago

@streamer45 @agnivade Can you help take a look?

hakansa commented 3 years ago

I guess I figured out that what happened; When I run make run-server again, the go run ./cmd/mattermost/main.go process started but port 8065 is not listening. This time, I decided to wait. A few minutes later, mattermost-server process started to listening port 8065. I think, there should be some signs so people understand they should wait.

I have some suggestions;

  1. Instead of using go run ./cmd/mattermost/main.go we can compile code first with go build ./cmd/mattermost/main.go -o ./bin/mattermost-server and run the compiled binary if compilation success. I think that is important, because when I run make run-server I couldn't understand why I'm waiting for. Binary to be compiled, or the server to be initialized?

  2. There is no log message is printed until HTTP server started. If some log messages is printed during early initializations, people could figure out they should wait to finish initializations

streamer45 commented 3 years ago

@hakansa Thanks for the thorough feedback, it's highly appreciated. I agree that the user shouldn't be left guessing for (possibly) several minutes. I've created a ticket (MM-35029) to keep track of this.

hakansa commented 3 years ago

@streamer45 thanks for the reply. Is it OK to change this issue's title to [MM-35029]Improve logging during make run-server ? I'm currently working on another issue, when I finish to work on int maybe I can deal with this issue.

streamer45 commented 3 years ago

Sure, that would be great :+1: