Make wmJob worker thread use their own reports list instead of WM one. #113548

Bastien Montagne · 2023-10-11T16:15:47+02:00

Bastien Montagne commented

2023-10-11 16:15:47 +02:00

Calling WM_report & co API from wmJob worker thread is utterly unsafe,
and should never have been done. It 'worked' so far presumably because
worker threads were barely (if ever) reporting anything that way, but
now USD IO code is spamming reports in some cases, leading to fairly
common crashes.

This commit addresses the root of the issue by adding some ReportList data
to each wmJob wmJobWorkerStatus shared data, and some code in wmJob
management (update) area to move these reports to the main WM list.

Implements #112537.

NOTE: The changes to the USD code are mostly here as demonstration for
the new system. Not very happy with current implementation, but it seems
difficult to have access to a common data from everywhere in USD IO
code... Would need to be committed separately for sure.

Calling `WM_report` & co API from wmJob worker thread is utterly unsafe, and should never have been done. It 'worked' so far presumably because worker threads were barely (if ever) reporting anything that way, but now USD IO code is spamming reports in some cases, leading to fairly common crashes. This commit addresses the root of the issue by adding some ReportList data to each wmJob `wmJobWorkerStatus` shared data, and some code in wmJob management (update) area to move these reports to the main WM list. Implements #112537. NOTE: The changes to the USD code are mostly here as demonstration for the new system. Not very happy with current implementation, but it seems difficult to have access to a common data from everywhere in USD IO code... Would need to be committed separately for sure.

Bastien Montagne requested review from Sergey Sharybin 2023-10-11 16:16:13 +02:00

Bastien Montagne requested review from Michael Kowalski 2023-10-11 16:16:14 +02:00

Bastien Montagne added the

Module

Core

label 2023-10-11 16:16:24 +02:00

Bastien Montagne commented

2023-10-11 16:18:10 +02:00

@Sergey mostly interested on your view on the trick am using with the two ReportList data swapped with each-other during wmJob timer updates, to avoid the need of proper mutex locking when accessing this data.

@makowalski would love to have your PoV on USD-related changes in this code.

@Sergey mostly interested on your view on the trick am using with the two `ReportList` data swapped with each-other during wmJob timer updates, to avoid the need of proper mutex locking when accessing this data. @makowalski would love to have your PoV on USD-related changes in this code.

Bastien Montagne force-pushed tmp-wmjob-report-refactor from ac22d3bba8 to 3c44a70389

2023-10-11 21:44:11 +02:00

Compare

Bastien Montagne force-pushed tmp-wmjob-report-refactor from 3c44a70389 to a2e378454b

2023-10-11 21:44:26 +02:00

Compare

Bastien Montagne commented

2023-10-11 22:13:07 +02:00

NOTE: After IRL talk with @Sergey , we are going to rather make ReportList/BKE_report threadsafe using a mutex. This will change a bit this code (although the part affecting USD code itself should not change here).

See !113561.

NOTE: After IRL talk with @Sergey , we are going to rather make `ReportList`/`BKE_report` threadsafe using a mutex. This will change a bit this code (although the part affecting USD code itself should not change here). See !113561.

Bastien Montagne referenced this pull request

2023-10-11 22:16:12 +02:00

BKE_reports: make the API thread-safe. #113561

Michael Kowalski reviewed 2023-10-12 03:10:20 +02:00

