test-rtp-7[7779]: GLIB DEBUG farsight-rtp - Clock lost, changing pipeline to PAUSED->PLAYING to find a new clock
test-rtp-7[7779]: GLIB DEBUG farsight-rtp - Changing state of the pipeline to PAUSED
0:00:34.912751000 7779 0x13050 DEBUG bin gstbin.c:2092:gst_bin_change_state_func:<pipeline> clearing EOS elements
0:00:34.916321000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<pipeline> resync
0:00:34.917847000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> recv99 add to queue
0:00:34.919556000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpsinkelement add to queue
0:00:34.921570000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element send0 not linked on any sinkpads
0:00:34.923676000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdemux0, degree 0->1, linked to recv99
0:00:34.925995000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 0->1, linked to rtpsinkelement
0:00:34.928376000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element send0, degree 0->1, linked to rtpdtmfmux0
0:00:34.931458000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 1->2, linked to rtpdemux0
0:00:34.933564000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element udpsrc not linked on any sinkpads
0:00:34.935578000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdtmfmux0, degree 0->1, linked to rtpbin0
0:00:34.938202000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element udpsrc, degree 0->1, linked to rtpbin0
0:00:34.940277000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives recv99
0:00:34.945587000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdemux0, degree 1->0, linked to recv99
0:00:34.947205000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpdemux0 add to queue
0:00:34.949311000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element recv99 to PAUSED, base_time 0:00:00.390000000
0:00:34.950989000 7779 0x13050 DEBUG bin gstbin.c:2092:gst_bin_change_state_func:<recv99> clearing EOS elements
0:00:34.953034000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<recv99> resync
0:00:34.954560000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<recv99> dspilbcsink0 add to queue
0:00:34.956635000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<recv99> change element rtpilbcdepay0, degree 0->1, linked to capsfilter3
0:00:34.959351000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<recv99> element rtpilbcdepay0 not linked on any sinkpads
0:00:34.961640000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<recv99> change element capsfilter3, degree 0->1, linked to dspilbcsink0
0:00:34.964234000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<recv99> queue head gives dspilbcsink0
0:00:34.966248000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<recv99> change element capsfilter3, degree 1->0, linked to dspilbcsink0
0:00:34.968140000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<recv99> capsfilter3 add to queue
0:00:34.970246000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<recv99> setting element dspilbcsink0 to PAUSED, base_time 0:00:00.390000000
0:00:34.972687000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<recv99> [msg 0xe0848] handling child dspilbcsink0 message of type async-start
0:00:34.974366000 7779 0x13050 DEBUG bin gstbin.c:2777:gst_bin_handle_message_func:<recv99> ASYNC_START message 0xe0848, dspilbcsink0
0:00:34.976136000 7779 0x13050 DEBUG bin gstbin.c:748:bin_replace_message:<recv99> got new message 0xe0848, async-start from dspilbcsink0
0:00:34.978119000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<recv99> posting message upward
0:00:34.980011000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xd4c58] handling child recv99 message of type async-start
0:00:34.982117000 7779 0x13050 DEBUG bin gstbin.c:2777:gst_bin_handle_message_func:<pipeline> ASYNC_START message 0xd4c58, recv99
0:00:34.983979000 7779 0x13050 DEBUG bin gstbin.c:748:bin_replace_message:<pipeline> got new message 0xd4c58, async-start from recv99
0:00:34.986206000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<recv99> queue head gives capsfilter3
0:00:34.988282000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<recv99> change element rtpilbcdepay0, degree 1->0, linked to capsfilter3
0:00:34.989930000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<recv99> rtpilbcdepay0 add to queue
0:00:34.995179000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<recv99> setting element capsfilter3 to PAUSED, base_time 0:00:00.390000000
0:00:34.998017000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<recv99> [msg 0xe9048] handling child capsfilter3 message of type state-changed
0:00:34.999939000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<recv99> posting message upward
0:00:35.001679000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xe9048] handling child capsfilter3 message of type state-changed
0:00:35.003357000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.005860000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<recv99> queue head gives rtpilbcdepay0
0:00:35.008454000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<recv99> element rtpilbcdepay0 not linked on any sinkpads
0:00:35.010102000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<recv99> setting element rtpilbcdepay0 to PAUSED, base_time 0:00:00.390000000
0:00:35.012451000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<recv99> [msg 0xe0f90] handling child rtpilbcdepay0 message of type state-changed
0:00:35.014832000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<recv99> posting message upward
0:00:35.016632000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xe0f90] handling child rtpilbcdepay0 message of type state-changed
0:00:35.018280000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.020813000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<recv99> queue empty, elements exhausted
0:00:35.022675000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<recv99> free
0:00:35.024597000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpsinkelement
0:00:35.026642000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 2->1, linked to rtpsinkelement
0:00:35.028717000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element rtpsinkelement to PAUSED, base_time 0:00:00.390000000
0:00:35.031372000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xe0888] handling child rtpsinkelement message of type async-start
0:00:35.033570000 7779 0x13050 DEBUG bin gstbin.c:2777:gst_bin_handle_message_func:<pipeline> ASYNC_START message 0xe0888, rtpsinkelement
0:00:35.035187000 7779 0x13050 DEBUG bin gstbin.c:748:bin_replace_message:<pipeline> got new message 0xe0888, async-start from rtpsinkelement
0:00:35.037293000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpdemux0
0:00:35.042115000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 1->0, linked to rtpdemux0
0:00:35.043763000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpbin0 add to queue
0:00:35.046234000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element rtpdemux0 to PAUSED, base_time 0:00:00.390000000
0:00:35.049134000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xddd08] handling child rtpdemux0 message of type state-changed
0:00:35.050782000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.053162000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpbin0
0:00:35.055451000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdtmfmux0, degree 1->0, linked to rtpbin0
0:00:35.057038000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpdtmfmux0 add to queue
0:00:35.059449000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element udpsrc, degree 1->0, linked to rtpbin0
0:00:35.061035000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> udpsrc add to queue
0:00:35.063477000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element rtpbin0 to PAUSED, base_time 0:00:00.390000000
0:00:35.065186000 7779 0x13050 DEBUG bin gstbin.c:2092:gst_bin_change_state_func:<rtpbin0> clearing EOS elements
0:00:35.066925000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<rtpbin0> resync
0:00:35.070771000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtpsend0 not linked on any sinkpads
0:00:35.072846000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<rtpbin0> change element rtprecv0, degree 0->1, linked to rtpjitterbuffer0
0:00:35.075531000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtprecv0 not linked on any sinkpads
0:00:35.077393000 7779 0x13050 DEBUG bin gstbin.c:1784:gst_bin_sort_iterator_next:<rtpbin0> queue empty, next best: rtpsend0
0:00:35.079224000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<rtpbin0> queue head gives rtpsend0
0:00:35.081543000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtpsend0 not linked on any sinkpads
0:00:35.083191000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<rtpbin0> setting element rtpsend0 to PAUSED, base_time 0:00:00.390000000
0:00:35.085785000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<rtpbin0> [msg 0x22e88] handling child rtpsend0 message of type state-changed
0:00:35.087433000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<rtpbin0> posting message upward
0:00:35.089722000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22e88] handling child rtpsend0 message of type state-changed
0:00:35.094269000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.096863000 7779 0x13050 DEBUG bin gstbin.c:1784:gst_bin_sort_iterator_next:<rtpbin0> queue empty, next best: rtpjitterbuffer0
0:00:35.098725000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<rtpbin0> queue head gives rtpjitterbuffer0
0:00:35.101013000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<rtpbin0> change element rtprecv0, degree 1->0, linked to rtpjitterbuffer0
0:00:35.103089000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<rtpbin0> rtprecv0 add to queue
0:00:35.105225000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<rtpbin0> setting element rtpjitterbuffer0 to PAUSED, base_time 0:00:00.390000000
0:00:35.107819000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<rtpbin0> [msg 0x22a80] handling child rtpjitterbuffer0 message of type state-changed
0:00:35.109803000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<rtpbin0> posting message upward
0:00:35.111573000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22a80] handling child rtpjitterbuffer0 message of type state-changed
0:00:35.113251000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.115784000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<rtpbin0> queue head gives rtprecv0
0:00:35.118317000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtprecv0 not linked on any sinkpads
0:00:35.119934000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<rtpbin0> setting element rtprecv0 to PAUSED, base_time 0:00:00.390000000
0:00:35.122711000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<rtpbin0> [msg 0x22e48] handling child rtprecv0 message of type state-changed
0:00:35.124665000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<rtpbin0> posting message upward
0:00:35.126435000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22e48] handling child rtprecv0 message of type state-changed
0:00:35.128113000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.130616000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<rtpbin0> queue empty, elements exhausted
0:00:35.132477000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<rtpbin0> free
0:00:35.134857000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22e08] handling child rtpbin0 message of type state-changed
0:00:35.136505000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.138947000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpdtmfmux0
0:00:35.145630000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element send0, degree 1->0, linked to rtpdtmfmux0
0:00:35.147248000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> send0 add to queue
0:00:35.149597000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element rtpdtmfmux0 to PAUSED, base_time 0:00:00.390000000
0:00:35.151978000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22dc8] handling child rtpdtmfmux0 message of type state-changed
0:00:35.153656000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.156281000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives udpsrc
0:00:35.158326000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element udpsrc not linked on any sinkpads
0:00:35.159912000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element udpsrc to PAUSED, base_time 0:00:00.390000000
0:00:35.162262000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22d88] handling child udpsrc message of type state-changed
0:00:35.164185000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.166565000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives send0
0:00:35.168183000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element send0 not linked on any sinkpads
0:00:35.169709000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element send0 to PAUSED, base_time 0:00:00.390000000
0:00:35.171570000 7779 0x13050 DEBUG bin gstbin.c:2092:gst_bin_change_state_func:<send0> clearing EOS elements
0:00:35.173371000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<send0> resync
0:00:35.175721000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element dsppcmsrc1, degree 0->1, linked to capsfilter4
0:00:35.178162000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element capsfilter4, degree 0->1, linked to rtppcmupay1
0:00:35.180481000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<send0> element dsppcmsrc1 not linked on any sinkpads
0:00:35.182068000 7779 0x13050 DEBUG bin gstbin.c:1784:gst_bin_sort_iterator_next:<send0> queue empty, next best: rtppcmupay1
0:00:35.183869000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives rtppcmupay1
0:00:35.185852000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element capsfilter4, degree 1->0, linked to rtppcmupay1
0:00:35.187714000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<send0> capsfilter4 add to queue
0:00:35.189820000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<send0> setting element rtppcmupay1 to PAUSED, base_time 0:00:00.390000000
0:00:35.195771000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<send0> [msg 0x22d48] handling child rtppcmupay1 message of type state-changed
0:00:35.197419000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<send0> posting message upward
0:00:35.199189000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22d48] handling child rtppcmupay1 message of type state-changed
0:00:35.200806000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.203583000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives capsfilter4
0:00:35.206024000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element dsppcmsrc1, degree 1->0, linked to capsfilter4
0:00:35.207672000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<send0> dsppcmsrc1 add to queue
0:00:35.210450000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<send0> setting element capsfilter4 to PAUSED, base_time 0:00:00.390000000
0:00:35.212860000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<send0> [msg 0x22d08] handling child capsfilter4 message of type state-changed
0:00:35.214539000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<send0> posting message upward
0:00:35.216278000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22d08] handling child capsfilter4 message of type state-changed
0:00:35.218201000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.220734000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives dsppcmsrc1
0:00:35.222321000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<send0> element dsppcmsrc1 not linked on any sinkpads
0:00:35.223847000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<send0> setting element dsppcmsrc1 to PAUSED, base_time 0:00:00.390000000
0:00:35.226471000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<send0> [msg 0x22cc8] handling child dsppcmsrc1 message of type state-changed
0:00:35.228699000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<send0> posting message upward
0:00:35.230500000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22cc8] handling child dsppcmsrc1 message of type state-changed
0:00:35.232117000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.234589000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<send0> queue empty, elements exhausted
0:00:35.236176000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<send0> free
0:00:35.238526000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0x22a00] handling child send0 message of type state-changed
0:00:35.243653000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.246064000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<pipeline> queue empty, elements exhausted
0:00:35.247681000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<pipeline> free
test-rtp-7[7779]: GLIB DEBUG farsight-rtp - Waiting for state to change to PAUSED - 3
test-rtp-7[7779]: GLIB DEBUG farsight-rtp - Changing state of the pipeline to PLAYING - 3
0:00:35.262116000 7779 0x13050 DEBUG bin gstbin.c:637:gst_bin_provide_clock_func:<pipeline> finding new clock
0:00:35.265290000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<pipeline> resync
0:00:35.266785000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> recv99 add to queue
0:00:35.268494000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpsinkelement add to queue
0:00:35.270294000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element send0 not linked on any sinkpads
0:00:35.272553000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdemux0, degree 0->1, linked to recv99
0:00:35.274933000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 0->1, linked to rtpsinkelement
0:00:35.277314000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element send0, degree 0->1, linked to rtpdtmfmux0
0:00:35.280213000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 1->2, linked to rtpdemux0
0:00:35.282257000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element udpsrc not linked on any sinkpads
0:00:35.284272000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdtmfmux0, degree 0->1, linked to rtpbin0
0:00:35.286652000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element udpsrc, degree 0->1, linked to rtpbin0
0:00:35.289002000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives recv99
0:00:35.290985000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdemux0, degree 1->0, linked to recv99
0:00:35.292572000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpdemux0 add to queue
0:00:35.294648000 7779 0x13050 DEBUG bin gstbin.c:681:gst_bin_provide_clock_func:<recv99> returning old clock (nil)
0:00:35.297516000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpsinkelement
0:00:35.299591000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 2->1, linked to rtpsinkelement
0:00:35.302277000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpdemux0
0:00:35.307404000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 1->0, linked to rtpdemux0
0:00:35.309021000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpbin0 add to queue
0:00:35.311219000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpbin0
0:00:35.313507000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdtmfmux0, degree 1->0, linked to rtpbin0
0:00:35.315552000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpdtmfmux0 add to queue
0:00:35.317963000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element udpsrc, degree 1->0, linked to rtpbin0
0:00:35.319550000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> udpsrc add to queue
0:00:35.321564000 7779 0x13050 DEBUG bin gstbin.c:681:gst_bin_provide_clock_func:<rtpbin0> returning old clock (nil)
0:00:35.323395000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpdtmfmux0
0:00:35.325409000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element send0, degree 1->0, linked to rtpdtmfmux0
0:00:35.326996000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> send0 add to queue
0:00:35.329529000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives udpsrc
0:00:35.331024000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element udpsrc not linked on any sinkpads
0:00:35.332794000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives send0
0:00:35.334748000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element send0 not linked on any sinkpads
0:00:35.336548000 7779 0x13050 DEBUG bin gstbin.c:637:gst_bin_provide_clock_func:<send0> finding new clock
0:00:35.338318000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<send0> resync
0:00:35.340271000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element dsppcmsrc1, degree 0->1, linked to capsfilter4
0:00:35.344208000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element capsfilter4, degree 0->1, linked to rtppcmupay1
0:00:35.346314000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<send0> element dsppcmsrc1 not linked on any sinkpads
0:00:35.347931000 7779 0x13050 DEBUG bin gstbin.c:1784:gst_bin_sort_iterator_next:<send0> queue empty, next best: rtppcmupay1
0:00:35.349701000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives rtppcmupay1
0:00:35.351960000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element capsfilter4, degree 1->0, linked to rtppcmupay1
0:00:35.354065000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<send0> capsfilter4 add to queue
0:00:35.359253000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives capsfilter4
0:00:35.361298000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element dsppcmsrc1, degree 1->0, linked to capsfilter4
0:00:35.362976000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<send0> dsppcmsrc1 add to queue
0:00:35.365174000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives dsppcmsrc1
0:00:35.366974000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<send0> element dsppcmsrc1 not linked on any sinkpads
0:00:35.369232000 7779 0x13050 DEBUG bin gstbin.c:648:gst_bin_provide_clock_func:<send0> found candidate clock 0xa02f8 by element dsppcmsrc1
0:00:35.370850000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<send0> queue empty, elements exhausted
0:00:35.373047000 7779 0x13050 DEBUG bin gstbin.c:667:gst_bin_provide_clock_func:<send0> provided new clock <clock> by provider <dsppcmsrc1>
0:00:35.375244000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<send0> free
0:00:35.376953000 7779 0x13050 DEBUG bin gstbin.c:648:gst_bin_provide_clock_func:<pipeline> found candidate clock 0xa02f8 by element send0
0:00:35.378601000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<pipeline> queue empty, elements exhausted
0:00:35.382263000 7779 0x13050 DEBUG bin gstbin.c:1006:gst_bin_remove_func:<send99> element :capsfilter2
0:00:35.385559000 7779 0x13050 DEBUG bin gstbin.c:1095:gst_bin_remove_func:<send99> marking state dirty
0:00:35.389862000 7779 0x13050 DEBUG bin gstbin.c:1006:gst_bin_remove_func:<send99> element :rtpilbcpay0
0:00:35.393372000 7779 0x13050 DEBUG bin gstbin.c:1095:gst_bin_remove_func:<send99> marking state dirty
0:00:35.397400000 7779 0x13050 DEBUG bin gstbin.c:1006:gst_bin_remove_func:<send99> element :rtpcnpayload0
0:00:35.400757000 7779 0x13050 DEBUG bin gstbin.c:1095:gst_bin_remove_func:<send99> marking state dirty
0:00:35.404694000 7779 0x13050 DEBUG bin gstbin.c:1006:gst_bin_remove_func:<send99> element :dspilbcsrc0
0:00:35.407288000 7779 0x13050 DEBUG bin gstbin.c:1095:gst_bin_remove_func:<send99> marking state dirty
0:00:35.416291000 7779 0x13050 DEBUG bin gstbin.c:667:gst_bin_provide_clock_func:<pipeline> provided new clock <clock> by provider <send0>
0:00:35.418366000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<pipeline> free
0:00:35.429444000 7779 0x13050 DEBUG bin gstbin.c:3127:gst_bin_query:<pipeline> Sending query 0xba060 (type latency) to sink children
0:00:35.431946000 7779 0x13050 DEBUG bin gstbin.c:3127:gst_bin_query:<recv99> Sending query 0xba060 (type latency) to sink children
0:00:35.434815000 7779 0x13050 DEBUG bin gstbin.c:3161:gst_bin_query:<recv99> query 0xba060 result 0
0:00:35.441681000 7779 0x13050 DEBUG bin gstbin.c:3161:gst_bin_query:<pipeline> query 0xba060 result 0
0:00:35.443634000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<pipeline> resync
0:00:35.445099000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> recv99 add to queue
0:00:35.446778000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpsinkelement add to queue
0:00:35.448609000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element send0 not linked on any sinkpads
0:00:35.450592000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdemux0, degree 0->1, linked to recv99
0:00:35.453705000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 0->1, linked to rtpsinkelement
0:00:35.456055000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element send0, degree 0->1, linked to rtpdtmfmux0
0:00:35.458466000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 1->2, linked to rtpdemux0
0:00:35.460785000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element udpsrc not linked on any sinkpads
0:00:35.462799000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdtmfmux0, degree 0->1, linked to rtpbin0
0:00:35.465149000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element udpsrc, degree 0->1, linked to rtpbin0
0:00:35.467194000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives recv99
0:00:35.469483000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdemux0, degree 1->0, linked to recv99
0:00:35.471070000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpdemux0 add to queue
0:00:35.473603000 7779 0x13050 DEBUG bin gstbin.c:1925:gst_bin_element_set_state:<recv99> element message 0xd4c58, recv99 async busy
0:00:35.475190000 7779 0x13050 DEBUG bin gstbin.c:1965:gst_bin_element_set_state:<recv99> element is was busy delaying state change
0:00:35.476960000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpsinkelement
0:00:35.479004000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 2->1, linked to rtpsinkelement
0:00:35.481049000 7779 0x13050 DEBUG bin gstbin.c:1925:gst_bin_element_set_state:<rtpsinkelement> element message 0xe0888, rtpsinkelement async busy
0:00:35.482575000 7779 0x13050 DEBUG bin gstbin.c:1965:gst_bin_element_set_state:<rtpsinkelement> element is was busy delaying state change
0:00:35.484375000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpdemux0
0:00:35.486389000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpbin0, degree 1->0, linked to rtpdemux0
0:00:35.491455000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpbin0 add to queue
0:00:35.493653000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element rtpdemux0 to PLAYING, base_time 0:00:00.000000000
0:00:35.496033000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xd4dd8] handling child rtpdemux0 message of type state-changed
0:00:35.497711000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.500336000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpbin0
0:00:35.502350000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element rtpdtmfmux0, degree 1->0, linked to rtpbin0
0:00:35.503937000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> rtpdtmfmux0 add to queue
0:00:35.506745000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element udpsrc, degree 1->0, linked to rtpbin0
0:00:35.508393000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> udpsrc add to queue
0:00:35.510468000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element rtpbin0 to PLAYING, base_time 0:00:00.000000000
0:00:35.512513000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<rtpbin0> resync
0:00:35.514740000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtpsend0 not linked on any sinkpads
0:00:35.516754000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<rtpbin0> change element rtprecv0, degree 0->1, linked to rtpjitterbuffer0
0:00:35.519471000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtprecv0 not linked on any sinkpads
0:00:35.521057000 7779 0x13050 DEBUG bin gstbin.c:1784:gst_bin_sort_iterator_next:<rtpbin0> queue empty, next best: rtpsend0
0:00:35.523102000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<rtpbin0> queue head gives rtpsend0
0:00:35.525421000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtpsend0 not linked on any sinkpads
0:00:35.527466000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<rtpbin0> setting element rtpsend0 to PLAYING, base_time 0:00:00.000000000
0:00:35.529877000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<rtpbin0> [msg 0xd4f18] handling child rtpsend0 message of type state-changed
0:00:35.531494000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<rtpbin0> posting message upward
0:00:35.533356000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xd4f18] handling child rtpsend0 message of type state-changed
0:00:35.534973000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.540741000 7779 0x13050 DEBUG bin gstbin.c:1784:gst_bin_sort_iterator_next:<rtpbin0> queue empty, next best: rtpjitterbuffer0
0:00:35.542633000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<rtpbin0> queue head gives rtpjitterbuffer0
0:00:35.544678000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<rtpbin0> change element rtprecv0, degree 1->0, linked to rtpjitterbuffer0
0:00:35.546265000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<rtpbin0> rtprecv0 add to queue
0:00:35.548371000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<rtpbin0> setting element rtpjitterbuffer0 to PLAYING, base_time 0:00:00.000000000
0:00:35.550965000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<rtpbin0> [msg 0xd4f58] handling child rtpjitterbuffer0 message of type state-changed
0:00:35.552613000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<rtpbin0> posting message upward
0:00:35.554383000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xd4f58] handling child rtpjitterbuffer0 message of type state-changed
0:00:35.556031000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.559357000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<rtpbin0> queue head gives rtprecv0
0:00:35.561920000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<rtpbin0> element rtprecv0 not linked on any sinkpads
0:00:35.563568000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<rtpbin0> setting element rtprecv0 to PLAYING, base_time 0:00:00.000000000
0:00:35.565918000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<rtpbin0> [msg 0xd4f98] handling child rtprecv0 message of type state-changed
0:00:35.567566000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<rtpbin0> posting message upward
0:00:35.569580000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xd4f98] handling child rtprecv0 message of type state-changed
0:00:35.571198000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.573761000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<rtpbin0> queue empty, elements exhausted
0:00:35.575348000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<rtpbin0> free
0:00:35.578492000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xd5020] handling child rtpbin0 message of type state-changed
0:00:35.580201000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.582550000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives rtpdtmfmux0
0:00:35.584565000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<pipeline> change element send0, degree 1->0, linked to rtpdtmfmux0
0:00:35.588257000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<pipeline> send0 add to queue
0:00:35.590393000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element rtpdtmfmux0 to PLAYING, base_time 0:00:00.000000000
0:00:35.593048000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xddf88] handling child rtpdtmfmux0 message of type state-changed
0:00:35.595215000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.597626000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives udpsrc
0:00:35.599152000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element udpsrc not linked on any sinkpads
0:00:35.600678000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element udpsrc to PLAYING, base_time 0:00:00.000000000
0:00:35.603211000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xddf48] handling child udpsrc message of type state-changed
0:00:35.604889000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.607239000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<pipeline> queue head gives send0
0:00:35.608795000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<pipeline> element send0 not linked on any sinkpads
0:00:35.610321000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<pipeline> setting element send0 to PLAYING, base_time 0:00:00.000000000
0:00:35.632691000 7779 0x13050 DEBUG bin gstbin.c:1811:gst_bin_sort_iterator_resync:<send0> resync
0:00:35.634674000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element dsppcmsrc1, degree 0->1, linked to capsfilter4
0:00:35.637085000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element capsfilter4, degree 0->1, linked to rtppcmupay1
0:00:35.639191000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<send0> element dsppcmsrc1 not linked on any sinkpads
0:00:35.640992000 7779 0x13050 DEBUG bin gstbin.c:1784:gst_bin_sort_iterator_next:<send0> queue empty, next best: rtppcmupay1
0:00:35.642792000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives rtppcmupay1
0:00:35.644806000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element capsfilter4, degree 1->0, linked to rtppcmupay1
0:00:35.646393000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<send0> capsfilter4 add to queue
0:00:35.648743000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<send0> setting element rtppcmupay1 to PLAYING, base_time 0:00:00.000000000
0:00:35.651795000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<send0> [msg 0xdddc8] handling child rtppcmupay1 message of type state-changed
0:00:35.653504000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<send0> posting message upward
0:00:35.662415000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xdddc8] handling child rtppcmupay1 message of type state-changed
0:00:35.664368000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.666901000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives capsfilter4
0:00:35.668946000 7779 0x13050 DEBUG bin gstbin.c:1720:update_degree:<send0> change element dsppcmsrc1, degree 1->0, linked to capsfilter4
0:00:35.670563000 7779 0x13050 DEBUG bin gstbin.c:1645:add_to_queue:<send0> dsppcmsrc1 add to queue
0:00:35.673493000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<send0> setting element capsfilter4 to PLAYING, base_time 0:00:00.000000000
0:00:35.675873000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<send0> [msg 0xddf08] handling child capsfilter4 message of type state-changed
0:00:35.677521000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<send0> posting message upward
0:00:35.679596000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xddf08] handling child capsfilter4 message of type state-changed
0:00:35.681214000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.683747000 7779 0x13050 DEBUG bin gstbin.c:1798:gst_bin_sort_iterator_next:<send0> queue head gives dsppcmsrc1
0:00:35.685303000 7779 0x13050 DEBUG bin gstbin.c:1740:update_degree:<send0> element dsppcmsrc1 not linked on any sinkpads
0:00:35.687104000 7779 0x13050 DEBUG bin gstbin.c:1947:gst_bin_element_set_state:<send0> setting element dsppcmsrc1 to PLAYING, base_time 0:00:00.000000000
0:00:35.689637000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<send0> [msg 0xddec8] handling child dsppcmsrc1 message of type state-changed
0:00:35.691864000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<send0> posting message upward
0:00:35.693726000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xddec8] handling child dsppcmsrc1 message of type state-changed
0:00:35.695649000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.698212000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<send0> queue empty, elements exhausted
0:00:35.699768000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<send0> free
0:00:35.702393000 7779 0x13050 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xdde88] handling child send0 message of type state-changed
0:00:35.704071000 7779 0x13050 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.706421000 7779 0x13050 DEBUG bin gstbin.c:1789:gst_bin_sort_iterator_next:<pipeline> queue empty, elements exhausted
0:00:35.711487000 7779 0x13050 DEBUG bin gstbin.c:1828:gst_bin_sort_iterator_free:<pipeline> free
test-rtp-7[7779]: GLIB DEBUG farsight-rtp - Clock provider found
0:00:35.631409000 7788 0xd7cc8 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<recv99> [msg 0xe90c8] handling child dspilbcsink0 message of type state-changed
0:00:35.719300000 7788 0xd7cc8 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<recv99> posting message upward
0:00:35.721100000 7788 0xd7cc8 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xe90c8] handling child dspilbcsink0 message of type state-changed
0:00:35.723206000 7788 0xd7cc8 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.726319000 7788 0xd7cc8 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<recv99> [msg 0xe9108] handling child dspilbcsink0 message of type async-done
0:00:35.728028000 7788 0xd7cc8 DEBUG bin gstbin.c:2826:gst_bin_handle_message_func:<recv99> ASYNC_DONE message 0xe9108, dspilbcsink0
0:00:35.729889000 7788 0xd7cc8 DEBUG bin gstbin.c:742:bin_replace_message:<recv99> replace old message async-done from dspilbcsink0
0:00:35.731476000 7788 0xd7cc8 DEBUG bin gstbin.c:775:bin_remove_messages:<dspilbcsink0> deleting message 0xe9108 of types 0x00200000
0:00:35.734192000 7788 0xd7cc8 DEBUG bin gstbin.c:2855:gst_bin_handle_message_func:<recv99> posting state change message
0:00:35.736054000 7788 0xd7cc8 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xe9148] handling child recv99 message of type state-changed
0:00:35.737702000 7788 0xd7cc8 DEBUG bin gstbin.c:2890:gst_bin_handle_message_func:<pipeline> posting message upward
0:00:35.739899000 7788 0xd7cc8 DEBUG bin gstbin.c:2861:gst_bin_handle_message_func:<recv99> all async-done, posting ASYNC_DONE to parent
0:00:35.742829000 7788 0xd7cc8 DEBUG bin gstbin.c:2637:gst_bin_handle_message_func:<pipeline> [msg 0xe9188] handling child recv99 message of type async-done
0:00:35.744477000 7788 0xd7cc8 DEBUG bin gstbin.c:2826:gst_bin_handle_message_func:<pipeline> ASYNC_DONE message 0xe9188, recv99
0:00:35.746338000 7788 0xd7cc8 DEBUG bin gstbin.c:742:bin_replace_message:<pipeline> replace old message async-done from recv99