<div dir="ltr">Liviu,<div><br></div><div><br></div><div>Thanks for your help. I have modified the debug to 4 here I am not seeing the memory messages but the scenario fails on all occasions even at initial launch l. Even after restarting the server to remove any possibility of a memory leak in my previous instance. The fact that ack is not being sent it causing the callee to drop the call. Here is the debug log:</div>
<div><br></div><div><br></div><div>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:core:tcp_send: buf=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/TCP 192.168.2.74:38602;received=108.xx.xx.184;rport=50456;branch=z9hG4bK1570207620#015#012From: <<a href="http://sip:brain.gmail@192.237.178.40:34145" target="_blank">sip:brain.gmail@</a>192.xxx.xx.xx<a href="http://sip:brain.gmail@192.237.178.40:34145" target="_blank">.40:34145</a>>;tag=1895987525#015#012To: <sip:pinky.gmail@192.xxx.xx.xx:34145>;tag=1763472269#015#012Call-ID: 321959835#015#012CSeq: 21 INVITE#015#012Record-Route: <sip:192.xxx.xx.xx:5060;lr=on;transport=tcp>#015#012Contact: <sip:pinky.gmail@108.xx.xx.184:57277;transport=tcp>#015#012Content-Type: application/sdp#015#012User-Agent: Linphone/3.6.1 (eXosip2/3.6.0)#015#012Content-Length: 760#015#012#015#012v=0#015#012o=pinky.gmail 3790 1167 IN IP4 192.168.2.122#015#012s=Talk#015#012c=IN IP4 192.168.2.122#015#012t=0 0#015#012a=nortpproxy:yes#015#012a=ice-pwd:6c1f278e2776535c3db87de5#015#012a=ice-ufrag:254135de#015#012m=audio 7078 RTP/AVP 8 0 120 111 110 101#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-11#015#012a=nortpproxy:yes#015#012a=candidate:1 1 UDP 2130706431 192.168.2.122 7078 typ host#015#012a=candidate:1 2 UDP 2130706430 192.168.2.122 7079 typ host#015#012m=video 9078 RTP/AVP 103 99#015#012a=rtpmap:103 VP8/90000#015#012a=rtpmap:99 MP4V-ES/90000#015#012a=fmtp:99 profile-level-id=3#015#012a=nortpproxy:yes#015#012a=candidate:1 1 UDP 2130706431 192.168.2.122 9078 typ host#015#012a=candidate:1 2 UDP 2130706430 192.168.2.122 9079 typ host#015#012</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:tm:_reply_light: reply sent out. buf=0x7d82c0: SIP/2.0 2..., shmem=0x7f635fae9668: SIP/2.0 2</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:tm:_reply_light: finished</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f635fa2bbb0] after is 0</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:seas:process_input: (Action dispatched,buffer.len=0)</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:tcp_read_req: content-length= 0</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: SIP Request:</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: method: <ACK></p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: uri: <sip:pinky.gmail@108.xx.xx.184:57277;transport=tcp></p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: version: <SIP/2.0></p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=2</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK926930436>; state=16</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_via: end of header reached, state=5</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: via found, flags=2</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: this is the first via</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:receive_msg: After parse_msg...</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:receive_msg: preparing to run routing scripts...</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=8</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to_param: tag=1763472269</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: end of header reached, state=29</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: display={}, ruri={sip:pinky.gmail@192.xxx.xx.xx:34145}</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: <To> [55]; uri=[sip:pinky.gmail@192.xxx.xx.xx:34145] </p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: to body [<sip:pinky.gmail@192.xxx.xx.xx:34145>]</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=ffffffffffffffff</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <ACK></p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: content_length=0</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: found end of header</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=200</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:is_preloaded: is_preloaded: No</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if host==us: 14==14 && [108.xx.xx.184] == [192.xxx.xx.xx]</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if port 5060 matches port 57277</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if host==us: 14==14 && [108.xx.xx.184] == [192.xxx.xx.xx]</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if port 5060 matches port 57277</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:check_self: host != me</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if host==us: 14==14 && [192.xxx.xx.xx] == [192.xxx.xx.xx]</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:after_loose: Topmost route URI: 'sip:192.xxx.xx.xx:5060;lr=on;transport=tcp' is me</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=200</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: found end of header</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:find_next_route: No next Route HF found</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:after_loose: No next URI found!</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr=on;transport=tcp></p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:dialog:dlg_onroute: Route param 'did' not found</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: here is a lose route </p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:uri:has_totag: totag found</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: This has a totag </p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: ack received by opensips sending to app server!</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=ffffffffffffffff</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: received at route 1 sending to seas</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=ffffffffffffffff</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=78</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_lookup_request: start searching: hash=12733, isACK=1</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=38</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to_param: tag=1895987525</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: end of header reached, state=29</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: display={}, ruri={sip:brain.gmail@192.xxx.xx.xx:34145}</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_lookup_request: REF_UNSAFE:[0x7f635fa2bbb0] after is 1</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_lookup_request: e2e proxy ACK found</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:seas:w_as_relay_t: as found ! (app_server_one) processor id = 2</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: ERROR:seas:create_as_event_t: no transaction provided...</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: ERROR:seas:w_as_relay_t: unable to create event code</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f635fa2bbb0] after is 0</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:destroy_avp_list: destroying list (nil)</p>
<p>Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:receive_msg: cleaning up</p></div><div><br></div><div><br></div><div><br></div><div><br></div><div><br></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">
On Wed, Nov 20, 2013 at 3:22 AM, Liviu Chircu <span dir="ltr"><<a href="mailto:liviu@opensips.org" target="_blank">liviu@opensips.org</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div bgcolor="#FFFFFF" text="#000000">
<div>Hello Tito,<br>
<br>
Firstly, note that OpenSIPS will not use the entire available RAM
on the box, but rather a predefined value ("-m" parameter, e.g.
"-m 128" for a 128MB preallocated memory pool).<br>
<br>
Does your scenario not work at all or does OpenSIPS start
misbehaving after some time? The log messages tell us that
OpenSIPS has run out of memory and is unable to properly process
incoming traffic.<br>
<br>
Best regards,<br>
<pre cols="72">Liviu Chircu
OpenSIPS Developer
<a href="http://www.opensips-solutions.com" target="_blank">http://www.opensips-solutions.com</a></pre><div><div class="h5">
On 11/20/2013 07:14 AM, Tito Cumpen wrote:<br>
</div></div></div>
<blockquote type="cite"><div><div class="h5">
<div dir="ltr">
<p>Group,</p>
<p><br>
</p>
<p><br>
</p>
<p>I am relaying my invites and loose routes to a
sipservlet using the seas module and wesip. I am noticing that
when acks are sent to opensips it is directed to relay those
acks to wesip and then back out to the recipient it fails to
do so. Consequently I see this message being generated and
eventually a memory problem. I am not seeing the message
traverse through seas into the my servlet. Take note this is a
single call on a server with more than sufficient ram. I am
using version opensips-1.7.2-tls</p>
<p><br>
Thanks,<br>
Tito </p>
<p><br>
</p>
<p><br>
</p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]:
here is a loose route </p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]:
This has a totag </p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]:
ack received by opensips sending to app server!</p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]:
received at route 1 sending to seas</p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]:
ERROR:seas:create_as_event_t: no transaction provided...</p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]:
ERROR:seas:w_as_relay_t: unable to create event code</p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2039]:
here is a lose route </p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2039]:
This has a totag </p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2039]:
received at route 1 sending to seas</p>
<p>Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2026]:
<a>INFO:seas:dispatcher_main_loop</a>: polling [2 ServSock] [1 pipe]
[1 App Servers] [0 Uncomplete AS]</p>
<p>Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]:
WARNING:core:fm_malloc: Not enough free memory, will atempt
defragmenation</p>
<p>Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]:
ERROR:tm:sip_msg_cloner: no more share memory</p>
<p>Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]:
ERROR:tm:new_t: out of mem</p>
<p>Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]:
ERROR:tm:t_newtran: new_t failed</p>
<p>Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2026]:
<a>INFO:seas:dispatcher_main_loop</a>: polling [2 ServSock] [1 pipe]
[1 App Servers] [0 Uncomplete AS]</p>
<p>Nov 19 20:21:11 mediaproxy2 /sbin/opensips[2026]:
<a>INFO:seas:dispatcher_main_loop</a>: polling [2 ServSock] [1 pipe]
[1 App Servers] [0 Uncomplete AS]</p>
<p>Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2038]:
here is a lose route </p>
<p>Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2038]:
This has a totag </p>
<p>Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2038]:
received at route 1 sending to seas</p>
<p>Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2026]:
<a>INFO:seas:dispatcher_main_loop</a>: polling [2 ServSock] [1 pipe]
[1 App Servers] [0 Uncomplete AS]</p>
<p>Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2026]:
<a>INFO:seas:dispatcher_main_loop</a>: polling [2 ServSock] [1 pipe]
[1 App Servers] [0 Uncomplete AS]</p>
<p>Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2026]:
<a>INFO:seas:dispatcher_main_loop</a>: polling [2 ServSock] [1 pipe]
[1 App Servers] [0 Uncomplete AS]</p>
<p>Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]:
WARNING:core:fm_malloc: Not enough free memory, will atempt
defragmenation</p>
<p>Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]:
ERROR:tm:relay_reply: no more share memory</p>
<p>Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]:
WARNING:core:fm_malloc: Not enough free memory, will atempt
defragmenation</p>
<p>Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]:
ERROR:tm:_reply_light: failed to allocate shmem buffer</p>
<p>Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]:
WARNING:core:fm_malloc: Not enough free memory, will atempt
defragmenation</p>
<p>Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]:
ERROR:tm:relay_reply: no more share memory</p>
</div>
<br>
<fieldset></fieldset>
<br>
</div></div><pre>_______________________________________________
Users mailing list
<a href="mailto:Users@lists.opensips.org" target="_blank">Users@lists.opensips.org</a>
<a href="http://lists.opensips.org/cgi-bin/mailman/listinfo/users" target="_blank">http://lists.opensips.org/cgi-bin/mailman/listinfo/users</a>
</pre>
</blockquote>
<br>
</div>
<br>_______________________________________________<br>
Users mailing list<br>
<a href="mailto:Users@lists.opensips.org">Users@lists.opensips.org</a><br>
<a href="http://lists.opensips.org/cgi-bin/mailman/listinfo/users" target="_blank">http://lists.opensips.org/cgi-bin/mailman/listinfo/users</a><br>
<br></blockquote></div><br></div>