Testcase: test_shuffle

Build #:266:20150723:20150708
Arch:mako (Nexus 4)
Release:wily
Variant:touch
Artifacts
Console Log

Failure explanation

This test failure has not yet been categorized.
Log in to edit.

Test case data

testcase
test_shuffle
testsuite
music_app.tests.test_music.TestMainWindow
returncode
1
command
autopilot
stderr
_StringException: Binary content:
  FailedTestScreenshot (image/png)

/var/log/syslog: {{{
Jul 23 09:03:02 ubuntu-phablet kernel: [   99.528918] input: py-evdev-uinput as /devices/virtual/input/input6
Jul 23 09:03:02 ubuntu-phablet kernel: [   99.531725] keychord: using input dev py-evdev-uinput for fevent
Jul 23 09:03:02 ubuntu-phablet kernel: [   99.897054] input: autopilot-finger as /devices/virtual/input/input7
Jul 23 09:03:05 ubuntu-phablet powerd[945]: handle_requestSysState from :1.62 (active) - ACTIVE (1)
Jul 23 09:03:05 ubuntu-phablet powerd[945]: name_watch_add: looking for :1.62
Jul 23 09:03:05 ubuntu-phablet powerd[945]: watching :1.62 to see when it disappears on dbus
Jul 23 09:03:05 ubuntu-phablet powerd[945]: libsuspend: acquire_wake_lock: powerd_power_request
Jul 23 09:03:05 ubuntu-phablet powerd[945]: handle_requestSysState - SUCCESS
Jul 23 09:03:05 ubuntu-phablet powerd[945]: Enqueue state change to ACTIVE
Jul 23 09:03:05 ubuntu-phablet powerd[945]: queue empty && state == current, discarding
Jul 23 09:03:05 ubuntu-phablet powerd[945]: libsuspend: release_wake_lock: powerd_power_request
Jul 23 09:03:15 ubuntu-phablet powerd[945]: handle_requestSysState from :1.26 (usensord) - ACTIVE (1)
Jul 23 09:03:15 ubuntu-phablet powerd[945]: name_watch_add: looking for :1.26
Jul 23 09:03:15 ubuntu-phablet powerd[945]: watching :1.26 to see when it disappears on dbus
Jul 23 09:03:15 ubuntu-phablet powerd[945]: libsuspend: acquire_wake_lock: powerd_power_request
Jul 23 09:03:15 ubuntu-phablet powerd[945]: handle_requestSysState - SUCCESS
Jul 23 09:03:15 ubuntu-phablet powerd[945]: Enqueue state change to ACTIVE
Jul 23 09:03:15 ubuntu-phablet powerd[945]: queue empty && state == current, discarding
Jul 23 09:03:15 ubuntu-phablet powerd[945]: libsuspend: release_wake_lock: powerd_power_request
Jul 23 09:03:18 ubuntu-phablet powerd[945]: handle_clearSysState from :1.26, cookie: 5a2a2888-b765-4514-b039-ec882e623592
Jul 23 09:03:18 ubuntu-phablet powerd[945]: clear_sys_request: usensord - :1.26
Jul 23 09:03:18 ubuntu-phablet powerd[945]: name_watch_remove: looking for :1.26
Jul 23 09:03:18 ubuntu-phablet powerd[945]: name_watch: ref_count for :1.26 is now 0
Jul 23 09:03:18 ubuntu-phablet powerd[945]: no longer watching :1.26, there are no more requests
Jul 23 09:03:18 ubuntu-phablet powerd[945]: libsuspend: acquire_wake_lock: powerd_power_request
Jul 23 09:03:18 ubuntu-phablet powerd[945]: Enqueue state change to ACTIVE
Jul 23 09:03:18 ubuntu-phablet powerd[945]: queue empty && state == current, discarding
Jul 23 09:03:18 ubuntu-phablet powerd[945]: libsuspend: release_wake_lock: powerd_power_request
Jul 23 09:03:18 ubuntu-phablet kernel: [  115.970028] amp_enable: AMP_EN is set to 1
Jul 23 09:03:18 ubuntu-phablet kernel: [  115.993438] setting pm_qos in msm_pcm_playback_copy with 1000
Jul 23 09:03:18 ubuntu-phablet kernel: [  115.993438] done setting pm_qos in msm_pcm_playback_copy
Jul 23 09:03:19 ubuntu-phablet kernel: [  116.346192] audit_printk_skb: 60 callbacks suppressed
Jul 23 09:03:19 ubuntu-phablet kernel: [  116.346192] type=1400 audit(1437642199.291:89): apparmor="DENIED" operation="mknod"
profile="/usr/bin/media-hub-server" name="/run/user/32011/orcexec.4TRFox" pid=4153 comm="aqueue:src" requested_mask="c" denied_mask="c" fsuid=32011
ouid=32011
Jul 23 09:03:19 ubuntu-phablet kernel: [  116.346314] type=1400 audit(1437642199.291:90): apparmor="DENIED" operation="mknod"
profile="/usr/bin/media-hub-server" name="/home/phablet/orcexec.C2rACU" pid=4153 comm="aqueue:src" requested_mask="c" denied_mask="c" fsuid=32011
ouid=32011
Jul 23 09:03:19 ubuntu-phablet powerd[945]: handle_requestSysState from :1.54 (media-hub-playback_lock) - ACTIVE (1)
Jul 23 09:03:19 ubuntu-phablet powerd[945]: name_watch_add: looking for :1.54
Jul 23 09:03:19 ubuntu-phablet powerd[945]: watching :1.54 to see when it disappears on dbus
Jul 23 09:03:19 ubuntu-phablet powerd[945]: libsuspend: acquire_wake_lock: powerd_power_request
Jul 23 09:03:19 ubuntu-phablet powerd[945]: handle_requestSysState - SUCCESS
Jul 23 09:03:19 ubuntu-phablet powerd[945]: Enqueue state change to ACTIVE
Jul 23 09:03:19 ubuntu-phablet powerd[945]: queue empty && state == current, discarding
Jul 23 09:03:19 ubuntu-phablet powerd[945]: libsuspend: release_wake_lock: powerd_power_request
Jul 23 09:03:24 ubuntu-phablet kernel: [  121.493209] wlan: [1533:E :HDD] hdd_tx_rx_pkt_cnt_stat_timer_handler: Disable split scan
Jul 23 09:03:28 ubuntu-phablet powerd[945]: handle_clearSysState from :1.54, cookie: 3560d438-385a-4a83-ad84-e06ee1711c16
Jul 23 09:03:28 ubuntu-phablet powerd[945]: clear_sys_request: media-hub-playback_lock - :1.54
Jul 23 09:03:28 ubuntu-phablet powerd[945]: name_watch_remove: looking for :1.54
Jul 23 09:03:28 ubuntu-phablet powerd[945]: name_watch: ref_count for :1.54 is now 0
Jul 23 09:03:28 ubuntu-phablet powerd[945]: no longer watching :1.54, there are no more requests
Jul 23 09:03:28 ubuntu-phablet powerd[945]: libsuspend: acquire_wake_lock: powerd_power_request
Jul 23 09:03:28 ubuntu-phablet powerd[945]: Enqueue state change to ACTIVE
Jul 23 09:03:28 ubuntu-phablet powerd[945]: queue empty && state == current, discarding
Jul 23 09:03:28 ubuntu-phablet powerd[945]: libsuspend: release_wake_lock: powerd_power_request
Jul 23 09:03:29 ubuntu-phablet kernel: [  126.679536] updating pm_qos value to default msm_pcm_playback_close
Jul 23 09:03:29 ubuntu-phablet kernel: [  126.679536] done updating pm_qos value to default msm_pcm_playback_close
Jul 23 09:03:29 ubuntu-phablet kernel: [  126.710666] SLIM_CL: skip reconfig sequence
Jul 23 09:03:29 ubuntu-phablet kernel: [  126.719945] amp_enable: amp enable bypass(2)
Jul 23 09:03:29 ubuntu-phablet kernel: [  126.719975] amp_enable: AMP_EN is set to 0
Jul 23 09:03:36 ubuntu-phablet powerd[945]: handle_clearSysState from :1.62, cookie: b63ba169-94b7-4ae3-b1e3-c816ce345a4d
Jul 23 09:03:36 ubuntu-phablet powerd[945]: clear_sys_request: active - :1.62
Jul 23 09:03:36 ubuntu-phablet powerd[945]: name_watch_remove: looking for :1.62
Jul 23 09:03:36 ubuntu-phablet powerd[945]: name_watch: ref_count for :1.62 is now 0
Jul 23 09:03:36 ubuntu-phablet powerd[945]: no longer watching :1.62, there are no more requests
Jul 23 09:03:36 ubuntu-phablet powerd[945]: libsuspend: acquire_wake_lock: powerd_power_request
Jul 23 09:03:36 ubuntu-phablet powerd[945]: Enqueue state change to ACTIVE
Jul 23 09:03:36 ubuntu-phablet powerd[945]: queue empty && state == current, discarding
Jul 23 09:03:36 ubuntu-phablet powerd[945]: libsuspend: release_wake_lock: powerd_power_request
Jul 23 09:03:37 ubuntu-phablet dbus[846]: [system] Activating service name='com.canonical.PropertyService' (using servicehelper)
Jul 23 09:03:37 ubuntu-phablet dbus[846]: [system] Successfully activated service 'com.canonical.PropertyService'
}}}

