add a logger that includes exception traceback, and wrap `Thread.@thr…

…eads` loops with it

* `Log.exception()` is like `Log.error()`, but includes exception information. Inspired by Python's
  `logging.exception()` and such.

* Since exceptions inside threads are silently swallowed right now
  (JuliaLang/julia#17532), always wrap the body of a `Thread.@threads`
  call with a try-catch that manually logs the exception.

src/Log.jl

@@ -26,5 +26,31 @@ end
 # In production mode, rather the development mode, don't log debug statements
 @inline debug(msg...) = is_production_run || ntputs(nodeid, threadid(), "DEBUG: ", msg...)
 
+# Like `error()`, but include exception info and stack trace. Should only be called from a `catch`
+# block, e.g.,
+# try
+#   ...
+# catch ex
+#   Log.exception(ex, catch_stacktrace(), "Something happened %s", some_var)
+# end
+function exception(exception::Exception, msg...)
+    if length(msg) > 0
+        error(msg...)
+    end
+    error(exception)
+    error("Stack trace:")
+    stack_trace = catch_stacktrace()
+    if length(stack_trace) > 100
+        stack_trace = vcat(
+            [string(line) for line in stack_trace[1:50]],
+            @sprintf("...(removed %d frames)...", length(stack_trace) - 100),
+            [string(line) for line in stack_trace[(length(stack_trace) - 50):length(stack_trace)]],
+        )
+    end
+    for stack_line in stack_trace
+        error(@sprintf("  %s", stack_line))
+    end
+end
+
 end
 

src/SDSSIO.jl

@@ -338,7 +338,12 @@ function load_field_images(rcfs, stagedir)
     images = Vector{Image}(N)
 
     Threads.@threads for n in 1:N
-        images[n] = convert(Image, raw_images[n])
+        try
+            images[n] = convert(Image, raw_images[n])
+        catch exc
+            Log.exception(exc)
+            rethrow()
+        end
     end
 
     return images

src/joint_infer.jl

@@ -317,12 +317,17 @@ function initialize_elboargs_sources!(ea_vec, cfg_vec, thread_initialize_sources
                                       trust_region, use_fft, min_radius_pix,
                                       target_source_variational_params)
     Threads.@threads for i in 1:nthreads()
-        for batch in 1:length(thread_initialize_sources_assignment[i])
-            initialize_elboargs_sources_kernel!(ea_vec, cfg_vec,
-                                                thread_initialize_sources_assignment[i][batch],
-                                                catalog, target_sources, neighbor_map, images,
-                                                trust_region, use_fft, min_radius_pix,
-                                                target_source_variational_params)
+        try
+            for batch in 1:length(thread_initialize_sources_assignment[i])
+                initialize_elboargs_sources_kernel!(ea_vec, cfg_vec,
+                                                    thread_initialize_sources_assignment[i][batch],
+                                                    catalog, target_sources, neighbor_map, images,
+                                                    trust_region, use_fft, min_radius_pix,
+                                                    target_source_variational_params)
+            end
+        catch ex
+            Log.exception(ex)
+            rethrow()
         end
     end
 end
@@ -393,11 +398,16 @@ function process_sources!(images::Vector{Model.Image},
             process_sources_elapsed_times::Vector{Float64} = Vector{Float64}(n_threads)
             # Process every batch of every iteration with n_threads
             Threads.@threads for i in 1:n_threads
-                tic()
-                process_sources_kernel!(images, ea_vec, cfg_vec,
-                                        thread_sources_assignment[i::Int][batch::Int],
-                                        iter, use_fft, within_batch_shuffling)
-                process_sources_elapsed_times[i::Int] = toq()
+                try
+                    tic()
+                    process_sources_kernel!(images, ea_vec, cfg_vec,
+                                            thread_sources_assignment[i::Int][batch::Int],
+                                            iter, use_fft, within_batch_shuffling)
+                    process_sources_elapsed_times[i::Int] = toq()
+                catch exc
+                    Log.exception(exc)
+                    rethrow()
+                end
             end
             Log.info("Batch $(batch) - $(process_sources_elapsed_times)")
         end