Improved log messages

lib/svg-sprite.js

@@ -21,7 +21,8 @@ var CONFIG					= require('./svg-sprite/config'),
 	events					= require('events'),
 	async					= require('async'),
 	os 						= require('os'),
-	winston					= require('winston');
+	winston					= require('winston'),
+	pretty					= require('prettysize');
 
 /**
  * SVGSpriter class
@@ -30,21 +31,22 @@ var CONFIG					= require('./svg-sprite/config'),
  */
 function SVGSpriter(config) {
 	this.config				= new CONFIG(config);
+	this.config.log.extend(this);
+
 	this._queue				= new QUEUE(this);
 	this._shapes			= [];
 	this._transformers		= {svgo: SVGO};
 	this._compileQueue		= [];
 	this._shapesDest		= [];
 
-	this.config.log.extend(this);
-	console.log(this.config.log.level);
-
 	this._reset();
 	events.EventEmitter.call(this);
 
 	this._queue.on('empty', this._compile.bind(this));
 	this._queue.on('empty', this._getShapes.bind(this));
 	this.on('compiled', this._compile.bind(this));
+
+	this.info('Created spriter instance');
 }
 
 /**
@@ -129,20 +131,6 @@ SVGSpriter.prototype._isVinylFile = function(file) {
 	return _.isObject(file) && ((file instanceof File) || ((file.constructor.name == 'File') && (['path', 'contents', 'relative'].filter(function(property){ return property in this; }, file).length == 3)));
 }
 
-/**
- * Transform the shapes
- * 
- * @param {Function} cb					Callback
- */
-SVGSpriter.prototype._transform = function(cb) {
-	var that		= this;
-	async.parallelLimit(this._shapes.map(function(shape){
-		return function(_cb) {
-			that._transformShape(shape, _cb);
-		}
-	}, this), os.cpus().length * 2, cb);
-}
-
 /**
  * Transform a single shape
  * 
@@ -207,6 +195,8 @@ SVGSpriter.prototype._compile = function() {
 
 	// If the shape queue is not currently active
 	if (!this._queue.active && this._compileQueue.length) {
+		this.info('Compiling %d shapes ...', this._shapes.length);
+
 		var that 				= this._reset(),
 		args					= this._compileQueue.shift();
 
@@ -231,8 +221,14 @@ SVGSpriter.prototype._compile = function() {
 			// Add intermediate SVG files
 			if (that.config.shape.dest) {
 				files.shapes	= that._getShapeFiles(that.config.shape.dest);
+				that.verbose('Returning %d intermediate SVG files', files.shapes.length);
 			}
+			that.info('Finished %s sprite compilation', _.keys(data).map(function(mode){
+				return '«' + mode + '»';
+			}).join(' + '));
 
+			that._logStats(files);
+
 			args[1](error, files, data);
 			that.emit('compiled');
 		});
@@ -267,8 +263,6 @@ SVGSpriter.prototype._layout = function(config, cb) {
 	layout						= new LAYOUTER(this, config);
 
 	for (var mode in config) {
-		this.info('Initializing %s mode layout process', mode);
-
 		tasks.push((function(m){
 			return function(_cb){
 				layout.layout(files, m, _cb);
@@ -331,6 +325,31 @@ SVGSpriter.prototype._getShapeFiles = function(dest) {
 	});
 }
 
+/**
+ * Log file statistics
+ * 
+ * @param {Object} files				Files
+ */
+SVGSpriter.prototype._logStats = function(files) {
+	var sizes			= {},
+	exts				= {};
+	for (var mode in files) {
+		for (var resource in files[mode]) {
+			var file	= files[mode][resource].relative,
+			ext			= path.extname(files[mode][resource].path).toUpperCase();
+			exts[ext]	= (exts[ext] || 0) + 1;
+			sizes[file]	= pretty(files[mode][resource].contents.length);
+		}
+	}
+	this.info('Created ' + _.pairs(exts).map(function(ext){
+		return ext[1] + ' × ' + ext[0].substr(1);
+	}).join(', '));
+
+	Object.keys(sizes).sort().forEach(function(file){
+		this.verbose('Created %s: %s', file, sizes[file]);
+	}, this);
+}
+
 /**
  * Module export (constructor wrapper)
  * 

lib/svg-sprite/config.js

@@ -23,7 +23,6 @@ var _									= require('lodash'),
  * @param {Object} config				Configuration
  */
 function SVGSpriterConfig(config) {	
-	this.dest							= path.resolve(config.dest || '.');
 
 	// Logging
 	this.log							= '';
@@ -35,6 +34,9 @@ function SVGSpriterConfig(config) {
 		}
 	}
 	if (_.isString(this.log)) {
+		var twoDigits					= function(i) {
+			return ('0' + i).slice(-2);
+		};
 		this.log						= new winston.Logger({
 			transports					: [new (winston.transports.Console)({
 				level					: this.log || 'info',
@@ -43,18 +45,24 @@ function SVGSpriterConfig(config) {
 				prettyPrint				: true,
 				timestamp				: function() {
 					var now				= new Date();
-					return now.getFullYear() + '-' + now.getMonth() + '-' + now.getDate() + ' ' + now.getHours() + ':' + now.getMinutes() + ':' + now.getSeconds();
+					return now.getFullYear() + '-' + twoDigits(now.getMonth()) + '-' + twoDigits(now.getDate()) + ' ' + twoDigits(now.getHours()) + ':' + twoDigits(now.getMinutes()) + ':' + twoDigits(now.getSeconds());
 				}
 			})]
 		});
 	}
+
+	this.log.debug('Started logging');
 
+	this.dest							= path.resolve(config.dest || '.');
+
+	this.log.debug('Prepared general options');
+
 	this.shape							= ('shape' in config) ? _.assign({}, config.shape || {}) : {};
-	this.shape.spacing					= ('spacing' in this.shape) ? (this.shape.spacing || {}) : {};
 
 	// Parse meta data (if configured)
 	if (('meta' in this.shape) && !_.isPlainObject(this.shape.meta)) {
 		var meta						= _.isString(this.shape.meta) ? path.resolve(this.shape.meta) : null,
+		metaFile						= meta,
 		stat							= meta ? fs.lstatSync(meta) : null;
 		this.shape.meta					= {};
 		if (stat) {
@@ -69,6 +77,7 @@ function SVGSpriterConfig(config) {
 					this.shape.meta[path.join(path.dirname(m), path.basename(m, '.svg'))] = _.pick(meta[m], ['title', 'description']);
 				}
 			}
+			this.log.debug('Processed meta data file "%s"', path.basename(metaFile));
 		}
 	} else {
 		this.shape.meta					= {};
@@ -79,6 +88,7 @@ function SVGSpriterConfig(config) {
 	this.shape.dest						= this.shape.dest.length ? path.resolve(this.dest, this.shape.dest) : null;
 
 	// Expand spacing options to arrays
+	this.shape.spacing					= ('spacing' in this.shape) ? (this.shape.spacing || {}) : {};
 	['padding'].forEach(function(property){
 		if (!_.isArray(this.spacing[property])) {
 			var spacing					= Math.max(0, parseInt(this.spacing[property] || 0, 10));
@@ -103,8 +113,12 @@ function SVGSpriterConfig(config) {
 		}
 	}, this.shape);
 
+	this.log.debug('Prepared `shape` options');
+
 	this.svg							= ('svg' in config) ? _.assign(this.svg, config.svg || {}) : this.svg;
 
+	this.log.debug('Prepared `svg` options');
+
 	this.transform						= [];
 	var transforms						= config.transform || defaultTransform;
 	if (_.isArray(transforms)) {
@@ -128,7 +142,12 @@ function SVGSpriterConfig(config) {
 		}
 	}
 
+	this.log.debug('Prepared `transform` options');
+
 	this.mode			= _.pick(config.mode || {}, ['css', 'defs', 'symbol', 'stack', 'view']);
+
+	this.log.debug('Prepared `shape` options');
+	this.log.verbose('Initialized spriter configuration');
 }
 
 /**

lib/svg-sprite/layouter.js

@@ -109,6 +109,8 @@ function SVGSpriteLayouter(spriter, config) {
             last                    : (index == (this._spriter._shapes.length - 1))
         });
     }, this);
+
+    this._spriter.debug('Created layouter instance');
 }
 
 /**
@@ -126,6 +128,7 @@ SVGSpriteLayouter.prototype = {};
  * @param {Function} cb             Callback
  */
 SVGSpriteLayouter.prototype.layout = function(files, mode, cb) {
+	this._spriter.info('Laying out as «%s» sprite', mode);
 	var SVGSpriteLayout				= require('./mode/' + mode),
     config                          = _.merge(_.merge(_.clone(defaultConfig[mode], true), {svg: this._spriter.config.svg}), this.config[mode] || {}),
     data                            = _.merge(_.merge(_.merge({}, this._commonData), this._spriter.config.variables), config.variables),

lib/svg-sprite/mode/base.js

@@ -82,6 +82,8 @@ SVGSpriteBase.prototype._initData = function(data) {
 		data.example				= path.relative(path.dirname(renderConfig.dest), this.config.sprite);
 	}
 
+	this._spriter.debug("Created «%s» sprite instance", this.mode);
+
 	return data;
 }
 
@@ -112,6 +114,7 @@ SVGSpriteBase.prototype._buildHTMLExample = function(files, cb) {
 				path				: this.config.example.dest,
 				contents			: new Buffer(out)
 			});
+			this._spriter.verbose("Created «%s» HTML example file", this.mode);
 		}
 	}
 

