Bug 494864 - Make nanojit debug output easier to follow, r=graydon.

js/src/jsregexp.cpp

@@ -2343,7 +2343,7 @@ class RegExpNativeCompiler {
     addName(LirBuffer* lirbuf, LIns* ins, const char* name)
     {
 #ifdef NJ_VERBOSE
-        debug_only_v(lirbuf->names->addName(ins, name);)
+        debug_only_stmt(lirbuf->names->addName(ins, name);)
 #endif
         return ins;
     }
@@ -2401,11 +2401,18 @@ class RegExpNativeCompiler {
 
         /* FIXME Use bug 463260 smart pointer when available. */
 #ifdef NJ_VERBOSE
-        debug_only_v(fragment->lirbuf->names = new (&gc) LirNameMap(&gc, fragmento->labels);)
+        debug_only_stmt(
+        fragment->lirbuf->names = new (&gc) LirNameMap(&gc, fragmento->labels);
+        )
 #endif
         /* FIXME Use bug 463260 smart pointer when available. */
 #ifdef NJ_VERBOSE
-        debug_only_v(lir = new (&gc) VerboseWriter(&gc, lir, lirbuf->names);)
+        debug_only_stmt(
+            if (js_LogController.lcbits & LC_TMRegexp) {
+                lir = new (&gc) VerboseWriter(&gc, lir, lirbuf->names,
+                                              &js_LogController);
+            }
+        )
 #endif
 
         lir->ins0(LIR_start);
@@ -2434,7 +2441,8 @@ class RegExpNativeCompiler {
 
         delete lirBufWriter;
 #ifdef NJ_VERBOSE
-        debug_only_v(delete lir;)
+        debug_only_stmt( if (js_LogController.lcbits & LC_TMRegexp)
+                             delete lir; )
 #endif
         return JS_TRUE;
     fail:
@@ -2448,7 +2456,8 @@ class RegExpNativeCompiler {
         }
         delete lirBufWriter;
 #ifdef NJ_VERBOSE
-        debug_only_v(delete lir;)
+        debug_only_stmt( if (js_LogController.lcbits & LC_TMRegexp)
+                             delete lir; )
 #endif
         return JS_FALSE;
     }
@@ -3923,16 +3932,17 @@ MatchRegExp(REGlobalData *gData, REMatchState *x)
         gData->skipped = (ptrdiff_t) x->cp;
 
 #ifdef JS_JIT_SPEW
-        debug_only_v({
+        debug_only_stmt({
             VOUCH_DOES_NOT_REQUIRE_STACK();
             JSStackFrame *caller = (JS_ON_TRACE(gData->cx))
                                    ? NULL
                                    : js_GetScriptedCaller(gData->cx, NULL);
-            printf("entering REGEXP trace at %s:%u@%u, code: %p\n",
+            debug_only_printf(LC_TMRegexp,
-                   caller ? caller->script->filename : "<unknown>",
+                              "entering REGEXP trace at %s:%u@%u, code: %p\n",
-                   caller ? js_FramePCToLineNumber(gData->cx, caller) : 0,
+                              caller ? caller->script->filename : "<unknown>",
-                   caller ? FramePCOffset(caller) : 0,
+                              caller ? js_FramePCToLineNumber(gData->cx, caller) : 0,
-                   JS_FUNC_TO_DATA_PTR(void *, native));
+                              caller ? FramePCOffset(caller) : 0,
+                              JS_FUNC_TO_DATA_PTR(void *, native));
         })
 #endif
 
@@ -3942,7 +3952,7 @@ MatchRegExp(REGlobalData *gData, REMatchState *x)
         result = native(x, gData);
 #endif
 
-        debug_only_v(printf("leaving REGEXP trace\n"));
+        debug_only_print0(LC_TMRegexp, "leaving  REGEXP trace\n");
 
         gData->skipped = ((const jschar *) gData->skipped) - cp;
         return result;

js/src/jstracer.h

@@ -154,10 +154,39 @@ public:
 };
 
 #ifdef JS_JIT_SPEW
-extern bool js_verboseDebug;
+
-#define debug_only_v(x) if (js_verboseDebug) { x; fflush(stdout); }
+enum LC_TMBits {
+    /* Output control bits for all non-Nanojit code.  Only use bits 16
+       and above, since Nanojit uses 0 .. 15 itself. */
+    LC_TMMinimal  = 1<<16,
+    LC_TMTracer   = 1<<17,
+    LC_TMRecorder = 1<<18,
+    LC_TMPatcher  = 1<<19,
+    LC_TMAbort    = 1<<20,
+    LC_TMStats    = 1<<21,
+    LC_TMRegexp   = 1<<22
+};
+
+// Top level logging controller object.
+extern nanojit::LogControl js_LogController;
+
+#define debug_only_stmt(stmt) \
+    stmt
+#define debug_only_printf(mask, fmt, ...) \
+    do { if ((js_LogController.lcbits & (mask)) > 0) {             \
+        js_LogController.printf(fmt, __VA_ARGS__); fflush(stdout); \
+    }} while (0)
+#define debug_only_print0(mask, str) \
+    do { if ((js_LogController.lcbits & (mask)) > 0) { \
+        js_LogController.printf(str); fflush(stdout);  \
+    }} while (0)
+
 #else
-#define debug_only_v(x)
+
+#define debug_only_stmt(action)            /* */
+#define debug_only_printf(mask, fmt, ...)  /* */
+#define debug_only_print0(mask, str)       /* */
+
 #endif
 
 /*

js/src/nanojit/Assembler.cpp

@@ -137,6 +137,59 @@ namespace nanojit
 			return i;
 		}
 	};
+
+	/* A listing filter for LIR, going through backwards.  It merely
+       passes its input to its output, but notes it down too.  When
+       destructed, prints out what went through.  Is intended to be
+       used to print arbitrary intermediate transformation stages of
+       LIR. */
+	class ReverseLister : public LirFilter
+	{
+		avmplus::GC* _gc;
+        LirNameMap*  _names;
+		const char*  _title;
+		StringList*  _strs;
+		LogControl*  _logc;
+	public:
+		ReverseLister(LirFilter* in, avmplus::GC* gc,
+					  LirNameMap* names, LogControl* logc, const char* title)
+			: LirFilter(in)
+		{
+			_gc    = gc;
+			_names = names;
+			_title = title;
+			_strs  = new StringList(gc);
+			_logc  = logc;
+		}
+
+		~ReverseLister()
+        {
+			_logc->printf("\n");
+			_logc->printf("=== BEGIN %s ===\n", _title);
+    		int i, j;
+			const char* prefix = "  ";
+			for (j = 0, i = _strs->size()-1; i >= 0; i--, j++) {
+				char* str = _strs->get(i);
+				_logc->printf("%s%02d: %s\n", prefix, j, str);
+				_gc->Free(str);
+			}
+			delete _strs;
+			_logc->printf("=== END %s ===\n", _title);
+			_logc->printf("\n");
+		}
+
+		LInsp read() 
+		{
+			LInsp i = in->read();
+			if (!i)
+				return i;
+			const char* str = _names->formatIns(i);
+			char* cpy = (char*)_gc->Alloc(strlen(str) + 1,  0/*AllocFlags*/);
+			strcpy(cpy, str);
+			_strs->add(cpy);
+			return i;
+		}
+	};
 #endif
 	
 	/**
@@ -144,7 +197,7 @@ namespace nanojit
 	 *
 	 *	- merging paths ( build a graph? ), possibly use external rep to drive codegen
 	 */
-    Assembler::Assembler(Fragmento* frago)
+    Assembler::Assembler(Fragmento* frago, LogControl* logc)
         : hasLoop(0)
         , _frago(frago)
         , _gc(frago->core()->gc)
@@ -155,9 +208,9 @@ namespace nanojit
 	{
         AvmCore *core = frago->core();
 		nInit(core);
-		verbose_only( _verbose = !core->quiet_opt() && core->verbose() );
+		verbose_only( _logc = logc; )
-		verbose_only( _outputCache = 0);
+		verbose_only( _outputCache = 0; )
-		verbose_only( outlineEOL[0] = '\0');
+		verbose_only( outlineEOL[0] = '\0'; )
 		
 		internalReset();
 		pageReset();		
@@ -578,7 +631,9 @@ namespace nanojit
 		int d = disp(resv);
 		Register rr = resv->reg;
 		bool quad = i->opcode() == LIR_param || i->isQuad();
-		verbose_only( if (d && _verbose) { outputForEOL("  <= spill %s", _thisfrag->lirbuf->names->formatRef(i)); } )
+		verbose_only( if (d && (_logc->lcbits & LC_RegAlloc)) { 
+			             outputForEOL("  <= spill %s",
+									  _thisfrag->lirbuf->names->formatRef(i)); } )
 		asm_spill(rr, d, pop, quad);
 	}
 
@@ -653,9 +708,9 @@ namespace nanojit
 			RegAlloc* captured = _branchStateMap->get(exit);
 			intersectRegisterState(*captured);
 			verbose_only(
-				verbose_outputf("        merging trunk with %s",
+				verbose_outputf("## merging trunk with %s",
 					_frago->labels->format(exit->target));
-				verbose_outputf("        %p:",_nIns);
+				verbose_outputf("%010lx:", (unsigned long)_nIns);
 			)			
 			at = exit->target->fragEntry;
 			NanoAssert(at != 0);
@@ -666,10 +721,8 @@ namespace nanojit
 	
 	NIns* Assembler::asm_leave_trace(LInsp guard)
 	{
-        verbose_only(bool priorVerbose = _verbose; )
-		verbose_only( _verbose = verbose_enabled() && _frago->core()->config.verbose_exits; )
         verbose_only( int32_t nativeSave = _stats.native );
-		verbose_only(verbose_outputf("--------------------------------------- end exit block %p", guard);)
+		verbose_only( verbose_outputf("----------------------------------- ## END exit block %p", guard);)
 
 		RegAlloc capture = _allocator;
 
@@ -704,15 +757,14 @@ namespace nanojit
 		_inExit = false;
 		
 		//verbose_only( verbose_outputf("         LIR_xt/xf swapptrs, _nIns is now %08X(%08X), _nExitIns is now %08X(%08X)",_nIns, *_nIns,_nExitIns,*_nExitIns) );
-		verbose_only( verbose_outputf("        %p:",jmpTarget);)
+		verbose_only( verbose_outputf("%010lx:", (unsigned long)jmpTarget);)
-		verbose_only( verbose_outputf("--------------------------------------- exit block (LIR_xt|LIR_xf)") );
+		verbose_only( verbose_outputf("----------------------------------- ## BEGIN exit block (LIR_xt|LIR_xf)") );
 
 #ifdef NANOJIT_IA32
 		NanoAssertMsgf(_fpuStkDepth == _sv_fpuStkDepth, "LIR_xtf, _fpuStkDepth=%d, expect %d",_fpuStkDepth, _sv_fpuStkDepth);
 		debug_only( _fpuStkDepth = _sv_fpuStkDepth; _sv_fpuStkDepth = 9999; )
 #endif
 
-        verbose_only( _verbose = priorVerbose; )
         verbose_only(_stats.exitnative += (_stats.native-nativeSave));
 
         return jmpTarget;
@@ -771,24 +823,73 @@ namespace nanojit
 		AvmCore *core = _frago->core();
         _thisfrag = frag;
 
-		// set up backwards pipeline: assembler -> StackFilter -> LirReader
+		// Used for debug printing, if needed
-		LirReader bufreader(frag->lastIns);
-		avmplus::GC *gc = core->gc;
-		StackFilter storefilter1(&bufreader, gc, frag->lirbuf, frag->lirbuf->sp);
-		StackFilter storefilter2(&storefilter1, gc, frag->lirbuf, frag->lirbuf->rp);
-		DeadCodeFilter deadfilter(&storefilter2);
-		LirFilter* rdr = &deadfilter;
 		verbose_only(
-			VerboseBlockReader vbr(rdr, this, frag->lirbuf->names);
+		ReverseLister *pp_init = NULL,
-			if (verbose_enabled())
+            		  *pp_after_sf1 = NULL,
-				rdr = &vbr;
+			          *pp_after_sf2 = NULL,
+			          *pp_after_dead = NULL;
+    	)
+
+		// set up backwards pipeline: assembler -> StackFilter -> LirReader
+		avmplus::GC *gc = core->gc;
+		LirReader bufreader(frag->lastIns);
+
+		// Used to construct the pipeline
+		LirFilter* prev = &bufreader;
+
+		// The LIR passes through these filters as listed in this
+		// function, viz, top to bottom.
+
+		// INITIAL PRINTING
+		verbose_only( if (_logc->lcbits & LC_ReadLIR) {
+		pp_init = new ReverseLister(prev, gc, frag->lirbuf->names, _logc,
+									"Initial LIR");
+		prev = pp_init;
+		})
+
+		// STOREFILTER for sp
+		StackFilter storefilter1(prev, gc, frag->lirbuf, frag->lirbuf->sp);
+		prev = &storefilter1;
+
+		verbose_only( if (_logc->lcbits & LC_AfterSF_SP) {
+		pp_after_sf1 = new ReverseLister(prev, gc, frag->lirbuf->names, _logc,
+										 "After Storefilter(sp)");
+		prev = pp_after_sf1;
+		})
+
+		// STOREFILTER for rp
+		StackFilter storefilter2(prev, gc, frag->lirbuf, frag->lirbuf->rp);
+		prev = &storefilter2;
+
+		verbose_only( if (_logc->lcbits & LC_AfterSF_RP) {
+		pp_after_sf2 = new ReverseLister(prev, gc, frag->lirbuf->names, _logc,
+										 "After StoreFilter(rp)");
+		prev = pp_after_sf2;
+		})
+
+		// DEAD CODE FILTER
+		DeadCodeFilter deadfilter(prev);
+		prev = &deadfilter;
+
+		verbose_only( if (_logc->lcbits & LC_AfterDeadF) {
+		pp_after_dead = new ReverseLister(prev, gc, frag->lirbuf->names, _logc,
+										  "After DeadFilter == Final LIR");
+		prev = pp_after_dead;
+		})
+
+		// end of pipeline
+		verbose_only(
+		VerboseBlockReader vbr(prev, this, frag->lirbuf->names);
+		if (_logc->lcbits & LC_Assembly)
+			prev = &vbr;
 		)
 
 		verbose_only(_thisfrag->compileNbr++; )
 		verbose_only(_frago->_stats.compiles++; )
 		verbose_only(_frago->_stats.totalCompiles++; )
 		_inExit = false;	
-        gen(rdr, loopJumps);
+        gen(prev, loopJumps);
 		frag->loopEntry = _nIns;
 		//frag->outbound = core->config.tree_opt? _latestGuard : 0;
 		//nj_dprintf("assemble frag %X entry %X\n", (int)frag, (int)frag->fragEntry);
@@ -814,6 +915,16 @@ namespace nanojit
             // In case of failure, reset _nIns ready for the next assembly run.
             resetInstructionPointer();
 		}
+
+		// If we were accumulating debug info in the various ReverseListers,
+		// destruct them now.  Their destructors cause them to emit whatever
+		// contents they have accumulated.
+		verbose_only(
+		if (pp_init)       delete pp_init;
+		if (pp_after_sf1)  delete pp_after_sf1;
+		if (pp_after_sf2)  delete pp_after_sf2;
+		if (pp_after_dead) delete pp_after_dead;
+   	    )
 	}
 
 	void Assembler::endAssembly(Fragment* frag, NInsList& loopJumps)
@@ -826,7 +937,7 @@ namespace nanojit
 	    NIns* SOT = 0;
 	    if (frag->isRoot()) {
 	        SOT = frag->loopEntry;
-            verbose_only( verbose_outputf("        %p:",_nIns); )
+            verbose_only( verbose_outputf("%010lx:", (unsigned long)_nIns); )
 	    } else {
 	        SOT = frag->root->fragEntry;
 	    }
@@ -834,7 +945,8 @@ namespace nanojit
 		while(!loopJumps.isEmpty())
 		{
 			NIns* loopJump = (NIns*)loopJumps.removeLast();
-            verbose_only( verbose_outputf("patching %p to %p", loopJump, SOT); )
+            verbose_only( verbose_outputf("## patching branch at %010lx to %010lx",
+										  loopJump, SOT); )
 			nPatchBranch(loopJump, SOT);
 		}
 
@@ -1312,7 +1424,7 @@ namespace nanojit
                         intersectRegisterState(label->regs);
                         label->addr = _nIns;
                     }
-					verbose_only( if (_verbose) { outputAddr=true; asm_output("[%s]", _thisfrag->lirbuf->names->formatRef(ins)); } )
+					verbose_only( if (_logc->lcbits & LC_Assembly) { outputAddr=true; asm_output("[%s]", _thisfrag->lirbuf->names->formatRef(ins)); } )
 					break;
 				}
 				case LIR_xbarrier: {
@@ -1342,7 +1454,8 @@ namespace nanojit
 				case LIR_x:
 				{
                     countlir_x();
-		            verbose_only(verbose_output(""));
+		            verbose_only( if (_logc->lcbits & LC_Assembly)
+									  asm_output("FIXME-whats-this?\n"); )
 					// generate the side exit branch on the main trace.
                     NIns *exit = asm_exit(ins);
 					JMP( exit ); 
@@ -1507,7 +1620,7 @@ namespace nanojit
 #ifdef NANOJIT_ARM
 		// @todo Why is there here?!?  This routine should be indep. of platform
 		verbose_only(
-			if (_verbose) {
+			if (_logc->lcbits & LC_Assembly) {
 				char* s = &outline[0];
 				memset(s, ' ', 51);  s[51] = '\0';
 				s += strlen(s);
@@ -1526,7 +1639,7 @@ namespace nanojit
 #else
 		verbose_only(
 			char* s = &outline[0];
-			if (_verbose) {
+			if (_logc->lcbits & LC_Assembly) {
 				memset(s, ' ', 51);  s[51] = '\0';
 				s += strlen(s);
 				sprintf(s, " ebp ");
@@ -1733,7 +1846,11 @@ namespace nanojit
 			}
 		}
         assignSaved(saved, skip);
-		verbose_only( if (shouldMention) verbose_outputf("                                              merging registers (intersect) with existing edge");  )
+		verbose_only(
+		    if (shouldMention)
+                verbose_outputf("## merging registers (intersect) "
+                                "with existing edge");
+        )
 	}
 
 	/**
@@ -1863,13 +1980,13 @@ namespace nanojit
             }
             else
             {
-                nj_dprintf("%s\n", s);
+                _logc->printf("%s\n", s);
             }
         }
 
         void Assembler::output_asm(const char* s)
         {
-            if (!verbose_enabled())
+            if (!(_logc->lcbits & LC_Assembly))
                 return;
 
             // Add the EOL string to the output, ensuring that we leave enough

js/src/nanojit/Assembler.h

@@ -159,13 +159,19 @@ namespace nanojit
 			void FASTCALL outputf(const char* format, ...); 
 			void FASTCALL output_asm(const char* s); 
 			
-			bool _verbose, outputAddr, vpad[2];  // if outputAddr=true then next asm instr. will include address in output
+			// if outputAddr=true then next asm instr. will include
+			// address in output
+			bool outputAddr, vpad[2];
 			void printActivationState();
 
 			StringList* _outputCache;
+
+			// Log controller object.  Contains what-stuff-should-we-print
+			// bits, and a sink function for debug printing
+			LogControl* _logc;
 			#endif
 
-			Assembler(Fragmento* frago);
+			Assembler(Fragmento* frago, LogControl* logc);
             ~Assembler() {}
 
 			void		assemble(Fragment* frag, NInsList& loopJumps);

js/src/nanojit/Fragmento.cpp

@@ -57,7 +57,7 @@ namespace nanojit
 	/**
 	 * This is the main control center for creating and managing fragments.
 	 */
-	Fragmento::Fragmento(AvmCore* core, uint32_t cacheSizeLog2) 
+	Fragmento::Fragmento(AvmCore* core, LogControl* logc, uint32_t cacheSizeLog2) 
 		:
 #ifdef NJ_VERBOSE
 		  enterCounts(NULL),
@@ -99,7 +99,7 @@ namespace nanojit
 		NanoAssert(_max_pages > _pagesGrowth); // shrink growth if needed 
 		_core = core;
 		GC *gc = core->GetGC();
-		_assm = NJ_NEW(gc, nanojit::Assembler)(this);
+		_assm = NJ_NEW(gc, nanojit::Assembler)(this, logc);
 		verbose_only( enterCounts = NJ_NEW(gc, BlockHist)(gc); )
 		verbose_only( mergeCounts = NJ_NEW(gc, BlockHist)(gc); )
 
@@ -384,9 +384,6 @@ namespace nanojit
 
 	void Fragmento::dumpStats()
 	{
-		bool vsave = _assm->_verbose;
-		_assm->_verbose = true;
-
 		_assm->output("");
 		dumpRatio("inline", enterCounts);
 		dumpRatio("merges", mergeCounts);
@@ -403,7 +400,6 @@ namespace nanojit
 		if (!count)
 		{
 			_assm->outputf("No fragments in cache, %d flushes", flushes);
-    		_assm->_verbose = vsave;
             return;
 		}
 
@@ -468,14 +464,12 @@ namespace nanojit
 				labels->format(d.frag->ip));
 		}
 
-		_assm->_verbose = vsave;
-
 	}
 
 	void Fragmento::countBlock(BlockHist *hist, const void* ip)
 	{
 		int c = hist->count(ip);
-		if (_assm->_verbose)
+		if (_assm->_logc->lcbits & LC_Assembly)
 			_assm->outputf("++ %s %d", labels->format(ip), c);
 	}
 

js/src/nanojit/Fragmento.h

@@ -94,7 +94,7 @@ namespace nanojit
 	class Fragmento : public avmplus::GCFinalizedObject
 	{
 		public:
-			Fragmento(AvmCore* core, uint32_t cacheSizeLog2);
+			Fragmento(AvmCore* core, LogControl* logc, uint32_t cacheSizeLog2);
 			~Fragmento();
 
 			void		addMemory(void* firstPage, uint32_t pageCount);  // gives memory to the Assembler

js/src/nanojit/LIR.cpp

@@ -45,18 +45,6 @@
 #endif /* PERFM */
 
 
-#if defined(NJ_VERBOSE)
-void nj_dprintf( const char* format, ... )
-{
-	va_list vargs;
-	va_start(vargs, format);
-	vfprintf(stdout, format, vargs);
-	va_end(vargs);
-}
-#endif /* NJ_VERBOSE */
-
-
-
 namespace nanojit
 {
     using namespace avmplus;
@@ -1486,7 +1474,7 @@ namespace nanojit
 		}
 	};
 
-    void live(GC *gc, Fragment *frag)
+    void live(GC *gc, Fragment *frag, LogControl *logc)
 	{
 		// traverse backwards to find live exprs and a few other stats.
 
@@ -1538,9 +1526,11 @@ namespace nanojit
 			}
 		}
  
-		nj_dprintf("live instruction count %d, total %u, max pressure %d\n",
+		logc->printf("  Live instruction count %d, total %u, max pressure %d\n",
-			live.retired.size(), total, live.maxlive);
+					 live.retired.size(), total, live.maxlive);
-        nj_dprintf("side exits %u\n", exits);
+        logc->printf("  Side exits %u\n", exits);
+		logc->printf("  Showing LIR instructions with live-after variables\n");
+		logc->printf("\n");
 
 		// print live exprs, going forwards
 		LirNameMap *names = frag->lirbuf->names;
@@ -1551,7 +1541,7 @@ namespace nanojit
             char livebuf[4000], *s=livebuf;
             *s = 0;
             if (!newblock && e->i->isop(LIR_label)) {
-                nj_dprintf("\n");
+                logc->printf("\n");
             }
             newblock = false;
             for (int k=0,n=e->live.size(); k < n; k++) {
@@ -1560,9 +1550,18 @@ namespace nanojit
 				*s++ = ' '; *s = 0;
 				NanoAssert(s < livebuf+sizeof(livebuf));
             }
-			nj_dprintf("%-60s %s\n", livebuf, names->formatIns(e->i));
+			/* If the LIR insn is pretty short, print it and its
+			   live-after set on the same line.  If not, put
+			   live-after set on a new line, suitably indented. */
+			const char* insn_text = names->formatIns(e->i);
+			if (strlen(insn_text) >= 30-2) {
+				logc->printf("  %-30s\n  %-30s %s\n", names->formatIns(e->i), "", livebuf);
+			} else {
+				logc->printf("  %-30s %s\n", names->formatIns(e->i), livebuf);
+			}
+
             if (e->i->isGuard() || e->i->isBranch() || e->i->isRet()) {
-				nj_dprintf("\n");
+				logc->printf("\n");
                 newblock = true;
             }
 		}
@@ -1965,12 +1964,35 @@ namespace nanojit
         AvmCore *core = frago->core();
         GC *gc = core->gc;
 
+		verbose_only(
+		LogControl *logc = assm->_logc;
+		bool anyVerb = (logc->lcbits & 0xFFFF) > 0;
+		bool asmVerb = (logc->lcbits & 0xFFFF & LC_Assembly) > 0;
+		bool liveVerb = (logc->lcbits & 0xFFFF & LC_Liveness) > 0;
+		)
+
+		/* BEGIN decorative preamble */
+		verbose_only( 
+        if (anyVerb) {
+			logc->printf("========================================"
+						 "========================================\n");
+			logc->printf("=== BEGIN LIR::compile(%p, %p)\n",
+						 (void*)assm, (void*)triggerFrag);
+		    logc->printf("===\n");
+		})
+		/* END decorative preamble */
+
+		verbose_only( if (liveVerb) {
+		    logc->printf("\n");
+			logc->printf("=== Results of liveness analysis:\n");
+		    logc->printf("===\n");
+			live(gc, triggerFrag, logc);
+		})
+
+		/* Set up the generic text output cache for the assembler */
 		verbose_only( StringList asmOutput(gc); )
 		verbose_only( assm->_outputCache = &asmOutput; )
 
-		verbose_only(if (assm->_verbose && core->config.verbose_live)
-			live(gc, triggerFrag);)
-
 		bool treeCompile = core->config.tree_opt && (triggerFrag->kind == BranchTrace);
 		RegAllocMap regMap(gc);
 		NInsList loopJumps(gc);
@@ -1981,28 +2003,44 @@ namespace nanojit
 		if (assm->error())
 			return;
 
-		//nj_dprintf("recompile trigger %X kind %d\n", (int)triggerFrag, triggerFrag->kind);
+		//logc->printf("recompile trigger %X kind %d\n", (int)triggerFrag, triggerFrag->kind);
+
+		verbose_only( if (anyVerb) {
+		    logc->printf("=== Translating LIR fragments into assembly:\n");
+		})
+
 		Fragment* root = triggerFrag;
 		if (treeCompile)
 		{
 			// recompile the entire tree
+			verbose_only( if (anyVerb) {
+			   logc->printf("=== -- Compile the entire tree: begin\n");
+			})
 			root = triggerFrag->root;
 			root->fragEntry = 0;
 			root->loopEntry = 0;
 			root->releaseCode(frago);
 			
 			// do the tree branches
+			verbose_only( if (anyVerb) {
+			   logc->printf("=== -- Do the tree branches\n");
+			})
 			Fragment* frag = root->treeBranches;
-			while(frag)
+			while (frag)
 			{
 				// compile til no more frags
 				if (frag->lastIns)
 				{
+        			verbose_only( if (anyVerb) {
+					    logc->printf("=== -- Compiling branch %s ip %s\n",
+									 frago->labels->format(frag),
+									 frago->labels->format(frag->ip));
+					})
 					assm->assemble(frag, loopJumps);
-					verbose_only(if (assm->_verbose) 
+					verbose_only(if (asmVerb) 
-						assm->outputf("compiling branch %s ip %s",
+						assm->outputf("## compiling branch %s ip %s",
-							frago->labels->format(frag),
+									  frago->labels->format(frag),
-							frago->labels->format(frag->ip)); )
+									  frago->labels->format(frag->ip)); )
 					
 					NanoAssert(frag->kind == BranchTrace);
 					RegAlloc* regs = NJ_NEW(gc, RegAlloc)();
@@ -2013,14 +2051,29 @@ namespace nanojit
 				}
 				frag = frag->treeBranches;
 			}
+			verbose_only( if (anyVerb) {
+			   logc->printf("=== -- Compile the entire tree: end\n");
+			})
 		}
 		
 		// now the the main trunk
+		verbose_only( if (anyVerb) {
+		    logc->printf("=== -- Compile trunk %s: begin\n",
+						 frago->labels->format(root));
+		})
 		assm->assemble(root, loopJumps);
-		verbose_only(if (assm->_verbose) 
+		verbose_only( if (anyVerb) {
-			assm->outputf("compiling trunk %s",
+		    logc->printf("=== -- Compile trunk %s: end\n",
-				frago->labels->format(root));)
+						 frago->labels->format(root));
-		NanoAssert(!frago->core()->config.tree_opt || root == root->anchor || root->kind == MergeTrace);			
+		})
+
+		verbose_only(
+		    if (asmVerb) 
+				assm->outputf("## compiling trunk %s",
+							  frago->labels->format(root));
+		)
+		NanoAssert(!frago->core()->config.tree_opt
+				   || root == root->anchor || root->kind == MergeTrace);
 		assm->endAssembly(root, loopJumps);
 			
 		// reverse output so that assembly is displayed low-to-high
@@ -2028,14 +2081,37 @@ namespace nanojit
 		// has been accumulating output.  Now we set it to NULL, traverse
 		// the entire list of stored strings, and hand them a second time
 		// to assm->output.  Since _outputCache is now NULL, outputf just
-		// hands these strings directly onwards to nj_dprintf.
+		// hands these strings directly onwards to logc->printf.
-		verbose_only( assm->_outputCache = 0; )
+		verbose_only( if (anyVerb) {
-		verbose_only(for(int i=asmOutput.size()-1; i>=0; --i) { assm->outputf("%s",asmOutput.get(i)); } );
+   		    logc->printf("\n");
+			logc->printf("=== Aggregated assembly output: BEGIN\n");
+   		    logc->printf("===\n");
+		    assm->_outputCache = 0;
+			for (int i = asmOutput.size() - 1; i >= 0; --i) { 
+				char* str = asmOutput.get(i);
+				assm->outputf("  %s", str);
+				gc->Free(str);
+			}
+   		    logc->printf("===\n");
+			logc->printf("=== Aggregated assembly output: END\n");
+		});
 
 		if (assm->error()) {
 			root->fragEntry = 0;
 			root->loopEntry = 0;
 		}
+
+		/* BEGIN decorative postamble */
+		verbose_only( if (anyVerb) {
+		    logc->printf("\n");
+		    logc->printf("===\n");
+		    logc->printf("=== END LIR::compile(%p, %p)\n",
+						 (void*)assm, (void*)triggerFrag);
+			logc->printf("========================================"
+						 "========================================\n");
+			logc->printf("\n");
+		});
+		/* END decorative postamble */
     }
 
     LInsp LoadFilter::insLoad(LOpcode v, LInsp base, LInsp disp)
@@ -2158,6 +2234,19 @@ namespace nanojit
 		strcpy(s, b);
 		return s;
 	}
+
+	// ---------------------------------------------------------------
+	// START debug-logging definitions
+	// ---------------------------------------------------------------
+
+	void LogControl::printf( const char* format, ... )
+	{
+        va_list vargs;
+        va_start(vargs, format);
+        vfprintf(stdout, format, vargs);
+        va_end(vargs);
+	}
+
 #endif // NJ_VERBOSE
 }
 	

js/src/nanojit/LIR.h

@@ -582,9 +582,11 @@ namespace nanojit
 	{
 		InsList code;
 		DWB(LirNameMap*) names;
+		LogControl* logc;
     public:
-		VerboseWriter(avmplus::GC *gc, LirWriter *out, LirNameMap* names) 
+		VerboseWriter(avmplus::GC *gc, LirWriter *out,
-			: LirWriter(out), code(gc), names(names)
+					  LirNameMap* names, LogControl* logc)
+			: LirWriter(out), code(gc), names(names), logc(logc)
 		{}
 
 		LInsp add(LInsp i) {
@@ -604,10 +606,10 @@ namespace nanojit
             int n = code.size();
             if (n) {
 			    for (int i=0; i < n; i++)
-				    nj_dprintf("    %s\n",names->formatIns(code[i]));
+				    logc->printf("    %s\n",names->formatIns(code[i]));
 			    code.clear();
                 if (n > 1)
-        			nj_dprintf("\n");
+        			logc->printf("\n");
             }
 		}
 

js/src/nanojit/Native.h

@@ -99,18 +99,20 @@ namespace nanojit {
 		#define gpn(r)					regNames[(r)]
 		#define fpn(r)					regNames[(r)]
 	#elif defined(NJ_VERBOSE)
-		#define asm_output(...) do {\
+		#define asm_output(...) do { \
-			counter_increment(native);\
+			counter_increment(native); \
-			if (verbose_enabled()) {\
+			if (_logc->lcbits & LC_Assembly) { \
-				outline[0]='\0';\
+				outline[0]='\0'; \
-				if (outputAddr) sprintf(outline, "  %10p  ",_nIns);\
+				if (outputAddr) \
-				else sprintf(outline, "              ");\
+                   sprintf(outline, "%010lx   ", (unsigned long)_nIns); \
-				sprintf(&outline[14], ##__VA_ARGS__);\
+				else \
-				Assembler::outputAlign(outline, 45);\
+                   memset(outline, (int)' ', 10+3); \
-				RegAlloc::formatRegisters(_allocator, outline, _thisfrag);\
+				sprintf(&outline[13], ##__VA_ARGS__); \
-				Assembler::output_asm(outline);\
+				Assembler::outputAlign(outline, 35); \
-				outputAddr=false; /* set =true if you like to see addresses for each native instruction */ \
+				RegAlloc::formatRegisters(_allocator, outline, _thisfrag); \
-			}\
+				Assembler::output_asm(outline); \
+				outputAddr=(_logc->lcbits & LC_NoCodeAddrs) ? false : true;	\
+			} \
 		} while (0) /* no semi */ 
 		#define gpn(r)					regNames[(r)] 
 		#define fpn(r)					regNames[(r)] 

js/src/nanojit/NativeARM.cpp

@@ -157,8 +157,8 @@ Assembler::genPrologue()
     if (amt)
         SUBi(SP, SP, amt);
 
-    verbose_only( verbose_outputf("         %p:",_nIns); )
+    verbose_only( asm_output("## %p:",(void*)_nIns); )
-    verbose_only( verbose_output("         patch entry"); )
+    verbose_only( asm_output("## patch entry"); )
     NIns *patchEntry = _nIns;
 
     MOV(FP, SP);
@@ -694,8 +694,7 @@ Assembler::asm_restore(LInsp i, Reservation *resv, Register r)
     }
 
     verbose_only(
-        if (_verbose)
+        asm_output("        restore %s",_thisfrag->lirbuf->names->formatRef(i));
-            outputf("        restore %s",_thisfrag->lirbuf->names->formatRef(i));
     )
 }
 
@@ -1076,7 +1075,7 @@ Assembler::JMP_far(NIns* addr)
         // B [PC+offs]
         *(--_nIns) = (NIns)( COND_AL | (0xA<<24) | ((offs>>2) & 0xFFFFFF) );
 
-        asm_output("b %p", addr);
+        asm_output("b %p", (void*)addr);
     } else {
         // Insert the target address as a constant in the instruction stream.
         *(--_nIns) = (NIns)((addr));
@@ -1084,7 +1083,7 @@ Assembler::JMP_far(NIns* addr)
         // the next instruction)
         *(--_nIns) = (NIns)( COND_AL | (0x51<<20) | (PC<<16) | (PC<<12) | (4));
 
-        asm_output("ldr pc, =%p", addr);
+        asm_output("ldr pc, =%p", (void*)addr);
     }
 }
 
