search

openziti / ngx_ziti_module

An NGINX module that allows OpenZiti to front upstream servers
Apache License 2.0
11 stars 0 forks source link

The identity is not loaded without daemon and master_process being set to off in the config file #5

Closed dariuszSki closed 1 year ago

dariuszSki commented 1 year ago

Experienced The service is not reachable with the following error on the client side:

/mnt/c/Users/dsliwinski/Repos/sdk-golang/example$ build/curlz https://akssand-d225fb69.4b98eb49-011c-426f-9ce3-edfa150aa84e.privatelink.centralus.azmk8s.io build/dariusz-curlz.json
panic: Get "https://akssand-d225fb69.4b98eb49-011c-426f-9ce3-edfa150aa84e.privatelink.centralus.azmk8s.io": unable to dial service 'akssand-d225fb69.4b98eb49-011c-426f-9ce3-edfa150aa84e.privatelink.centralus.azmk8s.io': dial failed: service 47clQA1FrqLNXEwB8RHxEX has no terminators
goroutine 1 [running]:
main.main()
        /mnt/c/Users/dsliwinski/Repos/sdk-golang/example/curlz/curlz.go:63 +0x105
dsliwinski:/mnt/c/Users/dsliwinski/Repos/sdk-golang/example$

No logs recorded in the nginx log error file related to Ziti

Expected Nginx process to run in daemon mode and able to reach services.

Reproduction

  1. Build the module using Build using CMake.
  2. Modify the existing conf file under configs/nginx.conf to comment out the following settings:

    daemon off;

    master_process off;

  3. Run this command: cmake-build/_deps/nginx/src/nginx/objs/nginx -c configs/nginx.conf -p .
  4. Build curlz using Build Examples
  5. Run Client Command: build/curlz https://akssand-d225fb69.4b98eb49-011c-426f-9ce3-edfa150aa84e.privatelink.centralus.azmk8s.io build/dariusz-curlz.json
dariuszSki commented 1 year ago

conf file details:

load_module cmake-build/ngx_ziti_module.so;

#error_log /dev/stderr debug;
error_log logs/error.log debug;

# development settings to keep nginx from starting in daemon mode and forking child processes
# do not use for non-dev deployments
#daemon off;
#master_process off;

thread_pool ngx_ziti_tp threads=32 max_queue=65536;

events {
    worker_connections  1024;
}

ziti myZitiInstaceNameUsedForLogging {
    identity_file /home/ziggy/azure-nginx-01.json;

    bind akssand-d225fb69.4b98eb49-011c-426f-9ce3-edfa150aa84e.privatelink.centralus.azmk8s.io {
        upstream akssand-d225fb69.4b98eb49-011c-426f-9ce3-edfa150aa84e.privatelink.centralus.azmk8s.io:443;
    }

    bind helloworld {
        upstream 10.17.1.114:5000;
    }

    bind 414523ab-69ab-47af-a99d-48467720a1c4.production.netfoundry.io {
        upstream 414523ab-69ab-47af-a99d-48467720a1c4.production.netfoundry.io:443;
    }
}
andrewpmartinez commented 1 year ago

Seems to work just fine. As a warning, when daemon is not specified (results in on) or is explicitly set to on, the starting command will exit and spawn a background process. It will appear that the process exits, but it should leave a process running in the background you can see via ps -x | grep nginx,

Edit: To clarify, I ran nginx loading the module dynamically with neither daemon nor master_process defined (so they default to on) and used a custom SDK client to reach the service.

dariuszSki commented 1 year ago

The issue that I came across is not that I can not run the nginx in the background. I can, but the ziti module is not working in that mode for me.

Here are logs when I run nginx in foreground.

