Blender freeze rendering animation with Mantaflow #92423

New Issue

Peter Baintner · 2021-10-22T22:15:31+02:00

Peter Baintner commented

2021-10-22 22:15:31 +02:00

System Information
Operating system: Windows-10-10.0.19041-SP0 64 Bits
Graphics card: NVIDIA GeForce GTX 1080 Ti/PCIe/SSE2 NVIDIA Corporation 4.5.0 NVIDIA 471.41

Blender Version
Broken: version: 3.0.0 Alpha, branch: master, commit date: 2021-10-14 20:36, hash: 2055ef107a
Worked: 2.93

Short description of error
Rendering the scene with Volumetrics and hair particles Cycles freezes. --debug-cycles gives this output.:

Fra:479 Mem:555.84M (Peak 592.46M) | Time:00:00.47 | Mem:0.00M, Peak:0.00M | Scene, main | Initializing
I1022 22:03:40.459005 21492 blender_object.cpp:736] Synchronizing motion for the relative time -1.
I1022 22:03:40.610047 16728 blender_curves.cpp:439] Exporting curve motion segments for hair human.male_genericMesh.003, motion step 0
I1022 22:03:40.610047 16728 blender_curves.cpp:448] Creating new motion vertex position attribute
I1022 22:03:40.611039 18140 blender_curves.cpp:439] Exporting curve motion segments for hair human.eyebrow009Mesh.002, motion step 0
I1022 22:03:40.611039 18140 blender_curves.cpp:448] Creating new motion vertex position attribute
I1022 22:03:40.625043 14316 blender_curves.cpp:439] Exporting curve motion segments for hair human.male_genericMesh.001, motion step 0
I1022 22:03:40.625043 14316 blender_curves.cpp:448] Creating new motion vertex position attribute
I1022 22:03:40.652051 19016 blender_curves.cpp:439] Exporting curve motion segments for hair human.male_genericMesh.007, motion step 0
I1022 22:03:40.652051 19016 blender_curves.cpp:448] Creating new motion vertex position attribute
I1022 22:03:40.676055 21492 blender_object.cpp:736] Synchronizing motion for the relative time 1.

Exact steps for others to reproduce the error
My apologies for the large file, but unfortunately this is the smallest file where I can reproduce the error.

Download and unpack the .zip file:
schlegeis_debug_package.zip
Specify an output path.
With 3.0 launch an animation render of shotfiles/SH_140.blend.
Blender should crash between the very first and the ~25th image.

**System Information** Operating system: Windows-10-10.0.19041-SP0 64 Bits Graphics card: NVIDIA GeForce GTX 1080 Ti/PCIe/SSE2 NVIDIA Corporation 4.5.0 NVIDIA 471.41 **Blender Version** Broken: version: 3.0.0 Alpha, branch: master, commit date: 2021-10-14 20:36, hash: `2055ef107a` Worked: 2.93 **Short description of error** Rendering the scene with Volumetrics and hair particles Cycles freezes. `--debug-cycles` gives this output.: ``` Fra:479 Mem:555.84M (Peak 592.46M) | Time:00:00.47 | Mem:0.00M, Peak:0.00M | Scene, main | Initializing I1022 22:03:40.459005 21492 blender_object.cpp:736] Synchronizing motion for the relative time -1. I1022 22:03:40.610047 16728 blender_curves.cpp:439] Exporting curve motion segments for hair human.male_genericMesh.003, motion step 0 I1022 22:03:40.610047 16728 blender_curves.cpp:448] Creating new motion vertex position attribute I1022 22:03:40.611039 18140 blender_curves.cpp:439] Exporting curve motion segments for hair human.eyebrow009Mesh.002, motion step 0 I1022 22:03:40.611039 18140 blender_curves.cpp:448] Creating new motion vertex position attribute I1022 22:03:40.625043 14316 blender_curves.cpp:439] Exporting curve motion segments for hair human.male_genericMesh.001, motion step 0 I1022 22:03:40.625043 14316 blender_curves.cpp:448] Creating new motion vertex position attribute I1022 22:03:40.652051 19016 blender_curves.cpp:439] Exporting curve motion segments for hair human.male_genericMesh.007, motion step 0 I1022 22:03:40.652051 19016 blender_curves.cpp:448] Creating new motion vertex position attribute I1022 22:03:40.676055 21492 blender_object.cpp:736] Synchronizing motion for the relative time 1. ``` **Exact steps for others to reproduce the error** My apologies for the large file, but unfortunately this is the smallest file where I can reproduce the error. - Download and unpack the .zip file: [schlegeis_debug_package.zip](https://archive.blender.org/developer/F11395974/schlegeis_debug_package.zip) - Specify an output path. - With 3.0 launch an animation render of `shotfiles/SH_140.blend`. - Blender should crash between the very first and the ~25th image.

Peter Baintner commented

2021-10-22 22:15:31 +02:00

Added subscriber: @PeterBaintner

blender-admin commented

2021-10-22 22:15:31 +02:00

#93136 was marked as duplicate of this issue

Peter Baintner changed title from ~~[Cycles X] Freeze at scene build time.~~ to [Cycles X] Freeze at Initializing

2021-10-23 09:13:21 +02:00

Peter Baintner commented

2021-10-23 10:30:06 +02:00

After further investigation I found out, that the problem is probably only the volume. Therefore I was able to reduce the size and complexity of the test file even further.
cycles_x_initializing_bug.zip
There are two scenarios how Cycles freezes. Either it stops after rendering one frame:

Fra:475 Mem:2481.06M (Peak 2940.32M) | Time:00:00.81 | Mem:43.28M, Peak:43.28M | Scene, main | Finished
I1023 10:11:41.508597 13104 blender_session.cpp:467] Total render time: 0.605517
I1023 10:11:41.508597 13104 blender_session.cpp:468] Render time (without synchronization): 0.392864
Saved: 'C:\Users\peter\Desktop\test\test3\SH_140-140--main-hq-v01-0475.exr'
Saved: 'C:\Users\peter\Desktop\test\test3\SH_140-140--main-hq-v01-0475.jpg'
 Time: 00:01.17 (Saving: 00:00.35)

