Linux,UDP数据报和内核时间戳:以后有很多示例和stackoversflow条目,但仍然根本无法获得时间戳

Tim*_*ler 5 c sockets linux timestamp udp

我一直在尝试并未能使Linux(内核4.1.4)为我提供发送和接收UDP数据报的时间戳。我已经阅读了原始的内核文档(https://www.kernel.org/doc/Documentation/networking/timestamping.txt),以及许多示例和许多stackoverflow条目。我可以在发送方和接收方之间毫无问题地发送数据报。但是我无法获得发送或接收数据报的时间戳,也无法弄清楚自己在做什么错。

一件奇怪的事情是,当我使用MSG_ERRQUEUE通道获取已发送数据报上的时间戳信息时,我确实获得了原始传出数据包,并且得到了第一条辅助消息(SOL_IP,IP_RECVERR),但是没有得到第二条消息(应为SOL_SOCKET级别,键入SCM_TIMESTAMPING)。

在另一个关于获取已发送数据包的时间戳记Timestamp传出数据包)的stackoverflow条目中,有人提到某些驱动程序可能未实现对的调用skb_tx_timestamp,但我检查了我的(Realtek),并且该调用肯定在其中。

这是我设置UDP接收器的方式(未显示错误处理代码):

inf->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);

timestampOn = SOF_TIMESTAMPING_RX_SOFTWARE | SOF_TIMESTAMPING_RX_HARDWARE;
r = setsockopt(inf->fd, SOL_SOCKET, SO_TIMESTAMPING, &timestampOn, sizeof(timestampOn));

r = setsockopt(inf->fd, SOL_SOCKET, SO_REUSEPORT, &on, sizeof(on));

memset(&(inf->local), 0, sizeof(struct sockaddr_in));
inf->local.sin_family = AF_INET;
inf->local.sin_port = htons(port);
inf->local.sin_addr.s_addr = htonl(INADDR_ANY);

r = bind(inf->fd, (struct sockaddr *)&(inf->local), sizeof(struct sockaddr_in));
Run Code Online (Sandbox Code Playgroud)

是否使用SO_REUSEPORT似乎无关紧要。

对于接收,我的理解是我们不使用MSG_ERRQUEUE。仅当我们需要已发送消息的时间戳时。此外,当我将MSG_ERRQUEUE与recvmsg一起使用时,会得到“资源暂时不可用”。这是我接收数据报的方式:

int recv_len;
struct msghdr   msg;
struct iovec    iov;

memset(&msg, 0, sizeof(msg));
memset(&iov, 0, sizeof(iov));

// Space for control message info plus timestamp
char ctrl[2048];
memset(ctrl, 0, sizeof(ctrl));
//struct cmsghdr *cmsg = (struct cmsghdr *) &ctrl;

// Ancillary data buffer and length
msg.msg_control      = (char *) ctrl;
msg.msg_controllen   = sizeof(ctrl);

// Dest address info
msg.msg_name         = (struct sockaddr *) &(inf->remote);
msg.msg_namelen      = sizeof(struct sockaddr_in);

// Array of data buffers (scatter/gather)
msg.msg_iov          = &iov;
msg.msg_iovlen       = 1;

// Data buffer pointer and length
iov.iov_base         = buf;
iov.iov_len          = len;

recv_len = recvmsg(inf->fd, &msg, 0);
Run Code Online (Sandbox Code Playgroud)

然后,我将指向msg的指针传递给handle_time执行此操作的另一个函数():

struct timespec* ts = NULL;
struct cmsghdr* cmsg;
struct sock_extended_err *ext;

for( cmsg = CMSG_FIRSTHDR(msg); cmsg; cmsg = CMSG_NXTHDR(msg,cmsg) ) {
    printf("level=%d, type=%d, len=%zu\n", cmsg->cmsg_level, cmsg->cmsg_type, cmsg->cmsg_len);
}
Run Code Online (Sandbox Code Playgroud)

收到零消息。 所以这是第一个问题。我上面的设置代码与我在网上找到的其他六个示例相匹配,但是我没有从中获得任何辅助数据。

接下来,让我们转向发送数据报。设置如下:

inf->port = port;
inf->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);

memset(&(inf->remote), 0, sizeof(struct sockaddr_in));
inf->remote.sin_family = AF_INET;
inf->remote.sin_port = htons(port);

