From 8f1bb4f498e6cf499db610d5bb395dd8520c7e2e Mon Sep 17 00:00:00 2001 From: downtownallday Date: Wed, 29 Jun 2022 10:42:09 -0400 Subject: [PATCH] Add a z-push test suite --- tests/lib/rest.sh | 5 +- tests/runner.sh | 1 + tests/suites/_init_miabldap.sh | 1 + tests/suites/_mail-functions.sh | 104 +++++++++++++++++++++++++++++++ tests/suites/_zpush-functions.sh | 32 ++++++++++ tests/suites/z-push.sh | 70 +++++++++++++++++++++ 6 files changed, 211 insertions(+), 2 deletions(-) create mode 100644 tests/suites/_zpush-functions.sh create mode 100644 tests/suites/z-push.sh diff --git a/tests/lib/rest.sh b/tests/lib/rest.sh index 1cf6d22e..0e16e93b 100644 --- a/tests/lib/rest.sh +++ b/tests/lib/rest.sh @@ -23,7 +23,7 @@ rest_urlencoded() { # Return values: # 0 indicates success (curl returned 0 or a code deemed to be # successful and HTTP status is >=200 but <300) - # 1 curl returned with non-zero code that indicates and error + # 1 curl returned with non-zero code that indicates an error # 2 the response status was <200 or >= 300 # # Debug messages are sent to stderr @@ -78,7 +78,8 @@ rest_urlencoded() { done echo "spawn: curl -w \"%{http_code}\" -X $verb --user \"${auth_user}:xxx\" ${data[@]} $url" 1>&2 - output=$(curl -s -S -w "%{http_code}" -X $verb --user "${auth_user}:${auth_pass}" "${data[@]}" $url) + # pipe through 'tr' to avoid bash "warning: command substitution: ignored null byte in input" where curl places a \0 between output and http_code + output=$(curl -s -S -w "%{http_code}" -X $verb --user "${auth_user}:${auth_pass}" "${data[@]}" $url | tr -d '\0') local code=$? # http status is last 3 characters of output, extract it diff --git a/tests/runner.sh b/tests/runner.sh index 3a817324..870907ae 100755 --- a/tests/runner.sh +++ b/tests/runner.sh @@ -20,6 +20,7 @@ default_suites=( mail-aliases mail-access management-users + z-push ) extra_suites=( diff --git a/tests/suites/_init_miabldap.sh b/tests/suites/_init_miabldap.sh index ca16d786..5c2d4ef7 100644 --- a/tests/suites/_init_miabldap.sh +++ b/tests/suites/_init_miabldap.sh @@ -7,6 +7,7 @@ set +eu . suites/_ldap-functions.sh || exit 1 . suites/_mail-functions.sh || exit 1 . suites/_mgmt-functions.sh || exit 1 +. suites/_zpush-functions.sh || exit 1 MIAB_DIR=".." diff --git a/tests/suites/_mail-functions.sh b/tests/suites/_mail-functions.sh index 6acd7527..85336e95 100644 --- a/tests/suites/_mail-functions.sh +++ b/tests/suites/_mail-functions.sh @@ -59,6 +59,16 @@ start_log_capture() { MAIL_LOG_LINECOUNT=$(wc -l /var/log/mail.log 2>>$TEST_OF | awk '{print $1}') || die "could not access /var/log/mail.log" fi DOVECOT_LOG_LINECOUNT=$(doveadm log errors 2>>$TEST_OF | wc -l | awk '{print $1}') || die "could not access doveadm error logs" + ZPUSH_LOG_LINECOUNT=0 + if [ -e /var/log/z-push/z-push.log ]; then + # z-push-errors.log only has errors, but z-push.log has errors + # and other logging, so use that + ZPUSH_LOG_LINECOUNT=$(wc -l /var/log/z-push/z-push.log 2>>$TEST_OF | awk '{print $1}') || die "could not access /var/log/z-push/z-push.log" + fi + NGINX_ACCESS_LOG_LINECOUNT=0 + if [ -e /var/log/nginx/access.log ]; then + NGINX_ACCESS_LOG_LINECOUNT=$(wc -l /var/log/nginx/access.log 2>>$TEST_OF | awk '{print $1}') || die "could not access /var/log/nginx/access.log" + fi } start_mail_capture() { @@ -101,6 +111,9 @@ dump_capture_logs() { echo "" echo "============= DOVECOT ERRORS ==============" doveadm log errors | tail --lines=+$DOVECOT_LOG_LINECOUNT 2>>$TEST_OF + echo "" + echo "============= Z-PUSH LOG ==============" + tail --lines=+$ZPUSH_LOG_LINECOUND /var/log/z-push/z-push.log 2>>TEST_OF } detect_syslog_error() { @@ -254,6 +267,86 @@ detect_mail_log_error() { return ${x[2]} } +detect_zpush_log_error() { + record + record "[Detect z-push log errors]" + local count + let count="$ZPUSH_LOG_LINECOUNT + 1" + tail --lines=+$count /var/log/z-push/z-push.log 2>>$TEST_OF | ( + let ec=0 # error count + let wc=0 # warning count + let ignored=0 + while read line; do + awk ' +/\[FATAL\]/ && /Unable to read filename .\/var\/lib\/z-push\/users. after 3 retries/ { exit 2 } +/\[FATAL\]/ { exit 1 } +/\[WARN\]/ { exit 2 } +' \ + >>$TEST_OF 2>&1 <<< "$line" + r=$? + if [ $r -eq 1 ]; then + let ec+=1 + record "$F_DANGER[ERROR] $line$F_RESET" + elif [ $r -eq 2 ]; then + let wc+=1 + record "$F_WARN[ WARN] $line$F_RESET" + elif [ $r -eq 3 ]; then + let ignored+=1 + else + record "[ OK] $line" + fi + done + record "$ignored unreported/ignored log lines" + [ $ec -gt 0 ] && exit 0 + exit 1 # no errors + ) + local x=( ${PIPESTATUS[*]} ) + [ ${x[0]} -ne 0 ] && die "Could not read /var/log/z-push/z-push.log" + return ${x[1]} +} + +detect_nginx_access_log_error() { + record + record "[Detect nginx access log errors]" + local count + let count="$NGINX_ACCESS_LOG_LINECOUNT + 1" + tail --lines=+$count /var/log/nginx/access.log 2>>$TEST_OF | ( + let ec=0 # error count + let wc=0 # warning count + let ignored=0 + while read line; do + cat <= 400: os.exit(1) + except: + pass + #print("ROW=( '%s' )" % "','".join(row)) +EOF + >>$TEST_OF 2>&1 <<< "$line" + r=$? + if [ $r -eq 1 ]; then + let ec+=1 + record "$F_DANGER[ERROR] $line$F_RESET" + elif [ $r -eq 2 ]; then + let wc+=1 + record "$F_WARN[ WARN] $line$F_RESET" + elif [ $r -eq 3 ]; then + let ignored+=1 + else + record "[ OK] $line" + fi + done + record "$ignored unreported/ignored log lines" + [ $ec -gt 0 ] && exit 0 + exit 1 # no errors + ) + local x=( ${PIPESTATUS[*]} ) + [ ${x[0]} -ne 0 ] && die "Could not read /var/log/nginx/access.log" + return ${x[1]} +} check_logs() { local assert="${1:-false}" @@ -288,6 +381,17 @@ check_logs() { detect_mail_log_error && $assert && test_failure "detected errors in mail log" fi + + if array_contains zpush ${types[@]} || array_contains z-push ${types[@]} + then + detect_zpush_log_error && $assert && + test_failure "detected errors in z-push.log" + fi + + if array_contains nginx_access ${types[@]}; then + detect_nginx_access_log_error && $assert && + test_failure "detected errors in nginx access log" + fi } assert_check_logs() { diff --git a/tests/suites/_zpush-functions.sh b/tests/suites/_zpush-functions.sh new file mode 100644 index 00000000..e1268ef7 --- /dev/null +++ b/tests/suites/_zpush-functions.sh @@ -0,0 +1,32 @@ + + +zpush_start() { + # Must be called before performing any tests + # enable debug logging + zpush_set_loglevel "DEBUG" + zpush_reset_database +} + +zpush_end() { + # Clean up after zpush_start + zpush_set_loglevel "ERROR" # ERROR is the default + zpush_reset_database +} + +zpush_set_loglevel() { + local level="$1" # eg. "DEBUG" + local config="$ZPUSH_DIR/config.php" # ZPUSH_DIR from lib/locations.sh + record "[set z-push loglevel to '$level']" + sed -i -E "s/^(\\s+define\\('LOGLEVEL', LOGLEVEL_).*(\\).*)$/\\1${level}\\2/" "$config" >>$TEST_OF 2>&1 + [ $? -ne 0 ] && die "Could not set z-push LOGLEVEL in $config" +} + +zpush_reset_database() { + # zpush keeps track of users and their devices - reset the database + record "[reset z-push database]" + rm -rf /var/lib/z-push >>$TEST_OF 2>&1 \ + || die "Could not delete /var/lib/z-push" + mkdir /var/lib/z-push >>$TEST_OF 2>&1 + chmod 750 /var/lib/z-push >>$TEST_OF 2>&1 + chown www-data:www-data /var/lib/z-push >>$TEST_OF 2>&1 +} diff --git a/tests/suites/z-push.sh b/tests/suites/z-push.sh new file mode 100644 index 00000000..2ae00023 --- /dev/null +++ b/tests/suites/z-push.sh @@ -0,0 +1,70 @@ + + + +test_zpush_logon() { + test_start "zpush-logon" + + # create regular user alice + local alice="alice@somedomain.com" + local alice_pw="123alice" + create_user "$alice" "$alice_pw" + + # issue a "Ping" command to z-push + local devid="device1" + local devtype="iPhone" + record "[issue a 'Ping' command]" + start_log_capture + rest_urlencoded POST "/Microsoft-Server-ActiveSync?Cmd=Ping&DeviceId=$devid&DeviceType=$devtype" "$alice" "$alice_pw" 2>>$TEST_OF + if [ $? -ne 0 ]; then + test_failure "$REST_ERROR" + fi + record "$REST_OUTPUT" + + assert_check_logs zpush nginx_access + + if ! have_test_failures; then + # Make sure we have Logon() calls for all three combined + # backends by examining the z-push.log file (which has + # LOGLEVEL set to DEBUG by + # _zpush-functions.sh:zpush_start) + # + # Logons were successful because of the assert_check_logs + # call above. + # + # In addition, nginx/access.log will have entries for rest + # calls made by z-push to nextcloud, but we're not looking at + # those here. Any nextcloud failures will produce a failure in + # the Ping command and cause a test_failure by the + # assert_check_logs call above, so it's not needed. + + # expected_backends must be sorted + local expected_backends="BackendCalDAV BackendCardDAV BackendIMAP Combined" + + # Example z-push.log file entries: + # ------------------------- + # DD/MM/YYYY HH:MM:SS [33891] [DEBUG] [alice@somedomain.com] BackendIMAP->Logon(): User 'alice@somedomain.com' is authenticated on '{127.0.0.1:993/imap/ssl/norsh/novalidate-cert}' + # DD/MM/YYYY HH:MM:SS [33891] [DEBUG] [alice@somedomain.com] BackendCalDAV->Logon(): User 'alice@somedomain.com' is authenticated on CalDAV 'https://127.0.0.1:443/caldav/calendars/alice@somedomain.com/' + # DD/MM/YYYY HH:MM:SS [33891] [DEBUG] [alice@somedomain.com] BackendCardDAV->Logon(): User 'alice@somedomain.com' is authenticated on 'https://127.0.0.1:443/carddav/addressbooks/alice@somedomain.com/' + + local count + let count="$ZPUSH_LOG_LINECOUNT + 1" + local matches + matches=( $(tail --lines=+$count /var/log/z-push/z-push.log 2>>$TEST_OF | grep -F -- "->Logon(" 2>>$TEST_OF | sed -E "s/^.* (.*)->Logon\\(.*$/\\1/" 2>>%TEST_OF | sort | uniq) ) + record "found successful logons for backends: ${matches[*]}" + if [ "${matches[*]}" != "$expected_backends" ] + then + test_failure "Expected logons for backends '$expected_backends', but got '${matches[*]}'" + fi + fi + + delete_user "$alice" + test_end +} + + +suite_start "z-push" zpush_start + +test_zpush_logon + +suite_end zpush_end +