Changeset: 57dff54c77b3 for MonetDB
URL: https://dev.monetdb.org/hg/MonetDB/rev/57dff54c77b3
Modified Files:
monetdb5/mal/mal_client.c
monetdb5/mal/mal_profiler.c
monetdb5/mal/mal_profiler.h
sql/backends/monet5/sql.c
sql/backends/monet5/sql_scenario.c
sql/include/sql_catalog.h
sql/server/sql_mvc.c
sql/storage/sql_storage.h
sql/storage/store.c
Branch: sql_profiler
Log Message:
Remove start of non-mal events. Add timings of events (usec).
diffs (295 lines):
diff --git a/monetdb5/mal/mal_client.c b/monetdb5/mal/mal_client.c
--- a/monetdb5/mal/mal_client.c
+++ b/monetdb5/mal/mal_client.c
@@ -209,7 +209,7 @@ MCexitClient(Client c)
}
if(malProfileMode > 0)
generic_event("client_connection",
- (struct GenericEvent) { &c->idx, NULL,
NULL, NULL, 0 },
+ (struct GenericEvent) { &c->idx,
NULL, NULL, NULL, c->session, 0 },
1);
setClientContext(NULL);
}
@@ -303,7 +303,7 @@ MCinitClient(oid user, bstream *fin, str
c = MCinitClientRecord(c, user, fin, fout);
if(malProfileMode > 0)
generic_event("client_connection",
- (struct GenericEvent) {
&c->idx, NULL, NULL, NULL, 0 },
+ (struct GenericEvent) {
&c->idx, NULL, NULL, NULL, c->session, 0 },
0);
}
MT_lock_unset(&mal_contextLock);
diff --git a/monetdb5/mal/mal_profiler.c b/monetdb5/mal/mal_profiler.c
--- a/monetdb5/mal/mal_profiler.c
+++ b/monetdb5/mal/mal_profiler.c
@@ -198,6 +198,7 @@ prepare_generic_event(str phase, struct
",\"thread\":%d"
",\"phase\":\"%s\""
",\"state\":\"%s\""
+ ",\"usec\":"LLFMT
",\"clientid\":\"%d\""
",\"transactionid\":"ULLFMT
",\"tag\":"OIDFMT
@@ -210,6 +211,7 @@ prepare_generic_event(str phase, struct
THRgettid(),
phase,
state ? "done" : "start",
+ e.usec,
e.cid ? *e.cid : 0,
e.tid ? *e.tid : 0,
e.tag ? *e.tag : 0,
diff --git a/monetdb5/mal/mal_profiler.h b/monetdb5/mal/mal_profiler.h
--- a/monetdb5/mal/mal_profiler.h
+++ b/monetdb5/mal/mal_profiler.h
@@ -25,6 +25,7 @@ struct GenericEvent {
oid* tag;
ulng* tid; /* transaction_id */
str query;
+ lng usec;
int rc; /* return code */
};
diff --git a/sql/backends/monet5/sql.c b/sql/backends/monet5/sql.c
--- a/sql/backends/monet5/sql.c
+++ b/sql/backends/monet5/sql.c
@@ -129,24 +129,13 @@ sql_symbol2relation(backend *be, symbol
int profile = be->mvc->emode == m_plan;
Client c = getClientContext();
+ Tbegin = GDKusec();
+ rel = rel_semantic(query, sym);
if(malProfileMode > 0 )
generic_event("sql_to_rel",
- (struct GenericEvent)
- { &(c->idx), &(c->curprg->def->tag),
NULL, NULL, 0 },
- 0);
-
- rel = rel_semantic(query, sym);
-
- if(malProfileMode > 0 ) {
- generic_event("sql_to_rel",
- (struct GenericEvent)
- { &(c->idx), &(c->curprg->def->tag),
NULL, NULL, rel ? 0 : 1 },
- 1);
- generic_event("rel_opt",
- (struct GenericEvent)
- { &(c->idx), &(c->curprg->def->tag),
NULL, NULL, 0 },
- 0);
- }
+ (struct GenericEvent)
+ { &(c->idx), &(c->curprg->def->tag),
NULL, NULL, GDKusec()-Tbegin, rel ? 0 : 1 },
+ 1);
storage_based_opt = value_based_opt && rel && !is_ddl(rel->op);
Tbegin = GDKusec();
@@ -160,9 +149,9 @@ sql_symbol2relation(backend *be, symbol
if(malProfileMode > 0)
generic_event("rel_opt",
- (struct GenericEvent)
- { &c->idx, &(c->curprg->def->tag),
NULL, NULL, rel ? 0 : 1},
- 1);
+ (struct GenericEvent)
+ { &c->idx, &(c->curprg->def->tag),
NULL, NULL, be->reloptimizer, rel ? 0 : 1},
+ 1);
return rel;
}
diff --git a/sql/backends/monet5/sql_scenario.c
b/sql/backends/monet5/sql_scenario.c
--- a/sql/backends/monet5/sql_scenario.c
+++ b/sql/backends/monet5/sql_scenario.c
@@ -971,6 +971,7 @@ SQLparser(Client c)
int pstatus = 0;
int err = 0, opt, preparedid = -1;
oid tag = 0;
+ lng Tbegin;
c->query = NULL;
be = (backend *) c->sqlcontext;
@@ -1114,11 +1115,7 @@ SQLparser(Client c)
assert(tag == c->curprg->def->tag);
(void) tag;
- if(malProfileMode > 0)
- generic_event("sql_parse",
- (struct GenericEvent)
- { &c->idx, &(c->curprg->def->tag),
NULL, NULL, 0 },
- 0);
+ Tbegin = GDKusec();
if ((err = sqlparse(m)) ||
/* Only forget old errors on transaction boundaries */
@@ -1147,11 +1144,11 @@ SQLparser(Client c)
c->query = query_cleaned(m->sa, QUERY(m->scanner));
if(malProfileMode > 0) {
- str escaped_query = c->query? mal_quote(c->query,
sizeof(c->query)) : NULL;
+ str escaped_query = c->query? mal_quote(c->query,
strlen(c->query)) : NULL;
generic_event("sql_parse",
- (struct GenericEvent)
- { &c->idx, &(c->curprg->def->tag),
NULL, escaped_query, c->query? 0 : 1 },
- 1);
+ (struct GenericEvent)
+ { &c->idx, &(c->curprg->def->tag),
NULL, escaped_query, GDKusec()-Tbegin, c->query? 0 : 1 },
+ 1);
GDKfree(escaped_query);
}
@@ -1210,11 +1207,7 @@ SQLparser(Client c)
}
}
- if(malProfileMode > 0)
- generic_event("rel_to_mal",
- (struct GenericEvent)
- { &c->idx,
&(c->curprg->def->tag), NULL, NULL, c->query? 0 : 1 },
- 0);
+ Tbegin = GDKusec();
if (backend_dumpstmt(be, c->curprg->def, r, !(m->emod &
mod_exec), 0, c->query) < 0)
err = 1;
@@ -1224,7 +1217,7 @@ SQLparser(Client c)
if(malProfileMode > 0)
generic_event("rel_to_mal",
(struct GenericEvent)
- { &c->idx,
&(c->curprg->def->tag), NULL, NULL, c->query? 0 : 1 },
+ { &c->idx,
&(c->curprg->def->tag), NULL, NULL, GDKusec()-Tbegin, c->query? 0 : 1 },
1);
} else {
char *q_copy = sa_strdup(m->sa, c->query);
@@ -1304,19 +1297,14 @@ SQLparser(Client c)
/* in case we had produced a non-cachable plan, the optimizer
should be called */
if (msg == MAL_SUCCEED && opt ) {
- if(malProfileMode > 0)
- generic_event("mal_opt",
- (struct GenericEvent)
- { &c->idx,
&(c->curprg->def->tag), NULL, NULL, 0 },
- 0);
-
+ Tbegin = GDKusec();
msg = SQLoptimizeQuery(c, c->curprg->def);
if(malProfileMode > 0)
generic_event("mal_opt",
- (struct GenericEvent)
- { &c->idx,
&(c->curprg->def->tag), NULL, NULL, msg == MAL_SUCCEED? 0 : 1 },
- 1);
+ (struct GenericEvent)
+ { &c->idx,
&(c->curprg->def->tag), NULL, NULL, GDKusec()-Tbegin, msg == MAL_SUCCEED? 0 : 1
},
+ 1);
if (msg != MAL_SUCCEED) {
str other = c->curprg->def->errors;
diff --git a/sql/include/sql_catalog.h b/sql/include/sql_catalog.h
--- a/sql/include/sql_catalog.h
+++ b/sql/include/sql_catalog.h
@@ -308,6 +308,7 @@ typedef struct sql_trans {
ulng ts; /* transaction start timestamp */
ulng tid; /* transaction id */
+ lng ts2; /* transaction timestamp for profiling */
sql_store store; /* keep link into the global store */
MT_Lock lock; /* lock protecting concurrent writes to the
changes list */
diff --git a/sql/server/sql_mvc.c b/sql/server/sql_mvc.c
--- a/sql/server/sql_mvc.c
+++ b/sql/server/sql_mvc.c
@@ -125,12 +125,12 @@ mvc_fix_depend(mvc *m, sql_column *depid
}
static void
-generic_event_wrapper(str phase, ulng tid, int rc, int state)
+generic_event_wrapper(str phase, ulng tid, lng usec, int rc, int state)
{
if(malProfileMode > 0)
generic_event(phase,
(struct GenericEvent)
- { NULL, NULL, &tid, NULL, rc },
+ { NULL, NULL, &tid, NULL, usec, rc },
state);
}
@@ -488,10 +488,11 @@ mvc_trans(mvc *m)
TRC_INFO(SQL_TRANS, "Starting transaction\n");
res = sql_trans_begin(m->session);
+ m->session->tr->ts2 = GDKusec();
if(malProfileMode > 0)
generic_event("transaction",
- (struct GenericEvent)
- { NULL, NULL, &(m->session->tr->tid),
NULL, (res || err)? 1 : 0 },
+ (struct GenericEvent)
+ { NULL, NULL, &(m->session->tr->tid),
NULL, GDKusec(), (res || err)? 1 : 0 },
0);
if (m->qc && (res || err)) {
diff --git a/sql/storage/sql_storage.h b/sql/storage/sql_storage.h
--- a/sql/storage/sql_storage.h
+++ b/sql/storage/sql_storage.h
@@ -331,7 +331,7 @@ extern res_table *res_tables_remove(res_
sql_export void res_tables_destroy(res_table *results);
extern res_table *res_tables_find(res_table *results, int res_id);
-typedef void (*generic_event_wrapper_fptr) (str phase, ulng tid, int rc, int
state);
+typedef void (*generic_event_wrapper_fptr) (str phase, ulng tid, lng usec, int
rc, int state);
extern struct sqlstore *store_init(int debug, store_type store, int readonly,
int singleuser, generic_event_wrapper_fptr event_wrapper);
extern void store_exit(struct sqlstore *store);
diff --git a/sql/storage/store.c b/sql/storage/store.c
--- a/sql/storage/store.c
+++ b/sql/storage/store.c
@@ -3579,8 +3579,7 @@ static void
sql_trans_rollback(sql_trans *tr, bool commit_lock)
{
sqlstore *store = tr->store;
-
- store->generic_event_wrapper("rollback", tr->tid, 0, 0);
+ lng Tbegin = GDKusec();
/* move back deleted */
if (tr->localtmps.dset) {
@@ -3678,7 +3677,7 @@ sql_trans_rollback(sql_trans *tr, bool c
tr->depchanges = NULL;
}
- store->generic_event_wrapper("rollback", tr->tid, 0, 1);
+ store->generic_event_wrapper("rollback", tr->tid, GDKusec()-Tbegin, 0,
1);
}
sql_trans *
@@ -3884,6 +3883,7 @@ sql_trans_commit(sql_trans *tr)
{
int ok = LOG_OK;
sqlstore *store = tr->store;
+ lng Tbegin;
if (!list_empty(tr->changes)) {
int flush = 0;
@@ -3911,7 +3911,7 @@ sql_trans_commit(sql_trans *tr)
}
}
- store->generic_event_wrapper("commit", tr->tid, 0, 0);
+ Tbegin = GDKusec();
/* log changes should only be done if there is something to log
*/
const bool log = !tr->parent && tr->logchanges > 0;
@@ -4043,7 +4043,7 @@ sql_trans_commit(sql_trans *tr)
if (ok == LOG_OK)
ok = clean_predicates_and_propagate_to_parent(tr);
- store->generic_event_wrapper("commit", tr->tid, (ok == LOG_OK)? SQL_OK
: SQL_ERR, 1);
+ store->generic_event_wrapper("commit", tr->tid, GDKusec()-Tbegin, (ok
== LOG_OK)? SQL_OK : SQL_ERR, 1);
return (ok==LOG_OK)?SQL_OK:SQL_ERR;
}
@@ -7079,7 +7079,7 @@ sql_trans_end(sql_session *s, int ok)
}
store->oldest = oldest;
assert(list_length(store->active) == (int)
ATOMIC_GET(&store->nr_active));
- store->generic_event_wrapper("transaction", s->tr->tid, (ok == LOG_OK)?
SQL_OK : SQL_ERR, 1);
+ store->generic_event_wrapper("transaction", s->tr->tid,
GDKusec()-(s->tr->ts2), (ok == LOG_OK)? SQL_OK : SQL_ERR, 1);
store_unlock(store);
return ok;
_______________________________________________
checkin-list mailing list -- [email protected]
To unsubscribe send an email to [email protected]
