0:00:00.174627146 [334m19227[00m 0x7f1358005a30 [31;01mERROR  [00m [00m           h264parse gsth264parse.c:1868:gst_h264_parse_set_caps:[00m video/x-h264 caps with codec_data but no stream-format=avc
0:00:10.088314415 [334m19227[00m      0x24ee140 [36mINFO   [00m [00m               pulse pulsesink.c:3232:gst_pulsesink_change_state:<pulsesink0>[00m new pa main loop thread
0:00:10.088413339 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:1827:gst_pulsesink_create_ringbuffer:<pulsesink0>[00m creating ringbuffer
0:00:10.088453114 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:1829:gst_pulsesink_create_ringbuffer:<pulsesink0>[00m created ringbuffer @0x7f132000e0b0
0:00:10.088474900 [334m19227[00m      0x24ee140 [36mINFO   [00m [00m               pulse pulsesink.c:533:gst_pulseringbuffer_open_device:<pulsesink0>[00m new context with name gst-play-1.0, pbuf=0x7f132000e0b0, pctx=0x26c6da0
0:00:10.089200353 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:550:gst_pulseringbuffer_open_device:<pulsesink0>[00m connect to server (NULL)
0:00:10.089222368 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 1
0:00:10.089279923 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:572:gst_pulseringbuffer_open_device:<pulsesink0>[00m context state is now 1
0:00:10.089295800 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:581:gst_pulseringbuffer_open_device:<pulsesink0>[00m waiting..
0:00:10.089385258 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 2
0:00:10.089551929 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 3
0:00:10.089715856 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 4
0:00:10.089732479 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:432:gst_pulsering_context_state_cb:[00m signaling
0:00:10.089818449 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:572:gst_pulseringbuffer_open_device:<pulsesink0>[00m context state is now 4
0:00:10.089832727 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:590:gst_pulseringbuffer_open_device:<pulsesink0>[00m opened the device
0:00:10.089885760 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2235:gst_pulsesink_query_acceptcaps:<pulsesink0>[00m caps audio/mpeg, mpegversion=(int)1, mpegaudioversion=(int)1, layer=(int)3, rate=(int)48000, channels=(int)2, parsed=(boolean)true
0:00:10.089937751 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:2076:gst_pulsesink_create_probe_stream:<pulsesink0>[00m Creating probe stream
0:00:10.089970980 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:658:gst_pulsering_stream_state_cb:<pulsesink0>[00m got new stream state 1
0:00:10.089986334 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:860:gst_pulsering_wait_for_stream_ready:<pulsesink0>[00m stream state is now 1
0:00:10.090082711 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:658:gst_pulsering_stream_state_cb:<pulsesink0>[00m got new stream state 3
0:00:10.090095525 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:664:gst_pulsering_stream_state_cb:<pulsesink0>[00m signaling
0:00:10.090113123 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:860:gst_pulsering_wait_for_stream_ready:<pulsesink0>[00m stream state is now 3
0:00:10.090152605 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:636:gst_pulseringbuffer_close_device:<pulsesink0>[00m closing device
0:00:10.090161270 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:339:gst_pulsering_destroy_context:<pulseringbuffer0>[00m destroying ringbuffer 0x7f132000e0b0
0:00:10.090169189 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:354:gst_pulsering_destroy_context:<pulseringbuffer0>[00m releasing context with name gst-play-1.0, pbuf=0x7f132000e0b0, pctx=0x26c6da0
0:00:10.090177557 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:361:gst_pulsering_destroy_context:<pulseringbuffer0>[00m destroying final context with name gst-play-1.0, pbuf=0x7f132000e0b0, pctx=0x26c6da0
0:00:10.090185698 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 6
0:00:10.090192499 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:432:gst_pulsering_context_state_cb:[00m signaling
0:00:10.090237084 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:642:gst_pulseringbuffer_close_device:<pulsesink0>[00m closed device
0:00:10.090255077 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:339:gst_pulsering_destroy_context:<pulseringbuffer0>[00m destroying ringbuffer 0x7f132000e0b0
0:00:10.090267875 [334m19227[00m      0x24ee140 [36mINFO   [00m [00m               pulse pulsesink.c:3214:gst_pulsesink_release_mainloop:<pulsesink0>[00m terminating pa main loop thread
0:00:10.094466582 [334m19227[00m      0x24ee140 [36mINFO   [00m [00m               pulse pulsesink.c:3232:gst_pulsesink_change_state:<pulsesink1>[00m new pa main loop thread
0:00:10.094554363 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:1827:gst_pulsesink_create_ringbuffer:<pulsesink1>[00m creating ringbuffer
0:00:10.094579763 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:1829:gst_pulsesink_create_ringbuffer:<pulsesink1>[00m created ringbuffer @0x7f132000e490
0:00:10.094595951 [334m19227[00m      0x24ee140 [36mINFO   [00m [00m               pulse pulsesink.c:533:gst_pulseringbuffer_open_device:<pulsesink1>[00m new context with name gst-play-1.0, pbuf=0x7f132000e490, pctx=0x26c6b80
0:00:10.095119964 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:550:gst_pulseringbuffer_open_device:<pulsesink1>[00m connect to server (NULL)
0:00:10.095138412 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 1
0:00:10.095185994 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:572:gst_pulseringbuffer_open_device:<pulsesink1>[00m context state is now 1
0:00:10.095201608 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:581:gst_pulseringbuffer_open_device:<pulsesink1>[00m waiting..
0:00:10.095230804 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 2
0:00:10.095394465 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 3
0:00:10.095482321 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:426:gst_pulsering_context_state_cb:[00m got new context state 4
0:00:10.095493793 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:432:gst_pulsering_context_state_cb:[00m signaling
0:00:10.095513130 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:572:gst_pulseringbuffer_open_device:<pulsesink1>[00m context state is now 4
0:00:10.095536113 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:590:gst_pulseringbuffer_open_device:<pulsesink1>[00m opened the device
0:00:10.095608242 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:2076:gst_pulsesink_create_probe_stream:<pulsesink1>[00m Creating probe stream
0:00:10.095638006 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:658:gst_pulsering_stream_state_cb:<pulsesink1>[00m got new stream state 1
0:00:10.095653668 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:860:gst_pulsering_wait_for_stream_ready:<pulsesink1>[00m stream state is now 1
0:00:10.097480696 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:658:gst_pulsering_stream_state_cb:<pulsesink1>[00m got new stream state 2
0:00:10.097534983 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:664:gst_pulsering_stream_state_cb:<pulsesink1>[00m signaling
0:00:10.097660851 [334m19227[00m      0x24ee140 [33;01mLOG    [00m [00m               pulse pulsesink.c:860:gst_pulsering_wait_for_stream_ready:<pulsesink1>[00m stream state is now 2
0:00:10.098225883 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.100971502 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2413:gst_pulsesink_set_volume:<pulsesink1>[00m setting volume to 1,000000
0:00:10.100995531 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2457:gst_pulsesink_set_volume:<pulsesink1>[00m we have no ringbuffer
0:00:10.101023002 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2631:gst_pulsesink_get_sink_input_info:<pulsesink1>[00m we have no ringbuffer
0:00:10.103123054 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.103414480 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:1179:gst_pulseringbuffer_clear:<pulsesink1>[00m clearing
0:00:10.104053808 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.104424744 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.108163789 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.108585444 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.108952191 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.109306994 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.109708998 [334m19227[00m      0x24ee140 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.110032328 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string){ S16LE, S16BE, F32LE, F32BE, S32LE, S32BE, S24LE, S24BE, S24_32LE, S24_32BE, U8 }, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-alaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]; audio/x-mulaw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ]
0:00:10.110590102 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, layout=(string)interleaved, rate=(int)48000, format=(string){ S16LE, S32LE, S24LE, F32LE }, channels=(int)[ 1, 32 ]; audio/x-raw, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], format=(string){ S16LE, S32LE, S24LE, F32LE }, channels=(int)[ 1, 32 ]
0:00:10.110996583 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, layout=(string)interleaved, rate=(int)48000, format=(string){ S16LE, S32LE, S24LE, F32LE }, channels=(int)[ 1, 32 ]; audio/x-raw, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], format=(string){ S16LE, S32LE, S24LE, F32LE }, channels=(int)[ 1, 32 ]
0:00:10.111363838 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, layout=(string)interleaved, rate=(int)48000, format=(string)S32LE, channels=(int)2, channel-mask=(bitmask)0x0000000000000003; audio/x-raw, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], format=(string)S32LE, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:10.111726677 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)48000, channels=(int)2, channel-mask=(bitmask)0x0000000000000003; audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:10.112003534 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2203:gst_pulsesink_query_getcaps:<pulsesink1>[00m caps audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)48000, channels=(int)2, channel-mask=(bitmask)0x0000000000000003; audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:10.112088036 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2235:gst_pulsesink_query_acceptcaps:<pulsesink1>[00m caps audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)48000, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:10.112314545 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2235:gst_pulsesink_query_acceptcaps:<pulsesink1>[00m caps audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)48000, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:10.112530290 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:2235:gst_pulsesink_query_acceptcaps:<pulsesink1>[00m caps audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)48000, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:10.112739713 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:899:gst_pulseringbuffer_acquire:<pulsesink1>[00m creating sample spec
0:00:10.113423297 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:658:gst_pulsering_stream_state_cb:<pulsesink1>[00m got new stream state 4
0:00:10.113445840 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:664:gst_pulsering_stream_state_cb:<pulsesink1>[00m signaling
0:00:10.113478821 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:919:gst_pulseringbuffer_acquire:<pulsesink1>[00m subscribing to context events
0:00:10.113515339 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:968:gst_pulseringbuffer_acquire:<pulsesink1>[00m tlength:   76800
0:00:10.113529335 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:969:gst_pulseringbuffer_acquire:<pulsesink1>[00m maxlength: -1
0:00:10.113540824 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:970:gst_pulseringbuffer_acquire:<pulsesink1>[00m prebuf:    0
0:00:10.113551542 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:971:gst_pulseringbuffer_acquire:<pulsesink1>[00m minreq:    3840
0:00:10.113562012 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:975:gst_pulseringbuffer_acquire:<pulsesink1>[00m have volume of 1,000000
0:00:10.113582574 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:1003:gst_pulseringbuffer_acquire:<pulsesink1>[00m connect for playback to device (NULL)
0:00:10.113611908 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:658:gst_pulsering_stream_state_cb:<pulsesink1>[00m got new stream state 1
0:00:10.113628317 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:860:gst_pulsering_wait_for_stream_ready:<pulsesink1>[00m stream state is now 1
0:00:10.132668654 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:658:gst_pulsering_stream_state_cb:<pulsesink1>[00m got new stream state 2
0:00:10.132708192 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:664:gst_pulsering_stream_state_cb:<pulsesink1>[00m signaling
0:00:10.132721384 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:684:gst_pulsering_stream_request_cb:<pulsesink1>[00m got request for length 42240
0:00:10.132753381 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:860:gst_pulsering_wait_for_stream_ready:<pulsesink1>[00m stream state is now 2
0:00:10.132786485 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:1021:gst_pulseringbuffer_acquire:<pulsesink1>[00m negotiated to: pcm, format.sample_format = "\"s32le\""  format.channels = "2"  format.rate = "48000"  format.channel_map = "\"front-left,front-right\""
0:00:10.132796200 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:1028:gst_pulseringbuffer_acquire:<pulsesink1>[00m stream is acquired now
0:00:10.132803013 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:1034:gst_pulseringbuffer_acquire:<pulsesink1>[00m tlength:   42240 (wanted: 76800)
0:00:10.132810855 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:1035:gst_pulseringbuffer_acquire:<pulsesink1>[00m maxlength: 4194304
0:00:10.132817425 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:1036:gst_pulseringbuffer_acquire:<pulsesink1>[00m prebuf:    0
0:00:10.132823789 [334m19227[00m 0x7f13340034a0 [36mINFO   [00m [00m               pulse pulsesink.c:1038:gst_pulseringbuffer_acquire:<pulsesink1>[00m minreq:    3840 (wanted 3840)
0:00:10.132852412 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:460:gst_pulsering_context_subscribe_cb:<pulsesink1>[00m type 0002, idx 100
0:00:10.132889071 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:757:gst_pulsering_stream_latency_cb:<pulsesink1>[00m latency_update, 1413971540588532000, 0:0, 0:0, 340355, 90000
0:00:10.133176227 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:2032:gst_pulsesink_get_time:<pulsesink1>[00m current time is 0:00:00.000000000
0:00:10.133459153 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:460:gst_pulsering_context_subscribe_cb:<pulsesink1>[00m type 0012, idx 100
0:00:10.133503067 [334m19227[00m 0x7f132c248a30 [33;01mLOG    [00m [00m               pulse pulsesink.c:460:gst_pulsering_context_subscribe_cb:<pulsesink1>[00m type 0012, idx 100
0:00:10.134519534 [334m19227[00m 0x7f13340034a0 [33;01mLOG    [00m [00m               pulse pulsesink.c:2032:gst_pulsesink_get_time:<pulsesink1>[00m current time is 0:00:00.000000000
0:00:10.134549406 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:1223:gst_pulseringbuffer_start:<pulsesink1>[00m scheduling stream status
0:00:10.134566750 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:1228:gst_pulseringbuffer_start:<pulsesink1>[00m starting
0:00:10.134583666 [334m19227[00m 0x7f13340034a0 [37mDEBUG  [00m [00m               pulse pulsesink.c:1241:gst_pulseringbuffer_start:<pulsesink1>[00m waiting for stream status (ENTER) to be posted
0:00:10.134618554 [334m19227[00m 0x7f132c248a30 [37mDEBUG  [00m [00m               pulse pulsesink.c:1196:mainloop_enter_defer_cb:<pulsesink1>[00m posting ENTER stream status
