2 Replies Latest reply on Aug 13, 2014 10:09 AM by ps.shi.phil

    Scheduled FTP Voyager task runs 1000+ times per night

    ps.shi.phil

      I'm using FTP Voyager scheduler to connect to a remote SFTP server on a nightly basis and download the contents of a folder, verify the downloads then empty the remote folder using 3 actions within each task.

       

      I have a different task set up for each day of the week as the remote server has a separate folder for each day's files, so essentially 7 different weekly tasks.  Each task is scheduled to execute at 00:15 each night.  Number of workers on each task is set at 2.

       

      The task executes correctly at 00:15 and has usually completed by 00:20, but instead of just ending and waiting until the next scheduled task it reruns the task over and over again until 01:15, sometimes executing over 1300 times per night.  At 01:15 it stops and waits for the next scheduled execution. Manually execute the task and it runs once only. 

       

      I need to resolve this as we need to set up an email alert to a group of users to confirm that the task executed successfully, currently it sends 1000+ emails per night if we enable the alert.

       

      Has anyone else had this weird behaviour? Running v16.1.0.0.

       

      Last part of the log file below, first 2 lines show that it completes the execution then immediately starts again

       

      [12] Wed 13Aug14 01:14:56 - (Task: Redrock_TuesdayData) - Execution successfully completed.

      [12] Wed 13Aug14 01:14:57 - (Task: Redrock_TuesdayData) - Performing scheduled execution of task for Wednesday, August 13, 2014 00:15:00.

      [03] Wed 13Aug14 01:14:57 - Resolving host "***********************"...

      [03] Wed 13Aug14 01:14:57 - Connecting to "*********************" on port 21.

      [03] Wed 13Aug14 01:14:57 - Connected to *******************:21 from ********************:55847.

      [06] Wed 13Aug14 01:14:57 - 220-Celaton inSTREAM FTPS service.

      [06] Wed 13Aug14 01:14:57 - 220-Authorised access only.

      [06] Wed 13Aug14 01:14:57 - 220 Use 'Auth TLS' connection mode.

      [05] Wed 13Aug14 01:14:57 - AUTH TLS

      [06] Wed 13Aug14 01:14:57 - 234 Using authentication type TLS

      [03] Wed 13Aug14 01:14:57 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:14:57 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [05] Wed 13Aug14 01:14:57 - HOST **************************

      [06] Wed 13Aug14 01:14:57 - 500 Syntax error, command unrecognized.

      [03] Wed 13Aug14 01:14:57 - Connected. Logging in to the server.

      [05] Wed 13Aug14 01:14:57 - USER ****************************

      [06] Wed 13Aug14 01:14:57 - 331 Password required for *********************************

      [05] Wed 13Aug14 01:14:57 - PASS ***

      [06] Wed 13Aug14 01:14:57 - 230 Logged on

      [03] Wed 13Aug14 01:14:57 - Login successful.

      [05] Wed 13Aug14 01:14:57 - SYST

      [06] Wed 13Aug14 01:14:57 - 215 UNIX emulated by FileZilla

      [05] Wed 13Aug14 01:14:57 - FEAT

      [06] Wed 13Aug14 01:14:58 - 211-Features:

      [06] Wed 13Aug14 01:14:58 -  MDTM

      [06] Wed 13Aug14 01:14:58 -  REST STREAM

      [06] Wed 13Aug14 01:14:58 -  SIZE

      [06] Wed 13Aug14 01:14:58 -  MODE Z

      [06] Wed 13Aug14 01:14:58 -  MLST type*;size*;modify*;

      [06] Wed 13Aug14 01:14:58 -  MLSD

      [06] Wed 13Aug14 01:14:58 -  AUTH SSL

      [06] Wed 13Aug14 01:14:58 -  AUTH TLS

      [06] Wed 13Aug14 01:14:58 -  PROT

      [06] Wed 13Aug14 01:14:58 -  PBSZ

      [06] Wed 13Aug14 01:14:58 -  UTF8

      [06] Wed 13Aug14 01:14:58 -  CLNT

      [06] Wed 13Aug14 01:14:58 -  MFMT

      [06] Wed 13Aug14 01:14:58 - 211 End

      [03] Wed 13Aug14 01:14:58 - Server supports resume.

      [05] Wed 13Aug14 01:14:58 - CLNT FTP Voyager 16.1.0.0

      [06] Wed 13Aug14 01:14:58 - 200 Don't care

      [05] Wed 13Aug14 01:14:58 - OPTS UTF8 ON

      [06] Wed 13Aug14 01:14:58 - 200 UTF8 mode enabled

      [05] Wed 13Aug14 01:14:58 - PBSZ 0

      [06] Wed 13Aug14 01:14:58 - 200 PBSZ=0

      [05] Wed 13Aug14 01:14:58 - PROT P

      [06] Wed 13Aug14 01:14:58 - 200 Protection level set to P

      [05] Wed 13Aug14 01:14:58 - PWD

      [06] Wed 13Aug14 01:14:58 - 257 "/" is current directory.

      [13] Wed 13Aug14 01:14:58 - (Action: "/Tue" to "D:\PD_Downloads\IMPORT") - Synchronizing local folder "D:\PD_Downloads\IMPORT" with remote folder "/Tue"

      [05] Wed 13Aug14 01:14:58 - MLST /Tue

      [06] Wed 13Aug14 01:14:58 - 250-Listing /Tue

      [06] Wed 13Aug14 01:14:58 -  type=dir;modify=20140730100454; /Tue

      [06] Wed 13Aug14 01:14:58 - 250 End

      [05] Wed 13Aug14 01:14:58 - CWD /Tue

      [06] Wed 13Aug14 01:14:58 - 250 CWD successful. "/Tue" is current directory.

      [05] Wed 13Aug14 01:14:58 - OPTS MODE Z LEVEL 6

      [06] Wed 13Aug14 01:14:58 - 200 MODE Z LEVEL set to 6

      [05] Wed 13Aug14 01:14:58 - MODE Z

      [06] Wed 13Aug14 01:14:58 - 200 MODE set to Z.

      [05] Wed 13Aug14 01:14:58 - PASV

      [06] Wed 13Aug14 01:14:58 - 227 Entering Passive Mode (************************,175)

      [03] Wed 13Aug14 01:14:58 - Opening passive mode data connection to *********************, port 50095.

      [03] Wed 13Aug14 01:14:58 - Negotiating SSL connection with server...

      [05] Wed 13Aug14 01:14:58 - MLSD

      [03] Wed 13Aug14 01:14:58 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:14:58 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [06] Wed 13Aug14 01:14:58 - 150 Connection accepted

      [06] Wed 13Aug14 01:14:58 - 226 Transfer OK

      [03] Wed 13Aug14 01:14:58 - Transferred 0 bytes (0 compressed to 0.00%). 0.00 actual KB/sec, 0.00 effective KB/sec.

      [13] Wed 13Aug14 01:14:58 - (Action: "/Tue" to "D:\PD_Downloads\IMPORT") - Action successfully completed.

      [13] Wed 13Aug14 01:14:58 - (Action: "/Tue" to "D:\PD_downloads\IMPORT") - Synchronizing local folder "D:\PD_downloads\IMPORT" with remote folder "/Tue"

      [05] Wed 13Aug14 01:14:58 - MLST /Tue

      [06] Wed 13Aug14 01:14:58 - 250-Listing /Tue

      [06] Wed 13Aug14 01:14:58 -  type=dir;modify=20140730100454; /Tue

      [06] Wed 13Aug14 01:14:58 - 250 End

      [05] Wed 13Aug14 01:14:58 - PASV

      [06] Wed 13Aug14 01:14:58 - 227 Entering Passive Mode (******************,176)

      [03] Wed 13Aug14 01:14:58 - Opening passive mode data connection to *********************, port 50096.

      [03] Wed 13Aug14 01:14:58 - Negotiating SSL connection with server...

      [05] Wed 13Aug14 01:14:58 - MLSD

      [03] Wed 13Aug14 01:14:58 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:14:58 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [06] Wed 13Aug14 01:14:58 - 150 Connection accepted

      [06] Wed 13Aug14 01:14:58 - 226 Transfer OK

      [03] Wed 13Aug14 01:14:58 - Transferred 0 bytes (0 compressed to 0.00%). 0.00 actual KB/sec, 0.00 effective KB/sec.

      [13] Wed 13Aug14 01:14:59 - (Action: "/Tue" to "D:\PD_downloads\IMPORT") - Action successfully completed.

      [13] Wed 13Aug14 01:14:59 - (Action: "/Tue/*.*") - Deleting remote path: /Tue/*.*

      [05] Wed 13Aug14 01:14:59 - PASV

      [06] Wed 13Aug14 01:14:59 - 227 Entering Passive Mode (*****************,178)

      [03] Wed 13Aug14 01:14:59 - Opening passive mode data connection to **************, port 50098.

      [03] Wed 13Aug14 01:14:59 - Negotiating SSL connection with server...

      [05] Wed 13Aug14 01:14:59 - MLSD

      [03] Wed 13Aug14 01:14:59 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:14:59 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [06] Wed 13Aug14 01:14:59 - 150 Connection accepted

      [06] Wed 13Aug14 01:14:59 - 226 Transfer OK

      [03] Wed 13Aug14 01:14:59 - Transferred 0 bytes (0 compressed to 0.00%). 0.00 actual KB/sec, 0.00 effective KB/sec.

      [13] Wed 13Aug14 01:14:59 - (Action: "/Tue/*.*") - Action successfully completed.

      [12] Wed 13Aug14 01:14:59 - (Task: Redrock_TuesdayData) - Execution successfully completed.

      [12] Wed 13Aug14 01:14:59 - (Task: Redrock_TuesdayData) - Performing scheduled execution of task for Wednesday, August 13, 2014 00:15:00.

      [03] Wed 13Aug14 01:14:59 - Resolving host "**********************************"...

      [03] Wed 13Aug14 01:14:59 - Connecting to "******************" on port 21.

      [03] Wed 13Aug14 01:14:59 - Connected to *****************:21 from ****************************:55851.

      [06] Wed 13Aug14 01:14:59 - 220-************************* FTPS service.

      [06] Wed 13Aug14 01:14:59 - 220-Authorised access only.

      [06] Wed 13Aug14 01:14:59 - 220 Use 'Auth TLS' connection mode.

      [05] Wed 13Aug14 01:14:59 - AUTH TLS

      [06] Wed 13Aug14 01:14:59 - 234 Using authentication type TLS

      [03] Wed 13Aug14 01:14:59 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:14:59 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [05] Wed 13Aug14 01:14:59 - HOST *********************************

      [06] Wed 13Aug14 01:14:59 - 500 Syntax error, command unrecognized.

      [03] Wed 13Aug14 01:14:59 - Connected. Logging in to the server.

      [05] Wed 13Aug14 01:14:59 - USER ********************************

      [06] Wed 13Aug14 01:15:00 - 331 Password required for *****************************************

      [05] Wed 13Aug14 01:15:00 - PASS ***

      [06] Wed 13Aug14 01:15:00 - 230 Logged on

      [03] Wed 13Aug14 01:15:00 - Login successful.

      [05] Wed 13Aug14 01:15:00 - SYST

      [06] Wed 13Aug14 01:15:00 - 215 UNIX emulated by FileZilla

      [05] Wed 13Aug14 01:15:00 - FEAT

      [06] Wed 13Aug14 01:15:00 - 211-Features:

      [06] Wed 13Aug14 01:15:00 -  MDTM

      [06] Wed 13Aug14 01:15:00 -  REST STREAM

      [06] Wed 13Aug14 01:15:00 -  SIZE

      [06] Wed 13Aug14 01:15:00 -  MODE Z

      [06] Wed 13Aug14 01:15:00 -  MLST type*;size*;modify*;

      [06] Wed 13Aug14 01:15:00 -  MLSD

      [06] Wed 13Aug14 01:15:00 -  AUTH SSL

      [06] Wed 13Aug14 01:15:00 -  AUTH TLS

      [06] Wed 13Aug14 01:15:00 -  PROT

      [06] Wed 13Aug14 01:15:00 -  PBSZ

      [06] Wed 13Aug14 01:15:00 -  UTF8

      [06] Wed 13Aug14 01:15:00 -  CLNT

      [06] Wed 13Aug14 01:15:00 -  MFMT

      [06] Wed 13Aug14 01:15:00 - 211 End

      [03] Wed 13Aug14 01:15:00 - Server supports resume.

      [05] Wed 13Aug14 01:15:00 - CLNT FTP Voyager 16.1.0.0

      [06] Wed 13Aug14 01:15:00 - 200 Don't care

      [05] Wed 13Aug14 01:15:00 - OPTS UTF8 ON

      [06] Wed 13Aug14 01:15:00 - 200 UTF8 mode enabled

      [05] Wed 13Aug14 01:15:00 - PBSZ 0

      [06] Wed 13Aug14 01:15:00 - 200 PBSZ=0

      [05] Wed 13Aug14 01:15:00 - PROT P

      [06] Wed 13Aug14 01:15:00 - 200 Protection level set to P

      [05] Wed 13Aug14 01:15:00 - PWD

      [06] Wed 13Aug14 01:15:00 - 257 "/" is current directory.

      [13] Wed 13Aug14 01:15:00 - (Action: "/Tue" to "D:\PD_Downloads\IMPORT") - Synchronizing local folder "D:\PD_Downloads\IMPORT" with remote folder "/Tue"

      [05] Wed 13Aug14 01:15:00 - MLST /Tue

      [06] Wed 13Aug14 01:15:00 - 250-Listing /Tue

      [06] Wed 13Aug14 01:15:00 -  type=dir;modify=20140730100454; /Tue

      [06] Wed 13Aug14 01:15:00 - 250 End

      [05] Wed 13Aug14 01:15:00 - QUIT

      [05] Wed 13Aug14 01:15:00 - QUIT

      [06] Wed 13Aug14 01:15:00 - 221 Goodbye

      [05] Wed 13Aug14 01:15:00 - CWD /Tue

      [06] Wed 13Aug14 01:15:00 - 221 Goodbye

      [06] Wed 13Aug14 01:15:00 - 250 CWD successful. "/Tue" is current directory.

      [05] Wed 13Aug14 01:15:00 - OPTS MODE Z LEVEL 6

      [06] Wed 13Aug14 01:15:00 - 200 MODE Z LEVEL set to 6

      [05] Wed 13Aug14 01:15:00 - MODE Z

      [06] Wed 13Aug14 01:15:00 - 200 MODE set to Z.

      [05] Wed 13Aug14 01:15:00 - PASV

      [06] Wed 13Aug14 01:15:00 - 227 Entering Passive Mode

      [03] Wed 13Aug14 01:15:00 - Opening passive mode data connection to *******************, port 50001.

      [03] Wed 13Aug14 01:15:00 - Negotiating SSL connection with server...

      [05] Wed 13Aug14 01:15:00 - MLSD

      [03] Wed 13Aug14 01:15:00 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:15:00 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [06] Wed 13Aug14 01:15:00 - 150 Connection accepted

      [06] Wed 13Aug14 01:15:00 - 226 Transfer OK

      [03] Wed 13Aug14 01:15:00 - Transferred 0 bytes (0 compressed to 0.00%). 0.00 actual KB/sec, 0.00 effective KB/sec.

      [13] Wed 13Aug14 01:15:00 - (Action: "/Tue" to "D:\PD_Downloads\IMPORT") - Action successfully completed.

      [13] Wed 13Aug14 01:15:00 - (Action: "/Tue" to "D:\PD_downloads\IMPORT") - Synchronizing local folder "D:\PD_downloads\IMPORT" with remote folder "/Tue"

      [05] Wed 13Aug14 01:15:00 - MLST /Tue

      [06] Wed 13Aug14 01:15:00 - 250-Listing /Tue

      [06] Wed 13Aug14 01:15:00 -  type=dir;modify=20140730100454; /Tue

      [06] Wed 13Aug14 01:15:00 - 250 End

      [05] Wed 13Aug14 01:15:00 - PASV

      [06] Wed 13Aug14 01:15:00 - 227 Entering Passive Mode

      [03] Wed 13Aug14 01:15:00 - Opening passive mode data connection to ********************, port 50002.

      [03] Wed 13Aug14 01:15:00 - Negotiating SSL connection with server...

      [05] Wed 13Aug14 01:15:00 - MLSD

      [03] Wed 13Aug14 01:15:00 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:15:00 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [06] Wed 13Aug14 01:15:00 - 150 Connection accepted

      [06] Wed 13Aug14 01:15:00 - 226 Transfer OK

      [03] Wed 13Aug14 01:15:00 - Transferred 0 bytes (0 compressed to 0.00%). 0.00 actual KB/sec, 0.00 effective KB/sec.

      [13] Wed 13Aug14 01:15:00 - (Action: "/Tue" to "D:\PD_downloads\IMPORT") - Action successfully completed.

      [13] Wed 13Aug14 01:15:00 - (Action: "/Tue/*.*") - Deleting remote path: /Tue/*.*

      [05] Wed 13Aug14 01:15:01 - PASV

      [06] Wed 13Aug14 01:15:01 - 227 Entering Passive Mode

      [03] Wed 13Aug14 01:15:01 - Opening passive mode data connection to *********************, port 50003.

      [03] Wed 13Aug14 01:15:01 - Negotiating SSL connection with server...

      [05] Wed 13Aug14 01:15:01 - MLSD

      [03] Wed 13Aug14 01:15:01 - SSL connection established. All transactions are now secure.

      [03] Wed 13Aug14 01:15:01 - Encryption cipher: 128 bit IDEA; Version: TLSv1/SSLv3.

      [06] Wed 13Aug14 01:15:01 - 150 Connection accepted

      [06] Wed 13Aug14 01:15:01 - 226 Transfer OK

      [03] Wed 13Aug14 01:15:01 - Transferred 0 bytes (0 compressed to 0.00%). 0.00 actual KB/sec, 0.00 effective KB/sec.

      [13] Wed 13Aug14 01:15:01 - (Action: "/Tue/*.*") - Action successfully completed.

      [12] Wed 13Aug14 01:15:01 - (Task: Redrock_TuesdayData) - Execution successfully completed.

      [12] Wed 13Aug14 01:15:01 - (Task: Redrock_TuesdayData) - Next scheduled execution on Wednesday, August 20, 2014 00:15:00

      [05] Wed 13Aug14 01:15:04 - QUIT

      [06] Wed 13Aug14 01:15:04 - 221 Goodbye