codeconsole commented on code in PR #16208:
URL: https://github.com/apache/grails-core/pull/16208#discussion_r4064845724
##########
grails-data-mongodb/core/src/main/groovy/org/grails/datastore/mapping/mongo/MongoDatastore.java:
##########
@@ -574,17 +598,188 @@ public ConnectionSources<MongoClient,
MongoConnectionSourceSettings> getConnecti
}
/**
- * Builds the MongoDB index for this datastore
+ * Builds the MongoDB index for this datastore.
+ *
+ * <p>Each index is created by a command that the server answers only once
the index has been built,
+ * so with the default settings this blocks whoever creates the datastore
— in an application, the
+ * startup thread — for as long as MongoDB takes to build every declared
index. Enabling
+ * {@code grails.mongodb.buildIndexesAsync} hands the work to a background
thread and returns
+ * immediately instead.
*/
public void buildIndex() {
Review Comment:
I went with the Javadoc in 848282548a rather than moving the submission. A
standalone `new MongoDatastore(...)` has no lifecycle callback to defer to, so
an `afterPropertiesSet` step would stop standalone users getting a build at all
unless they called something new. The hook now says it may run on a background
thread before a subclass constructor has finished, and must not depend on state
that constructor sets up. The base class itself is safe: everything the worker
reads is assigned before `initialize(settings)`, and it does not touch
`gormEnhancer`.
##########
grails-data-mongodb/core/src/main/groovy/org/grails/datastore/mapping/mongo/MongoDatastore.java:
##########
@@ -1241,6 +1500,14 @@ private boolean ownsClient() {
@PreDestroy
public void close() {
MongoClient current = this.mongo;
+ shutDownIndexBuild();
+ // Over a snapshot: the connection sources listener can still add a
child while this runs, and a
+ // ConcurrentModificationException here would escape before anything
below had a chance to close.
+ for (MongoDatastore datastore : new
ArrayList<>(datastoresByConnectionSource.values())) {
Review Comment:
Right, the copy iterated the map too. f4bb9466e6 makes it a
`ConcurrentHashMap` and drops both the copy and the comment. Nothing relied on
the `LinkedHashMap` order: `close()` is the only place it is iterated, and it
shuts every child down regardless. A child added while `close()` is iterating
may or may not be seen by the weakly consistent iterator, so that window
remains, but it can no longer corrupt the map or throw out of `close()`.
##########
grails-data-mongodb/core/src/main/groovy/org/grails/datastore/mapping/mongo/MongoDatastore.java:
##########
@@ -166,6 +171,19 @@ public class MongoDatastore extends AbstractDatastore
implements MappingContext.
protected final boolean stateless;
protected final boolean codecEngine;
protected final boolean transactionsEnabled;
+ protected final boolean buildIndexes;
+ protected final boolean buildIndexesAsync;
+
+ /**
+ * Runs the startup index build off the thread that creates the datastore
when
+ * {@code grails.mongodb.buildIndexesAsync} is enabled; {@code null}
otherwise. A single thread,
+ * so the indexes are still built one at a time per connection. The worker
expires after one idle
+ * second, releasing the worker while allowing subsequent calls to {@link
#buildIndex()}.
+ */
+ private final ExecutorService indexBuildExecutor;
+
+ /** The summary for the current build, scoped to its thread so the
protected index hook is preserved. */
+ private final ThreadLocal<IndexBuildSummary> indexBuildSummary = new
ThreadLocal<>();
Review Comment:
I've kept the ThreadLocal. The one-argument protected hook is what a
subclass overrides, so the startup build has to call that one or the override
is skipped on startup, which was the round-1 regression. Once the hook is
called through its one-argument signature, the build's summary has to reach the
base implementation without passing through the override, and that is what the
ThreadLocal does. An explicit `IndexBuild` passed to a two-argument method
would bypass the subclass. A subclass that skips
`super.initializeIndices(entity)` counts nothing under any design that counts
in the base implementation.
##########
grails-data-mongodb/core/src/main/groovy/org/grails/datastore/mapping/mongo/MongoDatastore.java:
##########
@@ -574,17 +598,188 @@ public ConnectionSources<MongoClient,
MongoConnectionSourceSettings> getConnecti
}
/**
- * Builds the MongoDB index for this datastore
+ * Builds the MongoDB index for this datastore.
+ *
+ * <p>Each index is created by a command that the server answers only once
the index has been built,
+ * so with the default settings this blocks whoever creates the datastore
— in an application, the
+ * startup thread — for as long as MongoDB takes to build every declared
index. Enabling
+ * {@code grails.mongodb.buildIndexesAsync} hands the work to a background
thread and returns
+ * immediately instead.
*/
public void buildIndex() {
- for (PersistentEntity entity :
this.mappingContext.getPersistentEntities()) {
- // Only create Mongo templates for entities that are mapped with
Mongo
- if (!entity.isExternal()) {
- if (entity.isMultiTenant() && multiTenancyMode ==
MultiTenancySettings.MultiTenancyMode.SCHEMA) continue;
+ if (!buildIndexes) {
+ LOG.info("Index creation is disabled by [{} = false]. The indexes
declared by the domain classes " +
+ "will not be created or reconciled; the indexes already
present on the server are left untouched.",
+ MongoSettings.SETTING_BUILD_INDEXES);
+ return;
+ }
+ if (indexBuildExecutor == null) {
+ buildDeclaredIndexes();
+ return;
+ }
+ LOG.info("Building the indexes declared by the domain classes on a
background thread ([{} = true]). " +
+ "Startup does not wait for them, so a query issued before its
index exists is served without it.",
+ MongoSettings.SETTING_BUILD_INDEXES_ASYNC);
+ indexBuildExecutor.execute(() -> {
+ try {
+ buildDeclaredIndexes();
+ }
+ catch (Throwable e) {
+ // Nothing is waiting on this thread, so an error that would
have failed startup has to be
+ // reported here or it is lost entirely.
+ if (indexBuildExecutor.isShutdown() ||
Thread.currentThread().isInterrupted()) {
+ // toString rather than the message: an interrupted driver
call can arrive wrapped in
+ // an exception that carries no message of its own.
+ LOG.debug("The background index build was abandoned
because the datastore is shutting down: {}",
+ e.toString(), e);
+ }
+ else {
+ LOG.error("The background index build failed: {}. The
application is running without the " +
+ "indexes that were not created.", e.getMessage(),
e);
+ }
+ }
+ });
+ }
+
+ /**
+ * Creates and reconciles the indexes declared by every entity mapped to
this datastore, and reports
+ * what that cost. MongoDB answers each {@code createIndex} only once the
index exists, so the elapsed
+ * time is the time the caller — startup, or the background build thread —
actually spent waiting.
+ */
+ private void buildDeclaredIndexes() {
+ long startedAt = System.nanoTime();
+ IndexBuildSummary summary = new IndexBuildSummary();
+ IndexBuildSummary previousSummary = indexBuildSummary.get();
+ indexBuildSummary.set(summary);
+ try {
+ for (PersistentEntity entity :
this.mappingContext.getPersistentEntities()) {
+ // Only create Mongo templates for entities that are mapped
with Mongo
+ if (!entity.isExternal()) {
+ if (entity.isMultiTenant() && multiTenancyMode ==
MultiTenancySettings.MultiTenancyMode.SCHEMA) continue;
- initializeIndices(entity);
+ summary.entities++;
+ initializeIndices(entity);
+ }
}
}
+ finally {
+ if (previousSummary == null) {
+ indexBuildSummary.remove();
+ }
+ else {
+ indexBuildSummary.set(previousSummary);
+ }
+ }
+ long elapsedMillis = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() -
startedAt);
+ if (summary.applied() == 0 && summary.failures == 0) {
+ LOG.debug("No indexes are declared by the {} domain class(es)
mapped to database [{}]",
+ summary.entities, defaultDatabase);
+ return;
+ }
+ String outcome = summary.classified ?
+ summary.created + " created, " + summary.alreadyPresent + "
already present" :
+ summary.applied() + " index declaration(s) applied";
+ if (summary.failures == 0) {
+ LOG.info("Index build for database [{}] finished in {}ms: {}, from
{} domain class(es)",
+ defaultDatabase, elapsedMillis, outcome, summary.entities);
+ }
+ else {
+ LOG.warn("Index build for database [{}] finished in {}ms: {}, {}
failed, from {} domain class(es). " +
+ "The failures are reported above.",
+ defaultDatabase, elapsedMillis, outcome, summary.failures,
summary.entities);
+ }
+ }
+
+ /**
+ * The indexes a collection already had when the build reached it, listed
once on first use and then
+ * reused. {@code createIndex} is idempotent and answers the same way
whether or not it had to build
+ * anything — the driver hands back only the index name, discarding the
{@code numIndexesBefore} /
+ * {@code numIndexesAfter} the server reports — so what was there
beforehand is what distinguishes an
+ * index this build created from one it merely confirmed.
+ *
+ * <p>Listed lazily so that an entity declaring no indexes costs no round
trip, and reused by the
+ * conflict path, which would otherwise list them again. Successful
changes are recorded so later
+ * declarations on the same keys see the current name and TTL, and are not
counted as new indexes.
+ */
+ private static final class ExistingIndexes {
+
+ private final com.mongodb.client.MongoCollection<Document> collection;
+
+ private final IndexBuildSummary summary;
+
+ private List<Document> indexes;
+
+ private boolean listed;
+
+ private ExistingIndexes(com.mongodb.client.MongoCollection<Document>
collection, IndexBuildSummary summary) {
+ this.collection = collection;
+ this.summary = summary;
+ }
+
+ /**
+ * @return the known current indexes, or {@code null} if they could
not be listed
+ */
+ private List<Document> get() {
+ if (!listed) {
+ listed = true;
+ try {
+ indexes = collection.listIndexes().into(new ArrayList<>());
Review Comment:
Gated on `LOG.isInfoEnabled()` in 848282548a, as @matrei suggested: an
application that does not log the summary does not pay for classifying it.
`BuildIndexesClassificationCostSpec` counts `listIndexes` commands with a
`CommandListener` — none with the logger at WARN, one with it at INFO.
I kept the listing rather than `runCommand("createIndexes")`. Reading
`numIndexesBefore`/`numIndexesAfter` means building the index specification by
hand from the `IndexOptions` GORM passes through, which is the driver's
internal mapping and not worth re-implementing. With INFO on, the cost is at
most one extra command per indexed collection, against at least one
`createIndex` there already.
##########
grails-data-mongodb/core/src/main/groovy/org/grails/datastore/mapping/mongo/MongoDatastore.java:
##########
@@ -1269,6 +1536,36 @@ public void close() {
}
}
+ private void shutDownIndexBuild() {
+ if (indexBuildExecutor != null) {
+ // Interrupt every connection's build before closing its client. A
build can run for minutes,
+ // so shutdown must not wait for it; the server carries on
building what it was asked for.
+ indexBuildExecutor.shutdownNow();
+ }
+ }
+
+ /**
+ * Names the background index build thread after the connection it serves,
so that a log line or a
+ * thread dump says which datastore is building indexes. The thread is a
daemon: an index build in
+ * flight must not hold the JVM open, and abandoning the wait does not
abandon the build — the server
+ * finishes an index it has been asked for whether or not a client is
still listening.
+ */
+ private static final class IndexBuildThreadFactory implements
ThreadFactory {
Review Comment:
Switched in 848282548a. `CustomizableThreadFactory` appends a counter, so
the thread is now `gorm-mongo-index-build-<connection>-<n>`; the guide and the
PR description say so.
##########
grails-data-mongodb/docs/src/docs/asciidoc/gettingStarted/advancedConfig.adoc:
##########
@@ -36,6 +49,8 @@ grails {
}
----
+NOTE: These settings are read by name, so write them exactly as they are
documented. Unlike Spring Boot's own configuration properties they are not
relaxed-bound, and a kebab-case spelling such as `database-name` is not
recognised — it is ignored, leaving the default in place.
Review Comment:
I checked this against a `StandardEnvironment` with
`ConfigurationPropertySources.attach`, and the NOTE holds under Boot too, as
@matrei found. Boot's attached source only answers canonical names, and
`grails.mongodb.databaseName` is not one (it has an uppercase letter), so the
lookup falls through to the underlying source, which matches literally: the
kebab-case value is there under its own name and never found under the one GORM
asks for.
You're right that the spec could not show that through a bare
`MapPropertySource`. 423ac93345 adds a feature through the Boot-attached
environment that asserts exactly this, so I've kept the NOTE.
##########
grails-data-mongodb/core/src/test/groovy/org/grails/datastore/gorm/mongo/BuildIndexesBackgroundFailureSpec.groovy:
##########
@@ -0,0 +1,170 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.grails.datastore.gorm.mongo
+
+import java.util.concurrent.CountDownLatch
+import java.util.concurrent.TimeUnit
+
+import ch.qos.logback.classic.Level
+import ch.qos.logback.classic.Logger
+import ch.qos.logback.classic.spi.ILoggingEvent
+import ch.qos.logback.core.read.ListAppender
+import com.mongodb.MongoException
+import com.mongodb.client.MongoClient
+import com.mongodb.client.MongoClients
+import grails.gorm.annotation.Entity
+import org.slf4j.LoggerFactory
+import spock.lang.Shared
+import spock.util.concurrent.PollingConditions
+
+import org.apache.grails.testing.mongo.AutoStartedMongoSpec
+import org.grails.datastore.mapping.core.DatastoreUtils
+import org.grails.datastore.mapping.mongo.MongoDatastore
+import org.grails.datastore.mapping.mongo.config.MongoSettings
+
+/**
+ * Nothing waits on the background index build, so what it does when it goes
wrong is only visible in the
+ * log. A build that fails has to say so loudly, because it can no longer fail
startup; a build abandoned
+ * because the application is shutting down has to stay quiet, because nothing
went wrong.
+ */
+class BuildIndexesBackgroundFailureSpec extends AutoStartedMongoSpec {
+
+ @Shared
+ MongoClient realClient
+
+ @Shared
+ Logger datastoreLogger
+
+ @Shared
+ ListAppender<ILoggingEvent> logged = new ListAppender<>()
+
+ @Shared
+ Level previousLevel
+
+ @Override
+ boolean shouldInitializeDatastore() {
+ false
+ }
+
+ void setupSpec() {
+ realClient =
MongoClients.create(dbContainer.getReplicaSetUrl('backgroundFailureDb'))
+ datastoreLogger =
LoggerFactory.getLogger('org.grails.datastore.mapping') as Logger
+ previousLevel = datastoreLogger.level
+ datastoreLogger.level = Level.DEBUG
+ logged.start()
+ datastoreLogger.addAppender(logged)
+ }
+
+ void cleanupSpec() {
+ datastoreLogger?.detachAppender(logged)
+ datastoreLogger?.level = previousLevel
+ realClient?.close()
+ }
+
+ private MongoDatastore asyncDatastoreOn(MongoClient client, String
database, Class... classes) {
+ new MongoDatastore(client, DatastoreUtils.createPropertyResolver([
+ 'grails.mongodb.databaseName' : database,
+ (MongoSettings.SETTING_BUILD_INDEXES_ASYNC): true
+ ]), classes)
+ }
+
+ void "test a background build that fails reports the failure instead of
losing it"() {
+ given:
+ def conditions = new PollingConditions(timeout: 30)
+ MongoClient broken = FailingMongoClient.wrap(realClient,
'getCollection') {
+ throw new MongoException('the connection went away mid-build')
+ }
+
+ when: "the datastore is created, which does not wait for the build"
+ def datastore = asyncDatastoreOn(broken, 'backgroundFailureDb',
FailedBackgroundThing)
+
+ then: "startup was not held up by, and did not fail because of, the
broken build"
+ datastore.isBuildIndexesAsync()
+
+ and: "the failure is reported at error level, since nothing else would
surface it"
+ conditions.eventually {
+ assert logged.list.any {
Review Comment:
Done in fd13f1a3d6: a shared `CapturedLog` backs the appender with a
`CopyOnWriteArrayList` and hands out snapshots, and the five specs use it in
place of their own attach/restore code.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
