[feature] Added logging in update_wireguard.sh script #36

When the script is executed by the Flask app, the uwsgi log will
contain the output from the update_wireguard.sh script.

Closes #36

Co-authored-by: Gagan Deep <pandafy.dev@gmail.com>
Co-authored-by: clutch2sft <148905f4@opayq.com>

tasks/pip.yml

@@ -1,41 +1,85 @@
 ---
 
-- name: "[CentOS7] Set virtualenv command"
-  set_fact:
-    openwisp2_wireguard_virtualenv_command: "virtualenv-3"
-  when: ansible_distribution == 'CentOS' and ansible_distribution_major_version == "7"
-
-- name: Update pip & related tools
-  pip:
-    name:
-      - pip
-      - setuptools
-      - wheel
-      - attrs
-    state: latest
-    virtualenv: "{{ virtualenv_path }}"
-    virtualenv_python: "{{ openwisp2_wireguard_python }}"
-    virtualenv_site_packages: true
-    virtualenv_command: "{{ openwisp2_wireguard_virtualenv_command }}"
-  retries: 5
-  delay: 10
-  register: result
-  until: result is success
-  notify: reload supervisor
+- name: Install Python packages on non CentOS 7 OS
+  when: not (ansible_distribution == 'CentOS' and ansible_distribution_major_version == "7")
+  block:
+  - name: Update pip & related tools
+    pip:
+      name:
+        - pip
+        - setuptools
+        - wheel
+        - attrs
+      state: latest
+      virtualenv: "{{ virtualenv_path }}"
+      virtualenv_python: "{{ openwisp2_wireguard_python }}"
+      virtualenv_site_packages: true
+      virtualenv_command: "{{ openwisp2_wireguard_virtualenv_command }}"
+    retries: 5
+    delay: 10
+    register: result
+    until: result is success
+    notify: reload supervisor
+  - name: Install Flask, Werkzeug and uWSGI
+    pip:
+      name:
+        - "Flask~=2.0.3"
+        - "uwsgi~=2.0.19"
+        - "Werkzeug>=2.0,<3.0"
+      state: latest
+      virtualenv: "{{ virtualenv_path }}"
+      virtualenv_python: "{{ openwisp2_wireguard_python }}"
+      virtualenv_site_packages: true
+      virtualenv_command: "{{ openwisp2_wireguard_virtualenv_command }}"
+    notify: reload supervisor
+    retries: 5
+    delay: 10
+    register: result
+    until: result is success
 
-- name: Install Flask, Werkzeug and uWSGI
-  pip:
-    name:
-      - "Flask~=2.0.3"
-      - "uwsgi~=2.0.19"
-      - "Werkzeug>=2.0,<3.0"
-    state: latest
-    virtualenv: "{{ virtualenv_path }}"
-    virtualenv_python: "{{ openwisp2_wireguard_python }}"
-    virtualenv_site_packages: true
-    virtualenv_command: "{{ openwisp2_wireguard_virtualenv_command }}"
-  notify: reload supervisor
-  retries: 5
-  delay: 10
-  register: result
-  until: result is success
+- name: Install Python packages on CentOS 7
+  when: ansible_distribution == 'CentOS' and ansible_distribution_major_version == "7"
+  # Use the the rh-devtoolset version of gcc when installing
+  # Python packages. Without this, installing uwsgi fails.
+  block:
+    - set_fact:
+        openwisp2_wireguard_virtualenv_command: "virtualenv-3"
+    - name: Update pip & related tools
+      pip:
+        name:
+          - pip
+          - setuptools
+          - wheel
+          - attrs
+        state: latest
+        virtualenv: "{{ virtualenv_path }}"
+        virtualenv_python: "{{ openwisp2_wireguard_python }}"
+        virtualenv_site_packages: true
+        virtualenv_command: "{{ openwisp2_wireguard_virtualenv_command }}"
+      retries: 5
+      delay: 10
+      register: result
+      until: result is success
+      notify: reload supervisor
+      environment:
+        PATH: "/opt/rh/devtoolset-9/root/usr/bin:{{ ansible_env.PATH }}"
+        LD_LIBRARY_PATH: "/opt/rh/devtoolset-9/root/usr/lib64"
+    - name: Install Flask, Werkzeug and uWSGI
+      pip:
+        name:
+          - "Flask~=2.0.3"
+          - "uwsgi~=2.0.19"
+          - "Werkzeug>=2.0,<3.0"
+        state: latest
+        virtualenv: "{{ virtualenv_path }}"
+        virtualenv_python: "{{ openwisp2_wireguard_python }}"
+        virtualenv_site_packages: true
+        virtualenv_command: "{{ openwisp2_wireguard_virtualenv_command }}"
+      notify: reload supervisor
+      retries: 5
+      delay: 10
+      register: result
+      until: result is success
+      environment:
+        PATH: "/opt/rh/devtoolset-9/root/usr/bin:{{ ansible_env.PATH }}"
+        LD_LIBRARY_PATH: "/opt/rh/devtoolset-9/root/usr/lib64"