Application Log (com.ubuntu.music_music_2.1.867.1): {{{
libust[4000/4004]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4004]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4003]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
Loading module: 'libubuntu_application_api_touch_mirclient.so.3.0.0'
/usr/lib/arm-linux-gnueabihf/qt5/bin/qmlscene: unrecognized option '--url='
/usr/lib/arm-linux-gnueabihf/qt5/bin/qmlscene: invalid option -- 'I'
Testability driver loaded. Wire protocol version is "1.4".

(process:4000): dconf-CRITICAL **: unable to create file '/run/user/32011/dconf/user': Permission denied.  dconf will not work properly.
libust[4000/4044]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4044]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4043]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4043]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
file:///usr/share/click/preinstalled/com.ubuntu.music/2.1.867.1/app/components/LoadingSpinnerComponent.qml:36:5: QML ActivityIndicator:
Theme.createStyleComponent() is deprecated. Use ThemeSettings instead.
file:///usr/share/click/preinstalled/com.ubuntu.music/2.1.867.1/app/components/HeadState/SearchHeadState.qml:32:15: QML TextField:
Theme.createStyleComponent() is deprecated. Use ThemeSettings instead.
qml: RECENT does not exist
Initializing AalServicePlugin
virtual QMediaService* AalServicePlugin::create(const QString&) "org.qt-project.qt.mediaplayer"
Creating a new static Service instance
virtual int AalMediaPlayerControl::volume() const 

