Comment 2 for bug 2008693

Revision history for this message
Đỗ Hoàng Sơn (dosonnd) wrote :

Here is the log of the designate-worker when the zone creation failed in non-default pool:
2023-02-28 01:40:39.530 17 INFO designate.worker.service [req-ffedfb33-9c8f-4525-bde5-4b5a044b85d3 ea5b595b241d45f785083490ef251d79 b15e413b73034d8b9527aecd0d7e9ec1 - - -] Lazily loading pool 48f7da36-223a-48d0-bb66-58280bab84c3
2023-02-28 01:40:39.590 17 DEBUG designate.plugin [req-25e0de66-6340-4c92-87ae-48d20c0f025e - - - - -] Looking for driver bind9 in designate.backend get_driver /var/lib/kolla/venv/lib/python3.8/site-packages/designate/plugin.py:67
2023-02-28 01:40:39.591 17 INFO designate.backend [req-25e0de66-6340-4c92-87ae-48d20c0f025e - - - - -] Backend Driver 'bind9' loaded. Has status of 'integrated'
2023-02-28 01:40:39.592 17 DEBUG designate.plugin [req-25e0de66-6340-4c92-87ae-48d20c0f025e - - - - -] Loaded plugin backend:bind9 __init__ /var/lib/kolla/venv/lib/python3.8/site-packages/designate/plugin.py:35
2023-02-28 01:40:39.597 17 INFO designate.worker.service [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] 1 targets setup
2023-02-28 01:40:39.599 17 INFO designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Attempting CREATE on zone sondh250.com.
2023-02-28 01:40:39.600 17 DEBUG designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Attempting CREATE zone sondh250.com. on <PoolTarget id:'954801e9-cef1-4b8b-93e7-9046e9b62dbd' type:'bind9' pool_id:'48f7da36-223a-48d0-bb66-58280bab84c3'> __call__ /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/tasks/zone.py:69
2023-02-28 01:40:39.601 17 DEBUG designate.backend.impl_bind9 [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Create Zone create_zone /var/lib/kolla/venv/lib/python3.8/site-packages/designate/backend/impl_bind9.py:80
2023-02-28 01:40:39.602 17 DEBUG designate.backend.impl_bind9 [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Executing RNDC call: ['rndc', '-s', '10.240.234.112', '-p', '953', '-k', '/etc/designate/rndc.key', 'addzone', 'sondh250.com { type slave; masters { 10.240.234.110 port 5354;}; file "slave.sondh250.com.af66b10e-bb30-4c9b-9f32-ef8ead13e969"; };'] with timeout None _execute_rndc /var/lib/kolla/venv/lib/python3.8/site-packages/designate/backend/impl_bind9.py:210
2023-02-28 01:40:39.602 17 DEBUG oslo_concurrency.processutils [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Running cmd (subprocess): sudo designate-rootwrap /etc/designate/rootwrap.conf rndc -s 10.240.234.112 -p 953 -k /etc/designate/rndc.key addzone sondh250.com { type slave; masters { 10.240.234.110 port 5354;}; file "slave.sondh250.com.af66b10e-bb30-4c9b-9f32-ef8ead13e969"; }; execute /var/lib/kolla/venv/lib/python3.8/site-packages/oslo_concurrency/processutils.py:384
2023-02-28 01:40:40.578 17 DEBUG oslo_concurrency.processutils [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] CMD "sudo designate-rootwrap /etc/designate/rootwrap.conf rndc -s 10.240.234.112 -p 953 -k /etc/designate/rndc.key addzone sondh250.com { type slave; masters { 10.240.234.110 port 5354;}; file "slave.sondh250.com.af66b10e-bb30-4c9b-9f32-ef8ead13e969"; };" returned: 0 in 0.975s execute /var/lib/kolla/venv/lib/python3.8/site-packages/oslo_concurrency/processutils.py:422
2023-02-28 01:40:40.580 17 DEBUG designate.mdns.rpcapi [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Letting worker send NOTIFYs instead notify_zone_changed /var/lib/kolla/venv/lib/python3.8/site-packages/designate/mdns/rpcapi.py:83
2023-02-28 01:40:40.585 17 DEBUG designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Sent NOTIFY to 10.240.234.112:53 for zone sondh250.com. __call__ /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/tasks/zone.py:132
2023-02-28 01:40:40.586 17 DEBUG designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Successful CREATE zone sondh250.com. on <PoolTarget id:'954801e9-cef1-4b8b-93e7-9046e9b62dbd' type:'bind9' pool_id:'48f7da36-223a-48d0-bb66-58280bab84c3'> __call__ /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/tasks/zone.py:87
2023-02-28 01:40:40.588 17 DEBUG designate.worker.processing [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Finished Tasks ['ZoneActionOnTarget-Create'] in 0.988216s run /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/processing.py:86
2023-02-28 01:40:45.590 17 DEBUG designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Polling for zone sondh250.com. serial 1677548439 on <PoolNameserver id:'dbfdd3f2-3388-49a5-8e56-1b35c35e1265' host:'10.240.234.112' port:'53' pool_id:'48f7da36-223a-48d0-bb66-58280bab84c3'> __call__ /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/tasks/zone.py:320
2023-02-28 01:40:45.597 17 DEBUG designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Found serial 0 on 10.240.234.112 for zone sondh250.com. __call__ /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/tasks/zone.py:329
2023-02-28 01:40:45.597 17 DEBUG designate.worker.processing [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Finished Tasks ['PollForZone'] in 0.007955s run /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/processing.py:86
2023-02-28 01:40:45.598 17 DEBUG designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Results for polling sondh250.com.-1677548439: DNSQueryResult(positives=0, no_zones=1, consensus_serial=0, results=[0]) parse_query_results /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/tasks/zone.py:294
2023-02-28 01:40:45.599 17 DEBUG designate.worker.tasks.zone [req-38d1682f-a27a-4a20-87e0-0e0c19273b96 - - - - -] Unsuccessful poll for sondh250.com. on attempt 1 _do_poll /var/lib/kolla/venv/lib/python3.8/site-packages/designate/worker/tasks/zone.py:402

Here is the log of designate-mdns when zone creation failed in non-default pool:
2023-02-28 01:32:58.008 22 DEBUG designate.service [req-28b4e51e-5b1c-49af-9495-7754c43e65cb - - - - -] Handling TCP Request from: 10.240.234.112:40177 _dns_handle_tcp /var/lib/kolla/venv/lib/python3.8/site-packages/designate/service.py:207
2023-02-28 01:32:58.021 22 WARNING designate.mdns.handler [req-50c4631b-84cd-4e52-9faf-9120121dd2e3 - - - - -] ZoneNotFound while handling axfr request. Question was sondh205.com. IN AXFR: designate.exceptions.ZoneNotFound: Could not find Zone
2023-02-28 01:40:40.497 21 DEBUG designate.service [req-77877113-699a-4346-b33b-9b84a29b6dd6 - - - - -] Handling UDP Request from: 10.240.234.112:48957 _dns_handle_udp /var/lib/kolla/venv/lib/python3.8/site-packages/designate/service.py:321
2023-02-28 01:40:40.523 21 WARNING designate.mdns.handler [req-69aa4a51-8757-4789-878d-ef93bf1d7265 - - - - -] ZoneNotFound while handling query request. Question was sondh250.com. IN SOA: designate.exceptions.ZoneNotFound: Could not find Zone
2023-02-28 01:40:40.526 21 DEBUG designate.service [req-69aa4a51-8757-4789-878d-ef93bf1d7265 - - - - -] Handling TCP Request from: 10.240.234.112:43025 _dns_handle_tcp /var/lib/kolla/venv/lib/python3.8/site-packages/designate/service.py:207
2023-02-28 01:40:40.534 21 WARNING designate.mdns.handler [req-1d2c59f6-0d95-4ed6-b0f2-70917b98a5e1 - - - - -] ZoneNotFound while handling axfr request. Question was sondh250.com. IN AXFR: designate.exceptions.ZoneNotFound: Could not find Zone
2023-02-28 01:41:32.499 22 DEBUG designate.service [req-50c4631b-84cd-4e52-9faf-9120121dd2e3 - - - - -] Handling UDP Request from: 10.240.234.112:58002 _dns_handle_udp /var/lib/kolla/venv/lib/python3.8/site-packages/designate/service.py:321
2023-02-28 01:41:32.524 22 WARNING designate.mdns.handler [req-cb71456a-752e-43ed-829a-a97428cf5b42 - - - - -] ZoneNotFound while handling query request. Question was sondh250.com. IN SOA: designate.exceptions.ZoneNotFound: Could not find Zone
2023-02-28 01:41:32.528 20 DEBUG designate.service [req-aea6f16d-8c8f-4295-8fb1-3cac2b9480b0 - - - - -] Handling TCP Request from: 10.240.234.112:48297 _dns_handle_tcp /var/lib/kolla/venv/lib/python3.8/site-packages/designate/service.py:207
2023-02-28 01:41:32.540 20 WARNING designate.mdns.handler [req-7a505d39-2a5d-4844-ae64-0e5813f99b01 - - - - -] ZoneNotFound while handling axfr request. Question was sondh250.com. IN AXFR: designate.exceptions.ZoneNotFound: Could not find Zone

I configured the test-bind-12 pool as the default pool and proceeded to create a zone on the test-bind-11 pool.
- name: test_bind-11
  description: Default DNS Pool
  attributes: {}
  ns_records:
  - hostname: external.vn.
    priority: 1
  nameservers:
  - host: 10.240.234.112
    port: 53
  targets:
  - type: bind9
    description: BIND9 Server master
    masters:
    - host: 10.240.234.110
      port: 5354
    options:
      host: 10.240.234.112
      port: '53'
      rndc_host: 10.240.234.112
      rndc_key_file: /etc/designate/rndc.key
      rndc_port: '953'
- name: test-bind-12
  description: Default BIND9 Pool
  attributes: {}
  ns_records:
  - hostname: external.vn.
    priority: 1
  nameservers:
  - host: 10.240.234.225
    port: 53
  targets:
  - type: bind9
    description: PDNS4 DNS Server
    masters:
    - host: 10.240.234.110
      port: 5354
    options:
      host: 10.240.234.225
      port: '53'
      rndc_host: 10.240.234.225
      rndc_key_file: /etc/designate/rndc.key
      rndc_port: '953'

I'm thinking the problem is that miniDNS is not creating the zone. Do you have any opinion on this matter?