8000 fix(install): stop waiting when Lens can't start, and show what it logged in the web installer by adeelahmad · Pull Request #359 · adeelahmad/lense · GitHub
[go: up one dir, main page]

Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 25 additions & 1 deletion .github/workflows/install.yml
Original file line number Diff line number Diff line change
Expand Up @@ -256,10 +256,13 @@ jobs:

- name: Running it again updates in place and keeps the secrets
run: |
# while it waited, it showed the steps the sandbox logged
grep -q ' Building Lens' install.log || { echo "install.sh didn't show the sandbox's progress"; exit 1; }
before="$(grep -E '^(ACCESS_SECRET_KEY|ARCHIVE_SECRET_KEY|AUTH_SECRET|SURREAL_PASS|LENS_SETUP_CODE)=' "$LENS_DIR/.env" | sha256sum)"
LENS_BACKEND='' sh < install.sh
LENS_BACKEND='' sh < install.sh | tee again.log
after="$(grep -E '^(ACCESS_SECRET_KEY|ARCHIVE_SECRET_KEY|AUTH_SECRET|SURREAL_PASS|LENS_SETUP_CODE)=' "$LENS_DIR/.env" | sha256sum)"
test "$before" = "$after" || { echo "the second run changed the secrets"; exit 1; }
grep -q "Stopping the Lens that's running" again.log || { echo "the second run didn't stop the running sandbox first"; exit 1; }
curl -fsS -o /dev/null "$(cat setup-url)"

- name: A lean install stays lean when the line runs again without LENS_TARGET
Expand All @@ -283,6 +286,27 @@ jobs:
msb exec lens -- chromium --version
curl -fsS -o /dev/null "$(cat setup-url)"

- name: A part of Lens that keeps stopping ends the wait at once, with what Lens logged
run: |
# keys that don't open the database: the API stops at each start, as after a reinstall with new keys
cp "$LENS_DIR/.env" env.bak
sed -i 's/^SURREAL_PASS=.*/SURREAL_PASS=not-the-one/' "$LENS_DIR/.env"
if LENS_BACKEND='' sh < install.sh >loop.log 2>&1; then cat loop.log; echo "it didn't stop waiting"; exit 1; fi
cat loop.log
grep -q "keeps stopping in its microsandbox" loop.log
grep -q 'The last lines Lens logged:' loop.log
grep -q 'cannot open SurrealDB' loop.log # the reason, in Lens's own words
cp env.bak "$LENS_DIR/.env"
LENS_BACKEND='' sh < install.sh >/dev/null
curl -fsS -o /dev/null "$(cat setup-url)"

- name: A start that takes too long stops waiting and says why
run: |
if LENS_BACKEND='' LENS_WAIT=8 sh < install.sh >slow.log 2>&1; then cat slow.log; echo "it didn't stop waiting"; exit 1; fi
cat slow.log
grep -q "Lens didn't answer on port [0-9]* within 8 seconds" slow.log
grep -q 'The last lines Lens logged:' slow.log

- name: Installing again after the install folder is deleted starts Lens on a volume of its own
run: |
export PATH="$HOME/.local/bin:$HOME/.microsandbox/bin:$PATH"
Expand Down
6 changes: 6 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,12 @@ The backend (`fastapi_backend`) and the frontend (`nextjs-frontend`) are version

## Unreleased

