[buildstream] 22/22: TEMP: INFO log pickle length and time

[no...@apache.org]

This is an automated email from the ASF dual-hosted git repository.

not-in-ldap pushed a commit to branch aevri/win32_minimal_seemstowork_20190829
in repository https://gitbox.apache.org/repos/asf/buildstream.git

commit d2d5dfe12208a2dacb205602636da2397a060491
Author: Angelos Evripiotis <je...@bloomberg.net>
AuthorDate: Tue Jul 9 13:07:56 2019 +0100

    TEMP: INFO log pickle length and time
---
 src/buildstream/_scheduler/jobs/job.py | 14 ++++++++++++++
 1 file changed, 14 insertions(+)

diff --git a/src/buildstream/_scheduler/jobs/job.py b/src/buildstream/_scheduler/jobs/job.py
index f192886..a47dbd1 100644
--- a/src/buildstream/_scheduler/jobs/job.py
+++ b/src/buildstream/_scheduler/jobs/job.py
@@ -23,10 +23,12 @@
 import asyncio
 import datetime
 import enum
+import io
 import multiprocessing
 import os
 import signal
 import sys
+import time
 import traceback
 
 # BuildStream toplevel imports
@@ -202,18 +204,30 @@ class Job():
             self._task_id,
         )
 
+        then = time.time()
         pickled = pickle_child_job(child_job, self._scheduler.context)
+        now = time.time()
+        pickled.seek(0, io.SEEK_END)
+        self.message(MessageType.INFO, "pickled len: {:,}".format(pickled.tell()))
+        self.message(MessageType.INFO, "pickle time: {}s".format(round(now - then, 2)))
+        pickled.seek(0)
+        then = time.time()
         self._process = Process(
             target=_do_pickled_child_job,
             args=[pickled, self._queue],
         )
+        now = time.time()
+        self.message(MessageType.INFO, "make process: {}s".format(round(now - then, 2)))
 
         # Block signals which are handled in the main process such that
         # the child process does not inherit the parent's state, but the main
         # process will be notified of any signal after we launch the child.
         #
+        then = time.time()
         with _signals.blocked([signal.SIGINT, signal.SIGTERM], ignore=False):
             self._process.start()
+        now = time.time()
+        self.message(MessageType.INFO, "start process: {}s".format(round(now - then, 2)))
 
         # Wait for the child task to complete.
         #