Task Failed to Render

im_thatoneguy · October 31, 2012, 6:27pm

2012-10-30 17:35:06: 0: Unloading plugin: 3dsmax 2012-10-30 17:35:07: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0 2012-10-30 17:35:07: Starting between task wait for available threads - seconds: 3 2012-10-30 17:35:10: Scheduler - The 5090312c5d99e51d88cff2bb limit is disabled. 2012-10-30 17:35:10: Scheduler - Successfully dequeued 1 task(s). Returning. 2012-10-30 17:35:11: 0: Got task: 98_98-98 2012-10-30 17:35:11: Constructor: 3dsmax 2012-10-30 17:35:11: 0: Loaded plugin: 3dsmax 2012-10-30 17:35:11: 0: Task timeout is disabled. 2012-10-30 17:35:11: 0: Loaded job: clock_A01.02 (5090312c5d99e51d88cff2bb) 2012-10-30 17:35:11: 0: Successfully mapped W: to \\sfs-file\working 2012-10-30 17:35:11: 0: Successfully mapped T: to \\sfs-file\tools 2012-10-30 17:35:11: 0: Successfully mapped O: to \\nas\nas\offline 2012-10-30 17:35:11: 0: Successfully mapped R: to \\nas\nas\archive 2012-10-30 17:35:11: 0: Successfully mapped G: to \\DEADALUS02\raid 2012-10-30 17:35:11: 0: INFO: StartJob: initializing script plugin 3dsmax 2012-10-30 17:46:01: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 17:57:31: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 18:09:00: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 18:20:29: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 18:32:00: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 18:43:25: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 18:54:57: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 19:06:26: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 19:18:00: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 19:29:26: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-30 19:40:59: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled

0: Loaded plugin: 3dsmax 0: Task timeout is disabled. 0: Loaded job: clock_A01.02 (5090312c5d99e51d88cff2bb) 0: Successfully mapped W: to \\sfs-file\working 0: Successfully mapped T: to \\sfs-file\tools 0: Successfully mapped O: to \\nas\nas\offline 0: Successfully mapped R: to \\nas\nas\archive 0: Successfully mapped G: to \\DEADALUS02\raid 0: INFO: StartJob: initializing script plugin 3dsmax

This task never started/finished and just sat for 12 hours.

rrussell · October 31, 2012, 6:46pm

Was this a one-off thing? I can see it’s stuck after the “initializing script plugin 3dsmax” line, and then doesn’t print out the About line, so there is a pretty small window for it to get stuck.

If it’s something that happens more than once, you can enable debug mode for the plugin by adding this line to the 3dsmax.dlinit file:

DebugLogging=True

The next time a new 3dsmax job starts, you’ll see a bunch of debug output, so if this problem happens on a regular basis, enabling debug mode should help us pinpoint where the problem is occurring.

Cheers,

Ryan

im_thatoneguy · October 31, 2012, 6:56pm

So far, it’s a one-off. I’ll enable debugging if I see it more often.

im_thatoneguy · October 31, 2012, 11:26pm

Ok, it’s now repeated itself [Beta 4]. I’ll turn on debugging mode and let you know if there is any more insight when it happens again.

im_thatoneguy · October 31, 2012, 11:43pm

Ok looks like that was unnecessary. I found the relevant bit of the log:

[code]2012-10-31 15:35:27: BEGIN - RENDER-I7-02\renderadmin
2012-10-31 15:35:27: Start-up
2012-10-31 15:35:27: 2012-10-31 15:35:27
2012-10-31 15:35:27: Deadline Slave 6.0 [v6.0.0.48930 R]
2012-10-31 15:35:27: Scanning for auto configuration
2012-10-31 15:35:30: Auto Configuration: No auto configuration could be detected, using local configuration
2012-10-31 15:35:30: Connecting to repository
2012-10-31 15:35:30: slave initialization beginning.
2012-10-31 15:35:32: Info Thread - Created.
2012-10-31 15:35:33: Purging old logs
2012-10-31 15:35:33: Starting between task wait - seconds: 2
2012-10-31 15:35:36: Scheduler Thread - Slave initialization complete.
2012-10-31 15:35:36: Scheduler Thread - Performing house cleaning…
2012-10-31 15:35:36: Trying to connect using license server ‘@sfs-file’
2012-10-31 15:35:36: Scheduler - The 509198075d99e5164030f78d limit is disabled.
2012-10-31 15:35:36: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-10-31 15:35:36:
2012-10-31 15:35:36: Scheduler Thread - Successfully mapped W: to \sfs-file\working
2012-10-31 15:35:37: Scheduler Thread - Successfully mapped T: to \sfs-file\tools
2012-10-31 15:35:37: Scheduler Thread - Successfully mapped O: to \nas\nas\offline
2012-10-31 15:35:37: Scheduler Thread - Successfully mapped R: to \nas\nas\archive
2012-10-31 15:35:37: Scheduler Thread - Successfully mapped G: to \DEADALUS02\raid
2012-10-31 15:35:38: Scheduler Thread - Synchronizing job files
2012-10-31 15:35:38: Scheduler Thread - Synchronization time for job files: 27 ms
2012-10-31 15:35:38: Scheduler Thread - Synchronizing plugin files
2012-10-31 15:35:38: Scheduler Thread - Synchronization time for plugin files: 253 ms
2012-10-31 15:35:39: 0: Got task: 42_42-42
2012-10-31 15:35:39: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified
2012-10-31 15:35:39: Constructor: 3dsmax
2012-10-31 15:35:39: 0: Loaded plugin: 3dsmax
2012-10-31 15:35:39: 0: Task timeout is disabled.
2012-10-31 15:35:39: 0: Loaded job: clock_A01.03 (509198075d99e5164030f78d)
2012-10-31 15:35:39: 0: Successfully mapped W: to \sfs-file\working
2012-10-31 15:35:39: 0: Successfully mapped T: to \sfs-file\tools
2012-10-31 15:35:39: 0: Successfully mapped O: to \nas\nas\offline
2012-10-31 15:35:39: 0: Successfully mapped R: to \nas\nas\archive
2012-10-31 15:35:39: 0: Successfully mapped G: to \DEADALUS02\raid
2012-10-31 15:35:39: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-10-31 15:35:41: 0: INFO: About: 3dsmax Plugin for Deadline
2012-10-31 15:35:41: 0: INFO: Start Job called - starting up 3dsmax plugin
2012-10-31 15:35:41: 0: INFO: Rendering with 3dsmax version: 2012
2012-10-31 15:35:41: 0: INFO: Build of 3dsmax to force: 64bit
2012-10-31 15:35:41: 0: INFO: Rendering with executable: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe
2012-10-31 15:35:41: 0: INFO: Checking registry for 3dsmax language code
2012-10-31 15:35:41: 0: INFO: Found language code: 409
2012-10-31 15:35:41: 0: INFO: Language code string: enu
2012-10-31 15:35:41: 0: INFO: Fail on existing 3dsmax process: 0
2012-10-31 15:35:41: 0: INFO: Load 3dsmax timeout: 1000 seconds
2012-10-31 15:35:41: 0: INFO: Start job timeout: 1000 seconds
2012-10-31 15:35:41: 0: INFO: Progress update timeout: 8000 seconds
2012-10-31 15:35:41: 0: INFO: Progress update timout disabled: 0
2012-10-31 15:35:41: 0: INFO: Slave mode enabled: 1
2012-10-31 15:35:41: 0: INFO: Silent mode enabled: 0
2012-10-31 15:35:41: 0: INFO: Local rendering enabled: 1
2012-10-31 15:35:41: 0: INFO: Running render sanity check using 3dsmaxcmd.exe
2012-10-31 15:35:41: 0: INFO: 3dsmaxcmd.exe returned: P10/31/2012 15:35:41 PM; Error opening scene file: “C:\Program Files\Autodesk\3ds Max 2012”
2012-10-31 15:35:41: 0: INFO: 3dsmax start up file: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\deadlineStartupMax2012.max
2012-10-31 15:35:41: 0: INFO: Using user profiles: 1
2012-10-31 15:35:41: 0: INFO: 3dsmax user profile path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu
2012-10-31 15:35:41: 0: INFO: 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-10-31 15:35:41: 0: INFO: 3dsmax ini file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\3dsmax.ini
2012-10-31 15:35:41: 0: INFO: Network log file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\Network\Max.log
2012-10-31 15:35:41: 0: INFO: Plugin ini file: C:\Program Files\Autodesk\3ds Max 2012\plugin.ini
2012-10-31 15:35:41: 0: INFO: Not including user profile plugin ini because it does not exist: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\Plugin.UserSettings.ini
2012-10-31 15:35:41: 0: INFO: Lightning connection plugin: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\lightning64Max2012.dlx
2012-10-31 15:35:41: 0: INFO: 3dsmax socket connection port: 52409
2012-10-31 15:35:41: 0: INFO: Creating startup script: C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms
2012-10-31 15:35:41: 0: An exception occurred: An error occurred in StartJob(): The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process. (Deadline.Plugins.RenderPluginException)
2012-10-31 15:35:41: 0: Unloading plugin: 3dsmax
2012-10-31 15:35:42: Scheduler Thread - Render Thread 0 threw an error:
2012-10-31 15:35:42: Scheduler Thread - An error occurred in StartJob(): The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process.
2012-10-31 15:35:42: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2012-10-31 15:35:42:
Exception Details
IOException – The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process.
Exception.Data: ( )
Exception.TargetSite: System.Object TrueDispatch(System.Collections.ArrayList)
Exception.Source: Python.Runtime
Exception.StackTrace:
at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath)
at System.IO.FileStream…ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy)
at System.IO.FileStream…ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
at System.IO.StreamWriter…ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize)
at System.IO.StreamWriter…ctor(String path, Boolean append)
at System.IO.File.CreateText(String path)
at Python.Runtime.Dispatcher.TrueDispatch(ArrayList args)
at Python.Runtime.Dispatcher.Dispatch(ArrayList args)
at Deadline.Plugins.ScriptPlugin.StartJob(Job job)

RenderPluginException – An error occurred in StartJob(): The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process.
RenderPluginException.Cause: JobError (2)
RenderPluginException.HasSlaveLog: True
Exception.Data: ( )
Exception.TargetSite: Void StartJob(Deadline.Jobs.Job)
Exception.Source: deadline
Exception.StackTrace:
at Deadline.Plugins.ScriptPlugin.StartJob(Job job)
at Deadline.Plugins.Plugin.StartJob(Job job)
at Deadline.Slaves.SlaveRenderThread.a(TaskLogWriter A_0)

2012-10-31 15:35:42: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2012-10-31 15:35:42: Starting between task wait for available threads - seconds: 4
2012-10-31 15:35:46: Scheduler - The 509198075d99e5164030f78d limit is disabled.
2012-10-31 15:35:46: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-10-31 15:35:46: 0: Got task: 42_42-42
2012-10-31 15:35:46: Constructor: 3dsmax
2012-10-31 15:35:46: 0: Loaded plugin: 3dsmax
2012-10-31 15:35:47: 0: Task timeout is disabled.
2012-10-31 15:35:47: 0: Loaded job: clock_A01.03 (509198075d99e5164030f78d)
2012-10-31 15:35:47: 0: Successfully mapped W: to \sfs-file\working
2012-10-31 15:35:47: 0: Successfully mapped T: to \sfs-file\tools
2012-10-31 15:35:47: 0: Successfully mapped O: to \nas\nas\offline
2012-10-31 15:35:47: 0: Successfully mapped R: to \nas\nas\archive
2012-10-31 15:35:47: 0: Successfully mapped G: to \DEADALUS02\raid
2012-10-31 15:35:47: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-10-31 15:46:04: Thermal Shutdown: Skipping zone “rendernodes” because it is disabled
2012-10-31 15:56:41: Thermal Shutdown: Skipping zone “rendernodes” because it is disabled
2012-10-31 16:07:15: Thermal Shutdown: Skipping zone “rendernodes” because it is disabled
2012-10-31 16:17:43: Thermal Shutdown: Skipping zone “rendernodes” because it is disabled
2012-10-31 16:26:47: Listener Thread - fe80::5bd:7556:6315:5c57%10 has connected
2012-10-31 16:26:47: Listener Thread - Received message: StopSlave
2012-10-31 16:26:47: Listener Thread - Responded with: Success
2012-10-31 16:26:47: Slave - slave shutdown: normal
2012-10-31 16:26:47: Listener Thread - OnConnect: Listener Socket has been closed.
2012-10-31 16:26:47: Info Thread - requesting slave info thread quit.
2012-10-31 16:26:47: sending cancel task command to plugin
2012-10-31 16:26:47: sending cancel task command to plugin
2012-10-31 16:26:47: 0: Shutdown
2012-10-31 16:26:48: Info Thread - shutdown complete
2012-10-31 16:26:48: sending cancel task command to plugin
2012-10-31 16:26:48: 0: Shutdown
2012-10-31 16:26:48: sending cancel task command to plugin
2012-10-31 16:26:48: 0: Shutdown
2012-10-31 16:26:48: sending cancel task command to plugin
2012-10-31 16:26:48: 0: Shutdown
2012-10-31 16:26:48: sending cancel task command to plugin
2012-10-31 16:26:48: 0: Shutdown
2012-10-31 16:26:49: sending cancel task command to plugin
2012-10-31 16:26:49: 0: Shutdown

ETC… [/code]

This was after I enabled debugging:

[code]2012-10-31 16:27:18: BEGIN - RENDER-I7-02\renderadmin
2012-10-31 16:27:18: Start-up
2012-10-31 16:27:18: 2012-10-31 16:27:17
2012-10-31 16:27:18: Deadline Slave 6.0 [v6.0.0.48930 R]
2012-10-31 16:27:18: Scanning for auto configuration
2012-10-31 16:27:21: Auto Configuration: No auto configuration could be detected, using local configuration
2012-10-31 16:27:21: Connecting to repository
2012-10-31 16:27:21: slave initialization beginning.
2012-10-31 16:27:23: Info Thread - Created.
2012-10-31 16:27:23: Slave ‘RENDER-I7-02’ has stalled because it has not updated its state in 35.532 s. Performing house cleaning…
2012-10-31 16:27:23: Could not find associated job class though.
2012-10-31 16:27:23: No stalled slave notification address specified in Repository Options - cannot send notification
2012-10-31 16:27:25: Purging old logs
2012-10-31 16:27:25: Starting between task wait - seconds: 2
2012-10-31 16:27:27: Scheduler Thread - Slave initialization complete.
2012-10-31 16:27:27: Scheduler Thread - Performing house cleaning…
2012-10-31 16:27:27: Trying to connect using license server ‘@sfs-file’
2012-10-31 16:27:27: Scheduler - The 509198075d99e5164030f78d limit is disabled.
2012-10-31 16:27:27: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-10-31 16:27:27:
2012-10-31 16:27:27: Scheduler Thread - Successfully mapped W: to \sfs-file\working
2012-10-31 16:27:28: Scheduler Thread - Successfully mapped T: to \sfs-file\tools
2012-10-31 16:27:28: Scheduler Thread - Successfully mapped O: to \nas\nas\offline
2012-10-31 16:27:28: Scheduler Thread - Successfully mapped R: to \nas\nas\archive
2012-10-31 16:27:28: Scheduler Thread - Successfully mapped G: to \DEADALUS02\raid
2012-10-31 16:27:29: Scheduler Thread - Synchronizing job files
2012-10-31 16:27:29: Scheduler Thread - Synchronization time for job files: 48.005 ms
2012-10-31 16:27:29: Scheduler Thread - Synchronizing plugin files
2012-10-31 16:27:29: Scheduler Thread - Synchronization time for plugin files: 738.074 ms
2012-10-31 16:27:30: 0: Got task: 42_42-42
2012-10-31 16:27:30: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified
2012-10-31 16:27:30: Constructor: 3dsmax
2012-10-31 16:27:30: 0: Loaded plugin: 3dsmax
2012-10-31 16:27:30: 0: Task timeout is disabled.
2012-10-31 16:27:30: 0: Loaded job: clock_A01.03 (509198075d99e5164030f78d)
2012-10-31 16:27:30: 0: Successfully mapped W: to \sfs-file\working
2012-10-31 16:27:30: 0: Successfully mapped T: to \sfs-file\tools
2012-10-31 16:27:30: 0: Successfully mapped O: to \nas\nas\offline
2012-10-31 16:27:30: 0: Successfully mapped R: to \nas\nas\archive
2012-10-31 16:27:30: 0: Successfully mapped G: to \DEADALUS02\raid
2012-10-31 16:27:30: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-10-31 16:27:30: 0: DEBUG: CanRenderOnThisMachine: loaded plugin config file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\3dsmax.dlinit
2012-10-31 16:27:30: 0: DEBUG: StartJob: debug logging enabled
2012-10-31 16:27:32: 0: DEBUG: StartJob: loaded plugin script file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\3dsmax.py
2012-10-31 16:27:32: 0: DEBUG: StartJob: initializing Deadline plugin
2012-10-31 16:27:32: 0: DEBUG: StartJob: rendering an advanced plugin job
2012-10-31 16:27:32: 0: INFO: About: 3dsmax Plugin for Deadline
2012-10-31 16:27:32: 0: DEBUG: StartJob: setting job filenames
2012-10-31 16:27:32: 0: DEBUG: PreLoadJob: called
2012-10-31 16:27:32: 0: DEBUG: PreLoadJob: returning
2012-10-31 16:27:32: 0: INFO: Start Job called - starting up 3dsmax plugin
2012-10-31 16:27:32: 0: INFO: Rendering with 3dsmax version: 2012
2012-10-31 16:27:32: 0: INFO: Build of 3dsmax to force: 64bit
2012-10-31 16:27:32: 0: INFO: Rendering with executable: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe
2012-10-31 16:27:32: 0: INFO: Checking registry for 3dsmax language code
2012-10-31 16:27:32: 0: INFO: Found language code: 409
2012-10-31 16:27:32: 0: INFO: Language code string: enu
2012-10-31 16:27:32: 0: INFO: Fail on existing 3dsmax process: 0
2012-10-31 16:27:32: 0: INFO: Load 3dsmax timeout: 1000 seconds
2012-10-31 16:27:32: 0: INFO: Start job timeout: 1000 seconds
2012-10-31 16:27:32: 0: INFO: Progress update timeout: 8000 seconds
2012-10-31 16:27:32: 0: INFO: Progress update timout disabled: 0
2012-10-31 16:27:32: 0: INFO: Slave mode enabled: 1
2012-10-31 16:27:32: 0: INFO: Silent mode enabled: 0
2012-10-31 16:27:32: 0: INFO: Local rendering enabled: 1
2012-10-31 16:27:32: 0: INFO: Running render sanity check using 3dsmaxcmd.exe
2012-10-31 16:27:32: 0: INFO: 3dsmaxcmd.exe returned: P10/31/2012 16:27:31 PM; Error opening scene file: “C:\Program Files\Autodesk\3ds Max 2012”
2012-10-31 16:27:32: 0: INFO: 3dsmax start up file: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\deadlineStartupMax2012.max
2012-10-31 16:27:32: 0: INFO: Using user profiles: 1
2012-10-31 16:27:32: 0: INFO: 3dsmax user profile path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu
2012-10-31 16:27:32: 0: INFO: 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-10-31 16:27:32: 0: INFO: 3dsmax ini file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\3dsmax.ini
2012-10-31 16:27:32: 0: INFO: Network log file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\Network\Max.log
2012-10-31 16:27:32: 0: INFO: Plugin ini file: C:\Program Files\Autodesk\3ds Max 2012\plugin.ini
2012-10-31 16:27:32: 0: INFO: Not including user profile plugin ini because it does not exist: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\Plugin.UserSettings.ini
2012-10-31 16:27:32: 0: INFO: Lightning connection plugin: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\lightning64Max2012.dlx
2012-10-31 16:27:32: 0: INFO: 3dsmax socket connection port: 52919
2012-10-31 16:27:32: 0: INFO: Creating startup script: C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms
2012-10-31 16:27:32: 0: An exception occurred: An error occurred in StartJob(): The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process. (Deadline.Plugins.RenderPluginException)
2012-10-31 16:27:32: 0: Unloading plugin: 3dsmax
2012-10-31 16:27:33: Scheduler Thread - Render Thread 0 threw an error:
2012-10-31 16:27:33: Scheduler Thread - An error occurred in StartJob(): The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process.
2012-10-31 16:27:33: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2012-10-31 16:27:33:
Exception Details
IOException – The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process.
Exception.Data: ( )
Exception.TargetSite: System.Object TrueDispatch(System.Collections.ArrayList)
Exception.Source: Python.Runtime
Exception.StackTrace:
at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath)
at System.IO.FileStream…ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy)
at System.IO.FileStream…ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
at System.IO.StreamWriter…ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize)
at System.IO.StreamWriter…ctor(String path, Boolean append)
at System.IO.File.CreateText(String path)
at Python.Runtime.Dispatcher.TrueDispatch(ArrayList args)
at Python.Runtime.Dispatcher.Dispatch(ArrayList args)
at Deadline.Plugins.ScriptPlugin.StartJob(Job job)

