31 Jul
2022
31 Jul
'22
11:15 p.m.
<!--
Kamailio Project uses GitHub Issues only for bugs in the code or feature requests. Please
use this template only for bug reports.
If you have questions about using Kamailio or related to its configuration file, ask on
sr-users mailing list:
* http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
If you have questions about developing extensions to Kamailio or its existing C code, ask
on sr-dev mailing list:
* http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-dev
Please try to fill this template as much as possible for any issue. It helps the
developers to troubleshoot the issue.
If there is no content to be filled in a section, the entire section can be removed.
You can delete the comments from the template sections when filling.
You can delete next line and everything above before submitting (it is a comment).
--
### Description
<!--
Explain what you did, what you expected to happen, and what actually happened.
--
some unexpected error in kamailio.log when KSR.xhttp.xhttp_reply(404...)
### Troubleshooting
#### Reproduction
cat /etc/kamailio/kamailio.cfg
```
listen=tcp:127.0.0.1:5060
tcp_accept_no_cl=yes
debug=3
log_stderror=yes
loadmodule "jsonrpcs.so"
loadmodule "tm.so"
loadmodule "sl.so"
loadmodule "pv.so"
loadmodule "xlog.so"
loadmodule "ctl.so"
loadmodule "cfg_rpc.so"
loadmodule "xhttp.so"
loadmodule "app_lua.so"
modparam("xhttp", "event_callback", "ksr_xhttp_event")
modparam("app_lua", "load", "/etc/kamailio/kamailio.lua")
cfgengine "lua"
```
cat /etc/kamailio/kamailio.lua
```
function ksr_request_route()
KSR.sl.send_reply(200, "OK")
KSR.x.exit()
end
function ksr_xhttp_event()
KSR.set_reply_no_connect()
KSR.set_reply_close()
KSR.xhttp.xhttp_reply(404, "Not Found", "", "")
KSR.x.exit()
end
```
curl http://127.0.0.1:5060 -v
<!--
If the issue can be reproduced, describe how it can be done.
--
#### Debugging Data
<!--
If you got a core dump, use gdb to extract troubleshooting data - full backtrace,
local variables and the list of the code at the issue location.
gdb /path/to/kamailio /path/to/corefile
bt full
info locals
list
If you are familiar with gdb, feel free to attach more of what you consider to
be relevant.
--
```
(paste your debugging data here)
```
#### Log Messages
<!--
Check the syslog file and if there are relevant log messages printed by Kamailio, add them
next, or attach to issue, or provide a link to download them (e.g., to a pastebin site).
--
```
15(5845) DEBUG: <core> [core/ip_addr.c:571]: print_ip(): tcpconn_new: new tcp
connection: 127.0.0.1
15(5845) DEBUG: <core> [core/tcp_main.c:1216]: tcpconn_new(): on port 54884, type 2,
socket 29
15(5845) DEBUG: <core> [core/tcp_main.c:1548]: tcpconn_add(): hashes:
1846:1992:1067, 1
15(5845) DEBUG: <core> [core/io_wait.h:374]: io_watch_add(): processing
io_watch_add(0x563c94544c20, 29, 2, 0x7fb2e4691088) - fd_no=23
15(5845) DEBUG: <core> [core/io_wait.h:599]: io_watch_del(): DBG: io_watch_del
(0x563c94544c20, 29, -1, 0x0) fd_no=24 called
15(5845) DEBUG: <core> [core/tcp_main.c:4545]: handle_tcpconn_ev(): sending to
child, events 1
15(5845) DEBUG: <core> [core/tcp_main.c:4215]: send2child(): selected tcp worker
idx:0 proc:7 pid:5837 for activity on [tcp:127.0.0.1:5060], 0x7fb2e4691088
7(5837) DEBUG: <core> [core/tcp_read.c:1735]: handle_io(): received n=8
con=0x7fb2e4691088, fd=6
7(5837) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first
line type 1 (request) flags 2
7(5837) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first
line type 1 (request) flags 2
7(5837) DEBUG: <core> [core/parser/msg_parser.c:677]: parse_msg(): SIP Request:
7(5837) DEBUG: <core> [core/parser/msg_parser.c:678]: parse_msg(): method:
<GET 7(5837) DEBUG: <core>
[core/parser/msg_parser.c:680]: parse_msg(): uri: </
7(5837) DEBUG: <core> [core/parser/msg_parser.c:682]: parse_msg(): version:
<HTTP/1.1 7(5837) DEBUG:
<core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name
[Host] type 0
7(5837) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [User-Agent] type 28
7(5837) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Accept] type 23
7(5837) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of
header
7(5837) DEBUG: <core> [core/receive.c:389]: receive_msg(): --- received sip message
- request - call-id: [] - cseq: []
7(5837) DEBUG: <core> [core/receive.c:261]: ksr_evrt_pre_routing(): event route
core:pre-routing not defined
7(5837) DEBUG: <core> [core/receive.c:426]: receive_msg(): handling non-sip request
message
7(5837) DEBUG: xhttp [xhttp_mod.c:371]: xhttp_handler(): new fake msg created (112
bytes):
<GET / HTTP/1.1
Via: SIP/2.0/TCP 127.0.0.1:54884
Host: 127.0.0.1:5060
User-Agent: curl/7.74.0
Accept: */*
7(5837) DEBUG: <core>
[core/parser/parse_fline.c:249]: parse_first_line(): first line type 1 (request) flags 2
7(5837) DEBUG: <core> [core/parser/msg_parser.c:677]: parse_msg(): SIP Request:
7(5837) DEBUG: <core> [core/parser/msg_parser.c:678]: parse_msg(): method:
<GET 7(5837) DEBUG: <core>
[core/parser/msg_parser.c:680]: parse_msg(): uri: </
7(5837) DEBUG: <core> [core/parser/msg_parser.c:682]: parse_msg(): version:
<HTTP/1.1 7(5837) DEBUG:
<core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name
[Via] type 1
7(5837) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header
reached, state=5
7(5837) DEBUG: <core> [core/parser/msg_parser.c:555]: parse_headers(): Via found,
flags=2
7(5837) DEBUG: <core> [core/parser/msg_parser.c:557]: parse_headers(): this is the
first via
7(5837) DEBUG: app_lua [app_lua_api.c:549]: sr_lua_reload_script(): No need to reload
[/etc/kamailio/kamailio.lua] is version 0
7(5837) DEBUG: app_lua [app_lua_api.c:733]: app_lua_run_ex(): executing Lua function:
[[ksr_xhttp_event]]
7(5837) DEBUG: app_lua [app_lua_api.c:735]: app_lua_run_ex(): lua top index is: 11
7(5837) DEBUG: app_lua [app_lua_api.c:1067]: sr_kemi_lua_exec_func_ex(): param[0] for:
xhttp_reply is int: 404
7(5837) DEBUG: app_lua [app_lua_api.c:1063]: sr_kemi_lua_exec_func_ex(): param[1] for:
xhttp_reply is str: Not Found
7(5837) DEBUG: app_lua [app_lua_api.c:1063]: sr_kemi_lua_exec_func_ex(): param[2] for:
xhttp_reply is str:
7(5837) DEBUG: app_lua [app_lua_api.c:1063]: sr_kemi_lua_exec_func_ex(): param[3] for:
xhttp_reply is str:
7(5837) DEBUG: xhttp [xhttp_mod.c:426]: xhttp_send_reply(): sending out response: 404 Not
Found
7(5837) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Host] type 0
7(5837) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [User-Agent] type 28
7(5837) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Accept] type 23
7(5837) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of
header
7(5837) DEBUG: <core> [core/msg_translator.c:162]: check_via_address(): (127.0.0.1,
127.0.0.1, 0)
7(5837) DEBUG: <core> [core/tcp_main.c:1644]: _tcpconn_find(): found connection by
id: 1
7(5837) DEBUG: <core> [core/tcp_main.c:2526]: tcpconn_send_put(): send from reader
(5837 (7)), reusing fd
7(5837) DEBUG: <core> [core/tcp_main.c:2761]: tcpconn_do_send(): sending...
7(5837) DEBUG: <core> [core/tcp_main.c:2794]: tcpconn_do_send(): after real write:
c= 0x7fb2e4691088 n=120 fd=6
7(5837) DEBUG: <core> [core/tcp_main.c:2795]: tcpconn_do_send(): buf=
HTTP/1.1 404 Not Found
Sia: SIP/2.0/TCP 127.0.0.1:54884
Server: kamailio (5.6.1 (x86_64/linux))
Content-Length: 0
15(5845) DEBUG: <core> [core/tcp_main.c:3880]: handle_ser_child(): read response=
7fb2e4691088, -1, fd -1 from 7 (5837)
7(5837) DEBUG: <core> [core/parser/parse_fline.c:255]: parse_first_line(): bad
request first line
7(5837) DEBUG: <core> [core/parser/parse_fline.c:258]: parse_first_line(): at line
0 char 16:
7(5837) DEBUG: <core> [core/parser/parse_fline.c:264]: parse_first_line(): parsed
so far: HTTP/1.1 404 Not
7(5837) ERROR: <core> [core/parser/parse_fline.c:271]: parse_first_line():
parse_first_line: bad message (offset: 16)
7(5837) DEBUG: <core> [core/parser/msg_parser.c:673]: parse_msg(): invalid message
7(5837) ERROR: <core> [core/parser/msg_parser.c:747]: parse_msg(): ERROR:
parse_msg: message=<HTTP/1.1 404 Not Found
Sia: SIP/2.0/TCP 127.0.0.1:54884
Server: kamailio (5.6.1 (x86_64/linux))
Content-Length: 0
7(5837) ERROR: <core>
[core/msg_translator.c:3256]: build_sip_msg_from_buf(): parsing failed 7(5837) DEBUG:
app_lua [app_lua_mod.c:164]: sr_kemi_config_engine_lua(): execution of route type 513 with
name [ksr_xhttp_event] returned 1
7(5837) DEBUG: <core> [core/receive.c:432]: receive_msg(): finished handling
non-sip request message
7(5837) DEBUG: <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list
(nil)
7(5837) DEBUG: <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list
(nil)
7(5837) DEBUG: <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list
(nil)
7(5837) DEBUG: <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list
(nil)
7(5837) DEBUG: <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list
(nil)
7(5837) DEBUG: <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list
(nil)
7(5837) DEBUG: <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list
(nil)
7(5837) DEBUG: <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list
(nil)
7(5837) DEBUG: <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list
(nil)
7(5837) DEBUG: <core> [core/receive.c:628]: receive_msg(): cleaning up
7(5837) DEBUG: <core> [core/io_wait.h:374]: io_watch_add(): processing
io_watch_add(0x563c94588ec0, 6, 2, 0x7fb2e4691088) - fd_no=1
7(5837) DEBUG: <core> [core/io_wait.h:599]: io_watch_del(): DBG: io_watch_del
(0x563c94588ec0, 6, -1, 0x10) fd_no=2 called
7(5837) DEBUG: <core> [core/tcp_read.c:1870]: handle_io(): removing from list
0x7fb2e4691088 id 1 fd 6, state -1, flags 4028, main fd -1, refcnt 1 ([127.0.0.1]:54884
-> [127.0.0.1]:5060)
7(5837) DEBUG: <core> [core/tcp_read.c:1653]: release_tcpconn(): releasing con
0x7fb2e4691088, state -2, fd=6, id=1 ([127.0.0.1]:54884 -> [127.0.0.1]:5060)
7(5837) DEBUG: <core> [core/tcp_read.c:1657]: release_tcpconn(): extra_data (nil)
15(5845) DEBUG: <core> [core/tcp_main.c:3641]: handle_tcp_child(): reader response=
7fb2e4691088, -2 from 0
15(5845) DEBUG: <core> [core/tcp_main.c:3566]: tcp_emit_closed_event(): TCP closed
event creation triggered (reason: 0)
15(5845) DEBUG: <core> [core/tcp_main.c:3574]: tcp_emit_closed_event(): no callback
registering for handling TCP closed event
2(5832) DEBUG: <core> [core/timer.c:422]: adjust_ticks(): adjusting timer ticks
(677813966) with 312 ms (5 ticks)
2(5832) DEBUG: <core> [core/timer.c:422]: adjust_ticks(): adjusting timer ticks
(677815246) with 250 ms (4 ticks)
2(5832) DEBUG: <core> [core/timer.c:422]: adjust_ticks(): adjusting timer ticks
(677816206) with 250 ms (4 ticks)
2(5832) DEBUG: <core> [core/timer.c:422]: adjust_ticks(): adjusting timer ticks
(677817406) with 312 ms (5 ticks)
```
#### SIP Traffic
<!--
If the issue is exposed by processing specific SIP messages, grab them with ngrep or save
in a pcap file, then add them next, or attach to issue, or provide a link to download them
(e.g., to a pastebin site).
--
```
(paste your sip traffic here)
```
### Possible Solutions
<!--
If you found a solution or workaround for the issue, describe it. Ideally, provide a pull
request with a fix.
--
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
```
Kamailio5.6.1
```
* **Operating System**:
<!--
Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04,
CentOS 7.1, ...), MacOS, xBSD, Solaris, ...;
Kernel details (output of `lsb_release -a` and `uname -a`)
--
```
Debian11
```
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3204
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3204(a)github.com