lightweightm2m-iotagent icon indicating copy to clipboard operation
lightweightm2m-iotagent copied to clipboard

Published 20 hours ago • verified publisher icon telefonicaid

Queries from Orion to IOTA: Error forwarding query

Open Secmotic opened this issue 8 years ago • 1 comments

Hi,

I have been using the LWM2M with success with one physical device. In order to implement a more complex device, we have created a Leshan client (https://github.com/eclipse/leshan), with several resources to observe.

With the first device, the lazy attributes were observable doing the proper requests in Orion. With the device disconnected we can see that the query is forwarded from Orion to the IOTA:

(curl localhost:1026/v1/queryContext -s -S --header 'Content-Type: application/json' --header 'Accept: application/json' --header 'Fiware-service: smartGondor' --header 'Fiware-servicepath: /gardens' -d @- | python -mjson.tool) <<EOF
{
    "entities": [
        {
            "type": "Device",
            "isPattern": "false",
            "id": "00124b0004117a7f:Device"
        }
    ],
"attributes": [
        "temperature"
    ]

} 
EOF

Resultado en Orion & IOTA:

{
    "errorCode": {
        "code": "404",
        "reasonPhrase": "No context element found"
    }
}


time=2016-05-17T10:10:29.395Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Request for path [//queryContext] from [130.206.125.211:4042]
time=2016-05-17T10:10:29.396Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Body:

{
    "entities": [
        {
            "type": "Device",
            "isPattern": "false",
            "id": "00124b0004117a7f:Device"
        }
    ],
    "attributes": [
        "temperature"
    ]
}


time=2016-05-17T10:10:29.396Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=Handling query from [130.206.125.211:4042]
time=2016-05-17T10:10:29.397Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=Handling received set of attributes: ["temperature"]
time=2016-05-17T10:10:29.397Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IOTAgent.NGSIHandlers | msg=Handling device data query from the northbound for device [00124b0004117a7f:Device] of type [Device]
time=2016-05-17T10:10:29.397Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IOTAgent.NGSIHandlers | msg=New attributes;
temperature
time=2016-05-17T10:10:29.398Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=Selecting ID from the stored device data
time=2016-05-17T10:10:29.398Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=There was an error handling the query: [object Object].
time=2016-05-17T10:10:29.398Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Error [DEVICE_NOT_FOUND] handing request: The device with id: 00124b0004117a7f was not found
`

But when trying to do the same with the leshan client, the query is not forwarded to the IOTA:

`#!/bin/bash
(curl localhost:1026/v1/queryContext -s -S --header 'Content-Type: application/json' --header 'Accept: application/json' --header 'Fiware-service: smartGondor' --header 'Fiware-servicepath: /gardens' -d @- | python -mjson.tool) <<EOF
{
    "entities": [
        {
            "type": "Device",
            "isPattern": "false",
            "id": "orioncentos.novalocal:Device"
        }
    ],
"attributes": [
        "TFlowCH2"
    ]

} 
EOF

{
    "errorCode": {
        "code": "404",
        "details": "error forwarding query",
        "reasonPhrase": "No context element found"
    }
}
`

Finally, the preprovision of the devices are:

-Device OK

`{
    "devices":[
        {
            "device_id": "00124b0004117a7f",
            "entity_name": "00124b0004117a7f:Device",
            "entity_type": "Device",
            "attributes": [],
            "lazy": [
                {
                "name": "serial",
                "type": "integer"
                },
                {
                "name": "temperature",
                "type": "integer"
                }

            ],
            "commands": [],
            "internal_attributes": {
                "lwm2mResourceMapping": {
                    "serial" : {
                        "objectType": 7111,
                        "objectInstance": 0,
                        "objectResource": 0
                    },
                    "reboot" : {
                        "objectType": 7111,
                        "objectInstance": 0,
                        "objectResource": 1
                    },
                    "temperature" : {
                        "objectType": 7111,
                        "objectInstance": 0,
                        "objectResource": 2
                    }
                }
            }
        }
  ]

}`

-Device NOK


`{
    "devices":[
        {
            "device_id": "orioncentos.novalocal",
            "entity_name": "orioncentos.novalocal:Device",
            "entity_type": "Device",
            "attributes": [],
            "lazy": [

                {
                "name": "DHW Setpoint",
                "type": "integer"
                },{
                    "name":"TFlowCH2",
                    "type":"integer"
                }

            ],
            "commands": [],
            "internal_attributes": {
                "lwm2mResourceMapping": {
                    "TFlowCH2" : {
                        "objectType": 6000,
                        "objectInstance": 0,
                        "objectResource": 31
                    },
                    "DHW Setpoint":{
                        "objectType": 6000,
                        "objectInstance": 0,
                        "objectResource": 56
                    }
                }
            }
        }
  ]

}`

The only difference seems to be the ID of the device, and in the logs of the IOTA, it can be seen that the device ID of the leshan client is the one that I am using as device_id:

`time=2016-05-17T09:29:09.337Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.Registration | msg=Storing the following device in the db:
{
    "name": "orioncentos.novalocal",
    "lifetime": "30",
    "address": "130.206.125.211",
    "port": 45935,
    "creationDate": "2016-05-17T09:29:09.337Z"
}
time=2016-05-17T09:29:09.337Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.Registration | msg=Registered device [orioncentos.novalocal] with type [Device]`

Thanks in advance

Secmotic avatar May 17 '16 10:05 Secmotic

@UPDATE: A very weird thing happened. When I try to do a pattern-query, the query is forwarded to the IOTA and some readings happens:

#!/bin/bash
(curl localhost:1026/v1/queryContext -s -S --header 'Content-Type: application/json' --header 'Accept: application/json' --header 'Fiware-service: smartGondor' --header 'Fiware-servicepath: /gardens' -d @- | python -mjson.tool) <<EOF
{
    "entities": [
        {
            "type": "Device",
            "isPattern": "true",
            "id": ".*"
        }
    ]
    } 
EOF

And the following is forwarded to the IOTA (actually, it reads from the device, but nothings come back):

time=2016-05-23T07:13:15.293Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Body:

{
    "entities": [
        {
            "type": "Device",
            "isPattern": "false",
            "id": "00124b0004117a7f:Device"
        }
    ],
    "attributes": [
        "serial",
        "temperature",
        "reboot"
    ]
}


time=2016-05-23T07:13:15.294Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=Handling query from [130.206.125.211:4042]
time=2016-05-23T07:13:15.294Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=Handling received set of attributes: ["serial","temperature","reboot"]
time=2016-05-23T07:13:15.294Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IOTAgent.NGSIHandlers | msg=Handling device data query from the northbound for device [00124b0004117a7f:Device] of type [Device]
time=2016-05-23T07:13:15.295Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IOTAgent.NGSIHandlers | msg=New attributes;
serial,temperature,reboot
time=2016-05-23T07:13:15.295Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=Selecting ID from the stored device data
time=2016-05-23T07:13:15.295Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=There was an error handling the query: [object Object].
time=2016-05-23T07:13:15.295Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Error [DEVICE_NOT_FOUND] handing request: The device with id: 00124b0004117a7f was not found
time=2016-05-23T07:13:15.381Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Request for path [//queryContext] from [130.206.125.211:4042]
time=2016-05-23T07:13:15.381Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Body:

{
    "entities": [
        {
            "type": "Device",
            "isPattern": "false",
            "id": "orioncentos.novalocal:Device"
        }
    ],
    "attributes": [
        "DHW Setpoint",
        "TFlowCH2",
        "Short Server ID",
        "Lifetime",
        "Default Minimum Period",
        "Default Maximum Period",
        "Disable",
        "Disable Timeout",
        "Notification Storing When Disabled or Offline",
        "Binding",
        "Registration Update Trigger",
        "Manufacturer",
        "Model Number",
        "Serial Number",
        "Firmware Version",
        "Reboot",
        "Factory Reset",
        "Available Power Sources",
        "Power Source Voltage",
        "Power Source Current",
        "Battery Level",
        "Memory Free",
        "Error Code",
        "Reset Error Code",
        "Current Time",
        "UTC Offset",
        "Timezone",
        "Supported Binding and Modes",
        "Latitude",
        "Longitude",
        "Altitude",
        "Uncertainty",
        "Velocity",
        "Timestamp"
    ]
}


time=2016-05-23T07:13:15.382Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=Handling query from [130.206.125.211:4042]
time=2016-05-23T07:13:15.382Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=Handling received set of attributes: ["DHW Setpoint","TFlowCH2","Short Server ID","Lifetime","Default Minimum Period","Default Maximum Period","Disable","Disable Timeout","Notification Storing When Disabled or Offline","Binding","Registration Update Trigger","Manufacturer","Model Number","Serial Number","Firmware Version","Reboot","Factory Reset","Available Power Sources","Power Source Voltage","Power Source Current","Battery Level","Memory Free","Error Code","Reset Error Code","Current Time","UTC Offset","Timezone","Supported Binding and Modes","Latitude","Longitude","Altitude","Uncertainty","Velocity","Timestamp"]
time=2016-05-23T07:13:15.383Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IOTAgent.NGSIHandlers | msg=Handling device data query from the northbound for device [orioncentos.novalocal:Device] of type [Device]
time=2016-05-23T07:13:15.383Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IOTAgent.NGSIHandlers | msg=New attributes;
DHW Setpoint,TFlowCH2,Short Server ID,Lifetime,Default Minimum Period,Default Maximum Period,Disable,Disable Timeout,Notification Storing When Disabled or Offline,Binding,Registration Update Trigger,Manufacturer,Model Number,Serial Number,Firmware Version,Reboot,Factory Reset,Available Power Sources,Power Source Voltage,Power Source Current,Battery Level,Memory Free,Error Code,Reset Error Code,Current Time,UTC Offset,Timezone,Supported Binding and Modes,Latitude,Longitude,Altitude,Uncertainty,Velocity,Timestamp
time=2016-05-23T07:13:15.383Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=Selecting ID from the stored device data
time=2016-05-23T07:13:15.384Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6000/0/56 in device [44]
time=2016-05-23T07:13:15.384Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6000/0/31 in device [44]
time=2016-05-23T07:13:15.386Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /1/0/0 in device [44]
time=2016-05-23T07:13:15.386Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /1/0/1 in device [44]
time=2016-05-23T07:13:15.386Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /1/0/2 in device [44]
time=2016-05-23T07:13:15.386Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /1/0/3 in device [44]
time=2016-05-23T07:13:15.387Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /1/0/5 in device [44]
time=2016-05-23T07:13:15.387Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /1/0/6 in device [44]
time=2016-05-23T07:13:15.387Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /1/0/7 in device [44]
time=2016-05-23T07:13:15.387Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/0 in device [44]
time=2016-05-23T07:13:15.388Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/1 in device [44]
time=2016-05-23T07:13:15.388Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/2 in device [44]
time=2016-05-23T07:13:15.388Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/3 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/6 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/7 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/8 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/9 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/10 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/11 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/13 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/14 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/15 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /3/0/16 in device [44]
time=2016-05-23T07:13:15.389Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6/0/0 in device [44]
time=2016-05-23T07:13:15.391Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6/0/1 in device [44]
time=2016-05-23T07:13:15.391Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6/0/2 in device [44]
time=2016-05-23T07:13:15.391Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6/0/3 in device [44]
time=2016-05-23T07:13:15.391Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6/0/4 in device [44]
time=2016-05-23T07:13:15.391Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.DeviceManagement | msg=Reading value from resource /6/0/5 in device [44]
time=2016-05-23T07:13:15.449Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.ContextServer | msg=There was an error handling the query: [object Object].
time=2016-05-23T07:13:15.449Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.NorthboundServer | msg=Error [RESOURCE_NOT_FOUND] handing request: The resource was not found in the registry

So it seems to be a problem in the registration. Nevertheless, the registry happens to be OK:

`time=2016-05-23T07:17:04.289Z | lvl=DEBUG | corr=n/a | trans=n/a | op=IoTAgentNGSI.DeviceService | msg=Registration success.
time=2016-05-23T07:17:04.289Z | lvl=DEBUG | corr=n/a | trans=n/a | op=LWM2MLib.Registration | msg=Registration request ended successfully
time=2016-05-23T07:17:04.349Z | lvl=DEBUG | corr=n/a | trans=n/a | op=n/a | msg=Observers created successfully.
`

And the request returns a 200 OK, but no readings:


{
    "errorCode": {
        "code": "200",
        "reasonPhrase": "OK"
    }
}

And in the LWM2M cliente, we can see the following:

may 23, 2016 8:44:31 AM org.eclipse.californium.core.network.config.NetworkConfig createStandardWithFile
INFORMACIÓN: Loading standard properties from file Californium.properties
[2016-05-23 08:44:31,692 INFO LeshanClient] Starting Leshan client ...
may 23, 2016 8:44:31 AM org.eclipse.californium.core.CoapServer start
INFORMACIÓN: Starting server
may 23, 2016 8:44:31 AM org.eclipse.californium.core.network.CoapEndpoint start
INFORMACIÓN: Starting endpoint at 0.0.0.0/0.0.0.0:0
may 23, 2016 8:44:31 AM org.eclipse.californium.scandium.DTLSConnector start
INFORMACIÓN: DTLS connector listening on [0.0.0.0/0.0.0.0:60414] with MTU [1.280] using (inbound) datagram buffer size [16.474 bytes]
may 23, 2016 8:44:31 AM org.eclipse.californium.core.network.CoapEndpoint start
INFORMACIÓN: Starting endpoint at 0.0.0.0/0.0.0.0:0
[2016-05-23 08:44:31,737 INFO LeshanClient] Leshan client started.
[2016-05-23 08:44:31,750 INFO RegistrationEngine] Trying to register to coap://130.206.125.211:4041 ...
[2016-05-23 08:44:31,848 INFO RegistrationEngine] Next registration update in 27.0s...
[2016-05-23 08:44:31,850 INFO RegistrationEngine] Registered with location '/rd/1'.
[2016-05-23 08:44:35,303 INFO OpenTherm] Read on OpenThermObject-Resource 56
[2016-05-23 08:44:35,308 INFO OpenTherm] Read on OpenThermObject-Resource 31

Secmotic avatar May 23 '16 07:05 Secmotic