Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve error reporting #2423

Merged
merged 25 commits into from
Jun 16, 2017
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
25 commits
Select commit Hold shift + click to select a range
117a1ea
partial work...
matthid Jun 13, 2017
8df0ed5
Merge remote-tracking branch 'origin/master' into improve_error_repor…
matthid Jun 15, 2017
6e74c7c
finish initial proper error reporting
matthid Jun 15, 2017
d315ec9
fix some random change
matthid Jun 15, 2017
ea32f48
fix another random change
matthid Jun 15, 2017
a20a6c5
fix Async.tryFind in special case of single item.
matthid Jun 15, 2017
fa2f230
change integration test suite to print output when the process timed …
matthid Jun 15, 2017
966b38e
print more exception informations & use this to forward NuGet errors …
matthid Jun 15, 2017
b4f9550
reduce nesting via ->
matthid Jun 15, 2017
bf2abbc
add missing newline
matthid Jun 15, 2017
6d10d98
fix Installtion Errors message
matthid Jun 15, 2017
88f6b3a
properly forward exception details.
matthid Jun 15, 2017
ecc8be4
fix newline location
matthid Jun 15, 2017
5e16733
' - ' is already given by the exception structure, remove it from th…
matthid Jun 15, 2017
c80c66a
generalize error handling and improve aggregateexception output
matthid Jun 15, 2017
9224d4c
fix endless loop
matthid Jun 15, 2017
07f320b
skip 'Exception: ' as it doesn't yield any information.
matthid Jun 15, 2017
0025b85
handle some other cases where error information is hidden
matthid Jun 15, 2017
79736fd
minor output improvement.
matthid Jun 15, 2017
ee7d1ff
track errors into the conflict-state and print them out if resolution…
matthid Jun 15, 2017
53c2063
use a different strategy and warn when resolution was OK.
matthid Jun 15, 2017
73bce52
fix a bug in the runtime resolution.
matthid Jun 15, 2017
e8f3067
minor output improvement.
matthid Jun 15, 2017
3cf9654
remove 'AggregateException: ' as well (this information can be inferr…
matthid Jun 15, 2017
c00d52d
add 'PAKET_DETAILED_ERRORS' feature, this will always print stacktrac…
matthid Jun 15, 2017
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
35 changes: 23 additions & 12 deletions integrationtests/Paket.IntegrationTests/TestHelper.fs
Original file line number Diff line number Diff line change
Expand Up @@ -72,20 +72,26 @@ let directPaketInPath command scenarioPath =
perfMessages.Add(msg)

msgs.Add((isError, msg))
if isError then
printfn "ERR: %s" msg
//else printfn "%s" msg

let result =
ExecProcessWithLambdas (fun info ->
info.FileName <- paketToolPath
info.WorkingDirectory <- scenarioPath
info.Arguments <- command)
(System.TimeSpan.FromMinutes 7.)
true
(addAndPrint true)
(addAndPrint false)

try
ExecProcessWithLambdas (fun info ->
info.FileName <- paketToolPath
info.WorkingDirectory <- scenarioPath
info.Arguments <- command)
(System.TimeSpan.FromMinutes 7.)
true
(addAndPrint true)
(addAndPrint false)
with exn ->
if exn.Message.Contains "timed out" then
printfn "PROCESS TIMED OUT, OUTPUT WAS: "
else
printfn "ExecProcessWithLambdas failed. Output was: "

for isError, msg in msgs do
printfn "%s%s" (if isError then "ERR: " else "") msg
reraise()
// Only throw after the result <> 0 check because the current test might check the argument parsing
// this is the only case where no performance is printed
let isUsageError = result <> 0 && msgs |> Seq.filter fst |> Seq.map snd |> Seq.exists (fun msg -> msg.Contains "USAGE:")
Expand All @@ -96,6 +102,11 @@ let directPaketInPath command scenarioPath =
for msg in perfMessages do
printfn "%s" msg

// always print stderr
for isError, msg in msgs do
if isError then
printfn "ERR: %s" msg

if result <> 0 then
let errors = String.Join(Environment.NewLine,msgs |> Seq.filter fst |> Seq.map snd)
failwith errors
Expand Down
50 changes: 32 additions & 18 deletions src/Paket.Core/Common/Async.fs
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ open System.Threading
[<AutoOpen>]
module AsyncExtensions =
open System
open System.Threading.Tasks

type Microsoft.FSharp.Control.Async with
/// Runs both computations in parallel and returns the result as a tuple.
Expand All @@ -17,34 +18,47 @@ module AsyncExtensions =
let! b'' = b'
return (a'',b'')
}

static member Choice(tasks : Async<'T option> seq) = async {
static member map f a =
async { return f a }
static member tryFind (f : 'T -> bool) (tasks : Async<'T> seq) = async {
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is an interesting API.
It is almost like Async.Choice, but will return all the started tasks and an index which one matched the given function.

match Seq.toArray tasks with
| [||] -> return None
| [|t|] -> return! t
| [||] -> return [||], None
| [|t|] ->
let! res = t
let task = Task.FromResult res
return if f res then [|task|], Some 0 else [|task|], None
| tasks ->

let! t = Async.CancellationToken
return! Async.FromContinuations <|
fun (sc,ec,cc) ->
let noneCount = ref 0
let currentIndex = ref 0
let exnCount = ref 0
let innerCts = CancellationTokenSource.CreateLinkedTokenSource t

let scont (result : 'T option) =
match result with
| Some _ when Interlocked.Increment exnCount = 1 -> innerCts.Cancel() ; sc result
| None when Interlocked.Increment noneCount = tasks.Length -> sc None
let results = Array.init tasks.Length (fun _ -> TaskCompletionSource<'T>())
let retResults = results |> Array.map (fun tcs -> tcs.Task)

let scont index (result : 'T) =
results.[index].TrySetResult result |> ignore
match f result with
| true when Interlocked.Increment exnCount = 1 ->
innerCts.Cancel()
sc (retResults, (Some index))
| false when Interlocked.Increment currentIndex = tasks.Length ->
sc (retResults,None)
| _ -> ()

let econt (exn : exn) =

let econt index (exn : exn) =
results.[index].TrySetException exn |> ignore
if Interlocked.Increment exnCount = 1 then
innerCts.Cancel() ; ec exn

let ccont (exn : OperationCanceledException) =

let ccont index (exn : OperationCanceledException) =
results.[index].TrySetCanceled () |> ignore
if Interlocked.Increment exnCount = 1 then
innerCts.Cancel(); cc exn

for task in tasks do
ignore <| System.Threading.Tasks.Task.Factory.StartNew(fun () -> Async.StartWithContinuations(task, scont, econt, ccont, innerCts.Token))

for i, task in tasks |> Seq.mapi (fun i t -> i, t) do
ignore <| System.Threading.Tasks.Task.Factory.StartNew(fun () ->
Async.StartWithContinuations(task, scont i, econt i, ccont i, innerCts.Token))
}
58 changes: 57 additions & 1 deletion src/Paket.Core/Common/Logging.fs
Original file line number Diff line number Diff line change
Expand Up @@ -98,4 +98,60 @@ let setLogFile fileName =
else
if fi.Directory.Exists |> not then
fi.Directory.Create()
event.Publish |> Observable.subscribe traceToFile
event.Publish |> Observable.subscribe traceToFile

/// [omit]
[<RequireQualifiedAccess>]
type private ExnType =
| First
| Aggregated
| Inner

/// [omit]
let printErrorExt printFirstStack printAggregatedStacks printInnerStacks (exn:exn) =
let defaultMessage = AggregateException().Message
let rec printErrorHelper exnType useArrow indent (exn:exn) =
let handleError () =
let s = if useArrow then "->" else "- "
let indentString = new String('\t', indent)
let splitMsg = exn.Message.Split([|"\r\n"; "\n"|], StringSplitOptions.None)
let typeString =
let t = exn.GetType()
if t = typeof<Exception> || t = typeof<AggregateException> then
""
else sprintf "%s: " t.Name
traceErrorfn "%s%s %s%s" indentString s typeString (String.Join(sprintf "%s%s " Environment.NewLine indentString , splitMsg))
let printStack =
match String.IsNullOrWhiteSpace exn.StackTrace, exnType with
| false, ExnType.First when printFirstStack -> true
| false, ExnType.Aggregated when printAggregatedStacks -> true
| false, ExnType.Inner when printInnerStacks -> true
| _ -> false
if printStack then
traceErrorfn "%s StackTrace:" indentString
let split = exn.StackTrace.Split([|"\r\n"; "\n"|], StringSplitOptions.None)
traceErrorfn "%s %s" indentString (String.Join(sprintf "%s%s " Environment.NewLine indentString, split))
match exn with
| :? AggregateException as aggr ->
if aggr.InnerExceptions.Count = 1 then
let inner = aggr.InnerExceptions.[0]
if aggr.Message = defaultMessage || aggr.Message = inner.Message then
// skip as no new information is available.
printErrorHelper exnType useArrow indent inner
else
handleError()
printErrorHelper ExnType.Aggregated true indent inner
else
handleError()
for inner in aggr.InnerExceptions do
printErrorHelper ExnType.Aggregated false (indent + 1) inner
| _ ->
handleError()
if not (isNull exn.InnerException) then
printErrorHelper ExnType.Inner true indent exn.InnerException

printErrorHelper ExnType.First true 0 exn

/// [omit]
let printError (exn:exn) =
printErrorExt verbose verbose false exn
6 changes: 5 additions & 1 deletion src/Paket.Core/Common/Logging.fsi
Original file line number Diff line number Diff line change
Expand Up @@ -36,4 +36,8 @@ val event : Event<Trace>

val traceToConsole : Trace -> unit

val setLogFile : string -> IDisposable
val setLogFile : string -> IDisposable

val printError : exn -> unit

val printErrorExt : printFirstStack:bool -> printAggregatedStacks:bool -> printInnerStacks:bool -> exn -> unit
29 changes: 12 additions & 17 deletions src/Paket.Core/Common/Utils.fs
Original file line number Diff line number Diff line change
Expand Up @@ -545,11 +545,6 @@ open System.Diagnostics
open System.Threading
open System.Collections.Generic

let innerText (exn:Exception) =
match exn.InnerException with
| null -> ""
| exn -> Environment.NewLine + " Details: " + exn.Message

/// [omit]
let downloadFromUrl (auth:Auth option, url : string) (filePath: string) =
async {
Expand All @@ -560,7 +555,7 @@ let downloadFromUrl (auth:Auth option, url : string) (filePath: string) =
do! task
with
| exn ->
failwithf "Could not download from %s%s Message: %s%s" url Environment.NewLine exn.Message (innerText exn)
raise <| Exception(sprintf "Could not download from '%s'" url, exn)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We almost never should do failwithf in a general with exn -> clause, not even when we embed the message (like here)...
I really think F# should make this more easy (with some syntax), even the F# compiler is doing it wrong everywhere

/cc @dsyme any ideas?
maybe allowing to use comma in combination with failwithf "some message", innerException

}

/// [omit]
Expand All @@ -575,8 +570,8 @@ let getFromUrl (auth:Auth option, url : string, contentType : string) =
return! client.DownloadStringTaskAsync (Uri url) |> Async.AwaitTask
with
| exn ->
failwithf "Could not retrieve data from %s%s Message: %s%s" url Environment.NewLine exn.Message (innerText exn)
return ""
return raise <| Exception(sprintf "Could not retrieve data from '%s'" url, exn)

}

let getXmlFromUrl (auth:Auth option, url : string) =
Expand All @@ -593,8 +588,7 @@ let getXmlFromUrl (auth:Auth option, url : string) =
return! client.DownloadStringTaskAsync (Uri url) |> Async.AwaitTask
with
| exn ->
failwithf "Could not retrieve data from %s%s Message: %s%s" url Environment.NewLine exn.Message (innerText exn)
return ""
return raise <| Exception(sprintf "Could not retrieve data from '%s'" url, exn)
}

/// [omit]
Expand All @@ -612,11 +606,12 @@ let safeGetFromUrl (auth:Auth option, url : string, contentType : string) =
#endif
use _ = Profile.startCategory Profile.Category.NuGetRequest
let! raw = client.DownloadStringTaskAsync(uri) |> Async.AwaitTask
return Some raw
return FSharp.Core.Result.Ok raw
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe I should use full-out exceptions everywhere :/

with e ->
if verbose then
Logging.verbosefn "Error while retrieving '%s': %O" url e
return None
let cap = System.Runtime.ExceptionServices.ExceptionDispatchInfo.Capture e
return FSharp.Core.Result.Error cap
}

let mutable autoAnswer = None
Expand Down Expand Up @@ -689,15 +684,15 @@ let RunInLockedAccessMode(rootFolder,action) =
waitForUnlocked 0
File.WriteAllText(fileName, string p.Id)
with
| exn when exn.Message = "timeout" ->
failwithf "Could not acquire lock to %s.%sThe process timed out." fileName Environment.NewLine
| exn ->
| exn when exn.Message = "timeout" ->
failwithf "Could not acquire lock to '%s'.%sThe process timed out." fileName Environment.NewLine
| exn ->
if trials > 0 then
let trials = trials - 1
tracefn "Could not acquire lock to %s.%s%s%sTrials left: %d." fileName Environment.NewLine exn.Message Environment.NewLine trials
acquireLock startTime timeOut trials
else
failwithf "Could not acquire lock to %s.%s%s" fileName Environment.NewLine exn.Message
raise <| Exception(sprintf "Could not acquire lock to '%s'." fileName, exn)

let rec releaseLock() =
try
Expand Down Expand Up @@ -840,7 +835,7 @@ let parseKeyValuePairs (s:string) : Dictionary<string,string> =
d
with
| exn ->
failwithf "Could not parse %s as key/value pairs.%s%s" s Environment.NewLine exn.Message
raise <| Exception(sprintf "Could not parse '%s' as key/value pairs." s, exn)

let downloadStringSync (url : string) (client : WebClient) =
try
Expand Down
20 changes: 11 additions & 9 deletions src/Paket.Core/Dependencies/GitCommandHelper.fs
Original file line number Diff line number Diff line change
Expand Up @@ -167,17 +167,19 @@ let ExecProcessWithLambdas configProcessStartInfoF (timeOut : TimeSpan) silent e
if d.Data <> null then messageF d.Data)
try
start proc
with exn -> failwithf "Start of process %s failed. %s" proc.StartInfo.FileName exn.Message
with exn -> raise <| Exception(sprintf "Start of process %s failed." proc.StartInfo.FileName, exn)
if silent then
proc.BeginErrorReadLine()
proc.BeginOutputReadLine()
if timeOut = TimeSpan.MaxValue then proc.WaitForExit()
else
if not <| proc.WaitForExit(int timeOut.TotalMilliseconds) then
try
proc.Kill()
with exn -> ()
failwithf "Process %s %s timed out." proc.StartInfo.FileName proc.StartInfo.Arguments
let inner =
try
proc.Kill()
null
with exn -> exn
raise <| Exception(sprintf "Process %s %s timed out." proc.StartInfo.FileName proc.StartInfo.Arguments, inner)
proc.ExitCode


Expand Down Expand Up @@ -234,7 +236,7 @@ let fireAndForget configProcessStartInfoF =
configProcessStartInfoF proc.StartInfo
try
start proc
with exn -> failwithf "Start of process %s failed. %s" proc.StartInfo.FileName exn.Message
with exn -> raise <| Exception(sprintf "Start of process %s failed." proc.StartInfo.FileName, exn)

/// Fires the given git command ind the given repository directory and returns immediatly.
let fireAndForgetGitCommand repositoryDir command =
Expand All @@ -250,7 +252,7 @@ let directExec configProcessStartInfoF =
configProcessStartInfoF proc.StartInfo
try
start proc
with exn -> failwithf "Start of process %s failed. %s" proc.StartInfo.FileName exn.Message
with exn -> raise <| Exception(sprintf "Start of process %s failed." proc.StartInfo.FileName, exn)
proc.WaitForExit()
proc.ExitCode = 0

Expand Down Expand Up @@ -286,7 +288,7 @@ let runFullGitCommand repositoryDir command =
msg |> Seq.iter (tracefn "%s")
msg |> Seq.toArray
with
| exn -> failwithf "Could not run \"git %s\".\r\nError: %s" command exn.Message
| exn -> raise <| Exception(sprintf "Could not run \"git %s\"." command, exn)

/// Runs the git command and returns the first line of the result.
let runSimpleGitCommand repositoryDir command =
Expand All @@ -302,4 +304,4 @@ let runSimpleGitCommand repositoryDir command =
msg |> Seq.iter (tracefn "%s")
msg.[0]
with
| exn -> failwithf "Could not run \"git %s\".\r\nError: %s" command exn.Message
| exn -> raise <| Exception(sprintf "Could not run \"git %s\"." command, exn)
Loading