Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Audiocodes SBC syslog #75

Closed
spady7 opened this issue Dec 17, 2020 · 50 comments
Closed

Audiocodes SBC syslog #75

spady7 opened this issue Dec 17, 2020 · 50 comments
Labels
enhancement help wanted

Comments

@spady7
Copy link

spady7 commented Dec 17, 2020

Hi, I'am trying to send "syslog" coming from Audiocodes SBC to Homer 7.
What i did so far is a configuration file for pastash:

`input {
udp {
host => 0.0.0.0
port => 514
type => syslog
}
}

output {
stdout{}
if [rcinfo] != 'undefined' {
hep {
host => '10.160.21.80'
port => 9069
hep_id => 2222
hep_type => 1
}
}
}`

and i am sending the following output to Homer 7:

[STDOUT] { "message": "<133>[S=1455266] [SID=b9027c:24:167717] (N 5828845) AcSIPDialog(#1532): Handling GENERAL_RESPONSE_REQ in state DialogInitiated \n(N 5828846) States: (#1532)AcSIPDialog[DialogInitiated->DialogConnected] \n(N 5828847) ---- Outgoing SIP Message to 52.114.76.76:12544 from SIPInterface #2 (Teams) TLS TO(#156) SocketID(182) ---- \nSIP/2.0 200 OK \nVia: SIP/2.0/TLS 52.114.76.76:5061;branch=z9hG4bK5e9ae5e1 \nFrom: <sip:sip-du-a-eu.pstnhub.microsoft.com:5061>;tag=d652f27d-dba2-466e-b4a6-c0b6db2fd363 \nTo: <sip:10.160.111.51>;tag=1c345880336 \nCall-ID: 7ac9a01a-9624-41b8-970d-c903c5b24cd5 \nCSeq: 1 OPTIONS \nContact: <sip:sbc.domain.com:5061;transport=tls> \nServer: SBC Lab/v.7.20A.260.012 \nContent-Length: 0 \n \n \n(N 5828848) AcSIPDialog(#1532): Handling DIALOG_DISCONNECT_REQ in state DialogConnected \n(N 5828849) States: (#1532)AcSIPDialog[DialogConnected->DialogDisconnected] \n(N 5828850) RELEASE_ACK_EV: (#117)SIPSBCDialogLeg -> (#23)SBCDialog[Disconnecting->Disconnected] \n -> (#17)SBCEndPoint[Releasing->Released] \n -> (#8)SBCController[Disconnecting->Disconnected] \n -> (#16)SBCEndPoint[Releasing->Released] \n -> (#90)SBCDialog[Disconnecting->Disconnected] \n -> (#113)SIPSBCDialogLeg[Deallocated] \n [Time:17-12@17:08:32.551]", "host": "10.160.21.20", "udp_port": "514", "type": "syslog", "@timestamp": "2020-12-17T15:08:39.891Z", "@version": "1" } [STDOUT] { "message": "<133>[S=1455267] [SID=b9027c:24:167717] (N 5828851) SIPAppMngr::GetControlIPAddress - Near NAT translation found for SIP Interface 2. Translated IP Address 82.185.88.164:5061 \n(N 5828852) States: (#117)SIPSBCDialogLeg[Deallocated] \n(N 5828853) Discarding event SBC_ROUTING_DONE_EV. Receiver is invalid (#127) \n(N 5828854) States: (#57)SBCRoutesIterator[Deallocated] \n (#127)SBCFeature[Deallocated] \n (#8)SBCController[Deallocated] \n(N 5828855) CAC: Remove SBC Outgoing Other, IPG 1 (Teams): 0, SRD 0 (DefaultSRD): 0, SipIF 2 (Teams): 0 \n(N 5828856) States: (#90)SBCCall[Deallocated] \n(N 5828857) CAC: Remove SBC Incoming Other, IPG 1 (Teams): 0, SRD 0 (DefaultSRD): 0, SipIF 2 (Teams): 0 \n(N 5828858) States: (#23)SBCCall[Deallocated] \n [Time:17-12@17:08:32.552]", "host": "10.160.21.20", "udp_port": "514", "type": "syslog", "@timestamp": "2020-12-17T15:08:39.892Z", "@version": "1" } [STDOUT] { "message": "<135>[S=1455268] [BID=b9027c:24] _DnsCallback: end query recieved _GetInterfaceIndexByCtx(ctx) 1, q->qtyp 1 q->name sip-du-a-as.pstnhub.microsoft.com, p.dnsp_ttl 2 [File:DnsApi_Linux.cpp Line:1390] [Time:17-12@17:08:32.560]", "host": "10.160.21.20", "udp_port": "514", "type": "syslog", "@timestamp": "2020-12-17T15:08:39.896Z", "@version": "1" } [STDOUT] { "message": "<135>[S=1455269] [BID=b9027c:24] _DnsUpdateCacheEntryAddrInfo: update addr for query sip-du-a-as.pstnhub.microsoft.com [File:DnsApi_Linux.cpp Line:360] [Time:17-12@17:08:32.560]", "host": "10.160.21.20", "udp_port": "514", "type": "syslog", "@timestamp": "2020-12-17T15:08:39.896Z", "@version": "1" } [STDOUT] { "message": "<135>[S=1455270] [BID=b9027c:24] sip-du-a-as.pstnhub.microsoft.com resolved to 52.114.7.24 [File:DnsApi_Linux.cpp Line:313] [Time:17-12@17:08:32.560]", "host": "10.160.21.20", "udp_port": "514", "type": "syslog", "@timestamp": "2020-12-17T15:08:39.897Z", "@version": "1" }

However I cannot see anything on Homer server.
Any help?

Regards
@lmangani
Copy link
Member

It's not that simple :) The current attempt will not produce any results. pastash can receive the syslog input, but needs help converting it into a format we can use. The key here is to find a correlation vector from syslog to our realm.

Is there any information in your syslog we can correlate back to a SIP session detail? S? BID? If so, we can build a parser (check out the Ribbon example for a reference) to convert the messages to either SIP HEP (1) or LOG HEP (100) to be sent to Homer. For some products, we look for an internal correlation ID and map it to ephemeral elements which might appear in the flow.

@spady7
Copy link
Author

spady7 commented Dec 17, 2020

Yes, we could use [SID=b9027c:24:167717]

It means:
b9027c = last 3 byte of MAC ADDRES of SBC
24 = number of reset (reset of SBC)
167717 = ID of the entire call (SIP call).

Can this help you?

@spady7

This comment has been minimized.

Sign in to view
@lmangani
Copy link
Member

lmangani commented Dec 17, 2020 •
edited
Loading

The SIP parsing part is quite simple and in-line with other syslog extractors we have for Sonus/Ribbon/Avaya/etc.
The shortcoming is about the network part - as you can observe, unless I'm missing something else, the logs only reveal the remote IPs and unfortunately never the local IP:PORT of the system handling the traffic- since names cannot be used this is the blocker/challenge to surpass:

Outgoing SIP Message to xx.yy.zz.qq:12544 from SIPInterface #2 (Teams) TLS TO(#156) SocketID(182)

The application would have to be provisioned with an array of IP:PORT equivalents for those Source IP Group aliases.

@lmangani

This comment has been minimized.

Sign in to view
@lmangani
Copy link
Member

@spady7 happy hacking: https://github.com/sipcapture/paStash/blob/next/plugins/filters/app_audiocodes/app_audiocodes.md

@spady7

This comment has been minimized.

Sign in to view
@lmangani
Copy link
Member

lmangani commented Dec 17, 2020 •
edited
Loading

The output on screen will not be much relevant. Could you show me your full pastash recipe with the new filter?
Should be something like so:

input {
  tcp {
    host => 0.0.0.0
    port => 9514
    type => syslog
  }
}

filter {
  app_audiocodes {}
}

output {
  stdout{}
  if [rcinfo] != 'undefined' {
        hep {
          host => '127.0.0.1'
          port => 9060
          hep_id => 2222
          hep_type => 1
        }
  }
}

Mind this is unlikely to work as is, its never been tested and a pure work of theory. You'll have to hack a little :)

@lmangani
Copy link
Member

Don't forget you need to also find a way to provide your realms or your SBC will always look as 127.0.0.1:5060 without Aliases. If you provide some examples for the parts i've explained are missing, we might be able to make progress on that too.

@spady7
Copy link
Author

spady7 commented Dec 17, 2020 via email

@spady7

This comment has been minimized.

Sign in to view
@lmangani

This comment has been minimized.

Sign in to view
@spady7

This comment has been minimized.

Sign in to view
@lmangani
Copy link
Member

Then the script is failing to parse and we need to debug it further. Do run this for a few minutes with traffic to get us something to work with consistently - check if the file is created it should have the data in the JSON format pastash uses internally.

input {
  udp {
    host => 0.0.0.0
    port => 514
    type => syslog
  }
}

output {
  file {
    path => /tmp/syslog.dump
  }
}

I'll test it domani ;)

@spady7
Copy link
Author

spady7 commented Dec 17, 2020 via email

@lmangani
Copy link
Member

lmangani commented Dec 17, 2020 •
edited
Loading

We will end up adding some custom config to the filter eventually, but first we need to parse this right. It's a step by step process. I see some other IPs in the logs referring to interfaces, but only you can tell us what's relevant and what's not.

@spady7
Copy link
Author

spady7 commented Dec 17, 2020 via email

@spady7
Copy link
Author

spady7 commented Dec 17, 2020 via email

@lmangani
Copy link
Member

That's perfect, sorry if I confused you, this will simply allow reimporting it into the JSON format pastash uses.
I'll give it a go and let you know what we find out.

@lmangani
Copy link
Member

Pushed a new version which SHOULD produce some output, feel free to try it out:

+ @pastash/filter_app_audiocodes@1.0.12

todo:

  • extract and use message timestamp instead of now()
  • convert SBC realm to IP:PORT instead of 127.0.0.1:5060

@spady7
Copy link
Author

spady7 commented Dec 18, 2020 via email

@lmangani
Copy link
Member

I don't see any picture, you can 'drag' them into the editor and they should upload. This is a good first step. I've based my example only on responses so there might be bugs on the other Incoming messages. Please confirm if this is the case and I'll take a look.
Once that's sorted, we can think of how to get the right ports and addresses figured.

@lmangani
Copy link
Member

  • @pastash/filter_app_audiocodes@1.0.13

@spady7
Copy link
Author

spady7 commented Dec 19, 2020

Schermata 2020-12-18 alle 22 26 27

Schermata 2020-12-18 alle 22 28 44

@spady7
Copy link
Author

spady7 commented Dec 19, 2020 via email

@lmangani
Copy link
Member

lmangani commented Dec 19, 2020 •
edited
Loading

The screenshot doesn't tell me anything. This is about looking for and sharing message details such as parsing of Call-IDs being right or wrong, not just clicking once :) You need to look inside a few messages and tell us if its even right. There's nothing more I can do on your behalf here unless you can share a large chunk of data or a full Call-Flow.

@adubovikov
Copy link
Member

on the call flow you see only one message, because for that call id only one message exists :-)

@spady7
Copy link
Author

spady7 commented Dec 19, 2020