void AalMediaPlayerService::createMetaDataReaderControl()
virtual QMediaPlayer::State AalMediaPlayerControl::state() const 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

virtual int AalMediaPlayerControl::volume() const 

qml: Debug: Version 2.1
qml: Playlist DB is version 
qml: Error reading old playlists, probably doesn't exist.
qml: Error reading old playlists tracks, probably doesn't exist.
qml: DB: Changing version of playlist db to 1.3, migrating 0 tracks
qml: Old playlists []
qml: DB: Restore {}
qml: RECENT does not exist
UbuntuWindow - regular geometry
UbuntuWindow::handleSurfaceFocusChange(focused=true)
UbuntuWindow::handleSurfaceResize(width=1080, height=846)
UbuntuClipboard - Got invalid serialized mime data. Ignoring it.
D-Bus error:  "Could not get thumbnail"
D-Bus error:  "Could not get thumbnail"
D-Bus error:  "Could not get thumbnail"
libust[4000/4044]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4043]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
D-Bus error:  "Could not get thumbnail"
D-Bus error:  "Could not get thumbnail"
D-Bus error:  "Could not get thumbnail"
libust[4000/4044]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4043]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
virtual void AalMediaPlayerControl::stop() 

PlaybackStatusChanged signal arrived via the bus (Status: PlaybackStatus::stopped)
qml: Source: file:///home/phablet/Music/1.ogg
qml: Index: 0
virtual void AalMediaPlayerControl::setMedia(const QMediaContent&, QIODevice*) 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

Local file URI:  "file:///home/phablet/Music/1.ogg"
Setting media to:   QUrl( "file:///home/phablet/Music/1.ogg" ) 
void AalMetaDataReaderControl::onMediaChanged(const QMediaContent&)
void AalMetaDataReaderControl::updateMetaData()
Doing a mediascanner lookup of file:  "///home/phablet/Music/1.ogg"
Caught runtime exception from mediascanner:  Could not find media ///home/phablet/Music/1.ogg
virtual void AalMediaPlayerControl::play() 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

void AalMediaPlayerService::play()
virtual void core::ubuntu::media::ServiceStub::pause_other_sessions(core::ubuntu::media::Player::PlayerKey)
virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

