Merge branch 'develop' into 651-job-api-validation

* develop: (32 commits) Add object variable lookup (nautobot#837) Add release-note for nautobot#718 Fix nautobot#718: Computed field template overflow (nautobot#831) Add release-notes for nautobot#825 and nautobot#832 remove celery worker -B option (nautobot#827) Update Using Plugins guide to have Post Upgrade run. (nautobot#833) Add release-notes for nautobot#715 and nautobot#812 GraphQL navbar overflowing into Graphiql (nautobot#812) Add release-notes for nautobot#464, nautobot#731, nautobot#818 Adding Logic for read-only hdb health check (nautobot#819) Fix nautobot#731 - enforce 'format' in config context schemas (nautobot#822) Fix GraphQL filterset handling of custom fields (nautobot#821) Add release-notes for nautobot#779, nautobot#791, nautobot#809 Change the docker-compose file version to support start_period property (nautobot#810) Adding docs and logic to skip initialization in docker (nautobot#793) Fix incorrect tenancy display in related prefixes table (nautobot#806) Bump version to 1.1.3-beta.1 Bump version and add release date Add release-notes for nautobot#785 and nautobot#786 Prioritize LoganImporter over built-in importers. See nautobot#785 (nautobot#788) ...
hellerve · Aug 23, 2021 · 384ccaa · 384ccaa
2 parents f0ee8d7 + ba9261f
commit 384ccaa
Show file tree

Hide file tree

Showing 66 changed files with 1,021 additions and 214 deletions.
diff --git a/development/docker-compose.build.yml b/development/docker-compose.build.yml
@@ -1,6 +1,6 @@
 # Used to run the final container images vs the dev containers
 ---
-version: "3"
+version: "3.4"
 services:
   nautobot:
     build:
@@ -10,3 +10,5 @@ services:
       - 8443:8443
   worker:
     image: "networktocode/nautobot-py${PYTHON_VER}:local"
+  celery_worker:
+    image: "networktocode/nautobot-py${PYTHON_VER}:local"
diff --git a/development/docker-compose.debug.yml b/development/docker-compose.debug.yml
@@ -1,6 +1,6 @@
 # Used to integrate with Microsoft VS Code dev containers feature.
 ---
-version: "3"
+version: "3.4"
 services:
   nautobot:
     command: "sleep infinity"

diff --git a/development/docker-compose.dev.yml b/development/docker-compose.dev.yml
@@ -3,7 +3,7 @@
 # any override will need to include these volumes to use them.
 # see:  https://github.com/docker/compose/issues/3729
 ---
-version: "3"
+version: "3.4"
 services:
   nautobot:
     volumes:

diff --git a/development/docker-compose.yml b/development/docker-compose.yml
@@ -1,5 +1,5 @@
 ---
-version: "3"
+version: "3.4"
 services:
   nautobot:
     build:
@@ -34,7 +34,7 @@ services:
     tty: true
   celery_worker:
     image: "networktocode/nautobot-dev-py${PYTHON_VER}:local"
-    entrypoint: "nautobot-server celery worker -B -l INFO"
+    entrypoint: "nautobot-server celery worker -l INFO"
     healthcheck:
       interval: 5s
       timeout: 5s

diff --git a/development/nautobot_config.py b/development/nautobot_config.py
@@ -34,7 +34,7 @@
 # Debug
 #
 
-DEBUG = True
+DEBUG = is_truthy(os.getenv("NAUTOBOT_DEBUG", True))
 
 # Django Debug Toolbar
 DEBUG_TOOLBAR_CONFIG = {"SHOW_TOOLBAR_CALLBACK": lambda _request: DEBUG and not TESTING}
@@ -70,12 +70,12 @@
         "handlers": {
             "normal_console": {
                 "level": "INFO",
-                "class": "rq.utils.ColorizingStreamHandler",
+                "class": "logging.StreamHandler",
                 "formatter": "normal",
             },
             "verbose_console": {
                 "level": "DEBUG",
-                "class": "rq.utils.ColorizingStreamHandler",
+                "class": "logging.StreamHandler",
                 "formatter": "verbose",
             },
         },

diff --git a/docker/docker-entrypoint.sh b/docker/docker-entrypoint.sh
@@ -8,14 +8,17 @@ set -e
 DB_WAIT_TIMEOUT=${DB_WAIT_TIMEOUT-3}
 MAX_DB_WAIT_TIME=${MAX_DB_WAIT_TIME-30}
 CUR_DB_WAIT_TIME=0
-while ! nautobot-server post_upgrade --no-invalidate-all 2>&1 && [ "${CUR_DB_WAIT_TIME}" -lt "${MAX_DB_WAIT_TIME}" ]; do
-  echo "⏳ Waiting on DB... (${CUR_DB_WAIT_TIME}s / ${MAX_DB_WAIT_TIME}s)"
-  sleep "${DB_WAIT_TIMEOUT}"
-  CUR_DB_WAIT_TIME=$(( CUR_DB_WAIT_TIME + DB_WAIT_TIMEOUT ))
-done
-if [ "${CUR_DB_WAIT_TIME}" -ge "${MAX_DB_WAIT_TIME}" ]; then
-  echo "❌ Waited ${MAX_DB_WAIT_TIME}s or more for the DB to become ready."
-  exit 1
+NAUTOBOT_DOCKER_SKIP_INIT=${NAUTOBOT_DOCKER_SKIP_INIT-false}
+if [ "$NAUTOBOT_DOCKER_SKIP_INIT" == "false" ]; then
+  while ! nautobot-server post_upgrade --no-invalidate-all 2>&1 && [ "${CUR_DB_WAIT_TIME}" -lt "${MAX_DB_WAIT_TIME}" ]; do
+    echo "⏳ Waiting on DB... (${CUR_DB_WAIT_TIME}s / ${MAX_DB_WAIT_TIME}s)"
+    sleep "${DB_WAIT_TIMEOUT}"
+    CUR_DB_WAIT_TIME=$(( CUR_DB_WAIT_TIME + DB_WAIT_TIMEOUT ))
+  done
+  if [ "${CUR_DB_WAIT_TIME}" -ge "${MAX_DB_WAIT_TIME}" ]; then
+    echo "❌ Waited ${MAX_DB_WAIT_TIME}s or more for the DB to become ready."
+    exit 1
+  fi
 fi
 
 # Run a quick healthcheck and bail if something fails, --deploy will warn on potential issues for production

diff --git a/docker/nautobot_config.append.py b/docker/nautobot_config.append.py
@@ -15,7 +15,7 @@
     "handlers": {
         "normal_console": {
             "level": "DEBUG",
-            "class": "rq.utils.ColorizingStreamHandler",
+            "class": "logging.StreamHandler",
             "formatter": "normal",
         },
     },

diff --git a/examples/logging/README.md b/examples/logging/README.md
@@ -0,0 +1 @@
+This folder contains some examples of how logging can be configured.
diff --git a/examples/logging/advanced_requests.md b/examples/logging/advanced_requests.md
@@ -0,0 +1,73 @@
+By default django logs [4xx and 5xx requests](https://docs.djangoproject.com/en/3.2/topics/logging/#django-request) 
+but is missing details such as the request user name.  This can be helpful in debugging. This example 
+shows how the request user can be added to the logs.
+
+```python
+def add_username(record):
+    record.username = record.request.user.username
+    return True
+
+
+LOG_LEVEL = "DEBUG" if DEBUG else "INFO"
+LOGGING = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "normal": {
+            "format": "%(asctime)s.%(msecs)03d %(levelname)-7s %(name)s: %(message)s",
+            "datefmt": "%H:%M:%S",
+        },
+        "request": {
+            "format": "%(asctime)s.%(msecs)03d %(levelname)-7s %(name)s: user=%(username)s %(message)s",
+            "datefmt": "%H:%M:%S",
+        },
+    },
+    "handlers": {
+        "normal_console": {
+            "level": "DEBUG",
+            "class": "logging.StreamHandler",
+            "formatter": "normal",
+        },
+        "requests": {
+            "level": "DEBUG",
+            "class": "logging.StreamHandler",
+            "formatter": "request",
+            "filters": ["add_username"],
+        },
+    },
+    "filters": {
+        "add_username": {
+            "()": "django.utils.log.CallbackFilter",
+            "callback": add_username,
+        }
+    },
+    "loggers": {
+        "django.request": {
+            "handlers": ["requests"],
+            "level": LOG_LEVEL,
+            "propagate": False,
+        },
+        "django": {
+            "handlers": ["normal_console"],
+            "level": "INFO"
+        },
+        "nautobot": {
+            "handlers": ["normal_console"],
+            "level": LOG_LEVEL,
+        },
+    },
+}
+```
+
+## Example Logs
+
+```no-highlight
+20:50:57.972 INFO    django.server:  "GET /health/ HTTP/1.1" 200 11743
+20:50:58.769 INFO    django.server:  "GET /login/?next=/ HTTP/1.1" 200 18336
+20:51:04.710 INFO    django.server:  "GET /health/ HTTP/1.1" 200 11741
+20:51:05.836 INFO    nautobot.auth.login:  User admin successfully authenticated
+20:51:07.340 INFO    django.server:  "POST /login/ HTTP/1.1" 302 0
+20:51:10.182 INFO    django.server:  "GET / HTTP/1.1" 200 118573
+21:02:25.928 WARNING django.request: user=admin Not Found: /api/ipam/ip-addresses/63b38cc7-979d-52c4-b26f-e44dd5f390ca/
+21:02:25.945 WARNING django.server: "GET /api/ipam/ip-addresses/63b38cc7-979d-52c4-b26f-e44dd5f390ca/ HTTP/1.1" 404 15611
+```
diff --git a/examples/logging/all_logs.md b/examples/logging/all_logs.md
@@ -0,0 +1,54 @@
+This example captures all logs sent to the python logger.  This is helpful if you don't know the logger name
+for the loggers config or if you simply want to make sure you collect ALL logs.  But be warned, ALL logs might
+be a lot of logs:
+
+```python
+LOG_LEVEL = "DEBUG" if DEBUG else "INFO"
+LOGGING = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "normal": {
+            "format": "%(asctime)s.%(msecs)03d %(levelname)-7s %(name)s:  %(message)s",
+            "datefmt": "%H:%M:%S",
+        },
+    },
+    "handlers": {
+        "normal_console": {
+            "level": "DEBUG",
+            "class": "logging.StreamHandler",
+            "formatter": "normal",
+        },
+    },
+    "loggers": {
+        "django": {
+            "handlers": ["normal_console"],
+            "level": "INFO"
+        },
+        "nautobot": {
+            "handlers": ["normal_console"],
+            "level": LOG_LEVEL,
+        },
+    },
+    "root": {
+        "handlers": "normal_console",
+        "level": LOG_LEVEL,
+    },
+}
+```
+
+The important addition is the `LOGGING["root"]` entry here.  You can skip the `LOGGING["loggers"]` section
+entirely if you wish.
+
+## Example Logs
+
+```no-highlight
+20:38:28.967 INFO    django.server: "GET / HTTP/1.1" 200 29409
+20:38:29.174 INFO    django.server: "GET /static/debug_toolbar/js/toolbar.js HTTP/1.1" 304 0
+20:38:29.194 INFO    django.server: "GET /static/debug_toolbar/css/toolbar.css HTTP/1.1" 304 0
+20:38:29.677 INFO    django.server: "GET /static/debug_toolbar/css/print.css HTTP/1.1" 304 0
+20:38:29.775 INFO    django.server: "GET /static/debug_toolbar/js/utils.js HTTP/1.1" 304 0
+20:38:33.433 INFO    django.server: "GET /login/?next=/ HTTP/1.1" 200 18335
+20:38:41.121 INFO    nautobot.auth.login: User admin successfully authenticated
+20:38:42.053 INFO    django.server: "POST /login/ HTTP/1.1" 302 0
+```
diff --git a/examples/logging/basic_file.md b/examples/logging/basic_file.md
@@ -0,0 +1,54 @@
+This example sends logging to files in `/var/log/nautobot`, please note this directory should exist and 
+be writeable by the nautobot user.  Files are rotated daily for 5 days at midnight UTC.
+
+```python
+LOG_DIR = "/var/log/nautobot"
+LOG_LEVEL = "DEBUG" if DEBUG else "INFO"
+LOGGING = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "normal": {
+            "format": "%(asctime)s.%(msecs)03d %(levelname)-7s %(name)s:  %(message)s",
+            "datefmt": "%H:%M:%S",
+        },
+    },
+    "handlers": {
+        "nautobot_log": {
+            "level": "DEBUG",
+            "class": "logging.handlers.TimedRotatingFileHandler",
+            "filename": f"{LOG_DIR}/nautobot.log",
+            "when": "midnight",
+            "utc": True,
+            "interval": 1,
+            "backupCount": 5,
+            "formatter": "normal",
+        },
+    },
+    "loggers": {
+        "django": {
+            "handlers": ["normal_console"],
+            "level": "INFO"
+        },
+        "nautobot": {
+            "handlers": ["normal_console"],
+            "level": LOG_LEVEL,
+        },
+    },
+}
+```
+
+## Example Logs
+
+```no-highlight
+20:38:28.967 INFO    django.server: "GET / HTTP/1.1" 200 29409
+20:38:29.174 INFO    django.server: "GET /static/debug_toolbar/js/toolbar.js HTTP/1.1" 304 0
+20:38:29.194 INFO    django.server: "GET /static/debug_toolbar/css/toolbar.css HTTP/1.1" 304 0
+20:38:29.677 INFO    django.server: "GET /static/debug_toolbar/css/print.css HTTP/1.1" 304 0
+20:38:29.775 INFO    django.server: "GET /static/debug_toolbar/js/utils.js HTTP/1.1" 304 0
+20:38:33.433 INFO    django.server: "GET /login/?next=/ HTTP/1.1" 200 18335
+20:38:40.878 DEBUG   nautobot.auth.login: Login form validation was successful
+20:38:41.121 INFO    nautobot.auth.login: User admin successfully authenticated
+20:38:41.121 DEBUG   nautobot.auth.login: Redirecting user to /
+20:38:42.053 INFO    django.server: "POST /login/ HTTP/1.1" 302 0
+```
diff --git a/examples/logging/basic_stdout.md b/examples/logging/basic_stdout.md
@@ -0,0 +1,47 @@
+This example provides adequate logging for basic deployments where the logs to stdout are captured by
+some external process such as Docker or Kubernetes:
+
+```python
+LOG_LEVEL = "DEBUG" if DEBUG else "INFO"
+LOGGING = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "normal": {
+            "format": "%(asctime)s.%(msecs)03d %(levelname)-7s %(name)s: %(message)s",
+            "datefmt": "%H:%M:%S",
+        },
+    },
+    "handlers": {
+        "normal_console": {
+            "level": "DEBUG",
+            "class": "logging.StreamHandler",
+            "formatter": "normal",
+        },
+    },
+    "loggers": {
+        "django": {
+            "handlers": ["normal_console"],
+            "level": "INFO"
+        },
+        "nautobot": {
+            "handlers": ["normal_console"],
+            "level": LOG_LEVEL,
+        },
+    },
+}
+```
+## Example Logs
+
+```no-highlight
+20:38:28.967 INFO    django.server: "GET / HTTP/1.1" 200 29409
+20:38:29.174 INFO    django.server: "GET /static/debug_toolbar/js/toolbar.js HTTP/1.1" 304 0
+20:38:29.194 INFO    django.server: "GET /static/debug_toolbar/css/toolbar.css HTTP/1.1" 304 0
+20:38:29.677 INFO    django.server: "GET /static/debug_toolbar/css/print.css HTTP/1.1" 304 0
+20:38:29.775 INFO    django.server: "GET /static/debug_toolbar/js/utils.js HTTP/1.1" 304 0
+20:38:33.433 INFO    django.server: "GET /login/?next=/ HTTP/1.1" 200 18335
+20:38:40.878 DEBUG   nautobot.auth.login: Login form validation was successful
+20:38:41.121 INFO    nautobot.auth.login: User admin successfully authenticated
+20:38:41.121 DEBUG   nautobot.auth.login: Redirecting user to /
+20:38:42.053 INFO    django.server: "POST /login/ HTTP/1.1" 302 0
+```