Troubleshooting modified Nuke plugin

JTB_MPS · January 16, 2018, 7:04pm

I’m normally able to follow the stack trace, but I’m at a bit of a loss on this one. We can’t find which path is empty.

It’s from a custom plugin based on the stock Nuke plugin, with very minimal alterations. We’re not sure where it’s failing; it gets into self.StartMonitoredManagedProcess() and I can’t track it any more. Any suggestions?

[code]=======================================================
Error

Error: Error: Path is empty (System.ArgumentException)
at System.IO.FileStream…ctor (System.String path, System.IO.FileMode mode, System.IO.FileAccess access, System.IO.FileShare share, System.Int32 bufferSize, System.Boolean anonymous, System.IO.FileOptions options) [0x0002d] in :0
at System.IO.FileStream…ctor (System.String path, System.IO.FileMode mode, System.IO.FileAccess access, System.IO.FileShare share) [0x00000] in :0
at (wrapper remoting-invoke-with-check) System.IO.FileStream:.ctor (string,System.IO.FileMode,System.IO.FileAccess,System.IO.FileShare)
at System.IO.File.OpenRead (System.String path) [0x00000] in :0
at Deadline.IO.PathMappingUtils. (System.String , System.String , System.String , System.String[] , System.String[] , FranticX.IO.MappedOSPath[] , System.Boolean , Deadline.Controllers.DataController , FranticX.GenericDelegate11[T] , System.String ) [0x00008] in <d8152fd02ca44a7e8cc4e23b7b25560a>:0 at Deadline.IO.PathMappingUtils.CheckPathMappingInFileAndReplace (System.String inFileName, System.String outFileName, System.String forceSeperator, System.String[] stringsToReplace, System.String[] newStrings, Deadline.Controllers.DataController dataController, FranticX.GenericDelegate11[T] logFunction, System.String regionID, System.Boolean readFileAsBytes) [0x000ea] in :0
at Deadline.IO.PathMappingUtils.CheckPathMappingInFileAndReplace (System.String inFileName, System.String outFileName, System.String forceSeperator, System.String[] stringsToReplace, System.String[] newStrings, Deadline.Controllers.DataController dataController, FranticX.GenericDelegate11[T] logFunction, System.String regionID) [0x00001] in <d8152fd02ca44a7e8cc4e23b7b25560a>:0 at Deadline.IO.PathMappingUtils.CheckPathMappingInFileAndReplace (System.String inFileName, System.String outFileName, System.String[] stringsToReplace, System.String[] newStrings, Deadline.Controllers.DataController dataController, FranticX.GenericDelegate11[T] logFunction, System.String regionID) [0x00001] in :0
at Deadline.Scripting.RepositoryUtils.CheckPathMappingInFileAndReplace (System.String inFileName, System.String outFileName, System.String[] stringsToReplace, System.String[] newStrings) [0x00023] in :0
at (wrapper managed-to-native) System.Reflection.MonoMethod:InternalInvoke (System.Reflection.MonoMethod,object,object[],System.Exception&)
at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00038] in :0
at Python.Runtime.Dispatcher.TrueDispatch (System.Collections.ArrayList args) [0x00092] in <11a88448843a42af8a1f1c43d5f5492d>:0
at Python.Runtime.Dispatcher.Dispatch (System.Collections.ArrayList args) [0x00008] in <11a88448843a42af8a1f1c43d5f5492d>:0
at Deadline.Plugins.PluginWrapper.StartJob (System.String& outMessage, FranticX.Processes.ManagedProcess+AbortLevel& abortLevel) [0x00081] in :0

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

RenderPluginException

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

at Deadline.Plugins.SandboxedPlugin. (Deadline.Net.DeadlineMessage ) [0x0025b] in :0
at Deadline.Plugins.SandboxedPlugin.StartJob (Deadline.Jobs.Job job) [0x00092] in :0
at Deadline.Slaves.SlaveRenderThread. (Deadline.IO.TaskLogWriter ) [0x0046c] in :0

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

