drachtio / drachtio-siprec-recording-server

SIPREC recording server based on drachtio and rtpengine
MIT License
81 stars 32 forks source link

not able to up recorder #7

Closed richnayay closed 5 years ago

richnayay commented 5 years ago

while executing node app facing following error

/root/shah/siprec/drachtio-siprec-recording-server/app.js:7 let callHandler; ^^^

SyntaxError: Block-scoped declarations (let, const, function, class) not yet supported outside strict mode at exports.runInThisContext (vm.js:53:16) at Module._compile (module.js:374:25) at Object.Module._extensions..js (module.js:417:10) at Module.load (module.js:344:32) at Function.Module._load (module.js:301:12) at Function.Module.runMain (module.js:442:10) at startup (node.js:136:18) at node.js:966:3

davehorton commented 5 years ago

I think you need to run a more updated version of node.js. What version are you currently running?

richnayay commented 5 years ago

v4.2.6

davehorton commented 5 years ago

yeah, that's way old. Can you install the latest LTS version (currently 10.15.0)?

richnayay commented 5 years ago

running after upgrade. but facing issue while call. I am using opensips siprec client and error is

{"level":50,"time":1548422009998,"msg":"Error connecting call: TypeError: Cannot read property '1' of null","pid":3657,"hostname":"ubuntu-sasmita08Feb17","callid":"B2B.457.5681350.1548422006","v":1}

davehorton commented 5 years ago

can you post a gist with the entire drachtio log file, showing the incoming INVITE from opensips

richnayay commented 5 years ago

{"level":30,"time":1548419354366,"msg":"attempting inbound connection","pid":3657,"hostname":"ubuntu-sasmita08Feb17","host":"127.0.0.1","port":9022,"secret":"cymru","v":1} {"level":30,"time":1548419354371,"msg":"using rtpengine as the recorder","pid":3657,"hostname":"ubuntu-sasmita08Feb17","remote":{"host":"167.99.54.110","port":22000},"localPort":22223,"v":1} {"level":30,"time":1548419354443,"msg":"inbound connection to drachtio listening on tcp/[::1]:5060,tcp/172.17.0.1:5060,udp/[::1]:5060,udp/172.17.0.1:5060,udp/138.197.47.209:5060,tcp/138.197.47.209:5060,udp/127.0.0.1:5060,udp/10.17.0.9:5060,tcp/127.0.0.1:5060,tcp/10.17.0.9:5060","pid":3657,"hostname":"ubuntu-sasmita08Feb17","v":1} {"level":30,"time":1548422009974,"msg":"received SIPREC invite: sip:138.197.47.209:5060","pid":3657,"hostname":"ubuntu-sasmita08Feb17","callid":"B2B.457.5681350.1548422006","v":1} {"level":50,"time":1548422009998,"msg":"Error connecting call: TypeError: Cannot read property '1' of null","pid":3657,"hostname":"ubuntu-sasmita08Feb17","callid":"B2B.457.5681350.1548422006","v":1}

davehorton commented 5 years ago

Sorry, no I mean the drachtio server log file. It would be in /var/log/drachtio/drachtio.log if you built from source

richnayay commented 5 years ago

drachtio.log

davehorton commented 5 years ago

can you run with debug enabled as below and show me that output?

DEBUG=drachtio:siprec-recording-server node app.js

Also, you running with rtpengine or freeswitch for the media processing?

davehorton commented 5 years ago

I just pushed a small change to the master branch to give some more debugging. Can you pull the latest and run the above command and then test again?

richnayay commented 5 years ago

recorder_screen.txt I am running with rtpengine. logs are after latest changes

davehorton commented 5 years ago

thanks that last trace was helpful. It appears that there is a problem created by opensips putting the "t=" line in an unexpected place in the SDP -- before the connection line rather than after. Let me work on a fix for this...

davehorton commented 5 years ago

Specifically, here we see the time descriptor appearing before the connection information:

v=0
o=- 1548422731 0 IN IP4 0.0.0.0
s=-
t=0 0
c=IN IP4 127.0.0.1

This appears to violate the RFC as described here

richnayay commented 5 years ago

thanks for your help Dave. I'll check at OpenSips part

richnayay commented 5 years ago

Hi Dave,

SDP contains connection at two different places one for session and other for media as per RFC. Session description v= (protocol version) o= (originator and session identifier) s= (session name) i= (session information) u= (URI of description) e= (email address) p= (phone number)