RenderPluginException – An error occurred in StartJob(): The process cannot access the file ‘C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms’ because it is being used by another process.
RenderPluginException.Cause: JobError (2)
RenderPluginException.HasSlaveLog: True
Exception.Data: ( )
Exception.TargetSite: Void StartJob(Deadline.Jobs.Job)
Exception.Source: deadline
Exception.StackTrace:
at Deadline.Plugins.ScriptPlugin.StartJob(Job job)
at Deadline.Plugins.Plugin.StartJob(Job job)
at Deadline.Slaves.SlaveRenderThread.a(TaskLogWriter A_0)

2012-10-31 16:27:33: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2012-10-31 16:27:33: Starting between task wait for available threads - seconds: 4
2012-10-31 16:27:34: Listener Thread - ::ffff:192.168.94.37 has connected
2012-10-31 16:27:34: Listener Thread - Received message: StreamLog
2012-10-31 16:27:34: Listener Thread - Responded with: Success
2012-10-31 16:27:37: Scheduler - The 509198075d99e5164030f78d limit is disabled.
2012-10-31 16:27:37: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-10-31 16:27:37: 0: Got task: 42_42-42
2012-10-31 16:27:37: Constructor: 3dsmax
2012-10-31 16:27:37: 0: Loaded plugin: 3dsmax
2012-10-31 16:27:37: 0: Task timeout is disabled.
2012-10-31 16:27:37: 0: Loaded job: clock_A01.03 (509198075d99e5164030f78d)
2012-10-31 16:27:37: 0: Successfully mapped W: to \sfs-file\working
2012-10-31 16:27:37: 0: Successfully mapped T: to \sfs-file\tools
2012-10-31 16:27:37: 0: Successfully mapped O: to \nas\nas\offline
2012-10-31 16:27:37: 0: Successfully mapped R: to \nas\nas\archive
2012-10-31 16:27:37: 0: Successfully mapped G: to \DEADALUS02\raid
2012-10-31 16:27:37: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-10-31 16:27:37: 0: DEBUG: CanRenderOnThisMachine: loaded plugin config file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\3dsmax.dlinit
2012-10-31 16:27:37: 0: DEBUG: StartJob: debug logging enabled
2012-10-31 16:30:18: Listener Thread - ::ffff:192.168.94.37 has connected
2012-10-31 16:30:18: Listener Thread - Received message: StreamLog
2012-10-31 16:30:18: Listener Thread - Responded with: Success
2012-10-31 16:31:17: Listener Thread - ::ffff:192.168.94.37 has connected
2012-10-31 16:31:17: Listener Thread - Received message: StreamLog
2012-10-31 16:31:17: Listener Thread - Responded with: Success
2012-10-31 16:31:40: Listener Thread - fe80::5bd:7556:6315:5c57%10 has connected
2012-10-31 16:31:41: Listener Thread - Received message: StopSlave
2012-10-31 16:31:41: Listener Thread - Responded with: Success
2012-10-31 16:31:41: Slave - slave shutdown: normal
2012-10-31 16:31:41: Listener Thread - OnConnect: Listener Socket has been closed.
2012-10-31 16:31:41: Info Thread - requesting slave info thread quit.
2012-10-31 16:31:41: sending cancel task command to plugin
2012-10-31 16:31:41: sending cancel task command to plugin
2012-10-31 16:31:41: 0: Shutdown
2012-10-31 16:31:41: sending cancel task command to plugin
2012-10-31 16:31:41: 0: Shutdown
2012-10-31 16:31:41: Info Thread - shutdown complete
2012-10-31 16:31:42: sending cancel task command to plugin
2012-10-31 16:31:42: 0: Shutdown
2012-10-31 16:31:42: sending cancel task command to plugin
2012-10-31 16:31:42: 0: Shutdown
2012-10-31 16:31:42: sending cancel task command to plugin
Etc…
[/code]

When I remote logged in there were two 3dsmax.exe’s running.

im_thatoneguy · November 1, 2012, 12:56am

Every single slave failed when starting up a new job.

2012-10-31 17:29:18: 0: INFO: Prepass 4 of 4... [00:03:39.6] [00:03:40.1 est] 2012-10-31 17:29:18: 0: INFO: Prepass 4 of 4... [00:03:39.9] [00:03:40.3 est] 2012-10-31 17:29:18: 0: INFO: Prepass 4 of 4... [00:03:40.0] [00:03:40.4 est] 2012-10-31 17:29:18: 0: INFO: Prepass 4 of 4... [00:03:40.1] [00:03:40.5 est] 2012-10-31 17:29:18: 0: INFO: Prepass 4 of 4...: done [00:03:40.1] 2012-10-31 17:29:40: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-31 17:34:06: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1 2012-10-31 17:34:06: 0: INFO: Lightning: Render done 2012-10-31 17:34:06: 0: INFO: Lightning: Saved image to W:\12058 ChangeItBack\Assets\Clock\Renders\A01.03\clock_anim_A01.03.0160.exr 2012-10-31 17:34:06: 0: INFO: Lightning: Checking render elements 2012-10-31 17:34:06: 0: Render time for frame: 11.684 m 2012-10-31 17:34:06: 0: Total time for task: 20.132 c 2012-10-31 17:34:07: Scheduler Thread - Render Thread 0 completed its task 2012-10-31 17:34:07: Starting between task wait for available threads - seconds: 4 2012-10-31 17:34:11: Scheduler - The 509198075d99e5164030f78d limit is disabled. 2012-10-31 17:34:11: sending cancel task command to plugin 2012-10-31 17:34:11: 0: Shutdown 2012-10-31 17:34:12: 0: Exited ThreadMain(), cleaning up... 2012-10-31 17:34:12: 0: INFO: End Job called - shutting down 3dsmax plugin 2012-10-31 17:34:12: sending cancel task command to plugin 2012-10-31 17:34:12: 0: Shutdown 2012-10-31 17:34:12: 0: WARNING: Trapped SEH Exception in EndJob(): Access Violation Process: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe Module: C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll Date Modified: 02/23/2011 Exception Code: C0000005 Read Address: 00000032 Instruction: 66 44 3B 60 32 73 1F 0F 1F 80 00 00 00 00 8B D3 Call Stack: 452A0000 C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll +0002B892 Exception Offset 2012-10-31 17:34:12: 0: WARNING: Did not receive a success message in response to EndJob: ERROR: Trapped SEH Exception in EndJob(): Access Violation Process: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe Module: C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll Date Modified: 02/23/2011 Exception Code: C0000005 Read Address: 00000032 Instruction: 66 44 3B 60 32 73 1F 0F 1F 80 00 00 00 00 8B D3 Call Stack: 452A0000 C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll +0002B892 Exception Offset 2012-10-31 17:34:12: 0: INFO: Disconnecting socket connection to 3dsmax 2012-10-31 17:34:12: 0: INFO: Waiting for 3dsmax to shut down 2012-10-31 17:34:12: 0: INFO: 3dsmax has shut down 2012-10-31 17:34:12: 0: Stopped job: clock_A01.03 2012-10-31 17:34:12: 0: Unloading plugin: 3dsmax 2012-10-31 17:34:13: Starting between task wait - seconds: 2 2012-10-31 17:34:16: Scheduler Thread - Performing house cleaning... 2012-10-31 17:34:16: Scheduler - The 509198075d99e5164030f78d limit is disabled. 2012-10-31 17:34:16: Scheduler - The 5091bc2b5d99e50f0088d44b limit is disabled. 2012-10-31 17:34:16: Scheduler - Successfully dequeued 1 task(s). Returning. 2012-10-31 17:34:16: 2012-10-31 17:34:16: Scheduler Thread - Successfully mapped W: to \\sfs-file\working 2012-10-31 17:34:16: Scheduler Thread - Successfully mapped T: to \\sfs-file\tools 2012-10-31 17:34:16: Scheduler Thread - Successfully mapped O: to \\nas\nas\offline 2012-10-31 17:34:17: Scheduler Thread - Successfully mapped R: to \\nas\nas\archive 2012-10-31 17:34:17: Scheduler Thread - Successfully mapped G: to \\DEADALUS02\raid 2012-10-31 17:34:17: Scheduler Thread - Synchronizing job files 2012-10-31 17:34:17: Scheduler Thread - Synchronization time for job files: 31.2 ms 2012-10-31 17:34:17: Scheduler Thread - Synchronizing plugin files 2012-10-31 17:34:17: Scheduler Thread - Synchronization time for plugin files: 421.2 ms 2012-10-31 17:34:18: 0: Got task: 7_7-7 2012-10-31 17:34:18: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified 2012-10-31 17:34:18: Constructor: 3dsmax 2012-10-31 17:34:18: 0: Loaded plugin: 3dsmax 2012-10-31 17:34:18: 0: Task timeout is disabled. 2012-10-31 17:34:18: 0: Loaded job: CIB_TLN_0010_Anim_A02.03 (5091bc2b5d99e50f0088d44b) 2012-10-31 17:34:18: 0: Successfully mapped W: to \\sfs-file\working 2012-10-31 17:34:18: 0: Successfully mapped T: to \\sfs-file\tools 2012-10-31 17:34:18: 0: Successfully mapped O: to \\nas\nas\offline 2012-10-31 17:34:18: 0: Successfully mapped R: to \\nas\nas\archive 2012-10-31 17:34:18: 0: Successfully mapped G: to \\DEADALUS02\raid 2012-10-31 17:34:18: 0: INFO: StartJob: initializing script plugin 3dsmax 2012-10-31 17:34:18: 0: DEBUG: CanRenderOnThisMachine: loaded plugin config file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-05\plugins\3dsmax.dlinit 2012-10-31 17:34:18: 0: DEBUG: StartJob: debug logging enabled 2012-10-31 17:40:51: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-31 17:52:25: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled

2012-10-31 17:32:18: 0: DEBUG: PopupHandler.CheckForPopups: Returning 2012-10-31 17:32:18: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1 2012-10-31 17:32:18: 0: INFO: Lightning: Render done 2012-10-31 17:32:18: 0: INFO: Lightning: Saved image to W:\12058 ChangeItBack\Assets\Clock\Renders\A01.03\clock_anim_A01.03.0181.exr 2012-10-31 17:32:18: 0: INFO: Lightning: Checking render elements 2012-10-31 17:32:18: 0: DEBUG: RenderTasks: returning 2012-10-31 17:32:18: 0: Render time for frame: 7.62 s 2012-10-31 17:32:18: 0: Total time for task: 20.132 c 2012-10-31 17:32:18: Scheduler Thread - Render Thread 0 completed its task 2012-10-31 17:32:18: Starting between task wait for available threads - seconds: 2 2012-10-31 17:32:20: Scheduler - The 509198075d99e5164030f78d limit is disabled. 2012-10-31 17:32:20: sending cancel task command to plugin 2012-10-31 17:32:20: 0: Shutdown 2012-10-31 17:32:21: sending cancel task command to plugin 2012-10-31 17:32:21: 0: Shutdown 2012-10-31 17:32:21: 0: Exited ThreadMain(), cleaning up... 2012-10-31 17:32:22: sending cancel task command to plugin 2012-10-31 17:32:22: 0: DEBUG: EndJob: called 2012-10-31 17:32:22: 0: INFO: End Job called - shutting down 3dsmax plugin 2012-10-31 17:32:22: 0: Shutdown 2012-10-31 17:32:22: sending cancel task command to plugin 2012-10-31 17:32:22: 0: Shutdown 2012-10-31 17:32:22: 0: WARNING: Trapped SEH Exception in EndJob(): Access Violation Process: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe Module: C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll Date Modified: 02/23/2011 Exception Code: C0000005 Read Address: 00000032 Instruction: 66 44 3B 60 32 73 1F 0F 1F 80 00 00 00 00 8B D3 Call Stack: 452A0000 C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll +0002B892 Exception Offset 2012-10-31 17:32:22: 0: WARNING: Did not receive a success message in response to EndJob: ERROR: Trapped SEH Exception in EndJob(): Access Violation Process: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe Module: C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll Date Modified: 02/23/2011 Exception Code: C0000005 Read Address: 00000032 Instruction: 66 44 3B 60 32 73 1F 0F 1F 80 00 00 00 00 8B D3 Call Stack: 452A0000 C:\Program Files\Autodesk\3ds Max 2012\ParamBlk2.dll +0002B892 Exception Offset 2012-10-31 17:32:22: 0: INFO: Disconnecting socket connection to 3dsmax 2012-10-31 17:32:22: 0: INFO: Waiting for 3dsmax to shut down 2012-10-31 17:32:22: 0: INFO: 3dsmax has shut down 2012-10-31 17:32:22: 0: DEBUG: EndJob: returning 2012-10-31 17:32:22: 0: Stopped job: clock_A01.03 2012-10-31 17:32:22: 0: Unloading plugin: 3dsmax 2012-10-31 17:32:23: Starting between task wait - seconds: 2 2012-10-31 17:32:26: Performing Job Repository Scan... 2012-10-31 17:32:26: Done. 2012-10-31 17:32:26: Scheduler Thread - Performing house cleaning... 2012-10-31 17:32:26: Scheduler - The 509198075d99e5164030f78d limit is disabled. 2012-10-31 17:32:26: Scheduler - The 5091bc2b5d99e50f0088d44b limit is disabled. 2012-10-31 17:32:26: Scheduler - Successfully dequeued 1 task(s). Returning. 2012-10-31 17:32:26: 2012-10-31 17:32:26: Scheduler Thread - Successfully mapped W: to \\sfs-file\working 2012-10-31 17:32:26: Scheduler Thread - Successfully mapped T: to \\sfs-file\tools 2012-10-31 17:32:27: Scheduler Thread - Successfully mapped O: to \\nas\nas\offline 2012-10-31 17:32:27: Scheduler Thread - Successfully mapped R: to \\nas\nas\archive 2012-10-31 17:32:27: Scheduler Thread - Successfully mapped G: to \\DEADALUS02\raid 2012-10-31 17:32:27: Scheduler Thread - Synchronizing job files 2012-10-31 17:32:27: Scheduler Thread - Synchronization time for job files: 31.2 ms 2012-10-31 17:32:27: Scheduler Thread - Synchronizing plugin files 2012-10-31 17:32:28: Scheduler Thread - Synchronization time for plugin files: 530.403 ms 2012-10-31 17:32:29: 0: Got task: 2_2-2 2012-10-31 17:32:29: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified 2012-10-31 17:32:29: Constructor: 3dsmax 2012-10-31 17:32:29: 0: Loaded plugin: 3dsmax 2012-10-31 17:32:29: 0: Task timeout is disabled. 2012-10-31 17:32:29: 0: Loaded job: CIB_TLN_0010_Anim_A02.03 (5091bc2b5d99e50f0088d44b) 2012-10-31 17:32:29: 0: Successfully mapped W: to \\sfs-file\working 2012-10-31 17:32:29: 0: Successfully mapped T: to \\sfs-file\tools 2012-10-31 17:32:29: 0: Successfully mapped O: to \\nas\nas\offline 2012-10-31 17:32:29: 0: Successfully mapped R: to \\nas\nas\archive 2012-10-31 17:32:29: 0: Successfully mapped G: to \\DEADALUS02\raid 2012-10-31 17:32:29: 0: INFO: StartJob: initializing script plugin 3dsmax 2012-10-31 17:32:29: 0: DEBUG: CanRenderOnThisMachine: loaded plugin config file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-02\plugins\3dsmax.dlinit 2012-10-31 17:32:29: 0: DEBUG: StartJob: debug logging enabled 2012-10-31 17:37:48: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled 2012-10-31 17:49:25: Thermal Shutdown: Skipping zone "rendernodes" because it is disabled

If there isn’t an easy solution I’m going to have to suspend all Deadline 6 testing until this gets resolved.

im_thatoneguy · November 1, 2012, 1:20am

One last Log.

Ok this could be a compound error.

It racks up an error in the job error count. But 1) I see no way to view errors anymore 2) It doesn’t register the error to the task just the job. So maybe some of these hangs are caused by an error crashing the slave or putting it into an error state and not restarting.

