[WIP] FIX migrate MongoDB driver to 4.x #689

fgalan · 2022-06-21T10:53:30Z

check lost of log fields (correlator, etc.) in some log messages

fgalan · 2022-06-21T10:54:00Z

test/component/db_test.js

@@ -27,15 +27,19 @@ var should = require('should'),
    utilsT = require('../utils/utilsT'),
    db = require('../../lib/db');

-describe('Db', function() {
+xdescribe('Db', function() {


Disabled while https://stackoverflow.com/questions/72699235/mongodb-node-driver-connect-ignores-connecttimeoutms-and-sockettimeoutms-set gets clarified

Question was answered. Based on it, fixed in 5be543e

fgalan · 2022-06-21T12:10:12Z

It seems that log information is lost in some cases

Eg. rulesStore.Save:

Now (nok):

time=2022-06-21T11:48:37.285Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=rulesStore.Save "{"acknowledged":true,"insertedId":"62b1b015e5c73b549bb684f0"}"

In master (ok)

time=2022-06-21T11:48:23.903Z | lvl=INFO | corr=b994265e-8e22-40de-9a9c-70822a9ab136; node=iswEc9mAeN; perseocep=0 | trans=b994265e-8e22-40de-9a9c-70822a9ab136 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=rulesStore.Save "{"result":{"n":1,"ok":1},"connection":{"id":4,"host":"localhost","port":27017},"ops":[{"name":"Blood","text":"select *,\"Bloo [...]"

fgalan · 2022-06-24T07:49:15Z

At the present moment, only some tests in the test/metrics/metrics_action_test.js are failling

  1) should increment successful sms
  2) should increment error for failed sms
  3) should increment a successful action for update
  4) should increment a failed for update
  5) should increment successful post
  6) should increment error for failed post

I have analysed more in detail one of them, "'should increment successful sms" case (probably the finding in this analysis apply to other cases).

The problem is that the following asserting fails:

should.equal(m.services.unknownt.sum.outgoingTransactions, 1);

I have diged into the code and find the problem is in this part of the code in lib/myutils.js:

function requestHelperAux(method, options, withMetrics, callback) {
    var localError,
        respObj,
        headers,
        domain = process.domain;
    logger.info('making %s to %s', method, options.url);
    if (withMetrics && domain.context) {
        metrics.IncMetrics(domain.context.srv, domain.context.subsrv, metrics.outgoingTransactions);
    }
    ...

The test is failing because the statement

metrics.IncMetrics(domain.context.srv, domain.context.subsrv, metrics.outgoingTransactions);

is not being executed. This is due the condition in the if clause (withMetrics && domain.context) is false due to domain.context is undefined (in can be easily checked using console.log just before the if clause).

Thus, why process.domain is undefined in this case? I'm not familiar with the domain concept in Node.js, but it seems to be something independent from mongodb driver operation.

Some additional things to take into account:

Maybe the domainsEnabled setting is related with this issue? It has been removed in 4.x. I have posted this at SOF: https://stackoverflow.com/questions/72736719/domainsenabled-client-option-removed-in-node-mongodb-driver-4-0?noredirect=1#comment128476800_72736719
Domains are not yet deprecated in Node.js. They are in "pending deprecation" which is a different status. See https://stackoverflow.com/questions/49494211/replacement-for-domain-in-nodejs
Maybe this problem with domains is also the cause of the logs problem described in a previou comment as the logging context is typically set using context = process.domain && process.domain.context.

fgalan · 2022-06-24T08:54:31Z

Full log, in debug level:

> [email protected] test:my2
> mocha --recursive 'test/component/metrics/metrics_actions_test.js' --reporter spec --timeout 5000 --ui bdd --exit --color true



  Metrics
    #PostAction()
      - should count fired valid actions
(node:46287) [MONGODB DRIVER] Warning: collection.remove is deprecated. Use deleteOne, deleteMany, or bulkWrite instead.
(Use `node --trace-warnings ...` to show where the warning was created)
time=2022-06-24T08:53:27.848Z | lvl=INFO | corr=n/a | trans=n/a | op=start | comp=perseo-fe | msg=starting perseo
time=2022-06-24T08:53:27.848Z | lvl=DEBUG | corr=n/a | trans=n/a | op=start | comp=perseo-fe | msg=Using config:

{
    "logLevel": "debug",
    "endpoint": {
        "host": "localhost",
        "port": 9182,
        "rulesPath": "/rules",
        "actionsPath": "/actions/do",
        "noticesPath": "/notices",
        "vrPath": "/m2m/vrules",
        "checkPath": "/check",
        "versionPath": "/version",
        "logPath": "/admin/log",
        "metricsPath": "/admin/metrics"
    },
    "isMaster": true,
    "slaveDelay": 500,
    "mongo": {
        "url": "mongodb://localhost:27017/perseo_testing",
        "connectTimeoutMS": 30000
    },
    "orionDb": {
        "url": "mongodb://localhost:27017/test",
        "collection": "entities",
        "prefix": "oriontest",
        "batchSize": 500
    },
    "perseoCore": {
        "rulesURL": "http://localhost:9753",
        "noticesURL": "http://localhost:9753",
        "interval": 600000
    },
    "nextCore": {},
    "smtp": {
        "port": 25,
        "host": "smtpserver",
        "secure": false,
        "tls": {
            "rejectUnauthorized": false
        }
    },
    "sms": {
        "URL": "http://localhost:9753",
        "API_KEY": "",
        "API_SECRET": "",
        "from": "tel:22012;phone-context=+34"
    },
    "smpp": {
        "host": "",
        "port": "",
        "systemid": "",
        "password": "",
        "from": "346666666",
        "enabled": false
    },
    "orion": {
        "URL": "http://orion-endpoint:1026"
    },
    "pep": {
        "URL": "http://pep-endpoint:1026"
    },
    "authentication": {
        "host": "keystone",
        "port": "5001",
        "user": "user",
        "password": "password",
        "service": "admin_domain"
    },
    "collections": {
        "rules": "rules",
        "executions": "executions"
    },
    "executionsTTL": 86400,
    "DEFAULT_SUBSERVICE": "/",
    "DEFAULT_SERVICE": "unknownt",
    "checkDB": {
        "delay": 5000,
        "reconnectTries": 1000,
        "reconnectInterval": 5000,
        "bufferMaxEntries": 5
    },
    "restBase": null,
    "castTypes": false,
    "maxRulesByCorr": 20
}

time=2022-06-24T08:53:27.992Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=rulesStore.FindAll []
time=2022-06-24T08:53:27.992Z | lvl=DEBUG | corr=n/a | trans=n/a | op=checkNonSignal | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=Refreshing all no-signal rules
time=2022-06-24T08:53:27.993Z | lvl=DEBUG | corr=n/a | trans=n/a | op=checkNonSignal | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=no-signal rules 0/0, checkers: 0
time=2022-06-24T08:53:27.993Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=putR2core using rulesAndContexts: []
time=2022-06-24T08:53:27.993Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=making put to http://localhost:9753
time=2022-06-24T08:53:28.019Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=put to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:53:28.020Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=done put to http://localhost:9753
time=2022-06-24T08:53:28.021Z | lvl=INFO | corr=n/a | trans=n/a | op=start | comp=perseo-fe | msg=listening on port 9182
time=2022-06-24T08:53:28.061Z | lvl=INFO | corr=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77; node=kSFpwfTiv0; perseocep=0 | trans=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=incoming request {"method":"POST","url":"/rules","headers":{"fiware-service":"unknownt","fiware-servicepath":"/","host":"localhost:9182","accept":"application/json","content-type":"application/json","content-length":"315","connection":"close"},"body":{"name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]","action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"}}},"subservice":"/","service":"unknownt"}
time=2022-06-24T08:53:28.063Z | lvl=INFO | corr=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77; node=kSFpwfTiv0; perseocep=0 | trans=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=posting rule {"name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]","action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"}},"subservice":"/","service":"unknownt"}
time=2022-06-24T08:53:28.063Z | lvl=DEBUG | corr=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77; node=kSFpwfTiv0; perseocep=0 | trans=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=validRule() - Default else clause
time=2022-06-24T08:53:28.085Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=Post2core using context {"name":"ctxt$unknownt$","text":"create context ctxt$unknownt$ partition by service from iotEvent(service=\"unknownt\" and subservice=\"/\")"} eplRule {"name":"Blood@unknownt/","text":"context ctxt$unknownt$ select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]"}
time=2022-06-24T08:53:28.086Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=making post to http://localhost:9753
time=2022-06-24T08:53:28.093Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=post to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:53:28.094Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=done post to http://localhost:9753
time=2022-06-24T08:53:28.094Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=making post to http://localhost:9753
time=2022-06-24T08:53:28.100Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=post to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:53:28.101Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=done post to http://localhost:9753
time=2022-06-24T08:53:28.122Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=rulesStore.Save "{\"acknowledged\":true,\"insertedId\":\"62b57b88a13649915e0abc46\"}"
time=2022-06-24T08:53:28.122Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=sending response: 200 {"error":null,"data":[false,[{"code":200,"body":"All right again!"},{"code":200,"body":"All right again!"},null],{"acknowledged":true,"insertedId":"62b57b88a13649915e0abc46"},null]}
time=2022-06-24T08:53:28.127Z | lvl=DEBUG | corr=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77; node=kSFpwfTiv0; perseocep=0 | trans=c5dc53d0-e514-4d40-aa8e-2b48cc99cf77 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=response-time: 94 statusCode: 200
time=2022-06-24T08:53:28.149Z | lvl=INFO | corr=a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1 | trans=a1991e1d-9175-4a93-9525-79ce4311d31a | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=incoming request {"method":"POST","url":"/actions/do","headers":{"fiware-service":"unknownt","fiware-servicepath":"/","host":"localhost:9182","accept":"application/json","content-type":"application/json","content-length":"431","connection":"close"},"body":{"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood"},"subservice":"/","service":"unknownt"}
time=2022-06-24T08:53:28.150Z | lvl=DEBUG | corr=a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1 | trans=a1991e1d-9175-4a93-9525-79ce4311d31a | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=Post action
time=2022-06-24T08:53:28.154Z | lvl=DEBUG | corr=a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1 | trans=a1991e1d-9175-4a93-9525-79ce4311d31a | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=response-time: 5 statusCode: 200
time=2022-06-24T08:53:28.154Z | lvl=DEBUG | corr=a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1 | trans=a1991e1d-9175-4a93-9525-79ce4311d31a | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=service unknownt, subservice /, event {"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"a1991e1d-9175-4a93-9525-79ce4311d31a","corr":"a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"}
time=2022-06-24T08:53:28.155Z | lvl=DEBUG | corr=a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1 | trans=a1991e1d-9175-4a93-9525-79ce4311d31a | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=response-time: 7
time=2022-06-24T08:53:28.179Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=rulesStore.Find {"_id":"62b57b88a13649915e0abc46","name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? [...]
time=2022-06-24T08:53:28.181Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=inserting in queue action {"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"},"index":0}
time=2022-06-24T08:53:28.182Z | lvl=DEBUG | corr=a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1 | trans=a1991e1d-9175-4a93-9525-79ce4311d31a | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=executing axn task {"action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"},"index":0},"event":{"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"a1991e1d-9175-4a93-9525-79ce4311d31a","corr":"a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"},"context":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"a1991e1d-9175-4a93-9525-79ce4311d31a","corr":"a1991e1d-9175-4a93-9525-79ce4311d31a; node=kSFpwfTiv0; perseocep=1","srv":"unknownt","subsrv":"/"}}
time=2022-06-24T08:53:28.203Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=making post to http://localhost:9753
time=2022-06-24T08:53:28.207Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=post to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:53:28.207Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=done post to http://localhost:9753
time=2022-06-24T08:53:28.210Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=smsAction.SendSMS done url:http://localhost:9753 result:{"code":200,"body":"All right again!"}, msg: {"to":["tel:123456789"],"message":"Meter null has pression null.","from":"tel:22012;phone-context=+34"}
      1) should increment successful sms