source/blender/io/usd/intern/usd_capi_export.cc Outdated

						
				@ -458,2 +459,4 @@

				  }

				  else {

				    /* NOTE: Since the `worker_status.reports` pointer is `nullptr` here, BKE_report API will only

				     * print to console. */

Michael Kowalski commented

2023-10-12 03:10:20 +02:00

Ideally, it would be nice if the reports wouldn't be limited to printing to the console when running the exporter in the foreground, but this might be an acceptable limitation.

Michael Kowalski commented

2023-10-12 03:32:56 +02:00

@makowalski would love to have your PoV on USD-related changes in this code.

I will aim to finish my review tomorrow, but so far the changes look good!

> @makowalski would love to have your PoV on USD-related changes in this code. I will aim to finish my review tomorrow, but so far the changes look good!

Michael Kowalski commented

2023-10-12 23:46:01 +02:00

Thank you so much for this important fix!

The USD implementation looks good to me and works in my test. Since you mentioned that the USD related changes will likely be submitted separately, I will defer approving this till that pull request is up.

As I mentioned in the comment, I do have a minor concern that the output for for jobs run in the foreground is printed in the console, which means that reports may be displayed differently when USD import/export is executed from a script. This is not necessarily a blocker for me. Would it be possible to get around this by allocating a ReportList on the "dummy" wmJobWorkerStatus instances created when running in the foreground?

I also have a high level question. Taking a step back, might it be possible to have the ReportList be maintained in a singleton of some sort for the USD IO code, so it can be passed to BKE_reportf() in a global function? I know using singletons is usually not a good design choice, but I was wondering if this is even possible.

Thank you so much for this important fix! The USD implementation looks good to me and works in my test. Since you mentioned that the USD related changes will likely be submitted separately, I will defer approving this till that pull request is up. As I mentioned in the comment, I do have a minor concern that the output for for jobs run in the foreground is printed in the console, which means that reports may be displayed differently when USD import/export is executed from a script. This is not necessarily a blocker for me. Would it be possible to get around this by allocating a `ReportList` on the "dummy" `wmJobWorkerStatus` instances created when running in the foreground? I also have a high level question. Taking a step back, might it be possible to have the `ReportList` be maintained in a singleton of some sort for the USD IO code, so it can be passed to ` BKE_reportf()` in a global function? I know using singletons is usually not a good design choice, but I was wondering if this is even possible.

Bastien Montagne referenced this issue from a commit

2023-10-13 11:30:08 +02:00

BKE_reports: make the API thread-safe.

Bastien Montagne force-pushed tmp-wmjob-report-refactor from a2e378454b to 234685ffe5

2023-10-13 12:36:49 +02:00

Compare

Bastien Montagne force-pushed tmp-wmjob-report-refactor from 234685ffe5 to 40fe7ad74b

2023-10-13 12:37:05 +02:00

Compare

Bastien Montagne reviewed 2023-10-13 12:38:16 +02:00

source/blender/windowmanager/intern/wm_event_system.cc Outdated

						
				@ -943,6 +944,8 @@ static void wm_add_reports(ReportList *reports)

				void WM_report(eReportType type, const char *message)

				{

				  BLI_assert_msg(BLI_thread_is_main(), "WM_report should only be called from the main thread");

Bastien Montagne commented

2023-10-13 12:38:16 +02:00

NOTE: This will only be committed once all wmJobs using it have been updated.

mont29 marked this conversation as resolved

Bastien Montagne force-pushed tmp-wmjob-report-refactor from 40fe7ad74b to 0a584dcead

2023-10-13 12:39:29 +02:00

Compare

Bastien Montagne force-pushed tmp-wmjob-report-refactor from 0a584dcead to 795bd49b63

2023-10-13 12:40:41 +02:00

Compare

Bastien Montagne reviewed 2023-10-13 12:44:32 +02:00

source/blender/windowmanager/intern/wm_event_system.cc Outdated

						
				@ -943,6 +944,8 @@ static void wm_add_reports(ReportList *reports)

				void WM_report(eReportType type, const char *message)

				{

				  BLI_assert_msg(BLI_thread_is_main(), "WM_report should only be called from the main thread");

Bastien Montagne commented

2023-10-13 12:44:32 +02:00

This will only be committed once all wmJobs using WM_report have been updated to use the new wmJob-dedicated reports instead.

This will only be committed once all wmJobs using `WM_report` have been updated to use the new wmJob-dedicated reports instead.

Bastien Montagne commented

2023-10-13 12:55:18 +02:00

@makowalski Thanks for the quick review!

As I mentioned in the comment, I do have a minor concern that the output for for jobs run in the foreground is printed in the console, which means that reports may be displayed differently when USD import/export is executed from a script. This is not necessarily a blocker for me. Would it be possible to get around this by allocating a ReportList on the "dummy" wmJobWorkerStatus instances created when running in the foreground?

That should be totally doable yes. Or maybe even assign the &WM.reports to wmJobWorkerStatus.reports, if this is for sure running from the main thread. And then manually calling WM_report_banner_show() at the end of this non-threaded code path.

I also have a high level question. Taking a step back, might it be possible to have the ReportList be maintained in a singleton of some sort for the USD IO code, so it can be passed to BKE_reportf() in a global function? I know using singletons is usually not a good design choice, but I was wondering if this is even possible.

Technically that should be doable now, yes. But I would rather avoid doing this, indeed singleton/global variables tend to be.... bad for code design, maintainability, proper isolation, and so on.

Also, I think USD I/O code is currently fairly abusing the Report system... Lots of these messages should rather be processed through the logging system imho (se are using CLOG), reports should only be used for messages that are important for the users. Having (sometimes) hundreds of them on a single export defeats this purpose.

Another issue on this topic is that currently, it seems that WM never 'pops-up' these reports generated by USD I/O code. Did not investigate this further, but I do suspect it is due to the UI being locked during that export? Either way, this does not help users discovering these reports.

@makowalski Thanks for the quick review! > As I mentioned in the comment, I do have a minor concern that the output for for jobs run in the foreground is printed in the console, which means that reports may be displayed differently when USD import/export is executed from a script. This is not necessarily a blocker for me. Would it be possible to get around this by allocating a `ReportList` on the "dummy" `wmJobWorkerStatus` instances created when running in the foreground? That should be totally doable yes. Or maybe even assign the `&WM.reports` to `wmJobWorkerStatus.reports`, if this is for sure running from the main thread. And then manually calling `WM_report_banner_show()` at the end of this non-threaded code path. > I also have a high level question. Taking a step back, might it be possible to have the `ReportList` be maintained in a singleton of some sort for the USD IO code, so it can be passed to ` BKE_reportf()` in a global function? I know using singletons is usually not a good design choice, but I was wondering if this is even possible. Technically that should be doable now, yes. But I would rather avoid doing this, indeed singleton/global variables tend to be.... bad for code design, maintainability, proper isolation, and so on. -------------- Also, I think USD I/O code is currently fairly abusing the Report system... Lots of these messages should rather be processed through the logging system imho (se are using CLOG), reports should only be used for messages that are important for the users. Having (sometimes) hundreds of them on a single export defeats this purpose. Another issue on this topic is that currently, it seems that WM never 'pops-up' these reports generated by USD I/O code. Did not investigate this further, but I do suspect it is due to the UI being locked during that export? Either way, this does not help users discovering these reports.

👍 1

Bastien Montagne changed title from ~~WIP: Make wmJob worker thread use their own reports list instead of WM one.~~ to Make wmJob worker thread use their own reports list instead of WM one.

2023-10-13 14:01:43 +02:00

Michael Kowalski commented

2023-10-13 15:18:49 +02:00

Also, I think USD I/O code is currently fairly abusing the Report system... Lots of these messages should rather be processed through the logging system imho (se are using CLOG), reports should only be used for messages that are important for the users. Having (sometimes) hundreds of them on a single export defeats this purpose.

I see your point. So it sounds like a separate task should be to change most of the report messages to use logging instead. I can look into this.

> Also, I think USD I/O code is currently fairly abusing the Report system... Lots of these messages should rather be processed through the logging system imho (se are using CLOG), reports should only be used for messages that are important for the users. Having (sometimes) hundreds of them on a single export defeats this purpose. I see your point. So it sounds like a separate task should be to change most of the report messages to use logging instead. I can look into this.

👍 1

Sergey Sharybin reviewed 2023-10-16 09:38:55 +02:00

source/blender/io/usd/hydra/usd_scene_delegate.cc Outdated

						
				@ -50,6 +52,11 @@ void USDSceneDelegate::populate(Depsgraph *depsgraph)

				  params.export_textures = false; /* Don't copy all textures, is slow. */

				  params.evaluation_mode = DEG_get_mode(depsgraph);

				  /* NOTE: Since the reports list will be `nullptr` here, reports generated by export code from

Sergey Sharybin commented

2023-10-16 09:38:44 +02:00

Does it mean that some reports which are currently sown in the UI will no longer be visible to regular Blender artists?

Bastien Montagne commented

2023-10-16 11:34:30 +02:00

No, because currently there are no reports shown in the UI at all (locking UI seems to also block the report popup from appearing). Which is something else to be tackled too - at some point.

Bastien Montagne commented

2023-10-16 11:35:28 +02:00

Hrrrrm actually, not sure, in the Hydra case... would need to test.

Bastien Montagne commented

2023-10-16 12:57:35 +02:00

Short answer after some testing: I do not know.
I could not get a complex scene (from Pets) to render with Hydra, just gives me an empty result after a split second...

Will just add a wrapper with temp ReportList and then move it to WM at the end here I guess for now. Although this code is not hit with default Hydra settings, you need to switch from Hydra to USD export method in the Hydra Debug panel to actually use this codepath.

Short answer after some testing: I do not know. I could not get a complex scene (from Pets) to render with Hydra, just gives me an empty result after a split second... Will just add a wrapper with temp `ReportList` and then move it to WM at the end here I guess for now. Although this code is not hit with default Hydra settings, you need to switch from `Hydra` to `USD` export method in the `Hydra Debug` panel to actually use this codepath.

mont29 marked this conversation as resolved

Bastien Montagne force-pushed tmp-wmjob-report-refactor from 795bd49b63 to 4da03616f9

2023-10-16 16:01:18 +02:00

Compare

Bastien Montagne commented

2023-10-16 16:01:39 +02:00

@blender-bot build

Sergey Sharybin approved these changes 2023-10-17 10:43:28 +02:00

Sergey Sharybin left a comment

Only did a quick look at the USD/Hydra code. Hopefully Michael can help looking into more details, as it is not really my area.

The changes outside of the IO seems fine. Was thinking maybe renaming WM_reports_add to WM_reports_move or WM_reports_add_move to make it more explicit that the reports are cleared. But not really sure that is really more clear.

Only did a quick look at the USD/Hydra code. Hopefully Michael can help looking into more details, as it is not really my area. The changes outside of the IO seems fine. Was thinking maybe renaming `WM_reports_add` to `WM_reports_move` or `WM_reports_add_move` to make it more explicit that the reports are cleared. But not really sure that is really more clear.

Bastien Montagne commented

2023-10-17 10:52:40 +02:00

The changes outside of the IO seems fine. Was thinking maybe renaming WM_reports_add to WM_reports_move or WM_reports_add_move to make it more explicit that the reports are cleared. But not really sure that is really more clear.

Could also re-use the same naming as the function in BKE : WM_reports_move_to_reports (or WM_reports_move_to_wm_reports ?). But still a bit weird, since we do not explicitly specify the destination reports in the WM version.

> The changes outside of the IO seems fine. Was thinking maybe renaming `WM_reports_add` to `WM_reports_move` or `WM_reports_add_move` to make it more explicit that the reports are cleared. But not really sure that is really more clear. Could also re-use the same naming as the function in BKE : `WM_reports_move_to_reports` (or `WM_reports_move_to_wm_reports` ?). But still a bit weird, since we do not explicitly specify the destination reports in the WM version.

Bastien Montagne referenced this issue from a commit

2023-10-18 12:48:58 +02:00

WM Jobs: Add job's own reporting mechanism.

Bastien Montagne referenced this pull request

2023-10-18 13:07:14 +02:00

Fix USD I/O crashing on reports by using new wmJob report system. #113883

Bastien Montagne commented

2023-10-18 13:08:45 +02:00

Committed core parts of the change as 9727373821 and c5a408f5a1. USD part is being reviewed in !113883.

Committed core parts of the change as 9727373821 and c5a408f5a1. USD part is being reviewed in !113883.

Bastien Montagne closed this pull request

2023-10-18 13:08:47 +02:00