login fail, but runs multiple downloads :: Support Forum

fuzzy50
Joined:: 2017-08-04
Posts:: 3
Location:: US

login fail, but runs multiple downloads

2022-01-24 15:35

I run

echo open sftp://myuser:mypass@redhat7server.com>files\get.scr
echo cd /opt/csv>>files\get.scr
echo option transfer ascii>>files\get.scr
echo get my.csv>>files\get.scr
echo close>>files\get.scr
echo exit>>files\get.scr

Then I run:

WinSCP.com /script="get.scr"  /log="winscp_debug.log" /loglevel=0 > sendfile.log  2>&1

On Redhat side I get:

Jan 24 07:20:02 redhat7server sshd[24131]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=myhost  user=myuser
Jan 24 07:20:02 redhat7server sshd[24131]: Accepted password for myuser from myip port 59506 ssh2
Jan 24 07:20:02 redhat7server sshd[24131]: pam_unix(sshd:session): session opened for user ldapcsv by (uid=0)
Jan 24 07:20:02 redhat7server sshd[24131]: pam_unix(sshd:session): session closed for user ldapcsv

In the debug log, it appears to download the file multiple times. Yet, the file is not on disk. I see multiple

Line 7554: . 2022-01-19 07:20:02.208 Copying "/opt/csv/my.csv" to local directory started.
Line 7723: . 2022-01-20 07:20:02.214 Copying "/opt/csv/my.csv" to local directory started.
Line 7892: . 2022-01-21 07:20:02.233 Copying "/opt/csv/my.csv" to local directory started.

I reran the job and it worked and it appears to only login once this time:

Jan 24 08:57:42 myredhat7 sshd[7330]: Accepted password for myuser  from myip port 59710 ssh2
Jan 24 08:57:42 myredhat7 sshd[7330]: pam_unix(sshd:session): session opened for user myuser by (uid=0)
Jan 24 08:57:43 myredhat7 sshd[7330]: pam_unix(sshd:session): session closed for user myuser

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,517
Location:: Prague, Czechia

Re: login fail, but runs multiple downloads

2022-01-27

Please attach complete WinSCP log.

Reply with quote

fuzzy50
Joined:: 2017-08-04
Posts:: 3
Location:: US

Re: login fail, but runs multiple downloads

2022-01-27 13:49

I have attached the log.

winscp_debug.log (634.29 KB, Private file)

Reply with quote

martin◆ Site Admin

Re: login fail, but runs multiple downloads

2022-02-01

There are over 50 sessions in that log. What should I look for? Can you post logs of two sessions only?
1) Log of session where there were three transfers, although there should have been one only.
2) Log of subsequent rerun that went as expected.

Reply with quote

fuzzy50
Joined:: 2017-08-04
Posts:: 3
Location:: US

Re: login fail, but runs multiple downloads

2022-02-01 15:15

I modified the log. The job runs at 07:20. My second attempt to get the file was at 08:57.

Actually, I see the first attempt never tried a get on the file. Something happened during the script creation:

< 2022-01-24 07:20:03.090 Script: transfer        ascii     
> 2022-01-24 07:20:03.090 Script: close

Maybe virus scanner? I don't know, we have painfully slow VM's sometimes. I guess the solution is to create the script once and not create it on the fly.

winscp_debug.log (20.35 KB)

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,517
Location:: Prague, Czechia

Re: login fail, but runs multiple downloads

2022-02-03

I cannot imagine what might go wrong with the simple batch file from your original post.
Is it really that simple?
Did you try to preserve/log contents of the batch file just before you run winscp.com, to double check that the contents is as you expected?
If the commands are fixed this way, why do you even generate the script?
If you wanted to avoid having yet another script file (beside the batch file), you can instead specify the commands on WinSCP command-line.
Example here: https://winscp.net/eng/docs/faq_batch_file#newline_escaping
This way, WinSCP will log the commandline including the commands, what will ease debugging.

Reply with quote

login fail, but runs multiple downloads