Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

create '_users' database for singleton mode:"The database could not be created, the file already exists. #4236

Closed
axiqia opened this issue Jan 25, 2019 · 6 comments · Fixed by #4250 or #4262
Closed

create '_users' database for singleton mode:"The database could not be created, the file already exists. #4236

axiqia opened this issue Jan 25, 2019 · 6 comments · Fixed by #4250 or #4262
Labels
couchdb

Comments

@axiqia
Copy link
Contributor

axiqia commented Jan 25, 2019

Environment details:

  • local deployment, native ubuntu
  • Docker version 18.09.1, ubuntu 16.04

Steps to reproduce the issue:

$ ansible-playbook -i environments/local setup.yml  

PLAY [localhost] ***********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  15:27:46 +0800 (0:00:00.166)       0:00:00.166 ******** 
ok: [localhost]

TASK [gen hosts if 'local' env is used] ************************************************************
Friday 25 January 2019  15:27:48 +0800 (0:00:01.824)       0:00:01.990 ******** 
ok: [localhost -> localhost]

TASK [find the ip of docker-machine] ***************************************************************
Friday 25 January 2019  15:27:49 +0800 (0:00:01.164)       0:00:03.155 ******** 
skipping: [localhost]

TASK [get the docker-machine ip] *******************************************************************
Friday 25 January 2019  15:27:49 +0800 (0:00:00.073)       0:00:03.228 ******** 
skipping: [localhost]

TASK [gen hosts for docker-machine] ****************************************************************
Friday 25 January 2019  15:27:50 +0800 (0:00:00.105)       0:00:03.334 ******** 
skipping: [localhost]

TASK [check if db_local.ini exists?] ***************************************************************
Friday 25 January 2019  15:27:50 +0800 (0:00:00.086)       0:00:03.420 ******** 
ok: [localhost]

TASK [prepare db_local.ini] ************************************************************************
Friday 25 January 2019  15:27:50 +0800 (0:00:00.485)       0:00:03.905 ******** 
skipping: [localhost]

TASK [gen untrusted server certificate for host] ***************************************************
Friday 25 January 2019  15:27:50 +0800 (0:00:00.110)       0:00:04.016 ******** 
changed: [localhost -> localhost]

TASK [gen untrusted client certificate for host] ***************************************************
Friday 25 January 2019  15:27:51 +0800 (0:00:01.042)       0:00:05.059 ******** 
changed: [localhost -> localhost]

TASK [clean up old kafka keystore] *****************************************************************
Friday 25 January 2019  15:27:53 +0800 (0:00:01.616)       0:00:06.675 ******** 
skipping: [localhost]

TASK [ensure kafka files directory exists] *********************************************************
Friday 25 January 2019  15:27:53 +0800 (0:00:00.076)       0:00:06.752 ******** 
skipping: [localhost]

TASK [generate kafka certificates] *****************************************************************
Friday 25 January 2019  15:27:53 +0800 (0:00:00.116)       0:00:06.868 ******** 
skipping: [localhost]

TASK [ensure controller files directory exists] ****************************************************
Friday 25 January 2019  15:27:53 +0800 (0:00:00.068)       0:00:06.937 ******** 
ok: [localhost]

TASK [generate controller certificates] ************************************************************
Friday 25 January 2019  15:27:54 +0800 (0:00:00.916)       0:00:07.853 ******** 
changed: [localhost -> localhost]

TASK [ensure invoker files directory exists] *******************************************************
Friday 25 January 2019  15:27:56 +0800 (0:00:01.540)       0:00:09.394 ******** 
ok: [localhost]

TASK [generate invoker certificates] ***************************************************************
Friday 25 January 2019  15:27:56 +0800 (0:00:00.882)       0:00:10.277 ******** 
changed: [localhost -> localhost]

PLAY RECAP *****************************************************************************************
localhost                  : ok=9    changed=4    unreachable=0    failed=0   

Friday 25 January 2019  15:27:58 +0800 (0:00:01.380)       0:00:11.657 ******** 
=============================================================================== 
Gathering Facts ----------------------------------------------------------------------------- 1.82s
gen untrusted client certificate for host --------------------------------------------------- 1.62s
generate controller certificates ------------------------------------------------------------ 1.54s
generate invoker certificates --------------------------------------------------------------- 1.38s
gen hosts if 'local' env is used ------------------------------------------------------------ 1.16s
gen untrusted server certificate for host --------------------------------------------------- 1.04s
ensure controller files directory exists ---------------------------------------------------- 0.92s
ensure invoker files directory exists ------------------------------------------------------- 0.88s
check if db_local.ini exists? --------------------------------------------------------------- 0.49s
ensure kafka files directory exists --------------------------------------------------------- 0.12s
prepare db_local.ini ------------------------------------------------------------------------ 0.11s
get the docker-machine ip ------------------------------------------------------------------- 0.11s
gen hosts for docker-machine ---------------------------------------------------------------- 0.09s
clean up old kafka keystore ----------------------------------------------------------------- 0.08s
find the ip of docker-machine --------------------------------------------------------------- 0.07s
generate kafka certificates ----------------------------------------------------------------- 0.07s

$ ansible-playbook -i environments/local prereq.yml --ask-sudo-pass
[DEPRECATION WARNING]: The sudo command line option has been deprecated in favor of the "become" 
command line arguments. This feature will be removed in version 2.6. Deprecation warnings can be 
disabled by setting deprecation_warnings=False in ansible.cfg.
SUDO password: 

