Manually Installed VistA Issue

Hello, everyone,

I followed the instructions on how to manually install VistA (https://github.com/OSEHRA/VistA/blob/master/Documentation/Install/Manual...), using the "-e" switch.  I installed it on an existing AWS Ubuntu server.  I believe it installed correctly as I can get to the prompt via "mumps -dir".  However, I can't connect via VistALink or CPRS.  In my troubleshooting attempts I tried accessing it with Chrome (<server-ip>:8001) and got this response: "15640 Job ended Tue Mar 1 19:13:16 UTC 2016".  VistALink gives me the following exceptions:

Could not create connection. ; 
    Root cause exception: 
    FoundationsException in executeInitSocketInteraction.; 
    Root cause exception: 
    gov.va.med.exception.FoundationsException: Exception occurred executing transfer, destroying connection; 
    Root cause exception: 
    gov.va.med.net.VistaSocketException: Error occurred reading from socket. ; 
    Root cause exception: 
    gov.va.med.net.VistaSocketException: End of stream encountered unexpectedly.

Any troubleshooting ideas would be much appreciated.

Thanks,

Joseph

like0

Comments

Ports open?

Joseph Snyder's picture

Hi Joseph,
The error corresponds to something going wrong when reading from the socket connection.
My first suggestion would be to ensure that the ports are open both from the OS level( should have been taken care of by the script, but it is worth double checking) and through the Amazon Web Services interface: http://stackoverflow.com/questions/5004159/opening-port-80-ec2-amazon-we....

Hope that helps,

Joe

 

like0

Any other ideas?

Joseph Carneiro's picture

Joe,

Using netstat I see that 8001 and 9430 are open and listening.  I don't have access to the AWS interface, but my colleague who does gaurantees those ports are open.  When I try to connect with VistALink the debug output indicates the connection is made, but something happens during the init interaction:

3450 2016-03-03 11:44:38,509 [AWT-EventQueue-0] DEBUG  resolved DNS address '10.208.122.52' as IP address '10.208.122.52'.
3481 2016-03-03 11:44:38,540 [AWT-EventQueue-0] DEBUG  gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1 M $JOB=[Not Set]
    Executing Init Socket interaction
3497 2016-03-03 11:44:38,556 [AWT-EventQueue-0] DEBUG  gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1 M $JOB=[Not Set]
    Executing interaction
3528 2016-03-03 11:44:38,587 [AWT-EventQueue-0] DEBUG  gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1 M $JOB=[Not Set]
    Executing transfer with time out of 10000
3528 2016-03-03 11:44:38,587 [AWT-EventQueue-0] ERROR  gov.va.med.vistalink.adapter.spi.VistaSocketConnection[mdi]gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1
    receiving data exception-> dataRead value: -1
    gov.va.med.net.VistaSocketException: End of stream encountered unexpectedly.

 

I also tried telnet and got this immediate result:

ubuntu@ip-10-208-122-52:~$ telnet localhost 8001
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
2457 Job ended Thu Mar  3 16:59:48 UTC 2016
Connection closed by foreign host.

I tried this same command with my local VM and noticed that it will block for a while before sending an XML response.  It seems that something is not quite correct with the AWS instance as it behaves differently than the VM on my system.

Any more troubleshooting ideas are welcome.

Thanks again,

Joseph

like0

Manually Installed VistA Issue

Sam Habiel's picture

I recommend using wire shark to see who is hanging up.

On Thursday, March 3, 2016, wrote:

> Joe,
>
> Using netstat I see that 8001 and 9430 are open and listening. I don't
> have access to the AWS interface, but my colleague who does gaurantees
> those ports are open. When I try to connect with VistALink the debug
> output indicates the connection is made, but something happens during the
> init interaction:
>
> 3450 2016-03-03 11:44:38,509 [AWT-EventQueue-0] DEBUG resolved DNS
> address '10.208.122.52' as IP address '10.208.122.52'.
> 3481 2016-03-03 11:44:38,540 [AWT-EventQueue-0] DEBUG
> gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1
> M $JOB=[Not Set]
> Executing Init Socket interaction
> 3497 2016-03-03 11:44:38,556 [AWT-EventQueue-0] DEBUG
> gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1
> M $JOB=[Not Set]
> Executing interaction
> 3528 2016-03-03 11:44:38,587 [AWT-EventQueue-0] DEBUG
> gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1
> M $JOB=[Not Set]
> Executing transfer with time out of 10000
> 3528 2016-03-03 11:44:38,587 [AWT-EventQueue-0] ERROR
> gov.va.med.vistalink.adapter.spi.VistaSocketConnection[mdi]gov.va.med.vistalink.adapter.spi.VistaLinkManagedConnection[]10.208.122.52[]8001[]1[]J2SE[fdi]1[mdi]1
> receiving data exception-> dataRead value: -1
> gov.va.med.net.VistaSocketException: End of stream encountered
> unexpectedly.
>
>
>
> I also tried telnet and got this immediate result:
>
> ubuntu@ip -10-208-122-52:~$
> telnet localhost 8001
> Trying 127.0.0.1...
> Connected to localhost.
> Escape character is '^]'.
> 2457 Job ended Thu Mar 3 16:59:48 UTC 2016
> Connection closed by foreign host.
>
> I tried this same command with my local VM and noticed that it will block
> for a while before sending an XML response. It seems that something is not
> quite correct with the AWS instance as it behaves differently than the VM
> on my system.
>
> Any more troubleshooting ideas are welcome.
>
> Thanks again,
>
> Joseph
> --
> Full post:
> https://www.osehra.org/post/development-tools-discussion-group/manually-...
> Manage my subscriptions: https://www.osehra.org/mailinglist
> Stop emails for this post:
> https://www.osehra.org/mailinglist/unsubscribe/4680
>

--
Sam Habiel, Pharm.D.
VISTA Expertise Network

like0

Sam,

Joseph Carneiro's picture

Sam,

Thanks for the suggestion.  I tried Wireshark and this is what happens:

1091    7.468472    10.252.151.37    10.208.122.52    TCP    66    49920 → 8001 [SYN] Seq=0 Win=8192 Len=0 MSS=1260 WS=4 SACK_PERM=1
1094    7.481162    10.208.122.52    10.252.151.37    TCP    66    8001 → 49920 [SYN, ACK] Seq=0 Ack=1 Win=26883 Len=0 MSS=1260 SACK_PERM=1 WS=128
1095    7.481235    10.252.151.37    10.208.122.52    TCP    54    49920 → 8001 [ACK] Seq=1 Ack=1 Win=66780 Len=0
1096    7.482947    10.252.151.37    10.208.122.52    TCP    384    49920 → 8001 [PSH, ACK] Seq=1 Ack=1 Win=66780 Len=330
1099    7.493774    10.208.122.52    10.252.151.37    TCP    54    8001 → 49920 [ACK] Seq=1 Ack=331 Win=28032 Len=0
1102    7.498994    10.208.122.52    10.252.151.37    TCP    98    8001 → 49920 [PSH, ACK] Seq=1 Ack=331 Win=28032 Len=44
1103    7.501078    10.208.122.52    10.252.151.37    TCP    54    8001 → 49920 [RST, ACK] Seq=45 Ack=331 Win=28032 Len=0

This is the "Follow TCP Stream" output:

<?xml version="1.0" encoding="utf-8" standalone="no"?><VistaLink xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" messageType="gov.va.med.foundations.vistalink.system.request" mode="singleton" version="1.6" xsi:noNamespaceSchemaLocation="vlSimpleRequest.xsd"><Request environment="J2SE" type="initializeSocket"/></VistaLink>.3282 Job ended Fri Mar 4 15:25:17 UTC 2016

The message is making it to the server, but it looks like it is not being handed off to the VistA service.  Is there any way to verify the services are configured properly?

Thanks again,

Joseph

like0

Manually Installed VistA Issue

Sam Habiel's picture

It looks to me that VISTA is prohibiting log ons.

What does ^ZTMCHK and ^ZTMON say?

On Friday, March 4, 2016, wrote:

> Sam,
>
> Thanks for the suggestion. I tried Wireshark and this is what happens:
>
> 1091 7.468472 10.252.151.37 10.208.122.52 TCP 66 49920 →
> 8001 [SYN] Seq=0 Win=8192 Len=0 MSS=1260 WS=4 SACK_PERM=1
> 1094 7.481162 10.208.122.52 10.252.151.37 TCP 66 8001 →
> 49920 [SYN, ACK] Seq=0 Ack=1 Win=26883 Len=0 MSS=1260 SACK_PERM=1 WS=128
> 1095 7.481235 10.252.151.37 10.208.122.52 TCP 54 49920 →
> 8001 [ACK] Seq=1 Ack=1 Win=66780 Len=0
> 1096 7.482947 10.252.151.37 10.208.122.52 TCP 384 49920
> → 8001 [PSH, ACK] Seq=1 Ack=1 Win=66780 Len=330
> 1099 7.493774 10.208.122.52 10.252.151.37 TCP 54 8001 →
> 49920 [ACK] Seq=1 Ack=331 Win=28032 Len=0
> 1102 7.498994 10.208.122.52 10.252.151.37 TCP 98 8001 →
> 49920 [PSH, ACK] Seq=1 Ack=331 Win=28032 Len=44
> 1103 7.501078 10.208.122.52 10.252.151.37 TCP 54 8001 →
> 49920 [RST, ACK] Seq=45 Ack=331 Win=28032 Len=0
>
> This is the "Follow TCP Stream" output:
>
> > xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
> messageType="gov.va.med.foundations.vistalink.system.request"
> mode="singleton" version="1.6"
> xsi:noNamespaceSchemaLocation="vlSimpleRequest.xsd"> > environment="J2SE" type="initializeSocket"/>.3282 Job ended
> Fri Mar 4 15:25:17 UTC 2016
>
> The message is making it to the server, but it looks like it is not being
> handed off to the VistA service. Is there any way to verify the services
> are configured properly?
>
> Thanks again,
>
> Joseph
> --
> Full post:
> https://www.osehra.org/post/development-tools-discussion-group/manually-...
> Manage my subscriptions: https://www.osehra.org/mailinglist
> Stop emails for this post:
> https://www.osehra.org/mailinglist/unsubscribe/4680
>

--
Sam Habiel, Pharm.D.
VISTA Expertise Network

like0

ZTMON and ZTCHK Status

Joseph Carneiro's picture

Sam,

I'm new to VistA and M, so bear with me.  From what I understand "mumps -dir" gives me access to the M programmer prompt.  When I do this I get an "OSEHRA>" prompt.  I tried D ^ZTMON and D ^ZTCHK and both give me:

%GTM-E-RELINKCTLERR, Error with relink control structure for $ZROUTINES directory /home/osehra/p/V6.2-000_x86_64
%GTM-E-SYSCALL, Error received from system call open() -- called from module /usr/library/V62000/src/relinkctl.c at line 148
%SYSTEM-E-ENO13, Permission denied

Assuming I've done this correctly, it looks like there was indeed a problem during the VistA installation.

like0

Manually Installed VistA Issue

DAVID Whitten's picture

could you type each of these commands and tell us what the results are::
I am concerned that the message:

%SYSTEM-E-ENO13, Permission denied

says that some file or directory doesn't have appropriate permissions.

ls -ld /home/osehra/p/V6.2-000_x86_64/

ls -ld /home/osehra/p/

ls -ld /home/osehra/r/

ls -ld /home/osehra/o/

ls -ld /home/osehra/p/V6.2-000_x86_64/r/

ls -ld /home/osehra/

ls -ld /home/

On Fri, Mar 4, 2016 at 4:35 PM, wrote:
> Sam,
>
> I'm new to VistA and M, so bear with me. From what I understand "mumps
> -dir" gives me access to the M programmer prompt. When I do this I get an
> "OSEHRA>" prompt. I tried D ^ZTMON and D ^ZTCHK and both give me:
>
> %GTM-E-RELINKCTLERR, Error with relink control structure for $ZROUTINES
> directory /home/osehra/p/V6.2-000_x86_64
> %GTM-E-SYSCALL, Error received from system call open() -- called from module
> /usr/library/V62000/src/relinkctl.c at line 148
> %SYSTEM-E-ENO13, Permission denied
>
> Assuming I've done this correctly, it looks like there was indeed a problem
> during the VistA installation.
>
> --
> Full post:
> https://www.osehra.org/post/development-tools-discussion-group/manually-...
> Manage my subscriptions: https://www.osehra.org/mailinglist
> Stop emails for this post:
> https://www.osehra.org/mailinglist/unsubscribe/4680

like0

Here is what I get.  I

Joseph Carneiro's picture

Here is what I get.  I noticed two of the directories are missing:

ls -ld /home/osehra/p/V6.2-000_x86_64/
drwxrwxr-x 2 osehra osehra 4096 Mar  1 18:05 /home/osehra/p/V6.2-000_x86_64/

ls -ld /home/osehra/p/
drwxrwxr-x 3 osehra osehra 4096 Mar  1 18:05 /home/osehra/p/

ls -ld /home/osehra/r/
drwxrwxr-x 3 osehra osehra 4096 Mar  1 18:00 /home/osehra/r/

ls -ld /home/osehra/o/
ls: cannot access /home/osehra/o/: No such file or directory

ls -ld /home/osehra/p/V6.2-000_x86_64/r/
ls: cannot access /home/osehra/p/V6.2-000_x86_64/r/: No such file or directory

ls -ld /home/osehra/
drwxrwxr-x 19 osehra osehra 4096 Mar  1 18:04 /home/osehra/

ls -ld /home/
drwxr-xr-x 4 root root 4096 Mar  1 18:00 /home/

like0

Manually Installed VistA Issue

Sam Habiel's picture

Looks like you just need to make the directories and chown to osehra.osehra.

On Mon, Mar 7, 2016 at 7:43 AM, wrote:
> Here is what I get. I noticed two of the directories are missing:
>
> ls -ld /home/osehra/p/V6.2-000_x86_64/
> drwxrwxr-x 2 osehra osehra 4096 Mar 1 18:05 /home/osehra/p/V6.2-000_x86_64/
>
> ls -ld /home/osehra/p/
> drwxrwxr-x 3 osehra osehra 4096 Mar 1 18:05 /home/osehra/p/
>
> ls -ld /home/osehra/r/
> drwxrwxr-x 3 osehra osehra 4096 Mar 1 18:00 /home/osehra/r/
>
> ls -ld /home/osehra/o/
> ls: cannot access /home/osehra/o/: No such file or directory
>
> ls -ld /home/osehra/p/V6.2-000_x86_64/r/
> ls: cannot access /home/osehra/p/V6.2-000_x86_64/r/: No such file or
> directory
>
> ls -ld /home/osehra/
> drwxrwxr-x 19 osehra osehra 4096 Mar 1 18:04 /home/osehra/
>
> ls -ld /home/
> drwxr-xr-x 4 root root 4096 Mar 1 18:00 /home/
>
> --
> Full post:
> https://www.osehra.org/post/development-tools-discussion-group/manually-...
> Manage my subscriptions: https://www.osehra.org/mailinglist
> Stop emails for this post:
> https://www.osehra.org/mailinglist/unsubscribe/4680

--
Sam Habiel, Pharm.D.
VISTA Expertise Network

like0

I added the missing

Joseph Carneiro's picture

I added the missing directories and changed the ownership as you suggested, but the problem persists.  Is there anything else that might explain the "permission denied" error message?

like0