[code]2012-10-31 17:59:39: BEGIN - RENDER-02\renderadmin
2012-10-31 17:59:39: Start-up
2012-10-31 17:59:39: 2012-10-31 17:59:39
2012-10-31 17:59:39: Deadline Slave 6.0 [v6.0.0.48930 R]
2012-10-31 17:59:39: Scanning for auto configuration
2012-10-31 17:59:42: Auto Configuration: No auto configuration could be detected, using local configuration
2012-10-31 17:59:42: Connecting to repository
2012-10-31 17:59:43: slave initialization beginning.
2012-10-31 17:59:45: Info Thread - Created.
2012-10-31 17:59:45: Slave ‘RENDER-02’ has stalled because it has not updated its state in 2.591 m. Performing house cleaning…
2012-10-31 17:59:45: Could not find associated job class though.
2012-10-31 17:59:45: No stalled slave notification address specified in Repository Options - cannot send notification
2012-10-31 17:59:46: Purging old logs
2012-10-31 17:59:46: Starting between task wait - seconds: 1
2012-10-31 17:59:48: Scheduler Thread - Slave initialization complete.
2012-10-31 17:59:48: Scheduler Thread - Performing house cleaning…
2012-10-31 17:59:48: Trying to connect using license server ‘@sfs-file’
2012-10-31 17:59:48: Scheduler - The 5091bc2b5d99e50f0088d44b limit is disabled.
2012-10-31 17:59:48: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-10-31 17:59:48:
2012-10-31 17:59:48: Scheduler Thread - Successfully mapped W: to \sfs-file\working
2012-10-31 17:59:49: Scheduler Thread - Successfully mapped T: to \sfs-file\tools
2012-10-31 17:59:49: Scheduler Thread - Successfully mapped O: to \nas\nas\offline
2012-10-31 17:59:49: Scheduler Thread - Successfully mapped R: to \nas\nas\archive
2012-10-31 17:59:50: Scheduler Thread - Successfully mapped G: to \DEADALUS02\raid
2012-10-31 17:59:50: Scheduler Thread - Synchronizing job files
2012-10-31 17:59:50: Scheduler Thread - Synchronization time for job files: 31.25 ms
2012-10-31 17:59:50: Scheduler Thread - Synchronizing plugin files
2012-10-31 17:59:50: Scheduler Thread - Synchronization time for plugin files: 484.375 ms
2012-10-31 17:59:51: 0: Got task: 1_1-1
2012-10-31 17:59:51: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified
2012-10-31 17:59:51: Constructor: 3dsmax
2012-10-31 17:59:51: 0: Loaded plugin: 3dsmax
2012-10-31 17:59:51: 0: Task timeout is disabled.
2012-10-31 17:59:51: 0: Loaded job: CIB_TLN_0010_Anim_A02.03 (5091bc2b5d99e50f0088d44b)
2012-10-31 17:59:51: 0: Successfully mapped W: to \sfs-file\working
2012-10-31 17:59:51: 0: Successfully mapped T: to \sfs-file\tools
2012-10-31 17:59:51: 0: Successfully mapped O: to \nas\nas\offline
2012-10-31 17:59:51: 0: Successfully mapped R: to \nas\nas\archive
2012-10-31 17:59:51: 0: Successfully mapped G: to \DEADALUS02\raid
2012-10-31 17:59:51: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-10-31 17:59:51: 0: DEBUG: CanRenderOnThisMachine: loaded plugin config file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\3dsmax.dlinit
2012-10-31 17:59:51: 0: DEBUG: StartJob: debug logging enabled
2012-10-31 17:59:52: 0: DEBUG: StartJob: loaded plugin script file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\3dsmax.py
2012-10-31 17:59:52: 0: DEBUG: StartJob: initializing Deadline plugin
2012-10-31 17:59:52: 0: DEBUG: StartJob: rendering an advanced plugin job
2012-10-31 17:59:52: 0: INFO: About: 3dsmax Plugin for Deadline
2012-10-31 17:59:52: 0: DEBUG: StartJob: setting job filenames
2012-10-31 17:59:52: 0: DEBUG: PreLoadJob: called
2012-10-31 17:59:52: 0: DEBUG: PreLoadJob: returning
2012-10-31 17:59:52: 0: INFO: Start Job called - starting up 3dsmax plugin
2012-10-31 17:59:52: 0: INFO: Rendering with 3dsmax version: 2012
2012-10-31 17:59:52: 0: INFO: Build of 3dsmax to force: 64bit
2012-10-31 17:59:52: 0: INFO: Rendering with executable: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe
2012-10-31 17:59:52: 0: INFO: Checking registry for 3dsmax language code
2012-10-31 17:59:52: 0: INFO: Found language code: 409
2012-10-31 17:59:52: 0: INFO: Language code string: enu
2012-10-31 17:59:52: 0: INFO: Fail on existing 3dsmax process: 0
2012-10-31 17:59:52: 0: INFO: Load 3dsmax timeout: 1000 seconds
2012-10-31 17:59:52: 0: INFO: Start job timeout: 1000 seconds
2012-10-31 17:59:52: 0: INFO: Progress update timeout: 8000 seconds
2012-10-31 17:59:52: 0: INFO: Progress update timout disabled: 0
2012-10-31 17:59:52: 0: INFO: Slave mode enabled: 1
2012-10-31 17:59:52: 0: INFO: Silent mode enabled: 0
2012-10-31 17:59:52: 0: INFO: Local rendering enabled: 1
2012-10-31 17:59:52: 0: INFO: Running render sanity check using 3dsmaxcmd.exe
2012-10-31 17:59:53: 0: INFO: 3dsmaxcmd.exe returned: P10/31/2012 17:59:52 PM; Error opening scene file: “C:\Program Files\Autodesk\3ds Max 2012”
2012-10-31 17:59:53: 0: INFO: 3dsmax start up file: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\deadlineStartupMax2012.max
2012-10-31 17:59:53: 0: INFO: Using user profiles: 1
2012-10-31 17:59:53: 0: INFO: 3dsmax user profile path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu
2012-10-31 17:59:53: 0: INFO: 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-10-31 17:59:53: 0: INFO: 3dsmax ini file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\3dsmax.ini
2012-10-31 17:59:53: 0: INFO: Network log file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\Network\Max.log
2012-10-31 17:59:53: 0: INFO: Plugin ini file: C:\Program Files\Autodesk\3ds Max 2012\plugin.ini
2012-10-31 17:59:53: 0: INFO: Not including user profile plugin ini because it does not exist: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\Plugin.UserSettings.ini
2012-10-31 17:59:53: 0: INFO: Lightning connection plugin: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\lightning64Max2012.dlx
2012-10-31 17:59:53: 0: INFO: 3dsmax socket connection port: 51408
2012-10-31 17:59:53: 0: INFO: Creating startup script: C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms
2012-10-31 17:59:53: 0: INFO: Copying C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\lightning64Max2012.dlx to C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\temp\lightning\lightning.dlx
2012-10-31 17:59:53: 0: INFO: Copying dl.ini to 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-10-31 17:59:53: 0: INFO: If this fails, make sure that the necessary permissions are set on this folder to allow for this copy to take place
2012-10-31 17:59:53: 0: INFO: Starting monitored managed process 3dsmaxProcess
2012-10-31 17:59:53: 0: INFO: Stdout Handling Enabled: False
2012-10-31 17:59:53: 0: INFO: Popup Handling Enabled: True
2012-10-31 17:59:53: 0: INFO: Using Process Tree: True
2012-10-31 17:59:53: 0: INFO: Hiding DOS Window: False
2012-10-31 17:59:53: 0: INFO: Creating New Console: False
2012-10-31 17:59:53: 0: INFO: Render Executable: “C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe”
2012-10-31 17:59:53: 0: INFO: Render Argument: -p “dl.ini” -q -s “C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\deadlineStartupMax2012.max”
2012-10-31 17:59:53: 0: INFO: Startup Directory: “C:\Program Files\Autodesk\3ds Max 2012”
2012-10-31 17:59:53: 0: INFO: Process Priority: BelowNormal
2012-10-31 17:59:53: 0: INFO: Process Affinity: default
2012-10-31 17:59:53: 0: INFO: Process is now running
2012-10-31 17:59:53: 0: INFO: Waiting for connection from 3dsmax
2012-10-31 17:59:53: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:53: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:53: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:54: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:54: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:54: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:54: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:54: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:54: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:55: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:55: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:55: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:56: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:56: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:56: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:56: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:56: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:56: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:57: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:57: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:57: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:58: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:58: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:58: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:58: 0: STDOUT: Dark
2012-10-31 17:59:58: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:58: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:58: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:59: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:59: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:59: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 17:59:59: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 17:59:59: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 17:59:59: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:00: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:00: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:00: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:01: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:01: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:01: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:01: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:01: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:01: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:02: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:02: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:02: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:03: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:03: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:03: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:03: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:03: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:03: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:04: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:04: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:04: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:04: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:04: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:04: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:05: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:05: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:05: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:06: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:06: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:06: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:06: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:06: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:06: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:07: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:07: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:07: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:08: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:08: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:08: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:08: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:08: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:08: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:09: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:09: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:09: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:09: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:09: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:09: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:10: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:10: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:10: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:11: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:11: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:11: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:11: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:11: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:11: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:12: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:12: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:12: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:12: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:12: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:12: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:13: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:13: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:13: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:13: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:13: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:13: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:14: 0: INFO: Connected to 3dsmax plugin version Lightning 5.2.0.48814 Oct 19 2012 10:00:55 R
2012-10-31 18:00:14: 0: INFO: Scene file to render: “C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\jobsData\CIB_TLN_0010_Anim_A02.03.max”
2012-10-31 18:00:14: 0: INFO: Camera: “Camera001”
2012-10-31 18:00:14: 0: INFO: Restarting renderer after each frame: 1
2012-10-31 18:00:14: 0: INFO: Showing frame buffer: 1
2012-10-31 18:00:14: 0: INFO: Overriding render output: “W:\12058 ChangeItBack\Shots\TLN\0010\Renders\ANIM\A02.03\CIB_TLN_0010_Anim_A02.03…exr”
2012-10-31 18:00:14: 0: INFO: Frame number base: 0
2012-10-31 18:00:14: 0: INFO: Remove padding from output filename: 0
2012-10-31 18:00:14: 0: INFO: Ignore missing external file errors: 1
2012-10-31 18:00:14: 0: INFO: Ignore missing UVW errors: 1
2012-10-31 18:00:14: 0: INFO: Ignore missing XREF errors: 1
2012-10-31 18:00:14: 0: INFO: Ignore missing DLL errors: 1
2012-10-31 18:00:14: 0: INFO: Disabling Multipass: 0
2012-10-31 18:00:14: 0: INFO: Loading 3dsmax scene file
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:14: 0: INFO: [filename]
[format]
[size] 640x480
[aspect] 1

2012-10-31 18:00:14: 0: INFO: Executing script: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\customize.ms
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:14: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:15: 0: INFO: Applying customizations to max file…
2012-10-31 18:00:15: 0: INFO: >Adding scene path ‘C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\jobsData’ to session paths
2012-10-31 18:00:15: 0: INFO: >General Renderer Settings:
2012-10-31 18:00:15: 0: INFO: +Render Width set to 1920
2012-10-31 18:00:15: 0: INFO: +Render Height set to 1080
2012-10-31 18:00:15: 0: INFO: +Pixel Aspect set to 1.0
2012-10-31 18:00:15: 0: INFO: +Atmospherics set to true
2012-10-31 18:00:15: 0: INFO: +Effects set to true
2012-10-31 18:00:15: 0: INFO: +Displacements set to true
2012-10-31 18:00:15: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:15: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:15: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:15: 0: INFO: +Area Lights/Shadows As Points set to false
2012-10-31 18:00:15: 0: INFO: +Force 2-Sided set to false
2012-10-31 18:00:15: 0: INFO: +Render Hidden Geometry set to false
2012-10-31 18:00:15: 0: INFO: +Video Color Check set to false
2012-10-31 18:00:15: 0: INFO: +Super Black set to false
2012-10-31 18:00:15: 0: INFO: +Render To Fields set to false
2012-10-31 18:00:15: 0: INFO: +Skip Existing Frames set to false
2012-10-31 18:00:15: 0: INFO: >Bitmap Pager Settings:
2012-10-31 18:00:15: 0: INFO: +Not overriding Bitmap Pager setting
2012-10-31 18:00:15: 0: INFO: >Render Environment Settings:
2012-10-31 18:00:15: 0: INFO: +Background Color set to (color 0 0 0)
2012-10-31 18:00:15: 0: INFO: +Use Environment Map set to false
2012-10-31 18:00:15: 0: INFO: +Ambient Color set to (color 0 0 0)
2012-10-31 18:00:15: 0: INFO: +Global Light Tint Color set to (color 255 255 255)
2012-10-31 18:00:15: 0: INFO: +Global Light Level set to 1.0
2012-10-31 18:00:15: 0: INFO: >V-Ray detected as current renderer.
2012-10-31 18:00:15: 0: INFO: +Enabled VRay silent mode
2012-10-31 18:00:15: 0: INFO: +fixedRate_subdivs set to 1
2012-10-31 18:00:15: 0: INFO: +twoLevel_baseSubdivs set to 1
2012-10-31 18:00:15: 0: INFO: +twoLevel_fineSubdivs set to 7
2012-10-31 18:00:15: 0: INFO: +adaptiveSubdivision_minRate set to -1
2012-10-31 18:00:15: 0: INFO: +adaptiveSubdivision_maxRate set to 2
2012-10-31 18:00:15: 0: INFO: +adaptiveSubdivision_threshold set to 0.1
2012-10-31 18:00:15: 0: INFO: +adaptiveSubdivision_rand set to true
2012-10-31 18:00:15: 0: INFO: +imageSampler_outline set to false
2012-10-31 18:00:15: 0: INFO: +imageSampler_normal set to false
2012-10-31 18:00:15: 0: INFO: +imageSamper_normal_threshold set to 0.05
2012-10-31 18:00:15: 0: INFO: +filter_on set to true
2012-10-31 18:00:15: 0: INFO: +filter_size set to 1.5
2012-10-31 18:00:15: 0: INFO: +options_displacement set to true
2012-10-31 18:00:15: 0: INFO: +options_lights set to true
2012-10-31 18:00:15: 0: INFO: +options_hiddenLights set to true
2012-10-31 18:00:15: 0: INFO: +options_shadows set to true
2012-10-31 18:00:15: 0: INFO: +options_defaultLights set to 2
2012-10-31 18:00:15: 0: INFO: +options_reflectionRefraction set to true
2012-10-31 18:00:15: 0: INFO: +options_limitDepth set to false
2012-10-31 18:00:15: 0: INFO: +options_maxDepth set to 2
2012-10-31 18:00:15: 0: INFO: +options_maps set to true
2012-10-31 18:00:15: 0: INFO: +options_filterMaps set to true
2012-10-31 18:00:15: 0: INFO: +options_transpMaxLevels set to 50
2012-10-31 18:00:15: 0: INFO: +options_transpCutoff set to 0.001
2012-10-31 18:00:15: 0: INFO: +options_dontRenderImage set to false
2012-10-31 18:00:15: 0: INFO: +options_overrideMtl_on set to false
2012-10-31 18:00:15: 0: INFO: +options_showGIOnly set to false
2012-10-31 18:00:15: 0: INFO: +options_ray_bias set to 0.0
2012-10-31 18:00:15: 0: INFO: +options_glossyEffects set to true
2012-10-31 18:00:15: 0: INFO: +gi_on set to true
2012-10-31 18:00:15: 0: INFO: +gi_reflectCaustics set to false
2012-10-31 18:00:15: 0: INFO: +gi_refractCaustics set to true
2012-10-31 18:00:15: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:15: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:15: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:15: 0: INFO: +gi_saturation set to 1.0
2012-10-31 18:00:15: 0: INFO: +gi_contrast set to 1.0
2012-10-31 18:00:15: 0: INFO: +gi_contrast_base set to 0.5
2012-10-31 18:00:15: 0: INFO: +gi_saveMapsPerFrame set to true
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_minRate set to -3
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_maxRate set to -2
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_subdivs set to 50
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_interpSamples set to 20
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_colorThreshold set to 0.4
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_normalThreshold set to 0.3
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_distThreshold set to 0.1
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_blurGI set to 0.0
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_showCalcPhase set to true
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_showDirectLight set to true
2012-10-31 18:00:16: 0: INFO: +gi_irradmap_showSamples set to false
2012-10-31 18:00:16: 0: INFO: +adv_irradmap_calcInterpSamples set to 15
2012-10-31 18:00:16: 0: INFO: +adv_irradmap_randomize set to true
2012-10-31 18:00:16: 0: INFO: +adv_irradmap_checkSampleVisibility set to false
2012-10-31 18:00:16: 0: INFO: +adv_irradmap_dontDelete set to true
2012-10-31 18:00:16: 0: INFO: +adv_irradmap_useCurrentPassSamples set to true
2012-10-31 18:00:16: 0: INFO: +adv_irradmap_autoSave set to false
2012-10-31 18:00:16: 0: INFO: +adv_irradmap_switchToSavedMap set to false
2012-10-31 18:00:16: 0: INFO: +photonMap_bounces set to 10
2012-10-31 18:00:16: 0: INFO: +photonMap_autoDist set to true
2012-10-31 18:00:16: 0: INFO: +photonMap_searchDist set to 20.0
2012-10-31 18:00:16: 0: INFO: +photonMap_maxPhotons set to 30
2012-10-31 18:00:16: 0: INFO: +photonMap_multiplier set to 1.0
2012-10-31 18:00:16: 0: INFO: +photonMap_maxDensity set to 0.0
2012-10-31 18:00:16: 0: INFO: +photonMap_convert set to false
2012-10-31 18:00:16: 0: INFO: +photonMap_interpSamples set to 10
2012-10-31 18:00:16: 0: INFO: +photonMap_convexHullEstimate set to false
2012-10-31 18:00:16: 0: INFO: +photonMap_storeDirectLight set to true
2012-10-31 18:00:16: 0: INFO: +photonMap_retraceCorners set to 0.0
2012-10-31 18:00:16: 0: INFO: +photonMap_retraceBounces set to 10
2012-10-31 18:00:16: 0: INFO: +photonMap_dontDelete set to true
2012-10-31 18:00:16: 0: INFO: +photonMap_autoSave set to false
2012-10-31 18:00:16: 0: INFO: +photonMap_switchToSavedMap set to false
2012-10-31 18:00:16: 0: INFO: +lightcache_subdivs set to 1000
2012-10-31 18:00:16: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:16: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:16: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:16: 0: INFO: +lightcache_sampleSize set to 0.02
2012-10-31 18:00:16: 0: INFO: +lightcache_filter_type set to 1
2012-10-31 18:00:16: 0: INFO: +lightcache_filter_size set to 0.04
2012-10-31 18:00:16: 0: INFO: +lightcache_bounces set to 100
2012-10-31 18:00:16: 0: INFO: +lightcache_showCalcPhase set to 1
2012-10-31 18:00:16: 0: INFO: +lightcache_storeDirectLight set to 1
2012-10-31 18:00:16: 0: INFO: +lightcache_scale set to 0
2012-10-31 18:00:16: 0: INFO: +lightcache_mode set to 0
2012-10-31 18:00:16: 0: INFO: +lightcache_interpSamples set to 10
2012-10-31 18:00:16: 0: INFO: +lightcache_prefilter_on set to false
2012-10-31 18:00:16: 0: INFO: +lightcache_prefilter_samples set to 10
2012-10-31 18:00:16: 0: INFO: +lightcache_dontDelete set to true
2012-10-31 18:00:16: 0: INFO: +lightcache_autoSave set to false
2012-10-31 18:00:16: 0: INFO: +lightcache_switchToSavedMap set to false
2012-10-31 18:00:16: 0: INFO: +lightcache_useForGlossyRays set to false
2012-10-31 18:00:16: 0: INFO: +lightcache_numPasses set to 8
2012-10-31 18:00:16: 0: INFO: +caustics_on set to false
2012-10-31 18:00:16: 0: INFO: +caustics_multiplier set to 1.0
2012-10-31 18:00:16: 0: INFO: +caustics_searchDist set to 5.0
2012-10-31 18:00:16: 0: INFO: +caustics_maxPhotons set to 60
2012-10-31 18:00:16: 0: INFO: +caustics_maxDensity set to 0.0
2012-10-31 18:00:16: 0: INFO: +caustics_dontDelete set to true
2012-10-31 18:00:16: 0: INFO: +casutics_autoSave set to false
2012-10-31 18:00:16: 0: INFO: +caustics_switchToSavedMap set to false
2012-10-31 18:00:16: 0: INFO: +environment_gi_on set to false
2012-10-31 18:00:16: 0: INFO: +environment_gi_color set to (color 204 229.5 255)
2012-10-31 18:00:16: 0: INFO: +environment_gi_color_multiplier set to 1.0
2012-10-31 18:00:16: 0: INFO: +environment_gi_map_on set to true
2012-10-31 18:00:16: 0: INFO: +environment_rr_on set to false
2012-10-31 18:00:16: 0: INFO: +environment_rr_color set to (color 0 0 0)
2012-10-31 18:00:16: 0: INFO: +environment_rr_color_multiplier set to 1.0
2012-10-31 18:00:16: 0: INFO: +environment_rr_map_on set to true
2012-10-31 18:00:16: 0: INFO: +colorMapping_type set to 0
2012-10-31 18:00:16: 0: INFO: +colorMapping_darkMult set to 1.0
2012-10-31 18:00:16: 0: INFO: +colorMapping_brightMult set to 1.0
2012-10-31 18:00:16: 0: INFO: +colorMapping_affectBackground set to true
2012-10-31 18:00:16: 0: INFO: +colorMapping_clampOutput set to false
2012-10-31 18:00:16: 0: INFO: +camera_type set to 0
2012-10-31 18:00:16: 0: INFO: +camera_overrideFOV set to false
2012-10-31 18:00:16: 0: INFO: +camera_fov set to 45.0
2012-10-31 18:00:16: 0: INFO: +camera_cyl_height set to 400.0
2012-10-31 18:00:16: 0: INFO: +camera_fish_autoDistance set to true
2012-10-31 18:00:16: 0: INFO: +camera_fish_distance set to 2.0
2012-10-31 18:00:16: 0: INFO: +camera_fish_curve set to 1.0
2012-10-31 18:00:16: 0: INFO: +dof_on set to false
2012-10-31 18:00:16: 0: INFO: +dof_shutter set to 5.0
2012-10-31 18:00:16: 0: INFO: +dof_bias set to 0.0
2012-10-31 18:00:16: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:16: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:16: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:16: 0: INFO: +dof_distance set to 200.0
2012-10-31 18:00:16: 0: INFO: +dof_getFromCamera set to false
2012-10-31 18:00:16: 0: INFO: +dof_sides_on set to false
2012-10-31 18:00:16: 0: INFO: +dof_sides_num set to 5
2012-10-31 18:00:16: 0: INFO: +dof_sides_rotation set to 0.0
2012-10-31 18:00:16: 0: INFO: +dof_anisotropy set to 0.0
2012-10-31 18:00:16: 0: INFO: +dof_subdivs set to 6
2012-10-31 18:00:17: 0: INFO: +moblur_on set to false
2012-10-31 18:00:17: 0: INFO: +moblur_duration set to 1.0
2012-10-31 18:00:17: 0: INFO: +moblur_intervalCenter set to 0.5
2012-10-31 18:00:17: 0: INFO: +moblur_bias set to 0.0
2012-10-31 18:00:17: 0: INFO: +moblur_prepassSamples set to 1
2012-10-31 18:00:17: 0: INFO: +moblur_geometryParticles set to false
2012-10-31 18:00:17: 0: INFO: +moblur_geomSamples set to 2
2012-10-31 18:00:17: 0: INFO: +dmc_earlyTermination_amount set to 0.85
2012-10-31 18:00:17: 0: INFO: +dmc_earlyTermination_threshold set to 0.005
2012-10-31 18:00:17: 0: INFO: +dmc_timeDependent set to true
2012-10-31 18:00:17: 0: INFO: +dmc_earlyTermination_minSamples set to 8
2012-10-31 18:00:17: 0: INFO: +dmc_subdivs_mult set to 1.0
2012-10-31 18:00:17: 0: INFO: +displacement_overrideMax set to true
2012-10-31 18:00:17: 0: INFO: +displacement_edgeLength set to 4.0
2012-10-31 18:00:17: 0: INFO: +displacement_viewDependent set to true
2012-10-31 18:00:17: 0: INFO: +displacement_maxSubdivs set to 256
2012-10-31 18:00:17: 0: INFO: +displacement_tightBounds set to true
2012-10-31 18:00:17: 0: INFO: +displacement_amount set to 1.0
2012-10-31 18:00:17: 0: INFO: +displacement_relative set to true
2012-10-31 18:00:17: 0: INFO: +system_raycaster_maxLevels set to 80
2012-10-31 18:00:17: 0: INFO: +system_raycaster_minLeafSize set to 0.0
2012-10-31 18:00:17: 0: INFO: +system_raycaster_faceLevelCoeff set to 1.0
2012-10-31 18:00:17: 0: INFO: +system_region_x set to 64
2012-10-31 18:00:17: 0: INFO: +system_region_y set to 64
2012-10-31 18:00:17: 0: INFO: +system_region_meaning set to 0
2012-10-31 18:00:17: 0: INFO: +system_region_sequence set to 4
2012-10-31 18:00:17: 0: INFO: +system_region_sequence_reverse set to 0
2012-10-31 18:00:17: 0: INFO: +system_previousRender set to 0
2012-10-31 18:00:17: 0: INFO: +system_frameStamp_on set to false
2012-10-31 18:00:17: 0: INFO: +system_frameStamp_string set to V-Ray %vrayversion | file: %filename | frame: %frame | primitives: %primitives | render time: %rendertime
2012-10-31 18:00:17: 0: INFO: +system_frameStamp_fullWidth set to true
2012-10-31 18:00:17: 0: INFO: +system_frameStamp_justify set to 0
2012-10-31 18:00:17: 0: INFO: +system_workInCameraSpace set to true
2012-10-31 18:00:17: 0: INFO: +system_instancedObjects set to 2
2012-10-31 18:00:17: 0: INFO: +system_checkForMissingFiles set to false
2012-10-31 18:00:17: 0: INFO: +system_optimizedAtmospherics set to false
2012-10-31 18:00:17: 0: INFO: +system_lowThreadPriority set to false
2012-10-31 18:00:17: 0: INFO: +system_vrayLog_show set to true
2012-10-31 18:00:17: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:17: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:17: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:17: 0: INFO: +system_vrayLog_level set to 3
2012-10-31 18:00:17: 0: INFO: +system_raycaster_memLimit set to 400
2012-10-31 18:00:17: 0: INFO: +system_vrayLog_file set to %TEMP%\VRayLog.txt
2012-10-31 18:00:17: 0: INFO: +output_on set to false
2012-10-31 18:00:17: 0: INFO: +output_useram set to true
2012-10-31 18:00:17: 0: INFO: +output_getsetsfrommax set to true
2012-10-31 18:00:17: 0: INFO: +output_width set to 640
2012-10-31 18:00:17: 0: INFO: +output_height set to 480
2012-10-31 18:00:17: 0: INFO: +output_aspect set to 1.0
2012-10-31 18:00:17: 0: INFO: +output_saveRawFile set to false
2012-10-31 18:00:17: 0: INFO: +output_rawFileName set to undefined
2012-10-31 18:00:17: 0: INFO: +output_genpreview set to false
2012-10-31 18:00:17: 0: INFO: +output_splitgbuffer set to false
2012-10-31 18:00:17: 0: INFO: +output_splitfilename set to undefined
2012-10-31 18:00:17: 0: INFO: +output_splitRGB set to true
2012-10-31 18:00:17: 0: INFO: +output_splitAlpha set to true
2012-10-31 18:00:17: 0: INFO: +Image Sampler set to Adaptive QMC
2012-10-31 18:00:17: 0: INFO: +Primary Bounces GI Engine set to Irradiance Map
2012-10-31 18:00:17: 0: INFO: +Primary Secondary GI Engine set to Light Cache
2012-10-31 18:00:17: 0: INFO: +Adv.Irradiance Map Interpolation Type set to Least squares fit (good/smooth)
2012-10-31 18:00:17: 0: INFO: +Adv.Irradiance Map Sample Lookup set to Density-based (best)
2012-10-31 18:00:17: 0: INFO: +Region Sequence set to Triangulation
2012-10-31 18:00:17: 0: INFO: +Frame Stamp Justify set to Left
2012-10-31 18:00:17: 0: INFO: >Performing XREF workaround…
2012-10-31 18:00:17: 0: INFO: >Scanning Renderer Paths…
2012-10-31 18:00:17: 0: INFO: >Done Scanning Renderer Paths.
2012-10-31 18:00:17: 0: DEBUG: StartJob: returning
2012-10-31 18:00:17: 0: Plugin rendering frame(s): 1
2012-10-31 18:00:17: 0: DEBUG: RenderTasks: called
2012-10-31 18:00:17: 0: DEBUG: RenderTasks: rendering frames 1 to 1
2012-10-31 18:00:17: 0: INFO: Render Tasks called
2012-10-31 18:00:18: 0: INFO: STARTED
2012-10-31 18:00:18: 0: DEBUG: PopupHandler.CheckForPopups: Getting popup handles
2012-10-31 18:00:18: 0: DEBUG: PopupHandler.CheckForPopups: Got 0 handles
2012-10-31 18:00:18: 0: DEBUG: PopupHandler.CheckForPopups: Returning
2012-10-31 18:00:18: 0: INFO: Lightning: Render frame 1
2012-10-31 18:00:18: 0: INFO: Lightning: Rendering frame W:\12058 ChangeItBack\Shots\TLN\0010\Renders\ANIM\A02.03\CIB_TLN_0010_Anim_A02.03.0001.exr
2012-10-31 18:00:18: 0: INFO: Lightning: Rendering 0 render elements
2012-10-31 18:00:18: 0: INFO: Lightning: Setting up render parameters
2012-10-31 18:00:18: 0: INFO: Lightning: Rendering camera node Camera001
2012-10-31 18:00:18: 0: INFO: Lightning: Checking multipass info for frame 1
2012-10-31 18:00:18: 0: INFO: Lightning: Opening renderer
2012-10-31 18:00:18: 0: INFO: ERROR: Traceback (most recent call last):
File “none”, line 72, in RenderTasks
File “none”, line 807, in RenderTasks
File “none”, line 1363, in RenderFrame
File “none”, line 1456, in PollUntilComplete
a: RenderTask: Unexpected exception (Failed to open the max renderer.
2012/10/31 18:00:13 INF: Loaded C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:13 ERR: Missing dll: Built-in - AnchorHelperObject
2012/10/31 18:00:14 WRN: Gamma Correction Settings are Being Changed
2012/10/31 18:00:14 WRN: The audio file could not be loaded because it could not be found or is in an invalid format.
2012/10/31 18:00:14 INF: Job: C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:14 INF: SYSTEM: Production renderer is changed to V-Ray Adv 2.10.01. Previous messages are cleared.
2012/10/31 18:00:14 WRN: MAXScript Callback script Exception: – Unknown system exception
2012/10/31 18:00:17 ERR: [V-Ray] UNHANDLED EXCEPTION: Sending RenderBegin() to scene Last marker is at , line 0:
)
at Deadline.Plugins.ScriptPlugin.FailRender(String message)

2012-10-31 18:00:19: 0: An exception occurred: Exception during render: An error occurred in RenderTasks(): RenderTask: Unexpected exception (Failed to open the max renderer.
2012/10/31 18:00:13 INF: Loaded C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:13 ERR: Missing dll: Built-in - AnchorHelperObject
2012/10/31 18:00:14 WRN: Gamma Correction Settings are Being Changed
2012/10/31 18:00:14 WRN: The audio file could not be loaded because it could not be found or is in an invalid format.
2012/10/31 18:00:14 INF: Job: C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:14 INF: SYSTEM: Production renderer is changed to V-Ray Adv 2.10.01. Previous messages are cleared.
2012/10/31 18:00:14 WRN: MAXScript Callback script Exception: – Unknown system exception
2012/10/31 18:00:17 ERR: [V-Ray] UNHANDLED EXCEPTION: Sending RenderBegin() to scene Last marker is at , line 0:
)
at Deadline.Plugins.ScriptPlugin.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage) (Deadline.Plugins.RenderPluginException)
2012-10-31 18:00:19: 0: Unloading plugin: 3dsmax
2012-10-31 18:00:19: Scheduler Thread - Render Thread 0 threw an error:
2012-10-31 18:00:19: Scheduler Thread - Exception during render: An error occurred in RenderTasks(): RenderTask: Unexpected exception (Failed to open the max renderer.
2012/10/31 18:00:13 INF: Loaded C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:13 ERR: Missing dll: Built-in - AnchorHelperObject
2012/10/31 18:00:14 WRN: Gamma Correction Settings are Being Changed
2012/10/31 18:00:14 WRN: The audio file could not be loaded because it could not be found or is in an invalid format.
2012/10/31 18:00:14 INF: Job: C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:14 INF: SYSTEM: Production renderer is changed to V-Ray Adv 2.10.01. Previous messages are cleared.
2012/10/31 18:00:14 WRN: MAXScript Callback script Exception: – Unknown system exception
2012/10/31 18:00:17 ERR: [V-Ray] UNHANDLED EXCEPTION: Sending RenderBegin() to scene Last marker is at , line 0:
)
at Deadline.Plugins.ScriptPlugin.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage)
2012-10-31 18:00:20: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2012-10-31 18:00:20:
Exception Details
RenderPluginException – Exception during render: An error occurred in RenderTasks(): RenderTask: Unexpected exception (Failed to open the max renderer.
2012/10/31 18:00:13 INF: Loaded C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:13 ERR: Missing dll: Built-in - AnchorHelperObject
2012/10/31 18:00:14 WRN: Gamma Correction Settings are Being Changed
2012/10/31 18:00:14 WRN: The audio file could not be loaded because it could not be found or is in an invalid format.
2012/10/31 18:00:14 INF: Job: C:/Users/renderadmin/AppData/Local/Thinkbox/Deadline6/slave/RENDER-02/jobsData/CIB_TLN_0010_Anim_A02.03.max
2012/10/31 18:00:14 INF: SYSTEM: Production renderer is changed to V-Ray Adv 2.10.01. Previous messages are cleared.
2012/10/31 18:00:14 WRN: MAXScript Callback script Exception: – Unknown system exception
2012/10/31 18:00:17 ERR: [V-Ray] UNHANDLED EXCEPTION: Sending RenderBegin() to scene Last marker is at , line 0:
)
at Deadline.Plugins.ScriptPlugin.RenderTasks(String taskId, Int32 startFrame, Int32 endFrame, String& outMessage)
RenderPluginException.Cause: JobError (2)
RenderPluginException.HasSlaveLog: True
Exception.Data: ( )
Exception.TargetSite: Void RenderTask(System.String, Int32, Int32)
Exception.Source: deadline
Exception.StackTrace:
at Deadline.Plugins.Plugin.RenderTask(String taskId, Int32 startFrame, Int32 endFrame)
at Deadline.Slaves.SlaveRenderThread.a(TaskLogWriter A_0)

