src/vm/jit/trace.cpp

   1 /* src/vm/jit/trace.cpp - Functions for tracing from java code.
   2
   3    Copyright (C) 1996-2005, 2006, 2007, 2008
   4    CACAOVM - Verein zur Foerderung der freien virtuellen Maschine CACAO
   5
   6    This file is part of CACAO.
   7
   8    This program is free software; you can redistribute it and/or
   9    modify it under the terms of the GNU General Public License as
  10    published by the Free Software Foundation; either version 2, or (at
  11    your option) any later version.
  12
  13    This program is distributed in the hope that it will be useful, but
  14    WITHOUT ANY WARRANTY; without even the implied warranty of
  15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  16    General Public License for more details.
  17
  18    You should have received a copy of the GNU General Public License
  19    along with this program; if not, write to the Free Software
  20    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
  21    02110-1301, USA.
  22
  23 */
  24
  25
  26 #include "config.h"
  27
  28 #include <stdio.h>
  29
  30 #include "arch.h"
  31 #include "md-abi.h"
  32
  33 #include "mm/memory.hpp"
  34
  35 #include "native/llni.h"
  36
  37 #include "threads/thread.hpp"
  38
  39 #include "toolbox/logging.hpp"
  40
  41 #include "vm/array.hpp"
  42 #include "vm/global.h"
  43 #include "vm/globals.hpp"
  44 #include "vm/hook.hpp"
  45 #include "vm/javaobjects.hpp"
  46 #include "vm/options.h"
  47 #include "vm/string.hpp"
  48 #include "vm/utf8.h"
  49
  50 #include "vm/jit/argument.hpp"
  51 #include "vm/jit/codegen-common.hpp"
  52 #include "vm/jit/trace.hpp"
  53 #include "vm/jit/show.hpp"
  54
  55
  56 #if !defined(NDEBUG)
  57
  58 // FIXME For now we export everything as C functions.
  59 extern "C" {
  60
  61 /* global variables ***********************************************************/
  62
  63 #if !defined(ENABLE_THREADS)
  64 s4 _no_threads_tracejavacallindent = 0;
  65 u4 _no_threads_tracejavacallcount= 0;
  66 #endif
  67
  68
  69 /* trace_java_call_print_argument **********************************************
  70
  71    XXX: Document me!
  72
  73 *******************************************************************************/
  74
  75 static char *trace_java_call_print_argument(methodinfo *m, char *logtext, s4 *logtextlen, typedesc *paramtype, imm_union imu)
  76 {
  77         java_object_t *o;
  78         classinfo     *c;
  79         utf           *u;
  80         u4             len;
  81
  82         switch (paramtype->type) {
  83         case TYPE_INT:
  84                 sprintf(logtext + strlen(logtext), "%d (0x%08x)", (int32_t)imu.l, (int32_t)imu.l);
  85                 break;
  86
  87         case TYPE_LNG:
  88 #if SIZEOF_VOID_P == 4
  89                 sprintf(logtext + strlen(logtext), "%lld (0x%016llx)", imu.l, imu.l);
  90 #else
  91                 sprintf(logtext + strlen(logtext), "%ld (0x%016lx)", imu.l, imu.l);
  92 #endif
  93                 break;
  94
  95         case TYPE_FLT:
  96                 sprintf(logtext + strlen(logtext), "%g (0x%08x)", imu.f, imu.i);
  97                 break;
  98
  99         case TYPE_DBL:
 100 #if SIZEOF_VOID_P == 4
 101                 sprintf(logtext + strlen(logtext), "%g (0x%016llx)", imu.d, imu.l);
 102 #else
 103                 sprintf(logtext + strlen(logtext), "%g (0x%016lx)", imu.d, imu.l);
 104 #endif
 105                 break;
 106
 107         case TYPE_ADR:
 108 #if SIZEOF_VOID_P == 4
 109                 sprintf(logtext + strlen(logtext), "0x%08x", (ptrint) imu.l);
 110 #else
 111                 sprintf(logtext + strlen(logtext), "0x%016lx", (ptrint) imu.l);
 112 #endif
 113
 114                 /* Workaround for sun.misc.Unsafe methods.  In the future
 115                    (exact GC) we should check if the address is on the GC
 116                    heap. */
 117
 118                 if ((m->clazz       != NULL) &&
 119                         (m->clazz->name == utf_new_char("sun/misc/Unsafe")))
 120                         break;
 121
 122                 /* Cast to java.lang.Object. */
 123
 124                 o = (java_handle_t*) (uintptr_t) imu.l;
 125
 126                 /* Check return argument for java.lang.Class or
 127                    java.lang.String. */
 128
 129                 if (o != NULL) {
 130                         if (o->vftbl->clazz == class_java_lang_String) {
 131                                 /* get java.lang.String object and the length of the
 132                                    string */
 133
 134                                 u = javastring_toutf(o, false);
 135
 136                                 len = strlen(" (String = \"") + utf_bytes(u) + strlen("\")");
 137
 138                                 /* realloc memory for string length */
 139
 140                                 logtext = (char*) DumpMemory::reallocate(logtext, *logtextlen, *logtextlen + len);
 141                                 *logtextlen += len;
 142
 143                                 /* convert to utf8 string and strcat it to the logtext */
 144
 145                                 strcat(logtext, " (String = \"");
 146                                 utf_cat(logtext, u);
 147                                 strcat(logtext, "\")");
 148                         }
 149                         else {
 150                                 if (o->vftbl->clazz == class_java_lang_Class) {
 151                                         /* if the object returned is a java.lang.Class
 152                                            cast it to classinfo structure and get the name
 153                                            of the class */
 154
 155                                         c = (classinfo *) o;
 156
 157                                         u = c->name;
 158                                 }
 159                                 else {
 160                                         /* if the object returned is not a java.lang.String or
 161                                            a java.lang.Class just print the name of the class */
 162
 163                                         u = o->vftbl->clazz->name;
 164                                 }
 165
 166                                 len = strlen(" (Class = \"") + utf_bytes(u) + strlen("\")");
 167
 168                                 /* realloc memory for string length */
 169
 170                                 logtext = (char*) DumpMemory::reallocate(logtext, *logtextlen, *logtextlen + len);
 171                                 *logtextlen += len;
 172
 173                                 /* strcat to the logtext */
 174
 175                                 strcat(logtext, " (Class = \"");
 176                                 utf_cat_classname(logtext, u);
 177                                 strcat(logtext, "\")");
 178                         }
 179                 }
 180         }
 181
 182         return logtext;
 183 }
 184
 185 /* trace_java_call_enter ******************************************************
 186
 187    Traces an entry into a java method.
 188
 189    arg_regs: Array containing all argument registers as int64_t values in
 190    the same order as listed in m->methoddesc. The array is usually allocated
 191    on the stack and used for restoring the argument registers later.
 192
 193    stack: Pointer to first on stack argument in the same format passed to
 194    asm_vm_call_method.
 195
 196 *******************************************************************************/
 197
 198 void trace_java_call_enter(methodinfo *m, uint64_t *arg_regs, uint64_t *stack)
 199 {
 200         methoddesc *md;
 201         imm_union   arg;
 202         char       *logtext;
 203         s4          logtextlen;
 204         s4          i;
 205         s4          pos;
 206
 207         /* We can only trace "slow" builtin functions (those with a stub)
 208          * here, because the argument passing of "fast" ones happens via
 209          * the native ABI and does not fit these functions. */
 210
 211         if (method_is_builtin(m)) {
 212                 if (!opt_TraceBuiltinCalls)
 213                         return;
 214         }
 215         else {
 216                 if (!opt_TraceJavaCalls)
 217                         return;
 218 #if defined(ENABLE_DEBUG_FILTER)
 219                 if (!show_filters_test_verbosecall_enter(m))
 220                         return;
 221 #endif
 222         }
 223
 224 #if defined(ENABLE_VMLOG)
 225         vmlog_cacao_enter_method(m);
 226         return;
 227 #endif
 228
 229         // Hook point on entry into Java method.
 230         Hook::method_enter(m);
 231
 232         md = m->parseddesc;
 233
 234         /* calculate message length */
 235
 236         logtextlen =
 237                 strlen("4294967295 ") +
 238                 strlen("-2147483647-") +        /* INT_MAX should be sufficient       */
 239                 TRACEJAVACALLINDENT +
 240                 strlen("called: ") +
 241                 ((m->clazz == NULL) ? strlen("NULL") : utf_bytes(m->clazz->name)) +
 242                 strlen(".") +
 243                 utf_bytes(m->name) +
 244                 utf_bytes(m->descriptor);
 245
 246         /* Actually it's not possible to have all flags printed, but:
 247            safety first! */
 248
 249         logtextlen +=
 250                 strlen(" PUBLIC") +
 251                 strlen(" PRIVATE") +
 252                 strlen(" PROTECTED") +
 253                 strlen(" STATIC") +
 254                 strlen(" FINAL") +
 255                 strlen(" SYNCHRONIZED") +
 256                 strlen(" VOLATILE") +
 257                 strlen(" TRANSIENT") +
 258                 strlen(" NATIVE") +
 259                 strlen(" INTERFACE") +
 260                 strlen(" ABSTRACT") +
 261                 strlen(" METHOD_BUILTIN");
 262
 263         /* add maximal argument length */
 264
 265         logtextlen +=
 266                 strlen("(") +
 267                 strlen("-9223372036854775808 (0x123456789abcdef0), ") * md->paramcount +
 268                 strlen("...(255)") +
 269                 strlen(")");
 270
 271         // Create new dump memory area.
 272         DumpMemoryArea dma;
 273
 274         // TODO Use a std::string here.
 275         logtext = (char*) DumpMemory::allocate(sizeof(char) * logtextlen);
 276
 277         TRACEJAVACALLCOUNT++;
 278
 279         sprintf(logtext, "%10d ", TRACEJAVACALLCOUNT);
 280         sprintf(logtext + strlen(logtext), "-%d-", TRACEJAVACALLINDENT);
 281
 282         pos = strlen(logtext);
 283
 284         for (i = 0; i < TRACEJAVACALLINDENT; i++)
 285                 logtext[pos++] = '\t';
 286
 287         strcpy(logtext + pos, "called: ");
 288
 289         if (m->clazz != NULL)
 290                 utf_cat_classname(logtext, m->clazz->name);
 291         else
 292                 strcat(logtext, "NULL");
 293         strcat(logtext, ".");
 294         utf_cat(logtext, m->name);
 295         utf_cat(logtext, m->descriptor);
 296
 297         if (m->flags & ACC_PUBLIC)         strcat(logtext, " PUBLIC");
 298         if (m->flags & ACC_PRIVATE)        strcat(logtext, " PRIVATE");
 299         if (m->flags & ACC_PROTECTED)      strcat(logtext, " PROTECTED");
 300         if (m->flags & ACC_STATIC)         strcat(logtext, " STATIC");
 301         if (m->flags & ACC_FINAL)          strcat(logtext, " FINAL");
 302         if (m->flags & ACC_SYNCHRONIZED)   strcat(logtext, " SYNCHRONIZED");
 303         if (m->flags & ACC_VOLATILE)       strcat(logtext, " VOLATILE");
 304         if (m->flags & ACC_TRANSIENT)      strcat(logtext, " TRANSIENT");
 305         if (m->flags & ACC_NATIVE)         strcat(logtext, " NATIVE");
 306         if (m->flags & ACC_INTERFACE)      strcat(logtext, " INTERFACE");
 307         if (m->flags & ACC_ABSTRACT)       strcat(logtext, " ABSTRACT");
 308
 309         strcat(logtext, "(");
 310
 311         for (i = 0; i < md->paramcount; ++i) {
 312                 arg = argument_jitarray_load(md, i, arg_regs, stack);
 313                 logtext = trace_java_call_print_argument(m, logtext, &logtextlen,
 314                                                                                                  &md->paramtypes[i], arg);
 315                 if (i != (md->paramcount - 1)) {
 316                         strcat(logtext, ", ");
 317                 }
 318         }
 319
 320         strcat(logtext, ")");
 321
 322         log_text(logtext);
 323
 324         TRACEJAVACALLINDENT++;
 325 }
 326
 327 /* trace_java_call_exit ********************************************************
 328
 329    Traces an exit form a java method.
 330
 331    return_regs: Array of size 1 containing return register.
 332    The array is usually allocated on the stack and used for restoring the
 333    registers later.
 334
 335 *******************************************************************************/
 336
 337 void trace_java_call_exit(methodinfo *m, uint64_t *return_regs)
 338 {
 339         methoddesc *md;
 340         char       *logtext;
 341         s4          logtextlen;
 342         s4          i;
 343         s4          pos;
 344         imm_union   val;
 345
 346         /* We can only trace "slow" builtin functions (those with a stub)
 347          * here, because the argument passing of "fast" ones happens via
 348          * the native ABI and does not fit these functions. */
 349
 350         if (method_is_builtin(m)) {
 351                 if (!opt_TraceBuiltinCalls)
 352                         return;
 353         }
 354         else {
 355                 if (!opt_TraceJavaCalls)
 356                         return;
 357 #if defined(ENABLE_DEBUG_FILTER)
 358                 if (!show_filters_test_verbosecall_exit(m))
 359                         return;
 360 #endif
 361         }
 362
 363 #if defined(ENABLE_VMLOG)
 364         vmlog_cacao_leave_method(m);
 365         return;
 366 #endif
 367
 368         // Hook point upon exit from Java method.
 369         Hook::method_exit(m);
 370
 371         md = m->parseddesc;
 372
 373         /* outdent the log message */
 374
 375         if (TRACEJAVACALLINDENT)
 376                 TRACEJAVACALLINDENT--;
 377         else
 378                 log_text("trace_java_call_exit: WARNING: unmatched unindent");
 379
 380         /* calculate message length */
 381
 382         logtextlen =
 383                 strlen("4294967295 ") +
 384                 strlen("-2147483647-") +        /* INT_MAX should be sufficient       */
 385                 TRACEJAVACALLINDENT +
 386                 strlen("finished: ") +
 387                 ((m->clazz == NULL) ? strlen("NULL") : utf_bytes(m->clazz->name)) +
 388                 strlen(".") +
 389                 utf_bytes(m->name) +
 390                 utf_bytes(m->descriptor) +
 391                 strlen(" SYNCHRONIZED") + strlen("(") + strlen(")");
 392
 393         /* add maximal argument length */
 394
 395         logtextlen += strlen("->0.4872328470301428 (0x0123456789abcdef)");
 396
 397         // Create new dump memory area.
 398         DumpMemoryArea dma;
 399
 400         // TODO Use a std::string here.
 401         logtext = (char*) DumpMemory::allocate(sizeof(char) * logtextlen);
 402
 403         /* generate the message */
 404
 405         sprintf(logtext, "           ");
 406         sprintf(logtext + strlen(logtext), "-%d-", TRACEJAVACALLINDENT);
 407
 408         pos = strlen(logtext);
 409
 410         for (i = 0; i < TRACEJAVACALLINDENT; i++)
 411                 logtext[pos++] = '\t';
 412
 413         strcpy(logtext + pos, "finished: ");
 414         if (m->clazz != NULL)
 415                 utf_cat_classname(logtext, m->clazz->name);
 416         else
 417                 strcat(logtext, "NULL");
 418         strcat(logtext, ".");
 419         utf_cat(logtext, m->name);
 420         utf_cat(logtext, m->descriptor);
 421
 422         if (!IS_VOID_TYPE(md->returntype.type)) {
 423                 strcat(logtext, "->");
 424                 val = argument_jitreturn_load(md, return_regs);
 425
 426                 logtext =
 427                         trace_java_call_print_argument(m, logtext, &logtextlen,
 428                                                                                    &md->returntype, val);
 429         }
 430
 431         log_text(logtext);
 432 }
 433
 434
 435 /* trace_exception *************************************************************
 436
 437    Traces an exception which is handled by exceptions_handle_exception.
 438
 439 *******************************************************************************/
 440
 441 void trace_exception(java_object_t *xptr, methodinfo *m, void *pos)
 442 {
 443         char *logtext;
 444         s4    logtextlen;
 445         codeinfo *code;
 446
 447         /* calculate message length */
 448
 449         if (xptr) {
 450                 logtextlen =
 451                         strlen("Exception ") + utf_bytes(xptr->vftbl->clazz->name);
 452         }
 453         else {
 454                 logtextlen = strlen("Some Throwable");
 455         }
 456
 457         logtextlen += strlen(" thrown in ");
 458
 459         if (m) {
 460                 logtextlen +=
 461                         utf_bytes(m->clazz->name) +
 462                         strlen(".") +
 463                         utf_bytes(m->name) +
 464                         utf_bytes(m->descriptor) +
 465                         strlen("(NOSYNC,NATIVE");
 466
 467 #if SIZEOF_VOID_P == 8
 468                 logtextlen +=
 469                         strlen(")(0x123456789abcdef0) at position 0x123456789abcdef0 (");
 470 #else
 471                 logtextlen += strlen(")(0x12345678) at position 0x12345678 (");
 472 #endif
 473
 474                 if (m->clazz->sourcefile == NULL)
 475                         logtextlen += strlen("<NO CLASSFILE INFORMATION>");
 476                 else
 477                         logtextlen += utf_bytes(m->clazz->sourcefile);
 478
 479                 logtextlen += strlen(":65536)");
 480
 481         }
 482         else {
 483                 logtextlen += strlen("call_java_method");
 484         }
 485
 486         logtextlen += strlen("0");
 487
 488         // Create new dump memory area.
 489         DumpMemoryArea dma;
 490
 491         // TODO Use a std::string here.
 492         logtext = (char*) DumpMemory::allocate(sizeof(char) * logtextlen);
 493
 494         if (xptr) {
 495                 strcpy(logtext, "Exception ");
 496                 utf_cat_classname(logtext, xptr->vftbl->clazz->name);
 497
 498         } else {
 499                 strcpy(logtext, "Some Throwable");
 500         }
 501
 502         strcat(logtext, " thrown in ");
 503
 504         if (m) {
 505                 utf_cat_classname(logtext, m->clazz->name);
 506                 strcat(logtext, ".");
 507                 utf_cat(logtext, m->name);
 508                 utf_cat(logtext, m->descriptor);
 509
 510                 if (m->flags & ACC_SYNCHRONIZED)
 511                         strcat(logtext, "(SYNC");
 512                 else
 513                         strcat(logtext, "(NOSYNC");
 514
 515                 if (m->flags & ACC_NATIVE) {
 516                         strcat(logtext, ",NATIVE");
 517
 518                         code = m->code;
 519
 520 #if SIZEOF_VOID_P == 8
 521                         sprintf(logtext + strlen(logtext),
 522                                         ")(0x%016lx) at position 0x%016lx",
 523                                         (ptrint) code->entrypoint, (ptrint) pos);
 524 #else
 525                         sprintf(logtext + strlen(logtext),
 526                                         ")(0x%08x) at position 0x%08x",
 527                                         (ptrint) code->entrypoint, (ptrint) pos);
 528 #endif
 529
 530                 } else {
 531
 532                         /* XXX preliminary: This should get the actual codeinfo */
 533                         /* in which the exception happened.                     */
 534                         code = m->code;
 535
 536 #if SIZEOF_VOID_P == 8
 537                         sprintf(logtext + strlen(logtext),
 538                                         ")(0x%016lx) at position 0x%016lx (",
 539                                         (ptrint) code->entrypoint, (ptrint) pos);
 540 #else
 541                         sprintf(logtext + strlen(logtext),
 542                                         ")(0x%08x) at position 0x%08x (",
 543                                         (ptrint) code->entrypoint, (ptrint) pos);
 544 #endif
 545
 546                         if (m->clazz->sourcefile == NULL)
 547                                 strcat(logtext, "<NO CLASSFILE INFORMATION>");
 548                         else
 549                                 utf_cat(logtext, m->clazz->sourcefile);
 550
 551                         sprintf(logtext + strlen(logtext), ":%d)", 0);
 552                 }
 553
 554         } else
 555                 strcat(logtext, "call_java_method");
 556
 557         log_text(logtext);
 558 }
 559
 560
 561 /* trace_exception_builtin *****************************************************
 562
 563    Traces an exception which is thrown by builtin_throw_exception.
 564
 565 *******************************************************************************/
 566
 567 void trace_exception_builtin(java_handle_t* h)
 568 {
 569         char                *logtext;
 570         s4                   logtextlen;
 571
 572         java_lang_Throwable jlt(h);
 573
 574         // Get detail message.
 575         java_handle_t* s = NULL;
 576
 577         if (jlt.get_handle() != NULL)
 578                 s = jlt.get_detailMessage();
 579
 580         java_lang_String jls(s);
 581
 582         /* calculate message length */
 583
 584         logtextlen = strlen("Builtin exception thrown: ") + strlen("0");
 585
 586         if (jlt.get_handle() != NULL) {
 587                 logtextlen += utf_bytes(jlt.get_vftbl()->clazz->name);
 588
 589                 if (jls.get_handle()) {
 590                         CharArray ca(jls.get_value());
 591                         // FIXME This is not handle capable!
 592                         uint16_t* ptr = (uint16_t*) ca.get_raw_data_ptr();
 593                         logtextlen += strlen(": ") +
 594                                 u2_utflength(ptr + jls.get_offset(), jls.get_count());
 595                 }
 596         }
 597         else {
 598                 logtextlen += strlen("(nil)");
 599         }
 600
 601         // Create new dump memory area.
 602         DumpMemoryArea dma;
 603
 604         logtext = (char*) DumpMemory::allocate(sizeof(char) * logtextlen);
 605
 606         strcpy(logtext, "Builtin exception thrown: ");
 607
 608         if (jlt.get_handle()) {
 609                 utf_cat_classname(logtext, jlt.get_vftbl()->clazz->name);
 610
 611                 if (s) {
 612                         char *buf;
 613
 614                         buf = javastring_tochar(jls.get_handle());
 615                         strcat(logtext, ": ");
 616                         strcat(logtext, buf);
 617                         MFREE(buf, char, strlen(buf) + 1);
 618                 }
 619
 620         } else {
 621                 strcat(logtext, "(nil)");
 622         }
 623
 624         log_text(logtext);
 625 }
 626
 627 } // extern "C"
 628
 629 #endif /* !defined(NDEBUG) */
 630
 631
 632 /*
 633  * These are local overrides for various environment variables in Emacs.
 634  * Please do not remove this and leave it at the end of the file, where
 635  * Emacs will automagically detect them.
 636  * ---------------------------------------------------------------------
 637  * Local variables:
 638  * mode: c++
 639  * indent-tabs-mode: t
 640  * c-basic-offset: 4
 641  * tab-width: 4
 642  * End:
 643  * vim:noexpandtab:sw=4:ts=4:
 644  */