[ https://jira.fiware.org/browse/HELP-13323?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Fernando Lopez reassigned HELP-13323:
-------------------------------------
Assignee: Backlog Manager
> [fiware-stackoverflow] Notification from subscription does not notify specific domains
> --------------------------------------------------------------------------------------
>
> Key: HELP-13323
> URL: https://jira.fiware.org/browse/HELP-13323
> Project: Help-Desk
> Issue Type: Monitor
> Components: FIWARE-TECH-HELP
> Reporter: Backlog Manager
> Assignee: Backlog Manager
> Labels: fiware, fiware-orion
>
> Created question in FIWARE Q/A platform on 14-11-2017 at 13:11
> {color: red}Please, ANSWER this question AT{color} 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: { $in: [ /^/howto$/ ] } })
> 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: { $in: [ /^/howto$/ ] } }, { $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: { $in: [ /^/howto$/ ] } })
> 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: { $in: [ /^/howto$/ ] } }, { $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: { servicePath: "/howto" }, 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.
--
This message was sent by Atlassian JIRA
(v6.4.1#64016)
You can get more information about our cookies and privacy policies clicking on the following links: Privacy policy Cookies policy