The Appalling Events of 6 November 2014

 

 

This page archives and comments an extremely unhelpful trace received from the framework during the process of working on the GPII's FlowManager. We should improve the framework in a few ways so that problems of this kind can't occur again, and/or are reported with sensible and readable diagnostics.

This log was received by running node UpdateTests.js from GPII universal's gpii/node_modules/flowManager/test

The commit involved is at https://github.com/kaspermarkus/universal/tree/b9bde973258ccb135f39061ef8f4d62d7e98d09e

The cause of the problem is this line: https://github.com/kaspermarkus/universal/blob/b9bde973258ccb135f39061ef8f4d62d7e98d09e/gpii/node_modules/flowManager/src/FlowManagerUtilities.js#L122 as follows:

 

        listeners: {
            onToken: "{that}.getPreferences",
            onReadyToMatch: "{that}.runMatchMakerFramework",
            onDevice: "{that}.getSolutions",
            "{gpii.matchMakerFramework}.events.onMatch": "{that}.fireOnMatch"  // <--- ERROR HERE
        }

This supplies a request scope listener to an injects an application scope event. As a result, when the event is fired, EVERY such request's listeners will be notified.

The test sequence executing is as follows (at https://github.com/kaspermarkus/universal/blob/b9bde973258ccb135f39061ef8f4d62d7e98d09e/gpii/node_modules/flowManager/test/UpdateTests.js#L167 ) - 

    sequence: [{ // point 1
        func: "{invalidUpdateRequest}.send",
        args: "You shall not pass!!"
    }, { // point 2
        event: "{invalidUpdateRequest}.events.onError",
        listener: "gpii.tests.flowManager.update.testInvalidUpdateRequest"
    }, { // point 3
        func: "{login}.send"
    }, { // point 4
        event: "{login}.events.onComplete",
        listener: "gpii.tests.flowManager.update.testLoginResponse"
    }, { // point 5
        func: "{updateRequest}.send",
        args: gpii.tests.flowManager.update.payload1
    }, { // point 6
        event: "{updateRequest}.events.onComplete",
        listener: "gpii.tests.flowManager.update.testFirstUpdateRequest"
    }, {

 

The first failure report occurs at sequence point 5 during "send" for the 2nd request:

20:21:38.417:  ASSERTION FAILED: Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed
20:21:38.417:  Current activity: 
    while resolving context value {that}.events.onMatch
    while expanding context value {that}.events.onMatch held at path ""
20:21:38.418:  FATAL ERROR: Uncaught exception: Object Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed has no method 'Assertion failure - check console for details'
TypeError: Object Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed has no method 'Assertion failure - check console for details'
    at Object.fluid.builtinFail (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:163:69)
    at kettle.utils.failureHandler (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:98:15)
    at Object.fluid.fail (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:184:13)
    at Object.fluid.makeStackFetcher.fetcher (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:726:23)
    at fetch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2053:32)
    at Object.fluid.resolveContextValue (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2061:20)
    at Object.fluid.expandSource (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2158:34)
    at Object.fluid.makeExpandOptions.options.expandSource (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2234:26)
    at Object.fluid.makeExpandOptions (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2249:42)
    at Object.fluid.expand (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2259:35)
    at Object.fluid.embodyDemands (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1226:37)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1655:40)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Array.gpii.matchMakerFramework.matchMakerDispatcher [as 0] (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\matchMakerFramework\src\MatchMakerFramework.js:91:19)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at Object.fluid.promise.that.then (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:31:21)
    at Function.fluid.promise.follow (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:83:16)
    at Array.kettle.dataSource.set [as 0] (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:220:31)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at Object.fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at onEnd (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:325:33)
    at applyCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:57:37)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1880:20)
    at Object.fluid.tryCatch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:219:24)
    at Object.fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1875:22)
    at IncomingMessage.wrapCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:54:30)
    at IncomingMessage.EventEmitter.emit (events.js:115:20)
    at IncomingMessage._emitEnd (http.js:366:10)
    at HTTPParser.parserOnMessageComplete [as onMessageComplete] (http.js:149:23)
    at Socket.socketOnData [as ondata] (http.js:1366:20)
    at TCP.onread (net.js:402:27)

This is of course highly puzzling to the user since they can see no logical path by which their request may be destroyed by this early point in request handling.

 

The sequence that occurs is this:

  1. The invalid update request from sequence points 1 and 2 resolves - it fires onError at the following point (line 398 of the trace):

    &&&&&&&&&&&&&&&&& FIRING SESSIONAWARE ONERROR FROM Error
        at gpii.request.flowManager.sessionAware.withSession (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:151:81)
        at Object.invoke (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1623:25)
        at Object.invokeInvoker [as withSession] (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1650:32)
        at gpii.request.flowManager.onMatchUpdateHandler (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\UserUpdate.js:111:14)
        at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
        at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
        at fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
        at gpii.request.flowManager.fireOnMatch (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:145:20)
        at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
        at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
        at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
        at Array.gpii.matchMakerFramework.matchMakerDispatcher [as 0] (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\matchMakerFramework\src\MatchMakerFramework.js:91:19)
        at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
        at fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
        at Object.fluid.promise.that.then (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:31:21)
        at Function.fluid.promise.follow (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:83:16)
        at Array.kettle.dataSource.set [as 0] (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:220:31)
        at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
        at Object.fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
        at onEnd (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:325:33)
        at applyCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:57:37)
        at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1880:20)
        at Object.fluid.tryCatch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:219:24)
        at Object.fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1875:22)
        at IncomingMessage.wrapCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:54:30)
        at IncomingMessage.EventEmitter.emit (events.js:115:20)
        at IncomingMessage._emitEnd (http.js:366:10)
        at HTTPParser.parserOnMessageComplete [as onMessageComplete] (http.js:149:23)
        at Socket.socketOnData [as ondata] (http.js:1366:20)
        at TCP.onread (net.js:402:27)

2. Unfortunately, resolution of this listener is synchronous - and the IoC Testing framework immediately moves on to sequence point 3 and issues a further request whilst the invalid update request is still on the stack - as well as still being an active request with a registered handler to onMatch. At this point we raised http://issues.fluidproject.org/browse/FLUID-5546 but as it turns out resolving this issue would leave this particular outcome unchanged. It is "too late" to clear the listener since we are already in the middle of dispatching it (from MatchMakerFramework.js line 91).

3. The second request then causes the application scope onMatch event to fire.

4. This, due to synchronous resolution, dispatches to the onMatch listener of the invalid update request which is still on the stack, and partway through its own destruction.

5. This attempts to fire a further error - since there is still no session attached to the first invalid update request - triggered via onMatchUpdateHandler at https://github.com/kaspermarkus/universal/blob/b9bde973258ccb135f39061ef8f4d62d7e98d09e/gpii/node_modules/flowManager/src/UserUpdate.js#L109 - which reads

    gpii.request.flowManager.onMatchUpdateHandler = function (lifecycleManagerServerDataSource, event, fluidRequest, that, match) {
        // TODO: Flatten out this horrid mess with async ginger world
        that.withSession(function (session, token) {
            lifecycleManagerServerDataSource.set({
                operation: "update",
                token: token
            }, match, function (response) {
                if (response.success) {
                    // Update the session.
                    session.preferences = fluidRequest.data;
                }
                gpii.request.flowManager.logAndNotify("Lifecycle manager returned: ", event)(response);
            });
        });
    };