c=* (connection information -- not required if included in all media)

     b=* (zero or more bandwidth information lines)
     One or more time descriptions ("t=" and "r=" lines; see below)
     z=* (time zone adjustments)
     k=* (encryption key)
     a=* (zero or more session attribute lines)
     Zero or more media descriptions

  Time description
     t=  (time the session is active)
     r=* (zero or more repeat times)

  Media description, if present
     m=  (media name and transport address)
     i=* (media title)
   ```

c=* (connection information -- optional if included at session level)


         b=* (zero or more bandwidth information lines)
         k=* (encryption key)
         a=* (zero or more media attribute lines)

So I think OpenSips is sending the INVITE as per the RFC. Can you Please go through the Issue again .
davehorton commented 5 years ago

will do. should have something later today on this.

davehorton commented 5 years ago

I checked in a fix on the master branch (I meant to check it in on a different branch, but oh well).

can you try it out?

richnayay commented 5 years ago

Hi Dave,

I think Drachtio recorder is working fine after the changes. Thanks for your help. But I am stuck with some other issue. RtpEngine is creating the empty recording files. Please let me know if you face similar issue and have any resolution.

richnayay commented 5 years ago

rtpEngine Version: git-master-3102357 command to execute: rtpengine --interface=A.B.C.D --listen-ng=A.B.C.D:22000 -m 25000 -M 35000 --log-facility=local5 --recording-dir=/var/spool/rtpengine/

drachtio recording server : config/local.json { "drachtio": { "host": "127.0.0.1", "port": 9022, "secret": "cymru" }, "rtpengine" : { "remote": { "host": "A.B.C.D", "port": 22000 }, "localPort": 22223 } }

davehorton commented 5 years ago

I'm not sure, but I assume it would be because the packets are not reaching rtpengine. I would suggest taking a tcpdump on the rtpengine server while you make a test call so you can see if packets are reaching the box. Is the rtpengine server running at a public IP address that is reachable from the opensips box?

richnayay commented 5 years ago

I can see the packets in tcpdump on the rtpengine. rtpengine is also reachable from opensips box. I am also able to create recording from rtpengine by sending command directly from opensips.

richnayay commented 5 years ago

Can you also please share me some details about what more drachtio siprec recording server provide over default rtpengine recording.

davehorton commented 5 years ago

hmm, could you possibly share the tcpdump file, along with the rtpengine log file (it logs to /var/log/syslog or /var/log/daemon I think)?

richnayay commented 5 years ago

rtpengine.log

rtpengine.zip

davehorton commented 5 years ago

would you happen to have the drachtio log file for that call as well?

davehorton commented 5 years ago

That rtpengine log shows two 'offer' commands for the incoming call. I am assuming this is because you are both recording from opensips and enabling siprec ? Both offer commands are coming from 54.160.157.91 -- what is running on this IP? drachtio and also opensips? Or is opensips runnign somewhere else.

I think perhaps we should first try to figure out why rtpengine is being asked to record the call twice, and eliminate one set of requests to make it easier to debug.

davehorton commented 5 years ago

Actually, there are 3 requests to turn on recording in that rtpengine log. The 3 different callids are 804036e787334c84a10a3187db3137d1 B2B.457.5522053.1548854058 B2B.457.7576095.1548854059 I suppose the latter two are recording the two legs direct from opensips.

If we look at the packet stats at the end, we can see that no packets were received for two of the streams (the latter two above) while packets were received for the first.

Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: Final packet stats:
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: --- Tag '1e4fb5cccfb3e75e573fc5734e091781-ce21', created 0:44 ago for branch '', in dialogue with '9a5098af-2bb1-4ced-b89c-7678e6e68884'
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: ------ Media #1 (audio over RTP/AVP) using unknown codec
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: --------- Port   167.99.54.110:25850 <>       127.0.0.1:35003, SSRC 0, 0 p, 0 b, 0 e, 44 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: --------- Port   167.99.54.110:25851 <>    192.168.1.43:64786 (RTCP), SSRC 0, 0 p, 0 b, 0 e, 44 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: --- Tag '9a5098af-2bb1-4ced-b89c-7678e6e68884', created 0:44 ago for branch '', in dialogue with '1e4fb5cccfb3e75e573fc5734e091781-ce21'
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: ------ Media #1 (audio over RTP/AVP) using unknown codec
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: --------- Port   167.99.54.110:25836 <>       127.0.0.1:35004, SSRC 0, 0 p, 0 b, 0 e, 44 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: --------- Port   167.99.54.110:25837 <>       127.0.0.1:35005 (RTCP), SSRC 0, 0 p, 0 b, 0 e, 44 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.7576095.1548854059]: Moved metadata file "/var/spool/rtpengine/tmp/rtpengine-meta-B2B.457.7576095.1548854059-0af191b2f8869c80.tmp" to "/var/spool/rtpengine/metadata"
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: Final packet stats:
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: --- Tag '22cf7b616c9040de9faf4d1a1bb1a245', created 0:47 ago for branch '', in dialogue with 'e702db0a'
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: ------ Media #1 (audio over RTP/AVP) using PCMA/8000
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: --------- Port   167.99.54.110:25782 <>   219.65.44.210:64784, SSRC 4e5563f5, 736 p, 126592 b, 0 e, 29 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: --------- Port   167.99.54.110:25783 <>   219.65.44.210:64786 (RTCP), SSRC 4e5563f5, 7 p, 544 b, 0 e, 29 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: --- Tag 'e702db0a', created 0:47 ago for branch '', in dialogue with '22cf7b616c9040de9faf4d1a1bb1a245'
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: ------ Media #1 (audio over RTP/AVP) using PCMA/8000
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: --------- Port   167.99.54.110:25766 <>   219.65.44.210:40006, SSRC 3d6c, 709 p, 121948 b, 0 e, 30 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [804036e787334c84a10a3187db3137d1]: --------- Port   167.99.54.110:25767 <>   219.65.44.210:40007 (RTCP), SSRC 0, 0 p, 0 b, 0 e, 47 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: Final packet stats:
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: --- Tag '1e4fb5cccfb3e75e573fc5734e091781-ce21', created 0:44 ago for branch '', in dialogue with '33626ac4-b89b-4e44-8ce7-217d22db74ae'
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: ------ Media #1 (audio over RTP/AVP) using unknown codec
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: --------- Port   167.99.54.110:25816 <>       127.0.0.1:35001, SSRC 0, 0 p, 0 b, 0 e, 44 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: --------- Port   167.99.54.110:25817 <>    192.168.1.43:64786 (RTCP), SSRC 0, 0 p, 0 b, 0 e, 44 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: --- Tag '33626ac4-b89b-4e44-8ce7-217d22db74ae', created 0:44 ago for branch '', in dialogue with '1e4fb5cccfb3e75e573fc5734e091781-ce21'
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: ------ Media #1 (audio over RTP/AVP) using unknown codec
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: --------- Port   167.99.54.110:25802 <>       127.0.0.1:35002, SSRC 0, 0 p, 0 b, 0 e, 44 ts
Jan 30 13:15:03 skhan-recording-poic rtpengine[10479]: INFO: [B2B.457.5522053.1548854058]: --------- Port   167.99.54.110:25803 <>       127.0.0.1:35003 (RTCP), SSRC 0, 0 p, 0 b, 0 e, 44 ts

In other words, only the recording with call-id 804036e787334c84a10a3187db3137d1 got packets.

Note also that rtpengine is configured to wait 30 secs after call end to generate the pcap file Scheduling deletion of call branch 'e702db0a' (via-branch '') in 30 seconds You can change this in the rtpengine systemd service file to eliminate this pause if you want.

Anyways, it seems to me that only the siprec recording got packets, but that is the opposite of what you are reporting...

davehorton commented 5 years ago

As to your question about recording directly from opensips vs using siprec.

There are some differences to consider:

Direct from opensips (1) I believe this does not use siprec, per se, but uses rtpengine as a media proxy (and can therefore record as a side affect). If you need a media proxy due to your network configuration, this may be suitable; but introducing a media proxy simply to get recording does create some added latency on the call as well as introducing another potential point of failure. In a siprec call, if rtpengine dies for some call the "real" call is unaffected; not so when rtpengine is a media proxy -- if it dies in that scenario callers lose audio.

(2) You have the ability to add additional metadata in the siprec call if needed

(3) Siprec call will generate one pcap file with caller and callee audio, I'm not sure if opensips recording generates a "mixed" file like that or one per stream

davehorton commented 5 years ago

In any case, to further troubleshoot I would say lets turn off call recording on opensips for now so we can see the single set of commands from siprec to rtpengine, then lets get another pcap, drachtio log, and rtpengine log

richnayay commented 5 years ago

1) That rtpengine log shows two 'offer' commands for the incoming call--> both softphone connected to same opensips so for each softphone it is creating an offer

2) Both offer commands are coming from 54.160.157.91 -- what is running on this IP: OpenSips drachtio is running on different machine

3) 804036e787334c84a10a3187db3137d1: callid id from softphone A to B B2B.457.5522053.1548854058: call id generated by OpenSips siprec INVITE for client A B2B.457.7576095.1548854059: call id generated by OpenSips siprec INVITE for client B

4)In last comment you are saying I need to run a call without recording i.e. without drachtio and Opensips siprec client. one with existing setup and send you the logs correct?

davehorton commented 5 years ago

Sorry, no. I would like to turn off the opensips direct recording, and only have the drachtio recording.

From what you are indicating, the drachtio server never sends a command to rtpengine? Then we would need to troubleshoot that. Is that the problem -- the offer command from drachtio never appears to be received by rtpengine?

richnayay commented 5 years ago

opensips direct recording is already off we have set only drachtio recording. only the drachtio server sends a command to rtpengine

davehorton commented 5 years ago

OK, so if I understand correctly:

Is that correct?

There are too many offer commands coming into rtpengine for a single call for some reason. Please do a retest and send all of these:

richnayay commented 5 years ago

opensips direct call recording is off BUT, you have configured opensips to proxy media through rtpengine. Is that correct? Yes

richnayay commented 5 years ago

drachtio.log drachtio.zip rtpengine.log rtpengine_31_jan.zip

richnayay commented 5 years ago

following are the ips of the setup astreik(party A): 162.243.203.27 opensips: 54.160.157.91 rtpengine: 167.99.54.110 drachtio: 138.197.47.209 softphone(party B): 219.65.44.210 >>registered at OPenSips

I have also attached metadata file empty recording file and drachtio recorder debug logs printed on screen B2B.457.4454992.1548917961-4ddab698029de44d.zip drachtio_recorder_debug_logs.txt rtpengine-meta-B2B.457.4454992.1548917961-4ddab698029de44d.txt

davehorton commented 5 years ago

I believe there is some issue with your siprec configuration on the opensip server. Below is the SDP that it offers in the SIPREC INVITE -- note that the connection address (c=) is 127.0.0.1 for some reason (i.e. localhost) whereas it should be 54.160.157.91.

From looking at the rtpengine logs, everything is set up fine, its just that opensips never sends any RTP packets, and I think it is related to the above configuration issue.

Can you correct the opensips configuration so that it is offering an SDP with its public IP address?

See below for the c= line....

v=0
o=- 1548917960 0 IN IP4 0.0.0.0
s=-
t=0 0
c=IN IP4 127.0.0.1
m=audio 35005 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=label:1
a=sendonly
m=audio 35006 RTP/AVP 8 101
b=AS:84
a=X-nat:0
b=TIAS:64000
a=rtcp:65076 IN IP4 192.168.1.224
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ice-ufrag:27251643
a=ice-pwd:0de56f3c
a=candidate:Hc0a801e0 1 UDP 2130706431 192.168.1.224 65074 typ host
a=candidate:Hc0a801e0 2 UDP 2130706430 192.168.1.224 65076 typ host
a=label:2
a=sendonly
davehorton commented 5 years ago

By comparison, in the 'offer' command sent by opensips to proxy the media, where we do see rtp packets arrive on rtpengine, note the presence of the public IP address of the asterisk server

o=root 26126825 26126825 IN IP4 162.243.203.27
s=Asterisk PBX 1.8.32.3
c=IN IP4 162.243.203.27
t=0 0
m=audio 13504 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
davehorton commented 5 years ago

see docs here

try setting media_ip in siprec_start_recording.

This presumes you are running rtpproxy on the same box as opensips (is that the case) ?

davehorton commented 5 years ago

I also wonder if if your configuration of running rtpengine as a media proxy for opensips, at the same time doing siprec which requires rtpproxy, is a valid configuration....

richnayay commented 5 years ago

This presumes you are running rtpproxy on the same box as opensips (is that the case) ?

using rtpengine on different machine than opensips

richnayay commented 5 years ago

You have mentioned. Interoperability This application has been tested with the following SIPREC client OpenSIPS (tested with rtpengine)

davehorton commented 5 years ago

Yes, it has been tested with opensips before. Someone other than myself did that testing, so I am not sure of the opensips configuration they used. I'm pretty sure though that that testing did not involve rtpengine being used simultaneously as the siprec server and as the media proxy server by the same opensips.

If you look at the siprec docs I pointed you to for opensips, it says that the siprec module depends on and requires the use of the rtpproxy module. rtpproxy is an alternative and different product from rtpengine, and it is not clear to me that you can mix and match them in a single opensips configuration the way you seem to be wanting to do. Thus I think you should first verify this configuration with the opensips guys.

davehorton commented 5 years ago

here is described a basic opensips configuration for siprec.

I would suggest starting with that basic configuration -- which uses the required rtpproxy, not rtpengine -- and verify that is working. Then, if necessary, make your opensips configuration changes from there.

richnayay commented 5 years ago

Its working fine with basic config and creating the recording file. thanks for your help Dave

davehorton commented 5 years ago

Great!