Seeking in flv doesn't seem to work in video on demand

[benmcmeen]

I have a simple config for VOD:

application indexed { play /tmp/indexed; }

The indexed directory contains recorded flv files that have been indexed with yamdi. When I play them with JWPlayer, I have a total duration and they play (and pause) fine. However, any scrubbing or seeking causes the video to start over at the beginning. I see entries in the error log like:

2014/07/04 17:16:45 [info] 7868#0: *28 seek: offset=10000000, client: 68.34.202.186, server: 0.0.0.0:1935

...which basically tell me nginx-rtmp is getting the seek request - but nothing after that indicating why the seek fails.

This problem exists when adding metadata with flvmeta as well.

I can confirm the indexed flvs play/pause/seek correctly in Cloudfront's RTMP server and crtmpserver.

[benmcmeen]

debug log portion follows:

2014/07/07 00:39:06 [debug] 28784#0: *1 send: fd:3 220 of 220
2014/07/07 00:39:06 [debug] 28784#0: posted event 0000000000000000
2014/07/07 00:39:06 [debug] 28784#0: *1 flv: schedule wait=39 timestamp=5920 end_timestamp=5881 bufen=3000
2014/07/07 00:39:06 [debug] 28784#0: *1 play: send schedule 39
2014/07/07 00:39:06 [debug] 28784#0: *1 event timer add: 0: 39:1404693546518
2014/07/07 00:39:06 [debug] 28784#0: posted events 0000000000000000
2014/07/07 00:39:06 [debug] 28784#0: worker cycle
2014/07/07 00:39:06 [debug] 28784#0: epoll timer: 39
2014/07/07 00:39:06 [debug] 28784#0: epoll: fd:3 ev:0001 d:00007FBE7B9BA190
2014/07/07 00:39:06 [debug] 28784#0: *1 recv: fd:3 34 of 146
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP bheader fmt=1 csid=8
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP mheader fmt=1 amf_cmd (20) time=419+3044 mlen=26 len=0 msid=1
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP recv amf_cmd (20) csid=8 timestamp=3463 mlen=26 msid=1 nbufs=1
2014/07/07 00:39:06 [debug] 28784#0: *1 nhandlers: 1
2014/07/07 00:39:06 [debug] 28784#0: *1 calling handler 0
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (1) 02 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (2) 00 04 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (4) 73 65 65 6B 'seek'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF func 'seek' passed to handler 0/1
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (1) 00 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (8) 00 00 00 00 00 00 00 00 '????????'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (1) 05 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (1) 00 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF read (8) 41 63 12 D0 00 00 00 00 'Ac??????'
2014/07/07 00:39:06 [info] 28784#0: *1 seek: offset=10000000, client: 68.34.202.186, server: 0.0.0.0:1935
2014/07/07 00:39:06 [debug] 28784#0: *1 create: stream_end msid=1
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP prep user (4) fmt=0 csid=2 timestamp=0 mlen=6 msid=0 nbufs=1
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP send nmsg=1, priority=0 #162
2014/07/07 00:39:06 [debug] 28784#0: *1 send: fd:3 18 of 18
2014/07/07 00:39:06 [debug] 28784#0: posted event 0000000000000000
2014/07/07 00:39:06 [debug] 28784#0: *1 play: seek timestamp=10000000
2014/07/07 00:39:06 [debug] 28784#0: *1 flv: seek timestamp=10000000
2014/07/07 00:39:06 [debug] 28784#0: *1 post event 000000000121C8D8
2014/07/07 00:39:06 [debug] 28784#0: *1 create: status code='NetStream.Seek.Notify' level='status' desc='Seeking'
2014/07/07 00:39:06 [debug] 28784#0: *1 create: amf nelts=4
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 02 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 08 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (8) 6F 6E 53 74 61 74 75 73 'onStatus'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 00 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (8) 00 00 00 00 00 00 00 00 '????????'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 05 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 03 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 05 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (5) 6C 65 76 65 6C 'level'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 02 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 06 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (6) 73 74 61 74 75 73 'status'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 04 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (4) 63 6F 64 65 'code'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 02 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 15 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (21) 4E 65 74 53 74 72 65 61 6D 2E 53 65 65 6B 2E 4E 'NetStream.Seek.N'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 0B '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (11) 64 65 73 63 72 69 70 74 69 6F 6E 'description'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 02 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 07 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (7) 53 65 65 6B 69 6E 67 'Seeking'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (2) 00 00 '??'
2014/07/07 00:39:06 [debug] 28784#0: *1 AMF write (1) 09 '?'
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP prep amf_cmd (20) fmt=0 csid=5 timestamp=0 mlen=94 msid=1 nbufs=1
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP send nmsg=1, priority=0 #163
2014/07/07 00:39:06 [debug] 28784#0: *1 send: fd:3 106 of 106
2014/07/07 00:39:06 [debug] 28784#0: posted event 0000000000000000
2014/07/07 00:39:06 [debug] 28784#0: *1 create: stream_begin msid=1
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP prep user (4) fmt=0 csid=2 timestamp=0 mlen=6 msid=0 nbufs=1
2014/07/07 00:39:06 [debug] 28784#0: *1 RTMP send nmsg=1, priority=0 #164
2014/07/07 00:39:06 [debug] 28784#0: *1 send: fd:3 18 of 18
2014/07/07 00:39:06 [debug] 28784#0: posted event 0000000000000000
2014/07/07 00:39:06 [debug] 28784#0: *1 recv: fd:3 -1 of 146
2014/07/07 00:39:06 [debug] 28784#0: *1 recv() not ready (11: Resource temporarily unavailable)
2014/07/07 00:39:06 [debug] 28784#0: timer delta: 33
2014/07/07 00:39:06 [debug] 28784#0: posted events 000000000121C8D8
2014/07/07 00:39:06 [debug] 28784#0: posted event 000000000121C8D8
2014/07/07 00:39:06 [debug] 28784#0: *1 delete posted event 000000000121C8D8
2014/07/07 00:39:06 [debug] 28784#0: *1 flv: lookup index start timestamp=10000000
2014/07/07 00:39:06 [debug] 28784#0: *1 flv: lookup index timestamp=10000000 offset=begin
2014/07/07 00:39:06 [debug] 28784#0: *1 flv: read tag at offset=13
2014/07/07 00:39:06 [debug] 28784#0: *1 read: 9, 00000000006EAD50, 11, 13
2014/07/07 00:39:06 [debug] 28784#0: *1 play: send restart
2014/07/07 00:39:06 [debug] 28784#0: *1 post event 000000000121C8D8
2014/07/07 00:39:06 [debug] 28784#0: posted event 000000000121C8D8
2014/07/07 00:39:06 [debug] 28784#0: *1 delete posted event 000000000121C8D8

[crackedeggs1]

I have been having the same issue since installing this module in Dec '13. The issue is consistent in all files. When we first attempted to debug the issue we started over with no metadata, used various different tools to generate the metadata, and re-upped the videos. However, there was no difference observed.

Seeking may be successful once or twice in the same video, but excessive forward-seeking and especially attempting to back-seek will just result in the video restarting, or freezing entirely. Frequently, attempting to seek in any direction while the player is in a paused state will cause the request to hang indefinitely.

[arut]

@benmcmeen it looks like there's still no metadata in the flv. I've just tried my flv with the JW Player and it works just fine. Could you send me your file for testing?

[crackedeggs1]

It seems the issue I was experiencing is probably a FlowPlayer bug. I tried the same video in JWPlayer and seeking works as expected.

More clearly, the issue was this:

1. Seeking while playing OK
2. Seeking while paused, player hangs indefinitely

[benmcmeen]

I'm really sorry I haven't been able to reply... I went into a different direction without the VOD - so I've had trouble digging up my old config.

I did experience this in both players, however. I'll try to find some time to replicate.

On Wed, Oct 1, 2014 at 4:19 PM, vaultwiki notifications@github.com wrote:

It seems the issue I was experiencing is probably a FlowPlayer bug. I tried the same video in JWPlayer and seeking works as expected.

More clearly, the issue was this:

1. Seeking while playing OK
2. Seeking while paused, player hangs indefinitely

— Reply to this email directly or view it on GitHub https://github.com/arut/nginx-rtmp-module/issues/432#issuecomment-57540475 .

[gmontard]

Hello,

I think the issue is related to #114 I do a pull from CloudFront and I've the same problem, it's impossible to seek in the video (using JWplayer). But if I use the direct cloudfront stream it works without any problems.

What can i do to help you debug it @vaultwiki ?

Thanks.

[crackedeggs1]

My server streams local files. It does not pull any [streaming] content from anywhere else.

As I mentioned, I think this is an issue with the player and not the server. At this point I am still waiting for time to try FlowPlayer's HTML5 variant to see if that works. Otherwise, I might be buying a license to a different player in the near future.

I had already noticed in the RTMP debug logs that no request was received by the server for the indefinite seeks. This implies to me that the player (FlowPlayer Flash) was not sending a seek request.

Since seeking worked as expected with JWPLayer, as mentioned previously, this further supports this idea, so please don't hold this report open on my account.

[gmontard]

Thanks for your reply.

In fact I'm using JWPlayer and I've got the same problem where seeking is not working. I don't see the problem with a direct RTMP stream but only when using the "proxy"..

[gmontard]

BTW here is my config:

rtmp{
  server {
    listen 1935;
    ping 30s;
    notify_method get;

    application cfx/st {
        live on;
        pull rtmp://SXXXXXXX.cloudfront.net:1935 app=cfx/st;
    }
  }
}

[VackerSimon]

I've had the same issue, my workaround is to remux the recordings to MP4 with ffmpeg on exec_record_done

[hoodsy]

@VackerSimon using ffmpeg -> MP4, but having seeking issues with the vod.

Mind sharing your ffmpeg -> MP4 command?

[VackerSimon]

@hoodsy nginx config: exec_record_done /path/flvtomp4.sh $dirname $basename;

flvtomp4.sh: ffmpeg -i "$1/$2.flv" -copyts -vcodec copy -acodec copy "$1/$2.mp4"