search

apache / incubator-heron

Apache Heron (Incubating) is a realtime, distributed, fault-tolerant stream processing engine from Twitter
https://heron.apache.org/
Apache License 2.0
3.65k stars 597 forks source link

Launch PEX on Kubernetes fails #2919

Open cristobalcl opened 6 years ago

cristobalcl commented 6 years ago

I recently get this error each time I try to launch a topology to Kubernetes:

[2018-06-14 12:17:11 +0000] [DEBUG]: Starting new HTTP connection (1): localhost
[2018-06-14 12:17:55 +0000] [DEBUG]: http://localhost:8001 "POST /api/v1/proxy/namespaces/heron/services/heron-apiserver:9000/api/v1/topologies HTTP/1.1" 500 137
[2018-06-14 12:17:55 +0000] [ERROR]: Encountered exceptions on uploading the package 'xxxxxxxxxx.tar.gz'
[2018-06-14 12:17:55 +0000] [ERROR]: Failed to launch topology 'xxxxxxxxxx' 
[2018-06-14 12:17:55 +0000] [DEBUG]: Elapsed time: 44.295s.

This is running locally through a kubectl proxy, but I get the same error when I try from another POD in the same Kubernetes cluster pointing directly to the Heron API.

$ heron version
heron.build.git.revision : ddbb98bbf173fb082c6fd575caaa35205abe34df
heron.build.git.status : Clean
heron.build.host : ci-server-01
heron.build.time : Sat Mar 31 09:25:55 UTC 2018
heron.build.timestamp : 1522488355000
heron.build.user : release-agent1
heron.build.version : 0.17.8

This is the log from the heron-apiserver instance in the Heron POD:

heron-apiserver.log

I deploy Heron in Kubernetes (AWS) using Helm:

helm repo add heron-charts https://storage.googleapis.com/heron-charts
helm install heron-charts/heron --name heron --namespace heron

Of course, the topologies work OK in my local Heron.

It fails both with big (50 mb) and small (1.5 mb) PEX [Edited: with small PEXs the submit works but then appears another error]. In the past, I have got it worked trying repeatedly 10-20 times (in a Jenkins pipeline in the same cluster), but now it does not work anymore.

Edited: I can reproduce the error locally using Minikube.

Edited: scripts and code to reproduce the bug: https://github.com/cristobalcl/heron-issue-2919

Code0x58 commented 6 years ago

That log file is a couple of hours off the event you reported, and there are a few things that look suspicious to me (inc.[SEVERE] log messages). I'd look around lines which have the topologies in them if they look like they are serving the request.

cristobalcl commented 6 years ago

The lapse in the timestamps of the logs is because I was using computers in different time zones (deploying from my local computer into the cluster). I was watching the logs in real-time and I can say those logs are related to the issue. Anyway, it's possible that I was missing another important logs of other system that is needed to debug, if so I could replicate the problem.

In the other hand, I'm looking for an alternative way of deploying the PEX. I was trying to use the S3 uploader, but I can not understand how it works. I could open another issue for this, if you wish, but anyway...

Firstly, I have no idea how to configure the CLI. I have tried multiple combinations of parameters and configuration files, but the only thing I have get to work is modifying the uploader.yaml for the local config and running heron submit local …. And doing so the PEX is uploaded to S3 succesfully... But nothing more. Ok, the PEX is in the S3 bucket, now what? How does Heron download the PEX and submit this and run the topology?

Sorry if this is obvious, but I have seen no example anywhere about using the S3 uploader. And again, I don't understand how to use the Heron CLI with the cluster/[role]/[env], configurations files, --config-path and --config-property arguments,...

What I usually do with Kubernetes is:

heron config heron set service_url http://…/heron-apiserver:9000
heron submit heron "dist/xxxxxxxxxxx.pex" --verbose - […]

And this worked like a charm. But I have no idea which uploader.yaml I need to edit, or how to set up this to use the S3 uploader. And, again, I don't know how the server will launch the topology, or if I need to config anything in the Helm chart of Heron.

Thank you very much!

Code0x58 commented 6 years ago

Ah, I was thrown off by the +0000 which made it look like it was all in UTC†, so thought you got logs for another instance of the event. I think this is the relevent section of the log which is littered with [WARNING] and [SEVERE]:

[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Starting Curator client connecting to: heron-zookeeper:2181  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.curator.framework.imps.CuratorFrameworkImpl: Starting  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=heron-zookeeper:2181 sessionTimeout=30000 watcher=org.apache.curator.ConnectionState@18db52f6  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.zookeeper.ClientCnxn: Opening socket connection to server heron-zookeeper.heron.svc.cluster.local/100.71.255.123:2181. Will not attempt to authenticate using SASL (unknown error)  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.zookeeper.ClientCnxn: Socket connection established to heron-zookeeper.heron.svc.cluster.local/100.71.255.123:2181, initiating session  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.zookeeper.ClientCnxn: Session establishment complete on server heron-zookeeper.heron.svc.cluster.local/100.71.255.123:2181, sessionid = 0x163fdb642fc0014, negotiated timeout = 30000  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.curator.framework.state.ConnectionStateManager: State change: CONNECTED  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Directory tree initialized.  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.uploader.dlog.DLUploader: Initializing distributedlog namespace for uploading topologies : distributedlog://heron-zookeeper:2181/distributedlog  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.api.namespace.NamespaceBuilder: No feature provider is set. All features are disabled now.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.impl.BKNamespaceDriver: Created shared zooKeeper client builder dlzk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared: zkServers = heron-zookeeper:2181, numRetries = 3, sessionTimeout = 30000, retryBackoff = 5000, maxRetryBackoff = 30000, zkAclId = null.  
[2018-06-14 10:17:44 +0000] [WARNING] org.apache.distributedlog.impl.BKNamespaceDriver: Could not use Netty Epoll event loop for bookie server: 
java.lang.NoClassDefFoundError: Could not initialize class dlshade.io.netty.channel.epoll.EpollEventLoopGroup
    at org.apache.distributedlog.impl.BKNamespaceDriver.getDefaultEventLoopGroup(BKNamespaceDriver.java:259)
    at org.apache.distributedlog.impl.BKNamespaceDriver.initializeBookKeeperClients(BKNamespaceDriver.java:270)
    at org.apache.distributedlog.impl.BKNamespaceDriver.initialize(BKNamespaceDriver.java:208)
    at org.apache.distributedlog.api.namespace.NamespaceBuilder.build(NamespaceBuilder.java:238)
    at com.twitter.heron.uploader.dlog.DLUploader.initializeNamespace(DLUploader.java:137)
    at com.twitter.heron.uploader.dlog.DLUploader.initialize(DLUploader.java:94)
    at com.twitter.heron.scheduler.SubmitterMain.submitTopology(SubmitterMain.java:420)
    at com.twitter.heron.apiserver.actions.SubmitTopologyAction.execute(SubmitTopologyAction.java:33)
    at com.twitter.heron.apiserver.resources.TopologyResource.submit(TopologyResource.java:223)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
    at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:841)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
    at org.eclipse.jetty.server.Server.handle(Server.java:564)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:317)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
    at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128)
    at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591)
    at java.lang.Thread.run(Thread.java:748)

