1 /* -*- mode: C; c-basic-offset: 3; -*- */ 2 3 /*--------------------------------------------------------------------*/ 4 /*--- Libc printing. m_libcprint.c ---*/ 5 /*--------------------------------------------------------------------*/ 6 7 /* 8 This file is part of Valgrind, a dynamic binary instrumentation 9 framework. 10 11 Copyright (C) 2000-2017 Julian Seward 12 jseward (at) acm.org 13 14 This program is free software; you can redistribute it and/or 15 modify it under the terms of the GNU General Public License as 16 published by the Free Software Foundation; either version 2 of the 17 License, or (at your option) any later version. 18 19 This program is distributed in the hope that it will be useful, but 20 WITHOUT ANY WARRANTY; without even the implied warranty of 21 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU 22 General Public License for more details. 23 24 You should have received a copy of the GNU General Public License 25 along with this program; if not, write to the Free Software 26 Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 27 02111-1307, USA. 28 29 The GNU General Public License is contained in the file COPYING. 30 */ 31 32 #include "pub_core_basics.h" 33 #include "pub_core_vki.h" 34 #include "pub_core_vkiscnums.h" 35 #include "pub_core_debuglog.h" 36 #include "pub_core_gdbserver.h" // VG_(gdb_printf) 37 #include "pub_core_libcbase.h" 38 #include "pub_core_libcassert.h" 39 #include "pub_core_libcfile.h" // VG_(write)(), VG_(write_socket)() 40 #include "pub_core_libcprint.h" 41 #include "pub_core_libcproc.h" // VG_(getpid)(), VG_(read_millisecond_timer() 42 #include "pub_core_mallocfree.h" // VG_(malloc) 43 #include "pub_core_machine.h" // VG_(machine_get_VexArchInfo) 44 #include "pub_core_options.h" 45 #include "pub_core_clreq.h" // For RUNNING_ON_VALGRIND 46 #include "pub_core_clientstate.h" 47 #include "pub_core_syscall.h" // VG_(strerror) 48 #include "pub_core_tooliface.h" // VG_(details) 49 50 51 /*====================================================================*/ 52 /*=== Printing the preamble ===*/ 53 /*====================================================================*/ 54 55 // Print the argument, escaping any chars that require it. 56 static void umsg_arg(const HChar *arg) 57 { 58 SizeT len = VG_(strlen)(arg); 59 const HChar *special = " \\<>"; 60 for (UInt i = 0; i < len; i++) { 61 if (VG_(strchr)(special, arg[i])) { 62 VG_(umsg)("\\"); // escape with a backslash if necessary 63 } 64 VG_(umsg)("%c", arg[i]); 65 } 66 } 67 68 // Send output to the XML-stream and escape any XML meta-characters. 69 static void xml_arg(const HChar *arg) 70 { 71 VG_(printf_xml)("%pS", arg); 72 } 73 74 // Write the name and value of log file qualifiers to the xml file. 75 // We can safely assume here that the format string is well-formed. 76 // It has been checked earlier in VG_(expand_file_name) when processing 77 // command line options. 78 static void print_file_vars(const HChar *format) 79 { 80 UInt i = 0; 81 82 while (format[i]) { 83 if (format[i] == '%') { 84 // We saw a '%'. What's next... 85 i++; 86 if ('q' == format[i]) { 87 i++; 88 if ('{' == format[i]) { 89 // Get the env var name, print its contents. 90 UInt begin_qualname = ++i; 91 while (True) { 92 if ('}' == format[i]) { 93 UInt qualname_len = i - begin_qualname; 94 HChar qualname[qualname_len + 1]; 95 VG_(strncpy)(qualname, format + begin_qualname, 96 qualname_len); 97 qualname[qualname_len] = '\0'; 98 HChar *qual = VG_(getenv)(qualname); 99 i++; 100 VG_(printf_xml)("<logfilequalifier> <var>%pS</var> " 101 "<value>%pS</value> </logfilequalifier>\n", 102 qualname, qual); 103 break; 104 } 105 i++; 106 } 107 } 108 } 109 } else { 110 i++; 111 } 112 } 113 } 114 115 /* Ok, the logging sink is running now. Print a suitable preamble. 116 If logging to file or a socket, write details of parent PID and 117 command line args, to help people trying to interpret the 118 results of a run which encompasses multiple processes. */ 119 void VG_(print_preamble)(Bool logging_to_fd) 120 { 121 const HChar *xpre = VG_(clo_xml) ? " <line>" : ""; 122 const HChar *xpost = VG_(clo_xml) ? "</line>" : ""; 123 UInt (*umsg_or_xml)( const HChar *, ... ) 124 = VG_(clo_xml) ? VG_(printf_xml) : VG_(umsg); 125 void (*umsg_or_xml_arg)( const HChar *) = VG_(clo_xml) ? xml_arg : umsg_arg; 126 127 vg_assert( VG_(args_for_client) ); 128 vg_assert( VG_(args_for_valgrind) ); 129 vg_assert( VG_(clo_toolname) ); 130 131 if (VG_(clo_xml)) { 132 VG_(printf_xml)("<?xml version=\"1.0\"?>\n"); 133 VG_(printf_xml)("\n"); 134 VG_(printf_xml)("<valgrindoutput>\n"); 135 VG_(printf_xml)("\n"); 136 VG_(printf_xml)("<protocolversion>4</protocolversion>\n"); 137 VG_(printf_xml)("<protocoltool>%s</protocoltool>\n", VG_(clo_toolname)); 138 VG_(printf_xml)("\n"); 139 } 140 141 if (VG_(clo_xml) || VG_(clo_verbosity) > 0) { 142 143 if (VG_(clo_xml)) 144 VG_(printf_xml)("<preamble>\n"); 145 146 /* Tool details */ 147 umsg_or_xml(VG_(clo_xml) ? "%s%pS%pS%pS, %pS%s\n" : "%s%s%s%s, %s%s\n", 148 xpre, 149 VG_(details).name, 150 NULL == VG_(details).version ? "" : "-", 151 NULL == VG_(details).version ? "" : VG_(details).version, 152 VG_(details).description, 153 xpost); 154 155 if (VG_(strlen)(VG_(clo_toolname)) >= 4 && 156 VG_STREQN(4, VG_(clo_toolname), "exp-")) { 157 umsg_or_xml("%sNOTE: This is an Experimental-Class Valgrind Tool%s\n", 158 xpre, xpost); 159 } 160 161 umsg_or_xml(VG_(clo_xml) ? "%s%pS%s\n" : "%s%s%s\n", 162 xpre, VG_(details).copyright_author, xpost); 163 164 /* Core details */ 165 umsg_or_xml( 166 "%sUsing Valgrind-%s and LibVEX; rerun with -h for copyright info%s\n", 167 xpre, VERSION, xpost); 168 169 // Print the command line. At one point we wrapped at 80 chars and 170 // printed a '\' as a line joiner, but that makes it hard to cut and 171 // paste the command line (because of the "==pid==" prefixes), so we now 172 // favour utility and simplicity over aesthetics. 173 umsg_or_xml("%sCommand: ", xpre); 174 umsg_or_xml_arg(VG_(args_the_exename)); 175 176 for (UInt i = 0; i < VG_(sizeXA)( VG_(args_for_client)); i++) { 177 HChar *s = *(HChar **)VG_(indexXA)( VG_(args_for_client), i); 178 umsg_or_xml(" "); 179 umsg_or_xml_arg(s); 180 } 181 umsg_or_xml("%s\n", xpost); 182 183 if (VG_(clo_xml)) 184 VG_(printf_xml)("</preamble>\n"); 185 } 186 187 // Print the parent PID, and other stuff, if necessary. 188 if (!VG_(clo_xml) && VG_(clo_verbosity) > 0 && !logging_to_fd) { 189 VG_(umsg)("Parent PID: %d\n", VG_(getppid)()); 190 } else if (VG_(clo_xml)) { 191 VG_(printf_xml)("\n"); 192 VG_(printf_xml)("<pid>%d</pid>\n", VG_(getpid)()); 193 VG_(printf_xml)("<ppid>%d</ppid>\n", VG_(getppid)()); 194 VG_(printf_xml)("<tool>%pS</tool>\n", VG_(clo_toolname)); 195 if (VG_(clo_xml_fname_unexpanded) != NULL) 196 print_file_vars(VG_(clo_xml_fname_unexpanded)); 197 if (VG_(clo_xml_user_comment)) { 198 /* Note: the user comment itself is XML and is therefore to 199 be passed through verbatim (%s) rather than escaped (%pS). */ 200 VG_(printf_xml)("<usercomment>%s</usercomment>\n", 201 VG_(clo_xml_user_comment)); 202 } 203 VG_(printf_xml)("\n"); 204 VG_(printf_xml)("<args>\n"); 205 206 VG_(printf_xml)(" <vargv>\n"); 207 if (VG_(name_of_launcher)) 208 VG_(printf_xml)(" <exe>%pS</exe>\n", VG_(name_of_launcher)); 209 else 210 VG_(printf_xml)(" <exe>%pS</exe>\n", "(launcher name unknown)"); 211 for (UInt i = 0; i < VG_(sizeXA)( VG_(args_for_valgrind) ); i++) { 212 VG_(printf_xml)( 213 " <arg>%pS</arg>\n", 214 *(HChar **) VG_(indexXA)( VG_(args_for_valgrind), i)); 215 } 216 VG_(printf_xml)(" </vargv>\n"); 217 218 VG_(printf_xml)(" <argv>\n"); 219 VG_(printf_xml)(" <exe>%pS</exe>\n", VG_(args_the_exename)); 220 for (UInt i = 0; i < VG_(sizeXA)( VG_(args_for_client) ); i++) { 221 VG_(printf_xml)( 222 " <arg>%pS</arg>\n", 223 *(HChar **) VG_(indexXA)( VG_(args_for_client), i)); 224 } 225 VG_(printf_xml)(" </argv>\n"); 226 227 VG_(printf_xml)("</args>\n"); 228 } 229 230 // Last thing in the preamble is a blank line. 231 if (VG_(clo_xml)) 232 VG_(printf_xml)("\n"); 233 else if (VG_(clo_verbosity) > 0) 234 VG_(umsg)("\n"); 235 236 if (VG_(clo_verbosity) > 1) { 237 # if defined(VGO_linux) 238 SysRes fd; 239 # endif 240 VexArch vex_arch; 241 VexArchInfo vex_archinfo; 242 if (!logging_to_fd) 243 VG_(message)(Vg_DebugMsg, "\n"); 244 VG_(message)(Vg_DebugMsg, "Valgrind options:\n"); 245 for (UInt i = 0; i < VG_(sizeXA)( VG_(args_for_valgrind) ); i++) { 246 VG_(message)(Vg_DebugMsg, 247 " %s\n", 248 *(HChar **) VG_(indexXA)( VG_(args_for_valgrind), i)); 249 } 250 251 # if defined(VGO_linux) 252 VG_(message)(Vg_DebugMsg, "Contents of /proc/version:\n"); 253 fd = VG_(open)("/proc/version", VKI_O_RDONLY, 0); 254 if (sr_isError(fd)) { 255 VG_(message)(Vg_DebugMsg, " can't open /proc/version\n"); 256 } else { 257 const SizeT bufsiz = 255; 258 HChar version_buf[bufsiz+1]; 259 VG_(message)(Vg_DebugMsg, " "); 260 Int n, fdno = sr_Res(fd); 261 do { 262 n = VG_(read)(fdno, version_buf, bufsiz); 263 if (n < 0) { 264 VG_(message)(Vg_DebugMsg, " error reading /proc/version\n"); 265 break; 266 } 267 version_buf[n] = '\0'; 268 VG_(message)(Vg_DebugMsg, "%s", version_buf); 269 } while (n == bufsiz); 270 VG_(message)(Vg_DebugMsg, "\n"); 271 VG_(close)(fdno); 272 } 273 # elif defined(VGO_darwin) 274 VG_(message)(Vg_DebugMsg, "Output from sysctl({CTL_KERN,KERN_VERSION}):\n"); 275 /* Note: preferable to use sysctlbyname("kern.version", kernelVersion, &len, NULL, 0) 276 however that syscall is OS X 10.10+ only. */ 277 Int mib[] = {CTL_KERN, KERN_VERSION}; 278 SizeT len; 279 VG_(sysctl)(mib, sizeof(mib)/sizeof(Int), NULL, &len, NULL, 0); 280 HChar *kernelVersion = VG_(malloc)("main.pp.1", len); 281 VG_(sysctl)(mib, sizeof(mib)/sizeof(Int), kernelVersion, &len, NULL, 0); 282 VG_(message)(Vg_DebugMsg, " %s\n", kernelVersion); 283 VG_(free)( kernelVersion ); 284 # elif defined(VGO_solaris) 285 /* There is no /proc/version file on Solaris so we try to get some 286 system information using the uname(2) syscall. */ 287 struct vki_utsname uts; 288 VG_(message)(Vg_DebugMsg, "System information:\n"); 289 SysRes res = VG_(do_syscall1)(__NR_uname, (UWord)&uts); 290 if (sr_isError(res)) 291 VG_(message)(Vg_DebugMsg, " uname() failed\n"); 292 else 293 VG_(message)(Vg_DebugMsg, " %s %s %s %s\n", 294 uts.sysname, uts.release, uts.version, uts.machine); 295 # endif 296 297 VG_(machine_get_VexArchInfo)(&vex_arch, &vex_archinfo); 298 VG_(message)( 299 Vg_DebugMsg, 300 "Arch and hwcaps: %s, %s, %s\n", 301 LibVEX_ppVexArch ( vex_arch ), 302 LibVEX_ppVexEndness ( vex_archinfo.endness ), 303 LibVEX_ppVexHwCaps ( vex_arch, vex_archinfo.hwcaps ) 304 ); 305 VG_(message)(Vg_DebugMsg, 306 "Page sizes: currently %u, max supported %u\n", 307 (UInt) VKI_PAGE_SIZE, (UInt) VKI_MAX_PAGE_SIZE); 308 VG_(message)(Vg_DebugMsg, 309 "Valgrind library directory: %s\n", VG_(libdir)); 310 } 311 } 312 313 /* --------------------------------------------------------------------- 314 Writing to file or a socket 315 ------------------------------------------------------------------ */ 316 317 /* The destination sinks for normal and XML output. These have their 318 initial values here; they are set to final values by 319 m_main.main_process_cmd_line_options(). See comment at the top of 320 that function for the associated logic. 321 After startup, the gdbserver monitor command might temporarily 322 set the fd of log_output_sink to -2 to indicate that output is 323 to be given to gdb rather than output to the startup fd */ 324 OutputSink VG_(log_output_sink) = { 2, VgLogTo_Fd, NULL }; /* 2 = stderr */ 325 OutputSink VG_(xml_output_sink) = { -1, VgLogTo_Fd, NULL }; /* disabled */ 326 327 static void revert_sink_to_stderr ( OutputSink *sink ) 328 { 329 sink->fd = 2; /* stderr */ 330 sink->type = VgLogTo_Fd; 331 VG_(free)(sink->fsname_expanded); 332 sink->fsname_expanded = NULL; 333 } 334 335 static Int prepare_sink_fd(const HChar *clo_fname_unexpanded, OutputSink *sink, 336 Bool is_xml) 337 { 338 vg_assert(clo_fname_unexpanded != NULL); 339 vg_assert(VG_(strlen)(clo_fname_unexpanded) <= 900); /* paranoia */ 340 341 // Nb: we overwrite an existing file of this name without asking 342 // any questions. 343 HChar *logfilename = VG_(expand_file_name)( 344 (is_xml) ? "--xml-file" : "--log-file", 345 clo_fname_unexpanded); 346 SysRes sres = VG_(open)(logfilename, 347 VKI_O_CREAT|VKI_O_WRONLY|VKI_O_TRUNC, 348 VKI_S_IRUSR|VKI_S_IWUSR|VKI_S_IRGRP|VKI_S_IROTH); 349 if (!sr_isError(sres)) { 350 Int fd = sr_Res(sres); 351 sink->fsname_expanded = logfilename; 352 sink->type = VgLogTo_File; 353 return fd; 354 } else { 355 VG_(fmsg)("Cannot create %s file '%s': %s\n", 356 (is_xml) ? "XML" : "log", logfilename, 357 VG_(strerror)(sr_Err(sres))); 358 VG_(exit)(1); 359 /*NOTREACHED*/ 360 } 361 } 362 363 static Int prepare_sink_socket(const HChar *clo_fname_unexpanded, 364 OutputSink *sink, Bool is_xml) 365 { 366 vg_assert(clo_fname_unexpanded != NULL); 367 vg_assert(VG_(strlen)(clo_fname_unexpanded) <= 900); /* paranoia */ 368 369 Int fd = VG_(connect_via_socket)(clo_fname_unexpanded); 370 if (fd == -1) { 371 VG_(fmsg)("Invalid %s spec of '%s'\n", 372 (is_xml) ? "--xml-socket" : "--log-socket", 373 clo_fname_unexpanded); 374 VG_(exit)(1); 375 /*NOTREACHED*/ 376 } 377 if (fd == -2) { 378 VG_(umsg)("Failed to connect to %slogging server '%s'.\n" 379 "%s will be sent to stderr instead.\n", 380 (is_xml) ? "XML " : "", 381 clo_fname_unexpanded, 382 (is_xml) ? "XML output" : "Logging messages"); 383 /* We don't change anything here. */ 384 vg_assert(sink->fd == 2); 385 vg_assert(sink->type == VgLogTo_Fd); 386 return 2; 387 } else { 388 vg_assert(fd > 0); 389 sink->type = VgLogTo_Socket; 390 return fd; 391 } 392 } 393 394 static void finalize_sink_fd(OutputSink *sink, Int new_fd, Bool is_xml) 395 { 396 // Move new_fd into the safe range, so it doesn't conflict with any app fds. 397 Int safe_fd = VG_(fcntl)(new_fd, VKI_F_DUPFD, VG_(fd_hard_limit)); 398 if (safe_fd < 0) { 399 VG_(message)(Vg_UserMsg, "Valgrind: failed to move %s file descriptor " 400 "into safe range, using stderr\n", 401 (is_xml) ? "XML" : "log"); 402 revert_sink_to_stderr(sink); 403 } else { 404 VG_(fcntl)(safe_fd, VKI_F_SETFD, VKI_FD_CLOEXEC); 405 sink->fd = safe_fd; 406 } 407 } 408 409 /* Re-opens an output file sink when exanded file name differs from what we 410 have now. Returns 'True' if the sink was reopened */ 411 static Bool reopen_sink_if_needed(const HChar *clo_fname_unexpanded, 412 OutputSink *sink, Bool is_xml) 413 { 414 if (sink->type == VgLogTo_File) { 415 /* Try to expand --log|xml-file again and see if it differs from what 416 we have now. */ 417 HChar *logfilename = VG_(expand_file_name)( 418 (is_xml) ? "--xml-file" : "--log-file", 419 clo_fname_unexpanded); 420 if (VG_(strcmp)(logfilename, sink->fsname_expanded) != 0) { 421 Int fd = prepare_sink_fd(clo_fname_unexpanded, sink, is_xml); 422 finalize_sink_fd(sink, fd, is_xml); 423 return True; 424 } 425 VG_(free)(logfilename); 426 } 427 428 return False; 429 } 430 431 void VG_(logging_atfork_child)(ThreadId tid) 432 { 433 /* If --child-silent-after-fork=yes was specified, set the output file 434 descriptors to 'impossible' values. This is noticed by 435 send_bytes_to_logging_sink(), which duly stops writing any further 436 output. */ 437 if (VG_(clo_child_silent_after_fork)) { 438 if (VG_(log_output_sink).type != VgLogTo_Socket) { 439 VG_(log_output_sink).fd = -1; 440 VG_(log_output_sink).type = VgLogTo_Fd; 441 } 442 if (VG_(xml_output_sink).type != VgLogTo_Socket) { 443 VG_(xml_output_sink).fd = -1; 444 VG_(xml_output_sink).type = VgLogTo_Fd; 445 } 446 } else { 447 if (reopen_sink_if_needed(VG_(clo_log_fname_unexpanded), 448 &VG_(log_output_sink), False) || 449 reopen_sink_if_needed(VG_(clo_xml_fname_unexpanded), 450 &VG_(xml_output_sink), True)) { 451 VG_(print_preamble)(VG_(log_output_sink).type != VgLogTo_File); 452 } 453 } 454 } 455 456 /* Initializes normal log and xml sinks (of type fd, file, or socket). 457 Any problem encountered is considered a hard error and causes V. to exit. 458 459 Comments on how the logging options are handled: 460 461 User can specify: 462 --log-fd= for a fd to write to (default setting, fd = 2) 463 --log-file= for a file name to write to 464 --log-socket= for a socket to write to 465 466 As a result of examining these and doing relevant socket/file 467 opening, a final fd is established. This is stored in 468 VG_(log_output_sink) in m_libcprint. Also, if --log-file=STR was 469 specified, then it is stored in VG_(clo_log_fname_unexpanded), in m_options. 470 And then STR, after expansion of %p and %q templates within 471 it, is stored in VG_(log_output_sink), just in case anybody wants to know 472 what it is. 473 474 When printing, VG_(log_output_sink) is consulted to find the 475 fd to send output to. 476 477 Exactly analogous actions are undertaken for the XML output 478 channel, with the one difference that the default fd is -1, meaning 479 the channel is disabled by default. */ 480 void VG_(init_log_xml_sinks)(VgLogTo log_to, VgLogTo xml_to, 481 Int /*initial*/log_fd, Int /*initial*/xml_fd) 482 { 483 // VG_(clo_log_fd) is used by all the messaging. It starts as 2 (stderr) 484 // and we cannot change it until we know what we are changing it to is ok. 485 486 /* Start setting up logging now. After this is done, VG_(log_output_sink) 487 and (if relevant) VG_(xml_output_sink) should be connected to whatever 488 sink has been selected, and we indiscriminately chuck stuff into it 489 without worrying what the nature of it is. 490 Oh the wonder of Unix streams. */ 491 492 vg_assert(VG_(log_output_sink).fd == 2 /* stderr */); 493 vg_assert(VG_(log_output_sink).type == VgLogTo_Fd); 494 vg_assert(VG_(log_output_sink).fsname_expanded == NULL); 495 496 vg_assert(VG_(xml_output_sink).fd == -1 /* disabled */); 497 vg_assert(VG_(xml_output_sink).type == VgLogTo_Fd); 498 vg_assert(VG_(xml_output_sink).fsname_expanded == NULL); 499 500 /* --- set up the normal text output channel --- */ 501 switch (log_to) { 502 case VgLogTo_Fd: 503 vg_assert(VG_(clo_log_fname_unexpanded) == NULL); 504 break; 505 506 case VgLogTo_File: 507 log_fd = prepare_sink_fd(VG_(clo_log_fname_unexpanded), 508 &VG_(log_output_sink), False); 509 break; 510 511 case VgLogTo_Socket: 512 log_fd = prepare_sink_socket(VG_(clo_log_fname_unexpanded), 513 &VG_(log_output_sink), False); 514 break; 515 } 516 517 /* --- set up the XML output channel --- */ 518 switch (xml_to) { 519 case VgLogTo_Fd: 520 vg_assert(VG_(clo_xml_fname_unexpanded) == NULL); 521 break; 522 523 case VgLogTo_File: 524 xml_fd = prepare_sink_fd(VG_(clo_xml_fname_unexpanded), 525 &VG_(xml_output_sink), True); 526 break; 527 528 case VgLogTo_Socket: 529 log_fd = prepare_sink_socket(VG_(clo_xml_fname_unexpanded), 530 &VG_(xml_output_sink), True); 531 break; 532 } 533 534 /* If we've got this far, and XML mode was requested, but no XML 535 output channel appears to have been specified, just stop. We 536 could continue, and XML output will simply vanish into nowhere, 537 but that is likely to confuse the hell out of users, which is 538 distinctly Ungood. */ 539 if (VG_(clo_xml) && xml_fd == -1) { 540 VG_(fmsg_bad_option)( 541 "--xml=yes, but no XML destination specified", 542 "--xml=yes has been specified, but there is no XML output\n" 543 "destination. You must specify an XML output destination\n" 544 "using --xml-fd, --xml-file or --xml-socket.\n" 545 ); 546 } 547 548 // Finalise the output fds: the log fd .. 549 if (log_fd >= 0) { 550 finalize_sink_fd(&VG_(log_output_sink), log_fd, False); 551 } else { 552 // If they said --log-fd=-1, don't print anything. Plausible for use in 553 // regression testing suites that use client requests to count errors. 554 VG_(log_output_sink).fd = -1; 555 VG_(log_output_sink).type = VgLogTo_Fd; 556 } 557 558 // Finalise the output fds: and the XML fd .. 559 if (xml_fd >= 0) { 560 finalize_sink_fd(&VG_(xml_output_sink), xml_fd, True); 561 } else { 562 // If they said --xml-fd=-1, don't print anything. Plausible for use in 563 // regression testing suites that use client requests to count errors. 564 VG_(xml_output_sink).fd = -1; 565 VG_(xml_output_sink).type = VgLogTo_Fd; 566 } 567 } 568 569 /* Do the low-level send of a message to the logging sink. */ 570 static 571 void send_bytes_to_logging_sink ( OutputSink* sink, const HChar* msg, Int nbytes ) 572 { 573 if (sink->type == VgLogTo_Socket) { 574 Int rc = VG_(write_socket)( sink->fd, msg, nbytes ); 575 if (rc == -1) { 576 // For example, the listener process died. Switch back to stderr. 577 revert_sink_to_stderr(sink); 578 VG_(write)( sink->fd, msg, nbytes ); 579 } 580 } else { 581 /* sink->fd could have been set to -1 in the various 582 sys-wrappers for sys_fork, if --child-silent-after-fork=yes 583 is in effect. That is a signal that we should not produce 584 any more output. */ 585 if (sink->fd >= 0) 586 VG_(write)( sink->fd, msg, nbytes ); 587 else if (sink->fd == -2 && nbytes > 0) 588 /* send to gdb the provided data, which must be 589 a null terminated string with len >= 1 */ 590 VG_(gdb_printf)("%s", msg); 591 } 592 } 593 594 595 /* --------------------------------------------------------------------- 596 printf() and friends 597 ------------------------------------------------------------------ */ 598 599 /* --------- printf --------- */ 600 601 typedef 602 struct { 603 HChar buf[512]; 604 Int buf_used; 605 OutputSink* sink; 606 } 607 printf_buf_t; 608 609 // Adds a single char to the buffer. When the buffer gets sufficiently 610 // full, we write its contents to the logging sink. 611 static void add_to__printf_buf ( HChar c, void *p ) 612 { 613 printf_buf_t *b = (printf_buf_t *)p; 614 615 if (b->buf_used > sizeof(b->buf) - 2 ) { 616 send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); 617 b->buf_used = 0; 618 } 619 b->buf[b->buf_used++] = c; 620 b->buf[b->buf_used] = 0; 621 vg_assert(b->buf_used < sizeof(b->buf)); 622 } 623 624 static UInt vprintf_to_buf ( printf_buf_t* b, 625 const HChar *format, va_list vargs ) 626 { 627 UInt ret = 0; 628 if (b->sink->fd >= 0 || b->sink->fd == -2) { 629 ret = VG_(debugLog_vprintf) 630 ( add_to__printf_buf, b, format, vargs ); 631 } 632 return ret; 633 } 634 635 static UInt vprintf_WRK ( OutputSink* sink, 636 const HChar *format, va_list vargs ) 637 { 638 printf_buf_t myprintf_buf 639 = { "", 0, sink }; 640 UInt ret 641 = vprintf_to_buf(&myprintf_buf, format, vargs); 642 // Write out any chars left in the buffer. 643 if (myprintf_buf.buf_used > 0) { 644 send_bytes_to_logging_sink( myprintf_buf.sink, 645 myprintf_buf.buf, 646 myprintf_buf.buf_used ); 647 } 648 return ret; 649 } 650 651 UInt VG_(vprintf) ( const HChar *format, va_list vargs ) 652 { 653 return vprintf_WRK( &VG_(log_output_sink), format, vargs ); 654 } 655 656 UInt VG_(printf) ( const HChar *format, ... ) 657 { 658 UInt ret; 659 va_list vargs; 660 va_start(vargs, format); 661 ret = VG_(vprintf)(format, vargs); 662 va_end(vargs); 663 return ret; 664 } 665 666 UInt VG_(vprintf_xml) ( const HChar *format, va_list vargs ) 667 { 668 return vprintf_WRK( &VG_(xml_output_sink), format, vargs ); 669 } 670 671 UInt VG_(printf_xml) ( const HChar *format, ... ) 672 { 673 UInt ret; 674 va_list vargs; 675 va_start(vargs, format); 676 ret = VG_(vprintf_xml)(format, vargs); 677 va_end(vargs); 678 return ret; 679 } 680 681 static UInt emit_WRK ( const HChar* format, va_list vargs ) 682 { 683 if (VG_(clo_xml)) { 684 return VG_(vprintf_xml)(format, vargs); 685 } else if (VG_(log_output_sink).fd == -2) { 686 return VG_(vprintf) (format, vargs); 687 } else { 688 return VG_(vmessage)(Vg_UserMsg, format, vargs); 689 } 690 } 691 UInt VG_(emit) ( const HChar* format, ... ) 692 { 693 UInt ret; 694 va_list vargs; 695 va_start(vargs, format); 696 ret = emit_WRK(format, vargs); 697 va_end(vargs); 698 return ret; 699 } 700 701 /* --------- sprintf --------- */ 702 703 /* If we had an explicit buf structure here, it would contain only one 704 field, indicating where the next char is to go. So use p directly 705 for that, rather than having it be a pointer to a structure. */ 706 707 static void add_to__sprintf_buf ( HChar c, void *p ) 708 { 709 HChar** b = p; 710 *(*b)++ = c; 711 } 712 713 UInt VG_(vsprintf) ( HChar* buf, const HChar *format, va_list vargs ) 714 { 715 Int ret; 716 HChar* sprintf_ptr = buf; 717 718 ret = VG_(debugLog_vprintf) 719 ( add_to__sprintf_buf, &sprintf_ptr, format, vargs ); 720 add_to__sprintf_buf('\0', &sprintf_ptr); 721 722 vg_assert(VG_(strlen)(buf) == ret); 723 724 return ret; 725 } 726 727 UInt VG_(sprintf) ( HChar* buf, const HChar *format, ... ) 728 { 729 UInt ret; 730 va_list vargs; 731 va_start(vargs,format); 732 ret = VG_(vsprintf)(buf, format, vargs); 733 va_end(vargs); 734 return ret; 735 } 736 737 738 /* --------- snprintf --------- */ 739 740 /* The return value of VG_(snprintf) and VG_(vsnprintf) differs from 741 what is defined in C99. Let S be the size of the buffer as given in 742 the 2nd argument. 743 Return value R: 744 R < S: The output string was successfully written to the buffer. 745 It is null-terminated and R == strlen( output string ) 746 R == S: The supplied buffer was too small to hold the output string. 747 The first S-1 characters of the output string were written 748 to the buffer followed by the terminating null character. 749 */ 750 751 typedef 752 struct { 753 HChar* buf; 754 Int buf_size; 755 Int buf_used; 756 } 757 snprintf_buf_t; 758 759 static void add_to__snprintf_buf ( HChar c, void* p ) 760 { 761 snprintf_buf_t* b = p; 762 if (b->buf_size > 0 && b->buf_used < b->buf_size) { 763 b->buf[b->buf_used++] = c; 764 if (b->buf_used < b->buf_size) 765 b->buf[b->buf_used] = 0; 766 else 767 b->buf[b->buf_size-1] = 0; /* pre: b->buf_size > 0 */ 768 } 769 } 770 771 UInt VG_(vsnprintf) ( HChar* buf, Int size, const HChar *format, va_list vargs ) 772 { 773 snprintf_buf_t b; 774 b.buf = buf; 775 b.buf_size = size < 0 ? 0 : size; 776 b.buf_used = 0; 777 if (b.buf_size > 0) 778 b.buf[0] = 0; // ensure to null terminate buf if empty format 779 (void) VG_(debugLog_vprintf) 780 ( add_to__snprintf_buf, &b, format, vargs ); 781 782 return b.buf_used; 783 } 784 785 UInt VG_(snprintf) ( HChar* buf, Int size, const HChar *format, ... ) 786 { 787 UInt ret; 788 va_list vargs; 789 va_start(vargs,format); 790 ret = VG_(vsnprintf)(buf, size, format, vargs); 791 va_end(vargs); 792 return ret; 793 } 794 795 796 /* --------- vcbprintf --------- */ 797 798 void VG_(vcbprintf)( void(*char_sink)(HChar, void* opaque), 799 void* opaque, 800 const HChar* format, va_list vargs ) 801 { 802 (void) VG_(debugLog_vprintf) 803 ( char_sink, opaque, format, vargs ); 804 } 805 806 807 /* --------- fprintf ---------- */ 808 809 /* This is like [v]fprintf, except it writes to a file handle using 810 VG_(write). */ 811 812 #define VGFILE_BUFSIZE 8192 813 814 struct _VgFile { 815 HChar buf[VGFILE_BUFSIZE]; 816 UInt num_chars; // number of characters in buf 817 Int fd; // file descriptor to write to 818 }; 819 820 821 static void add_to__vgfile ( HChar c, void *p ) 822 { 823 VgFile *fp = p; 824 825 fp->buf[fp->num_chars++] = c; 826 827 if (fp->num_chars == VGFILE_BUFSIZE) { 828 VG_(write)(fp->fd, fp->buf, fp->num_chars); 829 fp->num_chars = 0; 830 } 831 } 832 833 VgFile *VG_(fopen)(const HChar *name, Int flags, Int mode) 834 { 835 SysRes res = VG_(open)(name, flags, mode); 836 837 if (sr_isError(res)) 838 return NULL; 839 840 VgFile *fp = VG_(malloc)("fopen", sizeof(VgFile)); 841 842 fp->fd = sr_Res(res); 843 fp->num_chars = 0; 844 845 return fp; 846 } 847 848 849 UInt VG_(vfprintf) ( VgFile *fp, const HChar *format, va_list vargs ) 850 { 851 return VG_(debugLog_vprintf)(add_to__vgfile, fp, format, vargs); 852 } 853 854 UInt VG_(fprintf) ( VgFile *fp, const HChar *format, ... ) 855 { 856 UInt ret; 857 va_list vargs; 858 va_start(vargs,format); 859 ret = VG_(vfprintf)(fp, format, vargs); 860 va_end(vargs); 861 return ret; 862 } 863 864 void VG_(fclose)( VgFile *fp ) 865 { 866 // Flush the buffer. 867 if (fp->num_chars) 868 VG_(write)(fp->fd, fp->buf, fp->num_chars); 869 870 VG_(close)(fp->fd); 871 VG_(free)(fp); 872 } 873 874 875 /* --------------------------------------------------------------------- 876 elapsed_wallclock_time() 877 ------------------------------------------------------------------ */ 878 879 /* Get the elapsed wallclock time since startup into buf, which must 880 16 chars long. This is unchecked. It also relies on the 881 millisecond timer having been set to zero by an initial read in 882 m_main during startup. */ 883 884 void VG_(elapsed_wallclock_time) ( /*OUT*/HChar* buf, SizeT bufsize ) 885 { 886 UInt t, ms, s, mins, hours, days; 887 888 vg_assert(bufsize > 20); 889 890 t = VG_(read_millisecond_timer)(); /* milliseconds */ 891 892 ms = t % 1000; 893 t /= 1000; /* now in seconds */ 894 895 s = t % 60; 896 t /= 60; /* now in minutes */ 897 898 mins = t % 60; 899 t /= 60; /* now in hours */ 900 901 hours = t % 24; 902 t /= 24; /* now in days */ 903 904 days = t; 905 906 VG_(sprintf)(buf, "%02u:%02u:%02u:%02u.%03u ", days, hours, mins, s, ms); 907 } 908 909 910 /* --------------------------------------------------------------------- 911 message() 912 ------------------------------------------------------------------ */ 913 914 /* A buffer for accumulating VG_(message) style output. This is 915 pretty much the same as VG_(printf)'s scheme, with two differences: 916 917 * The message buffer persists between calls, so that multiple 918 calls to VG_(message) can build up output. 919 920 * Whenever the first character on a line is emitted, the 921 ==PID== style preamble is stuffed in before it. 922 */ 923 typedef 924 struct { 925 HChar buf[512+128]; 926 Int buf_used; 927 Bool atLeft; /* notionally, is the next char position at the 928 leftmost column? */ 929 /* Current message kind - changes from call to call */ 930 VgMsgKind kind; 931 /* destination */ 932 OutputSink* sink; 933 } 934 vmessage_buf_t; 935 936 static vmessage_buf_t vmessage_buf 937 = { "", 0, True, Vg_UserMsg, &VG_(log_output_sink) }; 938 939 940 // Adds a single char to the buffer. We aim to have at least 128 941 // bytes free in the buffer, so that it's always possible to emit 942 // the preamble into the buffer if c happens to be the character 943 // following a \n. When the buffer gets too full, we write its 944 // contents to the logging sink. 945 static void add_to__vmessage_buf ( HChar c, void *p ) 946 { 947 HChar tmp[64]; 948 vmessage_buf_t* b = (vmessage_buf_t*)p; 949 950 vg_assert(b->buf_used >= 0 && b->buf_used < sizeof(b->buf)-128); 951 952 if (UNLIKELY(b->atLeft)) { 953 // insert preamble 954 HChar ch; 955 Int i, depth; 956 957 // Print one '>' in front of the messages for each level of 958 // self-hosting being performed. 959 // Do not print such '>' if sim hint "no-inner-prefix" given 960 // (useful to run regression tests in an outer/inner setup 961 // and avoid the diff failing due to these unexpected '>'). 962 depth = RUNNING_ON_VALGRIND; 963 if (depth > 0 964 && !SimHintiS(SimHint_no_inner_prefix, VG_(clo_sim_hints))) { 965 if (depth > 10) 966 depth = 10; // ?!?! 967 for (i = 0; i < depth; i++) { 968 b->buf[b->buf_used++] = '>'; 969 } 970 } 971 972 if (Vg_FailMsg == b->kind) { 973 // "valgrind: " prefix. 974 b->buf[b->buf_used++] = 'v'; 975 b->buf[b->buf_used++] = 'a'; 976 b->buf[b->buf_used++] = 'l'; 977 b->buf[b->buf_used++] = 'g'; 978 b->buf[b->buf_used++] = 'r'; 979 b->buf[b->buf_used++] = 'i'; 980 b->buf[b->buf_used++] = 'n'; 981 b->buf[b->buf_used++] = 'd'; 982 b->buf[b->buf_used++] = ':'; 983 b->buf[b->buf_used++] = ' '; 984 } else { 985 switch (b->kind) { 986 case Vg_UserMsg: ch = '='; break; 987 case Vg_DebugMsg: ch = '-'; break; 988 case Vg_ClientMsg: ch = '*'; break; 989 default: ch = '?'; break; 990 } 991 992 b->buf[b->buf_used++] = ch; 993 b->buf[b->buf_used++] = ch; 994 995 if (VG_(clo_time_stamp)) { 996 VG_(elapsed_wallclock_time)(tmp, sizeof tmp); 997 for (i = 0; tmp[i]; i++) 998 b->buf[b->buf_used++] = tmp[i]; 999 } 1000 1001 VG_(sprintf)(tmp, "%d", VG_(getpid)()); 1002 tmp[sizeof(tmp)-1] = 0; 1003 for (i = 0; tmp[i]; i++) 1004 b->buf[b->buf_used++] = tmp[i]; 1005 1006 b->buf[b->buf_used++] = ch; 1007 b->buf[b->buf_used++] = ch; 1008 b->buf[b->buf_used++] = ' '; 1009 } 1010 1011 /* We can't possibly have stuffed 96 chars in merely as a result 1012 of making the preamble (can we?) */ 1013 vg_assert(b->buf_used < sizeof(b->buf)-32); 1014 } 1015 1016 b->buf[b->buf_used++] = c; 1017 b->buf[b->buf_used] = 0; 1018 1019 if (b->buf_used >= sizeof(b->buf) - 128) { 1020 send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); 1021 b->buf_used = 0; 1022 } 1023 1024 b->atLeft = c == '\n'; 1025 } 1026 1027 1028 UInt VG_(vmessage) ( VgMsgKind kind, const HChar* format, va_list vargs ) 1029 { 1030 UInt ret; 1031 1032 /* Note (carefully) that the buf persists from call to call, unlike 1033 with the other printf variants in earlier parts of this file. */ 1034 vmessage_buf_t* b = &vmessage_buf; /* shorthand for convenience */ 1035 1036 /* We have to set this each call, so that the correct flavour 1037 of preamble is emitted at each \n. */ 1038 b->kind = kind; 1039 1040 ret = VG_(debugLog_vprintf) ( add_to__vmessage_buf, 1041 b, format, vargs ); 1042 1043 /* If the message finished exactly with a \n, then flush it at this 1044 point. If not, assume more bits of the same line will turn up 1045 in later messages, so don't bother to flush it right now. */ 1046 1047 if (b->atLeft && b->buf_used > 0) { 1048 send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); 1049 b->buf_used = 0; 1050 } 1051 1052 return ret; 1053 } 1054 1055 /* Send a simple single-part message. */ 1056 UInt VG_(message) ( VgMsgKind kind, const HChar* format, ... ) 1057 { 1058 UInt count; 1059 va_list vargs; 1060 va_start(vargs,format); 1061 count = VG_(vmessage) ( kind, format, vargs ); 1062 va_end(vargs); 1063 return count; 1064 } 1065 1066 static void revert_to_stderr ( void ) 1067 { 1068 revert_sink_to_stderr(&VG_(log_output_sink)); 1069 } 1070 1071 /* VG_(message) variants with hardwired first argument. */ 1072 1073 UInt VG_(fmsg) ( const HChar* format, ... ) 1074 { 1075 UInt count; 1076 va_list vargs; 1077 va_start(vargs,format); 1078 count = VG_(vmessage) ( Vg_FailMsg, format, vargs ); 1079 va_end(vargs); 1080 return count; 1081 } 1082 1083 void VG_(fmsg_bad_option) ( const HChar* opt, const HChar* format, ... ) 1084 { 1085 va_list vargs; 1086 va_start(vargs,format); 1087 revert_to_stderr(); 1088 VG_(message) (Vg_FailMsg, "Bad option: %s\n", opt); 1089 VG_(vmessage)(Vg_FailMsg, format, vargs ); 1090 VG_(message) (Vg_FailMsg, "Use --help for more information or consult the user manual.\n"); 1091 va_end(vargs); 1092 VG_(exit)(1); 1093 } 1094 1095 void VG_(fmsg_unknown_option) ( const HChar* opt) 1096 { 1097 revert_to_stderr(); 1098 VG_(message) (Vg_FailMsg, "Unknown option: %s\n", opt); 1099 VG_(message) (Vg_FailMsg, "Use --help for more information or consult the user manual.\n"); 1100 VG_(exit)(1); 1101 } 1102 1103 UInt VG_(umsg) ( const HChar* format, ... ) 1104 { 1105 UInt count; 1106 va_list vargs; 1107 va_start(vargs,format); 1108 count = VG_(vmessage) ( Vg_UserMsg, format, vargs ); 1109 va_end(vargs); 1110 return count; 1111 } 1112 1113 UInt VG_(dmsg) ( const HChar* format, ... ) 1114 { 1115 UInt count; 1116 va_list vargs; 1117 va_start(vargs,format); 1118 count = VG_(vmessage) ( Vg_DebugMsg, format, vargs ); 1119 va_end(vargs); 1120 return count; 1121 } 1122 1123 /* Flush any output that has accumulated in vmessage_buf as a 1124 result of previous calls to VG_(message) et al. */ 1125 void VG_(message_flush) ( void ) 1126 { 1127 vmessage_buf_t* b = &vmessage_buf; 1128 send_bytes_to_logging_sink( b->sink, b->buf, b->buf_used ); 1129 b->buf_used = 0; 1130 } 1131 1132 __attribute__((noreturn)) 1133 void VG_(err_missing_prog) ( void ) 1134 { 1135 revert_to_stderr(); 1136 VG_(fmsg)("no program specified\n"); 1137 VG_(fmsg)("Use --help for more information.\n"); 1138 VG_(exit)(1); 1139 } 1140 1141 __attribute__((noreturn)) 1142 void VG_(err_config_error) ( const HChar* format, ... ) 1143 { 1144 va_list vargs; 1145 va_start(vargs,format); 1146 revert_to_stderr(); 1147 VG_(message) (Vg_FailMsg, "Startup or configuration error:\n "); 1148 VG_(vmessage)(Vg_FailMsg, format, vargs ); 1149 VG_(message) (Vg_FailMsg, "Unable to start up properly. Giving up.\n"); 1150 va_end(vargs); 1151 VG_(exit)(1); 1152 } 1153 1154 /* --------------------------------------------------------------------- 1155 VG_(sr_as_string)() 1156 ------------------------------------------------------------------ */ 1157 1158 #if defined(VGO_linux) 1159 // FIXME: Does this function need to be adjusted for MIPS's _valEx ? 1160 const HChar *VG_(sr_as_string) ( SysRes sr ) 1161 { 1162 static HChar buf[7+1+2+16+1+1]; // large enough 1163 1164 if (sr_isError(sr)) 1165 VG_(sprintf)(buf, "Failure(0x%lx)", sr_Err(sr)); 1166 else 1167 VG_(sprintf)(buf, "Success(0x%lx)", sr_Res(sr)); 1168 return buf; 1169 } 1170 1171 #elif defined(VGO_darwin) || defined(VGO_solaris) 1172 1173 const HChar *VG_(sr_as_string) ( SysRes sr ) 1174 { 1175 static HChar buf[7+1+2+16+1+2+16+1+1]; // large enough 1176 1177 if (sr_isError(sr)) 1178 VG_(sprintf)(buf, "Failure(0x%lx)", sr_Err(sr)); 1179 else 1180 VG_(sprintf)(buf, "Success(0x%lx:0x%lx)", sr_ResHI(sr), sr_Res(sr)); 1181 return buf; 1182 } 1183 1184 #else 1185 1186 #error unknown OS 1187 1188 #endif 1189 1190 /*--------------------------------------------------------------------*/ 1191 /*--- end ---*/ 1192 /*--------------------------------------------------------------------*/ 1193
