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