drachtio / drachtio-siprec-recording-server

SIPREC recording server based on drachtio and rtpengine
MIT License
83 stars 34 forks source link

Question - where is the metadata XML for each recording saved to (other than drachtio.log)? #11

Closed solarmon closed 5 years ago

solarmon commented 5 years ago

Hi,

I have a question regarding if/whether the metadata XML received in the SIPREC INVITE is, or can be, saved somewhere (other than in drachtio.log) - whether as individual files or as a database record?

davehorton commented 5 years ago

You are correct -- currently it is not stored anywhere. You can certainly modify the app to store it in any way that you like. One interesting and useful possibility is to JSONify it and put it in the 'offer' command to rtpengine as metadata (assuming you are using rtpengine as the recorder).

I've done that for one implementation, and this is nice as it ends up in the metadata file on the rtpengine server that is generated as part of recording. From there, as recordings appear, you can process the audio and the metadata for the call, which can contain anything useful that came in the XML part of the SDP.

But that's just one example, you could store it wherever you like. Since this is somewhat of a bare-bones app, and I can't predict all the different things people might want to do with the metadata, no specific handling of it is implemented

solarmon commented 5 years ago

Thanks for the quick response!

I basically need to transfer the call recording and any associated metadata to a remote storage solution for further processing. So it is ideal that the call recording and associated metadata are combined.

I certainly like the idea of injecting it in to the 'offer' message to rtpengine (which I am testing with)!

Are you able to provide, or point me to, any examples of such an implementation? My knowledge on node.js is non-existent at the moment, so any working examples will be of great help.

davehorton commented 5 years ago

What you would want to do is change this line

from