6. At this point, something very unfortunate happens - in trying to resolve the request responsible for the error, Kettle looks into its "thread-local records" and manages to locate the SECOND request even though the first request is in error - via Kettle's utils.js currently line 87 reads:

    // In case of a fluid.fail - abort any current request, and then throw an exception 
    kettle.utils.failureHandler = function (args, activity) {
        var messages = ["ASSERTION FAILED: "].concat(args).concat(activity);
        fluid.log.apply(null, [fluid.logLevel.FATAL].concat(messages));
        var request = kettle.getCurrentRequest();
        if (request) {
            request.events.onError.fire({
                isError: true,
                message: args[0]
            });
        }
        fluid.builtinFail(false, args, activity);
    };

The kettle threadlocal marking is not reentrant - since it ought to be completely impossible to access another request's dispatch code from the same stack frame as another. 

7. As a result of this, the SECOND request's onError fires, and it starts to destroy itself synchronously - thus unregistering its own onMatch handler from the application-scope event, hilariously before the first request's destructor which is already in progress succeeds in removing its own one. This causes extremely puzzling effects during debugging. However, this has no effect on the actual dispatch of any of the listeners which as per the current Infusion implementation use a "frozen" copy of the listeners list.

8. By the time we receive any I/O for the resources that the request requires in order to perform the matching, the request that we thought we were trying to service has already been aborted and destroyed - hence the incomprehensible message about failing to resolve {that}.events.onMatch for the required handler.

Take-Home Messages

Whilst the user made a fundamental design error, the behaviour of the framework was completely unacceptable. We need to guard all such code paths in order to provide much earlier and more comprehensible diagnostics. Before we implemented http://issues.fluidproject.org/browse/FLUID-4890 the behaviour was far worse - the framework would merrily carry on servicing invokers and listeners for components which had long been destroyed. This allowed lots of broken code to seem to  be "apparently working" if the test cases did not inspect or rely on the content of the destroyed components too carefully.

There are two primary points where the framework has the possibility of detecting the error:

Point 1

Firstly, the transition from the stack for request 2 back to the stack for request 1 via a synchronous path should be guarded immediately. All such transitions definitely represent implementation errors - since the only way to "reactivate" a request's code should be via resolution of the I/O for which they suspended in the first place. This implies that we provide further "guarding" semantics, and configurable ones, for the framework's validation of the component target of a dispatch - via either listeners or invokers - similar to the "destroyed component detection" operated by FLUID-4890. JIRA at http://issues.fluidproject.org/browse/FLUID-5577

Point 2

Secondly, we might consider any attempt to modify a set of listeners whilst we are in the process of iterating through them, to represent an implementation error - not least, because the current framework will ignore any such request, which is most likely a mismatch with any reasonable expectation of the implementor. Presumably we should allow an exception for a listener removing ITSELF from the listener chain which is an accepted implementation pattern (cf the "once" pattern within jQuery etc.). This implies that the "fail-fast" behaviour should apply to modification which would hit any listener other than the one at the currently notifying index. This seems like an annoyance to implement, and in any case would only provide detection later than that of Point 1, which is effective but rather less glamorous. We should therefore concentrate on the component validation scheme first. JIRA at http://issues.fluidproject.org/browse/FLUID-5578

The Full Trace:

 

Trace
20:21:37.261:  Registering module infusion from path E:\source\gits\gpii\node_modules\universal\node_modules\infusion
20:21:37.293:  Registering module kettle from path E:\source\gits\gpii\node_modules\universal\node_modules\kettle
20:21:37.594:  Clearing cache for component flowManager.io with gradeNames [
    "flowManager.io",
    "fluid.littleComponent",
    "kettle.config",
    "autoInit"
]
20:21:37.864:  Created new instantiator with id 9wrq5kv4-19 in order to operate on component kettle.test.serverEnvironment
20:21:37.906:  Successfully queued test Flow Manager update tests
20:21:37.919:  Initializing the Express app
20:21:37.924:  Initializing the HTTP server.
20:21:38.128:  Initializing the socket.io.
info: socket.io started
20:21:38.232:  Opening Kettle Server on port 8081
20:21:38.235:  Kettle Server 9wrq5kv4-108 is listening on port 8081
20:21:38.236:  connecting socket.io to: ws://localhost:8081/update
20:21:38.238:  Invoked new XHR request: Error
    at Object.ioClient.util.request (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\test\utils\js\KettleTestUtils.js:195:45)
    at Socket.handshake (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\socket.js:149:25)
    at Socket.connect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\socket.js:209:10)
    at new Socket (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\socket.js:61:12)
    at Object.io.connect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\io.js:193:16)
    at kettle.test.request.io.connect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\test\utils\js\KettleTestUtils.js:182:28)
    at Object.invokeInvoker [as connect] (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at kett .... [output suppressed at 1024 chars - for more output, increase fluid.logObjectRenderChars]
debug: client authorized
info: handshake authorized M1Yq4Sq5t8KEL3FVxQE3
debug: setting request GET /socket.io/1/websocket/M1Yq4Sq5t8KEL3FVxQE3
debug: set heartbeat interval for client M1Yq4Sq5t8KEL3FVxQE3
debug: client authorized for 
debug: websocket writing 1::
debug: client authorized for /update
debug: websocket writing 1::/update
&&&&&&&&&&&&&&&&& FIRING SESSIONAWARE ONERROR FROM Error
    at gpii.request.flowManager.sessionAware.withSession (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:151:81)
    at Object.invokeInvoker [as withSession] (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at gpii.request.flowManager.userUpdateHandle (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\UserUpdate.js:85:14)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1880:20)
    at Object.fluid.tryCatch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:219:24)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1875:22)
    at Object.fluid.event.invokeListener (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1052:25)
    at fluid.event.dispatchListener.togo (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1722:36)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Object.fluid.fireEvent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1219:24)
    at Object.fluid.initDependent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1316:15)
    at fluid.bindDeferredComponent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1337:23)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at kettle.requests.handleRequest (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\request.js:76:31)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Socket.onMessage (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\server.io.js:106:54)
    at Socket.EventEmitter.emit [as $emit] (events.js:91:17)
    at SocketNamespace.handlePacket (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\namespace.js:335:22)
    at Manager.onClientMessage (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\manager.js:518:38)
    at WebSocket.Transport.onMessage (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transport.js:369:20)
    at Parser.<anonymous> (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:39:10)
    at Parser.EventEmitter.emit (events.js:88:17)
    at opcodeHandlers.1.finish (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:295:16)
    at Parser.opcodeHandlers.1.expectData [as expectHandler] (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:306:15)
    at Parser.add (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:482:24)
    at Parser.expect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:519:10)
    at Parser.opcodeHandlers.1.expectData (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:305:18)
    at Parser.add (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:482:24)
    at Parser.expect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:519:10)
    at opcodeHandlers.1.expectData (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:303:16)
    at opcodeHandlers.1 (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:320:9)
    at Parser.processPacket (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:553:8)
    at Parser.add (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:482:24)
    at Socket.WebSocket.onSocketConnect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:146:17)
    at Socket.EventEmitter.emit (events.js:88:17)
    at TCP.onread (net.js:395:14)
