Release 0.8.0: Windows installer, twelve fixes from a real Server 2019 install, operator docs
This commit is contained in:
422
deploy/windows/shopdb-diagnose.py
Normal file
422
deploy/windows/shopdb-diagnose.py
Normal file
@@ -0,0 +1,422 @@
|
||||
"""Collect everything needed to diagnose a ShopDB-Flask stage 5 failure.
|
||||
|
||||
Stage 5 is the smoke test: the installer asks IIS for the site and expects 200.
|
||||
When it does not get one, the cause is always in one of four places, and this
|
||||
script reads all four in one pass so the answer arrives in a single round trip:
|
||||
|
||||
1. What IIS actually answers, and with which status code and error page.
|
||||
2. Whether the config sections httpPlatformHandler needs are unlocked.
|
||||
3. Whether the app-pool identity can read the app and run its venv.
|
||||
4. Whether the app itself imports and starts.
|
||||
|
||||
Run it ON THE SERVER, as Administrator:
|
||||
|
||||
C:\\Python314\\python.exe shopdb-diagnose.py
|
||||
|
||||
It writes shopdb-diagnose-<timestamp>.txt next to itself and prints the path.
|
||||
Send that file back.
|
||||
|
||||
SECRETS: the report never contains them. Values from .env (database password,
|
||||
SECRET_KEY, JWT_SECRET_KEY) are read first, then scrubbed out of every section
|
||||
of the report before it is written, including command output and tracebacks
|
||||
that might quote them.
|
||||
|
||||
Standard library only, so it runs on the bundled runtime or any system Python.
|
||||
"""
|
||||
|
||||
import os
|
||||
import re
|
||||
import socket
|
||||
import subprocess
|
||||
import sys
|
||||
import time
|
||||
from datetime import datetime
|
||||
|
||||
APP_ROOT = os.environ.get('SHOPDB_APPROOT', r'C:\shopdb-flask')
|
||||
ALIAS = 'shopdb'
|
||||
TIMEOUT = 25
|
||||
|
||||
# Filled from .env, then scrubbed from the whole report.
|
||||
SECRETS = []
|
||||
|
||||
WINDIR = os.environ.get('WINDIR', r'C:\Windows')
|
||||
# Sysnative gives a 32-bit process the real 64-bit System32. Harmless on 64-bit.
|
||||
APPCMD_CANDIDATES = [
|
||||
os.path.join(WINDIR, 'Sysnative', 'inetsrv', 'appcmd.exe'),
|
||||
os.path.join(WINDIR, 'System32', 'inetsrv', 'appcmd.exe'),
|
||||
]
|
||||
|
||||
|
||||
def find_appcmd():
|
||||
for path in APPCMD_CANDIDATES:
|
||||
if os.path.isfile(path):
|
||||
return path
|
||||
return None
|
||||
|
||||
|
||||
class Report(object):
|
||||
def __init__(self):
|
||||
self.chunks = []
|
||||
|
||||
def head(self, title):
|
||||
self.chunks.append('\n' + '=' * 72 + '\n' + title + '\n' + '=' * 72)
|
||||
|
||||
def line(self, text=''):
|
||||
self.chunks.append(str(text))
|
||||
|
||||
def block(self, title, body):
|
||||
self.chunks.append('\n--- %s ---' % title)
|
||||
if body is None or str(body).strip() == '':
|
||||
self.chunks.append('(no output)')
|
||||
else:
|
||||
self.chunks.append(str(body).rstrip())
|
||||
|
||||
def text(self):
|
||||
return '\n'.join(self.chunks) + '\n'
|
||||
|
||||
|
||||
def run(cmd, timeout=60):
|
||||
"""Run a command, return combined output. Never raises."""
|
||||
try:
|
||||
proc = subprocess.Popen(cmd, stdout=subprocess.PIPE,
|
||||
stderr=subprocess.STDOUT, shell=False)
|
||||
out, _ = proc.communicate(timeout=timeout)
|
||||
text = out.decode('utf-8', 'replace') if out else ''
|
||||
return '[exit %s]\n%s' % (proc.returncode, text)
|
||||
except subprocess.TimeoutExpired:
|
||||
try:
|
||||
proc.kill()
|
||||
except Exception:
|
||||
pass
|
||||
return '[TIMED OUT after %ss]' % timeout
|
||||
except Exception as exc:
|
||||
return '[could not run: %s]' % exc
|
||||
|
||||
|
||||
def powershell(script, timeout=90):
|
||||
exe = os.path.join(WINDIR, 'Sysnative', 'WindowsPowerShell', 'v1.0', 'powershell.exe')
|
||||
if not os.path.isfile(exe):
|
||||
exe = 'powershell.exe'
|
||||
return run([exe, '-NoProfile', '-ExecutionPolicy', 'Bypass', '-Command', script],
|
||||
timeout=timeout)
|
||||
|
||||
|
||||
def load_secrets():
|
||||
"""Read .env so its secret VALUES can be scrubbed from the report."""
|
||||
env_path = os.path.join(APP_ROOT, '.env')
|
||||
found = {}
|
||||
if not os.path.isfile(env_path):
|
||||
return found, None
|
||||
try:
|
||||
with open(env_path, 'r', encoding='utf-8', errors='replace') as handle:
|
||||
raw = handle.read()
|
||||
except Exception as exc:
|
||||
return found, '[could not read .env: %s]' % exc
|
||||
|
||||
for line in raw.splitlines():
|
||||
line = line.strip()
|
||||
if not line or line.startswith('#') or '=' not in line:
|
||||
continue
|
||||
key, value = line.split('=', 1)
|
||||
key, value = key.strip(), value.strip().strip('"').strip("'")
|
||||
found[key] = value
|
||||
if not value:
|
||||
continue
|
||||
upper = key.upper()
|
||||
if 'SECRET' in upper or 'PASSWORD' in upper or 'TOKEN' in upper or 'KEY' in upper:
|
||||
SECRETS.append(value)
|
||||
if upper == 'DATABASE_URL':
|
||||
# mysql+pymysql://user:PASSWORD@host/db -- the password only.
|
||||
match = re.match(r'^[^:]+://([^:@/]+):([^@]+)@', value)
|
||||
if match:
|
||||
SECRETS.append(match.group(2))
|
||||
return found, raw
|
||||
|
||||
|
||||
def scrub(text):
|
||||
"""Remove every known secret value from the report."""
|
||||
for secret in SECRETS:
|
||||
if secret and len(secret) >= 4:
|
||||
text = text.replace(secret, '<REDACTED>')
|
||||
# Catch a password inside any URL that did not come from .env.
|
||||
text = re.sub(r'(://[^:@/\s]+:)[^@\s]+(@)', r'\1<REDACTED>\2', text)
|
||||
return text
|
||||
|
||||
|
||||
def http_probe(url):
|
||||
"""Fetch a URL, returning status, headers and body even for an error page."""
|
||||
import urllib.error
|
||||
import urllib.request
|
||||
|
||||
started = time.time()
|
||||
try:
|
||||
request = urllib.request.Request(url, headers={'User-Agent': 'shopdb-diagnose'})
|
||||
with urllib.request.urlopen(request, timeout=TIMEOUT) as response:
|
||||
body = response.read(4000).decode('utf-8', 'replace')
|
||||
return {'status': response.status, 'reason': response.reason,
|
||||
'headers': dict(response.headers), 'body': body,
|
||||
'seconds': time.time() - started}
|
||||
except urllib.error.HTTPError as exc:
|
||||
body = ''
|
||||
try:
|
||||
body = exc.read(4000).decode('utf-8', 'replace')
|
||||
except Exception:
|
||||
pass
|
||||
return {'status': exc.code, 'reason': exc.reason,
|
||||
'headers': dict(exc.headers or {}), 'body': body,
|
||||
'seconds': time.time() - started}
|
||||
except Exception as exc:
|
||||
return {'status': None, 'reason': '%s: %s' % (type(exc).__name__, exc),
|
||||
'headers': {}, 'body': '', 'seconds': time.time() - started}
|
||||
|
||||
|
||||
def summarise_iis_error(body):
|
||||
"""Pull the meaningful bits out of an IIS error page."""
|
||||
if not body:
|
||||
return None
|
||||
import html
|
||||
|
||||
# style and script blocks first: their contents survive plain tag stripping
|
||||
# and drag CSS into the summary.
|
||||
flat = re.sub(r'(?is)<(script|style)[^>]*>.*?</\1>', ' ', body)
|
||||
flat = re.sub(r'(?s)<!--.*?-->', ' ', flat)
|
||||
flat = re.sub(r'(?s)<[^>]*>', ' ', flat)
|
||||
# Any unterminated tag left by the 4000-byte body truncation.
|
||||
flat = re.sub(r'(?s)<[^>]*$', ' ', flat)
|
||||
flat = html.unescape(flat)
|
||||
flat = re.sub(r'\s+', ' ', flat).strip()
|
||||
|
||||
hints = []
|
||||
for pattern in (r'\b\d{3}\.\d+\b', r'0x[0-9a-fA-F]{8}',
|
||||
r'Error Code[^.]{0,80}', r'Config (?:Error|File)[^.]{0,120}',
|
||||
r'Requested URL[^.]{0,120}', r'Physical Path[^.]{0,120}'):
|
||||
for match in re.findall(pattern, flat):
|
||||
cleaned = re.sub(r'\s+', ' ', match).strip(' :-')
|
||||
if cleaned and cleaned not in hints:
|
||||
hints.append(cleaned)
|
||||
return {'flat': flat[:1200], 'hints': hints}
|
||||
|
||||
|
||||
def main():
|
||||
report = Report()
|
||||
stamp = datetime.now().strftime('%Y%m%d-%H%M%S')
|
||||
|
||||
env_values, env_raw = load_secrets()
|
||||
|
||||
report.line('ShopDB-Flask stage 5 diagnostic')
|
||||
report.line('generated %s' % datetime.now().strftime('%Y-%m-%d %H:%M:%S'))
|
||||
report.line('host %s' % socket.gethostname())
|
||||
report.line('app root %s' % APP_ROOT)
|
||||
report.line('python %s' % sys.version.replace('\n', ' '))
|
||||
report.line('process is %d-bit' % (64 if sys.maxsize > 2 ** 32 else 32))
|
||||
|
||||
# ---------------------------------------------------------------- 1. HTTP
|
||||
report.head('1. WHAT IIS ANSWERS')
|
||||
report.line('This is the single most important section. The status code names')
|
||||
report.line('the fault: 500.19 = config locked, 502.3/503 = the app did not')
|
||||
report.line('start, 404 = application or handler mapping missing.')
|
||||
|
||||
hostname = socket.gethostname()
|
||||
targets = [
|
||||
'http://localhost/%s/' % ALIAS,
|
||||
'http://127.0.0.1/%s/' % ALIAS,
|
||||
'http://[::1]/%s/' % ALIAS,
|
||||
'http://%s/%s/' % (hostname, ALIAS),
|
||||
'http://localhost/',
|
||||
]
|
||||
for url in targets:
|
||||
result = http_probe(url)
|
||||
report.line('\n%s' % url)
|
||||
report.line(' status : %s %s' % (result['status'], result['reason']))
|
||||
report.line(' time : %.1fs' % result['seconds'])
|
||||
server = result['headers'].get('Server')
|
||||
if server:
|
||||
report.line(' server : %s' % server)
|
||||
summary = summarise_iis_error(result['body'])
|
||||
if summary and summary['hints']:
|
||||
report.line(' hints : %s' % ' | '.join(summary['hints'][:8]))
|
||||
if summary and summary['flat']:
|
||||
report.line(' body : %s' % summary['flat'][:600])
|
||||
|
||||
# localhost resolving to ::1 first has bitten this install before.
|
||||
report.block('name resolution for localhost', run(
|
||||
['nslookup', 'localhost'], timeout=20))
|
||||
|
||||
# ------------------------------------------------------------- 2. IIS state
|
||||
report.head('2. IIS STATE')
|
||||
appcmd = find_appcmd()
|
||||
if not appcmd:
|
||||
report.line('appcmd.exe NOT FOUND - is the IIS role installed?')
|
||||
else:
|
||||
report.line('appcmd: %s' % appcmd)
|
||||
report.block('sites', run([appcmd, 'list', 'sites']))
|
||||
report.block('applications', run([appcmd, 'list', 'apps']))
|
||||
report.block('app pools', run([appcmd, 'list', 'apppools']))
|
||||
report.block('worker processes (empty means nothing is running)',
|
||||
run([appcmd, 'list', 'wp']))
|
||||
report.block('modules: httpPlatformHandler present?',
|
||||
run([appcmd, 'list', 'modules']))
|
||||
# overrideMode tells us whether the unlock actually took effect.
|
||||
#
|
||||
# allowedServerVariables is in this list because it caused a 500.52 that
|
||||
# the first two sections could not explain: it is Deny by default, so an
|
||||
# <allowedServerVariables> block in the app's web.config is rejected
|
||||
# before httpPlatformHandler runs. Checking only the sections we unlock
|
||||
# would have missed the one we do not.
|
||||
for section in ('system.webServer/handlers',
|
||||
'system.webServer/httpPlatform',
|
||||
'system.webServer/rewrite/allowedServerVariables',
|
||||
'system.webServer/rewrite/rules'):
|
||||
report.block('lock state of %s' % section,
|
||||
run([appcmd, 'list', 'config', '/section:%s' % section,
|
||||
'/text:*']))
|
||||
|
||||
report.block('W3SVC / WAS services', powershell(
|
||||
"Get-Service W3SVC,WAS | Format-Table Name,Status,StartType -AutoSize | Out-String"))
|
||||
report.block('listeners on port 80', powershell(
|
||||
"Get-NetTCPConnection -LocalPort 80 -State Listen -EA SilentlyContinue | "
|
||||
"Format-Table LocalAddress,LocalPort,OwningProcess -AutoSize | Out-String"))
|
||||
report.block('app pool detail', powershell(
|
||||
"Import-Module WebAdministration -EA SilentlyContinue; "
|
||||
"Get-Item IIS:\\AppPools\\shopdbflask -EA SilentlyContinue | "
|
||||
"Select-Object name,state,managedRuntimeVersion,enable32BitAppOnWin64,"
|
||||
"@{n='identity';e={$_.processModel.identityType}} | Format-List | Out-String"))
|
||||
|
||||
# --------------------------------------------------------- 3. app + config
|
||||
report.head('3. APPLICATION AND CONFIG')
|
||||
|
||||
web_config = os.path.join(APP_ROOT, 'web.config')
|
||||
if os.path.isfile(web_config):
|
||||
try:
|
||||
with open(web_config, 'r', encoding='utf-8', errors='replace') as handle:
|
||||
report.block('web.config', handle.read())
|
||||
except Exception as exc:
|
||||
report.block('web.config', '[could not read: %s]' % exc)
|
||||
else:
|
||||
report.block('web.config', 'MISSING at %s' % web_config)
|
||||
|
||||
if env_raw is None:
|
||||
report.block('.env', 'MISSING at %s' % os.path.join(APP_ROOT, '.env'))
|
||||
else:
|
||||
# Keys and non-secret values only. Secret values are scrubbed anyway.
|
||||
lines = []
|
||||
for key in sorted(env_values):
|
||||
upper = key.upper()
|
||||
secretish = ('SECRET' in upper or 'PASSWORD' in upper
|
||||
or 'TOKEN' in upper or 'KEY' in upper
|
||||
or upper == 'DATABASE_URL')
|
||||
if secretish:
|
||||
lines.append('%s = <set, %d chars>' % (key, len(env_values[key])))
|
||||
else:
|
||||
lines.append('%s = %s' % (key, env_values[key]))
|
||||
report.block('.env (secret values withheld)', '\n'.join(lines))
|
||||
|
||||
venv_python = os.path.join(APP_ROOT, 'venv', 'Scripts', 'python.exe')
|
||||
report.line('\nvenv python exists: %s' % os.path.isfile(venv_python))
|
||||
if os.path.isfile(venv_python):
|
||||
# The exact failure stage 3 used to hit. Proves the app imports.
|
||||
report.block('venv: import shopdb', run(
|
||||
[venv_python, '-c',
|
||||
'import shopdb; print("import OK"); '
|
||||
'app = shopdb.create_app(); print("create_app OK")'], timeout=120))
|
||||
report.block('venv: waitress present', run(
|
||||
[venv_python, '-c', 'import waitress; print(waitress.__version__)'],
|
||||
timeout=60))
|
||||
|
||||
# What httpPlatformHandler is told to launch, and whether it exists.
|
||||
if os.path.isfile(web_config):
|
||||
try:
|
||||
with open(web_config, 'r', encoding='utf-8', errors='replace') as handle:
|
||||
raw = handle.read()
|
||||
match = re.search(r'processPath\s*=\s*"([^"]+)"', raw)
|
||||
args = re.search(r'arguments\s*=\s*"([^"]*)"', raw)
|
||||
if match:
|
||||
path = os.path.expandvars(match.group(1))
|
||||
report.line('\nhttpPlatform processPath : %s' % match.group(1))
|
||||
report.line(' resolved : %s' % path)
|
||||
report.line(' exists : %s' % os.path.isfile(path))
|
||||
if args:
|
||||
report.line('httpPlatform arguments : %s' % args.group(1))
|
||||
except Exception as exc:
|
||||
report.line('[could not parse web.config: %s]' % exc)
|
||||
|
||||
# ------------------------------------------------------------- 4. app logs
|
||||
report.head('4. APPLICATION LOGS')
|
||||
log_dir = os.path.join(APP_ROOT, 'logs')
|
||||
if not os.path.isdir(log_dir):
|
||||
report.line('MISSING: %s' % log_dir)
|
||||
else:
|
||||
entries = []
|
||||
for name in sorted(os.listdir(log_dir)):
|
||||
full = os.path.join(log_dir, name)
|
||||
try:
|
||||
entries.append((os.path.getmtime(full), full, name,
|
||||
os.path.getsize(full)))
|
||||
except OSError:
|
||||
pass
|
||||
if not entries:
|
||||
report.line('%s is EMPTY.' % log_dir)
|
||||
report.line('No stdout log at all means httpPlatformHandler never')
|
||||
report.line('launched python - look at the pool identity and ACLs.')
|
||||
for _, full, name, size in sorted(entries, reverse=True)[:5]:
|
||||
if size == 0:
|
||||
report.block('%s (0 bytes)' % name,
|
||||
'EMPTY - python was launched but wrote nothing.')
|
||||
continue
|
||||
try:
|
||||
with open(full, 'r', encoding='utf-8', errors='replace') as handle:
|
||||
tail = handle.readlines()[-60:]
|
||||
report.block('%s (%d bytes, last 60 lines)' % (name, size),
|
||||
''.join(tail))
|
||||
except Exception as exc:
|
||||
report.block(name, '[could not read: %s]' % exc)
|
||||
|
||||
# ---------------------------------------------------------------- 5. ACLs
|
||||
report.head('5. PERMISSIONS')
|
||||
report.line('The pool runs as "IIS AppPool\\shopdbflask". It needs RX on the')
|
||||
report.line('tree, Modify on logs and instance, and Read on .env.')
|
||||
for target in (APP_ROOT, log_dir, os.path.join(APP_ROOT, '.env'),
|
||||
os.path.join(APP_ROOT, 'venv', 'Scripts')):
|
||||
if os.path.exists(target):
|
||||
report.block('icacls %s' % target, run(['icacls', target], timeout=40))
|
||||
|
||||
# ------------------------------------------------------------ 6. event log
|
||||
report.head('6. EVENT LOG')
|
||||
report.block('recent application errors', powershell(
|
||||
"Get-WinEvent -FilterHashtable @{LogName='Application';"
|
||||
"StartTime=(Get-Date).AddHours(-6)} -EA SilentlyContinue | "
|
||||
"Where-Object { $_.ProviderName -match 'HttpPlatform|IIS|W3SVC|WAS|\\.NET' "
|
||||
"-or $_.LevelDisplayName -eq 'Error' } | Select-Object -First 25 "
|
||||
"TimeCreated,ProviderName,LevelDisplayName,Message | Format-List | Out-String",
|
||||
timeout=180))
|
||||
report.block('system log: WAS / W3SVC', powershell(
|
||||
"Get-WinEvent -FilterHashtable @{LogName='System';"
|
||||
"StartTime=(Get-Date).AddHours(-6)} -EA SilentlyContinue | "
|
||||
"Where-Object { $_.ProviderName -match 'WAS|W3SVC|HTTP' } | "
|
||||
"Select-Object -First 20 TimeCreated,ProviderName,LevelDisplayName,Message | "
|
||||
"Format-List | Out-String", timeout=180))
|
||||
|
||||
# ------------------------------------------------------------------ write
|
||||
body = scrub(report.text())
|
||||
out_path = os.path.join(os.path.dirname(os.path.abspath(__file__)),
|
||||
'shopdb-diagnose-%s.txt' % stamp)
|
||||
try:
|
||||
with open(out_path, 'w', encoding='utf-8') as handle:
|
||||
handle.write(body)
|
||||
except Exception:
|
||||
out_path = os.path.join(os.environ.get('TEMP', r'C:\Windows\Temp'),
|
||||
'shopdb-diagnose-%s.txt' % stamp)
|
||||
with open(out_path, 'w', encoding='utf-8') as handle:
|
||||
handle.write(body)
|
||||
|
||||
print('')
|
||||
print('Report written to:')
|
||||
print(' %s' % out_path)
|
||||
print('')
|
||||
print('%d secret value(s) were scrubbed from it.' % len(SECRETS))
|
||||
print('Send that file back.')
|
||||
return 0
|
||||
|
||||
|
||||
if __name__ == '__main__':
|
||||
sys.exit(main())
|
||||
Reference in New Issue
Block a user