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.doWriteInterna >> l(NioServletOutputStream.java:94) >> >> at >> org.apache.coyote.http11.upgrade.NioServletOutputStream.doWrite(NioSer >> vletOutputStream.java:61) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletOutputStream.writeInte >> rnal(AbstractServletOutputStream.java:165) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletOutputStream.write(Abs >> tractServletOutputStream.java:132) >> >> at >> org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.onWriteP >> 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(WsRe >> moteEndpointImplBase.java:341) >> >> at >> org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock >> (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(WsHttp >> UpgradeHandler.java:149) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.access$300(WsH >> ttpUpgradeHandler.java:47) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener >> .onError(WsHttpUpgradeHandler.java:206) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener >> .onDataAvailable(WsHttpUpgradeHandler.java:189) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvai >> lable(AbstractServletInputStream.java:198) >> >> at >> org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(Abs >> tractProcessor.java:96) >> >> at >> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(A >> bstractProtocol.java:647) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoi >> nt.java:1520) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint >> .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(TaskThr >> 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(NioServl >> etInputStream.java:80) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletInputStream.read(Abstr >> actServletInputStream.java:124) >> >> at >> org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFra >> meServer.java:60) >> >> at >> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener >> .onDataAvailable(WsHttpUpgradeHandler.java:185) >> >> at >> org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvai >> lable(AbstractServletInputStream.java:198) >> >> at >> org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(Abs >> tractProcessor.java:96) >> >> at >> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(A >> bstractProtocol.java:647) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoi >> nt.java:1520) >> >> at >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint >> .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(TaskThr >> 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.tryAcquireShared >> Nanos(AbstractQueuedSynchronizer.java:1325) >> >> at >> java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:414) >> >> at >> org.red5.server.adapter.ApplicationAdapter.disconnect(ApplicationAdapt >> 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(BaseRTMPTConnectio >> 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(RTMPConnecti >> on.java:1897) >> >> at >> org.springframework.scheduling.support.DelegatingErrorHandlingRunnable >> .run(DelegatingErrorHandlingRunnable.java:54) >> >> at >> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471 >> ) >> >> 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(DelegatingMethodAccess >> 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(BaseRTMPHandl >> 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:471 >> ) >> >> 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
