diff options
| -rw-r--r-- | src/vcl/ldp.c | 420 | ||||
| -rw-r--r-- | src/vcl/vppcom.c | 45 |
2 files changed, 129 insertions, 336 deletions
diff --git a/src/vcl/ldp.c b/src/vcl/ldp.c index c3dc64a4d3b..d538770eadb 100644 --- a/src/vcl/ldp.c +++ b/src/vcl/ldp.c @@ -112,7 +112,7 @@ typedef struct #define LDBG(_lvl, _fmt, _args...) \ if (ldp->debug > _lvl) \ - clib_warning (_fmt, ##_args) + clib_warning ("ldp<%d>: " _fmt, getpid(), ##_args) static ldp_main_t ldp_main = { .sid_bit_val = (1 << LDP_SID_BIT_MIN), @@ -261,9 +261,8 @@ ldp_init (void) ldp->vcl_needs_real_epoll = 0; if (rv == VPPCOM_EEXIST) return 0; - LDBG (2, "\nLDP<%d>: ERROR: ldp_init: vppcom_app_create()" - " failed! rv = %d (%s)\n", - getpid (), rv, vppcom_retval_str (rv)); + LDBG (2, "\nERROR: ldp_init: vppcom_app_create()" + " failed! rv = %d (%s)\n", rv, vppcom_retval_str (rv)); ldp->init = 0; return rv; } @@ -282,8 +281,8 @@ ldp_init (void) else { ldp->debug = tmp; - LDBG (0, "LDP<%d>: configured LDP debug level (%u) from env var " - LDP_ENV_DEBUG "!", getpid (), ldp->debug); + LDBG (0, "configured LDP debug level (%u) from env var " + LDP_ENV_DEBUG "!", ldp->debug); } } @@ -291,8 +290,8 @@ ldp_init (void) if (env_var_str) { ldp_set_app_name (env_var_str); - LDBG (0, "LDP<%d>: configured LDP app name (%s) from the env var " - LDP_ENV_APP_NAME "!", getpid (), ldp->app_name); + LDBG (0, "configured LDP app name (%s) from the env var " + LDP_ENV_APP_NAME "!", ldp->app_name); } env_var_str = getenv (LDP_ENV_SID_BIT); @@ -333,15 +332,15 @@ ldp_init (void) ldp->sid_bit_val = (1 << sb); ldp->sid_bit_mask = ldp->sid_bit_val - 1; - LDBG (0, "LDP<%d>: configured LDP sid bit (%u) from " - LDP_ENV_SID_BIT "! sid bit value %d (0x%x)", getpid (), sb, + LDBG (0, "configured LDP sid bit (%u) from " + LDP_ENV_SID_BIT "! sid bit value %d (0x%x)", sb, ldp->sid_bit_val, ldp->sid_bit_val); } } clib_time_init (&ldpw->clib_time); clib_rwlock_init (&ldp->fd_table_lock); - LDBG (0, "LDP<%d>: LDP initialization: done!", getpid ()); + LDBG (0, "LDP initialization: done!"); return 0; } @@ -350,7 +349,6 @@ int close (int fd) { int rv, refcnt; - const char *func_str; u32 sid = ldp_sid_from_fd (fd); if ((errno = -ldp_init ())) @@ -360,14 +358,11 @@ close (int fd) { int epfd; - func_str = "vppcom_session_attr[GET_LIBC_EPFD]"; epfd = vppcom_session_attr (sid, VPPCOM_ATTR_GET_LIBC_EPFD, 0, 0); if (epfd > 0) { - func_str = "libc_close"; - - LDBG (0, "LDP<%d>: fd %d (0x%x): calling %s(): epfd %u (0x%x)", - getpid (), fd, fd, func_str, epfd, epfd); + LDBG (0, "fd %d (0x%x): calling libc_close: epfd %u (0x%x)", + fd, fd, epfd, epfd); rv = libc_close (epfd); if (rv < 0) @@ -386,10 +381,8 @@ close (int fd) goto done; } - func_str = "vppcom_session_close"; - - LDBG (0, "LDP<%d>: fd %d (0x%x): calling %s(): sid %u (0x%x)", - getpid (), fd, fd, func_str, sid, sid); + LDBG (0, "fd %d (0x%x): calling vppcom_session_close: sid %u (0x%x)", + fd, fd, sid, sid); refcnt = vppcom_session_attr (sid, VPPCOM_ATTR_GET_REFCNT, 0, 0); rv = vppcom_session_close (sid); @@ -403,30 +396,13 @@ close (int fd) } else { - func_str = "libc_close"; - - LDBG (0, "LDP<%d>: fd %d (0x%x): calling %s()", getpid (), fd, fd, - func_str); - + LDBG (0, "fd %d (0x%x): calling libc_close", fd, fd); rv = libc_close (fd); } done: - if (LDP_DEBUG > 0) - { - if (rv < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), fd, fd, - func_str, rv, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: fd %d (0x%x): returning %d (0x%x)", - getpid (), fd, fd, rv, rv); - } + + LDBG (1, "fd %d (0x%x): returning %d (0x%x)", fd, fd, rv, rv); return rv; } @@ -434,7 +410,6 @@ ssize_t read (int fd, void *buf, size_t nbytes) { ssize_t size; - const char *func_str; u32 sid = ldp_sid_from_fd (fd); if ((errno = -ldp_init ())) @@ -442,12 +417,8 @@ read (int fd, void *buf, size_t nbytes) if (sid != INVALID_SESSION_ID) { - func_str = "vppcom_session_read"; - - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): " - "sid %u (0x%x), buf %p, nbytes %u", getpid (), - fd, fd, func_str, sid, sid, buf, nbytes); + LDBG (2, "fd %d (0x%x): calling vppcom_session_read(): sid %u (0x%x)," + " buf %p, nbytes %u", fd, fd, sid, sid, buf, nbytes); size = vppcom_session_read (sid, buf, nbytes); if (size < 0) @@ -458,38 +429,19 @@ read (int fd, void *buf, size_t nbytes) } else { - func_str = "libc_read"; - - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): " - "buf %p, nbytes %u", getpid (), - fd, fd, func_str, buf, nbytes); + LDBG (2, "fd %d (0x%x): calling libc_read(): buf %p, nbytes %u", + fd, fd, buf, nbytes); size = libc_read (fd, buf, nbytes); } - if (LDP_DEBUG > 2) - { - if (size < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), fd, fd, - func_str, size, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: fd %d (0x%x): returning %d (0x%x)", - getpid (), fd, fd, size, size); - } + LDBG (2, "fd %d (0x%x): returning %d (0x%x)", fd, fd, size, size); return size; } ssize_t readv (int fd, const struct iovec * iov, int iovcnt) { - const char *func_str; ssize_t size = 0; u32 sid = ldp_sid_from_fd (fd); int rv = 0, i, total = 0; @@ -499,16 +451,13 @@ readv (int fd, const struct iovec * iov, int iovcnt) if (sid != INVALID_SESSION_ID) { - func_str = "vppcom_session_read"; do { for (i = 0; i < iovcnt; ++i) { - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s() [%d]: " - "sid %u (0x%x), iov %p, iovcnt %d, total %d", - getpid (), fd, fd, func_str, i, sid, sid, - iov, iovcnt, total); + LDBG (2, "fd %d (0x%x): calling vppcom_session_read() [%d]:" + " sid %u (0x%x), iov %p, iovcnt %d, total %d", fd, fd, i, + sid, sid, iov, iovcnt, total); rv = vppcom_session_read (sid, iov[i].iov_base, iov[i].iov_len); if (rv < 0) @@ -518,11 +467,8 @@ readv (int fd, const struct iovec * iov, int iovcnt) total += rv; if (rv < iov[i].iov_len) { - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): " - "rv (%d) < iov[%d].iov_len (%d)", - getpid (), fd, fd, rv, i, - iov[i].iov_len); + LDBG (2, "fd %d (0x%x): rv (%d) < iov[%d].iov_len (%d)", + fd, fd, rv, i, iov[i].iov_len); break; } } @@ -540,37 +486,20 @@ readv (int fd, const struct iovec * iov, int iovcnt) } else { - func_str = "libc_readv"; - - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): " - "iov %p, iovcnt %d", getpid (), fd, fd, iov, iovcnt); + LDBG (2, "fd %d (0x%x): calling libc_readv(): iov %p, iovcnt %d", fd, + fd, iov, iovcnt); size = libc_readv (fd, iov, iovcnt); } - if (LDP_DEBUG > 2) - { - if (size < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), fd, fd, - func_str, size, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: fd %d (0x%x): returning %d (0x%x)", - getpid (), fd, fd, size, size); - } + + LDBG (2, "fd %d (0x%x): returning %d (0x%x)", fd, fd, size, size); return size; } ssize_t write (int fd, const void *buf, size_t nbytes) { - const char *func_str; ssize_t size = 0; u32 sid = ldp_sid_from_fd (fd); @@ -579,12 +508,8 @@ write (int fd, const void *buf, size_t nbytes) if (sid != INVALID_SESSION_ID) { - func_str = "vppcom_session_write"; - - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): " - "sid %u (0x%x), buf %p, nbytes %u", getpid (), - fd, fd, func_str, sid, sid, buf, nbytes); + LDBG (2, "fd %d (0x%x): calling vppcom_session_write(): sid %u (0x%x), " + "buf %p, nbytes %u", fd, fd, sid, sid, buf, nbytes); size = vppcom_session_write (sid, (void *) buf, nbytes); if (size < 0) @@ -595,31 +520,13 @@ write (int fd, const void *buf, size_t nbytes) } else { - func_str = "libc_write"; - - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): " - "buf %p, nbytes %u", getpid (), - fd, fd, func_str, buf, nbytes); + LDBG (2, "fd %d (0x%x): calling libc_write(): buf %p, nbytes %u", + fd, fd, buf, nbytes); size = libc_write (fd, buf, nbytes); } - if (LDP_DEBUG > 2) - { - if (size < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), fd, fd, - func_str, size, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: fd %d (0x%x): returning %d (0x%x)", - getpid (), fd, fd, size, size); - } + LDBG (2, "fd %d (0x%x): returning %d (0x%x)", fd, fd, size, size); return size; } @@ -734,8 +641,8 @@ fcntl (int fd, int cmd, ...) { case F_SETFL: func_str = "vppcom_session_attr[SET_FLAGS]"; - LDBG (2, "LDP<%d>: fd %d (0x%x): calling %s(): sid %u (0x%x) " - "flags %d (0x%x), size %d", getpid (), fd, fd, func_str, sid, + LDBG (2, "fd %d (0x%x): calling %s(): sid %u (0x%x) " + "flags %d (0x%x), size %d", fd, fd, func_str, sid, sid, flags, flags, size); rv = vppcom_session_attr (sid, VPPCOM_ATTR_SET_FLAGS, &flags, @@ -744,16 +651,16 @@ fcntl (int fd, int cmd, ...) case F_GETFL: func_str = "vppcom_session_attr[GET_FLAGS]"; - LDBG (2, "LDP<%d>: fd %d (0x%x): calling %s(): sid %u (0x%x), " - "flags %d (0x%x), size %d", getpid (), fd, fd, func_str, sid, + LDBG (2, "fd %d (0x%x): calling %s(): sid %u (0x%x), " + "flags %d (0x%x), size %d", fd, fd, func_str, sid, sid, flags, flags, size); rv = vppcom_session_attr (sid, VPPCOM_ATTR_GET_FLAGS, &flags, &size); if (rv == VPPCOM_OK) { - LDBG (2, "LDP<%d>: fd %d (0x%x), cmd %d (F_GETFL): %s() " - "returned flags %d (0x%x)", getpid (), fd, fd, cmd, + LDBG (2, "fd %d (0x%x), cmd %d (F_GETFL): %s() " + "returned flags %d (0x%x)", fd, fd, cmd, func_str, flags, flags); rv = flags; } @@ -777,9 +684,7 @@ fcntl (int fd, int cmd, ...) { func_str = "libc_vfcntl"; - if (LDP_DEBUG > 2) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): cmd %d", - getpid (), fd, fd, func_str, cmd); + LDBG (2, "fd %d (0x%x): calling %s(): cmd %d", fd, fd, func_str, cmd); rv = libc_vfcntl (fd, cmd, ap); } @@ -920,8 +825,7 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, /* select as fine grained sleep */ if (!nfds) { - LDBG (3, "LDP<%d>: sleeping for %.02f seconds", getpid (), - time_out); + LDBG (3, "sleeping for %.02f seconds", time_out); time_out += clib_time_now (&ldpw->clib_time); while (clib_time_now (&ldpw->clib_time) < time_out) @@ -942,8 +846,8 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, { func_str = "libc_pselect"; - LDBG (3, "LDP<%d>: calling %s(): nfds %d, readfds %p, writefds %p, " - "exceptfds %p, timeout %p, sigmask %p", getpid (), func_str, nfds, + LDBG (3, "calling %s(): nfds %d, readfds %p, writefds %p, " + "exceptfds %p, timeout %p, sigmask %p", func_str, nfds, readfds, writefds, exceptfds, timeout, sigmask); rv = libc_pselect (nfds, readfds, writefds, exceptfds, @@ -976,8 +880,7 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, if (fd > nfds) break; sid = ldp_sid_from_fd (fd); - LDBG (3, "LDP<%d>: readfds: fd %d (0x%x), sid %u (0x%x)", - getpid (), fd, fd, sid, sid); + LDBG (3, "readfds: fd %d (0x%x), sid %u (0x%x)", fd, fd, sid, sid); if (sid == INVALID_SESSION_ID) clib_bitmap_set_no_check (ldpw->libc_rd_bitmap, fd, 1); else @@ -992,8 +895,8 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, libc_bits_set = clib_bitmap_last_set (ldpw->libc_rd_bitmap) + 1; libc_bits = (libc_bits_set > libc_bits) ? libc_bits_set : libc_bits; - LDBG (3, "LDP<%d>: readfds: sid_bits_set %d, sid_bits %d, " - "libc_bits_set %d, libc_bits %d", getpid (), sid_bits_set, + LDBG (3, "readfds: sid_bits_set %d, sid_bits %d, " + "libc_bits_set %d, libc_bits %d", sid_bits_set, sid_bits, libc_bits_set, libc_bits); } if (writefds) @@ -1009,8 +912,7 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, if (fd > nfds) break; sid = ldp_sid_from_fd (fd); - LDBG (3, "LDP<%d>: writefds: fd %d (0x%x), sid %u (0x%x)", - getpid (), fd, fd, sid, sid); + LDBG (3, "writefds: fd %d (0x%x), sid %u (0x%x)", fd, fd, sid, sid); if (sid == INVALID_SESSION_ID) clib_bitmap_set_no_check (ldpw->libc_wr_bitmap, fd, 1); else @@ -1025,8 +927,8 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, libc_bits_set = clib_bitmap_last_set (ldpw->libc_wr_bitmap) + 1; libc_bits = (libc_bits_set > libc_bits) ? libc_bits_set : libc_bits; - LDBG (3, "LDP<%d>: writefds: sid_bits_set %d, sid_bits %d, " - "libc_bits_set %d, libc_bits %d", getpid (), + LDBG (3, "writefds: sid_bits_set %d, sid_bits %d, " + "libc_bits_set %d, libc_bits %d", sid_bits_set, sid_bits, libc_bits_set, libc_bits); } if (exceptfds) @@ -1042,8 +944,7 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, if (fd > nfds) break; sid = ldp_sid_from_fd (fd); - LDBG (3, "LDP<%d>: exceptfds: fd %d (0x%x), sid %u (0x%x)", - getpid (), fd, fd, sid, sid); + LDBG (3, "exceptfds: fd %d (0x%x), sid %u (0x%x)", fd, fd, sid, sid); if (sid == INVALID_SESSION_ID) clib_bitmap_set_no_check (ldpw->libc_ex_bitmap, fd, 1); else @@ -1058,8 +959,8 @@ ldp_pselect (int nfds, fd_set * __restrict readfds, libc_bits_set = clib_bitmap_last_set (ldpw->libc_ex_bitmap) + 1; libc_bits = (libc_bits_set > libc_bits) ? libc_bits_set : libc_bits; - LDBG (3, "LDP<%d>: exceptfds: sid_bits_set %d, sid_bits %d, " - "libc_bits_set %d, libc_bits %d", getpid (), + LDBG (3, "exceptfds: sid_bits_set %d, sid_bits %d, " + "libc_bits_set %d, libc_bits %d", sid_bits_set, sid_bits, libc_bits_set, libc_bits); } @@ -1264,9 +1165,8 @@ socket (int domain, int type, int protocol) func_str = "vppcom_session_create"; - LDBG (0, "LDP<%d>: : calling %s(): proto %u (%s), is_nonblocking %u", - getpid (), func_str, proto, vppcom_proto_str (proto), - is_nonblocking); + LDBG (0, "calling %s(): proto %u (%s), is_nonblocking %u", + func_str, proto, vppcom_proto_str (proto), is_nonblocking); sid = vppcom_session_create (proto, is_nonblocking); if (sid < 0) @@ -1290,7 +1190,7 @@ socket (int domain, int type, int protocol) { func_str = "libc_socket"; - LDBG (0, "LDP<%d>: : calling %s()", getpid (), func_str); + LDBG (0, "calling %s()", func_str); rv = libc_socket (domain, type, protocol); } @@ -1307,7 +1207,7 @@ socket (int domain, int type, int protocol) errno = errno_val; } else - clib_warning ("LDP<%d>: : returning fd %d (0x%x)", getpid (), rv, rv); + clib_warning ("returning fd %d (0x%x)", getpid (), rv, rv); } return rv; } @@ -1342,7 +1242,7 @@ socketpair (int domain, int type, int protocol, int fds[2]) { func_str = "libc_socket"; - LDBG (1, "LDP<%d>: : calling %s()", getpid (), func_str); + LDBG (1, "calling %s()", func_str); rv = libc_socketpair (domain, type, protocol, fds); } @@ -1368,7 +1268,6 @@ int bind (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) { int rv; - const char *func_str; u32 sid = ldp_sid_from_fd (fd); if ((errno = -ldp_init ())) @@ -1378,8 +1277,6 @@ bind (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) { vppcom_endpt_t ep; - func_str = "vppcom_session_bind"; - switch (addr->sa_family) { case AF_INET: @@ -1420,10 +1317,8 @@ bind (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) rv = -1; goto done; } - if (LDP_DEBUG > 0) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): sid %u (0x%x), " - "addr %p, len %u", - getpid (), fd, fd, func_str, sid, sid, addr, len); + LDBG (0, "fd %d (0x%x): calling vppcom_session_bind(): " + "sid %u (0x%x), addr %p, len %u", fd, fd, sid, sid, addr, len); rv = vppcom_session_bind (sid, &ep); if (rv != VPPCOM_OK) @@ -1434,32 +1329,15 @@ bind (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) } else { - func_str = "libc_bind"; - - if (LDP_DEBUG > 0) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): " - "addr %p, len %u", - getpid (), fd, fd, func_str, addr, len); + LDBG (0, "fd %d (0x%x): calling libc_bind(): addr %p, len %u", + fd, fd, addr, len); rv = libc_bind (fd, addr, len); } done: - if (LDP_DEBUG > 0) - { - if (rv < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), fd, fd, - func_str, rv, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: fd %d (0x%x): returning %d (0x%x)", - getpid (), fd, fd, rv, rv); - } + LDBG (1, "fd %d (0x%x): returning %d", fd, fd, rv); + return rv; } @@ -1583,7 +1461,6 @@ int connect (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) { int rv; - const char *func_str = __func__; u32 sid = ldp_sid_from_fd (fd); if ((errno = -ldp_init ())) @@ -1602,8 +1479,6 @@ connect (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) { vppcom_endpt_t ep; - func_str = "vppcom_session_connect"; - switch (addr->sa_family) { case AF_INET: @@ -1644,10 +1519,8 @@ connect (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) rv = -1; goto done; } - if (LDP_DEBUG > 0) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): sid %u (0x%x) " - "addr %p len %u", - getpid (), fd, fd, func_str, sid, sid, addr, len); + LDBG (0, "fd %d (0x%x): calling vppcom_session_connect(): sid %u (0x%x)" + " addr %p len %u", fd, fd, sid, sid, addr, len); rv = vppcom_session_connect (sid, &ep); if (rv != VPPCOM_OK) @@ -1658,32 +1531,14 @@ connect (int fd, __CONST_SOCKADDR_ARG addr, socklen_t len) } else { - func_str = "libc_connect"; - - if (LDP_DEBUG > 0) - clib_warning ("LDP<%d>: fd %d (0x%x): calling %s(): " - "addr %p, len %u", - getpid (), fd, fd, func_str, addr, len); + LDBG (0, "fd %d (0x%x): calling libc_connect(): addr %p, len %u", + fd, fd, addr, len); rv = libc_connect (fd, addr, len); } done: - if (LDP_DEBUG > 0) - { - if (rv < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), fd, fd, - func_str, rv, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: fd %d (0x%x): returning %d (0x%x)", - getpid (), fd, fd, rv, rv); - } + LDBG (1, "fd %d (0x%x): returning %d (0x%x)", fd, fd, rv, rv); return rv; } @@ -2865,7 +2720,6 @@ int listen (int fd, int n) { int rv; - const char *func_str; u32 sid = ldp_sid_from_fd (fd); if ((errno = -ldp_init ())) @@ -2873,10 +2727,8 @@ listen (int fd, int n) if (sid != INVALID_SESSION_ID) { - func_str = "vppcom_session_listen"; - - LDBG (0, "LDP<%d>: fd %d (0x%x): calling %s(): sid %u (0x%x), n %d", - getpid (), fd, fd, func_str, sid, sid, n); + LDBG (0, "fd %d (0x%x): calling vppcom_session_listen():" + " sid %u (0x%x), n %d", fd, fd, sid, sid, n); rv = vppcom_session_listen (sid, n); if (rv != VPPCOM_OK) @@ -2887,29 +2739,12 @@ listen (int fd, int n) } else { - func_str = "libc_listen"; - - LDBG (0, "LDP<%d>: fd %d (0x%x): calling %s(): n %d", getpid (), fd, - fd, func_str, n); + LDBG (0, "fd %d (0x%x): calling libc_listen(): n %d", fd, fd, n); rv = libc_listen (fd, n); } - if (LDP_DEBUG > 0) - { - if (rv < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), fd, fd, - func_str, rv, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: fd %d (0x%x): returning %d (0x%x)", - getpid (), fd, fd, rv, rv); - } + LDBG (1, "fd %d (0x%x): returning %d (0x%x)", fd, fd, rv, rv); return rv; } @@ -2918,7 +2753,6 @@ ldp_accept4 (int listen_fd, __SOCKADDR_ARG addr, socklen_t * __restrict addr_len, int flags) { int rv; - const char *func_str; u32 listen_sid = ldp_sid_from_fd (listen_fd); int accept_sid; @@ -2932,13 +2766,9 @@ ldp_accept4 (int listen_fd, __SOCKADDR_ARG addr, memset (&ep, 0, sizeof (ep)); ep.ip = src_addr; - func_str = "vppcom_session_accept"; - - if (LDP_DEBUG > 0) - clib_warning ("LDP<%d>: listen fd %d (0x%x): calling %s(): " - "listen sid %u (0x%x), ep %p, flags 0x%x", - getpid (), listen_fd, listen_fd, func_str, - listen_sid, listen_sid, ep, flags); + LDBG (0, "listen fd %d (0x%x): calling vppcom_session_accept:" + " listen sid %u (0x%x), ep %p, flags 0x%x", listen_fd, + listen_fd, listen_sid, listen_sid, ep, flags); accept_sid = vppcom_session_accept (listen_sid, &ep, flags); if (accept_sid < 0) @@ -2957,12 +2787,6 @@ ldp_accept4 (int listen_fd, __SOCKADDR_ARG addr, } else { - func_str = "ldp_fd_from_sid"; - if (LDP_DEBUG > 0) - clib_warning ("LDP<%d>: listen fd %d (0x%x): calling %s(): " - "accept sid %u (0x%x), ep %p, flags 0x%x", - getpid (), listen_fd, listen_fd, - func_str, accept_sid, accept_sid, ep, flags); rv = ldp_fd_alloc ((u32) accept_sid); if (rv < 0) { @@ -2975,32 +2799,16 @@ ldp_accept4 (int listen_fd, __SOCKADDR_ARG addr, } else { - func_str = "libc_accept4"; - - if (LDP_DEBUG > 0) - clib_warning ("LDP<%d>: listen fd %d (0x%x): calling %s(): " - "addr %p, addr_len %p, flags 0x%x", - getpid (), listen_fd, listen_fd, func_str, - addr, addr_len, flags); + LDBG (0, "listen fd %d (0x%x): calling libc_accept4(): " + "addr %p, addr_len %p, flags 0x%x", listen_fd, + listen_fd, addr, addr_len, flags); rv = libc_accept4 (listen_fd, addr, addr_len, flags); } - if (LDP_DEBUG > 0) - { - if (rv < 0) - { - int errno_val = errno; - perror (func_str); - clib_warning ("LDP<%d>: ERROR: listen fd %d (0x%x): %s() failed! " - "rv %d, errno = %d", getpid (), listen_fd, - listen_fd, func_str, rv, errno_val); - errno = errno_val; - } - else - clib_warning ("LDP<%d>: listen fd %d (0x%x): returning %d (0x%x)", - getpid (), listen_fd, listen_fd, rv, rv); - } + LDBG (1, "listen fd %d (0x%x): returning %d (0x%x)", listen_fd, listen_fd, + rv, rv); + return rv; } @@ -3076,12 +2884,12 @@ epoll_create1 (int flags) rv = libc_epoll_create1 (flags); ldp->vcl_needs_real_epoll = 0; ldpw->vcl_mq_epfd = rv; - LDBG (0, "LDP<%d>: created vcl epfd %u", getpid (), rv); + LDBG (0, "created vcl epfd %u", rv); return rv; } func_str = "vppcom_epoll_create"; - LDBG (1, "LDP<%d>: calling %s()", getpid (), func_str); + LDBG (1, "calling %s()", func_str); rv = vppcom_epoll_create (); @@ -3135,8 +2943,8 @@ epoll_ctl (int epfd, int op, int fd, struct epoll_event *event) */ func_str = "libc_epoll_ctl"; - LDBG (1, "LDP<%d>: epfd %d (0x%x): calling %s(): op %d, fd %d (0x%x)," - " event %p", getpid (), epfd, epfd, func_str, op, fd, fd, event); + LDBG (1, "epfd %d (0x%x): calling %s(): op %d, fd %d (0x%x)," + " event %p", epfd, epfd, func_str, op, fd, fd, event); rv = libc_epoll_ctl (epfd, op, fd, event); goto done; @@ -3144,15 +2952,15 @@ epoll_ctl (int epfd, int op, int fd, struct epoll_event *event) sid = ldp_sid_from_fd (fd); - LDBG (0, "LDP<%d>: epfd %d (0x%x), vep_idx %d (0x%x), sid %d (0x%x)", - getpid (), epfd, epfd, vep_idx, vep_idx, sid, sid); + LDBG (0, "epfd %d (0x%x), vep_idx %d (0x%x), sid %d (0x%x)", + epfd, epfd, vep_idx, vep_idx, sid, sid); if (sid != INVALID_SESSION_ID) { func_str = "vppcom_epoll_ctl"; - LDBG (1, "LDP<%d>: epfd %d (0x%x): calling %s(): vep_idx %d (0x%x)," - " op %d, sid %u (0x%x), event %p", getpid (), epfd, epfd, + LDBG (1, "epfd %d (0x%x): calling %s(): vep_idx %d (0x%x)," + " op %d, sid %u (0x%x), event %p", epfd, epfd, func_str, vep_idx, vep_idx, sid, sid, event); rv = vppcom_epoll_ctl (vep_idx, op, sid, event); @@ -3170,16 +2978,16 @@ epoll_ctl (int epfd, int op, int fd, struct epoll_event *event) func_str = "vppcom_session_attr[GET_LIBC_EPFD]"; libc_epfd = vppcom_session_attr (vep_idx, VPPCOM_ATTR_GET_LIBC_EPFD, 0, 0); - LDBG (1, "LDP<%d>: epfd %d (0x%x), vep_idx %d (0x%x): %s() " - "returned libc_epfd %d (0x%x)", getpid (), epfd, epfd, + LDBG (1, "epfd %d (0x%x), vep_idx %d (0x%x): %s() " + "returned libc_epfd %d (0x%x)", epfd, epfd, vep_idx, vep_idx, func_str, libc_epfd, libc_epfd); if (!libc_epfd) { func_str = "libc_epoll_create1"; - LDBG (1, "LDP<%d>: epfd %d (0x%x), vep_idx %d (0x%x): " - "calling %s(): EPOLL_CLOEXEC", getpid (), epfd, epfd, + LDBG (1, "epfd %d (0x%x), vep_idx %d (0x%x): " + "calling %s(): EPOLL_CLOEXEC", epfd, epfd, vep_idx, vep_idx, func_str); libc_epfd = libc_epoll_create1 (EPOLL_CLOEXEC); @@ -3190,9 +2998,9 @@ epoll_ctl (int epfd, int op, int fd, struct epoll_event *event) } func_str = "vppcom_session_attr[SET_LIBC_EPFD]"; - LDBG (1, "LDP<%d>: epfd %d (0x%x): calling %s(): vep_idx %d (0x%x)," + LDBG (1, "epfd %d (0x%x): calling %s(): vep_idx %d (0x%x)," " VPPCOM_ATTR_SET_LIBC_EPFD, libc_epfd %d (0x%x), size %d", - getpid (), epfd, epfd, func_str, vep_idx, vep_idx, libc_epfd, + epfd, epfd, func_str, vep_idx, vep_idx, libc_epfd, libc_epfd, size); rv = vppcom_session_attr (vep_idx, VPPCOM_ATTR_SET_LIBC_EPFD, @@ -3213,8 +3021,8 @@ epoll_ctl (int epfd, int op, int fd, struct epoll_event *event) func_str = "libc_epoll_ctl"; - LDBG (1, "LDP<%d>: epfd %d (0x%x): calling %s(): libc_epfd %d (0x%x), " - "op %d, fd %d (0x%x), event %p", getpid (), epfd, epfd, func_str, + LDBG (1, "epfd %d (0x%x): calling %s(): libc_epfd %d (0x%x), " + "op %d, fd %d (0x%x), event %p", epfd, epfd, func_str, libc_epfd, libc_epfd, op, fd, fd, event); rv = libc_epoll_ctl (libc_epfd, op, fd, event); @@ -3281,9 +3089,9 @@ ldp_epoll_pwait (int epfd, struct epoll_event *events, int maxevents, goto done; } - LDBG (2, "LDP<%d>: epfd %d (0x%x): vep_idx %d (0x%x), libc_epfd %d (0x%x), " + LDBG (2, "epfd %d (0x%x): vep_idx %d (0x%x), libc_epfd %d (0x%x), " "events %p, maxevents %d, timeout %d, sigmask %p: time_to_wait %.02f", - getpid (), epfd, epfd, vep_idx, vep_idx, libc_epfd, libc_epfd, events, + epfd, epfd, vep_idx, vep_idx, libc_epfd, libc_epfd, events, maxevents, timeout, sigmask, time_to_wait, time_out); do { @@ -3291,8 +3099,8 @@ ldp_epoll_pwait (int epfd, struct epoll_event *events, int maxevents, { func_str = "vppcom_epoll_wait"; - LDBG (3, "LDP<%d>: epfd %d (0x%x): calling %s(): vep_idx %d (0x%x)," - " events %p, maxevents %d", getpid (), epfd, epfd, func_str, + LDBG (3, "epfd %d (0x%x): calling %s(): vep_idx %d (0x%x)," + " events %p, maxevents %d", epfd, epfd, func_str, vep_idx, vep_idx, events, maxevents); rv = vppcom_epoll_wait (vep_idx, events, maxevents, 0); @@ -3315,8 +3123,8 @@ ldp_epoll_pwait (int epfd, struct epoll_event *events, int maxevents, { func_str = "libc_epoll_pwait"; - LDBG (3, "LDP<%d>: epfd %d (0x%x): calling %s(): libc_epfd %d " - "(0x%x), events %p, maxevents %d, sigmask %p", getpid (), + LDBG (3, "epfd %d (0x%x): calling %s(): libc_epfd %d " + "(0x%x), events %p, maxevents %d, sigmask %p", epfd, epfd, func_str, libc_epfd, libc_epfd, events, maxevents, sigmask); @@ -3374,8 +3182,7 @@ poll (struct pollfd *fds, nfds_t nfds, int timeout) vcl_poll_t *vp; double wait_for_time; - LDBG (3, "LDP<%d>: fds %p, nfds %d, timeout %d", getpid (), fds, nfds, - timeout); + LDBG (3, "fds %p, nfds %d, timeout %d", fds, nfds, timeout); if (timeout >= 0) wait_for_time = (f64) timeout / 1000; @@ -3387,9 +3194,8 @@ poll (struct pollfd *fds, nfds_t nfds, int timeout) if (fds[i].fd < 0) continue; - LDBG (3, "LDP<%d>: fds[%d] fd %d (0x%0x) events = 0x%x revents = 0x%x", - getpid (), i, fds[i].fd, fds[i].fd, fds[i].events, - fds[i].revents); + LDBG (3, "fds[%d] fd %d (0x%0x) events = 0x%x revents = 0x%x", + i, fds[i].fd, fds[i].fd, fds[i].events, fds[i].revents); sid = ldp_sid_from_fd (fds[i].fd); if (sid != INVALID_SESSION_ID) @@ -3420,8 +3226,8 @@ poll (struct pollfd *fds, nfds_t nfds, int timeout) { func_str = "vppcom_poll"; - LDBG (3, "LDP<%d>: calling %s(): vcl_poll %p, n_sids %u (0x%x): " - "n_libc_fds %u", getpid (), func_str, ldpw->vcl_poll, + LDBG (3, "calling %s(): vcl_poll %p, n_sids %u (0x%x): " + "n_libc_fds %u", func_str, ldpw->vcl_poll, vec_len (ldpw->vcl_poll), vec_len (ldpw->vcl_poll), vec_len (ldpw->libc_poll)); @@ -3440,8 +3246,8 @@ poll (struct pollfd *fds, nfds_t nfds, int timeout) { func_str = "libc_poll"; - LDBG (3, "LDP<%d>: calling %s(): fds %p, nfds %u: n_sids %u", - getpid (), fds, nfds, vec_len (ldpw->vcl_poll)); + LDBG (3, "calling %s(): fds %p, nfds %u: n_sids %u", + fds, nfds, vec_len (ldpw->vcl_poll)); rv = libc_poll (ldpw->libc_poll, vec_len (ldpw->libc_poll), 0); if (rv < 0) diff --git a/src/vcl/vppcom.c b/src/vcl/vppcom.c index 9bb6a9880d1..88a67ddab30 100644 --- a/src/vcl/vppcom.c +++ b/src/vcl/vppcom.c @@ -464,8 +464,7 @@ vcl_session_bound_handler (vcl_worker_t * wrk, session_bound_msg_t * mp) session->tx_fifo = tx_fifo; } - VDBG (0, "VCL<%d>: vpp handle 0x%llx, sid %u: bind succeeded!", - getpid (), mp->handle, sid); + VDBG (0, "session %u [0x%llx]: listen succeeded!", sid, mp->handle); return sid; } @@ -569,7 +568,7 @@ vppcom_wait_for_session_state_change (u32 session_index, } while (clib_time_now (&wrk->clib_time) < timeout); - VDBG (0, "VCL<%d>: timeout waiting for state 0x%x (%s)", getpid (), state, + VDBG (0, "timeout waiting for state 0x%x (%s)", state, vppcom_session_state_str (state)); vcl_evt (VCL_EVT_SESSION_TIMEOUT, session, session_state); @@ -1003,7 +1002,7 @@ vppcom_session_close (uint32_t session_handle) state = session->session_state; vpp_handle = session->vpp_handle; - VDBG (0, "Closing session handle %u vpp handle %u", session_handle, + VDBG (1, "closing session handle %u vpp handle %u", session_handle, vpp_handle); if (is_vep) @@ -1077,8 +1076,7 @@ cleanup: } vcl_session_free (wrk, session); - VDBG (0, "session handle %u vpp handle %u removed", session_handle, - vpp_handle); + VDBG (0, "session handle %u [0x%llx] removed", session_handle, vpp_handle); vcl_evt (VCL_EVT_CLOSE, session, rv); @@ -1138,29 +1136,22 @@ vppcom_session_listen (uint32_t listen_sh, uint32_t q_len) int rv; listen_session = vcl_session_get_w_handle (wrk, listen_sh); - if (!listen_session) + if (!listen_session || listen_session->is_vep) return VPPCOM_EBADFD; if (q_len == 0 || q_len == ~0) q_len = vcm->cfg.listen_queue_size; - if (listen_session->is_vep) - { - clib_warning ("VCL<%d>: ERROR: sid %u: cannot listen on an " - "epoll session!", getpid (), listen_sh); - return VPPCOM_EBADFD; - } - listen_vpp_handle = listen_session->vpp_handle; if (listen_session->session_state & STATE_LISTEN) { - VDBG (0, "VCL<%d>: vpp handle 0x%llx, sid %u: already in listen state!", - getpid (), listen_vpp_handle, listen_sh); + VDBG (0, "session %u [0x%llx]: already in listen state!", + listen_sh, listen_vpp_handle); return VPPCOM_OK; } - VDBG (0, "VCL<%d>: vpp handle 0x%llx, sid %u: sending VPP bind+listen " - "request...", getpid (), listen_vpp_handle, listen_sh); + VDBG (0, "session %u [0x%llx]: sending vpp listen request...", + listen_sh, listen_vpp_handle); /* * Send listen request to vpp and wait for reply @@ -1173,9 +1164,9 @@ vppcom_session_listen (uint32_t listen_sh, uint32_t q_len) if (PREDICT_FALSE (rv)) { listen_session = vcl_session_get_w_handle (wrk, listen_sh); - VDBG (0, "VCL<%d>: vpp handle 0x%llx, sid %u: bind+listen failed! " - "returning %d (%s)", getpid (), listen_session->vpp_handle, - listen_sh, rv, vppcom_retval_str (rv)); + VDBG (0, "session %u [0x%llx]: listen failed! returning %d (%s)", + listen_sh, listen_session->vpp_handle, rv, + vppcom_retval_str (rv)); return rv; } @@ -1271,7 +1262,7 @@ handle: VCL_SESS_ATTR_SET (client_session->attr, VCL_SESS_ATTR_NONBLOCK); listen_vpp_handle = listen_session->vpp_handle; - VDBG (0, "vpp handle 0x%llx, sid %u: Got a client request! " + VDBG (1, "vpp handle 0x%llx, sid %u: Got a client request! " "vpp handle 0x%llx, sid %u, flags %d, is_nonblocking %u", listen_vpp_handle, listen_session_handle, client_session->vpp_handle, client_session_index, @@ -1299,16 +1290,12 @@ handle: vcl_send_session_accepted_reply (vpp_evt_q, client_session->client_context, client_session->vpp_handle, 0); - VDBG (0, "vpp handle 0x%llx, sid %u: accepted vpp handle 0x%llx, " - "sid %u connection from peer %s address %U port %u to local %s " - "address %U port %u", listen_vpp_handle, - listen_session_handle, client_session->vpp_handle, - client_session_index, - client_session->transport.is_ip4 ? "IPv4" : "IPv6", + VDBG (0, "listener %u [0x%llx] accepted %u [0x%llx] peer: %U:%u " + "local: %U:%u", listen_session_handle, listen_vpp_handle, + client_session_index, client_session->vpp_handle, format_ip46_address, &client_session->transport.rmt_ip, client_session->transport.is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6, clib_net_to_host_u16 (client_session->transport.rmt_port), - client_session->transport.is_ip4 ? "IPv4" : "IPv6", format_ip46_address, &client_session->transport.lcl_ip, client_session->transport.is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6, clib_net_to_host_u16 (client_session->transport.lcl_port)); |