lib/svg-sprite/mode/css.js

@@ -110,6 +110,7 @@ SVGSpriteCss.prototype.layout = function(files, cb) {
 
 	// Build the sprite SVG file
 	files.sprite					= this._buildSVG(config.xmlDeclaration || '', config.doctypeDeclaration || '');
+	this._spriter.verbose("Created «%s» SVG sprite file", this.mode);
 
 	// Build the configured CSS resources
 	this._buildCSSResources(files, function(error) {
@@ -392,6 +393,7 @@ SVGSpriteCss.prototype._buildCSSResources = function(files, cb) {
 						path		: renderConfig.dest,
 						contents	: new Buffer(out)
 					});
+					this._spriter.verbose("Created «%s» stylesheet resource", ext);
 				}
 				_cb(null);
 			}

lib/svg-sprite/mode/defs.js

@@ -23,7 +23,6 @@ SVGSprite							= require('../sprite');
  */
 function SVGSpriteDefs(spriter, config, data) {
 	SVGSpriteStandalone.apply(this, arguments);
-	this._init(data);
 }
 
 /**

lib/svg-sprite/mode/stack.js

@@ -24,7 +24,6 @@ File								= require('vinyl');
  */
 function SVGSpriteStack(spriter, config, data) {
 	SVGSpriteStandalone.apply(this, arguments);
-	this._init(data);
 }
 
 /**

lib/svg-sprite/mode/standalone.js

@@ -105,6 +105,7 @@ SVGSpriteStandalone.prototype._layout = function(files, cb, extend) {
 
 	// Build the sprite SVG file
 	files.sprite					= this._buildSVG(xmlDeclaration || '', doctypeDeclaration || '');
+	this._spriter.verbose("Created «%s» SVG sprite file", this.mode);
 
 	// Build the HTML example
 	this._buildHTMLExample(files, cb);

lib/svg-sprite/mode/symbol.js

@@ -24,7 +24,6 @@ symbolAttributes					= ['id', 'xml:base', 'xml:lang', 'xml:space', 'onfocusin',
  */
 function SVGSpriteSymbol(spriter, config, data) {
 	SVGSpriteStandalone.apply(this, arguments);
-	this._init(data);
 }
 
 /**

lib/svg-sprite/queue.js

@@ -31,6 +31,8 @@ function SVGSpriterQueue(spriter) {
 	events.EventEmitter.call(this);
 	this.on('add', this.process.bind(this));
 	this.on('remove', this.process.bind(this));
+
+	this._spriter.debug('Created processing queue instance');
 }
 
 /**
@@ -46,7 +48,7 @@ SVGSpriterQueue.prototype = Object.create(events.EventEmitter.prototype);
  * @param {File} file					Shape file
  */
 SVGSpriterQueue.prototype.add = function(file) {
-	this._spriter.debug('Adding SVG shape "%s"', file.path.substr(file.base.length + path.sep.length));
+	this._spriter.debug('Added "%s" to processing queue', file.path.substr(file.base.length + path.sep.length));
 	this._files.push(file);
 	this.emit('add');
 }

