Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error while register node #50

Closed
momaek opened this issue Jul 13, 2021 · 23 comments
Closed

Error while register node #50

momaek opened this issue Jul 13, 2021 · 23 comments

Comments

@momaek
Copy link

momaek commented Jul 13, 2021

I've setup headscale(v0.3.3) on my Ubuntu 18.04 VM.
This is my config.json:

{
    "server_url": "http://127.0.0.1:8000",
    "listen_addr": "0.0.0.0:8000",
    "private_key_path": "/etc/wireguard/privatekey",
    "derp_map_path": "derp.yaml",
    "ephemeral_node_inactivity_timeout": "30m",
    "db_type": "postgres",
    "db_host": "localhost",
    "db_port": 5432,
    "db_name": "headscale",
    "db_user": "headscale",
    "db_pass": "BZv1XGkrC7dlzjudJy0J",
    "tls_letsencrypt_hostname": "",
    "tls_letsencrypt_cache_dir": ".cache",
    "tls_letsencrypt_challenge_type": "HTTP-01",
    "tls_cert_path": "",
    "tls_key_path": "",
    "acl_policy_path": ""
}

And I've created a namespace.

When I try to register a node from another vm, I got an output key and I manual registered on my headscale vm:
image

But nothing changed on my tailscale vm. screenshot below:

image

No success response

@juanfont
Copy link
Owner

Hi!

I am not being able to replicate this.

Can you paste the logs of headscale serve ?

@momaek
Copy link
Author

momaek commented Jul 14, 2021

