Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

No accelerated colorspace conversion found from yuv420p to rgba. #32

Open
myrmidon-media opened this issue Apr 1, 2013 · 35 comments
Open
Labels

Comments

@myrmidon-media
Copy link

When trying to play one of the streams of http://www.veetle.com, for example:

https://docs.google.com/file/d/0Bw8tro5yHyAlcVFNdklVc3ctSzg/edit?usp=sharing (Flv file)

http://213.254.202.146:80/flv/5106207423acc/testat123 (Stream)

Output gives:

ffmpeg: No accelerated colorspace conversion found from yuv420p to rgba

Shouldn't in this case this statement be true instead of using sws_scale?

if (ctx->pix_fmt == PIX_FMT_YUV420P) 

Version tested: Latest from https://review.appunite.com

@myrmidon-media
Copy link
Author

I guess there's a typo in the code of latest git version:

if (ctx->pix_fmt == PIX_FMT_YUV420P) {
....
}if (ctx->pix_fmt == PIX_FMT_NV12) {
...
}else {}

Should be:

if (ctx->pix_fmt == PIX_FMT_YUV420P) {
....
}else if (ctx->pix_fmt == PIX_FMT_NV12) {
...
}else {}

@myrmidon-media
Copy link
Author

Well once solve this small issue, I'm still unable to play this streams.

This is the output, no video shown.

04-03 01:37:11.561: I/player.c(31342): player_read_from_stream looking for stream
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream stream found [1]
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream waiting for queue
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream Read frame
04-03 01:37:11.561: I/player.c(31342): player_decode_video decoding
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream looking for stream
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream stream found [1]
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream waiting for queue
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream Read frame
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream looking for stream
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream stream found [0]
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream waiting for queue
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream Read frame
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream looking for stream
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream stream found [1]
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream waiting for queue
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream Read frame
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream looking for stream
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream stream found [1]
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream waiting for queue
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream Read frame
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream looking for stream
04-03 01:37:11.561: I/player.c(31342): player_read_from_stream stream found [1]
..etc

These streams play fine in ffplay or vlc.

ffplay  http://213.254.202.146:80/flv/5106207423acc/testat123 -loglevel debug

Any ideas?

@myrmidon-media
Copy link
Author

After playing a while with the code, I was able to get frames showing after changing sleep time:

int64_t sleep_time = (int64_t) (time * 100.0)
                - (int64_t) (time_diff / 100L);

if (sleep_time < -300) {
            int64_t new_value = player->start_time - (sleep_time * 100);
            player->start_time = new_value;
            pthread_cond_broadcast(&player->cond_queue);
        }

Although this helps playing some streams, in some others there's choppy playback.

Any Ideas on how to fix this?

@jacek-marchwicki
Copy link
Member

@pablo-navarro - this was a quite big bug - I will fix it tomorrow.

Log that you presented is quite normal... Maybe your device could not download or decode frames so fast.
Now I cant play your video - probably it is not available or there is slow connection to europe from this streaming server.

Please refer to commit version or change id and pachset because I do not know which version is newest? newest merged or newest in tree or newest commit.
For me there is newest version you should check https://review.appunite.com/#/c/3807/ (with newest pachset)

Please checkout this version - I will probably tomorrow push it to github - but im not sure.

@myrmidon-media
Copy link
Author

@jacek-marchwicki

Hi Jacek I'm testing on this version https://review.appunite.com/#/c/1779/ on patch set 19:

I've just changed log level and this is the output:

04-07 23:26:29.881: I/player.c(25814): player_wait_for_frame[1] Waiting for frame locked
04-07 23:26:29.881: I/player.c(25814): player_wait_for_frame[1 = Audio] = (1205.319000) - (23.190691)
04-07 23:26:29.881: I/player.c(25814): player_wait_for_frame[1] Waiting for frame: sleeping: 1182129
04-07 23:26:29.931: I/player.c(25814): player_wait_for_frame[0] timeout
04-07 23:26:29.931: I/player.c(25814): player_wait_for_frame[0] Waiting for frame
04-07 23:26:29.931: I/player.c(25814): player_wait_for_frame[0] Waiting for frame locked
04-07 23:26:29.931: I/player.c(25814): player_wait_for_frame[0 = Video] = (1205.397000) - (23.241691)
04-07 23:26:29.931: I/player.c(25814): player_wait_for_frame[0] Waiting for frame: sleeping: 1182156
04-07 23:26:30.382: I/player.c(25814): player_wait_for_frame[1] timeout
04-07 23:26:30.382: I/player.c(25814): player_wait_for_frame[1] Waiting for frame
04-07 23:26:30.392: I/player.c(25814): player_wait_for_frame[1] Waiting for frame locked
04-07 23:26:30.392: I/player.c(25814): player_wait_for_frame[1 = Audio] = (1205.319000) - (23.696567)
04-07 23:26:30.392: I/player.c(25814): player_wait_for_frame[1] Waiting for frame: sleeping: 1181623
04-07 23:26:30.432: I/player.c(25814): player_wait_for_frame[0] timeout
04-07 23:26:30.432: I/player.c(25814): player_wait_for_frame[0] Waiting for frame
04-07 23:26:31.172: I/player.c(25814): player_decode waiting for frame[1]