Actually calling m_hubPlayerSession->play()
PlaybackStatusChanged signal arrived via the bus (Status: PlaybackStatus::ready)
PlaybackStatusChanged signal arrived via the bus (Status: PlaybackStatus::paused)
PlaybackStatusChanged signal arrived via the bus (Status: PlaybackStatus::playing)
PlaybackStatusChanged signal arrived via the bus (Status: PlaybackStatus::playing)
qml: Debug: Queue: Now has: 0 tracks
qml: Debug: Queue: Now has: 3 tracks
qml: Debug: Queue: Now has: 3 tracks
D-Bus error:  "Could not get thumbnail"
libust[4000/4044]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4043]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
virtual void AalMediaPlayerControl::pause() 

PlaybackStatusChanged signal arrived via the bus (Status: PlaybackStatus::paused)
PlaybackStatusChanged signal arrived via the bus (Status: PlaybackStatus::paused)
virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

virtual QMediaPlayer::MediaStatus AalMediaPlayerControl::mediaStatus() const 

libust[4000/4044]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4043]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4044]: Error: Error opening shm /lttng-ust-wait-5-32011 (in get_wait_shm() at lttng-ust-comm.c:971)
libust[4000/4043]: Error: Error opening shm /lttng-ust-wait-5 (in get_wait_shm() at lttng-ust-comm.c:971)
}}}

test-log: {{{
09:03:03.012 WARNING testcase:175 - Process manager backend unavailable, application snapshot support disabled.
09:03:03.014 DEBUG __init__:145 - Creating music library for click test
09:03:03.015 DEBUG __init__:146 - Home set to /home/phablet
09:03:03.027 DEBUG __init__:148 - Music path set to /home/phablet/Music
09:03:03.029 DEBUG __init__:153 - Mediascanner path set to /home/phablet/.cache/mediascanner-2.0
09:03:03.030 DEBUG __init__:159 - Content dir set to /home/phablet/autopilot/music_app/content
09:03:03.456 DEBUG __init__:166 - Music copied, files ['1.ogg', '2.ogg', '3.mp3']
09:03:03.457 INFO logging:45 - TestMainWindow: launch_test_click. Arguments (). Keyword arguments: {}.
09:03:03.459 INFO _launcher:280 - Attempting to launch click application '(default)' from click package  'com.ubuntu.music' and URIs ''
09:03:04.699 INFO _launcher:120 - Attempting to launch application 'com.ubuntu.music_music_2.1.867.1' with URIs '' via upstart-app-launch
09:03:14.144 DEBUG _common:45 - Moving to object's globalRect coordinates.
09:03:14.145 DEBUG _uinput:485 - Tapping at: 68,848
09:03:14.248 INFO logging:45 - MainView: Open a tab. Arguments ('songsTab',). Keyword arguments: {}.
09:03:14.325 DEBUG dbus:352 - Selecting objects of type Tab with attributes: {}
09:03:14.575 INFO logging:45 - MainView: Open a tab. Arguments (3,). Keyword arguments: {}.
09:03:14.642 DEBUG dbus:352 - Selecting objects of type Tab with attributes: {}
09:03:15.173 INFO logging:45 - AppHeader: Open a tab. This only supports the new tabs in the header. Arguments (3,). Keyword arguments: {}.
09:03:15.472 DEBUG _common:45 - Moving to object's globalRect coordinates.
09:03:15.473 DEBUG _uinput:485 - Tapping at: 63,121
09:03:16.878 DEBUG _common:45 - Moving to object's globalRect coordinates.
09:03:16.879 DEBUG _uinput:485 - Tapping at: 180,581
09:03:17.232 DEBUG dbus:352 - Selecting objects of type Tab with attributes: {}
09:03:18.589 DEBUG _common:45 - Moving to object's globalRect coordinates.
09:03:18.590 DEBUG _uinput:485 - Tapping at: 540,481
09:03:24.506 DEBUG _common:45 - Moving to object's globalRect coordinates.
09:03:24.507 DEBUG _uinput:485 - Tapping at: 540,814
09:03:25.097 DEBUG _common:45 - Moving to object's globalRect coordinates.
09:03:25.098 DEBUG _uinput:485 - Tapping at: 828,814
}}}

Traceback (most recent call last):
  File "/home/phablet/autopilot/music_app/tests/test_music.py", line 254, in test_shuffle
    now_playing_page.set_shuffle(True)  # enable shuffle
  File "/home/phablet/autopilot/music_app/__init__.py", line 317, in set_shuffle
    self.player.shuffle.wait_for(state)
  File "/usr/lib/python3/dist-packages/autopilot/introspection/types.py", line 180, in wait_for
    failure_msg))
AssertionError: After 10.0 seconds test on Player.shuffle failed: True != dbus.Boolean(False, variant_level=1)

command_type
testcase_test