(node:46287) [MONGODB DRIVER] Warning: collection.update is deprecated. Use updateOne, updateMany, or bulkWrite instead.
time=2022-06-24T08:53:28.237Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=executionsStore.Update {"acknowledged":true,"modifiedCount":0,"upsertedId":"62b57b88c7cd76094fd60a4b","upsertedCount":1,"matchedCount":0}
time=2022-06-24T08:53:28.300Z | lvl=INFO | corr=n/a | trans=n/a | op=stop | comp=perseo-fe | msg=stopping perseo
      - should increment error for failed sms
      - should increment a successful action for update
      - should increment a failed for update
      - should increment successful post
      - should increment error for failed post
      - should increment error for failed email


  0 passing (681ms)
  7 pending
  1 failing

  1) Metrics
       #PostAction()
         should increment successful sms:

      Uncaught AssertionError: expected 0 == 1
      + expected - actual

      -0
      +1
      
      at Timeout._onTimeout (test/component/metrics/metrics_actions_test.js:104:40)
      at listOnTimeout (node:internal/timers:559:17)
      at processTimers (node:internal/timers:502:7)

fgalan · 2022-06-24T08:57:18Z

Same test log in master (ok case):

> [email protected] test:my2
> mocha --recursive 'test/component/metrics/metrics_actions_test.js' --reporter spec --timeout 5000 --ui bdd --exit --color true



  Metrics
    #PostAction()
      - should count fired valid actions