[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.impl.BKNamespaceDriver: Created shared client builder bk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared : zkServers = heron-zookeeper:2181, ledgersPath = /bookkeeper/ledgers, numIOThreads = 4  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.impl.metadata.BKDLConfig: Propagate BKDLConfig to DLConfig : encodeRegionID = false, firstLogSegmentSequenceNumber = 1, createStreamIfNotExists = true, isFederated = false.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.impl.BKNamespaceDriver: Initialized BK namespace driver: clientId = heron-uploader, regionId = 0, federated = false.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.logsegment.LogSegmentMetadataCache: Log segment cache is enabled = true  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Checking existence of path: /heron/topologies/xxxxxxxxxx  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking: Initalizing ResourceCompliantRRPacking. CPU default: 1.000000, RAM default: ByteAmount{1 GB (1073741824 bytes)}, DISK default: ByteAmount{1 GB (1073741824 bytes)}.  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking: ResourceCompliantRRPacking newPackingPlanBuilder. CPU max: 4.000000, RAMmaxMax: ByteAmount{4 GB (4724464026 bytes)}, DISK max: ByteAmount{4 GB (4724464026 bytes)}, Padding percentage: 10.  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking: ResourceCompliantRRPacking newPackingPlanBuilder. CPU max: 4.000000, RAMmaxMax: ByteAmount{4 GB (4724464026 bytes)}, DISK max: ByteAmount{4 GB (4724464026 bytes)}, Padding percentage: 10.  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking: ResourceCompliantRRPacking newPackingPlanBuilder. CPU max: 4.000000, RAMmaxMax: ByteAmount{4 GB (4724464026 bytes)}, DISK max: ByteAmount{4 GB (4724464026 bytes)}, Padding percentage: 10.  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking: ResourceCompliantRRPacking newPackingPlanBuilder. CPU max: 4.000000, RAMmaxMax: ByteAmount{4 GB (4724464026 bytes)}, DISK max: ByteAmount{4 GB (4724464026 bytes)}, Padding percentage: 10.  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking: ResourceCompliantRRPacking newPackingPlanBuilder. CPU max: 4.000000, RAMmaxMax: ByteAmount{4 GB (4724464026 bytes)}, DISK max: ByteAmount{4 GB (4724464026 bytes)}, Padding percentage: 10.  
[2018-06-14 10:17:44 +0000] [WARNING] com.twitter.heron.scheduler.SubmitterMain: The packing plan (generated by com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking) calls for a different number of containers (5) than what was explicitly set in the topology configs (1). Overriding the configs to specify 5 containers. When using com.twitter.heron.packing.roundrobin.ResourceCompliantRRPacking do not explicitly call config.setNumStmgrs(..) or config.setNumWorkers(..).  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=heron-zookeeper:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@19094b97  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxnSocket: jute.maxbuffer value is 4194304 Bytes  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: Opening socket connection to server heron-zookeeper/100.71.255.123:2181. Will not attempt to authenticate using SASL (unknown error)  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: Socket connection established, initiating session, client: /100.105.146.3:49994, server: heron-zookeeper/100.71.255.123:2181  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: Session establishment complete on server heron-zookeeper/100.71.255.123:2181, sessionid = 0x163fdb642fc0015, negotiated timeout = 30000  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase: ZooKeeper client is connected now.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.zk.LimitedPermitManager: EnablePermits = true, Epoch = 1.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.zk.LimitedPermitManager: EnablePermits = true, Epoch = 1.  
[2018-06-14 10:17:44 +0000] [INFO] com.twitter.heron.uploader.dlog.DLUploader: Uploading topology package at '/tmp/xxxxxxxxxx5459940652240403157/topology.tar.gz' to target DL at 'distributedlog://heron-zookeeper:2181/distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz'  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator for /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved version from -1 to 0.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.BKLogReadHandler: Initiating Recovery For xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default> : []  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.BKLogReadHandler: Initiating Recovery For xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default> : []  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved to phase ALLOCATING : version = 0.  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=heron-zookeeper:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@404da4b  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxnSocket: jute.maxbuffer value is 4194304 Bytes  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: Opening socket connection to server heron-zookeeper/100.71.255.123:2181. Will not attempt to authenticate using SASL (unknown error)  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: Socket connection established, initiating session, client: /100.105.146.3:49996, server: heron-zookeeper/100.71.255.123:2181  
[2018-06-14 10:17:44 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: Session establishment complete on server heron-zookeeper/100.71.255.123:2181, sessionid = 0x163fdb642fc0016, negotiated timeout = 30000  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase: ZooKeeper client is connected now.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Initialize rackaware ensemble placement policy @ <Bookie:100.105.146.3:0> @ /heron/tools : org.apache.distributedlog.net.DNSResolverForRacks.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Not weighted  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.client.BookKeeper: Weighted ledger placement is not enabled  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.net.NetworkTopologyImpl: Adding a new node: /default-region/default-rack/100.126.73.199:3181  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Initialize rackaware ensemble placement policy @ <Bookie:100.105.146.3:0> @ /heron/tools : org.apache.distributedlog.net.DNSResolverForRacks.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Not weighted  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.BookKeeperClient: BookKeeper Client created bk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared with its own ZK Client : ledgersPath = /bookkeeper/ledgers, numRetries = 3, sessionTimeout = 30000, backoff = 5000, maxBackoff = 30000, dnsResolver =   
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.net.NetworkTopologyImpl: Adding a new node: /default-region/default-rack/100.126.73.199:3181  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator for /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved version from 0 to 1.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved to phase ALLOCATED : version = 1.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved to phase HANDING_OVER : version = 1.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.BKLogReadHandler: No max ledger sequence number found while creating log segment 1 for xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved to phase HANDED_OVER : version = 1.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator for /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved version from 1 to 2.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved to phase ALLOCATING : version = 2.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.logsegment.PerStreamLogSegmentCache: xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz added log segment (inprogress_000000000000000001 : [LogSegmentId:4, firstTxId:131072, 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.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.BKLogReadHandler: Deleting log segments older than -7729412157735137 for xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default> : []  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator for /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved version from 2 to 3.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.distributedlog.bk.SimpleLedgerAllocator: Ledger allocator /distributedlog/xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz/<default>/allocation moved to phase ALLOCATED : version = 3.  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.proto.PerChannelBookieClient: Successfully connected to bookie: [id: 0xe89c134d, L:/100.105.146.3:42366 - R:100.126.73.199/100.126.73.199:3181]  
[2018-06-14 10:17:44 +0000] [INFO] org.apache.bookkeeper.proto.PerChannelBookieClient: Successfully connected to bookie: 100.126.73.199:3181  
[2018-06-14 10:17:45 +0000] [INFO] org.apache.bookkeeper.proto.PerChannelBookieClient: connection [id: 0xe89c134d, L:/100.105.146.3:42366 - R:100.126.73.199/100.126.73.199:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 101): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 102): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 103): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 104): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 105): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 106): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 107): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 108): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 109): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 110): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 111): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 112): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 113): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 114): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 115): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 116): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 117): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 118): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 119): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 120): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 121): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 122): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 123): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 124): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 125): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 126): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 127): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 128): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.PendingAddOp: Failed to write entry (4, 129): Bookie operation timeout  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.RegionAwareEnsemblePlacementPolicy: Failed to choose a bookie from /default-region/default-rack : excluded [<Bookie:100.126.73.199:3181>], fallback to choose bookie randomly from the cluster.  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Could not get additional bookie to remake ensemble, closing ledger: 4  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Closing ledger 4 due to error -6  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E101  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E102  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 102: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E103  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 103: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E104  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 104: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E105  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 105: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E106  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E107  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 106: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E108  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 107: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E109  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E110  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 108: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 109: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E111  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 110: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E112  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 111: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E113  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 112: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E114  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 113: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E115  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 114: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 115: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E116  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E117  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 116: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E118  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 117: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E119  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 118: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E120  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 119: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E121  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 120: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E122  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 121: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E123  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 122: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E124  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E125  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 123: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 124: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E126  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 125: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E127  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E128  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 126: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E129  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 127: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E130  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 128: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E131  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 129: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E132  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 130: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E133  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 131: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E134  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 132: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E135  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E136  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 133: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E137  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E138  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 134: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 135: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 136: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 137: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E139  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 138: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E140  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 139: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E141  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 140: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E142  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 141: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E143  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 142: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E144  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 143: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E145  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 144: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E146  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 145: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E147  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 146: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E148  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 147: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E149  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 148: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E150  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 149: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E151  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 150: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E152  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E153  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 151: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E154  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E155  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 152: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E156  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 153: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E157  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.PendingAddOp: Write of ledger entry to quorum failed: L4 E158  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 154: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 155: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [SEVERE] com.twitter.heron.uploader.dlog.DLUploader: Encountered exceptions on uploading the package 'xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz' 
org.apache.distributedlog.exceptions.WriteException: Write rejected because stream xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz has encountered an error : writer has been closed due to error.
    at org.apache.distributedlog.BKAsyncLogWriter.doGetLogSegmentWriter(BKAsyncLogWriter.java:217)
    at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:207)
    at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriterForEndOfStream(BKAsyncLogWriter.java:236)
    at org.apache.distributedlog.BKAsyncLogWriter.markEndOfStream(BKAsyncLogWriter.java:474)
    at org.apache.distributedlog.AppendOnlyStreamWriter.markEndOfStream(AppendOnlyStreamWriter.java:79)
    at com.twitter.heron.dlog.DLOutputStream.close(DLOutputStream.java:64)
    at com.twitter.heron.uploader.dlog.DLUploader.doUploadPackage(DLUploader.java:189)
    at com.twitter.heron.uploader.dlog.DLUploader.uploadPackage(DLUploader.java:154)
    at com.twitter.heron.scheduler.SubmitterMain.uploadPackage(SubmitterMain.java:542)
    at com.twitter.heron.scheduler.SubmitterMain.submitTopology(SubmitterMain.java:445)
    at com.twitter.heron.apiserver.actions.SubmitTopologyAction.execute(SubmitTopologyAction.java:33)
    at com.twitter.heron.apiserver.resources.TopologyResource.submit(TopologyResource.java:223)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
    at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:841)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
    at org.eclipse.jetty.server.Server.handle(Server.java:564)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:317)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
    at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128)
    at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591)
    at java.lang.Thread.run(Thread.java:748)

