Script started on Wed 13 Apr 2005 11:00:41 AM CDT
0;root@sd3test:~[root@sd3test root]# asterisk -vvvvvvr
  == Parsing '/etc/asterisk/asterisk.conf': Found
  == Parsing '/etc/asterisk/extconfig.conf': Found
  == Binding extensions.conf to odbc/mysql1/sd_config
  == Binding sip.conf to odbc/mysql1/sd_config
Asterisk CVS-HEAD-04/13/05-10:45:07, Copyright (C) 1999 - 2005 Digium.
Written by Mark Spencer <markster@digium.com>
=========================================================================
Connected to Asterisk CVS-HEAD-04/13/05-10:45:07 currently running on sd3test (pid = 20998)
VerbosityLis at least 6
    -- Remote UNIX connection
Ksd3test*CLI> sip show peer 271nv1000
sd3test*CLI>

  * Name       : 271nv1000
  Secret       : <Not set>
  MD5Secret    : <Not set>
  Context      : 271nv
  Language     : en
  Accountcode  : 4
  AMA flags    : Unknown
  CallingPres  : Presentation Allowed, Not Screened
  Callgroup    :
  Pickupgroup  :
  Mailbox      : 1000@271nv
  LastMsgsSent : 512
  Inc. limit   : 0
  Outg. limit  : 0
  Dynamic      : No
  Callerid     : "Terry Wilson" <1000>
  Expire       : -1
  Expiry       : 900
  Insecure     : no
  Nat	       : Always
  ACL	       : No
  CanReinvite  : No
  PromiscRedir : No
  User=Phone   : No
  DTMFmode     : inband
  LastMsg      : 0
  ToHost       : 192.168.1.165
  Addr->IP     : 192.168.1.165 Port 5060
  Defaddr->IP  : 0.0.0.0 Port 0
  Def. Username: 271nv1000
  Codecs       : 0x4 (ulaw)
  Codec Order  : (ulaw)
  Status       : UNKNOWN
  Useragent    :
  Reg. Contact :

Ksd3test*CLI> sip show peer ser
sd3test*CLI>

  * Name       : ser
  Secret       : <Not set>
  MD5Secret    : <Not set>
  Context      : inbound
  Language     : en
  AMA flags    : Unknown
  CallingPres  : Presentation Allowed, Not Screened
  Callgroup    :
  Pickupgroup  :
  Mailbox      :
  LastMsgsSent : -1
  Inc. limit   : 0
  Outg. limit  : 0
  Dynamic      : No
  Callerid     : "" <>
  Expire       : -1
  Expiry       : 900
  Insecure     : yes
  Nat	       : RFC3581
  ACL	       : No
  CanReinvite  : No
  PromiscRedir : No
  User=Phone   : No
  DTMFmode     : inband
  LastMsg      : 0
  ToHost       : 192.168.1.165
  Addr->IP     : 192.168.1.165 Port 5060
  Defaddr->IP  : 0.0.0.0 Port 0
  Def. Username:
  Codecs       : 0x4 (ulaw)
  Codec Order  : (ulaw)
  Status       : UNKNOWN
  Useragent    :
  Reg. Contact :

Ksd3test*CLI> sip debug
SIPtDebugging Enabled
Ksd3test*CLI>
<-- SIP read from 192.168.1.165:5060:
INVITE sip:5555551212@sdtest.company.com:5060;user=phone SIP/2.0
Record-Route: <sip:192.168.1.165;ftag=9C171289-75DE319E;lr>
Via: SIP/2.0/UDP 192.168.1.165;branch=z9hG4bKb779.fbbac6f6.0
Via: SIP/2.0/UDP 192.168.1.72;branch=z9hG4bK9dadf10450C0600F
From: "Terry Wilson" <sip:271nv1000@sdtest.company.com>;tag=9C171289-75DE319E
To: <sip:5555551212@sdtest.company.com;user=phone>
CSeq: 2 INVITE
Call-ID: c5a8b23d-a24bcb43-79336c78@192.168.1.72
Contact: <sip:271nv1000@192.168.1.72>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.4.1
Supported: 100rel,replace
Allow-Events: talk,hold,conference
Proxy-Authorization: Digest username="271nv1000", realm="company.com", nonce="425d436c9f0a9728a6a3297f9ebacf2756890c90", uri="sip:5555551212@sdtest.company.com:5060;user=phone", response="91f5aaf03905ecc429d04f6b66460b2d", algorithm=MD5
Max-Forwards: 16
Content-Type: application/sdp
Content-Length: 247

v=0
o=- 1113408059 1113408059 IN IP4 192.168.1.72
s=Polycom IP Phone
c=IN IP4 192.168.1.72
t=0 0
a=sendrecv
m=audio 2242 RTP/AVP 18 0 8 101
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000