Current request: { typeName: 'kettle.requests.request.io',
  id: '9wrq5kv4-568',
  destroy: [Function],
  options: 
   { gradeNames: 
      [ 'kettle.requests.request.io',
        'kettle.requests.request',
        'fluid.eventedComponent',
        'fluid.littleComponent',
        'fluid.applyGradeLinkage',
        'autoInit' ],
     socket: 
      { id: 'M1Yq4Sq5t8KEL3FVxQE3',
        namespace: [Object],
        manager: [Object],
        disconnected: false,
        ackPackets: 0,
        acks: {},
        flags: [Object],
        readable: true,
        store: [Object],
        _events: [Object],
        fluidRequest: [Circular] },
     data: 'You shall not pass!!',
     send: [Function: ack],
     members: 
      { socket: '{that}.options.socket',
        data: '{that}.options.data',
        send: '{that}.options.send' },
     listeners: { onCreate: [Object], onError: [Object], onSuccess: [Object] },
     invokers: 
      { onErrorHandler: [Object],
        onSuccessHandler: [Object],
        ensureResCompleted: [Object],
        attachFluidRequest: [Object] },
     components: { handler: [Object] },
     events: 
      { handle: null,
        onRequestEnd: null,
        onError: null,
        onSuccess: null,
        onCreate: null,
        onAttach: null,
        onClear: null,
        onDestroy: null,
        afterDestroy: null },
     argumentMap: { options: 0 } },
  nickName: 'io',
  events: 
   { handle: 
      { eventId: '9wrq5kv4-569',
        name: 'handle of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onRequestEnd: 
      { eventId: '9wrq5kv4-570',
        name: 'onRequestEnd of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Object] },
     onError: 
      { eventId: '9wrq5kv4-571',
        name: 'onError of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onSuccess: 
      { eventId: '9wrq5kv4-572',
        name: 'onSuccess of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onCreate: 
      { eventId: '9wrq5kv4-573',
        name: 'onCreate of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onAttach: 
      { eventId: '9wrq5kv4-574',
        name: 'onAttach of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     onClear: 
      { eventId: '9wrq5kv4-575',
        name: 'onClear of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     onDestroy: 
      { eventId: '9wrq5kv4-576',
        name: 'onDestroy of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     afterDestroy: 
      { eventId: '9wrq5kv4-577',
        name: 'afterDestroy of component with typename kettle.requests.request.io and id 9wrq5kv4-568',
        ownerId: '9wrq5kv4-568',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] } },
  ensureResCompleted: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-578' },
  attachFluidRequest: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-579' },
  onErrorHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-580' },
  onSuccessHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-583' },
  socket: 
   { id: 'M1Yq4Sq5t8KEL3FVxQE3',
     namespace: 
      { manager: [Object],
        name: '/update',
        sockets: [Object],
        auth: false,
        flags: [Object],
        _events: [Object] },
     manager: 
      { server: [Object],
        namespaces: [Object],
        sockets: [Object],
        _events: [Object],
        settings: [Object],
        handshaken: [Object],
        connected: [Object],
        open: [Object],
        closed: {},
        rooms: [Object],
        roomClients: [Object],
        oldListeners: [Object],
        sequenceNumber: -2033909449,
        gc: [Object] },
     disconnected: false,
     ackPackets: 0,
     acks: {},
     flags: { endpoint: '/update', room: '' },
     readable: true,
     store: { store: [Object], id: 'M1Yq4Sq5t8KEL3FVxQE3', data: {} },
     _events: 
      { error: [Function],
        message: [Function: onMessage],
        disconnect: [Function] },
     fluidRequest: [Circular] },
  data: 'You shall not pass!!',
  send: [Function: ack],
  handlerContext: 'kettle.requests.request.handler.userUpdate',
  handler: 
   { typeName: 'kettle.requests.request.handler',
     id: '9wrq5kv4-585',
     destroy: [Function],
     options: 
      { gradeNames: [Object],
        invokers: [Object],
        listeners: [Object],
        argumentMap: [Object],
        events: [Object] },
     nickName: 'handler',
     events: 
      { onSolutionsRegistry: [Object],
        onDevice: [Object],
        onToken: [Object],
        onPreferences: [Object],
        onMatch: [Object],
        onReadyForLifecycle: [Object],
        onReadyToMatch: [Object],
        onCreate: [Object],
        onAttach: [Object],
        onClear: [Object],
        onDestroy: [Object],
        afterDestroy: [Object] },
     getPreferences: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-603' },
     runMatchMakerFramework: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-604' },
     getSolutions: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-605' },
     fireOnMatch: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-606' },
     onMatchHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-607' },
     handle: [Function: invokeInvoker],
     getActiveSessionTokens: [Function: invokeInvoker],
     withSession: [Function: invokeInvoker],
     onMatch: [Function: invokeInvoker] } }
debug: websocket writing 5::/update:{"name":"error","args":[{"isError":true,"message":"Error handling request which required active session, but none was active"}]}
20:21:38.305:  Sending a GET request to: /user/testUser1/login on port 8081
20:21:38.324:  gpii.request.flowManager.getPreferences called - fetching preferences
20:21:38.326:  gpii.request.flowManager.getDevice called - fetching device info
20:21:38.367:  Fetched device reporter data: {
    "solutions": [
        {
            "id": "test.dummy"
        }
    ],
    "OS": {
        "id": "win32",
        "version": "6.1.7601"
    }
}
20:21:38.370:  Fetched raw user preferences: {
    "token": "testUser1",
    "preferences": {
        "flat": {
            "contexts": {
                "gpii-default": {
                    "name": "Default preferences",
                    "preferences": {
                        "http://registry.gpii.net/applications/test.dummy": {
                            "dummySetting1": 12
                        }
                    }
                }
            }
        }
    }
}
20:21:38.371:  Raw preferences fetched by preferencesServer: [object Object]
20:21:38.372:  Fetched user preferences: {
    "contexts": {
        "gpii-default": {
            "name": "Default preferences",
            "preferences": {
                "http://registry.gpii.net/applications/test.dummy": {
                    "dummySetting1": 12
                }
            }
        }
    }
}
20:21:38.372:  Fetched solutions registry: {
    "test.dummy": {
        "name": "Dummy solution registry entry",
        "contexts": {
            "OS": [
                {
                    "id": "darwin"
                }
            ]
        },
        "settingsHandlers": [
            {
                "type": "gpii.settingsHandlers.noSettings",
                "capabilities": [
                    "applications.test\\.dummy.id"
                ],
                "capabilitiesTransformations": {
                    "dummySetting1": "http://registry\\.gpii\\.net/common/fontSize",
                    "dummySetting2": "http://registry\\.gpii\\.net/common/setting2"
                }
            }
        ],
        "lifecycleManager": {
            "start": [],
            "stop": []
        }
    }
}
20:21:38.373:  MatchMaker Framework: dispatching to the flat MatchMaker
Returned from MM
!*!!*!*!*!*!*!!* FIRING TO ONMATCH NOW!!! listeners are [
    {
        "listener": { Function
            "$$fluid_guid": "9wrq5kv4-606"
        },
        "predicate": undefined,
        "namespace": "kettle.requests.request.handler.fireOnMatch",
        "softNamespace": true,
        "priority": 0
    },
    {
        "listener": { Function
            "$$fluid_guid": "9wrq5kv4-652"
        },
        "predicate": undefined,
        "namespace": "kettle.requests.request.handler.fireOnMatch",
        "softNamespace": true,
        "priority": 1
    }
]
&&&&&&&&&&&&&&&&& FIRING SESSIONAWARE ONERROR FROM Error
    at gpii.request.flowManager.sessionAware.withSession (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:151:81)
    at Object.invoke (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1623:25)
    at Object.invokeInvoker [as withSession] (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1650:32)
    at gpii.request.flowManager.onMatchUpdateHandler (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\UserUpdate.js:111:14)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at gpii.request.flowManager.fireOnMatch (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:145:20)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Array.gpii.matchMakerFramework.matchMakerDispatcher [as 0] (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\matchMakerFramework\src\MatchMakerFramework.js:91:19)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at Object.fluid.promise.that.then (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:31:21)
    at Function.fluid.promise.follow (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:83:16)
    at Array.kettle.dataSource.set [as 0] (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:220:31)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at Object.fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at onEnd (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:325:33)
    at applyCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:57:37)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1880:20)
    at Object.fluid.tryCatch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:219:24)
    at Object.fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1875:22)
    at IncomingMessage.wrapCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:54:30)
    at IncomingMessage.EventEmitter.emit (events.js:115:20)
    at IncomingMessage._emitEnd (http.js:366:10)
    at HTTPParser.parserOnMessageComplete [as onMessageComplete] (http.js:149:23)
    at Socket.socketOnData [as ondata] (http.js:1366:20)
    at TCP.onread (net.js:402:27)
Current request: { typeName: 'kettle.requests.request.http',
  id: '9wrq5kv4-609',
  destroy: [Function],
  options: 
   { gradeNames: 
      [ 'kettle.requests.request.evented',
        'fluid.eventedComponent',
        'fluid.littleComponent',
        'kettle.requests.request.http',
        'kettle.requests.request',
        'fluid.applyGradeLinkage',
        '{requests}.eventedRequestGrade',
        'autoInit' ],
     req: 
      { socket: [Object],
        connection: [Object],
        httpVersion: '1.1',
        complete: true,
        headers: [Object],
        trailers: {},
        readable: false,
        _paused: false,
        _pendings: [],
        _endEmitted: true,
        url: '/user/testUser1/login',
        method: 'GET',
        statusCode: null,
        client: [Object],
        httpVersionMajor: 1,
        httpVersionMinor: 1,
        upgrade: false,
        originalUrl: '/user/testUser1/login',
        _parsedUrl: [Object],
        query: {},
        res: [Object],
        next: [Function: next],
        fluidRequest: [Circular],
        body: {},
        _route_index: 6,
        route: [Object],
        params: [Object] },
     res: 
      { output: [],
        outputEncodings: [],
        writable: true,
        _last: false,
        chunkedEncoding: false,
        shouldKeepAlive: false,
        useChunkedEncodingByDefault: true,
        sendDate: true,
        _hasBody: true,
        _trailer: '',
        finished: false,
        socket: [Object],
        connection: [Object],
        _events: [Object],
        _headers: [Object],
        _headerNames: [Object],
        req: [Object],
        locals: [Function: locals] },
     next: [Function: next],
     events: 
      { onCORS: null,
        onBodyParser: null,
        onCreate: null,
        onAttach: null,
        onClear: null,
        onDestroy: null,
        afterDestroy: null,
        handle: null,
        onRequestEnd: null,
        onError: null,
        onSuccess: null },
     listeners: 
      { onCreate: [Object],
        onError: [Object],
        onSuccess: [Object],
        onAttach: [Object],
        onCORS: [Object],
        onBodyParser: [Object] },
     argumentMap: { options: 0 },
     members: 
      { req: '{that}.options.req',
        res: '{that}.options.res',
        next: '{that}.options.next',
        requestPromise: [Object] },
     invokers: 
      { onErrorHandler: [Object],
        onSuccessHandler: [Object],
        ensureResCompleted: [Object],
        attachFluidRequest: [Object],
        proceed: [Object] },
     components: { handler: [Object] } },
  nickName: 'http',
  events: 
   { onCORS: 
      { eventId: '9wrq5kv4-610',
        name: 'onCORS of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onBodyParser: 
      { eventId: '9wrq5kv4-611',
        name: 'onBodyParser of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onCreate: 
      { eventId: '9wrq5kv4-612',
        name: 'onCreate of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onAttach: 
      { eventId: '9wrq5kv4-613',
        name: 'onAttach of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onClear: 
      { eventId: '9wrq5kv4-614',
        name: 'onClear of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     onDestroy: 
      { eventId: '9wrq5kv4-615',
        name: 'onDestroy of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     afterDestroy: 
      { eventId: '9wrq5kv4-616',
        name: 'afterDestroy of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     handle: 
      { eventId: '9wrq5kv4-617',
        name: 'handle of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onRequestEnd: 
      { eventId: '9wrq5kv4-618',
        name: 'onRequestEnd of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     onError: 
      { eventId: '9wrq5kv4-619',
        name: 'onError of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onSuccess: 
      { eventId: '9wrq5kv4-620',
        name: 'onSuccess of component with typename kettle.requests.request.http and id 9wrq5kv4-609',
        ownerId: '9wrq5kv4-609',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] } },
  ensureResCompleted: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-621' },
  attachFluidRequest: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-622' },
  onErrorHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-623' },
  onSuccessHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-624' },
  proceed: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-625' },
  req: 
   { socket: 
      { _handle: [Object],
        _pendingWriteReqs: 0,
        _flags: 0,
        _connectQueueSize: 0,
        destroyed: false,
        errorEmitted: false,
        bytesRead: 79,
        _bytesDispatched: 0,
        allowHalfOpen: true,
        writable: true,
        readable: true,
        server: [Object],
        _events: [Object],
        _idleTimeout: 120000,
        _idleNext: [Object],
        _idlePrev: [Object],
        _idleStart: Thu Nov 06 2014 20:21:38 GMT+0000 (GMT Standard Time),
        parser: [Object],
        ondata: [Function],
        onend: [Function],
        _httpMessage: [Object],
        _paused: false },
     connection: 
      { _handle: [Object],
        _pendingWriteReqs: 0,
        _flags: 0,
        _connectQueueSize: 0,
        destroyed: false,
        errorEmitted: false,
        bytesRead: 79,
        _bytesDispatched: 0,
        allowHalfOpen: true,
        writable: true,
        readable: true,
        server: [Object],
        _events: [Object],
        _idleTimeout: 120000,
        _idleNext: [Object],
        _idlePrev: [Object],
        _idleStart: Thu Nov 06 2014 20:21:38 GMT+0000 (GMT Standard Time),
        parser: [Object],
        ondata: [Function],
        onend: [Function],
        _httpMessage: [Object],
        _paused: false },
     httpVersion: '1.1',
     complete: true,
     headers: { host: 'localhost:8081', connection: 'close' },
     trailers: {},
     readable: false,
     _paused: false,
     _pendings: [],
     _endEmitted: true,
     url: '/user/testUser1/login',
     method: 'GET',
     statusCode: null,
     client: 
      { _handle: [Object],
        _pendingWriteReqs: 0,
        _flags: 0,
        _connectQueueSize: 0,
        destroyed: false,
        errorEmitted: false,
        bytesRead: 79,
        _bytesDispatched: 0,
        allowHalfOpen: true,
        writable: true,
        readable: true,
        server: [Object],
        _events: [Object],
        _idleTimeout: 120000,
        _idleNext: [Object],
        _idlePrev: [Object],
        _idleStart: Thu Nov 06 2014 20:21:38 GMT+0000 (GMT Standard Time),
        parser: [Object],
        ondata: [Function],
        onend: [Function],
        _httpMessage: [Object],
        _paused: false },
     httpVersionMajor: 1,
     httpVersionMinor: 1,
     upgrade: false,
     originalUrl: '/user/testUser1/login',
     _parsedUrl: 
      { pathname: '/user/testUser1/login',
        path: '/user/testUser1/login',
        href: '/user/testUser1/login' },
     query: {},
     res: 
      { output: [],
        outputEncodings: [],
        writable: true,
        _last: false,
        chunkedEncoding: false,
        shouldKeepAlive: false,
        useChunkedEncodingByDefault: true,
        sendDate: true,
        _hasBody: true,
        _trailer: '',
        finished: false,
        socket: [Object],
        connection: [Object],
        _events: [Object],
        _headers: [Object],
        _headerNames: [Object],
        req: [Circular],
        locals: [Function: locals] },
     next: [Function: next],
     fluidRequest: [Circular],
     body: {},
     _route_index: 6,
     route: 
      { path: '/user/:token/login',
        method: 'get',
        callbacks: [Object],
        keys: [Object],
        regexp: /^\/user\/(?:([^\/]+?))\/login\/?$/i,
        params: [Object] },
     params: [ token: 'testUser1' ] },
  res: 
   { output: [],
     outputEncodings: [],
     writable: true,
     _last: false,
     chunkedEncoding: false,
     shouldKeepAlive: false,
     useChunkedEncodingByDefault: true,
     sendDate: true,
     _hasBody: true,
     _trailer: '',
     finished: false,
     socket: 
      { _handle: [Object],
        _pendingWriteReqs: 0,
        _flags: 0,
        _connectQueueSize: 0,
        destroyed: false,
        errorEmitted: false,
        bytesRead: 79,
        _bytesDispatched: 0,
        allowHalfOpen: true,
        writable: true,
        readable: true,
        server: [Object],
        _events: [Object],
        _idleTimeout: 120000,
        _idleNext: [Object],
        _idlePrev: [Object],
        _idleStart: Thu Nov 06 2014 20:21:38 GMT+0000 (GMT Standard Time),
        parser: [Object],
        ondata: [Function],
        onend: [Function],
        _httpMessage: [Circular],
        _paused: false },
     connection: 
      { _handle: [Object],
        _pendingWriteReqs: 0,
        _flags: 0,
        _connectQueueSize: 0,
        destroyed: false,
        errorEmitted: false,
        bytesRead: 79,
        _bytesDispatched: 0,
        allowHalfOpen: true,
        writable: true,
        readable: true,
        server: [Object],
        _events: [Object],
        _idleTimeout: 120000,
        _idleNext: [Object],
        _idlePrev: [Object],
        _idleStart: Thu Nov 06 2014 20:21:38 GMT+0000 (GMT Standard Time),
        parser: [Object],
        ondata: [Function],
        onend: [Function],
        _httpMessage: [Circular],
        _paused: false },
     _events: 
      { finish: [Object],
        close: [Function: eventListener],
        end: [Function: eventListener],
        error: [Function: eventListener] },
     _headers: 
      { 'x-powered-by': 'Express',
        'access-control-allow-origin': 'undefined',
        'access-control-allow-credentials': 'true',
        'access-control-allow-methods': 'GET,OPTIONS',
        'access-control-allow-headers': 'X-Requested-With,Content-Type' },
     _headerNames: 
      { 'x-powered-by': 'X-Powered-By',
        'access-control-allow-origin': 'Access-Control-Allow-Origin',
        'access-control-allow-credentials': 'Access-Control-Allow-Credentials',
        'access-control-allow-methods': 'Access-Control-Allow-Methods',
        'access-control-allow-headers': 'Access-Control-Allow-Headers' },
     req: 
      { socket: [Object],
        connection: [Object],
        httpVersion: '1.1',
        complete: true,
        headers: [Object],
        trailers: {},
        readable: false,
        _paused: false,
        _pendings: [],
        _endEmitted: true,
        url: '/user/testUser1/login',
        method: 'GET',
        statusCode: null,
        client: [Object],
        httpVersionMajor: 1,
        httpVersionMinor: 1,
        upgrade: false,
        originalUrl: '/user/testUser1/login',
        _parsedUrl: [Object],
        query: {},
        res: [Circular],
        next: [Function: next],
        fluidRequest: [Circular],
        body: {},
        _route_index: 6,
        route: [Object],
        params: [Object] },
     locals: [Function: locals] },
  next: [Function: next],
  requestPromise: 
   { onResolve: [ [Function] ],
     onReject: [ [Function] ],
     then: [Function],
     resolve: [Function],
     reject: [Function],
     complete: [Function] },
  handlerContext: 'kettle.requests.request.handler.userLogin',
  handler: 
   { typeName: 'kettle.requests.request.handler',
     id: '9wrq5kv4-629',
     destroy: [Function],
     options: 
      { gradeNames: [Object],
        invokers: [Object],
        listeners: [Object],
        argumentMap: [Object],
        events: [Object] },
     nickName: 'handler',
     events: 
      { onSolutionsRegistry: [Object],
        onDevice: [Object],
        onToken: [Object],
        onPreferences: [Object],
        onMatch: [Object],
        onReadyForLifecycle: [Object],
        onReadyToMatch: [Object],
        onCreate: [Object],
        onAttach: [Object],
        onClear: [Object],
        onDestroy: [Object],
        afterDestroy: [Object] },
     getPreferences: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-647' },
     getDevice: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-648' },
     runMatchMakerFramework: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-649' },
     getSolutions: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-651' },
     fireOnMatch: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-652' },
     runContextManager: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-653' },
     startLifecycle: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-654' },
     handle: [Function: invokeInvoker],
     onMatch: [Function: invokeInvoker],
     userToken: 'testUser1',
     userPreferences: { contexts: [Object] },
     userDevice: { solutions: [Object], OS: [Object] } } }
CLEARLISTENERS executing for shadow  { that: 
   { typeName: 'kettle.requests.request.handler',
     id: '9wrq5kv4-629',
     destroy: { __COMPONENT_DESTROYED__: true },
     options: 
      { gradeNames: [Object],
        invokers: [Object],
        listeners: [Object],
        argumentMap: [Object],
        events: [Object] },
     nickName: 'handler',
     events: 
      { onSolutionsRegistry: [Object],
        onDevice: [Object],
        onToken: [Object],
        onPreferences: [Object],
        onMatch: [Object],
        onReadyForLifecycle: [Object],
        onReadyToMatch: [Object],
        onCreate: [Object],
        onAttach: [Object],
        onClear: [Object],
        onDestroy: [Object],
        afterDestroy: [Object] },
     getPreferences: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-647' },
     getDevice: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-648' },
     runMatchMakerFramework: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-649' },
     getSolutions: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-651' },
     fireOnMatch: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-652' },
     runContextManager: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-653' },
     startLifecycle: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-654' },
     handle: [Function: invokeInvoker],
     onMatch: [Function: invokeInvoker],
     userToken: 'testUser1',
     userPreferences: { contexts: [Object] },
     userDevice: { solutions: [Object], OS: [Object] } },
  path: 'tests.configuration.server.requests.request.handler',
  mergePolicy: 
   { gradeNames: { '*': [Object] },
     mergePolicy: { '*': [Object] },
     argumentMap: { '*': [Object] },
     components: { '*': [Object] },
     dynamicComponents: { '*': [Object] },
     members: { '*': [Object] },
     invokers: { '*': [Object] },
     events: { '*': [Object] },
     listeners: { '*': [Object] },
     modelListeners: { '*': [Object] },
     distributeOptions: { '*': [Object] },
     transformOptions: { '*': [Object] },
     preInitFunction: { '*': [Object] },
     postInitFunction: { '*': [Object] },
     finalInitFunction: { '*': [Object] } },
  contextHash: 
   { 'kettle.requests.request.handler.userLogin': true,
     userLogin: true,
     'fluid.littleComponent': true,
     littleComponent: true,
     'gpii.request.flowManager.token': true,
     token: true,
     'fluid.eventedComponent': true,
     eventedComponent: true,
     'kettle.requests.request.handler': true,
     handler: true,
     '{request}.handlerContext': true,
     handlerContext: true,
     'fluid.applyGradeLinkage': true,
     applyGradeLinkage: true,
     autoInit: true },
  mergeOptions: 
   { mergePolicy: 
      { gradeNames: [Object],
        mergePolicy: [Object],
        argumentMap: [Object],
        components: [Object],
        dynamicComponents: [Object],
        members: [Object],
        invokers: [Object],
        events: [Object],
        listeners: [Object],
        modelListeners: [Object],
        distributeOptions: [Object],
        transformOptions: [Object],
        preInitFunction: [Object],
        postInitFunction: [Object],
        finalInitFunction: [Object] },
     sources: [ [Object] ],
     target: 
      { gradeNames: [Object],
        invokers: [Object],
        listeners: [Object],
        argumentMap: [Object],
        events: [Object] },
     sourceStrategies: [ [Function] ],
     initter: [Function],
     strategy: [Function],
     mergeBlocks: [ [Object] ],
     updateBlocks: [Function],
     destroyValue: [Function],
     evaluateFully: true },
  invokerStrategy: { strategy: [Function], initter: [Function] },
  eventStrategyBlock: { strategy: [Function], initter: [Function] },
  memberStrategy: { strategy: [Function], initter: [Function] },
  getConfig: 
   { strategies: 
      [ [Function],
        [Function],
        [Function],
        [Function],
        [Function],
        [Function] ] },
  subcomponentLocal: {},
  listeners: 
   [ { event: [Object], listener: [Object] },
     { event: [Object], listener: [Object] },
     { event: [Object], listener: [Object] } ] }
Error
    at Object.fluid.clearListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:760:25)
    at Object.fluid.instantiator.that.clearComponent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:882:23)
    at fluid.instantiator.that.clearComponent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:884:26)
    at Object.fluid.visitComponentChildren (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:35:17)
    at Object.fluid.instantiator.that.clearComponent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:883:23)
    at Object.fluid.fabricateDestroyMethod (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1053:26)
    at ServerResponse.eventListener (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\request.js:197:22)
    at ServerResponse.EventEmitter.emit (events.js:115:20)
    at ServerResponse.OutgoingMessage._finish (http.js:836:8)
    at ServerResponse.OutgoingMessage.end (http.js:821:10)
    at ServerResponse.res.send (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\express\lib\response.js:154:8)
    at ServerResponse.res.json (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\express\lib\response.js:196:15)
    at ServerResponse.res.send (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\express\lib\response.js:122:21)
    at kettle.requests.request.http.onErrorHandler (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\request.js:212:13)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at kettle.requests.eventHandler (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\request.js:87:40)
    at Object.invoke (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1623:25)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1650:32)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at gpii.request.flowManager.sessionAware.withSession (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:154:28)
    at Object.invoke (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1623:25)
    at Object.invokeInvoker [as withSession] (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1650:32)
    at gpii.request.flowManager.onMatchUpdateHandler (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\UserUpdate.js:111:14)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at gpii.request.flowManager.fireOnMatch (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:145:20)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Array.gpii.matchMakerFramework.matchMakerDispatcher [as 0] (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\matchMakerFramework\src\MatchMakerFramework.js:91:19)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at Object.fluid.promise.that.then (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:31:21)
    at Function.fluid.promise.follow (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:83:16)
    at Array.kettle.dataSource.set [as 0] (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:220:31)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at Object.fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at onEnd (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:325:33)
    at applyCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:57:37)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1880:20)
    at Object.fluid.tryCatch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:219:24)
    at Object.fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1875:22)
    at IncomingMessage.wrapCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:54:30)
    at IncomingMessage.EventEmitter.emit (events.js:115:20)
    at IncomingMessage._emitEnd (http.js:366:10)
    at HTTPParser.parserOnMessageComplete [as onMessageComplete] (http.js:149:23)
    at Socket.socketOnData [as ondata] (http.js:1366:20)
    at TCP.onread (net.js:402:27)
shadow.listeners:  [
  {
    "event": {
      "eventId": "9wrq5kv4-636",
      "name": " [composite] onReadyToMatch of component with typename kettle.requests.request.handler and id 9wrq5kv4-629",
      "typeName": "fluid.event.firer",
      "listeners": {
        "kettle.requests.request.handler.runMatchMakerFramework": [
          {
            "namespace": "kettle.requests.request.handler.runMatchMakerFramework",
            "softNamespace": true,
            "priority": 0
          }
        ],
        "kettle.requests.request.handler.userLogin.recordMatch": [
          {
            "namespace": "kettle.requests.request.handler.userLogin.recordMatch",
            "softNamespace": true,
            "priority": 1
          }
        ]
      },
      "byId": {
        "9wrq5kv4-649": {
          "namespace": "kettle.requests.request.handler.runMatchMakerFramework",
          "softNamespace": true,
          "priority": 0
        },
        "9wrq5kv4-650": {
          "namespace": "kettle.requests.request.handler.userLogin.recordMatch",
          "softNamespace": true,
          "priority": 1
        }
      },
      "sortedListeners": [
        {
          "namespace": "kettle.requests.request.handler.runMatchMakerFramework",
          "softNamespace": true,
          "priority": 0
        },
        {
          "namespace": "kettle.requests.request.handler.userLogin.recordMatch",
          "softNamespace": true,
          "priority": 1
        }
      ],
      "destroyed": true
    }
  },
  {
    "event": {
      "eventId": "9wrq5kv4-636",
      "name": " [composite] onReadyToMatch of component with typename kettle.requests.request.handler and id 9wrq5kv4-629",
      "typeName": "fluid.event.firer",
      "listeners": {
        "kettle.requests.request.handler.runMatchMakerFramework": [
          {
            "namespace": "kettle.requests.request.handler.runMatchMakerFramework",
            "softNamespace": true,
            "priority": 0
          }
        ],
        "kettle.requests.request.handler.userLogin.recordMatch": [
          {
            "namespace": "kettle.requests.request.handler.userLogin.recordMatch",
            "softNamespace": true,
            "priority": 1
          }
        ]
      },
      "byId": {
        "9wrq5kv4-649": {
          "namespace": "kettle.requests.request.handler.runMatchMakerFramework",
          "softNamespace": true,
          "priority": 0
        },
        "9wrq5kv4-650": {
          "namespace": "kettle.requests.request.handler.userLogin.recordMatch",
          "softNamespace": true,
          "priority": 1
        }
      },
      "sortedListeners": [
        {
          "namespace": "kettle.requests.request.handler.runMatchMakerFramework",
          "softNamespace": true,
          "priority": 0
        },
        {
          "namespace": "kettle.requests.request.handler.userLogin.recordMatch",
          "softNamespace": true,
          "priority": 1
        }
      ],
      "destroyed": true
    }
  },
  {
    "event": {
      "eventId": "9wrq5kv4-201",
      "name": "onMatch of component with typename gpii.matchMakerFramework and id 9wrq5kv4-197",
      "ownerId": "9wrq5kv4-197",
      "typeName": "fluid.event.firer",
      "listeners": {
        "kettle.requests.request.handler.fireOnMatch": [
          {
            "namespace": "kettle.requests.request.handler.fireOnMatch",
            "softNamespace": true,
            "priority": 0
          },
          {
            "namespace": "kettle.requests.request.handler.fireOnMatch",
            "softNamespace": true,
            "priority": 1
          }
        ]
      },
      "byId": {
        "9wrq5kv4-606": {
          "namespace": "kettle.requests.request.handler.fireOnMatch",
          "softNamespace": true,
          "priority": 0
        },
        "9wrq5kv4-652": {
          "namespace": "kettle.requests.request.handler.fireOnMatch",
          "softNamespace": true,
          "priority": 1
        }
      },
      "sortedListeners": [
        {
          "namespace": "kettle.requests.request.handler.fireOnMatch",
          "softNamespace": true,
          "priority": 0
        },
        {
          "namespace": "kettle.requests.request.handler.fireOnMatch",
          "softNamespace": true,
          "priority": 1
        }
      ]
    }
  }
]
CLEARLISTENERS REMOVING LISTENER  9wrq5kv4-649
CLEARLISTENERS REMOVING LISTENER  9wrq5kv4-650
CLEARLISTENERS REMOVING LISTENER  9wrq5kv4-652
shadow.listeners:  [
  {
    "event": {
      "eventId": "9wrq5kv4-636",
      "name": " [composite] onReadyToMatch of component with typename kettle.requests.request.handler and id 9wrq5kv4-629",
      "typeName": "fluid.event.firer",
      "listeners": {},
      "byId": {},
      "sortedListeners": [],
      "destroyed": true
    }
  },
  {
    "event": {
      "eventId": "9wrq5kv4-636",
      "name": " [composite] onReadyToMatch of component with typename kettle.requests.request.handler and id 9wrq5kv4-629",
      "typeName": "fluid.event.firer",
      "listeners": {},
      "byId": {},
      "sortedListeners": [],
      "destroyed": true
    }
  },
  {
    "event": {
      "eventId": "9wrq5kv4-201",
      "name": "onMatch of component with typename gpii.matchMakerFramework and id 9wrq5kv4-197",
      "ownerId": "9wrq5kv4-197",
      "typeName": "fluid.event.firer",
      "listeners": {
        "kettle.requests.request.handler.fireOnMatch": [
          {
            "namespace": "kettle.requests.request.handler.fireOnMatch",
            "softNamespace": true,
            "priority": 0
          }
        ]
      },
      "byId": {
        "9wrq5kv4-606": {
          "namespace": "kettle.requests.request.handler.fireOnMatch",
          "softNamespace": true,
          "priority": 0
        }
      },
      "sortedListeners": [
        {
          "namespace": "kettle.requests.request.handler.fireOnMatch",
          "softNamespace": true,
          "priority": 0
        }
      ]
    }
  }
]
20:21:38.417:  ASSERTION FAILED: Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed{
    "type": "expandContextValue",
    "message": "expanding context value %source held at path %path",
    "args": {
        "source": "{that}.events.onMatch",
        "path": ""
    },
    "time": 1415305298417
}{
    "type": "resolveContextValue",
    "message": "resolving context value %string",
    "args": {
        "string": "{that}.events.onMatch"
    },
    "time": 1415305298417
}
20:21:38.417:  ASSERTION FAILED: Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed
20:21:38.417:  Current activity: 
    while resolving context value {that}.events.onMatch
    while expanding context value {that}.events.onMatch held at path ""
20:21:38.418:  FATAL ERROR: Uncaught exception: Object Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed has no method 'Assertion failure - check console for details'
TypeError: Object Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed has no method 'Assertion failure - check console for details'
    at Object.fluid.builtinFail (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:163:69)
    at kettle.utils.failureHandler (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:98:15)
    at Object.fluid.fail (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:184:13)
    at Object.fluid.makeStackFetcher.fetcher (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:726:23)
    at fetch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2053:32)
    at Object.fluid.resolveContextValue (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2061:20)
    at Object.fluid.expandSource (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2158:34)
    at Object.fluid.makeExpandOptions.options.expandSource (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2234:26)
    at Object.fluid.makeExpandOptions (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2249:42)
    at Object.fluid.expand (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:2259:35)
    at Object.fluid.embodyDemands (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1226:37)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1655:40)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Array.gpii.matchMakerFramework.matchMakerDispatcher [as 0] (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\matchMakerFramework\src\MatchMakerFramework.js:91:19)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at Object.fluid.promise.that.then (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:31:21)
    at Function.fluid.promise.follow (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:83:16)
    at Array.kettle.dataSource.set [as 0] (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:220:31)
    at Object.fluid.promise.that.complete (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:65:25)
    at Object.fluid.promise.that.resolve (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidPromises.js:49:22)
    at onEnd (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\dataSource.js:325:33)
    at applyCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:57:37)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1880:20)
    at Object.fluid.tryCatch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:219:24)
    at Object.fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1875:22)
    at IncomingMessage.wrapCallback (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\utils.js:54:30)
    at IncomingMessage.EventEmitter.emit (events.js:115:20)
    at IncomingMessage._emitEnd (http.js:366:10)
    at HTTPParser.parserOnMessageComplete [as onMessageComplete] (http.js:149:23)
    at Socket.socketOnData [as ondata] (http.js:1366:20)
    at TCP.onread (net.js:402:27)
