Samuel Garfield
12/06/2023, 6:26 PMSamuel Garfield
12/06/2023, 6:26 PM14:22:28 1053 of 1139 PASS <final test name> [PASS in 65.22s]
14:22:28
14:22:28
14:22:28 Running 1 on-run-end hook
14:33:04 1 of 1 START hook: elementary.on-run-end.0 ..................................... [RUN]
14:33:04 1 of 1 OK hook: elementary.on-run-end.0 ........................................ [OK in 0.00s]Samuel Garfield
12/06/2023, 6:27 PM1 of 1 START hook: elementary.on-run-end.0 line isn't written until 11 minutes later at 2:33 PM UTCSamuel Garfield
12/06/2023, 6:28 PMSamuel Garfield
12/06/2023, 6:49 PM1053 of 1139 because it takes longer than any of the remaining 86 tests, not because this is an incomplete log fileDaniel Pollak
12/07/2023, 10:00 AMRunning 1 on-run-end hook log
2. In line 369, it's the event that writes the 1 of 1 START hook: elementary.on-run-end.0
Between those lines, in 362, you can see -
sql = self.get_hook_sql(...)
That's what takes time. It's compiling our end hook, and during the compilation we're doing all of our logic. So the logs are a bit deceiving.