@@ -1123,7 +1122,7 @@ Assembler::BranchWithLink(NIns* addr)
             // BL addr
             NanoAssert( ((offs>>2) & ~0xffffff) == 0);
             *(--_nIns) = (NIns)( (COND_AL) | (0xB<<24) | (offs>>2) );
-            asm_output("bl %p", addr);
+            asm_output("bl %p", (void*)addr);
         } else {
             // The target is Thumb, so emit a BLX.
 
@@ -1133,12 +1132,12 @@ Assembler::BranchWithLink(NIns* addr)
             // BLX addr
             NanoAssert( ((offs>>2) & ~0xffffff) == 0);
             *(--_nIns) = (NIns)( (0xF << 28) | (0x5<<25) | (H) | (offs>>2) );
-            asm_output("blx %p", addr);
+            asm_output("blx %p", (void*)addr);
         }
     } else {
         // BLX IP
         *(--_nIns) = (NIns)( (COND_AL) | (0x12<<20) | (0xFFF<<8) | (0x3<<4) | (IP) );
-        asm_output("blx ip (=%p)", addr);
+        asm_output("blx ip (=%p)", (void*)addr);
 
         // LDR IP, =addr
         LD32_nochk(IP, (int32_t)addr);
@@ -1193,7 +1192,7 @@ Assembler::LD32_nochk(Register r, int32_t imm)
 
     // Write the literal.
     *(++_nSlot) = imm;
-    asm_output("  (%d(PC) = 0x%x)", offset, imm);
+    asm_output("## imm= 0x%x", imm);
 
     // Load the literal.
     LDR_nochk(r,PC,offset);

js/src/nanojit/Nativei386.cpp

@@ -414,7 +414,9 @@ namespace nanojit
 	void Assembler::asm_restore(LInsp i, Reservation *resv, Register r)
 	{
         if (i->isop(LIR_alloc)) {
-			verbose_only( if (_verbose) { outputForEOL("  <= remat %s size %d", _thisfrag->lirbuf->names->formatRef(i), i->size()); } )
+			verbose_only( if (_logc->lcbits & LC_RegAlloc) {
+					        outputForEOL("  <= remat %s size %d",
+							_thisfrag->lirbuf->names->formatRef(i), i->size()); } )
             LEA(r, disp(resv), FP);
         }
         else if (i->isconst()) {
@@ -425,7 +427,9 @@ namespace nanojit
         }
         else {
             int d = findMemFor(i);
-			verbose_only( if (_verbose) { outputForEOL("  <= restore %s", _thisfrag->lirbuf->names->formatRef(i)); } )
+			verbose_only( if (_logc->lcbits & LC_RegAlloc) {
+					        outputForEOL("  <= restore %s", 
+							_thisfrag->lirbuf->names->formatRef(i)); } )
 			asm_load(d,r);
         }
 	}

js/src/nanojit/Nativei386.h

@@ -338,18 +338,18 @@ namespace nanojit
 
 #define LAHF()		do { count_alu(); ALU0(0x9F);					asm_output("lahf"); } while(0)
 #define SAHF()		do { count_alu(); ALU0(0x9E);					asm_output("sahf"); } while(0)
-#define OR(l,r)		do { count_alu(); ALU(0x0b, (l),(r));			asm_output("or %s,%s",gpn(l),gpn(r)); } while(0)
+#define OR(l,r)		do { count_alu(); ALU(0x0b, (l),(r));			asm_output("or    %s,%s",gpn(l),gpn(r)); } while(0)
-#define AND(l,r)	do { count_alu(); ALU(0x23, (l),(r));			asm_output("and %s,%s",gpn(l),gpn(r)); } while(0)
+#define AND(l,r)	do { count_alu(); ALU(0x23, (l),(r));			asm_output("and   %s,%s",gpn(l),gpn(r)); } while(0)
-#define XOR(l,r)	do { count_alu(); ALU(0x33, (l),(r));			asm_output("xor %s,%s",gpn(l),gpn(r)); } while(0)
+#define XOR(l,r)	do { count_alu(); ALU(0x33, (l),(r));			asm_output("xor   %s,%s",gpn(l),gpn(r)); } while(0)
-#define ADD(l,r)	do { count_alu(); ALU(0x03, (l),(r));			asm_output("add %s,%s",gpn(l),gpn(r)); } while(0)
+#define ADD(l,r)	do { count_alu(); ALU(0x03, (l),(r));			asm_output("add   %s,%s",gpn(l),gpn(r)); } while(0)
-#define SUB(l,r)	do { count_alu(); ALU(0x2b, (l),(r));			asm_output("sub %s,%s",gpn(l),gpn(r)); } while(0)
+#define SUB(l,r)	do { count_alu(); ALU(0x2b, (l),(r));			asm_output("sub   %s,%s",gpn(l),gpn(r)); } while(0)
-#define MUL(l,r)	do { count_alu(); ALU2(0x0faf,(l),(r));         asm_output("mul %s,%s",gpn(l),gpn(r)); } while(0)
+#define MUL(l,r)	do { count_alu(); ALU2(0x0faf,(l),(r));         asm_output("mul   %s,%s",gpn(l),gpn(r)); } while(0)
-#define DIV(r)      do { count_alu(); ALU(0xf7, (Register)7,(r));   asm_output("idiv edx:eax, %s",gpn(r)); } while(0)
+#define DIV(r)      do { count_alu(); ALU(0xf7, (Register)7,(r));   asm_output("idiv  edx:eax, %s",gpn(r)); } while(0)
-#define NOT(r)		do { count_alu(); ALU(0xf7, (Register)2,(r));	asm_output("not %s",gpn(r)); } while(0)
+#define NOT(r)		do { count_alu(); ALU(0xf7, (Register)2,(r));	asm_output("not   %s",gpn(r)); } while(0)
-#define NEG(r)		do { count_alu(); ALU(0xf7, (Register)3,(r));	asm_output("neg %s",gpn(r)); } while(0)
+#define NEG(r)		do { count_alu(); ALU(0xf7, (Register)3,(r));	asm_output("neg   %s",gpn(r)); } while(0)
-#define SHR(r,s)	do { count_alu(); ALU(0xd3, (Register)5,(r));	asm_output("shr %s,%s",gpn(r),gpn(s)); } while(0)
+#define SHR(r,s)	do { count_alu(); ALU(0xd3, (Register)5,(r));	asm_output("shr   %s,%s",gpn(r),gpn(s)); } while(0)
-#define SAR(r,s)	do { count_alu(); ALU(0xd3, (Register)7,(r));	asm_output("sar %s,%s",gpn(r),gpn(s)); } while(0)
+#define SAR(r,s)	do { count_alu(); ALU(0xd3, (Register)7,(r));	asm_output("sar   %s,%s",gpn(r),gpn(s)); } while(0)
-#define SHL(r,s)	do { count_alu(); ALU(0xd3, (Register)4,(r));	asm_output("shl %s,%s",gpn(r),gpn(s)); } while(0)
+#define SHL(r,s)	do { count_alu(); ALU(0xd3, (Register)4,(r));	asm_output("shl   %s,%s",gpn(r),gpn(s)); } while(0)
 
 #define SHIFT(c,r,i) \
 		underrunProtect(3);\
@@ -357,44 +357,44 @@ namespace nanojit
 		MODRM((Register)c,r);\
 		*--_nIns = 0xc1;
 
-#define SHLi(r,i)	do { count_alu(); SHIFT(4,r,i);	asm_output("shl %s,%d", gpn(r),i); } while(0)
+#define SHLi(r,i)	do { count_alu(); SHIFT(4,r,i);	asm_output("shl   %s,%d", gpn(r),i); } while(0)
-#define SHRi(r,i)	do { count_alu(); SHIFT(5,r,i);	asm_output("shr %s,%d", gpn(r),i); } while(0)
+#define SHRi(r,i)	do { count_alu(); SHIFT(5,r,i);	asm_output("shr   %s,%d", gpn(r),i); } while(0)
-#define SARi(r,i)	do { count_alu(); SHIFT(7,r,i);	asm_output("sar %s,%d", gpn(r),i); } while(0)
+#define SARi(r,i)	do { count_alu(); SHIFT(7,r,i);	asm_output("sar   %s,%d", gpn(r),i); } while(0)
 
 #define MOVZX8(d,s) do { count_alu(); ALU2(0x0fb6,d,s); asm_output("movzx %s,%s", gpn(d),gpn(s)); } while(0)
 
-#define SUBi(r,i)	do { count_alu(); ALUi(0x2d,r,i);				asm_output("sub %s,%d",gpn(r),i); } while(0)
+#define SUBi(r,i)	do { count_alu(); ALUi(0x2d,r,i);				asm_output("sub   %s,%d",gpn(r),i); } while(0)
-#define ADDi(r,i)	do { count_alu(); ALUi(0x05,r,i);				asm_output("add %s,%d",gpn(r),i); } while(0)
+#define ADDi(r,i)	do { count_alu(); ALUi(0x05,r,i);				asm_output("add   %s,%d",gpn(r),i); } while(0)
-#define ANDi(r,i)	do { count_alu(); ALUi(0x25,r,i);				asm_output("and %s,%d",gpn(r),i); } while(0)
+#define ANDi(r,i)	do { count_alu(); ALUi(0x25,r,i);				asm_output("and   %s,%d",gpn(r),i); } while(0)
-#define ORi(r,i)	do { count_alu(); ALUi(0x0d,r,i);				asm_output("or %s,%d",gpn(r),i); } while(0)
+#define ORi(r,i)	do { count_alu(); ALUi(0x0d,r,i);				asm_output("or    %s,%d",gpn(r),i); } while(0)
-#define XORi(r,i)	do { count_alu(); ALUi(0x35,r,i);				asm_output("xor %s,%d",gpn(r),i); } while(0)
+#define XORi(r,i)	do { count_alu(); ALUi(0x35,r,i);				asm_output("xor   %s,%d",gpn(r),i); } while(0)
 
-#define ADDmi(d,b,i) do { count_alust(); ALUmi(0x05, d, b, i); asm_output("add %d(%s), %d", d, gpn(b), i); } while(0)
+#define ADDmi(d,b,i) do { count_alust(); ALUmi(0x05, d, b, i); asm_output("add   %d(%s), %d", d, gpn(b), i); } while(0)
 
-#define TEST(d,s)	do { count_alu(); ALU(0x85,d,s);				asm_output("test %s,%s",gpn(d),gpn(s)); } while(0)
+#define TEST(d,s)	do { count_alu(); ALU(0x85,d,s);				asm_output("test  %s,%s",gpn(d),gpn(s)); } while(0)
-#define CMP(l,r)	do { count_alu(); ALU(0x3b, (l),(r));			asm_output("cmp %s,%s",gpn(l),gpn(r)); } while(0)
+#define CMP(l,r)	do { count_alu(); ALU(0x3b, (l),(r));			asm_output("cmp   %s,%s",gpn(l),gpn(r)); } while(0)
-#define CMPi(r,i)	do { count_alu(); ALUi(0x3d,r,i);				asm_output("cmp %s,%d",gpn(r),i); } while(0)
+#define CMPi(r,i)	do { count_alu(); ALUi(0x3d,r,i);				asm_output("cmp   %s,%d",gpn(r),i); } while(0)
 
-#define MR(d,s)		do { count_mov(); ALU(0x8b,d,s);				asm_output("mov %s,%s",gpn(d),gpn(s)); } while(0)
+#define MR(d,s)		do { count_mov(); ALU(0x8b,d,s);				asm_output("mov   %s,%s",gpn(d),gpn(s)); } while(0)
-#define LEA(r,d,b)	do { count_alu(); ALUm(0x8d, r,d,b);			asm_output("lea %s,%d(%s)",gpn(r),d,gpn(b)); } while(0)
+#define LEA(r,d,b)	do { count_alu(); ALUm(0x8d, r,d,b);			asm_output("lea   %s,%d(%s)",gpn(r),d,gpn(b)); } while(0)
 // lea %r, d(%i*4)
 // This addressing mode is not supported by the MODRMSIB macro.
 #define LEAmi4(r,d,i) do { count_alu(); IMM32(d); *(--_nIns) = (2<<6)|(i<<3)|5; *(--_nIns) = (0<<6)|(r<<3)|4; *(--_nIns) = 0x8d;                    asm_output("lea %s, %p(%s*4)", gpn(r), (void*)d, gpn(i)); } while(0)
 
 #define CDQ()       do { SARi(EDX, 31); MR(EDX, EAX); } while(0)
 
-#define SETE(r)		do { count_alu(); ALU2(0x0f94,(r),(r));			asm_output("sete %s",gpn(r)); } while(0)
+#define SETE(r)		do { count_alu(); ALU2(0x0f94,(r),(r));			asm_output("sete  %s",gpn(r)); } while(0)
 #define SETNP(r)	do { count_alu(); ALU2(0x0f9B,(r),(r));			asm_output("setnp %s",gpn(r)); } while(0)
-#define SETL(r)		do { count_alu(); ALU2(0x0f9C,(r),(r));			asm_output("setl %s",gpn(r)); } while(0)
+#define SETL(r)		do { count_alu(); ALU2(0x0f9C,(r),(r));			asm_output("setl  %s",gpn(r)); } while(0)
 #define SETLE(r)	do { count_alu(); ALU2(0x0f9E,(r),(r));			asm_output("setle %s",gpn(r)); } while(0)
-#define SETG(r)		do { count_alu(); ALU2(0x0f9F,(r),(r));			asm_output("setg %s",gpn(r)); } while(0)
+#define SETG(r)		do { count_alu(); ALU2(0x0f9F,(r),(r));			asm_output("setg  %s",gpn(r)); } while(0)
 #define SETGE(r)	do { count_alu(); ALU2(0x0f9D,(r),(r));			asm_output("setge %s",gpn(r)); } while(0)
-#define SETB(r)     do { count_alu(); ALU2(0x0f92,(r),(r));          asm_output("setb %s",gpn(r)); } while(0)
+#define SETB(r)     do { count_alu(); ALU2(0x0f92,(r),(r));          asm_output("setb  %s",gpn(r)); } while(0)
 #define SETBE(r)    do { count_alu(); ALU2(0x0f96,(r),(r));          asm_output("setbe %s",gpn(r)); } while(0)
-#define SETA(r)     do { count_alu(); ALU2(0x0f97,(r),(r));          asm_output("seta %s",gpn(r)); } while(0)
+#define SETA(r)     do { count_alu(); ALU2(0x0f97,(r),(r));          asm_output("seta  %s",gpn(r)); } while(0)
 #define SETAE(r)    do { count_alu(); ALU2(0x0f93,(r),(r));          asm_output("setae %s",gpn(r)); } while(0)
-#define SETC(r)     do { count_alu(); ALU2(0x0f90,(r),(r));          asm_output("setc %s",gpn(r)); } while(0)
+#define SETC(r)     do { count_alu(); ALU2(0x0f90,(r),(r));          asm_output("setc  %s",gpn(r)); } while(0)
-#define SETO(r)     do { count_alu(); ALU2(0x0f92,(r),(r));          asm_output("seto %s",gpn(r)); } while(0)
+#define SETO(r)     do { count_alu(); ALU2(0x0f92,(r),(r));          asm_output("seto  %s",gpn(r)); } while(0)
 
 #define MREQ(dr,sr)	do { count_alu(); ALU2(0x0f44,dr,sr); asm_output("cmove %s,%s", gpn(dr),gpn(sr)); } while(0)
 #define MRNE(dr,sr)	do { count_alu(); ALU2(0x0f45,dr,sr); asm_output("cmovne %s,%s", gpn(dr),gpn(sr)); } while(0)
@@ -416,12 +416,12 @@ namespace nanojit
 #define LD(reg,disp,base)	do { 	\
 	count_ld();\
 	ALUm(0x8b,reg,disp,base);	\
-	asm_output("mov %s,%d(%s)",gpn(reg),disp,gpn(base)); } while(0)
+	asm_output("mov   %s,%d(%s)",gpn(reg),disp,gpn(base)); } while(0)
 
 #define LDdm(reg,addr) do {		\
 	count_ld();                 \
 	ALUdm(0x8b,reg,addr);		\
-	asm_output("mov %s,0(%lx)",gpn(reg),(unsigned long)addr); \
+	asm_output("mov   %s,0(%lx)",gpn(reg),(unsigned long)addr); \
 	} while (0)
 
 
@@ -430,7 +430,7 @@ namespace nanojit
 #define LDsib(reg,disp,base,index,scale) do {	\
 	count_ld();                                 \
 	ALUsib(0x8b,reg,base,index,scale,disp);		\
-	asm_output("mov %s,%d(%s+%s*%c)",gpn(reg),disp,gpn(base),gpn(index),SIBIDX(scale)); \
+	asm_output("mov   %s,%d(%s+%s*%c)",gpn(reg),disp,gpn(base),gpn(index),SIBIDX(scale)); \
 	} while (0)
 
 // load 16-bit, sign extend
@@ -473,12 +473,12 @@ namespace nanojit
 	IMM32(i);					\
 	NanoAssert(((unsigned)r)<8); \
 	*(--_nIns) = (uint8_t) (0xb8 | (r) );		\
-	asm_output("mov %s,%d",gpn(r),i); } while(0)
+	asm_output("mov   %s,%d",gpn(r),i); } while(0)
 
 #define ST(base,disp,reg) do {  \
 	count_st();\
 	ALUm(0x89,reg,disp,base);	\