Sorry guys, Maybe it's not clear to me then how this tool really should work.
Following an entire call (done now) I report from the CLI what has arrived and how it is shown on Homer's GUI.
I expect the whole call-flow to be seen on HOMER (but maybe I misinterpreted and it doesn't have to be), or not?
Sorry if I ask you to explain me in a very basic way.
Thanks

[Sat, 19 Dec 2020 10:45:06 GMT] ERROR failed parsing Incoming SIP <133>[S=1718460] [SID=b9027c:24:198171] (N 6891676) (#228)Route found (5), Route by IPGroup, IP Group 1 -> 2 (Teams -> Oxe-Cloud) #012(N 6891677) ---- Incoming SIP Message from 52.114.75.24:9024 to SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012 [Time:19-12@12:44:54.873] [Sat, 19 Dec 2020 10:45:06 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718465] [SID=b9027c:24:198171] (N 6891688) AcSIPCall(#945)::UpdateRemoteLocation - Setting ReceivedFrom address as transport object's key 52.114.75.24:5061 #012(N 6891689) AcTransactionUser::CheckRemoteAddressChange - Remote is behind the NAT #012(N 6891690) States: (#945)AcSIPCall[Idle->Invited] #012(N 6891691) SBCSetupData: (#32)AcSBCCallAPI -> (#32)SIPSBCCallLeg #012(N 6891692) States: (#32)SBCOfferAnswerMngr[Idle->Offered] #012(N 6891693) (#21)MediaStream[Allocated] (#21)MediaStream belongs to call #7 #012(N 6891694) AllocateAddress: Allocated address port 8068 IntIPv4 1 IntIPv6 -1 extension 1 #012(N 6891695) MapLocalMediaIpPort - Translated media port 10.160.111.51:8068 to 82.185.88.164:8068 #012(N 6891696) (#7)ChannelResource::AllocateMediaIpPorts RealmIndex(2) port(8068) Allocated. #012(N 6891697) AcSIPCall(#945): Handling TRYING_REQ in state Invited #012(N 6891698) ---- Outgoing SIP Message to 52.114.75.24:9024 from SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012 [Time:19-12@12:44:54.874] [Sat, 19 Dec 2020 10:45:06 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718468] [SID=b9027c:24:198171] (N 6891721) UdpRtxMngr::Transmit 1 INVITE Rtx Left: 6 Dest: 10.160.21.200:5060, TU: AcSIPCall(#942) #012(N 6891722) ---- Outgoing SIP Message to 10.160.21.200:5060 from SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012 [Time:19-12@12:44:54.875] [Sat, 19 Dec 2020 10:45:06 GMT] ERROR failed parsing Incoming SIP <133>[S=1718471] [SID=b9027c:24:198171] (N 6891723) ---- Incoming SIP Message from 10.160.21.200:5060 to SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012SIP/2.0 100 Trying #012To: <sip:00522385011@10.160.21.200;user=phone> #012From: "Antonio Spirandelli" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=1c414268318 #012Call-ID: 111765558019122020124454@10.160.21.20 #012CSeq: 1 INVITE #012Via: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac435960060 #012Content-Length: 0 #012 #012 #012(N 6891724) UdpRtxMngr::Remove 1 INVITE, TU: AcSIPCall(#942) #012(N 6891725) AcSIPCall(#942): Handling 100 in state Inviting #012(N 6891726) States: (#942)AcSIPCall[Inviting->Proceeding] #012 [Time:19-12@12:44:54.891] [STDOUT] { "payload": "OPTIONS sip:10.160.21.20 SIP/2.0 \r\nVia: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac2110970476 \r\nMax-Forwards: 70 \r\nFrom: <sip:10.160.21.20>;tag=1c831784973 \r\nTo: <sip:10.160.21.20> \r\nCall-ID: 42154736119122020124454@10.160.21.20 \r\nCSeq: 1 OPTIONS \r\nContact: <sip:10.160.21.20:5062> \r\nAllow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE \r\nUser-Agent: LLSBC Laboratorio/v.7.20A.260.012 \r\nAccept: application/sdp, application/simple-message-summary, message/sipfrag \r\nContent-Length: 0 OPTIONS sip:10.160.21.20 SIP/2.0 \r\nVia: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac2110970476 \r\nMax-Forwards: 70 \r\nFrom: <sip:10.160.21.20>;tag=1c831784973 \r\nTo: <sip:10.160.21.20> \r\nCall-ID: 42154736119122020124454@10.160.21.20 \r\nCSeq: 1 OPTIONS \r\nContact: <sip:10.160.21.20:5062> \r\nAllow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE \r\nUser-Agent: LLSBC Laboratorio/v.7.20A.260.012 \r\nAccept: application/sdp, application/simple-message-summary, message/sipfrag \r\nContent-Length: 0 \r\n\r\n", "rcinfo": { "type": "HEP", "version": 3, "payload_type": 1, "ip_family": 2, "protocol": 17, "proto_type": 1, "correlation_id": "42154736119122020124454@10.160.21.20", "srcIp": "127.0.0.1", "srcPort": 5060, "dstIp": "10.160.21.200", "dstPort": "5060", "time_sec": 1608374706365, "time_usec": 0 } } [Sat, 19 Dec 2020 10:45:06 GMT] ERROR failed parsing Incoming SIP <133>[S=1718473] [BID=b9027c:24] (N 6891735) ---- Incoming SIP Message from 10.160.21.200:5060 to SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012SIP/2.0 200 OK #012Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, SUBSCRIBE, OPTIONS, UPDATE, INFO #012Contact: sip:10.160.21.200;isfocus #012Supported: timer,path,100rel #012User-Agent: OmniPCX Enterprise R12.1 m2.300.29.a #012To: <sip:10.160.21.20>;tag=d2128354b858191d177e29389ac8df93 #012From: <sip:10.160.21.20>;tag=1c831784973 #012Call-ID: 42154736119122020124454@10.160.21.20 #012CSeq: 1 OPTIONS #012Via: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac2110970476 #012Content-Length: 0 #012 #012 #012(N 6891736) UdpRtxMngr::Remove 1 OPTIONS, TU: AcSIPDialog(#951) #012(N 6891737) AcSIPDialog(#951): Handling 200 OK in state DialogInitiated #012(N 6891738) States: (#951)AcSIPDialog[DialogInitiated->DialogConnected] #012(N 6891739) SIPServersMngr::UpdateSetWithOnlineServer - Server 10.160.21.200 already on working servers list #012(N 6891740) AcSIPDialog(#951): Handling DIALOG_DISCONNECT_REQ in state DialogConnected #012(N 6891741) States: (#951)AcSIPDialog[DialogConnected->DialogDisconnected] #012(N 6891742) SIPAppMngr::FreeDialogAPI - (#468) #012 [Time:19-12@12:44:54.968] [Sat, 19 Dec 2020 10:45:08 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718476] [SID=b9027c:24:198173] (N 6891745) (#20)gwSession[Allocated]. Handle:00007FCCBDDC17D8; Global session ID: 53e6936eefa8ca7a #012(N 6891746) SIPEntity::PrepareConfigurationData: Setting persistent connection to proxy: 52.114.75.24:5061 #012(N 6891747) SIPAppMngr::GetControlIPAddress - Near NAT translation found for SIP Interface 2. Translated IP Address 82.185.88.164:5061 #012(N 6891748) States: (#949)AcSIPDialog[Allocated] #012(N 6891749) AcSIPDialog(#949): Handling DIALOG_INIT_REQ in state DialogIdle #012(N 6891750) States: (#949)AcSIPDialog[DialogIdle->DialogInitiated] #012(N 6891751) AcSIPDialog(#949): Handling GENERAL_REQ in state DialogInitiated #012(N 6891752) ---- Outgoing SIP Message to 52.114.75.24:5061 from SIPInterface #2 (Teams) TLS TO(#134) SocketID(200) ---- #012 [Time:19-12@12:44:56.587] [Sat, 19 Dec 2020 10:45:08 GMT] ERROR failed parsing Incoming SIP <133>[S=1718478] [SID=b9027c:24:198173] (N 6891753) ---- Incoming SIP Message from 52.114.75.24:5061 to SIPInterface #2 (Teams) TLS TO(#134) SocketID(200) ---- #012SIP/2.0 200 OK #012FROM: <sip:10.160.111.51>;tag=1c808889852 #012TO: <sip:10.160.111.51> #012CSEQ: 1 OPTIONS #012CALL-ID: 143672392819122020124456@sbc.llspa.it #012VIA: SIP/2.0/TLS sbc.llspa.it:5061;branch=z9hG4bKac1078538236 #012CONTENT-LENGTH: 0 #012ALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY #012SERVER: Microsoft.PSTNHub.SIPProxy v.2020.12.7.3 i.EUWE.9 #012 #012 #012(N 6891754) AcSIPDialog(#949): Handling 200 OK in state DialogInitiated #012(N 6891755) States: (#949)AcSIPDialog[DialogInitiated->DialogConnected] #012(N 6891756) SIPServersMngr::UpdateSetWithOnlineServer - Server 52.114.75.24 already on working servers list #012(N 6891757) AcSIPDialog(#949): Handling DIALOG_DISCONNECT_REQ in state DialogConnected #012(N 6891758) States: (#949)AcSIPDialog[DialogConnected->DialogDisconnected] #012(N 6891759) SIPAppMngr::FreeDialogAPI - (#461) #012(N 6891760) States: (#949)AcSIPDialog[Deallocated] #012 (#949)AcSIPDialog[DialogDisconnected->DialogIdle] #012 [Time:19-12@12:44:56.618] [Sat, 19 Dec 2020 10:45:08 GMT] ERROR failed parsing Incoming SIP <133>[S=1718481] [SID=b9027c:24:198174] (N 6891780) SBC_ADMIT_DIALOGS_EV: (#227)SBCRoutesIterator -> (#0)SBCAdmissionControlMngr #012(N 6891781) CAC: Add SBC Incoming Other, IPG 1 (Teams): 1, SRD 0 (DefaultSRD): 1, SipIF 2 (Teams): 1 #012(N 6891782) CAC: Add SBC Outgoing Other, IPG 1 (Teams): 1, SRD 0 (DefaultSRD): 1, SipIF 2 (Teams): 1 #012(N 6891783) (#227)Route found (0), Route by Address, IP Group 1 -> 1 (Teams -> Teams), Url:internal:0; #012(N 6891784) ---- Incoming SIP Message from 52.114.75.24:6912 to SIPInterface #2 (Teams) TLS TO(#129) SocketID(201) ---- #012OPTIONS sip:sbc.llspa.it:5061;transport=tls SIP/2.0 #012FROM: <sip:sip-du-a-eu.pstnhub.microsoft.com:5061>;tag=05132b06-9198-46ec-b9a3-2e9df77cc592 #012TO: <sip:10.160.111.51> #012CSEQ: 1 OPTIONS #012CALL-ID: 16fc0817-abbe-4b7c-93ab-33dae8af89a7 #012MAX-FORWARDS: 70 #012VIA: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK8bef4e8 #012CONTACT: <sip:sip-du-a-eu.pstnhub.microsoft.com:5061> #012CONTENT-LENGTH: 0 #012USER-AGENT: Microsoft.PSTNHub.SIPProxy v.2020.12.7.3 i.EUWE.9 #012ALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY #012 #012 #012(N 6891785) States: (#936)AcSIPDialog[Allocated] #012(N 6891786) SBCNewCallData: (#20)AcSBCDialogAPI -> (#20)SIPSBCDialogLeg #012 [Time:19-12@12:44:56.619] [STDOUT] { "payload": "SIP/2.0 200 OK \r\nVia: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK8bef4e8 \r\nFrom: <sip:sip-du-a-eu.pstnhub.microsoft.com:5061>;tag=05132b06-9198-46ec-b9a3-2e9df77cc592 \r\nTo: <sip:10.160.111.51>;tag=1c823013751 \r\nCall-ID: 16fc0817-abbe-4b7c-93ab-33dae8af89a7 \r\nCSeq: 1 OPTIONS \r\nContact: <sip:sbc.llspa.it:5061;transport=tls> \r\nServer: LLSBC Laboratorio/v.7.20A.260.012 \r\nContent-Length: 0 SIP/2.0 200 OK \r\nVia: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK8bef4e8 \r\nFrom: <sip:sip-du-a-eu.pstnhub.microsoft.com:5061>;tag=05132b06-9198-46ec-b9a3-2e9df77cc592 \r\nTo: <sip:10.160.111.51>;tag=1c823013751 \r\nCall-ID: 16fc0817-abbe-4b7c-93ab-33dae8af89a7 \r\nCSeq: 1 OPTIONS \r\nContact: <sip:sbc.llspa.it:5061;transport=tls> \r\nServer: LLSBC Laboratorio/v.7.20A.260.012 \r\nContent-Length: 0 \r\n\r\n", "rcinfo": { "type": "HEP", "version": 3, "payload_type": 1, "ip_family": 2, "protocol": 6, "proto_type": 1, "correlation_id": "16fc0817-abbe-4b7c-93ab-33dae8af89a7", "srcIp": "127.0.0.1", "srcPort": 5060, "dstIp": "52.114.75.24", "dstPort": "6912", "time_sec": 1608374708046, "time_usec": 0 } } [Sat, 19 Dec 2020 10:45:11 GMT] ERROR failed parsing Incoming SIP <133>[S=1718491] [SID=b9027c:24:198171] (N 6891824) ---- Incoming SIP Message from 10.160.21.200:5060 to SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012SIP/2.0 180 Ringing #012Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE #012Contact: sip:10.160.21.200 #012User-Agent: OmniPCX Enterprise R12.1 m2.300.29.a #012Content-Type: application/sdp #012To: <sip:00522385011@10.160.21.200;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d #012From: "Antonio Spirandelli" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=1c414268318 #012Call-ID: 111765558019122020124454@10.160.21.20 #012CSeq: 1 INVITE #012Via: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac435960060 #012Content-Length: 240 #012 #012v=0 #012o=OXE 1608374695 1608374695 IN IP4 10.160.21.200 #012s=abs #012c=IN IP4 10.160.20.30 #012t=0 0 #012m=audio 32600 RTP/AVP 18 101 #012a=sendrecv #012a=rtpmap:18 G729/8000 #012a=fmtp:18 annexb=no #012a=ptime:20 #012a=maxptime:40 #012a=rtpmap:101 telephone-event/8000 #012 #012(N 6891825) AcSIPCall(#942): Handling 180 in state Proceeding #012(N 6891826) SBCAlertData: (#86)AcSBCCallAPI -> (#86)SIPSBCCallLeg #012(N 6891827) States: (#86)SBCOfferAnswerMngr[Offering->Completed] #012 [Time:19-12@12:45:00.299] [Sat, 19 Dec 2020 10:45:11 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718493] [SID=b9027c:24:198171] (N 6891839) #6 OPEN_STREAM (Remote:10.160.20.30:32600, Local:10.160.21.20:7068, Mode:RxOnly, Coder:g72920, Payload:18, RemoteRTCPPort:32601, BrokenTimeout: 10, Red:104, DTMF:gwRFC2833RelayDTMF, Rx:101, Tx:101, FaxTran: 0) #012(N 6891840) (#20)ChannelConfiguration: [Voice], ConfTypeUpdate = OpenAndActivate #012(N 6891841) (#6)SBCCall: SetMsa CID 6 with 1 MSAs: 2 0 0 0 0 #012(N 6891842) (#12)StartSBCSession: CidA: 6(1), Mediation: None, ConnectionType: None, SrcDir: Unknown, DstDir: Unknown #012(N 6891843) AcSIPCall(#945): Handling ALERT_REQ in state Invited #012(N 6891844) ---- Outgoing SIP Message to 52.114.75.24:9024 from SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012 [Time:19-12@12:45:00.299] [Sat, 19 Dec 2020 10:45:12 GMT] ERROR failed parsing Incoming SIP <133>[S=1718499] [SID=b9027c:24:198171] (N 6891849) ---- Incoming SIP Message from 10.160.21.200:5060 to SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012SIP/2.0 200 OK #012Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE #012Contact: sip:10.160.21.200 #012Supported: replaces,timer,path,100rel #012User-Agent: OmniPCX Enterprise R12.1 m2.300.29.a #012Session-Expires: 1800;refresher=uas #012Content-Type: application/sdp #012To: <sip:00522385011@10.160.21.200;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d #012From: "Antonio Spirandelli" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=1c414268318 #012Call-ID: 111765558019122020124454@10.160.21.20 #012CSeq: 1 INVITE #012Via: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac435960060 #012Content-Length: 240 #012 #012v=0 #012o=OXE 1608374695 1608374695 IN IP4 10.160.21.200 #012s=abs #012c=IN IP4 10.160.20.30 #012t=0 0 #012m=audio 32600 RTP/AVP 18 101 #012a=sendrecv #012a=rtpmap:18 G729/8000 #012a=fmtp:18 annexb=no #012a=ptime:20 #012a=maxptime:40 #012a=rtpmap:101 telephone-event/8000 #012 #012(N 6891850) AcSIPCall(#942): Handling 200 OK in state Proceeding #012(N 6891851) TU(#942) SIPSessionTimer::SaveSTParams - remote session is enlarging my expires 180 to 1800 #012(N 6891852) States: (#942)AcSIPCall[Proceeding->RemoteAccepted] #012 [Time:19-12@12:45:00.709] [Sat, 19 Dec 2020 10:45:12 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718503] [SID=b9027c:24:198171] (N 6891888) #6 OPEN_STREAM (Remote:10.160.20.30:32600, Local:10.160.21.20:7068, Mode:TxRx, Coder:g72920, Payload:18, RemoteRTCPPort:32601, BrokenTimeout: 100, Red:104, DTMF:gwRFC2833RelayDTMF, Rx:101, Tx:101, FaxTran: 0) #012(N 6891889) (#20)ChannelConfiguration: [Voice], ConfTypeUpdate = OpenAndActivate #012(N 6891890) (#6)SBCCall: SetMsa CID 6 with 1 MSAs: 2 0 0 0 0 #012(N 6891891) (#11)StartSBCSession: CidA: 5(1), CidB: 6(2), Mediation: RTP, ConnectionType: FD, SrcDir: FromNet, DstDir: ToNet #012(N 6891892) States: (#12)StreamsConnector[Deallocated] #012(N 6891893) AcSIPCall(#945): Handling CONNECT_REQ in state Invited #012(N 6891894) ---- Outgoing SIP Message to 52.114.75.24:9024 from SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012 [Time:19-12@12:45:00.710] [Sat, 19 Dec 2020 10:45:12 GMT] ERROR failed parsing Incoming SIP <133>[S=1718515] [SID=b9027c:24:198171] (N 6891909) ---- Incoming SIP Message from 52.114.75.24:9024 to SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012ACK sip:sbc.llspa.it:5061;transport=tls SIP/2.0 #012FROM: Antonio Spirandelli<sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=51f0c299a9f8494eaf55fddf3590afd1 #012TO: <sip:+390522385011@sbc.llspa.it:5061>;user=phone;tag=633844cd2a52b012e6f0b21c4e950d1d #012CSEQ: 1 ACK #012CALL-ID: f8e538e4bf535025bfdd8c99080cd2ff #012MAX-FORWARDS: 70 #012VIA: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK8cde9665 #012CONTACT: <sip:api-du-c-euwe.pstnhub.microsoft.com:443;x-i=7924f078-9d30-4ac2-a95f-eeb3b8ea8c26;x-c=f8e538e4bf535025bfdd8c99080cd2ff/d/8/28e93822c4c1493f90f7be836cde3c1e> #012CONTENT-LENGTH: 0 #012USER-AGENT: Microsoft.PSTNHub.SIPProxy v.2020.12.7.3 i.EUWE.8 #012ALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY #012 #012 #012(N 6891910) AcSIPCall(#945): Handling ACK in state LocalAccepted #012(N 6891911) States: (#945)AcSIPCall[LocalAccepted->Connected] #012(N 6891912) SBCAckData: (#32)AcSBCCallAPI -> (#32)SIPSBCCallLeg #012(N 6891913) SIPSBCConnectAckEvent: (#32)SIPSBCCallLeg -> (#7)SBCCall #012(N 6891914) (#7)Required detectors Unset #012 [Time:19-12@12:45:00.741] [Sat, 19 Dec 2020 10:45:12 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718516] [SID=b9027c:24:198171] (N 6891915) SIPAppMngr::GetControlIPAddress - Near NAT translation found for SIP Interface 2. Translated IP Address 82.185.88.164:5061 #012(N 6891916) States: (#7)SBCCall[Connected->ConnectAcknowledged] #012(N 6891917) SIPSBCConnectAckEvent: (#7)SBCCall -> (#51)SBCEndPoint #012 -> (#25)SBCController #012 -> (#50)SBCEndPoint #012 -> (#6)SBCCall #012(N 6891918) (#6)MRA::For coder g729 Not allowed Control Detection #012(N 6891919) States: (#6)SBCCall[Connected->ConnectAcknowledged] #012(N 6891920) SIPSBCConnectAckEvent: (#6)SBCCall -> (#86)SIPSBCCallLeg #012(N 6891921) AcSIPCall(#942): Handling ACK_REQ in state RemoteAccepted #012(N 6891922) States: (#942)AcSIPCall[RemoteAccepted->Connected] #012(N 6891923) ---- Outgoing SIP Message to 10.160.21.200:5060 from SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012 [Time:19-12@12:45:00.742] [Sat, 19 Dec 2020 10:45:13 GMT] ERROR failed parsing Incoming SIP <133>[S=1718543] [SID=b9027c:24:198171] (N 6891937) ---- Incoming SIP Message from 52.114.75.24:9024 to SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012 [Time:19-12@12:45:02.514] [Sat, 19 Dec 2020 10:45:13 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718547] [SID=b9027c:24:198171] (N 6891950) ConnectionData::CalculateResourcesForRTPForwarding Leading:NONE Opposite:NONE MediationLevel:RTP #012(N 6891951) ConnectionData::CalculateResourcesForSRTP Leading:NONE Opposite:SRTP MediationLevel:RTP #012(N 6891952) SBCSDPSecurityFeature(index = 0, type = AUDIO, tag = -100) - new state: Idle #012(N 6891953) SBCSDPCodersFeature::PerformCodersPreference - Put in order audio coders according to allowed coders #012(N 6891954) SBCSDPSecurityFeature(index = 1, type = AUDIO, tag = -100) - new state: Offer_Extended #012(N 6891955) AcSIPCall(#942): Handling REINVITE_REQ in state Connected #012(N 6891956) UdpRtxMngr::Transmit 2 INVITE Rtx Left: 6 Dest: 10.160.21.200:5060, TU: AcSIPCall(#942) #012(N 6891957) ---- Outgoing SIP Message to 10.160.21.200:5060 from SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012 [Time:19-12@12:45:02.515] [Sat, 19 Dec 2020 10:45:13 GMT] ERROR failed parsing Incoming SIP <133>[S=1718549] [SID=b9027c:24:198171] (N 6891958) ---- Incoming SIP Message from 10.160.21.200:5060 to SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012SIP/2.0 100 Trying #012To: <sip:00522385011@10.160.21.200;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d #012From: "Antonio Spirandelli" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=1c414268318 #012Call-ID: 111765558019122020124454@10.160.21.20 #012CSeq: 2 INVITE #012Via: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac1159815029 #012Content-Length: 0 #012 #012 #012(N 6891959) UdpRtxMngr::Remove 2 INVITE, TU: AcSIPCall(#942) #012(N 6891960) AcSIPCall(#942): Handling 100 in state Connected #012(N 6891961) ---- Incoming SIP Message from 10.160.21.200:5060 to SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012 [Time:19-12@12:45:02.531] [Sat, 19 Dec 2020 10:45:13 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718553] [SID=b9027c:24:198171] (N 6891986) (#19)RTS: CID #5:Channel will be open WITHOUT DSP, Mediation: [HeaderNorm ] #012(N 6891987) #5 OPEN_STREAM (Remote:0.0.0.0:0, Local:10.160.111.51:8068, Mode:TxRx, Coder:g72920, Payload:18, RemoteRTCPPort:0, BrokenTimeout: 100, Red:104, DTMF:gwRFC2833RelayDTMF, Rx:101, Tx:101, FaxTran: 0) #012(N 6891988) (#19)ChannelConfiguration: [Voice], ConfTypeUpdate = OpenAndActivate #012(N 6891989) (#7)SBCCall: SetMsa CID 5 with 1 MSAs: 1 0 0 0 0 #012(N 6891990) (#10)StartSBCSession: CidA: 6(3), CidB: 5(2), Mediation: RTP, ConnectionType: FD, SrcDir: FromNet, DstDir: ToNet #012(N 6891991) States: (#11)StreamsConnector[Deallocated] #012(N 6891992) AcSIPCall(#945): Handling REINVITE_RESPONSE in state Connected #012(N 6891993) ---- Outgoing SIP Message to 52.114.75.24:9024 from SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012 [Time:19-12@12:45:02.532] [Sat, 19 Dec 2020 10:45:13 GMT] ERROR failed parsing Incoming SIP <133>[S=1718571] [SID=b9027c:24:198171] (N 6892016) ---- Incoming SIP Message from 52.114.75.24:9024 to SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012ACK sip:sbc.llspa.it:5061;transport=tls SIP/2.0 #012FROM: Antonio Spirandelli<sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=51f0c299a9f8494eaf55fddf3590afd1 #012TO: <sip:+390522385011@sbc.llspa.it:5061>;user=phone;tag=633844cd2a52b012e6f0b21c4e950d1d #012CSEQ: 2 ACK #012CALL-ID: f8e538e4bf535025bfdd8c99080cd2ff #012MAX-FORWARDS: 70 #012VIA: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK38883577 #012CONTACT: <sip:api-du-c-euwe.pstnhub.microsoft.com:443;x-i=7924f078-9d30-4ac2-a95f-eeb3b8ea8c26;x-c=f8e538e4bf535025bfdd8c99080cd2ff/d/8/28e93822c4c1493f90f7be836cde3c1e> #012CONTENT-LENGTH: 0 #012USER-AGENT: Microsoft.PSTNHub.SIPProxy v.2020.12.7.3 i.EUWE.8 #012ALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY #012 #012 #012(N 6892017) AcSIPCall(#945): Handling ACK in state Connected #012(N 6892018) SBCReinviteAckData: (#32)AcSBCCallAPI -> (#32)SIPSBCCallLeg #012(N 6892019) SIPSBCReinviteAckEvent: (#32)SIPSBCCallLeg -> (#7)SBCCall #012 -> (#51)SBCEndPoint #012 -> (#25)SBCController #012 -> (#50)SBCEndPoint #012 -> (#6)SBCCall #012 -> (#86)SIPSBCCallLeg #012(N 6892020) AcSIPCall(#942): Handling ACK_REQ in state Connected #012 [Time:19-12@12:45:02.563] [STDOUT] { "payload": "ACK sip:10.160.21.200 SIP/2.0 \r\nVia: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac1951884303 \r\nMax-Forwards: 69 \r\nFrom: \"Antonio Spirandelli\" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=1c414268318 \r\nTo: <sip:00522385011@10.160.21.200;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d \r\nCall-ID: 111765558019122020124454@10.160.21.20 \r\nCSeq: 2 ACK \r\nContact: <sip:10.160.21.20:5062;x-i=7924f078-9d30-4ac2-a95f-eeb3b8ea8c26;x-c=f8e538e4bf535025bfdd8c99080cd2ff/d/8/28e93822c4c1493f90f7be836cde3c1e> \r\nALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY \r\nUser-Agent: LLSBC Laboratorio/v.7.20A.260.012 \r\nContent-Length: 0 ACK sip:10.160.21.200 SIP/2.0 \r\nVia: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac1951884303 \r\nMax-Forwards: 69 \r\nFrom: \"Antonio Spirandelli\" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=1c414268318 \r\nTo: <sip:00522385011@10.160.21.200;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d \r\nCall-ID: 111765558019122020124454@10.160.21.20 \r\nCSeq: 2 ACK \r\nContact: <sip:10.160.21.20:5062;x-i=7924f078-9d30-4ac2-a95f-eeb3b8ea8c26;x-c=f8e538e4bf535025bfdd8c99080cd2ff/d/8/28e93822c4c1493f90f7be836cde3c1e> \r\nALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY \r\nUser-Agent: LLSBC Laboratorio/v.7.20A.260.012 \r\nContent-Length: 0 \r\n\r\n", "rcinfo": { "type": "HEP", "version": 3, "payload_type": 1, "ip_family": 2, "protocol": 17, "proto_type": 1, "correlation_id": "111765558019122020124454@10.160.21.20", "srcIp": "127.0.0.1", "srcPort": 5060, "dstIp": "10.160.21.200", "dstPort": "5060", "time_sec": 1608374713980, "time_usec": 0 } } [Sat, 19 Dec 2020 10:45:19 GMT] ERROR failed parsing Incoming SIP <133>[S=1718575] [SID=b9027c:24:198171] (N 6892026) ---- Incoming SIP Message from 52.114.75.24:9024 to SIPInterface #2 (Teams) TLS TO(#138) SocketID(204) ---- #012BYE sip:sbc.llspa.it:5061;transport=tls SIP/2.0 #012FROM: Antonio Spirandelli<sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=51f0c299a9f8494eaf55fddf3590afd1 #012TO: <sip:+390522385011@sbc.llspa.it:5061>;user=phone;tag=633844cd2a52b012e6f0b21c4e950d1d #012CSEQ: 4 BYE #012CALL-ID: f8e538e4bf535025bfdd8c99080cd2ff #012MAX-FORWARDS: 70 #012VIA: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK7df8648d #012REASON: Q.850;cause=16;text="7924f078-9d30-4ac2-a95f-eeb3b8ea8c26;CallEndReasonLocalUserInitiated" #012CONTACT: <sip:api-du-c-euwe.pstnhub.microsoft.com:443;x-i=7924f078-9d30-4ac2-a95f-eeb3b8ea8c26;x-c=f8e538e4bf535025bfdd8c99080cd2ff/d/8/28e93822c4c1493f90f7be836cde3c1e> #012CONTENT-LENGTH: 0 #012USER-AGENT: Microsoft.PSTNHub.SIPProxy v.2020.12.7.3 i.EUWE.8 #012ALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY #012P-ASSERTED-IDENTITY: <tel:+390522375550>,<sip:antonio.spirandelli@llspa.it> #012PRIVACY: id #012 #012 #012(N 6892027) ServerTransaction(#1251)::SetResponseAddr - Setting ReceivedFromIP as response IP due to configuration #012(N 6892028) AcSIPCall(#945): Handling BYE in state Connected #012 [Time:19-12@12:45:08.107] [Sat, 19 Dec 2020 10:45:19 GMT] ERROR failed parsing Outgoing SIP <133>[S=1718576] [SID=b9027c:24:198171] (N 6892029) States: (#945)AcSIPCall[Connected->Disconnected] #012(N 6892030) SBCDisconnectData: (#32)AcSBCCallAPI -> (#32)SIPSBCCallLeg #012(N 6892031) RELEASE_EV: (#32)SIPSBCCallLeg -> (#7)SBCCall[ConnectAcknowledged->Disconnecting] #012 -> (#51)SBCEndPoint[Session->Releasing] #012 -> (#25)SBCController[Active->Disconnecting] #012 -> (#50)SBCEndPoint[Session->Releasing] #012 -> (#6)SBCCall[ConnectAcknowledged->Disconnecting] #012 -> (#86)SIPSBCCallLeg #012(N 6892032) AcSIPCall(#942): Handling DISCONNECT_REQ in state Connected #012(N 6892033) UdpRtxMngr::Transmit 3 BYE Rtx Left: 6 Dest: 10.160.21.200:5060, TU: AcSIPCall(#942) #012(N 6892034) ---- Outgoing SIP Message to 10.160.21.200:5060 from SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012 [Time:19-12@12:45:08.107] [Sat, 19 Dec 2020 10:45:19 GMT] ERROR failed parsing Incoming SIP <133>[S=1718578] [SID=b9027c:24:198171] (N 6892036) ---- Incoming SIP Message from 10.160.21.200:5060 to SIPInterface #1 (Oxe-Cloud) UDP TO(#1) ---- #012SIP/2.0 200 OK #012Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE #012Supported: replaces,timer,path,100rel #012User-Agent: OmniPCX Enterprise R12.1 m2.300.29.a #012To: <sip:00522385011@10.160.21.200;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d #012From: "Antonio Spirandelli" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=1c414268318 #012Call-ID: 111765558019122020124454@10.160.21.20 #012CSeq: 3 BYE #012Via: SIP/2.0/UDP 10.160.21.20:5062;branch=z9hG4bKac2131008762 #012Content-Length: 0 #012 #012 #012(N 6892037) UdpRtxMngr::Remove 3 BYE, TU: AcSIPCall(#942) #012(N 6892038) AcSIPCall(#942): Handling 200 OK in state Disconnected #012(N 6892039) States: (#942)AcSIPCall[Disconnected->Idle] #012 (#942)AcSIPCall[Deallocated] #012(N 6892040) SBCDisconnectAckData: (#86)AcSBCCallAPI -> (#86)SIPSBCCallLeg #012(N 6892041) RELEASE_ACK_EV: (#86)SIPSBCCallLeg -> (#6)SBCCall[Disconnecting->Disconnected] #012(N 6892042) (#10)StopSBCSession: DisconnectAndCloseA, CidA 6(4) CidB 5(3) #012(N 6892043) States: (#10)StreamsConnector[Deallocated] #012 [Time:19-12@12:45:08.168] [STDOUT] { "payload": "SIP/2.0 200 OK \r\nVia: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK7df8648d \r\nFrom: \"Antonio Spirandelli\" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=51f0c299a9f8494eaf55fddf3590afd1 \r\nTo: <sip:+390522385011@sbc.llspa.it:5061;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d \r\nCall-ID: f8e538e4bf535025bfdd8c99080cd2ff \r\nCSeq: 4 BYE \r\nSupported: 100rel,timer,replaces,path \r\nAllow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE \r\nServer: LLSBC Laboratorio/v.7.20A.260.012 \r\nContent-Length: 0 SIP/2.0 200 OK \r\nVia: SIP/2.0/TLS 52.114.75.24:5061;branch=z9hG4bK7df8648d \r\nFrom: \"Antonio Spirandelli\" <sip:+390522375550@sip.pstnhub.microsoft.com:5061;user=phone>;tag=51f0c299a9f8494eaf55fddf3590afd1 \r\nTo: <sip:+390522385011@sbc.llspa.it:5061;user=phone>;tag=633844cd2a52b012e6f0b21c4e950d1d \r\nCall-ID: f8e538e4bf535025bfdd8c99080cd2ff \r\nCSeq: 4 BYE \r\nSupported: 100rel,timer,replaces,path \r\nAllow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE \r\nServer: LLSBC Laboratorio/v.7.20A.260.012 \r\nContent-Length: 0 \r\n\r\n", "rcinfo": { "type": "HEP", "version": 3, "payload_type": 1, "ip_family": 2, "protocol": 6, "proto_type": 1, "correlation_id": "f8e538e4bf535025bfdd8c99080cd2ff", "srcIp": "127.0.0.1", "srcPort": 5060, "dstIp": "52.114.75.24", "dstPort": "9024", "time_sec": 1608374719587, "time_usec": 0 } }

Schermata 2020-12-19 alle 11 51 48

Schermata 2020-12-19 alle 11 51 59

Schermata 2020-12-19 alle 11 52 07

@lmangani

This comment has been minimized.

Sign in to view
@lmangani

This comment has been minimized.

Sign in to view
@spady7
Copy link
Author

spady7 commented Dec 19, 2020

Ok, email sent to support@sipcapture.org

regards

@lmangani
Copy link
Member

lmangani commented Dec 19, 2020 •
edited
Loading

We need the logs from syslog. not file, or the parsing will be entirely different. Here's the recipe to do so:

input {
  udp {
    host => 0.0.0.0
    port => 514
    type => syslog
  }
}

output {
  stdout {}
  file {
    path => "/tmp/audiocodes.json"
    serializer => "json_logstash"
  }
}

Run the above, perform a full call, and then send us the audiocodes.json file - we'll be able to use it to fix the parser :)

@lmangani
Copy link
Member

By the way question for anyone using those logs - if ANY of those events reveals the IP:PORT of the realms used, please suggest so ;)

@lmangani
Copy link
Member

@spady7 the latest JSON file seems perfect, will take a look once possible and update you here

@lmangani

This comment has been minimized.

Sign in to view
@spady7
Copy link
Author

spady7 commented Dec 19, 2020

Hi, I checked the manuals and here are the only information about how the syslog message is structured. As I told you earlier the whole SIP call is marked with the value "SID". In fact, if I analyze the syslog trace with the tool provided by Audiocodes and I filter the SID value, I get the entire SIP call.
Syslog Format.pdf

@lmangani
Copy link
Member

We can try use that as the correlation ID but it seems VERY ephemeral and would overlap often. Not good in general.
Have you tried the last version? I see some issues with reassembling still but it should produce most messages.

@spady7

This comment has been minimized.

Sign in to view
@lmangani

This comment has been minimized.

Sign in to view
@lmangani

This comment has been minimized.

Sign in to view
@lmangani
Copy link
Member

lmangani commented Dec 19, 2020 •
edited
Loading

@spady7 i think we got it working. Your next test with the latest version should be more interesting ;)

