结构化 nginx 日志需要同时约定转义和字段类型

from contextlib import contextmanager
from pathlib import Path
from tempfile import TemporaryDirectory
import http.client,json,socket,subprocess,time,uuid

NGINX='nginx@sha256:552e7481ca93ffccd046aa658dbbed22caefbc09c66fa7cd247cbb90b8a5c609'
PYTHON='python@sha256:528257d48c1da0dcecc2e725d1ae34498d60c965f1241e39cd6a85a8859bdf84'
def docker(*args,check=True):
    result=subprocess.run(['docker',*args],capture_output=True,text=True,timeout=120)
    if check:assert result.returncode==0,result.stderr
    return result
def wait(predicate):
    deadline=time.monotonic()+15
    while time.monotonic()<deadline:
        try:
            if predicate():return
        except OSError:pass
        time.sleep(.1)
    raise AssertionError('fixture did not become ready')

@contextmanager
def lab(configuration,files=None,backend=None):
    name='xbcatm-nginx-'+uuid.uuid4().hex[:10];tags=[name+':proxy',name+':backend'];containers=[name+'-proxy',name+'-backend']
    try:
        with TemporaryDirectory(prefix=name+'-') as directory:
            root=Path(directory);(root/'files').mkdir();(root/'nginx.conf').write_text(configuration)
            for path,content in (files or {}).items():
                target=root/'files'/path;target.parent.mkdir(parents=True,exist_ok=True);target.write_text(content)
            docker('network','create',name)
            if backend is not None:
                (root/'backend.py').write_text(backend)
                (root/'backend.Dockerfile').write_text(f'FROM {PYTHON}\nCOPY backend.py /backend.py\nCMD ["python", "/backend.py"]\n')
                docker('build','--network','none','-f',str(root/'backend.Dockerfile'),'-t',tags[1],str(root))
                docker('run','-d','--name',containers[1],'--network',name,'--network-alias','backend',tags[1])
                wait(lambda:docker('exec',containers[1],'python','-c','import socket;s=socket.create_connection(("127.0.0.1",8081),timeout=.5);s.close()',check=False).returncode==0)
            (root/'Dockerfile').write_text(f'FROM {NGINX}\nCOPY nginx.conf /etc/nginx/nginx.conf\nCOPY files /srv\n')
            docker('build','--network','none','-t',tags[0],str(root))
            docker('run','--rm','--network',name,tags[0],'nginx','-t')
            docker('run','-d','--name',containers[0],'--network',name,'-p','127.0.0.1::8080',tags[0])
            details=json.loads(docker('inspect',containers[0]).stdout)[0]
            binding=details['NetworkSettings']['Ports']['8080/tcp'][0];assert binding['HostIp']=='127.0.0.1';port=int(binding['HostPort'])
            def ready():
                connection=socket.create_connection(('127.0.0.1',port),timeout=.5);connection.close();return True
            wait(ready)
            def request(path,method='GET',headers=None,body=None):
                connection=http.client.HTTPConnection('127.0.0.1',port,timeout=5)
                try:
                    connection.request(method,path,body=body,headers=headers or {})
                    response=connection.getresponse();return response.status,{k.lower():v for k,v in response.getheaders()},response.read()
                finally:connection.close()
            yield containers[0],request
    finally:
        docker('rm','-f',*containers,check=False);docker('image','rm',*tags,check=False);docker('network','rm',name,check=False)

def config(locations,extra=''):
    return 'worker_processes 1;\nerror_log /tmp/error.log notice;\nevents {}\nhttp {\naccess_log off;\n'+extra+'\nserver { listen 8080; root /srv;\n'+locations+'\n}\n}\n'

extra=r'''
log_format default_escape '{"agent":"$http_user_agent","upstream_time":"$upstream_response_time"}';
log_format raw escape=none '{"agent":"$http_user_agent"}';
log_format numeric escape=json '{"upstream_time":$upstream_response_time}';
log_format structured escape=json '{"agent":"$http_user_agent","upstream_time":"$upstream_response_time","status":$status,"request_id":"$request_id"}';
'''
locations=r'''
access_log /tmp/default.json default_escape;
access_log /tmp/raw.json raw;
access_log /tmp/numeric.json numeric;
access_log /tmp/structured.json structured;
location / { return 204; }
'''
with lab(config(locations,extra)) as (container,request):
    agent='reader "quoted" '+chr(92)+' path'+chr(9)+'tab'
    assert request('/local',headers={'User-Agent':agent})[0]==204
    assert request('/local',headers={'User-Agent':'plain'})[0]==204
    def lines(path):return docker('exec',container,'cat',path).stdout.splitlines()
    wait(lambda:len(lines('/tmp/structured.json'))==2)
    default=lines('/tmp/default.json');raw=lines('/tmp/raw.json');numeric=lines('/tmp/numeric.json');structured=list(map(json.loads,lines('/tmp/structured.json')))
    for line in [default[0],raw[0]]:
        try:json.loads(line)
        except json.JSONDecodeError:pass
        else:raise AssertionError('non-JSON escaping unexpectedly formed valid JSON')
    assert r'\x22' in default[0]
    assert json.loads(default[1])=={'agent':'plain','upstream_time':'-'}
    assert json.loads(raw[1])=={'agent':'plain'}
    for line in numeric:
        try:json.loads(line)
        except json.JSONDecodeError:pass
        else:raise AssertionError('unquoted missing timing unexpectedly formed valid JSON')
    assert [row['agent'] for row in structured]==[agent,'plain']
    assert all(row['status']==204 and row['upstream_time']=='' for row in structured)
    identifiers=[row['request_id'] for row in structured]
    assert len(set(identifiers))==2 and all(len(value)==32 and int(value,16)>=0 for value in identifiers)
    print('escape=json preserves quotes, backslashes and tabs as valid JSON strings; both default and no escaping break JSON on the same public header')
    print('default escaping writes a dash for the absent timing, while JSON escaping writes an empty string in the quoted field')
    print('an unavailable upstream timing is empty under JSON escaping, so emitting it unquoted still creates invalid JSON')
    print('structured records parse with a numeric status, explicit empty timing string and distinct nginx-generated request IDs')