@@ -106,8 +106,14 @@ def get_active_slice_indices(
106106 A set of integers representing the indices of the active slices.
107107 """
108108 if slice_to_devices is None :
109+ _logger .debug ("slice_to_devices is None. Getting from jax.devices()." )
109110 slice_to_devices = get_slice_to_devices (tuple (jax .devices ()))
110111
112+ _logger .debug (
113+ "Getting active slice indices for slices: %s" ,
114+ sorted (list (slice_to_devices .keys ())),
115+ )
116+
111117 active_slice_indices = set ()
112118
113119 results = {
@@ -116,17 +122,19 @@ def get_active_slice_indices(
116122 }
117123
118124 for slice_index , x in results .items ():
119- _logger .info ("Checking slice_index=%s" , slice_index )
125+ _logger .debug ("Checking slice_index=%s" , slice_index )
120126 expected = (
121127 np .zeros (len (slice_to_devices [slice_index ]), dtype = float )
122128 + _SIMPLE_EXECUTION_TEST_VALUE
123129 )
124130 try :
125131 with timing .Timer (f"Checking { slice_index = } " ):
132+ _logger .debug ("Blocking until ready for slice_index=%s" , slice_index )
126133 jax .block_until_ready (x )
134+ _logger .debug ("Execution finished for slice_index=%s" , slice_index )
127135 if np .allclose (x , expected ):
128136 active_slice_indices .add (slice_index )
129- _logger .info ("slice_index=%s active" , slice_index )
137+ _logger .debug ("slice_index=%s active" , slice_index )
130138 else :
131139 _logger .error (
132140 "Error with _simple_execution for slice_index=%s. "
@@ -140,8 +148,9 @@ def get_active_slice_indices(
140148 )
141149 except jax .errors .JaxRuntimeError as error :
142150 if not is_error_due_to_slice_down (error ):
151+ _logger .info ("Re-raising error for slice_index=%s" , slice_index )
143152 raise
144- _logger .info ("slice_index=%s bad" , slice_index )
153+ _logger .debug ("slice_index=%s bad" , slice_index )
145154
146155 _logger .info ("active_slice_indices=%s" , active_slice_indices )
147156
@@ -174,22 +183,36 @@ def wait_for_slices(
174183 active.
175184 """
176185 if slice_to_devices is None :
186+ _logger .debug ("slice_to_devices is None. Getting from jax.devices()." )
177187 slice_to_devices = get_slice_to_devices (jax .devices ())
178188
189+ _logger .info (
190+ "Waiting for %s slices. Poll interval: %s, Timeout: %s" ,
191+ slice_count ,
192+ poll_interval ,
193+ timeout ,
194+ )
179195 start_time = time .time ()
180196
181197 while True :
182198 check_start_time = time .time ()
183199
200+ _logger .debug ("Checking active slices..." )
184201 active_slice_indices = get_active_slice_indices (slice_to_devices )
185202 if len (active_slice_indices ) >= slice_count :
186- _logger .info ("%s slices active." , len (active_slice_indices ))
203+ _logger .info (
204+ "Sufficient slices active: %s >= %s. Active indices: %s" ,
205+ len (active_slice_indices ),
206+ slice_count ,
207+ active_slice_indices ,
208+ )
187209 return active_slice_indices
188210
189211 _logger .info (
190- "%s slices active. Wanting at least %s." ,
212+ "%s slices active. Wanting at least %s. Active indices: %s " ,
191213 len (active_slice_indices ),
192214 slice_count ,
215+ active_slice_indices ,
193216 )
194217
195218 time_to_sleep = max (0 , poll_interval - (time .time () - check_start_time ))
@@ -206,7 +229,7 @@ def wait_for_slices(
206229 )
207230
208231 if time_to_sleep > 0 :
209- _logger .info ("Sleeping for %.2f seconds." , time_to_sleep )
232+ _logger .debug ("Sleeping for %.2f seconds." , time_to_sleep )
210233
211234 time .sleep (time_to_sleep )
212235
@@ -228,10 +251,14 @@ def is_error_due_to_slice_down(error: Exception) -> bool:
228251 traceback_logging_level = logging .DEBUG
229252
230253 if isinstance (error , jax .errors .JaxRuntimeError ):
254+ _logger .debug ("Checking if JaxRuntimeError is due to slice down: %s" , error )
231255 if any (
232256 error_type in str (error ) for error_type in _ELASTIC_DOWN_ERROR_TYPES
233257 ):
234- _logger .info ("Caught an error due to slice down" )
258+ _logger .debug (
259+ "Caught an error due to slice down (matched"
260+ " _ELASTIC_DOWN_ERROR_TYPES)"
261+ )
235262
236263 error_due_to_slice_down = True
237264
@@ -240,15 +267,16 @@ def is_error_due_to_slice_down(error: Exception) -> bool:
240267 for error_type in _ELASTIC_DOWN_ADDITIONAL_ERROR_TYPES
241268 ):
242269 _logger .warning (
243- "Caught an error due that may or may not be due to slice down. This"
244- " error will be treated as due to slice down."
270+ "Caught an error that may or may not be due to slice down (matched"
271+ " _ELASTIC_DOWN_ADDITIONAL_ERROR_TYPES). This error will be treated"
272+ " as due to slice down."
245273 )
246274 traceback_logging_level = logging .WARNING
247275
248276 error_due_to_slice_down = True
249277
250278 if not error_due_to_slice_down :
251- _logger .info ("Caught an error not due to slice down" )
279+ _logger .debug ("Caught an error not due to slice down" )
252280
253281 _logger .log (traceback_logging_level , "Error details:" , exc_info = True )
254282
0 commit comments