After Effects 2017 and VC Color Vibrance Plugin errror

Deadline
1

I am getting a strange issue where the Video Copilot VC Color Vibrance plugin has a fail error in deadline but it manages to output the frame correctly anyway. This is only on the frame in the project that use that plugin. The problem is this causes the jobs to try to re-render those frames unless I override the error limit to 1.

I was hoping somebody from thinkbox could help me tweak deadline scripts to handle that plugins error better since it does not seem to be a fatal error.

Here is the error report:

=======================================================
Error

Error: Renderer returned non-zero error code, -1073741811. Check the log for more information.
at Deadline.Plugins.PluginWrapper.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage, AbortLevel& abortLevel)

=======================================================
Type

RenderPluginException

=======================================================
Stack Trace

at Deadline.Plugins.SandboxedPlugin.a(DeadlineMessage A_0)
at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
at Deadline.Slaves.SlaveRenderThread.a(TaskLogWriter A_0)

=======================================================
Log

2017-03-15 17:27:11: BEGIN - DC1PREND007\kchsarender
2017-03-15 17:27:11: 0: Loaded plugin AfterEffects (\kcow30\RenderFarm\DeadlineRepository8\plugins\AfterEffects)
2017-03-15 17:27:11: 0: Executing plugin command of type ‘Initialize Plugin’
2017-03-15 17:27:11: 0: INFO: Executing plugin script ‘C:\Users\KCHSARender\AppData\Local\Thinkbox\Deadline8\slave\dc1prend007\plugins\58c9baf2d9ce983b904a8177\AfterEffects.py’
2017-03-15 17:27:12: 0: INFO: Fail on Existing After Effects process: 0
2017-03-15 17:27:12: 0: INFO: About: After Effects Plugin for Deadline
2017-03-15 17:27:12: 0: INFO: The job’s environment will be merged with the current environment before rendering
2017-03-15 17:27:12: 0: Done executing plugin command of type ‘Initialize Plugin’
2017-03-15 17:27:12: 0: Start Job timeout is disabled.
2017-03-15 17:27:12: 0: Task timeout is disabled.
2017-03-15 17:27:12: 0: Loaded job: 65129_MRD_Shot_02_DSM_v012.aep - Main_DSM (58c9baf2d9ce983b904a8177)
2017-03-15 17:27:12: 0: Executing plugin command of type ‘Start Job’
2017-03-15 17:27:12: 0: Done executing plugin command of type ‘Start Job’
2017-03-15 17:27:12: 0: Plugin rendering frame(s): 1981-2010
2017-03-15 17:27:12: 0: Executing plugin command of type ‘Render Task’
2017-03-15 17:27:12: 0: INFO: Stdout Redirection Enabled: True
2017-03-15 17:27:12: 0: INFO: Stdout Handling Enabled: True
2017-03-15 17:27:12: 0: INFO: Popup Handling Enabled: True
2017-03-15 17:27:12: 0: INFO: QT Popup Handling Enabled: False
2017-03-15 17:27:12: 0: INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
2017-03-15 17:27:12: 0: INFO: Using Process Tree: True
2017-03-15 17:27:12: 0: INFO: Hiding DOS Window: True
2017-03-15 17:27:12: 0: INFO: Creating New Console: False
2017-03-15 17:27:12: 0: INFO: Running as user: kchsarender
2017-03-15 17:27:12: 0: INFO: Executable: “C:\Program Files\Adobe\Adobe After Effects CC 2017\Support Files\aerender.exe”
2017-03-15 17:27:12: 0: INFO: Argument: -project “\kcow30\NSO3D\Projects\BAT_MississippiRiverDiversion_65129\Post\Shot_02_DSM\65129_MRD_Shot_02_DSM_v012.aep” -comp “Main_DSM” -s 1981 -e 2010 -close DO_NOT_SAVE_CHANGES
2017-03-15 17:27:12: 0: INFO: Full Command: “C:\Program Files\Adobe\Adobe After Effects CC 2017\Support Files\aerender.exe” -project “\kcow30\NSO3D\Projects\BAT_MississippiRiverDiversion_65129\Post\Shot_02_DSM\65129_MRD_Shot_02_DSM_v012.aep” -comp “Main_DSM” -s 1981 -e 2010 -close DO_NOT_SAVE_CHANGES
2017-03-15 17:27:12: 0: INFO: Startup Directory: “C:\Program Files\Adobe\Adobe After Effects CC 2017\Support Files”
2017-03-15 17:27:12: 0: INFO: Process Priority: BelowNormal
2017-03-15 17:27:12: 0: INFO: Process Affinity: default
2017-03-15 17:27:12: 0: INFO: Process is now running
2017-03-15 17:27:12: 0: STDOUT: aerender version 14.1.0x57
2017-03-15 17:27:12: 0: STDOUT: Using DXGI: Device: “Microsoft Basic Render Driver” has dedicated video RAM (MB): 0
2017-03-15 17:27:12: 0: STDOUT: has video RAM(MB): 0
2017-03-15 17:27:12: 0: STDOUT: e[1me[0mOptiX has 1 devices available for use.
2017-03-15 17:27:12: 0: STDOUT: e[1me[31me[1m[ERROR] e[0mNVAPI error (C:\code\rtsdk\adobe-ae\cc13.1\src\Util\DriverInfo.cpp:309):
2017-03-15 17:27:12: 0: STDOUT: e[1me[0mNon-default knobs:
2017-03-15 17:27:12: 0: STDOUT: e[1me[0m
2017-03-15 17:27:12: 0: STDOUT: e[1me[31me[1m[ERROR] e[0mNVAPI error (C:\code\rtsdk\adobe-ae\cc13.1\src\Util\DriverInfo.cpp:78):
2017-03-15 17:27:12: 0: STDOUT: e[1me[32me[1m[LOG 4] e[0mCPU fallback enabled
2017-03-15 17:27:12: 0: STDOUT: e[1me[0mNon-default knobs:
2017-03-15 17:27:12: 0: STDOUT: e[1me[0m
2017-03-15 17:27:12: 0: STDOUT: e[1me[31me[1m[ERROR] e[0mNVAPI error (C:\code\rtsdk\adobe-ae\cc13.1\src\Util\DriverInfo.cpp:78):
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: 3/15/2017 5:27:21 PM: Starting composition Main_DSM.
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Render Settings: NSO_Renderfarm
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Quality: Best
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Resolution: Full
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Size: 1920 x 1080
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Proxy Use: Use No Proxies
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Effects: Current Settings
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Disk Cache: Read Only
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Color Depth: Current Settings
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Frame Blending: On for Checked Layers
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Field Render: Off
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Pulldown: Off
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Motion Blur: On for Checked Layers
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Solos: Current Settings
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Time Span: Custom
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Start: 01981
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: End: 02010
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Duration: 00030
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Frame Rate: 30.00 (comp)
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Guide Layers: All Off
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Skip Existing Files: Off
2017-03-15 17:27:21: 0: STDOUT: PROGRESS:
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Output Module: OpenEXR Sequence RGB (linear rec709)
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Output To: \kcow30\NSO3D\Projects\BAT_MississippiRiverDiversion_65129\Frames\Post\Shot_02_DSM\02_DSM_[#####].exr
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Format: OpenEXR
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Output Info: Piz compression
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Start Frame: 1981
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Output Audio: -
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Channels: RGB
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Depth: Floating Point
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Color: Premultiplied
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Resize: -
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Crop: -
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Final Size: 1920 x 1080
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Profile: HDTV (Rec. 709) (linear)
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Embed Profile: On
2017-03-15 17:27:21: 0: STDOUT: PROGRESS: Post-Render Action: None
2017-03-15 17:27:21: 0: STDOUT: PROGRESS:
2017-03-15 17:27:28: 0: STDOUT: PROGRESS: 01981 (1): 6 Seconds
2017-03-15 17:27:31: 0: STDOUT: PROGRESS: 01982 (2): 3 Seconds
2017-03-15 17:27:33: 0: STDOUT: PROGRESS: 01983 (3): 2 Seconds
2017-03-15 17:27:36: 0: STDOUT: PROGRESS: 01984 (4): 3 Seconds
2017-03-15 17:27:39: 0: STDOUT: PROGRESS: 01985 (5): 3 Seconds
2017-03-15 17:27:43: 0: STDOUT: PROGRESS: 01986 (6): 3 Seconds
2017-03-15 17:27:45: 0: STDOUT: PROGRESS: 01987 (7): 3 Seconds
2017-03-15 17:27:49: 0: STDOUT: PROGRESS: 01988 (8): 4 Seconds
2017-03-15 17:27:52: 0: STDOUT: PROGRESS: 01989 (9): 3 Seconds
2017-03-15 17:27:55: 0: STDOUT: PROGRESS: 01990 (10): 3 Seconds
2017-03-15 17:27:59: 0: STDOUT: PROGRESS: 01991 (11): 4 Seconds
2017-03-15 17:28:02: 0: STDOUT: PROGRESS: 01992 (12): 3 Seconds
2017-03-15 17:28:06: 0: STDOUT: PROGRESS: 01993 (13): 4 Seconds
2017-03-15 17:28:09: 0: STDOUT: PROGRESS: 01994 (14): 3 Seconds
2017-03-15 17:28:12: 0: STDOUT: PROGRESS: 01995 (15): 3 Seconds
2017-03-15 17:28:15: 0: STDOUT: PROGRESS: 01996 (16): 3 Seconds
2017-03-15 17:28:19: 0: STDOUT: PROGRESS: 01997 (17): 4 Seconds
2017-03-15 17:28:22: 0: STDOUT: PROGRESS: 01998 (18): 3 Seconds
2017-03-15 17:28:25: 0: STDOUT: PROGRESS: 01999 (19): 3 Seconds
2017-03-15 17:28:29: 0: STDOUT: PROGRESS: 02000 (20): 3 Seconds
2017-03-15 17:28:32: 0: STDOUT: PROGRESS: 02001 (21): 4 Seconds
2017-03-15 17:28:35: 0: STDOUT: PROGRESS: 02002 (22): 3 Seconds
2017-03-15 17:28:37: 0: STDOUT: PROGRESS: 02003 (23): 2 Seconds
2017-03-15 17:28:41: 0: STDOUT: PROGRESS: 02004 (24): 4 Seconds
2017-03-15 17:28:44: 0: STDOUT: PROGRESS: 02005 (25): 2 Seconds
2017-03-15 17:28:47: 0: STDOUT: PROGRESS: 02006 (26): 3 Seconds
2017-03-15 17:28:49: 0: STDOUT: PROGRESS: 02007 (27): 3 Seconds
2017-03-15 17:28:52: 0: STDOUT: PROGRESS: 02008 (28): 3 Seconds
2017-03-15 17:28:55: 0: STDOUT: PROGRESS: 02009 (29): 3 Seconds
2017-03-15 17:28:57: 0: STDOUT: PROGRESS: 02010 (30): 2 Seconds
2017-03-15 17:28:59: 0: INFO: Process exit code: -1073741811
2017-03-15 17:28:59: 0: Done executing plugin command of type ‘Render Task’
2017-03-15 17:28:59: 0: An exception occurred: Error: Renderer returned non-zero error code, -1073741811. Check the log for more information.
2017-03-15 17:28:59: at Deadline.Plugins.PluginWrapper.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage, AbortLevel& abortLevel) (Deadline.Plugins.RenderPluginException)

=======================================================
Details

Date: 03/15/2017 17:29:02
Frames: 1981-2010
Elapsed Time: 00:00:01:57
Job Submit Date: 03/15/2017 17:06:42
Job User: jpageau
Average RAM Usage: 5833759744 (9%)
Peak RAM Usage: 12623822848 (19%)
Average CPU Usage: 3%
Peak CPU Usage: 19%
Used CPU Clocks (x10^6 cycles): 541283
Total CPU Clocks (x10^6 cycles): 18042745

=======================================================
Slave Information

Slave Name: DC1PREND007
Version: v8.0.14.1 Release (534e1f067)
Operating System: Windows Server 2012 R2 Datacenter
Running As Service: No
Machine User: kchsarender
IP Address: 10.1.70.27
MAC Address: 18:66:DA:F1:3A:24
CPU Architecture: x64
CPUs: 64
CPU Usage: 15%
Memory Usage: 11.8 GB / 63.9 GB (18%)
Free Disk Space: 395.266 GB (150.723 GB on C:, 244.027 GB on D:, 254.727 MB on E:, 272.988 MB on F:)
Video Card: Microsoft Basic Display Adapter

2

Hey,

The problem here is the AE stdout is not providing any indication that a particular AE plugin is causing this issue.

I think what we really need to do here, is actually be more proactive and fix this issue BEFORE it ever becomes a problem for you. With that in mind, there is already a plan to build a system whereby we scan the AE project file prior to submission, gather ALL AE 3rd party plugin/effects used by the proj file and allow a system, where you can auto apply Deadline limits to control which machines render which AE projects. The point being, ensure a specific AE file is only ever rendered on a machine which is actually capable of rendering it.

Now the above, doesn’t quite answer your particular issue as it IS rendering ok, just not marking itself as complete. Now, we have an option in the AE plugin config in your repo to “fail out” AE jobs which do NOT provide a “finished composition” message in their stdout. Again, this won’t help you.

There is talk of another plan for AE to solve dilemmas like this, where frankly, the best thing to do, is probably just process that particular AE comp locally in the background… :wink:

Now, what you can do but I don’t like it, is this: in your AfterEffects.py plugin file, open it up in a good code editor and search for these lines in Deadline 9.0:

def CheckExitCode( self, exitCode ): if not self.RenderSuccess: if exitCode != 0: self.FailRender( "After Effects returned non-zero error code: %s. Check the render log." % exitCode )

and change it to this:

def CheckExitCode( self, exitCode ): if not self.RenderSuccess: if exitCode != -1073741811: self.FailRender( "After Effects returned non-zero error code: %s. Check the render log." % exitCode )

However, if you hit that same error exit code for any other AE project file, then your going to get false positives…

3

I get what you are saying. I was hopping that the number generated would be more specific to the plugin so that it would only catch that specific interaction. For me applying the fix would be worth it… but I understand that I am giving a whole category of errors a free pass.

Do you think that this is a bug in the Plugin that I could file with its developer to make it give a correct status in the command line render?

Thanks for your help. Thinkbox has been very good at supporting its users.

4

Hi,

In some of our other plugins, we do actually hard code the checking of specific exit codes, so what I did is perfectly valid and should work to help resolve your issue. I mean, its probably worth a go if it helps you out. After more thought overnight on this topic, I will discuss it with another collegue. Perhaps, we should add this specific exit code to our shipping plugin. Can you test it out for us, so we at least have some feedback that it does indeed work as intended and help resolve your issue? (You will need Deadline 8.0.17.1 or newer, to add this code change).

Ideally, yeah, if you are sure a certain plugin is to blame here, then if the developer could make their code more robust so it knows to not try and do something on a non-GPU based hardware machine, then that would great for users. Even handling the error by exiting with a nice, clean message would be preferred so others actually figure out what the issue is. However, sometimes, its not the 3rd plugin developer so much to blame here, but rather the host application might not have a mechanism by which the plugin developer can raise this exception cleanly.