Merge pull request #149 from KnisterPeter/add-debug-logging

feat: add debug logging

README.md

@@ -25,6 +25,7 @@ Dependency Injection container (IoC) for TypeScript.
 * [Lazy dependency injection (default)](#lazy-injection)
 * [Lifecycle listeners](#lifecycle-listeners)
 * [Eager components](#eager-components)
+* [Debug logging](#debug-logging)
 
 # Usage
 
@@ -286,6 +287,11 @@ const tsdi: TSDI = new TSDI();
 tsdi.register(A); // <-- here the class A is instantiated
 ```
 
+### Debug logging
+
+To inspect which component is created when and injected where one can enable debug logging by either
+set the environment variable `DEBUG` (node) or a localStorage key (browser) `debug` to `tsdi`.
+
 ## Future ideas / Roadmap
 
 * Static factories

lib/component.ts

@@ -2,11 +2,14 @@ import { IComponentOptions } from './decorators';
 import { addKnownComponent } from './global-state';
 import { getNamedOptions } from './helper';
 
+import * as debug from 'debug';
+const log = debug('tsdi');
+
 export function Component<TFunction extends Function>(target: TFunction): TFunction;
 export function Component(optionsOrString?: IComponentOptions | string): ClassDecorator;
 export function Component<TFunction extends Function>(...args: any[]): ClassDecorator| TFunction {
   const decorate = (target: TFunction, optionsOrString: IComponentOptions | string = {}) => {
-    // console.log(`@Component ${(target as any).name}`);
+    log(`@Component ${(target as any).name}`);
     const options = getNamedOptions<IComponentOptions>(optionsOrString);
     addKnownComponent({
       fn: target as any,

lib/decorators.ts

@@ -10,6 +10,9 @@ import {
   removeElement
 } from './helper';
 
+import * as debug from 'debug';
+const log = debug('tsdi');
+
 export type Constructable<T> = { new(...args: any[]): T; };
 
 export type IComponentOptions = ComponentOptions;
@@ -136,9 +139,14 @@ export class TSDI {
         console.warn(`Component with name '${componentMetadata.options.name}' already registered.`);
       }
 
+      log('registerComponent %o', isFactoryMetadata(componentMetadata) ?
+        (componentMetadata.rtti as any).name : (componentMetadata.fn as any).name);
       this.components.push(componentMetadata);
       if (componentMetadata.options.eager) {
-        this.getOrCreate(componentMetadata, this.components.length - 1);
+        const idx = this.components.length - 1;
+        setTimeout(() => {
+          this.getOrCreate(componentMetadata, idx);
+        }, 0);
       }
     }
   }
@@ -204,13 +212,16 @@ export class TSDI {
   }
 
   private getOrCreate<T>(metadata: ComponentOrFactoryMetadata, idx: number): T {
+    log('> getOrCreate %o', metadata);
     // todo: Use T here
     let instance: any = this.instances[idx];
     if (!instance || !this.isSingleton(metadata)) {
       if (isFactoryMetadata(metadata)) {
+        log('create %o from factory with %o', (metadata.rtti as any).name, metadata.options);
         instance = this.get(metadata.target.constructor as Constructable<any>)[metadata.property]();
         this.instances[idx] = instance;
       } else {
+        log('create %o with %o', (metadata.fn as any).name, metadata.options);
         const constructor: Constructable<T> =  metadata.fn as any;
         const parameters = this.getConstructorParameters(metadata);
         instance = new constructor(...parameters);
@@ -225,6 +236,7 @@ export class TSDI {
       }
       this.notifyOnCreate(instance);
     }
+    log('< getOrCreate %o -> %o', metadata, instance);
     return instance;
   }
 
@@ -243,6 +255,7 @@ export class TSDI {
     const injects: InjectMetadata[] = Reflect.getMetadata('component:injects', componentMetadata.fn.prototype);
     if (injects) {
       for (const inject of injects) {
+        log('injecting %s.%s', instance.constructor.name, inject.property);
         if (inject.options.name && typeof this.properties[inject.options.name] !== 'undefined') {
           instance[inject.property] = this.properties[inject.options.name];
         } else {
@@ -254,8 +267,10 @@ export class TSDI {
               get(): any {
                 let value = instance[`tsdi$${inject.property}`];
                 if (!value) {
+                  log('lazy-resolve injected property %s.%s', instance.constructor.name, inject.property);
                   value = tsdi.getComponentDependency(inject);
                   instance[`tsdi$${inject.property}`] = value;
+                  log('lazy-resolved to %o', value);
                 }
                 return value;
               }
@@ -284,12 +299,18 @@ export class TSDI {
 
   private checkAndThrowDependencyError(inject: InjectMetadata): void {
     if (inject.type && inject.options.name) {
-      throw new Error(`Injecting undefined type on ${(inject.target.constructor as any).name}`
+      const e = new Error(`Injecting undefined type on ${(inject.target.constructor as any).name}`
         + `#${inject.property}: Component named '${inject.options.name}' not found`);
+      log(e);
+      log('Known Components: %o', this.components.map(component =>
+        isFactoryMetadata(component) ? (component.rtti as any).name : (component.fn as any).name));
+      throw e;
     }
     if (!inject.type || inject.options.name) {
-      throw new Error(`Injecting undefined type on ${(inject.target.constructor as any).name}`
+      const e = new Error(`Injecting undefined type on ${(inject.target.constructor as any).name}`
         + `#${inject.property}: Probably a cyclic dependency, switch to name based injection`);
+      log(e);
+      throw e;
     }
   }
 

lib/external.ts

@@ -1,17 +1,20 @@
 import { addKnownExternal } from './global-state';
 
+import * as debug from 'debug';
+const log = debug('tsdi');
+
 export function External<TFunction extends Function>(target: TFunction): TFunction;
 export function External(): ClassDecorator;
 export function External<TFunction extends Function>(...args: any[]): ClassDecorator | TFunction {
   const decorate = (target: TFunction) => {
-    // console.log(`@External ${(target as any).name}`);
+    log(`@External ${(target as any).name}`);
     addKnownExternal(target);
     const constructor = function InjectedConstructor(this: any, ...args: any[]): any {
       return (target as any).__tsdi__.configureExternal(args, target);
     };
     (constructor as any).displayName = (target as any).name;
     Object.getOwnPropertyNames(target)
-      .filter(prop => !(constructor as any)[prop] && prop !== 'length')
+      .filter(prop => !(constructor as any)[prop] && prop !== 'name' && prop !== 'length')
       .forEach(prop => (constructor as any)[prop] = (target as any)[prop]);
     constructor.prototype = target.prototype;
     return constructor as any;

lib/factory.ts

@@ -1,11 +1,17 @@
 import { IFactoryOptions } from './decorators';
 import { addKnownComponent } from './global-state';
 
+import * as debug from 'debug';
+const log = debug('tsdi');
+
 export function Factory(target: Object, propertyKey: string): void;
 export function Factory(options?: IFactoryOptions): MethodDecorator;
 export function Factory(...args: any[]): MethodDecorator | void {
   const decorate = (target: Object, propertyKey: string, options: IFactoryOptions) => {
-    // console.log(`@Factory ${(target as any)[propertyKey].name}`);
+    if (log.enabled) {
+      log('@Factory %s#%s({name: "%s"})', (target.constructor as any).name, propertyKey,
+        (target as any)[propertyKey].name);
+    }
     addKnownComponent({
       target,
       property: propertyKey,
@@ -19,13 +25,7 @@ export function Factory(...args: any[]): MethodDecorator | void {
   }
   const options = args[0] || {};
   return function(target: Object, propertyKey: string): void {
-    // console.log(`@Factory ${(target as any)[propertyKey].name}`);
-    addKnownComponent({
-      target,
-      property: propertyKey,
-      options,
-      rtti: Reflect.getMetadata('design:returntype', target, propertyKey)
-    });
+    decorate(target, propertyKey, options);
   };
 }
 export const factory = Factory;

lib/initialize.ts

@@ -1,8 +1,11 @@
+import * as debug from 'debug';
+const log = debug('tsdi');
+
 export function Initialize(target: Object, propertyKey: string): void;
 export function Initialize(): MethodDecorator;
 export function Initialize(...args: any[]): MethodDecorator | void {
   const decorate = (target: Object, propertyKey: string) => {
-    // console.log(`@Initialize ${(target as any)[propertyKey].name}`);
+    log('@Initialize %s#%s', (target.constructor as any).name, propertyKey);
     Reflect.defineMetadata('component:init', propertyKey, target);
   };
   if (args.length > 0) {

lib/inject.ts

@@ -6,6 +6,9 @@ import {
 } from './decorators';
 import { getNamedOptions } from './helper';
 
+import * as debug from 'debug';
+const log = debug('tsdi');
+
 export function Inject(target: Object, propertyKey: string | symbol, parameterIndex?: number): void;
 export function Inject(optionsOrString?: IInjectOptions | string): PropertyDecorator & ParameterDecorator;
 export function Inject(...args: any[]): PropertyDecorator & ParameterDecorator | void {
@@ -18,7 +21,7 @@ export function Inject(...args: any[]): PropertyDecorator & ParameterDecorator |
   };
   const decorateProperty = (target: Object, propertyKey: string,
       options: IInjectOptions) => {
-    // console.log(`@Inject ${(target.constructor as any).name}#${propertyKey}`);
+    log(`@Inject ${(target.constructor as any).name}#${propertyKey}`);
     const type: Constructable<any> = Reflect.getMetadata('design:type', target, propertyKey);
     let injects: InjectMetadata[] = Reflect.getMetadata('component:injects', target);
     if (!injects) {
@@ -34,7 +37,7 @@ export function Inject(...args: any[]): PropertyDecorator & ParameterDecorator |
   };
   const decorateParameter = (target: Object, propertyKey: string | symbol, parameterIndex: number,
       options: IInjectOptions) => {
-    // console.log(`@Inject ${propertyKey}`);
+    log(`@Inject ${propertyKey}`);
     let parameters: ParameterMetadata[] = Reflect.getMetadata('component:parameters', target);
     if (!parameters) {
       parameters = [];

package.json

@@ -37,6 +37,7 @@
   "devDependencies": {
     "@knisterpeter/standard-tslint": "^1.5.1",
     "@types/chai": "^4.0.2",
+    "@types/debug": "0.0.30",
     "@types/mocha": "^2.2.41",
     "@types/node": "^8.0.19",
     "chai": "^4.1.0",
@@ -52,6 +53,7 @@
     "typescript": "^2.3.2"
   },
   "dependencies": {
+    "debug": "^3.0.1",
     "reflect-metadata": "^0.1.10"
   },
   "config": {