20:21:38.423:  jq: FAIL: Module "update tests" Test name "Flow Manager update tests" - Message: Unexpected failure in test case (see following log for more details): Object Cannot resolve reference {that}.events.onMatch from component { typeName: "kettle.requests.request.handler" gradeNames: ["kettle.requests.request.handler.userLogin","gpii.request.flowManager.token","kettle.requests.request.handler","{request}.handlerContext","fluid.applyGradeLinkage"] id: 9wrq5kv4-629} which has been destroyed has no method 'Assertion failure - check console for details'
20:21:38.423:  jq: Source:     at kettle.test.handleUncaughtException (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\test\utils\js\KettleTestUtils.js:32:15)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at process.onUncaughtException (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\module\fluid.js:94:35)
    at process.EventEmitter.emit (events.js:115:20)
20:21:38.425:  jq: FAIL: Module "update tests" Test name "Flow Manager update tests" - Message: Response is correct - at sequence position 6 of 19
20:21:38.425:  jq: Expected: User with token testUser1 was successfully logged in.
20:21:38.425:  jq: Actual: {
  "isError": true,
  "message": "Error handling request which required active session, but none was active"
}
20:21:38.425:  jq: Source:     at Object.jsUnitCompat.assertEquals (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\tests\test-core\jqUnit\js\jqUnit.js:127:19)
    at gpii.tests.flowManager.update.testLoginResponse (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\test\UpdateTests.js:71:12)
    at fluid.test.makeBinder.that.bind.wrapped (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\tests\test-core\utils\js\IoCTestUtils.js:313:26)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at IncomingMessage.kettle.test.request.http.send.req (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\test\utils\js\KettleTestUtils.js:329:13)
    at IncomingMessage.EventEmitter.emit (events.js:115:20)
    at IncomingMessage._emitEnd (http.js:366:10)
     .... [output suppressed at 1024 chars - for more output, increase fluid.logObjectRenderChars]
