Liviu,
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: 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: <sip:brain.gmail@ <http://sip:[email protected]:34145>192.xxx.xx.xx .40:34145 <http://sip:[email protected]:34145>>;tag=1895987525#015#012To: <sip:[email protected]: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:[email protected]: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 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 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:tm:_reply_light: finished Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f635fa2bbb0] after is 0 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4868]: DBG:seas:process_input: (Action dispatched,buffer.len=0) Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:tcp_read_req: content-length= 0 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: SIP Request: Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: method: <ACK> Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: uri: <sip:[email protected]:57277;transport=tcp> Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_msg: version: <SIP/2.0> Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=2 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK926930436>; state=16 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_via: end of header reached, state=5 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: via found, flags=2 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: this is the first via Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:receive_msg: After parse_msg... Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:receive_msg: preparing to run routing scripts... Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=8 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to_param: tag=1763472269 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: end of header reached, state=29 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: display={}, ruri={sip:[email protected]:34145} Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: <To> [55]; uri=[sip:[email protected]:34145] Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: to body [<sip:[email protected]:34145>] Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=ffffffffffffffff Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <ACK> Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: content_length=0 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: found end of header Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=200 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:is_preloaded: is_preloaded: No 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] Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if port 5060 matches port 57277 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] Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if port 5060 matches port 57277 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:check_self: host != me 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] Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 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 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=200 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:get_hdr_field: found end of header Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:find_next_route: No next Route HF found Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:after_loose: No next URI found! Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr=on;transport=tcp> Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:dialog:dlg_onroute: Route param 'did' not found Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: here is a lose route Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:uri:has_totag: totag found Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: This has a totag Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: ack received by opensips sending to app server! Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=ffffffffffffffff Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: received at route 1 sending to seas Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=ffffffffffffffff Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=78 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_lookup_request: start searching: hash=12733, isACK=1 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_headers: flags=38 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to_param: tag=1895987525 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: end of header reached, state=29 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:parse_to: display={}, ruri={sip:[email protected]:34145} Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_lookup_request: REF_UNSAFE:[0x7f635fa2bbb0] after is 1 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_lookup_request: e2e proxy ACK found Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:seas:w_as_relay_t: as found ! (app_server_one) processor id = 2 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: ERROR:seas:create_as_event_t: no transaction provided... Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: ERROR:seas:w_as_relay_t: unable to create event code Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f635fa2bbb0] after is 0 Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:destroy_avp_list: destroying list (nil) Nov 20 17:59:59 mediaproxy2 /sbin/opensips[4858]: DBG:core:receive_msg: cleaning up On Wed, Nov 20, 2013 at 3:22 AM, Liviu Chircu <[email protected]> wrote: > Hello Tito, > > 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). > > 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. > > Best regards, > > Liviu Chircu > OpenSIPS Developerhttp://www.opensips-solutions.com > > On 11/20/2013 07:14 AM, Tito Cumpen wrote: > > Group, > > > > 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 > > > Thanks, > Tito > > > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]: here is a loose route > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]: This has a totag > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]: ack received by opensips > sending to app server! > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]: received at route 1 > sending to seas > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]: > ERROR:seas:create_as_event_t: no transaction provided... > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2038]: ERROR:seas:w_as_relay_t: > unable to create event code > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2039]: here is a lose route > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2039]: This has a totag > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2039]: received at route 1 > sending to seas > > Nov 19 20:21:08 mediaproxy2 /sbin/opensips[2026]: > INFO:seas:dispatcher_main_loop: polling [2 ServSock] [1 pipe] [1 App > Servers] [0 Uncomplete AS] > > Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]: WARNING:core:fm_malloc: > Not enough free memory, will atempt defragmenation > > Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]: ERROR:tm:sip_msg_cloner: > no more share memory > > Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]: ERROR:tm:new_t: out of > mem > > Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2041]: ERROR:tm:t_newtran: > new_t failed > > Nov 19 20:21:09 mediaproxy2 /sbin/opensips[2026]: > INFO:seas:dispatcher_main_loop: polling [2 ServSock] [1 pipe] [1 App > Servers] [0 Uncomplete AS] > > Nov 19 20:21:11 mediaproxy2 /sbin/opensips[2026]: > INFO:seas:dispatcher_main_loop: polling [2 ServSock] [1 pipe] [1 App > Servers] [0 Uncomplete AS] > > Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2038]: here is a lose route > > Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2038]: This has a totag > > Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2038]: received at route 1 > sending to seas > > Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2026]: > INFO:seas:dispatcher_main_loop: polling [2 ServSock] [1 pipe] [1 App > Servers] [0 Uncomplete AS] > > Nov 19 20:21:17 mediaproxy2 /sbin/opensips[2026]: > INFO:seas:dispatcher_main_loop: polling [2 ServSock] [1 pipe] [1 App > Servers] [0 Uncomplete AS] > > Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2026]: > INFO:seas:dispatcher_main_loop: polling [2 ServSock] [1 pipe] [1 App > Servers] [0 Uncomplete AS] > > Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]: WARNING:core:fm_malloc: > Not enough free memory, will atempt defragmenation > > Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]: ERROR:tm:relay_reply: no > more share memory > > Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]: WARNING:core:fm_malloc: > Not enough free memory, will atempt defragmenation > > Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]: ERROR:tm:_reply_light: > failed to allocate shmem buffer > > Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]: WARNING:core:fm_malloc: > Not enough free memory, will atempt defragmenation > > Nov 19 20:21:38 mediaproxy2 /sbin/opensips[2031]: ERROR:tm:relay_reply: no > more share memory > > > _______________________________________________ > Users mailing > [email protected]http://lists.opensips.org/cgi-bin/mailman/listinfo/users > > > > _______________________________________________ > Users mailing list > [email protected] > http://lists.opensips.org/cgi-bin/mailman/listinfo/users > >
_______________________________________________ Users mailing list [email protected] http://lists.opensips.org/cgi-bin/mailman/listinfo/users
