1 /******************************************************************************
2 * Copyright (c) 2000-2016 Ericsson Telecom AB
3 * All rights reserved. This program and the accompanying materials
4 * are made available under the terms of the Eclipse Public License v1.0
5 * which accompanies this distribution, and is available at
6 * http://www.eclipse.org/legal/epl-v10.html
18 ******************************************************************************/
19 #include "LegacyLogger.hh"
21 #include "TitanLoggerApi.hh"
22 #include "Component.hh"
24 #include "ILoggerPlugin.hh"
25 #include "LoggingBits.hh"
26 #include "Communication.hh"
29 #include "../common/version_internal.h"
34 #include <sys/types.h>
37 // for WIFEXITED & co.
42 typedef long suseconds_t
;
47 // It's a static plug-in, destruction is done in the destructor. We need
48 // `extern "C"' for some reason.
49 ILoggerPlugin
*create_legacy_logger() { return new LegacyLogger(); }
53 static char *event_to_str(const TitanLoggerApi::TitanLogEvent
& event
,
54 bool without_header
= false);
55 static char *append_header(char *ret_val
, const struct timeval
& timestamp
,
56 const TTCN_Logger::Severity severity
,
57 const char *sourceinfo
);
59 static void timer_event_str(char *& ret_val
, const TitanLoggerApi::TimerEvent_choice
& tec
);
60 static void defaultop_event_str(char *& ret_val
, const TitanLoggerApi::DefaultEvent_choice
& dec
);
61 static void executor_event_str(char *& ret_val
, const TitanLoggerApi::ExecutorEvent_choice
& eec
);
62 static void portevent_str(char *& ret_val
, const TitanLoggerApi::PortEvent_choice
& pec
);
63 //void extcommand_str(char *& ret_val, const TitanLoggerApi::ExecutorEvent_choice& choice);
64 static void matchingop_str(char *& ret_val
, const TitanLoggerApi::MatchingEvent_choice
& choice
);
65 static void parallel_str(char *& ret_val
, const TitanLoggerApi::ParallelEvent_choice
& choice
);
66 static void testcaseop_str(char *& ret_val
, const TitanLoggerApi::TestcaseEvent_choice
& choice
);
67 static void verdictop_str(char *& ret_val
, const TitanLoggerApi::VerdictOp_choice
& choice
);
68 static void statistics_str(char *& ret_val
, const TitanLoggerApi::StatisticsType_choice
& choice
);
70 namespace API
= TitanLoggerApi
;
72 // Defined in Logger.cc. Compares the name or the component identifier.
73 extern bool operator==(const component_id_t
& left
,
74 const component_id_t
& right
);
76 LegacyLogger
* LegacyLogger::myself
= 0;
78 LegacyLogger::LegacyLogger()
79 : log_fp_(NULL
), er_(NULL
), logfile_bytes_(0), logfile_size_(0), logfile_number_(1),
80 logfile_index_(1), filename_skeleton_(NULL
), skeleton_given_(false),
81 append_file_(false), is_disk_full_(false), format_c_present_(false),
82 format_t_present_(false), current_filename_(NULL
)
86 // A déjà vu is usually a glitch in the Matrix.
87 // It happens when they change something.
88 fputs("Only one LegacyLogger allowed! Aborting.\n", stderr
);
89 abort(); // Don't use TTCN_error. Debugging infinite recursion is not fun.
94 this->name_
= mputstr(this->name_
, "LegacyLogger");
95 this->help_
= mputstr(this->help_
, "LegacyLogger");
96 this->disk_full_action_
.type
= TTCN_Logger::DISKFULL_ERROR
;
97 this->disk_full_action_
.retry_interval
= 0;
100 LegacyLogger::~LegacyLogger()
102 assert(this->name_
&& this->help_
);
107 Free(this->filename_skeleton_
);
108 this->filename_skeleton_
= NULL
;
109 Free(this->current_filename_
);
110 this->current_filename_
= NULL
;
115 void LegacyLogger::reset()
117 this->disk_full_action_
.type
= TTCN_Logger::DISKFULL_ERROR
;
118 this->disk_full_action_
.retry_interval
= 0;
119 this->logfile_size_
= 0;
120 this->logfile_number_
= 1;
121 this->logfile_bytes_
= 0;
122 this->logfile_index_
= 1;
123 this->is_disk_full_
= false;
124 this->skeleton_given_
= false;
125 this->append_file_
= false;
126 this->is_configured_
= false;
129 void LegacyLogger::init(const char */
*options*/
)
131 // Print some version information, handle general options etc. later...
134 void LegacyLogger::fini()
139 void LegacyLogger::fatal_error(const char *err_msg
, ...)
141 fputs("Fatal error during logging: ", stderr
);
143 va_start(p_var
, err_msg
);
144 vfprintf(stderr
, err_msg
, p_var
);
147 const char *error_string
= strerror(errno
);
148 if (error_string
!= NULL
) fprintf(stderr
, " (%s)", error_string
);
149 else fprintf(stderr
, " (Unknown error: errno = %d)", errno
);
152 fputs(" Exiting.\n", stderr
);
156 /** @brief Log a message to the log file and console (if required).
160 If the log file is open (\c is_configured is TRUE), it calls
161 should_log_to_file() to decide whether logging to file is wanted; calls
162 log_file(), which calls log_to_file() if affirmative.
164 If the log file is not open (\c is_configured is FALSE), it stores the
165 message until the file is opened.
167 For logging to the console:
169 If should_log_to_console() returns TRUE, sends the log message to the main
170 controller via TTCN_Communication::send_log() and possibly writes it to
171 the standard error depending on the return value.
174 @param [in] log_buffered
176 void LegacyLogger::log(const TitanLoggerApi::TitanLogEvent
& event
,
177 bool log_buffered
, bool separate_file
, bool use_emergency_mask
)
179 const TTCN_Logger::Severity
& severity
= (const TTCN_Logger::Severity
)(int)event
.severity();
182 log_file_emerg(event
);
184 if (use_emergency_mask
) {
185 if (TTCN_Logger::should_log_to_emergency(severity
)
187 TTCN_Logger::should_log_to_file(severity
))
189 log_file(event
, log_buffered
);
191 if (TTCN_Logger::should_log_to_console(severity
)) {
192 log_console(event
, severity
);
196 if (TTCN_Logger::should_log_to_file(severity
)) {
197 log_file(event
, log_buffered
);
199 if (TTCN_Logger::should_log_to_console(severity
)) {
200 log_console(event
, severity
);
206 bool LegacyLogger::log_file_emerg(const TitanLoggerApi::TitanLogEvent
& event
)
208 bool write_success
= true;
209 char *event_str
= event_to_str(event
);
210 if (event_str
== NULL
) {
211 TTCN_warning("No text for event");
214 size_t bytes_to_log
= mstrlen(event_str
);
217 char *filename_emergency
= get_file_name(0);
219 if (filename_emergency
== NULL
) {
220 // Valid filename is not available, use specific one.
221 filename_emergency
= mcopystr("emergency.log");
223 filename_emergency
= mputprintf(filename_emergency
, "_emergency");
225 er_
= fopen(filename_emergency
, "w");
228 fatal_error("Opening of log file `%s' for writing failed.",
231 Free(filename_emergency
);
234 write_success
= true;
236 if (bytes_to_log
> 0 && fwrite(event_str
, bytes_to_log
, 1, er_
) != 1)
237 write_success
= false;
245 return write_success
;
248 /** @brief Logs a message to the already opened log file.
249 @pre The log file is already open.
251 Writes the timestamp in the appropriate format, the event type (severity)
252 if needed, the source information if available, the message and a newline.
254 @param [in] event a properly initialized TITAN log event
255 @param [in] log_buffered TRUE if this is a buffered message, used to avoid
256 possible recursion of log_to_file() -> open_file() ->
257 log_to_file() -> open_file() -> ...
259 bool LegacyLogger::log_file(const TitanLoggerApi::TitanLogEvent
& event
,
262 if (!this->log_fp_
) return false;
264 struct timeval event_timestamp
= { (time_t)event
.timestamp().seconds(),
265 (suseconds_t
)event
.timestamp().microSeconds() };
266 if (this->is_disk_full_
) {
267 if (this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
) {
269 // If the specified time period has elapsed retry logging to file.
270 if (event_timestamp
.tv_usec
< this->disk_full_time_
.tv_usec
) {
271 diff
.tv_sec
= event_timestamp
.tv_sec
-
272 this->disk_full_time_
.tv_sec
- 1;
273 diff
.tv_usec
= event_timestamp
.tv_usec
+
274 (1000000L - this->disk_full_time_
.tv_usec
);
276 diff
.tv_sec
= event_timestamp
.tv_sec
- this->disk_full_time_
.tv_sec
;
277 diff
.tv_usec
= event_timestamp
.tv_usec
-
278 this->disk_full_time_
.tv_usec
;
280 if ((size_t)diff
.tv_sec
>= this->disk_full_action_
.retry_interval
)
281 this->is_disk_full_
= false;
288 // Check if there is a size limitation and the file is not empty, if the
289 // file is still empty the size limitation is ignored. If the size
290 // limitation is reached open a new log file and check the file number
291 // limitation. When writing the buffered messages the file size limitation
292 // is ignored. TODO: Replace length calculation with custom function call.
293 // Event buffering is not necessarily implemented in the plug-ins.
294 char *event_str
= event_to_str(event
);
295 if (event_str
== NULL
) {
296 TTCN_warning("No text for event");
299 size_t bytes_to_log
= mstrlen(event_str
) + 1;
300 if (this->logfile_size_
!= 0 && this->logfile_bytes_
!= 0 && !log_buffered
) {
301 if ((bytes_to_log
+ this->logfile_bytes_
+ 1023) / 1024 > this->logfile_size_
) {
302 // Close current log file and open the next one.
304 this->logfile_index_
++;
305 // Delete oldest log file if there is a file number limitation.
306 if (this->logfile_number_
> 1) {
307 if (this->logfile_index_
> this->logfile_number_
) {
308 char* filename_to_delete
=
309 get_file_name(this->logfile_index_
- this->logfile_number_
);
310 remove(filename_to_delete
);
311 Free(filename_to_delete
);
318 if (!log_buffered
&& (this->format_c_present_
|| this->format_t_present_
)) {
319 switch (TTCN_Runtime::get_state()) {
320 case TTCN_Runtime::HC_EXIT
:
321 case TTCN_Runtime::MTC_EXIT
:
322 case TTCN_Runtime::PTC_EXIT
:
323 // Can't call get_filename(), because it may call
324 // TTCN_Runtime::get_host_name(), and TTCN_Runtime::clean_up() (which is
325 // called once) has already happened.
328 char *new_filename
= get_file_name(this->logfile_index_
);
329 if (strcmp(new_filename
, this->current_filename_
)) {
330 // Different file name, have to switch. Reuse timestamp etc. of the
332 expstring_t switched
= mprintf("Switching to log file `%s'",
334 TitanLoggerApi::TitanLogEvent switched_event
;
335 switched_event
.timestamp() = event
.timestamp();
336 switched_event
.sourceInfo__list() = event
.sourceInfo__list();
337 switched_event
.severity() = (int)TTCN_Logger::EXECUTOR_RUNTIME
;
338 switched_event
.logEvent().choice().unhandledEvent() =
339 CHARSTRING(switched
);
340 log_file(switched_event
, true);
343 open_file(false); // calls get_filename again :(
350 // Write out the event_str, if it failed assume that the disk is full, then
351 // act according to DiskFullAction.
352 bool print_success
= log_to_file(event_str
);
353 if (!print_success
) {
354 switch (this->disk_full_action_
.type
) {
355 case TTCN_Logger::DISKFULL_ERROR
:
356 fatal_error("Writing to log file failed.");
357 case TTCN_Logger::DISKFULL_STOP
:
358 this->is_disk_full_
= true;
360 case TTCN_Logger::DISKFULL_RETRY
:
361 this->is_disk_full_
= true;
362 // Time of failure. TODO: Find a better way to transfer the timestamp.
363 this->disk_full_time_
.tv_sec
= event
.timestamp().seconds();
364 this->disk_full_time_
.tv_usec
= event
.timestamp().microSeconds();
366 case TTCN_Logger::DISKFULL_DELETE
:
367 // Try to delete older logfiles while writing fails, must leave at least
368 // two log files. Stop with error if cannot delete more files and
370 if (this->logfile_number_
== 0)
371 this->logfile_number_
= this->logfile_index_
;
372 while (!print_success
&& this->logfile_number_
> 2) {
373 this->logfile_number_
--;
374 if (this->logfile_index_
> this->logfile_number_
) {
375 char *filename_to_delete
=
376 get_file_name(this->logfile_index_
- this->logfile_number_
);
377 int remove_ret_val
= remove(filename_to_delete
);
378 Free(filename_to_delete
);
379 // File deletion failed.
380 if (remove_ret_val
!= 0) break;
381 print_success
= log_to_file(event_str
);
385 fatal_error("Writing to log file failed.");
386 else this->logfile_bytes_
+= bytes_to_log
;
389 fatal_error("LegacyLogger::log(): invalid DiskFullAction type.");
392 this->logfile_bytes_
+= bytes_to_log
;
398 bool LegacyLogger::log_console(const TitanLoggerApi::TitanLogEvent
& event
,
399 const TTCN_Logger::Severity
& severity
)
401 char *event_str
= event_to_str(event
, true);
402 if (event_str
== NULL
) {
403 TTCN_warning("No text for event");
406 size_t event_str_len
= mstrlen(event_str
);
407 if (!TTCN_Communication::send_log((time_t)event
.timestamp().seconds(),
408 (suseconds_t
)event
.timestamp().microSeconds(), severity
,
409 event_str_len
, event_str
)) {
410 // The event text shall be printed to stderr when there is no control
411 // connection towards MC (e.g. in single mode or in case of network
413 if (event_str_len
> 0) {
414 // Write the location info to the console for user logs only.
415 // TODO: some switch to turn on/off source info on console.
416 // Perhaps None/User/All?
418 if (TTCN_Logger::USER_UNQUALIFIED
== severity
&& ':' == *event_str
419 && (stackdepth
= event
.sourceInfo__list().lengthof()) > 0) {
420 API::LocationInfo
const& loc
= event
.sourceInfo__list()[stackdepth
-1];
421 if (fprintf(stderr
, "%s:%d", (const char*)loc
.filename(), (int)loc
.line()) < 0)
422 fatal_error("fprintf(sourceinfo) call failed on stderr. %s",
426 if (fwrite(event_str
, event_str_len
, 1, stderr
) != 1)
427 fatal_error("fwrite(message) call failed on stderr. %s",
430 if (putc('\n', stderr
) == EOF
)
431 fatal_error("putc() call failed on stderr. %s", strerror(errno
));
438 bool LegacyLogger::log_to_file(const char *message_ptr
)
440 // Retry and Delete: To avoid writing partial messages remember the initial
441 // file position to be able to remove partial message if writing failed.
443 int fgetpos_ret_val
= 0;
444 if (this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
||
445 this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_DELETE
) {
446 fgetpos_ret_val
= fgetpos(this->log_fp_
, &initial_pos
);
448 size_t message_len
= strlen(message_ptr
);
449 bool write_success
= true;
450 if (message_len
> 0 &&
451 fwrite(message_ptr
, message_len
, 1, this->log_fp_
) != 1)
452 write_success
= false;
453 if (write_success
&& putc('\n', this->log_fp_
) == EOF
) write_success
= false;
454 if (write_success
&& fflush(this->log_fp_
)) write_success
= false;
455 if ((this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
||
456 this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_DELETE
) &&
457 !write_success
&& fgetpos_ret_val
== 0) {
458 // Overwrite with spaces until EOF.
459 fsetpos(this->log_fp_
, &initial_pos
);
460 while (!feof(this->log_fp_
)) if (putc(' ', this->log_fp_
) == EOF
) break;
461 fsetpos(this->log_fp_
, &initial_pos
);
463 return write_success
;
466 char *append_header(char *ret_val
,
467 const struct timeval
& timestamp
, const TTCN_Logger::Severity severity
,
468 const char *sourceinfo
)
470 ret_val
= TTCN_Logger::mputstr_timestamp(ret_val
,
471 TTCN_Logger::get_timestamp_format(), ×tamp
);
472 ret_val
= mputc(ret_val
, ' ');
474 if (TTCN_Logger::get_log_event_types() != TTCN_Logger::LOGEVENTTYPES_NO
) {
475 ret_val
= TTCN_Logger::mputstr_severity(ret_val
, severity
);
476 if (TTCN_Logger::get_log_event_types() ==
477 TTCN_Logger::LOGEVENTTYPES_SUBCATEGORIES
)
478 ret_val
= mputprintf(ret_val
, "_%s",
479 TTCN_Logger::severity_subcategory_names
[severity
]);
480 ret_val
= mputc(ret_val
, ' ');
483 if (sourceinfo
!= NULL
)
484 ret_val
= mputprintf(ret_val
, "%s ", sourceinfo
);
490 #pragma GCC diagnostic push
491 #pragma GCC diagnostic error "-Wswitch-enum"
492 // Use the compiler to verify that all enum values are handled in switches.
493 // Wswitch-enum will report those even if there is a "default" label.
496 void timer_event_str(char *& ret_val
, const TitanLoggerApi::TimerEvent_choice
& tec
)
498 switch (tec
.get_selection()) {
499 case TitanLoggerApi::TimerEvent_choice::ALT_readTimer
: {
500 const TitanLoggerApi::TimerType
& timer
= tec
.readTimer();
501 ret_val
= mputprintf(ret_val
, "Read timer %s: %g s",
502 (const char *)timer
.name(), (double)timer
.value__());
505 case TitanLoggerApi::TimerEvent_choice::ALT_startTimer
: {
506 const TitanLoggerApi::TimerType
& timer
= tec
.startTimer();
507 ret_val
= mputprintf(ret_val
, "Start timer %s: %g s",
508 (const char *)timer
.name(), (double)timer
.value__());
511 case TitanLoggerApi::TimerEvent_choice::ALT_guardTimer
: {
512 const TitanLoggerApi::TimerGuardType
& timer
= tec
.guardTimer();
513 ret_val
= mputprintf(ret_val
, "Test case guard timer was set to %g s.",
514 (double)timer
.value__());
517 case TitanLoggerApi::TimerEvent_choice::ALT_stopTimer
: {
518 const TitanLoggerApi::TimerType
& timer
= tec
.stopTimer();
519 ret_val
= mputprintf(ret_val
, "Stop timer %s: %g s",
520 (const char *)timer
.name(), (double)timer
.value__());
523 case TitanLoggerApi::TimerEvent_choice::ALT_timeoutTimer
: {
524 const TitanLoggerApi::TimerType
& timer
= tec
.timeoutTimer();
525 ret_val
= mputprintf(ret_val
, "Timeout %s: %g s",
526 (const char *)timer
.name(), (double)timer
.value__());
529 case TitanLoggerApi::TimerEvent_choice::ALT_timeoutAnyTimer
: {
530 ret_val
= mputstr(ret_val
, "Operation `any timer.timeout' was successful.");
533 case TitanLoggerApi::TimerEvent_choice::ALT_unqualifiedTimer
: {
534 ret_val
= mputstr(ret_val
, (const char *)tec
.unqualifiedTimer());
537 case TitanLoggerApi::TimerEvent_choice::UNBOUND_VALUE
:
544 void defaultop_event_str(char *& ret_val
, const TitanLoggerApi::DefaultEvent_choice
& dec
)
546 switch (dec
.get_selection()) {
547 case TitanLoggerApi::DefaultEvent_choice::ALT_defaultopActivate
: {
548 TitanLoggerApi::DefaultOp
const& dflt
= dec
.defaultopActivate();
549 ret_val
= mputprintf(ret_val
, "Altstep %s was activated as default, id %u",
550 (const char*)dflt
.name(), (int)dflt
.id());
552 case TitanLoggerApi::DefaultEvent_choice::ALT_defaultopDeactivate
: {
553 TitanLoggerApi::DefaultOp
const& dflt
= dec
.defaultopDeactivate();
554 if (dflt
.name().lengthof()) ret_val
= mputprintf(ret_val
,
555 "Default with id %u (altstep %s) was deactivated.",
556 (int)dflt
.id(), (const char*)dflt
.name());
557 else ret_val
= mputprintf(ret_val
,
558 "Deactivate operation on a null default reference was ignored.");
560 case TitanLoggerApi::DefaultEvent_choice::ALT_defaultopExit
: {
561 TitanLoggerApi::DefaultOp
const& dflt
= dec
.defaultopExit();
562 // First the common part
563 ret_val
= mputprintf(ret_val
, "Default with id %u (altstep %s) ",
564 (int)dflt
.id(), (const char*)dflt
.name());
567 switch (dflt
.end()) {
568 case TitanLoggerApi::DefaultEnd::UNBOUND_VALUE
:
569 case TitanLoggerApi::DefaultEnd::UNKNOWN_VALUE
:
570 // Something has gone horribly wrong
573 case TitanLoggerApi::DefaultEnd::finish
:
574 ret_val
= mputstr(ret_val
, "finished. Skipping current alt statement "
575 "or receiving operation.");
577 case TitanLoggerApi::DefaultEnd::break__
:
578 ret_val
= mputstr(ret_val
, "has reached a repeat statement.");
580 case TitanLoggerApi::DefaultEnd::repeat__
:
581 ret_val
= mputstr(ret_val
, "has reached a break statement."
582 " Skipping current alt statement or receiving operation.");
587 case TitanLoggerApi::DefaultEvent_choice::UNBOUND_VALUE
:
594 void executor_event_str(char *& ret_val
, const TitanLoggerApi::ExecutorEvent_choice
& eec
)
596 switch (eec
.get_selection()) {
597 case API::ExecutorEvent_choice::ALT_executorRuntime
: {
598 TitanLoggerApi::ExecutorRuntime
const& rt
= eec
.executorRuntime();
599 // another monster-switch
600 switch (rt
.reason()) {
601 case TitanLoggerApi::ExecutorRuntime_reason::UNBOUND_VALUE
:
602 case TitanLoggerApi::ExecutorRuntime_reason::UNKNOWN_VALUE
:
605 case TitanLoggerApi::ExecutorRuntime_reason::connected__to__mc
:
606 ret_val
= mputstr(ret_val
, "Connected to MC.");
608 case TitanLoggerApi::ExecutorRuntime_reason::disconnected__from__mc
:
609 ret_val
= mputstr(ret_val
, "Disconnected from MC.");
611 case TitanLoggerApi::ExecutorRuntime_reason::initialization__of__modules__failed
:
612 ret_val
= mputstr(ret_val
, "Initialization of modules failed.");
614 case TitanLoggerApi::ExecutorRuntime_reason::exit__requested__from__mc__hc
:
615 ret_val
= mputstr(ret_val
, "Exit was requested from MC. Terminating HC.");
617 case TitanLoggerApi::ExecutorRuntime_reason::exit__requested__from__mc__mtc
:
618 ret_val
= mputstr(ret_val
, "Exit was requested from MC. Terminating MTC.");
620 case TitanLoggerApi::ExecutorRuntime_reason::stop__was__requested__from__mc
:
621 ret_val
= mputstr(ret_val
, "Stop was requested from MC.");
623 case TitanLoggerApi::ExecutorRuntime_reason::stop__was__requested__from__mc__ignored__on__idle__mtc
:
624 ret_val
= mputstr(ret_val
, "Stop was requested from MC. Ignored on idle MTC.");
626 case TitanLoggerApi::ExecutorRuntime_reason::stop__was__requested__from__mc__ignored__on__idle__ptc
:
627 ret_val
= mputstr(ret_val
, "Stop was requested from MC. Ignored on idle PTC.");
629 case TitanLoggerApi::ExecutorRuntime_reason::executing__testcase__in__module
:
630 ret_val
= mputprintf(ret_val
, "Executing test case %s in module %s.",
631 (const char *)rt
.testcase__name()(), (const char *)rt
.module__name()());
633 case TitanLoggerApi::ExecutorRuntime_reason::performing__error__recovery
:
634 ret_val
= mputstr(ret_val
, "Performing error recovery.");
636 case TitanLoggerApi::ExecutorRuntime_reason::executor__start__single__mode
:
637 ret_val
= mputstr(ret_val
, "TTCN-3 Test Executor "
638 "started in single mode. Version: " PRODUCT_NUMBER
".");
640 case TitanLoggerApi::ExecutorRuntime_reason::executor__finish__single__mode
:
641 ret_val
= mputstr(ret_val
, "TTCN-3 Test Executor finished in single mode.");
643 case TitanLoggerApi::ExecutorRuntime_reason::exiting
:
644 ret_val
= mputstr(ret_val
, "Exiting");
646 case TitanLoggerApi::ExecutorRuntime_reason::fd__limits
:
647 ret_val
= mputprintf(ret_val
, "Maximum number of open file descriptors: %i,"
648 " FD_SETSIZE = %li", (int)rt
.pid()(), (long)rt
.fd__setsize()());
650 case TitanLoggerApi::ExecutorRuntime_reason::host__controller__started
:
651 ret_val
= mputprintf(ret_val
, "TTCN-3 Host Controller started on %s."
652 " Version: " PRODUCT_NUMBER
".", (const char *)rt
.module__name()());
654 case TitanLoggerApi::ExecutorRuntime_reason::host__controller__finished
:
655 ret_val
= mputstr(ret_val
, "TTCN-3 Host Controller finished.");
657 case TitanLoggerApi::ExecutorRuntime_reason::initializing__module
:
658 ret_val
= mputprintf(ret_val
, "Initializing module %s.",
659 (const char *)rt
.module__name()());
661 case TitanLoggerApi::ExecutorRuntime_reason::initialization__of__module__finished
:
662 ret_val
= mputprintf(ret_val
, "Initialization of module %s finished.",
663 (const char *)rt
.module__name()());
665 case TitanLoggerApi::ExecutorRuntime_reason::mtc__created
:
666 ret_val
= mputprintf(ret_val
, "MTC was created. Process id: %ld.",
669 case TitanLoggerApi::ExecutorRuntime_reason::overload__check
:
670 ret_val
= mputstr(ret_val
, "Trying to create a dummy child process"
671 " to verify if the host is still overloaded.");
673 case TitanLoggerApi::ExecutorRuntime_reason::overload__check__fail
:
674 ret_val
= mputstr(ret_val
, "Creation of the dummy child process failed.");
676 case TitanLoggerApi::ExecutorRuntime_reason::overloaded__no__more
:
677 // FIXME ret_val = mputstr(ret_val, "");
679 case TitanLoggerApi::ExecutorRuntime_reason::resuming__execution
:
680 ret_val
= mputstr(ret_val
, "Resuming execution.");
682 case TitanLoggerApi::ExecutorRuntime_reason::stopping__control__part__execution
:
683 ret_val
= mputstr(ret_val
, "Resuming control part execution.");
685 case TitanLoggerApi::ExecutorRuntime_reason::stopping__current__testcase
:
686 ret_val
= mputstr(ret_val
, "Stopping current testcase.");
688 case TitanLoggerApi::ExecutorRuntime_reason::stopping__test__component__execution
:
689 ret_val
= mputstr(ret_val
, "Stopping test component execution.");
691 case TitanLoggerApi::ExecutorRuntime_reason::terminating__execution
:
692 ret_val
= mputstr(ret_val
, "Terminating execution.");
694 case TitanLoggerApi::ExecutorRuntime_reason::user__paused__waiting__to__resume
:
695 ret_val
= mputstr(ret_val
, "User has paused execution. Waiting for continue.");
697 case TitanLoggerApi::ExecutorRuntime_reason::waiting__for__ptcs__to__finish
:
698 ret_val
= mputstr(ret_val
, "Waiting for PTCs to finish.");
703 case TitanLoggerApi::ExecutorEvent_choice::ALT_executorConfigdata
: {
704 TitanLoggerApi::ExecutorConfigdata
const& cfg
= eec
.executorConfigdata();
705 switch (cfg
.reason()) {
706 case TitanLoggerApi::ExecutorConfigdata_reason::UNBOUND_VALUE
:
707 case TitanLoggerApi::ExecutorConfigdata_reason::UNKNOWN_VALUE
:
711 case TitanLoggerApi::ExecutorConfigdata_reason::received__from__mc
:
712 ret_val
= mputstr(ret_val
, "Processing configuration data received from MC.");
714 case TitanLoggerApi::ExecutorConfigdata_reason::processing__failed
:
715 ret_val
= mputstr(ret_val
, "Processing of configuration data failed.");
717 case TitanLoggerApi::ExecutorConfigdata_reason::processing__succeeded
:
718 ret_val
= mputstr(ret_val
, "Configuration data was processed successfully.");
720 case TitanLoggerApi::ExecutorConfigdata_reason::module__has__parameters
:
721 // TODO: module logs its own parameters directly, change it ?
723 case TitanLoggerApi::ExecutorConfigdata_reason::using__config__file
:
724 ret_val
= mputprintf( ret_val
, "Using configuration file: `%s'.",
725 (const char *)cfg
.param__()());
727 case TitanLoggerApi::ExecutorConfigdata_reason::overriding__testcase__list
:
728 ret_val
= mputprintf(ret_val
, "Overriding testcase list: %s.",
729 (const char *)cfg
.param__()());
732 break; } // executorConfigdata
734 case TitanLoggerApi::ExecutorEvent_choice::ALT_executorComponent
: {
735 TitanLoggerApi::ExecutorComponent
const& cm
= eec
.executorComponent();
736 switch (cm
.reason()) {
737 case TitanLoggerApi::ExecutorComponent_reason::UNBOUND_VALUE
:
738 case TitanLoggerApi::ExecutorComponent_reason::UNKNOWN_VALUE
:
743 case TitanLoggerApi::ExecutorComponent_reason::mtc__started
:
744 ret_val
= mputprintf(ret_val
, "TTCN-3 Main Test Component started on %s."
745 " Version: " PRODUCT_NUMBER
".", TTCN_Runtime::get_host_name());
748 case TitanLoggerApi::ExecutorComponent_reason::mtc__finished
:
749 ret_val
= mputstr(ret_val
, "TTCN-3 Main Test Component finished.");
752 case TitanLoggerApi::ExecutorComponent_reason::ptc__started
:
755 case TitanLoggerApi::ExecutorComponent_reason::ptc__finished
:
756 ret_val
= mputstr(ret_val
, "TTCN-3 Parallel Test Component finished.");
759 case TitanLoggerApi::ExecutorComponent_reason::component__init__fail
:
760 ret_val
= mputstr(ret_val
, "Component type initialization failed. PTC terminates.");
763 break; } // executorComponent
765 case TitanLoggerApi::ExecutorEvent_choice::ALT_executorMisc
: {
766 TitanLoggerApi::ExecutorUnqualified
const& ex
= eec
.executorMisc();
767 const char *name
= ex
.name(), *ip_addr_str
= ex
.addr();
768 switch (ex
.reason()) {
769 case TitanLoggerApi::ExecutorUnqualified_reason::UNBOUND_VALUE
:
770 case TitanLoggerApi::ExecutorUnqualified_reason::UNKNOWN_VALUE
:
774 case TitanLoggerApi::ExecutorUnqualified_reason::address__of__mc__was__set
:
775 if (strcmp(name
, ip_addr_str
)) { // the IP address has a canonical name
776 ret_val
= mputprintf(ret_val
, "The address of MC was set to %s[%s]:%d.",
777 name
, ip_addr_str
, (int)ex
.port__());
778 } else { // the IP address does not have a canonical name
779 ret_val
= mputprintf(ret_val
, "The address of MC was set to %s:%d.",
780 ip_addr_str
, (int)ex
.port__());
783 case TitanLoggerApi::ExecutorUnqualified_reason::address__of__control__connection
:
784 ret_val
= mputprintf(ret_val
,
785 "The local IP address of the control connection to MC is %s.",
788 case TitanLoggerApi::ExecutorUnqualified_reason::host__support__unix__domain__sockets
:
789 if (ex
.port__() == 0) { // success
790 ret_val
= mputstr(ret_val
, "This host supports UNIX domain sockets for local communication.");
792 else { // failed with the errno
793 ret_val
= mputstr(ret_val
,
794 "This host does not support UNIX domain sockets for local communication.");
798 case TitanLoggerApi::ExecutorUnqualified_reason::local__address__was__set
:
799 if (strcmp(name
, ip_addr_str
)) { // the IP address has a canonical name
800 ret_val
= mputprintf(ret_val
,
801 "The local address was set to %s[%s].", name
, ip_addr_str
);
802 } else { // the IP address does not have a canonical name
803 ret_val
= mputprintf(ret_val
,
804 "The local address was set to %s.", ip_addr_str
);
810 case TitanLoggerApi::ExecutorEvent_choice::ALT_logOptions
: {
811 // Append plug-in specific settings to the logger options. It's still a
812 // plain string with no structure.
813 ret_val
= mputstr(ret_val
, eec
.logOptions());
814 char * pso
= LegacyLogger::plugin_specific_settings();
816 ret_val
= mputstr(ret_val
, pso
);
820 case TitanLoggerApi::ExecutorEvent_choice::ALT_extcommandStart
:
821 ret_val
= mputprintf(ret_val
, "Starting external command `%s'.",
822 (const char*)eec
.extcommandStart());
824 case TitanLoggerApi::ExecutorEvent_choice::ALT_extcommandSuccess
:
825 ret_val
= mputprintf(ret_val
,
826 "External command `%s' was executed successfully (exit status: 0).",
827 (const char*)eec
.extcommandSuccess());
830 case API::ExecutorEvent_choice::UNBOUND_VALUE
:
837 char *LegacyLogger::plugin_specific_settings()
839 const char *disk_full_action_type_names
[] =
840 { "Error", "Stop", "Retry", "Delete" };
841 char *disk_full_action_str
= NULL
;
843 if (myself
->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
)
844 disk_full_action_str
= mprintf("Retry(%lu)",
845 (unsigned long)myself
->disk_full_action_
.retry_interval
);
847 disk_full_action_str
= mcopystr(
848 disk_full_action_type_names
[myself
->disk_full_action_
.type
]);
850 " LogFileSize:=%lu; LogFileNumber:=%lu; DiskFullAction:=%s",
851 (unsigned long)myself
->logfile_size_
,
852 (unsigned long)myself
->logfile_number_
,
853 disk_full_action_str
);
854 Free(disk_full_action_str
);
858 void portevent_str(char *& ret_val
, const TitanLoggerApi::PortEvent_choice
& pec
)
860 switch (pec
.get_selection()) {
861 case TitanLoggerApi::PortEvent_choice::ALT_portQueue
: {
862 TitanLoggerApi::Port__Queue
const& pq
= pec
.portQueue();
863 switch (pq
.operation()) {
864 case API::Port__Queue_operation::UNKNOWN_VALUE
:
865 case API::Port__Queue_operation::UNBOUND_VALUE
:
868 return; // can't happen
869 case API::Port__Queue_operation::enqueue__msg
:
870 ret_val
= mputstr(ret_val
, "Message");
873 case API::Port__Queue_operation::enqueue__call
:
874 ret_val
= mputstr(ret_val
, "Call");
877 case API::Port__Queue_operation::enqueue__reply
:
878 ret_val
= mputstr(ret_val
, "Reply");
881 case API::Port__Queue_operation::enqueue__exception
:
882 ret_val
= mputstr(ret_val
, "Exception");
884 char * cmpts
= COMPONENT::get_component_string(pq
.compref());
885 ret_val
= mputprintf(ret_val
, " enqueued on %s from %s%s%s id %u",
886 (const char*)pq
.port__name(), cmpts
,
887 (const char*)pq
.address__(), (const char*)pq
.param__(),
888 (unsigned int)pq
.msgid()
892 case API::Port__Queue_operation::extract__msg
:
893 ret_val
= mputstr(ret_val
, "Message");
896 case API::Port__Queue_operation::extract__op
:
897 ret_val
= mputstr(ret_val
, "Operation");
899 ret_val
= mputprintf(ret_val
, " with id %u was extracted from the queue of %s.",
900 (unsigned int)pq
.msgid(), (const char*)pq
.port__name());
905 case API::PortEvent_choice::ALT_portState
: {
906 API::Port__State
const& ps
= pec
.portState();
907 const char *what
= NULL
;
908 switch (ps
.operation()) {
909 case API::Port__State_operation::UNKNOWN_VALUE
:
910 case API::Port__State_operation::UNBOUND_VALUE
:
913 return; // can't happen
915 case API::Port__State_operation::started
:
918 case API::Port__State_operation::stopped
:
921 case API::Port__State_operation::halted
:
925 ret_val
= mputprintf(ret_val
, "Port %s was %s.",
926 (const char*)ps
.port__name(), what
);
929 case API::PortEvent_choice::ALT_procPortSend
: { // PORTEVENT_P[MC]OUT
930 API::Proc__port__out
const& ps
= pec
.procPortSend();
932 if (ps
.compref() == SYSTEM_COMPREF
) { // it's mapped
933 dest
= ps
.sys__name();
936 dest
= COMPONENT::get_component_string(ps
.compref());
939 switch (ps
.operation()) {
940 case API::Port__oper::UNBOUND_VALUE
:
941 case API::Port__oper::UNKNOWN_VALUE
:
946 case API::Port__oper::call__op
:
947 ret_val
= mputstr(ret_val
, "Called");
950 case API::Port__oper::reply__op
:
951 ret_val
= mputstr(ret_val
, "Replied");
954 case API::Port__oper::exception__op
:
955 ret_val
= mputstr(ret_val
, "Raised");
958 ret_val
= mputprintf(ret_val
, " on %s to %s %s",
959 (const char*)ps
.port__name(),
961 (const char*)ps
.parameter());
962 if (ps
.compref() != SYSTEM_COMPREF
) Free(const_cast<char*>(dest
));
965 case API::PortEvent_choice::ALT_procPortRecv
: { // PORTEVENT_P[MC]IN
966 API::Proc__port__in
const& ps
= pec
.procPortRecv();
968 switch (ps
.operation()) {
969 case API::Port__oper::UNBOUND_VALUE
:
970 case API::Port__oper::UNKNOWN_VALUE
:
975 case API::Port__oper::call__op
:
976 ret_val
= mputstr(ret_val
, ps
.check__() ? "Check-getcall" : "Getcall");
980 case API::Port__oper::reply__op
:
981 ret_val
= mputstr(ret_val
, ps
.check__() ? "Check-getreply" : "Getreply");
985 case API::Port__oper::exception__op
:
986 ret_val
= mputstr(ret_val
, ps
.check__() ? "Check-catch" : "Catch");
991 const char *source
= COMPONENT::get_component_string(ps
.compref());
992 ret_val
= mputprintf(ret_val
, " operation on port %s succeeded, %s from %s: %s id %d",
993 (const char*)ps
.port__name(), op2
, source
, (const char*)ps
.parameter(),
995 Free(const_cast<char*>(source
));
998 case API::PortEvent_choice::ALT_msgPortSend
: { // PORTEVENT_M[MC]SEND
999 API::Msg__port__send
const& ms
= pec
.msgPortSend();
1001 const char *dest
= COMPONENT::get_component_string(ms
.compref());
1002 ret_val
= mputprintf(ret_val
, "Sent on %s to %s%s",
1003 (const char*)ms
.port__name(), dest
, (const char*)ms
.parameter());
1004 //if (ms.compref() != SYSTEM_COMPREF)
1005 Free(const_cast<char*>(dest
));
1008 case API::PortEvent_choice::ALT_msgPortRecv
: { // PORTEVENT_M[MC]RECV
1009 API::Msg__port__recv
const& ms
= pec
.msgPortRecv();
1010 switch (ms
.operation()) {
1011 case API::Port__oper::UNBOUND_VALUE
:
1012 case API::Port__oper::UNKNOWN_VALUE
:
1016 case API::Msg__port__recv_operation::receive__op
:
1017 ret_val
= mputstr(ret_val
, "Receive");
1019 case API::Msg__port__recv_operation::check__receive__op
:
1020 ret_val
= mputstr(ret_val
, "Check-receive");
1022 case API::Msg__port__recv_operation::trigger__op
:
1023 ret_val
= mputstr(ret_val
, "Trigger");
1026 ret_val
= mputprintf(ret_val
, " operation on port %s succeeded, message from ",
1027 (const char *)ms
.port__name());
1029 if (ms
.compref() == SYSTEM_COMPREF
) { // mapped
1030 const char *sys
= ms
.sys__name(); // not dynamic alloc
1031 ret_val
= mputprintf(ret_val
, "system(%s)", sys
);
1033 const char *sys
= COMPONENT::get_component_string(ms
.compref()); // dynamic alloc
1034 ret_val
= mputstr(ret_val
, sys
);
1035 Free(const_cast<char *>(sys
));
1037 const char *ms_parameter
= (const char *)ms
.parameter();
1038 ret_val
= mputprintf(ret_val
, "%s id %d", ms_parameter
, (int)ms
.msgid());
1039 // Inconsistent dot...
1040 if (ms_parameter
== NULL
|| strlen(ms_parameter
) == 0)
1041 ret_val
= mputc(ret_val
, '.');
1044 case API::PortEvent_choice::ALT_dualMapped
: {
1045 API::Dualface__mapped
const& dual
= pec
.dualMapped();
1046 ret_val
= mputprintf(ret_val
, "%s message was mapped to %s : %s",
1047 (dual
.incoming() ? "Incoming" : "Outgoing"),
1048 (const char*)dual
.target__type(), (const char*)dual
.value__());
1050 if (dual
.incoming()) {
1051 ret_val
= mputprintf(ret_val
, " id %d", (int)dual
.msgid());
1055 case API::PortEvent_choice::ALT_dualDiscard
: {
1056 API::Dualface__discard
const& dualop
= pec
.dualDiscard();
1057 ret_val
= mputprintf(ret_val
, "%s message of type %s ",
1058 (dualop
.incoming() ? "Incoming" : "Outgoing"),
1059 (const char*)dualop
.target__type());
1061 ret_val
= mputprintf(ret_val
, (dualop
.unhandled()
1062 ? "could not be handled by the type mapping rules on port %s."
1063 " The message was discarded."
1064 : "was discarded on port %s."),
1065 (const char*) dualop
.port__name());
1068 case API::PortEvent_choice::ALT_portMisc
: {
1069 API::Port__Misc
const& pmisc
= pec
.portMisc();
1070 const char *comp_str
= COMPONENT::get_component_string(pmisc
.remote__component());
1071 switch (pmisc
.reason()) {
1072 case API::Port__Misc_reason::UNBOUND_VALUE
:
1073 case API::Port__Misc_reason::UNKNOWN_VALUE
:
1078 case API::Port__Misc_reason::removing__unterminated__connection
:
1079 ret_val
= mputprintf(ret_val
,
1080 "Removing unterminated connection between port %s and %s:%s.",
1081 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1083 case API::Port__Misc_reason::removing__unterminated__mapping
:
1084 ret_val
= mputprintf(ret_val
,
1085 "Removing unterminated mapping between port %s and system:%s.",
1086 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1088 case API::Port__Misc_reason::port__was__cleared
:
1089 ret_val
= mputprintf(ret_val
, "Port %s was cleared.",
1090 (const char*)pmisc
.port__name());
1092 case API::Port__Misc_reason::local__connection__established
:
1093 ret_val
= mputprintf(ret_val
,
1094 "Port %s has established the connection with local port %s.",
1095 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1097 case API::Port__Misc_reason::local__connection__terminated
:
1098 ret_val
= mputprintf(ret_val
,
1099 "Port %s has terminated the connection with local port %s.",
1100 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1102 case API::Port__Misc_reason::port__is__waiting__for__connection__tcp
:
1103 ret_val
= mputprintf(ret_val
,
1104 "Port %s is waiting for connection from %s:%s on TCP port %s:%d.",
1105 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1106 (const char*)pmisc
.ip__address(), (int)pmisc
.tcp__port());
1108 case API::Port__Misc_reason::port__is__waiting__for__connection__unix
:
1109 ret_val
= mputprintf(ret_val
,
1110 "Port %s is waiting for connection from %s:%s on UNIX pathname %s.",
1111 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1112 (const char*)pmisc
.ip__address());
1114 case API::Port__Misc_reason::connection__established
:
1115 ret_val
= mputprintf(ret_val
,
1116 "Port %s has established the connection with %s:%s using transport type %s.",
1117 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1118 (const char*)pmisc
.ip__address());
1120 case API::Port__Misc_reason::destroying__unestablished__connection
:
1121 ret_val
= mputprintf(ret_val
,
1122 "Destroying unestablished connection of port %s to %s:%s"
1123 " because the other endpoint has terminated.",
1124 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1126 case API::Port__Misc_reason::terminating__connection
:
1127 ret_val
= mputprintf(ret_val
,
1128 "Terminating the connection of port %s to %s:%s."
1129 " No more messages can be sent through this connection.",
1130 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1132 case API::Port__Misc_reason::sending__termination__request__failed
:
1133 ret_val
= mputprintf(ret_val
, "Sending the connection termination request"
1134 " on port %s to remote endpoint %s:%s failed.",
1135 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1137 case API::Port__Misc_reason::termination__request__received
:
1138 ret_val
= mputprintf(ret_val
,
1139 "Connection termination request was received on port %s from %s:%s."
1140 " No more data can be sent or received through this connection.",
1141 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1143 case API::Port__Misc_reason::acknowledging__termination__request__failed
:
1144 ret_val
= mputprintf(ret_val
,
1145 "Sending the acknowledgment for connection termination request"
1146 " on port %s to remote endpoint %s:%s failed.",
1147 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1149 case API::Port__Misc_reason::sending__would__block
:
1150 ret_val
= mputprintf(ret_val
,
1151 "Sending data on the connection of port %s to %s:%s would block execution."
1152 " The size of the outgoing buffer was increased from %d to %d bytes.",
1153 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1154 (int)pmisc
.tcp__port(), (int)pmisc
.new__size());
1156 case API::Port__Misc_reason::connection__accepted
:
1157 ret_val
= mputprintf(ret_val
, "Port %s has accepted the connection from %s:%s.",
1158 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1160 case API::Port__Misc_reason::connection__reset__by__peer
:
1161 ret_val
= mputprintf(ret_val
, "Connection of port %s to %s:%s was reset by the peer.",
1162 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1164 case API::Port__Misc_reason::connection__closed__by__peer
:
1165 ret_val
= mputprintf(ret_val
,
1166 "Connection of port %s to %s:%s was closed unexpectedly by the peer.",
1167 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1169 case API::Port__Misc_reason::port__disconnected
:
1170 ret_val
= mputprintf(ret_val
, "Port %s was disconnected from %s:%s.",
1171 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1173 case API::Port__Misc_reason::port__was__mapped__to__system
:
1174 ret_val
= mputprintf(ret_val
, "Port %s was mapped to system:%s.",
1175 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1177 case API::Port__Misc_reason::port__was__unmapped__from__system
:
1178 ret_val
= mputprintf(ret_val
, "Port %s was unmapped from system:%s.",
1179 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1183 Free(const_cast<char*>(comp_str
));
1188 case TitanLoggerApi::PortEvent_choice::UNBOUND_VALUE
:
1193 void matchingop_str(char *& ret_val
, const TitanLoggerApi::MatchingEvent_choice
& choice
)
1195 switch (choice
.get_selection()) {
1196 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingDone
: {
1197 TitanLoggerApi::MatchingDoneType
const& md
= choice
.matchingDone();
1198 switch (md
.reason()) {
1199 case TitanLoggerApi::MatchingDoneType_reason::UNBOUND_VALUE
:
1200 case TitanLoggerApi::MatchingDoneType_reason::UNKNOWN_VALUE
:
1204 case TitanLoggerApi::MatchingDoneType_reason::done__failed__no__return
:
1205 ret_val
= mputprintf(ret_val
, "Done operation with type %s on PTC %d"
1206 " failed: The started function did not return a value.",
1207 (const char*)md
.type__(), (int)md
.ptc());
1209 case TitanLoggerApi::MatchingDoneType_reason::done__failed__wrong__return__type
:
1210 ret_val
= mputprintf(ret_val
, "Done operation with type %s on PTC %d"
1211 " failed: The started function returned a value of type %s.",
1212 (const char*)md
.type__(), (int)md
.ptc(), (const char*)md
.return__type());
1214 case TitanLoggerApi::MatchingDoneType_reason::any__component__done__successful
:
1215 ret_val
= mputstr(ret_val
, "Operation 'any component.done' was successful.");
1217 case TitanLoggerApi::MatchingDoneType_reason::any__component__done__failed
:
1218 ret_val
= mputstr(ret_val
, "Operation 'any component.done' "
1219 "failed because no PTCs were created in the testcase.");
1221 case TitanLoggerApi::MatchingDoneType_reason::all__component__done__successful
:
1222 ret_val
= mputstr(ret_val
, "Operation 'all component.done' was successful.");
1224 case TitanLoggerApi::MatchingDoneType_reason::any__component__killed__successful
:
1225 ret_val
= mputstr(ret_val
, "Operation 'any component.killed' was successful.");
1227 case TitanLoggerApi::MatchingDoneType_reason::any__component__killed__failed
:
1228 ret_val
= mputstr(ret_val
, "Operation 'any component.killed' "
1229 "failed because no PTCs were created in the testcase.");
1231 case TitanLoggerApi::MatchingDoneType_reason::all__component__killed__successful
:
1232 ret_val
= mputstr(ret_val
, "Operation 'all component.killed' was successful.");
1237 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingFailure
: {
1238 boolean is_call
= FALSE
;
1239 TitanLoggerApi::MatchingFailureType
const& mf
= choice
.matchingFailure();
1240 switch (mf
.reason()) {
1241 case TitanLoggerApi::MatchingFailureType_reason::UNBOUND_VALUE
:
1242 case TitanLoggerApi::MatchingFailureType_reason::UNKNOWN_VALUE
:
1245 return; // can't happen
1246 case TitanLoggerApi::MatchingFailureType_reason::message__does__not__match__template
:
1247 ret_val
= mputprintf(ret_val
,
1248 "Matching on port %s "
1249 "%s: First message in the queue does not match the template: ",
1250 (const char*)mf
.port__name(), (const char*)mf
.info());
1252 case TitanLoggerApi::MatchingFailureType_reason::exception__does__not__match__template
:
1253 ret_val
= mputprintf(ret_val
,
1254 "Matching on port %s failed: "
1255 "The first exception in the queue does not match the template: %s",
1256 (const char*)mf
.port__name(), (const char*)mf
.info());
1258 case TitanLoggerApi::MatchingFailureType_reason::parameters__of__call__do__not__match__template
:
1259 is_call
= TRUE
; // fall through
1260 case TitanLoggerApi::MatchingFailureType_reason::parameters__of__reply__do__not__match__template
:
1261 ret_val
= mputprintf(ret_val
,
1262 "Matching on port %s failed: "
1263 "The parameters of the first %s in the queue do not match the template: %s",
1264 (is_call
? "call" : "reply"),
1265 (const char*)mf
.port__name(), (const char*)mf
.info());
1267 case TitanLoggerApi::MatchingFailureType_reason::sender__does__not__match__from__clause
:
1268 ret_val
= mputprintf(ret_val
,
1269 "Matching on port %s failed: "
1270 "Sender of the first entity in the queue does not match the from clause: %s",
1271 (const char*)mf
.port__name(), (const char*)mf
.info());
1273 case TitanLoggerApi::MatchingFailureType_reason::sender__is__not__system
:
1274 ret_val
= mputprintf(ret_val
,
1275 "Matching on port %s failed: "
1276 "Sender of the first entity in the queue is not the system.",
1277 (const char*)mf
.port__name());
1279 case TitanLoggerApi::MatchingFailureType_reason::not__an__exception__for__signature
:
1280 ret_val
= mputprintf(ret_val
,
1281 "Matching on port %s failed: "
1282 "The first entity in the queue is not an exception for signature %s.",
1283 (const char*)mf
.port__name(), (const char*)mf
.info());
1288 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingSuccess
: {
1289 TitanLoggerApi::MatchingSuccessType
const& ms
= choice
.matchingSuccess();
1290 ret_val
= mputprintf(ret_val
, "Matching on port %s succeeded: %s",
1291 (const char*)ms
.port__name(), (const char*)ms
.info());
1294 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingProblem
: {
1295 TitanLoggerApi::MatchingProblemType
const& mp
= choice
.matchingProblem();
1296 ret_val
= mputstr(ret_val
, "Operation `");
1297 if (mp
.any__port()) ret_val
= mputstr(ret_val
, "any port.");
1298 if (mp
.check__()) ret_val
= mputstr(ret_val
, "check(");
1299 switch (mp
.operation()) {
1300 case TitanLoggerApi::MatchingProblemType_operation::UNBOUND_VALUE
:
1301 case TitanLoggerApi::MatchingProblemType_operation::UNKNOWN_VALUE
:
1304 case TitanLoggerApi::MatchingProblemType_operation::receive__
:
1305 ret_val
= mputstr(ret_val
, "receive");
1307 case TitanLoggerApi::MatchingProblemType_operation::trigger__
:
1308 ret_val
= mputstr(ret_val
, "trigger");
1310 case TitanLoggerApi::MatchingProblemType_operation::getcall__
:
1311 ret_val
= mputstr(ret_val
, "getcall");
1313 case TitanLoggerApi::MatchingProblemType_operation::getreply__
:
1314 ret_val
= mputstr(ret_val
, "getreply");
1316 case TitanLoggerApi::MatchingProblemType_operation::catch__
:
1317 ret_val
= mputstr(ret_val
, "catch");
1319 case TitanLoggerApi::MatchingProblemType_operation::check__
:
1320 ret_val
= mputstr(ret_val
, "check");
1323 if (mp
.check__()) ret_val
= mputstr(ret_val
, ")");
1324 ret_val
= mputstr(ret_val
, "' ");
1326 if (mp
.port__name().is_bound()) ret_val
= mputprintf(ret_val
,
1327 "on port %s ", (const char*)mp
.port__name());
1328 // we could also check that any__port is false
1330 ret_val
= mputstr(ret_val
, "failed: ");
1332 switch (mp
.reason()) {
1333 case TitanLoggerApi::MatchingProblemType_reason::UNBOUND_VALUE
:
1334 case TitanLoggerApi::MatchingProblemType_reason::UNKNOWN_VALUE
:
1337 case TitanLoggerApi::MatchingProblemType_reason::component__has__no__ports
:
1338 ret_val
= mputstr(ret_val
, "The test component does not have ports.");
1340 case TitanLoggerApi::MatchingProblemType_reason::no__incoming__signatures
:
1341 ret_val
= mputstr(ret_val
, "The port type does not have any incoming signatures.");
1343 case TitanLoggerApi::MatchingProblemType_reason::no__incoming__types
:
1344 ret_val
= mputstr(ret_val
, "The port type does not have any incoming message types.");
1346 case TitanLoggerApi::MatchingProblemType_reason::no__outgoing__blocking__signatures
:
1347 ret_val
= mputstr(ret_val
, "The port type does not have any outgoing blocking signatures.");
1349 case TitanLoggerApi::MatchingProblemType_reason::no__outgoing__blocking__signatures__that__support__exceptions
:
1350 ret_val
= mputstr(ret_val
, "The port type does not have any outgoing blocking signatures that support exceptions.");
1352 case TitanLoggerApi::MatchingProblemType_reason::port__not__started__and__queue__empty
:
1353 ret_val
= mputstr(ret_val
, "Port is not started and the queue is empty.");
1356 break; } // matchingProblem
1358 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingTimeout
: {
1359 TitanLoggerApi::MatchingTimeout
const& mt
= choice
.matchingTimeout();
1360 if (mt
.timer__name().ispresent()) {
1361 ret_val
= mputprintf(ret_val
, "Timeout operation on timer %s failed:"
1362 " The timer is not started.", (const char*)mt
.timer__name()());
1365 ret_val
= mputstr(ret_val
, "Operation `any timer.timeout' failed:"
1366 " The test component does not have active timers.");
1370 case TitanLoggerApi::MatchingEvent_choice::UNBOUND_VALUE
:
1377 void parallel_str(char *& ret_val
, const TitanLoggerApi::ParallelEvent_choice
& choice
)
1379 switch (choice
.get_selection()) {
1380 case TitanLoggerApi::ParallelEvent_choice::ALT_parallelPTC
: {
1381 TitanLoggerApi::ParallelPTC
const& ptc
= choice
.parallelPTC();
1382 switch (ptc
.reason()) {
1383 case TitanLoggerApi::ParallelPTC_reason::UNKNOWN_VALUE
:
1384 case TitanLoggerApi::ParallelPTC_reason::UNBOUND_VALUE
:
1388 case TitanLoggerApi::ParallelPTC_reason::init__component__start
:
1389 ret_val
= mputprintf(ret_val
,
1390 "Initializing variables, timers and ports of component type %s.%s",
1391 (const char*)ptc
.module__(), (const char*)ptc
.name());
1392 if (ptc
.tc__loc().lengthof()) ret_val
= mputprintf(ret_val
,
1393 " inside testcase %s", (const char*)ptc
.tc__loc());
1394 ret_val
= mputc(ret_val
, '.');
1396 case TitanLoggerApi::ParallelPTC_reason::init__component__finish
:
1397 ret_val
= mputprintf(ret_val
, "Component type %s.%s was initialized.",
1398 (const char*)ptc
.module__(), (const char*)ptc
.name());
1400 case TitanLoggerApi::ParallelPTC_reason::terminating__component
:
1401 ret_val
= mputprintf(ret_val
, "Terminating component type %s.%s.",
1402 (const char*)ptc
.module__(), (const char*)ptc
.name());
1404 case TitanLoggerApi::ParallelPTC_reason::component__shut__down
:
1405 ret_val
= mputprintf(ret_val
, "Component type %s.%s was shut down",
1406 (const char*)ptc
.module__(), (const char*)ptc
.name());
1407 if (ptc
.tc__loc().lengthof()) ret_val
= mputprintf(ret_val
,
1408 " inside testcase %s", (const char*)ptc
.tc__loc());
1409 ret_val
= mputc(ret_val
, '.');
1411 case TitanLoggerApi::ParallelPTC_reason::error__idle__ptc
:
1412 ret_val
= mputstr(ret_val
,
1413 "Error occurred on idle PTC. The component terminates.");
1415 case TitanLoggerApi::ParallelPTC_reason::ptc__created
:
1416 ret_val
= mputprintf(ret_val
, "PTC was created."
1417 " Component reference: %d, alive: %s, type: %s.%s",
1418 (int)ptc
.compref(), (ptc
.alive__pid() ? "yes" : "no"),
1419 (const char*)ptc
.module__(), (const char*)ptc
.name());
1420 // The "testcase" member is used for the component name
1421 if (ptc
.compname().lengthof() != 0) ret_val
= mputprintf(ret_val
,
1422 ", component name: %s", (const char*)ptc
.compname());
1423 if (ptc
.tc__loc().lengthof() != 0) ret_val
= mputprintf(ret_val
,
1424 ", location: %s", (const char*)ptc
.tc__loc());
1425 ret_val
= mputc(ret_val
, '.');
1428 case API::ParallelPTC_reason::ptc__created__pid
:
1429 ret_val
= mputprintf(ret_val
, "PTC was created. Component reference: %d, "
1430 "component type: %s.%s", (int)ptc
.compref(),
1431 (const char*)ptc
.module__(), (const char*)ptc
.name());
1432 if (ptc
.compname().lengthof() != 0) ret_val
= mputprintf(ret_val
,
1433 ", component name: %s", (const char*)ptc
.compname());
1434 if (ptc
.tc__loc().lengthof() != 0) ret_val
= mputprintf(ret_val
,
1435 ", testcase name: %s", (const char*)ptc
.tc__loc());
1436 ret_val
= mputprintf(ret_val
, ", process id: %d.", (int)ptc
.alive__pid());
1439 case TitanLoggerApi::ParallelPTC_reason::function__started
:
1440 ret_val
= mputstr(ret_val
, "Function was started.");
1442 case TitanLoggerApi::ParallelPTC_reason::function__stopped
:
1443 ret_val
= mputprintf(ret_val
, "Function %s was stopped. PTC terminates.",
1444 (const char*)ptc
.name());
1446 case TitanLoggerApi::ParallelPTC_reason::function__finished
:
1447 ret_val
= mputprintf(ret_val
, "Function %s finished. PTC %s.",
1448 (const char*)ptc
.name(),
1449 ptc
.alive__pid() ? "remains alive and is waiting for next start" : "terminates");
1451 case TitanLoggerApi::ParallelPTC_reason::function__error
:
1452 ret_val
= mputprintf(ret_val
, "Function %s finished with an error. PTC terminates.",
1453 (const char*)ptc
.name());
1455 case TitanLoggerApi::ParallelPTC_reason::ptc__done
:
1456 ret_val
= mputprintf(ret_val
, "PTC with component reference %d is done.",
1457 (int)ptc
.compref());
1459 case TitanLoggerApi::ParallelPTC_reason::ptc__killed
:
1460 ret_val
= mputprintf(ret_val
, "PTC with component reference %d is killed.",
1461 (int)ptc
.compref());
1463 case TitanLoggerApi::ParallelPTC_reason::stopping__mtc
:
1464 ret_val
= mputstr(ret_val
, "Stopping MTC. The current test case will be terminated.");
1466 case TitanLoggerApi::ParallelPTC_reason::ptc__stopped
:
1467 ret_val
= mputprintf(ret_val
, "PTC with component reference %d was stopped.",
1468 (int)ptc
.compref());
1470 case TitanLoggerApi::ParallelPTC_reason::all__comps__stopped
:
1471 ret_val
= mputstr(ret_val
, "All components were stopped.");
1473 case TitanLoggerApi::ParallelPTC_reason::ptc__was__killed
:
1474 ret_val
= mputprintf(ret_val
, "PTC with component reference %d was killed.",
1475 (int)ptc
.compref());
1477 case TitanLoggerApi::ParallelPTC_reason::all__comps__killed
:
1478 ret_val
= mputstr(ret_val
, "All components were killed.");
1480 case TitanLoggerApi::ParallelPTC_reason::kill__request__frm__mc
:
1481 ret_val
= mputstr(ret_val
, "Kill was requested from MC. Terminating idle PTC.");
1483 case TitanLoggerApi::ParallelPTC_reason::mtc__finished
:
1484 ret_val
= mputstr(ret_val
, "MTC finished.");
1485 goto mpt_ptc_together
;
1486 case TitanLoggerApi::ParallelPTC_reason::ptc__finished
: {
1487 if (ptc
.compname().lengthof() != 0) {
1488 ret_val
= mputprintf(ret_val
, "PTC %s(%d) finished.",
1489 (const char*)ptc
.compname(), (int)ptc
.compref());
1491 ret_val
= mputprintf(ret_val
, "PTC with component reference %d "
1492 "finished.", (int)ptc
.compref());
1495 ret_val
= mputprintf(ret_val
, " Process statistics: { "
1496 "process id: %d, ", (int)ptc
.alive__pid());
1497 int statuscode
= ptc
.status();
1498 if (WIFEXITED(statuscode
)) {
1499 ret_val
= mputprintf(ret_val
, "terminated normally, "
1500 "exit status: %d, ", WEXITSTATUS(statuscode
));
1501 } else if (WIFSIGNALED(statuscode
)) {
1502 int signal_number
= WTERMSIG(statuscode
);
1503 ret_val
= mputprintf(ret_val
, "terminated by a signal, "
1504 "signal number: %d (%s), ", signal_number
,
1505 TTCN_Runtime::get_signal_name(signal_number
));
1507 // this macro is not available on all platforms
1508 if (WCOREDUMP(statuscode
))
1509 ret_val
= mputstr(ret_val
, "core dump was created, ");
1512 ret_val
= mputprintf(ret_val
, "termination reason and status is "
1513 "unknown: %d, ", statuscode
);
1515 ret_val
= mputstr(ret_val
, (const char*)ptc
.tc__loc());
1517 case TitanLoggerApi::ParallelPTC_reason::starting__function
:
1520 break; } // parallelPTC
1522 case TitanLoggerApi::ParallelEvent_choice::ALT_parallelPTC__exit
: {
1523 TitanLoggerApi::PTC__exit
const& px
= choice
.parallelPTC__exit();
1524 const int compref
= px
.compref();
1525 if (compref
== MTC_COMPREF
) {
1526 ret_val
= mputstr(ret_val
, "MTC finished.");
1528 const char *comp_name
= COMPONENT::get_component_name(px
.compref());
1529 if (comp_name
) ret_val
= mputprintf(ret_val
, "PTC %s(%d) finished.",
1530 comp_name
, compref
);
1531 else ret_val
= mputprintf(ret_val
, "PTC with component reference %d "
1532 "finished.", compref
);
1534 ret_val
= mputprintf(ret_val
, " Process statistics: { process id: %d, ",
1540 case TitanLoggerApi::ParallelEvent_choice::ALT_parallelPort
: {
1541 TitanLoggerApi::ParPort
const& pp
= choice
.parallelPort();
1542 const char *direction
= "on";
1543 const char *preposition
= "and";
1544 switch(pp
.operation()) {
1545 case API::ParPort_operation::UNBOUND_VALUE
:
1546 case API::ParPort_operation::UNKNOWN_VALUE
:
1550 case API::ParPort_operation::connect__
:
1551 ret_val
= mputstr(ret_val
, "Connect");
1553 case API::ParPort_operation::disconnect__
:
1554 ret_val
= mputstr(ret_val
, "Disconnect");
1556 case API::ParPort_operation::map__
:
1557 ret_val
= mputstr(ret_val
, "Map");
1561 case API::ParPort_operation::unmap__
:
1562 ret_val
= mputstr(ret_val
, "Unmap");
1564 preposition
= "from";
1567 char *src
= COMPONENT::get_component_string(pp
.srcCompref());
1568 char *dst
= COMPONENT::get_component_string(pp
.dstCompref());
1569 ret_val
= mputprintf(ret_val
, " operation %s %s:%s %s %s:%s finished.",
1570 direction
, src
, (const char*)pp
.srcPort(), preposition
,
1571 dst
, (const char*)pp
.dstPort());
1576 case TitanLoggerApi::ParallelEvent_choice::UNBOUND_VALUE
:
1583 void testcaseop_str(char *& ret_val
, const TitanLoggerApi::TestcaseEvent_choice
& choice
)
1585 switch (choice
.get_selection()) {
1586 case TitanLoggerApi::TestcaseEvent_choice::ALT_testcaseStarted
: {
1587 ret_val
= mputprintf(ret_val
, "Test case %s started.",
1588 (const char *)choice
.testcaseStarted().testcase__name());
1591 case TitanLoggerApi::TestcaseEvent_choice::ALT_testcaseFinished
: {
1592 const TitanLoggerApi::TestcaseType
& testcase
= choice
.testcaseFinished();
1593 ret_val
= mputprintf(ret_val
, "Test case %s finished. Verdict: %s",
1594 (const char *)testcase
.name().testcase__name(),
1595 verdict_name
[testcase
.verdict()]);
1596 if (testcase
.reason().lengthof() > 0) {
1597 ret_val
= mputprintf(ret_val
, " reason: %s", (const char *)testcase
.reason());
1601 case TitanLoggerApi::TestcaseEvent_choice::UNBOUND_VALUE
:
1608 void verdictop_str(char *& ret_val
, const TitanLoggerApi::VerdictOp_choice
& choice
)
1610 switch (choice
.get_selection()) {
1611 case TitanLoggerApi::VerdictOp_choice::ALT_setVerdict
: {
1612 const TitanLoggerApi::SetVerdictType
& set
= choice
.setVerdict();
1613 if (set
.newVerdict() > set
.oldVerdict()) { // the verdict is changing
1614 if (!set
.oldReason().ispresent() && !set
.newReason().ispresent()) {
1615 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s",
1616 verdict_name
[set
.newVerdict()], verdict_name
[set
.oldVerdict()],
1617 verdict_name
[set
.localVerdict()]);
1619 // The reason text (oldReason() and newReason()) is always the same
1620 // for some reason. Why?
1621 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s reason: "
1622 "\"%s\", new component reason: \"%s\"",
1623 verdict_name
[set
.newVerdict()], verdict_name
[set
.oldVerdict()],
1624 verdict_name
[set
.localVerdict()], (const char *)set
.oldReason()(),
1625 (const char *)set
.newReason()());
1628 if (!set
.oldReason().ispresent() && !set
.newReason().ispresent()) {
1629 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s, component "
1630 "reason not changed", verdict_name
[set
.newVerdict()],
1631 verdict_name
[set
.oldVerdict()], verdict_name
[set
.localVerdict()]);
1633 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s reason: "
1634 "\"%s\", component reason not changed",
1635 verdict_name
[set
.newVerdict()], verdict_name
[set
.oldVerdict()],
1636 verdict_name
[set
.localVerdict()], (const char *)set
.oldReason()());
1641 case TitanLoggerApi::VerdictOp_choice::ALT_getVerdict
: {
1642 ret_val
= mputprintf(ret_val
, "getverdict: %s",
1643 verdict_name
[choice
.getVerdict()]);
1646 case TitanLoggerApi::VerdictOp_choice::ALT_finalVerdict
: {
1647 switch (choice
.finalVerdict().choice().get_selection()) {
1648 case TitanLoggerApi::FinalVerdictType_choice::ALT_info
: {
1649 const TitanLoggerApi::FinalVerdictInfo
& info
= choice
.finalVerdict().choice().info();
1650 if (info
.is__ptc()) {
1651 if ((int)info
.ptc__compref().ispresent() && (int)info
.ptc__compref()() != UNBOUND_COMPREF
) {
1652 if (info
.ptc__name().ispresent() && info
.ptc__name()().lengthof() > 0) {
1653 ret_val
= mputprintf(ret_val
, "Local verdict of PTC %s(%d): ",
1654 (const char *)info
.ptc__name()(), (int)info
.ptc__compref()());
1656 ret_val
= mputprintf(ret_val
, "Local verdict of PTC with "
1657 "component reference %d: ", (int)info
.ptc__compref()());
1659 ret_val
= mputprintf(ret_val
, "%s (%s -> %s)",
1660 verdict_name
[info
.ptc__verdict()], verdict_name
[info
.local__verdict()],
1661 verdict_name
[info
.new__verdict()]);
1662 if (info
.verdict__reason().ispresent() &&
1663 info
.verdict__reason()().lengthof() > 0)
1664 ret_val
= mputprintf(ret_val
, " reason: \"%s\"",
1665 (const char *)info
.verdict__reason()());
1667 ret_val
= mputprintf(ret_val
, "Final verdict of PTC: %s",
1668 verdict_name
[info
.local__verdict()]);
1669 if (info
.verdict__reason().ispresent() &&
1670 info
.verdict__reason()().lengthof() > 0) {
1671 ret_val
= mputprintf(ret_val
, " reason: \"%s\"",
1672 (const char *)info
.verdict__reason()());
1676 ret_val
= mputprintf(ret_val
, "Local verdict of MTC: %s",
1677 verdict_name
[info
.local__verdict()]);
1678 if (info
.verdict__reason().ispresent() &&
1679 info
.verdict__reason()().lengthof() > 0) {
1680 ret_val
= mputprintf(ret_val
, " reason: \"%s\"",
1681 (const char *)info
.verdict__reason()());
1685 case TitanLoggerApi::FinalVerdictType_choice::ALT_notification
:
1686 switch (choice
.finalVerdict().choice().notification()) {
1687 case TitanLoggerApi::FinalVerdictType_choice_notification::no__ptcs__were__created
:
1688 ret_val
= mputstr(ret_val
, "No PTCs were created.");
1690 case TitanLoggerApi::FinalVerdictType_choice_notification::setting__final__verdict__of__the__test__case
:
1691 ret_val
= mputstr(ret_val
, "Setting final verdict of the test case.");
1693 case TitanLoggerApi::FinalVerdictType_choice_notification::UNBOUND_VALUE
:
1694 case TitanLoggerApi::FinalVerdictType_choice_notification::UNKNOWN_VALUE
:
1699 case TitanLoggerApi::FinalVerdictType_choice::UNBOUND_VALUE
:
1705 case TitanLoggerApi::VerdictOp_choice::UNBOUND_VALUE
:
1712 void statistics_str(char *& ret_val
, const TitanLoggerApi::StatisticsType_choice
& choice
)
1714 switch (choice
.get_selection()) {
1715 case TitanLoggerApi::StatisticsType_choice::ALT_verdictStatistics
: {
1716 const TitanLoggerApi::StatisticsType_choice_verdictStatistics
& statistics
=
1717 choice
.verdictStatistics();
1718 unsigned long none_count
= (size_t)statistics
.none__(),
1719 pass_count
= (size_t)statistics
.pass__(),
1720 inconc_count
= (size_t)statistics
.inconc__(),
1721 fail_count
= (size_t)statistics
.fail__(),
1722 error_count
= (size_t)statistics
.error__();
1723 if (none_count
> 0 || pass_count
> 0 || inconc_count
> 0 ||
1724 fail_count
> 0 || error_count
> 0) {
1725 ret_val
= mputprintf(ret_val
,
1726 "Verdict statistics: %lu none (%.2f %%), %lu pass (%.2f %%), %lu inconc "
1727 "(%.2f %%), %lu fail (%.2f %%), %lu error (%.2f %%).",
1728 none_count
, (float)statistics
.nonePercent(),
1729 pass_count
, (float)statistics
.passPercent(),
1730 inconc_count
, (float)statistics
.inconcPercent(),
1731 fail_count
, (float)statistics
.failPercent(),
1732 error_count
, (float)statistics
.errorPercent());
1734 ret_val
= mputstr(ret_val
,
1735 "Verdict statistics: 0 none, 0 pass, 0 inconc, 0 fail, 0 error.");
1739 case TitanLoggerApi::StatisticsType_choice::ALT_controlpartStart
:
1740 ret_val
= mputprintf(ret_val
, "Execution of control part in module %s %sed.",
1741 (const char*)choice
.controlpartStart(), "start");
1744 case TitanLoggerApi::StatisticsType_choice::ALT_controlpartFinish
:
1745 // The compiler might fold the two identical format strings
1746 ret_val
= mputprintf(ret_val
, "Execution of control part in module %s %sed.",
1747 (const char*)choice
.controlpartFinish(), "finish");
1750 case TitanLoggerApi::StatisticsType_choice::ALT_controlpartErrors
:
1751 ret_val
= mputprintf(ret_val
, "Number of errors outside test cases: %u",
1752 (unsigned int)choice
.controlpartErrors());
1755 case TitanLoggerApi::StatisticsType_choice::UNBOUND_VALUE
:
1762 char *event_to_str(const TitanLoggerApi::TitanLogEvent
& event
,
1763 bool without_header
)
1765 char *ret_val
= NULL
;
1766 if (!without_header
) {
1767 struct timeval timestamp
= { (time_t)event
.timestamp().seconds(),
1768 (suseconds_t
)event
.timestamp().microSeconds() };
1769 char *sourceinfo
= NULL
;
1770 if (event
.sourceInfo__list().is_bound()) {
1771 TTCN_Logger::source_info_format_t source_info_format
=
1772 TTCN_Logger::get_source_info_format();
1773 int stack_size
= event
.sourceInfo__list().size_of();
1774 if (stack_size
> 0) {
1776 switch (source_info_format
) {
1777 case TTCN_Logger::SINFO_NONE
:
1778 i
= stack_size
; // start == end; nothing printed
1780 case TTCN_Logger::SINFO_SINGLE
:
1781 i
= stack_size
- 1; // print just the last one
1783 case TTCN_Logger::SINFO_STACK
:
1784 // do nothing, start from the beginning
1788 for (; i
< stack_size
; ++i
) {
1789 API::LocationInfo
const& loc
= event
.sourceInfo__list()[i
];
1791 if (sourceinfo
) sourceinfo
= mputstr(sourceinfo
, "->");
1792 const char *file_name
= loc
.filename();
1793 int line_number
= loc
.line();
1794 const char *entity_name
= loc
.ent__name();
1795 API::LocationInfo_ent__type entity_type
= loc
.ent__type();
1796 sourceinfo
= mputprintf(sourceinfo
, "%s:%u", file_name
, line_number
);
1797 if (TTCN_Logger::get_log_entity_name()) {
1798 switch (entity_type
) {
1799 case API::LocationInfo_ent__type::controlpart
:
1800 sourceinfo
= mputprintf(sourceinfo
, "(controlpart:%s)", entity_name
);
1802 case API::LocationInfo_ent__type::testcase__
:
1803 sourceinfo
= mputprintf(sourceinfo
, "(testcase:%s)", entity_name
);
1805 case API::LocationInfo_ent__type::altstep__
:
1806 sourceinfo
= mputprintf(sourceinfo
, "(altstep:%s)", entity_name
);
1808 case API::LocationInfo_ent__type::function__
:
1809 sourceinfo
= mputprintf(sourceinfo
, "(function:%s)", entity_name
);
1811 case API::LocationInfo_ent__type::external__function
:
1812 sourceinfo
= mputprintf(sourceinfo
, "(externalfunction:%s)", entity_name
);
1814 case API::LocationInfo_ent__type::template__
:
1815 sourceinfo
= mputprintf(sourceinfo
, "(template:%s)", entity_name
);
1817 case API::LocationInfo_ent__type::UNBOUND_VALUE
:
1818 case API::LocationInfo_ent__type::UNKNOWN_VALUE
:
1819 case API::LocationInfo_ent__type::unknown
:
1826 if (source_info_format
== TTCN_Logger::SINFO_SINGLE
||
1827 source_info_format
== TTCN_Logger::SINFO_STACK
)
1828 sourceinfo
= mputc(sourceinfo
, '-');
1832 ret_val
= append_header(ret_val
, timestamp
,
1833 (const TTCN_Logger::Severity
)(int)event
.severity(), sourceinfo
);
1837 // Big, ugly switch to append the event message.
1838 // TODO: We need a fancier implementation.
1839 const TitanLoggerApi::LogEventType_choice
& choice
= event
.logEvent().choice();
1840 switch (choice
.get_selection()) {
1841 case TitanLoggerApi::LogEventType_choice::UNBOUND_VALUE
:
1844 case TitanLoggerApi::LogEventType_choice::ALT_unhandledEvent
: {
1845 ret_val
= mputstr(ret_val
,
1846 (const char *)choice
.unhandledEvent());
1849 case API::LogEventType_choice::ALT_timerEvent
:
1850 timer_event_str(ret_val
, choice
.timerEvent().choice());
1853 case TitanLoggerApi::LogEventType_choice::ALT_statistics
:
1854 statistics_str(ret_val
, choice
.statistics().choice());
1857 case TitanLoggerApi::LogEventType_choice::ALT_verdictOp
:
1858 verdictop_str(ret_val
, choice
.verdictOp().choice());
1862 case TitanLoggerApi::LogEventType_choice::ALT_testcaseOp
:
1863 testcaseop_str(ret_val
, choice
.testcaseOp().choice());
1866 case TitanLoggerApi::LogEventType_choice::ALT_actionEvent
:
1868 case TitanLoggerApi::LogEventType_choice::ALT_userLog
: {
1869 API::Strings_str__list
const& slist
=
1870 (choice
.get_selection() == TitanLoggerApi::LogEventType_choice::ALT_userLog
)
1871 ? choice
.userLog().str__list()
1872 : choice
.actionEvent().str__list();
1873 for (int i
= 0, size
= slist
.size_of(); i
< size
; ++i
) {
1874 ret_val
= mputstr(ret_val
, (const char *)slist
[i
]);
1878 case TitanLoggerApi::LogEventType_choice::ALT_debugLog
: {
1879 // TODO: We support multiple type of DEBUG_* events.
1880 ret_val
= mputstr(ret_val
, (const char *)choice
.debugLog().text());
1883 case TitanLoggerApi::LogEventType_choice::ALT_errorLog
: {
1884 ret_val
= mputstr(ret_val
, (const char *)choice
.errorLog().text());
1887 case TitanLoggerApi::LogEventType_choice::ALT_warningLog
: {
1888 ret_val
= mputstr(ret_val
, (const char *)choice
.warningLog().text());
1891 case TitanLoggerApi::LogEventType_choice::ALT_defaultEvent
:
1892 defaultop_event_str(ret_val
, choice
.defaultEvent().choice());
1895 case TitanLoggerApi::LogEventType_choice::ALT_executionSummary
: {
1896 // FIXME why is this empty?
1899 case TitanLoggerApi::LogEventType_choice::ALT_executorEvent
: {
1900 // En Taro Adun, executor!
1901 executor_event_str(ret_val
, choice
.executorEvent().choice());
1902 break; } // executorRuntime
1904 case TitanLoggerApi::LogEventType_choice::ALT_matchingEvent
:
1905 matchingop_str(ret_val
, choice
.matchingEvent().choice());
1908 case TitanLoggerApi::LogEventType_choice::ALT_functionEvent
:
1909 switch (choice
.functionEvent().choice().get_selection()) {
1910 case TitanLoggerApi::FunctionEvent_choice::ALT_random
: {
1911 TitanLoggerApi::FunctionEvent_choice_random
const& ra
= choice
.functionEvent().choice().random();
1912 switch (ra
.operation()) {
1913 case TitanLoggerApi::RandomAction::seed
: {
1914 long integer_seed
= ra
.intseed();
1915 ret_val
= mputprintf(ret_val
, "Random number generator was initialized with seed %f: "
1916 "srand48(%ld).", (double)ra
.retval(), integer_seed
);
1918 case TitanLoggerApi::RandomAction::read__out
:
1919 ret_val
= mputprintf(ret_val
, "Function rnd() returned %f.", (double)ra
.retval());
1921 case TitanLoggerApi::RandomAction::UNBOUND_VALUE
:
1922 case TitanLoggerApi::RandomAction::UNKNOWN_VALUE
:
1924 return NULL
; // something went wrong
1929 case TitanLoggerApi::FunctionEvent_choice::ALT_unqualified
:
1932 case TitanLoggerApi::FunctionEvent_choice::UNBOUND_VALUE
:
1938 case TitanLoggerApi::LogEventType_choice::ALT_parallelEvent
:
1939 parallel_str(ret_val
, choice
.parallelEvent().choice());
1942 case TitanLoggerApi::LogEventType_choice::ALT_portEvent
:
1943 portevent_str(ret_val
, choice
.portEvent().choice());
1947 return NULL
; // can't happen
1948 } // the big ugly switch
1953 #pragma GCC diagnostic pop
1956 void LegacyLogger::open_file(bool is_first
)
1960 if (!this->skeleton_given_
)
1961 set_file_name(TTCN_Runtime::is_single()
1962 ? (this->logfile_number_
== 1 ? "%e.%s" : "%e-part%i.%s")
1963 : (this->logfile_number_
== 1 ? "%e.%h-%r.%s" : "%e.%h-%r-part%i.%s"),
1966 // Logging_Bits have only effect on the actual plug-in. (Filtering is
1967 // implemented at higher level.)
1968 Free(this->current_filename_
);
1969 this->current_filename_
= get_file_name(this->logfile_index_
);
1970 if (this->current_filename_
!= NULL
) {
1971 create_parent_directories(this->current_filename_
);
1972 this->log_fp_
= fopen(this->current_filename_
,
1973 this->append_file_
? "a" : "w");
1974 if (this->log_fp_
== NULL
)
1975 fatal_error("Opening of log file `%s' for writing failed.",
1976 this->current_filename_
);
1977 if (!TTCN_Communication::set_close_on_exec(fileno(this->log_fp_
))) {
1978 fclose(this->log_fp_
);
1979 fatal_error("Setting the close-on-exec flag failed on log file `%s'.",
1980 this->current_filename_
);
1984 this->is_configured_
= true;
1985 this->logfile_bytes_
= 0;
1988 void LegacyLogger::close_file()
1990 if (!this->log_fp_
) return;
1991 fclose(this->log_fp_
);
1992 this->log_fp_
= NULL
;
1995 /** @brief Construct the log file name, performs substitutions.
1997 @return NULL if filename_skeleton is NULL or if the result would have been
1999 @return an expstring_t with the actual filename. The caller is
2000 responsible for deallocating it with Free().
2002 char *LegacyLogger::get_file_name(size_t idx
)
2004 if (this->filename_skeleton_
== NULL
) return NULL
;
2005 enum { SINGLE
, HC
, MTC
, PTC
} whoami
;
2006 if (TTCN_Runtime::is_single()) whoami
= SINGLE
;
2007 else if (TTCN_Runtime::is_hc()) whoami
= HC
;
2008 else if (TTCN_Runtime::is_mtc()) whoami
= MTC
;
2010 bool h_present
= false, p_present
= false, r_present
= false,
2012 this->format_c_present_
= false;
2013 this->format_t_present_
= false;
2014 char *ret_val
= memptystr();
2015 for (size_t i
= 0; this->filename_skeleton_
[i
] != '\0'; i
++) {
2016 if (this->filename_skeleton_
[i
] != '%') {
2017 ret_val
= mputc(ret_val
, this->filename_skeleton_
[i
]);
2020 switch (this->filename_skeleton_
[++i
]) {
2021 case 'c': // %c -> name of the current testcase (only on PTCs)
2022 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_testcase_name());
2023 this->format_c_present_
= true;
2025 case 'e': // %e -> name of executable
2026 ret_val
= mputstr(ret_val
, TTCN_Logger::get_executable_name());
2028 case 'h': // %h -> hostname
2029 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_host_name());
2032 case 'l': { // %l -> login name
2034 struct passwd
*p
= getpwuid(getuid());
2035 if (p
!= NULL
) ret_val
= mputstr(ret_val
, p
->pw_name
);
2038 case 'n': // %n -> component name (optional)
2042 ret_val
= mputstr(ret_val
, "MTC");
2045 ret_val
= mputstr(ret_val
, "HC");
2048 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_component_name());
2053 case 'p': // %p -> process id
2054 ret_val
= mputprintf(ret_val
, "%ld", (long)getpid());
2057 case 'r': // %r -> component reference
2060 ret_val
= mputstr(ret_val
, "single");
2063 ret_val
= mputstr(ret_val
, "hc");
2066 ret_val
= mputstr(ret_val
, "mtc");
2070 ret_val
= mputprintf(ret_val
, "%d", (component
)self
);
2075 case 's': // %s -> default suffix (currently: always "log")
2076 ret_val
= mputstr(ret_val
, "log");
2078 case 't': // %t -> component type (only on PTCs)
2079 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_component_type());
2080 this->format_t_present_
= true;
2082 case 'i': // %i -> log file index
2083 if (this->logfile_number_
!= 1)
2084 ret_val
= mputprintf(ret_val
, "%lu", (unsigned long)idx
);
2087 case '\0': // trailing single %: leave as it is
2088 i
--; // to avoid over-indexing in next iteration
2090 case '%': // escaping: %% -> %
2091 ret_val
= mputc(ret_val
, '%');
2093 default: // unknown sequence: leave as it is
2094 ret_val
= mputc(ret_val
, '%');
2095 ret_val
= mputc(ret_val
, this->filename_skeleton_
[i
]);
2100 static bool already_warned
= false;
2101 if (ret_val
[0] == '\0') { // result is empty
2104 } else if (whoami
== HC
&& !already_warned
) {
2105 already_warned
= true;
2106 if (!h_present
|| (!p_present
&& !r_present
))
2107 TTCN_warning("Skeleton `%s' does not guarantee unique log file name "
2108 "for every test system process. It may cause "
2109 "unpredictable results if several test components try to "
2110 "write into the same log file.", this->filename_skeleton_
);
2112 if (this->logfile_number_
!= 1 && !i_present
) {
2113 TTCN_warning("LogFileNumber = %lu, but `%%i' is missing from the log "
2114 "file name skeleton. `%%i' was appended to the skeleton.",
2115 (unsigned long)this->logfile_number_
);
2116 this->filename_skeleton_
= mputstr(this->filename_skeleton_
, "%i");
2117 ret_val
= mputprintf(ret_val
, "%lu", (unsigned long)idx
);
2122 /** @brief Create all directories in a full path.
2124 Ensures that all directories in the specified path exist (similar to mkdir
2125 -p). Existing directories are skipped, non-existing directories are
2126 created. Calls fatal_error() if a directory cannot be stat'ed or a
2127 non-existing directory cannot be created.
2129 @param path_name full path to log file name
2131 void LegacyLogger::create_parent_directories(const char *path_name
)
2133 char *path_backup
= NULL
;
2134 bool umask_saved
= false;
2135 mode_t old_umask
= 0;
2137 // if path_name is absolute skip the leading '/'(s)
2138 while (path_name
[i
] == '/') i
++;
2139 while (path_name
[i
] != '\0') {
2140 if (path_name
[i
] != '/') {
2144 // path_name up to index i should contain a directory name
2145 if (path_backup
== NULL
) path_backup
= mcopystr(path_name
);
2146 path_backup
[i
] = '\0';
2148 if (stat(path_backup
, &buf
) < 0) {
2149 if (errno
== ENOENT
) {
2150 // if the directory does not exist: create it
2153 old_umask
= umask(0);
2156 if (mkdir(path_backup
, 0755) < 0) {
2157 fatal_error("Creation of directory `%s' failed when trying to open "
2158 "log file `%s'.", path_backup
, path_name
);
2161 fatal_error("stat() system call failed on `%s' when creating parent "
2162 "directories for log file `%s'.", path_backup
, path_name
);
2165 path_backup
[i
] = '/';
2166 // skip over the duplicated slashes
2167 while (path_name
[++i
] == '/') ;
2169 if (umask_saved
) umask(old_umask
);
2173 void LegacyLogger::chk_logfile_data()
2175 if (this->logfile_size_
== 0 && this->logfile_number_
!= 1) {
2176 TTCN_warning("Invalid combination of LogFileSize (= %lu) and "
2177 "LogFileNumber (= %lu). LogFileNumber was reset to 1.",
2178 (unsigned long)this->logfile_size_
,
2179 (unsigned long)this->logfile_number_
);
2180 this->logfile_number_
= 1;
2182 if (this->logfile_size_
> 0 && this->logfile_number_
== 1) {
2183 TTCN_warning("Invalid combination of LogFileSize (= %lu) and "
2184 "LogFileNumber (= %lu). LogFileSize was reset to 0.",
2185 (unsigned long)this->logfile_size_
,
2186 (unsigned long)this->logfile_number_
);
2187 this->logfile_size_
= 0;
2189 if (this->logfile_number_
== 1 &&
2190 this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_DELETE
) {
2191 TTCN_warning("Invalid combination of LogFileNumber (= 1) and "
2192 "DiskFullAction (= Delete). DiskFullAction was reset to "
2194 this->disk_full_action_
.type
= TTCN_Logger::DISKFULL_ERROR
;
2196 if (this->logfile_number_
!= 1 && this->append_file_
) {
2197 TTCN_warning("Invalid combination of LogFileNumber (= %lu) and "
2198 "AppendFile (= Yes). AppendFile was reset to No.",
2199 (unsigned long)this->logfile_number_
);
2200 this->append_file_
= false;
2204 void LegacyLogger::set_file_name(const char *new_filename_skeleton
,
2205 boolean from_config
)
2207 Free(this->filename_skeleton_
);
2208 this->filename_skeleton_
= mcopystr(new_filename_skeleton
);
2209 if (from_config
) this->skeleton_given_
= true;
2212 bool LegacyLogger::set_file_size(int p_size
)
2214 this->logfile_size_
= p_size
;
2218 bool LegacyLogger::set_file_number(int p_number
)
2220 this->logfile_number_
= p_number
;
2224 bool LegacyLogger::set_disk_full_action(
2225 TTCN_Logger::disk_full_action_t p_disk_full_action
)
2227 this->disk_full_action_
= p_disk_full_action
;
2231 // LegacyLogger should be the only provider of log2str().
2232 CHARSTRING
LegacyLogger::log2str(const TitanLoggerApi::TitanLogEvent
& event
)
2234 char *event_str
= event_to_str(event
, true);
2235 // mstrlen can handle NULL; it will result in a bound but empty CHARSTRING
2236 CHARSTRING
ret_val(mstrlen(event_str
), event_str
);
2237 if (event_str
== NULL
) {
2238 TTCN_warning("No text for event");
2240 else Free(event_str
);
2244 void LegacyLogger::set_append_file(bool new_append_file
)
2246 this->append_file_
= new_append_file
;