tasks/yum.yml

@@ -74,14 +74,6 @@
       changed_when: false
       tags: [wireguard]
   rescue:
-    - name: CentOS/RHEL 7
-      block:
-        - name: Add jdoss/wireguard repository (CentOS/RHEL 7)
-          command: |
-            curl -o /etc/yum.repos.d/jdoss-wireguard-epel-7.repo \
-             https://copr.fedorainfracloud.org/coprs/jdoss/wireguard/repo/epel-7/jdoss-wireguard-epel-7.repo
-      when: ansible_distribution_major_version == "7"
-      tags: [molecule-idempotence-notest]
     - name: CentOS/RHEL 8
       block:
         - name: Enable PowerTools (CentOS 8)
@@ -94,6 +86,14 @@
           command: yum copr enable jdoss/wireguard -y
       when: ansible_distribution_major_version == "8"
       tags: [molecule-idempotence-notest]
+    - name: CentOS/RHEL 7
+      when: ansible_distribution_major_version == "7"
+      block:
+        - name: Add jdoss/wireguard repository (CentOS/RHEL 7)
+          command: |
+            curl -o /etc/yum.repos.d/jdoss-wireguard-epel-7.repo \
+             https://copr.fedorainfracloud.org/coprs/jdoss/wireguard/repo/epel-7/jdoss-wireguard-epel-7.repo
+      tags: [molecule-idempotence-notest]
     - name: Remove kmod-wireguard and elrepo-release
       yum:
         name:
@@ -153,3 +153,18 @@
   delay: 10
   register: result
   until: result is success
+
+- name: Install the latest version of GCC
+  # The default repositories of CentOS 7 contains an old
+  # version of GCC which does not supports the flags used
+  # by uWSGI
+  when: ansible_distribution_major_version == "7"
+  block:
+    - name: Install Software Collections repository
+      yum:
+        name: centos-release-scl
+        state: present
+    - name: Install latest version of gcc
+      yum:
+        name: devtoolset-9-gcc
+        state: present

templates/flask/vpn_updater.py

@@ -24,11 +24,15 @@ def _exec_command(command):
         stdout=subprocess.PIPE,
         stderr=subprocess.PIPE,
         close_fds=True,
+        universal_newlines=True,
     )
-    stdout, stderr = process.communicate()
+    stdout, _ = process.communicate()
     exit_code = process.wait(timeout=10)
     if exit_code != 0:
+        app.logger.error(stdout)
         raise subprocess.SubprocessError()
+    else:
+        app.logger.info(stdout)
 
 
 def _log(level, message, request):

templates/update_scripts/update_wireguard.sh.j2

@@ -1,10 +1,14 @@
 #!/bin/bash
+# Route stderr to stdout gloablly in the script.
+# This helps logging from the Flask app
+exec 2>&1
 
 if [ "$(whoami)" != "{{ openwisp_user }}" ]; then
     echo "Script should only be run by {{ openwisp_user }}. Exiting!"
     exit 9
 fi
 
