Periodic high kernel CPU load?

Surprisingly high kernel CPU for programs that normally uses little CPU. Linux machine alternates between states. Most of the time, programs execute normally using low CPU. During a CPU "surge", programs use high kernel CPU using 100% available CPU.

Sample C program and output below.

The machine goes in and out of a weird state roughly every five minutes where some, but not all, programs use high kernel CPU. The CPU "surge" might last a minute then the machine returns to normal state for another 5-10 minutes. Reboot sometimes help but the surges gradually build up over a week until the problem becomes severe enough that another reboot is required. Sometimes a reboot doesn't help and the only temporary fix is to try another reboot.

• CentOS release 6.9
• Dell PowerEdge R630 with 14 CPUs, 32 GB Ram
• Linux 2.6.32-696.30.1.el6.x86_64 x86_64

I was able to reproduce the CPU issue with this sample C program. It runs a shell script that executes a sleep for 0.01 second and prints the run time for each of 10 iterations. It runs quickly when the machine is in a normal state and runs slow when the machine is in the abnormal state.

test_system.c

#include <stdio.h>
#include <stdlib.h>

int main(int argc, char *argv[])
{
    int i, n;
    char cmd[100];

    if (argc == 2) {
        n = atoi(argv[1]);
    }
    else {
        n = 1;
    }

    printf("n=%d\n", n);

    for (i=0; i<n; i++) {
        system("ts=$(date +%s%N) ; sleep 0.01 ; tt=$((($(date +%s%N) - $ts)/1000000)) ; echo \"Time taken: $tt milliseconds\"");
    }
}

Here's output when the machine is in a normal state. Most of the CPU is in the user space.

$ time test_system 10
n=10
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds

real    0m0.210s
user    0m0.059s
sys     0m0.015s
$

Here's output when the machine is experiencing CPU "surge" mode. I added comments where two long pauses occurred. The delays are due to machine being CPU overloaded. The run time is 35.6 sec, 170x longer than normal. The kernel CPU usage for this run is 7.2 sec, a 480x increase from the normal run.

$ time test_system 10
n=10
Time taken: 161 milliseconds
Time taken: 406 milliseconds
Time taken: 58 milliseconds
Time taken: 176 milliseconds
Time taken: 189 milliseconds
--- approx. 17 sec delay ---
Time taken: 25 milliseconds
Time taken: 127 milliseconds
Time taken: 82 milliseconds
Time taken: 84 milliseconds
Time taken: 12 milliseconds
--- approx. 17 sec delay ---

real    0m35.641s
user    0m0.077s
sys     0m7.233s
$

This post suggests too much memory allocated for I/O buffers can cause this problem because the kernel has to work hard to reclaim memory in order to run programs. But there's no indication of memory swapping or shortage. I ran a separate test of allocating 100 MB memory and don't see delays or high CPU even during the CPU surge.

Any other suggestions on what can cause this behavior?

Here's my latest test program that times fork() and exec() separately.

test_fork.c

#include <stdio.h>
#include <stdlib.h>
#include <sys/time.h>
#include <unistd.h>
#include <assert.h>

#define ELAPSED_USEC(t1, t2)  (SEC2USEC((t2).tv_sec - (t1).tv_sec) + (t2).tv_usec - (t1).tv_usec)
#define SEC2USEC(sec)         ((sec)*1000000)


int main(int argc, char *argv[])
{
    int i, n;
    struct timeval start_time, end_time;
    struct timezone tz;
    pid_t pid;
    char *shell = "/bin/bash";
    char *shell_cmd;
    int status;

    if (argc == 3) {
        n = atoi(argv[1]);
        shell_cmd = argv[2];
    }
    else {
        fprintf(stderr, "Usage: %s count shell_cmd\n", argv[0]);
        exit(1);
    }

    printf("n=%d shell_cmd=[%s]\n", n, shell_cmd);

    for (i=0; i<n; i++) {
        gettimeofday(&start_time, &tz);
        pid = fork();
        if (pid == -1)
        {   
            fprintf(stderr, "fork failed.\n");
            exit(1);
        }
        else if (pid > 0)
        {   
            gettimeofday(&end_time, &tz);
            printf("fork: %ld usec, ", ELAPSED_USEC(start_time, end_time));

            gettimeofday(&start_time, &tz);
            waitpid(pid, &status, 0);
            gettimeofday(&end_time, &tz);
            printf("exec: %ld msec\n", ELAPSED_USEC(start_time, end_time)/1000);  // 1 msec = 1000 usec
            //assert(WEXITSTATUS(status) == 123);
        }
        else
        {
            // we are the child
            execl(shell, shell, "-c", shell_cmd, NULL);
            _exit(EXIT_FAILURE);   // exec never returns
        }
    }
}

And here are some sample output while machine is in surge state. Only exec() uses extra CPU.

$ test_fork 10 'exit 123'
n=10 shell_cmd=[exit 123]
fork: 41 usec, exec: 1 msec
fork: 46 usec, exec: 46586 msec
fork: 57 usec, exec: 1 msec
fork: 46 usec, exec: 12 msec
fork: 50 usec, exec: 112 msec
fork: 50 usec, exec: 1 msec
fork: 46 usec, exec: 2 msec
fork: 43 usec, exec: 1 msec
fork: 40 usec, exec: 18 msec
fork: 71 usec, exec: 1 msec

real    0m46.741s
user    0m0.005s
sys     0m13.999s
$