timestampOn = SOF_TIMESTAMPING_TX_SOFTWARE | SOF_TIMESTAMPING_TX_HARDWARE;
r = setsockopt(inf->fd, SOL_SOCKET, SO_TIMESTAMPING, &timestampOn, sizeof(timestampOn));

on = 1;
r = setsockopt(inf->fd, SOL_SOCKET, SO_BROADCAST, &on, sizeof(on));

r = inet_aton(address, &(inf->remote.sin_addr));
Run Code Online (Sandbox Code Playgroud)

这就是我发送数据报的方式:

int send_len, r, i;
struct msghdr   msg;
struct iovec    iov;

memset(&msg, 0, sizeof(msg));
memset(&iov, 0, sizeof(iov));

// Space for control message info plus timestamp
char ctrl[2048];
memset(ctrl, 0, sizeof(ctrl));
//struct cmsghdr *cmsg = (struct cmsghdr *) &ctrl;

// Ancillary data buffer and length
//msg.msg_control      = (char *) ctrl;
//msg.msg_controllen   = sizeof(ctrl);    

// Dest address info
msg.msg_name         = (struct sockaddr *) &(inf->remote);
msg.msg_namelen      = sizeof(struct sockaddr_in);

// Array of data buffers (scatter/gather)
msg.msg_iov          = &iov;
msg.msg_iovlen       = 1;

// Data buffer pointer and length
iov.iov_base         = buf;
iov.iov_len          = len;

send_len = sendmsg(inf->fd, &msg, 0);
Run Code Online (Sandbox Code Playgroud)

我已经看到了重用msg和iov数据结构的示例,但是在我的实验中,我添加了代码以确保已清除所有内容,以防万一send留下了任何东西,尽管这没有任何区别。这是获取时间戳的代码:

memset(&msg, 0, sizeof(msg));
memset(&iov, 0, sizeof(iov));
memset(ctrl, 0, sizeof(ctrl));
msg.msg_control      = (char *) ctrl;
msg.msg_controllen   = sizeof(ctrl);
msg.msg_name         = (struct sockaddr *) &(inf->remote);
msg.msg_namelen      = sizeof(struct sockaddr_in);
msg.msg_iov          = &iov;
msg.msg_iovlen       = 1;
iov.iov_base         = junk_buf;
iov.iov_len          = sizeof(junk_buf);

for (;;) {
    r = recvmsg(inf->fd, &msg, MSG_ERRQUEUE);
    if (r<0) {
        fprintf(stderr, "Didn't get kernel time\n");
        return send_len;
    }

    printf("recvmsg returned %d\n", r);
    handle_time(&msg);
}
Run Code Online (Sandbox Code Playgroud)

数据缓冲区包含预期的原始数据报。我得到的辅助数据仅包含一条消息,handle_time的输出为:

level=0, type=11, len=48
Run Code Online (Sandbox Code Playgroud)

这是SOL_IP级别,类型为IP_RECVERR,根据文档要求。查看有效负载(结构sock_extended_err),错误号为42(ENOMSG,没有所需类型的消息),来源为4(SO_EE_ORIGIN_TXSTATUS)。从文档来看,这是应该发生的,并表明实际上我确实设法通知内核我想要TX状态消息。但是没有第二条辅助信息!

我尝试查看是否有任何内核编译选项可能会禁用此功能,但我没有找到任何选项。所以我对此完全感到困惑。谁能帮我弄清楚我在做什么错?

谢谢!

更新: 我尝试在另一台Linux机器上运行相同的代码,这次是CentOS 7(内核3.10.0-693.2.2.el7.x86_64)。我无法弄清楚该计算机具有哪种类型的NIC,但是当我尝试发送数据报时,会出现一些其他奇怪的行为。对于第一个数据报,当我启动该程序时,我将获得消息和一条辅助消息,就像上面一样。对于每个后续sendmsg调用,errno告诉我,我收到“无效参数”错误。如果我没有在套接字上启用时间戳,此错误将消失。

更新2: 我发现我并没有进行必要的ioctl来启用驱动程序中的时间戳。不幸的是,当我进行此调用时,我从errno(没有此类设备)获得ENODEV。这是我尝试执行的操作(我从https://github.com/majek/openonload/blob/master/src/tests/onload/hwtimestamping/tx_timestamping.c模仿):

struct ifreq ifr;
struct hwtstamp_config hwc;

inf->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);

