Щупаем mx.logging

Многие, но, наверное, не все знают, что во Flex SDK есть пакет классов mx.logging. Давайте посмотрим, как это юзать и чего полезного можно с него поиметь.

За этим пакетом лежит незамысловатая теория, хорошо знакомая джава программистам, ибо mx.logging похож на log4j, но попроще.

Если очень кратко, то есть объекты mx.logging.ILogger которые вы распихиваете по коду в интересных местах, и вместо trace() юзаете logger.debug() или logger.info(). Есть фабрика mx.logging.Log, которая их создает экзепляры этих объектов. Ну и все это вместе предназначено для того, чтобы генерировать отладочную инфу.

А куда потом эта инфа деётся? А есть еще специальные log targets, которые эту инфу умеют принимать и что-нибудь с ней делать. Флекс предоставляет нам только один такой target -- mx.logging.targets.TraceTarget, который всего-то и умеет, что выводить инфу в консоль и в flashlog.txt все той же функцией trace().

Все это было бы не так интересно, если бы все закончилось на TraceTarget. Интересно то, что можно создавать собственные target, принимать инфу, и делать с ней еще что-нибудь полезное. Например, через LocalConnection отправлять на собственное флэш-приложение, которое отобразит все это мега-красиво и мега-удобно.

На этом с теорией все, подробнее читайте по вышеуказанной ссылке в доках Адоби. А сейчас сразу к практике.

Log, ILogger и TraceTarget

Для начала создадим Demo Application, который ничего полезного делать не будет, но будет генерировать отладочную инфу.

<?xml version="1.0"?>
<s:Application
		xmlns:fx="http://ns.adobe.com/mxml/2009"
		xmlns:s="library://ns.adobe.com/flex/spark"
		xmlns:mx="library://ns.adobe.com/flex/mx"
		initialize="init()">

	<fx:Script><![CDATA[
		import mx.logging.ILogger;
		import mx.logging.Log;

		private var logger1 : ILogger = Log.getLogger("DemoApp");
		private var logger2 : ILogger = Log.getLogger("TestCategory");

		private var counter1 : int = 0;
		private var counter2 : int = 0;

		private var timer1 : Timer;
		private var timer2 : Timer;

		private function init() : void
		{
			logger1.info("init");

			timer1 = new Timer(2000);
			timer1.addEventListener(TimerEvent.TIMER, do1);
			timer1.start();

			timer2 = new Timer(3000);
			timer2.addEventListener(TimerEvent.TIMER, do2);
			timer2.start();
		}

		private function do1(e : TimerEvent) : void
		{
			logger1.info("do1 " + counter1 + " times");
			counter1++;
		}

		private function do2(e : TimerEvent) : void
		{
			logger2.info("do2 " + counter2 + " times");
			counter2++;
		}
		]]></fx:Script>

	<fx:Declarations>
		<mx:TraceTarget id="logTarget"
						includeDate="true" includeTime="true"
						includeCategory="true" includeLevel="true">
			<mx:level>0</mx:level>
		</mx:TraceTarget>
	</fx:Declarations>

	<s:Label text="DemoApp"/>

</s:Application>

Здесь мы видим, как создаются логгеры:

private var logger1 : ILogger = Log.getLogger("DemoApp");
private var logger2 : ILogger = Log.getLogger("TestCategory");

И видим, как они используются:

logger1.info("do1 " + counter1 + " times");

Ничего сложного :)

Далее, чтобы эта инфа отображалась в консоли, мы подключаем TraceTarget:

<fx:Declarations>
	<mx:TraceTarget id="logTarget"
					includeDate="true" includeTime="true"
					includeCategory="true" includeLevel="true">
		<mx:level>0</mx:level>
	</mx:TraceTarget>
</fx:Declarations>

Все, запустив это приложение, мы наблюдаем в консоли следующее:

[trace] 9/27/2010 00:38:58.635 [INFO] DemoApp init
[trace] 9/27/2010 00:39:00.660 [INFO] DemoApp do1 0 times
[trace] 9/27/2010 00:39:01.662 [INFO] TestCategory do2 0 times
[trace] 9/27/2010 00:39:02.704 [INFO] DemoApp do1 1 times
[trace] 9/27/2010 00:39:04.708 [INFO] DemoApp do1 2 times
[trace] 9/27/2010 00:39:04.708 [INFO] TestCategory do2 1 times
[trace] 9/27/2010 00:39:06.741 [INFO] DemoApp do1 3 times
[trace] 9/27/2010 00:39:07.746 [INFO] TestCategory do2 2 times
[trace] 9/27/2010 00:39:08.742 [INFO] DemoApp do1 4 times
[trace] 9/27/2010 00:39:10.749 [INFO] DemoApp do1 5 times
[trace] 9/27/2010 00:39:10.749 [INFO] TestCategory do2 3 times
[trace] 9/27/2010 00:39:12.784 [INFO] DemoApp do1 6 times
[trace] 9/27/2010 00:39:13.788 [INFO] TestCategory do2 4 times
[trace] 9/27/2010 00:39:14.791 [INFO] DemoApp do1 7 times
[trace] 9/27/2010 00:39:16.824 [INFO] DemoApp do1 8 times
[trace] 9/27/2010 00:39:16.824 [INFO] TestCategory do2 5 times

Красота :)

Создаем свою log target

Что ж, давайте теперь создадим свою log target, подключим, и будем посылать эту же инфу через LocalConnection (пока не важно, кто ее будет получать).

Создадим такой класс:

package com.flashdevs.yzh.log
{
import mx.logging.ILogger;
import mx.logging.Log;
import mx.logging.LogEvent;
import mx.logging.LogEventLevel;
import mx.logging.targets.LineFormattedTarget;

public class DebugConsoleLogTarget extends LineFormattedTarget
{
	static private var connector : Connector = null;

	static public function init() : void
	{
		var target : DebugConsoleLogTarget = new DebugConsoleLogTarget();
		Log.addTarget(target);
	}

	public function DebugConsoleLogTarget()
	{
		filters = ["*"];
		level = LogEventLevel.ALL;
		includeDate = true;
		includeTime = true;
		includeCategory = true;
		includeLevel = true;
	}

	public override function logEvent(event : LogEvent) : void
	{
		super.logEvent(event);

		if(connector == null) connector = new Connector();
		connector.send(event.level, ILogger(event.target).category, event.message);
	}

	public function toString() : String
	{
		return 'DebugConsoleLogTarget';
	}
}
}

Он наследуется от LineFormattedTarget, переопределяет некоторые свойства в конструкторе, и обрабатывает событие LogEvent. Инфу из этого события передает некоему connector.

И вот этот connector:

package com.flashdevs.yzh.log
{
import flash.events.SecurityErrorEvent;
import flash.events.StatusEvent;
import flash.net.LocalConnection;

internal class Connector
{
	static public const CONNECTION_NAME : String = "debug_console";

	private var lc : LocalConnection = null;

	public function Connector()
	{
		lc = new LocalConnection();
		lc.client = this;
		lc.addEventListener(StatusEvent.STATUS, onStatusEvent);
		lc.addEventListener(SecurityErrorEvent.SECURITY_ERROR, onError);

		lc.send(CONNECTION_NAME, 'newSession');
	}

	internal function send(level : int, category : String, message : String) : void
	{
		try
		{
			lc.send(CONNECTION_NAME, 'trace', level, category, message);
		}
		catch(error : Object)
		{
			trace(this + '.send: ' + error.toString());
		}
	}

	private function onStatusEvent(event : StatusEvent) : void
	{
		if(event.level == 'error')
		{
			trace(' === DebugConsole not started === ');
			lc = null;
		}
	}

	private function onError(ev : SecurityErrorEvent) : void
	{
		trace(this + '.onError ' + ev.toString());
		lc = null;
	}

	public function toString() : String
	{
		return "Connector";
	}
}
}

Ну вот, тут опять ничего сложного. Осталось только подключить наш log target. Для этого в Demo Application добавим импорт import com.flashdevs.yzh.log.DebugConsoleLogTarget; и в методе init вызовем DebugConsoleLogTarget.init();

Все, этого достаточно :)

Debug Console

Уже N лет я юзаю для отладки флэш/флекс проектов собственный велосипед -- приложение Debug Console. Оно старое, написанное еще на AS2, и уже года 3 в нем не менялось ни строчки кода. Оно умеет принимать инфу через LocalConnection и отображать ее в виде чуть более удобном, чем это делает trace. Там есть фильтрация логов по категориям, раскраска сообщений разным цветом в зависимости от уровня, укорачивание длинных сообщений (и возможность просмотреть их целиком). Да и все, пожалуй.

Это далеко до возможностей DeMonsterDebugger, но я очень привык к своему велосипеду.

Те, кто отлаживает преимущественно с помощью брейкпоинтов, не поймут, зачем нужно такое приложение. Увы, брейкпоинты слабо помогают, когда нужно запустить несколько экземпляров приложения от разных пользователей и протестировать, как эти экземпляры взаимодействуют между собой. Специфика наших проектов такова, что это нужно делать довольно часто.

Ну так вот, эта Debug Console открывает LocalConnection и слушает, что ей будут присылать. А присылают свою отладочную инфу другие приложения. Это могут быть одновременно несколько экземпляров одного приложения, или даже разные приложения, которые взаимодействуют между собой в рамках одного проекта.

И до сих пор для отправки инфы я использовал свой класс Debug со статической функцией Trace. То есть, там, где иные разработчики писали trace("something"), я писал Debug.Trace("something", category, level);

А теперь я подумал, что пора бы заменить этот Debug.Trace на mx.logging. Ну и саму DebugConsole обновить и переписать на флексе.

Пока ничего мега-интересного я не написал, но вот часть кода, которая принимает инфу из LocalConnection:

package com.flashdevs.yzh.log
{
import flash.net.LocalConnection;

public class Controller
{
	static public const CONNECTION_NAME : String = "debug_console";

	// properties
	private var lc : LocalConnection;
	private var view : IView;

	// constructor
	public function Controller()
	{
	}

	// methods
	public function init(view : IView) : void
	{
		this.view = view;
		
		lc = new LocalConnection();
		lc.client = this;
		lc.allowDomain("*");

		try
		{
			lc.connect(CONNECTION_NAME);
		}
		catch(e : ArgumentError)
		{
			view.show("Can't connect... the connection name " + CONNECTION_NAME
					+ " is already being used by another SWF");
		}
		catch(e : Error)
		{
			view.show(e.toString());
		}

		view.show("Debug Console started");
	}

	public function trace(level : int, category : String, message : String) : void
	{
		var strLevel : String = "";
		switch(level)
		{
			case 1000: strLevel = "FATAL"; break;
			case 8: strLevel = "ERROR"; break;
			case 6: strLevel = "WARN"; break;
			case 4: strLevel = "INFO"; break;
			case 2: strLevel = "DEBUG"; break;
		}

		view.show(strLevel + " " + category + ": " + message);
	}

	public function newSession() : void
	{
		view.clear();
	}

	public function toString() : String
	{ return 'Controller'; }
}
}

Что дальше?

Дальше я постепенно реализую в своем новом Debug Console тот функционал, который был в старой версии. Может добавлю еще какие-нибудь фичи.

Оный проект я выложил на github и буду продолжать его.

Позже я расскажу, какие бывают проблемы отладки при использовании Mate и как их решать. Mate использует внутри себя mx.logging, но довольно своеобразно. И чтобы получить оттуда отладочную инфу, нужно предпринять некоторые неочевидные действия.

А еще я попробую подключить как log target DeMonsterDebugger.