[OpenSIPS-Users] Opensips MediaProxy Integration
Mike Tesliuk
mike at ultra.net.br
Thu Aug 18 22:18:02 CEST 2011
Ok, this problem is about the dialog module, the time of the hangup is
defined by my dialog module, but why ? i think that the dialog is ok and the
call was stablished, why is dialog assuming the hangup ?
2011/8/18 Mike Tesliuk <mike at ultra.net.br>
> Its me again!
>
> hehehe
>
>
> Well, i remove the configuration from proxy on freeradius based on this
> post ( http://www.openser.org/pipermail/users/2009-November/009489.html )
> , this solve my issue about the tm module and no reply from freeradius, but
> i stay with the 1 minute call problem.
>
> But now i have some new messages
>
>
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:db_mysql:db_mysql_do_
> prepared_query: doing BIND_PARAM in...
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:dialog:get_expired_dlgs:
> start with tl=0xb3392aec tl->prev=0xb3372f08 tl->next=0xb3372f08 (5296) at
> 5296 and end with end=0xb3372f08 end->prev=0xb3392aec end->next=0xb3392aec
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:dialog:get_expired_dlgs:
> getting tl=0xb3392aec tl->prev=0xb3372f08 tl->next=0xb3372f08 with 5296
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:dialog:get_expired_dlgs:
> end with tl=0xb3372f08 tl->prev=0xb3392aec tl->next=0xb3392aec and
> d_timer->first.next->prev=(nil)
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
> DBG:dialog:dlg_timer_routine: tl=0xb3392aec next=(nil)
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:dialog:next_state_dlg:
> dialog 0xb3392ac0 changed from state 4 to state 5, due event 7
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:dialog:dlg_ontimeout:
> timeout for dlg with CallID '1852647490 at 192.168.0.14' and tags
> '1198656166' 'as14e120f4'
> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
> DBG:dialog:run_dlg_callbacks: dialog=0xb3392ac0, type=64
> Aug 18 16:45:39 ser1-vm media-dispatcher[24931]: debug: Issuing "remove"
> command to relay at 204.16.3.27
> Aug 18 16:45:39 ser1-vm media-relay[24950]: debug: removing session
> 1852647490 at 192.168.0.14: pruonckk at MY____DOMAIN (1198656166) -->
> 21069743 at MY____DOMAIN
> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50024 Closed)
> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50025 Closed)
> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50026 Closed)
> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50027 Closed)
>
>
>
> my opensips mysql connection is fine, i get on the log the update execute
>
> 145223 Execute update dialog set
> state=4,timeout=1313696739,caller_cseq='2',callee_cseq='2',vars=NULL,profiles=NULL,script_flags=0
> where hash_entry=1274 AND hash_id=1549020372
>
>
> some idea ?
>
>
> 2011/8/18 Mike Tesliuk <mike.tesliuk at ultra.net.br>
>
>> Its me again!
>>
>> hehehe
>>
>>
>> Well, i remove the configuration from proxy on freeradius based on this
>> post ( http://www.openser.org/pipermail/users/2009-November/009489.html )
>> , this solve my issue about the tm module and no reply from freeradius, but
>> i stay with the 1 minute call problem.
>>
>> But now i have some new messages
>>
>>
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
>> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
>> DBG:dialog:get_expired_dlgs: start with tl=0xb3392aec tl->prev=0xb3372f08
>> tl->next=0xb3372f08 (5296) at 5296 and end with end=0xb3372f08
>> end->prev=0xb3392aec end->next=0xb3392aec
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
>> DBG:dialog:get_expired_dlgs: getting tl=0xb3392aec tl->prev=0xb3372f08
>> tl->next=0xb3372f08 with 5296
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
>> DBG:dialog:get_expired_dlgs: end with tl=0xb3372f08 tl->prev=0xb3392aec
>> tl->next=0xb3392aec and d_timer->first.next->prev=(nil)
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
>> DBG:dialog:dlg_timer_routine: tl=0xb3392aec next=(nil)
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:dialog:next_state_dlg:
>> dialog 0xb3392ac0 changed from state 4 to state 5, due event 7
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]: DBG:dialog:dlg_ontimeout:
>> timeout for dlg with CallID '1852647490 at 192.168.0.14' and tags
>> '1198656166' 'as14e120f4'
>> Aug 18 16:45:39 ser1-vm /sbin/opensips[25261]:
>> DBG:dialog:run_dlg_callbacks: dialog=0xb3392ac0, type=64
>> Aug 18 16:45:39 ser1-vm media-dispatcher[24931]: debug: Issuing "remove"
>> command to relay at 204.16.3.27
>> Aug 18 16:45:39 ser1-vm media-relay[24950]: debug: removing session
>> 1852647490 at 192.168.0.14: pruonckk at MY____DOMAIN (1198656166) -->
>> 21069743 at MY____DOMAIN
>> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50024 Closed)
>> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50025 Closed)
>> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50026 Closed)
>> Aug 18 16:45:39 ser1-vm media-relay[24950]: (Port 50027 Closed)
>>
>>
>>
>> my opensips mysql connection is fine, i get on the log the update execute
>>
>> 145223 Execute update dialog set
>> state=4,timeout=1313696739,caller_cseq='2',callee_cseq='2',vars=NULL,profiles=NULL,script_flags=0
>> where hash_entry=1274 AND hash_id=1549020372
>>
>>
>> some idea ?
>>
>>
>>
>> 2011/8/18 Mike Tesliuk <mike at ultra.net.br>
>>
>>> Almost :)
>>>
>>>
>>> Im getting two issues yet.
>>>
>>>
>>> 1). When i do a call im getting a good call but with 1 minute the call is
>>> finished on mediaproxy, i don know how solve this, i read on list the same
>>> kind of issue but was a problem with iptables, i dont have any iptables rule
>>> on my server from now.
>>>
>>>
>>> Below i put a small part of my log
>>>
>>> Aug 18 15:17:36 ser1-vm /sbin/opensips[25255]: DBG:core:forward_request:
>>> orig. len=701, new_len=751, proto=1
>>> Aug 18 15:17:36 ser1-vm /sbin/opensips[25255]:
>>> DBG:core:run_fwd_callbacks: FWD callback entered
>>> Aug 18 15:17:36 ser1-vm /sbin/opensips[25255]:
>>> DBG:siptrace:trace_msg_out: trace off...
>>> Aug 18 15:17:36 ser1-vm /sbin/opensips[25255]: DBG:tm:t_unref_cell:
>>> UNREF_UNSAFE: [0xb33932ec] after is 1
>>> Aug 18 15:17:36 ser1-vm /sbin/opensips[25255]: DBG:dialog:unref_dlg:
>>> unref dlg 0xb3392ac0 with 1 -> 3
>>> Aug 18 15:17:36 ser1-vm /sbin/opensips[25255]: DBG:core:destroy_avp_list:
>>> destroying list (nil)
>>> Aug 18 15:17:36 ser1-vm /sbin/opensips[25255]: DBG:core:receive_msg:
>>> cleaning up
>>> Aug 18 15:17:36 ser1-vm media-relay[24950]: debug: Got traffic
>>> information for stream: (audio) XXX.XXX.XXX.162:11798 (RTP:
>>> XXX.XXX.XXX.162:1024, RTCP: Unknown) <-> XXX.XXX.XXX.26:50008 <->
>>> XXX.XXX.XXX.26:50010 <-> XXX.XXX.XXX.101:14992 (RTP: XXX.XXX.XXX.101:14992,
>>> RTCP: Unknown)
>>> Aug 18 15:17:40 ser1-vm /sbin/opensips[25261]: DBG:tm:timer_routine:
>>> timer routine:2,tl=0xb3393334 next=(nil), timeout=24
>>> Aug 18 15:17:40 ser1-vm /sbin/opensips[25261]: DBG:tm:wait_handler:
>>> removing 0xb33932ec from table
>>> Aug 18 15:17:40 ser1-vm /sbin/opensips[25261]: DBG:tm:delete_cell:
>>> delete_cell 0xb33932ec: can't delete -- still reffed (1)
>>> Aug 18 15:17:40 ser1-vm /sbin/opensips[25261]: DBG:tm:set_timer: relative
>>> timeout is 2
>>> Aug 18 15:17:40 ser1-vm /sbin/opensips[25261]:
>>> DBG:tm:insert_timer_unsafe: [3]: 0xb3393350 (26)
>>> Aug 18 15:17:40 ser1-vm /sbin/opensips[25261]: DBG:tm:wait_handler: done
>>> Aug 18 15:17:41 ser1-vm media-relay[24950]: debug: Got traffic
>>> information for stream: (audio) XXX.XXX.XXX.162:11798 (RTP:
>>> XXX.XXX.XXX.162:1024, RTCP: Unknown) <-> XXX.XXX.XXX.26:50008 <->
>>> XXX.XXX.XXX.26:50010 <-> XXX.XXX.XXX.101:14992 (RTP: XXX.XXX.XXX.101:14992,
>>> RTCP: XXX.XXX.XXX.101:14993)
>>> Aug 18 15:17:42 ser1-vm /sbin/opensips[25261]: DBG:tm:timer_routine:
>>> timer routine:3,tl=0xb3393350 next=(nil), timeout=26
>>> Aug 18 15:17:42 ser1-vm /sbin/opensips[25261]: DBG:tm:delete_handler:
>>> removing 0xb33932ec
>>> Aug 18 15:17:42 ser1-vm /sbin/opensips[25261]: DBG:tm:delete_cell:
>>> delete_cell 0xb33932ec: can't delete -- still reffed (1)
>>> Aug 18 15:17:42 ser1-vm /sbin/opensips[25261]: DBG:tm:set_timer: relative
>>> timeout is 2
>>> Aug 18 15:17:42 ser1-vm /sbin/opensips[25261]:
>>> DBG:tm:insert_timer_unsafe: [3]: 0xb3393350 (28)
>>>
>>>
>>> i get a lot of this message about tm module, but i dont know how to
>>> solve, and with 1 minute i get a port close from mediaproxy
>>>
>>> i verify on my debug (ngrep) and i dont have any message when i get no
>>> sound anymore.
>>>
>>>
>>> The second question is about aaa_radius
>>>
>>> im getting this message from opensips on syslog
>>>
>>> Aug 18 15:18:17 ser1-vm media-dispatcher[24931]: error: failed to send
>>> radius accounting record:
>>> Aug 18 15:18:21 ser1-vm /sbin/opensips[25258]: rc_send_server: no reply
>>> from RADIUS server localhost:1813
>>> Aug 18 15:18:21 ser1-vm /sbin/opensips[25258]: ERROR:acc:acc_aaa_request:
>>> Radius accounting request failed for status: 'Stop' Call-Id: '
>>> 1050509697 at 192.168.0.14'
>>>
>>> but i have radius working
>>>
>>> udp 0 0 0.0.0.0:1812 0.0.0.0:
>>> *
>>> 23865/freeradius
>>> udp 0 0 0.0.0.0:1813 0.0.0.0:*
>>> 23865/freeradius
>>>
>>>
>>> and when i do a freeradius -X to verify the question i dont receive on my
>>> radius any request
>>>
>>> i configure my opensips/radius/client.conf with localhost and opensips
>>> send me other request's (below a sample)
>>>
>>> rlm_detail:
>>> /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to
>>> /var/log/freeradius/radacct/127.0.0.1/detail-20110818
>>> rlm_detail: Freeradius-Proxied-To set to 127.0.0.1
>>> modcall[accounting]: module "detail" returns ok for request 0
>>> WARNING: Attempt to use unknown xlat function, or non-existent attribute
>>> in string %{Sip-Application-Type}
>>> radius_xlat: ' CALL insert_radacct_record(
>>> 'radius', '97004099 at 192.168.0.14',
>>> '54998168f16b36de', '', '',
>>> '', '5060', '2011-08-18
>>> 15:26:09', '0', '0',
>>> '0', '0', 'sip:21069743 at MY____DOMAIN',
>>> 'sip:pruonckk at MY____DOMAIN', '200',
>>> 'Sip-Session', '', '',
>>> '0', '0', '200', 'Invite',
>>> ? 'sip:551121069743 at XXX.XXX.XXX.101',
>>> 'as2d79d6b6', '1986300728',
>>> '', '', '',
>>> 'sip:21069743 at MY____DOMAIN', '',
>>> '', '', 'Yealink SIP-T20P
>>> 9.51.0.10', '' )'
>>>
>>>
>>>
>>> Somebody have an idea about this ?
>>>
>>>
>>> 2011/8/18 Saúl Ibarra Corretgé <saul at ag-projects.com>
>>>
>>>>
>>>> On Aug 10, 2011, at 12:55 PM, Mike Tesliuk wrote:
>>>>
>>>> > Hello guys, i remove the nat variable but the problem was another
>>>> module declaration .
>>>> >
>>>> > modparam("mediaproxy", "disable", 0) ( i put 1 instead 0 )
>>>> >
>>>> >
>>>> > im sorry my mistake and thanks for the help
>>>> >
>>>>
>>>> I'm glad it now works for you :-)
>>>>
>>>> --
>>>> Saúl Ibarra Corretgé
>>>> AG Projects
>>>>
>>>>
>>>>
>>>>
>>>> _______________________________________________
>>>> 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/20110818/5faecc86/attachment.htm>
More information about the Users
mailing list