Is your Apache server running properly? For MakeCall to work, the HTTP
request will go through Apache first.

For AnswreCall app, can you provide AppServer log too?
Are you playing a WAV file or TTS string? If TTS string then please
make sure "VT Server" is running properly on you machine. You can check
it from Windows Services control panel.
The following error from your media engine log indicates either the TTS
engine is not functioning or the WAV file is invalid.
Sep 16 19:05:18.826(3) S004 media term error


-----Original Message-----
From: cuae-beta-bounces@developer.cisco.com
mailto:cuae-beta-bounces@developer.cisco.com On Behalf Of PATRICK
HOLLOWELL
Sent: Tuesday, September 16, 2008 6:19 PM
To: cuae-beta@developer.cisco.com
Subject: [Cuae-beta] CUAE 2.5 BETA 3 - Can't get MakeCall or AnswerCall
towork

MakeCall:

I have the HTTP trigger configured for url=/MakeCall, but the system
returns a 404 when I hit the URL with my browser:

HTTP ERROR: 404

NOT_FOUND

RequestURI=/MakeCall

Powered by jetty://

AnswerCall:

I have tried both SIP integration and H323, with no results.
Occasionally, the call will be answered (using SIP), but no audio. 90%
of the time the call is disconnected immediately. Here's one session
from the Media Server log. Note the "media term error" about 2/3 down.

Sep 16 19:05:18.435(3) IPCF command is CONNECT Sep 16 19:05:18.435(4)
SESP connection ID 22 bound to client 2 session 4 Sep 16 19:05:18.435(4)
POOL svc thread 5212 has session 4 command connect Sep 16
19:05:18.435(3) S004 registered for RFC2833 events Sep 16
19:05:18.435(3) POOL svc thread 5212 is idle Sep 16 19:05:18.435(4) S004
operation 85 connect end Sep 16 19:05:18.435(4) SERV memory usage pct 46
Sep 16 19:05:18.435(4) APMQ session 4 connect result 0 Sep 16
19:05:18.435(3) IPCF connect posted to IPC client 2 Sep 16
19:05:18.560(3) IPCF command is CONNECT Sep 16 19:05:18.560(4) POOL svc
thread 5552 has session 4 command connect Sep 16 19:05:18.560(3) POOL
svc thread 5552 is idle Sep 16 19:05:18.560(4) POOL session 4 op 86
started async Sep 16 19:05:18.607(3) POOL svc thread 1252 has session 4
event 36866-65 Sep 16 19:05:18.607(4) POOL session 4 op 86 event is
'start IP'
Sep 16 19:05:18.607(3) POOL svc thread 1252 is idle Sep 16
19:05:18.607(4) S004 operation 86 connect end Sep 16 19:05:18.607(4)
APMQ session 4 connect result 0 Sep 16 19:05:18.607(3) IPCF connect
posted to IPC client 2 Sep 16 19:05:18.638(3) IPCF command is PLAY Sep
16 19:05:18.638(4) POOL svc thread 5592 has session 4 command play Sep
16 19:05:18.638(3) S004 op 87 using vox10 Sep 16 19:05:18.685(4) S004 op
87 begin play 1 of 3 Sep 16 19:05:18.685(3) POOL svc thread 5592 is idle
Sep 16 19:05:18.685(4) POOL session 4 op 87 media started async Sep 16
19:05:18.685(4) APMQ session 4 play async ack Sep 16 19:05:18.685(3)
IPCF play posted to IPC client 2 Sep 16 19:05:18.826(3) POOL svc thread
5212 has session 4 event 129-66 Sep 16 19:05:18.826(4) POOL session 4 op
87 event is 'play'
Sep 16 19:05:18.826(3) S004 media term error Sep 16 19:05:18.826(3) POOL
svc thread 5212 is idle Sep 16 19:05:18.857(3) S004 op 87 vox10 released
Sep 16 19:05:18.857(4) S004 operation 87 play end Sep 16 19:05:18.857(4)
APMQ session 4 play result 27 Sep 16 19:05:18.857(3) IPCF play posted to
IPC client 2 Sep 16 19:05:18.888(3) IPCF command is DISCONNECT Sep 16
19:05:18.888(4) POOL svc thread 5552 has session 4 command disconnect
Sep 16 19:05:19.592(3) POOL svc thread 5552 is idle Sep 16
19:05:19.592(4) S004 operation 88 disconnect end Sep 16 19:05:19.592(4)
POOL session 4 end Sep 16 19:05:19.592(3) SESP unbind connection ID 22
Sep 16 19:05:19.592(4) APMQ session 4 disconnect result 0 Sep 16
19:05:19.592(3) IPCF disconnect posted to IPC client 2