I have tested on a nexus 4, nexus 7 and galaxy s III so I don't think it's a problem of the device not being faster enough to decode frames, I would also discard networks issues as the stream play well with vlc on android for example. And also the same happens when playing file stored on the device.

When I saw this timeout thing I just tried changing sleep time, and after doing so, frames are showing although audio is not sync.

I will check the version you mention. Thanks

@myrmidon-media
Copy link
Author

Just for the record, normal output happens with just reducing sleep_time by a factor of 10 as pointed out above, although audio is not sync:

04-07 23:43:49.771: I/player.c(26403): player_write_audio releasing local ref
04-07 23:43:52.874: I/player.c(26403): player_read_from_stream stream found [1]
04-07 23:43:52.874: I/player.c(26403): player_read_from_stream waiting for queue
04-07 23:43:52.874: I/player.c(26403): player_decode decoding frame[1]
04-07 23:43:52.874: I/player.c(26403): player_decode_audio decoding
04-07 23:43:52.874: I/player.c(26403): player_decode_audio Decoded audio frame
04-07 23:43:52.874: I/player.c(26403): Format: WINDOW_FORMAT_RGBA_8888
04-07 23:43:52.874: I/player.c(26403): Buffer: width: 576, height: 432, stride: 576
04-07 23:43:52.874: I/player.c(26403): player_decode_video copying...
04-07 23:43:52.874: I/player.c(26403): player_write_audio Writing audio frame
04-07 23:43:52.874: I/player.c(26403): player_write_audio - read from pts

PS: I accidentally clicked in close and comment :)

@myrmidon-media
Copy link
Author

@jacek-marchwicki

I've just tested with the version https://review.appunite.com/#/c/3807/ , with the same timeout results.

@myrmidon-media
Copy link
Author

@jacek-marchwicki

If we force diff_time to be (without touching sleep time):

int64_t time_diff = current_time - player->audio_clock;

in player_wait_for_frame(), frames show again normally although no audio sync.

@GiuseppeIuculano
Copy link

@jacek-marchwicki I'm testing https://review.appunite.com/#/c/3807/ and I've the same timeout results.

@jacek-marchwicki
Copy link
Member

if issue fix: https://review.appunite.com/#/c/3992

@jacek-marchwicki
Copy link
Member

in method you can try to use larger queue size. It will reduce network latency. And can consume problems where audio frames are rarely interlaced with video frames.

int player_alloc_queues(struct State *state) {
    struct Player *player = state->player;
    int capture_streams_no = player->caputre_streams_no;
    int stream_no;
    for (stream_no = 0; stream_no < capture_streams_no; ++stream_no) {
        player->packets[stream_no] = queue_init_with_custom_lock(50,
                (queue_fill_func) player_fill_packet,
                (queue_free_func) player_free_packet, state, state,
                &player->mutex_queue, &player->cond_queue);
        if (player->packets[stream_no] == NULL) {
            return -ERROR_COULD_NOT_PREPARE_PACKETS_QUEUE;
        }
    }
    return 0;
}

@myrmidon-media
Copy link
Author

No luck increasing size, I tried with 150 and 300.

My tests show:

int64_t sleep_time = stream_time - player->audio_clock;

Works great audio and video synchronized

int64_t time_diff = current_time - player->audio_clock;

Frames showing although audio is not synchronized

This issue is not realted only to veetle also happens with m3u8 files. Temporary solution above solves the issue on both veetle streams and m3u8 streams

http://iphone-streaming.ustream.tv/uhls/13286068/streams/live/iphone/playlist.m3u8

@jacek-marchwicki
Copy link
Member

You wrote that you have in logs something like this:

04-07 23:26:29.931: I/player.c(25814): player_wait_for_frame[0 = Video] = (1205.397000) - (23.241691)

This mean that you trying play video frame that should be played in 1205's second and you are now in 23's second. And this is correct that this frame is held.
But this is wired why video and audio frame have so stream_time or why your playback time is wrong.

Maybe because late frames synchronization method adjusted current playing time to older one.
Do you have in logs something like:

player_wait_for_frame[%d] Waiting for frame: sleeping: %

That message mean that you received late frame. And playback time will be moved a little back to stable synchronization.

Unfortunately non of your links works - I can't test it by myself.

@myrmidon-media
Copy link
Author

Try with these two:

http://213.254.202.139:80/flv/5105f4160ac15/testat123

http://iphone-streaming.ustream.tv/uhls/8236239/streams/live/iphone/playlist.m3u8

I'll change loglevel recompile and tell you what the logs say

Btw in first post you can download from google docs a test file pulled from veetle

@myrmidon-media
Copy link
Author

The log:

04-17 11:50:11.845: I/player.c(30037): player_wait_for_frame[0] timeout
04-17 11:50:11.845: I/player.c(30037): player_wait_for_frame[0 = Video] = (0.000000) - (13.686342)
04-17 11:50:11.845: I/player.c(30037): player_wait_for_frame[0] Waiting for frame: sleeping: 480750658
04-17 11:50:12.276: I/player.c(30037): player_wait_for_frame[1] timeout
04-17 11:50:12.276: I/player.c(30037): player_wait_for_frame[1 = Audio] = (0.000000) - (14.115672)
04-17 11:50:12.276: I/player.c(30037): player_wait_for_frame[1] Waiting for frame: sleeping: 480292328
04-17 11:50:12.346: I/player.c(30037): player_wait_for_frame[0] timeout
04-17 11:50:12.346: I/player.c(30037): player_wait_for_frame[0 = Video] = (0.000000) - (14.187029)
04-17 11:50:12.346: I/player.c(30037): player_wait_for_frame[0] Waiting for frame: sleeping: 480249971
04-17 11:50:12.776: I/player.c(30037): player_wait_for_frame[1] timeout
04-17 11:50:12.776: I/player.c(30037): player_wait_for_frame[1 = Audio] = (0.000000) - (14.616542)
04-17 11:50:12.776: I/player.c(30037): player_wait_for_frame[1] Waiting for frame: sleeping: 479791458
04-17 11:50:12.846: I/player.c(30037): player_wait_for_frame[0] timeout
04-17 11:50:12.846: I/player.c(30037): player_wait_for_frame[0 = Video] = (0.000000) - (14.687716)
04-17 11:50:12.846: I/player.c(30037): player_wait_for_frame[0] Waiting for frame: sleeping: 479749284
04-17 11:50:13.277: I/player.c(30037): player_wait_for_frame[1] timeout
04-17 11:50:13.277: I/player.c(30037): player_wait_for_frame[1 = Audio] = (0.000000) - (15.117290)
04-17 11:50:13.277: I/player.c(30037): player_wait_for_frame[1] Waiting for frame: sleeping: 479290710

@jacek-marchwicki
Copy link
Member

Pleas try again with: https://review.appunite.com/4017

@myrmidon-media
Copy link
Author

Here we go:

04-17 19:47:16.699: I/player.c(7312): player_wait_for_frame[1 = Audio] = (24.320000) - (5.101512)
04-17 19:47:16.699: I/player.c(7312): player_wait_for_frame[1] Waiting for frame: sleeping: 19218488
04-17 19:47:16.729: I/player.c(7312): player_wait_for_frame[0] timeout
04-17 19:47:16.729: I/player.c(7312): player_wait_for_frame[0 = Video] = (24.353000) - (5.127685)
04-17 19:47:16.729: I/player.c(7312): player_wait_for_frame[0] Waiting for frame: sleeping: 19225315
04-17 19:47:17.199: I/player.c(7312): player_wait_for_frame[1] timeout
04-17 19:47:17.199: I/player.c(7312): player_wait_for_frame[1 = Audio] = (24.320000) - (5.603647)
04-17 19:47:17.199: I/player.c(7312): player_wait_for_frame[1] Waiting for frame: sleeping: 18716353
04-17 19:47:17.229: I/player.c(7312): player_wait_for_frame[0] timeout
04-17 19:47:17.229: I/player.c(7312): player_wait_for_frame[0 = Video] = (24.353000) - (5.627951)
04-17 19:47:17.229: I/player.c(7312): player_wait_for_frame[0] Waiting for frame: sleeping: 18725049
04-17 19:47:17.699: I/player.c(7312): player_wait_for_frame[1] timeout
04-17 19:47:17.699: I/player.c(7312): player_wait_for_frame[1 = Audio] = (24.320000) - (6.105504)
04-17 19:47:17.709: I/player.c(7312): player_wait_for_frame[1] Waiting for frame: sleeping: 18214496
04-17 19:47:17.729: I/player.c(7312): player_wait_for_frame[0] timeout
04-17 19:47:17.729: I/player.c(7312): player_wait_for_frame[0 = Video] = (24.353000) - (6.128211)
04-17 19:47:17.729: I/player.c(7312): player_wait_for_frame[0] Waiting for frame: sleeping: 18224789
04-17 19:47:18.209: I/player.c(7312): player_wait_for_frame[1] timeout
04-17 19:47:18.209: I/player.c(7312): player_wait_for_frame[1 = Audio] = (24.320000) - (6.610612)
04-17 19:47:18.209: I/player.c(7312): player_wait_for_frame[1] Waiting for frame: sleeping: 17709388
04-17 19:47:18.229: I/player.c(7312): player_wait_for_frame[0] timeout
04-17 19:47:18.229: I/player.c(7312): player_wait_for_frame[0 = Video] = (24.353000) - (6.628562)
04-17 19:47:18.229: I/player.c(7312): player_wait_for_frame[0] Waiting for frame: sleeping: 17724438
04-17 19:47:18.709: I/player.c(7312): player_wait_for_frame[1] timeout
04-17 19:47:18.709: I/player.c(7312): player_wait_for_frame[1 = Audio] = (24.320000) - (7.111691)
04-17 19:47:18.709: I/player.c(7312): player_wait_for_frame[1] Waiting for frame: sleeping: 17208309
04-17 19:47:18.729: I/player.c(7312): player_wait_for_frame[0] timeout
04-17 19:47:18.729: I/player.c(7312): player_wait_for_frame[0 = Video] = (24.353000) - (7.128937)
04-17 19:47:18.729: I/player.c(7312): player_wait_for_frame[0] Waiting for frame: sleeping: 17224063
04-17 19:47:19.219: I/player.c(7312): player_wait_for_frame[1] timeout
04-17 19:47:19.229: I/player.c(7312): player_wait_for_frame[1 = Audio] = (24.320000) - (7.630162)
04-17 19:47:19.239: I/player.c(7312): player_wait_for_frame[1] Waiting for frame: sleeping: 16689838
04-17 19:47:19.239: I/player.c(7312): player_wait_for_frame[0] timeout
04-17 19:47:19.249: I/player.c(7312): player_wait_for_frame[0 = Video] = (24.353000) - (7.649456)
04-17 19:47:19.249: I/player.c(7312): player_wait_for_frame[0] Waiting for frame: sleeping: 16703544
04-17 19:47:19.379: I/player.c(7312): jni_player_render_frame_stop stopping render
04-17 19:47:19.379: I/player.c(7312): player_stop_without_lock stopping...
04-17 19:47:19.379: I/player.c(7312): player_read_from_stream queue interrupt stop
04-17 19:47:19.379: I/player.c(7312): player_read_from_stream stop
04-17 19:47:19.379: I/player.c(7312): player_wait_for_frame[1] stop_streams
04-17 19:47:19.379: I/player.c(7312): player_wait_for_frame[1] finish[1]
04-17 19:47:19.379: I/player.c(7312): player_update_time: 7.784704/0.000000
04-17 19:47:19.379: I/player.c(7312): player_wait_for_frame[0] stop_streams
04-17 19:47:19.379: I/player.c(7312): player_wait_for_frame[0] finish[1]
04-17 19:47:19.379: I/player.c(7312): player_update_current_time: 7.784704/7.784704

@jacek-marchwicki
Copy link
Member

This means that you receiving frames that should be displayed in 24's second, but player think that now is 7's second.

Did you hade somewhere in logs: "player_wait_for_frame[%d] correcting %f to %f because late"?

If there is no "correcting" string, probably there is issue while reading time from stream:

int64_t time = av_rescale_q(pts, stream->time_base, AV_TIME_BASE_Q);

maybe you should read time_base from context instead of reading it from stream?

@myrmidon-media
Copy link
Author

There is no such message "player_wait_for_frame[%d] correcting %f to %f because late"

By reading from context do you mean this?

int64_t time = av_rescale_q(pts, ctx->time_base, AV_TIME_BASE_Q);

In that case the differences are bigger:

04-17 21:14:05.219: I/player.c(16726): player_wait_for_frame[0] timeout
04-17 21:14:05.229: I/player.c(16726): player_wait_for_frame[0 = Video] = (1796.876981) - (6.066120)
04-17 21:14:05.229: I/player.c(16726): player_wait_for_frame[0] Waiting for frame: sleeping: 1790810861
04-17 21:14:05.699: I/player.c(16726): player_wait_for_frame[1] timeout
04-17 21:14:05.699: I/player.c(16726): player_wait_for_frame[1 = Audio] = (86.144000) - (6.540830)
04-17 21:14:05.699: I/player.c(16726): player_wait_for_frame[1] Waiting for frame: sleeping: 79603170
04-17 21:14:05.729: I/player.c(16726): player_wait_for_frame[0] timeout
04-17 21:14:05.729: I/player.c(16726): player_wait_for_frame[0 = Video] = (1796.876981) - (6.566555)
04-17 21:14:05.729: I/player.c(16726): player_wait_for_frame[0] Waiting for frame: sleeping: 1790310426

I'm completely blind here but maybe we can find something useful in ffplay source

@jacek-marchwicki
Copy link
Member

This looks much more wrong. Can you provide me this video file? It looks like your video starts counting time from 18th second's.

@myrmidon-media
Copy link
Author

Sure:

I've pulled 1 min from the stream, you can download it from here:

https://docs.google.com/file/d/0Bw8tro5yHyAlTjJwVk9tNFFwRkk/edit?usp=sharing

And the live stream:

http://213.254.202.149:80/flv/5105f4160ac15/testat123

@GiuseppeIuculano
Copy link

This happens also with my streams:

I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64672923967
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (7.049260)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64672394607
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (7.057988)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64672417879
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (7.554006)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64671889861
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (7.566031)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64671909836
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (8.057683)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64671386184
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (8.069983)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64671405884
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (8.561849)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64670882018
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (8.575187)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64670900680
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (9.065649)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64670378218
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (9.078346)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64670397521
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (9.569113)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64669874754
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (9.582298)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64669893569
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (10.072425)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64669371442
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (10.086311)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64669389556
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (10.576987)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64668866880
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (10.589470)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64668886397
I/player.c( 3383): player_wait_for_frame[0] timeout
I/player.c( 3383): player_wait_for_frame[0 = Video] = (64679.443867) - (11.080665)
I/player.c( 3383): player_wait_for_frame[0] Waiting for frame: sleeping: 64668363202
I/player.c( 3383): player_wait_for_frame[1] timeout
I/player.c( 3383): player_wait_for_frame[1 = Audio] = (64679.475867) - (11.092629)
I/player.c( 3383): player_wait_for_frame[1] Waiting for frame: sleeping: 64668383238

@jacek-marchwicki
Copy link
Member

I found in @pablo-navarro something like this:

ffprobe test.flv
ffprobe version N-44186-gb3fdfc8 Copyright (c) 2007-2012 the FFmpeg developers
  built on Sep  5 2012 21:25:22 with Apple clang version 3.1 (tags/Apple/clang-318.0.61) (based on LLVM 3.1svn)
  configuration: --prefix=/private/tmp/homebrew-ffmpeg-HEAD-LW3f/runtime --enable-static --disable-shared --enable-postproc --enable-nonfree --enable-libx264 --enable-gpl --enable-libfaac --enable-libmp3lame --enable-libtheora --enable-libxvid --enable-libvorbis --enable-libgsm --enable-libvpx --enable-avfilter --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-version3 --disable-ffplay --disable-ffserver --disable-network --disable-devices --disable-doc --cc=clang --extra-cflags=--static --extra-ldflags= --bindir=/private/tmp/homebrew-ffmpeg-HEAD-LW3f/dist/bin --incdir=/private/tmp/homebrew-ffmpeg-HEAD-LW3f/dist/include --libdir=/private/tmp/homebrew-ffmpeg-HEAD-LW3f/dist/lib --prefix=/usr/local/Cellar/ffmpeg/HEAD
  libavutil      51. 71.101 / 51. 71.101
  libavcodec     54. 55.100 / 54. 55.100
  libavformat    54. 25.104 / 54. 25.104
  libavdevice    54.  2.100 / 54.  2.100
  libavfilter     3. 15.103 /  3. 15.103
  libswscale      2.  1.101 /  2.  1.101
  libswresample   0. 15.100 /  0. 15.100
  libpostproc    52.  0.100 / 52.  0.100
Input #0, flv, from '/Users/mac/Downloads/test.flv':
  Metadata:
    canSeekToEnd    : false
  Duration: 00:00:00.00, start: 709.208000, bitrate: -2147483 kb/s
    Stream #0:0: Video: h264 (Main), yuv420p, 512x384 [SAR 1:1 DAR 4:3], 23.98 tbr, 1k tbn, 47.95 tbc
    Stream #0:1: Audio: mp3, 48000 Hz, stereo, s16, 96 kb/s

For me wired is: "start: 709.208000", because I usually get "start: 0.000000"

@Derevko Could you find something simillar?

@jacek-marchwicki
Copy link
Member

Maybe there we need only add something like this at start point to current time.

int_64_t start_time = av_rescale_q(input_format_ctx->start_time, input_format_ctx->time_base, AV_TIME_BASE_Q)

?

@GiuseppeIuculano
Copy link

@jacek-marchwicki why it is strange? if it is a live stream this is not strange.

My is:

 Duration: 00:00:00.13, start: 65179.443867, bitrate: 40 kb/s
    Stream #0:0: Video: h264 (Constrained Baseline) ([27][0][0][0] / 0x001B), yuv420p, 480x270, 25 fps, 25 tbr, 90k tbn, 50 tbc
    Stream #0:1: Audio: aac ([15][0][0][0] / 0x000F), 32000 Hz, stereo, s16, 40 kb/s

@myrmidon-media
Copy link
Author

@jacek-marchwicki

You got it:

//int64_t current_time = av_gettime();
        int64_t current_time = av_rescale_q(player->input_format_ctx->start_time, seek_input_stream->time_base, AV_TIME_BASE_Q);
        player->start_time = current_time - player->seek_position;
        player->pause_time = current_time;

I'm testing in different files and streams and seems to work

@GiuseppeIuculano
Copy link

@pablo-navarro do you replace it only in player_read_from_stream() ? My streams don't work with your proposed patch...

@myrmidon-media
Copy link
Author

@Derevko

My mistake I rushed. You are right I stumbled upon one stream that's not working with the patch.

04-18 12:56:03.897: I/player.c(20022): player_wait_for_frame[0 = Video] = (685.179000) - (57.464886)
04-18 12:56:03.897: I/player.c(20022): player_wait_for_frame[0] Waiting for frame: sleeping: 627714114
04-18 12:56:04.388: I/player.c(20022): player_wait_for_frame[1] timeout
04-18 12:56:04.388: I/player.c(20022): player_wait_for_frame[1 = Audio] = (685.160000) - (57.956936)
04-18 12:56:04.388: I/player.c(20022): player_wait_for_frame[1] Waiting for frame: sleeping: 627203064
04-18 12:56:04.398: I/player.c(20022): player_wait_for_frame[0] timeout
04-18 12:56:04.398: I/player.c(20022): player_wait_for_frame[0 = Video] = (685.179000) - (57.966702)
04-18 12:56:04.398: I/player.c(20022): player_wait_for_frame[0] Waiting for frame: sleeping: 627212298

@jacek-marchwicki
Copy link
Member

@pablo-navarro Did you use time_base from input_stream? AFAIK you should use time_base from input_format_ctx

Where exactly did you wrote this code?

@myrmidon-media
Copy link
Author

@jacek-marchwicki

I'm putting this code in player_read_from_stream(). input_format_context doesn't have time_base.

I tried with this:

void * player_read_from_stream(void *data)
{
......

LOGI(3, "player_read_from_stream seeking success");

        //int64_t current_time = av_gettime();
        int64_t current_time = av_rescale_q(player->input_format_ctx->start_time, player->input_codec_ctxs[player->video_stream_no]->time_base, AV_TIME_BASE_Q);
        player->start_time = current_time - player->seek_position;
        player->pause_time = current_time;

        // request stream to flush
        player_assign_to_no_boolean_array(player, player->flush_streams, TRUE);

....
}

