Hello Daniel, Just checking if you got what you were looking for. Do let me know if you need more info on the same.
Thanks, - Jayesh On Tue, Sep 22, 2015 at 8:23 PM Jayesh Nambiar <jayesh1...@gmail.com> wrote: > Hi, > Here's the NGREP trace where > {"event":"REGISTER","tindex":"3639","tlabel":"1889788252" > ... is present on the first line itself. > > 198.24.63.45:48886 -> 198.24.63.39:3927 [AP] > > 146:{"event":"REGISTER","tindex":"3639","tlabel":"1889788252","PhoneNumber":"42008","DeviceId":"abcd1234abcd1234","CallId":" > 11542-19872@198.24.63.39 > "},147:{"event":"REGISTER","tindex":"12600","tlabel":"1916422130","PhoneNumber":"42009","DeviceId":"abcd1234abcd1234","CallId":" > 11543-19872@198.24.63.39 > "},147:{"event":"REGISTER","tindex":"51251","tlabel":"1549871937","PhoneNumber":"42010","DeviceId":"abcd1234abcd > 1234","CallId":"11544-19872@198.24.63.39 > "},147:{"event":"REGISTER","tindex":"60213","tlabel":"2100336684","PhoneNumber":"42011","DeviceId":"abcd1234abcd1234","CallId":" > 11545-19872@198.24.63.39"},146:{"event > > ":"REGISTER","tindex":"33328","tlabel":"622251552","PhoneNumber":"42012","DeviceId":"abcd1234abcd1234","CallId":" > 11546-19872@198.24.63.39 > "},147:{"event":"REGISTER","tindex":"42289","tlabel":"1360864805","PhoneNumber":"42013","DeviceId":"abcd1234abcd1234","CallId":" > 11547-19872@198.24.63.39 > "},146:{"event":"REGISTER","tindex":"48204","tlabel":"315887672","PhoneNumber":"42014","DeviceId":"abcd1234abcd1234","CallId":" > 11548-19872@198.24.63.39 > "},145:{"event":"REGISTER","tindex":"36682","tlabel":"18660440","PhoneNumber":"42015","DeviceId":"abcd1234abcd1234","CallId":" > 11549-19872@198.24.63.39"}, > > And yes, this packet is right after the second packet in the pastebin > trace. > > Thanks, > > - Jayesh > > > > On Tue, Sep 22, 2015 at 5:03 PM Daniel-Constantin Mierla < > mico...@gmail.com> wrote: > >> Hello, >> >> I haven't seen in the ngrep when the data containing next line is >> received: >> >> {"event":"REGISTER","tindex":"3639","tlabel":"1889788252" ... >> >> Do you still have it? Is it after: >> >> {"event":"REGISTER","tindex":"12603","tlabel":"626010915", ... >> >> Cheers, >> Daniel >> >> >> On 22/09/15 09:09, Jayesh Nambiar wrote: >> >> Hi, >> Took time to get back with the test results as I was trying to analyze >> too much myself before getting back on the list. Also I was stuck with >> weird error of module version mismatch, but I figured and solved that issue. >> So I do see the logs "frame size mismatch" when I miss the events. Since >> the logs are too huge, I am sending it in pastebin. Here it is: >> http://pastebin.com/MzTpYsrk >> >> In Kamailio Logs, I see: >> DEBUG: evapi [evapi_dispatch.c:361]: evapi_recv_client(): frame size >> mismatch the ending char >> (h):[{"event":"REGISTER","tindex":"12603","tlabel":"626010915 >> ","PhoneNumber":"42000","D146:"event":"REGISTER","tindex":"3639","tlabel":" >> 1889788252","P] (146) >> >> Whereas the messages in ngrep looks good where the messages are split in >> two TCP packets. The first packet ends at D and the second packet is the >> proper continuation which send the rest. But it feels Kamailio skipped the >> beginning of the message and started parsing at colon again and it thinks >> the netstring started with D146 which is incorrect. Hence, it never emitted >> any event for the messages in the first chunk. >> >> Hoping this to be helpful !! Thanks. >> >> - Jayesh >> >> >> On Mon, Sep 21, 2015 at 4:37 PM Daniel-Constantin Mierla < >> mico...@gmail.com> wrote: >> >>> Hello, >>> >>> I pushed another commit to add more debug messages to see if the event >>> route is supposed to be executed or not. Can you run the tests again and >>> give again the log messages for missing event route executions? >>> >>> Cheers, >>> Daniel >>> >>> >>> On 21/09/15 09:04, Jayesh Nambiar wrote: >>> >>> Hi Daniel, >>> I have captured debug messages after testing with your latest commit on >>> master. Once again, here's what I'm doing exactly for my test: >>> 1) Use SIPp to send OPTIONS towards Kamailio. >>> 2) On getting options send event as follows: >>> >>> evapi_async_relay("{\"event\":\"REGISTER\",\"tindex\":\"$T(id_index)\",\"tlabel\":\"$T(id_label)\",\"PhoneNumber\":\"$avp(phone_number)\",\"DeviceId\":\"$avp(device_id)\",\"CallId\":\"$ci\"}"); >>> 3) There's a client connected which listens for messages on this socket, >>> parses the netstring, and sends same data back as netstring to Kamailio. >>> 4) On the event_route[evapi:message-received, I do the following: >>> xlog("L_INFO", "GOT [$evapi(msg)] from >>> $evapi(srcaddr):$evapi(srcport)\n"); >>> if($evapi(msg)=~"REGISTER" && $evapi(msg)=~"tindex") { >>> jansson_get_field("$evapi(msg)", "tlabel", "$var(tlabel)"); >>> jansson_get_field("$evapi(msg)", "tindex", "$var(tindex)"); >>> $var(t_index) = $(var(tindex){s.int}); >>> $var(t_label) = $(var(tlabel){s.int}); >>> t_continue('$var(t_index)', '$var(t_label)', >>> 'REGISTER_RESPONSE'); >>> exit; >>> } >>> 5) On route[REGISTER_RESPONSE], I send 200 OK to SIPp >>> >>> Now here are detailed logs for which neither SIPp didnt get a response >>> nor the GOT [$evapi(msg)] from $evapi(srcaddr):$evapi(srcport)\n"); got >>> logged in the syslog: >>> >>> First Event: >>> DEBUG: evapi [evapi_dispatch.c:598]: evapi_relay(): relaying event data >>> [{"event":"REGISTER","tindex":"26266","tlabel":"587925078","PhoneNumber":"21956","DeviceId":"abcd1234abcd1234","CallId":" >>> 23021-12910@198.24.63.39"}] (146) >>> DEBUG: evapi [evapi_dispatch.c:623]: evapi_relay(): sending >>> [0x7f132588de68] >>> [146:{"event":"REGISTER","tindex":"26266","tlabel":"587925078","PhoneNumber":"21956","DeviceId":"abcd1234abcd1234","CallId":" >>> 23021-12910@198.24.63.39"},] (151) >>> >>> DEBUG: evapi [evapi_dispatch.c:488]: evapi_recv_notify(): received >>> [0x7f132588de68] >>> [146:{"event":"REGISTER","tindex":"26266","tlabel":"587925078","PhoneNumber":"21956","DeviceId":"abcd1234abcd1234","CallId":" >>> 23021-12910@198.24.63.39"},] (151) >>> NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [ >>> 198.24.63.45:48881] - received >>> [146:{"event":"REGISTER","tindex":"26266","tlabel":"587925078","PhoneNumber":"21956","DeviceId":"abcd1234abcd1234","CallId":" >>> 23021-12910@198.24.63.39"},] (151) (18) >>> >>> Second Event: >>> DEBUG: evapi [evapi_dispatch.c:598]: evapi_relay(): relaying event data >>> [{"event":"REGISTER","tindex":"32244","tlabel":"1637923412","PhoneNumber":"25597","DeviceId":"abcd1234abcd1234","CallId":" >>> 27182-12910@198.24.63.39"}] (147) >>> DEBUG: evapi [evapi_dispatch.c:623]: evapi_relay(): sending >>> [0x7f1325884410] >>> [147:{"event":"REGISTER","tindex":"32244","tlabel":"1637923412","PhoneNumber":"25597","DeviceId":"abcd1234abcd1234","CallId":" >>> 27182-12910@198.24.63.39"},] (152) >>> >>> DEBUG: evapi [evapi_dispatch.c:488]: evapi_recv_notify(): received >>> [0x7f1325884410] >>> [147:{"event":"REGISTER","tindex":"32244","tlabel":"1637923412","PhoneNumber":"25597","DeviceId":"abcd1234abcd1234","CallId":" >>> 27182-12910@198.24.63.39"},] (152) >>> NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [ >>> 198.24.63.45:48881] - received >>> [147:{"event":"REGISTER","tindex":"32244","tlabel":"1637923412","PhoneNumber":"25597","DeviceId":"abcd1234abcd1234","CallId":" >>> 27182-12910@198.24.63.39"},] (152) (85) >>> >>> I had three such events which got missed out of some 25000 odd messages >>> sent from SIPp. Other major difference that I see in the debug logs for >>> problematic events are that there is a positive number in the second >>> parentheses of evapi_recv_client() function. For the events that were >>> invoked successfully the value of second parentheses is 0 for >>> evapi_recv_client() function. Hope the debugging helps. >>> >>> Debug log for a successful event: >>> DEBUG: evapi [evapi_dispatch.c:598]: evapi_relay(): relaying event data >>> [{"event":"REGISTER","tindex":"22127","tlabel":"1896682192","PhoneNumber":"73168","DeviceId":"abcd1234abcd1234","CallId":" >>> 49957-13056@198.24.63.39"}] (147) >>> DEBUG: evapi [evapi_dispatch.c:623]: evapi_relay(): sending >>> [0x7f132568e850] >>> [147:{"event":"REGISTER","tindex":"22127","tlabel":"1896682192","PhoneNumber":"73168","DeviceId":"abcd1234abcd1234","CallId":" >>> 49957-13056@198.24.63.39"},] (152) >>> >>> DEBUG: evapi [evapi_dispatch.c:488]: evapi_recv_notify(): received >>> [0x7f132568e850] >>> [147:{"event":"REGISTER","tindex":"22127","tlabel":"1896682192","PhoneNumber":"73168","DeviceId":"abcd1234abcd1234","CallId":" >>> 49957-13056@198.24.63.39"},] (152) >>> NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [ >>> 198.24.63.45:48881] - received >>> [147:{"event":"REGISTER","tindex":"22127","tlabel":"1896682192","PhoneNumber":"73168","DeviceId":"abcd1234abcd1234","CallId":" >>> 49957-13056@198.24.63.39"},] (152) (0) >>> >>> Thanks, >>> >>> - Jayesh >>> On Sat, Sep 19, 2015 at 3:55 AM Daniel-Constantin Mierla < >>> mico...@gmail.com> wrote: >>> >>>> I pushed a commit to add more debug message while processing received >>>> data. You can use debugger module to set a higher debug level for evapi >>>> module in order to see what happens. >>>> >>>> I checked the netstring packet size and it is invalid (unless email >>>> stripped some white chars there) -- for example in: >>>> >>>> >>>> >>>> 145:{"event":"REGISTER","tindex":"55567","tlabel":"627458699","PhoneNumber":"20711","DeviceId":"abcd1234abcd1234","CallId": >>>> "21225-3848@5.6.7.8" <21225-3848@5.6.7.8> <21225-3848@5.6.7.8>}, >>>> >>>> the size is 141, not 145 -- it looks like the size includes the size >>>> itself plus the delimiters ':,'. The size is only the effective data, see: >>>> >>>> https://en.wikipedia.org/wiki/Netstring >>>> >>>> If evapi gets a packet with an invalid size, then it discards the >>>> buffer content. >>>> >>>> See if the app on the other side of evapi connection builds netstrings >>>> with wrong size. >>>> >>>> Cheers, >>>> Daniel >>>> >>>> >>>> On 18/09/15 23:19, Jayesh Nambiar wrote: >>>> >>>> Here are the tests that I did: >>>> >>>> With the patch applied, I see that Kamailio is invoking event >>>> individually for each netstring even when they come in different chunks. >>>> But I did see instances where when there were complete netstrings in a >>>> single chunk; kamailio did not raise an event for them. Here's the >>>> illustration: >>>> >>>> T 1.2.3.4:48873 -> 5.6.7.8:3927 [AP] >>>> >>>> 146:{"event":"REGISTER","tindex":"16916","tlabel":"1753048277","PhoneNumber":"20708","DeviceId":"abcd1234abcd1234","CallId":" >>>> 21220-3848@5.6.7.8 >>>> "},144:{"event":"REGISTER","tindex":"7954","tlabel":"254315075","PhoneNumber":"20709","DeviceId":"abcd1234abcd1234","CallId":" >>>> 21223-3848@5.6.7.8 >>>> "},145:{"event":"REGISTER","tindex":"64529","tlabel":"599481568","PhoneNumber":"20709","DeviceId":"abcd1234abcd1234","CallId":" >>>> 21222-3848@5.6.7.8"},145:{"event":"REGISTER","tindex":"46605","tlabel":"112015324","PhoneNumber":"20710","DeviceId" >>>> >>>> >>>> >>>> >>>> T 1.2.3.4:48873 -> 5.6.7.8:3927 [AP] >>>> :"abcd1234abcd1234","CallId":"21224-3848@5.6.7.8"}, >>>> >>>> *The above two chunks contain 4 proper netstrings where the second >>>> chunk contains part of the 4th netstring. In this case Evapi properly >>>> raised 4 individual events.* >>>> >>>> 1.2.3.4:48873 -> 5.6.7.8:3927 [AP] >>>> >>>> 145:{"event":"REGISTER","tindex":"55567","tlabel":"627458699","PhoneNumber":"20711","DeviceId":"abcd1234abcd1234","CallId":" >>>> 21225-3848@5.6.7.8 >>>> "},143:{"event":"REGISTER","tindex":"28682","tlabel":"9676691","PhoneNumber":"20712","DeviceId":"abcd1234abcd1234","CallId":" >>>> 21226-3848@5.6.7.8"}, >>>> >>>> *This above chunk contains two complete netstrings but Kamailio never >>>> raised events for these two netstrings.* >>>> >>>> For the events that were not raised I see proper Kamailio Logs which is: >>>> evapi_recv_client(): {0} [1.2.3.4:48873] - received >>>> [145:{"event":"REGISTER","tindex":"55567","tlabel":"627458699","PhoneNumber":"20711","DeviceId":"abcd1234abcd1234","CallId":" >>>> 21225-3848@5.6.7.8 >>>> "},143:{"event":"REGISTER","tindex":"28682","tlabel":"9676691","PhoneNumber":"20712","DeviceId":"abcd1234abcd1234","CallId":" >>>> 21226-3848@5.6.7.8"},] >>>> >>>> But I don't see the logs that I've written in the script after the >>>> event was raised, which means Kamailio did not invoke events for these two >>>> netstrings. >>>> >>>> So in my tests, out of 27232 messages sent, there were approximately 27 >>>> messages for which the events were not raised by Evapi. The rate of >>>> messages started at 500cps and I stopped after I saw missed events at >>>> around 1200cps. >>>> >>>> Thanks, and do let me know for any further tests or information >>>> required about the same. >>>> >>>> - Jayesh >>>> >>>> >>>> >>>> On Fri, Sep 18, 2015 at 2:55 PM, Jayesh Nambiar <jayesh1...@gmail.com> >>>> wrote: >>>> >>>>> Will have this tested by tomorrow and will get back to you. Thanks. >>>>> >>>>> - Jayesh >>>>> >>>>> On Fri, Sep 18, 2015 at 1:41 PM, Daniel-Constantin Mierla < >>>>> mico...@gmail.com> wrote: >>>>> >>>>>> Hello, >>>>>> >>>>>> I just pushed a patch to master branch that should cope with partial >>>>>> data received on tcp connection. No time to test at all, therefore any >>>>>> feedback will be appreciated. >>>>>> >>>>>> Cheers, >>>>>> Daniel >>>>>> >>>>>> >>>>>> On 15/09/15 14:52, Daniel-Constantin Mierla wrote: >>>>>> >>>>>> Hello, >>>>>> >>>>>> I will look if there are options in libev to buffer data or try to >>>>>> implement a buffering mechanism locally for such cases. >>>>>> >>>>>> Cheers, >>>>>> Daniel >>>>>> >>>>>> On 14/09/15 23:00, Jayesh Nambiar wrote: >>>>>> >>>>>> Hello Daniel, >>>>>> After further testing with evapi module, I figured that when >>>>>> Netstrings are used, an event route is invoked individually for each >>>>>> message even if if multiple netstring messages are received in a single >>>>>> TCP >>>>>> packet. But this doesn't work effectively when a single proper message is >>>>>> split-up in two packets. For Example, if a message arrives as: >>>>>> 12:Hello World!, 12:Hello World!, 12:Hello World! in a single packet, >>>>>> kamailio properly invokes the event route "evapi:message-received" thrice >>>>>> for every individual proper netstring message. >>>>>> But if the first packet contains: >>>>>> 12:Hello World!, 12:Hello >>>>>> And Second Packet contains: >>>>>> World!, 12:Hello World! >>>>>> the event route is invoked only once !! >>>>>> >>>>>> The above pattern is very much possible while sending and receiving >>>>>> packets over TCP Socket. Our tests for receiving an approximately 150 >>>>>> byte >>>>>> message over evapi socket at the rate of roughly 1000cps causes a lot of >>>>>> real events to be missed because of the above problem. You can never be >>>>>> sure when TCP will split messages in different chunks. >>>>>> This definitely looks like a bug which makes it not very reliable at >>>>>> large scale deployments. Would really appreciate your inputs on this. >>>>>> Thanks; >>>>>> >>>>>> - Jayesh >>>>>> >>>>>> >>>>>> >>>>>> On Thu, Sep 10, 2015 at 4:01 PM, Jayesh Nambiar <jayesh1...@gmail.com >>>>>> > wrote: >>>>>> >>>>>>> Hi Daniel, >>>>>>> Thanks for the quick response. So if I do not use Netstrings, does >>>>>>> Kamailio allow me to create a custom logic in the script. For eg. if I >>>>>>> decide to use newline as a delimiter, can I keep buffering the message >>>>>>> until I encounter the delimiter from the event route and then execute >>>>>>> whatever I have to within the script?? >>>>>>> >>>>>>> Thanks, >>>>>>> >>>>>>> - Jayesh >>>>>>> >>>>>>> On Thu, Sep 10, 2015 at 1:29 PM, Daniel-Constantin Mierla < >>>>>>> mico...@gmail.com> wrote: >>>>>>> >>>>>>>> Hello, >>>>>>>> >>>>>>>> tcb is stream protocol and several messages can be queued on the >>>>>>>> pipe at the same time. That is the reason for netstring format, to be >>>>>>>> able >>>>>>>> to easily detect the boundaries of each message. If netstring format is >>>>>>>> enabled and kamailio receives several messages at once, it splits them >>>>>>>> and >>>>>>>> for each is executing the event route. >>>>>>>> >>>>>>>> If netstring format is not used, the kamailio is executing the >>>>>>>> event route with the entire content that was read at once from the tcp >>>>>>>> connection. >>>>>>>> >>>>>>>> Cheers, >>>>>>>> Daniel >>>>>>>> >>>>>>>> >>>>>>>> On 09/09/15 22:01, Jayesh Nambiar wrote: >>>>>>>> >>>>>>>> Hello, >>>>>>>> I'm exploring the evapi module for my kamailio to interface with an >>>>>>>> external node.js app for third party stuff like AAA, billing engine >>>>>>>> tasks, >>>>>>>> notifications and so on. I followed and took some ideas from the >>>>>>>> rtjson and >>>>>>>> evapi tutorial found here( >>>>>>>> http://kb.asipto.com/kamailio:k43-async-sip-routing-nodejs) to >>>>>>>> build the node.js app consuming events. >>>>>>>> When I stress tested the scenario using SIPp and tried sending a >>>>>>>> lot of events at 300-350cps from Kamailio, I noticed that at times the >>>>>>>> client is receiving 2-3 events in a single message together although I >>>>>>>> do >>>>>>>> event_sync_relay once per SIP message received and have netstrings >>>>>>>> enabled. >>>>>>>> I believe this is a typical behavior of TCP and needs to be handled by >>>>>>>> the >>>>>>>> client using some kind of Netstring handler. Please correct me if I'm >>>>>>>> wrong. >>>>>>>> And hence I'd like to know what particularly needs to be taken care >>>>>>>> of while writing a client that is listening for events on raw tcp >>>>>>>> socket >>>>>>>> and how does kamailio handle this situation while receiving messages >>>>>>>> over >>>>>>>> TCP socket?? Does kamailio recognize the end of netstring properly on >>>>>>>> evapi:message-received and give exactly one message to take care of on >>>>>>>> every "message-received" event or should that be handled in the script >>>>>>>> somewhere !! >>>>>>>> I also referred cgrates client over evapi example which is written >>>>>>>> in GO, but I couldnt find them handling TCP streams clearly either. >>>>>>>> I'd really appreciate some expert suggestion here to make an >>>>>>>> informed decision on using the evapi module for a large scale solution. >>>>>>>> >>>>>>>> Thanks, >>>>>>>> >>>>>>>> - Jayesh >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> _______________________________________________ >>>>>>>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing >>>>>>>> listsr-us...@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users >>>>>>>> >>>>>>>> >>>>>>>> -- >>>>>>>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - >>>>>>>> http://www.linkedin.com/in/miconda >>>>>>>> Book: SIP Routing With Kamailio - http://www.asipto.com >>>>>>>> Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - >>>>>>>> http://asipto.com/u/kat >>>>>>>> >>>>>>>> >>>>>>>> _______________________________________________ >>>>>>>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing >>>>>>>> list >>>>>>>> sr-users@lists.sip-router.org >>>>>>>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users >>>>>>>> >>>>>>>> >>>>>>> >>>>>> >>>>>> -- >>>>>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - >>>>>> http://www.linkedin.com/in/miconda >>>>>> Book: SIP Routing With Kamailio - http://www.asipto.com >>>>>> Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - >>>>>> http://asipto.com/u/kat >>>>>> >>>>>> >>>>>> -- >>>>>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - >>>>>> http://www.linkedin.com/in/miconda >>>>>> Book: SIP Routing With Kamailio - http://www.asipto.com >>>>>> Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - >>>>>> http://asipto.com/u/kat >>>>>> >>>>>> >>>>> >>>> >>>> -- >>>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - >>>> http://www.linkedin.com/in/miconda >>>> Book: SIP Routing With Kamailio - http://www.asipto.com >>>> Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - >>>> http://asipto.com/u/kat >>>> >>>> >>> -- >>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - >>> http://www.linkedin.com/in/miconda >>> Book: SIP Routing With Kamailio - http://www.asipto.com >>> Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - >>> http://asipto.com/u/kat >>> >>> >> -- >> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - >> http://www.linkedin.com/in/miconda >> Book: SIP Routing With Kamailio - http://www.asipto.com >> Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - >> http://asipto.com/u/kat >> >>
_______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users