2012-10-31 18:00:20: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2012-10-31 18:00:20: Starting between task wait for available threads - seconds: 2
2012-10-31 18:00:22: Scheduler - The 5091bc2b5d99e50f0088d44b limit is disabled.
2012-10-31 18:00:22: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-10-31 18:00:23: 0: Got task: 1_1-1
2012-10-31 18:00:23: Constructor: 3dsmax
2012-10-31 18:00:23: 0: Loaded plugin: 3dsmax
2012-10-31 18:00:23: 0: Task timeout is disabled.
2012-10-31 18:00:23: 0: Loaded job: CIB_TLN_0010_Anim_A02.03 (5091bc2b5d99e50f0088d44b)
2012-10-31 18:00:23: 0: Successfully mapped W: to \sfs-file\working
2012-10-31 18:00:23: 0: Successfully mapped T: to \sfs-file\tools
2012-10-31 18:00:23: 0: Successfully mapped O: to \nas\nas\offline
2012-10-31 18:00:23: 0: Successfully mapped R: to \nas\nas\archive
2012-10-31 18:00:23: 0: Successfully mapped G: to \DEADALUS02\raid
2012-10-31 18:00:23: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-10-31 18:00:23: 0: DEBUG: CanRenderOnThisMachine: loaded plugin config file C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-02\plugins\3dsmax.dlinit
2012-10-31 18:00:23: 0: DEBUG: StartJob: debug logging enabled
2012-10-31 18:11:42: Thermal Shutdown: Skipping zone “rendernodes” because it is disabled
2012-10-31 18:16:23: Listener Thread - fe80::6c8c:3a06:42f1:2ebf%12 has connected
2012-10-31 18:16:24: Listener Thread - Received message: StopSlave
2012-10-31 18:16:24: Listener Thread - Responded with: Success
2012-10-31 18:16:24: Slave - slave shutdown: normal
2012-10-31 18:16:24: Listener Thread - OnConnect: Listener Socket has been closed.
2012-10-31 18:16:24: Info Thread - requesting slave info thread quit.
2012-10-31 18:16:24: sending cancel task command to plugin
2012-10-31 18:16:24: sending cancel task command to plugin
2012-10-31 18:16:24: 0: Shutdown
2012-10-31 18:16:24: Info Thread - shutdown complete
2012-10-31 18:16:24: sending cancel task command to plugin
2012-10-31 18:16:24: 0: Shutdown
2012-10-31 18:16:24: sending cancel task command to plugin
2012-10-31 18:16:24: 0: Shutdown
2012-10-31 18:16:25: sending cancel task command to plugin
2012-10-31 18:16:25: 0: Shutdown
2012-10-31 18:16:25: sending cancel task command to plugin
2012-10-31 18:16:25: 0: Shutdown
2012-10-31 18:16:25: sending cancel task command to plugin
2012-10-31 18:16:25: 0: Shutdown
2012-10-31 18:16:25: sending cancel task command to plugin
2012-10-31 18:16:25: 0: Shutdown
2012-10-31 18:16:26: sending cancel task command to plugin
2012-10-31 18:16:26: 0: Shutdown
2012-10-31 18:16:26: sending cancel task command to plugin
2012-10-31 18:16:26: 0: Shutdown
2012-10-31 18:16:26: sending cancel task command to plugin
2012-10-31 18:16:26: 0: Shutdown
2012-10-31 18:16:26: sending cancel task command to plugin
2012-10-31 18:16:26: 0: Shutdown
2012-10-31 18:16:27: sending cancel task command to plugin
2012-10-31 18:16:27: 0: Shutdown
2012-10-31 18:16:27: sending cancel task command to plugin
2012-10-31 18:16:27: 0: Shutdown
2012-10-31 18:16:27: sending cancel task command to plugin
2012-10-31 18:16:27: 0: Shutdown
2012-10-31 18:16:27: sending cancel task command to plugin
2012-10-31 18:16:27: 0: Shutdown
2012-10-31 18:16:28: sending cancel task command to plugin
2012-10-31 18:16:28: 0: Shutdown
2012-10-31 18:16:28: sending cancel task command to plugin
2012-10-31 18:16:28: 0: Shutdown
2012-10-31 18:16:28: sending cancel task command to plugin
2012-10-31 18:16:28: 0: Shutdown
2012-10-31 18:16:28: sending cancel task command to plugin
2012-10-31 18:16:28: 0: Shutdown
2012-10-31 18:16:29: sending cancel task command to plugin
2012-10-31 18:16:29: 0: Shutdown
2012-10-31 18:16:29: sending cancel task command to plugin
2012-10-31 18:16:29: 0: Shutdown
2012-10-31 18:16:29: sending cancel task command to plugin
2012-10-31 18:16:29: 0: Shutdown
2012-10-31 18:16:29: sending cancel task command to plugin
2012-10-31 18:16:29: 0: Shutdown
2012-10-31 18:16:30: sending cancel task command to plugin
2012-10-31 18:16:30: 0: Shutdown
2012-10-31 18:16:30: sending cancel task command to plugin
2012-10-31 18:16:30: 0: Shutdown
2012-10-31 18:16:30: sending cancel task command to plugin
2012-10-31 18:16:30: 0: Shutdown
2012-10-31 18:16:30: sending cancel task command to plugin
2012-10-31 18:16:30: 0: Shutdown
2012-10-31 18:16:31: sending cancel task command to plugin
2012-10-31 18:16:31: 0: Shutdown
2012-10-31 18:16:31: sending cancel task command to plugin
2012-10-31 18:16:31: 0: Shutdown
2012-10-31 18:16:31: sending cancel task command to plugin
2012-10-31 18:16:31: 0: Shutdown
2012-10-31 18:16:31: sending cancel task command to plugin
2012-10-31 18:16:31: 0: Shutdown
2012-10-31 18:16:32: sending cancel task command to plugin
2012-10-31 18:16:32: 0: Shutdown
2012-10-31 18:16:32: sending cancel task command to plugin
2012-10-31 18:16:32: 0: Shutdown
2012-10-31 18:16:32: sending cancel task command to plugin
2012-10-31 18:16:32: 0: Shutdown
2012-10-31 18:16:32: sending cancel task command to plugin
2012-10-31 18:16:32: 0: Shutdown
2012-10-31 18:16:33: sending cancel task command to plugin
2012-10-31 18:16:33: 0: Shutdown
2012-10-31 18:16:33: sending cancel task command to plugin
2012-10-31 18:16:33: 0: Shutdown
2012-10-31 18:16:33: sending cancel task command to plugin
2012-10-31 18:16:33: 0: Shutdown
2012-10-31 18:16:33: sending cancel task command to plugin
2012-10-31 18:16:33: 0: Shutdown
2012-10-31 18:16:34: sending cancel task command to plugin
2012-10-31 18:16:34: 0: Shutdown
2012-10-31 18:16:34: sending cancel task command to plugin
2012-10-31 18:16:34: 0: Shutdown
2012-10-31 18:16:34: sending cancel task command to plugin
2012-10-31 18:16:34: 0: Shutdown
2012-10-31 18:16:34: sending cancel task command to plugin
2012-10-31 18:16:34: 0: Shutdown
2012-10-31 18:16:35: sending cancel task command to plugin
2012-10-31 18:16:35: 0: Shutdown
2012-10-31 18:16:35: sending cancel task command to plugin
2012-10-31 18:16:35: 0: Shutdown
2012-10-31 18:16:35: sending cancel task command to plugin
2012-10-31 18:16:35: 0: Shutdown
2012-10-31 18:16:35: sending cancel task command to plugin
2012-10-31 18:16:35: 0: Shutdown
2012-10-31 18:16:36: sending cancel task command to plugin
2012-10-31 18:16:36: 0: Shutdown
2012-10-31 18:16:36: sending cancel task command to plugin
2012-10-31 18:16:36: 0: Shutdown
2012-10-31 18:16:36: sending cancel task command to plugin
2012-10-31 18:16:36: 0: Shutdown
2012-10-31 18:16:36: sending cancel task command to plugin
2012-10-31 18:16:36: 0: Shutdown
2012-10-31 18:16:37: sending cancel task command to plugin
2012-10-31 18:16:37: 0: Shutdown
2012-10-31 18:16:37: sending cancel task command to plugin
2012-10-31 18:16:37: 0: Shutdown
2012-10-31 18:16:37: sending cancel task command to plugin
2012-10-31 18:16:37: 0: Shutdown
2012-10-31 18:16:37: sending cancel task command to plugin
2012-10-31 18:16:37: 0: Shutdown
2012-10-31 18:16:38: sending cancel task command to plugin
2012-10-31 18:16:38: 0: Shutdown
2012-10-31 18:16:38: sending cancel task command to plugin
2012-10-31 18:16:38: 0: Shutdown
2012-10-31 18:16:38: sending cancel task command to plugin
2012-10-31 18:16:38: 0: Shutdown
2012-10-31 18:16:38: sending cancel task command to plugin
2012-10-31 18:16:38: 0: Shutdown
2012-10-31 18:16:39: sending cancel task command to plugin
2012-10-31 18:16:39: 0: Shutdown
2012-10-31 18:16:39: sending cancel task command to plugin
2012-10-31 18:16:39: 0: Shutdown
2012-10-31 18:16:39: sending cancel task command to plugin
2012-10-31 18:16:39: 0: Shutdown
2012-10-31 18:16:39: sending cancel task command to plugin
2012-10-31 18:16:39: 0: Shutdown
2012-10-31 18:16:40: sending cancel task command to plugin
2012-10-31 18:16:40: 0: Shutdown
2012-10-31 18:16:40: sending cancel task command to plugin
2012-10-31 18:16:40: 0: Shutdown
2012-10-31 18:16:40: sending cancel task command to plugin
2012-10-31 18:16:40: 0: Shutdown
2012-10-31 18:16:40: sending cancel task command to plugin
2012-10-31 18:16:40: 0: Shutdown
2012-10-31 18:16:41: sending cancel task command to plugin
2012-10-31 18:16:41: 0: Shutdown
2012-10-31 18:16:41: sending cancel task command to plugin
2012-10-31 18:16:41: 0: Shutdown
2012-10-31 18:16:41: sending cancel task command to plugin
2012-10-31 18:16:41: 0: Shutdown
2012-10-31 18:16:41: sending cancel task command to plugin
2012-10-31 18:16:41: 0: Shutdown
2012-10-31 18:16:42: sending cancel task command to plugin
2012-10-31 18:16:42: 0: Shutdown
2012-10-31 18:16:42: sending cancel task command to plugin
2012-10-31 18:16:42: 0: Shutdown
2012-10-31 18:16:42: sending cancel task command to plugin
2012-10-31 18:16:42: 0: Shutdown
2012-10-31 18:16:42: sending cancel task command to plugin
2012-10-31 18:16:42: 0: Shutdown
2012-10-31 18:16:43: sending cancel task command to plugin
2012-10-31 18:16:43: 0: Shutdown
2012-10-31 18:16:43: sending cancel task command to plugin
2012-10-31 18:16:43: 0: Shutdown
2012-10-31 18:16:43: sending cancel task command to plugin
2012-10-31 18:16:43: 0: Shutdown
2012-10-31 18:16:43: sending cancel task command to plugin
2012-10-31 18:16:43: 0: Shutdown
2012-10-31 18:16:44: sending cancel task command to plugin
2012-10-31 18:16:44: 0: Shutdown
2012-10-31 18:16:44: sending cancel task command to plugin
2012-10-31 18:16:44: 0: Shutdown
2012-10-31 18:16:44: sending cancel task command to plugin
2012-10-31 18:16:44: 0: Shutdown
2012-10-31 18:16:44: sending cancel task command to plugin
2012-10-31 18:16:44: 0: Shutdown
2012-10-31 18:16:45: sending cancel task command to plugin
2012-10-31 18:16:45: 0: Shutdown
2012-10-31 18:16:45: sending cancel task command to plugin
2012-10-31 18:16:45: 0: Shutdown
2012-10-31 18:16:45: sending cancel task command to plugin
2012-10-31 18:16:45: 0: Shutdown
2012-10-31 18:16:45: sending cancel task command to plugin
2012-10-31 18:16:45: 0: Shutdown
2012-10-31 18:16:46: sending cancel task command to plugin
2012-10-31 18:16:46: 0: Shutdown
2012-10-31 18:16:46: sending cancel task command to plugin
2012-10-31 18:16:46: 0: Shutdown
2012-10-31 18:16:46: sending cancel task command to plugin
2012-10-31 18:16:46: 0: Shutdown
2012-10-31 18:16:46: sending cancel task command to plugin
2012-10-31 18:16:46: 0: Shutdown
2012-10-31 18:16:47: sending cancel task command to plugin
2012-10-31 18:16:47: 0: Shutdown
2012-10-31 18:16:47: sending cancel task command to plugin
2012-10-31 18:16:47: 0: Shutdown
2012-10-31 18:16:47: sending cancel task command to plugin
2012-10-31 18:16:47: 0: Shutdown
2012-10-31 18:16:47: sending cancel task command to plugin
2012-10-31 18:16:47: 0: Shutdown
2012-10-31 18:16:48: sending cancel task command to plugin
2012-10-31 18:16:48: 0: Shutdown
2012-10-31 18:16:48: sending cancel task command to plugin
2012-10-31 18:16:48: 0: Shutdown
2012-10-31 18:16:48: sending cancel task command to plugin
2012-10-31 18:16:48: 0: Shutdown
2012-10-31 18:16:48: sending cancel task command to plugin
2012-10-31 18:16:48: 0: Shutdown
2012-10-31 18:16:49: sending cancel task command to plugin
2012-10-31 18:16:49: 0: Shutdown
2012-10-31 18:16:49: sending cancel task command to plugin
2012-10-31 18:16:49: 0: Shutdown
2012-10-31 18:16:49: sending cancel task command to plugin
2012-10-31 18:16:49: 0: Shutdown
2012-10-31 18:16:49: sending cancel task command to plugin
2012-10-31 18:16:49: 0: Shutdown
2012-10-31 18:16:50: sending cancel task command to plugin
2012-10-31 18:16:50: 0: Shutdown
2012-10-31 18:16:50: sending cancel task command to plugin
2012-10-31 18:16:50: 0: Shutdown
2012-10-31 18:16:50: sending cancel task command to plugin
2012-10-31 18:16:50: 0: Shutdown
2012-10-31 18:16:50: sending cancel task command to plugin
2012-10-31 18:16:50: 0: Shutdown
2012-10-31 18:16:51: sending cancel task command to plugin
2012-10-31 18:16:51: 0: Shutdown
2012-10-31 18:16:51: sending cancel task command to plugin
2012-10-31 18:16:51: 0: Shutdown
2012-10-31 18:16:51: sending cancel task command to plugin
2012-10-31 18:16:51: 0: Shutdown
2012-10-31 18:16:51: sending cancel task command to plugin
2012-10-31 18:16:51: 0: Shutdown
2012-10-31 18:16:52: sending cancel task command to plugin
2012-10-31 18:16:52: 0: Shutdown
2012-10-31 18:16:52: sending cancel task command to plugin
2012-10-31 18:16:52: 0: Shutdown
2012-10-31 18:16:52: sending cancel task command to plugin
2012-10-31 18:16:52: 0: Shutdown
2012-10-31 18:16:52: sending cancel task command to plugin
2012-10-31 18:16:52: 0: Shutdown
2012-10-31 18:16:53: sending cancel task command to plugin
2012-10-31 18:16:53: 0: Shutdown
2012-10-31 18:16:53: sending cancel task command to plugin
2012-10-31 18:16:53: 0: Shutdown
2012-10-31 18:16:53: sending cancel task command to plugin
2012-10-31 18:16:53: 0: Shutdown
2012-10-31 18:16:53: sending cancel task command to plugin
2012-10-31 18:16:53: 0: Shutdown
2012-10-31 18:16:54: sending cancel task command to plugin
2012-10-31 18:16:54: 0: Shutdown
2012-10-31 18:16:54: sending cancel task command to plugin
2012-10-31 18:16:54: 0: Shutdown
2012-10-31 18:16:54: sending cancel task command to plugin
2012-10-31 18:16:54: 0: Shutdown
2012-10-31 18:16:54: sending cancel task command to plugin
2012-10-31 18:16:54: 0: Shutdown
2012-10-31 18:16:55: sending cancel task command to plugin
2012-10-31 18:16:55: 0: Shutdown
2012-10-31 18:16:55: sending cancel task command to plugin
2012-10-31 18:16:55: 0: Shutdown
2012-10-31 18:16:55: sending cancel task command to plugin
2012-10-31 18:16:55: 0: Shutdown
2012-10-31 18:16:55: sending cancel task command to plugin
2012-10-31 18:16:55: 0: Shutdown
2012-10-31 18:16:56: sending cancel task command to plugin
2012-10-31 18:16:56: 0: Shutdown
2012-10-31 18:16:56: sending cancel task command to plugin
2012-10-31 18:16:56: 0: Shutdown
2012-10-31 18:16:56: sending cancel task command to plugin
2012-10-31 18:16:56: 0: Shutdown
2012-10-31 18:16:56: sending cancel task command to plugin
2012-10-31 18:16:56: 0: Shutdown
2012-10-31 18:16:57: sending cancel task command to plugin
2012-10-31 18:16:57: 0: Shutdown
2012-10-31 18:16:57: sending cancel task command to plugin
2012-10-31 18:16:57: 0: Shutdown
2012-10-31 18:16:57: sending cancel task command to plugin
2012-10-31 18:16:57: 0: Shutdown
2012-10-31 18:16:57: sending cancel task command to plugin
2012-10-31 18:16:57: 0: Shutdown
2012-10-31 18:16:58: sending cancel task command to plugin
2012-10-31 18:16:58: 0: Shutdown
2012-10-31 18:16:58: sending cancel task command to plugin
2012-10-31 18:16:58: 0: Shutdown
2012-10-31 18:16:58: sending cancel task command to plugin
2012-10-31 18:16:58: 0: Shutdown
2012-10-31 18:16:58: sending cancel task command to plugin
2012-10-31 18:16:58: 0: Shutdown
2012-10-31 18:16:59: sending cancel task command to plugin
2012-10-31 18:16:59: 0: Shutdown
2012-10-31 18:16:59: sending cancel task command to plugin
2012-10-31 18:16:59: 0: Shutdown
2012-10-31 18:16:59: sending cancel task command to plugin
2012-10-31 18:16:59: 0: Shutdown
2012-10-31 18:16:59: sending cancel task command to plugin
2012-10-31 18:16:59: 0: Shutdown
2012-10-31 18:17:00: sending cancel task command to plugin
2012-10-31 18:17:00: 0: Shutdown
2012-10-31 18:17:00: sending cancel task command to plugin
2012-10-31 18:17:00: 0: Shutdown
2012-10-31 18:17:00: sending cancel task command to plugin
2012-10-31 18:17:00: 0: Shutdown
2012-10-31 18:17:00: sending cancel task command to plugin
2012-10-31 18:17:00: 0: Shutdown
2012-10-31 18:17:01: sending cancel task command to plugin
2012-10-31 18:17:01: 0: Shutdown
2012-10-31 18:17:01: sending cancel task command to plugin
2012-10-31 18:17:01: 0: Shutdown
[/code]

rrussell · November 2, 2012, 6:04pm

Hmm, there seems to be an issue stopping the slave. This is probably related to the remote control problems you mentioned in another thread.

To view errors, you can just spawn a new Job Reports panel from the View menu.
This will be fixed in beta 5.

Do these max errors continue to occur after restarting the slave? The errors look like they are coming from Max, and Deadline is just the messenger, but if the errors go away after restarting the slave, then it could be that Deadline is screwing something up.

im_thatoneguy · November 2, 2012, 6:05pm

After closing/restarting a slave manually it continues to render fine. (Even the same frame)

rrussell · November 2, 2012, 7:14pm

Cool, thanks for confirming this. We have also seen cases here were the slave enters an unstable state, and we’re in the process of tracking this down. There is a good chance what you’re seeing is related to the problem we’re seeing.

im_thatoneguy · November 9, 2012, 1:22am

[code]012-11-08 17:18:16: Scheduler Thread - Successfully mapped W: to \sfs-file\working
2012-11-08 17:18:16: Scheduler Thread - Successfully mapped T: to \sfs-file\tools
2012-11-08 17:18:16: Scheduler Thread - Successfully mapped O: to \nas\nas\offline
2012-11-08 17:18:17: Scheduler Thread - Successfully mapped R: to \nas\nas\archive
2012-11-08 17:18:18: Scheduler Thread - Error mapping G: to \DEADALUS02\raid: No more connections can be made to this remote computer at this time because there are already as many connections as the computer can accept.

2012-11-08 17:18:19: Scheduler Thread - Successfully mapped M: to \sfs-file\maps
2012-11-08 17:18:19: Scheduler Thread - Synchronizing job files
2012-11-08 17:18:19: Scheduler Thread - Synchronization time for job files: 31.2 ms
2012-11-08 17:18:19: Scheduler Thread - Synchronizing plugin files
2012-11-08 17:18:19: Scheduler Thread - Synchronization time for plugin files: 265.197 ms
2012-11-08 17:18:20: 0: Got task: 7_207-207
2012-11-08 17:18:20: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified
2012-11-08 17:18:20: Constructor: 3dsmax
2012-11-08 17:18:20: 0: Loaded plugin: 3dsmax
2012-11-08 17:18:20: 0: Task timeout is disabled.
2012-11-08 17:18:20: 0: Loaded job: CIB_TLN_0010_Anim_A02.04 (50980b405d99e510bc2b836f)
2012-11-08 17:18:20: 0: Successfully mapped W: to \sfs-file\working
2012-11-08 17:18:20: 0: Successfully mapped T: to \sfs-file\tools
2012-11-08 17:18:20: 0: Successfully mapped O: to \nas\nas\offline
2012-11-08 17:18:20: 0: Successfully mapped R: to \nas\nas\archive
2012-11-08 17:18:20: 0: Error mapping G: to \DEADALUS02\raid: No more connections can be made to this remote computer at this time because there are already as many connections as the computer can accept.

2012-11-08 17:18:20: 0: Successfully mapped M: to \sfs-file\maps
2012-11-08 17:18:20: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-11-08 17:18:21: 0: INFO: About: 3dsmax Plugin for Deadline
2012-11-08 17:18:21: 0: INFO: Start Job called - starting up 3dsmax plugin
2012-11-08 17:18:21: 0: INFO: Rendering with 3dsmax version: 2012
2012-11-08 17:18:21: 0: INFO: Build of 3dsmax to force: 64bit
2012-11-08 17:18:21: 0: INFO: Rendering with executable: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe
2012-11-08 17:18:21: 0: INFO: Checking registry for 3dsmax language code
2012-11-08 17:18:21: 0: INFO: Found language code: 409
2012-11-08 17:18:21: 0: INFO: Language code string: enu
2012-11-08 17:18:21: 0: INFO: Fail on existing 3dsmax process: 0
2012-11-08 17:18:21: 0: INFO: Load 3dsmax timeout: 1000 seconds
2012-11-08 17:18:21: 0: INFO: Start job timeout: 1000 seconds
2012-11-08 17:18:21: 0: INFO: Progress update timeout: 8000 seconds
2012-11-08 17:18:21: 0: INFO: Progress update timout disabled: 0
2012-11-08 17:18:21: 0: INFO: Slave mode enabled: 1
2012-11-08 17:18:21: 0: INFO: Silent mode enabled: 0
2012-11-08 17:18:21: 0: INFO: Local rendering enabled: 1
2012-11-08 17:18:21: 0: INFO: Running render sanity check using 3dsmaxcmd.exe
2012-11-08 17:18:22: 0: INFO: 3dsmaxcmd.exe returned: P11/8/2012 17:18:21 PM; Error opening scene file: “C:\Program Files\Autodesk\3ds Max 2012”
2012-11-08 17:18:22: 0: INFO: 3dsmax start up file: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-03\plugins\deadlineStartupMax2012.max
2012-11-08 17:18:22: 0: INFO: Using user profiles: 1
2012-11-08 17:18:22: 0: INFO: 3dsmax user profile path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu
2012-11-08 17:18:22: 0: INFO: 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-11-08 17:18:22: 0: INFO: 3dsmax ini file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\3dsmax.ini
2012-11-08 17:18:22: 0: INFO: Network log file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\Network\Max.log
2012-11-08 17:18:22: 0: INFO: Plugin ini file: C:\Program Files\Autodesk\3ds Max 2012\plugin.ini
2012-11-08 17:18:22: 0: INFO: Not including user profile plugin ini because it does not exist: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\Plugin.UserSettings.ini
2012-11-08 17:18:22: 0: INFO: Lightning connection plugin: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-03\plugins\lightning64Max2012.dlx
2012-11-08 17:18:22: 0: INFO: 3dsmax socket connection port: 49896
2012-11-08 17:18:22: 0: INFO: Creating startup script: C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms
2012-11-08 17:18:22: 0: INFO: Copying C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-03\plugins\lightning64Max2012.dlx to C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\temp\lightning\lightning.dlx
2012-11-08 17:18:22: 0: INFO: Copying dl.ini to 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-11-08 17:18:22: 0: INFO: If this fails, make sure that the necessary permissions are set on this folder to allow for this copy to take place
2012-11-08 17:18:22: 0: INFO: Starting monitored managed process 3dsmaxProcess
2012-11-08 17:18:22: 0: INFO: Stdout Handling Enabled: False
2012-11-08 17:18:22: 0: INFO: Popup Handling Enabled: True
2012-11-08 17:18:22: 0: INFO: Using Process Tree: True
2012-11-08 17:18:22: 0: INFO: Hiding DOS Window: False
2012-11-08 17:18:22: 0: INFO: Creating New Console: False
2012-11-08 17:18:22: 0: INFO: Render Executable: “C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe”
2012-11-08 17:18:22: 0: INFO: Render Argument: -p “dl.ini” -q -s “C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-03\plugins\deadlineStartupMax2012.max”
2012-11-08 17:18:22: 0: INFO: Startup Directory: “C:\Program Files\Autodesk\3ds Max 2012”
2012-11-08 17:18:22: 0: INFO: Process Priority: BelowNormal
2012-11-08 17:18:22: 0: INFO: Process Affinity: default
2012-11-08 17:18:22: 0: INFO: Process is now running
2012-11-08 17:18:22: 0: INFO: Waiting for connection from 3dsmax
2012-11-08 17:18:24: 0: STDOUT: Dark
2012-11-08 17:18:26: Scheduler Thread - Cancelling task because task “7_207-207” could not be found
2012-11-08 17:18:26: Scheduler Thread - The task has either been changed externally (and requeued), or the Job has been deleted.
2012-11-08 17:18:26: sending cancel task command to plugin
2012-11-08 17:18:26: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader
2012-11-08 17:18:26: 0: Unloading plugin: 3dsmax
2012-11-08 17:18:27: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2012-11-08 17:18:27: Starting between task wait for available threads - seconds: 4
2012-11-08 17:18:31: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-08 17:18:31: 0: Got task: 9_209-209
2012-11-08 17:18:31: Constructor: 3dsmax
2012-11-08 17:18:31: 0: Loaded plugin: 3dsmax
2012-11-08 17:18:32: 0: Task timeout is disabled.
2012-11-08 17:18:32: 0: Loaded job: CIB_TLN_0010_Anim_A02.04 (50980b405d99e510bc2b836f)
2012-11-08 17:18:32: 0: Successfully mapped W: to \sfs-file\working
2012-11-08 17:18:32: 0: Successfully mapped T: to \sfs-file\tools
2012-11-08 17:18:32: 0: Successfully mapped O: to \nas\nas\offline
2012-11-08 17:18:32: 0: Successfully mapped R: to \nas\nas\archive
2012-11-08 17:18:32: 0: Error mapping G: to \DEADALUS02\raid: No more connections can be made to this remote computer at this time because there are already as many connections as the computer can accept.

