Why is my Fork child process not reading from pipe?

Question

I'm trying to create a separate "logger" process using fork(), which will log messages to a file when it receives them. However i'm having an issue, the child process seems to "give up" after one string.

I'm not even sure if this is a great way to go about having a logger process - but here is the output and code

Any ideas or help will be greatly appreciated - thanks

int main()
    {   
        int pipefd[2], nbytes;
        pid_t pid;
        char szLogtest[] = "Log Event: Blah blah blah\n";
        char szLogtest2[] = "Log Event: Blah blah 2\n";
        char readbuffer[512];

        pipe(pipefd);

        if ((pid = fork()) == -1)
        {
            fprintf(stderr, "Fork error!\n");
            exit(1);
        }
        else if (pid == 0)
        {
            printf("I am child!\n");
            close(pipefd[1]); // close the write end of pipe

            while(1)
            {
                nbytes = read(pipefd[0], readbuffer, sizeof(readbuffer));
                printf("Nbytes is %d\n", nbytes);
                if (nbytes)
                {
                    printf("Received string: %s", readbuffer);
                }

                nbytes = 0;
            }

        }
        else
        {
            printf("I am parent!\n");
            close(pipefd[0]); //close read end of pipe

            write(pipefd[1], szLogtest, (strlen(szLogtest)+1));
            write(pipefd[1], szLogtest2, (strlen(szLogtest2)+1));
        }

        return 0;
    }

You should catch when the child exits so you can see what exit code/signal it is finishing with. — Chris Turner
What happens if you add while(1) { sleep(1); } in the parent? — stark
stark The exact same output is produced, and Chris, the child should never exit; it's an infinite loop — Cherona
The child received 51 bytes, which is both messages including the null terminating characters on their ends. But your child is only printing up to the first null terminator. — Ian Abbott
You could use fixed length messages for both the write and the read so the child will read exactly the number of bytes that were written. This is inefficient if your messages are shorter that the fixed length most of the time. You could also add some smarts to the child to parse the receive buffer looking for multiple messages like you have here and process complete ones. Use the null characters as the delimiter if all the messages are text. If you send binary, you need to design some protocol to frame messages. — sizzzzlerz

Jonathan Leffler Jonathan Leffler · Accepted Answer · 2017-12-24T23:34:13

Correct diagnosis in comments

As correctly diagnosed by Ian Abbot in a comment, the immediate problem is that you received null bytes in the middle of the message, but tried to treat the message as a string. That chopped the information.

You also got sensible advice from sizzzzlerz in a comment.

Do not send null bytes

The simplest fix is not to send null bytes to the child. It then doesn't matter then how the child splits up the reads unless it is going to add information to the log printing (such as time information). Here's an example:

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/wait.h>
#include <unistd.h>

static void wait_for(pid_t pid)
{
    int corpse;
    int status;
    while ((corpse = wait(&status)) > 0)
    {
        printf("%d: PID %d exit status 0x%.4X\n", (int)getpid(), corpse, status);
        if (corpse == pid)
            break;
    }
}

static void write_log(int fd, const char *msg)
{
    ssize_t len = strlen(msg);
    if (write(fd, msg, len) != len)
    {
        fprintf(stderr, "%d: failed to write message to logger\n", (int)getpid());
        exit(EXIT_FAILURE);
    }
    printf("%d: Wrote: %zd [%s]\n", (int)getpid(), len, msg);
}

int main(void)
{
    int pipefd[2];
    pid_t pid;
    char szLogtest1[] = "Log Event: Blah blah blah\n";
    char szLogtest2[] = "Log Event: Blah blah 2\n";

    pipe(pipefd);

    if ((pid = fork()) == -1)
    {
        fprintf(stderr, "Fork error!\n");
        exit(1);
    }
    else if (pid == 0)
    {
        printf("%d: I am child!\n", (int)getpid());
        close(pipefd[1]);     // close the write end of pipe

        while (1)
        {
            char readbuffer[512];
            int nbytes = read(pipefd[0], readbuffer, sizeof(readbuffer));
            if (nbytes <= 0)
            {
                close(pipefd[0]);
                printf("EOF on pipe -exiting\n");
                exit(EXIT_SUCCESS);
            }
            printf("%d: Logging string: %d [%s]\n", (int)getpid(), nbytes, readbuffer);
        }
    }
    else
    {
        printf("%d: I am parent!\n", (int)getpid());
        close(pipefd[0]);     // close read end of pipe

        write_log(pipefd[1], szLogtest1);
        write_log(pipefd[1], szLogtest2);
        close(pipefd[1]);
        wait_for(pid);
    }

    return 0;
}

