search

nautobot / nautobot-app-version-control

Version Control App that uses and requires a Dolt Database
Other
30 stars 6 forks source link

Webhooks don't fire in dev container environment #128

Closed tim-fiola closed 2 years ago

tim-fiola commented 2 years ago

I configured the following webhook in the container environment described in the README.md file:

Screen Shot 2021-10-26 at 4 38 42 PM

This webhook should fire when a device object is created/updated/deleted. However, nothing fired when I made a change in the version control app container environment: (running invoke debug)

nautobot_1  | [26/Oct/2021 22:21:25] "GET /dcim/devices/4eeb2dea-6cd0-4493-8173-f894c4ef5168/edit/ HTTP/1.1" 200 217648
dolt_1      | 2021-10-26T22:21:25Z INFO [conn 23] ConnectionClosed {}
dolt_1      | 2021-10-26T22:21:25Z INFO [conn 22] ConnectionClosed {}
nautobot_1  | [26/Oct/2021 22:21:29] "GET /health/ HTTP/1.1" 201 0
nautobot_1  | [26/Oct/2021 22:21:34] "GET /health/ HTTP/1.1" 201 0
dolt_1      | 2021-10-26T22:21:36Z INFO [conn 24] NewConnection {}
dolt_1      | 2021-10-26T22:21:36Z INFO [conn 25] NewConnection {}
nautobot_1  | [26/Oct/2021 22:21:40] "POST /dcim/devices/4eeb2dea-6cd0-4493-8173-f894c4ef5168/edit/ HTTP/1.1" 302 0
dolt_1      | 2021-10-26T22:21:40Z INFO [conn 25] ConnectionClosed {}
dolt_1      | 2021-10-26T22:21:40Z INFO [conn 24] ConnectionClosed {}
dolt_1      | 2021-10-26T22:21:40Z INFO [conn 26] NewConnection {}
nautobot_1  | [26/Oct/2021 22:21:40] "GET /health/ HTTP/1.1" 201 0
dolt_1      | 2021-10-26T22:21:40Z INFO [conn 27] NewConnection {}
nautobot_1  | [26/Oct/2021 22:21:42] "GET /dcim/devices/4eeb2dea-6cd0-4493-8173-f894c4ef5168/ HTTP/1.1" 200 217815
dolt_1      | 2021-10-26T22:21:42Z INFO [conn 27] ConnectionClosed {}
dolt_1      | 2021-10-26T22:21:42Z INFO [conn 26] ConnectionClosed {}
nautobot_1  | [26/Oct/2021 22:21:45] "GET /health/ HTTP/1.1" 201 0
nautobot_1  | [26/Oct/2021 22:21:50] "GET /health/ HTTP/1.1" 201 0

When I configure the same webhook in the Nautobot dev container environment, the webhook fires and I see this info in the log: (running invoke debug)


