maidsafe-archive / MaidSafe

This is the super-project in which each MaidSafe library resides. Some information is common to all libraries, and is detailed here. Library-specific information can be found in each library's wiki.
Other
583 stars 101 forks source link

Running CreateUser repeatedly on local network fails (kSessionFailure) #80

Closed ghost closed 11 years ago

ghost commented 11 years ago

The test passes initially, but after approx. 3-5 runs, user creation consistently fails with result -207016 (kSessionFailure). This doesn't seem to depend on which test is run or on the amount of time between running tests.

Example output:

[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[==========] 1 test from OneUserApiTest
[ RUN      ] OneUserApiTest.FUNC_CreateLogoutLoginLogout
I 1 13:42:09.938269 lifestuff/rcs_helper.cc:80] Started PD client node.
E 2 13:42:32.738975 lifestuff/detail/user_credentials_impl.cc:667] Anmaid failed to store.
I 1 13:42:32.739092 lifestuff/detail/user_credentials_impl.cc:602] ANMID: -200003, ANSMID: -200003, ANTMID: -200003, PMID path: -200003
E 1 13:42:32.739152 lifestuff/detail/user_credentials_impl.cc:609] One of the operations for Anonymous Packets failed. Turn on INFO for feedback on which one. 
E 1 13:42:32.739195 lifestuff/detail/user_credentials_impl.cc:564] Failure to Store Anonymous packets: -207014
E 1 13:42:32.739235 lifestuff/detail/user_credentials_impl.cc:528] Failed processing signature packets: -207014
E 1 13:42:32.739277 lifestuff/lifestuff_impl.cc:287] Failed to Create User with result: -207016
E 1 13:42:32.739318 lifestuff/tests/api/api_test_resources.cc:299] Failed to create user: -207016
/home/alison/Development/Workspace/MaidSafe/src/lifestuff/src/maidsafe/lifestuff/tests/api/api_user_credentials_test.cc:46: Failure
Value of: DoFullCreateUser(test_elements, keyword_, pin_, password_)
  Actual: -207016
Expected: kSuccess
Which is: 0
I 1 13:42:32.739432 lifestuff/tests/api/api_test_resources.cc:339] About to stop messages and intros
E 1 13:42:32.739505 lifestuff/lifestuff_impl.cc:551] In unsuitable state to stop messages and intros: make sure user_credentials are logged in and drive is mounted.
E 1 13:42:32.739574 lifestuff/tests/api/api_test_resources.cc:342] Failed to start checking for messages and intros: -201002
/home/alison/Development/Workspace/MaidSafe/src/lifestuff/src/maidsafe/lifestuff/tests/api/api_user_credentials_test.cc:47: Failure
Value of: DoFullLogOut(test_elements)
  Actual: -201002
Expected: kSuccess
Which is: 0
I 1 13:42:32.750437 lifestuff/detail/routings_handler.cc:83] Cleared objects

I 1 13:42:33.100796 lifestuff/rcs_helper.cc:80] Started PD client node.
E 3 13:42:55.102071 lifestuff/detail/user_credentials_impl.cc:373] No MID found.
E 4 13:42:55.102245 lifestuff/detail/user_credentials_impl.cc:373] No SMID found.
I 1 13:42:55.102380 lifestuff/detail/user_credentials_impl.cc:322] mid_tmid_result: -207008 - true - true
I 1 13:42:55.102458 lifestuff/detail/user_credentials_impl.cc:324] smid_stmid_result: -207008 - true - true
I 1 13:42:55.102531 lifestuff/detail/user_credentials_impl.cc:329] User doesn't exist: cgZAeM, 5590
I 1 13:42:55.102601 lifestuff/detail/user_credentials_impl.cc:143] UserCredentialsImpl::LogIn - failed to get user info.
E 1 13:42:55.102679 lifestuff/tests/api/api_test_resources.cc:319] Failed to create log in: -207002
/home/alison/Development/Workspace/MaidSafe/src/lifestuff/src/maidsafe/lifestuff/tests/api/api_user_credentials_test.cc:52: Failure
Value of: DoFullLogIn(test_elements, keyword_, pin_, password_)
  Actual: -207002
Expected: kSuccess
Which is: 0
I 1 13:42:55.102838 lifestuff/tests/api/api_test_resources.cc:339] About to stop messages and intros
E 1 13:42:55.102909 lifestuff/lifestuff_impl.cc:551] In unsuitable state to stop messages and intros: make sure user_credentials are logged in and drive is mounted.
E 1 13:42:55.102977 lifestuff/tests/api/api_test_resources.cc:342] Failed to start checking for messages and intros: -201002
/home/alison/Development/Workspace/MaidSafe/src/lifestuff/src/maidsafe/lifestuff/tests/api/api_user_credentials_test.cc:53: Failure
Value of: DoFullLogOut(test_elements)
  Actual: -201002
Expected: kSuccess
Which is: 0
I 1 13:42:55.113472 lifestuff/detail/routings_handler.cc:83] Cleared objects

