Cloudron makes it easy to run web apps like WordPress, Nextcloud, GitLab on your server. Find out more or install now.


    Cloudron Forum

    • Register
    • Login
    • Search
    • Categories
    • Recent
    • Tags
    • Popular

    Solved Backup failing with "copy code: 1, signal: null": "cannot create hard link" "operation not permitted"

    Support
    backups
    3
    26
    222
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • d19dotca
      d19dotca last edited by d19dotca

      Hello,

      This has happened on occasion to me (maybe once a month if that), and the next backup run always succeeds. But for some reason I've had three in a row fail now. This is a similar report to what I made in a thread back in April. Same error anyways, and always occurs on mailboxes. But the mailbox it seems to get stuck on is different each time, so it isn't anything like a corrupt mailbox data or something like that (which was my initial thought that it could be corruption). The difference between this and the last one that I see is the last one would happen but the next attempt would be successful. For some reason this time it's not successful anytime, even when I manually invoke it.

      In that other thread, it seemed sort of chalked up to something about the disk infrastructure since it was mounted with NFS, but I am in a completely different hosting provider now and in a different datacentre, with a different setup. There is no NFS disk anymore, not even CIFS, just a regular ext4 disk attached. Been running on this new infrastructure for about two months without issue, so I just really don't think this is a infrastructure thing and suspect this is more Cloudron related. But I'd love to be proven wrong. πŸ™‚

      The reason why I suspect this is more of a Cloudron issue is because A) there have been no changes to the backup settings or disk it's backing up to, and B) The error says "operation not permitted" for creating hard links, but how is that possible when every other file in the backup was done with creating hard links? If it was an infrastructure limitation, I'd have expected that error constantly.

      Here is the full backup log from the latest attempt. I have replaced all email addresses with mailbox@example.com for privacy reasons, but know there are about 5 different email addresses referenced in the real log file. Your assistance in troubleshooting this would be appreciated.

      backup Logs 
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.643Z box:backups Adding mail/vmail/mailbox@example.com/mail/dovecot.index.cache position 196 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.643Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mailmailbox@example.com/mail/dovecot.index.log: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.643Z box:backups Uploaded mailmailbox@example.com/mail/dovecot.index.log
      Jul 27 07:46:45 box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/dovecot.index.log","reason":"changed","position":197}
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.643Z box:backups Adding mail/vmail/mailbox@example.com/mail/dovecot.index.log position 197 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.643Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mailmailbox@example.com/mail/new/1595860038.M499784P18107.6cc2d7e3254e,S=16017,W=16335: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.643Z box:backups Uploaded mailmailbox@example.com/mail/new/1595860038.M499784P18107.6cc2d7e3254e,S=16017,W=16335
      Jul 27 07:46:45 box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/new/1595856839.M870046P16787.6cc2d7e3254e,S=108441,W=110700","reason":"new","position":198}
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.643Z box:backups Adding mail/vmail/mailbox@example.com/mail/new/1595856839.M870046P16787.6cc2d7e3254e,S=108441,W=110700 position 198 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.644Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mailmailbox@example.com/mail/new/1595860713.M404938P18344.6cc2d7e3254e,S=9900,W=10074: done.
      Jul 27 07:46:45 box:backups Uploaded mailmailbox@example.com/mail/new/1595860713.M404938P18344.6cc2d7e3254e,S=9900,W=10074
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.644Z box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/cur/1595836229.M996989P11963.6cc2d7e3254e,S=8357,W=8530:2,S","reason":"new","position":199}
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.644Z box:backups Adding mail/vmail/mailbox@example.com/mail/cur/1595836229.M996989P11963.6cc2d7e3254e,S=8357,W=8530:2,S position 199 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.645Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/.dovecot.lda-dupes: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/.dovecot.lda-dupes
      Jul 27 07:46:45 box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/dovecot.index.log","reason":"changed","position":200}
      Jul 27 07:46:45 box:backups Adding mail/vmail/mailbox@example.com/mail/dovecot.index.log position 200 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.645Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mailmailbox@example.com/mail/dovecot.index.cache: done.
      Jul 27 07:46:45 box:backups Uploaded mailmailbox@example.com/mail/dovecot.index.cache
      Jul 27 07:46:45 box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/cur/1595854882.M88930P16257.6cc2d7e3254e,S=3323,W=3388:2,af","reason":"new","position":201}
      Jul 27 07:46:45 box:backups Adding mail/vmail/mailbox@example.com/mail/cur/1595854882.M88930P16257.6cc2d7e3254e,S=3323,W=3388:2,af position 201 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.649Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot-uidlist: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.649Z box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot-uidlist
      Jul 27 07:46:45 box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/dovecot-uidlist","reason":"changed","position":202}
      Jul 27 07:46:45 box:backups Adding mail/vmail/mailbox@example.com/mail/dovecot-uidlist position 202 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.651Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot.index.log: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot.index.log
      Jul 27 07:46:45 box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/dovecot.index.cache","reason":"changed","position":203}
      Jul 27 07:46:45 box:backups Adding mail/vmail/mailbox@example.com/mail/dovecot.index.cache position 203 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.653Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/cur/1595836229.M996989P11963.6cc2d7e3254e,S=8357,W=8530:2,S: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.653Z box:backups Uploaded mail/vmail/mailbox@example.com/mail/cur/1595836229.M996989P11963.6cc2d7e3254e,S=8357,W=8530:2,S
      Jul 27 07:46:45 box:backups sync: processing task: {"operation":"add","path":"mail/vmail/mailbox@example.com/mail/dovecot.index.log","reason":"changed","position":204}
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.653Z box:backups Adding mail/vmail/mailbox@example.com/mail/dovecot.index.log position 204 try 1
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.653Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot.index.log: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot.index.log
      Jul 27 07:46:45 box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/new/1595856839.M870046P16787.6cc2d7e3254e,S=108441,W=110700: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/mail/new/1595856839.M870046P16787.6cc2d7e3254e,S=108441,W=110700
      Jul 27 07:46:45 box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/cur/1595854882.M88930P16257.6cc2d7e3254e,S=3323,W=3388:2,af: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/mail/cur/1595854882.M88930P16257.6cc2d7e3254e,S=3323,W=3388:2,af
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.654Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot-uidlist: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot-uidlist
      Jul 27 07:46:45 box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot.index.log: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot.index.log
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.671Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot.index.cache: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.671Z box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot.index.cache
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.678Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot.index.cache: done.
      Jul 27 07:46:45 box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot.index.cache
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.721Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/.Spam/dovecot.index.cache: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.721Z box:backups Uploaded mail/vmail/mailbox@example.com/mail/.Spam/dovecot.index.cache
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.779Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/dovecot.index.cache: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.779Z box:backups Uploaded mail/vmail/mailbox@example.com/mail/dovecot.index.cache
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.861Z box:storage/filesystem upload /cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/.Archive/dovecot.index.cache: done.
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.861Z box:backups Uploaded mail/vmail/mailbox@example.com/mail/.Archive/dovecot.index.cache
      Jul 27 07:46:45 box:syncer Done processing adds null
      Jul 27 07:46:45 box:shell backup-snapshot/box (stdout): 2020-07-27T14:46:45.869Z box:backupupload upload completed. error: null
      Jul 27 07:46:45 box:backups runBackupUpload: result - {"result":""}
      Jul 27 07:46:45 box:backups uploadBoxSnapshot: time: 7.758 secs
      Jul 27 07:46:45 box:backups Rotating box backup to id 2020-07-27-144500-831/box_2020-07-27-144645-884_v5.4.1
      Jul 27 07:46:45 box:tasks 5029: {"percent":97.77419354838703,"message":"box: Copying /cloudron-backups/snapshot/box to /cloudron-backups/2020-07-27-144500-831/box_2020-07-27-144645-884_v5.4.1"}
      Jul 27 07:46:45 box:shell copy spawn: /bin/cp -al /cloudron-backups/snapshot/box /cloudron-backups/2020-07-27-144500-831/box_2020-07-27-144645-884_v5.4.1
      Jul 27 07:46:55 box:shell copy (stdout): /bin/cp: cannot create hard link '/cloudron-backups/2020-07-27-144500-831/box_2020-07-27-144645-884_v5.4.1/mail/vmail/mailbox@example.com/mail/.Drafts/cur/1595818035.M834704P2043.6cc2d7e3254e,S=170789,W=173039:2,DS' to '/cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/.Drafts/cur/1595818035.M834704P2043.6cc2d7e3254e,S=170789,W=173039:2,DS': Operation not permitted
      Jul 27 07:46:55 box:shell copy (stdout): /bin/cp:
      Jul 27 07:46:55 box:shell copy (stdout): cannot create hard link '/cloudron-backups/2020-07-27-144500-831/box_2020-07-27-144645-884_v5.4.1/mail/vmail/mailbox@example.com/mail/cur/1595789045.M441022P13667.6cc2d7e3254e,S=796283,W=806694:2,FSaf' to '/cloudron-backups/snapshot/box/mail/vmail/mailbox@example.com/mail/cur/1595789045.M441022P13667.6cc2d7e3254e,S=796283,W=806694:2,FSaf'
      Jul 27 07:46:55 box:shell copy (stdout): : Operation not permitted
      Jul 27 07:46:55 box:shell copy (stdout):
      Jul 27 07:46:56 box:shell copy code: 1, signal: null
      Jul 27 07:46:56 box:tasks setCompleted - 5029: {"result":null,"error":{"stack":"BoxError: copy exited with code 1 signal null\n at /home/yellowtent/box/src/storage/filesystem.js:185:51\n at f (/home/yellowtent/box/node_modules/once/once.js:25:25)\n at ChildProcess.<anonymous> (/home/yellowtent/box/src/shell.js:67:9)\n at ChildProcess.emit (events.js:198:13)\n at Process.ChildProcess._handle.onexit (internal/child_process.js:248:12)","name":"BoxError","reason":"External Error","details":{},"message":"copy exited with code 1 signal null"}}
      Jul 27 07:46:56 box:tasks 5029: {"percent":100,"result":null,"error":{"stack":"BoxError: copy exited with code 1 signal null\n at /home/yellowtent/box/src/storage/filesystem.js:185:51\n at f (/home/yellowtent/box/node_modules/once/once.js:25:25)\n at ChildProcess.<anonymous> (/home/yellowtent/box/src/shell.js:67:9)\n at ChildProcess.emit (events.js:198:13)\n at Process.ChildProcess._handle.onexit (internal/child_process.js:248:12)","name":"BoxError","reason":"External Error","details":{},"message":"copy exited with code 1 signal null"}}
      

      --
      Dustin Dauncey
      www.d19.ca

      1 Reply Last reply Reply Quote 0
      • d19dotca
        d19dotca last edited by d19dotca

        Update: Since it had been about 24 hours since my last successful backup, I got antsy and deleted all backups to effectively "start from scratch". However when I ran the first backup after that, it was successful but only took about 450 MB, which seems far too low. The first backup should be roughly 15 GB. Something seems wrong here.

        @girish at this point I have no real backups other than a VPS snapshot, so I could really use a hand on this one. I don't trust my backups right now.

        --
        Dustin Dauncey
        www.d19.ca

        1 Reply Last reply Reply Quote 0
        • girish
          girish Staff last edited by

          @d19dotca I guess this is rsync backup? Merely deleting the backups won't suffice, Can you try to quickly change the backup method to disabled/no-op and set it up again? This will clear the cache of what Cloudron thinks has been backed up so far (i.e the incremental backup state). I think after that you will see it takes a full backup.

          As for the original issue, this cp -al is the exact issue we had before and it seems this keeps popping up because of CIFS. I think @nebulon knows better about this, I will let him comment.

          d19dotca 1 Reply Last reply Reply Quote 1
          • d19dotca
            d19dotca @girish last edited by d19dotca

            @girish Ah okay that'd explain why it isn't backing it all up right now. I'll do that quickly and test. And yes this is rsync. I use rsync with hardlinks to save disk space and to speed up the backup process.

            --
            Dustin Dauncey
            www.d19.ca

            1 Reply Last reply Reply Quote 0
            • girish
              girish Staff last edited by

              Right, hardlinks is the correct approach. It will save a lot of space but it does fail at times when using that options with CIFS.

              d19dotca 1 Reply Last reply Reply Quote 0
              • d19dotca
                d19dotca @girish last edited by d19dotca

                @girish Okay I can report that did the trick in terms of at least getting a proper full backup now, so I have at least one backup. It was 17 GB in size. Thanks for that suggestion. πŸ™‚

                My ext4 hard disk is not mounted with CIFS or NFS, so I'm not certain that's a factor in this case. Here is what the line is in /etc/fstab:

                /dev/vdc /cloudron-backups ext defaults 0 2
                

                Since this worked fine after switching from no-op to Filesystem again (although I had also rm -rf * the /cloudron-backups/ directory before that too), I think this lends more evidence to this being an odd Cloudron issue (or at the very least a rare inconsistency/compatibility issue) rather than an infrastructure issue.

                Thoughts?

                --
                Dustin Dauncey
                www.d19.ca

                1 Reply Last reply Reply Quote 0
                • girish
                  girish Staff last edited by

                  @d19dotca Oh that's even better that this is not CIFS related because it points to a Cloudron issue. So, because you managed a full backup, it means that the hard links worked this time around. Can you let me know if it fails again?

                  d19dotca 2 Replies Last reply Reply Quote 0
                  • d19dotca
                    d19dotca @girish last edited by

                    @girish Yes, it seems all hardlinks were created properly this time. I'll let you know if it fails again, for sure. Definitely seems like an odd issue and at first I assumed it was my infrastructure because of the other thread back in April, but this seems at this point to be more of a Cloudron issue. I can't quite get past the fact that this always is an issue on emails too, it's never on a file in an app or anything like that, always email. Maybe a coincidence since mail is also taking up most of the disk space, but still... just very strange to me. Hopefully this can be fixed in a future release once we know the root cause. Thanks again for the help to get me out of that jam. πŸ™‚

                    --
                    Dustin Dauncey
                    www.d19.ca

                    1 Reply Last reply Reply Quote 0
                    • d19dotca
                      d19dotca @girish last edited by d19dotca

                      @girish & @nebulon

                      It's happening again, I'm afraid. Just got notified a short bit ago of this.

                      Aug 06 13:46:42 box:shell copy (stdout): /bin/cp: cannot create hard link '/cloudron-backups/2020-08-06-204501-046/box_2020-08-06-204642-043_v5.4.1/mail/vmail/user@example.com/mail/.A - PC + FD Referrals INBOX/cur/1596744663.M967808P27952.6cc2d7e3254e,S=2825,W=2866:2,S' to '/cloudron-backups/snapshot/box/mail/vmail/user@example.com/mail/.A - PC + FD Referrals INBOX/cur/1596744663.M967808P27952.6cc2d7e3254e,S=2825,W=2866:2,S': Operation not permitted
                      Aug 06 13:46:50 box:shell copy code: 1, signal: null
                      

                      If you think it's helpful to remote in or anything, just let me know and I can enable that option for you.

                      --
                      Dustin Dauncey
                      www.d19.ca

                      d19dotca 1 Reply Last reply Reply Quote 0
                      • d19dotca
                        d19dotca @d19dotca last edited by d19dotca

                        @girish Is there anything I need to be doing to help you guys out before I need to erase the backups again and start fresh? It's failed a second time now so I suspect this will always be like this until I force clear it again but I don't want to take away anything that'd help you narrow down what the issue is either.

                        --
                        Dustin Dauncey
                        www.d19.ca

                        d19dotca 1 Reply Last reply Reply Quote 0
                        • d19dotca
                          d19dotca @d19dotca last edited by

                          Update: The backup was successful just 55 minutes ago, without me needing to do anything this time. Still very interested in getting this resolved though as I'm sure it'll come back at some point again since this is several times this has happened this year now.

                          --
                          Dustin Dauncey
                          www.d19.ca

                          1 Reply Last reply Reply Quote 0
                          • girish
                            girish Staff last edited by

                            @d19dotca Yeah, we still haven't gotten to the bottom of this 😞 There is definitely some bug since it just manifests sporadically (and we have this from some other people's setups as well).

                            d19dotca 2 Replies Last reply Reply Quote 0
                            • d19dotca
                              d19dotca @girish last edited by d19dotca

                              @girish I just wanted to say that I'm still having this issue. It seems to happen very randomly, sometimes it doesn't happen for days or almost a week or more, but then it might happen for two backup attempts in a row. It's very intermittent, but still an issue. Hoping we can get to the bottom of this at some point (considering backups are a pretty critical piece of the solution), but I totally understand this is a rare issue so will likely be hard to nail down. If there's anything I can do for you to help narrow it down, I'd be happy to.

                              --
                              Dustin Dauncey
                              www.d19.ca

                              1 Reply Last reply Reply Quote 0
                              • d19dotca
                                d19dotca @girish last edited by

                                @girish This continues to be an issue. Anything I can do to help narrow this one down? It's quite annoying when every couple of days or so or even multiple times on the same day it fails to completely backup. Thankfully it seems all the apps get backed up, it's always doing this when backing up emails, getting stuck on different emails.

                                --
                                Dustin Dauncey
                                www.d19.ca

                                1 Reply Last reply Reply Quote 0
                                • girish
                                  girish Staff last edited by girish

                                  @d19dotca Let me contact you from support@ in a couple of days. Currently, a bit tied with the 5.6 release but I would love to get to the bottom of this.

                                  d19dotca 2 Replies Last reply Reply Quote 1
                                  • d19dotca
                                    d19dotca @girish last edited by

                                    @girish No problem at all, sounds great. Thanks Girish! πŸ™‚

                                    --
                                    Dustin Dauncey
                                    www.d19.ca

                                    1 Reply Last reply Reply Quote 0
                                    • d19dotca
                                      d19dotca @girish last edited by

                                      @girish Never heard back on this, but I know you guys are super busy too. I'd love to work together to fix this issue though as it's been much more prevalent to me the past few months and I suspect it coincides with email usage increase from my COVID-19 clinics since they're using email insanely often. My email history on the Email tab used to show upwards of sometimes an hour or two in time as there wasn't a ton of activity on it, but now it's maybe 3-5 minutes of activity at any given time, because those clinic emails are constantly being used. I suggest this possible relationship because every time the error occurs it's almost always (if not always) thrown on an email message file. Not always the clinic's email account files, but it just seems like it's become a much more frequent issue since the email use itself has skyrocketed on my server.

                                      --
                                      Dustin Dauncey
                                      www.d19.ca

                                      1 Reply Last reply Reply Quote 0
                                      • girish
                                        girish Staff last edited by

                                        @d19dotca I think we are a bit more free now since 5.6 is out. Are you able to write to support@cloudron.io and give us ssh access? I would like to take a detailed look at the logs and get to the bottom of this. Thanks!

                                        d19dotca 1 Reply Last reply Reply Quote 0
                                        • d19dotca
                                          d19dotca @girish last edited by

                                          @girish Just provided access and sent the email. πŸ™‚

                                          --
                                          Dustin Dauncey
                                          www.d19.ca

                                          1 Reply Last reply Reply Quote 1
                                          • girish
                                            girish Staff last edited by girish

                                            What I found so far is that the link operation is denied by the kernel. dmesg has the following lines:

                                            [563683.439933] audit: type=1702 audit(1601496162.706:33): op=linkat ppid=5039 pid=10646 auid=4294967295 uid=1001 gid=1001 euid=1001 suid=1001 fsuid=1001 egid=1001 sgid=1001 fsgid=1001 tty=(none) ses=4294967295 comm="cp" exe="/bin/cp" res=0
                                            [563683.439938] audit: type=1302 audit(1601496162.706:34): item=0 name="/path/dovecot-uidlist.lock" inode=2246683 dev=fc:20 mode=0100644 ouid=0 ogid=0 rdev=00:00 nametype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
                                            

                                            The type= means this from audit.h

                                            1702 /* Suspicious use of file links */
                                            1302    /* Filename path information */
                                            

                                            And according to https://access.redhat.com/articles/4409591 it's triggering for some ANOM_LINK event type. So far, there is little to no information on what all this means.

                                            robi 1 Reply Last reply Reply Quote 1
                                            • robi
                                              robi @girish last edited by

                                              @girish this sounds to me like a resource or policy type exhaustion issue. Like when ulimit it too low or we run out of inodes.

                                              Is anything else running in the kernel, like SE Linux?

                                              Are we hitting limits on hardlinks with large enough backups? I believe the limit on ext4 is 65k

                                              It would be interesting to switch filesystems and see if it happens on xfs for example.

                                              Do you have an Object Store target option via S3?

                                              Life of Advanced Technology

                                              1 Reply Last reply Reply Quote 0
                                              • girish
                                                girish Staff last edited by

                                                I think the 65k is the number of hardlinks on a file and not the hardlinks on a file system.

                                                The rabbit hole goes as deep as we want to πŸ™‚

                                                I think I found the problem though of course I have to try it out. audit_log_path_denied here - https://elixir.bootlin.com/linux/latest/source/fs/namei.c#L955 is where the audit log is raised. I am no kernel expert but a casual reading of the comment "Allowed if owner and follower match" suggests that the owner of file and the linker is not matching. The symlinking process runs as user yellowtent.

                                                root@my:/cloudron-backups/snapshot/box/mail# find . -user root -type f
                                                ./blah/blah/dovecot-uidlist.lock
                                                ./blah/blah/1600972556.M892349P24001.69d0c668883d,S=6124,W=6234:2,S
                                                

                                                Bingo! For some reason, these 2 specific files are not owner yellowtent and are root. Looks like some bug/race in the code that creates snapshot. Curiously, both the files above are of 0 size, so maybe that's causing some strange event ordering.

                                                1 Reply Last reply Reply Quote 1
                                                • girish
                                                  girish Staff last edited by

                                                  Yay, found the problem πŸ™‚ Issue is that if a file disappears when we are creating the snapshot, the code errors. Usually files in the snapshot are chowned to the yellowtent user but on an error it ends up creating an empty file in the snapshot directory with the root permission. The hard linking code is run as yellowtent user, and thus symlinking fails. Phew!

                                                  1 Reply Last reply Reply Quote 2
                                                  • robi
                                                    robi last edited by

                                                    Yaay! .. and there was much rejoicing! πŸ˜‰

                                                    Nicely done.

                                                    That root owned file would be concerning as a local root escalation. What else there runs as root while yellowtent is doing it's thing?

                                                    Life of Advanced Technology

                                                    1 Reply Last reply Reply Quote 0
                                                    • girish
                                                      girish Staff last edited by

                                                      Fixed with https://git.cloudron.io/cloudron/box/-/issues/741

                                                      d19dotca 1 Reply Last reply Reply Quote 1
                                                      • d19dotca
                                                        d19dotca @girish last edited by

                                                        @girish that’s perfect, great detective work! Thanks Girish for working to solve that. I really appreciate it. I’ll keep an eye on it in my server you patched and see if the issue comes back. Thanks again! πŸ™‚

                                                        --
                                                        Dustin Dauncey
                                                        www.d19.ca

                                                        1 Reply Last reply Reply Quote 0
                                                        • First post
                                                          Last post
                                                        Powered by NodeBB