Or it stops while initializing:

Fra:484 Mem:2447.35M (Peak 2940.32M) | Time:00:00.15 | Mem:43.89M, Peak:43.89M | Scene, main | Initializing
I1023 10:12:39.088085 16584 blender_object.cpp:736] Synchronizing motion for the relative time -1.
I1023 10:12:39.203111 16584 blender_object.cpp:736] Synchronizing motion for the relative time 1.

After further investigation I found out, that the problem is probably only the volume. Therefore I was able to reduce the size and complexity of the test file even further. [cycles_x_initializing_bug.zip](https://archive.blender.org/developer/F11417645/cycles_x_initializing_bug.zip) There are two scenarios how Cycles freezes. Either it stops after rendering one frame: ``` Fra:475 Mem:2481.06M (Peak 2940.32M) | Time:00:00.81 | Mem:43.28M, Peak:43.28M | Scene, main | Finished I1023 10:11:41.508597 13104 blender_session.cpp:467] Total render time: 0.605517 I1023 10:11:41.508597 13104 blender_session.cpp:468] Render time (without synchronization): 0.392864 Saved: 'C:\Users\peter\Desktop\test\test3\SH_140-140--main-hq-v01-0475.exr' Saved: 'C:\Users\peter\Desktop\test\test3\SH_140-140--main-hq-v01-0475.jpg' Time: 00:01.17 (Saving: 00:00.35) ``` Or it stops while initializing: ``` Fra:484 Mem:2447.35M (Peak 2940.32M) | Time:00:00.15 | Mem:43.89M, Peak:43.89M | Scene, main | Initializing I1023 10:12:39.088085 16584 blender_object.cpp:736] Synchronizing motion for the relative time -1. I1023 10:12:39.203111 16584 blender_object.cpp:736] Synchronizing motion for the relative time 1. ```

Raimund Klink commented

2021-10-25 13:34:49 +02:00

Added subscriber: @Raimund58

William Leeson commented

2021-10-25 15:17:57 +02:00

Added subscriber: @leesonw

William Leeson commented

2021-10-25 15:17:57 +02:00

If I run the regular version it seems to hang. I got a lot of debug output when I rand this on a debug build see P2539 but it did not crash I could even try and render and that worked kind of. It does seem like something is wrong as there are division by zero errors which is probably causing something probably uninitialised data which would be different in a debug vs release build :-)

