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 <[email protected]> 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 '[email protected]' > 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 > [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