20:21:38.426:  connecting socket.io to: ws://localhost:8081/update
20:21:38.428:  Invoked new XHR request: Error
    at Object.ioClient.util.request (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\test\utils\js\KettleTestUtils.js:195:45)
    at Socket.handshake (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\socket.js:149:25)
    at Socket.connect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\socket.js:209:10)
    at new Socket (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\socket.js:61:12)
    at Object.io.connect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io-client\lib\io.js:193:16)
    at kettle.test.request.io.connect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\test\utils\js\KettleTestUtils.js:182:28)
    at Object.invokeInvoker [as connect] (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at kett .... [output suppressed at 1024 chars - for more output, increase fluid.logObjectRenderChars]
debug: client authorized
info: handshake authorized jw2k7iQDQItgrP-wxQE4
debug: setting request GET /socket.io/1/websocket/jw2k7iQDQItgrP-wxQE4
debug: set heartbeat interval for client jw2k7iQDQItgrP-wxQE4
debug: client authorized for 
debug: websocket writing 1::
debug: client authorized for /update
debug: websocket writing 1::/update
&&&&&&&&&&&&&&&&& FIRING SESSIONAWARE ONERROR FROM Error
    at gpii.request.flowManager.sessionAware.withSession (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\FlowManagerUtilities.js:151:81)
    at Object.invokeInvoker [as withSession] (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at gpii.request.flowManager.userUpdateHandle (E:\source\gits\gpii\node_modules\universal\gpii\node_modules\flowManager\src\UserUpdate.js:85:14)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1664:29)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1880:20)
    at Object.fluid.tryCatch (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:219:24)
    at fluid.withEnvironment (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1875:22)
    at Object.fluid.event.invokeListener (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1052:25)
    at fluid.event.dispatchListener.togo (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1722:36)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Object.fluid.fireEvent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1219:24)
    at Object.fluid.initDependent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1316:15)
    at fluid.bindDeferredComponent (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1337:23)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at kettle.requests.handleRequest (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\request.js:76:31)
    at Object.invoke (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1623:25)
    at invokeInvoker (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\FluidIoC.js:1650:32)
    at fireToListeners (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1106:68)
    at Object.fluid.makeEventFirer.that.fire (E:\source\gits\gpii\node_modules\universal\node_modules\infusion\src\framework\core\js\Fluid.js:1205:24)
    at Socket.onMessage (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\lib\server.io.js:106:54)
    at Socket.EventEmitter.emit [as $emit] (events.js:91:17)
    at SocketNamespace.handlePacket (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\namespace.js:335:22)
    at Manager.onClientMessage (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\manager.js:518:38)
    at WebSocket.Transport.onMessage (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transport.js:369:20)
    at Parser.<anonymous> (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:39:10)
    at Parser.EventEmitter.emit (events.js:88:17)
    at opcodeHandlers.1.finish (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:295:16)
    at Parser.opcodeHandlers.1.expectData [as expectHandler] (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:306:15)
    at Parser.add (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:482:24)
    at Parser.expect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:519:10)
    at Parser.opcodeHandlers.1.expectData (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:305:18)
    at Parser.add (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:482:24)
    at Parser.expect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:519:10)
    at opcodeHandlers.1.expectData (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:303:16)
    at opcodeHandlers.1 (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:320:9)
    at Parser.processPacket (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:553:8)
    at Parser.add (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:482:24)
    at Socket.WebSocket.onSocketConnect (E:\source\gits\gpii\node_modules\universal\node_modules\kettle\node_modules\socket.io\lib\transports\websocket\hybi-16.js:146:17)
    at Socket.EventEmitter.emit (events.js:88:17)
    at TCP.onread (net.js:395:14)