-    asm_output("mov %d(%s),%s",disp,base==UnknownReg?"0":gpn(base),gpn(reg)); } while(0)
+    asm_output("mov   %d(%s),%s",disp,base==UnknownReg?"0":gpn(base),gpn(reg)); } while(0)
 
 #define STi(base,disp,imm)	do { \
 	count_st();\
@@ -486,7 +486,7 @@ namespace nanojit
 	IMM32(imm);				\
 	MODRMm(0, disp, base);	\
 	*(--_nIns) = 0xc7;		\
-	asm_output("mov %d(%s),%d",disp,gpn(base),imm); } while(0)
+	asm_output("mov   %d(%s),%d",disp,gpn(base),imm); } while(0)
 
 #define RET()   do { count_ret(); ALU0(0xc3); asm_output("ret"); } while(0)
 #define NOP() 	do { count_alu(); ALU0(0x90); asm_output("nop"); } while(0)
@@ -497,7 +497,7 @@ namespace nanojit
 	if (isS8(i)) { \
 		underrunProtect(2);			\
 		_nIns-=2; _nIns[0] = 0x6a; _nIns[1] = (uint8_t)(i); \
-		asm_output("push %d",i); \
+		asm_output("push  %d",i); \
 	} else \
 		{ PUSHi32(i); } } while(0)
 