--- (17 headers 11 lines)---
Using latest request as basis request
Sending to 192.168.1.165 : 5060 (non-NAT)
Apr 13 11:01:04 DEBUG[21005]: chan_sip.c:5894 check_user_full: Setting NAT on RTP to 524288
Found user '271nv1000'
Found RTP audio format 18
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 101
PeertaudioLRTP is at port 192.168.1.72:2242
Apr313s11:01:04 DEBUG[21005]: chan_sip.c:2947 process_sdp: Peer audio RTP is at port 192.168.1.72:2242
Foundedescription format G729
Foundedescription format PCMU
Foundedescription format PCMA
Foundedescription format telephone-event
Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw)
Non-codecCcapabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Apr313s11:01:04 DEBUG[21005]: chan_sip.c:8388 handle_request_invite: Check for res for 271nv1000
LookingtforI5555551212 in 271nv
Apr313s11:01:04 DEBUG[21005]: chan_sip.c:5060 build_route: build_route: Record-Route hop: <sip:192.168.1.165;ftag=9C171289-75DE319E;lr>
Apr313s11:01:04 DEBUG[21005]: chan_sip.c:5085 build_route: build_route: Contact hop: <sip:271nv1000@192.168.1.72>
list_route:Ihop: <sip:192.168.1.165;ftag=9C171289-75DE319E;lr>
list_route:Ihop: <sip:271nv1000@192.168.1.72>
Transmitting>(NAT) to 192.168.1.165:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.165;branch=z9hG4bKb779.fbbac6f6.0;received=192.168.1.165;rport=5060
Via: SIP/2.0/UDP 192.168.1.72;branch=z9hG4bK9dadf10450C0600F
From: "Terry Wilson" <sip:271nv1000@sdtest.company.com>;tag=9C171289-75DE319E
To: <sip:5555551212@sdtest.company.com;user=phone>
Call-ID: c5a8b23d-a24bcb43-79336c78@192.168.1.72
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
Contact: <sip:5555551212@192.168.1.187>
Content-Length: 0


---
Ksd3--sExecuting SetCallerID("SIP/271nv1000-539e", ""TechOps"<5555551212>") in new stack
Ksd3--sExecuting SetMusicOnHold("SIP/271nv1000-539e", "jazz") in new stack
Ksd3--sExecuting Macro("SIP/271nv1000-539e", "outbound") in new stack
Ksd3--sExecuting AppendCDRUserField("SIP/271nv1000-539e", "DNID[5555551212]") in new stack
Apr313s11:01:04 DEBUG[21084]: pbx.c:1505 pbx_substitute_variables_helper_full: Expression is '0'
Ksd3--sExecuting GotoIf("SIP/271nv1000-539e", "0?3:5") in new stack
Ksd3--sGotoI(macro-outbound,s,5)
Ksd3--sExecuting Cut("SIP/271nv1000-539e", "device=CHANNEL||1") in new stack
Ksd3--sExecuting Cut("SIP/271nv1000-539e", "sipacct=device|/|2") in new stack
Ksd3--sExecuting DBget("SIP/271nv1000-539e", "cid=CID/271nv1000") in new stack
Ksd3--sDBget: varname=cid, family=CID, key=271nv1000
Apr313s11:01:04 DEBUG[21084]: db.c:177 ast_db_get: Unable to find key '271nv1000' in family 'CID'
Ksd3--sDBget: Value not found in database.
Ksd3--sExecuting Goto("SIP/271nv1000-539e", "outbound|+15555551212|1") in new stack
Ksd3--sGotoI(outbound,+15555551212,1)
Ks==tChannel>'SIP/271nv1000-539e' jumping out of macro 'outbound'
Ksd3--sExecuting Goto("SIP/271nv1000-539e", "company-inbound|s|1") in new stack
Ksd3--sGotoI(company-inbound,s,1)
Ksd3--sExecuting AGI("SIP/271nv1000-539e", "targus-lookup.pl") in new stack
Ksd3--sLaunched AGI Script /var/lib/asterisk/agi-bin/targus-lookup.pl
Ksd3--sAGILScript targus-lookup.pl completed, returning 0
Ksd3--sExecuting Goto("SIP/271nv1000-539e", "company-attendant|s|1") in new stack
Ksd3--sGotoI(company-attendant,s,1)
Ksd3--sExecuting Answer("SIP/271nv1000-539e", "") in new stack
We'reeat*192.168.1.187 port 17780
AnsweringCwith preferred capability 0x4 (ulaw)
AnsweringCwith non-codec capability 0x1 (telephone-event)
Reliably*Transmitting (NAT) to 192.168.1.165:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.165;branch=z9hG4bKb779.fbbac6f6.0;received=192.168.1.165;rport=5060
Via: SIP/2.0/UDP 192.168.1.72;branch=z9hG4bK9dadf10450C0600F
Record-Route: <sip:192.168.1.165;ftag=9C171289-75DE319E;lr>
From: "Terry Wilson" <sip:271nv1000@sdtest.company.com>;tag=9C171289-75DE319E
To: <sip:5555551212@sdtest.company.com;user=phone>;tag=as325fd0a5
Call-ID: c5a8b23d-a24bcb43-79336c78@192.168.1.72
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
Contact: <sip:5555551212@192.168.1.187>
Content-Type: application/sdp
Content-Length: 216