- **The installer stops waiting when Lens can't start, and shows why.** A microsandbox install that couldn't start Lens
waited 30 minutes at "Waiting for the web app..." and then named only a command to run. It now lists the sandbox's own
steps as they happen, and stops as soon as a step fails, the sandbox stops or a part of Lens keeps stopping, with the
last lines Lens logged; the web installer shows them under the reason. Running the line again stops the running
sandbox first and waits for its port ([microsandbox](docs/microsandbox.md#day-to-day)).

- **A microsandbox install after the install folder was deleted comes up.** The data volume (`lens-data`) outlives
`~/lens`, but its database opens only with the keys in that folder's `.env`. A first install made new keys, mounted
the earlier volume anyway, and waited 30 minutes for a web app whose API couldn't open the database. It now leaves
Expand Down
8 changes: 5 additions & 3 deletions docs/get-started.md
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,8 @@ code already filled in. On a server without a desktop, Lens is reachable from th
server's address. Run the same line again to update: the secrets, the database and the archive are kept. Settings go
before `sh`: `LENS_DIR`, `LENS_PORT`, `LENS_PUBLIC` (`1`: from the network, `0`: this machine only), `LENS_TARGET`
(`lean` for the smaller image, kept when the line runs again) and `LENS_REF` (a branch or tag) change the defaults;
the top of `install.sh` lists them.
the top of `install.sh` lists them. If Lens doesn't answer in time (`LENS_WAIT`, in seconds: 10 minutes with Docker,
30 in a microsandbox), the installer stops waiting and shows the last lines Lens logged and why.

Where it can (Linux with KVM, or a Mac with Apple silicon), a first install asks whether to run Lens in Docker (the
default) or in a [microsandbox](microsandbox.md) microVM, which needs no Docker; `LENS_BACKEND=microsandbox` chooses
Expand Down Expand Up @@ -43,8 +44,9 @@ above opens an installer in your browser instead of asking anything in the termi
4. **Review**, then **Install**: **More options** under the review holds what's optional, each with its default: the
first namespace, search by meaning (an embeddings server), the typesafe.ai decision model's key, cloud
transcription and its key, email (SMTP), remote access through a Cloudflare tunnel, anytopdf, and telemetry.
**Install** runs `install.sh` with those answers and shows its progress (and the full output under **Details**). If
something fails, it says what, and **Try again** runs it again (what's done stays done).
**Install** runs `install.sh` with those answers and shows its progress, in a microsandbox step by step as the
sandbox installs and builds (and the full output under **Details**). If something fails, it says what, with the
last lines Lens logged when Lens itself didn't start, and **Try again** runs it again (what's done stays done).
5. **Open Lens** goes to the setup page with the setup code filled in, where you create the admin account with a
passkey.

Expand Down
7 changes: 6 additions & 1 deletion docs/microsandbox.md
Original file line number Diff line number Diff line change
Expand Up @@ -100,7 +100,12 @@ msb stop lens # stop it; ~/lens/.lens-sandbox starts it again
msb exec lens -- sh # a shell inside it
```

To update, run the install line again.
To update, run the install line again. It stops the running sandbox first (giving the database up to a minute to
close cleanly) and waits for its port to be free, then starts Lens in a new one. While it waits for the web app, it
shows the steps the sandbox logs (installing packages, building, starting the database). If the sandbox stops, a step
fails, a part of Lens keeps stopping (run.sh starts it again three times), or the web app doesn't answer within 30
minutes (`LENS_WAIT`, in seconds), it stops waiting and shows the last lines the sandbox logged and why, for example a
port that another program holds. The web installer shows those lines under the reason.

## Not yet

Expand Down
97 changes: 89 additions & 8 deletions 97 install.sh
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,8 @@
# can serve https:// with certificates it gets itself, set up in Settings › HTTPS (docs/https.md);
# 0: don't (default: as the last run left it, else 0)
# LENS_UPGRADE_AGENT 0: don't set up the agent that lets the web app install new releases (docs/updates.md)
# LENS_WAIT how long to wait for the web app to answer, in seconds (default: 1800 in a microsandbox, whose
# first start builds everything, else 600)
# LENS_WIZARD 1: answer everything in the web installer, in the browser (the default for a first install at a
# terminal, where Python 3 is there); 0: here in the terminal
set -eu
Expand Down Expand Up @@ -150,6 +152,7 @@ case "$BACKEND" in
microsandbox) msb_ok || fail "microsandbox needs KVM on 64-bit Linux or a Mac with Apple silicon. Use LENS_BACKEND=docker." ;;
*) fail "LENS_BACKEND is docker or microsandbox, not $BACKEND." ;;
esac
case "${LENS_WAIT:-0}" in *[!0-9]*) fail "LENS_WAIT is a number of seconds, not ${LENS_WAIT:-}." ;; esac

# --- What's missing: listed, and installed once you say yes ---------------------------------------------------------
# Asked only at a terminal; piped in by a script or CI (no terminal, or LENS_YES=1) it goes ahead, as before.
Expand Down Expand Up @@ -465,10 +468,27 @@ if [ "$BACKEND" = microsandbox ]; then
echo
} >.lens-sandbox
chmod +x .lens-sandbox
# Run again: the running sandbox stops first, so its database closes cleanly (a replace kills it after 10 seconds)
# and its port is free for the new one
if msb ls --running -q </dev/null 2>/dev/null | grep -qx lens; then
say "Stopping the Lens that's running..."
msb stop -q -t 60 lens </dev/null >/dev/null 2>&1 || msb stop -q -f lens </dev/null >/dev/null 2>&1 || true
fi
i=0
until free "$PORT"; do
i=$((i + 1))
if [ $i -gt 15 ]; then
who="$(lsof -nP -iTCP:"$PORT" -sTCP:LISTEN 2>/dev/null | awk 'NR == 2 {print $1 " (process " $2 ")"}' || true)"
fail "Port $PORT is in use${who:+ by $who}, so Lens can't start on it. Stop that, or run this again with LENS_PORT set to a free port."
fi
sleep 2
done
since="$(date -u +%Y-%m-%dT%H:%M:%SZ)" # what the new sandbox logs, for the progress below
./.lens-sandbox >/dev/null
LOGS="msb logs -f lens"
TAIL="msb logs lens --tail 40"
STOP="msb stop lens"
WAIT=900 # 30 minutes: the first start installs the system packages and builds everything
WAIT=1800 # 30 minutes: the first start installs the system packages and builds everything
# back after a restart of the machine, as Docker's restart policy does
if [ "$os" = Linux ] && have systemctl && [ -d /run/systemd/system ]; then
unit=/etc/systemd/system/lens-microsandbox.service
Expand Down Expand Up @@ -496,8 +516,9 @@ else
# shellcheck disable=SC2086
$COMPOSE $files up -d --build
LOGS="$COMPOSE $files logs"
TAIL="$COMPOSE $files logs --tail 40"
STOP="$COMPOSE $files down"
WAIT=300
WAIT=600
fi

# --- The upgrade agent: runs packaging/host/lens-upgrade.sh when the web app asks for a new release ---------------
Expand Down Expand Up @@ -546,12 +567,72 @@ PLIST
fi

say "Waiting for the web app..."
i=0
# the page and the API behind it: the setup page needs both, and the API starts a few seconds after the page
until curl -fsS -o /dev/null "http://127.0.0.1:$PORT/login" 2>/dev/null &&
curl -fsS -o /dev/null "http://127.0.0.1:$PORT/api/v1/auth/status" 2>/dev/null; do
i=$((i + 1))
[ $i -gt $WAIT ] && fail "Lens didn't answer within $((WAIT * 2 / 60)) minutes. See what happened: cd $DIR && $LOGS"
# the page and the API behind it: the setup page needs both, and the API starts a few seconds after the page. Each
# try gives up after a few seconds: a port that takes the connection but never answers mustn't hold this forever.
up() {
curl -fsS -o /dev/null --max-time 5 "http://127.0.0.1:$PORT/login" 2>/dev/null &&
curl -fsS -o /dev/null --max-time 5 "http://127.0.0.1:$PORT/api/v1/auth/status" 2>/dev/null
}
# why it stopped waiting, after the last lines Lens logged
stuck() {
echo "The last lines Lens logged:"
$TAIL 2>&1 </dev/null | tail -n 40 || true
fail "$1 See everything: cd $DIR && $LOGS"
}
# the steps the sandbox reports (run.sh's "[lens] ..." lines), each shown once; it stops waiting when one failed or
# the sandbox stopped
seen=0 down=0 step=""
sandbox_progress() {
lines="$(msb logs lens --since "$since" --grep '\[lens\]' </dev/null 2>/dev/null | grep '^\[lens\] ' || true)"
n="$(printf '%s\n' "$lines" | grep -c . || true)"
if [ "$n" -gt "$seen" ]; then
# as steps of their own (the web installer lists them)
printf '%s\n' "$lines" | sed -n "$((seen + 1)),\$p" | sed 's/^\[lens\] //' | while IFS= read -r line; do say " $line"; done
seen=$n
shown=$now
step="$(printf '%s\n' "$lines" | tail -n 1 | sed 's/^\[lens\] //; s/[.][.][.]$//')"
fi
failed="$(printf '%s\n' "$lines" | sed -n 's/^\[lens\] \(Failed.*\)/\1/p' | tail -n 1)"
[ -z "$failed" ] || stuck "Lens couldn't start in its microsandbox. $failed."
# a part that stops again and again (run.sh starts it again each time) won't start by waiting longer
looping="$(printf '%s\n' "$lines" | sed -n 's/^\[lens\] \([a-z]*\) stopped; starting it again.*/\1/p' | sort | uniq -c |
awk '$1 >= 3 {print $2; exit}')"
case "$looping" in
'') ;;
surrealdb) stuck "Lens's database keeps stopping in its microsandbox." ;;
api) stuck "Lens's API keeps stopping in its microsandbox." ;;
web) stuck "Lens's web app keeps stopping in its microsandbox." ;;
worker) stuck "Lens's job worker keeps stopping in its microsandbox." ;;
*) stuck "Lens's $looping keeps stopping in its microsandbox." ;;
esac
if running="$(msb ls --running -q </dev/null 2>/dev/null)"; then # twice in a row, as it may be booting
if printf '%s\n' "$running" | grep -qx lens; then down=0; else down=$((down + 1)); fi
fi
[ $down -lt 2 ] || stuck "Lens's microsandbox stopped${step:+ at: $step}."
}
WAIT="${LENS_WAIT:-$WAIT}"
start=$(date +%s)
shown=$start checked=0
until up; do
now=$(date +%s)
if [ "$BACKEND" = microsandbox ] && [ $((now - checked)) -ge 10 ]; then
checked=$now
sandbox_progress
fi
if [ $((now - start)) -ge "$WAIT" ]; then
if [ "$WAIT" -lt 120 ]; then within="$WAIT seconds"; else within="$((WAIT / 60)) minutes"; fi
why="Lens didn't answer on port $PORT within $within${step:+ (its last step: $step)}."
# up in the sandbox, but not on this machine's port: the port is the problem, not Lens
if [ "$BACKEND" = microsandbox ] &&
msb exec lens -- curl -fsS -o /dev/null --max-time 5 http://127.0.0.1:3000/login </dev/null >/dev/null 2>&1; then
why="Lens is running in its microsandbox, but port $PORT on this machine doesn't reach it. Is another program using the port?"
fi
stuck "$why"
fi
if [ $((now - shown)) -ge 60 ]; then # never silent for long
echo " still starting ($(((now - start) / 60)) min so far)..."
shown=$now
fi
sleep 2
done

Expand Down
20 changes: 20 additions & 0 deletions installer/lens_installer.py
Original file line number Diff line number Diff line change
Expand Up @@ -381,13 +381,29 @@ def step_of(line):
return ANSI.sub("", line).strip() if line.startswith("\x1b[1m") else None


# install.sh prints this, then the last lines Lens logged, when it stops waiting for Lens; then why (the last line)
TAIL_HEAD = "The last lines Lens logged:"


def log_tail(lines, error=None):
"""The last lines Lens logged, as install.sh showed them when it stopped waiting, without its reason after them."""
for i in range(len(lines) - 1, -1, -1):
if lines[i].strip() == TAIL_HEAD:
tail = lines[i + 1 :]
while tail and (not tail[-1].strip() or tail[-1] == error):
tail.pop()
return tail
return []


class Installer:
def __init__(self, folder, repo, ref, script=None, token=None):
self.dir, self.repo, self.ref, self.script = folder, repo, ref, script
self.token = token or secrets.token_urlsafe(18)
self.lock = threading.Lock()
self.lines, self.steps = [], []
self.state, self.url, self.error, self.code = "idle", None, None, None
self.tail = []
self.password = None
self.proc = None
self.tmp = tempfile.mkdtemp(prefix="lens-installer-")
Expand Down Expand Up @@ -490,6 +506,7 @@ def start(self, answers):
self.dir = env_vars["LENS_DIR"]
with self.lock:
self.lines, self.steps, self.state, self.url, self.error, self.code = [], [], "running", None, None, None
self.tail = []
threading.Thread(target=self._run, args=(env_vars,), daemon=True, name="install").start()

def _run(self, env_vars):
Expand Down Expand Up @@ -533,6 +550,8 @@ def _run(self, env_vars):
self._finish("done")
else:
last = next((ln for ln in reversed(self.lines) if ln.strip()), "")
with self.lock:
self.tail = log_tail(self.lines, last)
self._finish("failed", last or f"install.sh stopped (exit {code})")

def _finish(self, state, error=None):
Expand All @@ -551,6 +570,7 @@ def progress(self, since=0):
"next": offset + len(self.lines),
"url": self.url,
"error": self.error,
"tail": list(self.tail),
}


Expand Down
3 changes: 3 additions & 0 deletions installer/page.html
Original file line number Diff line number Diff line change
Expand Up @@ -503,6 +503,9 @@ <h1>Install Lens</h1>
: "You can leave this page open and come back. Closing it doesn't stop the install."),
el("ul", { class: "progress" }, steps.map((t, i) => el("li", { class: i === steps.length - 1 && !done ? (failed ? "fail" : "now") : "" }, t))));
if (failed) box.append(el("div", { class: "msg err" }, P.error || "install.sh stopped"));
// what Lens itself logged last, when install.sh stopped waiting for it: usually the reason in Lens's own words
if (failed && P.tail && P.tail.length) box.append(el("p", { class: "muted" }, "What Lens logged last:"),
el("pre", { class: "log" }, P.tail.join("\n")));
const pre = el("pre", { class: "log" }, S.log.join("\n") || "…");
box.append(el("details", { open: failed }, el("summary", {}, "Details"), pre));
if (done) box.append(el("div", { class: "nav" }, el("button", { class: "primary big", onclick: async () => {
Expand Down
25 changes: 25 additions & 0 deletions installer/test_lens_installer.py
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,13 @@
} >"$LENS_DIR/.env"
chmod 600 "$LENS_DIR/.env"
[ "${FAIL:-0}" = 1 ] && { echo "Docker isn't running. Start it, then run this again." >&2; exit 1; }
if [ "${FAIL:-0}" = 2 ]; then
echo "The last lines Lens logged:"
echo "[lens] api stopped; starting it again in 5 seconds"
echo "cannot open SurrealDB: authentication failed"
echo "Lens's API keeps stopping in its microsandbox. See everything: msb logs -f lens" >&2
exit 1
fi
printf '\033[1m%s\033[0m\n' "Lens is running: http://localhost:$LENS_PORT/setup?code=abc123"
"""

Expand Down Expand Up @@ -135,6 +142,11 @@ def test_plan_lists_docker_when_it_is_missing(self):
self.assertEqual(items, [{"what": "Docker Engine with Compose (from get.docker.com)", "admin": True}])
self.assertEqual(li.plan("docker", {**docker, "installed": True, "running": True, "compose": True}, "root"), [])

def test_log_tail_is_what_lens_logged_without_the_reason(self):
lines = ["Waiting for the web app...", li.TAIL_HEAD, "[lens] Building Lens...", "error: boom", "", "Lens couldn't start."]
self.assertEqual(li.log_tail(lines, "Lens couldn't start."), ["[lens] Building Lens...", "error: boom"])
self.assertEqual(li.log_tail(["Docker isn't running."], "Docker isn't running."), [])

def test_lens_app_offers_microsandbox_first_where_it_runs(self):
inst = li.Installer("/tmp/lens-x", "adeelahmad/lense", "main", token="t")
for wanted, can, expect in (("microsandbox", True, "microsandbox"), ("microsandbox", False, "docker"), ("", True, "docker")):
Expand Down Expand Up @@ -214,6 +226,19 @@ def test_a_failed_install_says_why(self):
self.assertEqual(progress["state"], "failed")
self.assertIn("Docker isn't running", progress["error"])

def test_a_failed_start_shows_what_lens_logged(self):
os.environ["FAIL"] = "2"
try:
self.assertEqual(self.call("POST", "/api/install", {"dir": self.dir})[0], 202)
progress = self.wait()
finally:
del os.environ["FAIL"]
self.assertEqual(progress["state"], "failed")
self.assertIn("API keeps stopping", progress["error"])
self.assertEqual(
progress["tail"], ["[lens] api stopped; starting it again in 5 seconds", "cannot open SurrealDB: authentication failed"]
)

def test_bad_answers_are_refused(self):
status, _, data = self.call("POST", "/api/install", {"backend": "podman"})
self.assertEqual(status, 400)
Expand Down
Loading
Loading
0