Trouble Getting Timestamps in vma_recv_callback
mikeb01 opened this issue · 3 comments
mikeb01 commented
Trouble Getting Timestamps in vma_recv_callback
Issue type
- Bug report
- Feature request
Configuration:
- CX512A
- Linux plinth 5.11.0-44-generic ~20.04.2-Ubuntu SMP Tue Dec 14 15:36:44 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
- MLNX_OFED_LINUX-5.5-1.0.3.2
- AMD Ryzen Threadripper 3960X 24-Core Processor
Actual behavior:
Hardware timestamps in vma_recv_callback don't appear to report correct values. Running the attached code and sending a packet through once per second the timestamp doesn't appear to move forward as expected:
$ sudo setcap cap_net_raw+eip a.out
$ ./a.out 192.168.88.10 9999
VMA INFO: ---------------------------------------------------------------------------
VMA INFO: VMA_VERSION: 9.4.0-1 Release built on Oct 5 2021 11:18:30
VMA INFO: Cmd Line: ./a.out 192.168.88.10 9999
VMA INFO: OFED Version: MLNX_OFED_LINUX-5.5-1.0.3.2:
VMA INFO: ---------------------------------------------------------------------------
VMA INFO: Log Level INFO [VMA_TRACELEVEL]
VMA INFO: ---------------------------------------------------------------------------
140725551717760 139795563478062
[0] Received data: 4
94260213317881 140725551717456
[1] Received data: 4
94260213317881 140725551717456
[2] Received data: 4
94260213317881 140725551717456
[3] Received data: 4
94260213317881 140725551717456
[4] Received data: 4
94260213317881 140725551717456
[5] Received data: 4
94260213317881 140725551717456
[6] Received data: 4
Expected behavior:
That the timestamp would move forward.
Steps to reproduce:
Compile and run the attached code:
gcc vma_timestamping.c -l dl
#if defined(__linux__)
#define _GNU_SOURCE
#endif
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <errno.h>
#include <sys/socket.h>
#include <sys/epoll.h>
#include <netinet/in.h>
#include <arpa/inet.h>
#include <linux/net_tstamp.h>
#include <mellanox/vma_extra.h>
#include <dlfcn.h>
static void *lib_handle = NULL;
static struct vma_api_t *vma_api = NULL;
static int (*vma_socket)(int domain, int type, int protocol);
static int (*vma_bind)(int sockfd, const struct sockaddr *addr, socklen_t addrlen);
static int (*vma_getsockopt)(int sockfd, int level, int optname, void *optval, socklen_t *optlen);
static int (*vma_setsockopt)(int sockfd, int level, int optname, const void *optval, socklen_t optlen);
#define VMA_BINDINGS_SET_FUNC(handle, func) \
do \
{ \
const char *func_name = #func; \
if ((*(void **)(&vma_##func) = dlsym(handle, func_name)) == NULL) \
{ \
fprintf(stderr, "failed to dlsym(\"libvma.so\", \"%s\")\n", func_name); \
return -1; \
} \
} \
while (0)
static inline struct vma_api_t* _vma_get_api()
{
struct vma_api_t *api_ptr = NULL;
socklen_t len = sizeof(api_ptr);
int err = vma_getsockopt(-1, SOL_SOCKET, SO_VMA_GET_API, &api_ptr, &len);
if (err < 0) {
return NULL;
}
return api_ptr;
}
int _init_vma_pointers()
{
if (NULL != lib_handle)
{
return 0;
}
lib_handle = dlopen("libvma.so", RTLD_LAZY | RTLD_GLOBAL);
if (NULL == lib_handle)
{
fprintf(stderr, "Unable to load lib_handle\n");
return -1;
}
VMA_BINDINGS_SET_FUNC(lib_handle, socket);
VMA_BINDINGS_SET_FUNC(lib_handle, bind);
VMA_BINDINGS_SET_FUNC(lib_handle, getsockopt);
VMA_BINDINGS_SET_FUNC(lib_handle, setsockopt);
vma_api = _vma_get_api();
if (NULL == vma_api)
{
fprintf(stderr, "%s\n", "failed to get vma_api");
return -1;
}
return 0;
}
vma_recv_callback_retval_t aeron_vma_bindings_recv_callback(
int fd,
size_t sz_iov,
struct iovec iov[],
struct vma_info_t *vma_info,
void *context)
{
printf("%ld %ld\n", vma_info->hw_timestamp.tv_sec, vma_info->hw_timestamp.tv_nsec);
return VMA_PACKET_RECV;
}
int bind_new_socket(struct sockaddr_in *addr)
{
int fd = vma_socket(AF_INET, SOCK_DGRAM, IPPROTO_IP);
vma_api->register_recv_callback(fd, aeron_vma_bindings_recv_callback, NULL);
int rc = -1;
uint32_t enable_timestamp = 1;
if (vma_setsockopt(fd, SOL_SOCKET, SO_TIMESTAMPNS, &enable_timestamp, sizeof(enable_timestamp)) < 0)
{
printf("%s", "setsockopt(SO_TIMESTAMPNS)");
return -1;
}
uint32_t timestamp_flags = SOF_TIMESTAMPING_RX_HARDWARE;
if (setsockopt(fd, SOL_SOCKET, SO_TIMESTAMPING, ×tamp_flags, sizeof(timestamp_flags)) < 0)
{
printf("%s", "setsockopt(SO_TIMESTAMPING)");
return -1;
}
rc = vma_bind(fd, (struct sockaddr *)addr, sizeof(*addr));
if (rc < 0)
{
fprintf(stderr, "bind() failed %d : %s\n", errno, strerror(errno));
return -1;
}
return fd;
}
int main(int argc, char**argv)
{
_init_vma_pointers();
int rc = 0;
int fd = -1;
struct sockaddr_in addr = { 0 };
char *straddr = (argc > 1 ? argv[1] : NULL);
char *strport = (argc > 2 ? argv[2] : NULL);
int i = 0;
if (!straddr || !strport)
{
printf("Wrong options\n");
exit(1);
}
addr.sin_family = AF_INET;
addr.sin_addr.s_addr = inet_addr(straddr);
addr.sin_port = htons(atoi(strport));
fd = bind_new_socket(&addr);
if (fd < 0)
{
exit(1);
}
uint8_t buf[1024];
int flags = 0;
struct sockaddr_storage addr_out = { 0 };
socklen_t socklen = 0;
while (0 == rc)
{
/* Polling any RX events / data */
rc = vma_api->recvfrom_zcopy(fd, (void *)buf, 1024, &flags, (struct sockaddr*)&addr_out, &socklen);
if (rc > 0)
{
printf("[%d] Received data: %d\n", i++, rc);
rc = 0;
}
}
close(fd);
fprintf(stderr, "socket closed\n");
return 0;
}
igor-ivanov commented
Hi @mikeb01,
Thank you for detailed information. I am able to reproduce and will pass to debug.
igor-ivanov commented
I see few issues in your solution:
- use
if (vma_setsockopt(fd, SOL_SOCKET, SO_TIMESTAMPING, ×tamp_flags, sizeof(timestamp_flags)) < 0) - should be
uint32_t timestamp_flags = SOF_TIMESTAMPING_RAW_HARDWARE | SOF_TIMESTAMPING_RX_HARDWARE;
One note:
vma_recv_callback can be used with standard recvfrom() too.
I see following output after changes above:
1644584782 269462186
[0] Received data: 14
1644584783 269428906
[1] Received data: 14
1644584784 269430583
[2] Received data: 14
1644584785 269433651
[3] Received data: 14
1644584786 269439744
[4] Received data: 14
1644584787 269439961
[5] Received data: 14
1644584788 269443763
mikeb01 commented
I can confirm that this works, thank you.