Note that most of the messages are prefixed with the PID of the process producing it. It makes it easier to see what's happening in multi-process debugging.

Sample output from this program (log61):

$ ./log61
48941: I am parent!
48941: Wrote: 26 [Log Event: Blah blah blah
]
48941: Wrote: 23 [Log Event: Blah blah 2
]
48942: I am child!
48942: Logging string: 49 [Log Event: Blah blah blah
Log Event: Blah blah 2
]
EOF on pipe -exiting
48941: PID 48942 exit status 0x0000
$

Prefix messages with length

Another simple (but not quite so simple) fix is to break the messages into chunks of not more than 255 bytes, and to write a 1-byte length followed by that many bytes of data. The child then reads the 1-byte length and that many bytes of data. This code creates a read_log() function parallel to the write_log() function, and the write_log() function is modified too.

#include <assert.h>
#include <limits.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/wait.h>
#include <unistd.h>

static void wait_for(pid_t pid)
{
    int corpse;
    int status;
    while ((corpse = wait(&status)) > 0)
    {
        printf("%d: PID %d exit status 0x%.4X\n", (int)getpid(), corpse, status);
        if (corpse == pid)
            break;
    }
}

static void write_log(int fd, const char *msg)
{
    ssize_t len = strlen(msg);
    unsigned char byte = len;
    assert(len > 0 && len <= UCHAR_MAX);

    if (write(fd, &byte, sizeof(byte)) != sizeof(byte) ||
        write(fd, msg, len) != len)
    {
        fprintf(stderr, "%d: failed to write message to logger\n", (int)getpid());
        exit(EXIT_FAILURE);
    }
    printf("%d: Wrote: %zd [%s]\n", (int)getpid(), len, msg);
}

static int read_log(int fd, size_t buflen, char buffer[buflen])
{
    unsigned char byte;
    if (read(fd, &byte, sizeof(byte)) != sizeof(byte))
    {
        fprintf(stderr, "%d: EOF on file descriptor %d\n", (int)getpid(), fd);
        return 0;
    }
    if (buflen < (size_t)(byte + 1))        // avoid signed/unsigned comparison
    {
        fprintf(stderr, "%d: buffer length %zu cannot hold %d bytes\n",
                (int)getpid(), buflen, byte + 1);
        exit(EXIT_FAILURE);
    }
    if (read(fd, buffer, byte) != byte)
    {
        fprintf(stderr, "%d: failed to read %d bytes from file descriptor %d\n",
                (int)getpid(), byte, fd);
        exit(EXIT_FAILURE);
    }
    buffer[byte] = '\0';
    return byte;
}

int main(void)
{
    int pipefd[2];
    pid_t pid;
    char szLogtest1[] = "Log Event: Blah blah blah\n";
    char szLogtest2[] = "Log Event: Blah blah 2\n";

    pipe(pipefd);

    if ((pid = fork()) == -1)
    {
        fprintf(stderr, "Fork error!\n");
        exit(1);
    }
    else if (pid == 0)
    {
        printf("%d: I am child!\n", (int)getpid());
        close(pipefd[1]);     // close the write end of pipe

        char readbuffer[512];
        int nbytes;
        while ((nbytes = read_log(pipefd[0], sizeof(readbuffer), readbuffer)) > 0)
        {
            printf("%d: Logging string: %d [%s]\n", (int)getpid(), nbytes, readbuffer);
        }
        close(pipefd[0]);
        printf("EOF on pipe -exiting\n");
        exit(EXIT_SUCCESS);
    }
    else
    {
        printf("%d: I am parent!\n", (int)getpid());
        close(pipefd[0]);     // close read end of pipe

        write_log(pipefd[1], szLogtest1);
        write_log(pipefd[1], szLogtest2);
        close(pipefd[1]);
        wait_for(pid);
    }

    return 0;
}

Sample output from this program (log59):

$ ./log59
48993: I am parent!
48993: Wrote: 26 [Log Event: Blah blah blah
]
48993: Wrote: 23 [Log Event: Blah blah 2
]
48994: I am child!
48994: Logging string: 26 [Log Event: Blah blah blah
]
48994: Logging string: 23 [Log Event: Blah blah 2
]
48994: EOF on file descriptor 3
EOF on pipe -exiting
48993: PID 48994 exit status 0x0000
$

As you can see, the separate messages are logged separately, unlike the joint messaging in the first example.

Encoding very long messages

If it is crucial that long messages are handled as one unit, but they're fairly rare, you could send 1..254 as the length for a single unit message, and send 255 to indicate '254 byte chunk follows but its incomplete'. Or, indeed, you could send 1..255 to indicate a complete message of up to 255 bytes, and 0 to indicate 'this is the next 255-byte installment of a message that is longer than 255 bytes'. (Note that you must only send 255 bytes so that there is a follow-up message of at least 1 byte.) This modifies the write_log() and read_log() functions, but the main code doesn't have to change — except that it is necessary to test the multi-block functionality.

This code is more complex than the previous versions. It is shown with some of the debugging printing commented out.

/* SO 4481-0272 */
/* Variant 3 - handle long messages */
#include <assert.h>
#include <limits.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/wait.h>
#include <unistd.h>

static void wait_for(pid_t pid)
{
    int corpse;
    int status;
    while ((corpse = wait(&status)) > 0)
    {
        printf("%d: PID %d exit status 0x%.4X\n", (int)getpid(), corpse, status);
        if (corpse == pid)
            break;
    }
}

static void write_log_segment(int fd, size_t lencode, size_t length, const char *msg)
{
    unsigned char byte = lencode;
    assert(lencode == length || (lencode == 0 && length == UCHAR_MAX));

    if (write(fd, &byte, sizeof(byte)) != sizeof(byte) ||
        write(fd, msg, length) != (ssize_t)length)    // avoid signed/unsigned comparison
    {
        fprintf(stderr, "%d: failed to write message to logger\n", (int)getpid());
        exit(EXIT_FAILURE);
    }
    //printf("%d: Wrote segment: %zu (code %zu) [%s]\n", (int)getpid(), length, lencode, msg);
}

static void write_log(int fd, const char *msg)
{
    size_t len = strlen(msg);
    printf("%d: Write buffer: %zu [%s]\n", (int)getpid(), len, msg);
    while (len > 0)
    {
        size_t lencode = (len <= UCHAR_MAX) ? len : 0;
        size_t length  = (len <= UCHAR_MAX) ? len : UCHAR_MAX;
        write_log_segment(fd, lencode, length, msg);
        len -= length;
        msg += length;
    }
    //printf("%d: Buffer complete\n", (int)getpid());
}

/*
** This code could encounter:
** 1.  EOF (or a read error) - return EOF.
** 2.  A regular complete message in a single segment - return message
**     length (1..255).
** 3.  A partial message with more segments to follow - return MSG_SEGMENT.
** Partial segments with more to follow are of length 255, but it is
** possible to have a regular complete message of length 255.
*/
enum { MSG_SEGMENT = -2 };
static_assert(MSG_SEGMENT != EOF, "EOF is not distinct from MSG_SEGMENT");

static int read_log_segment(int fd, size_t buflen, char buffer[buflen])
{
    unsigned char byte;
    if (read(fd, &byte, sizeof(byte)) != sizeof(byte))
    {
        fprintf(stderr, "%d: EOF on file descriptor %d\n", (int)getpid(), fd);
        return EOF;
    }
    size_t length = byte;
    if (length == 0)
        length = UCHAR_MAX;
    if (buflen < (size_t)(byte + 1))        // avoid signed/unsigned comparison
    {
        fprintf(stderr, "%d: buffer length %zu cannot hold %d bytes\n",
                (int)getpid(), buflen, byte + 1);
        exit(EXIT_FAILURE);
    }
    if (read(fd, buffer, length) != (ssize_t)length)    // avoid signed/unsigned comparison
    {
        fprintf(stderr, "%d: failed to read %zu bytes from file descriptor %d\n",
                (int)getpid(), length, fd);
        exit(EXIT_FAILURE);
    }
    buffer[length] = '\0';
    return (byte == 0) ? MSG_SEGMENT : byte;
}