[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.BookKeeperClient: BookKeeper Client closed bk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.bookkeeper.proto.PerChannelBookieClient: Closing the per channel bookie client for 100.126.73.199:3181  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 156: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 157: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.distributedlog.BKLogSegmentWriter: Log segment xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz:<default>:inprogress_000000000000000001 entryId 158: Tried to set transmit result to (-6) but is already (-6)  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.bookkeeper.proto.PerChannelBookieClient: Disconnected from bookie channel [id: 0xe89c134d, L:/100.105.146.3:42366 ! R:100.126.73.199/100.126.73.199:3181]  
[2018-06-14 10:17:55 +0000] [SEVERE] org.apache.bookkeeper.client.LedgerHandle: Error update ledger metadata for ledger 4 : -19  
[2018-06-14 10:17:55 +0000] [WARNING] org.apache.bookkeeper.client.LedgerHandle: Close failed: BookKeeper client is closed  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.ZooKeeperClient: Close zookeeper client bk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared:zk.  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.ZooKeeperClient: Closing zookeeper client bk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared:zk.  
[2018-06-14 10:17:55 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: EventThread shut down for session: 0x163fdb642fc0016  
[2018-06-14 10:17:55 +0000] [INFO] dlshade.org.apache.zookeeper.ZooKeeper: Session: 0x163fdb642fc0016 closed  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.ZooKeeperClient: Closed zookeeper client bk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared:zk.  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.ZooKeeperClient: Close zookeeper client dlzk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared.  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.ZooKeeperClient: Closing zookeeper client dlzk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared.  
[2018-06-14 10:17:55 +0000] [INFO] dlshade.org.apache.zookeeper.ClientCnxn: EventThread shut down for session: 0x163fdb642fc0015  
[2018-06-14 10:17:55 +0000] [INFO] dlshade.org.apache.zookeeper.ZooKeeper: Session: 0x163fdb642fc0015 closed  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.ZooKeeperClient: Closed zookeeper client dlzk:distributedlog://heron-zookeeper:2181/distributedlog:factory_writer_shared.  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.impl.BKNamespaceDriver: Release external resources used by channel factory.  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.impl.BKNamespaceDriver: Stopped request timer  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.distributedlog.BKDistributedLogNamespace: Executor Service Stopped.  
[2018-06-14 10:17:55 +0000] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Closing the CuratorClient to: heron-zookeeper:2181  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.zookeeper.ClientCnxn: EventThread shut down  
[2018-06-14 10:17:55 +0000] [INFO] org.apache.zookeeper.ZooKeeper: Session: 0x163fdb642fc0014 closed  
[2018-06-14 10:17:55 +0000] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Closing the tunnel processes  
[2018-06-14 10:17:55 +0000] [SEVERE] com.twitter.heron.apiserver.resources.TopologyResource: error submitting topology xxxxxxxxxx 
com.twitter.heron.spi.uploader.UploaderException: Encountered exceptions on uploading the package 'xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz'
    at com.twitter.heron.uploader.dlog.DLUploader.uploadPackage(DLUploader.java:160)
    at com.twitter.heron.scheduler.SubmitterMain.uploadPackage(SubmitterMain.java:542)
    at com.twitter.heron.scheduler.SubmitterMain.submitTopology(SubmitterMain.java:445)
    at com.twitter.heron.apiserver.actions.SubmitTopologyAction.execute(SubmitTopologyAction.java:33)
    at com.twitter.heron.apiserver.resources.TopologyResource.submit(TopologyResource.java:223)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
    at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:841)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
    at org.eclipse.jetty.server.Server.handle(Server.java:564)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:317)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
    at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128)
    at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.distributedlog.exceptions.WriteException: Write rejected because stream xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz has encountered an error : writer has been closed due to error.
    at org.apache.distributedlog.BKAsyncLogWriter.doGetLogSegmentWriter(BKAsyncLogWriter.java:217)
    at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:207)
    at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriterForEndOfStream(BKAsyncLogWriter.java:236)
    at org.apache.distributedlog.BKAsyncLogWriter.markEndOfStream(BKAsyncLogWriter.java:474)
    at org.apache.distributedlog.AppendOnlyStreamWriter.markEndOfStream(AppendOnlyStreamWriter.java:79)
    at com.twitter.heron.dlog.DLOutputStream.close(DLOutputStream.java:64)
    at com.twitter.heron.uploader.dlog.DLUploader.doUploadPackage(DLUploader.java:189)
    at com.twitter.heron.uploader.dlog.DLUploader.uploadPackage(DLUploader.java:154)
    ... 53 more