2022/12/20 01:51:20 [notice] 99930#99930: using the "epoll" event method
2022/12/20 01:51:20 [notice] 99930#99930: nginx/1.23.2 (nginx-plus-r28)
2022/12/20 01:51:20 [notice] 99930#99930: built by gcc 11.2.0 (Ubuntu 11.2.0-19ubuntu1)
2022/12/20 01:51:20 [notice] 99930#99930: OS: Linux 5.15.0-1029-azure
2022/12/20 01:51:20 [notice] 99930#99930: getrlimit(RLIMIT_NOFILE): 1024:1048576
2022/12/20 01:51:20 [warn] 99930#99930: initializing block identity1
(99930)[        0.002]    INFO ziti_log_set_level set log level: root=1
2022/12/20 01:51:20 [info] 99930#99930: offloading service start for block identity1 service nginx-service-01
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 348d
2022/12/20 01:51:20 [debug] 99930#99938: writing to client
2022/12/20 01:51:20 [debug] 99930#99938: --wrote 2531d
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 1954d
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 86d
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 353d
2022/12/20 01:51:20 [debug] 99930#99938: writing to client
2022/12/20 01:51:20 [debug] 99930#99938: --wrote 55d
2022/12/20 01:51:20 [debug] 99930#99938: writing to client
2022/12/20 01:51:20 [debug] 99930#99938: --wrote 66d
2022/12/20 01:51:20 [debug] 99930#99938: writing to client
2022/12/20 01:51:20 [debug] 99930#99938: --wrote 8192d
2022/12/20 01:51:20 [debug] 99930#99938: writing to client
2022/12/20 01:51:20 [debug] 99930#99938: --wrote 1147d
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 31d
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 35d
2022/12/20 01:51:20 [debug] 99930#99938: closing, client disconnected
2022/12/20 01:51:20 [debug] 99930#99938: service client thread exited

Client kubectl call to get nodes info:

PS tmp>.\kubectl-windows-amd64.exe get nodes
NAME                                STATUS   ROLES   AGE    VERSION
aks-agentpool-15371798-vmss000000   Ready    agent   5d9h   v1.23.12
PS tmp>
dariuszSki commented 1 year ago

When I run in the background, the logs are:

ziggy@akssandeastus-nginx:~$ sudo systemctl start nginx
ziggy@akssandeastus-nginx:~$ ps -ef | grep nginx
root      100019       1  0 02:01 ?        00:00:00 nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf
root      100021  100019  0 02:01 ?        00:00:00 nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf
ziggy     100028   99286  0 02:01 pts/0    00:00:00 grep --color=auto nginx
ziggy@akssandeastus-nginx:~$

Nginx logs:

2022/12/20 01:51:20 [debug] 99930#99938: --wrote 8192d
2022/12/20 01:51:20 [debug] 99930#99938: writing to client
2022/12/20 01:51:20 [debug] 99930#99938: --wrote 1147d
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 31d
2022/12/20 01:51:20 [debug] 99930#99938: writing upstream
2022/12/20 01:51:20 [debug] 99930#99938: wrote 35d
2022/12/20 01:51:20 [debug] 99930#99938: closing, client disconnected
2022/12/20 01:51:20 [debug] 99930#99938: service client thread exited
2022/12/20 01:51:20 [debug] 99930#99938: --writing to client: 
2022/12/20 02:00:20 [notice] 99930#99930: signal 2 (SIGINT) received, exiting
2022/12/20 02:00:20 [info] 99930#99930: epoll_wait() failed (4: Interrupted system call)
2022/12/20 02:00:22 [notice] 99930#99930: signal 2 (SIGINT) received, exiting
2022/12/20 02:00:22 [notice] 99930#99930: signal 2 (SIGINT) received, exiting
2022/12/20 02:00:23 [notice] 99930#99930: signal 2 (SIGINT) received, exiting
2022/12/20 02:00:24 [notice] 99930#99930: signal 2 (SIGINT) received, exiting
2022/12/20 02:01:43 [notice] 100017#100017: using the "epoll" event method
2022/12/20 02:01:43 [notice] 100017#100017: nginx/1.23.2 (nginx-plus-r28)
2022/12/20 02:01:43 [notice] 100017#100017: built by gcc 11.2.0 (Ubuntu 11.2.0-19ubuntu1)
2022/12/20 02:01:43 [notice] 100017#100017: OS: Linux 5.15.0-1029-azure
2022/12/20 02:01:43 [notice] 100017#100017: getrlimit(RLIMIT_NOFILE): 1024:524288
2022/12/20 02:01:43 [notice] 100019#100019: start worker processes
2022/12/20 02:01:43 [notice] 100019#100019: start worker process 100021
ziggy@akssandeastus-nginx:~$

