Sphereserver / Source

http://spherecommunity.net
Apache License 2.0
108 stars 58 forks source link

Very high CPU utilization under FreeBSD #263

Closed ldilley closed 3 years ago

ldilley commented 3 years ago

I've successfully built spheresvr 0.56d (latest master commit e01bb6f) under FreeBSD 12.2 using Clang 10.0.1. However, after executing spheresvr, there is a significant degradation of response time within the spheresvr console for input/output, scripts are parsed slower than they should be, and client connections are delayed.

After some investigation, CPU utilization is significantly elevated per the output below. The CPU utilization remains high for the runtime of the program.

  PID USER      PRI  NI  VIRT   RES S CPU% MEM%   TIME+  Command
20699 1002      100   0  116M 70592 R 96.0 1.7   0:50.75 ./spheresvr

Upon further inspection, it appears that the program is stuck in a loop calling clock_gettime() at a very high frequency per the output below. I've tracked this particular call to line 10 of src/common/CTime.cpp (clock_gettime(CLOCK_MONOTONIC, &ts);). If the aforementioned line is commented, spheresvr is rebuilt, and the program is executed again, the CPU utilization returns to much more acceptable levels. I am hoping for a fix while maintaining the call to clock_gettime() if it is essential.

<11:18:01> (~)
[root@game] {97}# truss -p 20699 -f
20699: clock_gettime(4,{ 792332.469464224 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.469776734 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.470129864 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.470285904 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.470427614 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.470621444 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.470781924 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.470958024 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.471337324 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.471483434 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.471626414 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.471831694 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.471979174 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.472134144 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.472469104 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.472606794 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.472755594 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.473023774 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.473227454 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.473624324 })     = 0 (0x0)
20699: clock_gettime(4,{ 792332.473780094 })     = 0 (0x0)
...
coruja747 commented 3 years ago

Sphere is a server based on ticks, this is the "main timer" to control all timer-based actions, like skill delay, actions, timers, etc, so it is expected that it should call clock_gettime() at each tick, which is something really fast

But this is a lightweight function and should not affect server performance, so indeed there's something wrong. Probably the error is not on clock_gettime(), but on something near it

Just to make sure, try compile the build using GCC instead CLang to check if it works fine, maybe this is a compiler-related issue

ldilley commented 3 years ago

Thank you for the response, @coruja747.

I understand regarding the ticks. After some more experimentation, FreeBSD's implementation of clock_gettime() with CLOCK_MONOTONIC seems to be responsible for causing the performance issues. I recompiled spheresvr with gcc 9.3.0 under FreeBSD and the same symptoms occurred. I am not able to replicate the symptoms under Linux (Debian 10.9).

As I mentioned previously, if I comment the call to clock_gettime(), then performance is great (this is how I determined the root cause). If I also modify the clock ID to be CLOCK_MONOTONIC_FAST (which is a FreeBSD extension), then performance becomes acceptable. An excerpt from golang/go#22942:

CLOCK_MONOTONIC_FAST will use getnanouptime, while CLOCK_MONOTONIC will use nanouptime
https://github.com/freebsd/freebsd/blob/release/11.1.0/sys/kern/kern_time.c#L345.

    Functions with the "get" prefix returns a less precise result
    much faster than the functions without "get" prefix and should
    be used where a precision of 1/hz seconds is acceptable or where
    performance is priority. (NB: "precision", not "resolution" !)

If this minor loss of precision is acceptable to you at the gain of running normally under FreeBSD while still using a monotonic clock, I can submit a PR to remedy the issue.

coruja747 commented 3 years ago

That's nice, thanks for the PR! Honestly I don't have FreeBSD here so I can't test it, but if it works for you I'll assume everything is ok

But by default sphere is compiled with Visual Studio on Windows and GCC on unix/linux, so to keep the code portable, we must compile it using GCC instead CLang to make sure all builds will have the same compiled code. Of course you can still using CLang on your local/custom build, but on main branch (nightly builds) it's recommended use GCC instead CLang

Anyway, try update your files to latest commit https://github.com/Sphereserver/Source/commit/0d2c1bef214706556d188e144e3ac4b8aac8c5fe, I did some changes to improve FreeBSD support and also merged PR changes, if something still missing feel free to update it

ldilley commented 3 years ago

Fix merged in e01bb6f.