OSX: Unresponsive launcher, massive memory usage

nrusch · March 2, 2015, 11:39pm

I have a launcher process on an OSX slave that does not respond to remote commands (including trying to stop it), and is using a ton of memory (RSS: 1967356). It has been running since February 14th, and the last launcher log file is from 2/19, last modified around 8 PM.

This is using 6.2.1.50 on Mavericks, and it seems to happen after a certain amount of time no matter what.

I’ve created and uploaded a bzipped core snapshot generated with gcore. It can be downloaded here: we.tl/AxpkNPdNu4

eamsler · March 3, 2015, 6:16pm

Poking at this now.

Best guess is that it stopped growing because it was running as a 32bit program. It would explain why it’s completely locked up as well.

Now to learn some LLDB and brush up my gdb skills.

eamsler · March 3, 2015, 6:21pm

This looks really interesting for the OS X issues:
developer.apple.com/library/ios … Leaks.html

I have no idea what leaks is going to return for the buffer contents, but I’m interested to see.

eamsler · March 3, 2015, 6:46pm

Well, after much poking I’ve run out of time for today.

If you can get some output from leaks that would be great. I’m still trying to find out how to see the leaked objects. The launcher doesn’t do much, so I’m not sure.

eamsler · March 3, 2015, 8:08pm

One more update (and so that I quadruple post destroying all forum etiquette), it turns out we may have fixed this for 7.1.

Are there a lot of remote commands being sent to this launcher? I’m told we had a leak during some instances of process creation that’s been cleaned up.

nrusch · March 3, 2015, 8:37pm

No, not at all. I looked through some of the older logs, and I think I can give you a better idea of the timeline of all this.

Launcher started (2015/02/14 18:37:55)
Over the next ~4 days, there are maybe 4 or 5 remote commands sent to the launcher.
Then on 2/18, this happens:

2015-02-18 21:05:23: Updating Repository options 2015-02-18 21:05:23: - Remote Administration: enabled 2015-02-18 21:05:23: - Automatic Updates: disabled 2015-02-18 21:10:23: Updating Repository options 2015-02-18 21:10:23: - Remote Administration: enabled 2015-02-18 21:10:23: - Automatic Updates: disabled 2015-02-18 21:10:29: Launcher Thread - OnConnect: SocketException occured: Invalid arguments 2015-02-18 21:10:29: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:10:29: Exception Details 2015-02-18 21:10:29: SocketException -- Invalid arguments 2015-02-18 21:10:29: SocketException.ErrorCode: 10022 (Invalid arguments) 2015-02-18 21:10:29: SocketException.SocketErrorCode: InvalidArgument (10022) 2015-02-18 21:10:29: Win32Exception.NativeErrorCode: 10022 2015-02-18 21:10:29: Exception.Source: System 2015-02-18 21:10:29: Exception.TargetSite: System.Net.EndPoint get_RemoteEndPoint() 2015-02-18 21:10:29: Exception.Data: ( ) 2015-02-18 21:10:29: Exception.StackTrace: 2015-02-18 21:10:29: at System.Net.Sockets.Socket.get_RemoteEndPoint () [0x00000] in <filename unknown>:0 2015-02-18 21:10:29: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:10:29: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:10:29: Launcher Thread - OnConnect: Restarting Launcher Thread because it exited prematurely!! (System.Exception) 2015-02-18 21:10:29: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:10:29: Exception Details 2015-02-18 21:10:29: Exception -- Restarting Launcher Thread because it exited prematurely!! 2015-02-18 21:10:29: Exception.Data: ( ) 2015-02-18 21:10:29: Exception.StackTrace: 2015-02-18 21:10:29: (null) 2015-02-18 21:10:29: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:10:29: Launcher Thread - Waiting 5 seconds to restart the thread. 2015-02-18 21:11:45: ::ffff:100.100.100.66 has connected 2015-02-18 21:11:56: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:11:56: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:06: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:12:06: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:15: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:12:17: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:26: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for commands. Connection will be closed 2015-02-18 21:12:26: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:36: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:12:36: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:36: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:12:36: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:12:36: Exception Details 2015-02-18 21:12:36: OutOfMemoryException -- Out of memory 2015-02-18 21:12:36: Exception.Source: franticx 2015-02-18 21:12:36: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:12:36: Exception.Data: ( ) 2015-02-18 21:12:36: Exception.StackTrace: 2015-02-18 21:12:36: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:12:36: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:12:36: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:12:36: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:12:36: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:12:36: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:12:36: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:47: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:12:47: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:47: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:12:47: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:12:47: Exception Details 2015-02-18 21:12:47: OutOfMemoryException -- Out of memory 2015-02-18 21:12:47: Exception.Source: franticx 2015-02-18 21:12:47: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:12:47: Exception.Data: ( ) 2015-02-18 21:12:47: Exception.StackTrace: 2015-02-18 21:12:47: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:12:47: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:12:47: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:12:47: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:12:47: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:12:47: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:12:47: ::ffff:100.100.100.66 has connected 2015-02-18 21:12:57: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:12:57: ::ffff:100.100.100.66 has connected 2015-02-18 21:13:08: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for commands. Connection will be closed 2015-02-18 21:13:08: ::ffff:100.100.100.66 has connected 2015-02-18 21:13:08: Launcher Thread - Exception (::ffff:100.100.100.66): Number overflow. 2015-02-18 21:13:08: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:13:08: Exception Details 2015-02-18 21:13:08: OverflowException -- Number overflow. 2015-02-18 21:13:08: Exception.Source: franticx 2015-02-18 21:13:08: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:13:08: Exception.Data: ( ) 2015-02-18 21:13:08: Exception.StackTrace: 2015-02-18 21:13:08: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:13:08: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:13:08: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:13:08: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:13:08: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:13:08: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:13:08: ::ffff:100.100.100.66 has connected 2015-02-18 21:13:17: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:13:29: ::ffff:100.100.100.66 has connected 2015-02-18 21:13:39: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:13:39: ::ffff:100.100.100.66 has connected 2015-02-18 21:13:39: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:13:39: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:13:39: Exception Details 2015-02-18 21:13:39: OutOfMemoryException -- Out of memory 2015-02-18 21:13:39: Exception.Source: franticx 2015-02-18 21:13:39: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:13:39: Exception.Data: ( ) 2015-02-18 21:13:39: Exception.StackTrace: 2015-02-18 21:13:39: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:13:39: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:13:39: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:13:39: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:13:39: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:13:39: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:14:00: ::ffff:100.100.100.66 has connected 2015-02-18 21:14:09: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for commands. Connection will be closed 2015-02-18 21:14:42: ::ffff:100.100.100.66 has connected 2015-02-18 21:14:42: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:14:42: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:14:42: Exception Details 2015-02-18 21:14:42: OutOfMemoryException -- Out of memory 2015-02-18 21:14:42: Exception.Source: franticx 2015-02-18 21:14:42: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:14:42: Exception.Data: ( ) 2015-02-18 21:14:42: Exception.StackTrace: 2015-02-18 21:14:42: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:14:42: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:14:42: ::ffff:100.100.100.66 has connected 2015-02-18 21:14:42: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:14:42: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:14:42: Exception Details 2015-02-18 21:14:42: OutOfMemoryException -- Out of memory 2015-02-18 21:14:42: Exception.Source: franticx 2015-02-18 21:14:42: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:14:42: Exception.Data: ( ) 2015-02-18 21:14:42: Exception.StackTrace: 2015-02-18 21:14:42: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:14:42: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:14:42: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:15:06: ::ffff:100.100.100.66 has connected 2015-02-18 21:15:17: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for commands. Connection will be closed 2015-02-18 21:15:17: ::ffff:100.100.100.66 has connected 2015-02-18 21:15:17: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:15:17: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:15:17: Exception Details 2015-02-18 21:15:17: OutOfMemoryException -- Out of memory 2015-02-18 21:15:17: Exception.Source: franticx 2015-02-18 21:15:17: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:15:17: Exception.Data: ( ) 2015-02-18 21:15:17: Exception.StackTrace: 2015-02-18 21:15:17: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:15:17: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:15:17: ::ffff:100.100.100.66 has connected 2015-02-18 21:15:17: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:15:17: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:15:17: Exception Details 2015-02-18 21:15:17: OutOfMemoryException -- Out of memory 2015-02-18 21:15:17: Exception.Source: franticx 2015-02-18 21:15:17: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:15:17: Exception.Data: ( ) 2015-02-18 21:15:17: Exception.StackTrace: 2015-02-18 21:15:17: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:15:17: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:15:17: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:15:23: Updating Repository options 2015-02-18 21:15:23: - Remote Administration: enabled 2015-02-18 21:15:23: - Automatic Updates: disabled 2015-02-18 21:16:09: ::ffff:100.100.100.66 has connected 2015-02-18 21:16:09: Launcher Thread - Exception (::ffff:100.100.100.66): Out of memory 2015-02-18 21:16:09: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:16:09: Exception Details 2015-02-18 21:16:09: OutOfMemoryException -- Out of memory 2015-02-18 21:16:09: Exception.Source: franticx 2015-02-18 21:16:09: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:16:09: Exception.Data: ( ) 2015-02-18 21:16:09: Exception.StackTrace: 2015-02-18 21:16:09: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:16:09: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:16:09: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:16:09: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:16:09: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:16:09: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:16:17: ::ffff:100.100.100.66 has connected 2015-02-18 21:16:27: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:16:27: ::ffff:100.100.100.66 has connected 2015-02-18 21:16:38: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:16:38: ::ffff:100.100.100.66 has connected 2015-02-18 21:16:47: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:16:47: ::ffff:100.100.100.66 has connected 2015-02-18 21:16:57: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for data. Connection will be closed 2015-02-18 21:17:59: ::ffff:100.100.100.66 has connected 2015-02-18 21:17:59: Launcher Thread - Received command: 2015-02-18 21:17:59: Launcher Thread - Responded with: 2015-02-18 21:19:12: ::ffff:100.100.100.66 has connected 2015-02-18 21:19:23: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for commands. Connection will be closed 2015-02-18 21:20:03: ::ffff:100.100.100.66 has connected 2015-02-18 21:20:14: Launcher Thread - SimpleSocketException (::ffff:100.100.100.66): timed out while waiting for commands. Connection will be closed 2015-02-18 21:20:23: Updating Repository options 2015-02-18 21:20:23: - Remote Administration: enabled 2015-02-18 21:20:23: - Automatic Updates: disabled 2015-02-18 21:21:23: ::ffff:100.100.100.66 has connected 2015-02-18 21:21:23: Launcher Thread - Exception (::ffff:100.100.100.66): Number overflow. 2015-02-18 21:21:23: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:21:23: Exception Details 2015-02-18 21:21:23: OverflowException -- Number overflow. 2015-02-18 21:21:23: Exception.Source: franticx 2015-02-18 21:21:23: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:21:23: Exception.Data: ( ) 2015-02-18 21:21:23: Exception.StackTrace: 2015-02-18 21:21:23: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:21:23: ::ffff:100.100.100.66 has connected 2015-02-18 21:21:23: Launcher Thread - Exception (::ffff:100.100.100.66): Number overflow. 2015-02-18 21:21:23: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:21:23: Exception Details 2015-02-18 21:21:23: OverflowException -- Number overflow. 2015-02-18 21:21:23: Exception.Source: franticx 2015-02-18 21:21:23: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:21:23: Exception.Data: ( ) 2015-02-18 21:21:23: Exception.StackTrace: 2015-02-18 21:21:23: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:21:23: ::ffff:100.100.100.66 has connected 2015-02-18 21:21:23: Launcher Thread - Exception (::ffff:100.100.100.66): Number overflow. 2015-02-18 21:21:23: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:21:23: Exception Details 2015-02-18 21:21:23: OverflowException -- Number overflow. 2015-02-18 21:21:23: Exception.Source: franticx 2015-02-18 21:21:23: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:21:23: Exception.Data: ( ) 2015-02-18 21:21:23: Exception.StackTrace: 2015-02-18 21:21:23: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:21:23: ::ffff:100.100.100.66 has connected 2015-02-18 21:21:23: Launcher Thread - Exception (::ffff:100.100.100.66): Number overflow. 2015-02-18 21:21:23: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:21:23: Exception Details 2015-02-18 21:21:23: OverflowException -- Number overflow. 2015-02-18 21:21:23: Exception.Source: franticx 2015-02-18 21:21:23: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:21:23: Exception.Data: ( ) 2015-02-18 21:21:23: Exception.StackTrace: 2015-02-18 21:21:23: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:21:23: ::ffff:100.100.100.66 has connected 2015-02-18 21:21:23: Launcher Thread - Exception (::ffff:100.100.100.66): Number overflow. 2015-02-18 21:21:23: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2015-02-18 21:21:23: Exception Details 2015-02-18 21:21:23: OverflowException -- Number overflow. 2015-02-18 21:21:23: Exception.Source: franticx 2015-02-18 21:21:23: Exception.TargetSite: System.Byte[] ReadBytes(System.Net.Sockets.NetworkStream, Int32, Int32) 2015-02-18 21:21:23: Exception.Data: ( ) 2015-02-18 21:21:23: Exception.StackTrace: 2015-02-18 21:21:23: at (wrapper managed-to-native) object:__icall_wrapper_mono_array_new_specific (intptr,int) 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.ReadBytes (System.Net.Sockets.NetworkStream networkStream, Int32 length, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at FranticX.Net.SocketUtils.RecvMessage (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds, Int32 maxMessageLength) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.WaitForCommands (System.Net.Sockets.NetworkStream networkStream, Int32 timeoutMilliseconds) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: at Deadline.Launcher.LauncherThread.OnConnect (IAsyncResult ar) [0x00000] in <filename unknown>:0 2015-02-18 21:21:23: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2015-02-18 21:25:23: Updating Repository options 2015-02-18 21:25:23: - Remote Administration: enabled 2015-02-18 21:25:23: - Automatic Updates: disabled 2015-02-18 21:30:23: Updating Repository options 2015-02-18 21:30:23: - Remote Administration: enabled 2015-02-18 21:30:23: - Automatic Updates: disabled 2015-02-18 21:35:23: Updating Repository options 2015-02-18 21:35:23: - Remote Administration: enabled 2015-02-18 21:35:23: - Automatic Updates: disabled

As you can see, after all of this, the launcher seems to continue on unaffected, and continues printing updates until 2/19 at 20:10:49, when the log stops being updated.

eamsler · March 6, 2015, 10:56pm

So, just a heads up that I’ve found some things that might help us track down some allocation problems.

I want to give this a go, but I need to practice with it a bit:
mono-project.com/docs/debug+ … /heapshot/

It should show us what exactly is being allocated into program memory. Mainly we’ll use the profiler and dig through that stuff after execution. My quick tests on OS X didn’t give me an output file, so I want to practice on Linux for a bit to get myself sturdy on it.

eamsler · March 13, 2015, 8:05pm

Alright folks! I have come bearing information on the Mono profiler, and it’s pretty fancy!

Firstly if you think you may have a leaky instance of Deadline, look for Python.net leaks by using the ‘dump python objects’ under the ‘help’ menu. There’s some weird allocation stuff that can happen in there, and you’ll get a list both in the Monitor’s console panel (see the ‘view’ menu), or in the application log of whatever you performed the command on. Note that you’ll need to run Slave/Launcher/Pulse/whatever with the UI available to do this. That text will be really helpful for us.

For Mono leaks (which even more uncommon), we can use the log profiler:
mono-project.com/docs/debug+ … /profiler/

It boils down to running this (Linux is my example here):

sudo yum install mono-devel
cd /opt/Thinkbox/Deadline7/bin
./mono --profile=log:heapshot=600000ms,output=%p-output.mlpd,zip deadlineslave.exe -nogui

That will start dumping a list of allocated objects every 10 minutes to a file in the current directory called “[pid]-output.mlpd” where “[pid]” is Mono’s process id. Leaving this run while the leaks are happening should give us a good history of what’s been allocated and what’s hanging around. Very similar to how the ‘dump python objects’ works in the Monitor.

I’m sure this is doable on the Mac as well, but I need to find out how to get the mono-devel package equivalent into OS X so our Mono can find it.

In any case, if you want to look at the output of that, just run it through mprof-report which should have come along with the ‘mono-devel’ package:

# Replace '[pid]' with the process ID mono is/was running as
mprof-report [pid]-output.mlpd  | less

Sending it to us is always appreciated, so if you have a delivery mechanism for big files, just send us a link. If you don’t have something, we can give you a link to our Box account.

nrusch · March 18, 2015, 1:12am

Thanks for the information Edwin. Unfortunately, running Launchers in GUI mode is not really realistic for us, so I’m not really going to be able to use the “Dump Python objects” tool.

As for the Mono profiler, am I correct in thinking that that can only be used if you start a process from scratch, or is there a way to attach it to a running process?

eamsler · March 18, 2015, 6:19pm

Bad news on both I’m afraid.

So far we don’t have anything that could dump the Python objects from a CLI. I’ll ask Jon if it would be possible via a secret remote command or something triggerable from Deadline Command. That’s obviously not going to be helpful for you since the feature would come in 7.1 at the earliest.

For the profiler, near as I can tell there’s no way than to run it fresh.

Not great… I’ll try and see what we can do to make this better anyway.

eamsler · March 18, 2015, 8:32pm

Update:

Jon just used this, so you can run a Python script through Launcher / Slave using the same code:
docs.python.org/2/library/gc.html

The function he used was this:

gc.get_objects()

So, if you’re game giving that a go that should be the tool you need. If you want me to wrap that up for you in a handy Python script, just let me know.

[code] for o in gc.get_objects():
t = type( o )

        if useStrRep:
            t = str( t )

        count = result.get( t, 0 )
        result[t] = count + 1[/code]