search

apache / pulsar

Apache Pulsar - distributed pub-sub messaging system
https://pulsar.apache.org/
Apache License 2.0
14.15k stars 3.57k forks source link

Strange CPU usage in standalone using Docker #6175

Closed nicolo-paganin closed 4 years ago

nicolo-paganin commented 4 years ago

Describe the bug I am testing Pulsar 2.5.0 in the standalone mode using Docker 2.2.0.0. The container is created using docker-compose, this is the configuration:

pulsar:
    image: apachepulsar/pulsar:2.5.0
    ports:
      - "8080:8080"
      - "6650:6650"
    expose:
      - 8080
      - 6650
    environment:
      - PULSAR_MEM=" -Xms512m -Xmx512m -XX:MaxDirectMemorySize=1g"
    command: >
      /bin/bash -c
      "bin/apply-config-from-env.py conf/standalone.conf
      && bin/pulsar standalone"

I noted a strange cpu usage, always ~40% cpu usage without doing any operation after the docker-compose up, look at this log


Tasks:   3 total,   1 running,   2 sleeping,   0 stopped,   0 zombie
%Cpu(s):  5.6 us,  7.4 sy,  0.0 ni, 87.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   7964.3 total,   4760.5 free,   1862.6 used,   1341.2 buff/cache
MiB Swap:   1024.0 total,    947.5 free,     76.5 used.   5851.5 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
    1 root      20   0 5324348 637228  30316 S  33.3   7.8   7:00.23 /usr/local/openjdk-8/bin/java -cp /pulsar/conf:::/pulsar/lib/*: -Dlog4j.configurationFile=log4j2.yaml -Djute.maxbuffer=10485760 -Djava.net.preferIPv4Stack=true -Dpulsar.allocator.exit_on_oom=true -Dio.netty.recycler.maxCapacity.default=1000 -Dio.netty.recycler.linkCapacity=1024 -Xms512m -Xm+
  610 root      20   0    5752   3652   3128 S   0.0   0.0   0:00.11 bash
  692 root      20   0    9616   3328   2968 R   0.0   0.0   0:00.00 top

top - 10:57:20 up 14:11,  0 users,  load average: 0.35, 0.40, 0.94
Tasks:   3 total,   1 running,   2 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.7 us,  2.6 sy,  0.0 ni, 96.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   7964.3 total,   4758.7 free,   1864.3 used,   1341.2 buff/cache
MiB Swap:   1024.0 total,    947.5 free,     76.5 used.   5849.8 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
    1 root      20   0 5324348 637228  30316 S  31.7   7.8   7:01.18 /usr/local/openjdk-8/bin/java -cp /pulsar/conf:::/pulsar/lib/*: -Dlog4j.configurationFile=log4j2.yaml -Djute.maxbuffer=10485760 -Djava.net.preferIPv4Stack=true -Dpulsar.allocator.exit_on_oom=true -Dio.netty.recycler.maxCapacity.default=1000 -Dio.netty.recycler.linkCapacity=1024 -Xms512m -Xm+
  610 root      20   0    5752   3652   3128 S   0.0   0.0   0:00.11 bash
  692 root      20   0    9616   3328   2968 R   0.0   0.0   0:00.00 top```

is this normal?
jiazhai commented 4 years ago

@nicolo-paganin is there any suspicious error logs?

nicolo-paganin commented 4 years ago

Hi @jiazhai these are the logs starting from the command docker-compose up

Attaching to argo-compose_pulsar_1
pulsar_1          | [conf/pulsar_env.sh] Applying config PULSAR_MEM = " -Xms512m -Xmx512m -XX:MaxDirectMemorySize=1g"
pulsar_1          | [AppClassLoader@18b4aac2] info AspectJ Weaver Version 1.9.2 built on Wednesday Oct 24, 2018 at 15:43:33 GMT
pulsar_1          | [AppClassLoader@18b4aac2] info register classloader sun.misc.Launcher$AppClassLoader@18b4aac2
pulsar_1          | [AppClassLoader@18b4aac2] info using configuration file:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-2.5.0.jar!/META-INF/aop.xml
pulsar_1          | [AppClassLoader@18b4aac2] info using configuration file:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-utils-2.5.0.jar!/META-INF/aop.xml
pulsar_1          | [AppClassLoader@18b4aac2] info register aspect org.apache.pulsar.zookeeper.FinalRequestProcessorAspect
pulsar_1          | [AppClassLoader@18b4aac2] info register aspect org.apache.pulsar.zookeeper.ZooKeeperServerAspect
pulsar_1          | [AppClassLoader@18b4aac2] info register aspect org.apache.pulsar.broker.zookeeper.aspectj.ClientCnxnAspect
pulsar_1          | 10:10:58.231 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - Running 1 bookie(s) and advertised them at 127.0.0.1.
pulsar_1          | 10:10:58.243 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - Starting ZK server
pulsar_1          | [AppClassLoader@18b4aac2] info processing reweavable type org.apache.zookeeper.server.ZooKeeperServer: org/apache/zookeeper/server/ZooKeeperServer.java
pulsar_1          | [AppClassLoader@18b4aac2] info successfully verified type org.apache.pulsar.zookeeper.ZooKeeperServerAspect exists.  Originates from org/apache/pulsar/zookeeper/ZooKeeperServerAspect.java
pulsar_1          | 10:10:58.522 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:zookeeper.version=3.5.6-c11b7e26bc554b8523dc929761dd28808913f091, built on 10/08/2019 20:18 GMT
pulsar_1          | 10:10:58.522 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:host.name=add8b0c83481
pulsar_1          | 10:10:58.522 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:java.version=1.8.0_232
pulsar_1          | 10:10:58.523 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:java.vendor=Oracle Corporation
pulsar_1          | 10:10:58.523 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:java.home=/usr/local/openjdk-8/jre
pulsar_1          | 10:10:58.524 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:java.class.path=/pulsar/conf:::/pulsar/lib/com.sun.activation-javax.activation-1.2.0.jar:/pulsar/lib/org.apache.pulsar-managed-ledger-2.5.0.jar:/pulsar/lib/joda-time-joda-time-2.10.1.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-api-9.4.20.v20190813.jar:/pulsar/lib/org.glassfish.hk2-hk2-api-2.5.0-b42.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-client-9.4.20.v20190813.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-proto-4.10.0.jar:/pulsar/lib/javax.xml.bind-jaxb-api-2.3.1.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-worker-2.5.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-slf4j-impl-2.10.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-util-9.4.20.v20190813.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-api-examples-2.5.0.jar:/pulsar/lib/org.glassfish.jersey.ext-jersey-entity-filtering-2.27.jar:/pulsar/lib/io.kubernetes-client-java-api-2.0.0.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-servlet-9.4.20.v20190813.jar:/pulsar/lib/org.eclipse.jetty-jetty-servlet-9.4.20.v20190813.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-tools-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-secrets-2.5.0.jar:/pulsar/lib/org.apache.bookkeeper.stats-bookkeeper-stats-api-4.10.0.jar:/pulsar/lib/net.java.dev.jna-jna-4.2.0.jar:/pulsar/lib/javax.servlet-javax.servlet-api-3.1.0.jar:/pulsar/lib/org.slf4j-slf4j-api-1.7.25.jar:/pulsar/lib/com.fasterxml.jackson.module-jackson-module-jaxb-annotations-2.10.1.jar:/pulsar/lib/org.jvnet.mimepull-mimepull-1.9.6.jar:/pulsar/lib/org.glassfish.jersey.containers-jersey-container-servlet-core-2.27.jar:/pulsar/lib/org.glassfish.hk2-hk2-utils-2.5.0-b42.jar:/pulsar/lib/io.dropwizard.metrics-metrics-jvm-3.1.0.jar:/pulsar/lib/log4j-log4j-1.2.17.jar:/pulsar/lib/org.glassfish.jersey.media-jersey-media-json-jackson-2.27.jar:/pulsar/lib/io.netty-netty-tcnative-boringssl-static-2.0.26.Final.jar:/pulsar/lib/com.github.ben-manes.caffeine-caffeine-2.6.2.jar:/pulsar/lib/org.slf4j-jul-to-slf4j-1.7.25.jar:/pulsar/lib/org.apache.httpcomponents-httpcore-4.4.9.jar:/pulsar/lib/io.prometheus-simpleclient-0.5.0.jar:/pulsar/lib/io.grpc-grpc-testing-1.18.0.jar:/pulsar/lib/io.opencensus-opencensus-contrib-grpc-metrics-0.18.0.jar:/pulsar/lib/org.inferred-freebuilder-1.14.9.jar:/pulsar/lib/org.rocksdb-rocksdbjni-5.13.3.jar:/pulsar/lib/org.codehaus.jackson-jackson-core-asl-1.9.13.jar:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-runtime-2.5.0.jar:/pulsar/lib/commons-lang-commons-lang-2.6.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-admin-original-2.5.0.jar:/pulsar/lib/org.aspectj-aspectjweaver-1.9.2.jar:/pulsar/lib/javax.inject-javax.inject-1.jar:/pulsar/lib/io.grpc-grpc-okhttp-1.18.0.jar:/pulsar/lib/com.beust-jcommander-1.48.jar:/pulsar/lib/io.prometheus-simpleclient_hotspot-0.5.0.jar:/pulsar/lib/org.bouncycastle-bcprov-ext-jdk15on-1.60.jar:/pulsar/lib/org.apache.bookkeeper-statelib-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-utils-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-websocket-2.5.0.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-common-9.4.20.v20190813.jar:/pulsar/lib/org.hdrhistogram-HdrHistogram-2.1.9.jar:/pulsar/lib/com.thoughtworks.paranamer-paranamer-2.7.jar:/pulsar/lib/org.apache.pulsar-pulsar-io-core-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-server-9.4.20.v20190813.jar:/pulsar/lib/io.netty-netty-codec-dns-4.1.43.Final.jar:/pulsar/lib/org.apache.curator-curator-client-4.0.1.jar:/pulsar/lib/org.apache.avro-avro-protobuf-1.8.2.jar:/pulsar/lib/io.netty-netty-transport-4.1.43.Final.jar:/pulsar/lib/org.glassfish.jersey.media-jersey-media-multipart-2.27.jar:/pulsar/lib/jakarta.activation-jakarta.activation-api-1.2.1.jar:/pulsar/lib/org.xerial.snappy-snappy-java-1.1.1.3.jar:/pulsar/lib/javax.annotation-javax.annotation-api-1.2.jar:/pulsar/lib/io.prometheus-simpleclient_servlet-0.5.0.jar:/pulsar/lib/io.netty-netty-handler-4.1.43.Final.jar:/pulsar/lib/org.eclipse.jetty-jetty-security-9.4.20.v20190813.jar:/pulsar/lib/org.glassfish.hk2-osgi-resource-locator-1.0.1.jar:/pulsar/lib/io.netty-netty-common-4.1.43.Final.jar:/pulsar/lib/io.swagger-swagger-core-1.5.21.jar:/pulsar/lib/io.vertx-vertx-auth-common-3.4.1.jar:/pulsar/lib/org.glassfish.jersey.core-jersey-server-2.27.jar:/pulsar/lib/commons-cli-commons-cli-1.2.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-core-4.10.0.jar:/pulsar/lib/org.slf4j-jcl-over-slf4j-1.7.25.jar:/pulsar/lib/org.eclipse.jetty-jetty-xml-9.4.20.v20190813.jar:/pulsar/lib/net.jcip-jcip-annotations-1.0.jar:/pulsar/lib/com.github.luben-zstd-jni-1.3.7-3.jar:/pulsar/lib/io.jsonwebtoken-jjwt-api-0.10.5.jar:/pulsar/lib/org.checkerframework-checker-qual-2.0.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-web-2.10.0.jar:/pulsar/lib/org.apache.bookkeeper.stats-codahale-metrics-provider-4.10.0.jar:/pulsar/lib/com.github.zafarkhaja-java-semver-0.9.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-service-impl-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-utils-2.5.0.jar:/pulsar/lib/io.netty-netty-codec-http-4.1.43.Final.jar:/pulsar/lib/com.google.errorprone-error_prone_annotations-2.1.3.jar:/pulsar/lib/io.netty-netty-resolver-dns-4.1.43.Final.jar:/pulsar/lib/org.glassfish.hk2.external-aopalliance-repackaged-2.5.0-b42.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-api-4.10.0.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-tools-framework-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-broker-2.5.0.jar:/pulsar/lib/io.netty-netty-codec-http2-4.1.43.Final.jar:/pulsar/lib/com.yahoo.datasketches-memory-0.8.3.jar:/pulsar/lib/org.reactivestreams-reactive-streams-1.0.2.jar:/pulsar/lib/io.prometheus-simpleclient_caffeine-0.5.0.jar:/pulsar/lib/org.yaml-snakeyaml-1.24.jar:/pulsar/lib/org.eclipse.jetty-jetty-http-9.4.20.v20190813.jar:/pulsar/lib/com.google.code.gson-gson-2.8.2.jar:/pulsar/lib/com.fasterxml.jackson.core-jackson-annotations-2.10.1.jar:/pulsar/lib/io.grpc-grpc-all-1.18.0.jar:/pulsar/lib/commons-io-commons-io-2.5.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-common-allocator-4.10.0.jar:/pulsar/lib/commons-codec-commons-codec-1.10.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-common-4.10.0.jar:/pulsar/lib/io.swagger-swagger-annotations-1.5.21.jar:/pulsar/lib/commons-collections-commons-collections-3.2.2.jar:/pulsar/lib/com.squareup.okio-okio-1.13.0.jar:/pulsar/lib/io.jsonwebtoken-jjwt-jackson-0.10.5.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-server-4.10.0.jar:/pulsar/lib/io.vertx-vertx-web-3.4.1.jar:/pulsar/lib/io.jsonwebtoken-jjwt-impl-0.10.5.jar:/pulsar/lib/org.apache.pulsar-pulsar-proxy-2.5.0.jar:/pulsar/lib/io.netty-netty-resolver-4.1.43.Final.jar:/pulsar/lib/org.apache.bookkeeper.stats-prometheus-metrics-provider-4.10.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-service-api-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-common-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-testclient-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-api-2.5.0.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-server-9.4.20.v20190813.jar:/pulsar/lib/com.squareup.okhttp-okhttp-ws-2.7.5.jar:/pulsar/lib/io.grpc-grpc-protobuf-lite-1.18.0.jar:/pulsar/lib/io.netty-netty-transport-native-epoll-4.1.43.Final.jar:/pulsar/lib/com.squareup.okhttp-okhttp-2.5.0.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:/pulsar/lib/org.glassfish.jersey.core-jersey-common-2.27.jar:/pulsar/lib/io.vertx-vertx-core-3.4.1.jar:/pulsar/lib/org.asynchttpclient-async-http-client-2.7.0.jar:/pulsar/lib/com.carrotsearch-hppc-0.7.3.jar:/pulsar/lib/org.bouncycastle-bcpkix-jdk15on-1.60.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-api-2.5.0.jar:/pulsar/lib/io.netty-netty-handler-proxy-4.1.43.Final.jar:/pulsar/lib/io.kubernetes-client-java-proto-2.0.0.jar:/pulsar/lib/io.grpc-grpc-netty-1.18.0.jar:/pulsar/lib/com.google.protobuf-protobuf-java-3.5.1.jar:/pulsar/lib/org.lz4-lz4-java-1.5.0.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-broker-auth-sasl-2.5.0.jar:/pulsar/lib/net.jodah-typetools-0.5.0.jar:/pulsar/lib/com.google.j2objc-j2objc-annotations-1.1.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-local-runner-original-2.5.0.jar:/pulsar/lib/com.google.auth-google-auth-library-credentials-0.9.0.jar:/pulsar/lib/com.fasterxml.jackson.jaxrs-jackson-jaxrs-json-provider-2.10.1.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-original-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-auth-sasl-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-servlets-9.4.20.v20190813.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-proto-4.10.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-java-client-base-4.10.0.jar:/pulsar/lib/org.codehaus.jackson-jackson-mapper-asl-1.9.13.jar:/pulsar/lib/com.squareup.okhttp-logging-interceptor-2.7.5.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-instance-2.5.0.jar:/pulsar/lib/org.glassfish.jersey.inject-jersey-hk2-2.27.jar:/pulsar/lib/io.prometheus-simpleclient_jetty-0.5.0.jar:/pulsar/lib/com.fasterxml.jackson.core-jackson-databind-2.10.1.jar:/pulsar/lib/commons-logging-commons-logging-1.1.1.jar:/pulsar/lib/javax.validation-validation-api-1.1.0.Final.jar:/pulsar/lib/io.prometheus-simpleclient_httpserver-0.5.0.jar:/pulsar/lib/io.opencensus-opencensus-api-0.18.0.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-core-4.10.0-tests.jar:/pulsar/lib/io.grpc-grpc-core-1.18.0.jar:/pulsar/lib/com.google.guava-guava-25.1-jre.jar:/pulsar/lib/com.google.code.findbugs-jsr305-3.0.2.jar:/pulsar/lib/org.apache.zookeeper-zookeeper-jute-3.5.6.jar:/pulsar/lib/org.eclipse.jetty-jetty-continuation-9.4.20.v20190813.jar:/pulsar/lib/io.netty-netty-transport-native-unix-common-4.1.43.Final.jar:/pulsar/lib/org.eclipse.jetty.websocket-javax-websocket-client-impl-9.4.20.v20190813.jar:/pulsar/lib/com.fasterxml.jackson.dataformat-jackson-dataformat-yaml-2.10.1.jar:/pulsar/lib/io.dropwizard.metrics-metrics-core-3.1.0.jar:/pulsar/lib/org.asynchttpclient-async-http-client-netty-utils-2.7.0.jar:/pulsar/lib/io.dropwizard.metrics-metrics-graphite-3.1.0.jar:/pulsar/lib/io.netty-netty-codec-socks-4.1.43.Final.jar:/pulsar/lib/javax.ws.rs-javax.ws.rs-api-2.1.jar:/pulsar/lib/com.fasterxml.jackson.core-jackson-core-2.10.1.jar:/pulsar/lib/com.typesafe.netty-netty-reactive-streams-2.0.0.jar:/pulsar/lib/org.apache.bookkeeper.http-http-server-4.10.0.jar:/pulsar/lib/org.aspectj-aspectjrt-1.9.2.jar:/pulsar/lib/org.tukaani-xz-1.5.jar:/pulsar/lib/io.netty-netty-buffer-4.1.43.Final.jar:/pulsar/lib/org.apache.commons-commons-compress-1.19.jar:/pulsar/lib/org.apache.pulsar-protobuf-shaded-2.1.0-incubating.jar:/pulsar/lib/io.netty-netty-codec-4.1.43.Final.jar:/pulsar/lib/org.apache.pulsar-pulsar-discovery-service-2.5.0.jar:/pulsar/lib/org.apache.yetus-audience-annotations-0.5.0.jar:/pulsar/lib/jakarta.xml.bind-jakarta.xml.bind-api-2.3.2.jar:/pulsar/lib/org.apache.commons-commons-collections4-4.1.jar:/pulsar/lib/org.apache.httpcomponents-httpclient-4.5.5.jar:/pulsar/lib/org.javassist-javassist-3.25.0-GA.jar:/pulsar/lib/com.yahoo.datasketches-sketches-core-0.8.3.jar:/pulsar/lib/io.grpc-grpc-protobuf-nano-1.18.0.jar:/pulsar/lib/org.apache.bookkeeper-circe-checksum-4.10.0.jar:/pulsar/lib/org.glassfish.hk2.external-javax.inject-2.5.0-b42.jar:/pulsar/lib/org.apache.bookkeeper.tests-stream-storage-tests-common-4.10.0.jar:/pulsar/lib/io.swagger-swagger-models-1.5.21.jar:/pulsar/lib/org.apache.curator-curator-recipes-4.0.1.jar:/pulsar/lib/org.apache.curator-curator-framework-4.0.1.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-protocol-4.10.0.jar:/pulsar/lib/org.codehaus.mojo-animal-sniffer-annotations-1.14.jar:/pulsar/lib/org.apache.avro-avro-1.8.2.jar:/pulsar/lib/io.grpc-grpc-auth-1.18.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-proto-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-proxy-9.4.20.v20190813.jar:/pulsar/lib/io.prometheus-simpleclient_common-0.5.0.jar:/pulsar/lib/io.prometheus.jmx-collector-0.12.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-core-2.10.0.jar:/pulsar/lib/org.glassfish.jersey.media-jersey-media-jaxb-2.27.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-common-4.10.0.jar:/pulsar/lib/org.checkerframework-checker-compat-qual-2.5.2.jar:/pulsar/lib/io.prometheus-simpleclient_log4j2-0.5.0.jar:/pulsar/lib/commons-configuration-commons-configuration-1.10.jar:/pulsar/lib/io.grpc-grpc-protobuf-1.18.0.jar:/pulsar/lib/io.grpc-grpc-stub-1.18.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-api-2.10.0.jar:/pulsar/lib/org.apache.bookkeeper.http-vertx-http-server-4.10.0.jar:/pulsar/lib/org.apache.commons-commons-lang3-3.4.jar:/pulsar/lib/javax.websocket-javax.websocket-client-api-1.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-transaction-coordinator-2.5.0.jar:/pulsar/lib/org.bouncycastle-bcprov-jdk15on-1.60.jar:/pulsar/lib/org.apache.bookkeeper-cpu-affinity-4.10.0.jar:/pulsar/lib/org.hamcrest-hamcrest-core-1.3.jar:/pulsar/lib/io.grpc-grpc-context-1.18.0.jar:/pulsar/lib/org.glassfish.jersey.core-jersey-client-2.27.jar:/pulsar/lib/com.google.api.grpc-proto-google-common-protos-1.12.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-transaction-common-2.5.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-java-client-4.10.0.jar:/pulsar/lib/com.google.protobuf-protobuf-java-util-3.5.1.jar:/pulsar/lib/org.jctools-jctools-core-2.1.2.jar:/pulsar/lib/org.eclipse.jetty-jetty-io-9.4.20.v20190813.jar:/pulsar/lib/io.kubernetes-client-java-2.0.0.jar:/pulsar/lib/com.google.protobuf.nano-protobuf-javanano-3.0.0-alpha-5.jar:/pulsar/lib/org.apache.pulsar-pulsar-broker-common-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-client-9.4.20.v20190813.jar:/pulsar/lib/com.fasterxml.jackson.jaxrs-jackson-jaxrs-base-2.10.1.jar:/pulsar/lib/com.fasterxml.jackson.module-jackson-module-jsonSchema-2.10.1.jar:/pulsar/lib/org.glassfish.hk2-hk2-locator-2.5.0-b42.jar:/pulsar/lib/org.glassfish.jersey.containers-jersey-container-servlet-2.27.jar::/pulsar/lib/org.aspectj-aspectjweaver-1.9.2.jar
pulsar_1          | 10:10:58.527 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:java.io.tmpdir=/tmp
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:java.compiler=<NA>
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:os.name=Linux
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:os.arch=amd64
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:os.version=4.19.76-linuxkit
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:user.name=root
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:user.home=/root
pulsar_1          | 10:10:58.528 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:user.dir=/pulsar
pulsar_1          | 10:10:58.529 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:os.memory.free=459MB
pulsar_1          | 10:10:58.529 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:os.memory.max=512MB
pulsar_1          | 10:10:58.529 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Server environment:os.memory.total=512MB
pulsar_1          | 10:10:58.534 [main] INFO  org.apache.zookeeper.server.persistence.FileTxnSnapLog - zookeeper.snapshot.trust.empty : true
pulsar_1          | 10:10:58.572 [main] INFO  org.apache.zookeeper.server.ZKDatabase - zookeeper.snapshotSizeFactor = 0.33
pulsar_1          | 10:10:58.578 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - minSessionTimeout set to 6000
pulsar_1          | 10:10:58.579 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - maxSessionTimeout set to 60000
pulsar_1          | 10:10:58.581 [main] INFO  org.apache.zookeeper.server.ZooKeeperServer - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /pulsar/data/standalone/zookeeper/version-2 snapdir /pulsar/data/standalone/zookeeper/version-2
pulsar_1          | 10:10:58.619 [main] INFO  org.apache.zookeeper.server.NIOServerCnxnFactory - Configuring NIO connection handler with 10s sessionless connection timeout, 1 selector thread(s), 8 worker threads, and 64 kB direct buffers.
pulsar_1          | 10:10:58.635 [main] INFO  org.apache.zookeeper.server.NIOServerCnxnFactory - binding to port 0.0.0.0/0.0.0.0:2181
pulsar_1          | 10:10:58.655 [main] INFO  org.apache.zookeeper.server.persistence.FileTxnSnapLog - Snapshotting: 0x0 to /pulsar/data/standalone/zookeeper/version-2/snapshot.0
pulsar_1          | 10:10:58.663 [main] INFO  org.apache.zookeeper.server.persistence.FileTxnSnapLog - Snapshotting: 0x0 to /pulsar/data/standalone/zookeeper/version-2/snapshot.0
pulsar_1          | [AppClassLoader@18b4aac2] info processing reweavable type org.apache.zookeeper.server.FinalRequestProcessor: org/apache/zookeeper/server/FinalRequestProcessor.java
pulsar_1          | [AppClassLoader@18b4aac2] info successfully verified type org.apache.pulsar.zookeeper.FinalRequestProcessorAspect exists.  Originates from org/apache/pulsar/zookeeper/FinalRequestProcessorAspect.java
pulsar_1          | 10:10:58.811 [NIOWorkerThread-1] INFO  org.apache.zookeeper.server.command.FourLetterCommands - The list of known four letter word commands is : [{1936881266=srvr, 1937006964=stat, 2003003491=wchc, 1685417328=dump, 1668445044=crst, 1936880500=srst, 1701738089=envi, 1668247142=conf, -720899=telnet close, 2003003507=wchs, 2003003504=wchp, 1684632179=dirs, 1668247155=cons, 1835955314=mntr, 1769173615=isro, 1920298859=ruok, 1735683435=gtmk, 1937010027=stmk}]
pulsar_1          | 10:10:58.812 [NIOWorkerThread-1] INFO  org.apache.zookeeper.server.command.FourLetterCommands - The list of enabled four letter word commands is : [[wchs, stat, wchp, dirs, stmk, conf, ruok, mntr, srvr, wchc, envi, srst, isro, dump, gtmk, telnet close, crst, cons]]
pulsar_1          | 10:10:58.813 [NIOWorkerThread-1] INFO  org.apache.zookeeper.server.NIOServerCnxn - Processing stat command from /127.0.0.1:55148
pulsar_1          | 10:10:58.826 [NIOWorkerThread-1] INFO  org.apache.zookeeper.server.command.AbstractFourLetterCommand - Stat command output
pulsar_1          | 10:10:58.829 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - Server UP
pulsar_1          | 10:10:58.830 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - ZooKeeper server up: true
pulsar_1          | 10:10:58.831 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - Instantiate ZK Client
pulsar_1          | 10:10:58.842 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:zookeeper.version=3.5.6-c11b7e26bc554b8523dc929761dd28808913f091, built on 10/08/2019 20:18 GMT
pulsar_1          | 10:10:58.842 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:host.name=add8b0c83481
pulsar_1          | 10:10:58.843 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:java.version=1.8.0_232
pulsar_1          | 10:10:58.843 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:java.vendor=Oracle Corporation
pulsar_1          | 10:10:58.843 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:java.home=/usr/local/openjdk-8/jre
pulsar_1          | 10:10:58.844 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:java.class.path=/pulsar/conf:::/pulsar/lib/com.sun.activation-javax.activation-1.2.0.jar:/pulsar/lib/org.apache.pulsar-managed-ledger-2.5.0.jar:/pulsar/lib/joda-time-joda-time-2.10.1.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-api-9.4.20.v20190813.jar:/pulsar/lib/org.glassfish.hk2-hk2-api-2.5.0-b42.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-client-9.4.20.v20190813.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-proto-4.10.0.jar:/pulsar/lib/javax.xml.bind-jaxb-api-2.3.1.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-worker-2.5.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-slf4j-impl-2.10.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-util-9.4.20.v20190813.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-api-examples-2.5.0.jar:/pulsar/lib/org.glassfish.jersey.ext-jersey-entity-filtering-2.27.jar:/pulsar/lib/io.kubernetes-client-java-api-2.0.0.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-servlet-9.4.20.v20190813.jar:/pulsar/lib/org.eclipse.jetty-jetty-servlet-9.4.20.v20190813.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-tools-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-secrets-2.5.0.jar:/pulsar/lib/org.apache.bookkeeper.stats-bookkeeper-stats-api-4.10.0.jar:/pulsar/lib/net.java.dev.jna-jna-4.2.0.jar:/pulsar/lib/javax.servlet-javax.servlet-api-3.1.0.jar:/pulsar/lib/org.slf4j-slf4j-api-1.7.25.jar:/pulsar/lib/com.fasterxml.jackson.module-jackson-module-jaxb-annotations-2.10.1.jar:/pulsar/lib/org.jvnet.mimepull-mimepull-1.9.6.jar:/pulsar/lib/org.glassfish.jersey.containers-jersey-container-servlet-core-2.27.jar:/pulsar/lib/org.glassfish.hk2-hk2-utils-2.5.0-b42.jar:/pulsar/lib/io.dropwizard.metrics-metrics-jvm-3.1.0.jar:/pulsar/lib/log4j-log4j-1.2.17.jar:/pulsar/lib/org.glassfish.jersey.media-jersey-media-json-jackson-2.27.jar:/pulsar/lib/io.netty-netty-tcnative-boringssl-static-2.0.26.Final.jar:/pulsar/lib/com.github.ben-manes.caffeine-caffeine-2.6.2.jar:/pulsar/lib/org.slf4j-jul-to-slf4j-1.7.25.jar:/pulsar/lib/org.apache.httpcomponents-httpcore-4.4.9.jar:/pulsar/lib/io.prometheus-simpleclient-0.5.0.jar:/pulsar/lib/io.grpc-grpc-testing-1.18.0.jar:/pulsar/lib/io.opencensus-opencensus-contrib-grpc-metrics-0.18.0.jar:/pulsar/lib/org.inferred-freebuilder-1.14.9.jar:/pulsar/lib/org.rocksdb-rocksdbjni-5.13.3.jar:/pulsar/lib/org.codehaus.jackson-jackson-core-asl-1.9.13.jar:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-runtime-2.5.0.jar:/pulsar/lib/commons-lang-commons-lang-2.6.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-admin-original-2.5.0.jar:/pulsar/lib/org.aspectj-aspectjweaver-1.9.2.jar:/pulsar/lib/javax.inject-javax.inject-1.jar:/pulsar/lib/io.grpc-grpc-okhttp-1.18.0.jar:/pulsar/lib/com.beust-jcommander-1.48.jar:/pulsar/lib/io.prometheus-simpleclient_hotspot-0.5.0.jar:/pulsar/lib/org.bouncycastle-bcprov-ext-jdk15on-1.60.jar:/pulsar/lib/org.apache.bookkeeper-statelib-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-utils-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-websocket-2.5.0.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-common-9.4.20.v20190813.jar:/pulsar/lib/org.hdrhistogram-HdrHistogram-2.1.9.jar:/pulsar/lib/com.thoughtworks.paranamer-paranamer-2.7.jar:/pulsar/lib/org.apache.pulsar-pulsar-io-core-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-server-9.4.20.v20190813.jar:/pulsar/lib/io.netty-netty-codec-dns-4.1.43.Final.jar:/pulsar/lib/org.apache.curator-curator-client-4.0.1.jar:/pulsar/lib/org.apache.avro-avro-protobuf-1.8.2.jar:/pulsar/lib/io.netty-netty-transport-4.1.43.Final.jar:/pulsar/lib/org.glassfish.jersey.media-jersey-media-multipart-2.27.jar:/pulsar/lib/jakarta.activation-jakarta.activation-api-1.2.1.jar:/pulsar/lib/org.xerial.snappy-snappy-java-1.1.1.3.jar:/pulsar/lib/javax.annotation-javax.annotation-api-1.2.jar:/pulsar/lib/io.prometheus-simpleclient_servlet-0.5.0.jar:/pulsar/lib/io.netty-netty-handler-4.1.43.Final.jar:/pulsar/lib/org.eclipse.jetty-jetty-security-9.4.20.v20190813.jar:/pulsar/lib/org.glassfish.hk2-osgi-resource-locator-1.0.1.jar:/pulsar/lib/io.netty-netty-common-4.1.43.Final.jar:/pulsar/lib/io.swagger-swagger-core-1.5.21.jar:/pulsar/lib/io.vertx-vertx-auth-common-3.4.1.jar:/pulsar/lib/org.glassfish.jersey.core-jersey-server-2.27.jar:/pulsar/lib/commons-cli-commons-cli-1.2.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-core-4.10.0.jar:/pulsar/lib/org.slf4j-jcl-over-slf4j-1.7.25.jar:/pulsar/lib/org.eclipse.jetty-jetty-xml-9.4.20.v20190813.jar:/pulsar/lib/net.jcip-jcip-annotations-1.0.jar:/pulsar/lib/com.github.luben-zstd-jni-1.3.7-3.jar:/pulsar/lib/io.jsonwebtoken-jjwt-api-0.10.5.jar:/pulsar/lib/org.checkerframework-checker-qual-2.0.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-web-2.10.0.jar:/pulsar/lib/org.apache.bookkeeper.stats-codahale-metrics-provider-4.10.0.jar:/pulsar/lib/com.github.zafarkhaja-java-semver-0.9.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-service-impl-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-utils-2.5.0.jar:/pulsar/lib/io.netty-netty-codec-http-4.1.43.Final.jar:/pulsar/lib/com.google.errorprone-error_prone_annotations-2.1.3.jar:/pulsar/lib/io.netty-netty-resolver-dns-4.1.43.Final.jar:/pulsar/lib/org.glassfish.hk2.external-aopalliance-repackaged-2.5.0-b42.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-api-4.10.0.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-tools-framework-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-broker-2.5.0.jar:/pulsar/lib/io.netty-netty-codec-http2-4.1.43.Final.jar:/pulsar/lib/com.yahoo.datasketches-memory-0.8.3.jar:/pulsar/lib/org.reactivestreams-reactive-streams-1.0.2.jar:/pulsar/lib/io.prometheus-simpleclient_caffeine-0.5.0.jar:/pulsar/lib/org.yaml-snakeyaml-1.24.jar:/pulsar/lib/org.eclipse.jetty-jetty-http-9.4.20.v20190813.jar:/pulsar/lib/com.google.code.gson-gson-2.8.2.jar:/pulsar/lib/com.fasterxml.jackson.core-jackson-annotations-2.10.1.jar:/pulsar/lib/io.grpc-grpc-all-1.18.0.jar:/pulsar/lib/commons-io-commons-io-2.5.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-common-allocator-4.10.0.jar:/pulsar/lib/commons-codec-commons-codec-1.10.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-common-4.10.0.jar:/pulsar/lib/io.swagger-swagger-annotations-1.5.21.jar:/pulsar/lib/commons-collections-commons-collections-3.2.2.jar:/pulsar/lib/com.squareup.okio-okio-1.13.0.jar:/pulsar/lib/io.jsonwebtoken-jjwt-jackson-0.10.5.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-server-4.10.0.jar:/pulsar/lib/io.vertx-vertx-web-3.4.1.jar:/pulsar/lib/io.jsonwebtoken-jjwt-impl-0.10.5.jar:/pulsar/lib/org.apache.pulsar-pulsar-proxy-2.5.0.jar:/pulsar/lib/io.netty-netty-resolver-4.1.43.Final.jar:/pulsar/lib/org.apache.bookkeeper.stats-prometheus-metrics-provider-4.10.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-service-api-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-common-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-testclient-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-api-2.5.0.jar:/pulsar/lib/org.eclipse.jetty.websocket-websocket-server-9.4.20.v20190813.jar:/pulsar/lib/com.squareup.okhttp-okhttp-ws-2.7.5.jar:/pulsar/lib/io.grpc-grpc-protobuf-lite-1.18.0.jar:/pulsar/lib/io.netty-netty-transport-native-epoll-4.1.43.Final.jar:/pulsar/lib/com.squareup.okhttp-okhttp-2.5.0.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:/pulsar/lib/org.glassfish.jersey.core-jersey-common-2.27.jar:/pulsar/lib/io.vertx-vertx-core-3.4.1.jar:/pulsar/lib/org.asynchttpclient-async-http-client-2.7.0.jar:/pulsar/lib/com.carrotsearch-hppc-0.7.3.jar:/pulsar/lib/org.bouncycastle-bcpkix-jdk15on-1.60.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-api-2.5.0.jar:/pulsar/lib/io.netty-netty-handler-proxy-4.1.43.Final.jar:/pulsar/lib/io.kubernetes-client-java-proto-2.0.0.jar:/pulsar/lib/io.grpc-grpc-netty-1.18.0.jar:/pulsar/lib/com.google.protobuf-protobuf-java-3.5.1.jar:/pulsar/lib/org.lz4-lz4-java-1.5.0.jar:/pulsar/lib/org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-broker-auth-sasl-2.5.0.jar:/pulsar/lib/net.jodah-typetools-0.5.0.jar:/pulsar/lib/com.google.j2objc-j2objc-annotations-1.1.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-local-runner-original-2.5.0.jar:/pulsar/lib/com.google.auth-google-auth-library-credentials-0.9.0.jar:/pulsar/lib/com.fasterxml.jackson.jaxrs-jackson-jaxrs-json-provider-2.10.1.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-original-2.5.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-client-auth-sasl-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-servlets-9.4.20.v20190813.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-proto-4.10.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-java-client-base-4.10.0.jar:/pulsar/lib/org.codehaus.jackson-jackson-mapper-asl-1.9.13.jar:/pulsar/lib/com.squareup.okhttp-logging-interceptor-2.7.5.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-instance-2.5.0.jar:/pulsar/lib/org.glassfish.jersey.inject-jersey-hk2-2.27.jar:/pulsar/lib/io.prometheus-simpleclient_jetty-0.5.0.jar:/pulsar/lib/com.fasterxml.jackson.core-jackson-databind-2.10.1.jar:/pulsar/lib/commons-logging-commons-logging-1.1.1.jar:/pulsar/lib/javax.validation-validation-api-1.1.0.Final.jar:/pulsar/lib/io.prometheus-simpleclient_httpserver-0.5.0.jar:/pulsar/lib/io.opencensus-opencensus-api-0.18.0.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-core-4.10.0-tests.jar:/pulsar/lib/io.grpc-grpc-core-1.18.0.jar:/pulsar/lib/com.google.guava-guava-25.1-jre.jar:/pulsar/lib/com.google.code.findbugs-jsr305-3.0.2.jar:/pulsar/lib/org.apache.zookeeper-zookeeper-jute-3.5.6.jar:/pulsar/lib/org.eclipse.jetty-jetty-continuation-9.4.20.v20190813.jar:/pulsar/lib/io.netty-netty-transport-native-unix-common-4.1.43.Final.jar:/pulsar/lib/org.eclipse.jetty.websocket-javax-websocket-client-impl-9.4.20.v20190813.jar:/pulsar/lib/com.fasterxml.jackson.dataformat-jackson-dataformat-yaml-2.10.1.jar:/pulsar/lib/io.dropwizard.metrics-metrics-core-3.1.0.jar:/pulsar/lib/org.asynchttpclient-async-http-client-netty-utils-2.7.0.jar:/pulsar/lib/io.dropwizard.metrics-metrics-graphite-3.1.0.jar:/pulsar/lib/io.netty-netty-codec-socks-4.1.43.Final.jar:/pulsar/lib/javax.ws.rs-javax.ws.rs-api-2.1.jar:/pulsar/lib/com.fasterxml.jackson.core-jackson-core-2.10.1.jar:/pulsar/lib/com.typesafe.netty-netty-reactive-streams-2.0.0.jar:/pulsar/lib/org.apache.bookkeeper.http-http-server-4.10.0.jar:/pulsar/lib/org.aspectj-aspectjrt-1.9.2.jar:/pulsar/lib/org.tukaani-xz-1.5.jar:/pulsar/lib/io.netty-netty-buffer-4.1.43.Final.jar:/pulsar/lib/org.apache.commons-commons-compress-1.19.jar:/pulsar/lib/org.apache.pulsar-protobuf-shaded-2.1.0-incubating.jar:/pulsar/lib/io.netty-netty-codec-4.1.43.Final.jar:/pulsar/lib/org.apache.pulsar-pulsar-discovery-service-2.5.0.jar:/pulsar/lib/org.apache.yetus-audience-annotations-0.5.0.jar:/pulsar/lib/jakarta.xml.bind-jakarta.xml.bind-api-2.3.2.jar:/pulsar/lib/org.apache.commons-commons-collections4-4.1.jar:/pulsar/lib/org.apache.httpcomponents-httpclient-4.5.5.jar:/pulsar/lib/org.javassist-javassist-3.25.0-GA.jar:/pulsar/lib/com.yahoo.datasketches-sketches-core-0.8.3.jar:/pulsar/lib/io.grpc-grpc-protobuf-nano-1.18.0.jar:/pulsar/lib/org.apache.bookkeeper-circe-checksum-4.10.0.jar:/pulsar/lib/org.glassfish.hk2.external-javax.inject-2.5.0-b42.jar:/pulsar/lib/org.apache.bookkeeper.tests-stream-storage-tests-common-4.10.0.jar:/pulsar/lib/io.swagger-swagger-models-1.5.21.jar:/pulsar/lib/org.apache.curator-curator-recipes-4.0.1.jar:/pulsar/lib/org.apache.curator-curator-framework-4.0.1.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-protocol-4.10.0.jar:/pulsar/lib/org.codehaus.mojo-animal-sniffer-annotations-1.14.jar:/pulsar/lib/org.apache.avro-avro-1.8.2.jar:/pulsar/lib/io.grpc-grpc-auth-1.18.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-functions-proto-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-proxy-9.4.20.v20190813.jar:/pulsar/lib/io.prometheus-simpleclient_common-0.5.0.jar:/pulsar/lib/io.prometheus.jmx-collector-0.12.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-core-2.10.0.jar:/pulsar/lib/org.glassfish.jersey.media-jersey-media-jaxb-2.27.jar:/pulsar/lib/org.apache.distributedlog-distributedlog-common-4.10.0.jar:/pulsar/lib/org.checkerframework-checker-compat-qual-2.5.2.jar:/pulsar/lib/io.prometheus-simpleclient_log4j2-0.5.0.jar:/pulsar/lib/commons-configuration-commons-configuration-1.10.jar:/pulsar/lib/io.grpc-grpc-protobuf-1.18.0.jar:/pulsar/lib/io.grpc-grpc-stub-1.18.0.jar:/pulsar/lib/org.apache.logging.log4j-log4j-api-2.10.0.jar:/pulsar/lib/org.apache.bookkeeper.http-vertx-http-server-4.10.0.jar:/pulsar/lib/org.apache.commons-commons-lang3-3.4.jar:/pulsar/lib/javax.websocket-javax.websocket-client-api-1.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-transaction-coordinator-2.5.0.jar:/pulsar/lib/org.bouncycastle-bcprov-jdk15on-1.60.jar:/pulsar/lib/org.apache.bookkeeper-cpu-affinity-4.10.0.jar:/pulsar/lib/org.hamcrest-hamcrest-core-1.3.jar:/pulsar/lib/io.grpc-grpc-context-1.18.0.jar:/pulsar/lib/org.glassfish.jersey.core-jersey-client-2.27.jar:/pulsar/lib/com.google.api.grpc-proto-google-common-protos-1.12.0.jar:/pulsar/lib/org.apache.pulsar-pulsar-transaction-common-2.5.0.jar:/pulsar/lib/org.apache.bookkeeper-stream-storage-java-client-4.10.0.jar:/pulsar/lib/com.google.protobuf-protobuf-java-util-3.5.1.jar:/pulsar/lib/org.jctools-jctools-core-2.1.2.jar:/pulsar/lib/org.eclipse.jetty-jetty-io-9.4.20.v20190813.jar:/pulsar/lib/io.kubernetes-client-java-2.0.0.jar:/pulsar/lib/com.google.protobuf.nano-protobuf-javanano-3.0.0-alpha-5.jar:/pulsar/lib/org.apache.pulsar-pulsar-broker-common-2.5.0.jar:/pulsar/lib/org.eclipse.jetty-jetty-client-9.4.20.v20190813.jar:/pulsar/lib/com.fasterxml.jackson.jaxrs-jackson-jaxrs-base-2.10.1.jar:/pulsar/lib/com.fasterxml.jackson.module-jackson-module-jsonSchema-2.10.1.jar:/pulsar/lib/org.glassfish.hk2-hk2-locator-2.5.0-b42.jar:/pulsar/lib/org.glassfish.jersey.containers-jersey-container-servlet-2.27.jar::/pulsar/lib/org.aspectj-aspectjweaver-1.9.2.jar
pulsar_1          | 10:10:58.845 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
pulsar_1          | 10:10:58.846 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:java.io.tmpdir=/tmp
pulsar_1          | 10:10:58.846 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:java.compiler=<NA>
pulsar_1          | 10:10:58.846 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:os.name=Linux
pulsar_1          | 10:10:58.846 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:os.arch=amd64
pulsar_1          | 10:10:58.846 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:os.version=4.19.76-linuxkit
pulsar_1          | 10:10:58.846 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:user.name=root
pulsar_1          | 10:10:58.846 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:user.home=/root
pulsar_1          | 10:10:58.847 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:user.dir=/pulsar
pulsar_1          | 10:10:58.847 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:os.memory.free=442MB
pulsar_1          | 10:10:58.847 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:os.memory.max=512MB
pulsar_1          | 10:10:58.847 [main] INFO  org.apache.zookeeper.ZooKeeper - Client environment:os.memory.total=512MB
pulsar_1          | 10:10:58.858 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=5000 watcher=org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble$ZKConnectionWatcher@13c612bd
pulsar_1          | 10:10:58.879 [main] INFO  org.apache.zookeeper.common.X509Util - Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation
pulsar_1          | 10:10:58.887 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:10:58.908 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:10:58.931 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:10:58.933 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55150, server: localhost/127.0.0.1:2181
pulsar_1          | 10:10:58.946 [SyncThread:0] INFO  org.apache.zookeeper.server.persistence.FileTxnLog - Creating new log file: log.1
pulsar_1          | 10:10:58.984 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560000, negotiated timeout = 6000
pulsar_1          | 10:10:59.042 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - Starting Bookie(s)
pulsar_1          | 10:10:59.116 [main] INFO  org.apache.bookkeeper.proto.BookieServer - {
pulsar_1          |   "loadBalancerSheddingGracePeriodMinutes" : "30",
pulsar_1          |   "backlogQuotaCheckIntervalInSeconds" : "60",
pulsar_1          |   "loadBalancerNamespaceBundleMaxBandwidthMbytes" : "100",
pulsar_1          |   "bookkeeperClientTimeoutInSeconds" : "30",
pulsar_1          |   "exposeTopicLevelMetricsInPrometheus" : "true",
pulsar_1          |   "managedLedgerCacheEvictionFrequency" : "100.0",
pulsar_1          |   "managedLedgerCursorBackloggedThreshold" : "1000",
pulsar_1          |   "autoSkipNonRecoverableData" : "false",
pulsar_1          |   "brokerPublisherThrottlingMaxByteRate" : "0",
pulsar_1          |   "bookkeeperClientHealthCheckErrorThresholdPerInterval" : "5",
pulsar_1          |   "bookkeeperClientHealthCheckEnabled" : "true",
pulsar_1          |   "brokerDeduplicationEntriesInterval" : "1000",
pulsar_1          |   "authenticateOriginalAuthData" : "false",
pulsar_1          |   "anonymousUserRole" : "",
pulsar_1          |   "dbStorage_rocksDB_numFilesInLevel0" : "4",
pulsar_1          |   "brokerDeleteInactiveTopicsFrequencySeconds" : "60",
pulsar_1          |   "dbStorage_rocksDB_numLevels" : "-1",
pulsar_1          |   "managedLedgerDigestType" : "CRC32C",
pulsar_1          |   "managedLedgerReadEntryTimeoutSeconds" : "0",
pulsar_1          |   "loadBalancerBrokerMaxTopics" : "50000",
pulsar_1          |   "loadBalancerAutoBundleSplitEnabled" : "true",
pulsar_1          |   "managedLedgerAddEntryTimeoutSeconds" : "0",
pulsar_1          |   "bookkeeperClientAuthenticationParametersName" : "",
pulsar_1          |   "managedLedgerDefaultAckQuorum" : "1",
pulsar_1          |   "managedLedgerMaxEntriesPerLedger" : "50000",
pulsar_1          |   "loadBalancerNamespaceMaximumBundles" : "128",
pulsar_1          |   "managedLedgerCacheCopyEntries" : "false",
pulsar_1          |   "webSocketConnectionsPerBroker" : "8",
pulsar_1          |   "journalSyncData" : "false",
pulsar_1          |   "zkServers" : "127.0.0.1:2181",
pulsar_1          |   "dbStorage_rocksDB_maxSizeInLevel1MB" : "256",
pulsar_1          |   "brokerServicePort" : "6650",
pulsar_1          |   "loadBalancerReportUpdateMaxIntervalMinutes" : "15",
pulsar_1          |   "bindAddress" : "0.0.0.0",
pulsar_1          |   "transactionMetadataStoreProviderClassName" : "org.apache.pulsar.transaction.coordinator.impl.InMemTransactionMetadataStoreProvider",
pulsar_1          |   "managedLedgerNumSchedulerThreads" : "4",
pulsar_1          |   "allowEphemeralPorts" : "true",
pulsar_1          |   "clientLibraryVersionCheckEnabled" : "false",
pulsar_1          |   "tokenAuthClaim" : "",
pulsar_1          |   "maxProducersPerTopic" : "0",
pulsar_1          |   "subscriptionExpirationTimeMinutes" : "0",
pulsar_1          |   "bookkeeperClientReorderReadSequenceEnabled" : "false",
pulsar_1          |   "numWorkerThreadsForNonPersistentTopic" : "8",
pulsar_1          |   "dbStorage_rocksDB_blockCacheSize" : "",
pulsar_1          |   "maxConcurrentNonPersistentMessagePerConnection" : "1000",
pulsar_1          |   "brokerShutdownTimeoutMs" : "60000",
pulsar_1          |   "maxConsumersPerSubscription" : "0",
pulsar_1          |   "bookkeeperClientAuthenticationParameters" : "",
pulsar_1          |   "authenticationEnabled" : "false",
pulsar_1          |   "numIOThreads" : "",
pulsar_1          |   "allocatorPoolingPolicy" : "UnpooledHeap",
pulsar_1          |   "maxConsumersPerTopic" : "0",
pulsar_1          |   "managedLedgerMinLedgerRolloverTimeMinutes" : "10",
pulsar_1          |   "bookkeeperTLSTrustCertsFilePath" : "",
pulsar_1          |   "clusterName" : "standalone",
pulsar_1          |   "superUserRoles" : "",
pulsar_1          |   "authenticationProviders" : "",
pulsar_1          |   "subscriptionRedeliveryTrackerEnabled" : "true",
pulsar_1          |   "dispatchThrottlingRatePerTopicInByte" : "0",
pulsar_1          |   "dispatchThrottlingRateRelativeToPublishRate" : "false",
pulsar_1          |   "managedLedgerCursorRolloverTimeInSeconds" : "14400",
pulsar_1          |   "globalZookeeperServers" : "",
pulsar_1          |   "defaultNumberOfNamespaceBundles" : "4",
pulsar_1          |   "loadBalancerEnabled" : "false",
pulsar_1          |   "dbStorage_readAheadCacheMaxSizeMb" : "",
pulsar_1          |   "activeConsumerFailoverDelayTimeMillis" : "1000",
pulsar_1          |   "managedLedgerDefaultEnsembleSize" : "1",
pulsar_1          |   "dbStorage_readAheadCacheBatchSize" : "1000",
pulsar_1          |   "authorizationProvider" : "org.apache.pulsar.broker.authorization.PulsarAuthorizationProvider",
pulsar_1          |   "zookeeperServers" : "",
pulsar_1          |   "bookiePort" : "3181",
pulsar_1          |   "defaultRetentionSizeInMB" : "0",
pulsar_1          |   "defaultNumPartitions" : "1",
pulsar_1          |   "managedLedgerCacheSizeMB" : "",
pulsar_1          |   "advertisedAddress" : "127.0.0.1",
pulsar_1          |   "bookkeeperClientRegionawarePolicyEnabled" : "false",
pulsar_1          |   "brokerDeduplicationEnabled" : "false",
pulsar_1          |   "bookkeeperTLSProviderFactoryClass" : "org.apache.bookkeeper.tls.TLSContextFactory",
pulsar_1          |   "topicPublisherThrottlingTickTimeMillis" : "2",
pulsar_1          |   "dispatchThrottlingOnNonBacklogConsumerEnabled" : "true",
pulsar_1          |   "bookkeeperTLSTrustCertTypes" : "PEM",
pulsar_1          |   "webSocketServiceEnabled" : "true",
pulsar_1          |   "bookkeeperTLSCertificateFilePath" : "",
pulsar_1          |   "numHttpServerThreads" : "",
pulsar_1          |   "maxConcurrentLookupRequest" : "50000",
pulsar_1          |   "bookkeeperTLSKeyStorePasswordPath" : "",
pulsar_1          |   "managedLedgerCacheEvictionWatermark" : "0.9",
pulsar_1          |   "defaultRetentionTimeInMinutes" : "0",
pulsar_1          |   "brokerPublisherThrottlingMaxMessageRate" : "0",
pulsar_1          |   "loadBalancerNamespaceBundleMaxMsgRate" : "30000",
pulsar_1          |   "bookkeeperClientHealthCheckIntervalSeconds" : "60",
pulsar_1          |   "replicationProducerQueueSize" : "1000",
pulsar_1          |   "loadBalancerNamespaceBundleMaxSessions" : "1000",
pulsar_1          |   "webSocketSessionIdleTimeoutMillis" : "300000",
pulsar_1          |   "allowAutoTopicCreationType" : "non-partitioned",
pulsar_1          |   "managedLedgerDefaultWriteQuorum" : "1",
pulsar_1          |   "zooKeeperSessionTimeoutMillis" : "30000",
pulsar_1          |   "statusFilePath" : "/usr/local/apache/htdocs",
pulsar_1          |   "exposePublisherStats" : "true",
pulsar_1          |   "bookkeeperClientSecondaryIsolationGroups" : "",
pulsar_1          |   "maxUnackedMessagesPerConsumer" : "50000",
pulsar_1          |   "replicationConnectionsPerBroker" : "16",
pulsar_1          |   "brokerServicePurgeInactiveFrequencyInSeconds" : "60",
pulsar_1          |   "journalMaxGroupWaitMSec" : "1",
pulsar_1          |   "brokerPublisherThrPottlingTickTimeMillis" : "50",
pulsar_1          |   "bookkeeperTLSTrustStorePasswordPath" : "",
pulsar_1          |   "dbStorage_rocksDB_bloomFilterBitsPerKey" : "10",
pulsar_1          |   "managedLedgerMetadataOperationsTimeoutSeconds" : "60",
pulsar_1          |   "webServicePort" : "8080",
pulsar_1          |   "brokerDeduplicationMaxNumberOfProducers" : "10000",
pulsar_1          |   "ledgerStorageClass" : "org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage",
pulsar_1          |   "diskUsageWarnThreshold" : "0.99",
pulsar_1          |   "brokerDeduplicationProducerInactivityTimeoutMinutes" : "360",
pulsar_1          |   "gcWaitTime" : "300000",
pulsar_1          |   "enableNonPersistentTopics" : "true",
pulsar_1          |   "loadBalancerNamespaceBundleMaxTopics" : "1000",
pulsar_1          |   "bookkeeperClientAuthenticationPlugin" : "",
pulsar_1          |   "managedLedgerCursorMaxEntriesPerLedger" : "50000",
pulsar_1          |   "brokerClientAuthenticationPlugin" : "",
pulsar_1          |   "bookkeeperDiskWeightBasedPlacementEnabled" : "false",
pulsar_1          |   "bookkeeperClientMinAvailableBookiesInIsolationGroups" : "",
pulsar_1          |   "authorizationAllowWildcardsMatching" : "false",
pulsar_1          |   "athenzDomainNames" : "",
pulsar_1          |   "dbStorage_rocksDB_writeBufferSizeMB" : "4",
pulsar_1          |   "managedLedgerDefaultMarkDeleteRateLimit" : "0.1",
pulsar_1          |   "managedLedgerMaxLedgerRolloverTimeMinutes" : "240",
pulsar_1          |   "proxyRoles" : "",
pulsar_1          |   "subscriptionExpiryCheckIntervalInMinutes" : "5",
pulsar_1          |   "maxUnackedMessagesPerBroker" : "0",
pulsar_1          |   "keepAliveIntervalSeconds" : "30",
pulsar_1          |   "managedLedgerNumWorkerThreads" : "4",
pulsar_1          |   "flushInterval" : "60000",
pulsar_1          |   "brokerClientAuthenticationParameters" : "",
pulsar_1          |   "loadBalancerReportUpdateThresholdPercentage" : "10",
pulsar_1          |   "managedLedgerCacheEvictionTimeThresholdMillis" : "1000",
pulsar_1          |   "dbStorage_rocksDB_sstSizeInMB" : "4",
pulsar_1          |   "brokerDeleteInactiveTopicsEnabled" : "true",
pulsar_1          |   "diskUsageThreshold" : "0.99",
pulsar_1          |   "bookkeeperClientRackawarePolicyEnabled" : "true",
pulsar_1          |   "replicationMetricsEnabled" : "true",
pulsar_1          |   "managedLedgerMaxUnackedRangesToPersist" : "10000",
pulsar_1          |   "maxConcurrentTopicLoadRequest" : "5000",
pulsar_1          |   "enablePersistentTopics" : "true",
pulsar_1          |   "bookkeeperClientSpeculativeReadTimeoutInMillis" : "0",
pulsar_1          |   "bookkeeperTLSKeyFileType" : "PEM",
pulsar_1          |   "loadBalancerAutoUnloadSplitBundlesEnabled" : "true",
pulsar_1          |   "ttlDurationDefaultInSeconds" : "0",
pulsar_1          |   "backlogQuotaDefaultLimitGB" : "10",
pulsar_1          |   "ledgerDirectories" : "data/standalone/bookkeeper0",
pulsar_1          |   "dbStorage_rocksDB_blockSize" : "4096",
pulsar_1          |   "zooKeeperOperationTimeoutSeconds" : "30",
pulsar_1          |   "journalDirectories" : "data/standalone/bookkeeper0",
pulsar_1          |   "bookkeeperTLSClientAuthentication" : "false",
pulsar_1          |   "bookkeeperTLSKeyFilePath" : "",
pulsar_1          |   "managedLedgerMaxUnackedRangesToPersistInZooKeeper" : "1000",
pulsar_1          |   "allowLoopback" : "true",
pulsar_1          |   "dispatchThrottlingRatePerTopicInMsg" : "0",
pulsar_1          |   "maxUnackedMessagesPerSubscription" : "200000",
pulsar_1          |   "backlogQuotaCheckEnabled" : "true",
pulsar_1          |   "allowAutoTopicCreation" : "true",
pulsar_1          |   "failureDomainsEnabled" : "false",
pulsar_1          |   "bookkeeperClientIsolationGroups" : "",
pulsar_1          |   "managedLedgerUnackedRangesOpenCacheSetEnabled" : "true",
pulsar_1          |   "webSocketNumIoThreads" : "8",
pulsar_1          |   "configurationStoreServers" : "",
pulsar_1          |   "maxUnackedMessagesPerSubscriptionOnBrokerBlocked" : "0.16",
pulsar_1          |   "dbStorage_writeCacheMaxSizeMb" : "",
pulsar_1          |   "messageExpiryCheckIntervalInMinutes" : "5",
pulsar_1          |   "authorizationEnabled" : "false",
pulsar_1          |   "loadBalancerSheddingIntervalMinutes" : "1",
pulsar_1          |   "loadBalancerHostUsageCheckIntervalMinutes" : "1",
pulsar_1          |   "loadManagerClassName" : "org.apache.pulsar.broker.loadbalance.NoopLoadManager",
pulsar_1          |   "bookkeeperClientHealthCheckQuarantineTimeInSeconds" : "1800",
pulsar_1          |   "loadBalancerResourceQuotaUpdateIntervalMinutes" : "15"
pulsar_1          | }
pulsar_1          | 10:10:59.271 [main] WARN  org.apache.bookkeeper.util.EventLoopUtil - Could not use Netty Epoll event loop: failed to load the required native library
pulsar_1          | 10:10:59.580 [main] INFO  org.apache.bookkeeper.meta.MetadataDrivers - BookKeeper metadata driver manager initialized
pulsar_1          | 10:10:59.580 [main] INFO  org.apache.bookkeeper.meta.MetadataDrivers - BookKeeper metadata driver manager initialized
pulsar_1          | 10:10:59.581 [main] INFO  org.apache.bookkeeper.meta.MetadataDrivers - BookKeeper metadata driver manager initialized
pulsar_1          | 10:10:59.590 [main] INFO  org.apache.bookkeeper.meta.zk.ZKMetadataDriverBase - Initialize zookeeper metadata driver at metadata service uri zk+null://127.0.0.1:2181/ledgers : zkServers = 127.0.0.1:2181, ledgersRootPath = /ledgers.
pulsar_1          | 10:10:59.598 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=10000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@f9b5552
pulsar_1          | 10:10:59.599 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:10:59.599 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:10:59.602 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:10:59.603 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55152, server: localhost/127.0.0.1:2181
pulsar_1          | 10:10:59.615 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560001, negotiated timeout = 10000
pulsar_1          | 10:10:59.617 [main-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:10:59.665 [main] INFO  org.apache.bookkeeper.discover.ZKRegistrationManager - INSTANCEID not exists in zookeeper. Not considering it for data verification
pulsar_1          | 10:10:59.708 [main] INFO  org.apache.bookkeeper.bookie.Bookie - Stamping new cookies on all dirs [data/standalone/bookkeeper0/current] [data/standalone/bookkeeper0/current]
pulsar_1          | 10:10:59.966 [main] INFO  org.apache.bookkeeper.bookie.Bookie - instantiate ledger manager org.apache.bookkeeper.meta.HierarchicalLedgerManagerFactory
pulsar_1          | 10:11:00.026 [main] ERROR org.apache.bookkeeper.bookie.Journal - Problems reading from data/standalone/bookkeeper0/current/lastMark (this is okay if it is the first time starting this bookie
pulsar_1          | 10:11:00.029 [main] INFO  org.apache.bookkeeper.bookie.Bookie - Using ledger storage: org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage
pulsar_1          | 10:11:00.037 [main] INFO  org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage - Started Db Ledger Storage
pulsar_1          | 10:11:00.037 [main] INFO  org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage -  - Number of directories: 1
pulsar_1          | 10:11:00.037 [main] INFO  org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage -  - Write cache size: 256 MB
pulsar_1          | 10:11:00.037 [main] INFO  org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage -  - Read Cache: 256 MB
pulsar_1          | 10:11:00.048 [main] INFO  org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage - Creating single directory db ledger storage on data/standalone/bookkeeper0/current
pulsar_1          | 10:11:00.339 [main] INFO  org.apache.bookkeeper.bookie.ScanAndCompareGarbageCollector - Over Replicated Ledger Deletion : enabled=true, interval=86400000
pulsar_1          | 10:11:00.362 [main] INFO  org.apache.bookkeeper.bookie.GarbageCollectorThread - Minor Compaction : enabled=true, threshold=0.20000000298023224, interval=3600000
pulsar_1          | 10:11:00.363 [main] INFO  org.apache.bookkeeper.bookie.GarbageCollectorThread - Major Compaction : enabled=true, threshold=0.800000011920929, interval=86400000
pulsar_1          | 10:11:00.428 [main] INFO  org.apache.bookkeeper.bookie.Bookie - Finished replaying journal in 2 ms.
pulsar_1          | 10:11:00.470 [SyncThread-7-1] INFO  org.apache.bookkeeper.bookie.SyncThread - Flush ledger storage at checkpoint CheckpointList{checkpoints=[LogMark: logFileId - 0 , logFileOffset - 0]}.
pulsar_1          | 10:11:00.481 [main] INFO  org.apache.bookkeeper.bookie.Bookie - Finished reading journal, starting bookie
pulsar_1          | 10:11:00.485 [BookieJournal-3181] INFO  org.apache.bookkeeper.bookie.Journal - Starting journal on data/standalone/bookkeeper0/current
pulsar_1          | 10:11:00.487 [ForceWriteThread] INFO  org.apache.bookkeeper.bookie.Journal - ForceWrite Thread started
pulsar_1          | 10:11:00.501 [BookieJournal-3181] INFO  org.apache.bookkeeper.bookie.JournalChannel - Opening journal data/standalone/bookkeeper0/current/1700a882907.txn
pulsar_1          | 10:11:00.769 [main] WARN  org.apache.curator.retry.ExponentialBackoffRetry - maxRetries too large (2147483647). Pinning to 29
pulsar_1          | 10:11:00.976 [main] INFO  org.apache.curator.framework.imps.CuratorFrameworkImpl - Starting
pulsar_1          | 10:11:00.986 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=60000 watcher=org.apache.curator.ConnectionState@5533dc72
pulsar_1          | 10:11:00.986 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:00.986 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:00.988 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:00.989 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55154, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:01.000 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560002, negotiated timeout = 60000
pulsar_1          | 10:11:01.017 [main-EventThread] INFO  org.apache.curator.framework.state.ConnectionStateManager - State change: CONNECTED
pulsar_1          | 10:11:01.020 [main] INFO  org.apache.curator.framework.imps.CuratorFrameworkImpl - Default schema
pulsar_1          | 10:11:01.033 [main-EventThread] INFO  org.apache.curator.framework.imps.EnsembleTracker - New config event received: {}
pulsar_1          | 10:11:01.034 [main-EventThread] INFO  org.apache.curator.framework.imps.EnsembleTracker - New config event received: {}
pulsar_1          | 10:11:01.837 [main] INFO  org.apache.bookkeeper.stream.storage.impl.cluster.ZkClusterInitializer - Initializing the stream cluster with 2 storage containers with segment store path {}.
pulsar_1          | 10:11:01.969 [main] INFO  org.apache.bookkeeper.stream.storage.impl.cluster.ZkClusterInitializer - Successfully initialized the stream cluster : 
pulsar_1          | num_storage_containers: 2
pulsar_1          | 
pulsar_1          | 10:11:01.973 [Curator-Framework-0] INFO  org.apache.curator.framework.imps.CuratorFrameworkImpl - backgroundOperationsLoop exiting
pulsar_1          | 10:11:02.095 [main] INFO  org.apache.zookeeper.ZooKeeper - Session: 0x10007e92a560002 closed
pulsar_1          | 10:11:02.095 [main-EventThread] INFO  org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x10007e92a560002
pulsar_1          | 10:11:02.132 [main] INFO  org.apache.bookkeeper.stream.server.StorageServer - Dlog configuration : {
pulsar_1          |   "bkcEnsembleSize" : "1",
pulsar_1          |   "bkcWriteQuorumSize" : "1",
pulsar_1          |   "bkcAckQuorumSize" : "1"
pulsar_1          | }
pulsar_1          | 10:11:02.132 [main] INFO  org.apache.bookkeeper.stream.server.StorageServer - Storage configuration : { }
pulsar_1          | 10:11:02.133 [main] INFO  org.apache.bookkeeper.stream.server.StorageServer - Server configuration : {
pulsar_1          |   "grpc.port" : "4181"
pulsar_1          | }
pulsar_1          | 10:11:02.162 [main] WARN  org.apache.curator.retry.ExponentialBackoffRetry - maxRetries too large (2147483647). Pinning to 29
pulsar_1          | 10:11:02.293 [main] INFO  org.apache.bookkeeper.meta.zk.ZKMetadataDriverBase - Initialize zookeeper metadata driver at metadata service uri zk://127.0.0.1:2181/ledgers : zkServers = 127.0.0.1:2181, ledgersRootPath = /ledgers.
pulsar_1          | 10:11:02.293 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=10000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@7ef9c8a5
pulsar_1          | 10:11:02.293 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:02.294 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:02.297 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:02.298 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55156, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:02.308 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560003, negotiated timeout = 10000
pulsar_1          | 10:11:02.308 [main-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:02.445 [main] INFO  org.apache.zookeeper.ZooKeeper - Session: 0x10007e92a560003 closed
pulsar_1          | 10:11:02.445 [main-EventThread] INFO  org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x10007e92a560003
pulsar_1          | 10:11:02.448 [main] INFO  org.apache.curator.framework.imps.CuratorFrameworkImpl - Starting
pulsar_1          | 10:11:02.450 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=60000 watcher=org.apache.curator.ConnectionState@4fe4503a
pulsar_1          | 10:11:02.451 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:02.451 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:02.454 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:02.455 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55158, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:02.458 [main] INFO  org.apache.curator.framework.imps.CuratorFrameworkImpl - Default schema
pulsar_1          | 10:11:02.458 [main] INFO  org.apache.bookkeeper.stream.server.service.CuratorProviderService - Provided curator clients to zookeeper 127.0.0.1:2181.
pulsar_1          | 10:11:02.458 [main] INFO  org.apache.bookkeeper.stream.server.service.DLNamespaceProviderService - Initializing dlog namespace at distributedlog://127.0.0.1:2181/stream/storage
pulsar_1          | 10:11:02.468 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560004, negotiated timeout = 60000
pulsar_1          | 10:11:02.469 [main-EventThread] INFO  org.apache.curator.framework.state.ConnectionStateManager - State change: CONNECTED
pulsar_1          | 10:11:02.481 [main-EventThread] INFO  org.apache.curator.framework.imps.EnsembleTracker - New config event received: {}
pulsar_1          | 10:11:02.482 [main-EventThread] INFO  org.apache.curator.framework.imps.EnsembleTracker - New config event received: {}
pulsar_1          | 10:11:02.484 [main] INFO  org.apache.distributedlog.namespace.NamespaceDriverManager - DistributedLog NamespaceDriverManager initialized
pulsar_1          | 10:11:02.510 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@71f8ce0e
pulsar_1          | 10:11:02.511 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:02.511 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:02.514 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:02.514 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55160, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:02.519 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560005, negotiated timeout = 30000
pulsar_1          | 10:11:02.520 [main-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:02.531 [main] INFO  org.apache.distributedlog.ZooKeeperClient - Close zookeeper client default.
pulsar_1          | 10:11:02.531 [main] INFO  org.apache.distributedlog.ZooKeeperClient - Closing zookeeper client default.
pulsar_1          | 10:11:02.637 [main] INFO  org.apache.zookeeper.ZooKeeper - Session: 0x10007e92a560005 closed
pulsar_1          | 10:11:02.637 [main-EventThread] INFO  org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x10007e92a560005
pulsar_1          | 10:11:02.638 [main] INFO  org.apache.distributedlog.ZooKeeperClient - Closed zookeeper client default.
pulsar_1          | 10:11:02.656 [main] INFO  org.apache.distributedlog.api.namespace.NamespaceBuilder - No feature provider is set. All features are disabled now.
pulsar_1          | 10:11:02.666 [main] INFO  org.apache.distributedlog.impl.BKNamespaceDriver - Created shared zooKeeper client builder dlzk:distributedlog://127.0.0.1:2181/stream/storage:factory_writer_shared: zkServers = 127.0.0.1:2181, numRetries = 3, sessionTimeout = 30000, retryBackoff = 5000, maxRetryBackoff = 30000, zkAclId = null.
pulsar_1          | 10:11:02.669 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@73db7df0
pulsar_1          | 10:11:02.670 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:02.670 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:02.672 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:02.673 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55162, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:02.676 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560006, negotiated timeout = 30000
pulsar_1          | 10:11:02.678 [main-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:02.683 [main] WARN  org.apache.distributedlog.impl.BKNamespaceDriver - Could not use Netty Epoll event loop for bookie server:
pulsar_1          | java.lang.NoClassDefFoundError: Could not initialize class io.netty.channel.epoll.EpollEventLoop
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.newChild(EpollEventLoopGroup.java:142) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.newChild(EpollEventLoopGroup.java:35) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:84) ~[io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:58) ~[io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:47) ~[io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.MultithreadEventLoopGroup.<init>(MultithreadEventLoopGroup.java:59) ~[io.netty-netty-transport-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.<init>(EpollEventLoopGroup.java:104) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.<init>(EpollEventLoopGroup.java:91) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.<init>(EpollEventLoopGroup.java:68) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at org.apache.distributedlog.impl.BKNamespaceDriver.getDefaultEventLoopGroup(BKNamespaceDriver.java:257) ~[org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.distributedlog.impl.BKNamespaceDriver.initializeBookKeeperClients(BKNamespaceDriver.java:268) ~[org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.distributedlog.impl.BKNamespaceDriver.initialize(BKNamespaceDriver.java:206) ~[org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.distributedlog.api.namespace.NamespaceBuilder.build(NamespaceBuilder.java:239) ~[org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.bookkeeper.stream.server.service.DLNamespaceProviderService.doStart(DLNamespaceProviderService.java:120) ~[org.apache.bookkeeper-stream-storage-server-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.bookkeeper.common.component.AbstractLifecycleComponent.start(AbstractLifecycleComponent.java:83) ~[org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.bookkeeper.common.component.LifecycleComponentStack.lambda$start$2(LifecycleComponentStack.java:113) ~[org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
pulsar_1          |    at com.google.common.collect.ImmutableList.forEach(ImmutableList.java:407) [com.google.guava-guava-25.1-jre.jar:?]
pulsar_1          |    at org.apache.bookkeeper.common.component.LifecycleComponentStack.start(LifecycleComponentStack.java:113) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.bookkeeper.stream.server.StreamStorageLifecycleComponent.doStart(StreamStorageLifecycleComponent.java:51) [org.apache.bookkeeper-stream-storage-server-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.bookkeeper.common.component.AbstractLifecycleComponent.start(AbstractLifecycleComponent.java:83) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble.runStreamStorage(LocalBookkeeperEnsemble.java:323) [org.apache.pulsar-pulsar-zookeeper-utils-2.5.0.jar:2.5.0]
pulsar_1          |    at org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble.startStandalone(LocalBookkeeperEnsemble.java:405) [org.apache.pulsar-pulsar-zookeeper-utils-2.5.0.jar:2.5.0]
pulsar_1          |    at org.apache.pulsar.PulsarStandalone.start(PulsarStandalone.java:260) [org.apache.pulsar-pulsar-broker-2.5.0.jar:2.5.0]
pulsar_1          |    at org.apache.pulsar.PulsarStandaloneStarter.main(PulsarStandaloneStarter.java:119) [org.apache.pulsar-pulsar-broker-2.5.0.jar:2.5.0]
pulsar_1          | 10:11:02.694 [main] INFO  org.apache.distributedlog.impl.BKNamespaceDriver - Created shared client builder bk:distributedlog://127.0.0.1:2181/stream/storage:factory_writer_shared : zkServers = 127.0.0.1:2181, ledgersPath = /ledgers, numIOThreads = 4
pulsar_1          | 10:11:02.700 [main] INFO  org.apache.distributedlog.impl.metadata.BKDLConfig - Propagate BKDLConfig to DLConfig : encodeRegionID = false, firstLogSegmentSequenceNumber = 1, createStreamIfNotExists = true, isFederated = false.
pulsar_1          | 10:11:02.723 [main] INFO  org.apache.distributedlog.impl.BKNamespaceDriver - Initialized BK namespace driver: clientId = storage-server, regionId = 0, federated = false.
pulsar_1          | 10:11:02.774 [main] INFO  org.apache.distributedlog.logsegment.LogSegmentMetadataCache - Log segment cache is enabled = true
pulsar_1          | 10:11:02.774 [main] INFO  org.apache.bookkeeper.stream.server.service.DLNamespaceProviderService - Provided distributedlog namespace at distributedlog://127.0.0.1:2181/stream/storage.
pulsar_1          | 10:11:03.122 [main] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Watched cluster assignment data.
pulsar_1          | 10:11:03.124 [main] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Scheduled storage container probe task at every 15000 ms
pulsar_1          | 10:11:03.213 [main] INFO  org.apache.bookkeeper.stream.storage.impl.grpc.GrpcMetaRangeService - Created MetaRange service
pulsar_1          | 10:11:03.227 [main] INFO  org.apache.bookkeeper.stream.storage.impl.grpc.GrpcTableService - Created Table service
pulsar_1          | 10:11:03.314 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=10000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@7010c9e4
pulsar_1          | 10:11:03.315 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:03.315 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:03.323 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:03.324 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55164, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:03.327 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560007, negotiated timeout = 10000
pulsar_1          | 10:11:03.328 [main-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:03.339 [main] INFO  org.apache.bookkeeper.stream.server.service.RegistrationStateService - Successfully register myself under registration path /stream/servers/172.28.0.2:4181
pulsar_1          | 10:11:03.367 [main] INFO  org.apache.bookkeeper.stream.server.service.ClusterControllerService - Successfully started the cluster controller.
pulsar_1          | 10:11:03.404 [Curator-LeaderSelector-0] INFO  org.apache.bookkeeper.stream.storage.impl.cluster.ClusterControllerLeaderImpl - Become controller leader to monitor servers for assigning storage containers.
pulsar_1          | 10:11:03.410 [registration-service-provider-scheduler] INFO  org.apache.bookkeeper.stream.storage.impl.cluster.ClusterControllerLeaderImpl - Cluster topology is changed - new cluster : Versioned(value=[172.28.0.2:4181], version=1)
pulsar_1          | 10:11:03.467 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Servers joined : [hostname: "172.28.0.2"
pulsar_1          | port: 4181
pulsar_1          | ]
pulsar_1          | 10:11:03.481 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Process container changes:
pulsar_1          |    Ideal = [0, 1]
pulsar_1          |    Live = []
pulsar_1          |    Pending = []
pulsar_1          |    ToStart = [0, 1]
pulsar_1          |    ToStop = []
pulsar_1          | 10:11:03.483 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Starting storage container (0)
pulsar_1          | 10:11:03.513 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.grpc.GrpcMetaRangeService - Created MetaRange service
pulsar_1          | 10:11:03.513 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.grpc.GrpcTableService - Created Table service
pulsar_1          | 10:11:03.525 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerRegistryImpl - Registered StorageContainer ('0').
pulsar_1          | 10:11:03.526 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl - Starting storage container (0) ...
pulsar_1          | 10:11:03.528 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Initializing stream(0)/range(0) at storage container (0)
pulsar_1          | 10:11:03.607 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initializing the local state for mvcc store 000000000000000000/000000000000000000/000000000000000000
pulsar_1          | 10:11:03.626 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.rocksdb.checkpoint.RocksCheckpointer - Successfully restore checkpoint b9704565-de1a-4379-8d57-05163d544b11 to /pulsar/data/bookkeeper/ranges/ranges/000000000000000000/000000000000000000/000000000000000000/checkpoints/b9704565-de1a-4379-8d57-05163d544b11
pulsar_1          | 10:11:03.633 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Initializing stream(1)/range(0) at storage container (0)
pulsar_1          | 10:11:03.639 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initializing the local state for mvcc store 000000000000000000/000000000000000001/000000000000000000
pulsar_1          | 10:11:03.646 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.rocksdb.checkpoint.RocksCheckpointer - Successfully restore checkpoint 576afb6f-a671-4bca-afb0-19f4ca0c7fa8 to /pulsar/data/bookkeeper/ranges/ranges/000000000000000000/000000000000000001/000000000000000000/checkpoints/576afb6f-a671-4bca-afb0-19f4ca0c7fa8
pulsar_1          | 10:11:03.662 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Starting storage container (1)
pulsar_1          | 10:11:03.662 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.grpc.GrpcMetaRangeService - Created MetaRange service
pulsar_1          | 10:11:03.662 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.grpc.GrpcTableService - Created Table service
pulsar_1          | 10:11:03.663 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerRegistryImpl - Registered StorageContainer ('1').
pulsar_1          | 10:11:03.663 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl - Starting storage container (1) ...
pulsar_1          | 10:11:03.663 [zk-storage-container-manager] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Initializing stream(1)/range(0) at storage container (1)
pulsar_1          | 10:11:03.709 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initialized the local state for mvcc store 000000000000000000/000000000000000001/000000000000000000
pulsar_1          | 10:11:03.709 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initialized the local state for mvcc store 000000000000000000/000000000000000000/000000000000000000
pulsar_1          | 10:11:03.712 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initializing the local state for mvcc store 000000000000000001/000000000000000001/000000000000000000
pulsar_1          | 10:11:03.720 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.rocksdb.checkpoint.RocksCheckpointer - Successfully restore checkpoint 60f8e729-9549-4f44-9698-08fa9d9d40f8 to /pulsar/data/bookkeeper/ranges/ranges/000000000000000001/000000000000000001/000000000000000000/checkpoints/60f8e729-9549-4f44-9698-08fa9d9d40f8
pulsar_1          | 10:11:03.754 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initialized the local state for mvcc store 000000000000000001/000000000000000001/000000000000000000
pulsar_1          | 10:11:03.815 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved version from -1 to 0.
pulsar_1          | 10:11:03.873 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved version from -1 to 0.
pulsar_1          | 10:11:03.881 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - Initiating Recovery For streams_000000000000000000_000000000000000000_000000000000000000:<default> : []
pulsar_1          | 10:11:03.890 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initialized the journal writer for mvcc store 000000000000000000/000000000000000000/000000000000000000 : last revision = 0
pulsar_1          | 10:11:03.890 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - Initiating Recovery For streams_000000000000000000_000000000000000001_000000000000000000:<default> : []
pulsar_1          | 10:11:03.891 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved version from -1 to 0.
pulsar_1          | 10:11:03.894 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initialized the journal writer for mvcc store 000000000000000000/000000000000000001/000000000000000000 : last revision = 0
pulsar_1          | 10:11:03.903 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - Initiating Recovery For streams_000000000000000001_000000000000000001_000000000000000000:<default> : []
pulsar_1          | 10:11:03.941 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.distributedlog.BKLogWriteHandler - Initiating Recovery For streams_000000000000000000_000000000000000001_000000000000000000:<default> : []
pulsar_1          | 10:11:03.944 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.distributedlog.BKLogWriteHandler - Initiating Recovery For streams_000000000000000000_000000000000000000_000000000000000000:<default> : []
pulsar_1          | 10:11:03.949 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATING : version = 0.
pulsar_1          | 10:11:03.953 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved to phase ALLOCATING : version = 0.
pulsar_1          | 10:11:03.986 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@1c6da07f
pulsar_1          | 10:11:03.987 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:03.988 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:03.990 [io-write-scheduler-OrderedScheduler-1-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:03.991 [io-write-scheduler-OrderedScheduler-1-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55168, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:03.996 [io-write-scheduler-OrderedScheduler-1-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560008, negotiated timeout = 30000
pulsar_1          | 10:11:03.996 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:04.012 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.meta.zk.ZKMetadataDriverBase - Initialize zookeeper metadata driver with external zookeeper client : ledgersRootPath = /ledgers.
pulsar_1          | 10:11:04.057 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Initialize rackaware ensemble placement policy @ <Bookie:172.28.0.2:0> @ /default-region/default-rack : org.apache.distributedlog.net.DNSResolverForRacks.
pulsar_1          | 10:11:04.057 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Not weighted
pulsar_1          | 10:11:04.064 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.client.BookKeeper - Weighted ledger placement is not enabled
pulsar_1          | 10:11:04.078 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-region/default-rack/127.0.0.1:3181
pulsar_1          | 10:11:04.079 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Initialize rackaware ensemble placement policy @ <Bookie:172.28.0.2:0> @ /default-region/default-rack : org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy$DNSResolverDecorator.
pulsar_1          | 10:11:04.079 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Not weighted
pulsar_1          | 10:11:04.079 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-region/default-rack/127.0.0.1:3181
pulsar_1          | 10:11:04.094 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.distributedlog.BookKeeperClient - BookKeeper Client created bk:distributedlog://127.0.0.1:2181/stream/storage:factory_writer_shared with its own ZK Client : ledgersPath = /ledgers, numRetries = 3, sessionTimeout = 30000, backoff = 5000, maxBackoff = 30000, dnsResolver = 
pulsar_1          | 10:11:04.134 [io-write-scheduler-OrderedScheduler-1-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:04.136 [io-write-scheduler-OrderedScheduler-0-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:04.182 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Initialized the journal writer for mvcc store 000000000000000001/000000000000000001/000000000000000000 : last revision = 0
pulsar_1          | 10:11:04.184 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.distributedlog.BKLogWriteHandler - Initiating Recovery For streams_000000000000000001_000000000000000001_000000000000000000:<default> : []
pulsar_1          | 10:11:04.188 [DLM-/stream/storage-OrderedScheduler-2-0] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATING : version = 0.
pulsar_1          | 10:11:04.189 [DLM-/stream/storage-OrderedScheduler-2-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:04.226 [client-scheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.clients.impl.channel.StorageServerChannelManager - Added range server (hostname: "172.28.0.2"
pulsar_1          | port: 4181
pulsar_1          | ) into the channel manager.
pulsar_1          | 10:11:04.294 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 0
pulsar_1          | 10:11:04.298 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 1
pulsar_1          | 10:11:04.299 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 2
pulsar_1          | 10:11:04.303 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved version from 0 to 1.
pulsar_1          | 10:11:04.303 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATED : version = 1.
pulsar_1          | 10:11:04.308 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved to phase HANDING_OVER : version = 1.
pulsar_1          | 10:11:04.310 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - No max ledger sequence number found while creating log segment 1 for streams_000000000000000000_000000000000000001_000000000000000000:<default>.
pulsar_1          | 10:11:04.320 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved version from 0 to 1.
pulsar_1          | 10:11:04.322 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved to phase ALLOCATED : version = 1.
pulsar_1          | 10:11:04.323 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved to phase HANDING_OVER : version = 1.
pulsar_1          | 10:11:04.323 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - No max ledger sequence number found while creating log segment 1 for streams_000000000000000000_000000000000000000_000000000000000000:<default>.
pulsar_1          | 10:11:04.324 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved version from 0 to 1.
pulsar_1          | 10:11:04.325 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATED : version = 1.
pulsar_1          | 10:11:04.326 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved to phase HANDING_OVER : version = 1.
pulsar_1          | 10:11:04.329 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - No max ledger sequence number found while creating log segment 1 for streams_000000000000000001_000000000000000001_000000000000000000:<default>.
pulsar_1          | 10:11:04.330 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved to phase HANDED_OVER : version = 1.
pulsar_1          | 10:11:04.331 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved version from 1 to 2.
pulsar_1          | 10:11:04.332 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATING : version = 2.
pulsar_1          | 10:11:04.335 [main-EventThread] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:04.341 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 3
pulsar_1          | 10:11:04.346 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000000_000000000000000001_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:0, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:04.350 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved to phase HANDED_OVER : version = 1.
pulsar_1          | 10:11:04.351 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved version from 1 to 2.
pulsar_1          | 10:11:04.351 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved to phase ALLOCATING : version = 2.
pulsar_1          | 10:11:04.352 [main-EventThread] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:04.353 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000000_000000000000000000_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:1, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:04.353 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved to phase HANDED_OVER : version = 1.
pulsar_1          | 10:11:04.353 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved version from 1 to 2.
pulsar_1          | 10:11:04.357 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATING : version = 2.
pulsar_1          | 10:11:04.358 [main-EventThread] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:04.359 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000001_000000000000000001_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:2, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:04.359 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved version from 2 to 3.
pulsar_1          | 10:11:04.360 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATED : version = 3.
pulsar_1          | 10:11:04.366 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 4
pulsar_1          | 10:11:04.376 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 5
pulsar_1          | 10:11:04.379 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved version from 2 to 3.
pulsar_1          | 10:11:04.379 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000000_000000000000000000_000000000000000000/<default>/allocation moved to phase ALLOCATED : version = 3.
pulsar_1          | 10:11:04.382 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved version from 2 to 3.
pulsar_1          | 10:11:04.382 [main-EventThread] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000001_000000000000000001_000000000000000000/<default>/allocation moved to phase ALLOCATED : version = 3.
pulsar_1          | 10:11:04.395 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - Deleting log segments older than 1580465464391 for streams_000000000000000000_000000000000000001_000000000000000000:<default> : []
pulsar_1          | 10:11:04.399 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - Deleting log segments older than 1580465464396 for streams_000000000000000000_000000000000000000_000000000000000000:<default> : []
pulsar_1          | 10:11:04.421 [main-EventThread] INFO  org.apache.distributedlog.BKLogWriteHandler - Deleting log segments older than 1580465464417 for streams_000000000000000001_000000000000000001_000000000000000000:<default> : []
pulsar_1          | 10:11:04.516 [DL-io-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x7dfe7b68, L:/127.0.0.1:33812 - R:localhost/127.0.0.1:3181]
pulsar_1          | 10:11:04.529 [DL-io-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:04.537 [bookie-io-1-2] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:04.539 [bookie-io-1-2] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x064736bb, L:/127.0.0.1:3181 - R:/127.0.0.1:33812]
pulsar_1          | 10:11:04.577 [DL-io-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x7dfe7b68, L:/127.0.0.1:33812 - R:localhost/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:04.681 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Successfully write a barrier record for mvcc store 000000000000000000/000000000000000001/000000000000000000 at DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}
pulsar_1          | 10:11:04.684 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Successfully write a barrier record for mvcc store 000000000000000000/000000000000000000/000000000000000000 at DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}
pulsar_1          | 10:11:04.695 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000000_000000000000000001_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:0, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:04.706 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Successfully write a barrier record for mvcc store 000000000000000001/000000000000000001/000000000000000000 at DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}
pulsar_1          | 10:11:04.741 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Successfully open the journal reader for mvcc store 000000000000000000/000000000000000001/000000000000000000 : end dlsn = DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}
pulsar_1          | 10:11:04.749 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000000_000000000000000000_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:1, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:04.752 [io-write-scheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Successfully open the journal reader for mvcc store 000000000000000000/000000000000000000/000000000000000000 : end dlsn = DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}
pulsar_1          | 10:11:04.752 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000001_000000000000000001_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:2, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:04.770 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Successfully open the journal reader for mvcc store 000000000000000001/000000000000000001/000000000000000000 : end dlsn = DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}
pulsar_1          | 10:11:04.792 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000000_000000000000000001_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:0, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:04.793 [main-EventThread] INFO  org.apache.distributedlog.ReadAheadEntryReader - Starting the readahead entry reader for streams_000000000000000000_000000000000000001_000000000000000000:<default> : segments = [[LogSegmentId:0, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:04.796 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - segments is updated with [[LogSegmentId:0, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.123 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000000_000000000000000000_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:1, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:05.129 [main-EventThread] INFO  org.apache.distributedlog.ReadAheadEntryReader - Starting the readahead entry reader for streams_000000000000000000_000000000000000000_000000000000000000:<default> : segments = [[LogSegmentId:1, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.136 [DLM-/stream/storage-OrderedScheduler-1-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - segments is updated with [[LogSegmentId:1, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.136 [main-EventThread] INFO  org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - streams_000000000000000001_000000000000000001_000000000000000000 added log segment (inprogress_000000000000000001 : [LogSegmentId:2, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:-1]) to cache.
pulsar_1          | 10:11:05.136 [main-EventThread] INFO  org.apache.distributedlog.ReadAheadEntryReader - Starting the readahead entry reader for streams_000000000000000001_000000000000000001_000000000000000000:<default> : segments = [[LogSegmentId:2, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.139 [DLM-/stream/storage-OrderedScheduler-1-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - segments is updated with [[LogSegmentId:2, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.144 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - Reinitialize log segments with [[LogSegmentId:1, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.145 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - Reinitialize log segments with [[LogSegmentId:2, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.147 [DLM-/stream/storage-OrderedScheduler-3-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - Reinitialize log segments with [[LogSegmentId:0, firstTxId:1, lastTxId:-999, version:VERSION_V5_SEQUENCE_ID, completionTime:0, recordCount:0, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:-1, lastSlotId:-1, inprogress:true, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]]
pulsar_1          | 10:11:05.220 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - ReadAhead for streams_000000000000000001_000000000000000001_000000000000000000:<default> is caught up
pulsar_1          | 10:11:05.249 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - ReadAhead for streams_000000000000000000_000000000000000001_000000000000000000:<default> is caught up
pulsar_1          | 10:11:05.259 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO  org.apache.distributedlog.ReadAheadEntryReader - ReadAhead for streams_000000000000000000_000000000000000000_000000000000000000:<default> is caught up
pulsar_1          | 10:11:05.312 [DLM-/stream/storage-OrderedScheduler-3-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Finished replaying journal for state store 000000000000000000/000000000000000001/000000000000000000
pulsar_1          | 10:11:05.312 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Finished replaying journal for state store 000000000000000001/000000000000000001/000000000000000000
pulsar_1          | 10:11:05.315 [DLM-/stream/storage-OrderedScheduler-3-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Successfully initialize stream(1)/range(0) at storage container (0)
pulsar_1          | 10:11:05.315 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Successfully initialize stream(1)/range(0) at storage container (1)
pulsar_1          | 10:11:05.318 [DLM-/stream/storage-OrderedScheduler-3-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Add store (scId = 0, streamId = 1, rangeId = 0) at storage container (0)
pulsar_1          | 10:11:05.319 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Add store (scId = 1, streamId = 1, rangeId = 0) at storage container (1)
pulsar_1          | 10:11:05.322 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl - Successfully started storage container (1).
pulsar_1          | 10:11:05.341 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerRegistryImpl - Successfully started registered StorageContainer ('1').
pulsar_1          | 10:11:05.342 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Successfully started storage container (1)
pulsar_1          | 10:11:05.343 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Storage container (org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl@33f3bde2) is added to live set.
pulsar_1          | 10:11:05.344 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal - Finished replaying journal for state store 000000000000000000/000000000000000000/000000000000000000
pulsar_1          | 10:11:05.344 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Successfully initialize stream(0)/range(0) at storage container (0)
pulsar_1          | 10:11:05.345 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Add store (scId = 0, streamId = 0, rangeId = 0) at storage container (0)
pulsar_1          | 10:11:05.350 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl - Successfully started storage container (0).
pulsar_1          | 10:11:05.351 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerRegistryImpl - Successfully started registered StorageContainer ('0').
pulsar_1          | 10:11:05.351 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Successfully started storage container (0)
pulsar_1          | 10:11:05.351 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Storage container (org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl@6000369f) is added to live set.
pulsar_1          | 10:11:05.436 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - Creating default namespace
pulsar_1          | 10:11:05.546 [main] INFO  org.apache.pulsar.zookeeper.LocalBookkeeperEnsemble - Successfully created 'default' namespace :
pulsar_1          | namespace_name: "default"
pulsar_1          | default_stream_conf {
pulsar_1          |   key_type: HASH
pulsar_1          |   min_num_ranges: 24
pulsar_1          |   initial_num_ranges: 24
pulsar_1          |   split_policy {
pulsar_1          |     fixed_range_policy {
pulsar_1          |       num_ranges: 2
pulsar_1          |     }
pulsar_1          |   }
pulsar_1          |   rolling_policy {
pulsar_1          |     size_policy {
pulsar_1          |       max_segment_size: 134217728
pulsar_1          |     }
pulsar_1          |   }
pulsar_1          |   retention_policy {
pulsar_1          |     time_policy {
pulsar_1          |       retention_minutes: -1
pulsar_1          |     }
pulsar_1          |   }
pulsar_1          | }
pulsar_1          | 
pulsar_1          | [MethodUtil@73e17fd6] info AspectJ Weaver Version 1.9.2 built on Wednesday Oct 24, 2018 at 15:43:33 GMT
pulsar_1          | [MethodUtil@73e17fd6] info register classloader sun.reflect.misc.MethodUtil@73e17fd6
pulsar_1          | [MethodUtil@73e17fd6] info using configuration file:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-2.5.0.jar!/META-INF/aop.xml
pulsar_1          | [MethodUtil@73e17fd6] info using configuration file:/pulsar/lib/org.apache.pulsar-pulsar-zookeeper-utils-2.5.0.jar!/META-INF/aop.xml
pulsar_1          | [MethodUtil@73e17fd6] info register aspect org.apache.pulsar.zookeeper.FinalRequestProcessorAspect
pulsar_1          | [MethodUtil@73e17fd6] info register aspect org.apache.pulsar.zookeeper.ZooKeeperServerAspect
pulsar_1          | [MethodUtil@73e17fd6] info register aspect org.apache.pulsar.broker.zookeeper.aspectj.ClientCnxnAspect
pulsar_1          | 10:11:05.816 [main] INFO  org.apache.pulsar.broker.PulsarService - Starting Pulsar Broker service; version: '2.5.0'
pulsar_1          | 10:11:05.816 [main] INFO  org.apache.pulsar.broker.PulsarService - Git Revision ed147269a51c217ff0b7dea2b6ed9fcfbcf2cb71
pulsar_1          | 10:11:05.816 [main] INFO  org.apache.pulsar.broker.PulsarService - Built by  <> on fv-az59 at 2020-01-16T18:46:15+0000
pulsar_1          | 10:11:05.831 [main] INFO  org.apache.pulsar.broker.protocol.ProtocolHandlerUtils - Searching for protocol handlers in /pulsar/./protocols
pulsar_1          | 10:11:05.832 [main] WARN  org.apache.pulsar.broker.protocol.ProtocolHandlerUtils - Protocol handler directory not found
pulsar_1          | 10:11:05.844 [pulsar-ordered-OrderedExecutor-0-0] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@3436e7f7
pulsar_1          | 10:11:05.845 [pulsar-ordered-OrderedExecutor-0-0] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:05.846 [pulsar-ordered-OrderedExecutor-0-0] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:05.848 [pulsar-ordered-OrderedExecutor-0-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:05.849 [pulsar-ordered-OrderedExecutor-0-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55174, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:05.851 [pulsar-ordered-OrderedExecutor-0-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a560009, negotiated timeout = 30000
pulsar_1          | 10:11:05.852 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:05.853 [pulsar-ordered-OrderedExecutor-0-0] INFO  org.apache.pulsar.zookeeper.ZookeeperBkClientFactoryImpl - ZooKeeper session established: State:CONNECTED Timeout:30000 sessionid:0x10007e92a560009 local:/127.0.0.1:55174 remoteserver:localhost/127.0.0.1:2181 lastZxid:0 xid:1 sent:1 recv:1 queuedpkts:0 pendingresp:0 queuedevents:0
pulsar_1          | 10:11:05.859 [main] INFO  org.apache.pulsar.broker.PulsarService - starting configuration cache service
pulsar_1          | 10:11:05.932 [pulsar-ordered-OrderedExecutor-3-0] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@4b4adcab
pulsar_1          | 10:11:05.934 [pulsar-ordered-OrderedExecutor-3-0] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:05.934 [pulsar-ordered-OrderedExecutor-3-0] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:05.936 [pulsar-ordered-OrderedExecutor-3-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:05.937 [pulsar-ordered-OrderedExecutor-3-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55176, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:05.939 [pulsar-ordered-OrderedExecutor-3-0-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a56000a, negotiated timeout = 30000
pulsar_1          | 10:11:05.940 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:05.940 [pulsar-ordered-OrderedExecutor-3-0] INFO  org.apache.pulsar.zookeeper.ZookeeperBkClientFactoryImpl - ZooKeeper session established: State:CONNECTED Timeout:30000 sessionid:0x10007e92a56000a local:/127.0.0.1:55176 remoteserver:localhost/127.0.0.1:2181 lastZxid:0 xid:1 sent:1 recv:1 queuedpkts:0 pendingresp:0 queuedevents:0
pulsar_1          | 10:11:06.014 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a560009 local:/127.0.0.1:55174 remoteserver:localhost/127.0.0.1:2181 lastZxid:80 xid:3 sent:3 recv:4 queuedpkts:0 pendingresp:0 queuedevents:1] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeCreated path:/managed-ledgers
pulsar_1          | 10:11:06.026 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a560009 local:/127.0.0.1:55174 remoteserver:localhost/127.0.0.1:2181 lastZxid:81 xid:5 sent:5 recv:7 queuedpkts:0 pendingresp:0 queuedevents:1] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeCreated path:/namespace
pulsar_1          | 10:11:06.032 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a560009 local:/127.0.0.1:55174 remoteserver:localhost/127.0.0.1:2181 lastZxid:82 xid:7 sent:7 recv:10 queuedpkts:0 pendingresp:0 queuedevents:1] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeCreated path:/admin/local-policies
pulsar_1          | 10:11:06.114 [main] INFO  org.apache.bookkeeper.meta.zk.ZKMetadataDriverBase - Initialize zookeeper metadata driver with external zookeeper client : ledgersRootPath = /ledgers.
pulsar_1          | 10:11:06.115 [main] WARN  org.apache.bookkeeper.util.EventLoopUtil - Could not use Netty Epoll event loop: Could not initialize class io.netty.channel.epoll.EpollEventLoop
pulsar_1          | 10:11:06.125 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie rack affinity mapping cache.
pulsar_1          | 10:11:06.142 [main] WARN  org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy - Failed to resolve network location for 172.28.0.2, using default rack for it : /default-rack.
pulsar_1          | 10:11:06.142 [main] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Initialize rackaware ensemble placement policy @ <Bookie:172.28.0.2:0> @ /default-rack : org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.
pulsar_1          | 10:11:06.142 [main] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Not weighted
pulsar_1          | 10:11:06.142 [main] INFO  org.apache.bookkeeper.client.BookKeeper - Weighted ledger placement is not enabled
pulsar_1          | 10:11:06.148 [BookKeeperClientScheduler-OrderedScheduler-0-0] WARN  org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy - Failed to resolve network location for 127.0.0.1, using default rack for it : /default-rack.
pulsar_1          | 10:11:06.149 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/127.0.0.1:3181
pulsar_1          | 10:11:06.184 [main] INFO  org.apache.bookkeeper.mledger.impl.EntryCacheManager - Initialized managed-ledger entry cache of 204.0 Mb
pulsar_1          | 10:11:06.222 [main] INFO  org.apache.pulsar.broker.service.BrokerService - Using 8 threads for broker service IO
pulsar_1          | 10:11:06.230 [main] INFO  org.apache.pulsar.broker.authentication.AuthenticationService - Authentication is disabled
pulsar_1          | 10:11:06.251 [main] INFO  org.apache.pulsar.broker.service.BrokerService - Disabling per broker unack-msg blocking due invalid unAckMsgSubscriptionPercentageLimitOnBrokerBlocked 0.16 
pulsar_1          | 10:11:06.263 [main] INFO  org.apache.pulsar.broker.PulsarService - No ledger offloader configured, using NULL instance
pulsar_1          | 10:11:06.283 [main] INFO  org.apache.pulsar.broker.service.DistributedIdGenerator - Created sequential node at /counters/producer-name/-0000000000 -- Generator Id is standalone-0
pulsar_1          | 10:11:06.288 [main] INFO  org.apache.pulsar.broker.service.BrokerService - Started Pulsar Broker service on /0.0.0.0:6650
pulsar_1          | 10:11:06.374 [main] INFO  org.apache.pulsar.broker.service.BrokerService - Scheduling a thread to check backlog quota after [60] seconds in background
pulsar_1          | 10:11:06.425 [main] INFO  org.eclipse.jetty.util.log - Logging initialized @12659ms to org.eclipse.jetty.util.log.Slf4jLog
pulsar_1          | 10:11:06.723 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.pulsar.zookeeper.ZookeeperClientFactoryImpl$$Lambda$376/393476856@30f99ca1
pulsar_1          | 10:11:06.723 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:06.724 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:06.727 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:06.727 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55178, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:06.731 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a56000b, negotiated timeout = 30000
pulsar_1          | 10:11:06.731 [main-EventThread] INFO  org.apache.pulsar.zookeeper.ZookeeperClientFactoryImpl - ZooKeeper session established: State:CONNECTED Timeout:30000 sessionid:0x10007e92a56000b local:/127.0.0.1:55178 remoteserver:localhost/127.0.0.1:2181 lastZxid:0 xid:1 sent:1 recv:1 queuedpkts:0 pendingresp:0 queuedevents:0
pulsar_1          | 10:11:06.738 [main] INFO  org.apache.pulsar.websocket.WebSocketService - Global Zookeeper cache started
pulsar_1          | 10:11:06.738 [main] INFO  org.apache.pulsar.broker.authentication.AuthenticationService - Authentication is disabled
pulsar_1          | 10:11:06.738 [main] INFO  org.apache.pulsar.websocket.WebSocketService - Pulsar WebSocket Service started
pulsar_1          | 10:11:06.807 [main] INFO  org.apache.bookkeeper.meta.zk.ZKMetadataDriverBase - Initialize zookeeper metadata driver with external zookeeper client : ledgersRootPath = /ledgers.
pulsar_1          | 10:11:06.807 [main] WARN  org.apache.bookkeeper.util.EventLoopUtil - Could not use Netty Epoll event loop: Could not initialize class io.netty.channel.epoll.EpollEventLoop
pulsar_1          | 10:11:06.809 [main] WARN  org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy - Failed to resolve network location for 172.28.0.2, using default rack for it : /default-rack.
pulsar_1          | 10:11:06.810 [main] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Initialize rackaware ensemble placement policy @ <Bookie:172.28.0.2:0> @ /default-rack : org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.
pulsar_1          | 10:11:06.810 [main] INFO  org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Not weighted
pulsar_1          | 10:11:06.810 [main] INFO  org.apache.bookkeeper.client.BookKeeper - Weighted ledger placement is not enabled
pulsar_1          | 10:11:06.817 [BookKeeperClientScheduler-OrderedScheduler-0-0] WARN  org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy - Failed to resolve network location for 127.0.0.1, using default rack for it : /default-rack.
pulsar_1          | 10:11:06.818 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/127.0.0.1:3181
pulsar_1          | 10:11:06.840 [main] INFO  org.eclipse.jetty.server.Server - jetty-9.4.20.v20190813; built: 2019-08-13T21:28:18.144Z; git: 84700530e645e812b336747464d6fbbf370c9a20; jvm 1.8.0_232-b09
pulsar_1          | 10:11:06.905 [main] INFO  org.eclipse.jetty.server.session - DefaultSessionIdManager workerName=node0
pulsar_1          | 10:11:06.907 [main] INFO  org.eclipse.jetty.server.session - No SessionScavenger set, using defaults
pulsar_1          | 10:11:06.912 [main] INFO  org.eclipse.jetty.server.session - node0 Scavenging every 600000ms
pulsar_1          | 10:11:08.928 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@684eb4a0{/,null,AVAILABLE}
pulsar_1          | 10:11:09.056 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@19a4cdea{/,null,AVAILABLE}
pulsar_1          | 10:11:09.881 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@6fb51e17{/admin,null,AVAILABLE}
pulsar_1          | 10:11:10.389 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@5fb0a09e{/admin/v2,null,AVAILABLE}
pulsar_1          | 10:11:11.029 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@45e68fac{/admin/v3,null,AVAILABLE}
pulsar_1          | 10:11:11.150 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@732bb49d{/lookup,null,AVAILABLE}
pulsar_1          | 10:11:11.152 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@721fc228{/metrics,null,AVAILABLE}
pulsar_1          | 10:11:11.228 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@6debf1b8{/ws/producer,null,AVAILABLE}
pulsar_1          | 10:11:11.232 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@4fe9fb65{/ws/v2/producer,null,AVAILABLE}
pulsar_1          | 10:11:11.237 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@722d3ddb{/ws/consumer,null,AVAILABLE}
pulsar_1          | 10:11:11.241 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@701da311{/ws/v2/consumer,null,AVAILABLE}
pulsar_1          | 10:11:11.245 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@25b87e1b{/ws/reader,null,AVAILABLE}
pulsar_1          | 10:11:11.248 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@5de14222{/ws/v2/reader,null,AVAILABLE}
pulsar_1          | 10:11:11.252 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.h.ContextHandler@434a2a10{/static,null,AVAILABLE}
pulsar_1          | 10:11:11.280 [main] INFO  org.eclipse.jetty.server.AbstractConnector - Started PulsarServerConnector@7fa2473a{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
pulsar_1          | 10:11:11.285 [main] INFO  org.eclipse.jetty.server.Server - Started @17556ms
pulsar_1          | 10:11:11.285 [main] INFO  org.apache.pulsar.broker.web.WebService - HTTP Service started at http://0.0.0.0:8080
pulsar_1          | 10:11:11.285 [main] INFO  org.apache.pulsar.broker.web.WebService - HTTPS Service disabled
pulsar_1          | 10:11:11.286 [main] INFO  org.apache.pulsar.broker.PulsarService - Starting name space service, bootstrap namespaces=[]
pulsar_1          | 10:11:11.334 [main] INFO  org.apache.pulsar.broker.loadbalance.LeaderElectionService - LeaderElectionService started
pulsar_1          | 10:11:11.345 [main] INFO  org.apache.pulsar.broker.loadbalance.LeaderElectionService - Broker [http://localhost:8080] is the leader now, notifying the listener...
pulsar_1          | 10:11:11.365 [main] INFO  org.apache.pulsar.broker.cache.LocalZooKeeperCacheService - Successfully created local policies for /admin/local-policies/pulsar/standalone/localhost:8080 -- Optional.empty
pulsar_1          | 10:11:11.387 [main] INFO  org.apache.pulsar.broker.namespace.OwnershipCache - Trying to acquire ownership of pulsar/standalone/localhost:8080/0x00000000_0xffffffff
pulsar_1          | 10:11:11.411 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.broker.namespace.OwnershipCache - Successfully acquired ownership of /namespace/pulsar/standalone/localhost:8080/0x00000000_0xffffffff
pulsar_1          | 10:11:11.413 [main] INFO  org.apache.pulsar.broker.namespace.NamespaceService - added heartbeat namespace name in local cache: ns=pulsar/standalone/localhost:8080
pulsar_1          | 10:11:11.414 [pulsar-30-1] INFO  org.apache.pulsar.broker.PulsarService - Loading all topics on bundle: pulsar/standalone/localhost:8080/0x00000000_0xffffffff
pulsar_1          | 10:11:11.440 [main] INFO  org.apache.pulsar.broker.PulsarService - Starting load management service ...
pulsar_1          | 10:11:11.478 [main] INFO  org.apache.pulsar.broker.PulsarService - SLA Namespace = sla-monitor/standalone/localhost:8080 doesn't exist.
pulsar_1          | 10:11:11.478 [main] INFO  org.apache.pulsar.broker.PulsarService - Starting function worker service
pulsar_1          | 10:11:11.487 [main] INFO  org.apache.pulsar.broker.PulsarService - Created property public for function worker
pulsar_1          | 10:11:11.492 [main] INFO  org.apache.pulsar.broker.PulsarService - Created cluster standalone for function worker
pulsar_1          | 10:11:11.518 [main] INFO  org.apache.pulsar.broker.PulsarService - Created namespace public/functions for function worker service
pulsar_1          | 10:11:11.530 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@43aa9ccd
pulsar_1          | 10:11:11.530 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:11.531 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:11.533 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:11.533 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55180, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:11.538 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a56000c, negotiated timeout = 30000
pulsar_1          | 10:11:11.539 [main-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:11.547 [main] INFO  org.apache.distributedlog.ZooKeeperClient - Close zookeeper client default.
pulsar_1          | 10:11:11.547 [main] INFO  org.apache.distributedlog.ZooKeeperClient - Closing zookeeper client default.
pulsar_1          | 10:11:11.650 [main] INFO  org.apache.zookeeper.ZooKeeper - Session: 0x10007e92a56000c closed
pulsar_1          | 10:11:11.651 [main] INFO  org.apache.distributedlog.ZooKeeperClient - Closed zookeeper client default.
pulsar_1          | 10:11:11.651 [main] INFO  org.apache.pulsar.broker.PulsarService - Function worker service setup completed
pulsar_1          | 10:11:11.651 [main-EventThread] INFO  org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x10007e92a56000c
pulsar_1          | 10:11:11.651 [main] INFO  org.apache.pulsar.functions.worker.WorkerService - Starting worker c-standalone-fw-localhost-8080...
pulsar_1          | 10:11:11.671 [main] INFO  org.apache.pulsar.functions.worker.WorkerService - Worker Configs: {
pulsar_1          |   "workerId" : "c-standalone-fw-localhost-8080",
pulsar_1          |   "workerHostname" : "localhost",
pulsar_1          |   "workerPort" : 8080,
pulsar_1          |   "workerPortTls" : 6751,
pulsar_1          |   "jvmGCMetricsLoggerClassName" : null,
pulsar_1          |   "numHttpServerThreads" : 8,
pulsar_1          |   "configurationStoreServers" : "127.0.0.1:2181",
pulsar_1          |   "zooKeeperSessionTimeoutMillis" : 30000,
pulsar_1          |   "zooKeeperOperationTimeoutSeconds" : 30,
pulsar_1          |   "connectorsDirectory" : "./connectors",
pulsar_1          |   "functionMetadataTopicName" : "metadata",
pulsar_1          |   "functionWebServiceUrl" : null,
pulsar_1          |   "pulsarServiceUrl" : "pulsar://localhost:6650",
pulsar_1          |   "pulsarWebServiceUrl" : "http://localhost:8080",
pulsar_1          |   "clusterCoordinationTopicName" : "coordinate",
pulsar_1          |   "pulsarFunctionsNamespace" : "public/functions",
pulsar_1          |   "pulsarFunctionsCluster" : "standalone",
pulsar_1          |   "numFunctionPackageReplicas" : 1,
pulsar_1          |   "downloadDirectory" : "download/pulsar_functions",
pulsar_1          |   "stateStorageServiceUrl" : "bk://127.0.0.1:4181",
pulsar_1          |   "functionAssignmentTopicName" : "assignments",
pulsar_1          |   "schedulerClassName" : "org.apache.pulsar.functions.worker.scheduler.RoundRobinScheduler",
pulsar_1          |   "failureCheckFreqMs" : 30000,
pulsar_1          |   "rescheduleTimeoutMs" : 60000,
pulsar_1          |   "initialBrokerReconnectMaxRetries" : 60,
pulsar_1          |   "assignmentWriteMaxRetries" : 60,
pulsar_1          |   "instanceLivenessCheckFreqMs" : 30000,
pulsar_1          |   "clientAuthenticationPlugin" : "org.apache.pulsar.client.impl.auth.AuthenticationDisabled",
pulsar_1          |   "clientAuthenticationParameters" : "",
pulsar_1          |   "bookkeeperClientAuthenticationPlugin" : null,
pulsar_1          |   "bookkeeperClientAuthenticationParametersName" : null,
pulsar_1          |   "bookkeeperClientAuthenticationParameters" : null,
pulsar_1          |   "topicCompactionFrequencySec" : 1800,
pulsar_1          |   "tlsEnabled" : true,
pulsar_1          |   "tlsCertificateFilePath" : null,
pulsar_1          |   "tlsKeyFilePath" : null,
pulsar_1          |   "tlsTrustCertsFilePath" : "",
pulsar_1          |   "tlsAllowInsecureConnection" : false,
pulsar_1          |   "tlsRequireTrustedClientCertOnConnect" : false,
pulsar_1          |   "useTls" : false,
pulsar_1          |   "tlsHostnameVerificationEnable" : false,
pulsar_1          |   "tlsCertRefreshCheckDurationSec" : 300,
pulsar_1          |   "authenticationEnabled" : false,
pulsar_1          |   "authenticationProviders" : [ ],
pulsar_1          |   "authorizationEnabled" : false,
pulsar_1          |   "authorizationProvider" : "org.apache.pulsar.broker.authorization.PulsarAuthorizationProvider",
pulsar_1          |   "superUserRoles" : [ ],
pulsar_1          |   "properties" : { },
pulsar_1          |   "functionRuntimeFactoryClassName" : "org.apache.pulsar.functions.runtime.process.ProcessRuntimeFactory",
pulsar_1          |   "functionRuntimeFactoryConfigs" : {
pulsar_1          |     "logDirectory" : "/tmp",
pulsar_1          |     "javaInstanceJarLocation" : null,
pulsar_1          |     "pythonInstanceLocation" : null,
pulsar_1          |     "extraFunctionDependenciesDir" : null
pulsar_1          |   },
pulsar_1          |   "secretsProviderConfiguratorClassName" : null,
pulsar_1          |   "secretsProviderConfiguratorConfig" : null,
pulsar_1          |   "functionInstanceMinResources" : null,
pulsar_1          |   "functionAuthProviderClassName" : null,
pulsar_1          |   "runtimeCustomizerClassName" : null,
pulsar_1          |   "runtimeCustomizerConfig" : { },
pulsar_1          |   "threadContainerFactory" : null,
pulsar_1          |   "processContainerFactory" : null,
pulsar_1          |   "kubernetesContainerFactory" : null,
pulsar_1          |   "workerWebAddress" : "http://localhost:8080",
pulsar_1          |   "functionAssignmentTopic" : "persistent://public/functions/assignments",
pulsar_1          |   "clusterCoordinationTopic" : "persistent://public/functions/coordinate",
pulsar_1          |   "functionMetadataTopic" : "persistent://public/functions/metadata",
pulsar_1          |   "tlsTrustChainBytes" : null
pulsar_1          | }
pulsar_1          | 10:11:11.675 [main] INFO  org.apache.distributedlog.api.namespace.NamespaceBuilder - No feature provider is set. All features are disabled now.
pulsar_1          | 10:11:11.679 [main] INFO  org.apache.distributedlog.impl.BKNamespaceDriver - Created shared zooKeeper client builder dlzk:distributedlog://127.0.0.1:2181/pulsar/functions:factory_writer_shared: zkServers = 127.0.0.1:2181, numRetries = 3, sessionTimeout = 30000, retryBackoff = 5000, maxRetryBackoff = 30000, zkAclId = null.
pulsar_1          | 10:11:11.680 [main] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=127.0.0.1:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@a0464ce
pulsar_1          | 10:11:11.681 [main] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
pulsar_1          | 10:11:11.681 [main] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=
pulsar_1          | 10:11:11.686 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
pulsar_1          | 10:11:11.687 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /127.0.0.1:55182, server: localhost/127.0.0.1:2181
pulsar_1          | 10:11:11.689 [main-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x10007e92a56000d, negotiated timeout = 30000
pulsar_1          | 10:11:11.690 [main-EventThread] INFO  org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
pulsar_1          | 10:11:11.694 [main] WARN  org.apache.distributedlog.impl.BKNamespaceDriver - Could not use Netty Epoll event loop for bookie server:
pulsar_1          | java.lang.NoClassDefFoundError: Could not initialize class io.netty.channel.epoll.EpollEventLoop
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.newChild(EpollEventLoopGroup.java:142) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.newChild(EpollEventLoopGroup.java:35) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:84) ~[io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:58) ~[io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:47) ~[io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.MultithreadEventLoopGroup.<init>(MultithreadEventLoopGroup.java:59) ~[io.netty-netty-transport-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.<init>(EpollEventLoopGroup.java:104) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.<init>(EpollEventLoopGroup.java:91) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at io.netty.channel.epoll.EpollEventLoopGroup.<init>(EpollEventLoopGroup.java:68) ~[io.netty-netty-transport-native-epoll-4.1.43.Final.jar:4.1.43.Final]
pulsar_1          |    at org.apache.distributedlog.impl.BKNamespaceDriver.getDefaultEventLoopGroup(BKNamespaceDriver.java:257) [org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.distributedlog.impl.BKNamespaceDriver.initializeBookKeeperClients(BKNamespaceDriver.java:268) [org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.distributedlog.impl.BKNamespaceDriver.initialize(BKNamespaceDriver.java:206) [org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.distributedlog.api.namespace.NamespaceBuilder.build(NamespaceBuilder.java:239) [org.apache.distributedlog-distributedlog-core-4.10.0.jar:4.10.0]
pulsar_1          |    at org.apache.pulsar.functions.worker.WorkerService.start(WorkerService.java:105) [org.apache.pulsar-pulsar-functions-worker-2.5.0.jar:2.5.0]
pulsar_1          |    at org.apache.pulsar.broker.PulsarService.startWorkerService(PulsarService.java:1108) [org.apache.pulsar-pulsar-broker-2.5.0.jar:2.5.0]
pulsar_1          |    at org.apache.pulsar.broker.PulsarService.start(PulsarService.java:505) [org.apache.pulsar-pulsar-broker-2.5.0.jar:2.5.0]
pulsar_1          |    at org.apache.pulsar.PulsarStandalone.start(PulsarStandalone.java:318) [org.apache.pulsar-pulsar-broker-2.5.0.jar:2.5.0]
pulsar_1          |    at org.apache.pulsar.PulsarStandaloneStarter.main(PulsarStandaloneStarter.java:119) [org.apache.pulsar-pulsar-broker-2.5.0.jar:2.5.0]
pulsar_1          | 10:11:11.697 [main] INFO  org.apache.distributedlog.impl.BKNamespaceDriver - Created shared client builder bk:distributedlog://127.0.0.1:2181/pulsar/functions:factory_writer_shared : zkServers = 127.0.0.1:2181, ledgersPath = /ledgers, numIOThreads = 4
pulsar_1          | 10:11:11.698 [main] INFO  org.apache.distributedlog.impl.metadata.BKDLConfig - Propagate BKDLConfig to DLConfig : encodeRegionID = false, firstLogSegmentSequenceNumber = 1, createStreamIfNotExists = true, isFederated = false.
pulsar_1          | 10:11:11.699 [main] INFO  org.apache.distributedlog.impl.BKNamespaceDriver - Initialized BK namespace driver: clientId = function-worker-c-standalone-fw-localhost-8080, regionId = 0, federated = false.
pulsar_1          | 10:11:11.699 [main] INFO  org.apache.distributedlog.logsegment.LogSegmentMetadataCache - Log segment cache is enabled = true
pulsar_1          | 10:11:12.513 [main] INFO  org.apache.pulsar.functions.worker.WorkerService - Created Pulsar client
pulsar_1          | 10:11:12.949 [pulsar-web-57-6] INFO  org.eclipse.jetty.util.TypeUtil - JVM Runtime does not support Modules
pulsar_1          | 10:11:13.207 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.broker.cache.LocalZooKeeperCacheService - Successfully copyied bundles data to local zk at /admin/local-policies/public/functions
pulsar_1          | 10:11:13.207 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.broker.cache.LocalZooKeeperCacheService - Successfully created local policies for /admin/local-policies/public/functions -- Optional[org.apache.pulsar.common.policies.data.LocalPolicies@6d50a12c]
pulsar_1          | 10:11:13.229 [pulsar-30-2] INFO  org.apache.pulsar.broker.namespace.OwnershipCache - Trying to acquire ownership of public/functions/0x40000000_0x80000000
pulsar_1          | 10:11:13.241 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.broker.namespace.OwnershipCache - Successfully acquired ownership of /namespace/public/functions/0x40000000_0x80000000
pulsar_1          | 10:11:13.241 [pulsar-30-3] INFO  org.apache.pulsar.broker.PulsarService - Loading all topics on bundle: public/functions/0x40000000_0x80000000
pulsar_1          | 10:11:13.303 [pulsar-web-57-6] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - Opening managed ledger public/functions/persistent/assignments
pulsar_1          | 10:11:13.310 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO  org.apache.bookkeeper.mledger.impl.MetaStoreImplZookeeper - Creating '/managed-ledgers/public/functions/persistent/assignments'
pulsar_1          | 10:11:13.328 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a560009 local:/127.0.0.1:55174 remoteserver:localhost/127.0.0.1:2181 lastZxid:129 xid:74 sent:74 recv:78 queuedpkts:0 pendingresp:0 queuedevents:1] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeCreated path:/managed-ledgers/public/functions/persistent
pulsar_1          | 10:11:13.333 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - reloadCache called in zookeeperChildrenCache for path /managed-ledgers/public/functions/persistent
pulsar_1          | 10:11:13.341 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:13.362 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 6
pulsar_1          | 10:11:13.365 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/functions/persistent/assignments] Created ledger 6
pulsar_1          | 10:11:13.406 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN  org.apache.pulsar.broker.service.AbstractTopic - [persistent://public/functions/assignments] Error getting policies java.util.concurrent.CompletableFuture cannot be cast to org.apache.pulsar.common.policies.data.Policies and publish throttling will be disabled
pulsar_1          | 10:11:13.406 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO  org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://public/functions/assignments
pulsar_1          | 10:11:13.428 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/assignments] There are no replicated subscriptions on the topic
pulsar_1          | 10:11:13.438 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO  org.apache.pulsar.broker.service.BrokerService - Created topic persistent://public/functions/assignments - dedup is disabled
pulsar_1          | 10:11:13.442 [pulsar-web-57-6] INFO  org.apache.pulsar.broker.admin.impl.PersistentTopicsBase - [null] Successfully created non-partitioned topic PersistentTopic{topic=persistent://public/functions/assignments}
pulsar_1          | 10:11:13.482 [pulsar-web-57-6] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:12 +0000] "PUT /admin/v2/persistent/public/functions/assignments HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 525
pulsar_1          | 10:11:13.511 [pulsar-ordered-OrderedExecutor-7-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - Opening managed ledger public/functions/persistent/coordinate
pulsar_1          | 10:11:13.513 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.bookkeeper.mledger.impl.MetaStoreImplZookeeper - Creating '/managed-ledgers/public/functions/persistent/coordinate'
pulsar_1          | 10:11:13.521 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a560009 local:/127.0.0.1:55174 remoteserver:localhost/127.0.0.1:2181 lastZxid:135 xid:84 sent:84 recv:89 queuedpkts:0 pendingresp:0 queuedevents:1] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/managed-ledgers/public/functions/persistent
pulsar_1          | 10:11:13.525 [bookkeeper-ml-workers-OrderedExecutor-2-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:13.527 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - reloadCache called in zookeeperChildrenCache for path /managed-ledgers/public/functions/persistent
pulsar_1          | 10:11:13.535 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 7
pulsar_1          | 10:11:13.536 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/functions/persistent/coordinate] Created ledger 7
pulsar_1          | 10:11:13.540 [bookkeeper-ml-workers-OrderedExecutor-2-0] WARN  org.apache.pulsar.broker.service.AbstractTopic - [persistent://public/functions/coordinate] Error getting policies java.util.concurrent.CompletableFuture cannot be cast to org.apache.pulsar.common.policies.data.Policies and publish throttling will be disabled
pulsar_1          | 10:11:13.540 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://public/functions/coordinate
pulsar_1          | 10:11:13.542 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/coordinate] There are no replicated subscriptions on the topic
pulsar_1          | 10:11:13.542 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.pulsar.broker.service.BrokerService - Created topic persistent://public/functions/coordinate - dedup is disabled
pulsar_1          | 10:11:13.545 [pulsar-web-57-1] INFO  org.apache.pulsar.broker.admin.impl.PersistentTopicsBase - [null] Successfully created non-partitioned topic PersistentTopic{topic=persistent://public/functions/coordinate}
pulsar_1          | 10:11:13.547 [pulsar-web-57-1] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:13 +0000] "PUT /admin/v2/persistent/public/functions/coordinate HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 45
pulsar_1          | 10:11:13.555 [pulsar-ordered-OrderedExecutor-6-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - Opening managed ledger public/functions/persistent/metadata
pulsar_1          | 10:11:13.557 [bookkeeper-ml-workers-OrderedExecutor-1-0] INFO  org.apache.bookkeeper.mledger.impl.MetaStoreImplZookeeper - Creating '/managed-ledgers/public/functions/persistent/metadata'
pulsar_1          | 10:11:13.559 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a560009 local:/127.0.0.1:55174 remoteserver:localhost/127.0.0.1:2181 lastZxid:140 xid:92 sent:92 recv:98 queuedpkts:0 pendingresp:0 queuedevents:1] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/managed-ledgers/public/functions/persistent
pulsar_1          | 10:11:13.561 [bookkeeper-ml-workers-OrderedExecutor-1-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:13.563 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - reloadCache called in zookeeperChildrenCache for path /managed-ledgers/public/functions/persistent
pulsar_1          | 10:11:13.570 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 8
pulsar_1          | 10:11:13.570 [bookkeeper-ml-workers-OrderedExecutor-1-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/functions/persistent/metadata] Created ledger 8
pulsar_1          | 10:11:13.575 [bookkeeper-ml-workers-OrderedExecutor-1-0] WARN  org.apache.pulsar.broker.service.AbstractTopic - [persistent://public/functions/metadata] Error getting policies java.util.concurrent.CompletableFuture cannot be cast to org.apache.pulsar.common.policies.data.Policies and publish throttling will be disabled
pulsar_1          | 10:11:13.575 [bookkeeper-ml-workers-OrderedExecutor-1-0] INFO  org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://public/functions/metadata
pulsar_1          | 10:11:13.577 [bookkeeper-ml-workers-OrderedExecutor-1-0] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/metadata] There are no replicated subscriptions on the topic
pulsar_1          | 10:11:13.577 [bookkeeper-ml-workers-OrderedExecutor-1-0] INFO  org.apache.pulsar.broker.service.BrokerService - Created topic persistent://public/functions/metadata - dedup is disabled
pulsar_1          | 10:11:13.578 [pulsar-web-57-4] INFO  org.apache.pulsar.broker.admin.impl.PersistentTopicsBase - [null] Successfully created non-partitioned topic PersistentTopic{topic=persistent://public/functions/metadata}
pulsar_1          | 10:11:13.579 [pulsar-web-57-4] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:13 +0000] "PUT /admin/v2/persistent/public/functions/metadata HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 28
pulsar_1          | 10:11:13.987 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConnectionPool - [[id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]] Connected to server
pulsar_1          | 10:11:14.006 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - New connection from /127.0.0.1:36144
pulsar_1          | 10:11:14.162 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerStatsRecorderImpl - Starting Pulsar producer perf with config: {
pulsar_1          |   "topicName" : "persistent://public/functions/assignments",
pulsar_1          |   "producerName" : null,
pulsar_1          |   "sendTimeoutMs" : 0,
pulsar_1          |   "blockIfQueueFull" : true,
pulsar_1          |   "maxPendingMessages" : 1000,
pulsar_1          |   "maxPendingMessagesAcrossPartitions" : 50000,
pulsar_1          |   "messageRoutingMode" : "RoundRobinPartition",
pulsar_1          |   "hashingScheme" : "JavaStringHash",
pulsar_1          |   "cryptoFailureAction" : "FAIL",
pulsar_1          |   "batchingMaxPublishDelayMicros" : 1000,
pulsar_1          |   "batchingPartitionSwitchFrequencyByPublishDelay" : 10,
pulsar_1          |   "batchingMaxMessages" : 1000,
pulsar_1          |   "batchingMaxBytes" : 131072,
pulsar_1          |   "batchingEnabled" : false,
pulsar_1          |   "compressionType" : "LZ4",
pulsar_1          |   "initialSequenceId" : null,
pulsar_1          |   "autoUpdatePartitions" : true,
pulsar_1          |   "multiSchema" : true,
pulsar_1          |   "properties" : { }
pulsar_1          | }
pulsar_1          | 10:11:14.167 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerStatsRecorderImpl - Pulsar client config: {
pulsar_1          |   "serviceUrl" : "pulsar://localhost:6650",
pulsar_1          |   "authPluginClassName" : null,
pulsar_1          |   "authParams" : null,
pulsar_1          |   "operationTimeoutMs" : 30000,
pulsar_1          |   "statsIntervalSeconds" : 60,
pulsar_1          |   "numIoThreads" : 1,
pulsar_1          |   "numListenerThreads" : 1,
pulsar_1          |   "connectionsPerBroker" : 1,
pulsar_1          |   "useTcpNoDelay" : true,
pulsar_1          |   "useTls" : false,
pulsar_1          |   "tlsTrustCertsFilePath" : "",
pulsar_1          |   "tlsAllowInsecureConnection" : false,
pulsar_1          |   "tlsHostnameVerificationEnable" : false,
pulsar_1          |   "concurrentLookupRequest" : 5000,
pulsar_1          |   "maxLookupRequest" : 50000,
pulsar_1          |   "maxNumberOfRejectedRequestPerConnection" : 50,
pulsar_1          |   "keepAliveIntervalSeconds" : 30,
pulsar_1          |   "connectionTimeoutMs" : 10000,
pulsar_1          |   "requestTimeoutMs" : 60000,
pulsar_1          |   "initialBackoffIntervalNanos" : 100000000,
pulsar_1          |   "maxBackoffIntervalNanos" : 60000000000
pulsar_1          | }
pulsar_1          | 10:11:14.210 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerImpl - [persistent://public/functions/assignments] [null] Creating producer on cnx [id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]
pulsar_1          | 10:11:14.225 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144][persistent://public/functions/assignments] Creating producer. producerId=0
pulsar_1          | 10:11:14.246 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] persistent://public/functions/assignments configured with schema false
pulsar_1          | 10:11:14.261 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Created new producer: Producer{topic=PersistentTopic{topic=persistent://public/functions/assignments}, client=/127.0.0.1:36144, producerName=standalone-0-0, producerId=0}
pulsar_1          | 10:11:14.272 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerImpl - [persistent://public/functions/assignments] [standalone-0-0] Created producer on cnx [id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]
pulsar_1          | 10:11:14.281 [main] INFO  org.apache.pulsar.functions.utils.Actions - Sucessfully completed action [ Creating producer for assignment topic persistent://public/functions/assignments ]
pulsar_1          | 10:11:14.310 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerStatsRecorderImpl - Starting Pulsar producer perf with config: {
pulsar_1          |   "topicName" : "persistent://public/functions/metadata",
pulsar_1          |   "producerName" : null,
pulsar_1          |   "sendTimeoutMs" : 30000,
pulsar_1          |   "blockIfQueueFull" : false,
pulsar_1          |   "maxPendingMessages" : 1000,
pulsar_1          |   "maxPendingMessagesAcrossPartitions" : 50000,
pulsar_1          |   "messageRoutingMode" : "RoundRobinPartition",
pulsar_1          |   "hashingScheme" : "JavaStringHash",
pulsar_1          |   "cryptoFailureAction" : "FAIL",
pulsar_1          |   "batchingMaxPublishDelayMicros" : 1000,
pulsar_1          |   "batchingPartitionSwitchFrequencyByPublishDelay" : 10,
pulsar_1          |   "batchingMaxMessages" : 1000,
pulsar_1          |   "batchingMaxBytes" : 131072,
pulsar_1          |   "batchingEnabled" : true,
pulsar_1          |   "compressionType" : "NONE",
pulsar_1          |   "initialSequenceId" : null,
pulsar_1          |   "autoUpdatePartitions" : true,
pulsar_1          |   "multiSchema" : true,
pulsar_1          |   "properties" : { }
pulsar_1          | }
pulsar_1          | 10:11:14.312 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerStatsRecorderImpl - Pulsar client config: {
pulsar_1          |   "serviceUrl" : "pulsar://localhost:6650",
pulsar_1          |   "authPluginClassName" : null,
pulsar_1          |   "authParams" : null,
pulsar_1          |   "operationTimeoutMs" : 30000,
pulsar_1          |   "statsIntervalSeconds" : 60,
pulsar_1          |   "numIoThreads" : 1,
pulsar_1          |   "numListenerThreads" : 1,
pulsar_1          |   "connectionsPerBroker" : 1,
pulsar_1          |   "useTcpNoDelay" : true,
pulsar_1          |   "useTls" : false,
pulsar_1          |   "tlsTrustCertsFilePath" : "",
pulsar_1          |   "tlsAllowInsecureConnection" : false,
pulsar_1          |   "tlsHostnameVerificationEnable" : false,
pulsar_1          |   "concurrentLookupRequest" : 5000,
pulsar_1          |   "maxLookupRequest" : 50000,
pulsar_1          |   "maxNumberOfRejectedRequestPerConnection" : 50,
pulsar_1          |   "keepAliveIntervalSeconds" : 30,
pulsar_1          |   "connectionTimeoutMs" : 10000,
pulsar_1          |   "requestTimeoutMs" : 60000,
pulsar_1          |   "initialBackoffIntervalNanos" : 100000000,
pulsar_1          |   "maxBackoffIntervalNanos" : 60000000000
pulsar_1          | }
pulsar_1          | 10:11:14.315 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerImpl - [persistent://public/functions/metadata] [null] Creating producer on cnx [id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]
pulsar_1          | 10:11:14.316 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144][persistent://public/functions/metadata] Creating producer. producerId=1
pulsar_1          | 10:11:14.319 [ForkJoinPool.commonPool-worker-3] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] persistent://public/functions/metadata configured with schema false
pulsar_1          | 10:11:14.321 [ForkJoinPool.commonPool-worker-3] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Created new producer: Producer{topic=PersistentTopic{topic=persistent://public/functions/metadata}, client=/127.0.0.1:36144, producerName=standalone-0-1, producerId=1}
pulsar_1          | 10:11:14.323 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ProducerImpl - [persistent://public/functions/metadata] [standalone-0-1] Created producer on cnx [id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]
pulsar_1          | 10:11:14.328 [main] INFO  org.apache.pulsar.functions.utils.io.ConnectorUtils - Searching for connectors in /pulsar/./connectors
pulsar_1          | 10:11:15.935 [main] INFO  org.apache.pulsar.functions.utils.io.ConnectorUtils - Found connector ConnectorDefinition(name=oncode-influxdb-connector, description=Writes from a pulsar topic to database. Fork from PulsarIO InfluxDB connector, sourceClass=null, sinkClass=it.oncode.argo.pulsar.connectors.InfluxDBGenericRecordSink) from /pulsar/./connectors/pulsar-io-influxdb-oncode-1.0.nar
pulsar_1          | 10:11:16.025 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl - Starting Pulsar consumer status recorder with config: {
pulsar_1          |   "topicNames" : [ "persistent://public/functions/coordinate" ],
pulsar_1          |   "topicsPattern" : null,
pulsar_1          |   "subscriptionName" : "participants",
pulsar_1          |   "subscriptionType" : "Failover",
pulsar_1          |   "receiverQueueSize" : 1000,
pulsar_1          |   "acknowledgementsGroupTimeMicros" : 100000,
pulsar_1          |   "negativeAckRedeliveryDelayMicros" : 60000000,
pulsar_1          |   "maxTotalReceiverQueueSizeAcrossPartitions" : 50000,
pulsar_1          |   "consumerName" : null,
pulsar_1          |   "ackTimeoutMillis" : 0,
pulsar_1          |   "tickDurationMillis" : 1000,
pulsar_1          |   "priorityLevel" : 0,
pulsar_1          |   "cryptoFailureAction" : "FAIL",
pulsar_1          |   "properties" : {
pulsar_1          |     "id" : "c-standalone-fw-localhost-8080:localhost:8080"
pulsar_1          |   },
pulsar_1          |   "readCompacted" : false,
pulsar_1          |   "subscriptionInitialPosition" : "Latest",
pulsar_1          |   "patternAutoDiscoveryPeriod" : 1,
pulsar_1          |   "regexSubscriptionMode" : "PersistentOnly",
pulsar_1          |   "deadLetterPolicy" : null,
pulsar_1          |   "autoUpdatePartitions" : true,
pulsar_1          |   "replicateSubscriptionState" : false,
pulsar_1          |   "resetIncludeHead" : false,
pulsar_1          |   "keySharedPolicy" : null
pulsar_1          | }
pulsar_1          | 10:11:16.029 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl - Pulsar client config: {
pulsar_1          |   "serviceUrl" : "pulsar://localhost:6650",
pulsar_1          |   "authPluginClassName" : null,
pulsar_1          |   "authParams" : null,
pulsar_1          |   "operationTimeoutMs" : 30000,
pulsar_1          |   "statsIntervalSeconds" : 60,
pulsar_1          |   "numIoThreads" : 1,
pulsar_1          |   "numListenerThreads" : 1,
pulsar_1          |   "connectionsPerBroker" : 1,
pulsar_1          |   "useTcpNoDelay" : true,
pulsar_1          |   "useTls" : false,
pulsar_1          |   "tlsTrustCertsFilePath" : "",
pulsar_1          |   "tlsAllowInsecureConnection" : false,
pulsar_1          |   "tlsHostnameVerificationEnable" : false,
pulsar_1          |   "concurrentLookupRequest" : 5000,
pulsar_1          |   "maxLookupRequest" : 50000,
pulsar_1          |   "maxNumberOfRejectedRequestPerConnection" : 50,
pulsar_1          |   "keepAliveIntervalSeconds" : 30,
pulsar_1          |   "connectionTimeoutMs" : 10000,
pulsar_1          |   "requestTimeoutMs" : 60000,
pulsar_1          |   "initialBackoffIntervalNanos" : 100000000,
pulsar_1          |   "maxBackoffIntervalNanos" : 60000000000
pulsar_1          | }
pulsar_1          | 10:11:16.043 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/coordinate][participants] Subscribing to topic on cnx [id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]
pulsar_1          | 10:11:16.069 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Subscribing on topic persistent://public/functions/coordinate / participants
pulsar_1          | 10:11:16.142 [pulsar-io-50-1] INFO  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/functions/persistent/coordinate] Cursor participants recovered to position 7:-1
pulsar_1          | 10:11:16.161 [pulsar-io-50-1] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [127.0.0.1:3181] is not adhering to Placement Policy. quarantinedBookies: []
pulsar_1          | 10:11:16.173 [pulsar-ordered-OrderedExecutor-0-0-EventThread] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [127.0.0.1:3181] for ledger: 9
pulsar_1          | 10:11:16.203 [BookKeeperClientWorker-OrderedExecutor-1-0] INFO  com.scurrilous.circe.checksum.Crc32cIntChecksum - SSE4.2 CRC32C provider initialized
pulsar_1          | 10:11:16.240 [bookie-io-1-6] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.240 [bookie-io-1-3] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.240 [bookie-io-1-6] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x4b92ba2f, L:/127.0.0.1:3181 - R:/127.0.0.1:33834]
pulsar_1          | 10:11:16.241 [bookie-io-1-3] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x09d742ee, L:/127.0.0.1:3181 - R:/127.0.0.1:33830]
pulsar_1          | 10:11:16.247 [bookie-io-1-5] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.247 [bookie-io-1-7] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.247 [bookie-io-1-5] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x6a299cc8, L:/127.0.0.1:3181 - R:/127.0.0.1:33832]
pulsar_1          | 10:11:16.248 [bookie-io-1-7] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x0cca8e9b, L:/127.0.0.1:3181 - R:/127.0.0.1:33836]
pulsar_1          | 10:11:16.250 [bookie-io-1-4] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.250 [bookie-io-1-4] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x86fd95a1, L:/127.0.0.1:3181 - R:/127.0.0.1:33828]
pulsar_1          | 10:11:16.262 [bookkeeper-io-41-5] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0xebcbc76a, L:/127.0.0.1:33830 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.262 [bookkeeper-io-41-3] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x22a1aae9, L:/127.0.0.1:33828 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.264 [bookkeeper-io-41-5] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.265 [bookkeeper-io-41-5] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0xebcbc76a, L:/127.0.0.1:33830 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.264 [bookkeeper-io-41-3] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.266 [bookkeeper-io-41-3] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x22a1aae9, L:/127.0.0.1:33828 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.269 [bookkeeper-io-41-5] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0xc9a757e5, L:/127.0.0.1:33836 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.269 [bookkeeper-io-41-2] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0xf44a4f7b, L:/127.0.0.1:33834 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.270 [bookkeeper-io-41-2] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.270 [bookkeeper-io-41-5] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.270 [bookie-io-1-8] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.270 [bookkeeper-io-41-5] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0xc9a757e5, L:/127.0.0.1:33836 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.269 [bookkeeper-io-41-3] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x0eaacb65, L:/127.0.0.1:33832 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.271 [bookkeeper-io-41-3] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.270 [bookkeeper-io-41-2] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0xf44a4f7b, L:/127.0.0.1:33834 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.270 [bookie-io-1-8] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x2dde2f0f, L:/127.0.0.1:3181 - R:/127.0.0.1:33838]
pulsar_1          | 10:11:16.273 [bookkeeper-io-41-3] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x0eaacb65, L:/127.0.0.1:33832 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.276 [bookkeeper-io-41-2] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x1084b116, L:/127.0.0.1:33838 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.276 [bookkeeper-io-41-2] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.281 [bookie-io-1-1] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.281 [bookie-io-1-1] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x798d640d, L:/127.0.0.1:3181 - R:/127.0.0.1:33840]
pulsar_1          | 10:11:16.297 [bookie-io-1-1] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.297 [bookie-io-1-1] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x9dfc813d, L:/127.0.0.1:3181 - R:/127.0.0.1:33858]
pulsar_1          | 10:11:16.290 [bookkeeper-io-41-1] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0xd5456edb, L:/127.0.0.1:33842 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.298 [bookkeeper-io-41-1] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.298 [bookkeeper-io-41-1] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0xd5456edb, L:/127.0.0.1:33842 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.300 [bookkeeper-io-41-7] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x8dc8552e, L:/127.0.0.1:33848 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.300 [bookkeeper-io-41-4] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x339019b0, L:/127.0.0.1:33846 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.300 [bookkeeper-io-41-7] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.300 [bookkeeper-io-41-7] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x8dc8552e, L:/127.0.0.1:33848 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.300 [bookkeeper-io-41-4] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.300 [bookkeeper-io-41-4] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x339019b0, L:/127.0.0.1:33846 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.303 [bookkeeper-io-41-2] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x1084b116, L:/127.0.0.1:33838 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.307 [bookkeeper-io-41-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x30ae819a, L:/127.0.0.1:33840 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.307 [bookkeeper-io-41-6] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x95c37199, L:/127.0.0.1:33850 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.307 [bookkeeper-io-41-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.307 [bookkeeper-io-41-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x30ae819a, L:/127.0.0.1:33840 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.308 [bookkeeper-io-41-6] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.308 [bookkeeper-io-41-7] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x08fa0b4e, L:/127.0.0.1:33856 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.308 [bookie-io-1-6] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.308 [bookkeeper-io-41-7] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.308 [bookkeeper-io-41-1] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x8e821244, L:/127.0.0.1:33852 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.308 [bookkeeper-io-41-1] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.308 [bookie-io-1-6] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x42f6228f, L:/127.0.0.1:3181 - R:/127.0.0.1:33852]
pulsar_1          | 10:11:16.309 [bookkeeper-io-41-1] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x8e821244, L:/127.0.0.1:33852 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.308 [bookkeeper-io-41-6] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x95c37199, L:/127.0.0.1:33850 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.309 [bookkeeper-io-41-7] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x08fa0b4e, L:/127.0.0.1:33856 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.310 [bookie-io-1-7] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.310 [bookie-io-1-7] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0xc3d98c0b, L:/127.0.0.1:3181 - R:/127.0.0.1:33854]
pulsar_1          | 10:11:16.310 [bookie-io-1-5] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.310 [bookkeeper-io-41-4] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x8e37f0c2, L:/127.0.0.1:33854 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.310 [bookkeeper-io-41-4] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.311 [bookkeeper-io-41-4] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x8e37f0c2, L:/127.0.0.1:33854 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.310 [bookie-io-1-5] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x2511daf2, L:/127.0.0.1:3181 - R:/127.0.0.1:33850]
pulsar_1          | 10:11:16.312 [bookie-io-1-3] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.313 [bookie-io-1-8] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.313 [bookie-io-1-3] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x9481b1f4, L:/127.0.0.1:3181 - R:/127.0.0.1:33842]
pulsar_1          | 10:11:16.313 [bookie-io-1-8] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0xb16bf54d, L:/127.0.0.1:3181 - R:/127.0.0.1:33856]
pulsar_1          | 10:11:16.313 [bookie-io-1-4] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.313 [bookie-io-1-2] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.314 [bookie-io-1-4] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x95db9c4f, L:/127.0.0.1:3181 - R:/127.0.0.1:33848]
pulsar_1          | 10:11:16.314 [bookie-io-1-2] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x2f23ccfc, L:/127.0.0.1:3181 - R:/127.0.0.1:33846]
pulsar_1          | 10:11:16.321 [bookkeeper-io-41-6] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0xad804b6c, L:/127.0.0.1:33858 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.321 [bookkeeper-io-41-6] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.321 [bookkeeper-io-41-6] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0xad804b6c, L:/127.0.0.1:33858 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.321 [bookkeeper-io-41-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: [id: 0x80bd5e4a, L:/127.0.0.1:33860 - R:/127.0.0.1:3181]
pulsar_1          | 10:11:16.322 [bookkeeper-io-41-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 127.0.0.1:3181
pulsar_1          | 10:11:16.322 [bookkeeper-io-41-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x80bd5e4a, L:/127.0.0.1:33860 - R:/127.0.0.1:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
pulsar_1          | 10:11:16.328 [bookie-io-1-2] INFO  org.apache.bookkeeper.proto.AuthHandler - Authentication success on server side
pulsar_1          | 10:11:16.328 [bookie-io-1-2] INFO  org.apache.bookkeeper.proto.BookieRequestHandler - Channel connected  [id: 0x64d58e12, L:/127.0.0.1:3181 - R:/127.0.0.1:33860]
pulsar_1          | 10:11:16.388 [BookKeeperClientWorker-OrderedExecutor-1-0] INFO  org.apache.bookkeeper.mledger.impl.MetaStoreImplZookeeper - [public/functions/persistent/coordinate] [participants] Updating cursor info ledgerId=9 mark-delete=7:-1
pulsar_1          | 10:11:16.395 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/functions/persistent/coordinate] Updated cursor participants with ledger id 9 md-position=7:-1 rd-position=7:0
pulsar_1          | 10:11:16.396 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/functions/persistent/coordinate] Opened new cursor: ManagedCursorImpl{ledger=public/functions/persistent/coordinate, name=participants, ackPos=7:-1, readPos=7:0}
pulsar_1          | 10:11:16.427 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/coordinate] There are no replicated subscriptions on the topic
pulsar_1          | 10:11:16.428 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/coordinate][participants] Created new subscription for 0
pulsar_1          | 10:11:16.428 [bookkeeper-ml-workers-OrderedExecutor-2-0] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Created subscription on topic persistent://public/functions/coordinate / participants
pulsar_1          | 10:11:16.432 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/coordinate][participants] Subscribed to topic on localhost/127.0.0.1:6650 -- consumer: 0
pulsar_1          | 10:11:16.496 [pulsar-web-57-5] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "GET /admin/v2/persistent/public/functions/coordinate/stats HTTP/1.1" 200 882 "-" "Pulsar-Java-v2.5.0" 56
pulsar_1          | 10:11:16.572 [main] INFO  org.apache.pulsar.functions.runtime.process.ProcessRuntimeFactory - Java instance jar location is not defined, using the location defined in system environment : /pulsar/instances/java-instance.jar
pulsar_1          | 10:11:16.572 [main] INFO  org.apache.pulsar.functions.runtime.process.ProcessRuntimeFactory - Python instance file location is not defined using the location defined in system environment : /pulsar/instances/python-instance/python_instance_main.py
pulsar_1          | 10:11:16.573 [main] INFO  org.apache.pulsar.functions.runtime.process.ProcessRuntimeFactory - Extra dependencies location is not defined using the location defined in system environment : /pulsar/instances/deps
pulsar_1          | 10:11:16.578 [main] INFO  org.apache.pulsar.functions.worker.FunctionMetaDataManager - /** Initializing Function Metadata Manager **/
pulsar_1          | 10:11:16.596 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl - Starting Pulsar consumer status recorder with config: {
pulsar_1          |   "topicNames" : [ "persistent://public/functions/metadata" ],
pulsar_1          |   "topicsPattern" : null,
pulsar_1          |   "subscriptionName" : "reader-e0ceb49585",
pulsar_1          |   "subscriptionType" : "Exclusive",
pulsar_1          |   "receiverQueueSize" : 1000,
pulsar_1          |   "acknowledgementsGroupTimeMicros" : 100000,
pulsar_1          |   "negativeAckRedeliveryDelayMicros" : 60000000,
pulsar_1          |   "maxTotalReceiverQueueSizeAcrossPartitions" : 50000,
pulsar_1          |   "consumerName" : null,
pulsar_1          |   "ackTimeoutMillis" : 0,
pulsar_1          |   "tickDurationMillis" : 1000,
pulsar_1          |   "priorityLevel" : 0,
pulsar_1          |   "cryptoFailureAction" : "FAIL",
pulsar_1          |   "properties" : { },
pulsar_1          |   "readCompacted" : false,
pulsar_1          |   "subscriptionInitialPosition" : "Latest",
pulsar_1          |   "patternAutoDiscoveryPeriod" : 1,
pulsar_1          |   "regexSubscriptionMode" : "PersistentOnly",
pulsar_1          |   "deadLetterPolicy" : null,
pulsar_1          |   "autoUpdatePartitions" : true,
pulsar_1          |   "replicateSubscriptionState" : false,
pulsar_1          |   "resetIncludeHead" : false,
pulsar_1          |   "keySharedPolicy" : null
pulsar_1          | }
pulsar_1          | 10:11:16.597 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl - Pulsar client config: {
pulsar_1          |   "serviceUrl" : "pulsar://localhost:6650",
pulsar_1          |   "authPluginClassName" : null,
pulsar_1          |   "authParams" : null,
pulsar_1          |   "operationTimeoutMs" : 30000,
pulsar_1          |   "statsIntervalSeconds" : 60,
pulsar_1          |   "numIoThreads" : 1,
pulsar_1          |   "numListenerThreads" : 1,
pulsar_1          |   "connectionsPerBroker" : 1,
pulsar_1          |   "useTcpNoDelay" : true,
pulsar_1          |   "useTls" : false,
pulsar_1          |   "tlsTrustCertsFilePath" : "",
pulsar_1          |   "tlsAllowInsecureConnection" : false,
pulsar_1          |   "tlsHostnameVerificationEnable" : false,
pulsar_1          |   "concurrentLookupRequest" : 5000,
pulsar_1          |   "maxLookupRequest" : 50000,
pulsar_1          |   "maxNumberOfRejectedRequestPerConnection" : 50,
pulsar_1          |   "keepAliveIntervalSeconds" : 30,
pulsar_1          |   "connectionTimeoutMs" : 10000,
pulsar_1          |   "requestTimeoutMs" : 60000,
pulsar_1          |   "initialBackoffIntervalNanos" : 100000000,
pulsar_1          |   "maxBackoffIntervalNanos" : 60000000000
pulsar_1          | }
pulsar_1          | 10:11:16.601 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/metadata][reader-e0ceb49585] Subscribing to topic on cnx [id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]
pulsar_1          | 10:11:16.606 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Subscribing on topic persistent://public/functions/metadata / reader-e0ceb49585
pulsar_1          | 10:11:16.607 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/metadata][reader-e0ceb49585] Creating non-durable subscription at msg id -1:-1:-1:-1
pulsar_1          | 10:11:16.614 [pulsar-io-50-1] INFO  org.apache.bookkeeper.mledger.impl.NonDurableCursorImpl - [public/functions/persistent/metadata] Created non-durable cursor read-position=8:0 mark-delete-position=8:-1
pulsar_1          | 10:11:16.615 [pulsar-io-50-1] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/functions/persistent/metadata] Opened new cursor: NonDurableCursorImpl{ledger=public/functions/persistent/metadata, ackPos=8:-1, readPos=8:0}
pulsar_1          | 10:11:16.618 [pulsar-io-50-1] INFO  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/functions/persistent/metadata-reader-e0ceb49585] Rewind from 8:0 to 8:0
pulsar_1          | 10:11:16.620 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/metadata] There are no replicated subscriptions on the topic
pulsar_1          | 10:11:16.621 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/metadata][reader-e0ceb49585] Created new subscription for 1
pulsar_1          | 10:11:16.621 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Created subscription on topic persistent://public/functions/metadata / reader-e0ceb49585
pulsar_1          | 10:11:16.624 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/metadata][reader-e0ceb49585] Subscribed to topic on localhost/127.0.0.1:6650 -- consumer: 1
pulsar_1          | 10:11:16.632 [main] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/metadata][reader-e0ceb49585] Get topic last message Id
pulsar_1          | 10:11:16.655 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/metadata][reader-e0ceb49585] Successfully getLastMessageId 8:-1
pulsar_1          | 10:11:16.659 [main] INFO  org.apache.pulsar.functions.worker.FunctionRuntimeManager - /** Initializing Runtime Manager **/
pulsar_1          | 10:11:16.673 [pulsar-web-57-7] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "GET /admin/v2/persistent/public/functions/coordinate/stats HTTP/1.1" 200 882 "-" "Pulsar-Java-v2.5.0" 13
pulsar_1          | 10:11:16.682 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl - Starting Pulsar consumer status recorder with config: {
pulsar_1          |   "topicNames" : [ "persistent://public/functions/assignments" ],
pulsar_1          |   "topicsPattern" : null,
pulsar_1          |   "subscriptionName" : "reader-f5ae7c7a05",
pulsar_1          |   "subscriptionType" : "Exclusive",
pulsar_1          |   "receiverQueueSize" : 1000,
pulsar_1          |   "acknowledgementsGroupTimeMicros" : 100000,
pulsar_1          |   "negativeAckRedeliveryDelayMicros" : 60000000,
pulsar_1          |   "maxTotalReceiverQueueSizeAcrossPartitions" : 50000,
pulsar_1          |   "consumerName" : null,
pulsar_1          |   "ackTimeoutMillis" : 0,
pulsar_1          |   "tickDurationMillis" : 1000,
pulsar_1          |   "priorityLevel" : 0,
pulsar_1          |   "cryptoFailureAction" : "FAIL",
pulsar_1          |   "properties" : { },
pulsar_1          |   "readCompacted" : true,
pulsar_1          |   "subscriptionInitialPosition" : "Latest",
pulsar_1          |   "patternAutoDiscoveryPeriod" : 1,
pulsar_1          |   "regexSubscriptionMode" : "PersistentOnly",
pulsar_1          |   "deadLetterPolicy" : null,
pulsar_1          |   "autoUpdatePartitions" : true,
pulsar_1          |   "replicateSubscriptionState" : false,
pulsar_1          |   "resetIncludeHead" : false,
pulsar_1          |   "keySharedPolicy" : null
pulsar_1          | }
pulsar_1          | 10:11:16.684 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl - Pulsar client config: {
pulsar_1          |   "serviceUrl" : "pulsar://localhost:6650",
pulsar_1          |   "authPluginClassName" : null,
pulsar_1          |   "authParams" : null,
pulsar_1          |   "operationTimeoutMs" : 30000,
pulsar_1          |   "statsIntervalSeconds" : 60,
pulsar_1          |   "numIoThreads" : 1,
pulsar_1          |   "numListenerThreads" : 1,
pulsar_1          |   "connectionsPerBroker" : 1,
pulsar_1          |   "useTcpNoDelay" : true,
pulsar_1          |   "useTls" : false,
pulsar_1          |   "tlsTrustCertsFilePath" : "",
pulsar_1          |   "tlsAllowInsecureConnection" : false,
pulsar_1          |   "tlsHostnameVerificationEnable" : false,
pulsar_1          |   "concurrentLookupRequest" : 5000,
pulsar_1          |   "maxLookupRequest" : 50000,
pulsar_1          |   "maxNumberOfRejectedRequestPerConnection" : 50,
pulsar_1          |   "keepAliveIntervalSeconds" : 30,
pulsar_1          |   "connectionTimeoutMs" : 10000,
pulsar_1          |   "requestTimeoutMs" : 60000,
pulsar_1          |   "initialBackoffIntervalNanos" : 100000000,
pulsar_1          |   "maxBackoffIntervalNanos" : 60000000000
pulsar_1          | }
pulsar_1          | 10:11:16.688 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/assignments][reader-f5ae7c7a05] Subscribing to topic on cnx [id: 0x4f408ddf, L:/127.0.0.1:36144 - R:localhost/127.0.0.1:6650]
pulsar_1          | 10:11:16.689 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Subscribing on topic persistent://public/functions/assignments / reader-f5ae7c7a05
pulsar_1          | 10:11:16.690 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/assignments][reader-f5ae7c7a05] Creating non-durable subscription at msg id -1:-1:-1:-1
pulsar_1          | 10:11:16.691 [pulsar-io-50-1] INFO  org.apache.bookkeeper.mledger.impl.NonDurableCursorImpl - [public/functions/persistent/assignments] Created non-durable cursor read-position=6:0 mark-delete-position=6:-1
pulsar_1          | 10:11:16.691 [pulsar-io-50-1] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/functions/persistent/assignments] Opened new cursor: NonDurableCursorImpl{ledger=public/functions/persistent/assignments, ackPos=6:-1, readPos=6:0}
pulsar_1          | 10:11:16.692 [pulsar-io-50-1] INFO  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/functions/persistent/assignments-reader-f5ae7c7a05] Rewind from 6:0 to 6:0
pulsar_1          | 10:11:16.693 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/assignments] There are no replicated subscriptions on the topic
pulsar_1          | 10:11:16.693 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/functions/assignments][reader-f5ae7c7a05] Created new subscription for 2
pulsar_1          | 10:11:16.694 [pulsar-io-50-1] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:36144] Created subscription on topic persistent://public/functions/assignments / reader-f5ae7c7a05
pulsar_1          | 10:11:16.695 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/assignments][reader-f5ae7c7a05] Subscribed to topic on localhost/127.0.0.1:6650 -- consumer: 2
pulsar_1          | 10:11:16.700 [main] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/assignments][reader-f5ae7c7a05] Get topic last message Id
pulsar_1          | 10:11:16.702 [pulsar-client-io-76-1] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/functions/assignments][reader-f5ae7c7a05] Successfully getLastMessageId 6:-1
pulsar_1          | 10:11:16.703 [main] INFO  org.apache.pulsar.functions.worker.WorkerService - Start cluster services...
pulsar_1          | 10:11:16.707 [main] INFO  org.apache.pulsar.functions.worker.FunctionRuntimeManager - /** Starting Function Runtime Manager **/
pulsar_1          | 10:11:16.707 [main] INFO  org.apache.pulsar.functions.worker.FunctionRuntimeManager - Starting function assignment tailer...
pulsar_1          | 10:11:16.707 [main] INFO  org.apache.pulsar.broker.PulsarService - Function worker service started
pulsar_1          | 10:11:16.707 [main] INFO  org.apache.pulsar.broker.PulsarService - messaging service is ready
pulsar_1          | 10:11:16.726 [main] INFO  org.apache.pulsar.broker.PulsarService - messaging service is ready, bootstrap service port = 8080broker url= pulsar://localhost:6650, cluster=standalone, configs=org.apache.pulsar.broker.ServiceConfiguration@53e968c2[zookeeperServers=127.0.0.1:2181,globalZookeeperServers=<null>,configurationStoreServers=127.0.0.1:2181,brokerServicePort=Optional[6650],brokerServicePortTls=Optional.empty,webServicePort=Optional[8080],webServicePortTls=Optional.empty,bindAddress=0.0.0.0,advertisedAddress=localhost,numIOThreads=8,numHttpServerThreads=8,delayedDeliveryEnabled=true,delayedDeliveryTrackerFactoryClassName=org.apache.pulsar.broker.delayed.InMemoryDelayedDeliveryTrackerFactory,delayedDeliveryTickTimeMillis=1000,webSocketServiceEnabled=true,isRunningStandalone=true,clusterName=standalone,failureDomainsEnabled=false,zooKeeperSessionTimeoutMillis=30000,zooKeeperOperationTimeoutSeconds=30,brokerShutdownTimeoutMs=60000,backlogQuotaCheckEnabled=true,backlogQuotaCheckIntervalInSeconds=60,backlogQuotaDefaultLimitGB=10,backlogQuotaDefaultRetentionPolicy=producer_request_hold,ttlDurationDefaultInSeconds=0,brokerDeleteInactiveTopicsEnabled=true,brokerDeleteInactiveTopicsFrequencySeconds=60,messageExpiryCheckIntervalInMinutes=5,activeConsumerFailoverDelayTimeMillis=1000,subscriptionExpirationTimeMinutes=0,subscriptionRedeliveryTrackerEnabled=true,subscriptionExpiryCheckIntervalInMinutes=5,subscriptionKeySharedEnable=true,brokerDeduplicationEnabled=false,brokerDeduplicationMaxNumberOfProducers=10000,brokerDeduplicationEntriesInterval=1000,brokerDeduplicationProducerInactivityTimeoutMinutes=360,defaultNumberOfNamespaceBundles=4,clientLibraryVersionCheckEnabled=false,statusFilePath=/usr/local/apache/htdocs,maxUnackedMessagesPerConsumer=50000,maxUnackedMessagesPerSubscription=200000,maxUnackedMessagesPerBroker=0,maxUnackedMessagesPerSubscriptionOnBrokerBlocked=0.16,topicPublisherThrottlingTickTimeMillis=2,brokerPublisherThrottlingTickTimeMillis=50,brokerPublisherThrottlingMaxMessageRate=0,brokerPublisherThrottlingMaxByteRate=0,subscribeThrottlingRatePerConsumer=0,subscribeRatePeriodPerConsumerInSecond=30,dispatchThrottlingRatePerTopicInMsg=0,dispatchThrottlingRatePerTopicInByte=0,dispatchThrottlingRatePerSubscriptionInMsg=0,dispatchThrottlingRatePerSubscriptionInByte=0,dispatchThrottlingRatePerReplicatorInMsg=0,dispatchThrottlingRatePerReplicatorInByte=0,dispatchThrottlingRateRelativeToPublishRate=false,dispatchThrottlingOnNonBacklogConsumerEnabled=true,dispatcherMaxReadBatchSize=100,dispatcherMinReadBatchSize=1,dispatcherMaxRoundRobinBatchSize=20,maxConcurrentLookupRequest=50000,maxConcurrentTopicLoadRequest=5000,maxConcurrentNonPersistentMessagePerConnection=1000,numWorkerThreadsForNonPersistentTopic=8,enablePersistentTopics=true,enableNonPersistentTopics=true,enableRunBookieTogether=false,enableRunBookieAutoRecoveryTogether=false,maxProducersPerTopic=0,maxConsumersPerTopic=0,maxConsumersPerSubscription=0,maxMessageSize=5242880,enableReplicatedSubscriptions=true,replicatedSubscriptionsSnapshotFrequencyMillis=1000,replicatedSubscriptionsSnapshotTimeoutSeconds=30,replicatedSubscriptionsSnapshotMaxCachedPerSubscription=10,protocolHandlerDirectory=./protocols,messagingProtocols=[],tlsEnabled=false,tlsCertRefreshCheckDurationSec=300,tlsCertificateFilePath=<null>,tlsKeyFilePath=<null>,tlsTrustCertsFilePath=,tlsAllowInsecureConnection=false,tlsProtocols=[],tlsCiphers=[],tlsRequireTrustedClientCertOnConnect=false,authenticationEnabled=false,authenticationProviders=[],authorizationEnabled=false,authorizationProvider=org.apache.pulsar.broker.authorization.PulsarAuthorizationProvider,superUserRoles=[],proxyRoles=[],authenticateOriginalAuthData=false,authorizationAllowWildcardsMatching=false,brokerClientAuthenticationPlugin=org.apache.pulsar.client.impl.auth.AuthenticationDisabled,brokerClientAuthenticationParameters=,brokerClientTrustCertsFilePath=,anonymousUserRole=<null>,saslJaasClientAllowedIds=.*pulsar.*,saslJaasServerSectionName=PulsarBroker,kinitCommand=/usr/bin/kinit,bookkeeperClientAuthenticationPlugin=<null>,bookkeeperClientAuthenticationParametersName=<null>,bookkeeperClientAuthenticationParameters=<null>,bookkeeperClientTimeoutInSeconds=30,bookkeeperClientSpeculativeReadTimeoutInMillis=0,bookkeeperUseV2WireProtocol=true,bookkeeperClientHealthCheckEnabled=true,bookkeeperClientHealthCheckIntervalSeconds=60,bookkeeperClientHealthCheckErrorThresholdPerInterval=5,bookkeeperClientHealthCheckQuarantineTimeInSeconds=1800,bookkeeperClientRackawarePolicyEnabled=true,bookkeeperClientRegionawarePolicyEnabled=false,bookkeeperClientReorderReadSequenceEnabled=false,bookkeeperClientIsolationGroups=<null>,bookkeeperClientSecondaryIsolationGroups=<null>,bookkeeperEnableStickyReads=false,bookkeeperTLSProviderFactoryClass=org.apache.bookkeeper.tls.TLSContextFactory,bookkeeperTLSClientAuthentication=false,bookkeeperTLSKeyFileType=PEM,bookkeeperTLSTrustCertTypes=PEM,bookkeeperTLSKeyStorePasswordPath=<null>,bookkeeperTLSTrustStorePasswordPath=<null>,bookkeeperTLSKeyFilePath=<null>,bookkeeperTLSCertificateFilePath=<null>,bookkeeperTLSTrustCertsFilePath=<null>,bookkeeperDiskWeightBasedPlacementEnabled=false,managedLedgerDefaultEnsembleSize=1,managedLedgerDefaultWriteQuorum=1,managedLedgerDefaultAckQuorum=1,managedLedgerDigestType=CRC32C,managedLedgerMaxEnsembleSize=5,managedLedgerMaxWriteQuorum=5,managedLedgerMaxAckQuorum=5,managedLedgerCacheSizeMB=204,managedLedgerCacheCopyEntries=false,managedLedgerCacheEvictionWatermark=0.9,managedLedgerCacheEvictionFrequency=100.0,managedLedgerCacheEvictionTimeThresholdMillis=1000,managedLedgerCursorBackloggedThreshold=1000,managedLedgerDefaultMarkDeleteRateLimit=0.1,allowAutoTopicCreation=true,allowAutoTopicCreationType=non-partitioned,defaultNumPartitions=1,managedLedgerNumWorkerThreads=4,managedLedgerNumSchedulerThreads=4,managedLedgerMaxEntriesPerLedger=50000,managedLedgerMinLedgerRolloverTimeMinutes=10,managedLedgerMaxLedgerRolloverTimeMinutes=240,managedLedgerOffloadDeletionLagMs=14400000,managedLedgerOffloadAutoTriggerSizeThresholdBytes=-1,managedLedgerCursorMaxEntriesPerLedger=50000,managedLedgerCursorRolloverTimeInSeconds=14400,managedLedgerMaxUnackedRangesToPersist=10000,managedLedgerMaxUnackedRangesToPersistInZooKeeper=1000,managedLedgerUnackedRangesOpenCacheSetEnabled=true,autoSkipNonRecoverableData=false,managedLedgerMetadataOperationsTimeoutSeconds=60,managedLedgerReadEntryTimeoutSeconds=0,managedLedgerAddEntryTimeoutSeconds=0,loadBalancerEnabled=false,loadBalancerPlacementStrategy=leastLoadedServer,loadBalancerReportUpdateThresholdPercentage=10,loadBalancerReportUpdateMaxIntervalMinutes=15,loadBalancerHostUsageCheckIntervalMinutes=1,loadBalancerSheddingEnabled=true,loadBalancerSheddingIntervalMinutes=1,loadBalancerSheddingGracePeriodMinutes=30,loadBalancerBrokerUnderloadedThresholdPercentage=50,loadBalancerBrokerMaxTopics=50000,loadBalancerBrokerOverloadedThresholdPercentage=85,loadBalancerResourceQuotaUpdateIntervalMinutes=15,loadBalancerBrokerComfortLoadLevelPercentage=65,loadBalancerAutoBundleSplitEnabled=true,loadBalancerAutoUnloadSplitBundlesEnabled=true,loadBalancerNamespaceBundleMaxTopics=1000,loadBalancerNamespaceBundleMaxSessions=1000,loadBalancerNamespaceBundleMaxMsgRate=30000,loadBalancerNamespaceBundleMaxBandwidthMbytes=100,loadBalancerNamespaceMaximumBundles=128,loadManagerClassName=org.apache.pulsar.broker.loadbalance.NoopLoadManager,loadBalancerOverrideBrokerNicSpeedGbps=<null>,replicationMetricsEnabled=true,replicationConnectionsPerBroker=16,replicatorPrefix=pulsar.repl,replicationProducerQueueSize=1000,replicationTlsEnabled=false,brokerClientTlsEnabled=false,defaultRetentionTimeInMinutes=0,defaultRetentionSizeInMB=0,keepAliveIntervalSeconds=30,brokerServicePurgeInactiveFrequencyInSeconds=60,bootstrapNamespaces=[],properties={loadBalancerNamespaceMaximumBundles=128, managedLedgerDigestType=CRC32C, bookkeeperTLSKeyFileType=PEM, dbStorage_readAheadCacheMaxSizeMb=, dispatchThrottlingRatePerTopicInByte=0, bookkeeperClientReorderReadSequenceEnabled=false, bookkeeperTLSKeyFilePath=, allowAutoTopicCreation=true, enablePersistentTopics=true, brokerShutdownTimeoutMs=60000, webSocketNumIoThreads=8, maxConsumersPerTopic=0, managedLedgerNumSchedulerThreads=4, brokerPublisherThrottlingMaxMessageRate=0, dbStorage_rocksDB_numLevels=-1, exposePublisherStats=true, managedLedgerAddEntryTimeoutSeconds=0, bookkeeperClientRackawarePolicyEnabled=true, loadBalancerResourceQuotaUpdateIntervalMinutes=15, zooKeeperSessionTimeoutMillis=30000, backlogQuotaCheckIntervalInSeconds=60, dispatchThrottlingOnNonBacklogConsumerEnabled=true, bookkeeperTLSKeyStorePasswordPath=, managedLedgerMinLedgerRolloverTimeMinutes=10, enableNonPersistentTopics=true, bookkeeperClientSpeculativeReadTimeoutInMillis=0, dispatchThrottlingRateRelativeToPublishRate=false, brokerDeduplicationProducerInactivityTimeoutMinutes=360, loadBalancerSheddingIntervalMinutes=1, dbStorage_rocksDB_blockCacheSize=, authenticationProviders=, bookkeeperTLSProviderFactoryClass=org.apache.bookkeeper.tls.TLSContextFactory, managedLedgerMetadataOperationsTimeoutSeconds=60, managedLedgerDefaultAckQuorum=1, managedLedgerCacheEvictionFrequency=100.0, defaultNumPartitions=1, allowAutoTopicCreationType=non-partitioned, authenticateOriginalAuthData=false, loadBalancerNamespaceBundleMaxTopics=1000, managedLedgerCacheEvictionWatermark=0.9, brokerPublisherThrPottlingTickTimeMillis=50, bookkeeperClientAuthenticationPlugin=, managedLedgerMaxLedgerRolloverTimeMinutes=240, managedLedgerMaxEntriesPerLedger=50000, brokerDeduplicationMaxNumberOfProducers=10000, configurationStoreServers=, bookkeeperClientHealthCheckEnabled=true, defaultRetentionTimeInMinutes=0, managedLedgerReadEntryTimeoutSeconds=0, activeConsumerFailoverDelayTimeMillis=1000, managedLedgerCacheEvictionTimeThresholdMillis=1000, webSocketSessionIdleTimeoutMillis=300000, brokerDeleteInactiveTopicsFrequencySeconds=60, keepAliveIntervalSeconds=30, advertisedAddress=, managedLedgerCacheCopyEntries=false, athenzDomainNames=, ledgerStorageClass=org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage, replicationMetricsEnabled=true, diskUsageWarnThreshold=0.99, loadBalancerReportUpdateThresholdPercentage=10, failureDomainsEnabled=false, managedLedgerCursorBackloggedThreshold=1000, loadBalancerReportUpdateMaxIntervalMinutes=15, loadBalancerNamespaceBundleMaxBandwidthMbytes=100, bookkeeperClientHealthCheckIntervalSeconds=60, managedLedgerCursorRolloverTimeInSeconds=14400, loadBalancerEnabled=false, bookkeeperClientHealthCheckQuarantineTimeInSeconds=1800, diskUsageThreshold=0.99, bookkeeperClientRegionawarePolicyEnabled=false, gcWaitTime=300000, allowLoopback=true, brokerServicePurgeInactiveFrequencyInSeconds=60, autoSkipNonRecoverableData=false, numHttpServerThreads=, brokerClientAuthenticationPlugin=, bookkeeperTLSCertificateFilePath=, managedLedgerNumWorkerThreads=4, managedLedgerUnackedRangesOpenCacheSetEnabled=true, superUserRoles=, replicationProducerQueueSize=1000, managedLedgerDefaultMarkDeleteRateLimit=0.1, dbStorage_writeCacheMaxSizeMb=, bookkeeperTLSTrustCertTypes=PEM, dispatchThrottlingRatePerTopicInMsg=0, proxyRoles=, brokerPublisherThrottlingMaxByteRate=0, maxConcurrentTopicLoadRequest=5000, maxConsumersPerSubscription=0, bookkeeperClientSecondaryIsolationGroups=, bookkeeperClientTimeoutInSeconds=30, managedLedgerDefaultEnsembleSize=1, webSocketConnectionsPerBroker=8, statusFilePath=/usr/local/apache/htdocs, maxUnackedMessagesPerConsumer=50000, dbStorage_rocksDB_writeBufferSizeMB=4, loadBalancerNamespaceBundleMaxSessions=1000, maxConcurrentNonPersistentMessagePerConnection=1000, loadBalancerAutoBundleSplitEnabled=true, loadBalancerAutoUnloadSplitBundlesEnabled=true, defaultNumberOfNamespaceBundles=4, defaultRetentionSizeInMB=0, brokerDeleteInactiveTopicsEnabled=true, maxUnackedMessagesPerSubscription=200000, flushInterval=60000, transactionMetadataStoreProviderClassName=org.apache.pulsar.transaction.coordinator.impl.InMemTransactionMetadataStoreProvider, bookkeeperTLSClientAuthentication=false, brokerDeduplicationEntriesInterval=1000, backlogQuotaDefaultLimitGB=10, bindAddress=0.0.0.0, topicPublisherThrottlingTickTimeMillis=2, globalZookeeperServers=, maxProducersPerTopic=0, maxConcurrentLookupRequest=50000, zookeeperServers=, bookkeeperClientIsolationGroups=, dbStorage_rocksDB_bloomFilterBitsPerKey=10, authorizationAllowWildcardsMatching=false, journalMaxGroupWaitMSec=1, loadBalancerHostUsageCheckIntervalMinutes=1, managedLedgerMaxUnackedRangesToPersistInZooKeeper=1000, authenticationEnabled=false, messageExpiryCheckIntervalInMinutes=5, bookkeeperTLSTrustCertsFilePath=, brokerDeduplicationEnabled=false, loadBalancerBrokerMaxTopics=50000, managedLedgerCacheSizeMB=, brokerServicePort=6650, clientLibraryVersionCheckEnabled=false, clusterName=standalone, dbStorage_readAheadCacheBatchSize=1000, maxUnackedMessagesPerBroker=0, webSocketServiceEnabled=true, managedLedgerMaxUnackedRangesToPersist=10000, ttlDurationDefaultInSeconds=0, tokenAuthClaim=, subscriptionExpiryCheckIntervalInMinutes=5, managedLedgerCursorMaxEntriesPerLedger=50000, zooKeeperOperationTimeoutSeconds=30, bookkeeperClientMinAvailableBookiesInIsolationGroups=, subscriptionExpirationTimeMinutes=0, loadBalancerNamespaceBundleMaxMsgRate=30000, dbStorage_rocksDB_maxSizeInLevel1MB=256, dbStorage_rocksDB_numFilesInLevel0=4, bookkeeperDiskWeightBasedPlacementEnabled=false, authorizationEnabled=false, managedLedgerDefaultWriteQuorum=1, webServicePort=8080, dbStorage_rocksDB_sstSizeInMB=4, bookkeeperClientHealthCheckErrorThresholdPerInterval=5, journalSyncData=false, numWorkerThreadsForNonPersistentTopic=8, bookkeeperClientAuthenticationParametersName=, subscriptionRedeliveryTrackerEnabled=true, backlogQuotaCheckEnabled=true, anonymousUserRole=, exposeTopicLevelMetricsInPrometheus=true, numIOThreads=, replicationConnectionsPerBroker=16, authorizationProvider=org.apache.pulsar.broker.authorization.PulsarAuthorizationProvider, loadManagerClassName=org.apache.pulsar.broker.loadbalance.NoopLoadManager, brokerClientAuthenticationParameters=, dbStorage_rocksDB_blockSize=4096, bookkeeperClientAuthenticationParameters=, bookkeeperTLSTrustStorePasswordPath=, loadBalancerSheddingGracePeriodMinutes=30, maxUnackedMessagesPerSubscriptionOnBrokerBlocked=0.16},preferLaterVersions=false,brokerServiceCompactionMonitorIntervalInSeconds=60,isSchemaValidationEnforced=false,schemaRegistryStorageClassName=org.apache.pulsar.broker.service.schema.BookkeeperSchemaStorageFactory,schemaRegistryCompatibilityCheckers=[org.apache.pulsar.broker.service.schema.JsonSchemaCompatibilityCheck, org.apache.pulsar.broker.service.schema.AvroSchemaCompatibilityCheck],webSocketNumIoThreads=8,webSocketConnectionsPerBroker=8,webSocketSessionIdleTimeoutMillis=300000,exposeTopicLevelMetricsInPrometheus=true,exposeConsumerLevelMetricsInPrometheus=false,jvmGCMetricsLoggerClassName=<null>,functionsWorkerEnabled=false,exposePublisherStats=true,statsUpdateFrequencyInSecs=60,statsUpdateInitialDelayInSecs=60,offloadersDirectory=./offloaders,managedLedgerOffloadDriver=<null>,managedLedgerOffloadMaxThreads=2,transactionCoordinatorEnabled=true,transactionMetadataStoreProviderClassName=org.apache.pulsar.transaction.coordinator.impl.InMemTransactionMetadataStoreProvider]
pulsar_1          | 10:11:16.732 [main] INFO  org.apache.pulsar.broker.TransactionMetadataStoreService - Added new transaction meta store TransactionCoordinatorID(id=0)
pulsar_1          | 10:11:16.840 [pulsar-web-57-8] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "GET /admin/v2/clusters HTTP/1.1" 200 14 "-" "Pulsar-Java-v2.5.0" 18
pulsar_1          | 10:11:16.886 [pulsar-web-57-3] INFO  org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Updated cluster standalone
pulsar_1          | 10:11:16.888 [pulsar-web-57-3] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "POST /admin/v2/clusters/standalone HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 36
pulsar_1          | 10:11:16.897 [pulsar-web-57-1] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "GET /admin/v2/clusters HTTP/1.1" 200 14 "-" "Pulsar-Java-v2.5.0" 5
pulsar_1          | 10:11:16.921 [pulsar-web-57-4] INFO  org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Created cluster global
pulsar_1          | 10:11:16.921 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a56000a local:/127.0.0.1:55176 remoteserver:localhost/127.0.0.1:2181 lastZxid:150 xid:26 sent:26 recv:27 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/admin/clusters
pulsar_1          | 10:11:16.922 [pulsar-web-57-4] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "PUT /admin/v2/clusters/global HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 16
pulsar_1          | 10:11:16.926 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - reloadCache called in zookeeperChildrenCache for path /admin/clusters
pulsar_1          | 10:11:16.945 [pulsar-web-57-5] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "GET /admin/v2/tenants HTTP/1.1" 200 10 "-" "Pulsar-Java-v2.5.0" 11
pulsar_1          | 10:11:16.967 [pulsar-web-57-7] INFO  org.apache.pulsar.broker.admin.impl.TenantsBase - [null] Created tenant sample
pulsar_1          | 10:11:16.969 [pulsar-web-57-7] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "PUT /admin/v2/tenants/sample HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 16
pulsar_1          | 10:11:16.987 [pulsar-web-57-6] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "GET /admin/v2/namespaces/sample HTTP/1.1" 200 2 "-" "Pulsar-Java-v2.5.0" 15
pulsar_1          | 10:11:17.023 [pulsar-web-57-8] INFO  org.apache.pulsar.broker.web.PulsarWebResource - Successfully validated clusters on tenant [sample]
pulsar_1          | 10:11:17.048 [pulsar-web-57-8] INFO  org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Created namespace sample/standalone/ns1
pulsar_1          | 10:11:17.051 [pulsar-web-57-8] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:16 +0000] "PUT /admin/namespaces/sample/standalone/ns1 HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 58
pulsar_1          | 10:11:17.061 [pulsar-web-57-3] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:17 +0000] "GET /admin/v2/tenants HTTP/1.1" 200 19 "-" "Pulsar-Java-v2.5.0" 6
pulsar_1          | 10:11:17.075 [pulsar-web-57-1] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:17 +0000] "GET /admin/v2/namespaces/public HTTP/1.1" 200 20 "-" "Pulsar-Java-v2.5.0" 9
pulsar_1          | 10:11:17.083 [pulsar-web-57-4] INFO  org.apache.pulsar.broker.web.PulsarWebResource - Successfully validated clusters on tenant [public]
pulsar_1          | 10:11:17.110 [pulsar-web-57-4] INFO  org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Created namespace public/default
pulsar_1          | 10:11:17.112 [pulsar-web-57-4] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:17 +0000] "PUT /admin/v2/namespaces/public/default HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 33
pulsar_1          | 10:11:17.131 [pulsar-web-57-5] INFO  org.apache.pulsar.broker.web.PulsarWebResource - Successfully validated clusters on tenant [public]
pulsar_1          | 10:11:17.158 [pulsar-web-57-5] INFO  org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the replication clusters on namespace public/default
pulsar_1          | 10:11:17.156 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO  org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000 sessionid:0x10007e92a56000a local:/127.0.0.1:55176 remoteserver:localhost/127.0.0.1:2181 lastZxid:156 xid:42 sent:42 recv:44 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/public/default
pulsar_1          | 10:11:17.160 [pulsar-web-57-5] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:17 +0000] "POST /admin/v2/namespaces/public/default/replication HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.5.0" 44
pulsar_1          | 10:11:17.166 [ForkJoinPool.commonPool-worker-3] INFO  org.apache.pulsar.broker.service.BrokerService - /admin/policies/public/default updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[standalone], bundles=BundlesData{numBundles=4, boundaries=[0x00000000, 0x40000000, 0x80000000, 0xc0000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, antiAffinityGroup=null, message_ttl_in_seconds=0, retention_policies=null, deleted=false, encryption_required=false, subscription_auth_mode=None, max_producers_per_topic=0, max_consumers_per_topic=0, max_consumers_per_subscription=0, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true}
pulsar_1          | 10:11:17.428 [pulsar-io-50-2] INFO  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/functions/persistent/coordinate-participants] Rewind from 7:0 to 7:0
pulsar_1          | 10:11:46.686 [pulsar-web-57-6] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:11:46 +0000] "GET /admin/v2/persistent/public/functions/coordinate/stats HTTP/1.1" 200 882 "-" "Pulsar-Java-v2.5.0" 5
pulsar_1          | 10:12:00.416 [SyncThread-7-1] INFO  org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file because current active log channel has not initialized yet
pulsar_1          | 10:12:00.421 [SyncThread-7-1] INFO  org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file data/standalone/bookkeeper0/current/0.log for logId 0.
pulsar_1          | 10:12:00.433 [pool-5-thread-1] INFO  org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file data/standalone/bookkeeper0/current/1.log for logId 1.
pulsar_1          | 10:12:16.649 [pulsar-web-57-4] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [03/Feb/2020:10:12:16 +0000] "GET /admin/v2/persistent/public/functions/coordinate/stats HTTP/1.1" 200 882 "-" "Pulsar-Java-v2.5.0" 5

I do not see any strange log but the cpu is always between the 30% and 40% without doing nothing. Is this something that happen only to me or are you able to reproduce?

Screenshot 2020-02-03 at 11 13 57
codelipenghui commented 4 years ago

This issue is related to #6414 since the broker also has an internal pulsar client. And in the standalone docker. The thread named "DLM-/stream/storage-OrderedScheduler-*" also with high CPU load.

image

"DLM-/stream/storage-OrderedScheduler-2-0" #98 prio=5 os_prio=0 tid=0x00007f76ada0e000 nid=0x127 runnable [0x00007f756fa9f000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000e51c93d0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)
"DLM-/stream/storage-OrderedScheduler-1-0" #97 prio=5 os_prio=0 tid=0x00007f76ada0d800 nid=0x126 runnable [0x00007f756fca1000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000e51c9648> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)
"DLM-/stream/storage-OrderedScheduler-0-0" #96 prio=5 os_prio=0 tid=0x00007f76ad4da000 nid=0x125 waiting on condition [0x00007f756fba0000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000e51c9860> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)
jiazhai commented 4 years ago

would like to close this issue. since it is a dup to 6414