nautobot_1       | 20:57:52.632 INFO    django.server :
nautobot_1       |   "GET /dcim/devices/de85a2b0-3f16-4655-812d-4b28b4b51ff8/edit/ HTTP/1.1" 200 214873
nautobot_1       | 20:57:57.306 INFO    django.server :
nautobot_1       |   "GET /health/ HTTP/1.1" 200 11758
nautobot_1       | 20:57:59.690 DEBUG   nautobot.views.ObjectEditView generic.py                                post() :
nautobot_1       |   Form validation was successful
celery_worker_1  | [2021-10-26 20:57:59,867: INFO/MainProcess] Task nautobot.extras.tasks.process_webhook[994d202c-171e-421e-8124-7111315a698b] received
nautobot_1       | 20:57:59.905 INFO    nautobot.views.ObjectEditView generic.py                                post() :
nautobot_1       |   Modified device nyc-spine-02.infra.ntc.com (PK: de85a2b0-3f16-4655-812d-4b28b4b51ff8)
celery_worker_1  | 20:57:59.928 INFO    nautobot.extras.tasks tasks.py                       process_webhook() :
celery_worker_1  |   Sending POST request to https://hooks.slack.com/services/<redacted url> (device updated)
celery_worker_1  | [2021-10-26 20:57:59,928: INFO/ForkPoolWorker-6] Sending POST request to https://hooks.slack.com/services/<redacted url> (device updated)
celery_worker_1  | 20:57:59.930 DEBUG   nautobot.extras.tasks tasks.py                       process_webhook() :
celery_worker_1  |   {'method': 'POST', 'url': 'https://hooks.slack.com/services/<redacted url>', 'headers': {'Content-Type': 'application/json'}, 'data': b'{"text":"tim updated {&#39;id&#39;: &#39;de85a2b0-3f16-4655-812d-4b28b4b51ff8&#39;, &#39;url&#39;: &#39;/api/dcim/devices/de85a2b0-3f16-4655-812d-4b28b4b51ff8/&#39;, &#39;name&#39;: &#39;nyc-spine-02.infra.ntc.com&#39;, &#39;device_type&#39;: {&#39;id&#39;: &#39;3f44ae69-9bdd-4b7d-beea-d38af56fffa5&#39;, &#39;url&#39;: &#39;/api/dcim/device-types/3f44ae69-9bdd-4b7d-beea-d38af56fffa5/&#39;, &#39;manufacturer&#39;: {&#39;id&#39;: &#39;e83e2d58-73e2-468b-8a86-0530dbf3dff9&#39;, &#39;url&#39;: &#39;/api/dcim/manufacturers/e83e2d58-73e2-468b-8a86-0530dbf3dff9/&#39;, &#39;name&#39;: &#39;Arista&#39;, &#39;slug&#39;: &#39;arista&#39;, &#39;display&#39;: &#39;Arista&#39;}, &#39;model&#39;: &#39;vEOS&#39;, &#39;slug&#39;: &#39;veos&#39;, &#39;display&#39;: &#39;Arista vEOS&#39;}, &#39;device_role&#39;: {&#39;id&#39;: &#39;5293eb42-255d-4f0a-871d-280677e97636&#39;, &#39;url&#39;: &#39;/api/dcim/device-roles/5293eb42-255d-4f0a-871d-280677e97636/&#39;, &#39;name&#39;: &#39;spine&#39;, &#39;slug&#39;: &#39;spine&#39;, &#39;display&#39;: &#39;spine&#39;}, &#39;tenant&#39;: None, &#39;platform&#39;: {&#39;id&#39;: &#39;a3eb3305-7c3a-4922-8a01-cb4840b2b688&#39;, &#39;url&#39;: &#39;/api/dcim/platforms/a3eb3305-7c3a-4922-8a01-cb4840b2b688/&#39;, &#39;name&#39;: &#39;Arista EOS&#39;, &#39;slug&#39;: &#39;arista_eos&#39;, &#39;display&#39;: &#39;Arista EOS&#39;}, &#39;serial&#39;: &#39;&#39;, &#39;asset_tag&#39;: None, &#39;site&#39;: {&#39;id&#39;: &#39;e4818386-4e53-4ce5-acd5-e40e7308ba24&#39;, &#39;url&#39;: &#39;/api/dcim/sites/e4818386-4e53-4ce5-acd5-e40e7308ba24/&#39;, &#39;name&#39;: &#39;New York City&#39;, &#39;slug&#39;: &#39;nyc&#39;, &#39;display&#39;: &#39;New York City&#39;}, &#39;rack&#39;: None, &#39;position&#39;: None, &#39;face&#39;: None, &#39;parent_device&#39;: None, &#39;status&#39;: {&#39;value&#39;: &#39;active&#39;, &#39;label&#39;: &#39;Active&#39;}, &#39;primary_ip&#39;: None, &#39;primary_ip4&#39;: None, &#39;primary_ip6&#39;: None, &#39;cluster&#39;: None, &#39;virtual_chassis&#39;: None, &#39;vc_position&#39;: None, &#39;vc_priority&#39;: None, &#39;comments&#39;: &#39;test webhook&#39;, &#39;local_context_schema&#39;: None, &#39;local_context_data&#39;: None, &#39;tags&#39;: [], &#39;custom_fields&#39;: {}, &#39;created&#39;: &#39;2021-07-26&#39;, &#39;last_updated&#39;: &#39;2021-10-26T20:57:59.693337Z&#39;, &#39;display&#39;: &#39;nyc-spine-02.infra.ntc.com&#39;}"}'}
celery_worker_1  | [2021-10-26 20:57:59,930: DEBUG/ForkPoolWorker-6] {'method': 'POST', 'url': 'https://hooks.slack.com/services/<redacted url>', 'headers': {'Content-Type': 'application/json'}, 'data': b'{"text":"tim updated {&#39;id&#39;: &#39;de85a2b0-3f16-4655-812d-4b28b4b51ff8&#39;, &#39;url&#39;: &#39;/api/dcim/devices/de85a2b0-3f16-4655-812d-4b28b4b51ff8/&#39;, &#39;name&#39;: &#39;nyc-spine-02.infra.ntc.com&#39;, &#39;device_type&#39;: {&#39;id&#39;: &#39;3f44ae69-9bdd-4b7d-beea-d38af56fffa5&#39;, &#39;url&#39;: &#39;/api/dcim/device-types/3f44ae69-9bdd-4b7d-beea-d38af56fffa5/&#39;, &#39;manufacturer&#39;: {&#39;id&#39;: &#39;e83e2d58-73e2-468b-8a86-0530dbf3dff9&#39;, &#39;url&#39;: &#39;/api/dcim/manufacturers/e83e2d58-73e2-468b-8a86-0530dbf3dff9/&#39;, &#39;name&#39;: &#39;Arista&#39;, &#39;slug&#39;: &#39;arista&#39;, &#39;display&#39;: &#39;Arista&#39;}, &#39;model&#39;: &#39;vEOS&#39;, &#39;slug&#39;: &#39;veos&#39;, &#39;display&#39;: &#39;Arista vEOS&#39;}, &#39;device_role&#39;: {&#39;id&#39;: &#39;5293eb42-255d-4f0a-871d-280677e97636&#39;, &#39;url&#39;: &#39;/api/dcim/device-roles/5293eb42-255d-4f0a-871d-280677e97636/&#39;, &#39;name&#39;: &#39;spine&#39;, &#39;slug&#39;: &#39;spine&#39;, &#39;display&#39;: &#39;spine&#39;}, &#39;tenant&#39;: None, &#39;platform&#39;: {&#39;id&#39;: &#39;a3eb3305-7c3a-4922-8a01-cb4840b2b688&#39;, &#39;url&#39;: &#39;/api/dcim/platforms/a3eb3305-7c3a-4922-8a01-cb4840b2b688/&#39;, &#39;name&#39;: &#39;Arista EOS&#39;, &#39;slug&#39;: &#39;arista_eos&#39;, &#39;display&#39;: &#39;Arista EOS&#39;}, &#39;serial&#39;: &#39;&#39;, &#39;asset_tag&#39;: None, &#39;site&#39;: {&#39;id&#39;: &#39;e4818386-4e53-4ce5-acd5-e40e7308ba24&#39;, &#39;url&#39;: &#39;/api/dcim/sites/e4818386-4e53-4ce5-acd5-e40e7308ba24/&#39;, &#39;name&#39;: &#39;New York City&#39;, &#39;slug&#39;: &#39;nyc&#39;, &#39;display&#39;: &#39;New York City&#39;}, &#39;rack&#39;: None, &#39;position&#39;: None, &#39;face&#39;: None, &#39;parent_device&#39;: None, &#39;status&#39;: {&#39;value&#39;: &#39;active&#39;, &#39;label&#39;: &#39;Active&#39;}, &#39;primary_ip&#39;: None, &#39;primary_ip4&#39;: None, &#39;primary_ip6&#39;: None, &#39;cluster&#39;: None, &#39;virtual_chassis&#39;: None, &#39;vc_position&#39;: None, &#39;vc_priority&#39;: None, &#39;comments&#39;: &#39;test webhook&#39;, &#39;local_context_schema&#39;: None, &#39;local_context_data&#39;: None, &#39;tags&#39;: [], &#39;custom_fields&#39;: {}, &#39;created&#39;: &#39;2021-07-26&#39;, &#39;last_updated&#39;: &#39;2021-10-26T20:57:59.693337Z&#39;, &#39;display&#39;: &#39;nyc-spine-02.infra.ntc.com&#39;}"}'}
celery_worker_1  | 20:58:00.252 INFO    nautobot.extras.tasks tasks.py                       process_webhook() :
celery_worker_1  |   Request succeeded; response status 200
celery_worker_1  | [2021-10-26 20:58:00,252: INFO/ForkPoolWorker-6] Request succeeded; response status 200
celery_worker_1  | [2021-10-26 20:58:00,256: INFO/ForkPoolWorker-6] Task nautobot.extras.tasks.process_webhook[994d202c-171e-421e-8124-7111315a698b] succeeded in 0.3837292999960482s: 'Status 200 returned, webhook successfully processed.'
nautobot_1       | 20:58:00.759 INFO    django.server :
nautobot_1       |   "POST /dcim/devices/de85a2b0-3f16-4655-812d-4b28b4b51ff8/edit/ HTTP/1.1" 302 0
nautobot_1       | 20:58:01.296 INFO    django.server :
nautobot_1       |   "GET /dcim/devices/de85a2b0-3f16-4655-812d-4b28b4b51ff8/ HTTP/1.1" 200 216097
tim-fiola commented 2 years ago

