423 lines
18 KiB
Python
423 lines
18 KiB
Python
"""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())
|