Current request: { typeName: 'kettle.requests.request.io',
  id: '9wrq5kv4-768',
  destroy: [Function],
  options: 
   { gradeNames: 
      [ 'kettle.requests.request.io',
        'kettle.requests.request',
        'fluid.eventedComponent',
        'fluid.littleComponent',
        'fluid.applyGradeLinkage',
        'autoInit' ],
     socket: 
      { id: 'jw2k7iQDQItgrP-wxQE4',
        namespace: [Object],
        manager: [Object],
        disconnected: false,
        ackPackets: 0,
        acks: {},
        flags: [Object],
        readable: true,
        store: [Object],
        _events: [Object],
        fluidRequest: [Circular] },
     data: { 'test.dummy': [Object] },
     send: [Function: ack],
     members: 
      { socket: '{that}.options.socket',
        data: '{that}.options.data',
        send: '{that}.options.send' },
     listeners: { onCreate: [Object], onError: [Object], onSuccess: [Object] },
     invokers: 
      { onErrorHandler: [Object],
        onSuccessHandler: [Object],
        ensureResCompleted: [Object],
        attachFluidRequest: [Object] },
     components: { handler: [Object] },
     events: 
      { handle: null,
        onRequestEnd: null,
        onError: null,
        onSuccess: null,
        onCreate: null,
        onAttach: null,
        onClear: null,
        onDestroy: null,
        afterDestroy: null },
     argumentMap: { options: 0 } },
  nickName: 'io',
  events: 
   { handle: 
      { eventId: '9wrq5kv4-769',
        name: 'handle of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onRequestEnd: 
      { eventId: '9wrq5kv4-770',
        name: 'onRequestEnd of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Object] },
     onError: 
      { eventId: '9wrq5kv4-771',
        name: 'onError of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onSuccess: 
      { eventId: '9wrq5kv4-772',
        name: 'onSuccess of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onCreate: 
      { eventId: '9wrq5kv4-773',
        name: 'onCreate of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function],
        listeners: [Object],
        byId: [Object],
        sortedListeners: [Object] },
     onAttach: 
      { eventId: '9wrq5kv4-774',
        name: 'onAttach of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     onClear: 
      { eventId: '9wrq5kv4-775',
        name: 'onClear of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     onDestroy: 
      { eventId: '9wrq5kv4-776',
        name: 'onDestroy of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] },
     afterDestroy: 
      { eventId: '9wrq5kv4-777',
        name: 'afterDestroy of component with typename kettle.requests.request.io and id 9wrq5kv4-768',
        ownerId: '9wrq5kv4-768',
        typeName: 'fluid.event.firer',
        destroy: [Function],
        addListener: [Function],
        removeListener: [Function],
        fireToListeners: [Function],
        fire: [Function] } },
  ensureResCompleted: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-778' },
  attachFluidRequest: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-779' },
  onErrorHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-780' },
  onSuccessHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-783' },
  socket: 
   { id: 'jw2k7iQDQItgrP-wxQE4',
     namespace: 
      { manager: [Object],
        name: '/update',
        sockets: [Object],
        auth: false,
        flags: [Object],
        _events: [Object] },
     manager: 
      { server: [Object],
        namespaces: [Object],
        sockets: [Object],
        _events: [Object],
        settings: [Object],
        handshaken: [Object],
        connected: [Object],
        open: [Object],
        closed: {},
        rooms: [Object],
        roomClients: [Object],
        oldListeners: [Object],
        sequenceNumber: -2033909448,
        gc: [Object] },
     disconnected: false,
     ackPackets: 0,
     acks: {},
     flags: { endpoint: '/update', room: '' },
     readable: true,
     store: { store: [Object], id: 'jw2k7iQDQItgrP-wxQE4', data: {} },
     _events: 
      { error: [Function],
        message: [Function: onMessage],
        disconnect: [Function] },
     fluidRequest: [Circular] },
  data: { 'test.dummy': { settings: [Object] } },
  send: [Function: ack],
  handlerContext: 'kettle.requests.request.handler.userUpdate',
  handler: 
   { typeName: 'kettle.requests.request.handler',
     id: '9wrq5kv4-785',
     destroy: [Function],
     options: 
      { gradeNames: [Object],
        invokers: [Object],
        listeners: [Object],
        argumentMap: [Object],
        events: [Object] },
     nickName: 'handler',
     events: 
      { onSolutionsRegistry: [Object],
        onDevice: [Object],
        onToken: [Object],
        onPreferences: [Object],
        onMatch: [Object],
        onReadyForLifecycle: [Object],
        onReadyToMatch: [Object],
        onCreate: [Object],
        onAttach: [Object],
        onClear: [Object],
        onDestroy: [Object],
        afterDestroy: [Object] },
     getPreferences: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-803' },
     runMatchMakerFramework: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-804' },
     getSolutions: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-805' },
     fireOnMatch: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-806' },
     onMatchHandler: { [Function: invokeInvoker] '$$fluid_guid': '9wrq5kv4-807' },
     handle: [Function: invokeInvoker],
     getActiveSessionTokens: [Function: invokeInvoker],
     withSession: [Function: invokeInvoker],
     onMatch: [Function: invokeInvoker] } }
debug: websocket writing 5::/update:{"name":"error","args":[{"isError":true,"message":"Error handling request which required active session, but none was active"}]}
20:21:43.436:  Test case listener has not responded after 5000ms - at sequence pos 8 of 19 sequence element {
    "event": "{updateRequest}.events.onComplete",
    "listener": "gpii.tests.flowManager.update.testFirstUpdateRequest"
} of fixture Flow Manager update tests