search

google-code-export / red5

Automatically exported from code.google.com/p/red5
0 stars 0 forks source link

slow session closing #422

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?
1.Open a rtmp connection
2.Close a rtmp connection while web browser is closing

What is the expected output? 
The Red5 application is immediately notified of the end of the connection.

What do you see instead?
It takes about 30 seconds, until the Red5 application is notified about the end 
of the connection.

2013-08-09 23:52:04,212 [NioProcessor-7] INFO  o.r.s.net.rtmp.RTMPMinaIoHandler 
- Session opened: 6 id: XASUTZIJ2Z4QE
2013-08-09 23:52:04,340 [RTMPExecutor#XASUTZIJ2Z4QE-1] INFO  Red5.appl - W3C 
x-category:session x-event:connect c-ip:192.168.1.104 c-client-id:5
2013-08-09 23:52:06,550 [NioProcessor-7] WARN  o.r.s.net.rtmp.RTMPMinaIoHandler 
- Exception caught on session: 6
2013-08-09 23:52:06,551 [NioProcessor-8] WARN  o.r.s.net.rtmp.RTMPMinaIoHandler 
- Force close - session: 7
2013-08-09 23:52:43,930 [Red5_Scheduler_Worker-22] INFO  Red5.appl - W3C 
x-category:session x-event:disconnect c-ip:192.168.1.104 c-client-id:5

What version of the product are you using? On what operating system?
Gentoo Linux r4708

Please provide any additional information below.
I think the force close is not needed on the RTMPMinaIoHandler Exception,
when the cause is an instance of IOException
(see 
http://mina.apache.org/mina-project/apidocs/org/apache/mina/core/service/IoHandl
er.html#exceptionCaught%28org.apache.mina.core.session.IoSession,%20java.lang.Th
rowable%29)

Original issue reported on code.google.com by wer...@icm-world.com on 10 Aug 2013 at 11:24

Attachments:

GoogleCodeExporter commented 9 years ago 
Thanks for the patch and good catch on the IOException caveat. I'll be adding 
this to trunk real soon.

Original comment by mondain on 13 Aug 2013 at 2:50

GoogleCodeExporter commented 9 years ago 
Thank you very much for the ticket and the patch! Indeed disconnection is very 
long and caused many problems for publishing on a stream and resume playback 
for clients that played this stream.

I just did a test, if I disconnect wildly and recovery published before this 
disconnection, customers are not aware of the new "publish". In the meantime 
properly disconnect the publish is sent immediately.

Original comment by equipe.p...@gmail.com on 14 Aug 2013 at 12:57

GoogleCodeExporter commented 9 years ago 
Try the latest trunk revision 4710 and let me know if it works any better for 
you.

Original comment by mondain on 29 Aug 2013 at 8:02

GoogleCodeExporter commented 9 years ago 
I try the trunk revision 4710 and it looks good, I don't found a slow session 
closing.

But I see an other problem with closing connection.

On my live system after a few weeks I have this list of open and not complete 
closed session. In my red5 applications there are no more connections.

ctive Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address           Foreign Address  State       
PID/Program name Timer
tcp        0      0 0.0.0.0:1935            0.0.0.0:*        LISTEN      
9565/java        off (0.00/0/0)
tcp        0      0 0.0.0.0:5080            0.0.0.0:*        LISTEN      
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      217.x.x.x:63859     CLOSE_WAIT  
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      77.x.x.x:2419       CLOSE_WAIT  
9565/java        off (0.00/0/0)
tcp     1537      0 red5server:1935      193.x.x.x:53655     ESTABLISHED 
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      31.x.x.x:50815      CLOSE_WAIT  
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      37.x.x.x:65212      CLOSE_WAIT  
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      37.x.x.x:63665      CLOSE_WAIT  
9565/java        off (0.00/0/0)
tcp     1537      0 red5server:1935      80.x.x.x:58753      ESTABLISHED 
9565/java        off (0.00/0/0)
tcp     1537      0 red5server:1935      91.x.x.x:3168       ESTABLISHED 
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      92.x.x.x:53044      CLOSE_WAIT  
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      37.x.x.x:65334      CLOSE_WAIT  
9565/java        off (0.00/0/0)
tcp     1538      0 red5server:1935      31.x.x.x:50617      CLOSE_WAIT  
9565/java        off (0.00/0/0)

In the attempt to produce the problem, I just found the exception 
NullPointerException.

2013-09-08 15:30:21,113 [RTMPConnectionExecutor#13786470161131] WARN  
o.r.server.net.rtmp.RTMPConnection - Closing 5ZEXGDFMSBA1J, due to long 
handshake. State: connect
2013-09-08 15:30:47,020 [RTMPConnectionExecutor#13786470161131] ERROR 
o.s.s.s.TaskUtils$LoggingErrorHandler - Unexpected error occurred in scheduled 
task.
java.lang.NullPointerException: null
    at org.red5.server.net.rtmp.RTMPConnection.close(RTMPConnection.java:724) ~[red5-server.jar:na]
    at org.red5.server.net.rtmp.RTMPMinaConnection.close(RTMPMinaConnection.java:112) ~[red5-server.jar:na]
    at org.red5.server.net.rtmp.RTMPMinaConnection.onInactive(RTMPMinaConnection.java:298) ~[red5-server.jar:na]
    at org.red5.server.net.rtmp.RTMPConnection$WaitForHandshakeTask.run(RTMPConnection.java:1375) ~[red5-server.jar:na]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:53) ~[spring-context-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439) [na:1.6.0_45]
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [na:1.6.0_45]
    at java.util.concurrent.FutureTask.run(FutureTask.java:138) [na:1.6.0_45]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) [na:1.6.0_45]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) [na:1.6.0_45]
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895) [na:1.6.0_45]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918) [na:1.6.0_45]
    at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]

You god this exception by open a tcp connection to rtmp port with telnet and 
wait.
At RTMPConnection.java:724 the scope is null.

Original comment by wer...@icm-world.com on 8 Sep 2013 at 2:09

GoogleCodeExporter commented 9 years ago 
The close_wait issue has been fixed for several of the last few revisions; 
please re-test and let us know if you have the same results.

Original comment by mondain on 31 Oct 2013 at 11:12