2018-01-16 12:02:22: 0: Loading Job’s Plugin timeout is Disabled
2018-01-16 12:02:23: 0: Executing plugin command of type ‘Sync Files for Job’
2018-01-16 12:02:23: 0: All job files are already synchronized
2018-01-16 12:02:23: 0: Synchronizing Plugin mpsSlate from /vfx/DeadlineRepository10/custom/plugins/mpsSlate took: 0 seconds
2018-01-16 12:02:23: 0: Done executing plugin command of type ‘Sync Files for Job’
2018-01-16 12:02:23: 0: Executing plugin command of type ‘Initialize Plugin’
2018-01-16 12:02:23: 0: CheckPathMapping: Swapped “//nauvoo/pipeline/src/windows/josh/” with “/vfx/pipe/src/windows/josh/”
2018-01-16 12:02:23: 0: INFO: Executing plugin preload script: ‘/tmp/Thinkbox/Deadline10/root/slave/samson-090/plugins/5a5e4c3be127c604f05ea905/PluginPreLoad.py’
2018-01-16 12:02:23: 0: CheckPathMapping: Swapped “\nauvoo\pipeline\src\windows\renae” with “/vfx/pipe\src\windows\renae”
2018-01-16 12:02:23: 0: PYTHON: PLTOOLS should work now on this linux2 system: /vfx/pipe/src/windows/renae
2018-01-16 12:02:23: 0: PYTHON: Checking env vars…
2018-01-16 12:02:23: 0: PYTHON: ALERT: True
2018-01-16 12:02:23: 0: PYTHON: DEADLINE_PATH: /opt/Thinkbox/Deadline10/bin
2018-01-16 12:02:23: 0: PYTHON: FRAME_STRING: 1001
2018-01-16 12:02:23: 0: PYTHON: HISTCONTROL: ignoredups
2018-01-16 12:02:23: 0: PYTHON: HISTSIZE: 1000
2018-01-16 12:02:23: 0: PYTHON: HOSTNAME: samson-090.ldschurch.org
2018-01-16 12:02:23: 0: PYTHON: LANG: en_US.UTF-8
2018-01-16 12:02:23: 0: PYTHON: LD_LIBRARY_PATH: /opt/Thinkbox/Deadline10/bin:/opt/Thinkbox/Deadline10/bin:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin…/mono/lib:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin…/mono/lib:/opt/Thinkbox/Deadline10/bin:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin…/mono/lib:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin…/mono/lib:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin/plugins/platforms:/opt/Thinkbox/Deadline10/bin::/opt/Thinkbox/Deadline10/bin…/mono/lib::/opt/Thinkbox/Deadline10/bin/plugins/platforms
2018-01-16 12:02:23: 0: PYTHON: LESSOPEN: ||/usr/bin/lesspipe.sh %s
2018-01-16 12:02:23: 0: PYTHON: LOGNAME: root
2018-01-16 12:02:23: 0: PYTHON: MAIL: /var/spool/mail/root
2018-01-16 12:02:23: 0: PYTHON: MONO_THREADS_PER_CPU: 50
2018-01-16 12:02:23: 0: PYTHON: NUKE_VERSION: 10.5v5
2018-01-16 12:02:23: 0: PYTHON: PATH: /usr/lib64/qt-3.3/bin:/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin:/opt/puppetlabs/bin:/root/bin
2018-01-16 12:02:23: 0: PYTHON: PLTOOLS: /vfx/pipe/src/windows/renae
2018-01-16 12:02:23: 0: PYTHON: PWD: /opt/Thinkbox/Deadline10/bin
2018-01-16 12:02:23: 0: PYTHON: PYTHONPATH: :/vfx/pipe/src/windows/renae:/vfx/pipe/src/windows/renae/external/lib/python2.7/site-packages
2018-01-16 12:02:23: 0: PYTHON: QTDIR: /usr/lib64/qt-3.3
2018-01-16 12:02:23: 0: PYTHON: QTINC: /usr/lib64/qt-3.3/include
2018-01-16 12:02:23: 0: PYTHON: QTLIB: /usr/lib64/qt-3.3/lib
2018-01-16 12:02:23: 0: PYTHON: QT_GRAPHICSSYSTEM_CHECKED: 1
2018-01-16 12:02:23: 0: PYTHON: RSD: None
2018-01-16 12:02:23: 0: PYTHON: SAPPHIRE_SILENT: 1
2018-01-16 12:02:23: 0: PYTHON: SESI_LMHOST: mps-license-server
2018-01-16 12:02:23: 0: PYTHON: SHELL: /bin/bash
2018-01-16 12:02:23: 0: PYTHON: SHLVL: 1
2018-01-16 12:02:23: 0: PYTHON: SLATE: False
2018-01-16 12:02:23: 0: PYTHON: THINKBOX_LICENSE_FILE: 2708@deadline.ldschurch.org
2018-01-16 12:02:23: 0: PYTHON: USER: root
2018-01-16 12:02:23: 0: PYTHON: VRAY_FOR_MAYA2015_MAIN_x64: /usr/autodesk/maya2015/vray
2018-01-16 12:02:23: 0: PYTHON: VRAY_FOR_MAYA2015_PLUGINS_x64: /usr/autodesk/maya2015/vray/vrayplugins
2018-01-16 12:02:23: 0: PYTHON: VRAY_FOR_MAYA2017_MAIN_x64: /usr/autodesk/maya2017/vray
2018-01-16 12:02:23: 0: PYTHON: VRAY_FOR_MAYA2017_PLUGINS_x64: /usr/autodesk/maya2017/vray/vrayplugins
2018-01-16 12:02:23: 0: PYTHON: VRAY_OSL_PATH_MAYA2015_x64: /usr/ChaosGroup/V-Ray/Maya2015/opensl
2018-01-16 12:02:23: 0: PYTHON: VRAY_OSL_PATH_MAYA2017_x64: /usr/ChaosGroup/V-Ray/Maya2017-x64/opensl
2018-01-16 12:02:23: 0: PYTHON: VRAY_PATH: :/usr/autodesk/maya2017/vray/bin
2018-01-16 12:02:23: 0: PYTHON: VRAY_TOOLS_MAYA2015_x64: /usr/ChaosGroup/V-Ray/Maya2015/bin
2018-01-16 12:02:23: 0: PYTHON: VRAY_TOOLS_MAYA2017_x64: /usr/ChaosGroup/V-Ray/Maya2017-x64/bin
2018-01-16 12:02:23: 0: PYTHON: XDG_RUNTIME_DIR: /run/user/0
2018-01-16 12:02:23: 0: PYTHON: XDG_SESSION_ID: c2
2018-01-16 12:02:23: 0: INFO: Executing plugin script ‘/tmp/Thinkbox/Deadline10/root/slave/samson-090/plugins/5a5e4c3be127c604f05ea905/mpsSlate.py’
2018-01-16 12:02:24: 0: INFO: About: Nuke Plugin for Deadline
2018-01-16 12:02:24: 0: INFO: Render Job As User disabled, running as current user ‘root’
2018-01-16 12:02:24: 0: INFO: The job’s environment will be merged with the current environment before rendering
2018-01-16 12:02:24: 0: Done executing plugin command of type ‘Initialize Plugin’
2018-01-16 12:02:24: 0: Start Job timeout is disabled.
2018-01-16 12:02:24: 0: Task timeout is disabled.
2018-01-16 12:02:24: 0: Loaded job: Remove Slate for Delivery - farmtest:rd.josh:seqdefNuke.cmp:databaseRename-017:4096x2160:dpx (5a5e4c3be127c604f05ea905)
2018-01-16 12:02:24: 0: Executing plugin command of type ‘Start Job’
2018-01-16 12:02:24: 0: INFO: Executing global job preload script ‘/tmp/Thinkbox/Deadline10/root/slave/samson-090/plugins/5a5e4c3be127c604f05ea905/GlobalJobPreLoad.py’
2018-01-16 12:02:24: 0: INFO: PRELOAAAAD
2018-01-16 12:02:24: 0: CheckPathMapping: Swapped “\nauvoo\pipeline\src\windows\renae” with “/vfx/pipe\src\windows\renae”
2018-01-16 12:02:24: 0: INFO: Scrubbing the LD and DYLD LIBRARY paths
2018-01-16 12:02:24: 0: INFO: Prepping OFX cache
2018-01-16 12:02:24: 0: INFO: Checking Nuke temp path: /var/tmp/nuke-u0
2018-01-16 12:02:24: 0: INFO: Path already exists
2018-01-16 12:02:24: 0: INFO: OFX cache prepped
2018-01-16 12:02:24: 0: INFO: Grabbing BatchMode
2018-01-16 12:02:24: 0: INFO: BatchMode: True
2018-01-16 12:02:24: 0: INFO: Grabbing ScriptJob
2018-01-16 12:02:24: 0: INFO: ScriptJob: True
2018-01-16 12:02:24: 0: INFO: Grabbing RemoveSlate
2018-01-16 12:02:24: 0: INFO: RemoveSlate: True
2018-01-16 12:02:24: 0: INFO: Grabbing OutputFilepath
2018-01-16 12:02:24: 0: CheckPathMapping: Swapped “\nauvoo\pipeline\sandbox\renae\deliveryExports\rd-josh\databaseRename_v017.####.dpx” with “/vfx/pipe\sandbox\renae\deliveryExports\rd-josh\databaseRename_v017.####.dpx”
2018-01-16 12:02:24: 0: INFO: OutputFilepath: /vfx/pipe/sandbox/renae/deliveryExports/rd-josh/databaseRename_v017.####.dpx
2018-01-16 12:02:24: 0: INFO: Mad it past self.Process… about to run self.StartMonitoredManagedProcess and I still don’t know which Path is Empty.
2018-01-16 12:02:24: 0: INFO: Starting monitored managed process Nuke
2018-01-16 12:02:24: 0: INFO: Enable Path Mapping: True
2018-01-16 12:02:24: 0: Done executing plugin command of type ‘Start Job’

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

Date: 01/16/2018 12:02:26
Frames: 1001
Elapsed Time: 00:00:00:04
Job Submit Date: 01/16/2018 12:02:19
Job User: renaemb
Average RAM Usage: 1448306396 (3%)
Peak RAM Usage: 1449844736 (3%)
Average CPU Usage: 1%
Peak CPU Usage: 2%
Used CPU Clocks (x10^6 cycles): 389
Total CPU Clocks (x10^6 cycles): 38850

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

Slave Name: samson-090
Version: v10.0.6.3 Release (73d5e0b3b)
Operating System: CentOS Linux release 7.4.1708 (Core)
Machine User: root
IP Address: 10.88.105.190
MAC Address: F4:03:43:3E:33:08
CPU Architecture: x86_64
CPUs: 40
CPU Usage: 0%
Memory Usage: 1.3 GB / 62.4 GB (2%)
Free Disk Space: 215.242 GB
Video Card: Matrox Electronics Systems Ltd. Device 0538 (rev 02)[/code]

eamsler · January 17, 2018, 4:16pm

Looks like the path passed into CheckPathMappingInFileAndReplace().

It gets pretty far by the looks of things. It only chokes when C# is going to open the file to start streaming. I’d throw some print()s in here:

    def pathMappingWithFilePermissionFix( self, inFileName, outFileName, stringsToReplace, newStrings ):
        RepositoryUtils.CheckPathMappingInFileAndReplace( inFileName, outFileName, stringsToReplace, newStrings )
        if SystemUtils.IsRunningOnLinux() or SystemUtils.IsRunningOnMac():
            os.chmod( outFileName, os.stat( inFileName ).st_mode )

If you were generating the job yourself, check to see the “SceneFile” is populated properly. If it’s completely blank, it defaults to the first auxiliary file submitted with the job from what I see in the plugin.

Troubleshooting modified Nuke plugin

[code]======================================================= Error

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

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

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

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