Use ip instead of localhost to not resolve anything

Update netstat script
Merge branch 'fix-proposer-queue-cleanup' into netstat-logs
2026-08-14 10:11:33 +00:00 · 2021-10-18 22:33:36 +03:00 · 2021-10-15 18:34:25 +03:00 · 2021-10-15 14:04:45 +03:00 · 2021-10-15 13:59:17 +03:00 · 2021-10-15 11:34:15 +03:00
86 changed files with 1848 additions and 1346 deletions
@@ -241,17 +241,21 @@ jobs:
            if << parameters.run_in_parallel >>; then
              EXTRA_PARAMS="-n4 $EXTRA_PARAMS"
            fi;
+            ./netstat-script.sh &
+            NS_PID=$!
            # Run the tests.
            #
            # The junit.xml file allows CircleCI to display more fine-grained test information
            # in its "Tests" tab in the results page.
-            # -s prevents pytest from capturing output, which helps to see
-            # what's going on if the test hangs
            # --verbose prints name of each test (helpful when there are
            # multiple tests in one file)
            # -rA prints summary in the end
            # -n4 uses four processes to run tests via pytest-xdist
-            pipenv run pytest --junitxml=$TEST_OUTPUT/junit.xml --tb=short -s --verbose -rA $TEST_SELECTION $EXTRA_PARAMS
+            # -s is not used to prevent pytest from capturing output, because tests are running
+            # in parallel and logs are mixed between different tests
+            pipenv run pytest --junitxml=$TEST_OUTPUT/junit.xml --tb=short --verbose -rA $TEST_SELECTION $EXTRA_PARAMS
+            kill $NS_PID
+            awk '/===/ {if (count) print count; print; count=0; next} {count++} END {print count}' $TEST_OUTPUT/netstat.stdout > $TEST_OUTPUT/netstat_stats.stdout
      - run:
          # CircleCI artifacts are preserved one file at a time, so skipping
          # this step isn't a good idea. If you want to extract the
@@ -260,7 +264,7 @@ jobs:
          when: always
          command: |
            du -sh /tmp/test_output/*
-            find /tmp/test_output -type f ! -name "pg.log" ! -name "pageserver.log" ! -name "wal_acceptor.log" ! -name "regression.diffs" ! -name "junit.xml" ! -name "*.filediff" ! -name "*.stdout" ! -name "*.stderr" -delete
+            find /tmp/test_output -type f ! -name "pg.log" ! -name "pageserver.log" ! -name "safekeeper.log" ! -name "regression.diffs" ! -name "junit.xml" ! -name "*.filediff" ! -name "*.stdout" ! -name "*.stderr" -delete
            du -sh /tmp/test_output/*
      - store_artifacts:
          path: /tmp/test_output
@@ -325,8 +329,7 @@ jobs:
                \"inputs\": {
                  \"ci_job_name\": \"zenith-remote-ci\",
                  \"commit_hash\": \"$CIRCLE_SHA1\",
-                  \"remote_repo\": \"$LOCAL_REPO\",
-                  \"zenith_image_branch\": \"$CIRCLE_BRANCH\"
+                  \"remote_repo\": \"$LOCAL_REPO\"
                }
              }"

@@ -26,18 +26,21 @@ dependencies = [
 "winapi",
 ]

+[[package]]
+name = "ansi_term"
+version = "0.12.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2"
+dependencies = [
+ "winapi",
+]
+
 [[package]]
 name = "anyhow"
 version = "1.0.42"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "595d3cfa7a60d4555cb5067b99f07142a08ea778de5cf993f7b75c7d8fabc486"

-[[package]]
-name = "arc-swap"
-version = "1.3.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "e906254e445520903e7fc9da4f709886c84ae4bc4ddaf0e093188d66df4dc820"
-
 [[package]]
 name = "async-trait"
 version = "0.1.50"
@@ -298,7 +301,7 @@ version = "2.33.3"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "37e58ac78573c40708d45522f0d80fa2f01cc4f9b4e2bf749807255454312002"
 dependencies = [
- "ansi_term",
+ "ansi_term 0.11.0",
 "atty",
 "bitflags",
 "strsim",
@@ -387,26 +390,6 @@ dependencies = [
 "rustc_version",
 ]

-[[package]]
-name = "crossbeam-channel"
-version = "0.5.1"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "06ed27e177f16d65f0f0c22a213e17c696ace5dd64b14258b52f9417ccb52db4"
-dependencies = [
- "cfg-if 1.0.0",
- "crossbeam-utils",
-]
-
-[[package]]
-name = "crossbeam-utils"
-version = "0.8.5"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "d82cfc11ce7f2c3faef78d8a684447b40d503d9681acebed6cb728d45940c4db"
-dependencies = [
- "cfg-if 1.0.0",
- "lazy_static",
-]
-
 [[package]]
 name = "crypto-mac"
 version = "0.10.0"
@@ -445,16 +428,6 @@ dependencies = [
 "dirs-sys",
 ]

-[[package]]
-name = "dirs-next"
-version = "2.0.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "b98cf8ebf19c3d1b223e151f99a4f9f0690dca41414773390fc824184ac833e1"
-dependencies = [
- "cfg-if 1.0.0",
- "dirs-sys-next",
-]
-
 [[package]]
 name = "dirs-sys"
 version = "0.3.6"
@@ -466,17 +439,6 @@ dependencies = [
 "winapi",
 ]

-[[package]]
-name = "dirs-sys-next"
-version = "0.1.2"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "4ebda144c4fe02d1f7ea1a7d9641b6fc6b580adcfa024ae48797ecdeb6825b4d"
-dependencies = [
- "libc",
- "redox_users",
- "winapi",
-]
-
 [[package]]
 name = "dlv-list"
 version = "0.2.3"
@@ -956,6 +918,15 @@ dependencies = [
 "cfg-if 1.0.0",
 ]

+[[package]]
+name = "matchers"
+version = "0.0.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f099785f7595cc4b4553a174ce30dd7589ef93391ff414dbb67f62392b9e0ce1"
+dependencies = [
+ "regex-automata",
+]
+
 [[package]]
 name = "matches"
 version = "0.1.8"
@@ -1220,10 +1191,12 @@ dependencies = [
 "scopeguard",
 "serde",
 "serde_json",
+ "signal-hook",
 "tar",
 "thiserror",
 "tokio",
 "toml",
+ "tracing",
 "workspace_hack",
 "zenith_metrics",
 "zenith_utils",
@@ -1531,6 +1504,15 @@ dependencies = [
 "regex-syntax",
 ]

+[[package]]
+name = "regex-automata"
+version = "0.1.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132"
+dependencies = [
+ "regex-syntax",
+]
+
 [[package]]
 name = "regex-syntax"
 version = "0.6.25"
@@ -1689,12 +1671,6 @@ dependencies = [
 "webpki",
 ]

-[[package]]
-name = "rustversion"
-version = "1.0.5"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "61b3909d758bb75c79f23d4736fac9433868679d3ad2ea7a61e3c25cfda9a088"
-
 [[package]]
 name = "ryu"
 version = "1.0.5"
@@ -1852,12 +1828,32 @@ dependencies = [
 "opaque-debug",
 ]

+[[package]]
+name = "sharded-slab"
+version = "0.1.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "740223c51853f3145fe7c90360d2d4232f2b62e3449489c207eccde818979982"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "shlex"
 version = "1.0.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "42a568c8f2cd051a4d283bd6eb0343ac214c1b0f1ac19f93e1175b2dee38c73d"

+[[package]]
+name = "signal-hook"
+version = "0.3.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "9c98891d737e271a2954825ef19e46bd16bdb98e2746f2eec4f7a4ef7946efd1"
+dependencies = [
+ "cc",
+ "libc",
+ "signal-hook-registry",
+]
+
 [[package]]
 name = "signal-hook-registry"
 version = "1.4.0"
@@ -1890,59 +1886,6 @@ version = "0.4.3"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "f173ac3d1a7e3b28003f40de0b5ce7fe2710f9b9dc3fc38664cebee46b3b6527"

-[[package]]
-name = "slog"
-version = "2.7.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "8347046d4ebd943127157b94d63abb990fcf729dc4e9978927fdf4ac3c998d06"
-
-[[package]]
-name = "slog-async"
-version = "2.6.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c60813879f820c85dbc4eabf3269befe374591289019775898d56a81a804fbdc"
-dependencies = [
- "crossbeam-channel",
- "slog",
- "take_mut",
- "thread_local",
-]
-
-[[package]]
-name = "slog-scope"
-version = "4.4.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "2f95a4b4c3274cd2869549da82b57ccc930859bdbf5bcea0424bc5f140b3c786"
-dependencies = [
- "arc-swap",
- "lazy_static",
- "slog",
-]
-
-[[package]]
-name = "slog-stdlog"
-version = "4.1.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "8228ab7302adbf4fcb37e66f3cda78003feb521e7fd9e3847ec117a7784d0f5a"
-dependencies = [
- "log",
- "slog",
- "slog-scope",
-]
-
-[[package]]
-name = "slog-term"
-version = "2.8.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "95c1e7e5aab61ced6006149ea772770b84a0d16ce0f7885def313e4829946d76"
-dependencies = [
- "atty",
- "chrono",
- "slog",
- "term",
- "thread_local",
-]
-
 [[package]]
 name = "smallvec"
 version = "1.6.1"
@@ -1998,12 +1941,6 @@ dependencies = [
 "unicode-xid",
 ]

-[[package]]
-name = "take_mut"
-version = "0.2.2"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "f764005d11ee5f36500a149ace24e00e3da98b0158b3e2d53a7495660d3f4d60"
-
 [[package]]
 name = "tap"
 version = "1.0.1"
@@ -2035,17 +1972,6 @@ dependencies = [
 "winapi",
 ]

-[[package]]
-name = "term"
-version = "0.7.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c59df8ac95d96ff9bede18eb7300b0fda5e5d8d90960e76f8e14ae765eedbf1f"
-dependencies = [
- "dirs-next",
- "rustversion",
- "winapi",
-]
-
 [[package]]
 name = "termcolor"
 version = "1.1.2"
@@ -2223,24 +2149,79 @@ checksum = "360dfd1d6d30e05fda32ace2c8c70e9c0a9da713275777f5a4dbb8a1893930c6"

 [[package]]
 name = "tracing"
-version = "0.1.26"
+version = "0.1.29"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "09adeb8c97449311ccd28a427f96fb563e7fd31aabf994189879d9da2394b89d"
+checksum = "375a639232caf30edfc78e8d89b2d4c375515393e7af7e16f01cd96917fb2105"
 dependencies = [
 "cfg-if 1.0.0",
 "pin-project-lite",
+ "tracing-attributes",
 "tracing-core",
 ]

 [[package]]
-name = "tracing-core"
+name = "tracing-attributes"
 version = "0.1.18"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "a9ff14f98b1a4b289c6248a023c1c2fa1491062964e9fed67ab29c4e4da4a052"
+checksum = "f4f480b8f81512e825f337ad51e94c1eb5d3bbdf2b363dcd01e2b19a9ffe3f8e"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn",
+]
+
+[[package]]
+name = "tracing-core"
+version = "0.1.21"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "1f4ed65637b8390770814083d20756f87bfa2c21bf2f110babdc5438351746e4"
 dependencies = [
 "lazy_static",
 ]

+[[package]]
+name = "tracing-log"
+version = "0.1.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "a6923477a48e41c1951f1999ef8bb5a3023eb723ceadafe78ffb65dc366761e3"
+dependencies = [
+ "lazy_static",
+ "log",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-serde"
+version = "0.1.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "fb65ea441fbb84f9f6748fd496cf7f63ec9af5bca94dd86456978d055e8eb28b"
+dependencies = [
+ "serde",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.2.25"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "0e0d2eaa99c3c2e41547cfa109e910a68ea03823cccad4a0525dcbc9b01e8c71"
+dependencies = [
+ "ansi_term 0.12.1",
+ "chrono",
+ "lazy_static",
+ "matchers",
+ "regex",
+ "serde",
+ "serde_json",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "tracing",
+ "tracing-core",
+ "tracing-log",
+ "tracing-serde",
+]
+
 [[package]]
 name = "try-lock"
 version = "0.2.3"
@@ -2345,6 +2326,7 @@ dependencies = [
 "fs2",
 "hex",
 "humantime",
+ "hyper",
 "lazy_static",
 "log",
 "pageserver",
@@ -2352,6 +2334,7 @@ dependencies = [
 "postgres-protocol",
 "postgres_ffi",
 "regex",
+ "routerify",
 "rust-s3",
 "serde",
 "serde_json",
@@ -2592,7 +2575,6 @@ dependencies = [
 "bincode",
 "byteorder",
 "bytes",
- "crossbeam-utils",
 "hex",
 "hex-literal",
 "hyper",
@@ -2606,14 +2588,12 @@ dependencies = [
 "rustls-split",
 "serde",
 "serde_json",
- "slog",
- "slog-async",
- "slog-scope",
- "slog-stdlog",
- "slog-term",
 "tempfile",
 "thiserror",
 "tokio",
+ "tracing",
+ "tracing-log",
+ "tracing-subscriber",
 "webpki",
 "workspace_hack",
 "zenith_metrics",
@@ -37,7 +37,9 @@ RUN apt-get update && apt-get -yq install libreadline-dev libseccomp-dev openssl
    mkdir zenith_install

 COPY --from=build /zenith/target/release/pageserver /usr/local/bin
-COPY --from=build /zenith/target/release/wal_acceptor /usr/local/bin
+COPY --from=build /zenith/target/release/safekeeper /usr/local/bin
+# TODO: temporary alias for compatibility, see https://github.com/zenithdb/zenith/pull/740
+RUN ln -s /usr/local/bin/safekeeper /usr/local/bin/wal_acceptor
 COPY --from=build /zenith/target/release/proxy /usr/local/bin
 COPY --from=pg-build /zenith/tmp_install postgres_install
 COPY docker-entrypoint.sh /docker-entrypoint.sh
@@ -81,7 +81,9 @@ FROM alpine:3.13
 RUN apk add --update openssl build-base libseccomp-dev
 RUN apk --no-cache --update --repository https://dl-cdn.alpinelinux.org/alpine/edge/testing add rocksdb
 COPY --from=build /zenith/target/release/pageserver /usr/local/bin
-COPY --from=build /zenith/target/release/wal_acceptor /usr/local/bin
+COPY --from=build /zenith/target/release/safekeeper /usr/local/bin
+# TODO: temporary alias for compatibility, see https://github.com/zenithdb/zenith/pull/740
+RUN ln -s /usr/local/bin/safekeeper /usr/local/bin/wal_acceptor
 COPY --from=build /zenith/target/release/proxy /usr/local/bin
 COPY --from=pg-build /zenith/tmp_install /usr/local
 COPY docker-entrypoint.sh /docker-entrypoint.sh
@@ -10,32 +10,43 @@ endif
 # We differentiate between release / debug build types using the BUILD_TYPE
 # environment variable.
 #
+BUILD_TYPE ?= debug
 ifeq ($(BUILD_TYPE),release)
 	PG_CONFIGURE_OPTS = --enable-debug
-	PG_CFLAGS = -O2 -g3 ${CFLAGS}
-else
+	PG_CFLAGS = -O2 -g3 $(CFLAGS)
+	# Unfortunately, `--profile=...` is a nightly feature
+	CARGO_BUILD_FLAGS += --release
+else ifeq ($(BUILD_TYPE),debug)
 	PG_CONFIGURE_OPTS = --enable-debug --enable-cassert --enable-depend
-	PG_CFLAGS = -O0 -g3 ${CFLAGS}
+	PG_CFLAGS = -O0 -g3 $(CFLAGS)
+else
+$(error Bad build type `$(BUILD_TYPE)', see Makefile for options)
 endif

+# Choose whether we should be silent or verbose
+CARGO_BUILD_FLAGS += --$(if $(filter s,$(MAKEFLAGS)),quiet,verbose)
+# Fix for a corner case when make doesn't pass a jobserver
+CARGO_BUILD_FLAGS += $(filter -j1,$(MAKEFLAGS))
+
+# This option has a side effect of passing make jobserver to cargo.
+# However, we shouldn't do this if `make -n` (--dry-run) has been asked.
+CARGO_CMD_PREFIX += $(if $(filter n,$(MAKEFLAGS)),,+)
+# Force cargo not to print progress bar
+CARGO_CMD_PREFIX += CARGO_TERM_PROGRESS_WHEN=never CI=1
+
 #
 # Top level Makefile to build Zenith and PostgreSQL
 #
+.PHONY: all
 all: zenith postgres

-# We don't want to run 'cargo build' in parallel with the postgres build,
-# because interleaving cargo build output with postgres build output looks
-# confusing. Also, 'cargo build' is parallel on its own, so it would be too
-# much parallelism. (Recursive invocation of postgres target still gets any
-# '-j' flag from the command line, so 'make -j' is still useful.)
-.NOTPARALLEL:
-
 ### Zenith Rust bits
 #
 # The 'postgres_ffi' depends on the Postgres headers.
 .PHONY: zenith
 zenith: postgres-headers
-	cargo build
+	+@echo "Compiling Zenith"
+	$(CARGO_CMD_PREFIX) cargo build $(CARGO_BUILD_FLAGS)

 ### PostgreSQL parts
 tmp_install/build/config.status:
@@ -57,10 +68,10 @@ postgres-headers: postgres-configure
 	+@echo "Installing PostgreSQL headers"
 	$(MAKE) -C tmp_install/build/src/include MAKELEVEL=0 install

-
 # Compile and install PostgreSQL and contrib/zenith
 .PHONY: postgres
-postgres: postgres-configure
+postgres: postgres-configure \
+		  postgres-headers # to prevent `make install` conflicts with zenith's `postgres-headers`
 	+@echo "Compiling PostgreSQL"
 	$(MAKE) -C tmp_install/build MAKELEVEL=0 install
 	+@echo "Compiling contrib/zenith"
@@ -68,18 +79,21 @@ postgres: postgres-configure
 	+@echo "Compiling contrib/zenith_test_utils"
 	$(MAKE) -C tmp_install/build/contrib/zenith_test_utils install

+.PHONY: postgres-clean
 postgres-clean:
 	$(MAKE) -C tmp_install/build MAKELEVEL=0 clean

 # This doesn't remove the effects of 'configure'.
+.PHONY: clean
 clean:
-	cd tmp_install/build && ${MAKE} clean
-	cargo clean
+	cd tmp_install/build && $(MAKE) clean
+	$(CARGO_CMD_PREFIX) cargo clean

 # This removes everything
+.PHONY: distclean
 distclean:
 	rm -rf tmp_install
-	cargo clean
+	$(CARGO_CMD_PREFIX) cargo clean

 .PHONY: fmt
 fmt:
@@ -85,20 +85,20 @@ impl PageServerNode {
            ),
            env: env.clone(),
            http_client: Client::new(),
-            http_base_url: format!("http://localhost:{}/v1", env.pageserver_http_port),
+            http_base_url: format!("http://127.0.0.1:{}/v1", env.pageserver_http_port),
        }
    }

    fn pageserver_connection_config(password: &str, port: u16) -> Config {
-        format!("postgresql://no_user:{}@localhost:{}/no_db", password, port)
+        format!("postgresql://no_user:{}@127.0.0.1:{}/no_db", password, port)
            .parse()
            .unwrap()
    }

    pub fn init(&self, create_tenant: Option<&str>, enable_auth: bool) -> anyhow::Result<()> {
        let mut cmd = Command::new(self.env.pageserver_bin()?);
-        let listen_pg = format!("localhost:{}", self.env.pageserver_pg_port);
-        let listen_http = format!("localhost:{}", self.env.pageserver_http_port);
+        let listen_pg = format!("127.0.0.1:{}", self.env.pageserver_pg_port);
+        let listen_http = format!("127.0.0.1:{}", self.env.pageserver_http_port);
        let mut args = vec![
            "--init",
            "-D",
@@ -199,23 +199,45 @@ impl PageServerNode {
        bail!("pageserver failed to start in {} seconds", RETRIES);
    }

-    pub fn stop(&self) -> anyhow::Result<()> {
+    pub fn stop(&self, immediate: bool) -> anyhow::Result<()> {
        let pid = read_pidfile(&self.pid_file())?;
        let pid = Pid::from_raw(pid);
-        if kill(pid, Signal::SIGTERM).is_err() {
-            bail!("Failed to kill pageserver with pid {}", pid);
+        if immediate {
+            println!("Stop pageserver immediately");
+            if kill(pid, Signal::SIGQUIT).is_err() {
+                bail!("Failed to kill pageserver with pid {}", pid);
+            }
+        } else {
+            println!("Stop pageserver gracefully");
+            if kill(pid, Signal::SIGTERM).is_err() {
+                bail!("Failed to stop pageserver with pid {}", pid);
+            }
        }

-        // wait for pageserver stop
        let address = connection_address(&self.pg_connection_config);
-        for _ in 0..5 {
-            let stream = TcpStream::connect(&address);
-            thread::sleep(Duration::from_secs(1));
-            if let Err(_e) = stream {
-                println!("Pageserver stopped");
-                return Ok(());
+
+        // TODO Remove this "timeout" and handle it on caller side instead.
+        // Shutting down may take a long time,
+        // if pageserver checkpoints a lot of data
+        for _ in 0..100 {
+            if let Err(_e) = TcpStream::connect(&address) {
+                println!("Pageserver stopped receiving connections");
+
+                //Now check status
+                match self.check_status() {
+                    Ok(_) => {
+                        println!("Pageserver status is OK. Wait a bit.");
+                        thread::sleep(Duration::from_secs(1));
+                    }
+                    Err(err) => {
+                        println!("Pageserver status is: {}", err);
+                        return Ok(());
+                    }
+                }
+            } else {
+                println!("Pageserver still receives connections");
+                thread::sleep(Duration::from_secs(1));
            }
-            println!("Stopping pageserver on {}", address);
        }

        bail!("Failed to stop pageserver with pid {}", pid);
@@ -313,8 +335,9 @@ impl PageServerNode {

 impl Drop for PageServerNode {
    fn drop(&mut self) {
+        // TODO Looks like this flag is never set
        if self.kill_on_exit {
-            let _ = self.stop();
+            let _ = self.stop(true);
        }
    }
 }
@@ -7,7 +7,7 @@ if [ "$1" = 'pageserver' ]; then
        pageserver --init -D /data --postgres-distrib /usr/local
    fi
    echo "Staring pageserver at 0.0.0.0:6400"
-    pageserver -l 0.0.0.0:6400 -D /data
+    pageserver -l 0.0.0.0:6400 --listen-http 0.0.0.0:9898 -D /data
 else
    "$@"
 fi
@@ -4,7 +4,7 @@

 Currently we build two main images:

- [zenithdb/zenith](https://hub.docker.com/repository/docker/zenithdb/zenith) — image with pre-built `pageserver`, `wal_acceptor` and `proxy` binaries and all the required runtime dependencies. Built from [/Dockerfile](/Dockerfile).
+- [zenithdb/zenith](https://hub.docker.com/repository/docker/zenithdb/zenith) — image with pre-built `pageserver`, `safekeeper` and `proxy` binaries and all the required runtime dependencies. Built from [/Dockerfile](/Dockerfile).
 - [zenithdb/compute-node](https://hub.docker.com/repository/docker/zenithdb/compute-node) — compute node image with pre-built Postgres binaries from [zenithdb/postgres](https://github.com/zenithdb/postgres).

 And two intermediate images used either to reduce build time or to deliver some additional binary tools from other repos:
@@ -56,4 +56,4 @@ Tenant id is passed to postgres via GUC the same way as the timeline. Tenant id

 ### Safety

-For now particular tenant can only appear on a particular pageserver. Set of WAL acceptors are also pinned to particular (tenantid, timeline) pair so there can only be one writer for particular (tenantid, timeline).
+For now particular tenant can only appear on a particular pageserver. Set of safekeepers are also pinned to particular (tenantid, timeline) pair so there can only be one writer for particular (tenantid, timeline).
@@ -17,7 +17,7 @@ lazy_static = "1.4.0"
 log = "0.4.14"
 clap = "2.33.0"
 daemonize = "0.4.1"
-tokio = { version = "1.11", features = ["process", "macros", "fs"] }
+tokio = { version = "1.11", features = ["process", "macros", "fs", "rt"] }
 postgres-types = { git = "https://github.com/zenithdb/rust-postgres.git", rev="9eb0dbfbeb6a6c1b79099b9f7ae4a8c021877858" }
 postgres-protocol = { git = "https://github.com/zenithdb/rust-postgres.git", rev="9eb0dbfbeb6a6c1b79099b9f7ae4a8c021877858" }
 postgres = { git = "https://github.com/zenithdb/rust-postgres.git", rev="9eb0dbfbeb6a6c1b79099b9f7ae4a8c021877858" }
@@ -35,6 +35,8 @@ scopeguard = "1.1.0"
 rust-s3 = { version = "0.27.0-rc4", features = ["no-verify-ssl"] }
 async-trait = "0.1"
 const_format = "0.2.21"
+tracing = "0.1.27"
+signal-hook = {version = "0.3.10", features = ["extended-siginfo"] }

 postgres_ffi = { path = "../postgres_ffi" }
 zenith_metrics = { path = "../zenith_metrics" }
@@ -31,7 +31,7 @@ use zenith_utils::lsn::Lsn;
 pub struct Basebackup<'a> {
    ar: Builder<&'a mut dyn Write>,
    timeline: &'a Arc<dyn Timeline>,
-    lsn: Lsn,
+    pub lsn: Lsn,
    prev_record_lsn: Lsn,
 }

@@ -97,7 +97,6 @@ impl<'a> Basebackup<'a> {
    pub fn send_tarball(&mut self) -> anyhow::Result<()> {
        // Create pgdata subdirs structure
        for dir in pg_constants::PGDATA_SUBDIRS.iter() {
-            info!("send subdir {:?}", *dir);
            let header = new_tar_header_dir(*dir)?;
            self.ar.append(&header, &mut io::empty())?;
        }
@@ -2,7 +2,6 @@
 // Main entry point for the Page Server executable
 //

-use log::*;
 use pageserver::defaults::*;
 use serde::{Deserialize, Serialize};
 use std::{
@@ -12,9 +11,19 @@ use std::{
    str::FromStr,
    thread,
 };
+use tracing::*;
 use zenith_utils::{auth::JwtAuth, logging, postgres_backend::AuthType};

 use anyhow::{bail, ensure, Context, Result};
+use signal_hook::consts::signal::*;
+use signal_hook::consts::TERM_SIGNALS;
+use signal_hook::flag;
+use signal_hook::iterator::exfiltrator::WithOrigin;
+use signal_hook::iterator::SignalsInfo;
+use std::process::exit;
+use std::sync::atomic::AtomicBool;
+use std::sync::Arc;
+
 use clap::{App, Arg, ArgMatches};
 use daemonize::Daemonize;

@@ -28,6 +37,7 @@ use pageserver::{
    RelishStorageKind, S3Config, LOG_FILE_NAME,
 };
 use zenith_utils::http::endpoint;
+use zenith_utils::postgres_backend;

 use const_format::formatcp;

@@ -447,7 +457,18 @@ fn main() -> Result<()> {

 fn start_pageserver(conf: &'static PageServerConf) -> Result<()> {
    // Initialize logger
-    let (_scope_guard, log_file) = logging::init(LOG_FILE_NAME, conf.daemonize)?;
+    let log_file = logging::init(LOG_FILE_NAME, conf.daemonize)?;
+
+    let term_now = Arc::new(AtomicBool::new(false));
+    for sig in TERM_SIGNALS {
+        // When terminated by a second term signal, exit with exit code 1.
+        // This will do nothing the first time (because term_now is false).
+        flag::register_conditional_shutdown(*sig, 1, Arc::clone(&term_now))?;
+        // But this will "arm" the above for the second time, by setting it to true.
+        // The order of registering these is important, if you put this one first, it will
+        // first arm and then terminate ‒ all in the first round.
+        flag::register(*sig, Arc::clone(&term_now))?;
+    }

    // TODO: Check that it looks like a valid repository before going further

@@ -480,7 +501,7 @@ fn start_pageserver(conf: &'static PageServerConf) -> Result<()> {

        match daemonize.start() {
            Ok(_) => info!("Success, daemonized"),
-            Err(e) => error!("could not daemonize: {:#}", e),
+            Err(err) => error!(%err, "could not daemonize"),
        }
    }

@@ -525,13 +546,42 @@ fn start_pageserver(conf: &'static PageServerConf) -> Result<()> {
            page_service::thread_main(conf, auth, pageserver_listener, conf.auth_type)
        })?;

-    join_handles.push(page_service_thread);
+    for info in SignalsInfo::<WithOrigin>::new(TERM_SIGNALS)?.into_iter() {
+        match info.signal {
+            SIGQUIT => {
+                info!("Got SIGQUIT. Terminate pageserver in immediate shutdown mode");
+                exit(111);
+            }
+            SIGTERM => {
+                info!("Got SIGINT/SIGTERM. Terminate gracefully in fast shutdown mode");
+                // Terminate postgres backends
+                postgres_backend::set_pgbackend_shutdown_requested();
+                // Stop all tenants and flush their data
+                tenant_mgr::shutdown_all_tenants()?;
+                // Wait for pageservice thread to complete the job
+                page_service_thread
+                    .join()
+                    .expect("thread panicked")
+                    .expect("thread exited with an error");

-    for handle in join_handles.into_iter() {
-        handle
-            .join()
-            .expect("thread panicked")
-            .expect("thread exited with an error")
+                // Shut down http router
+                endpoint::shutdown();
+
+                // Wait for all threads
+                for handle in join_handles.into_iter() {
+                    handle
+                        .join()
+                        .expect("thread panicked")
+                        .expect("thread exited with an error");
+                }
+                info!("Pageserver shut down successfully completed");
+                exit(0);
+            }
+            _ => {
+                debug!("Unknown signal.");
+            }
+        }
    }
+
    Ok(())
 }
@@ -14,12 +14,12 @@ use std::{
    str::FromStr,
    sync::Arc,
 };
-use zenith_utils::zid::{ZTenantId, ZTimelineId};
+use tracing::*;

-use log::*;
 use zenith_utils::crashsafe_dir;
 use zenith_utils::logging;
 use zenith_utils::lsn::Lsn;
+use zenith_utils::zid::{ZTenantId, ZTimelineId};

 use crate::tenant_mgr;
 use crate::walredo::WalRedoManager;
@@ -100,7 +100,7 @@ pub struct PointInTime {
 pub fn init_pageserver(conf: &'static PageServerConf, create_tenant: Option<&str>) -> Result<()> {
    // Initialize logger
    // use true as daemonize parameter because otherwise we pollute zenith cli output with a few pages long output of info messages
-    let (_scope_guard, _log_file) = logging::init(LOG_FILE_NAME, true)?;
+    let _log_file = logging::init(LOG_FILE_NAME, true)?;

    // We don't use the real WAL redo manager, because we don't want to spawn the WAL redo
    // process during repository initialization.
@@ -176,13 +176,16 @@ fn get_lsn_from_controlfile(path: &Path) -> Result<Lsn> {
 // to get bootstrap data for timeline initialization.
 //
 fn run_initdb(conf: &'static PageServerConf, initdbpath: &Path) -> Result<()> {
-    info!("running initdb... ");
+    info!("running initdb in {}... ", initdbpath.display());

    let initdb_path = conf.pg_bin_dir().join("initdb");
    let initdb_output = Command::new(initdb_path)
        .args(&["-D", initdbpath.to_str().unwrap()])
        .args(&["-U", &conf.superuser])
        .arg("--no-instructions")
+        // This is only used for a temporary installation that is deleted shortly after,
+        // so no need to fsync it
+        .arg("--no-sync")
        .env_clear()
        .env("LD_LIBRARY_PATH", conf.pg_lib_dir().to_str().unwrap())
        .env("DYLD_LIBRARY_PATH", conf.pg_lib_dir().to_str().unwrap())
@@ -195,7 +198,6 @@ fn run_initdb(conf: &'static PageServerConf, initdbpath: &Path) -> Result<()> {
            String::from_utf8_lossy(&initdb_output.stderr)
        );
    }
-    info!("initdb succeeded");

    Ok(())
 }
@@ -210,6 +212,8 @@ fn bootstrap_timeline(
    tli: ZTimelineId,
    repo: &dyn Repository,
 ) -> Result<()> {
+    let _enter = info_span!("bootstrapping", timeline = %tli, tenant = %tenantid).entered();
+
    let initdb_path = conf.tenant_path(&tenantid).join("tmp");

    // Init temporarily repo to get bootstrap data
@@ -218,14 +222,12 @@ fn bootstrap_timeline(

    let lsn = get_lsn_from_controlfile(&pgdata_path)?.align();

-    info!("bootstrap_timeline {:?} at lsn {}", pgdata_path, lsn);
-
    // Import the contents of the data directory at the initial checkpoint
    // LSN, and any WAL after that.
    let timeline = repo.create_empty_timeline(tli)?;
    restore_local_repo::import_timeline_from_postgres_datadir(
        &pgdata_path,
-        timeline.as_ref(),
+        timeline.writer().as_ref(),
        lsn,
    )?;
    timeline.checkpoint()?;
@@ -1,4 +1,3 @@
-use std::str::FromStr;
 use std::sync::Arc;

 use anyhow::Result;
@@ -6,6 +5,7 @@ use hyper::header;
 use hyper::StatusCode;
 use hyper::{Body, Request, Response, Uri};
 use routerify::{ext::RequestExt, RouterBuilder};
+use tracing::*;
 use zenith_utils::auth::JwtAuth;
 use zenith_utils::http::endpoint::attach_openapi_ui;
 use zenith_utils::http::endpoint::auth_middleware;
@@ -15,6 +15,8 @@ use zenith_utils::http::{
    endpoint,
    error::HttpErrorBody,
    json::{json_request, json_response},
+    request::get_request_param,
+    request::parse_request_param,
 };

 use super::models::BranchCreateRequest;
@@ -56,33 +58,6 @@ fn get_config(request: &Request<Body>) -> &'static PageServerConf {
    get_state(request).conf
 }

-fn get_request_param<'a>(
-    request: &'a Request<Body>,
-    param_name: &str,
-) -> Result<&'a str, ApiError> {
-    match request.param(param_name) {
-        Some(arg) => Ok(arg),
-        None => {
-            return Err(ApiError::BadRequest(format!(
-                "no {} specified in path param",
-                param_name
-            )))
-        }
-    }
-}
-
-fn parse_request_param<T: FromStr>(
-    request: &Request<Body>,
-    param_name: &str,
-) -> Result<T, ApiError> {
-    match get_request_param(request, param_name)?.parse() {
-        Ok(v) => Ok(v),
-        Err(_) => Err(ApiError::BadRequest(
-            "failed to parse tenant id".to_string(),
-        )),
-    }
-}
-
 // healthcheck handler
 async fn status_handler(_: Request<Body>) -> Result<Response<Body>, ApiError> {
    Ok(Response::builder()
@@ -98,6 +73,7 @@ async fn branch_create_handler(mut request: Request<Body>) -> Result<Response<Bo
    check_permission(&request, Some(request_data.tenant_id))?;

    let response_data = tokio::task::spawn_blocking(move || {
+        let _enter = info_span!("/branch_create", name = %request_data.name, tenant = %request_data.tenant_id, startpoint=%request_data.start_point).entered();
        branches::create_branch(
            get_config(&request),
            &request_data.name,
@@ -116,6 +92,7 @@ async fn branch_list_handler(request: Request<Body>) -> Result<Response<Body>, A
    check_permission(&request, Some(tenantid))?;

    let response_data = tokio::task::spawn_blocking(move || {
+        let _enter = info_span!("branch_list", tenant = %tenantid).entered();
        crate::branches::get_branches(get_config(&request), &tenantid)
    })
    .await
@@ -126,11 +103,12 @@ async fn branch_list_handler(request: Request<Body>) -> Result<Response<Body>, A
 // TODO add to swagger
 async fn branch_detail_handler(request: Request<Body>) -> Result<Response<Body>, ApiError> {
    let tenantid: ZTenantId = parse_request_param(&request, "tenant_id")?;
-    let branch_name: &str = get_request_param(&request, "branch_name")?;
+    let branch_name: String = get_request_param(&request, "branch_name")?.to_string();
    let conf = get_state(&request).conf;
-    let path = conf.branch_path(branch_name, &tenantid);
+    let path = conf.branch_path(&branch_name, &tenantid);

    let response_data = tokio::task::spawn_blocking(move || {
+        let _enter = info_span!("branch_detail", tenant = %tenantid, branch=%branch_name).entered();
        let repo = tenant_mgr::get_repository_for_tenant(tenantid)?;
        BranchInfo::from_path(path, conf, &tenantid, &repo)
    })
@@ -144,10 +122,13 @@ async fn tenant_list_handler(request: Request<Body>) -> Result<Response<Body>, A
    // check for management permission
    check_permission(&request, None)?;

-    let response_data =
-        tokio::task::spawn_blocking(move || crate::branches::get_tenants(get_config(&request)))
-            .await
-            .map_err(ApiError::from_err)??;
+    let response_data = tokio::task::spawn_blocking(move || {
+        let _enter = info_span!("tenant_list").entered();
+        crate::branches::get_tenants(get_config(&request))
+    })
+    .await
+    .map_err(ApiError::from_err)??;
+
    Ok(json_response(StatusCode::OK, response_data)?)
 }

@@ -158,6 +139,7 @@ async fn tenant_create_handler(mut request: Request<Body>) -> Result<Response<Bo
    let request_data: TenantCreateRequest = json_request(&mut request).await?;

    let response_data = tokio::task::spawn_blocking(move || {
+        let _enter = info_span!("tenant_create", tenant = %request_data.tenant_id).entered();
        tenant_mgr::create_repository_for_tenant(get_config(&request), request_data.tenant_id)
    })
    .await
@@ -15,10 +15,9 @@ use anyhow::{anyhow, bail, ensure, Context, Result};
 use bookfile::Book;
 use bytes::Bytes;
 use lazy_static::lazy_static;
-use log::*;
 use postgres_ffi::pg_constants::BLCKSZ;
 use serde::{Deserialize, Serialize};
-use zenith_utils::batch_fsync::batch_fsync;
+use tracing::*;

 use std::collections::hash_map::Entry;
 use std::collections::HashMap;
@@ -27,16 +26,18 @@ use std::convert::TryInto;
 use std::fs;
 use std::fs::{File, OpenOptions};
 use std::io::Write;
-use std::ops::Bound::Included;
+use std::ops::{Bound::Included, Deref};
 use std::path::{Path, PathBuf};
 use std::sync::atomic::{AtomicUsize, Ordering};
 use std::sync::{Arc, Mutex, MutexGuard};
+use std::thread::JoinHandle;
 use std::time::{Duration, Instant};

-use crate::layered_repository::inmemory_layer::FreezeLayers;
 use crate::relish::*;
 use crate::relish_storage::schedule_timeline_upload;
-use crate::repository::{GcResult, Repository, Timeline, WALRecord};
+use crate::repository::{GcResult, Repository, Timeline, TimelineWriter, WALRecord};
+use crate::tenant_mgr;
+use crate::walreceiver;
 use crate::walreceiver::IS_WAL_RECEIVER;
 use crate::walredo::WalRedoManager;
 use crate::PageServerConf;
@@ -70,8 +71,6 @@ use storage_layer::{
    Layer, PageReconstructData, PageReconstructResult, SegmentTag, RELISH_SEG_SIZE,
 };

-use self::inmemory_layer::{NonWriteableError, WriteResult};
-
 static ZERO_PAGE: Bytes = Bytes::from_static(&[0u8; 8192]);

 // Timeout when waiting for WAL receiver to catch up to an LSN given in a GetPage@LSN call.
@@ -216,6 +215,23 @@ impl Repository for LayeredRepository {
                self.gc_iteration_internal(target_timelineid, horizon, checkpoint_before_gc)
            })
    }
+
+    // Wait for all threads to complete and persist repository data before pageserver shutdown.
+    fn shutdown(&self) -> Result<()> {
+        trace!("LayeredRepository shutdown for tenant {}", self.tenantid);
+
+        let timelines = self.timelines.lock().unwrap();
+        for (timelineid, timeline) in timelines.iter() {
+            walreceiver::stop_wal_receiver(*timelineid);
+            // Wait for syncing data to disk
+            trace!("repo shutdown. checkpoint timeline {}", timelineid);
+            timeline.checkpoint()?;
+
+            //TODO Wait for walredo process to shutdown too
+        }
+
+        Ok(())
+    }
 }

 /// Private functions
@@ -244,6 +260,10 @@ impl LayeredRepository {
                    None
                };

+                let _enter =
+                    info_span!("loading timeline", timeline = %timelineid, tenant = %self.tenantid)
+                        .entered();
+
                let mut timeline = LayeredTimeline::new(
                    self.conf,
                    metadata,
@@ -295,21 +315,24 @@ impl LayeredRepository {
    ///
    /// Launch the checkpointer thread in given repository.
    ///
-    pub fn launch_checkpointer_thread(conf: &'static PageServerConf, rc: Arc<LayeredRepository>) {
-        let _thread = std::thread::Builder::new()
+    pub fn launch_checkpointer_thread(
+        conf: &'static PageServerConf,
+        rc: Arc<LayeredRepository>,
+    ) -> JoinHandle<()> {
+        std::thread::Builder::new()
            .name("Checkpointer thread".into())
            .spawn(move || {
                // FIXME: relaunch it? Panic is not good.
                rc.checkpoint_loop(conf).expect("Checkpointer thread died");
            })
-            .unwrap();
+            .unwrap()
    }

    ///
    /// Checkpointer thread's main loop
    ///
    fn checkpoint_loop(&self, conf: &'static PageServerConf) -> Result<()> {
-        loop {
+        while !tenant_mgr::shutdown_requested() {
            std::thread::sleep(conf.checkpoint_period);
            info!("checkpointer thread for tenant {} waking up", self.tenantid);

@@ -317,44 +340,60 @@ impl LayeredRepository {
            // bytes of WAL since last checkpoint.
            {
                let timelines = self.timelines.lock().unwrap();
-                for (_timelineid, timeline) in timelines.iter() {
+                for (timelineid, timeline) in timelines.iter() {
+                    let _entered =
+                        info_span!("checkpoint", timeline = %timelineid, tenant = %self.tenantid)
+                            .entered();
+
                    STORAGE_TIME
                        .with_label_values(&["checkpoint_timed"])
                        .observe_closure_duration(|| {
-                            timeline.checkpoint_internal(conf.checkpoint_distance)
+                            timeline.checkpoint_internal(conf.checkpoint_distance, false)
                        })?
                }
                // release lock on 'timelines'
            }
        }
+        trace!("Checkpointer thread shut down");
+        Ok(())
    }

    ///
    /// Launch the GC thread in given repository.
    ///
-    pub fn launch_gc_thread(conf: &'static PageServerConf, rc: Arc<LayeredRepository>) {
-        let _thread = std::thread::Builder::new()
+    pub fn launch_gc_thread(
+        conf: &'static PageServerConf,
+        rc: Arc<LayeredRepository>,
+    ) -> JoinHandle<()> {
+        std::thread::Builder::new()
            .name("GC thread".into())
            .spawn(move || {
                // FIXME: relaunch it? Panic is not good.
                rc.gc_loop(conf).expect("GC thread died");
            })
-            .unwrap();
+            .unwrap()
    }

    ///
    /// GC thread's main loop
    ///
    fn gc_loop(&self, conf: &'static PageServerConf) -> Result<()> {
-        loop {
-            std::thread::sleep(conf.gc_period);
-            info!("gc thread for tenant {} waking up", self.tenantid);
-
+        while !tenant_mgr::shutdown_requested() {
            // Garbage collect old files that are not needed for PITR anymore
            if conf.gc_horizon > 0 {
                self.gc_iteration(None, conf.gc_horizon, false).unwrap();
            }
+
+            // TODO Write it in more adequate way using
+            // condvar.wait_timeout() or something
+            let mut sleep_time = conf.gc_period.as_secs();
+            while sleep_time > 0 && !tenant_mgr::shutdown_requested() {
+                sleep_time -= 1;
+                std::thread::sleep(Duration::from_secs(1));
+            }
+            info!("gc thread for tenant {} waking up", self.tenantid);
        }
+        Ok(())
    }

    /// Save timeline metadata to file
@@ -365,6 +404,7 @@ impl LayeredRepository {
        data: &TimelineMetadata,
        first_save: bool,
    ) -> Result<()> {
+        let _enter = info_span!("saving metadata").entered();
        let path = metadata_path(conf, timelineid, tenantid);
        // use OpenOptions to ensure file presence is consistent with first_save
        let mut file = OpenOptions::new()
@@ -372,8 +412,6 @@ impl LayeredRepository {
            .create_new(first_save)
            .open(&path)?;

-        info!("saving metadata {}", path.display());
-
        let mut metadata_bytes = TimelineMetadata::ser(data)?;

        assert!(metadata_bytes.len() <= METADATA_MAX_DATA_SIZE);
@@ -502,6 +540,10 @@ impl LayeredRepository {
        // Ok, we now know all the branch points.
        // Perform GC for each timeline.
        for timelineid in timelineids {
+            if tenant_mgr::shutdown_requested() {
+                return Ok(totals);
+            }
+
            // We have already loaded all timelines above
            // so this operation is just a quick map lookup.
            let timeline = self.get_timeline_locked(timelineid, &mut *timelines)?;
@@ -625,6 +667,13 @@ pub struct LayeredTimeline {

    /// If `true`, will backup its timeline files to remote storage after freezing.
    upload_relishes: bool,
+
+    /// Ensures layers aren't frozen by checkpointer between
+    /// [`LayeredTimeline::get_layer_for_write`] and layer reads.
+    /// Locked automatically by [`LayeredTimelineWriter`] and checkpointer.
+    /// Must always be acquired before the layer map/individual layer lock
+    /// to avoid deadlock.
+    write_lock: Mutex<()>,
 }

 /// Public interface functions
@@ -687,13 +736,7 @@ impl Timeline for LayeredTimeline {
            let segsize;
            if let Some((layer, lsn)) = self.get_layer_for_read(seg, lsn)? {
                segsize = layer.get_seg_size(lsn)?;
-                trace!(
-                    "get_seg_size: {} at {}/{} -> {}",
-                    seg,
-                    self.timelineid,
-                    lsn,
-                    segsize
-                );
+                trace!("get_seg_size: {} at {} -> {}", seg, lsn, segsize);
            } else {
                if segno == 0 {
                    return Ok(None);
@@ -795,138 +838,13 @@ impl Timeline for LayeredTimeline {
                result.insert(new_relish);
                trace!("List object {}", new_relish);
            } else {
-                trace!("Filter out droped object {}", new_relish);
+                trace!("Filtered out dropped object {}", new_relish);
            }
        }

        Ok(result)
    }

-    fn put_wal_record(&self, rel: RelishTag, blknum: u32, rec: WALRecord) -> Result<()> {
-        if !rel.is_blocky() && blknum != 0 {
-            bail!(
-                "invalid request for block {} for non-blocky relish {}",
-                blknum,
-                rel
-            );
-        }
-        ensure!(rec.lsn.is_aligned(), "unaligned record LSN");
-
-        let seg = SegmentTag::from_blknum(rel, blknum);
-        let delta_size = self.perform_write_op(seg, rec.lsn, |layer| {
-            layer.put_wal_record(blknum, rec.clone())
-        })?;
-        self.increase_current_logical_size(delta_size * BLCKSZ as u32);
-        Ok(())
-    }
-
-    fn put_truncation(&self, rel: RelishTag, lsn: Lsn, relsize: u32) -> anyhow::Result<()> {
-        if !rel.is_blocky() {
-            bail!("invalid truncation for non-blocky relish {}", rel);
-        }
-        ensure!(lsn.is_aligned(), "unaligned record LSN");
-
-        debug!("put_truncation: {} to {} blocks at {}", rel, relsize, lsn);
-
-        let oldsize = self
-            .get_relish_size(rel, self.get_last_record_lsn())?
-            .ok_or_else(|| {
-                anyhow!(
-                    "attempted to truncate non-existent relish {} at {}",
-                    rel,
-                    lsn
-                )
-            })?;
-
-        if oldsize <= relsize {
-            return Ok(());
-        }
-        let old_last_seg = (oldsize - 1) / RELISH_SEG_SIZE;
-
-        let last_remain_seg = if relsize == 0 {
-            0
-        } else {
-            (relsize - 1) / RELISH_SEG_SIZE
-        };
-
-        // Drop segments beyond the last remaining segment.
-        for remove_segno in (last_remain_seg + 1)..=old_last_seg {
-            let seg = SegmentTag {
-                rel,
-                segno: remove_segno,
-            };
-            self.perform_write_op(seg, lsn, |layer| layer.drop_segment(lsn))?;
-        }
-
-        // Truncate the last remaining segment to the specified size
-        if relsize == 0 || relsize % RELISH_SEG_SIZE != 0 {
-            let seg = SegmentTag {
-                rel,
-                segno: last_remain_seg,
-            };
-            self.perform_write_op(seg, lsn, |layer| {
-                layer.put_truncation(lsn, relsize % RELISH_SEG_SIZE)
-            })?;
-        }
-        self.decrease_current_logical_size((oldsize - relsize) * BLCKSZ as u32);
-        Ok(())
-    }
-
-    fn drop_relish(&self, rel: RelishTag, lsn: Lsn) -> Result<()> {
-        trace!("drop_segment: {} at {}", rel, lsn);
-
-        if rel.is_blocky() {
-            if let Some(oldsize) = self.get_relish_size(rel, self.get_last_record_lsn())? {
-                let old_last_seg = if oldsize == 0 {
-                    0
-                } else {
-                    (oldsize - 1) / RELISH_SEG_SIZE
-                };
-
-                // Drop all segments of the relish
-                for remove_segno in 0..=old_last_seg {
-                    let seg = SegmentTag {
-                        rel,
-                        segno: remove_segno,
-                    };
-                    self.perform_write_op(seg, lsn, |layer| layer.drop_segment(lsn))?;
-                }
-                self.decrease_current_logical_size(oldsize * BLCKSZ as u32);
-            } else {
-                warn!(
-                    "drop_segment called on non-existent relish {} at {}",
-                    rel, lsn
-                );
-            }
-        } else {
-            // TODO handle TwoPhase relishes
-            let seg = SegmentTag::from_blknum(rel, 0);
-            self.perform_write_op(seg, lsn, |layer| layer.drop_segment(lsn))?;
-        }
-
-        Ok(())
-    }
-
-    fn put_page_image(&self, rel: RelishTag, blknum: u32, lsn: Lsn, img: Bytes) -> Result<()> {
-        if !rel.is_blocky() && blknum != 0 {
-            bail!(
-                "invalid request for block {} for non-blocky relish {}",
-                blknum,
-                rel
-            );
-        }
-        ensure!(lsn.is_aligned(), "unaligned record LSN");
-
-        let seg = SegmentTag::from_blknum(rel, blknum);
-
-        let delta_size = self.perform_write_op(seg, lsn, |layer| {
-            layer.put_page_image(blknum, lsn, img.clone())
-        })?;
-
-        self.increase_current_logical_size(delta_size * BLCKSZ as u32);
-        Ok(())
-    }
-
    /// Public entry point for checkpoint(). All the logic is in the private
    /// checkpoint_internal function, this public facade just wraps it for
    /// metrics collection.
@@ -934,16 +852,7 @@ impl Timeline for LayeredTimeline {
        STORAGE_TIME
            .with_label_values(&["checkpoint_force"])
            //pass checkpoint_distance=0 to force checkpoint
-            .observe_closure_duration(|| self.checkpoint_internal(0))
-    }
-
-    ///
-    /// Remember the (end of) last valid WAL record remembered in the timeline.
-    ///
-    fn advance_last_record_lsn(&self, new_lsn: Lsn) {
-        assert!(new_lsn.is_aligned());
-
-        self.last_record_lsn.advance(new_lsn);
+            .observe_closure_duration(|| self.checkpoint_internal(0, true))
    }

    fn get_last_record_lsn(&self) -> Lsn {
@@ -973,6 +882,8 @@ impl Timeline for LayeredTimeline {
    fn get_current_logical_size_non_incremental(&self, lsn: Lsn) -> Result<usize> {
        let mut total_blocks: usize = 0;

+        let _enter = info_span!("calc logical size", %lsn).entered();
+
        // list of all relations in this timeline, including ancestor timelines
        let all_rels = self.list_rels(0, 0, lsn)?;

@@ -994,6 +905,13 @@ impl Timeline for LayeredTimeline {

        Ok(total_blocks * BLCKSZ as usize)
    }
+
+    fn writer<'a>(&'a self) -> Box<dyn TimelineWriter + 'a> {
+        Box::new(LayeredTimelineWriter {
+            tl: self,
+            _write_guard: self.write_lock.lock().unwrap(),
+        })
+    }
 }

 impl LayeredTimeline {
@@ -1034,6 +952,8 @@ impl LayeredTimeline {
            current_logical_size: AtomicUsize::new(current_logical_size),
            current_logical_size_gauge,
            upload_relishes,
+
+            write_lock: Mutex::new(()),
        };
        Ok(timeline)
    }
@@ -1043,11 +963,8 @@ impl LayeredTimeline {
    /// Returns all timeline-related files that were found and loaded.
    ///
    fn load_layer_map(&self, disk_consistent_lsn: Lsn) -> anyhow::Result<Vec<PathBuf>> {
-        info!(
-            "loading layer map for timeline {} into memory",
-            self.timelineid
-        );
        let mut layers = self.layers.lock().unwrap();
+        let mut num_layers = 0;
        let (imgfilenames, deltafilenames) =
            filename::list_files(self.conf, self.timelineid, self.tenantid)?;

@@ -1067,14 +984,10 @@ impl LayeredTimeline {

            let layer = ImageLayer::new(self.conf, self.timelineid, self.tenantid, filename);

-            info!(
-                "found layer {} {} on timeline {}",
-                layer.get_seg_tag(),
-                layer.get_start_lsn(),
-                self.timelineid
-            );
+            trace!("found layer {}", layer.filename().display());
            local_layers.push(layer.path());
            layers.insert_historic(Arc::new(layer));
+            num_layers += 1;
        }

        for filename in &deltafilenames {
@@ -1091,14 +1004,12 @@ impl LayeredTimeline {

            let layer = DeltaLayer::new(self.conf, self.timelineid, self.tenantid, filename);

-            info!(
-                "found layer {} on timeline {}",
-                layer.filename().display(),
-                self.timelineid,
-            );
+            trace!("found layer {}", layer.filename().display());
            local_layers.push(layer.path());
            layers.insert_historic(Arc::new(layer));
+            num_layers += 1;
        }
+        info!("loaded layer map with {} layers", num_layers);

        Ok(local_layers)
    }
@@ -1149,12 +1060,7 @@ impl LayeredTimeline {
        lsn: Lsn,
        self_layers: &MutexGuard<LayerMap>,
    ) -> Result<Option<(Arc<dyn Layer>, Lsn)>> {
-        trace!(
-            "get_layer_for_read called for {} at {}/{}",
-            seg,
-            self.timelineid,
-            lsn
-        );
+        trace!("get_layer_for_read called for {} at {}", seg, lsn);

        // If you requested a page at an older LSN, before the branch point, dig into
        // the right ancestor timeline. This can only happen if you launch a read-only
@@ -1272,17 +1178,15 @@ impl LayeredTimeline {
                // First modification on this timeline
                start_lsn = self.ancestor_lsn + 1;
                trace!(
-                    "creating layer for write for {} at branch point {}/{}",
+                    "creating layer for write for {} at branch point {}",
                    seg,
-                    self.timelineid,
                    start_lsn
                );
            } else {
                start_lsn = prev_layer.get_end_lsn();
                trace!(
-                    "creating layer for write for {} after previous layer {}/{}",
+                    "creating layer for write for {} after previous layer {}",
                    seg,
-                    self.timelineid,
                    start_lsn
                );
            }
@@ -1323,29 +1227,20 @@ impl LayeredTimeline {
    /// Flush to disk all data that was written with the put_* functions
    ///
    /// NOTE: This has nothing to do with checkpoint in PostgreSQL.
-    fn checkpoint_internal(&self, checkpoint_distance: u64) -> Result<()> {
-        // Grab lock on the layer map.
-        //
-        // TODO: We hold it locked throughout the checkpoint operation. That's bad,
-        // the checkpointing could take many seconds, and any incoming get_page_at_lsn()
-        // requests will block.
+    fn checkpoint_internal(&self, checkpoint_distance: u64, forced: bool) -> Result<()> {
+        let mut write_guard = self.write_lock.lock().unwrap();
        let mut layers = self.layers.lock().unwrap();

        // Bump the generation number in the layer map, so that we can distinguish
        // entries inserted after the checkpoint started
        let current_generation = layers.increment_generation();

-        // Read 'last_record_lsn'. That becomes the cutoff LSN for frozen layers.
        let RecordLsn {
            last: last_record_lsn,
            prev: prev_record_lsn,
        } = self.last_record_lsn.load();

-        trace!(
-            "checkpointing timeline {} at {}",
-            self.timelineid,
-            last_record_lsn
-        );
+        trace!("checkpoint starting at {}", last_record_lsn);

        // Take the in-memory layer with the oldest WAL record. If it's older
        // than the threshold, write it out to disk as a new image and delta file.
@@ -1363,6 +1258,10 @@ impl LayeredTimeline {
        while let Some((oldest_layer, oldest_generation)) = layers.peek_oldest_open() {
            let oldest_pending_lsn = oldest_layer.get_oldest_pending_lsn();

+            if tenant_mgr::shutdown_requested() && !forced {
+                return Ok(());
+            }
+
            // Does this layer need freezing?
            //
            // Write out all in-memory layers that contain WAL older than CHECKPOINT_DISTANCE.
@@ -1385,32 +1284,24 @@ impl LayeredTimeline {
                break;
            }

-            // Freeze the layer.
-            //
-            // This is a two-step process. First, we "freeze" the in-memory
-            // layer, to close it for new writes, and replace the original
-            // layer with the new frozen in-memory layer (and possibly a new
-            // open layer to hold changes newer than the cutoff.) Then we write
-            // the frozen layer to disk, and replace the in-memory frozen layer
-            // with the new on-disk layers.
-            let FreezeLayers {
-                frozen,
-                open: maybe_new_open,
-            } = oldest_layer.freeze(last_record_lsn)?;
+            // Mark the layer as no longer accepting writes and record the end_lsn.
+            // This happens in-place, no new layers are created now.
+            // We call `get_last_record_lsn` again, which may be different from the
+            // original load, as we may have released the write lock since then.
+            oldest_layer.freeze(self.get_last_record_lsn());

-            // replace this layer with the new layers that 'freeze' returned
+            // The layer is no longer open, update the layer map to reflect this.
+            // We will replace it with on-disk historics below.
            layers.pop_oldest_open();
-            if let Some(new_open) = maybe_new_open.clone() {
-                layers.insert_open(new_open);
-            }
-
-            // We temporarily insert InMemory layer into historic list here.
-            // TODO: check that all possible concurrent users of 'historic' treat it right
-            layers.insert_historic(frozen.clone());
+            layers.insert_historic(oldest_layer.clone());

            // Write the now-frozen layer to disk. That could take a while, so release the lock while do it
            drop(layers);
-            let new_historics = frozen.write_to_disk(self)?;
+            drop(write_guard);
+
+            let new_historics = oldest_layer.write_to_disk(self)?;
+
+            write_guard = self.write_lock.lock().unwrap();
            layers = self.layers.lock().unwrap();

            if !new_historics.is_empty() {
@@ -1418,7 +1309,7 @@ impl LayeredTimeline {
            }

            // Finally, replace the frozen in-memory layer with the new on-disk layers
-            layers.remove_historic(frozen.clone());
+            layers.remove_historic(oldest_layer);

            // Add the historics to the LayerMap
            for delta_layer in new_historics.delta_layers {
@@ -1439,13 +1330,14 @@ impl LayeredTimeline {
        }

        drop(layers);
+        drop(write_guard);

        if created_historics {
            // We must fsync the timeline dir to ensure the directory entries for
            // new layer files are durable
-            layer_uploads.push(self.conf.timeline_path(&self.timelineid, &self.tenantid));
-            batch_fsync(&layer_uploads)?;
-            layer_uploads.pop().unwrap();
+            let timeline_dir =
+                File::open(self.conf.timeline_path(&self.timelineid, &self.tenantid))?;
+            timeline_dir.sync_all()?;
        }

        // Save the metadata, with updated 'disk_consistent_lsn', to a
@@ -1521,11 +1413,11 @@ impl LayeredTimeline {
        let now = Instant::now();
        let mut result: GcResult = Default::default();

-        info!(
-            "running GC on timeline {}, cutoff {}",
-            self.timelineid, cutoff
-        );
-        info!("retain_lsns:  {:?}", retain_lsns);
+        let _enter = info_span!("garbage collection", timeline = %self.timelineid, tenant = %self.tenantid, cutoff = %cutoff).entered();
+
+        info!("GC starting");
+
+        debug!("retain_lsns: {:?}", retain_lsns);

        let mut layers_to_remove: Vec<Arc<dyn Layer>> = Vec::new();

@@ -1787,10 +1679,9 @@ impl LayeredTimeline {
        if data.records.is_empty() {
            if let Some(img) = &data.page_img {
                trace!(
-                    "found page image for blk {} in {} at {}/{}, no WAL redo required",
+                    "found page image for blk {} in {} at {}, no WAL redo required",
                    blknum,
                    rel,
-                    self.timelineid,
                    request_lsn
                );
                Ok(img.clone())
@@ -1804,7 +1695,7 @@ impl LayeredTimeline {
            //
            // If we don't have a base image, then the oldest WAL record better initialize
            // the page
-            if data.page_img.is_none() && !data.records.first().unwrap().will_init {
+            if data.page_img.is_none() && !data.records.first().unwrap().1.will_init {
                // FIXME: this ought to be an error?
                warn!(
                    "Base image for page {}/{} at {} not found, but got {} WAL records",
@@ -1816,9 +1707,9 @@ impl LayeredTimeline {
                Ok(ZERO_PAGE.clone())
            } else {
                if data.page_img.is_some() {
-                    trace!("found {} WAL records and a base image for blk {} in {} at {}/{}, performing WAL redo", data.records.len(), blknum, rel, self.timelineid, request_lsn);
+                    trace!("found {} WAL records and a base image for blk {} in {} at {}, performing WAL redo", data.records.len(), blknum, rel, request_lsn);
                } else {
-                    trace!("found {} WAL records that will init the page for blk {} in {} at {}/{}, performing WAL redo", data.records.len(), blknum, rel, self.timelineid, request_lsn);
+                    trace!("found {} WAL records that will init the page for blk {} in {} at {}, performing WAL redo", data.records.len(), blknum, rel, request_lsn);
                }
                let img = self.walredo_mgr.request_redo(
                    rel,
@@ -1866,36 +1757,163 @@ impl LayeredTimeline {
        self.current_logical_size_gauge
            .set(val as i64 - diff as i64);
    }
+}

-    /// If a layer is in the process of being replaced in [`LayerMap`], write
-    /// operations will fail with [`NonWriteableError`]. This may happen due to
-    /// a race: the checkpointer thread freezes a layer just after
-    /// [`Self::get_layer_for_write`] returned it. To handle this error, we try
-    /// again getting the layer and attempt the write.
-    fn perform_write_op<R>(
-        &self,
-        seg: SegmentTag,
-        lsn: Lsn,
-        write_op: impl Fn(&Arc<InMemoryLayer>) -> WriteResult<R>,
-    ) -> anyhow::Result<R> {
-        let mut layer = self.get_layer_for_write(seg, lsn)?;
-        loop {
-            match write_op(&layer) {
-                Ok(r) => return Ok(r),
-                Err(NonWriteableError {}) => {}
-            }
+struct LayeredTimelineWriter<'a> {
+    tl: &'a LayeredTimeline,
+    _write_guard: MutexGuard<'a, ()>,
+}

-            info!(
-                "attempted to write to non-writeable layer, retrying {} {}",
-                seg, lsn
+impl Deref for LayeredTimelineWriter<'_> {
+    type Target = dyn Timeline;
+
+    fn deref(&self) -> &Self::Target {
+        self.tl
+    }
+}
+
+impl<'a> TimelineWriter for LayeredTimelineWriter<'a> {
+    fn put_wal_record(&self, lsn: Lsn, rel: RelishTag, blknum: u32, rec: WALRecord) -> Result<()> {
+        if !rel.is_blocky() && blknum != 0 {
+            bail!(
+                "invalid request for block {} for non-blocky relish {}",
+                blknum,
+                rel
            );
-
-            // layer was non-writeable, try again
-            let new_layer = self.get_layer_for_write(seg, lsn)?;
-            // the new layer does not have to be writeable, but it should at least be different
-            assert!(!Arc::ptr_eq(&layer, &new_layer));
-            layer = new_layer;
        }
+        ensure!(lsn.is_aligned(), "unaligned record LSN");
+
+        let seg = SegmentTag::from_blknum(rel, blknum);
+        let layer = self.tl.get_layer_for_write(seg, lsn)?;
+        let delta_size = layer.put_wal_record(lsn, blknum, rec);
+        self.tl
+            .increase_current_logical_size(delta_size * BLCKSZ as u32);
+        Ok(())
+    }
+
+    fn put_page_image(&self, rel: RelishTag, blknum: u32, lsn: Lsn, img: Bytes) -> Result<()> {
+        if !rel.is_blocky() && blknum != 0 {
+            bail!(
+                "invalid request for block {} for non-blocky relish {}",
+                blknum,
+                rel
+            );
+        }
+        ensure!(lsn.is_aligned(), "unaligned record LSN");
+
+        let seg = SegmentTag::from_blknum(rel, blknum);
+
+        let layer = self.tl.get_layer_for_write(seg, lsn)?;
+        let delta_size = layer.put_page_image(blknum, lsn, img);
+
+        self.tl
+            .increase_current_logical_size(delta_size * BLCKSZ as u32);
+        Ok(())
+    }
+
+    fn put_truncation(&self, rel: RelishTag, lsn: Lsn, relsize: u32) -> Result<()> {
+        if !rel.is_blocky() {
+            bail!("invalid truncation for non-blocky relish {}", rel);
+        }
+        ensure!(lsn.is_aligned(), "unaligned record LSN");
+
+        debug!("put_truncation: {} to {} blocks at {}", rel, relsize, lsn);
+
+        let oldsize = self
+            .tl
+            .get_relish_size(rel, self.tl.get_last_record_lsn())?
+            .ok_or_else(|| {
+                anyhow!(
+                    "attempted to truncate non-existent relish {} at {}",
+                    rel,
+                    lsn
+                )
+            })?;
+
+        if oldsize <= relsize {
+            return Ok(());
+        }
+        let old_last_seg = (oldsize - 1) / RELISH_SEG_SIZE;
+
+        let last_remain_seg = if relsize == 0 {
+            0
+        } else {
+            (relsize - 1) / RELISH_SEG_SIZE
+        };
+
+        // Drop segments beyond the last remaining segment.
+        for remove_segno in (last_remain_seg + 1)..=old_last_seg {
+            let seg = SegmentTag {
+                rel,
+                segno: remove_segno,
+            };
+
+            let layer = self.tl.get_layer_for_write(seg, lsn)?;
+            layer.drop_segment(lsn);
+        }
+
+        // Truncate the last remaining segment to the specified size
+        if relsize == 0 || relsize % RELISH_SEG_SIZE != 0 {
+            let seg = SegmentTag {
+                rel,
+                segno: last_remain_seg,
+            };
+            let layer = self.tl.get_layer_for_write(seg, lsn)?;
+            layer.put_truncation(lsn, relsize % RELISH_SEG_SIZE)
+        }
+        self.tl
+            .decrease_current_logical_size((oldsize - relsize) * BLCKSZ as u32);
+        Ok(())
+    }
+
+    fn drop_relish(&self, rel: RelishTag, lsn: Lsn) -> Result<()> {
+        trace!("drop_segment: {} at {}", rel, lsn);
+
+        if rel.is_blocky() {
+            if let Some(oldsize) = self
+                .tl
+                .get_relish_size(rel, self.tl.get_last_record_lsn())?
+            {
+                let old_last_seg = if oldsize == 0 {
+                    0
+                } else {
+                    (oldsize - 1) / RELISH_SEG_SIZE
+                };
+
+                // Drop all segments of the relish
+                for remove_segno in 0..=old_last_seg {
+                    let seg = SegmentTag {
+                        rel,
+                        segno: remove_segno,
+                    };
+                    let layer = self.tl.get_layer_for_write(seg, lsn)?;
+                    layer.drop_segment(lsn);
+                }
+                self.tl
+                    .decrease_current_logical_size(oldsize * BLCKSZ as u32);
+            } else {
+                warn!(
+                    "drop_segment called on non-existent relish {} at {}",
+                    rel, lsn
+                );
+            }
+        } else {
+            // TODO handle TwoPhase relishes
+            let seg = SegmentTag::from_blknum(rel, 0);
+            let layer = self.tl.get_layer_for_write(seg, lsn)?;
+            layer.drop_segment(lsn);
+        }
+
+        Ok(())
+    }
+
+    ///
+    /// Remember the (end of) last valid WAL record remembered in the timeline.
+    ///
+    fn advance_last_record_lsn(&self, new_lsn: Lsn) {
+        assert!(new_lsn.is_aligned());
+
+        self.tl.last_record_lsn.advance(new_lsn);
    }
 }

@@ -198,7 +198,7 @@ impl Layer for DeltaLayer {
                .slice_range((Included(&minkey), Included(&maxkey)))
                .iter()
                .rev();
-            for ((_blknum, _lsn), blob_range) in iter {
+            for ((_blknum, pv_lsn), blob_range) in iter {
                let pv = PageVersion::des(&read_blob(&page_version_reader, blob_range)?)?;

                if let Some(img) = pv.page_image {
@@ -208,7 +208,7 @@ impl Layer for DeltaLayer {
                    break;
                } else if let Some(rec) = pv.record {
                    let will_init = rec.will_init;
-                    reconstruct_data.records.push(rec);
+                    reconstruct_data.records.push((*pv_lsn, rec));
                    if will_init {
                        // This WAL record initializes the page, so no need to go further back
                        need_image = false;
@@ -431,7 +431,8 @@ impl DeltaLayer {
        let book = chapter.close()?;

        // This flushes the underlying 'buf_writer'.
-        book.close()?;
+        let writer = book.close()?;
+        writer.get_ref().sync_all()?;

        trace!("saved {}", &path.display());

@@ -315,7 +315,8 @@ impl ImageLayer {
        let book = chapter.close()?;

        // This flushes the underlying 'buf_writer'.
-        book.close()?;
+        let writer = book.close()?;
+        writer.get_ref().sync_all()?;

        trace!("saved {}", path.display());

@@ -15,12 +15,10 @@ use crate::{ZTenantId, ZTimelineId};
 use anyhow::{bail, ensure, Result};
 use bytes::Bytes;
 use log::*;
-use std::cmp::min;
 use std::path::PathBuf;
 use std::sync::{Arc, RwLock};
 use zenith_utils::vec_map::VecMap;

-use zenith_utils::accum::Accum;
 use zenith_utils::lsn::Lsn;

 use super::page_versions::PageVersions;
@@ -37,9 +35,6 @@ pub struct InMemoryLayer {
    ///
    start_lsn: Lsn,

-    /// Frozen in-memory layers have an inclusive end LSN.
-    end_lsn: Option<Lsn>,
-
    /// LSN of the oldest page version stored in this layer
    oldest_pending_lsn: Lsn,

@@ -52,8 +47,13 @@ pub struct InMemoryLayer {
 }

 pub struct InMemoryLayerInner {
+    /// Frozen in-memory layers have an exclusive end LSN.
+    /// Writes are only allowed when this is None
+    end_lsn: Option<Lsn>,
+
    /// If this relation was dropped, remember when that happened.
-    drop_lsn: Option<Lsn>,
+    /// The drop LSN is recorded in [`end_lsn`].
+    dropped: bool,

    ///
    /// All versions of all pages in the layer are are kept here.
@@ -69,19 +69,11 @@ pub struct InMemoryLayerInner {
    /// a non-blocky rel, 'segsizes' is not used and is always empty.
    ///
    segsizes: VecMap<Lsn, u32>,
-
-    /// Writes are only allowed when true.
-    /// Set to false when this layer is in the process of being replaced.
-    writeable: bool,
 }

 impl InMemoryLayerInner {
-    fn check_writeable(&self) -> WriteResult<()> {
-        if self.writeable {
-            Ok(())
-        } else {
-            Err(NonWriteableError)
-        }
+    fn assert_writeable(&self) {
+        assert!(self.end_lsn.is_none());
    }

    fn get_seg_size(&self, lsn: Lsn) -> u32 {
@@ -104,20 +96,17 @@ impl Layer for InMemoryLayer {
        let inner = self.inner.read().unwrap();

        let end_lsn;
-        let dropped;
-        if let Some(drop_lsn) = inner.drop_lsn {
+        if let Some(drop_lsn) = inner.end_lsn {
            end_lsn = drop_lsn;
-            dropped = true;
        } else {
            end_lsn = Lsn(u64::MAX);
-            dropped = false;
        }

        let delta_filename = DeltaFileName {
            seg: self.seg,
            start_lsn: self.start_lsn,
            end_lsn,
-            dropped,
+            dropped: inner.dropped,
        }
        .to_string();

@@ -137,14 +126,10 @@ impl Layer for InMemoryLayer {
    }

    fn get_end_lsn(&self) -> Lsn {
-        if let Some(end_lsn) = self.end_lsn {
-            return Lsn(end_lsn.0 + 1);
-        }
-
        let inner = self.inner.read().unwrap();

-        if let Some(drop_lsn) = inner.drop_lsn {
-            drop_lsn
+        if let Some(end_lsn) = inner.end_lsn {
+            end_lsn
        } else {
            Lsn(u64::MAX)
        }
@@ -152,7 +137,7 @@ impl Layer for InMemoryLayer {

    fn is_dropped(&self) -> bool {
        let inner = self.inner.read().unwrap();
-        inner.drop_lsn.is_some()
+        inner.dropped
    }

    /// Look up given page in the cache.
@@ -175,13 +160,13 @@ impl Layer for InMemoryLayer {
                .get_block_lsn_range(blknum, ..=lsn)
                .iter()
                .rev();
-            for (_entry_lsn, entry) in iter {
+            for (entry_lsn, entry) in iter {
                if let Some(img) = &entry.page_image {
                    reconstruct_data.page_img = Some(img.clone());
                    need_image = false;
                    break;
                } else if let Some(rec) = &entry.record {
-                    reconstruct_data.records.push(rec.clone());
+                    reconstruct_data.records.push((*entry_lsn, rec.clone()));
                    if rec.will_init {
                        // This WAL record initializes the page, so no need to go further back
                        need_image = false;
@@ -230,8 +215,8 @@ impl Layer for InMemoryLayer {
        assert!(lsn >= self.start_lsn);

        // Is the requested LSN after the segment was dropped?
-        if let Some(drop_lsn) = inner.drop_lsn {
-            if lsn >= drop_lsn {
+        if let Some(end_lsn) = inner.end_lsn {
+            if lsn >= end_lsn {
                return Ok(false);
            }
        }
@@ -262,14 +247,14 @@ impl Layer for InMemoryLayer {
        let inner = self.inner.read().unwrap();

        let end_str = inner
-            .drop_lsn
+            .end_lsn
            .as_ref()
-            .map(|drop_lsn| drop_lsn.to_string())
+            .map(Lsn::to_string)
            .unwrap_or_default();

        println!(
-            "----- in-memory layer for tli {} seg {} {}-{} ----",
-            self.timelineid, self.seg, self.start_lsn, end_str
+            "----- in-memory layer for tli {} seg {} {}-{} {} ----",
+            self.timelineid, self.seg, self.start_lsn, end_str, inner.dropped,
        );

        for (k, v) in inner.segsizes.as_slice() {
@@ -290,21 +275,6 @@ impl Layer for InMemoryLayer {
    }
 }

-/// Write failed because the layer is in process of being replaced.
-/// See [`LayeredTimeline::perform_write_op`] for how to handle this error.
-#[derive(Debug)]
-pub struct NonWriteableError;
-
-pub type WriteResult<T> = std::result::Result<T, NonWriteableError>;
-
-/// Helper struct to cleanup `InMemoryLayer::freeze` return signature.
-pub struct FreezeLayers {
-    /// Replacement layer for the layer which freeze was called on.
-    pub frozen: Arc<InMemoryLayer>,
-    /// New open layer containing leftover data.
-    pub open: Option<Arc<InMemoryLayer>>,
-}
-
 /// A result of an inmemory layer data being written to disk.
 pub struct LayersOnDisk {
    pub delta_layers: Vec<DeltaLayer>,
@@ -318,10 +288,6 @@ impl LayersOnDisk {
 }

 impl InMemoryLayer {
-    fn assert_not_frozen(&self) {
-        assert!(self.end_lsn.is_none());
-    }
-
    /// Return the oldest page version that's stored in this layer
    pub fn get_oldest_pending_lsn(&self) -> Lsn {
        self.oldest_pending_lsn
@@ -357,14 +323,13 @@ impl InMemoryLayer {
            tenantid,
            seg,
            start_lsn,
-            end_lsn: None,
            oldest_pending_lsn,
            incremental: false,
            inner: RwLock::new(InMemoryLayerInner {
-                drop_lsn: None,
+                end_lsn: None,
+                dropped: false,
                page_versions: PageVersions::default(),
                segsizes,
-                writeable: true,
            }),
        })
    }
@@ -372,10 +337,10 @@ impl InMemoryLayer {
    // Write operations

    /// Remember new page version, as a WAL record over previous version
-    pub fn put_wal_record(&self, blknum: u32, rec: WALRecord) -> WriteResult<u32> {
+    pub fn put_wal_record(&self, lsn: Lsn, blknum: u32, rec: WALRecord) -> u32 {
        self.put_page_version(
            blknum,
-            rec.lsn,
+            lsn,
            PageVersion {
                page_image: None,
                record: Some(rec),
@@ -384,7 +349,7 @@ impl InMemoryLayer {
    }

    /// Remember new page version, as a full page image
-    pub fn put_page_image(&self, blknum: u32, lsn: Lsn, img: Bytes) -> WriteResult<u32> {
+    pub fn put_page_image(&self, blknum: u32, lsn: Lsn, img: Bytes) -> u32 {
        self.put_page_version(
            blknum,
            lsn,
@@ -397,8 +362,7 @@ impl InMemoryLayer {

    /// Common subroutine of the public put_wal_record() and put_page_image() functions.
    /// Adds the page version to the in-memory tree
-    pub fn put_page_version(&self, blknum: u32, lsn: Lsn, pv: PageVersion) -> WriteResult<u32> {
-        self.assert_not_frozen();
+    pub fn put_page_version(&self, blknum: u32, lsn: Lsn, pv: PageVersion) -> u32 {
        assert!(self.seg.blknum_in_seg(blknum));

        trace!(
@@ -410,7 +374,7 @@ impl InMemoryLayer {
        );
        let mut inner = self.inner.write().unwrap();

-        inner.check_writeable()?;
+        inner.assert_writeable();

        let old = inner.page_versions.append_or_update_last(blknum, lsn, pv);

@@ -471,22 +435,22 @@ impl InMemoryLayer {
                }

                inner.segsizes.append_or_update_last(lsn, newsize).unwrap();
-                return Ok(newsize - oldsize);
+                return newsize - oldsize;
            }
        }
-        Ok(0)
+
+        0
    }

    /// Remember that the relation was truncated at given LSN
-    pub fn put_truncation(&self, lsn: Lsn, segsize: u32) -> WriteResult<()> {
+    pub fn put_truncation(&self, lsn: Lsn, segsize: u32) {
        assert!(
            self.seg.rel.is_blocky(),
            "put_truncation() called on a non-blocky rel"
        );
-        self.assert_not_frozen();

        let mut inner = self.inner.write().unwrap();
-        inner.check_writeable()?;
+        inner.assert_writeable();

        // check that this we truncate to a smaller size than segment was before the truncation
        let oldsize = inner.get_seg_size(lsn);
@@ -498,25 +462,19 @@ impl InMemoryLayer {
            // We already had an entry for this LSN. That's odd..
            warn!("Inserting truncation, but had an entry for the LSN already");
        }
-
-        Ok(())
    }

    /// Remember that the segment was dropped at given LSN
-    pub fn drop_segment(&self, lsn: Lsn) -> WriteResult<()> {
-        self.assert_not_frozen();
-
+    pub fn drop_segment(&self, lsn: Lsn) {
        let mut inner = self.inner.write().unwrap();

-        inner.check_writeable()?;
-
-        assert!(inner.drop_lsn.is_none());
-        inner.drop_lsn = Some(lsn);
-        inner.writeable = false;
+        assert!(inner.end_lsn.is_none());
+        assert!(!inner.dropped);
+        inner.dropped = true;
+        assert!(self.start_lsn < lsn);
+        inner.end_lsn = Some(lsn);

        trace!("dropped segment {} at {}", self.seg, lsn);
-
-        Ok(())
    }

    ///
@@ -556,117 +514,43 @@ impl InMemoryLayer {
            tenantid,
            seg,
            start_lsn,
-            end_lsn: None,
            oldest_pending_lsn,
            incremental: true,
            inner: RwLock::new(InMemoryLayerInner {
-                drop_lsn: None,
+                end_lsn: None,
+                dropped: false,
                page_versions: PageVersions::default(),
                segsizes,
-                writeable: true,
            }),
        })
    }

    pub fn is_writeable(&self) -> bool {
        let inner = self.inner.read().unwrap();
-        inner.writeable
+        inner.end_lsn.is_none()
    }

-    /// Splits `self` into two InMemoryLayers: `frozen` and `open`.
-    /// All data up to and including `cutoff_lsn`
-    /// is copied to `frozen`, while the remaining data is copied to `open`.
-    /// After completion, self is non-writeable, but not frozen.
-    pub fn freeze(self: Arc<Self>, cutoff_lsn: Lsn) -> Result<FreezeLayers> {
-        info!(
-            "freezing in memory layer {} on timeline {} at {} (oldest {})",
-            self.filename().display(),
-            self.timelineid,
-            cutoff_lsn,
-            self.oldest_pending_lsn
-        );
+    /// Make the layer non-writeable. Only call once.
+    /// Records the end_lsn for non-dropped layers.
+    /// `end_lsn` is inclusive
+    pub fn freeze(&self, end_lsn: Lsn) {
+        let mut inner = self.inner.write().unwrap();

-        self.assert_not_frozen();
-
-        let self_ref = self.clone();
-        let mut inner = self_ref.inner.write().unwrap();
-        // Dropped layers don't need any special freeze actions,
-        // they are marked as non-writeable at drop and just
-        // written out to disk by checkpointer.
-        if inner.drop_lsn.is_some() {
-            assert!(!inner.writeable);
-            info!(
-                "freezing in memory layer for {} on timeline {} is dropped at {}",
-                self.seg,
-                self.timelineid,
-                inner.drop_lsn.unwrap()
-            );
-
-            // There should be no newer layer that refers this non-writeable layer,
-            // because layer that is created after dropped one represents a new rel.
-            return Ok(FreezeLayers {
-                frozen: self,
-                open: None,
-            });
-        }
-        assert!(inner.writeable);
-        inner.writeable = false;
-
-        // Divide all the page versions into old and new
-        // at the 'cutoff_lsn' point.
-        let mut after_oldest_lsn: Accum<Lsn> = Accum(None);
-
-        let cutoff_lsn_exclusive = Lsn(cutoff_lsn.0 + 1);
-
-        let (before_segsizes, mut after_segsizes) = inner.segsizes.split_at(&cutoff_lsn_exclusive);
-        if let Some((lsn, _size)) = after_segsizes.as_slice().first() {
-            after_oldest_lsn.accum(min, *lsn);
-        }
-
-        let (before_page_versions, after_page_versions) = inner
-            .page_versions
-            .split_at(cutoff_lsn_exclusive, &mut after_oldest_lsn);
-
-        let frozen = Arc::new(InMemoryLayer {
-            conf: self.conf,
-            tenantid: self.tenantid,
-            timelineid: self.timelineid,
-            seg: self.seg,
-            start_lsn: self.start_lsn,
-            end_lsn: Some(cutoff_lsn),
-            oldest_pending_lsn: self.start_lsn,
-            incremental: self.incremental,
-            inner: RwLock::new(InMemoryLayerInner {
-                drop_lsn: inner.drop_lsn,
-                page_versions: before_page_versions,
-                segsizes: before_segsizes,
-                writeable: false,
-            }),
-        });
-
-        let open = if !after_segsizes.is_empty() || !after_page_versions.is_empty() {
-            let mut new_open = Self::create_successor_layer(
-                self.conf,
-                frozen.clone(),
-                self.timelineid,
-                self.tenantid,
-                cutoff_lsn + 1,
-                after_oldest_lsn.0.unwrap(),
-            )?;
-
-            let new_inner = new_open.inner.get_mut().unwrap();
-            // Ensure page_versions doesn't contain anything
-            // so we can just replace it
-            assert!(new_inner.page_versions.is_empty());
-            new_inner.page_versions = after_page_versions;
-            new_inner.segsizes.extend(&mut after_segsizes).unwrap();
-
-            Some(Arc::new(new_open))
+        if inner.end_lsn.is_some() {
+            assert!(inner.dropped);
        } else {
-            None
-        };
+            assert!(!inner.dropped);
+            assert!(self.start_lsn < end_lsn + 1);
+            inner.end_lsn = Some(Lsn(end_lsn.0 + 1));

-        Ok(FreezeLayers { frozen, open })
+            if let Some((lsn, _)) = inner.segsizes.as_slice().last() {
+                assert!(lsn <= &end_lsn, "{:?} {:?}", lsn, end_lsn);
+            }
+
+            for (_blk, lsn, _pv) in inner.page_versions.ordered_page_version_iter(None) {
+                assert!(lsn <= end_lsn);
+            }
+        }
    }

    /// Write the this frozen in-memory layer to disk.
@@ -679,9 +563,8 @@ impl InMemoryLayer {
    /// end LSN are the same.)
    pub fn write_to_disk(&self, timeline: &LayeredTimeline) -> Result<LayersOnDisk> {
        trace!(
-            "write_to_disk {} end_lsn is {} get_end_lsn is {}",
+            "write_to_disk {} get_end_lsn is {}",
            self.filename().display(),
-            self.end_lsn.unwrap_or(Lsn(0)),
            self.get_end_lsn()
        );

@@ -695,16 +578,16 @@ impl InMemoryLayer {
        // would have to wait until we release it. That race condition is very
        // rare though, so we just accept the potential latency hit for now.
        let inner = self.inner.read().unwrap();
-        assert!(!inner.writeable);
+        let end_lsn_exclusive = inner.end_lsn.unwrap();

-        if let Some(drop_lsn) = inner.drop_lsn {
+        if inner.dropped {
            let delta_layer = DeltaLayer::create(
                self.conf,
                self.timelineid,
                self.tenantid,
                self.seg,
                self.start_lsn,
-                drop_lsn,
+                end_lsn_exclusive,
                true,
                inner.page_versions.ordered_page_version_iter(None),
                inner.segsizes.clone(),
@@ -713,7 +596,7 @@ impl InMemoryLayer {
                "freeze: created delta layer for dropped segment {} {}-{}",
                self.seg,
                self.start_lsn,
-                drop_lsn
+                end_lsn_exclusive
            );
            return Ok(LayersOnDisk {
                delta_layers: vec![delta_layer],
@@ -721,14 +604,19 @@ impl InMemoryLayer {
            });
        }

-        let end_lsn = self.end_lsn.unwrap();
+        // Since `end_lsn` is inclusive, subtract 1.
+        // We want to make an ImageLayer for the last included LSN,
+        // so the DeltaLayer should exlcude that LSN.
+        let end_lsn_inclusive = Lsn(end_lsn_exclusive.0 - 1);

-        let mut before_page_versions = inner.page_versions.ordered_page_version_iter(Some(end_lsn));
+        let mut page_versions = inner
+            .page_versions
+            .ordered_page_version_iter(Some(end_lsn_inclusive));

        let mut delta_layers = Vec::new();
-        if self.start_lsn != end_lsn {
-            let (before_segsizes, _after_segsizes) = inner.segsizes.split_at(&Lsn(end_lsn.0 + 1));

+        if self.start_lsn != end_lsn_inclusive {
+            let (segsizes, _) = inner.segsizes.split_at(&end_lsn_exclusive);
            // Write the page versions before the cutoff to disk.
            let delta_layer = DeltaLayer::create(
                self.conf,
@@ -736,27 +624,32 @@ impl InMemoryLayer {
                self.tenantid,
                self.seg,
                self.start_lsn,
-                end_lsn,
+                end_lsn_inclusive,
                false,
-                before_page_versions,
-                before_segsizes,
+                page_versions,
+                segsizes,
            )?;
            delta_layers.push(delta_layer);
            trace!(
                "freeze: created delta layer {} {}-{}",
                self.seg,
                self.start_lsn,
-                end_lsn
+                end_lsn_inclusive
            );
        } else {
-            assert!(before_page_versions.next().is_none());
+            assert!(page_versions.next().is_none());
        }

        drop(inner);

        // Write a new base image layer at the cutoff point
-        let image_layer = ImageLayer::create_from_src(self.conf, timeline, self, end_lsn)?;
-        trace!("freeze: created image layer {} at {}", self.seg, end_lsn);
+        let image_layer =
+            ImageLayer::create_from_src(self.conf, timeline, self, end_lsn_inclusive)?;
+        trace!(
+            "freeze: created image layer {} at {}",
+            self.seg,
+            end_lsn_inclusive
+        );

        Ok(LayersOnDisk {
            delta_layers,
@@ -1,6 +1,6 @@
 use std::{collections::HashMap, ops::RangeBounds, slice};

-use zenith_utils::{accum::Accum, lsn::Lsn, vec_map::VecMap};
+use zenith_utils::{lsn::Lsn, vec_map::VecMap};

 use super::storage_layer::PageVersion;

@@ -10,10 +10,6 @@ const EMPTY_SLICE: &[(Lsn, PageVersion)] = &[];
 pub struct PageVersions(HashMap<u32, VecMap<Lsn, PageVersion>>);

 impl PageVersions {
-    pub fn is_empty(&self) -> bool {
-        self.0.is_empty()
-    }
-
    pub fn append_or_update_last(
        &mut self,
        blknum: u32,
@@ -44,34 +40,6 @@ impl PageVersions {
            .unwrap_or(EMPTY_SLICE)
    }

-    /// Split the page version map into two.
-    ///
-    /// Left contains everything up to and not including [`cutoff_lsn`].
-    /// Right contains [`cutoff_lsn`] and everything after.
-    pub fn split_at(&self, cutoff_lsn: Lsn, after_oldest_lsn: &mut Accum<Lsn>) -> (Self, Self) {
-        let mut before_blocks = HashMap::new();
-        let mut after_blocks = HashMap::new();
-
-        for (blknum, vec_map) in self.0.iter() {
-            let (before_versions, after_versions) = vec_map.split_at(&cutoff_lsn);
-
-            if !before_versions.is_empty() {
-                let old = before_blocks.insert(*blknum, before_versions);
-                assert!(old.is_none());
-            }
-
-            if !after_versions.is_empty() {
-                let (first_lsn, _first_pv) = &after_versions.as_slice()[0];
-                after_oldest_lsn.accum(std::cmp::min, *first_lsn);
-
-                let old = after_blocks.insert(*blknum, after_versions);
-                assert!(old.is_none());
-            }
-        }
-
-        (Self(before_blocks), Self(after_blocks))
-    }
-
    /// Iterate through [`PageVersion`]s in (block, lsn) order.
    /// If a [`cutoff_lsn`] is set, only show versions with `lsn < cutoff_lsn`
    pub fn ordered_page_version_iter(&self, cutoff_lsn: Option<Lsn>) -> OrderedPageVersionIter<'_> {
@@ -78,7 +78,7 @@ pub struct PageVersion {
 /// 'records' contains the records to apply over the base image.
 ///
 pub struct PageReconstructData {
-    pub records: Vec<WALRecord>,
+    pub records: Vec<(Lsn, WALRecord)>,
    pub page_img: Option<Bytes>,
 }

@@ -13,7 +13,6 @@
 use anyhow::{anyhow, bail, ensure, Result};
 use bytes::{Buf, BufMut, Bytes, BytesMut};
 use lazy_static::lazy_static;
-use log::*;
 use regex::Regex;
 use std::net::TcpListener;
 use std::str;
@@ -21,10 +20,12 @@ use std::str::FromStr;
 use std::sync::Arc;
 use std::thread;
 use std::{io, net::TcpStream};
+use tracing::*;
 use zenith_metrics::{register_histogram_vec, HistogramVec};
 use zenith_utils::auth::{self, JwtAuth};
 use zenith_utils::auth::{Claims, Scope};
 use zenith_utils::lsn::Lsn;
+use zenith_utils::postgres_backend::is_socket_read_timed_out;
 use zenith_utils::postgres_backend::PostgresBackend;
 use zenith_utils::postgres_backend::{self, AuthType};
 use zenith_utils::pq_proto::{
@@ -187,17 +188,32 @@ pub fn thread_main(
    listener: TcpListener,
    auth_type: AuthType,
 ) -> anyhow::Result<()> {
-    loop {
+    let mut join_handles = Vec::new();
+
+    while !tenant_mgr::shutdown_requested() {
        let (socket, peer_addr) = listener.accept()?;
        debug!("accepted connection from {}", peer_addr);
        socket.set_nodelay(true).unwrap();
        let local_auth = auth.clone();
-        thread::spawn(move || {
-            if let Err(err) = page_service_conn_main(conf, local_auth, socket, auth_type) {
-                error!("page server thread exiting with error: {:#}", err);
-            }
-        });
+
+        let handle = thread::Builder::new()
+            .name("serving Page Service thread".into())
+            .spawn(move || {
+                if let Err(err) = page_service_conn_main(conf, local_auth, socket, auth_type) {
+                    error!(%err, "page server thread exited with error");
+                }
+            })
+            .unwrap();
+
+        join_handles.push(handle);
    }
+
+    debug!("page_service loop terminated. wait for connections to cancel");
+    for handle in join_handles.into_iter() {
+        handle.join().unwrap();
+    }
+
+    Ok(())
 }

 fn page_service_conn_main(
@@ -216,7 +232,7 @@ fn page_service_conn_main(
    }

    let mut conn_handler = PageServerHandler::new(conf, auth);
-    let pgbackend = PostgresBackend::new(socket, auth_type, None)?;
+    let pgbackend = PostgresBackend::new(socket, auth_type, None, true)?;
    pgbackend.run(&mut conn_handler)
 }

@@ -260,50 +276,66 @@ impl PageServerHandler {
        timelineid: ZTimelineId,
        tenantid: ZTenantId,
    ) -> anyhow::Result<()> {
+        let _enter = info_span!("pagestream", timeline = %timelineid, tenant = %tenantid).entered();
+
        // Check that the timeline exists
        let timeline = tenant_mgr::get_timeline_for_tenant(tenantid, timelineid)?;

        /* switch client to COPYBOTH */
        pgb.write_message(&BeMessage::CopyBothResponse)?;

-        while let Some(message) = pgb.read_message()? {
-            trace!("query({:?}): {:?}", timelineid, message);
+        while !tenant_mgr::shutdown_requested() {
+            match pgb.read_message() {
+                Ok(message) => {
+                    if let Some(message) = message {
+                        trace!("query: {:?}", message);

-            let copy_data_bytes = match message {
-                FeMessage::CopyData(bytes) => bytes,
-                _ => continue,
-            };
+                        let copy_data_bytes = match message {
+                            FeMessage::CopyData(bytes) => bytes,
+                            _ => continue,
+                        };

-            let zenith_fe_msg = PagestreamFeMessage::parse(copy_data_bytes)?;
+                        let zenith_fe_msg = PagestreamFeMessage::parse(copy_data_bytes)?;

-            let response = match zenith_fe_msg {
-                PagestreamFeMessage::Exists(req) => SMGR_QUERY_TIME
-                    .with_label_values(&["get_rel_exists"])
-                    .observe_closure_duration(|| {
-                        self.handle_get_rel_exists_request(&*timeline, &req)
-                    }),
-                PagestreamFeMessage::Nblocks(req) => SMGR_QUERY_TIME
-                    .with_label_values(&["get_rel_size"])
-                    .observe_closure_duration(|| self.handle_get_nblocks_request(&*timeline, &req)),
-                PagestreamFeMessage::GetPage(req) => SMGR_QUERY_TIME
-                    .with_label_values(&["get_page_at_lsn"])
-                    .observe_closure_duration(|| {
-                        self.handle_get_page_at_lsn_request(&*timeline, &req)
-                    }),
-            };
+                        let response = match zenith_fe_msg {
+                            PagestreamFeMessage::Exists(req) => SMGR_QUERY_TIME
+                                .with_label_values(&["get_rel_exists"])
+                                .observe_closure_duration(|| {
+                                    self.handle_get_rel_exists_request(&*timeline, &req)
+                                }),
+                            PagestreamFeMessage::Nblocks(req) => SMGR_QUERY_TIME
+                                .with_label_values(&["get_rel_size"])
+                                .observe_closure_duration(|| {
+                                    self.handle_get_nblocks_request(&*timeline, &req)
+                                }),
+                            PagestreamFeMessage::GetPage(req) => SMGR_QUERY_TIME
+                                .with_label_values(&["get_page_at_lsn"])
+                                .observe_closure_duration(|| {
+                                    self.handle_get_page_at_lsn_request(&*timeline, &req)
+                                }),
+                        };

-            let response = response.unwrap_or_else(|e| {
-                // print the all details to the log with {:#}, but for the client the
-                // error message is enough
-                error!("error reading relation or page version: {:#}", e);
-                PagestreamBeMessage::Error(PagestreamErrorResponse {
-                    message: e.to_string(),
-                })
-            });
+                        let response = response.unwrap_or_else(|e| {
+                            // print the all details to the log with {:#}, but for the client the
+                            // error message is enough
+                            error!("error reading relation or page version: {:#}", e);
+                            PagestreamBeMessage::Error(PagestreamErrorResponse {
+                                message: e.to_string(),
+                            })
+                        });

-            pgb.write_message(&BeMessage::CopyData(&response.serialize()))?;
+                        pgb.write_message(&BeMessage::CopyData(&response.serialize()))?;
+                    } else {
+                        break;
+                    }
+                }
+                Err(e) => {
+                    if !is_socket_read_timed_out(&e) {
+                        return Err(e);
+                    }
+                }
+            }
        }
-
        Ok(())
    }