+LOGGING_LEVEL="{{ openwisp2_wireguard_logging_level }}"
 BASE_URL="{{ openwisp2_wireguard_controller_url }}"
 VPN_UUID="{{ openwisp2_wireguard_vpn_uuid }}"
 VPN_KEY="{{ openwisp2_wireguard_vpn_key }}"
@@ -25,32 +29,77 @@ _CURL="curl -s --show-error --fail {% if openwisp2_wireguard_curl_insecure %}--i
 mkdir -p $_WORKING_DIR
 mkdir -p $_APPLIED_CONF_DIR
 
+get_log_level_value() {
+    case "$1" in
+        INFO)
+            echo 1 ;;
+        WARNING)
+            echo 2 ;;
+        ERROR)
+            echo 3 ;;
+        *)
+            # If an unknown log level is provided, it will default to INFO.
+            # This scenario is not expected to occur under normal circumstances.
+            echo 1 ;;
+    esac
+}
+
+# Function to log a message with timestamp
+log_with_timestamp() {
+    local log_level="$1" # Logging level (e.g., INFO, WARNING, ERROR)
+    local message="$2"   # Message to log
+    # Get the numerical values for the provided and current logging levels
+    local message_log_level_value=$(get_log_level_value "$log_level")
+    local global_log_level_value=$(get_log_level_value "$LOGGING_LEVEL")
+    # Check if the provided logging level is less than or equal to the current logging level
+    if [ "$message_log_level_value" -ge "$global_log_level_value" ]; then
+        # Print the timestamp, logging level, and message
+        echo "$(date '+%Y-%m-%d %H:%M:%S') [$log_level] - $message"
+    fi
+}
+
 assert_exit_code() {
+    # This function ensures that that the previous line
+    # exited with 0 exit code. If not, it logs error with
+    # line number and exit code, and exits the program.
+    # If the optional second argument is provided,
+    # it is added to the log message
     exit_code=$?
-    lineno=$(($1-1))
+    lineno=$(($1 - 1))
     if [ "$exit_code" != "0" ]; then
-        echo "Line $lineno: Command returned non zero exit code: $exit_code"
+        local message="Error at line $lineno: Command returned non-zero exit code: $exit_code"
+        if [ -n "$2" ]; then
+            # Add the second argument to the log message
+            message="$message. $2"
+        fi
+        log_with_timestamp "ERROR" "$message"
         exit $exit_code
     fi
 }
 
 check_config() {
+    log_with_timestamp "INFO" "Checking if configuration has changed"
     _latest_checksum=$($_CURL $_VPN_CHECKSUM_URL)
-    assert_exit_code $LINENO
+    assert_exit_code $LINENO "Failed to fetch checksum from '$_VPN_CHECKSUM_URL'"
+    log_with_timestamp "INFO" "Retrieved configuration checksum"
     if [ -f "$_CHECKSUM_FILE" ]; then
+        log_with_timestamp "INFO" "Setting current checksum from $_CHECKSUM_FILE."
         _current_checksum=$(cat $_CHECKSUM_FILE)
     else
+        log_with_timestamp "INFO" "Local checksum not found: $_CHECKSUM_FILE is not present."
         _current_checksum=""
     fi
 
     if [ "$_current_checksum" != "$_latest_checksum" ]; then
-        echo "Configuration changed, downloading new configuration..."
+        log_with_timestamp "INFO" "Configuration changed, will download new configuration..."
         update_config
+    else
+        log_with_timestamp "INFO" "Configuration has not changed, exiting!"
     fi
 }
 
 clean_old_interface() {
-    echo "Bringing down old wireguard interface $managed_interface_name"
+    log_with_timestamp "INFO" "Bringing down old wireguard interface $managed_interface_name"
     for old_conf_file in $_APPLIED_CONF_DIR/*.conf; do
         [ -e "$old_conf_file" ] || continue
         sudo wg-quick down $old_conf_file
@@ -59,19 +108,24 @@ clean_old_interface() {
 }
 
 create_new_interface() {
-    echo "Bringing up new wireguard interface $interface"
+    log_with_timestamp "INFO" "Bringing up new wireguard interface $interface"
     sudo wg-quick up $file
 }
 
 update_config() {
     # Set file permissions to 0660, otherwise wg will complain
     # for having public configurations
-    umask 0117;
+    umask 0117
+
+    log_with_timestamp "INFO" "Starting configuration download..."
     $($_CURL $_VPN_DOWNLOAD_URL > "$_CONF_TAR")
-    assert_exit_code $LINENO
-    echo "Configuration downloaded, extracting it..."
+    assert_exit_code $LINENO "Failed to download VPN configuration from $_VPN_DOWNLOAD_URL"
+    log_with_timestamp "INFO" "Configuration downloaded, extracting it..."
+
     tar -zxvf $_CONF_TAR -C $CONF_DIR > /dev/null
-    assert_exit_code $LINENO
+    assert_exit_code $LINENO "Failed to extract configuration from $_CONF_TAR."
+    log_with_timestamp "INFO" "Extracted configuration successfully."
+
     if [ -e "$_MANAGED_INTERFACE" ]; then
         managed_interface_name=$(cat "$_MANAGED_INTERFACE")
     fi
@@ -82,14 +136,16 @@ update_config() {
         interface="${filename%.*}"
 
         # There is no managed_interface
-        if [ -z ${managed_interface_name+x} ]; then
+        if [ -z "${managed_interface_name+x}" ]; then
             create_new_interface
+            assert_exit_code $LINENO "Failed to bring up new interface $interface."
         # Current managed interface is not present in new configuration
         elif [ "$managed_interface_name" != "$interface" ]; then
+            log_with_timestamp "INFO" "Cleaning old interface $managed_interface_name..."
             clean_old_interface
-            assert_exit_code $LINENO
+            assert_exit_code $LINENO "Failed to clean old interface $interface."
             create_new_interface
-            assert_exit_code $LINENO
+            assert_exit_code $LINENO "Failed to bring up new interface $interface."
         else
             # Update the configuration of current managed interface
             echo "Reloading wireguard interface $interface with config file $file..."
@@ -105,21 +161,31 @@ update_config() {
         assert_exit_code $LINENO
     done
 
+    log_with_timestamp "INFO" "Configuration update completed."
     # Save checksum of applied configuration
     echo $_latest_checksum > $_CHECKSUM_FILE
 
     export VXLAN_IPV4_METHOD="{{ openwisp2_wireguard_vxlan_ipv4_method }}" \
         VXLAN_IPV6_METHOD="{{ openwisp2_wireguard_vxlan_ipv6_method }}"
     if [ -e "$CONF_DIR/vxlan.json" ]; then
+        log_with_timestamp "INFO" "Updating VXLAN configuration using $CONF_DIR/vxlan.json."
         "$CONF_DIR/update_vxlan.py" "$CONF_DIR/vxlan.json"
+        assert_exit_code $LINENO "Failed to update VXLAN configuration."
+        log_with_timestamp "INFO" "VXLAN configuration updated successfully."
         mv -f "$CONF_DIR/vxlan.json" "$_APPLIED_CONF_DIR/vxlan.json"
+        log_with_timestamp "INFO" "Moved vxlan.json to $_APPLIED_CONF_DIR."
     fi
 }
 
 bring_up_interface() {
     for conf_file in $_APPLIED_CONF_DIR/*.conf; do
         [ -e "$conf_file" ] || continue
-        sudo wg-quick up $conf_file || true
+        log_with_timestamp "INFO" "Attempting to bring up interface with config: $conf_file"
+        # We don't want to exit the program if only one of many WireGuard interfaces
+        # fails to come up. That's the reason "log_with_timestamp" is used with "||"
+        # instead of "assert_exit_code".
+        sudo wg-quick up $conf_file || log_with_timestamp "ERROR" "Failed to bring up interface with config: $conf_file"
+        log_with_timestamp "INFO" "Successfully brought up interface with config: $conf_file"
     done
     exit 0
 }