С cf bind-service или cf unbind-serviceServicebroker (компонент Cloud Foundry) создает новые случайные сгенерированные учетные данные (см. Его с cf env $APP). Благодаря нашему сервису MongoEnterprise Service Broker подключается к API-интерфейсу Ops Manager и развертывает новый пользовательский репликатор mongod.
Когда менеджер Опс развертывает пользователя (createUser) он использует WriteConcern «большинство», что означает, по меньшей мере, один вторичный потребности признать запись.
COMMAND [conn53768] command rs_$DBNAME.$cmd command: createUser { createUser: "$USERNAME", pwd: "xxx", digestPassword: false, roles: [ { role: "readWrite", db: "rs_$DBNAME" } ], writeConcern: { w: "majority" } } keyUpdates:0 writeConflicts:0 numYields:0 reslen:138 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { W: 2 } }, Collection: { acquireCount: { w: 2 } } } protocol:op_query 9811ms
Благодаря mongorestore, которая была выполнена несколько часов, прежде чем произошла эта проблема, есть вероятность того, что команда createUser была таймаут из-за отсутствия подтверждения от вторичных, которые были заняты строительством индексов на переднем плане и фон. Индексная сборка (по умолчанию mongorestore вариантов) сначала делается на первичной основе, а когда она будет выполнена в секундах. Это объясняет увеличение запаздывания на вторичных станциях в течение createUser.
Создание индексов может занять очень много времени, в зависимости от индекса и размера данных. Мы слышали, что многие жалобы клиентов на создание индекса занимают слишком много времени.
Вот журналы из строкой индекса. Клиент Ops Manager может видеть потоковое mongodb.log (opsmanager.service.consul) с небольшой задержкой со всех членов набора реплик.
...
2017-02-15T10:40:06.199+0000 I INDEX [repl writer worker 10] build index done. scanned 1108917 total records. 672 secs
2017-02-15T10:50:08.553+0000 I INDEX [repl writer worker 4] build index done. scanned 1108917 total records. 602 secs
2017-02-15T11:01:13.888+0000 I INDEX [repl writer worker 7] build index done. scanned 1108917 total records. 665 secs
...
2017-02-15T15:01:37.405+0000 I INDEX [repl index builder 176] build index done. scanned 1109531 total records. 659 secs
2017-02-15T15:01:37.406+0000 I INDEX [repl index builder 170] build index done. scanned 1109531 total records. 659 secs
2017-02-15T15:16:20.139+0000 I INDEX [repl index builder 170] build index done. scanned 1109699 total records. 882 secs
Те ошибки из Automation Agent (Ops менеджер говорит на через HTTP с Autoamtion агентом на управляемой виртуальной машине, автоматизации Агент затем говорит с mongod с родным протоколом)
[2017/02/15 13:33:36.297] [.error] [cm/mongoctl/authctl.go:updateUser26Style:697] [101] <rs_$DB_NAME> [13:33:36.297] Error updating 2.6-style user = AuthUser([email protected]_$DB_NAME,roles=AuthRoles(1:{"Rolename":"readWrite","Db":"rs_$DB_NAME"}),interned=true,identity=2) in db = rs_$DB_NAME : <rs_$DB_NAME> [13:33:36.297] Timed out (timeout=-1ns) trying to runCommandWithTimeout(dbName=rs_$DB_NAME, cmd=[{"Name":"updateUser","Value":"$USER"},{"Name":"pwd","Value":"$PASSWORD"},{"Name":"digestPassword","Value":false},{"Name":"roles","Value":[{"db":"rs_$DB_NAME","role":"readWrite"}]}])
[2017/02/15 13:33:36.297] [.error] [cm/mongoctl/authctl.go:UpsertUser:516] [101] <rs_$DB_NAME> [13:33:36.297] Error upserting 2.6-style user = AuthUser([email protected]_$DB_NAME,roles=AuthRoles(1:{"Rolename":"readWrite","Db":"rs_$DB_NAME"}),interned=true,identity=2) : <rs_$DB_NAME> [13:33:36.297] Error updating 2.6-style user = AuthUser([email protected]_$DB_NAME,roles=AuthRoles(1:{"Rolename":"readWrite","Db":"rs_$DB_NAME"}),interned=true,identity=2) in db = rs_$DB_NAME : <rs_$DB_NAME> [13:33:36.297] Timed out (timeout=-1ns) trying to runCommandWithTimeout(dbName=rs_$DB_NAME, cmd=[{"Name":"updateUser","Value":"$USER"},{"Name":"pwd","Value":"$PASSWORD"},{"Name":"digestPassword","Value":false},{"Name":"roles","Value":[{"db":"rs_$DB_NAME","role":"readWrite"}]}])
[2017/02/15 13:33:36.297] [.error] [cm/action/adjustusers.go:adjustUsers:52] [101] <rs_$DB_NAME> [13:33:36.297] Error upserting user = AuthUser([email protected]_$DB_NAME,roles=AuthRoles(1:{"Rolename":"readWrite","Db":"rs_$DB_NAME"}),interned=true,identity=2). Trying to proceed though. : <rs_$DB_NAME> [13:33:36.297] Error upserting 2.6-style user = AuthUser([email protected]_$DB_NAME,roles=AuthRoles(1:{"Rolename":"readWrite","Db":"rs_$DB_NAME"}),interned=true,identity=2) : <rs_$DB_NAME> [13:33:36.297] Error updating 2.6-style user = AuthUser([email protected]_$DB_NAME,roles=AuthRoles(1:{"Rolename":"readWrite","Db":"rs_$DB_NAME"}),interned=true,identity=2) in db = rs_$DB_NAME : <rs_$DB_NAME> [13:33:36.297] Timed out (timeout=-1ns) trying to runCommandWithTimeout(dbName=rs_$DB_NAME, cmd=[{"Name":"updateUser","Value":"$USER"},{"Name":"pwd","Value":"$PASSWORD"},{"Name":"digestPassword","Value":false},{"Name":"roles","Value":[{"db":"rs_$DB_NAME","role":"readWrite"}]}])
[2017/02/15 13:33:36.381] [.error] [cm/executor/executor.go:ExecutePlan:184] <rs_$DB_NAME> [13:33:36.381] Postcondition failed for step AdjustUsers because
[The value of 'currentState.UsersRight' = false, but it should be true]. Outcome=3
Резюме: все с WriteConcern первичный работает отлично, но время ожидания WriteConcern, блокировка индекса блокировки.