more logging

diff --git a/clients/playrtp-log b/clients/playrtp-log
new file mode 100755 (executable)
index 0000000..52e79e2
--- /dev/null
+++ b/clients/playrtp-log
@@ -0,0 +1,38 @@
+#! /usr/bin/perl -w
+use strict;
+
+our $last;
+my %start = ();
+my %end = ();
+while(<>) {
+    if(/sequence (\d+) timestamp (\w+) length (\w+) end (\w+)/) {
+       my $seq = $1;
+       my $timestamp = hex($2);
+       my $length = hex($3);
+       my $end = hex($4);
+
+       if(defined $last) {
+           if($seq < $last) {
+               print "$seq < $last\n";
+           } elsif($seq != $last + 1) {
+               printf "%u when %u expected, missed %d\n",
+               $seq, $last + 1, $seq - $last;
+           }
+       }
+       if(exists $start{$seq}) {
+           print "$seq: duplicate";
+       }
+       $start{$seq} = $timestamp;
+       $end{$seq} = $end;
+       if(exists $start{$seq-1}) {
+           if($end{$seq-1} != $start{$seq}) {
+               printf "%u ends at %x but %u starts at %x (delta=%d)\n",
+               $seq-1, $end{$seq-1}, $seq, $start{$seq},
+               $start{$seq}-$end{$seq-1};
+           }
+       }
+
+
+       $last = $seq;
+    }
+}

diff --git a/clients/playrtp.c b/clients/playrtp.c
index bf96e84285906267fe54631b7dc6fe21eb47a32b..fe9d1e287fa330bcb5ad94dcbeb432e66bac6678 100644 (file)
--- a/clients/playrtp.c
+++ b/clients/playrtp.c
@@ -51,6 +51,9 @@
 /** @brief RTP socket */
 static int rtpfd;
 
 /** @brief RTP socket */
 static int rtpfd;
 

+/** @brief Log output */
+static FILE *logfp;
+

 /** @brief Output device */
 static const char *device;
 
 /** @brief Output device */
 static const char *device;
 


@@ -200,8 +203,10 @@ static void *listen_thread(void attribute((unused)) *arg) {
       }
     }
     /* Ignore too-short packets */
       }
     }
     /* Ignore too-short packets */

-    if((size_t)n <= sizeof (struct rtp_header))
+    if((size_t)n <= sizeof (struct rtp_header)) {
+      info("ignored a short packet");

       continue;
       continue;

+    }

     p->timestamp = ntohl(packet.header.timestamp);
     /* Ignore packets in the past */
     if(active && lt(p->timestamp, next_timestamp)) {
     p->timestamp = ntohl(packet.header.timestamp);
     /* Ignore packets in the past */
     if(active && lt(p->timestamp, next_timestamp)) {


@@ -232,13 +237,20 @@ static void *listen_thread(void attribute((unused)) *arg) {
       fatal(0, "unsupported RTP payload type %d",
             packet.header.mpt & 0x7F);
     }
       fatal(0, "unsupported RTP payload type %d",
             packet.header.mpt & 0x7F);
     }

+    if(logfp)
+      fprintf(logfp, "sequence %u timestamp %"PRIx32" length %"PRIx32" end %"PRIx32"\n",
+              ntohs(packet.header.seq), 
+              p->timestamp, p->nsamples, p->timestamp + p->nsamples);

     pthread_mutex_lock(&lock);
     /* Stop reading if we've reached the maximum.
      *
      * This is rather unsatisfactory: it means that if packets get heavily
      * out of order then we guarantee dropouts.  But for now... */
     pthread_mutex_lock(&lock);
     /* Stop reading if we've reached the maximum.
      *
      * This is rather unsatisfactory: it means that if packets get heavily
      * out of order then we guarantee dropouts.  But for now... */

-    while(nsamples >= maxbuffer)
-      pthread_cond_wait(&cond, &lock);
+    if(nsamples >= maxbuffer) {
+      info("buffer full");
+      while(nsamples >= maxbuffer)
+        pthread_cond_wait(&cond, &lock);
+    }

     for(pp = &packets;
         *pp && lt((*pp)->timestamp, p->timestamp);
         pp = &(*pp)->next)
     for(pp = &packets;
         *pp && lt((*pp)->timestamp, p->timestamp);
         pp = &(*pp)->next)


@@ -323,14 +335,12 @@ static OSStatus adioproc
         next_timestamp += samples_available;
         samplesOut += samples_available;
         samplesOutLeft -= samples_available;
         next_timestamp += samples_available;
         samplesOut += samples_available;
         samplesOutLeft -= samples_available;

-        /* TODO log infill */

       } else {
         /* There's no next packet at all */
         info("infilled by %zu", samplesOutLeft);
         next_timestamp += samplesOutLeft;
         samplesOut += samplesOutLeft;
         samplesOutLeft = 0;
       } else {
         /* There's no next packet at all */
         info("infilled by %zu", samplesOutLeft);
         next_timestamp += samplesOutLeft;
         samplesOut += samplesOutLeft;
         samplesOutLeft = 0;

-        /* TODO log infill */

       }
     }
     ++ab;
       }
     }
     ++ab;


@@ -677,7 +687,7 @@ int main(int argc, char **argv) {
 
   mem_init();
   if(!setlocale(LC_CTYPE, "")) fatal(errno, "error calling setlocale");
 
   mem_init();
   if(!setlocale(LC_CTYPE, "")) fatal(errno, "error calling setlocale");

-  while((n = getopt_long(argc, argv, "hVdD:m:b:x:", options, 0)) >= 0) {
+  while((n = getopt_long(argc, argv, "hVdD:m:b:x:L:", options, 0)) >= 0) {

     switch(n) {
     case 'h': help();
     case 'V': version();
     switch(n) {
     case 'h': help();
     case 'V': version();


@@ -686,6 +696,7 @@ int main(int argc, char **argv) {
     case 'm': minbuffer = 2 * atol(optarg); break;
     case 'b': readahead = 2 * atol(optarg); break;
     case 'x': maxbuffer = 2 * atol(optarg); break;
     case 'm': minbuffer = 2 * atol(optarg); break;
     case 'b': readahead = 2 * atol(optarg); break;
     case 'x': maxbuffer = 2 * atol(optarg); break;

+    case 'L': logfp = fopen(optarg, "w"); break;

     default: fatal(0, "invalid option");
     }
   }
     default: fatal(0, "invalid option");
     }
   }