@@ -363,6 +395,8 @@ impl PageServerHandler {
        timeline: &dyn Timeline,
        req: &PagestreamExistsRequest,
    ) -> Result<PagestreamBeMessage> {
+        let _enter = info_span!("get_rel_exists", rel = %req.rel, req_lsn = %req.lsn).entered();
+
        let tag = RelishTag::Relation(req.rel);
        let lsn = Self::wait_or_get_last_lsn(timeline, req.lsn, req.latest)?;

@@ -378,6 +412,7 @@ impl PageServerHandler {
        timeline: &dyn Timeline,
        req: &PagestreamNblocksRequest,
    ) -> Result<PagestreamBeMessage> {
+        let _enter = info_span!("get_nblocks", rel = %req.rel, req_lsn = %req.lsn).entered();
        let tag = RelishTag::Relation(req.rel);
        let lsn = Self::wait_or_get_last_lsn(timeline, req.lsn, req.latest)?;

@@ -397,6 +432,8 @@ impl PageServerHandler {
        timeline: &dyn Timeline,
        req: &PagestreamGetPageRequest,
    ) -> Result<PagestreamBeMessage> {
+        let _enter = info_span!("get_page", rel = %req.rel, blkno = &req.blkno, req_lsn = %req.lsn)
+            .entered();
        let tag = RelishTag::Relation(req.rel);
        let lsn = Self::wait_or_get_last_lsn(timeline, req.lsn, req.latest)?;

@@ -414,17 +451,20 @@ impl PageServerHandler {
        lsn: Option<Lsn>,
        tenantid: ZTenantId,
    ) -> anyhow::Result<()> {
+        let span = info_span!("basebackup", timeline = %timelineid, tenant = %tenantid, lsn = field::Empty);
+        let _enter = span.enter();
+
        // check that the timeline exists
        let timeline = tenant_mgr::get_timeline_for_tenant(tenantid, timelineid)?;

-        /* switch client to COPYOUT */
+        // switch client to COPYOUT
        pgb.write_message(&BeMessage::CopyOutResponse)?;
-        info!("sent CopyOut");

        /* Send a tarball of the latest layer on the timeline */
        {
            let mut writer = CopyDataSink { pgb };
            let mut basebackup = basebackup::Basebackup::new(&mut writer, &timeline, lsn)?;
+            span.record("lsn", &basebackup.lsn.to_string().as_str());
            basebackup.send_tarball()?;
        }
        pgb.write_message(&BeMessage::CopyDone)?;
@@ -529,11 +569,6 @@ impl postgres_backend::Handler for PageServerHandler {
                None
            };

-            info!(
-                "got basebackup command. tenantid=\"{}\" timelineid=\"{}\" lsn=\"{:#?}\"",
-                tenantid, timelineid, lsn
-            );
-
            // Check that the timeline exists
            self.handle_basebackup_request(pgb, timelineid, lsn, tenantid)?;
            pgb.write_message_noflush(&BeMessage::CommandComplete(b"SELECT 1"))?;
@@ -551,6 +586,9 @@ impl postgres_backend::Handler for PageServerHandler {

            self.check_permission(Some(tenantid))?;

+            let _enter =
+                info_span!("callmemaybe", timeline = %timelineid, tenant = %tenantid).entered();
+
            // Check that the timeline exists
            tenant_mgr::get_timeline_for_tenant(tenantid, timelineid)?;

@@ -573,6 +611,9 @@ impl postgres_backend::Handler for PageServerHandler {

            self.check_permission(Some(tenantid))?;

+            let _enter =
+                info_span!("branch_create", name = %branchname, tenant = %tenantid).entered();
+
            let branch =
                branches::create_branch(self.conf, &branchname, &startpoint_str, &tenantid)?;
            let branch = serde_json::to_vec(&branch)?;
@@ -55,15 +55,21 @@ pub trait RelishStorage: Send + Sync {

    async fn list_relishes(&self) -> anyhow::Result<Vec<Self::RelishStoragePath>>;

-    async fn download_relish(
+    async fn download_relish<W: 'static + std::io::Write + Send>(
        &self,
        from: &Self::RelishStoragePath,
-        to: &Path,
-    ) -> anyhow::Result<()>;
+        // rust_s3 `get_object_stream` method requires `std::io::BufWriter` for some reason, not the async counterpart
+        // that forces us to consume and return the writer to satisfy the blocking operation async wrapper requirements
+        to: std::io::BufWriter<W>,
+    ) -> anyhow::Result<std::io::BufWriter<W>>;

    async fn delete_relish(&self, path: &Self::RelishStoragePath) -> anyhow::Result<()>;

-    async fn upload_relish(&self, from: &Path, to: &Self::RelishStoragePath) -> anyhow::Result<()>;
+    async fn upload_relish<R: tokio::io::AsyncRead + std::marker::Unpin + Send>(
+        &self,
+        from: &mut tokio::io::BufReader<R>,
+        to: &Self::RelishStoragePath,
+    ) -> anyhow::Result<()>;
 }

 fn strip_workspace_prefix<'a>(
@@ -9,11 +9,13 @@

 use std::{
    future::Future,
+    io::Write,
    path::{Path, PathBuf},
    pin::Pin,
 };

 use anyhow::{bail, Context};
+use tokio::{fs, io};

 use super::{strip_workspace_prefix, RelishStorage};

@@ -64,16 +66,33 @@ impl RelishStorage for LocalFs {
        Ok(get_all_files(&self.root).await?.into_iter().collect())
    }

-    async fn download_relish(
+    async fn download_relish<W: 'static + std::io::Write + Send>(
        &self,
        from: &Self::RelishStoragePath,
-        to: &Path,
-    ) -> anyhow::Result<()> {
+        mut to: std::io::BufWriter<W>,
+    ) -> anyhow::Result<std::io::BufWriter<W>> {
        let file_path = self.resolve_in_storage(from)?;
        if file_path.exists() && file_path.is_file() {
-            create_target_directory(to).await?;
-            tokio::fs::copy(file_path, to).await?;
-            Ok(())
+            let updated_buffer = tokio::task::spawn_blocking(move || {
+                let mut source = std::io::BufReader::new(
+                    std::fs::OpenOptions::new()
+                        .read(true)
+                        .open(&file_path)
+                        .with_context(|| {
+                            format!(
+                                "Failed to open source file '{}' to use in the download",
+                                file_path.display()
+                            )
+                        })?,
+                );
+                std::io::copy(&mut source, &mut to)
+                    .context("Failed to download the relish file")?;
+                to.flush().context("Failed to flush the download buffer")?;
+                Ok::<_, anyhow::Error>(to)
+            })
+            .await
+            .context("Failed to spawn a blocking task")??;
+            Ok(updated_buffer)
        } else {
            bail!(
                "File '{}' either does not exist or is not a file",
@@ -94,18 +113,30 @@ impl RelishStorage for LocalFs {
        }
    }

-    async fn upload_relish(&self, from: &Path, to: &Self::RelishStoragePath) -> anyhow::Result<()> {
+    async fn upload_relish<R: io::AsyncRead + std::marker::Unpin + Send>(
+        &self,
+        from: &mut io::BufReader<R>,
+        to: &Self::RelishStoragePath,
+    ) -> anyhow::Result<()> {
        let target_file_path = self.resolve_in_storage(to)?;
        create_target_directory(&target_file_path).await?;
+        let mut destination = io::BufWriter::new(
+            fs::OpenOptions::new()
+                .write(true)
+                .create(true)
+                .open(&target_file_path)
+                .await
+                .with_context(|| {
+                    format!(
+                        "Failed to open target fs destination at '{}'",
+                        target_file_path.display()
+                    )
+                })?,
+        );

-        tokio::fs::copy(&from, &target_file_path)
+        io::copy_buf(from, &mut destination)
            .await
-            .with_context(|| {
-                format!(
-                    "Failed to upload relish '{}' to local storage",
-                    from.display(),
-                )
-            })?;
+            .context("Failed to upload relish to local storage")?;
        Ok(())
    }
 }
@@ -1,5 +1,6 @@
 //! A wrapper around AWS S3 client library `rust_s3` to be used a relish storage.

+use std::io::Write;
 use std::path::Path;

 use anyhow::Context;
@@ -83,18 +84,14 @@ impl RelishStorage for RustS3 {
            .collect())
    }

-    async fn download_relish(
+    async fn download_relish<W: 'static + std::io::Write + Send>(
        &self,
        from: &Self::RelishStoragePath,
-        to: &Path,
-    ) -> anyhow::Result<()> {
-        let mut target_file = std::fs::OpenOptions::new()
-            .write(true)
-            .open(to)
-            .with_context(|| format!("Failed to open target s3 destination at {}", to.display()))?;
+        mut to: std::io::BufWriter<W>,
+    ) -> anyhow::Result<std::io::BufWriter<W>> {
        let code = self
            .bucket
-            .get_object_stream(from.key(), &mut target_file)
+            .get_object_stream(from.key(), &mut to)
            .await
            .with_context(|| format!("Failed to download s3 object with key {}", from.key()))?;
        if code != 200 {
@@ -103,7 +100,12 @@ impl RelishStorage for RustS3 {
                code
            ))
        } else {
-            Ok(())
+            tokio::task::spawn_blocking(move || {
+                to.flush().context("Failed to fluch the downoad buffer")?;
+                Ok::<_, anyhow::Error>(to)
+            })
+            .await
+            .context("Failed to joim the download buffer flush task")?
        }
    }

@@ -124,12 +126,14 @@ impl RelishStorage for RustS3 {
        }
    }

-    async fn upload_relish(&self, from: &Path, to: &Self::RelishStoragePath) -> anyhow::Result<()> {
-        let mut local_file = tokio::fs::OpenOptions::new().read(true).open(from).await?;
-
+    async fn upload_relish<R: tokio::io::AsyncRead + std::marker::Unpin + Send>(
+        &self,
+        from: &mut tokio::io::BufReader<R>,
+        to: &Self::RelishStoragePath,
+    ) -> anyhow::Result<()> {
        let code = self
            .bucket
-            .put_object_stream(&mut local_file, to.key())
+            .put_object_stream(from, to.key())
            .await
            .with_context(|| format!("Failed to create s3 object with key {}", to.key()))?;
        if code != 200 {
@@ -1,6 +1,7 @@
 use std::time::Duration;
 use std::{collections::BinaryHeap, sync::Mutex, thread};

+use crate::tenant_mgr;
 use crate::{relish_storage::RelishStorage, PageServerConf};

 lazy_static::lazy_static! {
@@ -31,22 +32,26 @@ pub fn run_storage_sync_thread<

    let handle = thread::Builder::new()
        .name("Queue based relish storage sync".to_string())
-        .spawn(move || loop {
-            let mut queue_accessor = UPLOAD_QUEUE.lock().unwrap();
-            log::debug!("Upload queue length: {}", queue_accessor.len());
-            let next_task = queue_accessor.pop();
-            drop(queue_accessor);
-            match next_task {
-                Some(task) => runtime.block_on(async {
-                    // suppress warnings
-                    let _ = (config, task, &relish_storage, max_concurrent_sync);
-                    todo!("omitted for brevity")
-                }),
-                None => {
-                    thread::sleep(Duration::from_secs(1));
-                    continue;
+        .spawn(move || {
+            while !tenant_mgr::shutdown_requested() {
+                let mut queue_accessor = UPLOAD_QUEUE.lock().unwrap();
+                log::debug!("Upload queue length: {}", queue_accessor.len());
+                let next_task = queue_accessor.pop();
+                drop(queue_accessor);
+                match next_task {
+                    Some(task) => runtime.block_on(async {
+                        // suppress warnings
+                        let _ = (config, task, &relish_storage, max_concurrent_sync);
+                        todo!("omitted for brevity")
+                    }),
+                    None => {
+                        thread::sleep(Duration::from_secs(1));
+                        continue;
+                    }
                }
            }
+            log::debug!("Queue based relish storage sync thread shut down");
+            Ok(())
        })?;
    Ok(Some(handle))
 }
@@ -3,7 +3,7 @@ use anyhow::Result;
 use bytes::{Buf, BufMut, Bytes, BytesMut};
 use serde::{Deserialize, Serialize};
 use std::collections::HashSet;
-use std::ops::AddAssign;
+use std::ops::{AddAssign, Deref};
 use std::sync::Arc;
 use std::time::Duration;
 use zenith_utils::lsn::{Lsn, RecordLsn};
@@ -13,6 +13,8 @@ use zenith_utils::zid::ZTimelineId;
 /// A repository corresponds to one .zenith directory. One repository holds multiple
 /// timelines, forked off from the same initial call to 'initdb'.
 pub trait Repository: Send + Sync {
+    fn shutdown(&self) -> Result<()>;
+
    /// Get Timeline handle for given zenith timeline ID.
    fn get_timeline(&self, timelineid: ZTimelineId) -> Result<Arc<dyn Timeline>>;

@@ -123,26 +125,6 @@ pub trait Timeline: Send + Sync {
    // These are called by the WAL receiver to digest WAL records.
    //------------------------------------------------------------------------------

-    /// Put a new page version that can be constructed from a WAL record
-    ///
-    /// This will implicitly extend the relation, if the page is beyond the
-    /// current end-of-file.
-    fn put_wal_record(&self, tag: RelishTag, blknum: u32, rec: WALRecord) -> Result<()>;
-
-    /// Like put_wal_record, but with ready-made image of the page.
-    fn put_page_image(&self, tag: RelishTag, blknum: u32, lsn: Lsn, img: Bytes) -> Result<()>;
-
-    /// Truncate relation
-    fn put_truncation(&self, rel: RelishTag, lsn: Lsn, nblocks: u32) -> Result<()>;
-
-    /// This method is used for marking dropped relations and truncated SLRU files and aborted two phase records
-    fn drop_relish(&self, tag: RelishTag, lsn: Lsn) -> Result<()>;
-
-    /// Track end of the latest digested WAL record.
-    ///
-    /// Advance requires aligned LSN as an argument and would wake wait_lsn() callers.
-    /// Previous last record LSN is stored alongside the latest and can be read.
-    fn advance_last_record_lsn(&self, lsn: Lsn);
    /// Atomically get both last and prev.
    fn get_last_record_rlsn(&self) -> RecordLsn;
    /// Get last or prev record separately. Same as get_last_record_rlsn().last/prev.
@@ -150,6 +132,9 @@ pub trait Timeline: Send + Sync {
    fn get_prev_record_lsn(&self) -> Lsn;
    fn get_start_lsn(&self) -> Lsn;

+    /// Mutate the timeline with a [`TimelineWriter`].
+    fn writer<'a>(&'a self) -> Box<dyn TimelineWriter + 'a>;
+
    ///
    /// Flush to disk all data that was written with the put_* functions
    ///
@@ -168,9 +153,35 @@ pub trait Timeline: Send + Sync {
    fn get_current_logical_size_non_incremental(&self, lsn: Lsn) -> Result<usize>;
 }

+/// Various functions to mutate the timeline.
+// TODO Currently, Deref is used to allow easy access to read methods from this trait.
+// This is probably considered a bad practice in Rust and should be fixed eventually,
+// but will cause large code changes.
+pub trait TimelineWriter: Deref<Target = dyn Timeline> {
+    /// Put a new page version that can be constructed from a WAL record
+    ///
+    /// This will implicitly extend the relation, if the page is beyond the
+    /// current end-of-file.
+    fn put_wal_record(&self, lsn: Lsn, tag: RelishTag, blknum: u32, rec: WALRecord) -> Result<()>;
+
+    /// Like put_wal_record, but with ready-made image of the page.
+    fn put_page_image(&self, tag: RelishTag, blknum: u32, lsn: Lsn, img: Bytes) -> Result<()>;
+
+    /// Truncate relation
+    fn put_truncation(&self, rel: RelishTag, lsn: Lsn, nblocks: u32) -> Result<()>;
+
+    /// This method is used for marking dropped relations and truncated SLRU files and aborted two phase records
+    fn drop_relish(&self, tag: RelishTag, lsn: Lsn) -> Result<()>;
+
+    /// Track end of the latest digested WAL record.
+    ///
+    /// Advance requires aligned LSN as an argument and would wake wait_lsn() callers.
+    /// Previous last record LSN is stored alongside the latest and can be read.
+    fn advance_last_record_lsn(&self, lsn: Lsn);
+}
+
 #[derive(Debug, Clone, Serialize, Deserialize, PartialEq, Eq)]
 pub struct WALRecord {
-    pub lsn: Lsn, // LSN at the *end* of the record
    pub will_init: bool,
    pub rec: Bytes,
    // Remember the offset of main_data in rec,
@@ -181,22 +192,19 @@ pub struct WALRecord {

 impl WALRecord {
    pub fn pack(&self, buf: &mut BytesMut) {
-        buf.put_u64(self.lsn.0);
        buf.put_u8(self.will_init as u8);
        buf.put_u32(self.main_data_offset);
        buf.put_u32(self.rec.len() as u32);
        buf.put_slice(&self.rec[..]);
    }
    pub fn unpack(buf: &mut Bytes) -> WALRecord {
-        let lsn = Lsn::from(buf.get_u64());
        let will_init = buf.get_u8() != 0;
        let main_data_offset = buf.get_u32();
-        let mut dst = vec![0u8; buf.get_u32() as usize];
-        buf.copy_to_slice(&mut dst);
+        let rec_len = buf.get_u32() as usize;
+        let rec = buf.split_to(rec_len);
        WALRecord {
-            lsn,
            will_init,
-            rec: Bytes::from(dst),
+            rec,
            main_data_offset,
        }
    }
@@ -306,14 +314,15 @@ mod tests {

        // Create timeline to work on
        let tline = repo.create_empty_timeline(TIMELINE_ID)?;
+        let writer = tline.writer();

-        tline.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
-        tline.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
-        tline.put_page_image(TESTREL_A, 0, Lsn(0x30), TEST_IMG("foo blk 0 at 3"))?;
-        tline.put_page_image(TESTREL_A, 1, Lsn(0x40), TEST_IMG("foo blk 1 at 4"))?;
-        tline.put_page_image(TESTREL_A, 2, Lsn(0x50), TEST_IMG("foo blk 2 at 5"))?;
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x30), TEST_IMG("foo blk 0 at 3"))?;
+        writer.put_page_image(TESTREL_A, 1, Lsn(0x40), TEST_IMG("foo blk 1 at 4"))?;
+        writer.put_page_image(TESTREL_A, 2, Lsn(0x50), TEST_IMG("foo blk 2 at 5"))?;

-        tline.advance_last_record_lsn(Lsn(0x50));
+        writer.advance_last_record_lsn(Lsn(0x50));

        assert_current_logical_size(&tline, Lsn(0x50));

@@ -359,8 +368,8 @@ mod tests {
        );

        // Truncate last block
-        tline.put_truncation(TESTREL_A, Lsn(0x60), 2)?;
-        tline.advance_last_record_lsn(Lsn(0x60));
+        writer.put_truncation(TESTREL_A, Lsn(0x60), 2)?;
+        writer.advance_last_record_lsn(Lsn(0x60));
        assert_current_logical_size(&tline, Lsn(0x60));

        // Check reported size and contents after truncation
@@ -382,13 +391,13 @@ mod tests {
        );

        // Truncate to zero length
-        tline.put_truncation(TESTREL_A, Lsn(0x68), 0)?;
-        tline.advance_last_record_lsn(Lsn(0x68));
+        writer.put_truncation(TESTREL_A, Lsn(0x68), 0)?;
+        writer.advance_last_record_lsn(Lsn(0x68));
        assert_eq!(tline.get_relish_size(TESTREL_A, Lsn(0x68))?.unwrap(), 0);

        // Extend from 0 to 2 blocks, leaving a gap
-        tline.put_page_image(TESTREL_A, 1, Lsn(0x70), TEST_IMG("foo blk 1"))?;
-        tline.advance_last_record_lsn(Lsn(0x70));
+        writer.put_page_image(TESTREL_A, 1, Lsn(0x70), TEST_IMG("foo blk 1"))?;
+        writer.advance_last_record_lsn(Lsn(0x70));
        assert_eq!(tline.get_relish_size(TESTREL_A, Lsn(0x70))?.unwrap(), 2);
        assert_eq!(tline.get_page_at_lsn(TESTREL_A, 0, Lsn(0x70))?, ZERO_PAGE);
        assert_eq!(
@@ -423,25 +432,26 @@ mod tests {

        // Create timeline to work on
        let tline = repo.create_empty_timeline(TIMELINE_ID)?;
+        let writer = tline.writer();

-        tline.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
-        tline.advance_last_record_lsn(Lsn(0x20));
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
+        writer.advance_last_record_lsn(Lsn(0x20));

        // Check that rel exists and size is correct
        assert_eq!(tline.get_rel_exists(TESTREL_A, Lsn(0x20))?, true);
        assert_eq!(tline.get_relish_size(TESTREL_A, Lsn(0x20))?.unwrap(), 1);

        // Drop relish
-        tline.drop_relish(TESTREL_A, Lsn(0x30))?;
-        tline.advance_last_record_lsn(Lsn(0x30));
+        writer.drop_relish(TESTREL_A, Lsn(0x30))?;
+        writer.advance_last_record_lsn(Lsn(0x30));

        // Check that rel is not visible anymore
        assert_eq!(tline.get_rel_exists(TESTREL_A, Lsn(0x30))?, false);
        assert!(tline.get_relish_size(TESTREL_A, Lsn(0x30))?.is_none());

        // Extend it again
-        tline.put_page_image(TESTREL_A, 0, Lsn(0x40), TEST_IMG("foo blk 0 at 4"))?;
-        tline.advance_last_record_lsn(Lsn(0x40));
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x40), TEST_IMG("foo blk 0 at 4"))?;
+        writer.advance_last_record_lsn(Lsn(0x40));

        // Check that rel exists and size is correct
        assert_eq!(tline.get_rel_exists(TESTREL_A, Lsn(0x40))?, true);
@@ -459,6 +469,7 @@ mod tests {

        // Create timeline to work on
        let tline = repo.create_empty_timeline(TIMELINE_ID)?;
+        let writer = tline.writer();

        //from storage_layer.rs
        const RELISH_SEG_SIZE: u32 = 10 * 1024 * 1024 / 8192;
@@ -468,10 +479,10 @@ mod tests {
        for blkno in 0..relsize {
            let lsn = Lsn(0x20);
            let data = format!("foo blk {} at {}", blkno, lsn);
-            tline.put_page_image(TESTREL_A, blkno, lsn, TEST_IMG(&data))?;
+            writer.put_page_image(TESTREL_A, blkno, lsn, TEST_IMG(&data))?;
        }

-        tline.advance_last_record_lsn(Lsn(0x20));
+        writer.advance_last_record_lsn(Lsn(0x20));

        // The relation was created at LSN 2, not visible at LSN 1 yet.
        assert_eq!(tline.get_rel_exists(TESTREL_A, Lsn(0x10))?, false);
@@ -495,8 +506,8 @@ mod tests {

        // Truncate relation so that second segment was dropped
        // - only leave one page
-        tline.put_truncation(TESTREL_A, Lsn(0x60), 1)?;
-        tline.advance_last_record_lsn(Lsn(0x60));
+        writer.put_truncation(TESTREL_A, Lsn(0x60), 1)?;
+        writer.advance_last_record_lsn(Lsn(0x60));

        // Check reported size and contents after truncation
        assert_eq!(tline.get_relish_size(TESTREL_A, Lsn(0x60))?.unwrap(), 1);
@@ -529,9 +540,9 @@ mod tests {
        for blkno in 0..relsize {
            let lsn = Lsn(0x80);
            let data = format!("foo blk {} at {}", blkno, lsn);
-            tline.put_page_image(TESTREL_A, blkno, lsn, TEST_IMG(&data))?;
+            writer.put_page_image(TESTREL_A, blkno, lsn, TEST_IMG(&data))?;
        }
-        tline.advance_last_record_lsn(Lsn(0x80));
+        writer.advance_last_record_lsn(Lsn(0x80));

        assert_eq!(tline.get_rel_exists(TESTREL_A, Lsn(0x80))?, true);
        assert_eq!(
@@ -557,14 +568,15 @@ mod tests {
    fn test_large_rel() -> Result<()> {
        let repo = RepoHarness::create("test_large_rel")?.load();
        let tline = repo.create_empty_timeline(TIMELINE_ID)?;
+        let writer = tline.writer();

        let mut lsn = 0x10;
        for blknum in 0..pg_constants::RELSEG_SIZE + 1 {
            let img = TEST_IMG(&format!("foo blk {} at {}", blknum, Lsn(lsn)));
            lsn += 0x10;
-            tline.put_page_image(TESTREL_A, blknum as u32, Lsn(lsn), img)?;
+            writer.put_page_image(TESTREL_A, blknum as u32, Lsn(lsn), img)?;
        }
-        tline.advance_last_record_lsn(Lsn(lsn));
+        writer.advance_last_record_lsn(Lsn(lsn));

        assert_current_logical_size(&tline, Lsn(lsn));

@@ -575,8 +587,8 @@ mod tests {

        // Truncate one block
        lsn += 0x10;
-        tline.put_truncation(TESTREL_A, Lsn(lsn), pg_constants::RELSEG_SIZE)?;
-        tline.advance_last_record_lsn(Lsn(lsn));
+        writer.put_truncation(TESTREL_A, Lsn(lsn), pg_constants::RELSEG_SIZE)?;
+        writer.advance_last_record_lsn(Lsn(lsn));
        assert_eq!(
            tline.get_relish_size(TESTREL_A, Lsn(lsn))?.unwrap(),
            pg_constants::RELSEG_SIZE
@@ -585,8 +597,8 @@ mod tests {

        // Truncate another block
        lsn += 0x10;
-        tline.put_truncation(TESTREL_A, Lsn(lsn), pg_constants::RELSEG_SIZE - 1)?;
-        tline.advance_last_record_lsn(Lsn(lsn));
+        writer.put_truncation(TESTREL_A, Lsn(lsn), pg_constants::RELSEG_SIZE - 1)?;
+        writer.advance_last_record_lsn(Lsn(lsn));
        assert_eq!(
            tline.get_relish_size(TESTREL_A, Lsn(lsn))?.unwrap(),
            pg_constants::RELSEG_SIZE - 1
@@ -598,8 +610,8 @@ mod tests {
        let mut size: i32 = 3000;
        while size >= 0 {
            lsn += 0x10;
-            tline.put_truncation(TESTREL_A, Lsn(lsn), size as u32)?;
-            tline.advance_last_record_lsn(Lsn(lsn));
+            writer.put_truncation(TESTREL_A, Lsn(lsn), size as u32)?;
+            writer.advance_last_record_lsn(Lsn(lsn));
            assert_eq!(
                tline.get_relish_size(TESTREL_A, Lsn(lsn))?.unwrap(),
                size as u32
@@ -619,16 +631,17 @@ mod tests {
    fn test_list_rels_drop() -> Result<()> {
        let repo = RepoHarness::create("test_list_rels_drop")?.load();
        let tline = repo.create_empty_timeline(TIMELINE_ID)?;
+        let writer = tline.writer();
        const TESTDB: u32 = 111;

        // Import initial dummy checkpoint record, otherwise the get_timeline() call
        // after branching fails below
-        tline.put_page_image(RelishTag::Checkpoint, 0, Lsn(0x10), ZERO_CHECKPOINT.clone())?;
+        writer.put_page_image(RelishTag::Checkpoint, 0, Lsn(0x10), ZERO_CHECKPOINT.clone())?;

        // Create a relation on the timeline
-        tline.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;

-        tline.advance_last_record_lsn(Lsn(0x30));
+        writer.advance_last_record_lsn(Lsn(0x30));

        // Check that list_rels() lists it after LSN 2, but no before it
        assert!(!tline.list_rels(0, TESTDB, Lsn(0x10))?.contains(&TESTREL_A));
@@ -638,14 +651,17 @@ mod tests {
        // Create a branch, check that the relation is visible there
        repo.branch_timeline(TIMELINE_ID, NEW_TIMELINE_ID, Lsn(0x30))?;
        let newtline = repo.get_timeline(NEW_TIMELINE_ID)?;
+        let new_writer = newtline.writer();

        assert!(newtline
            .list_rels(0, TESTDB, Lsn(0x30))?
            .contains(&TESTREL_A));

        // Drop it on the branch
-        newtline.drop_relish(TESTREL_A, Lsn(0x40))?;
-        newtline.advance_last_record_lsn(Lsn(0x40));
+        new_writer.drop_relish(TESTREL_A, Lsn(0x40))?;
+        new_writer.advance_last_record_lsn(Lsn(0x40));
+
+        drop(new_writer);

        // Check that it's no longer listed on the branch after the point where it was dropped
        assert!(newtline
@@ -673,28 +689,30 @@ mod tests {
    fn test_branch() -> Result<()> {
        let repo = RepoHarness::create("test_branch")?.load();
        let tline = repo.create_empty_timeline(TIMELINE_ID)?;
+        let writer = tline.writer();

        // Import initial dummy checkpoint record, otherwise the get_timeline() call
        // after branching fails below
-        tline.put_page_image(RelishTag::Checkpoint, 0, Lsn(0x10), ZERO_CHECKPOINT.clone())?;
+        writer.put_page_image(RelishTag::Checkpoint, 0, Lsn(0x10), ZERO_CHECKPOINT.clone())?;

        // Create a relation on the timeline
-        tline.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
-        tline.put_page_image(TESTREL_A, 0, Lsn(0x30), TEST_IMG("foo blk 0 at 3"))?;
-        tline.put_page_image(TESTREL_A, 0, Lsn(0x40), TEST_IMG("foo blk 0 at 4"))?;
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x20), TEST_IMG("foo blk 0 at 2"))?;
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x30), TEST_IMG("foo blk 0 at 3"))?;
+        writer.put_page_image(TESTREL_A, 0, Lsn(0x40), TEST_IMG("foo blk 0 at 4"))?;

        // Create another relation
-        tline.put_page_image(TESTREL_B, 0, Lsn(0x20), TEST_IMG("foobar blk 0 at 2"))?;
+        writer.put_page_image(TESTREL_B, 0, Lsn(0x20), TEST_IMG("foobar blk 0 at 2"))?;

-        tline.advance_last_record_lsn(Lsn(0x40));
+        writer.advance_last_record_lsn(Lsn(0x40));
        assert_current_logical_size(&tline, Lsn(0x40));

        // Branch the history, modify relation differently on the new timeline
        repo.branch_timeline(TIMELINE_ID, NEW_TIMELINE_ID, Lsn(0x30))?;
        let newtline = repo.get_timeline(NEW_TIMELINE_ID)?;
+        let new_writer = newtline.writer();

-        newtline.put_page_image(TESTREL_A, 0, Lsn(0x40), TEST_IMG("bar blk 0 at 4"))?;
-        newtline.advance_last_record_lsn(Lsn(0x40));
+        new_writer.put_page_image(TESTREL_A, 0, Lsn(0x40), TEST_IMG("bar blk 0 at 4"))?;
+        new_writer.advance_last_record_lsn(Lsn(0x40));

        // Check page contents on both branches
        assert_eq!(
@@ -810,7 +828,7 @@ mod tests {
            blknum: u32,
            lsn: Lsn,
            base_img: Option<Bytes>,
-            records: Vec<WALRecord>,
+            records: Vec<(Lsn, WALRecord)>,
        ) -> Result<Bytes, WalRedoError> {
            let s = format!(
                "redo for {} blk {} to get to {}, with {} and {} records",
@@ -2,7 +2,6 @@
 //! Import data and WAL from a PostgreSQL data directory and WAL segments into
 //! zenith Timeline.
 //!
-use log::*;
 use postgres_ffi::nonrelfile_utils::clogpage_precedes;
 use postgres_ffi::nonrelfile_utils::slru_may_delete_clogsegment;
 use std::cmp::min;
@@ -13,6 +12,7 @@ use std::path::Path;

 use anyhow::{bail, Result};
 use bytes::{Buf, Bytes};
+use tracing::*;

 use crate::relish::*;
 use crate::repository::*;
@@ -34,7 +34,7 @@ static ZERO_PAGE: Bytes = Bytes::from_static(&[0u8; 8192]);
 ///
 pub fn import_timeline_from_postgres_datadir(
    path: &Path,
-    timeline: &dyn Timeline,
+    writer: &dyn TimelineWriter,
    lsn: Lsn,
 ) -> Result<()> {
    // Scan 'global'
@@ -44,10 +44,10 @@ pub fn import_timeline_from_postgres_datadir(
            None => continue,

            Some("pg_control") => {
-                import_control_file(timeline, lsn, &direntry.path())?;
+                import_control_file(writer, lsn, &direntry.path())?;
            }
            Some("pg_filenode.map") => import_nonrel_file(
-                timeline,
+                writer,
                lsn,
                RelishTag::FileNodeMap {
                    spcnode: pg_constants::GLOBALTABLESPACE_OID,
@@ -59,7 +59,7 @@ pub fn import_timeline_from_postgres_datadir(
            // Load any relation files into the page server
            _ => import_relfile(
                &direntry.path(),
-                timeline,
+                writer,
                lsn,
                pg_constants::GLOBALTABLESPACE_OID,
                0,
@@ -86,7 +86,7 @@ pub fn import_timeline_from_postgres_datadir(

                Some("PG_VERSION") => continue,
                Some("pg_filenode.map") => import_nonrel_file(
-                    timeline,
+                    writer,
                    lsn,
                    RelishTag::FileNodeMap {
                        spcnode: pg_constants::DEFAULTTABLESPACE_OID,
@@ -98,7 +98,7 @@ pub fn import_timeline_from_postgres_datadir(
                // Load any relation files into the page server
                _ => import_relfile(
                    &direntry.path(),
-                    timeline,
+                    writer,
                    lsn,
                    pg_constants::DEFAULTTABLESPACE_OID,
                    dboid,
@@ -108,24 +108,24 @@ pub fn import_timeline_from_postgres_datadir(
    }
    for entry in fs::read_dir(path.join("pg_xact"))? {
        let entry = entry?;
-        import_slru_file(timeline, lsn, SlruKind::Clog, &entry.path())?;
+        import_slru_file(writer, lsn, SlruKind::Clog, &entry.path())?;
    }
    for entry in fs::read_dir(path.join("pg_multixact").join("members"))? {
        let entry = entry?;
-        import_slru_file(timeline, lsn, SlruKind::MultiXactMembers, &entry.path())?;
+        import_slru_file(writer, lsn, SlruKind::MultiXactMembers, &entry.path())?;
    }
    for entry in fs::read_dir(path.join("pg_multixact").join("offsets"))? {
        let entry = entry?;
-        import_slru_file(timeline, lsn, SlruKind::MultiXactOffsets, &entry.path())?;
+        import_slru_file(writer, lsn, SlruKind::MultiXactOffsets, &entry.path())?;
    }
    for entry in fs::read_dir(path.join("pg_twophase"))? {
        let entry = entry?;
        let xid = u32::from_str_radix(entry.path().to_str().unwrap(), 16)?;
-        import_nonrel_file(timeline, lsn, RelishTag::TwoPhase { xid }, &entry.path())?;
+        import_nonrel_file(writer, lsn, RelishTag::TwoPhase { xid }, &entry.path())?;
    }
    // TODO: Scan pg_tblspc

-    timeline.advance_last_record_lsn(lsn);
+    writer.advance_last_record_lsn(lsn);

    Ok(())
 }
@@ -133,12 +133,13 @@ pub fn import_timeline_from_postgres_datadir(
 // subroutine of import_timeline_from_postgres_datadir(), to load one relation file.
 fn import_relfile(
    path: &Path,
-    timeline: &dyn Timeline,
+    timeline: &dyn TimelineWriter,
    lsn: Lsn,
    spcoid: Oid,
    dboid: Oid,
 ) -> Result<()> {
    // Does it look like a relation file?
+    trace!("importing rel file {}", path.display());

    let p = parse_relfilename(path.file_name().unwrap().to_str().unwrap());
    if let Err(e) = p {
@@ -166,14 +167,14 @@ fn import_relfile(
            }

            // TODO: UnexpectedEof is expected
-            Err(e) => match e.kind() {
+            Err(err) => match err.kind() {
                std::io::ErrorKind::UnexpectedEof => {
                    // reached EOF. That's expected.
                    // FIXME: maybe check that we read the full length of the file?
                    break;
                }
                _ => {
-                    bail!("error reading file {}: {:#}", path.display(), e);
+                    bail!("error reading file {}: {:#}", path.display(), err);
                }
            },
        };
@@ -190,7 +191,7 @@ fn import_relfile(
 /// are just slurped into the repository as one blob.
 ///
 fn import_nonrel_file(
-    timeline: &dyn Timeline,
+    timeline: &dyn TimelineWriter,
    lsn: Lsn,
    tag: RelishTag,
    path: &Path,
@@ -200,7 +201,7 @@ fn import_nonrel_file(
    // read the whole file
    file.read_to_end(&mut buffer)?;

-    info!("importing non-rel file {}", path.display());
+    trace!("importing non-rel file {}", path.display());

    timeline.put_page_image(tag, 0, lsn, Bytes::copy_from_slice(&buffer[..]))?;
    Ok(())
@@ -211,13 +212,13 @@ fn import_nonrel_file(
 ///
 /// The control file is imported as is, but we also extract the checkpoint record
 /// from it and store it separated.
-fn import_control_file(timeline: &dyn Timeline, lsn: Lsn, path: &Path) -> Result<()> {
+fn import_control_file(timeline: &dyn TimelineWriter, lsn: Lsn, path: &Path) -> Result<()> {
    let mut file = File::open(path)?;
    let mut buffer = Vec::new();
    // read the whole file
    file.read_to_end(&mut buffer)?;

-    info!("importing control file {}", path.display());
+    trace!("importing control file {}", path.display());

    // Import it as ControlFile
    timeline.put_page_image(
@@ -238,13 +239,18 @@ fn import_control_file(timeline: &dyn Timeline, lsn: Lsn, path: &Path) -> Result
 ///
 /// Import an SLRU segment file
 ///
-fn import_slru_file(timeline: &dyn Timeline, lsn: Lsn, slru: SlruKind, path: &Path) -> Result<()> {
+fn import_slru_file(
+    timeline: &dyn TimelineWriter,
+    lsn: Lsn,
+    slru: SlruKind,
+    path: &Path,
+) -> Result<()> {
    // Does it look like an SLRU file?
    let mut file = File::open(path)?;
    let mut buf: [u8; 8192] = [0u8; 8192];
    let segno = u32::from_str_radix(path.file_name().unwrap().to_str().unwrap(), 16)?;

-    info!("importing slru file {}", path.display());
+    trace!("importing slru file {}", path.display());

    let mut rpageno = 0;
    loop {
@@ -260,14 +266,14 @@ fn import_slru_file(timeline: &dyn Timeline, lsn: Lsn, slru: SlruKind, path: &Pa
            }

            // TODO: UnexpectedEof is expected
-            Err(e) => match e.kind() {
+            Err(err) => match err.kind() {
                std::io::ErrorKind::UnexpectedEof => {
                    // reached EOF. That's expected.
                    // FIXME: maybe check that we read the full length of the file?
                    break;
                }
                _ => {
-                    bail!("error reading file {}: {:#}", path.display(), e);
+                    bail!("error reading file {}: {:#}", path.display(), err);
                }
            },
        };
@@ -285,12 +291,15 @@ fn import_slru_file(timeline: &dyn Timeline, lsn: Lsn, slru: SlruKind, path: &Pa
 ///
 pub fn save_decoded_record(
    checkpoint: &mut CheckPoint,
-    timeline: &dyn Timeline,
+    checkpoint_modified: &mut bool,
+    timeline: &dyn TimelineWriter,
    decoded: &DecodedWALRecord,
    recdata: Bytes,
    lsn: Lsn,
 ) -> Result<()> {
-    checkpoint.update_next_xid(decoded.xl_xid);
+    if checkpoint.update_next_xid(decoded.xl_xid) {
+        *checkpoint_modified = true;
+    }

    // Iterate through all the blocks that the record modifies, and
    // "put" a separate copy of the record for each block.
@@ -303,13 +312,12 @@ pub fn save_decoded_record(
        });

        let rec = WALRecord {
-            lsn,
            will_init: blk.will_init || blk.apply_image,
            rec: recdata.clone(),
            main_data_offset: decoded.main_data_offset as u32,
        };

-        timeline.put_wal_record(tag, blk.blkno, rec)?;
+        timeline.put_wal_record(lsn, tag, blk.blkno, rec)?;
    }

    let mut buf = decoded.record.clone();
@@ -374,7 +382,7 @@ pub fn save_decoded_record(
        } else {
            assert!(info == pg_constants::CLOG_TRUNCATE);
            let xlrec = XlClogTruncate::decode(&mut buf);
-            save_clog_truncate_record(checkpoint, timeline, lsn, &xlrec)?;
+            save_clog_truncate_record(checkpoint, checkpoint_modified, timeline, lsn, &xlrec)?;
        }
    } else if decoded.xl_rmid == pg_constants::RM_XACT_ID {
        let info = decoded.xl_info & pg_constants::XLOG_XACT_OPMASK;
@@ -443,10 +451,17 @@ pub fn save_decoded_record(
            )?;
        } else if info == pg_constants::XLOG_MULTIXACT_CREATE_ID {
            let xlrec = XlMultiXactCreate::decode(&mut buf);
-            save_multixact_create_record(checkpoint, timeline, lsn, &xlrec, decoded)?;
+            save_multixact_create_record(
+                checkpoint,
+                checkpoint_modified,
+                timeline,
+                lsn,
+                &xlrec,
+                decoded,
+            )?;
        } else if info == pg_constants::XLOG_MULTIXACT_TRUNCATE_ID {
            let xlrec = XlMultiXactTruncate::decode(&mut buf);
-            save_multixact_truncate_record(checkpoint, timeline, lsn, &xlrec)?;
+            save_multixact_truncate_record(checkpoint, checkpoint_modified, timeline, lsn, &xlrec)?;
        }
    } else if decoded.xl_rmid == pg_constants::RM_RELMAP_ID {
        let xlrec = XlRelmapUpdate::decode(&mut buf);
@@ -455,7 +470,10 @@ pub fn save_decoded_record(
        let info = decoded.xl_info & pg_constants::XLR_RMGR_INFO_MASK;
        if info == pg_constants::XLOG_NEXTOID {
            let next_oid = buf.get_u32_le();
-            checkpoint.nextOid = next_oid;
+            if checkpoint.nextOid != next_oid {
+                checkpoint.nextOid = next_oid;
+                *checkpoint_modified = true;
+            }
        } else if info == pg_constants::XLOG_CHECKPOINT_ONLINE
            || info == pg_constants::XLOG_CHECKPOINT_SHUTDOWN
        {
@@ -471,6 +489,7 @@ pub fn save_decoded_record(
            );
            if (checkpoint.oldestXid.wrapping_sub(xlog_checkpoint.oldestXid) as i32) < 0 {
                checkpoint.oldestXid = xlog_checkpoint.oldestXid;
+                *checkpoint_modified = true;
            }
        }
    }
@@ -478,7 +497,11 @@ pub fn save_decoded_record(
 }

 /// Subroutine of save_decoded_record(), to handle an XLOG_DBASE_CREATE record.
-fn save_xlog_dbase_create(timeline: &dyn Timeline, lsn: Lsn, rec: &XlCreateDatabase) -> Result<()> {
+fn save_xlog_dbase_create(
+    timeline: &dyn TimelineWriter,
+    lsn: Lsn,
+    rec: &XlCreateDatabase,
+) -> Result<()> {
    let db_id = rec.db_id;
    let tablespace_id = rec.tablespace_id;
    let src_db_id = rec.src_db_id;
@@ -555,7 +578,11 @@ fn save_xlog_dbase_create(timeline: &dyn Timeline, lsn: Lsn, rec: &XlCreateDatab
 /// Subroutine of save_decoded_record(), to handle an XLOG_SMGR_TRUNCATE record.
 ///
 /// This is the same logic as in PostgreSQL's smgr_redo() function.
-fn save_xlog_smgr_truncate(timeline: &dyn Timeline, lsn: Lsn, rec: &XlSmgrTruncate) -> Result<()> {
+fn save_xlog_smgr_truncate(
+    timeline: &dyn TimelineWriter,
+    lsn: Lsn,
+    rec: &XlSmgrTruncate,
+) -> Result<()> {
    let spcnode = rec.rnode.spcnode;
    let dbnode = rec.rnode.dbnode;
    let relnode = rec.rnode.relnode;
@@ -617,7 +644,7 @@ fn save_xlog_smgr_truncate(timeline: &dyn Timeline, lsn: Lsn, rec: &XlSmgrTrunca
 /// Subroutine of save_decoded_record(), to handle an XLOG_XACT_* records.
 ///
 fn save_xact_record(
-    timeline: &dyn Timeline,
+    timeline: &dyn TimelineWriter,
    lsn: Lsn,
    parsed: &XlXactParsedRecord,
    decoded: &DecodedWALRecord,
@@ -628,12 +655,12 @@ fn save_xact_record(
    let segno = pageno / pg_constants::SLRU_PAGES_PER_SEGMENT;
    let rpageno = pageno % pg_constants::SLRU_PAGES_PER_SEGMENT;
    let rec = WALRecord {
-        lsn,
        will_init: false,
        rec: decoded.record.clone(),
        main_data_offset: decoded.main_data_offset as u32,
    };
    timeline.put_wal_record(
+        lsn,
        RelishTag::Slru {
            slru: SlruKind::Clog,
            segno,
@@ -649,6 +676,7 @@ fn save_xact_record(
            let segno = pageno / pg_constants::SLRU_PAGES_PER_SEGMENT;
            let rpageno = pageno % pg_constants::SLRU_PAGES_PER_SEGMENT;
            timeline.put_wal_record(
+                lsn,
                RelishTag::Slru {
                    slru: SlruKind::Clog,
                    segno,
@@ -674,7 +702,8 @@ fn save_xact_record(

 fn save_clog_truncate_record(
    checkpoint: &mut CheckPoint,
-    timeline: &dyn Timeline,
+    checkpoint_modified: &mut bool,
+    timeline: &dyn TimelineWriter,
    lsn: Lsn,
    xlrec: &XlClogTruncate,
 ) -> Result<()> {
@@ -692,6 +721,7 @@ fn save_clog_truncate_record(
    // TODO Figure out if there will be any issues with replica.
    checkpoint.oldestXid = xlrec.oldest_xid;
    checkpoint.oldestXidDB = xlrec.oldest_xid_db;
+    *checkpoint_modified = true;

    // TODO Treat AdvanceOldestClogXid() or write a comment why we don't need it

@@ -734,13 +764,13 @@ fn save_clog_truncate_record(

 fn save_multixact_create_record(
    checkpoint: &mut CheckPoint,
-    timeline: &dyn Timeline,
+    checkpoint_modified: &mut bool,
+    timeline: &dyn TimelineWriter,
    lsn: Lsn,
    xlrec: &XlMultiXactCreate,
    decoded: &DecodedWALRecord,
 ) -> Result<()> {
    let rec = WALRecord {
-        lsn,
        will_init: false,
        rec: decoded.record.clone(),
        main_data_offset: decoded.main_data_offset as u32,
@@ -749,6 +779,7 @@ fn save_multixact_create_record(
    let segno = pageno / pg_constants::SLRU_PAGES_PER_SEGMENT;
    let rpageno = pageno % pg_constants::SLRU_PAGES_PER_SEGMENT;
    timeline.put_wal_record(
+        lsn,
        RelishTag::Slru {
            slru: SlruKind::MultiXactOffsets,
            segno,
@@ -768,6 +799,7 @@ fn save_multixact_create_record(
        let segno = pageno / pg_constants::SLRU_PAGES_PER_SEGMENT;
        let rpageno = pageno % pg_constants::SLRU_PAGES_PER_SEGMENT;
        timeline.put_wal_record(
+            lsn,
            RelishTag::Slru {
                slru: SlruKind::MultiXactMembers,
                segno,
@@ -790,9 +822,11 @@ fn save_multixact_create_record(
    }
    if xlrec.mid >= checkpoint.nextMulti {
        checkpoint.nextMulti = xlrec.mid + 1;
+        *checkpoint_modified = true;
    }
    if xlrec.moff + xlrec.nmembers > checkpoint.nextMultiOffset {
        checkpoint.nextMultiOffset = xlrec.moff + xlrec.nmembers;
+        *checkpoint_modified = true;
    }
    let max_mbr_xid = xlrec.members.iter().fold(0u32, |acc, mbr| {
        if mbr.xid.wrapping_sub(acc) as i32 > 0 {
@@ -802,18 +836,22 @@ fn save_multixact_create_record(
        }
    });

-    checkpoint.update_next_xid(max_mbr_xid);
+    if checkpoint.update_next_xid(max_mbr_xid) {
+        *checkpoint_modified = true;
+    }
    Ok(())
 }

 fn save_multixact_truncate_record(
    checkpoint: &mut CheckPoint,
-    timeline: &dyn Timeline,
+    checkpoint_modified: &mut bool,
+    timeline: &dyn TimelineWriter,
    lsn: Lsn,
    xlrec: &XlMultiXactTruncate,
 ) -> Result<()> {
    checkpoint.oldestMulti = xlrec.end_trunc_off;
    checkpoint.oldestMultiDB = xlrec.oldest_multi_db;
+    *checkpoint_modified = true;

    // PerformMembersTruncation
    let maxsegment: i32 = mx_offset_to_member_segment(pg_constants::MAX_MULTIXACT_OFFSET);
@@ -847,7 +885,7 @@ fn save_multixact_truncate_record(
 }

 fn save_relmap_page(
-    timeline: &dyn Timeline,
+    timeline: &dyn TimelineWriter,
    lsn: Lsn,
    xlrec: &XlRelmapUpdate,
    decoded: &DecodedWALRecord,
@@ -8,12 +8,14 @@ use crate::walredo::PostgresRedoManager;
 use crate::PageServerConf;
 use anyhow::{anyhow, bail, Context, Result};
 use lazy_static::lazy_static;
-use log::info;
+use log::{debug, info};
 use std::collections::hash_map::Entry;
 use std::collections::HashMap;
 use std::fs;
 use std::str::FromStr;
+use std::sync::atomic::{AtomicBool, Ordering};
 use std::sync::{Arc, Mutex, MutexGuard};
+use std::thread::JoinHandle;
 use zenith_utils::zid::{ZTenantId, ZTimelineId};

 lazy_static! {
@@ -24,6 +26,19 @@ lazy_static! {
 fn access_repository() -> MutexGuard<'static, HashMap<ZTenantId, Arc<dyn Repository>>> {
    REPOSITORY.lock().unwrap()
 }
+struct TenantHandleEntry {
+    checkpointer_handle: Option<JoinHandle<()>>,
+    gc_handle: Option<JoinHandle<()>>,
+}
+
+// Logically these handles belong to Repository,
+// but it's just simpler to store them separately
+lazy_static! {
+    static ref TENANT_HANDLES: Mutex<HashMap<ZTenantId, TenantHandleEntry>> =
+        Mutex::new(HashMap::new());
+}
+
+static SHUTDOWN_REQUESTED: AtomicBool = AtomicBool::new(false);

 pub fn init(conf: &'static PageServerConf) {
    let mut m = access_repository();
@@ -47,8 +62,18 @@ fn init_repo(conf: &'static PageServerConf, tenant_id: ZTenantId) -> Arc<Layered
        tenant_id,
        true,
    ));
-    LayeredRepository::launch_checkpointer_thread(conf, repo.clone());
-    LayeredRepository::launch_gc_thread(conf, repo.clone());
+
+    let checkpointer_handle = LayeredRepository::launch_checkpointer_thread(conf, repo.clone());
+    let gc_handle = LayeredRepository::launch_gc_thread(conf, repo.clone());
+
+    let mut handles = TENANT_HANDLES.lock().unwrap();
+    let h = TenantHandleEntry {
+        checkpointer_handle: Some(checkpointer_handle),
+        gc_handle: Some(gc_handle),
+    };
+
+    handles.insert(tenant_id, h);
+
    repo
 }

@@ -82,6 +107,35 @@ fn init_timeline(repo: &dyn Repository, timeline_id: ZTimelineId) {
    }
 }

+// Check this flag in the thread loops to know when to exit
+pub fn shutdown_requested() -> bool {
+    SHUTDOWN_REQUESTED.load(Ordering::Relaxed)
+}
+
+pub fn stop_tenant_threads(tenantid: ZTenantId) {
+    let mut handles = TENANT_HANDLES.lock().unwrap();
+    if let Some(h) = handles.get_mut(&tenantid) {
+        h.checkpointer_handle.take().map(JoinHandle::join);
+        debug!("checkpointer for tenant {} has stopped", tenantid);
+        h.gc_handle.take().map(JoinHandle::join);
+        debug!("gc for tenant {} has stopped", tenantid);
+    }
+}
+
+pub fn shutdown_all_tenants() -> Result<()> {
+    SHUTDOWN_REQUESTED.swap(true, Ordering::Relaxed);
+
+    let tenants = list_tenants()?;
+    for tenantid in tenants {
+        stop_tenant_threads(tenantid);
+        let repo = get_repository_for_tenant(tenantid)?;
+        debug!("shutdown tenant {}", tenantid);
+        repo.shutdown()?;
+    }
+
+    Ok(())
+}
+
 pub fn create_repository_for_tenant(
    conf: &'static PageServerConf,
    tenantid: ZTenantId,
@@ -115,3 +169,14 @@ pub fn get_timeline_for_tenant(
        .get_timeline(timelineid)
        .with_context(|| format!("cannot fetch timeline {}", timelineid))
 }
+
+fn list_tenants() -> Result<Vec<ZTenantId>> {
+    let o = &mut REPOSITORY.lock().unwrap();
+
+    o.iter()
+        .map(|tenant| {
+            let (tenantid, _) = tenant;
+            Ok(*tenantid)
+        })
+        .collect()
+}
@@ -72,6 +72,10 @@ impl WalStreamDecoder {
    ///     Err(WalDecodeError): an error occured while decoding, meaning the input was invalid.
    ///
    pub fn poll_decode(&mut self) -> Result<Option<(Lsn, Bytes)>, WalDecodeError> {
+        let recordbuf;
+
+        // Run state machine that validates page headers, and reassembles records
+        // that cross page boundaries.
        loop {
            // parse and verify page boundaries as we go
            if self.lsn.segment_offset(pg_constants::WAL_SEGMENT_SIZE) == 0 {
@@ -120,29 +124,41 @@ impl WalStreamDecoder {
                self.lsn += self.padlen as u64;
                self.padlen = 0;
            } else if self.contlen == 0 {
-                // need to have at least the xl_tot_len field
+                assert!(self.recordbuf.is_empty());

+                // need to have at least the xl_tot_len field
                if self.inputbuf.remaining() < 4 {
                    return Ok(None);
                }

-                // read xl_tot_len FIXME: assumes little-endian
+                // peek xl_tot_len at the beginning of the record.
+                // FIXME: assumes little-endian
                self.startlsn = self.lsn;
-                let xl_tot_len = self.inputbuf.get_u32_le();
+                let xl_tot_len = (&self.inputbuf[0..4]).get_u32_le();
                if (xl_tot_len as usize) < XLOG_SIZE_OF_XLOG_RECORD {
                    return Err(WalDecodeError {
                        msg: format!("invalid xl_tot_len {}", xl_tot_len),
                        lsn: self.lsn,
                    });
                }
-                self.lsn += 4;

-                self.recordbuf.clear();
-                self.recordbuf.reserve(xl_tot_len as usize);
-                self.recordbuf.put_u32_le(xl_tot_len);
-
-                self.contlen = xl_tot_len - 4;
-                continue;
+                // Fast path for the common case that the whole record fits on the page.
+                let pageleft = self.lsn.remaining_in_block() as u32;
+                if self.inputbuf.remaining() >= xl_tot_len as usize && xl_tot_len <= pageleft {
+                    // Take the record from the 'inputbuf', and validate it.
+                    recordbuf = self.inputbuf.copy_to_bytes(xl_tot_len as usize);
+                    self.lsn += xl_tot_len as u64;
+                    break;
+                } else {
+                    // Need to assemble the record from pieces. Remember the size of the
+                    // record, and loop back. On next iteration, we will reach the 'else'
+                    // branch below, and copy the part of the record that was on this page
+                    // to 'recordbuf'.  Subsequent iterations will skip page headers, and
+                    // append the continuations from the next pages to 'recordbuf'.
+                    self.recordbuf.reserve(xl_tot_len as usize);
+                    self.contlen = xl_tot_len;
+                    continue;
+                }
            } else {
                // we're continuing a record, possibly from previous page.
                let pageleft = self.lsn.remaining_in_block() as u32;
@@ -159,47 +175,42 @@ impl WalStreamDecoder {
                self.contlen -= n as u32;

                if self.contlen == 0 {
-                    let recordbuf = std::mem::replace(&mut self.recordbuf, BytesMut::new());
-
-                    let recordbuf = recordbuf.freeze();
-                    let mut buf = recordbuf.clone();
-
-                    let xlogrec = XLogRecord::from_bytes(&mut buf);
-
-                    // XLOG_SWITCH records are special. If we see one, we need to skip
-                    // to the next WAL segment.
-                    if xlogrec.is_xlog_switch_record() {
-                        trace!("saw xlog switch record at {}", self.lsn);
-                        self.padlen =
-                            self.lsn.calc_padding(pg_constants::WAL_SEGMENT_SIZE as u64) as u32;
-                    } else {
-                        // Pad to an 8-byte boundary
-                        self.padlen = self.lsn.calc_padding(8u32) as u32;
-                    }
-
-                    let mut crc = crc32c_append(0, &recordbuf[XLOG_RECORD_CRC_OFFS + 4..]);
-                    crc = crc32c_append(crc, &recordbuf[0..XLOG_RECORD_CRC_OFFS]);
-                    if crc != xlogrec.xl_crc {
-                        return Err(WalDecodeError {
-                            msg: "WAL record crc mismatch".into(),
-                            lsn: self.lsn,
-                        });
-                    }
-
-                    // Always align resulting LSN on 0x8 boundary -- that is important for getPage()
-                    // and WalReceiver integration. Since this code is used both for WalReceiver and
-                    // initial WAL import let's force alignment right here.
-                    let result = (self.lsn.align(), recordbuf);
-                    return Ok(Some(result));
+                    // The record is now complete.
+                    recordbuf = std::mem::replace(&mut self.recordbuf, BytesMut::new()).freeze();
+                    break;
                }
                continue;
            }
        }
-        // check record boundaries

-        // deal with continuation records
+        // We now have a record in the 'recordbuf' local variable.
+        let xlogrec = XLogRecord::from_slice(&recordbuf[0..XLOG_SIZE_OF_XLOG_RECORD]);

-        // deal with xlog_switch records
+        let mut crc = 0;
+        crc = crc32c_append(crc, &recordbuf[XLOG_RECORD_CRC_OFFS + 4..]);
+        crc = crc32c_append(crc, &recordbuf[0..XLOG_RECORD_CRC_OFFS]);
+        if crc != xlogrec.xl_crc {
+            return Err(WalDecodeError {
+                msg: "WAL record crc mismatch".into(),
+                lsn: self.lsn,
+            });
+        }
+
+        // XLOG_SWITCH records are special. If we see one, we need to skip
+        // to the next WAL segment.
+        if xlogrec.is_xlog_switch_record() {
+            trace!("saw xlog switch record at {}", self.lsn);
+            self.padlen = self.lsn.calc_padding(pg_constants::WAL_SEGMENT_SIZE as u64) as u32;
+        } else {
+            // Pad to an 8-byte boundary
+            self.padlen = self.lsn.calc_padding(8u32) as u32;
+        }
+
+        // Always align resulting LSN on 0x8 boundary -- that is important for getPage()
+        // and WalReceiver integration. Since this code is used both for WalReceiver and
+        // initial WAL import let's force alignment right here.
+        let result = (self.lsn.align(), recordbuf);
+        Ok(Some(result))
    }
 }

@@ -12,7 +12,6 @@ use crate::waldecoder::*;
 use crate::PageServerConf;
 use anyhow::{bail, Error, Result};
 use lazy_static::lazy_static;
-use log::*;
 use postgres::fallible_iterator::FallibleIterator;
 use postgres::replication::ReplicationIter;
 use postgres::{Client, NoTls, SimpleQueryMessage, SimpleQueryRow};
@@ -25,8 +24,10 @@ use std::str::FromStr;
 use std::sync::Mutex;
 use std::thread;
 use std::thread::sleep;
+use std::thread::JoinHandle;
 use std::thread_local;
 use std::time::{Duration, SystemTime};
+use tracing::*;
 use zenith_utils::lsn::Lsn;
 use zenith_utils::zid::ZTenantId;
 use zenith_utils::zid::ZTimelineId;
@@ -36,6 +37,7 @@ use zenith_utils::zid::ZTimelineId;
 //
 struct WalReceiverEntry {
    wal_producer_connstr: String,
+    wal_receiver_handle: Option<JoinHandle<()>>,
 }

 lazy_static! {
@@ -50,6 +52,19 @@ thread_local! {
    pub(crate) static IS_WAL_RECEIVER: Cell<bool> = Cell::new(false);
 }

+// Wait for walreceiver to stop
+// Now it stops when pageserver shutdown is requested.
+// In future we can make this more granular and send shutdown signals
+// per tenant/timeline to cancel inactive walreceivers.
+// TODO deal with blocking pg connections
+pub fn stop_wal_receiver(timelineid: ZTimelineId) {
+    let mut receivers = WAL_RECEIVERS.lock().unwrap();
+    if let Some(r) = receivers.get_mut(&timelineid) {
+        r.wal_receiver_handle.take();
+        // r.wal_receiver_handle.take().map(JoinHandle::join);
+    }
+}
+
 // Launch a new WAL receiver, or tell one that's running about change in connection string
 pub fn launch_wal_receiver(
    conf: &'static PageServerConf,
@@ -64,19 +79,19 @@ pub fn launch_wal_receiver(
            receiver.wal_producer_connstr = wal_producer_connstr.into();
        }
        None => {
-            let receiver = WalReceiverEntry {
-                wal_producer_connstr: wal_producer_connstr.into(),
-            };
-            receivers.insert(timelineid, receiver);
-
-            // Also launch a new thread to handle this connection
-            let _walreceiver_thread = thread::Builder::new()
+            let wal_receiver_handle = thread::Builder::new()
                .name("WAL receiver thread".into())
                .spawn(move || {
                    IS_WAL_RECEIVER.with(|c| c.set(true));
                    thread_main(conf, timelineid, tenantid);
                })
                .unwrap();
+
+            let receiver = WalReceiverEntry {
+                wal_producer_connstr: wal_producer_connstr.into(),
+                wal_receiver_handle: Some(wal_receiver_handle),
+            };
+            receivers.insert(timelineid, receiver);
        }
    };
 }
@@ -96,16 +111,14 @@ fn get_wal_producer_connstr(timelineid: ZTimelineId) -> String {
 // This is the entry point for the WAL receiver thread.
 //
 fn thread_main(conf: &'static PageServerConf, timelineid: ZTimelineId, tenantid: ZTenantId) {
-    info!(
-        "WAL receiver thread started for timeline : '{}'",
-        timelineid
-    );
+    let _enter = info_span!("WAL receiver", timeline = %timelineid, tenant = %tenantid).entered();
+    info!("WAL receiver thread started");

    //
    // Make a connection to the WAL safekeeper, or directly to the primary PostgreSQL server,
    // and start streaming WAL from it. If the connection is lost, keep retrying.
    //
-    loop {
+    while !tenant_mgr::shutdown_requested() {
        // Look up the current WAL producer address
        let wal_producer_connstr = get_wal_producer_connstr(timelineid);

@@ -119,6 +132,7 @@ fn thread_main(conf: &'static PageServerConf, timelineid: ZTimelineId, tenantid:
            sleep(Duration::from_secs(1));
        }
    }
+    debug!("WAL streaming shut down");
 }

 fn walreceiver_main(
@@ -169,8 +183,8 @@ fn walreceiver_main(
    startpoint += startpoint.calc_padding(8u32);

    info!(
-        "last_record_lsn {} starting replication from {} for timeline {}, server is at {}...",
-        last_rec_lsn, startpoint, timelineid, end_of_wal
+        "last_record_lsn {} starting replication from {}, server is at {}...",
+        last_rec_lsn, startpoint, end_of_wal
    );

    let query = format!("START_REPLICATION PHYSICAL {}", startpoint);
@@ -198,27 +212,32 @@ fn walreceiver_main(
                waldecoder.feed_bytes(data);

                while let Some((lsn, recdata)) = waldecoder.poll_decode()? {
-                    // Save old checkpoint value to compare with it after decoding WAL record
-                    let old_checkpoint_bytes = checkpoint.encode();
-                    let decoded = decode_wal_record(recdata.clone());
+                    let _enter = info_span!("processing record", lsn = %lsn).entered();

                    // It is important to deal with the aligned records as lsn in getPage@LSN is
                    // aligned and can be several bytes bigger. Without this alignment we are
                    // at risk of hittind a deadlock.
                    assert!(lsn.is_aligned());

+                    let writer = timeline.writer();
+
+                    let mut checkpoint_modified = false;
+
+                    let decoded = decode_wal_record(recdata.clone());
                    restore_local_repo::save_decoded_record(
                        &mut checkpoint,
-                        &*timeline,
+                        &mut checkpoint_modified,
+                        writer.as_ref(),
                        &decoded,
                        recdata,
                        lsn,
                    )?;

-                    let new_checkpoint_bytes = checkpoint.encode();
                    // Check if checkpoint data was updated by save_decoded_record
-                    if new_checkpoint_bytes != old_checkpoint_bytes {
-                        timeline.put_page_image(
+                    if checkpoint_modified {
+                        let new_checkpoint_bytes = checkpoint.encode();
+
+                        writer.put_page_image(
                            RelishTag::Checkpoint,
                            0,
                            lsn,
@@ -228,7 +247,7 @@ fn walreceiver_main(

                    // Now that this record has been fully handled, including updating the
                    // checkpoint data, let the repository know that it is up-to-date to this LSN
-                    timeline.advance_last_record_lsn(lsn);
+                    writer.advance_last_record_lsn(lsn);
                    last_rec_lsn = lsn;
                }

@@ -273,6 +292,11 @@ fn walreceiver_main(

            physical_stream.standby_status_update(write_lsn, flush_lsn, apply_lsn, ts, NO_REPLY)?;
        }
+
+        if tenant_mgr::shutdown_requested() {
+            debug!("stop walreceiver because pageserver shutdown is requested");
+            break;
+        }
    }
    Ok(())
 }
@@ -82,7 +82,7 @@ pub trait WalRedoManager: Send + Sync {
        blknum: u32,
        lsn: Lsn,
        base_img: Option<Bytes>,
-        records: Vec<WALRecord>,
+        records: Vec<(Lsn, WALRecord)>,
    ) -> Result<Bytes, WalRedoError>;
 }

@@ -99,7 +99,7 @@ impl crate::walredo::WalRedoManager for DummyRedoManager {
        _blknum: u32,
        _lsn: Lsn,
        _base_img: Option<Bytes>,
-        _records: Vec<WALRecord>,
+        _records: Vec<(Lsn, WALRecord)>,
    ) -> Result<Bytes, WalRedoError> {
        Err(WalRedoError::InvalidState)
    }
@@ -150,7 +150,7 @@ struct WalRedoRequest {
    lsn: Lsn,

    base_img: Option<Bytes>,
-    records: Vec<WALRecord>,
+    records: Vec<(Lsn, WALRecord)>,
 }

 /// An error happened in WAL redo
@@ -179,7 +179,7 @@ impl WalRedoManager for PostgresRedoManager {
        blknum: u32,
        lsn: Lsn,
        base_img: Option<Bytes>,
-        records: Vec<WALRecord>,
+        records: Vec<(Lsn, WALRecord)>,
    ) -> Result<Bytes, WalRedoError> {
        let start_time;
        let lock_time;
@@ -277,7 +277,7 @@ impl PostgresRedoManager {
                page.extend_from_slice(&ZERO_PAGE);
            }
            // Apply all collected WAL records
-            for record in records {
+            for (_lsn, record) in records {
                let mut buf = record.rec.clone();

                WAL_REDO_RECORD_COUNTER.inc();
@@ -544,7 +544,7 @@ impl PostgresRedoProcess {
        &mut self,
        tag: BufferTag,
        base_img: Option<Bytes>,
-        records: &[WALRecord],
+        records: &[(Lsn, WALRecord)],
    ) -> Result<Bytes, std::io::Error> {
        let stdout = &mut self.stdout;
        // Buffer the writes to avoid a lot of small syscalls.
@@ -565,22 +565,16 @@ impl PostgresRedoProcess {
                stdin.write_all(&build_begin_redo_for_block_msg(tag)),
            )
            .await??;
-            if base_img.is_some() {
-                timeout(
-                    TIMEOUT,
-                    stdin.write_all(&build_push_page_msg(tag, base_img.unwrap())),
-                )
-                .await??;
+            if let Some(img) = base_img {
+                timeout(TIMEOUT, stdin.write_all(&build_push_page_msg(tag, &img))).await??;
            }

            // Send WAL records.
-            for rec in records.iter() {
-                let r = rec.clone();
-
+            for (lsn, rec) in records.iter() {
                WAL_REDO_RECORD_COUNTER.inc();

                stdin
-                    .write_all(&build_apply_record_msg(r.lsn, r.rec))
+                    .write_all(&build_apply_record_msg(*lsn, &rec.rec))
                    .await?;

                //debug!("sent WAL record to wal redo postgres process ({:X}/{:X}",
@@ -617,58 +611,41 @@ impl PostgresRedoProcess {
 // process. See vendor/postgres/src/backend/tcop/zenith_wal_redo.c for
 // explanation of the protocol.

-fn build_begin_redo_for_block_msg(tag: BufferTag) -> Bytes {
+fn build_begin_redo_for_block_msg(tag: BufferTag) -> Vec<u8> {
    let len = 4 + 1 + 4 * 4;
-    let mut buf = BytesMut::with_capacity(1 + len);
+    let mut buf = Vec::with_capacity(1 + len);

    buf.put_u8(b'B');
    buf.put_u32(len as u32);

-    // FIXME: this is a temporary hack that should go away when we refactor
-    // the postgres protocol serialization + handlers.
-    //
-    // BytesMut is a dynamic growable buffer, used a lot in tokio code but
-    // not in the std library. To write to a BytesMut from a serde serializer,
-    // we need to either:
-    // - pre-allocate the required buffer space. This is annoying because we
-    //   shouldn't care what the exact serialized size is-- that's the
-    //   serializer's job.
-    // - Or, we need to create a temporary "writer" (which implements the
-    //   `Write` trait). It's a bit awkward, because the writer consumes the
-    //   underlying BytesMut, and we need to extract it later with
-    //   `into_inner`.
-    let mut writer = buf.writer();
-    tag.ser_into(&mut writer)
+    tag.ser_into(&mut buf)
        .expect("serialize BufferTag should always succeed");
-    let buf = writer.into_inner();

    debug_assert!(buf.len() == 1 + len);

-    buf.freeze()
+    buf
 }

-fn build_push_page_msg(tag: BufferTag, base_img: Bytes) -> Bytes {
+fn build_push_page_msg(tag: BufferTag, base_img: &[u8]) -> Vec<u8> {
    assert!(base_img.len() == 8192);

    let len = 4 + 1 + 4 * 4 + base_img.len();
-    let mut buf = BytesMut::with_capacity(1 + len);
+    let mut buf = Vec::with_capacity(1 + len);

    buf.put_u8(b'P');
    buf.put_u32(len as u32);
-    let mut writer = buf.writer();
-    tag.ser_into(&mut writer)
+    tag.ser_into(&mut buf)
        .expect("serialize BufferTag should always succeed");
-    let mut buf = writer.into_inner();
    buf.put(base_img);

    debug_assert!(buf.len() == 1 + len);

-    buf.freeze()
+    buf
 }

-fn build_apply_record_msg(endlsn: Lsn, rec: Bytes) -> Bytes {
+fn build_apply_record_msg(endlsn: Lsn, rec: &[u8]) -> Vec<u8> {
    let len = 4 + 8 + rec.len();
-    let mut buf = BytesMut::with_capacity(1 + len);
+    let mut buf: Vec<u8> = Vec::with_capacity(1 + len);

    buf.put_u8(b'A');
    buf.put_u32(len as u32);
@@ -677,21 +654,19 @@ fn build_apply_record_msg(endlsn: Lsn, rec: Bytes) -> Bytes {

    debug_assert!(buf.len() == 1 + len);

-    buf.freeze()
+    buf
 }

-fn build_get_page_msg(tag: BufferTag) -> Bytes {
+fn build_get_page_msg(tag: BufferTag) -> Vec<u8> {
    let len = 4 + 1 + 4 * 4;
-    let mut buf = BytesMut::with_capacity(1 + len);
+    let mut buf = Vec::with_capacity(1 + len);

    buf.put_u8(b'G');
    buf.put_u32(len as u32);
-    let mut writer = buf.writer();
-    tag.ser_into(&mut writer)
+    tag.ser_into(&mut buf)
        .expect("serialize BufferTag should always succeed");
-    let buf = writer.into_inner();

    debug_assert!(buf.len() == 1 + len);

-    buf.freeze()
+    buf
 }
@@ -329,7 +329,12 @@ pub fn main() {
 }

 impl XLogRecord {
-    pub fn from_bytes(buf: &mut Bytes) -> XLogRecord {
+    pub fn from_slice(buf: &[u8]) -> XLogRecord {
+        use zenith_utils::bin_ser::LeSer;
+        XLogRecord::des(buf).unwrap()
+    }
+
+    pub fn from_bytes<B: Buf>(buf: &mut B) -> XLogRecord {
        use zenith_utils::bin_ser::LeSer;
        XLogRecord::des_from(&mut buf.reader()).unwrap()
    }
@@ -377,10 +382,12 @@ impl CheckPoint {
        Ok(CheckPoint::des(buf)?)
    }

-    // Update next XID based on provided new_xid and stored epoch.
-    // Next XID should be greater than new_xid.
-    // Also take in account 32-bit wrap-around.
-    pub fn update_next_xid(&mut self, xid: u32) {
+    /// Update next XID based on provided new_xid and stored epoch.
+    /// Next XID should be greater than new_xid. This handles 32-bit
+    /// XID wraparound correctly.
+    ///
+    /// Returns 'true' if the XID was updated.
+    pub fn update_next_xid(&mut self, xid: u32) -> bool {
        let xid = xid.wrapping_add(XID_CHECKPOINT_INTERVAL - 1) & !(XID_CHECKPOINT_INTERVAL - 1);
        let full_xid = self.nextXid.value;
        let new_xid = std::cmp::max(xid + 1, pg_constants::FIRST_NORMAL_TRANSACTION_ID);
@@ -391,10 +398,14 @@ impl CheckPoint {
                // wrap-around
                epoch += 1;
            }
-            self.nextXid = FullTransactionId {
-                value: (epoch << 32) | new_xid as u64,
-            };
+            let nextXid = (epoch << 32) | new_xid as u64;
+
+            if nextXid != self.nextXid.value {
+                self.nextXid = FullTransactionId { value: nextXid };
+                return true;
+            }
        }
+        false
    }
 }

@@ -99,7 +99,7 @@ fn main() -> anyhow::Result<()> {
                .long("uri")
                .takes_value(true)
                .help("redirect unauthenticated users to given uri")
-                .default_value("http://localhost:3000/psql_session/"),
+                .default_value("http://127.0.0.1:3000/psql_session/"),
        )
        .arg(
            Arg::with_name("auth-endpoint")
@@ -107,7 +107,7 @@ fn main() -> anyhow::Result<()> {
                .long("auth-endpoint")
                .takes_value(true)
                .help("redirect unauthenticated users to given uri")
-                .default_value("http://localhost:3000/authenticate_proxy_request/"),
+                .default_value("http://127.0.0.1:3000/authenticate_proxy_request/"),
        )
        .arg(
            Arg::with_name("ssl-key")
@@ -34,7 +34,7 @@ pub fn thread_main(state: &'static ProxyState, listener: TcpListener) -> anyhow:

 pub fn mgmt_conn_main(state: &'static ProxyState, socket: TcpStream) -> anyhow::Result<()> {
    let mut conn_handler = MgmtHandler { state };
-    let pgbackend = PostgresBackend::new(socket, AuthType::Trust, None)?;
+    let pgbackend = PostgresBackend::new(socket, AuthType::Trust, None, true)?;
    pgbackend.run(&mut conn_handler)
 }

@@ -64,6 +64,7 @@ pub fn proxy_conn_main(
            socket,
            postgres_backend::AuthType::MD5,
            state.conf.ssl_config.clone(),
+            false,
        )?,
        md5_salt: [0u8; 4],
        psql_session_id: "".into(),
@@ -1,6 +1,6 @@
 import subprocess
 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
-
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -13,7 +13,7 @@ def test_branch_behind(zenith_cli, pageserver: ZenithPageserver, postgres: Postg
    zenith_cli.run(["branch", "test_branch_behind", "empty"])

    pgmain = postgres.create_start('test_branch_behind')
-    print("postgres is running on 'test_branch_behind' branch")
+    log.info("postgres is running on 'test_branch_behind' branch")

    main_pg_conn = pgmain.connect()
    main_cur = main_pg_conn.cursor()
@@ -27,7 +27,7 @@ def test_branch_behind(zenith_cli, pageserver: ZenithPageserver, postgres: Postg
    ''')
    main_cur.execute('SELECT pg_current_wal_insert_lsn()')
    lsn_a = main_cur.fetchone()[0]
-    print('LSN after 100 rows: ' + lsn_a)
+    log.info(f'LSN after 100 rows: {lsn_a}')

    # Insert some more rows. (This generates enough WAL to fill a few segments.)
    main_cur.execute('''
@@ -37,7 +37,7 @@ def test_branch_behind(zenith_cli, pageserver: ZenithPageserver, postgres: Postg
    ''')
    main_cur.execute('SELECT pg_current_wal_insert_lsn()')
    lsn_b = main_cur.fetchone()[0]
-    print('LSN after 200100 rows: ' + lsn_b)
+    log.info(f'LSN after 200100 rows: {lsn_b}')

    # Branch at the point where only 100 rows were inserted
    zenith_cli.run(["branch", "test_branch_behind_hundred", "test_branch_behind@" + lsn_a])
@@ -52,7 +52,7 @@ def test_branch_behind(zenith_cli, pageserver: ZenithPageserver, postgres: Postg

    main_cur.execute('SELECT pg_current_wal_insert_lsn()')
    lsn_c = main_cur.fetchone()[0]
-    print('LSN after 400100 rows: ' + lsn_c)
+    log.info(f'LSN after 400100 rows: {lsn_c}')

    # Branch at the point where only 200100 rows were inserted
    zenith_cli.run(["branch", "test_branch_behind_more", "test_branch_behind@" + lsn_b])
@@ -89,4 +89,4 @@ def test_branch_behind(zenith_cli, pageserver: ZenithPageserver, postgres: Postg
    try:
        zenith_cli.run(["branch", "test_branch_preinitdb", "test_branch_behind@0/42"])
    except subprocess.CalledProcessError:
-        print("Branch creation with pre-initdb LSN failed (as expected)")
+        log.info("Branch creation with pre-initdb LSN failed (as expected)")
@@ -4,6 +4,7 @@ import os
 from contextlib import closing

 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -24,7 +25,7 @@ def test_clog_truncate(zenith_cli, pageserver: ZenithPageserver, postgres: Postg
    ]

    pg = postgres.create_start('test_clog_truncate', config_lines=config)
-    print('postgres is running on test_clog_truncate branch')
+    log.info('postgres is running on test_clog_truncate branch')

    # Install extension containing function needed for test
    pg.safe_psql('CREATE EXTENSION zenith_test_utils')
@@ -33,22 +34,22 @@ def test_clog_truncate(zenith_cli, pageserver: ZenithPageserver, postgres: Postg
    with closing(pg.connect()) as conn:
        with conn.cursor() as cur:
            cur.execute('select test_consume_xids(1000*1000*10);')
-            print('xids consumed')
+            log.info('xids consumed')

            # call a checkpoint to trigger TruncateSubtrans
            cur.execute('CHECKPOINT;')

            # ensure WAL flush
            cur.execute('select txid_current()')
-            print(cur.fetchone())
+            log.info(cur.fetchone())

    # wait for autovacuum to truncate the pg_xact
    # XXX Is it worth to add a timeout here?
    pg_xact_0000_path = os.path.join(pg.pg_xact_dir_path(), '0000')
-    print("pg_xact_0000_path = " + pg_xact_0000_path)
+    log.info(f"pg_xact_0000_path = {pg_xact_0000_path}")

    while os.path.isfile(pg_xact_0000_path):
-        print("file exists. wait for truncation. " "pg_xact_0000_path = " + pg_xact_0000_path)
+        log.info(f"file exists. wait for truncation. " "pg_xact_0000_path = {pg_xact_0000_path}")
        time.sleep(5)

    # checkpoint to advance latest lsn
@@ -59,14 +60,14 @@ def test_clog_truncate(zenith_cli, pageserver: ZenithPageserver, postgres: Postg
            lsn_after_truncation = cur.fetchone()[0]

    # create new branch after clog truncation and start a compute node on it
-    print('create branch at lsn_after_truncation ' + lsn_after_truncation)
+    log.info(f'create branch at lsn_after_truncation {lsn_after_truncation}')
    zenith_cli.run(
        ["branch", "test_clog_truncate_new", "test_clog_truncate@" + lsn_after_truncation])

    pg2 = postgres.create_start('test_clog_truncate_new')
-    print('postgres is running on test_clog_truncate_new branch')
+    log.info('postgres is running on test_clog_truncate_new branch')

    # check that new node doesn't contain truncated segment
    pg_xact_0000_path_new = os.path.join(pg2.pg_xact_dir_path(), '0000')
-    print("pg_xact_0000_path_new = " + pg_xact_0000_path_new)
+    log.info(f"pg_xact_0000_path_new = {pg_xact_0000_path_new}")
    assert os.path.isfile(pg_xact_0000_path_new) is False
@@ -1,6 +1,7 @@
 from contextlib import closing

 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -14,7 +15,7 @@ def test_config(zenith_cli, pageserver: ZenithPageserver, postgres: PostgresFact

    # change config
    pg = postgres.create_start('test_config', config_lines=['log_min_messages=debug1'])
-    print('postgres is running on test_config branch')
+    log.info('postgres is running on test_config branch')

    with closing(pg.connect()) as conn:
        with conn.cursor() as cur:
@@ -3,6 +3,7 @@ import pathlib

 from contextlib import closing
 from fixtures.zenith_fixtures import ZenithPageserver, PostgresFactory, ZenithCli, check_restored_datadir_content
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -19,7 +20,7 @@ def test_createdb(
    zenith_cli.run(["branch", "test_createdb", "empty"])

    pg = postgres.create_start('test_createdb')
-    print("postgres is running on 'test_createdb' branch")
+    log.info("postgres is running on 'test_createdb' branch")

    with closing(pg.connect()) as conn:
        with conn.cursor() as cur:
@@ -53,7 +54,7 @@ def test_dropdb(
    zenith_cli.run(["branch", "test_dropdb", "empty"])

    pg = postgres.create_start('test_dropdb')
-    print("postgres is running on 'test_dropdb' branch")
+    log.info("postgres is running on 'test_dropdb' branch")

    with closing(pg.connect()) as conn:
        with conn.cursor() as cur:
@@ -88,13 +89,13 @@ def test_dropdb(

    # Test that database subdir exists on the branch before drop
    dbpath = pathlib.Path(pg_before.pgdata_dir) / 'base' / str(dboid)
-    print(dbpath)
+    log.info(dbpath)

    assert os.path.isdir(dbpath) == True

    # Test that database subdir doesn't exist on the branch after drop
    dbpath = pathlib.Path(pg_after.pgdata_dir) / 'base' / str(dboid)
-    print(dbpath)
+    log.info(dbpath)

    assert os.path.isdir(dbpath) == False

@@ -1,6 +1,7 @@
 from contextlib import closing

 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -12,7 +13,7 @@ def test_createuser(zenith_cli, pageserver: ZenithPageserver, postgres: Postgres
    zenith_cli.run(["branch", "test_createuser", "empty"])

    pg = postgres.create_start('test_createuser')
-    print("postgres is running on 'test_createuser' branch")
+    log.info("postgres is running on 'test_createuser' branch")

    with closing(pg.connect()) as conn:
        with conn.cursor() as cur:
@@ -1,4 +1,5 @@
 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver, check_restored_datadir_content
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -15,7 +16,7 @@ def test_multixact(pageserver: ZenithPageserver, postgres: PostgresFactory,
    zenith_cli.run(["branch", "test_multixact", "empty"])
    pg = postgres.create_start('test_multixact')

-    print("postgres is running on 'test_multixact' branch")
+    log.info("postgres is running on 'test_multixact' branch")
    pg_conn = pg.connect()
    cur = pg_conn.cursor()

@@ -55,7 +56,7 @@ def test_multixact(pageserver: ZenithPageserver, postgres: PostgresFactory,
    zenith_cli.run(["branch", "test_multixact_new", "test_multixact@" + lsn])
    pg_new = postgres.create_start('test_multixact_new')

-    print("postgres is running on 'test_multixact_new' branch")
+    log.info("postgres is running on 'test_multixact_new' branch")
    pg_new_conn = pg_new.connect()
    cur_new = pg_new_conn.cursor()

@@ -1,6 +1,7 @@
 from contextlib import closing

 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -18,7 +19,7 @@ def test_old_request_lsn(zenith_cli, pageserver: ZenithPageserver, postgres: Pos
    # Create a branch for us
    zenith_cli.run(["branch", "test_old_request_lsn", "empty"])
    pg = postgres.create_start('test_old_request_lsn')
-    print('postgres is running on test_old_request_lsn branch')
+    log.info('postgres is running on test_old_request_lsn branch')

    pg_conn = pg.connect()
    cur = pg_conn.cursor()
@@ -46,7 +47,7 @@ def test_old_request_lsn(zenith_cli, pageserver: ZenithPageserver, postgres: Pos
        from pg_settings where name = 'shared_buffers'
    ''')
    row = cur.fetchone()
-    print(f'shared_buffers is {row[0]}, table size {row[1]}');
+    log.info(f'shared_buffers is {row[0]}, table size {row[1]}');
    assert int(row[0]) < int(row[1])

    cur.execute('VACUUM foo');
@@ -5,6 +5,7 @@ import time
 from contextlib import closing
 from multiprocessing import Process, Value
 from fixtures.zenith_fixtures import WalAcceptorFactory, ZenithPageserver, PostgresFactory
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -40,7 +41,7 @@ def test_pageserver_restart(zenith_cli, pageserver: ZenithPageserver, postgres:
        from pg_settings where name = 'shared_buffers'
    ''')
    row = cur.fetchone()
-    print("shared_buffers is {}, table size {}", row[0], row[1]);
+    log.info(f"shared_buffers is {row[0]}, table size {row[1]}");
    assert int(row[0]) < int(row[1])

    # Stop and restart pageserver. This is a more or less graceful shutdown, although
@@ -1,4 +1,5 @@
 from fixtures.zenith_fixtures import PostgresFactory
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -8,7 +9,7 @@ def test_pgbench(postgres: PostgresFactory, pg_bin, zenith_cli):
    zenith_cli.run(["branch", "test_pgbench", "empty"])

    pg = postgres.create_start('test_pgbench')
-    print("postgres is running on 'test_pgbench' branch")
+    log.info("postgres is running on 'test_pgbench' branch")

    connstr = pg.connstr()

@@ -2,6 +2,7 @@ import pytest

 from contextlib import closing
 from fixtures.zenith_fixtures import ZenithPageserver, PostgresFactory
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -27,7 +28,7 @@ def test_restart_compute(

    pg = postgres.create_start('test_restart_compute',
                               wal_acceptors=wal_acceptor_connstrs)
-    print("postgres is running on 'test_restart_compute' branch")
+    log.info("postgres is running on 'test_restart_compute' branch")

    with closing(pg.connect()) as conn:
        with conn.cursor() as cur:
@@ -36,7 +37,7 @@ def test_restart_compute(
            cur.execute('SELECT sum(key) FROM t')
            r = cur.fetchone()
            assert r == (5000050000, )
-            print("res = ", r)
+            log.info(f"res = {r}")

    # Remove data directory and restart
    pg.stop_and_destroy().create_start('test_restart_compute',
@@ -49,7 +50,7 @@ def test_restart_compute(
            cur.execute('SELECT sum(key) FROM t')
            r = cur.fetchone()
            assert r == (5000050000, )
-            print("res = ", r)
+            log.info(f"res = {r}")

            # Insert another row
            cur.execute("INSERT INTO t VALUES (100001, 'payload2')")
@@ -57,7 +58,7 @@ def test_restart_compute(

            r = cur.fetchone()
            assert r == (100001, )
-            print("res = ", r)
+            log.info(f"res = {r}")

    # Again remove data directory and restart
    pg.stop_and_destroy().create_start('test_restart_compute',
@@ -72,7 +73,7 @@ def test_restart_compute(

            r = cur.fetchone()
            assert r == (100001, )
-            print("res = ", r)
+            log.info(f"res = {r}")

    # And again remove data directory and restart
    pg.stop_and_destroy().create_start('test_restart_compute',
@@ -85,4 +86,4 @@ def test_restart_compute(

            r = cur.fetchone()
            assert r == (100001, )
-            print("res = ", r)
+            log.info(f"res = {r}")
@@ -1,13 +1,14 @@
 from contextlib import closing
 import psycopg2.extras
-import time;
+import time
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

 def print_gc_result(row):
-    print("GC duration {elapsed} ms".format_map(row));
-    print("  REL    total: {layer_relfiles_total}, needed_by_cutoff {layer_relfiles_needed_by_cutoff}, needed_by_branches: {layer_relfiles_needed_by_branches}, not_updated: {layer_relfiles_not_updated}, needed_as_tombstone {layer_relfiles_needed_as_tombstone}, removed: {layer_relfiles_removed}, dropped: {layer_relfiles_dropped}".format_map(row))
-    print("  NONREL total: {layer_nonrelfiles_total}, needed_by_cutoff {layer_nonrelfiles_needed_by_cutoff}, needed_by_branches: {layer_nonrelfiles_needed_by_branches}, not_updated: {layer_nonrelfiles_not_updated}, needed_as_tombstone {layer_nonrelfiles_needed_as_tombstone}, removed: {layer_nonrelfiles_removed}, dropped: {layer_nonrelfiles_dropped}".format_map(row))
+    log.info("GC duration {elapsed} ms".format_map(row));
+    log.info("  REL    total: {layer_relfiles_total}, needed_by_cutoff {layer_relfiles_needed_by_cutoff}, needed_by_branches: {layer_relfiles_needed_by_branches}, not_updated: {layer_relfiles_not_updated}, needed_as_tombstone {layer_relfiles_needed_as_tombstone}, removed: {layer_relfiles_removed}, dropped: {layer_relfiles_dropped}".format_map(row))
+    log.info("  NONREL total: {layer_nonrelfiles_total}, needed_by_cutoff {layer_nonrelfiles_needed_by_cutoff}, needed_by_branches: {layer_nonrelfiles_needed_by_branches}, not_updated: {layer_nonrelfiles_not_updated}, needed_as_tombstone {layer_nonrelfiles_needed_as_tombstone}, removed: {layer_nonrelfiles_removed}, dropped: {layer_nonrelfiles_dropped}".format_map(row))


 #
@@ -35,7 +36,7 @@ def test_layerfiles_gc(zenith_cli, pageserver, postgres, pg_bin):

                    cur.execute("select relfilenode from pg_class where oid = 'foo'::regclass");
                    row = cur.fetchone();
-                    print("relfilenode is {}", row[0]);
+                    log.info(f"relfilenode is {row[0]}");

                    # Run GC, to clear out any garbage left behind in the catalogs by
                    # the CREATE TABLE command. We want to have a clean slate with no garbage
@@ -50,7 +51,7 @@ def test_layerfiles_gc(zenith_cli, pageserver, postgres, pg_bin):
                    # update to confuse our numbers either.
                    cur.execute("DELETE FROM foo")

-                    print("Running GC before test")
+                    log.info("Running GC before test")
                    pscur.execute(f"do_gc {pageserver.initial_tenant} {timeline} 0")
                    row = pscur.fetchone()
                    print_gc_result(row);
@@ -61,7 +62,7 @@ def test_layerfiles_gc(zenith_cli, pageserver, postgres, pg_bin):
                    # Insert a row and run GC. Checkpoint should freeze the layer
                    # so that there is only the most recent image layer left for the rel,
                    # removing the old image and delta layer.
-                    print("Inserting one row and running GC")
+                    log.info("Inserting one row and running GC")
                    cur.execute("INSERT INTO foo VALUES (1)")
                    pscur.execute(f"do_gc {pageserver.initial_tenant} {timeline} 0")
                    row = pscur.fetchone()
@@ -73,7 +74,7 @@ def test_layerfiles_gc(zenith_cli, pageserver, postgres, pg_bin):
                    # Insert two more rows and run GC.
                    # This should create new image and delta layer file with the new contents, and
                    # then remove the old one image and the just-created delta layer.
-                    print("Inserting two more rows and running GC")
+                    log.info("Inserting two more rows and running GC")
                    cur.execute("INSERT INTO foo VALUES (2)")
                    cur.execute("INSERT INTO foo VALUES (3)")

@@ -85,7 +86,7 @@ def test_layerfiles_gc(zenith_cli, pageserver, postgres, pg_bin):
                    assert row['layer_relfiles_dropped'] == 0

                    # Do it again. Should again create two new layer files and remove old ones.
-                    print("Inserting two more rows and running GC")
+                    log.info("Inserting two more rows and running GC")
                    cur.execute("INSERT INTO foo VALUES (2)")
                    cur.execute("INSERT INTO foo VALUES (3)")

@@ -97,7 +98,7 @@ def test_layerfiles_gc(zenith_cli, pageserver, postgres, pg_bin):
                    assert row['layer_relfiles_dropped'] == 0

                    # Run GC again, with no changes in the database. Should not remove anything.
-                    print("Run GC again, with nothing to do")
+                    log.info("Run GC again, with nothing to do")
                    pscur.execute(f"do_gc {pageserver.initial_tenant} {timeline} 0")
                    row = pscur.fetchone()
                    print_gc_result(row);
@@ -108,7 +109,7 @@ def test_layerfiles_gc(zenith_cli, pageserver, postgres, pg_bin):
                    #
                    # Test DROP TABLE checks that relation data and metadata was deleted by GC from object storage
                    #
-                    print("Drop table and run GC again");
+                    log.info("Drop table and run GC again");
                    cur.execute("DROP TABLE foo")

                    pscur.execute(f"do_gc {pageserver.initial_tenant} {timeline} 0")
@@ -2,7 +2,7 @@ from contextlib import closing
 from uuid import UUID
 import psycopg2.extras
 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
-
+from fixtures.log_helper import log

 def test_timeline_size(
    zenith_cli, pageserver: ZenithPageserver, postgres: PostgresFactory, pg_bin
@@ -15,7 +15,7 @@ def test_timeline_size(
    assert res["current_logical_size"] == res["current_logical_size_non_incremental"]

    pgmain = postgres.create_start("test_timeline_size")
-    print("postgres is running on 'test_timeline_size' branch")
+    log.info("postgres is running on 'test_timeline_size' branch")

    with closing(pgmain.connect()) as conn:
        with conn.cursor() as cur:
@@ -1,7 +1,7 @@
 import os

 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver, PgBin
-
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -13,7 +13,7 @@ def test_twophase(zenith_cli, pageserver: ZenithPageserver, postgres: PostgresFa
    zenith_cli.run(["branch", "test_twophase", "empty"])

    pg = postgres.create_start('test_twophase', config_lines=['max_prepared_transactions=5'])
-    print("postgres is running on 'test_twophase' branch")
+    log.info("postgres is running on 'test_twophase' branch")

    conn = pg.connect()
    cur = conn.cursor()
@@ -45,7 +45,7 @@ def test_twophase(zenith_cli, pageserver: ZenithPageserver, postgres: PostgresFa
    cur.execute('CHECKPOINT')

    twophase_files = os.listdir(pg.pg_twophase_dir_path())
-    print(twophase_files)
+    log.info(twophase_files)
    assert len(twophase_files) == 4

    cur.execute("COMMIT PREPARED 'insert_three'")
@@ -53,7 +53,7 @@ def test_twophase(zenith_cli, pageserver: ZenithPageserver, postgres: PostgresFa
    cur.execute('CHECKPOINT')

    twophase_files = os.listdir(pg.pg_twophase_dir_path())
-    print(twophase_files)
+    log.info(twophase_files)
    assert len(twophase_files) == 2

    # Create a branch with the transaction in prepared state
@@ -67,7 +67,7 @@ def test_twophase(zenith_cli, pageserver: ZenithPageserver, postgres: PostgresFa

    # Check that we restored only needed twophase files
    twophase_files2 = os.listdir(pg2.pg_twophase_dir_path())
-    print(twophase_files2)
+    log.info(twophase_files2)
    assert twophase_files2.sort() == twophase_files.sort()

    conn2 = pg2.connect()
@@ -1,4 +1,5 @@
 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -11,7 +12,7 @@ def test_vm_bit_clear(pageserver: ZenithPageserver, postgres: PostgresFactory, p
    zenith_cli.run(["branch", "test_vm_bit_clear", "empty"])
    pg = postgres.create_start('test_vm_bit_clear')

-    print("postgres is running on 'test_vm_bit_clear' branch")
+    log.info("postgres is running on 'test_vm_bit_clear' branch")
    pg_conn = pg.connect()
    cur = pg_conn.cursor()

@@ -63,7 +64,7 @@ def test_vm_bit_clear(pageserver: ZenithPageserver, postgres: PostgresFactory, p
    # server at the right point-in-time avoids that full-page image.
    pg_new = postgres.create_start('test_vm_bit_clear_new')

-    print("postgres is running on 'test_vm_bit_clear_new' branch")
+    log.info("postgres is running on 'test_vm_bit_clear_new' branch")
    pg_new_conn = pg_new.connect()
    cur_new = pg_new_conn.cursor()

@@ -9,6 +9,7 @@ from contextlib import closing
 from multiprocessing import Process, Value
 from fixtures.zenith_fixtures import WalAcceptorFactory, ZenithPageserver, PostgresFactory, PgBin
 from fixtures.utils import lsn_to_hex, mkdir_if_needed
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -203,6 +204,7 @@ def test_race_conditions(zenith_cli, pageserver: ZenithPageserver, postgres: Pos
    stop_value.value = 1
    proc.join()

+
 class ProposerPostgres:
    """Object for running safekeepers sync with walproposer"""
    def __init__(self, pgdata_dir: str, pg_bin: PgBin, timeline_id: str, tenant_id: str):
@@ -284,10 +286,38 @@ def test_sync_safekeepers(repo_dir: str, pg_bin: PgBin, wa_factory: WalAcceptorF
        )
        lsn_hex = lsn_to_hex(res["inserted_wal"]["end_lsn"])
        lsn_after_append.append(lsn_hex)
-        print(f"safekeeper[{i}] lsn after append: {lsn_hex}")
+        log.info(f"safekeeper[{i}] lsn after append: {lsn_hex}")

    # run sync safekeepers
    lsn_after_sync = pg.sync_safekeepers()
-    print(f"lsn after sync = {lsn_after_sync}")
+    log.info(f"lsn after sync = {lsn_after_sync}")

    assert all(lsn_after_sync == lsn for lsn in lsn_after_append)
+
+
+def test_timeline_status(zenith_cli, pageserver, postgres, wa_factory: WalAcceptorFactory):
+    wa_factory.start_n_new(1)
+
+    zenith_cli.run(["branch", "test_timeline_status", "empty"])
+    pg = postgres.create_start('test_timeline_status', wal_acceptors=wa_factory.get_connstrs())
+
+    wa = wa_factory.instances[0]
+    wa_http_cli = wa.http_client()
+    wa_http_cli.check_status()
+
+    # learn zenith timeline from compute
+    tenant_id = pg.safe_psql("show zenith.zenith_tenant")[0][0]
+    timeline_id = pg.safe_psql("show zenith.zenith_timeline")[0][0]
+
+    # fetch something sensible from status
+    epoch = wa_http_cli.timeline_status(tenant_id, timeline_id).acceptor_epoch
+
+    pg.safe_psql("create table t(i int)")
+
+    # ensure epoch goes up after reboot
+    pg.stop().start()
+    pg.safe_psql("insert into t values(10)")
+
+    epoch_after_reboot = wa_http_cli.timeline_status(tenant_id,
+                                                     timeline_id).acceptor_epoch
+    assert epoch_after_reboot > epoch
@@ -3,9 +3,10 @@ import asyncpg
 import random

 from fixtures.zenith_fixtures import WalAcceptor, WalAcceptorFactory, ZenithPageserver, PostgresFactory, Postgres
+from fixtures.log_helper import getLogger
 from typing import List
-from fixtures.utils import debug_print

+log = getLogger('root.wal_acceptor_async')
 pytest_plugins = ("fixtures.zenith_fixtures")


@@ -63,18 +64,18 @@ class WorkerStats(object):
        self.counters[worker_id] += 1

    def check_progress(self):
-        debug_print("Workers progress: {}".format(self.counters))
+        log.debug("Workers progress: {}".format(self.counters))

        # every worker should finish at least one tx
        assert all(cnt > 0 for cnt in self.counters)

        progress = sum(self.counters)
-        print('All workers made {} transactions'.format(progress))
+        log.info('All workers made {} transactions'.format(progress))


 async def run_random_worker(stats: WorkerStats, pg: Postgres, worker_id, n_accounts, max_transfer):
    pg_conn = await pg.connect_async()
-    debug_print('Started worker {}'.format(worker_id))
+    log.debug('Started worker {}'.format(worker_id))

    while stats.running:
        from_uid = random.randint(0, n_accounts - 1)
@@ -84,9 +85,9 @@ async def run_random_worker(stats: WorkerStats, pg: Postgres, worker_id, n_accou
        await bank_transfer(pg_conn, from_uid, to_uid, amount)
        stats.inc_progress(worker_id)

-        debug_print('Executed transfer({}) {} => {}'.format(amount, from_uid, to_uid))
+        log.debug('Executed transfer({}) {} => {}'.format(amount, from_uid, to_uid))

-    debug_print('Finished worker {}'.format(worker_id))
+    log.debug('Finished worker {}'.format(worker_id))

    await pg_conn.close()

@@ -134,7 +135,7 @@ async def run_restarts_under_load(pg: Postgres, acceptors: List[WalAcceptor], n_

        victim.start()

-    print('Iterations are finished, exiting coroutines...')
+    log.info('Iterations are finished, exiting coroutines...')
    stats.running = False
    # await all workers
    await asyncio.gather(*workers)
@@ -2,6 +2,7 @@ import os

 from fixtures.utils import mkdir_if_needed
 from fixtures.zenith_fixtures import PageserverPort, PostgresFactory, check_restored_datadir_content
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures")

@@ -38,7 +39,7 @@ def test_zenith_regress(postgres: PostgresFactory, pg_bin, zenith_cli, test_outp
        '--inputdir={}'.format(src_path),
    ]

-    print(pg_regress_command)
+    log.info(pg_regress_command)
    env = {
        'PGPORT': str(pg.port),
        'PGUSER': pg.username,
@@ -1,5 +1,3 @@
-from pprint import pprint
-
 import os
 import re
 import timeit
@@ -0,0 +1,44 @@
+import logging
+import logging.config
+
+"""
+This file configures logging to use in python tests.
+Logs are automatically captured and shown in their
+own section after all tests are executed. 
+
+To see logs for all (even successful) tests, run
+pytest with the following command:
+- `pipenv run pytest -n8 -rA`
+
+Other log config can be set in pytest.ini file.
+You can add `log_cli = true` to it to watch
+logs in real time.
+
+To get more info about logging with pytest, see
+https://docs.pytest.org/en/6.2.x/logging.html
+"""
+
+# this config is only used for default log levels,
+# log format is specified in pytest.ini file
+LOGGING = {
+    "version": 1,
+    "loggers": {
+        "root": {
+            "level": "INFO"
+        },
+        "root.wal_acceptor_async": {
+            "level": "INFO" # a lot of logs on DEBUG level
+        }
+    }
+}
+
+def getLogger(name='root') -> logging.Logger:
+    """Method to get logger for tests.
+    
+    Should be used to get correctly initialized logger. """
+    return logging.getLogger(name)
+
+# default logger for tests
+log = getLogger()
+
+logging.config.dictConfig(LOGGING)
@@ -2,7 +2,7 @@ import os
 import subprocess

 from typing import Any, List
-
+from fixtures.log_helper import log

 def get_self_dir() -> str:
    """ Get the path to the directory where this script lives. """
@@ -39,7 +39,7 @@ def subprocess_capture(capture_dir: str, cmd: List[str], **kwargs: Any) -> str:

    with open(stdout_filename, 'w') as stdout_f:
        with open(stderr_filename, 'w') as stderr_f:
-            print('(capturing output to "{}.stdout")'.format(base))
+            log.info('(capturing output to "{}.stdout")'.format(base))
            subprocess.run(cmd, **kwargs, stdout=stdout_f, stderr=stderr_f)

    return basepath
@@ -58,14 +58,6 @@ def global_counter() -> int:
    _global_counter += 1
    return _global_counter

-def debug_print(*args, **kwargs) -> None:
-    """ Print to the console if TEST_DEBUG_PRINT is set in env.
-    
-    All parameters are passed to print().
-    """
-    if os.environ.get('TEST_DEBUG_PRINT') is not None:
-        print(*args, **kwargs)
-
 def lsn_to_hex(num: int) -> str:
    """ Convert lsn from int to standard hex notation. """
    return "{:X}/{:X}".format(num >> 32, num & 0xffffffff)
@@ -27,6 +27,8 @@ from typing_extensions import Literal
 import requests

 from .utils import (get_self_dir, mkdir_if_needed, subprocess_capture)
+from fixtures.log_helper import log
+
 """
 This file contains pytest fixtures. A fixture is a test resource that can be
 summoned by placing its name in the test's arguments.
@@ -64,7 +66,7 @@ def pytest_configure(config):
         raise Exception('Too many workers configured. Cannot distrubute ports for services.')

    # does not use -c as it is not supported on macOS
-    cmd = ['pgrep', 'pageserver|postgres|wal_acceptor']
+    cmd = ['pgrep', 'pageserver|postgres|safekeeper']
    result = subprocess.run(cmd, stdout=subprocess.DEVNULL)
    if result.returncode == 0:
        # returncode of 0 means it found something.
@@ -72,7 +74,7 @@ def pytest_configure(config):
        # result of the test.
        # NOTE this shows as an internal pytest error, there might be a better way
        raise Exception(
-            'Found interfering processes running. Stop all Zenith pageservers, nodes, WALs, as well as stand-alone Postgres.'
+            'Found interfering processes running. Stop all Zenith pageservers, nodes, safekeepers, as well as stand-alone Postgres.'
        )


@@ -188,13 +190,13 @@ class ZenithCli:

        >>> result = zenith_cli.run(...)
        >>> assert result.stderr == ""
-        >>> print(result.stdout)
+        >>> log.info(result.stdout)
        """

        assert type(arguments) == list

        args = [self.bin_zenith] + arguments
-        print('Running command "{}"'.format(' '.join(args)))
+        log.info('Running command "{}"'.format(' '.join(args)))

        # Interceipt CalledProcessError and print more info
        try:
@@ -211,7 +213,7 @@ class ZenithCli:
              stdout: {exc.stdout}
              stderr: {exc.stderr}
            """
-            print(msg)
+            log.info(msg)

            raise Exception(msg) from exc

@@ -233,16 +235,16 @@ class ZenithPageserverHttpClient(requests.Session):
            self.headers['Authorization'] = f'Bearer {auth_token}'

    def check_status(self):
-        self.get(f"http://localhost:{self.port}/v1/status").raise_for_status()
+        self.get(f"http://127.0.0.1:{self.port}/v1/status").raise_for_status()

    def branch_list(self, tenant_id: uuid.UUID) -> List[Dict]:
-        res = self.get(f"http://localhost:{self.port}/v1/branch/{tenant_id.hex}")
+        res = self.get(f"http://127.0.0.1:{self.port}/v1/branch/{tenant_id.hex}")
        res.raise_for_status()
        return res.json()

    def branch_create(self, tenant_id: uuid.UUID, name: str, start_point: str) -> Dict:
        res = self.post(
-            f"http://localhost:{self.port}/v1/branch",
+            f"http://127.0.0.1:{self.port}/v1/branch",
            json={
                'tenant_id': tenant_id.hex,
                'name': name,
@@ -254,19 +256,19 @@ class ZenithPageserverHttpClient(requests.Session):

    def branch_detail(self, tenant_id: uuid.UUID, name: str) -> Dict:
        res = self.get(
-            f"http://localhost:{self.port}/v1/branch/{tenant_id.hex}/{name}",
+            f"http://127.0.0.1:{self.port}/v1/branch/{tenant_id.hex}/{name}",
        )
        res.raise_for_status()
        return res.json()

    def tenant_list(self) -> List[str]:
-        res = self.get(f"http://localhost:{self.port}/v1/tenant")
+        res = self.get(f"http://127.0.0.1:{self.port}/v1/tenant")
        res.raise_for_status()
        return res.json()

    def tenant_create(self, tenant_id: uuid.UUID):
        res = self.post(
-            f"http://localhost:{self.port}/v1/tenant",
+            f"http://127.0.0.1:{self.port}/v1/tenant",
            json={
                'tenant_id': tenant_id.hex,
            },
@@ -275,7 +277,7 @@ class ZenithPageserverHttpClient(requests.Session):
        return res.json()

    def get_metrics(self) -> str:
-        res = self.get(f"http://localhost:{self.port}/metrics")
+        res = self.get(f"http://127.0.0.1:{self.port}/metrics")
        res.raise_for_status()
        return res.text

@@ -346,7 +348,7 @@ class PageserverPort:
 class ZenithPageserver(PgProtocol):
    """ An object representing a running pageserver. """
    def __init__(self, zenith_cli: ZenithCli, repo_dir: str, port: PageserverPort):
-        super().__init__(host='localhost', port=port.pg)
+        super().__init__(host='127.0.0.1', port=port.pg)
        self.zenith_cli = zenith_cli
        self.running = False
        self.initial_tenant = None
@@ -375,6 +377,7 @@ class ZenithPageserver(PgProtocol):
        Start the page server.
        Returns self.
        """
+        assert self.running == False

        self.zenith_cli.run(['start'])
        self.running = True
@@ -382,14 +385,18 @@ class ZenithPageserver(PgProtocol):
        self.initial_tenant = self.zenith_cli.run(['tenant', 'list']).stdout.strip()
        return self

-    def stop(self) -> 'ZenithPageserver':
+    def stop(self, immediate=False) -> 'ZenithPageserver':
        """
        Stop the page server.
        Returns self.
        """
+        cmd = ['stop']
+        if immediate:
+            cmd.append('immediate')

+        log.info(f"Stopping pageserver with {cmd}")
        if self.running:
-            self.zenith_cli.run(['stop'])
+            self.zenith_cli.run(cmd)
            self.running = False

        return self
@@ -398,7 +405,7 @@ class ZenithPageserver(PgProtocol):
        return self

    def __exit__(self, exc_type, exc, tb):
-        self.stop()
+        self.stop(True)

    @cached_property
    def auth_keys(self) -> AuthKeys:
@@ -419,7 +426,7 @@ class ZenithPageserver(PgProtocol):
 def pageserver_port(port_distributor: PortDistributor) -> PageserverPort:
    pg = port_distributor.get_port()
    http = port_distributor.get_port()
-    print(f"pageserver_port: pg={pg} http={http}")
+    log.info(f"pageserver_port: pg={pg} http={http}")
    return PageserverPort(pg=pg, http=http)


@@ -443,8 +450,8 @@ def pageserver(zenith_cli: ZenithCli, repo_dir: str, pageserver_port: Pageserver
    yield ps

    # After the yield comes any cleanup code we need.
-    print('Starting pageserver cleanup')
-    ps.stop()
+    log.info('Starting pageserver cleanup')
+    ps.stop(True)

 class PgBin:
    """ A helper class for executing postgres binaries """
@@ -481,7 +488,7 @@ class PgBin:
        """

        self._fixpath(command)
-        print('Running command "{}"'.format(' '.join(command)))
+        log.info('Running command "{}"'.format(' '.join(command)))
        env = self._build_env(env)
        subprocess.run(command, env=env, cwd=cwd, check=True)

@@ -498,7 +505,7 @@ class PgBin:
        """

        self._fixpath(command)
-        print('Running command "{}"'.format(' '.join(command)))
+        log.info('Running command "{}"'.format(' '.join(command)))
        env = self._build_env(env)
        return subprocess_capture(self.log_dir, command, env=env, cwd=cwd, check=True, **kwargs)

@@ -518,7 +525,7 @@ def pageserver_auth_enabled(zenith_cli: ZenithCli, repo_dir: str, pageserver_por
 class Postgres(PgProtocol):
    """ An object representing a running postgres daemon. """
    def __init__(self, zenith_cli: ZenithCli, repo_dir: str, pg_bin: PgBin, tenant_id: str, port: int):
-        super().__init__(host='localhost', port=port)
+        super().__init__(host='127.0.0.1', port=port)

        self.zenith_cli = zenith_cli
        self.running = False
@@ -566,12 +573,12 @@ class Postgres(PgProtocol):

        assert self.branch is not None

-        print(f"Starting postgres on branch {self.branch}")
+        log.info(f"Starting postgres on branch {self.branch}")

        run_result = self.zenith_cli.run(['pg', 'start', self.branch, f'--tenantid={self.tenant_id}', f'--port={self.port}'])
        self.running = True

-        print(f"stdout: {run_result.stdout}")
+        log.info(f"stdout: {run_result.stdout}")

        return self

@@ -786,7 +793,7 @@ def postgres(zenith_cli: ZenithCli, initial_tenant: str, repo_dir: str, pg_bin:
    yield pgfactory

    # After the yield comes any cleanup code we need.
-    print('Starting postgres cleanup')
+    log.info('Starting postgres cleanup')
    pgfactory.stop_all()

 def read_pid(path: Path):
@@ -816,29 +823,36 @@ class WalAcceptor:

        cmd = [str(self.wa_bin_path)]
        cmd.extend(["-D", str(self.data_dir)])
-        cmd.extend(["--listen-pg", f"localhost:{self.port.pg}"])
-        cmd.extend(["--listen-http", f"localhost:{self.port.http}"])
+        cmd.extend(["--listen-pg", f"127.0.0.1:{self.port.pg}"])
+        cmd.extend(["--listen-http", f"127.0.0.1:{self.port.http}"])
        cmd.append("--daemonize")
        cmd.append("--no-sync")
        # Tell page server it can receive WAL from this WAL safekeeper
-        cmd.extend(["--pageserver", f"localhost:{self.pageserver_port}"])
+        cmd.extend(["--pageserver", f"127.0.0.1:{self.pageserver_port}"])
        cmd.extend(["--recall", "1 second"])
-        print('Running command "{}"'.format(' '.join(cmd)))
+        log.info('Running command "{}"'.format(' '.join(cmd)))
        env = {'PAGESERVER_AUTH_TOKEN': self.auth_token} if self.auth_token else None
        subprocess.run(cmd, check=True, env=env)

-        # wait for wal acceptor start by checkking that pid is readable
-        for _ in range(3):
-            pid = self.get_pid()
-            if pid is not None:
-                return self
-            time.sleep(0.5)
-
-        raise RuntimeError("cannot get wal acceptor pid")
+        # wait for wal acceptor start by checking its status
+        started_at = time.time()
+        while True:
+            try:
+                http_cli = self.http_client()
+                http_cli.check_status()
+            except Exception as e:
+                elapsed = time.time() - started_at
+                if elapsed > 3:
+                    raise RuntimeError(
+                        f"timed out waiting {elapsed:.0f}s for wal acceptor start: {e}")
+                time.sleep(0.5)
+            else:
+                break  # success
+        return self

    @property
    def pidfile(self) -> Path:
-        return self.data_dir / "wal_acceptor.pid"
+        return self.data_dir / "safekeeper.pid"

    def get_pid(self) -> Optional[int]:
        if not self.pidfile.exists():
@@ -852,10 +866,10 @@ class WalAcceptor:
        return pid

    def stop(self) -> 'WalAcceptor':
-        print('Stopping wal acceptor {}'.format(self.num))
+        log.info('Stopping wal acceptor {}'.format(self.num))
        pid = self.get_pid()
        if pid is None:
-            print("Wal acceptor {} is not running".format(self.num))
+            log.info("Wal acceptor {} is not running".format(self.num))
            return self

        try:
@@ -874,23 +888,27 @@ class WalAcceptor:

        # "replication=0" hacks psycopg not to send additional queries
        # on startup, see https://github.com/psycopg/psycopg2/pull/482
-        connstr = f"host=localhost port={self.port.pg} replication=0 options='-c ztimelineid={timeline_id} ztenantid={tenant_id}'"
+        connstr = f"host=127.0.0.1 port={self.port.pg} replication=0 options='-c ztimelineid={timeline_id} ztenantid={tenant_id}'"

        with closing(psycopg2.connect(connstr)) as conn:
            # server doesn't support transactions
            conn.autocommit = True
            with conn.cursor() as cur:
                request_json = json.dumps(request)
-                print(f"JSON_CTRL request on port {self.port.pg}: {request_json}")
+                log.info(f"JSON_CTRL request on port {self.port.pg}: {request_json}")
                cur.execute("JSON_CTRL " + request_json)
                all = cur.fetchall()
-                print(f"JSON_CTRL response: {all[0][0]}")
+                log.info(f"JSON_CTRL response: {all[0][0]}")
                return json.loads(all[0][0])

+    def http_client(self):
+        return WalAcceptorHttpClient(port=self.port.http)
+
+
 class WalAcceptorFactory:
    """ An object representing multiple running wal acceptors. """
    def __init__(self, zenith_binpath: Path, data_dir: Path, pageserver_port: int, port_distributor: PortDistributor):
-        self.wa_bin_path = zenith_binpath / 'wal_acceptor'
+        self.wa_bin_path = zenith_binpath / 'safekeeper'
        self.data_dir = data_dir
        self.instances: List[WalAcceptor] = []
        self.port_distributor = port_distributor
@@ -931,7 +949,7 @@ class WalAcceptorFactory:

    def get_connstrs(self) -> str:
        """ Get list of wal acceptor endpoints suitable for wal_acceptors GUC  """
-        return ','.join(["localhost:{}".format(wa.port.pg) for wa in self.instances])
+        return ','.join(["127.0.0.1:{}".format(wa.port.pg) for wa in self.instances])


@zenfixture
@@ -945,16 +963,34 @@ def wa_factory(zenith_binpath: str, repo_dir: str, pageserver_port: PageserverPo
    )
    yield wafactory
    # After the yield comes any cleanup code we need.
-    print('Starting wal acceptors cleanup')
+    log.info('Starting wal acceptors cleanup')
    wafactory.stop_all()

+@dataclass
+class PageserverTimelineStatus:
+    acceptor_epoch: int
+
+class WalAcceptorHttpClient(requests.Session):
+    def __init__(self, port: int) -> None:
+        super().__init__()
+        self.port = port
+
+    def check_status(self):
+        self.get(f"http://127.0.0.1:{self.port}/v1/status").raise_for_status()
+
+    def timeline_status(self, tenant_id: str, timeline_id: str) -> PageserverTimelineStatus:
+        res = self.get(f"http://127.0.0.1:{self.port}/v1/timeline/{tenant_id}/{timeline_id}")
+        res.raise_for_status()
+        resj = res.json()
+        return PageserverTimelineStatus(acceptor_epoch=resj['acceptor_state']['epoch'])
+

@zenfixture
 def base_dir() -> str:
    """ find the base directory (currently this is the git root) """

    base_dir = os.path.normpath(os.path.join(get_self_dir(), '../..'))
-    print('\nbase_dir is', base_dir)
+    log.info(f'base_dir is {base_dir}')
    return base_dir


@@ -983,7 +1019,7 @@ def test_output_dir(request: Any, top_output_dir: str) -> str:
        test_name = 'shared'

    test_output_dir = os.path.join(top_output_dir, test_name)
-    print('test_output_dir is', test_output_dir)
+    log.info(f'test_output_dir is {test_output_dir}')
    shutil.rmtree(test_output_dir, ignore_errors=True)
    mkdir_if_needed(test_output_dir)
    return test_output_dir
@@ -1025,7 +1061,7 @@ def pg_distrib_dir(base_dir: str) -> str:
        pg_dir = env_postgres_bin
    else:
        pg_dir = os.path.normpath(os.path.join(base_dir, DEFAULT_POSTGRES_DIR))
-    print('postgres dir is', pg_dir)
+    log.info(f'postgres dir is {pg_dir}')
    if not os.path.exists(os.path.join(pg_dir, 'bin/postgres')):
        raise Exception('postgres not found at "{}"'.format(pg_dir))
    return pg_dir
@@ -1064,7 +1100,7 @@ def list_files_to_compare(pgdata_dir: str):
                pgdata_files.append(rel_file)

    pgdata_files.sort()
-    print(pgdata_files)
+    log.info(pgdata_files)
    return pgdata_files

 # pg is the existing and running compute node, that we want to compare with a basebackup
@@ -1088,7 +1124,7 @@ def check_restored_datadir_content(zenith_cli: ZenithCli, test_output_dir: str,
    cmd = rf"""
        {psql_path}                                    \
            --no-psqlrc                                \
-            postgres://localhost:{pageserver_pg_port}  \
+            postgres://127.0.0.1:{pageserver_pg_port}  \
            -c 'basebackup {pg.tenant_id} {timeline}'  \
         | tar -x -C {restored_dir_path}
    """
@@ -1110,9 +1146,7 @@ def check_restored_datadir_content(zenith_cli: ZenithCli, test_output_dir: str,
                                                restored_dir_path,
                                                pgdata_files,
                                                shallow=False)
-    print('filecmp result mismatch and error lists:')
-    print(mismatch)
-    print(error)
+    log.info(f'filecmp result mismatch and error lists:\n\t mismatch={mismatch}\n\t error={error}')

    for f in mismatch:

@@ -0,0 +1,8 @@
+#!/bin/bash
+
+while true; do
+  echo -n "==== CURRENT TIME:" >> /tmp/test_output/netstat.stdout
+  date +"%T.%N" >> /tmp/test_output/netstat.stdout
+  sudo netstat -vpnoa | grep tcp | sort >> /tmp/test_output/netstat.stdout
+  sleep 0.5
+done
@@ -1,6 +1,7 @@
 import os
 from contextlib import closing
 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures", "fixtures.benchmark_fixture")

@@ -19,7 +20,7 @@ def test_bulk_insert(postgres: PostgresFactory, pageserver: ZenithPageserver, pg
    zenith_cli.run(["branch", "test_bulk_insert", "empty"])

    pg = postgres.create_start('test_bulk_insert')
-    print("postgres is running on 'test_bulk_insert' branch")
+    log.info("postgres is running on 'test_bulk_insert' branch")

    # Open a connection directly to the page server that we'll use to force
    # flushing the layers to disk
@@ -0,0 +1,49 @@
+import os
+from contextlib import closing
+from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log
+
+pytest_plugins = ("fixtures.zenith_fixtures", "fixtures.benchmark_fixture")
+
+#
+# Test buffering GisT build. It WAL-logs the whole relation, in 32-page chunks.
+# As of this writing, we're duplicate those giant WAL records for each page,
+# which makes the delta layer about 32x larger than it needs to be.
+#
+def test_gist_buffering_build(postgres: PostgresFactory, pageserver: ZenithPageserver, pg_bin, zenith_cli, zenbenchmark, repo_dir: str):
+    # Create a branch for us
+    zenith_cli.run(["branch", "test_gist_buffering_build", "empty"])
+
+    pg = postgres.create_start('test_gist_buffering_build')
+    log.info("postgres is running on 'test_gist_buffering_build' branch")
+
+    # Open a connection directly to the page server that we'll use to force
+    # flushing the layers to disk
+    psconn = pageserver.connect();
+    pscur = psconn.cursor()
+
+    # Get the timeline ID of our branch. We need it for the 'do_gc' command
+    with closing(pg.connect()) as conn:
+        with conn.cursor() as cur:
+            cur.execute("SHOW zenith.zenith_timeline")
+            timeline = cur.fetchone()[0]
+
+            # Create test table.
+            cur.execute("create table gist_point_tbl(id int4, p point)");
+            cur.execute("insert into gist_point_tbl select g, point(g, g) from generate_series(1, 1000000) g;");
+
+            # Build the index.
+            with zenbenchmark.record_pageserver_writes(pageserver, 'pageserver_writes'):
+                with zenbenchmark.record_duration('build'):
+                    cur.execute("create index gist_pointidx2 on gist_point_tbl using gist(p) with (buffering = on)");
+
+                    # Flush the layers from memory to disk. This is included in the reported
+                    # time and I/O
+                    pscur.execute(f"do_gc {pageserver.initial_tenant} {timeline} 1000000")
+
+            # Record peak memory usage
+            zenbenchmark.record("peak_mem", zenbenchmark.get_peak_mem(pageserver) / 1024, 'MB')
+
+            # Report disk space used by the repository
+            timeline_size = zenbenchmark.get_timeline_size(repo_dir, pageserver.initial_tenant, timeline)
+            zenbenchmark.record('size', timeline_size / (1024*1024), 'MB')
@@ -1,6 +1,7 @@
 import os
 from contextlib import closing
 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures", "fixtures.benchmark_fixture")

@@ -18,7 +19,7 @@ def test_pgbench(postgres: PostgresFactory, pageserver: ZenithPageserver, pg_bin
    zenith_cli.run(["branch", "test_pgbench_perf", "empty"])

    pg = postgres.create_start('test_pgbench_perf')
-    print("postgres is running on 'test_pgbench_perf' branch")
+    log.info("postgres is running on 'test_pgbench_perf' branch")

    # Open a connection directly to the page server that we'll use to force
    # flushing the layers to disk
@@ -13,6 +13,7 @@
 import os
 from contextlib import closing
 from fixtures.zenith_fixtures import PostgresFactory, ZenithPageserver
+from fixtures.log_helper import log

 pytest_plugins = ("fixtures.zenith_fixtures", "fixtures.benchmark_fixture")

@@ -21,7 +22,7 @@ def test_write_amplification(postgres: PostgresFactory, pageserver: ZenithPagese
    zenith_cli.run(["branch", "test_write_amplification", "empty"])

    pg = postgres.create_start('test_write_amplification')
-    print("postgres is running on 'test_write_amplification' branch")
+    log.info("postgres is running on 'test_write_amplification' branch")

    # Open a connection directly to the page server that we'll use to force
    # flushing the layers to disk
@@ -1,2 +1,4 @@
 [pytest]
 minversion = 6.0
+log_format = %(asctime)s.%(msecs)-3d %(levelname)s [%(filename)s:%(lineno)d] %(message)s
+log_date_format = %Y-%m-%d %H:%M:%S
@@ -1,6 +1,8 @@
 import pytest
 import os

+from fixtures.log_helper import log
+
 pytest_plugins = ("fixtures.zenith_fixtures")
 """
 Use this test to see what happens when tests fail.
@@ -22,7 +24,7 @@ def test_broken(zenith_cli, pageserver, postgres, pg_bin):
    zenith_cli.run(["branch", "test_broken", "empty"])

    postgres.create_start("test_broken")
-    print('postgres is running')
+    log.info('postgres is running')

-    print('THIS NEXT COMMAND WILL FAIL:')
+    log.info('THIS NEXT COMMAND WILL FAIL:')
    pg_bin.run('pgbench -i_am_a_broken_test'.split())
@@ -11,6 +11,8 @@ regex = "1.4.5"
 bincode = "1.3"
 bytes = "1.0.1"
 byteorder = "1.4.3"
+hyper = "0.14"
+routerify = "2"
 fs2 = "0.4.3"
 lazy_static = "1.4.0"
 serde_json = "1"
@@ -89,12 +89,12 @@ A: Page Server is a single server which can be lost. As our primary

 Q: What if the compute node evicts a page, needs it back, but the page is yet
   to reach the Page Server?
-A: If the compute node has evicted a page, all changes from that page are
-   already committed, i.e. they are saved on majority of WAL safekeepers. These
-   WAL records will eventually reach the Page Server. The Page Server notes
-   that the compute note requests pages with a very recent LSN and will not
-   respond to the compute node until it a corresponding WAL is received from WAL
-   safekeepers.
+A: If the compute node has evicted a page, changes to it have been WAL-logged
+   (that's why it is called Write Ahead logging; there are some exceptions like
+   index builds, but these are exceptions). These WAL records will eventually
+   reach the Page Server. The Page Server notes that the compute note requests
+   pages with a very recent LSN and will not respond to the compute node until a
+   corresponding WAL is received from WAL safekeepers.

 Q: How long may Page Server wait for?
 A: Not too long, hopefully. If a page is evicted, it probably was not used for
@@ -1,5 +1,5 @@
 //
-// Main entry point for the wal_acceptor executable
+// Main entry point for the safekeeper executable
 //
 use anyhow::Result;
 use clap::{App, Arg};
@@ -14,20 +14,21 @@ use zenith_utils::http::endpoint;
 use zenith_utils::logging;

 use walkeeper::defaults::{DEFAULT_HTTP_LISTEN_ADDR, DEFAULT_PG_LISTEN_ADDR};
+use walkeeper::http;
 use walkeeper::s3_offload;
 use walkeeper::wal_service;
 use walkeeper::WalAcceptorConf;

 fn main() -> Result<()> {
    zenith_metrics::set_common_metrics_prefix("safekeeper");
-    let arg_matches = App::new("Zenith wal_acceptor")
+    let arg_matches = App::new("Zenith safekeeper")
        .about("Store WAL stream to local file system and push it to WAL receivers")
        .arg(
            Arg::with_name("datadir")
                .short("D")
                .long("dir")
                .takes_value(true)
-                .help("Path to the WAL acceptor data directory"),
+                .help("Path to the safekeeper data directory"),
        )
        .arg(
            Arg::with_name("listen-pg")
@@ -128,14 +129,20 @@ fn main() -> Result<()> {
 }

 fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {
-    let log_filename = conf.data_dir.join("wal_acceptor.log");
-    let (_scope_guard, log_file) = logging::init(log_filename, conf.daemonize)?;
+    let log_filename = conf.data_dir.join("safekeeper.log");
+    let log_file = logging::init(log_filename, conf.daemonize)?;

    let http_listener = TcpListener::bind(conf.listen_http_addr.clone()).map_err(|e| {
        error!("failed to bind to address {}: {}", conf.listen_http_addr, e);
        e
    })?;

+    info!("Starting safekeeper on {}", conf.listen_pg_addr);
+    let pg_listener = TcpListener::bind(conf.listen_pg_addr.clone()).map_err(|e| {
+        error!("failed to bind to address {}: {}", conf.listen_pg_addr, e);
+        e
+    })?;
+
    if conf.daemonize {
        info!("daemonizing...");

@@ -145,7 +152,7 @@ fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {
        let stderr = log_file;

        let daemonize = Daemonize::new()
-            .pid_file("wal_acceptor.pid")
+            .pid_file("safekeeper.pid")
            .working_directory(Path::new("."))
            .stdout(stdout)
            .stderr(stderr);
@@ -158,11 +165,12 @@ fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {

    let mut threads = Vec::new();

+    let conf_cloned = conf.clone();
    let http_endpoint_thread = thread::Builder::new()
        .name("http_endpoint_thread".into())
-        .spawn(move || {
-            // No authentication at all: read-only metrics only, early stage.
-            let router = endpoint::make_router();
+        .spawn(|| {
+            // TODO authentication
+            let router = http::make_router(conf_cloned);
            endpoint::serve_thread_main(router, http_listener).unwrap();
        })
        .unwrap();
@@ -184,7 +192,7 @@ fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {
        .name("WAL acceptor thread".into())
        .spawn(|| {
            // thread code
-            let thread_result = wal_service::thread_main(conf);
+            let thread_result = wal_service::thread_main(conf, pg_listener);
            if let Err(e) = thread_result {
                info!("wal_service thread terminated: {}", e);
            }
@@ -0,0 +1,2 @@
+pub mod routes;
+pub use routes::make_router;
@@ -0,0 +1,88 @@
+use hyper::{Body, Request, Response, StatusCode};
+use routerify::ext::RequestExt;
+use routerify::RouterBuilder;
+use serde::Serialize;
+use serde::Serializer;
+use std::fmt::Display;
+use std::sync::Arc;
+use zenith_utils::lsn::Lsn;
+
+use crate::safekeeper::AcceptorState;
+use crate::timeline::CreateControlFile;
+use crate::timeline::GlobalTimelines;
+use crate::WalAcceptorConf;
+use zenith_utils::http::endpoint;
+use zenith_utils::http::error::ApiError;
+use zenith_utils::http::json::json_response;
+use zenith_utils::http::request::parse_request_param;
+use zenith_utils::zid::{ZTenantId, ZTimelineId};
+
+/// Healthcheck handler.
+async fn status_handler(_: Request<Body>) -> Result<Response<Body>, ApiError> {
+    Ok(json_response(StatusCode::OK, "")?)
+}
+
+fn get_conf(request: &Request<Body>) -> &WalAcceptorConf {
+    request
+        .data::<Arc<WalAcceptorConf>>()
+        .expect("unknown state type")
+        .as_ref()
+}
+
+fn display_serialize<S, F>(z: &F, s: S) -> Result<S::Ok, S::Error>
+where
+    S: Serializer,
+    F: Display,
+{
+    s.serialize_str(&format!("{}", z))
+}
+
+/// Info about timeline on safekeeper ready for reporting.
+#[derive(Debug, Serialize)]
+struct TimelineStatus {
+    #[serde(serialize_with = "display_serialize")]
+    tenant_id: ZTenantId,
+    #[serde(serialize_with = "display_serialize")]
+    timeline_id: ZTimelineId,
+    acceptor_state: AcceptorState,
+    #[serde(serialize_with = "display_serialize")]
+    commit_lsn: Lsn,
+    #[serde(serialize_with = "display_serialize")]
+    truncate_lsn: Lsn,
+}
+
+/// Report info about timeline.
+async fn timeline_status_handler(request: Request<Body>) -> Result<Response<Body>, ApiError> {
+    let tenant_id: ZTenantId = parse_request_param(&request, "tenant_id")?;
+    let timeline_id: ZTimelineId = parse_request_param(&request, "timeline_id")?;
+
+    let tli = GlobalTimelines::get(
+        get_conf(&request),
+        tenant_id,
+        timeline_id,
+        CreateControlFile::False,
+    )
+    .map_err(ApiError::from_err)?;
+    let sk_state = tli.get_info();
+
+    let status = TimelineStatus {
+        tenant_id,
+        timeline_id,
+        acceptor_state: sk_state.acceptor_state,
+        commit_lsn: sk_state.commit_lsn,
+        truncate_lsn: sk_state.truncate_lsn,
+    };
+    Ok(json_response(StatusCode::OK, status)?)
+}
+
+/// Safekeeper http router.
+pub fn make_router(conf: WalAcceptorConf) -> RouterBuilder<hyper::Body, ApiError> {
+    let router = endpoint::make_router();
+    router
+        .data(Arc::new(conf))
+        .get("/v1/status", status_handler)
+        .get(
+            "/v1/timeline/:tenant_id/:timeline_id",
+            timeline_status_handler,
+        )
+}
@@ -2,6 +2,7 @@
 use std::path::PathBuf;
 use std::time::Duration;

+pub mod http;
 pub mod json_ctrl;
 pub mod receive_wal;
 pub mod replication;
@@ -290,13 +290,13 @@ lazy_static! {
        "Current flush_lsn, grouped by timeline",
        &["ztli"]
    )
-    .expect("Failed to register safekeeper_flush_lsn int gauge vec");
+    .expect("Failed to register safekeeper_flush_lsn gauge vec");
    static ref COMMIT_LSN_GAUGE: GaugeVec = register_gauge_vec!(
        "safekeeper_commit_lsn",
        "Current commit_lsn (not necessarily persisted to disk), grouped by timeline",
        &["ztli"]
    )
-    .expect("Failed to register safekeeper_commit_lsn int gauge vec");
+    .expect("Failed to register safekeeper_commit_lsn gauge vec");
 }

 struct SafeKeeperMetrics {
@@ -312,6 +312,13 @@ impl SafeKeeperMetrics {
            commit_lsn: COMMIT_LSN_GAUGE.with_label_values(&[&ztli_str]),
        }
    }
+
+    fn new_noname() -> SafeKeeperMetrics {
+        SafeKeeperMetrics {
+            flush_lsn: FLUSH_LSN_GAUGE.with_label_values(&["n/a"]),
+            commit_lsn: COMMIT_LSN_GAUGE.with_label_values(&["n/a"]),
+        }
+    }
 }

 /// SafeKeeper which consumes events (messages from compute) and provides
@@ -322,7 +329,7 @@ pub struct SafeKeeper<ST: Storage> {
    pub flush_lsn: Lsn,
    pub tli: u32,
    // Cached metrics so we don't have to recompute labels on each update.
-    metrics: Option<SafeKeeperMetrics>,
+    metrics: SafeKeeperMetrics,
    /// not-yet-flushed pairs of same named fields in s.*
    pub commit_lsn: Lsn,
    pub truncate_lsn: Lsn,
@@ -341,7 +348,7 @@ where
        SafeKeeper {
            flush_lsn,
            tli,
-            metrics: None,
+            metrics: SafeKeeperMetrics::new_noname(),
            commit_lsn: state.commit_lsn,
            truncate_lsn: state.truncate_lsn,
            storage,
@@ -393,7 +400,7 @@ where
        self.s.server.wal_seg_size = msg.wal_seg_size;
        self.storage.persist(&self.s, true)?;

-        self.metrics = Some(SafeKeeperMetrics::new(self.s.server.ztli));
+        self.metrics = SafeKeeperMetrics::new(self.s.server.ztli);

        info!(
            "processed greeting from proposer {:?}, sending term {:?}",
@@ -518,11 +525,7 @@ where
        }
        if last_rec_lsn > self.flush_lsn {
            self.flush_lsn = last_rec_lsn;
-            self.metrics
-                .as_ref()
-                .unwrap()
-                .flush_lsn
-                .set(u64::from(self.flush_lsn) as f64);
+            self.metrics.flush_lsn.set(u64::from(self.flush_lsn) as f64);
        }

        // Advance commit_lsn taking into account what we have locally. xxx this
@@ -541,8 +544,6 @@ where
                commit_lsn >= msg.h.epoch_start_lsn && self.s.commit_lsn < msg.h.epoch_start_lsn;
            self.commit_lsn = commit_lsn;
            self.metrics
-                .as_ref()
-                .unwrap()
                .commit_lsn
                .set(u64::from(self.commit_lsn) as f64);
        }
@@ -13,14 +13,13 @@ use std::str::FromStr;
 use std::sync::Arc;
 use zenith_utils::postgres_backend;
 use zenith_utils::postgres_backend::PostgresBackend;
-use zenith_utils::pq_proto::{BeMessage, FeStartupMessage, RowDescriptor};
+use zenith_utils::pq_proto::{BeMessage, FeStartupMessage, RowDescriptor, INT4_OID, TEXT_OID};
 use zenith_utils::zid::{ZTenantId, ZTimelineId};

 use crate::timeline::CreateControlFile;

 /// Handler for streaming WAL from acceptor
 pub struct SendWalHandler {
-    /// wal acceptor configuration
    pub conf: WalAcceptorConf,
    /// assigned application name
    pub appname: Option<String>,
@@ -72,19 +71,16 @@ impl postgres_backend::Handler for SendWalHandler {
        }
        if query_string.starts_with(b"IDENTIFY_SYSTEM") {
            self.handle_identify_system(pgb)?;
-            Ok(())
        } else if query_string.starts_with(b"START_REPLICATION") {
            ReplicationConn::new(pgb).run(self, pgb, &query_string)?;
-            Ok(())
        } else if query_string.starts_with(b"START_WAL_PUSH") {
            ReceiveWalConn::new(pgb)?.run(self)?;
-            Ok(())
        } else if query_string.starts_with(b"JSON_CTRL") {
            handle_json_ctrl(self, pgb, &query_string)?;
-            Ok(())
        } else {
            bail!("Unexpected command {:?}", query_string);
        }
+        Ok(())
    }
 }

@@ -114,25 +110,25 @@ impl SendWalHandler {
        pgb.write_message_noflush(&BeMessage::RowDescription(&[
            RowDescriptor {
                name: b"systemid",
-                typoid: 25,
+                typoid: TEXT_OID,
                typlen: -1,
                ..Default::default()
            },
            RowDescriptor {
                name: b"timeline",
-                typoid: 23,
+                typoid: INT4_OID,
                typlen: 4,
                ..Default::default()
            },
            RowDescriptor {
                name: b"xlogpos",
-                typoid: 25,
+                typoid: TEXT_OID,
                typlen: -1,
                ..Default::default()
            },
            RowDescriptor {
                name: b"dbname",
-                typoid: 25,
+                typoid: TEXT_OID,
                typlen: -1,
                ..Default::default()
            },
@@ -112,7 +112,7 @@ impl SharedState {
        }
        match opts.open(&control_file_path) {
            Ok(mut file) => {
-                // Lock file to prevent two or more active wal_acceptors
+                // Lock file to prevent two or more active safekeepers
                match file.try_lock_exclusive() {
                    Ok(()) => {}
                    Err(e) => {
@@ -289,7 +289,7 @@ lazy_static! {
 }

 /// A zero-sized struct used to manage access to the global timelines map.
-struct GlobalTimelines;
+pub struct GlobalTimelines;

 impl GlobalTimelines {
    /// Get a timeline with control file loaded from the global TIMELINES map.
@@ -12,13 +12,7 @@ use crate::WalAcceptorConf;
 use zenith_utils::postgres_backend::{AuthType, PostgresBackend};

 /// Accept incoming TCP connections and spawn them into a background thread.
-pub fn thread_main(conf: WalAcceptorConf) -> Result<()> {
-    info!("Starting wal acceptor on {}", conf.listen_pg_addr);
-    let listener = TcpListener::bind(conf.listen_pg_addr.clone()).map_err(|e| {
-        error!("failed to bind to address {}: {}", conf.listen_pg_addr, e);
-        e
-    })?;
-
+pub fn thread_main(conf: WalAcceptorConf, listener: TcpListener) -> Result<()> {
    loop {
        match listener.accept() {
            Ok((socket, peer_addr)) => {
@@ -41,8 +35,8 @@ fn handle_socket(socket: TcpStream, conf: WalAcceptorConf) -> Result<()> {
    socket.set_nodelay(true)?;

    let mut conn_handler = SendWalHandler::new(conf);
-    let pgbackend = PostgresBackend::new(socket, AuthType::Trust, None)?;
-    // libpq replication protocol between wal_acceptor and replicas/pagers
+    let pgbackend = PostgresBackend::new(socket, AuthType::Trust, None, false)?;
+    // libpq replication protocol between safekeeper and replicas/pagers
    pgbackend.run(&mut conn_handler)?;

    Ok(())
@@ -88,7 +88,12 @@ fn main() -> Result<()> {
        )
        .subcommand(SubCommand::with_name("status"))
        .subcommand(SubCommand::with_name("start").about("Start local pageserver"))
-        .subcommand(SubCommand::with_name("stop").about("Stop local pageserver"))
+        .subcommand(SubCommand::with_name("stop").about("Stop local pageserver")
+                    .arg(Arg::with_name("immediate")
+                    .help("Don't flush repository data at shutdown")
+                    .required(false)
+                    )
+        )
        .subcommand(SubCommand::with_name("restart").about("Restart local pageserver"))
        .subcommand(
            SubCommand::with_name("pg")
@@ -196,10 +201,12 @@ fn main() -> Result<()> {
            }
        }

-        ("stop", Some(_sub_m)) => {
+        ("stop", Some(stop_match)) => {
            let pageserver = PageServerNode::from_env(&env);

-            if let Err(e) = pageserver.stop() {
+            let immediate = stop_match.is_present("immediate");
+
+            if let Err(e) = pageserver.stop(immediate) {
                eprintln!("pageserver stop failed: {}", e);
                exit(1);
            }
@@ -208,7 +215,8 @@ fn main() -> Result<()> {
        ("restart", Some(_sub_m)) => {
            let pageserver = PageServerNode::from_env(&env);

-            if let Err(e) = pageserver.stop() {
+            //TODO what shutdown strategy should we use here?
+            if let Err(e) = pageserver.stop(false) {
                eprintln!("pageserver stop failed: {}", e);
                exit(1);
            }
@@ -18,13 +18,9 @@ serde = { version = "1.0", features = ["derive"] }
 serde_json = "1"
 thiserror = "1.0"
 tokio = "1.11"
-crossbeam-utils = "0.8.5"
-
-slog-async = "2.6.0"
-slog-stdlog = "4.1.0"
-slog-scope = "4.4.0"
-slog-term = "2.8.0"
-slog = "2.7.0"
+tracing = "0.1"
+tracing-log = "0.1"
+tracing-subscriber = "0.2"

 zenith_metrics = { path = "../zenith_metrics" }
 workspace_hack = { path = "../workspace_hack" }
@@ -1,45 +0,0 @@
-use crossbeam_utils::thread;
-
-use std::{
-    fs::File,
-    io,
-    path::PathBuf,
-    sync::atomic::{AtomicUsize, Ordering},
-};
-
-pub fn batch_fsync(paths: &[PathBuf]) -> std::io::Result<()> {
-    let next = AtomicUsize::new(0);
-
-    let num_threads = std::cmp::min(paths.len() / 2, 256);
-
-    if num_threads <= 1 {
-        for path in paths {
-            let file = File::open(&path)?;
-            file.sync_all()?;
-        }
-
-        return Ok(());
-    }
-
-    thread::scope(|s| -> io::Result<()> {
-        let mut handles = Vec::new();
-        for _ in 0..num_threads {
-            handles.push(s.spawn(|_| loop {
-                let idx = next.fetch_add(1, Ordering::Relaxed);
-                if idx >= paths.len() {
-                    return io::Result::Ok(());
-                }
-
-                let file = File::open(&paths[idx])?;
-                file.sync_all()?;
-            }));
-        }
-
-        for handle in handles {
-            handle.join().unwrap()?;
-        }
-
-        Ok(())
-    })
-    .unwrap()
-}
@@ -29,24 +29,24 @@ mod tests {

    #[test]
    fn test_connection_host_port() {
-        let config: Config = "postgresql://no_user@localhost:64000/no_db"
+        let config: Config = "postgresql://no_user@127.0.0.1:64000/no_db"
            .parse()
            .unwrap();
        assert_eq!(
            connection_host_port(&config),
-            ("localhost".to_owned(), 64000)
+            ("127.0.0.1".to_owned(), 64000)
        );
    }

    #[test]
    #[should_panic(expected = "only one pair of host and port is supported in connection string")]
    fn test_connection_host_port_multiple_ports() {
-        let config: Config = "postgresql://no_user@localhost:64000,localhost:64001/no_db"
+        let config: Config = "postgresql://no_user@127.0.0.1:64000,127.0.0.1:64001/no_db"
            .parse()
            .unwrap();
        assert_eq!(
            connection_host_port(&config),
-            ("localhost".to_owned(), 64000)
+            ("127.0.0.1".to_owned(), 64000)
        );
    }
 }
@@ -12,8 +12,17 @@ use std::net::TcpListener;
 use zenith_metrics::{new_common_metric_name, register_int_counter, IntCounter};
 use zenith_metrics::{Encoder, TextEncoder};

+use std::sync::Mutex;
+use tokio::sync::oneshot::Sender;
+
 use super::error::ApiError;

+lazy_static! {
+    /// Channel used to send shutdown signal - wrapped in an Option to allow
+    /// it to be taken by value (since oneshot channels consume themselves on send)
+    static ref SHUTDOWN_SENDER: Mutex<Option<Sender<()>>> = Mutex::new(None);
+}
+
 lazy_static! {
    static ref SERVE_METRICS_COUNT: IntCounter = register_int_counter!(
        new_common_metric_name("serve_metrics_count"),
@@ -143,11 +152,18 @@ pub fn check_permission(req: &Request<Body>, tenantid: Option<ZTenantId>) -> Res
    }
 }

+// Send shutdown signal
+pub fn shutdown() {
+    if let Some(tx) = SHUTDOWN_SENDER.lock().unwrap().take() {
+        let _ = tx.send(());
+    }
+}
+
 pub fn serve_thread_main(
    router_builder: RouterBuilder<hyper::Body, ApiError>,
    listener: TcpListener,
 ) -> anyhow::Result<()> {
-    log::info!("Starting a http endoint at {}", listener.local_addr()?);
+    log::info!("Starting a http endpoint at {}", listener.local_addr()?);

    // Create a Service from the router above to handle incoming requests.
    let service = RouterService::new(router_builder.build().map_err(|err| anyhow!(err))?).unwrap();
@@ -159,7 +175,14 @@ pub fn serve_thread_main(

    let _guard = runtime.enter();

-    let server = Server::from_tcp(listener)?.serve(service);
+    let (send, recv) = tokio::sync::oneshot::channel::<()>();
+    *SHUTDOWN_SENDER.lock().unwrap() = Some(send);
+
+    let server = Server::from_tcp(listener)?
+        .serve(service)
+        .with_graceful_shutdown(async {
+            recv.await.ok();
+        });

    runtime.block_on(server)?;

@@ -1,3 +1,4 @@
 pub mod endpoint;
 pub mod error;
 pub mod json;
+pub mod request;
@@ -0,0 +1,33 @@
+use std::str::FromStr;
+
+use super::error::ApiError;
+use hyper::{Body, Request};
+use routerify::ext::RequestExt;
+
+pub fn get_request_param<'a>(
+    request: &'a Request<Body>,
+    param_name: &str,
+) -> Result<&'a str, ApiError> {
+    match request.param(param_name) {
+        Some(arg) => Ok(arg),
+        None => {
+            return Err(ApiError::BadRequest(format!(
+                "no {} specified in path param",
+                param_name
+            )))
+        }
+    }
+}
+
+pub fn parse_request_param<T: FromStr>(
+    request: &Request<Body>,
+    param_name: &str,
+) -> Result<T, ApiError> {
+    match get_request_param(request, param_name)?.parse() {
+        Ok(v) => Ok(v),
+        Err(_) => Err(ApiError::BadRequest(format!(
+            "failed to parse {}",
+            param_name
+        ))),
+    }
+}
@@ -40,6 +40,3 @@ pub mod logging;

 // Misc
 pub mod accum;
-
-/// Utility for quickly fsyncing many files at once
-pub mod batch_fsync;
@@ -1,4 +1,3 @@
-use slog::{Drain, Level};
 use std::{
    fs::{File, OpenOptions},
    path::Path,
@@ -6,10 +5,12 @@ use std::{

 use anyhow::{Context, Result};

-pub fn init(
-    log_filename: impl AsRef<Path>,
-    daemonize: bool,
-) -> Result<(slog_scope::GlobalLoggerGuard, File)> {
+use tracing::subscriber::set_global_default;
+use tracing_log::LogTracer;
+use tracing_subscriber::fmt;
+use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};
+
+pub fn init(log_filename: impl AsRef<Path>, daemonize: bool) -> Result<File> {
    // Don't open the same file for output multiple times;
    // the different fds could overwrite each other's output.
    let log_file = OpenOptions::new()
@@ -18,30 +19,38 @@ pub fn init(
        .open(&log_filename)
        .with_context(|| format!("failed to open {:?}", log_filename.as_ref()))?;

+    let default_filter_str = "info";
+
+    // We fall back to printing all spans at info-level or above if
+    // the RUST_LOG environment variable is not set.
+    let env_filter =
+        EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new(default_filter_str));
+
    // we are cloning and returning log file in order to allow redirecting daemonized stdout and stderr to it
    // if we do not use daemonization (e.g. in docker) it is better to log to stdout directly
    // for example to be in line with docker log command which expects logs comimg from stdout
-    let guard = if daemonize {
-        let decorator = slog_term::PlainSyncDecorator::new(log_file.try_clone()?);
-        let drain = slog_term::FullFormat::new(decorator)
-            .build()
-            .filter_level(Level::Info)
-            .fuse();
-        let logger = slog::Logger::root(drain, slog::o!());
-        slog_scope::set_global_logger(logger)
+    //
+    // TODO: perhaps use a more human-readable format when !daemonize
+    if daemonize {
+        let x = log_file.try_clone().unwrap();
+
+        let fmt_layer = fmt::layer()
+            .pretty()
+            .with_target(false) // don't include event targets
+            .with_ansi(false) // don't use colors in log file
+            .with_writer(move || x.try_clone().unwrap());
+        let subscriber = Registry::default().with(env_filter).with(fmt_layer);
+
+        set_global_default(subscriber).expect("Failed to set subscriber");
    } else {
-        let decorator = slog_term::TermDecorator::new().build();
-        let drain = slog_term::FullFormat::new(decorator)
-            .build()
-            .filter_level(Level::Info)
-            .fuse();
-        let drain = slog_async::Async::new(drain).chan_size(1000).build().fuse();
-        let logger = slog::Logger::root(drain, slog::o!());
-        slog_scope::set_global_logger(logger)
-    };
+        let fmt_layer = fmt::layer().with_target(false); // don't include event targets
+        let subscriber = Registry::default().with(env_filter).with(fmt_layer);

-    // initialise forwarding of std log calls
-    slog_stdlog::init()?;
+        set_global_default(subscriber).expect("Failed to set subscriber");
+    }

-    Ok((guard, log_file))
+    // Redirect all `log`'s events to our subscriber
+    LogTracer::init().expect("Failed to set logger");
+
+    Ok(log_file)
 }
@@ -13,7 +13,11 @@ use serde::{Deserialize, Serialize};
 use std::io::{self, Write};
 use std::net::{Shutdown, SocketAddr, TcpStream};
 use std::str::FromStr;
+use std::sync::atomic::{AtomicBool, Ordering};
 use std::sync::Arc;
+use std::time::Duration;
+
+static PGBACKEND_SHUTDOWN_REQUESTED: AtomicBool = AtomicBool::new(false);

 pub trait Handler {
    /// Handle single query.
@@ -135,13 +139,32 @@ pub fn query_from_cstring(query_string: Bytes) -> Vec<u8> {
    query_string
 }

+// Helper function for socket read loops
+pub fn is_socket_read_timed_out(error: &anyhow::Error) -> bool {
+    for cause in error.chain() {
+        if let Some(io_error) = cause.downcast_ref::<io::Error>() {
+            if io_error.kind() == std::io::ErrorKind::WouldBlock {
+                return true;
+            }
+        }
+    }
+    false
+}
+
 impl PostgresBackend {
    pub fn new(
        socket: TcpStream,
        auth_type: AuthType,
        tls_config: Option<Arc<rustls::ServerConfig>>,
+        set_read_timeout: bool,
    ) -> io::Result<Self> {
        let peer_addr = socket.peer_addr()?;
+        if set_read_timeout {
+            socket
+                .set_read_timeout(Some(Duration::from_secs(5)))
+                .unwrap();
+        }
+
        Ok(Self {
            stream: Some(Stream::Bidirectional(BidiStream::from_tcp(socket))),
            buf_out: BytesMut::with_capacity(10 * 1024),
@@ -229,12 +252,26 @@ impl PostgresBackend {

        let mut unnamed_query_string = Bytes::new();

-        while let Some(msg) = self.read_message()? {
-            trace!("got message {:?}", msg);
+        while !PGBACKEND_SHUTDOWN_REQUESTED.load(Ordering::Relaxed) {
+            match self.read_message() {
+                Ok(message) => {
+                    if let Some(msg) = message {
+                        trace!("got message {:?}", msg);

-            match self.process_message(handler, msg, &mut unnamed_query_string)? {
-                ProcessMsgResult::Continue => continue,
-                ProcessMsgResult::Break => break,
+                        match self.process_message(handler, msg, &mut unnamed_query_string)? {
+                            ProcessMsgResult::Continue => continue,
+                            ProcessMsgResult::Break => break,
+                        }
+                    } else {
+                        break;
+                    }
+                }
+                Err(e) => {
+                    // If it is a timeout error, continue the loop
+                    if !is_socket_read_timed_out(&e) {
+                        return Err(e);
+                    }
+                }
            }
        }

@@ -427,3 +464,8 @@ impl PostgresBackend {
        Ok(ProcessMsgResult::Continue)
    }
 }
+
+// Set the flag to inform connections to cancel
+pub fn set_pgbackend_shutdown_requested() {
+    PGBACKEND_SHUTDOWN_REQUESTED.swap(true, Ordering::Relaxed);
+}
@@ -15,8 +15,9 @@ use std::str;
 pub type Oid = u32;
 pub type SystemId = u64;

-pub const TEXT_OID: Oid = 25;
 pub const INT8_OID: Oid = 20;
+pub const INT4_OID: Oid = 23;
+pub const TEXT_OID: Oid = 25;

 #[derive(Debug)]
 pub enum FeMessage {
@@ -110,7 +110,7 @@ fn ssl() {
        .unwrap();
    let tls_config = Some(Arc::new(cfg));

-    let pgb = PostgresBackend::new(server_sock, AuthType::Trust, tls_config).unwrap();
+    let pgb = PostgresBackend::new(server_sock, AuthType::Trust, tls_config, true).unwrap();
    pgb.run(&mut handler).unwrap();
    assert!(handler.got_query);

@@ -150,7 +150,7 @@ fn no_ssl() {

    let mut handler = TestHandler;

-    let pgb = PostgresBackend::new(server_sock, AuthType::Trust, None).unwrap();
+    let pgb = PostgresBackend::new(server_sock, AuthType::Trust, None, true).unwrap();
    pgb.run(&mut handler).unwrap();

    client_jh.join().unwrap();
@@ -214,7 +214,7 @@ fn server_forces_ssl() {
        .unwrap();
    let tls_config = Some(Arc::new(cfg));

-    let pgb = PostgresBackend::new(server_sock, AuthType::Trust, tls_config).unwrap();
+    let pgb = PostgresBackend::new(server_sock, AuthType::Trust, tls_config, true).unwrap();
    let res = pgb.run(&mut handler).unwrap_err();
    assert_eq!("client did not connect with TLS", format!("{}", res));
Author	SHA1	Message	Date
Arthur Petukhovsky	5c904dd5d8	Use ip instead of localhost to not resolve anything	2021-10-18 22:33:36 +03:00
Arthur Petukhovsky	b05757d3a2	Update netstat script	2021-10-15 18:34:25 +03:00
Arthur Petukhovsky	b4bf0a01bb	Merge branch 'fix-proposer-queue-cleanup' into netstat-logs	2021-10-15 14:04:45 +03:00
Arthur Petukhovsky	0907fe638d	Collect netstat info while running tests	2021-10-15 13:59:17 +03:00
Kirill Bulatov	4ade0bb41c	Refactor upload/download_relish function signatures. This makes them more generic, by taking any Read / Write trait implementation, instead of operating directly on a a file.	2021-10-15 11:34:15 +03:00
Stas Kelvich	100da024b6	expose pageserver http socket in docker	2021-10-15 00:26:38 +03:00
Arseny Sher	de744a44dd	Add /timeline http request to safekeeper returning its status. Which is mainly generational state (terms) and useful LSNs. Also add /status basic healthcheck request which is now used in tests to determine the safekeeper is up; this fixes #726. ref #115	2021-10-14 19:02:38 +03:00
Arthur Petukhovsky	6ed0c23731	Bump vendor/postgres	2021-10-14 17:26:11 +03:00
Heikki Linnakangas	0e026371ec	Optimize WAL decoding slightly. This adds a fast-path for the common case that the record doesn't cross a page boundary. We now split off a new Bytes directly from the original input buffer in that case, instead of copying the record to a new BytesMut. Shaves about 5% of the page server's CPU time on my laptop, in the 'test_bulk_insert' test.	2021-10-14 14:21:23 +03:00
Arthur Petukhovsky	4b87acb1f6	Use logging in python tests (#674 ) * Use logging in python tests * Use f-strings for logs * Don't log test output while running * Use only pytest logging handler * Add more info about pytest logging	2021-10-14 13:10:09 +03:00
Dmitry Ivanov	43957f4401	[cross-repo-ci] Use solely commit hash to test PRs in CI See #744 for the discussion.	2021-10-13 17:16:02 +03:00
Heikki Linnakangas	8a4f092e82	Skip syncing the temp initdb installation. Doesn't make much difference on my laptop with SSD, but every little helps, and with a slower disk it might be noticeable.	2021-10-13 16:59:00 +03:00
Egor Suvorov	6b6b3f68be	Safekeeper metrics refactor (#747 )	2021-10-13 16:28:24 +03:00
Arseny Sher	96f1175a80	Cleanup hardcoded oids.	2021-10-13 10:52:47 +03:00
Patrick Insinger	1c29de81de	pageserver - remove `lsn` from `WALRecord`	2021-10-13 00:03:42 -07:00
Egor Suvorov	f658263543	Revert "Dockerfile: remove wal_acceptor alias for safekeeper" This reverts commit `64ca947722`.	2021-10-12 19:05:58 +00:00
Egor Suvorov	64ca947722	Dockerfile: remove wal_acceptor alias for safekeeper	2021-10-12 19:05:16 +00:00
Egor Suvorov	23f4c0a742	Rename `wal_acceptor` binary to `safekeeper` (#740 ), stage 1/2 * Rename wal_acceptor binary to safekeeper * Rename wal_acceptor.pid and wal_acceptor.log to safekeeper.pid and safekeeper.log * Change some mentions of WAL acceptor to safekeeper * Dockerfile: alias wal_acceptor to safekeeper temporarily until internal scripts are updated	2021-10-12 22:03:06 +03:00
Dmitry Ivanov	7c5b99683c	Speed up builds by passing make jobserver to cargo This change brings the following improvements to our build system: * Now BUILD_TYPE also affects rust apps. * From now on, cargo will respect `-jN` passed via `make`. However, note that `rustc` may spawn multiple threads depending on compile flags. * Cargo is able to cooperate with make to better schedule parallel jobs, which leads to better build times (-20s in release mode on my machine).	2021-10-12 21:02:39 +03:00
Patrick Insinger	160c4aff61	pageserver - use write guard for checkpointing	2021-10-12 10:02:15 -07:00
Patrick Insinger	6e5ca5dc5c	pageserver - create TimelineWriter	2021-10-12 10:02:15 -07:00
Egor Suvorov	f3445949d1	Wal acceptor: report socket bind errors better when daemonizing (#738 ) Fixes #664	2021-10-12 16:51:28 +03:00
Heikki Linnakangas	95a85312f5	Simplify code to build walredo messages. No need to use BytesMut in these functions. Plain Vec is simpler. And should be marginally faster too; I saw BytesMut functions previously in 'perf' profile, consuming around 5% of the overall pageserver CPU time. That's gone with this patch, although I don't see any discernible difference in the overall performance test results.	2021-10-12 10:16:26 +03:00
Heikki Linnakangas	934fb8592f	Detect when a checkpoint is modified in a smarter way. Previously, the WAL receiver we would make a decoded copy of the current Checkpoint before each WAL record, and compare it with the Checkpoint after the record has been processed. If it has changed, the checkpoint relish is updated in the repository. That's somewhat expensive, the Checkpoint::encode() function is visible in 'perf' profile. Change that so that we set a flag whenever the Checkpoint struct is modified, so that we dont need to compare the whole struct anymore.	2021-10-12 09:09:10 +03:00
Dmitry Ivanov	bb239b4f69	[Makefile] Set default build type to debug	2021-10-11 17:08:31 +03:00
Dmitry Ivanov	1cd7900790	[Makefile] Make build type detection more precise Previously, typos like `BUILD_TYPE=rlease` would silently lead to building debug binaries. The current approach is also more future-proof, since we might add `profile`, `valgrind` as well as other build types.	2021-10-11 17:03:51 +03:00
Arseny Sher	8c61c3e54e	Minor safekeeper readme fix.	2021-10-11 16:31:44 +03:00
anastasia	d7c9dd06f4	Implement graceful shutdown at 'pageserver stop': - perform checkpoint for each tenant repository. - wait for the completion of all threads. Add new option 'immediate' to 'pageserver stop' command to terminate the pageserver immediately.	2021-10-11 13:35:01 +03:00
Heikki Linnakangas	b9119f11bf	Add perf test case for buffering GiST build. When a WAL record affects multiple pages, we currently duplicate the record for each affected page. That's a bit wasteful, but not too bad for b-tree splits and non-hot heap updates that affect two pages. But buffering GiST index build WAL-logs the whole relation in 32 page chunks, with one giant WAL record for each 32-page chunk. Currently we duplicate that giant record for each of the 32 pages, which is really wasteful. Github issue https://github.com/zenithdb/zenith/issues/720 tracks the problem. This commit adds a test case for it to demonstrate it.	2021-10-11 11:10:58 +03:00
Heikki Linnakangas	7216f22609	Use tracing crate to have more context in log messages. Whenever we start processing a request, we now enter a tracing "span" that includes context information like the tenant and timeline ID, and the operation we're performing. That context information gets attached to every log message we create within the span. That way, we don't need to include basic context information like that in every log message, and it also becomes easier to filter the logs programmatically. This removes the eplicit timeline and tenant IDs from most log messages, as you get that information from the enclosing span now. Also improve log messages in general, dialing down the level of some messages that are not very useful, and adding information to others. We now obey the RUST_LOG env variable, if it's set. The 'tracing' crate allows for different log formatters, like JSON or bunyan output. The one we use now is human-readable multi-line format, which is nice when reading the log directly, but hard for post-processing. For production, we'll probably want JSON output and some tools for working with it, but that's left as a TODO. The log format is easy to change.	2021-10-11 08:59:06 +03:00