libdvr: Images stoped when playing DTV [1/1]
PD#SWPL-90382
Problem:
libdvr prints are not friendly for issue analysis.
Solution:
Improve log prints to make it easier to understand.
Verify:
Locally tested OK in AH212 RDK environment.
Signed-off-by: Wentao.MA <wentao.ma@amlogic.com>
Change-Id: I72732abaf20dcc2d941f9368a99314c6c26123e4
(cherry picked from commit 2416acb38b5b8866f5ac124d4be5d0280e891e1f)
diff --git a/src/dvr_playback.c b/src/dvr_playback.c
index 0f52f64..e22eefc 100644
--- a/src/dvr_playback.c
+++ b/src/dvr_playback.c
@@ -36,6 +36,11 @@
#define IS_KERNEL_SPEED(_SPEED_) (((_SPEED_) == PLAYBACK_SPEED_X2) || ((_SPEED_) == PLAYBACK_SPEED_X1) || ((_SPEED_) == PLAYBACK_SPEED_S2) || ((_SPEED_) == PLAYBACK_SPEED_S4) || ((_SPEED_) == PLAYBACK_SPEED_S8))
#define IS_FAST_SPEED(_SPEED_) (((_SPEED_) == PLAYBACK_SPEED_X2) || ((_SPEED_) == PLAYBACK_SPEED_S2) || ((_SPEED_) == PLAYBACK_SPEED_S4) || ((_SPEED_) == PLAYBACK_SPEED_S8))
+#define DVR_PLAYER_CHANGE_STATE(player,newstate)\
+ DVR_PB_INFO("%s:%d player %p changes state from %s to %s",__func__,__LINE__,\
+ player,_dvr_playback_state_toString(player->state),_dvr_playback_state_toString(newstate));\
+ player->state=newstate;
+
#define FFFB_SLEEP_TIME (1000)//500ms
#define FB_DEFAULT_LEFT_TIME (3000)
@@ -96,21 +101,20 @@
}
-static char* _dvr_playback_state_toString(int stat)
+static char* _dvr_playback_state_toString(int state)
{
- char *string[DVR_PLAYBACK_STATE_FB+1]={
- "start",
- "stop",
- "pause",
- "ff",
- "fb"
+ char *strings[5]={
+ "START",
+ "STOP",
+ "PAUSE",
+ "FF",
+ "FB",
};
- if (stat > DVR_PLAYBACK_STATE_FB) {
- return "unknown";
- } else {
- return string[stat];
+ if (state >= 5 || state < 0) {
+ return "UNKNOWN";
}
+ return strings[state];
}
static DVR_Bool_t _dvr_support_speed(int speed) {
@@ -153,6 +157,7 @@
}
return ret;
}
+
void _dvr_tsplayer_callback_test(void *user_data, am_tsplayer_event *event)
{
DVR_PB_INFO("in callback test ");
@@ -1055,6 +1060,42 @@
//DVR_PB_INFO("lock check_no_data_time:%d", check_no_data_time);
dvr_mutex_lock(&player->lock);
+ {
+ static struct timespec _prevts={0,0};
+ struct timespec _nowts,_diffts;
+ clock_gettime(CLOCK_MONOTONIC, &_nowts);
+ clock_timespec_subtract(&_nowts,&_prevts,&_diffts);
+ if (_diffts.tv_sec>0) {
+ char _logbuf[512]={0};
+ char* _pbuf=_logbuf;
+ int _nchar=0;
+ DVR_PlaybackSegmentInfo_t* _segment;
+ list_for_each_entry(_segment, &player->segment_list, head) {
+ if (player->cur_segment_id == _segment->segment_id) {
+ int segsize = segment_get_cur_segment_size(player->r_handle);
+ int readptr = segment_tell_position(player->r_handle);
+ float progress = -1.0f;
+ if (segsize>0) {
+ progress = (float)readptr*100/segsize;
+ }
+ _nchar=sprintf(_pbuf,"%lld(%.1f%), ",_segment->segment_id,progress);
+ } else {
+ _nchar=sprintf(_pbuf,"%lld, ",_segment->segment_id);
+ }
+ if (_nchar<0) {
+ break;
+ }
+ _pbuf+=_nchar;
+ if (_pbuf-_logbuf+10 >= sizeof(_logbuf)) {
+ sprintf(_pbuf,"...");
+ break;
+ }
+ }
+ DVR_PB_INFO("clk: %08u, seglist: %s",_nowts.tv_sec,_logbuf);
+ _prevts=_nowts;
+ }
+ }
+
if (player->cmd.cur_cmd == DVR_PLAYBACK_CMD_SEEK ||
player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FF ||
player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FB ||
@@ -1079,7 +1120,7 @@
//need change to pause state
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_PAUSE;
player->cmd.state = DVR_PLAYBACK_STATE_PAUSE;
- player->state = DVR_PLAYBACK_STATE_PAUSE;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_PAUSE);
//clear flag
player->play_flag = player->play_flag & (~DVR_PLAYBACK_STARTED_PAUSEDLIVE);
player->first_frame = 0;
@@ -1266,9 +1307,7 @@
//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_INFO("read end but cache time is %d > 20s, this is an error at media_hal", _cache_time);
- DVR_PB_INFO("read end but cache time is %d > 20s, this is an error at media_hal", _cache_time);
- DVR_PB_INFO("read end but cache time is %d > 20s, this is an error at media_hal", _cache_time);
+ DVR_PB_WARN("read end but cache time is %d > 20s, this is an error at media_hal", _cache_time);
}
//_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);
@@ -1613,7 +1652,7 @@
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_STOP;
player->cmd.speed.speed.speed = PLAYBACK_SPEED_X1;
player->cmd.state = DVR_PLAYBACK_STATE_STOP;
- player->state = DVR_PLAYBACK_STATE_STOP;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_STOP);
player->cmd.pos = 0;
player->speed = 1.0f;
player->first_trans_ok = DVR_FALSE;
@@ -1833,7 +1872,7 @@
if (player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FB
|| player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FF) {
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
} else {
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_START;
@@ -1858,7 +1897,7 @@
}
}
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
}
}
#ifdef AVSYNC_USED_PCR
@@ -2141,7 +2180,7 @@
}
//audio and video all close
if (!player->has_audio && !player->has_video) {
- player->state = DVR_PLAYBACK_STATE_STOP;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_STOP);
}
} else if (type == 2) {
//case disable ad
@@ -2429,7 +2468,7 @@
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_STOP;
player->cmd.state = DVR_PLAYBACK_STATE_STOP;
- player->state = DVR_PLAYBACK_STATE_STOP;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_STOP);
player->cur_segment_id = UINT64_MAX;
player->segment_is_open = DVR_FALSE;
DVR_PB_DEBUG("unlock");
@@ -2472,7 +2511,7 @@
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_A_START;
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
DVR_PB_DEBUG("unlock");
dvr_mutex_unlock(&player->lock);
return DVR_SUCCESS;
@@ -2493,7 +2532,7 @@
//playback_device_audio_stop(player->handle);
if (player->has_video == DVR_FALSE) {
player->cmd.state = DVR_PLAYBACK_STATE_STOP;
- player->state = DVR_PLAYBACK_STATE_STOP;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_STOP);
//destory thread
_stop_playback_thread(handle);
} else {
@@ -2552,7 +2591,7 @@
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_V_START;
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
DVR_PB_DEBUG("unlock");
dvr_mutex_unlock(&player->lock);
return DVR_SUCCESS;
@@ -2572,7 +2611,7 @@
if (player->has_audio == DVR_FALSE) {
player->cmd.state = DVR_PLAYBACK_STATE_STOP;
- player->state = DVR_PLAYBACK_STATE_STOP;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_STOP);
//destory thread
_stop_playback_thread(handle);
} else {
@@ -2623,12 +2662,12 @@
if (player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FF ||
player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FB) {
player->cmd.state = DVR_PLAYBACK_STATE_PAUSE;
- player->state = DVR_PLAYBACK_STATE_PAUSE;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_PAUSE);
} else {
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_PAUSE;
player->cmd.state = DVR_PLAYBACK_STATE_PAUSE;
- player->state = DVR_PLAYBACK_STATE_PAUSE;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_PAUSE);
}
dvr_mutex_unlock(&player->lock);
DVR_PB_DEBUG("unlock");
@@ -2805,12 +2844,12 @@
if (player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FF ||
player->cmd.cur_cmd == DVR_PLAYBACK_CMD_FB) {
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
} else {
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_RESUME;
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
}
DVR_PB_DEBUG("unlock");
dvr_mutex_unlock(&player->lock);
@@ -2834,7 +2873,7 @@
if (player->cmd.speed.speed.speed == PLAYBACK_SPEED_X1)
_dvr_cmd(handle, player->cmd.cur_cmd);
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
DVR_PB_INFO("unlock");
dvr_mutex_unlock(&player->lock);
} else {
@@ -3092,7 +3131,7 @@
}
if (player->state == DVR_PLAYBACK_STATE_PAUSE) {
player->cmd.state = DVR_PLAYBACK_STATE_PAUSE;
- player->state = DVR_PLAYBACK_STATE_PAUSE;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_PAUSE);
if (VALID_PID(audio_params.pid) || VALID_PID(video_params.pid))
player->seek_pause = DVR_TRUE;
DVR_PB_INFO("set state pause in seek vpid[0x%x]apid[0x%x]",video_params.pid, audio_params.pid);
@@ -3107,7 +3146,7 @@
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_SEEK;
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
}
player->last_send_time_id = UINT64_MAX;
DVR_PB_DEBUG("unlock");
@@ -3702,7 +3741,7 @@
player->cmd.last_cmd = player->cmd.cur_cmd;
player->cmd.cur_cmd = DVR_PLAYBACK_CMD_START;
player->cmd.state = DVR_PLAYBACK_STATE_START;
- player->state = DVR_PLAYBACK_STATE_START;
+ DVR_PLAYER_CHANGE_STATE(player,DVR_PLAYBACK_STATE_START);
return 0;
}