gabgren
December 14, 2015, 10:33pm
1
Hi,
Sometimes Deadline does not seem to catch that a task is done… The Slave log clearly states Render finished, but the task is still going in Deadline and therefore the slave doesn’t jump to the next task. The frame is successfully saved and not corrupted
eamsler
December 15, 2015, 3:39pm
2
We’re reliant on the rendering program closing to know when we can move on.
What version of Deadline is this? Also, is this a Maya job?
gabgren
December 15, 2015, 3:46pm
3
Hi, this is Deadline Version: 7.2.0.18 R (79a3ddcab)
And Cinema 4D R17.048
I remember seeing the same behaviour very rarely in R16,
but now in R17 this seems to be 1/10 tasks pretty much all the time
eamsler
December 15, 2015, 4:03pm
4
I definitely didn’t expect this to be C4D.
I wonder if it’s due to a crash. If you go over to one of the machines that’s stuck, can you see if there’s a crash dialog asking to report the issue or close the app? If that’s not the case, try closing C4D from task manager just to make sure it’s that app and not Deadline (it shouldn’t be Deadline, but worth checking).
If the app did crash, we can set the registry to make sure Windows doesn’t hold it open.
gabgren
December 15, 2015, 4:38pm
5
No diaglog/crash …
In the task manager tho we can clearly see that C4D is still running
I killed the process, but Deadline saw this as an error: “Renderer returned non-zero error code”
gabgren
December 15, 2015, 4:42pm
6
last lines from the slave log
2015-12-15 11:37:32: 0: STDOUT: Rendering Phase: Setup
2015-12-15 11:37:32: 0: STDOUT: Progress: 0%
2015-12-15 11:37:32: 0: STDOUT:
2015-12-15 11:37:32: 0: STDOUT: FRAME 24 fps:30 camMb:0 objMb:0
2015-12-15 11:37:32: 0: STDOUT: Movable:13 Nodes:64 Tri:0/7k Mesh:15 Hair:0 Used/free/total vram:100Mb/11.52Gb/12Gb
2015-12-15 11:37:33: 0: STDOUT: Progress: 3%
2015-12-15 11:37:33: 0: STDOUT: Progress: 11%
2015-12-15 11:37:34: 0: STDOUT: Progress: 20%
2015-12-15 11:37:35: 0: STDOUT: Progress: 31%
2015-12-15 11:37:35: 0: STDOUT: Progress: 43%
2015-12-15 11:37:36: 0: STDOUT: Progress: 50%
2015-12-15 11:37:36: 0: STDOUT: Progress: 65%
2015-12-15 11:37:37: 0: STDOUT: Progress: 75%
2015-12-15 11:37:38: 0: STDOUT: Progress: 86%
2015-12-15 11:37:38: 0: STDOUT: Progress: 98%
2015-12-15 11:37:38: 0: STDOUT: Progress: 100%
2015-12-15 11:37:39: 0: INFO: Task Overall Progress: 100%
2015-12-15 11:37:39: 0: STDOUT: Rendering Phase: Finalize
2015-12-15 11:37:39: 0: STDOUT: Progress: 0%
2015-12-15 11:37:39: 0: STDOUT: Progress: 2%
2015-12-15 11:37:40: 0: STDOUT: Progress: 25%
2015-12-15 11:37:40: 0: STDOUT: Progress: 63%
2015-12-15 11:37:41: 0: STDOUT: Progress: 0%
2015-12-15 11:37:41: 0: STDOUT: Progress: 2%
2015-12-15 11:37:41: 0: STDOUT: Progress: 25%
2015-12-15 11:37:42: 0: STDOUT: Progress: 63%
2015-12-15 11:37:42: 0: STDOUT: Progress: 0%
2015-12-15 11:37:42: 0: STDOUT: Progress: 2%
2015-12-15 11:37:43: 0: STDOUT: Progress: 25%
2015-12-15 11:37:44: 0: STDOUT: Progress: 63%
2015-12-15 11:37:45: 0: STDOUT: Scene created in plugin version -1
2015-12-15 11:37:45: 0: STDOUT: Progress: 100%
2015-12-15 11:37:45: 0: STDOUT: Rendering successful: 65.866 sec.
does this “Scene created in plugin version -1” line can be related ? I think it’s from Octane render. But i had the same issue with scenes rendering in standard.
gabgren
December 15, 2015, 4:45pm
7
Just so you know,
when i killed the Cinema4D.exe from task manager, deadline saw this as an error so it made the slave re render this task
few minutes later, same behaviour: i was stuck at 100%
i killed again c4d, and again deadline restarted this task with the same slave
it went through!
So same slave, same task. not working twice, then working!
eamsler
December 15, 2015, 5:05pm
8
Ugh. These are always the most fun to troubleshoot.
Forcing the application to close can cause it to return a non-zero exit code, it depends on how the software was written. At least we know Deadline can carry on after that.
I wonder if the Octane support staff have any experience with this. For fun, can you try and send a non-Octane job though and see if it gets stuck the same way? It sounds like the problem is at least reliable enough that you should see a difference.
Normally we’d try and isolate the problem away from Deadline so that the app or plugin developers of the software can have something to test with without needing Deadline… I can work with you and the OTOY staff on this one. Just CC me to your support request to them. My address is edwin@thinkboxsoftware.com .
Hi !
It just happened with standard renderer, so nothing to do with Octane.
Here is the log from the slave machine. The job is stuck at 100%
Connecting to render50win...
2016-01-04 09:48:20: 0: STDOUT: Progress: 87%
2016-01-04 09:48:20: 0: STDOUT: Progress: 88%
2016-01-04 09:48:20: 0: STDOUT: Progress: 89%
2016-01-04 09:48:20: 0: STDOUT: Progress: 90%
2016-01-04 09:48:20: 0: STDOUT: Progress: 91%
2016-01-04 09:48:20: 0: STDOUT: Progress: 92%
2016-01-04 09:48:20: 0: STDOUT: Progress: 94%
2016-01-04 09:48:20: 0: STDOUT: Progress: 95%
2016-01-04 09:48:20: 0: STDOUT: Progress: 96%
2016-01-04 09:48:20: 0: STDOUT: Progress: 97%
2016-01-04 09:48:20: 0: STDOUT: Progress: 98%
2016-01-04 09:48:20: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:20: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:20: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:20: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:20: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:20: 0: STDOUT: Rendering frame 55 at <Mon Jan 04 09:48:20 2016>
2016-01-04 09:48:20: 0: INFO: Task Overall Progress: 50%
2016-01-04 09:48:20: 0: STDOUT: Rendering Phase: Finalize
2016-01-04 09:48:20: 0: STDOUT: Progress: 0%
2016-01-04 09:48:20: 0: STDOUT: Rendering Phase: Setup
2016-01-04 09:48:20: 0: STDOUT: Progress: 0%
2016-01-04 09:48:20: 0: STDOUT: Rendering Phase: Main Render
2016-01-04 09:48:20: 0: STDOUT: Progress: 0%
2016-01-04 09:48:20: 0: STDOUT: Progress: 1%
2016-01-04 09:48:20: 0: STDOUT: Progress: 2%
2016-01-04 09:48:20: 0: STDOUT: Progress: 3%
2016-01-04 09:48:20: 0: STDOUT: Progress: 4%
2016-01-04 09:48:20: 0: STDOUT: Progress: 5%
2016-01-04 09:48:20: 0: STDOUT: Progress: 7%
2016-01-04 09:48:20: 0: STDOUT: Progress: 8%
2016-01-04 09:48:20: 0: STDOUT: Progress: 9%
2016-01-04 09:48:20: 0: STDOUT: Progress: 10%
2016-01-04 09:48:20: 0: STDOUT: Progress: 11%
2016-01-04 09:48:20: 0: STDOUT: Progress: 12%
2016-01-04 09:48:20: 0: STDOUT: Progress: 14%
2016-01-04 09:48:20: 0: STDOUT: Progress: 15%
2016-01-04 09:48:20: 0: STDOUT: Progress: 16%
2016-01-04 09:48:20: 0: STDOUT: Progress: 17%
2016-01-04 09:48:20: 0: STDOUT: Progress: 18%
2016-01-04 09:48:20: 0: STDOUT: Progress: 20%
2016-01-04 09:48:20: 0: STDOUT: Progress: 21%
2016-01-04 09:48:20: 0: STDOUT: Progress: 22%
2016-01-04 09:48:20: 0: STDOUT: Progress: 23%
2016-01-04 09:48:20: 0: STDOUT: Progress: 24%
2016-01-04 09:48:20: 0: STDOUT: Progress: 25%
2016-01-04 09:48:20: 0: STDOUT: Progress: 27%
2016-01-04 09:48:20: 0: STDOUT: Progress: 28%
2016-01-04 09:48:20: 0: STDOUT: Progress: 29%
2016-01-04 09:48:20: 0: STDOUT: Progress: 30%
2016-01-04 09:48:20: 0: STDOUT: Progress: 31%
2016-01-04 09:48:20: 0: STDOUT: Progress: 32%
2016-01-04 09:48:20: 0: STDOUT: Progress: 34%
2016-01-04 09:48:20: 0: STDOUT: Progress: 35%
2016-01-04 09:48:20: 0: STDOUT: Progress: 36%
2016-01-04 09:48:20: 0: STDOUT: Progress: 37%
2016-01-04 09:48:20: 0: STDOUT: Progress: 38%
2016-01-04 09:48:20: 0: STDOUT: Progress: 40%
2016-01-04 09:48:20: 0: STDOUT: Progress: 41%
2016-01-04 09:48:20: 0: STDOUT: Progress: 42%
2016-01-04 09:48:20: 0: STDOUT: Progress: 43%
2016-01-04 09:48:20: 0: STDOUT: Progress: 44%
2016-01-04 09:48:20: 0: STDOUT: Progress: 45%
2016-01-04 09:48:20: 0: STDOUT: Progress: 47%
2016-01-04 09:48:20: 0: STDOUT: Progress: 48%
2016-01-04 09:48:20: 0: STDOUT: Progress: 49%
2016-01-04 09:48:20: 0: STDOUT: Progress: 50%
2016-01-04 09:48:20: 0: STDOUT: Progress: 51%
2016-01-04 09:48:20: 0: STDOUT: Progress: 52%
2016-01-04 09:48:20: 0: STDOUT: Progress: 54%
2016-01-04 09:48:20: 0: STDOUT: Progress: 55%
2016-01-04 09:48:20: 0: STDOUT: Progress: 56%
2016-01-04 09:48:20: 0: STDOUT: Progress: 57%
2016-01-04 09:48:20: 0: STDOUT: Progress: 58%
2016-01-04 09:48:20: 0: STDOUT: Progress: 60%
2016-01-04 09:48:20: 0: STDOUT: Progress: 61%
2016-01-04 09:48:20: 0: STDOUT: Progress: 62%
2016-01-04 09:48:20: 0: STDOUT: Progress: 63%
2016-01-04 09:48:20: 0: STDOUT: Progress: 64%
2016-01-04 09:48:20: 0: STDOUT: Progress: 65%
2016-01-04 09:48:20: 0: STDOUT: Progress: 67%
2016-01-04 09:48:20: 0: STDOUT: Progress: 68%
2016-01-04 09:48:20: 0: STDOUT: Progress: 69%
2016-01-04 09:48:20: 0: STDOUT: Progress: 70%
2016-01-04 09:48:20: 0: STDOUT: Progress: 71%
2016-01-04 09:48:20: 0: STDOUT: Progress: 72%
2016-01-04 09:48:20: 0: STDOUT: Progress: 74%
2016-01-04 09:48:20: 0: STDOUT: Progress: 75%
2016-01-04 09:48:20: 0: STDOUT: Progress: 76%
2016-01-04 09:48:20: 0: STDOUT: Progress: 77%
2016-01-04 09:48:20: 0: STDOUT: Progress: 78%
2016-01-04 09:48:20: 0: STDOUT: Progress: 80%
2016-01-04 09:48:20: 0: STDOUT: Progress: 81%
2016-01-04 09:48:20: 0: STDOUT: Progress: 82%
2016-01-04 09:48:20: 0: STDOUT: Progress: 83%
2016-01-04 09:48:20: 0: STDOUT: Progress: 84%
2016-01-04 09:48:20: 0: STDOUT: Progress: 85%
2016-01-04 09:48:20: 0: STDOUT: Progress: 87%
2016-01-04 09:48:20: 0: STDOUT: Progress: 88%
2016-01-04 09:48:20: 0: STDOUT: Progress: 89%
2016-01-04 09:48:20: 0: STDOUT: Progress: 90%
2016-01-04 09:48:20: 0: STDOUT: Progress: 91%
2016-01-04 09:48:20: 0: STDOUT: Progress: 92%
2016-01-04 09:48:20: 0: STDOUT: Progress: 94%
2016-01-04 09:48:20: 0: STDOUT: Progress: 95%
2016-01-04 09:48:20: 0: STDOUT: Progress: 96%
2016-01-04 09:48:20: 0: STDOUT: Progress: 97%
2016-01-04 09:48:20: 0: STDOUT: Progress: 98%
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: Rendering frame 56 at <Mon Jan 04 09:48:20 2016>
2016-01-04 09:48:21: 0: INFO: Task Overall Progress: 60%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Finalize
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Setup
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Main Render
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Progress: 1%
2016-01-04 09:48:21: 0: STDOUT: Progress: 2%
2016-01-04 09:48:21: 0: STDOUT: Progress: 3%
2016-01-04 09:48:21: 0: STDOUT: Progress: 4%
2016-01-04 09:48:21: 0: STDOUT: Progress: 5%
2016-01-04 09:48:21: 0: STDOUT: Progress: 7%
2016-01-04 09:48:21: 0: STDOUT: Progress: 8%
2016-01-04 09:48:21: 0: STDOUT: Progress: 9%
2016-01-04 09:48:21: 0: STDOUT: Progress: 10%
2016-01-04 09:48:21: 0: STDOUT: Progress: 11%
2016-01-04 09:48:21: 0: STDOUT: Progress: 12%
2016-01-04 09:48:21: 0: STDOUT: Progress: 14%
2016-01-04 09:48:21: 0: STDOUT: Progress: 15%
2016-01-04 09:48:21: 0: STDOUT: Progress: 16%
2016-01-04 09:48:21: 0: STDOUT: Progress: 17%
2016-01-04 09:48:21: 0: STDOUT: Progress: 18%
2016-01-04 09:48:21: 0: STDOUT: Progress: 20%
2016-01-04 09:48:21: 0: STDOUT: Progress: 21%
2016-01-04 09:48:21: 0: STDOUT: Progress: 22%
2016-01-04 09:48:21: 0: STDOUT: Progress: 23%
2016-01-04 09:48:21: 0: STDOUT: Progress: 24%
2016-01-04 09:48:21: 0: STDOUT: Progress: 25%
2016-01-04 09:48:21: 0: STDOUT: Progress: 27%
2016-01-04 09:48:21: 0: STDOUT: Progress: 28%
2016-01-04 09:48:21: 0: STDOUT: Progress: 29%
2016-01-04 09:48:21: 0: STDOUT: Progress: 30%
2016-01-04 09:48:21: 0: STDOUT: Progress: 31%
2016-01-04 09:48:21: 0: STDOUT: Progress: 32%
2016-01-04 09:48:21: 0: STDOUT: Progress: 34%
2016-01-04 09:48:21: 0: STDOUT: Progress: 35%
2016-01-04 09:48:21: 0: STDOUT: Progress: 36%
2016-01-04 09:48:21: 0: STDOUT: Progress: 37%
2016-01-04 09:48:21: 0: STDOUT: Progress: 38%
2016-01-04 09:48:21: 0: STDOUT: Progress: 40%
2016-01-04 09:48:21: 0: STDOUT: Progress: 41%
2016-01-04 09:48:21: 0: STDOUT: Progress: 42%
2016-01-04 09:48:21: 0: STDOUT: Progress: 43%
2016-01-04 09:48:21: 0: STDOUT: Progress: 44%
2016-01-04 09:48:21: 0: STDOUT: Progress: 45%
2016-01-04 09:48:21: 0: STDOUT: Progress: 47%
2016-01-04 09:48:21: 0: STDOUT: Progress: 48%
2016-01-04 09:48:21: 0: STDOUT: Progress: 49%
2016-01-04 09:48:21: 0: STDOUT: Progress: 50%
2016-01-04 09:48:21: 0: STDOUT: Progress: 51%
2016-01-04 09:48:21: 0: STDOUT: Progress: 52%
2016-01-04 09:48:21: 0: STDOUT: Progress: 54%
2016-01-04 09:48:21: 0: STDOUT: Progress: 55%
2016-01-04 09:48:21: 0: STDOUT: Progress: 56%
2016-01-04 09:48:21: 0: STDOUT: Progress: 57%
2016-01-04 09:48:21: 0: STDOUT: Progress: 58%
2016-01-04 09:48:21: 0: STDOUT: Progress: 60%
2016-01-04 09:48:21: 0: STDOUT: Progress: 61%
2016-01-04 09:48:21: 0: STDOUT: Progress: 62%
2016-01-04 09:48:21: 0: STDOUT: Progress: 63%
2016-01-04 09:48:21: 0: STDOUT: Progress: 64%
2016-01-04 09:48:21: 0: STDOUT: Progress: 65%
2016-01-04 09:48:21: 0: STDOUT: Progress: 67%
2016-01-04 09:48:21: 0: STDOUT: Progress: 68%
2016-01-04 09:48:21: 0: STDOUT: Progress: 69%
2016-01-04 09:48:21: 0: STDOUT: Progress: 70%
2016-01-04 09:48:21: 0: STDOUT: Progress: 71%
2016-01-04 09:48:21: 0: STDOUT: Progress: 72%
2016-01-04 09:48:21: 0: STDOUT: Progress: 74%
2016-01-04 09:48:21: 0: STDOUT: Progress: 75%
2016-01-04 09:48:21: 0: STDOUT: Progress: 76%
2016-01-04 09:48:21: 0: STDOUT: Progress: 77%
2016-01-04 09:48:21: 0: STDOUT: Progress: 78%
2016-01-04 09:48:21: 0: STDOUT: Progress: 80%
2016-01-04 09:48:21: 0: STDOUT: Progress: 81%
2016-01-04 09:48:21: 0: STDOUT: Progress: 82%
2016-01-04 09:48:21: 0: STDOUT: Progress: 83%
2016-01-04 09:48:21: 0: STDOUT: Progress: 84%
2016-01-04 09:48:21: 0: STDOUT: Progress: 85%
2016-01-04 09:48:21: 0: STDOUT: Progress: 87%
2016-01-04 09:48:21: 0: STDOUT: Progress: 88%
2016-01-04 09:48:21: 0: STDOUT: Progress: 89%
2016-01-04 09:48:21: 0: STDOUT: Progress: 90%
2016-01-04 09:48:21: 0: STDOUT: Progress: 91%
2016-01-04 09:48:21: 0: STDOUT: Progress: 92%
2016-01-04 09:48:21: 0: STDOUT: Progress: 94%
2016-01-04 09:48:21: 0: STDOUT: Progress: 95%
2016-01-04 09:48:21: 0: STDOUT: Progress: 96%
2016-01-04 09:48:21: 0: STDOUT: Progress: 97%
2016-01-04 09:48:21: 0: STDOUT: Progress: 98%
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: Rendering frame 57 at <Mon Jan 04 09:48:21 2016>
2016-01-04 09:48:21: 0: INFO: Task Overall Progress: 70%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Finalize
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Setup
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Main Render
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Progress: 1%
2016-01-04 09:48:21: 0: STDOUT: Progress: 2%
2016-01-04 09:48:21: 0: STDOUT: Progress: 3%
2016-01-04 09:48:21: 0: STDOUT: Progress: 4%
2016-01-04 09:48:21: 0: STDOUT: Progress: 5%
2016-01-04 09:48:21: 0: STDOUT: Progress: 7%
2016-01-04 09:48:21: 0: STDOUT: Progress: 8%
2016-01-04 09:48:21: 0: STDOUT: Progress: 9%
2016-01-04 09:48:21: 0: STDOUT: Progress: 10%
2016-01-04 09:48:21: 0: STDOUT: Progress: 11%
2016-01-04 09:48:21: 0: STDOUT: Progress: 12%
2016-01-04 09:48:21: 0: STDOUT: Progress: 14%
2016-01-04 09:48:21: 0: STDOUT: Progress: 15%
2016-01-04 09:48:21: 0: STDOUT: Progress: 16%
2016-01-04 09:48:21: 0: STDOUT: Progress: 17%
2016-01-04 09:48:21: 0: STDOUT: Progress: 18%
2016-01-04 09:48:21: 0: STDOUT: Progress: 20%
2016-01-04 09:48:21: 0: STDOUT: Progress: 21%
2016-01-04 09:48:21: 0: STDOUT: Progress: 22%
2016-01-04 09:48:21: 0: STDOUT: Progress: 23%
2016-01-04 09:48:21: 0: STDOUT: Progress: 24%
2016-01-04 09:48:21: 0: STDOUT: Progress: 25%
2016-01-04 09:48:21: 0: STDOUT: Progress: 27%
2016-01-04 09:48:21: 0: STDOUT: Progress: 28%
2016-01-04 09:48:21: 0: STDOUT: Progress: 29%
2016-01-04 09:48:21: 0: STDOUT: Progress: 30%
2016-01-04 09:48:21: 0: STDOUT: Progress: 31%
2016-01-04 09:48:21: 0: STDOUT: Progress: 32%
2016-01-04 09:48:21: 0: STDOUT: Progress: 34%
2016-01-04 09:48:21: 0: STDOUT: Progress: 35%
2016-01-04 09:48:21: 0: STDOUT: Progress: 36%
2016-01-04 09:48:21: 0: STDOUT: Progress: 37%
2016-01-04 09:48:21: 0: STDOUT: Progress: 38%
2016-01-04 09:48:21: 0: STDOUT: Progress: 40%
2016-01-04 09:48:21: 0: STDOUT: Progress: 41%
2016-01-04 09:48:21: 0: STDOUT: Progress: 42%
2016-01-04 09:48:21: 0: STDOUT: Progress: 43%
2016-01-04 09:48:21: 0: STDOUT: Progress: 44%
2016-01-04 09:48:21: 0: STDOUT: Progress: 45%
2016-01-04 09:48:21: 0: STDOUT: Progress: 47%
2016-01-04 09:48:21: 0: STDOUT: Progress: 48%
2016-01-04 09:48:21: 0: STDOUT: Progress: 49%
2016-01-04 09:48:21: 0: STDOUT: Progress: 50%
2016-01-04 09:48:21: 0: STDOUT: Progress: 51%
2016-01-04 09:48:21: 0: STDOUT: Progress: 52%
2016-01-04 09:48:21: 0: STDOUT: Progress: 54%
2016-01-04 09:48:21: 0: STDOUT: Progress: 55%
2016-01-04 09:48:21: 0: STDOUT: Progress: 56%
2016-01-04 09:48:21: 0: STDOUT: Progress: 57%
2016-01-04 09:48:21: 0: STDOUT: Progress: 58%
2016-01-04 09:48:21: 0: STDOUT: Progress: 60%
2016-01-04 09:48:21: 0: STDOUT: Progress: 61%
2016-01-04 09:48:21: 0: STDOUT: Progress: 62%
2016-01-04 09:48:21: 0: STDOUT: Progress: 63%
2016-01-04 09:48:21: 0: STDOUT: Progress: 64%
2016-01-04 09:48:21: 0: STDOUT: Progress: 65%
2016-01-04 09:48:21: 0: STDOUT: Progress: 67%
2016-01-04 09:48:21: 0: STDOUT: Progress: 68%
2016-01-04 09:48:21: 0: STDOUT: Progress: 69%
2016-01-04 09:48:21: 0: STDOUT: Progress: 70%
2016-01-04 09:48:21: 0: STDOUT: Progress: 71%
2016-01-04 09:48:21: 0: STDOUT: Progress: 72%
2016-01-04 09:48:21: 0: STDOUT: Progress: 74%
2016-01-04 09:48:21: 0: STDOUT: Progress: 75%
2016-01-04 09:48:21: 0: STDOUT: Progress: 76%
2016-01-04 09:48:21: 0: STDOUT: Progress: 77%
2016-01-04 09:48:21: 0: STDOUT: Progress: 78%
2016-01-04 09:48:21: 0: STDOUT: Progress: 80%
2016-01-04 09:48:21: 0: STDOUT: Progress: 81%
2016-01-04 09:48:21: 0: STDOUT: Progress: 82%
2016-01-04 09:48:21: 0: STDOUT: Progress: 83%
2016-01-04 09:48:21: 0: STDOUT: Progress: 84%
2016-01-04 09:48:21: 0: STDOUT: Progress: 85%
2016-01-04 09:48:21: 0: STDOUT: Progress: 87%
2016-01-04 09:48:21: 0: STDOUT: Progress: 88%
2016-01-04 09:48:21: 0: STDOUT: Progress: 89%
2016-01-04 09:48:21: 0: STDOUT: Progress: 90%
2016-01-04 09:48:21: 0: STDOUT: Progress: 91%
2016-01-04 09:48:21: 0: STDOUT: Progress: 92%
2016-01-04 09:48:21: 0: STDOUT: Progress: 94%
2016-01-04 09:48:21: 0: STDOUT: Progress: 95%
2016-01-04 09:48:21: 0: STDOUT: Progress: 96%
2016-01-04 09:48:21: 0: STDOUT: Progress: 97%
2016-01-04 09:48:21: 0: STDOUT: Progress: 98%
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:21: 0: STDOUT: Rendering frame 58 at <Mon Jan 04 09:48:21 2016>
2016-01-04 09:48:21: 0: INFO: Task Overall Progress: 80%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Finalize
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Setup
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Rendering Phase: Main Render
2016-01-04 09:48:21: 0: STDOUT: Progress: 0%
2016-01-04 09:48:21: 0: STDOUT: Progress: 2%
2016-01-04 09:48:21: 0: STDOUT: Progress: 3%
2016-01-04 09:48:21: 0: STDOUT: Progress: 4%
2016-01-04 09:48:21: 0: STDOUT: Progress: 5%
2016-01-04 09:48:21: 0: STDOUT: Progress: 6%
2016-01-04 09:48:21: 0: STDOUT: Progress: 8%
2016-01-04 09:48:21: 0: STDOUT: Progress: 9%
2016-01-04 09:48:21: 0: STDOUT: Progress: 10%
2016-01-04 09:48:21: 0: STDOUT: Progress: 11%
2016-01-04 09:48:21: 0: STDOUT: Progress: 12%
2016-01-04 09:48:21: 0: STDOUT: Progress: 13%
2016-01-04 09:48:21: 0: STDOUT: Progress: 15%
2016-01-04 09:48:21: 0: STDOUT: Progress: 16%
2016-01-04 09:48:22: 0: STDOUT: Progress: 17%
2016-01-04 09:48:22: 0: STDOUT: Progress: 18%
2016-01-04 09:48:22: 0: STDOUT: Progress: 19%
2016-01-04 09:48:22: 0: STDOUT: Progress: 20%
2016-01-04 09:48:22: 0: STDOUT: Progress: 22%
2016-01-04 09:48:22: 0: STDOUT: Progress: 23%
2016-01-04 09:48:22: 0: STDOUT: Progress: 24%
2016-01-04 09:48:22: 0: STDOUT: Progress: 25%
2016-01-04 09:48:22: 0: STDOUT: Progress: 26%
2016-01-04 09:48:22: 0: STDOUT: Progress: 28%
2016-01-04 09:48:22: 0: STDOUT: Progress: 29%
2016-01-04 09:48:22: 0: STDOUT: Progress: 30%
2016-01-04 09:48:22: 0: STDOUT: Progress: 31%
2016-01-04 09:48:22: 0: STDOUT: Progress: 32%
2016-01-04 09:48:22: 0: STDOUT: Progress: 33%
2016-01-04 09:48:22: 0: STDOUT: Progress: 35%
2016-01-04 09:48:22: 0: STDOUT: Progress: 36%
2016-01-04 09:48:22: 0: STDOUT: Progress: 37%
2016-01-04 09:48:22: 0: STDOUT: Progress: 38%
2016-01-04 09:48:22: 0: STDOUT: Progress: 39%
2016-01-04 09:48:22: 0: STDOUT: Progress: 40%
2016-01-04 09:48:22: 0: STDOUT: Progress: 42%
2016-01-04 09:48:22: 0: STDOUT: Progress: 43%
2016-01-04 09:48:22: 0: STDOUT: Progress: 44%
2016-01-04 09:48:22: 0: STDOUT: Progress: 45%
2016-01-04 09:48:22: 0: STDOUT: Progress: 46%
2016-01-04 09:48:22: 0: STDOUT: Progress: 48%
2016-01-04 09:48:22: 0: STDOUT: Progress: 49%
2016-01-04 09:48:22: 0: STDOUT: Progress: 50%
2016-01-04 09:48:22: 0: STDOUT: Progress: 51%
2016-01-04 09:48:22: 0: STDOUT: Progress: 52%
2016-01-04 09:48:22: 0: STDOUT: Progress: 53%
2016-01-04 09:48:22: 0: STDOUT: Progress: 55%
2016-01-04 09:48:22: 0: STDOUT: Progress: 56%
2016-01-04 09:48:22: 0: STDOUT: Progress: 57%
2016-01-04 09:48:22: 0: STDOUT: Progress: 58%
2016-01-04 09:48:22: 0: STDOUT: Progress: 59%
2016-01-04 09:48:22: 0: STDOUT: Progress: 60%
2016-01-04 09:48:22: 0: STDOUT: Progress: 62%
2016-01-04 09:48:22: 0: STDOUT: Progress: 63%
2016-01-04 09:48:22: 0: STDOUT: Progress: 64%
2016-01-04 09:48:22: 0: STDOUT: Progress: 65%
2016-01-04 09:48:22: 0: STDOUT: Progress: 66%
2016-01-04 09:48:22: 0: STDOUT: Progress: 68%
2016-01-04 09:48:22: 0: STDOUT: Progress: 69%
2016-01-04 09:48:22: 0: STDOUT: Progress: 70%
2016-01-04 09:48:22: 0: STDOUT: Progress: 71%
2016-01-04 09:48:22: 0: STDOUT: Progress: 72%
2016-01-04 09:48:22: 0: STDOUT: Progress: 73%
2016-01-04 09:48:22: 0: STDOUT: Progress: 75%
2016-01-04 09:48:22: 0: STDOUT: Progress: 76%
2016-01-04 09:48:22: 0: STDOUT: Progress: 77%
2016-01-04 09:48:22: 0: STDOUT: Progress: 78%
2016-01-04 09:48:22: 0: STDOUT: Progress: 79%
2016-01-04 09:48:22: 0: STDOUT: Progress: 80%
2016-01-04 09:48:22: 0: STDOUT: Progress: 82%
2016-01-04 09:48:22: 0: STDOUT: Progress: 83%
2016-01-04 09:48:22: 0: STDOUT: Progress: 84%
2016-01-04 09:48:22: 0: STDOUT: Progress: 85%
2016-01-04 09:48:22: 0: STDOUT: Progress: 86%
2016-01-04 09:48:22: 0: STDOUT: Progress: 88%
2016-01-04 09:48:22: 0: STDOUT: Progress: 89%
2016-01-04 09:48:22: 0: STDOUT: Progress: 90%
2016-01-04 09:48:22: 0: STDOUT: Progress: 91%
2016-01-04 09:48:22: 0: STDOUT: Progress: 92%
2016-01-04 09:48:22: 0: STDOUT: Progress: 93%
2016-01-04 09:48:22: 0: STDOUT: Progress: 95%
2016-01-04 09:48:22: 0: STDOUT: Progress: 96%
2016-01-04 09:48:22: 0: STDOUT: Progress: 97%
2016-01-04 09:48:22: 0: STDOUT: Progress: 98%
2016-01-04 09:48:22: 0: STDOUT: Progress: 99%
2016-01-04 09:48:22: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:22: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:22: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:22: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:22: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
2016-01-04 09:48:22: 0: STDOUT: Rendering frame 59 at <Mon Jan 04 09:48:22 2016>
2016-01-04 09:48:22: 0: INFO: Task Overall Progress: 90%
2016-01-04 09:48:22: 0: STDOUT: Rendering Phase: Finalize
2016-01-04 09:48:22: 0: STDOUT: Progress: 0%
2016-01-04 09:48:22: 0: STDOUT: Rendering Phase: Setup
2016-01-04 09:48:22: 0: STDOUT: Progress: 0%
2016-01-04 09:48:22: 0: STDOUT: Rendering Phase: Main Render
2016-01-04 09:48:22: 0: STDOUT: Progress: 0%
2016-01-04 09:48:22: 0: STDOUT: Progress: 1%
2016-01-04 09:48:22: 0: STDOUT: Progress: 3%
2016-01-04 09:48:22: 0: STDOUT: Progress: 4%
2016-01-04 09:48:22: 0: STDOUT: Progress: 5%
2016-01-04 09:48:22: 0: STDOUT: Progress: 6%
2016-01-04 09:48:22: 0: STDOUT: Progress: 7%
2016-01-04 09:48:22: 0: STDOUT: Progress: 9%
2016-01-04 09:48:22: 0: STDOUT: Progress: 10%
2016-01-04 09:48:22: 0: STDOUT: Progress: 11%
2016-01-04 09:48:22: 0: STDOUT: Progress: 12%
2016-01-04 09:48:22: 0: STDOUT: Progress: 13%
2016-01-04 09:48:22: 0: STDOUT: Progress: 14%
2016-01-04 09:48:22: 0: STDOUT: Progress: 16%
2016-01-04 09:48:22: 0: STDOUT: Progress: 17%
2016-01-04 09:48:22: 0: STDOUT: Progress: 18%
2016-01-04 09:48:22: 0: STDOUT: Progress: 19%
2016-01-04 09:48:22: 0: STDOUT: Progress: 20%
2016-01-04 09:48:22: 0: STDOUT: Progress: 21%
2016-01-04 09:48:22: 0: STDOUT: Progress: 23%
2016-01-04 09:48:22: 0: STDOUT: Progress: 24%
2016-01-04 09:48:22: 0: STDOUT: Progress: 25%
2016-01-04 09:48:22: 0: STDOUT: Progress: 26%
2016-01-04 09:48:22: 0: STDOUT: Progress: 27%
2016-01-04 09:48:22: 0: STDOUT: Progress: 29%
2016-01-04 09:48:22: 0: STDOUT: Progress: 30%
2016-01-04 09:48:22: 0: STDOUT: Progress: 31%
2016-01-04 09:48:22: 0: STDOUT: Progress: 32%
2016-01-04 09:48:22: 0: STDOUT: Progress: 33%
2016-01-04 09:48:22: 0: STDOUT: Progress: 34%
2016-01-04 09:48:22: 0: STDOUT: Progress: 36%
2016-01-04 09:48:22: 0: STDOUT: Progress: 37%
2016-01-04 09:48:22: 0: STDOUT: Progress: 38%
2016-01-04 09:48:22: 0: STDOUT: Progress: 39%
2016-01-04 09:48:22: 0: STDOUT: Progress: 40%
2016-01-04 09:48:22: 0: STDOUT: Progress: 41%
2016-01-04 09:48:22: 0: STDOUT: Progress: 43%
2016-01-04 09:48:22: 0: STDOUT: Progress: 44%
2016-01-04 09:48:22: 0: STDOUT: Progress: 45%
2016-01-04 09:48:22: 0: STDOUT: Progress: 46%
2016-01-04 09:48:22: 0: STDOUT: Progress: 47%
2016-01-04 09:48:22: 0: STDOUT: Progress: 49%
2016-01-04 09:48:22: 0: STDOUT: Progress: 50%
2016-01-04 09:48:22: 0: STDOUT: Progress: 51%
2016-01-04 09:48:22: 0: STDOUT: Progress: 52%
2016-01-04 09:48:22: 0: STDOUT: Progress: 53%
2016-01-04 09:48:22: 0: STDOUT: Progress: 54%
2016-01-04 09:48:22: 0: STDOUT: Progress: 56%
2016-01-04 09:48:22: 0: STDOUT: Progress: 57%
2016-01-04 09:48:22: 0: STDOUT: Progress: 58%
2016-01-04 09:48:22: 0: STDOUT: Progress: 59%
2016-01-04 09:48:22: 0: STDOUT: Progress: 60%
2016-01-04 09:48:22: 0: STDOUT: Progress: 61%
2016-01-04 09:48:22: 0: STDOUT: Progress: 63%
2016-01-04 09:48:22: 0: STDOUT: Progress: 64%
2016-01-04 09:48:22: 0: STDOUT: Progress: 65%
2016-01-04 09:48:22: 0: STDOUT: Progress: 66%
2016-01-04 09:48:22: 0: STDOUT: Progress: 67%
2016-01-04 09:48:22: 0: STDOUT: Progress: 69%
2016-01-04 09:48:22: 0: STDOUT: Progress: 70%
2016-01-04 09:48:22: 0: STDOUT: Progress: 71%
2016-01-04 09:48:22: 0: STDOUT: Progress: 72%
2016-01-04 09:48:22: 0: STDOUT: Progress: 73%
2016-01-04 09:48:22: 0: STDOUT: Progress: 74%
2016-01-04 09:48:22: 0: STDOUT: Progress: 76%
2016-01-04 09:48:22: 0: STDOUT: Progress: 77%
2016-01-04 09:48:22: 0: STDOUT: Progress: 78%
2016-01-04 09:48:22: 0: STDOUT: Progress: 79%
2016-01-04 09:48:22: 0: STDOUT: Progress: 80%
2016-01-04 09:48:22: 0: STDOUT: Progress: 81%
2016-01-04 09:48:22: 0: STDOUT: Progress: 83%
2016-01-04 09:48:22: 0: STDOUT: Progress: 84%
2016-01-04 09:48:22: 0: STDOUT: Progress: 85%
2016-01-04 09:48:22: 0: STDOUT: Progress: 86%
2016-01-04 09:48:22: 0: STDOUT: Progress: 87%
2016-01-04 09:48:22: 0: STDOUT: Progress: 89%
2016-01-04 09:48:22: 0: STDOUT: Progress: 90%
2016-01-04 09:48:22: 0: STDOUT: Progress: 91%
2016-01-04 09:48:22: 0: STDOUT: Progress: 92%
2016-01-04 09:48:22: 0: STDOUT: Progress: 93%
2016-01-04 09:48:22: 0: STDOUT: Progress: 94%
2016-01-04 09:48:22: 0: STDOUT: Progress: 96%
2016-01-04 09:48:22: 0: STDOUT: Progress: 97%
2016-01-04 09:48:22: 0: STDOUT: Progress: 98%
2016-01-04 09:48:22: 0: STDOUT: Progress: 99%
2016-01-04 09:48:22: 0: INFO: Task Overall Progress: 100%
2016-01-04 09:48:22: 0: STDOUT: Rendering Phase: Finalize
2016-01-04 09:48:22: 0: STDOUT: Rendering successful: 4.869 sec.
2016-01-04 09:49:54: Connecting to Slave log: render50win
I am noticing in that log that there seem to be some critical messages at the end of each frame, but that it is still moving on. Can you verify if there is appropriate output on this job? If not, we would probably want to investigate those critical messages to see if they could be playing a part.
Example:
2016-01-04 09:48:20: 0: STDOUT: CRITICAL: Stop [atom.cpp(377)]
gabgren
January 4, 2016, 10:05pm
11
hi,
yeah i frankly don’t know what they are.
looking for ‘atom.cpp’, the only one i can find in the C4D install folder is under plugins/cinema4dsdk that comes with the software
gabgren
January 4, 2016, 10:11pm
12
and line 377 of atom.cpp is an empty line, so no clue here
Hello,
So it seems like there is some issue on a blank line in a file that is part of C4D. Could you check with Maxon to see if they have any idea?
Hi,
will do.
Meanwhile, can i add something to the plugin’s script? (c4d deadline plugin)
I remember back in deadline 6 I added few lines to handle missing error messages, the job was flagged as success but in fact failed.
Now it’s kind of the opposite… can i do something to tell Deadline to ignore a particular message ?
I just wanted to clarify that these frames are not successful, and you need to have them captured as failures, correct? The log looked like the work continued and wasn’t caught as a fail, so I wanted to make sure what you need to do with that output. Thanks.
No, the other way around.
These frames are successful !
The error messages (from C4D “atom.cpp” or Octane “plugin version -1”) may confuse us into thinking they are related…
These frames render correctly, so the error messages are just warnings that should be ignored.
It’s just that Deadline doesn’t jump to the next task and sticks at “Successful. 100% complete”
So I looked at the ‘end’ of your log there, and it ends with:
2016-01-04 09:48:22: 0: STDOUT: Rendering successful: 4.869 sec.
and I looked at one of ours internally and see the following:
2015-04-06 10:44:28: 0: STDOUT: Rendering successful: 161.467 sec.
2015-04-06 10:44:31: 0: INFO: Process exit code: 0
2015-04-06 10:44:31: 0: INFO: Finished Cinema 4D Task
So it looks like in your case, C4D is not exiting, or at least not telling us. Can you verify if the “CINEMA 4D.exe” process is still running when it hangs like this? If it is not, then we are not properly detecting it closing. If it is still there, then the issue is that C4D hasn’t closed, and that is what Deadline is waiting for.
Are you free for a call on Monday so we can maybe try to poke at this?
gabgren
January 8, 2016, 11:34pm
18
Sure thst would be great. Call me monday pm. 514-849-555
Thanks!
Hello Gabriel,
I just wanted to follow up on our call. I hope Maxon can give some insight into this issue as I would hate to see this continue to be an issue for you.