Isaac Logging

Improvements to logging:
- Logging levels as DEBUG 0 INFO 1 WARN 2 ERROR 3 REQ 4
- External logging to Datadog
- A function to shorten duplicate lines in installation logs
- Ability to extract install.log in the time when Installomator was running, if further investigations needs to be done to logs

CHANGELOG.md

@@ -7,6 +7,12 @@
 - Changed logic if `IGNORE_APP_STORE_APPS=yes`. Before this version a label like `microsoftonedrive` that was installed from App Store, and that we want to replace with the “ordinary” version, Installomator would still use `updateTool`, even though `IGNORE_APP_STORE_APPS=yes`. So we would have to have `INSTALL=force` in order to have the app replaced, as `updateTool` would be used. But now if `IGNORE_APP_STORE_APPS=yes` then `updateTool` will be not set, and the App Store app will be replaced. BUT if the installed software was not from App Store, then `updateTool` will not be used, and it would be a kind of a forced install (in the example of `microsoftonedrive`), except if the version is the same (where installation is skipped).
 - Added variable `SYSTEMOWNER` that is used when copying files when installing. Default `0` is to change owner of the app to the current user on the Mac, like this user was installing this app themselves. When using `1` we will put “root:wheel” on the app, which can be useful for shared machines.
 
+Big changes to logging:
+- Logging levels as DEBUG 0 INFO 1 WARN 2 ERROR 3 REQ 4
+- External logging to Datadog
+- A function to shorten duplicate lines in installation logs
+- Ability to extract install.log in the time when Installomator was running, if further investigations needs to be done to logs
+
 ## v8.0
 
 - removed leading `0` from the version because it has lost all meaning (thanks to @grahampugh for the inspiration)

fragments/functions.sh

