Merge into devel : lp-1614657-fix-percent-done-error-in-helpers-test-failure : Code : Keeper

Status:

Needs review

Proposed branch:

lp://qastaging/~charlesk/keeper/lp-1614657-fix-percent-done-error-in-helpers-test-failure

Merge into:

lp://qastaging/keeper/devel

Prerequisite:

lp://qastaging/~charlesk/keeper/fix-tar-creator-test

Diff against target:

70 lines (+12/-10)

3 files modified

tests/fakes/fake-backup-helper.cpp (+5/-5)
tests/integration/helpers/helpers-test-failure.cpp (+5/-5)
tests/integration/helpers/test-helpers-base.cpp (+2/-0)

To merge this branch:

bzr merge lp://qastaging/~charlesk/keeper/lp-1614657-fix-percent-done-error-in-helpers-test-failure

Medium

Fix Committed

Link a bug report

Reviewer	Review Type	Date Requested	Status
Xavi Garcia (community)		2016-08-20	Needs Fixing on 2016-08-25
unity-api-1-bot	continuous-integration		Needs Fixing on 2016-08-20
Review via email: mp+303475@code.qastaging.launchpad.net

Commit message

Update helpers-test-failure because Keeper now tracks the current task

Description of the change

(WORK IN PROGRESS)

Update helpers-test-failure because Keeper now tracks the current task

Bug discussion @ https://bugs.launchpad.net/keeper/+bug/1614657/comments/1

Revision history for this message

unity-api-1-bot (unity-api-1-bot) wrote on 2016-08-20:

#

Click here to trigger a rebuild:
https://jenkins.canonical.com/unity-api-1/job/lp-keeper-ci/25/rebuild

FAILED: Continuous integration, rev:114
https://jenkins.canonical.com/unity-api-1/job/lp-keeper-ci/25/
Executed test runs:
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build/436/console
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-0-fetch/442
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-1-sourcepkg/release=vivid+overlay/348
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-1-sourcepkg/release=xenial+overlay/348
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-1-sourcepkg/release=yakkety/348
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=vivid+overlay/278
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=vivid+overlay/278/artifact/output/*zip*/output.zip
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=xenial+overlay/278
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=xenial+overlay/278/artifact/output/*zip*/output.zip
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=yakkety/278
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=yakkety/278/artifact/output/*zip*/output.zip
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=vivid+overlay/278/console
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=xenial+overlay/278/console
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=yakkety/278/console
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=vivid+overlay/278
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=vivid+overlay/278/artifact/output/*zip*/output.zip
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=xenial+overlay/278/console
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=yakkety/278/console

Click here to trigger a rebuild:
https://jenkins.canonical.com/unity-api-1/job/lp-keeper-ci/25/rebuild

review: Needs Fixing (continuous-integration)

Reply

lp://qastaging/~charlesk/keeper/lp-1614657-fix-percent-done-error-in-helpers-test-failure updated on 2016-08-20

115. By Charles Kerr on 2016-08-20: in TestHelpersBase, add code to query Keeper and wait until all tasks are finished
116. By Charles Kerr on 2016-08-20: in helpers-test-failure, use the new wait_for_tasks_to_finish() method
117. By Charles Kerr on 2016-08-20: revert r115, r116 as a failed experiment since we have to trigger the upstart 'stopped' event ourselves
118. By Charles Kerr on 2016-08-20: in test-helpers-base, cleanup the flag file before starting tests

Revision history for this message

unity-api-1-bot (unity-api-1-bot) wrote on 2016-08-20:

#

Click here to trigger a rebuild:
https://jenkins.canonical.com/unity-api-1/job/lp-keeper-ci/26/rebuild

FAILED: Continuous integration, rev:118
https://jenkins.canonical.com/unity-api-1/job/lp-keeper-ci/26/
Executed test runs:
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build/437/console
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-0-fetch/443
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-1-sourcepkg/release=vivid+overlay/349
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-1-sourcepkg/release=xenial+overlay/349
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-1-sourcepkg/release=yakkety/349
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=vivid+overlay/279
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=vivid+overlay/279/artifact/output/*zip*/output.zip
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=xenial+overlay/279/console
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=amd64,release=yakkety/279/console
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=vivid+overlay/279
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=vivid+overlay/279/artifact/output/*zip*/output.zip
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=xenial+overlay/279
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=xenial+overlay/279/artifact/output/*zip*/output.zip
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=armhf,release=yakkety/279/console
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=vivid+overlay/279
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=vivid+overlay/279/artifact/output/*zip*/output.zip
    SUCCESS: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=xenial+overlay/279
        deb: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=xenial+overlay/279/artifact/output/*zip*/output.zip
    FAILURE: https://jenkins.canonical.com/unity-api-1/job/build-2-binpkg/arch=i386,release=yakkety/279/console

