xref: /unit/test/test_access_log.py (revision 2627:36afea93a678)
1import time
2
3import pytest
4
5from unit.applications.lang.python import ApplicationPython
6from unit.option import option
7
8prerequisites = {'modules': {'python': 'any'}}
9
10client = ApplicationPython()
11
12
13def load(script):
14    client.load(script)
15
16    assert 'success' in client.conf(
17        f'"{option.temp_dir}/access.log"', 'access_log'
18    ), 'access_log configure'
19
20
21def set_format(log_format):
22    assert 'success' in client.conf(
23        {
24            'path': f'{option.temp_dir}/access.log',
25            'format': log_format,
26        },
27        'access_log',
28    ), 'access_log format'
29
30
31def set_if(condition):
32    assert 'success' in client.conf(f'"{condition}"', 'access_log/if')
33
34
35def test_access_log_keepalive(wait_for_record):
36    load('mirror')
37
38    assert client.get()['status'] == 200, 'init'
39
40    (_, sock) = client.post(
41        headers={
42            'Host': 'localhost',
43            'Connection': 'keep-alive',
44        },
45        start=True,
46        body='01234',
47        read_timeout=1,
48    )
49
50    assert (
51        wait_for_record(r'"POST / HTTP/1.1" 200 5', 'access.log') is not None
52    ), 'keepalive 1'
53
54    _ = client.post(sock=sock, body='0123456789')
55
56    assert (
57        wait_for_record(r'"POST / HTTP/1.1" 200 10', 'access.log') is not None
58    ), 'keepalive 2'
59
60
61def test_access_log_pipeline(wait_for_record):
62    load('empty')
63
64    client.http(
65        b"""GET / HTTP/1.1
66Host: localhost
67Referer: Referer-1
68
69GET / HTTP/1.1
70Host: localhost
71Referer: Referer-2
72
73GET / HTTP/1.1
74Host: localhost
75Referer: Referer-3
76Connection: close
77
78""",
79        raw_resp=True,
80        raw=True,
81    )
82
83    assert (
84        wait_for_record(r'"GET / HTTP/1.1" 200 0 "Referer-1" "-"', 'access.log')
85        is not None
86    ), 'pipeline 1'
87    assert (
88        wait_for_record(r'"GET / HTTP/1.1" 200 0 "Referer-2" "-"', 'access.log')
89        is not None
90    ), 'pipeline 2'
91    assert (
92        wait_for_record(r'"GET / HTTP/1.1" 200 0 "Referer-3" "-"', 'access.log')
93        is not None
94    ), 'pipeline 3'
95
96
97def test_access_log_ipv6(wait_for_record):
98    load('empty')
99
100    assert 'success' in client.conf(
101        {"[::1]:8080": {"pass": "applications/empty"}}, 'listeners'
102    )
103
104    client.get(sock_type='ipv6')
105
106    assert (
107        wait_for_record(
108            r'::1 - - \[.+\] "GET / HTTP/1.1" 200 0 "-" "-"', 'access.log'
109        )
110        is not None
111    ), 'ipv6'
112
113
114def test_access_log_unix(temp_dir, wait_for_record):
115    load('empty')
116
117    addr = f'{temp_dir}/sock'
118
119    assert 'success' in client.conf(
120        {f'unix:{addr}': {"pass": "applications/empty"}}, 'listeners'
121    )
122
123    client.get(sock_type='unix', addr=addr)
124
125    assert (
126        wait_for_record(
127            r'unix: - - \[.+\] "GET / HTTP/1.1" 200 0 "-" "-"', 'access.log'
128        )
129        is not None
130    ), 'unix'
131
132
133def test_access_log_referer(wait_for_record):
134    load('empty')
135
136    client.get(
137        headers={
138            'Host': 'localhost',
139            'Referer': 'referer-value',
140            'Connection': 'close',
141        }
142    )
143
144    assert (
145        wait_for_record(
146            r'"GET / HTTP/1.1" 200 0 "referer-value" "-"', 'access.log'
147        )
148        is not None
149    ), 'referer'
150
151
152def test_access_log_user_agent(wait_for_record):
153    load('empty')
154
155    client.get(
156        headers={
157            'Host': 'localhost',
158            'User-Agent': 'user-agent-value',
159            'Connection': 'close',
160        }
161    )
162
163    assert (
164        wait_for_record(
165            r'"GET / HTTP/1.1" 200 0 "-" "user-agent-value"', 'access.log'
166        )
167        is not None
168    ), 'user agent'
169
170
171def test_access_log_http10(wait_for_record):
172    load('empty')
173
174    client.get(http_10=True)
175
176    assert (
177        wait_for_record(r'"GET / HTTP/1.0" 200 0 "-" "-"', 'access.log')
178        is not None
179    ), 'http 1.0'
180
181
182def test_access_log_partial(wait_for_record):
183    load('empty')
184
185    assert client.post()['status'] == 200, 'init'
186
187    _ = client.http(b"""GE""", raw=True, read_timeout=1)
188
189    time.sleep(1)
190
191    assert (
192        wait_for_record(r'"-" 400 0 "-" "-"', 'access.log') is not None
193    ), 'partial'
194
195
196def test_access_log_partial_2(wait_for_record):
197    load('empty')
198
199    assert client.post()['status'] == 200, 'init'
200
201    client.http(b"""GET /\n""", raw=True)
202
203    assert (
204        wait_for_record(r'"-" 400 \d+ "-" "-"', 'access.log') is not None
205    ), 'partial 2'
206
207
208def test_access_log_partial_3(wait_for_record):
209    load('empty')
210
211    assert client.post()['status'] == 200, 'init'
212
213    _ = client.http(b"""GET / HTTP/1.1""", raw=True, read_timeout=1)
214
215    time.sleep(1)
216
217    assert (
218        wait_for_record(r'"-" 400 0 "-" "-"', 'access.log') is not None
219    ), 'partial 3'
220
221
222def test_access_log_partial_4(wait_for_record):
223    load('empty')
224
225    assert client.post()['status'] == 200, 'init'
226
227    _ = client.http(b"""GET / HTTP/1.1\n""", raw=True, read_timeout=1)
228
229    time.sleep(1)
230
231    assert (
232        wait_for_record(r'"-" 400 0 "-" "-"', 'access.log') is not None
233    ), 'partial 4'
234
235
236@pytest.mark.skip('not yet')
237def test_access_log_partial_5(wait_for_record):
238    load('empty')
239
240    assert client.post()['status'] == 200, 'init'
241
242    client.get(headers={'Connection': 'close'})
243
244    assert (
245        wait_for_record(r'"GET / HTTP/1.1" 400 \d+ "-" "-"', 'access.log')
246        is not None
247    ), 'partial 5'
248
249
250def test_access_log_get_parameters(wait_for_record):
251    load('empty')
252
253    client.get(url='/?blah&var=val')
254
255    assert (
256        wait_for_record(
257            r'"GET /\?blah&var=val HTTP/1.1" 200 0 "-" "-"', 'access.log'
258        )
259        is not None
260    ), 'get parameters'
261
262
263def test_access_log_delete(search_in_file):
264    load('empty')
265
266    assert 'success' in client.conf_delete('access_log')
267
268    client.get(url='/delete')
269
270    assert search_in_file(r'/delete', 'access.log') is None, 'delete'
271
272
273def test_access_log_change(temp_dir, wait_for_record):
274    load('empty')
275
276    client.get()
277
278    assert 'success' in client.conf(f'"{temp_dir}/new.log"', 'access_log')
279
280    client.get()
281
282    assert (
283        wait_for_record(r'"GET / HTTP/1.1" 200 0 "-" "-"', 'new.log')
284        is not None
285    ), 'change'
286
287
288def test_access_log_format(wait_for_record):
289    load('empty')
290
291    def check_format(log_format, expect, url='/'):
292        set_format(log_format)
293
294        assert client.get(url=url)['status'] == 200
295        assert wait_for_record(expect, 'access.log') is not None, 'found'
296
297    log_format = 'BLAH\t0123456789'
298    check_format(log_format, log_format)
299    check_format('$uri $status $uri $status', '/ 200 / 200')
300
301
302def test_access_log_variables(wait_for_record):
303    load('mirror')
304
305    # $body_bytes_sent
306
307    set_format('$uri $body_bytes_sent')
308    body = '0123456789' * 50
309    client.post(url='/bbs', body=body, read_timeout=1)
310    assert (
311        wait_for_record(fr'^\/bbs {len(body)}$', 'access.log') is not None
312    ), '$body_bytes_sent'
313
314
315def test_access_log_if(search_in_file, wait_for_record):
316    load('empty')
317    set_format('$uri')
318
319    def try_if(condition):
320        set_if(condition)
321        assert client.get(url=f'/{condition}')['status'] == 200
322
323    # const
324
325    try_if('')
326    try_if('0')
327    try_if('false')
328    try_if('undefined')
329    try_if('!')
330    try_if('!null')
331    try_if('1')
332
333    # variable
334
335    set_if('$arg_foo')
336    assert client.get(url='/bar?bar')['status'] == 200
337    assert client.get(url='/foo_empty?foo')['status'] == 200
338    assert client.get(url='/foo?foo=1')['status'] == 200
339
340    # check results
341
342    assert wait_for_record(r'^/foo$', 'access.log') is not None
343
344    assert search_in_file(r'^/$', 'access.log') is None
345    assert search_in_file(r'^/0$', 'access.log') is None
346    assert search_in_file(r'^/false$', 'access.log') is None
347    assert search_in_file(r'^/undefined$', 'access.log') is None
348    assert search_in_file(r'^/!$', 'access.log') is not None
349    assert search_in_file(r'^/!null$', 'access.log') is not None
350    assert search_in_file(r'^/1$', 'access.log') is not None
351
352    assert search_in_file(r'^/bar$', 'access.log') is None
353    assert search_in_file(r'^/foo_empty$', 'access.log') is None
354
355
356def test_access_log_if_njs(require, search_in_file, wait_for_record):
357    require({'modules': {'njs': 'any'}})
358
359    load('empty')
360    set_format('$uri')
361
362    set_if('`${args.foo == \'1\'}`')
363
364    assert client.get(url='/foo_2?foo=2')['status'] == 200
365    assert client.get(url='/foo_1?foo=1')['status'] == 200
366
367    assert wait_for_record(r'^/foo_1$', 'access.log') is not None
368    assert search_in_file(r'^/foo_2$', 'access.log') is None
369
370
371def test_access_log_incorrect(temp_dir, skip_alert):
372    skip_alert(r'failed to apply new conf')
373
374    assert 'error' in client.conf(
375        f'{temp_dir}/blah/access.log',
376        'access_log/path',
377    ), 'access_log path incorrect'
378
379    assert 'error' in client.conf(
380        {
381            'path': f'{temp_dir}/access.log',
382            'format': '$remote_add',
383        },
384        'access_log',
385    ), 'access_log format incorrect'
386
387    assert 'error' in client.conf('$arg_', 'access_log/if')
388