Built In Logging Causing Lag

ZEROibis

The problem from lack of file appending really hurts server performance in this game and needs to be either added or the method of current error logging changed. Part of the issue is that the log file is created when the server starts and never expires or is reset.

The result is that after your server runs for a day or two log sizes can easily exceed 50MB the server trying to recreate a >50MB file from scratch every time the file needs to be written b/c there is no file appending hurts performance.

Can these logs please be separated by 24 hour period and or file appending be added to address these issues. I understand that these are things that get overlooked during small testing phases in development but on live servers in the real world this is very damaging to ideal server operation.

endar

Surely this can't be right. If that is how it currently operates, then for a 50MB log file, to be updated 5 times in 1 second, that would be 250MB's of write on the disk.

I sound skeptical, because I know that if this were true, then I would have had much more severe impact from this. Some of my log files have exceeded 400MB. For it to write 400MB in 1.7 million lines, each of these writes would average 200MB (obviously not every write is 200MB, but it starts low, and ends up high averaging 200MB). 200MB * 1.7 million writes is over 600 TB.

How did you determine that this is how the logging takes place?

Or am I misreading something.

edit: procmon shows me that for each x bytes of text written, exactly x+2 is written to the file, at an ever increasing offset.

dePARA

@ZEROibis

I dont want to sound rude, but your server has other problems than a logfile
Why did you increase the playercount after the last patch to 22? Im sure your server cant handle 16 players.



You want better serverperformance? Change the CPU.
Atm your server is nearly unplayble in my opinion.

ZEROibis

Actually the cause of that is the fact that the server uses over 1.5GB of ram b/c of a memory leek which continues until it eats the dedicated box out of memory.

But I am sure the answer to that is just that I do not have 1TB of ram to fix that problem.

This is the shit that pisses me off with hosting servers for this game. Basically the attitude is that unless you run your server with 10 slots or have a 10GHz box with 10 SSD raid 0 and 1TB RAM your not allowed to talk about real problems with the game that need addressing to correct lag issues.

The server trying to write to large log files without file appending will cause lag. This is something that actually occurs in the real world not some idea that it may or may not cause lag.

ATM any server that runs for more than a few hours is going to be unplayable b/c of the memory leeks in latest build but you do not see anyone even really acknowledge those either.

ZEROibis

endar wrote: »

Surely this can't be right. If that is how it currently operates, then for a 50MB log file, to be updated 5 times in 1 second, that would be 250MB's of write on the disk.

I sound skeptical, because I know that if this were true, then I would have had much more severe impact from this. Some of my log files have exceeded 400MB. For it to write 400MB in 1.7 million lines, each of these writes would average 200MB (obviously not every write is 200MB, but it starts low, and ends up high averaging 200MB). 200MB * 1.7 million writes is over 600 TB.

How did you determine that this is how the logging takes place?

Or am I misreading something.

edit: procmon shows me that for each x bytes of text written, exactly x+2 is written to the file, at an ever increasing offset.

I have been told by modders that for example they can not offer more detailed logging b/c ns2 does not have file appending. So I am not sure if it is keeping this in memory and then trying to write it to disk at map change or what but regardless of when it does it's right a server should not be recreating such large files from scratch just becuase the engine has not implemented file appending.

Want to really lag up a NS2 server keep extended logs from dak on and then defrag at the same time. Your server will lag to shit! In CS:S while this is going on there is no lag despite the fact that the cs:s servers are writing way more data to disk b/c not only are they logging as well but also recording source tv demos.

dePARA

Every server? This is not true.
I can run multiple servers on my root for 2 weeks without the need of an restart and they never drop below 30 ticks.

Its the weak cpu of your server, believe me.
249 boost the serverperformance alot. Server that cant hold 25-30 ticks before 249 are now playable.

Can you post the specs of your server here?

ZEROibis

Week cpu does not cause memory leek or was a feature of the latest build to cause the game to go from using top 800MB to 1.5GB of ram!?

ZEROibis

You can see the thread about memory leek here: http://forums.unknownworlds.com/discussion/130645/server-exe-memory-leak-b249#latest

dePARA

Maybe there is an memory leak. But the base problem of your servers are the weak cpu.
Combat is good for weaker servers, cause there no structures, etc.
But you server cant handle combat also:



And your servers had this performance in 248 also.
My tip is to decrease the playerslots to 16 for an acceptable performance.
And if you have memory problems, why are you running a 2nd server since 2 weeks?

ZEROibis

Try to run map voting via DAK in combat mod and see what it does to your server tick. (unless this latest dak version fixed it)

But fuck it your more on a vendetta against large servers anyways and this is a perfect example of why a lot of server operators do not even bother to complain about real problems in the engine b/c rather than have those problems even acknowledged we are just going to become targets.

dePARA

I gave you an idea whats your real problems are. And if you think your only problem is a possible memory leak, then its fine.
If you think an mod dropping your performance, why are you still using it?

"This is a perfect example of why a lot of server operators do not even bother to complain about real problems."

Anyway.
Endar and me are two of the oldest NS2 admins.
We gave you tips, you know it better. Live with it.

ZEROibis

The mod was being updated to fix the problem so I need to turn it on to test it and the error only occurs in a live server environment. This is also why I made my log files directly available to the devs to help them bug fix it.

unter_hosen

@ZEROibis and @dePARA

I would say there is a problem somewhere with this build. I would put my hands up and say that I have probably ONE of the fastest servers out there, and there are points where the performance will suffer randomly. As to whether or not people are seeing it on my servers I don't know, I never get any feedback from players.

@ZEROibis, I have no idea what specs your server are, but I don't think you are alone in having dips in performance. What I will say is, if you are running NS2Stats, this DOES have quite an overhead (I don't know if you are or not).

Further more, I think dePARA is right, I don't think you have quite enough CPU horsepower to be running more than 20 man servers, purely based on looking at the performance graphs. Of course if there are mods running, then take them off and you will probably be able to run the player counts you desire.

For 20 man and NO mods such as stats/DAK, I would say 3.8GHz would be your minimum, which I believe is what Multiplay are using for the UWE officials and those who rent from them, such as YOClan.

16 man with no mods, 3.4GHz
18 man with no mods, around 3.6GHz
24 man with no mods, I would say 4.2GHz would be a safe bet.

I do know how you feel when you run servers at 0 profit, to provide a place for people to play and all you get is complaints or abuse. I regularly get f'ed off with people on the siege server saying "omg this server is lagging, whats going on? server must be crap"

I have on occasion opened the console and typed back saying, "no mate, its the code."

I don't think dePARA is having a go at you at all, just don't take it personally when it comes to servers, its a thankless business.

xDragon

I do not think the log file written by the engine has the issues with appending, they seem to work fine. The issue is with files created/accessed by lua.

The memory leak issues is twofold - there does appear to be a memory leak with 249 that can sometimes cause massive memory usage increases, but there is also a leak with regards to mods. If you run a server with multiple mods that changes maps somewhat frequently, then your memory usage will grow each map change. I suspect its a bug with the engines filesystem where its keeping the mod files loaded and then also remounting them again on mapchange, but I cannot be sure about that.

Ideally with 249 server load should have decreased quite significantly. I don't know if anyone has profiled the impacts of the changes yet, but I suspect with the theoretical improvements that 20 player servers should be possible on 'average' hardware (2.8ghz+ modern cpu) now.

ZEROibis

Once they clean up the memory leeks I think we will have a much better idea what sort of gains 249 has actually been able to offer.

unter_hosen

@xDragon

Purely based on looking at CPU usage graphs, I would say that the CPU usage in pure mode with no mods has come down around 10%, but that is entirely subjective and not based on numbers. I wouldn't think that 2.8GHz would run a 20 player server with a consistently good tick rate, but I would like to be proven wrong as it would mean that I could reduce the overclock, turn down the water cooling pump and lower the fan speeds, ultimately saving on power.

It would also mean that GSPs could provide servers at cheaper rates, which is obviously a massive benefit to the community

Kamamura

Strange. The servers I take care about use syslog for logging, and the administrator can specify where and what type of information will be written. The application just uses standard facility and severity parameters for each message, and the administrator uses syslog.conf to sort the info, or discards the logs altogether if he wishes so.

dePARA

*

MurphyIdiot

The log.txt file is appended to and as a result, will not have to reopen the file for each write.

Mods may be opening and writing to their own log files. We recommend that mods use the existing log file and write to it with the standard API functions (Shared.Message for example) to avoid these problems.

ZEROibis

How do the then avoid the problem of that file deleting itself when the server restarts?

It would be nice to have simple append based logs like what exited for ns1 all hl and sourcemod games and many others that allow servers to log on a map by map basis.

Tom_Bmx

ZEROibis wrote: »

How do the then avoid the problem of that file deleting itself when the server restarts?

It would be nice to have simple append based logs like what exited for ns1 all hl and sourcemod games and many others that allow servers to log on a map by map basis.

You have no idea what your talking about. I'm sorry to be blunt, but posting wild statements like in your OP is just... o.o

The files do not open and re write the data every time it wants to log.

The log files is wrote 2 in a sync style, opening the file handle once and flushing data to it, Since I'm a Software Engineer I have the ability to prove it:


below is a function in Spark_core.dll called ->

M4::Log_Message( const char* fmt, ... );

Which takes the format and va_args and calls vsnprintf which creates the output string.
that string is passed into this function below.



Which calls the following 2 functions:

fputs
fflush

This writes the data into the files stream buffer then makes sure it is flushed to file, appending the data on the end.

They could reduce the flushing of the file to help speed things up, but there is nothing wrong with the implementation of the log system in the spark engine.
The odd speed up here and there but very minimal difference.

ZEROibis

We are already past that here...

I am talking now about the ability of mods to create appended logs without storing everything in the existing log method which is deleted every time the server restarts.

Tom_Bmx

Make a copy of the file before you start the server again ?

Deleting the contents of log on restart of the server would be my approach also.

This means people who don't care for logs don't have huge logs building up.
And people that want the logs can back them up.

Why don't you just make a .bat file to automatically copy the log file when your server is started takes like 30 seconds...

gimmic

or you know.. implement some sort of sane logrotate

ZEROibis

This was more for regular admin mods to improve their implementation. Has anyone here actually run hl1 or source mod servers that understands the variance of log file types I am talking about? I am speaking about what I believe to be very simple features from other games including ns1 but everyone is acting like this is some sort of crazy new idea that only a shit head would want...

Racer1

Log rotation is a good idea. It would make it less likely to overwrite logs you want. However, having a single log file has nothing to do with performance, given the fact that the file is appended (and not reopened) every time it writes to the file (as stated by @MurphyIdiot).

The only point possibly in contention is whether flushing each log line is causing performance issues (mentioned by @Tom_Bmx). However, that (if true) would not depend on the log file size at all.