lib/svg-sprite/shape.js

@@ -134,6 +134,8 @@ function SVGShape(file, spriter) {
 	doctype					= this.svg.current.match(/<!DOCTYPE.*?>/gi);
 	this.xmlDeclaration		= xmldecl ? xmldecl[0] : '<?xml version="1.0" encoding="utf-8"?>';
 	this.doctypeDeclaration	= doctype ? doctype[0] : '';
+
+	this.spriter.verbose('Added shape "%s:%s"', this.base, this.state || 'regular');
 }
 
 /**

lib/svg-sprite/transform/svgo.js

@@ -67,8 +67,12 @@ module.exports = function(shape, config, spriter, cb) {
 	try {
 		svgoInstance.optimize(svg, function(result) {
 			shape.setSVG(result.data);
-			var optimizedSVGLength	= shape.getSVG(false).length;
-			spriter.verbose('Optimized "%s" with SVGO (saved %s / %s%%)', shape.name, pretty(svgLength - optimizedSVGLength), Math.round(100 * (svgLength - optimizedSVGLength) / svgLength));
+
+			if (spriter.config.log.level == 'debug') {
+				var optSVGLength	= shape.getSVG(false).length;
+				spriter.debug('Optimized "%s" with SVGO (saved %s / %s%%)', shape.name, pretty(svgLength - optSVGLength), Math.round(100 * (svgLength - optimizedSVGLength) / svgLength));
+			}
+
 			cb(null);
 		});
 	} catch (error) {