View Issue Details

IDProjectCategoryView StatusLast Update
0006029unrealircdpublic2021-12-25 09:00
Reporterarmyn Assigned Tosyzop  
PrioritynormalSeverityminorReproducibilitysometimes
Status resolvedResolutionfixed 
Product Version6.0.0 
Fixed in Version6.0.1 
Summary0006029: io.HIGH_LOAD [warn] HIGH CPU LOAD! fd_select() took 1234 msec (read: 1, write: 0)
DescriptionI noticed my server was showing this not even 5 minutes ago:

[13:03:56] -irc.domain.com- io.HIGH_LOAD [warn] HIGH CPU LOAD! fd_select() took 1234 msec (read: 1, write: 0)


I also ran a search for this regex on all logs to see a bit, here is:

[13:07:06] root@ns [~]# grep -Ri "HIGH_LOAD" /home/irclog/public_html/logs/status*122021*
/home/irclog/public_html/logs/status.18122021.log:[04:21:41] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1211 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:22:16] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1562 msec (read: 1, write: 5)
/home/irclog/public_html/logs/status.18122021.log:[04:23:34] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 11253 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:24:17] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 20252 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:24:25] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 7913 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:24:30] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1861 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:25:50] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 19683 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:26:12] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 15890 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:26:19] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1201 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.18122021.log:[04:26:28] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1432 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[00:54:16] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1513 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:07:06] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1399 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:13:19] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 2601 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:14:01] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 8817 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:14:35] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1422 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:17:46] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 3786 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:18:24] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1345 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:20:47] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 2941 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:21:41] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 2860 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:22:15] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 2969 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:22:50] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 2859 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:25:19] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 10637 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:25:45] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 24490 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:26:00] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 8388 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[04:27:09] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 44805 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.19122021.log:[13:15:56] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1000 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:03:52] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1136 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:06:34] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 4316 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:07:06] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1321 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:08:13] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1923 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:13:32] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1697 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:14:04] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 2388 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:16:39] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 5619 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:16:39] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 2929 msec (read: 51, write: 17)
/home/irclog/public_html/logs/status.20122021.log:[04:17:35] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 5869 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:21:15] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1915 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:21:55] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 3567 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:22:25] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1209 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:22:43] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 13479 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:23:06] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 3550 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:23:19] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 9480 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:23:35] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 5365 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[04:24:10] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 7319 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[09:05:18] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1060 msec (read: 1, write: 0)
/home/irclog/public_html/logs/status.20122021.log:[13:03:56] -NOTICE- 14io.HIGH_LOAD 07[warn] HIGH CPU LOAD! fd_select() took 1234 msec (read: 1, write: 0)
[13:07:19] root@ns [~]#

What does that mean?

UnrealIRCd 6.0.0 was put into production on December 18 around 4 a.m. as the first line of the log






TagsNo tags attached.
3rd party modules

Activities

syzop

2021-12-20 18:06

administrator   ~0022267

It basically means the machine is very busy and that it (unexpectedly) took >1000 msec (more than 1 second) to process all clients.

It's good you pasted your logs, it shows that it happens consistently every day at around 4am. Maybe you have some kind of backup job running or something other on the machine that uses high CPU or high I/O?
As you can see, I expect the cause to be outside UnrealIRCd due to that :)

We should probably remove the warning anyway, it will cause people something is wrong with UnrealIRCd which 99% likely isn't the case here. I put it in while debugging stuff in U6.

armyn

2021-12-20 19:55

reporter   ~0022271

" We should probably remove the warning anyway, it will cause people something is wrong with UnrealIRCd which 99% likely isn't the case here. I put it in while debugging stuff in U6. "

ah ok yes, so yes it's because of the server backup which takes place around 4:00 a.m. until 4:30 a.m. or 4:45 a.m.

syzop

2021-12-25 09:00

administrator   ~0022296

Last edited: 2021-12-25 09:00

Hehe:
/* Not sure if this is suitable for production,
 * but let's turn it on for U6 development.
 */
#define DETECT_HIGH_CPU

Thanks, the warning is now removed.

https://github.com/unrealircd/unrealircd/commit/7f9c7a0eb40e08ada3dd7ad42859e1339f9bf3b2
commit 7f9c7a0eb40e08ada3dd7ad42859e1339f9bf3b2 (HEAD -> unreal60_dev, origin/unreal60_dev)
Author: Bram Matthys <[email protected]>
Date: Sat Dec 25 08:58:46 2021 +0100

    Remove high cpu load warning, since it is confusing and may very well
    not be caused by UnrealIRCd.
    Reported by armyn in https://bugs.unrealircd.org/view.php?id=6029

Issue History

Date Modified Username Field Change
2021-12-20 13:12 armyn New Issue
2021-12-20 18:06 syzop Note Added: 0022267
2021-12-20 19:55 armyn Note Added: 0022271
2021-12-25 09:00 syzop Assigned To => syzop
2021-12-25 09:00 syzop Status new => resolved
2021-12-25 09:00 syzop Resolution open => fixed
2021-12-25 09:00 syzop Fixed in Version => 6.0.1
2021-12-25 09:00 syzop Note Added: 0022296
2021-12-25 09:00 syzop Note Edited: 0022296