Daniel,

Here is the version information.

root@tel-vc-fs03.telariscom.com> kamailio -v version: kamailio 4.1.2 (x86_64/linux) 73ea61 flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 73ea61 compiled on 20:41:21 Apr 1 2014 with gcc 4.4.7

We don’t see this happen in the lab environment. It only happens in production so we are little concern about it failing. Unfortunately, we don’t have any core dumps of this occurring; we didn’t have that feature enabled when this happened.

By enabling “men_safety”, will this affect the processing of any of other signaling messages when an error occurs or will it only affect the transaction in which the error occurred. There isn’t much detail in the description of this flag in the documentation to layout how it affects the overall system in an otherwise “abort” situation. Your assistance is appreciated and I hope that it doesn’t sound like we are being difficult but this element is setting in front of our entire network and failure causes us to block all calls. We were running close to 800 CPS through it when it failed. We don’t see any load on the machine that would indicate that the issue isn’t software based. If the “men_safety” will not affect the rest of the traffic, we can add this as well as enabling core dumps and try it again when we can closely monitor the system. Please provide the additional details about “men_safety” so we can assess the situation. Is there any other information that I can provide to assist your input like the part of the config file or what else?

Sam

On Apr 9, 2014, at 2:27 AM, Daniel-Constantin Mierla miconda@gmail.com wrote:

Can you get the output of kamailio -v?

Also, send the backtrace for the corefiles taken with gdb - the logs show that the core were generated (check / or the value of -w parameter):

gdb /usr/local/sbin/kamailio /path/to/core bt full

To protect against such cases, you can use in config file:

mem_safety=1

Cheers, Daniel

On 08/04/14 17:34, Samuel Ware wrote:

...

Here are the logs from the first crash

Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feac6836310,65572,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feaace02c98,65533,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feac6836310,65569,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:32 tel-vc-fs03 /usr/local/sbin/kamailio[7589]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7feaca6c9738), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:775]: handle_sigs(): child process 7589 exited by a signal 6 Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: INFO: <core> [main.c:790]: handle_sigs(): INFO: terminating due to SIGCHLD Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7604]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7597]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7603]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7601]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received

Logs from second crash

Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f34ec4f6ed8,65569,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f35242e5d28,65535,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f3516fb6720,65578,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d8e91088,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: sl [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d8e91088,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3961]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d81fa960,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3961]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3974]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f34d7d6b720), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: ALERT: <core> [main.c:775]: handle_sigs(): child process 3974 exited by a signal 6 Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: INFO: <core> [main.c:790]: handle_sigs(): INFO: terminating due to SIGCHLD Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3985]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3983]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3966]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3988]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3972]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3984]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received

---

SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

-- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

Hello,

have you found the corefiles? The backtrace would be useful not to let the issue unresolved and be sure there are not other side effects.

Another question, in the logs I see that the reason for failing to forward the branch is a very long sip message:

Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feac6836310,65572,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL)

So the branch has 65572 bytes, which exceed 64k, making the kernel reject sending the udp packet. Do you have such large SIP requests to send out?

Cheers, Daniel

On 09/04/14 19:34, Daniel-Constantin Mierla wrote:

Hello,

the logs show that the core file was generated:

Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated

Unless you deleted them, then you should have them somewhere on the file system.

mem_safety won't affect any kind of processing - it is just a protection for a double call of free() function. Actually, it is turned on with f_malloc memory manager which was the default in the past. Now we use q_malloc as default which is kind of f_malloc with defrag option. We should make this back on by default, but catching double free() is also good to solve anyhow.

Cheers, Daniel

On 09/04/14 17:15, Samuel Ware wrote:

...

Daniel,

Here is the version information.

root@tel-vc-fs03.telariscom.com> kamailio -v
version: kamailio 4.1.2 (x86_64/linux) 73ea61
flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, 

DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 73ea61 compiled on 20:41:21 Apr 1 2014 with gcc 4.4.7

We don’t see this happen in the lab environment. It only happens in production so we are little concern about it failing. Unfortunately, we don’t have any core dumps of this occurring; we didn’t have that feature enabled when this happened.

By enabling “men_safety”, will this affect the processing of any of other signaling messages when an error occurs or will it only affect the transaction in which the error occurred. There isn’t much detail in the description of this flag in the documentation to layout how it affects the overall system in an otherwise “abort” situation. Your assistance is appreciated and I hope that it doesn’t sound like we are being difficult but this element is setting in front of our entire network and failure causes us to block all calls. We were running close to 800 CPS through it when it failed. We don’t see any load on the machine that would indicate that the issue isn’t software based. If the “men_safety” will not affect the rest of the traffic, we can add this as well as enabling core dumps and try it again when we can closely monitor the system. Please provide the additional details about “men_safety” so we can assess the situation. Is there any other information that I can provide to assist your input like the part of the config file or what else?

Sam

On Apr 9, 2014, at 2:27 AM, Daniel-Constantin Mierla miconda@gmail.com wrote:

...

Can you get the output of kamailio -v?

Also, send the backtrace for the corefiles taken with gdb - the logs show that the core were generated (check / or the value of -w parameter):

gdb /usr/local/sbin/kamailio /path/to/core bt full

To protect against such cases, you can use in config file:

mem_safety=1

Cheers, Daniel

On 08/04/14 17:34, Samuel Ware wrote:

...

Here are the logs from the first crash

Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feac6836310,65572,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feaace02c98,65533,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feac6836310,65569,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:32 tel-vc-fs03 /usr/local/sbin/kamailio[7589]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7feaca6c9738), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:775]: handle_sigs(): child process 7589 exited by a signal 6 Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: INFO: <core> [main.c:790]: handle_sigs(): INFO: terminating due to SIGCHLD Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7604]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7597]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7603]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7601]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received

Logs from second crash

Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f34ec4f6ed8,65569,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f35242e5d28,65535,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f3516fb6720,65578,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d8e91088,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: sl [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d8e91088,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3961]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d81fa960,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3961]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3974]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f34d7d6b720), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: ALERT: <core> [main.c:775]: handle_sigs(): child process 3974 exited by a signal 6 Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: INFO: <core> [main.c:790]: handle_sigs(): INFO: terminating due to SIGCHLD Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3985]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3983]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3966]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3988]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3972]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3984]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received

---

SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

-- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

Hello,

wondering if you got new log messages with "qm_free: freeing already freed pointer". I tried to simulate a similar situation when t_send_branch() fails, but couldn't reproduce the crash. It would be good to sort out the reason and be sure that there are no side effects, so I am trying to troubleshoot it further.

Cheers, Daniel

On 10/04/14 19:50, Samuel Ware wrote:

Daniel,

I was unable to locate them. We made the mem_safety change and put the machine back into Production. It has been running for 5 hours without crashing. The only error that seems different than before is the following

Apr 10 17:36:29 tel-vc-fs03 /usr/local/sbin/kamailio[31365]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 10 17:36:29 tel-vc-fs03 /usr/local/sbin/kamailio[31365]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 10 17:37:02 tel-vc-fs03 /usr/local/sbin/kamailio[31368]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c19c22f10), called from tm: h_table.c: free_cell(186), first free tm: h_table .c: free_cell(186) - aborting

On Apr 9, 2014, at 12:34 PM, Daniel-Constantin Mierla miconda@gmail.com wrote:

...

Hello,

the logs show that the core file was generated:

Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated

Unless you deleted them, then you should have them somewhere on the file system.

mem_safety won't affect any kind of processing - it is just a protection for a double call of free() function. Actually, it is turned on with f_malloc memory manager which was the default in the past. Now we use q_malloc as default which is kind of f_malloc with defrag option. We should make this back on by default, but catching double free() is also good to solve anyhow.

Cheers, Daniel

On 09/04/14 17:15, Samuel Ware wrote:

...

Daniel,

Here is the version information.

root@tel-vc-fs03.telariscom.com> kamailio -v version: kamailio 4.1.2 (x86_64/linux) 73ea61 flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 73ea61 compiled on 20:41:21 Apr 1 2014 with gcc 4.4.7

We don’t see this happen in the lab environment. It only happens in production so we are little concern about it failing. Unfortunately, we don’t have any core dumps of this occurring; we didn’t have that feature enabled when this happened.

