zymap commented on PR #3225:
URL: https://github.com/apache/bookkeeper/pull/3225#issuecomment-1104615724
Now it has zookeeper logs, but the bookie logs look like still missing.
Startup with your branch:
```
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:java.library.path=/Users/zhangyong/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:java.io.tmpdir=/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:java.compiler=<NA>
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:os.name=Mac OS X
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:os.arch=x86_64
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:os.version=10.16
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:user.name=zhangyong
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:user.home=/Users/zhangyong
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:user.dir=/Volumes/ZY_TWO/yong/github.com/zymap/bookkeeper
2022-04-21T09:23:19,874 - INFO - [main:Environment@98] - Server
environment:os.memory.free=946MB
2022-04-21T09:23:19,875 - INFO - [main:Environment@98] - Server
environment:os.memory.max=1024MB
2022-04-21T09:23:19,875 - INFO - [main:Environment@98] - Server
environment:os.memory.total=1024MB
2022-04-21T09:23:19,875 - INFO - [main:ZooKeeperServer@140] -
zookeeper.enableEagerACLCheck = false
2022-04-21T09:23:19,875 - INFO - [main:ZooKeeperServer@153] -
zookeeper.digest.enabled = true
2022-04-21T09:23:19,875 - INFO - [main:ZooKeeperServer@157] -
zookeeper.closeSessionTxn.enabled = true
2022-04-21T09:23:19,875 - INFO - [main:ZooKeeperServer@1496] -
zookeeper.flushDelay = 0 ms
2022-04-21T09:23:19,875 - INFO - [main:ZooKeeperServer@1505] -
zookeeper.maxWriteQueuePollTime = 0 ms
2022-04-21T09:23:19,875 - INFO - [main:ZooKeeperServer@1514] -
zookeeper.maxBatchSize=1000
2022-04-21T09:23:19,875 - INFO - [main:ZooKeeperServer@264] -
zookeeper.intBufferStartingSizeBytes = 1024
2022-04-21T09:23:19,878 - INFO - [main:FileTxnSnapLog@124] -
zookeeper.snapshot.trust.empty : false
2022-04-21T09:23:19,901 - INFO - [main:WatchManagerFactory@42] - Using
org.apache.zookeeper.server.watch.WatchManager as watch manager
2022-04-21T09:23:19,901 - INFO - [main:WatchManagerFactory@42] - Using
org.apache.zookeeper.server.watch.WatchManager as watch manager
2022-04-21T09:23:19,901 - INFO - [main:ZKDatabase@132] -
zookeeper.snapshotSizeFactor = 0.33
2022-04-21T09:23:19,901 - INFO - [main:ZKDatabase@152] -
zookeeper.commitLogCount=500
2022-04-21T09:23:19,906 - INFO - [main:BlueThrottle@141] - Weighed
connection throttling is disabled
2022-04-21T09:23:19,910 - INFO - [main:ZooKeeperServer@1297] -
minSessionTimeout set to 6000 ms
2022-04-21T09:23:19,910 - INFO - [main:ZooKeeperServer@1306] -
maxSessionTimeout set to 60000 ms
2022-04-21T09:23:19,911 - INFO - [main:ResponseCache@45] - getData response
cache size is initialized with value 400.
2022-04-21T09:23:19,911 - INFO - [main:ResponseCache@45] - getChildren
response cache size is initialized with value 400.
2022-04-21T09:23:19,913 - INFO - [main:RequestPathMetricsCollector@109] -
zookeeper.pathStats.slotCapacity = 60
2022-04-21T09:23:19,913 - INFO - [main:RequestPathMetricsCollector@110] -
zookeeper.pathStats.slotDuration = 15
2022-04-21T09:23:19,913 - INFO - [main:RequestPathMetricsCollector@111] -
zookeeper.pathStats.maxDepth = 6
2022-04-21T09:23:19,913 - INFO - [main:RequestPathMetricsCollector@112] -
zookeeper.pathStats.initialDelay = 5
2022-04-21T09:23:19,913 - INFO - [main:RequestPathMetricsCollector@113] -
zookeeper.pathStats.delay = 5
2022-04-21T09:23:19,913 - INFO - [main:RequestPathMetricsCollector@114] -
zookeeper.pathStats.enabled = false
2022-04-21T09:23:19,915 - INFO - [main:ZooKeeperServer@1533] - The max
bytes for all large requests are set to 104857600
2022-04-21T09:23:19,915 - INFO - [main:ZooKeeperServer@1547] - The large
request threshold is set to -1
2022-04-21T09:23:19,916 - INFO - [main:AuthenticationHelper@66] -
zookeeper.enforce.auth.enabled = false
2022-04-21T09:23:19,916 - INFO - [main:AuthenticationHelper@67] -
zookeeper.enforce.auth.schemes = []
2022-04-21T09:23:19,916 - INFO - [main:ZooKeeperServer@365] - Created
server with tickTime 3000 ms minSessionTimeout 6000 ms maxSessionTimeout 60000
ms clientPortListenBacklog -1 datadir
/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/zookeeper6029457320140506891test/version-2
snapdir
/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/zookeeper6029457320140506891test/version-2
2022-04-21T09:23:19,926 - WARN - [main:ServerCnxnFactory@309] - maxCnxns is
not configured, using default value 0.
2022-04-21T09:23:19,928 - INFO - [main:NIOServerCnxnFactory@652] -
Configuring NIO connection handler with 10s sessionless connection timeout, 2
selector thread(s), 24 worker threads, and 64 kB direct buffers.
2022-04-21T09:23:19,939 - INFO - [main:NIOServerCnxnFactory@660] - binding
to port 0.0.0.0/0.0.0.0:2181
2022-04-21T09:23:19,965 - INFO - [main:SnapStream@61] -
zookeeper.snapshot.compression.method = CHECKED
2022-04-21T09:23:19,965 - INFO - [main:FileTxnSnapLog@479] - Snapshotting:
0x0 to
/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/zookeeper6029457320140506891test/version-2/snapshot.0
2022-04-21T09:23:19,968 - INFO - [main:ZKDatabase@289] - Snapshot loaded in
26 ms, highest zxid is 0x0, digest is 1371985504
2022-04-21T09:23:19,970 - INFO - [main:FileTxnSnapLog@479] - Snapshotting:
0x0 to
/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/zookeeper6029457320140506891test/version-2/snapshot.0
2022-04-21T09:23:19,971 - INFO - [main:ZooKeeperServer@547] - Snapshot
taken in 0 ms
2022-04-21T09:23:19,983 - INFO - [ProcessThread(sid:0
cport:2181)::PrepRequestProcessor@138] - PrepRequestProcessor (sid:0) started,
reconfigEnabled=false
2022-04-21T09:23:19,984 - INFO - [main:RequestThrottler@75] -
zookeeper.request_throttler.shutdownTimeout = 10000 ms
2022-04-21T09:23:20,013 - INFO - [NIOWorkerThread-1:FourLetterCommands@223]
- The list of known four letter word commands is : [{1936881266=srvr,
1937006964=stat, 2003003491=wchc, 1685417328=dump, 1668445044=crst,
1936880500=srst, 1701738089=envi, 1668247142=conf, -720899=telnet close,
1751217000=hash, 2003003507=wchs, 2003003504=wchp, 1684632179=dirs,
1668247155=cons, 1835955314=mntr, 1769173615=isro, 1920298859=ruok,
1735683435=gtmk, 1937010027=stmk}]
2022-04-21T09:23:20,014 - INFO - [NIOWorkerThread-1:FourLetterCommands@224]
- The list of enabled four letter word commands is : [[wchs, stat, wchp, dirs,
stmk, conf, ruok, mntr, srvr, wchc, envi, srst, isro, dump, gtmk, telnet close,
crst, hash, cons]]
2022-04-21T09:23:20,014 - INFO - [NIOWorkerThread-1:NIOServerCnxn@514] -
Processing stat command from /127.0.0.1:55422
2022-04-21T09:23:20,020 - INFO - [NIOWorkerThread-1:StatCommand@52] - Stat
command output
```
Startup with a released bookie:
```
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:java.library.path=/Users/zhangyong/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:java.io.tmpdir=/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:java.compiler=<NA>
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:os.name=Mac OS X
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:os.arch=x86_64
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:os.version=10.16
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:user.name=zhangyong
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:user.home=/Users/zhangyong
2022-04-21 09:24:52,694 - INFO - [main:Environment@98] - Client
environment:user.dir=/Users/zhangyong/Downloads/bookkeeper-all-4.14.5
2022-04-21 09:24:52,695 - INFO - [main:Environment@98] - Client
environment:os.memory.free=985MB
2022-04-21 09:24:52,695 - INFO - [main:Environment@98] - Client
environment:os.memory.max=1024MB
2022-04-21 09:24:52,695 - INFO - [main:Environment@98] - Client
environment:os.memory.total=1024MB
2022-04-21 09:24:52,701 - INFO - [main:ZooKeeper@1006] - Initiating client
connection, connectString=127.0.0.1:2181 sessionTimeout=5000
watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@31f924f5
2022-04-21 09:24:52,705 - INFO - [main:X509Util@77] - Setting -D
jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS
renegotiation
2022-04-21 09:24:52,708 - INFO - [main:ClientCnxnSocket@239] -
jute.maxbuffer value is 1048575 Bytes
2022-04-21 09:24:52,715 - INFO - [main:ClientCnxn@1716] -
zookeeper.request.timeout value is 0. feature enabled=false
2022-04-21 09:24:52,720 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1167] - Opening socket
connection to server localhost/127.0.0.1:2181.
2022-04-21 09:24:52,720 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1169] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
2022-04-21 09:24:52,721 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@999] - Socket connection
established, initiating session, client: /127.0.0.1:55468, server:
localhost/127.0.0.1:2181
2022-04-21 09:24:52,727 - INFO - [SyncThread:0:FileTxnLog@284] - Creating
new log file: log.1
2022-04-21 09:24:52,733 - INFO - [SyncThread:0:ZKAuditProvider@42] -
ZooKeeper audit is disabled.
2022-04-21 09:24:52,736 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1433] - Session
establishment complete on server localhost/127.0.0.1:2181, session id =
0x1000faf49ff0000, negotiated timeout = 6000
2022-04-21 09:24:52,739 - INFO -
[main-EventThread:ZooKeeperWatcherBase@130] - ZooKeeper client is connected now.
2022-04-21 09:24:52,872 - INFO - [main:ZooKeeper@1619] - Session:
0x1000faf49ff0000 closed
2022-04-21 09:24:52,873 - INFO - [main:LocalBookKeeper@184] - Starting
Bookie(s)
2022-04-21 09:24:52,872 - INFO -
[main-EventThread:ClientCnxn$EventThread@577] - EventThread shut down for
session: 0x1000faf49ff0000
2022-04-21 09:24:53,143 - INFO - [main:BookieServer@111] - {
"storage.cluster.controller.schedule.interval.ms" : "30000",
"zkEnableSecurity" : "false",
"dlog.bkcAckQuorumSize" : "2",
"zkServers" : "localhost:2181",
"storage.range.store.dirs" : "data/bookkeeper/ranges",
"httpServerPort" : "8080",
"dlog.bkcWriteQuorumSize" : "2",
"storage.serve.readonly.tables" : "false",
"bookiePort" : "5001",
"zkTimeout" : "10000",
"ledgerDirectories" : "/tmp/bk-data/bookie0",
"httpServerClass" : "org.apache.bookkeeper.http.vertx.VertxHttpServer",
"httpServerEnabled" : "false",
"metadataServiceUri" : "zk+null://127.0.0.1:2181/ledgers",
"dlog.bkcEnsembleSize" : "3",
"journalDirectories" :
"/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/localbookkeeper01046924220169534388test",
"allowLoopback" : "true",
"storageserver.grpc.port" : "4181",
"extraServerComponents" : ""
}
2022-04-21 09:24:53,246 - INFO - [main:BookieNettyServer@357] - Binding
bookie-rpc endpoint to 0.0.0.0/0.0.0.0:5001
2022-04-21 09:24:53,294 - INFO - [main:MetadataDrivers@106] - BookKeeper
metadata driver manager initialized
2022-04-21 09:24:53,295 - INFO - [main:ZKMetadataDriverBase@197] -
Initialize zookeeper metadata driver at metadata service uri
zk+null://127.0.0.1:2181/ledgers : zkServers = 127.0.0.1:2181, ledgersRootPath
= /ledgers.
2022-04-21 09:24:53,295 - INFO - [main:ZooKeeper@1006] - Initiating client
connection, connectString=127.0.0.1:2181 sessionTimeout=10000
watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@792b749c
2022-04-21 09:24:53,295 - INFO - [main:ClientCnxnSocket@239] -
jute.maxbuffer value is 1048575 Bytes
2022-04-21 09:24:53,295 - INFO - [main:ClientCnxn@1716] -
zookeeper.request.timeout value is 0. feature enabled=false
2022-04-21 09:24:53,296 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1167] - Opening socket
connection to server localhost/127.0.0.1:2181.
2022-04-21 09:24:53,297 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1169] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
2022-04-21 09:24:53,297 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@999] - Socket connection
established, initiating session, client: /127.0.0.1:55469, server:
localhost/127.0.0.1:2181
2022-04-21 09:24:53,299 - INFO -
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1433] - Session
establishment complete on server localhost/127.0.0.1:2181, session id =
0x1000faf49ff0001, negotiated timeout = 10000
2022-04-21 09:24:53,299 - INFO -
[main-EventThread:ZooKeeperWatcherBase@130] - ZooKeeper client is connected now.
2022-04-21 09:24:53,310 - INFO - [main:ZKRegistrationManager@426] -
INSTANCEID not exists in zookeeper. Not considering it for data verification
2022-04-21 09:24:53,321 - INFO - [main:Bookie@413] - Stamping new cookies
on all dirs
[/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/localbookkeeper01046924220169534388test/current]
[/tmp/bk-data/bookie0/current]
2022-04-21 09:24:53,399 - INFO - [main:Bookie@736] - instantiate ledger
manager org.apache.bookkeeper.meta.HierarchicalLedgerManagerFactory
2022-04-21 09:24:53,462 - WARN - [main:DiskChecker@163] - Space left on
device /tmp/bk-data/bookie0/current : 39520133120, Used space fraction:
0.9209539 > WarnThreshold 0.9.
2022-04-21 09:24:53,467 - ERROR - [main:Journal$LastLogMark@252] - Problems
reading from /tmp/bk-data/bookie0/current/lastMark (this is okay if it is the
first time starting this bookie
2022-04-21 09:24:53,470 - INFO - [main:Bookie@654] - Using ledger storage:
org.apache.bookkeeper.bookie.SortedLedgerStorage
2022-04-21 09:24:53,496 - INFO - [main:IndexPersistenceMgr@99] -
openFileLimit = 20000
2022-04-21 09:24:53,514 - INFO - [main:IndexInMemPageMgr@361] -
maxDirectMemory = 2147483648, pageSize = 8192, pageLimit = 87381
2022-04-21 09:24:53,518 - INFO - [main:ScanAndCompareGarbageCollector@102]
- Over Replicated Ledger Deletion : enabled=true, interval=86400000
2022-04-21 09:24:53,524 - INFO - [main:GarbageCollectorThread@245] - Minor
Compaction : enabled=true, threshold=0.20000000298023224, interval=3600000
2022-04-21 09:24:53,525 - INFO - [main:GarbageCollectorThread@247] - Major
Compaction : enabled=true, threshold=0.800000011920929, interval=86400000
2022-04-21 09:24:53,552 - INFO - [main:Bookie@964] - Finished replaying
journal in 1 ms.
2022-04-21 09:24:53,553 - INFO - [SyncThread-7-1:SyncThread@135] - Flush
ledger storage at checkpoint CheckpointList{checkpoints=[LogMark: logFileId - 0
, logFileOffset - 0]}.
2022-04-21 09:24:53,554 - INFO - [main:Bookie@1054] - Finished reading
journal, starting bookie
2022-04-21 09:24:53,554 - INFO - [BookieJournal-5001:Journal@919] -
Starting journal on
/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/localbookkeeper01046924220169534388test/current
2022-04-21 09:24:53,556 - INFO -
[ForceWriteThread:Journal$ForceWriteThread@478] - ForceWrite Thread started
2022-04-21 09:24:53,558 - INFO - [BookieJournal-5001:JournalChannel@157] -
Opening journal
/var/folders/r1/rg57qn257396qmzytmvfqg9r0000gn/T/localbookkeeper01046924220169534388test/current/18049b8dcb5.txn
2022-04-21 09:24:53,907 - INFO - [BookieJournal-5001:NativeIO@48] - Unable
to link C library. Native methods will be disabled.
```
You can see there are missing bookie logs in this branch. Like
BookieJournal, Bookie and so on.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]