telefonicaid / iotagent-json

IoT Agent for a JSON based protocol (with HTTP, MQTT and AMQP transports)
https://fiware-iotagent-json.rtfd.io/
GNU Affero General Public License v3.0
51 stars 88 forks source link

Got a Stacktrace when explicitAttrs=true #576

Closed mapedraza closed 3 years ago

mapedraza commented 3 years ago

I am having having a stacktrace issue when sending data to a group defined witheplicitAttrs=true with the ´latest´ version of IoTA-JSON. The same issue is reproducible with the IoTA Agent.

The IoTA was deployed with the following envars:

IOTA_NORTH_PORT=4041
IOTA_DEFAULT_RESOURCE=/iot/json
IOTA_CB_NGSI_VERSION=v2
IOTA_TIMESTAMP=true
IOTA_APPEND_MODE=false
IOTA_LOG_LEVEL=DEBUG

1 - Group creation

curl -iX POST "http://localhost:4041/iot/services" -H 'Content-Type: application/json' -H 'fiware-service: test' -H 'fiware-servicepath:/' -d '{
  "services": [
    {
      "apikey": "apikeytest2",
      "cbroker": "http://orion:1026",
      "entity_type": "Sensor:Temperature",
      "resource": "/iot/json",
      "explicitAttrs":true
    }
  ]
}'

2 - Posting data:

curl -iX POST "http://localhost:7896/iot/json?k=apikeytest2&i=dev3" -H 'Content-Type: application/json'  -d '{"h":98,"t":99}'

3 - Log

