From 18d4c7e52bef4067f0fad39facbbcfa8c96729b9 Mon Sep 17 00:00:00 2001 From: Noriko Hosoi Date: Mon, 8 Jul 2019 13:39:05 -0700 Subject: [PATCH 01/37] LOG-372 - rsyslog - support improved undefined field handling Adding test cases to zzz-rsyslog.sh Adding the undefined field related env vars to rsyslog/README.md. Adding multi-container support to the rsyslog logs utility. Adding undefined test cases 6 & 7 to test/viaq-data-model.sh. --- hack/testing/test-viaq-data-model.py | 41 ++++++- hack/testing/util.sh | 23 +++- rsyslog/README.md | 9 ++ rsyslog/undefined_field/undefined_field.go | 12 +- rsyslog/utils/logs | 44 ++++++- test/viaq-data-model.sh | 42 +++++++ test/zzz-rsyslog.sh | 128 ++++++++++++++++++++- 7 files changed, 280 insertions(+), 19 deletions(-) diff --git a/hack/testing/test-viaq-data-model.py b/hack/testing/test-viaq-data-model.py index ad2903162..27c3ef4aa 100644 --- a/hack/testing/test-viaq-data-model.py +++ b/hack/testing/test-viaq-data-model.py @@ -41,7 +41,8 @@ def empty(thing): "undefined23": False }, "undefined4": "undefined4", - "undefined5": "undefined5" + "undefined5": "undefined5", + "undefined.6": "undefined6" }, "test2": {"undefined": {"undefined1": "undefined1", @@ -53,7 +54,8 @@ def empty(thing): "undefined23": False }, "undefined4": "undefined4", - "undefined5": "undefined5" + "undefined5": "undefined5", + "undefined.6": "undefined6" } }, "test3": {"undefined": @@ -64,7 +66,8 @@ def empty(thing): "undefined2": "undefined2", "undefined22": 2222, "undefined23": False - } + }, + "undefined.6": "undefined6" }, "undefined4": "undefined4", "undefined5": "undefined5" @@ -77,7 +80,8 @@ def empty(thing): "undefined2": "undefined2", "undefined22": 2222, "undefined23": False - } + }, + "undefined.6": "undefined6" }, "undefined4": "undefined4", "undefined5": "undefined5" @@ -90,7 +94,34 @@ def empty(thing): "undefined2": "undefined2", "undefined22": 2222, "undefined23": False - } + }, + "undefined.6": "undefined6" + }, + "undefined4": "undefined4", + "undefined5": "undefined5", + "empty1": "", + "undefined3": {"emptyvalue": ""} + }, + "test6": {"myname": + {"undefined1": "undefined1", + "undefined11": 1111, + "undefined12": True, + "undefined2": { + "undefined2": "undefined2", + "undefined22": 2222, + "undefined23": False + }, + "undefined_6": "undefined6" + }, + "undefined4": "undefined4", + "undefined5": "undefined5", + "empty1": "", + "undefined3": {"emptyvalue": ""} + }, + "test7": {"myname": + {"undefined1": "undefined1", + "undefined11": 1111, + "undefined12": True, }, "undefined4": "undefined4", "undefined5": "undefined5", diff --git a/hack/testing/util.sh b/hack/testing/util.sh index ccd8e4833..b06659e7a 100644 --- a/hack/testing/util.sh +++ b/hack/testing/util.sh @@ -582,8 +582,6 @@ function wait_for_fluentd_to_catch_up() { else os::log::error ops record for "$uuid_es_ops" not found in journal fi - os::log::error here is the starting fluentd journal cursor - echo $journalstartcursor os::log::error here is the current fluentd journal cursor oal_sudo cat /var/log/journal.pos || : oal_sudo cat /var/log/journal_pos.json || : @@ -713,6 +711,19 @@ get_mux_pod_log() { oc exec $pod -- cat $logfile 2> /dev/null || : } +# rsyslog may have pod logs and logs in the file +get_rsyslog_pod_log() { + local pod=${1:-$( get_running_pod rsyslog )} + local logfile=${2:-/var/log/rsyslog/rsyslog.log} + oc logs $pod -c rsyslog 2>&1 + if oc exec $pod -c rsyslog -- logs --all 2>&1 ; then + : # done + elif oal_sudo test -f $logfile ; then + # can't read from the pod directly - see if we can get the log file + oal_sudo cat $logfile + fi +} + # writes all pod logs to the given outdir or $ARTIFACT_DIR in the form # pod_name.container_name.log # it will get both the oc logs output and any log files produced by @@ -728,12 +739,13 @@ get_all_logging_pod_logs() { case "$p" in logging-fluentd-*|fluentd-*) get_fluentd_pod_log $p > $ARTIFACT_DIR/$p.$container.log 2>&1 ;; logging-mux-*) get_mux_pod_log $p > $ARTIFACT_DIR/$p.$container.log 2>&1 ;; + logging-rsyslog-*|rsyslog-*) get_rsyslog_pod_log $p > $ARTIFACT_DIR/$p.$container.log 2>&1 ;; logging-es-*|elasticsearch-*) oc logs -n ${LOGGING_NS} -c $container $p > $ARTIFACT_DIR/$p.$container.log 2>&1 oc exec -c elasticsearch -n ${LOGGING_NS} $p -- logs >> $ARTIFACT_DIR/$p.$container.log 2>&1 ;; - *) oc logs -n ${LOGGING_NS} -c $container $p > $ARTIFACT_DIR/$p.$container.log 2>&1 ;; + *) oc logs -n ${LOGGING_NS} -c $container $p > $ARTIFACT_DIR/$p.$container.log 2>&1 ;; esac - done + done done } @@ -784,6 +796,9 @@ get_fluentd_cm_name() { fluentd_cm=${fluentd_cm:-$(get_fluentd_cm_name)} +# Hardcode daemonset/rsyslog for the case the rsyslog pod does not exist. +rsyslog_ds=${rsyslog_ds:-daemonset/rsyslog} + enable_cluster_logging_operator() { if oc -n ${LOGGING_NS} get deploy cluster-logging-operator > /dev/null 2>&1 ; then oc patch -n ${LOGGING_NS} clusterlogging instance --type=json --patch '[ diff --git a/rsyslog/README.md b/rsyslog/README.md index e98da5a57..3f18342e9 100644 --- a/rsyslog/README.md +++ b/rsyslog/README.md @@ -10,6 +10,15 @@ Following are the environment variables that can be modified to adjust the confi | `LOGGING_FILE_PATH` | The log file absolute path where Rsyslog is writting its logs. If you want rsyslog to output its logs as Rsyslog does by default (`STDOUT`) set this variable to `console` value. Default value is `/var/log/rsyslog/rsyslog.log`. | `LOGGING_FILE_PATH=console` | | `LOGGING_FILE_AGE` | Number of log files that Rsyslog keeps before deleting the oldest file. Default value is `10`. | `LOGGING_FILE_AGE=30` | | `LOGGING_FILE_SIZE` | Maximum size of a rsyslog log file in bytes. If the size of the log file is bigger, the log file gets rotated. Default is 1MB | `LOGGING_FILE_SIZE=1024000` +| `CDM_USE_UNDEFINED` | Parameter to switch whether undefined fields are moved to the undefined property or not. default to "false". | `CDM_USE_UNDEFINED=true` +| `CDM_DEFAULT_KEEP_FIELDS` | Default set of fields to be kept in the top level of json. default to "CEE,time,@timestamp,aushape,ci_job,collectd,docker,fedora-ci,file,foreman,geoip,hostname,ipaddr4,ipaddr6,kubernetes,level,message,namespace_name,namespace_uuid,offset,openstack,ovirt,pid,pipeline_metadata,rsyslog,service,systemd,tags,testcase,tlog,viaq_msg_id", | - +| `CDM_EXTRA_KEEP_FIELDS` | Extra set of fields to be kept in the top level of json. A field not included in ${CDM_DEFAULT_KEEP_FIELDS} nor ${CDM_EXTRA_KEEP_FIELDS} are moved to ${CDM_UNDEFINED_NAME} if CDM_USE_UNDEFINED is "true". default to "" | `CDM_EXTRA_KEEP_FIELDS="broker"` +| `CDM_UNDEFINED_NAME` | Undefined property name used when CDM_USE_UNDEFINED is set to "true". default to "undefined". | `CDM_UNDEFINED_NAME="undef"` +| `CDM_KEEP_EMPTY_FIELDS` | Empty fields are dropped except the fields which names are set to CDM_KEEP_EMPTY_FIELDS in the CSV format. default to "". | `CDM_KEEP_EMPTY_FIELDS="offset"` +| `CDM_UNDEFINED_TO_STRING` | If set to "true", when CDM_USE_UNDEFINED is "true" and undefined property with ${CDM_UNDEFINED_NAME} is created, the value is converted to the json string. default to "false". | `CDM_UNDEFINED_TO_STRING=true +| `CDM_UNDEFINED_DOT_REPLACE_CHAR` | A dot character '.' in a property name (key) is replaced with the specified character unless the value is not "UNUSED". default to "UNUSED". Effective when MERGE_JSON_LOG is true. | `CDM_UNDEFINED_DOT_REPLACE_CHAR="_"` +| `CDM_UNDEFINED_MAX_NUM_FIELDS` | If a positive value is set, undefined fields are dropped once the number of fields has reached the value. default to "-1". | `CDM_UNDEFINED_MAX_NUM_FIELDS=4` +| `UNDEFINED_DEBUG` | Debug flag used in undefined_field as well as the config file calling the plugin. A debug file /var/log/rsyslog/rsyslog_debug.log is generated. default to "false". | `UNDEFINED_DEBUG=true` ## Rsyslog logging to file Rsyslog by default writes its logs into a file given by `LOGGING_FILE_PATH` environment variable. You can change the maximum size of a single log file or number of log files to keep(age), by setting `LOGGING_FILE_SIZE` and `LOGGING_FILE_AGE` environment variables accordingly. diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 3a410b62f..871ef7954 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -298,7 +298,9 @@ func main() { jsonMap := make(map[string]interface{}) rawStr := scanner.Text() if noaction { - fmt.Fprintln(logfile, "No Action Needed for ", rawStr) + if undefined_debug { + fmt.Fprintln(logfile, "No Action Needed for ", rawStr) + } fmt.Println(noChanges) continue } @@ -315,7 +317,9 @@ func main() { } topval, ismap := jsonMap["$!"].(map[string]interface{}) if !ismap { - fmt.Fprintln(logfile, "Result is String: ", rawStr) + if undefined_debug { + fmt.Fprintln(logfile, "Result is String: ", rawStr) + } fmt.Println(noChanges) continue } @@ -325,7 +329,9 @@ func main() { undefined_cur_num_fields = undefined_max_num_fields all, replace_me, has_undefined := replaceDotMoveUndefined(topval, true) if !replace_me { - fmt.Fprintln(logfile, "No Need to Replace for ", rawStr) + if undefined_debug { + fmt.Fprintln(logfile, "No Need to Replace for ", rawStr) + } fmt.Println(noChanges) continue } diff --git a/rsyslog/utils/logs b/rsyslog/utils/logs index ba908f940..5bb775fef 100755 --- a/rsyslog/utils/logs +++ b/rsyslog/utils/logs @@ -2,6 +2,7 @@ set -euo pipefail log_dir=`dirname ${LOGGING_FILE_PATH:-/var/log/rsyslog/rsyslog.log}` +pod_dir=${RSYSLOG_WORKDIRECTORY:-/var/lib/rsyslog.pod} cmd=cat helpMsg() { @@ -11,11 +12,13 @@ cat < /dev/null 2>&1 ) ; then + echo "" + echo "===== rsyslog debug logs =====" + for log_file in $( ls $log_dir/rsyslog_debug.* | sort -Vr ); do + cat $log_file + done + fi + if $( ls $log_dir/logrotate* > /dev/null 2>&1 ) ; then + echo "" + echo "===== logrotation logs ($log_dir) =====" + for log_file in $( ls $log_dir/logrotate* | sort -Vr ); do + cat $log_file + done + fi + if $( ls $pod_dir/logrotate* > /dev/null 2>&1 ) ; then + echo "" + echo "===== logrotation logs ($pod_dir) =====" + for log_file in $( ls $pod_dir/logrotate* | sort -Vr ); do + cat $log_file + done + fi + else + for log_file in $( ls $log_dir/rsyslog.* | sort -Vr ); do + cat $log_file + done + fi else log_file=`basename ${LOGGING_FILE_PATH:-/var/log/rsyslog/rsyslog.log}` exec tail "$tail_args" $log_dir/$log_file diff --git a/test/viaq-data-model.sh b/test/viaq-data-model.sh index 528b3d7f6..f6fc10853 100755 --- a/test/viaq-data-model.sh +++ b/test/viaq-data-model.sh @@ -85,6 +85,7 @@ cat > $cfg < remove_keys CONTAINER_TAG,logtag @@ -177,6 +178,47 @@ os::cmd::expect_success "cat $ARTIFACT_DIR/viaq-data-model-test.json | \ os::cmd::expect_success "cat $ARTIFACT_DIR/viaq-data-model-test-ops.json | \ python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test5 allow_empty" +# TEST 6 +# replace dot with underscore +stop_fluentd "${fpod:-}" $FLUENTD_WAIT_TIME 2>&1 | artifact_out +oc set env $fluentd_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 MERGE_JSON_LOG=true CDM_UNDEFINED_DOT_REPLACE_CHAR=_ 2>&1 | artifact_out +start_fluentd false $FLUENTD_WAIT_TIME 2>&1 | artifact_out +# if using MUX_CLIENT_MODE=maximal, also have to tell mux to replace the dots +is_maximal=$( oc set env $fluentd_ds --list | grep ^MUX_CLIENT_MODE=maximal ) || : +if [ -n "$is_maximal" ] ; then + muxpod=$( get_running_pod mux ) + oc set env dc/logging-mux MERGE_JSON_LOG=true CDM_UNDEFINED_DOT_REPLACE_CHAR=_ + os::cmd::try_until_failure "oc get pod $muxpod" + os::cmd::try_until_text "oc get pods -l component=mux" "^logging-mux-.* Running " +fi +fpod=$( get_running_pod fluentd ) +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $ARTIFACT_DIR/viaq-data-model-test.json | \ + python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test6 allow_empty" +os::cmd::expect_success "cat $ARTIFACT_DIR/viaq-data-model-test-ops.json | \ + python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test6 allow_empty" + +# TEST 7 +# set CDM_UNDEFINED_MAX_NUM_FIELDS to 3 +stop_fluentd "${fpod:-}" $FLUENTD_WAIT_TIME 2>&1 | artifact_out +oc set env $fluent_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 CMERGE_JSON_LOG=true DM_UNDEFINED_DOT_REPLACE_CHAR=_ CDM_UNDEFINED_MAX_NUM_FIELDS=3 2>&1 | artifact_out + +start_fluentd false $FLUENTD_WAIT_TIME 2>&1 | artifact_out +# if using MUX_CLIENT_MODE=maximal, also have to tell mux to replace the dots +is_maximal=$( oc set env $fluentd_ds --list | grep ^MUX_CLIENT_MODE=maximal ) || : +if [ -n "$is_maximal" ] ; then + muxpod=$( get_running_pod mux ) + oc set env dc/logging-mux CDM_UNDEFINED_MAX_NUM_FIELDS=3 + os::cmd::try_until_failure "oc get pod $muxpod" + os::cmd::try_until_text "oc get pods -l component=mux" "^logging-mux-.* Running " +fi +fpod=$( get_running_pod fluentd ) +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $ARTIFACT_DIR/viaq-data-model-test.json | \ + python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test7 allow_empty" +os::cmd::expect_success "cat $ARTIFACT_DIR/viaq-data-model-test-ops.json | \ + python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test7 allow_empty" + if [ -n "$is_maximal" ] ; then muxpod=$( get_running_pod mux ) oc set env dc/logging-mux CDM_KEEP_EMPTY_FIELDS- diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 33ecd7cb6..e901dc7f3 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -9,6 +9,7 @@ os::util::environment::use_sudo os::test::junit::declare_suite_start "test/zzz-rsyslog" +LOGGING_NS=${LOGGING_NS:-openshift-logging} es_pod=$( get_es_pod es ) es_ops_pod=$( get_es_pod es-ops ) es_ops_pod=${es_ops_pod:-$es_pod} @@ -47,6 +48,7 @@ cleanup() { local return_code="$?" set +e get_all_logging_pod_logs + oc get cm rsyslog -o yaml > $ARTIFACT_DIR/rsyslog_configmap.yaml 2>&1 if [ "deploy_using_ansible" = "$deployfunc" ] ; then if [ -n "${tmpinv:-}" -a -f "${tmpinv:-}" ] ; then rm -f $tmpinv @@ -274,7 +276,7 @@ if [ $logsize -gt 0 ]; then oc exec $rpod -c rsyslog -- ls -l /var/log/rsyslog/ | artifact_out oc exec $rpod -c rsyslog -- cat /var/log/rsyslog/rsyslog.log > $ARTIFACT_DIR/rsyslog-before-rotation.log # this will restart the rsyslog pod - oc set env daemonset/rsyslog LOGGING_FILE_SIZE=$maxsize LOGGING_FILE_AGE=$maxcount + oc set env $rsyslog_ds LOGGING_FILE_SIZE=$maxsize LOGGING_FILE_AGE=$maxcount os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" @@ -320,9 +322,131 @@ else fi # switch LOGGING_FILE_PATH to console -oc set env daemonset/rsyslog LOGGING_FILE_PATH=console +oc set env $rsyslog_ds LOGGING_FILE_PATH=console os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" rpod=$( get_running_pod rsyslog ) oc logs $rpod -c rsyslog > $ARTIFACT_DIR/rsyslog.console.log 2>&1 os::cmd::expect_failure "grep 'oc exec -- logs' $ARTIFACT_DIR/rsyslog.console.log" + +# switch back LOGGING_FILE_PATH to default +oc set env $rsyslog_ds LOGGING_FILE_PATH- +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +rpod=$( get_running_pod rsyslog ) + +artifact_log "************************" +artifact_log "Testing undefined fields" +artifact_log "************************" + +artifact_log "0. Preparing test data" +cfgdir=$( mktemp -d ) +oc extract cm/rsyslog --to=$cfgdir +cat > $cfgdir/66-debug.conf << EOF +# DEBUGGING +set \$!undefined1 = "undefined1"; +set \$!undefined11 = 1111; +set \$!undefined12 = "true"; +set \$!empty1 = ""; +set \$!undefined2!undefined2 = "undefined2"; +set \$!undefined1!undefined22 = 2222; +set \$!undefined2!undefined23 = "false"; +set \$!undefined3!emptyvalue = ""; +set \$!undefined4 = "undefined4"; +set \$!undefined5 = "undefined5"; +set \$!undefined.6 = "undefined6"; +# DEBUGGING +EOF +ls -l $cfgdir | artifact_out +oc delete cm rsyslog +oc create cm rsyslog --from-file=$cfgdir + +restart_rsyslog_pod $rpod +rpod=$( get_running_pod rsyslog ) + +oc exec $rpod -c rsyslog -- ls -l /etc/rsyslog.d/66-debug.conf | artifact_out +oc exec $rpod -c rsyslog -- cat /etc/rsyslog.d/66-debug.conf | artifact_out + +# DEBUG DEBUG DEBUG +oc set env $rsyslog_ds UNDEFINED_DEBUG=true +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +# DEBUG DEBUG DEBUG + +artifact_log "1. default values" +os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'use_undefined:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}'" "false" +os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'undefined_name:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}'" "undefined" +artifact_log "ok" + +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test1" +os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test1" + +artifact_log "2. enable use_undefined - undefined fields are stored in 'undefined' field" +keep_fields="method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL" +oc set env $rsyslog_ds CDM_USE_UNDEFINED=true CDM_EXTRA_KEEP_FIELDS=$keep_fields 2>&1 | artifact_out +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +rpod=$( get_running_pod rsyslog ) +os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'use_undefined:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}'" "true" + +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test2" +os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test2" + +artifact_log "3. user specifies extra fields to keep" +oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,$keep_fields 2>&1 | artifact_out +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +rpod=$( get_running_pod rsyslog ) +os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'extra_keep_fields:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}' | sed -e 's/.*\(undefined4\).*/\1/'" "undefined4" + +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test3" +os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test3" + +artifact_log "4. user specifies alternate undefined name to use" +oc set env $rsyslog_ds CDM_UNDEFINED_NAME=myname 2>&1 | artifact_out +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +rpod=$( get_running_pod rsyslog ) +os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'undefined_name:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}'" "myname" + +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test4" +os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test4" + +artifact_log "5. reserve specified empty field as empty" +oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 2>&1 | artifact_out +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +rpod=$( get_running_pod rsyslog ) +os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'keep_empty_fields:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}' | sed -e 's/.*\(empty1\).*/\1/'" "empty1" + +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test5 allow_empty" +os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test5 allow_empty" + +artifact_log "6. replace dot with underscore" +oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 MERGE_JSON_LOG=true CDM_UNDEFINED_DOT_REPLACE_CHAR=_ 2>&1 | artifact_out +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +rpod=$( get_running_pod rsyslog ) + +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test6 allow_empty" +os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test6 allow_empty" + +artifact_log "7. set CDM_UNDEFINED_MAX_NUM_FIELDS to 3" +oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 CMERGE_JSON_LOG=true DM_UNDEFINED_DOT_REPLACE_CHAR=_ CDM_UNDEFINED_MAX_NUM_FIELDS=3 2>&1 | artifact_out +os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" +os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +rpod=$( get_running_pod rsyslog ) + +wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 +os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test7 allow_empty" +os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test7 allow_empty" + +os::cmd::expect_success "oc exec $rpod -c rsyslog -- ls -l /var/log/rsyslog/rsyslog.log" +os::cmd::expect_failure "oc exec $rpod -c rsyslog -- grep 'panic: interface conversion' /var/log/rsyslog/rsyslog.log" + From 0a3fb1ef730d631de44a9933ec5fafad8f21699c Mon Sep 17 00:00:00 2001 From: Richard Megginson Date: Fri, 12 Jul 2019 15:12:45 -0600 Subject: [PATCH 02/37] no parentheses in if test The `if` command itself will return true or false - no need to enclose in `$( ... )` --- rsyslog/utils/logs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/rsyslog/utils/logs b/rsyslog/utils/logs index 5bb775fef..d9173b391 100755 --- a/rsyslog/utils/logs +++ b/rsyslog/utils/logs @@ -46,21 +46,21 @@ if [ $cmd = "cat" ] ; then for log_file in $( ls $log_dir/rsyslog.* | sort -Vr ); do cat $log_file done - if $( ls $log_dir/rsyslog_debug.* > /dev/null 2>&1 ) ; then + if ls $log_dir/rsyslog_debug.* > /dev/null 2>&1 ; then echo "" echo "===== rsyslog debug logs =====" for log_file in $( ls $log_dir/rsyslog_debug.* | sort -Vr ); do cat $log_file done fi - if $( ls $log_dir/logrotate* > /dev/null 2>&1 ) ; then + if ls $log_dir/logrotate* > /dev/null 2>&1 ; then echo "" echo "===== logrotation logs ($log_dir) =====" for log_file in $( ls $log_dir/logrotate* | sort -Vr ); do cat $log_file done fi - if $( ls $pod_dir/logrotate* > /dev/null 2>&1 ) ; then + if ls $pod_dir/logrotate* > /dev/null 2>&1 ; then echo "" echo "===== logrotation logs ($pod_dir) =====" for log_file in $( ls $pod_dir/logrotate* | sort -Vr ); do From 38bce2bbd38438ee06c52c31ac0d0fd0ee6686f9 Mon Sep 17 00:00:00 2001 From: Richard Megginson Date: Fri, 12 Jul 2019 21:08:27 -0600 Subject: [PATCH 03/37] undefined_field output should be quiet unless undefined_debug The undefined_field mmexternal program should be quiet if undefined_debug is not set --- rsyslog/undefined_field/undefined_field.go | 22 ++++++++++++---------- 1 file changed, 12 insertions(+), 10 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 871ef7954..71f691c6b 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -191,16 +191,18 @@ func onInit() { replacer = strings.NewReplacer(".", undefined_dot_replace_char) } - fmt.Fprintln(logfile, "mmexternal: merge_json_log: ", merge_json_log) - fmt.Fprintln(logfile, "mmexternal: use_undefined: ", use_undefined) - fmt.Fprintln(logfile, "mmexternal: default_keep_fields: ", default_keep_fields) - fmt.Fprintln(logfile, "mmexternal: extra_keep_fields: ", extra_keep_fields) - fmt.Fprintln(logfile, "mmexternal: undefined_name: ", undefined_name) - fmt.Fprintln(logfile, "mmexternal: keep_empty_fields: ", tmp_keep_empty_fields) - fmt.Fprintln(logfile, "mmexternal: undefined_to_string: ", undefined_to_string) - fmt.Fprintln(logfile, "mmexternal: undefined_dot_replace_char: ", undefined_dot_replace_char) - fmt.Fprintln(logfile, "mmexternal: undefined_max_num_fields: ", undefined_max_num_fields) - fmt.Fprintln(logfile, "mmexternal: noaction: ", noaction) + if undefined_debug { + fmt.Fprintln(logfile, "mmexternal: merge_json_log: ", merge_json_log) + fmt.Fprintln(logfile, "mmexternal: use_undefined: ", use_undefined) + fmt.Fprintln(logfile, "mmexternal: default_keep_fields: ", default_keep_fields) + fmt.Fprintln(logfile, "mmexternal: extra_keep_fields: ", extra_keep_fields) + fmt.Fprintln(logfile, "mmexternal: undefined_name: ", undefined_name) + fmt.Fprintln(logfile, "mmexternal: keep_empty_fields: ", tmp_keep_empty_fields) + fmt.Fprintln(logfile, "mmexternal: undefined_to_string: ", undefined_to_string) + fmt.Fprintln(logfile, "mmexternal: undefined_dot_replace_char: ", undefined_dot_replace_char) + fmt.Fprintln(logfile, "mmexternal: undefined_max_num_fields: ", undefined_max_num_fields) + fmt.Fprintln(logfile, "mmexternal: noaction: ", noaction) + } } func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (map[string]interface{},bool,bool) { From 0e1ba63f556f90ce9a303e8b460d2854264ee03a Mon Sep 17 00:00:00 2001 From: Noriko Hosoi Date: Fri, 12 Jul 2019 21:59:10 -0700 Subject: [PATCH 04/37] Wait until "use_undefined:" appears in rsyslog.log. --- hack/testing/util.sh | 12 ------------ test/zzz-rsyslog.sh | 9 +++++---- 2 files changed, 5 insertions(+), 16 deletions(-) diff --git a/hack/testing/util.sh b/hack/testing/util.sh index e5016da1f..8df35f1f1 100644 --- a/hack/testing/util.sh +++ b/hack/testing/util.sh @@ -709,18 +709,6 @@ get_fluentd_pod_log() { fi } -# rsyslog may have pod logs and logs in the file -get_rsyslog_pod_log() { - local pod=${1:-$( get_running_pod rsyslog )} - local container=${2:-rsyslog} - oc logs -c $container $pod 2>&1 - if [ $container = rsyslog ] ; then - oc exec -c $container $pod -- logs 2>&1 || oal_sudo cat /var/log/rsyslog/rsyslog.log.* /var/log/rsyslog/rsyslog.log || : - else - oal_sudo cat /var/lib/rsyslog.pod/logrotate.log /var/log/rsyslog/logrotate.log || : - fi -} - get_mux_pod_log() { local pod=${1:-$( get_running_pod mux )} local logfile=${2:-/var/log/fluentd/fluentd.log} diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index e901dc7f3..1f962bad3 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -346,11 +346,11 @@ cat > $cfgdir/66-debug.conf << EOF # DEBUGGING set \$!undefined1 = "undefined1"; set \$!undefined11 = 1111; -set \$!undefined12 = "true"; +set \$!undefined12 = "True"; set \$!empty1 = ""; set \$!undefined2!undefined2 = "undefined2"; set \$!undefined1!undefined22 = 2222; -set \$!undefined2!undefined23 = "false"; +set \$!undefined2!undefined23 = "False"; set \$!undefined3!emptyvalue = ""; set \$!undefined4 = "undefined4"; set \$!undefined5 = "undefined5"; @@ -367,11 +367,12 @@ rpod=$( get_running_pod rsyslog ) oc exec $rpod -c rsyslog -- ls -l /etc/rsyslog.d/66-debug.conf | artifact_out oc exec $rpod -c rsyslog -- cat /etc/rsyslog.d/66-debug.conf | artifact_out -# DEBUG DEBUG DEBUG +# UNDEFINED_DEBUG needs to be enabled for checking configs in the following tests. oc set env $rsyslog_ds UNDEFINED_DEBUG=true os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" -# DEBUG DEBUG DEBUG +rpod=$( get_running_pod rsyslog ) +os::cmd::try_until_success "oc exec $rpod -c rsyslog -- grep 'use_undefined:' /var/log/rsyslog/rsyslog.log" artifact_log "1. default values" os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'use_undefined:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}'" "false" From fdba78f47d50022a24952536a1d8575c003122b5 Mon Sep 17 00:00:00 2001 From: Noriko Hosoi Date: Sun, 14 Jul 2019 07:12:40 -0700 Subject: [PATCH 05/37] Trying boolean value in rsyslog "set". @@ -346,11 +346,11 @@ cat > $cfgdir/66-debug.conf << EOF .... -set \$!undefined12 = "True"; +set \$!undefined12 = True; .... -set \$!undefined2!undefined23 = "False"; +set \$!undefined2!undefined23 = False; --- test/zzz-rsyslog.sh | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 1f962bad3..1ae0ea5c2 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -346,11 +346,11 @@ cat > $cfgdir/66-debug.conf << EOF # DEBUGGING set \$!undefined1 = "undefined1"; set \$!undefined11 = 1111; -set \$!undefined12 = "True"; +set \$!undefined12 = True; set \$!empty1 = ""; set \$!undefined2!undefined2 = "undefined2"; set \$!undefined1!undefined22 = 2222; -set \$!undefined2!undefined23 = "False"; +set \$!undefined2!undefined23 = False; set \$!undefined3!emptyvalue = ""; set \$!undefined4 = "undefined4"; set \$!undefined5 = "undefined5"; From 1ea5eefd0fdca4088fcd11d50e5fbd0902357a55 Mon Sep 17 00:00:00 2001 From: Noriko Hosoi Date: Sun, 14 Jul 2019 21:25:11 -0700 Subject: [PATCH 06/37] Use parse_json to generate test data. --- rsyslog/undefined_field/undefined_field.go | 3 +++ test/zzz-rsyslog.sh | 14 +------------- 2 files changed, 4 insertions(+), 13 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 71f691c6b..74d52f8c1 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -210,6 +210,9 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m has_undefined := false cp := make(map[string]interface{}) for origkey, value := range input { + if len(origkey) == 0 { + continue + } key := origkey if topPropLevel && merge_json_log && undefined_dot_replace_char != "UNUSED" { // replace '.' with specified char (e.g., '_') diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 1ae0ea5c2..bb23b5a71 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -343,19 +343,7 @@ artifact_log "0. Preparing test data" cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF -# DEBUGGING -set \$!undefined1 = "undefined1"; -set \$!undefined11 = 1111; -set \$!undefined12 = True; -set \$!empty1 = ""; -set \$!undefined2!undefined2 = "undefined2"; -set \$!undefined1!undefined22 = 2222; -set \$!undefined2!undefined23 = False; -set \$!undefined3!emptyvalue = ""; -set \$!undefined4 = "undefined4"; -set \$!undefined5 = "undefined5"; -set \$!undefined.6 = "undefined6"; -# DEBUGGING +set $.ret = parse_json("{\"undefined1\":\"undefined1\",\"undefined11\":1111,\"undefined12\":True,\"empty1\":\"\",\"undefined2\":{\"undefined2\":\"undefined2\",\"\":\"\",\"undefined22\":2222,\"undefined23\":False},\"undefined3\":{\"emptyvalue\":\"\"},\"undefined4\":\"undefined4\",\"undefined5\":\"undefined5\",\"undefined.6\":\"undefined6\"}", "\$!"); EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From 13c407de334660d2ae56231dfc3aab44979d26fd Mon Sep 17 00:00:00 2001 From: Noriko Hosoi Date: Mon, 15 Jul 2019 20:41:28 -0700 Subject: [PATCH 07/37] Following the suggestion: https://github.com/openshift/origin-aggregated-logging/pull/1685#discussion_r303713318 --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index bb23b5a71..5f6decef0 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -343,7 +343,7 @@ artifact_log "0. Preparing test data" cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF -set $.ret = parse_json("{\"undefined1\":\"undefined1\",\"undefined11\":1111,\"undefined12\":True,\"empty1\":\"\",\"undefined2\":{\"undefined2\":\"undefined2\",\"\":\"\",\"undefined22\":2222,\"undefined23\":False},\"undefined3\":{\"emptyvalue\":\"\"},\"undefined4\":\"undefined4\",\"undefined5\":\"undefined5\",\"undefined.6\":\"undefined6\"}", "\$!"); +set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":"False"},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From 60c967212ca05a3e10e9b9e4cba3a53e00ba29e1 Mon Sep 17 00:00:00 2001 From: Noriko Hosoi Date: Tue, 16 Jul 2019 07:28:57 -0700 Subject: [PATCH 08/37] Removing "noaction" from undefined_field.go --- rsyslog/undefined_field/undefined_field.go | 12 ------------ test/zzz-rsyslog.sh | 2 +- 2 files changed, 1 insertion(+), 13 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 74d52f8c1..d82c2b689 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -115,7 +115,6 @@ var ( undefined_max_num_fields int64 undefined_cur_num_fields int64 logfile *os.File - noaction = false replacer = &strings.Replacer{} ) @@ -164,9 +163,6 @@ func onInit() { panic(fmt.Errorf("Could not open config file [%s]: [%v]", undefined_config, err)) } - if !use_undefined && tmp_keep_empty_fields == "" && !undefined_to_string && undefined_dot_replace_char == "UNUSED" { - noaction = true - } if undefined_max_num_fields == -1 { undefined_max_num_fields = int64(^uint(0) >> 1) } @@ -201,7 +197,6 @@ func onInit() { fmt.Fprintln(logfile, "mmexternal: undefined_to_string: ", undefined_to_string) fmt.Fprintln(logfile, "mmexternal: undefined_dot_replace_char: ", undefined_dot_replace_char) fmt.Fprintln(logfile, "mmexternal: undefined_max_num_fields: ", undefined_max_num_fields) - fmt.Fprintln(logfile, "mmexternal: noaction: ", noaction) } } @@ -302,13 +297,6 @@ func main() { jsonCopyMap := make(map[string]interface{}) jsonMap := make(map[string]interface{}) rawStr := scanner.Text() - if noaction { - if undefined_debug { - fmt.Fprintln(logfile, "No Action Needed for ", rawStr) - } - fmt.Println(noChanges) - continue - } if undefined_debug { fmt.Fprintln(logfile, "Source: ", rawStr) } diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 5f6decef0..037a392c1 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -343,7 +343,7 @@ artifact_log "0. Preparing test data" cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF -set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":"False"},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); +set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":False},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From 6f6458cc08304eadf5a44c4ac244e2eeac649026 Mon Sep 17 00:00:00 2001 From: Noriko Hosoi Date: Mon, 15 Jul 2019 08:21:41 -0700 Subject: [PATCH 09/37] Try making boolean a string... --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 037a392c1..316c24a6f 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -343,7 +343,7 @@ artifact_log "0. Preparing test data" cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF -set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":False},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); +set $.ret = parse_json("{\"undefined1\":\"undefined1\",\"undefined11\":1111,\"undefined12\":\"True\",\"empty1\":\"\",\"undefined2\":{\"undefined2\":\"undefined2\",\"\":\"\",\"undefined22\":2222,\"undefined23\":\"False\"},\"undefined3\":{\"emptyvalue\":\"\"},\"undefined4\":\"undefined4\",\"undefined5\":\"undefined5\",\"undefined.6\":\"undefined6\"}", "\$!"); EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From 5a6aae1727d7dc79f872b085a898023b9c51a824 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Mon, 15 Jul 2019 18:08:46 -0600 Subject: [PATCH 10/37] fix errors in undefined field handling --- rsyslog/undefined_field/undefined_field.go | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index d82c2b689..74edc52c6 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -220,9 +220,11 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m valuemap, ismap := value.(map[string]interface{}) valuearraymap, isarraymap := value.([]interface{}) if _, exists := keep_empty_fields[origkey]; !exists { - if !ismap && (value == nil || len(value.(string)) == 0) || - isarraymap && len(valuearraymap) == 0 || - ismap && len(valuemap) == 0 { + valuestring, isstring := value.(string) + if (isarraymap && len(valuearraymap) == 0) || + (ismap && len(valuemap) == 0) || + (isstring && len(valuestring) == 0) || + (value == nil) { replace_me = true continue } @@ -278,7 +280,7 @@ func replaceDotMoveUndefinedArray(inputs []interface{}) []interface{} { rval := replaceDotMoveUndefinedArray(valuearraymap) cp = append(cp, rval) } else { - fmt.Fprintln(logfile, "Error:", input, " is not a map. Ignoring...") + cp = append(cp, input) } } return cp From a30d76b684e5b1850417d3676f7f383bb6c0c394 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Mon, 15 Jul 2019 19:55:46 -0600 Subject: [PATCH 11/37] revert back to using boolean --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 316c24a6f..9bd663240 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -343,7 +343,7 @@ artifact_log "0. Preparing test data" cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF -set $.ret = parse_json("{\"undefined1\":\"undefined1\",\"undefined11\":1111,\"undefined12\":\"True\",\"empty1\":\"\",\"undefined2\":{\"undefined2\":\"undefined2\",\"\":\"\",\"undefined22\":2222,\"undefined23\":\"False\"},\"undefined3\":{\"emptyvalue\":\"\"},\"undefined4\":\"undefined4\",\"undefined5\":\"undefined5\",\"undefined.6\":\"undefined6\"}", "\$!"); +set $.ret = parse_json("{\"undefined1\":\"undefined1\",\"undefined11\":1111,\"undefined12\":True,\"empty1\":\"\",\"undefined2\":{\"undefined2\":\"undefined2\",\"\":\"\",\"undefined22\":2222,\"undefined23\":\"False\"},\"undefined3\":{\"emptyvalue\":\"\"},\"undefined4\":\"undefined4\",\"undefined5\":\"undefined5\",\"undefined.6\":\"undefined6\"}", "\$!"); EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From db3655618ef0490ae4f3aa4c4f6fba5b5dd40a0f Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Mon, 15 Jul 2019 21:27:49 -0600 Subject: [PATCH 12/37] fix test formatting --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 9bd663240..5f6decef0 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -343,7 +343,7 @@ artifact_log "0. Preparing test data" cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF -set $.ret = parse_json("{\"undefined1\":\"undefined1\",\"undefined11\":1111,\"undefined12\":True,\"empty1\":\"\",\"undefined2\":{\"undefined2\":\"undefined2\",\"\":\"\",\"undefined22\":2222,\"undefined23\":\"False\"},\"undefined3\":{\"emptyvalue\":\"\"},\"undefined4\":\"undefined4\",\"undefined5\":\"undefined5\",\"undefined.6\":\"undefined6\"}", "\$!"); +set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":"False"},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From 4dff863841f15397146a19ae7f0b46b91bd9b57e Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Tue, 16 Jul 2019 17:01:37 -0600 Subject: [PATCH 13/37] works with rsyslog test program --- rsyslog/undefined_field/undefined_field.go | 72 ++++++++++++---------- 1 file changed, 40 insertions(+), 32 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 74edc52c6..7ee21ddd2 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -76,46 +76,47 @@ package main import ( - "encoding/json" "bufio" - "strings" + "encoding/json" "fmt" "io/ioutil" "os" + "strings" ) const ( - initial_logging_file_path = "/var/log/rsyslog/rsyslog.log" - undefined_config = "/var/lib/rsyslog.pod/undefined.json" - noChanges = "{}" + initial_logging_file_path = "/var/tmp/rsyslog/rsyslog.log" + undefined_config = "/var/tmp/rsyslog/undefined.json" + noChanges = "{}" ) type UndefinedConfig struct { - Debug bool `json:"UNDEFINED_DEBUG"` - Merge_json_log bool `json:"MERGE_JSON_LOG"` - Use_undefined bool `json:"CDM_USE_UNDEFINED"` - Undefined_to_string bool `json:"CDM_UNDEFINED_TO_STRING"` - Default_keep_fields string `json:"CDM_DEFAULT_KEEP_FIELDS"` - Extra_keep_fields string `json:"CDM_EXTRA_KEEP_FIELDS"` - Undefined_name string `json:"CDM_UNDEFINED_NAME"` - Keep_empty_fields string `json:"CDM_KEEP_EMPTY_FIELDS"` - Undefined_dot_replace_char string `json:"CDM_UNDEFINED_DOT_REPLACE_CHAR"` - Undefined_max_num_fields int64 `json:"CDM_UNDEFINED_MAX_NUM_FIELDS"` + Debug bool `json:"UNDEFINED_DEBUG"` + Merge_json_log bool `json:"MERGE_JSON_LOG"` + Use_undefined bool `json:"CDM_USE_UNDEFINED"` + Undefined_to_string bool `json:"CDM_UNDEFINED_TO_STRING"` + Default_keep_fields string `json:"CDM_DEFAULT_KEEP_FIELDS"` + Extra_keep_fields string `json:"CDM_EXTRA_KEEP_FIELDS"` + Undefined_name string `json:"CDM_UNDEFINED_NAME"` + Keep_empty_fields string `json:"CDM_KEEP_EMPTY_FIELDS"` + Undefined_dot_replace_char string `json:"CDM_UNDEFINED_DOT_REPLACE_CHAR"` + Undefined_max_num_fields int64 `json:"CDM_UNDEFINED_MAX_NUM_FIELDS"` } var ( - undefined_debug bool - merge_json_log bool - use_undefined bool - keep_fields map[string]string - keep_empty_fields map[string]string - undefined_name string - undefined_to_string bool + undefined_debug bool + merge_json_log bool + use_undefined bool + keep_fields map[string]string + keep_empty_fields map[string]string + undefined_name string + undefined_to_string bool undefined_dot_replace_char string - undefined_max_num_fields int64 - undefined_cur_num_fields int64 - logfile *os.File - replacer = &strings.Replacer{} + undefined_max_num_fields int64 + undefined_cur_num_fields int64 + logfile *os.File + noaction = false + replacer = &strings.Replacer{} ) func getMapStringValue(m map[string]interface{}, key string) (string, bool) { @@ -200,7 +201,7 @@ func onInit() { } } -func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (map[string]interface{},bool,bool) { +func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (map[string]interface{}, bool, bool) { replace_me := false has_undefined := false cp := make(map[string]interface{}) @@ -220,14 +221,21 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m valuemap, ismap := value.(map[string]interface{}) valuearraymap, isarraymap := value.([]interface{}) if _, exists := keep_empty_fields[origkey]; !exists { - valuestring, isstring := value.(string) - if (isarraymap && len(valuearraymap) == 0) || - (ismap && len(valuemap) == 0) || - (isstring && len(valuestring) == 0) || - (value == nil) { + valuestring, isstring := value.(string) + if (isarraymap && len(valuearraymap) == 0) || + (ismap && len(valuemap) == 0) || + (isstring && len(valuestring) == 0) || + (value == nil) { replace_me = true + //if undefined_debug { + // fmt.Fprintf(logfile, "mmexternal: skipping empty field: [%v] and value [%v]\n", origkey, value) + //} continue + //} else { + //fmt.Fprintf(logfile, "mmexternal: keeping non-empty field: [%v] and value [%v]\n", origkey, value) } + //} else { + //fmt.Fprintf(logfile, "mmexternal: keeping field: [%v] and value [%v]\n", origkey, value) } // use_undefined and key is not in keep_fields? _, keepit := keep_fields[origkey] From cfa37cb1c6db310032449c162f0f36aa77292a46 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Tue, 16 Jul 2019 17:03:16 -0600 Subject: [PATCH 14/37] reset paths to default --- rsyslog/undefined_field/undefined_field.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 7ee21ddd2..3ea7a4148 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -85,8 +85,8 @@ import ( ) const ( - initial_logging_file_path = "/var/tmp/rsyslog/rsyslog.log" - undefined_config = "/var/tmp/rsyslog/undefined.json" + initial_logging_file_path = "/var/log/rsyslog/rsyslog.log" + undefined_config = "/var/lib/rsyslog.pod/undefined.json" noChanges = "{}" ) From 66539960272288d45cfdc79dd3f4f71a395341b6 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Tue, 16 Jul 2019 22:00:03 -0600 Subject: [PATCH 15/37] remove noaction; check for empty maps, arrays remove the check for noaction. There will always be an "action" by this command - it will always strip empty fields. After recursing through nested maps and arrays, check to see if they are empty after recursing, and remove them if they are now empty. --- rsyslog/undefined_field/undefined_field.go | 16 ++++++---------- 1 file changed, 6 insertions(+), 10 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 3ea7a4148..c40177cdb 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -115,7 +115,6 @@ var ( undefined_max_num_fields int64 undefined_cur_num_fields int64 logfile *os.File - noaction = false replacer = &strings.Replacer{} ) @@ -227,15 +226,8 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m (isstring && len(valuestring) == 0) || (value == nil) { replace_me = true - //if undefined_debug { - // fmt.Fprintf(logfile, "mmexternal: skipping empty field: [%v] and value [%v]\n", origkey, value) - //} continue - //} else { - //fmt.Fprintf(logfile, "mmexternal: keeping non-empty field: [%v] and value [%v]\n", origkey, value) } - //} else { - //fmt.Fprintf(logfile, "mmexternal: keeping field: [%v] and value [%v]\n", origkey, value) } // use_undefined and key is not in keep_fields? _, keepit := keep_fields[origkey] @@ -265,10 +257,14 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m } } else if isarraymap { rval := replaceDotMoveUndefinedArray(valuearraymap) - cp[key] = rval + if rval != nil && len(rval) > 0 { + cp[key] = rval + } } else if ismap { rval, _, _ := replaceDotMoveUndefined(valuemap, false) - cp[key] = rval + if rval != nil && len(rval) > 0 { + cp[key] = rval + } } else { cp[key] = value } From 83bf757ccd9d069567f351a350ea84a5d55e15b5 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Wed, 17 Jul 2019 10:44:25 -0600 Subject: [PATCH 16/37] check for empty before adding to array --- rsyslog/undefined_field/undefined_field.go | 13 ++++++++++--- 1 file changed, 10 insertions(+), 3 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index c40177cdb..eab8d81ac 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -277,13 +277,20 @@ func replaceDotMoveUndefinedArray(inputs []interface{}) []interface{} { for _, input := range inputs { valuemap, ismap := input.(map[string]interface{}) valuearraymap, isarraymap := input.([]interface{}) + valuestring, isstring := input.(string) if ismap { rval, _, _ := replaceDotMoveUndefined(valuemap, false) - cp = append(cp, rval) + if rval != nil && len(rval) > 0 { + cp = append(cp, rval) + } } else if isarraymap { rval := replaceDotMoveUndefinedArray(valuearraymap) - cp = append(cp, rval) - } else { + if rval != nil && len(rval) > 0 { + cp = append(cp, rval) + } + } else if isstring && len(valuestring) > 0 { + cp = append(cp, input) + } else if input != nil { cp = append(cp, input) } } From 51fcdb8ade10d5db0508625d3e6446e3d326de24 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Wed, 17 Jul 2019 10:49:33 -0600 Subject: [PATCH 17/37] add UNDEFINED_CONFIG env. var. for testing --- rsyslog/undefined_field/undefined_field.go | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index eab8d81ac..109734f79 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -86,7 +86,7 @@ import ( const ( initial_logging_file_path = "/var/log/rsyslog/rsyslog.log" - undefined_config = "/var/lib/rsyslog.pod/undefined.json" + default_undefined_config = "/var/lib/rsyslog.pod/undefined.json" noChanges = "{}" ) @@ -116,6 +116,7 @@ var ( undefined_cur_num_fields int64 logfile *os.File replacer = &strings.Replacer{} + undefined_config string ) func getMapStringValue(m map[string]interface{}, key string) (string, bool) { @@ -138,6 +139,10 @@ func onInit() { panic(fmt.Errorf("Could not open file [%s]: [%v]", logging_file_path, err)) } + undefined_config = default_undefined_config + if eval := os.Getenv("UNDEFINED_CONFIG"); eval != "" { + undefined_config = eval + } var undefined_config_obj UndefinedConfig var default_keep_fields string var extra_keep_fields string From de06199db990f44bc3cce04d50e62c15e7f99cfd Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Wed, 17 Jul 2019 12:44:59 -0600 Subject: [PATCH 18/37] use False boolean not string --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 5f6decef0..037a392c1 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -343,7 +343,7 @@ artifact_log "0. Preparing test data" cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF -set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":"False"},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); +set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":False},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From e3f99ea2f72143fdc2cb6ed3e6b2e60e7edf1dd8 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Wed, 17 Jul 2019 14:20:45 -0600 Subject: [PATCH 19/37] check keepEmpty for recursive deletes; only count field if used If we recursively cleared out a map or an array, only keep the field if it is in keep_empty. Only count the field against the max number of undefined fields if we actually used it in the result. There is no `arraymap` - it's just an `array` --- rsyslog/undefined_field/undefined_field.go | 35 ++++++++++++---------- 1 file changed, 19 insertions(+), 16 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 109734f79..38f1e83f7 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -223,10 +223,11 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m } // skip empty or not? valuemap, ismap := value.(map[string]interface{}) - valuearraymap, isarraymap := value.([]interface{}) - if _, exists := keep_empty_fields[origkey]; !exists { + valuearray, isarray := value.([]interface{}) + _, keepEmpty := keep_empty_fields[origkey] + if !keepEmpty { valuestring, isstring := value.(string) - if (isarraymap && len(valuearraymap) == 0) || + if (isarray && len(valuearray) == 0) || (ismap && len(valuemap) == 0) || (isstring && len(valuestring) == 0) || (value == nil) { @@ -237,37 +238,39 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m // use_undefined and key is not in keep_fields? _, keepit := keep_fields[origkey] if topPropLevel && use_undefined && !keepit { - // if unmdefined_max_num_fields > 0, move the undefined item to undefined_name + // if undefined_max_num_fields > 0, move the undefined item to undefined_name if undefined_cur_num_fields > 0 { if cp[undefined_name] == nil { subcp := make(map[string]interface{}) cp[undefined_name] = subcp } - if isarraymap { - rval := replaceDotMoveUndefinedArray(valuearraymap) - if len(rval) > 0 { + if isarray { + rval := replaceDotMoveUndefinedArray(valuearray) + if keepEmpty || len(rval) > 0 { cp[undefined_name].(map[string]interface{})[key] = rval + undefined_cur_num_fields-- } } else if ismap { rval, _, _ := replaceDotMoveUndefined(valuemap, false) - if len(rval) > 0 { + if keepEmpty || len(rval) > 0 { cp[undefined_name].(map[string]interface{})[key] = rval + undefined_cur_num_fields-- } } else { cp[undefined_name].(map[string]interface{})[key] = value + undefined_cur_num_fields-- } - undefined_cur_num_fields-- replace_me = true has_undefined = true } - } else if isarraymap { - rval := replaceDotMoveUndefinedArray(valuearraymap) - if rval != nil && len(rval) > 0 { + } else if isarray { + rval := replaceDotMoveUndefinedArray(valuearray) + if keepEmpty || (rval != nil && len(rval) > 0) { cp[key] = rval } } else if ismap { rval, _, _ := replaceDotMoveUndefined(valuemap, false) - if rval != nil && len(rval) > 0 { + if keepEmpty || (rval != nil && len(rval) > 0) { cp[key] = rval } } else { @@ -281,15 +284,15 @@ func replaceDotMoveUndefinedArray(inputs []interface{}) []interface{} { cp := make([]interface{}, 0) for _, input := range inputs { valuemap, ismap := input.(map[string]interface{}) - valuearraymap, isarraymap := input.([]interface{}) + valuearray, isarray := input.([]interface{}) valuestring, isstring := input.(string) if ismap { rval, _, _ := replaceDotMoveUndefined(valuemap, false) if rval != nil && len(rval) > 0 { cp = append(cp, rval) } - } else if isarraymap { - rval := replaceDotMoveUndefinedArray(valuearraymap) + } else if isarray { + rval := replaceDotMoveUndefinedArray(valuearray) if rval != nil && len(rval) > 0 { cp = append(cp, rval) } From 95c9a44a15f6029e416864eab18fb40ba88c028d Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Wed, 17 Jul 2019 14:22:56 -0600 Subject: [PATCH 20/37] unset stream to make test happy --- test/zzz-rsyslog.sh | 1 + 1 file changed, 1 insertion(+) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 037a392c1..623bb16a1 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -344,6 +344,7 @@ cfgdir=$( mktemp -d ) oc extract cm/rsyslog --to=$cfgdir cat > $cfgdir/66-debug.conf << EOF set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefined12":True,"empty1":"","undefined2":{"undefined2":"undefined2","":"","undefined22":2222,"undefined23":False},"undefined3":{"emptyvalue":""},"undefined4":"undefined4","undefined5":"undefined5","undefined.6":"undefined6"}', '\$!'); +unset \$!stream; EOF ls -l $cfgdir | artifact_out oc delete cm rsyslog From 51a8d97f2ec213b4bd4da58d1345d81f6493d0a0 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Wed, 17 Jul 2019 21:04:32 -0600 Subject: [PATCH 21/37] first pass at test for undefined_field --- .../undefined_field/undefined_field_test.go | 72 +++++++++++++++++++ 1 file changed, 72 insertions(+) create mode 100644 rsyslog/undefined_field/undefined_field_test.go diff --git a/rsyslog/undefined_field/undefined_field_test.go b/rsyslog/undefined_field/undefined_field_test.go new file mode 100644 index 000000000..755805452 --- /dev/null +++ b/rsyslog/undefined_field/undefined_field_test.go @@ -0,0 +1,72 @@ +package main + +import ( + "encoding/json" + "fmt" + "io/ioutil" + "os" + "testing" +) + +var ( + defaultKeepFields = "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL" +) + +func setup(t *testing.T) (string, error) { + testLogfile, err := ioutil.TempFile("", "log") + if err != nil { + return "", fmt.Errorf("Could not create temp log file: %v", err) + } + testCfgfile, err := ioutil.TempFile("", "cfg") + if err != nil { + os.Remove(testLogfile.Name()) + return "", fmt.Errorf("Could not create temp cfg file") + } + defer os.Remove(testCfgfile.Name()) + os.Setenv("LOGGING_FILE_PATH", testLogfile.Name()) + // write cfg options to testCfgfile + cfg := UndefinedConfig{ + Debug: true, + Merge_json_log: true, + Use_undefined: true, + Undefined_to_string: false, + Default_keep_fields: "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL", + Extra_keep_fields: "undefined4,undefined5,empty1,undefined3", + Undefined_name: "undefined", + Keep_empty_fields: "undefined4,undefined5,empty1,undefined3", + Undefined_dot_replace_char: "UNUSED", + Undefined_max_num_fields: -1, + } + b, err := json.Marshal(cfg) + if err != nil { + os.Remove(testLogfile.Name()) + return "", fmt.Errorf("Could not marshal JSON config object: %v", err) + } + if _, err := testCfgfile.Write(b); err != nil { + os.Remove(testLogfile.Name()) + return "", fmt.Errorf("Could not write config to %v: %v", testCfgfile.Name(), err) + } + os.Setenv("UNDEFINED_CONFIG", testCfgfile.Name()) + onInit() + return testLogfile.Name(), nil +} + +func TestKeepEmpty(t *testing.T) { + testLogfilename, err := setup(t) + defer os.Remove(testLogfilename) + if err != nil { + t.Errorf("test setup failed: %v", err) + } + inputString := `{"hostname": "hostname", "level": "info", "@timestamp": "2019-07-17T21:26:45.913217+00:00", ` + + `"undefined1": "undefined1", "undefined11": 1111, "undefined12": true, "empty1": "", ` + + `"undefined2": { "undefined2": "undefined2", "": "", "undefined22": 2222, "undefined23": false }, ` + + `"undefined3": { "emptyvalue": "" }, "undefined4": {}, "undefined5": "undefined5", ` + + `"undefined.6": "undefined6", "message": "message" }` + inputMap := make(map[string]interface{}) + if err := json.Unmarshal([]byte(inputString), &inputMap); err != nil { + t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) + } + all, replaceMe, hasUndefined := replaceDotMoveUndefined(inputMap, true) + outputBytes, err := json.Marshal(all) + t.Logf("outputBytes [%s] replaceMe [%v] hasUndefined [%v]", outputBytes, replaceMe, hasUndefined) +} From 98804babb97a9819e001b1f4b7d50352b2031d4f Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Wed, 17 Jul 2019 21:04:47 -0600 Subject: [PATCH 22/37] fix some go lint errors --- rsyslog/undefined_field/undefined_field.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 38f1e83f7..e504bd7bd 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -164,7 +164,7 @@ func onInit() { undefined_dot_replace_char = undefined_config_obj.Undefined_dot_replace_char undefined_max_num_fields = undefined_config_obj.Undefined_max_num_fields } else if !strings.Contains(err.Error(), "no such file or directory") { - fmt.Fprintln(logfile, "ERROR: Could not open config file [%s]: [%v]", undefined_config, err) + fmt.Fprintf(logfile, "ERROR: Could not open config file [%s]: [%v]\n", undefined_config, err) panic(fmt.Errorf("Could not open config file [%s]: [%v]", undefined_config, err)) } @@ -198,7 +198,7 @@ func onInit() { fmt.Fprintln(logfile, "mmexternal: default_keep_fields: ", default_keep_fields) fmt.Fprintln(logfile, "mmexternal: extra_keep_fields: ", extra_keep_fields) fmt.Fprintln(logfile, "mmexternal: undefined_name: ", undefined_name) - fmt.Fprintln(logfile, "mmexternal: keep_empty_fields: ", tmp_keep_empty_fields) + fmt.Fprintf(logfile, "mmexternal: keep_empty_fields: %v %v\n", tmp_keep_empty_fields, keep_empty_fields) fmt.Fprintln(logfile, "mmexternal: undefined_to_string: ", undefined_to_string) fmt.Fprintln(logfile, "mmexternal: undefined_dot_replace_char: ", undefined_dot_replace_char) fmt.Fprintln(logfile, "mmexternal: undefined_max_num_fields: ", undefined_max_num_fields) From 8ec9e0a98d6f6ff6dbfbbdf1a8c27350ee357bde Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 07:45:58 -0600 Subject: [PATCH 23/37] start_rsyslog; make rsyslog read from tail test improvements - added start_rsyslog, stop_rsyslog to make it easier and safer to change and restart rsyslog for testing make rsyslog read from tail to speed up testing write impstats.json for testing --- hack/testing/util.sh | 30 +++++++++++++++++++++++ test/zzz-rsyslog.sh | 57 ++++++++++++++++++++------------------------ 2 files changed, 56 insertions(+), 31 deletions(-) diff --git a/hack/testing/util.sh b/hack/testing/util.sh index 8df35f1f1..a97e465c1 100644 --- a/hack/testing/util.sh +++ b/hack/testing/util.sh @@ -433,6 +433,10 @@ function flush_fluentd_pos_files() { os::cmd::expect_success "oal_sudo rm -f /var/log/journal.pos /var/log/journal_pos.json" } +function flush_rsyslog_pos_files() { + os::cmd::expect_success "oal_sudo rm -f /var/lib/rsyslog.pod/imfile-state* /var/lib/rsyslog.pod/imjournal.state" +} + # return 0 if given file has size ge given size, otherwise, return 1 function file_has_size() { local f=$1 @@ -791,6 +795,32 @@ start_fluentd() { os::cmd::try_until_text "oc get pods -l component=fluentd" "^(logging-)*fluentd-.* Running " $wait_time } +stop_rsyslog() { + local rpod=${1:-$( get_running_pod rsyslog )} + local wait_time=${2:-$(( 2 * minute ))} + + oc label node -l logging-infra-rsyslog=true --overwrite logging-infra-rsyslog=false + os::cmd::try_until_text "oc get $rsyslog_ds -o jsonpath='{ .status.numberReady }'" "0" $wait_time + # not sure if it is a bug or a flake, but sometimes .status.numberReady is 0, the rsyslog pod hangs around + # in the Terminating state for many seconds, which seems to cause problems with subsequent tests + # so, we have to wait for the pod to completely disappear - we cannot rely on .status.numberReady == 0 + if [ -n "${rpod:-}" ] ; then + os::cmd::try_until_failure "oc get pod $rpod > /dev/null 2>&1" $wait_time + fi +} + +start_rsyslog() { + local cleanfirst=${1:-false} + local wait_time=${2:-$(( 2 * minute ))} + + if [ "$cleanfirst" != false ] ; then + flush_rsyslog_pos_files + oal_sudo rm -f /var/log/rsyslog/* /var/lib/rsyslog.pod/* + fi + oc label node -l logging-infra-rsyslog=false --overwrite logging-infra-rsyslog=true + os::cmd::try_until_text "oc get pods -l component=rsyslog" "^(logging-)*rsyslog-.* Running " $wait_time +} + get_fluentd_ds_name() { if oc -n ${LOGGING_NS} get daemonset fluentd -o name > /dev/null 2>&1 ; then echo daemonset/fluentd diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 623bb16a1..bae3d0d33 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -37,13 +37,6 @@ fi # clear the journal clear_and_restart_journal -restart_rsyslog_pod() { - local rpod=${1:-$( get_running_pod rsyslog )} - oc delete --force pod $rpod - os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" - os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" -} - cleanup() { local return_code="$?" set +e @@ -148,11 +141,14 @@ deploy_using_operators() { disable_cluster_logging_operator sleep 10 os::cmd::try_until_success "oc get cm rsyslog 2> /dev/null" + stop_rsyslog $rpod + oc set env $rsyslog_ds RSYSLOG_JOURNAL_READ_FROM_TAIL=on RSYSLOG_FILE_READ_FROM_TAIL=on RSYSLOG_USE_IMPSTATS_JSON=true # enable annotation_match oc get cm rsyslog -o yaml | \ sed -e 's/action(type="mmkubernetes"/action(type="mmkubernetes" annotation_match=["."]/' | \ oc replace --force -f - 2>&1 | artifact_out - restart_rsyslog_pod $rpod + start_rsyslog + rpod=$( get_running_pod rsyslog ) } get_logmessage() { @@ -275,11 +271,10 @@ if [ $logsize -gt 0 ]; then artifact_log logs before rotation oc exec $rpod -c rsyslog -- ls -l /var/log/rsyslog/ | artifact_out oc exec $rpod -c rsyslog -- cat /var/log/rsyslog/rsyslog.log > $ARTIFACT_DIR/rsyslog-before-rotation.log - # this will restart the rsyslog pod + stop_rsyslog $rpod oc set env $rsyslog_ds LOGGING_FILE_SIZE=$maxsize LOGGING_FILE_AGE=$maxcount + start_rsyslog - os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" - os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" # wait longer than ($maxcount + 1) * 60 seconds. sleep $( expr $( expr $maxcount + 1 ) \* 60 ) rpod=$( get_running_pod rsyslog ) @@ -322,17 +317,17 @@ else fi # switch LOGGING_FILE_PATH to console +stop_rsyslog $rpod oc set env $rsyslog_ds LOGGING_FILE_PATH=console -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) oc logs $rpod -c rsyslog > $ARTIFACT_DIR/rsyslog.console.log 2>&1 os::cmd::expect_failure "grep 'oc exec -- logs' $ARTIFACT_DIR/rsyslog.console.log" # switch back LOGGING_FILE_PATH to default +stop_rsyslog $rpod oc set env $rsyslog_ds LOGGING_FILE_PATH- -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) artifact_log "************************" @@ -347,19 +342,19 @@ set \$.ret = parse_json('{"undefined1":"undefined1","undefined11":1111,"undefine unset \$!stream; EOF ls -l $cfgdir | artifact_out +stop_rsyslog $rpod oc delete cm rsyslog oc create cm rsyslog --from-file=$cfgdir - -restart_rsyslog_pod $rpod +start_rsyslog rpod=$( get_running_pod rsyslog ) oc exec $rpod -c rsyslog -- ls -l /etc/rsyslog.d/66-debug.conf | artifact_out oc exec $rpod -c rsyslog -- cat /etc/rsyslog.d/66-debug.conf | artifact_out # UNDEFINED_DEBUG needs to be enabled for checking configs in the following tests. +stop_rsyslog $rpod oc set env $rsyslog_ds UNDEFINED_DEBUG=true -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) os::cmd::try_until_success "oc exec $rpod -c rsyslog -- grep 'use_undefined:' /var/log/rsyslog/rsyslog.log" @@ -374,9 +369,9 @@ os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq- artifact_log "2. enable use_undefined - undefined fields are stored in 'undefined' field" keep_fields="method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL" +stop_rsyslog $rpod oc set env $rsyslog_ds CDM_USE_UNDEFINED=true CDM_EXTRA_KEEP_FIELDS=$keep_fields 2>&1 | artifact_out -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'use_undefined:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}'" "true" @@ -385,9 +380,9 @@ os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test2" artifact_log "3. user specifies extra fields to keep" +stop_rsyslog $rpod oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,$keep_fields 2>&1 | artifact_out -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'extra_keep_fields:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}' | sed -e 's/.*\(undefined4\).*/\1/'" "undefined4" @@ -396,9 +391,9 @@ os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test3" artifact_log "4. user specifies alternate undefined name to use" +stop_rsyslog $rpod oc set env $rsyslog_ds CDM_UNDEFINED_NAME=myname 2>&1 | artifact_out -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'undefined_name:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}'" "myname" @@ -407,9 +402,9 @@ os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test4" artifact_log "5. reserve specified empty field as empty" +stop_rsyslog oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 2>&1 | artifact_out -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) os::cmd::expect_success_and_text "oc exec $rpod -c rsyslog -- grep 'keep_empty_fields:' /var/log/rsyslog/rsyslog.log | tail -n 1 | awk '{print \$3}' | sed -e 's/.*\(empty1\).*/\1/'" "empty1" @@ -418,9 +413,9 @@ os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test5 allow_empty" artifact_log "6. replace dot with underscore" +stop_rsyslog $rpod oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 MERGE_JSON_LOG=true CDM_UNDEFINED_DOT_REPLACE_CHAR=_ 2>&1 | artifact_out -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 @@ -428,9 +423,9 @@ os::cmd::expect_success "cat $proj | python $OS_O_A_L_DIR/hack/testing/test-viaq os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq-data-model.py test6 allow_empty" artifact_log "7. set CDM_UNDEFINED_MAX_NUM_FIELDS to 3" +stop_rsyslog $rpod oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 CMERGE_JSON_LOG=true DM_UNDEFINED_DOT_REPLACE_CHAR=_ CDM_UNDEFINED_MAX_NUM_FIELDS=3 2>&1 | artifact_out -os::cmd::try_until_failure "oc get pods $rpod > /dev/null 2>&1" -os::cmd::try_until_success "oc get pods 2> /dev/null | grep -q 'rsyslog.*Running'" +start_rsyslog rpod=$( get_running_pod rsyslog ) wait_for_fluentd_to_catch_up get_logmessage get_logmessage2 From eb0af39e549cecbb7b54d4016c720a931ddaf3de Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 14:53:27 -0600 Subject: [PATCH 24/37] start rsyslog clean --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index bae3d0d33..62ab0ce25 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -147,7 +147,7 @@ deploy_using_operators() { oc get cm rsyslog -o yaml | \ sed -e 's/action(type="mmkubernetes"/action(type="mmkubernetes" annotation_match=["."]/' | \ oc replace --force -f - 2>&1 | artifact_out - start_rsyslog + start_rsyslog cleanfirst rpod=$( get_running_pod rsyslog ) } From 5c243416a7f3230a4c6af7525825a852d79cea84 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 14:57:50 -0600 Subject: [PATCH 25/37] RSYSLOG_USE_IMPSTATS_FILE --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 62ab0ce25..45d4cb83f 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -142,7 +142,7 @@ deploy_using_operators() { sleep 10 os::cmd::try_until_success "oc get cm rsyslog 2> /dev/null" stop_rsyslog $rpod - oc set env $rsyslog_ds RSYSLOG_JOURNAL_READ_FROM_TAIL=on RSYSLOG_FILE_READ_FROM_TAIL=on RSYSLOG_USE_IMPSTATS_JSON=true + oc set env $rsyslog_ds RSYSLOG_JOURNAL_READ_FROM_TAIL=on RSYSLOG_FILE_READ_FROM_TAIL=on RSYSLOG_USE_IMPSTATS_FILE=true # enable annotation_match oc get cm rsyslog -o yaml | \ sed -e 's/action(type="mmkubernetes"/action(type="mmkubernetes" annotation_match=["."]/' | \ From 8c66ac77ef3a4f5c77d921ee381ede8f9a376e8f Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 20:12:42 -0600 Subject: [PATCH 26/37] only delete empty keys at top level --- rsyslog/undefined_field/undefined_field.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index e504bd7bd..c5567fd98 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -210,7 +210,7 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m has_undefined := false cp := make(map[string]interface{}) for origkey, value := range input { - if len(origkey) == 0 { + if topPropLevel && len(origkey) == 0 { continue } key := origkey From 5ae8fcf889d0cae27015160a22a522a9d8e81704 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 20:14:07 -0600 Subject: [PATCH 27/37] only check top level keys for being empty --- rsyslog/undefined_field/undefined_field.go | 23 +++++++++++++--------- 1 file changed, 14 insertions(+), 9 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index c5567fd98..cd95bbaea 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -224,16 +224,21 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m // skip empty or not? valuemap, ismap := value.(map[string]interface{}) valuearray, isarray := value.([]interface{}) - _, keepEmpty := keep_empty_fields[origkey] - if !keepEmpty { - valuestring, isstring := value.(string) - if (isarray && len(valuearray) == 0) || - (ismap && len(valuemap) == 0) || - (isstring && len(valuestring) == 0) || - (value == nil) { - replace_me = true - continue + var keepEmpty bool + if topPropLevel { + _, keepEmpty = keep_empty_fields[origkey] + if !keepEmpty { + valuestring, isstring := value.(string) + if (isarray && len(valuearray) == 0) || + (ismap && len(valuemap) == 0) || + (isstring && len(valuestring) == 0) || + (value == nil) { + replace_me = true + continue + } } + } else { + keepEmpty = true // only check top level fields } // use_undefined and key is not in keep_fields? _, keepit := keep_fields[origkey] From 6bd960c6829ccb829efc18bd69c69b89f451930d Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 20:14:47 -0600 Subject: [PATCH 28/37] additional fudge factor for rsyslog logrotation checking --- test/zzz-rsyslog.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 45d4cb83f..6f6493fa8 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -309,7 +309,7 @@ if [ $logsize -gt 0 ]; then oc exec $rpod -c logrotate -- /usr/bin/cat /var/lib/rsyslog.pod/logrotate.log 2>&1 | artifact_out artifact_log "==========" os::cmd::expect_success "test $filecount -le $maxcount" - os::cmd::expect_success "test $filesize -le $(( maxsize + 1024 ))" + os::cmd::expect_success "test $filesize -le $(( maxsize + 2048 ))" oc apply --force -f $savecm else From c7ba67076bbcae9c585cd91dfffe55784819c94e Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 20:15:12 -0600 Subject: [PATCH 29/37] test improvements --- .../undefined_field/undefined_field_test.go | 123 ++++++++++++++---- 1 file changed, 97 insertions(+), 26 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field_test.go b/rsyslog/undefined_field/undefined_field_test.go index 755805452..651f2a62f 100644 --- a/rsyslog/undefined_field/undefined_field_test.go +++ b/rsyslog/undefined_field/undefined_field_test.go @@ -5,68 +5,139 @@ import ( "fmt" "io/ioutil" "os" + "reflect" "testing" ) var ( - defaultKeepFields = "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL" + testLogfile *os.File ) -func setup(t *testing.T) (string, error) { - testLogfile, err := ioutil.TempFile("", "log") +func setup(t *testing.T, cfg UndefinedConfig) error { + var err error + testLogfile, err = ioutil.TempFile("", "log") if err != nil { - return "", fmt.Errorf("Could not create temp log file: %v", err) + return fmt.Errorf("Could not create temp log file: %v", err) } testCfgfile, err := ioutil.TempFile("", "cfg") if err != nil { os.Remove(testLogfile.Name()) - return "", fmt.Errorf("Could not create temp cfg file") + return fmt.Errorf("Could not create temp cfg file") } defer os.Remove(testCfgfile.Name()) os.Setenv("LOGGING_FILE_PATH", testLogfile.Name()) // write cfg options to testCfgfile - cfg := UndefinedConfig{ - Debug: true, - Merge_json_log: true, - Use_undefined: true, - Undefined_to_string: false, - Default_keep_fields: "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL", - Extra_keep_fields: "undefined4,undefined5,empty1,undefined3", - Undefined_name: "undefined", - Keep_empty_fields: "undefined4,undefined5,empty1,undefined3", - Undefined_dot_replace_char: "UNUSED", - Undefined_max_num_fields: -1, - } b, err := json.Marshal(cfg) if err != nil { os.Remove(testLogfile.Name()) - return "", fmt.Errorf("Could not marshal JSON config object: %v", err) + return fmt.Errorf("Could not marshal JSON config object: %v", err) } if _, err := testCfgfile.Write(b); err != nil { os.Remove(testLogfile.Name()) - return "", fmt.Errorf("Could not write config to %v: %v", testCfgfile.Name(), err) + return fmt.Errorf("Could not write config to %v: %v", testCfgfile.Name(), err) } os.Setenv("UNDEFINED_CONFIG", testCfgfile.Name()) + testLogfile.Close() onInit() - return testLogfile.Name(), nil + return nil +} + +func teardown(t *testing.T) { + tdLogfile, err := os.Open(testLogfile.Name()) + if err != nil { + t.Errorf("Could not open testLogfile: %v", err) + return + } + fi, err := tdLogfile.Stat() + if err != nil { + tdLogfile.Close() + t.Errorf("Could not seek to end of testLogfile: %v", err) + return + } + _, err = tdLogfile.Seek(0, 0) + if err != nil { + tdLogfile.Close() + t.Errorf("Could not rewind testLogfile: %v", err) + return + } + buf := make([]byte, fi.Size()) + _, err = tdLogfile.Read(buf) + if err != nil { + tdLogfile.Close() + t.Errorf("Could not read %v bytes from testLogfile: %v", fi.Size(), err) + return + } + tdLogfile.Close() + t.Logf("Test output: %s", buf) + os.Remove(testLogfile.Name()) +} + +func checkFieldsEqual(t *testing.T, expected, actual map[string]interface{}, fieldlist []string) error { + var err error + for _, field := range fieldlist { + if !reflect.DeepEqual(expected[field], actual[field]) { + t.Errorf("field [%s] expected value [%v] does not match actual value [%v]", + field, expected[field], actual[field]) + if err == nil { + err = fmt.Errorf("one or more field values did not match") + } + } + } + return err } func TestKeepEmpty(t *testing.T) { - testLogfilename, err := setup(t) - defer os.Remove(testLogfilename) + cfg := UndefinedConfig{ + Debug: true, + Merge_json_log: true, + Use_undefined: true, + Undefined_to_string: false, + Default_keep_fields: "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL", + Extra_keep_fields: "undefined4,undefined5,empty1,undefined3", + Undefined_name: "undefined", + Keep_empty_fields: "undefined4,undefined5,empty1,undefined3", + Undefined_dot_replace_char: "UNUSED", + Undefined_max_num_fields: -1, + } + err := setup(t, cfg) + defer teardown(t) if err != nil { t.Errorf("test setup failed: %v", err) } - inputString := `{"hostname": "hostname", "level": "info", "@timestamp": "2019-07-17T21:26:45.913217+00:00", ` + + inputString := `{"@timestamp": "2019-07-17T21:26:45.913217+00:00", ` + `"undefined1": "undefined1", "undefined11": 1111, "undefined12": true, "empty1": "", ` + `"undefined2": { "undefined2": "undefined2", "": "", "undefined22": 2222, "undefined23": false }, ` + `"undefined3": { "emptyvalue": "" }, "undefined4": {}, "undefined5": "undefined5", ` + - `"undefined.6": "undefined6", "message": "message" }` + `"undefined.6": "undefined6" }` inputMap := make(map[string]interface{}) if err := json.Unmarshal([]byte(inputString), &inputMap); err != nil { t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) } - all, replaceMe, hasUndefined := replaceDotMoveUndefined(inputMap, true) - outputBytes, err := json.Marshal(all) + undefined_cur_num_fields = 99999999 + outputMap, replaceMe, hasUndefined := replaceDotMoveUndefined(inputMap, true) + outputBytes, err := json.Marshal(outputMap) t.Logf("outputBytes [%s] replaceMe [%v] hasUndefined [%v]", outputBytes, replaceMe, hasUndefined) + fieldlist := []string{"@timestamp", "empty1", "undefined3", "undefined4", "undefined5"} + if err = checkFieldsEqual(t, inputMap, outputMap, fieldlist); err != nil { + t.Error(err) + } + var val1 float64 = 1111 + var val2 float64 = 2222 + undefined2Map := map[string]interface{}{ + "undefined2": "undefined2", + "": "", + "undefined22": val2, + "undefined23": false, + } + undefinedMap := map[string]interface{}{ + "undefined1": "undefined1", + "undefined11": val1, + "undefined12": true, + "undefined2": undefined2Map, + "undefined.6": "undefined6", + } + fieldlist = []string{"undefined1", "undefined11", "undefined12", "undefined2", "undefined.6"} + if err = checkFieldsEqual(t, undefinedMap, outputMap["undefined"].(map[string]interface{}), fieldlist); err != nil { + t.Error(err) + } } From 4837a16e8991f914c6ee2e5cb08b6bc72ce089da Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 20:24:58 -0600 Subject: [PATCH 30/37] add go test to beginning of rsyslog test --- test/zzz-rsyslog.sh | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 6f6493fa8..75c515599 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -9,6 +9,10 @@ os::util::environment::use_sudo os::test::junit::declare_suite_start "test/zzz-rsyslog" +pushd ${OS_O_A_L_DIR}/rsyslog/undefined_field > /dev/null +go test -v 2>&1 | artifact_out +popd > /dev/null + LOGGING_NS=${LOGGING_NS:-openshift-logging} es_pod=$( get_es_pod es ) es_ops_pod=$( get_es_pod es-ops ) From 362d91ffe02617994782fae4836895e1ecde8825 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 21:15:08 -0600 Subject: [PATCH 31/37] add rsyslog source to ci test image for devs --- openshift/ci-operator/build-image/Dockerfile.full | 1 + 1 file changed, 1 insertion(+) diff --git a/openshift/ci-operator/build-image/Dockerfile.full b/openshift/ci-operator/build-image/Dockerfile.full index 527ba1305..851b3be59 100644 --- a/openshift/ci-operator/build-image/Dockerfile.full +++ b/openshift/ci-operator/build-image/Dockerfile.full @@ -14,3 +14,4 @@ ADD openshift/ /go/src/github.com/openshift/origin-aggregated-logging/openshift/ ADD hack/ /go/src/github.com/openshift/origin-aggregated-logging/hack/ ADD test/ /go/src/github.com/openshift/origin-aggregated-logging/test/ ADD fluentd/ /go/src/github.com/openshift/origin-aggregated-logging/fluentd/ +ADD rsyslog/ /go/src/github.com/openshift/origin-aggregated-logging/rsyslog/ From 9cd2098e76973c2beb3d52a7a4a54c082f44a99d Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Thu, 18 Jul 2019 22:32:34 -0600 Subject: [PATCH 32/37] fix keep or delete empty recursion --- rsyslog/undefined_field/undefined_field.go | 52 +++++++++---------- .../undefined_field/undefined_field_test.go | 3 +- 2 files changed, 25 insertions(+), 30 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index cd95bbaea..1ca30e018 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -205,14 +205,11 @@ func onInit() { } } -func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (map[string]interface{}, bool, bool) { +func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool, keepEmpty bool) (map[string]interface{}, bool, bool) { replace_me := false has_undefined := false cp := make(map[string]interface{}) for origkey, value := range input { - if topPropLevel && len(origkey) == 0 { - continue - } key := origkey if topPropLevel && merge_json_log && undefined_dot_replace_char != "UNUSED" { // replace '.' with specified char (e.g., '_') @@ -224,21 +221,18 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m // skip empty or not? valuemap, ismap := value.(map[string]interface{}) valuearray, isarray := value.([]interface{}) - var keepEmpty bool if topPropLevel { _, keepEmpty = keep_empty_fields[origkey] - if !keepEmpty { - valuestring, isstring := value.(string) - if (isarray && len(valuearray) == 0) || - (ismap && len(valuemap) == 0) || - (isstring && len(valuestring) == 0) || - (value == nil) { - replace_me = true - continue - } + } + if !keepEmpty { + valuestring, isstring := value.(string) + if (isarray && len(valuearray) == 0) || + (ismap && len(valuemap) == 0) || + (isstring && len(valuestring) == 0) || + (value == nil) { + replace_me = true + continue } - } else { - keepEmpty = true // only check top level fields } // use_undefined and key is not in keep_fields? _, keepit := keep_fields[origkey] @@ -250,13 +244,13 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m cp[undefined_name] = subcp } if isarray { - rval := replaceDotMoveUndefinedArray(valuearray) + rval := replaceDotMoveUndefinedArray(valuearray, keepEmpty) if keepEmpty || len(rval) > 0 { cp[undefined_name].(map[string]interface{})[key] = rval undefined_cur_num_fields-- } } else if ismap { - rval, _, _ := replaceDotMoveUndefined(valuemap, false) + rval, _, _ := replaceDotMoveUndefined(valuemap, false, keepEmpty) if keepEmpty || len(rval) > 0 { cp[undefined_name].(map[string]interface{})[key] = rval undefined_cur_num_fields-- @@ -269,12 +263,12 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m has_undefined = true } } else if isarray { - rval := replaceDotMoveUndefinedArray(valuearray) + rval := replaceDotMoveUndefinedArray(valuearray, keepEmpty) if keepEmpty || (rval != nil && len(rval) > 0) { cp[key] = rval } } else if ismap { - rval, _, _ := replaceDotMoveUndefined(valuemap, false) + rval, _, _ := replaceDotMoveUndefined(valuemap, false, keepEmpty) if keepEmpty || (rval != nil && len(rval) > 0) { cp[key] = rval } @@ -285,24 +279,26 @@ func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool) (m return cp, replace_me, has_undefined } -func replaceDotMoveUndefinedArray(inputs []interface{}) []interface{} { +func replaceDotMoveUndefinedArray(inputs []interface{}, keepEmpty bool) []interface{} { cp := make([]interface{}, 0) for _, input := range inputs { valuemap, ismap := input.(map[string]interface{}) valuearray, isarray := input.([]interface{}) valuestring, isstring := input.(string) if ismap { - rval, _, _ := replaceDotMoveUndefined(valuemap, false) - if rval != nil && len(rval) > 0 { + rval, _, _ := replaceDotMoveUndefined(valuemap, false, keepEmpty) + if keepEmpty || (rval != nil && len(rval) > 0) { cp = append(cp, rval) } } else if isarray { - rval := replaceDotMoveUndefinedArray(valuearray) - if rval != nil && len(rval) > 0 { + rval := replaceDotMoveUndefinedArray(valuearray, keepEmpty) + if keepEmpty || (rval != nil && len(rval) > 0) { cp = append(cp, rval) } - } else if isstring && len(valuestring) > 0 { - cp = append(cp, input) + } else if isstring { + if keepEmpty || (len(valuestring) > 0) { + cp = append(cp, input) + } } else if input != nil { cp = append(cp, input) } @@ -346,7 +342,7 @@ func main() { jsonCopyMap["$!"] = make(map[string]interface{}) } undefined_cur_num_fields = undefined_max_num_fields - all, replace_me, has_undefined := replaceDotMoveUndefined(topval, true) + all, replace_me, has_undefined := replaceDotMoveUndefined(topval, true, false) if !replace_me { if undefined_debug { fmt.Fprintln(logfile, "No Need to Replace for ", rawStr) diff --git a/rsyslog/undefined_field/undefined_field_test.go b/rsyslog/undefined_field/undefined_field_test.go index 651f2a62f..028f0a02a 100644 --- a/rsyslog/undefined_field/undefined_field_test.go +++ b/rsyslog/undefined_field/undefined_field_test.go @@ -114,7 +114,7 @@ func TestKeepEmpty(t *testing.T) { t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) } undefined_cur_num_fields = 99999999 - outputMap, replaceMe, hasUndefined := replaceDotMoveUndefined(inputMap, true) + outputMap, replaceMe, hasUndefined := replaceDotMoveUndefined(inputMap, true, false) outputBytes, err := json.Marshal(outputMap) t.Logf("outputBytes [%s] replaceMe [%v] hasUndefined [%v]", outputBytes, replaceMe, hasUndefined) fieldlist := []string{"@timestamp", "empty1", "undefined3", "undefined4", "undefined5"} @@ -125,7 +125,6 @@ func TestKeepEmpty(t *testing.T) { var val2 float64 = 2222 undefined2Map := map[string]interface{}{ "undefined2": "undefined2", - "": "", "undefined22": val2, "undefined23": false, } From 1c4f21eb9e2639fbeed57bf446773518e4599a7c Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Fri, 19 Jul 2019 21:41:24 -0600 Subject: [PATCH 33/37] working with new implementation --- rsyslog/undefined_field/undefined_field.go | 507 +++++++++++------- .../undefined_field/undefined_field_test.go | 100 +++- test/zzz-rsyslog.sh | 3 +- 3 files changed, 384 insertions(+), 226 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 1ca30e018..0ce8a8adb 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -85,297 +85,392 @@ import ( ) const ( - initial_logging_file_path = "/var/log/rsyslog/rsyslog.log" - default_undefined_config = "/var/lib/rsyslog.pod/undefined.json" - noChanges = "{}" + initialLoggingFilePath = "/var/log/rsyslog/rsyslog.log" + defaultUndefinedConfig = "/var/lib/rsyslog.pod/undefined.json" + noChanges = "{}" ) -type UndefinedConfig struct { - Debug bool `json:"UNDEFINED_DEBUG"` - Merge_json_log bool `json:"MERGE_JSON_LOG"` - Use_undefined bool `json:"CDM_USE_UNDEFINED"` - Undefined_to_string bool `json:"CDM_UNDEFINED_TO_STRING"` - Default_keep_fields string `json:"CDM_DEFAULT_KEEP_FIELDS"` - Extra_keep_fields string `json:"CDM_EXTRA_KEEP_FIELDS"` - Undefined_name string `json:"CDM_UNDEFINED_NAME"` - Keep_empty_fields string `json:"CDM_KEEP_EMPTY_FIELDS"` - Undefined_dot_replace_char string `json:"CDM_UNDEFINED_DOT_REPLACE_CHAR"` - Undefined_max_num_fields int64 `json:"CDM_UNDEFINED_MAX_NUM_FIELDS"` +type undefinedConfig struct { + Debug bool `json:"UNDEFINED_DEBUG"` + MergeJSONLog bool `json:"MERGE_JSON_LOG"` + UseUndefined bool `json:"CDM_USE_UNDEFINED"` + UndefinedToString bool `json:"CDM_UNDEFINED_TO_STRING"` + DefaultKeepFields string `json:"CDM_DEFAULT_KEEP_FIELDS"` + ExtraKeepFields string `json:"CDM_EXTRA_KEEP_FIELDS"` + UndefinedName string `json:"CDM_UNDEFINED_NAME"` + KeepEmptyFields string `json:"CDM_KEEP_EMPTY_FIELDS"` + UndefinedDotReplaceChar string `json:"CDM_UNDEFINED_DOT_REPLACE_CHAR"` + UndefinedMaxNumFields int64 `json:"CDM_UNDEFINED_MAX_NUM_FIELDS"` } var ( - undefined_debug bool - merge_json_log bool - use_undefined bool - keep_fields map[string]string - keep_empty_fields map[string]string - undefined_name string - undefined_to_string bool - undefined_dot_replace_char string - undefined_max_num_fields int64 - undefined_cur_num_fields int64 - logfile *os.File - replacer = &strings.Replacer{} - undefined_config string + keepFields map[string]string + keepEmptyFields map[string]string + logfile *os.File + replacer = &strings.Replacer{} + checkMaxNumFields bool + cfg undefinedConfig ) -func getMapStringValue(m map[string]interface{}, key string) (string, bool) { - if val, ok := m[key]; ok { - return val.(string), ok - } else { - return "", ok - } -} - func onInit() { // opening the rsyslog log file - logging_file_path := initial_logging_file_path + loggingFilePath := initialLoggingFilePath if eval := os.Getenv("LOGGING_FILE_PATH"); eval != "" { - logging_file_path = eval + loggingFilePath = eval } - if f, err := os.OpenFile(logging_file_path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644); err == nil { + if f, err := os.OpenFile(loggingFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644); err == nil { logfile = f } else { - panic(fmt.Errorf("Could not open file [%s]: [%v]", logging_file_path, err)) + panic(fmt.Errorf("Could not open file [%s]: [%v]", loggingFilePath, err)) } - undefined_config = default_undefined_config + undefinedConfigFile := defaultUndefinedConfig if eval := os.Getenv("UNDEFINED_CONFIG"); eval != "" { - undefined_config = eval + undefinedConfigFile = eval } - var undefined_config_obj UndefinedConfig - var default_keep_fields string - var extra_keep_fields string - var tmp_keep_empty_fields string - if config, err := os.Open(undefined_config); err == nil { + if config, err := os.Open(undefinedConfigFile); err == nil { defer config.Close() - - config_read, _ := ioutil.ReadAll(config) - json.Unmarshal(config_read, &undefined_config_obj) - - undefined_debug = undefined_config_obj.Debug - merge_json_log = undefined_config_obj.Merge_json_log - use_undefined = undefined_config_obj.Use_undefined - default_keep_fields = undefined_config_obj.Default_keep_fields - extra_keep_fields = undefined_config_obj.Extra_keep_fields - undefined_name = undefined_config_obj.Undefined_name - tmp_keep_empty_fields = undefined_config_obj.Keep_empty_fields - undefined_to_string = undefined_config_obj.Undefined_to_string - undefined_dot_replace_char = undefined_config_obj.Undefined_dot_replace_char - undefined_max_num_fields = undefined_config_obj.Undefined_max_num_fields - } else if !strings.Contains(err.Error(), "no such file or directory") { - fmt.Fprintf(logfile, "ERROR: Could not open config file [%s]: [%v]\n", undefined_config, err) - panic(fmt.Errorf("Could not open config file [%s]: [%v]", undefined_config, err)) + configRead, _ := ioutil.ReadAll(config) + json.Unmarshal(configRead, &cfg) + } else if err != os.ErrNotExist { + fmt.Fprintf(logfile, "ERROR: Could not open config file [%s]: [%v]\n", undefinedConfigFile, err) + panic(fmt.Errorf("Could not open config file [%s]: [%v]", undefinedConfigFile, err)) } - if undefined_max_num_fields == -1 { - undefined_max_num_fields = int64(^uint(0) >> 1) + if cfg.UndefinedMaxNumFields == -1 { + checkMaxNumFields = false + cfg.UndefinedMaxNumFields = int64(^uint(0) >> 1) + } else { + checkMaxNumFields = true } - if use_undefined { - tmp_default := strings.Split(default_keep_fields, ",") - tmp_extra := strings.Split(extra_keep_fields, ",") - keep_fields = make(map[string]string) - for _, str := range tmp_default { - keep_fields[str] = str + if cfg.UseUndefined { + tmpDefault := strings.Split(cfg.DefaultKeepFields, ",") + tmpExtra := strings.Split(cfg.ExtraKeepFields, ",") + keepFields = make(map[string]string) + for _, str := range tmpDefault { + keepFields[str] = str } - for _, str := range tmp_extra { - keep_fields[str] = str + for _, str := range tmpExtra { + keepFields[str] = str } } - tmp := strings.Split(tmp_keep_empty_fields, ",") - keep_empty_fields = make(map[string]string) + tmp := strings.Split(cfg.KeepEmptyFields, ",") + keepEmptyFields = make(map[string]string) for _, str := range tmp { - keep_empty_fields[str] = str + keepEmptyFields[str] = str } - if undefined_dot_replace_char != "UNUSED" { - replacer = strings.NewReplacer(".", undefined_dot_replace_char) + if cfg.UndefinedDotReplaceChar != "UNUSED" { + replacer = strings.NewReplacer(".", cfg.UndefinedDotReplaceChar) } - if undefined_debug { - fmt.Fprintln(logfile, "mmexternal: merge_json_log: ", merge_json_log) - fmt.Fprintln(logfile, "mmexternal: use_undefined: ", use_undefined) - fmt.Fprintln(logfile, "mmexternal: default_keep_fields: ", default_keep_fields) - fmt.Fprintln(logfile, "mmexternal: extra_keep_fields: ", extra_keep_fields) - fmt.Fprintln(logfile, "mmexternal: undefined_name: ", undefined_name) - fmt.Fprintf(logfile, "mmexternal: keep_empty_fields: %v %v\n", tmp_keep_empty_fields, keep_empty_fields) - fmt.Fprintln(logfile, "mmexternal: undefined_to_string: ", undefined_to_string) - fmt.Fprintln(logfile, "mmexternal: undefined_dot_replace_char: ", undefined_dot_replace_char) - fmt.Fprintln(logfile, "mmexternal: undefined_max_num_fields: ", undefined_max_num_fields) + if cfg.Debug { + fmt.Fprintln(logfile, "mmexternal: merge_json_log: ", cfg.MergeJSONLog) + fmt.Fprintln(logfile, "mmexternal: use_undefined: ", cfg.UseUndefined) + fmt.Fprintln(logfile, "mmexternal: default_keep_fields: ", cfg.DefaultKeepFields) + fmt.Fprintln(logfile, "mmexternal: extra_keep_fields: ", cfg.ExtraKeepFields) + fmt.Fprintln(logfile, "mmexternal: undefined_name: ", cfg.UndefinedName) + fmt.Fprintf(logfile, "mmexternal: keep_empty_fields: %v %v\n", cfg.KeepEmptyFields, keepEmptyFields) + fmt.Fprintln(logfile, "mmexternal: undefined_to_string: ", cfg.UndefinedToString) + fmt.Fprintln(logfile, "mmexternal: undefined_dot_replace_char: ", cfg.UndefinedDotReplaceChar) + fmt.Fprintln(logfile, "mmexternal: undefinedMaxNumFields: ", cfg.UndefinedMaxNumFields) } } -func replaceDotMoveUndefined(input map[string]interface{}, topPropLevel bool, keepEmpty bool) (map[string]interface{}, bool, bool) { - replace_me := false - has_undefined := false - cp := make(map[string]interface{}) - for origkey, value := range input { - key := origkey - if topPropLevel && merge_json_log && undefined_dot_replace_char != "UNUSED" { - // replace '.' with specified char (e.g., '_') - key = replacer.Replace(origkey) - if key != origkey { - replace_me = true +// This function has two purposes. +// 1) Check if the number of undefined fields exceeds the maximum value, if any. +// If so, return a JSON string representation of a map of the undefined +// fields, suitable for returning in the record[$undefined] value, and +// the error, if any, returned from json.Marshal. +// 2) If use_undefined is true, move the undefined fields to a separate +// map. +// Return values: +// * The JSON string representation of the map of the undefined fields if the +// undefined field count exceeded the max, or "" +// * A map of the undefined fields if undefined field checking was enabled. +// Otherwise, nil. Map may be empty if there were no undefined fields. +// * err return from json.Marshal +// Side effects: +// The undefined fields are moved from the input map to the undefMap returned +func processUndefinedAndMaxNumFields(input map[string]interface{}) (string, map[string]interface{}, error) { + if !checkMaxNumFields && !cfg.UseUndefined { + return "", nil, nil // not used + } + count := cfg.UndefinedMaxNumFields + var undefMap map[string]interface{} + for field, val := range input { + if _, keep := keepFields[field]; !keep { + if undefMap == nil { + undefMap = make(map[string]interface{}) } + undefMap[field] = val + count-- } - // skip empty or not? - valuemap, ismap := value.(map[string]interface{}) - valuearray, isarray := value.([]interface{}) - if topPropLevel { - _, keepEmpty = keep_empty_fields[origkey] + } + if undefMap == nil || len(undefMap) == 0 { + return "", nil, nil // no undefined fields + } + if count < 0 || cfg.UseUndefined { + for field := range undefMap { + delete(input, field) } - if !keepEmpty { - valuestring, isstring := value.(string) - if (isarray && len(valuearray) == 0) || - (ismap && len(valuemap) == 0) || - (isstring && len(valuestring) == 0) || - (value == nil) { - replace_me = true - continue + if count < 0 { + // undefined fields converted to string - no undefMap + b, err := json.Marshal(undefMap) + return string(b), nil, err + } + } + return "", nil, nil +} + +func isFieldUndefined(field string, hasDefinedFields, hasUndefinedFields bool) bool { + if !hasUndefinedFields { + return false // input contains only defined fields + } else if !hasDefinedFields { + return true // input contains only undefined fields + } else { + _, definedField := keepFields[field] // see if field is a keeper + return !definedField + } +} + +func processUndefinedToString(input map[string]interface{}, field string, val interface{}) bool { + inputWasModified := false + if _, isstring := val.(string); !isstring { + var err error + input[field], err = json.Marshal(val) // replace val in-place + if err != nil { + if cfg.Debug { + fmt.Fprintf(logfile, "Could not convert field [%s] value [%v] to JSON string: %v\n", field, val, err) } + // fallback + input[field] = fmt.Sprintf("%v", val) // replace val in-place } - // use_undefined and key is not in keep_fields? - _, keepit := keep_fields[origkey] - if topPropLevel && use_undefined && !keepit { - // if undefined_max_num_fields > 0, move the undefined item to undefined_name - if undefined_cur_num_fields > 0 { - if cp[undefined_name] == nil { - subcp := make(map[string]interface{}) - cp[undefined_name] = subcp - } - if isarray { - rval := replaceDotMoveUndefinedArray(valuearray, keepEmpty) - if keepEmpty || len(rval) > 0 { - cp[undefined_name].(map[string]interface{})[key] = rval - undefined_cur_num_fields-- - } - } else if ismap { - rval, _, _ := replaceDotMoveUndefined(valuemap, false, keepEmpty) - if keepEmpty || len(rval) > 0 { - cp[undefined_name].(map[string]interface{})[key] = rval - undefined_cur_num_fields-- - } - } else { - cp[undefined_name].(map[string]interface{})[key] = value - undefined_cur_num_fields-- - } - replace_me = true - has_undefined = true + inputWasModified = true + } + return inputWasModified +} + +func processDotReplaceChar(field string, replacedFields map[string]string) (string, map[string]string) { + newfield := replacer.Replace(field) + if newfield != field { + if replacedFields == nil { + replacedFields = make(map[string]string) + } + replacedFields[field] = newfield + } + return newfield, replacedFields +} + +// a value is empty if +// * it is nil +// * it is an empty string +// * it is a zero length array or map +// * it is an array and all its elements are empty +// * it is a map and all of its values are empty +func isEmpty(val interface{}) bool { + switch tval := val.(type) { + case nil: + return true + case string: + return len(tval) == 0 + case []interface{}: + return len(tval) == 0 + case map[string]interface{}: + return len(tval) == 0 + default: + return false // no other type can have an empty value + } +} + +// go through val recursively deleting any empty elements found +// returns the value with the empty elements removed +func delEmpty(val interface{}) (interface{}, bool) { + changed := false + elemChanged := false + switch tval := val.(type) { + case []interface{}: + if len(tval) == 0 { + return val, changed + } + result := tval[:0] + for _, elem := range tval { + elem, elemChanged = delEmpty(elem) + if !isEmpty(elem) { + result = append(result, elem) + changed = true } - } else if isarray { - rval := replaceDotMoveUndefinedArray(valuearray, keepEmpty) - if keepEmpty || (rval != nil && len(rval) > 0) { - cp[key] = rval + if elemChanged { + changed = true } - } else if ismap { - rval, _, _ := replaceDotMoveUndefined(valuemap, false, keepEmpty) - if keepEmpty || (rval != nil && len(rval) > 0) { - cp[key] = rval + } + return result, changed + case map[string]interface{}: + if len(tval) == 0 { + return val, changed + } + for key, mapval := range tval { + mapval, elemChanged = delEmpty(mapval) + if isEmpty(mapval) { + delete(tval, key) + changed = true + } else { + tval[key] = mapval + } + if elemChanged { + changed = true } - } else { - cp[key] = value } + return val, changed + default: + return val, changed } - return cp, replace_me, has_undefined } -func replaceDotMoveUndefinedArray(inputs []interface{}, keepEmpty bool) []interface{} { - cp := make([]interface{}, 0) - for _, input := range inputs { - valuemap, ismap := input.(map[string]interface{}) - valuearray, isarray := input.([]interface{}) - valuestring, isstring := input.(string) - if ismap { - rval, _, _ := replaceDotMoveUndefined(valuemap, false, keepEmpty) - if keepEmpty || (rval != nil && len(rval) > 0) { - cp = append(cp, rval) +// process the undefined fields - convert to string value, convert +// "." in the field names to the undefined_dot_replace_char +// also remove empty fields +// The given input map may contain only undefined fields, or only +// defined fields, or a mix of both +// the given input map is modified in place +// Returns false if the input was unchanged +func processUndefinedAndEmpty(input map[string]interface{}, hasDefinedFields, hasUndefinedFields bool) bool { + var replacedFields map[string]string // map old to new name + inputWasModified := false + for field, val := range input { + newfield := field + if isFieldUndefined(field, hasDefinedFields, hasUndefinedFields) { + if cfg.UndefinedToString { + if processUndefinedToString(input, field, val) { + inputWasModified = true + } } - } else if isarray { - rval := replaceDotMoveUndefinedArray(valuearray, keepEmpty) - if keepEmpty || (rval != nil && len(rval) > 0) { - cp = append(cp, rval) + if cfg.UndefinedDotReplaceChar != "UNUSED" && strings.Contains(field, ".") { + newfield, replacedFields = processDotReplaceChar(field, replacedFields) } - } else if isstring { - if keepEmpty || (len(valuestring) > 0) { - cp = append(cp, input) + } + // should be the newfield if using undefined_dot_replace_char + _, keepEmpty := keepEmptyFields[newfield] + if !keepEmpty { + changed := false + val, changed = delEmpty(val) + if isEmpty(val) { + inputWasModified = true + delete(input, field) + } else { + input[field] = val + if changed { + inputWasModified = true + } } - } else if input != nil { - cp = append(cp, input) } } - return cp + if replacedFields != nil && len(replacedFields) > 0 { + inputWasModified = true + for oldfield, newfield := range replacedFields { + input[newfield] = input[oldfield] + delete(input, oldfield) + } + } + return inputWasModified } func main() { onInit() defer logfile.Close() - - reader := bufio.NewReader(os.Stdin) + var reader *bufio.Reader + var testInputFile *os.File + if ff := os.Getenv("TEST_INPUT_FILE"); ff != "" { + var err error + testInputFile, err = os.Open(ff) + if err != nil { + panic(fmt.Errorf("Could not open %v: %v", ff, err)) + } + reader = bufio.NewReader(testInputFile) + defer testInputFile.Close() + } else { + reader = bufio.NewReader(os.Stdin) + } scanner := bufio.NewScanner(reader) scanner.Split(bufio.ScanLines) for scanner.Scan() { - jsonCopyMap := make(map[string]interface{}) jsonMap := make(map[string]interface{}) rawStr := scanner.Text() - if undefined_debug { + if cfg.Debug { fmt.Fprintln(logfile, "Source: ", rawStr) } - if err := json.Unmarshal([]byte(rawStr), &jsonMap); err != nil { + if err := json.Unmarshal(scanner.Bytes(), &jsonMap); err != nil { fmt.Fprintln(logfile, "json.Unmarshal failed (", err, "): ", rawStr) fmt.Println(noChanges) continue } if jsonMap["$!"] == nil { + fmt.Fprintln(logfile, "Source contains no $! field: ", rawStr) continue } topval, ismap := jsonMap["$!"].(map[string]interface{}) if !ismap { - if undefined_debug { + if cfg.Debug { fmt.Fprintln(logfile, "Result is String: ", rawStr) } fmt.Println(noChanges) continue } - if jsonCopyMap["$!"] == nil { - jsonCopyMap["$!"] = make(map[string]interface{}) + undefString, undefMap, err := processUndefinedAndMaxNumFields(topval) + if err != nil { + // error marshalling undefined fields to JSON + if cfg.Debug { + fmt.Fprintf(logfile, "Unable to convert undefined fields to JSON string: %v : rawStr: %s\n", err, rawStr) + } + fmt.Println(noChanges) + continue + } + changes := false + if len(undefString) > 0 || undefMap != nil { + changes = true + } + if undefMap != nil { + if processUndefinedAndEmpty(undefMap, false, true) { + changes = true + } + } + if len(topval) > 0 { + if processUndefinedAndEmpty(topval, true, (undefMap == nil)) { + changes = true + } } - undefined_cur_num_fields = undefined_max_num_fields - all, replace_me, has_undefined := replaceDotMoveUndefined(topval, true, false) - if !replace_me { - if undefined_debug { + if !changes { + if cfg.Debug { fmt.Fprintln(logfile, "No Need to Replace for ", rawStr) } fmt.Println(noChanges) continue } - jsonCopyMap["$!"].(map[string]interface{})["openshift_logging_all"] = all - if tmp_val, err := json.Marshal(jsonCopyMap); err == nil { - if use_undefined && undefined_to_string && has_undefined { - if err := json.Unmarshal([]byte(tmp_val), &jsonCopyMap); err == nil { - // if unmarshal fails, giving up converting to string... - if undefined, err := json.Marshal(jsonCopyMap[undefined_name]); err == nil { - jsonCopyMap[undefined_name] = string(undefined) - if tmp_val0, err := json.Marshal(jsonCopyMap); err == nil { - tmp_val = tmp_val0 - } else { - fmt.Fprintln(logfile, "Marshaling undefined value converted to string failed (", err, "): ", tmp_val) - } - } else { - fmt.Fprintln(logfile, "Marshaling undefined value failed (", err, "): ", tmp_val) - } - } else { - fmt.Fprintln(logfile, "Parsing processed json failed (", err, "): ", tmp_val) - } - } - if undefined_debug { - fmt.Fprintln(logfile, "Result: ", string(tmp_val)) + if len(undefString) > 0 { + topval[cfg.UndefinedName] = undefString + } else if undefMap != nil && len(undefMap) > 0 { + // if len is 0, means all fields were empty + topval[cfg.UndefinedName] = undefMap + } + loggingAll := map[string]interface{}{ + "openshift_logging_all": topval, + } + outputMap := map[string]interface{}{ + "$!": loggingAll, + } + outputString, err := json.Marshal(outputMap) + if err != nil { + if cfg.Debug { + fmt.Fprintln(logfile, "Final Marshal failed (", err, "): ", rawStr) } - fmt.Println(string(tmp_val)) - } else { - fmt.Fprintln(logfile, "Final Marshal failed (", err, "): ", rawStr) fmt.Println(noChanges) + } else { + if cfg.Debug { + fmt.Fprintln(logfile, "Result: ", string(outputString)) + } + fmt.Println(string(outputString)) } } } diff --git a/rsyslog/undefined_field/undefined_field_test.go b/rsyslog/undefined_field/undefined_field_test.go index 028f0a02a..ddce316e1 100644 --- a/rsyslog/undefined_field/undefined_field_test.go +++ b/rsyslog/undefined_field/undefined_field_test.go @@ -13,7 +13,7 @@ var ( testLogfile *os.File ) -func setup(t *testing.T, cfg UndefinedConfig) error { +func setup(t *testing.T, cfg undefinedConfig) error { var err error testLogfile, err = ioutil.TempFile("", "log") if err != nil { @@ -87,17 +87,78 @@ func checkFieldsEqual(t *testing.T, expected, actual map[string]interface{}, fie } func TestKeepEmpty(t *testing.T) { - cfg := UndefinedConfig{ - Debug: true, - Merge_json_log: true, - Use_undefined: true, - Undefined_to_string: false, - Default_keep_fields: "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL", - Extra_keep_fields: "undefined4,undefined5,empty1,undefined3", - Undefined_name: "undefined", - Keep_empty_fields: "undefined4,undefined5,empty1,undefined3", - Undefined_dot_replace_char: "UNUSED", - Undefined_max_num_fields: -1, + testcfg := undefinedConfig{ + Debug: true, + MergeJSONLog: true, + UseUndefined: true, + UndefinedToString: false, + DefaultKeepFields: "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL", + ExtraKeepFields: "undefined4,undefined5,empty1,undefined3", + UndefinedName: "undefined", + KeepEmptyFields: "undefined4,undefined5,empty1,undefined3", + UndefinedDotReplaceChar: "UNUSED", + UndefinedMaxNumFields: -1, + } + err := setup(t, testcfg) + defer teardown(t) + if err != nil { + t.Errorf("test setup failed: %v", err) + } + inputString := `{"@timestamp": "2019-07-17T21:26:45.913217+00:00", ` + + `"undefined1": "undefined1", "undefined11": 1111, "undefined12": true, "empty1": "", ` + + `"undefined2": { "undefined2": "undefined2", "": "", "undefined22": 2222, "undefined23": false }, ` + + `"undefined3": { "emptyvalue": "" }, "undefined4": {}, "undefined5": "undefined5", ` + + `"undefined.6": "undefined6" }` + inputMap := make(map[string]interface{}) + if err := json.Unmarshal([]byte(inputString), &inputMap); err != nil { + t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) + } + origMap := make(map[string]interface{}) + if err := json.Unmarshal([]byte(inputString), &origMap); err != nil { + t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) + } + changed := processUndefinedAndEmpty(inputMap, true, true) + if !changed { + t.Errorf("Expected changes not performed on the input") + } + outputBytes, _ := json.Marshal(inputMap) + t.Logf("outputBytes [%s]", outputBytes) + fieldlist := []string{"@timestamp", "empty1", "undefined3", "undefined4", "undefined5"} + if err = checkFieldsEqual(t, origMap, inputMap, fieldlist); err != nil { + t.Error(err) + } + var val1 float64 = 1111 + var val2 float64 = 2222 + undefined2Map := map[string]interface{}{ + "undefined2": "undefined2", + "undefined22": val2, + "undefined23": false, + } + undefinedMap := map[string]interface{}{ + "undefined1": "undefined1", + "undefined11": val1, + "undefined12": true, + "undefined2": undefined2Map, + "undefined.6": "undefined6", + } + fieldlist = []string{"undefined1", "undefined11", "undefined12", "undefined2", "undefined.6"} + if err = checkFieldsEqual(t, undefinedMap, inputMap, fieldlist); err != nil { + t.Error(err) + } +} + +func TestUndefinedMaxNumFields(t *testing.T) { + cfg = undefinedConfig{ + Debug: true, + MergeJSONLog: true, + UseUndefined: true, + UndefinedToString: false, + DefaultKeepFields: "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL", + ExtraKeepFields: "undefined4,undefined5,empty1,undefined3", + UndefinedName: "undefined", + KeepEmptyFields: "undefined4,undefined5,empty1,undefined3", + UndefinedDotReplaceChar: "UNUSED", + UndefinedMaxNumFields: 1, } err := setup(t, cfg) defer teardown(t) @@ -113,12 +174,15 @@ func TestKeepEmpty(t *testing.T) { if err := json.Unmarshal([]byte(inputString), &inputMap); err != nil { t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) } - undefined_cur_num_fields = 99999999 - outputMap, replaceMe, hasUndefined := replaceDotMoveUndefined(inputMap, true, false) - outputBytes, err := json.Marshal(outputMap) - t.Logf("outputBytes [%s] replaceMe [%v] hasUndefined [%v]", outputBytes, replaceMe, hasUndefined) + origMap := make(map[string]interface{}) + if err := json.Unmarshal([]byte(inputString), &origMap); err != nil { + t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) + } + undefString, undefMap, _ := processUndefinedAndMaxNumFields(inputMap) + outputBytes, _ := json.Marshal(inputMap) + t.Logf("outputBytes [%s] undefString [%s] undefMap [%v]", outputBytes, undefString, undefMap) fieldlist := []string{"@timestamp", "empty1", "undefined3", "undefined4", "undefined5"} - if err = checkFieldsEqual(t, inputMap, outputMap, fieldlist); err != nil { + if err = checkFieldsEqual(t, origMap, inputMap, fieldlist); err != nil { t.Error(err) } var val1 float64 = 1111 @@ -136,7 +200,7 @@ func TestKeepEmpty(t *testing.T) { "undefined.6": "undefined6", } fieldlist = []string{"undefined1", "undefined11", "undefined12", "undefined2", "undefined.6"} - if err = checkFieldsEqual(t, undefinedMap, outputMap["undefined"].(map[string]interface{}), fieldlist); err != nil { + if err = checkFieldsEqual(t, undefinedMap, inputMap, fieldlist); err != nil { t.Error(err) } } diff --git a/test/zzz-rsyslog.sh b/test/zzz-rsyslog.sh index 75c515599..9b6218da0 100755 --- a/test/zzz-rsyslog.sh +++ b/test/zzz-rsyslog.sh @@ -428,7 +428,7 @@ os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq- artifact_log "7. set CDM_UNDEFINED_MAX_NUM_FIELDS to 3" stop_rsyslog $rpod -oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 CMERGE_JSON_LOG=true DM_UNDEFINED_DOT_REPLACE_CHAR=_ CDM_UNDEFINED_MAX_NUM_FIELDS=3 2>&1 | artifact_out +oc set env $rsyslog_ds CDM_EXTRA_KEEP_FIELDS=undefined4,undefined5,empty1,undefined3,$keep_fields CDM_KEEP_EMPTY_FIELDS=undefined4,undefined5,empty1,undefined3 MERGE_JSON_LOG=true CDM_UNDEFINED_DOT_REPLACE_CHAR=_ CDM_UNDEFINED_MAX_NUM_FIELDS=3 2>&1 | artifact_out start_rsyslog rpod=$( get_running_pod rsyslog ) @@ -438,4 +438,3 @@ os::cmd::expect_success "cat $ops | python $OS_O_A_L_DIR/hack/testing/test-viaq- os::cmd::expect_success "oc exec $rpod -c rsyslog -- ls -l /var/log/rsyslog/rsyslog.log" os::cmd::expect_failure "oc exec $rpod -c rsyslog -- grep 'panic: interface conversion' /var/log/rsyslog/rsyslog.log" - From 2672400c934bf7f5b1869020e3a7d1dc4a364934 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Sun, 21 Jul 2019 20:29:50 -0600 Subject: [PATCH 34/37] fix logic when deleting/keeping array elements --- rsyslog/undefined_field/undefined_field.go | 1 + 1 file changed, 1 insertion(+) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 0ce8a8adb..74f849966 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -298,6 +298,7 @@ func delEmpty(val interface{}) (interface{}, bool) { elem, elemChanged = delEmpty(elem) if !isEmpty(elem) { result = append(result, elem) + } else { changed = true } if elemChanged { From 9e49aef43584d7eaff0a4bf8523d32fc0e1d0ac7 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Sun, 21 Jul 2019 20:30:00 -0600 Subject: [PATCH 35/37] fix test logic --- rsyslog/undefined_field/undefined_field_test.go | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/rsyslog/undefined_field/undefined_field_test.go b/rsyslog/undefined_field/undefined_field_test.go index ddce316e1..202b5246d 100644 --- a/rsyslog/undefined_field/undefined_field_test.go +++ b/rsyslog/undefined_field/undefined_field_test.go @@ -185,6 +185,15 @@ func TestUndefinedMaxNumFields(t *testing.T) { if err = checkFieldsEqual(t, origMap, inputMap, fieldlist); err != nil { t.Error(err) } + if undefMap != nil { + t.Error("The undefMap is supposed to be nil") + } + // convert undefString back to map for comparison purposes + undefMap = make(map[string]interface{}) + err = json.Unmarshal([]byte(undefString), &undefMap) + if err != nil { + t.Errorf("Could not convert undefString [%s] back to map: %v", undefString, err) + } var val1 float64 = 1111 var val2 float64 = 2222 undefined2Map := map[string]interface{}{ From d3f2320e4deb3d54b5393a94ac293734ad1dc223 Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Mon, 22 Jul 2019 11:21:35 -0600 Subject: [PATCH 36/37] fix max num field test --- .../undefined_field/undefined_field_test.go | 29 ++++++++----------- 1 file changed, 12 insertions(+), 17 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field_test.go b/rsyslog/undefined_field/undefined_field_test.go index 202b5246d..2e9cd8e50 100644 --- a/rsyslog/undefined_field/undefined_field_test.go +++ b/rsyslog/undefined_field/undefined_field_test.go @@ -158,7 +158,9 @@ func TestUndefinedMaxNumFields(t *testing.T) { UndefinedName: "undefined", KeepEmptyFields: "undefined4,undefined5,empty1,undefined3", UndefinedDotReplaceChar: "UNUSED", - UndefinedMaxNumFields: 1, + // the test should have 5 undefined fields - if UndefinedMaxNumFields == number of undefined fields - 1 + // this allows us to check for off-by-one errors as well + UndefinedMaxNumFields: 4, } err := setup(t, cfg) defer teardown(t) @@ -178,9 +180,13 @@ func TestUndefinedMaxNumFields(t *testing.T) { if err := json.Unmarshal([]byte(inputString), &origMap); err != nil { t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) } + expectedUndefString := `{"undefined.6":"undefined6","undefined1":"undefined1","undefined11":1111,"undefined12":true,"undefined2":{"":"","undefined2":"undefined2","undefined22":2222,"undefined23":false}}` undefString, undefMap, _ := processUndefinedAndMaxNumFields(inputMap) outputBytes, _ := json.Marshal(inputMap) t.Logf("outputBytes [%s] undefString [%s] undefMap [%v]", outputBytes, undefString, undefMap) + if undefMap != nil { + t.Errorf("undefMap should be nil but has value %v", undefMap) + } fieldlist := []string{"@timestamp", "empty1", "undefined3", "undefined4", "undefined5"} if err = checkFieldsEqual(t, origMap, inputMap, fieldlist); err != nil { t.Error(err) @@ -190,26 +196,15 @@ func TestUndefinedMaxNumFields(t *testing.T) { } // convert undefString back to map for comparison purposes undefMap = make(map[string]interface{}) - err = json.Unmarshal([]byte(undefString), &undefMap) - if err != nil { + if err = json.Unmarshal([]byte(undefString), &undefMap); err != nil { t.Errorf("Could not convert undefString [%s] back to map: %v", undefString, err) } - var val1 float64 = 1111 - var val2 float64 = 2222 - undefined2Map := map[string]interface{}{ - "undefined2": "undefined2", - "undefined22": val2, - "undefined23": false, - } - undefinedMap := map[string]interface{}{ - "undefined1": "undefined1", - "undefined11": val1, - "undefined12": true, - "undefined2": undefined2Map, - "undefined.6": "undefined6", + expectedUndefMap := make(map[string]interface{}) + if err = json.Unmarshal([]byte(expectedUndefString), &expectedUndefMap); err != nil { + t.Errorf("Could not convert expectedUndefString [%s] back to map: %v", expectedUndefString, err) } fieldlist = []string{"undefined1", "undefined11", "undefined12", "undefined2", "undefined.6"} - if err = checkFieldsEqual(t, undefinedMap, inputMap, fieldlist); err != nil { + if err = checkFieldsEqual(t, expectedUndefMap, undefMap, fieldlist); err != nil { t.Error(err) } } From d85034cf3d732d61231194db5a379842b4196f0f Mon Sep 17 00:00:00 2001 From: Rich Megginson Date: Mon, 22 Jul 2019 15:30:23 -0600 Subject: [PATCH 37/37] fix undefined to string handling --- rsyslog/undefined_field/undefined_field.go | 24 +++-- .../undefined_field/undefined_field_test.go | 89 +++++++++++++++++++ 2 files changed, 106 insertions(+), 7 deletions(-) diff --git a/rsyslog/undefined_field/undefined_field.go b/rsyslog/undefined_field/undefined_field.go index 74f849966..cbaef9285 100644 --- a/rsyslog/undefined_field/undefined_field.go +++ b/rsyslog/undefined_field/undefined_field.go @@ -234,21 +234,29 @@ func isFieldUndefined(field string, hasDefinedFields, hasUndefinedFields bool) b } } -func processUndefinedToString(input map[string]interface{}, field string, val interface{}) bool { +// convert the given field value to a string if not already a string +// modifies the value in input in place - if the returned bool is +// true, the field value was changed, and the new value is returned in the +// interface{} return value +func processUndefinedToString(input map[string]interface{}, field string, val interface{}) (interface{}, bool) { inputWasModified := false + var newval string if _, isstring := val.(string); !isstring { - var err error - input[field], err = json.Marshal(val) // replace val in-place - if err != nil { + bval, err := json.Marshal(val) // convert to JSON string + if err == nil { + newval = string(bval) + input[field] = newval // replace val in-place + } else { if cfg.Debug { fmt.Fprintf(logfile, "Could not convert field [%s] value [%v] to JSON string: %v\n", field, val, err) } // fallback - input[field] = fmt.Sprintf("%v", val) // replace val in-place + newval = fmt.Sprintf("%v", val) + input[field] = newval // replace val in-place } inputWasModified = true } - return inputWasModified + return newval, inputWasModified } func processDotReplaceChar(field string, replacedFields map[string]string) (string, map[string]string) { @@ -342,8 +350,10 @@ func processUndefinedAndEmpty(input map[string]interface{}, hasDefinedFields, ha newfield := field if isFieldUndefined(field, hasDefinedFields, hasUndefinedFields) { if cfg.UndefinedToString { - if processUndefinedToString(input, field, val) { + newval, changed := processUndefinedToString(input, field, val) + if changed { inputWasModified = true + val = newval // use new val now } } if cfg.UndefinedDotReplaceChar != "UNUSED" && strings.Contains(field, ".") { diff --git a/rsyslog/undefined_field/undefined_field_test.go b/rsyslog/undefined_field/undefined_field_test.go index 2e9cd8e50..23965a466 100644 --- a/rsyslog/undefined_field/undefined_field_test.go +++ b/rsyslog/undefined_field/undefined_field_test.go @@ -208,3 +208,92 @@ func TestUndefinedMaxNumFields(t *testing.T) { t.Error(err) } } + +func TestUndefinedToString(t *testing.T) { + testcfg := undefinedConfig{ + Debug: true, + MergeJSONLog: true, + UseUndefined: true, + UndefinedToString: true, + DefaultKeepFields: "method,statusCode,type,@timestamp,req,res,CONTAINER_NAME,CONTAINER_ID_FULL", + ExtraKeepFields: "undefined4,undefined5,empty1,undefined3", + UndefinedName: "undefined", + KeepEmptyFields: "undefined4,undefined5,empty1,undefined3", + UndefinedDotReplaceChar: "UNUSED", + UndefinedMaxNumFields: -1, + } + err := setup(t, testcfg) + defer teardown(t) + if err != nil { + t.Errorf("test setup failed: %v", err) + } + inputString := `{"@timestamp": "2019-07-17T21:26:45.913217+00:00", ` + + `"undefined1": "undefined1", "undefined11": 1111, "undefined12": true, "empty1": "", ` + + `"undefined2": { "undefined2": "undefined2", "": "", "undefined22": 2222, "undefined23": false }, ` + + `"undefinedary": ["a",1,false,{"b":"c"},["d",2,true,{"e":"f"}]],` + + `"undefined3": { "emptyvalue": "" }, "undefined4": {}, "undefined5": "undefined5", ` + + `"undefined.6": "undefined6" }` + expectedOutputString := `{"@timestamp": "2019-07-17T21:26:45.913217+00:00", ` + + `"undefined1": "undefined1", "undefined11": "1111", "undefined12": "true", "empty1": "", ` + + `"undefined2": "{ \"undefined2\": \"undefined2\", \"\": \"\", \"undefined22\": 2222, \"undefined23\": false }", ` + + `"undefinedary": "[\"a\",1,false,{\"b\":\"c\"},[\"d\",2,true,{\"e\":\"f\"}]]",` + + `"undefined3": { "emptyvalue": "" }, "undefined4": {}, "undefined5": "undefined5", ` + + `"undefined.6": "undefined6" }` + inputMap := make(map[string]interface{}) + if err := json.Unmarshal([]byte(inputString), &inputMap); err != nil { + t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) + } + origMap := make(map[string]interface{}) + if err := json.Unmarshal([]byte(inputString), &origMap); err != nil { + t.Errorf("json.Unmarshal failed for inputString [%v]: %v", inputString, err) + } + changed := processUndefinedAndEmpty(inputMap, true, true) + if !changed { + t.Errorf("Expected changes not performed on the input") + } + outputBytes, _ := json.Marshal(inputMap) + t.Logf("outputBytes [%s]", outputBytes) + expectedOutputMap := make(map[string]interface{}) + if err = json.Unmarshal([]byte(expectedOutputString), &expectedOutputMap); err != nil { + t.Errorf("Could not convert expectedOutputString [%s] to map: %v", expectedOutputString, err) + } + t.Logf("using s [%s] using v [%v]", expectedOutputMap, expectedOutputMap) + expectedUndef2 := expectedOutputMap["undefined2"] + delete(expectedOutputMap, "undefined2") + expectedUndefAryStr := expectedOutputMap["undefinedary"] + delete(expectedOutputMap, "undefinedary") + actualUndef2 := inputMap["undefined2"] + delete(inputMap, "undefined2") + actualUndefAryStr := inputMap["undefinedary"] + delete(inputMap, "undefinedary") + t.Logf("expected undef2 [%s] undefary [%s] actual undef2 [%s] undefary [%s]", expectedUndef2, expectedUndefAryStr, actualUndef2, actualUndefAryStr) + + if !reflect.DeepEqual(expectedOutputMap, inputMap) { + t.Errorf("expected [%s] does not match actual [%s]", expectedOutputString, outputBytes) + } + + expectedUndef2Map := make(map[string]interface{}) + if err = json.Unmarshal([]byte(expectedUndef2.(string)), &expectedUndef2Map); err != nil { + t.Errorf("Could not convert expectedUndef2 [%s] to map: %v", expectedUndef2, err) + } + actualUndef2Map := make(map[string]interface{}) + if err = json.Unmarshal([]byte(actualUndef2.(string)), &actualUndef2Map); err != nil { + t.Errorf("Could not convert actualUndef2 [%s] to map: %v", actualUndef2, err) + } + if !reflect.DeepEqual(expectedUndef2Map, actualUndef2Map) { + t.Errorf("field undefined2 expected [%s] does not match actual [%s]", expectedUndef2, actualUndef2) + } + + var expectedUndefAry []interface{} + if err = json.Unmarshal([]byte(expectedUndefAryStr.(string)), &expectedUndefAry); err != nil { + t.Errorf("Could not convert expectedUndefAryStr [%s] to array: %v", expectedUndefAryStr, err) + } + var actualUndefAry []interface{} + if err = json.Unmarshal([]byte(actualUndefAryStr.(string)), &actualUndefAry); err != nil { + t.Errorf("Could not convert actualUndefAryStr [%s] to array: %v", actualUndefAryStr, err) + } + if !reflect.DeepEqual(expectedUndefAry, actualUndefAry) { + t.Errorf("field undefinedary expected [%s] does not match actual [%s]", expectedUndefAryStr, actualUndefAryStr) + } + +}