Perf: Add stat for io of ST.

trunk/3rdparty/st-srs/io.c

@@ -52,6 +52,25 @@
 #include <errno.h>
 #include "common.h"
 
+// Global stat.
+#ifdef DEBUG
+unsigned long long _st_stat_recvfrom = 0;
+unsigned long long _st_stat_recvfrom_eagain = 0;
+unsigned long long _st_stat_sendto = 0;
+unsigned long long _st_stat_sendto_eagain = 0;
+unsigned long long _st_stat_read = 0;
+unsigned long long _st_stat_read_eagain = 0;
+unsigned long long _st_stat_readv = 0;
+unsigned long long _st_stat_readv_eagain = 0;
+unsigned long long _st_stat_writev = 0;
+unsigned long long _st_stat_writev_eagain = 0;
+unsigned long long _st_stat_recvmsg = 0;
+unsigned long long _st_stat_recvmsg_eagain = 0;
+unsigned long long _st_stat_sendmsg = 0;
+unsigned long long _st_stat_sendmsg_eagain = 0;
+unsigned long long _st_stat_sendmmsg = 0;
+unsigned long long _st_stat_sendmmsg_eagain = 0;
+#endif
 
 #if EAGAIN != EWOULDBLOCK
     #define _IO_NOT_READY_ERROR  ((errno == EAGAIN) || (errno == EWOULDBLOCK))
