[OpenSIPS-Users] Db_mode=3(sql only) in USRLOC module in opensips_3.1
Saurabh Chopra
saurabhc at 3clogic.com
Mon Dec 21 07:03:17 EST 2020
Hi Donat/Opensips Team,
We have tested with "working_mode_preset" as *sql only* because db_mode is
deprecated. And as far as opensips logs is concerned , I am attaching
opensips logs as a text file with *log_level=4, *please check if you could
find anything unusual.
Will wait for your feedback.
Best Regards
Saurabh Chopra
+918861979979
On Wed, Dec 16, 2020 at 6:46 PM Donat Zenichev <donat.zenichev at gmail.com>
wrote:
> Good day Sasmita and Saurabh,
> that's a good question to ask and answer actually.
>
> As I was mentioning at the very beginning, did you try to look into the
> logs with the deep log_level?
> https://www.opensips.org/Documentation/Script-CoreParameters-3-1#toc37
> This is highly appreciated when doing a debug of an issue.
>
> What do "db_mysql.so" and "usrloc.so" say when you try to de-register a
> subscriber? (with a debug log_level)
>
> Other than that, I want to mention that the "db_mode" parameter is kept
> now for backwards compatibility.
> It also conflicts with "working_mode_preset" parameter:
> https://opensips.org/html/docs/modules/3.1.x/usrloc.html#param_working_mode_preset
> Try to see if "working_mode_preset" is also configured on your OpenSIPS
> instance.
> And might be, this would also be a good idea to switch to usage of
> "working_mode_preset" instead of "db_mode", at least because it's a more
> actual one.
>
> Also how about the:
>
> https://opensips.org/html/docs/modules/3.1.x/usrloc.html#param_restart_persistency
>
> https://opensips.org/html/docs/modules/3.1.x/usrloc.html#param_sql_write_mode
>
> Is that configured on your OpenSIPS instance? If so, what are the options
> set for that?
> (of course, this couple should be useless in db only mode, but just in
> case you have inadvertently configured this as well).
>
> Anyway, pay much attention to logs at the debug level.
> As this can give you some insight on what happens.
>
> Have a nice day!
>
> On Wed, Dec 16, 2020 at 7:58 AM Sasmita Panda <spanda at 3clogic.com> wrote:
>
>> Hi Donat,
>>
>> According to Saurabh , he is saying in " *db_mode=3 and sql-only mode*
>> " that direct DB operation happens .
>> When a user get registered that contact immediately get populated to the
>> DB and when the user send un-registration the entry from the DB should be
>> deleted at that time .
>> *The deletion part is not happening in his case *.* The contact from
>> location table delete when in the expiration time* .
>>
>> According to opensips documentation , the timer works when the user not
>> able to un-registrer itself . Then data persist in the DB . That should be
>> deleted in the timer interval . This is fine .
>>
>> If I will explain through example .
>> 1. Usr get register at 11.10.10 with expire 300sec .
>> 2. User send un-register at 11.11.10 (But the data wont get deleted from
>> the DB somehow)
>> 3. The user was gone away in 1min only . But the data in DB is there for
>> next 4min . * In this case the timer wont play any role . Even
>> though timer_interval is set to 120sec . Still the contact exists till 5min
>> . *
>> 4. If an INVITE will come for that user . Then opensips will try to push
>> the call to that existing contact . But I was expecting 404 Not Found .
>>
>> This is the problem . As for the previous version of opensips this is
>> working fine . But in 3.1 we are facing issue .
>>
>> I have taken opensips code from
>>
>> *git clone https://github.com/OpenSIPS/opensips.git <https://github.com/OpenSIPS/opensips.git> -b 3.1 opensips-3.1*
>>
>>
>> *Please suggest what else we should do .*
>>
>> *Thanks & Regards*
>> *Sasmita Panda*
>> *Senior Network Testing and Software Engineer*
>> *3CLogic , ph:07827611765*
>>
>>
>> On Mon, Dec 14, 2020 at 5:13 PM Donat Zenichev <donat.zenichev at gmail.com>
>> wrote:
>>
>>> Good day Saurabh, could you refer to the RFC and the particular row in
>>> that, that talks about a backend database and time in which the row should
>>> be deleted from that?
>>> I just wonder if I missed this somewhere. I haven't ever seen a
>>> specification for databases backend in RFCs related to the SIP protocol.
>>> Would be a good thing for me to learn something new! :)
>>>
>>> I just want to mention, and focus you on the fact, that you might need
>>> to take a look at this parameter:
>>>
>>> https://opensips.org/html/docs/modules/3.0.x/usrloc.html#param_timer_interval
>>>
>>> As this plays not the last role when working in sql-only mode.
>>> Did you read something about that?
>>>
>>> One more time, a quotation:
>>> 1. "Number of seconds between two timer runs. During each run, the
>>> module will update/delete dirty/expired contacts from memory and/or mirror
>>> these operations to the database, if configured to do so."
>>> 2. "sql-only - DB-Only scheme. No memory cache is kept, all operations
>>> being directly performed with the database. The timer deletes all expired
>>> contacts from database - cleans after clients that didn't un-register or
>>> re-register."
>>>
>>> This is how it works.
>>>
>>>
>>> On Mon, Dec 14, 2020 at 12:26 PM Saurabh Chopra <saurabhc at 3clogic.com>
>>> wrote:
>>>
>>>> Hi Donat/Opensips Team,
>>>>
>>>> Apologies for late response, but ideally the entry should be deleted
>>>> after un-registration is sent otherwise it will violate the RFC rule.
>>>> Also, this SQL Only Mode is perfectly working with opensips 2.2 and 3.0
>>>> versions with the same configuration. Could you guys try to replicate this
>>>> Or confirm if I am missing anything in the configuration side.
>>>>
>>>>
>>>> Best Regards
>>>> Saurabh Chopra
>>>> +918861979979
>>>>
>>>>
>>>> On Fri, Dec 11, 2020 at 2:22 PM Donat Zenichev <
>>>> donat.zenichev at gmail.com> wrote:
>>>>
>>>>> I just want to follow up with the thing that, using the sql-only mode,
>>>>> expired location records might not be deleted right away.
>>>>> I just remembered all of the sudden, that the timer interval controls
>>>>> data clearing/updating when using sql-only mode.
>>>>>
>>>>> Then you might also want to play with your timer interval value. How
>>>>> huge is that now?
>>>>>
>>>>> https://opensips.org/html/docs/modules/3.0.x/usrloc.html#param_timer_interval
>>>>>
>>>>> This one is responsible for clearing out expired contacts from the
>>>>> user location table.
>>>>> Here is a quotation from the "sql-only" mod description:
>>>>> "The timer deletes all expired contacts from database - cleans after
>>>>> clients that didn't un-register or re-register."
>>>>>
>>>>> On Fri, Dec 11, 2020 at 9:22 AM Donat Zenichev <
>>>>> donat.zenichev at gmail.com> wrote:
>>>>>
>>>>>> Good morning Saurabh,
>>>>>> that sounds a bit odd, as the sql only mode supposes that usrloc.so
>>>>>> updates the backend sql right away.
>>>>>>
>>>>>> Do you have any warnings occurring in the OpenSIPS log?
>>>>>> There might be a case for an inability of OpenSIPS to reach the sql
>>>>>> server at the moment of de-registration.
>>>>>> See if there are any re-connections to the database.
>>>>>>
>>>>>> And also did you try to gather opensips logs with a debug level?
>>>>>> Try to see which log rows both "db_mysql.so" (if you are using mysql
>>>>>> as a backend db) and "usrloc.so" are throwing out into the log, when you
>>>>>> send a de-registration.
>>>>>>
>>>>>> Otherwise, you might also try to use either
>>>>>> "single-instance-sql-write-through" or "single-instance-sql-write-back",
>>>>>> which perhaps can better fit your demands.
>>>>>>
>>>>>>
>>>>>> On Fri, Dec 11, 2020 at 9:00 AM Saurabh Chopra <saurabhc at 3clogic.com>
>>>>>> wrote:
>>>>>>
>>>>>>> Hi All,
>>>>>>>
>>>>>>> I am testing a usrloc module with db_mode=3(sql only) and a strange
>>>>>>> thing is happening, when we send an unregistration request the user entry
>>>>>>> is not deleting from the database . However the entry is deleted after
>>>>>>> expiry timer.
>>>>>>>
>>>>>>> loadmodule "usrloc.so"
>>>>>>> modparam("usrloc", "nat_bflag", "NAT")
>>>>>>> modparam("usrloc", "db_mode", 3)
>>>>>>> modparam("usrloc", "db_url", "mysql://root:xxxxg1c@localhost
>>>>>>> /opensips")
>>>>>>>
>>>>>>>
>>>>>>> Does db_mode=3 used to work like this? Or I am missing something?
>>>>>>>
>>>>>>> Best Regards
>>>>>>> Saurabh Chopra
>>>>>>> +918861979979
>>>>>>> _______________________________________________
>>>>>>> Users mailing list
>>>>>>> Users at lists.opensips.org
>>>>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>>>>
>>>>>>
>>>>>>
>>>>>> --
>>>>>>
>>>>>> Best regards,
>>>>>> Donat Zenichev
>>>>>>
>>>>>>
>>>>>
>>>>> --
>>>>>
>>>>> Best regards,
>>>>> Donat Zenichev
>>>>>
>>>>> _______________________________________________
>>>>> Users mailing list
>>>>> Users at lists.opensips.org
>>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>>
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users at lists.opensips.org
>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>
>>>
>>>
>>> --
>>>
>>> Best regards,
>>> Donat Zenichev
>>>
>>> _______________________________________________
>>> Users mailing list
>>> Users at lists.opensips.org
>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.opensips.org
>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>
>
>
> --
>
> Best regards,
> Donat Zenichev
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20201221/248f05bf/attachment-0001.html>
-------------- next part --------------
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_via: end of header reached, state=5
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: via found, flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: this is the first via
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:_parse_to: end of header reached, state=10
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:_parse_to: display={"test"}, ruri={sip:1234 at test-reg.i3clogic.com}
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:get_hdr_field: <To> [41]; uri=[sip:1234 at test-reg.i3clogic.com]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:get_hdr_field: to body ["test" <sip:1234 at test-reg.i3clogic.com>#015#012]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:get_hdr_field: cseq <CSeq>: <38161> <REGISTER>
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:get_hdr_field: content_length=0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:get_hdr_field: found end of header
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:receive_msg: After parse_msg...
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:receive_msg: preparing to run routing scripts...
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:maxfwd:is_maxfwd_present: value = 70
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:comp_scriptvar: int 27 : 470 / 8096
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=200
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:rr:find_first_route: No Route headers found
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:rr:loose_route: There is no Route HF
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:sipmsgops:has_totag: no totag
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=78
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:tm:t_lookup_request: start searching: hash=27909, isACK=0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:tm:t_lookup_request: no transaction found
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=200
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:rr:find_first_route: No Route headers found
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:rr:loose_route: There is no Route HF
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if host==us: 21==12 && [test-reg.i3clogic.com] == [20.0.214.175]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if host==us: 21==12 && [test-reg.i3clogic.com] == [20.0.214.175]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_to_param: tag=42db00bbf175440799b28474bfd99bd4
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:_parse_to: end of header reached, state=29
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:_parse_to: display={"test"}, ruri={sip:1234 at test-reg.i3clogic.com}
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_params: Parsing params for:[+sip.ice]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: REGISTER r-uri (sip:test-reg.i3clogic.com:5505) : Contact : <sip:1234 at 34.98.216.132:24542;ob>;+sip.ice :callID 059299f52292448c8849b68c1a4f8b16 : CSeq 38161
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:sipmsgops:is_present_hf: header 'X-Info'(0) not found
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x7f0c9eb0c0a0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: 17 columns returned from the query
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_allocate_columns: allocate 476 bytes for result columns at 0x7f0c9eb0c7e0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c868)[0]=[contact_id]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_BIGINT result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c878)[1]=[contact]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c888)[2]=[expires]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c898)[3]=[q]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_DOUBLE result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c8a8)[4]=[callid]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c8b8)[5]=[cseq]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c8c8)[6]=[flags]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c8d8)[7]=[cflags]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c8e8)[8]=[user_agent]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c8f8)[9]=[received]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c908)[10]=[path]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c918)[11]=[socket]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c928)[12]=[methods]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c938)[13]=[last_modified]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_DATETIME result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c948)[14]=[sip_instance]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c958)[15]=[kv_store]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_BLOB result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0c9eb0c968)[16]=[attr]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_allocate_rows: allocate 1120 bytes for result rows and values at 0x7f0c9eb0f8f0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT BIG[1]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:1234 at 100.127.3.22:65491;ob]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [1608195300]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting DOUBLE [-1.00]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [059299f52292448c8849b68c1a4f8b16]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [38159]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [0]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING []
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [MicroSIP/3.20.1]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:34.98.216.132:24542]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [udp:3.215.10.130:5505]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [8063]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting DATETIME [2020-12-17 08:50:00]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT BIG[2]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:1234 at 34.98.216.132:24542;ob]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [1608195301]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting DOUBLE [-1.00]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [059299f52292448c8849b68c1a4f8b16]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [38160]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [0]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING []
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [MicroSIP/3.20.1]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:34.98.216.132:24542]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting STRING [udp:3.215.10.130:5505]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting INT [8063]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:db_mysql:db_mysql_str2val: converting DATETIME [2020-12-17 08:50:01]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:dbrow2info: flag str: ''
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:dbrow2info: set flags: 0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if host==us: 12==12 && [3.215.10.130] == [20.0.214.175]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if port 5060 matches port 5505
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if host==us: 12==12 && [3.215.10.130] == [20.0.214.175]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if port 5505 matches port 5505
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: message repeated 4 times: [ DBG:core:evi_param_set: adding string param]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:destroy_avp_list: destroying list (nil)
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:dbrow2info: flag str: ''
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:dbrow2info: set flags: 0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if host==us: 12==12 && [3.215.10.130] == [20.0.214.175]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if port 5060 matches port 5505
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if host==us: 12==12 && [3.215.10.130] == [20.0.214.175]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:grep_sock_info_ext: checking if port 5505 matches port 5505
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: message repeated 4 times: [ DBG:core:evi_param_set: adding string param]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:destroy_avp_list: destroying list (nil)
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_free_columns: freeing result columns at 0x7f0c9eb0c7e0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_free_rows: freeing 2 rows
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_free_row: freeing row values at 0x7f0c9eb0f910
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_free_row: freeing row values at 0x7f0c9eb0fb30
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_free_rows: freeing rows at 0x7f0c9eb0f8f0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:db_free_result: freeing result set at 0x7f0c9eb0c0a0
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=8000000
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:get_ucontact: using ct matching mode 1
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:get_ucontact: successfully matched contact 'sip:1234 at 34.98.216.132:24542;ob'
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:delete_ucontact: deleting contact 'sip:1234 at 34.98.216.132:24542;ob'
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:registrar:build_contact: created Contact HF: Contact: <sip:1234 at 100.127.3.22:65491;ob>;expires=242;received="sip:34.98.216.132:24542"
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:usrloc:wb_timer: Binding '1234 at testreg.i3clogic.com','sip:1234 at 34.98.216.132:24542;ob' has expired
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: message repeated 4 times: [ DBG:core:evi_param_set: adding string param]
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding int param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:evi_param_set: adding string param
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:destroy_avp_list: destroying list (nil)
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:MD5StringArray: MD5 calculated: 8569e1a566e783ef91d6c907ff9e457d
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:MD5StringArray: MD5 calculated: 8569e1a566e783ef91d6c907ff9e457d
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:parse_headers: flags=ffffffffffffffff
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:destroy_avp_list: destroying list 0x7f0c9ce58008
Dec 17 08:50:58 ip-20-0-214-175 /opt/code/sbin/opensips[6150]: DBG:core:receive_msg: cleaning up
Dec 17 08:51:00 ip-20-0-214-175 /opt/code/sbin/opensips[6151]: DBG:qrouting:qr_rotate_samples: rotating samples for all (prefix, destination) pairs...
Dec 17 08:51:00 ip-20-0-214-175 /opt/code/sbin/opensips[6151]: DBG:qrouting:qr_rotate_samples: done!
More information about the Users
mailing list