[TIMOB-11769] CLI: colors, lines, and messages ill-formatted with CLI enabled

GitHub Issue	n/a
Type	Sub-task
Priority	Medium
Status	Closed
Resolution	Duplicate
Resolution Date	2013-03-05T01:12:12.000+0000
Affected Version/s	Release 3.0.0
Fix Version/s	Release 3.1.0
Components	CLI
Labels	cli, debugger, js, qe-ios100112
Reporter	Dustin Hyde
Assignee	Chris Barber
Created	2012-11-02T22:02:32.000+0000
Updated	2013-03-07T19:32:38.000+0000

Description

Console: colors, lines, and messages ill-formatted with CLI enabled (see screenshots). Steps to Reproduce: 1. Run code:

/* console */

if(Ti.Platform.osname != 'android') // TIMOB-11294 - Android: console: log functions fail in commonjs require
{
	console.log('console LOG');
	console.log(['console LOG', 'ARG1', 'ARG2']);
	 
	console.debug('console DEBUG');
	console.debug(['console DEBUG', 'ARG1', 'ARG2']);
	 
	console.info('console INFO');
	console.info(['console INFO', 'ARG1', 'ARG2']);
	 
	console.warn('console WARN');
	console.warn(['console WARN', 'ARG1', 'ARG2']);
	
	console.error('console ERROR');
	console.error(['console ERROR', 'ARG1', 'ARG2']);
}
else
{
	Ti.API.info('TIMOB-11294 - Android: console: log functions fail in commonjs require');
}

/* Ti.API */
 
Ti.API.trace('Ti.API TRACE');
Ti.API.trace(['Ti.API TRACE', 'ARG1', 'ARG2']);
 
Ti.API.debug('Ti.API DEBUG');
Ti.API.debug(['Ti.API DEBUG', 'ARG1', 'ARG2']);
 
Ti.API.info('Ti.API INFO');
Ti.API.info(['Ti.API INFO', 'ARG1', 'ARG2']);
 
Ti.API.warn('Ti.API WARN');
Ti.API.warn(['Ti.API WARN', 'ARG1', 'ARG2']);
 
Ti.API.error('Ti.API ERROR');
Ti.API.error(['Ti.API ERROR', 'ARG1', 'ARG2']);
 
/* Ti.API.log */
 
Ti.API.log('TRACE', 'Ti.API.log TRACE');
Ti.API.log('TRACE', ['Ti.API.log TRACE', 'ARG1', 'ARG2']);
 
Ti.API.log('DEBUG', 'Ti.API.log DEBUG');
Ti.API.log('DEBUG', ['Ti.API.log DEBUG', 'ARG1', 'ARG2']);
 
Ti.API.log('INFO', 'Ti.API.log INFO');
Ti.API.log('INFO', ['Ti.API.log INFO', 'ARG1', 'ARG2']);
 
Ti.API.log('WARN', 'Ti.API.log WARN');
Ti.API.log('WARN', ['Ti.API.log WARN', 'ARG1', 'ARG2']);
 
Ti.API.log('ERROR', 'Ti.API.log ERROR');
Ti.API.log('ERROR', ['Ti.API.log ERROR', 'ARG1', 'ARG2']);
 
Ti.API.log('LOG', 'Ti.API.log LOG');
Ti.API.log('LOG', ['Ti.API.log LOG', 'ARG1', 'ARG2']);
 
/* Ti.iOS.API */
 
if(Ti.Platform.osname == 'iphone' || Ti.Platform.osname == 'ipad')
{
    Ti.API.timestamp('Ti.API TIMESTAMP');
    Ti.API.timestamp(['Ti.API TIMESTAMP', 'ARG1', 'ARG2']);
}

Actual Result: colors, line formatting misaligned, and some messages do not display at all. Expected Result: colors, lines, and messages should appear and be properly formatted

Attachments

File	Date	Size
cli disabled.png	2012-11-02T22:07:02.000+0000	43928
cli enabled.png	2012-11-02T22:07:02.000+0000	43031
colors0.png	2012-11-02T22:02:32.000+0000	52522
colors1.png	2012-11-02T22:02:32.000+0000	53467
colors2.png	2012-11-02T22:02:32.000+0000	51465

