diff --git a/deploy/windows/shopdb-diagnose.py b/deploy/windows/shopdb-diagnose.py new file mode 100644 index 0000000..d2c2279 --- /dev/null +++ b/deploy/windows/shopdb-diagnose.py @@ -0,0 +1,413 @@ +"""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-.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, '') + # Catch a password inside any URL that did not come from .env. + text = re.sub(r'(://[^:@/\s]+:)[^@\s]+(@)', r'\1\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)[^>]*>.*?', ' ', 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. + for section in ('system.webServer/handlers', 'system.webServer/httpPlatform'): + 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 = ' % (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())