image

@sipcapture sipcapture deleted a comment from spady7 Dec 19, 2020
@lmangani
Copy link
Member

lmangani commented Dec 19, 2020 •
edited
Loading

Audiocodes works i bit complicated way. It use 'entities' (like ATA) and to this entity is associated a sip interface and to that sip interface is associated a network interface. This is way ( i suppose) we cannot see directly IP:PORT on syslog. But, we could think to put inside 'pastash_audiocodes.conf' a "MAPPING" of that name to an IP:PORT (I know it because i ve configured on Audiocodes sbc). Does should work? The name of the "trunk" or whatever seems to be inside the parenthesis, ATA in this example below possibly?

Could you provide some examples of this config? I'll prepare some mapping array to hold it.

@lmangani
Copy link
Member

@spady7 there's a good chance you will see RTP MOS reports as well :) Curious to hear what your test results will be

@spady7
Copy link
Author

spady7 commented Dec 20, 2020 via email

@spady7
Copy link
Author

spady7 commented Dec 20, 2020 via email

@spady7
Copy link
Author

spady7 commented Dec 20, 2020 via email

@lmangani
Copy link
Member

Yeah, just always pull the latest available, they get pushed as bugs get fixed.
By default it will only try reassemble SIP out, I've added a few options documented here: https://github.com/sipcapture/paStash/blob/next/plugins/filters/app_audiocodes/app_audiocodes.md

@lmangani
Copy link
Member

Try using this config for IP autodetection (very sketchy logs for TLS, only you can tell if it works)

filter {
  app_audiocodes {
    autolocal => true
    qos => true
  }
}

@lmangani
Copy link
Member

All seems to work! If there are other Audiocodes lurkers watching this thread and willing to try, crawl out, we'll help :)

@lmangani
Copy link
Member

Documented here: https://github.com/sipcapture/paStash/wiki/Example:-AUDIOCODES-Syslog

Good luck @spady7! In case of issues or new discoveries, please open a new issue for clean tracking!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
enhancement help wanted
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@lmangani @adubovikov @spady7