Author Message
RémyLetient
Joined: Jan 24, 2014
Messages: 13
Offline
Hi,
After reading some entries in this forum about SMS connection problem I don't a answer to my problem that's why I open a new entry.
I use the test application available (https://<host>/smsxml/smsxml_test.php) and I have the error : "Fault: Connection Failed:" on a simple display station.
The traces :

--------- message ---------
Apr 19 09:27:40 S8800-AES sudo: tomcat5 : TTY=unknown ; PWD=/usr/share/tomcat-6.0.32 ; USER=root ; COMMAND=/bin/chmod 600 /var/log/messages
Apr 19 09:28:45 S8800-AES SMS[2386]: station model acquiring read-only connection
Apr 19 09:28:45 S8800-AES SMS[2386]: Launching OSSI connector proxy with cmd: /opt/mvap/web/sms-bin/ossicm -h10.10.5.1 -p5022 -l4102 -d/opt/mvap/web/sms/templates_c/ -s -S -m5 -k1800 -o180 -Zossiz -n
Apr 19 09:28:45 S8800-AES SMS[2386]: OSSI Connector proxy execution returned:
Apr 19 09:28:45 S8800-AES saw-cm[19675]: CM Connector Initialized, Listening on 4102
Apr 19 09:28:45 S8800-AES saw-cm[19675]: Establishing listener socket on port 4102
Apr 19 09:28:45 S8800-AES saw-cm[19675]: SSH Library Initialization
Apr 19 09:28:45 S8800-AES saw-cm[19675]: Ready for incoming requests.
Apr 19 09:28:47 S8800-AES saw-cm[19675]: NEW connection for 10.10.5.1
Apr 19 09:28:57 S8800-AES SMS[2386]: Socket read timed out
Apr 19 09:28:57 S8800-AES SMS[2386]: Connection could not be established for operation: retrieve station .
Apr 19 09:29:05 S8800-AES sudo: tomcat5 : TTY=unknown ; PWD=/usr/share/tomcat-6.0.32 ; USER=root ; COMMAND=/bin/chmod 655 /var/log/messages
-----------------------------
------------- ossicm.log ----------------
Apr 19 09:51:34 S8800-AES SMS[2382]: OSSI Connector Failed with params: array ( 'Host' => 'localhost', 'Port' => '4101', 'Login' => 'smsuser', 'Writable' => false, 'SocketFailure' => NULL,
'OSSIFailure' => false, 'LogonRequired' => false, 'ServerStatus' => 'active', )
Apr 19 09:51:34 S8800-AES SMS[2382]: Connection could not be established for operation: retrieve station .
-------------------------------------------

------------- apache/ssl_error.log ---------
[Fri Apr 19 09:51:45 2013] [error] [client 172.20.8.108] PHP Notice: Undefined index: SMS_SESSION_ID in /opt/mvap/web/sms/include/SMS_XMLTestController.cla
ss.php on line 482, referer: https://10.10.4.5/smsxml/smsxml_test.php
-----------------------------------------------


I already check the connection between AES and the CM with telnet and it's OK on port 5022.
I have no idea for others investigations ?
- Note : smsuser is define only on the CM, it doesn't exist on AES

RémyLetient
Joined: Jan 24, 2014
Messages: 13
Offline
Few precisions :

I can open SAT session via ssh <hostname> -p 5022 with sms user from AES.

----------- saw.ini -----------
[General]
connection=OSSI
AllowHTTP=true

[ACP]
Name=
ProxyHost=localhost
ProxyPort=4101
ProxyPortRange=16
CMHost=localhost
CMPort=5022
ProxyFile=proxyhost
ProxyOptions=-S -m5 -k1800 -o180 -Zossiz -n
OSSI_ResponseTimeout=10

[Dev]
tpl_debug=false
tpl_session=false
dev_commands=false
msg_console=false
msg_debug=false
msg_log=false
msg_dst=syslog
proxy_log_dst=/var/log/avaya/aes/ossicm.log
web_service_log_enable=true
web_service_message_trace_enable=false
bypass_web_session=true
bypass_server_status=active
ProxyPath=/opt/mvap/web/sms-bin/
ProxyDataPath=/opt/mvap/web/sms/templates_c/

-------------------------------
CraigJohnson5
Joined: Oct 24, 2013
Messages: 413
Offline
Once you have a SAT session can you run the command 'display station'?

When using the smsxml_test.php web applicaton for CM Login ID are you using 'smsuser@[CM_IP]'?

The only difference between your saw.ini file and the one in my lab is that my ProxyOptions start with -V and yours with -S. The rest is the same.
RémyLetient
Joined: Jan 24, 2014
Messages: 13
Offline
With my SAT session I can run display station with smsuser from AES with ssh session on port 5022.


I try by replacing ProxyOptions -S by -V without success.
------------- osscmi.log ------------
Apr 25 12:27:13 S8800-AES SMS[14060]: Deserializing modelChoices
Apr 25 12:27:13 S8800-AES SMS[14060]: SOAP_WebService instantiated
Apr 25 12:27:13 S8800-AES SMS[14060]: XMLConverter instantiated
Apr 25 12:27:13 S8800-AES SMS[14060]: Station Model CTOR
Apr 25 12:27:13 S8800-AES SMS[14060]: Constructing model
Apr 25 12:27:13 S8800-AES SMS[14060]: Establishing OSSI connector
Apr 25 12:27:13 S8800-AES SMS[14060]: station model acquiring read-only connection
Apr 25 12:27:13 S8800-AES SMS[14060]: Connecting to proxy for host 10.10.5.1:5022 at localhost:4102
Apr 25 12:27:13 S8800-AES SMS[14060]: Connecting to proxy for host 10.10.5.1:5022 at localhost:4102
Apr 25 12:27:13 S8800-AES SMS[14060]: Launching OSSI connector proxy with cmd: /opt/mvap/web/sms-bin/ossicm -h10.10.5.1 -p5022 -l4102 -d/opt/mvap/web/sms/templates_c/ -s -V -m5 -k1800 -o180 -Zossiz -n
Apr 25 12:27:13 S8800-AES SMS[14060]: OSSI Connector proxy execution returned:
Apr 25 12:27:13 S8800-AES saw-cm[11427]: CM Connector Initialized, Listening on 4102
Apr 25 12:27:13 S8800-AES saw-cm[11427]: Connecting to OSSI on 10.10.5.1:5022
Apr 25 12:27:13 S8800-AES saw-cm[11427]: Establishing listener socket on port 4102
Apr 25 12:27:13 S8800-AES saw-cm[11427]: SSH Library Initialization
Apr 25 12:27:13 S8800-AES saw-cm[11427]: Ready for incoming requests.
Apr 25 12:27:15 S8800-AES SMS[14060]: Sending to proxy: r51f86cee001149bed59285e458a7f9d1SMS smsuser ******** 10.10.5.1 5022
Apr 25 12:27:15 S8800-AES saw-cm[11427]: 1/6[localhost.localdomain:38462:]=>0/0 inbound: Inbound connection accepted
Apr 25 12:27:15 S8800-AES saw-cm[11427]: 1/6[localhost.localdomain:38462:]=>0/0 inbound: Receiving Data
Apr 25 12:27:15 S8800-AES saw-cm[11427]: 70 bytes received: r51f86cee001149bed59285e458a7f9d1SMS smsuser smsuser1 10.10.5.1 5022
Apr 25 12:27:15 S8800-AES saw-cm[11427]: 1/6[localhost.localdomain:38462:smsuser]=>0/0 inbound: Connect/Reconnect to outbound socket.
Apr 25 12:27:15 S8800-AES SMS[14060]: Waiting for connector handshaking response
Apr 25 12:27:15 S8800-AES saw-cm[11427]: NEW connection for 10.10.5.1
Apr 25 12:27:15 S8800-AES saw-cm[11427]: Allocating SSH client socket for new outbound connection
Apr 25 12:27:15 S8800-AES saw-cm[11427]: SSH_ClientSocket constructed
Apr 25 12:27:15 S8800-AES saw-cm[11427]: TCP Keepalive is ON
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Allocating new SSH Session
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Starting SSH Session
Apr 25 12:27:25 S8800-AES SMS[14060]: Socket read timed out
Apr 25 12:27:25 S8800-AES SMS[14060]: Closing Socket Connection to ossicm
Apr 25 12:27:25 S8800-AES SMS[14060]: Response Received:
Apr 25 12:27:25 S8800-AES SMS[14060]: Closing Socket
Apr 25 12:27:25 S8800-AES SMS[14060]: OSSI Connector Failed with params: array ( 'Host' => 'localhost', 'Port' => '4101', 'Login' => 'smsuser', 'Writable' => false, 'SocketFailure' => NULL, 'OSSIFailure' => false, 'LogonRequired' => false, 'ServerStatus' => 'active', )
Apr 25 12:27:25 S8800-AES SMS[14060]: Connection could not be established for operation: retrieve station .
Apr 25 12:27:25 S8800-AES SMS[14060]: ==========> OSSIConnector::dtor() invoked; disconnecting
Apr 25 12:27:25 S8800-AES SMS[14060]: OSSI Connector Failed with params: array ( 'TimeoutFailue' => true, )
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Performing SSH Authentication
Apr 25 12:27:25 S8800-AES saw-cm[11427]: SSH Authentication challenge: xqÑ
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Processing 1 prompts...
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Prompt 0: Password: û^W1
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Instruction: xqÑ
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Responding with: smsuser1
Apr 25 12:27:25 S8800-AES saw-cm[11427]: SSH Authentication challenge: À<91><94> ^H
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Processing 0 prompts...
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Opening SSH Session
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Requesting SSH remote terminal
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Establishing SSH channel
Apr 25 12:27:25 S8800-AES saw-cm[11427]: SSH Connection established
Apr 25 12:27:25 S8800-AES saw-cm[11427]: 1/6[localhost.localdomain:38462:smsuser]=>2/5 inbound: Receiving Data
Apr 25 12:27:25 S8800-AES saw-cm[11427]: inbound socket close detected
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Failed to complete protocol handshake, closing outbound socket.
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Destructing SSH_ClientSocket
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Freeing SSH Channel
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Disconnecting SSH Session
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Freeing SSH Session
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Decrementing count: 0
Apr 25 12:27:25 S8800-AES saw-cm[11427]: 2/0[:0:smsuser]=>1/6 outbound: Socket closed.
Apr 25 12:27:25 S8800-AES saw-cm[11427]: 1/0[:0:smsuser]=>2/0 inbound: Socket closed.
Apr 25 12:27:25 S8800-AES saw-cm[11427]: 2/0[:0:smsuser]=>1/0 outbound:REMOVABLE (closed and buffers flushed), deleting socket reference
Apr 25 12:27:25 S8800-AES saw-cm[11427]: 1/0[:0:smsuser]=>0/0 inbound:REMOVABLE (closed and buffers flushed), deleting socket reference
JohnBiggs
Joined: Jun 20, 2005
Messages: 1136
Location: Rural, Virginia
Offline
well the 10 second gap here

Apr 25 12:27:15 S8800-AES saw-cm[11427]: TCP Keepalive is ON
Apr 25 12:27:25 S8800-AES saw-cm[11427]: Allocating new SSH Session

indicates to me that the SSL is not establishing.. however you state

"I can open SAT session via ssh <hostname> -p 5022 with sms user from AES. "

Assuming in both cases you are using the same IP for Communication Manager (10.10.5.1)... I am left wondering where this problem is originating....

Here is the similar exchange on our lab system.. note it takes about 2 seconds for the handshaking response to be received.

[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: Deserializing modelChoices
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: SOAP_WebService instantiated
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: XMLConverter instantiated
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: Station Model CTOR
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: Constructing model
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: Establishing OSSI connector
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_INFO: Thu Apr 25 10:00:29 2013: station model acquiring read-only connection
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: Connecting to proxy for host 135.9.231.41:5022 at localhost:4102
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: Sending to proxy: ra9cb975fbc2ddb9adf627c0f4dd76a9dSMS\tcraft\t******\t\t135.9.231.41\t5022
[Thu Apr 25 10:00:29 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:29 2013: Waiting for connector handshaking response
[Thu Apr 25 10:00:31 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:31 2013: Response Received: 0
[Thu Apr 25 10:00:31 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:31 2013: Retrieve operation: display station 32002;
[Thu Apr 25 10:00:31 2013] [error] [client 135.9.231.40] PHP_INFO: Thu Apr 25 10:00:31 2013: station model releasing connection
[Thu Apr 25 10:00:31 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:31 2013: Closing Socket Connection to ossicm
[Thu Apr 25 10:00:31 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:31 2013: Serializing modelChoices
[Thu Apr 25 10:00:31 2013] [error] [client 135.9.231.40] PHP: Thu Apr 25 10:00:31 2013: Request: \n<?xml version="1.0" encoding="UTF-8"?>\n<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" xmlns:ns1="http://xml.avaya.com/ws/SystemManagementService/2008/07/01" xmlns:ns2="http://xml.avaya.com/ws/session"><SOAP-ENV:Header><ns2:sessionID SOAP-ENV:mustUnderstand="1" SOAP-ENV:actor="http://schemas.xmlsoap.org/soap/actor/next">a9cb975fbc2ddb9adf627c0f4dd76a9d</ns2:sessionID></SOAP-ENV:Header><SOAP-ENV:Body><ns1:submitRequest><modelFields><Station/></modelFields><operation>display</operation><objectname></objectname><qualifier>32002</qualifier></ns1:submitRequest></SOAP-ENV:Body></SOAP-ENV:Envelope>\n
[Thu Apr 25 10:00:31 2013] [error] [client 135.9.231.40] PHP_DEBUG: Thu Apr 25 10:00:31 2013: ==========> OSSIConnector::dtor() invoked; disconnecting
RémyLetient
Joined: Jan 24, 2014
Messages: 13
Offline
To help to understand my log
CM : 10.10.5.1 SSH port 5022, user : smsuser
AES : 10.10.4.5 user craft
JohnBiggs
Joined: Jun 20, 2005
Messages: 1136
Location: Rural, Virginia
Offline
Can you do a ethereal trace of the communication between AE Services and Communication Manager for the two cases (ssh and sms) and compare how one works and the other (appears to) break down at the socket level.

I would think that the same credentials/certificates are used by both the ssh connection and the sms connection although I don't know that for a fact. Have you installed any custom certificates in AE Services or Communication Manager?

Is there a firewall between the two servers (although I think that would cause a problem for the ssh connection as well as the sms --- although the AE Services side port could be the problem if there is a firewall)?
JohnBiggs
Joined: Jun 20, 2005
Messages: 1136
Location: Rural, Virginia
Offline
what version of AE Services are you working with? (do a 'swversion' to a linux prompt from AE Services to find out).

If you are on 4.x SMS needs to be licensed.
RémyLetient
Joined: Jan 24, 2014
Messages: 13
Offline
Thank to the time spent on my problem.

AE Services version : r6-1-1-30-0

I realized one thing. I use the example "SMS Interactive Test" application through the https protocol, but I do not need to authenticate me, same thing with test application provide inside the SDK. Perhaps the problem is around the user used to run the sms application ?
CraigJohnson5
Joined: Oct 24, 2013
Messages: 413
Offline
So are you saying that you don't need to authenticate with the SMS Interactive test and you are getting results? Please explain further what you are entering into the SMS Interactive test and the results you are getting.
RémyLetient
Joined: Jan 24, 2014
Messages: 13
Offline
Solution found and that's work for me !

Problem Clarification
The SMS test does not work and throws a response as below:
'Fault: Connection Failed.'
Cause
The System Platform has the Primary DNS configured same as that of the Default Gateway. This is a Invalid DNS entry.
Also this entry is observed in the resolv.conf of the AES under /etc.
Solution
Delete the DNS entry from the resolv.conf.
1.   Log into System Platform and under Server Management --> Network Configuration.
2.   Check for the DNS entry if this Valid. If not have this removed. Then apply these changes and this would the restart the network configration. This would take approximately 5 minutes.
3.   This would then prompt you to log back into System Platform.
4.   Go to Virtual Machine Management --> Manage --> Application Enablement Services --> Reboot.
5.   Log into the AES and check the resolv.conf under /etc. If it exists, then vi this file and have this removed.
6.   Restart the Network services.
7.   Then do the SMS test.
CraigJohnson5
Joined: Oct 24, 2013
Messages: 413
Offline
Great! Thanks for posting the resolution!
CraigJohnson5
Joined: Oct 24, 2013
Messages: 413
Offline
Great! Thanks for posting the resolution!
Go to:   
Mobile view