Corona Render crashes on animation render

jacobhutson · November 19, 2014, 3:36am

Corona 0.71 stable (daily does the same)
3dsmax design 2014 sp5 (win7 pro64bit)
RC1 for Deadline on all boxes and server

We are rendering an animation using corona using a baked gi solution
it crashes when sent to deadline (backburner works fine) it gets to about 20 passes and then stops

it works as stand alone in max and a single frame works in deadline
Single frame as a tile render occasionally gets stuck for us so may be related after rendering 40(this number would be random)/200 tiles

there is nothing that stands out in the log other than when it dies
this is the part it dies
46: 0: INFO: Rendering pass 30/75 (this: 0:04:03, total: 0:04:19)
2014-11-18 10:45:46: 0: INFO: Rendering pass 30/75 (this: 0:04:04, total: 0:04:20)
2014-11-18 10:45:47: 0: INFO: Rendering pass 30/75 (this: 0:04:04, total: 0:04:21)
2014-11-18 10:45:47: 0: INFO: Rendering pass 30/75 (this: 0:04:05, total: 0:04:21)
2014-11-18 10:45:48: 0: INFO: Rendering pass 30/75 (this: 0:04:05, total: 0:04:22)
2014-11-18 10:45:48: 0: INFO: Rendering pass 30/75 (this: 0:04:06, total: 0:04:22)
2014-11-18 10:45:49: 0: INFO: Rendering pass 30/75 (this: 0:04:06, total: 0:04:23)
2014-11-18 10:45:49: 0: INFO: Rendering pass 30/75 (this: 0:04:07, total: 0:04:23)
2014-11-18 10:45:50: 0: INFO: Rendering pass 30/75 (this: 0:04:07, total: 0:04:24)
2014-11-18 10:45:50: 0: INFO: Rendering pass 30/75 (this: 0:04:08, total: 0:04:24)
2014-11-18 10:45:50: Scheduler Thread - Task “0_0-0” could not be found because task has been modified:
2014-11-18 10:45:50: current status = Rendering, new status = Queued
2014-11-18 10:45:50: current slave = QRND00, new slave =
2014-11-18 10:45:50: current frames = 0-0, new frames = 0-0
2014-11-18 10:45:50: Scheduler Thread - Cancelling task…
2014-11-18 10:45:52: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader
2014-11-18 10:45:52: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2014-11-18 10:45:54: Update timeout has been set to 1800 seconds
2014-11-18 10:45:54: Stdout Handling Enabled: False
2014-11-18 10:45:54: Popup Handling Enabled: False
2014-11-18 10:45:54: Using Process Tree: True

when using the daily build we had this in the log, but not with stable build
Timed out waiting for the lightning 3dsmax plugin to acknowledge the ExecuteScript command

can we please get an upload number and send a scene package to you.
deadlineslave-QRND00-2014-11-18-0001.log (1 MB)

jacobhutson · November 19, 2014, 4:22am

Ok, it does the same thing with VRAY as well, on all nodes

error is this
2014-11-19 14:20:32: Connecting to slave log: QBOX00
2014-11-19 14:20:47: Scheduler Thread - Task “3_3-3” could not be found because task has been modified:
2014-11-19 14:20:47: current status = Rendering, new status = Rendering
2014-11-19 14:20:47: current slave = QBOX00, new slave = QRND10
2014-11-19 14:20:47: current frames = 3-3, new frames = 3-3
2014-11-19 14:20:47: Scheduler Thread - Cancelling task…
2014-11-19 14:20:48: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader
2014-11-19 14:20:48: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2014-11-19 14:20:52: Scheduler Thread - Synchronizing job auxiliary files from \wbox\DeadlineRepository7\jobs\546c1a675444950e64d2b3cd

so we are trying a still image to see what happens.

jacobhutson · November 19, 2014, 4:40am

Vray still frame does the same

2014-11-19 14:33:44: 0: INFO: Building motion blur raycast accelerator…
2014-11-19 14:33:44: 0: INFO: Building static hair raycast accelerator…
2014-11-19 14:33:44: 0: INFO: Building motion blur hair raycast accelerator…
2014-11-19 14:33:44: 0: INFO: Preparing direct light manager…
2014-11-19 14:33:45: 0: INFO: Preparing global light manager…
2014-11-19 14:38:50: Scheduler Thread - Task “0_30-30” could not be found because task has been modified:
2014-11-19 14:38:50: current status = Rendering, new status = Queued
2014-11-19 14:38:50: current slave = QBOX00, new slave =
2014-11-19 14:38:50: current frames = 30-30, new frames = 30-30
2014-11-19 14:38:50: Scheduler Thread - Cancelling task…
2014-11-19 14:38:51: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader
2014-11-19 14:38:51: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2014-11-19 14:38:55: Scheduler Thread - Synchronizing job auxiliary files from \wbox\DeadlineRepository7\jobs\546c1b9f54449511d81f6a94

jacobhutson · November 19, 2014, 4:46am

Corona Still does the same thing, same error
renders for about 4 minutes before dying

we will roll back to beta 7 and try it

jacobhutson · November 19, 2014, 5:58am

beta 7 still broken in client side
uninstalled 7 completely and installed DL6 and is working as it should
so major issue it seems somewhere in seven on job stability

rrussell · November 19, 2014, 3:20pm

This bug was fixed in beta 7, and we’ve had confirmation from other uses that this is the case.

The key thing is that if ANY client machines (render nodes, workstations, pulse machine) are still running beta 6 or earlier, this problem can still occur. As long as all of your machines are running beta 7 or later, you should be good.

The safe thing to do would be to run the client installer on all your machines again (you don’t need to uninstall first).

Cheers,
Ryan

jacobhutson · November 20, 2014, 12:47am

everything had had a manual install of the RC1
from server to nodes
i installed over top for repository and mongo db

rrussell · November 20, 2014, 2:24pm

Hmm… I definitely can’t reproduce this here with RC2.

Are you guys running Pulse? If so, can you send us the pulse logs for the days in which this problem occurred?

If you aren’t running Pulse, then it would likely be one of your slaves doing this when they run the repository repair operation. You can check the Version column in the slave list in the Monitor to see if you have any slaves that might still be running an older version.

Cheers,
Ryan

jacobhutson · November 24, 2014, 1:00am

Hi Ryan

We have completely uninstalled deadline, repository, everything from all render nodes and the server, deleted folders and reinstalled RC2 and get this message
we havent been running pulse but are now. i will report if it makes the issue go away.

we are still getting this
10:28:03: 0: INFO: Rendering pass 37/150 (this: 0:31:55, total: 0:32:12)
2014-11-24 10:28:04: 0: INFO: Rendering pass 37/150 (this: 0:31:55, total: 0:32:12)
2014-11-24 10:28:04: 0: INFO: Rendering pass 37/150 (this: 0:31:56, total: 0:32:13)
2014-11-24 10:28:05: 0: INFO: Rendering pass 37/150 (this: 0:31:56, total: 0:32:14)
2014-11-24 10:28:05: 0: INFO: Rendering pass 37/150 (this: 0:31:57, total: 0:32:14)
2014-11-24 10:28:06: 0: INFO: Rendering pass 37/150 (this: 0:31:57, total: 0:32:15)
2014-11-24 10:28:06: 0: INFO: Rendering pass 37/150 (this: 0:31:58, total: 0:32:15)
2014-11-24 10:28:07: Scheduler Thread - Task “7_7-7” could not be found because task has been modified:
2014-11-24 10:28:07: current status = Rendering, new status = Queued
2014-11-24 10:28:07: current slave = QRND00, new slave =
2014-11-24 10:28:07: current frames = 7-7, new frames = 7-7
2014-11-24 10:28:07: Scheduler Thread - Cancelling task…
2014-11-24 10:28:07: 0: INFO: Rendering pass 37/150 (this: 0:31:58, total: 0:32:16)
2014-11-24 10:28:07: 0: INFO: Rendering pass 37/150 (this: 0:31:59, total: 0:32:16)
deadlineslave-QRND00-2014-11-24-0000.log (809 KB)

jacobhutson · November 24, 2014, 4:33am

we enabled 1 pulse server and it seems to be working now with no errors
so maybe it is a job reset command on the repair operation from the slave

our deadline and pulse server are on the same server and its not a rendering server.

jacobhutson · November 24, 2014, 5:50am

hmm , maybe not

pulse server running
error from slave

2014-11-24 15:47:16: 0: INFO: Rendering pass 4/4 (this: 1:54:21, total: 1:55:50)
2014-11-24 15:47:17: 0: INFO: Rendering pass 4/4 (this: 1:54:22, total: 1:55:51)
2014-11-24 15:47:17: 0: INFO: Rendering pass 4/4 (this: 1:54:22, total: 1:55:51)
2014-11-24 15:47:17: Scheduler Thread - Task “10_10-10” could not be found because task has been modified:
2014-11-24 15:47:17: current status = Rendering, new status = Rendering
2014-11-24 15:47:17: current slave = QRND07, new slave = QRND00
2014-11-24 15:47:17: current frames = 10-10, new frames = 10-10
2014-11-24 15:47:17: Scheduler Thread - Cancelling task…
2014-11-24 15:47:17: 0: INFO: Rendering pass 4/4 (this: 1:54:23, total: 1:55:52)

pulse log
i can send the whole log file if required

