excessive server file count causes 100% cpu on DU

[hexparrot]

See post at http://discourse.codeemo.com/t/mineos-node-100-cpu-with-large-server/692/4

The du module works very slowly when there are many thousands of files on the file system, most notably when detailed mapping is involved.

Perhaps the directory should be probed for excessive file count or time out and provide a null value, rather than lose all the cpu cycles.

[ciak2009]

Doesn't look like its du on my end, I ran strace it appears to be stat.

I'm trying to take this production, so any help you can give me is much appreciated, a lot of people are really sad our original server "Rexxit" is down, I tweeted you, I'm @TechPackMod

If I can provide anything more please let me know, and I can be reached via Skype, my username is TechnicPackMod or corporate@endermedia.com works too!

stat("/home/minecraft/servers/Rexxit/world/StartingInv/julian55556.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166460, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166462, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/jump_chinaman.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166470, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/jurrasicland.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166478, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/justi2112.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166486, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/justinnn10.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166494, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/juzMatthijs21.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166502, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/jw99097.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166510, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/k0dy100.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166518, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kaasci.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166526, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kadenbrown.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166534, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kaileonte.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166542, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kakla.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166550, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kalim18.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166558, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kamensky73.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166566, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kana_ninja.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166574, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kappie7.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166582, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/karim143.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166590, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/karrow1.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166598, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kasperleed1234.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166606, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kauz2007.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166614, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kaznut.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166622, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kc0hev_1.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166630, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kd7tqn.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166638, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kdogg1981.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166646, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/keelan1745.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166654, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/keish_miner2.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166662, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kellym737.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166670, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kenkenken123.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166678, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kenzo30101.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166686, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kervalin.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166694, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kevinnobel_2002.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166702, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kevvelevve123.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166710, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/khastings.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166718, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kian585.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166726, NULL) = 0
futex(0xee2ae0, FUTEX_WAKE_PRIVATE, 1)  = 0
stat("/home/minecraft/servers/Rexxit/world/StartingInv/kidbotic.si", {st_mode=S_IFREG|0777, st_size=12, ...}) = 0
futex(0xee2aa4, FUTEX_WAIT_PRIVATE, 2166734, NULL) = -1 EAGAIN (Resource temporarily unavailable) 

[hexparrot]

Wouldn't stat be the command that du is using to get file size information?

[ciak2009]

I don't think so, as you are calling fs.stat in several places, and I know that du and stat are different commands when it comes to linux, but I certainly don't have as much NodeJS experience as you. I'd love to know just how to shut off that calculation until a fix can be made :) if you'd like to speak easier feel free to hit me up on Skype, I referenced my account name in the prior issue ;)

EDIT:

I also removed the du module for NodeJS so it doesn't even have the code needed to run du, but the strace still returns all that stat data.

[hexparrot]

du and stat are different, but du depends on stat to return file sizes. Doing stat doesn't cost much time, but doing it tens of thousands of time does add up, and is an I/O bottleneck, so it's still rather possible. Do you have an estimation of how many files exist in that particular server?

[ciak2009]

Thousands, but its all player data, so it can't be reduced. And yeah you are totally right it du does use stat, but I tossed out the stat (correction, I meant du module) module like I said, so unless it can operate du without the du module, its the remaining stat commands.

[ciak2009]

Any ideas good sir?

Thanks again!

[hexparrot]

How did you remove the du module, specifically?

[ciak2009]

node-modules folder created by npm/node install in the /usr/games/minecraft folder.

[hexparrot]

And it isn't failing, crashing the webui, or reporting missing modules in the logs?

[ciak2009]

Not that I can tell, it just returns NaN or something like that, which makes me wonder if its not the du, and is perhaps something else, like one of the direct stat commands ran inside of the main scripts.

[ciak2009]

I can get the exact specifics if thats helpful.

[ciak2009]

I've also got a discord if you would care to hop on, not sure if you use it, but if you do here is the instant invite link.

https://discordapp.com/invite/0XTT1GvkZC2m3aMD

[ciak2009]

Hey sorry to bother you, I was wondering if you had any further thoughts, as I'm currently stuck on MineOS Legacy :(

[hexparrot]

Hrm. If you have removed the du module and this problem persists, then this is a different issue entirely.

Are you able to trace where all the CPU cycles are being used, seeing as how it is no longer where I expect it to be? Please open up a separate Git Issue to address this.

[ciak2009]

I can certainly try, how would you recommend tracing it back to a specific file or process inside of NodeJS, strace was all I could think of, but if you have any other ideas I'm certainly happy to try them.

EDIT: I'll make sure to open a new ticket right after you reply :)

[hexparrot]

https://github.com/hexparrot/mineos-node/blob/master/server.js#L509

Comment out line 509--this whole line with sync_chown. Restart the webui and see if the issue persists.

[hexparrot]

Addressed in ee110b515059e47b858eb9e2f68c67ea24c65ae3, pending pull into master.

[ciak2009]

Sorry I've been so devastatingly busy, I'm getting ready to pull in the fs_tweaks right now and give it a go!

[hexparrot]

This issue was created for du-related issues, which has been addressed with timeouts (2-3 seconds) and has been pulled into master.

After each timeout, the 'disk space used by' fields will report 0, but this should not affect any other functionality.

Issue 146 exists with similar symptoms, but a different cause (server detection fireworm causing 100% cpu). This issue is resolved, 146 is being addressed separately.