2012-11-08 17:18:32: 0: Successfully mapped M: to \sfs-file\maps
2012-11-08 17:18:32: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-11-08 17:19:40: Listener Thread - ::ffff:192.168.94.37 has connected
2012-11-08 17:19:40: Listener Thread - Received message: StreamLog
2012-11-08 17:19:40: Listener Thread - Responded with: Success[/code]

2012-11-08 17:18:08: Scheduler - Job chooser found no jobs. 2012-11-08 17:18:09: Starting between task wait - seconds: 2 2012-11-08 17:18:11: Scheduler Thread - Performing house cleaning... 2012-11-08 17:18:11: Scheduler - Job chooser found no jobs. 2012-11-08 17:18:12: Starting between task wait - seconds: 2 2012-11-08 17:18:14: Scheduler Thread - Performing house cleaning... 2012-11-08 17:18:14: Scheduler - Successfully dequeued 1 task(s). Returning. 2012-11-08 17:18:14: 2012-11-08 17:18:15: Scheduler Thread - Successfully mapped W: to \\sfs-file\working 2012-11-08 17:18:15: Scheduler Thread - Successfully mapped T: to \\sfs-file\tools 2012-11-08 17:18:15: Scheduler Thread - Successfully mapped O: to \\nas\nas\offline 2012-11-08 17:18:16: Scheduler Thread - Successfully mapped R: to \\nas\nas\archive 2012-11-08 17:18:16: Scheduler Thread - Successfully mapped G: to \\DEADALUS02\raid 2012-11-08 17:18:16: Scheduler Thread - Successfully mapped M: to \\sfs-file\maps 2012-11-08 17:18:17: Scheduler Thread - Synchronizing job files 2012-11-08 17:18:17: Scheduler Thread - Synchronization time for job files: 46.875 ms 2012-11-08 17:18:17: Scheduler Thread - Synchronizing plugin files 2012-11-08 17:18:17: Scheduler Thread - Synchronization time for plugin files: 359.373 ms 2012-11-08 17:18:17: 0: Got task: 3_203-203 2012-11-08 17:18:17: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified 2012-11-08 17:18:17: Constructor: 3dsmax 2012-11-08 17:18:17: 0: Loaded plugin: 3dsmax 2012-11-08 17:18:18: 0: Task timeout is disabled. 2012-11-08 17:18:18: 0: Loaded job: CIB_TLN_0010_Anim_A02.04 (50980b405d99e510bc2b836f) 2012-11-08 17:18:18: 0: Successfully mapped W: to \\sfs-file\working 2012-11-08 17:18:18: 0: Successfully mapped T: to \\sfs-file\tools 2012-11-08 17:18:18: 0: Successfully mapped O: to \\nas\nas\offline 2012-11-08 17:18:18: 0: Successfully mapped R: to \\nas\nas\archive 2012-11-08 17:18:18: 0: Successfully mapped G: to \\DEADALUS02\raid 2012-11-08 17:18:18: 0: Successfully mapped M: to \\sfs-file\maps 2012-11-08 17:18:18: 0: INFO: StartJob: initializing script plugin 3dsmax 2012-11-08 17:18:19: 0: INFO: About: 3dsmax Plugin for Deadline 2012-11-08 17:18:19: 0: INFO: Start Job called - starting up 3dsmax plugin 2012-11-08 17:18:19: 0: INFO: Rendering with 3dsmax version: 2012 2012-11-08 17:18:19: 0: INFO: Build of 3dsmax to force: 64bit 2012-11-08 17:18:19: 0: INFO: Rendering with executable: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe 2012-11-08 17:18:19: 0: INFO: Checking registry for 3dsmax language code 2012-11-08 17:18:19: 0: INFO: Found language code: 409 2012-11-08 17:18:19: 0: INFO: Language code string: enu 2012-11-08 17:18:19: 0: INFO: Fail on existing 3dsmax process: 0 2012-11-08 17:18:19: 0: INFO: Load 3dsmax timeout: 1000 seconds 2012-11-08 17:18:19: 0: INFO: Start job timeout: 1000 seconds 2012-11-08 17:18:19: 0: INFO: Progress update timeout: 8000 seconds 2012-11-08 17:18:19: 0: INFO: Progress update timout disabled: 0 2012-11-08 17:18:19: 0: INFO: Slave mode enabled: 1 2012-11-08 17:18:19: 0: INFO: Silent mode enabled: 0 2012-11-08 17:18:19: 0: INFO: Local rendering enabled: 1 2012-11-08 17:18:19: 0: INFO: Running render sanity check using 3dsmaxcmd.exe 2012-11-08 17:18:20: 0: INFO: 3dsmaxcmd.exe returned: P11/8/2012 17:18:19 PM; Error opening scene file: "C:\Program Files\Autodesk\3ds Max 2012\" 2012-11-08 17:18:20: 0: INFO: 3dsmax start up file: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-09\plugins\deadlineStartupMax2012.max 2012-11-08 17:18:20: 0: INFO: Using user profiles: 1 2012-11-08 17:18:20: 0: INFO: 3dsmax user profile path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu 2012-11-08 17:18:20: 0: INFO: 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\ 2012-11-08 17:18:20: 0: INFO: 3dsmax ini file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\3dsmax.ini 2012-11-08 17:18:20: 0: INFO: Network log file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\Network\Max.log 2012-11-08 17:18:20: 0: INFO: Plugin ini file: C:\Program Files\Autodesk\3ds Max 2012\plugin.ini 2012-11-08 17:18:20: 0: INFO: Not including user profile plugin ini because it does not exist: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\Plugin.UserSettings.ini 2012-11-08 17:18:20: 0: INFO: Lightning connection plugin: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-09\plugins\lightning64Max2012.dlx 2012-11-08 17:18:20: 0: INFO: 3dsmax socket connection port: 49230 2012-11-08 17:18:20: 0: INFO: Creating startup script: C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms 2012-11-08 17:18:20: 0: INFO: Copying C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-09\plugins\lightning64Max2012.dlx to C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\temp\lightning\lightning.dlx 2012-11-08 17:18:20: 0: INFO: Copying dl.ini to 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\ 2012-11-08 17:18:20: 0: INFO: If this fails, make sure that the necessary permissions are set on this folder to allow for this copy to take place 2012-11-08 17:18:20: 0: INFO: Starting monitored managed process 3dsmaxProcess 2012-11-08 17:18:20: 0: INFO: Stdout Handling Enabled: False 2012-11-08 17:18:20: 0: INFO: Popup Handling Enabled: True 2012-11-08 17:18:20: 0: INFO: Using Process Tree: True 2012-11-08 17:18:20: 0: INFO: Hiding DOS Window: False 2012-11-08 17:18:20: 0: INFO: Creating New Console: False 2012-11-08 17:18:20: 0: INFO: Render Executable: "C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe" 2012-11-08 17:18:20: 0: INFO: Render Argument: -p "dl.ini" -q -s "C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-09\plugins\deadlineStartupMax2012.max" 2012-11-08 17:18:20: 0: INFO: Startup Directory: "C:\Program Files\Autodesk\3ds Max 2012" 2012-11-08 17:18:20: 0: INFO: Process Priority: BelowNormal 2012-11-08 17:18:20: 0: INFO: Process Affinity: default 2012-11-08 17:18:20: 0: INFO: Process is now running 2012-11-08 17:18:20: 0: INFO: Waiting for connection from 3dsmax 2012-11-08 17:18:22: Scheduler Thread - Cancelling task because task "3_203-203" could not be found 2012-11-08 17:18:22: Scheduler Thread - The task has either been changed externally (and requeued), or the Job has been deleted. 2012-11-08 17:18:22: sending cancel task command to plugin 2012-11-08 17:18:22: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader 2012-11-08 17:18:22: 0: Unloading plugin: 3dsmax 2012-11-08 17:18:23: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0 2012-11-08 17:18:23: Starting between task wait for available threads - seconds: 2 2012-11-08 17:18:26: Scheduler - Successfully dequeued 1 task(s). Returning. 2012-11-08 17:18:26: 0: Got task: 8_208-208 2012-11-08 17:18:26: Constructor: 3dsmax 2012-11-08 17:18:26: 0: Loaded plugin: 3dsmax 2012-11-08 17:18:27: 0: Task timeout is disabled. 2012-11-08 17:18:27: 0: Loaded job: CIB_TLN_0010_Anim_A02.04 (50980b405d99e510bc2b836f) 2012-11-08 17:18:27: 0: Successfully mapped W: to \\sfs-file\working 2012-11-08 17:18:27: 0: Successfully mapped T: to \\sfs-file\tools 2012-11-08 17:18:27: 0: Successfully mapped O: to \\nas\nas\offline 2012-11-08 17:18:27: 0: Successfully mapped R: to \\nas\nas\archive 2012-11-08 17:18:27: 0: Successfully mapped G: to \\DEADALUS02\raid 2012-11-08 17:18:27: 0: Successfully mapped M: to \\sfs-file\maps 2012-11-08 17:18:27: 0: INFO: StartJob: initializing script plugin 3dsmax

Still broken.

rrussell · November 9, 2012, 4:37pm

Can you provide more details? These two logs just show the task being canceled because the task was either requeued or the job was deleted.

im_thatoneguy · November 10, 2012, 1:02am

All I did was start a job. They picked up tasks and then their CPU stayed at 0% and they would stall out on the task.

rrussell · November 12, 2012, 4:20pm

Ah, I was looking a little too far up the log and missing this line at the bottom of each report:

Was this with debug mode enabled? It doesn’t look like it, but that might be okay, since I found this in an earlier log you posted:

It also looks like that once the slave is stuck here, it doesn’t respond to canceling the job, which is why you see all those “shutdown” messages.

This is strange. We never seen this problem, and we’ve been testing with Max since the beginning. Does this happen with other job types, or just 3dsmax jobs?

im_thatoneguy · November 13, 2012, 3:39am

I don’t know if it’s exclusively max jobs. We don’t run anything else through it.

It’s exclusively a problem with slaves running as a service. Are you testing with service slaves? Do you have Vray installed? Are you running Max 2012? I think they’re mostly runing Vista not Windows 7. Ummm… it’s on a domain with domain account for the service. Not sure what else might be unique.

[code]2012-11-12 19:15:09: BEGIN - RENDER-I7-01\renderadmin
2012-11-12 19:15:09: Start-up
2012-11-12 19:15:09: 2012-11-12 19:15:08
2012-11-12 19:15:09: Deadline Slave 6.0 [v6.0.0.49068 R]
2012-11-12 19:15:09: Scanning for auto configuration
2012-11-12 19:15:12: Auto Configuration: No auto configuration could be detected, using local configuration
2012-11-12 19:15:12: Connecting to repository
2012-11-12 19:15:12: slave initialization beginning.
2012-11-12 19:15:14: Info Thread - Created.
2012-11-12 19:15:15: Purging old logs
2012-11-12 19:15:15: Starting between task wait - seconds: 2
2012-11-12 19:15:17: Scheduler Thread - Slave initialization complete.
2012-11-12 19:15:17: Scheduler Thread - Performing house cleaning…
2012-11-12 19:15:17: Trying to connect using license server ‘@sfs-file’
2012-11-12 19:15:17: Scheduler - Job chooser found no jobs.
2012-11-12 19:15:18: Starting between task wait - seconds: 2
2012-11-12 19:15:20: Scheduler Thread - Performing house cleaning…
2012-11-12 19:15:20: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:15:20:
2012-11-12 19:15:20: Scheduler Thread - Successfully mapped W: to \sfs-file\working
2012-11-12 19:15:21: Scheduler Thread - Successfully mapped T: to \sfs-file\tools
2012-11-12 19:15:21: Scheduler Thread - Successfully mapped O: to \nas\nas\offline
2012-11-12 19:15:21: Scheduler Thread - Successfully mapped R: to \nas\nas\archive
2012-11-12 19:15:21: Scheduler Thread - Successfully mapped G: to \DEADALUS02\raid
2012-11-12 19:15:21: Scheduler Thread - Successfully mapped M: to \sfs-file\maps
2012-11-12 19:15:22: Scheduler Thread - Synchronizing job files
2012-11-12 19:15:30: Scheduler Thread - Synchronization time for job files: 8.244 s
2012-11-12 19:15:30: Scheduler Thread - Synchronizing plugin files
2012-11-12 19:15:32: Scheduler Thread - Synchronization time for plugin files: 1.646 s
2012-11-12 19:15:32: 0: Got task: 8_65-65
2012-11-12 19:15:32: 0: Plugin will be reloaded because a new job has been loaded, or one of the job files has been modified
2012-11-12 19:15:32: Constructor: 3dsmax
2012-11-12 19:15:32: 0: Loaded plugin: 3dsmax
2012-11-12 19:15:32: 0: Task timeout is disabled.
2012-11-12 19:15:32: 0: Loaded job: AutoBackup03 (50a1bb455d99e505186aa876)
2012-11-12 19:15:32: 0: Successfully mapped W: to \sfs-file\working
2012-11-12 19:15:32: 0: Successfully mapped T: to \sfs-file\tools
2012-11-12 19:15:32: 0: Successfully mapped O: to \nas\nas\offline
2012-11-12 19:15:32: 0: Successfully mapped R: to \nas\nas\archive
2012-11-12 19:15:32: 0: Successfully mapped G: to \DEADALUS02\raid
2012-11-12 19:15:32: 0: Successfully mapped M: to \sfs-file\maps
2012-11-12 19:15:32: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-11-12 19:15:33: 0: INFO: About: 3dsmax Plugin for Deadline
2012-11-12 19:15:33: 0: INFO: Start Job called - starting up 3dsmax plugin
2012-11-12 19:15:33: 0: INFO: Rendering with 3dsmax version: 2012
2012-11-12 19:15:33: 0: INFO: Build of 3dsmax to force: 64bit
2012-11-12 19:15:33: 0: INFO: Rendering with executable: C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe
2012-11-12 19:15:33: 0: INFO: Checking registry for 3dsmax language code
2012-11-12 19:15:33: 0: INFO: Found language code: 409
2012-11-12 19:15:33: 0: INFO: Language code string: enu
2012-11-12 19:15:33: 0: INFO: Fail on existing 3dsmax process: 0
2012-11-12 19:15:33: 0: INFO: Load 3dsmax timeout: 1000 seconds
2012-11-12 19:15:33: 0: INFO: Start job timeout: 1000 seconds
2012-11-12 19:15:33: 0: INFO: Progress update timeout: 8000 seconds
2012-11-12 19:15:33: 0: INFO: Progress update timout disabled: 0
2012-11-12 19:15:33: 0: INFO: Slave mode enabled: 1
2012-11-12 19:15:33: 0: INFO: Silent mode enabled: 0
2012-11-12 19:15:33: 0: INFO: Local rendering enabled: 1
2012-11-12 19:15:33: 0: INFO: Running render sanity check using 3dsmaxcmd.exe
2012-11-12 19:15:34: 0: INFO: 3dsmaxcmd.exe returned: P11/12/2012 19:15:33 PM; Error opening scene file: “C:\Program Files\Autodesk\3ds Max 2012”
2012-11-12 19:15:34: 0: INFO: 3dsmax start up file: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\plugins\deadlineStartupMax2012.max
2012-11-12 19:15:34: 0: INFO: Using user profiles: 1
2012-11-12 19:15:34: 0: INFO: 3dsmax user profile path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu
2012-11-12 19:15:34: 0: INFO: 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-11-12 19:15:34: 0: INFO: 3dsmax ini file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\3dsmax.ini
2012-11-12 19:15:34: 0: INFO: Network log file: C:\Users\renderadmin\AppData\Local\Autodesk\3dsmax\2012 - 64bit\enu\Network\Max.log
2012-11-12 19:15:34: 0: INFO: Plugin ini file: C:\Program Files\Autodesk\3ds Max 2012\plugin.ini
2012-11-12 19:15:34: 0: INFO: Including user profile plugin ini: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu\Plugin.UserSettings.ini
2012-11-12 19:15:34: 0: INFO: Lightning connection plugin: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\plugins\lightning64Max2012.dlx
2012-11-12 19:15:34: 0: INFO: 3dsmax socket connection port: 53837
2012-11-12 19:15:34: 0: INFO: Creating startup script: C:\Users\renderadmin\AppData\Local\Temp\lightning_startup.ms
2012-11-12 19:15:34: 0: INFO: Copying C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\plugins\lightning64Max2012.dlx to C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\temp\lightning\lightning.dlx
2012-11-12 19:15:34: 0: INFO: Copying dl.ini to 3dsmax data path: C:\Users\renderadmin\AppData\Local\Autodesk\3dsMax\2012 - 64bit\enu
2012-11-12 19:15:34: 0: INFO: If this fails, make sure that the necessary permissions are set on this folder to allow for this copy to take place
2012-11-12 19:15:34: 0: INFO: Starting monitored managed process 3dsmaxProcess
2012-11-12 19:15:34: 0: INFO: Stdout Handling Enabled: False
2012-11-12 19:15:34: 0: INFO: Popup Handling Enabled: True
2012-11-12 19:15:34: 0: INFO: Using Process Tree: True
2012-11-12 19:15:34: 0: INFO: Hiding DOS Window: False
2012-11-12 19:15:34: 0: INFO: Creating New Console: False
2012-11-12 19:15:34: 0: INFO: Render Executable: “C:\Program Files\Autodesk\3ds Max 2012\3dsmax.exe”
2012-11-12 19:15:34: 0: INFO: Render Argument: -p “dl.ini” -q -s “C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\plugins\deadlineStartupMax2012.max”
2012-11-12 19:15:34: 0: INFO: Startup Directory: “C:\Program Files\Autodesk\3ds Max 2012”
2012-11-12 19:15:34: 0: INFO: Process Priority: BelowNormal
2012-11-12 19:15:34: 0: INFO: Process Affinity: default
2012-11-12 19:15:34: 0: INFO: Process is now running
2012-11-12 19:15:34: 0: INFO: Waiting for connection from 3dsmax
2012-11-12 19:15:36: 0: STDOUT: Dark
2012-11-12 19:15:50: 0: INFO: Connected to 3dsmax plugin version Lightning 5.2.0.49019 Nov 5 2012 09:44:17 R
2012-11-12 19:15:50: 0: INFO: Scene file to render: “C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\jobsData\PMR_PreRoll_010_B05.03_PART-A.max”
2012-11-12 19:15:50: 0: INFO: Camera: “Hero_Camera”
2012-11-12 19:15:50: 0: INFO: Restarting renderer after each frame: 1
2012-11-12 19:15:50: 0: INFO: Showing frame buffer: 1
2012-11-12 19:15:50: 0: INFO: Overriding render output: “W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02…exr”
2012-11-12 19:15:50: 0: INFO: Frame number base: 0
2012-11-12 19:15:50: 0: INFO: Remove padding from output filename: 0
2012-11-12 19:15:50: 0: INFO: Ignore missing external file errors: 1
2012-11-12 19:15:50: 0: INFO: Ignore missing UVW errors: 1
2012-11-12 19:15:50: 0: INFO: Ignore missing XREF errors: 1
2012-11-12 19:15:50: 0: INFO: Ignore missing DLL errors: 1
2012-11-12 19:15:50: 0: INFO: Disabling Multipass: 0
2012-11-12 19:15:50: 0: INFO: Loading 3dsmax scene file
2012-11-12 19:15:58: 0: INFO: [filename]
[format]
[size] 640x480
[aspect] 1