I really haven't seen any issues on the forums with anyone getting the
sample apps to work. I actually tried 2.4(3) and got the same results,
although I didn't delve into the log files as much as I have in 2.5B3.
I'm not sure if this is normal behavior, but I see the exact same log
entries in the H323 log that I do under the Media Server log. I never
get any log entries at all (other than startup info) in the SIP log.

Any help that anyone can offer would be greatly appreciated.

Thanks in advance,

Patrick
_______________________________________________
Cuae-beta mailing list
Cuae-beta@developer.cisco.com

_______________________________________________
Cuae-beta mailing list
Cuae-beta@developer.cisco.com

CUME is not working well under VMWare environment, the behavious is
unpredictable. I believe that's the reason why you do not hear the
audio.

Just FYI: Dialogic's HMP (used by Media Engine to perform media
processing) may not work well on laptop due to APIC timer
imcompatibility.

-----Original Message-----
From: cuae-beta-bounces@developer.cisco.com
mailto:cuae-beta-bounces@developer.cisco.com On Behalf Of PATRICK
HOLLOWELL
Sent: Wednesday, September 17, 2008 4:38 PM
To: cuae-beta@developer.cisco.com
Subject: Re: [Cuae-beta] CUAE 2.5 BETA 3 - Can't get MakeCall or
AnswerCallto work

Here's the Media Engine log and the AppServer log for a call. Notice at
the top of the AppServer log there are several failures. I hit redial a
few times and the fifth or sixth call got answered. No changes were
made between calls. On the one that did get answered, I never got
audio.

Sep 17 17:23:38.094(3) IPCF command is CONNECT Sep 17 17:23:38.094(4)
SESP connection ID 5 bound to client 1 session 5 Sep 17 17:23:38.094(4)
POOL svc thread 5244 has session 5 command connect Sep 17
17:23:38.094(3) S005 registered for RFC2833 events Sep 17
17:23:38.094(3) POOL svc thread 5244 is idle Sep 17 17:23:38.094(4) S005
operation 17 connect end Sep 17 17:23:38.094(4) APMQ session 5 connect
result 0 Sep 17 17:23:38.094(3) IPCF connect posted to IPC client 1 Sep
17 17:23:38.359(3) IPCF command is CONNECT Sep 17 17:23:38.359(4) POOL
svc thread 4752 has session 5 command connect Sep 17 17:23:38.359(3)
POOL svc thread 4752 is idle Sep 17 17:23:38.359(4) POOL session 5 op 18
started async Sep 17 17:23:38.406(3) POOL svc thread 4344 has session 5
event 36866-14 Sep 17 17:23:38.406(4) POOL session 5 op 18 event is
'start IP'
Sep 17 17:23:38.406(3) POOL svc thread 4344 is idle Sep 17
17:23:38.406(4) S005 operation 18 connect end Sep 17 17:23:38.406(4)
APMQ session 5 connect result 0 Sep 17 17:23:38.406(3) IPCF connect
posted to IPC client 1 Sep 17 17:23:38.437(3) IPCF command is PLAY Sep
17 17:23:38.437(4) POOL svc thread 4680 has session 5 command play Sep
17 17:23:38.437(3) S005 op 19 using vox11 Sep 17 17:23:38.484(4) S005 op
19 begin play 1 of 3 Sep 17 17:23:38.484(3) POOL svc thread 4680 is idle
Sep 17 17:23:38.484(4) POOL session 5 op 19 media started async Sep 17
17:23:38.484(4) APMQ session 5 play async ack Sep 17 17:23:38.484(3)
IPCF play posted to IPC client 1 Sep 17 17:23:47.250(3) IPCF command is
DISCONNECT

