libev loop uses 99% of the CPU while idle

Question

So I have a program that runs an libev I/O loop and a timer loop. When the char array hits 7000 chars or the timer loop hits ten seconds its going to JSON POST a service running on localhost. The I/O loop is causing the program to use almost 100% CPU when it is idle.

This program requires an argv of either a 1 or a 0:

A 1 makes the program only process one line and exit.
A 0 makes it wait for input.

The error only happens when we pass it a 0 and have it wait for input.

#include <stdio.h>
#include <ev.h>
#include <curl/curl.h>
#include <json-c/json.h>
#include <unistd.h>

void curlPage(char url[], char message[]);
void io_callback(EV_P_ ev_io *w_, int rev);
void time_callback(EV_P_ ev_timer *w_, int rev);

struct watcher
{
    ev_io stdin_watcher;
    ev_timer time_watcher;
};

char lines[BUFSIZ];
char *argv1;
char url[1024] = "http://127.0.0.1:";
char *end;


int main(int argc, char *argv[]) {
    struct ev_loop *loop;
    struct watcher w;

    if (!argv[1]) {
        printf("YOU NEED A 1 OR 0 PARAMATER FOR THIS TO WORK!\n");
        exit(0);
    }
    else {
        end = argv[1];
    }
    argv1 = argv[2];

    if (argv[3]) {
        strcat(url, argv[3]);
    }
    else {
        strcat(url, "8888");
    }

    loop = ev_default_loop(0);

    ev_io_init(&w.stdin_watcher, io_callback, STDIN_FILENO, EV_READ);
    ev_timer_init(&w.time_watcher, time_callback, 10, 0);
    w.time_watcher.repeat=10;
    ev_io_set(&w.stdin_watcher, STDIN_FILENO, EV_READ);
    ev_io_start(loop, &w.stdin_watcher);
    ev_timer_start(loop, &w.time_watcher);

    ev_run(loop, 0); 

    return 0;
}

void time_callback(EV_P_ ev_timer *w_, int rev) {
     if (strlen(lines)) {
         curlPage(url, lines);
         lines[0] = '\0';
     }
     return;
}

void io_callback(EV_P_ ev_io *w_, int rev) {
    struct watcher *w = (struct watcher *)w_;

    char buf[BUFSIZ];
    char * resp;

    resp = fgets(buf, sizeof buf, stdin);
    if (resp != NULL) {
        sprintf(lines, "%s %s", lines, buf);
    }


    if (strlen(lines) > 7000) {
        curlPage(url, lines);
        lines[0] = '\0';
    }
    if (strcmp(end, "1")  == 0) {
        ev_io_stop(loop, w_);
    }
    return;
}

void curlPage(char url[], char message[]) {
    CURL *curl;
    CURLcode res;
    json_object * jsonObj = json_object_new_object();
    char hostname[1024];

    gethostname(hostname, 1024);
    struct curl_slist * headers=NULL;
    headers = curl_slist_append(headers, "Accept: application/json");
    headers = curl_slist_append(headers, "Content-Type: application/json");
    headers = curl_slist_append(headers, "charsets: utf-8");

    curl = curl_easy_init();

    if(curl) {

        if (hostname) {
            json_object *jstring2 = json_object_new_string(hostname);
            json_object_object_add(jsonObj, "hostname", jstring2);
        }
        if (argv1) {
            json_object *jstring3 = json_object_new_string(argv1);
            json_object_object_add(jsonObj, "tag", jstring3);
        }

        json_object *jstring = json_object_new_string(message);
        json_object_object_add(jsonObj, "message", jstring);

        curl_easy_setopt(curl, CURLOPT_CUSTOMREQUEST, "POST");
        curl_easy_setopt(curl, CURLOPT_HTTPHEADER, headers);
        curl_easy_setopt(curl, CURLOPT_URL, url);
        curl_easy_setopt(curl, CURLOPT_POSTFIELDS, json_object_get_string(jsonObj));

        res = curl_easy_perform(curl);

        if(res != CURLE_OK) {
            fprintf(stderr, "curl_easy_preform() failed: %s\n", curl_easy_strerror(res));
        }
        curl_easy_cleanup(curl);
    }
    curl_global_cleanup();
    json_object_put(jsonObj);

    // run only once. 
    if (strcmp(end, "1")  == 0) {
         exit(0);
    }
    return;
}

Here is the thread back trace and the stack print out:

So it appears like the I/O watcher gets continuous I/O events after the first event. It waits properly for the first event but after that consumes most of the CPU. I'm using it like this:

cat test.txt | logpush 0 &

perhaps the pipe is causing this condition?

So I wrote a test program that is just a simple libev I/O watcher:

#include <stdio.h>
#include <ev.h>
#include <unistd.h>

void io_callback(EV_P_ ev_io *w_, int rev);
void time_callback(EV_P_ ev_timer *w_, int rev);

char lines[BUFSIZ];

int main(int argc, char *argv[]) {
    struct ev_loop *loop;
    struct ev_io stdin_watcher;

    loop = ev_default_loop(0);

    ev_io_init(&stdin_watcher, io_callback, STDIN_FILENO, EV_READ);
    ev_io_set(&stdin_watcher, STDIN_FILENO, EV_READ);
    ev_io_start(loop, &stdin_watcher);

    ev_run(loop, 0);

    return 0;
}

void io_callback(EV_P_ ev_io *w_, int rev) {
    printf("callback hit\n");
    return;
}

The I/O callback gets hit hundreds of times a second even if there is no input if called with a pipe, like so:

cat test.txt | ./test &

This also happens when I pipe stdout of a process to my program.

This is the root cause of my issue.

`if (argv[3])` is UB if `if (argv[2]) == NULL`. Suggest checking `argc` for expected range. — chux - Reinstate Monica, Aug 04 '16 at 23:00
Posting text, rather than pictures of text, is more useful in problem solving. — chux - Reinstate Monica, Aug 05 '16 at 14:23
`cat test.txt | logpush 0 &` your logpush doesn't recognise the EOF on the file descriptor, and continues to call the callback. — joop, Aug 05 '16 at 15:12

score 0 · Answer 1 · edited Aug 05 '16 at 03:04

0

sprintf(lines, "%s %s", lines, buf); is undefined behavior.

int sprintf(char * restrict s, const char * restrict format, ...);

The restrict means that sprintf() does not expect the data s points to to be accessed by anything else the function accesses. Since code passed lines to s and an argument, code broke the contract and undefined behavior results. Possible lines is simple growing and growing and growing.

Instead

// sprintf(lines, "%s %s", lines, buf);
strcat(lines, " ");
strcat(lines, buf);
// Other more time efficient code is possible

As usual, watching out for buffer overflow is a concern.

Code likely has other issues too.

edited Aug 05 '16 at 03:04

David C. Rankin

81,885
6
58
85

answered Aug 05 '16 at 01:36

chux - Reinstate Monica

143,097
13
135
256

Took license *contact* -> *contract* `:)` – David C. Rankin Aug 05 '16 at 03:05
'changing the sprintf to strcat like you suggested doesn't fix the issue. ' – Jacob McCoy Aug 05 '16 at 13:56
'even if i comment out the whole callback block and only have return it still uses 90% of the cpu. ' – Jacob McCoy Aug 05 '16 at 13:56
@Jacob McCoy "Code likely has other issues too." so suggest testing smaller sections of code. – chux - Reinstate Monica Aug 05 '16 at 14:22
please see above update. The root cause of the issue is a run away io loop. – Jacob McCoy Aug 05 '16 at 14:44
this issue also happens when i pipe the stdout of a process to this program. ( not just with cat) – Jacob McCoy Aug 05 '16 at 14:44

joop · Accepted Answer · 2016-08-05T15:44:34.387

This modification of the second snippet works on pipes (at least: cat event.c | ./a.out) . The problem seems to be not detecting EOF, and keep on hammering on the filedescriptor

#include <stdio.h>
#include <ev.h>
#include <unistd.h>

void io_callback(EV_P_ ev_io *w_, int rev);
void time_callback(EV_P_ ev_timer *w_, int rev);


struct ev_loop *loop; /* made this global, because needed by the callback at closing time */

int main(int argc, char *argv[]) {
    struct ev_io stdin_watcher;

    loop = ev_default_loop(0);

    ev_io_init(&stdin_watcher, io_callback, STDIN_FILENO, EV_READ);
    ev_io_set(&stdin_watcher, STDIN_FILENO, EV_READ);
    ev_io_start(loop, &stdin_watcher);

    // ev_run(loop, 0);
    ev_loop(loop, 0);

    return 0;
}

void io_callback(EV_P_ ev_io *w_, int rev) {
    int rc;
    char ch;

        /* replaced fgets() by read() */
    rc = read(STDIN_FILENO, &ch, 1);

        /* diagnostic output should go to stderr */
    fprintf(stderr, "Callback hit, rc=%d, ch = %02x\n"
        , rc, ch & 0xff
        );
    if (rc == 0) ev_io_stop(loop, w_);
    return;
}

-- and for testing you could use the below program and pipe its output through the binary, like: sh loop.sh | ./a.out

#!/bin/sh
while true; do
        date
        sleep 5
done

It is not about efficiency. I wanted to get rid of the buffering (at least not be confused by it) Internally, fgets() of course calls read() when it thinks it needs a buffer full of data. And you should of course call read() with a larger buffer and 3rd argument. — joop, Aug 05 '16 at 15:35

libev loop uses 99% of the CPU while idle

2 Answers2