[2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Verb: 'NTFY', Identifier: '619930229', Endpoint: 'aaln/1@fqdn.1.0.e0.6f.d2 .90.5c', Version: 'MGCP 1.0' [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] 3 headers, 0 lines [2006-08-19 11:44:37] DEBUG[9168]: Coundn't determine subchannel, assuming current master aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Handling request 'NTFY' on aaln/1@fqdn.1.0.e0.6f.d2.90.5c [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Transmitting: 200 619930229 OK to 10.97.2.62:2427 [2006-08-19 11:44:37] DEBUG[9168]: Endpoint 'aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' observed 'hd' [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] -- Creating connection for aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1 in cxmode: sendrecv callid: 1cee122d15a994ae [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] We're at 8x.xxx.xxx.xx port 12696 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Answering with capability 4 [2006-08-19 11:44:37] DEBUG[9168]: Slow sequence is 0 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Posting Request: CRCX 2403 aaln/1@fqdn.1.0.e0.6f.d2.90.5c MGCP 1.0 C: 1cee122d15a994ae L: p:20, a:PCMU M: sendrecv X: 15a994ae v=0 o=root 9168 9168 IN IP4 8x.xxx.xxx.xxx s=session c=IN IP4 8x.xxx.xxx.xxx t=0 0 m=audio 12696 RTP/AVP 0 a=rtpmap:0 PCMU/8000 to 10.97.2.62:2427 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] -- MGCP Asked to indicate tone: L/dl on aaln/1@fqdn.1.0.e0.6f.d2.90.5 c-1 in cxmode: sendrecv [2006-08-19 11:44:37] DEBUG[9168]: Slow sequence is 0 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Posting Request: RQNT 2404 aaln/1@fqdn.1.0.e0.6f.d2.90.5c MGCP 1.0 X: 04882cac R: L/hu(N),L/hf(N),D/[0-9#*](N) S: L/dl to 10.97.2.62:2427 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] -- MGCP mgcp_new(MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1) created in sta te: Down [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] MGCP read: 200 2404 OK from 10.97.2.62:2427 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Verb: '200', Identifier: '2404', Endpoint: 'OK', Version: '(null)' [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] 1 headers, 0 lines [2006-08-19 11:44:37] DEBUG[9168]: Got response back on transaction 2404 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] MGCP read: 200 2403 OK I: 79C v=0 o=- 2615653766 2615653766 IN IP4 10.97.2.62 s=- c=IN IP4 10.97.2.62 b=AS:64 t=0 0 m=audio 3000 RTP/AVP 0 a=X-pc-codecs:PCMU a=sendrecv a=ptime:20 a=mptime:20 a=rtpmap:0 PCMU/8000 from 10.97.2.62:2427 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Verb: '200', Identifier: '2403', Endpoint: 'OK', Version: '(null)' [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] 2 headers, 12 lines [2006-08-19 11:44:37] DEBUG[9168]: Got response back on transaction 2403 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Capabilities: us - 4, them - 4, combined - 4 [2006-08-19 11:44:37] VERBOSE[9168]: [2006-08-19 11:44:37] Non-codec capabilities: us - 1, them - 0, combined - 0 [2006-08-19 11:44:39] VERBOSE[9168]: [2006-08-19 11:44:39] MGCP read: NTFY 619930246 aaln/1@fqdn.1.0.e0.6f.d2.90.5c MGCP 1.0 NCS 1.0 X: 04882cac O: 1 from 10.97.2.62:2427 [2006-08-19 11:44:39] VERBOSE[9168]: [2006-08-19 11:44:39] Verb: 'NTFY', Identifier: '619930246', Endpoint: 'aaln/1@fqdn.1.0.e0.6f.d2 .90.5c', Version: 'MGCP 1.0' [2006-08-19 11:44:39] VERBOSE[9168]: [2006-08-19 11:44:39] 3 headers, 0 lines [2006-08-19 11:44:39] DEBUG[9168]: Coundn't determine subchannel, assuming current master aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1 [2006-08-19 11:44:39] VERBOSE[9168]: [2006-08-19 11:44:39] Handling request 'NTFY' on aaln/1@fqdn.1.0.e0.6f.d2.90.5c [2006-08-19 11:44:39] VERBOSE[9168]: [2006-08-19 11:44:39] Transmitting: 200 619930246 OK to 10.97.2.62:2427 [2006-08-19 11:44:39] DEBUG[9168]: Endpoint 'aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' observed '1' [2006-08-19 11:44:39] VERBOSE[9168]: [2006-08-19 11:44:39] -- MGCP Asked to indicate tone: L/dl on aaln/1@fqdn.1.0.e0.6f.d2.90.5 c-1 in cxmode: sendrecv [2006-08-19 11:44:39] DEBUG[9168]: Slow sequence is 0 [2006-08-19 11:44:39] VERBOSE[9168]: [2006-08-19 11:44:39] Posting Request: RQNT 2405 aaln/1@fqdn.1.0.e0.6f.d2.90.5c MGCP 1.0 X: 04882cac R: L/hu(N),L/hf(N),D/[0-9#*](N) S: L/dl to 10.97.2.62:2427 Then lotsa "stopping restransmission..." And finally: [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] DEBUG[9171]: Avoiding initial deadlock for 'MGCP/aaln/1@fqdn.1.0.e0.6f.d2.90.5c-1' [2006-08-19 11:52:54] WARNING[9171]: Avoided initial deadlock for '0x8215378', 10 retries!