[SR-Users] event_route [tcp:closed] not executed

Juha Heinanen jh at tutpro.com
Tue Sep 4 12:46:24 CEST 2018


Daniel-Constantin Mierla writes:

> Can you test with latest master and debug=3, then send all debug
> messages from tcp connect to disconnect?

Below is the debug.  First REGISTER comes at 13:13:26 and un-REGISTER at
13:13:29 followed by tcp connection close.

-- Juha

Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 192.168.43.107
Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 43822, type 2
Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/tcp_main.c:1305]: tcpconn_add(): hashes: 23:2680:2459, 4
Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0x55561b5d2d40, 69, 2, 0x7f64144e38b0), fd_no=57
Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x55561b5d2d40, 69, -1, 0x0) fd_no=58 called
Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/tcp_main.c:3847]: send2child(): checking per-socket generic workers (15845/27..15874/34) [tcp:192.168.43.107:5060]
Sep  4 13:13:26 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/tcp_main.c:3875]: send2child(): selected tcp worker 0 27(15845) for activity on [tcp:192.168.43.107:5060], 0x7f64144e38b0
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7f64144e38b0, fd=12
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:1540]: tcp_read_req(): content-length=0
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/receive.c:232]: receive_msg(): --- received sip message - request - call-id: [b89bf3310da039ee] - cseq: [59445 REGISTER]
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/receive.c:287]: receive_msg(): preparing to run routing scripts...
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2225]: tcpconn_send_put(): send from reader (15845 (27)), reusing fd
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7f64144e38b0 n=519 fd=12
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012SIP/2.0 401 Unauthorized ...
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/receive.c:449]: receive_msg(): cleaning up
Sep  4 13:13:26 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0x55561b61bf40, 12, 2, 0x7f64144e38b0), fd_no=1
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:1540]: tcp_read_req(): content-length=0
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/receive.c:232]: receive_msg(): --- received sip message - request - call-id: [b89bf3310da039ee] - cseq: [59447 REGISTER]
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/socket_info.c:559]: grep_sock_info(): checking if host==us: 14==14 && [192.168.43.107] == [192.168.43.107]
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/socket_info.c:566]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2225]: tcpconn_send_put(): send from reader (15845 (27)), reusing fd
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7f64144e38b0 n=417 fd=12
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012SIP/2.0 200 OK ...
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/receive.c:449]: receive_msg(): cleaning up
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:198]: tcp_emit_closed_event(): TCP closed event creation triggered (reason: 0)
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:206]: tcp_emit_closed_event(): no callback registering for handling TCP closed event
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:315]: tcp_read_data(): EOF on 0x7f64144e38b0, FD 12 ([192.168.43.107]:43822 ->
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:316]: tcp_read_data(): -> [192.168.43.107]:5060)
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:1507]: tcp_read_req(): EOF
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x55561b61bf40, 12, -1, 0x10) fd_no=2 called
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:1661]: release_tcpconn(): releasing con 0x7f64144e38b0, state -1, fd=12, id=4 ([192.168.43.107]:43822 -> [192.168.43.107]:5060)
Sep  4 13:13:29 char /usr/bin/sip-proxy[15845]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data (nil)
Sep  4 13:13:29 char /usr/bin/sip-proxy[15893]: DEBUG: <core> [core/tcp_main.c:3307]: handle_tcp_child(): reader response= 7f64144e38b0, -1 from 0



More information about the sr-users mailing list