Project

General

Profile

Bug #2706

OsmoMSC crashes on LU with 'DBI: 1: near "AND": syntax error' for empty MSISDN

Added by msuraev 5 months ago. Updated 3 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
-
Target version:
-
Start date:
12/04/2017
Due date:
% Done:

100%

Resolution:

Description

The following was observed while testing edge with single phone (no voice/sms traffic):

...
<001e> vlr_lu_fsm.c:201 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_P
RES_COMPL
<001e> vlr_lu_fsm.c:404 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
<001e> vlr_lu_fsm.c:413 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TM
SI_CNF
<000a> a_iface_bssap.c:699 Rx BSC DT: 01 00 02 05 9b
<001f> a_iface_bssap.c:91 Found A subscriber for conn_id 26
<000a> a_iface_bssap.c:680 BSC sends layer 3 dtap (conn_id=26)
<001e> vlr.c:941 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
<001e> vlr_lu_fsm.c:1204 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_
TMSI_ACK
<001e> vlr_lu_fsm.c:329 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
<001e> vlr_lu_fsm.c:363 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
<001e> vlr_lu_fsm.c:739 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
<001e> vlr_lu_fsm.c:739 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(1416361685)[
0x5592eb0160c0]
<001e> vlr_lu_fsm.c:739 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_DONE}: Freeing instance
<001e> fsm.c:287 lu_compl_vlr_fsm(1416361685)[0x5592eb015e60]{LU_COMPL_VLR_S_DONE}: Deallocated
<001e> vlr_lu_fsm.c:706 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
<000d> db.c:188 DBI: 1: near "AND": syntax error
<000d> backtrace.c:47 backtrace() returned 30 addresses
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0xe83f) [0x5592e93ba83f]
<000d> backtrace.c:57   /usr/lib/libdbi.so.1(_error_handler+0x183) [0x7fdf8fdb7100]
<000d> backtrace.c:57   /usr/lib/libdbi.so.1(dbi_conn_queryf+0x146) [0x7fdf8fdb6196]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0xfdd5) [0x5592e93bbdd5]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0x1d61d) [0x5592e93c961d]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(osmo_signal_dispatch+0x3c) [0x7fdf90a62bec]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_state_chg+0x1a2) [0x7fdf90a65bb2]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0x21b54) [0x5592e93cdb54]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_dispatch+0x10f) [0x7fdf90a65dbf]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_state_chg+0x1a2) [0x7fdf90a65bb2]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_dispatch+0x10f) [0x7fdf90a65dbf]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_state_chg+0x1a2) [0x7fdf90a65bb2]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_dispatch+0x10f) [0x7fdf90a65dbf]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_dispatch+0x10f) [0x7fdf90a65dbf]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0x17103) [0x5592e93c3103]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0x214dd) [0x5592e93cd4dd]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0xdd83) [0x5592e93b9d83]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0xb3dc) [0x5592e93b73dc]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(_osmo_fsm_inst_dispatch+0x10f) [0x7fdf90a65dbf]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmo-sigtran.so.0(+0x11195) [0x7fdf901db195]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmo-sigtran.so.0(+0xee03) [0x7fdf901d8e03]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmo-sigtran.so.0(+0x11cd5) [0x7fdf901dbcd5]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmo-sigtran.so.0(+0x9933) [0x7fdf901d3933]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmo-sigtran.so.0(+0x14cd3) [0x7fdf901decd3]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmonetif.so.4(+0x8873) [0x7fdf8f233873]
<000d> backtrace.c:57   /usr/lib/x86_64-linux-gnu/libosmocore.so.9(osmo_select_main+0x21f) [0x7fdf90a6294f]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0xa96c) [0x5592e93b696c]
<000d> backtrace.c:57   /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1) [0x7fdf8f9f21c1]
<000d> backtrace.c:57   ./src/osmo-msc/osmo-msc(+0xabda) [0x5592e93b6bda]
<001e> subscr_conn.c:243 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
<001e> subscr_conn.c:243 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(1416361685)[0x5592eb015f90]
<001e> vlr_lu_fsm.c:1361 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
<001e> subscr_conn.c:243 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_DONE}: Freeing instance
<001e> fsm.c:287 vlr_lu_fsm(1416361685)[0x5592eb0160c0]{VLR_ULA_S_DONE}: Deallocated
<000a> a_iface.c:428 Sending clear command to BSC (conn_id=26)
<000a> a_iface_bssap.c:699 Rx BSC DT: 00 01 21
<000a> a_iface_bssap.c:629 Rx MSC DT1 BSSMAP CLEAR COMPLETE
<000a> a_iface_bssap.c:261 Releasing connection (conn_id=26)

Not sure how to reproduce this reliably, but this should be investigated by someone with more experience with OsmoMSC codebase.

History

#1 Updated by neels 5 months ago

  • Status changed from New to Feedback
  • Assignee set to msuraev
  • % Done changed from 0 to 90

Since the MSC is not concerned at all whether we use egprs, gprs or no gprs at all, I would argue that this must be independent from the gprs settting.

I wonder why then OsmoMSC works fine in our osmo-gsm-tester tests and so on.

<000d> db.c:188 DBI: 1: near "AND": syntax error

Unfortunately, we don't log the SQL that failed.

This appears to come from triggering signal S_SUBSCR_ATTACHED upon successful LU. It triggers db_sms_get_unsent_for_subscr() in sms_subscr_cb() -> sub_ready_for_sm() and does

        result = dbi_conn_queryf(conn,
                "SELECT * FROM SMS"    
                " WHERE sent IS NULL"  
                " AND dest_addr=%s" 
                " AND deliver_attempts <= %u" 
                " ORDER BY id LIMIT 1",
                vsub->msisdn, max_failed);

It appears that it fails after "dest_addr=<vsub->msisdn>".
a) the MSISDN should be quoted properly,
b) we don't really need to query for empty MSISDN.

So you probably have no phone number set for the subscriber, and our SMS db code is unable to handle that gracefully. Can you verify this by configuring an MSISDN in the HLR and see whether the error goes away?

I have submitted https://gerrit.osmocom.org/5183 https://gerrit.osmocom.org/5184

#2 Updated by neels 5 months ago

  • Subject changed from OsmoMSC reports backtrace to OsmoMSC crashes on LU with 'DBI: 1: near "AND": syntax error' for empty MSISDN

#3 Updated by msuraev 5 months ago

  • Status changed from Feedback to Resolved
  • % Done changed from 90 to 100

Tested with latest master - the error has been fixed.

#4 Updated by laforge 3 months ago

  • Status changed from Resolved to Closed

Also available in: Atom PDF