PLAY [all:!ansible] ********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  15:29:41 +0800 (0:00:00.157)       0:00:00.157 ******** 
ok: [172.17.0.1]

TASK [prereq : check for pip] **********************************************************************
Friday 25 January 2019  15:29:42 +0800 (0:00:01.651)       0:00:01.809 ******** 
changed: [172.17.0.1]

TASK [prereq : install pip] ************************************************************************
Friday 25 January 2019  15:29:44 +0800 (0:00:01.638)       0:00:03.448 ******** 
skipping: [172.17.0.1]

TASK [prereq : install requests] *******************************************************************
Friday 25 January 2019  15:29:44 +0800 (0:00:00.073)       0:00:03.522 ******** 
ok: [172.17.0.1]

TASK [prereq : install docker for python] **********************************************************
Friday 25 January 2019  15:29:45 +0800 (0:00:01.082)       0:00:04.604 ******** 
ok: [172.17.0.1]

TASK [prereq : install httplib2] *******************************************************************
Friday 25 January 2019  15:29:46 +0800 (0:00:00.929)       0:00:05.534 ******** 
ok: [172.17.0.1]

TASK [prereq : remove requests] ********************************************************************
Friday 25 January 2019  15:29:47 +0800 (0:00:00.961)       0:00:06.496 ******** 
skipping: [172.17.0.1]

TASK [prereq : remove docker] **********************************************************************
Friday 25 January 2019  15:29:47 +0800 (0:00:00.068)       0:00:06.564 ******** 
skipping: [172.17.0.1]

TASK [prereq : remove httplib2] ********************************************************************
Friday 25 January 2019  15:29:47 +0800 (0:00:00.068)       0:00:06.632 ******** 
skipping: [172.17.0.1]

PLAY [all:!ansible] ********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  15:29:47 +0800 (0:00:00.051)       0:00:06.683 ******** 
ok: [controller0]

TASK [prereq : check for pip] **********************************************************************
Friday 25 January 2019  15:29:49 +0800 (0:00:01.160)       0:00:07.844 ******** 
changed: [controller0]

TASK [prereq : install pip] ************************************************************************
Friday 25 January 2019  15:29:50 +0800 (0:00:01.380)       0:00:09.224 ******** 
skipping: [controller0]

TASK [prereq : install requests] *******************************************************************
Friday 25 January 2019  15:29:50 +0800 (0:00:00.068)       0:00:09.292 ******** 
ok: [controller0]

TASK [prereq : install docker for python] **********************************************************
Friday 25 January 2019  15:29:51 +0800 (0:00:00.919)       0:00:10.212 ******** 
ok: [controller0]

TASK [prereq : install httplib2] *******************************************************************
Friday 25 January 2019  15:29:52 +0800 (0:00:00.973)       0:00:11.186 ******** 
ok: [controller0]

TASK [prereq : remove requests] ********************************************************************
Friday 25 January 2019  15:29:53 +0800 (0:00:00.932)       0:00:12.118 ******** 
skipping: [controller0]

TASK [prereq : remove docker] **********************************************************************
Friday 25 January 2019  15:29:53 +0800 (0:00:00.104)       0:00:12.223 ******** 
skipping: [controller0]

TASK [prereq : remove httplib2] ********************************************************************
Friday 25 January 2019  15:29:53 +0800 (0:00:00.065)       0:00:12.288 ******** 
skipping: [controller0]

PLAY [all:!ansible] ********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  15:29:53 +0800 (0:00:00.050)       0:00:12.339 ******** 
ok: [invoker0]

TASK [prereq : check for pip] **********************************************************************
Friday 25 January 2019  15:29:54 +0800 (0:00:01.146)       0:00:13.486 ******** 
changed: [invoker0]

TASK [prereq : install pip] ************************************************************************
Friday 25 January 2019  15:29:56 +0800 (0:00:01.482)       0:00:14.968 ******** 
skipping: [invoker0]

TASK [prereq : install requests] *******************************************************************
Friday 25 January 2019  15:29:56 +0800 (0:00:00.071)       0:00:15.040 ******** 
ok: [invoker0]

TASK [prereq : install docker for python] **********************************************************
Friday 25 January 2019  15:29:57 +0800 (0:00:00.877)       0:00:15.918 ******** 
ok: [invoker0]

TASK [prereq : install httplib2] *******************************************************************
Friday 25 January 2019  15:29:58 +0800 (0:00:00.945)       0:00:16.864 ******** 
ok: [invoker0]

TASK [prereq : remove requests] ********************************************************************
Friday 25 January 2019  15:29:58 +0800 (0:00:00.920)       0:00:17.784 ******** 
skipping: [invoker0]

TASK [prereq : remove docker] **********************************************************************
Friday 25 January 2019  15:29:59 +0800 (0:00:00.073)       0:00:17.858 ******** 
skipping: [invoker0]

TASK [prereq : remove httplib2] ********************************************************************
Friday 25 January 2019  15:29:59 +0800 (0:00:00.071)       0:00:17.930 ******** 
skipping: [invoker0]

PLAY [all:!ansible] ********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  15:29:59 +0800 (0:00:00.050)       0:00:17.981 ******** 
ok: [kafka0]

TASK [prereq : check for pip] **********************************************************************
Friday 25 January 2019  15:30:00 +0800 (0:00:01.156)       0:00:19.137 ******** 
changed: [kafka0]