By enabling “men_safety”, will this affect the processing of any of other signaling messages when an error occurs or will it only affect the transaction in which the error occurred. There isn’t much detail in the description of this flag in the documentation to layout how it affects the overall system in an otherwise “abort” situation. Your assistance is appreciated and I hope that it doesn’t sound like we are being difficult but this element is setting in front of our entire network and failure causes us to block all calls. We were running close to 800 CPS through it when it failed. We don’t see any load on the machine that would indicate that the issue isn’t software based. If the “men_safety” will not affect the rest of the traffic, we can add this as well as enabling core dumps and try it again when we can closely monitor the system. Please provide the additional details about “men_safety” so we can assess the situation. Is there any other information that I can provide to assist your input like the part of the config file or what else?

Sam

On Apr 9, 2014, at 2:27 AM, Daniel-Constantin Mierla miconda@gmail.com wrote:

...

Can you get the output of kamailio -v?

Also, send the backtrace for the corefiles taken with gdb - the logs show that the core were generated (check / or the value of -w parameter):

gdb /usr/local/sbin/kamailio /path/to/core bt full

To protect against such cases, you can use in config file:

mem_safety=1

Cheers, Daniel

On 08/04/14 17:34, Samuel Ware wrote:

...

Here are the logs from the first crash

Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:13:59 tel-vc-fs03 /usr/local/sbin/kamailio[7602]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feac6836310,65572,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:05 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feaace02c98,65533,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:20 tel-vc-fs03 /usr/local/sbin/kamailio[7594]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7feac6836310,65569,0,205.251.172.14:5060,16): Message too long(90) Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 13:14:27 tel-vc-fs03 /usr/local/sbin/kamailio[7583]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 13:14:32 tel-vc-fs03 /usr/local/sbin/kamailio[7589]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7feaca6c9738), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:775]: handle_sigs(): child process 7589 exited by a signal 6 Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7553]: INFO: <core> [main.c:790]: handle_sigs(): INFO: terminating due to SIGCHLD Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7604]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7597]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7579]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7603]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 13:14:55 tel-vc-fs03 /usr/local/sbin/kamailio[7601]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received

Logs from second crash

Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f34ec4f6ed8,65569,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:42 tel-vc-fs03 /usr/local/sbin/kamailio[3979]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f35242e5d28,65535,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:44 tel-vc-fs03 /usr/local/sbin/kamailio[3965]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f3516fb6720,65578,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [t_fwd.c:1609]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d8e91088,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: sl [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: sl [sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: Unfortunately error on sending to next hop occurred (477/SL) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d8e91088,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:57 tel-vc-fs03 /usr/local/sbin/kamailio[3968]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3961]: ERROR: <core> [udp_server.c:591]: udp_send(): ERROR: udp_send: sendto(sock,0x7f37d81fa960,65522,0,205.251.172.14:5060,16): Message too long(90) Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3961]: ERROR: tm [../../forward.h:199]: msg_send(): msg_send: ERROR: udp_send failed Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3974]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f34d7d6b720), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: ALERT: <core> [main.c:775]: handle_sigs(): child process 3974 exited by a signal 6 Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: ALERT: <core> [main.c:778]: handle_sigs(): core was generated Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3935]: INFO: <core> [main.c:790]: handle_sigs(): INFO: terminating due to SIGCHLD Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3985]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3983]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3966]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3988]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3972]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received Apr 3 14:39:20 tel-vc-fs03 /usr/local/sbin/kamailio[3984]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received

---

SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

-- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

-- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

Are the error messages before those with realloc related to failing sending on branch 0? Any error messages related to sending "an empty buffer"?

Daniel

On 22/04/14 15:34, Samuel D Ware wrote:

Apr 3 13:14:32 tel-vc-fs03 /usr/local/sbin/kamailio[7589]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7feaca6c9738), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 3 14:38:58 tel-vc-fs03 /usr/local/sbin/kamailio[3974]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f34d7d6b720), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 14:16:34 tel-vc-fs03 /usr/local/sbin/kamailio[31354]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c00319b40), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 14:28:00 tel-vc-fs03 /usr/local/sbin/kamailio[31350]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c3bcddf00), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 16:00:08 tel-vc-fs03 /usr/local/sbin/kamailio[31357]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1e5ba128), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 17:26:53 tel-vc-fs03 /usr/local/sbin/kamailio[31368]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c09557a80), called from tm: h_table.c: free_cell(159), first free tm: t_reply.c: reply_received(2260) - aborting Apr 10 17:37:02 tel-vc-fs03 /usr/local/sbin/kamailio[31368]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c19c22f10), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Apr 10 17:50:22 tel-vc-fs03 /usr/local/sbin/kamailio[31356]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c4dc899c8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 18:16:50 tel-vc-fs03 /usr/local/sbin/kamailio[31359]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c034dcc58), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 18:21:56 tel-vc-fs03 /usr/local/sbin/kamailio[31351]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c4dc899c8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 18:21:56 tel-vc-fs03 /usr/local/sbin/kamailio[31359]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c3daa95a8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 19:18:38 tel-vc-fs03 /usr/local/sbin/kamailio[31359]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c4182b490), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 19:21:50 tel-vc-fs03 /usr/local/sbin/kamailio[31364]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c020bbea8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 19:28:23 tel-vc-fs03 /usr/local/sbin/kamailio[31350]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c19be2f78), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 19:38:07 tel-vc-fs03 /usr/local/sbin/kamailio[31363]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c467eb400), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 19:40:56 tel-vc-fs03 /usr/local/sbin/kamailio[31354]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c68795760), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 20:45:07 tel-vc-fs03 /usr/local/sbin/kamailio[31362]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c50863060), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 20:48:49 tel-vc-fs03 /usr/local/sbin/kamailio[31363]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c751ef678), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 10 21:18:21 tel-vc-fs03 /usr/local/sbin/kamailio[31362]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c2e90f2b0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 13:19:00 tel-vc-fs03 /usr/local/sbin/kamailio[31348]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c02b3d950), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 13:19:00 tel-vc-fs03 /usr/local/sbin/kamailio[31347]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c02b3d950), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 14:32:49 tel-vc-fs03 /usr/local/sbin/kamailio[31362]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1647be10), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 14:38:21 tel-vc-fs03 /usr/local/sbin/kamailio[31359]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c2d3301a8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 15:06:57 tel-vc-fs03 /usr/local/sbin/kamailio[31354]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c2b7d4c10), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 15:08:29 tel-vc-fs03 /usr/local/sbin/kamailio[31358]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1860fbd8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 15:24:14 tel-vc-fs03 /usr/local/sbin/kamailio[31351]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c6bc778e0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 15:24:37 tel-vc-fs03 /usr/local/sbin/kamailio[31344]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c029efac8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 15:29:28 tel-vc-fs03 /usr/local/sbin/kamailio[31356]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1ddd3a90), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 15:31:09 tel-vc-fs03 /usr/local/sbin/kamailio[31345]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c188cfa78), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 16:23:48 tel-vc-fs03 /usr/local/sbin/kamailio[31355]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c425b4728), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 16:27:59 tel-vc-fs03 /usr/local/sbin/kamailio[31351]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c204b2b08), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 16:29:05 tel-vc-fs03 /usr/local/sbin/kamailio[31351]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1e6fda38), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 16:34:51 tel-vc-fs03 /usr/local/sbin/kamailio[31345]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c02d23ac0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 16:41:28 tel-vc-fs03 /usr/local/sbin/kamailio[31346]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c69cd7408), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 16:48:36 tel-vc-fs03 /usr/local/sbin/kamailio[31361]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1f4e8ef0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 16:48:52 tel-vc-fs03 /usr/local/sbin/kamailio[31355]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c44264c70), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 17:05:43 tel-vc-fs03 /usr/local/sbin/kamailio[31342]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c106423b8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 17:12:50 tel-vc-fs03 /usr/local/sbin/kamailio[31360]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c580c4798), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 17:18:00 tel-vc-fs03 /usr/local/sbin/kamailio[31349]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c3d1e0718), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 17:19:01 tel-vc-fs03 /usr/local/sbin/kamailio[31344]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1155b210), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 17:21:14 tel-vc-fs03 /usr/local/sbin/kamailio[31343]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c4e9a1fd8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 17:40:36 tel-vc-fs03 /usr/local/sbin/kamailio[31355]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c3e2fad90), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 17:50:37 tel-vc-fs03 /usr/local/sbin/kamailio[31361]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8bff534998), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:00:00 tel-vc-fs03 /usr/local/sbin/kamailio[31349]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c3c8a3420), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:02:37 tel-vc-fs03 /usr/local/sbin/kamailio[31354]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c18527dd8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:10:49 tel-vc-fs03 /usr/local/sbin/kamailio[31351]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c44264950), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:12:09 tel-vc-fs03 /usr/local/sbin/kamailio[31349]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c0a35fb20), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:33:31 tel-vc-fs03 /usr/local/sbin/kamailio[31364]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c3c5f5bf0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:50:22 tel-vc-fs03 /usr/local/sbin/kamailio[31349]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1b627730), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:54:37 tel-vc-fs03 /usr/local/sbin/kamailio[31346]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c7de453a8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 18:56:01 tel-vc-fs03 /usr/local/sbin/kamailio[31355]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c39272270), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 11 19:03:03 tel-vc-fs03 /usr/local/sbin/kamailio[31360]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c65ac0570), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 12 19:18:08 tel-vc-fs03 /usr/local/sbin/kamailio[31344]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c07408498), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 14 19:42:56 tel-vc-fs03 /usr/local/sbin/kamailio[31349]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c1e496290), called from <core>: mem/shm_mem.c: sh_realloc(88), first free tm: h_table.c: free_cell(186) - aborting Apr 14 19:57:09 tel-vc-fs03 /usr/local/sbin/kamailio[31362]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c099e66e0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 14 22:33:51 tel-vc-fs03 /usr/local/sbin/kamailio[31356]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c37ccdca8), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 15 18:58:28 tel-vc-fs03 /usr/local/sbin/kamailio[31358]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c3e880ad0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 15 20:29:03 tel-vc-fs03 /usr/local/sbin/kamailio[31356]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c02ff8838), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 15 20:44:59 tel-vc-fs03 /usr/local/sbin/kamailio[31365]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c21d52468), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 15 20:55:17 tel-vc-fs03 /usr/local/sbin/kamailio[31354]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c39e39860), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 15 21:01:25 tel-vc-fs03 /usr/local/sbin/kamailio[31355]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c31199c70), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 15 22:13:53 tel-vc-fs03 /usr/local/sbin/kamailio[31353]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c5ea743b0), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 16 22:14:24 tel-vc-fs03 /usr/local/sbin/kamailio[31345]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c19d96248), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting Apr 17 22:56:50 tel-vc-fs03 /usr/local/sbin/kamailio[31357]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f8c751ef678), called from <core>: mem/shm_mem.c: sh_realloc(88), first free <core>: mem/shm_mem.c: sh_realloc(88) - aborting