Client kubectl response logs:

PS tmp>.\kubectl-windows-amd64.exe get nodes
Unable to connect to the server: unable to dial service 'nginx-service-01': dial failed: service 1CjEXfTeYLFqLL6F0aZIA9 has no terminators
PS tmp>
dariuszSki commented 1 year ago

As you can see in the background mode that the ziti identity and service logs are not reported.

i.e. this from the foreground mode.

2022/12/20 01:51:20 [warn] 99930#99930: initializing block identity1
(99930)[        0.002]    INFO ziti_log_set_level set log level: root=1
2022/12/20 01:51:20 [info] 99930#99930: offloading service start for block identity1 service nginx-service-01
andrewpmartinez commented 1 year ago

It seems to work for me. I'm using this config:

load_module cmake-build-debug/ngx_ziti_module.so;

error_log /dev/stderr debug;
error_log logs/error.log debug;

daemon on;
master_process on;

thread_pool ngx_ziti_tp threads=32 max_queue=65536;

events {
    worker_connections  1024;
}

ziti myZitiInstaceNameUsedForLogging {
    identity_file /home/andrew/.zi/identities/http_host.json;

    bind http-service {
        upstream localhost:7070;
    }
}

and in the error log file I can see:

2022/12/19 14:19:10 [notice] 26312#26312: using the "epoll" event method
2022/12/19 14:19:10 [notice] 26312#26312: nginx/1.23.2
2022/12/19 14:19:10 [notice] 26312#26312: built by gcc 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04.1) 
2022/12/19 14:19:10 [notice] 26312#26312: OS: Linux 5.15.79.1-microsoft-standard-WSL2
2022/12/19 14:19:10 [notice] 26312#26312: getrlimit(RLIMIT_NOFILE): 1048576:1048576
2022/12/19 14:19:10 [notice] 26312#26312: start worker processes
2022/12/19 14:19:10 [notice] 26312#26312: start worker process 26317
2022/12/19 14:19:10 [warn] 26317#26317: initializing block myZitiInstaceNameUsedForLogging
2022/12/19 14:19:10 [info] 26317#26317: offloading service start for block myZitiInstaceNameUsedForLogging service http-service
2022/12/19 14:19:10 [emerg] 26317#26320: connection with the upstream server failed
2022/12/19 14:19:40 [debug] 26317#26321: writing upstream
2022/12/19 14:19:40 [debug] 26317#26321: wrote 93d
2022/12/19 14:19:40 [debug] 26317#26321: writing to client
2022/12/19 14:19:40 [debug] 26317#26321: --wrote 224d
2022/12/19 14:19:40 [debug] 26317#26321: writing upstream
2022/12/19 14:19:40 [debug] 26317#26321: wrote 93d
2022/12/19 14:19:40 [debug] 26317#26321: writing to client
2022/12/19 14:19:40 [debug] 26317#26321: --wrote 224d
2022/12/19 14:19:40 [debug] 26317#26321: writing upstream
2022/12/19 14:19:40 [debug] 26317#26321: wrote 93d
2022/12/19 14:19:40 [debug] 26317#26321: writing to client
2022/12/19 14:19:40 [debug] 26317#26321: --wrote 224d
2022/12/19 14:19:40 [debug] 26317#26321: closing, upstream disconnected

The 2022/12/19 14:19:10 [emerg] 26317#26320: connection with the upstream server failed is me testing the upstream going up/down was working in this mode.

andrewpmartinez commented 1 year ago

It turns out my testing was flawed. I had daemons running in the bg that were handling the requests - not the instance I was testing. I found the issue, PR to follow.