But isn't working either:


04-19 11:58:13.898: I/player.c(20023): player_wait_for_frame[1 = Audio] = (320.009000) - (10.566275)
04-19 11:58:13.898: I/player.c(20023): player_wait_for_frame[1] Waiting for frame: sleeping: 309442725
04-19 11:58:13.908: I/player.c(20023): player_wait_for_frame[0] timeout
04-19 11:58:13.908: I/player.c(20023): player_wait_for_frame[0 = Video] = (320.000000) - (10.572593)
04-19 11:58:13.908: I/player.c(20023): player_wait_for_frame[0] Waiting for frame: sleeping: 309427407
04-19 11:58:14.399: I/player.c(20023): player_wait_for_frame[1] timeout
04-19 11:58:14.399: I/player.c(20023): player_wait_for_frame[1 = Audio] = (320.009000) - (11.066443)
04-19 11:58:14.399: I/player.c(20023): player_wait_for_frame[1] Waiting for frame: sleeping: 308942557

@myrmidon-media
Copy link
Author

@Derevko

Can you test how this works for you:

struct Player {
...
+    int64_t video_start_time;

..

}


void player_get_video_duration(struct Player *player) {
    player->last_updated_time = -1;
    player->video_duration = 0;
+   player->video_start_time = 0;
    int i;

+ for (i = 0; i < player->capture_streams_no; ++i) {
+       AVStream *stream = player->input_streams[i];
+       if (stream->start_time > 0) {
+           player->video_start_time = av_rescale_q(
+                   stream->start_time, stream->time_base, AV_TIME_BASE_Q);
+           LOGI(3,
+                   "player_set_data_source stream[%d] start_time: %ld",
+                   i, player->video_start_time);
+           break;
+       }
+   }

....

}

inline int64_t player_get_current_video_time(struct Player *player) {
....

-  int64_t current_time = av_gettime();
+ int64_t current_time = av_gettime() + player->video_start_time; 

...

}

Modify Logs also in player_wait_for_frame():

LOGI(8,
                "player_wait_for_frame[%d = %s] = (%f) - (%f)",
                stream_no,
                player->video_stream_no == stream_no ? "Video" : "Audio",
                        stream_time/1000000.0,
                        current_video_time/1000000.0);

        int64_t sleep_time = stream_time - current_video_time;

        LOGI(8,
                "player_wait_for_frame[%d] Waiting for frame: sleeping: %" SCNd64,
                stream_no, sleep_time);

@pbarvinko
Copy link

@pablo-navarro
I would like to confirm that the latest patch that you have posted works with the transport stream files where timestamp does not start with 0. There are some other issues still - like cannot seek in a video using the demo app - but that's something not critical at this point.

I do have an issue however with playing live transport streams (not files), delivered using http. The video starts and plays for 5-6 seconds and then hangs waiting for a frame that never arrives. Would you happen to have an advise where I should start looking for a reason? thanks.

@myrmidon-media
Copy link
Author

@pbarvinko

Probably the reason is in function player_wait_for_frame(). Can you post the stream url so I can test it?

@pbarvinko
Copy link

@pablo-navarro

I would be very much happy to provide you with a link, but unfortunately it is not the internet stream.
We are makers of DVBLink software and this is a stream produced by our own server software, which users run in-house - either on PC or on a NAS platform, streaming live TV from antenna, satellite or cable.


Edit.
I have found the reason for the hangup on the live streams. The queues allocated by player_alloc_queues function are not big enough to hold the real-time stream pushed in between player_open_input and player_start_decoding_threads. Increasing number of nodes in the queue to 300 has done the trick. But probably we need a better approach here with a largest queue for video stream, large queues for audio streams and small queues for other elementary streams not to waste the memory.

@kostaspl
Copy link

kostaspl commented Jan 6, 2014

Hi guys.

Any news on this issue?
I used the patch posted by @pablo-navarro , which finally gave me rendered frames but it seems to stop after a while (a few seconds) waiting for a frame forever.
I tried what @pbarvinko suggested, increased queue size even up to 1000, but still seems to pause after a while.

The device is decoding it pretty easy (low CPU use).

I'm trying to playback a MPEG-TS stream (MPEG-2 video, AC3 audio), streamed locally via HTTP by FFmpeg executable, coming from a USB DVB/ATSC card.

  • I'm using latest FFmpeg code with this, but it seems the behavior is similar even with the one that comes with your default git config.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

5 participants