Comment 10 for bug 1612367

@Pat: that doesn't look right. For a normal case, you should only see one Engine: playing uri: ...

Normal output should look like this:

[II 2016-09-01 12:58:26.995539] [engine.cpp:73@on_playbin_state_changed] State changed on playbin: READY
[II 2016-09-01 12:58:26.995731] [player_implementation.cpp:193@operator()] Emiting playback_status_changed signal: PlaybackStatus::ready
PulseAudio event for sink with index 0 received.
[II 2016-09-01 12:58:27.032896] [pulse_audio_output_observer.cpp:323@on_query_for_primary_sink_finished] Checking if port is available -> 0
PulseAudio sink details for sink.primary with index 0 is available:
  Output to wired headphone: false
  Output to wired headset: false
[DD 2016-09-01 12:58:27.199917] [track_list_skeleton.cpp:702@current_iterator] Wrapping d->current_track back to begin()
[DD 2016-09-01 12:58:27.201450] [player_implementation.cpp:129@operator()] Setting state for parent: 0xec838214
[II 2016-09-01 12:58:27.202742] [player_implementation.cpp:158@operator()] Requesting power state
[II 2016-09-01 12:58:27.203175] [engine.cpp:73@on_playbin_state_changed] State changed on playbin: PAUSED
[TT 2016-09-01 12:58:27.203987] [player_implementation.cpp:200@request_power_state]
[II 2016-09-01 12:58:27.204181] [player_implementation.cpp:216@request_power_state] Requesting new system wakelock.
[TT 2016-09-01 12:58:27.204319] [state_controller.cpp:210@request_acquire]
[II 2016-09-01 12:58:27.204794] [player_implementation.cpp:218@request_power_state] Requested new system wakelock.
[II 2016-09-01 12:58:27.204041] [player_implementation.cpp:193@operator()] Emiting playback_status_changed signal: PlaybackStatus::paused
[II 2016-09-01 12:58:27.207937] [engine.cpp:73@on_playbin_state_changed] State changed on playbin: PLAYING
[II 2016-09-01 12:58:27.208175] [player_implementation.cpp:193@operator()] Emiting playback_status_changed signal: PlaybackStatus::playing
[II 2016-09-01 12:58:27.210584] [player_implementation.cpp:94@operator()] Acquired new system state: SystemState::active
[II 2016-09-01 12:58:27.207938] [engine.cpp:455@play] Engine: playing uri: file:///usr/share/sounds/ubuntu/ringtones/Ubuntu.ogg
[II 2016-09-01 12:58:27.216218] [player_implementation.cpp:193@operator()] Emiting playback_status_changed signal: PlaybackStatus::playing