2008:09:17::17:22:25(84): Info: SIP Added Sip callId 1000021 stackCallId
bf736880-8d11751e-1c86c-d66cb4a@74.203.102.13;60073a62;1e8d401f-ca39-45f
7-bea9-6f03b1705293-22306410
2008:09:17::17:22:26(64): Warning: HandleInboundCall-20 No handler
registered for 'Metreos.CallControl.StartTx' event
2008:09:17::17:22:26(64): Warning: HandleInboundCall-20 No handler
registered for 'Metreos.CallControl.StartRx' event
2008:09:17::17:23:25(40): Info: SIP Added Sip callId 1000022 stackCallId
e29e1800-8d117559-1c86f-d66cb4a@74.203.102.13;d576d755;1e8d401f-ca39-45f
7-bea9-6f03b1705293-22306412
2008:09:17::17:23:25(90): Warning: HandleInboundCall-21 No handler
registered for 'Metreos.CallControl.StartTx' event
2008:09:17::17:23:25(90): Warning: HandleInboundCall-21 No handler
registered for 'Metreos.CallControl.StartRx' event
2008:09:17::17:23:29(15): Info: SIP Added Sip callId 1000023 stackCallId
e5007200-8d11755d-1c872-d66cb4a@74.203.102.13;0d28ee23;1e8d401f-ca39-45f
7-bea9-6f03b1705293-22306414
2008:09:17::17:23:29(45): Warning: HandleInboundCall-22 No handler
registered for 'Metreos.CallControl.StartTx' event
2008:09:17::17:23:29(45): Warning: HandleInboundCall-22 No handler
registered for 'Metreos.CallControl.StartRx' event
2008:09:17::17:23:31(26): Info: SIP Added Sip callId 1000024 stackCallId
e6319f00-8d11755f-1c875-d66cb4a@74.203.102.13;b17b1d26;1e8d401f-ca39-45f
7-bea9-6f03b1705293-22306416
2008:09:17::17:23:31(57): Warning: HandleInboundCall-23 No handler
registered for 'Metreos.CallControl.StartTx' event
2008:09:17::17:23:31(57): Warning: HandleInboundCall-23 No handler
registered for 'Metreos.CallControl.StartRx' event
2008:09:17::17:23:38(04): Info: SIP Added Sip callId 1000025 stackCallId
ea5dbc80-8d117566-1c879-d66cb4a@74.203.102.13;4d52b550;1e8d401f-ca39-45f
7-bea9-6f03b1705293-22306418
2008:09:17::17:23:38(48): Warning: HandleInboundCall-24 No handler
registered for 'Metreos.CallControl.StartTx' event
2008:09:17::17:23:38(48): Warning: HandleInboundCall-24 No handler
registered for 'Metreos.CallControl.StartRx' event
2008:09:17::17:23:52(26): Warning: MCP Media control action timed out:
InternalMessage:
Type: ActionMessage
Message ID: Metreos.MediaControl.DeleteConnection
Routing GUID: 40ea6816-fe4c-438e-8bbd-c7fd328403b5
Source: TelephonyManager
SourceType: Application
SourceQueue: specified
Destination: Metreos.MediaControl
session guid: unspecified
actiontype: Synchronous
userdata: unspecified
hiddendata: unspecified
timeout: unspecified
hiddendata1: unspecified
action guid: 40ea6816-fe4c-438e-8bbd-c7fd328403b5.10
Fields:
ConnectionId: 16777221
CallId: 1000025
2008:09:17::17:23:52(60): Warning: TM Acting on timeout condition
(1000025:RemoteHangup:10) http://q=0,cpu=4.346601%,mem=155541KB
2008:09:17::17:23:52(60): Warning: TM Enqueuing 'failure' (1000025)
response from Metreos.MediaControl
2008:09:17::17:25:08(28): Warning: MCP Lost connection to media server
uae (74.203.102.12)
2008:09:17::17:25:10(99): Info: MCP Unable to connect to media server
uae (74.203.102.12)
2008:09:17::17:25:18(85): Warning: MCP IPC connection to uae
(74.203.102.12) lost: Unable to read data from the transport connection:
An existing connection was forcibly closed by the remote host.
2008:09:17::17:25:18(85): Warning: AnswerCall Received a 'failure'
response, but script is already gone:
40ea6816-fe4c-438e-8bbd-c7fd328403b5
2008:09:17::17:25:25(99): Info: MCP Unable to connect to media server
uae (74.203.102.12)


Here's another interesting log entry:

