Details
-
Type: Monitor
-
Status: Closed
-
Priority: Major
-
Resolution: Done
-
Affects Version/s: None
-
Fix Version/s: 2021
-
Component/s: FIWARE-TECH-HELP
-
Labels:
-
HD-Enabler:Orion
Description
Created question in FIWARE Q/A platform on 14-11-2017 at 13:11
Please, ANSWER this question AT https://stackoverflow.com/questions/47286499/notification-from-subscription-does-not-notify-specific-domains
Question:
Notification from subscription does not notify specific domains
Description:
We are migrating from one pre-production platform on the cloud to another server. We have successfully migrated everything but something strange is happening with the subscriptions of Orion Context Broker, since our instance of Orion is successfully notifying different endpoints, but not the one from our platform.
Both of the subscriptions are done from the same instance and implementing HTTPS, and the security groups are equally configured. The Orion context broker logs doesnt show any useful information about what is happening with the cURL request that internally is doing.
Here is an example of a right subscription from this Orion:
time=Tuesday 14 Nov 12:54:03 2017.102Z | lvl=INFO | corr=e42533b2-c93a-11e7-b333-0242ac110003 | trans=1510663280-019-00000000009 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1832]:lmTransactionStart | msg=Starting transaction from 54.194.53.34:48920/v1/updateContext
time=Tuesday 14 Nov 12:54:03 2017.102Z | lvl=INFO | corr=e42533b2-c93a-11e7-b333-0242ac110003 | trans=1510663280-019-00000000009 | from=54.194.53.34 | srv=pending | subsrv=/howto | comp=Orion | op=rest.cpp[882]:servicePathSplit | msg=Service Path 0: '/howto'
time=Tuesday 14 Nov 12:54:03 2017.103Z | lvl=INFO | corr=e42533b2-c93a-11e7-b333-0242ac110003 | trans=1510663280-019-00000000009 | from=54.194.53.34 | srv=howtoservice | subsrv=/howto | comp=Orion | op=connectionOperations.cpp[92]:collectionQuery | msg=Database Operation Successful (query: { _id.id: "M1111", _id.type: "Thing", _id.servicePath:
})
time=Tuesday 14 Nov 12:54:03 2017.104Z | lvl=INFO | corr=e42533b2-c93a-11e7-b333-0242ac110003 | trans=1510663280-019-00000000009 | from=54.194.53.34 | srv=howtoservice | subsrv=/howto | comp=Orion | op=connectionOperations.cpp[447]:collectionUpdate | msg=Database Operation Successful (update: <{ _id.id: "M1111", _id.type: "Thing", _id.servicePath:
}, { $set: { attrs.local: { value: "1.1.1.1,50", type: "string", md: { TimeInstant:
{ type: "ISO8601", value: "2017-11-14T12:54:03.090Z" }}, mdNames: [ "TimeInstant" ], creDate: 1510662361, modDate: 1510664043 }, attrs.serial_number: { value: "M1111", type: "string", md: { TimeInstant:
{ type: "ISO8601", value: "2017-11-14T12:54:03.090Z" }}, mdNames: [ "TimeInstant" ], creDate: 1510662361, modDate: 1510664043 }, attrs.TimeInstant:
{ value: "2017-11-14T12:54:03.090Z", type: "ISO8601", mdNames: [], creDate: 1510662361, modDate: 1510664043 }, modDate: 1510664043, lastCorrelator: "e42533b2-c93a-11e7-b333-0242ac110003" }, $unset:
{ location: 1 } }>)
time=Tuesday 14 Nov 12:54:03 2017.104Z | lvl=INFO | corr=e42533b2-c93a-11e7-b333-0242ac110003 | trans=1510663280-019-00000000009 | from=54.194.53.34 | srv=howtoservice | subsrv=/howto | comp=Orion | op=logMsg.h[1916]:lmTransactionEnd | msg=Transaction ended
time=Tuesday 14 Nov 12:54:03 2017.105Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000010 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1832]:lmTransactionStart | msg=Starting transaction to https://visualfy.secmotic.com:443/api/v1/devices/orion/local
time=Tuesday 14 Nov 12:54:03 2017.105Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000010 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=httpRequestSend.cpp[599]:httpRequestSendWithCurl | msg=Sending message 2 to HTTP server: sending message of 540 bytes to HTTP server
time=Tuesday 14 Nov 12:54:03 2017.238Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000010 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=httpRequestSend.cpp[620]:httpRequestSendWithCurl | msg=Notification Successfully Sent to https://visualfy.secmotic.com:443/api/v1/devices/orion/local
time=Tuesday 14 Nov 12:54:03 2017.239Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000010 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1916]:lmTransactionEnd | msg=Transaction ended
And here is an example of a failed notification.
time=Tuesday 14 Nov 12:55:13 2017.809Z | lvl=INFO | corr=0e4a4e20-c93b-11e7-957f-0242ac110003 | trans=1510663280-019-00000000012 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1832]:lmTransactionStart | msg=Starting transaction from 54.194.53.34:48922/v1/updateContext
time=Tuesday 14 Nov 12:55:13 2017.810Z | lvl=INFO | corr=0e4a4e20-c93b-11e7-957f-0242ac110003 | trans=1510663280-019-00000000012 | from=54.194.53.34 | srv=pending | subsrv=/howto | comp=Orion | op=rest.cpp[882]:servicePathSplit | msg=Service Path 0: '/howto'
time=Tuesday 14 Nov 12:55:13 2017.810Z | lvl=INFO | corr=0e4a4e20-c93b-11e7-957f-0242ac110003 | trans=1510663280-019-00000000012 | from=54.194.53.34 | srv=howtoservice | subsrv=/howto | comp=Orion | op=connectionOperations.cpp[92]:collectionQuery | msg=Database Operation Successful (query: { _id.id: "M1111", _id.type: "Thing", _id.servicePath:
})
time=Tuesday 14 Nov 12:55:13 2017.811Z | lvl=INFO | corr=0e4a4e20-c93b-11e7-957f-0242ac110003 | trans=1510663280-019-00000000012 | from=54.194.53.34 | srv=howtoservice | subsrv=/howto | comp=Orion | op=connectionOperations.cpp[447]:collectionUpdate | msg=Database Operation Successful (update: <{ _id.id: "M1111", _id.type: "Thing", _id.servicePath:
}, { $set: { attrs.local: { value: "1.1.1.1,50", type: "string", md: { TimeInstant:
{ type: "ISO8601", value: "2017-11-14T12:55:13.800Z" }}, mdNames: [ "TimeInstant" ], creDate: 1510662361, modDate: 1510664113 }, attrs.serial_number: { value: "M1111", type: "string", md: { TimeInstant:
{ type: "ISO8601", value: "2017-11-14T12:55:13.800Z" }}, mdNames: [ "TimeInstant" ], creDate: 1510662361, modDate: 1510664113 }, attrs.TimeInstant:
{ value: "2017-11-14T12:55:13.800Z", type: "ISO8601", mdNames: [], creDate: 1510662361, modDate: 1510664113 }, modDate: 1510664113, lastCorrelator: "0e4a4e20-c93b-11e7-957f-0242ac110003" }, $unset:
{ location: 1 } }>)
time=Tuesday 14 Nov 12:55:13 2017.812Z | lvl=INFO | corr=0e4a4e20-c93b-11e7-957f-0242ac110003 | trans=1510663280-019-00000000012 | from=54.194.53.34 | srv=howtoservice | subsrv=/howto | comp=Orion | op=logMsg.h[1916]:lmTransactionEnd | msg=Transaction ended
time=Tuesday 14 Nov 12:55:13 2017.812Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000013 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1832]:lmTransactionStart | msg=Starting transaction to https://iot.visualfy.com:443/api/v1/devices/orion/local
time=Tuesday 14 Nov 12:55:13 2017.812Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000013 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=httpRequestSend.cpp[599]:httpRequestSendWithCurl | msg=Sending message 3 to HTTP server: sending message of 535 bytes to HTTP server
time=Tuesday 14 Nov 12:55:13 2017.891Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000013 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1916]:lmTransactionEnd | msg=Transaction ended
The subscription is the same with the http attribute changed to the endpoint.
Any help would be appreciated and if you need further information don't hesitate asking.
UPDATE 1
After shutting down the process in the 443 port and adding a listener, performing a netcat like: nc -l 443 has resulted in a notification arriving to netcat with a non readable data stream.
The orion context broker logs shows some interesting information:
time=Friday 17 Nov 11:05:56 2017.587Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000090 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1832]:lmTransactionStart | msg=Starting transaction to https://34.240.0.113:443/api/v1/devices/orion/local
time=Friday 17 Nov 11:05:56 2017.587Z | lvl=INFO | corr=N/A | trans=1510663280-019-00000000090 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=httpRequestSend.cpp[599]:httpRequestSendWithCurl | msg=Sending message 22 to HTTP server: sending message of 531 bytes to HTTP server
time=Friday 17 Nov 11:06:04 2017.153Z | lvl=INFO | corr=4da159ee-cb87-11e7-97f4-0242ac110003 | trans=1510663280-019-00000000091 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=logMsg.h[1832]:lmTransactionStart | msg=Starting transaction from 37.11.95.120:60933/v2/subscriptions
time=Friday 17 Nov 11:06:04 2017.154Z | lvl=INFO | corr=4da159ee-cb87-11e7-97f4-0242ac110003 | trans=1510663280-019-00000000091 | from=37.11.95.120 | srv=pending | subsrv=/howto | comp=Orion | op=rest.cpp[882]:servicePathSplit | msg=Service Path 0: '/howto'
time=Friday 17 Nov 11:06:04 2017.154Z | lvl=INFO | corr=4da159ee-cb87-11e7-97f4-0242ac110003 | trans=1510663280-019-00000000091 | from=37.11.95.120 | srv=howtoservice | subsrv=/howto | comp=Orion | op=connectionOperations.cpp[175]:collectionRangedQuery | msg=Database Operation Successful (query: { query:
, orderby:
{ _id: 1 } })
time=Friday 17 Nov 11:06:04 2017.155Z | lvl=INFO | corr=4da159ee-cb87-11e7-97f4-0242ac110003 | trans=1510663280-019-00000000091 | from=37.11.95.120 | srv=howtoservice | subsrv=/howto | comp=Orion | op=logMsg.h[1916]:lmTransactionEnd | msg=Transaction ended
time=Friday 17 Nov 11:06:04 2017.556Z | lvl=WARN | corr=N/A | trans=1510663280-019-00000000090 | from=pending | srv=pending | subsrv=pending | comp=Orion | op=AlarmManager.cpp[328]:notificationError | msg=Raising alarm NotificationError https://34.240.0.113:443/api/v1/devices/orion/local: (curl_easy_perform failed: SSL connect error)
Which has the same looking than the failed notification instead of the one that ended OK.
The same process to the service that is working, when the notification reachs netcat has more characters notifying. In other words, this is what I receive in the netcat that doesnt receive notifications correctly:
HD?#
??s???s0?^0M
c1\6?QSb?J3298/5
?
And this is what I receive in the netcat that receive the notifications OK:
?_??=?)>B??w{?d?O?އ?$V? ?bG??B?>?????
??O?[06?gZZ̨̩?+?/?,?0????/5
? ?&?ualfy.secmotic.com#?ۻ??f??s??? ir??b?;?!~?"-$?}?G?A?Ӎ8??ؽV?%2ߨ??B&?
?Wr?n?<=T?h?A{R?Ϛ?y??'L1??1????w"m?kY?oKl??5%'?["?X9??h?f?`?Hj?%mZ?{?I?ʤx??v???m??H?9?????Ƥf%
hhttp/1.1uP
????@^C
UPDATE 2
It is clear now that it is an HTTPS error with the notifications.
I have gone in the docker container where Orion Context Broker is and tried to perform a curl to the HTTPS domain, having the following output:
- About to connect() to iot.visualfy.com port 443 (#0)
- Trying 34.240.0.113... connected
- Connected to iot.visualfy.com (34.240.0.113) port 443 (#0)
- Initializing NSS with certpath: sql:/etc/pki/nssdb
- CAfile: /etc/pki/tls/certs/ca-bundle.crt
CApath: none - NSS error -5961
- Closing connection #0
- SSL connect error
curl: (35) SSL connect error
I actually tried to configure Orion as the documentation says with the -insecureNotif option, but the result is the same.
Activity
Field | Original Value | New Value |
---|---|---|
Component/s | FIWARE-TECH-HELP [ 10278 ] |
Status | Open [ 1 ] | In Progress [ 3 ] |
Resolution | Done [ 10000 ] | |
Status | In Progress [ 3 ] | Closed [ 6 ] |
Assignee | Backlog Manager [ backlogmanager ] |
HD-Enabler | Orion [ 10875 ] |
Fix Version/s | 2021 [ 12600 ] |