diff --git a/bin/Main.ml b/bin/Main.ml index 038bdf5..271bf20 100644 --- a/bin/Main.ml +++ b/bin/Main.ml @@ -2,6 +2,11 @@ open Cmdliner;; Fmt.set_style_renderer Fmt.stdout `Ansi_tty +let setup_log = + let open Term in + const OSnap.Logger.init $ Fmt_cli.style_renderer () $ Logs_cli.level () +;; + let print_warning msg = let printer = Fmt.pr "%a @." (Fmt.styled `Yellow Fmt.string) in Printf.ksprintf printer msg @@ -119,7 +124,7 @@ let default_cmd = let open Arg in value & opt (some int) None & info [ "p"; "parallelism" ] ~doc in - let exec noCreate noOnly noSkip parallelism config_path = + let exec noCreate noOnly noSkip parallelism config_path () = let ( let*? ) = Result.bind in let run ~sw ~env = let*? t = OSnap.setup ~sw ~env ~config_path ~noCreate ~noOnly ~noSkip in @@ -153,7 +158,7 @@ let default_cmd = @@ fun _ -> Eio.Switch.run @@ fun sw -> run ~sw ~env in ( (let open Term in - const exec $ noCreate $ noOnly $ noSkip $ parallelism $ config) + const exec $ noCreate $ noOnly $ noSkip $ parallelism $ config $ setup_log) , Cmd.info "osnap" ~man: diff --git a/bin/dune b/bin/dune index ba45a4c..8f23ba5 100644 --- a/bin/dune +++ b/bin/dune @@ -6,6 +6,7 @@ (ocamlopt_flags -O3) (libraries OSnap + OSnap_Logger cmdliner mirage-crypto-rng mirage-crypto-rng.unix diff --git a/dune-project b/dune-project index 1a310a1..4328b0f 100644 --- a/dune-project +++ b/dune-project @@ -31,6 +31,7 @@ fileutils fmt libspng + logs odiff-core re uri diff --git a/lib/OSnap.ml b/lib/OSnap.ml index 5a0019f..70de7f4 100644 --- a/lib/OSnap.ml +++ b/lib/OSnap.ml @@ -2,6 +2,7 @@ module Config = OSnap_Config module Browser = OSnap_Browser module Test = OSnap_Test open OSnap_Utils +module Logger = OSnap_Logger type t = { config : Config.Types.global @@ -13,11 +14,15 @@ type t = let setup ~sw ~env ~noCreate ~noOnly ~noSkip ~config_path = let ( let*? ) = Result.bind in let open Config.Types in + let debug = Logger.info ~header:"SETUP" in let start_time = Eio.Time.now (Eio.Stdenv.clock env) in let*? config = Config.Global.init ~env ~config_path in + debug "initializing folder structure"; let () = OSnap_Paths.init_folder_structure config in + debug "getting snapshow dir"; let snapshot_dir = OSnap_Paths.get_base_images_dir config in let*? all_tests = Config.Test.init config in + debug (Printf.sprintf "found %i tests" (List.length all_tests)); let*? only_tests, tests = all_tests |> ResultList.traverse (fun test -> @@ -58,6 +63,8 @@ let setup ~sw ~env ~noCreate ~noOnly ~noSkip ~config_path = | [], tests -> tests | only_tests, _ -> only_tests in + debug (Printf.sprintf "found %i tests to run" (List.length tests_to_run)); + debug "setting test priority"; let tests_to_run = tests_to_run |> List.fast_sort (fun (_test, _size, exists1) (_test, _size, exists2) -> @@ -71,10 +78,12 @@ let run ~env t = Eio.Switch.run @@ fun sw -> let open Config.Types in + let debug = Logger.info ~header:"RUN" in let { tests_to_run; config; start_time; browser } = t in Test.Printer.Progress.set_total (List.length tests_to_run); let domain_count = Domain.recommended_domain_count () in let parallelism = domain_count * 3 in + debug (Printf.sprintf "creating pool of %i runners" parallelism); let test_stream = Eio.Stream.create 0 in let browser_pool = Eio.Pool.create @@ -82,6 +91,7 @@ let run ~env t = (fun () -> Browser.Target.make browser) ~validate:(fun target -> Result.is_ok target) in + debug "Assigning tests to runners..."; for _ = 1 to parallelism do Eio.Fiber.fork_daemon ~sw (fun () -> let rec aux () = @@ -95,6 +105,7 @@ let run ~env t = in aux ()) done; + debug "Waiting for test results to come back"; let rec run_test test = let reply, resolve_reply = Eio.Promise.create () in Eio.Stream.add test_stream (test, resolve_reply); @@ -126,6 +137,7 @@ let run ~env t = ; result = None } in + debug "Tests were run to completion. Calculating final stats."; let end_time = Eio.Time.now (Eio.Stdenv.clock env) in let seconds = end_time -. start_time in Test.Printer.stats ~seconds test_results diff --git a/lib/OSnap.mli b/lib/OSnap.mli index cb5fe88..731c16a 100644 --- a/lib/OSnap.mli +++ b/lib/OSnap.mli @@ -1,3 +1,4 @@ +module Logger = OSnap_Logger module Config = OSnap_Config module Browser = OSnap_Browser diff --git a/lib/OSnap_Browser/OSnap_Browser_Launcher.ml b/lib/OSnap_Browser/OSnap_Browser_Launcher.ml index 1aac502..fa6f58b 100644 --- a/lib/OSnap_Browser/OSnap_Browser_Launcher.ml +++ b/lib/OSnap_Browser/OSnap_Browser_Launcher.ml @@ -1,13 +1,24 @@ +module Logger = OSnap_Logger module Websocket = OSnap_Websocket open OSnap_Browser_Types +let debug = Logger.info ~header:"BROWSER" + let make ~sw ~env () = let ( let*? ) = Result.bind in let latest_chromium_revision = OSnap_Browser_Path.get_latest_revision () in + debug + (Printf.sprintf + "Found browser version %s to launch" + (OSnap_Browser_Path.revision_to_version latest_chromium_revision)); let*? () = if not (OSnap_Browser_Download.is_revision_downloaded latest_chromium_revision) - then OSnap_Browser_Download.download ~env latest_chromium_revision - else Result.ok () + then ( + debug "Browser is not downloaded"; + OSnap_Browser_Download.download ~env latest_chromium_revision) + else ( + debug "Browser is already downloaded"; + Result.ok ()) in let base_path = OSnap_Browser_Path.get_chromium_path latest_chromium_revision in let executable = @@ -24,6 +35,7 @@ let make ~sw ~env () = in let process_manager = Eio.Stdenv.process_mgr env in let read_stderr, write_stderr = Eio.Process.pipe process_manager ~sw in + debug (Printf.sprintf "Spawning browser process from %S" executable); let process = Eio.Process.spawn ~stderr:write_stderr @@ -63,8 +75,10 @@ let make ~sw ~env () = ; "--use-mock-keychain" ] in + debug "Launching Browser was successful. Trying to establish a connection"; let rec get_ws_url ~from proc = let line = from |> Eio.Buf_read.line in + debug (Printf.sprintf "CHROME: %S" line); match line with | line when line |> OSnap_Utils.contains_substring ~search:"Cannot start http server" -> @@ -79,7 +93,9 @@ let make ~sw ~env () = in let stderr_buffer = Eio.Buf_read.of_flow read_stderr ~max_size:max_int in let*? url = get_ws_url ~from:stderr_buffer process in + debug (Printf.sprintf "Connecting to: %S" url); let*? () = Websocket.connect ~sw ~env url in + debug (Printf.sprintf "Connected!"); let*? result = let open Cdp.Commands.Target.CreateBrowserContext in Request.make ?sessionId:None ~params:(Params.make ()) diff --git a/lib/OSnap_Browser/dune b/lib/OSnap_Browser/dune index 83522b3..d8d7a69 100644 --- a/lib/OSnap_Browser/dune +++ b/lib/OSnap_Browser/dune @@ -2,6 +2,7 @@ (name OSnap_Browser) (libraries OSnap_Utils + OSnap_Logger OSnap_Websocket unix fmt diff --git a/lib/OSnap_Config/dune b/lib/OSnap_Config/dune index 2726b3b..2ba11df 100644 --- a/lib/OSnap_Config/dune +++ b/lib/OSnap_Config/dune @@ -1,3 +1,3 @@ (library (name OSnap_Config) - (libraries OSnap_Utils eio eio.unix unix re fileutils yaml)) + (libraries OSnap_Logger OSnap_Utils eio eio.unix unix re fileutils yaml)) diff --git a/lib/OSnap_Logger/OSnap_Logger.ml b/lib/OSnap_Logger/OSnap_Logger.ml new file mode 100644 index 0000000..2a4889b --- /dev/null +++ b/lib/OSnap_Logger/OSnap_Logger.ml @@ -0,0 +1,21 @@ +let src = Logs.Src.create "osnap" + +let init style_renderer level = + Fmt_tty.setup_std_outputs ?style_renderer (); + Logs.Src.set_level src level; + Logs.set_reporter (Logs_fmt.reporter ()) +;; + +let debug ~header message = + Logs.debug ~src (fun log -> log ~header "%a" (Fmt.styled `Faint Fmt.string) message) +;; + +let info ~header message = Logs.info ~src (fun log -> log ~header "%a" Fmt.string message) + +let warn ~header message = + Logs.warn ~src (fun log -> log ~header "%a" (Fmt.styled `Yellow Fmt.string) message) +;; + +let error ~header message = + Logs.err ~src (fun log -> log ~header "%a" (Fmt.styled `Red Fmt.string) message) +;; diff --git a/lib/OSnap_Logger/dune b/lib/OSnap_Logger/dune new file mode 100644 index 0000000..e84ca3f --- /dev/null +++ b/lib/OSnap_Logger/dune @@ -0,0 +1,3 @@ +(library + (name OSnap_Logger) + (libraries fmt fmt.cli fmt.tty logs logs.cli logs.fmt)) diff --git a/lib/OSnap_Websocket/OSnap_Websocket.ml b/lib/OSnap_Websocket/OSnap_Websocket.ml index de4381f..b73f85b 100644 --- a/lib/OSnap_Websocket/OSnap_Websocket.ml +++ b/lib/OSnap_Websocket/OSnap_Websocket.ml @@ -20,9 +20,15 @@ let call_event_handlers key message = Hashtbl.remove events key)) ;; +let debug_send = OSnap_Logger.debug ~header:"Websocket >>>" +let debug_recieve = OSnap_Logger.debug ~header:"Websocket <<<" + let websocket_handler recv send = let close () = Websocket.Frame.close 1002 |> send in - let send_payload payload = Websocket.Frame.create ~content:payload () |> send in + let send_payload payload = + debug_send payload; + Websocket.Frame.create ~content:payload () |> send + in let rec input_loop () = let* () = Lwt.pause () in if not (Queue.is_empty pending_requests) @@ -40,6 +46,7 @@ let websocket_handler recv send = | Pong -> Lwt.return () | Text | Binary -> let response = frame.Websocket.Frame.content in + debug_recieve (String.sub response 0 (min (String.length response) 800)); let id = response |> Yojson.Safe.from_string diff --git a/lib/OSnap_Websocket/dune b/lib/OSnap_Websocket/dune index edbfea7..e57971a 100644 --- a/lib/OSnap_Websocket/dune +++ b/lib/OSnap_Websocket/dune @@ -1,6 +1,7 @@ (library (name OSnap_Websocket) (libraries + OSnap_Logger OSnap_Utils conduit-lwt conduit-lwt-unix diff --git a/lib/dune b/lib/dune index 7428e06..6ee8e15 100644 --- a/lib/dune +++ b/lib/dune @@ -5,6 +5,7 @@ OSnap_Test OSnap_Paths OSnap_Utils + OSnap_Logger OSnap_Config OSnap_Browser unix diff --git a/osnap.opam b/osnap.opam index ba7e702..1c42c84 100644 --- a/osnap.opam +++ b/osnap.opam @@ -21,6 +21,7 @@ depends: [ "fileutils" "fmt" "libspng" + "logs" "odiff-core" "re" "uri"