Click here to trigger a rebuild:
https://jenkins.canonical.com/unity-api-1/job/lp-keeper-ci/26/rebuild

review: Needs Fixing (continuous-integration)

Reply

Revision history for this message

Xavi Garcia (xavi-garcia-mena) wrote on 2016-08-25:

#

I see at least one of the builds failed due to this test:
[debug] Helper::StartBackup(n_bytes=513) (src/service/keeper.cpp:413)
04:57:57 [debug] id: "/tmp/helpers-test-failure-kbPVxd/storage-framework" (src/storage-framework/storage_framework_client.cpp:54)
04:57:57 [debug] time: QDateTime(2016-08-20 04:57:57.550 UTC Qt::TimeSpec(LocalTime)) (src/storage-framework/storage_framework_client.cpp:55)
04:57:57 [debug] waiting for worker thread to initialize (:0)
04:57:57 [debug] worker thread ready (:0)
04:57:57 [debug] getNewFileForBackup() returned socket 17 (src/service/keeper.cpp:420)
04:57:57 [debug] calling helper.set_storage_framework_socket(n_bytes=513 socket=17) (src/service/keeper.cpp:421)
04:57:57 [debug] changing state of helper 0x7fc5d07daae0 from "complete" to "started" (src/helper/helper.cpp:169)
04:57:57 [debug] Backup helper started (src/service/keeper.cpp:160)
04:57:57 wrote 512 bytes
04:57:57 [debug] upload_buffer_.size() is 512 after reading 512 from helper (src/helper/backup-helper.cpp:170)
04:57:57 [debug] upload_buffer_.size() is 0 after writing 512 to cloud (src/helper/backup-helper.cpp:183)
04:57:57 [debug] emitting percent-done-changed 0.998051 (src/helper/helper.cpp:308)
04:57:57 [CRITICAL] no task data for "" (src/service/keeper.cpp:263)
04:57:57 [debug] n_read 512 n_uploaded 512 (newly uploaded 512) (src/helper/backup-helper.cpp:154)
04:57:57 (process:13033): libdbustest-DEBUG: Waiting on name from DBusMock
04:57:57 (process:13033): libdbustest-DEBUG: Add object (org.linuxcontainers.cgmanager0_0) on '/org/linuxcontainers/cgmanager'
04:57:57 DBusMock : 1471669077.537 GetJobByName "untrusted-helper"
04:57:57 DBusMock : 1471669077.539 Start ["APP_ID=dekko.dekkoproject_dekko_0.6.20", "HELPER_TYPE=backup-helper", "APP_URIS='/��BUILDDIR��/keeper-0.0.1+yakkety349bzr118/obj-x86_64-linux-gnu/tests/fakes/fake-backup-helper-failure' '/tmp/helpers-test-failure-xaoaO7/Music'", "INSTANCE_ID=1471669077536689"] True
04:57:57 DBusMock : 1471669077.543 emit com.ubuntu.Upstart0_6.EventEmitted "stopped" ["JOB=untrusted-helper", "INSTANCE=backup-helper::dekko.dekkoproject_dekko_0.6.20"]
04:57:57 [debug] storage framework directory is "/tmp/helpers-test-failure-kbPVxd/storage-framework" (tests/integration/helpers/test-helpers-base.cpp:356)
04:57:57 /��BUILDDIR��/keeper-0.0.1+yakkety349bzr118/tests/integration/helpers/helpers-test-failure.cpp:86: Failure
04:57:57 Value of: state_values["action"].toString().toStdString()
04:57:57 Actual: "complete"
04:57:57 Expected: std::string{"failed"}
04:57:57 Which is: "failed"
04:57:57 [debug] joining with worker thread (:0)

the helper is in the "complete" state, when it shouldn't.
That's why I added an intermediate state DATA_COMPLETE to the helper in the branch:
lp:~xavi-garcia-mena/keeper/task-state-manager

The helper only reaches COMPLETE when we decide either to drop the uploader or when we finish it successfully.