time=2021-07-07T08:36:16.646Z | lvl=DEBUG | corr=f3868914-43e6-4197-8b08-fb1b3238fb5f | trans=f3868914-43e6-4197-8b08-fb1b3238fb5f | op=IOTASON.HTTP.Binding | from=n/a | srv=n/a | subsrv=n/a | msg=Parsed data: [[{"h":98,"t":99}]] | comp=IoTAgent
time=2021-07-07T08:36:16.646Z | lvl=DEBUG | corr=f3868914-43e6-4197-8b08-fb1b3238fb5f | trans=f3868914-43e6-4197-8b08-fb1b3238fb5f | op=IOTASON.HTTP.Binding | from=n/a | srv=n/a | subsrv=n/a | msg=Processing multiple HTTP measures for device [dev3] with apiKey [apikeytest2] | comp=IoTAgent
time=2021-07-07T08:36:16.647Z | lvl=DEBUG | corr=f3868914-43e6-4197-8b08-fb1b3238fb5f | trans=f3868914-43e6-4197-8b08-fb1b3238fb5f | op=IoTAgentNGSI.MongoDBGroupRegister | from=n/a | srv=n/a | subsrv=n/a | msg=Looking for group params ["resource","apikey"] with queryObj {"resource":"/iot/json","apikey":"apikeytest2"} | comp=IoTAgent
time=2021-07-07T08:36:16.673Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBGroupRegister | from=n/a | srv=test | subsrv=/ | msg=Device group data found: {"_id":"60e56760cdab00ac6a7ecc77","resource":"/iot/json","apikey":"apikeytest2","type":"Sensor:Temperature","service":"test","subservice":"/","explicitAttrs":true} | comp=IoTAgent
time=2021-07-07T08:36:16.674Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBDeviceRegister | from=n/a | srv=test | subsrv=/ | msg=Looking for device with id [dev3]. | comp=IoTAgent
time=2021-07-07T08:36:16.681Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBDeviceRegister | from=n/a | srv=test | subsrv=/ | msg=Device [dev3] not found. | comp=IoTAgent
time=2021-07-07T08:36:16.682Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBDeviceRegister | from=n/a | srv=test | subsrv=/ | msg=Looking for device with id [dev3]. | comp=IoTAgent
time=2021-07-07T08:36:16.701Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBDeviceRegister | from=n/a | srv=test | subsrv=/ | msg=Device [dev3] not found. | comp=IoTAgent
time=2021-07-07T08:36:16.702Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBGroupRegister | from=n/a | srv=n/a | subsrv=n/a | msg=Looking for group params ["service","subservice","apikey"] with queryObj {"service":"test","subservice":"/"} | comp=IoTAgent
time=2021-07-07T08:36:16.713Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBGroupRegister | from=n/a | srv=test | subsrv=/ | msg=Device group data found: {"_id":"60e56760cdab00ac6a7ecc77","resource":"/iot/json","apikey":"apikeytest2","type":"Sensor:Temperature","service":"test","subservice":"/","explicitAttrs":true} | comp=IoTAgent
time=2021-07-07T08:36:16.713Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.DeviceService | from=n/a | srv=test | subsrv=/ | msg=Device name not found, falling back to deviceType:deviceId [Sensor:Temperature:dev3] | comp=IoTAgent
time=2021-07-07T08:36:16.714Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.DeviceService | from=n/a | srv=test | subsrv=/ | msg=deviceData before merge with conf: {"id":"dev3","service":"test","subservice":"/","type":"Sensor:Temperature","transport":"HTTP","explicitAttrs":true,"name":"Sensor:Temperature:dev3"} | comp=IoTAgent
time=2021-07-07T08:36:16.714Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.DeviceService | from=n/a | srv=test | subsrv=/ | msg=deviceData after merge with conf: {"id":"dev3","service":"test","subservice":"/","type":"Sensor:Temperature","transport":"HTTP","explicitAttrs":true,"name":"Sensor:Temperature:dev3","lazy":null,"active":null,"staticAttributes":[],"commands":[],"subscriptions":[]} | comp=IoTAgent
time=2021-07-07T08:36:16.714Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.DeviceService | from=n/a | srv=test | subsrv=/ | msg=Registering device into NGSI Service:
{
    "id": "dev3",
    "service": "test",
    "subservice": "/",
    "type": "Sensor:Temperature",
    "transport": "HTTP",
    "explicitAttrs": true,
    "name": "Sensor:Temperature:dev3",
    "lazy": null,
    "active": null,
    "staticAttributes": [],
    "commands": [],
    "subscriptions": []
} | comp=IoTAgent
time=2021-07-07T08:36:16.714Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.Registration | from=n/a | srv=test | subsrv=/ | msg=Registration with Context Provider is not needed. Device without lazy atts or commands | comp=IoTAgent
time=2021-07-07T08:36:16.715Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.Devices-v2 | from=n/a | srv=test | subsrv=/ | msg=deviceData: {"id":"dev3","service":"test","subservice":"/","type":"Sensor:Temperature","transport":"HTTP","explicitAttrs":true,"name":"Sensor:Temperature:dev3","lazy":null,"active":null,"staticAttributes":[],"commands":[],"subscriptions":[]} | comp=IoTAgent
time=2021-07-07T08:36:16.715Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.Devices-v2 | from=n/a | srv=test | subsrv=/ | msg=config.timestamp undefined true | comp=IoTAgent
time=2021-07-07T08:36:16.716Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.Devices-v2 | from=n/a | srv=test | subsrv=/ | msg=Creating initial entity in the Context Broker:
 {
    "url": "http://localhost:1026/v2/entities?options=upsert",
    "method": "POST",
    "json": {
        "id": "Sensor:Temperature:dev3",
        "type": "Sensor:Temperature",
        "TimeInstant": {
            "type": "DateTime",
            "value": "2021-07-07T08:36:16.715Z"
        }
    },
    "headers": {
        "fiware-service": "test",
        "fiware-servicepath": "/",
        "fiware-correlator": "761a6d32-a5c1-4944-bd1b-65d8f9c2636e"
    }
} | comp=IoTAgent
time=2021-07-07T08:36:16.717Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.RestUtils | from=n/a | srv=test | subsrv=/ | msg=executeWithSecurity | comp=IoTAgent
time=2021-07-07T08:36:16.717Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBGroupRegister | from=n/a | srv=n/a | subsrv=n/a | msg=Looking for group params ["type"] with queryObj {"type":"Sensor:Temperature"} | comp=IoTAgent
time=2021-07-07T08:36:16.722Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBGroupRegister | from=n/a | srv=test | subsrv=/ | msg=Device group data found: {"_id":"60e56760cdab00ac6a7ecc77","resource":"/iot/json","apikey":"apikeytest2","type":"Sensor:Temperature","service":"test","subservice":"/","explicitAttrs":true} | comp=IoTAgent
time=2021-07-07T08:36:16.810Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.Devices-v2 | from=n/a | srv=test | subsrv=/ | msg=Initial entity created successfully. | comp=IoTAgent
time=2021-07-07T08:36:16.813Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.MongoDBDeviceRegister | from=n/a | srv=test | subsrv=/ | msg=Storing device with id [dev3] and type [Sensor:Temperature] | comp=IoTAgent
time=2021-07-07T08:36:16.840Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.DeviceService | from=n/a | srv=test | subsrv=/ | msg=deviceData before merge with conf: {"commands":[],"staticAttributes":[],"subscriptions":[],"_id":"60e56780cdab00ac6a7ecc78","creationDate":"2021-07-07T08:36:16.811Z","id":"dev3","type":"Sensor:Temperature","name":"Sensor:Temperature:dev3","service":"test","subservice":"/","transport":"HTTP","explicitAttrs":true,"__v":0} | comp=IoTAgent
time=2021-07-07T08:36:16.840Z | lvl=DEBUG | corr=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | trans=761a6d32-a5c1-4944-bd1b-65d8f9c2636e | op=IoTAgentNGSI.DeviceService | from=n/a | srv=test | subsrv=/ | msg=deviceData after merge with conf: {"commands":[],"staticAttributes":[],"subscriptions":[],"_id":"60e56780cdab00ac6a7ecc78","creationDate":"2021-07-07T08:36:16.811Z","id":"dev3","type":"Sensor:Temperature","name":"Sensor:Temperature:dev3","service":"test","subservice":"/","transport":"HTTP","explicitAttrs":true,"__v":0,"lazy":null,"active":null} | comp=IoTAgent
time=2021-07-07T08:36:16.841Z | lvl=ERROR | corr=n/a | trans=n/a | op=IoTAgentNGSI.DomainControl | from=n/a | srv=n/a | subsrv=n/a | msg=TypeError: Cannot read property 'length' of null
    at checkAttributes (/Users/mpedraza/Documents/GitHub/iotagent-json/lib/commonBindings.js:107:43)
    at Object.extractAttributes (/Users/mpedraza/Documents/GitHub/iotagent-json/lib/commonBindings.js:118:46)
    at Function.processHTTPWithDevice (/Users/mpedraza/Documents/GitHub/iotagent-json/lib/bindings/HTTPBinding.js:245:41)
    at Domain.expandedFunction (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/iotagent-node-lib/lib/services/common/domain.js:171:23)
    at Domain.run (node:domain:373:15)
    at ensureSouthboundTransaction (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/iotagent-node-lib/lib/services/common/domain.js:154:22)
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/iotagent-node-lib/lib/services/common/domain.js:174:16
    at processDeviceMeasure (/Users/mpedraza/Documents/GitHub/iotagent-json/lib/bindings/HTTPBinding.js:290:59)
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/async/dist/async.js:473:16
    at next (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/async/dist/async.js:5329:29)
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/async/dist/async.js:969:16
    at mergeDeviceWithConfiguration (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/iotagent-node-lib/lib/services/devices/deviceService.js:183:5)
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/async/dist/async.js:66:19
    at nextTask (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/async/dist/async.js:5324:14)
    at next (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/async/dist/async.js:5331:9)
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/async/dist/async.js:969:16
    at Function.<anonymous> (/Users/mpedraza/Documents/GitHub/iotagent-json/lib/iotaUtils.js:200:21)
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/iotagent-node-lib/lib/services/common/alarmManagement.js:105:29
    at saveHandler (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/iotagent-node-lib/lib/services/devices/deviceRegistryMongoDB.js:111:13)
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/mongoose/lib/model.js:4599:16
    at /Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/mongoose/lib/utils.js:264:16
    at model.<anonymous> (/Users/mpedraza/Documents/GitHub/iotagent-json/node_modules/mongoose/lib/model.js:470:7) {
  domainThrown: true
} | comp=IoTAgent
time=2021-07-07T08:36:16.847Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.DomainControl | from=n/a | srv=n/a | subsrv=n/a | msg=response-time: 67438 | comp=IoTAgent
fgalan commented 3 years ago

Fixed by PR https://github.com/telefonicaid/iotagent-json/pull/577

@mapedraza please have a look and close this issue is you confirm now it's working as expected.

mapedraza commented 3 years ago

Issue solved