Cannot write to ogg file using application API

I have a buffer of PCM data and I want to compress it to ogg/opus using the C API.

I tried to do something like this:

appsrc ! audioconvert ! opusenc ! oggmux ! appsink

But only the ogg header is written to my buffer.

To summarize here is what I do:

  1. Create all the element with gst_element_factory_make
  2. Link them in the above order with gst_element_link_many
  3. I set “format” to GST_FORMAT_TIME on appsrc
  4. I set caps to audio/x-raw;format=S16LE,channels=1,rate=48000
  5. I set “emit-signals” to true on appsink
  6. I connect “new-sample” on appsink
  7. I set the pipeline to GST_STATE_PLAYING
  8. I create a buffer with gst_buffer_new_wrapped_full
  9. I emit the “push-buffer” signal on appsrc with buffer
  10. I emit the “end-of-stream” signal on appsrc
  11. I run gst_bus_timed_pop_filtered until EOS or ERROR
  12. I set the pipeline to GST_STATE_NULL

My new_sample function which I passed to the “new-sample” signal is called only with the ogg headers (total 122 bytes).

If I set the debug to 7 for oggmux I get (the section at the bottom between the lines ending in collected are repeated numerous times):

0:00:00.026056285 1888741 0x7e925802a8f0 DEBUG                 oggmux gstoggmux.c:464:gst_ogg_mux_request_new_pad:<muxer> Creating new pad for serial 753600480
0:00:00.026068167 1888741 0x7e925802a8f0 DEBUG                 oggmux gstoggmux.c:282:gst_ogg_mux_sinkconnect:<muxer> sinkconnect triggered on audio_753600480
0:00:00.026114733 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:310:gst_ogg_mux_sink_event:<muxer:audio_753600480> Got stream-start event
0:00:00.026253591 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:310:gst_ogg_mux_sink_event:<muxer:audio_753600480> Got caps event
0:00:00.026284669 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:310:gst_ogg_mux_sink_event:<muxer:audio_753600480> Got segment event
0:00:00.026288486 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:310:gst_ogg_mux_sink_event:<muxer:audio_753600480> Got tag event
0:00:00.026293094 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:343:gst_ogg_mux_sink_event:<muxer> Got tags taglist, bitrate=(uint)64000;
0:00:00.026300809 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:2061:gst_ogg_mux_collected:<muxer> collected
0:00:00.026307211 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1010:gst_ogg_mux_queue_pads:<muxer:audio_753600480> looking at pad for buffer
0:00:00.026311238 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1017:gst_ogg_mux_queue_pads:<muxer:audio_753600480> popped buffer buffer: 0x7e9218019fd0, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 3, offset none, offset_end none, flags 0x40
0:00:00.026318492 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:1047:gst_ogg_mux_queue_pads:<muxer:audio_753600480> checking caps: audio/x-opus, rate=(int)48000, channels=(int)1, channel-mapping-family=(int)0, stream-count=(int)1, coupled-count=(int)0, streamheader=(buffer)< 4f707573486561640101380180bb0000000000, 4f707573546167731e000000456e636f6465642077697468204753747265616d6572206f707573656e630000000001 >
0:00:00.026328079 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:1067:gst_ogg_mux_queue_pads:<muxer:audio_753600480> caps detected: audio/x-opus, rate=(int)48000, channels=(int)1, channel-mapping-family=(int)0, stream-count=(int)1, coupled-count=(int)0, streamheader=(buffer)< 4f707573486561640101380180bb0000000000, 4f707573546167731f0000004753747265616d657220656e636f64656420766f72626973636f6d6d656e740000000001 >
0:00:00.026331295 1888741 0x7e921c000d70 DEBUG                 oggmux gstoggmux.c:1100:gst_ogg_mux_queue_pads:<muxer> got data buffer in control state, switching to data mode
0:00:00.026336705 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:912:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> buffer ts 99:99:99.999999999, duration 99:99:99.999999999, granule duration 960
0:00:00.026341434 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:929:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> expected granule 0 == time 0:00:00.000000000 --> ts diff -0:00:00.000000001 < tolerance 0:00:00.040000000 (?)
0:00:00.026344510 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:961:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> [gp      960] decorated buffer 0x7e9218016e70 (granulepos time 0:00:00.013500000)
0:00:00.026348317 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1132:gst_ogg_mux_queue_pads:<muxer:audio_753600480> new best pad, with buffer buffer: 0x7e9218016e70, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 3, offset 13500000, offset_end 960, flags 0x40
0:00:00.026433886 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:2061:gst_ogg_mux_collected:<muxer> collected
0:00:00.026435920 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1010:gst_ogg_mux_queue_pads:<muxer:audio_753600480> looking at pad for buffer
0:00:00.026438595 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1132:gst_ogg_mux_queue_pads:<muxer:audio_753600480> new best pad, with buffer buffer: 0x7e9218016e70, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 3, offset 13500000, offset_end 960, flags 0x40
0:00:00.026446750 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1696:gst_ogg_mux_process_best_pad:<muxer> best pad <muxer:audio_753600480>, currently pulling from (NULL)
0:00:00.026449264 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1763:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> pulling from best pad
0:00:00.026451839 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1768:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> updated times, next ts 99:99:99.999999999
0:00:00.026453793 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1436:gst_ogg_mux_send_headers:<muxer> collecting headers
0:00:00.026455897 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1448:gst_ogg_mux_send_headers:<muxer> looking at pad muxer:audio_753600480
0:00:00.026457710 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1155:gst_ogg_mux_get_headers:<muxer:audio_753600480> getting headers
0:00:00.026460295 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1166:gst_ogg_mux_get_headers:<muxer:audio_753600480> got header
0:00:00.026462028 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1171:gst_ogg_mux_get_headers:<muxer:audio_753600480> got fixed list
0:00:00.026463801 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1176:gst_ogg_mux_get_headers:<muxer:audio_753600480> item 0
0:00:00.026466116 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1180:gst_ogg_mux_get_headers:<muxer:audio_753600480> adding item 0 to header list
0:00:00.026468119 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1176:gst_ogg_mux_get_headers:<muxer:audio_753600480> item 1
0:00:00.026470123 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1180:gst_ogg_mux_get_headers:<muxer:audio_753600480> adding item 1 to header list
0:00:00.026471746 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1458:gst_ogg_mux_send_headers:<muxer> creating BOS pages
0:00:00.026473359 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1476:gst_ogg_mux_send_headers:<muxer:audio_753600480> looping over headers
0:00:00.026475513 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1513:gst_ogg_mux_send_headers:<muxer:audio_753600480> flushing out BOS page
0:00:00.026480763 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:573:gst_ogg_mux_buffer_from_page:<muxer> [gp        0] created buffer 0x7e9218014af0 from ogg page
0:00:00.026482687 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1519:gst_ogg_mux_send_headers:<muxer> swapped out page with mime type 'audio/x-opus'
0:00:00.026484700 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1549:gst_ogg_mux_send_headers:<muxer> creating next headers
0:00:00.026486654 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1563:gst_ogg_mux_send_headers:<muxer> looping over headers for pad muxer:audio_753600480
0:00:00.026489048 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1589:gst_ogg_mux_send_headers:<muxer> flushing page as packet 1 is first or last packet
0:00:00.026492044 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:573:gst_ogg_mux_buffer_from_page:<muxer> [gp        0] created buffer 0x7e921405e9f0 from ogg page
0:00:00.026493817 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1595:gst_ogg_mux_send_headers:<muxer> swapped out page
0:00:00.026498295 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1225:gst_ogg_mux_set_header_on_caps: Setting HEADER on buffer of length 47
0:00:00.026500309 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1225:gst_ogg_mux_set_header_on_caps: Setting HEADER on buffer of length 75
0:00:00.026509887 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:598:gst_ogg_mux_push_buffer:<muxer:src> pushing 0x7e9218014af0, last_ts=99:99:99.999999999
sample 47
0:00:00.026564458 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:598:gst_ogg_mux_push_buffer:<muxer:src> pushing 0x7e921405e9f0, last_ts=99:99:99.999999999
sample 75
0:00:00.026569478 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1794:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> pulling from pad
0:00:00.026571852 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1825:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> [gp      960] packet 2 (3 bytes) created from buffer
0:00:00.026573555 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1853:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> discont at stream start
0:00:00.026578414 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1915:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> [gp      960] packet 2, gp time 0:00:00.013500000, timestamp 99:99:99.999999999 packetin'd
0:00:00.026582372 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1995:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> Updated running gp time of pad <muxer:audio_753600480> to 0:00:00.013500000
0:00:00.026584215 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1010:gst_ogg_mux_queue_pads:<muxer:audio_753600480> looking at pad for buffer
0:00:00.026587120 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1017:gst_ogg_mux_queue_pads:<muxer:audio_753600480> popped buffer buffer: 0x7e921405eef0, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 238, offset none, offset_end none, flags 0x0
0:00:00.026591098 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:912:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> buffer ts 99:99:99.999999999, duration 99:99:99.999999999, granule duration 960
0:00:00.026594895 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:929:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> expected granule 960 == time 0:00:00.013500000 --> ts diff -0:00:00.013500001 < tolerance 0:00:00.040000000 (?)
0:00:00.026597900 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:961:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> [gp     1920] decorated buffer 0x7e9218016e70 (granulepos time 0:00:00.033500000)
0:00:00.026600505 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1132:gst_ogg_mux_queue_pads:<muxer:audio_753600480> new best pad, with buffer buffer: 0x7e9218016e70, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 238, offset 33500000, offset_end 1920, flags 0x0
0:00:00.026697586 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:2061:gst_ogg_mux_collected:<muxer> collected
0:00:00.026699379 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1010:gst_ogg_mux_queue_pads:<muxer:audio_753600480> looking at pad for buffer
0:00:00.026701673 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1132:gst_ogg_mux_queue_pads:<muxer:audio_753600480> new best pad, with buffer buffer: 0x7e9218016e70, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 238, offset 33500000, offset_end 1920, flags 0x0
0:00:00.026704538 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1696:gst_ogg_mux_process_best_pad:<muxer> best pad <muxer:audio_753600480>, currently pulling from <muxer:audio_753600480>
0:00:00.026706382 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1794:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> pulling from pad
0:00:00.026708496 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1825:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> [gp     1920] packet 3 (238 bytes) created from buffer
0:00:00.026712954 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1915:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> [gp     1920] packet 3, gp time 0:00:00.033500000, timestamp 99:99:99.999999999 packetin'd
0:00:00.026716390 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1995:gst_ogg_mux_process_best_pad:<muxer:audio_753600480> Updated running gp time of pad <muxer:audio_753600480> to 0:00:00.033500000
0:00:00.026718254 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1010:gst_ogg_mux_queue_pads:<muxer:audio_753600480> looking at pad for buffer
0:00:00.026720598 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1017:gst_ogg_mux_queue_pads:<muxer:audio_753600480> popped buffer buffer: 0x7e9218019fd0, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 129, offset none, offset_end none, flags 0x0
0:00:00.026725026 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:912:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> buffer ts 99:99:99.999999999, duration 99:99:99.999999999, granule duration 960
0:00:00.026728142 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:929:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> expected granule 1920 == time 0:00:00.033500000 --> ts diff -0:00:00.033500001 < tolerance 0:00:00.040000000 (?)
0:00:00.026730988 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:961:gst_ogg_mux_decorate_buffer:<muxer:audio_753600480> [gp     2880] decorated buffer 0x7e9218016e70 (granulepos time 0:00:00.053500000)
0:00:00.026733352 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:1132:gst_ogg_mux_queue_pads:<muxer:audio_753600480> new best pad, with buffer buffer: 0x7e9218016e70, pts 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 129, offset 53500000, offset_end 2880, flags 0x0
0:00:00.026825192 1888741 0x7e921c000d70 LOG                   oggmux gstoggmux.c:2061:gst_ogg_mux_collected:<muxer> collected
...

Are you setting timestamps (GST_BUFFER_PTS) in nanoseconds on the buffers you push into appsrc?

No I forgot, I thought gst_buffer_new_wrapped_full would initialize pts to 0.

Thanks, it works fine now.

Even if it did, you only want pts 0 on the first buffer, and increasing timestamps thereafter (just to be sure).

Yes of course, but I had only one buffer here, so I totally forgot about timing.