Hi,
I am creating a plugin for Arnold’s maketx. Everything works, except I don’t get any output from the process.
E.g. maketx --invalidargument fails, but I don’t see anything in the log.
Running it in cmd shows the correct output.
Digging further I discovered that maketx prints all its errors to the stdout. Is this why deadline is not showing it? Can I change this behaviour?
Hello!
We might need some more information on this issue. The render logs would helpful here which failed to write the output. You can either upload the logs here in the forum or if anything sensitive feel free to open a ticket with us on (https://awsthinkbox.zendesk.com/).
Regards
Karpreet
Hi Karpreet,
You can find 4 logs in the attached zip. A success and a fail from deadline, then running the same commands from a cmd.
I found that even when maketx executes successfully I don’t have any output from it in the DL logs.
dl_maketx_logs.zip (4.8 KB)
How are you starting MakeTx in your plugin? The Deadline Worker should be capturing all the stdout.
Hi Justin,
This is a simple plugin, there is nothing special. Here is the WIP code.
MakeTx.py (8.7 KB)
It’s not helpful but that should be working so far as I can tell. We know the executable is running and we know that Deadline is catching the exit code.
If the output is actually going to STDOUT all that should be coming through. If you submit a CommandLine job that runs maketx.exe does that properly capture the output?
I tried it through CommandLine, but no output here either. You can see the log below.
So what is the difference between DL running the executable through the CommandLine plugin, and me running it in a cmd window?
These maybe?
INFO: Stdout Redirection Enabled: True
INFO: Stdout Handling Enabled: True
INFO: Popup Handling Enabled: True
INFO: QT Popup Handling Enabled: False
INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
INFO: Using Process Tree: True
INFO: Hiding DOS Window: True
INFO: Creating New Console: False
INFO: Running as user: daniel.asztalos
=======================================================
Error
=======================================================
Error: Renderer returned non-zero error code, 1. 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.SendMessageToSandbox(DeadlineMessage messageToSend)
at Deadline.Plugins.SandboxedPlugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
at Deadline.Slaves.SlaveRenderThread.RenderCurrentTask(TaskLogWriter tlw)
=======================================================
Log
=======================================================
2020-10-22 08:53:55: BEGIN - WS29\daniel.asztalos
2020-10-22 08:53:55: 0: Executing plugin command of type 'Initialize Plugin'
2020-10-22 08:53:55: 0: INFO: Executing plugin script 'C:\Users\daniel.asztalos\AppData\Local\Thinkbox\Deadline8\slave\ws29\plugins\5f912c7bfac9c31dd42594e7\CommandLine.py'
2020-10-22 08:53:55: 0: INFO: About: Command Line support for Deadline
2020-10-22 08:53:55: 0: INFO: The job's environment will be merged with the current environment before rendering
2020-10-22 08:53:55: 0: Done executing plugin command of type 'Initialize Plugin'
2020-10-22 08:53:55: 0: Start Job timeout is disabled.
2020-10-22 08:53:55: 0: Task timeout is disabled.
2020-10-22 08:53:55: 0: Loaded job: Untitled (5f912c7bfac9c31dd42594e7)
2020-10-22 08:53:55: 0: Executing plugin command of type 'Start Job'
2020-10-22 08:53:55: 0: INFO: Executing global job preload script 'C:\Users\daniel.asztalos\AppData\Local\Thinkbox\Deadline8\slave\ws29\plugins\5f912c7bfac9c31dd42594e7\GlobalJobPreLoad.py'
2020-10-22 08:53:55: 0: Done executing plugin command of type 'Start Job'
2020-10-22 08:53:55: 0: Plugin rendering frame(s): 1
2020-10-22 08:53:55: 0: Executing plugin command of type 'Render Task'
2020-10-22 08:53:55: 0: INFO: Stdout Redirection Enabled: True
2020-10-22 08:53:55: 0: INFO: Stdout Handling Enabled: True
2020-10-22 08:53:55: 0: INFO: Popup Handling Enabled: True
2020-10-22 08:53:55: 0: INFO: QT Popup Handling Enabled: False
2020-10-22 08:53:55: 0: INFO: WindowsForms10.Window.8.app.* Popup Handling Enabled: False
2020-10-22 08:53:55: 0: INFO: Using Process Tree: True
2020-10-22 08:53:55: 0: INFO: Hiding DOS Window: True
2020-10-22 08:53:55: 0: INFO: Creating New Console: False
2020-10-22 08:53:55: 0: INFO: Running as user: daniel.asztalos
2020-10-22 08:53:55: 0: INFO: Executable: "C:\Users\daniel.asztalos\AppData\Local\limes_da_sites\studio1\pkgs\0-dev-package\mtoadeploy\4.0.4.2\maya-2019\bin\maketx.exe"
2020-10-22 08:53:55: 0: INFO: Argument: --invalidargument
2020-10-22 08:53:55: 0: INFO: Full Command: "C:\Users\daniel.asztalos\AppData\Local\limes_da_sites\studio1\pkgs\0-dev-package\mtoadeploy\4.0.4.2\maya-2019\bin\maketx.exe" --invalidargument
2020-10-22 08:53:55: 0: INFO: Startup Directory: "C:\Users\daniel.asztalos\AppData\Local\limes_da_sites\studio1\pkgs\0-dev-package\mtoadeploy\4.0.4.2\maya-2019\bin"
2020-10-22 08:53:55: 0: INFO: Process Priority: BelowNormal
2020-10-22 08:53:55: 0: INFO: Process Affinity: default
2020-10-22 08:53:55: 0: INFO: Process is now running
2020-10-22 08:53:56: 0: INFO: Process exit code: 1
2020-10-22 08:53:56: 0: Done executing plugin command of type 'Render Task'
Well, running the executable through the commandline plugin gets the possibility of the newly built plugin having issues out of the way. If maketx is indeed outputting to stdout we should have chatter in the CommandLine plugin logs.
I’m not sure how it’s different from the output you’re getting from the cmd window - those options you’ve highlighted should have stdout and stderr being redirected to the Worker’s logging. (Stdout Redirection Enabled: True should be doing this based on the code I’m reading).
Where’d you find the info about maketx outputting to stdout? Maybe there’s a caveat there I can’t think of?
I was running it from python with subprocess.Popen() when I found it only prints to stdout.
And I may be onto something. I can get the same result as through deadline if I run the following script.
import subprocess
args = r'"C:\Users\daniel.asztalos\AppData\Local\limes_da_sites\studio1\pkgs\0-dev-package\mtoadeploy\4.0.4.2\maya-2019\bin\maketx.exe" -invalidargument'
CREATE_NO_WINDOW = 0x08000000
CREATE_NEW_PROCESS_GROUP = 0x00000200
DETACHED_PROCESS = 0x00000008
creationflags = CREATE_NO_WINDOW | CREATE_NEW_PROCESS_GROUP | DETACHED_PROCESS
p = subprocess.Popen(args, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True, creationflags=creationflags)
stdout, stderr = p.communicate()
print p.returncode
print "----------------stdout----------------"
print stdout
print "----------------stderr----------------"
print stderr
output:
1
----------------stdout----------------
----------------stderr----------------
But if I remove the DETACHED_PROCESS from the flags, runs as expected:
1
----------------stdout----------------
ERROR: Invalid option "-invalidargument"
WARNING: node "color_manager_syncolor" is already installed
maketx -- convert images to tiled, MIP-mapped textures
OpenImageIO-Arnold 2.2.1 http://www.openimageio.org
Usage: maketx [options] file...
--help -v -o --threads -u --format --nchannels --chnames -d --tile --separate --compression --fovcot --wrap --swrap --twrap --resize --noresize --filter --hicomp --sharpen --nomipmap --checknan --fixnan --fullpixels --Mcamera --Mscreen --prman-metadata --attrib --sattrib --sansattrib --constant-color-detect --monochrome-detect --opaque-detect --no-compute-average --ignore-unassoc --runstats --mipimage
Basic modes (default is plain texture):
--shadow --envlatl --lightprobe --bumpslopes --bumpformat
Color Management Options (OpenColorIO DISABLED)
--colorconfig --colorconvert --unpremult
Configuration Presets
--prman --oiio
For detailed help: maketx --help
Arnold Extensions
--colorengine Select the color processor engine to use: ocio or syncolor
(default: ocio, available: ocio, syncolor)
--colorconfig For OCIO, set the OCIO config (leave empty to use OCIO
environment variable).
For synColor, use this flag twice to set the native and
the custom catalog paths.
----------------stderr----------------
I’m not sure what to do with this information yet… Is there a way, to remove the DETACHED_PROCESS flag when running through DL?
I don’t expect we’re letting the process break off into it’s own console:
https://docs.python.org/3/library/subprocess.html#subprocess.DETACHED_PROCESS
I have seen problems with output buffering before (for example, Python itself usually needs a “-u” flag when running inside of Deadline). I checked the maketx flags and don’t see anything about the output handling there.
From the commented out parts of your code, might be worth re-enabling standard output handling just in case
def InitializeProcess(self):
self.SingleFramesOnly = False
self.PluginType = PluginType.Simple
# self.StdoutHandling = True # <-- This one should only be for handler, but may be worth it anyway
# self.HideDosWindow = False
# self.CreateNewConsole = True
The others don’t exist (or at least aren’t documented). Docs are here:
https://docs.thinkboxsoftware.com/products/deadline/10.1/2_Scripting%20Reference/class_deadline_1_1_plugins_1_1_deadline_plugin.html
We use .net Core’s C# Process object to start applications, so there are probably a few Python-centric things that won’t apply here unfortunately.
Ran a quick test by installing the maketx from C4D Arnold version (C4DtoA-2.6.1.5-win-R21.exe specifically) on Deadline 10.1.9.2 and it seems to have worked:
=======================================================
Log
=======================================================
2020-10-29 09:56:44: 0: Loading Job's Plugin timeout is Disabled
2020-10-29 09:56:46: 0: Executing plugin command of type 'Sync Files for Job'
2020-10-29 09:56:46: 0: All job files are already synchronized
2020-10-29 09:56:46: 0: Synchronizing Plugin CommandLine from C:\DeadlineRepository10\plugins\CommandLine took: 0 seconds
2020-10-29 09:56:46: 0: Done executing plugin command of type 'Sync Files for Job'
2020-10-29 09:56:46: 0: Executing plugin command of type 'Initialize Plugin'
2020-10-29 09:56:46: 0: INFO: Executing plugin script 'C:\Users\me\AppData\Local\Thinkbox\Deadline10\slave\mymachine\plugins\5f9ad7f47abab05150ba68eb\CommandLine.py'
2020-10-29 09:56:47: 0: INFO: Single Frames Only: False
2020-10-29 09:56:47: 0: INFO: About: Command Line Plugin for Deadline
2020-10-29 09:56:47: 0: INFO: Render Job As User disabled, running as current user 'me'
2020-10-29 09:56:47: 0: INFO: The job's environment will be merged with the current environment before rendering
2020-10-29 09:56:47: 0: Done executing plugin command of type 'Initialize Plugin'
2020-10-29 09:56:47: 0: Start Job timeout is disabled.
2020-10-29 09:56:47: 0: Task timeout is disabled.
2020-10-29 09:56:47: 0: Loaded job: Testing Output (5f9ad7f47abab05150ba68eb)
2020-10-29 09:56:47: 0: Executing plugin command of type 'Start Job'
2020-10-29 09:56:47: 0: DEBUG: S3BackedCache Client is not installed.
2020-10-29 09:56:47: 0: INFO: Executing global asset transfer preload script 'C:\Users\me\AppData\Local\Thinkbox\Deadline10\slave\mymachine\plugins\5f9ad7f47abab05150ba68eb\GlobalAssetTransferPreLoad.py'
2020-10-29 09:56:47: 0: INFO: Looking for legacy (pre-10.0.26) AWS Portal File Transfer...
2020-10-29 09:56:47: 0: INFO: Looking for legacy (pre-10.0.26) File Transfer controller in C:/Program Files/Thinkbox/S3BackedCache/bin/task.py...
2020-10-29 09:56:47: 0: INFO: Could not find legacy (pre-10.0.26) AWS Portal File Transfer.
2020-10-29 09:56:47: 0: INFO: Legacy (pre-10.0.26) AWS Portal File Transfer is not installed on the system.
2020-10-29 09:56:47: 0: Done executing plugin command of type 'Start Job'
2020-10-29 09:56:47: 0: Plugin rendering frame(s): 1
2020-10-29 09:56:47: 0: Executing plugin command of type 'Render Task'
2020-10-29 09:56:47: 0: INFO: Executable: C:\Users\me\Desktop\Deleteme\plugins\C4DtoA\arnold\bin\maketx.exe
2020-10-29 09:56:47: 0: INFO: Arguments: --non-existant
2020-10-29 09:56:47: 0: INFO: Execute in Shell: False
2020-10-29 09:56:47: 0: INFO: Invoking: Run Process
2020-10-29 09:56:48: 0: STDOUT: maketx -- convert images to tiled, MIP-mapped textures
2020-10-29 09:56:48: 0: STDOUT: OpenImageIO-Arnold 2.1.0dev http://www.openimageio.org
2020-10-29 09:56:48: 0: STDOUT: Usage: maketx [options] file...
2020-10-29 09:56:48: 0: STDOUT: --help Print help message
2020-10-29 09:56:48: 0: STDOUT: -v Verbose status messages
2020-10-29 09:56:48: 0: STDOUT: -o %s Output filename
2020-10-29 09:56:48: 0: STDOUT: --threads %d Number of threads (default: #cores)
2020-10-29 09:56:48: 0: STDOUT: -u Update mode
2020-10-29 09:56:48: 0: STDOUT: --format %s Specify output file format (default: guess from extension)
2020-10-29 09:56:48: 0: STDOUT: Invalid option "--non-existant"
2020-10-29 09:56:48: 0: STDOUT: --nchannels %d Specify the number of output image channels.
2020-10-29 09:56:48: 0: STDOUT: --chnames %s Rename channels (comma-separated)
2020-10-29 09:56:48: 0: STDOUT: -d %s Set the output data format to one of: uint8, sint8, uint16, sint16, half, float
2020-10-29 09:56:48: 0: STDOUT: --tile %d %d Specify tile size
2020-10-29 09:56:48: 0: STDOUT: --separate Use planarconfig separate (default: contiguous)
2020-10-29 09:56:48: 0: STDOUT: --compression %s Set the compression method (default = zip, if possible)
2020-10-29 09:56:48: 0: STDOUT: --fovcot %f Override the frame aspect ratio. Default is width/height.
2020-10-29 09:56:48: 0: STDOUT: --wrap %s Specify wrap mode (black, clamp, periodic, mirror)
2020-10-29 09:56:48: 0: STDOUT: --swrap %s Specific s wrap mode separately
2020-10-29 09:56:48: 0: STDOUT: --twrap %s Specific t wrap mode separately
2020-10-29 09:56:48: 0: STDOUT: --resize Resize textures to power of 2 (default: no)
2020-10-29 09:56:48: 0: STDOUT: --noresize Do not resize textures to power of 2 (deprecated)
2020-10-29 09:56:48: 0: STDOUT: --filter %s Select filter for resizing (choices: box triangle gaussian sharp-gaussian catmull-rom blackman-harris sinc lanczos3 radial-lanczos3 nuke-lanczos6 mitchell bspline disk cubic keys simon rifman, default=box)
2020-10-29 09:56:48: 0: STDOUT: --hicomp Compress HDR range before resize, expand after.
2020-10-29 09:56:48: 0: STDOUT: --sharpen %f Sharpen MIP levels (default = 0.0 = no)
2020-10-29 09:56:48: 0: STDOUT: --nomipmap Do not make multiple MIP-map levels
2020-10-29 09:56:48: 0: STDOUT: --checknan Check for NaN/Inf values (abort if found)
2020-10-29 09:56:48: 0: STDOUT: --fixnan %s Attempt to fix NaN/Inf values in the image (options: none, black, box3)
2020-10-29 09:56:48: 0: STDOUT: --fullpixels Set the 'full' image range to be the pixel data window
2020-10-29 09:56:48: 0: STDOUT: --Mcamera %f %f %f %f %f %f %f %f %f %f %f %f %f %f %f %f
2020-10-29 09:56:48: 0: STDOUT: Set the camera matrix
2020-10-29 09:56:48: 0: STDOUT: --Mscreen %f %f %f %f %f %f %f %f %f %f %f %f %f %f %f %f
2020-10-29 09:56:48: 0: STDOUT: Set the screen matrix
2020-10-29 09:56:48: 0: STDOUT: --prman-metadata Add prman specific metadata
2020-10-29 09:56:48: 0: STDOUT: --attrib %s %s Sets metadata attribute (name, value)
2020-10-29 09:56:48: 0: STDOUT: --sattrib %s %s Sets string metadata attribute (name, value)
2020-10-29 09:56:48: 0: STDOUT: --sansattrib Write command line into Software & ImageHistory but remove --sattrib and --attrib options
2020-10-29 09:56:48: 0: STDOUT: --constant-color-detect Create 1-tile textures from constant color inputs
2020-10-29 09:56:48: 0: STDOUT: --monochrome-detect Create 1-channel textures from monochrome inputs
2020-10-29 09:56:48: 0: STDOUT: --opaque-detect Drop alpha channel that is always 1.0
2020-10-29 09:56:48: 0: STDOUT: --no-compute-average Don't compute and store average color
2020-10-29 09:56:48: 0: STDOUT: --ignore-unassoc Ignore unassociated alpha tags in input (don't autoconvert)
2020-10-29 09:56:48: 0: STDOUT: --runstats Print runtime statistics
2020-10-29 09:56:48: 0: STDOUT: --mipimage %s Specify an individual MIP level
2020-10-29 09:56:48: 0: STDOUT: Basic modes (default is plain texture):
2020-10-29 09:56:48: 0: STDOUT: --shadow Create shadow map
2020-10-29 09:56:48: 0: STDOUT: --envlatl Create lat/long environment map
2020-10-29 09:56:48: 0: STDOUT: --lightprobe Create lat/long environment map from a light probe
2020-10-29 09:56:48: 0: STDOUT: --bumpslopes Create a 6 channels bump-map with height, derivatives and square derivatives from an height or a normal map
2020-10-29 09:56:48: 0: STDOUT: --bumpformat %s Specify the interpretation of a 3-channel input image for --bumpslopes: "height", "normal" or "auto" (default).
2020-10-29 09:56:48: 0: STDOUT: Color Management Options (OpenColorIO DISABLED)
2020-10-29 09:56:48: 0: STDOUT: --colorconfig %s Explicitly specify an OCIO configuration file
2020-10-29 09:56:48: 0: STDOUT: --colorconvert %s %s Apply a color space conversion to the image. If the output color space is not the same bit depth as input color space, it is your responsibility to set the data format to the proper bit depth using the -d option. (choices: sRGB, linear)
2020-10-29 09:56:48: 0: STDOUT: --unpremult Unpremultiply before color conversion, then premultiply after the color conversion. You'll probably want to use this flag if your image contains an alpha channel.
2020-10-29 09:56:48: 0: STDOUT: Configuration Presets
2020-10-29 09:56:48: 0: STDOUT: --prman Use PRMan-safe settings for tile size, planarconfig, and metadata.
2020-10-29 09:56:48: 0: STDOUT: --oiio Use OIIO-optimized settings for tile size, planarconfig, metadata.
2020-10-29 09:56:48: 0: INFO: Process returned: 1
2020-10-29 09:56:48: 0: Done executing plugin command of type 'Render Task'