# Ways to debug server code (Nakama Defold tictactoe XOXO example)
**URL:** https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492
**Category:** Local Setup
**Created:** [February 5, 2023, 3:36pm UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492 "2023-02-05T15:36:14Z")
**Posts on this page:** 9
**Page:** 1
### Author:  [@kragil](https://forum.heroiclabs.com/u/kragil)
#### Post date: [February 5, 2023, 3:36pm UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/1 "2023-02-05T15:36:14Z")
I set up my own local server with the Linux binary and a free cockroach db.
I tried to get [Creating online games using Nakama and Defold](https://defold.com/2021/03/02/Creating-online-games-using-Nakama-and-Defold/)
working with my server. So I changed server address in the client and when I start the client two times I can connect, I can find a match, but then I only get stuck with “Loading game”
I don’t know how to find the source of the problem. How would one go about debugging this?
---
### Author:  [@kragil](https://forum.heroiclabs.com/u/kragil)
#### Post date: [February 6, 2023, 7:47pm UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/2 "2023-02-06T19:47:01Z")
These are the logs:
{“severity”:“ERROR”,“time”:“2023-02-06T19:36:33.051740437+01:00”,“caller”:“server/console\_authenticate.go:139”,“message”:“Failed to parse the session token.”,“error”:“Token is expired”}
{“severity”:“ERROR”,“time”:“2023-02-06T19:36:33.052141531+01:00”,“caller”:“server/console\_authenticate.go:143”,“message”:“Invalid token.”,“error”:“Token is expired”}
{“severity”:“INFO”,“time”:“2023-02-06T19:36:55.991717841+01:00”,“caller”:“server/session\_ws.go:80”,“message”:“New WebSocket session connected”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“format”:0}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:36:57.639573777+01:00”,“caller”:“server/pipeline.go:65”,“message”:“Received _rtapi.Envelope\_MatchmakerAdd message",“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“cid”:“1”,“message”:{“MatchmakerAdd”:{“min\_count”:2,“max\_count”:2,“query”:"_”}}}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:36:57.641548068+01:00”,“caller”:“server/session\_ws.go:395”,“message”:“Sending \*rtapi.Envelope\_MatchmakerTicket message”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“envelope”:“cid:"1" matchmaker\_ticket:{ticket:"156c77a5-7222-4bc8-b868-acd63b5d4e3e"}”}
{“severity”:“INFO”,“time”:“2023-02-06T19:37:07.4521532+01:00”,“caller”:“server/session\_ws.go:80”,“message”:“New WebSocket session connected”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”,“format”:0}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:44.374702346+01:00”,“caller”:“server/pipeline.go:65”,“message”:“Received _rtapi.Envelope\_MatchmakerAdd message",“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”,“cid”:“1”,“message”:{“MatchmakerAdd”:{“min\_count”:2,“max\_count”:2,“query”:"_”}}}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:44.380206601+01:00”,“caller”:“server/session\_ws.go:395”,“message”:“Sending \*rtapi.Envelope\_MatchmakerTicket message”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”,“envelope”:“cid:"1" matchmaker\_ticket:{ticket:"f57be3e2-36ec-4c85-9fc2-2cc8f2e6584a"}”}
{“severity”:“INFO”,“time”:“2023-02-06T19:37:53.893276235+01:00”,“caller”:“server/runtime\_lua\_nakama.go:2176”,“message”:“Creating TicTacToe match”,“runtime”:“lua”,“mode”:“matchmaker”}
{“severity”:“INFO”,“time”:“2023-02-06T19:37:53.893460015+01:00”,“caller”:“server/runtime\_lua\_nakama.go:2176”,“message”:“Matched user ‘441de9a5-ae74-485e-bdde-71c6f77c357c’ named ‘BYwmAfKYgl’”,“runtime”:“lua”,“mode”:“matchmaker”}
{“severity”:“INFO”,“time”:“2023-02-06T19:37:53.893524789+01:00”,“caller”:“server/runtime\_lua\_nakama.go:2176”,“message”:“Matched user ‘0e4e409c-e3f0-4ce3-8fd5-7f16667f025c’ named ‘uITviUMWHL’”,“runtime”:“lua”,“mode”:“matchmaker”}
{“severity”:“ERROR”,“time”:“2023-02-06T19:37:53.896561084+01:00”,“caller”:“server/matchmaker.go:644”,“message”:“Error running Matchmaker Matched hook.”,“error”:“Error running runtime Matchmaker Matched hook: /home/udo/data/modules/main.lua:21: match\_signal not found or not a function\nstack traceback:\n\t[G]: in function ‘match\_create’\n\t/home/udo/data/modules/main.lua:21: in main chunk\n\t[G]: ?”}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:53.941949702+01:00”,“caller”:“server/pipeline.go:65”,“message”:“Received \*rtapi.Envelope\_MatchJoin message”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”,“cid”:“2”,“message”:{“MatchJoin”:{“Id”:{“Token”:“eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE2NzU3MDg3MDMsIm1pZCI6IjdjODc0YzIzLTRmNDYtNDI0Ny1hNjNkLWUzMmMzODZjMDNlNi4ifQ.JKQ-xVOcMT1iyc1EEZgbVCn37NrLUfUDmjq7IsGjp48”}}}}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:53.942481844+01:00”,“caller”:“server/session\_ws.go:395”,“message”:“Sending \*rtapi.Envelope\_Match message”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”,“envelope”:“cid:"2" match:{match\_id:"7c874c23-4f46-4247-a63d-e32c386c03e6." self:{user\_id:"0e4e409c-e3f0-4ce3-8fd5-7f16667f025c" session\_id:"425e47c3-a64d-11ed-b9ef-006100a0eb06" username:"uITviUMWHL"}}”}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:53.942753122+01:00”,“caller”:“server/tracker.go:907”,“message”:“Processing presence event”,“joins”:1,“leaves”:0}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:56.844535765+01:00”,“caller”:“server/pipeline.go:65”,“message”:“Received \*rtapi.Envelope\_MatchJoin message”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“cid”:“2”,“message”:{“MatchJoin”:{“Id”:{“Token”:“eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE2NzU3MDg3MDMsIm1pZCI6IjdjODc0YzIzLTRmNDYtNDI0Ny1hNjNkLWUzMmMzODZjMDNlNi4ifQ.JKQ-xVOcMT1iyc1EEZgbVCn37NrLUfUDmjq7IsGjp48”}}}}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:56.844763151+01:00”,“caller”:“server/session\_ws.go:395”,“message”:“Sending \*rtapi.Envelope\_Match message”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“envelope”:"cid:"2" match:{match\_id:"7c874c23-4f46-4247-a63d-e32c386c03e6." size:1 presences:{user\_id:"0e4e409c-e3f0-4ce3-8fd5-7f16667f025c" session\_id:"425e47c3-a64d-11ed-b9ef-006100a0eb06" username:"uITviUMWHL"} \>
{“severity”:“DEBUG”,“time”:“2023-02-06T19:37:56.844905787+01:00”,“caller”:“server/tracker.go:907”,“message”:“Processing presence event”,“joins”:1,“leaves”:0}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:43:27.338974328+01:00”,“caller”:“server/session\_ws.go:204”,“message”:“Error reading message from client”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”,“error”:“websocket: close 1006 (abnormal closure): unexpected EOF”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:27.339209652+01:00”,“caller”:“server/session\_ws.go:438”,“message”:“Cleaning up closed client connection”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:27.339247515+01:00”,“caller”:“server/session\_ws.go:446”,“message”:“Cleaned up closed connection matchmaker”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:27.339287107+01:00”,“caller”:“server/session\_ws.go:450”,“message”:“Cleaned up closed connection tracker”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:27.339310321+01:00”,“caller”:“server/session\_ws.go:454”,“message”:“Cleaned up closed connection status registry”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:27.339338885+01:00”,“caller”:“server/session\_ws.go:458”,“message”:“Cleaned up closed connection session registry”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:27.339489115+01:00”,“caller”:“server/session\_ws.go:517”,“message”:“Closed client connection”,“uid”:“0e4e409c-e3f0-4ce3-8fd5-7f16667f025c”,“sid”:“425e47c3-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:43:27.339582105+01:00”,“caller”:“server/tracker.go:907”,“message”:“Processing presence event”,“joins”:0,“leaves”:1}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:43:31.02919071+01:00”,“caller”:“server/pipeline.go:65”,“message”:“Received \*rtapi.Envelope\_MatchLeave message”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“cid”:“3”,“message”:{“MatchLeave”:{“match\_id”:“7c874c23-4f46-4247-a63d-e32c386c03e6.”}}}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:43:31.029369839+01:00”,“caller”:“server/session\_ws.go:395”,“message”:“Sending message”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“envelope”:“cid:"3"”}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:43:31.0295111+01:00”,“caller”:“server/tracker.go:907”,“message”:“Processing presence event”,“joins”:0,“leaves”:1}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:34.303176901+01:00”,“caller”:“server/session\_ws.go:438”,“message”:“Cleaning up closed client connection”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:34.303285256+01:00”,“caller”:“server/session\_ws.go:446”,“message”:“Cleaned up closed connection matchmaker”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:34.303314902+01:00”,“caller”:“server/session\_ws.go:450”,“message”:“Cleaned up closed connection tracker”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:34.303334937+01:00”,“caller”:“server/session\_ws.go:454”,“message”:“Cleaned up closed connection status registry”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:34.303357526+01:00”,“caller”:“server/session\_ws.go:458”,“message”:“Cleaned up closed connection session registry”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”}
{“severity”:“DEBUG”,“time”:“2023-02-06T19:43:34.303380983+01:00”,“caller”:“server/session\_ws.go:510”,“message”:“Could not send close message”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”,“error”:“websocket: close sent”}
{“severity”:“INFO”,“time”:“2023-02-06T19:43:34.30346078+01:00”,“caller”:“server/session\_ws.go:517”,“message”:“Closed client connection”,“uid”:“441de9a5-ae74-485e-bdde-71c6f77c357c”,“sid”:“3b898cfa-a64d-11ed-b9ef-006100a0eb06”}
---
### Author:  [@kragil](https://forum.heroiclabs.com/u/kragil)
#### Post date: [February 7, 2023, 7:42am UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/3 "2023-02-07T07:42:40Z")
I’m new to all of this: The match says in the Nakama console that it is not authoritative. Could it be that the lua code on the server isn’t called at all? I also don’t see any log messages.
---
### Author:  [@ftkg](https://forum.heroiclabs.com/u/ftkg)
#### Post date: [February 7, 2023, 4:02pm UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/4 "2023-02-07T16:02:14Z")
Hi @kragil, it’s a bit difficult to tell you where exactly the issue is. There is an error on the matchmaker matched hook, are you appropriately registering the hook function? To help you debug this further, add some lines of logging to both client and server main hooks (join/matchmaker/match handlers and loop) and see where it hangs.
---
### Author:  [@kragil](https://forum.heroiclabs.com/u/kragil)
#### Post date: [February 10, 2023, 7:04am UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/5 "2023-02-10T07:04:57Z")
How would I register them appropriately?
They show up under:
Lua Modules
/home/u/data/modules/main.lua 2023-02-01T11:43:37Z
/home/u/data/modules/tictactoe\_match.lua 2023-02-01T11:49:18Z
/home/u/data/modules/tictactoe\_state.lua 2023-02-01T11:49:49Z
Do I have to do anything else?
---
### Author:  [@dela](https://forum.heroiclabs.com/u/dela)
#### Post date: [February 10, 2023, 9:00am UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/6 "2023-02-10T09:00:18Z")
See these register\_… functions: [Nakama: Function Reference | Heroic Labs Documentation](https://heroiclabs.com/docs/nakama/server-framework/lua-runtime/function-reference/#Hooks)
---
### Author:  [@kragil](https://forum.heroiclabs.com/u/kragil)
#### Post date: [February 10, 2023, 9:42am UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/7 "2023-02-10T09:42:34Z")
I don’t get it. Are the three files from the example not complete? Do I need to add something?
---
### Author:  [@flavio](https://forum.heroiclabs.com/u/flavio)
#### Post date: [February 10, 2023, 12:51pm UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/8 "2023-02-10T12:51:17Z")
Hi @kragil,
That guide is outdated, as you can see [here](https://github.com/heroiclabs/nakama/commit/5d74bb0b0e14ee668e0ebc398988a68ebdc7a6a8) the `match_signal` mentioned in the error you get was added after that guide was written.
For you to advance, adding the `match_signal` function after the others match functions should be enough. An example of a snippet can be found [here](https://heroiclabs.com/docs/nakama/server-framework/lua-runtime/function-reference/match-handler/#match_signal) in our documentation.
Something along these lines:
```auto
function M.match_signal(context, dispatcher, tick, state, data)
return state, "signal received: " .. data
end
```
To clarify the other replies, the `matchmaker_matched` is registered [here](https://github.com/defold/game-xoxo-nakama-server/blob/main/main.lua#L45) but I believe you have done that already because the `match_signal` error happens within the function `match_create` which is called in the function register at line 45.
For the sake of curiosity, more details about the hook concept can be found [here](https://heroiclabs.com/docs/nakama/server-framework/introduction/#hooks).
---
### Author:  [@kragil](https://forum.heroiclabs.com/u/kragil)
#### Post date: [February 11, 2023, 12:55pm UTC](https://forum.heroiclabs.com/t/ways-to-debug-server-code-nakama-defold-tictactoe-xoxo-example/3492/9 "2023-02-11T12:55:36Z")
> [@flavio](#):
>
> ```auto
> function M.match_signal(context, dispatcher, tick, state, data)
> return state, "signal received: " .. data
> end
>
> ```
I added that to tictactoe\_match.lua and now it works! Thanks Flavio!
It still has all the bugs mentioned here, though: [Creating online games using Nakama and Defold - #24 by Tom\_Arnold - Announcements - Defold game engine forum](https://forum.defold.com/t/creating-online-games-using-nakama-and-defold/67687/24)
But I made a PR anyways. Thanks again.