Project

General

Profile

Actions

Bug #1898

open

Wrong handover detection with l1sap on wrong ss=0/ts=0

Added by zecke over 7 years ago. Updated over 6 years ago.

Status:
Feedback
Priority:
Low
Assignee:
-
Category:
-
Target version:
-
Start date:
12/27/2016
Due date:
% Done:

50%

Spec Reference:

Description

So handover being detected on TS=0, SS=0... which is unlikely to be the right channel.. Need input validation and checking if the channel is allocated? But verify it.. not sure why it detects it like that.. Happens frequently at the 33C3

<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<0006> l1_if.c:700 SACCH for pchan 9?
<000a> handover.c:111 (bts=0,trx=0,ts=0,ss=0) RACH on dedicated channel received with TA=0
<0007> l1sap.c:1205 modifying channel chan_nr=0x20 trx=0
<000a> oml.c:1852 (bts=0,trx=0,ts=0,ss=0) modifying channel for handover
<0006> oml.c:1077 (bts=0,trx=0,ts=0,ss=0) MPH-ACTIVATE.req (hL2=0x000000bb, SDCCH TxDL)
<0007> l1_if.c:166 Tx L1 prim MPH-ACTIVATE.req
<0000> rsl.c:578 Sending HANDOver DETect

Program received signal SIGSEGV, Segmentation fault.
rslms_rx_rll_udata_req (msg=msg@entry=0xc0748, dl=dl@entry=0xb6fc14b0) at lapdm.c:855
855    lapdm.c: No such file or directory.
(gdb) bt
#0  rslms_rx_rll_udata_req (msg=msg@entry=0xc0748, dl=dl@entry=0xb6fc14b0) at lapdm.c:855
#1  0x4fcacb00 in rslms_rx_rll (lc=0xb6fc133c, msg=0xc0748) at lapdm.c:1154
#2  lapdm_rslms_recvmsg (msg=msg@entry=0xc0748, lc=lc@entry=0xb6fc1294) at lapdm.c:1223
#3  0x000279d4 in ho_tx_phys_info (lchan=lchan@entry=0xb6fc11ec) at handover.c:61
#4  0x00027cbc in handover_rach (lchan=0xb6fc11ec, ra=<optimized out>, acc_delay=acc_delay@entry=0 '\000') at handover.c:131
#5  0x0002a680 in l1sap_handover_rach (l1sap=<optimized out>, rach_ind=<optimized out>, rach_ind=<optimized out>, 
    rach_ind=<optimized out>, trx=0xb6fbd038) at l1sap.c:659
#6  l1sap_ph_rach_ind (rach_ind=0xbf4fc, l1sap=0xbf4ec, trx=0xb6fbd038) at l1sap.c:974
#7  l1sap_up (trx=trx@entry=0xb6fbd038, l1sap=l1sap@entry=0xbf4ec) at l1sap.c:1022
#8  0x0000d690 in handle_ph_ra_ind (l1p_msg=0xbf428, ra_ind=<optimized out>, fl1=0xbf428) at l1_if.c:1064
#9  l1if_handle_ind (fl1=<optimized out>, msg=msg@entry=0xbf428) at l1_if.c:1090
#10 0x0000dfc8 in l1if_handle_l1prim (wq=<optimized out>, fl1h=<optimized out>, msg=msg@entry=0xbf428) at l1_if.c:1144
#11 0x00017e48 in read_dispatch_one (queue=<optimized out>, msg=0xbf428, fl1h=<optimized out>) at l1_transp_hw.c:190
#12 l1if_fd_cb (ofd=0xb86d0, what=<optimized out>) at l1_transp_hw.c:224
#13 0x4fcd6330 in osmo_fd_disp_fds (_eset=0xbefffb48, _wset=0xbefffac8, _rset=0xbefffa48) at select.c:149
#14 osmo_select_main (polling=polling@entry=0) at select.c:189
#15 0x0002bf84 in bts_main (argc=<optimized out>, argv=<optimized out>) at main.c:349
#16 0x4fa61684 in __libc_start_main (main=0xbefffd84, argc=1337463808, argv=0x4fa61684 <__libc_start_main+276>, 
    init=<optimized out>, fini=0x2ec70 <__libc_csu_fini>, rtld_fini=0x4fa27dc4 <_dl_fini>, stack_end=0xbefffd84) at libc-start.c:269
