enhancement: timestamp in every output line

[cleo-yin]

• Version of iperf3:
  iperf 3.7 (cJSON 1.5.2)

Enhancement Request

sometimes especially in wireless roaming test, we need the timestamp in the output per second, so we can know the exact time(in millisecond) that the throughput is going down, it's very helpful in the wireless roaming debugging.

• Current behavior
  no timestamp for every output line
  $ iperf3 -c 127.0.0.1 -t 3 -u
  Connecting to host 127.0.0.1, port 5201
  warning: Block size 16332 > sending socket buffer size 9216
  Increasing socket buffer size to 17356
  [ 5] local 127.0.0.1 port 62057 connected to 127.0.0.1 port 5201
  [ ID] Interval Transfer Bitrate Total Datagrams
  [ 5] 0.00-1.00 sec 144 KBytes 1.18 Mbits/sec 9
  [ 5] 1.00-2.00 sec 128 KBytes 1.05 Mbits/sec 8
  [ 5] 2.00-3.00 sec 128 KBytes 1.05 Mbits/sec 8

---

[ ID] Interval Transfer Bitrate Jitter Lost/Total Datagrams
[ 5] 0.00-3.00 sec 399 KBytes 1.09 Mbits/sec 0.000 ms 0/25 (0%) sender
[ 5] 0.00-3.00 sec 399 KBytes 1.09 Mbits/sec 0.019 ms 0/25 (0%) receiver

• Desired behavior
  $ iperf3 -c 127.0.0.1 -t 3 -u --timestamp
  Connecting to host 127.0.0.1, port 5201
  warning: Block size 16332 > sending socket buffer size 9216
  Increasing socket buffer size to 17356
  [ 5] local 127.0.0.1 port 62878 connected to 127.0.0.1 port 5201
  Sep 02 15:19:31.524 [ ID] Interval Transfer Bitrate Total Datagrams
  Sep 02 15:19:31.524 [ 5] 0.00-1.00 sec 144 KBytes 1.18 Mbits/sec 9
  Sep 02 15:19:32.524 [ 5] 1.00-2.00 sec 128 KBytes 1.05 Mbits/sec 8
  Sep 02 15:19:33.525 [ 5] 2.00-3.00 sec 128 KBytes 1.05 Mbits/sec 8

---

Sep 02 15:19:33.525 [ ID] Interval Transfer Bitrate Jitter Lost/Total Datagrams
Sep 02 15:19:33.525 [ 5] 0.00-3.00 sec 399 KBytes 1.09 Mbits/sec 0.000 ms 0/25 (0%) sender
Sep 02 15:19:33.525 [ 5] 0.00-3.00 sec 399 KBytes 1.09 Mbits/sec 0.018 ms 0/25 (0%) receiver

[buscseik]

I also would be very happy for this option

[justoneliu]

On windows, you can use powershell to add the timestamp
iperf -s -u -e -i 5 | Foreach{"{0}-{1}" -f (get-date),$_}
or save the log at the same time
iperf -s -u -e -i 5 | Foreach{"{0}-{1}" -f (get-date),$_} | tee /path/to/file

[bmah888]

This should be pretty easy for someone to do if they felt like hacking on iperf3. See iperf_print in src/iperf_api.c.

[davidBar-On]

Assuming that accuracy of seconds is sufficient (millisec accuracy is no needed) then the following changes to iperf_printf() can be done to add current time at the beginning of each line (proposed changes are in bold):

**time_t now;
time(&now);**

if (test->role == 'c') {
    **fprintf(test->outfile, "%s ", ctime(&now));**
    if (test->title)
	....
}
else if (test->role == 's') {
    char linebuffer[1024];
    **int i;
    i = sprintf(linebuffer, "%s ", ctime(&now));**
    va_start(argp, format);
    r = vsnprintf(&**linebuffer[i]**, sizeof(linebuffer)**-i**, format, argp);
    va_end(argp);
    ....

It would be useful to also add the time in iperf_err() and iperf_errexit() messages. In addition it would be useful to add errno value to these messages (to debug issues such as #499). Therefore, the suggested changes to these two functions are (changes in bold):

Add in both functions:
    **time_t now;
    time(&now);**

Changes to the 4 fprintf():
    fprintf(test->outfile, "**%s** iperf3: %s **\(errno=%d - %s\)**\n", **ctime(&now),** str, **errno, strerror(errno)**);

Changes to the 2 cJSON_AddStringToObject():
	**sprintf(str, "%s ", ctime(&now));**
	va_start(argp, format);
	vsnprintf(**&str[strlen(str)]**, sizeof(str)**-strlen(str)**, format, argp);
	......

[davidBar-On]

Resending - now bold is bold and not ** bold **.

Changes to iperf_printf()

Assuming that accuracy of seconds is sufficient (millisec accuracy is no needed) then the following changes to iperf_printf() can be done to add current time at the beginning of each line (proposed changes are in bold):

time_t now;
time(&now);

if (test->role == 'c') {
    fprintf(test->outfile, "%s ", ctime(&now));
    if (test->title)
    ....
}
else if (test->role == 's') {
    char linebuffer[1024];
    int i;
    i = sprintf(linebuffer, "%s ", ctime(&now));
    va_start(argp, format);
    r = vsnprintf(&linebuffer[i], sizeof(linebuffer)-i, format, argp);
    va_end(argp);
    ....

Changes to iperf_err() and iperf_errexit()

It would be useful to also add the time in iperf_err() and iperf_errexit() messages. In addition it would be useful to add errno value to these messages (to debug issues such as #499). Therefore, the suggested changes to these two functions are (changes in bold):

Add in both functions:

    time_t now;
    time(&now);

Changes to the 4 fprintf():

    fprintf(test->outfile, "%s iperf3: %s \(errno=%d - %s\)\n", ctime(&now), str, errno, strerror(errno));

Changes to the 2 cJSON_AddStringToObject():

	sprintf(str, "%s ", ctime(&now));
	va_start(argp, format);
	vsnprintf(&str[strlen(str)], sizeof(str)*-strlen(str), format, argp);
	......