Make GCP proxy log in a Stackdriver logging compliant format

When not running locally, the logging formatter is set to convert the log record to a single-line JSON string that Stackdriver logging agent running in GKE will pick up and parse correctly.

Also removed redundant logging handler in the proxy frontend connection. They have two problems: 1) it is possible to leak PII when all frontend traffic is logged, such as client IPs. Even though this is less of a concern because the GCP TCP proxy load balancer masquerade source IPs. 2) We are only logging the HTTP request/response that the frontend connection is sending to/receiving from the backend connection, but the backend already has its own logging handler to log the same message that it gets from/sends to the GAE app, so the logging in the frontend connection does not really give extra information.
Logging of some potential PII information such as the source IP of a proxied connection are also removed.

Thirdly, added a k8s autoscaling object that scales the containers based on CPU load. The default target load is 80%. This, in connection with GKE cluster VM autoscaling, means that when traffic is low, we'll only have one VM running one container of the proxy.

Fixes a bug where the MetricsComponent generates a separate ProxyConfig that does not call parse method on the command line args passed, resulting default Environment always being used in constructing the metric reporter.

Lastly a little bit of cleaning of the MOE config script, no newlines are necessary as the BUILD are formatted after string substitution.

-------------
Created by MOE: https://github.com/google/moe
MOE_MIGRATED_REVID=188029019

java/google/registry/proxy/BUILD