(node:46465) [MONGODB DRIVER] Warning: Current Server Discovery and Monitoring engine is deprecated, and will be removed in a future version. To use the new Server Discover and Monitoring engine, pass option { useUnifiedTopology: true } to the MongoClient constructor.
(Use `node --trace-warnings ...` to show where the warning was created)
(node:46465) DeprecationWarning: collection.remove is deprecated. Use deleteOne, deleteMany, or bulkWrite instead.
time=2022-06-24T08:56:42.104Z | lvl=INFO | corr=n/a | trans=n/a | op=start | comp=perseo-fe | msg=starting perseo
time=2022-06-24T08:56:42.105Z | lvl=DEBUG | corr=n/a | trans=n/a | op=start | comp=perseo-fe | msg=Using config:

{
    "logLevel": "debug",
    "endpoint": {
        "host": "localhost",
        "port": 9182,
        "rulesPath": "/rules",
        "actionsPath": "/actions/do",
        "noticesPath": "/notices",
        "vrPath": "/m2m/vrules",
        "checkPath": "/check",
        "versionPath": "/version",
        "logPath": "/admin/log",
        "metricsPath": "/admin/metrics"
    },
    "isMaster": true,
    "slaveDelay": 500,
    "mongo": {
        "url": "mongodb://localhost:27017/perseo_testing"
    },
    "orionDb": {
        "url": "mongodb://localhost:27017/test",
        "collection": "entities",
        "prefix": "oriontest",
        "batchSize": 500
    },
    "perseoCore": {
        "rulesURL": "http://localhost:9753",
        "noticesURL": "http://localhost:9753",
        "interval": 600000
    },
    "nextCore": {},
    "smtp": {
        "port": 25,
        "host": "smtpserver",
        "secure": false,
        "tls": {
            "rejectUnauthorized": false
        }
    },
    "sms": {
        "URL": "http://localhost:9753",
        "API_KEY": "",
        "API_SECRET": "",
        "from": "tel:22012;phone-context=+34"
    },
    "smpp": {
        "host": "",
        "port": "",
        "systemid": "",
        "password": "",
        "from": "346666666",
        "enabled": false
    },
    "orion": {
        "URL": "http://orion-endpoint:1026"
    },
    "pep": {
        "URL": "http://pep-endpoint:1026"
    },
    "authentication": {
        "host": "keystone",
        "port": "5001",
        "user": "user",
        "password": "password",
        "service": "admin_domain"
    },
    "collections": {
        "rules": "rules",
        "executions": "executions"
    },
    "executionsTTL": 86400,
    "DEFAULT_SUBSERVICE": "/",
    "DEFAULT_SERVICE": "unknownt",
    "checkDB": {
        "delay": 5000,
        "reconnectTries": 1000,
        "reconnectInterval": 5000,
        "bufferMaxEntries": 5
    },
    "restBase": null,
    "castTypes": false,
    "maxRulesByCorr": 20
}