2014-11-24 15:45:05: Slave Report Scan - Loading slave IDs
2014-11-24 15:45:05: Slave Report Scan - Loaded 22 slave IDs in 0.000 s
2014-11-24 15:45:05: Slave Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 15:45:05: Slave Report Scan - Done.
2014-11-24 15:45:05: Purging Old Limits
2014-11-24 15:45:05: Old Limit Scan - Loading machine limits
2014-11-24 15:45:05: Old Limit Scan - Found 2 machine limits in 0.000 s
2014-11-24 15:45:05: Old Limit Scan - Loading job IDs
2014-11-24 15:45:05: Old Limit Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:45:05: Old Limit Scan - Purged 0 machine limits in 0.000 s
2014-11-24 15:45:05: Old Limit Scan - Done.
2014-11-24 15:45:05: Purging Temporary Repository Files
2014-11-24 15:45:05: Temporary File Scan - Scanning for ‘connectReadWriteTest’ files
2014-11-24 15:45:05: Temporary File Scan - Deleted 0 temporary files in 0.000 s
2014-11-24 15:45:05: Temporary File Scan - Done.
2014-11-24 15:45:05: Purging Old Statistics
2014-11-24 15:45:05: Old Statistics - Skipping job statistics because the option to purge them is disabled in the Repository Options
2014-11-24 15:45:05: Old Statistics - Purging slave statistics that are older than Jul 27/14 15:45:05
2014-11-24 15:45:05: Old Statistics - Purged old slave statistics in 0.000 s
2014-11-24 15:45:05: Old Statistics - Purging repository statistics that are older than Jul 27/14 15:45:05
2014-11-24 15:45:05: Old Statistics - Purged old repository statistics in 0.000 s
2014-11-24 15:45:05: Purging Deleted Document Stubs From Database
2014-11-24 15:45:05: Deleted Document Stubs - Deleting stubs that are older than 3 days
2014-11-24 15:45:05: Deleted Document Stubs - Deleted 0 stubs in 0.000 s
2014-11-24 15:45:05: Triggering House Cleaning Events
2014-11-24 15:45:50: Performing repository repair
2014-11-24 15:45:50: Performing Orphaned Task Scan…
2014-11-24 15:45:50: Orphaned Task Scan - Loading rendering jobs
2014-11-24 15:45:50: Orphaned Task Scan - Loaded 1 rendering jobs in 0.000 s
2014-11-24 15:45:50: Orphaned Task Scan - Scanning for orphaned tasks
2014-11-24 15:45:50: Orphaned Task Scan - Cleaned up 0 orphaned tasks in 0.000 s
2014-11-24 15:45:50: Orphaned Task Scan - Done.
2014-11-24 15:45:50: Performing Orphaned Limit Stub Scan…
2014-11-24 15:45:50: Orphaned Limit Stub Scan - Loading limits
2014-11-24 15:45:50: Orphaned Limit Stub Scan - Loaded 2 limits in 0.000 s
2014-11-24 15:45:50: Orphaned Limit Stub Scan - Loading slave states
2014-11-24 15:45:50: Orphaned Limit Stub Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:45:50: Orphaned Limit Stub Scan - Returned 0 orphaned limit stubs in 0.000 s
2014-11-24 15:45:50: Orphaned Limit Stub Scan - Done.
2014-11-24 15:45:50: Checking Available Database Connections
2014-11-24 15:45:50: Available Database Connections - Skipping because there are no Low Database Connection notification email addresses set in the Repository Options
2014-11-24 15:45:50: Performing Stalled Slave Scan…
2014-11-24 15:45:50: Stalled Slave Scan - Loading slave states
2014-11-24 15:45:50: Stalled Slave Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:45:50: Stalled Slave Scan - Scanning slave states
2014-11-24 15:45:50: Stalled Slave Scan - Cleaned up 0 stalled slaves in 0.000 s
2014-11-24 15:45:50: Stalled Slave Scan - Done.
2014-11-24 15:45:50: Performing Stalled Pulse Scan…
2014-11-24 15:45:50: Stalled Pulse Scan - Loading pulse states
2014-11-24 15:45:50: Stalled Pulse Scan - Loaded 1 pulse states in 0.000 s
2014-11-24 15:45:50: Stalled Pulse Scan - Scanning pulse states
2014-11-24 15:45:50: Stalled Pulse Scan - Cleaned up 0 stalled pulses in 0.000 s
2014-11-24 15:45:50: Stalled Pulse Scan - Done.
2014-11-24 15:45:50: Performing Stalled Balancer Scan…
2014-11-24 15:45:50: Stalled Balancer Scan - Loading balancer states
2014-11-24 15:45:50: Stalled Balancer Scan - Loaded 0 balancer states in 0.000 s
2014-11-24 15:45:50: Stalled Balancer Scan - Done.
2014-11-24 15:45:50: Triggering Repository Repair Events
2014-11-24 15:46:00: Performing Pending Job Scan…
2014-11-24 15:46:00: Pending Job Scan - Loading pending and active jobs
2014-11-24 15:46:00: Pending Job Scan - Loaded 1 pending and active jobs in 0.000 s
2014-11-24 15:46:00: Pending Job Scan - Scanning pending and active jobs
2014-11-24 15:46:00: Pending Job Scan - Released 0 pending jobs and 0 pending tasks in 0.000 s
2014-11-24 15:46:00: Pending Job Scan - Done.
2014-11-24 15:46:00: Processing Pending Job Events
2014-11-24 15:46:00: Pending Job Events - Checking for pending job events
2014-11-24 15:46:00: Pending Job Events - Processing 0 job events
2014-11-24 15:46:00: Pending Job Events - No more job events to process
2014-11-24 15:46:00: Pending Job Events - Done.
2014-11-24 15:46:04: Performing house cleaning
2014-11-24 15:46:04: Performing Job Cleanup Scan…
2014-11-24 15:46:04: Job Cleanup Scan - Loading completed jobs
2014-11-24 15:46:04: Job Cleanup Scan - Loaded 1 completed jobs in 0.000 s
2014-11-24 15:46:04: Job Cleanup Scan - Scanning completed jobs
2014-11-24 15:46:04: Job Cleanup Scan - Deleted 0 and archived 0 completed jobs in 0.000 s
2014-11-24 15:46:04: Job Cleanup Scan - Done.
2014-11-24 15:46:04: Purging Unsubmitted Jobs
2014-11-24 15:46:04: Unsubmitted Job Scan - Loading unsubmitted jobs
2014-11-24 15:46:04: Unsubmitted Job Scan - Loaded 0 unsubmitted jobs in 0.000 s
2014-11-24 15:46:04: Unsubmitted Job Scan - Done.
2014-11-24 15:46:04: Purging Deleted Jobs
2014-11-24 15:46:04: Deleted Job Scan - Loading deleted jobs
2014-11-24 15:46:04: Deleted Job Scan - Loaded 0 deleted jobs in 0.000 s
2014-11-24 15:46:04: Deleted Job Scan - Done.
2014-11-24 15:46:04: Purging Old Job Auxiliary Files
2014-11-24 15:46:04: Auxiliary File Scan - Scanning for auxiliary directories
2014-11-24 15:46:04: Auxiliary File Scan - Found 9 auxiliary directories in 0.000 s
2014-11-24 15:46:04: Auxiliary File Scan - Loading job IDs
2014-11-24 15:46:04: Auxiliary File Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:46:11: Auxiliary File Scan - Purged 0 auxiliary folders in 7.000 s
2014-11-24 15:46:11: Auxiliary File Scan - Done.
2014-11-24 15:46:11: Purging Old Job Reports
2014-11-24 15:46:11: Job Report Scan - Loading job report collections
2014-11-24 15:46:11: Job Report Scan - Found 4 report collections in 0.000 s
2014-11-24 15:46:11: Job Report Scan - Loading job IDs
2014-11-24 15:46:11: Job Report Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:46:11: Job Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 15:46:11: Job Report Scan - Purging old job report files
2014-11-24 15:46:11: Job Report Scan - Purged 0 report files in 0.000 s
2014-11-24 15:46:11: Job Report Scan - Done.
2014-11-24 15:46:11: Purging Obsolete Slaves
2014-11-24 15:46:11: Obsolete Slave Scan - Skipping because it is disabled in the Repository Options
2014-11-24 15:46:11: Purging Old Slave Reports
2014-11-24 15:46:11: Slave Report Scan - Loading slave report collections
2014-11-24 15:46:11: Slave Report Scan - Found 22 report collections in 0.000 s
2014-11-24 15:46:11: Slave Report Scan - Loading slave IDs
2014-11-24 15:46:11: Slave Report Scan - Loaded 22 slave IDs in 0.000 s
2014-11-24 15:46:11: Slave Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 15:46:11: Slave Report Scan - Done.
2014-11-24 15:46:11: Purging Old Limits
2014-11-24 15:46:11: Old Limit Scan - Loading machine limits
2014-11-24 15:46:11: Old Limit Scan - Found 2 machine limits in 0.000 s
2014-11-24 15:46:11: Old Limit Scan - Loading job IDs
2014-11-24 15:46:11: Old Limit Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:46:11: Old Limit Scan - Purged 0 machine limits in 0.000 s
2014-11-24 15:46:11: Old Limit Scan - Done.
2014-11-24 15:46:11: Purging Temporary Repository Files
2014-11-24 15:46:11: Temporary File Scan - Scanning for ‘connectReadWriteTest’ files
2014-11-24 15:46:11: Temporary File Scan - Deleted 0 temporary files in 0.000 s
2014-11-24 15:46:11: Temporary File Scan - Done.
2014-11-24 15:46:11: Purging Old Statistics
2014-11-24 15:46:11: Old Statistics - Skipping job statistics because the option to purge them is disabled in the Repository Options
2014-11-24 15:46:11: Old Statistics - Purging slave statistics that are older than Jul 27/14 15:46:11
2014-11-24 15:46:11: Old Statistics - Purged old slave statistics in 0.000 s
2014-11-24 15:46:11: Old Statistics - Purging repository statistics that are older than Jul 27/14 15:46:11
2014-11-24 15:46:11: Old Statistics - Purged old repository statistics in 0.000 s
2014-11-24 15:46:11: Purging Deleted Document Stubs From Database
2014-11-24 15:46:11: Deleted Document Stubs - Deleting stubs that are older than 3 days
2014-11-24 15:46:11: Deleted Document Stubs - Deleted 0 stubs in 0.000 s
2014-11-24 15:46:11: Triggering House Cleaning Events
2014-11-24 15:46:49: Performing repository repair
2014-11-24 15:46:49: Performing Orphaned Task Scan…
2014-11-24 15:46:49: Orphaned Task Scan - Loading rendering jobs
2014-11-24 15:46:49: Orphaned Task Scan - Loaded 1 rendering jobs in 0.000 s
2014-11-24 15:46:49: Orphaned Task Scan - Scanning for orphaned tasks
2014-11-24 15:46:49: Orphaned Task Scan - Cleaned up 0 orphaned tasks in 0.000 s
2014-11-24 15:46:49: Orphaned Task Scan - Done.
2014-11-24 15:46:49: Performing Orphaned Limit Stub Scan…
2014-11-24 15:46:49: Orphaned Limit Stub Scan - Loading limits
2014-11-24 15:46:49: Orphaned Limit Stub Scan - Loaded 2 limits in 0.000 s
2014-11-24 15:46:49: Orphaned Limit Stub Scan - Loading slave states
2014-11-24 15:46:49: Orphaned Limit Stub Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:46:49: Orphaned Limit Stub Scan - Returned 0 orphaned limit stubs in 0.000 s
2014-11-24 15:46:49: Orphaned Limit Stub Scan - Done.
2014-11-24 15:46:49: Checking Available Database Connections
2014-11-24 15:46:49: Available Database Connections - Skipping because there are no Low Database Connection notification email addresses set in the Repository Options
2014-11-24 15:46:49: Performing Stalled Slave Scan…
2014-11-24 15:46:49: Stalled Slave Scan - Loading slave states
2014-11-24 15:46:49: Stalled Slave Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:46:49: Stalled Slave Scan - Scanning slave states
2014-11-24 15:46:49: Stalled Slave Scan - Cleaned up 0 stalled slaves in 0.000 s
2014-11-24 15:46:49: Stalled Slave Scan - Done.
2014-11-24 15:46:49: Performing Stalled Pulse Scan…
2014-11-24 15:46:49: Stalled Pulse Scan - Loading pulse states
2014-11-24 15:46:49: Stalled Pulse Scan - Loaded 1 pulse states in 0.000 s
2014-11-24 15:46:49: Stalled Pulse Scan - Scanning pulse states
2014-11-24 15:46:49: Stalled Pulse Scan - Cleaned up 0 stalled pulses in 0.000 s
2014-11-24 15:46:49: Stalled Pulse Scan - Done.
2014-11-24 15:46:49: Performing Stalled Balancer Scan…
2014-11-24 15:46:49: Stalled Balancer Scan - Loading balancer states
2014-11-24 15:46:49: Stalled Balancer Scan - Loaded 0 balancer states in 0.000 s
2014-11-24 15:46:49: Stalled Balancer Scan - Done.
2014-11-24 15:46:49: Triggering Repository Repair Events
2014-11-24 15:46:59: Performing Pending Job Scan…
2014-11-24 15:46:59: Pending Job Scan - Loading pending and active jobs
2014-11-24 15:46:59: Pending Job Scan - Loaded 1 pending and active jobs in 0.000 s
2014-11-24 15:46:59: Pending Job Scan - Scanning pending and active jobs
2014-11-24 15:46:59: Pending Job Scan - Released 0 pending jobs and 0 pending tasks in 0.000 s
2014-11-24 15:46:59: Pending Job Scan - Done.
2014-11-24 15:46:59: Processing Pending Job Events
2014-11-24 15:46:59: Pending Job Events - Checking for pending job events
2014-11-24 15:46:59: Pending Job Events - Processing 0 job events
2014-11-24 15:46:59: Pending Job Events - No more job events to process
2014-11-24 15:46:59: Pending Job Events - Done.
2014-11-24 15:47:11: Performing house cleaning
2014-11-24 15:47:11: Performing Job Cleanup Scan…
2014-11-24 15:47:11: Job Cleanup Scan - Loading completed jobs
2014-11-24 15:47:11: Job Cleanup Scan - Loaded 1 completed jobs in 0.000 s
2014-11-24 15:47:11: Job Cleanup Scan - Scanning completed jobs
2014-11-24 15:47:11: Job Cleanup Scan - Deleted 0 and archived 0 completed jobs in 0.000 s
2014-11-24 15:47:11: Job Cleanup Scan - Done.
2014-11-24 15:47:11: Purging Unsubmitted Jobs
2014-11-24 15:47:11: Unsubmitted Job Scan - Loading unsubmitted jobs
2014-11-24 15:47:11: Unsubmitted Job Scan - Loaded 0 unsubmitted jobs in 0.000 s
2014-11-24 15:47:11: Unsubmitted Job Scan - Done.
2014-11-24 15:47:11: Purging Deleted Jobs
2014-11-24 15:47:11: Deleted Job Scan - Loading deleted jobs
2014-11-24 15:47:11: Deleted Job Scan - Loaded 0 deleted jobs in 0.000 s
2014-11-24 15:47:11: Deleted Job Scan - Done.
2014-11-24 15:47:11: Purging Old Job Auxiliary Files
2014-11-24 15:47:11: Auxiliary File Scan - Scanning for auxiliary directories
2014-11-24 15:47:11: Auxiliary File Scan - Found 9 auxiliary directories in 0.000 s
2014-11-24 15:47:11: Auxiliary File Scan - Loading job IDs
2014-11-24 15:47:11: Auxiliary File Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:47:17: Auxiliary File Scan - Purged 0 auxiliary folders in 6.907 s
2014-11-24 15:47:17: Auxiliary File Scan - Done.
2014-11-24 15:47:17: Purging Old Job Reports
2014-11-24 15:47:17: Job Report Scan - Loading job report collections
2014-11-24 15:47:17: Job Report Scan - Found 4 report collections in 0.000 s
2014-11-24 15:47:17: Job Report Scan - Loading job IDs
2014-11-24 15:47:17: Job Report Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:47:17: Job Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 15:47:17: Job Report Scan - Purging old job report files
2014-11-24 15:47:17: Job Report Scan - Purged 0 report files in 0.000 s
2014-11-24 15:47:17: Job Report Scan - Done.
2014-11-24 15:47:17: Purging Obsolete Slaves
2014-11-24 15:47:17: Obsolete Slave Scan - Skipping because it is disabled in the Repository Options
2014-11-24 15:47:17: Purging Old Slave Reports
2014-11-24 15:47:17: Slave Report Scan - Loading slave report collections
2014-11-24 15:47:17: Slave Report Scan - Found 22 report collections in 0.000 s
2014-11-24 15:47:17: Slave Report Scan - Loading slave IDs
2014-11-24 15:47:17: Slave Report Scan - Loaded 22 slave IDs in 0.000 s
2014-11-24 15:47:17: Slave Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 15:47:17: Slave Report Scan - Done.
2014-11-24 15:47:17: Purging Old Limits
2014-11-24 15:47:17: Old Limit Scan - Loading machine limits
2014-11-24 15:47:17: Old Limit Scan - Found 2 machine limits in 0.000 s
2014-11-24 15:47:17: Old Limit Scan - Loading job IDs
2014-11-24 15:47:17: Old Limit Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:47:17: Old Limit Scan - Purged 0 machine limits in 0.000 s
2014-11-24 15:47:17: Old Limit Scan - Done.
2014-11-24 15:47:17: Purging Temporary Repository Files
2014-11-24 15:47:17: Temporary File Scan - Scanning for ‘connectReadWriteTest’ files
2014-11-24 15:47:17: Temporary File Scan - Deleted 0 temporary files in 0.000 s
2014-11-24 15:47:17: Temporary File Scan - Done.
2014-11-24 15:47:17: Purging Old Statistics
2014-11-24 15:47:17: Old Statistics - Skipping job statistics because the option to purge them is disabled in the Repository Options
2014-11-24 15:47:17: Old Statistics - Purging slave statistics that are older than Jul 27/14 15:47:17
2014-11-24 15:47:17: Old Statistics - Purged old slave statistics in 0.000 s
2014-11-24 15:47:17: Old Statistics - Purging repository statistics that are older than Jul 27/14 15:47:17
2014-11-24 15:47:17: Old Statistics - Purged old repository statistics in 0.000 s
2014-11-24 15:47:17: Purging Deleted Document Stubs From Database
2014-11-24 15:47:17: Deleted Document Stubs - Deleting stubs that are older than 3 days
2014-11-24 15:47:17: Deleted Document Stubs - Deleted 0 stubs in 0.000 s
2014-11-24 15:47:17: Triggering House Cleaning Events
2014-11-24 15:47:49: Performing repository repair
2014-11-24 15:47:49: Performing Orphaned Task Scan…
2014-11-24 15:47:49: Orphaned Task Scan - Loading rendering jobs
2014-11-24 15:47:49: Orphaned Task Scan - Loaded 1 rendering jobs in 0.000 s
2014-11-24 15:47:49: Orphaned Task Scan - Scanning for orphaned tasks
2014-11-24 15:47:49: Orphaned Task Scan - Cleaned up 0 orphaned tasks in 0.000 s
2014-11-24 15:47:49: Orphaned Task Scan - Done.
2014-11-24 15:47:49: Performing Orphaned Limit Stub Scan…
2014-11-24 15:47:49: Orphaned Limit Stub Scan - Loading limits
2014-11-24 15:47:49: Orphaned Limit Stub Scan - Loaded 2 limits in 0.000 s
2014-11-24 15:47:49: Orphaned Limit Stub Scan - Loading slave states
2014-11-24 15:47:49: Orphaned Limit Stub Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:47:49: Orphaned Limit Stub Scan - Returned 0 orphaned limit stubs in 0.000 s
2014-11-24 15:47:49: Orphaned Limit Stub Scan - Done.
2014-11-24 15:47:49: Checking Available Database Connections
2014-11-24 15:47:49: Available Database Connections - Skipping because there are no Low Database Connection notification email addresses set in the Repository Options
2014-11-24 15:47:49: Performing Stalled Slave Scan…
2014-11-24 15:47:49: Stalled Slave Scan - Loading slave states
2014-11-24 15:47:49: Stalled Slave Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:47:49: Stalled Slave Scan - Scanning slave states
2014-11-24 15:47:49: Stalled Slave Scan - Cleaned up 0 stalled slaves in 0.000 s
2014-11-24 15:47:49: Stalled Slave Scan - Done.
2014-11-24 15:47:49: Performing Stalled Pulse Scan…
2014-11-24 15:47:49: Stalled Pulse Scan - Loading pulse states
2014-11-24 15:47:49: Stalled Pulse Scan - Loaded 1 pulse states in 0.000 s
2014-11-24 15:47:49: Stalled Pulse Scan - Scanning pulse states
2014-11-24 15:47:49: Stalled Pulse Scan - Cleaned up 0 stalled pulses in 0.000 s
2014-11-24 15:47:49: Stalled Pulse Scan - Done.
2014-11-24 15:47:49: Performing Stalled Balancer Scan…
2014-11-24 15:47:49: Stalled Balancer Scan - Loading balancer states
2014-11-24 15:47:49: Stalled Balancer Scan - Loaded 0 balancer states in 0.000 s
2014-11-24 15:47:49: Stalled Balancer Scan - Done.
2014-11-24 15:47:49: Triggering Repository Repair Events
2014-11-24 15:47:59: Performing Pending Job Scan…
2014-11-24 15:47:59: Pending Job Scan - Loading pending and active jobs
2014-11-24 15:47:59: Pending Job Scan - Loaded 1 pending and active jobs in 0.000 s
2014-11-24 15:47:59: Pending Job Scan - Scanning pending and active jobs
2014-11-24 15:47:59: Pending Job Scan - Released 0 pending jobs and 0 pending tasks in 0.000 s
2014-11-24 15:47:59: Pending Job Scan - Done.
2014-11-24 15:47:59: Processing Pending Job Events
2014-11-24 15:47:59: Pending Job Events - Checking for pending job events
2014-11-24 15:47:59: Pending Job Events - Processing 0 job events
2014-11-24 15:47:59: Pending Job Events - No more job events to process
2014-11-24 15:47:59: Pending Job Events - Done.
2014-11-24 15:48:17: Performing house cleaning
2014-11-24 15:48:17: Performing Job Cleanup Scan…
2014-11-24 15:48:17: Job Cleanup Scan - Loading completed jobs
2014-11-24 15:48:17: Job Cleanup Scan - Loaded 1 completed jobs in 0.000 s
2014-11-24 15:48:17: Job Cleanup Scan - Scanning completed jobs
2014-11-24 15:48:17: Job Cleanup Scan - Deleted 0 and archived 0 completed jobs in 0.000 s
2014-11-24 15:48:17: Job Cleanup Scan - Done.
2014-11-24 15:48:17: Purging Unsubmitted Jobs
2014-11-24 15:48:17: Unsubmitted Job Scan - Loading unsubmitted jobs
2014-11-24 15:48:17: Unsubmitted Job Scan - Loaded 0 unsubmitted jobs in 0.000 s
2014-11-24 15:48:17: Unsubmitted Job Scan - Done.
2014-11-24 15:48:17: Purging Deleted Jobs
2014-11-24 15:48:17: Deleted Job Scan - Loading deleted jobs
2014-11-24 15:48:17: Deleted Job Scan - Loaded 0 deleted jobs in 0.000 s
2014-11-24 15:48:17: Deleted Job Scan - Done.
2014-11-24 15:48:17: Purging Old Job Auxiliary Files
2014-11-24 15:48:17: Auxiliary File Scan - Scanning for auxiliary directories
2014-11-24 15:48:17: Auxiliary File Scan - Found 9 auxiliary directories in 0.000 s
2014-11-24 15:48:17: Auxiliary File Scan - Loading job IDs
2014-11-24 15:48:17: Auxiliary File Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:48:24: Auxiliary File Scan - Purged 0 auxiliary folders in 6.891 s
2014-11-24 15:48:24: Auxiliary File Scan - Done.
2014-11-24 15:48:24: Purging Old Job Reports
2014-11-24 15:48:24: Job Report Scan - Loading job report collections
2014-11-24 15:48:24: Job Report Scan - Found 4 report collections in 0.000 s
2014-11-24 15:48:24: Job Report Scan - Loading job IDs
2014-11-24 15:48:24: Job Report Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:48:24: Job Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 15:48:24: Job Report Scan - Purging old job report files
2014-11-24 15:48:24: Job Report Scan - Purged 0 report files in 0.000 s
2014-11-24 15:48:24: Job Report Scan - Done.
2014-11-24 15:48:24: Purging Obsolete Slaves
2014-11-24 15:48:24: Obsolete Slave Scan - Skipping because it is disabled in the Repository Options
2014-11-24 15:48:24: Purging Old Slave Reports
2014-11-24 15:48:24: Slave Report Scan - Loading slave report collections
2014-11-24 15:48:24: Slave Report Scan - Found 22 report collections in 0.000 s
2014-11-24 15:48:24: Slave Report Scan - Loading slave IDs
2014-11-24 15:48:24: Slave Report Scan - Loaded 22 slave IDs in 0.000 s
2014-11-24 15:48:24: Slave Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 15:48:24: Slave Report Scan - Done.
2014-11-24 15:48:24: Purging Old Limits
2014-11-24 15:48:24: Old Limit Scan - Loading machine limits
2014-11-24 15:48:24: Old Limit Scan - Found 2 machine limits in 0.000 s
2014-11-24 15:48:24: Old Limit Scan - Loading job IDs
2014-11-24 15:48:24: Old Limit Scan - Loaded 2 job IDs in 0.000 s
2014-11-24 15:48:24: Old Limit Scan - Purged 0 machine limits in 0.000 s
2014-11-24 15:48:24: Old Limit Scan - Done.
2014-11-24 15:48:24: Purging Temporary Repository Files
2014-11-24 15:48:24: Temporary File Scan - Scanning for ‘connectReadWriteTest’ files
2014-11-24 15:48:24: Temporary File Scan - Deleted 0 temporary files in 0.000 s
2014-11-24 15:48:24: Temporary File Scan - Done.
2014-11-24 15:48:24: Purging Old Statistics
2014-11-24 15:48:24: Old Statistics - Skipping job statistics because the option to purge them is disabled in the Repository Options
2014-11-24 15:48:24: Old Statistics - Purging slave statistics that are older than Jul 27/14 15:48:24
2014-11-24 15:48:24: Old Statistics - Purged old slave statistics in 0.000 s
2014-11-24 15:48:24: Old Statistics - Purging repository statistics that are older than Jul 27/14 15:48:24
2014-11-24 15:48:24: Old Statistics - Purged old repository statistics in 0.000 s
2014-11-24 15:48:24: Purging Deleted Document Stubs From Database
2014-11-24 15:48:24: Deleted Document Stubs - Deleting stubs that are older than 3 days
2014-11-24 15:48:24: Deleted Document Stubs - Deleted 0 stubs in 0.000 s
2014-11-24 15:48:24: Triggering House Cleaning Events
2014-11-24 15:48:48: Performing repository repair
2014-11-24 15:48:48: Performing Orphaned Task Scan…
2014-11-24 15:48:48: Orphaned Task Scan - Loading rendering jobs
2014-11-24 15:48:48: Orphaned Task Scan - Loaded 1 rendering jobs in 0.000 s
2014-11-24 15:48:48: Orphaned Task Scan - Scanning for orphaned tasks
2014-11-24 15:48:48: Orphaned Task Scan - Cleaned up 0 orphaned tasks in 0.000 s
2014-11-24 15:48:48: Orphaned Task Scan - Done.
2014-11-24 15:48:48: Performing Orphaned Limit Stub Scan…
2014-11-24 15:48:48: Orphaned Limit Stub Scan - Loading limits
2014-11-24 15:48:48: Orphaned Limit Stub Scan - Loaded 2 limits in 0.000 s
2014-11-24 15:48:48: Orphaned Limit Stub Scan - Loading slave states
2014-11-24 15:48:48: Orphaned Limit Stub Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:48:48: Orphaned Limit Stub Scan - Returned 0 orphaned limit stubs in 0.000 s
2014-11-24 15:48:48: Orphaned Limit Stub Scan - Done.
2014-11-24 15:48:48: Checking Available Database Connections
2014-11-24 15:48:48: Available Database Connections - Skipping because there are no Low Database Connection notification email addresses set in the Repository Options
2014-11-24 15:48:48: Performing Stalled Slave Scan…
2014-11-24 15:48:48: Stalled Slave Scan - Loading slave states
2014-11-24 15:48:48: Stalled Slave Scan - Loaded 22 slave states in 0.000 s
2014-11-24 15:48:48: Stalled Slave Scan - Scanning slave states
2014-11-24 15:48:48: Stalled Slave Scan - Cleaned up 0 stalled slaves in 0.000 s
2014-11-24 15:48:48: Stalled Slave Scan - Done.
2014-11-24 15:48:48: Performing Stalled Pulse Scan…
2014-11-24 15:48:48: Stalled Pulse Scan - Loading pulse states
2014-11-24 15:48:48: Stalled Pulse Scan - Loaded 1 pulse states in 0.000 s
2014-11-24 15:48:48: Stalled Pulse Scan - Scanning pulse states
2014-11-24 15:48:48: Stalled Pulse Scan - Cleaned up 0 stalled pulses in 0.000 s
2014-11-24 15:48:48: Stalled Pulse Scan - Done.
2014-11-24 15:48:48: Performing Stalled Balancer Scan…
2014-11-24 15:48:48: Stalled Balancer Scan - Loading balancer states
2014-11-24 15:48:48: Stalled Balancer Scan - Loaded 0 balancer states in 0.000 s
2014-11-24 15:48:48: Stalled Balancer Scan - Done.
2014-11-24 15:48:48: Triggering Repository Repair Events
2014-11-24 15:48:49: Connecting to Pulse log
2014-11-24 15:48:58: Performing Pending Job Scan…
2014-11-24 15:48:58: Pending Job Scan - Loading pending and active jobs
2014-11-24 15:48:58: Pending Job Scan - Loaded 1 pending and active jobs in 0.000 s
2014-11-24 15:48:58: Pending Job Scan - Scanning pending and active jobs
2014-11-24 15:48:58: Pending Job Scan - Released 0 pending jobs and 0 pending tasks in 0.000 s
2014-11-24 15:48:58: Pending Job Scan - Done.
2014-11-24 15:48:58: Processing Pending Job Events
2014-11-24 15:48:58: Pending Job Events - Checking for pending job events
2014-11-24 15:48:58: Pending Job Events - Processing 0 job events
2014-11-24 15:48:58: Pending Job Events - No more job events to process
2014-11-24 15:48:58: Pending Job Events - Done.
2014-11-24 15:49:23: Performing house cleaning
2014-11-24 15:49:23: Performing Job Cleanup Scan…
2014-11-24 15:49:23: Job Cleanup Scan - Loading completed jobs
2014-11-24 15:49:23: Job Cleanup Scan - Loaded 1 completed jobs in 0.000 s
2014-11-24 15:49:23: Job Cleanup Scan - Scanning completed jobs
2014-11-24 15:49:23: Job Cleanup Scan - Deleted 0 and archived 0 completed jobs in 0.000 s
2014-11-24 15:49:23: Job Cleanup Scan - Done.
2014-11-24 15:49:23: Purging Unsubmitted Jobs
2014-11-24 15:49:23: Unsubmitted Job Scan - Loading unsubmitted jobs
2014-11-24 15:49:23: Unsubmitted Job Scan - Loaded 0 unsubmitted jobs in 0.000 s
2014-11-24 15:49:23: Unsubmitted Job Scan - Done.
2014-11-24 15:49:23: Purging Deleted Jobs
2014-11-24 15:49:23: Deleted Job Scan - Loading deleted jobs
2014-11-24 15:49:23: Deleted Job Scan - Loaded 0 deleted jobs in 0.000 s
2014-11-24 15:49:23: Deleted Job Scan - Done.
2014-11-24 15:49:23: Purging Old Job Auxiliary Files
2014-11-24 15:49:23: Auxiliary File Scan - Scanning for auxiliary directories
2014-11-24 15:49:23: Auxiliary File Scan - Found 9 auxiliary directories in 0.000 s
2014-11-24 15:49:23: Auxiliary File Scan - Loading job IDs
2014-11-24 15:49:23: Auxiliary File Scan - Loaded 2 job IDs in 0.000 s

