Mattermost-server: Can't Upload Avatar/Photo [500 Internal Error]

[emresaracoglu]

Hi,
I use on Docker and when I want to add a photo in the channel/direct message, I get 500 errors.
I tired on Windows desktop, iOS, Android and web interace.

https://mmcay y.domain.com/api/v4/files


[2018/04/13 19:29:37 UTC] [EROR] /api/v4/channels/undefined/posts:Context code=400 rid=j5y1oum817n1mnfmop7xxxf9hh uid=a6k91nqkzpr1bm2c98qmxo944h ip=PUBLIC-IP Invalid or missing channel_id parameter in request URL [details: ]

What could be the reason for this?
Thanks

[lindy65]

Hi @emresaracoglu

Thanks for your feedback,

Which Mattermost server version are you using?

[emresaracoglu]

Mattermost Version: 4.9.0-rc4
Database Schema Version: 4.9.0
Database: mysql

[lindy65]

Thanks for your feedback @emresaracoglu,

Let's see if @pichouk can help with this Docker issue?

[pichouk]

Hi @emresaracoglu :) What is the size of your uploaded file ? It may be reach the 50M default limit.

[emresaracoglu]

Hi,

Each photo average 2-3 MB

---

_Log:_

[2018/04/16 11:48:12 UTC] [EROR] /api/v4/logs:client code=0 rid=ebtyyetogbdq8eo4tgo8xywofy uid=a6k91nqkzpr1bm9c98qmxo944h ip=PUBLICIP msg: TypeError: n is not a function row: 1 col: 545632 stack: TypeError: n is not a function url: https://mm.domain.com/static/0.9341a65a7ef9540b671d.js [details: ]

[pichouk]

Hum this is weird. This log was the same as in this issue where it happens that the size of the uploaded file was too big. Are you sure that you have no configured limitation to uploaded file size on your mattermost app and your reverse proxy ?

[emresaracoglu]

If the problem is size, it may give an error message. Maybe my proxy files may not be working correctly.

I give you HAproxy and Proxy files.

Proxy file:
```
location ~ /api/v[0-9]+/(users/)?websocket$ {
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection "upgrade";
client_max_body_size 250M;
proxy_set_header Host $http_host;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header X-Forwarded-Proto $scheme;
proxy_set_header X-Frame-Options SAMEORIGIN;
proxy_buffers 256 64k;
proxy_buffer_size 64k;
proxy_read_timeout 600s;
proxy_pass http://mmchat;
}

location / {
client_max_body_size 250M;
proxy_set_header Connection "";
proxy_set_header Host $http_host;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header X-Forwarded-Proto $scheme;
proxy_set_header X-Frame-Options SAMEORIGIN;
proxy_buffers 256 64k;
proxy_buffer_size 64k;
proxy_read_timeout 600s;
proxy_cache mattermost_cache;
proxy_cache_revalidate on;
proxy_cache_min_uses 2;
proxy_cache_use_stale timeout;
proxy_cache_lock on;
proxy_pass http://mmchat;
}

HAproxy Conf. File:

global
log 127.0.0.1 local0
log 127.0.0.1 local1 notice
#log loghost local0 info
maxconn 50000
chroot /var/lib/haproxy
user haproxy
group haproxy
daemon
#debug
#quiet
stats socket /var/lib/haproxy/stats

defaults
mode http
log global
option httplog
option dontlognull
option http-server-close
option forwardfor except 127.0.0.0/8
option redispatch
retries 6

    timeout http-request    250s
    timeout queue           5m
    timeout connect         250s
    timeout client          10m
    timeout server          100m
    timeout http-keep-alive 250s
    timeout check           250s 
    maxconn                 500000

frontend MAIN
bind *:80
bind *:443
bind *:8065
mode http

acl MMCHAT_URL hdr(host) -i         mm.domain.com

use_backend MMCHAT  if MMCHAT_URL

backend MMCHAT
mode http
server web-mmchat 192.168.1.197:80

```

[pichouk]

Hmm I don't think it is a Docker related issue. I see other issues (https://github.com/mattermost/mattermost-server/issues/8329 and https://github.com/mattermost/mattermost-server/issues/8515) with the same error message but it was related to empty file uploading, seems not to be the same thing here.

@lindy65 Is there a Mattermost developer that may know this error message better than me ? ^^

[lindy65]

Thanks for your help @pichouk - I'll ask one of our engineers to take a look at the error messages and see if they can help troubleshoot.

[lieut-data]

Prior to 4.10, there was a client-side bug in how server-side errors were handled -- see https://github.com/mattermost/mattermost-webapp/pull/1076 for the resolution that will be part of the next release.