[  FAILED  ] OneUserApiTest.FUNC_CreateLogoutLoginLogout (46056 ms)
[----------] 1 test from OneUserApiTest (46056 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (46056 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] OneUserApiTest.FUNC_CreateLogoutLoginLogout

 1 FAILED TEST
Dan-Schmidt commented 11 years ago

Does the output from the vaults suggest that they have started refusing all operations for some reason? It seems from the test output that packets fail to store.

Fraser999 commented 11 years ago

Are you using the gtest_repeat command line arg to achieve repetition or just manually invoking the test repeatedly?

Also, does the test always pass if we use a fresh network each time?

ghost commented 11 years ago

Fraser: I have tried repeating the test using gtest_repeat, and also repeating it manually. Both follow the same pattern.

The test CreateLogoutLoginLogout always passes the first few times on a clean network.

Dan: I will try to find out.

ghost commented 11 years ago

As per Prakash's suggestion (https://basecamp.com/2074288/projects/1592290-lifestuff-dev/todos/23679938-issues-80-running) I set up a network using the qa.py script, started lifestuff_mgr manually and alternated running the qa script's extended vault test with running the CreateLogoutLoginLogout API test. The network was more durable this time, with user creation failing on the 5th and 10th attempts, and hanging on the 11th and 12th attempts. The extended vaults test (run with 3 chunks) started failing to store the keys and failing to start the clients from the 11th attempt. In both cases the later tests were slower than the earlier tests.

Output from 5th attempt of CreateLogoutLoginLogout:

I 1 15:55:42.689825 lifestuff/rcs_helper.cc:80] Started PD client node.
I 1 15:55:44.887294 lifestuff/detail/user_credentials_impl.cc:602] ANMID: 0, ANSMID: 0, ANTMID: 0, PMID path: 0
I 1 15:55:45.952618 lifestuff/detail/user_credentials_impl.cc:771] MID: 0, SMID: 0, TMID: 0, STMID: 0
I 1 15:55:50.967581 lifestuff/lifestuff_impl.cc:291] user_credentials_->CreateUser success.
I 1 15:55:51.919823 lifestuff/lifestuff_impl.cc:301] CreateVaultInLocalMachine success.
E 1 15:58:51.987425 lifestuff/lifestuff_impl.cc:1212] Failed to start client container: -1
E 1 15:58:51.987532 lifestuff/lifestuff_impl.cc:307] Failed to set valid PMID with result: -1
E 1 15:58:51.987606 lifestuff/tests/api/api_test_resources.cc:299] Failed to create user: -1
/home/alison/Development/Workspace/MaidSafe/src/lifestuff/src/maidsafe/lifestuff/tests/api/api_user_credentials_test.cc:46: Failure
Value of: DoFullCreateUser(test_elements, keyword_, pin_, password_)
  Actual: -1
Expected: kSuccess
Which is: 0

Output from the 10th attempt of CreateLogoutLoginLogout:

I 1 16:09:13.643904 lifestuff/rcs_helper.cc:80] Started PD client node.
I 1 16:09:16.534344 lifestuff/detail/user_credentials_impl.cc:602] ANMID: 0, ANSMID: 0, ANTMID: 0, PMID path: 0
I 1 16:09:17.697535 lifestuff/detail/user_credentials_impl.cc:771] MID: 0, SMID: 0, TMID: 0, STMID: 0
I 1 16:09:22.714797 lifestuff/lifestuff_impl.cc:291] user_credentials_->CreateUser success.
E 1 16:10:22.720983 lifestuff/lifestuff_impl.cc:1276] Failed to create vault through client controller.
E 1 16:10:22.721083 lifestuff/lifestuff_impl.cc:298] Failed to create vault. No LifeStuff for you! (Result: -201034)
E 1 16:10:22.721125 lifestuff/tests/api/api_test_resources.cc:299] Failed to create user: -201034
/home/alison/Development/Workspace/MaidSafe/src/lifestuff/src/maidsafe/lifestuff/tests/api/api_user_credentials_test.cc:46: Failure
Value of: DoFullCreateUser(test_elements, keyword_, pin_, password_)
  Actual: -201034
Expected: kSuccess
Which is: 0

I have started looking at the vault output from a new network. Again, the CreateLogoutLoginLogout test seems fine for the first few attempts.

ghost commented 11 years ago

Yesterday I ran a network of 12 vaults using qa.py, and started lifestuff_mgr manually. I manually ran CreateLogoutLoginLogout eleven times (still on the api_fixtures branch of LifeStuff), and encountered failures on the 5th, 9th, 10th and 11th runs.

E 7 17:06:31.870949 pd/vault/chunk_service.cc:789] OnChunkGot - 906152..a2f486 - Failed to retrieve chunk dz2ryr6..nrjw4ic~MBO

The above error message occurred a couple of times around the middle of each vault's output, and occurred several times near the end of the output. There seems to be a (rather weak) correlation between the failing tests and the appearance of this error. I know it's a flimsy correlation, and I can't currently say what's causing the error, but I'd rather mention it than not.

I didn't notice anything outstanding in the rest of the vaults' output; I intend to investigate vault output more thoroughly.

ghost commented 11 years ago

This morning I repeatedly ran the extended vaults test (from vault.py) against a network and lifestuff_manager. I used 3 chunks each time, and left approx. 1 minute between runs. The test ran successfully for 38 attempts, and the amount of time for each run seemed consistent. I ran CreateLogoutLoginLogout successfully after the 30th and 38th runs of the vaults test. I stopped repeating the test out of choice; I didn't encounter any problems with it.

Comparing this to the results of repeatedly running CreateLogoutLoginLogout against a network, it seems that creating a user and logging in/out has a negative effect on the network, but running the extended vaults test (which stores/retrieves/modifies/retrieves/deletes... etc.) doesn't have an impact on the network's robustness.