jacobhutson · November 24, 2014, 6:11am

or not, looks like it still happening
we are going to try max2015 and see what happens

2014-11-24 16:06:37: 0: INFO: Rendering pass 4/4 (elapsed: 2:16:00)
2014-11-24 16:06:37: 0: INFO: Rendering pass 4/4 (elapsed: 2:16:00)
2014-11-24 16:06:38: 0: INFO: Rendering pass 4/4 (elapsed: 2:16:01)
2014-11-24 16:06:38: 0: INFO: Rendering pass 4/4 (elapsed: 2:16:02)
2014-11-24 16:06:39: 0: INFO: Rendering pass 4/4 (elapsed: 2:16:02)
2014-11-24 16:06:39: Scheduler Thread - Task “7_7-7” could not be found because task has been modified:
2014-11-24 16:06:39: current status = Rendering, new status = Rendering
2014-11-24 16:06:39: current slave = QRND10, new slave = QRND06
2014-11-24 16:06:39: current frames = 7-7, new frames = 7-7
2014-11-24 16:06:39: Scheduler Thread - Cancelling task…
2014-11-24 16:06:39: 0: INFO: Rendering pass 4/4 (elapsed: 2:16:03)
2014-11-24 16:06:40: 0: In the process of canceling current task: ignoring exception thrown by PluginLoader
2014-11-24 16:06:41: Scheduler Thread - In the process of canceling current tasks: ignoring exception thrown by render thread 0
2014-11-24 16:06:50: Connecting to slave log: QRND10
Success
2014-11-24 16:06:52: Trying to connect using license server ‘@WBOX’…
2014-11-24 16:06:52: License obtained.
2014-11-24 16:06:52: Warning: The license file being used will expire in 4 days.
2014-11-24 16:06:52: Scheduler Thread - Synchronizing job auxiliary files from \wbox\DeadlineRepository7\jobs\5472a65254449535244d28c2
2014-11-24 16:06:52: Scheduler Thread - All job files are already synchronized
2014-11-24 16:06:52: Scheduler Thread - Synchronizing plugin files from \wbox\DeadlineRepository7\plugins\3dsmax
2014-11-24 16:06:52: Scheduler Thread - Synchronization time for plugin files: 280.156 ms
2014-11-24 16:06:53: Constructor: 3dsmax
2014-11-24 16:06:53: 0: Start Job timeout is disabled.
2014-11-24 16:06:53: 0: Task timeout is disabled.
2014-11-24 16:06:53: 0: Loaded job: close_up_livingroom_08 (5472a65254449535244d28c2)
2014-11-24 16:06:53: 0: INFO: Executing plugin script C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\plugins\5472a65254449535244d28c2\3dsmax.py
2014-11-24 16:06:53: 0: INFO: About: 3dsmax Plugin for Deadline
2014-11-24 16:06:53: 0: INFO: The current environment will be used for rendering
2014-11-24 16:06:53: 0: INFO: Start Job called - starting up 3dsmax plugin
2014-11-24 16:06:53: 0: INFO: Sys Env Var PATH: C:\Program Files\Thinkbox\Deadline7\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0;C:\Program Files\Common Files\Autodesk Shared;C:\Program Files (x86)\Autodesk\Backburner
2014-11-24 16:06:53: 0: INFO: Sys Env Var PATH length: 231
2014-11-24 16:06:53: 0: INFO: Backburner Path(s) Found in PATH: ‘C:\Program Files (x86)\Autodesk\Backburner’
2014-11-24 16:06:53: 0: INFO: Backburner server.exe version: 2015.0.1.1688
2014-11-24 16:06:53: 0: INFO: Rendering with 3dsmax Design version: 2014
2014-11-24 16:06:53: 0: INFO: Not forcing a build of 3dsmax because version 2014 and later is 64 bit only
2014-11-24 16:06:53: 0: INFO: Rendering with executable: C:\Program Files\Autodesk\3ds Max Design 2014\3dsmax.exe
2014-11-24 16:06:53: 0: INFO: Slave 3dsmax.exe version: 16.5.277.0
2014-11-24 16:06:53: 0: INFO: Slave 3dsmax.exe description: 3ds Max 2014 + servicepack_sp5
2014-11-24 16:06:53: 0: INFO: Submitted from 3dsmax.exe version: 16.5.277.0
2014-11-24 16:06:53: 0: INFO: Submitted from 3dsmax.exe description: 3ds Max 2014 + servicepack_sp5
2014-11-24 16:06:53: 0: INFO: Checking registry for 3dsmax language code
2014-11-24 16:06:53: 0: WARNING: Language code could not be found in registry. Defaulting to ENU (English)
2014-11-24 16:06:53: 0: WARNING: Language sub directory could not be found in registry. Defaulting to en-US (English)
2014-11-24 16:06:53: 0: INFO: Language code string: ENU
2014-11-24 16:06:53: 0: INFO: Language sub directory: en-US
2014-11-24 16:06:53: 0: INFO: Fail on existing 3dsmax process: 0
2014-11-24 16:06:53: 0: INFO: Load 3dsmax timeout: 1000 seconds
2014-11-24 16:06:53: 0: INFO: Start job timeout: 1000 seconds
2014-11-24 16:06:53: 0: INFO: Progress update timeout: 8000 seconds
2014-11-24 16:06:53: 0: INFO: Progress update timeout disabled: 0
2014-11-24 16:06:53: 0: INFO: Kill ADSK WSCommCntr*.exe process: False
2014-11-24 16:06:53: 0: INFO: Slave mode enabled: 1
2014-11-24 16:06:53: 0: INFO: Silent mode enabled: 0
2014-11-24 16:06:53: 0: INFO: Local rendering enabled: 1
2014-11-24 16:06:53: 0: INFO: Running render sanity check using 3dsmaxcmd.exe
2014-11-24 16:06:54: 0: INFO: 3dsmaxcmd.exe exit code: 3
2014-11-24 16:06:54: 0: INFO: 3dsmaxcmd.exe returned: 24/11/2014 16:06:53 PM; Error opening scene file: “C:\Program Files\Autodesk\3ds Max Design 2014”
2014-11-24 16:06:54: 0: INFO: Render sanity check using 3dsmaxcmd.exe completed successfully. Please ignore the ‘Error opening…’ message thrown by 3dsmaxcmd.exe above.
2014-11-24 16:06:54: 0: INFO: 3dsmax start up file: C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\plugins\5472a65254449535244d28c2\deadlineStartupMax2014.max
2014-11-24 16:06:54: 0: INFO: Using user profiles: 1
2014-11-24 16:06:54: 0: INFO: 3dsmax user profile path: C:\Users\render\AppData\Local\Autodesk\3dsMaxDesign\2014 - 64bit\ENU
2014-11-24 16:06:54: 0: INFO: 3dsmax data path: C:\Users\render\AppData\Local\Autodesk\3dsMaxDesign\2014 - 64bit\ENU
2014-11-24 16:06:54: 0: INFO: 3dsmax ini file: C:\Users\render\AppData\Local\Autodesk\3dsMaxDesign\2014 - 64bit\ENU\3dsmax.ini
2014-11-24 16:06:54: 0: INFO: Network log file: C:\Users\render\AppData\Local\Autodesk\3dsMaxDesign\2014 - 64bit\ENU\Network\Max.log
2014-11-24 16:06:54: 0: INFO: Plugin ini file: C:\Program Files\Autodesk\3ds Max Design 2014\en-US\plugin.ini
2014-11-24 16:06:54: 0: INFO: Including user profile plugin ini: C:\Users\render\AppData\Local\Autodesk\3dsMaxDesign\2014 - 64bit\ENU\Plugin.UserSettings.ini
2014-11-24 16:06:54: 0: INFO: Lightning connection plugin: C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\plugins\5472a65254449535244d28c2\lightning64Max2014.dlx
2014-11-24 16:06:54: 0: INFO: 3dsmax socket connection port: 53302
2014-11-24 16:06:54: 0: INFO: Setting up startup environment
2014-11-24 16:06:54: 0: INFO: Copying C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\plugins\5472a65254449535244d28c2\lightning64Max2014.dlx to C:\Users\render\AppData\Local\Thinkbox\Deadline7\temp\lightning\lightning.dlx
2014-11-24 16:06:54: 0: INFO: Starting monitored managed process 3dsmaxProcess
2014-11-24 16:06:54: 0: INFO: Stdout Handling Enabled: True
2014-11-24 16:06:54: 0: INFO: Popup Handling Enabled: True
2014-11-24 16:06:54: 0: INFO: Using Process Tree: True
2014-11-24 16:06:54: 0: INFO: Hiding DOS Window: False
2014-11-24 16:06:54: 0: INFO: Creating New Console: False
2014-11-24 16:06:54: 0: INFO: Running as user: render
2014-11-24 16:06:54: 0: INFO: Executable: “C:\Program Files\Autodesk\3ds Max Design 2014\3dsmax.exe”
2014-11-24 16:06:54: 0: INFO: Argument: -p “c:\temp\dl.ini” -q -s “C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\plugins\5472a65254449535244d28c2\deadlineStartupMax2014.max”
2014-11-24 16:06:54: 0: INFO: Startup Directory: “C:\Program Files\Autodesk\3ds Max Design 2014”
2014-11-24 16:06:54: 0: INFO: Process Priority: BelowNormal
2014-11-24 16:06:54: 0: INFO: Process Affinity: default
2014-11-24 16:06:54: 0: INFO: Process is now running
2014-11-24 16:06:54: 0: INFO: Waiting for connection from 3dsmax
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.000 INFO: Begin setting up global configuration
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.031 INFO: Begin resolve assembly 'Autodesk.Max.Wrappers.XmlSerializers, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null- 16:06:56.031 INFO: Cannot resolve assembly
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.031 INFO: Begin resolve assembly 'Autodesk.Max.Wrappers.XmlSerializers- 16:06:56.031 INFO: Cannot resolve assembly
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.047 INFO: End setting up global configuration
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.047 INFO: Begin initialize system watcher to detect file changes
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.047 INFO: End initialize system watcher to detect file changes
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.047 INFO: Begin loading assemblies
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.047 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\Autodesk.Max.StateSets.dll- 16:06:56.063 INFO: Begin loading assembly file
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.063 INFO: End loading assembly file
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.063 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.094 INFO: Retrieved a list of types, processing
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.094 INFO: Discovered IPlugin-derived type 'Plugin- 16:06:56.094 INFO: Begin resolve assembly 'Autodesk.Max.StateSets.XmlSerializers, Version=16.5.277.0, Culture=neutral, PublicKeyToken=null- 16:06:56.094 INFO: Cannot resolve assembly
2014-11-24 16:06:56: 0: STDOUT: - 16:06:56.094 INFO: Begin resolve assembly 'Autodesk.Max.StateSets.XmlSerializers- 16:06:56.094 INFO: Cannot resolve assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: Created instance of type
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: Adding as startup/static plugin
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: Discovered IPlugin-derived type 'Plugin- 16:06:57.733 INFO: Created instance of type
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: Adding as startup/static plugin
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\Autodesk.Max.Wrappers.dll- 16:06:57.733 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.733 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.749 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\DaylightSimulation.dll- 16:06:57.765 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\FPMaxWpfContent.dll- 16:06:57.765 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\ManagedBootstrap.dll- 16:06:57.765 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\ManagedNetworkUtilities.dll- 16:06:57.765 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\MaterialExplorerView.dll- 16:06:57.765 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\MaxWpfContent.dll- 16:06:57.765 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.765 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\nunit.framework.dll- 16:06:57.780 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\SceneExplorerView.dll- 16:06:57.780 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Begin loading assembly 'C:\Program Files\Autodesk\3ds Max Design 2014\bin\assemblies\Sunlight.dll- 16:06:57.780 INFO: Begin loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: End loading assembly file
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.780 INFO: Begin discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.796 INFO: Retrieved a list of types, processing
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.796 INFO: End discovering pluggable types in assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.796 INFO: End loading assembly
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.796 INFO: End loading assemblies
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.796 INFO: Begin registering loaded plugins
2014-11-24 16:06:57: 0: STDOUT: - 16:06:57.905 INFO: End registering loaded plugins
2014-11-24 16:07:04: 0: STDOUT: - 16:07:04.894 INFO: Begin resolve assembly 'ManagedMC3, Version=7.2.0.0, Culture=neutral, PublicKeyToken=99052d24520ebbb3- 16:07:04.894 INFO: Cannot resolve assembly
2014-11-24 16:07:07: 0: INFO: Connected to 3dsmax plugin: Lightning Aug 20 2014 11:57:56 R
2014-11-24 16:07:07: 0: INFO: Scene file to render: “C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\jobsData\5472a65254449535244d28c2\close_up_livingroom_08.max”
2014-11-24 16:07:07: 0: INFO: Camera: “CLOSEUP_livingRoom_HD”
2014-11-24 16:07:07: 0: INFO: Restarting renderer after each frame: 0
2014-11-24 16:07:07: 0: INFO: Showing frame buffer: 1
2014-11-24 16:07:07: 0: INFO: Overriding render output: “\qvault\Projects\NGP-NewGroundProperty\NGP001 43 Bradshaw Street\02 Design\09 Marketing\3D\Interiors\render\temp\hd-anti_flicker_\anti_flicker_.exr”
2014-11-24 16:07:07: 0: INFO: Overriding save file option: True
2014-11-24 16:07:07: 0: INFO: Frame number base: 0
2014-11-24 16:07:07: 0: INFO: Remove padding from output filename: 0
2014-11-24 16:07:07: 0: INFO: Enable gamma correction: 0
2014-11-24 16:07:07: 0: INFO: Ignore missing external file errors: 1
2014-11-24 16:07:07: 0: INFO: Ignore missing UVW errors: 1
2014-11-24 16:07:07: 0: INFO: Ignore missing XREF errors: 1
2014-11-24 16:07:07: 0: INFO: Ignore missing DLL errors: 0
2014-11-24 16:07:07: 0: INFO: Disabling Multipass: 0
2014-11-24 16:07:07: 0: INFO: The following elements will not be saved
2014-11-24 16:07:07: 0: INFO: CGeometry_ZDepth
2014-11-24 16:07:07: 0: INFO: CShading_Albedo
2014-11-24 16:07:07: 0: INFO: AO
2014-11-24 16:07:07: 0: INFO: WireColor
2014-11-24 16:07:07: 0: INFO: CESSENTIAL_Direct
2014-11-24 16:07:07: 0: INFO: CESSENTIAL_Emission
2014-11-24 16:07:07: 0: INFO: CESSENTIAL_Indirect
2014-11-24 16:07:07: 0: INFO: CESSENTIAL_Reflect
2014-11-24 16:07:07: 0: INFO: CESSENTIAL_Refract
2014-11-24 16:07:07: 0: INFO: CESSENTIAL_Translucency
2014-11-24 16:07:07: 0: INFO: Loading 3dsmax scene file
2014-11-24 16:07:07: 0: STDOUT: - 16:07:07.061 INFO: Begin resolve assembly 'Autodesk.Max.StateSets, Version=16.5.277.0, Culture=neutral, PublicKeyToken=null- 16:07:07.061 INFO: Resolved assembly
2014-11-24 16:07:22: 0: STDOUT: - 16:07:22.943 INFO: Begin resolve assembly 'Autodesk.Max.StateSets.XmlSerializers, Version=16.5.277.0, Culture=neutral, PublicKeyToken=null- 16:07:22.943 INFO: Cannot resolve assembly
2014-11-24 16:07:22: 0: STDOUT: - 16:07:22.943 INFO: Begin resolve assembly 'Autodesk.Max.StateSets.XmlSerializers- 16:07:22.943 INFO: Cannot resolve assembly
2014-11-24 16:07:22: 0: INFO: Scene loaded successfully
2014-11-24 16:07:22: 0: INFO: Executing script: C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\plugins\5472a65254449535244d28c2\customize.ms
2014-11-24 16:07:23: 0: INFO: >Version Information:
2014-11-24 16:07:23: 0: INFO: +OS version: Microsoft Windows NT 6.1.7601 Service Pack 1
2014-11-24 16:07:23: 0: INFO: +3dsMAX, API, SDK version: #(16000, 42, 0)
2014-11-24 16:07:23: 0: INFO: +3dsmax.exe version: 16.5.277.0
2014-11-24 16:07:23: 0: INFO: +Assigned renderer: CoronaRenderer:CoronaRenderer
2014-11-24 16:07:23: 0: INFO: Applying customizations to max file…
2014-11-24 16:07:23: 0: INFO: >Adding scene path ‘C:\Users\render\AppData\Local\Thinkbox\Deadline7\slave\QRND10\jobsData\5472a65254449535244d28c2’ to session paths
2014-11-24 16:07:23: 0: INFO: >General Renderer Settings:
2014-11-24 16:07:23: 0: INFO: +Render Width set to 1280
2014-11-24 16:07:23: 0: INFO: +Render Height set to 720
2014-11-24 16:07:23: 0: INFO: +Pixel Aspect set to 1.0
2014-11-24 16:07:23: 0: INFO: +Atmospherics set to true
2014-11-24 16:07:23: 0: INFO: +Effects set to true
2014-11-24 16:07:23: 0: INFO: +Displacements set to true
2014-11-24 16:07:23: 0: INFO: +Area Lights/Shadows As Points set to true
2014-11-24 16:07:23: 0: INFO: +Force 2-Sided set to false
2014-11-24 16:07:23: 0: INFO: +Render Hidden Geometry set to false
2014-11-24 16:07:23: 0: INFO: +Video Color Check set to false
2014-11-24 16:07:23: 0: INFO: +Super Black set to false
2014-11-24 16:07:23: 0: INFO: +Render To Fields set to false
2014-11-24 16:07:23: 0: INFO: +Skip Existing Frames set to false
2014-11-24 16:07:23: 0: INFO: >Bitmap Pager Settings:
2014-11-24 16:07:23: 0: INFO: +Not overriding Bitmap Pager setting
2014-11-24 16:07:23: 0: INFO: >Render Environment Settings:
2014-11-24 16:07:23: 0: INFO: +Background Color set to (color 0 0 0)
2014-11-24 16:07:23: 0: INFO: +Use Environment Map set to true
2014-11-24 16:07:23: 0: INFO: +Ambient Color set to (color 0 0 0)
2014-11-24 16:07:23: 0: INFO: +Global Light Tint Color set to (color 255 255 255)
2014-11-24 16:07:23: 0: INFO: +Global Light Level set to 1.0
2014-11-24 16:07:23: 0: INFO: >Performing XREF workaround…
2014-11-24 16:07:23: 0: INFO: >Scanning Renderer Paths…
2014-11-24 16:07:23: 0: INFO: >Done Scanning Renderer Paths.
2014-11-24 16:07:23: 0: Plugin rendering frame(s): 20
2014-11-24 16:07:23: 0: INFO: Render Tasks called
2014-11-24 16:07:23: 0: INFO: STARTED
2014-11-24 16:07:24: 0: INFO: Lightning: Render frame 20
2014-11-24 16:07:24: 0: INFO: Lightning: Overriding save file option to 1
2014-11-24 16:07:24: 0: INFO: Lightning: Rendering frame \qvault\Projects\NGP-NewGroundProperty\NGP001 43 Bradshaw Street\02 Design\09 Marketing\3D\Interiors\render\temp\hd-anti_flicker_\anti_flicker_0020.exr
2014-11-24 16:07:24: 0: INFO: Lightning: Rendering 10 render elements
2014-11-24 16:07:24: 0: INFO: Lightning: Setting up render parameters
2014-11-24 16:07:24: 0: INFO: Lightning: Rendering camera node CLOSEUP_livingRoom_HD
2014-11-24 16:07:24: 0: INFO: Lightning: Checking multipass info for frame 20
2014-11-24 16:07:24: 0: INFO: Lightning: Opening renderer
2014-11-24 16:07:24: 0: INFO: Lightning: Multipass disabled
2014-11-24 16:07:24: 0: INFO: Lightning: Rendering 1 passes
2014-11-24 16:07:24: 0: INFO: Lightning: Checking output paths
2014-11-24 16:07:24: 0: INFO: Lightning: Checking default actions
2014-11-24 16:07:24: 0: INFO: Lightning: TYPE_MISSING_EXTERNAL_FILES = IGNORE
2014-11-24 16:07:24: 0: INFO: Lightning: TYPE_MISSING_UVWS = IGNORE
2014-11-24 16:07:24: 0: INFO: Lightning: TYPE_MISSING_DLL_FILES = FAIL
2014-11-24 16:07:24: 0: INFO: Lightning: TYPE_MISSING_XREF_FILES = IGNORE
2014-11-24 16:07:24: 0: INFO: Lightning: Calling renderer

