Hi, http_reply_parse is not present in the configs. I've explicitly set it as "no" and the result is the same. If I set it as "yes", topos complains like this:
Jan 22 15:00:10 proxy1 kamailio[29316]: ERROR: topos [topos_mod.c:282]: tps_prepare_msg(): cannot parse cseq header Thank you, Nuno On Wed, Jan 22, 2020 at 2:45 PM Daniel-Constantin Mierla <[email protected]> wrote: > Hello, > > do you have http_reply_parse=yes ? > > The error is from topos catching the http reply being sent out and trying > to handle it. > > Cheers, > Daniel > On 22.01.20 12:34, Nuno Ferreira wrote: > > Hi, > > I'm using kamailio 5.2.4 (topos enabled) and HTTP 1.1 > Here's ngrep output: > #### > T 127.0.0.1:32322 -> 127.0.0.1:8000 [AP] > POST /RPC HTTP/1.1. > User-Agent: curl/7.29.0. > Host: 127.0.0.1:8000. > Accept: */*. > Content-Type: application/json. > Content-Length: 75. > . > {"id": 1, "jsonrpc": "2.0", "method": "pl.list", "params": ["pipe_INVITE"]} > ## > T 127.0.0.1:8000 -> 127.0.0.1:32322 [AP] > HTTP/1.1 400 Unknown pipe id pipe_INVITE. > Sia: SIP/2.0/TCP 127.0.0.1:32322. > Content-Type: application/json. > Server: SIP Proxy (v1.1.0-360). > Content-Length: 105. > . > { > ."jsonrpc":."2.0", > ."error":.{ > .."code":.400, > .."message":."Unknown pipe id pipe_INVITE" > .}, > ."id":.1 > } > #### > > Debug logs from kamailio: > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 127.0.0.1 > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/tcp_main.c:999]: tcpconn_new(): on port 32304, type 2 > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/tcp_main.c:1309]: tcpconn_add(): hashes: 3634:3788:434, 41 > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa85ba0, 39, 2, > 0x7f87c726b9e0), fd_no=29 > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa85ba0, 39, -1, > 0x0) fd_no=30 called > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1 > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/tcp_main.c:3878]: send2child(): selected tcp worker idx:0 proc:19 > pid:18996 for activity on [tcp:127.0.0.1:8000], 0x7f87c726b9e0 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:1759]: handle_io(): received n=8 con=0x7f87c726b9e0, fd=11 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:1560]: tcp_read_req(): content-length=75 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:612]: parse_msg(): method: <POST> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:614]: parse_msg(): uri: </RPC> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:616]: parse_msg(): version: <HTTP/1.1> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=75 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: topos [topos_mod.c:269]: > tps_prepare_msg(): non sip request message > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:612]: parse_msg(): method: <POST> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:614]: parse_msg(): uri: </RPC> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:616]: parse_msg(): version: <HTTP/1.1> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=75 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/receive.c:246]: receive_msg(): --- received sip message - request - > call-id: [] - cseq: [] > Jan 22 11:20:50 proxy1 kamailio[18996]: [328B blob data] > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:612]: parse_msg(): method: <POST> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:614]: parse_msg(): uri: </RPC> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:616]: parse_msg(): version: <HTTP/1.1> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:500]: parse_headers(): this is the first via > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=75 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header > Jan 22 11:20:50 proxy1 kamailio[18996]: ERROR: pipelimit [pl_ht.c:519]: > rpc_pl_list(): no pipe: pipe_INVITE > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: jsonrpcs > [jsonrpcs_mod.c:423]: jsonrpc_send(): sending response with body: > 0x7ffce2bc6810 - 400 Unknown pipe id pipe_INVITE > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: xhttp [xhttp_mod.c:429]: > xhttp_send_reply(): response with content-type: application/json > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: xhttp [xhttp_mod.c:439]: > xhttp_send_reply(): response with body: { > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: xhttp [xhttp_mod.c:441]: > xhttp_send_reply(): sending out response: 400 Unknown pipe id pipe_INVITE > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/msg_translator.c:162]: check_via_address(): (127.0.0.1, 127.0.0.1, 0) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: sl [sl_funcs.c:500]: > sl_run_callbacks(): execute callback for event type 1 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: siptrace [siptrace.c:1369]: > trace_sl_onreply_out(): trace off... > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/parse_fline.c:249]: parse_first_line(): parse_first_line: bad > request first line > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/parse_fline.c:251]: parse_first_line(): at line 0 char 20: > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/parse_fline.c:257]: parse_first_line(): parsed so far: > HTTP/1.1 400 Unknown > Jan 22 11:20:50 proxy1 kamailio[18996]: ERROR: <core> > [core/parser/parse_fline.c:262]: parse_first_line(): parse_first_line: bad > message (offset: 20) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/parser/msg_parser.c:606]: parse_msg(): invalid message > Jan 22 11:20:50 proxy1 kamailio[18996]: [456B blob data] > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: topos [topos_mod.c:263]: > tps_prepare_msg(): outbuf buffer parsing failed! > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_main.c:2226]: tcpconn_send_put(): send from reader (18996 (19)), > reusing fd > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_main.c:2460]: tcpconn_do_send(): sending... > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= > 0x7f87c726b9e0 n=278 fd=11 > Jan 22 11:20:50 proxy1 kamailio[18996]: [431B blob data] > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> [core/xavp.c:495]: > xavp_destroy_list(): destroying xavp list (nil) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/receive.c:458]: receive_msg(): cleaning up > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xaf1560, 11, 2, > 0x7f87c726b9e0), fd_no=1 > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:198]: tcp_emit_closed_event(): TCP closed event creation > triggered (reason: 0) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:206]: tcp_emit_closed_event(): no callback registering for > handling TCP closed event > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:318]: tcp_read_data(): EOF on 0x7f87c726b9e0, FD 11 > ([127.0.0.1]:32304 -> > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:319]: tcp_read_data(): -> [127.0.0.1]:8000) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:1527]: tcp_read_req(): EOF > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xaf1560, 11, -1, > 0x10) fd_no=2 called > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:1683]: release_tcpconn(): releasing con 0x7f87c726b9e0, > state -1, fd=11, id=4137 ([127.0.0.1]:32304 -> [127.0.0.1]:8000) > Jan 22 11:20:50 proxy1 kamailio[18996]: DEBUG: <core> > [core/tcp_read.c:1684]: release_tcpconn(): extra_data (nil) > Jan 22 11:20:50 proxy1 kamailio[19000]: DEBUG: <core> > [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7f87c726b9e0, > -1 from 0 > > Regards, > > Nuno > > On Wed, Jan 22, 2020 at 7:19 AM Daniel-Constantin Mierla < > [email protected]> wrote: > >> Hello, >> >> what version of kamailio are you using and what http version is curl >> using? Can you paste here the http request taken with ngrep from the >> network? >> >> Cheers, >> Daniel >> On 21.01.20 19:00, Nuno Ferreira wrote: >> >> Hi Daniel, >> >> There's no other traffic than the HTTP requests. >> This comment in src/core/parser/parse_fline.c 99 - 113, caugh my >> attention: >> >> } else if (http_reply_parse != 0 && >> (*tmp=='H' || *tmp=='h') && >> /* 'HTTP/1.' */ >> strncasecmp( tmp+1, HTTP_VERSION+1, HTTP_VERSION_LEN-1)==0 && >> /* [0|1] */ >> ((*(tmp+HTTP_VERSION_LEN)=='0') || (*(tmp+HTTP_VERSION_LEN)=='1')) && >> (*(tmp+HTTP_VERSION_LEN+1)==' ') ){ >> >> >> * /* ugly hack to be able to route http replies * Note: - the http reply >> must have a via * - the message is marked as SIP_REPLY (ugly)* >> */ >> fl->type=SIP_REPLY; >> fl->flags|=FLINE_FLAG_PROTO_HTTP; >> fl->u.reply.version.len=HTTP_VERSION_LEN+1 /*include last digit*/; >> tmp=buffer+HTTP_VERSION_LEN+1 /* last digit */; >> >> and later in error1: >> error1: >> fl->type=SIP_INVALID; >> LOG((core, core_cfg, corelog), "parse_first_line: bad message (offset: >> %d)\n", offset); >> /* skip line */ >> nl=eat_line(buffer,len); >> return nl; >> >> So that log line can be conditional if FLINE_FLAG_PROTO_HTTP is not part >> of fl->flags. >> I just don't know where the "[466B blob data]" is getting printed >> >> On Tue, Jan 21, 2020 at 4:30 PM Daniel-Constantin Mierla < >> [email protected]> wrote: >> >>> Hello, >>> >>> as I said, watch the traffic on port 8000 with ngrep or some other >>> network sniffer to see what data comes there. You can also start kamailio >>> with debug=3 in config, more debug logs should be printed to syslog to get >>> the context of what is processed at that time. >>> >>> Cheers, >>> Daniel >>> On 21.01.20 16:31, Nuno Ferreira wrote: >>> >>> Hi Daniel, >>> >>> Thanks for your feedback. >>> I have a dedicated listen directive for JSONRPC >>> listen = 127.0.0.1:8000 >>> >>> and then an event_route for it: >>> event_route[xhttp:request] { >>> if ($Rp != 8000) { >>> xhttp_reply("403", "Forbidden", "text/html", >>> "<html><body>Forbidden</body></html>"); >>> exit; >>> } >>> if ($hu =~ "^/RPC") { >>> jsonrpc_dispatch(); >>> } else { >>> xhttp_reply("200", "OK", "text/html", "<html><body>Wrong URL >>> $hu</body></html>"); >>> } >>> return; >>> } >>> >>> So, I'm already doing HTTP traffic only in port 8000. >>> The interesting part is that if I use kamcmd pl.list pipe_INVITE, only >>> the first log line is printed. Using curl, I see the other 2 logs all the >>> time. >>> >>> Thank you >>> >>> On Tue, Jan 21, 2020 at 2:45 PM Daniel-Constantin Mierla < >>> [email protected]> wrote: >>> >>>> Hello, >>>> >>>> can you want the traffic on port 8000 and see if there is no >>>> "unexpected" traffic there? There should be no error message for parsing >>>> the first line of an HTTP request. >>>> >>>> The error message related the missing pipe can be made debug. >>>> >>>> Cheers, >>>> Daniel >>>> On 21.01.20 15:34, Nuno Ferreira wrote: >>>> >>>> Hi all, >>>> >>>> I'm using pipelimit with the "clean_unused" option to get rid of pipes >>>> that are not used for quite some time. At the same time we are monitoring >>>> pipelimit with a jsonrpc call similar to: >>>> >>>> # curl --header 'Content-Type: application/json' --data-binary '{"id": >>>> 1, "jsonrpc": "2.0", "method": "pl.list", "params": ["pipe_INVITE"]' >>>> http://127.0.0.1:8000/RPC >>>> >>>> Reply: >>>> { >>>> "jsonrpc": "2.0", >>>> "error": { >>>> "code": 400, >>>> "message": "Unknown pipe id pipe_INVITE" >>>> }, >>>> "id": 1 >>>> } >>>> >>>> The above reply is valid because the pipe_INVITE was not loaded yet, >>>> but the request makes kamailio to log the following log messages: >>>> >>>> Jan 20 11:21:48 proxy1 kamailio[24474]: ERROR: pipelimit [pl_ht.c:519]: >>>> rpc_pl_list(): no pipe: pipe_INVITE >>>> Jan 20 11:21:48 proxy1 kamailio[24474]: ERROR: <core> >>>> [core/parser/parse_fline.c:262]: parse_first_line(): parse_first_line: bad >>>> message (offset: 20) >>>> Jan 20 11:21:48 proxy1 kamailio[24474]: [466B blob data] >>>> >>>> Since the monitoring system does periodic requests, those log lines get >>>> a bit annoying and fill the log with ERROR messages that aren't really >>>> errors. >>>> >>>> IMHO the first log line should be converted to DEBUG instead of ERROR, >>>> but I have some doubts about the one >>>> from parse_fline.c:262. parse_first_line() is used to process both SIP and >>>> HTTP. It makes sense to log ERROR if SIP but not in the case of HTTP... >>>> Regarding the "[466B blob data]" I really don't know from where it's >>>> coming from. >>>> I can submit a PR, but I would like to have first some feedback from >>>> you. >>>> >>>> Thank you, >>>> >>>> Nuno >>>> >>>> >>>> *Confidentiality Notice: The information contained in this e-mail and >>>> any >>>> attachments may be confidential. If you are not an intended recipient, >>>> you >>>> are hereby notified that any dissemination, distribution or copying of >>>> this >>>> e-mail is strictly prohibited. If you have received this e-mail in >>>> error, >>>> please notify the sender and permanently delete the e-mail and any >>>> attachments immediately. You should not retain, copy or use this e-mail >>>> or >>>> any attachment for any purpose, nor disclose all or any part of the >>>> contents to any other person. Thank you.* >>>> >>>> _______________________________________________ >>>> Kamailio (SER) - Users Mailing >>>> [email protected]https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >>>> >>>> -- >>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- >>>> www.linkedin.com/in/miconda >>>> Kamailio Advanced Training - March 9-11, 2020, Berlin - www.asipto.com >>>> Kamailio World Conference - April 27-29, 2020, in Berlin -- >>>> www.kamailioworld.com >>>> >>>> >>> >>> *Confidentiality Notice: The information contained in this e-mail and any >>> attachments may be confidential. If you are not an intended recipient, >>> you >>> are hereby notified that any dissemination, distribution or copying of >>> this >>> e-mail is strictly prohibited. If you have received this e-mail in error, >>> please notify the sender and permanently delete the e-mail and any >>> attachments immediately. You should not retain, copy or use this e-mail >>> or >>> any attachment for any purpose, nor disclose all or any part of the >>> contents to any other person. Thank you.* >>> >>> -- >>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- >>> www.linkedin.com/in/miconda >>> Kamailio Advanced Training - March 9-11, 2020, Berlin - www.asipto.com >>> Kamailio World Conference - April 27-29, 2020, in Berlin -- >>> www.kamailioworld.com >>> >>> >> >> *Confidentiality Notice: The information contained in this e-mail and any >> attachments may be confidential. If you are not an intended recipient, you >> are hereby notified that any dissemination, distribution or copying of >> this >> e-mail is strictly prohibited. If you have received this e-mail in error, >> please notify the sender and permanently delete the e-mail and any >> attachments immediately. You should not retain, copy or use this e-mail or >> any attachment for any purpose, nor disclose all or any part of the >> contents to any other person. Thank you.* >> >> -- >> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- >> www.linkedin.com/in/miconda >> Kamailio Advanced Training - March 9-11, 2020, Berlin - www.asipto.com >> Kamailio World Conference - April 27-29, 2020, in Berlin -- >> www.kamailioworld.com >> >> > > *Confidentiality Notice: The information contained in this e-mail and any > attachments may be confidential. If you are not an intended recipient, you > are hereby notified that any dissemination, distribution or copying of this > e-mail is strictly prohibited. If you have received this e-mail in error, > please notify the sender and permanently delete the e-mail and any > attachments immediately. You should not retain, copy or use this e-mail or > any attachment for any purpose, nor disclose all or any part of the > contents to any other person. Thank you.* > > -- > Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- > www.linkedin.com/in/miconda > Kamailio Advanced Training - March 9-11, 2020, Berlin - www.asipto.com > Kamailio World Conference - April 27-29, 2020, in Berlin -- > www.kamailioworld.com > > -- *Confidentiality Notice: The information contained in this e-mail and any attachments may be confidential. If you are not an intended recipient, you are hereby notified that any dissemination, distribution or copying of this e-mail is strictly prohibited. If you have received this e-mail in error, please notify the sender and permanently delete the e-mail and any attachments immediately. You should not retain, copy or use this e-mail or any attachment for any purpose, nor disclose all or any part of the contents to any other person. Thank you.*
_______________________________________________ Kamailio (SER) - Users Mailing List [email protected] https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
