[SR-Users] evapi tcp parsing??

Tue Sep 29 13:13:41 CEST 2015

Hi Daniel:
I did a new test where I stopped as soon as I saw one message that got
discarded. Basically the following message got discarded:
{"event":"REGISTER","tindex":"52171","tlabel":"748030241","PhoneNumber":"11161","DeviceId":"abcd1234abcd1234","CallId":"
10943-15480 at 198.24.63.39"}
The CallId parameter in the above json is auto incremented, so I tried
gathering logs for messages with following CallIds:
"CallId":"10940-15480 at 198.24.63.39"
"CallId":"10941-15480 at 198.24.63.39"
"CallId":"10942-15480 at 198.24.63.39"
"CallId":"10943-15480 at 198.24.63.39"
"CallId":"10944-15480 at 198.24.63.39"
"CallId":"10945-15480 at 198.24.63.39"

And the message with CallID "CallId":"10943-15480 at 198.24.63.39" got
discarded.

Here's the bunch of kamailio logs printed by the evapi module:
*Logs for processed messages just before the discarded message:*
DEBUG: evapi [evapi_dispatch.c:492]: evapi_recv_notify(): received
[0x7f43da494ad0]
[146:{"event":"REGISTER","tindex":"61133","tlabel":"450961398","PhoneNumber":"11158","DeviceId":"abcd1234abcd1234","CallId":"
10940-15480 at 198.24.63.39"},] (151)

NOTICE: evapi_recv_client(): {0} [198.24.63.45:48905] - received
[147:{"event":"REGISTER","tindex":"25291","tlabel":"2047024302","PhoneNumber":"11132","DeviceId":"abcd1234abcd1234","CallId":"
10914-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"61136","tlabel":"839735223","PhoneNumber":"11148","DeviceId":"abcd1234abcd1234","CallId":"
10930-15480 at 198.24.63.39
"},143:{"event":"REGISTER","tindex":"4562","tlabel":"6586867","PhoneNumber":"11149","DeviceId":"abcd1234abcd1234","CallId":"
10931-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"43213","tlabel":"220429340","PhoneNumber":"11151","DeviceId":"abcd1234abcd1234","CallId":"
10932-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"52174","tlabel":"708781916","PhoneNumber":"11150","DeviceId":"abcd1234abcd1234","CallId":"
10933-15480 at 198.24.63.39
"},147:{"event":"REGISTER","tindex":"34251","tlabel":"1354642017","PhoneNumber":"11153","DeviceId":"abcd1234abcd1234","CallId":"
10935-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"7366","tlabel":"1368396808","PhoneNumber":"11154","DeviceId":"abcd1234abcd1234","CallId":"
10936-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"25289","tlabel":"119788881","PhoneNumber":"11152","DeviceId":"abcd1234abcd1234","CallId":"
10934-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"16327","tlabel":"971937029","PhoneNumber":"11155","DeviceId":"abcd1234abcd1234","CallId":"
10937-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"22242","tlabel":"609737074","PhoneNumber":"11156","DeviceId":"abcd1234abcd1234","CallId":"
10938-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"10720","tlabel":"930036340","PhoneNumber":"11157","DeviceId":"abcd1234abcd1234","CallId":"
10939-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"61133","tlabel":"450961398","PhoneNumber":"11158","DeviceId":"abcd1234abcd1234","CallId":"
10940-15480 at 198.24.63.39"},146:{"event":"REGISTER","tindex":"43210","tlabel":"639090568","PhoneNumber":"11160","Dev]
(1899) (0)

evapi_recv_client(): executing event route for frame:
[{"event":"REGISTER","tindex":"61133","tlabel":"450961398","PhoneNumber":"11158","DeviceId":"abcd1234abcd1234","CallId":"
10940-15480 at 198.24.63.39"}] (146)

Sep 29 05:35:14 v39 /usr/local/kamailio-dev/sbin/kamailio[15387]: DEBUG:
evapi [evapi_dispatch.c:492]: evapi_recv_notify(): received
[0x7f43da4b67e0]
[146:{"event":"REGISTER","tindex":"4559","tlabel":"1701553747","PhoneNumber":"11159","DeviceId":"abcd1234abcd1234","CallId":"
10941-15480 at 198.24.63.39"},] (151)

NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [
198.24.63.45:48905] - received [iceId":"abcd1234abcd1234","CallId":"
10942-15480 at 198.24.63.39
"},146:{"event":"REGISTER","tindex":"4559","tlabel":"1701553747","PhoneNumber":"11159","DeviceId":"abcd1234abcd1234","CallId":"
10941-15480 at 198.24.63.39"},] (214) (88)

DEBUG: evapi [evapi_dispatch.c:370]: evapi_recv_client(): executing event
route for frame:
[{"event":"REGISTER","tindex":"4559","tlabel":"1701553747","PhoneNumber":"11159","DeviceId":"abcd1234abcd1234","CallId":"
10941-15480 at 198.24.63.39"}] (146)

DEBUG: evapi [evapi_dispatch.c:492]: evapi_recv_notify(): received
[0x7f43d93c2a70]
[146:{"event":"REGISTER","tindex":"43210","tlabel":"639090568","PhoneNumber":"11160","DeviceId":"abcd1234abcd1234","CallId":"
10942-15480 at 198.24.63.39"},] (151)

DEBUG: evapi [evapi_dispatch.c:370]: evapi_recv_client(): executing event
route for frame:
[{"event":"REGISTER","tindex":"43210","tlabel":"639090568","PhoneNumber":"11160","DeviceId":"abcd1234abcd1234","CallId":"
10942-15480 at 198.24.63.39"}] (146)

DEBUG: evapi [evapi_dispatch.c:353]: evapi_recv_client(): residual data
[146:{"event":"REGISTER","tindex":"43210","tlabel":"639090568","PhoneNumber":"11160","Dev]
(88)

DEBUG: evapi [evapi_dispatch.c:361]: evapi_recv_client(): frame size
mismatch the ending char ("):
[{"event":"REGISTER","tindex":"43210","tlabel":"639090568","PhoneNumber":"11160","Dev146:{"event":"REGISTER","tindex":"52171","tlabel":"748030241",]
(146)

*Logs for discarded message:*
DEBUG: evapi [evapi_dispatch.c:492]: evapi_recv_notify(): received
[0x7f43da3e69a0]
[146:{"event":"REGISTER","tindex":"52171","tlabel":"748030241","PhoneNumber":"11161","DeviceId":"abcd1234abcd1234","CallId":"
10943-15480 at 198.24.63.39"},] (151)

NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [
198.24.63.45:48905] - received
[146:{"event":"REGISTER","tindex":"52171","tlabel":"748030241","PhoneNumber":"11161","DeviceId":"abcd1234abcd1234","CallId":"
10943-15480 at 198.24.63.39"},] (151) (88)

*Logs for messages after the discarded message:*
DEBUG: evapi [evapi_dispatch.c:492]: evapi_recv_notify(): received
[0x7f43da3e6aa0]
[146:{"event":"REGISTER","tindex":"25286","tlabel":"809034258","PhoneNumber":"11163","DeviceId":"abcd1234abcd1234","CallId":"
10944-15480 at 198.24.63.39"},] (151)

NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [
198.24.63.45:48905] - received
[146:{"event":"REGISTER","tindex":"25286","tlabel":"809034258","PhoneNumber":"11163","DeviceId":"abcd1234abcd1234","CallId":"
10944-15480 at 198.24.63.39"},] (151) (0)

DEBUG: evapi [evapi_dispatch.c:370]: evapi_recv_client(): executing event
route for frame:
[{"event":"REGISTER","tindex":"25286","tlabel":"809034258","PhoneNumber":"11163","DeviceId":"abcd1234abcd1234","CallId":"
10944-15480 at 198.24.63.39"}] (146)

DEBUG: evapi [evapi_dispatch.c:492]: evapi_recv_notify(): received
[0x7f43d9598778]
[146:{"event":"REGISTER","tindex":"34248","tlabel":"187029249","PhoneNumber":"11162","DeviceId":"abcd1234abcd1234","CallId":"
10945-15480 at 198.24.63.39"},] (151)

NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [
198.24.63.45:48905] - received
[146:{"event":"REGISTER","tindex":"34248","tlabel":"187029249","PhoneNumber":"11162","DeviceId":"abcd1234abcd1234","CallId":"
10945-15480 at 198.24.63.39"},] (151) (0)

DEBUG: evapi [evapi_dispatch.c:370]: evapi_recv_client(): executing event
route for frame:
[{"event":"REGISTER","tindex":"34248","tlabel":"187029249","PhoneNumber":"11162","DeviceId":"abcd1234abcd1234","CallId":"
10945-15480 at 198.24.63.39"}] (146)

DEBUG: evapi [evapi_dispatch.c:492]: evapi_recv_notify(): received
[0x7f43d9598878]
[145:{"event":"REGISTER","tindex":"7363","tlabel":"949153805","PhoneNumber":"11164","DeviceId":"abcd1234abcd1234","CallId":"
10946-15480 at 198.24.63.39"},] (150)

NOTICE: evapi [evapi_dispatch.c:290]: evapi_recv_client(): {0} [
198.24.63.45:48905] - received
[145:{"event":"REGISTER","tindex":"7363","tlabel":"949153805","PhoneNumber":"11164","DeviceId":"abcd1234abcd1234","CallId":"
10946-15480 at 198.24.63.39"},] (150) (0)

DEBUG: evapi [evapi_dispatch.c:370]: evapi_recv_client(): executing event
route for frame:
[{"event":"REGISTER","tindex":"7363","tlabel":"949153805","PhoneNumber":"11164","DeviceId":"abcd1234abcd1234","CallId":"
10946-15480 at 198.24.63.39"}] (145)

Just in case if you need to see the NGREP trace for the above messages, it
is here:
http://pastebin.com/4zTKmBJX

Thanks,

- Jayesh

On Tue, Sep 29, 2015 at 12:16 PM Daniel-Constantin Mierla <miconda at gmail.com>
wrote:

> Hello,
>
> can you send here the log messages printed by evapi that contain "] -
> received [" which have:
>
> - the previous bunch of json documents that were processed ok (just before
> the one that was discarded)
> - the bunch of json documents that were discarded
> - the next bunch of json documents that were processed ok
>
> The logs were sent on could of emails and pastebin, so it is hard to track
> them -- if you have the logs, just locate the log messages with the
> discarded json and send it here along with the previous and next logs.
>
> Cheers,
> Daniel
>
>
> On 28/09/15 17:04, Jayesh Nambiar wrote:
>
> Thank you daniel.
> Yes, they all get printed by the evapi module even when they get
> discarded. If you once again check the paste-bin, the logs pasted as
> Kamailio Logs are all discarded packets but show up as received by evapi
> module.
> I believe they got discarded because a packet that came before them was
> partial and evapi discarded the remaining part of the message in the new
> packet and encountered error.
> - Jayesh
>
> On Mon, Sep 28, 2015 at 11:13 AM Daniel-Constantin Mierla <
> miconda at gmail.com> wrote:
>
>> Hello,
>>
>> I will look over it during next days.
>>
>> One more thing, are the packages sent by you printed by evapi module,
>> even not they are not processed (but discarded)?
>>
>> Cheers,
>> Daniel
>>
>>
> --
> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
> Book: SIP Routing With Kamailio - http://www.asipto.com
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20150929/430eab24/attachment.html>