memset(&ifr, 0, sizeof(ifr));
hwc.flags = 0;
hwc.tx_type = HWTSTAMP_TX_ON;
hwc.rx_filter = HWTSTAMP_FILTER_ALL;
ifr.ifr_data = (char*)&hwc;
r = ioctl(inf->fd, SIOCSHWTSTAMP, &ifr);
Run Code Online (Sandbox Code Playgroud)

话虽这么说,我对软件时间戳比较满意,不需要该调用。所以我不确定这是否有帮助。

更新3: 请求一个可编译的示例。整个程序非常简单,因此我将其放在以下的pastebin中:https : //pastebin.com/qd0gspRc

另外,这是ethtool的输出:

Time stamping parameters for eth0:
Capabilities:
        software-transmit     (SOF_TIMESTAMPING_TX_SOFTWARE)
        software-receive      (SOF_TIMESTAMPING_RX_SOFTWARE)
        software-system-clock (SOF_TIMESTAMPING_SOFTWARE)
PTP Hardware Clock: none
Hardware Transmit Timestamp Modes: none
Hardware Receive Filter Modes: none
Run Code Online (Sandbox Code Playgroud)

由于这显然不支持硬件时间戳,因此ioctl毫无意义。我尝试将发送方和接收方的SO_TIMESTAMPING设置更改为SOF_TIMESTAMPING_TX_SOFTWARE和SOF_TIMESTAMPING_RX_SOFTWARE。那没有帮助。

然后,我尝试将SOF_TIMESTAMPING_SOFTWARE添加到两者中。我终于开始得到一些东西:

level=1, type=37, len=64
Run Code Online (Sandbox Code Playgroud)

级别1是SOL_SOCKET,类型37是SCM_TIMESTAMPING。我将回到文档,并弄清楚如何解释这一点。它说了有关传递三个时间结构的数组的内容。驾驶员skb_tx_timestamp对它的调用应该已经足够,这样就不需要我启用“伪”软件时间戳来获取信息。

Sta*_*eur 5

就像我在评论中所说的使用SOF_TIMESTAMPING_SOFTWAREandSOF_TIMESTAMPING_RAW_HARDWARE是必要的,因为如果我正确理解文档,有些位将生成时间戳,有些位在这里用于在控制消息中报告它们:

1.3.1 时间戳生成

一些位是对堆栈的请求,以尝试生成时间戳。它们的任何组合都是有效的。对这些位的更改适用于新创建的数据包,而不适用于堆栈中已有的数据包。因此,可以通过send()在两个setsockopt 调用中嵌入一​​个调用来选择性地请求数据包子集的时间戳(例如,用于采样),一个是启用时间戳生成,另一个是禁用它。时间戳也可能是由于特定套接字请求之外的原因而生成的,例如在系统范围内启用接收时间戳时,如前所述。

1.3.2 时间戳报告

其他三位控制将在生成的控制消息中报告哪些时间戳。对位的更改在堆栈中的时间戳报告位置立即生效。仅针对也具有相关时间戳生成请求集的数据包报告时间戳。

之后,使用数据文档说:

2.1SCM_TIMESTAMPING记录

这些时间戳在带有 cmsg_level SOL_SOCKET、 cmsg_typeSCM_TIMESTAMPING和有效载荷类型的控制消息中返回

struct scm_timestamping { struct timespec ts[3]; };

...

该结构最多可以返回三个时间戳。这是一个遗留功能。任何时候至少有一个字段是非零的。大多数时间戳都传入ts[0]. 硬件时间戳被传入ts[2]

要获得传输时间戳,这需要一些配置,首先您需要知道软件时间戳并不总是可用的,我只实现了获取硬件传输时间戳。但我不是这些领域的专家,我只是尝试使用我发现的信息来实现时间戳。

其次,我需要使用linuxptp 工具激活硬件功能,我使用hwstamp_cli

hwstamp_ctl -i eth0 -r 1 -t 1
Run Code Online (Sandbox Code Playgroud)

通过这个和对你的代码的一些修改,我实现了硬件传输时间戳,但只能使用 ethX 接口,因为 lo 接口没有这些功能 AFAIK 所以最终代码是:

