H.323 delay in outbound dialling

Last week users reported a long delay when dialling out from their SIP extensions. My setup is quite simple.

Avaya PBX connected to the outside world - H323 Trunk to Asterisk - Asterisk connected to SIP users using softphones from their macs/linux laptops (all this because Avaya don't have a decent softphone for macs/linux yet).

The logs for a few test calls showed a 60+ seconds delay from the time the call was dialled to the time the call was placed over the H323 ip trunk between Avaya and Asterisk.

After checking that it was not a sip problem, dialling problem, h323 trunk problem by checking logs, tcpdump, avaya trunk side, etc. I concluded the problem was on the h323 setup on Asterisk.

Googling around I found only 1 case of a user asking on the asterisk user list about a similar problem and that he fixed the problem by "disable h323 srv lookups".

I honestly didn't have about srv-enum-etc but helped me find out the problem. My DNS was not resolving any request because it was down. It didn't matter that on /etc/resolve.conf I had 4 dns entries, the first one was down and it was enough to stop this.

It seems h323 does a srv lookup for enum information before dialing out and possible it can be disabled. I couldn't find how unfortunately so to fix this I had to point the box to another dns server on my network. Once this was done all starting working again.

Just in case I am copying some logs of what I was seeing when the problem was present.

[Nov 28 15:34:09] VERBOSE[10584] logger.c: -- Executing [myavayaextension@default:1] Dial("SIP/myasteriskextension-081b5bc8", "H323/myavayaextension@Avaya") in new stack
[Nov 28 15:34:09] VERBOSE[10584] logger.c: -- Requested transfer capability: 0x00 - SPEECH
------------------- 64 seconds delay -----------------
[Nov 28 15:35:13] VERBOSE[10584] logger.c: -- Called myavayaextension@Avaya
[Nov 28 15:35:13] VERBOSE[10584] logger.c: -- H323/Avaya-31 is making progress passing it to SIP/myasteriskextension-081b5bc8
[Nov 28 15:35:13] VERBOSE[10584] logger.c: -- H323/Avaya-31 is ringing
[Nov 28 15:35:17] VERBOSE[10584] logger.c: -- H323/Avaya-31 answered SIP/myasteriskextension-081b5bc8
[Nov 28 15:35:18] VERBOSE[10584] logger.c: == Spawn extension (default, myavayaextension, 1) exited non-zero on 'SIP/myasteriskextension-081b5bc8'


[Nov 28 15:19:52] VERBOSE[10551] logger.c: -- Executing [myavayaextension@default:1] Dial("SIP/myasteriskextension-081b5bc8", "H323/myavayaextension@Avaya") in new stack
[Nov 28 15:19:52] DEBUG[10551] chan_h323.c: type=H323, format=8, data=myavayaextension@Avaya.
[Nov 28 15:19:52] DEBUG[10551] chan_h323.c: Extension: myavayaextensionHost: Avaya
[Nov 28 15:19:52] DEBUG[10551] chan_h323.c: Calling to myavayaextension@Avaya on H323/Avaya-30
[Nov 28 15:19:52] VERBOSE[10551] logger.c: -- Requested transfer capability: 0x00 - SPEECH
[Nov 28 15:19:52] DEBUG[10551] chan_h323.c: Placing outgoing call to myavayaextension@192.168.58.216:1720, 101
[Nov 28 15:19:52] VERBOSE[10551] logger.c: -- Making call to myavayaextension@192.168.58.216:1720 without gatekeeper.
[Nov 28 15:19:52] VERBOSE[10551] logger.c: Using 192.168.58.227 for outbound call
------------------- 64 seconds delay -----------------
[Nov 28 15:20:56] VERBOSE[10551] logger.c: == New H.323 Connection created.
[Nov 28 15:20:56] VERBOSE[10551] logger.c: -- root is calling host myavayaextension@192.168.58.216:1720
[Nov 28 15:20:56] VERBOSE[10551] logger.c: -- Call token is ip$localhost/9446
[Nov 28 15:20:56] VERBOSE[10551] logger.c: -- Call reference is 9446
[Nov 28 15:20:56] VERBOSE[10551] logger.c: -- DTMF Payload is [pt=101]
[Nov 28 15:20:56] VERBOSE[10551] logger.c: -- Called myavayaextension@Avaya

Notes:
myasteriskextension
myavayaextension = my 5 digit extension on the avaya pbx.