[BUG] grsecurity 2.0.2 Stability problem
Posted: Mon Nov 22, 2004 7:00 pm
We upgraded our servers to Linux 2.4.28 + grsecurity 2.0.2 and got bit by a rather nasty bug which forced us to revert to 2.4.27 + 2.0.1.
It seems there are a few problems:
1) RLIMITs are not being enforced
2) log message DOS protection not working
3) Interrupts are being masked when grsecurity is logging
4) Clock skew with grsecurity log flood control
In the case of #1, that is very easy to illustrate with the following spinme.sh script:
From the logfiles on that server:
Notice how the process ran for 339 seconds. It should have been killed at 6 seconds.
Which brings us to the next issue. When grsecurity was dutifully logging these resource oversteps, it is clear to see that the log flooding controls did not work. Ours is set to:
FLOODTIME: 10
FLOODBURST: 16
Also, when the logging was happening, interrupts appeared to be masked as the server's network card was no longer responsive. From the outside, it appeared that the server was dead, however through the serial console, the server was very much alive and caught in a very tight loop.
The only way to recover the server was to remotely pull its power and bring it back online using the older Linux 2.4.27 + grsecurity 2.0.1 combination.
The above error can be reproduced with that simple spinme.sh script, and also we had five of our servers appear to lockup before we had a chance to revert to the older kernel set.
One more mention, it appears that when grsecurity is handing message flooding, our server clocks become skewed, usually anywhere from 500ms to 1 second. With resource logging turned on, our clocks would become terribly skewed if it were not for us using a modified DJB clockspeed with aggressive adjtimex settings to counteract grsecurity skew.
If you need any additional details, please let us know.
--
Terra
It seems there are a few problems:
1) RLIMITs are not being enforced
2) log message DOS protection not working
3) Interrupts are being masked when grsecurity is logging
4) Clock skew with grsecurity log flood control
In the case of #1, that is very easy to illustrate with the following spinme.sh script:
- Code: Select all
#!/bin/sh
ulimit -t 5
while true; do :; done
From the logfiles on that server:
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 6 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:24892] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
......
......
......
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
ttyR11.log.1.gz:grsec: From 68.202.145.28: attempted resource overstep by requesting 339 for RLIMIT_CPU against limit 5 by /home/fqbuild/work/spinme.sh[spinme.sh:11999] uid/euid:210/210 gid/egid:210/210, parent /bin/bash[bash:3007] uid/euid:210/210 gid/egid:210/210
Notice how the process ran for 339 seconds. It should have been killed at 6 seconds.
Which brings us to the next issue. When grsecurity was dutifully logging these resource oversteps, it is clear to see that the log flooding controls did not work. Ours is set to:
FLOODTIME: 10
FLOODBURST: 16
Also, when the logging was happening, interrupts appeared to be masked as the server's network card was no longer responsive. From the outside, it appeared that the server was dead, however through the serial console, the server was very much alive and caught in a very tight loop.
The only way to recover the server was to remotely pull its power and bring it back online using the older Linux 2.4.27 + grsecurity 2.0.1 combination.
The above error can be reproduced with that simple spinme.sh script, and also we had five of our servers appear to lockup before we had a chance to revert to the older kernel set.
One more mention, it appears that when grsecurity is handing message flooding, our server clocks become skewed, usually anywhere from 500ms to 1 second. With resource logging turned on, our clocks would become terribly skewed if it were not for us using a modified DJB clockspeed with aggressive adjtimex settings to counteract grsecurity skew.
If you need any additional details, please let us know.
--
Terra