Our Products:   CompleteFTP  edtFTPnet/Free  edtFTPnet/PRO  edtFTPj/Free  edtFTPj/PRO
Ask a Question

How do I execute a program from JSS?

+1 vote
1.7k views
in CompleteFTP by (130 points)
I am setting up a server to receive files that contain data in a proprietary format. There is a tool that can read the file and insert the data into the database, but how do I invoke this tool from JSS?

The tool doesn't take file path etc. from the command line - it uses a configuration file. So I have a template configuration file which I read, replace the placeholder values with actual values from the event variables, and write to a tmp file. Then I need to invoke the tool with the tmp file as an argument, but I can't see a way to do this...

Thanks!
by (162k points)
You may not be able to use JSS. But you could try passing the variables to a batch program  that does what you need, or write a simple program that does this.
by (130 points)
Thank you for the prompt response. I wrote a small Perl wrapper (below) which is now invoked by the CompleteFTP server, but it is still failing. If I call the Perl script manually it works - so what is different about calling it from CompleteFTP????


use strict;
use warnings;

my $upfile = shift(@ARGV);
my $e5efile = 'B:\\' . time() . '.e5e';
my $template = "UPSERT-E5F.e5e";

open(my $in, '<', $template) or die "Could not open file '$template' $!";
open(my $out, '>', $e5efile) or die "Could not open file '$e5efile' $!";

while (my $row = <$in>) {
   $row =~ s/XXXXXXXX/$upfile/g; # do the replacement
   print $out $row; # print to the modified file
}

close($in);
close($out);

my $cmd = qq[ "C:\\Program Files (x86)\\Eccairs5\\Bin\\E5DataManager.exe" -file:$e5efile -silent];

print $cmd;
 
system $cmd;
by (162k points)
How do you invoke it? Could you post the debug level logging from the diagnnostics.log file of the server that shows it being invoked?

1 Answer

0 votes
by (2.7k points)

Actually, you should be able to invoke the program from JSS by invoking the System.Diagnostics.Process.Start method as follows:

var programPath = "C:\\directory\\myprogram.exe";
var arguments = "arg1 arg2";
System.Diagnostics.Process.Start(programPath, arguments);

JSS allows calling out to .NET (in process triggers at least) so that should work.

by (130 points)
I have loosly translated my Perl script (above) into JSS script but I haven't been able to get past an error:

Time    Level    Category    IP Address    Session    User    Message
11:09:46,781    ERROR    Event        Server.1        The given path's format is not supported.:  (9, 0): out.writeText(content);

As you can see, the path I have provided to new File() is a virtual path: "/B-drive/UPSERT-" + time + ".e5e" so I don't know how to move beyond this message. The Windows path doesn't work - I tried it even though the documentation says the File class only works with virtual paths.

One other little quirk: Date.now() seems to return a string rather than milliseconds as per the documentation on the Mozilla website.

Here is the script:

var template = new File("/B-drive/UPSERT-E5F.e5e");
var content = template.readText().replace("XXXXXXXX", event.windowsPath);

var time = Date.now();
var virtE5Efile = "/B-drive/UPSERT-" + time + ".e5e";
var winE5Efile = "B:\\UPSERT-" + time + ".e5e";

var out = new File(virtE5Efile);
out.writeText(content);

var programPath = "C:\\Program Files (x86)\\Eccairs5\\Bin\\E5DataManager.exe";
var arguments = "-file:" + winE5Efile + " -silent";

System.Diagnostics.Process.Start(programPath, arguments);
by (130 points)
That Date quirk I mentioned appears to be the cause of the file name issue. If I replace Date.now() with new Date.getTime() it works.

However, the script still is not successfully calling my program.
by (130 points)
Part 2:

2017-05-25 11:26:14,673 DEBUG ImpersonationContext [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Impersonation begin -> 'ICAONET\mhenry'
2017-05-25 11:26:14,673 DEBUG SFTPServerMessageFactory [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Received message (type=12,len=31)
2017-05-25 11:26:14,673 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Received message (SSH_FXP_READDIR,id=32012)
2017-05-25 11:26:14,673 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] OnReadDir()
2017-05-25 11:26:14,673 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Listing directory /B-drive/INPUT
2017-05-25 11:26:14,673 DEBUG SSHServerChannel [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Transmit 130 bytes (max = 16384)
2017-05-25 11:26:14,673 DEBUG ChannelDataWindow [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Remote window size decreased to 2147482018
2017-05-25 11:26:14,673 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sequence: 54
2017-05-25 11:26:14,673 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sending 192 bytes
2017-05-25 11:26:14,673 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sent 192 bytes
2017-05-25 11:26:14,673 DEBUG ImpersonationContext [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Impersonation end -> 'NT AUTHORITY\SYSTEM'
2017-05-25 11:26:14,673 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] OnReceive called
2017-05-25 11:26:14,673 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] OnReceive 80 bytes
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] PreProcessPacket pt=SSH_MSG_CHANNEL_DATA,len=31
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] SSH_MSG_CHANNEL_DATA for channel 0
2017-05-25 11:26:14,674 DEBUG SSHServerChannel [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Channel 0: ProcessPacket pt=SSH_MSG_CHANNEL_DATA
2017-05-25 11:26:14,674 DEBUG ImpersonationContext [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Impersonation begin -> 'ICAONET\mhenry'
2017-05-25 11:26:14,674 DEBUG SFTPServerMessageFactory [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Received message (type=12,len=31)
2017-05-25 11:26:14,674 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Received message (SSH_FXP_READDIR,id=32268)
2017-05-25 11:26:14,674 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] OnReadDir()
2017-05-25 11:26:14,674 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sending SSH_FXP_STATUS [requestid=32268,code=1]
2017-05-25 11:26:14,674 DEBUG SSHServerChannel [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Transmit 21 bytes (max = 16384)
2017-05-25 11:26:14,674 DEBUG ChannelDataWindow [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Remote window size decreased to 2147481997
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sequence: 55
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sending 80 bytes
2017-05-25 11:26:14,674 DEBUG ImpersonationContext [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Impersonation end -> 'NT AUTHORITY\SYSTEM'
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] OnReceive called
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] OnReceive 80 bytes
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] PreProcessPacket pt=SSH_MSG_CHANNEL_DATA,len=31
2017-05-25 11:26:14,674 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] SSH_MSG_CHANNEL_DATA for channel 0
2017-05-25 11:26:14,674 DEBUG SSHServerChannel [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Channel 0: ProcessPacket pt=SSH_MSG_CHANNEL_DATA
2017-05-25 11:26:14,674 DEBUG ImpersonationContext [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Impersonation begin -> 'ICAONET\mhenry'
2017-05-25 11:26:14,674 DEBUG SFTPServerMessageFactory [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Received message (type=4,len=31)
2017-05-25 11:26:14,674 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Received message (SSH_FXP_CLOSE,id=32516)
2017-05-25 11:26:14,674 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] OnClose()
2017-05-25 11:26:14,674 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Removed dir handle 154062587
2017-05-25 11:26:14,674 DEBUG SFTPSubsystemServer [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sending SSH_FXP_STATUS [requestid=32516,code=0]
2017-05-25 11:26:14,674 DEBUG SSHServerChannel [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Transmit 34 bytes (max = 16384)
2017-05-25 11:26:14,674 DEBUG ChannelDataWindow [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Remote window size decreased to 2147481963
2017-05-25 11:26:14,675 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sequence: 56
2017-05-25 11:26:14,675 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sending 96 bytes
2017-05-25 11:26:14,675 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sent 96 bytes
2017-05-25 11:26:14,675 DEBUG ImpersonationContext [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Impersonation end -> 'NT AUTHORITY\SYSTEM'
2017-05-25 11:26:14,675 DEBUG SFTPConnection [Session.9:Default Site:ICAONET\MHenry:127.0.0.1] Sent 80 bytes
2017-05-25 11:26:15,967 DEBUG ProcessTrigger [Server.1] Finished process for rule UPSERT E5F FILE (1) after 1.295 seconds
2017-05-25 11:26:15,967 INFO ProcessTrigger [Server.1] Process trigger UPSERT E5F FILE finished after 1.297s
by (51.6k points)
Thanks for reporting the Date.now() bug.  We'll fix that for the next release.

It turns out that Process.Start only launches the executable, but doesn't wait for it to complete.  To make it wait, please add .WaitForExit() as shown below:

System.Diagnostics.Process.Start(programPath, arguments).WaitForExit();

I also suggest logging the programPath and arguments before you call process start as follows:

console.log("Starting " + programPath + " " + arguments);

and adding another logging message after the program exits.

If it appears to run successfully but doesn't report an error then it's probably writing something to stderr.  In this case, you should be able to use something like the following to log the output:

var process = new System.Diagnostics.Process();
process.StartInfo.CreateNoWindow = true;
process.StartInfo.UseShellExecute = false;
process.StartInfo.RedirectStandardOutput = true;
process.StartInfo.RedirectStandardError = true;
process.StartInfo.FileName = programPath;
process.StartInfo.Arguments = arguments;

process.Start();
while (process.StandardOutput.Peek() > -1)
    console.log(process.StandardOutput.ReadLine());
while (process.StandardError.Peek() > -1)
    console.log(process.StandardError.ReadLine());
process.WaitForExit();
by (130 points)
What has become very clear is that the difference between calling my Perl wrapper from the command line (which succeeds) and calling it from the FTP server (which does not) is that the FTP server is running as a different user and the process executes in a different environment - which involves differences, e.g. with file access - that cause the program to fail.

I made the changes you suggested to my JSS script and this is the output:


2017-05-26 09:54:04,897 INFO WindowsImpersonation [Session.10:Default Site:ICAONET\MHenry:127.0.0.1] Windows Interactive logon succeeded for ICAONET\MHenry
2017-05-26 09:54:04,897 INFO WindowsImpersonation [Session.10:Default Site:ICAONET\MHenry:127.0.0.1] Using Windows identity ICAONET\mhenry
2017-05-26 09:54:04,898 INFO UserSession [Session.10:Default Site:ICAONET\MHenry:127.0.0.1] ICAONET\MHenry logged into Default Site with protocol SSH/SFTP/SCP on 127.0.0.1:22 from 127.0.0.1:50131
2017-05-26 09:54:21,525 INFO SFTPSubsystemServer [Session.10:Default Site:ICAONET\MHenry:127.0.0.1] Opened /B-drive/INPUT/TEST.e5f for writing
2017-05-26 09:54:21,528 INFO FileDetails [Session.10:Default Site:ICAONET\MHenry:127.0.0.1] Closed file /B-drive/INPUT/TEST.e5f after writing 2732 bytes
2017-05-26 09:54:21,535 INFO UserSession [Session.10:Default Site:ICAONET\MHenry:127.0.0.1] ICAONET\MHenry logged into Default Site with protocol  
2017-05-26 09:54:21,535 INFO ProcessTrigger [Session.4:Default Site:ICAONET\MHenry:127.0.0.1] Running process trigger JSS UPSERT E5F FILE
2017-05-26 09:54:21,817 INFO JSS [Server.1] Javascript (log): Starting C:\Program Files (x86)\Eccairs5\Bin\E5DataManager.exe -file:B:\UPSERT-1495806861810.e5e -silent
2017-05-26 09:54:23,326 INFO JSS [Server.1] Javascript (log): Finished!
2017-05-26 09:54:23,327 INFO ProcessTrigger [Server.1] Process trigger JSS UPSERT E5F FILE finished after 1.792s

The program I am trying to call does not produce any output. The JSS trigger includes the "Run as" menu which I used to run the script as me, but it still did not succeed.

I use my Perl wrapper to dump the environment variables of the process, and I then compared these between the two calls. Where there were differences (e.g. TEMP) I redefined those variables in the script before I called the program, and I set those variables to paths that I knew would be accessible to the process spawned by the FTP server. Still no success.

I downloaded the Process Monitor (https://technet.microsoft.com/en-ca/sysinternals) and used it to track all the system calls made by the program, hoping that I could identify the system calls that were failing. However there were far too many system calls for me to be able to pinpoint the call that triggered the whole process to fail.

At this point I think I've given up on trying to get this to work. Thank you for all your help!
by (2.7k points)
I just experimented a bit more with this.  I used the script that I've included below to call a process that tried to write a file to a specific directory.  I found that when the SERVICE account had permission to the directory then it worked fine, and when it didn't have permission then the error message of the program would be written to the log synchronously (i.e. before the "Finished" message).  The script logs the exit code of the program so that could potentially give you some clues.

I'd really like to help you get this working, so if you have any patience left then I can make a few suggestions:

1. Check if there's any way to get E5DataManager to write to stdout or stderr, so that you can see if it's being called.

2. Check if E5DataManager produces a log file.  If so, then check to see if anything is written.

3. Try to call a program other than E5DataManager - preferably one that writes something to stdout or stderr, so that you can confirm that it's being called.

4. Run the CompleteFTP server from the console (see start menu), so that it runs under your own account, which should remove any permission issues.

By the way, what is E5DataManager?  If it's not a console-mode program then it may have trouble running from a Windows service.


The JSS script:

function runProcess(program, dir, args) {
    var process = new System.Diagnostics.Process();
    process.StartInfo.CreateNoWindow = true;
    process.StartInfo.UseShellExecute = false;
    process.StartInfo.RedirectStandardOutput = true;
    process.StartInfo.RedirectStandardError = true;
    process.StartInfo.FileName = program;
    process.StartInfo.WorkingDirectory = dir;
    process.StartInfo.Arguments = args;

    console.log("Running: " + program);
    process.Start();
    while (process.StandardOutput.Peek() > -1)
        console.log(process.StandardOutput.ReadLine());
    while (process.StandardError.Peek() > -1)
        console.log(process.StandardError.ReadLine());
    process.WaitForExit();
    console.log("Exit code = " + process.ExitCode);
}

runProcess("C:\\Utils\\randomFile.exe", "C:\\Temp\\Test", "test.dat 1KB");
by (130 points)
Thank you again for your response.

With regards to (1), (2), and (3), the program is definitely being called as I can see all the system calls being made by the program using the Process Monitor software.

I tried (4) and it worked with no problems at all.

2017-05-29 09:30:03,415 INFO SFTPSubsystemServer [Session.3:Default Site:ICAONET\MHenry:127.0.0.1] Opened /B-drive/INPUT/TEST.e5f for writing
2017-05-29 09:30:03,427 INFO FileDetails [Session.3:Default Site:ICAONET\MHenry:127.0.0.1] Closed file /B-drive/INPUT/TEST.e5f after writing 2732 bytes
2017-05-29 09:30:03,435 INFO ProcessTrigger [] Running process trigger JSS UPSERT E5F FILE
2017-05-29 09:30:03,679 INFO JSS [Server.1] Javascript (log): Starting C:\Program Files (x86)\Eccairs5\Bin\E5DataManager.exe -file:B:\UPSERT-1496064603672.e5e -silent
2017-05-29 09:30:12,319 INFO JSS [Server.1] Javascript (log): Exit code: 0
2017-05-29 09:30:12,320 INFO ProcessTrigger [Server.1] Process trigger JSS UPSERT E5F FILE finished after 8.885s

Contrast this output with the output when the server is running as a service and I have set the JSS script to "Run as" myself:

2017-05-29 09:43:02,894 INFO SFTPSubsystemServer [Session.1:Default Site:ICAONET\MHenry:127.0.0.1] Opened /B-drive/INPUT/TEST.e5f for writing
2017-05-29 09:43:02,896 INFO FileDetails [Session.1:Default Site:ICAONET\MHenry:127.0.0.1] Closed file /B-drive/INPUT/TEST.e5f after writing 2732 bytes
2017-05-29 09:43:02,896 INFO UserSession [Session.1:Default Site:ICAONET\MHenry:127.0.0.1] ICAONET\MHenry logged into Default Site with protocol  
2017-05-29 09:43:02,915 INFO JSS [Server.1] Javascript (log): Starting C:\Program Files (x86)\Eccairs5\Bin\E5DataManager.exe -file:B:\UPSERT-1496065382910.e5e -silent
2017-05-29 09:43:04,608 INFO JSS [Server.1] Javascript (log): Exit code: 0
2017-05-29 09:43:04,608 INFO ProcessTrigger [Server.1] Process trigger JSS UPSERT E5F FILE finished after 1.711s


They both have an exit code of 0 but the failed process takes much less time to complete.

E5DataManager is a part of ECCAIRS (http://eccairsportal.jrc.ec.europa.eu/index.php?id=2) which is used by many countries to record details of accidents.
by (2.7k points)
It seems probable that E5DataManager is hitting some permission problem, but since it's failing to report an error, it's very hard to guess what permission is blocking it.  It really should report some errors and not just exit silently, so that's pretty poor.

You could consider changing the account that the server runs under in the Windows Services panel.  The main requirement is that the account has access to CompleteFTP's program-data directory, i.e.

C:\ProgramData\Enterprise Distributed Technologies\Complete FTP
by (130 points)
Yes, I'm working with the vendor of the Data Manager to configure an account that has sufficient permissions to work successfully.

Since running the FTP server from the console worked perfectly I'm convinced that this is the solution we want so hopefully you'll be hearing from our procurement team. The software will have to go through a security  audit first so I don't know how long it will take.

I just noticed you guys are in Brisbane. Such a small world - I'm from Brisbane on a one-year contract in Montreal. Moving back in October. Crazy!
by (2.7k points)
That's great.  Let us know if you need help with anything else.

Aussie!  Aussie!  Aussie!  :-)

Categories

EnterpriseDT 2020
...