@@ -21,6 +21,9 @@ java_library(
         "//java/google/registry/config",
         "//java/google/registry/util",
         "@com_beust_jcommander",
+        "@com_fasterxml_jackson_core",
+        "@com_fasterxml_jackson_core_jackson_annotations",
+        "@com_fasterxml_jackson_core_jackson_databind",
         "@com_google_api_client",
         "@com_google_apis_google_api_services_cloudkms",
         "@com_google_apis_google_api_services_monitoring",

java/google/registry/proxy/EppProtocolModule.java

@@ -39,7 +39,6 @@ import io.netty.channel.ChannelHandler;
 import io.netty.channel.socket.nio.NioSocketChannel;
 import io.netty.handler.codec.LengthFieldBasedFrameDecoder;
 import io.netty.handler.codec.LengthFieldPrepender;
-import io.netty.handler.logging.LoggingHandler;
 import io.netty.handler.timeout.ReadTimeoutHandler;
 import java.io.IOException;
 import java.util.concurrent.ExecutorService;
@@ -87,7 +86,6 @@ public class EppProtocolModule {
       Provider<LengthFieldPrepender> lengthFieldPrependerProvider,
       Provider<EppServiceHandler> eppServiceHandlerProvider,
       Provider<EppQuotaHandler> eppQuotaHandlerProvider,
-      Provider<LoggingHandler> loggingHandlerProvider,
       Provider<FullHttpRequestRelayHandler> relayHandlerProvider) {
     return ImmutableList.of(
         proxyProtocolHandlerProvider,
@@ -97,7 +95,6 @@ public class EppProtocolModule {
         lengthFieldPrependerProvider,
         eppServiceHandlerProvider,
         eppQuotaHandlerProvider,
-        loggingHandlerProvider,
         relayHandlerProvider);
   }
 

java/google/registry/proxy/GcpJsonFormatter.java

@@ -0,0 +1,138 @@
+// Copyright 2017 The Nomulus Authors. All Rights Reserved.
+//
+// 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 google.registry.proxy;
+
+import com.fasterxml.jackson.annotation.JsonProperty;
+import com.fasterxml.jackson.core.JsonProcessingException;
+import com.fasterxml.jackson.databind.ObjectMapper;
+import com.google.auto.value.AutoValue;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.logging.Formatter;
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+
+/**
+ * JUL formatter that formats log messages in a single-line JSON that Stackdriver logging can parse.
+ *
+ * <p>There is no clear documentation on how to achieve this or on the format of the JSON. This is
+ * much a trial and error process, plus a lot of searching. To summarize, if the logs are printed to
+ * {@code STDOUT} or {@code STDERR} in a single-line JSON, with the content in the {@code message}
+ * field and the log level in the {@code severity} field, it will be picked up by Stackdriver
+ * logging agent running in GKE containers and logged at correct level..
+ *
+ * @see <a
+ *     href="https://medium.com/retailmenot-engineering/formatting-python-logs-for-stackdriver-5a5ddd80761c">
+ *     Formatting Python Logs from Stackdriver</a> <a
+ *     href="https://stackoverflow.com/questions/44164730/gke-stackdriver-java-logback-logging-format">
+ *     GKE & Stackdriver: Java logback logging format?</a>
+ */
+class GcpJsonFormatter extends Formatter {
+
+  private static final ObjectMapper MAPPER = new ObjectMapper();
+
+  @Override
+  public String format(LogRecord record) {
+    try {
+      return MAPPER.writeValueAsString(LogEvent.create(record)) + "\n";
+    } catch (JsonProcessingException e) {
+      throw new RuntimeException(e);
+    }
+  }
+
+  @AutoValue
+  abstract static class LogEvent {
+
+    /** Field that determines the log level. */
+    @JsonProperty("severity")
+    abstract String severity();
+
+    /**
+     * Field that stores the calling class and function when the log occurs.
+     *
+     * <p>This field is not used by Stackdriver, but it is useful and can be found when the log
+     * entries are expanded
+     */
+    @JsonProperty("source")
+    abstract String source();
+
+    /** Field that contains the content, this will show up as the main entry in a log. */
+    @JsonProperty("message")
+    abstract String message();
+
+    static LogEvent create(LogRecord record) {
+      // Add an extra newline before the message. Stackdriver does not show newlines correctly, and
+      // treats them as whitespace. If you want to see correctly formatted log message, expand the
+      // log and look for the jsonPayload.message field. This newline makes sure that the entire
+      // message starts on its own line, so that indentation within the message is correct.
+
+      String message = "\n" + record.getMessage();
+      Level level = record.getLevel();
+      // See
+      // https://github.com/GoogleCloudPlatform/google-cloud-java/blob/master/google-cloud-logging/src/main/java/com/google/cloud/logging/Severity.java
+      // on how {@code Level} is mapped to severity.
+      String severity;
+      switch (level.intValue()) {
+          // FINEST
+        case 300:
+          // FINER
+        case 400:
+          // FINE
+        case 500:
+          severity = "DEBUG";
+          break;
+          // CONFIG
+        case 700:
+          // INFO
+        case 800:
+          severity = "INFO";
+          break;
+          // WARNING
+        case 900:
+          severity = "WARNING";
+          break;
+          // SEVERE
+        case 1000:
+          severity = "ERROR";
+          break;
+        default:
+          severity = "DEFAULT";
+      }
+
+      // The rest is mostly lifted from java.util.logging.SimpleFormatter.
+      String stacktrace = "";
+      if (record.getThrown() != null) {
+        StringWriter sw = new StringWriter();
+        try (PrintWriter pw = new PrintWriter(sw)) {
+          pw.println();
+          record.getThrown().printStackTrace(pw);
+        }
+        stacktrace = sw.toString();
+      }
+
+      String source;
+      if (record.getSourceClassName() != null) {
+        source = record.getSourceClassName();
+        if (record.getSourceMethodName() != null) {
+          source += " " + record.getSourceMethodName();
+        }
+      } else {
+        source = record.getLoggerName();
+      }
+
+      return new AutoValue_GcpJsonFormatter_LogEvent(severity, source, message + stacktrace);
+    }
+  }
+}

java/google/registry/proxy/ProxyModule.java

@@ -28,9 +28,9 @@ import com.google.api.services.cloudkms.v1.CloudKMS;
 import com.google.api.services.cloudkms.v1.model.DecryptRequest;
 import com.google.common.base.Optional;
 import com.google.common.base.Supplier;
-import com.google.common.collect.ImmutableList;
 import com.google.common.collect.ImmutableMap;
 import com.google.common.collect.Maps;
+import com.google.monitoring.metrics.MetricReporter;
 import dagger.Component;
 import dagger.Module;
 import dagger.Provides;
@@ -42,11 +42,12 @@ import google.registry.proxy.WhoisProtocolModule.WhoisProtocol;
 import google.registry.util.Clock;
 import google.registry.util.FormattingLogger;
 import google.registry.util.SystemClock;
+import io.netty.handler.logging.LogLevel;
 import io.netty.handler.logging.LoggingHandler;
 import io.netty.handler.ssl.OpenSsl;
 import io.netty.handler.ssl.SslProvider;
 import java.io.IOException;
-import java.util.Objects;
+import java.util.Arrays;
 import java.util.Set;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
@@ -83,28 +84,27 @@ public class ProxyModule {
   boolean log;
 
   /**
-   * Enable FINE level logging.
+   * Configure logging parameters depending on the {@link Environment}.
    *
-   * <p>Set the loggers log level to {@code FINE}, and also add a console handler that actually
-   * output {@code FINE} level messages to stdout. The handler filters out all non FINE level log
-   * record to avoid double logging. Log records at level higher than FINE (e. g. INFO) will be
-   * handled at parent loggers. Note that {@code FINE} level corresponds to {@code DEBUG} level in
-   * Netty.
+   * <p>If not running locally, set the logging formatter to {@link GcpJsonFormatter} that formats
+   * the log in a single-line json string printed to {@code STDOUT} or {@code STDERR}, will be
+   * correctly parsed by Stackdriver logging.
+   *
+   * @see <a href="https://cloud.google.com/kubernetes-engine/docs/how-to/logging#best_practices">
+   *     Logging Best Practices</a>
    */
-  private static void enableDebugLevelLogging() {
-    ImmutableList<Logger> parentLoggers =
-        ImmutableList.of(
-            Logger.getLogger("io.netty.handler.logging.LoggingHandler"),
-            // Parent of all FormattingLoggers, so that we do not have to configure each
-            // FormattingLogger individually.
-            Logger.getLogger("google.registry.proxy"));
-    for (Logger logger : parentLoggers) {
-      logger.setLevel(Level.FINE);
-      Handler handler = new ConsoleHandler();
-      handler.setFilter(record -> Objects.equals(record.getLevel(), Level.FINE));
-      handler.setLevel(Level.FINE);
-      logger.addHandler(handler);
+  private void configureLogging() {
+    // Remove all other handlers on the root logger to avoid double logging.
+    Logger rootLogger = Logger.getLogger("");
+    Arrays.asList(rootLogger.getHandlers()).forEach(h -> rootLogger.removeHandler(h));
+
+    // If running on in a non-local environment, use GCP JSON formater.
+    Handler rootHandler = new ConsoleHandler();
+    rootHandler.setLevel(Level.FINE);
+    if (env != Environment.LOCAL) {
+      rootHandler.setFormatter(new GcpJsonFormatter());
     }
+    rootLogger.addHandler(rootHandler);
   }
 
   /**
@@ -122,10 +122,7 @@ public class ProxyModule {
       jCommander.usage();
       throw e;
     }
-    if (log) {
-      logger.info("DEBUG LOGGING: ENABLED");
-      enableDebugLevelLogging();
-    }
+    configureLogging();
     return this;
   }
 
@@ -158,11 +155,23 @@ public class ProxyModule {
     return env;
   }
 
-  /** Shared logging handler, set to default DEBUG(FINE) level. */
+  /**
+   * Provides shared logging handler.
+   *
+   * <p>The {@link LoggingHandler} records logs at {@code LogLevel.DEBUG} (internal Netty log
+   * level), which corresponds to {@code Level.FINE} (JUL log level). It uses a JUL logger called
+   * {@code io.netty.handler.logging.LoggingHandler} to actually process the logs. This logger is
+   * set to {@code Level.FINE} if {@code --log} parameter is passed, so that it does not filter out
+   * logs that the {@link LoggingHandler} captures. Otherwise the logs are silently ignored because
+   * the default logger level is {@code Level.INFO}.
+   */
   @Singleton
   @Provides
-  static LoggingHandler provideLoggingHandler() {
-    return new LoggingHandler();
+  LoggingHandler provideLoggingHandler() {
+    if (log) {
+      Logger.getLogger("io.netty.handler.logging.LoggingHandler").setLevel(Level.FINE);
+    }
+    return new LoggingHandler(LogLevel.DEBUG);
   }
 
   @Singleton
@@ -308,10 +317,14 @@ public class ProxyModule {
       HttpsRelayProtocolModule.class,
       WhoisProtocolModule.class,
       EppProtocolModule.class,
-      HealthCheckProtocolModule.class
+      HealthCheckProtocolModule.class,
+      MetricsModule.class
     }
   )
   interface ProxyComponent {
+
     ImmutableMap<Integer, FrontendProtocol> portToProtocolMap();
+
+    MetricReporter metricReporter();
   }
 }

java/google/registry/proxy/ProxyServer.java

@@ -51,8 +51,7 @@ import javax.inject.Provider;
 public class ProxyServer implements Runnable {
 
   private static final FormattingLogger logger = FormattingLogger.getLoggerForCallerClass();
-  private static final MetricReporter metricReporter =
-      DaggerMetricsModule_MetricsComponent.create().metricReporter();
+
   /** Maximum length of the queue of incoming connections. */
   private static final int MAX_SOCKET_BACKLOG = 128;
 
@@ -211,6 +210,14 @@ public class ProxyServer implements Runnable {
     // which is what google.registry.util.FormattingLog uses under the hood.
     InternalLoggerFactory.setDefaultFactory(JdkLoggerFactory.INSTANCE);
 
+    // Configure the components, this needs to run first so that the logging format is properly
+    // configured for each environment.
+    ProxyComponent proxyComponent =
+        DaggerProxyModule_ProxyComponent.builder()
+            .proxyModule(new ProxyModule().parse(args))
+            .build();
+
+    MetricReporter metricReporter = proxyComponent.metricReporter();
     try {
       metricReporter.startAsync().awaitRunning(10, TimeUnit.SECONDS);
       logger.info("Started up MetricReporter");
@@ -226,14 +233,10 @@ public class ProxyServer implements Runnable {
                     metricReporter.stopAsync().awaitTerminated(10, TimeUnit.SECONDS);
                     logger.info("Shut down MetricReporter");
                   } catch (TimeoutException timeoutException) {
-                    logger.severefmt("Failed to stop MetricReporter: %s", timeoutException);
+                    logger.warningfmt("Failed to stop MetricReporter: %s", timeoutException);
                   }
                 }));
 
-    ProxyComponent proxyComponent =
-        DaggerProxyModule_ProxyComponent.builder()
-            .proxyModule(new ProxyModule().parse(args))
-            .build();
     new ProxyServer(proxyComponent).run();
   }
 }

java/google/registry/proxy/WhoisProtocolModule.java

@@ -33,7 +33,6 @@ import google.registry.proxy.quota.TokenStore;
 import google.registry.util.Clock;
 import io.netty.channel.ChannelHandler;
 import io.netty.handler.codec.LineBasedFrameDecoder;
-import io.netty.handler.logging.LoggingHandler;
 import io.netty.handler.timeout.ReadTimeoutHandler;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.ScheduledExecutorService;
@@ -76,7 +75,6 @@ public class WhoisProtocolModule {
       Provider<LineBasedFrameDecoder> lineBasedFrameDecoderProvider,
       Provider<WhoisServiceHandler> whoisServiceHandlerProvider,
       Provider<WhoisQuotaHandler> whoisQuotaHandlerProvider,
-      Provider<LoggingHandler> loggingHandlerProvider,
       Provider<FullHttpRequestRelayHandler> relayHandlerProvider) {
     return ImmutableList.of(
         proxyProtocolHandlerProvider,
@@ -84,7 +82,6 @@ public class WhoisProtocolModule {
         lineBasedFrameDecoderProvider,
         whoisServiceHandlerProvider,
         whoisQuotaHandlerProvider,
-        loggingHandlerProvider,
         relayHandlerProvider);
   }
 

java/google/registry/proxy/handler/ProxyProtocolHandler.java

@@ -17,7 +17,6 @@ package google.registry.proxy.handler;
 import static com.google.common.base.Preconditions.checkState;
 import static java.nio.charset.StandardCharsets.US_ASCII;
 
-import google.registry.util.FormattingLogger;
 import io.netty.buffer.ByteBuf;
 import io.netty.channel.ChannelHandlerContext;
 import io.netty.handler.codec.ByteToMessageDecoder;
@@ -56,8 +55,6 @@ public class ProxyProtocolHandler extends ByteToMessageDecoder {
   public static final AttributeKey<String> REMOTE_ADDRESS_KEY =
       AttributeKey.valueOf("REMOTE_ADDRESS_KEY");
 
-  private static final FormattingLogger logger = FormattingLogger.getLoggerForCallerClass();
-
   // The proxy header must start with this prefix.
   // Sample header: "PROXY TCP4 255.255.255.255 255.255.255.255 65535 65535\r\n".
   private static final byte[] HEADER_PREFIX = "PROXY".getBytes(US_ASCII);
@@ -73,8 +70,6 @@ public class ProxyProtocolHandler extends ByteToMessageDecoder {
     super.channelRead(ctx, msg);
     if (finished) {
       if (proxyHeader != null) {
-        logger.finefmt("PROXIED CONNECTION: %s", ctx.channel());
-        logger.finefmt("PROXY HEADER: %s", proxyHeader);
         ctx.channel().attr(REMOTE_ADDRESS_KEY).set(proxyHeader.split(" ")[2]);
       } else {
         SocketAddress remoteAddress = ctx.channel().remoteAddress();
@@ -82,7 +77,6 @@ public class ProxyProtocolHandler extends ByteToMessageDecoder {
           ctx.channel()
               .attr(REMOTE_ADDRESS_KEY)
               .set(((InetSocketAddress) remoteAddress).getAddress().getHostAddress());
-          logger.finefmt("REMOTE IP ADDRESS: %s", ctx.channel().attr(REMOTE_ADDRESS_KEY).get());
         }
       }
       ctx.pipeline().remove(this);

java/google/registry/proxy/handler/SslClientInitializer.java

@@ -53,7 +53,7 @@ public class SslClientInitializer<C extends Channel> extends ChannelInitializer<
   SslClientInitializer(
       SslProvider sslProvider,
       @Nullable @Named("relayTrustedCertificates") X509Certificate... trustCertificates) {
-    logger.finefmt("Client SSL Provider: %s", sslProvider);
+    logger.infofmt("Client SSL Provider: %s", sslProvider);
     this.sslProvider = sslProvider;
     this.trustedCertificates = trustCertificates;
   }

java/google/registry/proxy/handler/SslServerInitializer.java

@@ -68,7 +68,7 @@ public class SslServerInitializer<C extends Channel> extends ChannelInitializer<
       SslProvider sslProvider,
       PrivateKey privateKey,
       @Named("eppServerCertificates") X509Certificate... certificates) {
-    logger.finefmt("Server SSL Provider: %s", sslProvider);
+    logger.infofmt("Server SSL Provider: %s", sslProvider);
     this.sslProvider = sslProvider;
     this.privateKey = privateKey;
     this.certificates = certificates;

java/google/registry/proxy/kubernetes/proxy-autoscale.yaml

@@ -0,0 +1,13 @@
+apiVersion: autoscaling/v2beta1
+kind: HorizontalPodAutoscaler
+metadata:
+  name: proxy-autoscale
+  labels:
+    app: proxy
+spec:
+  scaleTargetRef:
+    apiVersion: extensions/v1beta1
+    kind: Deployment
+    name: proxy-deployment
+  maxReplicas: 5
+  minReplicas: 1

java/google/registry/proxy/kubernetes/proxy-deployment.yaml

@@ -42,7 +42,7 @@ spec:
         - name: service-account
           mountPath: /var/secrets/google
         imagePullPolicy: Always
-        args: ["--log"]
+        args: ["--env", "alpha", "--log"]
         env:
         - name: GOOGLE_APPLICATION_CREDENTIALS
           value: /var/secrets/google/service-account.json

javatests/google/registry/proxy/GcpJsonFormatterTest.java

@@ -0,0 +1,108 @@
+// Copyright 2017 The Nomulus Authors. All Rights Reserved.
+//
+// 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 google.registry.proxy;
+
+import static com.google.common.truth.Truth.assertThat;
+
+import com.google.common.base.Joiner;
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+import org.junit.Before;
+import org.junit.Test;
+import org.junit.runner.RunWith;
+import org.junit.runners.JUnit4;
+
+/** Unit tests for {@link google.registry.proxy.GcpJsonFormatter}. */
+@RunWith(JUnit4.class)
+public class GcpJsonFormatterTest {
+
+  private static final String LOGGER_NAME = "example.company.app.logger";
+  private static final String SOURCE_CLASS_NAME = "example.company.app.component.Doer";
+  private static final String SOURCE_METHOD_NAME = "doStuff";
+  private static final String MESSAGE = "Something I have to say";
+
+  private final GcpJsonFormatter formatter = new GcpJsonFormatter();
+  private final LogRecord logRecord = new LogRecord(Level.WARNING, MESSAGE);
+
+  private static String makeJson(String severity, String source, String message) {
+    StringBuilder builder = new StringBuilder();
+    builder.append("{");
+    builder.append(
+        Joiner.on(",")
+            .join(
+                makeJsonField("severity", severity),
+                makeJsonField("source", source),
+                makeJsonField("message", "\\n" + message)));
+    builder.append("}\n");
+    return builder.toString();
+  }
+
+  private static String makeJsonField(String name, String content) {
+    return Joiner.on(":").join(addQuoteAndReplaceNewline(name), addQuoteAndReplaceNewline(content));
+  }
+
+  private static String addQuoteAndReplaceNewline(String content) {
+    // This quadruple escaping is hurting my eyes.
+    return "\"" + content.replaceAll("\n", "\\\\n") + "\"";
+  }
+
+  @Before
+  public void setUp() {
+    logRecord.setLoggerName(LOGGER_NAME);
+  }
+
+  @Test
+  public void testSuccess() {
+    String actual = formatter.format(logRecord);
+    String expected = makeJson("WARNING", LOGGER_NAME, MESSAGE);
+    assertThat(actual).isEqualTo(expected);
+  }
+
+  @Test
+  public void testSuccess_sourceClassAndMethod() {
+    logRecord.setSourceClassName(SOURCE_CLASS_NAME);
+    logRecord.setSourceMethodName(SOURCE_METHOD_NAME);
+    String actual = formatter.format(logRecord);
+    String expected = makeJson("WARNING", SOURCE_CLASS_NAME + " " + SOURCE_METHOD_NAME, MESSAGE);
+    assertThat(actual).isEqualTo(expected);
+  }
+
+  @Test
+  public void testSuccess_multilineMessage() {
+    String multilineMessage = "First line message\nSecond line message\n";
+    logRecord.setMessage(multilineMessage);
+    String actual = formatter.format(logRecord);
+    String expected = makeJson("WARNING", LOGGER_NAME, multilineMessage);
+    assertThat(actual).isEqualTo(expected);
+  }
+
+  @Test
+  public void testSuccess_withCause() {
+    Throwable throwable = new Throwable("Some reason");
+    StackTraceElement[] stacktrace = {
+      new StackTraceElement("class1", "method1", "file1", 5),
+      new StackTraceElement("class2", "method2", "file2", 10),
+    };
+    String stacktraceString =
+        "java.lang.Throwable: Some reason\\n"
+            + "\\tat class1.method1(file1:5)\\n"
+            + "\\tat class2.method2(file2:10)\\n";
+    throwable.setStackTrace(stacktrace);
+    logRecord.setThrown(throwable);
+    String actual = formatter.format(logRecord);
+    String expected = makeJson("WARNING", LOGGER_NAME, MESSAGE + "\\n" + stacktraceString);
+    assertThat(actual).isEqualTo(expected);
+  }
+}