const args = Object.assign({}, opts.callDetails, {

to something like:

const args = Object.assign({metadata: ${JSON.stringify(myData)}, opts.callDetails, {

where you had put all of the metadata you wanted to save with the call into an object called 'myData'.

You can see in the docs for the offer command that whatever you put as a 'metadata' attribute will end up at the bottom of the metadata file that rtpengine creates for each recording

davehorton commented 5 years ago

Closing this for now as I think we are good?. (feel free to ping me at daveh @ drachtio.org if you'd like help building out your app and the audio/metadata post-processing service on a commercial basis)

solarmon commented 5 years ago

Hi,

Thank you for the example - much appreciated.

It looks like rtpengine deletes its metadata files (in /var/spool/rtpengine) after the call has completed:

https://github.com/sipwise/rtpengine/issues/374

I was able to get rtpengine-recording to send call records to a database, and am trying to get the metadata part working.

I have used the following just to test

const args = Object.assign({'metadata': {'src': "1.1.1.1", 'dst': "2.2.2.2"}}, opts.callDetails, {

So I'm expecting those key pairs to appear in the rtpengine metadata file and in the 'recording_metakeys' table in the database.

I see neither at the moment.

The debug shows that drachtio is attempting to send the metadata in the 'offer':

rtpengine:client RtpEngine: sending command: 1ffb0aaf-9ea1-4334-9fb8-6a54505533fd: {"metadata":{"src":"1.1.1.1","dst":"2.2.2.2"},"call-id":"B2B.436.1149906.1554981777","from-tag":"ab4a1a9184a3756688fb9d8cb2be795b-ce21","sdp":"v=0\r\no=- 1554981777 0 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\nc=IN IP4 212.161.103.203\r\nm=audio 35051 RTP/AVP 8 0 101\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=label:1\r\na=sendonly\r\n","replace":["origin","session-connection"],"ICE":"remove","record call":"yes","command":"offer"} +0ms

Looking at the rtpengine offer-message documentation it states:

metadata string must contain a list of key:val pairs separated by | character

I cannot perform a packet capture of the 'offer' request at the moment since rtpengine is local to drachtio - so I cannot check the format of the 'offer'.

Can you confirm that the JSON metadata is translated in to a key/value pair delimited by '|'?

davehorton commented 5 years ago

No, the JSON metadata is not automatically translated to a string with '|'. If you re-read the rtpengine doc, you onlly need to do that if you want the data written to the recording-metakey table, using their mysql integration. Otherwise it gets written to the bottom of the rtpengine metadata file (in this case, as JSON). Of course, you can change the app to format it as a pipe-delimited string if you like. I've not used their mysql integration, but it looks interesting. I'm not familiar with the problem of metadata files getting delieted; was not happening in the earlier release I originally deployed with

solarmon commented 5 years ago

Hi,

Below is an example of the tshark/wireshark packet capture for the offer message going to rtpengine:

ff20bfd6-697a-410f-81bc-9b9527f8e89e d3:ICE6:remove7:call-id26:B2B.436.4098990.15555979807:command5:offer8:from-tag37:ab4a1a9184a3756688fb9d8cb2be795b-ce218:metadatad3:dst7:2.2.2.23:src7:1.1.1.1e11:record call3:yes7:replacel6:origin18:session-connectione3:sdp182:v=0
o=- 1555597980 0 IN IP4 0.0.0.0
s=-
t=0 0
c=IN IP4 212.161.103.203
m=audio 35069 RTP/AVP 8 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=label:1
a=sendonly
e

Is this the expected format? I can see where it contains the metadata, but rtpengine is not adding it to the .meta file (in /var/spool/rtpengine).

Would you say this an rtpengine issue?

davehorton commented 5 years ago

well it appears that the metadata is being included in the offer request. What version of rtpengine are you using? When you turn up rtpengine log files to debug, what logging do you see on that side?

solarmon commented 5 years ago

Should be latest/recent one from github:

# rtpengine --version
Version: git-master-3d64af1

# rtpengine-recording --version
Version: git-master-3d64af1

I will turn on debug on rtpengine/rtpengine-recording side, and probably raise a ticket with them also, and will report back.

davehorton commented 5 years ago

ok I will try to test myself on this release in the next day or two

solarmon commented 5 years ago

I enabled debugging on rtpengine-recording.

Below is a filtered view just for metafile.c:

DEBUG: [metafile.c:167] allocating metafile info for B2B.436.5791941.1555657239-2a863fa315726bcb.meta
DEBUG: [metafile.c:247] section CALL-ID
DEBUG: [metafile.c:267] content length 26
DEBUG: [metafile.c:247] section PARENT
DEBUG: [metafile.c:267] content length 43
DEBUG: [metafile.c:247] section RECORDING 1
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section FORWARDING 0
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section STREAM 0 details
DEBUG: [metafile.c:267] content length 49
DEBUG: [metafile.c:91] stream 0 details TAG 1 MEDIA 0 TAG-MEDIA 1 COMPONENT 1 FLAGS 65536
DEBUG: [metafile.c:247] section STREAM 0 interface
DEBUG: [metafile.c:267] content length 34
DEBUG: [metafile.c:84] stream 0 interface tag-1-media-1-component-1-RTP-id-0
DEBUG: [metafile.c:247] section STREAM 1 details
DEBUG: [metafile.c:267] content length 50
DEBUG: [metafile.c:91] stream 1 details TAG 1 MEDIA 0 TAG-MEDIA 1 COMPONENT 2 FLAGS 131072
DEBUG: [metafile.c:247] section STREAM 1 interface
DEBUG: [metafile.c:267] content length 35
DEBUG: [metafile.c:84] stream 1 interface tag-1-media-1-component-2-RTCP-id-1
DEBUG: [metafile.c:247] section STREAM 2 details
DEBUG: [metafile.c:267] content length 51
DEBUG: [metafile.c:91] stream 2 details TAG 0 MEDIA 1 TAG-MEDIA 1 COMPONENT 1 FLAGS 1114112
DEBUG: [metafile.c:247] section STREAM 2 interface
DEBUG: [metafile.c:267] content length 34
DEBUG: [metafile.c:84] stream 2 interface tag-0-media-1-component-1-RTP-id-2
DEBUG: [metafile.c:247] section STREAM 3 details
DEBUG: [metafile.c:267] content length 51
DEBUG: [metafile.c:91] stream 3 details TAG 0 MEDIA 1 TAG-MEDIA 1 COMPONENT 2 FLAGS 1179649
DEBUG: [metafile.c:247] section STREAM 3 interface
DEBUG: [metafile.c:267] content length 35
DEBUG: [metafile.c:84] stream 3 interface tag-0-media-1-component-2-RTCP-id-3
DEBUG: [metafile.c:247] section MEDIA 0 PAYLOAD TYPE 101
DEBUG: [metafile.c:267] content length 20
DEBUG: [metafile.c:104] payload type in media 0 num 101 is telephone-event/8000
DEBUG: [metafile.c:247] section MEDIA 0 PAYLOAD TYPE 0
DEBUG: [metafile.c:267] content length 9
DEBUG: [metafile.c:104] payload type in media 0 num 0 is PCMU/8000
DEBUG: [metafile.c:247] section MEDIA 0 PAYLOAD TYPE 8
DEBUG: [metafile.c:267] content length 9
DEBUG: [metafile.c:104] payload type in media 0 num 8 is PCMA/8000
DEBUG: [metafile.c:247] section TAG 0
DEBUG: [metafile.c:267] content length 37
DEBUG: [metafile.c:247] section SDP from 0 before offer
DEBUG: [metafile.c:267] content length 182
DEBUG: [metafile.c:247] section SDP from 0 after offer
DEBUG: [metafile.c:267] content length 240
DEBUG: [metafile.c:247] section RECORDING 1
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section FORWARDING 0
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section STREAM 0 FORWARDING 0
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section STREAM 1 FORWARDING 0
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section STREAM 2 FORWARDING 0
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section STREAM 3 FORWARDING 0
DEBUG: [metafile.c:267] content length 0
DEBUG: [metafile.c:247] section MEDIA 1 PAYLOAD TYPE 101
DEBUG: [metafile.c:267] content length 20
DEBUG: [metafile.c:104] payload type in media 1 num 101 is telephone-event/8000
DEBUG: [metafile.c:247] section MEDIA 1 PAYLOAD TYPE 8
DEBUG: [metafile.c:267] content length 9
DEBUG: [metafile.c:104] payload type in media 1 num 8 is PCMA/8000
DEBUG: [metafile.c:247] section TAG 1
DEBUG: [metafile.c:267] content length 36
DEBUG: [metafile.c:247] section SDP from 1 before answer
DEBUG: [metafile.c:267] content length 214
DEBUG: [metafile.c:247] section SDP from 1 after answer
DEBUG: [metafile.c:267] content length 228

This does not have a section for 'METADATA', which I'm expecting during the metafile creation - as per the metafile.c code:

https://github.com/sipwise/rtpengine/blob/26b725d0245d98ec04f0944a60fb348932339d22/recording-daemon/metafile.c

So it looks like the json metadata in the offer message is not be matched/processed for whatever reason.

davehorton commented 5 years ago

did the logging show the actual 'offer' command, as received by rtpengine?

solarmon commented 5 years ago

I also enabled debugging for the rtpengine process (there is a separate rtpengine-recording process). Unfortunately, it seems the rtpengine debugs doesn't show and break down the received 'offer' message, only that it has been received and replied to:

rtpengine[19278]: INFO: [B2B.436.1216600.1555681659]: Received command 'offer' from 10.201.244.78:43045
rtpengine[19278]: [527B blob data]
rtpengine[19278]: NOTICE: [B2B.436.1216600.1555681659]: Creating new call
rtpengine[19278]: NOTICE: [B2B.436.1216600.1555681659]: Turning on call recording.
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: kernel call idx is 1
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: Default sink codec is PCMA/8000
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: Creating codec handler for PCMA/8000
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: Sink supports codec PCMA/8000
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: Creating codec handler for PCMU/8000
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: Sink supports codec PCMU/8000
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: Creating codec handler for telephone-event/8000
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: creating send_timer
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: creating send_timer
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: creating send_timer
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: creating send_timer
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: kernel stream idx is 4
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: kernel stream idx is 5
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: set FILLED flag for stream 212.161.103.203:35087
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: set FILLED flag for stream 212.161.103.203:35088
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: kernel stream idx is 6
rtpengine[19278]: DEBUG: [B2B.436.1216600.1555681659]: kernel stream idx is 7
rtpengine[19278]: INFO: [B2B.436.1216600.1555681659]: Replying to 'offer' from 10.201.244.78:43045 (elapsed time 0.001823 sec)
rtpengine[19278]: [356B blob data]
davehorton commented 5 years ago

Let's go back to the detailed offer command you sent, because now I see a problem. Here is is, broken out:

ff20bfd6-697a-410f-81bc-9b9527f8e89e <== message cookie, followed by bencoded stuff d <== dictionary 3:ICE 6:remove 7:call-id 26:B2B.436.4098990.1555597980 7:command 5:offer 8:from-tag 37:ab4a1a9184a3756688fb9d8cb2be795b-ce21 8:metadata d <== dictionary 3:dst 7:2.2.2.2 3:src 7:1.1.1.1 e <= end dictionary 11:record call 3:yes 7:replace l <== list of values 6:origin 18:session-connection e <== end list 3:sdp 182:v=0 o=- 1555597980 0 IN IP4 0.0.0.0 s=- t=0 0 c=IN IP4 212.161.103.203 m=audio 35069 RTP/AVP 8 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=label:1 a=sendonly e <== end big dictionary

Do you see the problem? Your metadata is a dictionary. It must be a string, per the docs

- metadata
        This is a generic metadata string...

Remember above when I told you to do JSON.stringify on your metadata object? I think you forgot to do that, and I am guessing that is the problem..

solarmon commented 5 years ago

I had used:

const args = Object.assign({'metadata': {'src': "1.1.1.1", 'dst': "2.2.2.2"}}, opts.callDetails, {

If I use your recommended code, with a myData variable set:

var myData = { src: "1.1.1.1", dst: "2.2.2.2"};
const args = Object.assign({metadata: ${JSON.stringify(myData)}, opts.callDetails, {

I get following error:

const args = Object.assign({metadata: ${JSON.stringify(myData)}, opts.callDetails, {
                                       ^

SyntaxError: Unexpected token {

Even when corrected (added missing closing curly bracket):

const args = Object.assign({metadata: ${JSON.stringify(myData)}}, opts.callDetails, {

I still get the 'Unexpected token' error.

Can you confirm again what the format of the example code should be. Sorry, my node.js language skill is rubbish.

davehorton commented 5 years ago
const args = Object.assign({metadata: JSON.stringify({src: "1.1.1.1", dst: "2.2.2.2"})}, opts.callDetails, {
solarmon commented 5 years ago

Bingo!

Now debugs shows a METADATA section:

rtpengine-recording[19297]: DEBUG: [metafile.c:167] allocating metafile info for B2B.436.1521424.1555688174-c4a9bf8015a2cdce.meta
rtpengine-recording[19297]: DEBUG: [metafile.c:247] section CALL-ID
rtpengine-recording[19297]: DEBUG: [metafile.c:267] content length 26
rtpengine-recording[19297]: DEBUG: [metafile.c:247] section PARENT
rtpengine-recording[19297]: DEBUG: [metafile.c:267] content length 43
rtpengine-recording[19297]: DEBUG: [metafile.c:247] section METADATA
rtpengine-recording[19297]: DEBUG: [metafile.c:267] content length 33

and now the rtpengine database has an entry in the 'recording_metakeys' table, although the key/value processing is not correct.

INSERT INTO `recording_metakeys` (`id`, `call`, `key`, `value`) VALUES
(1, 45, '{"src"', '"1.1.1.1","dst":"2.2.2.2"}')

with key of:

{"src"

and value of:

"1.1.1.1","dst":"2.2.2.2"}

I'm surprised it got through to the database in the first place, as I thought the key/value pairs needed to be separated with a '|' character.

solarmon commented 5 years ago

In the temporary .meta file created, it now contains the JSON metadata:

METADATA
33:
{"src":"1.1.1.1","dst":"2.2.2.2"}
solarmon commented 5 years ago

Just an update for completeness.

I've managed to figure out how to send a '|' delimited string, instead of the JSON formatted string. I've used this example:

var myData = "local_party:" + opts.caller.number + "|" + "remote_party:" + opts.callee.number;
const args = Object.assign({metadata: myData}, opts.callDetails, {

This seems to work, and I get the appropriate 'local_party' and 'remote_party' keys in the 'recording_metakeys' table:

(30, 61, 'local_party', 'test'),
(31, 61, 'remote_party', '44123456789');

Thank you very much for your support and patience - it is much appreciated!

davehorton commented 5 years ago

excellent!