29 Aug
2019
29 Aug
'19
11:53 a.m.
Being reply processing, one potential operation that can be slow is
writing the acc record to the database. Any external tool blocking the
acc tables?
Cheers,
Daniel
On 29.08.19 10:26, Juha Heinanen wrote:
Daniel-Constantin Mierla writes:
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Can you see what is the next debug message
printed by pid 19674?
Below is a few lines of the process before the freeze and a
few after
(freeze took this time about 13 minutes). Looks like the process
resumed processing of the same sip request.
If you have access to the system when that blocks
in this way during
that interval, take the output of 'kamctl trap' or the backtrace with
gdb for a sip udp worker process.
Will try during the next free.
-- Juha
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: <core> [core/receive.c:241]:
receive_msg(): --- received sip message - reply - call-id:
[SDm882f01-3268f8b9028f4a395a9cb72379c4b423-ao92gd1] - cseq: [1 INVITE]
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1041]:
t_check_msg(): msg (0x7fd7cd1278a0) id=7999/19674 global id=7998/19674 T start=(nil)
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:919]:
t_reply_matching(): t_reply_matching: hash 51831 label 0 branch 0
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:974]:
t_reply_matching(): reply (0x7fd7cd1278a0) matched an active transaction
(T=0x7fd7b443ead0)!
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_hooks.c:258]:
run_trans_callbacks_internal(): DBG: trans=0x7fd7b443ead0, callback type 2, id 0 entered
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: acc [acc_logic.c:681]:
tmcb_func(): acc callback called for t(0x7fd7b443ead0) event type 2, reply code 480
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: acc [acc_logic.c:413]:
should_acc_reply(): probing acc state - code: 480 flags: 0x240005c4
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: acc [acc_logic.c:430]:
should_acc_reply(): failed acc is on
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1111]:
t_check_msg(): msg (0x7fd7cd1278a0) id=7999/19674 global id=7999/19674 T
end=0x7fd7b443ead0
Aug 28 08:31:15 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_reply.c:2243]:
reply_received(): transaction found - T:0x7fd7b443ead0 branch:0
.... freeze
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_reply.c:2256]:
reply_received(): org. status uas=408, uac[0]=408 local=0 is_invite=1)
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1041]:
t_check_msg(): msg (0x7fd7cd1278a0) id=7999/19674 global id=7999/19674 T
start=0x7fd7b443ead0
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1116]:
t_check_msg(): T (0x7fd7b443ead0) already found for msg (0x7fd7cd1278a0)!
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [tm.c:951]: t_check_status():
checked status is <480>
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1041]:
t_check_msg(): msg (0x7fd7cd1278a0) id=7999/19674 global id=7999/19674 T
start=0x7fd7b443ead0
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1116]:
t_check_msg(): T (0x7fd7b443ead0) already found for msg (0x7fd7cd1278a0)!
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [tm.c:951]: t_check_status():
checked status is <480>
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1041]:
t_check_msg(): msg (0x7fd7cd1278a0) id=7999/19674 global id=7999/19674 T
start=0x7fd7b443ead0
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [t_lookup.c:1116]:
t_check_msg(): T (0x7fd7b443ead0) already found for msg (0x7fd7cd1278a0)!
Aug 28 08:44:50 rox2 /usr/bin/sip-proxy[19674]: DEBUG: tm [tm.c:951]: t_check_status():
checked status is <480>