Project

General

Profile

Actions

Bug #4792

closed

TLV parsing problem during SNS-ADD / SNS-DEL

Added by laforge over 3 years ago. Updated over 3 years ago.

Status:
Resolved
Priority:
Urgent
Assignee:
Category:
libosmogb
Target version:
-
Start date:
10/09/2020
Due date:
% Done:

100%

Spec Reference:

Description

While executing PCU_Tests_SNS.TC_sns_add or TC_sns_del, we are seeing the following error message on stderr of osmo-pcu (using gprs_ns2):

Error during TLV Parse in [L2]> 0d 04 82 04 d2 17 05 88 7f 00 00 01 59 da 00 01  (gprs_ns2.c:881)
Error during TLV Parse in [L2]> 11 04 82 04 d2 18 05 88 7f 00 00 01 59 d9 00 01  (gprs_ns2.c:881)
Error during TLV Parse in [L2]> 0e 04 82 04 d2 19 05 88 7f 00 00 01 59 d9 00 c8  (gprs_ns2.c:881)

First of all, the question is whether those errors are errors in NS2 or erors in our TTCN3 tests.

Secondly, why are those TLV parsing errors written to stderr without any prefix? There's no subssystem/level/... printed in frot. Look at this example:

20201009144947177 DLNS DEBUG GPRS-NS2-VC[0x5634298c0e40]{UNBLOCKED}: Received Event UNITDATA (gprs_ns2_vc_fsm.c:647)
20201009144947177 DBSSGP DEBUG rx BVCI_PTP=1234 gprs_bssgp_rx_ptp (gprs_bssgp_pcu.cpp:483)
20201009144947177 DBSSGP DEBUG Rx BSSGP BVCI=1234 (PTP) FLOW-CONTROL-BVC-ACK (gprs_bssgp_pcu.cpp:279)
Error during TLV Parse in [L2]> 0d 04 82 04 d2 17 05 88 7f 00 00 01 59 da 00 01  (gprs_ns2.c:881)
20201009144957174 DBSSGP DEBUG Sending flow control info on BVCI 1234 (gprs_bssgp_pcu.cpp:917)
20201009144957175 DBSSGP DEBUG Computed BVC leak rate = 20000, num_pdch = 8, cs = CS-4 (gprs_bssgp_pcu.cpp:825)


Files

sns-add.png View sns-add.png 51.3 KB laforge, 10/09/2020 01:28 PM
TC_sns_add.pcap TC_sns_add.pcap 1.32 KB laforge, 10/09/2020 01:30 PM
Actions #1

Updated by laforge over 3 years ago

The SNS-ADD PDU is in my opinion correct. Wireshark also has no trouble decoding it:

I'm attaching a related pcap file for reference.

I'm a bit surprised this was not detected during local testing before submitting the patch for merge, given that we do have multiple existing test cases that trigger the problem.

Actions #2

Updated by laforge over 3 years ago

See https://gerrit.osmocom.org/c/libosmocore/+/20509 - this code could never have been tested even once.

Even with the patch applied, there's now a segfault:

20201009153944364 DLNS DEBUG NSEI=1234 Rx SNS PDU type SNS-ADD (gprs_ns2_sns.c:1370)
20201009153944364 DLNS DEBUG GPRS-NS2-SNS-BSS[0x555555643c30]{CONFIGURED}: Received Event ADD (gprs_ns2_sns.c:1393)
20201009153944364 DLGLOBAL DEBUG validating counter group 0x7ffff7f87780(ns:nsvc) with 12 counters (rate_ctr.c:87)
20201009153944364 DLNS DEBUG GPRS-NS2-VC[0x5555556f4690]{UNCONFIGURED}: Allocated (fsm.c:461)
20201009153944364 DLNS DEBUG GPRS-NS2-VC[0x5555556f4690]{UNCONFIGURED}: Received Event START (gprs_ns2_vc_fsm.c:595)
20201009153944364 DLNS DEBUG GPRS-NS2-VC[0x5555556f4690]{UNCONFIGURED}: state_chg to ALIVE (gprs_ns2_vc_fsm.c:223)
20201009153944364 DLNS DEBUG NSEI=1234 Tx NS ALIVE (NSVCI=0) (gprs_ns2_message.c:372)
20201009153944367 DLNS INFO Ignoring NS ALIVE ACK from newconnection for non-existing NS-VC (gprs_ns2.c:640)