Sep 17 15:27:02.788(3) IPCF command is CONNECT Sep 17 15:27:02.788(4)
SESP connection ID 1 bound to client 1 session 1 Sep 17 15:27:02.804(4)
POOL svc thread 4684 has session 1 command connect Sep 17
15:27:02.804(3) S001 registered for RFC2833 events Sep 17
15:27:02.804(3) POOL svc thread 4684 is idle Sep 17 15:27:02.804(4) S001
operation 1 connect end Sep 17 15:27:02.804(4) SERV memory usage pct 58
Sep 17 15:27:02.804(4) APMQ session 1 connect result 0 Sep 17
15:27:02.804(3) IPCF connect posted to IPC client 1 Sep 17
15:27:02.944(3) IPCF command is CONNECT Sep 17 15:27:02.944(4) POOL svc
thread 4848 has session 1 command connect Sep 17 15:27:02.944(3) POOL
svc thread 4848 is idle Sep 17 15:27:02.944(4) POOL session 1 op 2
started async Sep 17 15:27:02.991(3) POOL svc thread 5216 has session 1
event 36866-2 Sep 17 15:27:02.991(4) POOL session 1 op 2 event is 'start
IP'
Sep 17 15:27:02.991(3) POOL svc thread 5216 is idle Sep 17
15:27:02.991(4) S001 operation 2 connect end Sep 17 15:27:02.991(4) APMQ
session 1 connect result 0 Sep 17 15:27:02.991(3) IPCF connect posted to
IPC client 1 Sep 17 15:27:03.022(3) IPCF command is PLAY Sep 17
15:27:03.022(4) IPCF 'makecall_good_bye.wav' not found - converting to
TTS Sep 17 15:27:03.022(4) IPCF 'makecall_good_bye.wav' not found -
converting to TTS Sep 17 15:27:03.022(4) IPCF 'makecall_good_bye.wav'
not found - converting to TTS Sep 17 15:27:03.022(4) POOL svc thread
5124 has session 1 command play Sep 17 15:27:03.022(3) S001 op 3 using
vox7 Sep 17 15:27:03.163(3) TTSX session 1 TTS to 8bit 00766F27.wav Sep
17 15:27:03.272(3) TTSX session 1 TTS to 8bit 00766F94.wav Sep 17
15:27:03.382(3) TTSX session 1 TTS to 8bit 00767001.wav Sep 17
15:27:03.382(4) S001 op 3 begin play 1 of 3 Sep 17 15:27:03.382(3) POOL
svc thread 5124 is idle Sep 17 15:27:03.382(4) POOL session 1 op 3 media
started async Sep 17 15:27:03.382(4) APMQ session 1 play async ack Sep
17 15:27:03.382(3) IPCF play posted to IPC client 1 Sep 17
15:27:29.382(3) IPCF command is DISCONNECT Sep 17 15:27:42.085(6) SERV
SMGR has not responded in 10 seconds Sep 17 15:27:52.085(6) SERV SMGR
has not responded in 20 seconds Sep 17 15:28:02.085(6) SERV SMGR has not
responded in 30 seconds Sep 17 15:28:12.085(6) SERV SMGR has not
responded in 40 seconds Sep 17 15:28:22.085(6) SERV SMGR has not
responded in 50 seconds Sep 17 15:28:32.086(6) SERV SMGR has not
responded in 60 seconds Sep 17 15:28:32.086(8) SMGR SMGR appears down -
forcing server stop


Any idea what's happening here? I saw where the .WAV file wasn't found,
so I manually put it in the "Audio" folder in the proper app directory.
Got those error messages to stop, but still can't get the audio.
Another odd thing: I saw the Media Server attempt to start up a
multicast stream at one point (229.x.x.x IP address). Why would it be
doing this? Unfortunately, when I went back to grab the logfile, it had
been overwritten.

I'm not sure if this is related or not, but this development environment
is a virtual machine under VMWare. I've reinstalled the entire
environment (including OS) several times (following the install doc each
time), and still have yet to hear audio an can only occasionally get UAE
to answer the call. Are there any known issues with running this
software under VMWare? The host processor is a Intel P4 Xeon.

Thanks for the help!

Patrick
_______________________________________________
Cuae-beta mailing list
Cuae-beta@developer.cisco.com

_______________________________________________
Cuae-beta mailing list
Cuae-beta@developer.cisco.com