davehorton / drachtio-srs-freeswitch

A simple SIPREC recording server
7 stars 0 forks source link

UncaughtException error while running app.js #1

Closed sahil-ecosmob closed 2 years ago

sahil-ecosmob commented 2 years ago

Hello. I am trying to run app.js so that it connects to FS on ESL (8021 port). facing this error:

root@sahil-HP-Laptop-15s-ey1xxx:/usr/local/src/drachtio-srs-freeswitch# node app.js error: uncaughtException: invalid message from server, did not start with length#: Content-Type: auth/request

date=Tue Aug 23 2022 13:02:52 GMT+0530 (India Standard Time), pid=47961, uid=0, gid=0, cwd=/usr/local/src/drachtio-srs-freeswitch, execPath=/usr/bin/node, version=v16.17.0, argv=[/usr/bin/node, /usr/local/src/drachtio-srs-freeswitch/app.js], rss=50581504, heapTotal=17600512, heapUsed=9028880, external=2019520, arrayBuffers=25601, loadavg=[0.64, 0.51, 0.71], uptime=4593.85, trace=[column=12, file=/usr/local/src/drachtio-srs-freeswitch/node_modules/drachtio/lib/client/agent.js, function=Socket.onData, line=328, method=onData, native=false, column=28, file=node:events, function=Socket.emit, line=513, method=emit, native=false, column=12, file=node:internal/streams/readable, function=addChunk, line=315, method=null, native=false, column=11, file=node:internal/streams/readable, function=readableAddChunk, line=285, method=null, native=false, column=10, file=node:internal/streams/readable, function=Socket.Readable.push, line=228, method=push, native=false, column=23, file=node:internal/stream_base_commons, function=TCP.onStreamRead, line=190, method=onStreamRead, native=false], stack=[Error: invalid message from server, did not start with length#: Content-Type: auth/request, , , at Socket.onData (/usr/local/src/drachtio-srs-freeswitch/node_modules/drachtio/lib/client/agent.js:328:12), at Socket.emit (node:events:513:28), at addChunk (node:internal/streams/readable:315:12), at readableAddChunk (node:internal/streams/readable:285:11), at Socket.Readable.push (node:internal/streams/readable:228:10), at TCP.onStreamRead (node:internal/stream_base_commons:190:23)]

davehorton commented 2 years ago

somehow you have configured things so your app.js is connecting to freeswitch, not drachtio server

sahil-ecosmob commented 2 years ago

I am sorry. I am new to this. I believe I also need to run a drachtio-server if i am running that script(app.js) as a client. So when I am running the server, i get this error ===

root@sahil-HP-Laptop-15s-ey1xxx:/usr/local/src/drachtio-server# drachtio -f drachtio.conf.xml checking for blacklist in config did not find blacklist at all

Can you refer me to any script or configuration where i need to declare the blacklist ??

davehorton commented 2 years ago

Those log messages

checking for blacklist in config
did not find blacklist at all

are normal and not concerning.

sahil-ecosmob commented 2 years ago

okay. Thank you. Is there any way to verify if the server is running? I tried grepping the port 9022, but no result there. When I run app.js , the connection is failed. This is the fail message.

root@sahil-HP-Laptop-15s-ey1xxx:/usr/local/src/drachtio-srs-freeswitch# node app.js error: uncaughtException: drachtio-client connection to 127.0.0.1:9022 failed - Error: connect ECONNREFUSED 127.0.0.1:9022 date=Tue Aug 23 2022 16:02:38 GMT+0530 (India Standard Time), pid=56649, uid=0, gid=0, cwd=/usr/local/src/drachtio-srs-freeswitch, execPath=/usr/bin/node, version=v16.17.0, argv=[/usr/bin/node, /usr/local/src/drachtio-srs-freeswitch/app.js], rss=49655808, heapTotal=17600512, heapUsed=9005640, external=2019469, arrayBuffers=25550, loadavg=[0.56, 0.7, 0.84], uptime=15379.42, trace=[column=25, file=/usr/local/src/drachtio-srs-freeswitch/node_modules/drachtio/lib/client/agent.js, function=Socket.onError, line=305, method=onError, native=false, column=28, file=node:events, function=Socket.emit, line=513, method=emit, native=false, column=8, file=node:internal/streams/destroy, function=emitErrorNT, line=157, method=null, native=false, column=3, file=node:internal/streams/destroy, function=emitErrorCloseNT, line=122, method=null, native=false, column=21, file=node:internal/process/task_queues, function=processTicksAndRejections, line=83, method=null, native=false], stack=[Error: drachtio-client connection to 127.0.0.1:9022 failed - Error: connect ECONNREFUSED 127.0.0.1:9022, at Socket.onError (/usr/local/src/drachtio-srs-freeswitch/node_modules/drachtio/lib/client/agent.js:305:25), at Socket.emit (node:events:513:28), at emitErrorNT (node:internal/streams/destroy:157:8), at emitErrorCloseNT (node:internal/streams/destroy:122:3), at processTicksAndRejections (node:internal/process/task_queues:83:21)]

This is the grep output : root@sahil-HP-Laptop-15s-ey1xxx:/usr/local/src/drachtio-server# netstat -anlp | grep 9022 unix 3 [ ] STREAM CONNECTED 90222 6913/chrome --type=
unix 3 [ ] STREAM CONNECTED 90226 7656/chrome --type=
unix 3 [ ] STREAM CONNECTED 90225 9523/chrome --type=
unix 3 [ ] STREAM CONNECTED 90221 9523/chrome --type=

davehorton commented 2 years ago

usually you dont start the drachtio server from the command line, but since you appear to be doing that, add this parameter

drachtio -f /etc/drachtio.conf.xml --stdout

to get the logging sent to stdout

sahil-ecosmob commented 2 years ago

ok ok. I tried it...it's showing this error. root@sahil-HP-Laptop-15s-ey1xxx:/usr/local/src/drachtio-server# drachtio -f drachtio.conf.xml --stdout checking for blacklist in config did not find blacklist at all 2022-08-23 16:23:25.343505 Starting drachtio version v0.8.18-rc5 2022-08-23 16:23:25.343555 Logging threshold: 4 2022-08-23 16:23:25.343570 DrachtioController::run listening for applications on tcp port 9022 and tls port 0 2022-08-23 16:23:25.344420 DrachtioController::run - blacklist checking config 2022-08-23 16:23:25.344443 responding to Prometheus on 127.0.0.1:8088 2022-08-23 16:23:25.344505 ClientController::threadFunc - ClientController: io_context run loop started (or restarted) 2022-08-23 16:23:25.344817 tcp keep alives will be sent to clients every 45 seconds 2022-08-23 16:23:25.344879 DrachtioController::run: starting sip stack on sip:172.20.10.3:5080;transport=udp,tcp 2022-08-23 16:23:25.344968 nta.c:2336 nta_agent_add_tport() nta: bind(172.20.10.3:5080;transport=*): Address already in use 2022-08-23 16:23:25.344986 DrachtioController::run: Error calling nta_agent_create

---- probably related to FS only.

davehorton commented 2 years ago

172.20.10.3:5080;transport=*): Address already in use

Freeswitch is listening on port 5080 (as it should) but now you tried to have drachtio server listen on the same port. drachtio server should be configured to listen on port 5060

sahil-ecosmob commented 2 years ago

5060 also shows the same error. Freeswitch is running internal profile on 5060. I tried with 5061. It worked.

root@sahil-HP-Laptop-15s-ey1xxx:/usr/local/src/drachtio-server# drachtio -f drachtio.conf.xml --stdout checking for blacklist in config did not find blacklist at all 2022-08-23 17:29:44.980140 Starting drachtio version v0.8.18-rc5 2022-08-23 17:29:44.980217 Logging threshold: 4 2022-08-23 17:29:44.980247 DrachtioController::run listening for applications on tcp port 9022 and tls port 0 2022-08-23 17:29:44.982072 DrachtioController::run - blacklist checking config 2022-08-23 17:29:44.982123 responding to Prometheus on 127.0.0.1:8088 2022-08-23 17:29:44.982159 ClientController::threadFunc - ClientController: io_context run loop started (or restarted) 2022-08-23 17:29:44.982507 tcp keep alives will be sent to clients every 45 seconds 2022-08-23 17:29:44.982570 DrachtioController::run: starting sip stack on sip::5061;transport=udp,tcp 2022-08-23 17:29:44.983073 sres.c:2463 sres_parse_options() sres: /etc/resolv.conf: unknown option
2022-08-23 17:29:44.983418 SipTransport::addTransports - creating transport: 0x559c73cc2f10: udp/[2405:204:30ae:f92e:fff7:e715:bf19:cce7]:5061 2022-08-23 17:29:44.983715 SipTransport::addTransports - creating transport: 0x559c73cc33c0: tcp/[2405:204:30ae:f92e:fff7:e715:bf19:cce7]:5061 2022-08-23 17:29:44.984010 SipTransport::addTransports - creating transport: 0x559c73cc3870: udp/[2405:204:30ae:f92e:b98e:bbd7:98e2:bf20]:5061 2022-08-23 17:29:44.984301 SipTransport::addTransports - creating transport: 0x559c73cc3fb0: tcp/[2405:204:30ae:f92e:b98e:bbd7:98e2:bf20]:5061 2022-08-23 17:29:44.984592 SipTransport::addTransports - creating transport: 0x559c73cc4460: udp/172.20.10.3:5061 2022-08-23 17:29:44.984886 SipTransport::addTransports - creating transport: 0x559c73cc4910: tcp/172.20.10.3:5061 2022-08-23 17:29:44.985203 SipTransport::addTransports - creating transport: 0x559c73cc4dc0: udp/172.17.0.1:5061 2022-08-23 17:29:44.985497 SipTransport::addTransports - creating transport: 0x559c73cc5270: tcp/172.17.0.1:5061 2022-08-23 17:29:44.985790 SipTransport::addTransports - creating transport: 0x559c73cc5720: udp/127.0.0.1:5061 2022-08-23 17:29:44.986090 SipTransport::addTransports - creating transport: 0x559c73cc5bd0: tcp/127.0.0.1:5061 2022-08-23 17:29:44.986396 SipTransport::addTransports - creating transport: 0x559c73cc6080: udp/[::1]:5061 2022-08-23 17:29:44.986691 SipTransport::addTransports - creating transport: 0x559c73cc6530: tcp/[::1]:5061 2022-08-23 17:29:44.986988 SipTransport::logTransports - there are : 12 transports 2022-08-23 17:29:44.986999 SipTransport::logTransports - tcp/[::1]:5061 (sip:
:5061;transport=udp,tcp, external-ip: , local-net: ) 2022-08-23 17:29:44.987011 SipTransport::logTransports - udp/[::1]:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ), mtu size: 1300 2022-08-23 17:29:44.987022 SipTransport::logTransports - tcp/127.0.0.1:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: 127.0.0.1/32) 2022-08-23 17:29:44.987032 SipTransport::logTransports - udp/127.0.0.1:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: 127.0.0.1/32), mtu size: 1300 2022-08-23 17:29:44.987041 SipTransport::logTransports - udp/172.20.10.3:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ), mtu size: 1300 2022-08-23 17:29:44.987051 SipTransport::logTransports - tcp/[2405:204:30ae:f92e:b98e:bbd7:98e2:bf20]:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ) 2022-08-23 17:29:44.987060 SipTransport::logTransports - tcp/172.17.0.1:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ) 2022-08-23 17:29:44.987071 SipTransport::logTransports - udp/[2405:204:30ae:f92e:b98e:bbd7:98e2:bf20]:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ), mtu size: 1300 2022-08-23 17:29:44.987089 SipTransport::logTransports - udp/172.17.0.1:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ), mtu size: 1300 2022-08-23 17:29:44.987099 SipTransport::logTransports - tcp/[2405:204:30ae:f92e:fff7:e715:bf19:cce7]:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ) 2022-08-23 17:29:44.987107 SipTransport::logTransports - tcp/172.20.10.3:5061 (sip::5061;transport=udp,tcp, external-ip: , local-net: ) 2022-08-23 17:29:44.987117 SipTransport::logTransports - udp/[2405:204:30ae:f92e:fff7:e715:bf19:cce7]:5061 (sip:*:5061;transport=udp,tcp, external-ip: , local-net: ), mtu size: 1300 2022-08-23 17:29:44.987155 Starting sofia event loop in main thread: 139751465150848 2022-08-23 17:29:48.038637 ClientController::join - Added client, count of connected clients is now: 1