2012-11-12 19:15:58: 0: INFO: Executing script: C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\plugins\customize.ms
2012-11-12 19:15:58: 0: INFO: Applying customizations to max file…
2012-11-12 19:15:58: 0: INFO: >Adding scene path ‘C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\jobsData’ to session paths
2012-11-12 19:15:58: 0: INFO: >General Renderer Settings:
2012-11-12 19:15:58: 0: INFO: +Render Width set to 1280
2012-11-12 19:15:58: 0: INFO: +Render Height set to 720
2012-11-12 19:15:58: 0: INFO: +Pixel Aspect set to 1.0
2012-11-12 19:15:58: 0: INFO: +Atmospherics set to true
2012-11-12 19:15:58: 0: INFO: +Effects set to true
2012-11-12 19:15:58: 0: INFO: +Displacements set to true
2012-11-12 19:15:58: 0: INFO: +Area Lights/Shadows As Points set to false
2012-11-12 19:15:58: 0: INFO: +Force 2-Sided set to false
2012-11-12 19:15:58: 0: INFO: +Render Hidden Geometry set to false
2012-11-12 19:15:58: 0: INFO: +Video Color Check set to false
2012-11-12 19:15:58: 0: INFO: +Super Black set to false
2012-11-12 19:15:58: 0: INFO: +Render To Fields set to false
2012-11-12 19:15:58: 0: INFO: +Skip Existing Frames set to false
2012-11-12 19:15:58: 0: INFO: >Bitmap Pager Settings:
2012-11-12 19:15:58: 0: INFO: +Not overriding Bitmap Pager setting
2012-11-12 19:15:58: 0: INFO: >Render Environment Settings:
2012-11-12 19:15:58: 0: INFO: +Background Color set to (color 255 255 255)
2012-11-12 19:15:58: 0: INFO: +Use Environment Map set to true
2012-11-12 19:15:58: 0: INFO: +Ambient Color set to (color 0 0 0)
2012-11-12 19:15:58: 0: INFO: +Global Light Tint Color set to (color 255 255 255)
2012-11-12 19:15:58: 0: INFO: +Global Light Level set to 1.0
2012-11-12 19:15:58: 0: INFO: >Brazil r/s 2.x detected as current renderer.
2012-11-12 19:15:58: 0: INFO: +Bucket Reverse Order set to false
2012-11-12 19:15:59: 0: INFO: +Low Priority Thread set to false
2012-11-12 19:15:59: 0: INFO: +Force Thread Count set to 1
2012-11-12 19:15:59: 0: INFO: +Mapping On set to true
2012-11-12 19:15:59: 0: INFO: +Map Filtering On set to true
2012-11-12 19:15:59: 0: INFO: +Map Filtering GI On set to false
2012-11-12 19:15:59: 0: INFO: +Map Filtering Glossy On set to false
2012-11-12 19:15:59: 0: INFO: +Float Output On set to false
2012-11-12 19:15:59: 0: INFO: +Camera Space Shading On set to false
2012-11-12 19:15:59: 0: INFO: +Flat Z Buffer On set to true
2012-11-12 19:15:59: 0: INFO: +Atmos Camera On set to true
2012-11-12 19:15:59: 0: INFO: +Atmos Reflect On set to true
2012-11-12 19:15:59: 0: INFO: +Atmos Refract On set to true
2012-11-12 19:15:59: 0: INFO: +Atmos Indir Vis On set to true
2012-11-12 19:15:59: 0: INFO: +Atmos Subsurface On set to true
2012-11-12 19:15:59: 0: INFO: +Frame Offset set to 0.0
2012-11-12 19:15:59: 0: INFO: +Bucket Order set to Hilbert
2012-11-12 19:15:59: 0: INFO: +Bucket Size set to 48
2012-11-12 19:15:59: 0: INFO: +Render Threading Mode set to Automatic
2012-11-12 19:15:59: 0: INFO: +Sampling Min set to 0
2012-11-12 19:15:59: 0: INFO: +Sampling Max set to 0
2012-11-12 19:15:59: 0: INFO: +Jitter On set to true
2012-11-12 19:15:59: 0: INFO: +Jitter set to 0.7
2012-11-12 19:15:59: 0: INFO: +Clamp set to 1.5
2012-11-12 19:15:59: 0: INFO: +Adapt On set to false
2012-11-12 19:15:59: 0: INFO: +Adapt Color set to (color 255 255 0)
2012-11-12 19:15:59: 0: INFO: +Contrast On set to true
2012-11-12 19:15:59: 0: INFO: +Contrast Color set to (color 25.5 25.5 25.5)
2012-11-12 19:15:59: 0: INFO: +Normal On set to false
2012-11-12 19:15:59: 0: INFO: +Normal set to 0.9
2012-11-12 19:15:59: 0: INFO: +Z-Depth On set to false
2012-11-12 19:15:59: 0: INFO: +Z-Depth set to 5.0
2012-11-12 19:15:59: 0: INFO: +Object Edge On set to false
2012-11-12 19:15:59: 0: INFO: +Filter Radius set to 2.0
2012-11-12 19:15:59: 0: INFO: +Filter Param 1 set to 0.333
2012-11-12 19:15:59: 0: INFO: +Filter Param 2 set to 0.333
2012-11-12 19:15:59: 0: INFO: +Filter set to BrMitNetFilter
2012-11-12 19:15:59: 0: INFO: +Shutter Duration set to 0.75
2012-11-12 19:15:59: 0: INFO: +Shutter Bias set to 0.5
2012-11-12 19:15:59: 0: INFO: +Shutter Open set to 0.25
2012-11-12 19:15:59: 0: INFO: +Shutter Close set to 0.25
2012-11-12 19:15:59: 0: INFO: +Velocity Blur Env On set to false
2012-11-12 19:15:59: 0: INFO: +Velocity Blur After RenderFX On set to false
2012-11-12 19:15:59: 0: INFO: +MBlur3D Cam On set to true
2012-11-12 19:15:59: 0: INFO: +MBlur3D Transform On set to true
2012-11-12 19:15:59: 0: INFO: +MBlur3D Deform On set to false
2012-11-12 19:15:59: 0: INFO: +MBlur3D Cam Segments set to 8
2012-11-12 19:15:59: 0: INFO: +MBlur3D Transform Segments set to 8
2012-11-12 19:15:59: 0: INFO: +MBlur3D Deform Segments set to 1
2012-11-12 19:15:59: 0: INFO: +MBlur3D Min Samples set to 4
2012-11-12 19:15:59: 0: INFO: +MBlur3D Max Samples set to 16
2012-11-12 19:15:59: 0: INFO: +MBlur3D Error set to 1.0
2012-11-12 19:15:59: 0: INFO: +Motion Blur set to Image Motion Blur
2012-11-12 19:15:59: 0: INFO: +Shutter Type set to Basic
2012-11-12 19:15:59: 0: INFO: +Reflection Depth set to 3
2012-11-12 19:15:59: 0: INFO: +Refracted Depth set to 8
2012-11-12 19:15:59: 0: INFO: +Total Depth set to 11
2012-11-12 19:15:59: 0: INFO: +Auto Cutoff set to 0.05
2012-11-12 19:15:59: 0: INFO: +Secondary Effects set to true
2012-11-12 19:15:59: 0: INFO: +Raytrace Reflections set to true
2012-11-12 19:15:59: 0: INFO: +Glossy Reflections set to true
2012-11-12 19:15:59: 0: INFO: +Raytrace Refractions set to true
2012-11-12 19:15:59: 0: INFO: +Glossy Refractions set to true
2012-11-12 19:15:59: 0: INFO: +Self Reflect set to true
2012-11-12 19:15:59: 0: INFO: +Secondary Material IDs set to true
2012-11-12 19:15:59: 0: INFO: +Conserve Memory set to false
2012-11-12 19:15:59: 0: INFO: +Ray Accelerator set to BrDefaultAccel
2012-11-12 19:15:59: 0: INFO: +Shadows set to true
2012-11-12 19:15:59: 0: INFO: +Default Light set to false
2012-11-12 19:15:59: 0: INFO: +Direct Light set to true
2012-11-12 19:15:59: 0: INFO: +Dir Point Lights set to true
2012-11-12 19:15:59: 0: INFO: +Dir Area Lights set to true
2012-11-12 19:15:59: 0: INFO: +Dir Sky Light set to false
2012-11-12 19:15:59: 0: INFO: +Subsurface Effects set to true
2012-11-12 19:15:59: 0: INFO: +Subsurface Sample Rate set to 5
2012-11-12 19:15:59: 0: INFO: +Subsurface Intensity set to 1.0
2012-11-12 19:15:59: 0: INFO: +Subsurface Depth Scale set to 1.0
2012-11-12 19:15:59: 0: INFO: +GI On set to false
2012-11-12 19:15:59: 0: INFO: +GI Photon Map set to false
2012-11-12 19:15:59: 0: INFO: +GI Regather set to false
2012-11-12 19:15:59: 0: INFO: +GI Render Cache set to false
2012-11-12 19:15:59: 0: INFO: +QMC Point Lights set to true
2012-11-12 19:15:59: 0: INFO: +QMC Area Lights set to true
2012-11-12 19:15:59: 0: INFO: +QMC Sky Light set to true
2012-11-12 19:15:59: 0: INFO: +QMC Caustics set to false
2012-11-12 19:15:59: 0: INFO: +QMC Atmos set to true
2012-11-12 19:15:59: 0: INFO: +QMC Toon set to true
2012-11-12 19:15:59: 0: INFO: +QMC Rate set to 10
2012-11-12 19:15:59: 0: INFO: +QMC Bounces set to 2
2012-11-12 19:15:59: 0: INFO: +QMC Use Portals set to true
2012-11-12 19:15:59: 0: INFO: +QMC Portal Rate set to 15
2012-11-12 19:15:59: 0: INFO: +QMC Portal Only Skylight set to false
2012-11-12 19:15:59: 0: INFO: +Energy Multiplier set to 1.0
2012-11-12 19:15:59: 0: INFO: +Energy Saturation set to 1.0
2012-11-12 19:15:59: 0: INFO: +Energy Black Point set to 0.0
2012-11-12 19:15:59: 0: INFO: +Energy White Point set to 1.0
2012-11-12 19:15:59: 0: INFO: +Energy Tint set to (color 255 255 255)
2012-11-12 19:15:59: 0: INFO: +Energy Gamma set to 1.0
2012-11-12 19:15:59: 0: INFO: +Skylight Use 3dsMax Env set to false
2012-11-12 19:15:59: 0: INFO: +Skylight Transarent Shadows set to true
2012-11-12 19:15:59: 0: INFO: +Skylight Mulitlier set to 0.9
2012-11-12 19:15:59: 0: INFO: +Skylight Color set to (color 255 255 255)
2012-11-12 19:15:59: 0: INFO: +Skylight Map Amount set to 100
2012-11-12 19:15:59: 0: INFO: +Render Cache Mode set to No Enhancement
2012-11-12 19:15:59: 0: INFO: >Performing XREF workaround…
2012-11-12 19:15:59: 0: INFO: +Found A Version Of The File In The Repository, Repathing To [C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\jobsData]
2012-11-12 19:15:59: 0: INFO: +Found A Version Of The File In The Repository, Repathing To [C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\jobsData]
2012-11-12 19:15:59: 0: INFO: +Found A Version Of The File In The Repository, Repathing To [C:\Users\renderadmin\AppData\Local\Thinkbox\Deadline6\slave\RENDER-I7-01\jobsData]
2012-11-12 19:15:59: 0: Plugin rendering frame(s): 65
2012-11-12 19:16:00: 0: INFO: Render Tasks called
2012-11-12 19:16:00: 0: INFO: STARTED
2012-11-12 19:16:00: 0: INFO: Lightning: Render frame 65
2012-11-12 19:16:00: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0065.exr
2012-11-12 19:16:00: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:16:00: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:16:00: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:16:00: 0: INFO: Lightning: Checking multipass info for frame 65
2012-11-12 19:16:00: 0: INFO: Lightning: Opening renderer
2012-11-12 19:16:01: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:16:01: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:16:01: 0: INFO: Lightning: Checking output paths
2012-11-12 19:16:01: 0: INFO: Lightning: Checking default actions
2012-11-12 19:16:01: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:16:01: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:16:01: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:16:01: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:16:01: 0: INFO: Lightning: Calling renderer
2012-11-12 19:16:02: 0: INFO: Updating View
2012-11-12 19:16:02: 0: INFO: Updating World
2012-11-12 19:16:02: 0: INFO: Updating Geometry
2012-11-12 19:16:39: 0: INFO: Updating Materials
2012-11-12 19:16:39: 0: INFO: Updating Lights
2012-11-12 19:16:39: 0: INFO: Updating Environment and Effects
2012-11-12 19:16:39: 0: INFO: Updating World
2012-11-12 19:16:39: 0: INFO: Updating Render Database
2012-11-12 19:16:40: 0: INFO: Updating Ray Server
2012-11-12 19:17:01: 0: INFO: Initializing Render Clients
2012-11-12 19:17:01: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:17:01: 0: INFO: Rendering Frame
2012-11-12 19:17:45: 0: INFO: Broadcasting Frame End
2012-11-12 19:17:46: 0: INFO: Image Motion Blur Pass 1
2012-11-12 19:17:46: 0: INFO: Image Motion Blur Pass 2
2012-11-12 19:17:46: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1
2012-11-12 19:17:46: 0: INFO: Lightning: Render done
2012-11-12 19:17:46: 0: INFO: Lightning: Saved image to W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0065.exr
2012-11-12 19:17:46: 0: INFO: Lightning: Checking render elements
2012-11-12 19:17:47: 0: Render time for frame: 2.244 m
2012-11-12 19:17:47: 0: Total time for task: 20.132 c
2012-11-12 19:17:48: Scheduler Thread - Render Thread 0 completed its task
2012-11-12 19:17:48: Starting between task wait for available threads - seconds: 5
2012-11-12 19:17:53: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:17:53: 0: Got task: 13_70-70
2012-11-12 19:17:53: 0: Plugin already loaded: 3dsmax
2012-11-12 19:17:53: 0: Task timeout is disabled.
2012-11-12 19:17:53: 0: Job already loaded: AutoBackup03
2012-11-12 19:17:53: 0: Plugin rendering frame(s): 70
2012-11-12 19:17:54: 0: INFO: Render Tasks called
2012-11-12 19:17:54: 0: INFO: STARTED
2012-11-12 19:17:54: 0: INFO: Lightning: Render frame 70
2012-11-12 19:17:54: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0070.exr
2012-11-12 19:17:54: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:17:54: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:17:54: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:17:54: 0: INFO: Lightning: Checking multipass info for frame 70
2012-11-12 19:17:54: 0: INFO: Lightning: Opening renderer
2012-11-12 19:17:55: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:17:55: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:17:55: 0: INFO: Lightning: Checking output paths
2012-11-12 19:17:55: 0: INFO: Lightning: Checking default actions
2012-11-12 19:17:55: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:17:55: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:17:55: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:17:55: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:17:55: 0: INFO: Lightning: Calling renderer
2012-11-12 19:17:55: 0: INFO: Updating View
2012-11-12 19:17:55: 0: INFO: Updating World
2012-11-12 19:17:56: 0: INFO: Updating Geometry
2012-11-12 19:17:59: 0: INFO: Updating Materials
2012-11-12 19:17:59: 0: INFO: Updating Lights
2012-11-12 19:17:59: 0: INFO: Updating Environment and Effects
2012-11-12 19:17:59: 0: INFO: Updating World
2012-11-12 19:17:59: 0: INFO: Updating Render Database
2012-11-12 19:18:00: 0: INFO: Updating Ray Server
2012-11-12 19:18:21: 0: INFO: Initializing Render Clients
2012-11-12 19:18:21: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:18:21: 0: INFO: Rendering Frame
2012-11-12 19:19:15: 0: INFO: Broadcasting Frame End
2012-11-12 19:19:16: 0: INFO: Image Motion Blur Pass 1
2012-11-12 19:19:16: 0: INFO: Image Motion Blur Pass 2
2012-11-12 19:19:16: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1
2012-11-12 19:19:16: 0: INFO: Lightning: Render done
2012-11-12 19:19:17: 0: INFO: Lightning: Saved image to W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0070.exr
2012-11-12 19:19:17: 0: INFO: Lightning: Checking render elements
2012-11-12 19:19:17: 0: Render time for frame: 1.402 m
2012-11-12 19:19:17: 0: Total time for task: 20.132 c
2012-11-12 19:19:18: Scheduler Thread - Render Thread 0 completed its task
2012-11-12 19:19:18: Starting between task wait for available threads - seconds: 2
2012-11-12 19:19:20: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:19:20: 0: Got task: 0_57-57
2012-11-12 19:19:20: 0: Plugin already loaded: 3dsmax
2012-11-12 19:19:21: 0: Task timeout is disabled.
2012-11-12 19:19:21: 0: Job already loaded: AutoBackup03
2012-11-12 19:19:21: 0: Plugin rendering frame(s): 57
2012-11-12 19:19:21: 0: INFO: Render Tasks called
2012-11-12 19:19:21: 0: INFO: STARTED
2012-11-12 19:19:21: 0: INFO: Lightning: Render frame 57
2012-11-12 19:19:21: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0057.exr
2012-11-12 19:19:21: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:19:21: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:19:21: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:19:21: 0: INFO: Lightning: Checking multipass info for frame 57
2012-11-12 19:19:21: 0: INFO: Lightning: Opening renderer
2012-11-12 19:19:22: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:19:22: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:19:22: 0: INFO: Lightning: Checking output paths
2012-11-12 19:19:22: 0: INFO: Lightning: Checking default actions
2012-11-12 19:19:22: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:19:22: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:19:22: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:19:22: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:19:22: 0: INFO: Lightning: Calling renderer
2012-11-12 19:19:23: 0: INFO: Updating View
2012-11-12 19:19:23: 0: INFO: Updating World
2012-11-12 19:19:23: 0: INFO: Updating Geometry
2012-11-12 19:19:26: 0: INFO: Updating Materials
2012-11-12 19:19:26: 0: INFO: Updating Lights
2012-11-12 19:19:26: 0: INFO: Updating Environment and Effects
2012-11-12 19:19:26: 0: INFO: Updating World
2012-11-12 19:19:26: 0: INFO: Updating Render Database
2012-11-12 19:19:27: 0: INFO: Updating Ray Server
2012-11-12 19:19:45: 0: INFO: Initializing Render Clients
2012-11-12 19:19:45: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:19:45: 0: INFO: Rendering Frame
2012-11-12 19:20:12: 0: INFO: Broadcasting Frame End
2012-11-12 19:20:12: 0: INFO: Image Motion Blur Pass 1
2012-11-12 19:20:12: 0: INFO: Image Motion Blur Pass 2
2012-11-12 19:20:13: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1
2012-11-12 19:20:13: 0: INFO: Lightning: Render done
2012-11-12 19:20:13: 0: INFO: Lightning: Saved image to W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0057.exr
2012-11-12 19:20:13: 0: INFO: Lightning: Checking render elements
2012-11-12 19:20:13: 0: Render time for frame: 52.786 s
2012-11-12 19:20:13: 0: Total time for task: 20.132 c
2012-11-12 19:20:14: Scheduler Thread - Render Thread 0 completed its task
2012-11-12 19:20:14: Starting between task wait for available threads - seconds: 2
2012-11-12 19:20:16: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:20:16: 0: Got task: 18_75-75
2012-11-12 19:20:16: 0: Plugin already loaded: 3dsmax
2012-11-12 19:20:17: 0: Task timeout is disabled.
2012-11-12 19:20:17: 0: Job already loaded: AutoBackup03
2012-11-12 19:20:17: 0: Plugin rendering frame(s): 75
2012-11-12 19:20:17: 0: INFO: Render Tasks called
2012-11-12 19:20:17: 0: INFO: STARTED
2012-11-12 19:20:17: 0: INFO: Lightning: Render frame 75
2012-11-12 19:20:17: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0075.exr
2012-11-12 19:20:17: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:20:17: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:20:17: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:20:17: 0: INFO: Lightning: Checking multipass info for frame 75
2012-11-12 19:20:17: 0: INFO: Lightning: Opening renderer
2012-11-12 19:20:18: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:20:18: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:20:18: 0: INFO: Lightning: Checking output paths
2012-11-12 19:20:18: 0: INFO: Lightning: Checking default actions
2012-11-12 19:20:18: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:20:18: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:20:18: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:20:18: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:20:18: 0: INFO: Lightning: Calling renderer
2012-11-12 19:20:19: 0: INFO: Updating View
2012-11-12 19:20:19: 0: INFO: Updating World
2012-11-12 19:20:19: 0: INFO: Updating Geometry
2012-11-12 19:20:22: 0: INFO: Updating Materials
2012-11-12 19:20:22: 0: INFO: Updating Lights
2012-11-12 19:20:22: 0: INFO: Updating Environment and Effects
2012-11-12 19:20:22: 0: INFO: Updating World
2012-11-12 19:20:22: 0: INFO: Updating Render Database
2012-11-12 19:20:23: 0: INFO: Updating Ray Server
2012-11-12 19:20:42: 0: INFO: Initializing Render Clients
2012-11-12 19:20:42: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:20:42: 0: INFO: Rendering Frame
2012-11-12 19:21:50: 0: INFO: Broadcasting Frame End
2012-11-12 19:21:50: 0: INFO: Image Motion Blur Pass 1
2012-11-12 19:21:50: 0: INFO: Image Motion Blur Pass 2
2012-11-12 19:21:50: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1
2012-11-12 19:21:50: 0: INFO: Lightning: Render done
2012-11-12 19:21:51: 0: INFO: Lightning: Saved image to W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0075.exr
2012-11-12 19:21:51: 0: INFO: Lightning: Checking render elements
2012-11-12 19:21:51: 0: Render time for frame: 1.579 m
2012-11-12 19:21:51: 0: Total time for task: 20.132 c
2012-11-12 19:21:51: Scheduler Thread - Render Thread 0 completed its task
2012-11-12 19:21:51: Starting between task wait for available threads - seconds: 3
2012-11-12 19:21:55: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:21:55: 0: Got task: 20_77-77
2012-11-12 19:21:55: 0: Plugin already loaded: 3dsmax
2012-11-12 19:21:56: 0: Task timeout is disabled.
2012-11-12 19:21:56: 0: Job already loaded: AutoBackup03
2012-11-12 19:21:56: 0: Plugin rendering frame(s): 77
2012-11-12 19:21:56: 0: INFO: Render Tasks called
2012-11-12 19:21:56: 0: INFO: STARTED
2012-11-12 19:21:56: 0: INFO: Lightning: Render frame 77
2012-11-12 19:21:56: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0077.exr
2012-11-12 19:21:56: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:21:56: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:21:56: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:21:56: 0: INFO: Lightning: Checking multipass info for frame 77
2012-11-12 19:21:56: 0: INFO: Lightning: Opening renderer
2012-11-12 19:21:57: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:21:57: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:21:57: 0: INFO: Lightning: Checking output paths
2012-11-12 19:21:57: 0: INFO: Lightning: Checking default actions
2012-11-12 19:21:57: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:21:57: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:21:57: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:21:57: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:21:57: 0: INFO: Lightning: Calling renderer
2012-11-12 19:21:58: 0: INFO: Updating View
2012-11-12 19:21:58: 0: INFO: Updating World
2012-11-12 19:21:58: 0: INFO: Updating Geometry
2012-11-12 19:22:01: 0: INFO: Updating Materials
2012-11-12 19:22:01: 0: INFO: Updating Lights
2012-11-12 19:22:01: 0: INFO: Updating Environment and Effects
2012-11-12 19:22:01: 0: INFO: Updating World
2012-11-12 19:22:01: 0: INFO: Updating Render Database
2012-11-12 19:22:02: 0: INFO: Updating Ray Server
2012-11-12 19:22:23: 0: INFO: Initializing Render Clients
2012-11-12 19:22:23: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:22:23: 0: INFO: Rendering Frame
2012-11-12 19:23:39: 0: INFO: Broadcasting Frame End
2012-11-12 19:23:39: 0: INFO: Image Motion Blur Pass 1
2012-11-12 19:23:39: 0: INFO: Image Motion Blur Pass 2
2012-11-12 19:23:39: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1
2012-11-12 19:23:39: 0: INFO: Lightning: Render done
2012-11-12 19:23:40: 0: INFO: Lightning: Saved image to W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0077.exr
2012-11-12 19:23:40: 0: INFO: Lightning: Checking render elements
2012-11-12 19:23:40: 0: Render time for frame: 1.747 m
2012-11-12 19:23:40: 0: Total time for task: 20.132 c
2012-11-12 19:23:41: Scheduler Thread - Render Thread 0 completed its task
2012-11-12 19:23:41: Starting between task wait for available threads - seconds: 5
2012-11-12 19:23:46: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:23:46: 0: Got task: 24_81-81
2012-11-12 19:23:46: 0: Plugin already loaded: 3dsmax
2012-11-12 19:23:47: 0: Task timeout is disabled.
2012-11-12 19:23:47: 0: Job already loaded: AutoBackup03
2012-11-12 19:23:47: 0: Plugin rendering frame(s): 81
2012-11-12 19:23:47: 0: INFO: Render Tasks called
2012-11-12 19:23:47: 0: INFO: STARTED
2012-11-12 19:23:47: 0: INFO: Lightning: Render frame 81
2012-11-12 19:23:47: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0081.exr
2012-11-12 19:23:47: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:23:47: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:23:47: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:23:47: 0: INFO: Lightning: Checking multipass info for frame 81
2012-11-12 19:23:47: 0: INFO: Lightning: Opening renderer
2012-11-12 19:23:48: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:23:48: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:23:48: 0: INFO: Lightning: Checking output paths
2012-11-12 19:23:48: 0: INFO: Lightning: Checking default actions
2012-11-12 19:23:48: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:23:48: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:23:48: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:23:48: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:23:48: 0: INFO: Lightning: Calling renderer
2012-11-12 19:23:49: 0: INFO: Updating View
2012-11-12 19:23:49: 0: INFO: Updating World
2012-11-12 19:23:49: 0: INFO: Updating Geometry
2012-11-12 19:23:52: 0: INFO: Updating Materials
2012-11-12 19:23:52: 0: INFO: Updating Lights
2012-11-12 19:23:52: 0: INFO: Updating Environment and Effects
2012-11-12 19:23:52: 0: INFO: Updating World
2012-11-12 19:23:52: 0: INFO: Updating Render Database
2012-11-12 19:23:54: 0: INFO: Updating Ray Server
2012-11-12 19:24:12: 0: INFO: Initializing Render Clients
2012-11-12 19:24:12: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:24:12: 0: INFO: Rendering Frame
2012-11-12 19:25:41: 0: INFO: Broadcasting Frame End
2012-11-12 19:25:42: 0: INFO: Image Motion Blur Pass 1
2012-11-12 19:25:42: 0: INFO: Image Motion Blur Pass 2
2012-11-12 19:25:42: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1
2012-11-12 19:25:43: 0: INFO: Lightning: Render done
2012-11-12 19:25:43: 0: INFO: Lightning: Saved image to W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0081.exr
2012-11-12 19:25:43: 0: INFO: Lightning: Checking render elements
2012-11-12 19:25:44: 0: Render time for frame: 1.962 m
2012-11-12 19:25:44: 0: Total time for task: 20.132 c
2012-11-12 19:25:45: Scheduler Thread - Render Thread 0 completed its task
2012-11-12 19:25:45: Starting between task wait for available threads - seconds: 3
2012-11-12 19:25:48: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:25:49: 0: Got task: 27_84-84
2012-11-12 19:25:49: 0: Plugin already loaded: 3dsmax
2012-11-12 19:25:49: 0: Task timeout is disabled.
2012-11-12 19:25:49: 0: Job already loaded: AutoBackup03
2012-11-12 19:25:49: 0: Plugin rendering frame(s): 84
2012-11-12 19:25:49: 0: INFO: Render Tasks called
2012-11-12 19:25:49: 0: INFO: STARTED
2012-11-12 19:25:49: 0: INFO: Lightning: Render frame 84
2012-11-12 19:25:50: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0084.exr
2012-11-12 19:25:50: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:25:50: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:25:50: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:25:50: 0: INFO: Lightning: Checking multipass info for frame 84
2012-11-12 19:25:50: 0: INFO: Lightning: Opening renderer
2012-11-12 19:25:51: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:25:51: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:25:51: 0: INFO: Lightning: Checking output paths
2012-11-12 19:25:51: 0: INFO: Lightning: Checking default actions
2012-11-12 19:25:51: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:25:51: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:25:51: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:25:51: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:25:51: 0: INFO: Lightning: Calling renderer
2012-11-12 19:25:51: 0: INFO: Updating View
2012-11-12 19:25:51: 0: INFO: Updating World
2012-11-12 19:25:52: 0: INFO: Updating Geometry
2012-11-12 19:25:52: Thermal Shutdown: Skipping zone “rendernodes” because it is disabled
2012-11-12 19:25:55: 0: INFO: Updating Materials
2012-11-12 19:25:55: 0: INFO: Updating Lights
2012-11-12 19:25:55: 0: INFO: Updating Environment and Effects
2012-11-12 19:25:55: 0: INFO: Updating World
2012-11-12 19:25:55: 0: INFO: Updating Render Database
2012-11-12 19:25:56: 0: INFO: Updating Ray Server
2012-11-12 19:26:15: 0: INFO: Initializing Render Clients
2012-11-12 19:26:15: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:26:15: 0: INFO: Rendering Frame
2012-11-12 19:27:56: 0: INFO: Broadcasting Frame End
2012-11-12 19:27:57: 0: INFO: Image Motion Blur Pass 1
2012-11-12 19:27:57: 0: INFO: Image Motion Blur Pass 2
2012-11-12 19:27:58: 0: INFO: Lightning: CallCurRendererRenderFrame returned code 1
2012-11-12 19:27:58: 0: INFO: Lightning: Render done
2012-11-12 19:27:59: 0: INFO: Lightning: Saved image to W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0084.exr
2012-11-12 19:27:59: 0: INFO: Lightning: Checking render elements
2012-11-12 19:27:59: 0: Render time for frame: 2.173 m
2012-11-12 19:27:59: 0: Total time for task: 20.132 c
2012-11-12 19:28:00: Scheduler Thread - Render Thread 0 completed its task
2012-11-12 19:28:00: Starting between task wait for available threads - seconds: 5
2012-11-12 19:28:06: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:28:06: 0: Got task: 31_88-88
2012-11-12 19:28:06: 0: Plugin already loaded: 3dsmax
2012-11-12 19:28:06: 0: Task timeout is disabled.
2012-11-12 19:28:06: 0: Job already loaded: AutoBackup03
2012-11-12 19:28:06: 0: Plugin rendering frame(s): 88
2012-11-12 19:28:07: 0: INFO: Render Tasks called
2012-11-12 19:28:07: 0: INFO: STARTED
2012-11-12 19:28:07: 0: INFO: Lightning: Render frame 88
2012-11-12 19:28:07: 0: INFO: Lightning: Rendering frame W:\12065 Tmo Holiday Mosaic Rev\Shots\0010\0010\Renders\AOV\B05.02\TPM_PreRoll_0010_Patch_B05.02.0088.exr
2012-11-12 19:28:07: 0: INFO: Lightning: Rendering 0 render elements
2012-11-12 19:28:07: 0: INFO: Lightning: Setting up render parameters
2012-11-12 19:28:07: 0: INFO: Lightning: Rendering camera node Hero_Camera
2012-11-12 19:28:07: 0: INFO: Lightning: Checking multipass info for frame 88
2012-11-12 19:28:07: 0: INFO: Lightning: Opening renderer
2012-11-12 19:28:08: 0: INFO: Lightning: Multipass disabled
2012-11-12 19:28:08: 0: INFO: Lightning: Rendering 1 passes
2012-11-12 19:28:08: 0: INFO: Lightning: Checking output paths
2012-11-12 19:28:08: 0: INFO: Lightning: Checking default actions
2012-11-12 19:28:08: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2012-11-12 19:28:08: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2012-11-12 19:28:08: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = IGNORE
2012-11-12 19:28:08: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2012-11-12 19:28:08: 0: INFO: Lightning: Calling renderer
2012-11-12 19:28:09: 0: INFO: Updating View
2012-11-12 19:28:09: 0: INFO: Updating World
2012-11-12 19:28:09: 0: INFO: Updating Geometry
2012-11-12 19:28:13: 0: INFO: Updating Materials
2012-11-12 19:28:13: 0: INFO: Updating Lights
2012-11-12 19:28:13: 0: INFO: Updating Environment and Effects
2012-11-12 19:28:13: 0: INFO: Updating World
2012-11-12 19:28:13: 0: INFO: Updating Render Database
2012-11-12 19:28:14: 0: INFO: Updating Ray Server
2012-11-12 19:28:32: 0: INFO: Initializing Render Clients
2012-11-12 19:28:32: 0: INFO: Broadcasting Frame Begin
2012-11-12 19:28:32: 0: INFO: Rendering Frame
2012-11-12 19:30:15: Scheduler Thread - Cancelling task because task “31_88-88” could not be found
2012-11-12 19:30:15: Scheduler Thread - The task has either been changed externally (and requeued), or the Job has been deleted.
2012-11-12 19:30:16: sending cancel task command to plugin
2012-11-12 19:30:20: 0: INFO: ERROR: Traceback (most recent call last):
File “none”, line 72, in RenderTasks
File “none”, line 807, in RenderTasks
File “none”, line 1363, in RenderFrame
File “none”, line 1459, in PollUntilComplete
a: Render was canceled
at Deadline.Plugins.ScriptPlugin.FailRender(String message)

