14 Feb
2019
14 Feb
'19
4:46 p.m.
Hello!
I have faced with Kamailio (5.1.7) crashes, probably it is connected to cdp
module, please check the source of issue:
14(5649) INFO: cdp [receiver.c:455]: receiver_process():
receiver_process(): [diameter1.dev] Receiver process doing init on new
process...
14(5649) INFO: cdp [receiver.c:188]: add_serviced_peer():
add_serviced_peer(): Adding serviced_peer_t to receiver for peer
[diameter1.dev]
14(5649) INFO: cdp [receiver.c:460]: receiver_process():
receiver_process(): [diameter1.dev] Receiver process starting up...
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: cdp [cdp_timer]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: cdp_avp [cdp_timer]
16(5651) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [1001]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: acc [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: uac [cdp_acceptor]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: ims_charging [cdp_timer]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: ims_dialog [cdp_timer]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: htable [cdp_acceptor]
15(5650) DEBUG: htable [htable.c:236]: child_init(): rank is (1000)
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: carrierroute [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: dispatcher [cdp_acceptor]
16(5651) INFO: cdp [timer.c:205]: timer_process(): Timer process starting
up...
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: cdp [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: cdp_avp [cdp_acceptor]
15(5650) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [1000]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: ims_charging [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: ims_dialog [cdp_acceptor]
15(5650) INFO: cdp [acceptor.c:81]: acceptor_process(): Acceptor process
starting up...
15(5650) DEBUG: cdp [tcp_accept.c:114]: create_socket(): create_sockets:
create socket and bind for IPv4...
15(5650) WARNING: cdp [tcp_accept.c:121]: create_socket(): create_socket():
Trying to open/bind/listen on 10.10.10.10 port 38680
15(5650) WARNING: cdp [tcp_accept.c:146]: create_socket(): create_socket():
Successful socket open/bind/listen on 10.10.10.10 port 38680
15(5650) INFO: cdp [acceptor.c:95]: acceptor_process(): Acceptor opened
sockets. Entering accept loop ...
[root@10-10-10-10 kamailio]# 17(5652) DEBUG: <core> [core/sr_module.c:942]:
init_mod_child(): idx 17 rank -4: kex [tcp main process]
17(5652) DEBUG: kex [kex_mod.c:157]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[srid-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: corex [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: tm [tcp main process]
17(5652) DEBUG: tm [callid.c:137]: child_init_callid(): callid: '
46ac84cd57961b27-5652(a)10.10.10.10'
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: tmx [tcp main process]
17(5652) DEBUG: tmx [tmx_mod.c:261]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: sl [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: usrloc [tcp main process]
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[ulcx-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: registrar [tcp main process]
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[uloc-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: ctl [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: acc [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: uac [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: htable [tcp main process]
17(5652) DEBUG: htable [htable.c:236]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: carrierroute [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: dispatcher [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: cdp [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: cdp_avp [tcp main process]
17(5652) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [-4]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: ims_charging [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: ims_dialog [tcp main process]
17(5652) DEBUG: <core> [core/local_timer.c:61]: init_local_timer():
timer_list between 0xa6e0a8 and 0xab20a8
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 7, 4, 0x7fbdd97d7bec), fd_no=0
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 8, 4, 0x7fbdd97d7c78), fd_no=1
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 9, 4, 0x7fbdd97d7d04), fd_no=2
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 10, 4, 0x7fbdd97d7d90), fd_no=3
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 11, 4, 0x7fbdd97d7e1c), fd_no=4
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 12, 4, 0x7fbdd97d7ea8), fd_no=5
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 13, 4, 0x7fbdd97d7f34), fd_no=6
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 15, 4, 0x7fbdd97d7fc0), fd_no=7
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 4, 4, 0x7fbdd97d804c), fd_no=8
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 16, 4, 0x7fbdd97d80d8), fd_no=9
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 17, 4, 0x7fbdd97d8164), fd_no=10
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 18, 4, 0x7fbdd97d81f0), fd_no=11
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 23, 4, 0x7fbdd97d827c), fd_no=12
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 24, 4, 0x7fbdd97d8308), fd_no=13
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 25, 4, 0x7fbdd97d8394), fd_no=14
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 26, 4, 0x7fbdd97d8420), fd_no=15
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine(): getting
expired ro-sessions 5(5640) DEBUG: ims_charging [ro_timer.c:211]:
get_expired_ro_sessions(): my ticks are [32829471]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: cdp [peermanager.c:263]: peer_timer(): peer_timer(): taking
care of peers...
16(5651) DEBUG: cdp [peermanager.c:280]: peer_timer(): peer_timer(): Peer
diameter1.dev State 0
16(5651) DEBUG: cdp [peerstatemachine.c:90]: sm_process(): sm_process():
Peer diameter1.dev State Closed Event Start
16(5651) INFO: cdp [peerstatemachine.c:525]: I_Snd_Conn_Req():
I_Snd_Conn_Req(): Peer diameter1.dev
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) INFO: cdp [receiver.c:875]: peer_connect(): peer_connect(): Trying
to connect to 10.10.10.20 port 3868
16(5651) INFO: cdp [receiver.c:954]: peer_connect(): peer_connect(): Peer
diameter1.dev:3868 connected
14(5649) DEBUG: cdp [receiver.c:702]: receive_loop(): select_recv(): There
is something on the fd exchange pipe
14(5649) DEBUG: cdp [receiver.c:711]: receive_loop(): select_recv(): fd
exchange pipe says fd [8] for peer 0x7fbdd979e368:[diameter1.dev]
14(5649) DEBUG: cdp [peerstatemachine.c:90]: sm_process(): sm_process():
Peer diameter1.dev State Wait_Conn_Ack Event I_Rcv_Conn_Ack
14(5649) DEBUG: cdp [diameter_msg.c:184]: AAANewMessage(): AAANewMessage:
param session received null and it's a request!!
14(5649) ERROR: cdp [peerstatemachine.c:634]: I_Snd_CER(): I_Snd_CER():
Error on finding local host address > Socket operation on non-socket
14(5649) DEBUG: cdp [diameter_msg.c:81]: AAABuildMsgBuffer():
AAABuildMsgBuffer(): len=184
14(5649) DEBUG: cdp [receiver.c:1013]: peer_send_msg(): peer_send_msg():
Pipe push [0x7fbdd97e0788]
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:756]: receive_loop(): select_recv(): There
is something on the send pipe
14(5649) DEBUG: cdp [receiver.c:769]: receive_loop(): select_recv(): Send
pipe says [0x7fbdd97e0788] 8
14(5649) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage(): AAAFreeMessage:
Freeing message (0x7fbdd97e0788) 257
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: cdp [peermanager.c:143]: log_peer_list(): --- Peer List: ---
16(5651) DEBUG: cdp [peermanager.c:145]: log_peer_list(): State of peer:
Wait_I_CEA FQDN: diameter1.dev Port: 3868 Is dynamic
16(5651) DEBUG: cdp [peermanager.c:149]: log_peer_list(): ------------------
16(5651) DEBUG: cdp [session.c:396]: cdp_sessions_log(): ------- CDP
Sessions ----------------
16(5651) DEBUG: cdp [session.c:431]: cdp_sessions_log():
-------------------------------------
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 1
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:579]: do_receive(): receive_loop():
[diameter1.dev] Recv Version 1 Length 172
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 2
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:1107]: receive_message():
receive_message(): [diameter1.dev] Recv msg 257
14(5649) DEBUG: cdp [peerstatemachine.c:90]: sm_process(): sm_process():
Peer diameter1.dev State Wait_I_CEA Event I_Rcv_CEA
14(5649) DEBUG: cdp [peerstatemachine.c:698]:
count_Supported_Vendor_Id_AVPS(): Found 1 Supported_Vendor AVPS14(5649)
DEBUG: cdp [peerstatemachine.c:681]: add_peer_application(): Application 0
of maximum 1
14(5649) DEBUG: cdp [peerstatemachine.c:750]: save_peer_applications():
Found Supported Vendor for Application 0: 10415
14(5649) DEBUG: cdp [peerstatemachine.c:681]: add_peer_application():
Application 1 of maximum 1
14(5649) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage(): AAAFreeMessage:
Freeing message (0x7fbdd97e0788) 257
14(5649) CRITICAL: <core> [core/mem/q_malloc.c:149]: qm_debug_check_frag():
BUG: qm: prev. fragm. tail overwritten(28af,
abcdefed)[0x7fbdd97e0c98:0x7fbdd97e0cd0]! Memory allocator was called from
cdp: diameter_avp.c:365. Fragment marked by cdp: diameter_avp.c:142. Exec
from core/mem/q_malloc.c:504.
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine(): getting
expired ro-sessions 5(5640) DEBUG: ims_charging [ro_timer.c:211]:
get_expired_ro_sessions(): my ticks are [32829472]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
15(5650) DEBUG: cdp [tcp_accept.c:221]: accept_loop(): accept_loop(): No
connection attempts
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine(): getting
expired ro-sessions 5(5640) DEBUG: ims_charging [ro_timer.c:211]:
get_expired_ro_sessions(): my ticks are [32829473]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
17(5652) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 24
17(5652) DEBUG: <core> [core/tcp_main.c:3513]: handle_ser_child(): dead
child 14, pid 5649 (shutting down?)
17(5652) DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG:
io_watch_del (0xa6dee0, 24, -1, 0x0) fd_no=16 called
0(5635) ALERT: <core> [main.c:739]: handle_sigs(): child process 5649
exited by a signal 6
0(5635) ALERT: <core> [main.c:742]: handle_sigs(): core was generated
0(5635) INFO: <core> [main.c:764]: handle_sigs(): terminating due to
SIGCHLD
0(5635) DEBUG: <core> [main.c:766]: handle_sigs(): terminating due to
SIGCHLD
16(5651) INFO: <core> [main.c:819]: sig_usr(): signal 15 received
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-114.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html
This is free software: you are free to change
and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/kamailio...Reading symbols from
/usr/lib/debug/usr/sbin/kamailio.debug...done.
done.
[New LWP 5649]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `kamailio -f kamailio.cfg -E'.
Program terminated with signal 6, Aborted.
#0 0x00007fbde6015207 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install
glibc-2.17-260.el7_6.3.x86_64 keyutils-libs-1.5.8-3.el7.x86_64
krb5-libs-1.15.1-37.el7_6.x86_64 libcom_err-1.42.9-13.el7.x86_64
libgcc-4.8.5-36.el7.x86_64 libselinux-2.5-14.1.el7.x86_64
libstdc++-4.8.5-36.el7.x86_64 libxml2-2.9.1-6.el7_2.3.x86_64
mariadb-libs-5.5.60-1.el7_5.x86_64 openssl-libs-1.0.2k-16.el7.x86_64
pcre-8.32-17.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-18.el7.x86_64
(gdb) bt full
#0 0x00007fbde6015207 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007fbde60168f8 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x0000000000673469 in qm_debug_check_frag (qm=0x7fbdd94fd000,
f=0x7fbdd97e0c98, file=0x7fbdde6bb992 "cdp: diameter_avp.c", line=365,
efile=0x7dc6b7 "core/mem/q_malloc.c", eline=504)
at core/mem/q_malloc.c:151
__FUNCTION__ = "qm_debug_check_frag"
#3 0x00000000006765ec in qm_free (qmp=0x7fbdd94fd000, p=0x7fbdd97e0cd0,
file=0x7fbdde6bb992 "cdp: diameter_avp.c", func=0x7fbdde6bd478
<__FUNCTION__.7016> "AAAFreeAVP", line=365, mname=0x7fbdde6bb7c0
"cdp")
at core/mem/q_malloc.c:504
qm = 0x7fbdd94fd000
f = 0x7fbdd97e0c98
size = 140730526467984
next = 0x7a8db8
prev = 0x7a8db8
__FUNCTION__ = "qm_free"
#4 0x0000000000680148 in qm_shm_free (qmp=0x7fbdd94fd000,
p=0x7fbdd97e0cd0, file=0x7fbdde6bb992 "cdp: diameter_avp.c",
func=0x7fbdde6bd478 <__FUNCTION__.7016> "AAAFreeAVP", line=365,
mname=0x7fbdde6bb7c0 "cdp") at core/mem/q_malloc.c:1268
No locals.
#5 0x00007fbdde696e61 in AAAFreeAVP (avp=0x7ffe610a0860) at
diameter_avp.c:365
__FUNCTION__ = "AAAFreeAVP"
#6 0x00007fbdde65c88f in AAAFreeAVPList (avpList=0x7fbdd97e07d8) at
diameter_msg.c:396
avp_t = 0x7fbdd97e0cd0
avp = 0x7fbdd97e0bb8
#7 0x00007fbdde65cc4c in AAAFreeMessage (msg=0x7ffe610a0910) at
diameter_msg.c:416
__FUNCTION__ = "AAAFreeMessage"
#8 0x00007fbdde63f05e in Process_CEA (p=0x7fbdd979e368,
cea=0x7fbdd97e0788) at peerstatemachine.c:804
avp = 0x7fbdd97e10b0
#9 0x00007fbdde638223 in sm_process (p=0x7fbdd979e368, event=I_Rcv_CEA,
msg=0x7fbdd97e0788, peer_locked=0, sock=8) at peerstatemachine.c:166
result_code = -563425872
next_event = 32701
msg_received = 0
__FUNCTION__ = "sm_process"
#10 0x00007fbdde6874be in receive_message (msg=0x7fbdd97e0788,
sp=0x7fbde59538b0) at receiver.c:1147
avp1 = 0xde6b2c50
avp2 = 0x7fbdd97e0990
__FUNCTION__ = "receive_message"
#11 0x00007fbdde67c5bb in do_receive (sp=0x7fbde59538b0) at receiver.c:598
cnt = 152
n = 152
version = 1
dst = 0x7fbdd97e1164 ""
dmsg = 0x7fbdd97e0788
__FUNCTION__ = "do_receive"
#12 0x00007fbdde68038e in receive_loop (original_peer=0x7fbdd979e368) at
receiver.c:805
rfds = {__fds_bits = {256, 0 <repeats 15 times>}}
efds = {__fds_bits = {0 <repeats 16 times>}}
tv = {tv_sec = 0, tv_usec = 999998}
n = 1
max = 21
cnt = 1
msg = 0x0
sp = 0x7fbde59538b0
sp2 = 0x7fbde59538b0
p = 0x7fbdd979e368
fd = 8
fd_exchange_pipe_local = 21
__FUNCTION__ = "receive_loop"
#13 0x00007fbdde679aec in receiver_process (p=0x7fbdd979e368) at
receiver.c:464
---Type <return> to continue, or q <return> to quit---
__FUNCTION__ = "receiver_process"
#14 0x00007fbdde62a7d5 in diameter_peer_start (blocking=0) at
diameter_peer.c:289
pid = 0
k = -1
p = 0x7fbdd979e368
__FUNCTION__ = "diameter_peer_start"
#15 0x00007fbdde61c9a8 in cdp_child_init (rank=0) at cdp_mod.c:243
__FUNCTION__ = "cdp_child_init"
#16 0x000000000053b6b1 in init_mod_child (m=0x7fbde5885150, rank=0) at
core/sr_module.c:943
__FUNCTION__ = "init_mod_child"
#17 0x000000000053b353 in init_mod_child (m=0x7fbde5885dc8, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#18 0x000000000053b353 in init_mod_child (m=0x7fbde5886190, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#19 0x000000000053b353 in init_mod_child (m=0x7fbde58865d0, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#20 0x000000000053ba85 in init_child (rank=0) at core/sr_module.c:970
No locals.
#21 0x0000000000424fe5 in main_loop () at main.c:1701
i = 4
pid = 5641
si = 0x0
si_desc = "udp receiver child=3
sock=10.10.10.10:5060\000\275\177\000\000\300\023\na\376\177\000\000\022\000\000\000\000\000\000\000\000\000\000\004\000\000\000\000\000\000\200\000\000\000\000\000\263\215z",
'\000' <repeats 13 times>,
"\220\026\na\376\177\000\000\207\"\003\346\275\177\000\000\260yw\000\000\000\000\000\060;\223\345\275\177\000"
nrprocs = 4
woneinit = 1
__FUNCTION__ = "main_loop"
#22 0x000000000042b994 in main (argc=4, argv=0x7ffe610a1778) at main.c:2642
cfg_stream = 0x103a020
c = -1
r = 0
tmp = 0x0
tmp_len = 0
port = 0
proto = 0
options = 0x758c10
":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:"
ret = -1
seed = 1364069336
rfd = 4
debug_save = 0
debug_flag = 0
dont_fork_cnt = 0
n_lst = 0x0
p = 0x0
st = {st_dev = 19, st_ino = 68292, st_nlink = 2, st_mode = 16832,
st_uid = 995, st_gid = 994, __pad0 = 0, st_rdev = 0, st_size = 40,
st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1550156643,
tv_nsec = 630000000}, st_mtim = {tv_sec = 1550158563, tv_nsec =
502470819}, st_ctim = {tv_sec = 1550158563, tv_nsec = 502470819}, __unused
= {0, 0, 0}}
__FUNCTION__ = "main"
(gdb)
version: kamailio 5.1.7 (x86_64/linux) 567df3
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS,
DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC,
Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, 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_URI_SIZE 1024,
BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: 567df3
compiled on 02:06:09 Feb 2 2019 with gcc 4.8.5
--
BR,
Denys Pozniak
15 Feb
15 Feb
8:33 a.m.
Hello,
it looks like a buffer overflow there. I am not familiar with the cdp
module, however, if nobody takes over it, I will try to troubleshoot as
I get some spare time. So it is better to open an bug on issue tracker
on github project not to forget about this one. Also, keep the core file
because it may be needed to get some more info from it with gdb.
Cheers,
Daniel
On 14.02.19 16:46, Denys Pozniak wrote:
Hello!
I have faced with Kamailio (5.1.7) crashes, probably it is connected
to cdp module, please check the source of issue:
14(5649) INFO: cdp [receiver.c:455]: receiver_process():
receiver_process(): [diameter1.dev] Receiver process doing init on new
process...
14(5649) INFO: cdp [receiver.c:188]: add_serviced_peer():
add_serviced_peer(): Adding serviced_peer_t to receiver for peer
[diameter1.dev]
14(5649) INFO: cdp [receiver.c:460]: receiver_process():
receiver_process(): [diameter1.dev] Receiver process starting up...
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
16 rank 1001: cdp [cdp_timer]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
16 rank 1001: cdp_avp [cdp_timer]
16(5651) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [1001]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: acc [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: uac [cdp_acceptor]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
16 rank 1001: ims_charging [cdp_timer]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
16 rank 1001: ims_dialog [cdp_timer]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: htable [cdp_acceptor]
15(5650) DEBUG: htable [htable.c:236]: child_init(): rank is (1000)
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: carrierroute [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: dispatcher [cdp_acceptor]
16(5651) INFO: cdp [timer.c:205]: timer_process(): Timer process
starting up...
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: cdp [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: cdp_avp [cdp_acceptor]
15(5650) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [1000]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: ims_charging [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
15 rank 1000: ims_dialog [cdp_acceptor]
15(5650) INFO: cdp [acceptor.c:81]: acceptor_process(): Acceptor
process starting up...
15(5650) DEBUG: cdp [tcp_accept.c:114]: create_socket():
create_sockets: create socket and bind for IPv4...
15(5650) WARNING: cdp [tcp_accept.c:121]: create_socket():
create_socket(): Trying to open/bind/listen on 10.10.10.10 port 38680
15(5650) WARNING: cdp [tcp_accept.c:146]: create_socket():
create_socket(): Successful socket open/bind/listen on 10.10.10.10
port 38680
15(5650) INFO: cdp [acceptor.c:95]: acceptor_process(): Acceptor
opened sockets. Entering accept loop ...
[root@10-10-10-10 kamailio]# 17(5652) DEBUG: <core>
[core/sr_module.c:942]: init_mod_child(): idx 17 rank -4: kex [tcp
main process]
17(5652) DEBUG: kex [kex_mod.c:157]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[srid-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: corex [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: tm [tcp main process]
17(5652) DEBUG: tm [callid.c:137]: child_init_callid(): callid:
'46ac84cd57961b27-5652(a)10.10.10.10
<mailto:46ac84cd57961b27-5652@10.10.10.10>'
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: tmx [tcp main process]
17(5652) DEBUG: tmx [tmx_mod.c:261]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: sl [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: usrloc [tcp main process]
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[ulcx-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: registrar [tcp main process]
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[uloc-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: ctl [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: acc [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: uac [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: htable [tcp main process]
17(5652) DEBUG: htable [htable.c:236]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: carrierroute [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: dispatcher [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: cdp [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: cdp_avp [tcp main process]
17(5652) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [-4]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: ims_charging [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx
17 rank -4: ims_dialog [tcp main process]
17(5652) DEBUG: <core> [core/local_timer.c:61]: init_local_timer():
timer_list between 0xa6e0a8 and 0xab20a8
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 7, 4, 0x7fbdd97d7bec), fd_no=0
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 8, 4, 0x7fbdd97d7c78), fd_no=1
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 9, 4, 0x7fbdd97d7d04), fd_no=2
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 10, 4, 0x7fbdd97d7d90), fd_no=3
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 11, 4, 0x7fbdd97d7e1c), fd_no=4
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 12, 4, 0x7fbdd97d7ea8), fd_no=5
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 13, 4, 0x7fbdd97d7f34), fd_no=6
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 15, 4, 0x7fbdd97d7fc0), fd_no=7
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 4, 4, 0x7fbdd97d804c), fd_no=8
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 16, 4, 0x7fbdd97d80d8), fd_no=9
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 17, 4, 0x7fbdd97d8164), fd_no=10
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 18, 4, 0x7fbdd97d81f0), fd_no=11
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 23, 4, 0x7fbdd97d827c), fd_no=12
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 24, 4, 0x7fbdd97d8308), fd_no=13
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 25, 4, 0x7fbdd97d8394), fd_no=14
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 26, 4, 0x7fbdd97d8420), fd_no=15
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine():
getting expired ro-sessions 5(5640) DEBUG: ims_charging
[ro_timer.c:211]: get_expired_ro_sessions(): my ticks are [32829471]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: cdp [peermanager.c:263]: peer_timer(): peer_timer():
taking care of peers...
16(5651) DEBUG: cdp [peermanager.c:280]: peer_timer(): peer_timer():
Peer diameter1.dev State 0
16(5651) DEBUG: cdp [peerstatemachine.c:90]: sm_process():
sm_process(): Peer diameter1.dev State Closed Event Start
16(5651) INFO: cdp [peerstatemachine.c:525]: I_Snd_Conn_Req():
I_Snd_Conn_Req(): Peer diameter1.dev
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) INFO: cdp [receiver.c:875]: peer_connect(): peer_connect():
Trying to connect to 10.10.10.20 port 3868
16(5651) INFO: cdp [receiver.c:954]: peer_connect(): peer_connect():
Peer diameter1.dev:3868 connected
14(5649) DEBUG: cdp [receiver.c:702]: receive_loop(): select_recv():
There is something on the fd exchange pipe
14(5649) DEBUG: cdp [receiver.c:711]: receive_loop(): select_recv():
fd exchange pipe says fd [8] for peer 0x7fbdd979e368:[diameter1.dev]
14(5649) DEBUG: cdp [peerstatemachine.c:90]: sm_process():
sm_process(): Peer diameter1.dev State Wait_Conn_Ack Event I_Rcv_Conn_Ack
14(5649) DEBUG: cdp [diameter_msg.c:184]: AAANewMessage():
AAANewMessage: param session received null and it's a request!!
14(5649) ERROR: cdp [peerstatemachine.c:634]: I_Snd_CER():
I_Snd_CER(): Error on finding local host address > Socket operation on
non-socket
14(5649) DEBUG: cdp [diameter_msg.c:81]: AAABuildMsgBuffer():
AAABuildMsgBuffer(): len=184
14(5649) DEBUG: cdp [receiver.c:1013]: peer_send_msg():
peer_send_msg(): Pipe push [0x7fbdd97e0788]
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:756]: receive_loop(): select_recv():
There is something on the send pipe
14(5649) DEBUG: cdp [receiver.c:769]: receive_loop(): select_recv():
Send pipe says [0x7fbdd97e0788] 8
14(5649) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage():
AAAFreeMessage: Freeing message (0x7fbdd97e0788) 257
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: cdp [peermanager.c:143]: log_peer_list(): --- Peer
List: ---
16(5651) DEBUG: cdp [peermanager.c:145]: log_peer_list(): State of
peer: Wait_I_CEA FQDN: diameter1.dev Port: 3868 Is dynamic
16(5651) DEBUG: cdp [peermanager.c:149]: log_peer_list():
------------------
16(5651) DEBUG: cdp [session.c:396]: cdp_sessions_log(): ------- CDP
Sessions ----------------
16(5651) DEBUG: cdp [session.c:431]: cdp_sessions_log():
-------------------------------------
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 1
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:579]: do_receive(): receive_loop():
[diameter1.dev] Recv Version 1 Length 172
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 2
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:1107]: receive_message():
receive_message(): [diameter1.dev] Recv msg 257
14(5649) DEBUG: cdp [peerstatemachine.c:90]: sm_process():
sm_process(): Peer diameter1.dev State Wait_I_CEA Event I_Rcv_CEA
14(5649) DEBUG: cdp [peerstatemachine.c:698]:
count_Supported_Vendor_Id_AVPS(): Found 1 Supported_Vendor
AVPS14(5649) DEBUG: cdp [peerstatemachine.c:681]:
add_peer_application(): Application 0 of maximum 1
14(5649) DEBUG: cdp [peerstatemachine.c:750]:
save_peer_applications(): Found Supported Vendor for Application 0: 10415
14(5649) DEBUG: cdp [peerstatemachine.c:681]: add_peer_application():
Application 1 of maximum 1
14(5649) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage():
AAAFreeMessage: Freeing message (0x7fbdd97e0788) 257
14(5649) CRITICAL: <core> [core/mem/q_malloc.c:149]:
qm_debug_check_frag(): BUG: qm: prev. fragm. tail overwritten(28af,
abcdefed)[0x7fbdd97e0c98:0x7fbdd97e0cd0]! Memory allocator was called
from cdp: diameter_avp.c:365. Fragment marked by cdp:
diameter_avp.c:142. Exec from core/mem/q_malloc.c:504.
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine():
getting expired ro-sessions 5(5640) DEBUG: ims_charging
[ro_timer.c:211]: get_expired_ro_sessions(): my ticks are [32829472]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
15(5650) DEBUG: cdp [tcp_accept.c:221]: accept_loop(): accept_loop():
No connection attempts
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine():
getting expired ro-sessions 5(5640) DEBUG: ims_charging
[ro_timer.c:211]: get_expired_ro_sessions(): my ticks are [32829473]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): ---
Receiver cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
17(5652) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 24
17(5652) DEBUG: <core> [core/tcp_main.c:3513]: handle_ser_child():
dead child 14, pid 5649 (shutting down?)
17(5652) DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG:
io_watch_del (0xa6dee0, 24, -1, 0x0) fd_no=16 called
0(5635) ALERT: <core> [main.c:739]: handle_sigs(): child process 5649
exited by a signal 6
0(5635) ALERT: <core> [main.c:742]: handle_sigs(): core was generated
0(5635) INFO: <core> [main.c:764]: handle_sigs(): terminating due to
SIGCHLD
0(5635) DEBUG: <core> [main.c:766]: handle_sigs(): terminating due to
SIGCHLD
16(5651) INFO: <core> [main.c:819]: sig_usr(): signal 15 received
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-114.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/kamailio...Reading symbols from
/usr/lib/debug/usr/sbin/kamailio.debug...done.
done.
[New LWP 5649]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `kamailio -f kamailio.cfg -E'.
Program terminated with signal 6, Aborted.
#0 0x00007fbde6015207 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install
glibc-2.17-260.el7_6.3.x86_64 keyutils-libs-1.5.8-3.el7.x86_64
krb5-libs-1.15.1-37.el7_6.x86_64 libcom_err-1.42.9-13.el7.x86_64
libgcc-4.8.5-36.el7.x86_64 libselinux-2.5-14.1.el7.x86_64
libstdc++-4.8.5-36.el7.x86_64 libxml2-2.9.1-6.el7_2.3.x86_64
mariadb-libs-5.5.60-1.el7_5.x86_64 openssl-libs-1.0.2k-16.el7.x86_64
pcre-8.32-17.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64
zlib-1.2.7-18.el7.x86_64
(gdb) bt full
#0 0x00007fbde6015207 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007fbde60168f8 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x0000000000673469 in qm_debug_check_frag (qm=0x7fbdd94fd000,
f=0x7fbdd97e0c98, file=0x7fbdde6bb992 "cdp: diameter_avp.c", line=365,
efile=0x7dc6b7 "core/mem/q_malloc.c", eline=504)
at core/mem/q_malloc.c:151
__FUNCTION__ = "qm_debug_check_frag"
#3 0x00000000006765ec in qm_free (qmp=0x7fbdd94fd000,
p=0x7fbdd97e0cd0, file=0x7fbdde6bb992 "cdp: diameter_avp.c",
func=0x7fbdde6bd478 <__FUNCTION__.7016> "AAAFreeAVP", line=365,
mname=0x7fbdde6bb7c0 "cdp")
at core/mem/q_malloc.c:504
qm = 0x7fbdd94fd000
f = 0x7fbdd97e0c98
size = 140730526467984
next = 0x7a8db8
prev = 0x7a8db8
__FUNCTION__ = "qm_free"
#4 0x0000000000680148 in qm_shm_free (qmp=0x7fbdd94fd000,
p=0x7fbdd97e0cd0, file=0x7fbdde6bb992 "cdp: diameter_avp.c",
func=0x7fbdde6bd478 <__FUNCTION__.7016> "AAAFreeAVP", line=365,
mname=0x7fbdde6bb7c0 "cdp") at core/mem/q_malloc.c:1268
No locals.
#5 0x00007fbdde696e61 in AAAFreeAVP (avp=0x7ffe610a0860) at
diameter_avp.c:365
__FUNCTION__ = "AAAFreeAVP"
#6 0x00007fbdde65c88f in AAAFreeAVPList (avpList=0x7fbdd97e07d8) at
diameter_msg.c:396
avp_t = 0x7fbdd97e0cd0
avp = 0x7fbdd97e0bb8
#7 0x00007fbdde65cc4c in AAAFreeMessage (msg=0x7ffe610a0910) at
diameter_msg.c:416
__FUNCTION__ = "AAAFreeMessage"
#8 0x00007fbdde63f05e in Process_CEA (p=0x7fbdd979e368,
cea=0x7fbdd97e0788) at peerstatemachine.c:804
avp = 0x7fbdd97e10b0
#9 0x00007fbdde638223 in sm_process (p=0x7fbdd979e368,
event=I_Rcv_CEA, msg=0x7fbdd97e0788, peer_locked=0, sock=8) at
peerstatemachine.c:166
result_code = -563425872
next_event = 32701
msg_received = 0
__FUNCTION__ = "sm_process"
#10 0x00007fbdde6874be in receive_message (msg=0x7fbdd97e0788,
sp=0x7fbde59538b0) at receiver.c:1147
avp1 = 0xde6b2c50
avp2 = 0x7fbdd97e0990
__FUNCTION__ = "receive_message"
#11 0x00007fbdde67c5bb in do_receive (sp=0x7fbde59538b0) at receiver.c:598
cnt = 152
n = 152
version = 1
dst = 0x7fbdd97e1164 ""
dmsg = 0x7fbdd97e0788
__FUNCTION__ = "do_receive"
#12 0x00007fbdde68038e in receive_loop (original_peer=0x7fbdd979e368)
at receiver.c:805
rfds = {__fds_bits = {256, 0 <repeats 15 times>}}
efds = {__fds_bits = {0 <repeats 16 times>}}
tv = {tv_sec = 0, tv_usec = 999998}
n = 1
max = 21
cnt = 1
msg = 0x0
sp = 0x7fbde59538b0
sp2 = 0x7fbde59538b0
p = 0x7fbdd979e368
fd = 8
fd_exchange_pipe_local = 21
__FUNCTION__ = "receive_loop"
#13 0x00007fbdde679aec in receiver_process (p=0x7fbdd979e368) at
receiver.c:464
---Type <return> to continue, or q <return> to quit---
__FUNCTION__ = "receiver_process"
#14 0x00007fbdde62a7d5 in diameter_peer_start (blocking=0) at
diameter_peer.c:289
pid = 0
k = -1
p = 0x7fbdd979e368
__FUNCTION__ = "diameter_peer_start"
#15 0x00007fbdde61c9a8 in cdp_child_init (rank=0) at cdp_mod.c:243
__FUNCTION__ = "cdp_child_init"
#16 0x000000000053b6b1 in init_mod_child (m=0x7fbde5885150, rank=0) at
core/sr_module.c:943
__FUNCTION__ = "init_mod_child"
#17 0x000000000053b353 in init_mod_child (m=0x7fbde5885dc8, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#18 0x000000000053b353 in init_mod_child (m=0x7fbde5886190, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#19 0x000000000053b353 in init_mod_child (m=0x7fbde58865d0, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#20 0x000000000053ba85 in init_child (rank=0) at core/sr_module.c:970
No locals.
#21 0x0000000000424fe5 in main_loop () at main.c:1701
i = 4
pid = 5641
si = 0x0
si_desc = "udp receiver child=3 sock=10.10.10.10:5060
<http://10.10.10.10:5060>\000\275\177\000\000\300\023\na\376\177\000\000\022\000\000\000\000\000\000\000\000\000\000\004\000\000\000\000\000\000\200\000\000\000\000\000\263\215z",
'\000' <repeats 13 times>,
"\220\026\na\376\177\000\000\207\"\003\346\275\177\000\000\260yw\000\000\000\000\000\060;\223\345\275\177\000"
nrprocs = 4
woneinit = 1
__FUNCTION__ = "main_loop"
#22 0x000000000042b994 in main (argc=4, argv=0x7ffe610a1778) at
main.c:2642
cfg_stream = 0x103a020
c = -1
r = 0
tmp = 0x0
tmp_len = 0
port = 0
proto = 0
options = 0x758c10
":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:"
ret = -1
seed = 1364069336
rfd = 4
debug_save = 0
debug_flag = 0
dont_fork_cnt = 0
n_lst = 0x0
p = 0x0
st = {st_dev = 19, st_ino = 68292, st_nlink = 2, st_mode =
16832, st_uid = 995, st_gid = 994, __pad0 = 0, st_rdev = 0, st_size =
40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1550156643,
tv_nsec = 630000000}, st_mtim = {tv_sec = 1550158563,
tv_nsec = 502470819}, st_ctim = {tv_sec = 1550158563, tv_nsec =
502470819}, __unused = {0, 0, 0}}
__FUNCTION__ = "main"
(gdb)
version: kamailio 5.1.7 (x86_64/linux) 567df3
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS,
USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM,
SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY,
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_URI_SIZE
1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: 567df3
compiled on 02:06:09 Feb 2 2019 with gcc 4.8.5
--
BR,
Denys Pozniak
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference - May 6-8, 2019 -- www.kamailioworld.com
Kamailio Advanced Training - Mar 4-6, 2019 in Berlin; Mar 25-27, 2019, in Washington, DC,
USA -- www.asipto.com
1:18 p.m.
New subject: Memory allocator was called from cdp: diameter_avp.c:365
Hello!
Issue was created:
https://github.com/kamailio/kamailio/issues/1851
пт, 15 февр. 2019 г. в 09:33, Daniel-Constantin Mierla <miconda(a)gmail.com>om>:
Hello,
it looks like a buffer overflow there. I am not familiar with the cdp
module, however, if nobody takes over it, I will try to troubleshoot as I
get some spare time. So it is better to open an bug on issue tracker on
github project not to forget about this one. Also, keep the core file
because it may be needed to get some more info from it with gdb.
Cheers,
Daniel
On 14.02.19 16:46, Denys Pozniak wrote:
Hello!
I have faced with Kamailio (5.1.7) crashes, probably it is connected to
cdp module, please check the source of issue:
14(5649) INFO: cdp [receiver.c:455]: receiver_process():
receiver_process(): [diameter1.dev] Receiver process doing init on new
process...
14(5649) INFO: cdp [receiver.c:188]: add_serviced_peer():
add_serviced_peer(): Adding serviced_peer_t to receiver for peer
[diameter1.dev]
14(5649) INFO: cdp [receiver.c:460]: receiver_process():
receiver_process(): [diameter1.dev] Receiver process starting up...
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: cdp [cdp_timer]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: cdp_avp [cdp_timer]
16(5651) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [1001]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: acc [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: uac [cdp_acceptor]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: ims_charging [cdp_timer]
16(5651) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 16
rank 1001: ims_dialog [cdp_timer]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: htable [cdp_acceptor]
15(5650) DEBUG: htable [htable.c:236]: child_init(): rank is (1000)
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: carrierroute [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: dispatcher [cdp_acceptor]
16(5651) INFO: cdp [timer.c:205]: timer_process(): Timer process starting
up...
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: cdp [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: cdp_avp [cdp_acceptor]
15(5650) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [1000]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: ims_charging [cdp_acceptor]
15(5650) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 15
rank 1000: ims_dialog [cdp_acceptor]
15(5650) INFO: cdp [acceptor.c:81]: acceptor_process(): Acceptor process
starting up...
15(5650) DEBUG: cdp [tcp_accept.c:114]: create_socket(): create_sockets:
create socket and bind for IPv4...
15(5650) WARNING: cdp [tcp_accept.c:121]: create_socket():
create_socket(): Trying to open/bind/listen on 10.10.10.10 port 38680
15(5650) WARNING: cdp [tcp_accept.c:146]: create_socket():
create_socket(): Successful socket open/bind/listen on 10.10.10.10 port
38680
15(5650) INFO: cdp [acceptor.c:95]: acceptor_process(): Acceptor opened
sockets. Entering accept loop ...
[root@10-10-10-10 kamailio]# 17(5652) DEBUG: <core>
[core/sr_module.c:942]: init_mod_child(): idx 17 rank -4: kex [tcp main
process]
17(5652) DEBUG: kex [kex_mod.c:157]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[srid-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: corex [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: tm [tcp main process]
17(5652) DEBUG: tm [callid.c:137]: child_init_callid(): callid: '
46ac84cd57961b27-5652(a)10.10.10.10'
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: tmx [tcp main process]
17(5652) DEBUG: tmx [tmx_mod.c:261]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: sl [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: usrloc [tcp main process]
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[ulcx-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: registrar [tcp main process]
17(5652) DEBUG: <core> [sruid.c:106]: sruid_init(): root for sruid is
[uloc-5c658bbb-1614-] (0 / 19)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: ctl [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: acc [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: uac [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: htable [tcp main process]
17(5652) DEBUG: htable [htable.c:236]: child_init(): rank is (-4)
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: carrierroute [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: dispatcher [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: cdp [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: cdp_avp [tcp main process]
17(5652) DEBUG: cdp_avp [cdp_avp_mod.c:211]: cdp_avp_child_init():
Initializing child in module cdp_avp for rank [-4]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: ims_charging [tcp main process]
17(5652) DEBUG: <core> [core/sr_module.c:942]: init_mod_child(): idx 17
rank -4: ims_dialog [tcp main process]
17(5652) DEBUG: <core> [core/local_timer.c:61]: init_local_timer():
timer_list between 0xa6e0a8 and 0xab20a8
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 7, 4, 0x7fbdd97d7bec), fd_no=0
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 8, 4, 0x7fbdd97d7c78), fd_no=1
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 9, 4, 0x7fbdd97d7d04), fd_no=2
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 10, 4, 0x7fbdd97d7d90), fd_no=3
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 11, 4, 0x7fbdd97d7e1c), fd_no=4
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 12, 4, 0x7fbdd97d7ea8), fd_no=5
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 13, 4, 0x7fbdd97d7f34), fd_no=6
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 15, 4, 0x7fbdd97d7fc0), fd_no=7
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 4, 4, 0x7fbdd97d804c), fd_no=8
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 16, 4, 0x7fbdd97d80d8), fd_no=9
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 17, 4, 0x7fbdd97d8164), fd_no=10
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 18, 4, 0x7fbdd97d81f0), fd_no=11
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 23, 4, 0x7fbdd97d827c), fd_no=12
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 24, 4, 0x7fbdd97d8308), fd_no=13
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 25, 4, 0x7fbdd97d8394), fd_no=14
17(5652) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG:
io_watch_add(0xa6dee0, 26, 4, 0x7fbdd97d8420), fd_no=15
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine(): getting
expired ro-sessions 5(5640) DEBUG: ims_charging [ro_timer.c:211]:
get_expired_ro_sessions(): my ticks are [32829471]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: cdp [peermanager.c:263]: peer_timer(): peer_timer():
taking care of peers...
16(5651) DEBUG: cdp [peermanager.c:280]: peer_timer(): peer_timer(): Peer
diameter1.dev State 0
16(5651) DEBUG: cdp [peerstatemachine.c:90]: sm_process(): sm_process():
Peer diameter1.dev State Closed Event Start
16(5651) INFO: cdp [peerstatemachine.c:525]: I_Snd_Conn_Req():
I_Snd_Conn_Req(): Peer diameter1.dev
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: -1 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) INFO: cdp [receiver.c:875]: peer_connect(): peer_connect():
Trying to connect to 10.10.10.20 port 3868
16(5651) INFO: cdp [receiver.c:954]: peer_connect(): peer_connect(): Peer
diameter1.dev:3868 connected
14(5649) DEBUG: cdp [receiver.c:702]: receive_loop(): select_recv(): There
is something on the fd exchange pipe
14(5649) DEBUG: cdp [receiver.c:711]: receive_loop(): select_recv(): fd
exchange pipe says fd [8] for peer 0x7fbdd979e368:[diameter1.dev]
14(5649) DEBUG: cdp [peerstatemachine.c:90]: sm_process(): sm_process():
Peer diameter1.dev State Wait_Conn_Ack Event I_Rcv_Conn_Ack
14(5649) DEBUG: cdp [diameter_msg.c:184]: AAANewMessage(): AAANewMessage:
param session received null and it's a request!!
14(5649) ERROR: cdp [peerstatemachine.c:634]: I_Snd_CER(): I_Snd_CER():
Error on finding local host address > Socket operation on non-socket
14(5649) DEBUG: cdp [diameter_msg.c:81]: AAABuildMsgBuffer():
AAABuildMsgBuffer(): len=184
14(5649) DEBUG: cdp [receiver.c:1013]: peer_send_msg(): peer_send_msg():
Pipe push [0x7fbdd97e0788]
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:756]: receive_loop(): select_recv(): There
is something on the send pipe
14(5649) DEBUG: cdp [receiver.c:769]: receive_loop(): select_recv(): Send
pipe says [0x7fbdd97e0788] 8
14(5649) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage():
AAAFreeMessage: Freeing message (0x7fbdd97e0788) 257
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 0
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
16(5651) DEBUG: cdp [peermanager.c:143]: log_peer_list(): --- Peer List:
---
16(5651) DEBUG: cdp [peermanager.c:145]: log_peer_list(): State of peer:
Wait_I_CEA FQDN: diameter1.dev Port: 3868 Is dynamic
16(5651) DEBUG: cdp [peermanager.c:149]: log_peer_list():
------------------
16(5651) DEBUG: cdp [session.c:396]: cdp_sessions_log(): ------- CDP
Sessions ----------------
16(5651) DEBUG: cdp [session.c:431]: cdp_sessions_log():
-------------------------------------
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 1
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:579]: do_receive(): receive_loop():
[diameter1.dev] Recv Version 1 Length 172
14(5649) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp_receiver_peer=diameter1.dev Serviced Peers: ---
14(5649) DEBUG: cdp [receiver.c:112]: log_serviced_peers(): Peer:
diameter1.dev TCP Socket: 8 Recv.State: 2
14(5649) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
14(5649) DEBUG: cdp [receiver.c:1107]: receive_message():
receive_message(): [diameter1.dev] Recv msg 257
14(5649) DEBUG: cdp [peerstatemachine.c:90]: sm_process(): sm_process():
Peer diameter1.dev State Wait_I_CEA Event I_Rcv_CEA
14(5649) DEBUG: cdp [peerstatemachine.c:698]:
count_Supported_Vendor_Id_AVPS(): Found 1 Supported_Vendor AVPS14(5649)
DEBUG: cdp [peerstatemachine.c:681]: add_peer_application(): Application 0
of maximum 1
14(5649) DEBUG: cdp [peerstatemachine.c:750]: save_peer_applications():
Found Supported Vendor for Application 0: 10415
14(5649) DEBUG: cdp [peerstatemachine.c:681]: add_peer_application():
Application 1 of maximum 1
14(5649) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage():
AAAFreeMessage: Freeing message (0x7fbdd97e0788) 257
14(5649) CRITICAL: <core> [core/mem/q_malloc.c:149]:
qm_debug_check_frag(): BUG: qm: prev. fragm. tail overwritten(28af,
abcdefed)[0x7fbdd97e0c98:0x7fbdd97e0cd0]! Memory allocator was called from
cdp: diameter_avp.c:365. Fragment marked by cdp: diameter_avp.c:142. Exec
from core/mem/q_malloc.c:504.
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine(): getting
expired ro-sessions 5(5640) DEBUG: ims_charging [ro_timer.c:211]:
get_expired_ro_sessions(): my ticks are [32829472]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
15(5650) DEBUG: cdp [tcp_accept.c:221]: accept_loop(): accept_loop(): No
connection attempts
5(5640) DEBUG: ims_charging [ro_timer.c:252]: ro_timer_routine(): getting
expired ro-sessions 5(5640) DEBUG: ims_charging [ro_timer.c:211]:
get_expired_ro_sessions(): my ticks are [32829473]
13(5648) DEBUG: cdp [receiver.c:106]: log_serviced_peers(): --- Receiver
cdp receiver peer unknown Serviced Peers: ---
13(5648) DEBUG: cdp [receiver.c:114]: log_serviced_peers():
--------------------------------------------------------
17(5652) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 24
17(5652) DEBUG: <core> [core/tcp_main.c:3513]: handle_ser_child(): dead
child 14, pid 5649 (shutting down?)
17(5652) DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG:
io_watch_del (0xa6dee0, 24, -1, 0x0) fd_no=16 called
0(5635) ALERT: <core> [main.c:739]: handle_sigs(): child process 5649
exited by a signal 6
0(5635) ALERT: <core> [main.c:742]: handle_sigs(): core was generated
0(5635) INFO: <core> [main.c:764]: handle_sigs(): terminating due to
SIGCHLD
0(5635) DEBUG: <core> [main.c:766]: handle_sigs(): terminating due to
SIGCHLD
16(5651) INFO: <core> [main.c:819]: sig_usr(): signal 15 received
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-114.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <
http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/kamailio...Reading symbols from
/usr/lib/debug/usr/sbin/kamailio.debug...done.
done.
[New LWP 5649]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `kamailio -f kamailio.cfg -E'.
Program terminated with signal 6, Aborted.
#0 0x00007fbde6015207 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install
glibc-2.17-260.el7_6.3.x86_64 keyutils-libs-1.5.8-3.el7.x86_64
krb5-libs-1.15.1-37.el7_6.x86_64 libcom_err-1.42.9-13.el7.x86_64
libgcc-4.8.5-36.el7.x86_64 libselinux-2.5-14.1.el7.x86_64
libstdc++-4.8.5-36.el7.x86_64 libxml2-2.9.1-6.el7_2.3.x86_64
mariadb-libs-5.5.60-1.el7_5.x86_64 openssl-libs-1.0.2k-16.el7.x86_64
pcre-8.32-17.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-18.el7.x86_64
(gdb) bt full
#0 0x00007fbde6015207 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007fbde60168f8 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x0000000000673469 in qm_debug_check_frag (qm=0x7fbdd94fd000,
f=0x7fbdd97e0c98, file=0x7fbdde6bb992 "cdp: diameter_avp.c", line=365,
efile=0x7dc6b7 "core/mem/q_malloc.c", eline=504)
at core/mem/q_malloc.c:151
__FUNCTION__ = "qm_debug_check_frag"
#3 0x00000000006765ec in qm_free (qmp=0x7fbdd94fd000, p=0x7fbdd97e0cd0,
file=0x7fbdde6bb992 "cdp: diameter_avp.c", func=0x7fbdde6bd478
<__FUNCTION__.7016> "AAAFreeAVP", line=365, mname=0x7fbdde6bb7c0
"cdp")
at core/mem/q_malloc.c:504
qm = 0x7fbdd94fd000
f = 0x7fbdd97e0c98
size = 140730526467984
next = 0x7a8db8
prev = 0x7a8db8
__FUNCTION__ = "qm_free"
#4 0x0000000000680148 in qm_shm_free (qmp=0x7fbdd94fd000,
p=0x7fbdd97e0cd0, file=0x7fbdde6bb992 "cdp: diameter_avp.c",
func=0x7fbdde6bd478 <__FUNCTION__.7016> "AAAFreeAVP", line=365,
mname=0x7fbdde6bb7c0 "cdp") at core/mem/q_malloc.c:1268
No locals.
#5 0x00007fbdde696e61 in AAAFreeAVP (avp=0x7ffe610a0860) at
diameter_avp.c:365
__FUNCTION__ = "AAAFreeAVP"
#6 0x00007fbdde65c88f in AAAFreeAVPList (avpList=0x7fbdd97e07d8) at
diameter_msg.c:396
avp_t = 0x7fbdd97e0cd0
avp = 0x7fbdd97e0bb8
#7 0x00007fbdde65cc4c in AAAFreeMessage (msg=0x7ffe610a0910) at
diameter_msg.c:416
__FUNCTION__ = "AAAFreeMessage"
#8 0x00007fbdde63f05e in Process_CEA (p=0x7fbdd979e368,
cea=0x7fbdd97e0788) at peerstatemachine.c:804
avp = 0x7fbdd97e10b0
#9 0x00007fbdde638223 in sm_process (p=0x7fbdd979e368, event=I_Rcv_CEA,
msg=0x7fbdd97e0788, peer_locked=0, sock=8) at peerstatemachine.c:166
result_code = -563425872
next_event = 32701
msg_received = 0
__FUNCTION__ = "sm_process"
#10 0x00007fbdde6874be in receive_message (msg=0x7fbdd97e0788,
sp=0x7fbde59538b0) at receiver.c:1147
avp1 = 0xde6b2c50
avp2 = 0x7fbdd97e0990
__FUNCTION__ = "receive_message"
#11 0x00007fbdde67c5bb in do_receive (sp=0x7fbde59538b0) at receiver.c:598
cnt = 152
n = 152
version = 1
dst = 0x7fbdd97e1164 ""
dmsg = 0x7fbdd97e0788
__FUNCTION__ = "do_receive"
#12 0x00007fbdde68038e in receive_loop (original_peer=0x7fbdd979e368) at
receiver.c:805
rfds = {__fds_bits = {256, 0 <repeats 15 times>}}
efds = {__fds_bits = {0 <repeats 16 times>}}
tv = {tv_sec = 0, tv_usec = 999998}
n = 1
max = 21
cnt = 1
msg = 0x0
sp = 0x7fbde59538b0
sp2 = 0x7fbde59538b0
p = 0x7fbdd979e368
fd = 8
fd_exchange_pipe_local = 21
__FUNCTION__ = "receive_loop"
#13 0x00007fbdde679aec in receiver_process (p=0x7fbdd979e368) at
receiver.c:464
---Type <return> to continue, or q <return> to quit---
__FUNCTION__ = "receiver_process"
#14 0x00007fbdde62a7d5 in diameter_peer_start (blocking=0) at
diameter_peer.c:289
pid = 0
k = -1
p = 0x7fbdd979e368
__FUNCTION__ = "diameter_peer_start"
#15 0x00007fbdde61c9a8 in cdp_child_init (rank=0) at cdp_mod.c:243
__FUNCTION__ = "cdp_child_init"
#16 0x000000000053b6b1 in init_mod_child (m=0x7fbde5885150, rank=0) at
core/sr_module.c:943
__FUNCTION__ = "init_mod_child"
#17 0x000000000053b353 in init_mod_child (m=0x7fbde5885dc8, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#18 0x000000000053b353 in init_mod_child (m=0x7fbde5886190, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#19 0x000000000053b353 in init_mod_child (m=0x7fbde58865d0, rank=0) at
core/sr_module.c:939
__FUNCTION__ = "init_mod_child"
#20 0x000000000053ba85 in init_child (rank=0) at core/sr_module.c:970
No locals.
#21 0x0000000000424fe5 in main_loop () at main.c:1701
i = 4
pid = 5641
si = 0x0
si_desc = "udp receiver child=3
sock=10.10.10.10:5060\000\275\177\000\000\300\023\na\376\177\000\000\022\000\000\000\000\000\000\000\000\000\000\004\000\000\000\000\000\000\200\000\000\000\000\000\263\215z",
'\000' <repeats 13 times>,
"\220\026\na\376\177\000\000\207\"\003\346\275\177\000\000\260yw\000\000\000\000\000\060;\223\345\275\177\000"
nrprocs = 4
woneinit = 1
__FUNCTION__ = "main_loop"
#22 0x000000000042b994 in main (argc=4, argv=0x7ffe610a1778) at main.c:2642
cfg_stream = 0x103a020
c = -1
r = 0
tmp = 0x0
tmp_len = 0
port = 0
proto = 0
options = 0x758c10
":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:"
ret = -1
seed = 1364069336
rfd = 4
debug_save = 0
debug_flag = 0
dont_fork_cnt = 0
n_lst = 0x0
p = 0x0
st = {st_dev = 19, st_ino = 68292, st_nlink = 2, st_mode = 16832,
st_uid = 995, st_gid = 994, __pad0 = 0, st_rdev = 0, st_size = 40,
st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1550156643,
tv_nsec = 630000000}, st_mtim = {tv_sec = 1550158563, tv_nsec
= 502470819}, st_ctim = {tv_sec = 1550158563, tv_nsec = 502470819},
__unused = {0, 0, 0}}
__FUNCTION__ = "main"
(gdb)
version: kamailio 5.1.7 (x86_64/linux) 567df3
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS,
DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC,
Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, 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_URI_SIZE 1024,
BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: 567df3
compiled on 02:06:09 Feb 2 2019 with gcc 4.8.5
--
BR,
Denys Pozniak
_______________________________________________
Kamailio (SER) - Users Mailing
Listsr-users@lists.kamailio.orghttps://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda --
www.linkedin.com/in/miconda
Kamailio World Conference - May 6-8, 2019 -- www.kamailioworld.com
Kamailio Advanced Training - Mar 4-6, 2019 in Berlin; Mar 25-27, 2019, in Washington, DC,
USA -- www.asipto.com
--
BR,
Denys Pozniak
1904
days inactive
1905
days old
2 comments
2 participants
participants (2)
-
Daniel-Constantin Mierla -
Denys Pozniak