search

omec-project / nrf

1 stars 15 forks source link

NRF panics during deregistration #127

Closed gatici closed 1 month ago

gatici commented 1 month ago

NRF version: 1.4.2 NRF panics when handing a deregistration request: This situation needs to be handled properly. NRF logs:

2024-09-26T09:12:49.364Z [nrf] 2024-09-26T09:12:49Z [INFO][NRF][MGMT] Handle UpdateNFInstanceRequest
2024-09-26T09:12:49.387Z [nrf] 2024-09-26T09:12:49Z [INFO][NRF][MGMT] nf profile [UDM] update success
2024-09-26T09:12:49.387Z [nrf] 2024-09-26T09:12:49Z [INFO][NRF][GIN] | 200 |     10.1.146.40 | PATCH   | /nnrf-nfm/v1/nf-instances/b050e05b-8743-48e7-8b16-06187b002c86 |
2024-09-26T09:12:50.165Z [pebble] Cannot flush logs to target "grafana-agent/0": Post "http://grafana-agent-0.grafana-agent-endpoints.sdcore.svc.cluster.local:3500/loki/api/v1/push": dial tcp 10.1.146.9:3500: connect: connection refused
2024-09-26T09:12:51.790Z [nrf] 2024-09-26T09:12:51Z [INFO][NRF][MGMT] Handle NFDeregisterRequest
2024-09-26T09:12:52.791Z [pebble] Cannot flush logs to target "grafana-agent/0": Post "http://grafana-agent-0.grafana-agent-endpoints.sdcore.svc.cluster.local:3500/loki/api/v1/push": dial tcp 10.1.146.9:3500: connect: connection refused
2024-09-26T09:12:52.792Z [nrf] 2024-09-26T09:12:52Z [ERRO][NRF][GIN] [Debugging] panic:
2024-09-26T09:12:52.792Z [nrf] DELETE /nnrf-nfm/v1/nf-instances/79a14804-526e-45e7-a3a2-839ba64fca7c HTTP/2.0
2024-09-26T09:12:52.792Z [nrf] Host: nrf:29510
2024-09-26T09:12:52.792Z [nrf] Accept-Encoding: gzip
2024-09-26T09:12:52.792Z [nrf] Content-Type: application/json
2024-09-26T09:12:52.792Z [nrf] User-Agent: OpenAPI-Generator/1.0.0/go
2024-09-26T09:12:52.792Z [nrf] 
2024-09-26T09:12:52.792Z [nrf] 
2024-09-26T09:12:52.792Z [nrf] runtime error: index out of range [0] with length 0
2024-09-26T09:12:52.792Z [nrf] goroutine 20406 [running]:
2024-09-26T09:12:52.792Z [nrf] runtime/debug.Stack()
2024-09-26T09:12:52.792Z [nrf]  /snap/go/10678/src/runtime/debug/stack.go:24 +0x5e
2024-09-26T09:12:52.792Z [nrf] github.com/omec-project/util/logger.NewGinWithLogrus.ginRecover.func2.1()
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/omec-project/util@v1.1.0/logger/logger.go:248 +0x117
2024-09-26T09:12:52.792Z [nrf] panic({0xe6f800?, 0xc0004a9308?})
2024-09-26T09:12:52.792Z [nrf]  /snap/go/10678/src/runtime/panic.go:914 +0x21f
2024-09-26T09:12:52.792Z [nrf] github.com/omec-project/nrf/producer.NFDeregisterProcedure({0xc00081c99a, 0x24})
2024-09-26T09:12:52.792Z [nrf]  /root/parts/nrf/build/producer/nf_management.go:275 +0x5e5
2024-09-26T09:12:52.792Z [nrf] github.com/omec-project/nrf/producer.HandleNFDeregisterRequest(0xc0002a0ab0)
2024-09-26T09:12:52.792Z [nrf]  /root/parts/nrf/build/producer/nf_management.go:33 +0x85
2024-09-26T09:12:52.792Z [nrf] github.com/omec-project/nrf/management.HTTPDeregisterNFInstance(0xc000231200)
2024-09-26T09:12:52.792Z [nrf]  /root/parts/nrf/build/management/api_nf_instance_id_document.go:35 +0x12f
2024-09-26T09:12:52.792Z [nrf] github.com/gin-gonic/gin.(*Context).Next(0xc000231200)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/gin-gonic/gin@v1.10.0/context.go:185 +0x2b
2024-09-26T09:12:52.792Z [nrf] github.com/omec-project/util/logger.NewGinWithLogrus.ginRecover.func2(0x0?)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/omec-project/util@v1.1.0/logger/logger.go:280 +0x57
2024-09-26T09:12:52.792Z [nrf] github.com/gin-gonic/gin.(*Context).Next(0xc000231200)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/gin-gonic/gin@v1.10.0/context.go:185 +0x2b
2024-09-26T09:12:52.792Z [nrf] github.com/omec-project/util/logger.NewGinWithLogrus.ginToLogrus.func1(0xc000231200)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/omec-project/util@v1.1.0/logger/logger.go:215 +0x5f
2024-09-26T09:12:52.792Z [nrf] github.com/gin-gonic/gin.(*Context).Next(...)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/gin-gonic/gin@v1.10.0/context.go:185
2024-09-26T09:12:52.792Z [nrf] github.com/gin-gonic/gin.(*Engine).handleHTTPRequest(0xc000102b60, 0xc000231200)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/gin-gonic/gin@v1.10.0/gin.go:633 +0x892
2024-09-26T09:12:52.792Z [nrf] github.com/gin-gonic/gin.(*Engine).ServeHTTP(0xc000102b60, {0x10ae870?, 0xc00069c1c8}, 0xc000c99700)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/github.com/gin-gonic/gin@v1.10.0/gin.go:589 +0x1dd
2024-09-26T09:12:52.792Z [nrf] golang.org/x/net/http2/h2c.h2cHandler.ServeHTTP({{0x10a8380?, 0xc000102b60?}, 0xc00055c4b0?}, {0x10ae870, 0xc00069c1c8}, 0xc000c99700)
2024-09-26T09:12:52.792Z [nrf]  /root/go/pkg/mod/golang.org/x/net@v0.25.0/http2/h2c/h2c.go:125 +0x68e
2024-09-26T09:12:52.792Z [nrf] net/http.serverHandler.ServeHTTP({0x6bdae0?}, {0x10ae870?, 0xc00069c1c8?}, 0xc00054ab60?)
2024-09-26T09:12:52.792Z [nrf]  /snap/go/10678/src/net/http/server.go:2943 +0x8e
2024-09-26T09:12:52.792Z [nrf] net/http.initALPNRequest.ServeHTTP({{0x10b00c0?, 0xc000631aa0?}, 0xc0009b6000?, {0xc0005420f0?}}, {0x10ae870, 0xc00069c1c8}, 0xc000c99700)
2024-09-26T09:12:52.792Z [nrf]  /snap/go/10678/src/net/http/server.go:3551 +0x231
2024-09-26T09:12:52.792Z [nrf] net/http.(*http2serverConn).runHandler(0xc0004882c0?, 0x10b01d8?, 0x174b2e0?, 0xc0007d6b80?)
2024-09-26T09:12:52.792Z [nrf]  /snap/go/10678/src/net/http/h2_bundle.go:6232 +0xbb
2024-09-26T09:12:52.792Z [nrf] created by net/http.(*http2serverConn).scheduleHandler in goroutine 20419
2024-09-26T09:12:52.792Z [nrf]  /snap/go/10678/src/net/http/h2_bundle.go:6167 +0x21d
2024-09-26T09:12:52.792Z [nrf] 2024-09-26T09:12:52Z [INFO][NRF][GIN] | 500 |     10.1.146.11 | DELETE  | /nnrf-nfm/v1/nf-instances/79a14804-526e-45e7-a3a2-839ba64fca7c |
2024-09-26T09:12:53.793Z [pebble] Cannot flush logs to target "grafana-agent/0": Post "http://grafana-agent-0.grafana-agent-endpoints.sdcore.svc.cluster.local:3500/loki/api/v1/push": dial tcp 10.1.146.9:3500: connect: connection refused
2024-09-26T09:12:54.165Z [nrf] 2024-09-26T09:12:54Z [ERRO][Config5g][GRPC] Connectivity status idle, trying to connect again
2024-09-26T09:12:55.167Z [pebble] Cannot flush logs to target "grafana-agent/0": Post "http://grafana-agent-0.grafana-agent-endpoints.sdcore.svc.cluster.local:3500/loki/api/v1/push": dial tcp 10.1.146.9:3500: connect: connection refused
2024-09-26T09:12:57.856Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][MGMT] Handle NFRegisterRequest
2024-09-26T09:12:57.856Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][MGMT] HearBeat Timer value: 60 sec
2024-09-26T09:12:57.861Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][MGMT] urilist update
2024-09-26T09:12:57.865Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][MGMT] Create NF Profile  PCF
2024-09-26T09:12:57.866Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][MGMT] Location header:  https://nrf:29510/nnrf-nfm/v1/nf-instances/e541eeec-d7fd-4a78-b52b-07036427ad50
2024-09-26T09:12:57.866Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][GIN] | 201 |     10.1.146.11 | PUT     | /nnrf-nfm/v1/nf-instances/e541eeec-d7fd-4a78-b52b-07036427ad50 |
2024-09-26T09:12:57.868Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][DSCV] Handle NFDiscoveryRequest
2024-09-26T09:12:57.869Z [nrf] 2024-09-26T09:12:57Z [INFO][NRF][GIN] | 200 |     10.1.146.11 | GET     | /nnrf-disc/v1/nf-instances?requester-nf-type=PCF&service-names=nudr-dr&target-nf-type=UDR |

SMF logs:

2024-09-26T09:30:35.219Z [pebble] GET /v1/changes/2/wait?timeout=4.000s 2.111043275s 200
2024-09-26T09:30:35.256Z [pebble] POST /v1/services 24.123726ms 202
2024-09-26T09:30:35.275Z [smf] 2024-09-26T09:30:35Z [INFO][SMF][Init] terminating SMF...
2024-09-26T09:30:35.275Z [smf] 2024-09-26T09:30:35Z [INFO][SMF][Consumer] Send Deregister NFInstance
2024-09-26T09:30:36.277Z [pebble] Cannot flush logs to target "grafana-agent/0": Post "http://grafana-agent-0.grafana-agent-endpoints.sdcore.svc.cluster.local:3500/loki/api/v1/push": dial tcp 10.1.146.38:3500: connect: connection refused
2024-09-26T09:30:36.282Z [smf] 2024-09-26T09:30:36Z [ERRO][SMF][Init] deregister NF instance Error[500 is not a valid status code in DeregisterNFInstance]
2024-09-26T09:30:36.284Z [pebble] Service "smf" stopped
2024-09-26T09:30:36.328Z [pebble] Service "smf" starting: /bin/smf -smfcfg /etc/smf/smfcfg.yaml -uerouting /etc/smf/uerouting.yaml
dariofaccin commented 1 month ago

This issue will be fixed by https://github.com/omec-project/nrf/pull/128