[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:	export GIN_MODE=release
 - using code:	gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /key                      --> github.com/juanfont/headscale.(*Headscale).KeyHandler-fm (3 handlers)
[GIN-debug] GET    /register                 --> github.com/juanfont/headscale.(*Headscale).RegisterWebAPI-fm (3 handlers)
[GIN-debug] POST   /machine/:id/map          --> github.com/juanfont/headscale.(*Headscale).PollNetMapHandler-fm (3 handlers)
[GIN-debug] POST   /machine/:id              --> github.com/juanfont/headscale.(*Headscale).RegistrationHandler-fm (3 handlers)
[GIN-debug] Listening and serving HTTP on 0.0.0.0:8000
[GIN] 2021/07/13 - 14:41:13 | 200 |      10.933µs |       127.0.0.1 | GET      "/key"
[GIN] 2021/07/13 - 14:52:42 | 404 |         841ns |  122.228.235.37 | GET      "/"
[GIN] 2021/07/13 - 14:53:17 | 200 |      40.751µs |  122.228.235.37 | GET      "/key"
2021/07/13 14:53:17 New Machine!
2021/07/13 14:53:17 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:17 | 200 |    5.048844ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:17 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:17 | 200 |      899.77µs |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:17 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:17 | 200 |     833.998µs |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:17 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:17 | 200 |    1.064822ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:17 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:17 | 200 |    1.044999ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:17 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:17 | 200 |    1.122197ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:17 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:17 | 200 |    1.006174ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:18 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:18 | 200 |     990.494µs |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:18 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:18 | 200 |    1.061863ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:19 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:19 | 200 |    1.112326ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:20 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:20 | 200 |    1.049061ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:21 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:21 | 200 |    1.055216ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:22 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:22 | 200 |    1.084824ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:24 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:24 | 200 |      985.07µs |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:25 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:25 | 200 |    1.336628ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:27 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:27 | 200 |    1.106841ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:29 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:29 | 200 |    1.005188ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:30 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:30 | 200 |    1.065916ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:33 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:33 | 200 |    1.127932ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:36 [awxt-aaaw] Not registered and not NodeKey rotation. Sending a authurl to register
[GIN] 2021/07/13 - 14:53:36 | 200 |    1.164391ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:40 [awxt-aaaw] Client is registered and we have the current NodeKey. All clear to /map
[GIN] 2021/07/13 - 14:53:40 | 200 |    4.058121ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537"
2021/07/13 14:53:40 [awxt-aaaw] ReadOnly=true   OmitPeers=false    Stream=true
2021/07/13 14:53:40 [awxt-aaaw] Client is starting up. Asking for DERP map
[GIN] 2021/07/13 - 14:53:40 | 200 |    6.833069ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537/map"
2021/07/13 14:53:40 [awxt-aaaw] ReadOnly=true   OmitPeers=false    Stream=true
2021/07/13 14:53:40 [awxt-aaaw] Client is starting up. Asking for DERP map
[GIN] 2021/07/13 - 14:53:40 | 200 |    7.011296ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537/map"
2021/07/13 14:53:40 [awxt-aaaw] ReadOnly=true   OmitPeers=false    Stream=true
2021/07/13 14:53:40 [awxt-aaaw] Client is starting up. Asking for DERP map
[GIN] 2021/07/13 - 14:53:40 | 200 |    4.396302ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537/map"
2021/07/13 14:53:40 [awxt-aaaw] ReadOnly=false   OmitPeers=false    Stream=true
2021/07/13 14:53:40 [awxt-aaaw] Client is ready to access the tailnet
2021/07/13 14:53:40 [awxt-aaaw] Sending initial map
2021/07/13 14:53:40 [awxt-aaaw] Notifying peers
2021/07/13 14:53:40 [awxt-aaaw] Sending data (1598 bytes)
2021/07/13 14:53:40 [awxt-aaaw] Sending keepalive
2021/07/13 14:53:40 [awxt-aaaw] Sending data (75 bytes)
2021/07/13 14:53:41 [awxt-aaaw] The client has closed the connection
[GIN] 2021/07/13 - 14:53:41 | 200 |   27.610709ms |  122.228.235.37 | POST     "/machine/6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537/map"
2021/07/13 14:53:41 [awxt-aaaw] ReadOnly=false   OmitPeers=false    Stream=true
2021/07/13 14:53:41 [awxt-aaaw] Client is ready to access the tailnet
2021/07/13 14:53:41 [awxt-aaaw] Sending initial map
2021/07/13 14:53:41 [awxt-aaaw] Notifying peers
2021/07/13 14:53:41 [awxt-aaaw] Sending data (1598 bytes)
2021/07/13 14:53:41 [awxt-aaaw] Sending keepalive
2021/07/13 14:53:41 [awxt-aaaw] Sending data (75 bytes)
2021/07/13 14:54:41 [awxt-aaaw] Sending keepalive
2021/07/13 14:54:41 [awxt-aaaw] Sending data (75 bytes)
2021/07/13 14:55:41 [awxt-aaaw] Sending keepalive
2021/07/13 14:55:41 [awxt-aaaw] Sending data (75 bytes)
2021/07/13 14:56:41 [awxt-aaaw] Sending keepalive

2021/07/13 14:53:41 [awxt-aaaw] The client has closed the connection this log is so weird..........

@juanfont
Copy link
Owner

Ok. This is weird. Did your node remained hanged, and showing the register URL?

The client has closed the connection

Thats a perfectly normal log message. Clients poke the server multiple times as part of their initialization...

@momaek
Copy link
Author

momaek commented Jul 14, 2021

Yes, after showing the register URL, it hangs .. Nothing output

@juanfont
Copy link
Owner

Can you please send me the output of these commands?

In the client:

tailscale status

In the server:

headscale -n wentx nodes list -o json

@momaek
Copy link
Author

momaek commented Jul 14, 2021

tailscale status:

root@awxt-aaaw:~# tailscale status
Logged out.

Log in at: http://127.0.0.1:8000/register?key=6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537

headscale -n wentx nodes list -o json :

ubuntu@VM-4-11-ubuntu:~$ sudo headscale -n wentx nodes list -o json
[
	{
		"ID": 1,
		"MachineKey": "6b81abd8292b2edfe86720f53c25f4fa3c968974df844b9b99238f800588d537",
		"NodeKey": "523aec74972f1477d63712705de9db24d32f8852765170f1ac72b446fd38cb50",
		"DiscoKey": "89e37ceee33501990c4becce8ecbf52f2c49a65757a4b81a7f8a3c8e63c4f450",
		"IPAddress": "100.127.105.139",
		"Name": "awxt-aaaw",
		"NamespaceID": 1,
		"Namespace": {
			"ID": 0,
			"CreatedAt": "0001-01-01T00:00:00Z",
			"UpdatedAt": "0001-01-01T00:00:00Z",
			"DeletedAt": null,
			"Name": ""
		},
		"Registered": true,
		"RegisterMethod": "cli",
		"AuthKeyID": 0,
		"AuthKey": null,
		"LastSeen": "2021-07-14T23:26:44.203438+08:00",
		"Expiry": "0001-01-01T08:05:43+08:05",
		"HostInfo": {
			"OS": "linux",
			"GoArch": "amd64",
			"NetInfo": {
				"PCP": false,
				"PMP": false,
				"UPnP": false,
				"WorkingUDP": true,
				"DERPLatency": {
					"1-v4": 0.214764163,
					"2-v4": 0.136939201,
					"3-v4": 0.330014741,
					"4-v4": 0.259974053,
					"5-v4": 0.315374518,
					"6-v4": 0.340824564,
					"7-v4": 0.248941838,
					"8-v4": 0.255692985,
					"9-v4": 0.176007433
				},
				"HairPinning": true,
				"WorkingIPv6": false,
				"PreferredDERP": 2,
				"MappingVariesByDestIP": false
			},
			"Hostname": "awxt-aaaw",
			"Services": [
				{
					"Port": 64569,
					"Proto": "peerapi4"
				}
			],
			"OSVersion": "Ubuntu 18.04.5 LTS (Bionic Beaver); kernel=4.15.0-144-generic; container",
			"IPNVersion": "1.10.1-t6b6016130-g49e1dcc20",
			"BackendLogID": "64b9694a57e0e228a490a1f35cc30f90e8c0ee747e4354dfc0fe283511c531e6"
		},
		"Endpoints": [
			"122.228.235.37:41641",
			"10.10.10.9:41641"
		],
		"EnabledRoutes": null,
		"CreatedAt": "2021-07-13T14:53:17.215468+08:00",
		"UpdatedAt": "2021-07-14T23:26:44.204246+08:00",
		"DeletedAt": null
	}
]

@juanfont
Copy link
Owner

I have been able to replicate it when running the tailscale client in the same machine as the headscale server. Is that your case?

@juanfont
Copy link
Owner

Can you try

sudo tailscale up --login-server http://localhost:8000 --force-reauth

@momaek
Copy link
Author

momaek commented Jul 15, 2021

I have been able to replicate it when running the tailscale client in the same machine as the headscale server. Is that your case?

Nop

Can you try

sudo tailscale up --login-server http://localhost:8000 --force-reauth

It hangs..

image

@momaek
Copy link
Author

momaek commented Jul 15, 2021

Does headscale have any dependencies? I'v installed wireguard on my headscale vm. I'll try without wireguard

@momaek
Copy link
Author

momaek commented Jul 15, 2021

It just the same.. tailscale hangs

I can grant an access to my vm. And you can try it yourself....

@juanfont
Copy link
Owner

juanfont commented Jul 15, 2021 via email

@faicker
Copy link

faicker commented Jul 30, 2021

The same problem on different host.
But it does work though tailscale status tell me logged out.
I can ping each other OK.

Both versions are the latest main branch.

@juanfont
Copy link
Owner

@faicker do you have nginx in front?

@faicker
Copy link

faicker commented Jul 31, 2021

no. @juanfont

@maddie
Copy link

maddie commented Aug 2, 2021

I've encountered the same problem, and it turns out it's because I have a tailscaled joined in the official network running. Starting headscale on a freshly spawned VM fixes the hang problem.

@kradalby kradalby mentioned this issue Aug 3, 2021
@kradalby
Copy link
Collaborator

kradalby commented Aug 3, 2021

I am running into a similar issue when registering many nodes in succession. It seems to me like there is a deadlock somewhere, potentially in the HTTP server.

What I have observed is:

I try to join 5 clients at the same time, 3 succeeds while 2 hangs, if I restart headscale while they are still hanging, it looks like the request gets retried and succeed.

It does not always succeed tho, so I suspect that if you restart and already connected clients try to talk to headscale, it gets busy again and blocks.

I tried to join about 13 hosts and I think I had to restart it 8-9 times over 20 minutes to get them all in.

@bharathmsd7
Copy link

I am running into a similar issue when registering many nodes in succession. It seems to me like there is a deadlock somewhere, potentially in the HTTP server.

What I have observed is:

I try to join 5 clients at the same time, 3 succeeds while 2 hangs, if I restart headscale while they are still hanging, it looks like the request gets retried and succeed.

It does not always succeed tho, so I suspect that if you restart and already connected clients try to talk to headscale, it gets busy again and blocks.

I tried to join about 13 hosts and I think I had to restart it 8-9 times over 20 minutes to get them all in.

+1

Facing the same issue
After restarting headscale the new peer is connected but some peers not getting update about the new peer connection,
running tailscale status doesn't shows the new peer. Logging out and logging in the old peer in solves this issue but it again hangs needs to restart headscale for everytime.

@juanfont
Copy link
Owner

juanfont commented Aug 5, 2021

@bharathmsd7
Copy link

@bharathmsd7 @momaek @faicker Can you please try with v0.5.0? https://github.com/juanfont/headscale/releases/tag/v0.5.0

This works man, Deadlock is not occurring now.
But my peers which are already connected doesn't get any update on newly connected peer.
tailscale status not updating newly joining peers.

@kradalby
Copy link
Collaborator

kradalby commented Aug 6, 2021

Ah yes, I see what you mean, it get it on some of the first joined nodes.

I will try to do a dive into it, it would definitively benefit us with some integration tests, just need to find a clever way to wire them up.

@juanfont
Copy link
Owner

This is fixed now in 0.7.

@mbugert
Copy link

mbugert commented Jan 26, 2022

For the record, I ran into the same issue as OP using headscale v0.12.3 and tailscale 1.20.2 on a bunch of Debian VMs. The issues I saw were tailscale up on clients not printing "Success" and just hanging indefinitely, tailscale up --force-reauth hanging as well, and tailscale status saying state=Starting, wantRunning=true.
The problem was that my headscale server and tailscale client were running in a local network without WAN access (I had used the host-only adapter network mode in virtualbox). Giving them WAN access (NAT network mode) fixed it for me.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants