Odd Behavior with rclone from a BASH Script

Help and Support
1

What is the problem you are having with rclone?

I'm not sure at all that this is a problem with rclone, but...

When I run rclone from a script under Linux Mint 19.3 I get some odd results. On the first run, rclone creates the folder and copies the files from the source to my Google Drive just as it should. On the second run of the script, however, instead of updating the files inside the folder, rclone creates a new folder of the same name and copies the files into that. On subsequent runs of the script, rclone just creates more and more folders full of duplicate files.

Now here is the really odd part...

If I copy and paste the command line (see below) from the script to a terminal command prompt, everything works just fine. The first copy and paste creates the folder and copies the files. Subsequent copy and pastes updates the files inside the remote folder.

While I've written many scripts to do tasks, I am not an expert. I suspect that something is getting passed to rclone from the script that is not a part of the actual command line.

What is your rclone version (output from rclone version)

1.51

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Linux Mint 19.3 64-bit with Cinnamon

Which cloud storage system are you using? (eg Google Drive)

Google Drive

The command you were trying to run (eg rclone copy /tmp remote:tmp)

The Script:

# 
rclone sync -vv /home/melodee/TestFolder remote:home/TestFolder
#

The Command Cut From The Script and Pasted To The Terminal:

rclone sync -vv /home/melodee/TestFolder remote:home/TestFolder

The rclone config contents with secrets removed.

Not sure what to remove and not sure it's relevant here.

A log from the command with the -vv flag

Doesn't seem relevant here

I've tried stripping the script down to just the command line with a at the end and no comments at all. Same results. I even tried removing the at the end. Same results.

I've edited the script in several different text editors and IDE front ends. Same Results.

I've tried changing folder names. Same results.

I'm out of ideas!

Thanks in advance!

Take Care & 73
de KC6UFM
Charles

2

What's your rclone.conf without passwords and such as it's relevant to your question.

The log file would also help show what's going on.

Also, that's a few versions behind, you want to update.

3

This would be helpful. Just XXX out anything which looks like a random string of numbers/letters.

4

As it seems I was wrong on the config and log files not being all that relevant, here they are:

First is the config file. What appeared to be "secret" was replaced with four * in the below:

[remote]
type = drive
client_id = 
client_secret = 
token = {"access_token":"****","token_type":"Bearer","refresh_token":"****","expiry":"2020-09-26T22:57:26.854551009-07:00"}
root_folder_id = ****

Next is the log file for the FIRST run from the script:

2020/09/27 10:12:41 DEBUG : rclone: Version "v1.51.0" starting with parameters ["rclone" "sync" "-vv" "--log-file" "first_script.log" "/home/melodee/TestFolder" "remote:home/TestFolder\r"]
2020/09/27 10:12:41 DEBUG : Using config file from "/home/melodee/.rclone.conf"
2020/09/27 10:12:41 DEBUG : remote: Loaded invalid token from config file - ignoring
2020/09/27 10:12:41 DEBUG : remote: Saved new token in config file
2020/09/27 10:12:43 INFO  : Google drive root 'home/TestFolder
': Waiting for checks to finish
2020/09/27 10:12:43 INFO  : Google drive root 'home/TestFolder
': Waiting for transfers to finish
2020/09/27 10:12:45 DEBUG : File 01.txt: MD5 = 65a3701ae7f82763875daed42736e6a4 OK
2020/09/27 10:12:45 INFO  : File 01.txt: Copied (new)
2020/09/27 10:12:46 DEBUG : File 02.odt: MD5 = ae130e1e3f752bb62e607db82635ea83 OK
2020/09/27 10:12:46 INFO  : File 02.odt: Copied (new)
2020/09/27 10:12:47 DEBUG : File 04.doc: MD5 = 5bf9484abfe7a5c62c3dc93f70bd1680 OK
2020/09/27 10:12:47 INFO  : File 04.doc: Copied (new)
2020/09/27 10:12:47 DEBUG : File 05.odt: MD5 = 5e4ec10eae225c864f72f84cded5ff8c OK
2020/09/27 10:12:47 INFO  : File 05.odt: Copied (new)
2020/09/27 10:12:52 DEBUG : File 03.pdf: MD5 = 8f0b38633524f9cc873f12657b9465c1 OK
2020/09/27 10:12:52 INFO  : File 03.pdf: Copied (new)
2020/09/27 10:13:04 DEBUG : File 06.pdf: MD5 = 91969bce281fafce9a17cf5fff36f06a OK
2020/09/27 10:13:04 INFO  : File 06.pdf: Copied (new)
2020/09/27 10:13:04 INFO  : Waiting for deletions to finish
2020/09/27 10:13:04 INFO  : 
Transferred:   	    1.241M / 1.241 MBytes, 100%, 60.131 kBytes/s, ETA 0s
Transferred:            6 / 6, 100%
Elapsed time:        21.1s