Program received signal SIGSEGV, Segmentation fault.
ns2_create_vc (bind=bind@entry=0x5555556eff90, msg=msg@entry=0x5555556f2e20, logname=logname@entry=0x7ffff7f7f167 "newconnection", 
    reject=reject@entry=0x7fffffffdd68, success=success@entry=0x7fffffffdd60) at gprs_ns2.c:698
698             nse = gprs_ns2_nse_by_nsei(bind->nsi, nsei);
(gdb) bt full
#0  ns2_create_vc (bind=bind@entry=0x5555556eff90, msg=msg@entry=0x5555556f2e20, logname=logname@entry=0x7ffff7f7f167 "newconnection", 
    reject=reject@entry=0x7fffffffdd68, success=success@entry=0x7fffffffdd60) at gprs_ns2.c:698
        nsh = <optimized out>
        tp = {lv = {{len = 0, val = 0x0} <repeats 256 times>}}
        nsvc = <optimized out>
        nse = <optimized out>
        nsvci = <optimized out>
        nsei = <error reading variable nsei (Cannot access memory at address 0x0)>
        rc = <optimized out>
#1  0x00007ffff7f710c4 in handle_nsip_read (bfd=0x55555565e680) at gprs_ns2_udp.c:223
        nsvc = 0x0
        msg = 0x5555556f2e20
        rc = <optimized out>
        error = <optimized out>
        bind = 0x5555556eff90
        saddr = {u = {sa = {sa_family = 2, sa_data = "Y\332\177\000\000\001\000\000\000\000\000\000\000"}, sas = {ss_family = 2, 
              __ss_padding = "Y\332\177\000\000\001\000\000\000\000\000\000\000\000\036\000\000\000\000\000\000\000(>\347\367\377\177\000\000 h\200_\000\000\000\000\345\377\004\000\000\000\000\000\350\354^UUU\000\000\340\335\377\377\377\177\000\000\001\000\000\000\000\000\000\000i\b\375\367\377\177\000\000 h\200_\000\000\000\000i\b\375\367\377\177\000\000h\367\223\367\377\177\000\000\300\336\377\377\377\177\000\000\000\336\377\377\377\177\000", 
              __ss_align = 140737352515625}, sin = {sin_family = 2, sin_port = 55897, sin_addr = {s_addr = 16777343}, 
              sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 55897, sin6_flowinfo = 16777343, sin6_addr = {__in6_u = {
                  __u6_addr8 = "\000\000\000\000\000\000\000\000\036\000\000\000\000\000\000", __u6_addr16 = {0, 0, 0, 0, 30, 0, 0, 0}, __u6_addr32 = {0, 0, 
                    30, 0}}}, sin6_scope_id = 4159127080}}}
        reject = 0x10
        rc = <optimized out>
        error = <optimized out>
        bind = <optimized out>
        saddr = <optimized out>
        nsvc = <optimized out>
        msg = <optimized out>
        reject = <optimized out>

I'm stopping here. please fix.

Actions #3

Updated by lynxis over 3 years ago

  • Status changed from New to In Progress

I've found the crash and reverted the commit.
The crash was only a side track. The root problem is the NS2 code can't find the correct NS-VC for the just added NS-VC.

Actions #4

Updated by lynxis over 3 years ago

  • Status changed from In Progress to Feedback
  • % Done changed from 0 to 100
Actions #5

Updated by lynxis over 3 years ago

https://gerrit.osmocom.org/c/libosmocore/+/20568 gprs_ns2: fix empty prefix in TLV Parse error

Actions #6

Updated by laforge over 3 years ago

  • Status changed from Feedback to Resolved

all three patches merged, marking as resolved.

Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)