#include <arpa/inet.h>
#include <errno.h>
#include <inttypes.h>
#include <linux/errqueue.h>
#include <linux/net_tstamp.h>
#include <linux/sockios.h>
#include <net/if.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/ioctl.h>
#include <sys/socket.h>
#include <sys/time.h>
#include <sys/types.h>
#include <unistd.h>

#define UDP_MAX_LENGTH 1500

typedef struct {
  int fd;
  int port;
  int err_no;
  struct sockaddr_in local;
  struct sockaddr_in remote;
  struct timeval time_kernel;
  struct timeval time_user;
  int64_t prev_serialnum;
} socket_info;

static int setup_udp_receiver(socket_info *inf, int port) {
  inf->port = port;
  inf->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
  if (inf->fd < 0) {
    inf->err_no = errno;
    fprintf(stderr, "setup_udp_server: socket failed: %s\n",
            strerror(inf->err_no));
    return inf->fd;
  }

  int timestampOn =
      SOF_TIMESTAMPING_RX_SOFTWARE | SOF_TIMESTAMPING_TX_SOFTWARE |
      SOF_TIMESTAMPING_SOFTWARE | SOF_TIMESTAMPING_RX_HARDWARE |
      SOF_TIMESTAMPING_TX_HARDWARE | SOF_TIMESTAMPING_RAW_HARDWARE |
      // SOF_TIMESTAMPING_OPT_TSONLY |
      0;
  int r = setsockopt(inf->fd, SOL_SOCKET, SO_TIMESTAMPING, &timestampOn,
                     sizeof timestampOn);
  if (r < 0) {
    inf->err_no = errno;
    fprintf(stderr, "setup_udp_server: setsockopt failed: %s\n",
            strerror(inf->err_no));
    return r;
  }

  int on = 1;
  r = setsockopt(inf->fd, SOL_SOCKET, SO_REUSEPORT, &on, sizeof on);
  if (r < 0) {
    inf->err_no = errno;
    fprintf(stderr, "setup_udp_server: setsockopt2 failed: %s\n",
            strerror(inf->err_no));
    return r;
  }

  inf->local = (struct sockaddr_in){.sin_family = AF_INET,
                                    .sin_port = htons((uint16_t)port),
                                    .sin_addr.s_addr = htonl(INADDR_ANY)};
  r = bind(inf->fd, (struct sockaddr *)&inf->local, sizeof inf->local);
  if (r < 0) {
    inf->err_no = errno;
    fprintf(stderr, "setup_udp_server: bind failed: %s\n",
            strerror(inf->err_no));
    return r;
  }

  inf->prev_serialnum = -1;

  return 0;
}

static int setup_udp_sender(socket_info *inf, int port, char *address) {
  inf->port = port;
  inf->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
  if (inf->fd < 0) {
    inf->err_no = errno;
    fprintf(stderr, "setup_udp_client: socket failed: %s\n",
            strerror(inf->err_no));
    return inf->fd;
  }

  int timestampOn =
      SOF_TIMESTAMPING_RX_SOFTWARE | SOF_TIMESTAMPING_TX_SOFTWARE |
      SOF_TIMESTAMPING_SOFTWARE | SOF_TIMESTAMPING_RX_HARDWARE |
      SOF_TIMESTAMPING_TX_HARDWARE | SOF_TIMESTAMPING_RAW_HARDWARE |
      // SOF_TIMESTAMPING_OPT_TSONLY |
      0;
  int r = setsockopt(inf->fd, SOL_SOCKET, SO_TIMESTAMPING, &timestampOn,
                     sizeof timestampOn);
  if (r < 0) {
    inf->err_no = errno;
    fprintf(stderr, "setup_udp_server: setsockopt failed: %s\n",
            strerror(inf->err_no));
    return r;
  }

  inf->remote = (struct sockaddr_in){.sin_family = AF_INET,
                                     .sin_port = htons((uint16_t)port)};
  r = inet_aton(address, &inf->remote.sin_addr);
  if (r == 0) {
    fprintf(stderr, "setup_udp_client: inet_aton failed\n");
    inf->err_no = 0;
    return -1;
  }

  inf->local = (struct sockaddr_in){.sin_family = AF_INET,
                                    .sin_port = htons(0),
                                    .sin_addr.s_addr = htonl(INADDR_ANY)};
  inf->prev_serialnum = -1;

  return 0;
}