davehorton commented 2 years ago

ok if freeswitch is listening on port 5060 then I guess you have not set it up the way I normally do. I do a specific configuration of freeswitch where freeswitch listens only on 5080.

sahil-ecosmob commented 2 years ago

Thank you for helping me out. I need one suggestion from you. I have FS running which is integrated with OPENSIPS. Any call that comes to FS goes through the proxy server i.e opensips. At the same time I am firing SIPREC (from OPENSIPS cfg file). So OPENSIPS act as a SRC and FS as SRS. but when OPENSIPS sends the call to freeSWITCH, it gets the response 420 (Bad Extension). This is most probably because of the 'siprec' in Require header that FS is rejecting the INVITE packet. Do you have any idea how we can disable this functionality on FREESWITCH end or anything else that we might be missing ?? I am attaching the INVITE packet from OPENSIPS -> FS.

2022/08/16 15:33:06.003852 127.0.0.1:5070 -> 192.168.1.10:5080 INVITE sip:8700225@192.168.1.10:5080 SIP/2.0 Via: SIP/2.0/UDP 127.0.0.1:5070;branch=z9hG4bK091.e15ee874.0 To: sip:8700225@192.168.1.10:5080 From: sip:8700225@192.168.1.10:5080;tag=1d7f30bc25db1f77ac988809eee16ad4-ce21 CSeq: 2 INVITE Call-ID: B2B.43.2356878.1660644185 Max-Forwards: 70 Content-Length: 2276 User-Agent: OpenSIPS (3.2.2 (x86_64/linux)) Require: siprec Content-Type: multipart/mixed;boundary=OSS-unique-boundary-42 Contact: ;+sip.src

P.S : 8700225 is the extension in public.xml where we had written youor script. SIPREC in opensips.cfg is pointing towards this extension.