From d0546a4f554bbd90dd395b09ddfb6466b610a642 Mon Sep 17 00:00:00 2001
From: Samuel Williams <samuel.williams@oriontransfer.co.nz>
Date: Sat, 10 Apr 2021 13:23:56 +1200
Subject: [PATCH] Don't use `self.logger` for logging.

The `@logger` should only be used for carrying logger state between parent
and child tasks. But using it directly for logging is likely to produce
inconsistent output because the methods of the task might not execute in the
scope of the fiber itself. In the future, we hope it would be possible to
remove this variable completely and instead have a more direct relationship
between parent and child fiber locals.
---
 lib/async/reactor.rb | 13 +++++--------
 lib/async/task.rb    | 16 +++++++---------
 2 files changed, 12 insertions(+), 17 deletions(-)

diff --git a/lib/async/reactor.rb b/lib/async/reactor.rb
index 33095227..d6cde33e 100644
--- a/lib/async/reactor.rb
+++ b/lib/async/reactor.rb
@@ -94,6 +94,7 @@ def initialize(parent = nil, selector: self.class.selector, logger: nil)
 		end
 		
 		attr :scheduler
+		attr :logger
 		
 		# @reentrant Not thread safe.
 		def block(blocker, timeout)
@@ -133,10 +134,6 @@ def fiber(&block)
 			end
 		end
 		
-		def logger
-			@logger || Console.logger
-		end
-		
 		def to_s
 			"\#<#{self.description} #{@children&.size || 0} children (#{stopped? ? 'stopped' : 'running'})>"
 		end
@@ -165,7 +162,7 @@ def async(*arguments, **options, &block)
 			# - Avoid scheduler overhead if no blocking operation is performed.
 			task.run(*arguments)
 			
-			# logger.debug "Initial execution of task #{fiber} complete (#{result} -> #{fiber.alive?})..."
+			# Console.logger.debug "Initial execution of task #{fiber} complete (#{result} -> #{fiber.alive?})..."
 			return task
 		end
 		
@@ -208,7 +205,7 @@ def finished?
 		# @param timeout [Float | nil] the maximum timeout, or if nil, indefinite.
 		# @return [Boolean] whether there is more work to do.
 		def run_once(timeout = nil)
-			# logger.debug(self) {"@ready = #{@ready} @running = #{@running}"}
+			# Console.logger.debug(self) {"@ready = #{@ready} @running = #{@running}"}
 			
 			if @ready.any?
 				# running used to correctly answer on `finished?`, and to reuse Array object.
@@ -256,7 +253,7 @@ def run_once(timeout = nil)
 				interval = timeout
 			end
 			
-			# logger.info(self) {"Selecting with #{@children&.size} children with interval = #{interval ? interval.round(2) : 'infinite'}..."}
+			# Console.logger.info(self) {"Selecting with #{@children&.size} children with interval = #{interval ? interval.round(2) : 'infinite'}..."}
 			if monitors = @selector.select(interval)
 				monitors.each do |monitor|
 					monitor.value.resume
@@ -293,7 +290,7 @@ def run(*arguments, **options, &block)
 			return initial_task
 		ensure
 			@scheduler&.clear!
-			logger.debug(self) {"Exiting run-loop because #{$! ? $! : 'finished'}."}
+			Console.logger.debug(self) {"Exiting run-loop because #{$! ? $! : 'finished'}."}
 		end
 		
 		def stop(later = true)
diff --git a/lib/async/task.rb b/lib/async/task.rb
index 765ebccc..e49c763c 100644
--- a/lib/async/task.rb
+++ b/lib/async/task.rb
@@ -81,11 +81,13 @@ def initialize(reactor, parent = Task.current?, logger: nil, finished: nil, **op
 			@result = nil
 			@finished = finished
 			
-			@logger = logger || parent&.instance_variable_get(:@logger)
+			@logger = logger || @parent.logger
 			
 			@fiber = make_fiber(&block)
 		end
 		
+		attr :logger
+		
 		if Fiber.current.respond_to?(:backtrace)
 			def backtrace(*arguments)
 				@fiber&.backtrace(*arguments)
@@ -96,10 +98,6 @@ def to_s
 			"\#<#{self.description} (#{@status})>"
 		end
 		
-		def logger
-			@logger || Console.logger
-		end
-		
 		# @attr ios [Reactor] The reactor the task was created within.
 		attr :reactor
 		
@@ -242,9 +240,9 @@ def fail!(exception = nil, propagate = true)
 				raise
 			elsif @finished.nil?
 				# If no one has called wait, we log this as an error:
-				logger.error(self) {$!}
+				Console.logger.error(self) {$!}
 			else
-				logger.debug(self) {$!}
+				Console.logger.debug(self) {$!}
 			end
 		end
 		
@@ -264,7 +262,7 @@ def make_fiber(&block)
 				begin
 					@result = yield(self, *arguments)
 					@status = :complete
-					# logger.debug(self) {"Task was completed with #{@children.size} children!"}
+					# Console.logger.debug(self) {"Task was completed with #{@children.size} children!"}
 				rescue Stop
 					stop!
 				rescue StandardError => error
@@ -272,7 +270,7 @@ def make_fiber(&block)
 				rescue Exception => exception
 					fail!(exception, true)
 				ensure
-					# logger.debug(self) {"Task ensure $!=#{$!} with #{@children.size} children!"}
+					# Console.logger.debug(self) {"Task ensure $!=#{$!} with #{@children.size} children!"}
 					finish!
 				end
 			end