Seg fault when trying to print a string

Question

I am hitting segmentation fault when I try to print a variable length string. When I print the string using printf or in a log file, the string gets printed fine. Another issue is, I am seeing the crash only in some machine where as the same test works fine in another. I am really confused as to why.

EDIT: A complete working code which is causing a crash I am pasting below. Crash is with Centos 6.3 and Centos 6.5. Crash is not seen in Centos 5

#include <stdio.h>
#include <stdarg.h>
#include <stdint.h>
#include <sys/time.h>
#include <time.h>

typedef struct {
    uint64_t  total_bytes_sent;
    uint64_t  total_bytes_received;
    uint64_t  total_blocks_sent;
    uint64_t  total_blocks_received;
    uint64_t  total_commands_sent;
    uint64_t  total_commands_received;
    uint64_t  time_to_process_data;
    char      mark_sent_time[64];
    char      mark_received_time[64];
} csperf_stats_t;

void
csperf_stats_printf(const char *format, ...)
{
    /* Write to file */
    va_list args;

    /* Write to stdout */
    va_start(args, format);
    vfprintf(stdout, format, args);
    va_end(args);
}

void
ansperf_stats_display(csperf_stats_t *stats)
{
    if (!stats) {
        return;
    }

    stats->total_blocks_sent = 1000;
    stats->total_blocks_received = 2000;
    stats->time_to_process_data = 22;

    csperf_stats_printf("%3d   %15s    %10s    %10zu    %10zu    %10zu       %10s    "
            "%10s\n\n",
                0, "hi", "testing.",
            stats->total_blocks_sent, stats->total_blocks_received,
            stats->time_to_process_data,
            "crash", "test");
}

/* Get time in millisecond */
uint64_t
csperf_network_get_time(char *buf)
{
    char            fmt[64];
    struct tm       *tm;
    struct timeval tv;
    uint64_t s;

    gettimeofday(&tv, NULL);

    if (buf) {
        if((tm = localtime(&tv.tv_sec)) != NULL) {
            strftime(fmt, sizeof(fmt), "%Y-%m-%d %H:%M:%S.%03u", tm);
            snprintf(buf, sizeof(fmt), fmt, tv.tv_usec);
        }
    }
    s = tv.tv_sec * 1000LL;
    return(s + tv.tv_usec / 1000LL);
}

int main()
{
    csperf_stats_t stats = { 0 };
    csperf_network_get_time(stats.mark_sent_time);
    csperf_network_get_time(stats.mark_received_time);
    printf("%s%s\n", stats.mark_sent_time, stats.mark_received_time);
    ansperf_stats_display(&stats);
}

Following is the code snippet where it is crashing.

It is crashing in vfprintf() when it is trying to print stats->mark_sent_time, stats->mark_received_time. when i printing the string in gdb, it doesn't complain.

void
csperf_stats_printf(FILE *fd, const char *format, ...)
{
    /* Write to file */
    va_list args;

    va_start(args, format);
    if (fd) {
        vfprintf(fd, format, args);
    }
    va_end(args);

    /* Write to stdout */
    va_start(args, format);
    vfprintf(stdout, format, args);
    va_end(args);
}

void
ansperf_stats_display(csperf_stats_t *stats, FILE *fd)
{
    static int header_displayed = 0;
    static int cycle = 0;
    char total_bytes_sent_str[50];
    char total_bytes_recv_str[50];

    if (!stats) {
        return;
    }

    if (!header_displayed) {
        csperf_stats_printf(fd, "%s%s", header, seperator_line);
        header_displayed = 1;
    }

    csperf_common_calculate_size(total_bytes_sent_str,
            stats->total_bytes_sent);
    csperf_common_calculate_size(total_bytes_recv_str,
            stats->total_bytes_received);

    csperf_stats_printf(fd, "%3d   %15s    %10s    %10zu    %10zu    %10zu       %10s    "
            "%10s\n\n", ++cycle,
            total_bytes_sent_str, total_bytes_recv_str,
            stats->total_blocks_sent, stats->total_blocks_received,
            stats->time_to_process_data,
            stats->mark_sent_time, stats->mark_received_time);
}

This is what the gdb shows

(gdb) p stats->mark_sent_time
No symbol "stats" in current context.
(gdb) f 2
#2  0x08051f56 in ansperf_stats_display (stats=0x892ded4, fd=0x892e888) at /home/nikhil/csperf/src/csperf_stats.c:55
55          csperf_stats_printf(fd, "%3d   %15s    %10s    %10zu    %10zu    %10zu       %100s    "
(gdb) p stats->mark_sent_time
$1 = "20160821 21325800007", '\000' <repeats 79 times>
(gdb) p stats->mark_recei9ved_time
There is no member named mark_recei9ved_time.
(gdb) p stats->mark_received_time
$2 = "20160821 21325800007", '\000' <repeats 79 times>

The string is an array of 100 bytes as follows

char      mark_sent_time[100];
char      mark_received_time[100];

It is set like this:

command->echo_timestamp = csperf_network_get_time(
        client->stats.mark_sent_time);

This function copies the timestamp to the string "mark_sent_time"

uint64_t
csperf_network_get_time(char *buf)
{
    char            fmt[64];
    struct tm       *tm;
    struct timeval tv;
    uint64_t s;

    gettimeofday(&tv, NULL);

    if (buf) {
        if((tm = localtime(&tv.tv_sec)) != NULL) {
            strftime(fmt, sizeof(fmt), "%Y-%m-%d %H:%M:%S.%03u", tm);
            snprintf(buf, sizeof(fmt), fmt, tv.tv_usec);
        }
    }
    s = tv.tv_sec * 1000LL;
    return(s + tv.tv_usec / 1000LL);
}

Backtrace:

(gdb) bt
#0  0x002b535e in _IO_vfprintf_internal (s=Cannot access memory at address 0xffffffff
) at vfprintf.c:1603
#1  0x08051de7 in csperf_stats_printf (fd=0x892e888, format=0x8079a6c "%3d   %15s    %10s    %10zu    %10zu    %10zu       %100s    %100s \n\n") at /home/nikhil/csperf/src/csperf_stats.c:23
#2  0x08051f56 in ansperf_stats_display (stats=0x892ded4, fd=0x892e888) at /home/nikhil/csperf/src/csperf_stats.c:55

#3  0x08050ad3 in csperf_client_shutdown (client=0x892deb0) at /home/nikhil/csperf/src/csperf_client.c:67

What am I missing?

Answer 1

The problem is your use of %zu to display a uint64_t variable in your format string.

On a 64-bit target this is fine the %zu is for size_t, and (at least on my 64-bit system) this is 64-bits. On a 32-bit system however (for me at least) size_t is 32-bits, but the uint64_t variable still places 64 bits into the va_list structure. The %zu only consumes 32-bits, and this leaves a 32-bit value in the va_list that is used instead of the next parameter.

Replace uses of "%zu" with "%" PRIu64 when you are printing a uint64_t variable (at least 3 places in your example).

You might need to include the <inttypes.h> header to get access to PRIu64.

.... And as I mentioned in a comment, I don't think that this:

strftime(fmt, sizeof(fmt), "%Y-%m-%d %H:%M:%S.%03u", tm);
snprintf(buf, sizeof(fmt), fmt, tv.tv_usec);

is doing what you expect. I think that you probably want the %03u in the strftime line to carry over into the snprintf line to consume the tv.tv_usec, however %u for strftime is day of the week as a digit, you probably should use %%03u in the strftime call, then your fmt for snprintf will contain just %03u.