Added Log facilities like we're used to, and discovered a host of

new wacky things (and possible compiler bugs) on the way.


git-svn-id: svn+ssh://src.earth.threerings.net/narya/trunk@3888 542714f4-19e9-0310-aa3c-eee0fc999fb1

src/as/com/threerings/presents/Log.as

@@ -0,0 +1,36 @@
+package com.threerings.presents {
+
+import mx.logging.ILogger;
+
+import com.threerings.util.LogDaddy;
+
+public class Log extends LogDaddy
+{
+    /** The Logger for this package. */
+    public static var log :ILogger = getLogger("presents");
+
+    /** Convenience function. */
+    public static function debug (message :String, ... rest) :void
+    {
+        log.debug(message, rest);
+    }
+
+    /** Convenience function. */
+    public static function info (message :String, ... rest) :void
+    {
+        log.info(message, rest);
+    }
+
+    /** Convenience function. */
+    public static function warning (message :String, ... rest) :void
+    {
+        log.warn(message, rest);
+    }
+
+    /** Convenience function. */
+    public static function logStackTrace (err :Error) :void
+    {
+        log.warn(err.getStackTrace());
+    }
+}
+}

src/as/com/threerings/presents/client/Client.as

@@ -1,7 +1,5 @@
 package com.threerings.presents.client {
 
-import flash.util.trace;
-
 import flash.events.EventDispatcher;
 import flash.events.TimerEvent;
 import flash.util.Timer;
@@ -16,6 +14,8 @@ import com.threerings.presents.net.Credentials;
 import com.threerings.presents.net.PingRequest;
 import com.threerings.presents.net.PongResponse;
 
+import com.threerings.presents.Log;
+
 public class Client extends EventDispatcher
 {
     /** The default port on which the server listens for client connections. */
@@ -159,7 +159,7 @@ public class Client extends EventDispatcher
     public function logoff (abortable :Boolean) :Boolean
     {
         if (_comm == null) {
-            trace("Ignoring request to log off: not logged on.");
+            Log.warning("Ignoring request to log off: not logged on.");
             return true;
         }
 
@@ -180,7 +180,7 @@ public class Client extends EventDispatcher
     public function gotBootstrap (data :BootstrapData, omgr :DObjectManager)
             :void
     {
-        trace("Got bootstrap " + data + ".");
+        Log.debug("Got bootstrap " + data + ".");
 
         _bstrap = data;
         _omgr = omgr;

src/as/com/threerings/presents/client/ClientDObjectMgr.as

@@ -24,8 +24,6 @@ package com.threerings.presents.client {
 import flash.events.TimerEvent;
 import flash.util.Timer;
 
-import flash.util.trace;
-
 import mx.collections.IList;
 
 import com.threerings.util.ClassUtil;
@@ -48,6 +46,8 @@ import com.threerings.presents.net.SubscribeRequest;
 import com.threerings.presents.net.UnsubscribeRequest;
 import com.threerings.presents.net.UnsubscribeResponse;
 
+import com.threerings.presents.Log;
+
 /**
  * The client distributed object manager manages a set of proxy objects
  * which mirror the distributed objects maintained on the server.
@@ -209,7 +209,7 @@ public class ClientDObjectMgr
         } else if (obj is UnsubscribeResponse) {
             var oid :int = obj.getOid();
             if (_dead[oid] == null) {
-                trace("Received unsub ACK from unknown object " +
+                Log.warning("Received unsub ACK from unknown object " +
                             "[oid=" + oid + "].");
             }
             _dead[oid] = undefined;
@@ -253,8 +253,8 @@ public class ClientDObjectMgr
         var target :DObject = _ocache[toid];
         if (target == null) {
             if (_dead[toid] === undefined) {
-                trace("Unable to dispatch event on non-proxied " +
+                Log.warning("Unable to dispatch event on non-proxied " +
-                      "object [event=" + event + "].");
+                    "object [event=" + event + "].");
             }
             return;
         }
@@ -278,9 +278,9 @@ public class ClientDObjectMgr
             }
 
         } catch (e :Error) {
-            trace("Failure processing event [event=" + event +
+            Log.warning("Failure processing event [event=" + event +
                 ", target=" + target + "].");
-            //Log.logStackTrace(e);
+            Log.logStackTrace(e);
         }
     }
 
@@ -301,8 +301,8 @@ public class ClientDObjectMgr
         var req :PendingRequest = _penders[oid];
         _penders[oid] = undefined;
         if (req == null) {
-            trace("Got object, but no one cares?! " +
+            Log.warning("Got object, but no one cares?! " +
-                  "[oid=" + oid + ", obj=" + obj + "].");
+                "[oid=" + oid + ", obj=" + obj + "].");
             return;
         }
 
@@ -325,7 +325,7 @@ public class ClientDObjectMgr
         var req :PendingRequest = _penders[oid];
         _penders[oid] = undefined;
         if (req == null) {
-            trace("Failed to get object, but no one cares?! " +
+            Log.warning("Failed to get object, but no one cares?! " +
                         "[oid=" + oid + "].");
             return;
         }
@@ -386,7 +386,7 @@ public class ClientDObjectMgr
             dobj.removeSubscriber(target);
 
         } else {
-            trace("Requested to remove subscriber from " +
+            Log.info("Requested to remove subscriber from " +
                      "non-proxied object [oid=" + oid +
                      ", sub=" + target + "].");
         }

src/as/com/threerings/presents/client/Communicator.as

@@ -1,7 +1,5 @@
 package com.threerings.presents.client {
 
-import flash.util.trace;
-
 import flash.events.Event;
 import flash.events.IOErrorEvent;
 
@@ -17,6 +15,8 @@ import com.threerings.io.FrameReader;
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 
+import com.threerings.presents.Log;
+
 import com.threerings.presents.net.AuthRequest;
 import com.threerings.presents.net.AuthResponse;
 import com.threerings.presents.net.AuthResponseData;
@@ -75,7 +75,7 @@ public class Communicator
             try {
                 _socket.close();
             } catch (err :Error) {
-                trace("Error closing failed socket: " + err);
+                Log.warning("Error closing failed socket [error=" + err + "].");
             }
             _socket = null;
             _outStream = null;
@@ -92,7 +92,7 @@ public class Communicator
         // write the message (ends up in _outBuffer)
         _outStream.writeObject(msg);
 
-        //trace("outBuffer: " + Util.bytesToString(_outBuffer));
+        //Log.debug("outBuffer: " + Util.bytesToString(_outBuffer));
 
         // Frame it by writing the length, then the bytes.
         // We add 4 to the length, because the length is of the entire frame
@@ -133,13 +133,15 @@ public class Communicator
     {
         // convert the frame data into a message from the server
         var frameData :ByteArray = event.getFrameData();
-        //trace("length of in frame: " + frameData.length);
+        //Log.debug("length of in frame: " + frameData.length);
-        //trace("inBuffer: " + Util.bytesToString(frameData));
+        //Log.debug("inBuffer: " + Util.bytesToString(frameData));
         _inStream.setSource(frameData);
         var msg :DownstreamMessage =
             (_inStream.readObject() as DownstreamMessage);
         if (frameData.bytesAvailable > 0) {
-            trace("OMG, we didn't fully read the frame. Surely there's a bug");
+            Log.warning("Beans! We didn't fully read a frame, surely there's " +
+                "a bug in some streaming code. " +
+                "[bytesLeftOver=" + frameData.bytesAvailable + "].");
         }
 
         if (_omgr != null) {
@@ -177,7 +179,7 @@ public class Communicator
      */
     protected function socketError (event :IOErrorEvent) :void
     {
-        trace("socketError: " + event);
+        Log.warning("socket error: " + event);
         shutdown(new Error("socket closed unexpectedly."));
     }
 

src/as/com/threerings/presents/client/InvocationDirector.as

@@ -1,17 +1,17 @@
 package com.threerings.presents.client {
 
-import flash.util.trace;
-
 import com.threerings.presents.dobj.DObjectManager;
 
 import com.threerings.presents.data.ClientObject;
 
+import com.threerings.presents.Log;
+
 public class InvocationDirector
 {
     public function init (omgr :DObjectManager, cloid :int, client :Client) :void
     {
         if (_clobj != null) {
-            trace("Zoiks, client object around during invmgr init!");
+            Log.warning("Zoiks, client object around during invmgr init!");
             cleanup();
         }
 

src/as/com/threerings/presents/dobj/DEvent.as

@@ -1,7 +1,6 @@
 package com.threerings.presents.dobj {
 
 import flash.util.StringBuilder;
-import flash.util.trace;
 
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
@@ -9,6 +8,8 @@ import com.threerings.io.Streamable;
 
 import com.threerings.util.Comparable;
 
+import com.threerings.presents.Log;
+
 public /* abstract */ class DEvent
     implements Streamable
 {
@@ -34,7 +35,8 @@ public /* abstract */ class DEvent
      */
     public function applyToObject (target :DObject) :Boolean
     {
-        trace("TODO: abstract methods?");
+        // TODO
+        Log.warning("DEvent.applyToTarget is really an abstract method.");
         return false;
     }
 

src/as/com/threerings/presents/dobj/DObject.as

@@ -1,16 +1,20 @@
 package com.threerings.presents.dobj {
 
 import flash.events.EventDispatcher;
-import flash.util.trace;
+
+import flash.util.StringBuilder;
 
 import mx.collections.ArrayCollection;
 
+import com.threerings.util.ClassUtil;
 import com.threerings.util.Comparable;
 
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 import com.threerings.io.Streamable;
 
+import com.threerings.presents.Log;
+
 public class DObject // extends EventDispatcher
     implements Streamable
 {
@@ -53,7 +57,9 @@ public class DObject // extends EventDispatcher
             _listeners = new ArrayCollection();
 
         } else if (_listeners.contains(listener)) {
-            trace("Refusing repeat listener registration");
+            Log.warning("Refusing repeat listener registration " +
+                "[dobj=" + which() + ", list=" + listener + "].");
+            Log.logStackTrace(new Error());
             return;
         }
         _listeners.addItem(listener);
@@ -84,8 +90,9 @@ public class DObject // extends EventDispatcher
                     listener.eventReceived(event);
                 }
             } catch (e :Error) {
-                trace("Listener choked during notification");
+                Log.warning("Listener choked during notification " +
-                trace(e.getStackTrace());
+                    "[list=" + listener + ", event=" + event + "].");
+                Log.logStackTrace(e);
             }
         }
     }
@@ -102,10 +109,48 @@ public class DObject // extends EventDispatcher
             _omgr.postEvent(event);
 
         } else {
-            trace("Unable to post event, object has no omgr");
+            Log.warning("Unable to post event, object has no omgr " +
+                "[oid=" + getOid() + ", class=" + ClassUtil.getClassName(this) +
+                ", event=" + event + "].");
+            
         }
     }
 
+    /**
+     * Generates a concise string representation of this object.
+     */
+    public function which () :String
+    {
+        var buf :StringBuilder = new StringBuilder();
+        whichBuf(buf);
+        return buf.toString();
+    }
+
+    /**
+     * Used to briefly describe this distributed object.
+     */
+    public function whichBuf (buf :StringBuilder) :void
+    {
+        buf.append(ClassUtil.shortClassName(this), ":", _oid);
+    }
+
+    // documentation inherited
+    public function toString () :String
+    {
+        var buf :StringBuilder = new StringBuilder("[");
+        toStringBuf(buf);
+        buf.append("]");
+        return buf.toString();
+    }
+
+    /**
+     * Generates a string representation of this object.
+     */
+    public function toStringBuf (buf :StringBuilder) :void
+    {
+        buf.append("oid=", _oid);
+    }
+
     public function startTransaction () :void
     {
         // TODO

src/as/com/threerings/presents/dobj/DSet.as

@@ -1,14 +1,14 @@
 package com.threerings.presents.dobj {
 
 import flash.util.StringBuilder;
-import flash.util.trace;
 
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 import com.threerings.io.Streamable;
 
-import  com.threerings.util.Comparable;
+import com.threerings.util.Comparable;
 
+import com.threerings.presents.Log;
 
 /**
  * The distributed set class provides a means by which an unordered set of
@@ -161,7 +161,7 @@ public class DSet
     internal function add (elem :DSetEntry) :Boolean
     {
         if (contains(elem)) {
-            trace("Refusing to add duplicate entry [set=" + this +
+            Log.warning("Refusing to add duplicate entry [set=" + this +
                   ", entry=" + elem + "].");
             return false;
         }
@@ -244,7 +244,7 @@ public class DSet
     // documentation inherited from interface Streamable
     public function writeObject (out :ObjectOutputStream) :void
     {
-        trace("TODO");
+        Log.warning("TODO!");
     }
 
     // documentation inherited from interface Streamable

src/as/com/threerings/presents/dobj/EntryAddedEvent.as

@@ -1,11 +1,12 @@
 package com.threerings.presents.dobj {
 
 import flash.util.StringBuilder;
-import flash.util.trace;
 
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 
+import com.threerings.presents.Log;
+
 /**
  * An entry added event is dispatched when an entry is added to a {@link
  * DSet} attribute of a distributed entry. It can also be constructed to
@@ -48,7 +49,7 @@ public class EntryAddedEvent extends NamedEvent
     {
         var added :Boolean = target[_name].add(_entry);
         if (!added) {
-            trace("Duplicate entry found [event=" + this + "].");
+            Log.warning("Duplicate entry found [event=" + this + "].");
         }
         return true;
     }

src/as/com/threerings/presents/dobj/EntryRemovedEvent.as

@@ -1,13 +1,14 @@
 package com.threerings.presents.dobj {
 
 import flash.util.StringBuilder;
-import flash.util.trace;
     
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 
 import com.threerings.util.Comparable;
 
+import com.threerings.presents.Log;
+
 /**
  * An entry removed event is dispatched when an entry is removed from a
  * {@link DSet} attribute of a distributed object. It can also be
@@ -65,8 +66,8 @@ public class EntryRemovedEvent extends NamedEvent
             _oldEntry = dset.removeKey(_key);
             if (_oldEntry == null) {
                 // complain if there was actually nothing there
-                trace("No matching entry to remove [key=" + _key +
+                Log.warning("No matching entry to remove [key=" + _key +
-                            ", set=" + dset + "].");
+                    ", set=" + dset + "].");
                 return false;
             }
         }

src/as/com/threerings/presents/dobj/EntryUpdatedEvent.as

@@ -1,12 +1,12 @@
 package com.threerings.presents.dobj {
 
-import flash.util.trace;
-
 import flash.util.StringBuilder;
 
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 
+import com.threerings.presents.Log;
+
 /**
  * An entry updated event is dispatched when an entry of a {@link DSet} is
  * updated. It can also be constructed to request the update of an entry
@@ -64,7 +64,7 @@ public class EntryUpdatedEvent extends NamedEvent
             _oldEntry = dset.update(_entry);
             if (_oldEntry == null) {
                 // complain if we didn't update anything
-                trace("No matching entry to update [entry=" + this +
+                Log.warning("No matching entry to update [entry=" + this +
                             ", set=" + dset + "].");
                 return false;
             }

src/as/com/threerings/presents/dobj/OidList.as

@@ -1,6 +1,5 @@
 package com.threerings.presents.dobj {
 
-import flash.util.trace;
 import flash.util.StringBuilder;
 
 import com.threerings.io.Streamable;
@@ -8,6 +7,8 @@ import com.threerings.io.Streamable;
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 
+import com.threerings.presents.Log;
+
 /**
  * An oid list is used to store lists of object ids. The list will not
  * allow duplicate ids. This class is not synchronized, with the
@@ -100,7 +101,7 @@ public class OidList
     // documentation inherited from interface Streamable
     public function writeObject (out :ObjectOutputStream) :void
     {
-        trace("Not implemented");
+        Log.warning("TODO: Not implemented: " + this);
     }
 
     // documentation inherited from interface Streamable

src/as/com/threerings/presents/net/BootstrapData.as

@@ -1,13 +1,13 @@
 package com.threerings.presents.net {
 
-import flash.util.trace;
-
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 import com.threerings.io.Streamable;
 
 import com.threerings.util.StreamableArrayList;
 
+import com.threerings.presents.Log;
+
 /**
  * A BoostrapData object is communicated back to the client
  * after authentication has succeeded and after the server is fully
@@ -26,7 +26,7 @@ public class BootstrapData
     // documentation inherited from interface Streamable
     public function writeObject (out :ObjectOutputStream) :void
     {
-        trace("This is client code: BootstrapData shouldn't be written");
+        Log.warning("This is client code: BootstrapData shouldn't be written");
         //out.writeShort(messageId);
     }
 

src/as/com/threerings/presents/net/DownstreamMessage.as

@@ -1,11 +1,11 @@
 package com.threerings.presents.net {
 
-import flash.util.trace;
-
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 import com.threerings.io.Streamable;
 
+import com.threerings.presents.Log;
+
 public /* abstract */ class DownstreamMessage
     implements Streamable
 {
@@ -17,7 +17,8 @@ public /* abstract */ class DownstreamMessage
     // documentation inherited from interface Streamable
     public function writeObject (out :ObjectOutputStream) :void
     {
-        trace("This is client code: Downstream messages shouldn't be written");
+        Log.warning("This is client code: Downstream messages shouldn't " +
+            "be written");
         //out.writeShort(messageId);
     }
 

src/as/com/threerings/presents/net/UpstreamMessage.as

@@ -1,13 +1,13 @@
 package com.threerings.presents.net {
 
-import flash.util.trace;
-
 import com.threerings.io.Streamable;
 import com.threerings.io.ObjectInputStream;
 import com.threerings.io.ObjectOutputStream;
 
 import com.threerings.util.JavaConstants;
 
+import com.threerings.presents.Log;
+
 public /* abstract */ class UpstreamMessage
     implements Streamable
 {
@@ -35,7 +35,7 @@ public /* abstract */ class UpstreamMessage
     // documentation inherited from interface Streamable
     public function readObject (ins :ObjectInputStream) :void
     {
-        trace("This is client code: Upstream messages shouldn't be read");
+        Log.warning("This is client code: Upstream messages shouldn't be read");
         //messageId = ins.readShort();
     }
 

src/as/com/threerings/util/ClassUtil.as

@@ -7,6 +7,16 @@ public class ClassUtil
         return flash.util.getQualifiedClassName(obj).replace("::", ".");
     }
 
+    public static function shortClassName (obj :Object) :String
+    {
+        var s :String = flash.util.getQualifiedClassName(obj);
+        var dex :int = s.lastIndexOf(".");
+        if (dex != -1) {
+            s = s.substring(dex);
+        }
+        return s.replace("::", ".");
+    }
+
     public static function getClass (obj :Object) :Class
     {
         return flash.util.getClassByName(getClassName(obj));

src/as/com/threerings/util/LogDaddy.as

@@ -0,0 +1,40 @@
+package com.threerings.util {
+
+import mx.logging.ILogger;
+import mx.logging.LogEventLevel;
+
+import mx.logging.targets.TraceTarget;
+
+/**
+ * Jesus Horseradish Christ. I wanted to just call this class Log, but
+ * other classes that don't even import it are getting confused between
+ * this and the subclasses with the same name. It's possible that this
+ * is some wacky compiler bug.
+ */
+public class LogDaddy
+{
+    /**
+     * Retrieve the Logger for the specified package name, and ensure
+     * that our log target is set up.
+     */
+    public static function getLogger (pkg :String) :ILogger
+    {
+        if (_targ == null) {
+            // goddamn I wish we could just have static initializers
+            _targ = new TraceTarget();
+            _targ.filters = ["*"];
+            _targ.level = LogEventLevel.DEBUG;
+            mx.logging.Log.addTarget(_targ);
+            // we could do some stuff here: set up different targets
+            // with different log levels...
+        }
+
+        return mx.logging.Log.getLogger(pkg);
+    }
+
+    /** The logging target for all packages. Needed only because we
+     * cannot have static initializers, so we need to know in getLogger
+     * if we've set up the target yet or not. */
+    private static var _targ :TraceTarget;
+}
+}