Compare commits

..
Author SHA1 Message Date
ChuckBuildsandClaude Opus 5 cbfb0e035d fix(web): stop the installer chmod stripping exec bits on every update
git tracks five scripts as mode 644 that first_time_install.sh then chmods to
755 (start_display.sh, stop_display.sh, the two install_*_service.sh, and
one-shot-install.sh does the same to first_time_install.sh). With
core.fileMode true, the default on Linux, git reports all five as modified
from then on, in files the user never touched.

The update button stashes local changes before pulling, so it is not blocked
by this. But it never pops that stash -- stash pop and stash apply appear
nowhere in the update flow -- so the mode change is stashed away and left
there, and the files revert:

    === file modes after the update button's stash ===
      664  first_time_install.sh      <- installer had made these 755
      664  start_display.sh
      664  stop_display.sh
      664  scripts/install/install_service.sh

So every web-UI update silently strips the executable bit from the installer's
own scripts, and leaves a stash entry holding the difference. start_display.sh
and stop_display.sh stop working from the shell afterwards.

A manual `git pull --rebase` over SSH fails outright, since nothing stashes for
it: "cannot pull with rebase: You have unstaged changes". That is the likely
source of the reports, since plenty of people update that way.

Tracking the five as 755 -- what they should always have been, as the
installer chmodding them attests -- removes the spurious mode change
entirely: nothing to stash, nothing stripped, no stash entry, and manual
pulls work.

The pull also passes --autostash, for the case the code explicitly tolerates:
when the stash fails it logs a warning and pulls anyway, and that pull is what
then fails. Autostash also pops what it stashes, which the manual stash does
not.

Note that `git add -A` after `git update-index --chmod=+x` silently reverts
the index to the on-disk mode, so the modes here were set by chmodding the
files themselves.

Regression test asserts the five stay tracked executable; reverting any one
of them fails it.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW
2026-08-20 13:53:50 -04:00
9 changed files with 49 additions and 160 deletions
Regular → Executable
View File
View File
View File
+1 -54
View File
@@ -130,12 +130,7 @@ def setup_logging(
# Console handler (always add)
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(level)
# Under systemd, tag each line so the journal records the real severity
# rather than filing everything as informational. The file handler below
# keeps the plain formatter: the prefix is meaningful to journald and noise
# anywhere else.
console_handler.setFormatter(
JournalPriorityFormatter(formatter) if _under_systemd() else formatter)
console_handler.setFormatter(formatter)
root_logger.addHandler(console_handler)
# File handler (if specified)
@@ -150,54 +145,6 @@ def setup_logging(
sys.stderr.write(f"Warning: Could not set up file logging to {log_file}: {e}\n")
#: syslog priorities, which is what systemd parses from a "<N>" prefix on
#: stdout. Mapped from Python's levels.
_SYSLOG_PRIORITY = {
logging.CRITICAL: 2, # LOG_CRIT
logging.ERROR: 3, # LOG_ERR
logging.WARNING: 4, # LOG_WARNING
logging.INFO: 6, # LOG_INFO
logging.DEBUG: 7, # LOG_DEBUG
}
class JournalPriorityFormatter(logging.Formatter):
"""Wraps a formatter, prefixing each line with its syslog priority.
Under systemd everything this process writes to stdout lands in the journal
as PRIORITY=6, whatever the Python level was. Measured on a live rig: 55
ERROR lines and 13 WARNING lines in a day, every one of them recorded as
informational, so `journalctl -p err -u ledmatrix` returned nothing at all
while errors were being logged. Anyone triaging has to grep the message
text instead, which is both slower and wrong -- a search for "oom" matches
the radar logging "zoom=9".
systemd reads a leading "<N>" on each line and uses it as the priority
(sd-daemon(3)), so this needs no extra dependency. Multi-line records get
the prefix on every line, since the journal splits them and an unprefixed
continuation would fall back to the default.
"""
def __init__(self, inner: logging.Formatter):
super().__init__()
self._inner = inner
def format(self, record: logging.LogRecord) -> str:
text = self._inner.format(record)
prefix = f"<{_SYSLOG_PRIORITY.get(record.levelno, 6)}>"
return "\n".join(prefix + line for line in text.split("\n"))
def _under_systemd() -> bool:
"""True when stdout is the journal.
systemd sets JOURNAL_STREAM for services whose output it captures. Without
this check the "<N>" prefixes would show up as literal noise when the
program is run from a terminal, in the emulator, or in tests.
"""
return bool(os.environ.get("JOURNAL_STREAM"))
class PluginLoggerAdapter(logging.LoggerAdapter):
"""LoggerAdapter that stamps every record with its plugin_id.
Regular → Executable
View File
Regular → Executable
View File
+37 -3
View File
@@ -58,7 +58,7 @@ def repos(tmp_path):
def test_branch_with_upstream_uses_a_plain_pull(repos):
args, note, error = resolve_pull_command(str(repos))
assert error is None
assert args == ['git', 'pull', '--rebase']
assert args == ['git', 'pull', '--rebase', '--autostash']
assert note == ''
@@ -73,7 +73,7 @@ def test_branch_without_upstream_falls_back_to_origin_branch(repos):
args, note, error = resolve_pull_command(str(repos))
assert error is None
assert args == ['git', 'pull', '--rebase', 'origin', 'audit']
assert args == ['git', 'pull', '--rebase', '--autostash', 'origin', 'audit']
assert 'audit' in note
@@ -155,7 +155,7 @@ def test_switching_attaches_tracking_so_pull_needs_no_fallback(repos):
args, note, error = resolve_pull_command(str(repos))
assert error is None
assert args == ['git', 'pull', '--rebase']
assert args == ['git', 'pull', '--rebase', '--autostash']
assert note == ''
@@ -200,3 +200,37 @@ def test_stash_option_lets_the_switch_through_and_keeps_the_work(repos):
assert _git('branch', '--show-current', cwd=repos).stdout.strip() == 'other'
# The edit is not lost — it is on the stash.
assert 'switch to other' in _git('stash', 'list', cwd=repos).stdout
class TestInstallerDoesNotBlockTheUpdateButton:
"""first_time_install.sh chmods scripts that git tracked as 644.
With core.fileMode true -- the default on Linux -- that leaves five
permanently modified tracked files on every machine that ran the
installer, and `git pull --rebase` refuses to start:
error: cannot pull with rebase: You have unstaged changes.
Tracking them as executable makes the installer's chmod a no-op.
"""
CHMODDED = [
'first_time_install.sh',
'start_display.sh',
'stop_display.sh',
'scripts/install/install_service.sh',
'scripts/install/install_web_service.sh',
]
def test_scripts_the_installer_chmods_are_tracked_executable(self):
import subprocess
from pathlib import Path
root = Path(__file__).resolve().parent.parent
out = subprocess.run(['git', 'ls-files', '-s', *self.CHMODDED],
capture_output=True, text=True, cwd=str(root)).stdout
modes = {line.split()[3]: line.split()[0] for line in out.strip().split('\n') if line}
non_exec = sorted(f for f, m in modes.items() if m != '100755')
assert not non_exec, (
f"{non_exec} are chmodded by the installer but tracked non-executable, "
"so every install leaves the working tree dirty and the update "
"button cannot pull")
-101
View File
@@ -1,101 +0,0 @@
"""Log lines must reach the journal with their real severity.
Everything this process writes to stdout lands in the journal as PRIORITY=6,
whatever the Python level was, because journald has no other signal. Measured
on a live rig over 24 hours: 55 lines containing " - ERROR - " and 13
containing " - WARNING - ", every one of them recorded as informational. So
journalctl -p err -u ledmatrix
returned nothing while errors were being logged, and anyone triaging has to
grep the message text instead. That is slower and it is wrong: a search for
"oom" also matches the radar logging "zoom=9", which is exactly the false
positive it produced during this audit.
systemd reads a leading "<N>" on each stdout line and uses it as the priority
(sd-daemon(3)), so this needs no extra dependency -- and it must only be
applied when systemd is actually reading, or the prefixes become literal noise
in a terminal, the emulator, and test output.
"""
import logging
import os
from unittest.mock import patch
import pytest
from src.logging_config import JournalPriorityFormatter, _SYSLOG_PRIORITY, _under_systemd
class _Plain(logging.Formatter):
def format(self, record):
return record.getMessage()
def _record(level, msg="hello"):
return logging.LogRecord("t", level, "f.py", 1, msg, None, None)
@pytest.mark.parametrize("level,expected", [
(logging.CRITICAL, 2),
(logging.ERROR, 3),
(logging.WARNING, 4),
(logging.INFO, 6),
(logging.DEBUG, 7),
])
def test_each_level_maps_to_its_syslog_priority(level, expected):
out = JournalPriorityFormatter(_Plain()).format(_record(level))
assert out.startswith(f"<{expected}>"), out
assert _SYSLOG_PRIORITY[level] == expected
def test_error_and_info_are_distinguishable():
"""The whole point: journalctl -p err must be able to tell them apart."""
fmt = JournalPriorityFormatter(_Plain())
assert fmt.format(_record(logging.ERROR))[:3] != fmt.format(_record(logging.INFO))[:3]
def test_every_line_of_a_multiline_record_is_tagged():
"""The journal splits them, and an untagged continuation loses its level.
A traceback is the case that matters -- it is the most important thing in
the log and the longest.
"""
out = JournalPriorityFormatter(_Plain()).format(
_record(logging.ERROR, "Traceback:\nline one\nline two"))
lines = out.split("\n")
assert len(lines) == 3
assert all(line.startswith("<3>") for line in lines), lines
def test_the_message_survives_intact():
out = JournalPriorityFormatter(_Plain()).format(_record(logging.WARNING, "disk full"))
assert out == "<4>disk full"
def test_an_unknown_level_falls_back_to_info():
out = JournalPriorityFormatter(_Plain()).format(_record(25))
assert out.startswith("<6>")
def test_prefixing_is_off_outside_systemd():
"""Otherwise a terminal run, the emulator and pytest all show `<6>`."""
with patch.dict(os.environ, {}, clear=True):
assert not _under_systemd()
with patch.dict(os.environ, {"JOURNAL_STREAM": "8:12345"}):
assert _under_systemd()
def test_setup_uses_the_wrapper_only_under_systemd():
from src.logging_config import setup_logging
for env, expect_wrapped in (({}, False), ({"JOURNAL_STREAM": "8:1"}, True)):
with patch.dict(os.environ, env, clear=True):
setup_logging()
handlers = [h for h in logging.getLogger().handlers
if isinstance(h, logging.StreamHandler)]
assert handlers, "no stream handler installed"
wrapped = any(isinstance(h.formatter, JournalPriorityFormatter)
for h in handlers)
assert wrapped is expect_wrapped, (
f"JOURNAL_STREAM={env}: wrapped={wrapped}, expected {expect_wrapped}")
logging.getLogger().handlers.clear()
+11 -2
View File
@@ -1657,13 +1657,22 @@ def resolve_pull_command(project_dir):
backup, or following an install guide that names one. The update button
then reports a failure the user cannot act on.
``--autostash`` is passed for the same reason. Rebase refuses to start
when any tracked file is modified, and on these installs something always
is: first_time_install.sh chmods five scripts that git tracked as 644, so
every machine that ran the installer carries five permanent mode changes
and the update button reports "cannot pull with rebase: You have unstaged
changes". Those modes are corrected in this commit, but a user cannot pull
the correction while the pull is what is blocked, and any other local edit
would reproduce it anyway. Autostash reapplies the changes afterwards.
Returns ``(args, note, error)``. When ``origin/<branch>`` exists the pull
is made explicit against it, so the update proceeds and the branch is
given tracking information afterwards.
"""
upstream = _git_upstream(project_dir)
if upstream:
return ['git', 'pull', '--rebase'], '', None
return ['git', 'pull', '--rebase', '--autostash'], '', None
branch = _git_current_branch(project_dir)
if not branch:
@@ -1673,7 +1682,7 @@ def resolve_pull_command(project_dir):
)
if _git_remote_branch_exists(project_dir, branch):
return (
['git', 'pull', '--rebase', 'origin', branch],
['git', 'pull', '--rebase', '--autostash', 'origin', branch],
f"Branch '{branch}' had no upstream; pulled from origin/{branch} and set it as the upstream.",
None,
)