Skip to content

Instantly share code, notes, and snippets.

@huslage
Created August 24, 2011 00:52
Show Gist options
  • Save huslage/1167040 to your computer and use it in GitHub Desktop.
Save huslage/1167040 to your computer and use it in GitHub Desktop.
2011-08-24 00:46:31.311 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: (i)[INVITE sip:tropo_voicememo.rb@50.16.198.185:6061 SIP/2.0\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>\r\nContent-Type: application/sdp\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport;branch=z9hG4bKac138394000000174e5449eb173522e900000001\r\nCSeq: 1 INVITE\r\nContent-Length: 368\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nUser-Agent: SJphone/1.60.299a/L (SJ Labs)\r\nMax-Forwards: 70\r\nFrom: "unknown"<sip:12.130.124.10>;tag=41817704561257438920\r\nContact: <sip:12.130.124.10:1024>\r\n\r\nv=0\r\no=- 3523135595 3523135595 IN IP4 12.130.124.10\r\ns=SJphone\r\nc=IN IP4 12.130.124.10\r\nt=0 0\r\na=direction:active\r\nm=audio 49152 RTP/AVP 3 97 98 110 8 0 101\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:97 iLBC/8000\r\na=rtpmap:98 iLBC/8000\r\na=fmtp:98 mode=20\r\na=rtpmap:110 speex/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-11,16\r\n] #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.322 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: The transaction was created: z9hG4bKac138394000000174e5449eb173522e900000001 #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.328 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: (o)[SIP/2.0 100 Trying\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport=8544;branch=z9hG4bKac138394000000174e5449eb173522e900000001;received=12.130.124.10\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nFrom: unknown <sip:12.130.124.10>;tag=41817704561257438920\r\n\r\n] #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:tropo_voicememo.rb@50.16.198.185:6061(12.130.124.10:8544)][sip:12.130.124.10(10.114.247.27:6061)]
2011-08-24 00:46:31.329 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Send message to: /12.130.124.10:8544 by udp #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:tropo_voicememo.rb@50.16.198.185:6061(12.130.124.10:8544)][sip:12.130.124.10(10.114.247.27:6061)]
2011-08-24 00:46:31.330 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Connected to 12.130.124.10:8544/udp #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:tropo_voicememo.rb@50.16.198.185:6061(12.130.124.10:8544)][sip:12.130.124.10(10.114.247.27:6061)]
2011-08-24 00:46:31.331 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Found [tropo] to handle the request by port mappings: 6061
2011-08-24 00:46:31.334 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: SipApplicationInfo: SipApplicationRouterInfo[ApplicationName=tropo, RouteModifier=NO_ROUTE, RouteRegion=null, SubscriberURI=sip:tropo_voicememo.rb@50.16.198.185:6061, StateInfo=tropo] #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.344 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-sm4o7zqrx5wka6tropo, ] will expired after 7200000
2011-08-24 00:46:31.354 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Session creating: ss_6itxbdny8ydn #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.357 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Session created:SipSessionImpl[_id=ss_6itxbdny8ydn, _parentId=sas_2-14-sm4o7zqrx5wka6tropo, _handler=tropo, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UNKNOW, _method=INVITE, _callId=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148, ] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.357 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: SessionManagementLayer recv request: INVITE #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.358 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: ApplicationDispatchLayer invoke application: tropo with INVITE #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.358 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: SipServletWrapper[tropo, com.voxeo.tropo.SIPDriver] is forwarding. #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.361 DEBUG [udp/0.0.0.0/6061-t-4] doInvite: [INVITE sip:tropo_voicememo.rb@50.16.198.185:6061 SIP/2.0
To: <sip:tropo_voicememo.rb@50.16.198.185:6061>
Content-Type: application/sdp
Via: SIP/2.0/UDP 172.19.131.148:1024;rport=8544;branch=z9hG4bKac138394000000174e5449eb173522e900000001;received=12.130.124.10
CSeq: 1 INVITE
Content-Length: 368
Call-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148
User-Agent: SJphone/1.60.299a/L (SJ Labs)
Max-Forwards: 70
From: unknown <sip:12.130.124.10>;tag=41817704561257438920
Contact: <sip:12.130.124.10:1024>
v=0
o=- 3523135595 3523135595 IN IP4 12.130.124.10
s=SJphone
c=IN IP4 12.130.124.10
t=0 0
a=direction:active
m=audio 49152 RTP/AVP 3 97 98 110 8 0 101
a=rtpmap:3 GSM/8000
a=rtpmap:97 iLBC/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=20
a=rtpmap:110 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11,16
]
2011-08-24 00:46:31.363 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: SessionManagementLayer send response: INVITE/100 #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.364 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: (o)[SIP/2.0 100 Trying\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport=8544;branch=z9hG4bKac138394000000174e5449eb173522e900000001;received=12.130.124.10\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nFrom: unknown <sip:12.130.124.10>;tag=41817704561257438920\r\n\r\n] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.364 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Send message to: /12.130.124.10:8544 by udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.365 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Connected to 12.130.124.10:8544/udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.365 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: true
2011-08-24 00:46:31.365 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: processInvalidationWhenReady [ss_6itxbdny8ydn], current State = EARLY, Vaild:true, Role:UNKNOW, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.365 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: processInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: true
2011-08-24 00:46:31.366 INFO [udp/0.0.0.0/6061-t-4] A new call is coming from sip:12.130.124.10 to sip:tropo_voicememo.rb@50.16.198.185:6061
2011-08-24 00:46:31.373 INFO [udp/0.0.0.0/6061-t-4] Set logging context for udp/0.0.0.0/6061-t-4 to accountID=0 host=ip-10-114-247-27.ec2.internal sessionGUID=-1 sessionNumber=-1 callID=-1
2011-08-24 00:46:31.445 DEBUG [http-0.0.0.0-8080-exec-4] #HTTP#: (i)HEAD /tropo/script/tropo_voicememo.rb HTTP/1.1\r\nUser-agent: Java/1.6.0_18\r\nHost: localhost:8080\r\nAccept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2\r\nConnection: keep-alive\r\n
2011-08-24 00:46:31.451 DEBUG [http-0.0.0.0-8080-exec-4] #HTTP#: Mapping HTTP Request(/tropo/script/tropo_voicememo.rb) to ApplicationImpl[_symbolicName=tropo-0, _state=STARTED, ] and HttpServletWrapper[default, org.apache.catalina.servlets.DefaultServlet]
2011-08-24 00:46:31.452 DEBUG [http-0.0.0.0-8080-exec-4] #HTTP#: GenericAuthenticator[, , m_name=DefaultHttpAuthenticator, m_state=STARTED, ] no applicable login config defined
2011-08-24 00:46:31.452 DEBUG [http-0.0.0.0-8080-exec-4] #HTTP#: Invoke HttpServletWrapper[default, org.apache.catalina.servlets.DefaultServlet] for HTTP Request(/tropo/script/tropo_voicememo.rb)
2011-08-24 00:46:31.452 DEBUG [http-0.0.0.0-8080-exec-4] #HTTP#: Invoke org.apache.catalina.servlets.DefaultServlet@7dd5a7f6 for HTTP Request(/tropo/script/tropo_voicememo.rb:tropo)
2011-08-24 00:46:31.455 DEBUG [http-0.0.0.0-8080-exec-4] #HTTP#: (o)HTTP/1.1 200\r\nETag: W/"2775-1314146455000"\r\nLast-Modified: Wed, 24 Aug 2011 00:40:55 GMT\r\nContent-Length: 2775\r\nDate: Wed, 24 Aug 2011 00:46:31 GMT\r\n\r\n
2011-08-24 00:46:31.455 DEBUG [udp/0.0.0.0/6061-t-4] Determined type=jruby from filename suffix
2011-08-24 00:46:31.456 DEBUG [udp/0.0.0.0/6061-t-4] Trying to create application for URL=http://localhost:8080/tropo/script/tropo_voicememo.rb and type=jruby
2011-08-24 00:46:31.471 ERROR [udp/0.0.0.0/6061-t-4] TROPO_APP_HOME is NOT defined or the referred directory does not exist!
2011-08-24 00:46:31.472 INFO [udp/0.0.0.0/6061-t-4] Set logging context for udp/0.0.0.0/6061-t-4 to accountID=0 host=ip-10-114-247-27.ec2.internal sessionGUID=0 sessionNumber=0 callID=0
2011-08-24 00:46:31.472 INFO [udp/0.0.0.0/6061-t-4] Application[http://localhost:8080/tropo/script/tropo_voicememo.rb:null] ver(1.0.53150) has been created.
2011-08-24 00:46:31.473 INFO [udp/0.0.0.0/6061-t-4] Set logging context for udp/0.0.0.0/6061-t-4 to accountID=0 host=ip-10-114-247-27.ec2.internal sessionGUID=0 sessionNumber=0 callID=0
2011-08-24 00:46:31.473 INFO [udp/0.0.0.0/6061-t-4] Application[http://localhost:8080/tropo/script/tropo_voicememo.rb:null] ver(1.0.53150) has been found.
2011-08-24 00:46:31.534 INFO [udp/0.0.0.0/6061-t-4] Set logging context for udp/0.0.0.0/6061-t-4 to accountID=0 host=ip-10-114-247-27.ec2.internal sessionGUID=0 sessionNumber=18cd95ec1af002857d3d976860f491da callID=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148
2011-08-24 00:46:31.534 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: SessionManagementLayer send response: INVITE/180 #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.537 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Add Path[ id=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148-41817704561257438920-ai1h18ae885c, session=SipSessionImpl[_id=ss_6itxbdny8ydn, _parentId=sas_2-14-sm4o7zqrx5wka6tropo, _handler=tropo, _state=EARLY, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148, ], party= CALLER] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.540 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: (o)[SIP/2.0 180 Ringing\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>;tag=ai1h18ae885c\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport=8544;branch=z9hG4bKac138394000000174e5449eb173522e900000001;received=12.130.124.10\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nFrom: unknown <sip:12.130.124.10>;tag=41817704561257438920\r\n\r\n] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.540 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Send message to: /12.130.124.10:8544 by udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.541 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: Connected to 12.130.124.10:8544/udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.541 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: true
2011-08-24 00:46:31.541 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: processInvalidationWhenReady [ss_6itxbdny8ydn], current State = EARLY, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.541 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: processInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: true
2011-08-24 00:46:31.542 INFO [udp/0.0.0.0/6061-t-4] Set logging context for udp/0.0.0.0/6061-t-4 to accountID=0 host=ip-10-114-247-27.ec2.internal sessionGUID=0 sessionNumber=18cd95ec1af002857d3d976860f491da callID=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148
2011-08-24 00:46:31.542 DEBUG [udp/0.0.0.0/6061-t-4] Thread udp/0.0.0.0/6061-t-4 acquired engine org.jruby.embed.jsr223.JRubyEngine@156f6adb of type jruby, activeEngines = 1
2011-08-24 00:46:31.543 DEBUG [udp/0.0.0.0/6061-t-4] Thread udp/0.0.0.0/6061-t-4 got engine to compile script
2011-08-24 00:46:31.545 DEBUG [http-0.0.0.0-8080-exec-5] #HTTP#: (i)GET /tropo/script/tropo_voicememo.rb HTTP/1.1\r\nUser-agent: Java/1.6.0_18\r\nHost: localhost:8080\r\nAccept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2\r\nConnection: keep-alive\r\n
2011-08-24 00:46:31.551 DEBUG [http-0.0.0.0-8080-exec-5] #HTTP#: Mapping HTTP Request(/tropo/script/tropo_voicememo.rb) to ApplicationImpl[_symbolicName=tropo-0, _state=STARTED, ] and HttpServletWrapper[default, org.apache.catalina.servlets.DefaultServlet]
2011-08-24 00:46:31.552 DEBUG [http-0.0.0.0-8080-exec-5] #HTTP#: GenericAuthenticator[, , m_name=DefaultHttpAuthenticator, m_state=STARTED, ] no applicable login config defined
2011-08-24 00:46:31.552 DEBUG [http-0.0.0.0-8080-exec-5] #HTTP#: Invoke HttpServletWrapper[default, org.apache.catalina.servlets.DefaultServlet] for HTTP Request(/tropo/script/tropo_voicememo.rb)
2011-08-24 00:46:31.552 DEBUG [http-0.0.0.0-8080-exec-5] #HTTP#: Invoke org.apache.catalina.servlets.DefaultServlet@7dd5a7f6 for HTTP Request(/tropo/script/tropo_voicememo.rb:tropo)
2011-08-24 00:46:31.553 DEBUG [http-0.0.0.0-8080-exec-5] #HTTP#: (o)HTTP/1.1 200\r\nETag: W/"2775-1314146455000"\r\nLast-Modified: Wed, 24 Aug 2011 00:40:55 GMT\r\nContent-Length: 2775\r\nDate: Wed, 24 Aug 2011 00:46:31 GMT\r\n\r\n
2011-08-24 00:46:31.556 INFO [udp/0.0.0.0/6061-t-4] require 'rubygems' # line 215
2011-08-24 00:46:31.558 INFO [udp/0.0.0.0/6061-t-4] require 'json' # line 216
2011-08-24 00:46:31.558 INFO [udp/0.0.0.0/6061-t-4] require 'rest-client' # line 217
2011-08-24 00:46:31.558 INFO [udp/0.0.0.0/6061-t-4] # line 218
2011-08-24 00:46:31.558 INFO [udp/0.0.0.0/6061-t-4] myvoice = "Kate" # line 219
2011-08-24 00:46:31.558 INFO [udp/0.0.0.0/6061-t-4] # line 220
2011-08-24 00:46:31.558 INFO [udp/0.0.0.0/6061-t-4] # apiurl = 'http://web1.tunnlr.com:11053' #test # line 221
2011-08-24 00:46:31.559 INFO [udp/0.0.0.0/6061-t-4] # apiurl = 'http://voiceboard.heroku.com' #production # line 222
2011-08-24 00:46:31.559 INFO [udp/0.0.0.0/6061-t-4] apiurl = "http://50.16.198.185" # line 223
2011-08-24 00:46:31.559 INFO [udp/0.0.0.0/6061-t-4] # line 224
2011-08-24 00:46:31.559 INFO [udp/0.0.0.0/6061-t-4] say "welcome to the burning man voice board!", {:voice => myvoice} # line 225
2011-08-24 00:46:31.559 INFO [udp/0.0.0.0/6061-t-4] # line 226
2011-08-24 00:46:31.560 INFO [udp/0.0.0.0/6061-t-4] while $currentCall.isActive do # line 227
2011-08-24 00:46:31.560 INFO [udp/0.0.0.0/6061-t-4] # line 228
2011-08-24 00:46:31.560 INFO [udp/0.0.0.0/6061-t-4] conferences = RestClient.get apiurl + '/conferences.json' # line 229
2011-08-24 00:46:31.560 INFO [udp/0.0.0.0/6061-t-4] confdata = JSON.parse(conferences) # line 230
2011-08-24 00:46:31.560 INFO [udp/0.0.0.0/6061-t-4] # line 231
2011-08-24 00:46:31.561 INFO [udp/0.0.0.0/6061-t-4] # line 232
2011-08-24 00:46:31.561 INFO [udp/0.0.0.0/6061-t-4] if confdata[0].nil? # line 233
2011-08-24 00:46:31.561 INFO [udp/0.0.0.0/6061-t-4] # line 234
2011-08-24 00:46:31.561 INFO [udp/0.0.0.0/6061-t-4] result = ask "Press one to listen to the voice board or two to start a new recording", { # line 235
2011-08-24 00:46:31.561 INFO [udp/0.0.0.0/6061-t-4] :voice => myvoice, # line 236
2011-08-24 00:46:31.561 INFO [udp/0.0.0.0/6061-t-4] :choices => "[1 DIGITS]", # line 237
2011-08-24 00:46:31.562 INFO [udp/0.0.0.0/6061-t-4] :attempts => 3} # line 238
2011-08-24 00:46:31.562 INFO [udp/0.0.0.0/6061-t-4] # line 239
2011-08-24 00:46:31.562 INFO [udp/0.0.0.0/6061-t-4] if result.value == '1' # line 240
2011-08-24 00:46:31.562 INFO [udp/0.0.0.0/6061-t-4] # Get list of voice messages # line 241
2011-08-24 00:46:31.562 INFO [udp/0.0.0.0/6061-t-4] memos = RestClient.get apiurl + '/voicememos.json?callerid=' + $currentCall.callerID # line 242
2011-08-24 00:46:31.563 INFO [udp/0.0.0.0/6061-t-4] memodata = JSON.parse(memos) # line 243
2011-08-24 00:46:31.563 INFO [udp/0.0.0.0/6061-t-4] if memodata[0].nil? # line 244
2011-08-24 00:46:31.563 INFO [udp/0.0.0.0/6061-t-4] say "you are up to date on all voice memos", {:voice => myvoice} # line 245
2011-08-24 00:46:31.563 INFO [udp/0.0.0.0/6061-t-4] else # line 246
2011-08-24 00:46:31.563 INFO [udp/0.0.0.0/6061-t-4] lastmsg = 0 # line 247
2011-08-24 00:46:31.564 INFO [udp/0.0.0.0/6061-t-4] memodata.each do |memo| # line 248
2011-08-24 00:46:31.564 INFO [udp/0.0.0.0/6061-t-4] if lastmsg != 0 # line 249
2011-08-24 00:46:31.564 INFO [udp/0.0.0.0/6061-t-4] say "next message.", {:voice => myvoice} # line 250
2011-08-24 00:46:31.564 INFO [udp/0.0.0.0/6061-t-4] end # line 251
2011-08-24 00:46:31.564 INFO [udp/0.0.0.0/6061-t-4] lastmsg = memo["conference"]["id"] # line 252
2011-08-24 00:46:31.565 INFO [udp/0.0.0.0/6061-t-4] memorec = RestClient.get apiurl + '/conferences/' + memo["conference"]["id"].to_s + '.json?callerid=' + $currentCall.callerID # line 253
2011-08-24 00:46:31.565 INFO [udp/0.0.0.0/6061-t-4] memorecdata = JSON.parse(memorec) # line 254
2011-08-24 00:46:31.565 INFO [udp/0.0.0.0/6061-t-4] say apiurl + "/data/" + memorecdata["conference"]["filename"] # line 255
2011-08-24 00:46:31.565 INFO [udp/0.0.0.0/6061-t-4] # say "http://voicememo-uploads.s3.amazonaws.com/" + memorecdata["conference"]["filename"] # line 256
2011-08-24 00:46:31.565 INFO [udp/0.0.0.0/6061-t-4] end # line 257
2011-08-24 00:46:31.566 INFO [udp/0.0.0.0/6061-t-4] end # line 258
2011-08-24 00:46:31.566 INFO [udp/0.0.0.0/6061-t-4] # line 259
2011-08-24 00:46:31.566 INFO [udp/0.0.0.0/6061-t-4] elsif result.value == '2' # line 260
2011-08-24 00:46:31.566 INFO [udp/0.0.0.0/6061-t-4] # line 261
2011-08-24 00:46:31.566 INFO [udp/0.0.0.0/6061-t-4] # Start a recorded conference call # line 262
2011-08-24 00:46:31.566 INFO [udp/0.0.0.0/6061-t-4] confid = "burn" + rand(10000000).to_s # line 263
2011-08-24 00:46:31.567 INFO [udp/0.0.0.0/6061-t-4] # line 264
2011-08-24 00:46:31.567 INFO [udp/0.0.0.0/6061-t-4] # Write a conf # line 265
2011-08-24 00:46:31.567 INFO [udp/0.0.0.0/6061-t-4] conf = RestClient.post apiurl + '/conferences.json', "[conference][filename]=" + confid + "&[conference][inprogress]=1" # line 266
2011-08-24 00:46:31.567 INFO [udp/0.0.0.0/6061-t-4] # line 267
2011-08-24 00:46:31.567 INFO [udp/0.0.0.0/6061-t-4] say "starting new voice board conference, press pound to stop recording", {:voice => myvoice} # line 268
2011-08-24 00:46:31.568 INFO [udp/0.0.0.0/6061-t-4] # line 269
2011-08-24 00:46:31.568 INFO [udp/0.0.0.0/6061-t-4] startCallRecording apiurl + '/uploadfile', { # line 270
2011-08-24 00:46:31.568 INFO [udp/0.0.0.0/6061-t-4] :format => 'audio/mp3'} # line 271
2011-08-24 00:46:31.568 INFO [udp/0.0.0.0/6061-t-4] # line 272
2011-08-24 00:46:31.568 INFO [udp/0.0.0.0/6061-t-4] conference confid, { # line 273
2011-08-24 00:46:31.568 INFO [udp/0.0.0.0/6061-t-4] :terminator => "#", # line 274
2011-08-24 00:46:31.569 INFO [udp/0.0.0.0/6061-t-4] :playTones => true} # line 275
2011-08-24 00:46:31.569 INFO [udp/0.0.0.0/6061-t-4] # line 276
2011-08-24 00:46:31.569 INFO [udp/0.0.0.0/6061-t-4] stopCallRecording # line 277
2011-08-24 00:46:31.569 INFO [udp/0.0.0.0/6061-t-4] # line 278
2011-08-24 00:46:31.569 INFO [udp/0.0.0.0/6061-t-4] say "thank you. your message has been recorded on the voice board.", {:voice => myvoice} # line 279
2011-08-24 00:46:31.570 INFO [udp/0.0.0.0/6061-t-4] # line 280
2011-08-24 00:46:31.570 INFO [udp/0.0.0.0/6061-t-4] end # line 281
2011-08-24 00:46:31.570 INFO [udp/0.0.0.0/6061-t-4] # line 282
2011-08-24 00:46:31.570 INFO [udp/0.0.0.0/6061-t-4] else # line 283
2011-08-24 00:46:31.570 INFO [udp/0.0.0.0/6061-t-4] # line 284
2011-08-24 00:46:31.570 INFO [udp/0.0.0.0/6061-t-4] if confdata # line 285
2011-08-24 00:46:31.571 INFO [udp/0.0.0.0/6061-t-4] #join existing conference # line 286
2011-08-24 00:46:31.571 INFO [udp/0.0.0.0/6061-t-4] confname = confdata[0]["conference"]["filename"] # line 287
2011-08-24 00:46:31.571 INFO [udp/0.0.0.0/6061-t-4] say "joining existing voice board conference", {:voice => myvoice} # line 288
2011-08-24 00:46:31.571 INFO [udp/0.0.0.0/6061-t-4] conference confname, { # line 289
2011-08-24 00:46:31.571 INFO [udp/0.0.0.0/6061-t-4] :terminator => "#", # line 290
2011-08-24 00:46:31.572 INFO [udp/0.0.0.0/6061-t-4] :playTones => true} # line 291
2011-08-24 00:46:31.572 INFO [udp/0.0.0.0/6061-t-4] else # line 292
2011-08-24 00:46:31.572 INFO [udp/0.0.0.0/6061-t-4] say "something went wrong. sorry.", {:voice => myvoice} # line 293
2011-08-24 00:46:31.572 INFO [udp/0.0.0.0/6061-t-4] end # line 294
2011-08-24 00:46:31.572 INFO [udp/0.0.0.0/6061-t-4] end # line 295
2011-08-24 00:46:31.573 INFO [udp/0.0.0.0/6061-t-4] # line 296
2011-08-24 00:46:31.573 INFO [udp/0.0.0.0/6061-t-4] end #loop # line 297
2011-08-24 00:46:31.573 INFO [udp/0.0.0.0/6061-t-4] # line 298
2011-08-24 00:46:31.573 INFO [udp/0.0.0.0/6061-t-4] #curl POST -d "[conference][filename]=hello&[conference][inprogress]=1" http://web1.tunnlr.com:11053/conferences.json # line 299
2011-08-24 00:46:31.573 INFO [udp/0.0.0.0/6061-t-4] #RestClient.post "http://web1.tunnlr.com:11053/conferences.json", "[conference][filename]=hello&[conference][inprogress]=1" # line 300
2011-08-24 00:46:31.575 DEBUG [udp/0.0.0.0/6061-t-4] Thread udp/0.0.0.0/6061-t-4 returning engine after compiling script
2011-08-24 00:46:31.575 DEBUG [udp/0.0.0.0/6061-t-4] Thread udp/0.0.0.0/6061-t-4 returned engine org.jruby.embed.jsr223.JRubyEngine@156f6adb of type jruby, activeEngines = 0
2011-08-24 00:46:31.582 DEBUG [udp/0.0.0.0/6061-t-4] SipApplicationSession sas_2-14-sm4o7zqrx5wka6tropo associated with Tropo session 18cd95ec1af002857d3d976860f491da
2011-08-24 00:46:31.600 INFO [udp/0.0.0.0/6061-t-4] ApplicationInstance[http://localhost:8080/tropo/script/tropo_voicememo.rb , sas_2-14-sm4o7zqrx5wka6tropo] has been created.
2011-08-24 00:46:31.600 DEBUG [udp/0.0.0.0/6061-t-4] com.voxeo.tropo.core.SimpleCallFactory@3a3e9a4 is added into the context of app instance : ApplicationInstance[http://localhost:8080/tropo/script/tropo_voicememo.rb , sas_2-14-sm4o7zqrx5wka6tropo]
2011-08-24 00:46:31.602 INFO [udp/0.0.0.0/6061-t-4] Clearing logging context for udp/0.0.0.0/6061-t-4
2011-08-24 00:46:31.605 INFO [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Set logging context for Tropo-Thread-18cd95ec1af002857d3d976860f491da to accountID=0 host=ip-10-114-247-27.ec2.internal sessionGUID=0 sessionNumber=18cd95ec1af002857d3d976860f491da callID=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148
2011-08-24 00:46:31.606 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: false
2011-08-24 00:46:31.606 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: processInvalidationWhenReady [ss_6itxbdny8ydn], current State = EARLY, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:31.606 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: processInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: false
2011-08-24 00:46:31.635 WARN [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Attribute com.voxeo.tropo.core.call.inst added to Sip Session ss_6itxbdny8ydn in state EARLY
2011-08-24 00:46:31.635 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] SipSession ss_6itxbdny8ydn - 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148 associated with Tropo call e74644a96e8f0051f6c944f96bd98cb9
2011-08-24 00:46:31.641 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] SimpleIncomingCall[unknown/unknown->tropo_voicememo.rb/null] state is changed: NEW->RINGING
2011-08-24 00:46:31.641 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Call e74644a96e8f0051f6c944f96bd98cb9 state changed from NEW to RINGING on thread Tropo-Thread-18cd95ec1af002857d3d976860f491da
2011-08-24 00:46:31.642 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] SimpleIncomingCall[unknown/unknown->tropo_voicememo.rb/null]->got INVITE:
[INVITE sip:tropo_voicememo.rb@50.16.198.185:6061 SIP/2.0
To: <sip:tropo_voicememo.rb@50.16.198.185:6061>
Content-Type: application/sdp
Via: SIP/2.0/UDP 172.19.131.148:1024;rport=8544;branch=z9hG4bKac138394000000174e5449eb173522e900000001;received=12.130.124.10
CSeq: 1 INVITE
Content-Length: 368
Call-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148
User-Agent: SJphone/1.60.299a/L (SJ Labs)
Max-Forwards: 70
From: unknown <sip:12.130.124.10>;tag=41817704561257438920
Contact: <sip:12.130.124.10:1024>
v=0
o=- 3523135595 3523135595 IN IP4 12.130.124.10
s=SJphone
c=IN IP4 12.130.124.10
t=0 0
a=direction:active
m=audio 49152 RTP/AVP 3 97 98 110 8 0 101
a=rtpmap:3 GSM/8000
a=rtpmap:97 iLBC/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=20
a=rtpmap:110 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11,16
]
2011-08-24 00:46:31.642 INFO [Tropo-Thread-18cd95ec1af002857d3d976860f491da] SimpleIncomingCall[unknown/unknown->tropo_voicememo.rb/null] is received.
2011-08-24 00:46:31.814 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] SimpleIncomingCall[unknown/unknown->tropo_voicememo.rb/null] is added into the context
2011-08-24 00:46:31.815 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] ApplicationInstance[http://localhost:8080/tropo/script/tropo_voicememo.rb , sas_2-14-sm4o7zqrx5wka6tropo] starts execution on Thread Tropo-Thread-18cd95ec1af002857d3d976860f491da
2011-08-24 00:46:31.815 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Thread Tropo-Thread-18cd95ec1af002857d3d976860f491da acquired engine org.jruby.embed.jsr223.JRubyEngine@156f6adb of type jruby, activeEngines = 1
2011-08-24 00:46:35.747 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Thread Tropo-Thread-18cd95ec1af002857d3d976860f491da returned engine org.jruby.embed.jsr223.JRubyEngine@156f6adb of type jruby, activeEngines = 0
2011-08-24 00:46:35.748 ERROR [Tropo-Thread-18cd95ec1af002857d3d976860f491da] ApplicationInstance[http://localhost:8080/tropo/script/tropo_voicememo.rb , sas_2-14-sm4o7zqrx5wka6tropo] has runtime errors: org.jruby.exceptions.RaiseException: (NameError) uninitialized constant Encoding with cause: org.jruby.exceptions.RaiseException: (NameError) uninitialized constant Encoding
javax.script.ScriptException: org.jruby.exceptions.RaiseException: (NameError) uninitialized constant Encoding
at org.jruby.embed.jsr223.JRubyEngine.wrapException(JRubyEngine.java:115)
at org.jruby.embed.jsr223.JRubyEngine.eval(JRubyEngine.java:93)
at com.voxeo.tropo.app.SimulatedCompiledScript.eval(SimulatedCompiledScript.java:59)
at com.voxeo.tropo.app.SimpleInstance.evaluateScript(SimpleInstance.java:248)
at com.voxeo.tropo.app.SimpleInstance.run(SimpleInstance.java:211)
at com.voxeo.tropo.app.AbstractLocalApplicationManager$1.run(AbstractLocalApplicationManager.java:180)
at java.lang.Thread.run(Thread.java:619)
Caused by: org.jruby.exceptions.RaiseException: (NameError) uninitialized constant Encoding
2011-08-24 00:46:35.749 INFO [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Hanging up call [id=e74644a96e8f0051f6c944f96bd98cb9]
2011-08-24 00:46:35.749 INFO [Tropo-Thread-18cd95ec1af002857d3d976860f491da] SimpleIncomingCall[unknown/unknown->tropo_voicememo.rb/null]->hangup(), headers ={}
2011-08-24 00:46:35.754 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: SessionManagementLayer send response: INVITE/603 #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.757 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: (o)[SIP/2.0 603 Decline\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>;tag=ai1h18ae885c\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport=8544;branch=z9hG4bKac138394000000174e5449eb173522e900000001;received=12.130.124.10\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nFrom: unknown <sip:12.130.124.10>;tag=41817704561257438920\r\n\r\n] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.758 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: Send message to: /12.130.124.10:8544 by udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.758 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: Connected to 12.130.124.10:8544/udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.758 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: false
2011-08-24 00:46:35.764 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: processInvalidationWhenReady [ss_6itxbdny8ydn], current State = TERMINATED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.765 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: server will automatically invalidate sipsession [ss_6itxbdny8ydn] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.766 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: SipSessionImpl[_id=ss_6itxbdny8ydn, _parentId=sas_2-14-sm4o7zqrx5wka6tropo, _handler=tropo, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148, ] is invalidating. (s) #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.766 WARN [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Attribute com.voxeo.tropo.core.call.inst removed from Sip Session ss_6itxbdny8ydn in state TERMINATED
2011-08-24 00:46:35.768 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: Remove Path[ id=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148-41817704561257438920-ai1h18ae885c, session=SipSessionImpl[_id=ss_6itxbdny8ydn, _parentId=sas_2-14-sm4o7zqrx5wka6tropo, _handler=tropo, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=INVITE, _callId=84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148, ]] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:35.769 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: processInvalidationWhenReady [sas_2-14-sm4o7zqrx5wka6tropo], invalidateWhenReady: false
2011-08-24 00:46:35.769 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] SimpleIncomingCall[unknown/unknown->tropo_voicememo.rb/null] state is changed: RINGING->DISCONNECTED
2011-08-24 00:46:35.769 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Call e74644a96e8f0051f6c944f96bd98cb9 state changed from RINGING to DISCONNECTED on thread Tropo-Thread-18cd95ec1af002857d3d976860f491da
2011-08-24 00:46:35.770 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Stopping MRCP
2011-08-24 00:46:35.770 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] MRCP stopped
2011-08-24 00:46:35.770 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Disconnect processed
2011-08-24 00:46:35.770 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-sm4o7zqrx5wka6tropo, ] is invalidating. (as)
2011-08-24 00:46:35.771 DEBUG [Tropo-Thread-18cd95ec1af002857d3d976860f491da] sas_2-14-sm4o7zqrx5wka6tropo invalidated
2011-08-24 00:46:35.771 WARN [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Instance 18cd95ec1af002857d3d976860f491da removed
2011-08-24 00:46:35.772 INFO [Tropo-Thread-18cd95ec1af002857d3d976860f491da] Clearing logging context for Tropo-Thread-18cd95ec1af002857d3d976860f491da
2011-08-24 00:46:36.259 DEBUG [Timer-11] #SIP#: InviteServerTransaction[, , _state=COMPLETED, _id=z9hG4bKac138394000000174e5449eb173522e900000001, ] timerReSend is fired. #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:36.269 DEBUG [Timer-11] #SIP#: (o)[SIP/2.0 603 Decline\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>;tag=ai1h18ae885c\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport=8544;branch=z9hG4bKac138394000000174e5449eb173522e900000001;received=12.130.124.10\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nFrom: unknown <sip:12.130.124.10>;tag=41817704561257438920\r\n\r\n] #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:36.273 DEBUG [Timer-11] #SIP#: Send message to: /12.130.124.10:8544 by udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:36.274 DEBUG [Timer-11] #SIP#: Connected to 12.130.124.10:8544/udp #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:36.644 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: (i)[ACK sip:tropo_voicememo.rb@50.16.198.185:6061 SIP/2.0\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>;tag=ai1h18ae885c\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport;branch=z9hG4bKac138394000000174e5449eb173522e900000001\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nUser-Agent: SJphone/1.60.299a/L (SJ Labs)\r\nMax-Forwards: 70\r\nFrom: "unknown"<sip:12.130.124.10>;tag=41817704561257438920\r\n\r\n] #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:36.768 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: (i)[ACK sip:tropo_voicememo.rb@50.16.198.185:6061 SIP/2.0\r\nTo: <sip:tropo_voicememo.rb@50.16.198.185:6061>;tag=ai1h18ae885c\r\nVia: SIP/2.0/UDP 172.19.131.148:1024;rport;branch=z9hG4bKac138394000000174e5449eb173522e900000001\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: 84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148\r\nUser-Agent: SJphone/1.60.299a/L (SJ Labs)\r\nMax-Forwards: 70\r\nFrom: "unknown"<sip:12.130.124.10>;tag=41817704561257438920\r\n\r\n] #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:36.769 DEBUG [udp/0.0.0.0/6061-t-4] #SIP#: InviteServerTransaction[, , _state=CONFIRMED, _id=z9hG4bKac138394000000174e5449eb173522e900000001, ] doAck of unknow case. #[N/A][N/A][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][N/A][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:41.647 DEBUG [Timer-8] #SIP#: InviteServerTransaction[, , _state=CONFIRMED, _id=z9hG4bKac138394000000174e5449eb173522e900000001, ] timerRemoveTransaction is fired. #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:46:41.654 DEBUG [Timer-8] #SIP#: InviteServerTransaction[, , _state=TERMINATED, _id=z9hG4bKac138394000000174e5449eb173522e900000001, ] is released. #[tropo][sas_2-14-sm4o7zqrx5wka6tropo][84EE0C9A-1DD2-11B2-A30B-A1814BC77F4D@172.19.131.148][ss_6itxbdny8ydn][sip:12.130.124.10(12.130.124.10:8544)][sip:tropo_voicememo.rb@50.16.198.185:6061(10.114.247.27:6061)]
2011-08-24 00:47:45.447 INFO [ApplicationMonitor] Starts loop detection.
2011-08-24 00:47:45.449 INFO [ApplicationMonitor] Ends loop detection.
2011-08-24 00:49:45.449 INFO [ApplicationMonitor] Starts loop detection.
2011-08-24 00:49:45.450 INFO [ApplicationMonitor] Ends loop detection.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment