🐛 BUG: Issues with multiple fixed IP addresses for lighthouse
What version of nebula are you using?
1.7.2
What operating system are you using?
Linux
Describe the Bug
I'm having issues with hosts connecting when they have multiple IPs set for their lighthouse/relay. Most things seem to work fine but I was running into issues with NAT to NAT connections across two networks using multiple fixed IP addresses for one of my lighthouses:
Just for reference, here's what the connection looks like:
rsyslog daemon -> NAT -> internet -> NAT -> rsyslog server
The relevant part of my config looks like this:
static_host_map:
172.0.0.2:
- xxx.example.com:4242
- xxx.xxx.245.206:4242
- xxx.xxx.181.204:4242
172.0.0.3:
- xxx.xxx.118.198:4242
The rsyslog daemon on 172.0.3.109 shows this:
xxx.xxxlevel=info msg="Attempt to relay through hosts" localIndex=2357375276 relays="[172.0.0.2 172.0.0.3 172.0.0.2 172.0.0.3]" remoteIndex=0 vpnIp=172.0.2.116
xxx.xxxlevel=info msg="Send handshake via relay" localIndex=2357375276 relay=172.0.0.2 remoteIndex=0 vpnIp=172.0.2.116
xxx.xxxlevel=info msg="Send handshake via relay" localIndex=2357375276 relay=172.0.0.3 remoteIndex=0 vpnIp=172.0.2.116
xxx.xxxlevel=info msg="Send handshake via relay" localIndex=2357375276 relay=172.0.0.2 remoteIndex=0 vpnIp=172.0.2.116
xxx.xxxlevel=info msg="Send handshake via relay" localIndex=2357375276 relay=172.0.0.3 remoteIndex=0 vpnIp=172.0.2.116
xxx.xxxlevel=info msg="Handshake timed out" durationNs=3037758038 handshake="map[stage:1 style:ix_psk0]" initiatorIndex=2357375276 localIndex=2357375276 remoteIndex=0 udpAddrs="[xxx.xxx.142.18:53561 10.0.0.12:53561]" vpnIp=172.0.2.116
While the rsyslog server host 172.0.2.116 shows this:
xxx.xxxlevel=info msg="Attempt to relay through hosts" relayIps="[172.0.0.2 172.0.0.3 172.0.0.2 172.0.0.3]" vpnIp=172.0.3.109
xxx.xxxlevel=info msg="Re-send CreateRelay request" relay=172.0.0.2 vpnIp=172.0.3.109
xxx.xxxlevel=info msg="Re-send CreateRelay request" relay=172.0.0.3 vpnIp=172.0.3.109
xxx.xxxlevel=info msg="Re-send CreateRelay request" relay=172.0.0.2 vpnIp=172.0.3.109
xxx.xxxlevel=info msg="Re-send CreateRelay request" relay=172.0.0.3 vpnIp=172.0.3.109
xxx.xxxlevel=info msg="Handshake message sent" handshake="map[stage:1 style:ix_psk0]" initiatorIndex=2890926437 udpAddrs="[xxx.xxx.151.80:52928 xxx.xxx.151.80:65320 192.168.1.214:55504]" vpnIp=172.0.3.109
When I remove the xxx.example.com:4242 and xxx.xxx.181.204:4242 lines from both host's static_host_map entry, the traffic flows.
Logs from affected hosts
see above
Config files from affected hosts
see above
Actually, I had an internal lighthouse that only the hosts on the same network as the rsyslog daemon host could. I removed that and things seem to work now. Thoughts?
@Cyberes Hey there - I'm not clear on the scenarios and behavior. Maybe you can help clarify. In the initial ticket you state:
When I remove the xxx.example.com:4242 and xxx.xxx.181.204:4242 lines from both host's static_host_map entry, the traffic flows.
So when your config looks like this, everything works correctly?
static_host_map:
172.0.0.2:
- xxx.xxx.245.206:4242
172.0.0.3:
- xxx.xxx.118.198:4242
In your reply you stated...
Actually, I had an internal lighthouse that only the hosts on the same network as the rsyslog daemon host could. I removed that and things seem to work now. Thoughts?
Was that the 172.0.0.3 node? If so, are you stating that this config also works?
static_host_map:
172.0.0.2:
- xxx.example.com:4242
- xxx.xxx.245.206:4242
- xxx.xxx.181.204:4242
Please includes full logs from all nodes for both working scenarios as well as the single non-working scenario, clearly denoting which is which. Thank you!
Sorry, not surprised my confusion carried over to you. Let me try and explain...
When I first created this bug report, I believed that having multiple IPs listed for one static host was the issue. I thought that this entry in static_host_map was broken:
172.0.0.2:
- xxx.example.com:4242
- xxx.xxx.245.206:4242
- xxx.xxx.181.204:4242
And that it should have been this for it to work correctly:
172.0.0.2:
- xxx.xxx.245.206:4242
This change didn't resolve the issue.
But over the course of my testing, I found that having a hidden lighthouse (that I set up for internal communication on a different network) that was not accessible by all hosts was the issue. I saw in the rsyslog server host's (172.0.2.116) logs that Nebula was trying to connect to this inaccessible lighthouse. I shut that hidden lighthouse down and removed it from all hosts' configs and things seem to work as expected now.
When I set up that internal lighthouse the idea was that it would serve as a backup for its local network in the event that my main, global lighthouse failed and went offline. But it seems like the Nebula hosts on that local network are expecting other hosts that aren't on that local network to be able to connect to the hidden lighthouse which seems to create all sorts of problems.
I'm wondering if this behavior is unexpected or not. We can also dig deeper into this problem if you'd like (including logs).
I haven't put the multiple static IPs back in the static_host_map. Would you like me to do that and verify things work?
Thanks for clarifying. Things are starting to make sense. :)
But over the course of my testing, I found that having a hidden lighthouse (that I set up for internal communication on a different network) that was not accessible by all hosts was the issue. I saw in the rsyslog server host's (172.0.2.116) logs that Nebula was trying to connect to this inaccessible lighthouse. I shut that hidden lighthouse down and removed it from all hosts' configs and things seem to work as expected now.
What is the inaccessible Lighthouse's Nebula IP? Is it specified in some (or all, accessible or not) node's configs? Are there any nodes connecting to that Lighthouse only, which may have a duplicate IP as a node talking to the other Lighthouse?
In a network with a single Lighthouse, it's important that all nodes can talk to it. Without the Lighthouse used for discovery, nodes won't be able to find each other.
With two Lighthouses, you need all nodes to be able to connect to at least one of them. This is because if a single node can only talk to one Lighthouse, and another node can only talk to a second Lighthouse, they won't be able to discover each other. As long as all nodes share at least one however, they should be able to find a route.
(With three or more Lighthouses, the math is more complicated and not relevant to this discussion.)
So, if all nodes in your network can talk to one Lighthouse, and only some can talk to a second, things should still work! Unless of course there is a confounding factor. For example: maybe you have a test node you forgot about only talking to your secondary lighthouse with a Nebula IP that's also used by another node talking to your main lighthouse.
Without the requested logs, it's impossible to say.
Okay, let's keep breaking this down. Logs are coming (I have to re-create the setup I had when things weren't communicating).
What is the inaccessible Lighthouse's Nebula IP?
It was 172.0.3.103. Let's call the 172.0.3.xxx prefix Network B. 172.0.2.xxx is Network A. These two networks are completely separate LANs and can only talk to each other over the internet.
Is [the inaccessible Lighthouse] specified in some (or all, accessible or not) node's configs?
Only on the hosts in Network B.
Are there any nodes connecting to that Lighthouse only, which may have a duplicate IP as a node talking to the other Lighthouse?
No, all hosts on my Nebula network communicate with the main lighthouse/relay, 172.0.0.2. Hosts on Network B had 172.0.0.2 configured as a lighthouse and relay as well as having 172.0.3.103 configured as a lighthouse. Hosts on Network A did not have 172.0.3.103.
I know there aren't any duplicate IPs on my Nebula network because the script I use to generate certs/configs doesn't allow that.
With two Lighthouses, you need all nodes to be able to connect to at least one of them.
That's what I assumed, which is what is confusing about this whole thing.
One more thing: some hosts on Network B could communicate with 172.0.2.116(my rsyslog server) while others could not (172.0.3.109 in this case). Those hosts that could not were not reachable by 172.0.2.116. Restarting Nebula on 172.0.2.116 and 172.0.3.109 fixed the communication issues for a few minutes.
I don't know if this matters, but I have an OPNsense router on both networks.
One more thing: some hosts on Network B could communicate with 172.0.2.116(my rsyslog server) while others could not (172.0.3.109 in this case). Those hosts that could not were not reachable by 172.0.2.116. Restarting Nebula on 172.0.2.116 and 172.0.3.109 fixed the communication issues for a few minutes.
So a host 172.0.2.116 (rsyslog) on Network A was able to communicate with some Network B hosts, but not 172.0.3.109 (unknown name) until Nebula was restarted on each of these hosts, at which time communication could be re-established?
Nebula has 10 slots for each of IPv4 and IPv6 addresses for a given host. A failure scenario for Nebula can occur when a host has more than 10 IP addresses, most of which are not routable (e.g. a bunch of Docker networks running on the host) and reports them to the Lighthouse. Nodes will query the Lighthouse and have no routable IP addresses. You can use local_allow_list to restrict which addresses / adapters are considered. You should be able to see through handshake logs that all of the udpAddrs are non-routable.
Restarting the affected hosts can temporarily solve the problem because they will re-send their IP addresses to the Lighthouse, possibly in a different order.
AFAICT, that issue would not be resolved or affected by having some hosts report to an extra Lighthouse.
This is all speculation without logs. Waiting with abated breath. :)
@Cyberes Are you still experiencing this issue? Were you able to get logs of the problem?
Also, if you are still experiencing this issue, could you try running a nebula nightly build? In particular, I'd like to know whether this fix may have solved this issue for you. We observed that in some cases, making a change to the Nebula config and reloading it could break relay functionality.
I'm unable to confirm whether this was the issue in this case without Nebula logs.
Sorry, things got busy with school starting back up. I think I have time to do some more debugging. I'll have those logs somewhat soon.
Okay, I checked the status of the rsyslog server and it does not seem to have a Nebula connection. I can't ping its address and I can't ping any other Nebula hosts from the server.
This is without the multiple fixed IP addresses thing. In the rsyslog server's Nebula config, each lighthouse only has one address.
The last log item was from October 17. Systemd shows Nebula is running fine.
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:40 syslog nebula[149]: time="2023-10-17T12:00:40-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:41 syslog nebula[149]: time="2023-10-17T12:00:41-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="sendNoMetrics failed to find HostInfo" certName=proxy_2 error="unable to find host with relay" localIndex=26529179 relay=172.0.0.3 remoteIndex=3313359189 vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=3313359189 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:00:42 syslog nebula[149]: time="2023-10-17T12:00:42-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:00:53 syslog nebula[149]: time="2023-10-17T12:00:53-00:00" level=info msg="Tunnel status" certName=proxy_2 localIndex=26529179 remoteIndex=3313359189 tunnelCheck="map[method:active state:dead]" vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message sent" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:2 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx relay=172.0.0.2 remoteIndex=0 responderIndex=160405638 sentCachedPackets=0 vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:12 syslog nebula[149]: time="2023-10-17T12:02:12-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:13 syslog nebula[149]: time="2023-10-17T12:02:13-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:14 syslog nebula[149]: time="2023-10-17T12:02:14-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:15 syslog nebula[149]: time="2023-10-17T12:02:15-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Oct 17 12:02:16 syslog nebula[149]: time="2023-10-17T12:02:16-00:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.3 vpnIp=172.0.4.8
Oct 17 12:02:17 syslog nebula[149]: time="2023-10-17T12:02:17-00:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx handshake="map[stage:1 style:ix_psk0]" initiatorIndex=1534500982 issuer=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
Restarting the service with systemctl restart nebula failed:
Oct 23 21:52:13 syslog systemd[1]: Stopping nebula...
Oct 23 21:52:13 syslog nebula[149]: time="2023-10-23T21:52:13-00:00" level=info msg="Caught signal, shutting down" signal=terminated
Oct 23 21:53:43 syslog systemd[1]: nebula.service: State 'stop-sigterm' timed out. Killing.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 149 (nebula) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 225 (nebula) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 226 (nebula) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 228 (nebula) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 259 (n/a) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 260 (n/a) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 261 (nebula) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 723 (n/a) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 724 (n/a) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Killing process 1213 (n/a) with signal SIGKILL.
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Main process exited, code=killed, status=9/KILL
Oct 23 21:53:43 syslog systemd[1]: nebula.service: Failed with result 'timeout'.
Oct 23 21:53:43 syslog systemd[1]: Stopped nebula.
Once restarted, it started working as expected.
Just want to clarify that my rsyslog server has dozens of connections to my other servers.
Hey @Cyberes - thanks for these logs. I understand that the first set of logs is from a period where the node wasn't working, but the logs indicate a "steady state" (as in, nothing is really happening.) The interesting part is probably above all of this.
The restart failure is interesting and indicates that Nebula was not responding. I believe this has occurred when the UDP writer routine freezes / hangs. In a case where Nebula is not responding, it's best if you can issue a SIGQUIT to the process, as this will dump a stack trace that will help us understand what the process was waiting for when it hung.
At this point, we can go down two paths:
(a) You can share the logs prior to the steady state and we can see if anything jumps out regarding the hang. Regardless, please try a SIGQUIT and retrieve logs if this hang occurs again. (b) We can go ahead and continue tracking down the multiple fixed IP addresses bug. For that, I'll still need the logs I've requested... thanks.
The earliest log entry I have is this:
Oct 16 01:43:15 syslog nebula[149]: time="2023-10-16T01:43:15-06:00" level=info msg="Handshake message sent" cached=true handshake="map[stage:2 style:ix_psk0]" relay=172.0.0.2 vpnIp=172.0.4.8
Oct 16 01:43:15 syslog nebula[149]: time="2023-10-16T01:43:15-06:00" level=info msg="Handshake message received" certName=proxy_2 fingerprint=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX handshake="map[stage:1 style:ix_psk0]" initiatorIndex=701286131 issuer=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX remoteIndex=0 responderIndex=0 udpAddr="<nil>" vpnIp=172.0.4.8
and then it repeats for thousands of lines. Maybe something broke on the other host. I'll ignore it for now and see if it happens again.
I've added the multiple IP addresses for the 172.0.0.2 lighthouse/relay back to the host's config. I'll post logs once the connection dies.
I've added the multiple IP addresses for the 172.0.0.2 lighthouse/relay back to the host's config. I'll post logs once the connection dies.
@Cyberes I'm not following. From your original report, I thought you were noting that with a single address, it worked, but that as soon as you added multiple and reloaded the process, it stopped working. I'm hearing you now say that you've added both addresses, reloaded it, and it's currently working. Did I misunderstand originally?
It sounds like the issue is really that at some point, it stops responding, and that's the issue you posted about just above?
I mean that I set the config back to how it was when I originally encountered the issue so that I can collect the logs.
@Cyberes I'm still a little confused. From the original ticket, I see:
The relevant part of my config looks like this:
static_host_map: 172.0.0.2: - xxx.example.com:4242 - xxx.xxx.245.206:4242 - xxx.xxx.181.204:4242 172.0.0.3: - xxx.xxx.118.198:4242
You demonstrated that with this config, you are failing to perform a handshake between 172.0.3.109 and 172.0.2.116. You stated that when you removed two of the entries from 172.0.0.2's list of IP addresses, you are able to successfully handshake. Is that right?
Where I am confused is that just above you stated:
I've added the multiple IP addresses for the 172.0.0.2 lighthouse/relay back to the host's config. I'll post logs once the connection dies.
It sounds like you are able to form a handshake, even with this config in place, but that you expect the connection to die eventually? If that's the case, it sounds like the scenario you're describing now differs from the original issue: a failure to handshake versus a successful handshake with a connection that dies later. Am I following you correctly?
Sorry for the confusion.
It sounds like you are able to form a handshake, even with this config in place, but that you expect the connection to die eventually?
Yes, that's what I'm seeing. After running for a few weeks, Nebula on the rsyslog host seems to be able to connect out and no hosts can connect to the rsyslog server.
If that's the case, it sounds like the scenario you're describing now differs from the original issue: a failure to handshake versus a successful handshake with a connection that dies later.
It seems to be the second case, a successful handshake with a connection that dies later. But I think where the confusion is coming from is that I noticed both cases happening. Let's wait for logs and then we can break this down further. I'll make a long, detailed post once I have more info for you.
Thanks for your patience!
Hey @Cyberes - I know this is an old ticket... are you still facing this issue? From the last comment, it sounds like we were waiting for logs. Thanks!
That work on tunnel reconnection seems to have fixed everything and I haven't had any issues since.