From: Julian Seward Date: Wed, 15 Jul 2009 14:48:32 +0000 (+0000) Subject: Merge coregrind/ changes from branches/MESSAGING_TIDYUP r10464. X-Git-Tag: svn/VALGRIND_3_5_0~383 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=e7dde85a24ee8155eae1ba06bc36fa32e70860fe;p=thirdparty%2Fvalgrind.git Merge coregrind/ changes from branches/MESSAGING_TIDYUP r10464. This commit tidies up and rationalises what could be called the "messaging" system -- that part of V to do with presenting output to the user. In particular it brings significant improvements to XML output. Changes are: * XML and normal text output now have separate file descriptors, which solves longstanding problems for XML consumers caused by the XML output getting polluted by unexpected non-XML output. * This also means that we no longer have to hardwire all manner of output settings (verbosity, etc) when XML is requested. * The XML output format has been revised, cleaned up, and made more suitable for use by error detecting tools in general (various Memcheck-specific features have been removed). XML output is enabled for Ptrcheck and Helgrind, and Memcheck is updated to the new format. * One side effect is that the behaviour of VG_(message) has been made to be consistent with printf: it no longer automatically adds a newline at the end of the output. This means multiple calls to it can be used to build up a single line message; or a single call can write a multi-line message. The ==pid== preamble is automatically inserted at each newline. * VG_(message)(Vg_UserMsg, ..args..) now has the abbreviated form VG_(UMSG)(..args..); ditto VG_(DMSG) for Vg_DebugMsg and VG_(EMSG) for Vg_DebugExtraMsg. A couple of other useful printf derivatives have been added to pub_tool_libcprint.h, most particularly VG_(vcbprintf). * There's a small change in the core-tool interface to do with error handling: VG_(needs_tool_errors) has a new method void (*before_pp_Error)(Error* err) which, if non-NULL, is called just before void (*pp_Error)(Error* err). This is to give tools the chance to look at errors before any part of them is printed, so they can print any XML preamble they like. * coregrind/m_errormgr.c has been overhauled and cleaned up, and is a bit simpler and more commented. In particular pp_Error and VG_(maybe_record_error) are significantly changed. The diff is huge, but mostly very boring. Most of the changes are of the form - VG_(message)(Vg_UserMsg, "this is a message %d", n); + VG_(message)(Vg_UserMsg, "this is a message %d\n", n); Unfortunately as a result of this, it touches a large number of source files. git-svn-id: svn://svn.valgrind.org/valgrind/trunk@10465 --- diff --git a/coregrind/m_commandline.c b/coregrind/m_commandline.c index e4ab751661..327560a792 100644 --- a/coregrind/m_commandline.c +++ b/coregrind/m_commandline.c @@ -81,7 +81,7 @@ static HChar* read_dot_valgrindrc ( HChar* dir ) else VG_(message)(Vg_UserMsg, "%s was not read as it is world writeable or not owned by the " - "current user", filename); + "current user\n", filename); VG_(close)(sr_Res(fd)); } diff --git a/coregrind/m_coredump/coredump-elf.c b/coregrind/m_coredump/coredump-elf.c index 0d409aa4a4..e29700af3f 100644 --- a/coregrind/m_coredump/coredump-elf.c +++ b/coregrind/m_coredump/coredump-elf.c @@ -444,11 +444,11 @@ void make_elf_coredump(ThreadId tid, const vki_siginfo_t *si, UInt max_size) Addr *seg_starts; Int n_seg_starts; - if (VG_(clo_log_name) != NULL) { + if (VG_(clo_log_fname_expanded) != NULL) { coreext = ".core"; basename = VG_(expand_file_name)( "--log-file (while creating core filename)", - VG_(clo_log_name)); + VG_(clo_log_fname_expanded)); } vg_assert(coreext); diff --git a/coregrind/m_debugger.c b/coregrind/m_debugger.c index 1bc9fe5f1b..aaa6c6b815 100644 --- a/coregrind/m_debugger.c +++ b/coregrind/m_debugger.c @@ -296,22 +296,22 @@ void VG_(start_debugger) ( ThreadId tid ) *bufptr++ = '\0'; - VG_(message)(Vg_UserMsg, "starting debugger with cmd: %s", buf); + VG_(message)(Vg_UserMsg, "starting debugger with cmd: %s\n", buf); res = VG_(system)(buf); if (res == 0) { - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); VG_(message)(Vg_UserMsg, "Debugger has detached. Valgrind regains control." - " We continue."); + " We continue.\n"); } else { VG_(message)(Vg_UserMsg, - "Warning: Debugger attach failed! (sys_system)"); - VG_(message)(Vg_UserMsg, ""); + "Warning: Debugger attach failed! (sys_system)\n"); + VG_(message)(Vg_UserMsg, "\n"); } } else { VG_(message)(Vg_UserMsg, - "Warning: Debugger attach failed! (ptrace problem?)"); - VG_(message)(Vg_UserMsg, ""); + "Warning: Debugger attach failed! (ptrace problem?)\n"); + VG_(message)(Vg_UserMsg, "\n"); } VG_(kill)(pid, VKI_SIGKILL); diff --git a/coregrind/m_debuginfo/d3basics.c b/coregrind/m_debuginfo/d3basics.c index 055f814684..a61ed05cb2 100644 --- a/coregrind/m_debuginfo/d3basics.c +++ b/coregrind/m_debuginfo/d3basics.c @@ -641,7 +641,7 @@ GXResult ML_(evaluate_Dwarf3_Expr) ( UChar* expr, UWord exprszB, if (!VG_(clo_xml)) VG_(message)(Vg_DebugMsg, "warning: evaluate_Dwarf3_Expr: unhandled " - "DW_OP_ 0x%x", (Int)opcode); + "DW_OP_ 0x%x\n", (Int)opcode); FAIL("evaluate_Dwarf3_Expr: unhandled DW_OP_"); /*NOTREACHED*/ } diff --git a/coregrind/m_debuginfo/debuginfo.c b/coregrind/m_debuginfo/debuginfo.c index 34442f6bc7..dfc9f316f3 100644 --- a/coregrind/m_debuginfo/debuginfo.c +++ b/coregrind/m_debuginfo/debuginfo.c @@ -306,7 +306,7 @@ static void discard_DebugInfo ( DebugInfo* di ) if (curr->have_dinfo && (VG_(clo_verbosity) > 1 || VG_(clo_trace_redir))) VG_(message)(Vg_DebugMsg, - "Discarding syms at %#lx-%#lx in %s due to %s()", + "Discarding syms at %#lx-%#lx in %s due to %s()\n", di->text_avma, di->text_avma + di->text_size, curr->filename ? curr->filename : (UChar*)"???", @@ -904,10 +904,10 @@ void VG_(di_notify_pdb_debuginfo)( Int fd_obj, Addr avma_obj, struct vg_stat stat_buf; if (VG_(clo_verbosity) > 0) { - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); VG_(message)(Vg_UserMsg, "LOAD_PDB_DEBUGINFO(fd=%d, avma=%#lx, total_size=%lu, " - "uu_reloc=%#lx)", + "uu_reloc=%#lx)\n", fd_obj, avma_obj, total_size, unknown_purpose__reloc ); } @@ -933,7 +933,7 @@ void VG_(di_notify_pdb_debuginfo)( Int fd_obj, Addr avma_obj, vg_assert(exename[sizeof(exename)-1] == 0); if (VG_(clo_verbosity) > 0) { - VG_(message)(Vg_UserMsg, "LOAD_PDB_DEBUGINFO: objname: %s", exename); + VG_(message)(Vg_UserMsg, "LOAD_PDB_DEBUGINFO: objname: %s\n", exename); } /* Try to find a matching PDB file from which to read debuginfo. @@ -961,24 +961,25 @@ void VG_(di_notify_pdb_debuginfo)( Int fd_obj, Addr avma_obj, /* See if we can find it, and check it's in-dateness. */ sres = VG_(stat)(pdbname, &stat_buf); if (sr_isError(sres)) { - VG_(message)(Vg_UserMsg, "Warning: Missing or un-stat-able %s", + VG_(message)(Vg_UserMsg, "Warning: Missing or un-stat-able %s\n", pdbname); if (VG_(clo_verbosity) > 0) - VG_(message)(Vg_UserMsg, "LOAD_PDB_DEBUGINFO: missing: %s", pdbname); + VG_(message)(Vg_UserMsg, "LOAD_PDB_DEBUGINFO: missing: %s\n", pdbname); goto out; } pdb_mtime = stat_buf.mtime; if (pdb_mtime < obj_mtime ) { /* PDB file is older than PE file - ignore it or we will either (a) print wrong stack traces or more likely (b) crash. */ - VG_(message)(Vg_UserMsg, "Warning: Ignoring %s since it is older than %s", - pdbname, exename); + VG_(message)(Vg_UserMsg, + "Warning: Ignoring %s since it is older than %s\n", + pdbname, exename); goto out; } sres = VG_(open)(pdbname, VKI_O_RDONLY, 0); if (sr_isError(sres)) { - VG_(message)(Vg_UserMsg, "Warning: Can't open %s", pdbname); + VG_(message)(Vg_UserMsg, "Warning: Can't open %s\n", pdbname); goto out; } @@ -993,7 +994,7 @@ void VG_(di_notify_pdb_debuginfo)( Int fd_obj, Addr avma_obj, } if (VG_(clo_verbosity) > 0) - VG_(message)(Vg_UserMsg, "LOAD_PDB_DEBUGINFO: pdbname: %s", pdbname); + VG_(message)(Vg_UserMsg, "LOAD_PDB_DEBUGINFO: pdbname: %s\n", pdbname); /* play safe; always invalidate the CFI cache. I don't know if this is necessary, but anyway .. */ @@ -2250,7 +2251,8 @@ Bool VG_(use_FPO_info) ( /*MOD*/Addr* ipP, spHere = *spP; *ipP = *(Addr *)(spHere + 4*(fpo->cbRegs + fpo->cdwLocals)); - *spP = spHere + 4*(fpo->cbRegs + fpo->cdwLocals + 1 + fpo->cdwParams); + *spP = spHere + 4*(fpo->cbRegs + fpo->cdwLocals + 1 + + fpo->cdwParams); *fpP = *(Addr *)(spHere + 4*2); return True; } @@ -2263,6 +2265,35 @@ Bool VG_(use_FPO_info) ( /*MOD*/Addr* ipP, /*--- ---*/ /*--------------------------------------------------------------*/ +/* Implement a "p2XA" function ("printf-to-XA"), which printfs into an + XArray of HChar, adding stuff at the end. This is very convenient + for concocting result strings in format_message(). Note that the + resulting string is NOT zero-terminated. + + Unfortunately no format check on p2XA, since we need to use %t + for XML escaped-string output, and gcc complains about that. +*/ +static void add_char_to_XA ( HChar c, void* opaque ) +{ + XArray* dst = (XArray*)opaque; + (void) VG_(addBytesToXA)( dst, &c, 1 ); +} +static void p2XA ( XArray* dst, const HChar* format, ... ) +{ + va_list vargs; + va_start(vargs, format); + VG_(vcbprintf)( add_char_to_XA, (void*)dst, format, vargs ); + va_end(vargs); +} + +/* Add a zero-terminating byte to DST. */ +static void zterm_XA ( XArray* dst ) +{ + HChar zero = 0; + (void) VG_(addBytesToXA)( dst, &zero, 1 ); +} + + /* Evaluate the location expression/list for var, to see whether or not data_addr falls within the variable. If so also return the offset of data_addr from the start of the variable. Note that @@ -2329,13 +2360,14 @@ static Bool data_address_is_in_var ( /*OUT*/PtrdiffT* offset, } -/* Format the acquired information into dname1[0 .. n_dname-1] and - dname2[0 .. n_dname-1] in an understandable way. Not so easy. - If frameNo is -1, this is assumed to be a global variable; else - a local variable. */ -static void format_message ( /*OUT*/Char* dname1, - /*OUT*/Char* dname2, - Int n_dname, +/* Format the acquired information into DN(AME)1 and DN(AME)2, which + are XArray*s of HChar, that have been initialised by the caller. + Resulting strings will be zero terminated. Information is + formatted in an understandable way. Not so easy. If frameNo is + -1, this is assumed to be a global variable; else a local + variable. */ +static void format_message ( /*MOD*/XArray* /* of HChar */ dn1, + /*MOD*/XArray* /* of HChar */ dn2, Addr data_addr, DiVariable* var, PtrdiffT var_offset, @@ -2344,19 +2376,35 @@ static void format_message ( /*OUT*/Char* dname1, Int frameNo, ThreadId tid ) { - Bool have_descr, have_srcloc; + Bool have_descr, have_srcloc; + Bool xml = VG_(clo_xml); UChar* vo_plural = var_offset == 1 ? "" : "s"; UChar* ro_plural = residual_offset == 1 ? "" : "s"; + UChar* basetag = "auxwhat"; /* a constant */ + UChar tagL[32], tagR[32], xagL[32], xagR[32]; vg_assert(frameNo >= -1); - vg_assert(dname1 && dname2 && n_dname > 1); + vg_assert(dn1 && dn2); vg_assert(described); vg_assert(var && var->name); have_descr = VG_(sizeXA)(described) > 0 && *(UChar*)VG_(indexXA)(described,0) != '\0'; have_srcloc = var->fileName && var->lineNo > 0; - dname1[0] = dname2[0] = '\0'; + tagL[0] = tagR[0] = xagL[0] = xagR[0] = 0; + if (xml) { + VG_(sprintf)(tagL, "<%s>", basetag); // + VG_(sprintf)(tagR, "", basetag); // + VG_(sprintf)(xagL, "", basetag); // + VG_(sprintf)(xagR, "", basetag); // + } + +# define TAGL(_xa) p2XA(_xa, "%s", tagL) +# define TAGR(_xa) p2XA(_xa, "%s", tagR) +# define XAGL(_xa) p2XA(_xa, "%s", xagL) +# define XAGR(_xa) p2XA(_xa, "%s", xagR) +# define TXTL(_xa) p2XA(_xa, "%s", "") +# define TXTR(_xa) p2XA(_xa, "%s", "") /* ------ local cases ------ */ @@ -2365,13 +2413,23 @@ static void format_message ( /*OUT*/Char* dname1, Location 0x7fefff6cf is 543 bytes inside local var "a", in frame #1 of thread 1 */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside local var \"%s\",", - data_addr, var_offset, vo_plural, var->name ); - VG_(snprintf)( - dname2, n_dname, - "in frame #%d of thread %d", frameNo, (Int)tid); + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside local var \"%t\",", + data_addr, var_offset, vo_plural, var->name ); + TAGR( dn1 ); + TAGL( dn2 ); + p2XA( dn2, + "in frame #%d of thread %d", frameNo, (Int)tid ); + TAGR( dn2 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside local var \"%s\",", + data_addr, var_offset, vo_plural, var->name ); + p2XA( dn2, + "in frame #%d of thread %d", frameNo, (Int)tid ); + } } else if ( frameNo >= 0 && have_srcloc && (!have_descr) ) { @@ -2379,14 +2437,31 @@ static void format_message ( /*OUT*/Char* dname1, Location 0x7fefff6cf is 543 bytes inside local var "a" declared at dsyms7.c:17, in frame #1 of thread 1 */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside local var \"%s\"", - data_addr, var_offset, vo_plural, var->name ); - VG_(snprintf)( - dname2, n_dname, - "declared at %s:%d, in frame #%d of thread %d", - var->fileName, var->lineNo, frameNo, (Int)tid); + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside local var \"%t\"", + data_addr, var_offset, vo_plural, var->name ); + TAGR( dn1 ); + XAGL( dn2 ); + TXTL( dn2 ); + p2XA( dn2, + "declared at %t:%d, in frame #%d of thread %d", + var->fileName, var->lineNo, frameNo, (Int)tid ); + TXTR( dn2 ); + // FIXME: also do + p2XA( dn2, + " %t %d ", + var->fileName, var->lineNo ); + XAGR( dn2 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside local var \"%s\"", + data_addr, var_offset, vo_plural, var->name ); + p2XA( dn2, + "declared at %s:%d, in frame #%d of thread %d", + var->fileName, var->lineNo, frameNo, (Int)tid ); + } } else if ( frameNo >= 0 && (!have_srcloc) && have_descr ) { @@ -2394,28 +2469,57 @@ static void format_message ( /*OUT*/Char* dname1, Location 0x7fefff6cf is 2 bytes inside a[3].xyzzy[21].c2 in frame #1 of thread 1 */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside %s%s", - data_addr, residual_offset, ro_plural, var->name, - (char*)(VG_(indexXA)(described,0)) ); - VG_(snprintf)( - dname2, n_dname, - "in frame #%d of thread %d", frameNo, (Int)tid); + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %t%t", + data_addr, residual_offset, ro_plural, var->name, + (HChar*)(VG_(indexXA)(described,0)) ); + TAGR( dn1 ); + TAGL( dn2 ); + p2XA( dn2, + "in frame #%d of thread %d", frameNo, (Int)tid ); + TAGR( dn2 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %s%s", + data_addr, residual_offset, ro_plural, var->name, + (HChar*)(VG_(indexXA)(described,0)) ); + p2XA( dn2, + "in frame #%d of thread %d", frameNo, (Int)tid ); + } } else if ( frameNo >= 0 && have_srcloc && have_descr ) { - /* Location 0x7fefff6cf is 2 bytes inside a[3].xyzzy[21].c2, - declared at dsyms7.c:17, in frame #1 of thread 1 */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside %s%s,", - data_addr, residual_offset, ro_plural, var->name, - (char*)(VG_(indexXA)(described,0)) ); - VG_(snprintf)( - dname2, n_dname, - "declared at %s:%d, in frame #%d of thread %d", - var->fileName, var->lineNo, frameNo, (Int)tid); + /* Location 0x7fefff6cf is 2 bytes inside a[3].xyzzy[21].c2, + declared at dsyms7.c:17, in frame #1 of thread 1 */ + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %t%t,", + data_addr, residual_offset, ro_plural, var->name, + (HChar*)(VG_(indexXA)(described,0)) ); + TAGR( dn1 ); + XAGL( dn2 ); + TXTL( dn2 ); + p2XA( dn2, + "declared at %t:%d, in frame #%d of thread %d", + var->fileName, var->lineNo, frameNo, (Int)tid ); + TXTR( dn2 ); + // FIXME: also do + p2XA( dn2, + " %t %d ", + var->fileName, var->lineNo ); + XAGR( dn2 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %s%s,", + data_addr, residual_offset, ro_plural, var->name, + (HChar*)(VG_(indexXA)(described,0)) ); + p2XA( dn2, + "declared at %s:%d, in frame #%d of thread %d", + var->fileName, var->lineNo, frameNo, (Int)tid ); + } } else /* ------ global cases ------ */ @@ -2423,10 +2527,17 @@ static void format_message ( /*OUT*/Char* dname1, /* no srcloc, no description: Location 0x7fefff6cf is 543 bytes inside global var "a" */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside global var \"%s\"", - data_addr, var_offset, vo_plural, var->name ); + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside global var \"%t\"", + data_addr, var_offset, vo_plural, var->name ); + TAGR( dn1 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside global var \"%s\"", + data_addr, var_offset, vo_plural, var->name ); + } } else if ( frameNo >= -1 && have_srcloc && (!have_descr) ) { @@ -2434,14 +2545,31 @@ static void format_message ( /*OUT*/Char* dname1, Location 0x7fefff6cf is 543 bytes inside global var "a" declared at dsyms7.c:17 */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside global var \"%s\"", - data_addr, var_offset, vo_plural, var->name ); - VG_(snprintf)( - dname2, n_dname, - "declared at %s:%d", - var->fileName, var->lineNo); + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside global var \"%t\"", + data_addr, var_offset, vo_plural, var->name ); + TAGR( dn1 ); + XAGL( dn2 ); + TXTL( dn2 ); + p2XA( dn2, + "declared at %t:%d", + var->fileName, var->lineNo); + TXTR( dn2 ); + // FIXME: also do + p2XA( dn2, + " %t %d ", + var->fileName, var->lineNo ); + XAGR( dn2 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside global var \"%s\"", + data_addr, var_offset, vo_plural, var->name ); + p2XA( dn2, + "declared at %s:%d", + var->fileName, var->lineNo); + } } else if ( frameNo >= -1 && (!have_srcloc) && have_descr ) { @@ -2449,43 +2577,82 @@ static void format_message ( /*OUT*/Char* dname1, Location 0x7fefff6cf is 2 bytes inside a[3].xyzzy[21].c2, a global variable */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside %s%s,", - data_addr, residual_offset, ro_plural, var->name, - (char*)(VG_(indexXA)(described,0)) ); - VG_(snprintf)( - dname2, n_dname, - "a global variable"); + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %t%t,", + data_addr, residual_offset, ro_plural, var->name, + (HChar*)(VG_(indexXA)(described,0)) ); + TAGR( dn1 ); + TAGL( dn2 ); + p2XA( dn2, + "a global variable"); + TAGR( dn2 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %s%s,", + data_addr, residual_offset, ro_plural, var->name, + (char*)(VG_(indexXA)(described,0)) ); + p2XA( dn2, + "a global variable"); + } } else if ( frameNo >= -1 && have_srcloc && have_descr ) { - /* Location 0x7fefff6cf is 2 bytes inside a[3].xyzzy[21].c2, - a global variable declared at dsyms7.c:17 */ - VG_(snprintf)( - dname1, n_dname, - "Location 0x%lx is %lu byte%s inside %s%s,", - data_addr, residual_offset, ro_plural, var->name, - (char*)(VG_(indexXA)(described,0)) ); - VG_(snprintf)( - dname2, n_dname, - "a global variable declared at %s:%d", - var->fileName, var->lineNo); + /* Location 0x7fefff6cf is 2 bytes inside a[3].xyzzy[21].c2, + a global variable declared at dsyms7.c:17 */ + if (xml) { + TAGL( dn1 ); + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %t%t,", + data_addr, residual_offset, ro_plural, var->name, + (HChar*)(VG_(indexXA)(described,0)) ); + TAGR( dn1 ); + XAGL( dn2 ); + TXTL( dn2 ); + p2XA( dn2, + "a global variable declared at %t:%d", + var->fileName, var->lineNo); + TXTR( dn2 ); + // FIXME: also do + p2XA( dn2, + " %t %d ", + var->fileName, var->lineNo ); + XAGR( dn2 ); + } else { + p2XA( dn1, + "Location 0x%lx is %lu byte%s inside %s%s,", + data_addr, residual_offset, ro_plural, var->name, + (HChar*)(VG_(indexXA)(described,0)) ); + p2XA( dn2, + "a global variable declared at %s:%d", + var->fileName, var->lineNo); + } } else vg_assert(0); - dname1[n_dname-1] = dname2[n_dname-1] = 0; + /* Zero terminate both strings */ + zterm_XA( dn1 ); + zterm_XA( dn2 ); + +# undef TAGL +# undef TAGR +# undef XAGL +# undef XAGR +# undef TXTL +# undef TXTR } + /* Determine if data_addr is a local variable in the frame - characterised by (ip,sp,fp), and if so write its description into - dname{1,2}[0..n_dname-1], and return True. If not, return - False. */ + characterised by (ip,sp,fp), and if so write its description at the + ends of DNAME{1,2}, which are XArray*s of HChar, that have been + initialised by the caller, zero terminate both, and return True. + If it's not a local variable in said frame, return False. */ static -Bool consider_vars_in_frame ( /*OUT*/Char* dname1, - /*OUT*/Char* dname2, - Int n_dname, +Bool consider_vars_in_frame ( /*MOD*/XArray* /* of HChar */ dname1, + /*MOD*/XArray* /* of HChar */ dname2, Addr data_addr, Addr ip, Addr sp, Addr fp, /* shown to user: */ @@ -2593,7 +2760,7 @@ Bool consider_vars_in_frame ( /*OUT*/Char* dname1, XArray* described = ML_(describe_type)( &residual_offset, di->admin_tyents, var->typeR, offset ); - format_message( dname1, dname2, n_dname, + format_message( dname1, dname2, data_addr, var, offset, residual_offset, described, frameNo, tid ); VG_(deleteXA)( described ); @@ -2605,15 +2772,24 @@ Bool consider_vars_in_frame ( /*OUT*/Char* dname1, return False; } -/* Try to form some description of data_addr by looking at the DWARF3 +/* Try to form some description of DATA_ADDR by looking at the DWARF3 debug info we have. This considers all global variables, and all - frames in the stacks of all threads. Result (or as much as will - fit) is put into into dname{1,2}[0 .. n_dname-1] and is guaranteed - to be zero terminated. */ -Bool VG_(get_data_description)( /*OUT*/Char* dname1, - /*OUT*/Char* dname2, - Int n_dname, - Addr data_addr ) + frames in the stacks of all threads. Result is written at the ends + of DNAME{1,2}V, which are XArray*s of HChar, that have been + initialised by the caller, and True is returned. If no description + is created, False is returned. Regardless of the return value, + DNAME{1,2}V are guaranteed to be zero terminated after the call. + + Note that after the call, DNAME{1,2} may have more than one + trailing zero, so callers should establish the useful text length + using VG_(strlen) on the contents, rather than VG_(sizeXA) on the + XArray itself. +*/ +Bool VG_(get_data_description)( + /*MOD*/ void* /* really, XArray* of HChar */ dname1v, + /*MOD*/ void* /* really, XArray* of HChar */ dname2v, + Addr data_addr + ) { # define N_FRAMES 8 Addr ips[N_FRAMES], sps[N_FRAMES], fps[N_FRAMES]; @@ -2625,8 +2801,8 @@ Bool VG_(get_data_description)( /*OUT*/Char* dname1, DebugInfo* di; Word j; - vg_assert(n_dname > 1); - dname1[n_dname-1] = dname2[n_dname-1] = 0; + XArray* dname1 = (XArray*)dname1v; + XArray* dname2 = (XArray*)dname2v; if (0) VG_(printf)("get_data_description: dataaddr %#lx\n", data_addr); /* First, see if data_addr is (or is part of) a global variable. @@ -2692,11 +2868,12 @@ Bool VG_(get_data_description)( /*OUT*/Char* dname1, XArray* described = ML_(describe_type)( &residual_offset, di->admin_tyents, var->typeR, offset ); - format_message( dname1, dname2, n_dname, + format_message( dname1, dname2, data_addr, var, offset, residual_offset, described, -1/*frameNo*/, tid ); VG_(deleteXA)( described ); - dname1[n_dname-1] = dname2[n_dname-1] = 0; + zterm_XA( dname1 ); + zterm_XA( dname2 ); return True; } } @@ -2716,12 +2893,13 @@ Bool VG_(get_data_description)( /*OUT*/Char* dname1, while ( VG_(thread_stack_next)(&tid, &stack_min, &stack_max) ) { if (stack_min >= stack_max) continue; /* ignore obviously stupid cases */ - if (consider_vars_in_frame( dname1, dname2, n_dname, + if (consider_vars_in_frame( dname1, dname2, data_addr, VG_(get_IP)(tid), VG_(get_SP)(tid), VG_(get_FP)(tid), tid, 0 )) { - dname1[n_dname-1] = dname2[n_dname-1] = 0; + zterm_XA( dname1 ); + zterm_XA( dname2 ); return True; } } @@ -2740,7 +2918,8 @@ Bool VG_(get_data_description)( /*OUT*/Char* dname1, } } if (!found) { - dname1[n_dname-1] = dname2[n_dname-1] = 0; + zterm_XA( dname1 ); + zterm_XA( dname2 ); return False; } @@ -2755,11 +2934,12 @@ Bool VG_(get_data_description)( /*OUT*/Char* dname1, Oh well. */ vg_assert(n_frames >= 0 && n_frames <= N_FRAMES); for (j = 0; j < n_frames; j++) { - if (consider_vars_in_frame( dname1, dname2, n_dname, + if (consider_vars_in_frame( dname1, dname2, data_addr, ips[j], sps[j], fps[j], tid, j )) { - dname1[n_dname-1] = dname2[n_dname-1] = 0; + zterm_XA( dname1 ); + zterm_XA( dname2 ); return True; } /* Now, it appears that gcc sometimes appears to produce @@ -2781,17 +2961,19 @@ Bool VG_(get_data_description)( /*OUT*/Char* dname1, either (1) I misunderstood something, or (2) GDB has an equivalent kludge. */ if (j > 0 /* this is a non-innermost frame */ - && consider_vars_in_frame( dname1, dname2, n_dname, + && consider_vars_in_frame( dname1, dname2, data_addr, ips[j] + 1, sps[j], fps[j], tid, j )) { - dname1[n_dname-1] = dname2[n_dname-1] = 0; + zterm_XA( dname1 ); + zterm_XA( dname2 ); return True; } } /* We didn't find anything useful. */ - dname1[n_dname-1] = dname2[n_dname-1] = 0; + zterm_XA( dname1 ); + zterm_XA( dname2 ); return False; # undef N_FRAMES } diff --git a/coregrind/m_debuginfo/readdwarf.c b/coregrind/m_debuginfo/readdwarf.c index 24bb473384..02716576d7 100644 --- a/coregrind/m_debuginfo/readdwarf.c +++ b/coregrind/m_debuginfo/readdwarf.c @@ -347,7 +347,7 @@ Word process_extended_line_op( struct _DebugInfo* di, if (len == 0) { VG_(message)(Vg_UserMsg, "Warning: DWARF2 reader: " - "Badly formed extended line op encountered"); + "Badly formed extended line op encountered\n"); return (Word)bytes_read; } @@ -2167,7 +2167,7 @@ static Bool summarise_context( /*OUT*/DiCfSI* si, if (VG_(clo_verbosity) > 2 || debuginfo->trace_cfi) { VG_(message)(Vg_DebugMsg, "summarise_context(loc_start = %#lx)" - ": cannot summarise(why=%d): ", loc_start, why); + ": cannot summarise(why=%d): \n", loc_start, why); ppUnwindContext(ctx); } return False; @@ -2648,7 +2648,7 @@ static Int dwarfexpr_to_dag ( UnwindContext* ctx, if (!VG_(clo_xml)) VG_(message)(Vg_DebugMsg, "Warning: DWARF2 CFI reader: unhandled DW_OP_ " - "opcode 0x%x", (Int)opcode); + "opcode 0x%x\n", (Int)opcode); return -1; } @@ -3089,7 +3089,7 @@ static Int run_CF_instruction ( /*MOD*/UnwindContext* ctx, default: VG_(message)(Vg_DebugMsg, "DWARF2 CFI reader: unhandled CFI " - "instruction 0:%d", (Int)lo6); + "instruction 0:%d\n", (Int)lo6); if (di->ddump_frames) VG_(printf)(" rci:run_CF_instruction:default\n"); i = 0; @@ -3877,7 +3877,8 @@ void ML_(read_callframe_info_dwarf3) bad: if (!VG_(clo_xml) && VG_(clo_verbosity) > 1) - VG_(message)(Vg_UserMsg, "Warning: %s in DWARF2 CFI reading", how); + VG_(message)(Vg_UserMsg, + "Warning: %s in DWARF2 CFI reading\n", how); return; } diff --git a/coregrind/m_debuginfo/readdwarf3.c b/coregrind/m_debuginfo/readdwarf3.c index db46cc3688..3c194b961c 100644 --- a/coregrind/m_debuginfo/readdwarf3.c +++ b/coregrind/m_debuginfo/readdwarf3.c @@ -1675,7 +1675,7 @@ static void parse_var_DIE ( if (0 && VG_(clo_verbosity) >= 0) { VG_(message)(Vg_DebugMsg, "warning: parse_var_DIE: non-external variable " - "outside DW_TAG_subprogram"); + "outside DW_TAG_subprogram\n"); } /* goto bad_DIE; */ /* This seems to happen a lot. Just ignore it -- if, diff --git a/coregrind/m_debuginfo/readelf.c b/coregrind/m_debuginfo/readelf.c index 2da1cf258e..02cea02bb6 100644 --- a/coregrind/m_debuginfo/readelf.c +++ b/coregrind/m_debuginfo/readelf.c @@ -925,7 +925,7 @@ Addr open_debug_file( Char* name, UInt crc, /*OUT*/UWord* size ) } if (VG_(clo_verbosity) > 1) - VG_(message)(Vg_DebugMsg, "Reading debug info from %s ..", name); + VG_(message)(Vg_DebugMsg, "Reading debug info from %s ..\n", name); *size = stat_buf.size; @@ -943,7 +943,7 @@ Addr open_debug_file( Char* name, UInt crc, /*OUT*/UWord* size ) vg_assert(!sr_isError(res)); if (VG_(clo_verbosity) > 1) VG_(message)(Vg_DebugMsg, - ".. CRC mismatch (computed %08x wanted %08x)", calccrc, crc); + ".. CRC mismatch (computed %08x wanted %08x)\n", calccrc, crc); return 0; } @@ -1115,7 +1115,7 @@ Bool ML_(read_elf_debug_info) ( struct _DebugInfo* di ) oimage = (Addr)NULL; if (VG_(clo_verbosity) > 1 || VG_(clo_trace_redir)) - VG_(message)(Vg_DebugMsg, "Reading syms from %s (%#lx)", + VG_(message)(Vg_DebugMsg, "Reading syms from %s (%#lx)\n", di->filename, di->rx_map_avma ); /* mmap the object image aboard, so that we can read symbols and @@ -1143,8 +1143,8 @@ Bool ML_(read_elf_debug_info) ( struct _DebugInfo* di ) VG_(close)(sr_Res(fd)); if (sr_isError(sres)) { - VG_(message)(Vg_UserMsg, "warning: mmap failed on %s", di->filename ); - VG_(message)(Vg_UserMsg, " no symbols or debug info loaded" ); + VG_(message)(Vg_UserMsg, "warning: mmap failed on %s\n", di->filename ); + VG_(message)(Vg_UserMsg, " no symbols or debug info loaded\n" ); return False; } @@ -1491,11 +1491,12 @@ Bool ML_(read_elf_debug_info) ( struct _DebugInfo* di ) di->bss_debug_svma = 0; di->bss_debug_bias = 0; if (!VG_(clo_xml)) { - VG_(message)(Vg_UserMsg, "Warning: the following file's .bss is " - "mapped r-x only - ignoring .bss syms"); - VG_(message)(Vg_UserMsg, " %s", di->filename - ? di->filename - : (UChar*)"(null?!)" ); + VG_(message)(Vg_UserMsg, + "Warning: the following file's .bss is " + "mapped r-x only - ignoring .bss syms\n"); + VG_(message)(Vg_UserMsg, " %s\n", di->filename + ? di->filename + : (UChar*)"(null?!)" ); } } else @@ -1646,7 +1647,7 @@ Bool ML_(read_elf_debug_info) ( struct _DebugInfo* di ) di->text_avma, di->text_size, di->text_bias); if (VG_(clo_verbosity) > 2 || VG_(clo_trace_redir)) - VG_(message)(Vg_DebugMsg, " svma %#010lx, avma %#010lx", + VG_(message)(Vg_DebugMsg, " svma %#010lx, avma %#010lx\n", di->text_avma - di->text_bias, di->text_avma ); diff --git a/coregrind/m_debuginfo/readpdb.c b/coregrind/m_debuginfo/readpdb.c index 88fb7f6731..2eae5da753 100644 --- a/coregrind/m_debuginfo/readpdb.c +++ b/coregrind/m_debuginfo/readpdb.c @@ -1220,8 +1220,9 @@ static ULong DEBUG_SnarfCodeView( ULong n_syms_read = 0; if (debug) - VG_(message)(Vg_UserMsg, "SnarfCodeView addr=%p offset=%d length=%d", - root, offset, size ); + VG_(message)(Vg_UserMsg, + "SnarfCodeView addr=%p offset=%d length=%d\n", + root, offset, size ); VG_(memset)(&vsym, 0, sizeof(vsym)); /* avoid holes */ /* @@ -1261,7 +1262,7 @@ static ULong DEBUG_SnarfCodeView( symname[sym->data_v1.p_name.namelen] = '\0'; if (debug) - VG_(message)(Vg_UserMsg, "Data %s", symname ); + VG_(message)(Vg_UserMsg, "Data %s\n", symname ); if (0 /*VG_(needs).data_syms*/) { nmstr = ML_(addStr)(di, symname, sym->data_v1.p_name.namelen); @@ -1285,7 +1286,7 @@ static ULong DEBUG_SnarfCodeView( if (debug) VG_(message)(Vg_UserMsg, - "S_GDATA_V2/S_LDATA_V2/S_PUB_V2 %s", symname ); + "S_GDATA_V2/S_LDATA_V2/S_PUB_V2 %s\n", symname ); if (sym->generic.id==S_PUB_V2 /*VG_(needs).data_syms*/) { nmstr = ML_(addStr)(di, symname, k); @@ -1315,7 +1316,8 @@ static ULong DEBUG_SnarfCodeView( if (debug) VG_(message)(Vg_UserMsg, - "S_PUB_FUNC1_V3/S_PUB_FUNC2_V3/S_PUB_V3 %s", symname ); + "S_PUB_FUNC1_V3/S_PUB_FUNC2_V3/S_PUB_V3 %s\n", + symname ); if (1 /*sym->generic.id==S_PUB_FUNC1_V3 || sym->generic.id==S_PUB_FUNC2_V3*/) { @@ -1361,8 +1363,9 @@ static ULong DEBUG_SnarfCodeView( vsym.size = sym->proc_v1.proc_len; vsym.isText = True; if (debug) - VG_(message)(Vg_UserMsg, "Adding function %s addr=%#lx length=%d", - symname, vsym.addr, vsym.size ); + VG_(message)(Vg_UserMsg, + "Adding function %s addr=%#lx length=%d\n", + symname, vsym.addr, vsym.size ); ML_(addSym)( di, &vsym ); n_syms_read++; break; @@ -1380,8 +1383,9 @@ static ULong DEBUG_SnarfCodeView( vsym.size = sym->proc_v2.proc_len; vsym.isText = True; if (debug) - VG_(message)(Vg_UserMsg, "Adding function %s addr=%#lx length=%d", - symname, vsym.addr, vsym.size ); + VG_(message)(Vg_UserMsg, + "Adding function %s addr=%#lx length=%d\n", + symname, vsym.addr, vsym.size ); ML_(addSym)( di, &vsym ); n_syms_read++; break; @@ -1389,7 +1393,7 @@ static ULong DEBUG_SnarfCodeView( case S_GPROC_V3: { if (debug) VG_(message)(Vg_UserMsg, - "S_LPROC_V3/S_GPROC_V3 %s", sym->proc_v3.name ); + "S_LPROC_V3/S_GPROC_V3 %s\n", sym->proc_v3.name ); if (1) { nmstr = ML_(addStr)(di, sym->proc_v3.name, @@ -1590,7 +1594,7 @@ static ULong DEBUG_SnarfLinetab( if (debug) VG_(message)(Vg_UserMsg, - "Adding %d lines for file %s segment %d addr=%#x end=%#x", + "Adding %d lines for file %s segment %d addr=%#x end=%#x\n", linecount, filename, segno, start[k].start, start[k].end ); for ( j = 0; j < linecount; j++ ) { @@ -1602,7 +1606,7 @@ static ULong DEBUG_SnarfLinetab( : start[k].end); if (debug) VG_(message)(Vg_UserMsg, - "Adding line %d addr=%#lx end=%#lx", + "Adding line %d addr=%#lx end=%#lx\n", ((unsigned short *)(pnt2.ui + linecount))[j], startaddr, endaddr ); ML_(addLineInfo)( @@ -1811,21 +1815,21 @@ static void pdb_dump( struct pdb_reader* pdb, if (VG_(clo_verbosity) > 0) { VG_(message)(Vg_DebugMsg, - "PDB_READER:"); + "PDB_READER:\n"); VG_(message)(Vg_DebugMsg, - " BIAS_FOR_SYMBOLS = %#08lx %s", + " BIAS_FOR_SYMBOLS = %#08lx %s\n", (PtrdiffT)BIAS_FOR_SYMBOLS, VG_STRINGIFY(BIAS_FOR_SYMBOLS)); VG_(message)(Vg_DebugMsg, - " BIAS_FOR_LINETAB = %#08lx %s", + " BIAS_FOR_LINETAB = %#08lx %s\n", (PtrdiffT)BIAS_FOR_LINETAB, VG_STRINGIFY(BIAS_FOR_LINETAB)); VG_(message)(Vg_DebugMsg, - " BIAS_FOR_LINETAB2 = %#08lx %s", + " BIAS_FOR_LINETAB2 = %#08lx %s\n", (PtrdiffT)BIAS_FOR_LINETAB2, VG_STRINGIFY(BIAS_FOR_LINETAB2)); VG_(message)(Vg_DebugMsg, - " BIAS_FOR_FPO = %#08lx %s", + " BIAS_FOR_FPO = %#08lx %s\n", (PtrdiffT)BIAS_FOR_FPO, VG_STRINGIFY(BIAS_FOR_FPO)); VG_(message)(Vg_DebugMsg, - " RELOC = %#08lx", + " RELOC = %#08lx\n", (PtrdiffT)reloc); } @@ -1917,8 +1921,9 @@ static void pdb_dump( struct pdb_reader* pdb, break; default: if (VG_(clo_verbosity) > 1) - VG_(message)(Vg_UserMsg, "Unknown .pdb type info version %ld\n", - types.version ); + VG_(message)(Vg_UserMsg, + "Unknown .pdb type info version %ld\n", + types.version ); } header_size = 0; @@ -1931,8 +1936,9 @@ static void pdb_dump( struct pdb_reader* pdb, break; default: if (VG_(clo_verbosity) > 1) - VG_(message)(Vg_UserMsg, "Unknown .pdb symbol info version %ld\n", - symbols.version ); + VG_(message)(Vg_UserMsg, + "Unknown .pdb symbol info version %ld\n", + symbols.version ); } /* @@ -1980,7 +1986,8 @@ static void pdb_dump( struct pdb_reader* pdb, if (symbol_size) { if (VG_(clo_verbosity) > 1) - VG_(message)(Vg_UserMsg, "Reading symbols for %s", file_name ); + VG_(message)(Vg_UserMsg, "Reading symbols for %s\n", + file_name ); n_syms_read += DEBUG_SnarfCodeView( di, sectp_avma, modimage, sizeof(unsigned long), @@ -1989,7 +1996,7 @@ static void pdb_dump( struct pdb_reader* pdb, if (lineno_size) { if (VG_(clo_verbosity) > 1) - VG_(message)(Vg_UserMsg, "Reading lines for %s", file_name ); + VG_(message)(Vg_UserMsg, "Reading lines for %s\n", file_name ); n_lines_read += DEBUG_SnarfLinetab( di, sectp_avma, modimage + symbol_size, lineno_size ); @@ -2027,10 +2034,14 @@ static void pdb_dump( struct pdb_reader* pdb, if ( pdb->u.jg.toc ) ML_(dinfo_free)( pdb->u.jg.toc ); if (VG_(clo_verbosity) > 0) { - VG_(message)(Vg_DebugMsg," # symbols read = %llu", n_syms_read ); - VG_(message)(Vg_DebugMsg," # lines read = %llu", n_lines_read ); - VG_(message)(Vg_DebugMsg," # line2s read = %llu", n_line2s_read ); - VG_(message)(Vg_DebugMsg," # fpos read = %llu", n_fpos_read ); + VG_(message)(Vg_DebugMsg, + " # symbols read = %llu\n", n_syms_read ); + VG_(message)(Vg_DebugMsg, + " # lines read = %llu\n", n_lines_read ); + VG_(message)(Vg_DebugMsg, + " # line2s read = %llu\n", n_line2s_read ); + VG_(message)(Vg_DebugMsg, + " # fpos read = %llu\n", n_fpos_read ); } } @@ -2063,7 +2074,7 @@ Bool ML_(read_pdb_debug_info)( IMAGE_SECTION_HEADER* pe_sechdr_avma; if (VG_(clo_verbosity) > 1) - VG_(message)(Vg_UserMsg, "Processing PDB file %s ", pdbname ); + VG_(message)(Vg_UserMsg, "Processing PDB file %s\n", pdbname ); dos_avma = (IMAGE_DOS_HEADER *)obj_avma; if (dos_avma->e_magic != IMAGE_DOS_SIGNATURE) @@ -2103,7 +2114,7 @@ Bool ML_(read_pdb_debug_info)( if (VG_(clo_verbosity) > 1) VG_(message)(Vg_UserMsg, - " Scanning PE section %s at avma %p svma %#lx", + " Scanning PE section %s at avma %p svma %#lx\n", pe_sechdr_avma->Name, pe_seg_avma, pe_sechdr_avma->VirtualAddress); @@ -2114,7 +2125,7 @@ Bool ML_(read_pdb_debug_info)( mapped_end_avma = mapped_avma + pe_sechdr_avma->Misc.VirtualSize; if (VG_(clo_verbosity) > 1) VG_(message)(Vg_DebugMsg, - " ::: mapped_avma is %#lx", mapped_avma); + " ::: mapped_avma is %#lx\n", mapped_avma); if (pe_sechdr_avma->Characteristics & IMAGE_SCN_CNT_CODE) { /* Ignore uninitialised code sections - if you have diff --git a/coregrind/m_debuginfo/readstabs.c b/coregrind/m_debuginfo/readstabs.c index 1cd72c6193..c8eaf2e0fb 100644 --- a/coregrind/m_debuginfo/readstabs.c +++ b/coregrind/m_debuginfo/readstabs.c @@ -258,7 +258,7 @@ void ML_(read_debuginfo_stabs) ( DebugInfo* di, VG_(message)(Vg_UserMsg, "Warning: file %s is very big (> 65535 lines) " "Line numbers and annotation for this file might " - "be wrong. Sorry", + "be wrong. Sorry.\n", file.name); /* FALLTHROUGH */ @@ -304,7 +304,7 @@ void ML_(read_debuginfo_stabs) ( DebugInfo* di, if (line.prev > line.no + OVERFLOW_DIFFERENCE && file.same) { VG_(message)(Vg_DebugMsg, - "Line number overflow detected (%d --> %d) in %s", + "Line number overflow detected (%d --> %d) in %s\n", line.prev, line.no, file.name); line.ovf++; } diff --git a/coregrind/m_debuginfo/readxcoff.c b/coregrind/m_debuginfo/readxcoff.c index 1be4e94f7a..466e423422 100644 --- a/coregrind/m_debuginfo/readxcoff.c +++ b/coregrind/m_debuginfo/readxcoff.c @@ -1538,7 +1538,7 @@ HChar* read_symbol_table ( "fixme-Name-printing(5)" /*s->name*/ ); if (guessed_toc) - VG_(message)(Vg_DebugMsg, "WARNING: assuming toc 0x%lx for %s", + VG_(message)(Vg_DebugMsg, "WARNING: assuming toc 0x%lx for %s\n", s->r2value, dis.name); } } @@ -2424,10 +2424,10 @@ Bool ML_(read_xcoff_debug_info) ( struct _DebugInfo* di, if (VG_(clo_verbosity) > 1 || VG_(clo_trace_redir)) { if (di->memname) { - VG_(message)(Vg_DebugMsg, "Reading syms from %s(%s) (%#lx)", + VG_(message)(Vg_DebugMsg, "Reading syms from %s(%s) (%#lx)\n", di->filename, di->memname, di->text_avma); } else { - VG_(message)(Vg_DebugMsg, "Reading syms from %s (%#lx)", + VG_(message)(Vg_DebugMsg, "Reading syms from %s (%#lx)\n", di->filename, di->text_avma); } } diff --git a/coregrind/m_debuginfo/storage.c b/coregrind/m_debuginfo/storage.c index f8d0834c85..49ba306e33 100644 --- a/coregrind/m_debuginfo/storage.c +++ b/coregrind/m_debuginfo/storage.c @@ -68,20 +68,20 @@ void ML_(symerr) ( struct _DebugInfo* di, Bool serious, HChar* msg ) if (serious) { VG_(message)(Vg_DebugMsg, "WARNING: Serious error when " - "reading debug info"); + "reading debug info\n"); if (True || VG_(clo_verbosity) < 2) { /* Need to show what the file name is, at verbosity levels 2 or below, since that won't already have been shown */ VG_(message)(Vg_DebugMsg, - "When reading debug info from %s:", + "When reading debug info from %s:\n", (di && di->filename) ? di->filename : (UChar*)"???"); } - VG_(message)(Vg_DebugMsg, "%s", msg); + VG_(message)(Vg_DebugMsg, "%s\n", msg); } else { /* !serious */ if (VG_(clo_verbosity) >= 2) - VG_(message)(Vg_DebugMsg, "%s", msg); + VG_(message)(Vg_DebugMsg, "%s\n", msg); } } @@ -90,11 +90,11 @@ void ML_(symerr) ( struct _DebugInfo* di, Bool serious, HChar* msg ) /* Print a symbol. */ void ML_(ppSym) ( Int idx, DiSym* sym ) { - VG_(printf)( "%5d: %#8lx .. %#8lx (%d) %s\n", - idx, - sym->addr, - sym->addr + sym->size - 1, sym->size, - sym->name ); + VG_(printf)( "%5d: %#8lx .. %#8lx (%d) %s\n", + idx, + sym->addr, + sym->addr + sym->size - 1, sym->size, + sym->name ); } /* Print a call-frame-info summary. */ @@ -329,7 +329,7 @@ void ML_(addLineInfo) ( struct _DebugInfo* di, if (VG_(clo_verbosity) > 2) { VG_(message)(Vg_DebugMsg, "warning: line info addresses out of order " - "at entry %d: 0x%lx 0x%lx", entry, this, next); + "at entry %d: 0x%lx 0x%lx\n", entry, this, next); } size = 1; } @@ -338,7 +338,7 @@ void ML_(addLineInfo) ( struct _DebugInfo* di, if (0) VG_(message)(Vg_DebugMsg, "warning: line info address range too large " - "at entry %d: %d", entry, size); + "at entry %d: %d\n", entry, size); size = 1; } @@ -351,7 +351,7 @@ void ML_(addLineInfo) ( struct _DebugInfo* di, if (0) VG_(message)(Vg_DebugMsg, "warning: ignoring line info entry falling " - "outside current DebugInfo: %#lx %#lx %#lx %#lx", + "outside current DebugInfo: %#lx %#lx %#lx %#lx\n", di->text_avma, di->text_avma + di->text_size, this, next-1); @@ -365,12 +365,12 @@ void ML_(addLineInfo) ( struct _DebugInfo* di, complained = True; VG_(message)(Vg_UserMsg, "warning: ignoring line info entry with " - "huge line number (%d)", lineno); + "huge line number (%d)\n", lineno); VG_(message)(Vg_UserMsg, " Can't handle line numbers " - "greater than %d, sorry", MAX_LINENO); + "greater than %d, sorry\n", MAX_LINENO); VG_(message)(Vg_UserMsg, - "(Nb: this message is only shown once)"); + "(Nb: this message is only shown once)\n"); } return; } @@ -382,7 +382,7 @@ void ML_(addLineInfo) ( struct _DebugInfo* di, loc.dirname = dirname; if (0) VG_(message)(Vg_DebugMsg, - "addLoc: addr %#lx, size %d, line %d, file %s", + "addLoc: addr %#lx, size %d, line %d, file %s\n", this,size,lineno,filename); addLoc ( di, &loc ); @@ -433,7 +433,7 @@ void ML_(addDiCfSI) ( struct _DebugInfo* di, DiCfSI* cfsi_orig ) if (VG_(clo_verbosity) > 1) { VG_(message)( Vg_DebugMsg, - "warning: DiCfSI %#lx .. %#lx outside segment %#lx .. %#lx", + "warning: DiCfSI %#lx .. %#lx outside segment %#lx .. %#lx\n", cfsi.base, cfsi.base + cfsi.len - 1, di->text_avma, @@ -871,7 +871,7 @@ void ML_(addVar)( struct _DebugInfo* di, if (VG_(clo_verbosity) >= 0) { VG_(message)(Vg_DebugMsg, "warning: addVar: in range %#lx .. %#lx outside " - "segment %#lx .. %#lx (%s)", + "segment %#lx .. %#lx (%s)\n", aMin, aMax, di->text_avma, di->text_avma + di->text_size -1, name @@ -898,7 +898,7 @@ void ML_(addVar)( struct _DebugInfo* di, if (badness) { static Int complaints = 10; if (VG_(clo_verbosity) >= 2 && complaints > 0) { - VG_(message)(Vg_DebugMsg, "warning: addVar: %s (%s)", + VG_(message)(Vg_DebugMsg, "warning: addVar: %s (%s)\n", badness, name ); complaints--; } diff --git a/coregrind/m_demangle/demangle.c b/coregrind/m_demangle/demangle.c index 7d8f6e3a11..9ad4b26bca 100644 --- a/coregrind/m_demangle/demangle.c +++ b/coregrind/m_demangle/demangle.c @@ -297,12 +297,14 @@ Bool VG_(maybe_Z_demangle) ( const HChar* sym, if (error) { /* Something's wrong. Give up. */ - VG_(message)(Vg_UserMsg, "m_demangle: error Z-demangling: %s", sym); + VG_(message)(Vg_UserMsg, + "m_demangle: error Z-demangling: %s\n", sym); return False; } if (oflow) { /* It didn't fit. Give up. */ - VG_(message)(Vg_UserMsg, "m_demangle: oflow Z-demangling: %s", sym); + VG_(message)(Vg_UserMsg, + "m_demangle: oflow Z-demangling: %s\n", sym); return False; } diff --git a/coregrind/m_errormgr.c b/coregrind/m_errormgr.c index a5ef3c8055..64ae47aa93 100644 --- a/coregrind/m_errormgr.c +++ b/coregrind/m_errormgr.c @@ -261,7 +261,8 @@ Bool VG_(showing_core_errors)(void) return VG_(needs).core_errors && VG_(clo_verbosity) >= 1 && !VG_(clo_xml); } -/* Compare errors, to detect duplicates. */ +/* Compare errors, to detect duplicates. +*/ static Bool eq_Error ( VgRes res, Error* e1, Error* e2 ) { if (e1->ekind != e2->ekind) @@ -286,54 +287,99 @@ static Bool eq_Error ( VgRes res, Error* e1, Error* e2 ) } } -static void pp_Error ( Error* err ) + +/* Helper function for suppression generation: print a single line of + a suppression pseudo-stack-trace, either in XML or text mode. +*/ +#define ERRTXT_LEN 4096 + +static void printSuppForIp(UInt n, Addr ip) { - if (VG_(clo_xml)) { - VG_UMSG(""); - VG_UMSG(" 0x%x", err->unique); - VG_UMSG(" %d", err->tid); + static UChar buf[ERRTXT_LEN]; + + if ( VG_(get_fnname_no_cxx_demangle) (ip, buf, ERRTXT_LEN) ) { + if (VG_(clo_xml)) + VG_(printf_xml_no_f_c)(" %t \n", buf); + else + VG_(printf)(" fun:%s\n", buf); + + } else if ( VG_(get_objname)(ip, buf, ERRTXT_LEN) ) { + if (VG_(clo_xml)) + VG_(printf_xml_no_f_c)(" %t \n", buf); + else + VG_(printf)(" obj:%s\n", buf); + + } else { + if (VG_(clo_xml)) + VG_(printf_xml_no_f_c)(" * \n"); + else + VG_(printf)(" obj:*\n"); } +} - if (!VG_(clo_xml)) { - if (VG_(tdict).tool_show_ThreadIDs_for_errors - && err->tid > 0 && err->tid != last_tid_printed) { - VG_UMSG("Thread %d:", err->tid ); - last_tid_printed = err->tid; + +/* Generate a suppression for an error, either in text or XML mode. +*/ +static void gen_suppression(Error* err) +{ + ExeContext* ec = VG_(get_error_where)(err); + + //(example code, see comment on CoreSuppKind above) + if (0) { + //if (0) ThreadErr == err->ekind) { + // VG_(printf)("{\n"); + // VG_(printf)(" \n"); + // VG_(printf)(" core:Thread\n"); + + } else { + Char* name = VG_TDICT_CALL(tool_get_error_name, err); + if (NULL == name) { + VG_(umsg)("(%s does not allow error to be suppressed)\n", + VG_(details).name); + return; } + if (VG_(clo_xml)) { + VG_(printf_xml)(" \n"); + VG_(printf_xml)(" insert_a_suppression_name_here\n"); + VG_(printf_xml)(" %s:%s\n", VG_(details).name, name); + } else { + VG_(printf)("{\n"); + VG_(printf)(" \n"); + VG_(printf)(" %s:%s\n", VG_(details).name, name); + } + VG_TDICT_CALL(tool_print_extra_suppression_info, err); } - switch (err->ekind) { - //(example code, see comment on CoreSuppKind above) - //case ThreadErr: - // vg_assert(VG_(needs).core_errors); - // VG_(tm_error_print)(err); - // break; - default: - if (VG_(needs).tool_errors) - VG_TDICT_CALL( tool_pp_Error, err ); - else { - VG_(printf)("\nUnhandled error type: %u. VG_(needs).tool_errors\n" - "probably needs to be set?\n", - err->ekind); - VG_(tool_panic)("unhandled error type"); - } - } + // Print stack trace elements + VG_(apply_StackTrace)(printSuppForIp, + VG_(get_ExeContext_StackTrace)(ec), + VG_(get_ExeContext_n_ips)(ec)); - if (VG_(clo_xml)) - VG_UMSG(""); + if (VG_(clo_xml)) { + VG_(printf_xml)(" \n"); + } else { + VG_(printf)("}\n"); + } } -/* Figure out if we want to perform a given action for this error, possibly - by asking the user. */ + +/* Figure out if we want to perform a given action for this error, + possibly by asking the user. +*/ Bool VG_(is_action_requested) ( Char* action, Bool* clo ) { Char ch, ch2; Int res; + /* First off, we shouldn't be asking the user anything if + we're in XML mode. */ + if (VG_(clo_xml)) + return False; /* That's a Nein, oder Nay as they say down here in B-W */ + if (*clo == False) return False; - VG_UMSG(""); + VG_(umsg)("\n"); again: VG_(printf)( @@ -366,8 +412,120 @@ Bool VG_(is_action_requested) ( Char* action, Bool* clo ) } +/* Do text-mode actions on error, that is, immediately after an error + is printed. These are: + * possibly, attach to a debugger + * possibly, generate a suppression. + Note this should not be called in XML mode! +*/ +static +void do_actions_on_error(Error* err, Bool allow_db_attach) +{ + Bool still_noisy = True; + + /* Should be assured by caller */ + vg_assert( ! VG_(clo_xml) ); + + /* Perhaps we want a debugger attach at this point? */ + if (allow_db_attach && + VG_(is_action_requested)( "Attach to debugger", & VG_(clo_db_attach) )) + { + if (0) VG_(printf)("starting debugger\n"); + VG_(start_debugger)( err->tid ); + } + /* Or maybe we want to generate the error's suppression? */ + if (VG_(clo_gen_suppressions) == 2 + || (VG_(clo_gen_suppressions) == 1 + && VG_(is_action_requested)( "Print suppression", &still_noisy )) + ) { + gen_suppression(err); + } + if (VG_(clo_gen_suppressions) == 1 && !still_noisy) + VG_(clo_gen_suppressions) = 0; +} + + +/* Prints an error. Not entirely simple because of the differences + between XML and text mode output. + + In XML mode: + + * calls the tool's pre-show method, so the tool can create any + preamble ahead of the message, if it wants. + + * prints the opening tag, and the and fields + + * prints the tool-specific parts of the message + + * if suppression generation is required, a suppression + + * the closing tag + + In text mode: + + * calls the tool's pre-show method, so the tool can create any + preamble ahead of the message, if it wants. + + * prints the tool-specific parts of the message + + * calls do_actions_on_error. This optionally does a debugger + attach (and detach), and optionally prints a suppression; both + of these may require user input. +*/ +static void pp_Error ( Error* err, Bool allow_db_attach ) +{ + /* If this fails, you probably specified your tool's method + dictionary incorrectly. */ + vg_assert(VG_(needs).tool_errors); + + if (VG_(clo_xml)) { + + /* Note, allow_db_attach is ignored in here. */ + + /* Ensure that suppression generation is either completely + enabled or completely disabled; either way, we won't require + any user input. m_main.process_cmd_line_options should + ensure the asserted condition holds. */ + vg_assert( VG_(clo_gen_suppressions) == 0 /* disabled */ + || VG_(clo_gen_suppressions) == 2 /* for all errors */ ); + + /* Pre-show it to the tool */ + VG_TDICT_CALL( tool_before_pp_Error, err ); + + /* standard preamble */ + VG_(printf_xml)("\n"); + VG_(printf_xml)(" 0x%x\n", err->unique); + VG_(printf_xml)(" %d\n", err->tid); + + /* actually print it */ + VG_TDICT_CALL( tool_pp_Error, err ); + + if (VG_(clo_gen_suppressions) > 0) + gen_suppression(err); + + /* postamble */ + VG_(printf_xml)("\n"); + + } else { + + VG_TDICT_CALL( tool_before_pp_Error, err ); + + if (VG_(tdict).tool_show_ThreadIDs_for_errors + && err->tid > 0 && err->tid != last_tid_printed) { + VG_(umsg)("Thread %d:\n", err->tid ); + last_tid_printed = err->tid; + } + + VG_TDICT_CALL( tool_pp_Error, err ); + + do_actions_on_error(err, allow_db_attach); + + } +} + + /* Construct an error */ -static __inline__ +static void construct_error ( Error* err, ThreadId tid, ErrorKind ekind, Addr a, Char* s, void* extra, ExeContext* where ) { @@ -397,75 +555,7 @@ void construct_error ( Error* err, ThreadId tid, ErrorKind ekind, Addr a, vg_assert( tid < VG_N_THREADS ); } -#define ERRTXT_LEN 4096 - -static void printSuppForIp(UInt n, Addr ip) -{ - static UChar buf[ERRTXT_LEN]; - - if ( VG_(get_fnname_no_cxx_demangle) (ip, buf, ERRTXT_LEN) ) { - VG_(printf)(" fun:%s\n", buf); - } else if ( VG_(get_objname)(ip, buf, ERRTXT_LEN) ) { - VG_(printf)(" obj:%s\n", buf); - } else { - VG_(printf)(" obj:*\n"); - } -} - -static void gen_suppression(Error* err) -{ - ExeContext* ec = VG_(get_error_where)(err); - - //(example code, see comment on CoreSuppKind above) - if (0) { - //if (0) ThreadErr == err->ekind) { - // VG_(printf)("{\n"); - // VG_(printf)(" \n"); - // VG_(printf)(" core:Thread\n"); - - } else { - Char* name = VG_TDICT_CALL(tool_get_error_name, err); - if (NULL == name) { - VG_UMSG("(%s does not allow error to be suppressed)", - VG_(details).name); - return; - } - VG_(printf)("{\n"); - VG_(printf)(" \n"); - VG_(printf)(" %s:%s\n", VG_(details).name, name); - VG_TDICT_CALL(tool_print_extra_suppression_info, err); - } - - // Print stack trace elements - VG_(apply_StackTrace)(printSuppForIp, - VG_(get_ExeContext_StackTrace)(ec), - VG_(get_ExeContext_n_ips)(ec)); - - VG_(printf)("}\n"); -} - -static -void do_actions_on_error(Error* err, Bool allow_db_attach) -{ - Bool still_noisy = True; - /* Perhaps we want a debugger attach at this point? */ - if (allow_db_attach && - VG_(is_action_requested)( "Attach to debugger", & VG_(clo_db_attach) )) - { - if (0) VG_(printf)("starting debugger\n"); - VG_(start_debugger)( err->tid ); - } - /* Or maybe we want to generate the error's suppression? */ - if (VG_(clo_gen_suppressions) == 2 - || (VG_(clo_gen_suppressions) == 1 - && VG_(is_action_requested)( "Print suppression", &still_noisy )) - ) { - gen_suppression(err); - } - if (VG_(clo_gen_suppressions) == 1 && !still_noisy) - VG_(clo_gen_suppressions) = 0; -} /* Shared between VG_(maybe_record_error)() and VG_(unique_error)(), just for pretty printing purposes. */ @@ -498,25 +588,29 @@ void VG_(maybe_record_error) ( ThreadId tid, || n_errs_found >= M_COLLECT_NO_ERRORS_AFTER_FOUND) && !VG_(clo_xml)) { if (!stopping_message) { - VG_UMSG(""); + VG_(umsg)("\n"); if (n_errs_shown >= M_COLLECT_NO_ERRORS_AFTER_SHOWN) { - VG_UMSG( + VG_(umsg)( "More than %d different errors detected. " - "I'm not reporting any more.", + "I'm not reporting any more.\n", M_COLLECT_NO_ERRORS_AFTER_SHOWN ); } else { - VG_UMSG( + VG_(umsg)( "More than %d total errors detected. " - "I'm not reporting any more.", + "I'm not reporting any more.\n", M_COLLECT_NO_ERRORS_AFTER_FOUND ); } - VG_UMSG("Final error counts will be inaccurate. Go fix your program!"); - VG_UMSG("Rerun with --error-limit=no to disable this cutoff. Note"); - VG_UMSG("that errors may occur in your program without prior warning from"); - VG_UMSG("Valgrind, because errors are no longer being displayed."); - VG_UMSG(""); + VG_(umsg)("Final error counts will be inaccurate. " + "Go fix your program!\n"); + VG_(umsg)("Rerun with --error-limit=no to disable " + "this cutoff. Note\n"); + VG_(umsg)("that errors may occur in your program without " + "prior warning from\n"); + VG_(umsg)("Valgrind, because errors are no longer " + "being displayed.\n"); + VG_(umsg)("\n"); stopping_message = True; } return; @@ -529,10 +623,11 @@ void VG_(maybe_record_error) ( ThreadId tid, && !VG_(clo_xml)) { exe_res = Vg_LowRes; if (!slowdown_message) { - VG_UMSG(""); - VG_UMSG("More than %d errors detected. Subsequent errors", - M_COLLECT_ERRORS_SLOWLY_AFTER); - VG_UMSG("will still be recorded, but in less detail than before."); + VG_(umsg)("\n"); + VG_(umsg)("More than %d errors detected. Subsequent errors\n", + M_COLLECT_ERRORS_SLOWLY_AFTER); + VG_(umsg)("will still be recorded, but in less " + "detail than before.\n"); slowdown_message = True; } } @@ -618,12 +713,19 @@ void VG_(maybe_record_error) ( ThreadId tid, errors = p; if (p->supp == NULL) { n_errs_found++; - if (!is_first_shown_context) - VG_UMSG(""); - pp_Error(p); + /* A bit of prettyprinting, to ensure there's a blank line + in between each error. */ + if (!is_first_shown_context) { + if (VG_(clo_xml)) + VG_(printf_xml)("\n"); + else + VG_(umsg)("\n"); + } + /* Actually show the error; more complex than you might think. */ + pp_Error( p, /*allow_db_attach*/True ); + /* update stats */ is_first_shown_context = False; n_errs_shown++; - do_actions_on_error(p, /*allow_db_attach*/True); } else { n_errs_suppressed++; p->supp->count++; @@ -662,12 +764,19 @@ Bool VG_(unique_error) ( ThreadId tid, ErrorKind ekind, Addr a, Char* s, n_errs_found++; if (print_error) { - if (!is_first_shown_context) - VG_UMSG(""); - pp_Error(&err); + /* A bit of prettyprinting, to ensure there's a blank line + in between each error. */ + if (!is_first_shown_context) { + if (VG_(clo_xml)) + VG_(printf_xml)("\n"); + else + VG_(umsg)("\n"); + } + /* Actually show the error; more complex than you might think. */ + pp_Error(&err, allow_db_attach); + /* update stats */ is_first_shown_context = False; n_errs_shown++; - do_actions_on_error(&err, allow_db_attach); } return False; @@ -691,7 +800,7 @@ static Bool show_used_suppressions ( void ) Bool any_supp; if (VG_(clo_xml)) - VG_UMSG(""); + VG_(printf_xml)("\n"); any_supp = False; for (su = suppressions; su != NULL; su = su->next) { @@ -699,19 +808,18 @@ static Bool show_used_suppressions ( void ) continue; any_supp = True; if (VG_(clo_xml)) { - VG_(message_no_f_c)(Vg_DebugMsg, - " \n" - " %d\n" - " %t\n" - " ", - su->count, su->sname); + VG_(printf_xml_no_f_c)( " \n" + " %d\n" + " %t\n" + " \n", + su->count, su->sname ); } else { - VG_DMSG("supp: %6d %s", su->count, su->sname); + VG_(dmsg)("supp: %6d %s\n", su->count, su->sname); } } if (VG_(clo_xml)) - VG_UMSG(""); + VG_(printf_xml)("\n"); return any_supp; } @@ -750,10 +858,10 @@ void VG_(show_all_errors) ( void ) } /* We only get here if not printing XML. */ - VG_UMSG("ERROR SUMMARY: " - "%d errors from %d contexts (suppressed: %d from %d)", - n_errs_found, n_err_contexts, - n_errs_suppressed, n_supp_contexts ); + VG_(umsg)("ERROR SUMMARY: " + "%d errors from %d contexts (suppressed: %d from %d)\n", + n_errs_found, n_err_contexts, + n_errs_suppressed, n_supp_contexts ); if (VG_(clo_verbosity) <= 1) return; @@ -771,10 +879,13 @@ void VG_(show_all_errors) ( void ) } if (p_min == NULL) VG_(tool_panic)("show_all_errors()"); - VG_UMSG(""); - VG_UMSG("%d errors in context %d of %d:", - p_min->count, i+1, n_err_contexts); - pp_Error( p_min ); + VG_(umsg)("\n"); + VG_(umsg)("%d errors in context %d of %d:\n", + p_min->count, i+1, n_err_contexts); + pp_Error( p_min, False/*allow_db_attach*/ ); + + // We're not printing XML -- we'd have exited above if so. + vg_assert(! VG_(clo_xml)); if ((i+1 == VG_(clo_dump_error))) { StackTrace ips = VG_(get_ExeContext_StackTrace)(p_min->where); @@ -788,17 +899,17 @@ void VG_(show_all_errors) ( void ) } if (n_supp_contexts > 0) - VG_UMSG( ""); + VG_(umsg)("\n"); any_supp = show_used_suppressions(); if (n_err_contexts > 0) { if (any_supp) - VG_UMSG(""); - VG_UMSG("IN SUMMARY: " - "%d errors from %d contexts (suppressed: %d from %d)", - n_errs_found, n_err_contexts, n_errs_suppressed, - n_supp_contexts ); - VG_UMSG(""); + VG_(umsg)("\n"); + VG_(umsg)("IN SUMMARY: " + "%d errors from %d contexts (suppressed: %d from %d)\n", + n_errs_found, n_err_contexts, n_errs_suppressed, + n_supp_contexts ); + VG_(umsg)("\n"); } } @@ -807,18 +918,18 @@ void VG_(show_all_errors) ( void ) void VG_(show_error_counts_as_XML) ( void ) { Error* err; - VG_UMSG(""); + VG_(printf_xml)("\n"); for (err = errors; err != NULL; err = err->next) { if (err->supp != NULL) continue; if (err->count <= 0) continue; - VG_UMSG(" "); - VG_UMSG(" %d", err->count); - VG_UMSG(" 0x%x", err->unique); - VG_UMSG(" "); + VG_(printf_xml)(" \n"); + VG_(printf_xml)(" %d\n", err->count); + VG_(printf_xml)(" 0x%x\n", err->unique); + VG_(printf_xml)(" \n"); } - VG_UMSG(""); + VG_(printf_xml)("\n"); } @@ -955,8 +1066,8 @@ static void load_one_suppressions_file ( Char* filename ) // Check it's not a directory. if (VG_(is_dir)( filename )) { if (VG_(clo_xml)) - VG_UMSG("\n"); - VG_UMSG("FATAL: suppressions file \"%s\" is a directory", filename ); + VG_(umsg)("\n"); + VG_(umsg)("FATAL: suppressions file \"%s\" is a directory\n", filename ); VG_(exit)(1); } @@ -964,8 +1075,8 @@ static void load_one_suppressions_file ( Char* filename ) sres = VG_(open)( filename, VKI_O_RDONLY, 0 ); if (sr_isError(sres)) { if (VG_(clo_xml)) - VG_UMSG("\n"); - VG_UMSG("FATAL: can't open suppressions file \"%s\"", filename ); + VG_(umsg)("\n"); + VG_(umsg)("FATAL: can't open suppressions file \"%s\"\n", filename ); VG_(exit)(1); } fd = sr_Res(sres); @@ -1121,13 +1232,13 @@ static void load_one_suppressions_file ( Char* filename ) syntax_error: if (VG_(clo_xml)) - VG_UMSG("\n"); - VG_UMSG("FATAL: in suppressions file \"%s\" near line %d:", + VG_(umsg)("\n"); + VG_(umsg)("FATAL: in suppressions file \"%s\" near line %d:\n", filename, lineno ); - VG_UMSG(" %s", err_str ); + VG_(umsg)(" %s\n", err_str ); VG_(close)(fd); - VG_UMSG("exiting now."); + VG_(umsg)("exiting now.\n"); VG_(exit)(1); # undef BOMB @@ -1141,7 +1252,8 @@ void VG_(load_suppressions) ( void ) suppressions = NULL; for (i = 0; i < VG_(clo_n_suppressions); i++) { if (VG_(clo_verbosity) > 1) { - VG_DMSG("Reading suppressions file: %s", VG_(clo_suppressions)[i] ); + VG_(dmsg)("Reading suppressions file: %s\n", + VG_(clo_suppressions)[i] ); } load_one_suppressions_file( VG_(clo_suppressions)[i] ); } @@ -1299,12 +1411,12 @@ static Supp* is_suppressible_error ( Error* err ) */ void VG_(print_errormgr_stats) ( void ) { - VG_DMSG( - " errormgr: %'lu supplist searches, %'lu comparisons during search", + VG_(dmsg)( + " errormgr: %'lu supplist searches, %'lu comparisons during search\n", em_supplist_searches, em_supplist_cmps ); - VG_DMSG( - " errormgr: %'lu errlist searches, %'lu comparisons during search", + VG_(dmsg)( + " errormgr: %'lu errlist searches, %'lu comparisons during search\n", em_errlist_searches, em_errlist_cmps ); } diff --git a/coregrind/m_execontext.c b/coregrind/m_execontext.c index 645f1c4840..7f00e4bb39 100644 --- a/coregrind/m_execontext.c +++ b/coregrind/m_execontext.c @@ -149,18 +149,18 @@ void VG_(print_ExeContext_stats) ( void ) { init_ExeContext_storage(); VG_(message)(Vg_DebugMsg, - " exectx: %'lu lists, %'llu contexts (avg %'llu per list)", + " exectx: %'lu lists, %'llu contexts (avg %'llu per list)\n", ec_htab_size, ec_totstored, ec_totstored / (ULong)ec_htab_size ); VG_(message)(Vg_DebugMsg, - " exectx: %'llu searches, %'llu full compares (%'llu per 1000)", + " exectx: %'llu searches, %'llu full compares (%'llu per 1000)\n", ec_searchreqs, ec_searchcmps, ec_searchreqs == 0 ? 0ULL : ( (ec_searchcmps * 1000ULL) / ec_searchreqs ) ); VG_(message)(Vg_DebugMsg, - " exectx: %'llu cmp2, %'llu cmp4, %'llu cmpAll", + " exectx: %'llu cmp2, %'llu cmp4, %'llu cmpAll\n", ec_cmp2s, ec_cmp4s, ec_cmpAlls ); } diff --git a/coregrind/m_libcassert.c b/coregrind/m_libcassert.c index 8e3eba2f9f..bfab45c559 100644 --- a/coregrind/m_libcassert.c +++ b/coregrind/m_libcassert.c @@ -146,8 +146,8 @@ static void report_and_quit ( const Char* report, } stacktop = tst->os_state.valgrind_stack_init_SP; - - n_ips = + + n_ips = VG_(get_StackTrace_wrk)( 0/*tid is unknown*/, ips, BACKTRACE_DEPTH, @@ -155,6 +155,7 @@ static void report_and_quit ( const Char* report, NULL/*array to dump FP values in*/, ip, sp, fp, lr, sp, stacktop ); + VG_(clo_xml) = False; VG_(pp_StackTrace) (ips, n_ips); VG_(show_sched_status)(); @@ -200,7 +201,7 @@ void VG_(assert_fail) ( Bool isCore, const Char* expr, const Char* file, } if (VG_(clo_xml)) - VG_UMSG("\n"); + VG_(printf_xml)("\n"); // Treat vg_assert2(0, "foo") specially, as a panicky abort if (VG_STREQ(expr, "0")) { @@ -221,7 +222,7 @@ static void panic ( Char* name, Char* report, Char* str, Addr ip, Addr sp, Addr fp, Addr lr ) { if (VG_(clo_xml)) - VG_UMSG("\n"); + VG_(printf_xml)("\n"); VG_(printf)("\n%s: the 'impossible' happened:\n %s\n", name, str); report_and_quit(report, ip, sp, fp, lr); } @@ -245,18 +246,20 @@ void VG_(tool_panic) ( Char* str ) void VG_(unimplemented) ( Char* msg ) { if (VG_(clo_xml)) - VG_UMSG("\n"); - VG_UMSG(""); - VG_UMSG("Valgrind detected that your program requires"); - VG_UMSG("the following unimplemented functionality:"); - VG_UMSG(" %s", msg); - VG_UMSG("This may be because the functionality is hard to implement,"); - VG_UMSG("or because no reasonable program would behave this way,"); - VG_UMSG("or because nobody has yet needed it. In any case, let us know at"); - VG_UMSG("%s and/or try to work around the problem, if you can.", VG_BUGS_TO); - VG_UMSG(""); - VG_UMSG("Valgrind has to exit now. Sorry. Bye!"); - VG_UMSG(""); + VG_(printf_xml)("\n"); + VG_(umsg)("\n"); + VG_(umsg)("Valgrind detected that your program requires\n"); + VG_(umsg)("the following unimplemented functionality:\n"); + VG_(umsg)(" %s\n", msg); + VG_(umsg)("This may be because the functionality is hard to implement,\n"); + VG_(umsg)("or because no reasonable program would behave this way,\n"); + VG_(umsg)("or because nobody has yet needed it. " + "In any case, let us know at\n"); + VG_(umsg)("%s and/or try to work around the problem, if you can.\n", + VG_BUGS_TO); + VG_(umsg)("\n"); + VG_(umsg)("Valgrind has to exit now. Sorry. Bye!\n"); + VG_(umsg)("\n"); VG_(show_sched_status)(); VG_(exit)(1); } diff --git a/coregrind/m_libcprint.c b/coregrind/m_libcprint.c index 8783f9c2c4..91f07a9804 100644 --- a/coregrind/m_libcprint.c +++ b/coregrind/m_libcprint.c @@ -40,130 +40,158 @@ #include "valgrind.h" // For RUNNING_ON_VALGRIND - /* --------------------------------------------------------------------- Writing to file or a socket ------------------------------------------------------------------ */ -/* Tell the logging mechanism whether we are logging to a file - descriptor or a socket descriptor. */ -Bool VG_(logging_to_socket) = False; - +/* The destination sinks for normal and XML output. These have their + initial values here; they are set to final values by + m_main.main_process_cmd_line_options(). See comment at the top of + that function for the associated logic. */ +OutputSink VG_(log_output_sink) = { 2, False }; /* 2 = stderr */ +OutputSink VG_(xml_output_sink) = { -1, False }; /* disabled */ + /* Do the low-level send of a message to the logging sink. */ -static void send_bytes_to_logging_sink ( Char* msg, Int nbytes ) +static +void send_bytes_to_logging_sink ( OutputSink* sink, Char* msg, Int nbytes ) { - if (!VG_(logging_to_socket)) { - /* VG_(clo_log_fd) could have been set to -1 in the various - sys-wrappers for sys_fork, if --child-silent-after-fork=yes - is in effect. That is a signal that we should not produce - any more output. */ - if (VG_(clo_log_fd) >= 0) - VG_(write)( VG_(clo_log_fd), msg, nbytes ); - } else { - Int rc = VG_(write_socket)( VG_(clo_log_fd), msg, nbytes ); + if (sink->is_socket) { + Int rc = VG_(write_socket)( sink->fd, msg, nbytes ); if (rc == -1) { // For example, the listener process died. Switch back to stderr. - VG_(logging_to_socket) = False; - VG_(clo_log_fd) = 2; - VG_(write)( VG_(clo_log_fd), msg, nbytes ); + sink->is_socket = False; + sink->fd = 2; + VG_(write)( sink->fd, msg, nbytes ); } + } else { + /* sink->fd could have been set to -1 in the various + sys-wrappers for sys_fork, if --child-silent-after-fork=yes + is in effect. That is a signal that we should not produce + any more output. */ + if (sink->fd >= 0) + VG_(write)( sink->fd, msg, nbytes ); } } + /* --------------------------------------------------------------------- printf() and friends ------------------------------------------------------------------ */ +/* --------- printf --------- */ + typedef struct { - HChar buf[128]; - Int n; + HChar buf[512]; + Int buf_used; + OutputSink* sink; } - printf_buf; - -static UInt vprintf_to_buf ( printf_buf *prbuf, - const HChar *format, va_list vargs ); -static UInt printf_to_buf ( printf_buf* prbuf, const HChar *format, ... ); + printf_buf_t; // Adds a single char to the buffer. When the buffer gets sufficiently // full, we write its contents to the logging sink. -static void add_to_myprintf_buf ( HChar c, void *p ) +static void add_to__printf_buf ( HChar c, void *p ) { - printf_buf *myprintf_buf = (printf_buf *)p; + printf_buf_t *b = (printf_buf_t *)p; - if (myprintf_buf->n > sizeof(myprintf_buf->buf) - 2 ) { - send_bytes_to_logging_sink( myprintf_buf->buf, myprintf_buf->n ); - myprintf_buf->n = 0; + if (b->buf_used > sizeof(b->buf) - 2 ) { + send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); + b->buf_used = 0; } - myprintf_buf->buf[myprintf_buf->n++] = c; - myprintf_buf->buf[myprintf_buf->n] = 0; - tl_assert(myprintf_buf->n < sizeof(myprintf_buf->buf)); + b->buf[b->buf_used++] = c; + b->buf[b->buf_used] = 0; + tl_assert(b->buf_used < sizeof(b->buf)); } -UInt VG_(vprintf) ( const HChar *format, va_list vargs ) +static UInt vprintf_to_buf ( printf_buf_t* b, + const HChar *format, va_list vargs ) { UInt ret = 0; - printf_buf myprintf_buf = {"",0}; - - ret = vprintf_to_buf(&myprintf_buf, format, vargs); - // Write out any chars left in the buffer. - if (myprintf_buf.n > 0) { - send_bytes_to_logging_sink( myprintf_buf.buf, myprintf_buf.n ); + if (b->sink->fd >= 0) { + ret = VG_(debugLog_vprintf) + ( add_to__printf_buf, b, format, vargs ); } return ret; } -static UInt vprintf_to_buf ( printf_buf *prbuf, - const HChar *format, va_list vargs ) +static UInt vprintf_WRK ( OutputSink* sink, + const HChar *format, va_list vargs ) { - UInt ret = 0; - - if (VG_(clo_log_fd) >= 0) { - ret = VG_(debugLog_vprintf) - ( add_to_myprintf_buf, prbuf, format, vargs ); + printf_buf_t myprintf_buf + = { "", 0, sink }; + UInt ret + = vprintf_to_buf(&myprintf_buf, format, vargs); + // Write out any chars left in the buffer. + if (myprintf_buf.buf_used > 0) { + send_bytes_to_logging_sink( myprintf_buf.sink, + myprintf_buf.buf, + myprintf_buf.buf_used ); } return ret; } +UInt VG_(vprintf) ( const HChar *format, va_list vargs ) +{ + return vprintf_WRK( &VG_(log_output_sink), format, vargs ); +} + UInt VG_(printf) ( const HChar *format, ... ) { UInt ret; va_list vargs; - va_start(vargs, format); ret = VG_(vprintf)(format, vargs); va_end(vargs); - return ret; } -static UInt printf_to_buf ( printf_buf* prbuf, const HChar *format, ... ) +UInt VG_(vprintf_xml) ( const HChar *format, va_list vargs ) +{ + return vprintf_WRK( &VG_(xml_output_sink), format, vargs ); +} + +UInt VG_(printf_xml) ( const HChar *format, ... ) { UInt ret; va_list vargs; - va_start(vargs, format); - ret = vprintf_to_buf(prbuf, format, vargs); + ret = VG_(vprintf_xml)(format, vargs); va_end(vargs); + return ret; +} +/* An exact clone of VG_(printf_xml), unfortunately. */ +UInt VG_(printf_xml_no_f_c) ( const HChar *format, ... ) +{ + UInt ret; + va_list vargs; + va_start(vargs, format); + ret = VG_(vprintf_xml)(format, vargs); + va_end(vargs); return ret; } -/* A general replacement for sprintf(). */ -static void add_to_vg_sprintf_buf ( HChar c, void *p ) + +/* --------- sprintf --------- */ + +/* If we had an explicit buf structure here, it would contain only one + field, indicating where the next char is to go. So use p directly + for that, rather than having it be a pointer to a structure. */ + +static void add_to__sprintf_buf ( HChar c, void *p ) { - char **vg_sprintf_ptr = p; - *(*vg_sprintf_ptr)++ = c; + HChar** b = p; + *(*b)++ = c; } UInt VG_(vsprintf) ( Char* buf, const HChar *format, va_list vargs ) { Int ret; - Char *vg_sprintf_ptr = buf; + HChar* sprintf_ptr = buf; ret = VG_(debugLog_vprintf) - ( add_to_vg_sprintf_buf, &vg_sprintf_ptr, format, vargs ); - add_to_vg_sprintf_buf('\0', &vg_sprintf_ptr); + ( add_to__sprintf_buf, &sprintf_ptr, format, vargs ); + add_to__sprintf_buf('\0', &sprintf_ptr); vg_assert(VG_(strlen)(buf) == ret); @@ -174,27 +202,26 @@ UInt VG_(sprintf) ( Char* buf, const HChar *format, ... ) { UInt ret; va_list vargs; - va_start(vargs,format); ret = VG_(vsprintf)(buf, format, vargs); va_end(vargs); - return ret; } -/* A replacement for snprintf. */ +/* --------- snprintf --------- */ + typedef struct { HChar* buf; Int buf_size; Int buf_used; } - snprintf_buf; + snprintf_buf_t; -static void add_to_vg_snprintf_buf ( HChar c, void* p ) +static void add_to__snprintf_buf ( HChar c, void* p ) { - snprintf_buf* b = p; + snprintf_buf_t* b = p; if (b->buf_size > 0 && b->buf_used < b->buf_size) { b->buf[b->buf_used++] = c; if (b->buf_used < b->buf_size) @@ -207,13 +234,13 @@ static void add_to_vg_snprintf_buf ( HChar c, void* p ) UInt VG_(vsnprintf) ( Char* buf, Int size, const HChar *format, va_list vargs ) { Int ret; - snprintf_buf b; + snprintf_buf_t b; b.buf = buf; b.buf_size = size < 0 ? 0 : size; b.buf_used = 0; ret = VG_(debugLog_vprintf) - ( add_to_vg_snprintf_buf, &b, format, vargs ); + ( add_to__snprintf_buf, &b, format, vargs ); return b.buf_used; } @@ -222,15 +249,24 @@ UInt VG_(snprintf) ( Char* buf, Int size, const HChar *format, ... ) { UInt ret; va_list vargs; - va_start(vargs,format); ret = VG_(vsnprintf)(buf, size, format, vargs); va_end(vargs); - return ret; } +/* --------- vcbprintf --------- */ + +void VG_(vcbprintf)( void(*char_sink)(HChar, void* opaque), + void* opaque, + const HChar* format, va_list vargs ) +{ + (void) VG_(debugLog_vprintf) + ( char_sink, opaque, format, vargs ); +} + + /* --------------------------------------------------------------------- percentify() ------------------------------------------------------------------ */ @@ -321,48 +357,137 @@ void VG_(elapsed_wallclock_time) ( /*OUT*/HChar* buf ) message() ------------------------------------------------------------------ */ -UInt VG_(vmessage) ( VgMsgKind kind, const HChar* format, va_list vargs ) +/* A buffer for accumulating VG_(message) style output. This is + pretty much the same as VG_(printf)'s scheme, with two differences: + + * The message buffer persists between calls, so that multiple + calls to VG_(message) can build up output. + + * Whenever the first character on a line is emitted, the + ==PID== style preamble is stuffed in before it. +*/ +typedef + struct { + HChar buf[512+128]; + Int buf_used; + Bool atLeft; /* notionally, is the next char position at the + leftmost column? */ + /* Current message kind - changes from call to call */ + VgMsgKind kind; + /* PID; acquired just once and stays constant */ + Int my_pid; + /* destination */ + OutputSink* sink; + } + vmessage_buf_t; + +static vmessage_buf_t vmessage_buf + = { "", 0, True, Vg_UserMsg, -1, &VG_(log_output_sink) }; + + +// Adds a single char to the buffer. We aim to have at least 128 +// bytes free in the buffer, so that it's always possible to emit +// the preamble into the buffer if c happens to be the character +// following a \n. When the buffer gets too full, we write its +// contents to the logging sink. +static void add_to__vmessage_buf ( HChar c, void *p ) { - UInt count = 0; - Char c; - Int i, depth; - printf_buf myprintf_buf = {"",0}; - - switch (kind) { - case Vg_UserMsg: c = '='; break; - case Vg_DebugMsg: c = '-'; break; - case Vg_DebugExtraMsg: c = '+'; break; - case Vg_ClientMsg: c = '*'; break; - default: c = '?'; break; - } + HChar tmp[64]; + vmessage_buf_t* b = (vmessage_buf_t*)p; + + vg_assert(b->buf_used >= 0 && b->buf_used < sizeof(b->buf)-128); + + if (UNLIKELY(b->atLeft)) { + // insert preamble + HChar ch; + Int i, depth; + + switch (b->kind) { + case Vg_UserMsg: ch = '='; break; + case Vg_DebugMsg: ch = '-'; break; + case Vg_DebugExtraMsg: ch = '+'; break; + case Vg_ClientMsg: ch = '*'; break; + default: ch = '?'; break; + } + + // Print one '>' in front of the messages for each level of + // self-hosting being performed. + depth = RUNNING_ON_VALGRIND; + if (depth > 10) + depth = 10; // ?!?! + for (i = 0; i < depth; i++) { + b->buf[b->buf_used++] = '>'; + } + + b->buf[b->buf_used++] = ch; + b->buf[b->buf_used++] = ch; + + if (VG_(clo_time_stamp)) { + VG_(memset)(tmp, 0, sizeof(tmp)); + VG_(elapsed_wallclock_time)(tmp); + tmp[sizeof(tmp)-1] = 0; + for (i = 0; tmp[i]; i++) + b->buf[b->buf_used++] = tmp[i]; + } + + VG_(sprintf)(tmp, "%d", b->my_pid); + tmp[sizeof(tmp)-1] = 0; + for (i = 0; tmp[i]; i++) + b->buf[b->buf_used++] = tmp[i]; - // Print one '>' in front of the messages for each level of self-hosting - // being performed. - depth = RUNNING_ON_VALGRIND; - for (i = 0; i < depth; i++) { - count += printf_to_buf (&myprintf_buf, ">"); + b->buf[b->buf_used++] = ch; + b->buf[b->buf_used++] = ch; + b->buf[b->buf_used++] = ' '; + + /* We can't possibly have stuffed 96 chars in merely as a result + of making the preamble (can we?) */ + vg_assert(b->buf_used < sizeof(b->buf)-32); } + + b->buf[b->buf_used++] = c; + b->buf[b->buf_used] = 0; - if (!VG_(clo_xml)) - count += printf_to_buf (&myprintf_buf, "%c%c", c,c); + if (b->buf_used >= sizeof(b->buf) - 128) { + send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); + b->buf_used = 0; + } + + b->atLeft = c == '\n'; +} + + +UInt VG_(vmessage) ( VgMsgKind kind, const HChar* format, va_list vargs ) +{ + UInt ret; + + /* Note (carefully) that the buf persists from call to call, unlike + with the other printf variants in earlier parts of this file. */ + vmessage_buf_t* b = &vmessage_buf; /* shorthand for convenience */ - if (VG_(clo_time_stamp)) { - HChar buf[50]; - VG_(elapsed_wallclock_time)(buf); - count += printf_to_buf(&myprintf_buf, "%s ", buf); + /* We have to set this each call, so that the correct flavour + of preamble is emitted at each \n. */ + b->kind = kind; + + /* Cache the results of getpid just once, so we don't have to call + getpid once for each line of text output. */ + if (UNLIKELY(b->my_pid == -1)) { + b->my_pid = VG_(getpid)(); + vg_assert(b->my_pid >= 0); } - if (!VG_(clo_xml)) - count += printf_to_buf (&myprintf_buf, "%d%c%c ", VG_(getpid)(), c,c); + ret = VG_(debugLog_vprintf) ( add_to__vmessage_buf, + b, format, vargs ); - count += vprintf_to_buf (&myprintf_buf, format, vargs); - count += printf_to_buf (&myprintf_buf, "\n"); + /* If the message finished exactly with a \n, then flush it at this + point. If not, assume more bits of the same line will turn up + in later messages, so don't bother to flush it right now. */ - if (myprintf_buf.n > 0) { - send_bytes_to_logging_sink( myprintf_buf.buf, myprintf_buf.n ); + if (b->atLeft && b->buf_used > 0) { + send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); + b->buf_used = 0; } - return count; + return ret; } /* Send a simple single-part XML message. */ @@ -387,6 +512,47 @@ UInt VG_(message) ( VgMsgKind kind, const HChar* format, ... ) return count; } +/* VG_(message) variants with hardwired first argument. */ +UInt VG_(umsg) ( const HChar* format, ... ) +{ + UInt count; + va_list vargs; + va_start(vargs,format); + count = VG_(vmessage) ( Vg_UserMsg, format, vargs ); + va_end(vargs); + return count; +} + +UInt VG_(dmsg) ( const HChar* format, ... ) +{ + UInt count; + va_list vargs; + va_start(vargs,format); + count = VG_(vmessage) ( Vg_DebugMsg, format, vargs ); + va_end(vargs); + return count; +} + +UInt VG_(emsg) ( const HChar* format, ... ) +{ + UInt count; + va_list vargs; + va_start(vargs,format); + count = VG_(vmessage) ( Vg_DebugExtraMsg, format, vargs ); + va_end(vargs); + return count; +} + +/* Flush any output that has accumulated in vmessage_buf as a + result of previous calls to VG_(message) et al. */ +void VG_(message_flush) ( void ) +{ + vmessage_buf_t* b = &vmessage_buf; + send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); + b->buf_used = 0; +} + + /*--------------------------------------------------------------------*/ /*--- end ---*/ /*--------------------------------------------------------------------*/ diff --git a/coregrind/m_libcproc.c b/coregrind/m_libcproc.c index 1c02ba4ef1..46bdfe630d 100644 --- a/coregrind/m_libcproc.c +++ b/coregrind/m_libcproc.c @@ -435,7 +435,8 @@ Int VG_(gettid)(void) res = VG_(mk_SysRes_Success)( VG_(strtoll10)(pid, &s) ); if (*s != '\0') { VG_(message)(Vg_DebugMsg, - "Warning: invalid file name linked to by /proc/self: %s", pid); + "Warning: invalid file name linked to by /proc/self: %s\n", + pid); } } } diff --git a/coregrind/m_main.c b/coregrind/m_main.c index f41f201830..2ba71a89f2 100644 --- a/coregrind/m_main.c +++ b/coregrind/m_main.c @@ -87,13 +87,13 @@ static void print_all_stats ( void ) // Memory stats if (VG_(clo_verbosity) > 2) { - VG_(message)(Vg_DebugMsg, ""); + VG_(message)(Vg_DebugMsg, "\n"); VG_(message)(Vg_DebugMsg, - "------ Valgrind's internal memory use stats follow ------" ); + "------ Valgrind's internal memory use stats follow ------\n" ); VG_(sanity_check_malloc_all)(); - VG_(message)(Vg_DebugMsg, "------" ); + VG_(message)(Vg_DebugMsg, "------\n" ); VG_(print_all_arena_stats)(); - VG_(message)(Vg_DebugMsg, ""); + VG_(message)(Vg_DebugMsg, "\n"); } } @@ -140,8 +140,11 @@ static void usage_NORETURN ( Bool debug_help ) " tools that make use of it (Memcheck, Helgrind)\n" "\n" " user options for Valgrind tools that report errors:\n" -" --xml=yes all output is in XML (some tools only)\n" -" --xml-user-comment=STR copy STR verbatim to XML output\n" +" --xml=yes emit error output in XML (some tools only)\n" +" --xml-fd= XML output to file descriptor\n" +" --xml-file= XML output to \n" +" --xml-socket=ipaddr:port XML output to socket ipaddr:port\n" +" --xml-user-comment=STR copy STR verbatim into XML output\n" " --demangle=no|yes automatically demangle C++ names? [yes]\n" " --num-callers= show callers in stack traces [12]\n" " --error-limit=no|yes stop showing new errors if too many? [yes]\n" @@ -217,8 +220,8 @@ static void usage_NORETURN ( Bool debug_help ) Char* gdb_path = GDB_PATH; // Ensure the message goes to stdout - VG_(clo_log_fd) = 1; - vg_assert( !VG_(logging_to_socket) ); + VG_(log_output_sink).fd = 1; + VG_(log_output_sink).is_socket = False; /* 'usage1' expects one char* argument */ VG_(printf)(usage1, gdb_path); @@ -276,7 +279,8 @@ static void early_process_cmd_line_options ( /*OUT*/Int* need_help, vg_assert(str); // Nb: the version string goes to stdout. - if VG_XACT_CLO(str, "--version", VG_(clo_log_fd), 1) { + if VG_XACT_CLO(str, "--version", VG_(log_output_sink).fd, 1) { + VG_(log_output_sink).is_socket = False; VG_(printf)("valgrind-" VERSION "\n"); VG_(exit)(0); } @@ -298,26 +302,59 @@ static void early_process_cmd_line_options ( /*OUT*/Int* need_help, } /* The main processing for command line options. See comments above - on early_process_cmd_line_options. + on early_process_cmd_line_options. + + Comments on how the logging options are handled: + + User can specify: + --log-fd= for a fd to write to (default setting, fd = 2) + --log-file= for a file name to write to + --log-socket= for a socket to write to + + As a result of examining these and doing relevant socket/file + opening, a final fd is established. This is stored in + VG_(log_output_sink) in m_libcprint. Also, if --log-file=STR was + specified, then STR, after expansion of %p and %q templates within + it, is stored in VG_(clo_log_fname_expanded), in m_options, just in + case anybody wants to know what it is. + + When printing, VG_(log_output_sink) is consulted to find the + fd to send output to. + + Exactly analogous actions are undertaken for the XML output + channel, with the one difference that the default fd is -1, meaning + the channel is disabled by default. */ -static Bool main_process_cmd_line_options( const HChar* toolname ) +static +void main_process_cmd_line_options ( /*OUT*/Bool* logging_to_fd, + /*OUT*/Char** xml_fname_unexpanded, + const HChar* toolname ) { // VG_(clo_log_fd) is used by all the messaging. It starts as 2 (stderr) // and we cannot change it until we know what we are changing it to is // ok. So we have tmp_log_fd to hold the tmp fd prior to that point. SysRes sres; - Int i, tmp_log_fd; + Int i, tmp_log_fd, tmp_xml_fd; Int toolname_len = VG_(strlen)(toolname); Char* tmp_str; // Used in a couple of places. enum { VgLogTo_Fd, VgLogTo_File, VgLogTo_Socket - } log_to = VgLogTo_Fd; // Where is logging output to be sent? + } log_to = VgLogTo_Fd, // Where is logging output to be sent? + xml_to = VgLogTo_Fd; // Where is XML output to be sent? - /* log to stderr by default, but usage message goes to stdout */ - tmp_log_fd = 2; + /* Temporarily holds the string STR specified with + --{log,xml}-{name,socket}=STR. 'fs' stands for + file-or-socket. */ + Char* log_fsname_unexpanded = NULL; + Char* xml_fsname_unexpanded = NULL; + /* Log to stderr by default, but usage message goes to stdout. XML + output is initially disabled. */ + tmp_log_fd = 2; + tmp_xml_fd = -1; + /* Check for sane path in ./configure --prefix=... */ if (VG_LIBDIR[0] != '/') VG_(err_config_error)("Please use absolute paths in " @@ -325,6 +362,8 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) vg_assert( VG_(args_for_valgrind) ); + /* BEGIN command-line processing loop */ + for (i = 0; i < VG_(sizeXA)( VG_(args_for_valgrind) ); i++) { HChar* arg = * (HChar**) VG_(indexXA)( VG_(args_for_valgrind), i ); @@ -454,25 +493,35 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) else if VG_INT_CLO(arg, "--log-fd", tmp_log_fd) { log_to = VgLogTo_Fd; - VG_(clo_log_name) = NULL; + log_fsname_unexpanded = NULL; + } + else if VG_INT_CLO(arg, "--xml-fd", tmp_xml_fd) { + xml_to = VgLogTo_Fd; + xml_fsname_unexpanded = NULL; } - else if VG_STR_CLO(arg, "--log-file", VG_(clo_log_name)) { + else if VG_STR_CLO(arg, "--log-file", log_fsname_unexpanded) { log_to = VgLogTo_File; } - - else if VG_STR_CLO(arg, "--log-socket", VG_(clo_log_name)) { + else if VG_STR_CLO(arg, "--xml-file", xml_fsname_unexpanded) { + xml_to = VgLogTo_File; + } + + else if VG_STR_CLO(arg, "--log-socket", log_fsname_unexpanded) { log_to = VgLogTo_Socket; } + else if VG_STR_CLO(arg, "--xml-socket", xml_fsname_unexpanded) { + xml_to = VgLogTo_Socket; + } else if VG_STR_CLO(arg, "--xml-user-comment", VG_(clo_xml_user_comment)) {} else if VG_STR_CLO(arg, "--suppressions", tmp_str) { if (VG_(clo_n_suppressions) >= VG_CLO_MAX_SFILES) { - VG_(message)(Vg_UserMsg, "Too many suppression files specified."); + VG_(message)(Vg_UserMsg, "Too many suppression files specified.\n"); VG_(message)(Vg_UserMsg, - "Increase VG_CLO_MAX_SFILES and recompile."); + "Increase VG_CLO_MAX_SFILES and recompile.\n"); VG_(err_bad_option)(arg); } VG_(clo_suppressions)[VG_(clo_n_suppressions)] = tmp_str; @@ -485,7 +534,7 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) if (8 != VG_(strlen)(tmp_str)) { VG_(message)(Vg_UserMsg, - "--trace-flags argument must have 8 digits"); + "--trace-flags argument must have 8 digits\n"); VG_(err_bad_option)(arg); } for (j = 0; j < 8; j++) { @@ -493,7 +542,7 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) else if ('1' == tmp_str[j]) VG_(clo_trace_flags) |= (1 << (7-j)); else { VG_(message)(Vg_UserMsg, "--trace-flags argument can only " - "contain 0s and 1s"); + "contain 0s and 1s\n"); VG_(err_bad_option)(arg); } } @@ -505,7 +554,7 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) if (8 != VG_(strlen)(tmp_str)) { VG_(message)(Vg_UserMsg, - "--profile-flags argument must have 8 digits"); + "--profile-flags argument must have 8 digits\n"); VG_(err_bad_option)(arg); } for (j = 0; j < 8; j++) { @@ -513,7 +562,7 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) else if ('1' == tmp_str[j]) VG_(clo_profile_flags) |= (1 << (7-j)); else { VG_(message)(Vg_UserMsg, "--profile-flags argument can only " - "contain 0s and 1s"); + "contain 0s and 1s\n"); VG_(err_bad_option)(arg); } } @@ -534,6 +583,8 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) } } + /* END command-line processing loop */ + /* Make VEX control parameters sane */ if (VG_(clo_vex_control).guest_chase_thresh @@ -552,34 +603,72 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) if (VG_(clo_gen_suppressions) > 0 && !VG_(needs).core_errors && !VG_(needs).tool_errors) { VG_(message)(Vg_UserMsg, - "Can't use --gen-suppressions= with this tool,"); + "Can't use --gen-suppressions= with this tool,\n"); VG_(message)(Vg_UserMsg, - "as it doesn't generate errors."); + "as it doesn't generate errors.\n"); VG_(err_bad_option)("--gen-suppressions="); } + /* If XML output is requested, check that the tool actually + supports it. */ + if (VG_(clo_xml) && !VG_(needs).xml_output) { + VG_(clo_xml) = False; + VG_(message)(Vg_UserMsg, + "%s does not support XML output.\n", VG_(details).name); + VG_(err_bad_option)("--xml=yes"); + /*NOTREACHED*/ + } + + vg_assert( VG_(clo_gen_suppressions) >= 0 ); + vg_assert( VG_(clo_gen_suppressions) <= 2 ); + /* If we've been asked to emit XML, mash around various other options so as to constrain the output somewhat, and to remove - any need for user input during the run. */ + any need for user input during the run. + */ if (VG_(clo_xml)) { - /* Disable suppression generation (requires user input) */ - VG_(clo_gen_suppressions) = 0; - /* Disable attaching to GDB (requires user input) */ - VG_(clo_db_attach) = False; - /* Set a known verbosity level */ - VG_(clo_verbosity) = 1; + + /* We can't allow --gen-suppressions=yes, since that requires us + to print the error and then ask the user if she wants a + suppression for it, but in XML mode we won't print it until + we know whether we also need to print a suppression. Hence a + circular dependency. So disallow this. + (--gen-suppressions=all is still OK since we don't need any + user interaction in this case.) */ + if (VG_(clo_gen_suppressions) == 1) { + VG_(umsg)( + "When --xml=yes is specified, only --gen-suppressions=no\n" + "or --gen-suppressions=all are allowed, but not " + "--gen-suppressions=yes.\n"); + /* FIXME: this is really a misuse of VG_(err_bad_option). */ + VG_(err_bad_option)( + "--xml=yes together with --gen-suppressions=yes"); + } + + /* We can't allow DB attaching (or we maybe could, but results + could be chaotic ..) since it requires user input. Hence + disallow. */ + if (VG_(clo_db_attach)) { + VG_(umsg)("--db-attach=yes is not allowed in XML mode,\n" + "as it would require user input.\n"); + /* FIXME: this is really a misuse of VG_(err_bad_option). */ + VG_(err_bad_option)( + "--xml=yes together with --db-attach=yes"); + } + + /* Disallow dump_error in XML mode; sounds like a recipe for + chaos. No big deal; dump_error is a flag for debugging V + itself. */ + if (VG_(clo_dump_error) > 0) { + /* FIXME: this is really a misuse of VG_(err_bad_option). */ + VG_(err_bad_option)( + "--xml=yes together with --dump-error="); + } + /* Disable error limits (this might be a bad idea!) */ VG_(clo_error_limit) = False; /* Disable emulation warnings */ - VG_(clo_show_emwarns) = False; - /* Disable waiting for GDB to debug Valgrind */ - VG_(clo_wait_for_gdb) = False; - /* No file-descriptor leak checking yet */ - VG_(clo_track_fds) = False; - /* Disable timestamped output */ - VG_(clo_time_stamp) = False; - /* Disable heap profiling, since that prints lots of stuff. */ - VG_(clo_profile_heap) = False; + /* Also, we want to set options for the leak checker, but that will have to be done in Memcheck's flag-handling code, not here. */ @@ -592,116 +681,233 @@ static Bool main_process_cmd_line_options( const HChar* toolname ) the terminal any problems to do with processing command line opts.) - So set up logging now. After this is done, VG_(clo_log_fd) - should be connected to whatever sink has been selected, and we - indiscriminately chuck stuff into it without worrying what the - nature of it is. Oh the wonder of Unix streams. */ + So set up logging now. After this is done, VG_(log_output_sink) + and (if relevant) VG_(xml_output_sink) should be connected to + whatever sink has been selected, and we indiscriminately chuck + stuff into it without worrying what the nature of it is. Oh the + wonder of Unix streams. */ - vg_assert(VG_(clo_log_fd) == 2 /* stderr */); - vg_assert(VG_(logging_to_socket) == False); + vg_assert(VG_(log_output_sink).fd == 2 /* stderr */); + vg_assert(VG_(log_output_sink).is_socket == False); + vg_assert(VG_(clo_log_fname_expanded) == NULL); + + vg_assert(VG_(xml_output_sink).fd == -1 /* disabled */); + vg_assert(VG_(xml_output_sink).is_socket == False); + vg_assert(VG_(clo_xml_fname_expanded) == NULL); + + /* --- set up the normal text output channel --- */ switch (log_to) { case VgLogTo_Fd: - vg_assert(VG_(clo_log_name) == NULL); + vg_assert(log_fsname_unexpanded == NULL); break; case VgLogTo_File: { Char* logfilename; - vg_assert(VG_(clo_log_name) != NULL); - vg_assert(VG_(strlen)(VG_(clo_log_name)) <= 900); /* paranoia */ + vg_assert(log_fsname_unexpanded != NULL); + vg_assert(VG_(strlen)(log_fsname_unexpanded) <= 900); /* paranoia */ // Nb: we overwrite an existing file of this name without asking // any questions. - logfilename = VG_(expand_file_name)("--log-file", VG_(clo_log_name)); + logfilename = VG_(expand_file_name)("--log-file", + log_fsname_unexpanded); sres = VG_(open)(logfilename, VKI_O_CREAT|VKI_O_WRONLY|VKI_O_TRUNC, VKI_S_IRUSR|VKI_S_IWUSR); if (!sr_isError(sres)) { tmp_log_fd = sr_Res(sres); + VG_(clo_log_fname_expanded) = logfilename; } else { VG_(message)(Vg_UserMsg, - "Can't create log file '%s' (%s); giving up!", + "Can't create log file '%s' (%s); giving up!\n", logfilename, VG_(strerror)(sr_Err(sres))); VG_(err_bad_option)( "--log-file= (didn't work out for some reason.)"); /*NOTREACHED*/ } - break; /* switch (VG_(clo_log_to)) */ + break; } case VgLogTo_Socket: { - vg_assert(VG_(clo_log_name) != NULL); - vg_assert(VG_(strlen)(VG_(clo_log_name)) <= 900); /* paranoia */ - tmp_log_fd = VG_(connect_via_socket)( VG_(clo_log_name) ); + vg_assert(log_fsname_unexpanded != NULL); + vg_assert(VG_(strlen)(log_fsname_unexpanded) <= 900); /* paranoia */ + tmp_log_fd = VG_(connect_via_socket)( log_fsname_unexpanded ); if (tmp_log_fd == -1) { VG_(message)(Vg_UserMsg, - "Invalid --log-socket=ipaddr or --log-socket=ipaddr:port spec"); + "Invalid --log-socket=ipaddr or " + "--log-socket=ipaddr:port spec\n"); VG_(message)(Vg_UserMsg, - "of '%s'; giving up!", VG_(clo_log_name) ); + "of '%s'; giving up!\n", log_fsname_unexpanded ); VG_(err_bad_option)( "--log-socket="); /*NOTREACHED*/ } if (tmp_log_fd == -2) { VG_(message)(Vg_UserMsg, - "valgrind: failed to connect to logging server '%s'.", - VG_(clo_log_name) ); + "valgrind: failed to connect to logging server '%s'.\n", + log_fsname_unexpanded ); VG_(message)(Vg_UserMsg, - "Log messages will sent to stderr instead." ); + "Log messages will sent to stderr instead.\n" ); VG_(message)(Vg_UserMsg, - "" ); + "\n" ); /* We don't change anything here. */ - vg_assert(VG_(clo_log_fd) == 2); + vg_assert(VG_(log_output_sink).fd == 2); tmp_log_fd = 2; } else { vg_assert(tmp_log_fd > 0); - VG_(logging_to_socket) = True; + VG_(log_output_sink).is_socket = True; } break; } } + /* --- set up the XML output channel --- */ - /* Check that the requested tool actually supports XML output. */ - if (VG_(clo_xml) && !VG_(needs).xml_output) { - VG_(clo_xml) = False; - VG_(message)(Vg_UserMsg, - "%s does not support XML output.", VG_(details).name); - VG_(err_bad_option)("--xml=yes"); - /*NOTREACHED*/ + switch (xml_to) { + + case VgLogTo_Fd: + vg_assert(xml_fsname_unexpanded == NULL); + break; + + case VgLogTo_File: { + Char* xmlfilename; + + vg_assert(xml_fsname_unexpanded != NULL); + vg_assert(VG_(strlen)(xml_fsname_unexpanded) <= 900); /* paranoia */ + + // Nb: we overwrite an existing file of this name without asking + // any questions. + xmlfilename = VG_(expand_file_name)("--xml-file", + xml_fsname_unexpanded); + sres = VG_(open)(xmlfilename, + VKI_O_CREAT|VKI_O_WRONLY|VKI_O_TRUNC, + VKI_S_IRUSR|VKI_S_IWUSR); + if (!sr_isError(sres)) { + tmp_xml_fd = sr_Res(sres); + VG_(clo_xml_fname_expanded) = xmlfilename; + /* strdup here is probably paranoid overkill, but ... */ + *xml_fname_unexpanded = VG_(strdup)( "main.mpclo.2", + xml_fsname_unexpanded ); + } else { + VG_(message)(Vg_UserMsg, + "Can't create XML file '%s' (%s); giving up!\n", + xmlfilename, VG_(strerror)(sr_Err(sres))); + VG_(err_bad_option)( + "--xml-file= (didn't work out for some reason.)"); + /*NOTREACHED*/ + } + break; + } + + case VgLogTo_Socket: { + vg_assert(xml_fsname_unexpanded != NULL); + vg_assert(VG_(strlen)(xml_fsname_unexpanded) <= 900); /* paranoia */ + tmp_xml_fd = VG_(connect_via_socket)( xml_fsname_unexpanded ); + if (tmp_xml_fd == -1) { + VG_(message)(Vg_UserMsg, + "Invalid --xml-socket=ipaddr or " + "--xml-socket=ipaddr:port spec\n"); + VG_(message)(Vg_UserMsg, + "of '%s'; giving up!\n", xml_fsname_unexpanded ); + VG_(err_bad_option)( + "--xml-socket="); + /*NOTREACHED*/ + } + if (tmp_xml_fd == -2) { + VG_(message)(Vg_UserMsg, + "valgrind: failed to connect to XML logging server '%s'.\n", + xml_fsname_unexpanded ); + VG_(message)(Vg_UserMsg, + "XML output will sent to stderr instead.\n" ); + VG_(message)(Vg_UserMsg, + "\n" ); + /* We don't change anything here. */ + vg_assert(VG_(xml_output_sink).fd == 2); + tmp_xml_fd = 2; + } else { + vg_assert(tmp_xml_fd > 0); + VG_(xml_output_sink).is_socket = True; + } + break; + } } + /* If we've got this far, and XML mode was requested, but no XML + output channel appears to have been specified, just stop. We + could continue, and XML output will simply vanish into nowhere, + but that is likely to confuse the hell out of users, which is + distinctly Ungood. */ + if (VG_(clo_xml) && tmp_xml_fd == -1) { + VG_(umsg)( + "--xml=yes has been specified, but there is no XML output\n" + "destination. You must specify an XML output destination\n" + "using --xml-fd=, --xml-file= or --xml=socket=.\n" ); + /* FIXME: this is really a misuse of VG_(err_bad_option). */ + VG_(err_bad_option)( + "--xml=yes, but no XML destination specified"); + } + + // Finalise the output fds: the log fd .. + if (tmp_log_fd >= 0) { - // Move log_fd into the safe range, so it doesn't conflict with any app fds. + // Move log_fd into the safe range, so it doesn't conflict with + // any app fds. tmp_log_fd = VG_(fcntl)(tmp_log_fd, VKI_F_DUPFD, VG_(fd_hard_limit)); if (tmp_log_fd < 0) { - VG_(message)(Vg_UserMsg, "valgrind: failed to move logfile fd into safe range, using stderr"); - VG_(clo_log_fd) = 2; // stderr + VG_(message)(Vg_UserMsg, "valgrind: failed to move logfile fd " + "into safe range, using stderr\n"); + VG_(log_output_sink).fd = 2; // stderr + VG_(log_output_sink).is_socket = False; } else { - VG_(clo_log_fd) = tmp_log_fd; - VG_(fcntl)(VG_(clo_log_fd), VKI_F_SETFD, VKI_FD_CLOEXEC); + VG_(log_output_sink).fd = tmp_log_fd; + VG_(fcntl)(VG_(log_output_sink).fd, VKI_F_SETFD, VKI_FD_CLOEXEC); } } else { // If they said --log-fd=-1, don't print anything. Plausible for use in // regression testing suites that use client requests to count errors. - VG_(clo_log_fd) = tmp_log_fd; + VG_(log_output_sink).fd = -1; + VG_(log_output_sink).is_socket = False; + } + + // Finalise the output fds: and the XML fd .. + + if (tmp_xml_fd >= 0) { + // Move xml_fd into the safe range, so it doesn't conflict with + // any app fds. + tmp_xml_fd = VG_(fcntl)(tmp_xml_fd, VKI_F_DUPFD, VG_(fd_hard_limit)); + if (tmp_xml_fd < 0) { + VG_(message)(Vg_UserMsg, "valgrind: failed to move XML file fd " + "into safe range, using stderr\n"); + VG_(xml_output_sink).fd = 2; // stderr + VG_(xml_output_sink).is_socket = False; + } else { + VG_(xml_output_sink).fd = tmp_xml_fd; + VG_(fcntl)(VG_(xml_output_sink).fd, VKI_F_SETFD, VKI_FD_CLOEXEC); + } + } else { + // If they said --xml-fd=-1, don't print anything. Plausible for use in + // regression testing suites that use client requests to count errors. + VG_(xml_output_sink).fd = -1; + VG_(xml_output_sink).is_socket = False; } + // Suppressions related stuff + if (VG_(clo_n_suppressions) < VG_CLO_MAX_SFILES-1 && (VG_(needs).core_errors || VG_(needs).tool_errors)) { /* If we haven't reached the max number of suppressions, load the default one. */ static const Char default_supp[] = "default.supp"; Int len = VG_(strlen)(VG_(libdir)) + 1 + sizeof(default_supp); - Char *buf = VG_(arena_malloc)(VG_AR_CORE, "main.mpclo.2", len); + Char *buf = VG_(arena_malloc)(VG_AR_CORE, "main.mpclo.3", len); VG_(sprintf)(buf, "%s/%s", VG_(libdir), default_supp); VG_(clo_suppressions)[VG_(clo_n_suppressions)] = buf; VG_(clo_n_suppressions)++; } - return (log_to == VgLogTo_Fd); + *logging_to_fd = log_to == VgLogTo_Fd || log_to == VgLogTo_Socket; } // Write the name and value of log file qualifiers to the xml file. @@ -732,9 +938,9 @@ static void print_file_vars(Char* format) i++; } - VG_(message_no_f_c)(Vg_UserMsg, + VG_(message_no_f_c)(Vg_UserMsg, " %t " - "%t ", + "%t \n", qualname,qual); format[i] = '}'; i++; @@ -755,146 +961,154 @@ static void print_file_vars(Char* format) If logging to file or a socket, write details of parent PID and command line args, to help people trying to interpret the results of a run which encompasses multiple processes. */ -static void print_preamble(Bool logging_to_fd, const char* toolname) +static void print_preamble ( Bool logging_to_fd, + Char* xml_fname_unexpanded, + const HChar* toolname ) { + Int i; HChar* xpre = VG_(clo_xml) ? " " : ""; HChar* xpost = VG_(clo_xml) ? "" : ""; - Int i; + UInt (*umsg_or_xml)( const HChar*, ... ) + = VG_(clo_xml) ? VG_(printf_xml) : VG_(umsg); vg_assert( VG_(args_for_client) ); vg_assert( VG_(args_for_valgrind) ); vg_assert( toolname ); if (VG_(clo_xml)) { - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "3"); - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml)("\n"); + VG_(printf_xml)("\n"); + VG_(printf_xml)("\n"); + VG_(printf_xml)("\n"); + VG_(printf_xml)("4\n"); + VG_(printf_xml)("%s\n", toolname); + VG_(printf_xml)("\n"); } - if (VG_(clo_verbosity > 0)) { + if (VG_(clo_xml) || VG_(clo_verbosity > 0)) { if (VG_(clo_xml)) - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml)("\n"); /* Tool details */ - VG_(message)(Vg_UserMsg, "%s%s%s%s, %s.%s", + umsg_or_xml( "%s%s%s%s, %s.%s\n", xpre, VG_(details).name, NULL == VG_(details).version ? "" : "-", NULL == VG_(details).version ? (Char*)"" : VG_(details).version, VG_(details).description, - xpost); + xpost ); if (VG_(strlen)(toolname) >= 4 && VG_STREQN(4, toolname, "exp-")) { - VG_UMSG( - "%sNOTE: This is an Experimental-Class Valgrind Tool.%s", + umsg_or_xml( + "%sNOTE: This is an Experimental-Class Valgrind Tool.%s\n", xpre, xpost ); } - VG_(message)(Vg_UserMsg, "%s%s%s", + umsg_or_xml("%s%s%s\n", xpre, VG_(details).copyright_author, xpost); /* Core details */ - VG_(message)(Vg_UserMsg, - "%sBuilt with Valgrind and LibVEX; rerun with -h for copyright info%s", - xpre, xpost ); + umsg_or_xml( + "%sBuilt with Valgrind and LibVEX; rerun with -h for copyright info%s\n", + xpre, xpost + ); if (VG_(clo_xml)) - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml)("\n"); } if (!VG_(clo_xml) && VG_(clo_verbosity) > 0 && !logging_to_fd) { - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, - "My PID = %d, parent PID = %d. Prog and args are:", - VG_(getpid)(), VG_(getppid)() ); + VG_(umsg)("\n"); + VG_(umsg)("My PID = %d, parent PID = %d. Prog and args are:\n", + VG_(getpid)(), VG_(getppid)() ); if (VG_(args_the_exename)) - VG_(message)(Vg_UserMsg, " %s", VG_(args_the_exename)); + VG_(umsg)(" %s\n", VG_(args_the_exename)); for (i = 0; i < VG_(sizeXA)( VG_(args_for_client) ); i++) - VG_(message)(Vg_UserMsg, - " %s", - * (HChar**) VG_(indexXA)( VG_(args_for_client), i )); + VG_(umsg)(" %s\n", + * (HChar**) VG_(indexXA)( VG_(args_for_client), i )); } else if (VG_(clo_xml)) { - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "%d", VG_(getpid)()); - VG_(message)(Vg_UserMsg, "%d", VG_(getppid)()); - VG_(message_no_f_c)(Vg_UserMsg, "%t", toolname); - if (VG_(clo_log_name)) - print_file_vars(VG_(clo_log_name)); + VG_(printf_xml)("\n"); + VG_(printf_xml)("%d\n", VG_(getpid)()); + VG_(printf_xml)("%d\n", VG_(getppid)()); + VG_(printf_xml_no_f_c)("%t\n", toolname); + if (xml_fname_unexpanded) + print_file_vars(xml_fname_unexpanded); if (VG_(clo_xml_user_comment)) { /* Note: the user comment itself is XML and is therefore to be passed through verbatim (%s) rather than escaped (%t). */ - VG_(message)(Vg_UserMsg, "%s", - VG_(clo_xml_user_comment)); + VG_(printf_xml)("%s\n", + VG_(clo_xml_user_comment)); } - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml)("\n"); + VG_(printf_xml)("\n"); - VG_(message)(Vg_UserMsg, " "); + VG_(printf_xml)(" \n"); if (VG_(name_of_launcher)) - VG_(message_no_f_c)(Vg_UserMsg, " %t", - VG_(name_of_launcher)); + VG_(printf_xml_no_f_c)(" %t\n", + VG_(name_of_launcher)); else - VG_(message_no_f_c)(Vg_UserMsg, " %t", - "(launcher name unknown)"); + VG_(printf_xml_no_f_c)(Vg_UserMsg, " %t\n", + "(launcher name unknown)"); for (i = 0; i < VG_(sizeXA)( VG_(args_for_valgrind) ); i++) { - VG_(message_no_f_c)(Vg_UserMsg, - " %t", - * (HChar**) VG_(indexXA)( VG_(args_for_valgrind), i )); + VG_(printf_xml_no_f_c)( + " %t\n", + * (HChar**) VG_(indexXA)( VG_(args_for_valgrind), i ) + ); } - VG_(message)(Vg_UserMsg, " "); + VG_(printf_xml)(" \n"); - VG_(message)(Vg_UserMsg, " "); + VG_(printf_xml)(" \n"); if (VG_(args_the_exename)) - VG_(message_no_f_c)(Vg_UserMsg, " %t", - VG_(args_the_exename)); + VG_(printf_xml_no_f_c)(" %t\n", + VG_(args_the_exename)); for (i = 0; i < VG_(sizeXA)( VG_(args_for_client) ); i++) { - VG_(message_no_f_c)(Vg_UserMsg, - " %t", - * (HChar**) VG_(indexXA)( VG_(args_for_client), i )); + VG_(printf_xml_no_f_c)( + " %t\n", + * (HChar**) VG_(indexXA)( VG_(args_for_client), i ) + ); } - VG_(message)(Vg_UserMsg, " "); + VG_(printf_xml)(" \n"); - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml)("\n"); } // Empty line after the preamble if (VG_(clo_verbosity) > 0) - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); + if (VG_(clo_xml)) + VG_(printf_xml)("\n"); if (VG_(clo_verbosity) > 1) { SysRes fd; VexArch vex_arch; VexArchInfo vex_archinfo; if (!logging_to_fd) - VG_(message)(Vg_DebugMsg, ""); - VG_(message)(Vg_DebugMsg, "Command line"); + VG_(message)(Vg_DebugMsg, "\n"); + VG_(message)(Vg_DebugMsg, "Command line\n"); if (VG_(args_the_exename)) - VG_(message)(Vg_DebugMsg, " %s", VG_(args_the_exename)); + VG_(message)(Vg_DebugMsg, " %s\n", VG_(args_the_exename)); for (i = 0; i < VG_(sizeXA)( VG_(args_for_client) ); i++) VG_(message)(Vg_DebugMsg, - " %s", + " %s\n", * (HChar**) VG_(indexXA)( VG_(args_for_client), i )); - VG_(message)(Vg_DebugMsg, "Startup, with flags:"); + VG_(message)(Vg_DebugMsg, "Startup, with flags:\n"); for (i = 0; i < VG_(sizeXA)( VG_(args_for_valgrind) ); i++) { VG_(message)(Vg_DebugMsg, - " %s", + " %s\n", * (HChar**) VG_(indexXA)( VG_(args_for_valgrind), i )); } - VG_(message)(Vg_DebugMsg, "Contents of /proc/version:"); + VG_(message)(Vg_DebugMsg, "Contents of /proc/version:\n"); fd = VG_(open) ( "/proc/version", VKI_O_RDONLY, 0 ); if (sr_isError(fd)) { - VG_(message)(Vg_DebugMsg, " can't open /proc/version"); + VG_(message)(Vg_DebugMsg, " can't open /proc/version\n"); } else { # define BUF_LEN 256 Char version_buf[BUF_LEN]; @@ -902,9 +1116,9 @@ static void print_preamble(Bool logging_to_fd, const char* toolname) vg_assert(n <= BUF_LEN); if (n > 0) { version_buf[n-1] = '\0'; - VG_(message)(Vg_DebugMsg, " %s", version_buf); + VG_(message)(Vg_DebugMsg, " %s\n", version_buf); } else { - VG_(message)(Vg_DebugMsg, " (empty?)"); + VG_(message)(Vg_DebugMsg, " (empty?)\n"); } VG_(close)(sr_Res(fd)); # undef BUF_LEN @@ -913,16 +1127,17 @@ static void print_preamble(Bool logging_to_fd, const char* toolname) VG_(machine_get_VexArchInfo)( &vex_arch, &vex_archinfo ); VG_(message)( Vg_DebugMsg, - "Arch and hwcaps: %s, %s", + "Arch and hwcaps: %s, %s\n", LibVEX_ppVexArch ( vex_arch ), LibVEX_ppVexHwCaps ( vex_arch, vex_archinfo.hwcaps ) ); VG_(message)( Vg_DebugMsg, - "Page sizes: currently %d, max supported %d", + "Page sizes: currently %d, max supported %d\n", (Int)VKI_PAGE_SIZE, (Int)VKI_MAX_PAGE_SIZE ); - VG_(message)(Vg_DebugMsg, "Valgrind library directory: %s", VG_(libdir)); + VG_(message)(Vg_DebugMsg, + "Valgrind library directory: %s\n", VG_(libdir)); } } @@ -1131,8 +1346,9 @@ Int valgrind_main ( Int argc, HChar **argv, HChar **envp ) HChar* toolname = "memcheck"; // default to Memcheck Int need_help = 0; // 0 = no, 1 = --help, 2 = --help-debug ThreadId tid_main = VG_INVALID_THREADID; + Bool logging_to_fd = False; + Char* xml_fname_unexpanded = NULL; Int loglevel, i; - Bool logging_to_fd; struct vki_rlimit zero = { 0, 0 }; XArray* addr2dihandle = NULL; @@ -1628,7 +1844,8 @@ Int valgrind_main ( Int argc, HChar **argv, HChar **envp ) VG_(debugLog)(1, "main", "(main_) Process Valgrind's command line options, " "setup logging\n"); - logging_to_fd = main_process_cmd_line_options(toolname); + main_process_cmd_line_options ( &logging_to_fd, &xml_fname_unexpanded, + toolname ); //-------------------------------------------------------------- // Zeroise the millisecond counter by doing a first read of it. @@ -1639,12 +1856,12 @@ Int valgrind_main ( Int argc, HChar **argv, HChar **envp ) //-------------------------------------------------------------- // Print the preamble // p: tl_pre_clo_init [for 'VG_(details).name' and friends] - // p: main_process_cmd_line_options() [for VG_(clo_verbosity), - // VG_(clo_xml), - // logging_to_fd] + // p: main_process_cmd_line_options() + // [for VG_(clo_verbosity), VG_(clo_xml), + // logging_to_fd, xml_fname_unexpanded] //-------------------------------------------------------------- VG_(debugLog)(1, "main", "Print the preamble...\n"); - print_preamble(logging_to_fd, toolname); + print_preamble(logging_to_fd, xml_fname_unexpanded, toolname); VG_(debugLog)(1, "main", "...finished the preamble\n"); //-------------------------------------------------------------- @@ -2050,13 +2267,12 @@ Int valgrind_main ( Int argc, HChar **argv, HChar **envp ) if (VG_(clo_xml)) { HChar buf[50]; VG_(elapsed_wallclock_time)(buf); - VG_(message_no_f_c)(Vg_UserMsg, - "\n" - " RUNNING\n" - " \n" - "", - buf); - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml_no_f_c)( "\n" + " RUNNING\n" + " \n" + "\n", + buf ); + VG_(printf_xml_no_f_c)( "\n" ); } VG_(debugLog)(1, "main", "Running thread 1\n"); @@ -2149,41 +2365,62 @@ void shutdown_actions_NORETURN( ThreadId tid, VG_(threads)[tid].status = VgTs_Empty; //-------------------------------------------------------------- - // Finalisation: cleanup, messages, etc. Order no so important, only + // Finalisation: cleanup, messages, etc. Order not so important, only // affects what order the messages come. //-------------------------------------------------------------- if (VG_(clo_verbosity) > 0) - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); + if (VG_(clo_xml)) + VG_(printf_xml)("\n"); if (VG_(clo_xml)) { HChar buf[50]; - if (VG_(needs).core_errors || VG_(needs).tool_errors) { - VG_(show_error_counts_as_XML)(); - VG_(message)(Vg_UserMsg, ""); - } VG_(elapsed_wallclock_time)(buf); - VG_(message_no_f_c)(Vg_UserMsg, - "\n" - " FINISHED\n" - " \n" - "", - buf); - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml_no_f_c)( "\n" + " FINISHED\n" + " \n" + "\n", + buf); } /* Print out file descriptor summary and stats. */ if (VG_(clo_track_fds)) VG_(show_open_fds)(); - if (VG_(needs).core_errors || VG_(needs).tool_errors) - VG_(show_all_errors)(); + /* ** HACK ALERT ** HACK ALERT ** HACK ALERT ** HACK ALERT ** */ + if (VG_(clo_xml)) { + /* THIS IS WHAT WE SHOULD CHANGE IT TO */ + /* For the moment, do it like this (the "right way") in XML + mode, so that output is as described in XML Protocol 4. */ + /* A good test is memcheck/tests/amd64/defcfaexpr; ensure + the output does not change */ + VG_TDICT_CALL(tool_fini, 0/*exitcode*/); + + /* Show the error counts. */ + if (VG_(needs).core_errors || VG_(needs).tool_errors) { + VG_(printf_xml)( "\n" ); + VG_(show_error_counts_as_XML)(); + VG_(printf_xml)( "\n" ); + } + + /* In XML mode, this merely prints the used suppressions. */ + if (VG_(needs).core_errors || VG_(needs).tool_errors) + VG_(show_all_errors)(); + + } else { + /* THIS IS WHAT IT HAS ALWAYS BEEN, + resulting in https://bugs.kde.org/show_bug.cgi?id=186790 */ + if (VG_(needs).core_errors || VG_(needs).tool_errors) + VG_(show_all_errors)(); - VG_TDICT_CALL(tool_fini, 0/*exitcode*/); + VG_TDICT_CALL(tool_fini, 0/*exitcode*/); + } + /* END ** HACK ALERT ** HACK ALERT ** HACK ALERT ** HACK ALERT ** */ if (VG_(clo_xml)) { - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, ""); + VG_(printf_xml)("\n"); + VG_(printf_xml)("\n"); + VG_(printf_xml)("\n"); } VG_(sanity_check_general)( True /*include expensive checks*/ ); @@ -2210,6 +2447,9 @@ void shutdown_actions_NORETURN( ThreadId tid, if (0) LibVEX_ShowAllocStats(); + /* Flush any output cached by previous calls to VG_(message). */ + VG_(message_flush)(); + /* Ok, finally exit in the os-specific way, according to the scheduler's return code. In short, if the (last) thread exited by calling sys_exit, do likewise; if the (last) thread stopped due to a fatal @@ -2282,9 +2522,9 @@ static void final_tidyup(ThreadId tid) r2 = VG_(get_tocptr)( __libc_freeres_wrapper ); if (r2 == 0) { VG_(message)(Vg_UserMsg, - "Caught __NR_exit, but can't run __libc_freeres()"); + "Caught __NR_exit, but can't run __libc_freeres()\n"); VG_(message)(Vg_UserMsg, - " since cannot establish TOC pointer for it."); + " since cannot establish TOC pointer for it.\n"); return; } # endif @@ -2293,7 +2533,7 @@ static void final_tidyup(ThreadId tid) VG_(clo_trace_syscalls) || VG_(clo_trace_sched)) VG_(message)(Vg_DebugMsg, - "Caught __NR_exit; running __libc_freeres()"); + "Caught __NR_exit; running __libc_freeres()\n"); /* set thread context to point to libc_freeres_wrapper */ /* ppc64-linux note: __libc_freeres_wrapper gives us the real diff --git a/coregrind/m_mallocfree.c b/coregrind/m_mallocfree.c index 14ee741b5d..bad1f7fa5b 100644 --- a/coregrind/m_mallocfree.c +++ b/coregrind/m_mallocfree.c @@ -495,7 +495,7 @@ void VG_(print_all_arena_stats) ( void ) for (i = 0; i < VG_N_ARENAS; i++) { Arena* a = arenaId_to_ArenaP(i); VG_(message)(Vg_DebugMsg, - "%8s: %8ld mmap'd, %8ld/%8ld max/curr", + "%8s: %8ld mmap'd, %8ld/%8ld max/curr\n", a->name, a->bytes_mmaped, a->bytes_on_loan_max, a->bytes_on_loan ); } @@ -1047,7 +1047,7 @@ static void sanity_check_malloc_arena ( ArenaId aid ) if (VG_(clo_verbosity) > 2) VG_(message)(Vg_DebugMsg, "%8s: %2d sbs, %5d bs, %2d/%-2d free bs, " - "%7ld mmap, %7ld loan", + "%7ld mmap, %7ld loan\n", a->name, superblockctr, blockctr_sb, blockctr_sb_free, blockctr_li, diff --git a/coregrind/m_options.c b/coregrind/m_options.c index 69270dd448..5db49f56f6 100644 --- a/coregrind/m_options.c +++ b/coregrind/m_options.c @@ -56,8 +56,8 @@ HChar* VG_(clo_xml_user_comment) = NULL; Bool VG_(clo_demangle) = True; Bool VG_(clo_trace_children) = False; Bool VG_(clo_child_silent_after_fork) = False; -Int VG_(clo_log_fd) = 2; /* must be signed, as -1 is possible. */ -Char* VG_(clo_log_name) = NULL; +Char* VG_(clo_log_fname_expanded) = NULL; +Char* VG_(clo_xml_fname_expanded) = NULL; Bool VG_(clo_time_stamp) = False; Int VG_(clo_input_fd) = 0; /* stdin */ Int VG_(clo_n_suppressions) = 0; @@ -99,8 +99,8 @@ Bool VG_(clo_auto_run_dsymutil) = False; static void revert_to_stderr ( void ) { - vg_assert( !VG_(logging_to_socket) ); - VG_(clo_log_fd) = 2; /* stderr */ + VG_(log_output_sink).fd = 2; /* stderr */ + VG_(log_output_sink).is_socket = False; } __attribute__((noreturn)) @@ -143,7 +143,7 @@ Char* VG_(expand_file_name)(Char* option_name, Char* format) if (VG_STREQ(format, "")) { // Empty name, bad. - VG_UMSG("%s: filename is empty", option_name); + VG_(umsg)("%s: filename is empty", option_name); goto bad; } @@ -152,10 +152,11 @@ Char* VG_(expand_file_name)(Char* option_name, Char* format) // that we don't allow a legitimate filename beginning with '~' but that // seems very unlikely. if (format[0] == '~') { - VG_UMSG("%s: filename begins with '~'", option_name); - VG_UMSG("You probably expected the shell to expand the '~', but it"); - VG_UMSG("didn't. The rules for '~'-expansion vary from shell to shell."); - VG_UMSG("You might have more luck using $HOME instead."); + VG_(umsg)("%s: filename begins with '~'\n", option_name); + VG_(umsg)("You probably expected the shell to expand the '~', but it\n"); + VG_(umsg)("didn't. The rules for '~'-expansion " + "vary from shell to shell.\n"); + VG_(umsg)("You might have more luck using $HOME instead.\n"); goto bad; } @@ -209,7 +210,7 @@ Char* VG_(expand_file_name)(Char* option_name, Char* format) qualname = &format[i]; while (True) { if (0 == format[i]) { - VG_(message)(Vg_UserMsg, "%s: malformed %%q specifier", + VG_(message)(Vg_UserMsg, "%s: malformed %%q specifier\n", option_name); goto bad; } else if ('}' == format[i]) { @@ -219,7 +220,7 @@ Char* VG_(expand_file_name)(Char* option_name, Char* format) qual = VG_(getenv)(qualname); if (NULL == qual) { VG_(message)(Vg_UserMsg, - "%s: environment variable %s is not set", + "%s: environment variable %s is not set\n", option_name, qualname); format[i] = '}'; // Put the '}' back. goto bad; @@ -234,14 +235,14 @@ Char* VG_(expand_file_name)(Char* option_name, Char* format) j += VG_(sprintf)(&out[j], "%s", qual); } else { VG_(message)(Vg_UserMsg, - "%s: expected '{' after '%%q'", option_name); + "%s: expected '{' after '%%q'\n", option_name); goto bad; } } else { // Something else, abort. VG_(message)(Vg_UserMsg, - "%s: expected 'p' or 'q' or '%%' after '%%'", option_name); + "%s: expected 'p' or 'q' or '%%' after '%%'\n", option_name); goto bad; } } diff --git a/coregrind/m_redir.c b/coregrind/m_redir.c index d824a79a42..6b8d60ce9d 100644 --- a/coregrind/m_redir.c +++ b/coregrind/m_redir.c @@ -412,7 +412,7 @@ void VG_(redir_notify_new_DebugInfo)( DebugInfo* newsi ) /* Complain */ VG_(message)(Vg_DebugMsg, - "WARNING: no TOC ptr for redir/wrap to %s %s", + "WARNING: no TOC ptr for redir/wrap to %s %s\n", demangled_sopatt, demangled_fnpatt); } } @@ -653,7 +653,7 @@ static void maybe_add_active ( Active act ) bad: vg_assert(what); if (VG_(clo_verbosity) > 1) { - VG_(message)(Vg_UserMsg, "WARNING: %s", what); + VG_(message)(Vg_UserMsg, "WARNING: %s\n", what); show_active( " new: ", &act); } } @@ -1081,12 +1081,12 @@ void handle_maybe_load_notifier( const UChar* soname, static void show_spec ( HChar* left, Spec* spec ) { - VG_(message)(Vg_DebugMsg, - "%s%25s %30s %s-> 0x%08llx", - left, - spec->from_sopatt, spec->from_fnpatt, - spec->isWrap ? "W" : "R", - (ULong)spec->to_addr ); + VG_(message)( Vg_DebugMsg, + "%s%25s %30s %s-> 0x%08llx\n", + left, + spec->from_sopatt, spec->from_fnpatt, + spec->isWrap ? "W" : "R", + (ULong)spec->to_addr ); } static void show_active ( HChar* left, Active* act ) @@ -1100,7 +1100,7 @@ static void show_active ( HChar* left, Active* act ) ok = VG_(get_fnname_w_offset)(act->to_addr, name2, 64); if (!ok) VG_(strcpy)(name2, "???"); - VG_(message)(Vg_DebugMsg, "%s0x%08llx (%20s) %s-> 0x%08llx %s", + VG_(message)(Vg_DebugMsg, "%s0x%08llx (%20s) %s-> 0x%08llx %s\n", left, (ULong)act->from_addr, name1, act->isWrap ? "W" : "R", @@ -1112,23 +1112,23 @@ static void show_redir_state ( HChar* who ) TopSpec* ts; Spec* sp; Active* act; - VG_(message)(Vg_DebugMsg, "<<"); - VG_(message)(Vg_DebugMsg, " ------ REDIR STATE %s ------", who); + VG_(message)(Vg_DebugMsg, "<<\n"); + VG_(message)(Vg_DebugMsg, " ------ REDIR STATE %s ------\n", who); for (ts = topSpecs; ts; ts = ts->next) { VG_(message)(Vg_DebugMsg, - " TOPSPECS of soname %s", + " TOPSPECS of soname %s\n", ts->seginfo ? (HChar*)VG_(seginfo_soname)(ts->seginfo) : "(hardwired)" ); for (sp = ts->specs; sp; sp = sp->next) show_spec(" ", sp); } - VG_(message)(Vg_DebugMsg, " ------ ACTIVE ------"); + VG_(message)(Vg_DebugMsg, " ------ ACTIVE ------\n"); VG_(OSetGen_ResetIter)( activeSet ); while ( (act = VG_(OSetGen_Next)(activeSet)) ) { show_active(" ", act); } - VG_(message)(Vg_DebugMsg, ">>"); + VG_(message)(Vg_DebugMsg, ">>\n"); } /*--------------------------------------------------------------------*/ diff --git a/coregrind/m_replacemalloc/replacemalloc_core.c b/coregrind/m_replacemalloc/replacemalloc_core.c index fbae2bc0f5..de1d9841b4 100644 --- a/coregrind/m_replacemalloc/replacemalloc_core.c +++ b/coregrind/m_replacemalloc/replacemalloc_core.c @@ -60,7 +60,9 @@ Bool VG_(replacement_malloc_process_cmd_line_option)(Char* arg) { VG_(message)(Vg_UserMsg, "Invalid --alignment= setting. " - "Should be a power of 2, >= %d, <= 4096.", VG_MIN_MALLOC_SZB); + "Should be a power of 2, >= %d, <= 4096.\n", + VG_MIN_MALLOC_SZB + ); VG_(err_bad_option)("--alignment"); } } diff --git a/coregrind/m_scheduler/scheduler.c b/coregrind/m_scheduler/scheduler.c index 91bb20cd81..295e0ab03d 100644 --- a/coregrind/m_scheduler/scheduler.c +++ b/coregrind/m_scheduler/scheduler.c @@ -127,12 +127,12 @@ static UInt sanity_slow_count = 0; void VG_(print_scheduler_stats)(void) { VG_(message)(Vg_DebugMsg, - "scheduler: %'llu jumps (bb entries).", bbs_done ); + "scheduler: %'llu jumps (bb entries).\n", bbs_done ); VG_(message)(Vg_DebugMsg, - "scheduler: %'llu/%'llu major/minor sched events.", + "scheduler: %'llu/%'llu major/minor sched events.\n", n_scheduling_events_MAJOR, n_scheduling_events_MINOR); VG_(message)(Vg_DebugMsg, - " sanity: %d cheap, %d expensive checks.", + " sanity: %d cheap, %d expensive checks.\n", sanity_fast_count, sanity_slow_count ); } @@ -147,7 +147,7 @@ static vg_sema_t the_BigLock; static void print_sched_event ( ThreadId tid, Char* what ) { - VG_(message)(Vg_DebugMsg, " SCHED[%d]: %s", tid, what ); + VG_(message)(Vg_DebugMsg, " SCHED[%d]: %s\n", tid, what ); } static @@ -320,7 +320,7 @@ void VG_(get_thread_out_of_syscall)(ThreadId tid) if (VG_(threads)[tid].status == VgTs_WaitSys) { if (VG_(clo_trace_signals)) { VG_(message)(Vg_DebugMsg, - "get_thread_out_of_syscall zaps tid %d lwp %d", + "get_thread_out_of_syscall zaps tid %d lwp %d\n", tid, VG_(threads)[tid].os_state.lwpid); } # if defined(VGO_darwin) @@ -1024,8 +1024,8 @@ VgSchedReturnCode VG_(scheduler) ( ThreadId tid ) n_scheduling_events_MINOR++; if (0) - VG_(message)(Vg_DebugMsg, "thread %d: running for %d bbs", - tid, VG_(dispatch_ctr) - 1 ); + VG_(message)(Vg_DebugMsg, "thread %d: running for %d bbs\n", + tid, VG_(dispatch_ctr) - 1 ); trc = run_thread_for_a_while ( tid ); @@ -1120,8 +1120,8 @@ VgSchedReturnCode VG_(scheduler) ( ThreadId tid ) : counts[ew]++ < 3; if (show && VG_(clo_show_emwarns) && !VG_(clo_xml)) { VG_(message)( Vg_UserMsg, - "Emulation warning: unsupported action:"); - VG_(message)( Vg_UserMsg, " %s", what); + "Emulation warning: unsupported action:\n"); + VG_(message)( Vg_UserMsg, " %s\n", what); VG_(get_and_pp_StackTrace)( tid, VG_(clo_backtrace_size) ); } break; @@ -1135,12 +1135,12 @@ VgSchedReturnCode VG_(scheduler) ( ThreadId tid ) ? "unknown (?!)" : LibVEX_EmWarn_string(ew); VG_(message)( Vg_UserMsg, - "Emulation fatal error -- Valgrind cannot continue:"); - VG_(message)( Vg_UserMsg, " %s", what); + "Emulation fatal error -- Valgrind cannot continue:\n"); + VG_(message)( Vg_UserMsg, " %s\n", what); VG_(get_and_pp_StackTrace)( tid, VG_(clo_backtrace_size) ); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "Valgrind has to exit now. Sorry."); - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); + VG_(message)(Vg_UserMsg, "Valgrind has to exit now. Sorry.\n"); + VG_(message)(Vg_UserMsg, "\n"); VG_(exit)(1); break; } @@ -1158,10 +1158,10 @@ VgSchedReturnCode VG_(scheduler) ( ThreadId tid ) break; case VEX_TRC_JMP_NODECODE: - VG_(message)(Vg_UserMsg, - "valgrind: Unrecognised instruction at address %#lx.", + VG_(umsg)( + "valgrind: Unrecognised instruction at address %#lx.\n", VG_(get_IP)(tid)); -#define M(a) VG_(message)(Vg_UserMsg, a); +#define M(a) VG_(umsg)(a "\n"); M("Your program just tried to execute an instruction that Valgrind" ); M("did not recognise. There are two possible reasons for this." ); M("1. Your program has a bug and erroneously jumped to a non-code" ); @@ -1318,8 +1318,8 @@ static Bool os_client_request(ThreadId tid, UWord *args) /* This is equivalent to an exit() syscall, but we don't set the exitcode (since it might already be set) */ if (0 || VG_(clo_trace_syscalls) || VG_(clo_trace_sched)) - VG_(message)(Vg_DebugMsg, - "__libc_freeres() done; really quitting!"); + VG_(message)(Vg_DebugMsg, + "__libc_freeres() done; really quitting!\n"); VG_(threads)[tid].exitreason = VgSrc_ExitThread; break; @@ -1349,7 +1349,7 @@ void do_client_request ( ThreadId tid ) case VG_USERREQ__CLIENT_CALL0: { UWord (*f)(ThreadId) = (void*)arg[1]; if (f == NULL) - VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL0: func=%p", f); + VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL0: func=%p\n", f); else SET_CLCALL_RETVAL(tid, f ( tid ), (Addr)f); break; @@ -1357,7 +1357,7 @@ void do_client_request ( ThreadId tid ) case VG_USERREQ__CLIENT_CALL1: { UWord (*f)(ThreadId, UWord) = (void*)arg[1]; if (f == NULL) - VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL1: func=%p", f); + VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL1: func=%p\n", f); else SET_CLCALL_RETVAL(tid, f ( tid, arg[2] ), (Addr)f ); break; @@ -1365,7 +1365,7 @@ void do_client_request ( ThreadId tid ) case VG_USERREQ__CLIENT_CALL2: { UWord (*f)(ThreadId, UWord, UWord) = (void*)arg[1]; if (f == NULL) - VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL2: func=%p", f); + VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL2: func=%p\n", f); else SET_CLCALL_RETVAL(tid, f ( tid, arg[2], arg[3] ), (Addr)f ); break; @@ -1373,7 +1373,7 @@ void do_client_request ( ThreadId tid ) case VG_USERREQ__CLIENT_CALL3: { UWord (*f)(ThreadId, UWord, UWord, UWord) = (void*)arg[1]; if (f == NULL) - VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL3: func=%p", f); + VG_(message)(Vg_DebugMsg, "VG_USERREQ__CLIENT_CALL3: func=%p\n", f); else SET_CLCALL_RETVAL(tid, f ( tid, arg[2], arg[3], arg[4] ), (Addr)f ); break; @@ -1388,18 +1388,21 @@ void do_client_request ( ThreadId tid ) case VG_USERREQ__PRINTF: { Int count = VG_(vmessage)( Vg_ClientMsg, (char *)arg[1], (void*)arg[2] ); + VG_(message_flush)(); SET_CLREQ_RETVAL( tid, count ); break; } case VG_USERREQ__INTERNAL_PRINTF: { Int count = VG_(vmessage)( Vg_DebugMsg, (char *)arg[1], (void*)arg[2] ); + VG_(message_flush)(); SET_CLREQ_RETVAL( tid, count ); break; } case VG_USERREQ__PRINTF_BACKTRACE: { Int count = VG_(vmessage)( Vg_ClientMsg, (char *)arg[1], (void*)arg[2] ); + VG_(message_flush)(); VG_(get_and_pp_StackTrace)( tid, VG_(clo_backtrace_size) ); SET_CLREQ_RETVAL( tid, count ); break; } @@ -1500,7 +1503,7 @@ void do_client_request ( ThreadId tid ) if (c2 == 0) c2 = '_'; VG_(message)(Vg_UserMsg, "Warning:\n" " unhandled client request: 0x%lx (%c%c+0x%lx). Perhaps\n" - " VG_(needs).client_requests should be set?", + " VG_(needs).client_requests should be set?\n", arg[0], c1, c2, arg[0] & 0xffff); whined = True; } @@ -1622,7 +1625,7 @@ void VG_(sanity_check_general) ( Bool force_expensive ) if (remains < VKI_PAGE_SIZE) VG_(message)(Vg_DebugMsg, "WARNING: Thread %d is within %ld bytes " - "of running out of stack!", + "of running out of stack!\n", tid, remains); } } diff --git a/coregrind/m_sigframe/sigframe-amd64-linux.c b/coregrind/m_sigframe/sigframe-amd64-linux.c index b3b97d1145..30f78dccc2 100644 --- a/coregrind/m_sigframe/sigframe-amd64-linux.c +++ b/coregrind/m_sigframe/sigframe-amd64-linux.c @@ -390,12 +390,12 @@ static Bool extend ( ThreadState *tst, Addr addr, SizeT size ) if (stackseg == NULL || !stackseg->hasR || !stackseg->hasW) { VG_(message)( Vg_UserMsg, - "Can't extend stack to %#lx during signal delivery for thread %d:", + "Can't extend stack to %#lx during signal delivery for thread %d:\n", addr, tid); if (stackseg == NULL) - VG_(message)(Vg_UserMsg, " no stack segment"); + VG_(message)(Vg_UserMsg, " no stack segment\n"); else - VG_(message)(Vg_UserMsg, " too small or bad protection modes"); + VG_(message)(Vg_UserMsg, " too small or bad protection modes\n"); /* set SIGSEGV to default handler */ VG_(set_default_handler)(VKI_SIGSEGV); @@ -543,7 +543,7 @@ Bool restore_vg_sigframe ( ThreadState *tst, if (frame->magicPI != 0x31415927 || frame->magicE != 0x27182818) { VG_(message)(Vg_UserMsg, "Thread %d return signal frame " - "corrupted. Killing process.", + "corrupted. Killing process.\n", tst->tid); VG_(set_default_handler)(VKI_SIGSEGV); VG_(synth_fault)(tst->tid); @@ -626,7 +626,7 @@ void VG_(sigframe_destroy)( ThreadId tid, Bool isRT ) if (VG_(clo_trace_signals)) VG_(message)( Vg_DebugMsg, - "VG_(signal_return) (thread %d): isRT=%d valid magic; RIP=%#llx", + "VG_(signal_return) (thread %d): isRT=%d valid magic; RIP=%#llx\n", tid, isRT, tst->arch.vex.guest_RIP); /* tell the tools */ diff --git a/coregrind/m_sigframe/sigframe-ppc32-aix5.c b/coregrind/m_sigframe/sigframe-ppc32-aix5.c index 3cecd57ba1..d6b6e28842 100644 --- a/coregrind/m_sigframe/sigframe-ppc32-aix5.c +++ b/coregrind/m_sigframe/sigframe-ppc32-aix5.c @@ -221,7 +221,7 @@ void VG_(sigframe_destroy)( ThreadId tid, Bool isRT ) if (VG_(clo_trace_signals)) VG_(message)(Vg_DebugMsg, - "vg_pop_signal_frame (thread %d): valid magic; CIA=%#x", + "vg_pop_signal_frame (thread %d): valid magic; CIA=%#x\n", tid, tst->arch.vex.guest_CIA); VG_TRACK( die_mem_stack_signal, diff --git a/coregrind/m_sigframe/sigframe-ppc32-linux.c b/coregrind/m_sigframe/sigframe-ppc32-linux.c index d36988c278..71442301c9 100644 --- a/coregrind/m_sigframe/sigframe-ppc32-linux.c +++ b/coregrind/m_sigframe/sigframe-ppc32-linux.c @@ -520,12 +520,12 @@ static Bool extend ( ThreadState *tst, Addr addr, SizeT size ) if (stackseg == NULL || !stackseg->hasR || !stackseg->hasW) { VG_(message)( Vg_UserMsg, - "Can't extend stack to %#lx during signal delivery for thread %d:", + "Can't extend stack to %#lx during signal delivery for thread %d:\n", addr, tid); if (stackseg == NULL) - VG_(message)(Vg_UserMsg, " no stack segment"); + VG_(message)(Vg_UserMsg, " no stack segment\n"); else - VG_(message)(Vg_UserMsg, " too small or bad protection modes"); + VG_(message)(Vg_UserMsg, " too small or bad protection modes\n"); /* set SIGSEGV to default handler */ VG_(set_default_handler)(VKI_SIGSEGV); @@ -942,7 +942,8 @@ void VG_(sigframe_destroy)( ThreadId tid, Bool isRT ) if (VG_(clo_trace_signals)) VG_(message)(Vg_DebugMsg, - "vg_pop_signal_frame (thread %d): isRT=%d valid magic; EIP=%#x", + "vg_pop_signal_frame (thread %d): " + "isRT=%d valid magic; EIP=%#x\n", tid, has_siginfo, tst->arch.vex.guest_CIA); /* tell the tools */ diff --git a/coregrind/m_sigframe/sigframe-ppc64-aix5.c b/coregrind/m_sigframe/sigframe-ppc64-aix5.c index 083a5a1d8d..1f94a93435 100644 --- a/coregrind/m_sigframe/sigframe-ppc64-aix5.c +++ b/coregrind/m_sigframe/sigframe-ppc64-aix5.c @@ -233,7 +233,7 @@ void VG_(sigframe_destroy)( ThreadId tid, Bool isRT ) if (frame->magicPI != 0x31415927) { if (!VG_(clo_xml)) VG_(message)(Vg_DebugMsg, - "WARNING: dubious signal return: searching %ld bytes for frame", + "WARNING: dubious signal return: searching %ld bytes for frame\n", scannable_bytes); for (i = 0; i < scannable_bytes/4; i++) { if (frame->magicPI == 0x31415927) @@ -255,7 +255,7 @@ void VG_(sigframe_destroy)( ThreadId tid, Bool isRT ) if (VG_(clo_trace_signals)) VG_(message)(Vg_DebugMsg, - "vg_pop_signal_frame (thread %d): valid magic; CIA=%#llx", + "vg_pop_signal_frame (thread %d): valid magic; CIA=%#llx\n", tid, tst->arch.vex.guest_CIA); VG_TRACK( die_mem_stack_signal, diff --git a/coregrind/m_sigframe/sigframe-ppc64-linux.c b/coregrind/m_sigframe/sigframe-ppc64-linux.c index 16411d7a24..f3cd180ba1 100644 --- a/coregrind/m_sigframe/sigframe-ppc64-linux.c +++ b/coregrind/m_sigframe/sigframe-ppc64-linux.c @@ -150,12 +150,12 @@ static Bool extend ( ThreadState *tst, Addr addr, SizeT size ) if (stackseg == NULL || !stackseg->hasR || !stackseg->hasW) { VG_(message)( Vg_UserMsg, - "Can't extend stack to %#lx during signal delivery for thread %d:", + "Can't extend stack to %#lx during signal delivery for thread %d:\n", addr, tid); if (stackseg == NULL) - VG_(message)(Vg_UserMsg, " no stack segment"); + VG_(message)(Vg_UserMsg, " no stack segment\n"); else - VG_(message)(Vg_UserMsg, " too small or bad protection modes"); + VG_(message)(Vg_UserMsg, " too small or bad protection modes\n"); /* set SIGSEGV to default handler */ VG_(set_default_handler)(VKI_SIGSEGV); @@ -377,7 +377,8 @@ void VG_(sigframe_destroy)( ThreadId tid, Bool isRT ) if (VG_(clo_trace_signals)) VG_(message)(Vg_DebugMsg, - "vg_pop_signal_frame (thread %d): isRT=%d valid magic; EIP=%#llx", + "vg_pop_signal_frame (thread %d): isRT=%d " + "valid magic; EIP=%#llx\n", tid, has_siginfo, tst->arch.vex.guest_CIA); /* tell the tools */ diff --git a/coregrind/m_sigframe/sigframe-x86-linux.c b/coregrind/m_sigframe/sigframe-x86-linux.c index 11b779f268..cfaaafb115 100644 --- a/coregrind/m_sigframe/sigframe-x86-linux.c +++ b/coregrind/m_sigframe/sigframe-x86-linux.c @@ -411,12 +411,12 @@ static Bool extend ( ThreadState *tst, Addr addr, SizeT size ) if (stackseg == NULL || !stackseg->hasR || !stackseg->hasW) { VG_(message)( Vg_UserMsg, - "Can't extend stack to %#lx during signal delivery for thread %d:", + "Can't extend stack to %#lx during signal delivery for thread %d:\n", addr, tid); if (stackseg == NULL) - VG_(message)(Vg_UserMsg, " no stack segment"); + VG_(message)(Vg_UserMsg, " no stack segment\n"); else - VG_(message)(Vg_UserMsg, " too small or bad protection modes"); + VG_(message)(Vg_UserMsg, " too small or bad protection modes\n"); /* set SIGSEGV to default handler */ VG_(set_default_handler)(VKI_SIGSEGV); @@ -627,7 +627,7 @@ Bool restore_vg_sigframe ( ThreadState *tst, if (frame->magicPI != 0x31415927 || frame->magicE != 0x27182818) { VG_(message)(Vg_UserMsg, "Thread %d return signal frame " - "corrupted. Killing process.", + "corrupted. Killing process.\n", tst->tid); VG_(set_default_handler)(VKI_SIGSEGV); VG_(synth_fault)(tst->tid); @@ -716,7 +716,7 @@ void VG_(sigframe_destroy)( ThreadId tid, Bool isRT ) if (VG_(clo_trace_signals)) VG_(message)( Vg_DebugMsg, - "VG_(signal_return) (thread %d): isRT=%d valid magic; EIP=%#x", + "VG_(signal_return) (thread %d): isRT=%d valid magic; EIP=%#x\n", tid, isRT, tst->arch.vex.guest_EIP); /* tell the tools */ diff --git a/coregrind/m_signals.c b/coregrind/m_signals.c index c4a1a36507..8765c769e5 100644 --- a/coregrind/m_signals.c +++ b/coregrind/m_signals.c @@ -871,12 +871,12 @@ static void handle_SCSS_change ( Bool force_update ) VG_(sigdelset)( &ksa.sa_mask, VKI_SIGSTOP ); if (VG_(clo_trace_signals) && VG_(clo_verbosity) > 2) - VG_DMSG("setting ksig %d to: hdlr %p, flags 0x%lx, " - "mask(msb..lsb) 0x%llx 0x%llx", - sig, ksa.ksa_handler, - (UWord)ksa.sa_flags, - _VKI_NSIG_WORDS > 1 ? (ULong)ksa.sa_mask.sig[1] : 0, - (ULong)ksa.sa_mask.sig[0]); + VG_(dmsg)("setting ksig %d to: hdlr %p, flags 0x%lx, " + "mask(msb..lsb) 0x%llx 0x%llx\n", + sig, ksa.ksa_handler, + (UWord)ksa.sa_flags, + _VKI_NSIG_WORDS > 1 ? (ULong)ksa.sa_mask.sig[1] : 0, + (ULong)ksa.sa_mask.sig[0]); res = VG_(sigaction)( sig, &ksa, &ksa_old ); vg_assert(res == 0); @@ -935,13 +935,13 @@ SysRes VG_(do_sys_sigaltstack) ( ThreadId tid, vki_stack_t* ss, vki_stack_t* oss m_SP = VG_(get_SP)(tid); if (VG_(clo_trace_signals)) - VG_EMSG("sys_sigaltstack: tid %d, " - "ss %p{%p,sz=%llu,flags=0x%llx}, oss %p (current SP %p)", - tid, (void*)ss, - ss ? ss->ss_sp : 0, - (ULong)(ss ? ss->ss_size : 0), - (ULong)(ss ? ss->ss_flags : 0), - (void*)oss, (void*)m_SP); + VG_(emsg)("sys_sigaltstack: tid %d, " + "ss %p{%p,sz=%llu,flags=0x%llx}, oss %p (current SP %p)\n", + tid, (void*)ss, + ss ? ss->ss_sp : 0, + (ULong)(ss ? ss->ss_size : 0), + (ULong)(ss ? ss->ss_flags : 0), + (void*)oss, (void*)m_SP); if (oss != NULL) { oss->ss_sp = VG_(threads)[tid].altstack.ss_sp; @@ -980,10 +980,10 @@ SysRes VG_(do_sys_sigaction) ( Int signo, vki_sigaction_fromK_t* old_act ) { if (VG_(clo_trace_signals)) - VG_EMSG("sys_sigaction: sigNo %d, " - "new %#lx, old %#lx, new flags 0x%llx", - signo, (UWord)new_act, (UWord)old_act, - (ULong)(new_act ? new_act->sa_flags : 0)); + VG_(emsg)("sys_sigaction: sigNo %d, " + "new %#lx, old %#lx, new flags 0x%llx\n", + signo, (UWord)new_act, (UWord)old_act, + (ULong)(new_act ? new_act->sa_flags : 0)); /* Rule out various error conditions. The aim is to ensure that if when the call is passed to the kernel it will definitely @@ -1046,25 +1046,25 @@ SysRes VG_(do_sys_sigaction) ( Int signo, bad_signo: if (VG_(showing_core_errors)() && !VG_(clo_xml)) { - VG_UMSG("Warning: bad signal number %d in sigaction()", signo); + VG_(umsg)("Warning: bad signal number %d in sigaction()\n", signo); } return VG_(mk_SysRes_Error)( VKI_EINVAL ); bad_signo_reserved: if (VG_(showing_core_errors)() && !VG_(clo_xml)) { - VG_UMSG("Warning: ignored attempt to set %s handler in sigaction();", - signame(signo)); - VG_UMSG(" the %s signal is used internally by Valgrind", - signame(signo)); + VG_(umsg)("Warning: ignored attempt to set %s handler in sigaction();\n", + signame(signo)); + VG_(umsg)(" the %s signal is used internally by Valgrind\n", + signame(signo)); } return VG_(mk_SysRes_Error)( VKI_EINVAL ); bad_sigkill_or_sigstop: if (VG_(showing_core_errors)() && !VG_(clo_xml)) { - VG_UMSG("Warning: ignored attempt to set %s handler in sigaction();", - signame(signo)); - VG_UMSG(" the %s signal is uncatchable", - signame(signo)); + VG_(umsg)("Warning: ignored attempt to set %s handler in sigaction();\n", + signame(signo)); + VG_(umsg)(" the %s signal is uncatchable\n", + signame(signo)); } return VG_(mk_SysRes_Error)( VKI_EINVAL ); } @@ -1129,19 +1129,19 @@ void do_setmask ( ThreadId tid, vki_sigset_t* oldset ) { if (VG_(clo_trace_signals)) - VG_EMSG("do_setmask: tid = %d how = %d (%s), newset = %p (%s)", - tid, how, - how==VKI_SIG_BLOCK ? "SIG_BLOCK" : ( - how==VKI_SIG_UNBLOCK ? "SIG_UNBLOCK" : ( - how==VKI_SIG_SETMASK ? "SIG_SETMASK" : "???")), - newset, newset ? format_sigset(newset) : "NULL" ); + VG_(emsg)("do_setmask: tid = %d how = %d (%s), newset = %p (%s)\n", + tid, how, + how==VKI_SIG_BLOCK ? "SIG_BLOCK" : ( + how==VKI_SIG_UNBLOCK ? "SIG_UNBLOCK" : ( + how==VKI_SIG_SETMASK ? "SIG_SETMASK" : "???")), + newset, newset ? format_sigset(newset) : "NULL" ); /* Just do this thread. */ vg_assert(VG_(is_valid_tid)(tid)); if (oldset) { *oldset = VG_(threads)[tid].sig_mask; if (VG_(clo_trace_signals)) - VG_EMSG("\toldset=%p %s", oldset, format_sigset(oldset)); + VG_(emsg)("\toldset=%p %s\n", oldset, format_sigset(oldset)); } if (newset) { do_sigprocmask_bitops (how, &VG_(threads)[tid].sig_mask, newset ); @@ -1166,7 +1166,7 @@ SysRes VG_(do_sys_sigprocmask) ( ThreadId tid, return VG_(mk_SysRes_Success)( 0 ); default: - VG_DMSG("sigprocmask: unknown 'how' field %d", how); + VG_(dmsg)("sigprocmask: unknown 'how' field %d\n", how); return VG_(mk_SysRes_Error)( VKI_EINVAL ); } } @@ -1229,7 +1229,7 @@ void push_signal_frame ( ThreadId tid, const vki_siginfo_t *siginfo, tst = & VG_(threads)[tid]; if (VG_(clo_trace_signals)) { - VG_DMSG("push_signal_frame (thread %d): signal %d", tid, sigNo); + VG_(dmsg)("push_signal_frame (thread %d): signal %d\n", tid, sigNo); VG_(get_and_pp_StackTrace)(tid, 10); } @@ -1243,11 +1243,11 @@ void push_signal_frame ( ThreadId tid, const vki_siginfo_t *siginfo, esp_top_of_frame = (Addr)(tst->altstack.ss_sp) + tst->altstack.ss_size; if (VG_(clo_trace_signals)) - VG_DMSG("delivering signal %d (%s) to thread %d: " - "on ALT STACK (%p-%p; %ld bytes)", - sigNo, signame(sigNo), tid, tst->altstack.ss_sp, - (UChar *)tst->altstack.ss_sp + tst->altstack.ss_size, - (unsigned long)tst->altstack.ss_size ); + VG_(dmsg)("delivering signal %d (%s) to thread %d: " + "on ALT STACK (%p-%p; %ld bytes)\n", + sigNo, signame(sigNo), tid, tst->altstack.ss_sp, + (UChar *)tst->altstack.ss_sp + tst->altstack.ss_size, + (Word)tst->altstack.ss_size ); /* Signal delivery to tools */ VG_TRACK( pre_deliver_signal, tid, sigNo, /*alt_stack*/True ); @@ -1469,9 +1469,9 @@ static void default_action(const vki_siginfo_t *info, ThreadId tid) vg_assert(!core || (core && terminate)); if (VG_(clo_trace_signals)) - VG_DMSG("delivering %d (code %d) to default handler; action: %s%s", - sigNo, info->si_code, terminate ? "terminate" : "ignore", - core ? "+core" : ""); + VG_(dmsg)("delivering %d (code %d) to default handler; action: %s%s\n", + sigNo, info->si_code, terminate ? "terminate" : "ignore", + core ? "+core" : ""); if (!terminate) return; /* nothing to do */ @@ -1492,9 +1492,10 @@ static void default_action(const vki_siginfo_t *info, ThreadId tid) (could_core && is_signal_from_kernel(tid, sigNo, info->si_code)) ) && !VG_(clo_xml) ) { - VG_UMSG(""); - VG_UMSG("Process terminating with default action of signal %d (%s)%s", - sigNo, signame(sigNo), core ? ": dumping core" : ""); + VG_(umsg)("\n"); + VG_(umsg)( + "Process terminating with default action of signal %d (%s)%s\n", + sigNo, signame(sigNo), core ? ": dumping core" : ""); /* Be helpful - decode some more details about this fault */ if (is_signal_from_kernel(tid, sigNo, info->si_code)) { @@ -1504,8 +1505,10 @@ static void default_action(const vki_siginfo_t *info, ThreadId tid) switch(sigNo) { case VKI_SIGSEGV: switch(info->si_code) { - case VKI_SEGV_MAPERR: event = "Access not within mapped region"; break; - case VKI_SEGV_ACCERR: event = "Bad permissions for mapped region"; break; + case VKI_SEGV_MAPERR: event = "Access not within mapped region"; + break; + case VKI_SEGV_ACCERR: event = "Bad permissions for mapped region"; + break; case VKI_SEGV_MADE_UP_GPF: /* General Protection Fault: The CPU/kernel isn't telling us anything useful, but this @@ -1562,9 +1565,10 @@ static void default_action(const vki_siginfo_t *info, ThreadId tid) if (event != NULL) { if (haveaddr) - VG_UMSG(" %s at address %p", event, info->VKI_SIGINFO_si_addr); + VG_(umsg)(" %s at address %p\n", + event, info->VKI_SIGINFO_si_addr); else - VG_UMSG(" %s", event); + VG_(umsg)(" %s\n", event); } } /* Print a stack trace. Be cautious if the thread's SP is in an @@ -1581,14 +1585,15 @@ static void default_action(const vki_siginfo_t *info, ThreadId tid) if (sigNo == VKI_SIGSEGV && info && is_signal_from_kernel(tid, sigNo, info->si_code) && info->si_code == VKI_SEGV_MAPERR) { - VG_UMSG(" If you believe this happened as a result of a stack" ); - VG_UMSG(" overflow in your program's main thread (unlikely but"); - VG_UMSG(" possible), you can try to increase the size of the" ); - VG_UMSG(" main thread stack using the --main-stacksize= flag." ); + VG_(umsg)(" If you believe this happened as a result of a stack\n" ); + VG_(umsg)(" overflow in your program's main thread (unlikely but\n"); + VG_(umsg)(" possible), you can try to increase the size of the\n" ); + VG_(umsg)(" main thread stack using the --main-stacksize= flag.\n" ); // FIXME: assumes main ThreadId == 1 if (VG_(is_valid_tid)(1)) { - VG_UMSG(" The main thread stack size used in this run was %d.", - (Int)VG_(threads)[1].client_stack_szB); + VG_(umsg)( + " The main thread stack size used in this run was %d.\n", + (Int)VG_(threads)[1].client_stack_szB); } } } @@ -1634,8 +1639,8 @@ static void deliver_signal ( ThreadId tid, const vki_siginfo_t *info, ThreadState *tst = VG_(get_ThreadState)(tid); if (VG_(clo_trace_signals)) - VG_DMSG("delivering signal %d (%s):%d to thread %d", - sigNo, signame(sigNo), info->si_code, tid ); + VG_(dmsg)("delivering signal %d (%s):%d to thread %d\n", + sigNo, signame(sigNo), info->si_code, tid ); if (sigNo == VG_SIGVGKILL) { /* If this is a SIGVGKILL, we're expecting it to interrupt any @@ -1849,8 +1854,8 @@ void queue_signal(ThreadId tid, const vki_siginfo_t *si) sq = tst->sig_queue; if (VG_(clo_trace_signals)) - VG_DMSG("Queueing signal %d (idx %d) to thread %d", - si->si_signo, sq->next, tid); + VG_(dmsg)("Queueing signal %d (idx %d) to thread %d\n", + si->si_signo, sq->next, tid); /* Add signal to the queue. If the queue gets overrun, then old queued signals may get lost. @@ -1859,8 +1864,8 @@ void queue_signal(ThreadId tid, const vki_siginfo_t *si) least a non-siginfo signal gets deliviered. */ if (sq->sigs[sq->next].si_signo != 0) - VG_UMSG("Signal %d being dropped from thread %d's queue", - sq->sigs[sq->next].si_signo, tid); + VG_(umsg)("Signal %d being dropped from thread %d's queue\n", + sq->sigs[sq->next].si_signo, tid); sq->sigs[sq->next] = *si; sq->next = (sq->next+1) % N_QUEUED_SIGNALS; @@ -1891,12 +1896,14 @@ static vki_siginfo_t *next_queued(ThreadId tid, const vki_sigset_t *set) do { if (0) VG_(printf)("idx=%d si_signo=%d inset=%d\n", idx, - sq->sigs[idx].si_signo, VG_(sigismember)(set, sq->sigs[idx].si_signo)); + sq->sigs[idx].si_signo, + VG_(sigismember)(set, sq->sigs[idx].si_signo)); - if (sq->sigs[idx].si_signo != 0 && VG_(sigismember)(set, sq->sigs[idx].si_signo)) { + if (sq->sigs[idx].si_signo != 0 + && VG_(sigismember)(set, sq->sigs[idx].si_signo)) { if (VG_(clo_trace_signals)) - VG_DMSG("Returning queued signal %d (idx %d) for thread %d", - sq->sigs[idx].si_signo, idx, tid); + VG_(dmsg)("Returning queued signal %d (idx %d) for thread %d\n", + sq->sigs[idx].si_signo, idx, tid); ret = &sq->sigs[idx]; goto out; } @@ -1947,8 +1954,8 @@ void async_signalhandler ( Int sigNo, info->si_code = sanitize_si_code(info->si_code); if (VG_(clo_trace_signals)) - VG_DMSG("async signal handler: signal=%d, tid=%d, si_code=%d", - sigNo, tid, info->si_code); + VG_(dmsg)("async signal handler: signal=%d, tid=%d, si_code=%d\n", + sigNo, tid, info->si_code); /* Update thread state properly. The signal can only have been delivered whilst we were in @@ -2105,7 +2112,8 @@ void sync_signalhandler_from_user ( ThreadId tid, get here unless the client wants this signal right now. This means we can simply use the async_signalhandler. */ if (VG_(clo_trace_signals)) - VG_DMSG("Delivering user-sent sync signal %d as async signal", sigNo); + VG_(dmsg)("Delivering user-sent sync signal %d as async signal\n", + sigNo); async_signalhandler(sigNo, info, uc); VG_(core_panic)("async_signalhandler returned!?\n"); @@ -2116,7 +2124,7 @@ void sync_signalhandler_from_user ( ThreadId tid, unblocked, so we can't rely on the kernel to route them properly, so we need to queue them manually. */ if (VG_(clo_trace_signals)) - VG_DMSG("Routing user-sent sync signal %d via queue", sigNo); + VG_(dmsg)("Routing user-sent sync signal %d via queue\n", sigNo); # if defined(VGO_linux) /* On Linux, first we have to do a sanity check of the siginfo. */ @@ -2132,8 +2140,8 @@ void sync_signalhandler_from_user ( ThreadId tid, Since we depend on siginfo to work out why we were sent a signal and what we should do about it, we really can't continue unless we get it. */ - VG_UMSG("Signal %d (%s) appears to have lost its siginfo; " - "I can't go on.", sigNo, signame(sigNo)); + VG_(umsg)("Signal %d (%s) appears to have lost its siginfo; " + "I can't go on.\n", sigNo, signame(sigNo)); VG_(printf)( " This may be because one of your programs has consumed your ration of\n" " siginfo structures. For more information, see:\n" @@ -2184,13 +2192,13 @@ static Bool extend_stack_if_appropriate(ThreadId tid, vki_siginfo_t* info) if (VG_(clo_trace_signals)) { if (seg == NULL) - VG_DMSG("SIGSEGV: si_code=%d faultaddr=%#lx tid=%d ESP=%#lx " - "seg=NULL", - info->si_code, fault, tid, esp); + VG_(dmsg)("SIGSEGV: si_code=%d faultaddr=%#lx tid=%d ESP=%#lx " + "seg=NULL\n", + info->si_code, fault, tid, esp); else - VG_DMSG("SIGSEGV: si_code=%d faultaddr=%#lx tid=%d ESP=%#lx " - "seg=%#lx-%#lx", - info->si_code, fault, tid, esp, seg->start, seg->end); + VG_(dmsg)("SIGSEGV: si_code=%d faultaddr=%#lx tid=%d ESP=%#lx " + "seg=%#lx-%#lx\n", + info->si_code, fault, tid, esp, seg->start, seg->end); } if (info->si_code == VKI_SEGV_MAPERR @@ -2209,12 +2217,12 @@ static Bool extend_stack_if_appropriate(ThreadId tid, vki_siginfo_t* info) Addr base = VG_PGROUNDDN(esp - VG_STACK_REDZONE_SZB); if (VG_(extend_stack)(base, VG_(threads)[tid].client_stack_szB)) { if (VG_(clo_trace_signals)) - VG_DMSG(" -> extended stack base to %#lx", - VG_PGROUNDDN(fault)); + VG_(dmsg)(" -> extended stack base to %#lx\n", + VG_PGROUNDDN(fault)); return True; } else { - VG_UMSG("Stack overflow in thread %d: can't grow stack to %#lx", - tid, fault); + VG_(umsg)("Stack overflow in thread %d: can't grow stack to %#lx\n", + tid, fault); return False; } } else { @@ -2265,13 +2273,13 @@ void sync_signalhandler_from_kernel ( ThreadId tid, client code, and therefore it was actually generated by Valgrind internally. */ - VG_DMSG("VALGRIND INTERNAL ERROR: Valgrind received " - "a signal %d (%s) - exiting", - sigNo, signame(sigNo)); + VG_(dmsg)("VALGRIND INTERNAL ERROR: Valgrind received " + "a signal %d (%s) - exiting\n", + sigNo, signame(sigNo)); - VG_DMSG("si_code=%x; Faulting address: %p; sp: %#lx", - info->si_code, info->VKI_SIGINFO_si_addr, - VG_UCONTEXT_STACK_PTR(uc)); + VG_(dmsg)("si_code=%x; Faulting address: %p; sp: %#lx\n", + info->si_code, info->VKI_SIGINFO_si_addr, + VG_UCONTEXT_STACK_PTR(uc)); if (0) VG_(kill_self)(sigNo); /* generate a core dump */ @@ -2314,11 +2322,11 @@ void sync_signalhandler ( Int sigNo, from_user = !is_signal_from_kernel(tid, sigNo, info->si_code); if (VG_(clo_trace_signals)) { - VG_DMSG("sync signal handler: " - "signal=%d, si_code=%d, EIP=%#lx, eip=%#lx, from %s", - sigNo, info->si_code, VG_(get_IP)(tid), - VG_UCONTEXT_INSTR_PTR(uc), - ( from_user ? "user" : "kernel" )); + VG_(dmsg)("sync signal handler: " + "signal=%d, si_code=%d, EIP=%#lx, eip=%#lx, from %s\n", + sigNo, info->si_code, VG_(get_IP)(tid), + VG_UCONTEXT_INSTR_PTR(uc), + ( from_user ? "user" : "kernel" )); } vg_assert(sigNo >= 1 && sigNo <= VG_(max_signal)); @@ -2358,7 +2366,7 @@ static void sigvgkill_handler(int signo, vki_siginfo_t *si, ThreadStatus at_signal = VG_(threads)[tid].status; if (VG_(clo_trace_signals)) - VG_DMSG("sigvgkill for lwp %d tid %d", VG_(gettid)(), tid); + VG_(dmsg)("sigvgkill for lwp %d tid %d\n", VG_(gettid)(), tid); VG_(acquire_BigLock)(tid, "sigvgkill_handler"); @@ -2448,19 +2456,19 @@ void VG_(poll_signals)(ThreadId tid) /* If there was nothing queued, ask the kernel for a pending signal */ if (sip == NULL && VG_(sigtimedwait_zero)(&pollset, &si) > 0) { if (VG_(clo_trace_signals)) - VG_DMSG("poll_signals: got signal %d for thread %d", - si.si_signo, tid); + VG_(dmsg)("poll_signals: got signal %d for thread %d\n", + si.si_signo, tid); sip = &si; } if (sip != NULL) { /* OK, something to do; deliver it */ if (VG_(clo_trace_signals)) - VG_DMSG("Polling found signal %d for tid %d", sip->si_signo, tid); + VG_(dmsg)("Polling found signal %d for tid %d\n", sip->si_signo, tid); if (!is_sig_ign(sip->si_signo)) deliver_signal(tid, sip, NULL); else if (VG_(clo_trace_signals)) - VG_DMSG(" signal %d ignored", sip->si_signo); + VG_(dmsg)(" signal %d ignored\n", sip->si_signo); sip->si_signo = 0; /* remove from signal queue, if that's where it came from */ @@ -2560,7 +2568,7 @@ void VG_(sigstartup_actions) ( void ) } if (VG_(clo_trace_signals)) - VG_DMSG("Max kernel-supported signal is %d", VG_(max_signal)); + VG_(dmsg)("Max kernel-supported signal is %d\n", VG_(max_signal)); /* Our private internal signals are treated as ignored */ scss.scss_per_sig[VG_SIGVGKILL].scss_handler = VKI_SIG_IGN; diff --git a/coregrind/m_stacks.c b/coregrind/m_stacks.c index db16239e41..c9e9abfc86 100644 --- a/coregrind/m_stacks.c +++ b/coregrind/m_stacks.c @@ -305,14 +305,14 @@ void VG_(unknown_SP_update)( Addr old_SP, Addr new_SP, UInt ecu ) moans--; VG_(message)(Vg_UserMsg, "Warning: client switching stacks? " - "SP change: 0x%lx --> 0x%lx", old_SP, new_SP); + "SP change: 0x%lx --> 0x%lx\n", old_SP, new_SP); VG_(message)(Vg_UserMsg, - " to suppress, use: --max-stackframe=%ld or greater", + " to suppress, use: --max-stackframe=%ld or greater\n", (delta < 0 ? -delta : delta)); if (moans == 0) VG_(message)(Vg_UserMsg, " further instances of this message " - "will not be shown."); + "will not be shown.\n"); } } else if (delta < 0) { VG_TRACK( new_mem_stack_w_ECU, new_SP, -delta, ecu ); diff --git a/coregrind/m_stacktrace.c b/coregrind/m_stacktrace.c index 6e3c8d07e4..130107afa4 100644 --- a/coregrind/m_stacktrace.c +++ b/coregrind/m_stacktrace.c @@ -523,9 +523,9 @@ static void printIpDesc(UInt n, Addr ip) VG_(describe_IP)(ip, buf, BUF_LEN); if (VG_(clo_xml)) { - VG_(message)(Vg_UserMsg, " %s", buf); + VG_(printf_xml)(" %s\n", buf); } else { - VG_(message)(Vg_UserMsg, " %s %s", ( n == 0 ? "at" : "by" ), buf); + VG_(message)(Vg_UserMsg, " %s %s\n", ( n == 0 ? "at" : "by" ), buf); } } @@ -535,12 +535,12 @@ void VG_(pp_StackTrace) ( StackTrace ips, UInt n_ips ) vg_assert( n_ips > 0 ); if (VG_(clo_xml)) - VG_(message)(Vg_UserMsg, " "); + VG_(printf_xml)(" \n"); VG_(apply_StackTrace)( printIpDesc, ips, n_ips ); if (VG_(clo_xml)) - VG_(message)(Vg_UserMsg, " "); + VG_(printf_xml)(" \n"); } /* Get and immediately print a StackTrace. */ diff --git a/coregrind/m_syswrap/syswrap-aix5.c b/coregrind/m_syswrap/syswrap-aix5.c index 90e966e0b2..6108ccee5b 100644 --- a/coregrind/m_syswrap/syswrap-aix5.c +++ b/coregrind/m_syswrap/syswrap-aix5.c @@ -219,9 +219,9 @@ void ML_(aix5_set_threadstate_for_emergency_exit)(ThreadId tid, HChar* why) tst->os_state.exitcode = 1; if (!VG_(clo_xml)) { VG_(message)(Vg_UserMsg, - "WARNING: AIX: %s", why); + "WARNING: AIX: %s\n", why); VG_(message)(Vg_UserMsg, - "WARNING: (too difficult to continue past this point)."); + "WARNING: (too difficult to continue past this point).\n"); VG_(get_and_pp_StackTrace)(tid, 10); } } @@ -1044,12 +1044,12 @@ PRE(sys_execve) too much of a mess to continue, so we have to abort. */ hosed: vg_assert(FAILURE); - VG_(message)(Vg_UserMsg, "execve(%#lx(%s), %#lx, %#lx) failed, errno %ld", + VG_(message)(Vg_UserMsg, "execve(%#lx(%s), %#lx, %#lx) failed, errno %ld\n", ARG1, (Char*)ARG1, ARG2, ARG3, ERR); VG_(message)(Vg_UserMsg, "EXEC FAILED: I can't recover from " - "execve() failing, so I'm dying."); + "execve() failing, so I'm dying.\n"); VG_(message)(Vg_UserMsg, "Add more stringent tests in PRE(sys_execve), " - "or work out how to recover."); + "or work out how to recover.\n"); VG_(exit)(101); } @@ -1435,14 +1435,14 @@ PRE(sys_kioctl) moans--; VG_(message)(Vg_UserMsg, "Warning: noted but unhandled ioctl 0x%lx" - " with no size/direction hints", + " with no size/direction hints\n", ARG2); VG_(message)(Vg_UserMsg, " This could cause spurious value errors" - " to appear."); + " to appear.\n"); VG_(message)(Vg_UserMsg, " See README_MISSING_SYSCALL_OR_IOCTL for " - "guidance on writing a proper wrapper." ); + "guidance on writing a proper wrapper.\n" ); } } else { if ((dir & _VKI_IOC_WRITE) && size > 0) diff --git a/coregrind/m_syswrap/syswrap-amd64-linux.c b/coregrind/m_syswrap/syswrap-amd64-linux.c index 0f1a6ae3b4..605d844d56 100644 --- a/coregrind/m_syswrap/syswrap-amd64-linux.c +++ b/coregrind/m_syswrap/syswrap-amd64-linux.c @@ -267,7 +267,8 @@ static SysRes do_clone ( ThreadId ptid, VG_(printf)("tid %d: guessed client stack range %#lx-%#lx\n", ctid, seg->start, VG_PGROUNDUP(rsp)); } else { - VG_(message)(Vg_UserMsg, "!? New thread %d starts with RSP(%#lx) unmapped\n", + VG_(message)(Vg_UserMsg, + "!? New thread %d starts with RSP(%#lx) unmapped\n", ctid, rsp); ctst->client_stack_szB = 0; } @@ -440,11 +441,16 @@ PRE(sys_clone) default: /* should we just ENOSYS? */ - VG_(message)(Vg_UserMsg, "Unsupported clone() flags: 0x%lx", ARG1); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "The only supported clone() uses are:"); - VG_(message)(Vg_UserMsg, " - via a threads library (LinuxThreads or NPTL)"); - VG_(message)(Vg_UserMsg, " - via the implementation of fork or vfork"); + VG_(message)(Vg_UserMsg, + "Unsupported clone() flags: 0x%lx\n", ARG1); + VG_(message)(Vg_UserMsg, + "\n"); + VG_(message)(Vg_UserMsg, + "The only supported clone() uses are:\n"); + VG_(message)(Vg_UserMsg, + " - via a threads library (LinuxThreads or NPTL)\n"); + VG_(message)(Vg_UserMsg, + " - via the implementation of fork or vfork\n"); VG_(unimplemented) ("Valgrind does not support general clone()."); } diff --git a/coregrind/m_syswrap/syswrap-generic.c b/coregrind/m_syswrap/syswrap-generic.c index a1fb344349..6332859a42 100644 --- a/coregrind/m_syswrap/syswrap-generic.c +++ b/coregrind/m_syswrap/syswrap-generic.c @@ -84,7 +84,7 @@ Bool ML_(valid_client_addr)(Addr start, SizeT size, ThreadId tid, if (!ret && syscallname != NULL) { VG_(message)(Vg_UserMsg, "Warning: client syscall %s tried " - "to modify addresses %#lx-%#lx", + "to modify addresses %#lx-%#lx\n", syscallname, start, start+size-1); if (VG_(clo_verbosity) > 1) { VG_(get_and_pp_StackTrace)(tid, VG_(clo_backtrace_size)); @@ -671,30 +671,30 @@ getsockdetails(Int fd) struct vki_sockaddr_in paddr; UInt plen = sizeof(struct vki_sockaddr_in); - if(VG_(getpeername)(fd, (struct vki_sockaddr *)&paddr, &plen) != -1) { - VG_(message)(Vg_UserMsg, "Open AF_INET socket %d: %s <-> %s", fd, + if (VG_(getpeername)(fd, (struct vki_sockaddr *)&paddr, &plen) != -1) { + VG_(message)(Vg_UserMsg, "Open AF_INET socket %d: %s <-> %s\n", fd, inet2name(&(laddr.in), llen, lname), inet2name(&paddr, plen, pname)); } else { - VG_(message)(Vg_UserMsg, "Open AF_INET socket %d: %s <-> unbound", + VG_(message)(Vg_UserMsg, "Open AF_INET socket %d: %s <-> unbound\n", fd, inet2name(&(laddr.in), llen, lname)); } return; } case VKI_AF_UNIX: { static char lname[256]; - VG_(message)(Vg_UserMsg, "Open AF_UNIX socket %d: %s", fd, + VG_(message)(Vg_UserMsg, "Open AF_UNIX socket %d: %s\n", fd, unix2name(&(laddr.un), llen, lname)); return; } default: - VG_(message)(Vg_UserMsg, "Open pf-%d socket %d:", + VG_(message)(Vg_UserMsg, "Open pf-%d socket %d:\n", laddr.a.sa_family, fd); return; } } - VG_(message)(Vg_UserMsg, "Open socket %d:", fd); + VG_(message)(Vg_UserMsg, "Open socket %d:\n", fd); } @@ -703,18 +703,19 @@ void VG_(show_open_fds) (void) { OpenFd *i = allocated_fds; - VG_(message)(Vg_UserMsg, "FILE DESCRIPTORS: %d open at exit.", fd_count); + VG_(message)(Vg_UserMsg, "FILE DESCRIPTORS: %d open at exit.\n", fd_count); - while(i) { - if(i->pathname) { - VG_(message)(Vg_UserMsg, "Open file descriptor %d: %s", i->fd, + while (i) { + if (i->pathname) { + VG_(message)(Vg_UserMsg, "Open file descriptor %d: %s\n", i->fd, i->pathname); } else { Int val; UInt len = sizeof(val); - if (VG_(getsockopt)(i->fd, VKI_SOL_SOCKET, VKI_SO_TYPE, &val, &len) == -1) { - VG_(message)(Vg_UserMsg, "Open file descriptor %d:", i->fd); + if (VG_(getsockopt)(i->fd, VKI_SOL_SOCKET, VKI_SO_TYPE, &val, &len) + == -1) { + VG_(message)(Vg_UserMsg, "Open file descriptor %d:\n", i->fd); } else { getsockdetails(i->fd); } @@ -722,16 +723,16 @@ void VG_(show_open_fds) (void) if(i->where) { VG_(pp_ExeContext)(i->where); - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); } else { - VG_(message)(Vg_UserMsg, " "); - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, " \n"); + VG_(message)(Vg_UserMsg, "\n"); } i = i->next; } - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); } /* If /proc/self/fd doesn't exist (e.g. you've got a Linux kernel that doesn't @@ -790,7 +791,8 @@ void VG_(init_preopened_fds)(void) ML_(record_fd_open_named)(-1, fno); } else { VG_(message)(Vg_DebugMsg, - "Warning: invalid file name in /proc/self/fd: %s", d.d_name); + "Warning: invalid file name in /proc/self/fd: %s\n", + d.d_name); } } @@ -1154,8 +1156,8 @@ Bool ML_(fd_allowed)(Int fd, const Char *syscallname, ThreadId tid, Bool isNewFd if (fd < 0 || fd >= VG_(fd_hard_limit)) allowed = False; - /* hijacking the logging fd is never allowed */ - if (fd == VG_(clo_log_fd)) + /* hijacking the output fds is never allowed */ + if (fd == VG_(log_output_sink).fd || fd == VG_(xml_output_sink).fd) allowed = False; /* if creating a new fd (rather than using an existing one), the @@ -1184,12 +1186,15 @@ Bool ML_(fd_allowed)(Int fd, const Char *syscallname, ThreadId tid, Bool isNewFd /* croak? */ if ((!allowed) && VG_(showing_core_errors)() ) { VG_(message)(Vg_UserMsg, - "Warning: invalid file descriptor %d in syscall %s()", + "Warning: invalid file descriptor %d in syscall %s()\n", fd, syscallname); - if (fd == VG_(clo_log_fd)) { + if (fd == VG_(log_output_sink).fd && VG_(log_output_sink).fd >= 0) VG_(message)(Vg_UserMsg, - " Use --log-fd= to select an alternative log fd."); - } + " Use --log-fd= to select an alternative log fd.\n"); + if (fd == VG_(xml_output_sink).fd && VG_(xml_output_sink).fd >= 0) + VG_(message)(Vg_UserMsg, + " Use --xml-fd= to select an alternative XML " + "output fd.\n"); // DDD: consider always printing this stack trace, it's useful. // Also consider also making this a proper core error, ie. // suppressible and all that. @@ -2700,12 +2705,12 @@ PRE(sys_execve) too much of a mess to continue, so we have to abort. */ hosed: vg_assert(FAILURE); - VG_(message)(Vg_UserMsg, "execve(%#lx(%s), %#lx, %#lx) failed, errno %ld", + VG_(message)(Vg_UserMsg, "execve(%#lx(%s), %#lx, %#lx) failed, errno %ld\n", ARG1, (char*)ARG1, ARG2, ARG3, ERR); VG_(message)(Vg_UserMsg, "EXEC FAILED: I can't recover from " - "execve() failing, so I'm dying."); + "execve() failing, so I'm dying.\n"); VG_(message)(Vg_UserMsg, "Add more stringent tests in PRE(sys_execve), " - "or work out how to recover."); + "or work out how to recover.\n"); VG_(exit)(101); } @@ -2921,11 +2926,15 @@ PRE(sys_fork) VG_(sigprocmask)(VKI_SIG_SETMASK, &fork_saved_mask, NULL); /* If --child-silent-after-fork=yes was specified, set the - logging file descriptor to an 'impossible' value. This is + output file descriptors to 'impossible' values. This is noticed by send_bytes_to_logging_sink in m_libcprint.c, which - duly stops writing any further logging output. */ - if (!VG_(logging_to_socket) && VG_(clo_child_silent_after_fork)) - VG_(clo_log_fd) = -1; + duly stops writing any further output. */ + if (VG_(clo_child_silent_after_fork)) { + if (!VG_(log_output_sink).is_socket) + VG_(log_output_sink).fd = -1; + if (!VG_(xml_output_sink).is_socket) + VG_(xml_output_sink).fd = -1; + } } else { VG_(do_atfork_parent)(tid); @@ -3231,11 +3240,11 @@ void ML_(PRE_unknown_ioctl)(ThreadId tid, UWord request, UWord arg) static Int moans = 3; if (moans > 0 && !VG_(clo_xml)) { moans--; - VG_UMSG("Warning: noted but unhandled ioctl 0x%lx" - " with no size/direction hints", request); - VG_UMSG(" This could cause spurious value errors to appear."); - VG_UMSG(" See README_MISSING_SYSCALL_OR_IOCTL for " - "guidance on writing a proper wrapper." ); + VG_(umsg)("Warning: noted but unhandled ioctl 0x%lx" + " with no size/direction hints\n", request); + VG_(umsg)(" This could cause spurious value errors to appear.\n"); + VG_(umsg)(" See README_MISSING_SYSCALL_OR_IOCTL for " + "guidance on writing a proper wrapper.\n" ); } } else { //VG_(message)(Vg_UserMsg, "UNKNOWN ioctl %#lx\n", request); @@ -3306,8 +3315,9 @@ Bool ML_(do_sigkill)(Int pid, Int tgid) /* Check to see that the target isn't already exiting. */ if (!VG_(is_exiting)(tid)) { if (VG_(clo_trace_signals)) - VG_(message)(Vg_DebugMsg, "Thread %d being killed with SIGKILL", - tst->tid); + VG_(message)(Vg_DebugMsg, + "Thread %d being killed with SIGKILL\n", + tst->tid); tst->exitreason = VgSrc_FatalSig; tst->os_state.fatalsig = VKI_SIGKILL; @@ -3340,7 +3350,7 @@ PRE(sys_kill) SET_STATUS_from_SysRes( VG_(do_syscall3)(SYSNO, ARG1, ARG2, ARG3) ); if (VG_(clo_trace_signals)) - VG_(message)(Vg_DebugMsg, "kill: sent signal %ld to pid %ld", + VG_(message)(Vg_DebugMsg, "kill: sent signal %ld to pid %ld\n", ARG2, ARG1); /* This kill might have given us a pending signal. Ask for a check once diff --git a/coregrind/m_syswrap/syswrap-linux.c b/coregrind/m_syswrap/syswrap-linux.c index 32a68f7bc5..df61d5a5b3 100644 --- a/coregrind/m_syswrap/syswrap-linux.c +++ b/coregrind/m_syswrap/syswrap-linux.c @@ -341,11 +341,15 @@ SysRes ML_(do_fork_clone) ( ThreadId tid, UInt flags, VG_(sigprocmask)(VKI_SIG_SETMASK, &fork_saved_mask, NULL); /* If --child-silent-after-fork=yes was specified, set the - logging file descriptor to an 'impossible' value. This is + output file descriptors to 'impossible' values. This is noticed by send_bytes_to_logging_sink in m_libcprint.c, which - duly stops writing any further logging output. */ - if (!VG_(logging_to_socket) && VG_(clo_child_silent_after_fork)) - VG_(clo_log_fd) = -1; + duly stops writing any further output. */ + if (VG_(clo_child_silent_after_fork)) { + if (!VG_(log_output_sink).is_socket) + VG_(log_output_sink).fd = -1; + if (!VG_(xml_output_sink).is_socket) + VG_(xml_output_sink).fd = -1; + } } else if (!sr_isError(res) && sr_Res(res) > 0) { @@ -1188,7 +1192,7 @@ PRE(sys_tkill) *flags |= SfPollAfter; if (VG_(clo_trace_signals)) - VG_(message)(Vg_DebugMsg, "tkill: sending signal %ld to pid %ld", + VG_(message)(Vg_DebugMsg, "tkill: sending signal %ld to pid %ld\n", ARG2, ARG1); /* If we're sending SIGKILL, check to see if the target is one of @@ -1212,7 +1216,7 @@ PRE(sys_tkill) POST(sys_tkill) { if (VG_(clo_trace_signals)) - VG_(message)(Vg_DebugMsg, "tkill: sent signal %ld to pid %ld", + VG_(message)(Vg_DebugMsg, "tkill: sent signal %ld to pid %ld\n", ARG2, ARG1); } @@ -1229,7 +1233,8 @@ PRE(sys_tgkill) *flags |= SfPollAfter; if (VG_(clo_trace_signals)) - VG_(message)(Vg_DebugMsg, "tgkill: sending signal %ld to pid %ld/%ld", + VG_(message)(Vg_DebugMsg, + "tgkill: sending signal %ld to pid %ld/%ld\n", ARG3, ARG1, ARG2); /* If we're sending SIGKILL, check to see if the target is one of @@ -1253,7 +1258,8 @@ PRE(sys_tgkill) POST(sys_tgkill) { if (VG_(clo_trace_signals)) - VG_(message)(Vg_DebugMsg, "tgkill: sent signal %ld to pid %ld/%ld", + VG_(message)(Vg_DebugMsg, + "tgkill: sent signal %ld to pid %ld/%ld\n", ARG3, ARG1, ARG2); } @@ -5297,7 +5303,8 @@ ML_(linux_POST_sys_getsockopt) ( ThreadId tid, else if (a->sa_family == VKI_AF_INET6) sl = sizeof(struct vki_sockaddr_in6); else { - VG_(message)(Vg_UserMsg, "Warning: getsockopt: unhandled address type %d", a->sa_family); + VG_(message)(Vg_UserMsg, "Warning: getsockopt: unhandled " + "address type %d\n", a->sa_family); } a = (struct vki_sockaddr*)((char*)a + sl); } diff --git a/coregrind/m_syswrap/syswrap-main.c b/coregrind/m_syswrap/syswrap-main.c index 5b8fc70feb..4cc9011991 100644 --- a/coregrind/m_syswrap/syswrap-main.c +++ b/coregrind/m_syswrap/syswrap-main.c @@ -1096,15 +1096,15 @@ void bad_before ( ThreadId tid, /*OUT*/SyscallStatus* status, /*OUT*/UWord* flags ) { - VG_DMSG("WARNING: unhandled syscall: %s", + VG_(dmsg)("WARNING: unhandled syscall: %s\n", VG_SYSNUM_STRING_EXTRA(args->sysno)); if (VG_(clo_verbosity) > 1) { VG_(get_and_pp_StackTrace)(tid, VG_(clo_backtrace_size)); } - VG_DMSG("You may be able to write your own handler."); - VG_DMSG("Read the file README_MISSING_SYSCALL_OR_IOCTL."); - VG_DMSG("Nevertheless we consider this a bug. Please report"); - VG_DMSG("it at http://valgrind.org/support/bug_reports.html."); + VG_(dmsg)("You may be able to write your own handler.\n"); + VG_(dmsg)("Read the file README_MISSING_SYSCALL_OR_IOCTL.\n"); + VG_(dmsg)("Nevertheless we consider this a bug. Please report\n"); + VG_(dmsg)("it at http://valgrind.org/support/bug_reports.html.\n"); SET_STATUS_Failure(VKI_ENOSYS); } diff --git a/coregrind/m_syswrap/syswrap-ppc32-linux.c b/coregrind/m_syswrap/syswrap-ppc32-linux.c index a9e709547a..d56eda52ea 100644 --- a/coregrind/m_syswrap/syswrap-ppc32-linux.c +++ b/coregrind/m_syswrap/syswrap-ppc32-linux.c @@ -313,7 +313,8 @@ static SysRes do_clone ( ThreadId ptid, VG_(printf)("\ntid %d: guessed client stack range %#lx-%#lx\n", ctid, seg->start, VG_PGROUNDUP(sp)); } else { - VG_(message)(Vg_UserMsg, "!? New thread %d starts with R1(%#lx) unmapped\n", + VG_(message)(Vg_UserMsg, + "!? New thread %d starts with R1(%#lx) unmapped\n", ctid, sp); ctst->client_stack_szB = 0; } @@ -553,7 +554,7 @@ PRE(sys_socketcall) } default: - VG_(message)(Vg_DebugMsg,"Warning: unhandled socketcall 0x%lx",ARG1); + VG_(message)(Vg_DebugMsg,"Warning: unhandled socketcall 0x%lx\n",ARG1); SET_STATUS_Failure( VKI_EINVAL ); break; } @@ -656,7 +657,7 @@ POST(sys_socketcall) break; default: - VG_(message)(Vg_DebugMsg,"FATAL: unhandled socketcall 0x%lx",ARG1); + VG_(message)(Vg_DebugMsg,"FATAL: unhandled socketcall 0x%lx\n",ARG1); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ } @@ -843,7 +844,7 @@ PRE(sys_ipc) ML_(generic_PRE_sys_shmctl)( tid, ARG2, ARG3, ARG5 ); break; default: - VG_(message)(Vg_DebugMsg, "FATAL: unhandled syscall(ipc) %ld", ARG1 ); + VG_(message)(Vg_DebugMsg, "FATAL: unhandled syscall(ipc) %ld\n", ARG1 ); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ } @@ -908,7 +909,7 @@ POST(sys_ipc) break; default: VG_(message)(Vg_DebugMsg, - "FATAL: unhandled syscall(ipc) %ld", + "FATAL: unhandled syscall(ipc) %ld\n", ARG1 ); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ @@ -1015,11 +1016,11 @@ PRE(sys_clone) default: /* should we just ENOSYS? */ - VG_(message)(Vg_UserMsg, "Unsupported clone() flags: 0x%lx", ARG1); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "The only supported clone() uses are:"); - VG_(message)(Vg_UserMsg, " - via a threads library (LinuxThreads or NPTL)"); - VG_(message)(Vg_UserMsg, " - via the implementation of fork or vfork"); + VG_(message)(Vg_UserMsg, "Unsupported clone() flags: 0x%lx\n", ARG1); + VG_(message)(Vg_UserMsg, "\n"); + VG_(message)(Vg_UserMsg, "The only supported clone() uses are:\n"); + VG_(message)(Vg_UserMsg, " - via a threads library (LinuxThreads or NPTL)\n"); + VG_(message)(Vg_UserMsg, " - via the implementation of fork or vfork\n"); VG_(unimplemented) ("Valgrind does not support general clone()."); } diff --git a/coregrind/m_syswrap/syswrap-ppc64-linux.c b/coregrind/m_syswrap/syswrap-ppc64-linux.c index 1ce4f64bbe..a19b3f4ee4 100644 --- a/coregrind/m_syswrap/syswrap-ppc64-linux.c +++ b/coregrind/m_syswrap/syswrap-ppc64-linux.c @@ -341,7 +341,8 @@ static SysRes do_clone ( ThreadId ptid, VG_(printf)("\ntid %d: guessed client stack range %#lx-%#lx\n", ctid, seg->start, VG_PGROUNDUP(sp)); } else { - VG_(message)(Vg_UserMsg, "!? New thread %d starts with R1(%#lx) unmapped\n", + VG_(message)(Vg_UserMsg, + "!? New thread %d starts with R1(%#lx) unmapped\n", ctid, sp); ctst->client_stack_szB = 0; } @@ -580,7 +581,7 @@ PRE(sys_socketcall) } default: - VG_(message)(Vg_DebugMsg,"Warning: unhandled socketcall 0x%lx",ARG1); + VG_(message)(Vg_DebugMsg,"Warning: unhandled socketcall 0x%lx\n",ARG1); SET_STATUS_Failure( VKI_EINVAL ); break; } @@ -683,7 +684,7 @@ POST(sys_socketcall) break; default: - VG_(message)(Vg_DebugMsg,"FATAL: unhandled socketcall 0x%lx",ARG1); + VG_(message)(Vg_DebugMsg,"FATAL: unhandled socketcall 0x%lx\n",ARG1); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ } @@ -856,7 +857,7 @@ PRE(sys_ipc) ML_(generic_PRE_sys_shmctl)( tid, ARG2, ARG3, ARG5 ); break; default: - VG_(message)(Vg_DebugMsg, "FATAL: unhandled syscall(ipc) %ld", ARG1 ); + VG_(message)(Vg_DebugMsg, "FATAL: unhandled syscall(ipc) %ld\n", ARG1 ); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ } @@ -921,7 +922,7 @@ POST(sys_ipc) break; default: VG_(message)(Vg_DebugMsg, - "FATAL: unhandled syscall(ipc) %ld", + "FATAL: unhandled syscall(ipc) %ld\n", ARG1 ); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ @@ -992,11 +993,11 @@ PRE(sys_clone) default: /* should we just ENOSYS? */ - VG_(message)(Vg_UserMsg, "Unsupported clone() flags: 0x%lx", ARG1); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "The only supported clone() uses are:"); - VG_(message)(Vg_UserMsg, " - via a threads library (LinuxThreads or NPTL)"); - VG_(message)(Vg_UserMsg, " - via the implementation of fork or vfork"); + VG_(message)(Vg_UserMsg, "Unsupported clone() flags: 0x%lx\n", ARG1); + VG_(message)(Vg_UserMsg, "\n"); + VG_(message)(Vg_UserMsg, "The only supported clone() uses are:\n"); + VG_(message)(Vg_UserMsg, " - via a threads library (LinuxThreads or NPTL)\n"); + VG_(message)(Vg_UserMsg, " - via the implementation of fork or vfork\n"); VG_(unimplemented) ("Valgrind does not support general clone()."); } diff --git a/coregrind/m_syswrap/syswrap-x86-linux.c b/coregrind/m_syswrap/syswrap-x86-linux.c index 60a052cd92..601ff941af 100644 --- a/coregrind/m_syswrap/syswrap-x86-linux.c +++ b/coregrind/m_syswrap/syswrap-x86-linux.c @@ -278,7 +278,8 @@ static SysRes do_clone ( ThreadId ptid, VG_(printf)("tid %d: guessed client stack range %#lx-%#lx\n", ctid, seg->start, VG_PGROUNDUP(esp)); } else { - VG_(message)(Vg_UserMsg, "!? New thread %d starts with ESP(%#lx) unmapped\n", + VG_(message)(Vg_UserMsg, + "!? New thread %d starts with ESP(%#lx) unmapped\n", ctid, esp); ctst->client_stack_szB = 0; } @@ -930,13 +931,13 @@ PRE(sys_clone) default: reject: /* should we just ENOSYS? */ - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "Unsupported clone() flags: 0x%lx", ARG1); - VG_(message)(Vg_UserMsg, ""); - VG_(message)(Vg_UserMsg, "The only supported clone() uses are:"); - VG_(message)(Vg_UserMsg, " - via a threads library (LinuxThreads or NPTL)"); - VG_(message)(Vg_UserMsg, " - via the implementation of fork or vfork"); - VG_(message)(Vg_UserMsg, " - for the Quadrics Elan3 user-space driver"); + VG_(message)(Vg_UserMsg, "\n"); + VG_(message)(Vg_UserMsg, "Unsupported clone() flags: 0x%lx\n", ARG1); + VG_(message)(Vg_UserMsg, "\n"); + VG_(message)(Vg_UserMsg, "The only supported clone() uses are:\n"); + VG_(message)(Vg_UserMsg, " - via a threads library (LinuxThreads or NPTL)\n"); + VG_(message)(Vg_UserMsg, " - via the implementation of fork or vfork\n"); + VG_(message)(Vg_UserMsg, " - for the Quadrics Elan3 user-space driver\n"); VG_(unimplemented) ("Valgrind does not support general clone()."); } @@ -1235,7 +1236,7 @@ PRE(sys_ipc) ML_(generic_PRE_sys_shmctl)( tid, ARG2, ARG3, ARG5 ); break; default: - VG_(message)(Vg_DebugMsg, "FATAL: unhandled syscall(ipc) %ld", ARG1 ); + VG_(message)(Vg_DebugMsg, "FATAL: unhandled syscall(ipc) %ld\n", ARG1 ); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ } @@ -1300,7 +1301,7 @@ POST(sys_ipc) break; default: VG_(message)(Vg_DebugMsg, - "FATAL: unhandled syscall(ipc) %ld", + "FATAL: unhandled syscall(ipc) %ld\n", ARG1 ); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ @@ -1562,7 +1563,7 @@ PRE(sys_socketcall) } default: - VG_(message)(Vg_DebugMsg,"Warning: unhandled socketcall 0x%lx",ARG1); + VG_(message)(Vg_DebugMsg,"Warning: unhandled socketcall 0x%lx\n",ARG1); SET_STATUS_Failure( VKI_EINVAL ); break; } @@ -1665,7 +1666,7 @@ POST(sys_socketcall) break; default: - VG_(message)(Vg_DebugMsg,"FATAL: unhandled socketcall 0x%lx",ARG1); + VG_(message)(Vg_DebugMsg,"FATAL: unhandled socketcall 0x%lx\n",ARG1); VG_(core_panic)("... bye!\n"); break; /*NOTREACHED*/ } diff --git a/coregrind/m_tooliface.c b/coregrind/m_tooliface.c index 4ed966d00e..e6d1652e71 100644 --- a/coregrind/m_tooliface.c +++ b/coregrind/m_tooliface.c @@ -214,7 +214,6 @@ Bool VG_(sanity_check_needs)(Char** failmsg) NEEDS(libc_freeres) NEEDS(core_errors) NEEDS(var_info) -NEEDS(xml_output) void VG_(needs_superblock_discards)( void (*discard)(Addr64, VexGuestExtents) @@ -226,6 +225,7 @@ void VG_(needs_superblock_discards)( void VG_(needs_tool_errors)( Bool (*eq) (VgRes, Error*, Error*), + void (*before_pp) (Error*), void (*pp) (Error*), Bool show_TIDs, UInt (*update) (Error*), @@ -238,6 +238,7 @@ void VG_(needs_tool_errors)( { VG_(needs).tool_errors = True; VG_(tdict).tool_eq_Error = eq; + VG_(tdict).tool_before_pp_Error = before_pp; VG_(tdict).tool_pp_Error = pp; VG_(tdict).tool_show_ThreadIDs_for_errors = show_TIDs; VG_(tdict).tool_update_extra = update; @@ -316,6 +317,11 @@ void VG_(needs_malloc_replacement)( VG_(tdict).tool_client_redzone_szB = client_malloc_redzone_szB; } +void VG_(needs_xml_output)( void ) +{ + VG_(needs).xml_output = True; +} + void VG_(needs_final_IR_tidy_pass)( IRSB*(*final_tidy)(IRSB*) ) diff --git a/coregrind/m_translate.c b/coregrind/m_translate.c index 1e1f049d5f..8ff300fb15 100644 --- a/coregrind/m_translate.c +++ b/coregrind/m_translate.c @@ -74,17 +74,17 @@ void VG_(print_translation_stats) ( void ) + n_SP_updates_generic_unknown; VG_(percentify)(n_SP_updates_fast, n_SP_updates, 1, 6, buf); VG_(message)(Vg_DebugMsg, - "translate: fast SP updates identified: %'u (%s)", + "translate: fast SP updates identified: %'u (%s)\n", n_SP_updates_fast, buf ); VG_(percentify)(n_SP_updates_generic_known, n_SP_updates, 1, 6, buf); VG_(message)(Vg_DebugMsg, - "translate: generic_known SP updates identified: %'u (%s)", + "translate: generic_known SP updates identified: %'u (%s)\n", n_SP_updates_generic_known, buf ); VG_(percentify)(n_SP_updates_generic_unknown, n_SP_updates, 1, 6, buf); VG_(message)(Vg_DebugMsg, - "translate: generic_unknown SP updates identified: %'u (%s)", + "translate: generic_unknown SP updates identified: %'u (%s)\n", n_SP_updates_generic_unknown, buf ); } @@ -1320,7 +1320,7 @@ Bool VG_(translate) ( ThreadId tid, ok = VG_(get_fnname_w_offset)(addr, name2, 64); if (!ok) VG_(strcpy)(name2, "???"); VG_(message)(Vg_DebugMsg, - "REDIR: 0x%llx (%s) redirected to 0x%llx (%s)", + "REDIR: 0x%llx (%s) redirected to 0x%llx (%s)\n", nraddr, name1, addr, name2 ); } @@ -1357,7 +1357,7 @@ Bool VG_(translate) ( ThreadId tid, || addr == TRANSTAB_BOGUS_GUEST_ADDR ) { if (VG_(clo_trace_signals)) VG_(message)(Vg_DebugMsg, "translations not allowed here (0x%llx)" - " - throwing SEGV", addr); + " - throwing SEGV\n", addr); /* U R busted, sonny. Place your hands on your head and step away from the orig_addr. */ /* Code address is bad - deliver a signal instead */ diff --git a/coregrind/m_transtab.c b/coregrind/m_transtab.c index a224b48760..c8954eb194 100644 --- a/coregrind/m_transtab.c +++ b/coregrind/m_transtab.c @@ -736,7 +736,7 @@ static void initialiseSector ( Int sno ) } if (VG_(clo_verbosity) > 2) - VG_(message)(Vg_DebugMsg, "TT/TC: initialise sector %d", sno); + VG_(message)(Vg_DebugMsg, "TT/TC: initialise sector %d\n", sno); } else { @@ -780,7 +780,7 @@ static void initialiseSector ( Int sno ) } if (VG_(clo_verbosity) > 2) - VG_(message)(Vg_DebugMsg, "TT/TC: recycle sector %d", sno); + VG_(message)(Vg_DebugMsg, "TT/TC: recycle sector %d\n", sno); } sec->tc_next = sec->tc; @@ -1459,7 +1459,7 @@ void VG_(init_tt_tc) ( void ) if (VG_(clo_verbosity) > 2) VG_(message)(Vg_DebugMsg, "TT/TC: VG_(init_tt_tc) " - "(startup of code management)"); + "(startup of code management)\n"); /* Figure out how big each tc area should be. */ avg_codeszQ = (VG_(details).avg_translation_sizeB + 7) / 8; @@ -1495,11 +1495,11 @@ void VG_(init_tt_tc) ( void ) if (VG_(clo_verbosity) > 2) { VG_(message)(Vg_DebugMsg, - "TT/TC: cache: %d sectors of %d bytes each = %d total", + "TT/TC: cache: %d sectors of %d bytes each = %d total\n", N_SECTORS, 8 * tc_sector_szQ, N_SECTORS * 8 * tc_sector_szQ ); VG_(message)(Vg_DebugMsg, - "TT/TC: table: %d total entries, max occupancy %d (%d%%)", + "TT/TC: table: %d total entries, max occupancy %d (%d%%)\n", N_SECTORS * N_TTES_PER_SECTOR, N_SECTORS * N_TTES_PER_SECTOR_USABLE, SECTOR_TT_LIMIT_PERCENT ); @@ -1534,23 +1534,23 @@ UInt VG_(get_bbs_translated) ( void ) void VG_(print_tt_tc_stats) ( void ) { VG_(message)(Vg_DebugMsg, - " tt/tc: %'llu tt lookups requiring %'llu probes", + " tt/tc: %'llu tt lookups requiring %'llu probes\n", n_full_lookups, n_lookup_probes ); VG_(message)(Vg_DebugMsg, - " tt/tc: %'llu fast-cache updates, %'llu flushes", + " tt/tc: %'llu fast-cache updates, %'llu flushes\n", n_fast_updates, n_fast_flushes ); VG_(message)(Vg_DebugMsg, " transtab: new %'lld " - "(%'llu -> %'llu; ratio %'llu:10) [%'llu scs]", + "(%'llu -> %'llu; ratio %'llu:10) [%'llu scs]\n", n_in_count, n_in_osize, n_in_tsize, safe_idiv(10*n_in_tsize, n_in_osize), n_in_sc_count); VG_(message)(Vg_DebugMsg, - " transtab: dumped %'llu (%'llu -> ?" "?)", + " transtab: dumped %'llu (%'llu -> ?" "?)\n", n_dump_count, n_dump_osize ); VG_(message)(Vg_DebugMsg, - " transtab: discarded %'llu (%'llu -> ?" "?)", + " transtab: discarded %'llu (%'llu -> ?" "?)\n", n_disc_count, n_disc_osize ); if (0) { diff --git a/coregrind/m_ume/main.c b/coregrind/m_ume/main.c index 504bd5349f..bc98d9a931 100644 --- a/coregrind/m_ume/main.c +++ b/coregrind/m_ume/main.c @@ -86,13 +86,13 @@ VG_(pre_exec_check)(const HChar* exe_name, Int* out_fd, Bool allow_setuid) if (0 != ret) { VG_(close)(fd); if (is_setuid && !VG_(clo_xml)) { - VG_(message)(Vg_UserMsg, ""); + VG_(message)(Vg_UserMsg, "\n"); VG_(message)(Vg_UserMsg, - "Warning: Can't execute setuid/setgid executable: %s", + "Warning: Can't execute setuid/setgid executable: %s\n", exe_name); VG_(message)(Vg_UserMsg, "Possible workaround: remove " - "--trace-children=yes, if in effect"); - VG_(message)(Vg_UserMsg, ""); + "--trace-children=yes, if in effect\n"); + VG_(message)(Vg_UserMsg, "\n"); } return VG_(mk_SysRes_Error)(ret); } diff --git a/coregrind/pub_core_libcprint.h b/coregrind/pub_core_libcprint.h index 3b3460cd17..c043c2d42a 100644 --- a/coregrind/pub_core_libcprint.h +++ b/coregrind/pub_core_libcprint.h @@ -38,9 +38,15 @@ #include "pub_tool_libcprint.h" -/* Tell the logging mechanism whether we are logging to a file - descriptor or a socket descriptor. */ -extern Bool VG_(logging_to_socket); +/* An output file descriptor wrapped up with a Bool indicating whether + or not the fd is a socket. */ +typedef + struct { Int fd; Bool is_socket; } + OutputSink; + +/* And the destinations for normal and XML output. */ +extern OutputSink VG_(log_output_sink); +extern OutputSink VG_(xml_output_sink); /* Get the elapsed wallclock time since startup into buf, which must 16 chars long. This is unchecked. It also relies on the diff --git a/coregrind/pub_core_options.h b/coregrind/pub_core_options.h index 73f4a630b2..b113a7e9de 100644 --- a/coregrind/pub_core_options.h +++ b/coregrind/pub_core_options.h @@ -65,30 +65,14 @@ extern Bool VG_(clo_trace_children); intermingled with the parent's output. This is especially problematic when VG_(clo_xml) is True. Setting VG_(clo_child_silent_after_fork) causes children to fall silent - after fork() calls. */ + after fork() calls. Although note they become un-silent again + after the subsequent exec(). */ extern Bool VG_(clo_child_silent_after_fork); -/* Where logging output is to be sent to. - - With --log-fd (and by default), clo_log_fd holds the file id, and is - taken from the command line. (fd 2, stderr, is the default.) - clo_log_name is irrelevant. - - With --log-file, clo_log_name holds the log-file name, and is taken from - the command line (and possibly has process ID/env var contents in it, if - the %p or %q format specifiers are used). clo_log_fd is then made to - hold the relevant file id, by opening clo_log_name (concatenated with the - process ID) for writing. - - With --log-socket, clo_log_name holds the hostname:portnumber pair, - and is taken from the command line. clo_log_fd is then made to hold - the relevant file handle, by opening a connection to that - hostname:portnumber pair. - - Global default is to set log_to == VgLogTo_Fd and log_fd == 2 - (stderr). */ -extern Int VG_(clo_log_fd); -extern Char* VG_(clo_log_name); +/* If the user specified --log-file=STR and/or --xml-file=STR, these + hold STR after expansion of the %p and %q templates. */ +extern Char* VG_(clo_log_fname_expanded); +extern Char* VG_(clo_xml_fname_expanded); /* Add timestamps to log messages? default: NO */ extern Bool VG_(clo_time_stamp); diff --git a/coregrind/pub_core_tooliface.h b/coregrind/pub_core_tooliface.h index 25cfb2652e..f9a8005405 100644 --- a/coregrind/pub_core_tooliface.h +++ b/coregrind/pub_core_tooliface.h @@ -117,6 +117,7 @@ typedef struct { // VG_(needs).tool_errors Bool (*tool_eq_Error) (VgRes, Error*, Error*); + void (*tool_before_pp_Error) (Error*); void (*tool_pp_Error) (Error*); Bool tool_show_ThreadIDs_for_errors; UInt (*tool_update_extra) (Error*); @@ -161,6 +162,9 @@ typedef struct { // VG_(needs).final_IR_tidy_pass IRSB* (*tool_final_IR_tidy_pass) (IRSB*); + // VG_(needs).xml_output + // (none) + // -- Event tracking functions ------------------------------------ void (*track_new_mem_startup) (Addr, SizeT, Bool, Bool, Bool, ULong); void (*track_new_mem_stack_signal)(Addr, SizeT, ThreadId);