TASK [prereq : install pip] ************************************************************************
Friday 25 January 2019  15:30:01 +0800 (0:00:01.512)       0:00:20.650 ******** 
skipping: [kafka0]

TASK [prereq : install requests] *******************************************************************
Friday 25 January 2019  15:30:01 +0800 (0:00:00.071)       0:00:20.721 ******** 
ok: [kafka0]

TASK [prereq : install docker for python] **********************************************************
Friday 25 January 2019  15:30:02 +0800 (0:00:00.941)       0:00:21.663 ******** 
ok: [kafka0]

TASK [prereq : install httplib2] *******************************************************************
Friday 25 January 2019  15:30:03 +0800 (0:00:00.944)       0:00:22.607 ******** 
ok: [kafka0]

TASK [prereq : remove requests] ********************************************************************
Friday 25 January 2019  15:30:04 +0800 (0:00:00.917)       0:00:23.525 ******** 
skipping: [kafka0]

TASK [prereq : remove docker] **********************************************************************
Friday 25 January 2019  15:30:04 +0800 (0:00:00.065)       0:00:23.590 ******** 
skipping: [kafka0]

TASK [prereq : remove httplib2] ********************************************************************
Friday 25 January 2019  15:30:04 +0800 (0:00:00.104)       0:00:23.695 ******** 
skipping: [kafka0]

PLAY RECAP *****************************************************************************************
172.17.0.1                 : ok=5    changed=1    unreachable=0    failed=0   
controller0                : ok=5    changed=1    unreachable=0    failed=0   
invoker0                   : ok=5    changed=1    unreachable=0    failed=0   
kafka0                     : ok=5    changed=1    unreachable=0    failed=0   

Friday 25 January 2019  15:30:04 +0800 (0:00:00.029)       0:00:23.724 ******** 
=============================================================================== 
Gathering Facts ----------------------------------------------------------------------------- 1.65s
prereq : check for pip ---------------------------------------------------------------------- 1.51s
Gathering Facts ----------------------------------------------------------------------------- 1.16s
Gathering Facts ----------------------------------------------------------------------------- 1.16s
Gathering Facts ----------------------------------------------------------------------------- 1.15s
prereq : install docker for python ---------------------------------------------------------- 0.94s
prereq : install requests ------------------------------------------------------------------- 0.94s
prereq : install httplib2 ------------------------------------------------------------------- 0.92s
prereq : remove docker ---------------------------------------------------------------------- 0.10s
prereq : install pip ------------------------------------------------------------------------ 0.07s
prereq : remove requests -------------------------------------------------------------------- 0.07s
prereq : remove httplib2 -------------------------------------------------------------------- 0.03s

$ ansible-playbook -i environments/local couchdb.yml               

PLAY [db] ******************************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  15:30:15 +0800 (0:00:00.178)       0:00:00.178 ******** 
ok: [172.17.0.1]

TASK [couchdb : set the coordinator to the first node] *********************************************
Friday 25 January 2019  15:30:17 +0800 (0:00:01.693)       0:00:01.871 ******** 
ok: [172.17.0.1]

TASK [couchdb : Set the volumes] *******************************************************************
Friday 25 January 2019  15:30:17 +0800 (0:00:00.105)       0:00:01.977 ******** 
ok: [172.17.0.1]

TASK [couchdb : check if db credentials are valid for CouchDB] *************************************
Friday 25 January 2019  15:30:17 +0800 (0:00:00.104)       0:00:02.082 ******** 
skipping: [172.17.0.1]

TASK [couchdb : check for persistent disk] *********************************************************
Friday 25 January 2019  15:30:17 +0800 (0:00:00.140)       0:00:02.222 ******** 
skipping: [172.17.0.1]

TASK [couchdb : set the volume_dir] ****************************************************************
Friday 25 January 2019  15:30:17 +0800 (0:00:00.073)       0:00:02.295 ******** 
skipping: [172.17.0.1]

TASK [couchdb : include_tasks] *********************************************************************
Friday 25 January 2019  15:30:17 +0800 (0:00:00.070)       0:00:02.366 ******** 
skipping: [172.17.0.1]

TASK [couchdb : set the erlang cookie volume] ******************************************************
Friday 25 January 2019  15:30:18 +0800 (0:00:00.135)       0:00:02.501 ******** 
skipping: [172.17.0.1]

TASK [couchdb : (re)start CouchDB from 'apache/couchdb:2.1 '] **************************************
Friday 25 January 2019  15:30:18 +0800 (0:00:00.134)       0:00:02.635 ******** 
changed: [172.17.0.1]

TASK [couchdb : wait until CouchDB in this host is up and running] *********************************
Friday 25 January 2019  15:30:21 +0800 (0:00:03.340)       0:00:05.976 ******** 
ok: [172.17.0.1]

TASK [couchdb : create '_users' database for singleton mode] ***************************************
Friday 25 January 2019  15:30:22 +0800 (0:00:00.653)       0:00:06.630 ******** 
fatal: [172.17.0.1]: FAILED! => {"cache_control": "must-revalidate", "changed": false, "connection": "close", "content": "{\"error\":\"file_exists\",\"reason\":\"The database could not be created, the file already exists.\"}\n", "content_length": "95", "content_type": "application/json", "date": "Fri, 25 Jan 2019 07:30:22 GMT", "json": {"error": "file_exists", "reason": "The database could not be created, the file already exists."}, "msg": "Status code was 412 and not [201]: HTTP Error 412: Precondition Failed", "redirected": false, "server": "CouchDB/2.1.2 (Erlang OTP/17)", "status": 412, "url": "http://172.17.0.1:5984/_users", "x_couch_request_id": "e5d81bdf5a", "x_couchdb_body_time": "0"}