v=0
o=root 21084 21084 IN IP4 192.168.1.187
s=session
c=IN IP4 192.168.1.187
t=0 0
m=audio 17780 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

---
Ksd3--sExecuting SetMusicOnHold("SIP/271nv1000-539e", "jazz") in new stack
Ksd3--sExecuting ResponseTimeout("SIP/271nv1000-539e", "5") in new stack
Ksd3--sSetLResponse Timeout to 5
Ksd3--sExecuting Wait("SIP/271nv1000-539e", "2") in new stack
Ksd3test*CLI>
<-- SIP read from 192.168.1.165:5060:
ACK sip:5555551212@192.168.1.187:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.165;branch=0
Via: SIP/2.0/UDP 192.168.1.72;branch=z9hG4bKbe496ddb6C377CB6
From: "Terry Wilson" <sip:271nv1000@sdtest.company.com>;tag=9C171289-75DE319E
To: <sip:5555551212@sdtest.company.com;user=phone>;tag=as325fd0a5
CSeq: 2 ACK
Call-ID: c5a8b23d-a24bcb43-79336c78@192.168.1.72
Contact: <sip:271nv1000@192.168.1.72>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.4.1
Max-Forwards: 16
Content-Length: 0


--- (12 headers 0 lines)---
Apr 13 11:01:04 DEBUG[21005]: chan_sip.c:1013 __sip_ack: Stopping retransmission on 'c5a8b23d-a24bcb43-79336c78@192.168.1.72' of Response 2: Found
Ksd3--sExecuting BackGround("SIP/271nv1000-539e", "company-prompts/company-greeting") in new stack
Ksd3--sPlaying 'company-prompts/company-greeting' (language 'en')
Ksd3test*CLI>
sd3test*CLI>
sd3test*CLI>
sd3test*CLI> PRESSING KEYS NOTHING HAPPENING
No3such*command 'PRESSING' (type 'help' for help)
Ksd3test*CLI>
sd3test*CLI>
sd3test*CLI>
<-- SIP read from 192.168.1.165:5060:
BYE sip:5555551212@192.168.1.187:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.165;branch=z9hG4bKc779.81a60ec3.0
Via: SIP/2.0/UDP 192.168.1.72;branch=z9hG4bK40e9b4a7B45FC2
From: "Terry Wilson" <sip:271nv1000@sdtest.company.com>;tag=9C171289-75DE319E
To: <sip:5555551212@sdtest.company.com;user=phone>;tag=as325fd0a5
CSeq: 3 BYE
Call-ID: c5a8b23d-a24bcb43-79336c78@192.168.1.72
Contact: <sip:271nv1000@192.168.1.72>
User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.4.1
Proxy-Authorization: Digest username="271nv1000", realm="company.com", nonce="425d436c9f0a9728a6a3297f9ebacf2756890c90", uri="sip:5555551212@sdtest.company.com:5060;user=phone", response="91f5aaf03905ecc429d04f6b66460b2d", algorithm=MD5
Max-Forwards: 16
Content-Length: 0


--- (12 headers 0 lines)---
Sending to 192.168.1.165 : 5060 (NAT)
Transmitting (NAT) to 192.168.1.165:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.165;branch=z9hG4bKc779.81a60ec3.0;received=192.168.1.165;rport=5060
Via: SIP/2.0/UDP 192.168.1.72;branch=z9hG4bK40e9b4a7B45FC2
From: "Terry Wilson" <sip:271nv1000@sdtest.company.com>;tag=9C171289-75DE319E
To: <sip:5555551212@sdtest.company.com;user=phone>;tag=as325fd0a5
Call-ID: c5a8b23d-a24bcb43-79336c78@192.168.1.72
CSeq: 3 BYE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
Contact: <sip:5555551212@192.168.1.187>
Content-Length: 0


---
Apr313s11:01:28 WARNING[21084]: file.c:564 ast_readaudio_callback: Failed to write frame
  == Spawn extension (company-attendant, s, 5) exited non-zero on 'SIP/271nv1000-539e'
Apr313s11:01:28 DEBUG[21084]: chan_sip.c:1913 sip_hangup: update_user_counter(271nv1000) - decrement inUse counter
DestroyingLcall 'c5a8b23d-a24bcb43-79336c78@192.168.1.72'
Ksd3test*CLI> quit
Executing last minute cleanups
0;root@sd3test:~[root@sd3test root]#
Script done on Wed 13 Apr 2005 11:01:35 AM CDT