-- Samuel D Ware Sent with Airmail

On April 22, 2014 at 3:59:28 AM, Daniel-Constantin Mierla (miconda@gmail.com mailto:miconda@gmail.com) wrote:

...

Hello,

wondering if you got new log messages with "qm_free: freeing already freed pointer". I tried to simulate a similar situation when t_send_branch() fails, but couldn't reproduce the crash. It would be good to sort out the reason and be sure that there are no side effects, so I am trying to troubleshoot it further.

Cheers, Daniel

Hi Sam,

There are two ways to decode I know about:

1. Dump in ad-hoc format, decode with extractaudio tool, which is still work-in-progress, so we have not really released it yet. Latest code is available here http://bitbucket.org/sippysoft/rtpproxy/. Subdir "extractaudio". It might not even compile out of the box, but that could be easily fixed

2. Dump in the pcap format (rtpproxy has an option for that), and fiddle around with the wireshark and friends. It has pretty decent rtp decoder, I am not sure if you can script it though.

The caller/callee info can be passed through file name using AVPs, or some side channel and linked to file name by call-id. On Apr 23, 2014 12:54 AM, sam@dsmedia.com.sg wrote:

Hi,

I am running a SIP Service using Kamailio.

I have activated the RTP Proxy Recording.

I need two things to be done.

1. RTP files saved need to have caller and callee usernames as file names.
2. Need to convert RTP files to mp3.

Can anyone assist on this?

Thanks SamG DS Media

---

SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users