Users become logged in to another user

Troubleshooting
1

[Note: ticket is likely related to this one: [Urgent] User messages shown to wrong user - where the incorrectly-logged-in-user now sends messages incorrectly too]

Summary

User will become logged into another user’s account somehow, either over time or immediately after logging in.

Steps to reproduce

Mattermost Version: 5.3.1
Database Schema Version: 5.3.0
Database: postgres

  1. User logs in.
  2. User leaves session running
  3. User returns, sees they are now logged in as another user.

OR

  1. User logs in
  2. User immediately sees that they are logged in as another user.

Expected behavior

User should log in as the user they expect.

Observed behavior

User becomes logged in as another user. They are able to send messages as that user instead of themselves.

2

Hi @Camille,

  1. What sign-in / auth method is being used on your server?
  2. Does the user who sees this issue have multiple accounts on Mattermost (with different email addresses)?
  3. What device and browser does this happen on?
3
  1. Whatever is the default setting. Is there somewhere I can see this?
  2. No, different users using different email addresses. One account per person.
  3. Windows 10 PCs, using Chrome.
4

Hi @Camille,

For 1, you can go to System Console > Authentication to see which ones are enabled on your server.

Some other questions:

  1. Is this happening to one or multiple users?
  2. What is your session setting set to for https://docs.mattermost.com/administration/config-settings.html#sessions?
  3. Do you see any error messages in the logs when this issue happens?
5

Hi,

I have seen this issue here too. Its a test system, and there are only a handful of users registered. The Websocket-Port was not available when it happend (proxy).

Sessions (LDAP/Mobile/SSO): 30 days
Session Cache: 30 Min

Auth: email Registration, email login and username login all set to true, gitlab off

Only one user was affected.

Feel free to ask for further infos

Andreas

releavant timestamp around 1544002699.9016292

Log:

{"level":"info","ts":1543611462.540184,"caller":"app/app.go:204","msg":"Server is initializing..."}
{"level":"info","ts":1543611462.5437896,"caller":"sqlstore/supplier.go:209","msg":"Pinging SQL master database"}
{"level":"error","ts":1543611462.5451984,"caller":"sqlstore/supplier.go:221","msg":"Failed to ping DB retrying in 10 seconds err=dial tcp 172.21.0.2:5432: connect: connection refused"}
{"level":"info","ts":1543611472.5453799,"caller":"sqlstore/supplier.go:209","msg":"Pinging SQL master database"}
{"level":"info","ts":1543611472.5532699,"caller":"sqlstore/channel_store_experimental.go:47","msg":"Enabling experimental public channels materialization"}
{"level":"info","ts":1543611472.786928,"caller":"sqlstore/upgrade.go:101","msg":"The database schema has been set to version 5.5.0"}
{"level":"error","ts":1543611473.1770208,"caller":"commands/server.go:79","msg":"SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: http://about.mattermost.com/default-site-url"}
{"level":"info","ts":1543611473.17714,"caller":"commands/server.go:82","msg":"Current version is 5.5.0 (5.5.0/Thu Nov 15 18:39:02 UTC 2018/826252252404c13bf564a8c4fd51616fc2cc4df9/8eb31159c091f8a1e75c99ae6f4e47010dbf3731)"}
{"level":"info","ts":1543611473.177166,"caller":"commands/server.go:83","msg":"Enterprise Enabled: true"}
{"level":"info","ts":1543611473.177184,"caller":"commands/server.go:84","msg":"Current working directory is /mattermost"}
{"level":"info","ts":1543611473.1772916,"caller":"commands/server.go:85","msg":"Loaded config file from /mattermost/config/config.json"}
{"level":"info","ts":1543611473.1776323,"caller":"filesstore/localstore.go:33","msg":"Able to write files to local storage."}
{"level":"info","ts":1543611473.1797395,"caller":"app/license.go:44","msg":"License key from https://mattermost.com required to unlock enterprise features."}
{"level":"info","ts":1543611473.1805081,"caller":"app/app.go:545","msg":"Migrating roles to database."}
{"level":"info","ts":1543611473.2255137,"caller":"sqlstore/post_store.go:1297","msg":"Post.Message supports at most 16383 characters (65535 bytes)"}
{"level":"info","ts":1543611473.2531612,"caller":"app/app.go:621","msg":"Migrating emojis config to database."}
{"level":"info","ts":1543611473.2611668,"caller":"app/plugin.go:100","msg":"Starting up plugins"}
{"level":"error","ts":1543611473.4490578,"caller":"app/plugin.go:129","msg":"Failed to unpack prepackaged plugin","error":"installPlugin: Unable to move plugin from temporary directory to final destination. Another plugin may be using the same directory name., mkdir /mattermost/plugins/jira: permission denied","path":"/mattermost/prepackaged_plugins/mattermost-jira-plugin-linux-amd64.tar.gz"}
{"level":"error","ts":1543611473.63367,"caller":"app/plugin.go:129","msg":"Failed to unpack prepackaged plugin","error":"installPlugin: Unable to move plugin from temporary directory to final destination. Another plugin may be using the same directory name., mkdir /mattermost/plugins/zoom: permission denied","path":"/mattermost/prepackaged_plugins/mattermost-zoom-plugin-linux-amd64.tar.gz"}
{"level":"info","ts":1543611473.6340206,"caller":"app/server.go:88","msg":"Starting Server..."}
{"level":"info","ts":1543611473.6340418,"caller":"app/server.go:114","msg":"RateLimiter is enabled"}
{"level":"info","ts":1543611473.6342072,"caller":"app/server.go:148","msg":"Server is listening on [::]:8000"}
{"level":"info","ts":1543611473.641773,"caller":"app/web_hub.go:75","msg":"Starting 28 websocket hubs"}
{"level":"info","ts":1543611473.6884718,"caller":"jobs/workers.go:63","msg":"Starting workers"}
{"level":"info","ts":1543611473.688623,"caller":"jobs/schedulers.go:68","msg":"Starting schedulers."}
{"level":"info","ts":1543611484.3701124,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.5964255,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.7460868,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.778702,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.7790365,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.79785,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.798956,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.7989955,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611484.7992055,"caller":"web/handlers.go:95","msg":"Invalid session","error":"GetSession: Invalid session token=ihgq3xycitdduffxmhdne5dyho, err=<no value>, "}
{"level":"info","ts":1543611545.472673,"caller":"migrations/worker.go:109","msg":"Worker: Job is complete","worker":"Migrations","job_id":"qb1w17j1wtgsfe3pwkrf1rgiue"}
{"level":"error","ts":1543613441.3099,"caller":"web/context.go:60","msg":"Login failed because email address has not been verified","path":"/api/v4/users/login","request_id":"ro84q7bamifixctj5j8wkeu61y","ip_addr":"93.239.168.1","user_id":"","method":"POST","err_where":"Login","http_code":401,"err_details":"user_id=sqz7cgmj9tncjr86pb1eu7c6ga"}
{"level":"error","ts":1543649706.8724155,"caller":"web/context.go:60","msg":"Login failed because email address has not been verified","path":"/api/v4/users/login","request_id":"ubshk5ssz78o5b9ghyfo1dmw1w","ip_addr":"93.239.168.1","user_id":"","method":"POST","err_where":"Login","http_code":401,"err_details":"user_id=sqz7cgmj9tncjr86pb1eu7c6ga"}
{"level":"error","ts":1543655067.61145,"caller":"web/context.go:60","msg":"Connection unsuccessful: SendMail: Error setting \"To Address\", 454 4.7.1 <andreas.schrell@set.de>: Relay access denied","path":"/api/v4/email/test","request_id":"tz1tpkoh5iy3tgfg8od6wncduo","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":500,"err_details":""}
{"level":"error","ts":1543655093.7459931,"caller":"web/context.go:60","msg":"The SMTP server, port, or username has changed. Please re-enter the SMTP password to test connection.","path":"/api/v4/email/test","request_id":"a35qgmgxdpdutpn8icqzezmz9a","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":400,"err_details":""}
{"level":"error","ts":1543655118.3421202,"caller":"web/context.go:60","msg":"Connection unsuccessful: SendMail: Error setting \"To Address\", 454 4.7.1 <andreas.schrell@set.de>: Relay access denied","path":"/api/v4/email/test","request_id":"jicku4e5cig1xgozrnpdybwjya","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":500,"err_details":""}
{"level":"error","ts":1543655184.0301938,"caller":"web/context.go:60","msg":"The SMTP server, port, or username has changed. Please re-enter the SMTP password to test connection.","path":"/api/v4/email/test","request_id":"bucfotackiredjxag6e38yknba","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":400,"err_details":""}
{"level":"info","ts":1543655245.0208557,"caller":"app/admin.go:141","msg":"Purging all caches"}
{"level":"error","ts":1543655245.021867,"caller":"app/app.go:724","msg":"Elasticsearch.start: Elasticsearch is already stopped, "}
{"level":"info","ts":1543655245.023267,"caller":"app/license.go:44","msg":"License key from https://mattermost.com required to unlock enterprise features."}
{"level":"error","ts":1543655295.884512,"caller":"mailservice/mail.go:134","msg":"Failed to open a connection to SMTP server EOF"}
{"level":"error","ts":1543655295.8850725,"caller":"web/context.go:60","msg":"Connection unsuccessful: SendMail: Failed to open TLS connection, EOF","path":"/api/v4/email/test","request_id":"xprtfpyuuf8nxbwsnwfhx883ho","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":500,"err_details":""}
{"level":"error","ts":1543657055.1799138,"caller":"web/context.go:60","msg":"Connection unsuccessful: SendMail: Failed to open TLS connection, tls: first record does not look like a TLS handshake","path":"/api/v4/email/test","request_id":"wtqow73pqire9ytdnkpaso89uc","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":500,"err_details":""}
{"level":"error","ts":1543657066.4635332,"caller":"web/context.go:60","msg":"The SMTP server, port, or username has changed. Please re-enter the SMTP password to test connection.","path":"/api/v4/email/test","request_id":"mzqp365agfrg8nnstbj1i76fie","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":400,"err_details":""}
{"level":"error","ts":1543657079.9372268,"caller":"web/context.go:60","msg":"The SMTP server, port, or username has changed. Please re-enter the SMTP password to test connection.","path":"/api/v4/email/test","request_id":"c4kcfks9ip81pfg1n5jp11fypa","ip_addr":"93.239.168.1","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"POST","err_where":"testEmail","http_code":400,"err_details":""}
{"level":"warn","ts":1543658922.1430693,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=5wdyayzgofg9txydtrdde4sf7huser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"error","ts":1543668097.884317,"caller":"app/plugin_requests.go:33","msg":"Access to route for non-existent plugin","missing_plugin_id":"weathermap","error":"plugin not found: weathermap"}
{"level":"error","ts":1543690284.6304362,"caller":"web/context.go:60","msg":"Unable to parse incoming data","path":"/hooks/wbkd7nscopruiq6qcxdu6hw9eo","request_id":"x74mo74ztjdadqk5a5q9ng81dc","ip_addr":"193.31.27.184","user_id":"","method":"POST","err_where":"IncomingWebhookRequestFromJson","http_code":400,"err_details":"invalid character '\\\\' looking for beginning of object key string"}
{"level":"error","ts":1543690399.0600736,"caller":"web/context.go:60","msg":"Unable to parse incoming data","path":"/hooks/wbkd7nscopruiq6qcxdu6hw9eo","request_id":"g6wa3xwjn7g3fk19ias4173nqh","ip_addr":"193.31.27.184","user_id":"","method":"POST","err_where":"IncomingWebhookRequestFromJson","http_code":400,"err_details":"invalid character '\\\\' looking for beginning of object key string"}
{"level":"error","ts":1543690497.752325,"caller":"web/context.go:60","msg":"Unable to parse incoming data","path":"/hooks/wbkd7nscopruiq6qcxdu6hw9eo","request_id":"itx8o5h91idfdyyxpyxipp64gr","ip_addr":"193.31.27.184","user_id":"","method":"POST","err_where":"IncomingWebhookRequestFromJson","http_code":400,"err_details":"invalid character ':' in string escape code"}
{"level":"error","ts":1543690509.656307,"caller":"web/context.go:60","msg":"Unable to parse incoming data","path":"/hooks/wbkd7nscopruiq6qcxdu6hw9eo","request_id":"k9ktkgcc9jdyie9aacsxo7o1ya","ip_addr":"193.31.27.184","user_id":"","method":"POST","err_where":"IncomingWebhookRequestFromJson","http_code":400,"err_details":"invalid character '\\\\' looking for beginning of object key string"}
{"level":"error","ts":1543690619.5234547,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543691931.3684554,"caller":"web/context.go:60","msg":"Unable to parse incoming data","path":"/hooks/wbkd7nscopruiq6qcxdu6hw9eo","request_id":"4g8b3w9ytp8qimu3ghttekmnhe","ip_addr":"193.31.27.184","user_id":"","method":"POST","err_where":"IncomingWebhookRequestFromJson","http_code":400,"err_details":"EOF"}
{"level":"error","ts":1543694951.8647408,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543695409.7174847,"caller":"app/plugin.go:86","msg":"failed to notify plugin status changed","error":"GetPluginStatuses: Plugins have been disabled. Please check your logs for details., "}
{"level":"info","ts":1543695409.7175927,"caller":"app/plugin.go:156","msg":"Shutting down plugins"}
{"level":"info","ts":1543695418.3192344,"caller":"app/plugin.go:100","msg":"Starting up plugins"}
{"level":"error","ts":1543695418.514827,"caller":"app/plugin.go:129","msg":"Failed to unpack prepackaged plugin","error":"installPlugin: Unable to move plugin from temporary directory to final destination. Another plugin may be using the same directory name., mkdir /mattermost/plugins/jira: permission denied","path":"/mattermost/prepackaged_plugins/mattermost-jira-plugin-linux-amd64.tar.gz"}
{"level":"error","ts":1543695418.7114947,"caller":"app/plugin.go:129","msg":"Failed to unpack prepackaged plugin","error":"installPlugin: Unable to move plugin from temporary directory to final destination. Another plugin may be using the same directory name., mkdir /mattermost/plugins/zoom: permission denied","path":"/mattermost/prepackaged_plugins/mattermost-zoom-plugin-linux-amd64.tar.gz"}
{"level":"error","ts":1543696956.2283878,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543697199.5166519,"caller":"web/context.go:60","msg":"Unable to parse incoming data","path":"/hooks/wbkd7nscopruiq6qcxdu6hw9eo","request_id":"x5dnkpuz738d5jxuiyn7761azc","ip_addr":"193.31.27.184","user_id":"","method":"POST","err_where":"IncomingWebhookRequestFromJson","http_code":400,"err_details":"EOF"}
{"level":"error","ts":1543697510.7627432,"caller":"web/context.go:60","msg":"Unable to parse incoming data","path":"/hooks/wbkd7nscopruiq6qcxdu6hw9eo","request_id":"yz6rr9wogirxmjqarxho8xzrpa","ip_addr":"193.31.27.184","user_id":"","method":"POST","err_where":"IncomingWebhookRequestFromJson","http_code":400,"err_details":"EOF"}
{"level":"error","ts":1543701844.8538427,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543706525.192326,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543748882.149343,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543825004.928532,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543842121.0643983,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543842225.4815443,"caller":"web/context.go:60","msg":"Unable to find an existing account matching your credentials. This team may require an invite from the team owner to join.","path":"/api/v4/users/login","request_id":"gfn7rejftibi5mmhf981o6kmea","ip_addr":"unknown","user_id":"","method":"POST","err_where":"GetUserForLogin","http_code":400,"err_details":""}
{"level":"error","ts":1543843864.6281734,"caller":"app/notification_push.go:276","msg":"Device push reported as error for UserId=sqz7cgmj9tncjr86pb1eu7c6ga SessionId=tpdj8zeofpgwtqtg41kfk7htae message=Post http://push-test.mattermost.com/api/v1/send_push: dial tcp: i/o timeout","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga"}
{"level":"error","ts":1543845898.1459417,"caller":"app/post.go:806","msg":"GetOpenGraphMetadata request failed for url=http://www.set.de with err=Get https://www.set.de/: x509: certificate signed by unknown authority"}
{"level":"error","ts":1543907065.5255935,"caller":"app/plugin_requests.go:33","msg":"Access to route for non-existent plugin","missing_plugin_id":"weathermap","error":"plugin not found: weathermap"}
{"level":"error","ts":1543917084.0131054,"caller":"app/plugin_requests.go:33","msg":"Access to route for non-existent plugin","missing_plugin_id":"weathermap","error":"plugin not found: weathermap"}
{"level":"error","ts":1543949229.2549407,"caller":"app/plugin_requests.go:33","msg":"Access to route for non-existent plugin","missing_plugin_id":"weathermap","error":"plugin not found: weathermap"}
{"level":"error","ts":1543969128.9502053,"caller":"app/plugin_requests.go:33","msg":"Access to route for non-existent plugin","missing_plugin_id":"weathermap","error":"plugin not found: weathermap"}
{"level":"warn","ts":1544002699.9016292,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544002729.2570977,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544002735.6797197,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544002735.7217083,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544002735.7465432,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544009725.975564,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544009739.1028051,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"error","ts":1544009740.1382554,"caller":"web/context.go:60","msg":"Invalid or missing channel_id parameter in request URL","path":"/api/v4/channels/undefined/posts","request_id":"wuidztdsa7ng5fumnmgc43gfiy","ip_addr":"unknown","user_id":"sqz7cgmj9tncjr86pb1eu7c6ga","method":"GET","err_where":"Context","http_code":400,"err_details":""}
{"level":"warn","ts":1544009740.4790547,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544012048.80506,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544012194.5471137,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544012200.1784813,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544012202.16077,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
{"level":"warn","ts":1544012286.7585442,"caller":"app/channel.go:1578","msg":"Failed to get membership SqlChannelStore.GetMember: No channel member found for that user ID and channel ID, channel_id=neq5a3ok97n5uexwt6yogdr76auser_id=sqz7cgmj9tncjr86pb1eu7c6ga,sql: no rows in result set"}
6
  • and even after stopping and restarting the windows client it opens with the wrong account
  • after “clear cache and reload” the client shows the correct user again
  • both these users are admins
7

Hi @Schrell,

Does the affected user have one or multiple accounts on the same server?
If multiple accounts, did they have multiple active sessions when this issue occurred?
When the user logged in and ended up logging in on a wrong account, did he do the log in on the same browser and device, or a different browser / device than previously?

8

Only one Account. The user change did not happen on login. It happend after popping up the window or reopening after a while. I assume the session timed out. All happened on the same device on Windows 10 with the Windows client. It may also be that network connections changed.

9

Hello, @Schrell.

I’d be interested to also know if the machine where the affected user reproduces the issue was previously used by other accounts prior to this issue, which could potentially explain the cache of the other user loaded instead of the right one.

Since you mentioned that the problem was showing the right user again after clearing cache and reload, does that mean that the problem constantly happens even after that was done and you have to perform cache clearance and reload every time?

Also, does the account of the other user shows another session when the wrong account logs in? You can check this under Security >> View and Logout of Active Sessions. For example:
42

10

The machine was only used by the affected user. We did not share passwords, so it could not have happened by accident.

The problem only happened once and is not reproduceable.

My idea to this is that the session ended and the search for the connected user ended by scanning the db with no result. But the last (first?) tested user was left in cache (or as last tested db result) on the server. And so taken as the result of the search.

This result reached the client and resulted in displaying the same user.

Restarting the client cached this wrong user and displayed him again at next start.

Cleaning the cache results in a new log in, now with the correct user.

Andreas

1 Like
11

Hi, Andreas.

Thank you for sharing your thoughts on this. While it is a unique scenario which only happened once, I would relay this thought to the dev / engineering team to see if it is something that they would be interested to investigate further.

@amy.blais do you have any other thoughts on this matter?

12

Hi @Camille, have you experienced this issue recently?

13

Hi @Camille, @Schrell,

Can you help with more details on your setup? What are you running Mattermost on, e.g. HA/no, proxy config, etc.?

Our team suspects that this could be an issue where you have some severely messed up proxy/caching settings.

14

no, normal linux server, no proxy, no HA. and it was a fresh ubuntu standard setup for our chat testing.

15

Thanks for confirming, @Schrell. Given the testing setup, are you able to recall your user setup process? I assume the system admin was created on first start, and then were all the test accounts created manually thereafter? Or using the CLI or API? How long after setup was the problem observed?

1 Like
16

Also, @Schrell, can you confirm the Mattermost versions at play? The logs above don’t correlate with 5.3.1, but seem to be from 5.5:

{"level":"info","ts":1543611473.17714,"caller":"commands/server.go:82","msg":"Current version is 5.5.0 (5.5.0/Thu Nov 15 18:39:02 UTC 2018/826252252404c13bf564a8c4fd51616fc2cc4df9/8eb31159c091f8a1e75c99ae6f4e47010dbf3731)"}

Are there multiple servers at play, and are you perhaps testing an upgrade?

17

Yes we tested 5.5. The original post from @Camille was 5.3. That was no server of us. I just had the same problem on our setup as @Camille had, so i posted in this thread.

So the problem has happened in at least two mattermost instances with different versions.

I did setup a new root server, fresh installed ubuntu 18.04 and then installed mattermost. First user admin, the other three test users created their accounts with email registration. The setup was running only for a few days while testing several chat solutions. There are and were no other mattermost servers. For the test rocketchat was installed on another and both users had also accounts there. And we used HipChat. But I do not see any relations here.

Andreas

18

Hi guys,

we are experiencing the same problem!

our system:
OS Server: SLES 11 SP4
OS Client: Windows 10 Enterprise 64 bit
Server: 5.7.1 (initially 5.1-> 5.4 -> 5.7.1)
Client: mostly mattermost desktop app 4.2.0/4.2.1, no browser

Sessions (LDAP/Mobile/SSO): 30 days
Session Cache: 10 Min

our mattermnost runs behind nginx. Configuration as described here:
https://docs.mattermost.com/install/config-proxy-nginx.html

Summary (exactly the same behaviour as descibed by Camille and Schrell):
User will become logged into another user’s account somehow, either over time or immediately after logging in.

all users were set up the same way.

after client start the user is automatically logged in as another user (sporadically!) so you can read the whole communication(posts/channels etc.) of the affected colleague.
sometimes it is enough to click on File -> Settings… -> server name and then you are magically logged in as another user

it is difficult to reproduce the issue because very offen it is working as expected.

the affected users have only one account. Our working stations are new and without “history” so there is only one user profile

currently there is only one workaround: “clear cache and reload” and then it just works.

There is nothing suspicious in the log and i have no guess what is going on and the project leads are getting nervous. :slight_smile:

Any Ideas for further investigations?

Thanks in advance

Roman