(node:46465) [MONGODB DRIVER] DeprecationWarning: Db.collection option [strict] is deprecated and will be removed in a later version.
time=2022-06-24T08:56:42.307Z | lvl=INFO | corr=n/a | trans=n/a | op=initialRefresh | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=rulesStore.FindAll []
time=2022-06-24T08:56:42.311Z | lvl=DEBUG | corr=n/a | trans=n/a | op=checkNonSignal | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=Refreshing all no-signal rules
time=2022-06-24T08:56:42.312Z | lvl=DEBUG | corr=n/a | trans=n/a | op=checkNonSignal | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=no-signal rules 0/0, checkers: 0
time=2022-06-24T08:56:42.313Z | lvl=DEBUG | corr=n/a | trans=n/a | op=initialRefresh | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=putR2core using rulesAndContexts: []
time=2022-06-24T08:56:42.313Z | lvl=INFO | corr=n/a | trans=n/a | op=initialRefresh | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=making put to http://localhost:9753
time=2022-06-24T08:56:42.375Z | lvl=DEBUG | corr=n/a | trans=n/a | op=initialRefresh | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=put to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:56:42.375Z | lvl=INFO | corr=n/a | trans=n/a | op=initialRefresh | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=done put to http://localhost:9753
time=2022-06-24T08:56:42.376Z | lvl=INFO | corr=n/a | trans=n/a | op=start | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=listening on port 9182
time=2022-06-24T08:56:42.402Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=incoming request {"method":"POST","url":"/rules","headers":{"fiware-service":"unknownt","fiware-servicepath":"/","host":"localhost:9182","accept":"application/json","content-type":"application/json","content-length":"315","connection":"close"},"body":{"name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]","action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"}}},"subservice":"/","service":"unknownt"}
time=2022-06-24T08:56:42.403Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=posting rule {"name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]","action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"}},"subservice":"/","service":"unknownt"}
time=2022-06-24T08:56:42.403Z | lvl=DEBUG | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=validRule() - Default else clause
time=2022-06-24T08:56:42.413Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=Post2core using context {"name":"ctxt$unknownt$","text":"create context ctxt$unknownt$ partition by service from iotEvent(service=\"unknownt\" and subservice=\"/\")"} eplRule {"name":"Blood@unknownt/","text":"context ctxt$unknownt$ select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]"}
time=2022-06-24T08:56:42.413Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=making post to http://localhost:9753
time=2022-06-24T08:56:42.419Z | lvl=DEBUG | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=post to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:56:42.420Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=done post to http://localhost:9753
time=2022-06-24T08:56:42.420Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=making post to http://localhost:9753
time=2022-06-24T08:56:42.427Z | lvl=DEBUG | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=post to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:56:42.428Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=done post to http://localhost:9753
(node:46465) DeprecationWarning: collection.save is deprecated. Use insertOne, insertMany, updateOne, or updateMany instead.
time=2022-06-24T08:56:42.435Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=rulesStore.Save "{\"result\":{\"n\":1,\"ok\":1},\"connection\":{\"id\":4,\"host\":\"localhost\",\"port\":27017},\"ops\":[{\"name\":\"Blood\",\"text\":\"select *,\\\"Bloo [...]"
time=2022-06-24T08:56:42.435Z | lvl=INFO | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=sending response: 200 {"error":null,"data":[false,[{"code":200,"body":"All right again!"},{"code":200,"body":"All right again!"},null],{"result":{"n":1,"ok":1},"connection":{"id":4,"host":"localhost","port":27017},"ops":[{"name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]","action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"}},"subservice":"/","service":"unknownt","_id":"62b57c4a88ad89b581f6fd28"}],"n":1,"ok":1},null]}
time=2022-06-24T08:56:42.437Z | lvl=DEBUG | corr=f219f72f-dfa1-4920-96e5-905c2b3b0d34; node=xFkoiSZ5kl; perseocep=0 | trans=f219f72f-dfa1-4920-96e5-905c2b3b0d34 | op=/rules | path=/rules | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=response-time: 50 statusCode: 200
time=2022-06-24T08:56:42.447Z | lvl=INFO | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=incoming request {"method":"POST","url":"/actions/do","headers":{"fiware-service":"unknownt","fiware-servicepath":"/","host":"localhost:9182","accept":"application/json","content-type":"application/json","content-length":"431","connection":"close"},"body":{"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood"},"subservice":"/","service":"unknownt"}
time=2022-06-24T08:56:42.447Z | lvl=DEBUG | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=Post action
time=2022-06-24T08:56:42.448Z | lvl=DEBUG | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | from=::ffff:127.0.0.1 | msg=response-time: 2 statusCode: 200
time=2022-06-24T08:56:42.450Z | lvl=DEBUG | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=service unknownt, subservice /, event {"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7","corr":"40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"}
time=2022-06-24T08:56:42.452Z | lvl=DEBUG | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=response-time: 6
time=2022-06-24T08:56:42.460Z | lvl=INFO | corr=n/a | trans=n/a | op=n/a | msg=rulesStore.Find {"_id":"62b57c4a88ad89b581f6fd28","name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? [...]
time=2022-06-24T08:56:42.461Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=inserting in queue action {"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"},"index":0}
time=2022-06-24T08:56:42.462Z | lvl=DEBUG | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=executing axn task {"action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"},"index":0},"event":{"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7","corr":"40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"},"context":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7","corr":"40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1","srv":"unknownt","subsrv":"/"}}
time=2022-06-24T08:56:42.471Z | lvl=INFO | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=making post to http://localhost:9753
time=2022-06-24T08:56:42.477Z | lvl=DEBUG | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=post to http://localhost:9753 returns {"code":200,"body":"All right again!"}
time=2022-06-24T08:56:42.477Z | lvl=INFO | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=done post to http://localhost:9753
time=2022-06-24T08:56:42.487Z | lvl=INFO | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=smsAction.SendSMS done url:http://localhost:9753 result:{"code":200,"body":"All right again!"}, msg: {"to":["tel:123456789"],"message":"Meter null has pression null.","from":"tel:22012;phone-context=+34"}
(node:46465) DeprecationWarning: collection.update is deprecated. Use updateOne, updateMany, or bulkWrite instead.
time=2022-06-24T08:56:42.497Z | lvl=INFO | corr=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7; node=xFkoiSZ5kl; perseocep=1 | trans=40f2a9a6-58b9-47f1-a9c4-60dd2ec77bb7 | op=/actions/do | path=/actions/do | comp=perseo-fe | srv=unknownt | subsrv=/ | msg=executionsStore.Update {"result":{"n":1,"upserted":[{"index":0,"_id":"62b57c4ac7cd76094fd60a79"}],"nModified":0,"ok":1},"connection":{"id":4,"host":"localhost","port":27017},"n":1,"upserted":[{"index":0,"_id":"62b57c4ac7cd76094fd60a79"}],"nModified":0,"ok":1}
      ✓ should increment successful sms (129ms)
