vicidial.org

Hi.

Can you explain me how Vicidial recognize who hangup the call: agent or customer? Information about this is in User Stats.

I have a problem with one of my customers: agents claim that conversation is disconnected in the middle of speaking. They got Costumer Hangup information. In User Stats there is an info that Caller hang up the call.
But when we call the customer again he/she claim that he/she did not hang up the call.

VoIP provider also claim that hang up of call is started from Vicidial.

Can I check which party hang up the call from asterisk log?

vicidial.php version and build?

Have you looked in the Asterisk CLI output for specific examples of the call and traced the channel to it's last entries?

As for carriers, they never accept responsibility until forced to by facts

If this becomes a chronic problem, you might want to consider installing a Utility like HOMER(it's free and open source), which allows full SIP message tracing, we have used it extensively to help diagnose problems like this.

Version: 2.12b0.5
SVN Version: 2580
DB Schema Version: 1465

I have made test calls (Manual Dial from Agent Panel to my cell phone):

1. Agent finish the call:

Code: Select all

[Mar 28 12:33:21] VERBOSE[9982] pbx.c: [Mar 28 12:33:21]     -- Executing [8600051@default:1] MeetMe("Local/8600051@default-00000000;2", "8600051,F") in new stack
[Mar 28 12:33:21] VERBOSE[9981] pbx.c: [Mar 28 12:33:21]        > Channel Local/8600051@default-00000000;1 was answered.
[Mar 28 12:33:21] VERBOSE[9983] pbx.c: [Mar 28 12:33:21]     -- Executing [1600600600@default:1] AGI("Local/8600051@default-00000000;1", "agi://127.0.0.1:4577/call_log") in new stack
[Mar 28 12:33:21] VERBOSE[9983] res_agi.c: [Mar 28 12:33:21]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=TESTOWA))
[Mar 28 12:33:22] VERBOSE[9983] res_agi.c: [Mar 28 12:33:22]     -- <Local/8600051@default-00000000;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Mar 28 12:33:22] VERBOSE[9983] pbx.c: [Mar 28 12:33:22]     -- Executing [1600600600@default:2] Dial("Local/8600051@default-00000000;1", "SIP/voip1/600600600,,tTor") in new stack
[Mar 28 12:33:22] VERBOSE[9983] netsock2.c: [Mar 28 12:33:22]   == Using SIP RTP CoS mark 5
[Mar 28 12:33:22] VERBOSE[9983] app_dial.c: [Mar 28 12:33:22]     -- Called SIP/voip1/600600600
[Mar 28 12:33:22] VERBOSE[9983] app_dial.c: [Mar 28 12:33:22]     -- SIP/voip1-00000001 is ringing
[Mar 28 12:33:22] VERBOSE[9983] app_dial.c: [Mar 28 12:33:22]     -- SIP/voip1-00000001 is making progress passing it to Local/8600051@default-00000000;1
[Mar 28 12:33:22] VERBOSE[9990] pbx.c: [Mar 28 12:33:22]     -- Executing [58600051@default:1] MeetMe("Local/58600051@default-00000001;2", "8600051,Fmq") in new stack
[Mar 28 12:33:22] VERBOSE[9989] pbx.c: [Mar 28 12:33:22]        > Channel Local/58600051@default-00000001;1 was answered.
[Mar 28 12:33:22] VERBOSE[9991] pbx.c: [Mar 28 12:33:22]     -- Executing [8309@default:1] Answer("Local/58600051@default-00000001;1", "") in new stack
[Mar 28 12:33:22] VERBOSE[9991] pbx.c: [Mar 28 12:33:22]     -- Executing [8309@default:2] Monitor("Local/58600051@default-00000001;1", "wav,20170328-123321_TESTOWA_6666_600600600") in new stack
[Mar 28 12:33:23] VERBOSE[9991] pbx.c: [Mar 28 12:33:23]     -- Executing [8309@default:3] Wait("Local/58600051@default-00000001;1", "3600") in new stack
[Mar 28 12:33:24] VERBOSE[9983] app_dial.c: [Mar 28 12:33:24]     -- SIP/voip1-00000001 is ringing
[Mar 28 12:33:24] VERBOSE[9983] app_dial.c: [Mar 28 12:33:24]     -- SIP/voip1-00000001 is ringing
xxxxxx[Mar 28 12:33:29] VERBOSE[9983] app_dial.c: [Mar 28 12:33:29]     -- SIP/voip1-00000001 answered Local/8600051@default-00000000;1
[Mar 28 12:33:46] VERBOSE[9983] pbx.c: [Mar 28 12:33:46]     -- Executing [h@default:1] AGI("Local/8600051@default-00000000;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----25-----17") in new stack
[Mar 28 12:33:46] VERBOSE[9982] pbx.c: [Mar 28 12:33:46]   == Spawn extension (default, 8600051, 1) exited non-zero on 'Local/8600051@default-00000000;2'
[Mar 28 12:33:46] VERBOSE[9982] pbx.c: [Mar 28 12:33:46]     -- Executing [h@default:1] AGI("Local/8600051@default-00000000;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Mar 28 12:33:46] VERBOSE[9990] pbx.c: [Mar 28 12:33:46]   == Spawn extension (default, 58600051, 1) exited non-zero on 'Local/58600051@default-00000001;2'
[Mar 28 12:33:46] VERBOSE[9990] pbx.c: [Mar 28 12:33:46]     -- Executing [h@default:1] AGI("Local/58600051@default-00000001;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Mar 28 12:33:46] VERBOSE[9982] res_agi.c: [Mar 28 12:33:46]     -- <Local/8600051@default-00000000;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[Mar 28 12:33:46] VERBOSE[9990] res_agi.c: [Mar 28 12:33:46]     -- <Local/58600051@default-00000001;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[Mar 28 12:33:46] VERBOSE[9991] pbx.c: [Mar 28 12:33:46]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600051@default-00000001;1'
[Mar 28 12:33:46] VERBOSE[9991] pbx.c: [Mar 28 12:33:46]     -- Executing [h@default:1] AGI("Local/58600051@default-00000001;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Mar 28 12:33:46] VERBOSE[9983] res_agi.c: [Mar 28 12:33:46]     -- <Local/8600051@default-00000000;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----25-----17 completed, returning 0
[Mar 28 12:33:46] VERBOSE[9983] pbx.c: [Mar 28 12:33:46]   == Spawn extension (default, 1600600600, 2) exited non-zero on 'Local/8600051@default-00000000;1'
[Mar 28 12:33:46] VERBOSE[9991] res_agi.c: [Mar 28 12:33:46]     -- <Local/58600051@default-00000001;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0

2. Customer finish the call:

Code: Select all

[Mar 28 12:34:43] VERBOSE[10149] pbx.c: [Mar 28 12:34:43]     -- Executing [8600051@default:1] MeetMe("Local/8600051@default-00000002;2", "8600051,F") in new stack
[Mar 28 12:34:43] VERBOSE[10148] pbx.c: [Mar 28 12:34:43]        > Channel Local/8600051@default-00000002;1 was answered.
[Mar 28 12:34:43] VERBOSE[10150] pbx.c: [Mar 28 12:34:43]     -- Executing [1600600600@default:1] AGI("Local/8600051@default-00000002;1", "agi://127.0.0.1:4577/call_log") in new stack
[Mar 28 12:34:43] VERBOSE[10150] res_agi.c: [Mar 28 12:34:43]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=TESTOWA))
[Mar 28 12:34:43] VERBOSE[10150] res_agi.c: [Mar 28 12:34:43]     -- <Local/8600051@default-00000002;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Mar 28 12:34:43] VERBOSE[10150] pbx.c: [Mar 28 12:34:43]     -- Executing [1600600600@default:2] Dial("Local/8600051@default-00000002;1", "SIP/voip1/600600600,,tTor") in new stack
[Mar 28 12:34:43] VERBOSE[10150] netsock2.c: [Mar 28 12:34:43]   == Using SIP RTP CoS mark 5
[Mar 28 12:34:43] VERBOSE[10150] app_dial.c: [Mar 28 12:34:43]     -- Called SIP/voip1/600600600
[Mar 28 12:34:43] VERBOSE[10150] app_dial.c: [Mar 28 12:34:43]     -- SIP/voip1-00000002 is ringing
[Mar 28 12:34:43] VERBOSE[10155] pbx.c: [Mar 28 12:34:43]     -- Executing [58600051@default:1] MeetMe("Local/58600051@default-00000003;2", "8600051,Fmq") in new stack
[Mar 28 12:34:43] VERBOSE[10154] pbx.c: [Mar 28 12:34:43]        > Channel Local/58600051@default-00000003;1 was answered.
[Mar 28 12:34:43] VERBOSE[10156] pbx.c: [Mar 28 12:34:43]     -- Executing [8309@default:1] Answer("Local/58600051@default-00000003;1", "") in new stack
[Mar 28 12:34:43] VERBOSE[10156] pbx.c: [Mar 28 12:34:43]     -- Executing [8309@default:2] Monitor("Local/58600051@default-00000003;1", "wav,20170328-123442_TESTOWA_6666_600600600") in new stack
[Mar 28 12:34:43] VERBOSE[10156] pbx.c: [Mar 28 12:34:43]     -- Executing [8309@default:3] Wait("Local/58600051@default-00000003;1", "3600") in new stack
[Mar 28 12:34:43] VERBOSE[10150] app_dial.c: [Mar 28 12:34:43]     -- SIP/voip1-00000002 is making progress passing it to Local/8600051@default-00000002;1
[Mar 28 12:34:48] VERBOSE[10150] app_dial.c: [Mar 28 12:34:48]     -- SIP/voip1-00000002 is ringing
[Mar 28 12:34:48] VERBOSE[10150] app_dial.c: [Mar 28 12:34:48]     -- SIP/voip1-00000002 is making progress passing it to Local/8600051@default-00000002;1
xxxxxx[Mar 28 12:34:52] VERBOSE[10150] app_dial.c: [Mar 28 12:34:52]     -- SIP/voip1-00000002 answered Local/8600051@default-00000002;1
[Mar 28 12:35:04] VERBOSE[10150] pbx.c: [Mar 28 12:35:04]     -- Executing [h@default:1] AGI("Local/8600051@default-00000002;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----21-----12") in new stack
[Mar 28 12:35:04] VERBOSE[10150] res_agi.c: [Mar 28 12:35:04]     -- <Local/8600051@default-00000002;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----21-----12 completed, returning 0
[Mar 28 12:35:04] VERBOSE[10150] pbx.c: [Mar 28 12:35:04]   == Spawn extension (default, 1600600600, 2) exited non-zero on 'Local/8600051@default-00000002;1'
[Mar 28 12:35:04] VERBOSE[10149] pbx.c: [Mar 28 12:35:04]   == Spawn extension (default, 8600051, 1) exited non-zero on 'Local/8600051@default-00000002;2'
[Mar 28 12:35:04] VERBOSE[10149] pbx.c: [Mar 28 12:35:04]     -- Executing [h@default:1] AGI("Local/8600051@default-00000002;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Mar 28 12:35:04] VERBOSE[10149] res_agi.c: [Mar 28 12:35:04]     -- <Local/8600051@default-00000002;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[Mar 28 12:35:10] VERBOSE[10155] pbx.c: [Mar 28 12:35:10]   == Spawn extension (default, 58600051, 1) exited non-zero on 'Local/58600051@default-00000003;2'
[Mar 28 12:35:10] VERBOSE[10155] pbx.c: [Mar 28 12:35:10]     -- Executing [h@default:1] AGI("Local/58600051@default-00000003;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Mar 28 12:35:10] VERBOSE[10155] res_agi.c: [Mar 28 12:35:10]     -- <Local/58600051@default-00000003;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[Mar 28 12:35:10] VERBOSE[10156] pbx.c: [Mar 28 12:35:10]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600051@default-00000003;1'
[Mar 28 12:35:10] VERBOSE[10156] pbx.c: [Mar 28 12:35:10]     -- Executing [h@default:1] AGI("Local/58600051@default-00000003;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Mar 28 12:35:10] VERBOSE[10156] res_agi.c: [Mar 28 12:35:10]     -- <Local/58600051@default-00000003;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0

after xxxxxx tag there are information about call finish. I just don't see the difference

You need to make a sip trace using the command sip set debug on and verify who sent the BYE request. the information is on the from header of the BYE request

example ;
101 HANGUP the call

BYE sip:13052362323@45.32.165.238:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.13:62621;branch=z9hG4bK-524287-1---6950a575d696bb47
Max-Forwards: 70
Contact: <sip:101@192.168.1.13:62621;transport=UDP>
To: <sip:13052362323@45.32.165.238;transport=UDP>;tag=as467448be
From: <sip:101@45.32.165.238;transport=UDP>;tag=607b0105
Call-ID: fxEm4NiMlkSErQdd0rOn2A..
CSeq: 3 BYE
User-Agent: Z 3.15.40006 rv2.8.20
Authorization: Digest username="101",realm="asterisk",nonce="45b13fc8",uri="sip:13052362323@45.32.165.238:5060",response="85b74df16daba2cdf0ea9ffc0501bfcc",algorithm=MD5
Content-Length: 0


13052362323 HANGUP the call

<--- SIP read from UDP:186.149.86.232:61001 --->
BYE sip:101@45.32.165.238:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.15:5060;branch=z9hG4bK329816069
From: <sip:13052362323@186.149.86.232:61001>;tag=237119318
To: <sip:101@45.32.165.238>;tag=as4934dafd
Call-ID: 014e88936a632b9c266216e303f31ac7@45.32.165.238:5060
CSeq: 103 BYE
Contact: <sip:130523623230@192.168.1.15:5060>
Max-Forwards: 30
User-Agent: dble
Content-Length: 0

Thank you. Final question:
Vicidial marks a Call finished by Caller or Agent in User Stats based on BYE request from SIP header or based on some internal times or something?

I just want to know how reliable is this information in User Stats.