Data race in cache termination goroutine

[natesales]

2021-07-06T04:20:02.1752225Z ##[group]Run go test -race -coverprofile=coverage.txt -covermode=atomic
2021-07-06T04:20:02.1753288Z go test -race -coverprofile=coverage.txt -covermode=atomic
2021-07-06T04:20:02.1795370Z shell: /usr/bin/bash -e {0}
2021-07-06T04:20:02.1795831Z env:
2021-07-06T04:20:02.1796361Z   GOROOT: /opt/hostedtoolcache/go/1.16.5/x64
2021-07-06T04:20:02.1796928Z ##[endgroup]
2021-07-06T04:20:15.1795216Z time="2021-07-06T04:20:15Z" level=info msg="Starting fake BIRD socket server"
2021-07-06T04:20:15.1897457Z time="2021-07-06T04:20:15Z" level=info msg="Connected to BIRD socket"
2021-07-06T04:20:15.1903292Z time="2021-07-06T04:20:15Z" level=info msg="BIRD response (multiline): 0001 Fake BIRD response 2"
2021-07-06T04:20:15.2010111Z ## Config
2021-07-06T04:20:15.2011270Z | Option | Type | Default | Validation | Description |
2021-07-06T04:20:15.2012505Z |--------|------|---------|------------|-------------|
2021-07-06T04:20:15.2013430Z | asn | int | 0 | required | Autonomous System Number |
2021-07-06T04:20:15.2014525Z | prefixes | []string |  |  | List of prefixes to announce |
2021-07-06T04:20:15.2015467Z | communities | []string |  |  | List of RFC1997 BGP communities |
2021-07-06T04:20:15.2016781Z | large-communities | []string |  |  | List of RFC8092 large BGP communities |
2021-07-06T04:20:15.2018345Z | router-id | string |  | required | Router ID (dotted quad notation) |
2021-07-06T04:20:15.2019850Z | irr-server | string | rr.ntt.net |  | Internet routing registry server |
2021-07-06T04:20:15.2021317Z | rtr-server | string | rtr.rpki.cloudflare.com:8282 |  | RPKI-to-router server |
2021-07-06T04:20:15.2022878Z | keep-filtered | bool | false |  | Should filtered routes be kept in memory? |
2021-07-06T04:20:15.2024515Z | kernel-learn | bool | false |  | Inject Kernel routes into BIRD wich have been injected into the kernel from other deamons e.g FRR OSPFd |
2021-07-06T04:20:15.2026896Z | merge-paths | bool | false |  | Should best and equivalent non-best routes be imported to build ECMP routes? |
2021-07-06T04:20:15.2028410Z | source4 | string |  |  | Source IPv4 address |
2021-07-06T04:20:15.2029382Z | source6 | string |  |  | Source IPv6 address |
2021-07-06T04:20:15.2030882Z | default-route | bool | true |  | Add a default route |
2021-07-06T04:20:15.2032192Z | accept-default | bool | false |  | Should default routes be added to the bogon list? |
2021-07-06T04:20:15.2034488Z | kernel-table | int |  |  | Kernel table |
2021-07-06T04:20:15.2035645Z | peers | map[string]Peer |  |  | BGP peer configuration |
2021-07-06T04:20:15.2036652Z | templates | map[string]Peer |  |  | BGP peer templates |
2021-07-06T04:20:15.2037725Z | vrrp | []VRRPInstance |  |  | List of VRRP instances |
2021-07-06T04:20:15.2038788Z | augments | Augments |  |  | Custom configuration options |
2021-07-06T04:20:15.2039821Z | optimizer | Optimizer |  |  | Route optimizer options |
2021-07-06T04:20:15.2040413Z 
2021-07-06T04:20:15.2041218Z ## Peer
2021-07-06T04:20:15.2042149Z | Option | Type | Default | Validation | Description |
2021-07-06T04:20:15.2043801Z |--------|------|---------|------------|-------------|
2021-07-06T04:20:15.2044976Z | template | string |  |  | Configuration template |
2021-07-06T04:20:15.2045933Z | description | string |  |  | Peer description |
2021-07-06T04:20:15.2048018Z | disabled | bool | false |  | Should the sessions be disabled? |
2021-07-06T04:20:15.2048976Z | asn | int | 0 | required | Local ASN |
2021-07-06T04:20:15.2049952Z | neighbors | []string |  | required,ip | List of neighbor IPs |
2021-07-06T04:20:15.2056543Z | prepends | int | 0 |  | Number of times to prepend local AS on export |
2021-07-06T04:20:15.2059501Z | local-pref | int | 100 |  | BGP local preference |
2021-07-06T04:20:15.2060571Z | multihop | bool | false |  | Should BGP multihop be enabled? (255 max hops) |
2021-07-06T04:20:15.2061367Z | listen | string |  |  | BGP listen address |
2021-07-06T04:20:15.2062282Z | local-asn | int |  |  | Local ASN as defined in the global ASN field |
2021-07-06T04:20:15.2063193Z | local-port | int | 179 |  | Local TCP port |
2021-07-06T04:20:15.2064769Z | neighbor-port | int | 179 |  | Neighbor TCP port |
2021-07-06T04:20:15.2065738Z | passive | bool | false |  | Should we listen passively? |
2021-07-06T04:20:15.2067029Z | next-hop-self | bool | false |  | Should BGP next-hop-self be enabled? |
2021-07-06T04:20:15.2067832Z | bfd | bool | false |  | Should BFD be enabled? |
2021-07-06T04:20:15.2068533Z | password | string |  |  | BGP MD5 password |
2021-07-06T04:20:15.2069580Z | rs-client | bool | false |  | Should this peer be a route server client? |
2021-07-06T04:20:15.2070892Z | rr-client | bool | false |  | Should this peer be a route reflector client? |
2021-07-06T04:20:15.2072204Z | remove-private-asns | bool | true |  | Should private ASNs be removed from path before exporting? |
2021-07-06T04:20:15.2073670Z | mp-unicast-46 | bool | false |  | Should this peer be configured with multiprotocol IPv4 and IPv6 unicast? |
2021-07-06T04:20:15.2074984Z | allow-local-as | bool | false |  | Should routes originated by the local ASN be accepted? |
2021-07-06T04:20:15.2076304Z | import-communities | []string |  |  | List of communities to add to all imported routes |
2021-07-06T04:20:15.2077850Z | export-communities | []string |  |  | List of communities to add to all exported routes |
2021-07-06T04:20:15.2079539Z | announce-communities | []string |  |  | Announce all routes matching these communities to the peer |
2021-07-06T04:20:15.2081282Z | remove-communities | []string |  |  | List of communities to remove before from routes announced by this peer |
2021-07-06T04:20:15.2082496Z | as-set | string |  |  | Peer's as-set for filtering |
2021-07-06T04:20:15.2083708Z | import-limit4 | int | 1000000 |  | Maximum number of IPv4 prefixes to import |
2021-07-06T04:20:15.2084953Z | import-limit6 | int | 200000 |  | Maximum number of IPv6 prefixes to import |
2021-07-06T04:20:15.2086316Z | enforce-first-as | bool | true |  | Should we only accept routes who's first AS is equal to the configured peer address? |
2021-07-06T04:20:15.2088296Z | enforce-peer-nexthop | bool | true |  | Should we only accept routes with a next hop equal to the configured neighbor address? |
2021-07-06T04:20:15.2089943Z | max-prefix-action | string | disable |  | What action should be taken when the max prefix limit is tripped? |
2021-07-06T04:20:15.2091513Z | allow-blackhole-community | bool | false |  | Should this peer be allowed to send routes with the blackhole community? |
2021-07-06T04:20:15.2093350Z | filter-irr | bool | false |  | Should IRR filtering be applied? |
2021-07-06T04:20:15.2094453Z | filter-rpki | bool | true |  | Should RPKI invalids be rejected? |
2021-07-06T04:20:15.2095555Z | filter-max-prefix | bool | true |  | Should max prefix filtering be applied? |
2021-07-06T04:20:15.2097000Z | filter-bogon-routes | bool | true |  | Should bogon prefixes be rejected? |
2021-07-06T04:20:15.2098360Z | filter-bogon-asns | bool | true |  | Should paths containing a bogon ASN be rejected? |
2021-07-06T04:20:15.2099820Z | filter-transit-asns | bool | false |  | Should paths containing transit-free ASNs be rejected? (Peerlock Lite)' |
2021-07-06T04:20:15.2101645Z | filter-prefix-length | bool | true |  | Should too large/small prefixes (IPv4: len > 24 || len < 8; IPv6: len > 48 || len < 12) be rejected? |
2021-07-06T04:20:15.2103118Z | auto-import-limits | bool | false |  | Get import limits automatically from PeeringDB? |
2021-07-06T04:20:15.2104334Z | auto-as-set | bool | false |  | Get as-set automatically from PeeringDB? |
2021-07-06T04:20:15.2105860Z | honor-graceful-shutdown | bool | true |  | Should RFC8326 graceful shutdown be enabled? |
2021-07-06T04:20:15.2106811Z | prefixes | []string |  |  | Prefixes to accept |
2021-07-06T04:20:15.2107872Z | announce-default | bool | false |  | Should a default route be exported to this peer? |
2021-07-06T04:20:15.2109267Z | announce-originated | bool | true |  | Should locally originated routes be announced to this peer? |
2021-07-06T04:20:15.2110702Z | session-global | string |  |  | Configuration to add to each session before any defined BGP protocols |
2021-07-06T04:20:15.2112209Z | pre-import | string |  |  | Configuration to add at the beginning of the import filter |
2021-07-06T04:20:15.2113481Z | pre-export | string |  |  | Configuration to add at the beginning of the export filter |
2021-07-06T04:20:15.2114900Z | pre-import-final | string |  |  | Configuration to add immediately before the final accept/reject on import |
2021-07-06T04:20:15.2116539Z | pre-export-final | string |  |  | Configuration to add immediately before the final accept/reject on export |
2021-07-06T04:20:15.2118219Z | probe-sources | []string |  |  | Optimizer probe source addresses |
2021-07-06T04:20:15.2119217Z | optimize | bool | false |  | Should the optimizer be enabled for this peer? |
2021-07-06T04:20:15.2120412Z | optimize-inbound | bool | false |  | Should the optimizer modify inbound policy? |
2021-07-06T04:20:15.2121328Z 
2021-07-06T04:20:15.2121773Z ## VRRPInstance
2021-07-06T04:20:15.2122370Z | Option | Type | Default | Validation | Description |
2021-07-06T04:20:15.2123317Z |--------|------|---------|------------|-------------|
2021-07-06T04:20:15.2124232Z | state | string |  | required | VRRP instance state ('primary' or 'backup') |
2021-07-06T04:20:15.2125370Z | interface | string |  | required | Interface to send VRRP packets on |
2021-07-06T04:20:15.2126435Z | vrid | uint |  | required | RFC3768 VRRP Virtual Router ID (1-255) |
2021-07-06T04:20:15.2127631Z | priority | uint |  | required | RFC3768 VRRP Priority |
2021-07-06T04:20:15.2128503Z | vips | []string |  | required,cidr | List of virtual IPs |
2021-07-06T04:20:15.2128979Z 
2021-07-06T04:20:15.2129384Z ## Augments
2021-07-06T04:20:15.2130032Z | Option | Type | Default | Validation | Description |
2021-07-06T04:20:15.2131300Z |--------|------|---------|------------|-------------|
2021-07-06T04:20:15.2132078Z | accept4 | []string |  |  | List of BIRD protocols to import into the IPv4 table |
2021-07-06T04:20:15.2133046Z | accept6 | []string |  |  | List of BIRD protocols to import into the IPv6 table |
2021-07-06T04:20:15.2133970Z | reject4 | []string |  |  | List of BIRD protocols to not import into the IPv4 table |
2021-07-06T04:20:15.2135874Z | reject6 | []string |  |  | List of BIRD protocols to not import into the IPv6 table |
2021-07-06T04:20:15.2136828Z | statics | map[string]string |  |  | List of static routes to include in BIRD |
2021-07-06T04:20:15.2137364Z 
2021-07-06T04:20:15.2137814Z ## Optimizer
2021-07-06T04:20:15.2138490Z | Option | Type | Default | Validation | Description |
2021-07-06T04:20:15.2139735Z |--------|------|---------|------------|-------------|
2021-07-06T04:20:15.2140375Z | targets | []string |  |  | List of probe targets |
2021-07-06T04:20:15.2141480Z | latency-threshold | uint | 100 |  | Maximum allowable latency in milliseconds |
2021-07-06T04:20:15.2142779Z | packet-loss-threshold | float64 | 0.5 |  | Maximum allowable packet loss (percent) |
2021-07-06T04:20:15.2144274Z | acquisition-threshold | float64 | 0.9 |  | Acquisition percentage to start applying optimizations (range 0-1) |
2021-07-06T04:20:15.2145435Z | modifier | uint | 20 |  | Amount to lower local pref by for depreferred peers |
2021-07-06T04:20:15.2146449Z | probe-count | int | 5 |  | Number of pings to send in each run |
2021-07-06T04:20:15.2147705Z | probe-timeout | int | 1 |  | Number of seconds to wait before considering the ICMP message unanswered |
2021-07-06T04:20:15.2149069Z | probe-interval | int | 120 |  | Number of seconds wait between each optimizer run |
2021-07-06T04:20:15.2150559Z | cache-size | int | 15 |  | Number of probe results to store per peer |
2021-07-06T04:20:15.2151093Z 
2021-07-06T04:20:15.4681873Z time="2021-07-06T04:20:15Z" level=debug msg="Starting pathvector devel"
2021-07-06T04:20:15.4683909Z time="2021-07-06T04:20:15Z" level=debug msg="Loading config from tests/generate-simple.yml"
2021-07-06T04:20:15.4720516Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Template with ingored default (-)"
2021-07-06T04:20:15.4733662Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Description with ingored default (-)"
2021-07-06T04:20:15.4766286Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Disabled value <invalid reflect.Value>"
2021-07-06T04:20:15.4770623Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Disabled to value false"
2021-07-06T04:20:15.4772660Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ASN value 65510"
2021-07-06T04:20:15.4774091Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field NeighborIPs with ingored default (-)"
2021-07-06T04:20:15.4775670Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Prepends value <invalid reflect.Value>"
2021-07-06T04:20:15.4777234Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Prepends to value 0"
2021-07-06T04:20:15.4779644Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field LocalPref value <invalid reflect.Value>"
2021-07-06T04:20:15.4796460Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field LocalPref to value 100"
2021-07-06T04:20:15.4798744Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Multihop value <invalid reflect.Value>"
2021-07-06T04:20:15.4800516Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Multihop to value false"
2021-07-06T04:20:15.4813560Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Listen with ingored default (-)"
2021-07-06T04:20:15.4814891Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field LocalASN with ingored default (-)"
2021-07-06T04:20:15.4816418Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field LocalPort value <invalid reflect.Value>"
2021-07-06T04:20:15.4817752Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field LocalPort to value 179"
2021-07-06T04:20:15.4819238Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field NeighborPort value <invalid reflect.Value>"
2021-07-06T04:20:15.4820650Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field NeighborPort to value 179"
2021-07-06T04:20:15.4822345Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Passive value <invalid reflect.Value>"
2021-07-06T04:20:15.4823747Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Passive to value false"
2021-07-06T04:20:15.4825191Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field NextHopSelf value <invalid reflect.Value>"
2021-07-06T04:20:15.4826912Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field NextHopSelf to value false"
2021-07-06T04:20:15.4828412Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field BFD value <invalid reflect.Value>"
2021-07-06T04:20:15.4829822Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field BFD to value false"
2021-07-06T04:20:15.4831071Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Password with ingored default (-)"
2021-07-06T04:20:15.4832630Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RSClient value <invalid reflect.Value>"
2021-07-06T04:20:15.4834689Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RSClient to value false"
2021-07-06T04:20:15.4836357Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RRClient value <invalid reflect.Value>"
2021-07-06T04:20:15.4838146Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RRClient to value false"
2021-07-06T04:20:15.4839816Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RemovePrivateASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.4841547Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RemovePrivateASNs to value true"
2021-07-06T04:20:15.4843158Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field MPUnicast46 value <invalid reflect.Value>"
2021-07-06T04:20:15.4845266Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field MPUnicast46 to value false"
2021-07-06T04:20:15.4847222Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AllowLocalAS value <invalid reflect.Value>"
2021-07-06T04:20:15.4848845Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AllowLocalAS to value false"
2021-07-06T04:20:15.4850362Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportCommunities with ingored default (-)"
2021-07-06T04:20:15.4851703Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportCommunities with ingored default (-)"
2021-07-06T04:20:15.4853133Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceCommunities with ingored default (-)"
2021-07-06T04:20:15.4854599Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveCommunities with ingored default (-)"
2021-07-06T04:20:15.4855859Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ASSet with ingored default (-)"
2021-07-06T04:20:15.4864848Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ImportLimit4 value <invalid reflect.Value>"
2021-07-06T04:20:15.4866800Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field ImportLimit4 to value 1000000"
2021-07-06T04:20:15.4868478Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ImportLimit6 value <invalid reflect.Value>"
2021-07-06T04:20:15.4870099Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field ImportLimit6 to value 200000"
2021-07-06T04:20:15.4871725Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field EnforceFirstAS value <invalid reflect.Value>"
2021-07-06T04:20:15.4873283Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field EnforceFirstAS to value true"
2021-07-06T04:20:15.4874884Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field EnforcePeerNexthop value <invalid reflect.Value>"
2021-07-06T04:20:15.4877058Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field EnforcePeerNexthop to value true"
2021-07-06T04:20:15.4879047Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field MaxPrefixTripAction value <invalid reflect.Value>"
2021-07-06T04:20:15.4880984Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field MaxPrefixTripAction to value disable"
2021-07-06T04:20:15.4882634Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AllowBlackholeCommunity value <invalid reflect.Value>"
2021-07-06T04:20:15.4884683Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AllowBlackholeCommunity to value false"
2021-07-06T04:20:15.4886629Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterIRR value <invalid reflect.Value>"
2021-07-06T04:20:15.4889058Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterIRR to value false"
2021-07-06T04:20:15.4890859Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterRPKI value <invalid reflect.Value>"
2021-07-06T04:20:15.4892805Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterRPKI to value true"
2021-07-06T04:20:15.4894518Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterMaxPrefix value <invalid reflect.Value>"
2021-07-06T04:20:15.4896372Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterMaxPrefix to value true"
2021-07-06T04:20:15.4898104Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterBogonRoutes value <invalid reflect.Value>"
2021-07-06T04:20:15.4901898Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterBogonRoutes to value true"
2021-07-06T04:20:15.4907742Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterBogonASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.4928444Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterBogonASNs to value true"
2021-07-06T04:20:15.4931820Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterTransitASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.4982406Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterTransitASNs to value false"
2021-07-06T04:20:15.4984099Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterPrefixLength value <invalid reflect.Value>"
2021-07-06T04:20:15.4986138Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterPrefixLength to value true"
2021-07-06T04:20:15.4988064Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AutoImportLimits value <invalid reflect.Value>"
2021-07-06T04:20:15.4989632Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AutoImportLimits to value false"
2021-07-06T04:20:15.4991224Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AutoASSet value <invalid reflect.Value>"
2021-07-06T04:20:15.4993034Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AutoASSet to value false"
2021-07-06T04:20:15.4994666Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field HonorGracefulShutdown value <invalid reflect.Value>"
2021-07-06T04:20:15.4996550Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field HonorGracefulShutdown to value true"
2021-07-06T04:20:15.4997924Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Prefixes with ingored default (-)"
2021-07-06T04:20:15.4999425Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AnnounceDefault value <invalid reflect.Value>"
2021-07-06T04:20:15.5001026Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AnnounceDefault to value false"
2021-07-06T04:20:15.5003102Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AnnounceOriginated value <invalid reflect.Value>"
2021-07-06T04:20:15.5006579Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AnnounceOriginated to value true"
2021-07-06T04:20:15.5008188Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field SessionGlobal with ingored default (-)"
2021-07-06T04:20:15.5009635Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreImport with ingored default (-)"
2021-07-06T04:20:15.5011031Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreExport with ingored default (-)"
2021-07-06T04:20:15.5012812Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreImportFinal with ingored default (-)"
2021-07-06T04:20:15.5014401Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreExportFinal with ingored default (-)"
2021-07-06T04:20:15.5016158Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field OptimizerProbeSources with ingored default (-)"
2021-07-06T04:20:15.5018565Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field OptimizerEnabled value <invalid reflect.Value>"
2021-07-06T04:20:15.5020980Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field OptimizerEnabled to value false"
2021-07-06T04:20:15.5022885Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field OptimizeInbound value <invalid reflect.Value>"
2021-07-06T04:20:15.5024506Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field OptimizeInbound to value false"
2021-07-06T04:20:15.5025909Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ProtocolName with ingored default (-)"
2021-07-06T04:20:15.5028093Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Protocols with ingored default (-)"
2021-07-06T04:20:15.5029553Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PrefixSet4 with ingored default (-)"
2021-07-06T04:20:15.5030980Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PrefixSet6 with ingored default (-)"
2021-07-06T04:20:15.5032799Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5034675Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5038458Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5040558Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5043958Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5045711Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5047594Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5049649Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5051220Z time="2021-07-06T04:20:15Z" level=debug msg="Finished loading config"
2021-07-06T04:20:15.5052311Z time="2021-07-06T04:20:15Z" level=debug msg="Loading templates from embedded filesystem"
2021-07-06T04:20:15.5053812Z time="2021-07-06T04:20:15Z" level=debug msg="Finished loading templates"
2021-07-06T04:20:15.5055017Z time="2021-07-06T04:20:15Z" level=debug msg="Making cache directory test-cache"
2021-07-06T04:20:15.5056239Z time="2021-07-06T04:20:15Z" level=debug msg="Creating global config"
2021-07-06T04:20:15.5127228Z time="2021-07-06T04:20:15Z" level=debug msg="Finished creating global config file"
2021-07-06T04:20:15.5129365Z time="2021-07-06T04:20:15Z" level=debug msg="Writing global config file"
2021-07-06T04:20:15.5135308Z time="2021-07-06T04:20:15Z" level=debug msg="Finished writing global config file"
2021-07-06T04:20:15.5151047Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field ASN = 65530\n"
2021-07-06T04:20:15.5166482Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Prefixes = [192.0.2.0/24 2001:db8::/48]\n"
2021-07-06T04:20:15.5175654Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Communities = []\n"
2021-07-06T04:20:15.5182806Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field LargeCommunities = []\n"
2021-07-06T04:20:15.5189236Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RouterID = 192.0.2.1\n"
2021-07-06T04:20:15.5190825Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field IRRServer = rr.ntt.net\n"
2021-07-06T04:20:15.5192853Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RTRServer = rtr.rpki.cloudflare.com:8282\n"
2021-07-06T04:20:15.5194968Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field KeepFiltered = false\n"
2021-07-06T04:20:15.5196197Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field KernelLearn = false\n"
2021-07-06T04:20:15.5197744Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field MergePaths = false\n"
2021-07-06T04:20:15.5199380Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Source4 = 192.0.2.1\n"
2021-07-06T04:20:15.5202438Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Source6 = 2001:db8::1\n"
2021-07-06T04:20:15.5209735Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field DefaultRoute = true\n"
2021-07-06T04:20:15.5211604Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field AcceptDefault = false\n"
2021-07-06T04:20:15.5212980Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field KernelTable = 0\n"
2021-07-06T04:20:15.5214263Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Peers = map[Example:0xc000480480]\n"
2021-07-06T04:20:15.5215656Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Templates = map[]\n"
2021-07-06T04:20:15.5217674Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field VRRPInstances = []\n"
2021-07-06T04:20:15.5219086Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Augments = {[] [] [] [] map[] map[] map[]}\n"
2021-07-06T04:20:15.5220925Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Optimizer = {[] 100 0.5 0.9 20 5 1 120 15 map[] false}\n"
2021-07-06T04:20:15.5222449Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RTRServerHost = rtr.rpki.cloudflare.com\n"
2021-07-06T04:20:15.5223950Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RTRServerPort = 8282\n"
2021-07-06T04:20:15.5225182Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Prefixes4 = [192.0.2.0/24]\n"
2021-07-06T04:20:15.5227074Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Prefixes6 = [2001:db8::/48]\n"
2021-07-06T04:20:15.5228295Z time="2021-07-06T04:20:15Z" level=info msg="Processing AS65510 Example"
2021-07-06T04:20:15.5229363Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Disabled = false\n"
2021-07-06T04:20:15.5230593Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ASN = 65510\n"
2021-07-06T04:20:15.5232034Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field NeighborIPs = [203.0.113.12 2001:db8::12]\n"
2021-07-06T04:20:15.5233295Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Prepends = 0\n"
2021-07-06T04:20:15.5234345Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field LocalPref = 100\n"
2021-07-06T04:20:15.5235397Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Multihop = false\n"
2021-07-06T04:20:15.5237073Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field LocalPort = 179\n"
2021-07-06T04:20:15.5238162Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field NeighborPort = 179\n"
2021-07-06T04:20:15.5239589Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Passive = false\n"
2021-07-06T04:20:15.5240862Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field NextHopSelf = false\n"
2021-07-06T04:20:15.5241960Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field BFD = false\n"
2021-07-06T04:20:15.5242930Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field RSClient = false\n"
2021-07-06T04:20:15.5244173Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field RRClient = false\n"
2021-07-06T04:20:15.5245378Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field RemovePrivateASNs = true\n"
2021-07-06T04:20:15.5246726Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field MPUnicast46 = false\n"
2021-07-06T04:20:15.5248229Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AllowLocalAS = false\n"
2021-07-06T04:20:15.5249394Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ImportLimit4 = 1000000\n"
2021-07-06T04:20:15.5250465Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ImportLimit6 = 200000\n"
2021-07-06T04:20:15.5255164Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field EnforceFirstAS = true\n"
2021-07-06T04:20:15.5256486Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field EnforcePeerNexthop = true\n"
2021-07-06T04:20:15.5257902Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field MaxPrefixTripAction = disable\n"
2021-07-06T04:20:15.5259459Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AllowBlackholeCommunity = false\n"
2021-07-06T04:20:15.5263247Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterIRR = false\n"
2021-07-06T04:20:15.5304260Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterRPKI = true\n"
2021-07-06T04:20:15.5306543Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterMaxPrefix = true\n"
2021-07-06T04:20:15.5308213Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterBogonRoutes = true\n"
2021-07-06T04:20:15.5309787Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterBogonASNs = true\n"
2021-07-06T04:20:15.5311276Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterTransitASNs = false\n"
2021-07-06T04:20:15.5312488Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterPrefixLength = true\n"
2021-07-06T04:20:15.5427563Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AutoImportLimits = false\n"
2021-07-06T04:20:15.5428651Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AutoASSet = false\n"
2021-07-06T04:20:15.5429942Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field HonorGracefulShutdown = true\n"
2021-07-06T04:20:15.5431323Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AnnounceDefault = false\n"
2021-07-06T04:20:15.5432516Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AnnounceOriginated = true\n"
2021-07-06T04:20:15.5433836Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field OptimizerEnabled = false\n"
2021-07-06T04:20:15.5435088Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field OptimizeInbound = false\n"
2021-07-06T04:20:15.5436136Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ProtocolName = EXAMPLE\n"
2021-07-06T04:20:15.5437061Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] Writing config"
2021-07-06T04:20:15.5438112Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] Wrote config"
2021-07-06T04:20:15.5438984Z time="2021-07-06T04:20:15Z" level=debug msg="Validating BIRD config"
2021-07-06T04:20:15.5440058Z time="2021-07-06T04:20:15Z" level=info msg="BIRD config validation passed"
2021-07-06T04:20:15.5441512Z time="2021-07-06T04:20:15Z" level=debug msg="Starting pathvector devel"
2021-07-06T04:20:15.5442709Z time="2021-07-06T04:20:15Z" level=debug msg="Loading config from tests/probe-simple.yml"
2021-07-06T04:20:15.5444278Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Template with ingored default (-)"
2021-07-06T04:20:15.5445817Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Description with ingored default (-)"
2021-07-06T04:20:15.5447390Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Disabled value <invalid reflect.Value>"
2021-07-06T04:20:15.5448721Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Disabled to value false"
2021-07-06T04:20:15.5449887Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ASN value 65510"
2021-07-06T04:20:15.5451369Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field NeighborIPs with ingored default (-)"
2021-07-06T04:20:15.5452764Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Prepends value <invalid reflect.Value>"
2021-07-06T04:20:15.5454372Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Prepends to value 0"
2021-07-06T04:20:15.5455683Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field LocalPref value <invalid reflect.Value>"
2021-07-06T04:20:15.5457502Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field LocalPref to value 100"
2021-07-06T04:20:15.5458895Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Multihop value <invalid reflect.Value>"
2021-07-06T04:20:15.5460721Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Multihop to value false"
2021-07-06T04:20:15.5461866Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Listen with ingored default (-)"
2021-07-06T04:20:15.5464633Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field LocalASN with ingored default (-)"
2021-07-06T04:20:15.5466255Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field LocalPort value <invalid reflect.Value>"
2021-07-06T04:20:15.5467806Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field LocalPort to value 179"
2021-07-06T04:20:15.5469209Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field NeighborPort value <invalid reflect.Value>"
2021-07-06T04:20:15.5470588Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field NeighborPort to value 179"
2021-07-06T04:20:15.5472323Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Passive value <invalid reflect.Value>"
2021-07-06T04:20:15.5488656Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Passive to value false"
2021-07-06T04:20:15.5490197Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field NextHopSelf value <invalid reflect.Value>"
2021-07-06T04:20:15.5491858Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field NextHopSelf to value false"
2021-07-06T04:20:15.5493680Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field BFD value <invalid reflect.Value>"
2021-07-06T04:20:15.5495306Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field BFD to value false"
2021-07-06T04:20:15.5496416Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Password with ingored default (-)"
2021-07-06T04:20:15.5497759Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RSClient value <invalid reflect.Value>"
2021-07-06T04:20:15.5499036Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RSClient to value false"
2021-07-06T04:20:15.5500358Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RRClient value <invalid reflect.Value>"
2021-07-06T04:20:15.5501614Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RRClient to value false"
2021-07-06T04:20:15.5503006Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RemovePrivateASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.5504454Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RemovePrivateASNs to value true"
2021-07-06T04:20:15.5505853Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field MPUnicast46 value <invalid reflect.Value>"
2021-07-06T04:20:15.5507170Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field MPUnicast46 to value false"
2021-07-06T04:20:15.5508535Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AllowLocalAS value <invalid reflect.Value>"
2021-07-06T04:20:15.5510090Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AllowLocalAS to value false"
2021-07-06T04:20:15.5511492Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportCommunities with ingored default (-)"
2021-07-06T04:20:15.5512763Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportCommunities with ingored default (-)"
2021-07-06T04:20:15.5514189Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceCommunities with ingored default (-)"
2021-07-06T04:20:15.5515486Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveCommunities with ingored default (-)"
2021-07-06T04:20:15.5516660Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ASSet with ingored default (-)"
2021-07-06T04:20:15.5517969Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ImportLimit4 value <invalid reflect.Value>"
2021-07-06T04:20:15.5519262Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field ImportLimit4 to value 1000000"
2021-07-06T04:20:15.5520998Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ImportLimit6 value <invalid reflect.Value>"
2021-07-06T04:20:15.5523294Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field ImportLimit6 to value 200000"
2021-07-06T04:20:15.5524858Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field EnforceFirstAS value <invalid reflect.Value>"
2021-07-06T04:20:15.5526222Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field EnforceFirstAS to value true"
2021-07-06T04:20:15.5527817Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field EnforcePeerNexthop value <invalid reflect.Value>"
2021-07-06T04:20:15.5529305Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field EnforcePeerNexthop to value true"
2021-07-06T04:20:15.5530805Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field MaxPrefixTripAction value <invalid reflect.Value>"
2021-07-06T04:20:15.5532283Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field MaxPrefixTripAction to value disable"
2021-07-06T04:20:15.5533855Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AllowBlackholeCommunity value <invalid reflect.Value>"
2021-07-06T04:20:15.5535427Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AllowBlackholeCommunity to value false"
2021-07-06T04:20:15.5536879Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterIRR value <invalid reflect.Value>"
2021-07-06T04:20:15.5538171Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterIRR to value false"
2021-07-06T04:20:15.5539517Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterRPKI value <invalid reflect.Value>"
2021-07-06T04:20:15.5540804Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterRPKI to value true"
2021-07-06T04:20:15.5542190Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterMaxPrefix value <invalid reflect.Value>"
2021-07-06T04:20:15.5543762Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterMaxPrefix to value true"
2021-07-06T04:20:15.5545253Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterBogonRoutes value <invalid reflect.Value>"
2021-07-06T04:20:15.5546847Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterBogonRoutes to value true"
2021-07-06T04:20:15.5548288Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterBogonASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.5549904Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterBogonASNs to value true"
2021-07-06T04:20:15.5551349Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterTransitASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.5552959Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterTransitASNs to value false"
2021-07-06T04:20:15.5554776Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterPrefixLength value <invalid reflect.Value>"
2021-07-06T04:20:15.5556370Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterPrefixLength to value true"
2021-07-06T04:20:15.5557974Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AutoImportLimits value <invalid reflect.Value>"
2021-07-06T04:20:15.5559368Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AutoImportLimits to value false"
2021-07-06T04:20:15.5561077Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AutoASSet value <invalid reflect.Value>"
2021-07-06T04:20:15.5562367Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AutoASSet to value false"
2021-07-06T04:20:15.5564774Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field HonorGracefulShutdown value <invalid reflect.Value>"
2021-07-06T04:20:15.5566614Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field HonorGracefulShutdown to value true"
2021-07-06T04:20:15.5568369Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Prefixes with ingored default (-)"
2021-07-06T04:20:15.5569785Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AnnounceDefault value <invalid reflect.Value>"
2021-07-06T04:20:15.5571195Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AnnounceDefault to value false"
2021-07-06T04:20:15.5572846Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AnnounceOriginated value <invalid reflect.Value>"
2021-07-06T04:20:15.5574660Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AnnounceOriginated to value true"
2021-07-06T04:20:15.5576310Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field SessionGlobal with ingored default (-)"
2021-07-06T04:20:15.5577856Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreImport with ingored default (-)"
2021-07-06T04:20:15.5579116Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreExport with ingored default (-)"
2021-07-06T04:20:15.5580736Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreImportFinal with ingored default (-)"
2021-07-06T04:20:15.5582001Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreExportFinal with ingored default (-)"
2021-07-06T04:20:15.5583589Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field OptimizerProbeSources with ingored default (-)"
2021-07-06T04:20:15.5585141Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field OptimizerEnabled value true"
2021-07-06T04:20:15.5586814Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field OptimizeInbound value true"
2021-07-06T04:20:15.5588178Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ProtocolName with ingored default (-)"
2021-07-06T04:20:15.5589422Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Protocols with ingored default (-)"
2021-07-06T04:20:15.5590720Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PrefixSet4 with ingored default (-)"
2021-07-06T04:20:15.5592619Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PrefixSet6 with ingored default (-)"
2021-07-06T04:20:15.5594460Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5596190Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5598115Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5599795Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5601480Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5603179Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5604734Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5606263Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5607828Z time="2021-07-06T04:20:15Z" level=debug msg="Finished loading config"
2021-07-06T04:20:15.5608889Z time="2021-07-06T04:20:15Z" level=debug msg="Loading templates from embedded filesystem"
2021-07-06T04:20:15.5609949Z time="2021-07-06T04:20:15Z" level=debug msg="Finished loading templates"
2021-07-06T04:20:15.5611133Z time="2021-07-06T04:20:15Z" level=debug msg="Making cache directory test-cache"
2021-07-06T04:20:15.5612074Z time="2021-07-06T04:20:15Z" level=debug msg="Creating global config"
2021-07-06T04:20:15.5613415Z time="2021-07-06T04:20:15Z" level=debug msg="Finished creating global config file"
2021-07-06T04:20:15.5614350Z time="2021-07-06T04:20:15Z" level=debug msg="Writing global config file"
2021-07-06T04:20:15.5615649Z time="2021-07-06T04:20:15Z" level=debug msg="Finished writing global config file"
2021-07-06T04:20:15.5616651Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field ASN = 65530\n"
2021-07-06T04:20:15.5618518Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Prefixes = [192.0.2.0/24 2001:db8::/48]\n"
2021-07-06T04:20:15.5619851Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Communities = []\n"
2021-07-06T04:20:15.5621005Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field LargeCommunities = []\n"
2021-07-06T04:20:15.5622174Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RouterID = 192.0.2.1\n"
2021-07-06T04:20:15.5623518Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field IRRServer = rr.ntt.net\n"
2021-07-06T04:20:15.5624869Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RTRServer = rtr.rpki.cloudflare.com:8282\n"
2021-07-06T04:20:15.5626221Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field KeepFiltered = false\n"
2021-07-06T04:20:15.5627443Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field KernelLearn = false\n"
2021-07-06T04:20:15.5628630Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field MergePaths = false\n"
2021-07-06T04:20:15.5629796Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Source4 = 192.0.2.1\n"
2021-07-06T04:20:15.5631193Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Source6 = 2001:db8::1\n"
2021-07-06T04:20:15.5632362Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field DefaultRoute = true\n"
2021-07-06T04:20:15.5633726Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field AcceptDefault = false\n"
2021-07-06T04:20:15.5634884Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field KernelTable = 0\n"
2021-07-06T04:20:15.5636415Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Peers = map[Example:0xc00040ed80]\n"
2021-07-06T04:20:15.5637780Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Templates = map[]\n"
2021-07-06T04:20:15.5638921Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field VRRPInstances = []\n"
2021-07-06T04:20:15.5640099Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Augments = {[] [] [] [] map[] map[] map[]}\n"
2021-07-06T04:20:15.5641345Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Optimizer = {[192.0.2.2] 100 0.5 0.1 20 5 1 1 15 map[] false}\n"
2021-07-06T04:20:15.5642832Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RTRServerHost = rtr.rpki.cloudflare.com\n"
2021-07-06T04:20:15.5644157Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field RTRServerPort = 8282\n"
2021-07-06T04:20:15.5645853Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Prefixes4 = [192.0.2.0/24]\n"
2021-07-06T04:20:15.5647810Z time="2021-07-06T04:20:15Z" level=debug msg="[pathvector.global] field Prefixes6 = [2001:db8::/48]\n"
2021-07-06T04:20:15.5648890Z time="2021-07-06T04:20:15Z" level=info msg="Processing AS65510 Example"
2021-07-06T04:20:15.5650036Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Disabled = false\n"
2021-07-06T04:20:15.5650943Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ASN = 65510\n"
2021-07-06T04:20:15.5652165Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field NeighborIPs = [203.0.113.12 2001:db8::12]\n"
2021-07-06T04:20:15.5653172Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Prepends = 0\n"
2021-07-06T04:20:15.5654101Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field LocalPref = 100\n"
2021-07-06T04:20:15.5655055Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Multihop = false\n"
2021-07-06T04:20:15.5656008Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field LocalPort = 179\n"
2021-07-06T04:20:15.5657166Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field NeighborPort = 179\n"
2021-07-06T04:20:15.5658170Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field Passive = false\n"
2021-07-06T04:20:15.5659345Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field NextHopSelf = false\n"
2021-07-06T04:20:15.5660288Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field BFD = false\n"
2021-07-06T04:20:15.5661225Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field RSClient = false\n"
2021-07-06T04:20:15.5662180Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field RRClient = false\n"
2021-07-06T04:20:15.5663230Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field RemovePrivateASNs = true\n"
2021-07-06T04:20:15.5664292Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field MPUnicast46 = false\n"
2021-07-06T04:20:15.5667124Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AllowLocalAS = false\n"
2021-07-06T04:20:15.5668250Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ImportLimit4 = 1000000\n"
2021-07-06T04:20:15.5669339Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ImportLimit6 = 200000\n"
2021-07-06T04:20:15.5670782Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field EnforceFirstAS = true\n"
2021-07-06T04:20:15.5671880Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field EnforcePeerNexthop = true\n"
2021-07-06T04:20:15.5673256Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field MaxPrefixTripAction = disable\n"
2021-07-06T04:20:15.5674675Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AllowBlackholeCommunity = false\n"
2021-07-06T04:20:15.5676136Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterIRR = false\n"
2021-07-06T04:20:15.5677311Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterRPKI = true\n"
2021-07-06T04:20:15.5678364Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterMaxPrefix = true\n"
2021-07-06T04:20:15.5680263Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterBogonRoutes = true\n"
2021-07-06T04:20:15.5681709Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterBogonASNs = true\n"
2021-07-06T04:20:15.5683037Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterTransitASNs = false\n"
2021-07-06T04:20:15.5684409Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field FilterPrefixLength = true\n"
2021-07-06T04:20:15.5685752Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AutoImportLimits = false\n"
2021-07-06T04:20:15.5687694Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AutoASSet = false\n"
2021-07-06T04:20:15.5688938Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field HonorGracefulShutdown = true\n"
2021-07-06T04:20:15.5690633Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AnnounceDefault = false\n"
2021-07-06T04:20:15.5691774Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field AnnounceOriginated = true\n"
2021-07-06T04:20:15.5693713Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field OptimizerProbeSources = [192.0.2.1 2001:db8::1]\n"
2021-07-06T04:20:15.5694902Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field OptimizerEnabled = true\n"
2021-07-06T04:20:15.5696395Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field OptimizeInbound = true\n"
2021-07-06T04:20:15.5697697Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] field ProtocolName = EXAMPLE\n"
2021-07-06T04:20:15.5698736Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] Writing config"
2021-07-06T04:20:15.5699992Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] Wrote config"
2021-07-06T04:20:15.5700909Z time="2021-07-06T04:20:15Z" level=debug msg="Validating BIRD config"
2021-07-06T04:20:15.5701841Z time="2021-07-06T04:20:15Z" level=info msg="BIRD config validation passed"
2021-07-06T04:20:15.5703118Z time="2021-07-06T04:20:15Z" level=debug msg="Loading config from tests/probe-simple.yml"
2021-07-06T04:20:15.5704361Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Template with ingored default (-)"
2021-07-06T04:20:15.5705631Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Description with ingored default (-)"
2021-07-06T04:20:15.5707103Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Disabled value <invalid reflect.Value>"
2021-07-06T04:20:15.5708468Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Disabled to value false"
2021-07-06T04:20:15.5709725Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ASN value 65510"
2021-07-06T04:20:15.5711049Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field NeighborIPs with ingored default (-)"
2021-07-06T04:20:15.5712726Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Prepends value <invalid reflect.Value>"
2021-07-06T04:20:15.5714032Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Prepends to value 0"
2021-07-06T04:20:15.5715395Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field LocalPref value <invalid reflect.Value>"
2021-07-06T04:20:15.5716714Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field LocalPref to value 100"
2021-07-06T04:20:15.5718049Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Multihop value <invalid reflect.Value>"
2021-07-06T04:20:15.5719376Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Multihop to value false"
2021-07-06T04:20:15.5720523Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Listen with ingored default (-)"
2021-07-06T04:20:15.5721707Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field LocalASN with ingored default (-)"
2021-07-06T04:20:15.5723119Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field LocalPort value <invalid reflect.Value>"
2021-07-06T04:20:15.5725202Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field LocalPort to value 179"
2021-07-06T04:20:15.5726756Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field NeighborPort value <invalid reflect.Value>"
2021-07-06T04:20:15.5728337Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field NeighborPort to value 179"
2021-07-06T04:20:15.5729906Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field Passive value <invalid reflect.Value>"
2021-07-06T04:20:15.5731212Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field Passive to value false"
2021-07-06T04:20:15.5732595Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field NextHopSelf value <invalid reflect.Value>"
2021-07-06T04:20:15.5733972Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field NextHopSelf to value false"
2021-07-06T04:20:15.5735346Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field BFD value <invalid reflect.Value>"
2021-07-06T04:20:15.5736596Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field BFD to value false"
2021-07-06T04:20:15.5737941Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Password with ingored default (-)"
2021-07-06T04:20:15.5739405Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RSClient value <invalid reflect.Value>"
2021-07-06T04:20:15.5740884Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RSClient to value false"
2021-07-06T04:20:15.5742251Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RRClient value <invalid reflect.Value>"
2021-07-06T04:20:15.5743578Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RRClient to value false"
2021-07-06T04:20:15.5745025Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field RemovePrivateASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.5746519Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field RemovePrivateASNs to value true"
2021-07-06T04:20:15.5747983Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field MPUnicast46 value <invalid reflect.Value>"
2021-07-06T04:20:15.5749335Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field MPUnicast46 to value false"
2021-07-06T04:20:15.5750745Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AllowLocalAS value <invalid reflect.Value>"
2021-07-06T04:20:15.5752258Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AllowLocalAS to value false"
2021-07-06T04:20:15.5753476Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportCommunities with ingored default (-)"
2021-07-06T04:20:15.5754799Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportCommunities with ingored default (-)"
2021-07-06T04:20:15.5756141Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceCommunities with ingored default (-)"
2021-07-06T04:20:15.5757462Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveCommunities with ingored default (-)"
2021-07-06T04:20:15.5758682Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ASSet with ingored default (-)"
2021-07-06T04:20:15.5760047Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ImportLimit4 value <invalid reflect.Value>"
2021-07-06T04:20:15.5761353Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field ImportLimit4 to value 1000000"
2021-07-06T04:20:15.5762712Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field ImportLimit6 value <invalid reflect.Value>"
2021-07-06T04:20:15.5764189Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field ImportLimit6 to value 200000"
2021-07-06T04:20:15.5765558Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field EnforceFirstAS value <invalid reflect.Value>"
2021-07-06T04:20:15.5768176Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field EnforceFirstAS to value true"
2021-07-06T04:20:15.5770146Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field EnforcePeerNexthop value <invalid reflect.Value>"
2021-07-06T04:20:15.5771607Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field EnforcePeerNexthop to value true"
2021-07-06T04:20:15.5773120Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field MaxPrefixTripAction value <invalid reflect.Value>"
2021-07-06T04:20:15.5774629Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field MaxPrefixTripAction to value disable"
2021-07-06T04:20:15.5776191Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AllowBlackholeCommunity value <invalid reflect.Value>"
2021-07-06T04:20:15.5777969Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AllowBlackholeCommunity to value false"
2021-07-06T04:20:15.5779638Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterIRR value <invalid reflect.Value>"
2021-07-06T04:20:15.5780919Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterIRR to value false"
2021-07-06T04:20:15.5782262Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterRPKI value <invalid reflect.Value>"
2021-07-06T04:20:15.5783783Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterRPKI to value true"
2021-07-06T04:20:15.5785716Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterMaxPrefix value <invalid reflect.Value>"
2021-07-06T04:20:15.5787187Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterMaxPrefix to value true"
2021-07-06T04:20:15.5788649Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterBogonRoutes value <invalid reflect.Value>"
2021-07-06T04:20:15.5790066Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterBogonRoutes to value true"
2021-07-06T04:20:15.5791689Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterBogonASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.5793373Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterBogonASNs to value true"
2021-07-06T04:20:15.5795700Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterTransitASNs value <invalid reflect.Value>"
2021-07-06T04:20:15.5797415Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterTransitASNs to value false"
2021-07-06T04:20:15.5799011Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field FilterPrefixLength value <invalid reflect.Value>"
2021-07-06T04:20:15.5800949Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field FilterPrefixLength to value true"
2021-07-06T04:20:15.5802558Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AutoImportLimits value <invalid reflect.Value>"
2021-07-06T04:20:15.5804064Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AutoImportLimits to value false"
2021-07-06T04:20:15.5805536Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AutoASSet value <invalid reflect.Value>"
2021-07-06T04:20:15.5807144Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AutoASSet to value false"
2021-07-06T04:20:15.5808801Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field HonorGracefulShutdown value <invalid reflect.Value>"
2021-07-06T04:20:15.5810306Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field HonorGracefulShutdown to value true"
2021-07-06T04:20:15.5811562Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Prefixes with ingored default (-)"
2021-07-06T04:20:15.5813274Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AnnounceDefault value <invalid reflect.Value>"
2021-07-06T04:20:15.5814603Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AnnounceDefault to value false"
2021-07-06T04:20:15.5816020Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field AnnounceOriginated value <invalid reflect.Value>"
2021-07-06T04:20:15.5817975Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] setting field AnnounceOriginated to value true"
2021-07-06T04:20:15.5819452Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field SessionGlobal with ingored default (-)"
2021-07-06T04:20:15.5820874Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreImport with ingored default (-)"
2021-07-06T04:20:15.5822065Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreExport with ingored default (-)"
2021-07-06T04:20:15.5823288Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreImportFinal with ingored default (-)"
2021-07-06T04:20:15.5824550Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PreExportFinal with ingored default (-)"
2021-07-06T04:20:15.5825886Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field OptimizerProbeSources with ingored default (-)"
2021-07-06T04:20:15.5827498Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field OptimizerEnabled value true"
2021-07-06T04:20:15.5829357Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] (before defaulting, after templating) field OptimizeInbound value true"
2021-07-06T04:20:15.5830947Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ProtocolName with ingored default (-)"
2021-07-06T04:20:15.5832136Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field Protocols with ingored default (-)"
2021-07-06T04:20:15.5833337Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PrefixSet4 with ingored default (-)"
2021-07-06T04:20:15.5834536Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field PrefixSet6 with ingored default (-)"
2021-07-06T04:20:15.5835873Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5837348Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ImportLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5838834Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5840682Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field ExportLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5842188Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5843715Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field AnnounceLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5845191Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveStandardCommunities with ingored default (-)"
2021-07-06T04:20:15.5846672Z time="2021-07-06T04:20:15Z" level=debug msg="[Example] skipping field RemoveLargeCommunities with ingored default (-)"
2021-07-06T04:20:15.5848215Z time="2021-07-06T04:20:15Z" level=debug msg="Finished loading config"
2021-07-06T04:20:15.5849449Z time="2021-07-06T04:20:15Z" level=info msg="Starting optimizer"
2021-07-06T04:20:15.5850771Z time="2021-07-06T04:20:15Z" level=debug msg="Optimizer probe sources: map[65510####Example:[192.0.2.1 2001:db8::1]]"
2021-07-06T04:20:15.5851882Z time="2021-07-06T04:20:15Z" level=debug msg="[Optimizer] Sending 5 ICMP probes src 192.0.2.1 dst 192.0.2.2"
2021-07-06T04:20:16.5521683Z time="2021-07-06T04:20:16Z" level=debug msg="[Optimizer] Acquisition progress: 1/15 (0.6666666666666666%)"
2021-07-06T04:20:16.5523668Z time="2021-07-06T04:20:16Z" level=debug msg="[Optimizer] Waiting 1s until next probe run"
2021-07-06T04:20:17.5524733Z time="2021-07-06T04:20:17Z" level=debug msg="[Optimizer] Sending 5 ICMP probes src 192.0.2.1 dst 192.0.2.2"
2021-07-06T04:20:18.5966206Z time="2021-07-06T04:20:18Z" level=debug msg="[Optimizer] Acquisition progress: 2/15 (1.3333333333333333%)"
2021-07-06T04:20:18.5968426Z time="2021-07-06T04:20:18Z" level=debug msg="[Optimizer] Peer 65510####Example exceeded maximum allowable packet loss: 100.000000 >= 0.500000"
2021-07-06T04:20:18.5975099Z time="2021-07-06T04:20:18Z" level=info msg="[Optimizer] Lowered Example local-pref from 100 to 80"
2021-07-06T04:20:18.5976986Z time="2021-07-06T04:20:18Z" level=debug msg="Validating BIRD config"
2021-07-06T04:20:18.6006511Z time="2021-07-06T04:20:18Z" level=info msg="BIRD config validation passed"
2021-07-06T04:20:18.6007869Z time="2021-07-06T04:20:18Z" level=debug msg="[Optimizer] Waiting 1s until next probe run"
2021-07-06T04:20:19.6010656Z time="2021-07-06T04:20:19Z" level=debug msg="[Optimizer] Sending 5 ICMP probes src 192.0.2.1 dst 192.0.2.2"
2021-07-06T04:20:20.6192281Z time="2021-07-06T04:20:20Z" level=debug msg="[Optimizer] Acquisition progress: 3/15 (2%)"
2021-07-06T04:20:20.6194093Z time="2021-07-06T04:20:20Z" level=debug msg="[Optimizer] Peer 65510####Example exceeded maximum allowable packet loss: 100.000000 >= 0.500000"
2021-07-06T04:20:20.6221556Z time="2021-07-06T04:20:20Z" level=info msg="[Optimizer] Lowered Example local-pref from 100 to 80"
2021-07-06T04:20:20.6225331Z time="2021-07-06T04:20:20Z" level=debug msg="Validating BIRD config"
2021-07-06T04:20:20.6258210Z time="2021-07-06T04:20:20Z" level=info msg="BIRD config validation passed"
2021-07-06T04:20:20.6259844Z time="2021-07-06T04:20:20Z" level=debug msg="[Optimizer] Waiting 1s until next probe run"
2021-07-06T04:20:21.6261619Z ==================
2021-07-06T04:20:21.6262726Z WARNING: DATA RACE
2021-07-06T04:20:21.6263267Z Read at 0x000000f0d740 by goroutine 44:
2021-07-06T04:20:21.6263948Z   github.com/natesales/pathvector.startProbe()
2021-07-06T04:20:21.6265277Z       /home/runner/work/pathvector/pathvector/optimizer.go:72 +0xe9d
2021-07-06T04:20:21.6266115Z   github.com/natesales/pathvector.glob..func2()
2021-07-06T04:20:21.6269238Z       /home/runner/work/pathvector/pathvector/main.go:234 +0xa24
2021-07-06T04:20:21.6269952Z   github.com/spf13/cobra.(*Command).execute()
2021-07-06T04:20:21.6270921Z       /home/runner/go/pkg/mod/github.com/spf13/cobra@v1.2.1/command.go:860 +0x8cb
2021-07-06T04:20:21.6271845Z   github.com/spf13/cobra.(*Command).ExecuteC()
2021-07-06T04:20:21.6272618Z       /home/runner/go/pkg/mod/github.com/spf13/cobra@v1.2.1/command.go:974 +0x4c4
2021-07-06T04:20:21.6273316Z   github.com/spf13/cobra.(*Command).Execute()
2021-07-06T04:20:21.6274133Z       /home/runner/go/pkg/mod/github.com/spf13/cobra@v1.2.1/command.go:902 +0x689
2021-07-06T04:20:21.6275422Z   github.com/natesales/pathvector.TestMainOptimizer()
2021-07-06T04:20:21.6276502Z       /home/runner/work/pathvector/pathvector/main_test.go:69 +0x66a
2021-07-06T04:20:21.6277139Z   testing.tRunner()
2021-07-06T04:20:21.6277813Z       /opt/hostedtoolcache/go/1.16.5/x64/src/testing/testing.go:1193 +0x202
2021-07-06T04:20:21.6278277Z 
2021-07-06T04:20:21.6278743Z Previous write at 0x000000f0d740 by goroutine 49:
2021-07-06T04:20:21.6279636Z   github.com/natesales/pathvector.TestMainOptimizer.func1()
2021-07-06T04:20:21.6280859Z       /home/runner/work/pathvector/pathvector/main_test.go:59 +0xa4
2021-07-06T04:20:21.6281631Z 
2021-07-06T04:20:21.6282081Z Goroutine 44 (running) created at:
2021-07-06T04:20:21.6285629Z   testing.(*T).Run()
2021-07-06T04:20:21.6286445Z       /opt/hostedtoolcache/go/1.16.5/x64/src/testing/testing.go:1238 +0x5d7
2021-07-06T04:20:21.6287521Z   testing.runTests.func1()
2021-07-06T04:20:21.6288856Z       /opt/hostedtoolcache/go/1.16.5/x64/src/testing/testing.go:1511 +0xa6
2021-07-06T04:20:21.6289529Z   testing.tRunner()
2021-07-06T04:20:21.6290430Z       /opt/hostedtoolcache/go/1.16.5/x64/src/testing/testing.go:1193 +0x202
2021-07-06T04:20:21.6291105Z   testing.runTests()
2021-07-06T04:20:21.6291811Z       /opt/hostedtoolcache/go/1.16.5/x64/src/testing/testing.go:1509 +0x612
2021-07-06T04:20:21.6292442Z   testing.(*M).Run()
2021-07-06T04:20:21.6293118Z       /opt/hostedtoolcache/go/1.16.5/x64/src/testing/testing.go:1417 +0x3b3
2021-07-06T04:20:21.6293715Z   main.main()
2021-07-06T04:20:21.6294161Z       _testmain.go:157 +0x356
2021-07-06T04:20:21.6294479Z 
2021-07-06T04:20:21.6294913Z Goroutine 49 (finished) created at:
2021-07-06T04:20:21.6295729Z   github.com/natesales/pathvector.TestMainOptimizer()
2021-07-06T04:20:21.6296722Z       /home/runner/work/pathvector/pathvector/main_test.go:56 +0x449
2021-07-06T04:20:21.6297372Z   testing.tRunner()
2021-07-06T04:20:21.6298188Z       /opt/hostedtoolcache/go/1.16.5/x64/src/testing/testing.go:1193 +0x202
2021-07-06T04:20:21.6298811Z ==================
2021-07-06T04:20:21.6299970Z --- FAIL: TestMainOptimizer (6.12s)
2021-07-06T04:20:21.6302899Z     main_test.go:67: running probe integration with args [--verbose --dry-run --cache-directory test-cache optimizer --udp --config tests/probe-simple.yml]
2021-07-06T04:20:21.6304100Z     main_test.go:58: disabling optimizer
2021-07-06T04:20:21.6304831Z     testing.go:1092: race detected during execution of test
2021-07-06T04:20:21.6305937Z time="2021-07-06T04:20:21Z" level=debug msg="[Optimizer] Acquisition progress: 0/5 (0%)"
2021-07-06T04:20:21.6307064Z time="2021-07-06T04:20:21Z" level=debug msg="[Optimizer] Acquisition progress: 5/5 (10%)"
2021-07-06T04:20:21.6309753Z time="2021-07-06T04:20:21Z" level=debug msg="[Optimizer] Acquisition progress: 2/5 (4%)"
2021-07-06T04:20:25.5912309Z time="2021-07-06T04:20:25Z" level=warning msg="Original as-set RIPE::AS34553:AS-ALL has an IRRDB prefix in it. Using AS34553:AS-ALL"
2021-07-06T04:20:25.5917435Z time="2021-07-06T04:20:25Z" level=warning msg="Original as-set RADB::AS-HURRICANE RADB::AS-HURRICANEV6 has a space in it. Selecting first element RADB::AS-HURRICANE"
2021-07-06T04:20:25.5921040Z time="2021-07-06T04:20:25Z" level=warning msg="Original as-set RADB::AS-HURRICANE RADB::AS-HURRICANEV6 has an IRRDB prefix in it. Using AS-HURRICANE"
2021-07-06T04:20:25.6075665Z time="2021-07-06T04:20:25Z" level=debug msg="Creating UI output file"
2021-07-06T04:20:25.6077647Z time="2021-07-06T04:20:25Z" level=debug msg="Finished creating UI file"
2021-07-06T04:20:25.6078969Z time="2021-07-06T04:20:25Z" level=debug msg="Writing UI file"
2021-07-06T04:20:25.6080335Z time="2021-07-06T04:20:25Z" level=debug msg="Finished writing UI file"
2021-07-06T04:20:25.6081911Z time="2021-07-06T04:20:25Z" level=info msg="No VRRP instances are defined, not writing config"
2021-07-06T04:20:25.6138350Z FAIL
2021-07-06T04:20:25.6173058Z coverage: 67.9% of statements
2021-07-06T04:20:25.6204791Z exit status 1
2021-07-06T04:20:25.6205828Z FAIL   github.com/natesales/pathvector 10.476s
2021-07-06T04:20:25.6386261Z ##[error]Process completed with exit code 1.

[natesales]

Fixed in 1188af0