console work

Expecto.Tests/Tests.fs

@@ -1300,7 +1300,7 @@ let cancel =
         use ct = new CancellationTokenSource()
         let! _ = Async.StartChild(async { do! Async.Sleep 50
                                           ct.Cancel() })
-        let! results = evalTestsWithCancel ct.Token config t
+        let! results = evalTestsWithCancel ct.Token config t false
         results |> List.iter (fun (_,r) ->
           let d = int r.duration.TotalMilliseconds
           Expect.isLessThan d 1000 "cancel length"

Expecto/Expecto.fs

@@ -396,6 +396,11 @@ module Impl =
 
   let mutable logger = Log.create "Expecto"
   let setLogName name = logger <- Log.create name
+  let flush (l:Logger) =
+    if l :? IFlushable then
+      ProgressIndicator.pause (fun () ->
+        (l :?> IFlushable).Flush()
+      )
 
   type TestResult =
     | Passed
@@ -953,9 +958,14 @@ module Impl =
       config.parallelWorkers
 
   /// Evaluates tests.
-  let evalTestsWithCancel (ct:CancellationToken) config test =
+  let evalTestsWithCancel (ct:CancellationToken) config test progressStarted =
     async {
 
+      let tests = Test.toTestCodeList test
+      let testLength = List.length tests
+
+      let testsCompleted = ref 0
+
       let evalTestAsync (test:FlatTest) =
 
         let beforeEach (test:FlatTest) =
@@ -966,10 +976,14 @@ module Impl =
           let! result = execTestAsync ct config test
           do! beforeAsync
           do! TestPrinters.printResult config test result
+
+          if progressStarted then
+            Interlocked.Increment(testsCompleted) + testLength/200
+            / testLength |> ProgressIndicator.update
+
           return test,result
         }
 
-      let tests = Test.toTestCodeList test
       let inline cons xs x = x::xs
 
       if not config.``parallel`` ||
@@ -1015,7 +1029,7 @@ module Impl =
 
   /// Evaluates tests.
   let evalTests config test =
-    evalTestsWithCancel CancellationToken.None config test
+    evalTestsWithCancel CancellationToken.None config test false
 
   let evalTestsSilent test =
     let config =
@@ -1031,16 +1045,26 @@ module Impl =
     async {
       do! config.printer.beforeRun test
 
+      ProgressIndicator.text "Expecto Running... "
+      let progressStarted = ProgressIndicator.start()
+
+
       let w = Stopwatch.StartNew()
-      let! results = evalTests config test
+      let! results = evalTestsWithCancel ct config test progressStarted
       w.Stop()
-      let testSummary = { results = results
-                          duration = w.Elapsed
-                          maxMemory = 0L
-                          memoryLimit = 0L
-                          timedOut = [] }
+      let testSummary = {
+        results = results
+        duration = w.Elapsed
+        maxMemory = 0L
+        memoryLimit = 0L
+        timedOut = []
+      }
       do! config.printer.summary config testSummary
 
+      if progressStarted then ProgressIndicator.stop()
+
+      flush logger
+
       return testSummary.errorCode
     }
 
@@ -1052,6 +1076,9 @@ module Impl =
     async {
       do! config.printer.beforeRun test
 
+      ProgressIndicator.text "Expecto Running... "
+      let progressStarted = ProgressIndicator.start()
+
       let tests =
         Test.toTestCodeList test
         |> List.filter (fun t -> Option.isNone t.shouldSkipEvaluation)
@@ -1068,11 +1095,13 @@ module Impl =
         let next = List.length tests |> rand.Next
         List.item next tests
 
-      let finishTimestamp =
-        lazy
+      let totalTicks =
         config.stress.Value.TotalSeconds * float Stopwatch.Frequency
         |> int64
-        |> (+) (Stopwatch.GetTimestamp())
+
+      let finishTime =
+        lazy
+        totalTicks |> (+) (Stopwatch.GetTimestamp())
 
       let asyncRun foldRunner (runningTests:ResizeArray<_>,
                                results,
@@ -1101,7 +1130,7 @@ module Impl =
 
         Async.Start(async {
           let finishMilliseconds =
-            max (finishTimestamp.Value - Stopwatch.GetTimestamp()) 0L
+            max (finishTime.Value - Stopwatch.GetTimestamp()) 0L
             * 1000L / Stopwatch.Frequency
           let timeout =
             int finishMilliseconds + int config.stressTimeout.TotalMilliseconds
@@ -1110,7 +1139,13 @@ module Impl =
         }, cancel.Token)
 
         Seq.takeWhile (fun test ->
-          if Stopwatch.GetTimestamp() < finishTimestamp.Value
+          let now = Stopwatch.GetTimestamp()
+
+          if progressStarted then
+            100 - int((finishTime.Value - now + totalTicks / 200L) / totalTicks)
+            |> ProgressIndicator.update
+
+          if now < finishTime.Value
               && not ct.IsCancellationRequested then
             runningTests.Add test
             true
@@ -1136,7 +1171,7 @@ module Impl =
           |> asyncRun Async.foldSequentiallyWithCancel initial
           |> Async.bind (fun (runningTests,results,maxMemory) ->
                if maxMemory > memoryLimit ||
-                  Stopwatch.GetTimestamp() > finishTimestamp.Value then
+                  Stopwatch.GetTimestamp() > finishTime.Value then
                  async.Return (runningTests,results,maxMemory)
                else
                  let parallel =
@@ -1165,6 +1200,10 @@ module Impl =
 
       do! config.printer.summary config testSummary
 
+      if progressStarted then ProgressIndicator.stop()
+
+      flush logger
+
       return testSummary.errorCode
     }
 
@@ -1640,7 +1679,7 @@ module Tests =
   let runTestsWithCancel (ct:CancellationToken) config (tests:Test) =
     Global.initialiseIfDefault
       { Global.defaultConfig with
-          getLogger = fun name -> LiterateConsoleTarget(name, config.verbosity, consoleSemaphore = Global.semaphore()) :> Logger }
+          getLogger = fun name -> ANSIConsoleLogger(name, config.verbosity, consoleSemaphore = Global.semaphore()) :> Logger }
     config.logName |> Option.iter setLogName
     if config.failOnFocusedTests && passesFocusTestCheck config tests |> not then
       1

Expecto/Expecto.fsproj

@@ -15,6 +15,7 @@
   </PropertyGroup>
   <ItemGroup>
     <Compile Include="AssemblyInfo.fs" />
+    <Compile Include="Progress.fs" />
     <Compile Include="Logging.fs" />
     <Compile Include="Statistics.fs" />
     <Compile Include="Expecto.fs" />

Expecto/Logging.fs

@@ -12,10 +12,12 @@
 ///
 /// Changes:
 ///     Changed namespace to Expecto.Logging and file name to Logging.fs - Anthony Lloyd - 11 Jun 2018
+///     Add IFlushable - Anthony Lloyd - 19 Jun 2018
 ///
 namespace Expecto.Logging
 
 open System
+open System.Text
 
 /// The log level denotes how 'important' the gauge or event message is.
 [<CustomEquality; CustomComparison>]
@@ -293,6 +295,9 @@ module LoggerEx =
 
     // TODO: timeXXX functions
 
+type IFlushable =
+  abstract Flush : unit -> unit
+
 type LoggingConfig =
   { /// The `timestamp` function should preferably be monotonic and not 'jumpy'
     /// or take much time to call.
@@ -936,6 +941,80 @@ type CombiningTarget(name, otherLoggers: Logger list) =
       |> Async.Parallel
       |> Async.Ignore // Async<unit>
 
+type ANSIConsoleLogger(name, minLevel, ?consoleSemaphore) =
+  let sem = defaultArg consoleSemaphore (obj())
+  let options = Literate.LiterateOptions.create()
+  let tokenise = LiterateTokenisation.tokeniseMessage
+  let buffer = StringBuilder()
+
+  let colorForWhite =
+    if Console.BackgroundColor = ConsoleColor.White then "\x1B[90m" else "\x1B[97m"
+  let colorReset = "\x1B[0m"
+
+  let colorANSI = function
+    | ConsoleColor.White -> colorForWhite
+    | ConsoleColor.Gray -> "\x1B[31m"
+    | ConsoleColor.DarkGray -> "\x1B[90m"
+    | ConsoleColor.Yellow -> "\x1B[93m"
+    | ConsoleColor.Red -> "\x1B[91m"
+    | ConsoleColor.Blue -> "\x1B[33m"
+    | ConsoleColor.Magenta -> "\x1B[95m"
+    | ConsoleColor.Cyan -> "\x1B[96m"
+    | ConsoleColor.Green -> "\x1B[92m"
+    | _ -> "\x1B[334m"
+
+  let atomicallyWriteColouredTextToConsole sem (parts: (string * ConsoleColor) list) =
+    lock sem <| fun _ ->
+      let mutable currentColour = Console.ForegroundColor
+      parts |> List.iter (fun (text, colour) ->
+        if currentColour <> colour then
+          colorANSI colour |> buffer.Append |> ignore
+          currentColour <- colour
+        buffer.Append text |> ignore
+      )
+      buffer.Append colorReset |> ignore
+
+  let atomicallyWriteTextToConsole sem (parts: (string * ConsoleColor) list) =
+    lock sem <| fun _ ->
+      parts |> List.iter (fun (text, _) ->
+        buffer.Append text |> ignore
+      )
+
+  let textToBuffer =
+    if Console.IsOutputRedirected then atomicallyWriteTextToConsole
+    else atomicallyWriteColouredTextToConsole
+
+  let writeColourisedThenNewLine message =
+    [ yield! tokenise options message
+      yield Environment.NewLine, Literate.Text ]
+    |> List.map (fun (s, t) -> s, options.theme(t))
+    |> textToBuffer sem
+
+  interface IFlushable with
+    member __.Flush() =
+      lock sem (fun _ ->
+        buffer.ToString() |> Console.Write
+        buffer.Clear() |> ignore
+      )
+
+  interface Logger with
+    member __.name = name
+    member x.logWithAck level msgFactory =
+      if level >= minLevel then
+        writeColourisedThenNewLine (msgFactory level)
+        Expecto.ProgressIndicator.pause (fun () ->
+            (x :> IFlushable).Flush()
+          )
+      async.Return()
+    member x.log level msgFactory =
+      if level >= minLevel then
+        writeColourisedThenNewLine (msgFactory level)
+        if level=Error then
+          Expecto.ProgressIndicator.pause (fun () ->
+            (x :> IFlushable).Flush()
+          )
+      async.Return()
+
 module Global =
   /// This is the global semaphore for colourising the console output. Ensure
   /// that the same semaphore is used across libraries by using the Logary
@@ -945,7 +1024,7 @@ module Global =
   /// The global default configuration, which logs to Console at Info level.
   let defaultConfig =
     { timestamp        = fun () -> DateTimeOffset.timestamp DateTimeOffset.UtcNow
-      getLogger        = fun name -> LiterateConsoleTarget(name, Info) :> Logger
+      getLogger        = fun name -> ANSIConsoleLogger(name, Info) :> Logger
       consoleSemaphore = consoleSemaphore }
 
   let private config =
@@ -980,6 +1059,10 @@ module Global =
       member x.logWithAck level msgFactory =
         withLogger (fun logger -> logger.logWithAck level (msgFactory >> ensureName))
 
+    interface IFlushable with
+      member __.Flush() =
+        if logger :? IFlushable then (logger :?> IFlushable).Flush()
+
   let internal getStaticLogger (name: string []) =
     Flyweight name
 

Expecto/Progress.fs

@@ -0,0 +1,70 @@
+namespace Expecto
+
+open System
+open System.Threading
+
+module internal ProgressIndicator =
+
+  let private hideCursor = "\x1B[?25l"
+  let private showCursor = "\x1B[?25h"
+  let private animation = @"|/-\"
+
+  let mutable private textValue = String.Empty
+  let mutable private eraseLine = String.Empty
+  let private percentValue = ref 0
+  let private isRunning = ref false
+
+  let text s =
+    textValue <- s
+    let lineLength = textValue.Length + 7
+    eraseLine <- String('\b', lineLength)
+
+  let update percent =
+    percentValue := max percent 0 |> min 100
+
+  let start() =
+    lock isRunning (fun () ->
+      if !isRunning then false
+      else
+        isRunning := true
+        if not Console.IsOutputRedirected then
+          hideCursor |> stdout.Write
+          Thread(fun () ->
+              let start = DateTime.UtcNow
+              while !isRunning do
+                lock isRunning (fun () ->
+                  if !isRunning then
+                    let p = !percentValue
+                    let t = (DateTime.UtcNow - start).TotalSeconds
+                    let a = animation.[int t % animation.Length]
+                    let percent =
+                      if p=100 then [|'1';'0';'0';'%';' ';a|]
+                      elif p<10 then [|' ';' ';char(48+p);'%';' ';a|]
+                      else [|' ';char(48+p/10);char(48+p%10);'%';' ';a|]
+                    eraseLine + textValue + String percent + eraseLine |> stdout.Write
+                    Console.Out.Flush()
+                )
+                Thread.Sleep 250
+          ).Start()
+        true
+    )
+
+  let stop() =
+    lock isRunning (fun() ->
+      if !isRunning then
+        isRunning := false
+        if not Console.IsOutputRedirected then
+          eraseLine + String(' ', eraseLine.Length) + eraseLine + showCursor |> stdout.Write
+          Console.Out.Flush()
+    )
+
+  let pause f =
+    lock isRunning (fun () ->
+      if !isRunning then
+        stop(); f(); start() |> ignore
+      else f()
+    )
+
+// TODO
+// 123/199 tests
+// test output, where can I be