Tons of errors on client pause

[Diego Fantoma]

Dear all,

I successfully installed red5 0.9 trunk rev. 4047 on debian Lenny and it
works very well except when a client (consumer) invokes the pause method
generating over 1K similar error lines in the console log. After that
the client can't un-pause because the connection is lost so the user has
to refresh the page.

Has somebody the same error? I was looking for that error for a few days
but I didn't found any response.

Thank you in advance, follows the console log error

Diego Fantoma

[ERROR] [NioProcessor-1] org.red5.server.service.ServiceInvoker - Error
executing call: Service: null Method: pause Num Params: 2 0: true 1: 208359
[ERROR] [NioProcessor-1] org.red5.server.service.ServiceInvoker -
Service invocation error
java.lang.reflect.InvocationTargetException: null
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[na:1.6.0_12]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[na:1.6.0_12]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[na:1.6.0_12]
at java.lang.reflect.Method.invoke(Method.java:597) [na:1.6.0_12]
at
org.red5.server.service.ServiceInvoker.invoke(ServiceInvoker.java:200)
[red5.jar:na]
at
org.red5.server.net.rtmp.RTMPHandler.invokeCall(RTMPHandler.java:185)
[red5.jar:na]
at
org.red5.server.net.rtmp.RTMPHandler.onInvoke(RTMPHandler.java:393)
[red5.jar:na]
at
org.red5.server.net.rtmp.BaseRTMPHandler.messageReceived(BaseRTMPHandler.java:138)
[red5.jar:na]
at
org.red5.server.net.rtmp.RTMPMinaIoHandler.messageReceived(RTMPMinaIoHandler.java:180)
[red5.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:713)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.red5.server.net.filter.TrafficShapingFilter.messageReceived(TrafficShapingFilter.java:204)
[red5.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:383)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:229)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:708)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:665)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:654)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$500(AbstractPollingIoProcessor.java:64)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1111)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
[mina-core-2.0.0-RC2-SNAPSHOT.jar:na]
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[na:1.6.0_12]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[na:1.6.0_12]
at java.lang.Thread.run(Thread.java:619) [na:1.6.0_12]
java.lang.StackOverflowError: null
at
org.red5.server.stream.StreamService.pause(StreamService.java:183)
[red5.jar:na]
...
(OK - THERE ARE MORE 1013 ROWS SIMILAR TO THE LAST ONE)

[jez]

I'd like to report this very problem too. Very annoying. It used to
work, and now when my Flash applets pause, I get the exact same
'Service invocation error', even on 0.9 final. :-(

Best regards,
Jeremy Morton (Jez)

[jez]

I'm gonna add to this...

Having tested this further, this is an *catastrophic* error. I'm
going to have to downgrade to 0.8 or something posthaste.

It seems that pausing the client stream can cause some kind of service
invocation error. This effectively hangs the service, because from
then on until the service is restarted, this appears in
red5_service.log every time a client tries to connect to a stream:

=====
INFO | jvm 1 | 2010/02/20 15:12:37 | [INFO] [NioProcessor-1]
org.red5.server.net.rtmp.RTMPHandler - Connecting to: [WebScope@bdd2e7
Depth = 1, Path = '/default', Name = 'steamStream']
INFO | jvm 1 | 2010/02/20 15:12:37 | [INFO] [NioProcessor-1]
org.red5.server.net.rtmp.RTMPHandler - Remembering client buffer on
stream: 4000
INFO | jvm 1 | 2010/02/20 15:12:37 | [ERROR] [NioProcessor-1]

org.red5.server.service.ServiceInvoker - Error executing call:

Service: null Method: play Num Params: 4 0: 00c0022baab3 1: -1000 2:
-1000 3: 1
INFO | jvm 1 | 2010/02/20 15:12:37 | [ERROR] [NioProcessor-1]

org.red5.server.service.ServiceInvoker - Service invocation error

INFO | jvm 1 | 2010/02/20 15:12:37 |
java.lang.reflect.InvocationTargetException: null
INFO | jvm 1 | 2010/02/20 15:12:37 | at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [na:
1.6.0_11]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) [na:
1.6.0_11]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) [na:
1.6.0_11]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
java.lang.reflect.Method.invoke(Unknown Source) [na:1.6.0_11]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.service.ServiceInvoker.invoke(ServiceInvoker.java:200)
[red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.net.rtmp.RTMPHandler.invokeCall(RTMPHandler.java:186)
[red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.net.rtmp.RTMPHandler.onInvoke(RTMPHandler.java:395)
[red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.net.rtmp.BaseRTMPHandler.messageReceived(BaseRTMPHandler.java:
138) [red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.net.rtmp.RTMPMinaIoHandler.messageReceived(RTMPMinaIoHandler.java:
180) [red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain
$TailFilter.messageReceived(DefaultIoFilterChain.java:713) [mina-
core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:
434) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access
$1200(DefaultIoFilterChain.java:46) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl
$1.messageReceived(DefaultIoFilterChain.java:793) [mina-core-2.0.0-
RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.net.filter.TrafficShapingFilter.messageReceived(TrafficShapingFilter.java:
204) [red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:
434) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access
$1200(DefaultIoFilterChain.java:46) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl
$1.messageReceived(DefaultIoFilterChain.java:793) [mina-core-2.0.0-
RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.filter.codec.ProtocolCodecFilter
$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:375) [mina-
core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:
229) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:
434) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access
$1200(DefaultIoFilterChain.java:46) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl
$1.messageReceived(DefaultIoFilterChain.java:793) [mina-core-2.0.0-
RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:
119) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:
434) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:
426) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:
638) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:
598) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:
587) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access
$400(AbstractPollingIoProcessor.java:61) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.core.polling.AbstractPollingIoProcessor
$Processor.run(AbstractPollingIoProcessor.java:969) [mina-core-2.0.0-
RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:
64) [mina-core-2.0.0-RC1.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
[na:1.6.0_11]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:
1.6.0_11]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
java.lang.Thread.run(Unknown Source) [na:1.6.0_11]
INFO | jvm 1 | 2010/02/20 15:12:37 | Caused by:
java.lang.AbstractMethodError:
com.xuggle.red5.io.BroadcastStream.getMetaData()Lorg/red5/server/net/
rtmp/event/Notify;
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.stream.PlayEngine.playLive(PlayEngine.java:488)
[red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.stream.PlayEngine.play(PlayEngine.java:392)
[red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.stream.PlayEngine.play(PlayEngine.java:286)
[red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.stream.PlaylistSubscriberStream.play(PlaylistSubscriberStream.java:
226) [red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | at
org.red5.server.stream.StreamService.play(StreamService.java:299)
[red5.jar:na]
INFO | jvm 1 | 2010/02/20 15:12:37 | ... 34 common frames
omitted
=====

Mondain et al., how you could release something with this bug as a
'Final' version is beyond me. It's goddamn useless. I recommend you
fix this bug as a priority.

*sigh... goes to downgrade*

- Jez

[jez]

And downgrading to 0.9 RC2 seems to fix this problem. Looks like it
was introduced in Final.

- Jez

> ...
>
> read more »

[Mondain]

I would be glad to debug this if anyone having the issue would like to provide steps to reproduce it and maybe even a test swf?

Paul

[Andy Shaules]

I can try to make an error.

[Andy Shaules]

oh wow.

 

a thousand lines or more generated in a couple seconds and not ceasing until I disconnected.

 

Endless loop it seems.

 

to reproduce:

 

Start a record session and push pause.

 

 

 

____________

 

java.lang.reflect.InvocationTargetException: null

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [na:1.6.0_12]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [na:1.6.0_12]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [na:1.6.0_12]

at java.lang.reflect.Method.invoke(Method.java:597) [na:1.6.0_12]

at org.red5.server.service.ServiceInvoker.invoke(ServiceInvoker.java:200) [red5.jar:na]

at org.red5.server.net.rtmp.RTMPHandler.invokeCall(RTMPHandler.java:185) [red5.jar:na]

at org.red5.server.net.rtmp.RTMPHandler.onInvoke(RTMPHandler.java:393) [red5.jar:na]

at org.red5.server.net.rtmp.BaseRTMPHandler.messageReceived(BaseRTMPHandler.java:138) [red5.jar:na]

at org.red5.server.net.rtmp.RTMPMinaIoHandler.messageReceived(RTMPMinaIoHandler.java:180) [red5.jar:na]

at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:713) [mina-core-2.0.0-RC2-SNAPSHOT.jar:na]

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) [mina-core-2.0.0-RC2-SNAPSHOT.jar:na]

at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46) [mina-core-2.0.0-RC2-SNAPSHOT.jar:na]

at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793) [mina-core-2.0.0-RC2-SNAPSHOT.jar:na]

