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.doWriteInternal(NioServletOutputStream.java:94)
>
> at
> org.apache.coyote.http11.upgrade.NioServletOutputStream.doWrite(NioServletOutputStream.java:61)
>
> at
> org.apache.coyote.http11.upgrade.AbstractServletOutputStream.writeInternal(AbstractServletOutputStream.java:165)
>
> at
> org.apache.coyote.http11.upgrade.AbstractServletOutputStream.write(AbstractServletOutputStream.java:132)
>
> at
> org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.onWritePossible(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(WsRemoteEndpointImplBase.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(WsHttpUpgradeHandler.java:149)
>
> at
> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.access$300(WsHttpUpgradeHandler.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.onDataAvailable(AbstractServletInputStream.java:198)
>
> at
> org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(AbstractProcessor.java:96)
>
> at
> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:647)
>
> at
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1520)
>
> at
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1476)
>
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>
> at
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.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(NioServletInputStream.java:80)
>
> at
> org.apache.coyote.http11.upgrade.AbstractServletInputStream.read(AbstractServletInputStream.java:124)
>
> at
> org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:60)
>
> at
> org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onDataAvailable(WsHttpUpgradeHandler.java:185)
>
> at
> org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvailable(AbstractServletInputStream.java:198)
>
> at
> org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(AbstractProcessor.java:96)
>
> at
> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:647)
>
> at
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1520)
>
> at
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1476)
>
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>
> at
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.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.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1325)
>
> at java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:414)
>
> at
> org.red5.server.adapter.ApplicationAdapter.disconnect(ApplicationAdapter.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(BaseRTMPTConnection.java:131)
>
> at
> org.red5.server.net.rtmpt.RTMPTConnection.close(RTMPTConnection.java:128)
>
> at
> org.red5.server.net.rtmpt.RTMPTConnection.onInactive(RTMPTConnection.java:108)
>
> at
> org.red5.server.net.rtmp.RTMPConnection$KeepAliveTask.run(RTMPConnection.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.access$301(ScheduledThreadPoolExecutor.java:178)
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java: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.java:57)
>
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.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(BaseRTMPHandler.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.java: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