If I run the regular version it seems to hang. I got a lot of debug output when I rand this on a debug build see [P2539](https://archive.blender.org/developer/P2539.txt) but it did not crash I could even try and render and that worked kind of. It does seem like something is wrong as there are division by zero errors which is probably causing something probably uninitialised data which would be different in a debug vs release build :-)

William Leeson commented

2021-10-25 15:18:18 +02:00

Changed status from 'Needs Triage' to: 'Confirmed'

Brecht Van Lommel commented

2021-10-26 16:57:04 +02:00

Added subscriber: @brecht

Brecht Van Lommel commented

2021-10-26 16:57:04 +02:00

I see this backtrace for one of the threads:
P2547: (An Untitled Masterwork)

Thread 132 (Thread 0x7f8ada7f9700 (LWP 183428)):
#0  __lll_lock_wait (futex=futex@entry=0x10f4dc08 <python_driver_lock>, private=0) at lowlevellock.c:52
#1  0x00007f8bd38810a3 in __GI___pthread_mutex_lock (mutex=0x10f4dc08 <python_driver_lock>) at ../nptl/pthread_mutex_lock.c:80
#2  0x0000000001314eeb in evaluate_driver_python (anim_rna=0x7f8ada7b2ba0, driver=0x7f8ac409f138, driver_orig=0x7f8ac409f138, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve_driver.c:1261
#3  evaluate_driver (anim_rna=0x7f8ada7b2ba0, driver=0x7f8ac409f138, driver_orig=0x7f8ac409f138, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve_driver.c:1300
#4  0x00000000013137b9 in evaluate_fcurve_driver (anim_rna=0x7f8ada7b2ba0, fcu=0x7f8ac409f068, driver_orig=0x2, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve.c:2217
#5  calculate_fcurve (anim_rna=0x7f8ada7b2ba0, fcu=0x7f8ac409f068, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve.c:2273
#6  0x00000000012bb4d8 in BKE_animsys_eval_driver (depsgraph=0x7f8a605b0ac8, id=<optimized out>, driver_index=<optimized out>, fcu_orig=0x28bc8748) at /home/brecht/dev/blender/source/blender/blenkernel/intern/anim_sys.c:3565
#7  0x00000000014d62c4 in std::function<void (Depsgraph*)>::operator()(Depsgraph*) const (this=0x7f8a606d7098, __args=0x7f8a605b0ac8) at /usr/bin/../lib/gcc/x86_64-linux-gnu/10/../../../../include/c++/10/bits/std_function.h:622
#8  blender::deg::(anonymous namespace)::evaluate_node(blender::deg::(anonymous namespace)::DepsgraphEvalState const*, blender::deg::OperationNode*) (state=0x7f8a8b7b9220, operation_node=<optimized out>) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:118
#9  blender::deg::(anonymous namespace)::deg_task_run_func(TaskPool*, void*) (pool=0x7f8a605210c8, taskdata=0x7f8a606d6fe8) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:129
#10 0x000000000a956baf in Task::operator()() const (this=0xfffffffffffffe08) at /home/brecht/dev/blender/source/blender/blenlib/intern/task_pool.cc:178
#11 tbb::internal::function_task<Task>::execute() (this=0xfffffffffffffe00) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/task.h:1059
#12 0x00000000013d0935 in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::process_bypass_loop(tbb::internal::context_guard_helper<false>&, tbb::task*, long) ()
#13 0x00000000013d0beb in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::local_wait_for_all(tbb::task&, tbb::task*) ()
#14 0x00000000013ce490 in tbb::internal::generic_scheduler::local_spawn_root_and_wait(tbb::task*, tbb::task*&) ()
#15 0x0000000008f7f67f in tbb::task::spawn_root_and_wait(tbb::task&) (root=...) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/task.h:809
#16 tbb::interface9::internal::start_for<tbb::blocked_range<long long>, Manta::knCopyVec3ToReal, tbb::auto_partitioner const>::run(tbb::blocked_range<long long> const&, Manta::knCopyVec3ToReal const&, tbb::auto_partitioner const&) (range=..., body=..., partitioner=...) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/parallel_for.h:95
--Type <RET> for more, q to quit, c to continue without paging--
#17 0x0000000008f2f8fe in tbb::parallel_for<tbb::blocked_range<long long>, Manta::knCopyVec3ToReal>(tbb::blocked_range<long long> const&, Manta::knCopyVec3ToReal const&) (range=..., body=...) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/parallel_for.h:201
#18 Manta::knCopyVec3ToReal::run() (this=0x7f8ada7b2f10) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1890
#19 Manta::knCopyVec3ToReal::knCopyVec3ToReal(Manta::Grid<Manta::Vector3D<float> >&, Manta::Grid<float>&, Manta::Grid<float>&, Manta::Grid<float>&) (this=0x7f8ada7b2f10, source=..., targetX=..., targetY=..., targetZ=...) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1829
#20 Manta::copyVec3ToReal(Manta::Grid<Manta::Vector3D<float> >&, Manta::Grid<float>&, Manta::Grid<float>&, Manta::Grid<float>&) (source=..., targetX=..., targetY=..., targetZ=...) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1905
#21 Manta::_W_8(_object*, _object*, _object*) (_self=<optimized out>, _linargs=<optimized out>, _kwds=<optimized out>) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1922
#22 0x000000000943efb3 in cfunction_call (func=0x7f8b6e603540, args=<optimized out>, kwargs=<optimized out>) at Objects/methodobject.c:543
#23 0x0000000009400cf0 in _PyObject_MakeTpCall (tstate=0x7f8a78113a50, callable=0x7f8b6e603540, args=<optimized out>, nargs=<optimized out>, keywords=0x7f8b640cc040) at Objects/call.c:191
#24 0x0000000000f5370c in _PyObject_VectorcallTstate (kwnames=0x7f8b640cc040, nargsf=<optimized out>, args=0x7f8b6c0cb598, callable=0x7f8b6e603540, tstate=0x7f8a78113a50) at ./Include/cpython/abstract.h:116
#25 _PyObject_VectorcallTstate (kwnames=0x7f8b640cc040, nargsf=<optimized out>, args=0x7f8b6c0cb598, callable=0x7f8b6e603540, tstate=0x7f8a78113a50) at ./Include/cpython/abstract.h:103
#26 PyObject_Vectorcall (kwnames=0x7f8b640cc040, nargsf=<optimized out>, args=0x7f8b6c0cb598, callable=0x7f8b6e603540) at ./Include/cpython/abstract.h:127
#27 call_function (kwnames=0x7f8b640cc040, oparg=<optimized out>, pp_stack=<synthetic pointer>, tstate=0x7f8a78113a50) at Python/ceval.c:5075
#28 _PyEval_EvalFrameDefault (tstate=<optimized out>, f=<optimized out>, throwflag=<optimized out>) at Python/ceval.c:3535
#29 0x0000000000f4c54b in _PyEval_EvalFrame (throwflag=0, f=0x7f8b6c0cb400, tstate=0x7f8a78113a50) at ./Include/internal/pycore_ceval.h:40
#30 function_code_fastcall (tstate=0x7f8a78113a50, co=<optimized out>, args=<optimized out>, nargs=4, globals=<optimized out>) at Objects/call.c:330
#31 0x0000000000f52e7c in _PyObject_VectorcallTstate (kwnames=0x0, nargsf=<optimized out>, args=0x7f8b1c0956c0, callable=0x7f8b640ca670, tstate=0x7f8a78113a50) at ./Include/cpython/abstract.h:118
#32 PyObject_Vectorcall (kwnames=0x0, nargsf=<optimized out>, args=0x7f8b1c0956c0, callable=<optimized out>) at ./Include/cpython/abstract.h:127
#33 call_function (kwnames=0x0, oparg=<optimized out>, pp_stack=<synthetic pointer>, tstate=0x7f8a78113a50) at Python/ceval.c:5075
#34 _PyEval_EvalFrameDefault (tstate=<optimized out>, f=<optimized out>, throwflag=<optimized out>) at Python/ceval.c:3518
#35 0x00000000094ae464 in _PyEval_EvalFrame (throwflag=0, f=0x7f8b1c095550, tstate=0x7f8a78113a50) at ./Include/internal/pycore_ceval.h:40
#36 _PyEval_EvalCode (tstate=0x7f8a78113a50, _co=_co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, args=args@entry=0x0, argcount=argcount@entry=0, kwnames=0x0, kwargs=0x0, kwcount=0, kwstep=2, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0, name=0x0, qualname=0x0) at Python/ceval.c:4327
#37 0x00000000094ae7ae in _PyEval_EvalCodeWithName (_co=_co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, args=args@entry=0x0, argcount=argcount@entry=0, kwnames=kwnames@entry=0x0, kwargs=0x0, kwcount=0, kwstep=2, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0, name=0x0, qualname=0x0) at Python/ceval.c:4359
#38 0x00000000094ae7fe in PyEval_EvalCodeEx (_co=_co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, args=args@entry=0x0, argcount=argcount@entry=0, kws=kws@entry=0x0, kwcount=0, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0) at Python/ceval.c:4375
#39 0x00000000094ae82b in PyEval_EvalCode (co=co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140) at Python/ceval.c:826
#40 0x00000000094e9155 in run_eval_code_obj (locals=0x7f8b8aff2140, globals=0x7f8b8aff2140, co=0x7f8b1c092870, tstate=0x7f8a78113a50) at Python/pythonrun.c:1219
#41 run_mod (mod=mod@entry=0x7f8a7816b1a0, filename=filename@entry=0x7f8b8af01a70, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, flags=flags@entry=0x0, arena=arena@entry=0x7f8b1c30d950) at Python/pythonrun.c:1240
#42 0x00000000094e9e53 in PyRun_StringFlags (str=<optimized out>, start=257, globals=0x7f8b8aff2140, locals=0x7f8b8aff2140, flags=0x0) at Python/pythonrun.c:1106
#43 0x0000000008e7923f in MANTA::runPythonString(std::vector<std::string, std::allocator<std::string> >) (this=<optimized out>, commands=warning: Type size unknown, assuming 1. Try casting to a known type, or void *.
warning: Type size unknown, assuming 1. Try casting to a known type, or void *.
Python Exception <class 'gdb.error'> Cannot perform pointer math on incomplete type "std::basic_string<char, std::char_traits<char>, std::allocator<char> >", try casting to a known type, or void *.: 
std::vector of length 8, capacity 8) at /home/brecht/dev/blender/intern/mantaflow/intern/MANTA_main.cpp:609
#44 0x0000000008e7dad5 in MANTA::readData(FluidModifierData*, int, bool) (this=<optimized out>, fmd=<optimized out>, framenr=475, resumable=false) at /home/brecht/dev/blender/intern/mantaflow/intern/MANTA_main.cpp:1277
#45 0x000000000131a15d in BKE_fluid_modifier_processDomain (fmd=<optimized out>, depsgraph=<optimized out>, scene=<optimized out>, ob=<optimized out>, me=0x7f8a781778e8, scene_framenr=<optimized out>) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fluid.c:3867
#46 0x0000000001316d5a in BKE_fluid_modifier_process (fmd=0x7f8ad0155a38, depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, me=0x7f8a781778e8) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fluid.c:4160
#47 BKE_fluid_modifier_do (fmd=0x7f8ad0155a38, depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, me=0x7f8a781778e8) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fluid.c:4178
#48 0x000000000168e261 in modifyMesh (md=0x7f8ad0155a38, ctx=0x7f8ada7b44e0, me=0x7f8a781778e8) at /home/brecht/dev/blender/source/blender/modifiers/intern/MOD_fluid.c:130
#49 0x00000000012ae3b4 in mesh_calc_modifiers(Depsgraph*, Scene*, Object*, bool, bool, CustomData_MeshMasks const*, int, bool, bool, Mesh**, Mesh**, GeometrySet**) (depsgraph=<optimized out>, scene=<optimized out>, ob=<optimized out>, use_deform=true, need_mapping=false, dataMask=<optimized out>, index=-1, use_cache=<optimized out>, allow_shared_mesh=<optimized out>, r_deform=0x7f8ada7b49c8, r_final=0x7f8ada7b49d0, r_geometry_set=0x7f8ada7b49c0) at /home/brecht/dev/blender/source/blender/blenkernel/intern/DerivedMesh.cc:1249
#50 0x00000000012ad575 in mesh_build_data(Depsgraph*, Scene*, Object*, CustomData_MeshMasks const*, bool) (depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, dataMask=0x7f8ada7b4a20, need_mapping=false) at /home/brecht/dev/blender/source/blender/blenkernel/intern/DerivedMesh.cc:1872
#51 0x00000000012ac8bb in makeDerivedMesh(Depsgraph*, Scene*, Object*, BMEditMesh*, CustomData_MeshMasks const*) (depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, em=0x0, dataMask=<optimized out>) at /home/brecht/dev/blender/source/blender/blenkernel/intern/DerivedMesh.cc:2019
#52 0x00000000010048b6 in BKE_object_handle_data_update (depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928) at /home/brecht/dev/blender/source/blender/blenkernel/intern/object_update.c:202
#53 0x0000000001004c2f in BKE_object_eval_uber_data (depsgraph=0x7f8a605b0ac8, scene=0x80, ob=0x7f8a60648928) at /home/brecht/dev/blender/source/blender/blenkernel/intern/object_update.c:395
#54 0x00000000014d62c4 in std::function<void (Depsgraph*)>::operator()(Depsgraph*) const (this=0x7f8a6064a7b8, __args=0x7f8a605b0ac8) at /usr/bin/../lib/gcc/x86_64-linux-gnu/10/../../../../include/c++/10/bits/std_function.h:622
#55 blender::deg::(anonymous namespace)::evaluate_node(blender::deg::(anonymous namespace)::DepsgraphEvalState const*, blender::deg::OperationNode*) (state=0x7f8a8b7b9220, operation_node=<optimized out>) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:118
#56 blender::deg::(anonymous namespace)::deg_task_run_func(TaskPool*, void*) (pool=0x7f8a605210c8, taskdata=0x7f8a6064a708) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:129
#57 0x000000000a956baf in Task::operator()() const (this=0xfffffffffffffe08) at /home/brecht/dev/blender/source/blender/blenlib/intern/task_pool.cc:178
#58 tbb::internal::function_task<Task>::execute() (this=0xfffffffffffffe00) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/task.h:1059
#59 0x00000000013d0935 in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::process_bypass_loop(tbb::internal::context_guard_helper<false>&, tbb::task*, long) ()
#60 0x00000000013d0beb in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::local_wait_for_all(tbb::task&, tbb::task*) ()
#61 0x00000000013bf827 in tbb::internal::arena::process(tbb::internal::generic_scheduler&) ()
#62 0x00000000013ca640 in tbb::internal::market::process(rml::job&) ()
#63 0x00000000013cc66c in tbb::internal::rml::private_worker::run() ()
#64 0x00000000013cc869 in tbb::internal::rml::private_worker::thread_routine(void*) ()
#65 0x00007f8bd387e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#66 0x00007f8bd3b09293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Looks like some kind of deadlock involving Mantaflow Python scripts, Python drivers, and TBB.