@@ -437,12 +456,21 @@ int st_connect(_st_netfd_t *fd, const struct sockaddr *addr, int addrlen, st_uti
 ssize_t st_read(_st_netfd_t *fd, void *buf, size_t nbyte, st_utime_t timeout)
 {
     ssize_t n;
+
+    #ifdef DEBUG
+    ++_st_stat_read;
+    #endif
     
     while ((n = read(fd->osfd, buf, nbyte)) < 0) {
         if (errno == EINTR)
             continue;
         if (!_IO_NOT_READY_ERROR)
             return -1;
+
+        #ifdef DEBUG
+        ++_st_stat_read_eagain;
+        #endif
+
         /* Wait until the socket becomes readable */
         if (st_netfd_poll(fd, POLLIN, timeout) < 0)
             return -1;
@@ -470,12 +498,21 @@ int st_read_resid(_st_netfd_t *fd, void *buf, size_t *resid, st_utime_t timeout)
 ssize_t st_readv(_st_netfd_t *fd, const struct iovec *iov, int iov_size, st_utime_t timeout)
 {
     ssize_t n;
+
+    #ifdef DEBUG
+    ++_st_stat_readv;
+    #endif
     
     while ((n = readv(fd->osfd, iov, iov_size)) < 0) {
         if (errno == EINTR)
             continue;
         if (!_IO_NOT_READY_ERROR)
             return -1;
+
+        #ifdef DEBUG
+        ++_st_stat_readv_eagain;
+        #endif
+
         /* Wait until the socket becomes readable */
         if (st_netfd_poll(fd, POLLIN, timeout) < 0)
             return -1;
@@ -572,6 +609,10 @@ ssize_t st_writev(_st_netfd_t *fd, const struct iovec *iov, int iov_size, st_uti
     nleft = nbyte;
     tmp_iov = (struct iovec *) iov;    /* we promise not to modify iov */
     iov_cnt = iov_size;
+
+    #ifdef DEBUG
+    ++_st_stat_writev;
+    #endif
     
     while (nleft > 0) {
         if (iov_cnt == 1) {
@@ -616,6 +657,11 @@ ssize_t st_writev(_st_netfd_t *fd, const struct iovec *iov, int iov_size, st_uti
                 tmp_iov[iov_cnt].iov_len = iov[index].iov_len;
             }
         }
+
+        #ifdef DEBUG
+        ++_st_stat_writev_eagain;
+        #endif
+
         /* Wait until the socket becomes writable */
         if (st_netfd_poll(fd, POLLOUT, timeout) < 0) {
             rv = -1;
@@ -633,6 +679,10 @@ ssize_t st_writev(_st_netfd_t *fd, const struct iovec *iov, int iov_size, st_uti
 int st_writev_resid(_st_netfd_t *fd, struct iovec **iov, int *iov_size, st_utime_t timeout)
 {
     ssize_t n;
+
+    #ifdef DEBUG
+    ++_st_stat_writev;
+    #endif
     
     while (*iov_size > 0) {
         if (*iov_size == 1)
@@ -659,6 +709,11 @@ int st_writev_resid(_st_netfd_t *fd, struct iovec **iov, int *iov_size, st_utime
             (*iov)->iov_base = (char *) (*iov)->iov_base + n;
             (*iov)->iov_len -= n;
         }
+
+        #ifdef DEBUG
+        ++_st_stat_writev_eagain;
+        #endif
+
         /* Wait until the socket becomes writable */
         if (st_netfd_poll(fd, POLLOUT, timeout) < 0)
             return -1;
@@ -674,12 +729,21 @@ int st_writev_resid(_st_netfd_t *fd, struct iovec **iov, int *iov_size, st_utime
 int st_recvfrom(_st_netfd_t *fd, void *buf, int len, struct sockaddr *from, int *fromlen, st_utime_t timeout)
 {
     int n;
-    
+
+    #ifdef DEBUG
+    ++_st_stat_recvfrom;
+    #endif
+
     while ((n = recvfrom(fd->osfd, buf, len, 0, from, (socklen_t *)fromlen)) < 0) {
         if (errno == EINTR)
             continue;
         if (!_IO_NOT_READY_ERROR)
             return -1;
+
+        #ifdef DEBUG
+        ++_st_stat_recvfrom_eagain;
+        #endif
+
         /* Wait until the socket becomes readable */
         if (st_netfd_poll(fd, POLLIN, timeout) < 0)
             return -1;
@@ -692,12 +756,21 @@ int st_recvfrom(_st_netfd_t *fd, void *buf, int len, struct sockaddr *from, int
 int st_sendto(_st_netfd_t *fd, const void *msg, int len, const struct sockaddr *to, int tolen, st_utime_t timeout)
 {
     int n;
+
+    #ifdef DEBUG
+    ++_st_stat_sendto;
+    #endif
     
     while ((n = sendto(fd->osfd, msg, len, 0, to, tolen)) < 0) {
         if (errno == EINTR)
             continue;
         if (!_IO_NOT_READY_ERROR)
             return -1;
+
+        #ifdef DEBUG
+        ++_st_stat_sendto_eagain;
+        #endif
+
         /* Wait until the socket becomes writable */
         if (st_netfd_poll(fd, POLLOUT, timeout) < 0)
             return -1;
@@ -710,12 +783,21 @@ int st_sendto(_st_netfd_t *fd, const void *msg, int len, const struct sockaddr *
 int st_recvmsg(_st_netfd_t *fd, struct msghdr *msg, int flags, st_utime_t timeout)
 {
     int n;
+
+    #ifdef DEBUG
+    ++_st_stat_recvmsg;
+    #endif
     
     while ((n = recvmsg(fd->osfd, msg, flags)) < 0) {
         if (errno == EINTR)
             continue;
         if (!_IO_NOT_READY_ERROR)
             return -1;
+
+        #ifdef DEBUG
+        ++_st_stat_recvmsg_eagain;
+        #endif
+
         /* Wait until the socket becomes readable */
         if (st_netfd_poll(fd, POLLIN, timeout) < 0)
             return -1;
@@ -728,12 +810,21 @@ int st_recvmsg(_st_netfd_t *fd, struct msghdr *msg, int flags, st_utime_t timeou
 int st_sendmsg(_st_netfd_t *fd, const struct msghdr *msg, int flags, st_utime_t timeout)
 {
     int n;
+
+    #ifdef DEBUG
+    ++_st_stat_sendmsg;
+    #endif
     
     while ((n = sendmsg(fd->osfd, msg, flags)) < 0) {
         if (errno == EINTR)
             continue;
         if (!_IO_NOT_READY_ERROR)
             return -1;
+
+        #ifdef DEBUG
+        ++_st_stat_sendmsg_eagain;
+        #endif
+
         /* Wait until the socket becomes writable */
         if (st_netfd_poll(fd, POLLOUT, timeout) < 0)
             return -1;
@@ -749,6 +840,10 @@ int st_sendmmsg(st_netfd_t fd, struct st_mmsghdr *msgvec, unsigned int vlen, int
     int left;
     struct mmsghdr *p;
 
+    #ifdef DEBUG
+    ++_st_stat_sendmmsg;
+    #endif
+
     left = (int)vlen;
     while (left > 0) {
         p = (struct mmsghdr*)msgvec + (vlen - left);
@@ -758,6 +853,11 @@ int st_sendmmsg(st_netfd_t fd, struct st_mmsghdr *msgvec, unsigned int vlen, int
                 continue;
             if (!_IO_NOT_READY_ERROR)
                 break;
+
+            #ifdef DEBUG
+            ++_st_stat_sendmmsg_eagain;
+            #endif
+
             /* Wait until the socket becomes writable */
             if (st_netfd_poll(fd, POLLOUT, timeout) < 0)
                 break;

trunk/src/app/srs_app_hybrid.cpp

@@ -39,6 +39,41 @@ extern SrsPps* _srs_pps_pub;
 extern SrsPps* _srs_pps_conn;
 extern SrsPps* _srs_pps_dispose;
 
+extern unsigned long long _st_stat_recvfrom;
+extern unsigned long long _st_stat_recvfrom_eagain;
+extern unsigned long long _st_stat_sendto;
+extern unsigned long long _st_stat_sendto_eagain;
+SrsPps* _srs_pps_recvfrom = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_recvfrom_eagain = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_sendto = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_sendto_eagain = new SrsPps(_srs_clock);
+
+extern unsigned long long _st_stat_read;
+extern unsigned long long _st_stat_read_eagain;
+extern unsigned long long _st_stat_readv;
+extern unsigned long long _st_stat_readv_eagain;
+extern unsigned long long _st_stat_writev;
+extern unsigned long long _st_stat_writev_eagain;
+SrsPps* _srs_pps_read = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_read_eagain = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_readv = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_readv_eagain = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_writev = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_writev_eagain = new SrsPps(_srs_clock);
+
+extern unsigned long long _st_stat_recvmsg;
+extern unsigned long long _st_stat_recvmsg_eagain;
+extern unsigned long long _st_stat_sendmsg;
+extern unsigned long long _st_stat_sendmsg_eagain;
+extern unsigned long long _st_stat_sendmmsg;
+extern unsigned long long _st_stat_sendmmsg_eagain;
+SrsPps* _srs_pps_recvmsg = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_recvmsg_eagain = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_sendmsg = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_sendmsg_eagain = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_sendmmsg = new SrsPps(_srs_clock);
+SrsPps* _srs_pps_sendmmsg_eagain = new SrsPps(_srs_clock);
+
 ISrsHybridServer::ISrsHybridServer()
 {
 }
@@ -225,15 +260,70 @@ srs_error_t SrsHybridServer::notify(int event, srs_utime_t interval, srs_utime_t
     // Resident Set Size: number of pages the process has in real memory.
     int memory = (int)(u->rss * 4 / 1024);
 
-    _srs_pps_cids_get->update(); _srs_pps_cids_set->update();
+    static char buf[128];
-    _srs_pps_timer->update(); _srs_pps_pub->update(); _srs_pps_conn->update();
-    _srs_pps_dispose->update();
 
-    srs_trace("Hybrid cpu=%.2f%%,%dMB, cid=%d,%d, timer=%d,%d,%d, free=%d",
+    string cid_desc;
+    _srs_pps_cids_get->update(); _srs_pps_cids_set->update();
+    if (_srs_pps_cids_get->r10s() || _srs_pps_cids_set->r10s()) {
+        snprintf(buf, sizeof(buf), ", cid=%d,%d", _srs_pps_cids_get->r10s(), _srs_pps_cids_set->r10s());
+        cid_desc = buf;
+    }
+
+    string timer_desc;
+    _srs_pps_timer->update(); _srs_pps_pub->update(); _srs_pps_conn->update();
+    if (_srs_pps_timer->r10s() || _srs_pps_pub->r10s() || _srs_pps_conn->r10s()) {
+        snprintf(buf, sizeof(buf), ", timer=%d,%d,%d", _srs_pps_timer->r10s(), _srs_pps_pub->r10s(), _srs_pps_conn->r10s());
+        timer_desc = buf;
+    }
+
+    string free_desc;
+    _srs_pps_dispose->update();
+    if (_srs_pps_dispose->r10s()) {
+        snprintf(buf, sizeof(buf), ", free=%d", _srs_pps_dispose->r10s());
+        free_desc = buf;
+    }
+
+    string recvfrom_desc;
+    _srs_pps_recvfrom->update(_st_stat_recvfrom); _srs_pps_recvfrom_eagain->update(_st_stat_recvfrom_eagain);
+    _srs_pps_sendto->update(_st_stat_sendto); _srs_pps_sendto_eagain->update(_st_stat_sendto_eagain);
+    if (_srs_pps_recvfrom->r10s() || _srs_pps_recvfrom_eagain->r10s() || _srs_pps_sendto->r10s() || _srs_pps_sendto_eagain->r10s()) {
+        snprintf(buf, sizeof(buf), ", udp=%d,%d,%d,%d",
+            _srs_pps_recvfrom->r10s(), _srs_pps_recvfrom_eagain->r10s(),
+            _srs_pps_sendto->r10s(), _srs_pps_sendto_eagain->r10s()
+        );
+        recvfrom_desc = buf;
+    }
+
+    string io_desc;
+    _srs_pps_read->update(_st_stat_read); _srs_pps_read_eagain->update(_st_stat_read_eagain);
+    _srs_pps_readv->update(_st_stat_readv); _srs_pps_readv_eagain->update(_st_stat_readv_eagain);
+    _srs_pps_writev->update(_st_stat_writev); _srs_pps_writev_eagain->update(_st_stat_writev_eagain);
+    if (_srs_pps_read->r10s() || _srs_pps_read_eagain->r10s() || _srs_pps_readv->r10s() || _srs_pps_readv_eagain->r10s() || _srs_pps_writev->r10s() || _srs_pps_writev_eagain->r10s()) {
+        snprintf(buf, sizeof(buf), ", io=%d,%d,%d,%d,%d,%d",
+            _srs_pps_read->r10s(), _srs_pps_read_eagain->r10s(),
+            _srs_pps_readv->r10s(), _srs_pps_readv_eagain->r10s(),
+            _srs_pps_writev->r10s(), _srs_pps_writev_eagain->r10s()
+        );
+        io_desc = buf;
+    }
+
+    string msg_desc;
+    _srs_pps_recvmsg->update(_st_stat_recvmsg); _srs_pps_recvmsg_eagain->update(_st_stat_recvmsg_eagain);
+    _srs_pps_sendmsg->update(_st_stat_sendmsg); _srs_pps_sendmsg_eagain->update(_st_stat_sendmsg_eagain);
+    _srs_pps_sendmmsg->update(_st_stat_sendmmsg); _srs_pps_sendmmsg_eagain->update(_st_stat_sendmmsg_eagain);
+    if (_srs_pps_recvmsg->r10s() || _srs_pps_recvmsg_eagain->r10s() || _srs_pps_sendmsg->r10s() || _srs_pps_sendmsg_eagain->r10s() || _srs_pps_sendmmsg->r10s() || _srs_pps_sendmmsg_eagain->r10s()) {
+        snprintf(buf, sizeof(buf), ", msg=%d,%d,%d,%d,%d,%d",
+        _srs_pps_recvmsg->r10s(), _srs_pps_recvmsg_eagain->r10s(),
+        _srs_pps_sendmsg->r10s(), _srs_pps_sendmsg_eagain->r10s(),
+        _srs_pps_sendmmsg->r10s(), _srs_pps_sendmmsg_eagain->r10s()
+        );
+        msg_desc = buf;
+    }
+
+    srs_trace("Hybrid cpu=%.2f%%,%dMB%s%s%s%s%s%s",
         u->percent * 100, memory,
-        _srs_pps_cids_get->r10s(), _srs_pps_cids_set->r10s(),
+        cid_desc.c_str(), timer_desc.c_str(), free_desc.c_str(),
-        _srs_pps_timer->r10s(), _srs_pps_pub->r10s(), _srs_pps_conn->r10s(),
+        recvfrom_desc.c_str(), io_desc.c_str(), msg_desc.c_str()
-        _srs_pps_dispose->r10s()
     );
 
     return err;

trunk/src/app/srs_app_rtc_conn.cpp

@@ -1282,8 +1282,8 @@ srs_error_t SrsRtcPublishStream::send_periodic_twcc()
     if (last_time_send_twcc_) {
         uint32_t nn = 0;
         srs_utime_t duration = srs_duration(last_time_send_twcc_, srs_get_system_time());
-        if (duration > 80 * SRS_UTIME_MILLISECONDS && twcc_epp_->can_print(0, &nn)) {
+        if (duration > 100 * SRS_UTIME_MILLISECONDS && twcc_epp_->can_print(0, &nn)) {
-            srs_warn2(TAG_LARGE_TIMER, "send_twcc interval exceeded %dms > 80ms, count=%u/%u",
+            srs_warn2(TAG_LARGE_TIMER, "twcc delay %dms > 100ms, count=%u/%u",
                 srsu2msi(duration), nn, twcc_epp_->nn_count);
         }
     }