I can't say I happen to know how any of this works at the moment, I am just interested in the issue as I will soon be deploying PEXs to Kubernetes. Does this work with Java toplogies? I think it would be a config issue too, but haven't got to that point myself to know better of the process or documentation. Hopefully someone else will know better and be able to give you more help, or I might encounter the same things and work it out but that would probably be a week or two away. If you do work it out I'd be interested in hearing what the issue is.

† out of curiosity, which time zones were the different applications running in, the +XXXX should be meaningful so I think one or both aren't behaving as they should

Code0x58 commented 6 years ago

While making and starting to test a heronpy PEX, I found that the documentation and example repos don't have valid imports. Were you able to execute your PEXs locally without getting import errors? I don't know if that could be a contributing factor. There is PR #2928 to get the documentation a bit more up to date.

cristobalcl commented 6 years ago

Yeah, it seems that the documentation is pretty outdated. I've just checked your PR and effectively that fixed the problems with the documented imports that we faced at the beginning.

My fear is that the Helm chart I'm using to install Heron in Kubernetes is also outdated.

Feel free to ask for anything you think I could help!

Code0x58 commented 6 years ago

Thanks! I'll probably have questions at some point.

Kubernetes moves pretty fast so I wouldn't be surprised if it is the case. That said, it looks like the chart was made with Helm 2.7.2 (vs. latest which is 2.9.1). I don't have practical experience with it yet but imagine I'll be there in 2-3 weeks so will have a look over it.