2020/09/27 10:13:04 DEBUG : 13 go routines active
2020/09/27 10:13:04 DEBUG : rclone: Version "v1.51.0" finishing with parameters ["rclone" "sync" "-vv" "--log-file" "first_script.log" "/home/melodee/TestFolder" "remote:home/TestFolder\r"]

Here is the log from the SECOND (and same for additional) run of the script:

2020/09/27 10:14:10 DEBUG : rclone: Version "v1.51.0" starting with parameters ["rclone" "sync" "-vv" "--log-file" "second_script.log" "/home/melodee/TestFolder" "remote:home/TestFolder\r"]
2020/09/27 10:14:10 DEBUG : Using config file from "/home/melodee/.rclone.conf"
2020/09/27 10:14:11 INFO  : Google drive root 'home/TestFolder
': Waiting for checks to finish
2020/09/27 10:14:11 INFO  : Google drive root 'home/TestFolder
': Waiting for transfers to finish
2020/09/27 10:14:13 DEBUG : File 01.txt: MD5 = 65a3701ae7f82763875daed42736e6a4 OK
2020/09/27 10:14:13 INFO  : File 01.txt: Copied (new)
2020/09/27 10:14:14 DEBUG : File 04.doc: MD5 = 5bf9484abfe7a5c62c3dc93f70bd1680 OK
2020/09/27 10:14:14 INFO  : File 04.doc: Copied (new)
2020/09/27 10:14:15 DEBUG : File 02.odt: MD5 = ae130e1e3f752bb62e607db82635ea83 OK
2020/09/27 10:14:15 INFO  : File 02.odt: Copied (new)
2020/09/27 10:14:15 DEBUG : File 05.odt: MD5 = 5e4ec10eae225c864f72f84cded5ff8c OK
2020/09/27 10:14:15 INFO  : File 05.odt: Copied (new)
2020/09/27 10:14:24 DEBUG : File 03.pdf: MD5 = 8f0b38633524f9cc873f12657b9465c1 OK
2020/09/27 10:14:24 INFO  : File 03.pdf: Copied (new)
2020/09/27 10:14:31 DEBUG : File 06.pdf: MD5 = 91969bce281fafce9a17cf5fff36f06a OK
2020/09/27 10:14:31 INFO  : File 06.pdf: Copied (new)
2020/09/27 10:14:31 INFO  : Waiting for deletions to finish
2020/09/27 10:14:31 INFO  : 
Transferred:   	    1.241M / 1.241 MBytes, 100%, 65.147 kBytes/s, ETA 0s
Transferred:            6 / 6, 100%
Elapsed time:        19.5s

2020/09/27 10:14:31 DEBUG : 11 go routines active
2020/09/27 10:14:31 DEBUG : rclone: Version "v1.51.0" finishing with parameters ["rclone" "sync" "-vv" "--log-file" "second_script.log" "/home/melodee/TestFolder" "remote:home/TestFolder\r"]

Here is the log for the FIRST run from the command line:

2020/09/27 10:15:58 DEBUG : rclone: Version "v1.51.0" starting with parameters ["rclone" "sync" "-vv" "--log-file" "first_command.log" "/home/melodee/TestFolder" "remote:home/TestFolder"]
2020/09/27 10:15:58 DEBUG : Using config file from "/home/melodee/.rclone.conf"
2020/09/27 10:15:59 INFO  : Google drive root 'home/TestFolder': Waiting for checks to finish
2020/09/27 10:15:59 INFO  : Google drive root 'home/TestFolder': Waiting for transfers to finish
2020/09/27 10:16:01 DEBUG : File 01.txt: MD5 = 65a3701ae7f82763875daed42736e6a4 OK
2020/09/27 10:16:01 INFO  : File 01.txt: Copied (new)
2020/09/27 10:16:02 DEBUG : File 04.doc: MD5 = 5bf9484abfe7a5c62c3dc93f70bd1680 OK
2020/09/27 10:16:02 INFO  : File 04.doc: Copied (new)
2020/09/27 10:16:02 DEBUG : File 02.odt: MD5 = ae130e1e3f752bb62e607db82635ea83 OK
2020/09/27 10:16:02 INFO  : File 02.odt: Copied (new)
2020/09/27 10:16:03 DEBUG : File 05.odt: MD5 = 5e4ec10eae225c864f72f84cded5ff8c OK
2020/09/27 10:16:03 INFO  : File 05.odt: Copied (new)
2020/09/27 10:16:15 DEBUG : File 03.pdf: MD5 = 8f0b38633524f9cc873f12657b9465c1 OK
2020/09/27 10:16:15 INFO  : File 03.pdf: Copied (new)
2020/09/27 10:16:19 DEBUG : File 06.pdf: MD5 = 91969bce281fafce9a17cf5fff36f06a OK
2020/09/27 10:16:19 INFO  : File 06.pdf: Copied (new)
2020/09/27 10:16:19 INFO  : Waiting for deletions to finish
2020/09/27 10:16:19 INFO  : 
Transferred:   	    1.241M / 1.241 MBytes, 100%, 64.580 kBytes/s, ETA 0s
Transferred:            6 / 6, 100%
Elapsed time:        19.6s

2020/09/27 10:16:19 DEBUG : 11 go routines active
2020/09/27 10:16:19 DEBUG : rclone: Version "v1.51.0" finishing with parameters ["rclone" "sync" "-vv" "--log-file" "first_command.log" "/home/melodee/TestFolder" "remote:home/TestFolder"]

And here is the log for the SECOND (and later) runs from the command line:

2020/09/27 10:17:05 DEBUG : rclone: Version "v1.51.0" starting with parameters ["rclone" "sync" "-vv" "--log-file" "second_command.log" "/home/melodee/TestFolder" "remote:home/TestFolder"]
2020/09/27 10:17:05 DEBUG : Using config file from "/home/melodee/.rclone.conf"
2020/09/27 10:17:05 INFO  : Google drive root 'home/TestFolder': Waiting for checks to finish
2020/09/27 10:17:05 DEBUG : File 01.txt: Size and modification time the same (differ by -374.326µs, within tolerance 1ms)
2020/09/27 10:17:05 DEBUG : File 01.txt: Unchanged skipping
2020/09/27 10:17:05 DEBUG : File 04.doc: Size and modification time the same (differ by 0s, within tolerance 1ms)
2020/09/27 10:17:05 DEBUG : File 04.doc: Unchanged skipping
2020/09/27 10:17:05 DEBUG : File 03.pdf: Size and modification time the same (differ by 0s, within tolerance 1ms)
2020/09/27 10:17:05 DEBUG : File 03.pdf: Unchanged skipping
2020/09/27 10:17:05 DEBUG : File 02.odt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2020/09/27 10:17:05 DEBUG : File 02.odt: Unchanged skipping
2020/09/27 10:17:05 DEBUG : File 05.odt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2020/09/27 10:17:05 DEBUG : File 05.odt: Unchanged skipping
2020/09/27 10:17:05 DEBUG : File 06.pdf: Size and modification time the same (differ by 0s, within tolerance 1ms)
2020/09/27 10:17:05 DEBUG : File 06.pdf: Unchanged skipping
2020/09/27 10:17:05 INFO  : Google drive root 'home/TestFolder': Waiting for transfers to finish
2020/09/27 10:17:05 INFO  : Waiting for deletions to finish
2020/09/27 10:17:05 INFO  : 
Transferred:   	         0 / 0 Bytes, -, 0 Bytes/s, ETA -
Checks:                 6 / 6, 100%
Elapsed time:         0.0s

