Google Voice long delay before ring on outgoing calls

Hi

I have installed a Pbx in a Flash system in a Vmware Server virtual machine.
I used PBX in a Flash 1.7.5.5.4 Purple Edition & The Incredible PBX 1.8 installer.

I am using google voice for incoming and outgoing calls. I have 2 seperate systems the first has 2 Grandstream GPX2000 telephones and the second system is using a Linksys PAP2T SIP Adapter. Both systems have their own Google Voice account. On both systems there is a huge delay when making outgoing calls. After dialing and hitting the pound key on the Grandstream (to start the dialing procces as fast as possible)there is about a 20-30 second delay before you hear any ringing. After that it starts to ring and by the 2nd or third ring the dialed phone will start ringing and the call works properly. I have attached the log of a call below to see if anyone can help figure this out. I have been searching with no luck. Thank you for any help you can give me!

Also after trying to fix this issue my one system it now plays a message after I dial that says “Please wait while I connect your call”

Rob

[2011-03-28 19:19:34] VERBOSE[3660] netsock2.c: == Using SIP RTP TOS bits 184
[2011-03-28 19:19:34] VERBOSE[3660] netsock2.c: == Using SIP RTP CoS mark 5
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] Macro(“SIP/701-00000016”, “user-callerid,SKIPTTL,”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] Set(“SIP/701-00000016”, “AMPUSER=701”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/701-00000016”, “0?report”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/701-00000016”, “1?Set(REALCALLERIDNUM=701)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:4] Set(“SIP/701-00000016”, “AMPUSER=701”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:5] Set(“SIP/701-00000016”, “AMPUSERCIDNAME=701”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:6] GotoIf(“SIP/701-00000016”, “0?report”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:7] Set(“SIP/701-00000016”, “AMPUSERCID=701”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:8] Set(“SIP/701-00000016”, “CALLERID(all)=“701” <701>”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:9] ExecIf(“SIP/701-00000016”, “0?Set(CHANNEL(language)=)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:10] GotoIf(“SIP/701-00000016”, “1?continue”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-user-callerid,s,19)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:19] NoOp(“SIP/701-00000016”, “Using CallerID “701” <701>”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:2] NoOp(“SIP/701-00000016”, “Calling Out Route: Default”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:3] Set(“SIP/701-00000016”, “MOHCLASS=default”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:4] Set(“SIP/701-00000016”, “_NODEST=”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:5] Macro(“SIP/701-00000016”, “record-enable,701,OUT,”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/701-00000016”, “1?check”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-record-enable,s,4)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/701-00000016”, “0?MacroExit()”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:5] GotoIf(“SIP/701-00000016”, “0?Group:OUT”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-record-enable,s,15)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:15] GotoIf(“SIP/701-00000016”, “0?IN”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:16] ExecIf(“SIP/701-00000016”, “1?MacroExit()”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:6] Macro(“SIP/701-00000016”, “dialout-trunk,2,14406530669,”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] Set(“SIP/701-00000016”, “DIAL_TRUNK=2”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:2] GosubIf(“SIP/701-00000016”, “0?sub-pincheck,s,1”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/701-00000016”, “0?disabletrunk,1”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:4] Set(“SIP/701-00000016”, “DIAL_NUMBER=14406530669”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:5] Set(“SIP/701-00000016”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:6] Set(“SIP/701-00000016”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/701-00000016”, “1?nomax”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-dialout-trunk,s,9)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/701-00000016”, “0?skipoutcid”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:10] Set(“SIP/701-00000016”, “DIAL_TRUNK_OPTIONS=”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:11] Macro(“SIP/701-00000016”, “outbound-callerid,2”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/701-00000016”, “0?Set(CALLERPRES()=)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:2] ExecIf(“SIP/701-00000016”, “0?Set(REALCALLERIDNUM=701)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/701-00000016”, “1?normcid”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-outbound-callerid,s,6)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:6] Set(“SIP/701-00000016”, “USEROUTCID=”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:7] Set(“SIP/701-00000016”, “EMERGENCYCID=”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:8] Set(“SIP/701-00000016”, “TRUNKOUTCID=”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/701-00000016”, “1?trunkcid”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-outbound-callerid,s,12)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:12] ExecIf(“SIP/701-00000016”, “0?Set(CALLERID(all)=)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:13] ExecIf(“SIP/701-00000016”, “0?Set(CALLERID(all)=)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:14] ExecIf(“SIP/701-00000016”, “0?Set(CALLERID(all)=)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:15] ExecIf(“SIP/701-00000016”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:12] GosubIf(“SIP/701-00000016”, “0?sub-flp-2,s,1”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:13] Set(“SIP/701-00000016”, “OUTNUM=14406530669”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:14] Set(“SIP/701-00000016”, “custom=AMP”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:15] ExecIf(“SIP/701-00000016”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:16] Macro(“SIP/701-00000016”, “dialout-trunk-predial-hook,”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] MacroExit(“SIP/701-00000016”, “”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:17] GotoIf(“SIP/701-00000016”, “0?bypass,1”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:18] GotoIf(“SIP/701-00000016”, “1?customtrunk”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-dialout-trunk,s,22)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:22] Set(“SIP/701-00000016”, “pre_num=AMP:local/”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:23] Set(“SIP/701-00000016”, “the_num=OUTNUM”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:24] Set(“SIP/701-00000016”, “[email protected]”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:25] GotoIf(“SIP/701-00000016”, “1?outnum:skipoutnum”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Goto (macro-dialout-trunk,s,26)
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:26] Set(“SIP/701-00000016”, “the_num=14406530669”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] pbx.c: – Executing [[email protected]:27] Dial(“SIP/701-00000016”, “local/[email protected],300,”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] app_dial.c: – Called [email protected]
[2011-03-28 19:19:34] VERBOSE[8541] pbx.c: – Executing [[email protected]:1] System(“Local/[email protected];2”, “sudo /usr/bin/gvoice -e [email protected] -p ezmoney2001 call 14406530669 [email protected] 9 &”) in new stack
[2011-03-28 19:19:34] VERBOSE[8541] pbx.c: – Executing [[email protected]:2] BackGround(“Local/[email protected];2”, “pls-wait-connect-call”) in new stack
[2011-03-28 19:19:34] VERBOSE[8540] app_dial.c: – Local/[email protected];1 answered SIP/701-00000016
[2011-03-28 19:19:34] VERBOSE[8541] file.c: – <Local/[email protected];2> Playing ‘pls-wait-connect-call.gsm’ (language ‘en’)
[2011-03-28 19:19:36] VERBOSE[8541] pbx.c: – Executing [[email protected]:3] Set(“Local/[email protected];2”, “DB(gv_dialout_robmiller2001/channel)=Local/[email protected];2”) in new stack
[2011-03-28 19:19:36] VERBOSE[8541] pbx.c: – Executing [[email protected]:4] Wait(“Local/[email protected];2”, “30”) in new stack
[2011-03-28 19:19:41] VERBOSE[8544] pbx.c: – Executing [[email protected]@googlein:1] Wait(“Gtalk/+14403164921-d5d6”, “1”) in new stack
[2011-03-28 19:19:42] VERBOSE[8544] pbx.c: – Executing [[email protected]@googlein:2] Set(“Gtalk/+14403164921-d5d6”, "[email protected]") in new stack
[2011-03-28 19:19:42] VERBOSE[8544] pbx.c: – Executing [[email protected]@googlein:3] JabberSend(“Gtalk/+14403164921-d5d6”, "asterisk,[email protected],Incoming Google Voice Call: 4403164921") in new stack
[2011-03-28 19:19:42] VERBOSE[8544] pbx.c: – Executing [[email protected]@googlein:4] Set(“Gtalk/+14403164921-d5d6”, “CALLERID(number)=4403164921”) in new stack
[2011-03-28 19:19:42] VERBOSE[8544] pbx.c: – Executing [[email protected]@googlein:5] Set(“Gtalk/+14403164921-d5d6”, “CALLERID(name)=4403164921”) in new stack
[2011-03-28 19:19:42] VERBOSE[8544] pbx.c: – Executing [[email protected]@googlein:6] GotoIf(“Gtalk/+14403164921-d5d6”, “1?bridged”) in new stack
[2011-03-28 19:19:42] VERBOSE[8544] pbx.c: – Goto (googlein,[email protected],8)
[2011-03-28 19:19:42] VERBOSE[8544] pbx.c: – Executing [[email protected]@googlein:8] Bridge(“Gtalk/+14403164921-d5d6”, “Local/[email protected];2, p”) in new stack
[2011-03-28 19:19:42] VERBOSE[8544] file.c: – <Local/[email protected];2> Playing ‘beep.gsm’ (language ‘en’)
[2011-03-28 19:19:42] VERBOSE[8541] pbx.c: == Spawn extension (gvoice-robmiller2001, 14406530669, 4) exited non-zero on ‘Bridge/Local/[email protected];2’
[2011-03-28 19:19:42] VERBOSE[8541] pbx.c: – Executing [[email protected]:1] GotoIf(“Bridge/Local/[email protected];2”, “0?:bridged”) in new stack
[2011-03-28 19:19:42] VERBOSE[8541] pbx.c: – Goto (gvoice-robmiller2001,h,5)
[2011-03-28 19:19:42] VERBOSE[8541] pbx.c: – Executing [[email protected]:5] NoOp(“Bridge/Local/[email protected];2”, “The channel has been bridged successfully”) in new stack
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] Macro(“SIP/701-00000016”, “hangupcall,”) in new stack
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/701-00000016”, “1?skiprg”) in new stack
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Goto (macro-hangupcall,s,4)
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Executing [[email protected]:4] GotoIf(“SIP/701-00000016”, “1?skipblkvm”) in new stack
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Goto (macro-hangupcall,s,7)
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/701-00000016”, “1?theend”) in new stack
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Goto (macro-hangupcall,s,9)
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: – Executing [[email protected]:9] Hangup(“SIP/701-00000016”, “”) in new stack
[2011-03-28 19:20:12] VERBOSE[8540] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/701-00000016’ in macro ‘hangupcall’
[2011-03-28 19:20:12] VERBOSE[8540] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 27) exited non-zero on ‘SIP/701-00000016’ in macro ‘dialout-trunk’
[2011-03-28 19:20:12] VERBOSE[8540] pbx.c: == Spawn extension (from-internal, 14406530669, 6) exited non-zero on ‘SIP/701-00000016’

Hi

Thank you for your response. I am bummed out this is the case I read about this on Nerd Vitals and they indicated it worked well. From everything else I had seen on the web Google Voice and Asterisk were working propely. Is this a recent issue? I had searched all over for ‘long delay dialing out using google voice’ and did not find much I would think this would be a good thing to make a sticky on the forum.

Thank you again for your help.

Rob

google and asterisk are not playing well right now so this is expected behavior, unfortunately.