JMX enabled by default
Using config: /etc/zookeeper/conf/zoo.cfg
Starting zookeeper ... STARTED
1519598438.915735579 CoordinatorMain.cc:96 in main NOTICE[1]: Command line: ./coordinator -C basic+udp:host=localhost,port=11100 -x zk:localhost:2181
1519598438.915770554 CoordinatorMain.cc:97 in main NOTICE[1]: Coordinator process id: 11541
1519598438.916377156 Common.cc:224 in pinAllMemory WARNING[1]: Could not lock all memory pages (Cannot allocate memory), so the OS might swap memory later. Check your user's "ulimit -l" and adjust /etc/security/limits.conf as necessary.
1519598438.916684853 UdpDriver.cc:86 in UdpDriver NOTICE[1]: UdpDriver bandwidth: 10 Gbits/sec, maxTransmitQueueSize: 2800 bytes
1519598438.919391285 UdpDriver.cc:123 in UdpDriver NOTICE[1]: Locator for UdpDriver: udp:host=localhost,port=11100
1519598438.919724415 BasicTransport.cc:126 in BasicTransport NOTICE[1]: BasicTransport parameters: maxDataPerPacket 1370, roundTripBytes 10960, grantIncrement 6850, pingIntervals 3, timeoutIntervals 40, timerInterval 2.00 ms
1519598438.919748807 CoordinatorMain.cc:108 in main NOTICE[1]: coordinator: Listening on basic+udp:host=localhost,port=11100
1519598438.919753112 CoordinatorMain.cc:111 in main NOTICE[1]: PortTimeOut=-1
1519598438.919755352 PortAlarm.cc:160 in setPortTimeout NOTICE[1]: Set PortTimeout to -1 (ms: -1 to disable.)
2018-02-25 17:40:38,919:11541(0x7f02e0607a40):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
2018-02-25 17:40:38,919:11541(0x7f02e0607a40):ZOO_INFO@log_env@716: Client environment:host.name=localhost.localdomain
2018-02-25 17:40:38,919:11541(0x7f02e0607a40):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2018-02-25 17:40:38,919:11541(0x7f02e0607a40):ZOO_INFO@log_env@724: Client environment:os.arch=3.10.0-693.el7.x86_64
2018-02-25 17:40:38,919:11541(0x7f02e0607a40):ZOO_INFO@log_env@725: Client environment:os.version=#1 SMP Tue Aug 22 21:09:27 UTC 2017
2018-02-25 17:40:38,920:11541(0x7f02e0607a40):ZOO_INFO@log_env@733: Client environment:user.name=antd
2018-02-25 17:40:38,920:11541(0x7f02e0607a40):ZOO_INFO@log_env@741: Client environment:user.home=/home/antd
2018-02-25 17:40:38,920:11541(0x7f02e0607a40):ZOO_INFO@log_env@753: Client environment:user.dir=/home/antd/RAMCloud/obj.master
2018-02-25 17:40:38,920:11541(0x7f02e0607a40):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=localhost:2181 sessionTimeout=1000000 watcher=(nil) sessionId=0 sessionPasswd=<null> context=(nil) flags=0
2018-02-25 17:40:38,922:11541(0x7f02cb7fe700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:2181]
2018-02-25 17:40:38,994:11541(0x7f02cb7fe700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:2181], sessionId=0x161cee556da0001, negotiated timeout=40000
1519598439.001675026 ZooStorage.cc:586 in open NOTICE[1]: ZooKeeper connection opened with localhost:2181
1519598439.001698336 CoordinatorMain.cc:138 in main NOTICE[1]: Cluster name is 'main', external storage workspace is '/ramcloud/main/'
1519598440.016996021 ZooStorage.cc:465 in checkLeader NOTICE[1]: Became leader with version 623 (old leader info was "basic+udp:host=localhost,port=11100")
1519598440.017623434 CoordinatorClusterClock.cc:164 in recoverClusterTime NOTICE[1]: initializing CoordinatorClusterClock: startingClusterTime = 321099646459
1519598440.018034857 MemoryMonitor.cc:62 in handleTimerEvent NOTICE[8]: Memory usage now 10 MB (increased 10 MB)
1519598440.142775911 CoordinatorClusterClock.cc:62 in getTime WARNING[9]: Returning stale time. SafeTimeUpdater may be running behind.
1519598440.146859445 CoordinatorUpdateManager.cc:84 in init NOTICE[9]: initializing CoordinatorUpdateManager: lastFinished = 0, firstAvailable = 1000
1519598440.147054515 CoordinatorServerList.cc:401 in recover NOTICE[9]: CoordinatorServerList recovery completed: 0 master(s), 0 backup(s), 0 update(s) to disseminate, server list version is 0
1519598440.147314948 TableManager.cc:763 in recover NOTICE[9]: Table recovery complete: 0 table(s)
1519598440.157004352 CoordinatorService.cc:112 in init NOTICE[9]: Coordinator state has been recovered from external storage; starting service
1519598714.642223486 CoordinatorServerList.cc:148 in enlistServer NOTICE[7]: Enlisting server at basic+udp:host=localhost,port=1101 (server id 1.0) supporting services: MASTER_SERVICE, BACKUP_SERVICE, ADMIN_SERVICE
1519598714.642223486 CoordinatorClusterClock.cc:62 in getTime WARNING[9]: (999 duplicates of this message were skipped) Returning stale time. SafeTimeUpdater may be running behind.
1519598625.828585169 ServerMain.cc:256 in main NOTICE[1]: Command line: ./server -L basic+udp:host=localhost,port=1101 -x zk:localhost:2181 --totalMasterMemory 16000 -f /dev/sdb1 --segmentFrames 10000 -r 2
1519598625.828612945 ServerMain.cc:257 in main NOTICE[1]: Server process id: 11762
1519598625.828960405 UdpDriver.cc:86 in UdpDriver NOTICE[1]: UdpDriver bandwidth: 10 Gbits/sec, maxTransmitQueueSize: 2800 bytes
1519598625.829383334 UdpDriver.cc:123 in UdpDriver NOTICE[1]: Locator for UdpDriver: udp:host=localhost,port=1101
1519598625.829464540 BasicTransport.cc:126 in BasicTransport NOTICE[1]: BasicTransport parameters: maxDataPerPacket 1370, roundTripBytes 10960, grantIncrement 6850, pingIntervals 3, timeoutIntervals 40, timerInterval 2.00 ms
1519598625.829516428 ServerMain.cc:289 in main NOTICE[1]: MASTER_SERVICE, BACKUP_SERVICE, ADMIN_SERVICE: Listening on basic+udp:host=localhost,port=1101
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@716: Client environment:host.name=localhost.localdomain
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@724: Client environment:os.arch=3.10.0-693.el7.x86_64
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@725: Client environment:os.version=#1 SMP Tue Aug 22 21:09:27 UTC 2017
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@733: Client environment:user.name=antd
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@741: Client environment:user.home=/root
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@log_env@753: Client environment:user.dir=/home/antd/RAMCloud/obj.master
2018-02-25 17:43:45,829:11762(0x7f9254018a40):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=localhost:2181 sessionTimeout=1000000 watcher=(nil) sessionId=0 sessionPasswd=<null> context=(nil) flags=0
2018-02-25 17:43:45,830:11762(0x7f924e723700):ZOO_INFO@check_events@1703: initiated connection to server [::1:2181]
2018-02-25 17:43:45,837:11762(0x7f924e723700):ZOO_INFO@check_events@1750: session establishment complete on server [::1:2181], sessionId=0x161cee556da0004, negotiated timeout=40000
1519598625.840272026 ZooStorage.cc:586 in open NOTICE[1]: ZooKeeper connection opened with localhost:2181
1519598625.841115182 ServerMain.cc:329 in main NOTICE[1]: Using 2 backups
1519598625.841131845 ServerConfig.h:581 in setLogAndHashTableSize NOTICE[1]: Master to allocate 16777216000 bytes total, 1677721600 of which are for the hash table
1519598625.841135867 ServerConfig.h:583 in setLogAndHashTableSize NOTICE[1]: Master will have 1800 segments and 26214400 lines in the hash table
1519598625.841138836 ServerConfig.h:587 in setLogAndHashTableSize NOTICE[1]: Hash table will have one entry for every 72 bytes in the log
1519598625.841140916 ServerMain.cc:334 in main NOTICE[1]: PortTimeOut=-1
1519598625.841142961 PortAlarm.cc:160 in setPortTimeout NOTICE[1]: Set PortTimeout to -1 (ms: -1 to disable.)
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@zookeeper_close@2509: Closing zookeeper sessionId=0x161cee556da0004 to [::1:2181]
1519598625.841570440 ZooStorage.cc:490 in close NOTICE[1]: ZooKeeper connection closed
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@716: Client environment:host.name=localhost.localdomain
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@724: Client environment:os.arch=3.10.0-693.el7.x86_64
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@725: Client environment:os.version=#1 SMP Tue Aug 22 21:09:27 UTC 2017
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@733: Client environment:user.name=antd
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@741: Client environment:user.home=/root
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@log_env@753: Client environment:user.dir=/home/antd/RAMCloud/obj.master
2018-02-25 17:43:45,841:11762(0x7f9254018a40):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=localhost:2181 sessionTimeout=1000000 watcher=(nil) sessionId=0 sessionPasswd=<null> context=(nil) flags=0
2018-02-25 17:43:45,842:11762(0x7f924df22700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:2181]
2018-02-25 17:43:45,854:11762(0x7f924df22700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:2181], sessionId=0x161cee556da0005, negotiated timeout=40000
1519598625.862219779 ZooStorage.cc:586 in open NOTICE[1]: ZooKeeper connection opened with localhost:2181
1519598625.862993831 Server.cc:86 in run NOTICE[1]: Starting services
1519598625.863010000 Server.cc:150 in createAndRegisterServices NOTICE[1]: Master is using 2 backups
1519598625.915364162 SegletAllocator.cc:162 in initializeEmergencyHeadReserve NOTICE[1]: Reserved 256 seglets for emergency head segments (16 MB). 230144 seglets (14384 MB) left in default pool.
1519598625.916520605 SegletAllocator.cc:197 in initializeCleanerReserve NOTICE[1]: Reserved 1920 seglets for the cleaner (120 MB). 228224 seglets (14264 MB) left in default pool.
1519598625.916552771 LogCleaner.cc:806 in TombstoneRatioBalancer NOTICE[1]: Using tombstone ratio balancer with ratio = 0.400000
1519598625.917733848 Server.cc:155 in createAndRegisterServices NOTICE[1]: Starting backup service
1519598625.930213724 MultiFileStorage.cc:1021 in MultiFileStorage NOTICE[1]: Backup storage opened with 83886080000 bytes available; allocated 10000 frame(s) across 1 file(s) with 8388608 bytes per frame
1519598627.668025145 BackupStorage.cc:68 in benchmark NOTICE[1]: Backup storage speeds (min): 20 MB/s read
1519598627.668032601 BackupStorage.cc:69 in benchmark NOTICE[1]: Backup storage speeds (avg): 84 MB/s read,
1519598627.668034102 BackupStorage.cc:75 in benchmark NOTICE[1]: RANDOM_REFINE_AVG BackupStrategy selected
1519598627.685774135 MultiFileStorage.cc:1514 in tryLoadSuperblock NOTICE[1]: Stored superblock had a bad checksum: stored checksum was 0, but stored data had checksum 88a5c087
1519598627.686369074 MultiFileStorage.cc:1514 in tryLoadSuperblock NOTICE[1]: Stored superblock had a bad checksum: stored checksum was 0, but stored data had checksum 7562ad4e
1519598627.686378598 MultiFileStorage.cc:1300 in loadSuperblock WARNING[1]: Backup couldn't find existing superblock; starting as fresh backup.
1519598627.686399698 BackupService.cc:96 in BackupService NOTICE[1]: Backup storing replicas with clusterName 'main'. Future backups must be restarted with the same clusterName for replicas stored on this backup to be reused.
1519598627.686408247 BackupService.cc:111 in BackupService NOTICE[1]: Replicas stored on disk have a different clusterName ('__unnamed__'). Scribbling storage to ensure any stale replicas left behind by old backups aren't used by future backups
2018-02-25 17:43:59,188:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:44:12,535:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:44:25,882:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:44:39,228:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:44:52,575:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:45:05,922:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
1519598708.602906658 Server.cc:159 in createAndRegisterServices NOTICE[1]: Backup service started
1519598708.602931611 Server.cc:88 in run NOTICE[1]: Services started
1519598708.602935184 Server.cc:93 in run NOTICE[1]: Pinning memory
1519598714.640267292 Server.cc:95 in run NOTICE[1]: Memory pinned
1519598714.640412232 MemoryMonitor.cc:62 in handleTimerEvent NOTICE[8]: Memory usage now 16600 MB (increased 16600 MB)
1519598714.640424792 Server.cc:192 in enlist NOTICE[8]: Enlisting with cooordinator
1519598714.641249617 CoordinatorSession.cc:105 in getSession NOTICE[8]: Opened session with coordinator at basic+udp:host=localhost,port=11100
1519598714.686751763 Server.cc:199 in enlist NOTICE[8]: Enlisted; serverId 1.0
1519598714.686759212 MasterService.cc:823 in initOnceEnlisted NOTICE[8]: My server ID is 1.0
1519598714.689723789 ServerList.cc:188 in applyServerList NOTICE[7]: Server 1.0 is up (server list version 1)
1519598714.691048272 BackupService.cc:323 in initOnceEnlisted NOTICE[8]: My server ID is 1.0
1519598714.691089085 LogCleaner.cc:199 in cleanerThreadEntry NOTICE[9]: LogCleaner thread started
1519598714.741413013 BackupService.cc:330 in initOnceEnlisted NOTICE[8]: Backup 1.0 will store replicas under cluster name 'main'
1519598714.743965936 FailureDetector.cc:104 in detectorThreadEntry NOTICE[10]: Failure detector thread started
2018-02-25 17:45:27,987:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:45:41,334:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:45:54,680:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2018-02-25 17:46:08,027:11762(0x7f924df22700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms