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