static void handle_scm_timestamping(struct scm_timestamping *ts) {
  for (size_t i = 0; i < sizeof ts->ts / sizeof *ts->ts; i++) {
    printf("timestamp: %lld.%.9lds\n", (long long)ts->ts[i].tv_sec,
           ts->ts[i].tv_nsec);
  }
}

static void handle_time(struct msghdr *msg) {

  for (struct cmsghdr *cmsg = CMSG_FIRSTHDR(msg); cmsg;
       cmsg = CMSG_NXTHDR(msg, cmsg)) {
    printf("level=%d, type=%d, len=%zu\n", cmsg->cmsg_level, cmsg->cmsg_type,
           cmsg->cmsg_len);

    if (cmsg->cmsg_level == SOL_IP && cmsg->cmsg_type == IP_RECVERR) {
      struct sock_extended_err *ext =
          (struct sock_extended_err *)CMSG_DATA(cmsg);
      printf("errno=%d, origin=%d\n", ext->ee_errno, ext->ee_origin);
      continue;
    }

    if (cmsg->cmsg_level != SOL_SOCKET)
      continue;

    switch (cmsg->cmsg_type) {
    case SO_TIMESTAMPNS: {
      struct scm_timestamping *ts = (struct scm_timestamping *)CMSG_DATA(cmsg);
      handle_scm_timestamping(ts);
    } break;
    case SO_TIMESTAMPING: {
      struct scm_timestamping *ts = (struct scm_timestamping *)CMSG_DATA(cmsg);
      handle_scm_timestamping(ts);
    } break;
    default:
      /* Ignore other cmsg options */
      break;
    }
  }
  printf("End messages\n");
}

static ssize_t udp_receive(socket_info *inf, char *buf, size_t len) {
  char ctrl[2048];
  struct iovec iov = (struct iovec){.iov_base = buf, .iov_len = len};
  struct msghdr msg = (struct msghdr){.msg_control = ctrl,
                                      .msg_controllen = sizeof ctrl,
                                      .msg_name = &inf->remote,
                                      .msg_namelen = sizeof inf->remote,
                                      .msg_iov = &iov,
                                      .msg_iovlen = 1};
  ssize_t recv_len = recvmsg(inf->fd, &msg, 0);
  gettimeofday(&inf->time_user, NULL);

  if (recv_len < 0) {
    inf->err_no = errno;
    fprintf(stderr, "udp_receive: recvfrom failed: %s\n",
            strerror(inf->err_no));
  }

  handle_time(&msg);

  return recv_len;
}

static ssize_t udp_send(socket_info *inf, char *buf, size_t len) {
  struct iovec iov = (struct iovec){.iov_base = buf, .iov_len = len};
  struct msghdr msg = (struct msghdr){.msg_name = &inf->remote,
                                      .msg_namelen = sizeof inf->remote,
                                      .msg_iov = &iov,
                                      .msg_iovlen = 1};
  gettimeofday(&inf->time_user, NULL);
  ssize_t send_len = sendmsg(inf->fd, &msg, 0);
  if (send_len < 0) {
    inf->err_no = errno;
    fprintf(stderr, "udp_send: sendmsg failed: %s\n", strerror(inf->err_no));
  }

  return send_len;
}

static ssize_t meq_receive(socket_info *inf, char *buf, size_t len) {
  struct iovec iov = (struct iovec){.iov_base = buf, .iov_len = len};
  char ctrl[2048];
  struct msghdr msg = (struct msghdr){.msg_control = ctrl,
                                      .msg_controllen = sizeof ctrl,
                                      .msg_name = &inf->remote,
                                      .msg_namelen = sizeof inf->remote,
                                      .msg_iov = &iov,
                                      .msg_iovlen = 1};
  ssize_t recv_len = recvmsg(inf->fd, &msg, MSG_ERRQUEUE);
  if (recv_len < 0) {
    inf->err_no = errno;
    if (errno != EAGAIN) {
      fprintf(stderr, "meq_receive: recvmsg failed: %s\n",
              strerror(inf->err_no));
    }
    return recv_len;
  }
  handle_time(&msg);

  return recv_len;
}

typedef struct {
  int64_t serialnum;

  int64_t user_time_serialnum;
  int64_t user_time;

  int64_t kernel_time_serialnum;
  int64_t kernel_time;

  size_t message_bytes;
} message_header;

static const size_t payload_max = UDP_MAX_LENGTH - sizeof(message_header);

static ssize_t generate_random_message(socket_info *inf, char *buf,
                                       size_t len) {
  if (len < sizeof(message_header)) {
    return -1;
  }
  message_header *header = (message_header *)buf;
  char *payload = (char *)(header + 1);
  size_t payload_len = (size_t)random() % (payload_max + 1);
  if (payload_len > len - sizeof(message_header)) {
    payload_len = len - sizeof(message_header);
  }
  for (size_t i = 0; i < payload_len; i++) {
    payload[i] = (char)random();
  }

  static int64_t serial_num = 0;
  *header = (message_header){
      .user_time_serialnum = inf->prev_serialnum,
      .user_time = inf->time_user.tv_sec * 1000000000L + inf->time_user.tv_usec,
      .kernel_time_serialnum = inf->prev_serialnum,
      .kernel_time =
          inf->time_kernel.tv_sec * 1000000000L + inf->time_kernel.tv_usec,
      .serialnum = serial_num,
      .message_bytes = payload_len};
  size_t total = payload_len + sizeof *header;

  printf("uts%5" PRId64 ": kt=%" PRId64 ", ut=%" PRId64 ", sn=%" PRId64
         ": s=%zu\n",
         header->user_time_serialnum, header->kernel_time, header->user_time,
         header->serialnum, total);

  inf->prev_serialnum = serial_num++;

  return (ssize_t)total;
}

static void sender_loop(char *host) {
  socket_info inf;
  int ret = setup_udp_sender(&inf, 8000, host);
  if (ret < 0) {
    return;
  }

  for (int i = 0; i < 2000; i++) {
    useconds_t t = random() % 2000000;
    usleep(t);
    char packet_buffer[4096];
    ssize_t len =
        generate_random_message(&inf, packet_buffer, sizeof packet_buffer);
    if (len < 0) {
      return;
    }
    udp_send(&inf, packet_buffer, (size_t)len);
    while (meq_receive(&inf, packet_buffer, sizeof packet_buffer) != -1) {
    }
  }
}

static void receiver_loop(void) {
  socket_info inf;
  int ret = setup_udp_receiver(&inf, 8000);
  if (ret < 0) {
    return;
  }

  for (int i = 0; i < 1000; i++) {
    char packet_buffer[4096];
    udp_receive(&inf, packet_buffer, sizeof packet_buffer);
  }
}

#define USAGE "Usage: %s [-r | -s host]\n"

int main(int argc, char *argv[]) {
  if (argc < 2) {
    fprintf(stderr, USAGE, argv[0]);
    return 0;
  }

  if (0 == strcmp(argv[1], "-s")) {
    if (argc < 3) {
      fprintf(stderr, USAGE, argv[0]);
      return 0;
    }
    sender_loop(argv[2]);
  } else if (0 == strcmp(argv[1], "-r")) {
    receiver_loop();
  } else {
    fprintf(stderr, USAGE, argv[0]);
  }
}
Run Code Online (Sandbox Code Playgroud)

示例输出:

$ ./a.out -r
level=1, type=37, len=64
timestamp: 1511196758.087209387s
timestamp: 0.000000000s
timestamp: 0.000000000s
End messages
level=1, type=37, len=64
timestamp: 1511196759.333507671s
timestamp: 0.000000000s
timestamp: 0.000000000s
End messages
$ ./a.out -s "8.8.8.8"
uts   -1: kt=238059712, ut=140918979990070, sn=0: s=482
uts    0: kt=238059712, ut=1511197522000237457, sn=1: s=132
level=1, type=37, len=64
timestamp: 0.000000000s
timestamp: 0.000000000s
timestamp: 1511197359.637050597s
level=0, type=11, len=48
errno=42, origin=4
End messages
uts    1: kt=238059712, ut=1511197523000483805, sn=2: s=1454
level=1, type=37, len=64
timestamp: 0.000000000s
timestamp: 0.000000000s
timestamp: 1511197360.883295397s
level=0, type=11, len=48
errno=42, origin=4
End messages
Run Code Online (Sandbox Code Playgroud)

现场测试:发送方接收方