Merge pull request #2331 from effigies/profile/vms

ENH: Profile VMS as well as RSS

Author: oesteban

nipype/interfaces/base/core.py

@@ -530,8 +530,9 @@ def run(self, **inputs):
 
                     runtime.prof_dict = {
                         'time': vals[:, 0].tolist(),
-                        'mem_gb': (vals[:, 1] / 1024).tolist(),
-                        'cpus': vals[:, 2].tolist(),
+                        'cpus': vals[:, 1].tolist(),
+                        'rss_GiB': (vals[:, 2] / 1024).tolist(),
+                        'vms_GiB': (vals[:, 3] / 1024).tolist(),
                     }
 
         return results

nipype/pipeline/engine/utils.py

@@ -1320,7 +1320,8 @@ def write_workflow_resources(graph, filename=None, append=None):
         'time': [],
         'name': [],
         'interface': [],
-        'mem_gb': [],
+        'rss_GiB': [],
+        'vms_GiB': [],
         'cpus': [],
         'mapnode': [],
         'params': [],
@@ -1361,7 +1362,7 @@ def write_workflow_resources(graph, filename=None, append=None):
                     '(mapflow %d/%d).', nodename, subidx + 1, len(rt_list))
                 continue
 
-            for key in ['time', 'mem_gb', 'cpus']:
+            for key in ['time', 'cpus', 'rss_GiB', 'vms_GiB']:
                 big_dict[key] += runtime.prof_dict[key]
 
             big_dict['interface'] += [classname] * nsamples

nipype/utils/profiler.py

@@ -67,11 +67,14 @@ def stop(self):
 
     def _sample(self, cpu_interval=None):
         cpu = 0.0
-        mem = 0.0
+        rss = 0.0
+        vms = 0.0
         try:
             with self._process.oneshot():
                 cpu += self._process.cpu_percent(interval=cpu_interval)
-                mem += self._process.memory_info().rss
+                mem_info = self._process.memory_info()
+                rss += mem_info.rss
+                vms += mem_info.vms
         except psutil.NoSuchProcess:
             pass
 
@@ -85,19 +88,24 @@ def _sample(self, cpu_interval=None):
             try:
                 with child.oneshot():
                     cpu += child.cpu_percent()
-                    mem += child.memory_info().rss
+                    mem_info = child.memory_info()
+                    rss += mem_info.rss
+                    vms += mem_info.vms
             except psutil.NoSuchProcess:
                 pass
 
-        print('%f,%f,%f' % (time(), (mem / _MB), cpu),
+        print('%f,%f,%f,%f' % (time(), cpu, rss / _MB, vms / _MB),
               file=self._logfile)
         self._logfile.flush()
 
     def run(self):
         """Core monitoring function, called by start()"""
+        start_time = time()
+        wait_til = start_time
         while not self._event.is_set():
             self._sample()
-            self._event.wait(self._freq)
+            wait_til += self._freq
+            self._event.wait(max(0, wait_til - time()))
 
 
 # Log node stats function