2024-09-04T09:44:26.363300897Z 21(558) INFO: <core> [core/cfg/cfg_ctx.c:589]: cfg_set_now(): core.debug has been changed to 3
2024-09-04T09:44:26.363336330Z 21(558) DEBUG: ctl [io_listener.c:520]: handle_stream_read(): bytes processed: 23
2024-09-04T09:44:26.363644620Z 21(558) DEBUG: ctl [io_listener.c:496]: handle_stream_read(): handle_stream read: eof on /var/run/kamailio/kamailio_ctl
2024-09-04T09:44:26.363728222Z 21(558) DEBUG: ctl [../../core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del (0x7f158d1b6380, 14, -1, 0x10) fd_no=2 called
2024-09-04T09:44:52.273273548Z 46(583) DEBUG: <core> [core/ip_addr.c:577]: print_ip(): tcpconn_new: new tcp connection: 11.15.32.1
2024-09-04T09:44:52.273324839Z 46(583) DEBUG: <core> [core/tcp_main.c:1242]: tcpconn_new(): on port 33333, type 3, socket 121
2024-09-04T09:44:52.273334127Z 46(583) DEBUG: <core> [core/tcp_main.c:1633]: tcpconn_add(): hashes: 3253:271:183, 1
2024-09-04T09:44:52.273340589Z 46(583) DEBUG: <core> [core/io_wait.h:369]: io_watch_add(): processing io_watch_add(0x55b362a68da0, 121, 2, 0x7f158e5f52d0) - fd_no=71
2024-09-04T09:44:52.273537448Z 46(583) DEBUG: <core> [core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del (0x55b362a68da0, 121, -1, 0x0) fd_no=72 called
2024-09-04T09:44:52.273553899Z 46(583) DEBUG: <core> [core/tcp_main.c:4684]: handle_tcpconn_ev(): sending to child, events 1
2024-09-04T09:44:52.273560733Z 46(583) DEBUG: <core> [core/tcp_main.c:4328]: send2child(): checking per-socket generic workers (568/31..580/43) [tls:198.18.55.66:443]
2024-09-04T09:44:52.273566763Z 46(583) DEBUG: <core> [core/tcp_main.c:4359]: send2child(): selected tcp worker idx:0 proc:31 pid:568 for activity on [tls:198.18.55.66:443], 0x7f158e5f52d0
2024-09-04T09:44:52.273715878Z 31(568) DEBUG: <core> [core/tcp_read.c:1776]: handle_io(): received n=8 con=0x7f158e5f52d0, fd=14
2024-09-04T09:44:52.273729528Z 31(568) DEBUG: tls [tls_server.c:242]: tls_complete_init(): completing tls connection initialization
2024-09-04T09:44:52.273736289Z 31(568) DEBUG: tls [tls_server.c:272]: tls_complete_init(): Using initial TLS domain TLSs<default> (dom 0x7f158dfb3d10 ctx 0x7f158e082960 sn [])
2024-09-04T09:44:52.274163332Z 31(568) DEBUG: tls [tls_domain.c:824]: sr_ssl_ctx_info_callback(): SSL handshake started
2024-09-04T09:44:52.275183499Z 31(568) DEBUG: tls [tls_domain.c:1026]: tls_server_name_cb(): received server_name (TLS extension): 'sip.frideo.eu'
2024-09-04T09:44:52.275213126Z 31(568) DEBUG: tls [tls_domain.c:1046]: tls_server_name_cb(): TLS cfg domain selected for received server name [sip.frideo.eu]: socket [:0] server name='' - switching SSL CTX to 0x7f158e082960 dom 0x7f158dfb3d10 (default)
2024-09-04T09:44:52.277623167Z 31(568) DEBUG: <core> [core/tcp_main.c:2849]: tcpconn_do_send(): sending...
2024-09-04T09:44:52.277724560Z 31(568) DEBUG: <core> [core/tcp_main.c:2885]: tcpconn_do_send(): after real write: c= 0x7f158e5f52d0 n=2504 fd=14
2024-09-04T09:44:52.277751814Z 31(568) DEBUG: <core> [core/tcp_main.c:2886]: tcpconn_do_send(): buf=
2024-09-04T09:44:52.277757769Z 
2024-09-04T09:44:52.277761715Z 31(568) DEBUG: <core> [core/io_wait.h:369]: io_watch_add(): processing io_watch_add(0x55b362ac4f40, 14, 2, 0x7f158e5f52d0) - fd_no=1
2024-09-04T09:44:52.281146110Z 31(568) DEBUG: tls [tls_domain.c:836]: sr_ssl_ctx_info_callback(): SSL handshake done
2024-09-04T09:44:52.281778180Z 31(568) DEBUG: tls [tls_server.c:459]: tls_accept(): TLS accept successful
2024-09-04T09:44:52.281792397Z 31(568) DEBUG: tls [tls_server.c:465]: tls_accept(): tls_accept: new connection from 11.15.32.1:33333 using TLSv1.3 TLS_AES_256_GCM_SHA384 256
2024-09-04T09:44:52.281798593Z 31(568) DEBUG: tls [tls_server.c:467]: tls_accept(): tls_accept: local socket: 198.18.55.66:443
2024-09-04T09:44:52.281802997Z 31(568) DEBUG: tls [tls_server.c:478]: tls_accept(): tls_accept: client did not present a certificate
2024-09-04T09:44:52.281807967Z 31(568) DEBUG: <core> [core/tcp_main.c:2849]: tcpconn_do_send(): sending...
2024-09-04T09:44:52.281854130Z 31(568) DEBUG: <core> [core/tcp_main.c:2885]: tcpconn_do_send(): after real write: c= 0x7f158e5f52d0 n=558 fd=14
2024-09-04T09:44:52.281862071Z 31(568) DEBUG: <core> [core/tcp_main.c:2886]: tcpconn_do_send(): buf=
2024-09-04T09:44:52.281866820Z �%�]�?�����Jr
2024-09-04T09:44:52.281872109Z ν�te�@K
2024-09-04T09:44:52.281876302Z c�h߷�?������,)vcJU�ٟ�Cw����V;t<��fs��ʵ{��u�fH��;�Z�쫓G� 쭄��HZ�d��:�I�濱��-���܉�����m�������f��<'�#G�"�/�N!��]�d�A�%$?�Uf�u�yBP\9AW���\��D�)c��]JQ����&�+�Cb8j�̎�dN�lP+ֳ��N��9�r��ƻ��ܥ�3�U@y��=_O
2024-09-04T09:44:52.281889145Z uM5���2�^��P��VO?��
                                                  ����'[T
2024-09-04T09:44:52.281893934Z 蛏(��h]��@>
2024-09-04T09:44:52.282041430Z 31(568) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 2
2024-09-04T09:44:52.282369561Z 31(568) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 2
2024-09-04T09:44:52.282383372Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:721]: parse_msg(): SIP Request:
2024-09-04T09:44:52.282389474Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg():  method:  <GET>
2024-09-04T09:44:52.282394332Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg():  uri:     </>
2024-09-04T09:44:52.282412860Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg():  version: <HTTP/1.1>
2024-09-04T09:44:52.282418646Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.282423773Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.282428948Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.282468076Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.282475663Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.282480603Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.282485347Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.282489973Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.282493669Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:44:52.282497016Z 31(568) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 2
2024-09-04T09:44:52.282500734Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:721]: parse_msg(): SIP Request:
2024-09-04T09:44:52.282522889Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg():  method:  <GET>
2024-09-04T09:44:52.282527620Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg():  uri:     </>
2024-09-04T09:44:52.282531981Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg():  version: <HTTP/1.1>
2024-09-04T09:44:52.282565262Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.282571081Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.282574983Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.282579209Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.282583273Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.282587475Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.282599421Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.282604111Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.282608381Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:44:52.282612261Z 31(568) DEBUG: <core> [core/receive.c:392]: receive_msg(): --- received sip message - request - call-id: [] - cseq: []
2024-09-04T09:44:52.282616218Z 31(568) DEBUG: <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined
2024-09-04T09:44:52.282620108Z 31(568) DEBUG: <core> [core/receive.c:429]: receive_msg(): handling non-sip request message
2024-09-04T09:44:52.282623989Z 31(568) DEBUG: xhttp [xhttp_mod.c:372]: xhttp_handler(): new fake msg created (333 bytes):
2024-09-04T09:44:52.282627775Z <GET / HTTP/1.1
2024-09-04T09:44:52.282631391Z Via: SIP/2.0/TLS 11.15.32.1:33333
2024-09-04T09:44:52.282634932Z X-Special: James special websocket client
2024-09-04T09:44:52.282638752Z Sec-WebSocket-Version: 13
2024-09-04T09:44:52.282642207Z Sec-WebSocket-Key: BusZNu+n1GkrSfuhBvbLQQ==
2024-09-04T09:44:52.282645830Z Connection: Upgrade
2024-09-04T09:44:52.282649294Z Upgrade: websocket
2024-09-04T09:44:52.282652832Z Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits
2024-09-04T09:44:52.282656428Z Sec-WebSocket-Protocol: sip
2024-09-04T09:44:52.282659811Z Host: sip.frideo.eu:443
2024-09-04T09:44:52.282663245Z 
2024-09-04T09:44:52.282666437Z >
2024-09-04T09:44:52.282669732Z 31(568) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 2
2024-09-04T09:44:52.282673424Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:721]: parse_msg(): SIP Request:
2024-09-04T09:44:52.282677242Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg():  method:  <GET>
2024-09-04T09:44:52.282681730Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg():  uri:     </>
2024-09-04T09:44:52.282685556Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg():  version: <HTTP/1.1>
2024-09-04T09:44:52.282689364Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.282693191Z 31(568) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:44:52.282696806Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:44:52.282700693Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:44:52.282709572Z 31(568) INFO: <script>: HTTP Request Received from 11.15.32.1:33333
2024-09-04T09:44:52.283411632Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.283415854Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.283419977Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.283424061Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283428166Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283432312Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.283457372Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.283461636Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283465515Z 31(568) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:44:52.283469394Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283492469Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283497194Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.283501089Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283506286Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.283531789Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283536292Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.283540134Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283544208Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283547903Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283551655Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283555291Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283558654Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283562084Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283565777Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.283569626Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283573096Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.283576940Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283581194Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.283585303Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283588657Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283593042Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283597110Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283601131Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283605017Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.283625924Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283630575Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.283635082Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283639001Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.283642934Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283646712Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283650608Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283654728Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283659282Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283663425Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.283667635Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283671450Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.283675354Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283679284Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283684112Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283688184Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283692142Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283696328Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.283700882Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283705363Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.283709662Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283719377Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.283724303Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283728792Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283732951Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283736788Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283740711Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283744797Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.283748655Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283752162Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.283755511Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283759713Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283763922Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.283767692Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==11 && [sip.frideo.eu] == [10.25.17.11]
2024-09-04T09:44:52.283772186Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:44:52.283776252Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283780204Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:44:52.283783772Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283787787Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9090 (advertise 0) matches port 443
2024-09-04T09:44:52.283791597Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [11.255.1.160]
2024-09-04T09:44:52.283795364Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:44:52.283804380Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [11.15.32.160]
2024-09-04T09:44:52.283809186Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9060 (advertise 0) matches port 443
2024-09-04T09:44:52.283813234Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==11 && [sip.frideo.eu] == [10.25.17.11]
2024-09-04T09:44:52.283817639Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:44:52.283821114Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283827143Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:44:52.283831780Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283836064Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9090 (advertise 0) matches port 443
2024-09-04T09:44:52.283840491Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283844724Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 80 (advertise 0) matches port 443
2024-09-04T09:44:52.283848698Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [11.255.1.160]
2024-09-04T09:44:52.283852338Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:44:52.283856447Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [11.15.32.160]
2024-09-04T09:44:52.283860246Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9090 (advertise 0) matches port 443
2024-09-04T09:44:52.283864581Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==11 && [sip.frideo.eu] == [10.25.17.11]
2024-09-04T09:44:52.283869290Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5061 (advertise 0) matches port 443
2024-09-04T09:44:52.283873425Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283877475Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5061 (advertise 0) matches port 443
2024-09-04T09:44:52.283881283Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283889988Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9091 (advertise 0) matches port 443
2024-09-04T09:44:52.283894894Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [198.18.55.66]
2024-09-04T09:44:52.283899152Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 443 (advertise 0) matches port 443
2024-09-04T09:44:52.283903398Z 31(568) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 13==12 && [sip.frideo.eu] == [11.255.1.160]
2024-09-04T09:44:52.283907848Z 31(568) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5061 (advertise 0) matches port 443
2024-09-04T09:44:52.283911949Z 31(568) DEBUG: <core> [core/name_alias.h:63]: grep_aliases(): matching (0:sip.frideo.eu:443) vs. (0:sip-anycast2.frideo.eu:0)
2024-09-04T09:44:52.283916044Z 31(568) DEBUG: <core> [core/name_alias.h:63]: grep_aliases(): matching (0:sip.frideo.eu:443) vs. (0:sip-anycast1.frideo.eu:0)
2024-09-04T09:44:52.283920066Z 31(568) DEBUG: <core> [core/name_alias.h:63]: grep_aliases(): matching (0:sip.frideo.eu:443) vs. (0:sip.frideo.eu:0)
2024-09-04T09:44:52.283924449Z 31(568) DEBUG: <core> [core/forward.c:447]: check_self(): host (0:sip.frideo.eu:443) == me
2024-09-04T09:44:52.283929024Z 31(568) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:52.283933145Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283937662Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.283941933Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283946081Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.283950694Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283955264Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.283959639Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283964348Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.283969128Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283973254Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.283977798Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:44:52.283988563Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Origin] type 0
2024-09-04T09:44:52.283993769Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.283998062Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284002574Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.284006992Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284011735Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.284016327Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284021059Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.284025643Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284030119Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.284034875Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284039815Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Special] type 0
2024-09-04T09:44:52.284044695Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Origin] type 0
2024-09-04T09:44:52.284049544Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284054170Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284058797Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284063380Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284068100Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284072154Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284076440Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284085611Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284090237Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284094358Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284098196Z 31(568) DEBUG: websocket [ws_handshake.c:242]: ws_handle_handshake(): found Sec-WebSocket-Version: 13
2024-09-04T09:44:52.284101758Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284105715Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284109043Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284112606Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284116304Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284120015Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284123487Z 31(568) DEBUG: websocket [ws_handshake.c:195]: ws_handle_handshake(): found Sec-WebSocket-Key: BusZNu+n1GkrSfuhBvbLQQ==
2024-09-04T09:44:52.284127171Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284130788Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284134682Z 31(568) DEBUG: websocket [ws_handshake.c:167]: ws_handle_handshake(): found Connection: upgrade
2024-09-04T09:44:52.284140083Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284144275Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284148204Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284152438Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284156100Z 31(568) DEBUG: websocket [ws_handshake.c:179]: ws_handle_handshake(): found Upgrade: websocket
2024-09-04T09:44:52.284159485Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.284163344Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284172556Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.284177277Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284181390Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.284185194Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284189177Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.284193711Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284197949Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.284201882Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284206518Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Extensions] type 0
2024-09-04T09:44:52.284211775Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Origin] type 0
2024-09-04T09:44:52.284216384Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284220911Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284285185Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284292169Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284297123Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284301682Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284306517Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284311143Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284316096Z 31(568) DEBUG: websocket [ws_handshake.c:206]: ws_handle_handshake(): found Sec-WebSocket-Protocol: sip
2024-09-04T09:44:52.284320316Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.284331163Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Connection] type 0
2024-09-04T09:44:52.284336452Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.284341423Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Upgrade] type 0
2024-09-04T09:44:52.284345879Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.284350317Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Key] type 0
2024-09-04T09:44:52.284354917Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.284359750Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Protocol] type 0
2024-09-04T09:44:52.284363990Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.284368430Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Sec-WebSocket-Version] type 0
2024-09-04T09:44:52.284372364Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Host] type 0
2024-09-04T09:44:52.284376188Z 31(568) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Origin] type 0
2024-09-04T09:44:52.284380504Z 31(568) DEBUG: websocket [ws_conn.c:195]: wsconn_add(): connection id [1]
2024-09-04T09:44:52.284384251Z 31(568) DEBUG: websocket [ws_conn.c:213]: wsconn_add(): new wsc => [0x7f158e612920], ref => [0]
2024-09-04T09:44:52.284388227Z 31(568) DEBUG: websocket [ws_conn.c:232]: wsconn_add(): added to conn_table wsc => [0x7f158e612920], ref => [1]
2024-09-04T09:44:52.284391872Z 31(568) DEBUG: sl [sl.c:306]: send_reply(): reply in stateless mode (sl)
2024-09-04T09:44:52.284395381Z 31(568) DEBUG: <core> [core/msg_translator.c:162]: check_via_address(): (11.15.32.1, 11.15.32.1, 0)
2024-09-04T09:44:52.284399068Z 31(568) DEBUG: sl [sl_funcs.c:564]: sl_run_callbacks(): execute callback for event type 1
2024-09-04T09:44:52.284402451Z 31(568) DEBUG: siptrace [siptrace.c:1985]: trace_sl_onreply_out(): trace off...
2024-09-04T09:44:52.284405805Z 31(568) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:52.284409484Z 31(568) DEBUG: <core> [core/tcp_main.c:2618]: tcpconn_send_put(): send from reader (568 (31)), reusing fd
2024-09-04T09:44:52.284413118Z 31(568) DEBUG: <core> [core/tcp_main.c:2849]: tcpconn_do_send(): sending...
2024-09-04T09:44:52.284416502Z 31(568) DEBUG: <core> [core/tcp_main.c:2885]: tcpconn_do_send(): after real write: c= 0x7f158e5f52d0 n=280 fd=14
2024-09-04T09:44:52.284424854Z 31(568) DEBUG: <core> [core/tcp_main.c:2886]: tcpconn_do_send(): buf=
2024-09-04T09:44:52.284428814Z õ�JP~��=H
2024-09-04T09:44:52.284433027Z 31(568) WARNING: <script>: P0772 HTTP handshake completed (from 11.15.32.1:33333 to 198.18.55.66:443)
2024-09-04T09:44:52.284457147Z 31(568) DEBUG: <core> [core/receive.c:435]: receive_msg(): finished handling non-sip request message
2024-09-04T09:44:52.284460871Z 31(568) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:44:52.284464553Z 31(568) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:44:52.284469554Z 31(568) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:44:52.284473358Z 31(568) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:44:52.284477062Z 31(568) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:44:52.284480985Z 31(568) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:44:52.284484585Z 31(568) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
2024-09-04T09:44:52.284488289Z 31(568) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
2024-09-04T09:44:52.284492135Z 31(568) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
2024-09-04T09:44:52.284495799Z 31(568) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up
2024-09-04T09:44:53.281228169Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:54.282223305Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:55.283266603Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:56.284315913Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:57.285110034Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:58.285931228Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:44:58.289199210Z 31(568) DEBUG: <core> [core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del (0x55b362ac4f40, 14, -1, 0x10) fd_no=2 called
2024-09-04T09:44:58.289232573Z 31(568) DEBUG: <core> [core/tcp_read.c:1696]: release_tcpconn(): releasing con 0x7f158e5f52d0, state 1, fd=14, id=1 ([11.15.32.1]:33333 -> [11.15.32.1]:443)
2024-09-04T09:44:58.289240021Z 31(568) DEBUG: <core> [core/tcp_read.c:1699]: release_tcpconn(): extra_data 0x7f158e5f9700
2024-09-04T09:44:58.289245948Z 46(583) DEBUG: <core> [core/tcp_main.c:3773]: handle_tcp_child(): reader response= 7f158e5f52d0, 1 from 0 
2024-09-04T09:44:58.289267008Z 46(583) DEBUG: <core> [core/io_wait.h:369]: io_watch_add(): processing io_watch_add(0x55b362a68da0, 121, 2, 0x7f158e5f52d0) - fd_no=71
2024-09-04T09:44:58.289272001Z 46(583) DEBUG: <core> [core/tcp_main.c:3905]: handle_tcp_child(): CONN_RELEASE  0x7f158e5f52d0 refcnt= 1
2024-09-04T09:44:59.286721222Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:00.287191325Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:01.288165301Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:02.289161841Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:03.290204966Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:03.485125103Z  1(538) DEBUG: <core> [core/receive.c:136]: sip_check_fline(): first line indicates a SIP request
2024-09-04T09:45:03.485165491Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 1
2024-09-04T09:45:03.485175195Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:721]: parse_msg(): SIP Request:
2024-09-04T09:45:03.485182437Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg():  method:  <INVITE>
2024-09-04T09:45:03.485189022Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg():  uri:     <sip:moon@bobbywomack.invalid;alias=11.15.32.1~33333~6;transport=ws>
2024-09-04T09:45:03.485196469Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.485204371Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.485210390Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
2024-09-04T09:45:03.485430967Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=16
2024-09-04T09:45:03.485445347Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.485452544Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.485458994Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.485464688Z  1(538) DEBUG: siptrace [siptrace.c:2335]: siptrace_net_data_recv(): processing message mode 1
2024-09-04T09:45:03.485470754Z  1(538) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.485476968Z  1(538) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.485496961Z  1(538) DEBUG: <core> [core/proxy.c:267]: mk_proxy(): doing DNS lookup...
2024-09-04T09:45:03.485502414Z  1(538) DEBUG: siptrace [siptrace_hep.c:185]: trace_send_hep3_duplicate(): setting up the socket_info
2024-09-04T09:45:03.485507160Z  1(538) DEBUG: siptrace [siptrace_hep.c:200]: trace_send_hep3_duplicate(): send sock addr activated - find the sock_info
2024-09-04T09:45:03.485511705Z  1(538) DEBUG: siptrace [siptrace_hep.c:212]: trace_send_hep3_duplicate(): found send socket: [11.15.32.160] [11.15.32.160]
2024-09-04T09:45:03.485516150Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 1
2024-09-04T09:45:03.485520967Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:721]: parse_msg(): SIP Request:
2024-09-04T09:45:03.485525049Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg():  method:  <INVITE>
2024-09-04T09:45:03.485529892Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg():  uri:     <sip:moon@bobbywomack.invalid;alias=11.15.32.1~33333~6;transport=ws>
2024-09-04T09:45:03.485534654Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.485539043Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.485543285Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
2024-09-04T09:45:03.485619930Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=16
2024-09-04T09:45:03.485648356Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.485671287Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.485682957Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.485690477Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Route] type 9
2024-09-04T09:45:03.485695501Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Route] type 9
2024-09-04T09:45:03.485700172Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.485704780Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.485709503Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10
2024-09-04T09:45:03.485713718Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [34]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.485718327Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (34)[<sip:+35315220000@sip.frideo.eu>
2024-09-04T09:45:03.485731681Z ], to tag (0)[]
2024-09-04T09:45:03.485736063Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Contact] type 7
2024-09-04T09:45:03.485741232Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.485746124Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.485751065Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.485755994Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Max-Forwards] type 8
2024-09-04T09:45:03.485760772Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:03.485765524Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0
2024-09-04T09:45:03.485769359Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:03.485774760Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 1
2024-09-04T09:45:03.485778887Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:721]: parse_msg(): SIP Request:
2024-09-04T09:45:03.485782540Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg():  method:  <INVITE>
2024-09-04T09:45:03.485786589Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg():  uri:     <sip:moon@bobbywomack.invalid;alias=11.15.32.1~33333~6;transport=ws>
2024-09-04T09:45:03.485791324Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.485795909Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.485800592Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
2024-09-04T09:45:03.485805611Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=16
2024-09-04T09:45:03.485810726Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.485918529Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.485940018Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.485961882Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Route] type 9
2024-09-04T09:45:03.485980997Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Route] type 9
2024-09-04T09:45:03.485987481Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.485992064Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.485996283Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10
2024-09-04T09:45:03.486000670Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [34]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.486005577Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (34)[<sip:+35315220000@sip.frideo.eu>
2024-09-04T09:45:03.486010496Z ], to tag (0)[]
2024-09-04T09:45:03.486016099Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Contact] type 7
2024-09-04T09:45:03.486020918Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.486025434Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.486030029Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.486034932Z  1(538) DEBUG: <core> [core/receive.c:392]: receive_msg(): --- received sip message - request - call-id: [te-e4d31-c287-4a7c-8c8a-1244552062] - cseq: [1244552062 INVITE]
2024-09-04T09:45:03.486039535Z  1(538) DEBUG: <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined
2024-09-04T09:45:03.486043898Z  1(538) DEBUG: <core> [core/receive.c:474]: receive_msg(): preparing to run routing scripts...
2024-09-04T09:45:03.486419536Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Max-Forwards] type 8
2024-09-04T09:45:03.486707814Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:03.486719586Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0
2024-09-04T09:45:03.486724304Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:03.486728607Z  1(538) DEBUG: siputils [checks.c:182]: has_totag(): no totag
2024-09-04T09:45:03.486732697Z  1(538) DEBUG: <core> [core/select.c:449]: run_select(): Calling SELECT 0x7f15d77ea910
2024-09-04T09:45:03.486737532Z  1(538) DEBUG: <core> [core/select.c:449]: run_select(): Calling SELECT 0x7f15d77ed0d0
2024-09-04T09:45:03.486742208Z  1(538) DEBUG: pv [pv_core.c:1095]: pv_get_useragent(): no User-Agent header
2024-09-04T09:45:03.486746755Z  1(538) DEBUG: pv [pv_core.c:1559]: pv_get_authattr(): no [Proxy-]Authorization header
2024-09-04T09:45:03.486763612Z  1(538) DEBUG: sanity [sanity.c:254]: check_ruri_sip_version(): check_ruri_sip_version entered
2024-09-04T09:45:03.486769153Z  1(538) DEBUG: sanity [sanity.c:278]: check_ruri_sip_version(): check_ruri_sip_version passed
2024-09-04T09:45:03.486774136Z  1(538) DEBUG: sanity [sanity.c:286]: check_ruri_scheme(): check_ruri_scheme entered
2024-09-04T09:45:03.486778399Z  1(538) DEBUG: sanity [sanity.c:305]: check_ruri_scheme(): check_ruri_scheme passed
2024-09-04T09:45:03.486782934Z  1(538) DEBUG: sanity [sanity.c:327]: check_required_headers(): check_required_headers entered
2024-09-04T09:45:03.486787388Z  1(538) DEBUG: sanity [sanity.c:350]: check_required_headers(): check_required_headers passed
2024-09-04T09:45:03.486791303Z  1(538) DEBUG: sanity [sanity.c:519]: check_cseq_method(): check_cseq_method entered
2024-09-04T09:45:03.486795227Z  1(538) DEBUG: sanity [sanity.c:553]: check_cseq_method(): check_cseq_method passed
2024-09-04T09:45:03.486798823Z  1(538) DEBUG: sanity [sanity.c:563]: check_cseq_value(): check_cseq_value entered
2024-09-04T09:45:03.486803145Z  1(538) DEBUG: sanity [sanity.c:591]: check_cseq_value(): check_cseq_value passed
2024-09-04T09:45:03.486806880Z  1(538) DEBUG: sanity [sanity.c:601]: check_cl(): check_cl entered
2024-09-04T09:45:03.486810907Z  1(538) DEBUG: sanity [sanity.c:626]: check_cl(): check_cl passed
2024-09-04T09:45:03.486815180Z  1(538) DEBUG: sanity [sanity.c:639]: check_expires_value(): check_expires_value entered
2024-09-04T09:45:03.486818876Z  1(538) DEBUG: sanity [sanity.c:675]: check_expires_value(): no expires header found
2024-09-04T09:45:03.486825001Z  1(538) DEBUG: sanity [sanity.c:772]: check_parse_uris(): check_parse_uris entered
2024-09-04T09:45:03.486828781Z  1(538) DEBUG: sanity [sanity.c:776]: check_parse_uris(): parsing ruri
2024-09-04T09:45:03.486832697Z  1(538) DEBUG: sanity [sanity.c:789]: check_parse_uris(): looking up From header
2024-09-04T09:45:03.486836207Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1a56f142c2ed4d2f
2024-09-04T09:45:03.486840308Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
2024-09-04T09:45:03.486844915Z  1(538) DEBUG: sanity [sanity.c:804]: check_parse_uris(): looking up To header
2024-09-04T09:45:03.486848940Z  1(538) DEBUG: sanity [sanity.c:854]: check_parse_uris(): check_parse_uris passed
2024-09-04T09:45:03.486852276Z  1(538) DEBUG: sanity [sanity_mod.c:252]: w_sanity_check(): sanity checks result: 1
2024-09-04T09:45:03.486855635Z  1(538) DEBUG: siputils [checks.c:182]: has_totag(): no totag
2024-09-04T09:45:03.486860469Z  1(538) DEBUG: <script>: [te-e4d31-c287-4a7c-8c8a-1244552062] Adding Route header to REGISTER message
2024-09-04T09:45:03.486864461Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 11==11 && [10.25.17.11] == [10.25.17.11]
2024-09-04T09:45:03.486873869Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
2024-09-04T09:45:03.486878148Z  1(538) DEBUG: <core> [core/forward.c:447]: check_self(): host (0:10.25.17.11:5060) == me
2024-09-04T09:45:03.486882076Z  1(538) DEBUG: rr [loose.c:1135]: redo_route_params(): Topmost route URI: 'sip:10.25.17.11;lr;r2=on' is me
2024-09-04T09:45:03.486886023Z  1(538) DEBUG: rr [loose.c:1325]: is_direction(): param ftag not found
2024-09-04T09:45:03.486889655Z  1(538) DEBUG: rr [record.c:489]: record_route(): inserted record route (r2: 1 - plen: 0)
2024-09-04T09:45:03.486893975Z  1(538) DEBUG: tm [t_lookup.c:1565]: t_check_msg(): msg (0x7f15d7b44bf0) id=1/538 global id=0/0 T start=0xffffffffffffffff
2024-09-04T09:45:03.486898667Z  1(538) DEBUG: tm [t_lookup.c:781]: t_lookup_request(): start searching: hash=5851, isACK=0
2024-09-04T09:45:03.486902528Z  1(538) DEBUG: tm [t_lookup.c:499]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK-d8754z-cc2c63344f5218d]
2024-09-04T09:45:03.486906863Z  1(538) DEBUG: tm [t_lookup.c:981]: t_lookup_request(): no transaction found
2024-09-04T09:45:03.486910662Z  1(538) DEBUG: tm [t_lookup.c:1637]: t_check_msg(): msg (0x7f15d7b44bf0) id=1/538 global id=1/538 T end=(nil)
2024-09-04T09:45:03.486915675Z  1(538) INFO: <script>: [te-e4d31-c287-4a7c-8c8a-1244552062] Initial INVITE received from 11.15.32.1:5060 to moon@bobbywomack.invalid:5060;transport=ws
2024-09-04T09:45:03.486920980Z  1(538) DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 10 
2024-09-04T09:45:03.486925196Z  1(538) DEBUG: <script>: [te-e4d31-c287-4a7c-8c8a-1244552062] Removing some X-headers before relaying INVITE message
2024-09-04T09:45:03.486947040Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.486951572Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.486956015Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Route] type 9
2024-09-04T09:45:03.486960957Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.486965459Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Route] type 9
2024-09-04T09:45:03.486969657Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.486979761Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.486984241Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.486988275Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.486992075Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.486995777Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Contact] type 7
2024-09-04T09:45:03.487000609Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.487005055Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.487009233Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.487013496Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.487017491Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.487021902Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Max-Forwards] type 8
2024-09-04T09:45:03.487026100Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.487030397Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:03.487034933Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [X-Encode-Contact-Header] type 0
2024-09-04T09:45:03.487039519Z  1(538) ERROR: <script>: [te-e4d31-c287-4a7c-8c8a-1244552062] P1052 WS initial INVITE arrives without appropriate KSS header field
2024-09-04T09:45:03.488572337Z  1(538) DEBUG: rr [loose.c:80]: is_preloaded(): is_preloaded: Yes
2024-09-04T09:45:03.488633673Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 11==11 && [10.25.17.11] == [10.25.17.11]
2024-09-04T09:45:03.488640285Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
2024-09-04T09:45:03.488644982Z  1(538) DEBUG: <core> [core/forward.c:447]: check_self(): host (0:10.25.17.11:5060) == me
2024-09-04T09:45:03.488649351Z  1(538) DEBUG: rr [loose.c:886]: after_loose(): Topmost route URI: 'sip:10.25.17.11;lr;r2=on' is me
2024-09-04T09:45:03.488949645Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==11 && [198.18.55.66] == [10.25.17.11]
2024-09-04T09:45:03.488959691Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:45:03.488965162Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [198.18.55.66]
2024-09-04T09:45:03.488970346Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:45:03.488977192Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [198.18.55.66]
2024-09-04T09:45:03.488982064Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9090 (advertise 0) matches port 443
2024-09-04T09:45:03.489615838Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [198.18.55.66]
2024-09-04T09:45:03.489667301Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 80 (advertise 0) matches port 443
2024-09-04T09:45:03.489674683Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [11.255.1.160]
2024-09-04T09:45:03.489679899Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 443
2024-09-04T09:45:03.489684927Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [11.15.32.160]
2024-09-04T09:45:03.489689326Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9090 (advertise 0) matches port 443
2024-09-04T09:45:03.489696280Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==11 && [198.18.55.66] == [10.25.17.11]
2024-09-04T09:45:03.489702085Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5061 (advertise 0) matches port 443
2024-09-04T09:45:03.489707121Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [198.18.55.66]
2024-09-04T09:45:03.489711792Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 5061 (advertise 0) matches port 443
2024-09-04T09:45:03.489982542Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [198.18.55.66]
2024-09-04T09:45:03.489990963Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 9091 (advertise 0) matches port 443
2024-09-04T09:45:03.490004860Z  1(538) DEBUG: <core> [core/socket_info.c:737]: grep_sock_info(): checking if host==us: 12==12 && [198.18.55.66] == [198.18.55.66]
2024-09-04T09:45:03.490010065Z  1(538) DEBUG: <core> [core/socket_info.c:741]: grep_sock_info(): checking if port 443 (advertise 0) matches port 443
2024-09-04T09:45:03.490094294Z  1(538) DEBUG: rr [loose.c:826]: rr_do_force_send_socket(): set send socket 0x7f15d779d7e0 for local route uri: sip:198.18.55.66:443;transport=ws;lr;r2=on
2024-09-04T09:45:03.490100293Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:03.490104961Z  1(538) DEBUG: rr [loose.c:181]: find_next_route(): No next Route HF found
2024-09-04T09:45:03.490109398Z  1(538) DEBUG: rr [loose.c:950]: after_loose(): no next URI found
2024-09-04T09:45:03.490125832Z  1(538) DEBUG: nathelper [nathelper.c:1251]: ki_handle_ruri_alias_mode(): setting dst_uri to <sip:11.15.32.1:33333;transport=ws>
2024-09-04T09:45:03.490130909Z  1(538) DEBUG: nathelper [nathelper.c:1273]: ki_handle_ruri_alias_mode(): rewriting r-uri to <sip:moon@bobbywomack.invalid;transport=ws>
2024-09-04T09:45:03.490135452Z  1(538) NOTICE: <script>: [te-e4d31-c287-4a7c-8c8a-1244552062] P1052 About to relay WS call to 11.15.32.1:33333 from tls:198.18.55.66:443 ($du is sip:11.15.32.1:33333;transport=ws)
2024-09-04T09:45:03.490140096Z  1(538) DEBUG: tm [t_lookup.c:1868]: t_newtran(): msg (0x7f15d7b44bf0) id=1/538 global id=1/538 T start=(nil)
2024-09-04T09:45:03.490144048Z  1(538) DEBUG: tm [t_lookup.c:781]: t_lookup_request(): start searching: hash=5851, isACK=0
2024-09-04T09:45:03.490149114Z  1(538) DEBUG: tm [t_lookup.c:499]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK-d8754z-cc2c63344f5218d]
2024-09-04T09:45:03.490153407Z  1(538) DEBUG: tm [t_lookup.c:981]: t_lookup_request(): no transaction found
2024-09-04T09:45:03.490158614Z  1(538) DEBUG: <core> [core/crypto/md5utils.c:67]: MD5StringArray(): MD5 calculated: 6a9011beb1cadc66c1a0d059f0abb104
2024-09-04T09:45:03.490162799Z  1(538) DEBUG: tm [h_table.c:415]: build_cell(): created new cell 0x7f158e609cf0
2024-09-04T09:45:03.490166769Z  1(538) DEBUG: tm [t_funcs.c:349]: t_relay_to(): new INVITE
2024-09-04T09:45:03.490170514Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:03.490174681Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:03.490178745Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.490182553Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <100>
2024-09-04T09:45:03.490186332Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Jamesb trying>
2024-09-04T09:45:03.490205200Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.490210019Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:03.490214928Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:03.490227319Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:03.490233072Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.490237622Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.490241904Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.490246202Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.490249003Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.490251720Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10
2024-09-04T09:45:03.490255387Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [34]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.490258330Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (34)[<sip:+35315220000@sip.frideo.eu>
2024-09-04T09:45:03.490261110Z ], to tag (0)[]
2024-09-04T09:45:03.490263341Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.490265893Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.490268404Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.490271042Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Server] type 29
2024-09-04T09:45:03.490273559Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:03.490276083Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0
2024-09-04T09:45:03.490278507Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:03.490280873Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:03.490283424Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:03.490285820Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.490288243Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <100>
2024-09-04T09:45:03.490290653Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Jamesb trying>
2024-09-04T09:45:03.490297221Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.490300174Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:03.490302980Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:03.490305809Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:03.490308936Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.490311508Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.490313950Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.490316454Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.490318956Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.490321481Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10
2024-09-04T09:45:03.490324113Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [34]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.490326718Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (34)[<sip:+35315220000@sip.frideo.eu>
2024-09-04T09:45:03.490329336Z ], to tag (0)[]
2024-09-04T09:45:03.490331590Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.490334091Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.490336600Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.490339228Z  1(538) DEBUG: siptrace [siptrace.c:2476]: siptrace_net_data_sent(): processing message mode 1
2024-09-04T09:45:03.490341570Z  1(538) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.490343981Z  1(538) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.490346304Z  1(538) DEBUG: <core> [core/proxy.c:267]: mk_proxy(): doing DNS lookup...
2024-09-04T09:45:03.490348645Z  1(538) DEBUG: siptrace [siptrace_hep.c:185]: trace_send_hep3_duplicate(): setting up the socket_info
2024-09-04T09:45:03.490351028Z  1(538) DEBUG: siptrace [siptrace_hep.c:200]: trace_send_hep3_duplicate(): send sock addr activated - find the sock_info
2024-09-04T09:45:03.490356052Z  1(538) DEBUG: siptrace [siptrace_hep.c:212]: trace_send_hep3_duplicate(): found send socket: [11.15.32.160] [11.15.32.160]
2024-09-04T09:45:03.490358868Z  1(538) DEBUG: tm [t_reply.c:634]: _reply_light(): reply sent out - buf=0x7f15d78c37f0: SIP/2.0 100 Jamesb t... shmem=0x7f158e5fd6a0: SIP/2.0 100 Jamesb t
2024-09-04T09:45:03.490361609Z  1(538) DEBUG: tm [t_reply.c:650]: _reply_light(): finished
2024-09-04T09:45:03.490364220Z  1(538) DEBUG: <core> [core/dns_cache.c:3256]: dns_srv_sip_resolve(): (11.15.32.1, 0, 0), ip, ret=0
2024-09-04T09:45:03.490366792Z  1(538) DEBUG: <core> [core/msg_translator.c:1869]: check_boundaries(): no multi-part body
2024-09-04T09:45:03.490369249Z  1(538) DEBUG: <core> [core/tcp_main.c:1746]: _tcpconn_find(): found connection by peer address (id: 1)
2024-09-04T09:45:03.490371637Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 1
2024-09-04T09:45:03.490374077Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:721]: parse_msg(): SIP Request:
2024-09-04T09:45:03.490376450Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg():  method:  <INVITE>
2024-09-04T09:45:03.490378910Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg():  uri:     <sip:moon@bobbywomack.invalid;transport=ws>
2024-09-04T09:45:03.490381490Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.490383911Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Record-Route] type 10
2024-09-04T09:45:03.490386515Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Record-Route] type 10
2024-09-04T09:45:03.490389025Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.490391552Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKbd61.6a9011beb1cadc66c1a0d059f0abb104.0>; state=16
2024-09-04T09:45:03.490394317Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.490396737Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.490399101Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.490401443Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.490403831Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=6
2024-09-04T09:45:03.490406478Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:03.490416857Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=16
2024-09-04T09:45:03.490421559Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.490425364Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=ffffffffffffffff
2024-09-04T09:45:03.490429648Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_headers(): this is the second via
2024-09-04T09:45:03.490432483Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.490435091Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.490437705Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10
2024-09-04T09:45:03.490440215Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [34]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.490442801Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (34)[<sip:+35315220000@sip.frideo.eu>
2024-09-04T09:45:03.490445430Z ], to tag (0)[]
2024-09-04T09:45:03.490447676Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Contact] type 7
2024-09-04T09:45:03.490450203Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.490452663Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.490455188Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.490457791Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Max-Forwards] type 8
2024-09-04T09:45:03.490460338Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:03.490462856Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0
2024-09-04T09:45:03.490465288Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:03.490467717Z  1(538) WARNING: tm [../../core/forward.h:209]: msg_send_buffer(): TCP/TLS connection for WebSocket could not be found
2024-09-04T09:45:03.490470176Z  1(538) DEBUG: tm [t_fwd.c:1571]: t_send_branch(): send to 11.15.32.1:33333 (5) failed
2024-09-04T09:45:03.490473237Z  1(538) WARNING: tm [t_fwd.c:1591]: t_send_branch(): sending request on branch 0 failed
2024-09-04T09:45:03.490475709Z  1(538) DEBUG: tm [t_funcs.c:358]: t_relay_to(): t_forward_nonack returned error -1 (-477)
2024-09-04T09:45:03.490482712Z  1(538) DEBUG: tm [t_funcs.c:376]: t_relay_to(): -477 error reply generation delayed 
2024-09-04T09:45:03.490507240Z  1(538) WARNING: <script>: [te-e4d31-c287-4a7c-8c8a-1244552062] P1052 Failed relaying WS call to 11.15.32.1:33333
2024-09-04T09:45:03.490509797Z  1(538) DEBUG: tm [t_lookup.c:1565]: t_check_msg(): msg (0x7f15d7b44bf0) id=1/538 global id=1/538 T start=0x7f158e609cf0
2024-09-04T09:45:03.490512294Z  1(538) DEBUG: tm [t_lookup.c:1641]: t_check_msg(): T (0x7f158e609cf0) already found for msg (0x7f15d7b44bf0)!
2024-09-04T09:45:03.490514783Z  1(538) DEBUG: tm [t_reply.c:1782]: cleanup_uac_timers(): RETR/FR timers reset
2024-09-04T09:45:03.490517067Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:03.490519630Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:03.490522018Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.490524465Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <503>
2024-09-04T09:45:03.490527604Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Relaying over WS to next hop failed P23>
2024-09-04T09:45:03.490530240Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.490532734Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:03.490535754Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:03.490538577Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:03.490541230Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.490543614Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.490545973Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.490551270Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.490554125Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.490556846Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=a87f9558cf5646d575962040dd7151c2-7daca974
2024-09-04T09:45:03.490559527Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
2024-09-04T09:45:03.490562071Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [80]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.490564730Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:+35315220000@sip.frideo.eu>], to tag (41)[a87f9558cf5646d575962040dd7151c2-7daca974]
2024-09-04T09:45:03.490567567Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.490570065Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.490572534Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.490575203Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Server] type 29
2024-09-04T09:45:03.490577698Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:03.490580190Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0
2024-09-04T09:45:03.490582575Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:03.490585179Z  1(538) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:03.490587790Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:03.490590174Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.490592599Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <503>
2024-09-04T09:45:03.490595012Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Relaying over WS to next hop failed P23>
2024-09-04T09:45:03.490597568Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.490599993Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:03.490602567Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:03.490607817Z  1(538) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:03.490610857Z  1(538) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.490613328Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.490615813Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.490618207Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.490620682Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.490623177Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=a87f9558cf5646d575962040dd7151c2-7daca974
2024-09-04T09:45:03.490625699Z  1(538) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
2024-09-04T09:45:03.490628119Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [80]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.490630777Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:+35315220000@sip.frideo.eu>], to tag (41)[a87f9558cf5646d575962040dd7151c2-7daca974]
2024-09-04T09:45:03.490633798Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.490636408Z  1(538) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.490638819Z  1(538) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.490641508Z  1(538) DEBUG: siptrace [siptrace.c:2476]: siptrace_net_data_sent(): processing message mode 1
2024-09-04T09:45:03.490643898Z  1(538) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.490646231Z  1(538) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.490648564Z  1(538) DEBUG: <core> [core/proxy.c:267]: mk_proxy(): doing DNS lookup...
2024-09-04T09:45:03.490650857Z  1(538) DEBUG: siptrace [siptrace_hep.c:185]: trace_send_hep3_duplicate(): setting up the socket_info
2024-09-04T09:45:03.490653239Z  1(538) DEBUG: siptrace [siptrace_hep.c:200]: trace_send_hep3_duplicate(): send sock addr activated - find the sock_info
2024-09-04T09:45:03.490655598Z  1(538) DEBUG: siptrace [siptrace_hep.c:212]: trace_send_hep3_duplicate(): found send socket: [11.15.32.160] [11.15.32.160]
2024-09-04T09:45:03.490658065Z  1(538) DEBUG: tm [t_reply.c:634]: _reply_light(): reply sent out - buf=0x7f15d78c37f0: SIP/2.0 503 Relaying... shmem=0x7f158e5fd6a0: SIP/2.0 503 Relaying
2024-09-04T09:45:03.490663234Z  1(538) DEBUG: tm [t_funcs.c:133]: put_on_wait(): put T [0x7f158e609cf0] on wait
2024-09-04T09:45:03.490665880Z  1(538) DEBUG: tm [t_reply.c:650]: _reply_light(): finished
2024-09-04T09:45:03.490668267Z  1(538) DEBUG: <core> [core/receive.c:532]: receive_msg(): request-route executed in: 3798 usec
2024-09-04T09:45:03.490670748Z  1(538) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:45:03.490673315Z  1(538) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:45:03.490675762Z  1(538) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:45:03.490678119Z  1(538) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:45:03.490680560Z  1(538) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:45:03.490682978Z  1(538) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
2024-09-04T09:45:03.490685422Z  1(538) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
2024-09-04T09:45:03.490687847Z  1(538) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
2024-09-04T09:45:03.490690746Z  1(538) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
2024-09-04T09:45:03.490693328Z  1(538) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up
2024-09-04T09:45:03.937352122Z 13(550) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:03.937574358Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:03.937584379Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.937588992Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <503>
2024-09-04T09:45:03.937593132Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Relaying over WS to next hop failed P23>
2024-09-04T09:45:03.937597161Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.937601275Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:03.937605590Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:03.937617623Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:03.938189726Z 13(550) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.938222074Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.938227127Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.938230935Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.938234853Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.938239130Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=a87f9558cf5646d575962040dd7151c2-7daca974
2024-09-04T09:45:03.938243442Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
2024-09-04T09:45:03.938247252Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [80]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.938250801Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:+35315220000@sip.frideo.eu>], to tag (41)[a87f9558cf5646d575962040dd7151c2-7daca974]
2024-09-04T09:45:03.938255518Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.938259627Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.938263934Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.938268807Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Server] type 29
2024-09-04T09:45:03.938272834Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:03.938277083Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0
2024-09-04T09:45:03.938281135Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:03.938288155Z 13(550) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:03.938292504Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:03.938296604Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:03.938300772Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <503>
2024-09-04T09:45:03.938304632Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Relaying over WS to next hop failed P23>
2024-09-04T09:45:03.938318845Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:03.938334702Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:03.938340877Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:03.938345498Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:03.938350233Z 13(550) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:03.938353903Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:03.938357549Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:03.938361404Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:03.938365204Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:03.938368723Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=a87f9558cf5646d575962040dd7151c2-7daca974
2024-09-04T09:45:03.938372816Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
2024-09-04T09:45:03.938376330Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [80]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:03.938380326Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:+35315220000@sip.frideo.eu>], to tag (41)[a87f9558cf5646d575962040dd7151c2-7daca974]
2024-09-04T09:45:03.938387957Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:03.938392357Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:03.938396364Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:03.938400247Z 13(550) DEBUG: siptrace [siptrace.c:2476]: siptrace_net_data_sent(): processing message mode 1
2024-09-04T09:45:03.938403734Z 13(550) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.938429871Z 13(550) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:03.938434779Z 13(550) DEBUG: <core> [core/proxy.c:267]: mk_proxy(): doing DNS lookup...
2024-09-04T09:45:03.938438963Z 13(550) DEBUG: siptrace [siptrace_hep.c:185]: trace_send_hep3_duplicate(): setting up the socket_info
2024-09-04T09:45:03.938443264Z 13(550) DEBUG: siptrace [siptrace_hep.c:200]: trace_send_hep3_duplicate(): send sock addr activated - find the sock_info
2024-09-04T09:45:03.938453167Z 13(550) DEBUG: siptrace [siptrace_hep.c:212]: trace_send_hep3_duplicate(): found send socket: [11.15.32.160] [11.15.32.160]
2024-09-04T09:45:03.938458043Z 13(550) DEBUG: tm [t_reply.c:1723]: t_retransmit_reply(): reply retransmitted. buf=0x7f158dbd39c0: SIP/2.0 5..., shmem=0x7f158e5fd6a0: SIP/2.0 5
2024-09-04T09:45:04.291254274Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:04.937365750Z 13(550) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:04.937394906Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:04.937401644Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:04.937406599Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <503>
2024-09-04T09:45:04.937411553Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Relaying over WS to next hop failed P23>
2024-09-04T09:45:04.937416800Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:04.937421254Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:04.937426381Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:04.937431290Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:04.937436762Z 13(550) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:04.937441717Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:04.937445933Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:04.937449613Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:04.937453373Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:04.937456939Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=a87f9558cf5646d575962040dd7151c2-7daca974
2024-09-04T09:45:04.937461392Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
2024-09-04T09:45:04.937465722Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [80]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:04.937471044Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:+35315220000@sip.frideo.eu>], to tag (41)[a87f9558cf5646d575962040dd7151c2-7daca974]
2024-09-04T09:45:04.937489888Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:04.937494798Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:04.937499338Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:04.937503534Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Server] type 29
2024-09-04T09:45:04.937507374Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Content-Length] type 12
2024-09-04T09:45:04.937511410Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0
2024-09-04T09:45:04.937514962Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
2024-09-04T09:45:04.937726846Z 13(550) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1
2024-09-04T09:45:04.937738932Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:731]: parse_msg(): SIP Reply  (status):
2024-09-04T09:45:04.937744501Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg():  version: <SIP/2.0>
2024-09-04T09:45:04.937748468Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg():  status:  <503>
2024-09-04T09:45:04.937753175Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg():  reason:  <Relaying over WS to next hop failed P23>
2024-09-04T09:45:04.937757760Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Via] type 1
2024-09-04T09:45:04.937762368Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
2024-09-04T09:45:04.937767759Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-d8754z-cc2c63344f5218d>; state=6
2024-09-04T09:45:04.937772776Z 13(550) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 234, <received> = <11.15.32.1>; state=16
2024-09-04T09:45:04.937785680Z 13(550) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
2024-09-04T09:45:04.937789823Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:591]: parse_headers(): Via found, flags=2
2024-09-04T09:45:04.937793616Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:593]: parse_headers(): this is the first via
2024-09-04T09:45:04.937797422Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [From] type 4
2024-09-04T09:45:04.937801693Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [To] type 3
2024-09-04T09:45:04.937815217Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=a87f9558cf5646d575962040dd7151c2-7daca974
2024-09-04T09:45:04.937820375Z 13(550) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
2024-09-04T09:45:04.937824599Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [80]; uri=[sip:+35315220000@sip.frideo.eu]
2024-09-04T09:45:04.937830096Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:+35315220000@sip.frideo.eu>], to tag (41)[a87f9558cf5646d575962040dd7151c2-7daca974]
2024-09-04T09:45:04.937834367Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [Call-ID] type 6
2024-09-04T09:45:04.937838773Z 13(550) DEBUG: <core> [core/parser/parse_hname2.c:314]: parse_sip_header_name(): parsed header name [CSeq] type 5
2024-09-04T09:45:04.937843606Z 13(550) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <1244552062> <INVITE>
2024-09-04T09:45:04.937847994Z 13(550) DEBUG: siptrace [siptrace.c:2476]: siptrace_net_data_sent(): processing message mode 1
2024-09-04T09:45:04.937851755Z 13(550) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:04.937855817Z 13(550) DEBUG: siptrace [siptrace_hep.c:523]: pipport2su(): the port string is 5060
2024-09-04T09:45:04.937860193Z 13(550) DEBUG: <core> [core/proxy.c:267]: mk_proxy(): doing DNS lookup...
2024-09-04T09:45:04.937864189Z 13(550) DEBUG: siptrace [siptrace_hep.c:185]: trace_send_hep3_duplicate(): setting up the socket_info
2024-09-04T09:45:04.937867994Z 13(550) DEBUG: siptrace [siptrace_hep.c:200]: trace_send_hep3_duplicate(): send sock addr activated - find the sock_info
2024-09-04T09:45:04.937872193Z 13(550) DEBUG: siptrace [siptrace_hep.c:212]: trace_send_hep3_duplicate(): found send socket: [11.15.32.160] [11.15.32.160]
2024-09-04T09:45:04.937876515Z 13(550) DEBUG: tm [t_reply.c:1723]: t_retransmit_reply(): reply retransmitted. buf=0x7f158dbd39c0: SIP/2.0 5..., shmem=0x7f158e5fd6a0: SIP/2.0 5
2024-09-04T09:45:05.292310677Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:06.293144650Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:06.437318386Z 12(549) DEBUG: tm [t_funcs.c:133]: put_on_wait(): put T [0x7f158e609cf0] on wait
2024-09-04T09:45:06.437365052Z 12(549) DEBUG: <core> [core/timer.c:555]: timer_add_safe(): timer_add called on an active timer 0x7f158e609da8 (0x7f158dd73e30, 0x7f158dd73e30), flags 201
2024-09-04T09:45:06.437374778Z 12(549) DEBUG: tm [t_funcs.c:156]: put_on_wait(): transaction 0x7f158e609cf0 already on wait
2024-09-04T09:45:07.293938667Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:08.295025109Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:08.437270978Z 13(550) DEBUG: tm [timer.c:642]: wait_handler(): finished transaction: 0x7f158e609cf0 (p:0x7f158dde0d80/n:0x7f158dde0d80)
2024-09-04T09:45:08.437305347Z 13(550) DEBUG: tm [h_table.c:133]: free_cell_helper(): freeing transaction 0x7f158e609cf0 from timer.c:651
2024-09-04T09:45:09.296040829Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:10.297096885Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:11.297725040Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:12.298828263Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1
2024-09-04T09:45:13.299833303Z 20(557) DEBUG: <core> [core/tcp_main.c:1726]: _tcpconn_find(): found connection by id: 1