Code: Select all
uname -a
Code: Select all
uname -a
I have followed your instructions.6by9 wrote:The main camera crystal is running at 25MHz instead of the intended 24.8MHz, so that will run 0.81% fast (ie too many frames per time interval) - not a big enough difference to explain your diffs.
All frames are timestamped, but as raspivid doesn't write to a container and the raw H264 bitstream doesn't have timestamps, you don't see it.
I'd suggest you do a couple of your own tests:
- checkout your own copy of the userland tree (git clone https://github.com/raspberrypi/userland.git)
- cd userland
- edit raspivid.c (nano host_applications/linux/apps/raspicam/RaspiVid.c) and add code in encoder_buffer_callback to print out buffer->pts.
- compile it (./buildme)
- run your new raspivid (it will have been installed to the normal /opt/vc directory by buildme) and see what the timestamps are.
If there are jumps of 80ms between some buffers then your SD card isn't keeping up. Retest with streaming to /dev/nul to confirm that the timestamps are then even.
Code: Select all
FILE *outputfile;
outputfile = fopen("/home/pi/userland/build/bin/output_raspivid.txt","a");
fprintf(outputfile,"%" PRId64 "\n", buffer->pts);
fclose(outputfile);
Code: Select all
0
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808
-9223372036854775808 = 8000000000000000 = 1<<63 = MMAL_TIME_UNKNOWN (see https://github.com/raspberrypi/userland ... ypes.h#L88) Bum! Either something odd is going on, or we should be looking at dts.el_cid wrote:I have followed your instructions.
At the end of the function encoder_buffer_callback() I addedWhen I then record a 2 second video I get in output_raspivid.txt:Code: Select all
FILE *outputfile; outputfile = fopen("/home/pi/userland/build/bin/output_raspivid.txt","a"); fprintf(outputfile,"%" PRId64 "\n", buffer->pts); fclose(outputfile);
Have you or anyone an idea what I could still be wrong?Code: Select all
0 -9223372036854775808 ...
I suspected that it is the value of MMAL_TIME_UNKNOWN - but I couldn't decipher the meaning of 1<<63 (my c understandings are somewhat limited...).6by9 wrote: -9223372036854775808 = 8000000000000000 = 1<<63 = MMAL_TIME_UNKNOWN (see https://github.com/raspberrypi/userland ... ypes.h#L88) Bum! Either something odd is going on, or we should be looking at dts.
I will try to spin up my own Pi tonight to have a look at this. The frames should be timestamped sensibly (with the GPU STC).
I can't remember what the default buffer size is. If it is smaller than the frame size, then the first buffer would come through with the correct timestamp (and flags having MMAL_BUFFER_HEADER_FLAG_FRAME_START set), and subsequent buffers in the same frame would get MMAL_TIME_UNKNOWN until the last buffer in the frame would also have the MMAL_BUFFER_HEADER_FLAG_FRAME_END flag set. That would explain seeing some buffers with TIME_UNKNOWN, but not all of them.
I don't know what current_time means, and if it can be a source of information for us. I will try to find that out.int64_t current_time = vcos_getmicrosecs64()/1000;
Code: Select all
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130108930
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130108932
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110025
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110056
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110123
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110158
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110222
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110263
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110323
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110380
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110384
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110387
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110423
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110465
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110523
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110527
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110571
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110576
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110623
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110626
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110667
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110671
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110723
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110727
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110769
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110773
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110822
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110825
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110866
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110869
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110921
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110926
pts =-9223372036854775808
dts =-9223372036854775808
current time =1418130110936
Interesting - If I can help with anything (which I doubt), please let me know.jamesh wrote:Every frame has a time stamp attached to it to enable it to (simplistically) sync up properly with everything. That time stamp doesn't appear to be present. It should be attached by the GPU during the processing of the frame. If it is not attaching it then there is actually something wrong. So that needs to be looked in to - you appear have found a real bug, and one that has recently been introduced because this hasn't been seen before.
Code: Select all
diff --git a/host_applications/linux/apps/raspicam/RaspiVid.c b/host_applications/linux/apps/raspicam/RaspiVid.c
index afb8363..2ad1e03 100755
--- a/host_applications/linux/apps/raspicam/RaspiVid.c
+++ b/host_applications/linux/apps/raspicam/RaspiVid.c
@@ -134,6 +134,7 @@ typedef struct
char header_bytes[29];
int header_wptr;
FILE *imv_file_handle; /// File handle to write inline motion vectors to.
+ FILE *pts_file_handle; /// File timestamps
} PORT_USERDATA;
/** Structure containing all state information for the current run
@@ -183,10 +184,14 @@ struct RASPIVID_STATE_S
int inlineMotionVectors; /// Encoder outputs inline Motion Vectors
char *imv_filename; /// filename of inline Motion Vectors output
-
int cameraNum; /// Camera number
int settings; /// Request settings from the camera
int sensor_mode; /// Sensor mode. 0=auto. Check docs/forum for modes selected by other values.
+ int frame;
+ char *pts_file;
+ int save_pts;
+ int64_t starttime;
+ int64_t lasttime;
};
@@ -240,6 +245,7 @@ static void display_valid_parameters(char *app_name);
#define CommandCamSelect 24
#define CommandSettings 25
#define CommandSensorMode 26
+#define CommandSavePTS 27
static COMMAND_LIST cmdline_commands[] =
{
@@ -270,6 +276,7 @@ static COMMAND_LIST cmdline_commands[] =
{ CommandCamSelect, "-camselect", "cs", "Select camera <number>. Default 0", 1 },
{ CommandSettings, "-settings", "set","Retrieve camera settings and write to stdout", 0},
{ CommandSensorMode, "-mode", "md", "Force sensor mode. 0=auto. See docs for other modes available", 1},
+ { CommandSavePTS, "-save-pts", "pts","Save Timestamt to file", 1 },
};
static int cmdline_commands_size = sizeof(cmdline_commands) / sizeof(cmdline_commands[0]);
@@ -334,11 +341,11 @@ static void default_status(RASPIVID_STATE *state)
state->splitWait = 0;
state->inlineMotionVectors = 0;
-
state->cameraNum = 0;
state->settings = 0;
state->sensor_mode = 0;
-
+ state->frame = 0;
+ state->save_pts = 0;
// Setup preview window defaults
raspipreview_set_defaults(&state->preview_parameters);
@@ -696,6 +703,23 @@ static int parse_cmdline(int argc, const char **argv, RASPIVID_STATE *state)
break;
}
+ case CommandSavePTS: // output filename
+ {
+ state->save_pts = 1;
+ int len = strlen(argv[i + 1]);
+ if (len)
+ {
+ state->pts_file = malloc(len + 1);
+ vcos_assert(state->pts_file);
+ if (state->pts_file)
+ strncpy(state->pts_file, argv[i + 1], len+1);
+ i++;
+ }
+ else
+ valid = 0;
+ break;
+ }
+
default:
{
// Try parsing for any image specific parameters
@@ -888,6 +912,27 @@ static FILE *open_imv_filename(RASPIVID_STATE *pState)
return new_handle;
}
+static FILE *open_pts_filename(RASPIVID_STATE *pState)
+{
+ FILE *new_handle = NULL;
+ char *filename = NULL;
+
+ filename = pState->pts_file;
+
+ if (filename)
+ new_handle = fopen(filename, "wb");
+
+ if (pState->verbose)
+ {
+ if (new_handle)
+ fprintf(stderr, "Opening pts output file \"%s\"\n", filename);
+ else
+ fprintf(stderr, "Failed to open new pts file \"%s\"\n", filename);
+ }
+
+ return new_handle;
+}
+
/**
* buffer header callback function for encoder
*
@@ -1050,7 +1095,18 @@ static void encoder_buffer_callback(MMAL_PORT_T *port, MMAL_BUFFER_HEADER_T *buf
}
else
{
- bytes_written = fwrite(buffer->data, 1, buffer->length, pData->file_handle);
+ bytes_written = fwrite(buffer->data, 1, buffer->length, pData->file_handle);
+ //printf("Bufferlag=%d\n",buffer->flags);
+ if(pData->pstate->save_pts && (buffer->flags & MMAL_BUFFER_HEADER_FLAG_FRAME_END || buffer->flags == 0 || buffer->flags & MMAL_BUFFER_HEADER_FLAG_KEYFRAME) && !(buffer->flags & MMAL_BUFFER_HEADER_FLAG_CONFIG))
+ {
+ if(buffer->pts != MMAL_TIME_UNKNOWN && buffer->pts != pData->pstate->lasttime)
+ {
+ if(pData->pstate->frame==0)pData->pstate->starttime=buffer->pts;
+ pData->pstate->lasttime=buffer->pts;
+ fprintf(pData->pts_file_handle,"%d %f\n",pData->pstate->frame,(buffer->pts-pData->pstate->starttime)/1000000.);
+ pData->pstate->frame++;
+ }
+ }
}
mmal_buffer_header_mem_unlock(buffer);
@@ -1177,7 +1233,7 @@ static MMAL_STATUS_T create_camera_component(RASPIVID_STATE *state)
.num_preview_video_frames = 3,
.stills_capture_circular_buffer_height = 0,
.fast_preview_resume = 0,
- .use_stc_timestamp = MMAL_PARAM_TIMESTAMP_MODE_RESET_STC
+ .use_stc_timestamp = MMAL_PARAM_TIMESTAMP_MODE_RAW_STC
};
mmal_port_parameter_set(camera->control, &cam_config.hdr);
}
@@ -1899,6 +1955,27 @@ int main(int argc, const char **argv)
}
}
+ state.callback_data.pts_file_handle = NULL;
+
+ if (state.pts_file)
+ {
+ if (state.pts_file[0] == '-')
+ {
+ state.callback_data.pts_file_handle = stdout;
+ }
+ else
+ {
+ state.callback_data.pts_file_handle = open_pts_filename(&state);
+ }
+
+ if (!state.callback_data.pts_file_handle)
+ {
+ // Notify user, carry on but discarding encoded output buffers
+ fprintf(stderr, "Error opening output file: %s\nNo output file will be generated\n",state.pts_file);
+ state.save_pts=0;
+ }
+ }
+
if(state.bCircularBuffer)
{
if(state.bitrate == 0)
@@ -2110,6 +2187,8 @@ error:
fclose(state.callback_data.file_handle);
if (state.callback_data.imv_file_handle && state.callback_data.imv_file_handle != stdout)
fclose(state.callback_data.imv_file_handle);
+ if (state.callback_data.pts_file_handle && state.callback_data.pts_file_handle != stdout)
+ fclose(state.callback_data.pts_file_handle);
/* Disable components */
if (state.encoder_component)
Code: Select all
./raspivid -v -o test.h264 -pts pts.dat -t 120000
It was supposed to be that every time you started capturing data on output[1] that the timestamps would reset to 0. That could be either through enabling the port with the MMAL_PARAMETER_CAPTURING already set, or enabling MMAL_PARAMETER_CAPTURING on the enabled port.ethanol100 wrote:RESET_STC is working, somehow. I think I'm just too dumb to use it. The first buffer containing MMAL_BUFFER_HEADER_FLAG_CONFIG has a time value of 0, but the first frame has a value different form 0. If I then manually substract the time of the first frame, after about 5 seconds the time stamp counter wraps and I get negative values. Would the start of the camera/component or the first frame be used to reset the clock?
I guess it is not the RESET_STC which creates the problem.
Ta, that was my suspicion.ethanol100 wrote:If I manually get the buffer from the camera video port, each frame is in one buffer and has only the flag "FRAME_END" set.
I wanted to try this with your raspivid version, ethanol100, but unfortunately it doesn't seem to work when I write the video file to /dev/null . A pts.dat file is generated, but it's empty...6by9 wrote: - run your new raspivid (it will have been installed to the normal /opt/vc directory by buildme) and see what the timestamps are.
If there are jumps of 80ms between some buffers then your SD card isn't keeping up. Retest with streaming to /dev/nul to confirm that the timestamps are then even.
Code: Select all
@@ -1050,7 +1096,24 @@ static void encoder_buffer_callback(MMAL_PORT_T *port, MMAL_BUFFER_HEADER_T *buf
}
else
{
- bytes_written = fwrite(buffer->data, 1, buffer->length, pData->file_handle);
+ bytes_written = fwrite(buffer->data, 1, buffer->length, pData->file_handle);
+ if(pData->pstate->save_pts &&
+ (buffer->flags & MMAL_BUFFER_HEADER_FLAG_FRAME_END ||
+ buffer->flags == 0 ||
+ buffer->flags & MMAL_BUFFER_HEADER_FLAG_KEYFRAME) &&
+ !(buffer->flags & MMAL_BUFFER_HEADER_FLAG_CONFIG))
+ {
+ if(buffer->pts != MMAL_TIME_UNKNOWN &&
+ (!buffer->pts || buffer->pts != pData->pstate->lasttime))
+ {
+ if(pData->pstate->frame==0)
+ pData->pstate->starttime=buffer->pts;
+ fprintf(pData->pts_file_handle,"%3d %3.6f delta %llu\n",pData->pstate->frame,(buffer->pts)/1000000.,
+ buffer->pts - pData->pstate->lasttime);
+ pData->pstate->lasttime=buffer->pts;
+ pData->pstate->frame++;
+ }
+ }
}
I'm at work so can't spend time analysing your logs, but as I was reading your latest description I was wondering about data corruption.el_cid wrote:--> Could the camera be faulty? I didn't treat it especially well.
Code: Select all
sudo vcgencmd set_logging level=192
Code: Select all
sudo vcdbg log msg 2>&1 | grep -i drop
Yesel_cid wrote:So while recording a video I need enter in the terminalIs that correct?Code: Select all
sudo vcdbg log msg 2>&1 | grep -i drop
It logs into a circular buffer, so it depends on how many logging messages are written by the GPU as to what the time period is that it covers. Default logging level is very low, but the vcgencmd line will turn it on for all the multimedia middleware so it will fill up and wrap around fairly fast.el_cid wrote:Just for better understanding: vcdbg log msg shows the logs since how much time? since start up of the pi?
How does the flat ribbon cable looks like? Are there any kinks or broken lines?el_cid wrote:--> Could the camera be faulty? I didn't treat it especially well.
Code: Select all
writing to data sample frame loss in %
/run/shm 1 28.34
/run/shm 2 32.63
/dev/null 1 30.76
/dev/null 2 23.03
/home/pi 1 30.28
/home/pi 2 0.252 *
there are kinks, but no broken lines.ethanol100 wrote:How does the flat ribbon cable looks like? Are there any kinks or broken lines?el_cid wrote:--> Could the camera be faulty? I didn't treat it especially well.
Could you try to remove the cable and reattach it, on both ends?
I have tried your commands and I never get a dropped frame. It really seems to be a problem with your camera, or its connection.
The sensor is being driven from a 25MHz crystal when it should be a 24.8MHz one, hence it is a couple of percent fast.RecDev wrote:Sadly I am also facing this issue.
I record both video and audio at the same time to a connected USB storage.
Now I'm already disappointed that the framerate is off by so much - I try to record with 20 fps and get 20.3(!) - but that's a problem that could be solved somehow if at least the amount of frames was constant.