Framework for issue 293: Need better logging for j3d error, warning, assertion messages.

Added logging capability for some error messages and for rendering stats


git-svn-id: https://svn.java.net/svn/j3d-core~svn/trunk@815 ba19aa83-45c5-6ac9-afd3-db810772062c

12 files changed, 411 insertions, 323 deletions

diff --git a/src/classes/share/javax/media/j3d/BranchGroupRetained.java b/src/classes/share/javax/media/j3d/BranchGroupRetained.java
index e9b0957..ca3b1a6 100644
--- a/src/classes/share/javax/media/j3d/BranchGroupRetained.java
+++ b/src/classes/share/javax/media/j3d/BranchGroupRetained.java
@@ -116,8 +116,7 @@ class BranchGroupRetained extends GroupRetained {
 
                 } else {
 		    // XXXX: change this to an assertion exception
-                    System.out.println("Can't Find matching hashKey in setNodeData.");
-                    System.out.println("We're in TROUBLE!!!");
+                    MasterControl.getCoreLogger().severe("Can't Find matching hashKey in setNodeData.");
                 }
             }
         }
diff --git a/src/classes/share/javax/media/j3d/ImageComponent2D.java b/src/classes/share/javax/media/j3d/ImageComponent2D.java
index 0d0164b..a69bf46 100644
--- a/src/classes/share/javax/media/j3d/ImageComponent2D.java
+++ b/src/classes/share/javax/media/j3d/ImageComponent2D.java
@@ -14,6 +14,7 @@ package javax.media.j3d;
 
 import java.awt.image.BufferedImage;
 import java.awt.image.RenderedImage;
+import java.util.logging.Level;
 
 /**
  * This class defines a 2D image component.  This is used for texture
@@ -74,7 +75,7 @@ public class ImageComponent2D extends ImageComponent {
 			    int		width,
 			    int		height) {
 
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.FINER)) {
             MasterControl.getDevLogger().finer("ImageComponent - using default of byCopy");            
         }
         ((ImageComponent2DRetained)this.retained).processParams(format, width, height, 1);
@@ -94,7 +95,7 @@ public class ImageComponent2D extends ImageComponent {
      */
     public ImageComponent2D(int format, BufferedImage image) {
 
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.FINER)) {
             MasterControl.getDevLogger().finer("ImageComponent - using default of byCopy");            
         }
         ((ImageComponent2DRetained)this.retained).processParams(format, image.getWidth(), image.getHeight(), 1);
@@ -118,7 +119,7 @@ public class ImageComponent2D extends ImageComponent {
     public ImageComponent2D(int format, RenderedImage image) {
 
 
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.FINER)) {
             MasterControl.getDevLogger().finer("ImageComponent - using default of byCopy");            
         }
 	((ImageComponent2DRetained)this.retained).processParams(format, image.getWidth(), image.getHeight(), 1);