2012-11-12 19:30:22: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader
2012-11-12 19:30:22: 0: Unloading plugin: 3dsmax
2012-11-12 19:30:27: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2012-11-12 19:30:27: Starting between task wait for available threads - seconds: 3
2012-11-12 19:30:30: Scheduler - Successfully dequeued 1 task(s). Returning.
2012-11-12 19:30:31: 0: Got task: 5_62-62
2012-11-12 19:30:31: Constructor: 3dsmax
2012-11-12 19:30:31: 0: Loaded plugin: 3dsmax
2012-11-12 19:30:31: 0: Task timeout is disabled.
2012-11-12 19:30:31: 0: Loaded job: AutoBackup03 (50a1bb455d99e505186aa876)
2012-11-12 19:30:31: 0: Successfully mapped W: to \sfs-file\working
2012-11-12 19:30:31: 0: Successfully mapped T: to \sfs-file\tools
2012-11-12 19:30:31: 0: Successfully mapped O: to \nas\nas\offline
2012-11-12 19:30:31: 0: Successfully mapped R: to \nas\nas\archive
2012-11-12 19:30:31: 0: Successfully mapped G: to \DEADALUS02\raid
2012-11-12 19:30:31: 0: Successfully mapped M: to \sfs-file\maps
2012-11-12 19:30:31: 0: INFO: StartJob: initializing script plugin 3dsmax
2012-11-12 19:32:21: Listener Thread - ::ffff:192.168.94.37 has connected
2012-11-12 19:32:21: Listener Thread - Received message: StreamLog
2012-11-12 19:32:23: Listener Thread - Responded with: Success
2012-11-12 19:36:58: Thermal Shutdown: Skipping zone “rendernodes” because it is disabled
[/code]

rrussell · November 13, 2012, 6:21pm

We’ll be testing it as a service today. Just to confirm, you’ve tested as a non-service and you never see this problem?

We have vray and max 2012, so we’ll test exclusively with that.

On a side note, we’ve figured out why this gets printed:

We had a catch-all exception handler in there for debugging that just printed out the error before letting it propagate up the calling stack. The “FailRender” function actually throws a special type of exception, so it was treated like any other exception here. This debugging code will be removed in beta 6, so you’ll no longer see then when a task is canceled.

im_thatoneguy · November 13, 2012, 6:35pm

My workstation seems to work perfectly. It’s just our slaves that are acting bizzare.

rrussell · November 13, 2012, 6:47pm

I was just able to reproduce this in service mode. I was also able to reproduce it by simply running the slave with the -nogui flag to hide the interface, so it’s not related to service mode directly. Yay for progress!

I will keep working on this today and keep you in the loop.

rrussell · November 13, 2012, 8:20pm

I think we’ve fixed this! I tested with normal -nogui mode, and with it running as a service, and I can’t reproduce this problem anymore. This fix will be included in the beta 6 release.

Thanks for your help with tracking this one down!!

im_thatoneguy · November 13, 2012, 8:22pm

Awesome! When will 6 be out soon? Is it patchable in the interim?