time=2022-06-24T08:56:42.549Z | lvl=INFO | corr=n/a | trans=n/a | op=stop | comp=perseo-fe | srv=n/a | subsrv=n/a | msg=stopping perseo
      - should increment error for failed sms
      - should increment a successful action for update
      - should increment a failed for update
      - should increment successful post
      - should increment error for failed post
      - should increment error for failed email


  1 passing (549ms)
  7 pending

fgalan · 2022-06-24T09:03:32Z

After applying this filter to the output (to remove timestamps, etc.)

The differences are:

In master (ok):

...
rulesStore.Save "{\"result\":{\"n\":1,\"ok\":1},\"connection\":{\"id\":4,\"host\":\"localhost\",\"port\":27017},\"ops\":[{\"name\":\"Blood\",\"text\":\"select *,\\\"Bloo [...]"
sending response: 200 {"error":null,"data":[false,[{"code":200,"body":"All right again!"},{"code":200,"body":"All right again!"},null],{"result":{"n":1,"ok":1},"connection":{"id":4,"host":"localhost","port":27017},"ops":[{"name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? as Meter from pattern [every ev=iotEvent(cast(cast(BloodPressure?,String),float)>1.5 and type=\"BloodMeter\")]","action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"}},"subservice":"/","service":"unknownt","_id":"62b57c915acaacb5a99bbedb"}],"n":1,"ok":1},null]}
response-time: 52 statusCode: 200
...
response-time: 6 statusCode: 200
service unknownt, subservice /, event {"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"4b83ca78-ef14-4b9a-9817-d5a116ff30bf","corr":"4b83ca78-ef14-4b9a-9817-d5a116ff30bf; node=k015gUFR3F; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"}
response-time: 8
rulesStore.Find {"_id":"62b57c915acaacb5a99bbedb","name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? [...]
...
executing axn task {"action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"},"index":0},"event":{"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"4b83ca78-ef14-4b9a-9817-d5a116ff30bf","corr":"4b83ca78-ef14-4b9a-9817-d5a116ff30bf; node=k015gUFR3F; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"},"context":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"4b83ca78-ef14-4b9a-9817-d5a116ff30bf","corr":"4b83ca78-ef14-4b9a-9817-d5a116ff30bf; node=k015gUFR3F; perseocep=1","srv":"unknownt","subsrv":"/"}}
...
executionsStore.Update {"result":{"n":1,"upserted":[{"index":0,"_id":"62b57c91c7cd76094fd60a9f"}],"nModified":0,"ok":1},"connection":{"id":4,"host":"localhost","port":27017},"n":1,"upserted":[{"index":0,"_id":"62b57c91c7cd76094fd60a9f"}],"nModified":0,"ok":1}
...

In this PR brach (nok):

...
rulesStore.Save "{\"acknowledged\":true,\"insertedId\":\"62b57ca5d1455064ccde386c\"}"
sending response: 200 {"error":null,"data":[false,[{"code":200,"body":"All right again!"},{"code":200,"body":"All right again!"},null],{"acknowledged":true,"insertedId":"62b57ca5d1455064ccde386c"},null]}
response-time: 36 statusCode: 200
...
response-time: 3 statusCode: 200
service unknownt, subservice /, event {"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"46908b12-ccb1-4dda-b170-44d537868171","corr":"46908b12-ccb1-4dda-b170-44d537868171; node=XiSQzxmM4h; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"}
response-time: 6
rulesStore.Find {"_id":"62b57ca5d1455064ccde386c","name":"Blood","text":"select *,\"Blood\" as ruleName,ev.BloodPressure? as Pression, ev.id? [...]
...
executing axn task {"action":{"type":"sms","template":"Meter ${Meter} has pression ${Pression}.","parameters":{"to":"123456789"},"index":0},"event":{"ev":{"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false","service":"unknownt","subservice":"/"},"ruleName":"Blood","subservice":"/","service":"unknownt","fiwarePerseoContext":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"46908b12-ccb1-4dda-b170-44d537868171","corr":"46908b12-ccb1-4dda-b170-44d537868171; node=XiSQzxmM4h; perseocep=1","srv":"unknownt","subsrv":"/"},"id":"termotro1","device__asset__name":"DEVICE NAME","temperature__type":"celsius","noticeId":"92c56c80-23a7-11e4-a657-2559eb004467","measure":{"value":"MEASURE VALUE"},"TimeInstant":"2014-04-29T13:18:05Z","TimeInstant__type":"urn:x-ogc:def:trs:IDAS:1.0:ISO8601","received":"2014-08-14T11:38:55.688Z","type":"ModeloTemperatura","temperature":"6","isPattern":"false"},"context":{"path":"/actions/do","op":"/actions/do","comp":"perseo-fe","trans":"46908b12-ccb1-4dda-b170-44d537868171","corr":"46908b12-ccb1-4dda-b170-44d537868171; node=XiSQzxmM4h; perseocep=1","srv":"unknownt","subsrv":"/"}}
...
executionsStore.Update {"acknowledged":true,"modifiedCount":0,"upsertedId":"62b57ca5c7cd76094fd60aca","upsertedCount":1,"matchedCount":0}
...

AlvaroVega · 2022-06-27T10:24:07Z

mongo 4.7.0 subdependencies:

    "bson": "^4.6.3",
    "denque": "^2.0.1",
    "mongodb-connection-string-url": "^2.5.2",
    "saslprep": "^1.0.3",
    "socks": "^2.6.2"

mongo 3.6.12 subdependencies:

    "bl": "^2.2.1",
    "bson": "^1.1.4",
    "denque": "^1.4.1",
    "optional-require": "^1.0.3",
    "safe-buffer": "^5.1.2",
    "saslprep": "^1.0.0"

fgalan · 2022-08-09T12:47:17Z

lib/db.js

+            //db.serverConfig.on('reconnectFailed', function() {
+            //    logger.fatal('too many tries to reconnect to database, dying ...');
+            //    process.exit(-2);
+            //});


From https://stackoverflow.com/questions/72699235/mongodb-node-driver-connect-ignores-connecttimeoutms-and-sockettimeoutms-set/73214803#73214803

You are always considered "connected" by the driver and then under the hood it auto reconnects for you

So all the reconnection logic in our code can be just removed. The driver will do it for us.

FIX migrate MongoDB driver to 4.x

a4229ef

fgalan commented Jun 21, 2022

View reviewed changes

Merge branch 'master' into harderning/migrate-mongodb-to-4.x

5e7124e

fgalan added 3 commits June 23, 2022 16:20

FIX entitiesStore and rulesStore to work with mongodb 4.x driver

240428d

FIX collectionExists() to keep the strict mode from mongodb 3.x

c9da8ad

FIX lint

a81b211

Update metrics_actions_test.js

1a56718

AlvaroVega and others added 2 commits June 27, 2022 12:43

Update metrics_actions_test.js

c13b0b4

FIX use right connection timeout parameters with MongoDB 4.x

5be543e

fgalan commented Aug 9, 2022

View reviewed changes

Merge branch 'master' into harderning/migrate-mongodb-to-4.x

2dd1ad6

AlvaroVega added the P1 label Jul 7, 2023

AlvaroVega mentioned this pull request Jul 7, 2023

Upgrade mongo driver (from 3.6.X to 4.X) #732

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[WIP] FIX migrate MongoDB driver to 4.x #689

[WIP] FIX migrate MongoDB driver to 4.x #689

fgalan commented Jun 21, 2022 •

edited

Loading

fgalan Jun 21, 2022

fgalan Aug 9, 2022

fgalan commented Jun 21, 2022

fgalan commented Jun 24, 2022

fgalan commented Jun 24, 2022

fgalan commented Jun 24, 2022

fgalan commented Jun 24, 2022

AlvaroVega commented Jun 27, 2022

fgalan Aug 9, 2022

[WIP] FIX migrate MongoDB driver to 4.x #689

Are you sure you want to change the base?

[WIP] FIX migrate MongoDB driver to 4.x #689

Conversation

fgalan commented Jun 21, 2022 • edited Loading

fgalan Jun 21, 2022

Choose a reason for hiding this comment

fgalan Aug 9, 2022

Choose a reason for hiding this comment

fgalan commented Jun 21, 2022

fgalan commented Jun 24, 2022

fgalan commented Jun 24, 2022

fgalan commented Jun 24, 2022

fgalan commented Jun 24, 2022

AlvaroVega commented Jun 27, 2022

fgalan Aug 9, 2022

Choose a reason for hiding this comment

fgalan commented Jun 21, 2022 •

edited

Loading