2020/09/27 10:17:05 DEBUG : 5 go routines active
2020/09/27 10:17:05 DEBUG : rclone: Version "v1.51.0" finishing with parameters ["rclone" "sync" "-vv" "--log-file" "second_command.log" "/home/melodee/TestFolder" "remote:home/TestFolder"]

For easy reference, here again is the script:

#
rclone sync -vv --log-file second_command.log /home/melodee/TestFolder remote:home/TestFolder
#

And here is the command used in the terminal, cut and pasted from the script:

rclone sync -vv --log-file second_command.log /home/melodee/TestFolder remote:home/TestFolder

Thanks again!

5

What's the issue you see between those two runs as they look good to me?

6

As in the original posting above, when running from the script, rclone creates a new folder and copies the files there on every run, regardless if the files have changed or not.

When running from the command line manually, rclone behaves as it should, only copying changed files.

7

Your script has an extra character on the end of the folder name. The \r looks to be a line feed or something.

8

Ah Ha!

I missed that \r escape sequence in the log files! Thank you for spotting that!

The /r (hex 0D) is indeed the carriage return function. Most text editors pair that with a /l (hex 0A) line feed to make the files compatible with pretty much all computers. The host system is supposed to parse those out as needed. Linux passes both to the application. Not sure that's a good idea, but it is the way it is.

The application is tasked with doing the parsing.

Obviously, rclone 1.51 is not dropping the /r and acting on it. Or at least trying to.

I used a hex editor to look at the script file and removed all of the 0D occurrences. The file will still load and look right in a text editor, but the script now works as it should.

Thanks again for the sharp eyes!

Perhaps a better coder than I can look at the rclone source and fix the command line parsing to toss the \r (x0D) characters.

9

No, that's not how it works, and never has worked. The "end of line" sequence can be different between operating systems. For an OS like DOS (and now Windows) you have 0x0d 0x0a as the sequence. Unix uses 0x0a. Historical MacOS used 0x0d as the sequence

If you open a Unix text file in Notepad on Windows you'll get a single line of output. If you open a Windows text file in Unix with cat then it might look right, 'cos the CR character doesn't hurt. But if you create a shell script beginning #!/bin/sh<CR> then Unix will complain becuase it looks for a program called /bin/sh<CR> which doesn't exist.

What makes it more complicated is some applications hide this information. eg vim will open a Windows file in "DOS mode" and write it back out in DOS mode. Similarly Wordpad on Windows handles Unix EOL normally.

Back in the long distant past, the "FTP" file transfer system had two modes; "TEXT" mode and "BINARY" mode. TEXT mode was meant to try and help with the conversion of all these different end-of-line sequences to make it easier. Modern file transfers (eg sftp or samba) don't have this. So if you create the file with the wrong line endings then it'll be stored with the wrong endings.

There are programs such as dos2unix and unix2dos to handle end-of-line conversions.

But it is most definitely not the application's responsibility to handle "foreign" end of line sequences. rclone could though, and may be worth a "request for enhancement"...

5 Likes
10

Out of all the posts I’ve seen , this is the first one of its kind.

11

Ah . . brings back memories . .

12

You definitely deserve a "log reader of the month" award for that :slight_smile:

13

I have my gold star on today :slight_smile:

14

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.