[OpenSIPS-Users] 1.9 git HEAD memory issues

Sun Sep 29 04:31:54 CEST 2013

Hi Vlad, so I followed the advice for doing the memory dump on restart, and
got back into a situation where I see regular memory errors in the log:

2013-09-29T02:09:09.822210+00:00 registrar2
/usr/local/opensips/sbin/opensips[25307]: ERROR:tm:sip_msg_cloner: no more
share memory
2013-09-29T02:09:09.822233+00:00 registrar2
/usr/local/opensips/sbin/opensips[25307]: ERROR:tm:new_t: out of mem
2013-09-29T02:09:09.822273+00:00 registrar2
/usr/local/opensips/sbin/opensips[25307]: ERROR:tm:t_newtran: new_t failed
2013-09-29T02:09:09.822286+00:00 registrar2
/usr/local/opensips/sbin/opensips[25303]: ERROR:tm:sip_msg_cloner: no more
share memory
2013-09-29T02:09:09.822325+00:00 registrar2
/usr/local/opensips/sbin/opensips[25303]: ERROR:tm:new_t: out of mem
2013-09-29T02:09:09.822335+00:00 registrar2
/usr/local/opensips/sbin/opensips[25303]: ERROR:tm:t_newtran: new_t failed

Looking at the statistics for shmem:

And the memory dump counting fragments:

On Fri, Sep 20, 2013 at 7:43 AM, Vlad Paiu <vladpaiu at opensips.org> wrote:

>  Hello,
>
> The log_next_state_dlg warning message means that you have received a 1xx
> reply message after the 200OK reply has came in - it's nothing critical if
> the communication was via UDP, since the order of the UDP datagrams is not
> guaranteed.
>
> About the memory issues, it seems you've just ran out of shared memory -
> the first build_req_buf_from_sip_req error message is miss-leading, it's
> actually trying to allocate shared memory.
>
> In order to further debug this, can you please follow the steps at
> http://www.opensips.org/Documentation/TroubleShooting-OutOfMem and send
> us the output of the memory dump ?
>
> Best Regards,
>
> Vlad Paiu
> OpenSIPS Developerhttp://www.opensips-solutions.com
>
> On 19.09.2013 23:58, Bobby Smith wrote:
>
> Greetings list,
>
>  We're trying to track down some memory issues that we originally thought
> were related to rabbitmq, but after updating to the latest 1.9 I'm seeing a
> lot of these errors in the log file:
>
>  2013-09-19T20:54:40.115582+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3916]:
> CRITICAL:dialog:log_next_state_dlg: bogus event 2 in state 3 for dlg
> 0x2acc8b7780b0 [3248:527118168] with clid '3388204-13671 at 10.215.190.98'
> and tags '3388204' '13665SIPpTag01563795'
>
>  I understand what this means (I think, it's around the order that a 200
> OK and ACK are processed), but repeating the same test on a previous
> revision doesn't show these messages.
>
>  Also, after a short amount of time running the test:
>
>  2013-09-19T18:02:23.809205+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3918]:
> ERROR:core:build_req_buf_from_sip_req: out of pkg memory
> 2013-09-19T18:02:23.809231+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3918]: ERROR:tm:print_uac_request: no
> more shm_mem
> 2013-09-19T18:02:23.809242+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3917]:
> ERROR:core:build_req_buf_from_sip_req: out of pkg memory
> 2013-09-19T18:02:23.809252+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3918]: ERROR:tm:t_forward_nonack: failure
> to add branches
> 2013-09-19T18:02:23.809261+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3917]: ERROR:tm:print_uac_request: no
> more shm_mem
> 2013-09-19T18:02:23.809271+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3917]: ERROR:tm:t_forward_nonack: failure
> to add branches
> 2013-09-19T18:02:23.809279+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3918]: ERROR:tm:_reply_light: failed to
> allocate shmem buffer
> 2013-09-19T18:02:23.809288+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3917]: ERROR:tm:_reply_light: failed to
> allocate shmem buffer
> 2013-09-19T18:02:23.809297+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3916]: ERROR:tm:new_t: out of mem
> 2013-09-19T18:02:23.809306+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3916]: ERROR:tm:t_newtran: new_t failed
> 2013-09-19T18:02:23.809911+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3921]: ERROR:tm:new_t: out of mem
> 2013-09-19T18:02:23.809942+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3917]: ERROR:tm:new_t: out of mem
> 2013-09-19T18:02:23.809970+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3917]: ERROR:tm:t_newtran: new_t failed
> 2013-09-19T18:02:23.809999+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3916]: ERROR:tm:new_t: out of mem
> 2013-09-19T18:02:23.810037+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3916]: ERROR:tm:t_newtran: new_t failed
> 2013-09-19T18:02:23.810068+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3921]: ERROR:tm:t_newtran: new_t failed
> 2013-09-19T18:02:23.810880+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3919]:
> ERROR:core:build_req_buf_from_sip_req: out of pkg memory
> 2013-09-19T18:02:23.810921+00:00 registrar2
> /usr/local/opensips/sbin/opensips[3921]: ERROR:dialog:dlg_add_leg_info:
> Failed to resize legs array
>
>  It seems very strange we'd run out of both package and shared memory at
> the same time.  When I dump statistics when these messages are propagating
> in the log, I see:
>
>  According to statistics:
>
>  shmem:total_size = 1073741824
> shmem:used_size = 168525088
> shmem:real_used_size = 390522728
> shmem:max_used_size = 1060997488
> shmem:free_size = 683219096
> shmem:fragments = 1106426
>
>  pkmem:0-real_used_size = 601136
> pkmem:1-real_used_size = 610592
> pkmem:2-real_used_size = 50858056
> pkmem:3-real_used_size = 610416
> pkmem:4-real_used_size = 610416
> pkmem:5-real_used_size = 610416
> pkmem:6-real_used_size = 610416
> pkmem:7-real_used_size = 610416
> pkmem:8-real_used_size = 610416
> pkmem:9-real_used_size = 610416
> pkmem:10-real_used_size = 610416
> pkmem:11-real_used_size = 650864
> pkmem:12-real_used_size = 654800
> pkmem:13-real_used_size = 650944
> pkmem:14-real_used_size = 651136
> pkmem:15-real_used_size = 650704
> pkmem:16-real_used_size = 650888
> pkmem:17-real_used_size = 651712
> pkmem:18-real_used_size = 651040
> pkmem:19-real_used_size = 601136
> pkmem:20-real_used_size = 618512
> pkmem:21-real_used_size = 669680
> pkmem:22-real_used_size = 669680
> pkmem:23-real_used_size = 669680
> pkmem:24-real_used_size = 669680
> pkmem:25-real_used_size = 669680
> pkmem:26-real_used_size = 669680
> pkmem:27-real_used_size = 669680
> pkmem:28-real_used_size = 669680
> pkmem:29-real_used_size = 660464
>
>  And pkmem is configured for 64MB per process.
>
>  Any thoughts?  It doesn't seem like transactions are dropping or
> anything, we just see these strange issues in the logs.
>
>  Thanks,
>
>
>
>
>
> _______________________________________________
> Users mailing listUsers at lists.opensips.orghttp://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
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20130928/5bfb1ca5/attachment.htm>