Comments

Dustin Hyde 2012-11-02

Attaching colors(0-2).png (2.1.3.GA), there is strange coloring. Some messages aren't displaying and newline formatting is misaligned. Titanium Studio: 3.0.0.201210291448 Titanium SDK: 3.0.0.v20121030170824, 2.1.3.GA OS: Mountain Lion 10.8.2 Xcode: 4.5.2 Titanium CLI: 3.0.13 Titanium CLI: enabled This is caused by the CLI. Related to TISTUD-2698.

Christopher Williams 2012-11-14

Here's my observations: The coloring issues are handled by TISTUD-2698. Using the new CLI with a very recent SDK build, I am not seeing proper output inside Studio _and_ on the command line, indicating it's a platform issue. I have an app with a bunch of logging calls:

   Ti.API.trace('line0\nline1\nline2\nline3');
   Ti.API.trace(['Ti.API TRACE', 'ARG1', 'ARG2']);
     
   Ti.API.debug('line0\nline1\nline2\nline3');
   Ti.API.debug(['Ti.API DEBUG', 'ARG1', 'ARG2']);
     
   Ti.API.info('line0\nline1\nline2\nline3');
   Ti.API.info(['Ti.API INFO', 'ARG1', 'ARG2']);
     
   Ti.API.warn('line0\nline1\nline2\nline3');
   Ti.API.warn(['Ti.API WARN', 'ARG1', 'ARG2']);
     
   Ti.API.error('line0\nline1\nline2\nline3');
   Ti.API.error(['Ti.API ERROR', 'ARG1', 'ARG2']);

Running it against CLI 3.0.16 and SDK 3.0.0.v20121112163159 on the command line as:

   "/usr/local/bin/titanium" "--no-banner" "--no-colors" "--no-prompt" "build" "--platform" "iphone" "--sdk" "3.0.0.v20121112163159" "--log-level" "trace" "--target" "simulator" "--ios-version" "6.0" "--device-family" "iphone"

