@@ -23,6 +23,7 @@ enum {
DMGCP,
DHO,
DDB,
+ DSQL,
DREF,
DGPRS,
DNS,
@@ -115,6 +115,11 @@ static const struct log_info_cat default_categories[] = {
.description = "Database Layer",
.enabled = 1, .loglevel = LOGL_NOTICE,
},
+ [DSQL] = {
+ .name = "DSQL",
+ .description = "SQL Queries Tracing",
+ .enabled = 0, .loglevel = LOGL_DEBUG,
+ },
[DREF] = {
.name = "DREF",
.description = "Reference Counting",
@@ -185,6 +185,13 @@ void db_error_func(dbi_conn conn, void *data)
osmo_log_backtrace(DDB, LOGL_ERROR);
}
+/* Use macro instead of vararg function because recursive vararg use is impossible.
+ ##__VA_ARGS__ extension is not used in order to catch useless calls to dbi_conn_queryf()
+ instead of dbi_conn_query()
+*/
+#define trace_dbi_conn_queryf(c, f, ...) \
+ dbi_conn_queryf(c, f, __VA_ARGS__); do { LOGP(DSQL, LOGL_DEBUG, f "\n", __VA_ARGS__); } while(0)
+
static int update_db_revision_2(void)
{
dbi_result result;
@@ -507,7 +514,7 @@ struct gsm_subscriber *db_create_subscriber(const char *imsi)
/* Is this subscriber known in the db? */
subscr = db_get_subscriber(GSM_SUBSCRIBER_IMSI, imsi);
if (subscr) {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE Subscriber set updated = datetime('now') "
"WHERE imsi = %s " , imsi);
if (!result)
@@ -521,7 +528,7 @@ struct gsm_subscriber *db_create_subscriber(const char *imsi)
if (!subscr)
return NULL;
subscr->flags |= GSM_SUBSCRIBER_FIRST_CONTACT;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT INTO Subscriber "
"(imsi, created, updated) "
"VALUES "
@@ -548,7 +555,7 @@ static int get_equipment_by_subscr(struct gsm_subscriber *subscr)
const unsigned char *cm2, *cm3;
struct gsm_equipment *equip = &subscr->equipment;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT Equipment.* "
"FROM Equipment JOIN EquipmentWatch ON "
"EquipmentWatch.equipment_id=Equipment.id "
@@ -597,7 +604,7 @@ int db_get_authinfo_for_subscr(struct gsm_auth_info *ainfo,
dbi_result result;
const unsigned char *a3a8_ki;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT * FROM AuthKeys WHERE subscriber_id=%llu",
subscr->id);
if (!result)
@@ -630,7 +637,7 @@ int db_sync_authinfo_for_subscr(struct gsm_auth_info *ainfo,
/* Deletion ? */
if (ainfo == NULL) {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM AuthKeys WHERE subscriber_id=%llu",
subscr->id);
@@ -653,13 +660,13 @@ int db_sync_authinfo_for_subscr(struct gsm_auth_info *ainfo,
ainfo->a3a8_ki, ainfo->a3a8_ki_len, &ki_str);
if (!upd) {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT INTO AuthKeys "
"(subscriber_id, algorithm_id, a3a8_ki) "
"VALUES (%llu, %u, %s)",
subscr->id, ainfo->auth_algo, ki_str);
} else {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE AuthKeys "
"SET algorithm_id=%u, a3a8_ki=%s "
"WHERE subscriber_id=%llu",
@@ -683,7 +690,7 @@ int db_get_lastauthtuple_for_subscr(struct gsm_auth_tuple *atuple,
int len;
const unsigned char *blob;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT * FROM AuthLastTuples WHERE subscriber_id=%llu",
subscr->id);
if (!result)
@@ -739,7 +746,7 @@ int db_sync_lastauthtuple_for_subscr(struct gsm_auth_tuple *atuple,
/* Deletion ? */
if (atuple == NULL) {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM AuthLastTuples WHERE subscriber_id=%llu",
subscr->id);
@@ -766,7 +773,7 @@ int db_sync_lastauthtuple_for_subscr(struct gsm_auth_tuple *atuple,
atuple->kc, sizeof(atuple->kc), &kc_str);
if (!upd) {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT INTO AuthLastTuples "
"(subscriber_id, issued, use_count, "
"key_seq, rand, sres, kc) "
@@ -777,7 +784,7 @@ int db_sync_lastauthtuple_for_subscr(struct gsm_auth_tuple *atuple,
} else {
char *issued = atuple->key_seq == atuple_old.key_seq ?
"issued" : "datetime('now')";
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE AuthLastTuples "
"SET issued=%s, use_count=%u, "
"key_seq=%u, rand=%s, sres=%s, kc=%s "
@@ -839,7 +846,7 @@ struct gsm_subscriber *db_get_subscriber(enum gsm_subscriber_field field,
switch (field) {
case GSM_SUBSCRIBER_IMSI:
dbi_conn_quote_string_copy(conn, id, "ed);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
BASE_QUERY
"WHERE imsi = %s ",
quoted
@@ -848,7 +855,7 @@ struct gsm_subscriber *db_get_subscriber(enum gsm_subscriber_field field,
break;
case GSM_SUBSCRIBER_TMSI:
dbi_conn_quote_string_copy(conn, id, "ed);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
BASE_QUERY
"WHERE tmsi = %s ",
quoted
@@ -857,7 +864,7 @@ struct gsm_subscriber *db_get_subscriber(enum gsm_subscriber_field field,
break;
case GSM_SUBSCRIBER_EXTENSION:
dbi_conn_quote_string_copy(conn, id, "ed);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
BASE_QUERY
"WHERE extension = %s ",
quoted
@@ -866,7 +873,7 @@ struct gsm_subscriber *db_get_subscriber(enum gsm_subscriber_field field,
break;
case GSM_SUBSCRIBER_ID:
dbi_conn_quote_string_copy(conn, id, "ed);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
BASE_QUERY
"WHERE id = %s ", quoted);
free(quoted);
@@ -907,7 +914,7 @@ int db_subscriber_update(struct gsm_subscriber *subscr)
/* Copy the id to a string as queryf with %llu is failing */
sprintf(buf, "%llu", subscr->id);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
BASE_QUERY
"WHERE id = %s", buf);
@@ -949,7 +956,7 @@ int db_sync_subscriber(struct gsm_subscriber *subscriber)
q_tmsi = strdup("NULL");
if (subscriber->expire_lu == GSM_SUBSCRIBER_NO_EXPIRATION) {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE Subscriber "
"SET updated = datetime('now'), "
"name = %s, "
@@ -966,7 +973,7 @@ int db_sync_subscriber(struct gsm_subscriber *subscriber)
subscriber->lac,
subscriber->imsi);
} else {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE Subscriber "
"SET updated = datetime('now'), "
"name = %s, "
@@ -1003,7 +1010,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
{
dbi_result result;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM AuthKeys WHERE subscriber_id=%llu",
subscr->id);
if (!result) {
@@ -1013,7 +1020,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
}
dbi_result_free(result);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM AuthLastTuples WHERE subscriber_id=%llu",
subscr->id);
if (!result) {
@@ -1023,7 +1030,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
}
dbi_result_free(result);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM AuthToken WHERE subscriber_id=%llu",
subscr->id);
if (!result) {
@@ -1033,7 +1040,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
}
dbi_result_free(result);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM EquipmentWatch WHERE subscriber_id=%llu",
subscr->id);
if (!result) {
@@ -1043,7 +1050,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
}
dbi_result_free(result);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM SMS WHERE src_addr=%s OR dest_addr=%s",
subscr->extension, subscr->extension);
if (!result) {
@@ -1053,7 +1060,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
}
dbi_result_free(result);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM VLR WHERE subscriber_id=%llu",
subscr->id);
if (!result) {
@@ -1063,7 +1070,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
}
dbi_result_free(result);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM ApduBlobs WHERE subscriber_id=%llu",
subscr->id);
if (!result) {
@@ -1073,7 +1080,7 @@ int db_subscriber_delete(struct gsm_subscriber *subscr)
}
dbi_result_free(result);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"DELETE FROM Subscriber WHERE id=%llu",
subscr->id);
if (!result) {
@@ -1143,7 +1150,7 @@ int db_sync_equipment(struct gsm_equipment *equip)
equip->classmark3_len, &cm3);
dbi_conn_quote_string_copy(conn, equip->imei, &q_imei);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE Equipment SET "
"updated = datetime('now'), "
"classmark1 = %u, "
@@ -1201,7 +1208,7 @@ int db_subscriber_alloc_tmsi(struct gsm_subscriber *subscriber)
sprintf(tmsi, "%u", subscriber->tmsi);
dbi_conn_quote_string_copy(conn, tmsi, &tmsi_quoted);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT * FROM Subscriber "
"WHERE tmsi = %s ",
tmsi_quoted);
@@ -1235,7 +1242,7 @@ int db_subscriber_alloc_exten(struct gsm_subscriber *subscriber)
for (;;) {
try = (rand()%(GSM_MAX_EXTEN-GSM_MIN_EXTEN+1)+GSM_MIN_EXTEN);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT * FROM Subscriber "
"WHERE extension = %i",
try
@@ -1274,7 +1281,7 @@ int db_subscriber_alloc_token(struct gsm_subscriber *subscriber, uint32_t *token
try = rand();
if (!try) /* 0 is an invalid token */
continue;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT * FROM AuthToken "
"WHERE subscriber_id = %llu OR token = \"%08X\" ",
subscriber->id, try);
@@ -1293,7 +1300,7 @@ int db_subscriber_alloc_token(struct gsm_subscriber *subscriber, uint32_t *token
}
dbi_result_free(result);
}
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT INTO AuthToken "
"(subscriber_id, created, token) "
"VALUES "
@@ -1319,7 +1326,7 @@ int db_subscriber_assoc_imei(struct gsm_subscriber *subscriber, char imei[GSM_IM
strncpy(subscriber->equipment.imei, imei,
sizeof(subscriber->equipment.imei)-1);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT OR IGNORE INTO Equipment "
"(imei, created, updated) "
"VALUES "
@@ -1339,7 +1346,7 @@ int db_subscriber_assoc_imei(struct gsm_subscriber *subscriber, char imei[GSM_IM
if (equipment_id)
DEBUGP(DDB, "New Equipment: ID %llu, IMEI %s\n", equipment_id, imei);
else {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT id FROM Equipment "
"WHERE imei = %s ",
imei
@@ -1357,7 +1364,7 @@ int db_subscriber_assoc_imei(struct gsm_subscriber *subscriber, char imei[GSM_IM
dbi_result_free(result);
}
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT OR IGNORE INTO EquipmentWatch "
"(subscriber_id, equipment_id, created, updated) "
"VALUES "
@@ -1377,7 +1384,7 @@ int db_subscriber_assoc_imei(struct gsm_subscriber *subscriber, char imei[GSM_IM
DEBUGP(DDB, "New EquipmentWatch: ID %llu, IMSI %s, IMEI %s\n",
equipment_id, subscriber->imsi, imei);
else {
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE EquipmentWatch "
"SET updated = datetime('now') "
"WHERE subscriber_id = %llu AND equipment_id = %llu ",
@@ -1411,7 +1418,7 @@ int db_sms_store(struct gsm_sms *sms)
&q_udata);
/* FIXME: correct validity period */
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT INTO SMS "
"(created, valid_until, "
"reply_path_req, status_rep_req, protocol_id, "
@@ -1500,7 +1507,7 @@ struct gsm_sms *db_sms_get(struct gsm_network *net, unsigned long long id)
dbi_result result;
struct gsm_sms *sms;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT * FROM SMS WHERE SMS.id = %llu", id);
if (!result)
return NULL;
@@ -1523,7 +1530,7 @@ struct gsm_sms *db_sms_get_unsent(struct gsm_network *net, unsigned long long mi
dbi_result result;
struct gsm_sms *sms;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT SMS.* "
"FROM SMS JOIN Subscriber ON "
"SMS.dest_addr = Subscriber.extension "
@@ -1553,7 +1560,7 @@ struct gsm_sms *db_sms_get_unsent_by_subscr(struct gsm_network *net,
dbi_result result;
struct gsm_sms *sms;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT SMS.* "
"FROM SMS JOIN Subscriber ON "
"SMS.dest_addr = Subscriber.extension "
@@ -1582,7 +1589,7 @@ struct gsm_sms *db_sms_get_unsent_for_subscr(struct gsm_subscriber *subscr)
dbi_result result;
struct gsm_sms *sms;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"SELECT SMS.* "
"FROM SMS JOIN Subscriber ON "
"SMS.dest_addr = Subscriber.extension "
@@ -1610,7 +1617,7 @@ int db_sms_mark_delivered(struct gsm_sms *sms)
{
dbi_result result;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE SMS "
"SET sent = datetime('now') "
"WHERE id = %llu", sms->id);
@@ -1628,7 +1635,7 @@ int db_sms_inc_deliver_attempts(struct gsm_sms *sms)
{
dbi_result result;
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"UPDATE SMS "
"SET deliver_attempts = deliver_attempts + 1 "
"WHERE id = %llu", sms->id);
@@ -1651,7 +1658,7 @@ int db_apdu_blob_store(struct gsm_subscriber *subscr,
dbi_conn_quote_binary_copy(conn, apdu, len, &q_apdu);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT INTO ApduBlobs "
"(created,subscriber_id,apdu_id_flags,apdu) VALUES "
"(datetime('now'),%llu,%u,%s)",
@@ -1673,7 +1680,7 @@ int db_store_counter(struct osmo_counter *ctr)
dbi_conn_quote_string_copy(conn, ctr->name, &q_name);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"INSERT INTO Counters "
"(timestamp,name,value) VALUES "
"(datetime('now'),%s,%lu)", q_name, ctr->value);
@@ -1696,7 +1703,7 @@ static int db_store_rate_ctr(struct rate_ctr_group *ctrg, unsigned int num,
dbi_conn_quote_string_copy(conn, ctrg->desc->ctr_desc[num].name,
&q_name);
- result = dbi_conn_queryf(conn,
+ result = trace_dbi_conn_queryf(conn,
"Insert INTO RateCounters "
"(timestamp,name,idx,value) VALUES "
"(datetime('now'),%s.%s,%u,%"PRIu64")",
Signed-off-by: Max <max.suraev@fairwaves.co> --- openbsc/include/openbsc/debug.h | 1 + openbsc/src/libcommon/debug.c | 5 +++ openbsc/src/libmsc/db.c | 97 ++++++++++++++++++++++------------------- 3 files changed, 58 insertions(+), 45 deletions(-)