@@ -506,26 +506,26 @@ namespace nanojit
 	underrunProtect(5);	\
 	IMM32(i);			\
 	*(--_nIns) = 0x68;	\
-	asm_output("push %d",i); } while(0)
+	asm_output("push  %d",i); } while(0)
 
 #define PUSHr(r) do {  \
 	count_push();\
 	underrunProtect(1);			\
 	NanoAssert(((unsigned)r)<8); \
 	*(--_nIns) = (uint8_t) ( 0x50 | (r) );	\
-	asm_output("push %s",gpn(r)); } while(0)
+	asm_output("push  %s",gpn(r)); } while(0)
 
 #define PUSHm(d,b) do { \
 	count_pushld();\
 	ALUm(0xff, 6, d, b);		\
-	asm_output("push %d(%s)",d,gpn(b)); } while(0)
+	asm_output("push  %d(%s)",d,gpn(b)); } while(0)
 
 #define POPr(r) do { \
 	count_pop();\
 	underrunProtect(1);			\
 	NanoAssert(((unsigned)r)<8); \
 	*(--_nIns) = (uint8_t) ( 0x58 | (r) ); \
-	asm_output("pop %s",gpn(r)); } while(0)
+	asm_output("pop   %s",gpn(r)); } while(0)
 
 #define JCC32 0x0f
 #define JMP8  0xeb
