test_integration fails. It seems dereference messages are not triggered as expected.
Especially, serverA does not garbage collect stubs to the echo callback and objB.inner.
One time in debugging, it runs successfully, below is the log from the successful run. In this successful run, all the stubs get garbage collected.
Pan-MacBookPro:nodermi pan$ node --debug-brk --expose-gc test/test_integration.js
debugger listening on port 5858
nodermi:socket listening on localhost:7000 +0ms
nodermi:socket listening on localhost:8000 +1ms
nodermi:socket listening on localhost:9000 +1ms
nodermi:socket connection established to localhost:7000 +2ms
nodermi:socket send 21 bytes +1ms
nodermi:socket connection established to localhost:7000 +0ms
nodermi:socket send 21 bytes +1ms
nodermi:server localhost:7000 got request {"host":"localhost","port":8000,"type":2,"args":[],"objName":"obj","referenceEntries":[]} +1ms
nodermi:socket send 105 bytes +1ms
nodermi:server retrieveObj response :{"sessionId":"0","host":"localhost","port":7000,"type":6,"args":[],"referenceEntries":[],"object":{"id":"0","type":1,"properties":[{"name":"property1","objectValue":{"type":10,"properties":[],"stringVal":"a","arrayElements":[]}},{"name":"echo","objectValue":{"id":"1","type":4,"properties":[],"arrayElements":[]}},{"name":"setProperty","objectValue":{"id":"2","type":4,"properties":[],"arrayElements":[]}},{"name":"getProperty","objectValue":{"id":"3","type":4,"properties":[],"arrayElements":[]}}],"arrayElements":[]}} +1ms
nodermi:server localhost:7000 got request {"host":"localhost","port":9000,"type":2,"args":[],"objName":"obj","referenceEntries":[]} +0ms
nodermi:socket send 105 bytes +1ms
nodermi:socket send 39 bytes +0ms
nodermi:server retrieveObj response :{"sessionId":"1","host":"localhost","port":7000,"type":6,"args":[],"referenceEntries":[],"object":{"id":"0","type":1,"properties":[{"name":"property1","objectValue":{"type":10,"properties":[],"stringVal":"a","arrayElements":[]}},{"name":"echo","objectValue":{"id":"1","type":4,"properties":[],"arrayElements":[]}},{"name":"setProperty","objectValue":{"id":"2","type":4,"properties":[],"arrayElements":[]}},{"name":"getProperty","objectValue":{"id":"3","type":4,"properties":[],"arrayElements":[]}}],"arrayElements":[]}} +0ms
nodermi:server localhost:7000 got request {"sessionId":"0","host":"localhost","port":8000,"type":1,"functionId":"1","objId":"0","args":[{"type":10,"properties":[],"stringVal":"1","arrayElements":[]},{"id":"0","type":4,"properties":[],"arrayElements":[]}],"referenceEntries":[]} +1ms
nodermi:socket send 16 bytes +3m
nodermi:fd start to ping... +0ms
nodermi:fd Ping localhost:8000,last active time is 1434340373273 +1ms
nodermi:fd Ping localhost:9000,last active time is 1434340373271 +0ms
nodermi:fd ping localhost:8000 +0ms
nodermi:fd ping localhost:9000 +0ms
nodermi:fd start to ping... +0ms
nodermi:fd start to ping... +0ms
nodermi:fd start to ping... +1m
nodermi:fd Ping localhost:8000,last active time is 1434340373273 +0ms
nodermi:fd Ping localhost:9000,last active time is 1434340373271 +0ms
nodermi:fd ping localhost:8000 +0ms
nodermi:fd ping localhost:9000 +1ms
nodermi:fd start to ping... +0ms
nodermi:fd start to ping... +0ms
nodermi:socket connection established to localhost:8000 +1ms
nodermi:socket send 33 bytes +0ms
nodermi:socket connection established to localhost:8000 +0ms
nodermi:socket send 16 bytes +0ms
nodermi:socket connection established to localhost:9000 +0ms
nodermi:socket send 16 bytes +1ms
nodermi:server localhost:8000 got request {"sessionId":"2","host":"localhost","port":7000,"type":1,"functionId":"0","args":[{"type":2,"properties":[],"arrayElements":[]},{"type":10,"properties":[],"stringVal":"1","arrayElements":[]}],"referenceEntries":[]} +0ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:8000 got request {"host":"localhost","port":7000,"type":3,"args":[],"referenceEntries":[]} +1ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:9000 got request {"host":"localhost","port":7000,"type":3,"args":[],"referenceEntries":[]} +0ms
nodermi:socket send 16 bytes +0ms
testing dereference
nodermi:socket send 69 bytes +1ms
objB.inner id is 1
nodermi:server localhost:7000 got request {"sessionId":"1","host":"localhost","port":8000,"type":1,"functionId":"2","objId":"0","args":[{"type":10,"properties":[],"stringVal":"stubProp","arrayElements":[]},{"id":"1","type":1,"properties":[{"name":"func1","objectValue":{"id":"2","type":4,"properties":[],"arrayElements":[]}}],"arrayElements":[]},{"id":"3","type":4,"properties":[],"arrayElements":[]}],"referenceEntries":[]} +23s
nodermi:socket send 22 bytes +1ms
nodermi:socket send 16 bytes +0ms
nodermi:socket connection established to localhost:8000 +0ms
nodermi:socket send 16 bytes +1ms
nodermi:socket connection established to localhost:9000 +0ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:8000 got request {"sessionId":"3","host":"localhost","port":7000,"type":1,"functionId":"3","args":[],"referenceEntries":[]} +0ms
nodermi:socket send 46 bytes +0ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:8000 got request {"host":"localhost","port":7000,"type":3,"args":[],"referenceEntries":[]} +4s
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:9000 got request {"host":"localhost","port":7000,"type":3,"args":[],"referenceEntries":[]} +0ms
nodermi:socket send 16 bytes +1ms
nodermi:server localhost:7000 got request {"sessionId":"0","host":"localhost","port":9000,"type":1,"functionId":"3","objId":"0","args":[{"type":10,"properties":[],"stringVal":"stubProp","arrayElements":[]},{"id":"0","type":4,"properties":[],"arrayElements":[]}],"referenceEntries":[]} +0ms
nodermi:socket send 43 bytes +1ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:8000 got request {"host":"localhost","port":7000,"type":4,"args":[],"referenceEntries":[{"sessionId":"1","objectIds":["1","2"]}],"referenceClient":{"host":"localhost","port":9000}} +24s
nodermi:socket send 16 bytes +1ms
nodermi:socket send 83 bytes +0ms
nodermi:server localhost:9000 got request {"sessionId":"4","host":"localhost","port":7000,"type":1,"functionId":"0","args":[{"type":2,"properties":[],"arrayElements":[]},{"id":"1","host":"localhost","port":8000,"type":1,"properties":[{"name":"func1","objectValue":{"id":"2","host":"localhost","port":8000,"type":4,"properties":[],"sessionId":"1","arrayElements":[]}}],"sessionId":"1","arrayElements":[]}],"referenceEntries":[]} +0ms
nodermi:socket send 16 bytes +1ms
delete reference from objA 1@localhost:8000
after delete objA.stubProp undefined
nodermi:objRegistry cleanup stub localhost:8000_1_3 +12ms
nodermi:socket send 22 bytes +13s
nodermi:fd start to ping... +50ms
nodermi:fd start to ping... +0ms
nodermi:fd start to ping... +0ms
nodermi:server localhost:8000 got request {"sessionId":"1","host":"localhost","port":7000,"type":5,"objId":"3","args":[],"referenceEntries":[]} +0ms
nodermi:objRegistry Reference to [3] cleared, safe to remove from strong map. +0ms
nodermi:objRegistry after dereference 3 {} +0ms
nodermi:socket send 16 bytes +1ms
delete reference from objC
nodermi:objRegistry cleanup stub localhost:8000_1_2 +9s
nodermi:objRegistry cleanup stub localhost:8000_1_1 +0ms
nodermi:objRegistry cleanup stub localhost:9000_0_0 +1ms
nodermi:socket send 22 bytes +0ms
nodermi:objRegistry cleanup stub localhost:8000_1_1 +0ms
nodermi:socket send 22 bytes +0ms
nodermi:objRegistry cleanup stub localhost:8000_1_2 +0ms
nodermi:socket send 22 bytes +0ms
nodermi:server localhost:9000 got request {"sessionId":"0","host":"localhost","port":7000,"type":5,"objId":"0","args":[],"referenceEntries":[]} +6s
nodermi:objRegistry Reference to [0] cleared, safe to remove from strong map. +1ms
nodermi:objRegistry after dereference 0 {} +0ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:8000 got request {"sessionId":"1","host":"localhost","port":7000,"type":5,"objId":"1","args":[],"referenceEntries":[]} +0ms
nodermi:objRegistry after dereference 1 {"localhost:9000":["1"]} +0ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:8000 got request {"sessionId":"1","host":"localhost","port":7000,"type":5,"objId":"2","args":[],"referenceEntries":[]} +0ms
nodermi:objRegistry after dereference 2 {"localhost:9000":["1"]} +0ms
nodermi:socket send 16 bytes +1ms
nodermi:socket connection established to localhost:8000 +0ms
nodermi:socket send 22 bytes +0ms
nodermi:socket connection established to localhost:8000 +0ms
nodermi:socket send 22 bytes +0ms
nodermi:server localhost:8000 got request {"sessionId":"1","host":"localhost","port":9000,"type":5,"objId":"2","args":[],"referenceEntries":[]} +1ms
nodermi:objRegistry Reference to [2] cleared, safe to remove from strong map. +0ms
nodermi:objRegistry after dereference 2 {} +0ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:8000 got request {"sessionId":"1","host":"localhost","port":9000,"type":5,"objId":"1","args":[],"referenceEntries":[]} +0ms
nodermi:objRegistry Reference to [1] cleared, safe to remove from strong map. +0ms
nodermi:objRegistry after dereference 1 {} +0ms
nodermi:socket send 16 bytes +0ms
nodermi:fd start to ping... +53s
nodermi:fd Ping localhost:8000,last active time is 1434340640638 +0ms
nodermi:fd Ping localhost:9000,last active time is 1434340644200 +0ms
nodermi:fd ping localhost:8000 +0ms
nodermi:socket send 16 bytes +1ms
nodermi:fd ping localhost:9000 +0ms
nodermi:socket send 16 bytes +0ms
nodermi:fd start to ping... +0ms
nodermi:fd start to ping... +0ms
nodermi:server localhost:8000 got request {"host":"localhost","port":7000,"type":3,"args":[],"referenceEntries":[]} +0ms
nodermi:socket send 16 bytes +0ms
nodermi:server localhost:9000 got request {"host":"localhost","port":7000,"type":3,"args":[],"referenceEntries":[]} +1ms
nodermi:socket send 16 bytes +0ms
nodermi:socket remove socket localhost:8000 from socket pool. +0ms
nodermi:socket remove socket localhost:9000 from socket pool. +0ms
nodermi:socket remove socket localhost:7000 from socket pool. +1ms
nodermi:socket remove socket localhost:7000 from socket pool. +0ms
nodermi:socket remove socket localhost:8000 from socket pool. +0ms
nodermi:error:socket Error: EOF
at SocketWrapper.lodash.assign.endData (/Users/pan/git/nodermi/lib/socket_transport.js:274:36)
at Socket.emit (events.js:117:20)
at _stream_readable.js:943:16
at process._tickCallback (node.js:419:13) +0ms
nodermi:error:socket Error: EOF
at SocketWrapper.lodash.assign.endData (/Users/pan/git/nodermi/lib/socket_transport.js:274:36)
at Socket.emit (events.js:117:20)
at _stream_readable.js:943:16
at process._tickCallback (node.js:419:13) +2ms
nodermi:error:socket Error: EOF
at SocketWrapper.lodash.assign.endData (/Users/pan/git/nodermi/lib/socket_transport.js:274:36)
at Socket.emit (events.js:117:20)
at _stream_readable.js:943:16
at process._tickCallback (node.js:419:13) +0ms
nodermi:error:socket Error: EOF
at SocketWrapper.lodash.assign.endData (/Users/pan/git/nodermi/lib/socket_transport.js:274:36)
at Socket.emit (events.js:117:20)
at _stream_readable.js:943:16
at process._tickCallback (node.js:419:13) +1ms
nodermi:error:socket Error: EOF
at SocketWrapper.lodash.assign.endData (/Users/pan/git/nodermi/lib/socket_transport.js:274:36)
at Socket.emit (events.js:117:20)
at _stream_readable.js:943:16
at process._tickCallback (node.js:419:13) +0ms