Status code was 412 and not [201]: HTTP Error 412: Precondition Failed

PLAY RECAP *****************************************************************************************
172.17.0.1                 : ok=5    changed=1    unreachable=0    failed=1   

Friday 25 January 2019  15:30:22 +0800 (0:00:00.392)       0:00:07.022 ******** 
=============================================================================== 
couchdb : (re)start CouchDB from 'apache/couchdb:2.1 '  ------------------------------------- 3.34s
Gathering Facts ----------------------------------------------------------------------------- 1.69s
couchdb : wait until CouchDB in this host is up and running --------------------------------- 0.65s
couchdb : create '_users' database for singleton mode --------------------------------------- 0.39s
couchdb : check if db credentials are valid for CouchDB ------------------------------------- 0.14s
couchdb : include_tasks --------------------------------------------------------------------- 0.14s
couchdb : set the erlang cookie volume ------------------------------------------------------ 0.13s
couchdb : set the coordinator to the first node --------------------------------------------- 0.11s
couchdb : Set the volumes ------------------------------------------------------------------- 0.10s
couchdb : check for persistent disk --------------------------------------------------------- 0.07s
couchdb : set the volume_dir ---------------------------------------------------------------- 0.07s
@axiqia
Copy link
Contributor Author

axiqia commented Jan 25, 2019

The distributed deploy command restart kernel and some containers cannot restart, so I try to redeploy from begin, then I got above issue.

@axiqia
Copy link
Contributor Author

axiqia commented Jan 25, 2019

additional：
After a retry, there is a different result.

$ ansible-playbook -i environments/local couchdb.yml               

PLAY [db] ******************************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  16:10:20 +0800 (0:00:00.177)       0:00:00.177 ******** 
ok: [172.17.0.1]

TASK [couchdb : set the coordinator to the first node] *********************************************
Friday 25 January 2019  16:10:21 +0800 (0:00:01.653)       0:00:01.830 ******** 
ok: [172.17.0.1]

TASK [couchdb : Set the volumes] *******************************************************************
Friday 25 January 2019  16:10:21 +0800 (0:00:00.104)       0:00:01.935 ******** 
ok: [172.17.0.1]

TASK [couchdb : check if db credentials are valid for CouchDB] *************************************
Friday 25 January 2019  16:10:21 +0800 (0:00:00.100)       0:00:02.036 ******** 
skipping: [172.17.0.1]

TASK [couchdb : check for persistent disk] *********************************************************
Friday 25 January 2019  16:10:22 +0800 (0:00:00.140)       0:00:02.176 ******** 
skipping: [172.17.0.1]

TASK [couchdb : set the volume_dir] ****************************************************************
Friday 25 January 2019  16:10:22 +0800 (0:00:00.073)       0:00:02.249 ******** 
skipping: [172.17.0.1]

TASK [couchdb : include_tasks] *********************************************************************
Friday 25 January 2019  16:10:22 +0800 (0:00:00.074)       0:00:02.324 ******** 
skipping: [172.17.0.1]

TASK [couchdb : set the erlang cookie volume] ******************************************************
Friday 25 January 2019  16:10:22 +0800 (0:00:00.130)       0:00:02.454 ******** 
skipping: [172.17.0.1]

TASK [couchdb : (re)start CouchDB from 'apache/couchdb:2.1 '] **************************************
Friday 25 January 2019  16:10:22 +0800 (0:00:00.136)       0:00:02.591 ******** 
changed: [172.17.0.1]

