Fix PluginLogFile to not open multiple appenders when run in parallel

In making PluginLogFile thread safe change (If1705b9dd), start method
was still creating AsyncAppender for each thread which is leading to
errors such as "too many open files". This change makes the creation
of AsyncAppender thread safe and only creates one if no AsyncAppender
was created before for a particular log file. Also, acquires a lock
on SystemLog which ensures the thread safety.

Change-Id: I60c2829c28129eb7256ed11f36a77e96cf24f25f

java/com/google/gerrit/acceptance/AbstractPluginLogFileTest.java

@@ -0,0 +1,112 @@
+// Copyright (C) 2020 The Android Open Source Project
+//
+// Licensed 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
+//
+// http://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 com.google.gerrit.acceptance;
+
+import com.google.gerrit.extensions.annotations.Exports;
+import com.google.gerrit.extensions.events.LifecycleListener;
+import com.google.gerrit.extensions.systemstatus.ServerInformation;
+import com.google.gerrit.server.DynamicOptions;
+import com.google.gerrit.server.config.SitePaths;
+import com.google.gerrit.server.util.PluginLogFile;
+import com.google.gerrit.server.util.SystemLog;
+import com.google.gerrit.sshd.commands.Query;
+import com.google.inject.AbstractModule;
+import com.google.inject.Inject;
+import com.google.inject.Singleton;
+import com.google.inject.internal.UniqueAnnotations;
+import java.util.Collections;
+import org.apache.log4j.AsyncAppender;
+import org.apache.log4j.Layout;
+import org.apache.log4j.PatternLayout;
+import org.eclipse.jgit.lib.Config;
+import org.kohsuke.args4j.Option;
+
+public class AbstractPluginLogFileTest extends AbstractDaemonTest {
+  protected static class Module extends AbstractModule {
+    @Override
+    public void configure() {
+      bind(com.google.gerrit.server.DynamicOptions.DynamicBean.class)
+          .annotatedWith(Exports.named(Query.class))
+          .to(MyClassNameProvider.class);
+    }
+  }
+
+  protected static class MyClassNameProvider implements DynamicOptions.ModulesClassNamesProvider {
+    @Override
+    public String getClassName() {
+      return "com.google.gerrit.acceptance.AbstractPluginLogFileTest$MyOptions";
+    }
+
+    @Override
+    public Iterable<String> getModulesClassNames() {
+      return Collections.singleton(
+          "com.google.gerrit.acceptance.AbstractPluginLogFileTest$MyOptions$MyOptionsModule");
+    }
+  }
+
+  public static class MyOptions implements DynamicOptions.DynamicBean {
+    @Option(name = "--opt")
+    public boolean opt;
+
+    public static class MyOptionsModule extends AbstractModule {
+      @Override
+      protected void configure() {
+        bind(LifecycleListener.class)
+            .annotatedWith(UniqueAnnotations.create())
+            .to(MyPluginLogFile.class);
+      }
+    }
+  }
+
+  protected static class MyPluginLogFile extends PluginLogFile {
+    protected static final String logName = "test_log";
+
+    @Inject
+    public MyPluginLogFile(MySystemLog mySystemLog, ServerInformation serverInfo) {
+      super(mySystemLog, serverInfo, logName, new PatternLayout("[%d] [%t] %m%n"));
+    }
+  }
+
+  @Singleton
+  protected static class MySystemLog extends SystemLog {
+    protected InvocationCounter invocationCounter;
+
+    @Inject
+    public MySystemLog(SitePaths site, Config config, InvocationCounter invocationCounter) {
+      super(site, config);
+      this.invocationCounter = invocationCounter;
+    }
+
+    @Override
+    public AsyncAppender createAsyncAppender(
+        String name, Layout layout, boolean rotate, boolean forPlugin) {
+      invocationCounter.increment();
+      return super.createAsyncAppender(name, layout, rotate, forPlugin);
+    }
+  }
+
+  @Singleton
+  public static class InvocationCounter {
+    private int counter = 0;
+
+    public int getCounter() {
+      return counter;
+    }
+
+    public synchronized void increment() {
+      counter++;
+    }
+  }
+}

java/com/google/gerrit/acceptance/BUILD

@@ -47,6 +47,7 @@ DEPLOY_ENV = [
     "//lib/guice",
     "//lib/guice:guice-assistedinject",
     "//lib/guice:guice-servlet",
+    "//lib/log:log4j",
     "//lib/mail",
     "//lib/mina:sshd",
     "//lib:guava",

java/com/google/gerrit/server/util/PluginLogFile.java

@@ -16,7 +16,6 @@ package com.google.gerrit.server.util;
 
 import com.google.gerrit.extensions.events.LifecycleListener;
 import com.google.gerrit.extensions.systemstatus.ServerInformation;
-import org.apache.log4j.AsyncAppender;
 import org.apache.log4j.Layout;
 import org.apache.log4j.LogManager;
 import org.apache.log4j.Logger;
@@ -38,12 +37,11 @@ public abstract class PluginLogFile implements LifecycleListener {
 
   @Override
   public void start() {
-    AsyncAppender asyncAppender = systemLog.createAsyncAppender(logName, layout, true, true);
     Logger logger = LogManager.getLogger(logName);
     if (logger.getAppender(logName) == null) {
-      synchronized (this) {
+      synchronized (systemLog) {
         if (logger.getAppender(logName) == null) {
-          logger.addAppender(asyncAppender);
+          logger.addAppender(systemLog.createAsyncAppender(logName, layout, true, true));
         }
       }
     }

javatests/com/google/gerrit/acceptance/server/util/BUILD

@@ -0,0 +1,7 @@
+load("//javatests/com/google/gerrit/acceptance:tests.bzl", "acceptance_tests")
+
+acceptance_tests(
+    srcs = glob(["*IT.java"]),
+    group = "server_util",
+    labels = ["server"],
+)

javatests/com/google/gerrit/acceptance/server/util/PluginLogFileIT.java

@@ -0,0 +1,58 @@
+// Copyright (C) 2020 The Android Open Source Project
+//
+// Licensed 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
+//
+// http://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 com.google.gerrit.acceptance.server.util;
+
+import static junit.framework.TestCase.assertEquals;
+import static org.junit.Assert.fail;
+
+import com.google.gerrit.acceptance.AbstractPluginLogFileTest;
+import com.google.gerrit.acceptance.NoHttpd;
+import com.google.gerrit.acceptance.UseSsh;
+import com.google.inject.Inject;
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import org.junit.Test;
+
+@NoHttpd
+@UseSsh
+public class PluginLogFileIT extends AbstractPluginLogFileTest {
+  @Inject private InvocationCounter invocationCounter;
+  private static final int NUMBER_OF_THREADS = 5;
+
+  @Test
+  public void testMultiThreadedPluginLogFile() throws Exception {
+    try (AutoCloseable ignored = installPlugin("my-plugin", Module.class)) {
+      ExecutorService service = Executors.newFixedThreadPool(NUMBER_OF_THREADS);
+      CountDownLatch latch = new CountDownLatch(NUMBER_OF_THREADS);
+      createChange();
+      for (int i = 0; i < NUMBER_OF_THREADS; i++) {
+        service.execute(
+            () -> {
+              try {
+                adminSshSession.exec("gerrit query --format json status:open --my-plugin--opt");
+                adminSshSession.assertSuccess();
+              } catch (Exception e) {
+                fail(e.getMessage());
+              } finally {
+                latch.countDown();
+              }
+            });
+      }
+      latch.await();
+      assertEquals(1, invocationCounter.getCounter());
+    }
+  }
+}