1%% 2%% %CopyrightBegin% 3%% 4%% Copyright Ericsson AB 1998-2019. All Rights Reserved. 5%% 6%% Licensed under the Apache License, Version 2.0 (the "License"); 7%% you may not use this file except in compliance with the License. 8%% You may obtain a copy of the License at 9%% 10%% http://www.apache.org/licenses/LICENSE-2.0 11%% 12%% Unless required by applicable law or agreed to in writing, software 13%% distributed under the License is distributed on an "AS IS" BASIS, 14%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 15%% See the License for the specific language governing permissions and 16%% limitations under the License. 17%% 18%% %CopyrightEnd% 19%% 20 21-module(wrap_log_reader_SUITE). 22 23%%-define(debug, true). 24 25-ifdef(debug). 26-define(format(S, A), io:format(S, A)). 27-define(line, put(line, ?LINE), ). 28-define(privdir(_), "./disk_log_SUITE_priv"). 29-define(config(X,Y), foo). 30-define(t,test_server). 31-else. 32-include_lib("common_test/include/ct.hrl"). 33-define(format(S, A), ok). 34-define(privdir(Conf), proplists:get_value(priv_dir, Conf)). 35-endif. 36 37-export([all/0, suite/0,groups/0,init_per_suite/1, end_per_suite/1, 38 init_per_group/2,end_per_group/2, 39 no_file/1, 40 one_empty/1, one_filled/1, 41 two_filled/1, 42 four_filled/1, 43 wrap_filled/1, 44 wrapping/1, 45 external/1, 46 error/1]). 47 48-export([init_per_testcase/2, end_per_testcase/2]). 49 50suite() -> 51 [{ct_hooks,[ts_install_cth]}, 52 {timetrap,{minutes,1}}]. 53 54all() -> 55 [no_file, {group, one}, {group, two}, {group, four}, 56 {group, wrap}, wrapping, external, error]. 57 58groups() -> 59 [{one, [], [one_empty, one_filled]}, 60 {two, [], [two_filled]}, {four, [], [four_filled]}, 61 {wrap, [], [wrap_filled]}]. 62 63init_per_suite(Config) -> 64 Config. 65 66end_per_suite(_Config) -> 67 ok. 68 69init_per_group(_GroupName, Config) -> 70 Config. 71 72end_per_group(_GroupName, Config) -> 73 Config. 74 75 76init_per_testcase(Func, Config) -> 77 Config. 78 79end_per_testcase(_Func, _Config) -> 80 ok. 81 82%% No log file exists. 83no_file(Conf) when is_list(Conf) -> 84 code:add_path(proplists:get_value(data_dir,Conf)), 85 Dir = ?privdir(Conf), 86 File = join(Dir, "sune.LOG"), 87 delete_files(File), 88 start(), 89 90 wlt ! {open, self(), File}, 91 rec({error, {index_file_not_found, File}}, ?LINE), 92 wlt ! {open, self(), File, 1}, 93 rec({error, {index_file_not_found, File}}, ?LINE), 94 wlt ! {open, self(), File, 4}, 95 rec({error, {index_file_not_found, File}}, ?LINE), 96 97 stop(), 98 delete_files(File), 99 ok. 100 101 102%% One empty index file. 103one_empty(Conf) when is_list(Conf) -> 104 Dir = ?privdir(Conf), 105 File = join(Dir, "sune.LOG"), 106 delete_files(File), 107 start(), 108 109 open(sune, File, ?LINE), 110 %% open 111 do_chunk([{open,File}, eof], wlt, ?LINE), 112 do_chunk([{open,File,1}, eof], wlt, ?LINE), 113 wlt ! {open, self(), File, 2}, 114 rec({error, {file_not_found, add_ext(File, 2)}}, ?LINE), 115 close(sune), 116 117 %% closed 118 do_chunk([{open,File}, eof], wlt, ?LINE), 119 do_chunk([{open,File,1}, eof], wlt, ?LINE), 120 wlt ! {open, self(), File, 2}, 121 rec({error, {file_not_found, add_ext(File, 2)}}, ?LINE), 122 123 stop(), 124 delete_files(File), 125 ok. 126 127%% One filled index file. 128one_filled(Conf) when is_list(Conf) -> 129 Dir = ?privdir(Conf), 130 File = join(Dir, "sune.LOG"), 131 delete_files(File), 132 start(), 133 134 open(sune, File, ?LINE), 135 log_terms(sune, ["first round, one", "first round, two"]), 136 sync(sune), 137 %% open 138 test_one(File), 139 close(sune), 140 %% closed 141 test_one(File), 142 143 stop(), 144 delete_files(File), 145 ok. 146 147test_one(File) -> 148 do_chunk([{open,File}, 149 {chunk, ["first round, one", "first round, two"]}, 150 eof], wlt, ?LINE), 151 do_chunk([{open,File,1}, 152 {chunk, ["first round, one", "first round, two"]}, 153 eof], wlt, ?LINE), 154 wlt ! {open, self(), File, 2}, 155 rec({error, {file_not_found, add_ext(File, 2)}}, ?LINE), 156 do_chunk([{open,File,1}, {chunk, 1, ["first round, one"]}, 157 {chunk, 1, ["first round, two"]}, eof], wlt, ?LINE), 158 ok. 159 160 161%% Two filled index files. 162two_filled(Conf) when is_list(Conf) -> 163 Dir = ?privdir(Conf), 164 File = list_to_atom(join(Dir, "sune.LOG")), 165 delete_files(File), 166 start(), 167 168 open(sune, File, ?LINE), 169 log_terms(sune, ["first round, 11", "first round, 12"]), 170 log_terms(sune, ["first round, 21", "first round, 22"]), 171 sync(sune), 172 %% open 173 test_two(File), 174 close(sune), 175 %% closed 176 test_two(File), 177 178 stop(), 179 delete_files(File), 180 ok. 181 182test_two(File) -> 183 do_chunk([{open,File}, 184 {chunk, infinity, ["first round, 11", "first round, 12"]}, 185 {chunk, ["first round, 21", "first round, 22"]}, 186 eof], wlt, ?LINE), 187 do_chunk([{open,File,1}, 188 {chunk, ["first round, 11", "first round, 12"]}, 189 eof], wlt, ?LINE), 190 do_chunk([{open,File,2}, 191 {chunk, ["first round, 21", "first round, 22"]}, 192 eof], wlt, ?LINE), 193 wlt ! {open, self(), File, 3}, 194 rec({error, {file_not_found, add_ext(File, 3)}}, ?LINE), 195 do_chunk([{open,File,1}, {chunk, 1, ["first round, 11"]}, 196 {chunk, 2, ["first round, 12"]}, eof], wlt, ?LINE), 197 ok. 198 199 200%% Four filled index files. 201four_filled(Conf) when is_list(Conf) -> 202 Dir = ?privdir(Conf), 203 File = join(Dir, "sune.LOG"), 204 delete_files(File), 205 start(), 206 207 open(sune, File, ?LINE), 208 init_files(0), 209 sync(sune), 210 %% open 211 test_four(File), 212 close(sune), 213 %% closed 214 test_four(File), 215 216 stop(), 217 delete_files(File), 218 ok. 219 220test_four(File) -> 221 do_chunk([{open,File}, 222 {chunk, ["first round, 11", "first round, 12"]}, 223 {chunk, ["first round, 21", "first round, 22"]}, 224 {chunk, ["first round, 31", "first round, 32"]}, 225 {chunk, ["first round, 41", "first round, 42"]}, 226 eof], wlt, ?LINE), 227 do_chunk([{open,File,1}, 228 {chunk, ["first round, 11", "first round, 12"]}, 229 eof], wlt, ?LINE), 230 do_chunk([{open,File,4}, 231 {chunk, ["first round, 41", "first round, 42"]}, 232 eof], wlt, ?LINE), 233 wlt ! {open, self(), File, 5}, 234 rec({error, {file_not_found, add_ext(File, 5)}}, ?LINE), 235 do_chunk([{open,File,1}, {chunk, 1, ["first round, 11"]}, 236 {chunk, 2, ["first round, 12"]}, eof], wlt, ?LINE), 237 do_chunk([{open,File,4}, {chunk, 1, ["first round, 41"]}, 238 {chunk, 2, ["first round, 42"]}, eof], wlt, ?LINE), 239 ok. 240 241 242%% First wrap, open, filled index file. 243wrap_filled(Conf) when is_list(Conf) -> 244 Dir = ?privdir(Conf), 245 File = join(Dir, "sune.LOG"), 246 delete_files(File), 247 start(), 248 249 open(sune, File, ?LINE), 250 init_files(0), 251 log_terms(sune, ["second round, 11", "second round, 12"]), 252 sync(sune), 253 %% open 254 test_wrap(File), 255 close(sune), 256 %% closed 257 test_wrap(File), 258 259 stop(), 260 delete_files(File), 261 ok. 262 263test_wrap(File) -> 264 do_chunk([{open,File}, 265 {chunk, ["first round, 21", "first round, 22"]}, 266 {chunk, ["first round, 31", "first round, 32"]}, 267 {chunk, ["first round, 41", "first round, 42"]}, 268 {chunk, ["second round, 11", "second round, 12"]}, 269 eof], wlt, ?LINE), 270 do_chunk([{open,File,1}, 271 {chunk, ["second round, 11", "second round, 12"]}, 272 eof], wlt, ?LINE), 273 do_chunk([{open,File,2}, 274 {chunk, ["first round, 21", "first round, 22"]}, 275 eof], wlt, ?LINE), 276 wlt ! {open, self(), File, 5}, 277 rec({error, {file_not_found, add_ext(File, 5)}}, ?LINE), 278 do_chunk([{open,File,1}, {chunk, 1, ["second round, 11"]}, 279 {chunk, 2, ["second round, 12"]}, eof], wlt, ?LINE), 280 do_chunk([{open,File,4}, {chunk, 1, ["first round, 41"]}, 281 {chunk, 2, ["first round, 42"]}, eof], wlt, ?LINE), 282 ok. 283 284%% Wrapping at the same time as reading. 285wrapping(Conf) when is_list(Conf) -> 286 Dir = ?privdir(Conf), 287 File = join(Dir, "sune.LOG"), 288 delete_files(File), 289 start(), 290 291 open(sune, File, ?LINE), 292 init_files(1100), 293 sync(sune), 294 C1 = 295 do_chunk([{open,File}, {chunk, 1, ["first round, 11"]}], wlt, ?LINE), 296 log_terms(sune, ["second round, 11", "second round, 12"]), 297 sync(sune), 298 do_chunk([{chunk, 1, ["first round, 12"]}, 299 %% Here two bad bytes are found. 300 {chunk, ["first round, 21", "first round, 22"]}, 301 {chunk, ["first round, 31", "first round, 32"]}, 302 {chunk, ["first round, 41", "first round, 42"]}, eof], 303 wlt, ?LINE, C1), 304 start(), 305 delete_files(File), 306 open(sune, File, ?LINE), 307 init_files(1100), 308 sync(sune), 309 C2 = 310 do_chunk([{open,File}, {chunk, 1, ["first round, 11"]}], wlt, ?LINE), 311 log_terms(sune, ["second round, 11", "second round, 12"]), 312 close(sune), 313 do_chunk([{chunk, 1, ["first round, 12"]}, 314 %% Here two bad bytes are found. 315 {chunk, ["first round, 21", "first round, 22"]}, 316 {chunk, ["first round, 31", "first round, 32"]}, 317 {chunk, ["first round, 41", "first round, 42"]}, eof], 318 wlt, ?LINE, C2), 319 start(), 320 delete_files(File), 321 open(sune, File, ?LINE), 322 init_files(1100), 323 sync(sune), 324 C3 = do_chunk([{open,File}], wlt, ?LINE), 325 log_terms(sune, ["second round, 11"]), 326 sync(sune), 327 do_chunk([{chunk, 1, ["second round, 11"]}, 328 {chunk, 1, ["first round, 21"]}, 329 {chunk, 1, ["first round, 22"]}, 330 {chunk, ["first round, 31", "first round, 32"]}, 331 {chunk, ["first round, 41", "first round, 42"]}, eof], 332 wlt, ?LINE, C3), 333 334 stop(), 335 delete_files(File), 336 ok. 337 338%% External format. 339external(Conf) when is_list(Conf) -> 340 Dir = ?privdir(Conf), 341 File = join(Dir, "sune.LOG"), 342 delete_files(File), 343 start(), 344 345 open_ext(sune, File, ?FILE), 346 init_files_ext(0), 347 close(sune), 348 P0 = pps(), 349 wlt ! {open, self(), File}, 350 rec({error, {not_a_log_file, add_ext(File, 1)}}, ?LINE), 351 check_pps(P0), 352 353 stop(), 354 delete_files(File), 355 ok. 356 357%% Error situations. 358error(Conf) when is_list(Conf) -> 359 Dir = ?privdir(Conf), 360 File = join(Dir, "sune.LOG"), 361 delete_files(File), 362 start(), 363 364 P0 = pps(), 365 wlt ! {open, self(), File, 1}, 366 rec({error, {index_file_not_found, File}}, ?LINE), 367 wlt ! {open, self(), File}, 368 rec({error, {index_file_not_found, File}}, ?LINE), 369 check_pps(P0), 370 371 open(sune, File, ?LINE), 372 close(sune), 373 P1 = pps(), 374 First = add_ext(File, 1), 375 ok = file:delete(First), 376 wlt ! {open, self(), File}, 377 rec({error, {not_a_log_file, First}}, ?LINE), 378 check_pps(P1), 379 380 delete_files(File), 381 open(sune, File, ?LINE), 382 init_files(0), 383 close(sune), 384 P2 = pps(), 385 C = do_chunk([{open,File}, 386 {chunk, ["first round, 11", "first round, 12"]}], 387 wlt, ?LINE), 388 Second = add_ext(File, 2), 389 ok = file:delete(Second), 390 wlt ! {chunk, self(), C}, 391 rec({error, {file_error, Second, {error, enoent}}}, ?LINE), 392 ok = file:write_file(Second, <<17:(3*8)>>), % three bytes 393 wlt ! {chunk, self(), C}, 394 rec({error, {not_a_log_file, Second}}, ?LINE), 395 do_chunk([close], wlt, ?LINE, C), 396 check_pps(P2), 397 398 delete_files(File), 399 open(sune, File, ?LINE), 400 init_files(0), 401 close(sune), 402 P3 = pps(), 403 timer:sleep(1100), 404 Now = calendar:local_time(), 405 ok = file:change_time(First, Now), 406 C2 = do_chunk([{open,File}, 407 {chunk, ["first round, 11", "first round, 12"]}], 408 wlt, ?LINE), 409 wlt ! {chunk, self(), C2}, 410 rec({error,{is_wrapped,First}}, ?LINE), 411 do_chunk([close], wlt, ?LINE, C2), 412 IndexFile = add_ext(File, idx), 413 ok = file:write_file(IndexFile, <<17:(3*8)>>), 414 wlt ! {open, self(), File, 1}, 415 rec({error, {index_file_not_found, File}}, ?LINE), 416 check_pps(P3), 417 418 stop(), 419 delete_files(File), 420 ok. 421 422start() -> 423 ok = wrap_log_test:stop(), 424 dl_wait(), 425 ok = wrap_log_test:init(). 426 427stop() -> 428 ok = wrap_log_test:stop(), 429 dl_wait(). 430 431%% Give disk logs opened by 'wlr_logger' and 'wlt' time to close after 432%% receiving EXIT signals. 433dl_wait() -> 434 case disk_log:accessible_logs() of 435 {[], []} -> 436 ok; 437 _X -> 438 erlang:display(_X), 439 timer:sleep(100), 440 dl_wait() 441 end. 442 443delete_files(File) -> 444 file:delete(add_ext(File, idx)), 445 file:delete(add_ext(File, siz)), 446 file:delete(add_ext(File, 1)), 447 file:delete(add_ext(File, 2)), 448 file:delete(add_ext(File, 3)), 449 file:delete(add_ext(File, 4)), 450 ok. 451 452init_files(Delay) -> 453 log_terms(sune, ["first round, 11", "first round, 12"]), 454 timer:sleep(Delay), 455 log_terms(sune, ["first round, 21", "first round, 22"]), 456 timer:sleep(Delay), 457 log_terms(sune, ["first round, 31", "first round, 32"]), 458 timer:sleep(Delay), 459 log_terms(sune, ["first round, 41", "first round, 42"]), 460 timer:sleep(Delay), 461 ok. 462 463init_files_ext(Delay) -> 464 blog_terms(sune, ["first round, 11", "first round, 12"]), 465 timer:sleep(Delay), 466 blog_terms(sune, ["first round, 21", "first round, 22"]), 467 timer:sleep(Delay), 468 blog_terms(sune, ["first round, 31", "first round, 32"]), 469 timer:sleep(Delay), 470 blog_terms(sune, ["first round, 41", "first round, 42"]), 471 timer:sleep(Delay), 472 ok. 473 474join(A, B) -> 475 filename:nativename(filename:join(A, B)). 476 477do_chunk(Commands, Server, Where) -> 478 do_chunk(Commands, Server, Where, foo). 479 480do_chunk([{open, File, One} | Cs], S, W, _C) -> 481 S ! {open, self(), File, One}, 482 NC = rec1(ok, {W,?LINE}), 483 do_chunk(Cs, S, W, NC); 484do_chunk([{open, File} | Cs], S, W, _C) -> 485 S ! {open, self(), File}, 486 NC = rec1(ok, {W,?LINE}), 487 do_chunk(Cs, S, W, NC); 488do_chunk([{chunk, Terms} | Cs], S, W, C) -> 489 S ! {chunk, self(), C}, 490 NC = rec2(Terms, {W,?LINE}), 491 do_chunk(Cs, S, W, NC); 492do_chunk([{chunk, N, Terms} | Cs], S, W, C) -> 493 S ! {chunk, self(), C, N}, 494 NC = rec2(Terms, {W,?LINE}), 495 do_chunk(Cs, S, W, NC); 496do_chunk([eof], S, W, C) -> 497 S ! {chunk, self(), C}, 498 C1 = rec2(eof, {W,?LINE}), 499 do_chunk([close], S, W, C1); 500do_chunk([close], S, W, C) -> 501 S ! {close, self(), C}, 502 rec(ok, {W,?LINE}); 503do_chunk([], _S, _W, C) -> 504 C. 505 506add_ext(Name, Ext) -> 507 lists:concat([Name, ".", Ext]). 508 509%% disk_log. 510open(Log, File, Where) -> 511 wlr_logger ! {open, self(), Log, File}, 512 rec1(ok, Where). 513 514open_ext(Log, File, Where) -> 515 wlr_logger ! {open_ext, self(), Log, File}, 516 rec1(ok, Where). 517 518close(Log) -> 519 wlr_logger ! {close, self(), Log}, 520 rec(ok, ?LINE). 521 522sync(Log) -> 523 wlr_logger ! {sync, self(), Log}, 524 rec(ok, ?LINE). 525 526log_terms(File, Terms) -> 527 wlr_logger ! {log_terms, self(), File, Terms}, 528 rec(ok, ?LINE). 529 530blog_terms(File, Terms) -> 531 wlr_logger ! {blog_terms, self(), File, Terms}, 532 rec(ok, ?LINE). 533 534rec1(M, Where) -> 535 receive 536 {M, C} -> C; 537 Else -> ct:fail({error, {Where, Else}}) 538 after 1000 -> ct:fail({error, {Where, time_out}}) 539 end. 540 541rec2(M, Where) -> 542 receive 543 {C, M} -> C; 544 Else -> ct:fail({error, {Where, Else}}) 545 after 1000 -> ct:fail({error, {Where, time_out}}) 546 end. 547 548rec(M, Where) -> 549 receive 550 M -> 551 ok; 552 Else -> ct:fail({error, {Where, Else}}) 553 after 5000 -> ct:fail({error, {Where, time_out}}) 554 end. 555 556check_pps({Ports0,Procs0} = P0) -> 557 case pps() of 558 P0 -> 559 ok; 560 _ -> 561 timer:sleep(500), 562 case pps() of 563 P0 -> 564 ok; 565 {Ports1,Procs1} = P1 -> 566 case {Ports1 -- Ports0, Procs1 -- Procs0} of 567 {[], []} -> ok; 568 {PortsDiff,ProcsDiff} -> 569 io:format("failure, got ~p~n, expected ~p\n", [P1, P0]), 570 show("Old port", Ports0 -- Ports1), 571 show("New port", PortsDiff), 572 show("Old proc", Procs0 -- Procs1), 573 show("New proc", ProcsDiff), 574 ct:fail(failed) 575 end 576 end 577 end. 578 579show(_S, []) -> 580 ok; 581show(S, [{Pid, Name, InitCall}|Pids]) when is_pid(Pid) -> 582 io:format("~s: ~w (~w), ~w: ~p~n", 583 [S, Pid, proc_reg_name(Name), InitCall, 584 erlang:process_info(Pid)]), 585 show(S, Pids); 586show(S, [{Port, _}|Ports]) when is_port(Port)-> 587 io:format("~s: ~w: ~p~n", [S, Port, erlang:port_info(Port)]), 588 show(S, Ports). 589 590pps() -> 591 timer:sleep(100), 592 {port_list(), process_list()}. 593 594port_list() -> 595 [{P,safe_second_element(erlang:port_info(P, name))} || 596 P <- erlang:ports()]. 597 598process_list() -> 599 [{P,process_info(P, registered_name), 600 safe_second_element(process_info(P, initial_call))} || 601 P <- processes(), erlang:is_process_alive(P)]. 602 603proc_reg_name({registered_name, Name}) -> Name; 604proc_reg_name([]) -> no_reg_name. 605 606safe_second_element({_,Info}) -> Info; 607safe_second_element(Other) -> Other. 608