[rtmpdump] patch: fix hang using 100% cpu

Peter Miller pmiller at opensource.org.au
Fri Apr 8 09:36:53 CEST 2011


Hi Folks,

The attached patch is a fix for one of the bugs I am seeing, where rtmp
would hang using 100% cpu.  More description available in the patch
file.

The problem is the peer closing the connection.  A resume (running
rtmpdump again) is almost always successful, so next I'm going to see if
I can do that inside rtmpdump.  Suggestions and hints most welcome.

-- 
Regards
Peter Miller <pmiller at opensource.org.au>
/\/\*        http://miller.emu.id.au/pmiller/

PGP public key ID: 1024D/D0EDB64D
fingerprint = AD0A C5DF C426 4F03 5D53  2BDB 18D8 A4E2 D0ED B64D
See http://www.keyserver.net or any PGP keyserver for public key.

"Savor the unbridled complexity that we've crafted for you." -- Final
Cut Pro easter egg
-------------- next part --------------
MIME-Version: 1.0
Content-Type: application/aegis-patch
Subject: rtmpdump.2.3 - bug fix: hang using 100% CPU
Content-Name: rtmpdump.2.3.C017.patch
Content-Disposition: attachment; filename=rtmpdump.2.3.C017.patch
X-Aegis-Project-Name: rtmpdump.2.3
X-Aegis-Change-Number: 17

#	
#	This change set fixes a bug where sometimes rtmpdump would hang,
#	making no progress, and consuming 100% CPU.  It turns out the server
#	had closed the connection, but main() kept calling Download() forever,
#	because Download was reporting RD_INCOMPLETE instead of RD_FAILED, and
#	RD_INCOMPLETE would have been OK except that the connection had been
#	closed and the file descriptor was invalid.
#	
#	In order to improved the debugging messages a new function was added
#	(rtmp_read-status_name) to obtain the RTMP_Read status names as text.
#	
# Aegis-Change-Set-Begin
# QlpoMzFBWSZTWbXPzUYAARbfgAAQUmf/+i8v1g6/79/qQALdmm1rO12AaIRpT9U/UJ+qe1T2
# ppkPSgPUzUNGmEbUD1BqaaMmppoaU00AABkaBoA0AGmpqQ9TRoGhoGjQNAaAAAASRBGgU8kh
# +gp5I0NqHqD0Ieo0BtTfmNXv0geIMJPBOF80j5dpx4wDkNATgwfpYB6Xx0msdTqA3zOENJzR
# ooCIZiZMv2vzzMNWe+jWXWxAjecmtiZC5ygRNkI3FSaONkih/NMQKDl4djy4/bbBzEUobjTY
# H4AedE657XW23I1t6LlTTw5h1sfQcKkVB5gYXikg1gPBErGKnWtX7ImPeGekpFavUls7EbI+
# UGbG28TSTKRWUes9Bh7E08sayXGkZ3tCCLcRyKtbrsLK3RrUb3xs8WCng47O+rmEQ1RDMQu/
# kOevwTn5PuV/Axvk5fN4QJkhXIXgwaAJmhrmDnHiD9DFxKf+duVObMHDgW4m3hMb3YBxIneN
# 1177kX/7k2HObiqVqmnzHKhBQcZ9pdz9F+/irjn+O1t6Ko+OnfFu4ncQWb1A0QC1LYEtLFyH
# eA+4cgQctaWl4XPTjdfjFtAbjXtAbtIB1aDJ5hTVvp2bM+bAogVYgNu3p8MibMzclehokgIZ
# 5B2TxxrXYWUUyYQlxHXQxlbAsmIOUpUqU6MSXHT3uCKbBgVxYVdwAECAB4CIoSTbAJZVoTsQ
# aBZpsISOT1LzWod8w7EVV4E9et5Y7nqTIJ2LbSwm5ceRHWoPvMrBXw0OIIy1a7rADRJADjUl
# BCDIrCfoNKJAzWOWgg8OMEWyJCEonN4tErwuUApZFDhVySTWxgXlYSpwLUjDCUAcvTEWqxCE
# Mtleklj1aFXTInzJr8PZqsVFm2L25vFsvtJDxTl5KwhJ0ZTEz+2h05BOt6Ps7KrV0spTeN1j
# XAW6cbzypQQSIaHVrMRV4XoyMOo88AosAoWUk0UYyj0XMQqCIx0RBmsC6gH/F3JFOFCQtc/N
# Rg==
# Aegis-Change-Set-End
#
Index: librtmp/rtmp.c
--- librtmp/rtmp.c
+++ librtmp/rtmp.c
@@ -3518,11 +3518,25 @@
       if (sb->sb_ssl)
 	{
 	  nBytes = TLS_read(sb->sb_ssl, sb->sb_start + sb->sb_size, nBytes);
+          if (nBytes < 0)
+            {
+              RTMP_Log(RTMP_LOGDEBUG, "%s: %d: TLS_read failed: %s", __FILE__,
+                       __LINE__, TLS_get_error(sb->sb_ssl, nBytes));
+            }
 	}
       else
 #endif
 	{
 	  nBytes = recv(sb->sb_socket, sb->sb_start + sb->sb_size, nBytes, 0);
+          if (nBytes < 0)
+            {
+              /* The Australian ABC's content server has a nasty habit of
+               * dropping the connection if it decides you are slurping
+               * the data too fast. */
+              int err = errno;
+              RTMP_Log(RTMP_LOGDEBUG, "%s: %d: recv failed: %s", __FILE__,
+                       __LINE__, strerror(err));
+            }
 	}
       if (nBytes != -1)
 	{
@@ -4225,6 +4239,8 @@
   case RTMP_READ_ERROR:  /* corrupted stream, resume failed */
     SetSockError(EINVAL);
     return -1;
+
+  case RTMP_READ_IGNORE:
   default:
     break;
   }