Here's what I see as the end of the output:

   [DEBUG] Found iPhone Simulator log file: /Users/cwilliams/Library/Application Support/iPhone Simulator/6.0/Applications/8246C10F-C9F0-463E-9071-B912CD17923D/Documents/19f00ffb-4c29-42ba-b9b7-1b088a8a374e.log
   [INFO] iPhone Simulator log:
   [DEBUG] line1
   [DEBUG] line2
   [DEBUG] line3
   [ERROR] ( 
   [ERROR] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [WARN] ActiveTab property points to tab not in list. Ignoring
   [DEBUG] Application booted in 39.372027 ms

Which indicates to me that the CLI/SDK is busted and is not spitting out all the output we expect. I see the same output inside the IDE.

Christopher Williams 2012-11-14

Another test, which shows that CLI output is being truncated/modified on some lines, as well as that the log level is being printed incorrectly for multi-line output. And it looks like the mis-classification and broken output from the CLI are causing the errors in Studio. app:

   console.log('console LOG');
   console.log(['console LOG', 'ARG1', 'ARG2']);
     
   console.debug('console DEBUG');
   console.debug(['console DEBUG', 'ARG1', 'ARG2']);
     
   console.info('console INFO');
   console.info(['console INFO', 'ARG1', 'ARG2']);
     
   console.warn('console WARN');
   console.warn(['console WARN', 'ARG1', 'ARG2']);
    
   console.error('console ERROR');
   console.error(['console ERROR', 'ARG1', 'ARG2']);
     
   Ti.API.trace('Ti.API TRACE');
   Ti.API.trace(['Ti.API TRACE', 'ARG1', 'ARG2']);
     
   Ti.API.debug('Ti.API DEBUG');
   Ti.API.debug(['Ti.API DEBUG', 'ARG1', 'ARG2']);
     
   Ti.API.info('Ti.API INFO');
   Ti.API.info(['Ti.API INFO', 'ARG1', 'ARG2']);
     
   Ti.API.warn('Ti.API WARN');
   Ti.API.warn(['Ti.API WARN', 'ARG1', 'ARG2']);
     
   Ti.API.error('Ti.API ERROR');
   Ti.API.error(['Ti.API ERROR', 'ARG1', 'ARG2']);
     
   Ti.API.log('TRACE', 'Ti.API.log TRACE');
   Ti.API.log('TRACE', ['Ti.API.log TRACE', 'ARG1', 'ARG2']);
     
   Ti.API.log('DEBUG', 'Ti.API.log DEBUG');
   Ti.API.log('DEBUG', ['Ti.API.log DEBUG', 'ARG1', 'ARG2']);
     
   Ti.API.log('INFO', 'Ti.API.log INFO');
   Ti.API.log('INFO', ['Ti.API.log INFO', 'ARG1', 'ARG2']);
     
   Ti.API.log('WARN', 'Ti.API.log WARN');
   Ti.API.log('WARN', ['Ti.API.log WARN', 'ARG1', 'ARG2']);
     
   Ti.API.log('ERROR', 'Ti.API.log ERROR');
   Ti.API.log('ERROR', ['Ti.API.log ERROR', 'ARG1', 'ARG2']);
     
   Ti.API.log('LOG', 'Ti.API.log LOG');
   Ti.API.log('LOG', ['Ti.API.log LOG', 'ARG1', 'ARG2']);
     
   if(Ti.Platform.osname == 'iphone' || Ti.Platform.osname == 'ipad')
   {
       Ti.API.timestamp('Ti.API TIMESTAMP');
       Ti.API.timestamp(['Ti.API TIMESTAMP', 'ARG1', 'ARG2']);
   }

Command line output:

   [DEBUG] Found iPhone Simulator log file: /Users/cwilliams/Library/Application Support/iPhone Simulator/6.0/Applications/8246C10F-C9F0-463E-9071-B912CD17923D/Documents/19f00ffb-4c29-42ba-b9b7-1b088a8a374e.log
   [INFO] iPhone Simulator log:
   [INFO] Application started
   [DEBUG] Reading stylesheet from: /Users/cwilliams/Library/Application Support/iPhone Simulator/6.0/Applications/8246C10F-C9F0-463E-9071-B912CD17923D/sfgsdfg.app/stylesheet.plist
   [INFO] sfgsdfg/1.0 (0.0.0.0d56fb4)
   [DEBUG] Analytics is enabled = YES
   [DEBUG] Loading: /Users/cwilliams/Library/Application Support/iPhone Simulator/6.0/Applications/8246C10F-C9F0-463E-9071-B912CD17923D/sfgsdfg.app/app.js, Resource: app_js
   [INFO] console LOG
   [INFO] ( 
   [DEBUG]     "console LOG",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [DEBUG] console DEBUG
   [DEBUG] ( 
   [DEBUG] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [INFO] console INFO
   [INFO] ( 
   [INFO] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [WARN] console WARN
   [WARN] ( 
   [WARN] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [ERROR] console ERROR
   [ERROR] ( 
   [ERROR] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [TRACE] Ti.API TRACE
   [TRACE] ( 
   [TRACE] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [DEBUG] Ti.API DEBUG
   [DEBUG] ( 
   [DEBUG] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [INFO] Ti.API INFO
   [INFO] ( 
   [INFO] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [WARN] Ti.API WARN
   [WARN] ( 
   [WARN] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [ERROR] Ti.API ERROR
   [ERROR] ( 
   [ERROR] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [TRACE] Ti.API.log TRACE
   [TRACE] ( 
   [TRACE] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [DEBUG] Ti.API.log DEBUG
   [DEBUG] ( 
   [DEBUG] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [INFO] Ti.API.log INFO
   [INFO] ( 
   [INFO] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [WARN] Ti.API.log WARN
   [WARN] ( 
   [WARN] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [ERROR] Ti.API.log ERROR
   [ERROR] ( 
   [ERROR] ",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [DEBUG] [LOG] Ti.API.log LOG
   [DEBUG] [LOG] (
   [DEBUG]     "Ti.API.log LOG",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [DEBUG] [TIMESTAMP] 374602955.638459 Ti.API TIMESTAMP
   [DEBUG] [TIMESTAMP] 374602955.638546 (
   [DEBUG]     "Ti.API TIMESTAMP",
   [DEBUG]     ARG1,
   [DEBUG]     ARG2
   [DEBUG] ) 
   [WARN] ActiveTab property points to tab not in list. Ignoring
   [DEBUG] Application booted in 40.673018 ms

Content of iphone log the output makes mention of:

   [INFO] Application started
   [DEBUG] Reading stylesheet from: /Users/cwilliams/Library/Application Support/iPhone Simulator/6.0/Applications/8246C10F-C9F0-463E-9071-B912CD17923D/sfgsdfg.app/stylesheet.plist
   [INFO] sfgsdfg/1.0 (0.0.0.0d56fb4)
   [DEBUG] Analytics is enabled = YES
   [DEBUG] Loading: /Users/cwilliams/Library/Application Support/iPhone Simulator/6.0/Applications/8246C10F-C9F0-463E-9071-B912CD17923D/sfgsdfg.app/app.js, Resource: app_js
   [INFO] console LOG
   [INFO] (
       "console LOG",
       ARG1,
       ARG2
   )
   [DEBUG] console DEBUG
   [DEBUG] (
       "console DEBUG",
       ARG1,
       ARG2
   )
   [INFO] console INFO
   [INFO] (
       "console INFO",
       ARG1,
       ARG2
   )
   [WARN] console WARN
   [WARN] (
       "console WARN",
       ARG1,
       ARG2
   )
   [ERROR] console ERROR
   [ERROR] (
       "console ERROR",
       ARG1,
       ARG2
   )
   [TRACE] Ti.API TRACE
   [TRACE] (
       "Ti.API TRACE",
       ARG1,
       ARG2
   )
   [DEBUG] Ti.API DEBUG
   [DEBUG] (
       "Ti.API DEBUG",
       ARG1,
       ARG2
   )
   [INFO] Ti.API INFO
   [INFO] (
       "Ti.API INFO",
       ARG1,
       ARG2
   )
   [WARN] Ti.API WARN
   [WARN] (
       "Ti.API WARN",
       ARG1,
       ARG2
   )
   [ERROR] Ti.API ERROR
   [ERROR] (
       "Ti.API ERROR",
       ARG1,
       ARG2
   )
   [TRACE] Ti.API.log TRACE
   [TRACE] (
       "Ti.API.log TRACE",
       ARG1,
       ARG2
   )
   [DEBUG] Ti.API.log DEBUG
   [DEBUG] (
       "Ti.API.log DEBUG",
       ARG1,
       ARG2
   )
   [INFO] Ti.API.log INFO
   [INFO] (
       "Ti.API.log INFO",
       ARG1,
       ARG2
   )
   [WARN] Ti.API.log WARN
   [WARN] (
       "Ti.API.log WARN",
       ARG1,
       ARG2
   )
   [ERROR] Ti.API.log ERROR
   [ERROR] (
       "Ti.API.log ERROR",
       ARG1,
       ARG2
   )
   [LOG] Ti.API.log LOG
   [LOG] (
       "Ti.API.log LOG",
       ARG1,
       ARG2
   )
   [TIMESTAMP] 374603024.160193 Ti.API TIMESTAMP
   [TIMESTAMP] 374603024.160246 (
       "Ti.API TIMESTAMP",
       ARG1,
       ARG2
   )
   [WARN] ActiveTab property points to tab not in list. Ignoring
   [DEBUG] Application booted in 184.858978 ms

And Studio's output when run inside the IDE with log level set to INFO (so DEBUG and TRACE are filtered out):

   [INFO] :  iPhone Simulator log:
   [INFO] :  Application started
   [INFO] :  sfgsdfg/1.0 (0.0.0.0d56fb4)
   [INFO] :  console LOG
   [INFO] :  (
   [INFO] :  console INFO
   [INFO] :  (
   [INFO] :  ",
   [WARN] :  console WARN
   [WARN] :  (
   [WARN] :  ",
   [ERROR] :  console ERROR
   [INFO] :  Ti.API INFO
   [INFO] :  (
   [INFO] :  ",
   [WARN] :  Ti.API WARN
   [WARN] :  (
   [WARN] :  ",
   [ERROR] :  (
   [ERROR] :  ",
   [ERROR] :  Ti.API ERROR
   [ERROR] :  (
   [ERROR] :  ",
   [INFO] :  Ti.API.log INFO
   [INFO] :  (
   [INFO] :  ",
   [WARN] :  Ti.API.log WARN
   [WARN] :  (
   [WARN] :  ",
   [ERROR] :  Ti.API.log ERROR
   [ERROR] :  (
   [ERROR] :  ",
   [WARN] :  ActiveTab property points to tab not in list. Ignoring

When you compare this versus the command line output you can see that the CLI is printing out the strings wrong in the multiline output just printing the ending ", - and that output with multiple lines that have some leading whitespace all get classified as [DEBUG] by the CLI improperly. As a result we're printing the bad string values and filtering the mis-classified lines (since they're below our log level threshold).

Dustin Hyde 2013-02-13

Using code:

   var win = Ti.UI.createWindow({
   	backgroundColor : 'blue'
   });
   
   var button = Ti.UI.createButton({
   	title : 'click',
   	top : '40%',
   	bottom : '40%',
   	left : '30%',
   	right : '30%'
   });
   
   button.addEventListener('click', function() {
   	console.log('console.log()');
   	console.log(['arg0', 'arg1', 'arg2']);
   
   	console.debug('console.debug()');
   	console.debug(['arg0', 'arg1', 'arg2']);
   
   	console.info('console.info()');
   	console.info(['arg0', 'arg1', 'arg2']);
   
   	console.warn('console.warn()');
   	console.warn(['arg0', 'arg1', 'arg2']);
   
   	console.error('console.error()');
   	console.error(['arg0', 'arg1', 'arg2']);
   
   	Ti.API.trace('Ti.API.trace()');
   	Ti.API.trace(['arg0', 'arg1', 'arg2']);
   
   	Ti.API.debug('Ti.API.debug([])');
   	Ti.API.debug(['arg0', 'arg1', 'arg2']);
   
   	Ti.API.info('Ti.API.info([])');
   	Ti.API.info(['arg0', 'arg1', 'arg2']);
   
   	Ti.API.warn('Ti.API.warn([])');
   	Ti.API.warn(['arg0', 'arg1', 'arg2']);
   
   	Ti.API.error('Ti.API.error([])');
   	Ti.API.error(['arg0', 'arg1', 'arg2']);
   
   	Ti.API.log('TRACE', 'Ti.API.log(TRACE)');
   	Ti.API.log('TRACE', ['arg0', 'arg1', 'arg2']);
   
   	Ti.API.log('DEBUG', 'Ti.API.log(DEBUG)');
   	Ti.API.log('DEBUG', ['arg0', 'arg1', 'arg2']);
   
   	Ti.API.log('INFO', 'Ti.API.log(INFO)');
   	Ti.API.log('INFO', ['arg0', 'arg1', 'arg2']);
   
   	Ti.API.log('WARN', 'Ti.API.log(WARN)');
   	Ti.API.log('WARN', ['arg0', 'arg1', 'arg2']);
   
   	Ti.API.log('ERROR', 'Ti.API.log(ERROR)');
   	Ti.API.log('ERROR', ['arg0', 'arg1', 'arg2']);
   
   	Ti.API.log('LOG', 'Ti.API.log(LOG)');
   	Ti.API.log('LOG', ['arg0', 'arg1', 'arg2']);
   
   	switch(Ti.Platform.osname)
   	{
   		case 'ipad':
   		case 'iphone':
   		{
   			Ti.API.timestamp('Ti.API.timestamp()');
   			Ti.API.timestamp(['arg0', 'arg1', 'arg2']);
   		}
   	}
   });
   
   win.add(button);
   win.open();

Produces output:

   [INFO] :  console.log()
   [DEBUG] :  console.debug()
   [DEBUG] :  (
   [INFO] :  (
   [DEBUG] :      arg0,
   [INFO] :      arg0,
   [DEBUG] :      arg1,
   [INFO] :      arg1,
   [DEBUG] :      arg2
   [INFO] :      arg2
   [DEBUG] :  )
   [INFO] :  )
   [INFO] :  console.info()
   [INFO] :  (
   [INFO] :      arg0,
   [INFO] :      arg1,
   [INFO] :      arg2
   [INFO] :  )
   [WARN] :  console.warn()
   [ERROR] :  console.error()
   [WARN] :  (
   [ERROR] :  (
   [WARN] :      arg0,
   [ERROR] :      arg0,
   [ERROR] :      arg1,
   [WARN] :      arg1,
   [ERROR] :      arg2
   [WARN] :      arg2
   [ERROR] :  )
   [WARN] :  )
   [DEBUG] :  Ti.API.debug([])
   [DEBUG] :  (
   [TRACE] :  Ti.API.trace()
   [DEBUG] :      arg0,
   [TRACE] :  (
   [DEBUG] :      arg1,
   [DEBUG] :      arg2
   [TRACE] :      arg0,
   [DEBUG] :  )
   [TRACE] :      arg1,
   [ERROR] :  Ti.API.error([])
   [TRACE] :      arg2
   [ERROR] :  (
   [TRACE] :  )
   [ERROR] :      arg0,
   [ERROR] :      arg1,
   [INFO] :  Ti.API.info([])
   [ERROR] :      arg2
   [INFO] :  (
   [ERROR] :  )
   [INFO] :      arg0,
   [DEBUG] :  Ti.API.log(DEBUG)
   [INFO] :      arg1,
   [DEBUG] :  (
   [INFO] :      arg2
   [DEBUG] :      arg0,
   [INFO] :  )
   [DEBUG] :      arg1,
   [WARN] :  Ti.API.warn([])
   [DEBUG] :      arg2
   [WARN] :  (
   [DEBUG] :  )
   [WARN] :      arg0,
   [WARN] :      arg1,
   [WARN] :      arg2
   [WARN] :  )
   [TRACE] :  Ti.API.log(TRACE)
   [TRACE] :  (
   [TRACE] :      arg0,
   [TRACE] :      arg1,
   [TRACE] :      arg2
   [TRACE] :  )
   [INFO] :  Ti.API.log(INFO)
   [INFO] :  (
   [INFO] :      arg0,
   [INFO] :      arg1,
   [INFO] :      arg2
   [INFO] :  )
   [WARN] :  Ti.API.log(WARN)
   [WARN] :  (
   [WARN] :      arg0,
   [WARN] :      arg1,
   [WARN] :      arg2
   [WARN] :  )
   [ERROR] :  Ti.API.log(ERROR)
   [ERROR] :  (
   [ERROR] :      arg0,
   [ERROR] :      arg1,
   [ERROR] :      arg2
   [ERROR] :  )
   [ERROR] :  [LOG] Ti.API.log(LOG)
   [ERROR] :  [LOG] (
   [ERROR] :      arg0,
   [ERROR] :      arg1,
   [ERROR] :      arg2
   [ERROR] :  )
   [ERROR] :  [TIMESTAMP] 382417823.074028 Ti.API.timestamp()
   [ERROR] :  [TIMESTAMP] 382417823.074065 (
   [ERROR] :      arg0,
   [ERROR] :      arg1,
   [ERROR] :      arg2
   [ERROR] :  )

The colors are correct, but the output appears to be on different threads. Titanium Studio: 3.0.2.201302081641 Titanium SDK: 3.0.2.v20130207164659 Titanium CLI: 3.0.23 OS: 10.8.2 Xcode: 4.6 iPhone Simulator: 6.1 Behavior captured in TIMOB-12719.

Dustin Hyde 2013-02-13

On a more positive note, some of this behavior seems to have gone away, such as the coloring inaccuracies. All isolated behaviors are being moved to sub-tasks of TIMOB-8424.
Chris Barber 2013-03-05

Dupe of TIMOB-12809.
Olga Romero 2013-03-07

Tested Dustin's code from 12/Feb/13 7:16 PM Produces output: [INFO] : console.log() [DEBUG] : console.debug() [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [DEBUG] : ( [DEBUG] : arg0, [DEBUG] : arg1, [DEBUG] : arg2 [DEBUG] : ) [INFO] : console.info() [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [WARN] : console.warn() [WARN] : ( [WARN] : arg0, [WARN] : arg1, [WARN] : arg2 [WARN] : ) [ERROR] : console.error() [ERROR] : ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [TRACE] : Ti.API.trace() [TRACE] : ( [TRACE] : arg0, [TRACE] : arg1, [TRACE] : arg2 [TRACE] : ) [DEBUG] : Ti.API.debug([]) [DEBUG] : ( [DEBUG] : arg0, [DEBUG] : arg1, [DEBUG] : arg2 [DEBUG] : ) [INFO] : Ti.API.info([]) [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [WARN] : Ti.API.warn([]) [WARN] : ( [WARN] : arg0, [WARN] : arg1, [WARN] : arg2 [WARN] : ) [ERROR] : Ti.API.error([]) [ERROR] : ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [TRACE] : Ti.API.log(TRACE) [TRACE] : ( [TRACE] : arg0, [TRACE] : arg1, [TRACE] : arg2 [TRACE] : ) [DEBUG] : Ti.API.log(DEBUG) [DEBUG] : ( [DEBUG] : arg0, [DEBUG] : arg1, [DEBUG] : arg2 [DEBUG] : ) [INFO] : Ti.API.log(INFO) [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [WARN] : Ti.API.log(WARN) [WARN] : ( [WARN] : arg0, [WARN] : arg1, [WARN] : arg2 [WARN] : ) [ERROR] : Ti.API.log(ERROR) [ERROR] : ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [ERROR] : [LOG] Ti.API.log(LOG) [ERROR] : [LOG] ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [ERROR] : [TIMESTAMP] 384374773.708832 Ti.API.timestamp() [ERROR] : [TIMESTAMP] 384374773.708888 ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [INFO] : console.log() [DEBUG] : console.debug() [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [INFO] : console.info() [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [WARN] : console.warn() [WARN] : ( [WARN] : arg0, [WARN] : arg1, [WARN] : arg2 [WARN] : ) [TRACE] : Ti.API.trace() [DEBUG] : ( [DEBUG] : arg0, [TRACE] : ( [DEBUG] : arg1, [DEBUG] : arg2 [DEBUG] : ) [TRACE] : arg0, [TRACE] : arg1, [ERROR] : console.error() [ERROR] : ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [TRACE] : arg2 [TRACE] : ) [DEBUG] : Ti.API.debug([]) [DEBUG] : ( [DEBUG] : arg0, [DEBUG] : arg1, [DEBUG] : arg2 [DEBUG] : ) [INFO] : Ti.API.info([]) [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [WARN] : Ti.API.warn([]) [WARN] : ( [WARN] : arg0, [WARN] : arg1, [WARN] : arg2 [WARN] : ) [ERROR] : Ti.API.error([]) [ERROR] : ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [TRACE] : Ti.API.log(TRACE) [TRACE] : ( [TRACE] : arg0, [TRACE] : arg1, [TRACE] : arg2 [TRACE] : ) [DEBUG] : Ti.API.log(DEBUG) [DEBUG] : ( [DEBUG] : arg0, [DEBUG] : arg1, [DEBUG] : arg2 [DEBUG] : ) [INFO] : Ti.API.log(INFO) [INFO] : ( [INFO] : arg0, [INFO] : arg1, [INFO] : arg2 [INFO] : ) [WARN] : Ti.API.log(WARN) [WARN] : ( [WARN] : arg0, [WARN] : arg1, [WARN] : arg2 [WARN] : ) [ERROR] : Ti.API.log(ERROR) [ERROR] : ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [ERROR] : [LOG] Ti.API.log(LOG) [ERROR] : [LOG] ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) [ERROR] : [TIMESTAMP] 384374799.414399 Ti.API.timestamp() [ERROR] : [TIMESTAMP] 384374799.414450 ( [ERROR] : arg0, [ERROR] : arg1, [ERROR] : arg2 [ERROR] : ) Titanium Studio: 3.0.2.201302191606 Titanium SDK: 3.1.0.v20130306145654 Titanium CLI: 3.0.25 OS: 10.8.2 Xcode: 4.6 iPhone Simulator: 6.1 Closing as Duplicate

JSON Source