However, the root cause to the issue remains a server-side error. @emresaracoglu, you mentioned an error 500, but I don't see that in any of the logs above. Can you grep your server logs for all error messages matching POST - /api/v4/files? This should hopefully give more context into the problem you're seeing.

[emresaracoglu]

Hi, @lieut-data I made a GIF for you, I dont know how do I access the log file in docker?

If you think that this problem is due to the Docker. I can manual install (?)

Console:

Network:

Data Path:

[lieut-data]

@emresaracoglu, thanks for sharing those -- very helpful! With nginx responding (vs. Mattermost proper), I'm inclined to think the platform binary is terminating unexpectedly.

We have had other reports of image uploads crashing the server (regardless of the image size), but no definitive root cause besides running out of memory in uploading and transforming the image. What are the memory constraints on your particular deployment?

If we could get at the Mattermost logs and/or system logs containing same, we might be able to pinpoint why things are failing. @pichouk, do you have expertise in extracting logs from a Dockerized Mattermost?

[pichouk]

@lieut-data By default you can collect Docker log using the command docker logs CONTAINERNAME but you will have nothing more than what's redirect to STDOUT/STDERR (which is by default the same content as you can see on the Mattermost System Console (on /admin_console/logs page).

[lieut-data]

@emresaracoglu, can you try streaming those logs while you do the file upload?

[pichouk]

To stream logs in real time you can use docker logs -f CONTAINERNAME ;)

[emresaracoglu]

These are the last records:

[2018/04/18 21:27:03 UTC] [INFO] Using config file at config/config_docker.json
[2018/04/18 21:27:03 UTC] [INFO] Loaded system translations for 'en' from '/mm/mattermost/i18n/en.json'
[2018/04/18 21:27:03 UTC] [INFO] Server is initializing...
[2018/04/18 21:27:03 UTC] [DEBG] Parsing server templates at /mm/mattermost/templates
[2018/04/18 21:27:03 UTC] [INFO] Pinging SQL master database
[2018/04/18 21:27:04 UTC] [DEBG] Deleting any unused pre-release features
[2018/04/18 21:27:04 UTC] [DEBG] Initializing built-in plugin: ldapextras
[2018/04/18 21:27:08 UTC] [INFO] Current version is 4.9.0 (4.9.0-rc4/Thu Apr 12 15:23:36 UTC 2018/bc49b1242714210bc4cb602f62a37eb710d19cea/none)
[2018/04/18 21:27:08 UTC] [INFO] Enterprise Enabled: false
[2018/04/18 21:27:08 UTC] [INFO] Current working directory is /mm/mattermost
[2018/04/18 21:27:08 UTC] [INFO] Loaded config file from /mm/mattermost/config/config_docker.json
[2018/04/18 21:27:08 UTC] [INFO] Able to write files to local storage.
[2018/04/18 21:27:08 UTC] [INFO] Starting up plugins
[2018/04/18 21:27:08 UTC] [WARN] unable to create user namespace: fork/exec /proc/self/exe: operation not permitted
[2018/04/18 21:27:08 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/
[2018/04/18 21:27:10 UTC] [INFO] Activated jira plugin
[2018/04/18 21:27:10 UTC] [INFO] Starting Server...
[2018/04/18 21:27:10 UTC] [INFO] Server is listening on [::]:8065
[2018/04/18 21:27:10 UTC] [DEBG] EXPERIMENTAL: Initializing plugin api
[2018/04/18 21:27:10 UTC] [DEBG] Email batching job starting. Checking for pending emails every 30 seconds.
[2018/04/18 21:27:10 UTC] [INFO] API version 3 is scheduled for deprecation. Please see https://api.mattermost.com for details.
[2018/04/18 21:27:10 UTC] [INFO] Starting 2 websocket hubs
[2018/04/18 21:27:10 UTC] [DEBG] Initializing web routes
[2018/04/18 21:27:10 UTC] [DEBG] Using client directory at /mm/mattermost/client
[2018/04/18 21:27:10 UTC] [DEBG] Hub for index 0 is starting with goroutine 2410
[2018/04/18 21:27:10 UTC] [DEBG] Hub for index 1 is starting with goroutine 2411
[2018/04/18 21:27:10 UTC] [INFO] Post.Message supports at most 16383 characters (65535 bytes)
[2018/04/18 21:27:10 UTC] [INFO] Using config file at config/config_docker.json
[2018/04/18 21:27:10 UTC] [DEBG] Email batching job starting. Checking for pending emails every 30 seconds.
[2018/04/18 21:27:10 UTC] [INFO] Starting workers
[2018/04/18 21:27:10 UTC] [DEBG] Initialising schedulers.
[2018/04/18 21:27:10 UTC] [DEBG] Cleaning up session store.
[2018/04/18 21:27:10 UTC] [DEBG] Cleaning up token store.
[2018/04/18 21:27:10 UTC] [DEBG] Cleaning up command webhook store.
[2018/04/18 21:27:10 UTC] [DEBG] Watcher Started
[2018/04/18 21:27:10 UTC] [INFO] Starting schedulers.
[2018/04/18 21:27:22 UTC] [DEBG] /
[2018/04/18 21:27:23 UTC] [DEBG] GET - /api/v4/config/client
[2018/04/18 21:27:23 UTC] [DEBG] GET - /api/v4/users/me/teams
[2018/04/18 21:27:23 UTC] [DEBG] GET - /api/v4/users/me
[2018/04/18 21:27:23 UTC] [DEBG] GET - /api/v4/users/me/preferences
[2018/04/18 21:27:23 UTC] [DEBG] GET - /api/v4/license/client
[2018/04/18 21:27:23 UTC] [DEBG] GET - /api/v4/users/me/teams/unread
[2018/04/18 21:27:23 UTC] [DEBG] GET - /api/v4/users/me/teams/members
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/plugins/webapp
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/teams/name/proddev/channels/name/town-square
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/users/me/teams/afzu8sz1yfd93bozuy3udr71oo/channels
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/users/me/teams/afzu8sz1yfd93bozuy3udr71oo/channels/members
[2018/04/18 21:27:24 UTC] [DEBG] POST - /api/v4/users/status/ids
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/websocket
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/channels/dzookcuh5fyu9ynpfdpjwa6nwa/members/me
[2018/04/18 21:27:24 UTC] [DEBG] POST - /api/v4/users/ids
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/teams
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/users/a6k91nqkzpr1bm9c98qmxo944h/status
[2018/04/18 21:27:24 UTC] [DEBG] GET - /api/v4/channels/dzookcuh5fyu9ynpfdpjwa6nwa/posts
[2018/04/18 21:27:24 UTC] [DEBG] POST - /api/v4/roles/names
[2018/04/18 21:27:25 UTC] [DEBG] GET - /api/v4/channels/dzookcuh5fyu9ynpfdpjwa6nwa/stats
[2018/04/18 21:27:25 UTC] [DEBG] POST - /api/v4/channels/members/me/view
[2018/04/18 21:27:25 UTC] [DEBG] POST - /api/v4/opengraph
[2018/04/18 21:27:25 UTC] [DEBG] GET - /api/v4/users/bjq3f8k8r7f9pka5gw99tmsgcw/image
[2018/04/18 21:27:28 UTC] [DEBG] POST - /api/v4/channels/members/me/view
[2018/04/18 21:27:40 UTC] [DEBG] Email batching job ran. 0 user(s) still have notifications pending.
[2018/04/18 21:27:41 UTC] [DEBG] POST - /api/v4/channels/members/me/view
[2018/04/18 21:27:41 UTC] [DEBG] GET - /api/v4/users/me/teams/afzu8sz1yfd93bozuy3udr71oo/channels/members
[2018/04/18 21:27:44 UTC] [DEBG] POST - /api/v4/logs
[2018/04/18 21:27:44 UTC] [EROR] /api/v4/logs:client code=0 rid=md3hm1964tf7xn8of4jmzq1p9c uid=a6k91nqkzpr1bm9c98qmxo944h ip=<PUBLIC_IP> msg: TypeError: n is not a function row: 1 col: 545632 stack: TypeError: n is not a function url: https://mm.domain.com/static/0.9341a65a7ef9540b671d.js [details: ]

This line occurs when I try to add a photo:

[2018/04/18 21:27:44 UTC] [EROR] /api/v4/logs:client code=0 rid=md3hm1964tf7xn8of4jmzq1p9c uid=a6k91nqkzpr1bm9c98qmxo944h ip=<PUBLIC_IP> msg: TypeError: n is not a function row: 1 col: 545632 stack: TypeError: n is not a function url: https://mm.domain.com/static/0.9341a65a7ef9540b671d.js [details: ]

In the morning, I will try manuel installation. I think I will not have a problem with manual installation.

[emresaracoglu]

Solved for now.
Solution: Install without Docker. It runs smoothly on CentOS7.

[pichouk]

Hmm weird... Did you setup any limitation (RAM or CPU) to your Docker container or Docker daemon ?

[emresaracoglu]

I can upload via local IP but can't install via domain.
This is my fault, I do not know why I get such an error.. probably originated from HAproxy file which does not work well

[emresaracoglu]

@pichouk , @lindy65 and @lieut-data

Thank you for your time, I solved the problem. This time I really solved :)
The problem is caused by HAproxy.

Thank you for your interest.
I apologize for my carelessness.

[lindy65]

Hi @emresaracoglu,

Thanks for letting us know that your issue is resolved :)