runner.odin 27 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820
  1. //+private
  2. package testing
  3. import "base:intrinsics"
  4. import "base:runtime"
  5. import "core:bytes"
  6. import "core:encoding/ansi"
  7. @require import "core:encoding/base64"
  8. import "core:fmt"
  9. import "core:io"
  10. @require import pkg_log "core:log"
  11. import "core:mem"
  12. import "core:os"
  13. import "core:slice"
  14. @require import "core:strings"
  15. import "core:sync/chan"
  16. import "core:thread"
  17. import "core:time"
  18. // Specify how many threads to use when running tests.
  19. TEST_THREADS : int : #config(ODIN_TEST_THREADS, 0)
  20. // Track the memory used by each test.
  21. TRACKING_MEMORY : bool : #config(ODIN_TEST_TRACK_MEMORY, true)
  22. // Always report how much memory is used, even when there are no leaks or bad frees.
  23. ALWAYS_REPORT_MEMORY : bool : #config(ODIN_TEST_ALWAYS_REPORT_MEMORY, false)
  24. // Specify how much memory each thread allocator starts with.
  25. PER_THREAD_MEMORY : int : #config(ODIN_TEST_THREAD_MEMORY, mem.ROLLBACK_STACK_DEFAULT_BLOCK_SIZE)
  26. // Select a specific set of tests to run by name.
  27. // Each test is separated by a comma and may optionally include the package name.
  28. // This may be useful when running tests on multiple packages with `-all-packages`.
  29. // The format is: `package.test_name,test_name_only,...`
  30. TEST_NAMES : string : #config(ODIN_TEST_NAMES, "")
  31. // Show the fancy animated progress report.
  32. FANCY_OUTPUT : bool : #config(ODIN_TEST_FANCY, true)
  33. // Copy failed tests to the clipboard when done.
  34. USE_CLIPBOARD : bool : #config(ODIN_TEST_CLIPBOARD, false)
  35. // How many test results to show at a time per package.
  36. PROGRESS_WIDTH : int : #config(ODIN_TEST_PROGRESS_WIDTH, 24)
  37. // This is the random seed that will be sent to each test.
  38. // If it is unspecified, it will be set to the system cycle counter at startup.
  39. SHARED_RANDOM_SEED : u64 : #config(ODIN_TEST_RANDOM_SEED, 0)
  40. // Set the lowest log level for this test run.
  41. LOG_LEVEL : string : #config(ODIN_TEST_LOG_LEVEL, "info")
  42. get_log_level :: #force_inline proc() -> runtime.Logger_Level {
  43. when ODIN_DEBUG {
  44. // Always use .Debug in `-debug` mode.
  45. return .Debug
  46. } else {
  47. when LOG_LEVEL == "debug" { return .Debug }
  48. else when LOG_LEVEL == "info" { return .Info }
  49. else when LOG_LEVEL == "warning" { return .Warning }
  50. else when LOG_LEVEL == "error" { return .Error }
  51. else when LOG_LEVEL == "fatal" { return .Fatal }
  52. }
  53. }
  54. end_t :: proc(t: ^T) {
  55. for i := len(t.cleanups)-1; i >= 0; i -= 1 {
  56. #no_bounds_check c := t.cleanups[i]
  57. context = c.ctx
  58. c.procedure(c.user_data)
  59. }
  60. delete(t.cleanups)
  61. t.cleanups = {}
  62. }
  63. Task_Data :: struct {
  64. it: Internal_Test,
  65. t: T,
  66. allocator_index: int,
  67. }
  68. Task_Timeout :: struct {
  69. test_index: int,
  70. at_time: time.Time,
  71. location: runtime.Source_Code_Location,
  72. }
  73. run_test_task :: proc(task: thread.Task) {
  74. data := cast(^Task_Data)(task.data)
  75. setup_task_signal_handler(task.user_index)
  76. chan.send(data.t.channel, Event_New_Test {
  77. test_index = task.user_index,
  78. })
  79. chan.send(data.t.channel, Event_State_Change {
  80. new_state = .Running,
  81. })
  82. context.assertion_failure_proc = test_assertion_failure_proc
  83. context.logger = {
  84. procedure = test_logger_proc,
  85. data = &data.t,
  86. lowest_level = get_log_level(),
  87. options = Default_Test_Logger_Opts,
  88. }
  89. free_all(context.temp_allocator)
  90. data.it.p(&data.t)
  91. end_t(&data.t)
  92. new_state : Test_State = .Failed if failed(&data.t) else .Successful
  93. chan.send(data.t.channel, Event_State_Change {
  94. new_state = new_state,
  95. })
  96. }
  97. runner :: proc(internal_tests: []Internal_Test) -> bool {
  98. BATCH_BUFFER_SIZE :: 32 * mem.Kilobyte
  99. POOL_BLOCK_SIZE :: 16 * mem.Kilobyte
  100. CLIPBOARD_BUFFER_SIZE :: 16 * mem.Kilobyte
  101. BUFFERED_EVENTS_PER_CHANNEL :: 16
  102. RESERVED_LOG_MESSAGES :: 64
  103. RESERVED_TEST_FAILURES :: 64
  104. ERROR_STRING_TIMEOUT : string : "Test timed out."
  105. ERROR_STRING_UNKNOWN : string : "Test failed for unknown reasons."
  106. OSC_WINDOW_TITLE : string : ansi.OSC + ansi.WINDOW_TITLE + ";Odin test runner (%i/%i)" + ansi.ST
  107. safe_delete_string :: proc(s: string, allocator := context.allocator) {
  108. // Guard against bad frees on static strings.
  109. switch raw_data(s) {
  110. case raw_data(ERROR_STRING_TIMEOUT), raw_data(ERROR_STRING_UNKNOWN):
  111. return
  112. case:
  113. delete(s, allocator)
  114. }
  115. }
  116. stdout := io.to_writer(os.stream_from_handle(os.stdout))
  117. stderr := io.to_writer(os.stream_from_handle(os.stderr))
  118. // -- Prepare test data.
  119. alloc_error: mem.Allocator_Error
  120. when TEST_NAMES != "" {
  121. select_internal_tests: [dynamic]Internal_Test
  122. defer delete(select_internal_tests)
  123. {
  124. index_list := TEST_NAMES
  125. for selector in strings.split_iterator(&index_list, ",") {
  126. // Temp allocator is fine since we just need to identify which test it's referring to.
  127. split_selector := strings.split(selector, ".", context.temp_allocator)
  128. found := false
  129. switch len(split_selector) {
  130. case 1:
  131. // Only the test name?
  132. #no_bounds_check name := split_selector[0]
  133. find_test_by_name: for it in internal_tests {
  134. if it.name == name {
  135. found = true
  136. _, alloc_error = append(&select_internal_tests, it)
  137. fmt.assertf(alloc_error == nil, "Error appending to select internal tests: %v", alloc_error)
  138. break find_test_by_name
  139. }
  140. }
  141. case 2:
  142. #no_bounds_check pkg := split_selector[0]
  143. #no_bounds_check name := split_selector[1]
  144. find_test_by_pkg_and_name: for it in internal_tests {
  145. if it.pkg == pkg && it.name == name {
  146. found = true
  147. _, alloc_error = append(&select_internal_tests, it)
  148. fmt.assertf(alloc_error == nil, "Error appending to select internal tests: %v", alloc_error)
  149. break find_test_by_pkg_and_name
  150. }
  151. }
  152. }
  153. if !found {
  154. fmt.wprintfln(stderr, "No test found for the name: %q", selector)
  155. }
  156. }
  157. }
  158. // Intentional shadow with user-specified tests.
  159. internal_tests := select_internal_tests[:]
  160. }
  161. total_failure_count := 0
  162. total_success_count := 0
  163. total_done_count := 0
  164. total_test_count := len(internal_tests)
  165. when !FANCY_OUTPUT {
  166. // This is strictly for updating the window title when the progress
  167. // report is disabled. We're otherwise able to depend on the call to
  168. // `needs_to_redraw`.
  169. last_done_count := -1
  170. }
  171. if total_test_count == 0 {
  172. // Exit early.
  173. fmt.wprintln(stdout, "No tests to run.")
  174. return true
  175. }
  176. for it in internal_tests {
  177. // NOTE(Feoramund): The old test runner skipped over tests with nil
  178. // procedures, but I couldn't find any case where they occurred.
  179. // This assert stands to prevent any oversight on my part.
  180. fmt.assertf(it.p != nil, "Test %s.%s has <nil> procedure.", it.pkg, it.name)
  181. }
  182. slice.sort_by(internal_tests, proc(a, b: Internal_Test) -> bool {
  183. if a.pkg == b.pkg {
  184. return a.name < b.name
  185. } else {
  186. return a.pkg < b.pkg
  187. }
  188. })
  189. // -- Set thread count.
  190. when TEST_THREADS == 0 {
  191. thread_count := os.processor_core_count()
  192. } else {
  193. thread_count := max(1, TEST_THREADS)
  194. }
  195. thread_count = min(thread_count, total_test_count)
  196. // -- Allocate.
  197. pool_stack: mem.Rollback_Stack
  198. alloc_error = mem.rollback_stack_init(&pool_stack, POOL_BLOCK_SIZE)
  199. fmt.assertf(alloc_error == nil, "Error allocating memory for thread pool: %v", alloc_error)
  200. defer mem.rollback_stack_destroy(&pool_stack)
  201. pool: thread.Pool
  202. thread.pool_init(&pool, mem.rollback_stack_allocator(&pool_stack), thread_count)
  203. defer thread.pool_destroy(&pool)
  204. task_channels: []Task_Channel = ---
  205. task_channels, alloc_error = make([]Task_Channel, thread_count)
  206. fmt.assertf(alloc_error == nil, "Error allocating memory for update channels: %v", alloc_error)
  207. defer delete(task_channels)
  208. for &task_channel, index in task_channels {
  209. task_channel.channel, alloc_error = chan.create_buffered(Update_Channel, BUFFERED_EVENTS_PER_CHANNEL, context.allocator)
  210. fmt.assertf(alloc_error == nil, "Error allocating memory for update channel #%i: %v", index, alloc_error)
  211. }
  212. defer for &task_channel in task_channels {
  213. chan.destroy(&task_channel.channel)
  214. }
  215. // This buffer is used to batch writes to STDOUT or STDERR, to help reduce
  216. // screen flickering.
  217. batch_buffer: bytes.Buffer
  218. bytes.buffer_init_allocator(&batch_buffer, 0, BATCH_BUFFER_SIZE)
  219. batch_writer := io.to_writer(bytes.buffer_to_stream(&batch_buffer))
  220. defer bytes.buffer_destroy(&batch_buffer)
  221. report: Report = ---
  222. report, alloc_error = make_report(internal_tests)
  223. fmt.assertf(alloc_error == nil, "Error allocating memory for test report: %v", alloc_error)
  224. defer destroy_report(&report)
  225. when FANCY_OUTPUT {
  226. // We cannot make use of the ANSI save/restore cursor codes, because they
  227. // work by absolute screen coordinates. This will cause unnecessary
  228. // scrollback if we print at the bottom of someone's terminal.
  229. ansi_redraw_string := fmt.aprintf(
  230. // ANSI for "go up N lines then erase the screen from the cursor forward."
  231. ansi.CSI + "%i" + ansi.CPL + ansi.CSI + ansi.ED +
  232. // We'll combine this with the window title format string, since it
  233. // can be printed at the same time.
  234. "%s",
  235. // 1 extra line for the status bar.
  236. 1 + len(report.packages), OSC_WINDOW_TITLE)
  237. assert(len(ansi_redraw_string) > 0, "Error allocating ANSI redraw string.")
  238. defer delete(ansi_redraw_string)
  239. thread_count_status_string: string = ---
  240. {
  241. PADDING :: PROGRESS_COLUMN_SPACING + PROGRESS_WIDTH
  242. unpadded := fmt.tprintf("%i thread%s", thread_count, "" if thread_count == 1 else "s")
  243. thread_count_status_string = fmt.aprintf("%- *[1]s", unpadded, report.pkg_column_len + PADDING)
  244. assert(len(thread_count_status_string) > 0, "Error allocating thread count status string.")
  245. }
  246. defer delete(thread_count_status_string)
  247. }
  248. task_data_slots: []Task_Data = ---
  249. task_data_slots, alloc_error = make([]Task_Data, thread_count)
  250. fmt.assertf(alloc_error == nil, "Error allocating memory for task data slots: %v", alloc_error)
  251. defer delete(task_data_slots)
  252. // Tests rotate through these allocators as they finish.
  253. task_allocators: []mem.Rollback_Stack = ---
  254. task_allocators, alloc_error = make([]mem.Rollback_Stack, thread_count)
  255. fmt.assertf(alloc_error == nil, "Error allocating memory for task allocators: %v", alloc_error)
  256. defer delete(task_allocators)
  257. when TRACKING_MEMORY {
  258. task_memory_trackers: []mem.Tracking_Allocator = ---
  259. task_memory_trackers, alloc_error = make([]mem.Tracking_Allocator, thread_count)
  260. fmt.assertf(alloc_error == nil, "Error allocating memory for memory trackers: %v", alloc_error)
  261. defer delete(task_memory_trackers)
  262. }
  263. #no_bounds_check for i in 0 ..< thread_count {
  264. alloc_error = mem.rollback_stack_init(&task_allocators[i], PER_THREAD_MEMORY)
  265. fmt.assertf(alloc_error == nil, "Error allocating memory for task allocator #%i: %v", i, alloc_error)
  266. when TRACKING_MEMORY {
  267. mem.tracking_allocator_init(&task_memory_trackers[i], mem.rollback_stack_allocator(&task_allocators[i]))
  268. }
  269. }
  270. defer #no_bounds_check for i in 0 ..< thread_count {
  271. when TRACKING_MEMORY {
  272. mem.tracking_allocator_destroy(&task_memory_trackers[i])
  273. }
  274. mem.rollback_stack_destroy(&task_allocators[i])
  275. }
  276. task_timeouts: [dynamic]Task_Timeout = ---
  277. task_timeouts, alloc_error = make([dynamic]Task_Timeout, 0, thread_count)
  278. fmt.assertf(alloc_error == nil, "Error allocating memory for task timeouts: %v", alloc_error)
  279. defer delete(task_timeouts)
  280. failed_test_reason_map: map[int]string = ---
  281. failed_test_reason_map, alloc_error = make(map[int]string, RESERVED_TEST_FAILURES)
  282. fmt.assertf(alloc_error == nil, "Error allocating memory for failed test reasons: %v", alloc_error)
  283. defer delete(failed_test_reason_map)
  284. log_messages: [dynamic]Log_Message = ---
  285. log_messages, alloc_error = make([dynamic]Log_Message, 0, RESERVED_LOG_MESSAGES)
  286. fmt.assertf(alloc_error == nil, "Error allocating memory for log message queue: %v", alloc_error)
  287. defer delete(log_messages)
  288. sorted_failed_test_reasons: [dynamic]int = ---
  289. sorted_failed_test_reasons, alloc_error = make([dynamic]int, 0, RESERVED_TEST_FAILURES)
  290. fmt.assertf(alloc_error == nil, "Error allocating memory for sorted failed test reasons: %v", alloc_error)
  291. defer delete(sorted_failed_test_reasons)
  292. when USE_CLIPBOARD {
  293. clipboard_buffer: bytes.Buffer
  294. bytes.buffer_init_allocator(&clipboard_buffer, 0, CLIPBOARD_BUFFER_SIZE)
  295. defer bytes.buffer_destroy(&clipboard_buffer)
  296. }
  297. when SHARED_RANDOM_SEED == 0 {
  298. shared_random_seed := cast(u64)intrinsics.read_cycle_counter()
  299. } else {
  300. shared_random_seed := SHARED_RANDOM_SEED
  301. }
  302. // -- Setup initial tasks.
  303. // NOTE(Feoramund): This is the allocator that will be used by threads to
  304. // persist log messages past their lifetimes. It has its own variable name
  305. // in the event it needs to be changed from `context.allocator` without
  306. // digging through the source to divine everywhere it is used for that.
  307. shared_log_allocator := context.allocator
  308. context.logger = {
  309. procedure = runner_logger_proc,
  310. data = &log_messages,
  311. lowest_level = get_log_level(),
  312. options = Default_Test_Logger_Opts - {.Short_File_Path, .Line, .Procedure},
  313. }
  314. run_index: int
  315. setup_tasks: for &data, task_index in task_data_slots {
  316. setup_next_test: for run_index < total_test_count {
  317. #no_bounds_check it := internal_tests[run_index]
  318. defer run_index += 1
  319. data.it = it
  320. data.t.seed = shared_random_seed
  321. #no_bounds_check data.t.channel = chan.as_send(task_channels[task_index].channel)
  322. data.t._log_allocator = shared_log_allocator
  323. data.allocator_index = task_index
  324. #no_bounds_check when TRACKING_MEMORY {
  325. task_allocator := mem.tracking_allocator(&task_memory_trackers[task_index])
  326. } else {
  327. task_allocator := mem.rollback_stack_allocator(&task_allocators[task_index])
  328. }
  329. thread.pool_add_task(&pool, task_allocator, run_test_task, &data, run_index)
  330. continue setup_tasks
  331. }
  332. }
  333. // -- Run tests.
  334. setup_signal_handler()
  335. fmt.wprint(stdout, ansi.CSI + ansi.DECTCEM_HIDE)
  336. when FANCY_OUTPUT {
  337. signals_were_raised := false
  338. redraw_report(stdout, report)
  339. draw_status_bar(stdout, thread_count_status_string, total_done_count, total_test_count)
  340. }
  341. when TEST_THREADS == 0 {
  342. pkg_log.infof("Starting test runner with %i thread%s. Set with -define:ODIN_TEST_THREADS=n.",
  343. thread_count,
  344. "" if thread_count == 1 else "s")
  345. } else {
  346. pkg_log.infof("Starting test runner with %i thread%s.",
  347. thread_count,
  348. "" if thread_count == 1 else "s")
  349. }
  350. when SHARED_RANDOM_SEED == 0 {
  351. pkg_log.infof("The random seed sent to every test is: %v. Set with -define:ODIN_TEST_RANDOM_SEED=n.", shared_random_seed)
  352. } else {
  353. pkg_log.infof("The random seed sent to every test is: %v.", shared_random_seed)
  354. }
  355. when TRACKING_MEMORY {
  356. when ALWAYS_REPORT_MEMORY {
  357. pkg_log.info("Memory tracking is enabled. Tests will log their memory usage when complete.")
  358. } else {
  359. pkg_log.info("Memory tracking is enabled. Tests will log their memory usage if there's an issue.")
  360. }
  361. pkg_log.info("< Final Mem/ Total Mem> < Peak Mem> (#Free/Alloc) :: [package.test_name]")
  362. } else when ALWAYS_REPORT_MEMORY {
  363. pkg_log.warn("ODIN_TEST_ALWAYS_REPORT_MEMORY is true, but ODIN_TRACK_MEMORY is false.")
  364. }
  365. start_time := time.now()
  366. thread.pool_start(&pool)
  367. main_loop: for !thread.pool_is_empty(&pool) {
  368. {
  369. events_pending := thread.pool_num_done(&pool) > 0
  370. if !events_pending {
  371. poll_tasks: for &task_channel in task_channels {
  372. if chan.len(task_channel.channel) > 0 {
  373. events_pending = true
  374. break poll_tasks
  375. }
  376. }
  377. }
  378. if !events_pending {
  379. // Keep the main thread from pegging a core at 100% usage.
  380. time.sleep(1 * time.Microsecond)
  381. }
  382. }
  383. cycle_pool: for task in thread.pool_pop_done(&pool) {
  384. data := cast(^Task_Data)(task.data)
  385. when TRACKING_MEMORY {
  386. #no_bounds_check tracker := &task_memory_trackers[data.allocator_index]
  387. memory_is_in_bad_state := len(tracker.allocation_map) + len(tracker.bad_free_array) > 0
  388. when ALWAYS_REPORT_MEMORY {
  389. should_report := true
  390. } else {
  391. should_report := memory_is_in_bad_state
  392. }
  393. if should_report {
  394. write_memory_report(batch_writer, tracker, data.it.pkg, data.it.name)
  395. pkg_log.log(.Warning if memory_is_in_bad_state else .Info, bytes.buffer_to_string(&batch_buffer))
  396. bytes.buffer_reset(&batch_buffer)
  397. }
  398. mem.tracking_allocator_reset(tracker)
  399. }
  400. free_all(task.allocator)
  401. if run_index < total_test_count {
  402. #no_bounds_check it := internal_tests[run_index]
  403. defer run_index += 1
  404. data.it = it
  405. data.t.seed = shared_random_seed
  406. data.t.error_count = 0
  407. thread.pool_add_task(&pool, task.allocator, run_test_task, data, run_index)
  408. }
  409. }
  410. handle_events: for &task_channel in task_channels {
  411. for ev in chan.try_recv(task_channel.channel) {
  412. switch event in ev {
  413. case Event_New_Test:
  414. task_channel.test_index = event.test_index
  415. case Event_State_Change:
  416. #no_bounds_check report.all_test_states[task_channel.test_index] = event.new_state
  417. #no_bounds_check it := internal_tests[task_channel.test_index]
  418. #no_bounds_check pkg := report.packages_by_name[it.pkg]
  419. #partial switch event.new_state {
  420. case .Failed:
  421. if task_channel.test_index not_in failed_test_reason_map {
  422. failed_test_reason_map[task_channel.test_index] = ERROR_STRING_UNKNOWN
  423. }
  424. total_failure_count += 1
  425. total_done_count += 1
  426. case .Successful:
  427. total_success_count += 1
  428. total_done_count += 1
  429. }
  430. when ODIN_DEBUG {
  431. pkg_log.debugf("Test #%i %s.%s changed state to %v.", task_channel.test_index, it.pkg, it.name, event.new_state)
  432. }
  433. pkg.last_change_state = event.new_state
  434. pkg.last_change_name = it.name
  435. pkg.frame_ready = false
  436. case Event_Set_Fail_Timeout:
  437. _, alloc_error = append(&task_timeouts, Task_Timeout {
  438. test_index = task_channel.test_index,
  439. at_time = event.at_time,
  440. location = event.location,
  441. })
  442. fmt.assertf(alloc_error == nil, "Error appending to task timeouts: %v", alloc_error)
  443. case Event_Log_Message:
  444. _, alloc_error = append(&log_messages, Log_Message {
  445. level = event.level,
  446. text = event.formatted_text,
  447. time = event.time,
  448. allocator = shared_log_allocator,
  449. })
  450. fmt.assertf(alloc_error == nil, "Error appending to log messages: %v", alloc_error)
  451. if event.level >= .Error {
  452. // Save the message for the final summary.
  453. if old_error, ok := failed_test_reason_map[task_channel.test_index]; ok {
  454. safe_delete_string(old_error, shared_log_allocator)
  455. }
  456. failed_test_reason_map[task_channel.test_index] = event.text
  457. } else {
  458. delete(event.text, shared_log_allocator)
  459. }
  460. }
  461. }
  462. }
  463. check_timeouts: for i := len(task_timeouts) - 1; i >= 0; i -= 1 {
  464. #no_bounds_check timeout := &task_timeouts[i]
  465. if time.since(timeout.at_time) < 0 {
  466. continue check_timeouts
  467. }
  468. defer unordered_remove(&task_timeouts, i)
  469. #no_bounds_check if report.all_test_states[timeout.test_index] > .Running {
  470. continue check_timeouts
  471. }
  472. if !thread.pool_stop_task(&pool, timeout.test_index) {
  473. // The task may have stopped a split second after we started
  474. // checking, but we haven't handled the new state yet.
  475. continue check_timeouts
  476. }
  477. #no_bounds_check report.all_test_states[timeout.test_index] = .Failed
  478. #no_bounds_check it := internal_tests[timeout.test_index]
  479. #no_bounds_check pkg := report.packages_by_name[it.pkg]
  480. pkg.frame_ready = false
  481. if old_error, ok := failed_test_reason_map[timeout.test_index]; ok {
  482. safe_delete_string(old_error, shared_log_allocator)
  483. }
  484. failed_test_reason_map[timeout.test_index] = ERROR_STRING_TIMEOUT
  485. total_failure_count += 1
  486. total_done_count += 1
  487. now := time.now()
  488. _, alloc_error = append(&log_messages, Log_Message {
  489. level = .Error,
  490. text = format_log_text(.Error, ERROR_STRING_TIMEOUT, Default_Test_Logger_Opts, timeout.location, now),
  491. time = now,
  492. allocator = context.allocator,
  493. })
  494. fmt.assertf(alloc_error == nil, "Error appending to log messages: %v", alloc_error)
  495. find_task_data: for &data in task_data_slots {
  496. if data.it.pkg == it.pkg && data.it.name == it.name {
  497. end_t(&data.t)
  498. break find_task_data
  499. }
  500. }
  501. }
  502. if should_stop_runner() {
  503. fmt.wprintln(stderr, "\nCaught interrupt signal. Stopping all tests.")
  504. thread.pool_shutdown(&pool)
  505. break main_loop
  506. }
  507. when FANCY_OUTPUT {
  508. // Because the bounds checking procs send directly to STDERR with
  509. // no way to redirect or handle them, we need to at least try to
  510. // let the user see those messages when using the animated progress
  511. // report. This flag may be set by the block of code below if a
  512. // signal is raised.
  513. //
  514. // It'll be purely by luck if the output is interleaved properly,
  515. // given the nature of non-thread-safe printing.
  516. //
  517. // At worst, if Odin did not print any error for this signal, we'll
  518. // just re-display the progress report. The fatal log error message
  519. // should be enough to clue the user in that something dire has
  520. // occurred.
  521. bypass_progress_overwrite := false
  522. }
  523. if test_index, reason, ok := should_stop_test(); ok {
  524. #no_bounds_check report.all_test_states[test_index] = .Failed
  525. #no_bounds_check it := internal_tests[test_index]
  526. #no_bounds_check pkg := report.packages_by_name[it.pkg]
  527. pkg.frame_ready = false
  528. fmt.assertf(thread.pool_stop_task(&pool, test_index),
  529. "A signal (%v) was raised to stop test #%i %s.%s, but it was unable to be found.",
  530. reason, test_index, it.pkg, it.name)
  531. if test_index not_in failed_test_reason_map {
  532. // We only write a new error message here if there wasn't one
  533. // already, because the message we can provide based only on
  534. // the signal won't be very useful, whereas asserts and panics
  535. // will provide a user-written error message.
  536. failed_test_reason_map[test_index] = fmt.aprintf("Signal caught: %v", reason, allocator = shared_log_allocator)
  537. pkg_log.fatalf("Caught signal to stop test #%i %s.%s for: %v.", test_index, it.pkg, it.name, reason)
  538. }
  539. when FANCY_OUTPUT {
  540. bypass_progress_overwrite = true
  541. signals_were_raised = true
  542. }
  543. total_failure_count += 1
  544. total_done_count += 1
  545. }
  546. // -- Redraw.
  547. when FANCY_OUTPUT {
  548. if len(log_messages) == 0 && !needs_to_redraw(report) {
  549. continue main_loop
  550. }
  551. if !bypass_progress_overwrite {
  552. fmt.wprintf(stdout, ansi_redraw_string, total_done_count, total_test_count)
  553. }
  554. } else {
  555. if total_done_count != last_done_count {
  556. fmt.wprintf(stdout, OSC_WINDOW_TITLE, total_done_count, total_test_count)
  557. last_done_count = total_done_count
  558. }
  559. if len(log_messages) == 0 {
  560. continue main_loop
  561. }
  562. }
  563. // Because each thread has its own messenger channel, log messages
  564. // arrive in chunks that are in-order, but when they're merged with the
  565. // logs from other threads, they become out-of-order.
  566. slice.stable_sort_by(log_messages[:], proc(a, b: Log_Message) -> bool {
  567. return time.diff(a.time, b.time) > 0
  568. })
  569. for message in log_messages {
  570. fmt.wprintln(batch_writer, message.text)
  571. delete(message.text, message.allocator)
  572. }
  573. fmt.wprint(stderr, bytes.buffer_to_string(&batch_buffer))
  574. clear(&log_messages)
  575. bytes.buffer_reset(&batch_buffer)
  576. when FANCY_OUTPUT {
  577. redraw_report(batch_writer, report)
  578. draw_status_bar(batch_writer, thread_count_status_string, total_done_count, total_test_count)
  579. fmt.wprint(stdout, bytes.buffer_to_string(&batch_buffer))
  580. bytes.buffer_reset(&batch_buffer)
  581. }
  582. }
  583. // -- All tests are complete, or the runner has been interrupted.
  584. // NOTE(Feoramund): If you've arrived here after receiving signal 11 or
  585. // SIGSEGV on the main runner thread, while using a UNIX-like platform,
  586. // there is the possibility that you may have encountered a rare edge case
  587. // involving the joining of threads.
  588. //
  589. // At the time of writing, the thread library is undergoing a rewrite that
  590. // should solve this problem; it is not an issue with the test runner itself.
  591. thread.pool_join(&pool)
  592. finished_in := time.since(start_time)
  593. when !FANCY_OUTPUT {
  594. // One line to space out the results, since we don't have the status
  595. // bar in plain mode.
  596. fmt.wprintln(batch_writer)
  597. }
  598. fmt.wprintf(batch_writer,
  599. "Finished %i test%s in %v.",
  600. total_done_count,
  601. "" if total_done_count == 1 else "s",
  602. finished_in)
  603. if total_done_count != total_test_count {
  604. not_run_count := total_test_count - total_done_count
  605. fmt.wprintf(batch_writer,
  606. " " + SGR_READY + "%i" + SGR_RESET + " %s left undone.",
  607. not_run_count,
  608. "test was" if not_run_count == 1 else "tests were")
  609. }
  610. if total_success_count == total_test_count {
  611. fmt.wprintfln(batch_writer,
  612. " %s " + SGR_SUCCESS + "successful." + SGR_RESET,
  613. "The test was" if total_test_count == 1 else "All tests were")
  614. } else if total_failure_count > 0 {
  615. if total_failure_count == total_test_count {
  616. fmt.wprintfln(batch_writer,
  617. " %s " + SGR_FAILED + "failed." + SGR_RESET,
  618. "The test" if total_test_count == 1 else "All tests")
  619. } else {
  620. fmt.wprintfln(batch_writer,
  621. " " + SGR_FAILED + "%i" + SGR_RESET + " test%s failed.",
  622. total_failure_count,
  623. "" if total_failure_count == 1 else "s")
  624. }
  625. for test_index in failed_test_reason_map {
  626. _, alloc_error = append(&sorted_failed_test_reasons, test_index)
  627. fmt.assertf(alloc_error == nil, "Error appending to sorted failed test reasons: %v", alloc_error)
  628. }
  629. slice.sort(sorted_failed_test_reasons[:])
  630. for test_index in sorted_failed_test_reasons {
  631. #no_bounds_check last_error := failed_test_reason_map[test_index]
  632. #no_bounds_check it := internal_tests[test_index]
  633. pkg_and_name := fmt.tprintf("%s.%s", it.pkg, it.name)
  634. fmt.wprintfln(batch_writer, " - %- *[1]s\t%s",
  635. pkg_and_name,
  636. report.pkg_column_len + report.test_column_len,
  637. last_error)
  638. safe_delete_string(last_error, shared_log_allocator)
  639. }
  640. if total_success_count > 0 {
  641. when USE_CLIPBOARD {
  642. clipboard_writer := io.to_writer(bytes.buffer_to_stream(&clipboard_buffer))
  643. fmt.wprint(clipboard_writer, "-define:ODIN_TEST_NAMES=")
  644. for test_index in sorted_failed_test_reasons {
  645. #no_bounds_check it := internal_tests[test_index]
  646. fmt.wprintf(clipboard_writer, "%s.%s,", it.pkg, it.name)
  647. }
  648. encoded_names := base64.encode(bytes.buffer_to_bytes(&clipboard_buffer), allocator = context.temp_allocator)
  649. fmt.wprintf(batch_writer,
  650. ansi.OSC + ansi.CLIPBOARD + ";c;%s" + ansi.ST +
  651. "\nThe name%s of the failed test%s been copied to your clipboard.",
  652. encoded_names,
  653. "" if total_failure_count == 1 else "s",
  654. " has" if total_failure_count == 1 else "s have")
  655. } else {
  656. fmt.wprintf(batch_writer, "\nTo run only the failed test%s, use:\n\t-define:ODIN_TEST_NAMES=",
  657. "" if total_failure_count == 1 else "s")
  658. for test_index in sorted_failed_test_reasons {
  659. #no_bounds_check it := internal_tests[test_index]
  660. fmt.wprintf(batch_writer, "%s.%s,", it.pkg, it.name)
  661. }
  662. fmt.wprint(batch_writer, "\n\nIf your terminal supports OSC 52, you may use -define:ODIN_TEST_CLIPBOARD to have this copied directly to your clipboard.")
  663. }
  664. fmt.wprintln(batch_writer)
  665. }
  666. }
  667. fmt.wprint(stdout, ansi.CSI + ansi.DECTCEM_SHOW)
  668. when FANCY_OUTPUT {
  669. if signals_were_raised {
  670. fmt.wprintln(batch_writer, `
  671. Signals were raised during this test run. Log messages are likely to have collided with each other.
  672. To partly mitigate this, redirect STDERR to a file or use the -define:ODIN_TEST_FANCY=false option.`)
  673. }
  674. }
  675. fmt.wprintln(stderr, bytes.buffer_to_string(&batch_buffer))
  676. return total_success_count == total_test_count
  677. }