Merge pull request #1631 from pbiering/improve-hook

Improve storage hook

DOCUMENTATION.md

@@ -578,14 +578,31 @@ authentication over HTTP.
 This tutorial describes how to keep track of all changes to calendars and
 address books with **git** (or any other version control system).
 
-The repository must be initialized by running `git init` in the file
-system folder. Internal files of Radicale can be excluded by creating the
-file `.gitignore` with the following content:
+The repository must be initialized in the collection base directory
+of the user running `radicale` daemon.
 
-```gitignore
+```bash
+## assuming "radicale" user is starting "radicale" service
+# change to user "radicale"
+su -l -s /bin/bash radicale
+
+# change to collection base directory defined in [storage] -> filesystem_folder
+#  assumed here /var/lib/radicale/collections
+cd /var/lib/radicale/collections
+
+# initialize git repository
+git init
+
+# set user and e-mail, here minimum example
+git config user.name "$USER"
+git config user.email "$USER@$HOSTNAME"
+
+# define ignore of cache/lock/tmp files
+cat <<'END' >.gitignore
 .Radicale.cache
 .Radicale.lock
 .Radicale.tmp-*
+END
 ```
 
 The configuration option `hook` in the `storage` section must be set to
@@ -598,16 +615,23 @@ git add -A && (git diff --cached --quiet || git commit -m "Changes by \"%(user)s
 The command gets executed after every change to the storage and commits
 the changes into the **git** repository.
 
-For the hook to not cause errors either **git** user details need to be set and match the owner of the collections directory or the repository needs to be marked as safe.
+Log of `git` can be investigated using
 
-When using the systemd unit file from the [Running as a service](#running-as-a-service) section this **cannot** be done via a `.gitconfig` file in the users home directory, as Radicale won't have read permissions!
-
-In `/var/lib/radicale/collections/.git` run:
 ```bash
-git config user.name "radicale"
-git config user.email "radicale@example.com"
+su -l -s /bin/bash radicale
+cd /var/lib/radicale/collections
+git log
 ```
 
+In case of problems, make sure you run radicale with ``--debug`` switch and
+inspect the log output. For more information, please visit
+[section on logging.]({{ site.baseurl }}/logging/) .
+
+Reason for problems can be
+ - SELinux status -> check related audit log
+ - problematic file/directory permissions
+ - command is not fond or cannot be executed or argument problem
+
 ## Documentation
 
 ### Configuration
@@ -1001,6 +1025,11 @@ Command that is run after changes to storage. Take a look at the
 
 Default:
 
+Supported placeholders:
+ - `%(user)`: logged-in user
+
+Command will be executed with base directory defined in `filesystem_folder` (see above)
+
 ##### predefined_collections
 
 Create predefined user collections
@@ -1528,7 +1557,7 @@ The ``radicale`` package offers the following modules.
 
 `ìtem`
 : Internal representation of address book and calendar entries. Based on
-  [VObject](https://eventable.github.io/vobject/).
+  [VObject](https://github.com/py-vobject/vobject/).
 
 `log`
 : The logger for Radicale based on the default Python logging module.

config

@@ -144,8 +144,12 @@
 # Skip broken item instead of triggering an exception
 #skip_broken_item = True
 
-# Command that is run after changes to storage
-# Example: ([ -d .git ] || git init) && git add -A && (git diff --cached --quiet || git commit -m "Changes by \"%(user)s\"")
+# Command that is run after changes to storage, default is emtpy
+#  Supported placeholders:
+#   %(user): logged-in user
+#  Command will be executed with base directory defined in filesystem_folder
+#  For "git" check DOCUMENTATION.md for bootstrap instructions
+# Example: git add -A && (git diff --cached --quiet || git commit -m "Changes by \"%(user)s\"")
 #hook =
 
 # Create predefined user collections

radicale/storage/multifilesystem/lock.py

@@ -75,27 +75,35 @@ class StoragePartLock(StorageBase):
                     preexec_fn = os.setpgrp
                 command = self._hook % {
                     "user": shlex.quote(user or "Anonymous")}
-                logger.debug("Running storage hook")
-                p = subprocess.Popen(
-                    command, stdin=subprocess.DEVNULL,
-                    stdout=subprocess.PIPE if debug else subprocess.DEVNULL,
-                    stderr=subprocess.PIPE if debug else subprocess.DEVNULL,
-                    shell=True, universal_newlines=True, preexec_fn=preexec_fn,
-                    cwd=self._filesystem_folder, creationflags=creationflags)
+                logger.debug("Executing storage hook: '%s'" % command)
+                try:
+                    p = subprocess.Popen(
+                        command, stdin=subprocess.DEVNULL,
+                        stdout=subprocess.PIPE if debug else subprocess.DEVNULL,
+                        stderr=subprocess.PIPE if debug else subprocess.DEVNULL,
+                        shell=True, universal_newlines=True, preexec_fn=preexec_fn,
+                        cwd=self._filesystem_folder, creationflags=creationflags)
+                except Exception as e:
+                    logger.error("Execution of storage hook not successful on 'Popen': %s" % e)
+                    return
+                logger.debug("Executing storage hook started 'Popen'")
                 try:
                     stdout_data, stderr_data = p.communicate()
-                except BaseException:  # e.g. KeyboardInterrupt or SystemExit
+                except BaseException as e:  # e.g. KeyboardInterrupt or SystemExit
+                    logger.error("Execution of storage hook not successful on 'communicate': %s" % e)
                     p.kill()
                     p.wait()
-                    raise
+                    return
                 finally:
                     if sys.platform != "win32":
                         # Kill remaining children identified by process group
                         with contextlib.suppress(OSError):
                             os.killpg(p.pid, signal.SIGKILL)
+                logger.debug("Executing storage hook finished")
                 if stdout_data:
-                    logger.debug("Captured stdout from hook:\n%s", stdout_data)
+                    logger.debug("Captured stdout from storage hook:\n%s", stdout_data)
                 if stderr_data:
-                    logger.debug("Captured stderr from hook:\n%s", stderr_data)
+                    logger.debug("Captured stderr from storage hook:\n%s", stderr_data)
                 if p.returncode != 0:
-                    raise subprocess.CalledProcessError(p.returncode, p.args)
+                    logger.error("Execution of storage hook not successful: %s" % subprocess.CalledProcessError(p.returncode, p.args))
+                    return

radicale/tests/test_storage.py

@@ -80,9 +80,9 @@ class TestMultiFileSystem(BaseTest):
         self.propfind("/created_by_hook/")
 
     def test_hook_fail(self) -> None:
-        """Verify that a request fails if the hook fails."""
+        """Verify that a request succeeded if the hook still fails (anyhow no rollback implemented)."""
         self.configure({"storage": {"hook": "exit 1"}})
-        self.mkcalendar("/calendar.ics/", check=500)
+        self.mkcalendar("/calendar.ics/", check=201)
 
     def test_item_cache_rebuild(self) -> None:
         """Delete the item cache and verify that it is rebuild."""