pulse log
2014-11-24 16:06:06: Job Report Scan - Loaded 3 job IDs in 0.000 s
2014-11-24 16:06:06: Job Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 16:06:06: Job Report Scan - Purging old job report files
2014-11-24 16:06:06: Error occurred while deleting job report file:
2014-11-24 16:06:06: Exception Details
2014-11-24 16:06:06: UnauthorizedAccessException – Access to the path ‘\wbox\DeadlineRepository7\reports\jobs\28\7\5472c9be5444952ae4aae287\5472ca839384f80d3089e630.bz2’ is denied.
2014-11-24 16:06:06: Exception.Data: ( )
2014-11-24 16:06:06: Exception.TargetSite: Void WinIOError(Int32, System.String)
2014-11-24 16:06:06: Exception.Source: mscorlib
2014-11-24 16:06:06: Exception.HResult: -2147024891
2014-11-24 16:06:06: Exception.StackTrace:
2014-11-24 16:06:06: at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
2014-11-24 16:06:06: at System.IO.File.InternalDelete(String path, Boolean checkHost)
2014-11-24 16:06:06: at FranticX.IO.File2.Delete(String fileName, Int32 attempts, TimeSpan retryDelay)
2014-11-24 16:06:06: at Deadline.StorageDB.JobStorage.DeleteJobReportFile(Report report)
2014-11-24 16:06:06: Job Report Scan - Purged 1 report files in 31.251 ms
2014-11-24 16:06:06: Job Report Scan - Done.
2014-11-24 16:06:06: Purging Obsolete Slaves
2014-11-24 16:06:06: Obsolete Slave Scan - Skipping because it is disabled in the Repository Options
2014-11-24 16:06:06: Purging Old Slave Reports
2014-11-24 16:06:06: Slave Report Scan - Loading slave report collections
2014-11-24 16:06:06: Slave Report Scan - Found 22 report collections in 0.000 s
2014-11-24 16:06:06: Slave Report Scan - Loading slave IDs
2014-11-24 16:06:06: Slave Report Scan - Loaded 22 slave IDs in 0.000 s
2014-11-24 16:06:06: Slave Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 16:06:06: Slave Report Scan - Done.
2014-11-24 16:06:06: Purging Old Limits
2014-11-24 16:06:06: Old Limit Scan - Loading machine limits
2014-11-24 16:06:06: Old Limit Scan - Found 3 machine limits in 0.000 s
2014-11-24 16:06:06: Old Limit Scan - Loading job IDs
2014-11-24 16:06:06: Old Limit Scan - Loaded 3 job IDs in 0.000 s
2014-11-24 16:06:06: Old Limit Scan - Purged 0 machine limits in 0.000 s
2014-11-24 16:06:06: Old Limit Scan - Done.
2014-11-24 16:06:06: Purging Temporary Repository Files
2014-11-24 16:06:06: Temporary File Scan - Scanning for ‘connectReadWriteTest’ files
2014-11-24 16:06:06: Temporary File Scan - Deleted 0 temporary files in 0.000 s
2014-11-24 16:06:06: Temporary File Scan - Done.
2014-11-24 16:06:06: Purging Old Statistics
2014-11-24 16:06:06: Old Statistics - Skipping job statistics because the option to purge them is disabled in the Repository Options
2014-11-24 16:06:06: Old Statistics - Purging slave statistics that are older than Jul 27/14 16:06:06
2014-11-24 16:06:06: Old Statistics - Purged old slave statistics in 0.000 s
2014-11-24 16:06:06: Old Statistics - Purging repository statistics that are older than Jul 27/14 16:06:06
2014-11-24 16:06:06: Old Statistics - Purged old repository statistics in 0.000 s
2014-11-24 16:06:06: Purging Deleted Document Stubs From Database
2014-11-24 16:06:06: Deleted Document Stubs - Deleting stubs that are older than 3 days
2014-11-24 16:06:06: Deleted Document Stubs - Deleted 0 stubs in 0.000 s
2014-11-24 16:06:06: Triggering House Cleaning Events
2014-11-24 16:06:40: Performing repository repair
2014-11-24 16:06:40: Performing Orphaned Task Scan…
2014-11-24 16:06:40: Orphaned Task Scan - Loading rendering jobs
2014-11-24 16:06:40: Orphaned Task Scan - Loaded 2 rendering jobs in 0.000 s
2014-11-24 16:06:40: Orphaned Task Scan - Scanning for orphaned tasks
2014-11-24 16:06:40: Orphaned Task Scan - Cleaned up 0 orphaned tasks in 0.000 s
2014-11-24 16:06:40: Orphaned Task Scan - Done.
2014-11-24 16:06:40: Performing Orphaned Limit Stub Scan…
2014-11-24 16:06:40: Orphaned Limit Stub Scan - Loading limits
2014-11-24 16:06:40: Orphaned Limit Stub Scan - Loaded 3 limits in 0.000 s
2014-11-24 16:06:40: Orphaned Limit Stub Scan - Loading slave states
2014-11-24 16:06:40: Orphaned Limit Stub Scan - Loaded 22 slave states in 0.000 s
2014-11-24 16:06:40: Orphaned Limit Stub Scan - Returned 0 orphaned limit stubs in 0.000 s
2014-11-24 16:06:40: Orphaned Limit Stub Scan - Done.
2014-11-24 16:06:40: Checking Available Database Connections
2014-11-24 16:06:40: Available Database Connections - Skipping because there are no Low Database Connection notification email addresses set in the Repository Options
2014-11-24 16:06:40: Performing Stalled Slave Scan…
2014-11-24 16:06:40: Stalled Slave Scan - Loading slave states
2014-11-24 16:06:40: Stalled Slave Scan - Loaded 22 slave states in 0.000 s
2014-11-24 16:06:40: Stalled Slave Scan - Scanning slave states
2014-11-24 16:06:40: Stalled Slave Scan - Cleaned up 0 stalled slaves in 0.000 s
2014-11-24 16:06:40: Stalled Slave Scan - Done.
2014-11-24 16:06:40: Performing Stalled Pulse Scan…
2014-11-24 16:06:40: Stalled Pulse Scan - Loading pulse states
2014-11-24 16:06:40: Stalled Pulse Scan - Loaded 1 pulse states in 0.000 s
2014-11-24 16:06:40: Stalled Pulse Scan - Scanning pulse states
2014-11-24 16:06:40: Stalled Pulse Scan - Cleaned up 0 stalled pulses in 0.000 s
2014-11-24 16:06:40: Stalled Pulse Scan - Done.
2014-11-24 16:06:40: Performing Stalled Balancer Scan…
2014-11-24 16:06:40: Stalled Balancer Scan - Loading balancer states
2014-11-24 16:06:40: Stalled Balancer Scan - Loaded 0 balancer states in 0.000 s
2014-11-24 16:06:40: Stalled Balancer Scan - Done.
2014-11-24 16:06:40: Triggering Repository Repair Events
2014-11-24 16:06:49: Performing Pending Job Scan…
2014-11-24 16:06:49: Pending Job Scan - Loading pending and active jobs
2014-11-24 16:06:49: Pending Job Scan - Loaded 2 pending and active jobs in 0.000 s
2014-11-24 16:06:49: Pending Job Scan - Scanning pending and active jobs
2014-11-24 16:06:49: Pending Job Scan - Released 0 pending jobs and 0 pending tasks in 0.000 s
2014-11-24 16:06:49: Pending Job Scan - Done.
2014-11-24 16:06:49: Processing Pending Job Events
2014-11-24 16:06:49: Pending Job Events - Checking for pending job events
2014-11-24 16:06:49: Pending Job Events - Processing 0 job events
2014-11-24 16:06:49: Pending Job Events - No more job events to process
2014-11-24 16:06:49: Pending Job Events - Done.
2014-11-24 16:07:05: Performing house cleaning
2014-11-24 16:07:05: Performing Job Cleanup Scan…
2014-11-24 16:07:05: Job Cleanup Scan - Loading completed jobs
2014-11-24 16:07:05: Job Cleanup Scan - Loaded 1 completed jobs in 0.000 s
2014-11-24 16:07:05: Job Cleanup Scan - Scanning completed jobs
2014-11-24 16:07:05: Job Cleanup Scan - Deleted 0 and archived 0 completed jobs in 0.000 s
2014-11-24 16:07:05: Job Cleanup Scan - Done.
2014-11-24 16:07:05: Purging Unsubmitted Jobs
2014-11-24 16:07:05: Unsubmitted Job Scan - Loading unsubmitted jobs
2014-11-24 16:07:05: Unsubmitted Job Scan - Loaded 0 unsubmitted jobs in 0.000 s
2014-11-24 16:07:05: Unsubmitted Job Scan - Done.
2014-11-24 16:07:05: Purging Deleted Jobs
2014-11-24 16:07:05: Deleted Job Scan - Loading deleted jobs
2014-11-24 16:07:05: Deleted Job Scan - Loaded 0 deleted jobs in 0.000 s
2014-11-24 16:07:05: Deleted Job Scan - Done.
2014-11-24 16:07:05: Purging Old Job Auxiliary Files
2014-11-24 16:07:05: Auxiliary File Scan - Scanning for auxiliary directories
2014-11-24 16:07:05: Auxiliary File Scan - Found 10 auxiliary directories in 0.000 s
2014-11-24 16:07:05: Auxiliary File Scan - Loading job IDs
2014-11-24 16:07:05: Auxiliary File Scan - Loaded 3 job IDs in 0.000 s
2014-11-24 16:07:12: Auxiliary File Scan - Purged 0 auxiliary folders in 6.906 s
2014-11-24 16:07:12: Auxiliary File Scan - Done.
2014-11-24 16:07:12: Purging Old Job Reports
2014-11-24 16:07:12: Job Report Scan - Loading job report collections
2014-11-24 16:07:12: Job Report Scan - Found 5 report collections in 0.000 s
2014-11-24 16:07:12: Job Report Scan - Loading job IDs
2014-11-24 16:07:12: Job Report Scan - Loaded 3 job IDs in 0.000 s
2014-11-24 16:07:12: Job Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 16:07:12: Job Report Scan - Purging old job report files
2014-11-24 16:07:12: Job Report Scan - Purged 0 report files in 0.000 s
2014-11-24 16:07:12: Job Report Scan - Done.
2014-11-24 16:07:12: Purging Obsolete Slaves
2014-11-24 16:07:12: Obsolete Slave Scan - Skipping because it is disabled in the Repository Options
2014-11-24 16:07:12: Purging Old Slave Reports
2014-11-24 16:07:12: Slave Report Scan - Loading slave report collections
2014-11-24 16:07:12: Slave Report Scan - Found 22 report collections in 0.000 s
2014-11-24 16:07:12: Slave Report Scan - Loading slave IDs
2014-11-24 16:07:12: Slave Report Scan - Loaded 22 slave IDs in 0.000 s
2014-11-24 16:07:12: Slave Report Scan - Purged 0 report collections in 0.000 s
2014-11-24 16:07:12: Slave Report Scan - Done.
2014-11-24 16:07:12: Purging Old Limits
2014-11-24 16:07:12: Old Limit Scan - Loading machine limits
2014-11-24 16:07:12: Old Limit Scan - Found 3 machine limits in 0.000 s
2014-11-24 16:07:12: Old Limit Scan - Loading job IDs
2014-11-24 16:07:12: Old Limit Scan - Loaded 3 job IDs in 0.000 s
2014-11-24 16:07:12: Old Limit Scan - Purged 0 machine limits in 0.000 s
2014-11-24 16:07:12: Old Limit Scan - Done.
2014-11-24 16:07:12: Purging Temporary Repository Files
2014-11-24 16:07:12: Temporary File Scan - Scanning for ‘connectReadWriteTest’ files
2014-11-24 16:07:12: Temporary File Scan - Deleted 0 temporary files in 0.000 s
2014-11-24 16:07:12: Temporary File Scan - Done.
2014-11-24 16:07:12: Purging Old Statistics
2014-11-24 16:07:12: Old Statistics - Skipping job statistics because the option to purge them is disabled in the Repository Options
2014-11-24 16:07:12: Old Statistics - Purging slave statistics that are older than Jul 27/14 16:07:12
2014-11-24 16:07:12: Old Statistics - Purged old slave statistics in 0.000 s
2014-11-24 16:07:12: Old Statistics - Purging repository statistics that are older than Jul 27/14 16:07:12
2014-11-24 16:07:12: Old Statistics - Purged old repository statistics in 0.000 s
2014-11-24 16:07:12: Purging Deleted Document Stubs From Database
2014-11-24 16:07:12: Deleted Document Stubs - Deleting stubs that are older than 3 days
2014-11-24 16:07:12: Deleted Document Stubs - Deleted 0 stubs in 0.000 s
2014-11-24 16:07:12: Triggering House Cleaning Events
2014-11-24 16:07:39: Performing repository repair
2014-11-24 16:07:39: Performing Orphaned Task Scan…
2014-11-24 16:07:39: Orphaned Task Scan - Loading rendering jobs
2014-11-24 16:07:39: Orphaned Task Scan - Loaded 2 rendering jobs in 0.000 s
2014-11-24 16:07:39: Orphaned Task Scan - Scanning for orphaned tasks
2014-11-24 16:07:39: Orphaned Task Scan - Cleaned up 0 orphaned tasks in 0.000 s
2014-11-24 16:07:39: Orphaned Task Scan - Done.
2014-11-24 16:07:39: Performing Orphaned Limit Stub Scan…
2014-11-24 16:07:39: Orphaned Limit Stub Scan - Loading limits
2014-11-24 16:07:39: Orphaned Limit Stub Scan - Loaded 3 limits in 0.000 s
2014-11-24 16:07:39: Orphaned Limit Stub Scan - Loading slave states
2014-11-24 16:07:39: Orphaned Limit Stub Scan - Loaded 22 slave states in 0.000 s
2014-11-24 16:07:39: Orphaned Limit Stub Scan - Returned 0 orphaned limit stubs in 0.000 s
2014-11-24 16:07:39: Orphaned Limit Stub Scan - Done.

