Bug / AFP Cache only share - running mover

[madburg]

Steps to reproduce:

 

Create a cache only share, and set to export via AFP as well as SMB. In my example the cache only AFP/SMB share is named "Test Movies"

Run mover you will receive rsync errors.

Versus a SMB cache only share which mover (rsync) skips the directory/folder altogether.

 

Attached: Screenshot of the AFP cache only share setting via web console. The same share '.cfg' file.

 

syslog snippet:

 

Sep 12 10:54:44 PNTower logger: mover started

Sep 12 10:54:44 PNTower logger: skipping Backup/

Sep 12 10:54:44 PNTower logger: skipping Handbrake/

Sep 12 10:54:44 PNTower logger: skipping NZBDrop/

Sep 12 10:54:44 PNTower logger: moving Test Movies/

Sep 12 10:54:44 PNTower logger: ./Test Movies/Mickey Mouse Clubhouse/Season 03/Mickey Mouse Clubhouse - s03e31 - Donald Hatches an Egg - HD TV.nfo-orig

Sep 12 10:54:44 PNTower logger: .d..t...... ./

Sep 12 10:54:44 PNTower shfs/user0: shfs_mkdir: assign_disk: Test Movies/Mickey Mouse Clubhouse (28) No space left on device

Sep 12 10:54:44 PNTower logger: .d..t...... Test Movies/

Sep 12 10:54:44 PNTower logger: cd+++++++++ Test Movies/Mickey Mouse Clubhouse/

Sep 12 10:54:44 PNTower logger: rsync: recv_generator: mkdir "/mnt/user0/Test Movies/Mickey Mouse Clubhouse" failed: No space left on device (28)

Sep 12 10:54:44 PNTower logger: *** Skipping any contents from this failed directory ***

Sep 12 10:54:44 PNTower logger: rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1042) [sender=3.0.7]

Sep 12 10:54:44 PNTower logger: ./Test Movies/Mickey Mouse Clubhouse/Season 03/Mickey Mouse Clubhouse - s03e30 - Aye Aye Captain Mickey - HD TV.nfo-orig

Sep 12 10:54:44 PNTower shfs/user0: shfs_mkdir: assign_disk: Test Movies/Mickey Mouse Clubhouse (28) No space left on device

Sep 12 10:54:44 PNTower logger: cd+++++++++ Test Movies/Mickey Mouse Clubhouse/

Sep 12 10:54:44 PNTower logger: rsync: recv_generator: mkdir "/mnt/user0/Test Movies/Mickey Mouse Clubhouse" failed: No space left on device (28)

Sep 12 10:54:44 PNTower logger: *** Skipping any contents from this failed directory ***

Sep 12 10:54:44 PNTower logger: rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1042) [sender=3.0.7]

Sep 12 10:54:44 PNTower logger: ./Test Movies/Mickey Mouse Clubhouse/Season 03/Mickey Mouse Clubhouse - s03e31 - Donald Hatches an Egg - HD TV.mkv

Sep 12 10:54:44 PNTower shfs/user0: shfs_mkdir: assign_disk: Test Movies/Mickey Mouse Clubhouse (28) No space left on device

Sep 12 10:54:44 PNTower logger: cd+++++++++ Test Movies/Mickey Mouse Clubhouse/

Sep 12 10:54:44 PNTower logger: rsync: recv_generator: mkdir "/mnt/user0/Test Movies/Mickey Mouse Clubhouse" failed: No space left on device (28)

Sep 12 10:54:44 PNTower logger: *** Skipping any contents from this failed directory ***

Sep 12 10:54:44 PNTower logger: rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1042) [sender=3.0.7]

Sep 12 10:54:44 PNTower logger: ./Test Movies/Mickey Mouse Clubhouse/Season 03/Mickey Mouse Clubhouse - s03e30 - Aye Aye Captain Mickey - HD TV.mkv

Sep 12 10:54:44 PNTower shfs/user0: shfs_mkdir: assign_disk: Test Movies/Mickey Mouse Clubhouse (28) No space left on device

Sep 12 10:54:44 PNTower logger: cd+++++++++ Test Movies/Mickey Mouse Clubhouse/

Sep 12 10:54:44 PNTower logger: rsync: recv_generator: mkdir "/mnt/user0/Test Movies/Mickey Mouse Clubhouse" failed: No space left on device (28)

Sep 12 10:54:44 PNTower logger: *** Skipping any contents from this failed directory ***

Sep 12 10:54:44 PNTower logger: rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1042) [sender=3.0.7]

Sep 12 10:54:44 PNTower logger: skipping iDownloads/

Sep 12 10:54:44 PNTower logger: mover finished

 

 

In addition large moves of data from the cache to the array via web console by manually invoking mover, the web page never refreshes back once mover is finished. Unlike when mover just has a small data set to move.

 

....Update post with correct .cfg attachment

Test_Movies.cfg

[dgaschk]

The screenshot does not match the description or the cfg. It appears the the log was taken when the share was not set to cache-only and the the min free space setting caused the failures.

[madburg]

You are correct (thanks), I was running various test to try to figure out if this was being caused by cache only share with AFP or not, and it is being caused by a cache only share with AFP. I accidently attached the wrong screenshoot and .cfg (I took several during my tests). I caught the wrong .cfg file earlier today and updated it, and you have now pointed out I had the wrong screenshot uploaded as well. I have just uploaded the correct one. This is very repeatable for me. Hope someone else can test as well.

 

It is very simple to set this up, as long as you have a cache drive and AFP enabled.

Just create a Cache Only share and enable AFP on it (or stop the array and copy that .cfg to your shares folder, restart the array) .

Have a terminal session open with a Tail and Hit the mover (you don't even have to have anything to move).

 

To be clear it is not being caused by the min free space, its a cache only share, mover should not be trying to move it at all, it should be getting skipped by mover just like the rest of the SMB cache only shares. (Plenty of free space on the cache drive)

 

 

[dgaschk]

I tried this and can confirm the erroneous log messages. The function is correct, however.

[madburg]

I tried this and can confirm the erroneous log messages. The function is correct, however.

 

Thanks for testing the scenario out. But can you elaborate what you mean by "can confirm the erroneous log messages. The function is correct, however."

 

I am no linux guys, but clearly its a bug because "mover" is making an attempt to move a Cache Only Share, instead of skipping it. And since "mover" uses rsync too move data to the array, thus the error(s) from rysnc in the log, not erroneous, they are errors.

 

Looking into the code for mover (again am no linux guy):

 

 

#!/bin/bash

 

    # This is the 'mover' script used for moving files from the cache disk to the

    # main array.  It is typically invoked via cron.

 

    # After checking if it's valid for this script to run, we check each of the top-level

    # directories on the cache disk: if the directory also already exists in the array, then we

    # use the 'find' command to process the objects (files and directories) of that directory.

    # Note that files at the top level of the cache disk are never copied to the array.

 

So clearly, the Cache only shares dont exit in the array, right? Lets keep going...

 

    # The script is set up so that hidden directories (i.e., directory names beginning with a '.'

    # character) at the topmost level of the cache drive are also not copied to the user share file

    # system. This behavior can be turned off by uncommenting the following line:

    # shopt -s dotglob

 

    # The 'find' command generates a list of all files and directories on the cache disk.

    # For each file, if the file is not "in use" by any process (as detected by 'fuser' command),

    # then the file is copied to the array, and upon success, deleted from the cache disk.

    # For each directory, if the directory is empty, then the directory is created on the array,

    # and upon success, deleted from the cache disk.

 

    # For each file or directory, we use 'rsync' to copy the file or directory to the array.

    # We specify the proper options to rsync so that files and directories get copied to the

    # array while preserving ownership, permissions, access timess, and extended attributes (this

    # is why we use rsync: a simple mv command will not preserve all metadata properly).

 

So we clearly see the logic comments state it will use rsync to do the work of moving data, deemed to be moved. Lets go to the actual code now...

 

 

    # Only run script if cache disk enabled and in use

    if [ ! -d /mnt/cache -o ! -d /mnt/user0 ]; then

      exit 0

    fi

 

    # If a previous invokation of this script is already running, exit

    if [ -f /var/run/mover.pid ]; then

      if ps h `cat /var/run/mover.pid` | grep mover ; then

          echo "mover already running"

          exit 0

      fi

    fi

    echo $$ >/var/run/mover.pid

    echo "mover started"

 

    cd /mnt/cache

 

    for Share in */ ; do

      if [ -d "/mnt/user0/$Share" ]; then

        echo "moving $Share"

        find "./$Share" -depth \( \( -type f ! -exec fuser -s {} \; \) -o \( -type d -empty \) \) -print \

          -exec rsync -i -dIWRpEAXogt --numeric-ids --inplace {} /mnt/user0/ \; -delete

      else

        echo "skipping $Share"

      fi

    done

 

    rm /var/run/mover.pid

    echo "mover finished"

 

Hmmm, the culprit above (sort of, don't believe its mover per say). In plain English its stating IF the top level folder is a match to a folder in /mnt/user0, then it is not a Cache Only Share, its a Regular Share in the Array. So move it!

 

Guess what? The Cache Only Share with AFP folder is found in /mnt/user0, you guessed it, so to "mover" its NOT a Cache Only Share. So "mover" has rsync make an attempt to move it.

 

So why is that Cache Only Share with AFP showing up under /mnt/user0? (when all other Cache Only Share(s) without AFP are not showing up under /mnt/user0) I don't know.

Should mover not be looking at that /mnt/user0 and use something instead, I don't know.

Its a bug I am pointing out and Tom needs to work it out (he knows this stuff inside out) and will apply the fix as required. If he reads this post.

 

I normal don't even go this deep, just wanted to show you its NOT erroneous log messages and the function is NOT correct.

 

It is a bug and should be corrected.

[dgaschk]

The function is correct because the cache-only share is not moved. The error report is erroneous because it is intended for rsync to fail. This is a common practice. It is only the reporting that is in error.

[madburg]

Dude are you listening to yourself? Glad your not coding this product.

 

Tom did not code the mover to be dumb and attempt to move any and everything in the cache drive, and have anything that is not slated to be in the Array Fail. He added logic to check if the top level folder in the cache drive exists in the array, and if it does not, then skip it (Hence Cache ONLY share, hello?).

 

So how can you say "The function is correct because the cache-only share is not moved." when an attempt is being made to move it, when it should be skipping it.

And then you go on to say "The error report is erroneous because it is intended for rsync to fail." when clearly it is NOT intended to fail, because if is it not a Cache Only Share (which should be skipped) it must mean it is an Array Share and the data is to be moved. So it is trying to move data to the array to a destination that does not exist and thus the errors and those errors being logged to the syslog. HELLO anyone there?

 

"This is a common practice. It is only the reporting that is in error." Really? It is NOT common practice in any world, only with bad coders (Tom is not clearly, this is just a bug, his logic is on the money to implement Cache Only Shares), and the reporting of the failure is not whats in error, it is what is actually happening (rsync failing to move data = ERROR), do to an attempt to move a Cache only Share (which has AFP turn on it).

 

If you cannot see this clear as day, you shouldn't even be posting. Good bye.

 

[dgaschk]

 

 

I am no linux guys, but clearly its a bug because "mover" is making an attempt to move a Cache Only Share, instead of skipping it. And since "mover" uses rsync too move data to the array, thus the error(s) from rysnc in the log, not erroneous, they are errors.

 

I am a linux guy with over 30 years of experience. Functions are often called without knowing how they will terminate. The code for the cache-only share is implemented so that the file system reports 0 space free in the array for cache-only shares. The error reported by rsync is expected on cache-only shares. However, this error should not be reported in the log.

 

Please try not to be so full of yourself.

[madburg]

 

 

I am no linux guys, but clearly its a bug because "mover" is making an attempt to move a Cache Only Share, instead of skipping it. And since "mover" uses rsync too move data to the array, thus the error(s) from rysnc in the log, not erroneous, they are errors.

 

I am a linux guy with over 30 years of experience. Functions are often called without knowing how they will terminate. The code for the cache-only share is implemented so that the file system reports 0 space free in the array for cache-only shares. The error reported by rsync is expected on cache-only shares. However, this error should not be reported in the log.

 

Please try not to be so full of yourself.

 

 

Nothing for you to to brag about your thirty years, if you can't clearly see, which I know you do clearly understand but cant except your wrong here, but now your just digging a deeper hole for yourself.

 

Tom is not looking for ANYTHING to do with free space with the "mover" scripts logic, it is looking to see if there is a match between the top-level folder name in the cache drive with any top-level folder in /mnt/user0 to know if it is a Cache Only share (Thats his logic). And that is where the bug is, and due to the bug, rsync is trying to move data with no destination and thus the rsync errors and his code is stating to log what rsync is doing:

 

    find "./$Share" -depth \( \( -type f ! -exec fuser -s {} \; \) -o \( -type d -empty \) \) -print \
      -exec rsync -i -dIWRpEAXogt --numeric-ids --inplace {} /mnt/user0/ \; -delete

 

That is why the error(s) are in the syslog. So once again your wrong with your statement "However, this error should not be reported in the log."

 

Again, glad your not coding this project.

 

[dgaschk]

The cache-only shares are not moved to the array. The function of the cache-only share is correct. If you don't look at the log you would never know this issue existed. Is your cache-only share not functioning correctly?

 

This is a low priority cosmetic issue that will not in any way effect users. Perhaps you should worry more about your neuroses.

[madburg]

An attempt to move the Cache Only share when it should be skipped (just like Cache Only shares that are shared out by SMB only are skipped, and as the comments Tom clearly states in his mover script logic) and just because it fails in its attempt for something it should have never attempted to makes, it ok for YOU. You summed it up " If you don't look at the log you would never know this issue existed", that's right ISSUE  .

 

You clearly display what little you know in your thirty years working with linux. You have managed to be wrong with every statement in this post and still you will not give up trying to save face. You have me laughing now, thank you.

 

Wait, maybe its the min. free space i have set on the share, LOL, you just have to laugh. 

 

 

[dgaschk]

So the cache-only share is functioning correctly. This cosmetic issue does not effect the correct function of your server.

[madburg]

Update:

 

Running 5RC8a, no change, mover still attempting to move cache only share.

[madburg]

Resolved in RC9a, mover no longer attempting to mover a AFP cache only share.

I want to thank you Tom, but not sure if you worked this out or it worked itself out as you didn't mention in your release notes that you fixed it.

Let us know.