From 018250e4e5ec2f4eee05ad7b6c3c4d57e701bb8a Mon Sep 17 00:00:00 2001
From: Griatch <griatch@gmail.com>
Date: Thu, 17 Sep 2015 22:39:48 +0200
Subject: [PATCH] More refined time tracing. It seems the AMP connection is
 really the bottleneck.

---
 evennia/server/amp.py                 | 15 ++++++++++++++-
 evennia/server/portal/telnet.py       |  1 -
 evennia/server/profiling/timetrace.py |  2 +-
 evennia/server/sessionhandler.py      |  2 +-
 4 files changed, 16 insertions(+), 4 deletions(-)

diff --git a/evennia/server/amp.py b/evennia/server/amp.py
index c47b705f65..f5b20c8ced 100644
--- a/evennia/server/amp.py
+++ b/evennia/server/amp.py
@@ -355,6 +355,17 @@ class AMPProtocol(amp.AMP):
                 as batch parts get sent (or fails).
 
         """
+        now = time()
+        batch = dumps([(sessid, kwargs)])
+        hashid = "%s-%s" % (id(batch), now)
+        deferreds = [self.callRemote(command,
+                               hashid=hashid,
+                               data=batch,
+                               ipart=0,
+                               nparts=1).addErrback(self.errback, command.key)]
+        return deferreds
+
+
         global _SENDBATCH
 
         if command:
@@ -472,6 +483,8 @@ class AMPProtocol(amp.AMP):
         batch = self.batch_recv(hashid, data, ipart, nparts)
         for (sessid, kwargs) in batch:
             #print "msg portal -> server (server side):", sessid, msg, loads(ret["data"])
+            from evennia.server.profiling.timetrace import timetrace
+            kwargs["msg"] = timetrace(kwargs["msg"], "AMP.amp_msg_portal2server")
             self.factory.server.sessions.data_in(sessid,
                                              text=kwargs["msg"],
                                              data=kwargs["data"])
@@ -496,7 +509,7 @@ class AMPProtocol(amp.AMP):
         msg = timetrace(msg, "AMP.call_remote_MsgPortal2Server")
         return self.batch_send(MsgPortal2Server, sessid,
                                msg=msg if msg is not None else "",
-                               data=data)
+                               data=data, force_send=True)
 
     # Server -> Portal message
 
diff --git a/evennia/server/portal/telnet.py b/evennia/server/portal/telnet.py
index 4960bd475c..730850de59 100644
--- a/evennia/server/portal/telnet.py
+++ b/evennia/server/portal/telnet.py
@@ -163,7 +163,6 @@ class TelnetProtocol(Telnet, StatefulTelnetProtocol, Session):
             parsed data directly to self.data_in.
 
         """
-
         if data and data[0] == IAC or self.iaw_mode:
             try:
                 #print "IAC mode"
diff --git a/evennia/server/profiling/timetrace.py b/evennia/server/profiling/timetrace.py
index 8f4b7141da..2bf462ec49 100644
--- a/evennia/server/profiling/timetrace.py
+++ b/evennia/server/profiling/timetrace.py
@@ -29,7 +29,7 @@ def timetrace(message, idstring, tracemessage="TEST_MESSAGE", final=False):
         else:
             t1 = time()
         # print to log (important!)
-        print "timetrace (%s): dT=%fs, total=%fs." % (idstring, t1-tlast, t1-t0)
+        print "** timetrace (%s): dT=%fs, total=%fs." % (idstring, t1-tlast, t1-t0)
 
         if final:
             message = "%s (total %f)" % (tracemessage, t1-t0)
diff --git a/evennia/server/sessionhandler.py b/evennia/server/sessionhandler.py
index 315a7dd429..c8efb59a42 100644
--- a/evennia/server/sessionhandler.py
+++ b/evennia/server/sessionhandler.py
@@ -602,7 +602,7 @@ class ServerSessionHandler(SessionHandler):
 
         """
         from evennia.server.profiling.timetrace import timetrace
-        text = timetrace(text, "ServerSession.data_in")
+        text = timetrace(text, "ServerSessionHandler.data_in")
         session = self.sessions.get(sessid, None)
         if session:
             text = text and to_unicode(strip_control_sequences(text), encoding=session.encoding)