From patchwork Sat Sep 3 08:47:17 2005 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Reinhard Nissl X-Patchwork-Id: 12002 Received: from mail.gmx.de ([213.165.64.20] helo=mail.gmx.net) by www.linuxtv.org with smtp (Exim 4.34) id 1EBTgo-0005Ve-FN for vdr@linuxtv.org; Sat, 03 Sep 2005 10:47:54 +0200 Received: (qmail invoked by alias); 03 Sep 2005 08:47:18 -0000 Received: from ambg-d9b97cb5.pool.mediaWays.net (EHLO [192.168.101.15]) [217.185.124.181] by mail.gmx.net (mp025) with SMTP; 03 Sep 2005 10:47:18 +0200 X-Authenticated: #527675 Message-ID: <43196315.4090603@gmx.de> Date: Sat, 03 Sep 2005 10:47:17 +0200 From: Reinhard Nissl User-Agent: Mozilla Thunderbird 1.0 (X11/20041207) X-Accept-Language: en-us, en MIME-Version: 1.0 To: Klaus Schmidinger's VDR X-Y-GMX-Trusted: 0 Subject: [vdr] INVITATION: help debugging cAudioRepacker X-BeenThere: vdr@linuxtv.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Klaus Schmidinger's VDR List-Id: Klaus Schmidinger's VDR List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 03 Sep 2005 08:47:54 -0000 Status: O X-Status: X-Keywords: X-UID: 4711 Hi, as some people seem to get messages like the following several seconds (> 60) after switching to a certain channel (or after a recording has switched a device) Sep 2 11:12:49 video vdr[14940]: cAudioRepacker: skipped 911 bytes to sync on next audio frame Sep 2 11:12:49 video vdr[14940]: cAudioRepacker: skipped 785 bytes to sync on next audio frame Sep 2 11:12:50 video vdr[14940]: cAudioRepacker: skipped 221 bytes to sync on next audio frame it may be likely that there is a bug in cAudioRepacker. Therefore I've added some debug output to possibly identify a bug. The attached patch is against vanilla VDR-1.3.31 and contains all my previously released patches since VDR-1.3.31 plus the new debug messages. As I experience such messages only rarely it takes quite some time to wait for the next log message and there are only about 30 hours left before VDR-1.3.32 is likely to be released. So I really invite you to help debugging this issue. Please send any such messages to the list or maybe to me privately. But be aware: I'm not interested in the messages that happen immediately after tuning the device! Especially VDR-1.3.31 reports sometimes a lot of them, as waiting for the tuner getting locked was removed. There is nothing special about these messages. To make it clear once more: just send such messages that happen for example 60 seconds after the last tuning activity (log message: "switching to channel X" or "switching device X to channel Y"). The sent log messages should also include the lines which allow to identy the thread that drives cAudioRepacker. Typically these log messages (like "transfer thread started" or "recording thread started") follow the switching messages. NPTL users: please turn off NPTL for this test (by defining an environment variable: export LD_ASSUME_KERNEL=2.4.1) as it is not possible to indentify the reporting thread otherwise. Bye. --- ../vdr-1.3.31-orig/remux.c 2005-08-28 13:46:44.000000000 +0200 +++ remux.c 2005-09-02 23:13:50.000000000 +0200 @@ -142,7 +142,7 @@ void cCommonRepacker::Reset(void) { cRepacker::Reset(); skippedBytes = 0; - packetTodo = maxPacketSize - 6 - 3; + packetTodo = 0; fragmentLen = 0; pesHeaderLen = 0; pesHeaderBackupLen = 0; @@ -361,7 +361,7 @@ void cVideoRepacker::Repack(cRingBufferL done++; todo--; // do we have to start a new packet as there is no more space left? - if (--packetTodo <= 0) { + if (state != syncing && --packetTodo <= 0) { // we connot start a new packet here if the current might end in a start // code and this start code shall possibly be put in the next packet. So // overfill the current packet until we can safely detect that we won't @@ -468,6 +468,9 @@ void cVideoRepacker::Repack(cRingBufferL int cVideoRepacker::BreakAt(const uchar *Data, int Count) { + if (initiallySyncing) + return -1; // fill the packet buffer completely until we have synced once + int PesPayloadOffset = 0; if (AnalyzePesHeader(Data, Count, PesPayloadOffset) <= phInvalid) @@ -513,9 +516,10 @@ private: } state; int frameTodo; int frameSize; - static bool IsValidAudioHeader(uint32_t Header, bool Mpeg2, int *FrameSize = NULL); + int cid; + /* static */ bool IsValidAudioHeader(uint32_t Header, bool Mpeg2, int *FrameSize = NULL); public: - cAudioRepacker(void); + cAudioRepacker(int Cid); virtual void Reset(void); virtual void Repack(cRingBufferLinear *ResultBuffer, const uchar *Data, int Count); virtual int BreakAt(const uchar *Data, int Count); @@ -536,8 +540,9 @@ int cAudioRepacker::bitRates[2][3][16] = 0, 8, 16, 24, 32, 40, 48, 56, 64, 80, 96, 112, 128, 144, 160, -1 }; -cAudioRepacker::cAudioRepacker(void) +cAudioRepacker::cAudioRepacker(int Cid) { + cid = Cid; Reset(); } @@ -566,23 +571,41 @@ bool cAudioRepacker::IsValidAudioHeader( //int orignal_copy = (Header & 0x00000004) >> 2; int emphasis = (Header & 0x00000003); - if (syncword != 0xFFF) + if (syncword != 0xFFF) { + if (FrameSize) + esyslog("cAudioRepacker(0x%02X): invalid audio header 0x%08X: syncword", cid, Header); return false; + } - if (id == 0 && !Mpeg2) // reserved in MPEG 1 + if (id == 0 && !Mpeg2) { // reserved in MPEG 1 + if (FrameSize) + esyslog("cAudioRepacker(0x%02X): invalid audio header 0x%08X: id", cid, Header); return false; + } - if (layer == 0) // reserved + if (layer == 0) { // reserved + if (FrameSize) + esyslog("cAudioRepacker(0x%02X): invalid audio header 0x%08X: layer", cid, Header); return false; + } - if (bitrate_index == 0xF) // forbidden + if (bitrate_index == 0xF) { // forbidden + if (FrameSize) + esyslog("cAudioRepacker(0x%02X): invalid audio header 0x%08X: bitrate_index", cid, Header); return false; + } - if (sampling_frequency == 3) // reserved + if (sampling_frequency == 3) { // reserved + if (FrameSize) + esyslog("cAudioRepacker(0x%02X): invalid audio header 0x%08X: sampling_frequency", cid, Header); return false; + } - if (emphasis == 2) // reserved + if (emphasis == 2) { // reserved + if (FrameSize) + esyslog("cAudioRepacker(0x%02X): invalid audio header 0x%08X: emphasis", cid, Header); return false; + } if (FrameSize) { if (bitrate_index == 0) @@ -649,12 +672,9 @@ void cAudioRepacker::Repack(cRingBufferL const uchar *payload = data; while (todo > 0) { - // collect number of skipped bytes while syncing - if (state <= syncing) - skippedBytes++; - else if (frameTodo > 0) { - frameTodo--; - if (frameTodo == 0 && state == scanFrame) { + // do we have to start a new packet as the current is done? + if (frameTodo > 0) { + if (--frameTodo == 0) { // the current audio frame is is done now. So push out the packet to // start a new packet for the next audio frame. PushOutPacket(ResultBuffer, payload, data - payload); @@ -662,10 +682,14 @@ void cAudioRepacker::Repack(cRingBufferL state = syncing; } } + // collect number of skipped bytes while syncing + if (state <= syncing) + skippedBytes++; // did we reach an audio frame header? scanner <<= 8; scanner |= *data; if ((scanner & 0xFFF00000) == 0xFFF00000) { + int LastFrameSize = frameSize; if (frameTodo <= 0 && IsValidAudioHeader(scanner, mpegLevel == phMPEG2, &frameSize)) { if (state == scanFrame) { // As a new audio frame starts here, the previous one is done. So push @@ -678,10 +702,15 @@ void cAudioRepacker::Repack(cRingBufferL state = syncing; } if (state == syncing) { + // report a change of frame size + if (!initiallySyncing && LastFrameSize != frameSize) + esyslog("cAudioRepacker(0x%02X): frame size changes from %d to %d", cid, LastFrameSize, frameSize); if (initiallySyncing) // omit report for the typical initial case initiallySyncing = false; - else if (skippedBytes > SkippedBytesLimit) // report that syncing dropped some bytes - esyslog("cAudioRepacker: skipped %d bytes to sync on next audio frame", skippedBytes - SkippedBytesLimit); + else if (skippedBytes > SkippedBytesLimit) { // report that syncing dropped some bytes + esyslog("cAudioRepacker(0x%02X): skipped %d bytes to sync on next audio frame", cid, skippedBytes - SkippedBytesLimit); + esyslog("cAudioRepacker(0x%02X): synchronization based on this header: 0x%08X, frame size: %d", cid, scanner, frameSize); + } skippedBytes = 0; // if there is a PES header available, then use it ... if (pesHeaderBackupLen > 0) { @@ -728,11 +757,13 @@ void cAudioRepacker::Repack(cRingBufferL } } } + else if (skippedBytes == SkippedBytesLimit) + esyslog("cAudioRepacker(0x%02X): no valid audio frame header (0x%08X) at expected location", cid, scanner); data++; done++; todo--; // do we have to start a new packet as there is no more space left? - if (--packetTodo <= 0) { + if (state != syncing && --packetTodo <= 0) { // We connot start a new packet here if the current might end in an audio // frame header and this header shall possibly be put in the next packet. So // overfill the current packet until we can safely detect that we won't @@ -829,13 +860,16 @@ void cAudioRepacker::Repack(cRingBufferL // report that syncing dropped some bytes if (skippedBytes > SkippedBytesLimit) { if (!initiallySyncing) // omit report for the typical initial case - esyslog("cAudioRepacker: skipped %d bytes while syncing on next audio frame", skippedBytes - SkippedBytesLimit); + esyslog("cAudioRepacker(0x%02X): skipped %d bytes while syncing on next audio frame", cid, skippedBytes - SkippedBytesLimit); skippedBytes = SkippedBytesLimit; } } int cAudioRepacker::BreakAt(const uchar *Data, int Count) { + if (initiallySyncing) + return -1; // fill the packet buffer completely until we have synced once + int PesPayloadOffset = 0; ePesHeader MpegLevel = AnalyzePesHeader(Data, Count, PesPayloadOffset); @@ -1189,6 +1223,9 @@ void cDolbyRepacker::Repack(cRingBufferL int cDolbyRepacker::BreakAt(const uchar *Data, int Count) { + if (initiallySyncing) + return -1; // fill the packet buffer completely until we have synced once + // enough data for test? if (Count < 6 + 3) return -1; @@ -1514,8 +1551,10 @@ void cTS2PES::instant_repack(const uint8 } if (mpeg == 1) { if (flag1 == 0xFF) { // MPEG1 stuffing - if (++mpeg1_stuffing > 16) + if (++mpeg1_stuffing > 16) { found = 0; // invalid MPEG1 header + esyslog("instant_repack: invalid MPEG1 header: stuffing"); + } else { // ignore stuffing found--; if (plength > 0) @@ -1524,8 +1563,10 @@ void cTS2PES::instant_repack(const uint8 } else if ((flag1 & 0xC0) == 0x40) // STD_buffer_scale/size mpeg1_required += 2; - else if (flag1 != 0x0F && (flag1 & 0xF0) != 0x20 && (flag1 & 0xF0) != 0x30) + else if (flag1 != 0x0F && (flag1 & 0xF0) != 0x20 && (flag1 & 0xF0) != 0x30) { found = 0; // invalid MPEG1 header + esyslog("instant_repack: invalid MPEG1 header: required 7"); + } else { flag2 = 0; hlength = 0; @@ -1543,8 +1584,10 @@ void cTS2PES::instant_repack(const uint8 if (!done && (mpeg == 2 || mpeg1_required > 7)) { hlength = Buf[c++]; found++; - if (mpeg == 1 && hlength != 0x0F && (hlength & 0xF0) != 0x20 && (hlength & 0xF0) != 0x30) + if (mpeg == 1 && hlength != 0x0F && (hlength & 0xF0) != 0x20 && (hlength & 0xF0) != 0x30) { found = 0; // invalid MPEG1 header + esyslog("instant_repack: invalid MPEG1 header: required 9"); + } } break; default: @@ -1685,13 +1728,15 @@ cRemux::cRemux(int VPid, const int *APid #endif if (APids) { int n = 0; - while (*APids && numTracks < MAXTRACKS && n < MAXAPIDS) + while (*APids && numTracks < MAXTRACKS && n < MAXAPIDS) { #define TEST_cAudioRepacker #ifdef TEST_cAudioRepacker - ts2pes[numTracks++] = new cTS2PES(*APids++, resultBuffer, IPACKS, 0xC0 + n++, 0x00, new cAudioRepacker); + ts2pes[numTracks++] = new cTS2PES(*APids++, resultBuffer, IPACKS, 0xC0 + n, 0x00, new cAudioRepacker(0xC0 + n)); + n++; #else ts2pes[numTracks++] = new cTS2PES(*APids++, resultBuffer, IPACKS, 0xC0 + n++); #endif + } } if (DPids) { int n = 0;