Dear Maxim, Would you happen to know why the SECOND time entering room is very fast, under the same firewall settings? Just wanted to learn the handshake process.
Thank you. Sincerely, Hemant K. Sabat Coscend Communications Solutions Web site: www.Coscend.com ------------------------------------------------------------------ CONFIDENTIALITY NOTICE: See 'Confidentiality Notice Regarding E-mail Messages from Coscend Communications Solutions' posted at: http://www.Coscend.com/Terms_and_Conditions.html -----Original Message----- From: Maxim Solodovnik [mailto:solomax...@gmail.com] Sent: Tuesday, September 13, 2016 11:58 AM To: Openmeetings user-list <user@openmeetings.apache.org>; om.insig...@coscend.com Subject: Re: RTMP Connection Delay delay is caused by your FW settings set REJECT (instead of DENY) for 1935 and it will speed-up everything On Tue, Sep 13, 2016 at 11:48 PM, Coscend@OM <om.insig...@coscend.com> wrote: > Dear Maxim, > > Yes, we are using reverse proxy. > Reverse proxy open: 5080 > OS Firewall open: 1935, 5080. > > FIRST time entering room takes 1 MINUTE during handshake. > Exit room. > SECOND time entering room takes only 1 SECOND. > > Only in 3.1.2. In 3.0.7, no delay. > > > Could this delay be caused by empty field in config.xml: > <rtmphostlocal></rtmphostlocal>? > Is this value stored somewhere in cache after the first login so that the > second time it is faster? If so, where is it stored? > > > Thank you. > > Sincerely, > > Hemant K. Sabat > > Coscend Communications Solutions > Web site: www.Coscend.com > ------------------------------------------------------------------ > CONFIDENTIALITY NOTICE: See 'Confidentiality Notice Regarding E-mail > Messages from Coscend Communications Solutions' posted at: > http://www.Coscend.com/Terms_and_Conditions.html > > > > -----Original Message----- > From: Maxim Solodovnik [mailto:solomax...@gmail.com] > Sent: Tuesday, September 13, 2016 2:10 AM > To: Openmeetings user-list <user@openmeetings.apache.org>; > om.insig...@coscend.com > Subject: Re: RTMP Connection Delay > > Are you behind the proxy? apache/nginx with port 1935 closed? > > On Tue, Sep 13, 2016 at 1:58 PM, Coscend@OM <om.insig...@coscend.com> wrote: >> Dear OpenMeetings Users, >> >> >> >> In OM 3.1.2, while logging in the FIRST time as well as while >> entering a room the FIRST time after login, there is a noticeable >> delay during handshake (HTTP to RTMP). This was not observed in OM >> 3.0.7 in the same environment. Could you advise us the cause of the delay >> in 3.1.2? >> >> (See ID: 3 in log below) >> >> >> >> Upon exiting the room and reentering the room, there is no delay at all. >> (See ID: 4 in log below). >> >> >> >> Could this be caused by empty field in config.xml: >> <rtmphostlocal></rtmphostlocal>? Is this value stored somewhere in >> cache after the first login so that the second time it is faster? If >> so, where is it stored? >> >> >> >> >> >> ============= >> >> OpenMeetings.log >> >> ============= >> >> ID: 3 >> >> Response-Code: 200 >> >> Content-Type: application/json >> >> Headers: {Content-Type=[application/json], Date=[Sat, 10 Sep 2016 >> 05:20:43 GMT]} >> >> Payload: {"fileExplorerObject":{"userHomeSize":0,"roomHomeSize":0}} >> >> -------------------------------------- >> >> DEBUG 09-10 00:20:43.780 ScopeApplicationAdapter.java 258296 1160 >> org.apache.openmeetings.core.remote.red5.ScopeApplicationAdapter >> [RTMPConnectionExecutor-2] - ----------- setRoomValues >> >> DEBUG 09-10 00:20:43.797 ConferenceLogDao.java 258313 52 >> org.apache.openmeetings.db.dao.log.ConferenceLogDao >> [RTMPConnectionExecutor-2] - [addConferenceLog]: >> org.apache.openmeetings.db.entity.log.ConferenceLog@74ca6007 >> >> … >> >> ERROR 09-10 00:21:29.713 WicketEndpoint.java 304229 77 >> org.apache.wicket.protocol.ws.javax.WicketEndpoint >> [http-nio-[IP]-[port]-exec-6] - An error occurred in web socket >> connection with id : 1 >> >> java.io.IOException: Broken pipe >> >> at sun.nio.ch.FileDispatcherImpl.write0(Native Method) >> >> at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) >> >> at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) >> >> at sun.nio.ch.IOUtil.write(IOUtil.java:65) >> >> at >> sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:492) >> >> at >> org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:124) >> >> at >> org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java: >> 183) >> >> at >> org.apache.coyote.http11.upgrade.NioServletOutputStream.doWriteIntern >> a >> l(NioServletOutputStream.java:94) >> >> at >> org.apache.coyote.http11.upgrade.NioServletOutputStream.doWrite(NioSe >> r >> vletOutputStream.java:61) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletOutputStream.writeInt >> e >> rnal(AbstractServletOutputStream.java:165) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletOutputStream.write(Ab >> s >> tractServletOutputStream.java:132) >> >> at >> org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.onWrite >> P >> ossible(WsRemoteEndpointImplServer.java:98) >> >> at >> org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.doWrite >> ( >> WsRemoteEndpointImplServer.java:79) >> >> at >> org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart >> ( >> WsRemoteEndpointImplBase.java:453) >> >> at >> org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessage(WsR >> e >> moteEndpointImplBase.java:341) >> >> at >> org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBloc >> k >> (WsRemoteEndpointImplBase.java:273) >> >> at >> org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java: >> 588) >> >> at >> org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:490) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.onError(WsHtt >> p >> UpgradeHandler.java:149) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.access$300(Ws >> H >> ttpUpgradeHandler.java:47) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListene >> r >> .onError(WsHttpUpgradeHandler.java:206) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListene >> r >> .onDataAvailable(WsHttpUpgradeHandler.java:189) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAva >> i >> lable(AbstractServletInputStream.java:198) >> >> at >> org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(Ab >> s >> tractProcessor.java:96) >> >> at >> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process( >> A >> bstractProtocol.java:647) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpo >> i >> nt.java:1520) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoin >> t >> .java:1476) >> >> at >> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor. >> j >> ava:1145) >> >> at >> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor. >> java:615) >> >> at >> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskTh >> r >> ead.java:61) >> >> at java.lang.Thread.run(Thread.java:745) >> >> DEBUG 09-10 00:21:29.715 MainPage.java 304231 223 >> org.apache.openmeetings.web.pages.MainPage >> [http-nio-[IP]-[port]-exec-6] - WebSocketBehavior::onClose >> >> ERROR 09-10 00:21:29.888 WicketEndpoint.java 304404 77 >> org.apache.wicket.protocol.ws.javax.WicketEndpoint >> [http-nio-[IP]-[port]-exec-6] - An error occurred in web socket >> connection with id : 1 >> >> java.io.IOException: Connection reset by peer >> >> at sun.nio.ch.FileDispatcherImpl.read0(Native Method) >> >> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) >> >> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223) >> >> at sun.nio.ch.IOUtil.read(IOUtil.java:197) >> >> at >> sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:384) >> >> at >> org.apache.tomcat.util.net.NioChannel.read(NioChannel.java:137) >> >> at >> org.apache.coyote.http11.upgrade.NioServletInputStream.fillReadBuffer >> ( >> NioServletInputStream.java:136) >> >> at >> org.apache.coyote.http11.upgrade.NioServletInputStream.doRead(NioServ >> l >> etInputStream.java:80) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletInputStream.read(Abst >> r >> actServletInputStream.java:124) >> >> at >> org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFr >> a >> meServer.java:60) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListene >> r >> .onDataAvailable(WsHttpUpgradeHandler.java:185) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAva >> i >> lable(AbstractServletInputStream.java:198) >> >> at >> org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(Ab >> s >> tractProcessor.java:96) >> >> at >> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process( >> A >> bstractProtocol.java:647) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpo >> i >> nt.java:1520) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoin >> t >> .java:1476) >> >> at >> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor. >> j >> ava:1145) >> >> at >> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor. >> java:615) >> >> at >> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskTh >> r >> ead.java:61) >> >> at java.lang.Thread.run(Thread.java:745) >> >> DEBUG 09-10 00:21:31.949 SessiondataDao.java 306465 263 >> org.apache.openmeetings.db.dao.server.SessiondataDao >> [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker- >> 1 >> ] - >> ****** clearSessionTable: >> >> DEBUG 09-10 00:21:31.952 SessiondataDao.java 306468 265 >> org.apache.openmeetings.db.dao.server.SessiondataDao >> [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker- >> 1 >> ] - >> clearSessionTable: 0 >> >> DEBUG 09-10 00:21:31.953 MeetingReminderJob.java 306469 35 >> org.apache.openmeetings.service.quartz.scheduler.MeetingReminderJob >> [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker- >> 2 >> ] - MeetingReminderJob.execute >> >> DEBUG 09-10 00:21:34.554 MeetingReminderJob.java 309070 35 >> org.apache.openmeetings.service.quartz.scheduler.MeetingReminderJob >> [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker- >> 2 >> ] - MeetingReminderJob.execute >> >> DEBUG 09-10 00:21:34.555 SessiondataDao.java 309071 263 >> org.apache.openmeetings.db.dao.server.SessiondataDao >> [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker- >> 1 >> ] - >> ****** clearSessionTable: >> >> DEBUG 09-10 00:21:34.559 SessiondataDao.java 309075 265 >> org.apache.openmeetings.db.dao.server.SessiondataDao >> [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker- >> 1 >> ] - >> clearSessionTable: 0 >> >> [WARN] [NioProcessor-4] org.apache.mina.core.service.IoProcessor - >> Create a new selector. Selected is 0, delta = 0 >> >> [WARN] [RTMPConnectionScheduler-2] >> org.red5.server.net.rtmp.RTMPConnection - Closing connection - >> inactivity timeout: session=[V6BEIJ0K2XRTE], >> lastPongReceived=[60008 ms ago], lastPingSent=[5001 ms ago], >> lastDataRx=[70009 ms ago] >> >> [WARN] [RTMPConnectionScheduler-2] >> org.red5.server.net.rtmp.RTMPConnection - Client on >> session=[V6BEIJ0K2XRTE] has not responded to our ping for [60008 ms] >> and we haven't received data for [70009 ms] >> >> java.lang.InterruptedException >> >> at >> java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireShare >> d >> Nanos(AbstractQueuedSynchronizer.java:1325) >> >> at >> java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:414) >> >> at >> org.red5.server.adapter.ApplicationAdapter.disconnect(ApplicationAdap >> t >> er.java:91) >> >> at org.red5.server.scope.Scope.disconnect(Scope.java:352) >> >> at >> org.red5.server.BaseConnection.close(BaseConnection.java:402) >> >> at >> org.red5.server.net.rtmp.RTMPConnection.close(RTMPConnection.java:990 >> ) >> >> at >> org.red5.server.net.rtmpt.BaseRTMPTConnection.close(BaseRTMPTConnecti >> o >> n.java:131) >> >> at >> org.red5.server.net.rtmpt.RTMPTConnection.close(RTMPTConnection.java: >> 1 >> 28) >> >> at >> org.red5.server.net.rtmpt.RTMPTConnection.onInactive(RTMPTConnection. >> j >> ava:108) >> >> at >> org.red5.server.net.rtmp.RTMPConnection$KeepAliveTask.run(RTMPConnect >> i >> on.java:1897) >> >> at >> org.springframework.scheduling.support.DelegatingErrorHandlingRunnabl >> e >> .run(DelegatingErrorHandlingRunnable.java:54) >> >> at >> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:47 >> 1 >> ) >> >> at >> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304) >> >> at >> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. >> a >> ccess$301(ScheduledThreadPoolExecutor.java:178) >> >> at >> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. >> r >> un(ScheduledThreadPoolExecutor.java:293) >> >> at >> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor. >> j >> ava:1145) >> >> at >> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor. >> java:615) >> >> at java.lang.Thread.run(Thread.java:745) >> >> DEBUG 09-10 00:21:53.516 MultiThreadedApplicationAdapter.java 328032 >> 507 org.apache.openmeetings.core.remote.red5.ScopeApplicationAdapter >> [RTMPConnectionScheduler-2] - leave: Client: V6BEIJ0K2XRTE << Scope >> [name=5, path=/default/test.om, type=ROOM, autoStart=true, >> creationTime=1473484696211, depth=2, enabled=true, running=true] >> >> autoStart=true, creationTime=1473484696211, depth=2, enabled=true, >> running=true] >> >> … >> >> DEBUG 09-10 00:21:53.557 MultiThreadedApplicationAdapter.java 328073 >> 711 org.apache.openmeetings.core.remote.red5.ScopeApplicationAdapter >> [RTMPConnectionScheduler-2] - appLeave: Client: V6BEIJ0K2XRTE << >> Scope [name=test.om, path=/default, type=APPLICATION, autoStart=true, >> creationTime=1473484588481, depth=1, enabled=true, running=true] >> >> [ERROR] [RTMPConnectionExecutor-4] >> org.red5.server.service.ServiceInvoker - Error executing call: >> Service: null Method: play Num Params: 2 0: undefined >> 1: NaN >> >> java.lang.IllegalArgumentException: argument type mismatch >> >> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >> >> at >> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. >> j >> ava:57) >> >> at >> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces >> s >> orImpl.java:43) >> >> at java.lang.reflect.Method.invoke(Method.java:606) >> >> at >> org.red5.server.service.ServiceInvoker.invoke(ServiceInvoker.java:189 >> ) >> >> at >> org.red5.server.net.rtmp.RTMPHandler.invokeCall(RTMPHandler.java:214) >> >> at >> org.red5.server.net.rtmp.RTMPHandler.onCommand(RTMPHandler.java:276) >> >> at >> org.red5.server.net.rtmp.BaseRTMPHandler.messageReceived(BaseRTMPHand >> l >> er.java:116) >> >> at >> org.red5.server.net.rtmp.ReceivedMessageTask.call(ReceivedMessageTask. >> java:72) >> >> at >> org.red5.server.net.rtmp.ReceivedMessageTask.call(ReceivedMessageTask. >> java:38) >> >> at java.util.concurrent.FutureTask.run(FutureTask.java:262) >> >> at >> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:47 >> 1 >> ) >> >> at java.util.concurrent.FutureTask.run(FutureTask.java:262) >> >> at >> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor. >> j >> ava:1145) >> >> at >> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor. >> java:615) >> >> at java.lang.Thread.run(Thread.java:745) >> >> [WARN] [RTMPConnectionExecutor-4] org.red5.server.net.rtmp.Channel - >> Non-existant stream for channel id: 8, session: DUNX6UQ7J3LP6 discarding: >> Invoke #0: Service: null Method: play Num Params: 2 0: undefined 1: >> NaN >> >> >> >> >> >> ID: 4 >> >> Response-Code: 200 >> >> Content-Type: application/json >> >> Headers: {Content-Type=[application/json], Date=[Sat, 10 Sep 2016 >> 05:27:51 GMT]} >> >> Payload: {"fileExplorerObject":{"userHomeSize":0,"roomHomeSize":0}} >> >> -------------------------------------- >> >> DEBUG 09-10 00:27:51.330 ScopeApplicationAdapter.java 685846 1160 >> org.apache.openmeetings.core.remote.red5.ScopeApplicationAdapter >> [RTMPConnectionExecutor-1] - ----------- setRoomValues >> >> DEBUG 09-10 00:27:51.351 ConferenceLogDao.java 685867 52 >> org.apache.openmeetings.db.dao.log.ConferenceLogDao >> [RTMPConnectionExecutor-1] - [addConferenceLog]: >> org.apache.openmeetings.db.entity.log.ConferenceLog@2b48c62a >> >> DEBUG 09-10 00:27:51.417 RecordingService.java 685933 377 >> org.apache.openmeetings.core.remote.RecordingService >> [RTMPConnectionExecutor-3] - getCurrentRoomClient -2- 1 >> >> >> >> >> >> >> >> Thank you. >> >> >> >> Sincerely, >> >> >> >> Hemant K. Sabat >> >> >> >> Coscend Communications Solutions >> >> Web site: www.Coscend.com >> >> ------------------------------------------------------------------ >> >> CONFIDENTIALITY NOTICE: See 'Confidentiality Notice Regarding E-mail >> Messages from Coscend Communications Solutions' posted at: >> http://www.Coscend.com/Terms_and_Conditions.html > > -- WBR Maxim aka solomax ----- No virus found in this message. Checked by AVG - www.avg.com Version: 2016.0.7752 / Virus Database: 4649/13010 - Release Date: 09/13/16
