libdvr: Unexpect exit from playing scrambled recordings [1/1]
PD#SWPL-102457
PD#SWPL-102797
PD#SWPL-103132
Problem:
Playback can exit unexpectly while playing a scrambled recording.
cause1: demux returns invalid pts when processing a scrambled stream.
Invalid pts will lead to delay time problem in TsPlayer.
cause2: A defect in dvr_wrapper_seek_playback which may return full
recording length instead of segment length while seeking to the end
of a recording.
Solution:
1. Enhance libdvr to handle delay/pts error condition.
2. Fix the mentioned defect in dvr_wrapper_seek_playback.
3. Improve log prints for fast analyzing similar problem in the future.
4. Remove useless log prints.
Verify:
Locally tested OK in AH212 environment.
Signed-off-by: Wentao.MA <wentao.ma@amlogic.com>
Change-Id: I971b97207b35df82f82f857bd0d6dcba16a8c39f
diff --git a/src/dvr_playback.c b/src/dvr_playback.c
index a92e5e4..b50f8aa 100644
--- a/src/dvr_playback.c
+++ b/src/dvr_playback.c
@@ -63,7 +63,7 @@
static int _dvr_playback_sent_transition_ok(DVR_PlaybackHandle_t handle, DVR_Bool_t is_lock);
static uint32_t dvr_playback_calculate_last_valid_segment(
DVR_PlaybackHandle_t handle, uint64_t *segmentid, uint32_t *pos);
-static int get_effective_tsplayer_delay_time(DVR_Playback_t* playback,int64_t* time);
+static int get_effective_tsplayer_delay_time(DVR_Playback_t* playback, int *time);
@@ -190,67 +190,43 @@
break;
}
}
+
void _dvr_tsplayer_callback(void *user_data, am_tsplayer_event *event)
{
- DVR_Playback_t *player = NULL;
- if (user_data != NULL) {
- player = (DVR_Playback_t *) user_data;
- DVR_PB_INFO("playing speed is [%f] in callback", player->speed);
+ DVR_Playback_t *play = (DVR_Playback_t*)user_data;
+ if (play == NULL) {
+ DVR_PB_WARN("play is invalid in %s",__func__);
+ return;
}
switch (event->type) {
- case AM_TSPLAYER_EVENT_TYPE_VIDEO_CHANGED:
- {
- DVR_PB_INFO("[evt] AM_TSPLAYER_EVENT_TYPE_VIDEO_CHANGED: %d x %d @%d\n",
- event->event.video_format.frame_width,
- event->event.video_format.frame_height,
- event->event.video_format.frame_rate);
- break;
- }
case AM_TSPLAYER_EVENT_TYPE_FIRST_FRAME:
- {
- DVR_PB_INFO("[evt] AM_TSPLAYER_EVENT_TYPE_FIRST_FRAME\n");
- if (player == NULL) {
- DVR_PB_WARN("player is null at line %d",__LINE__);
- break;
- }
- if (player->first_trans_ok == DVR_FALSE) {
- player->first_trans_ok = DVR_TRUE;
- _dvr_playback_sent_transition_ok((DVR_PlaybackHandle_t)player, DVR_FALSE);
- }
- if (player != NULL) {
- player->first_frame = 1;
- player->seek_pause = DVR_FALSE;
- }
- break;
- }
+ DVR_PB_INFO("Received AM_TSPLAYER_EVENT_TYPE_FIRST_FRAME");
+ if (play->first_trans_ok == DVR_FALSE) {
+ play->first_trans_ok = DVR_TRUE;
+ _dvr_playback_sent_transition_ok((DVR_PlaybackHandle_t)play, DVR_FALSE);
+ }
+ play->first_frame = 1;
+ play->seek_pause = DVR_FALSE;
+ break;
case AM_TSPLAYER_EVENT_TYPE_DECODE_FIRST_FRAME_AUDIO:
- DVR_PB_INFO("[evt]AM_TSPLAYER_EVENT_TYPE_DECODE_FIRST_FRAME_AUDIO [%d]\n", event->type);
- if (player == NULL) {
- DVR_PB_WARN("player is null at line %d",__LINE__);
- break;
- }
- if (player->first_trans_ok == DVR_FALSE && player->has_video == DVR_FALSE) {
- player->first_trans_ok = DVR_TRUE;
- _dvr_playback_sent_transition_ok((DVR_PlaybackHandle_t)player, DVR_FALSE);
- }
- if (player != NULL && player->has_video == DVR_FALSE) {
- DVR_PB_INFO("[evt]AM_TSPLAYER_EVENT_TYPE_DECODE_FIRST_FRAME_AUDIO [%d]\n", event->type);
- player->first_frame = 1;
- player->seek_pause = DVR_FALSE;
- }
+ DVR_PB_INFO("Received AM_TSPLAYER_EVENT_TYPE_DECODE_FIRST_FRAME_AUDIO");
+ if (play->first_trans_ok == DVR_FALSE && play->has_video == DVR_FALSE) {
+ play->first_trans_ok = DVR_TRUE;
+ _dvr_playback_sent_transition_ok((DVR_PlaybackHandle_t)play, DVR_FALSE);
+ }
+ if (play->has_video == DVR_FALSE) {
+ play->first_frame = 1;
+ play->seek_pause = DVR_FALSE;
+ }
break;
default:
- DVR_PB_INFO("[evt]unknown event [%d]\n", event->type);
break;
}
- if (player&&player->player_callback_func) {
- DVR_PB_INFO("calling callback");
- player->player_callback_func(player->player_callback_userdata, event);
- } else if (player == NULL){
- DVR_PB_WARN("player pointer %p is invalid",player);
- } else {
- DVR_PB_WARN("player callback function %p is invalid",player->player_callback_func);
+ if (play->player_callback_func == NULL) {
+ DVR_PB_WARN("play callback function %p is invalid",play->player_callback_func);
+ return;
}
+ play->player_callback_func(play->player_callback_userdata, event);
}
//convert video and audio fmt
@@ -369,18 +345,7 @@
dvr_mutex_restore(&player->lock, val);
return 0;
}
-//get tsplay delay time ms
-static int _dvr_playback_get_delaytime(DVR_PlaybackHandle_t handle ) {
- DVR_Playback_t *player = (DVR_Playback_t *) handle;
- int64_t cache = 0;
- if (player == NULL || player->handle == (am_tsplayer_handle)NULL) {
- DVR_PB_INFO("tsplayer delay time error, handle is NULL");
- return 0;
- }
- AmTsPlayer_getDelayTime(player->handle, &cache);
- DVR_PB_INFO("tsplayer cache time [%lld]ms", cache);
- return cache;
-}
+
//send signal
static int _dvr_playback_sendSignal(DVR_PlaybackHandle_t handle)
{
@@ -869,7 +834,6 @@
//get segment info
if (player->cur_segment_id != UINT64_MAX)
player->cur_segment_id = segment->segment_id;
- DVR_PB_INFO("get play info id [%lld]", player->cur_segment_id);
player->cur_segment.segment_id = segment->segment_id;
player->cur_segment.flags = segment->flags;
//pids
@@ -890,7 +854,9 @@
audio_param->pid = segment->pids.audio.pid;
ad_param->codectype =_dvr_convert_stream_fmt(segment->pids.ad.format, DVR_TRUE);
ad_param->pid =segment->pids.ad.pid;
- DVR_PB_INFO("get play info success[0x%x]apid[0x%x]vfmt[%d]afmt[%d]", video_param->pid, audio_param->pid, video_param->codectype, audio_param->codectype);
+ DVR_PB_DEBUG("get_playinfo, segment_id:%lld, vpid[0x%x], apid[0x%x], vfmt[%d], afmt[%d]",
+ player->cur_segment_id, video_param->pid, audio_param->pid,
+ video_param->codectype, audio_param->codectype);
found = 2;
break;
}
@@ -1323,26 +1289,22 @@
if (read == 0) {
//file end.need to play next segment
#define MIN_CACHE_TIME (3000)
- int _cache_time = _dvr_playback_get_delaytime((DVR_PlaybackHandle_t)player) ;
+ int delay = 0;
+ get_effective_tsplayer_delay_time(player,&delay);
/*if cache time is > min cache time ,not read next segment,wait cache data to play*/
- if (_cache_time > MIN_CACHE_TIME) {
+ if (delay > MIN_CACHE_TIME) {
//dvr_mutex_lock(&player->lock);
/*if cache time > 20s , we think get time is error,*/
- if (_cache_time - MIN_CACHE_TIME > 20 * 1000) {
- DVR_PB_WARN("read end but cache time is %d > 20s, this is an error at media_hal", _cache_time);
+ if (delay - MIN_CACHE_TIME > 20 * 1000) {
+ DVR_PB_WARN("read end but cache time is %d > 20s, this is an error at media_hal", delay);
}
- //_dvr_playback_timeoutwait((DVR_PlaybackHandle_t)player, ((_cache_time - MIN_CACHE_TIME) > MIN_CACHE_TIME ? MIN_CACHE_TIME : (_cache_time - MIN_CACHE_TIME)));
- //dvr_mutex_unlock(&player->lock);
- // DVR_PB_INFO("read end but cache time is %d > %d, to sleep end and continue", _cache_time, MIN_CACHE_TIME);
- //continue;
}
int ret = _change_to_next_segment((DVR_PlaybackHandle_t)player);
//init fffb time if change segment
_dvr_init_fffb_time((DVR_PlaybackHandle_t)player);
- int delay = _dvr_playback_get_delaytime((DVR_PlaybackHandle_t)player);
-
+ get_effective_tsplayer_delay_time(player,&delay);
if (ret != DVR_SUCCESS && delay < MIN_TSPLAYER_DELAY_TIME) {
player->noData++;
DVR_PB_INFO("playback nodata[%d]", player->noData);
@@ -1369,31 +1331,32 @@
" cond5:%d, cond6:%d. delay:%d, reach_end_timeout:%d",
(int)cond1,(int)cond2,(int)cond3,(int)cond4,(int)cond5,(int)cond6,
delay,reach_end_timeout);
- DVR_Play_Notify_t notify;
- memset(¬ify, 0 , sizeof(DVR_Play_Notify_t));
- notify.event = DVR_PLAYBACK_EVENT_REACHED_END;
- dvr_playback_pause((DVR_PlaybackHandle_t)player, DVR_FALSE);
- _dvr_playback_sent_event((DVR_PlaybackHandle_t)player, DVR_PLAYBACK_EVENT_REACHED_END, ¬ify, DVR_TRUE);
- dvr_mutex_lock(&player->lock);
- _dvr_playback_timeoutwait((DVR_PlaybackHandle_t)player, timeout);
- dvr_mutex_unlock(&player->lock);
- continue;
- } else if (ret != DVR_SUCCESS) {
- DVR_PB_INFO("delay:%d pauselive:%d", delay, _dvr_pauselive_decode_success((DVR_PlaybackHandle_t)player));
- dvr_mutex_lock(&player->lock);
- _dvr_playback_timeoutwait((DVR_PlaybackHandle_t)player, timeout);
- dvr_mutex_unlock(&player->lock);
- delay = _dvr_playback_get_delaytime((DVR_PlaybackHandle_t)player);
- //not send event and pause,sleep and go to next time to recheck
- if (delay < cache_time) {
- //delay time is changed and then has data to play, so not start timeout
- reach_end_timeout = 0;
- } else {
- reach_end_timeout = reach_end_timeout + timeout;
- }
- cache_time = delay;
- continue;
- }
+ DVR_Play_Notify_t notify;
+ memset(¬ify, 0 , sizeof(DVR_Play_Notify_t));
+ notify.event = DVR_PLAYBACK_EVENT_REACHED_END;
+ dvr_playback_pause((DVR_PlaybackHandle_t)player, DVR_FALSE);
+ _dvr_playback_sent_event((DVR_PlaybackHandle_t)player, DVR_PLAYBACK_EVENT_REACHED_END, ¬ify, DVR_TRUE);
+ dvr_mutex_lock(&player->lock);
+ _dvr_playback_timeoutwait((DVR_PlaybackHandle_t)player, timeout);
+ dvr_mutex_unlock(&player->lock);
+ continue;
+ } else if (ret != DVR_SUCCESS) {
+ DVR_PB_INFO("delay:%d pauselive:%d", delay, _dvr_pauselive_decode_success((DVR_PlaybackHandle_t)player));
+ dvr_mutex_lock(&player->lock);
+ _dvr_playback_timeoutwait((DVR_PlaybackHandle_t)player, timeout);
+ dvr_mutex_unlock(&player->lock);
+
+ get_effective_tsplayer_delay_time(player,&delay);
+ //not send event and pause,sleep and go to next time to recheck
+ if (delay < cache_time) {
+ //delay time is changed and then has data to play, so not start timeout
+ reach_end_timeout = 0;
+ } else {
+ reach_end_timeout = reach_end_timeout + timeout;
+ }
+ cache_time = delay;
+ continue;
+ }
reach_end_timeout = 0;
cache_time = 0;
//change next segment success case
@@ -1541,12 +1504,7 @@
}
//DVR_PB_INFO("write write_success:%d input_buffer.buf_size:%d", write_success, input_buffer.buf_size);
} else {
- pthread_mutex_unlock(&player->segment_lock);
- DVR_PB_INFO("write time out write_success:%d input_buffer.buf_size:%d systime:%u",
- write_success,
- input_buffer.buf_size,
- _dvr_time_getClock());
-
+ pthread_mutex_unlock(&player->segment_lock);
write_success = 0;
if (CONTROL_SPEED_ENABLE == 1) {
check1:
@@ -2106,7 +2064,6 @@
DVR_PB_INFO("player is NULL");
return DVR_FAILURE;
}
- DVR_PB_INFO(" do check");
if (now_pid.pid == set_pid.pid) {
//do nothing
return 0;
@@ -3251,44 +3208,29 @@
//get cur time of segment
DVR_Playback_t *player = (DVR_Playback_t *) handle;
- if (player == NULL || player->handle == 0) {
- DVR_PB_INFO("player is NULL");
- return DVR_FAILURE;
- }
+ DVR_RETURN_IF_FALSE(player != NULL);
+ DVR_RETURN_IF_FALSE(player->handle != 0);
- int64_t cache = 0;//default es buf cache 500ms
- int cur_time = 0;
pthread_mutex_lock(&player->segment_lock);
- loff_t pos = segment_tell_position(player->r_handle);
- uint64_t cur = 0;
- if (player->ts_cache_len > 0 && (pos < 0)) {
- //this case is open new segment end,but cache data is last segment.
- //we need used last segment len to send play time.
- cur = 0;
- DVR_PB_INFO("change segment [%lld][%lld]",
- player->last_segment_id, player->cur_segment_id);
- } else {
- cur = segment_tell_position_time(player->r_handle, pos);
- }
+ const loff_t pos = segment_tell_position(player->r_handle);
+ const uint64_t cur = segment_tell_position_time(player->r_handle, pos);
pthread_mutex_unlock(&player->segment_lock);
- int ret = get_effective_tsplayer_delay_time(player, &cache);
- if (player->first_start_id != UINT64_MAX && ret == DVR_FAILURE) {
- cur = player->first_start_time;
- *id = player->first_start_id;
- return cur;
- }
+ int cache = 0;
+ get_effective_tsplayer_delay_time(player, &cache);
if (player->state == DVR_PLAYBACK_STATE_STOP) {
cache = 0;
}
- cur_time = (int)(cur - cache);
- *id = player->cur_segment_id;
+
+ const int cur_time = (int)(cur - cache);
+ *id = player->cur_segment_id;
DVR_PB_INFO("***get playback slider position within segment. segment_id [%lld],"
" segment_slider_pos[%7d ms] = segment_read_pos[%7lld ms] - tsplayer_cache_len[%5lld ms],"
" last id [%lld] pos [%lld]",
player->cur_segment_id,cur_time,cur,cache,player->last_send_time_id,pos);
+
return cur_time;
}
@@ -3304,7 +3246,6 @@
pthread_mutex_lock(&player->segment_lock);
uint64_t end = segment_tell_total_time(player->r_handle);
- DVR_PB_INFO("get total time [%lld]", end);
pthread_mutex_unlock(&player->segment_lock);
return (int)end;
}
@@ -4158,31 +4099,35 @@
// of 20ms or less. During the said period, getDelayTime does NOT work as
// expect to return real delay length because demux isn't actually running
// to provide valid pts to TsPlayer.
-static int get_effective_tsplayer_delay_time(DVR_Playback_t* playback,int64_t* time)
+static int get_effective_tsplayer_delay_time(DVR_Playback_t* play, int *time)
{
int64_t delay=0;
uint64_t pts_a=0;
uint64_t pts_v=0;
- DVR_RETURN_IF_FALSE(playback != NULL);
+ DVR_RETURN_IF_FALSE(play != NULL);
+ DVR_RETURN_IF_FALSE(play->handle != NULL);
- AmTsPlayer_getDelayTime(playback->handle, &delay);
- DVR_RETURN_IF_FALSE(*time >= 0);
+ AmTsPlayer_getDelayTime(play->handle, &delay);
+ // In scambled stream situation, the returned TsPlayer delay time is
+ // invalid and dirty. An additional time check agaginst 15 minutes (900s)
+ // is introduced to insure such error condition is handled properly.
+ DVR_RETURN_IF_FALSE((delay >= 0) && (delay <= 900*1000));
- if (playback->delay_is_effective) {
- *time = delay;
+ if (play->delay_is_effective) {
+ *time = (int)delay;
return DVR_SUCCESS;
} else if (delay > 0) {
- *time = delay;
- playback->delay_is_effective=DVR_TRUE;
+ *time = (int)delay;
+ play->delay_is_effective=DVR_TRUE;
return DVR_SUCCESS;
}
- AmTsPlayer_getPts(playback->handle, TS_STREAM_AUDIO, &pts_a);
- AmTsPlayer_getPts(playback->handle, TS_STREAM_VIDEO, &pts_v);
+ AmTsPlayer_getPts(play->handle, TS_STREAM_AUDIO, &pts_a);
+ AmTsPlayer_getPts(play->handle, TS_STREAM_VIDEO, &pts_v);
if ((int64_t)pts_a > 0 || (int64_t)pts_v > 0) {
- *time = delay;
- playback->delay_is_effective=DVR_TRUE;
+ *time = (int)delay;
+ play->delay_is_effective=DVR_TRUE;
return DVR_SUCCESS;
}
diff --git a/src/dvr_record.c b/src/dvr_record.c
index faa2050..0825845 100644
--- a/src/dvr_record.c
+++ b/src/dvr_record.c
@@ -268,30 +268,18 @@
/* data from dmx, normal dvr case */
if (p_ctx->is_secure_mode) {
if (p_ctx->is_new_dmx) {
+ /* We resolve the below invoke for dvbcore to be under safety status */
+ memset(&new_dmx_secure_buf, 0, sizeof(new_dmx_secure_buf));
+ len = record_device_read(p_ctx->dev_handle, &new_dmx_secure_buf,
+ sizeof(new_dmx_secure_buf), 10);
- /* We resolve the below invoke for dvbcore to be under safety status */
- memset(&new_dmx_secure_buf, 0, sizeof(new_dmx_secure_buf));
- len = record_device_read(p_ctx->dev_handle, &new_dmx_secure_buf, sizeof(new_dmx_secure_buf), 10);
- if (len == DVR_FAILURE) {
- DVR_INFO("handle[%p] ret:%d\n", p_ctx->dev_handle, ret);
- /*For the second recording, poll always failed which we should check
- * dvbcore further. For now, Just ignore the fack poll fail, I think
- * it won't influence anything. But we need adjust the poll timeout
- * from 1000ms to 10ms.
- */
- //continue;
- }
-
- /* Read data from secure demux TA */
- len = record_device_read_ext(p_ctx->dev_handle, &secure_buf.addr,
- &secure_buf.len);
-
+ /* Read data from secure demux TA */
+ len = record_device_read_ext(p_ctx->dev_handle, &secure_buf.addr,
+ &secure_buf.len);
} else {
memset(&secure_buf, 0, sizeof(secure_buf));
- len = record_device_read(p_ctx->dev_handle, &secure_buf, sizeof(secure_buf), 1000);
- }
- if (len != DVR_FAILURE) {
- //DVR_INFO("%s, secure_buf:%#x, size:%#x", __func__, secure_buf.addr, secure_buf.len);
+ len = record_device_read(p_ctx->dev_handle, &secure_buf,
+ sizeof(secure_buf), 1000);
}
} else {
len = record_device_read(p_ctx->dev_handle, buf, block_size, 1000);
diff --git a/src/dvr_wrapper.c b/src/dvr_wrapper.c
index 9ffe28d..ef2399f 100644
--- a/src/dvr_wrapper.c
+++ b/src/dvr_wrapper.c
@@ -433,9 +433,9 @@
DVR_WRAPPER_INFO(" not found any play is in recording [%d]", DVR_WRAPPER_MAX);
return 0;
}
-//check this record is playing file
-//return 0 if not the playing
-//else return playback id
+
+// Check if the given record is being played.
+// Return 0 if it is not being played, otherwise return its playback id.
static inline int ctx_isRecord_playing(char *rec_location)
{
int i;
@@ -444,11 +444,11 @@
cnt = &playback_list[i];
//DVR_WRAPPER_INFO("[%d]sn[%d]P[%s]R[%s] ...\n", i, cnt->sn, cnt->playback.param_open.location, rec_location);
if (!strcmp(cnt->playback.param_open.location, rec_location)) {
- DVR_WRAPPER_INFO("[%d]sn[%d]P[%s]R[%s] ..found.\n",i, cnt->sn, cnt->playback.param_open.location, rec_location);
+ DVR_WRAPPER_DEBUG("[%d]sn[%d]P[%s]R[%s] ..found.",
+ i, cnt->sn, cnt->playback.param_open.location, rec_location);
return cnt->sn;
}
}
- DVR_WRAPPER_INFO(" not found rec is playing [%d]", DVR_WRAPPER_MAX);
return 0;
}
@@ -618,10 +618,10 @@
DVR_WrapperCtx_t *ctx = (evt->type == W_REC)?
ctx_getRecord(evt->sn) : ctx_getPlayback(evt->sn);
if (ctx == NULL) {
- DVR_WRAPPER_INFO("warp not get ctx.free event..\n");
+ DVR_WRAPPER_ERROR("Wrapper context is NULL");
goto processed;
}
- DVR_WRAPPER_INFO("start name(%s) sn(%d) running(%d) type(%d)\n", thread_ctx->name, (int)ctx->sn, thread_ctx->running, thread_ctx->type);
+ DVR_WRAPPER_DEBUG("start name(%s) sn(%d) running(%d) type(%d)\n", thread_ctx->name, (int)ctx->sn, thread_ctx->running, thread_ctx->type);
if (thread_ctx->running) {
/*
continue not break,
@@ -646,11 +646,10 @@
evt = (thread_ctx->type == W_REC)? ctx_getRecordEvent() : ctx_getPlaybackEvent();
}
- DVR_WRAPPER_INFO("start name(%s) running(%d) type(%d) con...\n", thread_ctx->name, thread_ctx->running, thread_ctx->type);
}
pthread_mutex_unlock(&thread_ctx->lock);
- DVR_WRAPPER_INFO("end name(%s) running(%d) type(%d) end...\n", thread_ctx->name, thread_ctx->running, thread_ctx->type);
+ DVR_WRAPPER_DEBUG("end name(%s) running(%d) type(%d) end...\n", thread_ctx->name, thread_ctx->running, thread_ctx->type);
return NULL;
}
@@ -1227,7 +1226,8 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("start record(sn:%ld, location:%s) save(%d)...\n", ctx->sn, ctx->record.param_open.location, params->save_rec_file);
+ DVR_WRAPPER_INFO("libdvr_api, start_record (sn:%ld) location:%s, save:%d",
+ ctx->sn, ctx->record.param_open.location, params->save_rec_file);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
start_param = &ctx->record.param_start;
@@ -1282,7 +1282,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("stop record(sn:%ld) ...\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, stop_record (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
memset(&seg_info, 0, sizeof(seg_info));
@@ -1306,7 +1306,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("pause record(sn:%ld) ...\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, pause_record (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
error = dvr_record_pause(ctx->record.recorder);
@@ -1328,7 +1328,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("resume record(sn:%ld) ...\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, resume_record (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
error = dvr_record_resume(ctx->record.recorder);
@@ -1439,7 +1439,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("update record(sn:%ld)\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, update_record (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
start_param = &ctx->record.param_update;
@@ -1491,7 +1491,7 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("get record(sn:%ld) status ...\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, get_record_status (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
error = process_generateRecordStatus(ctx, &s);
@@ -1578,7 +1578,8 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("open playback(dmx:%d) ..vendor[%d]params->block_size[%d].\n", params->dmx_dev_id, params->vendor, params->block_size);
+ DVR_WRAPPER_INFO("libdvr_api, open_playback (dmx:%d) ..vendor[%d]params->block_size[%d].",
+ params->dmx_dev_id, params->vendor, params->block_size);
ctx_reset(ctx);
@@ -1642,7 +1643,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("close playback(sn:%ld)\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, close_playback (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
if (ctx->playback.param_open.is_timeshift)
@@ -1716,15 +1717,16 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("start playback(sn:%ld) (%s)\n\t flags(0x%x) v/a/ad/sub/pcr(%d:%d %d:%d %d:%d %d:%d %d)\n",
- ctx->sn,
- ctx->playback.param_open.location,
- flags,
- p_pids->video.pid, p_pids->video.format,
- p_pids->audio.pid, p_pids->audio.format,
- p_pids->ad.pid, p_pids->ad.format,
- p_pids->subtitle.pid, p_pids->subtitle.format,
- p_pids->pcr.pid);
+ DVR_WRAPPER_INFO("libdvr_api, start_playback (sn:%ld) location:%s"
+ " flags:0x%x v/a/ad/sub/pcr(%d:%d %d:%d %d:%d %d:%d %d)",
+ ctx->sn,
+ ctx->playback.param_open.location,
+ flags,
+ p_pids->video.pid, p_pids->video.format,
+ p_pids->audio.pid, p_pids->audio.format,
+ p_pids->ad.pid, p_pids->ad.format,
+ p_pids->subtitle.pid, p_pids->subtitle.format,
+ p_pids->pcr.pid);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
@@ -1994,7 +1996,7 @@
{
DVR_WrapperCtx_t *ctx_record = NULL;/*for timeshift*/
int error;
- DVR_WRAPPER_INFO("stop timeshift record\n");
+ DVR_WRAPPER_INFO("libdvr_api, stop_timeshift");
//stop timeshift record
ctx_record = ctx_getRecord(sn_timeshift_record);
@@ -2021,7 +2023,8 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("restart record(sn:%ld, location:%s)...\n", ctx->sn, ctx->record.param_open.location);
+ DVR_WRAPPER_INFO("libdvr_api, restart_timeshift (sn:%ld) location:%s",
+ ctx->sn, ctx->record.param_open.location);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
{
@@ -2112,7 +2115,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("stop playback(sn:%ld) ...\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, stop_playback (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
error = dvr_playback_stop(ctx->playback.player, DVR_TRUE);
@@ -2150,7 +2153,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("pause playback(sn:%ld) ...\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, pause_playback (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
//clear end event
if (ctx->playback.last_event == DVR_PLAYBACK_EVENT_REACHED_END)
@@ -2187,7 +2190,7 @@
}
}
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("resume playback(sn:%ld) ...\n", ctx->sn);
+ DVR_WRAPPER_INFO("libdvr_api, resume_playback (sn:%ld)", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
error = dvr_playback_resume(ctx->playback.player);
@@ -2214,7 +2217,7 @@
DVR_RETURN_IF_FALSE(ctx);
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("speed playback(sn:%ld) (x%f) .(x%f)..\n", ctx->sn, speed, ctx->playback.speed);
+ DVR_WRAPPER_INFO("libdvr_api, set_playback_speed (sn:%ld) speed:%d", ctx->sn, (int)speed);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
error = dvr_playback_set_speed(ctx->playback.player, dvr_speed);
@@ -2253,7 +2256,8 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("set_limit playback(sn:%ld) (time:%lld limit:%d) ...\n", ctx->sn, time, limit);
+ DVR_WRAPPER_INFO("libdvr_api, setlimit_playback (sn:%ld) time:%lld, limit:%d",
+ ctx->sn, time, limit);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
error = dvr_playback_setlimit(ctx->playback.player, time, limit);
@@ -2269,10 +2273,8 @@
DVR_WrapperCtx_t *ctx;
int error;
DVR_WrapperPlaybackSegmentInfo_t *p_seg;
- uint64_t segment_id;
- uint32_t off;
- uint64_t last_segment_id;
- uint32_t pre_off;
+ uint64_t segment_id = ULLONG_MAX;
+ uint32_t segment_offset = 0;
DVR_RETURN_IF_FALSE(playback);
@@ -2281,14 +2283,9 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("seek playback(sn:%ld) (off:%d) ...\n", ctx->sn, time_offset);
+ DVR_WRAPPER_INFO("libdvr_api, seek_playback (sn:%ld) offset:%dms", ctx->sn, time_offset);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
- off = 0;
- segment_id = 0;
- pre_off = 0;
- last_segment_id = 0;
-
//if set limit info we need check ts data is
//expired when seek
if (dvr_playback_check_limit(ctx->playback.player)) {
@@ -2300,33 +2297,46 @@
}
}
- // This error is suppressed as the macro code is picked from kernel.
- // prefetch() here incurring self_assign is used to avoid some compiling
- // warnings.
- // coverity[self_assign]
- list_for_each_entry_reverse(p_seg, &ctx->segments, head) {
- segment_id = p_seg->seg_info.id;
+ const uint32_t obsolete_time = (uint32_t)ctx->playback.obsolete.time;
+ DVR_WrapperPlaybackSegmentInfo_t *p_seg_first = ctx->segments.c_prev;
+ DVR_WrapperPlaybackSegmentInfo_t *p_seg_last = ctx->segments.c_next;
+ const uint64_t first_id = p_seg_first->seg_info.id;
+ const uint64_t last_id = p_seg_last->seg_info.id;
+ const uint32_t last_duration = p_seg_last->seg_info.duration;
- if ((ctx->playback.obsolete.time + pre_off + p_seg->seg_info.duration) > time_offset)
- break;
-
- last_segment_id = p_seg->seg_info.id;
- pre_off += p_seg->seg_info.duration;
- }
-
- if (last_segment_id == segment_id) {
- /*1.only one seg with id:0, 2.offset exceeds the total duration*/
- off = time_offset;
- } else if (ctx->playback.obsolete.time >= time_offset) {
- off = 0;
+ if (time_offset <= obsolete_time) {
+ segment_id = first_id;
+ segment_offset = 0;
+ DVR_WRAPPER_WARN("time_offset %u isn't greater than obsolete time %u, "
+ "so seek to beginning position of segment %llu",
+ time_offset,obsolete_time,segment_id);
} else {
- off = time_offset - pre_off - ctx->playback.obsolete.time;
+ uint32_t total_duration = 0;
+ // This error is suppressed as the macro code is picked from kernel.
+ // prefetch() here incurring self_assign is used to avoid some compiling
+ // warnings.
+ // coverity[self_assign]
+ list_for_each_entry_reverse(p_seg, &ctx->segments, head) {
+ const uint32_t segment_begin = obsolete_time + total_duration;
+ const uint32_t segment_end = segment_begin + p_seg->seg_info.duration;
+ if (time_offset >= segment_begin && time_offset <= segment_end) {
+ segment_id = p_seg->seg_info.id;
+ segment_offset = time_offset - segment_begin;
+ break;
+ }
+ total_duration += p_seg->seg_info.duration;
+ }
+ if (segment_id == ULLONG_MAX) {
+ segment_id = last_id;
+ segment_offset = last_duration;
+ DVR_WRAPPER_WARN("time_offset %u is out of range, so seek to"
+ " the end position of segment %llu",time_offset,segment_id);
+ }
}
- DVR_WRAPPER_INFO("seek playback(sn:%ld) (seg:%lld, off:%d)\n",
- ctx->sn, segment_id, off);
- error = dvr_playback_seek(ctx->playback.player, segment_id, off);
- DVR_WRAPPER_INFO("playback(sn:%ld) seeked(off:%d) (%d)\n", ctx->sn, time_offset, error);
+ DVR_WRAPPER_INFO("seek playback(sn:%ld) (segment_id:%llu, segment_offset:%u)\n",
+ ctx->sn, segment_id, segment_offset);
+ error = dvr_playback_seek(ctx->playback.player, segment_id, segment_offset);
wrapper_mutex_unlock(&ctx->wrapper_lock);
@@ -2347,7 +2357,7 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("update playback(sn:%ld) v/a(%d:%d/%d:%d) ...\n",
+ DVR_WRAPPER_INFO("libdvr_api, update_playback (sn:%ld) v/a(%d:%d/%d:%d)",
ctx->sn,
p_pids->video.pid, p_pids->video.format,
p_pids->audio.pid, p_pids->audio.format);
@@ -2404,7 +2414,7 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("update playback(sn:%ld) v/a(%d:%d/%d:%d) ...\n",
+ DVR_WRAPPER_INFO("libdvr_api, only_update_playback (sn:%ld) v/a(%d:%d/%d:%d)",
ctx->sn,
p_pids->video.pid, p_pids->video.format,
p_pids->audio.pid, p_pids->audio.format);
@@ -2462,11 +2472,9 @@
wrapper_mutex_lock(&ctx->wrapper_lock);
- DVR_WRAPPER_INFO("get playback(sn:%ld) status ...\n", ctx->sn);
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
- error = dvr_playback_get_status(ctx->playback.player, &play_status);
- DVR_WRAPPER_INFO("playback(sn:%ld) get status (%d)\n", ctx->sn, error);
+ dvr_playback_get_status(ctx->playback.player, &play_status);
ctx->playback.seg_status = play_status;
error = process_generatePlaybackStatus(ctx, &s);
@@ -2476,13 +2484,8 @@
DVR_WRAPPER_INFO("set cur time to full time, reach end occur");
s.info_cur.time = s.info_full.time;
}
- DVR_WRAPPER_INFO("playback(sn:%ld) state/cur/full/obsolete(%d/%ld/%ld/%ld) (%d)\n",
- ctx->sn,
- s.state,
- s.info_cur.time,
- s.info_full.time,
- s.info_obsolete.time,
- error);
+ DVR_WRAPPER_INFO("get_playback_status (sn:%ld) state/cur/full/obsolete(%d/%ld/%ld/%ld)",
+ ctx->sn, s.state, s.info_cur.time, s.info_full.time, s.info_obsolete.time);
*status = s;
@@ -2687,7 +2690,7 @@
DVR_RETURN_IF_FALSE(userdata);
- DVR_WRAPPER_INFO("evt[sn:%ld, record, evt:0x%x]\n", evt.sn, evt.record.event);
+ DVR_WRAPPER_DEBUG("record event 0x%x (sn:%ld)", evt.record.event, evt.sn);
return ctx_addRecordEvent(&evt);
}
@@ -2706,7 +2709,7 @@
evt.type = W_PLAYBACK;
evt.playback.event = event;
evt.playback.status = *(DVR_Play_Notify_t *)params;
- DVR_WRAPPER_INFO("evt[sn:%ld, playback, evt:0x%x]\n", evt.sn, evt.playback.event);
+ DVR_WRAPPER_DEBUG("playback event 0x%x (sn:%ld)", evt.playback.event, evt.sn);
return ctx_addPlaybackEvent(&evt);
}
@@ -2838,8 +2841,8 @@
memset(&status, 0, sizeof(status));
- DVR_WRAPPER_INFO("evt (sn:%ld) 0x%x (state:%d)\n",
- evt->sn, evt->record.event, evt->record.status.state);
+ DVR_WRAPPER_DEBUG("evt (sn:%ld) 0x%x (state:%d)\n",
+ evt->sn, evt->record.event, evt->record.status.state);
if (ctx->record.param_update.segment.segment_id != evt->record.status.info.id) {
DVR_WRAPPER_INFO("evt (sn:%ld) cur id:0x%x (event id:%d)\n",
evt->sn, (int)ctx->record.param_update.segment.segment_id, (int)evt->record.status.info.id);
@@ -3005,7 +3008,6 @@
// coverity[self_assign]
list_for_each_entry_reverse(p_seg, &ctx->segments, head) {
if (p_seg->seg_info.id == ctx->playback.seg_status.segment_id) {
- DVR_WRAPPER_INFO("calculate cur time :[%lld]time[%d]\n", p_seg->seg_info.id, p_seg->seg_info.duration);
break;
}
@@ -3021,7 +3023,6 @@
ctx->playback.status.info_full.time += p_seg->seg_info.duration;
ctx->playback.status.info_full.size += p_seg->seg_info.size;
ctx->playback.status.info_full.pkts += p_seg->seg_info.nb_packets;
- DVR_WRAPPER_INFO("calculate full time :[%lld]time[%d]\n", p_seg->seg_info.id, p_seg->seg_info.duration);
}
if (status) {
@@ -3039,9 +3040,8 @@
}
else
{
- DVR_WRAPPER_INFO("warning not change start time :ctx->playback.tf_full[%d]id[%lld] [%lld] cur[%d]\n",ctx->playback.tf_full , p_seg->info.id, ctx->current_segment_id, status->info_cur.time);
- status->info_obsolete.time = ctx->playback.obsolete.time;
- status->disguised_info_obsolete.time = ctx->playback.obsolete.time;
+ status->info_obsolete.time = ctx->playback.obsolete.time;
+ status->disguised_info_obsolete.time = ctx->playback.obsolete.time;
}
}
@@ -3050,7 +3050,7 @@
static int process_handlePlaybackEvent(DVR_WrapperEventCtx_t *evt, DVR_WrapperCtx_t *ctx)
{
- DVR_WRAPPER_INFO("evt (sn:%ld) 0x%x (state:%d) cur(%lld:%u/%u)\n",
+ DVR_WRAPPER_DEBUG("evt (sn:%ld) 0x%x (state:%d) cur(%lld:%u/%u)\n",
evt->sn, evt->playback.event,
evt->playback.status.play_status.state,
evt->playback.status.play_status.segment_id,
@@ -3124,6 +3124,7 @@
int dvr_wrapper_set_log_level (int level)
{
+ DVR_WRAPPER_INFO("libdvr_api, set_log_level %d", level);
if (level<LOG_LV_DEFAULT || level>LOG_LV_FATAL) {
DVR_WRAPPER_ERROR("Invalid dvr log level:%d", g_dvr_log_level);
return DVR_FAILURE;
@@ -3147,7 +3148,7 @@
WRAPPER_RETURN_IF_FALSE_WITH_UNLOCK(ctx_valid(ctx), &ctx->wrapper_lock);
- DVR_WRAPPER_INFO("set ac4 preselection id: %d", presel_id);
+ DVR_WRAPPER_INFO("libdvr_api, set_ac4_preselection_id %d", presel_id);
error = dvr_playback_set_ac4_preselection_id(ctx->playback.player, presel_id);
wrapper_mutex_unlock(&ctx->wrapper_lock);
diff --git a/src/record_device.c b/src/record_device.c
index 34e8380..591493b 100644
--- a/src/record_device.c
+++ b/src/record_device.c
@@ -567,11 +567,9 @@
fds[0].events = fds[1].events = POLLIN | POLLERR;
ret = poll(fds, 2, timeout);
- if (ret <= 0) {
- if (ret < 0)
- DVR_INFO("%s, %d failed: %s fd %d event fd %d", __func__, __LINE__, strerror(errno), p_ctx->fd, p_ctx->evtfd);
- else
- DVR_INFO("%s, %d timeout", __func__, __LINE__);
+ if (ret < 0) {
+ DVR_INFO("%s, %d failed: %s fd %d event fd %d", __func__, __LINE__,
+ strerror(errno), p_ctx->fd, p_ctx->evtfd);
return DVR_FAILURE;
}
diff --git a/src/segment.c b/src/segment.c
index 80f4c8c..5289970 100644
--- a/src/segment.c
+++ b/src/segment.c
@@ -688,7 +688,6 @@
/*Save segment duration*/
memset(buf, 0, sizeof(buf));
- DVR_INFO("duration store:[%ld]", p_info->duration);
sprintf(buf, "duration=%ld\n", p_info->duration);
fputs(buf, p_ctx->dat_fp);
@@ -743,7 +742,6 @@
/*Save segment duration*/
memset(buf, 0, sizeof(buf));
- DVR_INFO("duration store:[%ld]", p_info->duration);
sprintf(buf, "duration=%ld\n", p_info->duration);
fputs(buf, p_ctx->all_dat_fp);