@@ -540,14 +540,14 @@ namespace nanojit
 		_nIns -= 2; \
 		_nIns[0] = (uint8_t) ( 0x70 | (o) ); \
 		_nIns[1] = (uint8_t) (tt); \
-		asm_output("%s %p",(n),(next+tt)); \
+		asm_output("%-5s %p",(n),(next+tt)); \
 	} else { \
 		verbose_only( NIns* next = _nIns; ) \
 		IMM32(tt); \
 		_nIns -= 2; \
 		_nIns[0] = JCC32; \
 		_nIns[1] = (uint8_t) ( 0x80 | (o) ); \
-		asm_output("%s %p",(n),(next+tt)); \
+		asm_output("%-5s %p",(n),(next+tt)); \
 	} } while(0)
 
 #define JMP_long(t) do { \
@@ -555,7 +555,7 @@ namespace nanojit
 	underrunProtect(5);	\
 	intptr_t tt = (intptr_t)t - (intptr_t)_nIns;	\
 	JMP_long_nochk_offset(tt);	\
-    verbose_only( verbose_outputf("        %p:",_nIns); ) \
+    verbose_only( verbose_outputf("%010lx:", (unsigned long)_nIns); )	\
 	} while(0)
 
 #define JMP(t)		do { 	\
@@ -567,7 +567,7 @@ namespace nanojit
 		_nIns -= 2; \
 		_nIns[0] = JMP8; \
 		_nIns[1] = (uint8_t) ( (tt)&0xff ); \
-		asm_output("jmp %p",(next+tt)); \
+		asm_output("jmp   %p",(next+tt)); \
 	} else { \
 		JMP_long_nochk_offset(tt);	\
 	} } while(0)
@@ -577,13 +577,13 @@ namespace nanojit
 		verbose_only( NIns* next = _nIns; (void)next; ) \
  		IMM32((o)); \
  		*(--_nIns) = JMP32; \
-		asm_output("jmp %p",(next+(o))); } while(0)
+		asm_output("jmp   %p",(next+(o))); } while(0)
 
 #define JMP_indirect(r) do { \
         underrunProtect(2);  \
         MODRMm(4, 0, r);     \
         *(--_nIns) = 0xff;   \
-        asm_output("jmp *(%s)", gpn(r)); } while (0)
+        asm_output("jmp   *(%s)", gpn(r)); } while (0)
 
 #define JE(t, isfar)	   JCC(0x04, t, isfar, "je")
 #define JNE(t, isfar)	   JCC(0x05, t, isfar, "jne")
@@ -659,13 +659,13 @@ namespace nanojit
 #define SSE_LDQ(r,d,b)do {  \
 	count_ldq();\
     SSEm(0xf30f7e, (r)&7, (d), (b)); \
-    asm_output("movq %s,%d(%s)",gpn(r),d,gpn(b)); \
+    asm_output("movq  %s,%d(%s)",gpn(r),d,gpn(b)); \
     } while(0)
 
 #define SSE_STQ(d,b,r)do {  \
 	count_stq();\
     SSEm(0x660fd6, (r)&7, (d), (b)); \
-    asm_output("movq %d(%s),%s",(d),gpn(b),gpn(r)); \
+    asm_output("movq  %d(%s),%s",(d),gpn(b),gpn(r)); \
     } while(0)
 
 #define SSE_CVTSI2SD(xr,gr) do{ \
@@ -691,7 +691,7 @@ namespace nanojit
 		NanoAssert(_is_xmm_reg_(d)); \
 		SSE(0x660f6e, (d)&7, (s)&7); \
 	} \
-    asm_output("movd %s,%s",gpn(d),gpn(s)); \
+    asm_output("movd  %s,%s",gpn(d),gpn(s)); \
     } while(0)
 
 #define SSE_MOVSD(rd,rs) do{ \
@@ -705,7 +705,7 @@ namespace nanojit
 	count_st();\
     NanoAssert(_is_xmm_reg_(xrs) && _is_gp_reg_(b));\
     SSEm(0x660f7e, (xrs)&7, d, b);\
-    asm_output("movd %d(%s),%s", d, gpn(b), gpn(xrs));\
+    asm_output("movd  %d(%s),%s", d, gpn(b), gpn(xrs));\
     } while(0)
 
 #define SSE_ADDSD(rd,rs) do{ \
@@ -799,7 +799,7 @@ namespace nanojit
 		*(--_nIns) = ((uint8_t)(i));			\
 		*(--_nIns) = 0xc4;					\
 		*(--_nIns) = 0xf6;					\
-		asm_output("test ah, %d",i); } while(0)
+		asm_output("test  ah, %d",i); } while(0)
 
 #define TEST_AX(i) do { 							\
 		count_fpu();\
@@ -809,7 +809,7 @@ namespace nanojit
 		*(--_nIns) = ((uint8_t)((i)>>8));		\
 		*(--_nIns) = (0);		\
 		*(--_nIns) = 0xa9;					\
-		asm_output("test ax, %d",i); } while(0)
+		asm_output("test  ax, %d",i); } while(0)
 
 #define FNSTSW_AX()	do { count_fpu(); FPUc(0xdfe0);				asm_output("fnstsw_ax"); } while(0)
 #define FCHS()		do { count_fpu(); FPUc(0xd9e0);				asm_output("fchs"); } while(0)
@@ -819,20 +819,20 @@ namespace nanojit
 #define FSTQ(p,d,b)	do { count_stq(); FPUm(0xdd02|(p), d, b);	asm_output("fst%sq %d(%s)",((p)?"p":""),d,gpn(b)); if (p) fpu_pop(); } while(0)
 #define FSTPQ(d,b)  FSTQ(1,d,b)
 #define FCOM(p,d,b)	do { count_fpuld(); FPUm(0xdc02|(p), d, b);	asm_output("fcom%s %d(%s)",((p)?"p":""),d,gpn(b)); if (p) fpu_pop(); } while(0)
-#define FLDQ(d,b)	do { count_ldq(); FPUm(0xdd00, d, b);		asm_output("fldq %d(%s)",d,gpn(b)); fpu_push();} while(0)
+#define FLDQ(d,b)	do { count_ldq(); FPUm(0xdd00, d, b);		asm_output("fldq  %d(%s)",d,gpn(b)); fpu_push();} while(0)
 #define FILDQ(d,b)	do { count_fpuld(); FPUm(0xdf05, d, b);		asm_output("fildq %d(%s)",d,gpn(b)); fpu_push(); } while(0)
-#define FILD(d,b)	do { count_fpuld(); FPUm(0xdb00, d, b);		asm_output("fild %d(%s)",d,gpn(b)); fpu_push(); } while(0)
+#define FILD(d,b)	do { count_fpuld(); FPUm(0xdb00, d, b);		asm_output("fild  %d(%s)",d,gpn(b)); fpu_push(); } while(0)
-#define FADD(d,b)	do { count_fpu(); FPUm(0xdc00, d, b);		asm_output("fadd %d(%s)",d,gpn(b)); } while(0)
+#define FADD(d,b)	do { count_fpu(); FPUm(0xdc00, d, b);		asm_output("fadd  %d(%s)",d,gpn(b)); } while(0)
-#define FSUB(d,b)	do { count_fpu(); FPUm(0xdc04, d, b);		asm_output("fsub %d(%s)",d,gpn(b)); } while(0)
+#define FSUB(d,b)	do { count_fpu(); FPUm(0xdc04, d, b);		asm_output("fsub  %d(%s)",d,gpn(b)); } while(0)
 #define FSUBR(d,b)	do { count_fpu(); FPUm(0xdc05, d, b);		asm_output("fsubr %d(%s)",d,gpn(b)); } while(0)
-#define FMUL(d,b)	do { count_fpu(); FPUm(0xdc01, d, b);		asm_output("fmul %d(%s)",d,gpn(b)); } while(0)
+#define FMUL(d,b)	do { count_fpu(); FPUm(0xdc01, d, b);		asm_output("fmul  %d(%s)",d,gpn(b)); } while(0)
-#define FDIV(d,b)	do { count_fpu(); FPUm(0xdc06, d, b);		asm_output("fdiv %d(%s)",d,gpn(b)); } while(0)
+#define FDIV(d,b)	do { count_fpu(); FPUm(0xdc06, d, b);		asm_output("fdiv  %d(%s)",d,gpn(b)); } while(0)
 #define FDIVR(d,b)	do { count_fpu(); FPUm(0xdc07, d, b);		asm_output("fdivr %d(%s)",d,gpn(b)); } while(0)
 #define FINCSTP()	do { count_fpu(); FPUc(0xd9f7);				asm_output("fincstp"); } while(0)
-#define FSTP(r)		do { count_fpu(); FPU(0xddd8, r&7);			asm_output("fstp %s",fpn(r)); fpu_pop();} while(0)
+#define FSTP(r)		do { count_fpu(); FPU(0xddd8, r&7);			asm_output("fstp  %s",fpn(r)); fpu_pop();} while(0)
 #define FCOMP()		do { count_fpu(); FPUc(0xD8D9);				asm_output("fcomp"); fpu_pop();} while(0)
 #define FCOMPP()	do { count_fpu(); FPUc(0xDED9);				asm_output("fcompp"); fpu_pop();fpu_pop();} while(0)
-#define FLDr(r)		do { count_ldq(); FPU(0xd9c0,r);				asm_output("fld %s",fpn(r)); fpu_push(); } while(0)
+#define FLDr(r)		do { count_ldq(); FPU(0xd9c0,r);				asm_output("fld   %s",fpn(r)); fpu_push(); } while(0)
 #define EMMS()		do { count_fpu(); FPUc(0x0f77);				asm_output("emms"); } while (0)
 
 // standard direct call
@@ -842,7 +842,7 @@ namespace nanojit
   int offset = (c->_address) - ((int)_nIns); \
   IMM32( (uint32_t)offset );	\
   *(--_nIns) = 0xE8;		\
-  verbose_only(asm_output("call %s",(c->_name));) \
+  verbose_only(asm_output("call  %s",(c->_name));) \
   debug_only(if ((c->_argtypes&3)==ARGSIZE_F) fpu_push();)\
 } while (0)
 
@@ -851,7 +851,7 @@ namespace nanojit
   count_calli();\
   underrunProtect(2);\
   ALU(0xff, 2, (r));\
-  verbose_only(asm_output("call %s",gpn(r));) \
+  verbose_only(asm_output("call  %s",gpn(r));) \
   debug_only(if ((c->_argtypes&3)==ARGSIZE_F) fpu_push();)\
 } while (0)
 

js/src/nanojit/avmplus.h

@@ -323,7 +323,7 @@ namespace avmplus {
         Config() {
             memset(this, 0, sizeof(Config));
 #ifdef DEBUG
-            verbose = getenv("TRACEMONKEY") && strstr(getenv("TRACEMONKEY"), "verbose");
+            verbose = false;
             verbose_addrs = 1;
             verbose_exits = 1;
             verbose_live = 1;

js/src/nanojit/nanojit.h

@@ -181,20 +181,16 @@ namespace nanojit
 
 #if defined(_MSC_VER) && _MSC_VER < 1400
 	#include <stdio.h>
-	#define verbose_output						if (verbose_enabled()) Assembler::output
+	#define verbose_outputf			if (_logc->lcbits & LC_Assembly) \
-	#define verbose_outputf						if (verbose_enabled()) Assembler::outputf
+	                                    Assembler::outputf
-	#define verbose_enabled()					(_verbose)
+	#define verbose_only(x)		    x
-	#define verbose_only(x)						x
 #elif defined(NJ_VERBOSE)
 	#include <stdio.h>
-	#define verbose_output						if (verbose_enabled()) Assembler::output
+	#define verbose_outputf			if (_logc->lcbits & LC_Assembly) \
-	#define verbose_outputf						if (verbose_enabled()) Assembler::outputf
+	                                    Assembler::outputf
-	#define verbose_enabled()					(_verbose)
+	#define verbose_only(...)		__VA_ARGS__
-	#define verbose_only(...)					__VA_ARGS__
 #else
-	#define verbose_output
 	#define verbose_outputf
-	#define verbose_enabled()
 	#define verbose_only(...)
 #endif /*NJ_VERBOSE*/
 
@@ -243,11 +239,18 @@ namespace nanojit
 #define samepage(x,y)       ( pageTop(x) == pageTop(y) )
 
 
-/* Debug printing stuff.  All Nanojit debug printing should be routed
+// -------------------------------------------------------------------
-   through this function.  Don't use ad-hoc calls to printf,
+// START debug-logging definitions
-   fprintf(stderr, ...) etc. */
+// -------------------------------------------------------------------
 
-#if defined(NJ_VERBOSE)
+/* Debug printing stuff.  All Nanojit and jstracer debug printing
+   should be routed through LogControl::printf.  Don't use
+   ad-hoc calls to printf, fprintf(stderr, ...) etc.
+
+   Similarly, don't use ad-hoc getenvs etc to decide whether or not to
+   print debug output.  Instead consult the relevant control bit in
+   LogControl::lcbits in the LogControl object you are supplied with.
+*/
 
 # if defined(__GNUC__)
 # define PRINTF_CHECK(x, y) __attribute__((format(__printf__, x, y)))
@@ -255,10 +258,41 @@ namespace nanojit
 # define PRINTF_CHECK(x, y)
 # endif
 
-/* is in LIR.cpp */
+namespace nanojit {
-void nj_dprintf( const char* format, ... ) PRINTF_CHECK(1,2);
 
-#endif /* NJ_VERBOSE */
+	// LogControl, a class for controlling and routing debug output
+
+	enum LC_Bits {
+		/* Output control bits for Nanojit code.  Only use bits 15
+		   and below, so that callers can use bits 16 and above for
+		   themselves. */
+		// TODO: add entries for the writer pipeline
+		LC_Liveness    = 1<<7, // (show LIR liveness analysis)
+		LC_ReadLIR     = 1<<6, // As read from LirBuffer
+		LC_AfterSF_SP  = 1<<5, // After StackFilter(sp)
+		LC_AfterSF_RP  = 1<<4, // After StackFilter(rp)
+		LC_AfterDeadF  = 1<<3, // After DeadFilter
+		LC_RegAlloc    = 1<<2, // stuff to do with reg alloc
+		LC_Assembly    = 1<<1, // final assembly
+		LC_NoCodeAddrs = 1<<0  // (don't show code addresses on asm output)
+	};
+
+	class LogControl
+	{
+	public:
+		// All Nanojit and jstracer printing should be routed through
+		// this function.
+		void printf( const char* format, ... ) PRINTF_CHECK(2,3);
+
+		// An OR of LC_Bits values, indicating what should be output
+		uint32_t lcbits;
+	};
+
+}
+
+// -------------------------------------------------------------------
+// END debug-logging definitions
+// -------------------------------------------------------------------