[ZOOKEEPER-3644] Data loss after upgrading standalone ZK server 3.4.14 to 3.5.6 with snapshot.trust.empty=true

• Type: Bug
• Status: Closed
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: 3.5.6
• Fix Version/s: 3.6.0, 3.7.0, 3.5.7
• Component/s: server
• Labels: pull-request-available
• Assignee: Michael Han
• Reporter: Manikumar
• Created: 10/Dec/19 15:38
• Updated: 14/Feb/20 15:23
• Resolved: 05/Jan/20 21:19

Description

We have tried to upgrade single node standalone ZK server from 3.4.14 to 3.5.6.  There were no snapshot files, so as suggested in ZOOKEEPER-3056, we have set snapshot.trust.empty to true. After server startup, when we tried to list the znodes, we found that znodes are missing.

Steps to reproduce:

1. Start a single node ZK 3.4.14 server and create few znodes
2. Upgrade the server to 3.5.6 with  snapshot.trust.empty=true config
3. try to list the znodes using zkShell

Looking into the source code, looks like we are not reading transaction log if there are no snapshot files and snapshot.trust.empty is set to true.

ZK 3.5.6 logs:

[2019-12-07 12:13:35,007] INFO Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /var/lib/zookeeper/version-2 snapdir /var/lib/zookeeper/version-2
 (org.apache.zookeeper.server.ZooKeeperServer)
[2019-12-07 12:13:35,012] INFO Using org.apache.zookeeper.server.NIOServerCnxnFactory as server connection factory (org.apache.zookeeper.server.ServerCnxnFactory)
[2019-12-07 12:13:35,014] INFO Configuring NIO connection handler with 10s sessionless connection timeout, 1 selector thread(s), 12 worker threads, and 64 kB direct buffers. (org.apache
.zookeeper.server.NIOServerCnxnFactory)
[2019-12-07 12:13:35,017] INFO binding to port 0.0.0.0/0.0.0.0:2181 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2019-12-07 12:13:35,027] INFO zookeeper.snapshotSizeFactor = 0.33 (org.apache.zookeeper.server.ZKDatabase)
[2019-12-07 12:13:35,029] DEBUG Created new input stream /var/lib/zookeeper/version-2/log.1 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2019-12-07 12:13:35,031] DEBUG Created new input archive /var/lib/zookeeper/version-2/log.1 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2019-12-07 12:13:35,035] DEBUG EOF exception java.io.EOFException: Failed to read /var/lib/zookeeper/version-2/log.1 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2019-12-07 12:13:35,035] WARN No snapshot found, but there are log entries. This should only be allowed during upgrading. (org.apache.zookeeper.server.persistence.FileTxnSnapLog)
[2019-12-07 12:13:35,035] INFO Snapshotting: 0x0 to /var/lib/zookeeper/version-2/snapshot.0 (org.apache.zookeeper.server.persistence.FileTxnSnapLog)
[2019-12-07 12:13:35,036] INFO Snapshotting: 0x0 to /var/lib/zookeeper/version-2/snapshot.0 (org.apache.zookeeper.server.persistence.FileTxnSnapLog)
[2019-12-07 12:13:35,050] INFO Using checkIntervalMs=60000 maxPerMinute=10000 (org.apache.zookeeper.server.ContainerManager)
[2019-12-07 12:15:07,137] DEBUG Accepted socket connection from /127.0.0.1:38888 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2019-12-07 12:15:07,144] DEBUG Session establishment request from client /127.0.0.1:38888 client's lastZxid is 0x0 (org.apache.zookeeper.server.ZooKeeperServer)
[2019-12-07 12:15:07,145] DEBUG Adding session 0x100006e15fb0000 (org.apache.zookeeper.server.SessionTrackerImpl)
[2019-12-07 12:15:07,148] TRACE SessionTrackerImpl — Adding session 0x100006e15fb0000 30000 (org.apache.zookeeper.server.SessionTrackerImpl)
[2019-12-07 12:15:07,149] DEBUG Client attempting to establish new session: session = 0x100006e15fb0000, zxid = 0x0, timeout = 30000, address = /127.0.0.1:38888 (org.apache.zookeeper.server.ZooKeeperServer)
[2019-12-07 12:15:07,155] TRACE :Psessionid:0x100006e15fb0000 type:createSession cxid:0x0 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.PrepRequestProcessor)
[2019-12-07 12:15:07,155] TRACE SessionTrackerImpl — Existing session 0x100006e15fb0000 30000 (org.apache.zookeeper.server.SessionTrackerImpl)
[2019-12-07 12:15:07,155] INFO Creating new log file: log.1 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2019-12-07 12:15:07,170] DEBUG Processing request:: sessionid:0x100006e15fb0000 type:createSession cxid:0x0 zxid:0x1 txntype:-10 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor)

Issue Links

• relates to: ZOOKEEPER-3056 Fails to load database with missing snapshot file but valid transaction log file
• links to: GitHub Pull Request #1177
• links to: GitHub Pull Request #1182