Reported by an artist:
cheers,
laszlo
The plugin type’s timeout settings:
What’s LAPRO1325 doing right now? My guess is that it’s no longer working on this task, and that it’s either crashed/hung, or moved on to something else (the slaves monitor their own tasks for timeouts). If that’s the case, this is something that Deadline’s housecleaning should have taken care of by now. Let us know what that machine is currently doing and we can go from there.
Thanks!
Ryan
It is rendering right now, something else.
The last log bits from last night:
2014-05-12 19:25:39: 0: Got task!
2014-05-12 19:25:39: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files or plugin files has been modified
2014-05-12 19:25:39: Constructor: 3dsmax
2014-05-12 19:25:39: 0: Loaded plugin: 3dsmax
2014-05-12 19:25:39: 0: Task timeout is 960 seconds (Regular Task Timeout)
2014-05-12 19:25:39: 0: Loaded job: [SEA] SQU_039_8830_v0091_lle_TurbMoreFrwd_S01_cache_flowline_SprayS01_3 (5370f585bb649a044cab7b04)
2014-05-12 19:25:39: 0: INFO: Executing plugin script C:\Users\ScanlineVFX\AppData\Local\Thinkbox\Deadline6\slave\LAPRO1325\plugins\5370f585bb649a044cab7b04\3dsmax.py
2014-05-12 19:25:39: 0: INFO: About: 3dsmax Plugin for Deadline
2014-05-12 19:25:39: 0: INFO: The job's environment will be merged with the current environment before rendering
2014-05-12 19:25:39: 0: INFO: Executing job preload script C:\Users\ScanlineVFX\AppData\Local\Thinkbox\Deadline6\slave\LAPRO1325\plugins\5370f585bb649a044cab7b04\JobPreLoad.py
2014-05-12 19:25:39: 0: INFO: JobPreLoad.__main__
2014-05-12 19:25:39: 0: INFO: RUN SCENEJANITOR
2014-05-12 19:25:42: 0: INFO: Done, wrangling env variables
2014-05-12 19:25:42: 0: INFO: JobPreLoad.unsetEnvironmentVariables
2014-05-12 19:25:42: 0: INFO: Delete: SCL_CONFIG_FARM_MODE
2014-05-12 19:25:42: 0: INFO: Checking for leftover assburner scripts in : C:\3ds Max 2012\Scripts\Startup\NetworkStartup
2014-05-12 19:25:42: 0: INFO: JobPreLoad Setting Job Environment Variables
2014-05-12 19:25:42: 0: INFO: JobPreLoad Setting: SCL_CONFIG_FARM_MODE = 1
2014-05-12 19:25:42: 0: INFO: JobPreLoad Setting: FLOWLINEVERSION = 5984
2014-05-12 19:25:42: 0: INFO: JobPreLoad Setting: FLOWLINE2_CFG_INI = C:\Flowline2.5\ini\flconfig.ini
2014-05-12 19:25:42: 0: INFO: JobPreLoad Setting: FLOWLINE2_PLUGIN_INI_MAX = c:\flowline2.5\ini\flplugs_max.ini
2014-05-12 19:25:42: 0: INFO: JobPreLoad Setting: FLOWLINE2_BASECFG_INI = \\s2\exchange\software\managed\flowline\FLOWLINE2_BASECFG_INI.ini
2014-05-12 19:25:42: 0: INFO: Done.
2014-05-12 19:25:42: 0: INFO: Job aux path: \\inferno2\deadline\repository6\jobs\5370f585bb649a044cab7b04
2014-05-12 19:25:42: 0: INFO: Scanline 3ds Max config file: \\s2\exchange\software\managed\SoftwareConfiguration\Max2012\ConfigurationSettings\SEA_Prestart_Max2012_64Bit_Farm.bat
2014-05-12 19:41:41: 0: Slave timed out -- canceling current task...Then nothing till this morning, when the user tried to manually requeue:
2014-05-13 09:28:52: BEGIN - LAPRO1325\ScanlineVFX
2014-05-13 09:28:52: Scheduler Thread - Task "75_1126-1126" could not be found because task has been modified:
2014-05-13 09:28:52: current status = Rendering, new status = Queued
2014-05-13 09:28:52: current slave = LAPRO1325, new slave =
2014-05-13 09:28:52: current frames = 1126-1126, new frames = 1126-1126
2014-05-13 09:28:52: Scheduler Thread - Cancelling task...
2014-05-13 09:29:15: Scheduler Thread - Task "75_1126-1126" could not be found because task has been modified:
2014-05-13 09:29:15: current status = Rendering, new status = Queued
2014-05-13 09:29:15: current slave = LAPRO1325, new slave =
2014-05-13 09:29:15: current frames = 1126-1126, new frames = 1126-1126
2014-05-13 09:29:15: Scheduler Thread - Cancelling task...
2014-05-13 09:29:39: Scheduler Thread - Task "75_1126-1126" could not be found because task has been modified:
2014-05-13 09:29:39: current status = Rendering, new status = Queued
2014-05-13 09:29:39: current slave = LAPRO1325, new slave =
2014-05-13 09:29:39: current frames = 1126-1126, new frames = 1126-1126This repeats for about 30 mins, then it appears to continue with the task? Or maybe these were ‘stuck’ log messages in the buffer?:
2014-05-13 09:57:10: Scheduler Thread - Task "75_1126-1126" could not be found because task has been modified:
2014-05-13 09:57:10: current status = Rendering, new status = Queued
2014-05-13 09:57:10: current slave = LAPRO1325, new slave =
2014-05-13 09:57:10: current frames = 1126-1126, new frames = 1126-1126
2014-05-13 09:57:10: Scheduler Thread - Cancelling task...
2014-05-13 09:57:28: 0: INFO: JobPreLoad.logScanlineEnvironmentVariables
2014-05-13 09:57:28: 0: INFO: SCL_CONFIG_FARM_MODE=1
2014-05-13 09:57:28: 0: INFO: Non scanline env variables
2014-05-13 09:57:28: 0: INFO: ADSK_3DSMAX_X64_2012=C:\3ds Max 2012\
2014-05-13 09:57:28: 0: INFO: ALLUSERSPROFILE=C:\ProgramData
2014-05-13 09:57:28: 0: INFO: APPDATA=C:\Users\ScanlineVFX\AppData\Roaming
2014-05-13 09:57:28: 0: INFO: CLASSPATH=.;C:\Program Files (x86)\QuickTime\QTSystem\QTJava.zip
2014-05-13 09:57:28: 0: INFO: CM2012DIR=C:\Program Files (x86)\Common Files\Autodesk Shared\Materials\
2014-05-13 09:57:28: 0: INFO: COMMONPROGRAMFILES=C:\Program Files\Common Files
2014-05-13 09:57:28: 0: INFO: COMMONPROGRAMFILES(X86)=C:\Program Files (x86)\Common Files
2014-05-13 09:57:28: 0: INFO: COMMONPROGRAMW6432=C:\Program Files\Common Files
2014-05-13 09:57:28: 0: INFO: COMPUTERNAME=LAPRO1325
2014-05-13 09:57:28: 0: INFO: COMSPEC=C:\Windows\system32\cmd.exe
2014-05-13 09:57:28: 0: INFO: DEADLINE_PATH=C:\Program Files\Thinkbox\Deadline6\bin
2014-05-13 09:57:28: 0: INFO: EXOCORTEX_LICENSE=5053@lapro0001.scanlinevfxla.com
2014-05-13 09:57:28: 0: INFO: FLOWLINE2_BASECFG_INI=\\S2\exchange\software\managed\flowline\FLOWLINE2_BASECFG_INI_16threads.ini
2014-05-13 09:57:28: 0: INFO: FLOWLINE2_BASE_CFG_INI=\FLOWLINE2_BASECFG_INI_Artist_12threads.ini
2014-05-13 09:57:28: 0: INFO: FLOWLINE2_CFG_INI=C:\Flowline2.5\ini\flconfig.ini
2014-05-13 09:57:28: 0: INFO: FLOWLINE2_PLUGIN_INI_MAX=c:\flowline2.5\ini\flplugs_max.ini
2014-05-13 09:57:28: 0: INFO: FLOWLINEVERSION=5984
2014-05-13 09:57:28: 0: INFO: FL_HOSTNAME=lapro1325
2014-05-13 09:57:28: 0: INFO: FL_LOGPATH=\\inferno2\deadline\repository6\jobs\5370f585bb649a044cab7b04
2014-05-13 09:57:28: 0: INFO: FOUNDRY_LICENSE_FILE=27000@lalicsrv02;27000@lalicsrv01;27000@s2la
2014-05-13 09:57:28: 0: INFO: FP_NO_HOST_CHECK=NO
2014-05-13 09:57:28: 0: INFO: HOMEDRIVE=C:
2014-05-13 09:57:28: 0: INFO: HOMEPATH=\Users\ScanlineVFX
2014-05-13 09:57:28: 0: INFO: HUMMPATH14=C:\Program Files\Hummingbird\Connectivity\14.00\NFS Maestro\;C:\Program Files (x86)\Hummingbird\Connectivity\14.00\NFS Maestro\
2014-05-13 09:57:28: 0: INFO: ILBDIR=C:\Program Files (x86)\Common Files\Autodesk Shared\Materials\
2014-05-13 09:57:28: 0: INFO: ILMDIR=C:\Program Files (x86)\Common Files\Autodesk Shared\Materials\
2014-05-13 09:57:28: 0: INFO: LOCALAPPDATA=C:\Users\ScanlineVFX\AppData\Local
2014-05-13 09:57:28: 0: INFO: LOGONSERVER=\\LAPRO1325
2014-05-13 09:57:28: 0: INFO: NUKE_PATH=\\s2\exchange\software\nuke\custom_gizmos
2014-05-13 09:57:28: 0: INFO: NUMBER_OF_PROCESSORS=16
2014-05-13 09:57:28: 0: INFO: OS=Windows_NT
2014-05-13 09:57:28: 0: INFO: PATH=\\s2\exchange\software\managed\Libraries\Qt\4.5.0_x64\bin;C:\Program Files\Thinkbox\Deadline6\bin\;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files\Common Files\Autodesk Shared\;C:\Python26_64;C:\Python26_64\Lib\site-packages\PyQt4;C:\cygwin\bin;C:\Program Files\Hummingbird\Connectivity\14.00\NFS Maestro\;C:\Program Files (x86)\Hummingbird\Connectivity\14.00\NFS Maestro\;C:\Program Files (x86)\Autodesk\Backburner\
2014-05-13 09:57:28: 0: INFO: PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC
2014-05-13 09:57:28: 0: INFO: PROCESSOR_ARCHITECTURE=AMD64
2014-05-13 09:57:28: 0: INFO: PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 45 Stepping 7, GenuineIntel
2014-05-13 09:57:28: 0: INFO: PROCESSOR_LEVEL=6
2014-05-13 09:57:28: 0: INFO: PROCESSOR_REVISION=2d07
2014-05-13 09:57:28: 0: INFO: PROGRAMDATA=C:\ProgramData
2014-05-13 09:57:28: 0: INFO: PROGRAMFILES=C:\Program Files
2014-05-13 09:57:28: 0: INFO: PROGRAMFILES(X86)=C:\Program Files (x86)
2014-05-13 09:57:28: 0: INFO: PROGRAMW6432=C:\Program Files
2014-05-13 09:57:28: 0: INFO: PSMODULEPATH=C:\Windows\system32\WindowsPowerShell\v1.0\Modules\
2014-05-13 09:57:28: 0: INFO: PUBLIC=C:\Users\Public
2014-05-13 09:57:28: 0: INFO: PYTHONPATH=C:\Program Files\Thinkbox\Deadline6\bin\lib;C:\Program Files\Thinkbox\Deadline6\bin\Dlls
2014-05-13 09:57:28: 0: INFO: QTDIR=\\s2\exchange\software\managed\Libraries\Qt\4.5.0_x64
2014-05-13 09:57:28: 0: INFO: QTJAVA=C:\Program Files (x86)\QuickTime\QTSystem\QTJava.zip
2014-05-13 09:57:28: 0: INFO: QT_PLUGIN_PATH=\\s2\exchange\software\managed\Libraries\Qt\4.5.0_x64\plugins
2014-05-13 09:57:28: 0: INFO: RVL_SERVER=s2la.scanlinevfxla.com
2014-05-13 09:57:28: 0: INFO: SESSIONNAME=Console
2014-05-13 09:57:28: 0: INFO: SYSTEMDRIVE=C:
2014-05-13 09:57:28: 0: INFO: SYSTEMROOT=C:\Windows
2014-05-13 09:57:28: 0: INFO: TEMP=S:\Temp
2014-05-13 09:57:28: 0: INFO: TMP=S:\Temp
2014-05-13 09:57:28: 0: INFO: USERDOMAIN=LAPRO1325
2014-05-13 09:57:28: 0: INFO: USERNAME=ScanlineVFX
2014-05-13 09:57:28: 0: INFO: USERPROFILE=C:\Users\ScanlineVFX
2014-05-13 09:57:28: 0: INFO: VRAY30_RT_FOR_3DSMAX2012_MAIN_X64=C:\Program Files\Chaos Group\V-Ray\RT for 3ds Max 2012 for x64\bin
2014-05-13 09:57:28: 0: INFO: VRAY30_RT_FOR_3DSMAX2012_PLUGINS_X64=C:\Program Files\Chaos Group\V-Ray\RT for 3ds Max 2012 for x64\bin\plugins
2014-05-13 09:57:28: 0: INFO: VRAY_RT_FOR_3DSMAX2012_MAIN_X64=C:\Program Files\Chaos Group\V-Ray\RT for 3ds Max 2012 for x64\bin
2014-05-13 09:57:28: 0: INFO: VRAY_RT_FOR_3DSMAX2012_PLUGINS_X64=C:\Program Files\Chaos Group\V-Ray\RT for 3ds Max 2012 for x64\bin\plugins
2014-05-13 09:57:28: 0: INFO: WINDIR=C:\Windows
2014-05-13 09:57:28: 0: INFO: WINDOWS_TRACING_FLAGS=3
2014-05-13 09:57:28: 0: INFO: WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log
2014-05-13 09:57:28: 0: INFO: Start Job called - starting up 3dsmax plugin
2014-05-13 09:57:28: 0: INFO: Sys Env Var PATH: \\s2\exchange\software\managed\Libraries\Qt\4.5.0_x64\bin;C:\Program Files\Thinkbox\Deadline6\bin\;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files\Common Files\Autodesk Shared\;C:\Python26_64;C:\Python26_64\Lib\site-packages\PyQt4;C:\cygwin\bin;C:\Program Files\Hummingbird\Connectivity\14.00\NFS Maestro\;C:\Program Files (x86)\Hummingbird\Connectivity\14.00\NFS Maestro\;C:\Program Files (x86)\Autodesk\Backburner\
2014-05-13 09:57:28: 0: INFO: Sys Env Var PATH length: 528
2014-05-13 09:57:28: 0: INFO: Backburner Path(s) Found in PATH: 'C:\Program Files (x86)\Autodesk\Backburner\'
2014-05-13 09:57:28: 0: INFO: Backburner server.exe version: 2014.0.0.1635
2014-05-13 09:57:28: 0: INFO: Rendering with 3dsmax version: 2012
2014-05-13 09:57:28: 0: INFO: Build of 3dsmax to force: 64bit
2014-05-13 09:57:28: 0: INFO: Rendering with executable: C:\3ds Max 2012\3dsmax.exe
2014-05-13 09:57:28: 0: INFO: Slave 3dsmax.exe version: 14.10.483.0
2014-05-13 09:57:28: 0: INFO: Slave 3dsmax.exe description: 3dsMax 2012 + productupdate_pu10
2014-05-13 09:57:28: 0: INFO: Submitted from 3dsmax.exe version: 14.10.483.0
2014-05-13 09:57:28: 0: INFO: Submitted from 3dsmax.exe description: 3dsMax 2012 + productupdate_pu10
2014-05-13 09:57:28: 0: INFO: Checking registry for 3dsmax language code
2014-05-13 09:57:28: 0: INFO: Found language code: 409
2014-05-13 09:57:28: 0: INFO: Language code string: enu
2014-05-13 09:57:28: 0: INFO: Fail on existing 3dsmax process: 0
2014-05-13 09:57:28: 0: INFO: Load 3dsmax timeout: 1000 seconds
2014-05-13 09:57:28: 0: INFO: Start job timeout: 1000 seconds
2014-05-13 09:57:28: 0: INFO: Progress update timeout: 8000 seconds
2014-05-13 09:57:28: 0: INFO: Progress update timeout disabled: 0
2014-05-13 09:57:28: 0: INFO: Kill ADSK WSCommCntr*.exe process: False
2014-05-13 09:57:28: 0: INFO: Slave mode enabled: 1
2014-05-13 09:57:28: 0: INFO: Silent mode enabled: 0
2014-05-13 09:57:28: 0: INFO: Local rendering enabled: 1
2014-05-13 09:57:28: 0: INFO: Running render sanity check using 3dsmaxcmd.exe
2014-05-13 09:57:28: 0: INFO: 3dsmaxcmd.exe exit code: 3
2014-05-13 09:57:28: 0: INFO: 3dsmaxcmd.exe returned: P5/13/2014 9:57:28 AM; Error opening scene file: "C:\3ds Max 2012\"
2014-05-13 09:57:28: 0: INFO: Render sanity check using 3dsmaxcmd.exe completed successfully. Please ignore the 'Error opening...' message thrown by 3dsmaxcmd.exe above.
2014-05-13 09:57:28: 0: INFO: 3dsmax start up file: C:\Users\ScanlineVFX\AppData\Local\Thinkbox\Deadline6\slave\LAPRO1325\plugins\5370f585bb649a044cab7b04\deadlineStartupMax2012.max
2014-05-13 09:57:28: 0: INFO: Using user profiles: 0
2014-05-13 09:57:28: 0: INFO: 3dsmax data path: C:\3ds Max 2012\
2014-05-13 09:57:28: 0: INFO: 3dsmax ini file: C:\3ds Max 2012\3dsmax.ini
2014-05-13 09:57:28: 0: INFO: Network log file: C:\3ds Max 2012\Network\Max.log
2014-05-13 09:57:28: 0: INFO: Plugin ini file: C:\3ds Max 2012\plugin.ini
2014-05-13 09:57:28: 0: INFO: Including user profile plugin ini: C:\3ds Max 2012\Plugin.UserSettings.ini
2014-05-13 09:57:28: 0: INFO: Lightning connection plugin: C:\Users\ScanlineVFX\AppData\Local\Thinkbox\Deadline6\slave\LAPRO1325\plugins\5370f585bb649a044cab7b04\lightning64Max2012.dlx
2014-05-13 09:57:28: 0: INFO: 3dsmax socket connection port: 60391
2014-05-13 09:57:28: 0: INFO: Setting up startup environment
2014-05-13 09:57:28: 0: INFO: Copying C:\Users\ScanlineVFX\AppData\Local\Thinkbox\Deadline6\slave\LAPRO1325\plugins\5370f585bb649a044cab7b04\lightning64Max2012.dlx to C:\Users\ScanlineVFX\AppData\Local\Thinkbox\Deadline6\temp\lightning\lightning.dlx
2014-05-13 09:57:28: 0: INFO: Copying dl.ini to 3dsmax data path: C:\3ds Max 2012\
2014-05-13 09:57:28: 0: INFO: If this fails, make sure that the necessary permissions are set on this folder to allow for this copy to take place
2014-05-13 09:57:28: 0: INFO: Starting monitored managed process 3dsmaxProcess
2014-05-13 09:57:28: 0: INFO: Stdout Handling Enabled: True
2014-05-13 09:57:28: 0: INFO: Popup Handling Enabled: True
2014-05-13 09:57:28: 0: INFO: Using Process Tree: True
2014-05-13 09:57:28: 0: INFO: Hiding DOS Window: False
2014-05-13 09:57:28: 0: INFO: Creating New Console: False
2014-05-13 09:57:28: 0: INFO: Executable: "C:\3ds Max 2012\3dsmax.exe"
2014-05-13 09:57:28: 0: INFO: Argument: -p "dl.ini" -q -s "C:\Users\ScanlineVFX\AppData\Local\Thinkbox\Deadline6\slave\LAPRO1325\plugins\5370f585bb649a044cab7b04\deadlineStartupMax2012.max"
2014-05-13 09:57:28: 0: INFO: Startup Directory: "C:\3ds Max 2012"
2014-05-13 09:57:29: 0: INFO: Process Priority: BelowNormal
2014-05-13 09:57:29: 0: INFO: Process Affinity: default
2014-05-13 09:57:29: 0: INFO: Process is now running
2014-05-13 09:57:29: 0: INFO: Waiting for connection from 3dsmax
2014-05-13 09:57:29: 0: Unloading plugin: 3dsmax
2014-05-13 09:57:30: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2014-05-13 09:57:30: Scheduler Thread - Seconds before next job scan: 2
2014-05-13 09:57:32: Scheduler - Performing Job scan on Primary Pools with scheduling order Pool, Weighted, Balanced
2014-05-13 09:57:32: Scheduler - Slave is not whitelisted for upload limit.
2014-05-13 09:57:32: Scheduler - The 53724c3380eca31f18ef591b limit is maxed out.It looks like the slave may have gotten stuck when running this batch file:
Scanline 3ds Max config file: \\s2\exchange\software\managed\SoftwareConfiguration\Max2012\ConfigurationSettings\SEA_Prestart_Max2012_64Bit_Farm.batIt looks like pre-job scripts aren’t affected by a job’s timeout setting, so if this batch file never exits, the script never returns, and the slave gets stuck indefinitely. Obviously this is not ideal, so we’ll have to look at making sure the timeout affects this script in a future release. For now, I wonder if it would be possible to modify your pre-job script to detect if the batch file is taking longer than expected to run…
Cheers,
Ryan
The code executing this is:
deadlinePlugin.LogInfo("Scanline 3ds Max config file: %s" % maxConfigFilePath)
maxLauncherSubProcess = subprocess.call(maxConfigFilePath)
if maxLauncherSubProcess != 0:
deadlinePlugin.FailRender("Error while calling Scanline 3ds Max config file [%s]." % maxConfigFilePath)
logScanlineEnvironmentVariables(deadlinePlugin)Based on the log, the slave detected that the startup is taking too long, but it was unable to cancel it. Shouldn’t it just kill the python execution?
Another strong vote for encapsulating the python environment?
I’m pretty sure the code isn’t set up to do this at this time. It’s set up to work with the pre and post job/task scripts, but the pre-job script was an oversight.