@@ -4411,3 +4427,50 @@
     }
   return size+s2;
 }
+
+
+const char *
+rtmp_read_status_name(int status)
+{
+  switch (status)
+    {
+    case RTMP_READ_COMPLETE:
+      return "RTMP_READ_COMPLETE";
+
+    case RTMP_READ_ERROR:
+      return "RTMP_READ_ERROR";
+
+    case RTMP_READ_EOF:
+      return "RTMP_READ_EOF";
+
+    case RTMP_READ_IGNORE:
+      return "RTMP_READ_IGNORE";
+
+    default:
+      {
+        static char buffer[10];
+        snprintf(buffer, sizeof(buffer), "%d", status);
+        return buffer;
+      }
+    }
+}
+
+
+#ifdef USE_POLARSSL
+
+/* it defies belief, but PolarSSL doesn't supply an strerror equivalent */
+const char *
+TLS_get_error(void *a, int b)
+{
+  static char buf[100];
+  (void)a;
+  if (!b)
+    return "no error";
+  if (b < 0)
+    snprintf(buf, sizeof(buf), "error -0x%04X", -b);
+  else
+    snprintf(buf, sizeof(buf), "error 0x%04X", b);
+  return buf;
+}
+
+#endif
Index: librtmp/rtmp.h
--- librtmp/rtmp.h
+++ librtmp/rtmp.h
@@ -190,6 +190,8 @@
 #endif
   } RTMP_LNK;
 
+  const char *rtmp_read_status_name(int status);
+
   /* state for read() wrapper */
   typedef struct RTMP_READ
   {
Index: librtmp/rtmp_sys.h
--- librtmp/rtmp_sys.h
+++ librtmp/rtmp_sys.h
@@ -80,6 +80,20 @@
 #define TLS_shutdown(s)	ssl_close_notify(s)
 #define TLS_close(s)	ssl_free(s); free(s)
 
+/**
+  * The TLS_get_error function is used to obtain a human readable description
+  * of the given error, similar to the strerror(3) ANSI C function.
+  *
+  * Unbelievably, PolarSSL does not actually provide one.
+  * This dummy simply prints the error number.
+  *
+  * @param context
+  *     The connection context
+  * @param error_number
+  *     The number of the error to be described.
+  */
+const char *TLS_get_error(void *context, int error_number);
+
 #elif defined(USE_GNUTLS)
 #include <gnutls/gnutls.h>
 typedef struct tls_ctx {
@@ -94,6 +108,7 @@
 #define TLS_write(s,b,l)	gnutls_record_send(s,b,l)
 #define TLS_shutdown(s)	gnutls_bye(s, GNUTLS_SHUT_RDWR)
 #define TLS_close(s)	gnutls_deinit(s)
+#define TLS_get_error(a, b) gnutls_strerror(b)
 
 #else	/* USE_OPENSSL */
 #define TLS_CTX	SSL_CTX *
@@ -104,6 +119,7 @@
 #define TLS_write(s,b,l)	SSL_write(s,b,l)
 #define TLS_shutdown(s)	SSL_shutdown(s)
 #define TLS_close(s)	SSL_free(s)
+#define TLS_get_error(a, b) SSL_get_error(a, b)
 
 #endif
 #endif
Index: rtmpdump.c
--- rtmpdump.c
+++ rtmpdump.c
@@ -448,6 +448,7 @@
   int nRead = 0;
   off_t size = ftello(file);
   unsigned long lastPercent = 0;
+  int status;
 
   rtmp->m_read.timestamp = dSeek;
 
@@ -516,7 +517,9 @@
 	  if (fwrite(buffer, sizeof(unsigned char), nRead, file) !=
 	      (size_t) nRead)
 	    {
-	      RTMP_Log(RTMP_LOGERROR, "%s: Failed writing, exiting!", __FUNCTION__);
+              int err = errno;
+	      RTMP_Log(RTMP_LOGERROR, "%s: Failed writing (%s), exiting",
+                       __FUNCTION__, strerror(err));
 	      free(buffer);
 	      return RD_FAILED;
 	    }
@@ -578,15 +581,17 @@
 #ifdef _DEBUG
       else
 	{
-	  RTMP_Log(RTMP_LOGDEBUG, "zero read!");
+          if (nRead < 0)
+	    RTMP_Log(RTMP_LOGDEBUG, "read failed");
+          else
+	    RTMP_Log(RTMP_LOGDEBUG, "zero read");
 	}
 #endif
 
     }
   while (!RTMP_ctrlC && nRead > -1 && RTMP_IsConnected(rtmp) && !RTMP_IsTimedout(rtmp));
   free(buffer);
-  if (nRead < 0)
-    nRead = rtmp->m_read.status;
+  status = nRead < 0 ? rtmp->m_read.status : RTMP_READ_IGNORE;
 
   /* Final status update */
   if (!bHashes)
@@ -606,21 +611,28 @@
 	}
     }
 
-  RTMP_Log(RTMP_LOGDEBUG, "RTMP_Read returned: %d", nRead);
+  RTMP_Log(RTMP_LOGDEBUG, "RTMP_Read returned: %d bytes, status = %s (%d)",
+           nRead, rtmp_read_status_name(status), status);
 
-  if (bResume && nRead == -2)
+  if (status == RTMP_READ_ERROR)
     {
-      RTMP_LogPrintf("Couldn't resume FLV file, try --skip %d\n\n",
-		nSkipKeyFrames + 1);
+      if (bResume)
+        RTMP_LogPrintf("Couldn't resume FLV file, try --skip %d\n",
+		       nSkipKeyFrames + 1);
+      else
+        RTMP_LogPrintf("read failed\n");
       return RD_FAILED;
     }
 
-  if (nRead == -3)
+  /* why don't we handle the RTMP_READ_EOF status here as well? */
+  if (status == RTMP_READ_COMPLETE)
     return RD_SUCCESS;
 
-  if ((duration > 0 && *percent < 99.9) || RTMP_ctrlC || nRead < 0
+  if ((duration > 0 && *percent < 99.9) || RTMP_ctrlC
+      || status != RTMP_READ_IGNORE
       || RTMP_IsTimedout(rtmp))
     {
+      /* status==RTMP_READ_EOF arrives here.  can that be right? */
       return RD_INCOMPLETE;
     }
 
@@ -1343,6 +1355,12 @@
       free(initialFrame);
       initialFrame = NULL;
 
+      /* FIXME: in some cases of nstatus==RD_FAILED, the download could be
+       * resumed.  The output file would need to be closed, and the connection
+       * shut down properly, and first=1 set.  Probably need a retry limit of
+       * some sort, too.
+       */
+
       /* If we succeeded, we're done.
        */
       if (nStatus != RD_INCOMPLETE || !RTMP_IsTimedout(&rtmp) || bLiveStream)


More information about the rtmpdump mailing list