#17 0x0000b8a4 in _start () at ../ports/sysdeps/arm/start.S:124
(gdb) frame 5
#5  0x0002a680 in l1sap_handover_rach (l1sap=<optimized out>, rach_ind=<optimized out>, rach_ind=<optimized out>, 
    rach_ind=<optimized out>, trx=0xb6fbd038) at l1sap.c:659
659    l1sap.c: No such file or directory.
#17 0x0000b8a4 in _start () at ../ports/sysdeps/arm/start.S:124
(gdb) frame 5
#5  0x0002a680 in l1sap_handover_rach (l1sap=<optimized out>, rach_ind=<optimized out>, rach_ind=<optimized out>, 
    rach_ind=<optimized out>, trx=0xb6fbd038) at l1sap.c:659
659    l1sap.c: No such file or directory.
(gdb) p lc
No symbol "lc" in current context.
(gdb) p lc^CQuit
(gdb) p *lchan
value has been optimized out
(gdb) p *rach_ind
value has been optimized out
(gdb) p rach_ind->chan_nr
value has been optimized out
(gdb) frame 6
#6  l1sap_ph_rach_ind (rach_ind=0xbf4fc, l1sap=0xbf4ec, trx=0xb6fbd038) at l1sap.c:974
974    in l1sap.c
(gdb) p *rach_ind
$1 = {chan_nr = 64 '@', ra = 0, acc_delay = 0 '\000', fn = 2107, is_11bit = 0 '\000', burst_type = GSM_L1_BURST_TYPE_ACCESS_0}
(gdb) frame 3
#3  0x000279d4 in ho_tx_phys_info (lchan=lchan@entry=0xb6fc11ec) at handover.c:61
61    handover.c: No such file or directory.
(gdb) p *lchan
$2 = {ts = 0xb6fc08f8, nr = 0 '\000', type = GSM_LCHAN_SDCCH, rsl_cmode = 0, tch_mode = GSM48_CMODE_SIGN, csd_mode = LCHAN_CSD_M_NT, 
  state = LCHAN_S_NONE, broken_reason = 0x0, bs_power = 0 '\000', ms_power = 0 '\000', encr = {alg_id = 0 '\000', 
    key_len = 0 '\000', key = '\000' <repeats 15 times>}, mr_ms_lv = "\000\000\000\000\000\000", 
  mr_bts_lv = "\000\000\000\000\000\000", sapis = "\000\000\000\000\000\000\000", sacch_deact = 0, abis_ip = {bound_ip = 0, 
    connect_ip = 0, bound_port = 0, connect_port = 0, conn_id = 0, rtp_payload = 0 '\000', rtp_payload2 = 0 '\000', 
    speech_mode = 0 '\000', rtp_socket = 0x0}, rqd_ta = 0 '\000', name = 0x6b778 "(bts=0,trx=0,ts=0,ss=0)", sapi_cmds = {
    next = 0xc0150, prev = 0xc0240}, sapis_dl = '\000' <repeats 22 times>, sapis_ul = '\000' <repeats 22 times>, lapdm_ch = {list = {
      next = 0x0, prev = 0x0}, name = 0x0, lapdm_acch = {datalink = {{dl = {send_dlsap = 0x0, send_ph_data_req = 0x0, 
            update_pending_frames = 0x0, cr = {loc2rem = {cmd = 0 '\000', resp = 0 '\000'}, rem2loc = {cmd = 0 '\000', 
                resp = 0 '\000'}}, mode = LAPD_MODE_USER, use_sabme = 0, reestablish = 0, n200 = 0, n200_est_rel = 0, lctx = {
              dl = 0x0, n201 = 0, cr = 0 '\000', sapi = 0 '\000', tei = 0 '\000', lpd = 0 '\000', format = 0 '\000', p_f = 0 '\000', 
              n_send = 0 '\000', n_recv = 0 '\000', s_u = 0 '\000', length = 0, more = 0 '\000'}, maxf = 0, k = 0 '\000', 
            v_range = 0 '\000', v_send = 0 '\000', v_ack = 0 '\000', v_recv = 0 '\000', state = 0, seq_err_cond = 0, 
            own_busy = 0 '\000', peer_busy = 0 '\000', t200_sec = 0, t200_usec = 0, t203_sec = 0, t203_usec = 0, t200 = {node = {
                rb_parent_color = 0, rb_right = 0x0, rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, timeout = {tv_sec = 0, 
                tv_usec = 0}, active = 0, cb = 0x0, data = 0x0}, t203 = {node = {rb_parent_color = 0, rb_right = 0x0, 
                rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, timeout = {tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, 
              data = 0x0}, retrans_ctr = 0 '\000', tx_queue = {next = 0x0, prev = 0x0}, send_queue = {next = 0x0, prev = 0x0}, 
            send_buffer = 0x0, send_out = 0, tx_hist = 0x0, range_hist = 0 '\000', rcv_buffer = 0x0, cont_res = 0x0}, mctx = {
            dl = 0x0, lapdm_fmt = 0, chan_nr = 0 '\000', link_id = 0 '\000', ta_ind = 0 '\000', tx_power_ind = 0 '\000'}, 
          entity = 0x0}, {dl = {send_dlsap = 0x0, send_ph_data_req = 0x0, update_pending_frames = 0x0, cr = {loc2rem = {
                cmd = 0 '\000', resp = 0 '\000'}, rem2loc = {cmd = 0 '\000', resp = 0 '\000'}}, mode = LAPD_MODE_USER, 
            use_sabme = 0, reestablish = 0, n200 = 0, n200_est_rel = 0, lctx = {dl = 0x0, n201 = 0, cr = 0 '\000', sapi = 0 '\000', 
              tei = 0 '\000', lpd = 0 '\000', format = 0 '\000', p_f = 0 '\000', n_send = 0 '\000', n_recv = 0 '\000', 
              s_u = 0 '\000', length = 0, more = 0 '\000'}, maxf = 0, k = 0 '\000', v_range = 0 '\000', v_send = 0 '\000', 
            v_ack = 0 '\000', v_recv = 0 '\000', state = 0, seq_err_cond = 0, own_busy = 0 '\000', peer_busy = 0 '\000', 
            t200_sec = 0, t200_usec = 0, t203_sec = 0, t203_usec = 0, t200 = {node = {rb_parent_color = 0, rb_right = 0x0, 
                rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, timeout = {tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, 
              data = 0x0}, t203 = {node = {rb_parent_color = 0, rb_right = 0x0, rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, 
              timeout = {tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, data = 0x0}, retrans_ctr = 0 '\000', tx_queue = {
              next = 0x0, prev = 0x0}, send_queue = {next = 0x0, prev = 0x0}, send_buffer = 0x0, send_out = 0, tx_hist = 0x0, 
            range_hist = 0 '\000', rcv_buffer = 0x0, cont_res = 0x0}, mctx = {dl = 0x0, lapdm_fmt = 0, chan_nr = 0 '\000', 
            link_id = 0 '\000', ta_ind = 0 '\000', tx_power_ind = 0 '\000'}, entity = 0x0}}, last_tx_dequeue = 0, tx_pending = 0, 
      mode = LAPDM_MODE_MS, flags = 0, l1_ctx = 0x0, l3_ctx = 0x0, l1_prim_cb = 0x0, l3_cb = 0x0, lapdm_ch = 0x0, ta = 0 '\000', 
      tx_power = 0 '\000'}, lapdm_dcch = {datalink = {{dl = {send_dlsap = 0x0, send_ph_data_req = 0x0, update_pending_frames = 0x0, 
            cr = {loc2rem = {cmd = 0 '\000', resp = 0 '\000'}, rem2loc = {cmd = 0 '\000', resp = 0 '\000'}}, mode = LAPD_MODE_USER, 
            use_sabme = 0, reestablish = 0, n200 = 0, n200_est_rel = 0, lctx = {dl = 0x0, n201 = 0, cr = 0 '\000', sapi = 0 '\000', 
              tei = 0 '\000', lpd = 0 '\000', format = 0 '\000', p_f = 0 '\000', n_send = 0 '\000', n_recv = 0 '\000', 
              s_u = 0 '\000', length = 0, more = 0 '\000'}, maxf = 0, k = 0 '\000', v_range = 0 '\000', v_send = 0 '\000', 
            v_ack = 0 '\000', v_recv = 0 '\000', state = 0, seq_err_cond = 0, own_busy = 0 '\000', peer_busy = 0 '\000', 
            t200_sec = 0, t200_usec = 0, t203_sec = 0, t203_usec = 0, t200 = {node = {rb_parent_color = 0, rb_right = 0x0, 
                rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, timeout = {tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, 
              data = 0x0}, t203 = {node = {rb_parent_color = 0, rb_right = 0x0, rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, 
              timeout = {tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, data = 0x0}, retrans_ctr = 0 '\000', tx_queue = {
              next = 0x0, prev = 0x0}, send_queue = {next = 0x0, prev = 0x0}, send_buffer = 0x0, send_out = 0, tx_hist = 0x0, 
            range_hist = 0 '\000', rcv_buffer = 0x0, cont_res = 0x0}, mctx = {dl = 0x0, lapdm_fmt = 0, chan_nr = 0 '\000', 
            link_id = 0 '\000', ta_ind = 0 '\000', tx_power_ind = 0 '\000'}, entity = 0x0}, {dl = {send_dlsap = 0x0, 
            send_ph_data_req = 0x0, update_pending_frames = 0x0, cr = {loc2rem = {cmd = 0 '\000', resp = 0 '\000'}, rem2loc = {
                cmd = 0 '\000', resp = 0 '\000'}}, mode = LAPD_MODE_USER, use_sabme = 0, reestablish = 0, n200 = 0, 
            n200_est_rel = 0, lctx = {dl = 0x0, n201 = 0, cr = 0 '\000', sapi = 0 '\000', tei = 0 '\000', lpd = 0 '\000', 
              format = 0 '\000', p_f = 0 '\000', n_send = 0 '\000', n_recv = 0 '\000', s_u = 0 '\000', length = 0, more = 0 '\000'}, 
            maxf = 0, k = 0 '\000', v_range = 0 '\000', v_send = 0 '\000', v_ack = 0 '\000', v_recv = 0 '\000', state = 0, 
            seq_err_cond = 0, own_busy = 0 '\000', peer_busy = 0 '\000', t200_sec = 0, t200_usec = 0, t203_sec = 0, t203_usec = 0, 
            t200 = {node = {rb_parent_color = 0, rb_right = 0x0, rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, timeout = {
                tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, data = 0x0}, t203 = {node = {rb_parent_color = 0, rb_right = 0x0, 
                rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, timeout = {tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, 
              data = 0x0}, retrans_ctr = 0 '\000', tx_queue = {next = 0x0, prev = 0x0}, send_queue = {next = 0x0, prev = 0x0}, 
            send_buffer = 0x0, send_out = 0, tx_hist = 0x0, range_hist = 0 '\000', rcv_buffer = 0x0, cont_res = 0x0}, mctx = {
            dl = 0x0, lapdm_fmt = 0, chan_nr = 0 '\000', link_id = 0 '\000', ta_ind = 0 '\000', tx_power_ind = 0 '\000'}, 
          entity = 0x0}}, last_tx_dequeue = 0, tx_pending = 0, mode = LAPDM_MODE_MS, flags = 0, l1_ctx = 0x0, l3_ctx = 0x0, 
      l1_prim_cb = 0x0, l3_cb = 0x0, lapdm_ch = 0x0, ta = 0 '\000', tx_power = 0 '\000'}}, dl_tch_queue = {next = 0xb6fc16c0, 
    prev = 0xb6fc16c0}, si = {valid = 0, last = 0, buf = {'\000' <repeats 22 times> <repeats 24 times>}}, meas = {flags = 0 '\000', 
    res_nr = 0 '\000', bts_tx_pwr = 0 '\000', num_ul_meas = 0 '\000', uplink = {{ber10k = 0, ta_offs_qbits = 0, c_i = 0, 
        is_sub = 0 '\000', inv_rssi = 0 '\000'} <repeats 104 times>}, l1_info = "\000", ul_res = {full = {rx_lev = 0 '\000', 
        rx_qual = 0 '\000'}, sub = {rx_lev = 0 '\000', rx_qual = 0 '\000'}}}, tch = {amr_mr = {gsm48_ie = "\000", ms_mode = {{
          mode = 0 '\000', threshold = 0 '\000', hysteresis = 0 '\000'}, {mode = 0 '\000', threshold = 0 '\000', 
          hysteresis = 0 '\000'}, {mode = 0 '\000', threshold = 0 '\000', hysteresis = 0 '\000'}, {mode = 0 '\000', 
          threshold = 0 '\000', hysteresis = 0 '\000'}}, bts_mode = {{mode = 0 '\000', threshold = 0 '\000', hysteresis = 0 '\000'}, 
        {mode = 0 '\000', threshold = 0 '\000', hysteresis = 0 '\000'}, {mode = 0 '\000', threshold = 0 '\000', 
          hysteresis = 0 '\000'}, {mode = 0 '\000', threshold = 0 '\000', hysteresis = 0 '\000'}}, num_modes = 0 '\000'}, dtx = {
      dl_amr_fsm = 0x0, cache = '\000' <repeats 19 times>, facch = '\000' <repeats 22 times>, len = 0 '\000', fn = 0, 
      is_update = false, ul_sid = false, dl_active = false}, last_cmr = 0 '\000', last_fn = 0}, ciph_state = 0 '\000', 
  ciph_ns = 0 '\000', loopback = 0 '\000', ho = {active = 2 '\002', ref = 0 '\000', t3105 = {node = {rb_parent_color = 0, 
        rb_right = 0x0, rb_left = 0x0}, list = {next = 0x0, prev = 0x0}, timeout = {tv_sec = 0, tv_usec = 0}, active = 0, cb = 0x0, 
      data = 0x0}, phys_info_count = 1}, s = 0, rel_act_kind = 0, rtp_tx_marker = false, ms_power_ctrl = {current = 0 '\000', 
    fixed = 0 '\000'}}
(gdb) frame 4         
#4  0x00027cbc in handover_rach (lchan=0xb6fc11ec, ra=<optimized out>, acc_delay=acc_delay@entry=0 '\000') at handover.c:131
131    in handover.c
(gdb) p ra
$3 = <optimized out>
(gdb) 
$4 = <optimized out>
(gdb) c
Continuing.

Program terminated with signal SIGSEGV, Segmentation fault.
The program no longer exists.
(gdb) 
Actions #1

Updated by zecke over 7 years ago

  • Description updated (diff)
Actions #2

Updated by zecke about 7 years ago

  • Priority changed from Normal to Urgent
Actions #3

Updated by laforge about 7 years ago

  • Assignee set to msuraev
Actions #4

Updated by msuraev about 7 years ago

Is there a way to reproduce this? Some particular phone or config? I can add input validation but would be nicer to digg out the root cause - why it gets detected there in a first place.

Actions #5

Updated by msuraev about 7 years ago

  • Status changed from New to In Progress
  • % Done changed from 0 to 20

Patches are sent for review in gerrit: 1959 should prevent segfault, 1960 checks for appropriate channel type.

Actions #7

Updated by zecke about 7 years ago

On 2 Mar 2017, at 19:33, msuraev [REDMINE] <> wrote:

Issue #1898 has been updated by msuraev.

Status changed from New to In Progress
% Done changed from 0 to 20

Patches are sent for review in gerrit: 1959 should prevent segfault, 1960 checks for appropriate channel type.

the point is that no handover is in progress ;)

Actions #8

Updated by msuraev about 7 years ago

zecke wrote:

the point is that no handover is in progress ;)

Do you have any ideas as to how to provoke this "no handover" situation?

Actions #9

Updated by msuraev about 7 years ago

  • Status changed from In Progress to Stalled

Gerrit 1960 is under review.

Actions #10

Updated by msuraev about 7 years ago

  • % Done changed from 20 to 50

Gerrit 1960 has been merged, so in theory it should be enough to workaround this error. However, we still don't know:
- how to reproduce this
- what's causing erroneous HO RACH detection

Actions #11

Updated by msuraev over 6 years ago

  • Status changed from Stalled to Feedback

Shall we wait for next congress to see if the issue would re-appear?

Actions #12

Updated by laforge over 6 years ago

  • Assignee deleted (msuraev)
Actions #13

Updated by laforge over 6 years ago

  • Priority changed from Urgent to Low
Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)