@@ -153,7 +154,7 @@ public class ImageComponent2D extends ImageComponent {
 			    boolean	byReference,
 			    boolean	yUp) {
 
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.INFO)) {
             if (byReference && !yUp) {
                 MasterControl.getDevLogger().info("ImageComponent - yUp should " +
                         "be set when using byReference, " +
@@ -190,7 +191,7 @@ public class ImageComponent2D extends ImageComponent {
 			    boolean byReference,
 			    boolean yUp) {
 
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.INFO)) {
             if (byReference && !yUp) {
                 MasterControl.getDevLogger().info("ImageComponent - yUp should " +
                         "be set when using byReference, " +
@@ -231,7 +232,7 @@ public class ImageComponent2D extends ImageComponent {
                             boolean byReference,
                             boolean yUp) {
 
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.INFO)) {
             if (byReference && !yUp)
                 MasterControl.getDevLogger().info("ImageComponent - yUp should " +
                         "be set when using byReference, " +
diff --git a/src/classes/share/javax/media/j3d/ImageComponentRetained.java b/src/classes/share/javax/media/j3d/ImageComponentRetained.java
index 6ebb2a8..1fe18ef 100644
--- a/src/classes/share/javax/media/j3d/ImageComponentRetained.java
+++ b/src/classes/share/javax/media/j3d/ImageComponentRetained.java
@@ -22,6 +22,7 @@ import java.awt.image.RenderedImage;
 import java.nio.ByteBuffer;
 import java.nio.ByteOrder;
 import java.nio.IntBuffer;
+import java.util.logging.Level;
 
 
 /**
@@ -1196,10 +1197,10 @@ abstract class ImageComponentRetained extends NodeComponentRetained {
     void copyUnsupportedNioImageToImageData(NioImageBuffer nioImage, int srcX, int srcY,
             int dstX, int dstY, int copyWidth, int copyHeight, ImageData iData) {
 
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.INFO)) {
             MasterControl.getDevLogger().info("ImageComponent - Copying Unsupported NioImage, use a different image type");
         }
-        
+
         assert (iData.getType() == ImageDataType.TYPE_BYTE_BUFFER);
         assert (getImageFormatType() == ImageFormatType.TYPE_BYTE_RGBA);  
         
@@ -1225,7 +1226,7 @@ abstract class ImageComponentRetained extends NodeComponentRetained {
         
         assert (data.getType() == ImageDataType.TYPE_BYTE_ARRAY);
         
-        if (MasterControl.logDevIssues) {
+        if (MasterControl.isDevLoggable(Level.INFO)) {
             MasterControl.getDevLogger().info("ImageComponent - Copying Unsupported Image, use a different image type");
         }
         
diff --git a/src/classes/share/javax/media/j3d/MasterControl.java b/src/classes/share/javax/media/j3d/MasterControl.java
index f2ad82c..95d6489 100644
--- a/src/classes/share/javax/media/j3d/MasterControl.java
+++ b/src/classes/share/javax/media/j3d/MasterControl.java
@@ -70,12 +70,20 @@ class MasterControl {
     static final Integer SET_QUERYPROPERTIES = new Integer(20);    
     static final Integer SET_VIEW = new Integer(21);
 
-    // Developer logger to report informational messages; see getDevLogger()
-    private static Logger devLogger = null;
-    
-    // Flag indicating whether devLogger is enabled
-    static boolean logDevIssues = false;
+    // Developer logger for reporting informational messages; see getDevLogger()
+    private static boolean devLoggerEnabled = false;
+    private static Logger devLogger;
+
+    // Stats logger for reporting runtime statistics; see getStatsLogger()
+    private static boolean statsLoggerEnabled = false;
+    private static Logger statsLogger;
+
+    // Core logger for reporting internal errors, warning, and
+    // informational messages; see getCoreLogger()
+    private static boolean coreLoggerEnabled = false;
+    private static Logger coreLogger;
 
+    // Flag indicating that the rendering pipeline libraries are loaded
     private static boolean librariesLoaded = false;
 
     /**
@@ -696,31 +704,80 @@ class MasterControl {
 	    canvasIds[i] = false;
 	}
         canvasFreeIndex = 0;
+    }
 
-        if (devLogger==null) {
-            devLogger = Logger.getLogger("j3d.developer");
-            final Logger fLogger = devLogger;
-            java.security.AccessController.doPrivileged(
-                new java.security.PrivilegedAction() {
-                    public Object run() {
-                        String levelStr = System.getProperty("j3d.developer.level");
-                        if (levelStr != null) {
-                            try {
-                                fLogger.setLevel( Level.parse(levelStr) );
-                                System.err.println("Java 3D: Developer logger level = " +
-                                        fLogger.getLevel().getName());
-                            } catch (IllegalArgumentException ex) {
-                                System.err.println("Java 3D: Unrecognized developer logger level : " + levelStr);
-                            } catch (Exception ex) {
-                                System.err.println(ex);
-                                System.err.println("Java 3D: Error setting developer logger level : "+ levelStr);
-                            }
-                        }
-                        return null;
-                    }
-                });
-            logDevIssues = ((devLogger.getLevel()!=null) && (devLogger.getLevel()!=Level.OFF));
+    private static Logger createLogger(String loggerName, Level defaultLevel) {
+        Logger logger = Logger.getLogger(loggerName);
+
+        if (defaultLevel != null && logger.getLevel() == null &&
+                logger.getLogger("j3d").getLevel() == null) {
+
+            // Set default logger level rather than inheriting from system global
+            logger.setLevel(defaultLevel);
         }
+
+        return logger;
+    }
+
+    // Called by the static initializer to initialize the loggers
+    private static void initLoggers() {
+        devLogger = createLogger("j3d.developer", Level.OFF);
+        devLoggerEnabled = devLogger.isLoggable(Level.SEVERE);
+        statsLogger = createLogger("j3d.stats", Level.OFF);
+        statsLoggerEnabled = statsLogger.isLoggable(Level.SEVERE);
+        coreLogger = createLogger("j3d.core", null);
+        coreLoggerEnabled = coreLogger.isLoggable(Level.SEVERE);
+    }
+
+    /**
+     * Get the developer logger -- OFF by default
+     *
+     * WARNING - for probable incorrect or inconsistent api usage
+     * INFO - for informational messages such as performance hints (less verbose than FINE)
+     * FINE - for informational messages from inner loops
+     * FINER - using default values which may not be optimal
+     */
+    static Logger getDevLogger() {
+        return devLogger;
+    }
+
+    static boolean isDevLoggable(Level level) {
+        return devLoggerEnabled && devLogger.isLoggable(level);
+    }
+
+    /**
+     * Get the stats logger -- OFF by default
+     *
+     * WARNING - statistical anomalies
+     * INFO - basic performance stats - not too verbose and minimally intrusive
+     * FINE - somewhat verbose and intrusive
+     * FINER - more verbose and intrusive
+     * FINEST - most verbose and intrusive
+     */
+    static Logger getStatsLogger() {
+        return statsLogger;
+    }
+
+    static boolean isStatsLoggable(Level level) {
+        return statsLoggerEnabled && statsLogger.isLoggable(level);
+    }
+
+    /**
+     * Get the core logger -- level is INFO by default
+     *
+     * SEVERE - Serious internal errors
+     * WARNING - Possible internal errors or anomalies
+     * INFO - General informational messages
+     * FINE - Internal debugging information - somewhat verbose
+     * FINER - Internal debugging information - more verbose
+     * FINEST - Internal debugging information - most verbose
+     */
+    static Logger getCoreLogger() {
+        return coreLogger;
+    }
+
+    static boolean isCoreLoggable(Level level) {
+        return coreLoggerEnabled && coreLogger.isLoggable(level);
     }
 
     private static String getProperty(final String prop) {
@@ -774,13 +831,25 @@ class MasterControl {
         boolean isWindowsVista = isWindowsOs && osName.indexOf("vista") != -1;
         boolean is64Bit = (sunArchDataModel != null) && sunArchDataModel.equals("64");
 
-//        System.err.println("MasterControl.loadLibraries()");
-//        System.err.println("    osName [lower-case] = \"" + osName + "\"" +
-//                ", sunArchDataModel = " + sunArchDataModel);
-//        System.err.println("    is64Bit = " + is64Bit +
-//                ", isWindowsOs = " + isWindowsOs +
-//                ", isMacOs = " + isMacOs +
-//                ", isWindowsVista = " + isWindowsVista);
+        if (isCoreLoggable(Level.CONFIG)) {
+            StringBuffer strBuf = new StringBuffer();
+            strBuf.append("MasterControl.loadLibraries()\n").
+                    append("    osName [lower-case] = \"").
+                    append(osName).
+                    append("\"").
+                    append(", sunArchDataModel = ").
+                    append(sunArchDataModel).
+                    append("\n").
+                    append("    is64Bit = ").
+                    append(is64Bit).
+                    append(", isWindowsOs = ").
+                    append(isWindowsOs).
+                    append(", isMacOs = ").
+                    append(isMacOs).
+                    append(", isWindowsVista = ").
+                    append(isWindowsVista);
+            getCoreLogger().config(strBuf.toString());
+        }
 
         // Initialize the Pipeline object associated with the
         // renderer specified by the "j3d.rend" system property.
@@ -1247,9 +1316,10 @@ class MasterControl {
 	    VirtualUniverse u = message.universe;
 	    int targetThreads = message.threads;
 
+            if (isCoreLoggable(Level.FINEST)) {
+                dumpMessage("sendMessage", message);
+            }
 
-	    //	    System.out.println("============> sendMessage");
-	    //		dumpmsg(message);
 	    if ((targetThreads & J3dThread.UPDATE_RENDERING_ATTRIBUTES) != 0) {
 		renderingAttributesStructure.addMessage(message);
 	    }
@@ -3467,8 +3537,10 @@ class MasterControl {
 		    updateMirrorObjects();
 		    done = true;
 
-//                    // Instrumentation of Java 3D renderer
-//                    printTimes();
+                    if (isStatsLoggable(Level.INFO)) {
+                        // Instrumentation of Java 3D renderer
+                        logTimes();
+                    }
 		}
 	    }
 	    break;
@@ -3556,126 +3628,153 @@ class MasterControl {
 
     // Static initializer
     static {
-	// create ThreadGroup
-	java.security.AccessController.doPrivileged(
-  	    new java.security.PrivilegedAction() {
+        // create ThreadGroup
+        java.security.AccessController.doPrivileged(
+            new java.security.PrivilegedAction() {
                 public Object run() {
-		    ThreadGroup parent;
-		    Thread thread = Thread.currentThread();
-		    threadPriority = thread.getPriority();
-		    rootThreadGroup = thread.getThreadGroup();
-		    while ((parent = rootThreadGroup.getParent()) != null) {
-			rootThreadGroup = parent;
-		    }
-		    rootThreadGroup = new ThreadGroup(rootThreadGroup,
-						      "Java3D");
-		    // use the default maximum group priority
-		    return null;
-		}
-	});
+                    ThreadGroup parent;
+                    Thread thread = Thread.currentThread();
+                    threadPriority = thread.getPriority();
+                    rootThreadGroup = thread.getThreadGroup();
+                    while ((parent = rootThreadGroup.getParent()) != null) {
+                        rootThreadGroup = parent;
+                    }
+                    rootThreadGroup = new ThreadGroup(rootThreadGroup,
+                            "Java3D");
+                    // use the default maximum group priority
+                    return null;
+                }
+        });
+
+        // Initialize loggers
+        initLoggers();
     }
 
 
     static String mtype[] = {
-	"-INSERT_NODES                   ",
-	"-REMOVE_NODES                   ",
-	"-RUN                            ",
-	"-TRANSFORM_CHANGED              ",
-	"-UPDATE_VIEW                    ",
-	"-STOP_THREAD                    ",
-	"-COLORINGATTRIBUTES_CHANGED     ",
-	"-LINEATTRIBUTES_CHANGED         ",
-	"-POINTATTRIBUTES_CHANGED        ",
-	"-POLYGONATTRIBUTES_CHANGED      ",
-
-	"-RENDERINGATTRIBUTES_CHANGED    ",
-	"-TEXTUREATTRIBUTES_CHANGED      ",
-	"-TRANSPARENCYATTRIBUTES_CHANGED ",
-	"-MATERIAL_CHANGED               ",
-	"-TEXCOORDGENERATION_CHANGED     ",
-	"-TEXTURE_CHANGED                ",
-	"-MORPH_CHANGED                  ",
-	"-GEOMETRY_CHANGED               ",
-	"-APPEARANCE_CHANGED             ",
-	"-LIGHT_CHANGED                  ",
-
-	"-BACKGROUND_CHANGED             ",
-	"-CLIP_CHANGED                   ",
-	"-FOG_CHANGED                    ",
-	"-BOUNDINGLEAF_CHANGED           ",
-	"-SHAPE3D_CHANGED                ",
-	"-TEXT3D_TRANSFORM_CHANGED       ",
-	"-TEXT3D_DATA_CHANGED            ",
-	"-SWITCH_CHANGED                 ",
-	"-COND_MET                       ",
-	"-BEHAVIOR_ENABLE                ",
-
-	"-BEHAVIOR_DISABLE               ",
-	"-INSERT_RENDERATOMS             ",
-	"-ORDERED_GROUP_INSERTED         ",
-	"-ORDERED_GROUP_REMOVED          ",
-	"-COLLISION_BOUND_CHANGED        ",
-	"-REGION_BOUND_CHANGED           ",
-	"-MODELCLIP_CHANGED              ",
-	"-BOUNDS_AUTO_COMPUTE_CHANGED    ",
-
-	"-SOUND_ATTRIB_CHANGED           ",
-	"-AURALATTRIBUTES_CHANGED        ",
-	"-SOUNDSCAPE_CHANGED             ",
-	"-ALTERNATEAPPEARANCE_CHANGED    ",
-	"-RENDER_OFFSCREEN               ",
-	"-RENDER_RETAINED                ",
-	"-RENDER_IMMEDIATE               ",
-	"-SOUND_STATE_CHANGED            ",
-	"-ORIENTEDSHAPE3D_CHANGED        ",
-	"-TEXTURE_UNIT_STATE_CHANGED     ",
-	"-UPDATE_VIEWPLATFORM            ",
-	"-BEHAVIOR_ACTIVATE              ",
-	"-GEOMETRYARRAY_CHANGED          ",
-	"-MEDIA_CONTAINER_CHANGED        ",
-    	"-RESIZE_CANVAS                  ",
-    	"-TOGGLE_CANVAS                  ",
-    	"-IMAGE_COMPONENT_CHANGED        ",
-    	"-SCHEDULING_INTERVAL_CHANGED    ",
-    	"-VIEWSPECIFICGROUP_CHANGED      ",
-    	"-VIEWSPECIFICGROUP_INIT         ",
-    	"-VIEWSPECIFICGROUP_CLEAR        ",
-	"-ORDERED_GROUP_TABLE_CHANGED"};
-
-
-    static void dumpThreads(int threads) {
+        "INSERT_NODES",
+        "REMOVE_NODES",
+        "RUN",
+        "TRANSFORM_CHANGED",
+        "UPDATE_VIEW",
+        "STOP_THREAD",
+        "COLORINGATTRIBUTES_CHANGED",
+        "LINEATTRIBUTES_CHANGED",
+        "POINTATTRIBUTES_CHANGED",
+        "POLYGONATTRIBUTES_CHANGED",
+        "RENDERINGATTRIBUTES_CHANGED",
+        "TEXTUREATTRIBUTES_CHANGED",
+        "TRANSPARENCYATTRIBUTES_CHANGED",
+        "MATERIAL_CHANGED",
+        "TEXCOORDGENERATION_CHANGED",
+        "TEXTURE_CHANGED",
+        "MORPH_CHANGED",
+        "GEOMETRY_CHANGED",
+        "APPEARANCE_CHANGED",
+        "LIGHT_CHANGED",
+        "BACKGROUND_CHANGED",
+        "CLIP_CHANGED",
+        "FOG_CHANGED",
+        "BOUNDINGLEAF_CHANGED",
+        "SHAPE3D_CHANGED",
+        "TEXT3D_TRANSFORM_CHANGED",
+        "TEXT3D_DATA_CHANGED",
+        "SWITCH_CHANGED",
+        "COND_MET",
+        "BEHAVIOR_ENABLE",
+        "BEHAVIOR_DISABLE",
+        "INSERT_RENDERATOMS",
+        "ORDERED_GROUP_INSERTED",
+        "ORDERED_GROUP_REMOVED",
+        "COLLISION_BOUND_CHANGED",
+        "REGION_BOUND_CHANGED",
+        "MODELCLIP_CHANGED",
+        "BOUNDS_AUTO_COMPUTE_CHANGED",
+        "SOUND_ATTRIB_CHANGED",
+        "AURALATTRIBUTES_CHANGED",
+        "SOUNDSCAPE_CHANGED",
+        "ALTERNATEAPPEARANCE_CHANGED",
+        "RENDER_OFFSCREEN",
+        "RENDER_RETAINED",
+        "RENDER_IMMEDIATE",
+        "SOUND_STATE_CHANGED",
+        "ORIENTEDSHAPE3D_CHANGED",
+        "TEXTURE_UNIT_STATE_CHANGED",
+        "UPDATE_VIEWPLATFORM",
+        "BEHAVIOR_ACTIVATE",
+        "GEOMETRYARRAY_CHANGED",
+        "MEDIA_CONTAINER_CHANGED",
+        "RESIZE_CANVAS",
+        "TOGGLE_CANVAS",
+        "IMAGE_COMPONENT_CHANGED",
+        "SCHEDULING_INTERVAL_CHANGED",
+        "VIEWSPECIFICGROUP_CHANGED",
+        "VIEWSPECIFICGROUP_INIT",
+        "VIEWSPECIFICGROUP_CLEAR",
+        "ORDERED_GROUP_TABLE_CHANGED",
+        "BEHAVIOR_REEVALUATE",
+        "CREATE_OFFSCREENBUFFER",
+        "DESTROY_CTX_AND_OFFSCREENBUFFER",
+        "SHADER_ATTRIBUTE_CHANGED",
+        "SHADER_ATTRIBUTE_SET_CHANGED",
+        "SHADER_APPEARANCE_CHANGED",
+        "ALLOCATE_CANVASID",
+        "FREE_CANVASID",
+    };
+
+    private String dumpThreads(int threads) {
+        StringBuffer strBuf = new StringBuffer();
+        strBuf.append("threads:");
 	//dump Threads type
-        if ((threads & J3dThread.BEHAVIOR_SCHEDULER) != 0)
-            System.out.println("  BEHAVIOR_SCHEDULER");
-        if ((threads & J3dThread.SOUND_SCHEDULER) != 0)
-            System.out.println("  SOUND_SCHEDULER");
-        if ((threads & J3dThread.INPUT_DEVICE_SCHEDULER) != 0)
-            System.out.println("  INPUT_DEVICE_SCHEDULER");
-
-        if ((threads & J3dThread.RENDER_THREAD) != 0)
-            System.out.println("  RENDER_THREAD");
-
-        if ((threads & J3dThread.UPDATE_GEOMETRY) != 0)
-            System.out.println("  UPDATE_GEOMETRY");
-        if ((threads & J3dThread.UPDATE_RENDER) != 0)
-            System.out.println("  UPDATE_RENDER");
-        if ((threads & J3dThread.UPDATE_BEHAVIOR) != 0)
-            System.out.println("  UPDATE_BEHAVIOR");
-        if ((threads & J3dThread.UPDATE_SOUND) != 0)
-            System.out.println("  UPDATE_SOUND");
-        if ((threads & J3dThread.UPDATE_RENDERING_ATTRIBUTES) != 0)
-            System.out.println("  UPDATE_RENDERING_ATTRIBUTES");
-        if ((threads & J3dThread.UPDATE_RENDERING_ENVIRONMENT) != 0)
-            System.out.println("  UPDATE_RENDERING_ENVIRONMENT");
-        if ((threads & J3dThread.UPDATE_TRANSFORM) != 0)
-            System.out.println("  UPDATE_TRANSFORM");
+        if ((threads & J3dThread.BEHAVIOR_SCHEDULER) != 0) {
+            strBuf.append(" BEHAVIOR_SCHEDULER");
+        }
+        if ((threads & J3dThread.SOUND_SCHEDULER) != 0) {
+            strBuf.append(" SOUND_SCHEDULER");
+        }
+        if ((threads & J3dThread.INPUT_DEVICE_SCHEDULER) != 0) {
+            strBuf.append(" INPUT_DEVICE_SCHEDULER");
+        }
+        if ((threads & J3dThread.RENDER_THREAD) != 0) {
+            strBuf.append(" RENDER_THREAD");
+        }
+        if ((threads & J3dThread.UPDATE_GEOMETRY) != 0) {
+            strBuf.append(" UPDATE_GEOMETRY");
+        }
+        if ((threads & J3dThread.UPDATE_RENDER) != 0) {
+            strBuf.append(" UPDATE_RENDER");
+        }
+        if ((threads & J3dThread.UPDATE_BEHAVIOR) != 0) {
+            strBuf.append(" UPDATE_BEHAVIOR");
+        }
+        if ((threads & J3dThread.UPDATE_SOUND) != 0) {
+            strBuf.append(" UPDATE_SOUND");
+        }
+        if ((threads & J3dThread.UPDATE_RENDERING_ATTRIBUTES) != 0) {
+            strBuf.append(" UPDATE_RENDERING_ATTRIBUTES");
+        }
+        if ((threads & J3dThread.UPDATE_RENDERING_ENVIRONMENT) != 0) {
+            strBuf.append(" UPDATE_RENDERING_ENVIRONMENT");
+        }
+        if ((threads & J3dThread.UPDATE_TRANSFORM) != 0) {
+            strBuf.append(" UPDATE_TRANSFORM");
+        }
+        
+        return strBuf.toString();
     }
 
-    static void dumpmsg(J3dMessage m) {
-	//dump message type
-        System.out.println(mtype[m.type]);
-
-	dumpThreads(m.threads);
+    // Method to log the specified message. Note that the caller
+    // should check for isCoreLoggable(FINEST) before calling
+    private void dumpMessage(String str, J3dMessage m) {
+        StringBuffer strBuf = new StringBuffer();
+        strBuf.append(str).append(" ");
+        if (m.type >= 0 && m.type < mtype.length) {
+            strBuf.append(mtype[m.type]);
+        } else {
+            strBuf.append("<UNKNOWN>");
+        }
+        strBuf.append("  ").append(dumpThreads(m.threads));
+        getCoreLogger().finest(strBuf.toString());
     }
 
 
@@ -3721,25 +3820,9 @@ class MasterControl {
         return Runtime.getRuntime().availableProcessors();
     }
 
-    /**
-     * Get the developer logger
-     *
-     * WARNING - for probable incorrect or inconsistent api usage
-     * INFO - for informational messages such as performance hints (less verbose than FINE)
-     * FINE - for informational messages from inner loops
-     * FINER - using default values which may not be optimal
-     */
-    static Logger getDevLogger() {
-        return devLogger;
-    }
-    
-    //
-    // The following framework supports code instrumentation. To enable this:
-    //     1) Uncomment all of the following code
-    //     2) Uncomment the call to printTimes (in doWork)
-    //     3) Uncomment the calls to nanoTime and recordTimes in the Renderer
     //
-    // Then add code of the following form to areas that you want to enable for
+    // The following framework supports code instrumentation. To use it,
+    // add code of the following form to areas that you want to enable for
     // timing:
     //
     //     long startTime = System.nanoTime();
@@ -3748,43 +3831,64 @@ class MasterControl {
     //     VirtualUniverse.mc.recordTime(MasterControl.TimeType.XXXXX, deltaTime);
     //
     // where "XXXXX" is the enum representing the code segment being timed.
+    // Additional enums can be defined for new subsystems.
     //
 
-//    static enum TimeType {
-//        TOTAL_FRAME,
-//        RENDER,
-//        // BEHAVIOR,
-//        // TRANSFORM_UPDATE,
-//        // ...
-//    }
-//    
-//    private long[] times = new long[TimeType.values().length];
-//    private int[] counts = new int[TimeType.values().length];
-//    private int frameTick = 0;
-//
-//    synchronized void recordTime(TimeType type, long deltaTime) {
-//        int idx = type.ordinal();
-//        times[idx] += deltaTime;
-//        counts[idx]++;
-//    }
-//    
-//    private synchronized void printTimes() {
-//        if (++frameTick >= 10) {
-//            System.err.println("\n-------------------------------------------------------------------");
-//            for (int i = 0; i < times.length; i++) {
-//                if (counts[i] > 0) {
-//                    System.err.println(TimeType.values()[i] + " [" + counts[i] + "] = " +
-//                            ((double)times[i] / 1000000.0 / (double)counts[i]) + " msec per call" );
-//                    times[i] = 0L;
-//                    counts[i] = 0;
-//                } else {
-//                    assert times[i] == 0L;
-//                    System.err.println(TimeType.values()[i] +
-//                            " [" + 0 + "] = 0.0 msec" );
-//                }
-//            }
-//            frameTick = 0;
-//        }
-//    }
+    static enum TimeType {
+        TOTAL_FRAME,
+        RENDER,
+        BEHAVIOR,
+        // TRANSFORM_UPDATE,
+        // ...
+    }
+
+    private long[] statTimes = new long[TimeType.values().length];
+    private int[] statCounts = new int[TimeType.values().length];
+    private boolean[] statSeen = new boolean[TimeType.values().length];
+    private int frameCycleTick = 0;
+    private long frameCycleNumber = 0L;
+
+    // Method to record times -- should not be called unless the stats logger
+    // level is set to INFO or lower
+    synchronized void recordTime(TimeType type, long deltaTime) {
+        int idx = type.ordinal();
+        statTimes[idx] += deltaTime;
+        statCounts[idx]++;
+        statSeen[idx] = true;
+    }
+
+    // Method to record times -- this is not called unless the stats logger
+    // level is set to INFO or lower
+    private synchronized void logTimes() {
+        ++frameCycleNumber;
+        if (++frameCycleTick >= 10) {
+            StringBuffer strBuf = new StringBuffer();
+            strBuf.append("----------------------------------------------\n").
+                    append("    Frame Number = ").
+                    append(frameCycleNumber).
+                    append("\n");
+            for (int i = 0; i < statTimes.length; i++) {
+                if (statSeen[i]) {
+                    strBuf.append("    ");
+                    if (statCounts[i] > 0) {
+                        strBuf.append(TimeType.values()[i]).
+                                append(" [").
+                                append(statCounts[i]).
+                                append("] = ").
+                                append((double)statTimes[i] / 1000000.0 / (double)statCounts[i]).
+                                append(" msec per call\n");
+                        statTimes[i] = 0L;
+                        statCounts[i] = 0;
+                    } else {
+                        assert statTimes[i] == 0L;
+                        strBuf.append(TimeType.values()[i]).
+                                append(" [0] = 0.0 msec\n");
+                    }
+                }
+            }
+            getStatsLogger().info(strBuf.toString());
+            frameCycleTick = 0;
+        }
+    }
 
 }
diff --git a/src/classes/share/javax/media/j3d/NnuIdManager.java b/src/classes/share/javax/media/j3d/NnuIdManager.java
index 186b6cd..60dabef 100644
--- a/src/classes/share/javax/media/j3d/NnuIdManager.java
+++ b/src/classes/share/javax/media/j3d/NnuIdManager.java
@@ -218,8 +218,7 @@ class NnuIdManager {
 		}
 		else {
 		    found = false;
-		    System.out.println("Can't Find matching nnuId.");
-		    System.out.println("We're in TROUBLE!!!");
+		    MasterControl.getCoreLogger().severe("Can't Find matching nnuId.");
 		}
 	    }
 	    
@@ -300,8 +299,7 @@ class NnuIdManager {
 	    nnuIdArr[lenLess1] = null;
 	}
 	else {
-	    System.out.println("Can't Find matching nnuId.");
-	    System.out.println("We're in TROUBLE!!!");
+	    MasterControl.getCoreLogger().severe("Can't Find matching nnuId.");
 	}
 
 	// insert new to nnuIdArr.
diff --git a/src/classes/share/javax/media/j3d/OrderedGroupRetained.java b/src/classes/share/javax/media/j3d/OrderedGroupRetained.java
index 559b290..27c7a1a 100644
--- a/src/classes/share/javax/media/j3d/OrderedGroupRetained.java
+++ b/src/classes/share/javax/media/j3d/OrderedGroupRetained.java
@@ -356,8 +356,7 @@ class OrderedGroupRetained extends GroupRetained {
                     setAuxData(s, j, hkIndex);
 
                 } else {
-                    System.out.println("Can't Find matching hashKey in setNodeData.");
-                    System.out.println("We're in TROUBLE!!!");
+                    MasterControl.getCoreLogger().severe("Can't Find matching hashKey in setNodeData.");
                 }
             }
         }
diff --git a/src/classes/share/javax/media/j3d/Renderer.java b/src/classes/share/javax/media/j3d/Renderer.java
index 7bb2a84..80d12f9 100644
--- a/src/classes/share/javax/media/j3d/Renderer.java
+++ b/src/classes/share/javax/media/j3d/Renderer.java
@@ -18,6 +18,7 @@
 
 package javax.media.j3d;
 
+import java.util.logging.Level;
 import javax.vecmath.*;
 import java.awt.*;
 import java.awt.image.*;
@@ -66,11 +67,6 @@ class Renderer extends J3dThread {
     // vworldtoVpc matrix for background geometry
     Transform3D bgVworldToVpc = new Transform3D();
 
-    long lasttime;
-    long currtime;
-    float numframes = 0.0f;
-    static final boolean doTiming = false;
-
     private static int numInstances = 0;
     private int instanceNum = -1;
 
@@ -160,8 +156,8 @@ class Renderer extends J3dThread {
     // It is used when sharedCtx = true;
     ArrayList textureIDResourceTable = new ArrayList(5);
 
-//    // Instrumentation of Java 3D renderer
-//    private long lastSwapTime = System.nanoTime();
+    // Instrumentation of Java 3D renderer
+    private long lastSwapTime = System.nanoTime();
 
     private synchronized int newInstanceNum() {
 	return (++numInstances);
@@ -287,11 +283,13 @@ class Renderer extends J3dThread {
                             cv.view.inCanvasCallback = false;
                             // Clear canvasDirty bit ONLY when postSwap() success
 
-//                            // Instrumentation of Java 3D renderer
-//                            long currSwapTime = System.nanoTime();
-//                            long deltaTime = currSwapTime - lastSwapTime;
-//                            lastSwapTime = currSwapTime;
-//                            VirtualUniverse.mc.recordTime(MasterControl.TimeType.TOTAL_FRAME, deltaTime);
+                            if (MasterControl.isStatsLoggable(Level.INFO)) {
+                                // Instrumentation of Java 3D renderer
+                                long currSwapTime = System.nanoTime();
+                                long deltaTime = currSwapTime - lastSwapTime;
+                                lastSwapTime = currSwapTime;
+                                VirtualUniverse.mc.recordTime(MasterControl.TimeType.TOTAL_FRAME, deltaTime);
+                            }
 
                             // Set all dirty bits except environment set and lightbin
                             // they are only set dirty if the last used light bin or
@@ -619,7 +617,7 @@ class Renderer extends J3dThread {
 		    m[nmesg++].decRefcount();
 		} else if (renderType == J3dMessage.RENDER_IMMEDIATE) {
                     int command = ((Integer)m[nmesg].args[1]).intValue();
-		    //System.out.println("command= " + command);
+		    //System.err.println("command= " + command);
 		    if (needToResendTextureDown) {
 			VirtualUniverse.mc.resendTexTimestamp++;
 			needToResendTextureDown = false;
@@ -770,8 +768,11 @@ class Renderer extends J3dThread {
 
 		    m[nmesg++].decRefcount();
 		} else { // retained mode rendering
-//                    // Instrumentation of Java 3D renderer
-//                    long startRenderTime = System.nanoTime();
+                    long startRenderTime = 0L;
+                    if (MasterControl.isStatsLoggable(Level.INFO)) {
+                        // Instrumentation of Java 3D renderer
+                        startRenderTime = System.nanoTime();
+                    }
 
                     m[nmesg++].decRefcount();
                     
@@ -1130,7 +1131,7 @@ class Renderer extends J3dThread {
 			    } else {
 
 				if (!canvas.antialiasingSet) {
-				    // System.out.println("Renderer : Enable FullSceneAntialiasing");
+				    // System.err.println("Renderer : Enable FullSceneAntialiasing");
 
 				    canvas.setFullSceneAntialiasing(canvas.ctx, true);
 				    canvas.antialiasingSet = true;
@@ -1139,7 +1140,7 @@ class Renderer extends J3dThread {
 		        } else {
 
 			    if (canvas.antialiasingSet) {
-				// System.out.println("Renderer : Disable SceneAntialiasing");
+				// System.err.println("Renderer : Disable SceneAntialiasing");
 				canvas.setFullSceneAntialiasing(canvas.ctx, false);
 				canvas.antialiasingSet = false;
 			    }
@@ -1442,53 +1443,18 @@ class Renderer extends J3dThread {
 
 			canvas.endScene();
 
-                        if (doTiming) {
-                            numframes += 1.0f;
-                            if (numframes >= 20.0f) {
-                                currtime = J3dClock.currentTimeMillis();
-                                System.err.println(
-				    numframes/((currtime-lasttime)/1000.0f) +
-						" frames per second");
-                                numframes = 0.0f;
-                                lasttime = currtime;
-
-				// For taking memory footprint of the entire scene.
-				/*
-				long totalMem, freeMem, usedMem;
-				for(int ii=0; ii<5;ii++) {
-				    totalMem = Runtime.getRuntime().totalMemory();
-				    freeMem = Runtime.getRuntime().freeMemory();
-				    usedMem = totalMem - freeMem;
-				    System.out.print("mem used - before: " + usedMem + "bytes ");
-				    //System.out.print("mem used - before: " + usedMem + " ");
-				    System.runFinalization();
-				    System.gc();
-				    System.runFinalization();
-				    totalMem = Runtime.getRuntime().totalMemory();
-				    freeMem = Runtime.getRuntime().freeMemory();
-				    usedMem = totalMem - freeMem;
-				    System.out.println("after: " + usedMem + "bytes ");
-				    //System.out.println("after: " + usedMem + " ");
-				    try {
-					Thread.sleep(100);
-				    }
-				    catch (InterruptedException e) { }
-			      
-				    }
-				*/
-				
-			    }
-			}
+                        if (MasterControl.isStatsLoggable(Level.INFO)) {
+                            // Instrumentation of Java 3D renderer
+                            long deltaTime = System.nanoTime() - startRenderTime;
+                            VirtualUniverse.mc.recordTime(MasterControl.TimeType.RENDER, deltaTime);
+                        }
+
 		    } else { // if (renderBin != null)
 			if ((offBufRetained != null) &&
 			    offBufRetained.isByReference()) {
 			    offBufRetained.geomLock.unLock();
 			}	
 		    }
-
-//                    // Instrumentation of Java 3D renderer
-//                    long deltaTime = System.nanoTime() - startRenderTime;
-//                    VirtualUniverse.mc.recordTime(MasterControl.TimeType.RENDER, deltaTime);
 		}
 	    }
 
@@ -1547,7 +1513,6 @@ class Renderer extends J3dThread {
         renderMessage = new J3dMessage[1];
 	rendererStructure = new RendererStructure();	
 	bgVworldToVpc = new Transform3D();
-	numframes = 0.0f;
 	sharedCtx = null;	 
 	sharedCtxTimeStamp = 0;
 	sharedCtxDisplay = 0;
@@ -1561,8 +1526,6 @@ class Renderer extends J3dThread {
 	offScreen = null;
 	m = null;
 	nmesg = 0;
-	lasttime = 0;
-	currtime = 0;
     }
 
 
@@ -1729,9 +1692,10 @@ class Renderer extends J3dThread {
 			continue;
 		    }
 		    if (val >= textureIDResourceTable.size()) {
-			System.out.println("Error in freeResourcesInFreeList : ResourceIDTableSize = " + 
-					   textureIDResourceTable.size() + 
-					   " val = " + val);
+			MasterControl.getCoreLogger().severe(
+                                "Error in freeResourcesInFreeList : ResourceIDTableSize = " +
+                                textureIDResourceTable.size() +
+                                " val = " + val);
 		    } else {
                         Object obj = textureIDResourceTable.get(val);
                         if (obj instanceof TextureRetained) {
diff --git a/src/classes/share/javax/media/j3d/SharedGroupRetained.java b/src/classes/share/javax/media/j3d/SharedGroupRetained.java
index c220d90..42f0d1e 100644
--- a/src/classes/share/javax/media/j3d/SharedGroupRetained.java
+++ b/src/classes/share/javax/media/j3d/SharedGroupRetained.java
@@ -190,8 +190,7 @@ class SharedGroupRetained extends GroupRetained implements TargetsInterface {
 	for(i=len, j=0; i<localToVworld.length; i++, j++) {
 
 	    if(s.keys[j].equals(localToVworldKeys, hkIndex, 0, i)) {
-		System.out.println("Found matching hashKey in setNodeData.");
-		System.out.println("We're in TROUBLE!!!");
+		MasterControl.getCoreLogger().severe("Found matching hashKey in setNodeData.");
 	    }
             s.hashkeyIndex[j] = hkIndex[0];
 
@@ -405,8 +404,7 @@ class SharedGroupRetained extends GroupRetained implements TargetsInterface {
 		}
 		else {
 		    found = false;
-		    System.out.println("Can't Find matching hashKey in SG.removeNodeData.");
-		    System.out.println("We're in TROUBLE!!!");
+		    MasterControl.getCoreLogger().severe("Can't Find matching hashKey in SG.removeNodeData.");
 		}
 	    }
 	
diff --git a/src/classes/share/javax/media/j3d/SwitchRetained.java b/src/classes/share/javax/media/j3d/SwitchRetained.java
index bf6d3b6..a566cf5 100644
--- a/src/classes/share/javax/media/j3d/SwitchRetained.java
+++ b/src/classes/share/javax/media/j3d/SwitchRetained.java
@@ -316,8 +316,7 @@ class SwitchRetained extends GroupRetained implements TargetsInterface
                 if(hkIndex >= 0) {
                     setAuxData(s, j, hkIndex);
                 } else {
-                    System.out.println("Can't Find matching hashKey in setNodeData.");
-                    System.out.println("We're in TROUBLE!!!");
+                    MasterControl.getCoreLogger().severe("Can't Find matching hashKey in setNodeData.");
                 }
                 s.hashkeyIndex[j] = hkIndex;
             }
diff --git a/src/classes/share/javax/media/j3d/TransformGroupRetained.java b/src/classes/share/javax/media/j3d/TransformGroupRetained.java
index 62e636a..9dd24ed 100644
--- a/src/classes/share/javax/media/j3d/TransformGroupRetained.java
+++ b/src/classes/share/javax/media/j3d/TransformGroupRetained.java
@@ -292,8 +292,7 @@ class TransformGroupRetained extends GroupRetained implements TargetsInterface
 						localToVworldKeys.length);
 	    
 	        if(hkIndex < 0) {		
-		    System.out.println("Can't Find matching hashKey in setNodeData.");
-		    System.out.println("We're in TROUBLE!!!");
+		    MasterControl.getCoreLogger().severe("Can't Find matching hashKey in setNodeData.");
 		    break;
 	        } else if(hkIndex >= i) { // Append to last.
 		    childLocalToVworld[i] = childTrans[j];
@@ -688,8 +687,7 @@ class TransformGroupRetained extends GroupRetained implements TargetsInterface
 		    }
 		    else {
 			found = false;
-			System.out.println("TG.removeNodeData-Can't find matching hashKey.");
-			System.out.println("We're in TROUBLE!!!");
+			MasterControl.getCoreLogger().severe("TG.removeNodeData-Can't find matching hashKey.");
 		    }
 		}
 	
diff --git a/src/classes/share/javax/media/j3d/ViewSpecificGroupRetained.java b/src/classes/share/javax/media/j3d/ViewSpecificGroupRetained.java
index 51e5fb9..fcf098e 100644
--- a/src/classes/share/javax/media/j3d/ViewSpecificGroupRetained.java
+++ b/src/classes/share/javax/media/j3d/ViewSpecificGroupRetained.java
@@ -672,8 +672,7 @@ class ViewSpecificGroupRetained extends GroupRetained {
                     setAuxData(s, j, hkIndex);
 
                 } else {
-                    System.out.println("Can't Find matching hashKey in setNodeData.");
-                    System.out.println("We're in TROUBLE!!!");
+                    MasterControl.getCoreLogger().severe("Can't Find matching hashKey in setNodeData.");
                 }
             }
         }
diff --git a/src/classes/share/javax/media/j3d/VirtualUniverse.java b/src/classes/share/javax/media/j3d/VirtualUniverse.java
index 9ed1d80..f8f736f 100644
--- a/src/classes/share/javax/media/j3d/VirtualUniverse.java
+++ b/src/classes/share/javax/media/j3d/VirtualUniverse.java
@@ -18,6 +18,8 @@ import java.util.Enumeration;
 import java.util.HashSet;
 import java.util.Iterator;
 import java.util.Map;
+import java.util.logging.Level;
+import java.util.logging.Logger;
 
 /**
  * A VirtualUniverse object is the top-level container for all scene
@@ -222,29 +224,48 @@ public class VirtualUniverse extends Object {
     }
 
     static {
-	// Print out version information unless this is a
-	// non-debuggable, release (fcs) build
-	if(J3dDebug.devPhase || VersionInfo.isDebug) {
-	    String versionStr = VersionInfo.getVersion();
+        boolean isLoggableConfig = MasterControl.isCoreLoggable(Level.CONFIG);
+        Logger logger = MasterControl.getCoreLogger();
+
+        // Print out version information unless this is a
+        // non-debuggable, release (fcs) build
+        if (isLoggableConfig || J3dDebug.devPhase || VersionInfo.isDebug) {
+            StringBuffer strBuf = new StringBuffer("Java 3D ");
 	    if (J3dDebug.devPhase) {
-		System.err.println("Java 3D [dev] " + versionStr);
-	    }
-	    else {
-		System.err.println("Java 3D " + versionStr);
+		strBuf.append("[dev] ");
 	    }
-	    System.err.println();
+            strBuf.append(VersionInfo.getVersion());
+            String str = strBuf.toString();
+            if (isLoggableConfig) {
+                logger.config(str);
+            } else {
+                System.err.println(str);
+                System.err.println();
+            }
 	}
 
 	// Print out debugging information for debug builds
-	if(VersionInfo.isDebug) {
-	    System.err.println("Initializing Java 3D runtime system:");
-	    System.err.println("    version = " + VersionInfo.getVersion());
-	    System.err.println("    vendor = " + VersionInfo.getVendor());
-	    System.err.println("    specification.version = " +
-			       VersionInfo.getSpecificationVersion());
-	    System.err.println("    specification.vendor = " +
-			       VersionInfo.getSpecificationVendor());
-	    System.err.println();
+	if (isLoggableConfig || VersionInfo.isDebug) {
+            StringBuffer strBuf = new StringBuffer();
+            strBuf.append("Initializing Java 3D runtime system:\n").
+                    append("    version = ").
+                    append(VersionInfo.getVersion()).
+                    append("\n").
+                    append("    vendor = ").
+                    append(VersionInfo.getVendor()).
+                    append("\n").
+                    append("    specification.version = ").
+                    append(VersionInfo.getSpecificationVersion()).
+                    append("\n").
+                    append("    specification.vendor = ").
+                    append(VersionInfo.getSpecificationVendor());
+            String str = strBuf.toString();
+            if (isLoggableConfig) {
+                logger.config(str);
+            } else {
+                System.err.println(str);
+                System.err.println();
+            }
 	}
 
 	// Java 3D cannot run in headless mode, so we will throw a
@@ -259,13 +280,20 @@ public class VirtualUniverse extends Object {
 	MasterControl.loadLibraries();
 	mc = new MasterControl();
 
-	// Print out debugging information for debug builds
-	if(VersionInfo.isDebug) {
-	    System.err.println("Java 3D system initialized");
-	    System.err.println("    rendering pipeline = " +
-                    Pipeline.getPipeline().getPipelineName());
-	    System.err.println();
-	}
+        // Print out debugging information for debug builds
+        if (isLoggableConfig || VersionInfo.isDebug) {
+            StringBuffer strBuf = new StringBuffer();
+            strBuf.append("Java 3D system initialized\n").
+                    append("    rendering pipeline = ").
+                    append(Pipeline.getPipeline().getPipelineName());
+            String str = strBuf.toString();
+            if (isLoggableConfig) {
+                logger.config(str);
+            } else {
+                System.err.println(str);
+                System.err.println();
+            }
+        }
     }
 
     /**