@@ -67,15 +67,104 @@ displaynotification() { # $1: message $2: title
 # MARK: Logging
 log_location="/private/var/log/Installomator.log"
 
-printlog(){
+# Check if we're in debug mode, if so then set logging to DEBUG, otherwise default to INFO
+# if no log level is specified.
+if [[ $DEBUG -ne 0 ]]; then
+    LOGGING=DEBUG
+elif [[ -z $LOGGING ]]; then
+    LOGGING=INFO
+    datadogLoggingLevel=INFO
+fi
 
+# Associate logging levels with a numerical value so that we are able to identify what
+# should be removed. For example if the LOGGING=ERROR only printlog statements with the
+# level REQ and ERROR will be displayed. LOGGING=DEBUG will show all printlog statements.
+# If a printlog statement has no level set it's automatically assigned INFO.
+
+declare -A levels=(DEBUG 0 INFO 1 WARN 2 ERROR 3 REQ 4)
+
+# If we are able to detect an MDM URL (Jamf Pro) or another identifier for a customer/instance we grab it here, this is useful if we're centrally logging multiple MDM instances.
+if [[ -f /Library/Preferences/com.jamfsoftware.jamf.plist ]]; then
+    mdmURL=$(defaults read /Library/Preferences/com.jamfsoftware.jamf.plist jss_url)
+elif [[ -n "$MDMProfileName" ]]; then
+    mdmURL=$(sudo profiles show | grep -A3 "$MDMProfileName" | sed -n -e 's/^.*organization: //p')
+else
+    mdmURL="Unknown"
+fi
+
+# Generate a session key for this run, this is useful to idenify streams when we're centrally logging.
+SESSION=$RANDOM
+
+printlog(){
+    [ -z "$2" ] && 2=INFO
+    log_message=$1
+    log_priority=$2
     timestamp=$(date +%F\ %T)
 
-    if [[ "$(whoami)" == "root" ]]; then
-        echo "$timestamp" "$label" "$1" | tee -a $log_location
-    else
-        echo "$timestamp" "$label" "$1"
+    # Check to make sure that the log isn't the same as the last, if it is then don't log and increment a timer.
+    if [[ ${log_message} == ${previous_log_message} ]];then
+        let logrepeat=$logrepeat+1
+        return
     fi
+
+    previous_log_message=$log_message
+
+    # Once we finally stop getting duplicate logs output the number of times we got a duplicate.
+    if [[ $logrepeat -gt 1 ]];then
+        echo "$timestamp" : "${log_priority} : ${VERSIONDATE//-/} : Last Log repeated ${logrepeat} times" | tee -a $log_location
+
+    if [[ ! -z $datadogAPI ]]; then
+        curl -s -X POST https://http-intake.logs.datadoghq.com/v1/input -H "Content-Type: text/plain" -H "DD-API-KEY: $datadogAPI" -d "${log_priority} : $mdmURL : $APPLICATION : $VERSIONDATE : $SESSION : Last Log repeated ${logrepeat} times" > /dev/null
+    fi
+    logrepeat=0
+
+    # If the datadogAPI key value is set and our logging level is greaterthan or equal to our set level
+    # then post to Datadog's HTTPs endpoint.
+    if [[ -n $datadogAPI && ${levels[$log_priority]} -ge ${levels[$datadogLoggingLevel]} ]]; then
+        while IFS= read -r logmessage; do
+            curl -s -X POST https://http-intake.logs.datadoghq.com/v1/input -H "Content-Type: text/plain" -H "DD-API-KEY: $datadogAPI" -d "${log_priority} : $mdmURL : Installomator-${label} : ${VERSIONDATE//-/} : $SESSION : ${logmessage}" > /dev/null
+        done <<< "$log_message"
+    fi
+
+    # If our logging level is greaterthan or equal to our set level then output locally.
+    if [[ ${levels[$log_priority]} -ge ${levels[$LOGGING]} ]]; then
+        while IFS= read -r logmessage; do
+            if [[ "$(whoami)" == "root" ]]; then
+                echo "$timestamp" : "${log_priority} : ${VERSIONDATE//-/} : ${logmessage}" | tee -a $log_location
+            else
+                echo "$timestamp" : "${log_priority} : ${VERSIONDATE//-/} : ${logmessage}"
+            fi
+        done <<< "$log_message"
+    fi
+
+#    if [[ "$(whoami)" == "root" ]]; then
+#        echo "$timestamp" "$label" "$1" | tee -a $log_location
+#    else
+#        echo "$timestamp" "$label" "$1"
+#    fi
+}
+
+# Used to remove dupplicate lines in large log output, for example from msupdate command
+# after it finishes running.
+deduplicatelogs() {
+    loginput=${1:-"Log"}
+    logoutput=""
+    # Read each line of the incoming log individually, match it with the previous.
+    # If it matches increment logrepeate then skip to the next line.
+    while read log; do
+        if [[ $log == $previous_log ]];then
+            let logrepeat=$logrepeat+1
+            continue
+        fi
+
+        previous_log="$log"
+        if [[ $logrepeat -gt 1 ]];then
+            logoutput+="Last Log repeated ${logrepeat} times\n"
+            logrepeat=0
+        fi
+
+        logoutput+="$log\n"
+    done <<< "$loginput"
 }
 
 # will get the latest release download from a github repo

fragments/header.sh

@@ -239,3 +239,40 @@ REOPEN="yes"
 #   installer that should be located after mounting/expanding the downloaded archive.
 #   See label adobecreativeclouddesktop
 #
+### Logging
+# Logging behavior
+LOGGING=""
+# options:
+#   - DEBUG     Everything is logged
+#   - INFO      (default) normal logging level
+#   - WARN      only warning
+#   - ERROR     only errors
+#   - REQ       ????
+
+# MDM profile name
+MDMProfileName=""
+# options:
+#   - MDM Profile               Addigy has this name on the profile
+#   - Mosyle Corporation MDM    Mosyle uses this name on the profile
+# From the LOGO variable we can know if Addigy og Mosyle is used, so if that variable
+# is either of these, and this variable is empty, then we can will auto detect this.
+
+# Datadog logging used
+datadogAPI=""
+# Simply add your own API key for this in order to have logs sent to Datadog
+# See more here: https://www.datadoghq.com/product/log-management/
+
+# Log Date format used when parsing logs for debugging, this is the default used by
+# install.log, override this in the case statements if you need something custom per
+# application (See adobeillustrator).  Using stadard GNU Date formatting.
+LogDateFormat="%Y-%m-%d %H:%M:%S"
+
+# Get the start time for parsing install.log if we fail.
+starttime=$(date "+$LogDateFormat")
+
+# Check if we have rosetta installed
+if [[ $(/usr/bin/arch) == "arm64" ]]; then
+    if ! arch -x86_64 /usr/bin/true >/dev/null 2>&1; then # pgrep oahd >/dev/null 2>&1
+        rosetta2=no
+    fi
+fi