Reducing log levels... lots of unauthorised connections

[Paul Wayper]

Hi all!

I run a TURN server for a game; I get lots of messages like this:

Jun 06 11:37:23 faf turnserver[2174422]: 2023-06-06T11:37:23+1000(2174424): ERROR: check_stun_auth: Cannot find credentials of user <1686099952:459082>
Jun 06 11:37:23 faf turnserver[2174422]: 2023-06-06T11:37:23+1000(2174424): INFO: session 001000000000012996: realm <geosearchef.de> user <1686099952:459082>: incoming packet message processed, error 401: Unauthorized
Jun 06 11:37:25 faf turnserver[2174422]: 2023-06-06T11:37:23+1000(2174424): INFO: session 001000000000012920: usage: realm=<geosearchef.de>, username=<1686103743:484823>, rp=12, rb=944, sp=12, sb=1248
Jun 06 11:37:25 faf turnserver[2174422]: 2023-06-06T11:37:23+1000(2174424): INFO: session 001000000000012920: peer usage: realm=<geosearchef.de>, username=<1686103743:484823>, rp=0, rb=0, sp=0, sb=0
Jun 06 11:37:25 faf turnserver[2174422]: 2023-06-06T11:37:23+1000(2174424): INFO: session 001000000000012920: closed (2nd stage), user <1686103743:484823> realm <geosearchef.de> origin <>, local 103.4.235.100:3478, remote 50.26.123.116:6699, reason: allocation watchdog determined stale session state
Jun 06 11:37:25 faf turnserver[2174422]: 2023-06-06T11:37:23+1000(2174424): ERROR: check_stun_auth: Cannot find credentials of user <1686099952:459082>
Jun 06 11:37:25 faf turnserver[2174422]: 2023-06-06T11:37:23+1000(2174424): INFO: session 001000000000012996: realm <geosearchef.de> user <1686099952:459082>: incoming packet message processed, error 401: Unauthorized
Jun 06 11:37:25 faf turnserver[2174422]: 2023-06-06T11:37:24+1000(2174423): INFO: session 000000000000013011: realm <geosearchef.de> user <>: incoming packet message processed, error 401: Unauthorized

I'd love to double check that I've got my configuration for this server right - it's what the game admins said to use but I suspect I haven't got it right somehow.  Maybe the fact that it's a public server just means that every script kiddie out there is trying to use the TURN server for their own ends?

But my secondary way of dealing with this was to make a patch where a 'minimum log level' can be set.  At the moment in the turnserver code almost everything goes through the TURN_LOG_FUNC - the '-verbose' flag doesn't seem to restrict this much.  So by e.g. setting --log-min-level to WARN I'd get saved a lot of these messages.

Do you want such a patch?

Just trying to avoid the X-Y problem,

Paul

[Warren McDonald]

Hi Paul,

From the logs I can see that the server is receiving credentials generated with shared secret scheme. This has a <timestamp:userid> username format you see. Some of these have been successful as there are active relayed packets being logged with the rp=, sp= numbers. Initial handshakes with no username, shown with just <>,  will always return a 401 Unauthorised. 

Some of the credentials are being rejected, which might mean there is a time sync issue somewhere. The way the shared secret works is that either a server or a client script will generate the timestamp part of the username and then generate a password field (which of course you don't see in the logs) which is derived from the username and the secret using an agreed hash function. In the case where the TURN server's time and the servers/clients' time are out of sync by more than the life of the timestamp, authentication will fail. 

Other common problems include the shared secret being rotated and not being updated on all clients/servers.

BTW the -verbose flag will increase the verbosity not restrict it. If you omit it, it there will not be much logged, but then we would not have seen this scenario properly. 

Cheers,

Warren

[Paul Wayper]

Hi Warren, thanks for that.

OK, so I think that's a reasonable case for this pull request:

https://github.com/coturn/coturn/pull/1222

This introduces the '--log-min-level <level>' command line option and the 'log_min_level=<level>' configuration option.  The level value is based on the TURN_LOG_LEVEL_* constants, starting with 0 = DEBUG and going up to 4 = ERROR, defaulting to 0.  Setting log_min_level to 5 and above would switch all logs off.  This is independent of the --verbose and --Verbose settings.

IOW I'll be happy to ignore all the stale sessions and working sessions if it cuts my logs to less than a gigabyte per day... :-)

Happy to take feedback on that pull request, either here or in its comments :-)

The shared secret is in relation to the use-auth-secret and static-auth-secret options, right?  If a client uses the wrong shared secret, that'd show up as an authentication failure I assume.

Thanks once again,

Paul

[Paul Wayper]

I suppose the other question I have really is: how do the rest of you deal with all this noise in your logs?

Is it because you're running private TURN servers that aren't published somewhere?

Is it because you're using other authentication methods that don't log if there's no correct handshake, and our using static-auth-secret is just a bad way of handling this?

Is it because we've configured something incorrectly and we could improve that?

Advice welcome! :-)

Thanks,

Paul

On Wednesday, 7 June 2023 at 13:28:26 UTC+10 Warren McDonald wrote: