[Asterisk-video] app_rtsp: asterisk hangup(exceptionallylong queue)

Sun Sep 16 05:13:05 CDT 2007

It's normal that you use 100%, you are just making the following:

 exten => stream,4,Nothing
 exten => stream,5,Goto(4)

:)

I'll try to take a look to see why the long queue is producced..

Best regards
Sergio

----- Original Message ----- 
From: "Sergio Garcia Murillo" <sergio.garcia at fontventa.com>
To: "Development discussion of video media support in Asterisk"
<asterisk-video at lists.digium.com>
Sent: Thursday, September 13, 2007 11:30 PM
Subject: Re: [Asterisk-video] app_rtsp: asterisk hangup(exceptionallylong
queue)

> Great!!
> I'll take a look at it and hope to have it resolved for monday.
>
> Best regards
> Sergio
>
> ----- Original Message ----- 
> From: "Thomas Frieling" <thomas.frieling at viif.de>
> To: "Development discussion of video media support in Asterisk"
> <asterisk-video at lists.digium.com>
> Sent: Wednesday, September 12, 2007 6:31 PM
> Subject: Re: [Asterisk-video] app_rtsp: asterisk hangup (exceptionallylong
> queue)
>
>
> > Hey guys!
> >
> > Earlier this day I found out that this "exceptionally long queue" bug is
> > easily reproduceable in cooperation with another application we use.
> > This was due to a loop which started a rtsp-stream of a non-existent
> > video several times a second.
> >
> > So I just translated this to extensions.conf and now I can reproduce
> > within seconds... Check it out:
> >
> > exten => stream,1,h324m_gw_answer
> > exten => stream,2,mp4play(/usr/local/movies/logo.mp4)
> > exten => stream,3,mp4play(/usr/local/movies/logo.mp4)
> > exten => stream,4,rtsp(rtsp://${DSS}:554/static/nonPresentVideo.mp4)
> > exten => stream,5,Goto(4)
> > exten => stream,6,Hangup
> >
> > This, of course, is not a very realistic scenario, but this way we can
> > find out easily what fills up the queue without having to wait for six
> > minutes.
> >
> > Another thing:
> > When you try this using a SIP-phone you'll end up with a CPU load of
> > 100% but you won't get the "exceptionally long queue"-warnings.
> > "sip show channels" also shows that the call has not been hung up
> > correctly although the SIP-phone itself says different. The loop seems
> > to go on in the background.
> >
> >
> > Hope this helps debugging,
> > Thomas
> >
> >
> > Am Mittwoch, den 12.09.2007, 00:02 +0200 schrieb Sergio Garcia Murillo:
> > > You're right perhaps it's not everything related whith bandwith, as
the
> > > frames should be queued inside
> > > of the libh324m and not in the local channel.
> > > I'll try to think more about it to see what could be happening.
> > >
> > > BR
> > > Sergio
> > >
> > > ----- Original Message ----- 
> > > From: "Thomas Frieling" <thomas.frieling at viif.de>
> > > To: "Development discussion of video media support in Asterisk"
> > > <asterisk-video at lists.digium.com>
> > > Sent: Tuesday, September 11, 2007 6:21 PM
> > > Subject: Re: [Asterisk-video] app_rtsp: asterisk hangup
> > >
> > >
> > > > OK I understand this... But don't you think we should check the
buffer
> > > > periodically and maybe clear it or even hangup before it is too
late?
> > > >
> > > > I just reproduced the problem two times by looping four videos (each
> ~10
> > > > seconds) all the time with app_rtsp. After about five or six minutes
> the
> > > > problem occured again (the errors and 100% CPU load). Since the
videos
> > > > were played correctly for about ten times before the crash, maybe
our
> > > > guess about the too high framerate is incorrect.
> > > >
> > > > How can I find out which queue it is exactly which causes the
problem
> > > > and maybe see when it is filled up?
> > > >
> > > > BR,
> > > > Thomas
> > > >
> > > > PS: here are some logs:
> > > >
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -Received rtcp [164]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -Received rtcp length
[84]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -rtcp type [200,28]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -rtcp type [202,56]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -rtcp type [204,84]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -Started playback [10000]
> > > > [Sep 11 17:34:22] ERROR[30677] app_rtsp.c: -Received rtcp [164]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -Received rtcp length
[84]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -rtcp type [200,28]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -rtcp type [202,56]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -rtcp type [204,84]
> > > > [Sep 11 17:34:15] ERROR[30677] app_rtsp.c: -Started playback [10000]
> > > > [Sep 11 17:34:22] ERROR[30677] app_rtsp.c: -Received rtcp [164]
> > > > [Sep 11 17:34:22] ERROR[30677] app_rtsp.c: -Received rtcp length
[84]
> > > > [Sep 11 17:34:22] ERROR[30677] app_rtsp.c: -rtcp type [200,28]
> > > > [Sep 11 17:34:22] ERROR[30677] app_rtsp.c: -rtcp type [202,56]
> > > > [Sep 11 17:34:22] ERROR[30677] app_rtsp.c: -rtcp type [204,84]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: Playback finished
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -rtsp_play end loop[Sep
> 11
> > > > 17:34:25] WARNING[30677] app_rtsp.c: -TEARDOWN
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: <rtsp_play[Sep 11
> 17:34:25]
> > > > WARNING[30677] app_rtsp.c: >rtsp play
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: >DESCRIBE
> > > > [/static/intro-b.mp4]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: <DESCRIBE
> > > > [/static/intro-b.mp4]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -rtsp play loop
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -Receiving describe
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [v=0]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
[o=StreamingServer
> > > > 3398513665 1189517873000 IN IP4 127.0.0.1]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
> > > > [s=/static/intro-b.mp4]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [u=http:///]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [e=admin@]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [c=IN IP4
0.0.0.0]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [b=AS:29]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [t=0 0]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=control:*]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=x-copyright:
> > > > MP4/3GP File hinted with GPAC 0.4.5-DEV (C)2000-2005 -
> > > > http://gpac.sourceforge.net]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=range:npt=0-
> > > > 10.00000]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [m=video 0
RTP/AVP
> > > > 96]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -creating media
> [1,m=video
> > > > 0 RTP/AVP 96]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
> [a=control:trackID=2]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=rtpmap:96
> > > > H263-2000/15]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
> > > > [a=cliprect:0,0,144,176]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [Content-Base:
> > > > rtsp://127.0.0.1/static/intro-b.mp4/]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [v=0]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
[o=StreamingServer
> > > > 3398513665 1189517873000 IN IP4 127.0.0.1]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
> > > > [s=/static/intro-b.mp4]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [u=http:///]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [e=admin@]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [c=IN IP4
0.0.0.0]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [b=AS:29]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [t=0 0]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=control:*]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=x-copyright:
> > > > MP4/3GP File hinted with GPAC 0.4.5-DEV (C)2000-2005 -
> > > > http://gpac.sourceforge.net]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=range:npt=0-
> > > > 10.00000]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [m=video 0
RTP/AVP
> > > > 96]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -creating media
> [1,m=video
> > > > 0 RTP/AVP 96]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
> [a=control:trackID=2]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line [a=rtpmap:96
> > > > H263-2000/15]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -line
> > > > [a=cliprect:0,0,144,176]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -video
> > > > [1048576,96,trackID=2]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -SETUP VIDEO
[trackID=2]
> > > > [Sep 11 17:34:25] WARNING[30677] app_rtsp.c: -PLAY
> [/static/intro-b.mp4]
> > > > [Sep 11 17:34:25] ERROR[30677] app_rtsp.c: -Started playback [10000]
> > > > [Sep 11 17:34:25] ERROR[30677] app_rtsp.c: -Received rtcp [166]
> > > > [Sep 11 17:34:25] ERROR[30677] app_rtsp.c: -Received rtcp length
[84]
> > > > [Sep 11 17:34:25] ERROR[30677] app_rtsp.c: -rtcp type [200,28]
> > > > [Sep 11 17:34:25] ERROR[30677] app_rtsp.c: -rtcp type [202,56]
> > > > [Sep 11 17:34:25] ERROR[30677] app_rtsp.c: -rtcp type [204,84]
> > > > [Sep 11 17:34:32] ERROR[30677] app_rtsp.c: -Received rtcp [166]
> > > > [Sep 11 17:34:32] ERROR[30677] app_rtsp.c: -Received rtcp length
[84]
> > > > [Sep 11 17:34:32] ERROR[30677] app_rtsp.c: -rtcp type [200,28]
> > > > [Sep 11 17:34:32] ERROR[30677] app_rtsp.c: -rtcp type [202,56]
> > > > [Sep 11 17:34:32] ERROR[30677] app_rtsp.c: -rtcp type [204,84]
> > > > [Sep 11 17:34:35] WARNING[30677] app_rtsp.c: Playback finished
> > > > [Sep 11 17:34:35] WARNING[30677] app_rtsp.c: -rtsp_play end loop[Sep
> 11
> > > > 17:34:35] WARNING[30677] app_rtsp.c: -TEARDOWN
> > > > [Sep 11 17:34:35] WARNING[30677] app_rtsp.c: <rtsp_play[Sep 11
> 17:34:35]
> > > > WARNING[30677] app_rtsp.c: >rtsp play
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [Sep 11 17:34:36] WARNING[30676] channel.c: Exceptionally long queue
> > > > length queuing to Local/stream at video-9710,2
> > > > [...]
> > > >
> > > >
> > > > Am Dienstag, den 11.09.2007, 16:53 +0200 schrieb Sergio Garcia:
> > > > >
> > > > > It could be possible to implement it, but you'll have to drop all
> the
> > > frames
> > > > > until the next I frame. And if the bandwith is so high you'll end
up
> > > droping
> > > > > almost instantaneously the next frames. And even that way the I
> frame is
> > > going
> > > > > to arrive late and not be synchronized with audio..
> > > > >
> > > > > So if you want to offer any kind of quality service the only
option
> is
> > > using
> > > > > videos encoded at the best bitrate according it's use. You may
even
> find
> > > that
> > > > > you have to encode the same video at different bitrates for
> different
> > > kind of
> > > > > access.
> > > > >
> > > > > BR
> > > > > Sergio
> > > > >
> > > > > ---------- Original Message ----------------------------------
> > > > > From: Thomas Frieling <thomas.frieling at viif.de>
> > > > > Reply-To: Development discussion of video media support in
> > > Asterisk<asterisk-video at lists.digium.com>
> > > > > Date:  Tue, 11 Sep 2007 16:44:52 +0200
> > > > >
> > > > > >Hi Klaus!
> > > > > >
> > > > > >Sounds pretty convincing to me... But if this is really the case,
> then
> > > > > >we should definitely handle this problem before it occurs: Maybe
we
> can
> > > > > >check the queue's size before sending a package and decide to
skip
> some
> > > > > >packages to synchronize the outgoing stream.
> > > > > >This would help keeping sound and video synchronous and it would
> > > prevent
> > > > > >the "exceptionally long queue" error.
> > > > > >
> > > > > >What do you think about this? Would it be hard to implement?
> > > > > >
> > > > > >Greetings,
> > > > > >Thomas
> > > > > >
> > > > > >Am Montag, den 10.09.2007, 09:35 +0200 schrieb Klaus Darilion:
> > > > > >> Thomas Frieling schrieb:
> > > > > >> > Hi all!
> > > > > >> >
> > > > > >> > When using app_rtsp with a 3G handset extensively asterisk
> starts
> > > > > >> > consuming 100% of the CPU and the following error appears
very
> > > often
> > > > > >> > (~80 times a second) on the CLI:
> > > > > >> >
> > > > > >> > [Sep  7 12:52:55] WARNING[11822]: channel.c:924
> ast_queue_frame:
> > > > > >> > Exceptionally long queue length queuing to
> > > Local/stream at video-bad8,2
> > > > > >> >
> > > > > >> > Does anyone know what this warning means or where it comes
> from?
> > > Which
> > > > > >> > logfile should I (or anyone who'd like to) take a look at?
> > > > > >>
> > > > > >>
> > > > > >> I guess the framerate received from app_rtsp is bigger then the
> > > > > >> framerate received from the h324m connection. Every time
h324m_gw
> > > reads
> > > > > >> a frame from the incoming 64kbit data call, it writes an frame
to
> the
> > > > > >> data call too.
> > > > > >>
> > > > > >> Thus if app_rtsp feeds to many frames the queue buffer might
> grow.
> > > > > >>
> > > > > >> btw: shouldn't the pseudo channel (Local/..) be gone when
> app_rtsp
> > > > > >> answers the call?
> > > > > >>
> > > > > >> regards
> > > > > >> klaus
> > > > > >>
> > > > > >> _______________________________________________
> > > > > >> --Bandwidth and Colocation Provided by
> http://www.api-digital.com--
> > > > > >>
> > > > > >> asterisk-video mailing list
> > > > > >> To UNSUBSCRIBE or update options visit:
> > > > > >>    http://lists.digium.com/mailman/listinfo/asterisk-video
> > > > > >-- 
> > > > > >www.ViiF.de - your Mobile Video Community
> > > > > >
> > > > > >~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> > > > > >
> > > > > >Thomas Frieling - IT Development
> > > > > >ViiF Mobile Video GmbH, Poststr. 21-22, 10178 Berlin
> > > > > >Cell: +49 (0) 173 63 62 62 3
> > > > > >
> > > > > >mailto:thomas at ViiF.de
> > > > > >
> > > > > >Sitz: Berlin, Amtgericht Berlin-Charlottenburg, HRB: 108350B
> > > > > >
> > > > > >GeschÃ¤ftsfÃ¼hrer: Daniel HÃ¶pfner, Steffen BrÃ¼nn
> > > > > >
> > > > > >~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> > > > > >
> > > > > >_______________________________________________
> > > > > >--Bandwidth and Colocation Provided by
http://www.api-digital.com--
> > > > > >
> > > > > >asterisk-video mailing list
> > > > > >To UNSUBSCRIBE or update options visit:
> > > > > >   http://lists.digium.com/mailman/listinfo/asterisk-video
> > > > >
> > > > >
> > > > >
> > > > > _______________________________________________
> > > > > --Bandwidth and Colocation Provided by
http://www.api-digital.com--
> > > > >
> > > > > asterisk-video mailing list
> > > > > To UNSUBSCRIBE or update options visit:
> > > > >    http://lists.digium.com/mailman/listinfo/asterisk-video
> > > > -- 
> > > > www.ViiF.de - your Mobile Video Community
> > > >
> > > > ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> > > >
> > > > Thomas Frieling - IT Development
> > > > ViiF Mobile Video GmbH, Poststr. 21-22, 10178 Berlin
> > > > Cell: +49 (0) 173 63 62 62 3
> > > >
> > > > mailto:thomas at ViiF.de
> > > >
> > > > Sitz: Berlin, Amtgericht Berlin-Charlottenburg, HRB: 108350B
> > > >
> > > > Geschäftsführer: Daniel Höpfner, Steffen Brünn
> > > >
> > > > ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> > > >
> > > > _______________________________________________
> > > > --Bandwidth and Colocation Provided by http://www.api-digital.com--
> > > >
> > > > asterisk-video mailing list
> > > > To UNSUBSCRIBE or update options visit:
> > > >    http://lists.digium.com/mailman/listinfo/asterisk-video
> > >
> > >
> > > _______________________________________________
> > > --Bandwidth and Colocation Provided by http://www.api-digital.com--
> > >
> > > asterisk-video mailing list
> > > To UNSUBSCRIBE or update options visit:
> > >    http://lists.digium.com/mailman/listinfo/asterisk-video
> > -- 
> > www.ViiF.de - your Mobile Video Community
> >
> > ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> >
> > Thomas Frieling - IT Development
> > ViiF Mobile Video GmbH, Poststr. 21-22, 10178 Berlin
> > Cell: +49 (0) 173 63 62 62 3
> >
> > mailto:thomas at ViiF.de
> >
> > Sitz: Berlin, Amtgericht Berlin-Charlottenburg, HRB: 108350B
> >
> > Geschäftsführer: Daniel Höpfner, Steffen Brünn
> >
> > ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> >
> > _______________________________________________
> > --Bandwidth and Colocation Provided by http://www.api-digital.com--
> >
> > asterisk-video mailing list
> > To UNSUBSCRIBE or update options visit:
> >    http://lists.digium.com/mailman/listinfo/asterisk-video
>
>
> _______________________________________________
> --Bandwidth and Colocation Provided by http://www.api-digital.com--
>
> asterisk-video mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-video