at org.red5.server.net.filter.TrafficShapingFilter.messageReceived(TrafficShapingFilter.java:204) [red5.jar:na]

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) [mina-core-2.0.0-RC2-SNAPSHOT.jar:na]

 

 

----- Original Message -----

From: Mondain

To: red5in...@googlegroups.com

Sent: Saturday, February 20, 2010 10:01 AM

Subject: Re: [Red5] Re: Tons of errors on client pause

[Andy Shaules]

Also, netstream send function throws a log error if there are no subscribers.

 

And finally, a publishing client will thrown an error if you refresh the page while publishing. Thats also a new one.

----- Original Message -----

From: Mondain

To: red5in...@googlegroups.com

Sent: Saturday, February 20, 2010 10:01 AM

Subject: Re: [Red5] Re: Tons of errors on client pause

[Diego Fantoma]

I have the error with the 0.9.0 final revision 4047 build #318 (also
trying
http://build.xuggle.com/view/Red5%20Dashboard/job/red5_jdk6_stable/),
both using the precompiled version or building it by myself on debian
lenny core install with the sun-java6 jvm and the ant package.

The error is blocking on the "viewer" client while streaming from
webcam, while streaming a file the error is raised but it is not
blocking (the pause works as expected, it just produces thousands rows
in the log).

In the beginning og the log I see that while invoking the pause red5
expects 2 extra, not defined, parameters.

I don't tried previous or RC versions.

May the new build (#321) works?

Hoping this would be soon fixed,
diego fantoma

Andy Shaules wrote:
> Also, netstream send function throws a log error if there are no
> subscribers.
>
> And finally, a publishing client will thrown an error if you refresh
> the page while publishing. Thats also a new one.
>
> ----- Original Message -----

> *From:* Mondain <mailto:mon...@gmail.com>
> *To:* red5in...@googlegroups.com
> <mailto:red5in...@googlegroups.com>
> *Sent:* Saturday, February 20, 2010 10:01 AM
> *Subject:* Re: [Red5] Re: Tons of errors on client pause

[Mondain]

Ok, I'll look into this tonight on trunk.. then maybe if I can fix it, I'll do a patch for 0.9.

--
http://gregoire.org/
http://code.google.com/p/red5/
http://code.google.com/p/blue5/

[Mondain]

This is now fixed on trunk, java seemed to get confused on the pause(boolean, int) vs. pause(Boolean, int) and thus stack overflowed. Not sure how I want to handle a patch for 0.9 yet.. maybe a 0.9.1 release?

Paul

[Gergely Zayzon]

Sounds like a good idea.

Regards,
Gergely Zayzon

[Diego Fantoma]

Nice! It works, finally!

Thank you very much!
d