MikeOwen · November 24, 2014, 8:40am

Hi,

It looks like the user account running Pulse does not have the correct permissions to access the following UNC location:
“\wbox\DeadlineRepository7”
Can you check permissions are good across your setup and possibly re-apply permissions recursively throughout your repository?

rrussell · November 24, 2014, 2:30pm

If you right-click on a job in the Monitor that had this happen to it and select View Job Reports, are there any Stalled Slave Reports in the report viewer? If there are, could you send a few to us? You can right-click on the report in the list to save it. Also, could you right-click on the same job and select View Job History, and send us the contents of the history as well?

Also, I’m not sure how many slaves you have, but would it be possible to send us every slave log and the pulse log for 2014-11-24? We can check each one around the time of 16:06 to see if any of them were responsible for requeuing the task. We’ll need the full log file, so you can just zip all of them up and post them.

We’re currently running a test here with a long running job and 3 slaves rendering it. 2 other non-rendering slaves and Pulse are running, and so far nothing has been requeued, so it doesn’t seem like this bug is still present. Maybe it’s a different bug… hopefully the logs you send us will help.

Thanks!
Ryan

jacobhutson · November 25, 2014, 3:12am

Hi

attached are slave reports, i altered permission to repository folder and changed security to right all
restarted pulse log is attached

10-24 nodes
12 are dedicated ann running rc2, clean install, havent updated non dedicated yet

job history
2014/11/24 15:58:54 jacob (super user) QBOX00 (DC8\jacob): Listed Machine Limit Slaves modified to: [qrnd08]
2014/11/25 09:21:04 thomas (super user) QBOX01 (DC8\thomas): Requeuing Tasks: [31, 1, 11, 22, 38, 46, 55]
2014/11/25 13:04:56 jacob (super user) QBOX00 (DC8\jacob): Viewed History Log

pulse.txt (35.3 KB)
slave log.zip (1.55 MB)

rrussell · November 25, 2014, 2:05pm

Thanks for the logs. So it definitely looks like it’s the Stalled Slave Detection that is resulting in the tasks being requeued. A slave is considered stalled if it hasn’t updated it’s state in the database for a while (the default is 10 minutes), and if a stalled slave was working on a task, that task gets requeued. So this is all normal behavior.

What we need to figure out is why your slaves are being detected as stalled. The first question I have is what OS do you have the database installed on? If it’s a non-Server edition of Windows, you’re likely running into its built-in connection limitation, which could result in the slaves not being able to communicate with the database, and thus not be able to report their state.

I also see that your slaves are appearing orange in the slave list. This is the default color if your slaves are unable to pull a license. What does the License column in the slave list say?

Cheers,
Ryan

jacobhutson · November 25, 2014, 11:10pm

in monitor it shows 2 days til expiry

repository is on windows server 2012 (its also the domain server)
gb lan
all workstations win 7 pro64bit
all in the domain, no firewall, no av on dedicated nodes, all nodes using the same domain user for login

we didnt have this problem in version 6 and up to version 7 beta 6 (i think)
nothing has changed config wise between version 6 and the beta of 7

rrussell · November 26, 2014, 2:09pm

Thanks for the info. Based on this, it shouldn’t be a connection issue.

I took another look at the stalled slave reports, and the machine performing the stalled slave detection is WBOX. Just to confirm, is this the machine that is running Pulse? It’s version number is 7.0.0.47, so it’s definitely running the latest version.

Another thing it could be is the amount of time between when the slaves update their state in the database. In the Monitor, enter Super User Mode, then select Tools -> Configure Repository Options. The select the Performance Settings page, and take a screen shot of the settings here and post the image.

Thanks!
Ryan

jacobhutson · November 27, 2014, 1:39am

yes pulse is running on same box as repository
server 2012

attached is performance page from monitor

rrussell · November 27, 2014, 2:33pm

Everything thing there looks good - you have the default 20 seconds between slave updates, which is well below the 10 minutes before a slave is considered stalled.

I’m really starting to get stumped here.

I took another look through this thread, and realized I had missed the job’s history you had posted:

Is it at all possible that in the most recent case of this issue, the tasks were simply requeued from the Monitor? The slave would behave just like this in this case as well, since its task has changed.

If that’s not the case, it might be best to contact our support team at support[at]thinkboxsoftware[dot]com, and they can set up a remote session to try and figure out what’s going on.

Cheers,
Ryan