It looks like the the files are here and the chart is generated here.

cristobalcl commented 6 years ago

I have edited the issue because I tested again with a small PEX and it works (though I have a new problem after that). With big PEX still does not work.

Also I have reproduce the issue locally using Minikube.

The problem that appeared when the small PEX was successfully submitted was that the topology does not launch because of an insufficient resources error in the launched pod: 0/5 nodes are available: 1 PodToleratesNodeTaints, 5 Insufficient cpu. Of course, I added a new node and the problem persisted. This same problem appeared in Minikube just the same (only with Heron deployed).

cristobalcl commented 6 years ago

I made this to reproduce the issue: https://github.com/cristobalcl/heron-issue-2919

Also, I tested more times and I can reproduce the issue with small PEX... :(

Code0x58 commented 6 years ago

I found I had to up the minikube resources, and wait for everything to come up before heron was deployed properly, so issues with time+lacking resources on my laptop/network were a problem to start with.

I also got the two issues:

  1. Failed to get physical plan for topology ExclamationTopology - this is mentioned in the troubleshooting guide but that wasn't helpful in this case - it only helps if there was an executor failure (it doesn't mention ~/.herondata/ is on the worker). I think the issue happens when the workers (topology pods) aren't up yet either because of start times/resources/executor failures. With a bit of poking around, it looks like this happens when trying to activate the topology while it is in the UNKOWN status. I guess this issue is less apparent on beefier setups. The documentation on troubleshooting could do with being updated, as well as docs for using Kubernetes/minikue and what to look out for with resource issues. It would be nice if the issue if the CLI gave more feedback if there are resource issues, and if it waited around for executors to come up.

  2. Caused by: org.apache.distributedlog.exceptions.WriteException: Write rejected because stream xxxxxxxxxx-cristobal-tag-0-7116362347360204918.tar.gz has encountered an error : writer has been closed due to error comes up for me with the larger PEX too. I think the topology is supposed to be uploaded to ZooKeeper by BookKeeper, but it is dying due to the ZooKeeper client session timing out (which I saw as a warning in BookKeeper's logs), which explains why smaller ones are more likely to succeed. I suspect increasing the tick duration will help, especially when using minikube when your machine is going to be under a lot of load. This would be something to document, or try avoiding by tweaking the deploy files to include an extended tick. I havent tested this, but am pretty sure that is the case.

It feels like the moral of the story is "have a beefy AF setup so you are less likely to encounter issues", time for a Dell Precision?

sautran commented 5 years ago

I am using the same exact issue when using minikube. it failed to upload. in the bookie server log, there ar e a lot of errors. It has error in the worker container as well as the following error java.lang.NoClassDefFoundError: Could not initialize class dlshade.io.netty.channel.epoll.EpollEventLoopGroup

I don't use helm. I follow this steps https://apache.github.io/incubator-heron/docs/operators/deployment/schedulers/kubernetes/

I created 2 tickets, #3170 and #3173

sautran commented 5 years ago

@Code0x58 , @cristobalcl , any progress on this? it seems nobody get this fixed.

Code0x58 commented 5 years ago

I think it was something to do with the resources requested by heron being something quite large (1CPU?) but there was way to get the client to request lower resources, there was some talk around the time of this in the general Heron slack channel which may be helpful. I've since fallen off the Heron trail

sautran commented 5 years ago

@Code0x58 , for me, I checked the bookkeeper log, it is full of bookkeeper IOException, I described here #3173

sautran commented 5 years ago

After I saw timeout warning, I migrate to a powerful box, the issue is gone.