Bug #4959
closedProblems on NS-VC recovery
100%
Description
I have a test that first brings up all NS-VC / BVC as usual in our GBProxy_Tests.ttcn f_init().
It then- disables NSVC 101
- waits for 60s
- re-enables NSVC 101
- waits for another 30s
In the osmo-gbproxy log we can see about 50s after the NS-VC is disabled:
Tue Jan 19 18:32:33 2021 DLNS gprs_ns2_vc_fsm.c:209 GPRS-NS2-VC(UDP-NSE00101-remote-127_0_0_10:7777)[0x612000002aa0]{UNBLOCKED}: State change to ALIVE (T0, 3s) Tue Jan 19 18:32:33 2021 DGPRS gb_proxy.c:1348 NS-NSE 101 became unavailable
Furthermore, we can see that after the NS-VC is re-enabled in the tester:
Tue Jan 19 18:33:03 2021 DLNS gprs_ns2_vc_fsm.c:353 GPRS-NS2-VC(UDP-NSE00101-remote-127_0_0_10:7777)[0x612000002aa0]{ALIVE}: State change to UNBLOCKED (no timeout) Tue Jan 19 18:33:03 2021 DGPRS gb_proxy.c:1314 NS-NSE 101 became available
so great, the unavailability / availability is detected correctly by NS2, and osmo-gproxy also understands those events. Furthermore, this triggers a BVC-RESET of the signaling BVC, as expected:
ue Jan 19 18:33:03 2021 DLBSSGP gb_proxy.c:1320 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{UNBLOCKED}: Received Event REQ-RESET Tue Jan 19 18:33:03 2021 DLBSSGP bssgp_bvc_fsm.c:173 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{UNBLOCKED}: Tx BSSGP BVC-RESET Tue Jan 19 18:33:03 2021 DLBSSGP bssgp_bvc_fsm.c:514 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{UNBLOCKED}: State change to WAIT_RESET_ACK (no timeout) Tue Jan 19 18:33:03 2021 DGPRS gb_proxy.c:1351 NS: Unknown NS-STATUS.ind cause=NSVC recovery from NS Tue Jan 19 18:33:03 2021 DLNS gprs_ns2_vc_fsm.c:707 GPRS-NS2-VC(UDP-NSE00101-remote-127_0_0_10:7777)[0x612000002aa0]{UNBLOCKED}: Received Event UNITDATA Tue Jan 19 18:33:03 2021 DGPRS gb_proxy.c:1087 NSE(00101/SGSN)-BVC(00000/??) Rx BVC-RESET-ACK Tue Jan 19 18:33:03 2021 DLBSSGP gb_proxy.c:1127 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{WAIT_RESET_ACK}: Received Event RX-BVC-RESET-ACK Tue Jan 19 18:33:03 2021 DLBSSGP bssgp_bvc_fsm.c:264 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{WAIT_RESET_ACK}: Updating features: Advertised 0x0000, Received 0x0000, Negotiated 0x0000 Tue Jan 19 18:33:03 2021 DLBSSGP bssgp_bvc_fsm.c:392 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{WAIT_RESET_ACK}: State change to UNBLOCKED (no timeout)
However, now it gets interesting, as a second outage is detected where there is none:
Tue Jan 19 18:33:06 2021 DLNS gprs_ns2_vc_fsm.c:209 GPRS-NS2-VC(UDP-NSE00101-remote-127_0_0_10:7777)[0x612000002aa0]{UNBLOCKED}: State change to ALIVE (T0, 3s) Tue Jan 19 18:33:06 2021 DLNS gprs_ns2_message.c:381 NSEI=101 Tx NS ALIVE (NSVCI=0) Tue Jan 19 18:33:06 2021 DGPRS gb_proxy.c:1348 NS-NSE 101 became unavailable Tue Jan 19 18:33:06 2021 DLNS gprs_ns2_vc_fsm.c:703 GPRS-NS2-VC(UDP-NSE00101-remote-127_0_0_10:7777)[0x612000002aa0]{ALIVE}: Received Event ALIVE_ACK Tue Jan 19 18:33:06 2021 DLNS gprs_ns2_vc_fsm.c:353 GPRS-NS2-VC(UDP-NSE00101-remote-127_0_0_10:7777)[0x612000002aa0]{ALIVE}: State change to UNBLOCKED (no timeout) Tue Jan 19 18:33:06 2021 DGPRS gb_proxy.c:1314 NS-NSE 101 became available
which in turn of course generates another BVC-RESET:
Tue Jan 19 18:33:06 2021 DLBSSGP gb_proxy.c:1320 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{UNBLOCKED}: Received Event REQ-RESET Tue Jan 19 18:33:06 2021 DLBSSGP bssgp_bvc_fsm.c:173 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{UNBLOCKED}: Tx BSSGP BVC-RESET Tue Jan 19 18:33:06 2021 DLBSSGP bssgp_bvc_fsm.c:514 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{UNBLOCKED}: State change to WAIT_RESET_ACK (no timeout) Tue Jan 19 18:33:06 2021 DGPRS gb_proxy.c:1351 NS: Unknown NS-STATUS.ind cause=NSVC recovery from NS Tue Jan 19 18:33:06 2021 DLNS gprs_ns2_vc_fsm.c:707 GPRS-NS2-VC(UDP-NSE00101-remote-127_0_0_10:7777)[0x612000002aa0]{UNBLOCKED}: Received Event UNITDATA Tue Jan 19 18:33:06 2021 DGPRS gb_proxy.c:1087 NSE(00101/SGSN)-BVC(00000/??) Rx BVC-RESET-ACK Tue Jan 19 18:33:06 2021 DLBSSGP gb_proxy.c:1127 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{WAIT_RESET_ACK}: Received Event RX-BVC-RESET-ACK Tue Jan 19 18:33:06 2021 DLBSSGP bssgp_bvc_fsm.c:264 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{WAIT_RESET_ACK}: Updating features: Advertised 0x0000, Received 0x0000, Negotiated 0x0000 Tue Jan 19 18:33:06 2021 DLBSSGP bssgp_bvc_fsm.c:392 BSSGP-BVC(NSE00101-BVC00000)[0x612000001120]{WAIT_RESET_ACK}: State change to UNBLOCKED (no timeout)
where does that second NS-VC unavailable come from? Line 209 of gprs_ns2_vc_fsm.c points to a timeout. However, I don't understand why? Maybe the timer state is not properly cleared on recovery?
Related issues
Updated by laforge about 3 years ago
Testcase TC_nsvc_loss
is available in osmo-ttcn3-hacks.git
branch laforge/os4959
Updated by laforge about 3 years ago
- Related to Feature #4521: gbproxy: Redundancy between NS-VCs (SGSN Side) added
Updated by lynxis about 3 years ago
- Status changed from New to Feedback
- % Done changed from 0 to 90
Updated by lynxis about 3 years ago
- Status changed from Feedback to Resolved
- % Done changed from 90 to 100