I am seeing this when I start the containers via invoke debug: dolt_worker_1 exited with code 2:

Starting Nautobot in debug mode...
Running docker-compose command "up"
Starting dolt_redis_1 ... 
Starting dolt_dolt_1  ... 
Starting dolt_redis_1 ... done
Starting dolt_dolt_1  ... done
Starting dolt_nautobot_1 ... 
Starting dolt_nautobot_1 ... done
Starting dolt_worker_1   ... 
Starting dolt_worker_1   ... done
Attaching to dolt_redis_1, dolt_dolt_1, dolt_nautobot_1, dolt_worker_1
dolt_1      | Starting server with Config HP="0.0.0.0:3306"|U="nautobot"|P="notverysecurepwd"|T="28800000"|R="false"|L="info"
redis_1     | 1:C 01 Nov 2021 22:10:46.335 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis_1     | 1:C 01 Nov 2021 22:10:46.335 # Redis version=6.2.2, bits=64, commit=00000000, modified=0, pid=1, just started
redis_1     | 1:C 01 Nov 2021 22:10:46.335 # Configuration loaded
redis_1     | 1:M 01 Nov 2021 22:10:46.336 * monotonic clock: POSIX clock_gettime
redis_1     | 1:M 01 Nov 2021 22:10:46.337 * Running mode=standalone, port=6379.
redis_1     | 1:M 01 Nov 2021 22:10:46.337 # Server initialized
redis_1     | 1:M 01 Nov 2021 22:10:46.338 * DB loaded from append only file: 0.001 seconds
redis_1     | 1:M 01 Nov 2021 22:10:46.338 * Ready to accept connections
dolt_1      | 2021-11-01T22:10:49Z INFO [conn 2] NewConnection {}
dolt_1      | 2021-11-01T22:10:49Z INFO [conn 1] NewConnection {}
worker_1    | Error: -l option requires an argument
dolt_1      | 2021-11-01T22:10:49Z INFO [conn 1] ConnectionClosed {}
dolt_worker_1 exited with code 2
nautobot_1  | Performing database migrations...
dolt_1      | 2021-11-01T22:10:50Z INFO [conn 3] NewConnection {}
nautobot_1  | Operations to perform:
nautobot_1  |   Apply all migrations: admin, auth, circuits, contenttypes, dcim, dolt, extras, ipam, sessions, social_django,
glennmatthews commented 2 years ago

worker_1 | Error: -l option requires an argument

Looks like the worker is being started up with the wrong (incomplete?) command. Looking at #130, do you have NAUTOBOT_LOG_LEVEL defined in your creds.env file?