I see at least one of the builds failed due to this test:
[debug] Helper::StartBackup(n_bytes=513) (src/service/keeper.cpp:413)
04:57:57 [debug] id: "/tmp/helpers-test-failure-kbPVxd/storage-framework" (src/storage-framework/storage_framework_client.cpp:54)
04:57:57 [debug] time: QDateTime(2016-08-20 04:57:57.550 UTC Qt::TimeSpec(LocalTime)) (src/storage-framework/storage_framework_client.cpp:55)
04:57:57 [debug] waiting for worker thread to initialize (:0)
04:57:57 [debug] worker thread ready (:0)
04:57:57 [debug] getNewFileForBackup() returned socket 17 (src/service/keeper.cpp:420)
04:57:57 [debug] calling helper.set_storage_framework_socket(n_bytes=513 socket=17) (src/service/keeper.cpp:421)
04:57:57 [debug] changing state of helper 0x7fc5d07daae0 from "complete" to "started" (src/helper/helper.cpp:169)
04:57:57 [debug] Backup helper started (src/service/keeper.cpp:160)
04:57:57 wrote 512 bytes
04:57:57 [debug] upload_buffer_.size() is 512 after reading 512 from helper (src/helper/backup-helper.cpp:170)
04:57:57 [debug] upload_buffer_.size() is 0 after writing 512 to cloud (src/helper/backup-helper.cpp:183)
04:57:57 [debug] emitting percent-done-changed 0.998051 (src/helper/helper.cpp:308)
04:57:57 [CRITICAL]  no task data for "" (src/service/keeper.cpp:263)
04:57:57 [debug] n_read 512 n_uploaded 512 (newly uploaded 512) (src/helper/backup-helper.cpp:154)
04:57:57 (process:13033): libdbustest-DEBUG: Waiting on name from DBusMock
04:57:57 (process:13033): libdbustest-DEBUG: Add object (org.linuxcontainers.cgmanager0_0) on '/org/linuxcontainers/cgmanager'
04:57:57 DBusMock  : 1471669077.537 GetJobByName "untrusted-helper"
04:57:57 DBusMock  : 1471669077.539 Start ["APP_ID=dekko.dekkoproject_dekko_0.6.20", "HELPER_TYPE=backup-helper", "APP_URIS='/��BUILDDIR��/keeper-0.0.1+yakkety349bzr118/obj-x86_64-linux-gnu/tests/fakes/fake-backup-helper-failure' '/tmp/helpers-test-failure-xaoaO7/Music'", "INSTANCE_ID=1471669077536689"] True
04:57:57 DBusMock  : 1471669077.543 emit com.ubuntu.Upstart0_6.EventEmitted "stopped" ["JOB=untrusted-helper", "INSTANCE=backup-helper::dekko.dekkoproject_dekko_0.6.20"]
04:57:57 [debug] storage framework directory is "/tmp/helpers-test-failure-kbPVxd/storage-framework" (tests/integration/helpers/test-helpers-base.cpp:356)
04:57:57 /��BUILDDIR��/keeper-0.0.1+yakkety349bzr118/tests/integration/helpers/helpers-test-failure.cpp:86: Failure
04:57:57 Value of: state_values["action"].toString().toStdString()
04:57:57   Actual: "complete"
04:57:57 Expected: std::string{"failed"}
04:57:57 Which is: "failed"
04:57:57 [debug] joining with worker thread (:0)

the helper is in the "complete" state, when it shouldn't.
That's why I added an intermediate state DATA_COMPLETE to the helper in the branch:
lp:~xavi-garcia-mena/keeper/task-state-manager

The helper only reaches COMPLETE when we decide either to drop the uploader or when we finish it successfully.

review: Needs Fixing

Reply

Unmerged revisions

118. By Charles Kerr on 2016-08-20: in test-helpers-base, cleanup the flag file before starting tests
117. By Charles Kerr on 2016-08-20: revert r115, r116 as a failed experiment since we have to trigger the upstart 'stopped' event ourselves
116. By Charles Kerr on 2016-08-20: in helpers-test-failure, use the new wait_for_tasks_to_finish() method
115. By Charles Kerr on 2016-08-20: in TestHelpersBase, add code to query Keeper and wait until all tasks are finished
114. By Charles Kerr on 2016-08-20: Change the helpers-test-failure integration test to write one byte too few instead of one byte too many. That way Keeper won't think the task is done and move to the next task before we can check the percent-done stats.

Keeper

Merge lp://qastaging/~charlesk/keeper/lp-1614657-fix-percent-done-error-in-helpers-test-failure into lp://qastaging/keeper/devel

Commit message

Description of the change

Unmerged revisions

Preview Diff

Subscribers