Skip to content

Instantly share code, notes, and snippets.

@benlangfeld

benlangfeld/sipmethod.log Secret

Created March 19, 2012 23:00
Show Gist options
  • Save benlangfeld/a656815535601c5daed1 to your computer and use it in GitHub Desktop.
Save benlangfeld/a656815535601c5daed1 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
sipmethod.log
2012-03-19 22:55:26.880 DEBUG [pool-21-thread-13] [IncomingCallActor[callId=4vg6dkqc-lx7-6aepek35vcgsb]] : Request [Output[callId=4vg6dkqc-lx7-6aepek35vcgsb,verbId=6594037a-a891-4bac-b341-e558d46200b3,interrupt-on=<null>,start-offset=<null>,start-paused=<null>,repeatInterval=<null>,repeatTimes=<null>,maxTime=<null>,voice=<null>,prompt=Ssml[ssml=<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="digits/3"/></speak>,voice=<null>,uri=data:application%2Fssml%2Bxml%2C%3Cspeak+version%3D%221.0%22+xmlns%3Axml%3D%22%22+xml%3Axml%3Alang%3D%22en-US%22%3E%3Caudio+src%3D%22digits%2F3%22%2F%3E%3C%2Fspeak%3E]]]
2012-03-19 22:55:26.880 DEBUG [pool-21-thread-13] Creating instance of bean 'outputHandler'
2012-03-19 22:55:26.880 DEBUG [pool-21-thread-13] Returning cached instance of singleton bean 'ssmlValidator'
2012-03-19 22:55:26.880 DEBUG [pool-21-thread-13] Finished creating instance of bean 'outputHandler'
2012-03-19 22:55:26.881 DEBUG [pool-21-thread-13] #MSCTRL#: Add PlayListItem[gi:0, pi:1, ei:0, null, rtcs=null, optargs={JUMP_PLAYLIST_INCREMENT=1, BEHAVIOUR_IF_BUSY=STOP_IF_BUSY, TTS_SPEECH_LANGUAGE=null, PLAYER_ENABLED_EVENTS=[Ljavax.media.mscontrol.EventType;@94026e, VOICE_NAME=null, BARGE_IN_ENABLED=false, PLAYER_MAX_DURATION=-1, PLAYER_FILE_FORMAT=FORMAT_INFERRED, PLAYER_JUMP_TIME=5000, PLAYER_START_PAUSED=false, PLAYER_START_OFFSET=0, VOLUME_CHANGE=3, PLAYER_AUDIO_CODEC=CODEC_INFERRED},"<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="digits/3"/></speak>"]
2012-03-19 22:55:26.882 DEBUG [pool-21-thread-13] #MSCTRL#: Find PlayListItem[IDLE, gi=0, pi=1, ei=0, null]
2012-03-19 22:55:26.882 DEBUG [pool-21-thread-13] #MSCTRL#: Player[IDLE, MG[MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea, MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea]] starts playing PlayListItem[IDLE, gi=0, pi=1, ei=0, null]
2012-03-19 22:55:26.882 DEBUG [pool-21-thread-13] #MSCTRL#: Player[ACTIVE, MG[MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea, MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea]] moves state from [IDLE] to [ACTIVE]
2012-03-19 22:55:26.882 DEBUG [pool-21-thread-13] #MSCTRL#: PlayListItem[0, 0, 1] moves state from [IDLE] to [PLAYING]
2012-03-19 22:55:26.883 DEBUG [pool-21-thread-13] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nSession: 757863367-959f440-04c33560-0000000a\r\nContent-Type: application/mrcp\r\nContent-Length: 314\r\n\r\nSPEAK 25001 MRCP/1.0\r\nKill-On-Barge-In: false\r\nSpeech-Language: en-us\r\nVendor-Specific-Parameters: Voxeo-Playback-Mode=JSR309;Voxeo-Speed-Out=100;Voxeo-Gain-Out=0\r\nContent-Type: application/synthesis+ssml\r\nContent-Length: 86\r\n\r\n<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="digits/3"/></speak> #[757863367-959f440-04c33560-0000000a][192.168.1.73:10074][192.168.1.73:60151]
2012-03-19 22:55:26.884 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 757863367-959f440-04c33560-0000000a\r\nCseq: 4\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 25001 200 IN-PROGRESS\r\n\r\n #[757863367-959f440-04c33560-0000000a][192.168.1.73:10074][192.168.1.73:60151]
2012-03-19 22:55:26.884 DEBUG [pool-21-thread-13] #MSCTRL#: PlayListItem[0, 0, 1] added (25001, 757863367-959f440-04c33560-0000000a)
2012-03-19 22:55:26.884 INFO [pool-21-thread-13] Reply [com.rayo.core.verb.VerbRef@12ba2d4]
2012-03-19 22:55:26.885 DEBUG [pool-21-thread-13] #XMPP#: (o)<iq from="4vg6dkqc-lx7-6aepek35vcgsb@blmbp.home" id="blather000e" to="usera@127.0.0.1/blmbp.home-16355" type="result"><ref id="4bd6ec4d-34a0-4618-9778-00f7ab7e3bee" xmlns="urn:xmpp:rayo:1"/></iq> #[rayo][null][xmpps_gb8ke9b0qvc3][CLIENT][usera@127.0.0.1/blmbp.home-16355, 127.0.0.1][127.0.0.1:60149][127.0.0.1:5222][xmpp][N/A]
2012-03-19 22:55:26.885 DEBUG [pool-21-thread-13] #XMPP#: Send message to: 127.0.0.1:60149 by xmpp #[rayo][null][xmpps_gb8ke9b0qvc3][CLIENT][usera@127.0.0.1/blmbp.home-16355, 127.0.0.1][127.0.0.1:60149][127.0.0.1:5222][xmpp][N/A]
2012-03-19 22:55:26.894 DEBUG [mrcp/2-t-25] #MRCP#: (i)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 2\r\nSession: 757863367-959f440-04c33560-0000000a\r\nContent-Type: application/mrcp\r\nContent-Length: 77\r\n\r\nSPEAK-COMPLETE 25001 COMPLETE MRCP/1.0\r\ncompletion-cause: 003 uri-failure\r\n\r\n #[757863367-959f440-04c33560-0000000a][192.168.1.73:10074][192.168.1.73:60151]
2012-03-19 22:55:26.894 DEBUG [mrcp/2-t-25] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 757863367-959f440-04c33560-0000000a\r\nCseq: 2\r\n\r\n #[757863367-959f440-04c33560-0000000a][192.168.1.73:10074][192.168.1.73:60151]
2012-03-19 22:55:26.895 DEBUG [mrcp/2-t-24] #MRCP#: Handling SPEAK-COMPLETE[25001] #[757863367-959f440-04c33560-0000000a][192.168.1.73:10074][192.168.1.73:60151]
2012-03-19 22:55:26.896 DEBUG [mrcp/2-t-24] #MSCTRL#: Find PlayListItem[PLAYING, gi=0, pi=1, ei=0, null, speakIds=[25001]]
2012-03-19 22:55:26.896 DEBUG [mrcp/2-t-24] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea, MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:25001, requestId:25001, rc:3, duration:14] #[757863367-959f440-04c33560-0000000a]
2012-03-19 22:55:26.896 DEBUG [mrcp/2-t-24] #MSCTRL#: PlayListItem[0, 0, 1] removed (25001, 757863367-959f440-04c33560-0000000a)
2012-03-19 22:55:26.896 DEBUG [mrcp/2-t-24] #MSCTRL#: PlayListItem[0, 0, 1] moves state from [PLAYING] to [IDLE]
2012-03-19 22:55:26.896 ERROR [mrcp/2-t-24] #MSCTRL#: SPEAK[25001] is complete with uri-failure@T: javax.media.mscontrol.MsControlException: SPEAK[25001] is complete with uri-failure\n at com.voxeo.mscontrol.mediagroup.AsyncMrcpPlayer$MrcpSpeakListener.handleEvent(AsyncMrcpPlayer.java:1320)\n at com.voxeo.sipmethod.mrcp.client.impl.MrcpSessionImpl.postMrcpEvent(MrcpSessionImpl.java:261)\n at com.voxeo.sipmethod.mrcp.client.impl.MrcpTtsSessionImpl.handleEvent(MrcpTtsSessionImpl.java:537)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPConnection.postMrcpEvent(MotV1MRCPConnection.java:177)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPTTSConnection.handleSpeakComplete(MotV1MRCPTTSConnection.java:121)\n at com.voxeo.motorola.mrcp.VMotV1MRCPTTSConnection.handleSpeakComplete(VMotV1MRCPTTSConnection.java:54)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPTTSConnection.handleEventMessage(MotV1MRCPTTSConnection.java:61)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPConnection$QueueDispatcher.run(MotV1MRCPConnection.java:92)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2012-03-19 22:55:26.897 DEBUG [mrcp/2-t-24] #MSCTRL#: Player[IDLE, MG[MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea, MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea]] moves state from [ACTIVE] to [IDLE]
2012-03-19 22:55:26.898 DEBUG [mrcp/2-t-24] #MSCTRL#: clear up playList=[PlayListItem[IDLE, gi=0, pi=1, ei=0, null]]
2012-03-19 22:55:26.898 DEBUG [msctrl/2-t-25] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea, MG-n3HpEOdOWwVnFKJYspEoIdsiSIt9CQea]], PLAY_COMPLETED, NOT_FOUND, SPEAK[25001] is complete with uri-failure, NO_QUALIFIER, null, null, 0, -1] to the application
2012-03-19 22:55:26.898 DEBUG [MOHO-48] Dispatching Event to listener:[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=25899251]
2012-03-19 22:55:26.899 DEBUG [pool-21-thread-13] [IncomingCallActor[callId=4vg6dkqc-lx7-6aepek35vcgsb]] : Request [[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=25899251]]
2012-03-19 22:55:26.910 INFO [pool-21-thread-13] Queued Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-6aepek35vcgsb,verbId=4bd6ec4d-34a0-4618-9778-00f7ab7e3bee,reason=ERROR,errorText=Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".]]
2012-03-19 22:55:26.910 INFO [pool-21-thread-13] Reply [null]
2012-03-19 22:55:26.911 INFO [pool-21-thread-13] Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-6aepek35vcgsb,verbId=4bd6ec4d-34a0-4618-9778-00f7ab7e3bee,reason=ERROR,errorText=Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".]]
Raw
wire.xml
<iq type="set" to="4vg6dkqc-lx7-b3t00ainaild@blmbp.home" id="blather0012">
<output xmlns="urn:xmpp:rayo:output:1">
<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US">
<audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/>
</speak>
</output>
</iq>
<presence from="4vg6dkqc-lx7-b3t00ainaild@blmbp.home/4e727ee7-4f55-4bb8-beab-a73771a86cc4" id="936a7607-a759-4689-b6ea-fb616e44019e" to="usera@127.0.0.1">
<complete xmlns="urn:xmpp:rayo:ext:1">
<success xmlns="urn:xmpp:rayo:output:complete:1"/>
</complete>
</presence>
<iq type="set" to="4vg6dkqc-lx7-6aepek35vcgsb@blmbp.home" id="blather000e">
<output xmlns="urn:xmpp:rayo:output:1">
<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US">
<audio src="digits/3"/>
</speak>
</output>
</iq>
<presence from="4vg6dkqc-lx7-6aepek35vcgsb@blmbp.home/4bd6ec4d-34a0-4618-9778-00f7ab7e3bee" id="722db534-d009-4191-9a34-a56744f6683d" to="usera@127.0.0.1">
<complete xmlns="urn:xmpp:rayo:ext:1">
<error xmlns="urn:xmpp:rayo:ext:complete:1">Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".</error>
</complete>
</presence>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment