google-code-export / red5

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

loop Non-existant stream for channel #496

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
What steps will reproduce the problem?
1. visitor starts looking at a stream
2. visitor connection is closed
3. _sometimes_ the server keeps trying to write to the closed connection

What is the expected output? 
After connection is closed, server should not try to write to connection or 
should stop trying after x times.
What do you see instead?
The server log fills with this message "Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}" until the publisher stops.

What version of the product are you using? On what operating system?
Red5 1.0.2 Release on Linux 3.2.0-4-amd64 #1 SMP Debian 3.2.35-2 x86_64 
GNU/Linux

Please provide any additional information below.

Server log:

2014-04-15T09:13:33.639Z - 7 -  [RTMPExecutor#CYYJCDRFXWJO0-1] - 
[com.mydomain.Application] - connect: RTMPMinaConnection from x.x.x.x (in: 3478 
out: 3073) session: CYYJCDRFXWJO0 state: connected > Scope [name=webcams, 
path=/default, type=APPLICATION, autoStart=true, creationTime=1397481775681, 
depth=1, enabled=true, running=true]
2014-04-15T09:13:33.640Z - 6 -  [RTMPExecutor#CYYJCDRFXWJO0-1] - 
[com.mydomain.Application] - W3C x-category:session x-event:connect 
c-ip:x.x.x.x c-client-id:1633
2014-04-15T09:13:33.665Z - 7 -  [RTMPExecutor#CYYJCDRFXWJO0-1] - 
[com.mydomain.Application] - appJoin: Client: 1633 >> Scope [name=webcams, 
path=/default, type=APPLICATION, autoStart=true, creationTime=1397481775681, 
depth=1, enabled=true, running=true]
2014-04-15T09:13:33.666Z - 7 -  [RTMPExecutor#CYYJCDRFXWJO0-1] - 
[com.mydomain.Application] - connect: RTMPMinaConnection from x.x.x.x (in: 3478 
out: 3073) session: CYYJCDRFXWJO0 state: connected > Scope [name=mywebcam, 
path=/default/webcams, type=ROOM, autoStart=true, creationTime=1397553150312, 
depth=2, enabled=true, running=true]
2014-04-15T09:13:33.666Z - 7 -  [RTMPExecutor#CYYJCDRFXWJO0-1] - 
[com.mydomain.Application] - roomConnect: RTMPMinaConnection from x.x.x.x (in: 
3478 out: 3073) session: CYYJCDRFXWJO0 state: connected
2014-04-15T09:13:33.666Z - 7 -  [RTMPExecutor#CYYJCDRFXWJO0-1] - 
[com.mydomain.Application] - roomJoin: Client: 1633 >> Scope [name=mywebcam, 
path=/default/webcams, type=ROOM, autoStart=true, creationTime=1397553150312, 
depth=2, enabled=true, running=true]
2014-04-15T09:13:33.955Z - 7 -  [NioProcessor-51] - [com.mydomain.Application] 
- disconnect: RTMPMinaConnection from x.x.x.x (in: 3589 out: 3318) session: 
CYYJCDRFXWJO0 state: disconnecting < Scope [name=mywebcam, 
path=/default/webcams, type=ROOM, autoStart=true, creationTime=1397553150312, 
depth=2, enabled=true, running=true]
2014-04-15T09:13:33.957Z - 7 -  [NioProcessor-51] - [com.mydomain.Application] 
- roomDisconnect: RTMPMinaConnection from x.x.x.x (in: 3589 out: 3318) session: 
CYYJCDRFXWJO0 state: disconnecting
2014-04-15T09:13:33.959Z - 7 -  [NioProcessor-51] - [com.mydomain.Application] 
- disconnect: RTMPMinaConnection from x.x.x.x (in: 3589 out: 3318) session: 
CYYJCDRFXWJO0 state: disconnecting < Scope [name=webcams, path=/default, 
type=APPLICATION, autoStart=true, creationTime=1397481775681, depth=1, 
enabled=true, running=true]
2014-04-15T09:13:33.963Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:33.963Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:33.964Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.001Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.001Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.002Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.022Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.022Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.064Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.066Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.090Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.091Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:13:34.091Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
...
etc etc
...
2014-04-15T09:23:33.408Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.410Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.442Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.443Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.482Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.483Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.519Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.520Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.543Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.544Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.544Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.545Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.577Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.578Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.635Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.635Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.636Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.676Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}
2014-04-15T09:23:33.677Z - 4 -  [RTMPExecutor#KSIST2WK3GOJC-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: CYYJCDRFXWJO0 discarding: {}

Original issue reported on code.google.com by petervan...@gmail.com on 15 Apr 2014 at 10:29

GoogleCodeExporter commented 9 years ago

Original comment by mondain on 15 Apr 2014 at 8:46

GoogleCodeExporter commented 9 years ago
hi,

some extra logs from same behaviour some time after previous log. (Same server, 
day etc)
Again, the subscriber disconnected very quickly:

2014-04-15T16:09:10.335Z - 7 -  [RTMPExecutor#ZVPPWM9ULVUWD-1] - 
[com.mydomain.Application] - connect: RTMPMinaConnection from x.x.x.x (in: 3823 
out: 3073) session: ZVPPWM9ULVUWD state: connected > Scope [name=webcams, 
path=/default, type=APPLICATION, autoStart=true, creationTime=1397481775681, 
depth=1, enabled=true, running=true]
2014-04-15T16:09:10.335Z - 6 -  [RTMPExecutor#ZVPPWM9ULVUWD-1] - 
[com.mydomain.Application] - W3C x-category:session x-event:connect 
c-ip:x.x.x.x c-client-id:24478
2014-04-15T16:09:10.388Z - 7 -  [RTMPExecutor#ZVPPWM9ULVUWD-1] - 
[com.mydomain.Application] - appJoin: Client: 24478 >> Scope [name=webcams, 
path=/default, type=APPLICATION, autoStart=true, creationTime=1397481775681, 
depth=1, enabled=true, running=true]
2014-04-15T16:09:10.389Z - 7 -  [RTMPExecutor#ZVPPWM9ULVUWD-1] - 
[com.mydomain.Application] - connect: RTMPMinaConnection from x.x.x.x (in: 3823 
out: 3091) session: ZVPPWM9ULVUWD state: connected > Scope [name=mywebcam, 
path=/default/webcams, type=ROOM, autoStart=true, creationTime=1397569815609, 
depth=2, enabled=true, running=true]
2014-04-15T16:09:10.390Z - 7 -  [RTMPExecutor#ZVPPWM9ULVUWD-1] - 
[com.mydomain.Application] - roomConnect: RTMPMinaConnection from x.x.x.x (in: 
3823 out: 3091) session: ZVPPWM9ULVUWD state: connected
2014-04-15T16:09:10.391Z - 7 -  [RTMPExecutor#ZVPPWM9ULVUWD-1] - 
[com.mydomain.Application] - roomJoin: Client: 24478 >> Scope [name=mywebcam, 
path=/default/webcams, type=ROOM, autoStart=true, creationTime=1397569815609, 
depth=2, enabled=true, running=true]
2014-04-15T16:09:10.569Z - 4 -  [NioProcessor-101] - 
[org.red5.server.net.rtmp.RTMPMinaIoHandler] - Exception caught on session: 
26340 id: ZVPPWM9ULVUWDjava.io.IOException: Connection reset by peer
2014-04-15T16:09:10.569Z - 7 -  [NioProcessor-101] - [com.mydomain.Application] 
- disconnect: RTMPMinaConnection from x.x.x.x (in: 4045 out: 3332) session: 
ZVPPWM9ULVUWD state: disconnecting < Scope [name=mywebcam, 
path=/default/webcams, type=ROOM, autoStart=true, creationTime=1397569815609, 
depth=2, enabled=true, running=true]
2014-04-15T16:09:10.570Z - 7 -  [NioProcessor-101] - [com.mydomain.Application] 
- roomDisconnect: RTMPMinaConnection from x.x.x.x (in: 4045 out: 3332) session: 
ZVPPWM9ULVUWD state: disconnecting
2014-04-15T16:09:10.571Z - 7 -  [NioProcessor-101] - [com.mydomain.Application] 
- disconnect: RTMPMinaConnection from x.x.x.x (in: 4045 out: 3332) session: 
ZVPPWM9ULVUWD state: disconnecting < Scope [name=webcams, path=/default, 
type=APPLICATION, autoStart=true, creationTime=1397481775681, depth=1, 
enabled=true, running=true]
2014-04-15T16:09:10.575Z - 4 -  [RTMPExecutor#ZVPPWM9ULVUWD-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: ZVPPWM9ULVUWD discarding: {}
2014-04-15T16:09:10.597Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: ZVPPWM9ULVUWD discarding: {}
2014-04-15T16:09:10.629Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: ZVPPWM9ULVUWD discarding: {}
2014-04-15T16:09:10.682Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: ZVPPWM9ULVUWD discarding: {}
2014-04-15T16:09:10.750Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: ZVPPWM9ULVUWD discarding: {}
...
2014-04-15T16:19:25.743Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: ZVPPWM9ULVUWD discarding: {}
2014-04-15T16:19:25.744Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: ZVPPWM9ULVUWD discarding: {}
2014-04-15T16:19:25.785Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 6, 
connection id: ZVPPWM9ULVUWD discarding: {}
2014-04-15T16:19:25.809Z - 4 -  [RTMPExecutor#S5NOBYKHEVSHZ-1] - 
[org.red5.server.net.rtmp.Channel] - Non-existant stream for channel id: 5, 
connection id: ZVPPWM9ULVUWD discarding: {}

Original comment by petervan...@gmail.com on 17 Apr 2014 at 11:02

GoogleCodeExporter commented 9 years ago
I've started a SNAPSHOT for the next release and would like you to try them as 
resolution for this issue; let me know if the issue is fixed or post any logs 
that would be helpful if its not. 

https://dl.dropboxusercontent.com/u/7316897/red5/latest/red5-server-1.0.3-SNAPSH
OT-server.tar.gz

https://dl.dropboxusercontent.com/u/7316897/red5/latest/red5-server-1.0.3-SNAPSH
OT-server.zip

Original comment by mondain on 17 Apr 2014 at 9:35

GoogleCodeExporter commented 9 years ago
We did not have the issue anymore when running the snapshot. Looks like it is 
fixed, thank you!

Original comment by petervan...@gmail.com on 23 Apr 2014 at 8:02

GoogleCodeExporter commented 9 years ago
Awesome

Original comment by mondain on 23 Apr 2014 at 3:44