TASK [couchdb : wait until CouchDB in this host is up and running] *********************************
Friday 25 January 2019  16:10:26 +0800 (0:00:04.108)       0:00:06.699 ******** 
FAILED - RETRYING: wait until CouchDB in this host is up and running (12 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (11 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (10 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (9 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (8 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (7 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (6 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (5 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (4 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (3 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (2 retries left).
FAILED - RETRYING: wait until CouchDB in this host is up and running (1 retries left).
fatal: [172.17.0.1]: FAILED! => {"attempts": 12, "changed": false, "content": "", "msg": "Status code was -1 and not [200]: Connection failure: timed out", "redirected": false, "status": -1, "url": "http://172.17.0.1:5984/_utils/"}

Status code was -1 and not [200]: Connection failure: timed out

PLAY RECAP *****************************************************************************************
172.17.0.1                 : ok=4    changed=1    unreachable=0    failed=1   

Friday 25 January 2019  16:17:30 +0800 (0:07:04.114)       0:07:10.814 ******** 
=============================================================================== 
couchdb : wait until CouchDB in this host is up and running ------------------------------- 424.11s
couchdb : (re)start CouchDB from 'apache/couchdb:2.1 '  ------------------------------------- 4.11s
Gathering Facts ----------------------------------------------------------------------------- 1.65s
couchdb : check if db credentials are valid for CouchDB ------------------------------------- 0.14s
couchdb : set the erlang cookie volume ------------------------------------------------------ 0.14s
couchdb : include_tasks --------------------------------------------------------------------- 0.13s
couchdb : set the coordinator to the first node --------------------------------------------- 0.10s
couchdb : Set the volumes ------------------------------------------------------------------- 0.10s
couchdb : set the volume_dir ---------------------------------------------------------------- 0.07s
couchdb : check for persistent disk --------------------------------------------------------- 0.07s

@axiqia
Copy link
Contributor Author

axiqia commented Jan 25, 2019

Moreover, when i first run openwhisk.yml on another host machine, it seems that i cannot connect to couchdb. So i ran curl 172.17.0.1:5984/whisk_local_whisks, of course it failed and told me Connection reset by peer.
Before this step, build and deploy went well.

$ ansible-playbook -i environments/local openwhisk.yml -e invoker_use_runc=False

PLAY [zookeepers] **********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  16:48:52 +0800 (0:00:00.120)       0:00:00.120 ******** 
ok: [kafka0]

TASK [zookeeper : pull the zookeeper:3.4 image] ****************************************************
Friday 25 January 2019  16:48:53 +0800 (0:00:01.241)       0:00:01.361 ******** 
changed: [kafka0]

TASK [zookeeper : (re)start zookeeper] *************************************************************
Friday 25 January 2019  16:48:55 +0800 (0:00:01.326)       0:00:02.687 ******** 
changed: [kafka0]

TASK [zookeeper : wait until the Zookeeper in this host is up and running] *************************
Friday 25 January 2019  16:48:57 +0800 (0:00:02.296)       0:00:04.984 ******** 
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (36 retries left).
changed: [kafka0]

TASK [zookeeper : remove old zookeeper] ************************************************************
Friday 25 January 2019  16:49:04 +0800 (0:00:07.360)       0:00:12.344 ******** 
skipping: [kafka0]

TASK [zookeeper : remove zookeeper] ****************************************************************
Friday 25 January 2019  16:49:04 +0800 (0:00:00.044)       0:00:12.389 ******** 
skipping: [kafka0]

PLAY [kafkas] **************************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  16:49:04 +0800 (0:00:00.049)       0:00:12.439 ******** 
ok: [kafka0]

TASK [kafka : create kafka certificate directory] **************************************************
Friday 25 January 2019  16:49:05 +0800 (0:00:00.800)       0:00:13.240 ******** 
ok: [kafka0]

TASK [kafka : copy keystore] ***********************************************************************
Friday 25 January 2019  16:49:06 +0800 (0:00:00.346)       0:00:13.586 ******** 
skipping: [kafka0]

TASK [kafka : add kafka default env vars] **********************************************************
Friday 25 January 2019  16:49:06 +0800 (0:00:00.049)       0:00:13.636 ******** 
ok: [kafka0]

TASK [kafka : add kafka non-ssl vars] **************************************************************
Friday 25 January 2019  16:49:06 +0800 (0:00:00.324)       0:00:13.960 ******** 
ok: [kafka0]

TASK [kafka : add kafka ssl env vars] **************************************************************
Friday 25 January 2019  16:49:06 +0800 (0:00:00.078)       0:00:14.038 ******** 
skipping: [kafka0]

TASK [kafka : join kafka ssl env vars] *************************************************************
Friday 25 January 2019  16:49:06 +0800 (0:00:00.050)       0:00:14.089 ******** 
skipping: [kafka0]

TASK [kafka : join kafka non-ssl env vars] *********************************************************
Friday 25 January 2019  16:49:06 +0800 (0:00:00.049)       0:00:14.139 ******** 
ok: [kafka0]

TASK [kafka : (re)start kafka using 'wurstmeister/kafka:0.11.0.1'] *********************************
Friday 25 January 2019  16:49:06 +0800 (0:00:00.095)       0:00:14.234 ******** 
changed: [kafka0]

TASK [kafka : wait until the kafka server started up] **********************************************
Friday 25 January 2019  16:49:09 +0800 (0:00:03.099)       0:00:17.334 ******** 
FAILED - RETRYING: wait until the kafka server started up (10 retries left).
changed: [kafka0]

TASK [kafka : remove old kafka] ********************************************************************
Friday 25 January 2019  16:49:17 +0800 (0:00:07.588)       0:00:24.922 ******** 
skipping: [kafka0]

TASK [kafka : remove kafka] ************************************************************************
Friday 25 January 2019  16:49:17 +0800 (0:00:00.044)       0:00:24.967 ******** 
skipping: [kafka0]

PLAY [controllers] *********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  16:49:17 +0800 (0:00:00.042)       0:00:25.009 ******** 
ok: [controller0]

TASK [controller : docker login] *******************************************************************
Friday 25 January 2019  16:49:18 +0800 (0:00:00.793)       0:00:25.803 ******** 
skipping: [controller0]

TASK [controller : get controller name and index] **************************************************
Friday 25 January 2019  16:49:18 +0800 (0:00:00.045)       0:00:25.848 ******** 
ok: [controller0]

TASK [controller : pull the latest image of controller] ********************************************
Friday 25 January 2019  16:49:18 +0800 (0:00:00.081)       0:00:25.930 ******** 
skipping: [controller0]

TASK [controller : ensure controller log directory is created with permissions] ********************
Friday 25 January 2019  16:49:18 +0800 (0:00:00.043)       0:00:25.973 ******** 
ok: [controller0]

TASK [controller : ensure controller log file is created with permissions] *************************
Friday 25 January 2019  16:49:18 +0800 (0:00:00.227)       0:00:26.201 ******** 
skipping: [controller0]

TASK [controller : ensure controller config directory is created with permissions] *****************
Friday 25 January 2019  16:49:18 +0800 (0:00:00.051)       0:00:26.252 ******** 
ok: [controller0]

TASK [controller : copy jmxremote password file] ***************************************************
Friday 25 January 2019  16:49:19 +0800 (0:00:00.531)       0:00:26.784 ******** 
ok: [controller0]

TASK [controller : copy jmxremote access file] *****************************************************
Friday 25 January 2019  16:49:19 +0800 (0:00:00.723)       0:00:27.507 ******** 
ok: [controller0]

TASK [controller : copy kafka truststore/keystore] *************************************************
Friday 25 January 2019  16:49:20 +0800 (0:00:00.596)       0:00:28.104 ******** 
skipping: [controller0]

TASK [controller : copy nginx certificate keystore] ************************************************
Friday 25 January 2019  16:49:20 +0800 (0:00:00.050)       0:00:28.154 ******** 
changed: [controller0]

TASK [controller : copy certificates] **************************************************************
Friday 25 January 2019  16:49:21 +0800 (0:00:01.040)       0:00:29.195 ******** 
changed: [controller0] => (item=controller-openwhisk-server-cert.pem)
changed: [controller0] => (item=controller-openwhisk-server-key.pem)

TASK [controller : check, that required databases exist] *******************************************
Friday 25 January 2019  16:49:23 +0800 (0:00:01.570)       0:00:30.766 ******** 
included: /home/openwhisk/openwhisk/ansible/tasks/db/checkDb.yml for controller0
included: /home/openwhisk/openwhisk/ansible/tasks/db/checkDb.yml for controller0
included: /home/openwhisk/openwhisk/ansible/tasks/db/checkDb.yml for controller0

TASK [controller : check if whisk_local_whisks with CouchDB exists] ********************************
Friday 25 January 2019  16:49:23 +0800 (0:00:00.255)       0:00:31.022 ******** 
ok: [controller0]

TASK [controller : check if whisk_local_subjects with CouchDB exists] ******************************
Friday 25 January 2019  16:49:23 +0800 (0:00:00.480)       0:00:31.502 ******** 
ok: [controller0]

TASK [controller : check if whisk_local_activations with CouchDB exists] ***************************
Friday 25 January 2019  16:49:24 +0800 (0:00:00.356)       0:00:31.859 ******** 
ok: [controller0]

TASK [controller : prepare controller port] ********************************************************
Friday 25 January 2019  16:49:24 +0800 (0:00:00.322)       0:00:32.181 ******** 
ok: [controller0]

TASK [controller : expose additional ports if jmxremote is enabled] ********************************
Friday 25 January 2019  16:49:24 +0800 (0:00:00.337)       0:00:32.519 ******** 
ok: [controller0]

TASK [controller : populate environment variables for controller] **********************************
Friday 25 January 2019  16:49:25 +0800 (0:00:00.338)       0:00:32.857 ******** 
ok: [controller0]

TASK [controller : merge extra env variables] ******************************************************
Friday 25 January 2019  16:49:25 +0800 (0:00:00.680)       0:00:33.538 ******** 
ok: [controller0]

TASK [controller : populate volumes for controller] ************************************************
Friday 25 January 2019  16:49:26 +0800 (0:00:00.345)       0:00:33.883 ******** 
ok: [controller0]

TASK [controller : check if coverage collection is enabled] ****************************************
Friday 25 January 2019  16:49:26 +0800 (0:00:00.333)       0:00:34.217 ******** 
skipping: [controller0]

TASK [controller : ensure controller coverage directory is created with permissions] ***************
Friday 25 January 2019  16:49:26 +0800 (0:00:00.053)       0:00:34.270 ******** 
skipping: [controller0] => (item=controller) 
skipping: [controller0] => (item=common) 

TASK [controller : extend controller volume for coverage] ******************************************
Friday 25 January 2019  16:49:26 +0800 (0:00:00.074)       0:00:34.344 ******** 
skipping: [controller0]

TASK [controller : include plugins] ****************************************************************
Friday 25 January 2019  16:49:26 +0800 (0:00:00.048)       0:00:34.393 ******** 
included: /home/openwhisk/openwhisk/ansible/roles/controller/tasks/join_akka_cluster.yml for controller0

TASK [controller : add akka port to ports_to_expose] ***********************************************
Friday 25 January 2019  16:49:26 +0800 (0:00:00.088)       0:00:34.482 ******** 
ok: [controller0]

TASK [controller : add seed nodes to controller environment] ***************************************
Friday 25 January 2019  16:49:27 +0800 (0:00:00.335)       0:00:34.817 ******** 
ok: [controller0] => (item=[0, '172.17.0.1'])

TASK [controller : Add akka environment to controller environment] *********************************
Friday 25 January 2019  16:49:27 +0800 (0:00:00.435)       0:00:35.253 ******** 
ok: [controller0]

TASK [controller : (re)start controller] ***********************************************************
Friday 25 January 2019  16:49:28 +0800 (0:00:00.370)       0:00:35.623 ******** 
changed: [controller0]

TASK [controller : wait until the Controller in this host is up and running] ***********************
Friday 25 January 2019  16:49:30 +0800 (0:00:02.014)       0:00:37.638 ******** 
FAILED - RETRYING: wait until the Controller in this host is up and running (12 retries left).
FAILED - RETRYING: wait until the Controller in this host is up and running (11 retries left).
ok: [controller0]

TASK [controller : get controller name] ************************************************************
Friday 25 January 2019  16:49:41 +0800 (0:00:11.203)       0:00:48.841 ******** 
skipping: [controller0]

TASK [controller : remove controller] **************************************************************
Friday 25 January 2019  16:49:41 +0800 (0:00:00.047)       0:00:48.889 ******** 
skipping: [controller0]

TASK [controller : remove controller log directory] ************************************************
Friday 25 January 2019  16:49:41 +0800 (0:00:00.055)       0:00:48.944 ******** 
skipping: [controller0]

TASK [controller : remove controller conf directory] ***********************************************
Friday 25 January 2019  16:49:41 +0800 (0:00:00.049)       0:00:48.994 ******** 
skipping: [controller0]

PLAY [invokers] ************************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  16:49:41 +0800 (0:00:00.299)       0:00:49.294 ******** 
ok: [invoker0]

TASK [invoker : docker login] **********************************************************************
Friday 25 January 2019  16:49:42 +0800 (0:00:00.827)       0:00:50.121 ******** 
skipping: [invoker0]

TASK [invoker : get invoker name and index] ********************************************************
Friday 25 January 2019  16:49:42 +0800 (0:00:00.045)       0:00:50.166 ******** 
ok: [invoker0]

TASK [invoker : pull invoker image with tag latest] ************************************************
Friday 25 January 2019  16:49:42 +0800 (0:00:00.085)       0:00:50.252 ******** 
skipping: [invoker0]

TASK [invoker : pull runtime action images per manifest] *******************************************
Friday 25 January 2019  16:49:42 +0800 (0:00:00.043)       0:00:50.296 ******** 
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'nodejs6action', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-nodejs-v8', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-nodejs-v10', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'python2action', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'python3action', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-swift-v3.1.1', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-swift-v4.1', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-swift-v4.2', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'java8action', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-php-v7.1', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-php-v7.2', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-php-v7.3', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-ruby-v2.5', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'actionloop-golang-v1.11', 'tag': 'latest'})
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'action-dotnet-v2.2', 'tag': 'latest'})

TASK [invoker : pull blackboxes action images per manifest] ****************************************
Friday 25 January 2019  16:58:46 +0800 (0:09:03.432)       0:09:53.728 ******** 
changed: [invoker0] => (item={'prefix': 'openwhisk', 'name': 'dockerskeleton', 'tag': 'latest'})

TASK [invoker : determine docker root dir on docker-machine] ***************************************
Friday 25 January 2019  16:58:47 +0800 (0:00:01.498)       0:09:55.227 ******** 
skipping: [invoker0]

TASK [invoker : set_fact] **************************************************************************
Friday 25 January 2019  16:58:47 +0800 (0:00:00.044)       0:09:55.271 ******** 
skipping: [invoker0]

TASK [invoker : determine docker root dir] *********************************************************
Friday 25 January 2019  16:58:47 +0800 (0:00:00.046)       0:09:55.317 ******** 
changed: [invoker0]

TASK [invoker : set_fact] **************************************************************************
Friday 25 January 2019  16:58:48 +0800 (0:00:00.235)       0:09:55.553 ******** 
ok: [invoker0]

TASK [invoker : ensure invoker log directory is created with permissions] **************************
Friday 25 January 2019  16:58:48 +0800 (0:00:00.115)       0:09:55.668 ******** 
ok: [invoker0]

TASK [invoker : ensure invoker config directory is created with permissions] ***********************
Friday 25 January 2019  16:58:48 +0800 (0:00:00.217)       0:09:55.886 ******** 
ok: [invoker0]

TASK [invoker : copy kafka truststore/keystore] ****************************************************
Friday 25 January 2019  16:58:48 +0800 (0:00:00.512)       0:09:56.399 ******** 
skipping: [invoker0]

TASK [invoker : copy keystore, key and cert] *******************************************************
Friday 25 January 2019  16:58:48 +0800 (0:00:00.048)       0:09:56.447 ******** 
changed: [invoker0] => (item=files/invoker-openwhisk-keystore.p12)
changed: [invoker0] => (item=files/invoker-openwhisk-server-key.pem)
changed: [invoker0] => (item=files/invoker-openwhisk-server-cert.pem)

TASK [invoker : check, that required databases exist] **********************************************
Friday 25 January 2019  16:58:51 +0800 (0:00:02.216)       0:09:58.663 ******** 
included: /home/openwhisk/openwhisk/ansible/tasks/db/checkDb.yml for invoker0
included: /home/openwhisk/openwhisk/ansible/tasks/db/checkDb.yml for invoker0

TASK [invoker : check if whisk_local_whisks with CouchDB exists] ***********************************
Friday 25 January 2019  16:58:51 +0800 (0:00:00.213)       0:09:58.877 ******** 
fatal: [invoker0]: FAILED! => {"changed": false, "content": "", "msg": "Status code was -1 and not [200]: Request failed: <urlopen error [Errno 104] Connection reset by peer>", "redirected": false, "status": -1, "url": "http://172.17.0.1:5984/whisk_local_whisks"}

Status code was -1 and not [200]: Request failed: <urlopen error [Errno
104] Connection reset by peer>

PLAY RECAP *****************************************************************************************
controller0                : ok=25   changed=3    unreachable=0    failed=0   
invoker0                   : ok=11   changed=4    unreachable=0    failed=1   
kafka0                     : ok=11   changed=5    unreachable=0    failed=0   

Friday 25 January 2019  16:58:51 +0800 (0:00:00.293)       0:09:59.171 ******** 
=============================================================================== 
invoker : pull runtime action images per manifest ----------------------------------------- 543.43s
controller : wait until the Controller in this host is up and running ---------------------- 11.20s
kafka : wait until the kafka server started up ---------------------------------------------- 7.59s
zookeeper : wait until the Zookeeper in this host is up and running ------------------------- 7.36s
kafka : (re)start kafka using 'wurstmeister/kafka:0.11.0.1'  -------------------------------- 3.10s
zookeeper : (re)start zookeeper ------------------------------------------------------------- 2.30s
invoker : copy keystore, key and cert ------------------------------------------------------- 2.22s
controller : (re)start controller ----------------------------------------------------------- 2.01s
controller : copy certificates -------------------------------------------------------------- 1.57s
invoker : pull blackboxes action images per manifest ---------------------------------------- 1.50s
zookeeper : pull the zookeeper:3.4 image ---------------------------------------------------- 1.33s
Gathering Facts ----------------------------------------------------------------------------- 1.24s
controller : copy nginx certificate keystore ------------------------------------------------ 1.04s
Gathering Facts ----------------------------------------------------------------------------- 0.83s
Gathering Facts ----------------------------------------------------------------------------- 0.80s
Gathering Facts ----------------------------------------------------------------------------- 0.79s
controller : copy jmxremote password file --------------------------------------------------- 0.72s
controller : populate environment variables for controller ---------------------------------- 0.68s
controller : copy jmxremote access file ----------------------------------------------------- 0.60s
controller : ensure controller config directory is created with permissions ----------------- 0.53s

But if i ran it again, a different issue occured.

$ ansible-playbook -i environments/local openwhisk.yml -e invoker_use_runc=False

PLAY [zookeepers] **********************************************************************************

TASK [Gathering Facts] *****************************************************************************
Friday 25 January 2019  17:04:30 +0800 (0:00:00.110)       0:00:00.110 ******** 
ok: [kafka0]

TASK [zookeeper : pull the zookeeper:3.4 image] ****************************************************
Friday 25 January 2019  17:04:32 +0800 (0:00:01.329)       0:00:01.440 ******** 
changed: [kafka0]

TASK [zookeeper : (re)start zookeeper] *************************************************************
Friday 25 January 2019  17:04:33 +0800 (0:00:01.557)       0:00:02.998 ******** 
changed: [kafka0]

TASK [zookeeper : wait until the Zookeeper in this host is up and running] *************************
Friday 25 January 2019  17:04:37 +0800 (0:00:03.722)       0:00:06.720 ******** 
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (36 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (35 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (34 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (33 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (32 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (31 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (30 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (29 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (28 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (27 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (26 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (25 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (24 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (23 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (22 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (21 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (20 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (19 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (18 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (17 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (16 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (15 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (14 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (13 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (12 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (11 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (10 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (9 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (8 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (7 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (6 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (5 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (4 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (3 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (2 retries left).
FAILED - RETRYING: wait until the Zookeeper in this host is up and running (1 retries left).
fatal: [kafka0]: FAILED! => {"attempts": 36, "changed": true, "cmd": "(echo ruok; sleep 1) | nc 172.17.0.1 2181", "delta": "0:00:01.004410", "end": "2019-01-25 17:08:19.775521", "msg": "non-zero return code", "rc": 1, "start": "2019-01-25 17:08:18.771111", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

[FAILED]
> (echo ruok; sleep 1) | nc 172.17.0.1 2181
non-zero return code

PLAY RECAP *****************************************************************************************
kafka0                     : ok=3    changed=2    unreachable=0    failed=1   

Friday 25 January 2019  17:08:19 +0800 (0:03:42.336)       0:03:49.057 ******** 
=============================================================================== 
zookeeper : wait until the Zookeeper in this host is up and running ----------------------- 222.34s
zookeeper : (re)start zookeeper ------------------------------------------------------------- 3.72s
zookeeper : pull the zookeeper:3.4 image ---------------------------------------------------- 1.56s
Gathering Facts ----------------------------------------------------------------------------- 1.33s

@rabbah
Copy link
Member

rabbah commented Feb 4, 2019

Just to confirm: you're running couchdb in a container and using the couchdb playbook?

@rabbah
Copy link
Member

rabbah commented Feb 6, 2019

I found a potential problem with the couch playbook and will propose a patch that should address this symptom.

@rabbah rabbah mentioned this issue Feb 6, 2019
Merged
21 tasks
@rabbah rabbah added the couchdb label Feb 6, 2019
@rabbah rabbah mentioned this issue Feb 8, 2019
Merged
21 tasks
@dgrove-oss
Copy link
Member

I wonder if something like what we do in the kube couch-db init job might be useful?

The idea is that after initialization completes, we create a marker table. Other jobs can then key on the existence of this table to know that the init job has completed.

https://github.com/apache/incubator-openwhisk-deploy-kube/blob/master/helm/openwhisk/configMapFiles/initCouchDB/initdb.sh#L70

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
couchdb
Projects
None yet
Milestone
No milestone
3 participants
@rabbah @dgrove-oss @axiqia