Same Job (write file to SFTP) triggered more than once from Redis queue connection

[Rafeethu]

• Laravel Version: 6.20.24

• PHP Version: 7.4.12

• Database Driver & Version: mysql 8

• machine : AWS EC2 ubuntu 20.04

Description:

I'm using a Job to write two files to SFTP path. My queue driver is redis which is monitored by supervisor. once in a while when
I trigger the job from controller, the relevant Job is triggered more than once simultaneously which causes some error in writing content to SFTP path and it fails.

The content is not written to path.

My EC2 instance is in aws Canada region and writing to a SFTP server in Singapore region.

The controller which triggers the job.

dispatch(new \App\Jobs\GeneratePdf($file, Auth::id(), $xml_content));

In the Job I have set public $timeout = 60 * 60;

i'm passing the content via parameter. pls see the que log below.

[2021-04-21 13:37:50][IqtRktkpROMBFqBuVPdTooZnMob4RsiC] Processed:  App\Jobs\UpdateAssetVersionFileChecksum
[2021-04-21 13:43:04][adfOBwZvIg30V7HEKGmBFSo7DBaxqaL2] Processing: App\Jobs\GeneratePdf
[2021-04-21 13:43:06][adfOBwZvIg30V7HEKGmBFSo7DBaxqaL2] Processed:  App\Jobs\GeneratePdf
[2021-04-21 13:46:17][cQ6bmeChk9iEXeWWoc4Kk7ZLwqfZZzk9] Processing: App\Jobs\GeneratePdf
[2021-04-21 13:46:20][cQ6bmeChk9iEXeWWoc4Kk7ZLwqfZZzk9] Processed:  App\Jobs\GeneratePdf
[2021-04-21 14:47:31][RUfQNpfSQq6dVa0Ca1sxyaWA9G2LGlv4] Processing: App\Jobs\GeneratePdf
[2021-04-21 14:47:31][RUfQNpfSQq6dVa0Ca1sxyaWA9G2LGlv4] Processing: App\Jobs\GeneratePdf
[2021-04-21 14:47:37][RUfQNpfSQq6dVa0Ca1sxyaWA9G2LGlv4] Processed:  App\Jobs\GeneratePdf
[2021-04-21 14:48:28][Jyj2Pl2wLHZylPGfCbRBnhf79X9wUkgn] Processing: App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 14:48:41][Jyj2Pl2wLHZylPGfCbRBnhf79X9wUkgn] Processed:  App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 14:50:13][kf6teizlLWPEWUMXW1NdaaPIdUpgeIV5] Processing: App\Jobs\GeneratePdf
[2021-04-21 14:50:13][kf6teizlLWPEWUMXW1NdaaPIdUpgeIV5] Processing: App\Jobs\GeneratePdf
[2021-04-21 14:50:19][kf6teizlLWPEWUMXW1NdaaPIdUpgeIV5] Processed:  App\Jobs\GeneratePdf
[2021-04-21 14:51:04][8A7JkCOtMVgJPbh76jLKGureb93FeyKs] Processing: App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 14:51:18][8A7JkCOtMVgJPbh76jLKGureb93FeyKs] Processed:  App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 14:53:29][KDgb3aCRYBkMwWokFflugfeTDQd9R2k4] Processing: App\Jobs\GeneratePdf
[2021-04-21 14:53:30][KDgb3aCRYBkMwWokFflugfeTDQd9R2k4] Processing: App\Jobs\GeneratePdf
[2021-04-21 14:53:35][KDgb3aCRYBkMwWokFflugfeTDQd9R2k4] Processed:  App\Jobs\GeneratePdf
[2021-04-21 14:54:23][OocZLXI2ZAtHth8e0oi1EXr8378O4ga0] Processing: App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 14:54:37][OocZLXI2ZAtHth8e0oi1EXr8378O4ga0] Processed:  App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 14:57:39][EZlKqJ5u0IhF9CObeXMBtlxPR8Km4uQZ] Processing: App\Jobs\GeneratePdf
[2021-04-21 14:57:41][EZlKqJ5u0IhF9CObeXMBtlxPR8Km4uQZ] Processed:  App\Jobs\GeneratePdf
[2021-04-21 14:58:27][Oy6FESFMbg0R495l065CJwCD8UUNesE3] Processing: App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 14:58:40][Oy6FESFMbg0R495l065CJwCD8UUNesE3] Processed:  App\Jobs\CopyPdfFromFtpToDam
[2021-04-21 15:06:29][fJvhpp2kKMzdAMfMnHWUlZQi4DsLDgPI] Processing: App\Jobs\GeneratePdf
[2021-04-21 15:06:32][fJvhpp2kKMzdAMfMnHWUlZQi4DsLDgPI] Processed:  App\Jobs\GeneratePdf

in this you can see that ques with id RUfQNpfSQq6dVa0Ca1sxyaWA9G2LGlv4, kf6teizlLWPEWUMXW1NdaaPIdUpgeIV5 etc are triggered twice and marked as processed only once but it's thrown some SFTP connection closed prematurely error and the file is not written to SFTP path.

After this error normally the SFTP is not working until I restart the queue, I'm unable to find any clue on what's causing this issue.

If it's a SFTP writing issue why the job is not marked as failed

Pls find the error log when this error occurs.

[2021-04-29 07:04:44] local.ERROR: Connection closed prematurely {"exception":"[object] (ErrorException(code: 0): Connection closed prematurely at /var/www/dam-demo/vendor/phpseclib/phpseclib>
[stacktrace]
#0 [internal function]: Illuminate\Foundation\Bootstrap\HandleExceptions->handleError()
#1 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3368): user_error()
#2 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#3 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#4 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#5 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#6 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#7 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#8 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#9 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#10 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#11 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#12 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#13 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
....
....
#240 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#241 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#242 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#243 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3479): phpseclib\Net\SSH2->_get_binary_packet()
#244 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3454): phpseclib\Net\SSH2->_filter()
#245 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SSH2.php(3725): phpseclib\Net\SSH2->_get_binary_packet()
#246 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SFTP.php(3073): phpseclib\Net\SSH2->_get_channel_packet()
#247 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SFTP.php(1391): phpseclib\Net\SFTP->_get_sftp_packet()
#248 /var/www/dam-demo/vendor/phpseclib/phpseclib/phpseclib/Net/SFTP.php(1280): phpseclib\Net\SFTP->_stat()
#249 /var/www/dam-demo/vendor/league/flysystem-sftp/src/SftpAdapter.php(548): phpseclib\Net\SFTP->stat()
#250 /var/www/dam-demo/vendor/league/flysystem-sftp/src/SftpAdapter.php(539): League\Flysystem\Sftp\SftpAdapter->getMetadata()
#251 /var/www/dam-demo/vendor/league/flysystem/src/Filesystem.php(57): League\Flysystem\Sftp\SftpAdapter->has()
#252 /var/www/dam-demo/vendor/league/flysystem/src/Filesystem.php(98): League\Flysystem\Filesystem->has()
#253 /var/www/dam-demo/vendor/laravel/framework/src/Illuminate/Filesystem/FilesystemAdapter.php(225): League\Flysystem\Filesystem->put()

Steps To Reproduce:

[Rafeethu]

I'm doing some more analysis from SFTP server end to check is it related to file getting removed before the SFTP writing process completed. just a guess. post more update here once analysed the SFTP server.

[driesvints]

Hey there,

Can you first please try one of the support channels below? If you can actually identify this as a bug, feel free to report back and I'll gladly help you out and re-open this issue.

• Laracasts Forums
• Laravel.io Forums
• StackOverflow
• Discord
• Larachat
• IRC

Thanks!