sporadic submission times

We have quite random submission times to deadline, for the very same job.

No max file is being copied to the aux folder (they are all on a network location, used from there). Yet submission times range from 6 seconds to 80.

Any idea why that could be?

Looking at procmon while its doing the submission, it seems most of the time is spent doing stuff like this:

1:17:33.4079612 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 119, startime: 987072, endtime: 987072, seqnum: 0, connid: 0
1:17:33.5289595 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 16384, startime: 987073, endtime: 987073, seqnum: 0, connid: 0
1:17:33.5289713 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 2577, startime: 987073, endtime: 987073, seqnum: 0, connid: 0
1:17:33.6194845 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:33.6195046 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 97, seqnum: 0, connid: 0
1:17:33.6228963 PM	deadlinecommand.exe	2656	Thread Create		SUCCESS	Thread ID: 6480
1:17:33.6257146 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 185, startime: 987074, endtime: 987074, seqnum: 0, connid: 0
1:17:33.9393296 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:33.9393430 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 57, seqnum: 0, connid: 0
1:17:33.9396541 PM	deadlinecommand.exe	2656	Thread Exit		SUCCESS	Thread ID: 6480, User Time: 0.0156001, Kernel Time: 0.0000000
1:17:33.9659756 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987078, endtime: 987078, seqnum: 0, connid: 0
1:17:34.0638611 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:34.0638807 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.0685501 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987079, endtime: 987079, seqnum: 0, connid: 0
1:17:34.2278037 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:34.2278289 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.2281412 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987080, endtime: 987080, seqnum: 0, connid: 0
1:17:34.4049274 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:34.4049542 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.4052815 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987082, endtime: 987082, seqnum: 0, connid: 0
1:17:34.5528381 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:34.5528597 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.5531437 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987083, endtime: 987083, seqnum: 0, connid: 0
1:17:34.5912816 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:34.5913084 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.5913285 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.6279127 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987084, endtime: 987084, seqnum: 0, connid: 0
1:17:34.6279375 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:34.6279509 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.6678276 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987084, endtime: 987085, seqnum: 0, connid: 0
1:17:34.7246595 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0
1:17:34.7246733 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 103, seqnum: 0, connid: 0
1:17:34.7249494 PM	deadlinecommand.exe	2656	TCP Send	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 343, startime: 987085, endtime: 987085, seqnum: 0, connid: 0
1:17:34.7614402 PM	deadlinecommand.exe	2656	TCP Receive	lapro3039.scanlinevfxla.com:59925 -> deadline.scanlinevfxla.com:27017	SUCCESS	Length: 4, seqnum: 0, connid: 0

It probably depends on the current network and current mongo load. I’m guessing the 80 second submission times are occurring when the database is under heavy load…