I see this backtrace for one of the threads: [P2547: (An Untitled Masterwork)](https://archive.blender.org/developer/P2547.txt) ``` Thread 132 (Thread 0x7f8ada7f9700 (LWP 183428)): #0 __lll_lock_wait (futex=futex@entry=0x10f4dc08 <python_driver_lock>, private=0) at lowlevellock.c:52 #1 0x00007f8bd38810a3 in __GI___pthread_mutex_lock (mutex=0x10f4dc08 <python_driver_lock>) at ../nptl/pthread_mutex_lock.c:80 #2 0x0000000001314eeb in evaluate_driver_python (anim_rna=0x7f8ada7b2ba0, driver=0x7f8ac409f138, driver_orig=0x7f8ac409f138, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve_driver.c:1261 #3 evaluate_driver (anim_rna=0x7f8ada7b2ba0, driver=0x7f8ac409f138, driver_orig=0x7f8ac409f138, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve_driver.c:1300 #4 0x00000000013137b9 in evaluate_fcurve_driver (anim_rna=0x7f8ada7b2ba0, fcu=0x7f8ac409f068, driver_orig=0x2, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve.c:2217 #5 calculate_fcurve (anim_rna=0x7f8ada7b2ba0, fcu=0x7f8ac409f068, anim_eval_context=0x7f8ada7b2b90) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fcurve.c:2273 #6 0x00000000012bb4d8 in BKE_animsys_eval_driver (depsgraph=0x7f8a605b0ac8, id=<optimized out>, driver_index=<optimized out>, fcu_orig=0x28bc8748) at /home/brecht/dev/blender/source/blender/blenkernel/intern/anim_sys.c:3565 #7 0x00000000014d62c4 in std::function<void (Depsgraph*)>::operator()(Depsgraph*) const (this=0x7f8a606d7098, __args=0x7f8a605b0ac8) at /usr/bin/../lib/gcc/x86_64-linux-gnu/10/../../../../include/c++/10/bits/std_function.h:622 #8 blender::deg::(anonymous namespace)::evaluate_node(blender::deg::(anonymous namespace)::DepsgraphEvalState const*, blender::deg::OperationNode*) (state=0x7f8a8b7b9220, operation_node=<optimized out>) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:118 #9 blender::deg::(anonymous namespace)::deg_task_run_func(TaskPool*, void*) (pool=0x7f8a605210c8, taskdata=0x7f8a606d6fe8) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:129 #10 0x000000000a956baf in Task::operator()() const (this=0xfffffffffffffe08) at /home/brecht/dev/blender/source/blender/blenlib/intern/task_pool.cc:178 #11 tbb::internal::function_task<Task>::execute() (this=0xfffffffffffffe00) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/task.h:1059 #12 0x00000000013d0935 in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::process_bypass_loop(tbb::internal::context_guard_helper<false>&, tbb::task*, long) () #13 0x00000000013d0beb in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::local_wait_for_all(tbb::task&, tbb::task*) () #14 0x00000000013ce490 in tbb::internal::generic_scheduler::local_spawn_root_and_wait(tbb::task*, tbb::task*&) () #15 0x0000000008f7f67f in tbb::task::spawn_root_and_wait(tbb::task&) (root=...) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/task.h:809 #16 tbb::interface9::internal::start_for<tbb::blocked_range<long long>, Manta::knCopyVec3ToReal, tbb::auto_partitioner const>::run(tbb::blocked_range<long long> const&, Manta::knCopyVec3ToReal const&, tbb::auto_partitioner const&) (range=..., body=..., partitioner=...) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/parallel_for.h:95 --Type <RET> for more, q to quit, c to continue without paging-- #17 0x0000000008f2f8fe in tbb::parallel_for<tbb::blocked_range<long long>, Manta::knCopyVec3ToReal>(tbb::blocked_range<long long> const&, Manta::knCopyVec3ToReal const&) (range=..., body=...) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/parallel_for.h:201 #18 Manta::knCopyVec3ToReal::run() (this=0x7f8ada7b2f10) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1890 #19 Manta::knCopyVec3ToReal::knCopyVec3ToReal(Manta::Grid<Manta::Vector3D<float> >&, Manta::Grid<float>&, Manta::Grid<float>&, Manta::Grid<float>&) (this=0x7f8ada7b2f10, source=..., targetX=..., targetY=..., targetZ=...) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1829 #20 Manta::copyVec3ToReal(Manta::Grid<Manta::Vector3D<float> >&, Manta::Grid<float>&, Manta::Grid<float>&, Manta::Grid<float>&) (source=..., targetX=..., targetY=..., targetZ=...) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1905 #21 Manta::_W_8(_object*, _object*, _object*) (_self=<optimized out>, _linargs=<optimized out>, _kwds=<optimized out>) at /home/brecht/dev/blender/extern/mantaflow/preprocessed/grid.cpp:1922 #22 0x000000000943efb3 in cfunction_call (func=0x7f8b6e603540, args=<optimized out>, kwargs=<optimized out>) at Objects/methodobject.c:543 #23 0x0000000009400cf0 in _PyObject_MakeTpCall (tstate=0x7f8a78113a50, callable=0x7f8b6e603540, args=<optimized out>, nargs=<optimized out>, keywords=0x7f8b640cc040) at Objects/call.c:191 #24 0x0000000000f5370c in _PyObject_VectorcallTstate (kwnames=0x7f8b640cc040, nargsf=<optimized out>, args=0x7f8b6c0cb598, callable=0x7f8b6e603540, tstate=0x7f8a78113a50) at ./Include/cpython/abstract.h:116 #25 _PyObject_VectorcallTstate (kwnames=0x7f8b640cc040, nargsf=<optimized out>, args=0x7f8b6c0cb598, callable=0x7f8b6e603540, tstate=0x7f8a78113a50) at ./Include/cpython/abstract.h:103 #26 PyObject_Vectorcall (kwnames=0x7f8b640cc040, nargsf=<optimized out>, args=0x7f8b6c0cb598, callable=0x7f8b6e603540) at ./Include/cpython/abstract.h:127 #27 call_function (kwnames=0x7f8b640cc040, oparg=<optimized out>, pp_stack=<synthetic pointer>, tstate=0x7f8a78113a50) at Python/ceval.c:5075 #28 _PyEval_EvalFrameDefault (tstate=<optimized out>, f=<optimized out>, throwflag=<optimized out>) at Python/ceval.c:3535 #29 0x0000000000f4c54b in _PyEval_EvalFrame (throwflag=0, f=0x7f8b6c0cb400, tstate=0x7f8a78113a50) at ./Include/internal/pycore_ceval.h:40 #30 function_code_fastcall (tstate=0x7f8a78113a50, co=<optimized out>, args=<optimized out>, nargs=4, globals=<optimized out>) at Objects/call.c:330 #31 0x0000000000f52e7c in _PyObject_VectorcallTstate (kwnames=0x0, nargsf=<optimized out>, args=0x7f8b1c0956c0, callable=0x7f8b640ca670, tstate=0x7f8a78113a50) at ./Include/cpython/abstract.h:118 #32 PyObject_Vectorcall (kwnames=0x0, nargsf=<optimized out>, args=0x7f8b1c0956c0, callable=<optimized out>) at ./Include/cpython/abstract.h:127 #33 call_function (kwnames=0x0, oparg=<optimized out>, pp_stack=<synthetic pointer>, tstate=0x7f8a78113a50) at Python/ceval.c:5075 #34 _PyEval_EvalFrameDefault (tstate=<optimized out>, f=<optimized out>, throwflag=<optimized out>) at Python/ceval.c:3518 #35 0x00000000094ae464 in _PyEval_EvalFrame (throwflag=0, f=0x7f8b1c095550, tstate=0x7f8a78113a50) at ./Include/internal/pycore_ceval.h:40 #36 _PyEval_EvalCode (tstate=0x7f8a78113a50, _co=_co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, args=args@entry=0x0, argcount=argcount@entry=0, kwnames=0x0, kwargs=0x0, kwcount=0, kwstep=2, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0, name=0x0, qualname=0x0) at Python/ceval.c:4327 #37 0x00000000094ae7ae in _PyEval_EvalCodeWithName (_co=_co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, args=args@entry=0x0, argcount=argcount@entry=0, kwnames=kwnames@entry=0x0, kwargs=0x0, kwcount=0, kwstep=2, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0, name=0x0, qualname=0x0) at Python/ceval.c:4359 #38 0x00000000094ae7fe in PyEval_EvalCodeEx (_co=_co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, args=args@entry=0x0, argcount=argcount@entry=0, kws=kws@entry=0x0, kwcount=0, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0) at Python/ceval.c:4375 #39 0x00000000094ae82b in PyEval_EvalCode (co=co@entry=0x7f8b1c092870, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140) at Python/ceval.c:826 #40 0x00000000094e9155 in run_eval_code_obj (locals=0x7f8b8aff2140, globals=0x7f8b8aff2140, co=0x7f8b1c092870, tstate=0x7f8a78113a50) at Python/pythonrun.c:1219 #41 run_mod (mod=mod@entry=0x7f8a7816b1a0, filename=filename@entry=0x7f8b8af01a70, globals=globals@entry=0x7f8b8aff2140, locals=locals@entry=0x7f8b8aff2140, flags=flags@entry=0x0, arena=arena@entry=0x7f8b1c30d950) at Python/pythonrun.c:1240 #42 0x00000000094e9e53 in PyRun_StringFlags (str=<optimized out>, start=257, globals=0x7f8b8aff2140, locals=0x7f8b8aff2140, flags=0x0) at Python/pythonrun.c:1106 #43 0x0000000008e7923f in MANTA::runPythonString(std::vector<std::string, std::allocator<std::string> >) (this=<optimized out>, commands=warning: Type size unknown, assuming 1. Try casting to a known type, or void *. warning: Type size unknown, assuming 1. Try casting to a known type, or void *. Python Exception <class 'gdb.error'> Cannot perform pointer math on incomplete type "std::basic_string<char, std::char_traits<char>, std::allocator<char> >", try casting to a known type, or void *.: std::vector of length 8, capacity 8) at /home/brecht/dev/blender/intern/mantaflow/intern/MANTA_main.cpp:609 #44 0x0000000008e7dad5 in MANTA::readData(FluidModifierData*, int, bool) (this=<optimized out>, fmd=<optimized out>, framenr=475, resumable=false) at /home/brecht/dev/blender/intern/mantaflow/intern/MANTA_main.cpp:1277 #45 0x000000000131a15d in BKE_fluid_modifier_processDomain (fmd=<optimized out>, depsgraph=<optimized out>, scene=<optimized out>, ob=<optimized out>, me=0x7f8a781778e8, scene_framenr=<optimized out>) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fluid.c:3867 #46 0x0000000001316d5a in BKE_fluid_modifier_process (fmd=0x7f8ad0155a38, depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, me=0x7f8a781778e8) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fluid.c:4160 #47 BKE_fluid_modifier_do (fmd=0x7f8ad0155a38, depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, me=0x7f8a781778e8) at /home/brecht/dev/blender/source/blender/blenkernel/intern/fluid.c:4178 #48 0x000000000168e261 in modifyMesh (md=0x7f8ad0155a38, ctx=0x7f8ada7b44e0, me=0x7f8a781778e8) at /home/brecht/dev/blender/source/blender/modifiers/intern/MOD_fluid.c:130 #49 0x00000000012ae3b4 in mesh_calc_modifiers(Depsgraph*, Scene*, Object*, bool, bool, CustomData_MeshMasks const*, int, bool, bool, Mesh**, Mesh**, GeometrySet**) (depsgraph=<optimized out>, scene=<optimized out>, ob=<optimized out>, use_deform=true, need_mapping=false, dataMask=<optimized out>, index=-1, use_cache=<optimized out>, allow_shared_mesh=<optimized out>, r_deform=0x7f8ada7b49c8, r_final=0x7f8ada7b49d0, r_geometry_set=0x7f8ada7b49c0) at /home/brecht/dev/blender/source/blender/blenkernel/intern/DerivedMesh.cc:1249 #50 0x00000000012ad575 in mesh_build_data(Depsgraph*, Scene*, Object*, CustomData_MeshMasks const*, bool) (depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, dataMask=0x7f8ada7b4a20, need_mapping=false) at /home/brecht/dev/blender/source/blender/blenkernel/intern/DerivedMesh.cc:1872 #51 0x00000000012ac8bb in makeDerivedMesh(Depsgraph*, Scene*, Object*, BMEditMesh*, CustomData_MeshMasks const*) (depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928, em=0x0, dataMask=<optimized out>) at /home/brecht/dev/blender/source/blender/blenkernel/intern/DerivedMesh.cc:2019 #52 0x00000000010048b6 in BKE_object_handle_data_update (depsgraph=0x7f8a605b0ac8, scene=0x7f8a6050cdb8, ob=0x7f8a60648928) at /home/brecht/dev/blender/source/blender/blenkernel/intern/object_update.c:202 #53 0x0000000001004c2f in BKE_object_eval_uber_data (depsgraph=0x7f8a605b0ac8, scene=0x80, ob=0x7f8a60648928) at /home/brecht/dev/blender/source/blender/blenkernel/intern/object_update.c:395 #54 0x00000000014d62c4 in std::function<void (Depsgraph*)>::operator()(Depsgraph*) const (this=0x7f8a6064a7b8, __args=0x7f8a605b0ac8) at /usr/bin/../lib/gcc/x86_64-linux-gnu/10/../../../../include/c++/10/bits/std_function.h:622 #55 blender::deg::(anonymous namespace)::evaluate_node(blender::deg::(anonymous namespace)::DepsgraphEvalState const*, blender::deg::OperationNode*) (state=0x7f8a8b7b9220, operation_node=<optimized out>) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:118 #56 blender::deg::(anonymous namespace)::deg_task_run_func(TaskPool*, void*) (pool=0x7f8a605210c8, taskdata=0x7f8a6064a708) at /home/brecht/dev/blender/source/blender/depsgraph/intern/eval/deg_eval.cc:129 #57 0x000000000a956baf in Task::operator()() const (this=0xfffffffffffffe08) at /home/brecht/dev/blender/source/blender/blenlib/intern/task_pool.cc:178 #58 tbb::internal::function_task<Task>::execute() (this=0xfffffffffffffe00) at /home/brecht/dev/lib/linux_centos7_x86_64/tbb/include/tbb/task.h:1059 #59 0x00000000013d0935 in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::process_bypass_loop(tbb::internal::context_guard_helper<false>&, tbb::task*, long) () #60 0x00000000013d0beb in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::local_wait_for_all(tbb::task&, tbb::task*) () #61 0x00000000013bf827 in tbb::internal::arena::process(tbb::internal::generic_scheduler&) () #62 0x00000000013ca640 in tbb::internal::market::process(rml::job&) () #63 0x00000000013cc66c in tbb::internal::rml::private_worker::run() () #64 0x00000000013cc869 in tbb::internal::rml::private_worker::thread_routine(void*) () #65 0x00007f8bd387e609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #66 0x00007f8bd3b09293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 ``` Looks like some kind of deadlock involving Mantaflow Python scripts, Python drivers, and TBB.

Sergey Sharybin commented

2021-10-26 17:03:07 +02:00

Added subscribers: @dr.sybren, @Sergey

Sergey Sharybin commented

2021-10-26 17:03:07 +02:00

This seems to be good old friend GIL. There were some changes in 3.0 related on how the dependency graph handles drivers and GIL, but reverting those does not solve the problem. Would be nice to have a closer look with @sybren.

Based on backtrace i have P2548 it seems one of the threads locks drivers mutex and is being held inside of the lock due to PyGILState_Ensure, while others are helding the GIL and are trying to enter the driver lock. Something like this, wouldn't know why otherwise the code will be locked in this state.

This seems to be good old friend GIL. There were some changes in 3.0 related on how the dependency graph handles drivers and GIL, but reverting those does not solve the problem. Would be nice to have a closer look with @sybren. Based on backtrace i have [P2548](https://archive.blender.org/developer/P2548.txt) it seems one of the threads locks drivers mutex and is being held inside of the lock due to `PyGILState_Ensure`, while others are helding the GIL and are trying to enter the driver lock. Something like this, wouldn't know why otherwise the code will be locked in this state.

Sergey Sharybin commented

2021-10-26 17:13:16 +02:00

Seems we've been typing with Brecht in parallel :)

Sybren had a look into my backtrace (thanks a lot!) so correction to my previous comment: the TBB threading in the mantaflow steals tasks from the dependency graph pool, which makes them to be executed from the wrong state of GIL. Seems like we "just" need to isolate either depsgraph or mantaflow pools.

Seems we've been typing with Brecht in parallel :) Sybren had a look into my backtrace (thanks a lot!) so correction to my previous comment: the TBB threading in the mantaflow steals tasks from the dependency graph pool, which makes them to be executed from the wrong state of GIL. Seems like we "just" need to isolate either depsgraph or mantaflow pools.

Sergey Sharybin commented

2021-10-26 17:36:17 +02:00

A proof-of-concept patch: P2549. Seems to work (tm), for this file at least. There are other parallel code in Mantaflow which might need isolation.

@brecht, having a second though here. Shall we isolate from Mantaflow, or we do isolation on the Mantaflow API usage level (as in, have isolation calls in BKE_fluid_*) ?

A proof-of-concept patch: [P2549](https://archive.blender.org/developer/P2549.txt). Seems to work (tm), for this file at least. There are other parallel code in Mantaflow which might need isolation. @brecht, having a second though here. Shall we isolate from Mantaflow, or we do isolation on the Mantaflow API usage level (as in, have isolation calls in `BKE_fluid_*`) ?

blender-admin commented

2021-10-27 14:40:18 +02:00

This issue was referenced by 8507336e76

This issue was referenced by 8507336e76902604a2128b23a4d8e52094031ab0

Sergey Sharybin changed title from ~~[Cycles X] Freeze at Initializing~~ to Blender freeze rendering animation with Mantaflow

2021-10-27 14:40:51 +02:00

Sergey Sharybin self-assigned this 2021-10-27 14:40:55 +02:00

Sergey Sharybin commented

2021-10-27 14:53:21 +02:00

Changed status from 'Confirmed' to: 'Resolved'

Sergey Sharybin closed this issue

2021-10-27 14:53:21 +02:00