static size_t read_log(int fd, size_t buflen, char buffer[buflen])
{
    //printf("%d: reading %zu\n", (int)getpid(), buflen);
    char *msg = buffer;
    size_t len = buflen;
    int nbytes;
    int tbytes = 0;
    while (len > 0 && (nbytes = read_log_segment(fd, len, msg)) != EOF)
    {
        if (nbytes != MSG_SEGMENT)
        {
            tbytes += nbytes;
            break;
        }
        nbytes = UCHAR_MAX;
        //printf("%d: segment %d [%s] (%zu: %d: %zu)\n", (int)getpid(), nbytes, msg, buflen, tbytes, len);
        msg += nbytes;
        len -= nbytes;
        tbytes += nbytes;
    }
    /* This disguises a read error or EOF as success when a long message is truncated */
    //if (tbytes != 0)
    //    printf("%d: logging %d [%s]\n", (int)getpid(), tbytes, buffer);
    //else
    //    printf("%d: EOF\n", (int)getpid());
    return tbytes;
}

static void gen_msg(size_t size, char *buffer)
{
    enum { CHUNK_SIZE = 64 };
    //char *obuffer = buffer;     // DEBUG
    //size_t osize = size;        // DEBUG
    char c = 'a';
    while (size >= CHUNK_SIZE)
    {
        memset(buffer, c, CHUNK_SIZE - 1);
        buffer[CHUNK_SIZE - 1] = '\n';
        size -= CHUNK_SIZE;
        buffer += CHUNK_SIZE;
        if (++c > 'z')
            c = 'a';
    }
    if (size > 0)
    {
        if (size > 1)
            memset(buffer, '@', size - 1);
        buffer[size - 1] = '\n';
        buffer += size;
    }
    buffer[0] = '\0';
    //printf("GM: Buffer %zu (%zu) [%s]\n", osize, strlen(obuffer), obuffer);   // DEBUG
}

int main(void)
{
    int pipefd[2];
    pid_t pid;
    char szLogtest1[] = "Log Event: Blah blah blah\n";
    char szLogtest2[] = "Log Event: Blah blah 2\n";

    pipe(pipefd);

    if ((pid = fork()) == -1)
    {
        fprintf(stderr, "Fork error!\n");
        exit(1);
    }
    else if (pid == 0)
    {
        printf("%d: I am child!\n", (int)getpid());
        close(pipefd[1]);     // close the write end of pipe

        char readbuffer[1200];
        int nbytes;
        while ((nbytes = read_log(pipefd[0], sizeof(readbuffer), readbuffer)) > 0)
        {
            printf("%d: Logging string: %d [%s]\n", (int)getpid(), nbytes, readbuffer);
        }
        close(pipefd[0]);
        printf("%d: EOF on pipe - exiting\n", (int)getpid());
        exit(EXIT_SUCCESS);
    }
    else
    {
        printf("%d: I am parent!\n", (int)getpid());
        close(pipefd[0]);     // close read end of pipe

        write_log(pipefd[1], szLogtest1);
        write_log(pipefd[1], szLogtest2);
        char buffer[1100];
        gen_msg(290, buffer);
        write_log(pipefd[1], buffer);
        gen_msg(842, buffer);
        write_log(pipefd[1], buffer);
        //int multiplier = 4;
        //for (int i = 64; i <= 1024; i *= multiplier)
        //{
        //    char buffer[1100];
        //    //for (int j = i - multiplier; j <= i + multiplier; j++)
        //    for (int j = i - 1; j <= i + 1; j++)
        //    {
        //        gen_msg(j, buffer);
        //        write_log(pipefd[1], buffer);
        //    }
        //}
        close(pipefd[1]);
        wait_for(pid);
    }

    return 0;
}

Sample output from this program (log67):

50183: I am parent!
50183: Write buffer: 26 [Log Event: Blah blah blah
]
50183: Write buffer: 23 [Log Event: Blah blah 2
]
50183: Write buffer: 290 [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
ccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccc
ddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddd
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
]
50183: Write buffer: 842 [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
ccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccc
ddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddd
eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee
fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
ggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggg
hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh
iiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiii
jjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjj
kkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkk
lllllllllllllllllllllllllllllllllllllllllllllllllllllllllllllll
mmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmm
@@@@@@@@@
]
50184: I am child!
50184: Logging string: 26 [Log Event: Blah blah blah
]
50184: Logging string: 23 [Log Event: Blah blah 2
]
50184: Logging string: 290 [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
ccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccc
ddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddd
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
]
50184: Logging string: 842 [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
ccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccc
ddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddd
eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee
fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
ggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggg
hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh
iiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiii
jjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjj
kkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkk
lllllllllllllllllllllllllllllllllllllllllllllllllllllllllllllll
mmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmm
@@@@@@@@@
]
50184: EOF on file descriptor 3
50184: EOF on pipe - exiting
50183: PID 50184 exit status 0x0000