[OpenSIPS-Users] 1.9 git HEAD memory issues

[Vlad Paiu]

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 Developer
http://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 
> <mailto: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 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/20130920/782607f4/attachment-0001.htm>