Heartbeat/Panic issues when using the mattermost sample bot and mattermost docker preview image

Troubleshooting
1

Summary

I appear to be receiving heartbeat error issues and panics when attempting to run the Mattermost sample bot with the Mattermost preview image

Steps to reproduce

  • Clone the test bot repo and run the bot via go run bot_sample.go. Go version 1.15.7
  • Docker-compose for mattermost preview:
version: "3.9"
services:
  test_mm:
    image: mattermost/mattermost-preview:5.26.0
    container_name: test_mm
    ports: 
    - "8065:8065"

User accounts added as specified in the test-bot README, or via this script:

docker exec test_mm mattermost team create --name botsample --display_name "Sample Bot playground" --email "admin@example.com"
docker exec test_mm mattermost user create --email="bot@example.com" --password="Password1!" --username="samplebot"
docker exec test_mm mattermost user create --email="bill@example.com" --password="Password1!" --username="bill"
docker exec test_mm mattermost roles system_admin bill
docker exec test_mm mattermost team add botsample samplebot bill
docker exec test_mm mattermost user verify samplebot

Note command difference in mmcl vs mattermost. Container seemed to work better with mattermost & passwords were updated to match more rigorous requirements (I.E. a capital letter and a special character)

Change to bot_sample.go to use updated password:

	USER_PASSWORD = "Password1!"

Expected behavior

I believe this hearbeat system shouldn’t fail, as both systems are online and functioning, as well as the system shouldn’t panic

Observed behavior

Output from bot on panic:

Mattermost Bot Sample
Server detected and is running version 5.26.0
panic: concurrent write to websocket connection

goroutine 34 [running]:
github.com/gorilla/websocket.(*messageWriter).flushFrame(0xc0001f4840, 0xc0001f4801, 0x0, 0x0, 0x0, 0x0, 0xc0001f4840)
        /home/user/go/pkg/mod/github.com/gorilla/websocket@v1.4.1/conn.go:610 +0x60e
github.com/gorilla/websocket.(*messageWriter).Close(0xc0001f4840, 0xa62c68, 0x0)
        /home/user/go/pkg/mod/github.com/gorilla/websocket@v1.4.1/conn.go:724 +0x65
github.com/gorilla/websocket.(*Conn).WriteMessage(0xc00028cf20, 0x9, 0xa62c68, 0x0, 0x0, 0xe74c4ad2b, 0xa31c80)
        /home/user/go/pkg/mod/github.com/gorilla/websocket@v1.4.1/conn.go:773 +0x109
main.main.func1(0xc000028780, 0xc000088b40)
        /home/user/Documents/other/work/mm_ex/mattermost-bot-sample-golang/bot_sample.go:87 +0x172
created by main.main
        /home/user/Documents/other/work/mm_ex/mattermost-bot-sample-golang/bot_sample.go:80 +0x4e5
exit status 2

Output from Container on panic:

{"level":"error","ts":1612375014.2964413,"caller":"mlog/log.go:190","msg":"RPC call MessageHasBeenPosted to plugin failed.","plugin_id":"com.mattermost.nps","error":"connection is shut down"}
{"level":"debug","ts":1612375014.299739,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/posts","request_id":"9utftexeeff1me3wjf6opa9cya","status_code":"201"}
{"level":"debug","ts":1612375029.3476431,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/users/status/ids","request_id":"1b67ayfsxfnu3fdic8mxg4qa8y","status_code":"200"}
{"level":"debug","ts":1612375074.3025775,"caller":"app/web_conn.go:419","msg":"websocket.read: closing websocket","user_id":"tsfgnprs97femfsb8e91jeyg3h","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"level":"debug","ts":1612375074.3026774,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"GET","url":"/api/v4/websocket","request_id":"cxxa7ha353r6pryc4cd8np8wre"}
{"level":"debug","ts":1612375089.369826,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/users/status/ids","request_id":"kg4stikdxfbrdnapi7ie8ntmqw","status_code":"200"}
{"level":"debug","ts":1612375150.2005756,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/users/status/ids","request_id":"xhjqkiar9bbtpgbbn7oep6utfa","status_code":"200"}

Output on bot for timeout:

Mattermost Bot Sample
Server detected and is running version 5.26.0
responding to debugging channel msg
responding to debugging channel msg
responding to debugging channel msg
responding to debugging channel msg
send heartbeat error:  (0x827440,0xc00000fe60)

Output on container for timeout:
I was unable to retrieve but will update if collected

2

This seems like an incorrect usage of the library. The client should never directly interact with the Conn object. But only use the methods exposed by the type.

Unfortunately, due to compatibility reasons, we cannot unexport the Conn, and therefore cases like these remain.

In this case, we can just remove the heartbeat logic since that is already done by the client behind the scenes.

1 Like
3

Hey agnivade

Thanks for getting back to me! I appreciate the feedback/assistance in understanding the root cause of this issue; I had never worked with that webSocketClient before so its good to understand.

Since this issue exits directly in the sample code, should I add this as an issue to the repo or open a pull request there to resolve this?

Thanks again for your assistance and have a terrific day!

4

An issue would be great, and a pull request would be even better!

5

Awesome! PR opened. Thanks again for your assistance with this