Orion contextBroker don't notifies correctly when data comes from IoTAgent

1
votes

I have in the same machine an IoTAgent, an Orion contextBroker, Cygnus and a MySQL database.

When I update a value via POST directly to the contextBroker, it is succesfully updated and the onchange subscription raises the notification to cygnus and then the value is persisted to MySQL database. The problem comes when I update the value via POST to the IoTAgent. The agent forward correctly the value to the contextBroker, and it is updated in his mongo DB.

EDIT:

Incorrect: "In this case the onchange subscription raise the notification to cygnus but it doesn't send the value to the MySQL database."

After some tests, I realized that the contextBroker doesn't send or even start the notification to Cygnus.

There is no significant errors in any of the logs.

This is the contextBroker log when receives and updateContext directly via my POST:

    time=2016-02-28T14:42:57.669CET | lvl=INFO | trans=1456501859-068-00000000028 | srv=<default> | subsrv=/ | from=83.50.53.181 | function=collectionUpdate | comp=Orion | msg=connectionOperations.cpp[401]: Database Operation Successful (update: <{ _id.id: "D000", _id.type: "thing", _id.servicePath: /\// }, { $set: { attrs.Temperature0: { value: "10", type: "Number", md: [ { name: "TimeInstant", type: "ISO8601", value: "2016-02-28T13:21:43.156957Z" } ], creDate: 1456351643, modDate: 1456666977 }, modDate: 1456666977 }, $unset: { location: 1 } }>)
time=2016-02-28T14:42:57.670CET | lvl=INFO | trans=1456501859-068-00000000029 | srv=pending | subsrv=pending | from=pending | function=lmTransactionStart | comp=Orion | msg=logMsg.h[1803]: Starting transaction to localhost:5050/notify
time=2016-02-28T14:42:57.670CET | lvl=INFO | trans=1456501859-068-00000000028 | srv=<default> | subsrv=/ | from=83.50.53.181 | function=lmTransactionEnd | comp=Orion | msg=logMsg.h[1887]: Transaction ended
time=2016-02-28T14:42:57.692CET | lvl=INFO | trans=1456501859-068-00000000029 | srv=pending | subsrv=pending | from=pending | function=httpRequestSendWithCurl | comp=Orion | msg=httpRequestSend.cpp[446]: Notification Successfully Sent to localhost:5050/notify
time=2016-02-28T14:42:57.692CET | lvl=INFO | trans=1456501859-068-00000000029 | srv=pending | subsrv=pending | from=pending | function=lmTransactionEnd | comp=Orion | msg=logMsg.h[1887]: Transaction ended
time=2016-02-28T14:43:06.330CET | lvl=INFO | trans=N/A | srv=N/A | subsrv=N/A | from=N/A | function=collectionQuery | comp=Orion | msg=connectionOperations.cpp[79]: Database Operation Successful (query: { conditions.type: "ONCHANGE" })
time=2016-02-28T14:43:06.331CET | lvl=INFO | trans=N/A | srv=N/A | subsrv=N/A | from=N/A | function=collectionUpdate | comp=Orion | msg=connectionOperations.cpp[401]: Database Operation Successful (update: <{ _id: ObjectId('56d2f43a919d4b4fe286b100') }, { $inc: { count: 1 } }>)
time=2016-02-28T14:43:06.332CET | lvl=INFO | trans=N/A | srv=N/A | subsrv=N/A | from=N/A | function=collectionUpdate | comp=Orion | msg=connectionOperations.cpp[401]: Database Operation Successful (update: <{ _id: ObjectId('56d2f43a919d4b4fe286b100'), lastNotification: { $lt: 1456666977 } }, { $set: { lastNotification: 1456666977 } }>)

or via IoTAgent:

    time=2016-02-28T14:54:11.427CET | lvl=INFO | trans=1456501859-068-00000000030 | srv=fiware | subsrv=/ | from=0.0.0.0 | function=collectionUpdate | comp=Orion | msg=connectionOperations.cpp[401]: Database Operation Successful (update: <{ _id.id: "D000", _id.type: "thing", _id.servicePath: /\// }, { $set: { attrs.Temperature0: { value: "43", type: "Number", md: [ { name: "TimeInstant", type: "ISO8601", value: "2016-02-28T13:54:11.416335Z" } ], creDate: 1456351643, modDate: 1456667651 }, attrs.TimeInstant: { value: "2016-02-28T13:54:11.416335Z", type: "ISO8601", creDate: 1456351372, modDate: 1456667651 }, modDate: 1456667651 }, $unset: { location: 1 } }>)
time=2016-02-28T14:54:11.428CET | lvl=INFO | trans=1456501859-068-00000000030 | srv=fiware | subsrv=/ | from=0.0.0.0 | function=lmTransactionEnd | comp=Orion | msg=logMsg.h[1887]: Transaction ended
time=2016-02-28T14:54:11.428CET | lvl=INFO | trans=1456501859-068-00000000031 | srv=fiware | subsrv=/ | from=0.0.0.0 | function=collectionQuery | comp=Orion | msg=connectionOperations.cpp[79]: Database Operation Successful (query: { _id.id: "D000", _id.type: "thing", _id.servicePath: /^\/$/ })
time=2016-02-28T14:54:11.430CET | lvl=INFO | trans=1456501859-068-00000000031 | srv=fiware | subsrv=/ | from=0.0.0.0 | function=collectionUpdate | comp=Orion | msg=connectionOperations.cpp[401]: Database Operation Successful (update: <{ _id.id: "D000", _id.type: "thing", _id.servicePath: /\// }, { $set: { attrs.Humidity0: { value: "61", type: "Number", md: [ { name: "TimeInstant", type: "ISO8601", value: "2016-02-28T13:54:11.417399Z" } ], creDate: 1456351679, modDate: 1456667651 }, attrs.TimeInstant: { value: "2016-02-28T13:54:11.417399Z", type: "ISO8601", creDate: 1456351372, modDate: 1456667651 }, modDate: 1456667651 }, $unset: { location: 1 } }>)
time=2016-02-28T14:54:11.430CET | lvl=INFO | trans=1456501859-068-00000000031 | srv=fiware | subsrv=/ | from=0.0.0.0 | function=lmTransactionEnd | comp=Orion | msg=logMsg.h[1887]: Transaction ended
time=2016-02-28T14:55:06.349CET | lvl=INFO | trans=N/A | srv=N/A | subsrv=N/A | from=N/A | function=collectionQuery | comp=Orion | msg=connectionOperations.cpp[79]: Database Operation Successful (query: { conditions.type: "ONCHANGE" })

EDIT:

These are the TCP Streams captured with Wireshark in both cases.

-When I send directly to the contextBroker:

##### 158.***.***.27:51112 -> 158.***.***.26:1026 #####
POST /v1/updateContext HTTP/1.1
Host: 158.***.***.26:1026
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:44.0) Gecko/20100101 Firefox/44.0
Accept: application/json
Accept-Language: es-ES,es;q=0.8,en-US;q=0.5,en;q=0.3
Accept-Encoding: gzip, deflate
Content-Type: application/json
Content-Length: 367
Connection: keep-alive

{
"contextElements": [
{
"type": "thing",
"isPattern": "false",
"id": "D000",
"attributes": [
{
"name": "Temperature0",
"type": "Number",
"value": "3"
}
]
}
],
"updateAction": "APPEND"
} 

##### 158.***.***.26:1026 -> 158.***.***.27:51112 #####
HTTP/1.1 200 OK
Content-Length: 398
Content-Type: application/json
Date: Mon, 29 Feb 2016 14:47:45 GMT

{
"contextResponses" : [
{
"contextElement" : {
"type" : "thing",
"isPattern" : "false",
"id" : "D000",
"attributes" : [
{
"name" : "Temperature0",
"type" : "Number",
"value" : ""
}
]
},
"statusCode" : {
"code" : "200",
"reasonPhrase" : "OK"
}
}
]
}

##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
l...................orion.entities.........A...._id.id.....D000.._id.type.....thing.._id.servicePath.^\/$...
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
....................................f...._id.5....id.....D000..type.....thing..servicePath...../...attrNames.=....0.....TimeInstant..1.
...Temperature0..2.
...Humidity0...attrs......TimeInstant.X....value.....2016-02-29T12:30:14.140066Z..type.....ISO8601..creDate..(.V.modDate..9.V..Temperature0......value.....2..type.....Number..md.\....0.T....name.....TimeInstant..type.....ISO8601..value.....2016-02-29T12:30:14.140066Z....creDate..).V.modDate.MX.V..Humidity0......value.....41..type.....Number..md.\....0.T....name.....TimeInstant..type.....ISO8601..value.....2016-02-28T14:11:27.896331Z....creDate..).V.modDate....V...creDate..(.V.modDate.MX.V.
##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
....................orion.$cmd..............update. ...entities..updates.L....0.D....q.?...._id.id.....D000.._id.type.....thing.._id.servicePath.\/....u......$set......attrs.Temperature0......value.....3..type.....Number..md.\....0.T....name.....TimeInstant..type.....ISO8601..value.....2016-02-29T12:30:14.140066Z....creDate..).V.modDate..Z.V..modDate..Z.V..$unset......location........multi...upsert.....ordered...writeConcern.......
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
G...................................#....ok......nModified......n......
##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
K... ...............orion.csubs.........#....conditions.type. ...ONCHANGE..
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
........ ................................_id.V..:..KO.....expiration..'.X.....reference.....http://localhost:5050/notify..throttling..........servicePath...../..entities./....0.'....id.....D000..isPattern.....false....attrs.*....0.
...Temperature0..1.
...Humidity0...conditions.Q....0.I....type. ...ONCHANGE..value.*....0.
...Temperature0..1.
...Humidity0.....expression.6....q.......geometry.......coords.......georel........lastNotification.MX.V.....count..........format.....XML..
##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
....!...............orion.$cmd..............update.....csubs..updates.Y....0.Q....q......_id.V..:..KO......u......$inc......count............multi...upsert.....ordered...writeConcern.......
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
G.......!...........................#....ok......nModified......n......
##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
...."...............orion.$cmd..............update.....csubs..updates......0......q.:...._id.V..:..KO.....lastNotification......$lt..Z.V.......u.*....$set......lastNotification..Z.V.......multi...upsert.....ordered...writeConcern.......
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
G......."...........................#....ok......nModified......n......

##### ::1:60964 -> ::1:5050 #####
POST /notify HTTP/1.1
User-Agent: orion/0.27.0 libcurl/7.19.7
Host: localhost:5050
Accept: application/xml, application/json
Content-length: 1400
Content-type: application/xml

<notifyContextRequest>
<subscriptionId>56d2f43a919d4b4fe286b100</subscriptionId>
<originator>localhost</originator>
<contextResponseList>
<contextElementResponse>
<contextElement>
<entityId type="thing" isPattern="false">
<id>D000</id>
</entityId>
<contextAttributeList>
<contextAttribute>
<name>Humidity0</name>
<type>Number</type>
<contextValue>41</contextValue>
<metadata>
<contextMetadata>
<name>TimeInstant</name>
<type>ISO8601</type>
<value>2016-02-28T14:11:27.896331Z</value>
</contextMetadata>
</metadata>
</contextAttribute>
<contextAttribute>
<name>Temperature0</name>
<type>Number</type>
<contextValue>3</contextValue>
<metadata>
<contextMetadata>
<name>TimeInstant</name>
<type>ISO8601</type>
<value>2016-02-29T12:30:14.140066Z</value>
</contextMetadata>
</metadata>
</contextAttribute>
</contextAttributeList>
</contextElement>
<statusCode>
<code>200</code>
<reasonPhrase>OK</reasonPhrase>
</statusCode>
</contextElementResponse>
</contextResponseList>
</notifyContextRequest>

##### ::1:5050 -> ::1:60964 #####
HTTP/1.1 200 OK
Transfer-Encoding: chunked
Server: Jetty(6.1.26)

0


##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
4...
5.1.73.g...o9k4^^<P...................\`K:{#7,t&]$.
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
;...........!.......................root..........1Ln2.=.E..f..
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
...........
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
...../* mysql-connector-java-5.1.31 ( Revision: alexander.soklakov@oracle.com-20140520065950-groqzzbvxprqdmnz ) */SHOW VARIABLES WHERE Variable_name ='language' OR Variable_name = 'net_write_timeout' OR Variable_name = 'interactive_timeout' OR Variable_name = 'wait_timeout' OR Variable_name = 'character_set_client' OR Variable_name = 'character_set_connection' OR Variable_name = 'character_set' OR Variable_name = 'character_set_server' OR Variable_name = 'tx_isolation' OR Variable_name = 'transaction_isolation' OR Variable_name = 'character_set_results' OR Variable_name = 'timezone' OR Variable_name = 'time_zone' OR Variable_name = 'system_time_zone' OR Variable_name = 'lower_case_table_names' OR Variable_name = 'max_allowed_packet' OR Variable_name = 'net_buffer_length' OR Variable_name = 'sql_mode' OR Variable_name = 'query_cache_type' OR Variable_name = 'query_cache_size' OR Variable_name = 'init_connect'
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
.....9....def. VARIABLES.
Variable_name
VARIABLE_NAME.!...........2....def. VARIABLES..Value.VARIABLE_VALUE.!.................."......character_set_client.utf8.....character_set_connection.utf8.....character_set_results.utf8.....character_set_server.latin1... .init_connect....
.interactive_timeout.28800#....language./usr/share/mysql/english/.....lower_case_table_names.0...
.max_allowed_packet.1048576.....net_buffer_length.16384.....net_write_timeout.60.....query_cache_size.0.....query_cache_type.ON
....sql_mode......system_time_zone.CET.... time_zone.SYSTEM.....tx_isolation.REPEATABLE-READ.....wait_timeout.28800.......".
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
...../* mysql-connector-java-5.1.31 ( Revision: alexander.soklakov@oracle.com-20140520065950-groqzzbvxprqdmnz ) */SELECT @@session.auto_increment_increment
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
.....8....def..."@@session.auto_increment_increment..?.........................1.........
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
.....SET NAMES latin1
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
...........
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
!....SET character_set_results = NULL
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
...........
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
.....SET autocommit=1
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
...........
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
#....SET sql_mode='STRICT_TRANS_TABLES'
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
...........
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
'....create database if not exists `fiware`
##### 127.0.0.1:3306 -> 127.0.0.1:57432 #####
...........
##### 127.0.0.1:57432 -> 127.0.0.1:3306 #####
.....

##### 127.0.0.1:57430 -> 127.0.0.1:3306 #####
.....
##### 127.0.0.1:3306 -> 127.0.0.1:57430 #####
........... 
##### 127.0.0.1:57430 -> 127.0.0.1:3306 #####
.....create table if not exists `ag1_d000_thing` (recvTimeTs long,recvTime text,fiwareservicepath text,entityId text,entityType text,attrName text,attrType text,attrValue text,attrMd text)
##### 127.0.0.1:3306 -> 127.0.0.1:57430 #####
........... 
##### 127.0.0.1:57430 -> 127.0.0.1:3306 #####
.....

##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
4...
5.1.73.h...?W{&HwA{...................j#lu+qz3*w>m.
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
A...........!.......................root.._...'.].s..7.8].....fiware.
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
...........
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
...../* mysql-connector-java-5.1.31 ( Revision: alexander.soklakov@oracle.com-20140520065950-groqzzbvxprqdmnz ) */SHOW VARIABLES WHERE Variable_name ='language' OR Variable_name = 'net_write_timeout' OR Variable_name = 'interactive_timeout' OR Variable_name = 'wait_timeout' OR Variable_name = 'character_set_client' OR Variable_name = 'character_set_connection' OR Variable_name = 'character_set' OR Variable_name = 'character_set_server' OR Variable_name = 'tx_isolation' OR Variable_name = 'transaction_isolation' OR Variable_name = 'character_set_results' OR Variable_name = 'timezone' OR Variable_name = 'time_zone' OR Variable_name = 'system_time_zone' OR Variable_name = 'lower_case_table_names' OR Variable_name = 'max_allowed_packet' OR Variable_name = 'net_buffer_length' OR Variable_name = 'sql_mode' OR Variable_name = 'query_cache_type' OR Variable_name = 'query_cache_size' OR Variable_name = 'init_connect'
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
.....9....def. VARIABLES.
Variable_name
VARIABLE_NAME.!...........2....def. VARIABLES..Value.VARIABLE_VALUE.!.................."......character_set_client.utf8.....character_set_connection.utf8.....character_set_results.utf8.....character_set_server.latin1... .init_connect....
.interactive_timeout.28800#....language./usr/share/mysql/english/.....lower_case_table_names.0...
.max_allowed_packet.1048576.....net_buffer_length.16384.....net_write_timeout.60.....query_cache_size.0.....query_cache_type.ON
....sql_mode......system_time_zone.CET.... time_zone.SYSTEM.....tx_isolation.REPEATABLE-READ.....wait_timeout.28800.......".
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
...../* mysql-connector-java-5.1.31 ( Revision: alexander.soklakov@oracle.com-20140520065950-groqzzbvxprqdmnz ) */SELECT @@session.auto_increment_increment
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
.....8....def..."@@session.auto_increment_increment..?.........................1.........
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
.....SET NAMES latin1
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
...........
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
!....SET character_set_results = NULL
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
...........
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
.....SET autocommit=1
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
...........
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
#....SET sql_mode='STRICT_TRANS_TABLES'
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
...........
##### 127.0.0.1:57433 -> 127.0.0.1:3306 #####
.....insert into `ag1_d000_thing` (recvTimeTs,recvTime,fiwareservicepath,entityId,entityType,attrName,attrType,attrValue,attrMd) values ('1456757265708','2016-02-29T14:47:45.708Z','ag1','D000','thing','Humidity0','Number','41','[{"name":"TimeInstant","type":"ISO8601","value":"2016-02-28T14:11:27.896331Z"}]'),('1456757265708','2016-02-29T14:47:45.708Z','ag1','D000','thing','Temperature0','Number','3','[{"name":"TimeInstant","type":"ISO8601","value":"2016-02-29T12:30:14.140066Z"}]')
##### 127.0.0.1:3306 -> 127.0.0.1:57433 #####
...........&Records: 2 Duplicates: 0 Warnings: 0

-When I send passing by the IoTAgent:

##### 158.***.***.27:51203 -> 158.***.***.26:8080 #####
POST /iot/d?i=D000&k=ak0 HTTP/1.1
Host: 158.***.***.26:8080
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:44.0) Gecko/20100101 Firefox/44.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: es-ES,es;q=0.8,en-US;q=0.5,en;q=0.3
Accept-Encoding: gzip, deflate
Fiware-Service: fiware
Fiware-ServicePath: /
Content-Type: application/json
Content-Length: 4
Connection: keep-alive

t0|4

##### 158.***.***.26:8080 -> 158.***.***.27:51203 #####
HTTP/1.1 200 OK
Connection: close
Host: 158.***.***.26:8080
Content-Length: 0

##### 127.0.0.1:40831 -> 127.0.0.1:27017 #####
`...t...............iot.SERVICE.........*....apikey.....ak0..resource...../iot/d......._id......
##### 127.0.0.1:27017 -> 127.0.0.1:40831 #####
....'...t...........................s....apikey.....ak0..token.....tk0..entity_type.......resource...../iot/d..service.....fiware..service_path...../..
##### 127.0.0.1:40823 -> 127.0.0.1:27017 #####
v...u...............iot.DEVICE.........A....device_id.....D000..service.....fiware..service_path...../......._id......
##### 127.0.0.1:27017 -> 127.0.0.1:40823 #####
A...(...u................................device_id.....D000..entity_name.....D000..entity_type.......protocol.....PDI-IoTA-UltraLight..attributes......0.?....object_id.....t0..name.
...Temperature0..type.....Number...1.<....object_id.....h0..name.
...Humidity0..type.....Number....service.....fiware..service_path...../..

##### ::1:34494 -> ::1:1026 #####
POST /v1/updateContext HTTP/1.1
X-Auth-Token: tk0
Fiware-ServicePath: /
Connection: close
Fiware-Service: fiware
Host: localhost:1026
Content-Length: 331
Accept: application/json
Content-Type: application/json

{"updateAction":"APPEND","contextElements":[{"id":"D000","type":"thing","isPattern":"false","attributes":[{"name":"Temperature0","type":"Number","value":"4","metadatas":[{"name":"TimeInstant","type":"ISO8601","value":"2016-02-29T14:57:34.858881Z"}]},{"name":"TimeInstant","type":"ISO8601","value":"2016-02-29T14:57:34.858881Z"}]}]}
##### ::1:1026 -> ::1:34494 #####
HTTP/1.1 200 OK
Connection: close
Content-Length: 723
Content-Type: application/json
Date: Mon, 29 Feb 2016 14:57:34 GMT

{
"contextResponses" : [
{
"contextElement" : {
"type" : "thing",
"isPattern" : "false",
"id" : "D000",
"attributes" : [
{
"name" : "Temperature0",
"type" : "Number",
"value" : "",
"metadatas" : [
{
"name" : "TimeInstant",
"type" : "ISO8601",
"value" : "2016-02-29T14:57:34.858881Z"
}
]
},
{
"name" : "TimeInstant",
"type" : "ISO8601",
"value" : ""
}
]
},
"statusCode" : {
"code" : "200",
"reasonPhrase" : "OK"
}
}
]
}

##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
l...,...............orion.entities.........A...._id.id.....D000.._id.type.....thing.._id.servicePath.^\/$...
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
....)...,...........................f...._id.5....id.....D000..type.....thing..servicePath...../...attrNames.=....0.....TimeInstant..1.
...Temperature0..2.
...Humidity0...attrs......TimeInstant.X....value.....2016-02-29T12:30:14.140066Z..type.....ISO8601..creDate..(.V.modDate..9.V..Temperature0......value.....3..type.....Number..md.\....0.T....name.....TimeInstant..type.....ISO8601..value.....2016-02-29T12:30:14.140066Z....creDate..).V.modDate..Z.V..Humidity0......value.....41..type.....Number..md.\....0.T....name.....TimeInstant..type.....ISO8601..value.....2016-02-28T14:11:27.896331Z....creDate..).V.modDate....V...creDate..(.V.modDate..Z.V. ##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
....-...............orion.$cmd..............update. ...entities..updates......0......q.?...._id.id.....D000.._id.type.....thing.._id.servicePath.\/....u.T....$set......attrs.Temperature0......value.....4..type.....Number..md.\....0.T....name.....TimeInstant..type.....ISO8601..value.....2016-02-29T14:57:34.858881Z....creDate..).V.modDate.^\.V..attrs.TimeInstant.X....value.....2016-02-29T14:57:34.858881Z..type.....ISO8601..creDate..(.V.modDate.^\.V..modDate.^\.V..$unset......location........multi...upsert.....ordered...writeConcern.......
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
G...*...-...........................#....ok......nModified......n......
##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
K...................orion.csubs.........#....conditions.type. ...ONCHANGE..
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
....+...................................._id.V..:..KO.....expiration..'.X.....reference.....http://localhost:5050/notify..throttling..........servicePath...../..entities./....0.'....id.....D000..isPattern.....false....attrs.*....0.
...Temperature0..1.
...Humidity0...conditions.Q....0.I....type. ...ONCHANGE..value.*....0.
...Temperature0..1.
...Humidity0.....expression.6....q.......geometry.......coords.......georel........lastNotification..Z.V.....count..........format.....XML..
##### 127.0.0.1:40671 -> 127.0.0.1:27017 #####
K.../...............orion.csubs.........#....conditions.type. ...ONCHANGE..
##### 127.0.0.1:27017 -> 127.0.0.1:40671 #####
....,.../................................_id.V..:..KO.....expiration..'.X.....reference.....http://localhost:5050/notify..throttling..........servicePath...../..entities./....0.'....id.....D000..isPattern.....false....attrs.*....0.
...Temperature0..1.
...Humidity0...conditions.Q....0.I....type. ...ONCHANGE..value.*....0.
...Temperature0..1.
...Humidity0.....expression.6....q.......geometry.......coords.......georel........lastNotification..Z.V.....count..........format.....XML..

EDIT:

This is the subscription info:

    {
    "id": "56d2f43a919d4b4fe286b100",
    "expires": "2017-02-27T13:20:58.00Z",
    "status": "active",
    "subject": {
        "entities": [{
            "id": "D000",
            "idPattern": "",
            "type": ""
        }],
        "condition": {
            "attributes": ["Temperature0", "Humidity0"],
            "expression": {
                "q": "",
                "geometry": "",
                "coords": "",
                "georel": ""
            }
        }
    },
    "notification": {
        "callback": "http://localhost:5050/notify",
        "throttling": 1,
        "timesSent": 8,
        "lastNotification": "2016-03-04T18:28:46.00Z",
        "attributes": ["Temperature0", "Humidity0"]
    }
}

EDIT:

Another useful information:

# ps aux | grep contextBroker
orion     2310  0.0  0.1 444700  5488 ?        Ssl  Mar10   0:03 /usr/bin/contextBroker -port 1026 -logDir /var/log/contextBroker -pidpath /var/run/contextBroker/contextBroker.pid -dbhost localhost -db orion -logLevel INFO
root     20648  0.0  0.0 103328   896 pts/0    S+   13:27   0:00 grep contextBroker

# echo 'show dbs' | mongo --quiet
iot    0.000GB
local  0.000GB
orion  0.000GB

Thanks.

2
fiwarefiware-orionfiware-cygnus
Maybe editing the question to include the notification message sent in one case in the other (e.g. captured using Wireshark) could help, please. – fgalan
After editing your post (thanks!) I see the notification sent from Orion to Cygnus in the case of updating Orion directly. However, I cannot see the notification sent from Orion to Cygnus in the case of using IoTAgent (on the contrary, the captured flow seems to be just the interaction between IoTAgent and Orion, but that is not piece of information I need to compare with the notification in the other case). – fgalan
I think that is exactly the problem. Now I have more entities, devices, etc. and I realize that both the log and the packet capture with wireshark have still the same messages sequence. I don't know why but when the updateContext comes from IoTAgent, the function:lmTransactionStart with "Starting transaction to localhost:5050/notify" doesn't rises or appear. But if I update Orion directly, it perfectly throws the notification. – cpuigaei
So, this part in the original post "The agent forward correctly the value to the contextBroker, and it is updated in his mongo DB. In this case the onchange subscription raise the notification to cygnus but it doesn't send the value to the MySQL database" is not correct? (as in this case, as far as I understand by your last comment, in the IoTAgent-CB scenario, notifications are not being sent to Cygnus) – fgalan
Yes, the original is incorrect. I should have changed that, sorry.. I will do it now. After check the packet trace and the Cygnus log, I realized the problem isn't in Cygnus. You have understood well, the problem is in contextBroker that doesn't send or even start notifications to Cygnus (in the IoTAgent-CB scenario) – cpuigaei

2 Answers

1
votes

Verify Fiware-Service header in append requests.

  • directly to CB does not use this header, so its value is per default. See: srv=<default> | subsrv=/

  • when pass by the IoTAgent this header is Fiware-Service: fiware. See: srv=fiware | subsrv=/

If we assume that the subcription is in default service, only first case is notified

1
votes

The behaviour described by @pepe-pepito in his answer makes sense only in the case of using -multiservice. However, you are running CB without -multiservice enabled... so there is a bug in Orion. We have analized the problem and it happens only when subscriptions cache is enabled (we have created an issue to deail with it).

Thus, in summary, there are basically two solutions to this:

  • Create the subscription in the same service that IoTAgent is using to send updates (i.e. fiware).
  • Disable cache using the -noCache CLI switch.

EDIT: the bug in subscription cache has been recently fixed in develop branch. It will be available in Orion 1.1.0.