{"action":"created","issue":{"url":"https://api.github.com/repos/alexa/avs-device-sdk/issues/545","repository_url":"https://api.github.com/repos/alexa/avs-device-sdk","labels_url":"https://api.github.com/repos/alexa/avs-device-sdk/issues/545/labels{/name}","comments_url":"https://api.github.com/repos/alexa/avs-device-sdk/issues/545/comments","events_url":"https://api.github.com/repos/alexa/avs-device-sdk/issues/545/events","html_url":"https://github.com/alexa/avs-device-sdk/issues/545","id":302571992,"number":545,"title":"MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed_Already used GST_DEBUG 4 and run again but cannot be solved","user":{"login":"actions-semi4378","id":37095622,"avatar_url":"https://avatars1.githubusercontent.com/u/37095622?v=4","gravatar_id":"","url":"https://api.github.com/users/actions-semi4378","html_url":"https://github.com/actions-semi4378","followers_url":"https://api.github.com/users/actions-semi4378/followers","following_url":"https://api.github.com/users/actions-semi4378/following{/other_user}","gists_url":"https://api.github.com/users/actions-semi4378/gists{/gist_id}","starred_url":"https://api.github.com/users/actions-semi4378/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/actions-semi4378/subscriptions","organizations_url":"https://api.github.com/users/actions-semi4378/orgs","repos_url":"https://api.github.com/users/actions-semi4378/repos","events_url":"https://api.github.com/users/actions-semi4378/events{/privacy}","received_events_url":"https://api.github.com/users/actions-semi4378/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":5,"created_at":"2018-03-06T05:47:47Z","updated_at":"2018-03-09T18:04:44Z","closed_at":null,"author_association":"NONE","body":"**IMPORTANT**: Before you create an issue, please take a look at our [Issue Reporting Guide](https://github.com/alexa/avs-device-sdk/wiki/Issue-Reporting-Guide).\r\n\r\n\r\n## Briefly summarize your issue:\r\nCommand: Alexa, play audible book \"After Life\"\r\nReply: Getting the book from XXX's audible library, resuming After Life, there's XXX left of the book.\r\n\r\n## What is the expected behavior:\r\nThe book should be played directly.\r\n\r\n## What behavior are you observing?\r\nNothing happened, but have to rewake up Alexa once then book starts to be played.\r\n\r\n## Provide the steps to reproduce the issue, if applicable:\r\n2018-03-06 03:57:22.523 [  7] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed\r\n0:00:45.088641308   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.088954790   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fake-audio-sink> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.089102391   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<fake-audio-sink> skipping transition from NULL to  NULL\r\n0:00:45.089210305   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'fake-audio-sink' changed state to 1(NULL) successfully\r\n0:00:45.089384363   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to NULL\r\n0:00:45.089510037   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 1(NULL) successfully\r\n0:00:45.089675867   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.089804666   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<volume> skipping transition from NULL to  NULL\r\n0:00:45.089915705   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 1(NULL) successfully\r\n0:00:45.090079087   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.090201740   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<converter> skipping transition from NULL to  NULL\r\n0:00:45.090303665   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 1(NULL) successfully\r\n0:00:45.090448088   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.090553503   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<decodedQueue> skipping transition from NULL to  NULL\r\n0:00:45.090645323   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 1(NULL) successfully\r\n0:00:45.090783862   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to NULL\r\n2018-03-06 03:57:22.530 [  7] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed\r\n0:00:45.095381150   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.095631144   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fake-audio-sink> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.095750204   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<fake-audio-sink> skipping transition from NULL to  NULL\r\n0:00:45.095845358   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'fake-audio-sink' changed state to 1(NULL) successfully\r\n0:00:45.095976449   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to NULL\r\n0:00:45.096068322   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 1(NULL) successfully\r\n0:00:45.096196756   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.096390918   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<volume> skipping transition from NULL to  NULL\r\n0:00:45.096485864   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 1(NULL) successfully\r\n0:00:45.096617111   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.096722265   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<converter> skipping transition from NULL to  NULL\r\n0:00:45.096816533   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 1(NULL) successfully\r\n0:00:45.096941426   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current NULL pending VOID_PENDING, desired next NULL\r\n0:00:45.097046216   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<decodedQueue> skipping transition from NULL to  NULL\r\n0:00:45.097137984   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 1(NULL) successfully\r\n0:00:45.097271158   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to NULL\r\n0:00:45.097441779   773 0x75200e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element \"appsrc\" named \"src\"\r\n0:00:45.097803281   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSrc@0x75208160> adding pad 'src'\r\n0:00:45.098013068   773 0x75200e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element \"decodebin\" named \"decoder\"\r\n0:00:45.098249260   773 0x75200e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element \"typefind\" named \"typefind\"\r\n0:00:45.098589252   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstTypeFindElement@0x7520f018> adding pad 'sink'\r\n0:00:45.098893100   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstTypeFindElement@0x7520f018> adding pad 'src'\r\n0:00:45.099235487   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad typefind:sink\r\n0:00:45.099660842   773 0x75200e00 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link sink:proxypad19 and typefind:sink\r\n0:00:45.330320195   773 0x75200e00 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked sink:proxypad19 and typefind:sink, successful\r\n0:00:45.330570085   773 0x75200e00 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:45.330828776   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstDecodeBin@0x7520d030> adding pad 'sink'\r\n0:00:45.331337358   773 0x75200e00 INFO        GST_ELEMENT_PADS gstutils.c:1633:gst_element_link_pads_full: trying to link element src:(any) to element decoder:(any)\r\n0:00:45.331501782   773 0x75200e00 INFO                GST_PADS gstutils.c:933:gst_pad_check_link: trying to link src:src and decoder:sink\r\n0:00:45.331764692   773 0x75200e00 INFO                GST_PADS gstutils.c:1447:prepare_link_maybe_ghosting: src and decoder in same bin, no need for ghost pads\r\n0:00:45.331958333   773 0x75200e00 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link src:src and decoder:sink\r\n0:00:45.332204317   773 0x75200e00 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked src:src and decoder:sink, successful\r\n0:00:45.332318429   773 0x75200e00 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:45.332401240   773 0x75200e00 INFO               GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<src:src> Received event on flushing pad. Discarding\r\n0:00:45.346606273   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:45.347201675   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current NULL pending VOID_PENDING, desired next READY\r\n0:00:45.347468961   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<fake-audio-sink> completed state change to NULL\r\n0:00:45.347675831   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking sink:proxypad1(0x1960218) and fake-audio-sink:sink(0x41947418)\r\n0:00:45.347872441   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked sink:proxypad1 and fake-audio-sink:sink\r\n0:00:45.348021760   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<audio_sink> removed child \"fake-audio-sink\"\r\n0:00:45.348277275   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<fake-audio-sink> 0x1962728 dispose\r\n0:00:45.348421595   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<fake-audio-sink> removing pad 'sink'\r\n0:00:45.348642371   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<fake-audio-sink> 0x1962728 parent class dispose\r\n0:00:45.348793826   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<fake-audio-sink> 0x1962728 finalize\r\n0:00:45.348884449   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<fake-audio-sink> 0x1962728 finalize parent\r\n0:00:45.353161901   773 0x75200e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element \"pulsesink\" named \"audio_sink-actual-sink-pulse\"\r\n0:00:45.353676576   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x75219a78> adding pad 'sink'\r\n0:00:45.354320676   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad audio_sink-actual-sink-pulse:sink\r\n0:00:45.354581138   773 0x75200e00 INFO                   pulse pulsesink.c:3238:gst_pulsesink_change_state:<audio_sink-actual-sink-pulse> new pa main loop thread\r\n0:00:45.355285653   773 0x75200e00 INFO                   pulse pulsesink.c:533:gst_pulseringbuffer_open_device:<audio_sink-actual-sink-pulse> new context with name SampleApp, pbuf=0x7521c040, pctx=0x1872dd0\r\n0:00:45.459929199   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to READY\r\n0:00:45.460165443   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.460943915   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad audio_sink-actual-sink-pulse:sink\r\n0:00:45.461171045   773 0x75200e00 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link sink:proxypad1 and audio_sink-actual-sink-pulse:sink\r\n0:00:45.461324531   773 0x75200e00 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked sink:proxypad1 and audio_sink-actual-sink-pulse:sink, successful\r\n0:00:45.461465361   773 0x75200e00 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:45.461557442   773 0x75200e00 INFO               GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<sink:proxypad1> Received event on flushing pad. Discarding\r\n0:00:45.461748896   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current READY pending VOID_PENDING, desired next READY\r\n0:00:45.461883737   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> skipping transition from READY to  READY\r\n0:00:45.461986078   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 2(READY) successfully\r\n0:00:45.462132585   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to READY\r\n0:00:45.462229666   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.462462317   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 2(READY) successfully\r\n0:00:45.462656791   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current NULL pending VOID_PENDING, desired next READY\r\n0:00:45.462809444   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to READY\r\n0:00:45.462901004   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.463067251   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 2(READY) successfully\r\n0:00:45.463231622   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current NULL pending VOID_PENDING, desired next READY\r\n0:00:45.463358858   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to READY\r\n0:00:45.463438023   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.463575989   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 2(READY) successfully\r\n0:00:45.463711454   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current NULL pending VOID_PENDING, desired next READY\r\n0:00:45.463835410   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to READY\r\n0:00:45.463911918   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.464041499   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 2(READY) successfully\r\n0:00:45.464199932   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current NULL pending VOID_PENDING, desired next READY\r\n0:00:45.464458051   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current NULL pending VOID_PENDING, desired next READY\r\n0:00:45.464573153   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to READY\r\n0:00:45.464652318   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.464793096   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 2(READY) successfully\r\n0:00:45.464920280   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to READY\r\n0:00:45.465008143   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.465145015   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 2(READY) successfully\r\n0:00:45.465275741   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current NULL pending VOID_PENDING, desired next READY\r\n0:00:45.465400581   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to READY\r\n0:00:45.465498756   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:45.465647711   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 2(READY) successfully\r\n0:00:45.465808489   773 0x75200e00 INFO              GST_STATES gstelement.c:2394:gst_element_continue_state:<audio-pipeline> committing state from NULL to READY, pending PLAYING, next PAUSED\r\n0:00:45.465923069   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed NULL to READY (PLAYING pending)\r\n0:00:45.466072076   773 0x75200e00 INFO              GST_STATES gstelement.c:2401:gst_element_continue_state:<audio-pipeline> continue state change READY to PAUSED, final PLAYING\r\n0:00:45.466429828   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.466656125   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.466993878   773 0x75200e00 INFO              GST_STATES gstbin.c:2975:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' is changing state asynchronously to PAUSED\r\n0:00:45.467224237   773 0x75200e00 INFO              GST_STATES gstbin.c:2975:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' is changing state asynchronously to PAUSED\r\n0:00:45.467373087   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.467565843   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to PAUSED\r\n0:00:45.467669903   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:45.467847191   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 3(PAUSED) successfully\r\n0:00:45.468024531   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.468232390   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to PAUSED\r\n0:00:45.468333325   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:45.468497124   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 3(PAUSED) successfully\r\n0:00:45.468623735   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.468878104   773 0x75200e00 INFO                    task gsttask.c:456:gst_task_set_lock: setting stream lock 0x17b4b0c on task 0x75221178\r\n0:00:45.469010080   773 0x75200e00 INFO                GST_PADS gstpad.c:5998:gst_pad_start_task:<decodedQueue:src> created task 0x75221178\r\n0:00:45.469735532   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to PAUSED\r\n0:00:45.469907195   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:45.470088753   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 3(PAUSED) successfully\r\n2018-03-06 03:57:23.170 [  b] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n0:00:45.741517974   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.742611700   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.743118876   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to PAUSED\r\n0:00:45.743340017   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:45.743673968   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 3(PAUSED) successfully\r\n0:00:45.744033856   773 0x75200e00 INFO              GST_STATES gstbin.c:2975:gst_bin_change_state_func:<audio-pipeline> child 'decoder' is changing state asynchronously to PAUSED\r\n0:00:45.744256039   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current READY pending VOID_PENDING, desired next PAUSED\r\n0:00:45.744588479   773 0x75200e00 INFO                 basesrc gstbasesrc.c:1343:gst_base_src_do_seek:<src> seeking: bytes segment start=0, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0, base=0, position 0, duration -1\r\n0:00:45.745152530   773 0x75200e00 INFO                    task gsttask.c:456:gst_task_set_lock: setting stream lock 0x19695ac on task 0x75221220\r\n0:00:45.745386483   773 0x75200e00 INFO                GST_PADS gstpad.c:5998:gst_pad_start_task:<src:src> created task 0x75221220\r\n0:00:45.746356149   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to PAUSED\r\n0:00:45.746702391   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:45.746990093   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'sink' in element \"src\"\r\n0:00:45.746979208   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 3(PAUSED) successfully\r\n0:00:45.747225713   773 0x748f2690 FIXME                default gstutils.c:3826:gst_pad_create_stream_id_internal:<src:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id\r\n0:00:45.747577008   773 0x748f2690 INFO                GST_PADS gstpad.c:4112:gst_pad_peer_query:<typefind:src> pad has no peer\r\n2018-03-06 03:57:23.763 [  b] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n0:00:46.678628815   773 0x748f2690 INFO               GST_EVENT gstevent.c:889:gst_event_new_segment: creating segment event bytes segment start=0, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0, base=0, position 0, duration -1\r\n0:00:46.679185054   773 0x748f2690 INFO                 basesrc gstbasesrc.c:2847:gst_base_src_loop:<src> marking pending DISCONT\r\n0:00:46.680626066   773 0x748f2690 INFO               GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event video/mpegts, systemstream=(boolean)true, packetsize=(int)188\r\n0:00:46.681014079   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad typefind:src\r\n0:00:46.681168242   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad typefind:sink\r\n2018-03-06 03:57:24.116 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:24.116 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:00:46.681730314   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link typefind:src and decodepad8:proxypad20\r\n0:00:46.682037026   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked typefind:src and decodepad8:proxypad20, successful\r\n0:00:46.682579567   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.695824452   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking typefind:src(0x1969aa0) and decodepad8:proxypad20(0x1960bb8)\r\n0:00:46.696330327   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked typefind:src and decodepad8:proxypad20\r\n0:00:46.696589488   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link typefind:src and decodepad8:proxypad20\r\n0:00:46.696722975   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked typefind:src and decodepad8:proxypad20, successful\r\n0:00:46.696818077   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.697129633   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking typefind:src(0x1969aa0) and decodepad8:proxypad20(0x1960bb8)\r\n0:00:46.697331244   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked typefind:src and decodepad8:proxypad20\r\n0:00:46.697482387   773 0x748f2690 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element \"tsdemux\"\r\n0:00:46.697866962   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<MpegTSBase@0x6d906770> adding pad 'sink'\r\n0:00:46.699424951   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link typefind:src and tsdemux1:sink\r\n0:00:46.699711143   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked typefind:src and tsdemux1:sink, successful\r\n0:00:46.699800308   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.700021657   773 0x748f2690 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to READY\r\n0:00:46.700151915   773 0x748f2690 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:46.700569823   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'video_%01x_%05x' in element \"tsdemux1\"\r\n0:00:46.700757684   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'audio_%01x_%05x' in element \"tsdemux1\"\r\n0:00:46.700865130   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'subpicture_%01x_%05x' in element \"tsdemux1\"\r\n0:00:46.700973773   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:913:gst_element_get_static_pad: no such pad 'private_%01x_%05x' in element \"tsdemux1\"\r\n0:00:46.701619541   773 0x748f2690 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to PAUSED\r\n0:00:46.701826412   773 0x748f2690 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:46.702459732   773 0x748f2690 INFO                typefind gsttypefindelement.c:180:gst_type_find_element_have_type:<typefind> found caps video/mpegts, systemstream=(boolean)true, packetsize=(int)188, probability=100\r\n0:00:46.703240758   773 0x748f2690 INFO        mpegtspacketizer mpegtspacketizer.c:769:mpegts_try_discover_packet_size: have packetsize detected: 188 bytes\r\n0:00:46.704103813   773 0x748f2690 INFO              mpegtsbase mpegtsbase.c:950:mpegts_base_apply_pat:<tsdemux1> PAT\r\n0:00:46.705212488   773 0x748f2690 INFO               GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event audio/mpeg, mpegversion=(int)2, stream-format=(string)adts\r\n0:00:46.705572429   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<tsdemux1> adding pad 'audio_0_0100'\r\n0:00:46.705803205   773 0x748f2690 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element \"multiqueue\"\r\n0:00:46.705976691   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad tsdemux1:sink\r\n0:00:46.706463921   773 0x748f2690 INFO              GST_STATES gstelement.c:2394:gst_element_continue_state:<multiqueue1> committing state from NULL to READY, pending PAUSED, next PAUSED\r\n0:00:46.706588814   773 0x748f2690 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed NULL to READY (PAUSED pending)\r\n0:00:46.706695739   773 0x748f2690 INFO              GST_STATES gstelement.c:2401:gst_element_continue_state:<multiqueue1> continue state change READY to PAUSED, final PAUSED\r\n0:00:46.706790581   773 0x748f2690 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to PAUSED\r\n0:00:46.706851153   773 0x748f2690 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:46.707377288   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link tsdemux1:audio_0_0100 and decodepad9:proxypad21\r\n0:00:46.707513118   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked tsdemux1:audio_0_0100 and decodepad9:proxypad21, successful\r\n0:00:46.707619158   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.709602606   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking tsdemux1:audio_0_0100(0x17b4820) and decodepad9:proxypad21(0x1960638)\r\n0:00:46.709893434   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked tsdemux1:audio_0_0100 and decodepad9:proxypad21\r\n0:00:46.710575034   773 0x748f2690 INFO                    task gsttask.c:456:gst_task_set_lock: setting stream lock 0x1969d8c on task 0x752216b8\r\n0:00:46.710899142   773 0x748f2690 INFO                GST_PADS gstpad.c:5998:gst_pad_start_task:<'':src_0> created task 0x752216b8\r\n0:00:46.711167574   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<multiqueue1> adding pad 'src_0'\r\n0:00:46.711303092   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<multiqueue1> adding pad 'sink_0'\r\n0:00:46.711433350   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link tsdemux1:audio_0_0100 and multiqueue1:sink_0\r\n0:00:46.711548973   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked tsdemux1:audio_0_0100 and multiqueue1:sink_0, successful\r\n0:00:46.711641367   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.711995943   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link multiqueue1:src_0 and decodepad9:proxypad21\r\n0:00:46.712151669   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked multiqueue1:src_0 and decodepad9:proxypad21, successful\r\n0:00:46.712256562   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.712510724   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking multiqueue1:src_0(0x1969d40) and decodepad9:proxypad21(0x1960638)\r\n0:00:46.712702699   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked multiqueue1:src_0 and decodepad9:proxypad21\r\n0:00:46.712880925   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link multiqueue1:src_0 and decodepad9:proxypad21\r\n0:00:46.712992381   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked multiqueue1:src_0 and decodepad9:proxypad21, successful\r\n0:00:46.713100451   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.713943403   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking multiqueue1:src_0(0x1969d40) and decodepad9:proxypad21(0x1960638)\r\n0:00:46.714236886   773 0x748f2690 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked multiqueue1:src_0 and decodepad9:proxypad21\r\n0:00:46.714417039   773 0x748f2690 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element \"aacparse\"\r\n0:00:46.714709272   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseParse@0x6d922eb0> adding pad 'sink'\r\n0:00:46.714995517   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseParse@0x6d922eb0> adding pad 'src'\r\n0:00:46.715539412   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link multiqueue1:src_0 and aacparse1:sink\r\n0:00:46.715708939   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked multiqueue1:src_0 and aacparse1:sink, successful\r\n0:00:46.715820552   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.716092213   773 0x748f2690 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to READY\r\n0:00:46.716194450   773 0x748f2690 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:46.716533714   773 0x748f2690 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad aacparse1:src\r\n0:00:46.716722669   773 0x748f2690 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link aacparse1:src and decodepad9:proxypad21\r\n0:00:46.716818813   773 0x748f2690 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked aacparse1:src and decodepad9:proxypad21, successful\r\n0:00:46.716893342   773 0x748f2690 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.716962560   773 0x748f2690 INFO               GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<aacparse1:src> Received event on flushing pad. Discarding\r\n0:00:46.717383488   773 0x748f2690 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to PAUSED\r\n0:00:46.717484372   773 0x748f2690 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:46.717789730   773 0x748f2690 INFO               baseparse gstbaseparse.c:3932:gst_base_parse_set_passthrough:<aacparse1> passthrough: no\r\n0:00:46.718897468   773 0x748f2690 INFO               GST_EVENT gstevent.c:889:gst_event_new_segment: creating segment event time segment start=0:00:00.050000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.050000000, base=0:00:00.000000000, position 0:00:00.050000000, duration 99:99:99.999999999\r\n0:00:46.719960936   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.925711111\r\n0:00:46.720440613   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.925722222\r\n0:00:46.727170267   773 0x6d934030 INFO               baseparse gstbaseparse.c:3932:gst_base_parse_set_passthrough:<aacparse1> passthrough: no\r\n0:00:46.727445053   773 0x6d934030 INFO               baseparse gstbaseparse.c:4767:gst_base_parse_set_upstream_tags:<aacparse1> upstream tags: taglist, audio-codec=(string)\"MPEG-2\\ AAC\";\r\n0:00:46.727750411   773 0x6d934030 INFO                aacparse gstaacparse.c:900:gst_aac_parse_detect_stream: ADTS ID: 0, framesize: 172\r\n0:00:46.727746349   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.925711111\r\n0:00:46.727887960   773 0x6d934030 INFO               baseparse gstbaseparse.c:3912:gst_base_parse_set_syncable:<aacparse1> syncable: yes\r\n0:00:46.728575446   773 0x6d934030 INFO                GST_PADS gstpad.c:4112:gst_pad_peer_query:<'':decodepad9> pad has no peer\r\n0:00:46.728805441   773 0x6d934030 INFO               GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event audio/mpeg, framed=(boolean)true, mpegversion=(int)4, level=(string)1, base-profile=(string)lc, profile=(string)lc, rate=(int)22050, channels=(int)1, stream-format=(string)adts\r\n0:00:46.729302046   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking aacparse1:src(0x41947958) and decodepad9:proxypad21(0x1960638)\r\n0:00:46.729522458   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked aacparse1:src and decodepad9:proxypad21\r\n0:00:46.729706360   773 0x6d934030 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link aacparse1:src and decodepad9:proxypad21\r\n0:00:46.729819223   773 0x6d934030 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked aacparse1:src and decodepad9:proxypad21, successful\r\n0:00:46.729953960   773 0x6d934030 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.738782945   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking aacparse1:src(0x41947958) and decodepad9:proxypad21(0x1960638)\r\n0:00:46.739486108   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked aacparse1:src and decodepad9:proxypad21\r\n0:00:46.739744332   773 0x6d934030 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link aacparse1:src and decodepad9:proxypad21\r\n0:00:46.739967869   773 0x6d934030 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked aacparse1:src and decodepad9:proxypad21, successful\r\n0:00:46.740254009   773 0x6d934030 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.740803581   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking aacparse1:src(0x41947958) and decodepad9:proxypad21(0x1960638)\r\n0:00:46.742415318   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked aacparse1:src and decodepad9:proxypad21\r\n0:00:46.742832549   773 0x6d934030 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link aacparse1:src and decodepad9:proxypad21\r\n0:00:46.743028379   773 0x6d934030 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked aacparse1:src and decodepad9:proxypad21, successful\r\n0:00:46.743174417   773 0x6d934030 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.743811436   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking aacparse1:src(0x41947958) and decodepad9:proxypad21(0x1960638)\r\n0:00:46.744130752   773 0x6d934030 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked aacparse1:src and decodepad9:proxypad21\r\n0:00:46.744366737   773 0x6d934030 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element \"avdec_aac\"\r\n0:00:46.744769593   773 0x6d934030 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstAudioDecoder@0x73e0c258> adding pad 'sink'\r\n0:00:46.745072451   773 0x6d934030 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstAudioDecoder@0x73e0c258> adding pad 'src'\r\n0:00:46.745823425   773 0x6d934030 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link aacparse1:src and avdec_aac1:sink\r\n0:00:46.746065868   773 0x6d934030 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked aacparse1:src and avdec_aac1:sink, successful\r\n0:00:46.746195605   773 0x6d934030 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.746863925   773 0x6d934030 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to READY\r\n0:00:46.747053609   773 0x6d934030 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed NULL to READY (VOID_PENDING pending)\r\n0:00:46.747508235   773 0x6d934030 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad avdec_aac1:src\r\n0:00:46.747823697   773 0x6d934030 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link avdec_aac1:src and decodepad9:proxypad21\r\n0:00:46.747999370   773 0x6d934030 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked avdec_aac1:src and decodepad9:proxypad21, successful\r\n0:00:46.748117233   773 0x6d934030 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:46.748210512   773 0x6d934030 INFO               GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<avdec_aac1:src> Received event on flushing pad. Discarding\r\n0:00:46.748819926   773 0x6d934030 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to PAUSED\r\n0:00:46.749023776   773 0x6d934030 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:46.755314949   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-2\\ AAC\";\r\n0:00:46.756118891   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\";\r\n0:00:46.757583445   773 0x6d934030 INFO               GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1\r\n0:00:46.758340773   773 0x6d934030 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<decoder> adding pad 'src_0'\r\n0:00:47.033806420   773 0x75200e00 INFO        GST_ELEMENT_PADS gstutils.c:1633:gst_element_link_pads_full: trying to link element decoder:(any) to element decodedQueue:(any)\r\n0:00:47.034225995   773 0x75200e00 INFO                GST_PADS gstutils.c:933:gst_pad_check_link: trying to link decoder:src_0 and decodedQueue:sink\r\n2018-03-06 03:57:24.470 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:24.471 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:00:47.071952929   773 0x75200e00 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ];\r\n0:00:47.072779266   773 0x75200e00 INFO                GST_PADS gstutils.c:1447:prepare_link_maybe_ghosting: decoder and decodedQueue in same bin, no need for ghost pads\r\n0:00:47.073083114   773 0x75200e00 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link decoder:src_0 and decodedQueue:sink\r\n0:00:47.076687051   773 0x75200e00 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 32 ];\r\n0:00:47.077378547   773 0x75200e00 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked decoder:src_0 and decodedQueue:sink, successful\r\n0:00:47.077536096   773 0x75200e00 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:00:47.086449194   773 0x6d934030 INFO               decodebin gstdecodebin2.c:4691:gst_decode_bin_expose:<decoder:src_0> added new decoded pad\r\n0:00:47.086775802   773 0x6d934030 INFO              GST_STATES gstbin.c:3441:bin_handle_async_done:<decoder> committing state from READY to PAUSED, old pending PAUSED\r\n0:00:47.086927101   773 0x6d934030 INFO              GST_STATES gstbin.c:3461:bin_handle_async_done:<decoder> completed state change, pending VOID\r\n0:00:47.087005224   773 0x6d934030 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:47.087450475   773 0x6d934030 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.088201450   773 0x6d934030 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.088881852   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.089325124   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.093523059   773 0x748f29b0 INFO           basetransform gstbasetransform.c:1370:gst_base_transform_setcaps:<converter> reuse caps\r\n0:00:47.093828990   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.094099714   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.094304241   773 0x748f29b0 INFO         audio-converter audio-converter.c:941:gst_audio_converter_new: unitsizes: 4 -> 4\r\n0:00:47.094384083   773 0x748f29b0 INFO         audio-converter audio-converter.c:599:chain_unpack: unpack format F32LE to F32LE\r\n0:00:47.094557830   773 0x748f29b0 INFO         audio-converter audio-converter.c:656:chain_mix: mix format F32LE, passthrough 1, in_channels 1, out_channels 1\r\n0:00:47.094671577   773 0x748f29b0 INFO         audio-converter audio-converter.c:743:chain_quantize: depth in 32, out 32\r\n0:00:47.094750586   773 0x748f29b0 INFO         audio-converter audio-converter.c:755:chain_quantize: using no dither and noise shaping\r\n0:00:47.094811939   773 0x748f29b0 INFO         audio-converter audio-converter.c:790:chain_pack: pack format F32LE to F32LE\r\n0:00:47.094884021   773 0x748f29b0 INFO         audio-converter audio-converter.c:965:gst_audio_converter_new: same formats, no resampler and passthrough mixing -> passthrough\r\n0:00:47.094965217   773 0x748f29b0 INFO               GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1\r\n0:00:47.095670932   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.098437854   773 0x748f29b0 INFO           basetransform gstbasetransform.c:1370:gst_base_transform_setcaps:<volume> reuse caps\r\n0:00:47.098673370   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.098893470   773 0x748f29b0 INFO               GST_EVENT gstevent.c:808:gst_event_new_caps: creating caps event audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1\r\n0:00:47.099308878   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.101874138   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.104434241   773 0x748f29b0 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)F32LE, layout=(string)interleaved, rate=(int)22050, channels=(int)1;\r\n0:00:47.106894555   773 0x748f29b0 INFO                   pulse pulsesink.c:968:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> tlength:   17600\r\n0:00:47.107099708   773 0x748f29b0 INFO                   pulse pulsesink.c:969:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> maxlength: -1\r\n0:00:47.107193456   773 0x748f29b0 INFO                   pulse pulsesink.c:970:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> prebuf:    0\r\n0:00:47.107254131   773 0x748f29b0 INFO                   pulse pulsesink.c:971:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> minreq:    880\r\n0:00:47.112591209   773 0x748f29b0 INFO                   pulse pulsesink.c:1021:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> negotiated to: pcm, format.sample_format = \"\\\"float32le\\\"\"  format.channels = \"1\"  format.rate = \"22050\"  format.channel_map = \"\\\"mono\\\"\"\r\n0:00:47.112821569   773 0x748f29b0 INFO                   pulse pulsesink.c:1034:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> tlength:   9680 (wanted: 17600)\r\n0:00:47.112934848   773 0x748f29b0 INFO                   pulse pulsesink.c:1035:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> maxlength: 4194304\r\n0:00:47.113030575   773 0x748f29b0 INFO                   pulse pulsesink.c:1036:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> prebuf:    0\r\n0:00:47.113098855   773 0x748f29b0 INFO                   pulse pulsesink.c:1038:gst_pulseringbuffer_acquire:<audio_sink-actual-sink-pulse> minreq:    880 (wanted 880)\r\n0:00:47.113194687   773 0x748f29b0 INFO              ringbuffer gstaudioringbuffer.c:581:gst_audio_ring_buffer_acquire:<pulseringbuffer7> Allocating an array for 11 timestamps\r\n0:00:47.114880173   773 0x748f29b0 INFO              GST_STATES gstbin.c:3441:bin_handle_async_done:<audio_sink> committing state from READY to PAUSED, old pending PAUSED\r\n0:00:47.115108658   773 0x748f29b0 INFO              GST_STATES gstbin.c:3461:bin_handle_async_done:<audio_sink> completed state change, pending VOID\r\n0:00:47.115202093   773 0x748f29b0 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed READY to PAUSED (VOID_PENDING pending)\r\n0:00:47.115424068   773 0x748f29b0 INFO              GST_STATES gstbin.c:3441:bin_handle_async_done:<audio-pipeline> committing state from READY to PAUSED, old pending PLAYING\r\n0:00:47.115531514   773 0x748f29b0 INFO              GST_STATES gstbin.c:3470:bin_handle_async_done:<audio-pipeline> continue state change, pending PLAYING\r\n0:00:47.115606200   773 0x748f29b0 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed READY to PAUSED (PLAYING pending)\r\n0:00:47.116170719   773 0x6d933d20 INFO              GST_STATES gstbin.c:3267:gst_bin_continue_func:<audio-pipeline> continue state change PAUSED to PLAYING, final PLAYING\r\n0:00:47.119033838   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)30663, maximum-bitrate=(uint)30663, bitrate=(uint)29870;\r\n0:00:47.118188594   773 0x6d933d20 INFO               GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000\r\n0:00:47.120482245   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)30663, maximum-bitrate=(uint)43583, bitrate=(uint)31117;\r\n0:00:47.120835311   773 0x6d933d20 INFO                     bin gstbin.c:2798:gst_bin_do_latency_func:<audio-pipeline> configured latency of 0:00:00.000000000\r\n0:00:47.121191970   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.121518214   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.121546859   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)28768, maximum-bitrate=(uint)43583, bitrate=(uint)30921;\r\n0:00:47.121846644   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to PLAYING\r\n0:00:47.122095702   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.123410987   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 4(PLAYING) successfully\r\n0:00:47.123736554   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)25667, maximum-bitrate=(uint)43583, bitrate=(uint)30517;\r\n0:00:47.125682920   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to PLAYING\r\n0:00:47.126019996   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.126462852   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 4(PLAYING) successfully\r\n0:00:47.126790189   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.127074558   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to PLAYING\r\n0:00:47.132022842   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.132464447   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 4(PLAYING) successfully\r\n0:00:47.132759806   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.132996207   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to PLAYING\r\n0:00:47.133158964   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.133374481   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 4(PLAYING) successfully\r\n0:00:47.133607445   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.133786816   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to PLAYING\r\n0:00:47.133929105   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.134127955   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 4(PLAYING) successfully\r\n0:00:47.134964656   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.135343242   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<avdec_aac1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.135528707   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to PLAYING\r\n0:00:47.135669225   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.135883544   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'avdec_aac1' changed state to 4(PLAYING) successfully\r\n0:00:47.136099008   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<aacparse1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.136437178   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to PLAYING\r\n0:00:47.136613477   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.136849722   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'aacparse1' changed state to 4(PLAYING) successfully\r\n0:00:47.137071436   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<multiqueue1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.137271640   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to PLAYING\r\n0:00:47.137396377   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.137569238   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'multiqueue1' changed state to 4(PLAYING) successfully\r\n0:00:47.137744078   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<tsdemux1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.138380628   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to PLAYING\r\n0:00:47.138600519   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.138853379   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'tsdemux1' changed state to 4(PLAYING) successfully\r\n0:00:47.139625654   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.140511938   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to PLAYING\r\n0:00:47.140752454   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.141047448   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 4(PLAYING) successfully\r\n0:00:47.141303120   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to PLAYING\r\n0:00:47.141496710   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.141724518   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 4(PLAYING) successfully\r\n0:00:47.141946857   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.142168727   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to PLAYING\r\n0:00:47.142320964   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.142676373   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 4(PLAYING) successfully\r\n0:00:47.144894244   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to PLAYING\r\n0:00:47.145201269   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.142942305   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)43583, bitrate=(uint)28615;\r\n0:00:47.162430186   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)43583, bitrate=(uint)28033;\r\n0:00:47.165971051   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)43583, bitrate=(uint)28610;\r\n0:00:47.180773768   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)46167, bitrate=(uint)29469;\r\n0:00:47.279488096   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)46167, bitrate=(uint)30079;\r\n0:00:47.345435909   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:47.345909441   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:47.346007824   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:47.346564323   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:01.207422222\r\n0:00:47.346730830   773 0x748f2690 WARN                 tsdemux tsdemux.c:2255:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 0, stream 12\r\n2018-03-06 03:57:24.828 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:24.829 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:00:47.394192148   773 0x75200e00 INFO               GST_EVENT gstevent.c:1268:gst_event_new_seek: creating seek rate 1.000000, format TIME, flags 5, start_type 1, start 0:00:05.000000000, stop_type 1, stop 99:99:99.999999999\r\n0:00:47.395615452   773 0x75200e00 INFO                 default gstsegment.c:372:gst_segment_do_seek: segment updated: bytes segment start=5000000000, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x01, time=5000000000, base=0, position 5000000000, duration -1\r\n0:00:47.395976799   773 0x75200e00 INFO                 default gstsegment.c:372:gst_segment_do_seek: segment updated: time segment start=0:00:05.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x01, time=0:00:05.000000000, base=0:00:00.000000000, position 0:00:05.000000000, duration 99:99:99.999999999\r\n0:00:47.396207419   773 0x75200e00 INFO               GST_EVENT gstevent.c:1275:gst_event_new_seek: creating seek rate 1.000000, format bytes, flags 5, start_type 1, start 49255, stop_type 0, stop -1\r\n0:00:47.400176869   773 0x748f29b0 INFO                    task gsttask.c:318:gst_task_func:<decodedQueue:src> Task going to paused\r\n0:00:47.400416864   773 0x748f2690 INFO                 basesrc gstbasesrc.c:2860:gst_base_src_loop:<src> pausing after gst_pad_push() = flushing\r\n0:00:47.400553059   773 0x748f2690 INFO                    task gsttask.c:318:gst_task_func:<src:src> Task going to paused\r\n0:00:47.400640297   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed PAUSED to PAUSED (PAUSED pending)\r\n0:00:47.400757065   773 0x6d934030 INFO                    task gsttask.c:318:gst_task_func:<multiqueue1:src_0> Task going to paused\r\n0:00:47.400845501   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PAUSED to PAUSED (PAUSED pending)\r\n0:00:47.401330282   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PAUSED to PAUSED (PAUSED pending)\r\n0:00:47.401656005   773 0x75200e00 INFO                 default gstsegment.c:372:gst_segment_do_seek: segment updated: bytes segment start=49255, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x01, time=49255, base=0, position 49255, duration -1\r\n0:00:47.401857928   773 0x75200e00 INFO                 basesrc gstbasesrc.c:1343:gst_base_src_do_seek:<src> seeking: bytes segment start=49255, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x01, time=49255, base=0, position 49255, duration -1\r\n0:00:47.402193390   773 0x75200e00 INFO               GST_EVENT gstevent.c:550:gst_event_new_flush_stop: creating flush stop 1\r\n0:00:47.403651849   773 0x748f29b0 INFO                    task gsttask.c:320:gst_task_func:<decodedQueue:src> Task resume from paused\r\n0:00:47.404158818   773 0x6d934030 INFO                    task gsttask.c:320:gst_task_func:<multiqueue1:src_0> Task resume from paused\r\n0:00:47.414341109   773 0x748f2690 INFO                    task gsttask.c:320:gst_task_func:<src:src> Task resume from paused\r\n0:00:47.417077303   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:47.416880224   773 0x748f2690 INFO               GST_EVENT gstevent.c:889:gst_event_new_segment: creating segment event bytes segment start=49255, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x01, time=49255, base=0, position 49255, duration -1\r\n0:00:47.417380057   773 0x75200e00 INFO              GST_STATES gstelement.c:2137:gst_element_get_state_func:<audio-pipeline> waiting for element to commit state\r\n0:00:47.417476826   773 0x75200e00 INFO              GST_STATES gstelement.c:2151:gst_element_get_state_func:<audio-pipeline> timed out\r\n0:00:47.417634271   773 0x748f2690 INFO                 basesrc gstbasesrc.c:2847:gst_base_src_loop:<src> marking pending DISCONT\r\n2018-03-06 03:57:24.853 [  7] I MediaPlayer:handleGetOffset:reason=getElementGetStateUnsuccessful,stateChangeReturn=ASYNC\r\n0:00:47.418572949   773 0x748f2690 INFO               GST_EVENT gstevent.c:889:gst_event_new_segment: creating segment event time segment start=0:00:12.913833333, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:12.913833333, base=0:00:00.000000000, position 0:00:12.913833333, duration 99:99:99.999999999\r\n0:00:47.419773237   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:47.420435463   773 0x75200e00 INFO              GST_STATES gstelement.c:2137:gst_element_get_state_func:<audio-pipeline> waiting for element to commit state\r\n0:00:47.420834778   773 0x75200e00 INFO              GST_STATES gstelement.c:2151:gst_element_get_state_func:<audio-pipeline> timed out\r\n0:00:47.421110085   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.925722222\r\n2018-03-06 03:57:24.856 [  7] I MediaPlayer:handleGetOffset:reason=getElementGetStateUnsuccessful,stateChangeReturn=ASYNC\r\n##############################################################################\r\n#     RenderPlayerInfoCard                                                    \r\n#-----------------------------------------------------------------------------\r\n# AudioItemId         : amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\r\n# Audio state         : PLAYING\r\n# Offset milliseconds : 0\r\n##############################################################################\r\n{\"content\":{\"header\":\"By Marcus Sakey\",\"provider\":{\"name\":\"Audible\",\"logo\":{\"sources\":[{\"url\":\"https://s3.amazonaws.com/music-provider-logos/Audible.svg\"}]}},\"art\":{\"sources\":[{\"url\":\"https://cds.audible.com/download/image?asin=B071KH1SDF&image_size=1280\"}]},\"mediaLengthInMilliseconds\":639000000,\"title\":\"Chapter 43\",\"titleSubtext1\":\"Afterlife\",\"headerSubtext1\":\"Narrated by Finty Williams\"},\"audioItemId\":\"amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\",\"controls\":[{\"selected\":false,\"name\":\"PLAY_PAUSE\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"PREVIOUS\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_BACKWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_FORWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"NEXT\",\"enabled\":true,\"type\":\"BUTTON\"}]}\r\n##############################################################################\r\n\r\n0:00:47.423677949   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.925711111\r\n0:00:47.424463922   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:47.424627148   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:47.424828081   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:47.425068076   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:01.300333333\r\n0:00:47.425299270   773 0x748f2690 WARN                 tsdemux tsdemux.c:2255:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 0, stream 12\r\n0:00:47.426655492   773 0x6d934030 INFO                aacparse gstaacparse.c:900:gst_aac_parse_detect_stream: ADTS ID: 0, framesize: 171\r\n0:00:47.426937934   773 0x6d934030 INFO               baseparse gstbaseparse.c:3912:gst_base_parse_set_syncable:<aacparse1> syncable: yes\r\n0:00:47.431472580   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)46167, bitrate=(uint)29280;\r\n0:00:47.435523799   773 0x748f29b0 INFO              GST_STATES gstbin.c:3441:bin_handle_async_done:<audio_sink> committing state from PAUSED to PAUSED, old pending PLAYING\r\n0:00:47.436916062   773 0x748f29b0 INFO              GST_STATES gstbin.c:3461:bin_handle_async_done:<audio_sink> completed state change, pending VOID\r\n0:00:47.437333033   773 0x748f29b0 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PAUSED to PAUSED (VOID_PENDING pending)\r\n0:00:47.437950572   773 0x748f29b0 INFO              GST_STATES gstbin.c:3441:bin_handle_async_done:<audio-pipeline> committing state from PAUSED to PAUSED, old pending PLAYING\r\n0:00:47.438411917   773 0x748f29b0 INFO              GST_STATES gstbin.c:3470:bin_handle_async_done:<audio-pipeline> continue state change, pending PLAYING\r\n0:00:47.438771389   773 0x748f29b0 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PAUSED to PAUSED (PLAYING pending)\r\n0:00:47.442196423   773 0x6d933d20 INFO              GST_STATES gstbin.c:3267:gst_bin_continue_func:<audio-pipeline> continue state change PAUSED to PLAYING, final PLAYING\r\n0:00:47.442345795   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)46167, bitrate=(uint)29881;\r\n0:00:47.443612800   773 0x6d933d20 INFO               GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000\r\n0:00:47.444730589   773 0x6d933d20 INFO                     bin gstbin.c:2798:gst_bin_do_latency_func:<audio-pipeline> configured latency of 0:00:00.000000000\r\n0:00:47.445213913   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.445546458   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:47.445812807   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to PLAYING\r\n0:00:47.445965356   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.446199257   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 4(PLAYING) successfully\r\n0:00:47.447017261   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to PLAYING\r\n0:00:47.447226267   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.447481158   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 4(PLAYING) successfully\r\n0:00:47.447775527   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.448380827   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<volume> skipping transition from PLAYING to  PLAYING\r\n0:00:47.448826651   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 4(PLAYING) successfully\r\n0:00:47.449329662   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.449530543   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<converter> skipping transition from PLAYING to  PLAYING\r\n0:00:47.449635385   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 4(PLAYING) successfully\r\n0:00:47.449805433   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.449919181   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<decodedQueue> skipping transition from PLAYING to  PLAYING\r\n0:00:47.450021470   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 4(PLAYING) successfully\r\n0:00:47.450189644   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.450488544   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<avdec_aac1> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.451014106   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<avdec_aac1> skipping transition from PLAYING to  PLAYING\r\n0:00:47.452580949   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'avdec_aac1' changed state to 4(PLAYING) successfully\r\n0:00:47.453303539   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<aacparse1> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.453581449   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<aacparse1> skipping transition from PLAYING to  PLAYING\r\n0:00:47.453748061   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'aacparse1' changed state to 4(PLAYING) successfully\r\n0:00:47.454003993   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<multiqueue1> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.454168833   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<multiqueue1> skipping transition from PLAYING to  PLAYING\r\n0:00:47.626926924   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'multiqueue1' changed state to 4(PLAYING) successfully\r\n0:00:47.627253793   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<tsdemux1> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.627403634   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<tsdemux1> skipping transition from PLAYING to  PLAYING\r\n0:00:47.627511809   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'tsdemux1' changed state to 4(PLAYING) successfully\r\n0:00:47.627654879   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.627801803   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<typefind> skipping transition from PLAYING to  PLAYING\r\n0:00:47.627954405   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 4(PLAYING) successfully\r\n0:00:47.628171848   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to PLAYING\r\n0:00:47.628391428   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 4(PLAYING) successfully\r\n0:00:47.628655485   773 0x6d933d20 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current PLAYING pending VOID_PENDING, desired next PLAYING\r\n0:00:47.628887720   773 0x6d933d20 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<src> skipping transition from PLAYING to  PLAYING\r\n0:00:47.629063654   773 0x6d933d20 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 4(PLAYING) successfully\r\n0:00:47.629301670   773 0x6d933d20 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to PLAYING\r\n0:00:47.629518802   773 0x6d933d20 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:47.456087596   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)46167, bitrate=(uint)30615;\r\n0:00:47.674147578   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.879277777\r\n2018-03-06 03:57:25.169 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:25.169 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:25.483 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:25.483 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:25.787 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:25.787 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:26.098 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:26.099 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:26.355 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:26.355 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:26.668 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:26.668 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:26.960 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:26.960 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:27.200 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:27.200 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:27.441 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:27.441 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:27.751 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:27.751 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:00:50.352523954   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\nt2018-03-06 03:57:28.095 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:28.095 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n\r\n0:00:50.832735688   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n############################\r\n#       Listening...       #\r\n############################\r\n\r\n2018-03-06 03:57:28.270 [  2] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=d278ffa0-2651-4ee3-86e2-bf9f38dd9b53,newValue=bc6b615f-bc36-4964-8940-622f873c287c\r\n0:00:50.835581320   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:50.835880325   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.836057354   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.837892637   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to PAUSED\r\n0:00:50.838075968   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.838324505   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 3(PAUSED) successfully\r\n0:00:50.838483565   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to PAUSED\r\n0:00:50.838562731   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.838695697   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 3(PAUSED) successfully\r\n0:00:50.838830174   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.838926840   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to PAUSED\r\n0:00:50.839005692   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.839128711   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 3(PAUSED) successfully\r\n0:00:50.839246626   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.839334229   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to PAUSED\r\n0:00:50.839396259   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.839489591   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 3(PAUSED) successfully\r\n0:00:50.839590735   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.839670682   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to PAUSED\r\n0:00:50.839730837   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.839825784   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 3(PAUSED) successfully\r\n0:00:50.839921095   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.840073644   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<avdec_aac1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.840153799   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to PAUSED\r\n0:00:50.840214580   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.840308693   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'avdec_aac1' changed state to 3(PAUSED) successfully\r\n0:00:50.840399368   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<aacparse1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.840481867   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to PAUSED\r\n0:00:50.840549887   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.840669364   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'aacparse1' changed state to 3(PAUSED) successfully\r\n0:00:50.840795352   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<multiqueue1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.840907381   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to PAUSED\r\n0:00:50.840985661   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.841101597   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'multiqueue1' changed state to 3(PAUSED) successfully\r\n0:00:50.841203783   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<tsdemux1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.841286021   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to PAUSED\r\n0:00:50.841360603   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.841456643   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'tsdemux1' changed state to 3(PAUSED) successfully\r\n0:00:50.841544506   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.841624401   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to PAUSED\r\n0:00:50.841682265   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.841772992   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 3(PAUSED) successfully\r\n0:00:50.841867782   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to PAUSED\r\n0:00:50.841934865   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.842042467   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 3(PAUSED) successfully\r\n0:00:50.842145538   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:00:50.842246422   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to PAUSED\r\n0:00:50.842311942   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.842411628   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 3(PAUSED) successfully\r\n0:00:50.842721988   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to PAUSED\r\n0:00:50.842800736   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:00:50.843567026   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:50.844439877   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:50.844949036   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n##############################################################################\r\n#     RenderPlayerInfoCard                                                    \r\n#-----------------------------------------------------------------------------\r\n# AudioItemId         : amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\r\n# Audio state         : PAUSED\r\n# Offset milliseconds : 63796\r\n##############################################################################\r\n{\"content\":{\"header\":\"By Marcus Sakey\",\"provider\":{\"name\":\"Audible\",\"logo\":{\"sources\":[{\"url\":\"https://s3.amazonaws.com/music-provider-logos/Audible.svg\"}]}},\"art\":{\"sources\":[{\"url\":\"https://cds.audible.com/download/image?asin=B071KH1SDF&image_size=1280\"}]},\"mediaLengthInMilliseconds\":639000000,\"title\":\"Chapter 43\",\"titleSubtext1\":\"Afterlife\",\"headerSubtext1\":\"Narrated by Finty Williams\"},\"audioItemId\":\"amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\",\"controls\":[{\"selected\":false,\"name\":\"PLAY_PAUSE\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"PREVIOUS\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_BACKWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_FORWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"NEXT\",\"enabled\":true,\"type\":\"BUTTON\"}]}\r\n##############################################################################\r\n\r\n2018-03-06 03:57:28.370 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:28.370 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:28.704 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:28.704 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:28.971 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:28.971 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:29.237 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:29.237 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:29.526 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:29.526 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:29.843 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:29.843 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\nt2018-03-06 03:57:30.152 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:30.153 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:30.433 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:30.433 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n\r\n###########################\r\n#       Thinking...       #\r\n###########################\r\n\r\n2018-03-06 03:57:30.636 [  6] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:30.764 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:30.764 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:30.952 [  3] I DirectiveSequencer:onDirective:directive={\"namespace\\:\"SpeechRecognizer\"\\,name\\:\"StopCapture\"\\,messageId\\:\"03751bdc-16ec-4075-b685-bf9d07cc7015\"\\,dialogRequestId\\:\"\"}\r\n2018-03-06 03:57:30.953 [  4] I DirectiveRouter:preHandleDirective:messageId=03751bdc-16ec-4075-b685-bf9d07cc7015,action=calling\r\n2018-03-06 03:57:30.953 [  5] I DirectiveRouter:handleDirective:messageId=03751bdc-16ec-4075-b685-bf9d07cc7015,action=calling\r\n2018-03-06 03:57:30.954 [  2] W Logger:debugLogLevelSpecifiedWhenDebugLogsCompiledOut:level=DEBUG9:\r\n\r\nWARNING: By default DEBUG logs are compiled out of RELEASE builds.\r\nRebuild with the cmake parameter -DCMAKE_BUILD_TYPE=DEBUG to enable debug logs.\r\n\r\n2018-03-06 03:57:30.954 [  2] E AudioInputProcessor:executeStopCaptureFailed:reason=invalidState,expectedState=RECOGNIZING,state=BUSY\r\n2018-03-06 03:57:31.049 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:31.050 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n########################################\r\n#       Alexa is currently idle!       #\r\n########################################\r\n\r\n0:00:53.720313947   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:53.721583826   773 0x75200e00 INFO               GST_EVENT gstevent.c:1382:gst_event_new_latency: creating latency event 0:00:00.000000000\r\n0:00:53.722536106   773 0x75200e00 INFO                     bin gstbin.c:2798:gst_bin_do_latency_func:<audio-pipeline> configured latency of 0:00:00.000000000\r\n0:00:53.723218753   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.723718226   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.724510663   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to PLAYING\r\n0:00:53.724692588   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.725552160   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 4(PLAYING) successfully\r\n0:00:53.726283557   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to PLAYING\r\n0:00:53.727032609   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.757078154   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 4(PLAYING) successfully\r\n0:00:53.757618408   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.757781635   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to PLAYING\r\n0:00:53.757868144   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.758061475   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 4(PLAYING) successfully\r\n0:00:53.758227931   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.758379075   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to PLAYING\r\n0:00:53.758486261   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.758636519   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 4(PLAYING) successfully\r\n0:00:53.758771830   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.758872714   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to PLAYING\r\n0:00:53.758970005   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.759101878   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 4(PLAYING) successfully\r\n0:00:53.759260470   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.759457290   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<avdec_aac1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.759615934   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to PLAYING\r\n0:00:53.759702547   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.759858795   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'avdec_aac1' changed state to 4(PLAYING) successfully\r\n0:00:53.768760398   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<aacparse1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.769718666   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to PLAYING\r\n0:00:53.769859081   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.770115380   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'aacparse1' changed state to 4(PLAYING) successfully\r\n0:00:53.770346314   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<multiqueue1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.772737325   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to PLAYING\r\n0:00:53.772950864   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.776680607   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'multiqueue1' changed state to 4(PLAYING) successfully\r\n0:00:53.777471534   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<tsdemux1> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.777927309   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to PLAYING\r\n0:00:53.778562561   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.779783795   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'tsdemux1' changed state to 4(PLAYING) successfully\r\n0:00:53.780552118   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.781162267   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to PLAYING\r\n0:00:53.783508382   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.784431807   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 4(PLAYING) successfully\r\n0:00:53.785152110   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to PLAYING\r\n0:00:53.785693718   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.786620998   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 4(PLAYING) successfully\r\n0:00:53.787749108   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current PAUSED pending VOID_PENDING, desired next PLAYING\r\n0:00:53.788493577   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to PLAYING\r\n0:00:53.789314400   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.790001162   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 4(PLAYING) successfully\r\n0:00:53.790519332   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to PLAYING\r\n0:00:53.790899640   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)\r\n0:00:53.794562248   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:53.795862023   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:00:53.796998518   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n##############################################################################\r\n#     RenderPlayerInfoCard                                                    \r\n#-----------------------------------------------------------------------------\r\n# AudioItemId         : amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\r\n# Audio state         : PLAYING\r\n# Offset milliseconds : 63749\r\n##############################################################################\r\n{\"content\":{\"header\":\"By Marcus Sakey\",\"provider\":{\"name\":\"Audible\",\"logo\":{\"sources\":[{\"url\":\"https://s3.amazonaws.com/music-provider-logos/Audible.svg\"}]}},\"art\":{\"sources\":[{\"url\":\"https://cds.audible.com/download/image?asin=B071KH1SDF&image_size=1280\"}]},\"mediaLengthInMilliseconds\":639000000,\"title\":\"Chapter 43\",\"titleSubtext1\":\"Afterlife\",\"headerSubtext1\":\"Narrated by Finty Williams\"},\"audioItemId\":\"amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\",\"controls\":[{\"selected\":false,\"name\":\"PLAY_PAUSE\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"PREVIOUS\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_BACKWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_FORWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"NEXT\",\"enabled\":true,\"type\":\"BUTTON\"}]}\r\n##############################################################################\r\n\r\n2018-03-06 03:57:31.408 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:31.409 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:31.735 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:31.736 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:32.043 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:32.043 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:00:54.811986335   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.879277777\r\n2018-03-06 03:57:32.309 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:32.309 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:00:55.141602297   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)49612, bitrate=(uint)30431;\r\n0:00:55.220321281   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2756, maximum-bitrate=(uint)50818, bitrate=(uint)30560;\r\n2018-03-06 03:57:32.671 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:32.672 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:00:55.304529000   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.925711111\r\n0:00:55.363263697   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:55.363598641   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:55.364044156   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:55.364241706   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:55.364379464   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:359:mpegts_packetizer_parse_adaptation_field_control: PID 0x0100 afc == 0x30 and length 183 > 182\r\n0:00:55.364718054   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:01.300288888\r\n0:00:55.365002321   773 0x748f2690 WARN                 tsdemux tsdemux.c:2255:gst_ts_demux_queue_data: CONTINUITY: Mismatch packet 0, stream 10\r\n0:00:55.385599621   773 0x6d934030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<avdec_aac1> upstream stream tags: taglist, audio-codec=(string)\"MPEG-4\\ AAC\", minimum-bitrate=(uint)2583, maximum-bitrate=(uint)50818, bitrate=(uint)30466;\r\n2018-03-06 03:57:33.113 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:33.114 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:33.401 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:33.401 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n2018-03-06 03:57:33.724 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:33.724 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:01:00.837964161   773 0x748f2690 WARN        mpegtspacketizer mpegtspacketizer.c:1854:_set_current_group: GAP detected. diff 0:00:02.786400000\r\n############################\r\n#       Listening...       #\r\n############################\r\n0:01:01.422086908   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n\r\n2018-03-06 03:57:38.860 [  2] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=bc6b615f-bc36-4964-8940-622f873c287c,newValue=72c440c4-38d2-4fed-afbe-99492efa521d\r\n0:01:01.425692607   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:01:01.426344946   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.426699839   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.432221720   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to PAUSED\r\n0:01:01.433496605   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.433960247   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 3(PAUSED) successfully\r\n0:01:01.434218266   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to PAUSED\r\n0:01:01.434355139   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.434580919   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 3(PAUSED) successfully\r\n0:01:01.435000499   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.435181903   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to PAUSED\r\n0:01:01.435292059   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.435464557   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 3(PAUSED) successfully\r\n0:01:01.435642108   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.435944605   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to PAUSED\r\n0:01:01.436069552   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.436375956   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 3(PAUSED) successfully\r\n0:01:01.436591475   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.436924597   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to PAUSED\r\n0:01:01.439160256   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.439459784   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 3(PAUSED) successfully\r\n0:01:01.439657387   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.440044884   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<avdec_aac1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.440224570   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to PAUSED\r\n0:01:01.440331079   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.440498943   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'avdec_aac1' changed state to 3(PAUSED) successfully\r\n0:01:01.440656962   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<aacparse1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.440899877   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to PAUSED\r\n0:01:01.441004459   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.441153833   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'aacparse1' changed state to 3(PAUSED) successfully\r\n0:01:01.441294457   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<multiqueue1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.441414247   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to PAUSED\r\n0:01:01.441504820   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.441652787   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'multiqueue1' changed state to 3(PAUSED) successfully\r\n0:01:01.442643039   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<tsdemux1> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.442982151   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to PAUSED\r\n0:01:01.443086004   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.443256992   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'tsdemux1' changed state to 3(PAUSED) successfully\r\n0:01:01.443408970   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.443532199   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to PAUSED\r\n0:01:01.443623292   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.443809071   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 3(PAUSED) successfully\r\n0:01:01.444032819   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to PAUSED\r\n0:01:01.444126569   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.444276567   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 3(PAUSED) successfully\r\n0:01:01.444407504   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current PLAYING pending VOID_PENDING, desired next PAUSED\r\n0:01:01.444531461   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to PAUSED\r\n0:01:01.444623492   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.444799844   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 3(PAUSED) successfully\r\n0:01:01.445058905   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to PAUSED\r\n0:01:01.445180622   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)\r\n0:01:01.446478320   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:01:01.449025955   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:01:01.449911104   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n##############################################################################\r\n#     RenderPlayerInfoCard                                                    \r\n#-----------------------------------------------------------------------------\r\n# AudioItemId         : amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\r\n# Audio state         : PAUSED\r\n# Offset milliseconds : 65853\r\n##############################################################################\r\n{\"content\":{\"header\":\"By Marcus Sakey\",\"provider\":{\"name\":\"Audible\",\"logo\":{\"sources\":[{\"url\":\"https://s3.amazonaws.com/music-provider-logos/Audible.svg\"}]}},\"art\":{\"sources\":[{\"url\":\"https://cds.audible.com/download/image?asin=B071KH1SDF&image_size=1280\"}]},\"mediaLengthInMilliseconds\":639000000,\"title\":\"Chapter 43\",\"titleSubtext1\":\"Afterlife\",\"headerSubtext1\":\"Narrated by Finty Williams\"},\"audioItemId\":\"amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\",\"controls\":[{\"selected\":false,\"name\":\"PLAY_PAUSE\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"PREVIOUS\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_BACKWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_FORWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"NEXT\",\"enabled\":true,\"type\":\"BUTTON\"}]}\r\n##############################################################################\r\n\r\n2018-03-06 03:57:40.719 [  3] I DirectiveSequencer:onDirective:directive={\"namespace\\:\"SpeechRecognizer\"\\,name\\:\"StopCapture\"\\,messageId\\:\"4bca4873-a80f-4a4d-b5a4-643db3b40afe\"\\,dialogRequestId\\:\"\"}\r\n2018-03-06 03:57:40.719 [  4] I DirectiveRouter:preHandleDirective:messageId=4bca4873-a80f-4a4d-b5a4-643db3b40afe,action=calling\r\n2018-03-06 03:57:40.720 [  5] I DirectiveRouter:handleDirective:messageId=4bca4873-a80f-4a4d-b5a4-643db3b40afe,action=calling\r\n###########################\r\n#       Thinking...       #\r\n###########################\r\n\r\n2018-03-06 03:57:40.729 [  6] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n2018-03-06 03:57:41.082 [  3] I DirectiveSequencer:onDirective:directive={\"namespace\\:\"AudioPlayer\"\\,name\\:\"Stop\"\\,messageId\\:\"52feb682-a867-41da-8448-e716e70dd79b\"\\,dialogRequestId\\:\"72c440c4-38d2-4fed-afbe-99492efa521d\"}\r\n2018-03-06 03:57:41.082 [  4] I DirectiveRouter:preHandleDirective:messageId=52feb682-a867-41da-8448-e716e70dd79b,action=calling\r\n2018-03-06 03:57:41.082 [  5] I DirectiveRouter:handleDirective:messageId=52feb682-a867-41da-8448-e716e70dd79b,action=calling\r\n0:01:03.648030246   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:01:03.648557273   773 0x75200e00 INFO              GST_STATES gstbin.c:2110:gst_bin_get_state_func:<audio-pipeline> getting state\r\n0:01:03.648764407   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.648950135   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.649888514   773 0x748f29b0 INFO                    task gsttask.c:318:gst_task_func:<decodedQueue:src> Task going to paused\r\n0:01:03.650105023   773 0x748f2690 INFO                 basesrc gstbasesrc.c:2860:gst_base_src_loop:<src> pausing after gst_pad_push() = flushing\r\n0:01:03.650328146   773 0x748f2690 INFO                    task gsttask.c:318:gst_task_func:<src:src> Task going to paused\r\n0:01:03.650203460   773 0x6d934030 INFO                    task gsttask.c:318:gst_task_func:<multiqueue1:src_0> Task going to paused\r\n0:01:03.653289845   773 0x75200e00 INFO              ringbuffer gstaudioringbuffer.c:675:gst_audio_ring_buffer_release:<pulseringbuffer7> Freeing timestamp buffer, 11 entries\r\n0:01:03.653697550   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to READY\r\n0:01:03.653872341   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.654107183   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 2(READY) successfully\r\n0:01:03.654397129   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to READY\r\n0:01:03.654563899   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.654768272   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 2(READY) successfully\r\n0:01:03.655016500   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.655354727   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to READY\r\n0:01:03.655634100   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.655912171   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 2(READY) successfully\r\n0:01:03.656162169   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.656646020   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to READY\r\n0:01:03.656852008   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.657107631   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 2(READY) successfully\r\n0:01:03.657327630   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.657582732   773 0x748f29b0 INFO                    task gsttask.c:320:gst_task_func:<decodedQueue:src> Task resume from paused\r\n0:01:03.657898668   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to READY\r\n0:01:03.658069343   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.658261946   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 2(READY) successfully\r\n0:01:03.658481789   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.658863713   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<avdec_aac1> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.659583135   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to READY\r\n0:01:03.659768082   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.659959903   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'avdec_aac1' changed state to 2(READY) successfully\r\n0:01:03.660133340   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<aacparse1> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.660529431   773 0x75200e00 INFO               baseparse gstbaseparse.c:4767:gst_base_parse_set_upstream_tags:<aacparse1> upstream tags: (NULL)\r\n0:01:03.660685992   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to READY\r\n0:01:03.660804846   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.660969219   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'aacparse1' changed state to 2(READY) successfully\r\n0:01:03.661123385   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<multiqueue1> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.661403748   773 0x6d934030 INFO                    task gsttask.c:320:gst_task_func:<multiqueue1:src_0> Task resume from paused\r\n0:01:03.661695569   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to READY\r\n0:01:03.661830568   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.661990462   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'multiqueue1' changed state to 2(READY) successfully\r\n0:01:03.662145461   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<tsdemux1> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.662478949   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<tsdemux1> removing pad 'audio_0_0100'\r\n0:01:03.662615510   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking tsdemux1:audio_0_0100(0x17b4820) and multiqueue1:sink_0(0x7520f9a0)\r\n0:01:03.668254742   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked tsdemux1:audio_0_0100 and multiqueue1:sink_0\r\n0:01:03.668670885   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to READY\r\n0:01:03.668759531   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.668889426   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'tsdemux1' changed state to 2(READY) successfully\r\n0:01:03.669046716   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<avdec_aac1> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.669122653   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<avdec_aac1> skipping transition from READY to  READY\r\n0:01:03.669184684   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'avdec_aac1' changed state to 2(READY) successfully\r\n0:01:03.669279840   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<aacparse1> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.669368849   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<aacparse1> skipping transition from READY to  READY\r\n0:01:03.669437807   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'aacparse1' changed state to 2(READY) successfully\r\n0:01:03.669529577   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<multiqueue1> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.669607181   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<multiqueue1> skipping transition from READY to  READY\r\n0:01:03.669672181   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'multiqueue1' changed state to 2(READY) successfully\r\n0:01:03.669782336   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<tsdemux1> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.669878950   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<tsdemux1> skipping transition from READY to  READY\r\n0:01:03.669956710   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'tsdemux1' changed state to 2(READY) successfully\r\n0:01:03.670069886   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.670286708   773 0x75200e00 INFO              GST_STATES gstelement.c:2137:gst_element_get_state_func:<typefind> waiting for element to commit state\r\n0:01:03.670365197   773 0x75200e00 INFO              GST_STATES gstelement.c:2151:gst_element_get_state_func:<typefind> timed out\r\n0:01:03.670461759   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to READY\r\n0:01:03.670536550   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.670662538   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 2(READY) successfully\r\n0:01:03.670861235   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to NULL\r\n0:01:03.670937068   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<avdec_aac1> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.671075452   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to NULL\r\n0:01:03.671145400   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<aacparse1> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.671278524   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to NULL\r\n0:01:03.671347117   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<multiqueue1> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.671467325   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to NULL\r\n0:01:03.671524043   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<tsdemux1> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.671648625   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking aacparse1:src(0x41947958) and avdec_aac1:sink(0x419472c8)\r\n0:01:03.671769145   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked aacparse1:src and avdec_aac1:sink\r\n0:01:03.671890811   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking avdec_aac1:src(0x41947bf8) and src_0:proxypad21(0x1960638)\r\n0:01:03.671999092   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked avdec_aac1:src and src_0:proxypad21\r\n0:01:03.672097008   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<decoder> removed child \"avdec_aac1\"\r\n0:01:03.672245132   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking multiqueue1:src_0(0x1969d40) and aacparse1:sink(0x19696b0)\r\n0:01:03.672353204   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked multiqueue1:src_0 and aacparse1:sink\r\n0:01:03.672459089   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<decoder> removed child \"aacparse1\"\r\n0:01:03.672563307   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<decoder> removing pad 'src_0'\r\n0:01:03.672620598   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking decoder:src_0(0x41902998) and decodedQueue:sink(0x17b4970)\r\n0:01:03.672718931   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked decoder:src_0 and decodedQueue:sink\r\n0:01:03.672904554   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<decoder> removed child \"multiqueue1\"\r\n0:01:03.673041949   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking typefind:src(0x1969aa0) and tsdemux1:sink(0x41947568)\r\n0:01:03.673145803   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked typefind:src and tsdemux1:sink\r\n0:01:03.673254760   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<decoder> removed child \"tsdemux1\"\r\n0:01:03.673439134   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<avdec_aac1> completed state change to NULL\r\n0:01:03.673514706   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<aacparse1> completed state change to NULL\r\n0:01:03.673589081   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<multiqueue1> removing pad 'src_0'\r\n0:01:03.673656945   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<multiqueue1> removing pad 'sink_0'\r\n0:01:03.673767934   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<multiqueue1> completed state change to NULL\r\n0:01:03.673841631   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<tsdemux1> completed state change to NULL\r\n0:01:03.673904912   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to READY\r\n0:01:03.673959703   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.674057255   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 2(READY) successfully\r\n0:01:03.674223087   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.674560585   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.674680115   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> skipping transition from READY to  READY\r\n0:01:03.674785843   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 2(READY) successfully\r\n0:01:03.674918290   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to READY\r\n0:01:03.675020738   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 2(READY) successfully\r\n0:01:03.675159487   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.675288184   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<volume> skipping transition from READY to  READY\r\n0:01:03.675399954   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 2(READY) successfully\r\n0:01:03.675551307   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.675678858   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<converter> skipping transition from READY to  READY\r\n0:01:03.675788753   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 2(READY) successfully\r\n0:01:03.675933700   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.676062710   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<decodedQueue> skipping transition from READY to  READY\r\n0:01:03.676202500   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 2(READY) successfully\r\n0:01:03.676482759   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.676765622   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current READY pending VOID_PENDING, desired next READY\r\n0:01:03.676920048   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<typefind> skipping transition from READY to  READY\r\n0:01:03.677034422   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 2(READY) successfully\r\n0:01:03.677172285   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to READY\r\n0:01:03.677281347   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 2(READY) successfully\r\n0:01:03.677410305   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current PAUSED pending VOID_PENDING, desired next READY\r\n0:01:03.677640303   773 0x748f2690 INFO                    task gsttask.c:320:gst_task_func:<src:src> Task resume from paused\r\n0:01:03.678139206   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to READY\r\n0:01:03.678301080   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed PAUSED to READY (VOID_PENDING pending)\r\n0:01:03.678469308   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 2(READY) successfully\r\n0:01:03.678624359   773 0x75200e00 INFO              GST_STATES gstelement.c:2394:gst_element_continue_state:<audio-pipeline> committing state from PAUSED to READY, pending NULL, next NULL\r\n0:01:03.678746962   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed PAUSED to READY (NULL pending)\r\n0:01:03.678893107   773 0x75200e00 INFO              GST_STATES gstelement.c:2401:gst_element_continue_state:<audio-pipeline> continue state change READY to NULL, final NULL\r\n0:01:03.679081699   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.679256646   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink-actual-sink-pulse> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.681693557   773 0x75200e00 INFO                   pulse pulsesink.c:3220:gst_pulsesink_release_mainloop:<audio_sink-actual-sink-pulse> terminating pa main loop thread\r\n0:01:03.682297354   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to NULL\r\n0:01:03.682459905   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink-actual-sink-pulse> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.682657873   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'audio_sink-actual-sink-pulse' changed state to 1(NULL) successfully\r\n0:01:03.682878080   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink-actual-sink-pulse> completed state change to NULL\r\n0:01:03.683039276   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking sink:proxypad1(0x1960218) and audio_sink-actual-sink-pulse:sink(0x1969e90)\r\n0:01:03.683178390   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked sink:proxypad1 and audio_sink-actual-sink-pulse:sink\r\n0:01:03.683304743   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<audio_sink> removed child \"audio_sink-actual-sink-pulse\"\r\n0:01:03.683515263   773 0x75200e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element \"fakesink\" named \"fake-audio-sink\"\r\n0:01:03.683798021   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x1962728> adding pad 'sink'\r\n0:01:03.684082134   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:916:gst_element_get_static_pad: found pad fake-audio-sink:sink\r\n0:01:03.684230727   773 0x75200e00 INFO                GST_PADS gstpad.c:2315:gst_pad_link_prepare: trying to link sink:proxypad1 and fake-audio-sink:sink\r\n0:01:03.684417652   773 0x75200e00 INFO                GST_PADS gstpad.c:2523:gst_pad_link_full: linked sink:proxypad1 and fake-audio-sink:sink, successful\r\n0:01:03.684526089   773 0x75200e00 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event\r\n0:01:03.684635359   773 0x75200e00 INFO               GST_EVENT gstpad.c:5652:gst_pad_send_event_unchecked:<sink:proxypad1> Received event on flushing pad. Discarding\r\n0:01:03.721217400   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to NULL\r\n0:01:03.721546200   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio_sink> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.721921927   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 1(NULL) successfully\r\n0:01:03.722299528   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.722686140   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<volume> completed state change to NULL\r\n0:01:03.722921607   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<volume> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.723226866   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 1(NULL) successfully\r\n0:01:03.723586863   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.723930715   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<converter> completed state change to NULL\r\n0:01:03.724166234   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<converter> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.724504149   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 1(NULL) successfully\r\n0:01:03.724821074   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.725149821   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decodedQueue> completed state change to NULL\r\n0:01:03.725438934   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decodedQueue> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.725742317   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 1(NULL) successfully\r\n0:01:03.726061430   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.726647415   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.727053454   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<typefind> completed state change to NULL\r\n0:01:03.727284494   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<typefind> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.727619804   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 1(NULL) successfully\r\n0:01:03.728015479   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to NULL\r\n0:01:03.728242144   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<decoder> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.728544746   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 1(NULL) successfully\r\n0:01:03.728835525   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current READY pending VOID_PENDING, desired next NULL\r\n0:01:03.729148231   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<src> completed state change to NULL\r\n0:01:03.729344793   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<src> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n0:01:03.729605416   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 1(NULL) successfully\r\n0:01:03.730522805   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<tsdemux1> 0x6d906770 dispose\r\n0:01:03.730930823   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<tsdemux1> removing pad 'sink'\r\n0:01:03.731263529   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<tsdemux1> 0x6d906770 parent class dispose\r\n0:01:03.731571809   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<tsdemux1> 0x6d906770 finalize\r\n0:01:03.731814359   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<tsdemux1> 0x6d906770 finalize parent\r\n0:01:03.734979025   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<multiqueue1> 0x195e590 dispose\r\n0:01:03.735385845   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<multiqueue1> 0x195e590 parent class dispose\r\n0:01:03.735645843   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<multiqueue1> 0x195e590 finalize\r\n0:01:03.735854123   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<multiqueue1> 0x195e590 finalize parent\r\n0:01:03.736152298   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<aacparse1> 0x6d922eb0 dispose\r\n0:01:03.736445265   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<aacparse1> removing pad 'sink'\r\n0:01:03.736802033   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<aacparse1> removing pad 'src'\r\n0:01:03.737108594   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<aacparse1> 0x6d922eb0 parent class dispose\r\n0:01:03.752163126   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<aacparse1> 0x6d922eb0 finalize\r\n0:01:03.752378072   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<aacparse1> 0x6d922eb0 finalize parent\r\n0:01:03.752519894   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<avdec_aac1> 0x73e0c258 dispose\r\n0:01:03.752631925   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<avdec_aac1> removing pad 'sink'\r\n0:01:03.752781819   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<avdec_aac1> removing pad 'src'\r\n0:01:03.752922235   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<avdec_aac1> 0x73e0c258 parent class dispose\r\n0:01:03.753113015   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<avdec_aac1> 0x73e0c258 finalize\r\n0:01:03.753234316   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<avdec_aac1> 0x73e0c258 finalize parent\r\n0:01:03.753432544   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<audio_sink-actual-sink-pulse> 0x75219a78 dispose\r\n0:01:03.753550616   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<audio_sink-actual-sink-pulse> removing pad 'sink'\r\n0:01:03.753680407   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<audio_sink-actual-sink-pulse> 0x75219a78 parent class dispose\r\n0:01:03.753799937   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<audio_sink-actual-sink-pulse> 0x75219a78 finalize\r\n0:01:03.753899989   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<audio_sink-actual-sink-pulse> 0x75219a78 finalize parent\r\n0:01:03.754025665   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to NULL\r\n0:01:03.754129258   773 0x75200e00 INFO              GST_STATES gstelement.c:2324:_priv_gst_element_state_changed:<audio-pipeline> notifying about state-changed READY to NULL (VOID_PENDING pending)\r\n2018-03-06 03:57:41.189 [  7] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed\r\n0:01:03.755122533   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<audio_sink> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.755395656   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<fake-audio-sink> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.755552373   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<fake-audio-sink> skipping transition from NULL to  NULL\r\n0:01:03.755720758   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio_sink> child 'fake-audio-sink' changed state to 1(NULL) successfully\r\n2018-03-06 03:57:41.191 [  c] I InProcessAttachmentReader:readFailed:reason=SDS is closed\r\n0:01:03.755907111   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio_sink> completed state change to NULL\r\n2018-03-06 03:57:41.191 [  c] I UrlContentToAttachmentConverter:readFinished:reason=CLOSED\r\n0:01:03.756075703   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'audio_sink' changed state to 1(NULL) successfully\r\n0:01:03.783504213   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<volume> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.783740201   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<volume> skipping transition from NULL to  NULL\r\n0:01:03.783949262   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'volume' changed state to 1(NULL) successfully\r\n0:01:03.784128792   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<converter> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.784253895   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<converter> skipping transition from NULL to  NULL\r\n0:01:03.784334468   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'converter' changed state to 1(NULL) successfully\r\n0:01:03.784448061   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decodedQueue> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.784537331   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<decodedQueue> skipping transition from NULL to  NULL\r\n0:01:03.784606914   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decodedQueue' changed state to 1(NULL) successfully\r\n0:01:03.784778371   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<decoder> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.785045036   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<typefind> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.785155296   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<typefind> skipping transition from NULL to  NULL\r\n0:01:03.785240764   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<decoder> child 'typefind' changed state to 1(NULL) successfully\r\n0:01:03.785353419   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<decoder> completed state change to NULL\r\n0:01:03.785433939   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'decoder' changed state to 1(NULL) successfully\r\n0:01:03.785531230   773 0x75200e00 INFO              GST_STATES gstbin.c:2521:gst_bin_element_set_state:<src> current NULL pending VOID_PENDING, desired next NULL\r\n0:01:03.785611959   773 0x75200e00 INFO              GST_STATES gstbin.c:2638:gst_bin_element_set_state:<src> skipping transition from NULL to  NULL\r\n0:01:03.785720812   773 0x75200e00 INFO              GST_STATES gstbin.c:2969:gst_bin_change_state_func:<audio-pipeline> child 'src' changed state to 1(NULL) successfully\r\n0:01:03.817579657   773 0x75200e00 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<audio-pipeline> completed state change to NULL\r\n0:01:03.818048456   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking src:src(0x1969560) and decoder:sink(0x195f5f0)\r\n0:01:03.818328558   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked src:src and decoder:sink\r\n0:01:03.818586577   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<audio-pipeline> removed child \"src\"\r\n0:01:03.819040584   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<src> 0x75208160 dispose\r\n0:01:03.819202718   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<src> removing pad 'src'\r\n0:01:03.819364384   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<src> 0x75208160 parent class dispose\r\n0:01:03.819499956   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<src> 0x75208160 finalize\r\n0:01:03.819592507   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<src> 0x75208160 finalize parent\r\n0:01:03.819978078   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<audio-pipeline> removed child \"decoder\"\r\n0:01:03.823802739   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking sink:proxypad19(0x1960d18) and typefind:sink(0x41947178)\r\n0:01:03.824289194   773 0x75200e00 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked sink:proxypad19 and typefind:sink\r\n0:01:03.824492266   773 0x75200e00 INFO           GST_PARENTAGE gstbin.c:1822:gst_bin_remove_func:<decoder> removed child \"typefind\"\r\n0:01:03.824971898   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<typefind> 0x7520f018 dispose\r\n0:01:03.825140594   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<typefind> removing pad 'sink'\r\n0:01:03.825300698   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<typefind> removing pad 'src'\r\n0:01:03.825427936   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<typefind> 0x7520f018 parent class dispose\r\n0:01:03.825528040   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<typefind> 0x7520f018 finalize\r\n0:01:03.825605435   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<typefind> 0x7520f018 finalize parent\r\n0:01:03.825727413   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<decoder> 0x7520d030 dispose\r\n0:01:03.825896006   773 0x75200e00 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<decoder> removing pad 'sink'\r\n0:01:03.827321777   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<decoder> 0x7520d030 parent class dispose\r\n0:01:03.827505735   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<decoder> 0x7520d030 finalize\r\n0:01:03.827591984   773 0x75200e00 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<decoder> 0x7520d030 finalize parent\r\n########################################\r\n#       Alexa is currently idle!       #\r\n########################################\r\n\r\n2018-03-06 03:57:41.568 [  d] E LibCurlHttpContentFetcher:curlEasyPerformFailed:error=Failed writing received data to disk/application\r\n2018-03-06 03:57:41.570 [  c] E UrlContentToAttachmentConverter:writeUrlContentToStreamFailed:info=closingWriter\r\n2018-03-06 03:57:41.572 [  7] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet\r\n2018-03-06 03:57:41.572 [  7] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet\r\n##############################################################################\r\n#     RenderPlayerInfoCard                                                    \r\n#-----------------------------------------------------------------------------\r\n# AudioItemId         : amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\r\n# Audio state         : STOPPED\r\n# Offset milliseconds : 65853\r\n##############################################################################\r\n{\"content\":{\"header\":\"By Marcus Sakey\",\"provider\":{\"name\":\"Audible\",\"logo\":{\"sources\":[{\"url\":\"https://s3.amazonaws.com/music-provider-logos/Audible.svg\"}]}},\"art\":{\"sources\":[{\"url\":\"https://cds.audible.com/download/image?asin=B071KH1SDF&image_size=1280\"}]},\"mediaLengthInMilliseconds\":639000000,\"title\":\"Chapter 43\",\"titleSubtext1\":\"Afterlife\",\"headerSubtext1\":\"Narrated by Finty Williams\"},\"audioItemId\":\"amzn1.as-ct.v1.AudibleClientId#ACRI#url#ACRI#playq:audiobook/audible;mv=Audible,0cc7ccc4-519f-4aad-bc0d-ff1ae45f6ba2#43\",\"controls\":[{\"selected\":false,\"name\":\"PLAY_PAUSE\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"PREVIOUS\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_BACKWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"SKIP_FORWARD\",\"enabled\":true,\"type\":\"BUTTON\"},{\"selected\":false,\"name\":\"NEXT\",\"enabled\":true,\"type\":\"BUTTON\"}]}\r\n##############################################################################\r\n\r\n2018-03-06 03:57:41.573 [  7] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet\r\n\r\n\r\n\r\n## Tell us about your environment:\r\n<!--- Include as many relevant details about the environment you experienced the bug in -->\r\n### What version of the AVS Device SDK are you using?\r\n      <SDK v1.5.0>\r\n\r\n### Tell us what hardware you're using:\r\nRaspberry Pi\r\n\r\n### Tell us about your OS (Type & version):\r\nRaspbian Stretch\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/alexa/avs-device-sdk/issues/comments/371895370","html_url":"https://github.com/alexa/avs-device-sdk/issues/545#issuecomment-371895370","issue_url":"https://api.github.com/repos/alexa/avs-device-sdk/issues/545","id":371895370,"user":{"login":"sanjayrd","id":6990939,"avatar_url":"https://avatars1.githubusercontent.com/u/6990939?v=4","gravatar_id":"","url":"https://api.github.com/users/sanjayrd","html_url":"https://github.com/sanjayrd","followers_url":"https://api.github.com/users/sanjayrd/followers","following_url":"https://api.github.com/users/sanjayrd/following{/other_user}","gists_url":"https://api.github.com/users/sanjayrd/gists{/gist_id}","starred_url":"https://api.github.com/users/sanjayrd/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sanjayrd/subscriptions","organizations_url":"https://api.github.com/users/sanjayrd/orgs","repos_url":"https://api.github.com/users/sanjayrd/repos","events_url":"https://api.github.com/users/sanjayrd/events{/privacy}","received_events_url":"https://api.github.com/users/sanjayrd/received_events","type":"User","site_admin":false},"created_at":"2018-03-09T18:04:44Z","updated_at":"2018-03-09T18:04:44Z","author_association":"MEMBER","body":"Hi @actions-semi4378,\r\n\r\nWe recently made an update in our 1.6 release to fix issues with certain Audible books not working. Could you try upgrading your SDK version?\r\n\r\nThanks,\r\nSanjay"}}
{"actor":{"display_login":"sanjayrd"}}