Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

save fired repeatedly in a loop #60

Closed
sameer-convergentappworks opened this issue Feb 5, 2016 · 5 comments
Closed

save fired repeatedly in a loop #60

sameer-convergentappworks opened this issue Feb 5, 2016 · 5 comments

Comments

@sameer-convergentappworks
Copy link

Hello guys,

I have a basic view builder like below

module.exports = require('cqrs-eventdenormalizer').defineViewBuilder({
  name: 'detailsUpdated',
  id: 'payload.id',
  context:'workflowContext',
  aggregate:'approval'
}, function(data, vm) {
    vm.set(data);
    debug('saving detailsUpdated', JSON.stringify(data, null, '\t'));
});

The debug statement is fired repeatedly on the console with the time (in ms) it takes for action.
It seems to be re-saving the document repeatedly in a loop. The issue is quite intermittent.

I have to kill the process to stop it from looping.

// log output on console
mymodule saving detailsUpdated +390ms { // JSON I removed }
mymodule saving detailsUpdated +827ms { // JSON I removed }
mymodule saving detailsUpdated +252ms { // JSON I removed }

....
...

I need to fix the issue before the product go-live. Please help.
@adrai
Copy link
Contributor

adrai commented Feb 5, 2016

I think this has nothing to do with eventstore...
but, without knowing how this is set up, I can't really help you. :-(

@sameer-convergentappworks
Copy link
Author

Possibly. I am using Mongo for store.

After few trials, looks like it could be due to the JSON with empty arrays or nested object with array.
Will keep you posted..

@sameer-convergentappworks
Copy link
Author

Sorry for not giving you a proper test for reproducing, but I think this seems to fix the issue.

For arrays properties I have to check if they exist and have elements
for other properties

if (data.peps !== undefined && data.peps.length > 0) {
     vm.set("peps", data.peps);
}

and because I pick out array properties for setting I have to repeat the following for other non array properties.

if (data.existingClient !== undefined) {
     vm.set("existingClient", data.existingClient);
}

Need to dig deep in code for vm.set for Mongo store.

@sameer-convergentappworks
Copy link
Author

hi adrai,

I have got better logs now. I use mongo store.
The logs show error in loop. I have to kill the process to stop. Does it help ?

  myprojectname.eventDenormalizer eventDenormalizer -- denormalize event  +121ms {
        "event": "detailsUpdated",
        "payload": {
                "_id": "56b84db219adf8c8224f5952",
                "id": "56b84db219adf8c8224f5952",
                "peps": [],
                "createdBy": {
                        "userid": "..removed..",
                        "id": "54dbab9f5cc06d449ca25cc6",
                        "name": "..removed.."
                },
                "tempTicketId": "cikdp9eq0001b64kgrti6hiak",
                "status": "draft",
                "auditTrail": [
                        {
                                "state": "draft",
                                "changedBy": {
                                        "userid": "..removed..",
                                        "id": "54dbab9f5cc06d449ca25cc6",
                                        "name": "..removed.."
                                },
                                "timeChanged": "2016-02-08T08:11:30.223Z"
                        }
                ],
                "commitStamp": 1454919090224,
                "_hash": "56b84db2cd9b7b6c2ec4c56a"
        },
        "head": {
                "revision": 4
        },
        "commandId": "msg1",
        "aggregate": {
                "name": "..removed..
        },
        "id": "d78966fa-39aa-46f0-88cb-4c8b4ea63510"
}
  denormalizer:revisionGuard no revision in store => retry [concatenatedId]=approval56b84db219adf8c8224f5952, [revInStore]=null, [revInEvt]=4 +4s
  denormalizer:revisionGuard no revision in store => retry [concatenatedId]=approval56b84db219adf8c8224f5952, [revInStore]=null, [revInEvt]=4 +723ms
  denormalizer:revisionGuard no revision in store => retry [concatenatedId]=approval56b84db219adf8c8224f5952, [revInStore]=null, [revInEvt]=4 +324ms
  denormalizer:revisionGuard finished loops for retry => proceed [concatenatedId]=approval56b84db219adf8c8224f5952, [revInStore]=null, [revInEvt]=4 +699ms
  denormalizer:revisionGuard first revision to store [concatenatedId]=approval56b84db219adf8c8224f5952, [revInStore]=null, [revInEvt]=4 +3ms
  denormalizer:eventDispatcher no version found, handling as version: 0 +4ms
  denormalizer:eventDispatcher no context found +2ms
  denormalizer:viewBuilder [detailsUpdated] found viewmodel id in event +8ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 call denormalizer function +15ms
  myprojectname.viewBuilder saving detailsUpdated +3s {
        "_id": "56b84db219adf8c8224f5952",
        "id": "56b84db219adf8c8224f5952",
        "peps": [],
        "createdBy": {
                "userid": "..removed..",
                "id": "54dbab9f5cc06d449ca25cc6",
                "name": "..removed.."
        },
        "tempTicketId": "cikdp9eq0001b64kgrti6hiak",
        "status": "draft",
        "auditTrail": [
                {
                        "state": "draft",
                        "changedBy": {
                                "userid": "..removed..",
                                "id": "54dbab9f5cc06d449ca25cc6",
                                "name": "..removed.."
                        },
                        "timeChanged": "2016-02-08T08:11:30.223Z"
                }
        ],
        "commitStamp": 1454919090224,
        "_hash": "56b84db2cd9b7b6c2ec4c56a"
}
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 generate new id for notification +20ms
  denormalizer:viewBuilder ConcurrencyError
    at C:\Temp\myprojectpath\node_modules\cqrs-eventdenormalizer\node_modules\viewmodel\lib\databases\mongodb.js:213:31
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\utils.js:96:12
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\collection.js:987:5
    at C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:780:13
    at [object Object].emit (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:95:3)
    at [object Object].messageHandler (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:249:23)
    at Socket.<anonymous> (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\connection\connection.js:265:22)
    at Socket.emit (events.js:95:17)
    at Socket.<anonymous> (_stream_readable.js:764:14)
    at Socket.emit (events.js:92:17)
    at emitReadable_ (_stream_readable.js:426:10)
    at emitReadable (_stream_readable.js:422:5)
    at readableAddChunk (_stream_readable.js:165:9)
    at Socket.push (_stream_readable.js:127:10)
    at TCP.onread (net.js:528:21) +6ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 retry in 38ms +9ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 call denormalizer function +46ms
  myprojectname.viewBuilder saving detailsUpdated +78ms {
        "_id": "56b84db219adf8c8224f5952",
        "id": "56b84db219adf8c8224f5952",
        "peps": [],
        "createdBy": {
                "userid": "..removed..",
                "id": "54dbab9f5cc06d449ca25cc6",
                "name": "..removed.."
        },
        "tempTicketId": "cikdp9eq0001b64kgrti6hiak",
        "status": "draft",
        "auditTrail": [
                {
                        "state": "draft",
                        "changedBy": {
                                "userid": "..removed..",
                                "id": "54dbab9f5cc06d449ca25cc6",
                                "name": "..removed.."
                        },
                        "timeChanged": "2016-02-08T08:11:30.223Z"
                }
        ],
        "commitStamp": 1454919090224,
        "_hash": "56b84db2cd9b7b6c2ec4c56a"
}
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 generate new id for notification +10ms
  denormalizer:viewBuilder ConcurrencyError
    at C:\Temp\myprojectpath\node_modules\cqrs-eventdenormalizer\node_modules\viewmodel\lib\databases\mongodb.js:213:31
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\utils.js:96:12
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\collection.js:987:5
    at C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:780:13
    at [object Object].emit (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:95:3)
    at [object Object].messageHandler (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:249:23)
    at Socket.<anonymous> (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\connection\connection.js:265:22)
    at Socket.emit (events.js:95:17)
    at Socket.<anonymous> (_stream_readable.js:764:14)
    at Socket.emit (events.js:92:17)
    at emitReadable_ (_stream_readable.js:426:10)
    at emitReadable (_stream_readable.js:422:5)
    at readableAddChunk (_stream_readable.js:165:9)
    at Socket.push (_stream_readable.js:127:10)
    at TCP.onread (net.js:528:21) +2ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 retry in 159ms +7ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 call denormalizer function +166ms
  myprojectname.viewBuilder saving detailsUpdated +185ms {
        "_id": "56b84db219adf8c8224f5952",
        "id": "56b84db219adf8c8224f5952",
        "peps": [],
        "createdBy": {
                "userid": "..removed..",
                "id": "54dbab9f5cc06d449ca25cc6",
                "name": "..removed.."
        },
        "tempTicketId": "cikdp9eq0001b64kgrti6hiak",
        "status": "draft",
        "auditTrail": [
                {
                        "state": "draft",
                        "changedBy": {
                                "userid": "..removed..",
                                "id": "54dbab9f5cc06d449ca25cc6",
                                "name": "..removed.."
                        },
                        "timeChanged": "2016-02-08T08:11:30.223Z"
                }
        ],
        "commitStamp": 1454919090224,
        "_hash": "56b84db2cd9b7b6c2ec4c56a"
}
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 generate new id for notification +11ms
  denormalizer:viewBuilder ConcurrencyError
    at C:\Temp\myprojectpath\node_modules\cqrs-eventdenormalizer\node_modules\viewmodel\lib\databases\mongodb.js:213:31
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\utils.js:96:12
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\collection.js:987:5
    at C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:780:13
    at [object Object].emit (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:95:3)
    at [object Object].messageHandler (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:249:23)
    at Socket.<anonymous> (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\connection\connection.js:265:22)
    at Socket.emit (events.js:95:17)
    at Socket.<anonymous> (_stream_readable.js:764:14)
    at Socket.emit (events.js:92:17)
    at emitReadable_ (_stream_readable.js:426:10)
    at emitReadable (_stream_readable.js:422:5)
    at readableAddChunk (_stream_readable.js:165:9)
    at Socket.push (_stream_readable.js:127:10)
    at TCP.onread (net.js:528:21) +1ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 retry in 583ms +6ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 call denormalizer function +590ms
  myprojectname.viewBuilder saving detailsUpdated +610ms {
        "_id": "56b84db219adf8c8224f5952",
        "id": "56b84db219adf8c8224f5952",
        "peps": [],
        "createdBy": {
                "userid": "..removed..",
                "id": "54dbab9f5cc06d449ca25cc6",
                "name": "..removed.."
        },
        "tempTicketId": "cikdp9eq0001b64kgrti6hiak",
        "status": "draft",
        "auditTrail": [
                {
                        "state": "draft",
                        "changedBy": {
                                "userid": "..removed..",
                                "id": "54dbab9f5cc06d449ca25cc6",
                                "name": "..removed.."
                        },
                        "timeChanged": "2016-02-08T08:11:30.223Z"
                }
        ],
        "commitStamp": 1454919090224,
        "_hash": "56b84db2cd9b7b6c2ec4c56a"
}
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 generate new id for notification +25ms
  denormalizer:viewBuilder ConcurrencyError
    at C:\Temp\myprojectpath\node_modules\cqrs-eventdenormalizer\node_modules\viewmodel\lib\databases\mongodb.js:213:31
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\utils.js:96:12
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\collection.js:987:5
    at C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:780:13
    at [object Object].emit (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:95:3)
    at [object Object].messageHandler (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:249:23)
    at Socket.<anonymous> (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\connection\connection.js:265:22)
    at Socket.emit (events.js:95:17)
    at Socket.<anonymous> (_stream_readable.js:764:14)
    at Socket.emit (events.js:92:17)
    at emitReadable_ (_stream_readable.js:426:10)
    at emitReadable (_stream_readable.js:422:5)
    at readableAddChunk (_stream_readable.js:165:9)
    at Socket.push (_stream_readable.js:127:10)
    at TCP.onread (net.js:528:21) +2ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 retry in 391ms +10ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 call denormalizer function +399ms
  myprojectname.viewBuilder saving detailsUpdated +439ms {
        "_id": "56b84db219adf8c8224f5952",
        "id": "56b84db219adf8c8224f5952",
        "peps": [],
        "createdBy": {
                "userid": "..removed..",
                "id": "54dbab9f5cc06d449ca25cc6",
                "name": "..removed.."
        },
        "tempTicketId": "cikdp9eq0001b64kgrti6hiak",
        "status": "draft",
        "auditTrail": [
                {
                        "state": "draft",
                        "changedBy": {
                                "userid": "..removed..",
                                "id": "54dbab9f5cc06d449ca25cc6",
                                "name": "..removed.."
                        },
                        "timeChanged": "2016-02-08T08:11:30.223Z"
                }
        ],
        "commitStamp": 1454919090224,
        "_hash": "56b84db2cd9b7b6c2ec4c56a"
}
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 generate new id for notification +29ms
  denormalizer:viewBuilder ConcurrencyError
    at C:\Temp\myprojectpath\node_modules\cqrs-eventdenormalizer\node_modules\viewmodel\lib\databases\mongodb.js:213:31
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\utils.js:96:12
    at C:\Temp\myprojectpath\node_modules\mongodb\lib\collection.js:987:5
    at C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:780:13
    at [object Object].emit (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:95:3)
    at [object Object].messageHandler (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\topologies\server.js:249:23)
    at Socket.<anonymous> (C:\Temp\myprojectpath\node_modules\mongodb\node_modules\mongodb-core\lib\connection\connection.js:265:22)
    at Socket.emit (events.js:95:17)
    at Socket.<anonymous> (_stream_readable.js:764:14)
    at Socket.emit (events.js:92:17)
    at emitReadable_ (_stream_readable.js:426:10)
    at emitReadable (_stream_readable.js:422:5)
    at readableAddChunk (_stream_readable.js:165:9)
    at Socket.push (_stream_readable.js:127:10)
    at TCP.onread (net.js:528:21) +4ms
  denormalizer:viewBuilder [detailsUpdated], [eventId]=d78966fa-39aa-46f0-88cb-4c8b4ea63510 retry in 741ms +11ms

@sameer-convergentappworks
Copy link
Author

Not an issue. closing.

This was happening on the page where a command was fired twice. I wasn't pulling the latest state before the second command was fired. So _hash value used for second request was stale.
As a result the framework raised concurrency error which is correct.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@adrai @sameer-convergentappworks