1 ///////////////////////////////////////////////////////////////////////////////
2 // Copyright (c) 2000-2014 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
7 ///////////////////////////////////////////////////////////////////////////////
8 #include "LegacyLogger.hh"
10 #include "TitanLoggerApi.hh"
11 #include "Component.hh"
13 #include "ILoggerPlugin.hh"
14 #include "LoggingBits.hh"
15 #include "Communication.hh"
18 #include "../common/version_internal.h"
23 #include <sys/types.h>
26 // for WIFEXITED & co.
31 typedef long suseconds_t
;
36 // It's a static plug-in, destruction is done in the destructor. We need
37 // `extern "C"' for some reason.
38 ILoggerPlugin
*create_legacy_logger() { return new LegacyLogger(); }
42 static char *event_to_str(const TitanLoggerApi::TitanLogEvent
& event
,
43 bool without_header
= false);
44 static char *append_header(char *ret_val
, const struct timeval
& timestamp
,
45 const TTCN_Logger::Severity severity
,
46 const char *sourceinfo
);
48 static void timer_event_str(char *& ret_val
, const TitanLoggerApi::TimerEvent_choice
& tec
);
49 static void defaultop_event_str(char *& ret_val
, const TitanLoggerApi::DefaultEvent_choice
& dec
);
50 static void executor_event_str(char *& ret_val
, const TitanLoggerApi::ExecutorEvent_choice
& eec
);
51 static void portevent_str(char *& ret_val
, const TitanLoggerApi::PortEvent_choice
& pec
);
52 //void extcommand_str(char *& ret_val, const TitanLoggerApi::ExecutorEvent_choice& choice);
53 static void matchingop_str(char *& ret_val
, const TitanLoggerApi::MatchingEvent_choice
& choice
);
54 static void parallel_str(char *& ret_val
, const TitanLoggerApi::ParallelEvent_choice
& choice
);
55 static void testcaseop_str(char *& ret_val
, const TitanLoggerApi::TestcaseEvent_choice
& choice
);
56 static void verdictop_str(char *& ret_val
, const TitanLoggerApi::VerdictOp_choice
& choice
);
57 static void statistics_str(char *& ret_val
, const TitanLoggerApi::StatisticsType_choice
& choice
);
59 namespace API
= TitanLoggerApi
;
61 // Defined in Logger.cc. Compares the name or the component identifier.
62 extern bool operator==(const component_id_t
& left
,
63 const component_id_t
& right
);
65 LegacyLogger
* LegacyLogger::myself
= 0;
67 LegacyLogger::LegacyLogger()
68 : log_fp_(NULL
), er_(NULL
), logfile_bytes_(0), logfile_size_(0), logfile_number_(1),
69 logfile_index_(1), filename_skeleton_(NULL
), skeleton_given_(false),
70 append_file_(false), is_disk_full_(false), format_c_present_(false),
71 format_t_present_(false), current_filename_(NULL
)
75 // A déjà vu is usually a glitch in the Matrix.
76 // It happens when they change something.
77 fputs("Only one LegacyLogger allowed! Aborting.\n", stderr
);
78 abort(); // Don't use TTCN_error. Debugging infinite recursion is not fun.
83 this->name_
= mputstr(this->name_
, "LegacyLogger");
84 this->help_
= mputstr(this->help_
, "LegacyLogger");
85 this->disk_full_action_
.type
= TTCN_Logger::DISKFULL_ERROR
;
86 this->disk_full_action_
.retry_interval
= 0;
89 LegacyLogger::~LegacyLogger()
91 assert(this->name_
&& this->help_
);
96 Free(this->filename_skeleton_
);
97 this->filename_skeleton_
= NULL
;
98 Free(this->current_filename_
);
99 this->current_filename_
= NULL
;
104 void LegacyLogger::reset()
106 this->disk_full_action_
.type
= TTCN_Logger::DISKFULL_ERROR
;
107 this->disk_full_action_
.retry_interval
= 0;
108 this->logfile_size_
= 0;
109 this->logfile_number_
= 1;
110 this->logfile_bytes_
= 0;
111 this->logfile_index_
= 1;
112 this->is_disk_full_
= false;
113 this->skeleton_given_
= false;
114 this->append_file_
= false;
115 this->is_configured_
= false;
118 void LegacyLogger::init(const char */
*options*/
)
120 // Print some version information, handle general options etc. later...
123 void LegacyLogger::fini()
128 void LegacyLogger::fatal_error(const char *err_msg
, ...)
130 fputs("Fatal error during logging: ", stderr
);
132 va_start(p_var
, err_msg
);
133 vfprintf(stderr
, err_msg
, p_var
);
136 const char *error_string
= strerror(errno
);
137 if (error_string
!= NULL
) fprintf(stderr
, " (%s)", error_string
);
138 else fprintf(stderr
, " (Unknown error: errno = %d)", errno
);
141 fputs(" Exiting.\n", stderr
);
145 /** @brief Log a message to the log file and console (if required).
149 If the log file is open (\c is_configured is TRUE), it calls
150 should_log_to_file() to decide whether logging to file is wanted; calls
151 log_file(), which calls log_to_file() if affirmative.
153 If the log file is not open (\c is_configured is FALSE), it stores the
154 message until the file is opened.
156 For logging to the console:
158 If should_log_to_console() returns TRUE, sends the log message to the main
159 controller via TTCN_Communication::send_log() and possibly writes it to
160 the standard error depending on the return value.
163 @param [in] log_buffered
165 void LegacyLogger::log(const TitanLoggerApi::TitanLogEvent
& event
,
166 bool log_buffered
, bool separate_file
, bool use_emergency_mask
)
168 const TTCN_Logger::Severity
& severity
= (const TTCN_Logger::Severity
)(int)event
.severity();
171 log_file_emerg(event
);
173 if (use_emergency_mask
) {
174 if (TTCN_Logger::should_log_to_emergency(severity
)
176 TTCN_Logger::should_log_to_file(severity
))
178 log_file(event
, log_buffered
);
180 if (TTCN_Logger::should_log_to_console(severity
)) {
181 log_console(event
, severity
);
185 if (TTCN_Logger::should_log_to_file(severity
)) {
186 log_file(event
, log_buffered
);
188 if (TTCN_Logger::should_log_to_console(severity
)) {
189 log_console(event
, severity
);
195 bool LegacyLogger::log_file_emerg(const TitanLoggerApi::TitanLogEvent
& event
)
197 bool write_success
= true;
198 char *event_str
= event_to_str(event
);
199 if (event_str
== NULL
) {
200 TTCN_warning("No text for event");
203 size_t bytes_to_log
= mstrlen(event_str
);
206 char *filename_emergency
= get_file_name(0);
208 if (filename_emergency
== NULL
) {
209 // Valid filename is not available, use specific one.
210 filename_emergency
= mcopystr("emergency.log");
212 filename_emergency
= mputprintf(filename_emergency
, "_emergency");
214 er_
= fopen(filename_emergency
, "w");
217 fatal_error("Opening of log file `%s' for writing failed.",
220 Free(filename_emergency
);
223 write_success
= true;
225 if (bytes_to_log
> 0 && fwrite(event_str
, bytes_to_log
, 1, er_
) != 1)
226 write_success
= false;
234 return write_success
;
237 /** @brief Logs a message to the already opened log file.
238 @pre The log file is already open.
240 Writes the timestamp in the appropriate format, the event type (severity)
241 if needed, the source information if available, the message and a newline.
243 @param [in] event a properly initialized TITAN log event
244 @param [in] log_buffered TRUE if this is a buffered message, used to avoid
245 possible recursion of log_to_file() -> open_file() ->
246 log_to_file() -> open_file() -> ...
248 bool LegacyLogger::log_file(const TitanLoggerApi::TitanLogEvent
& event
,
251 if (!this->log_fp_
) return false;
253 struct timeval event_timestamp
= { (time_t)event
.timestamp().seconds(),
254 (suseconds_t
)event
.timestamp().microSeconds() };
255 if (this->is_disk_full_
) {
256 if (this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
) {
258 // If the specified time period has elapsed retry logging to file.
259 if (event_timestamp
.tv_usec
< this->disk_full_time_
.tv_usec
) {
260 diff
.tv_sec
= event_timestamp
.tv_sec
-
261 this->disk_full_time_
.tv_sec
- 1;
262 diff
.tv_usec
= event_timestamp
.tv_usec
+
263 (1000000L - this->disk_full_time_
.tv_usec
);
265 diff
.tv_sec
= event_timestamp
.tv_sec
- this->disk_full_time_
.tv_sec
;
266 diff
.tv_usec
= event_timestamp
.tv_usec
-
267 this->disk_full_time_
.tv_usec
;
269 if ((size_t)diff
.tv_sec
>= this->disk_full_action_
.retry_interval
)
270 this->is_disk_full_
= false;
277 // Check if there is a size limitation and the file is not empty, if the
278 // file is still empty the size limitation is ignored. If the size
279 // limitation is reached open a new log file and check the file number
280 // limitation. When writing the buffered messages the file size limitation
281 // is ignored. TODO: Replace length calculation with custom function call.
282 // Event buffering is not necessarily implemented in the plug-ins.
283 char *event_str
= event_to_str(event
);
284 if (event_str
== NULL
) {
285 TTCN_warning("No text for event");
288 size_t bytes_to_log
= mstrlen(event_str
) + 1;
289 if (this->logfile_size_
!= 0 && this->logfile_bytes_
!= 0 && !log_buffered
) {
290 if ((bytes_to_log
+ this->logfile_bytes_
+ 1023) / 1024 > this->logfile_size_
) {
291 // Close current log file and open the next one.
293 this->logfile_index_
++;
294 // Delete oldest log file if there is a file number limitation.
295 if (this->logfile_number_
> 1) {
296 if (this->logfile_index_
> this->logfile_number_
) {
297 char* filename_to_delete
=
298 get_file_name(this->logfile_index_
- this->logfile_number_
);
299 remove(filename_to_delete
);
300 Free(filename_to_delete
);
307 if (!log_buffered
&& (this->format_c_present_
|| this->format_t_present_
)) {
308 switch (TTCN_Runtime::get_state()) {
309 case TTCN_Runtime::HC_EXIT
:
310 case TTCN_Runtime::MTC_EXIT
:
311 case TTCN_Runtime::PTC_EXIT
:
312 // Can't call get_filename(), because it may call
313 // TTCN_Runtime::get_host_name(), and TTCN_Runtime::clean_up() (which is
314 // called once) has already happened.
317 char *new_filename
= get_file_name(this->logfile_index_
);
318 if (strcmp(new_filename
, this->current_filename_
)) {
319 // Different file name, have to switch. Reuse timestamp etc. of the
321 expstring_t switched
= mprintf("Switching to log file `%s'",
323 TitanLoggerApi::TitanLogEvent switched_event
;
324 switched_event
.timestamp() = event
.timestamp();
325 switched_event
.sourceInfo__list() = event
.sourceInfo__list();
326 switched_event
.severity() = (int)TTCN_Logger::EXECUTOR_RUNTIME
;
327 switched_event
.logEvent().choice().unhandledEvent() =
328 CHARSTRING(switched
);
329 log_file(switched_event
, true);
332 open_file(false); // calls get_filename again :(
339 // Write out the event_str, if it failed assume that the disk is full, then
340 // act according to DiskFullAction.
341 bool print_success
= log_to_file(event_str
);
342 if (!print_success
) {
343 switch (this->disk_full_action_
.type
) {
344 case TTCN_Logger::DISKFULL_ERROR
:
345 fatal_error("Writing to log file failed.");
346 case TTCN_Logger::DISKFULL_STOP
:
347 this->is_disk_full_
= true;
349 case TTCN_Logger::DISKFULL_RETRY
:
350 this->is_disk_full_
= true;
351 // Time of failure. TODO: Find a better way to transfer the timestamp.
352 this->disk_full_time_
.tv_sec
= event
.timestamp().seconds();
353 this->disk_full_time_
.tv_usec
= event
.timestamp().microSeconds();
355 case TTCN_Logger::DISKFULL_DELETE
:
356 // Try to delete older logfiles while writing fails, must leave at least
357 // two log files. Stop with error if cannot delete more files and
359 if (this->logfile_number_
== 0)
360 this->logfile_number_
= this->logfile_index_
;
361 while (!print_success
&& this->logfile_number_
> 2) {
362 this->logfile_number_
--;
363 if (this->logfile_index_
> this->logfile_number_
) {
364 char *filename_to_delete
=
365 get_file_name(this->logfile_index_
- this->logfile_number_
);
366 int remove_ret_val
= remove(filename_to_delete
);
367 Free(filename_to_delete
);
368 // File deletion failed.
369 if (remove_ret_val
!= 0) break;
370 print_success
= log_to_file(event_str
);
374 fatal_error("Writing to log file failed.");
375 else this->logfile_bytes_
+= bytes_to_log
;
378 fatal_error("LegacyLogger::log(): invalid DiskFullAction type.");
381 this->logfile_bytes_
+= bytes_to_log
;
387 bool LegacyLogger::log_console(const TitanLoggerApi::TitanLogEvent
& event
,
388 const TTCN_Logger::Severity
& severity
)
390 char *event_str
= event_to_str(event
, true);
391 if (event_str
== NULL
) {
392 TTCN_warning("No text for event");
395 size_t event_str_len
= mstrlen(event_str
);
396 if (!TTCN_Communication::send_log((time_t)event
.timestamp().seconds(),
397 (suseconds_t
)event
.timestamp().microSeconds(), severity
,
398 event_str_len
, event_str
)) {
399 // The event text shall be printed to stderr when there is no control
400 // connection towards MC (e.g. in single mode or in case of network
402 if (event_str_len
> 0) {
403 // Write the location info to the console for user logs only.
404 // TODO: some switch to turn on/off source info on console.
405 // Perhaps None/User/All?
407 if (TTCN_Logger::USER_UNQUALIFIED
== severity
&& ':' == *event_str
408 && (stackdepth
= event
.sourceInfo__list().lengthof()) > 0) {
409 API::LocationInfo
const& loc
= event
.sourceInfo__list()[stackdepth
-1];
410 if (fprintf(stderr
, "%s:%d", (const char*)loc
.filename(), (int)loc
.line()) < 0)
411 fatal_error("fprintf(sourceinfo) call failed on stderr. %s",
415 if (fwrite(event_str
, event_str_len
, 1, stderr
) != 1)
416 fatal_error("fwrite(message) call failed on stderr. %s",
419 if (putc('\n', stderr
) == EOF
)
420 fatal_error("putc() call failed on stderr. %s", strerror(errno
));
427 bool LegacyLogger::log_to_file(const char *message_ptr
)
429 // Retry and Delete: To avoid writing partial messages remember the initial
430 // file position to be able to remove partial message if writing failed.
432 int fgetpos_ret_val
= 0;
433 if (this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
||
434 this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_DELETE
) {
435 fgetpos_ret_val
= fgetpos(this->log_fp_
, &initial_pos
);
437 size_t message_len
= strlen(message_ptr
);
438 bool write_success
= true;
439 if (message_len
> 0 &&
440 fwrite(message_ptr
, message_len
, 1, this->log_fp_
) != 1)
441 write_success
= false;
442 if (write_success
&& putc('\n', this->log_fp_
) == EOF
) write_success
= false;
443 if (write_success
&& fflush(this->log_fp_
)) write_success
= false;
444 if ((this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
||
445 this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_DELETE
) &&
446 !write_success
&& fgetpos_ret_val
== 0) {
447 // Overwrite with spaces until EOF.
448 fsetpos(this->log_fp_
, &initial_pos
);
449 while (!feof(this->log_fp_
)) if (putc(' ', this->log_fp_
) == EOF
) break;
450 fsetpos(this->log_fp_
, &initial_pos
);
452 return write_success
;
455 char *append_header(char *ret_val
,
456 const struct timeval
& timestamp
, const TTCN_Logger::Severity severity
,
457 const char *sourceinfo
)
459 ret_val
= TTCN_Logger::mputstr_timestamp(ret_val
,
460 TTCN_Logger::get_timestamp_format(), ×tamp
);
461 ret_val
= mputc(ret_val
, ' ');
463 if (TTCN_Logger::get_log_event_types() != TTCN_Logger::LOGEVENTTYPES_NO
) {
464 ret_val
= TTCN_Logger::mputstr_severity(ret_val
, severity
);
465 if (TTCN_Logger::get_log_event_types() ==
466 TTCN_Logger::LOGEVENTTYPES_SUBCATEGORIES
)
467 ret_val
= mputprintf(ret_val
, "_%s",
468 TTCN_Logger::severity_subcategory_names
[severity
]);
469 ret_val
= mputc(ret_val
, ' ');
472 if (sourceinfo
!= NULL
)
473 ret_val
= mputprintf(ret_val
, "%s ", sourceinfo
);
479 #pragma GCC diagnostic push
480 #pragma GCC diagnostic error "-Wswitch-enum"
481 // Use the compiler to verify that all enum values are handled in switches.
482 // Wswitch-enum will report those even if there is a "default" label.
485 void timer_event_str(char *& ret_val
, const TitanLoggerApi::TimerEvent_choice
& tec
)
487 switch (tec
.get_selection()) {
488 case TitanLoggerApi::TimerEvent_choice::ALT_readTimer
: {
489 const TitanLoggerApi::TimerType
& timer
= tec
.readTimer();
490 ret_val
= mputprintf(ret_val
, "Read timer %s: %g s",
491 (const char *)timer
.name(), (double)timer
.value__());
494 case TitanLoggerApi::TimerEvent_choice::ALT_startTimer
: {
495 const TitanLoggerApi::TimerType
& timer
= tec
.startTimer();
496 ret_val
= mputprintf(ret_val
, "Start timer %s: %g s",
497 (const char *)timer
.name(), (double)timer
.value__());
500 case TitanLoggerApi::TimerEvent_choice::ALT_guardTimer
: {
501 const TitanLoggerApi::TimerGuardType
& timer
= tec
.guardTimer();
502 ret_val
= mputprintf(ret_val
, "Test case guard timer was set to %g s.",
503 (double)timer
.value__());
506 case TitanLoggerApi::TimerEvent_choice::ALT_stopTimer
: {
507 const TitanLoggerApi::TimerType
& timer
= tec
.stopTimer();
508 ret_val
= mputprintf(ret_val
, "Stop timer %s: %g s",
509 (const char *)timer
.name(), (double)timer
.value__());
512 case TitanLoggerApi::TimerEvent_choice::ALT_timeoutTimer
: {
513 const TitanLoggerApi::TimerType
& timer
= tec
.timeoutTimer();
514 ret_val
= mputprintf(ret_val
, "Timeout %s: %g s",
515 (const char *)timer
.name(), (double)timer
.value__());
518 case TitanLoggerApi::TimerEvent_choice::ALT_timeoutAnyTimer
: {
519 ret_val
= mputstr(ret_val
, "Operation `any timer.timeout' was successful.");
522 case TitanLoggerApi::TimerEvent_choice::ALT_unqualifiedTimer
: {
523 ret_val
= mputstr(ret_val
, (const char *)tec
.unqualifiedTimer());
526 case TitanLoggerApi::TimerEvent_choice::UNBOUND_VALUE
:
533 void defaultop_event_str(char *& ret_val
, const TitanLoggerApi::DefaultEvent_choice
& dec
)
535 switch (dec
.get_selection()) {
536 case TitanLoggerApi::DefaultEvent_choice::ALT_defaultopActivate
: {
537 TitanLoggerApi::DefaultOp
const& dflt
= dec
.defaultopActivate();
538 ret_val
= mputprintf(ret_val
, "Altstep %s was activated as default, id %u",
539 (const char*)dflt
.name(), (int)dflt
.id());
541 case TitanLoggerApi::DefaultEvent_choice::ALT_defaultopDeactivate
: {
542 TitanLoggerApi::DefaultOp
const& dflt
= dec
.defaultopDeactivate();
543 if (dflt
.name().lengthof()) ret_val
= mputprintf(ret_val
,
544 "Default with id %u (altstep %s) was deactivated.",
545 (int)dflt
.id(), (const char*)dflt
.name());
546 else ret_val
= mputprintf(ret_val
,
547 "Deactivate operation on a null default reference was ignored.");
549 case TitanLoggerApi::DefaultEvent_choice::ALT_defaultopExit
: {
550 TitanLoggerApi::DefaultOp
const& dflt
= dec
.defaultopExit();
551 // First the common part
552 ret_val
= mputprintf(ret_val
, "Default with id %u (altstep %s) ",
553 (int)dflt
.id(), (const char*)dflt
.name());
556 switch (dflt
.end()) {
557 case TitanLoggerApi::DefaultEnd::UNBOUND_VALUE
:
558 case TitanLoggerApi::DefaultEnd::UNKNOWN_VALUE
:
559 // Something has gone horribly wrong
562 case TitanLoggerApi::DefaultEnd::finish
:
563 ret_val
= mputstr(ret_val
, "finished. Skipping current alt statement "
564 "or receiving operation.");
566 case TitanLoggerApi::DefaultEnd::break__
:
567 ret_val
= mputstr(ret_val
, "has reached a repeat statement.");
569 case TitanLoggerApi::DefaultEnd::repeat__
:
570 ret_val
= mputstr(ret_val
, "has reached a break statement."
571 " Skipping current alt statement or receiving operation.");
576 case TitanLoggerApi::DefaultEvent_choice::UNBOUND_VALUE
:
583 void executor_event_str(char *& ret_val
, const TitanLoggerApi::ExecutorEvent_choice
& eec
)
585 switch (eec
.get_selection()) {
586 case API::ExecutorEvent_choice::ALT_executorRuntime
: {
587 TitanLoggerApi::ExecutorRuntime
const& rt
= eec
.executorRuntime();
588 // another monster-switch
589 switch (rt
.reason()) {
590 case TitanLoggerApi::ExecutorRuntime_reason::UNBOUND_VALUE
:
591 case TitanLoggerApi::ExecutorRuntime_reason::UNKNOWN_VALUE
:
594 case TitanLoggerApi::ExecutorRuntime_reason::connected__to__mc
:
595 ret_val
= mputstr(ret_val
, "Connected to MC.");
597 case TitanLoggerApi::ExecutorRuntime_reason::disconnected__from__mc
:
598 ret_val
= mputstr(ret_val
, "Disconnected from MC.");
600 case TitanLoggerApi::ExecutorRuntime_reason::initialization__of__modules__failed
:
601 ret_val
= mputstr(ret_val
, "Initialization of modules failed.");
603 case TitanLoggerApi::ExecutorRuntime_reason::exit__requested__from__mc__hc
:
604 ret_val
= mputstr(ret_val
, "Exit was requested from MC. Terminating HC.");
606 case TitanLoggerApi::ExecutorRuntime_reason::exit__requested__from__mc__mtc
:
607 ret_val
= mputstr(ret_val
, "Exit was requested from MC. Terminating MTC.");
609 case TitanLoggerApi::ExecutorRuntime_reason::stop__was__requested__from__mc
:
610 ret_val
= mputstr(ret_val
, "Stop was requested from MC.");
612 case TitanLoggerApi::ExecutorRuntime_reason::stop__was__requested__from__mc__ignored__on__idle__mtc
:
613 ret_val
= mputstr(ret_val
, "Stop was requested from MC. Ignored on idle MTC.");
615 case TitanLoggerApi::ExecutorRuntime_reason::stop__was__requested__from__mc__ignored__on__idle__ptc
:
616 ret_val
= mputstr(ret_val
, "Stop was requested from MC. Ignored on idle PTC.");
618 case TitanLoggerApi::ExecutorRuntime_reason::executing__testcase__in__module
:
619 ret_val
= mputprintf(ret_val
, "Executing test case %s in module %s.",
620 (const char *)rt
.testcase__name()(), (const char *)rt
.module__name()());
622 case TitanLoggerApi::ExecutorRuntime_reason::performing__error__recovery
:
623 ret_val
= mputstr(ret_val
, "Performing error recovery.");
625 case TitanLoggerApi::ExecutorRuntime_reason::executor__start__single__mode
:
626 ret_val
= mputstr(ret_val
, "TTCN-3 Test Executor "
627 "started in single mode. Version: " PRODUCT_NUMBER
".");
629 case TitanLoggerApi::ExecutorRuntime_reason::executor__finish__single__mode
:
630 ret_val
= mputstr(ret_val
, "TTCN-3 Test Executor finished in single mode.");
632 case TitanLoggerApi::ExecutorRuntime_reason::exiting
:
633 ret_val
= mputstr(ret_val
, "Exiting");
635 case TitanLoggerApi::ExecutorRuntime_reason::fd__limits
:
636 ret_val
= mputprintf(ret_val
, "Maximum number of open file descriptors: %i,"
637 " FD_SETSIZE = %li", (int)rt
.pid()(), (long)rt
.fd__setsize()());
639 case TitanLoggerApi::ExecutorRuntime_reason::host__controller__started
:
640 ret_val
= mputprintf(ret_val
, "TTCN-3 Host Controller started on %s."
641 " Version: " PRODUCT_NUMBER
".", (const char *)rt
.module__name()());
643 case TitanLoggerApi::ExecutorRuntime_reason::host__controller__finished
:
644 ret_val
= mputstr(ret_val
, "TTCN-3 Host Controller finished.");
646 case TitanLoggerApi::ExecutorRuntime_reason::initializing__module
:
647 ret_val
= mputprintf(ret_val
, "Initializing module %s.",
648 (const char *)rt
.module__name()());
650 case TitanLoggerApi::ExecutorRuntime_reason::initialization__of__module__finished
:
651 ret_val
= mputprintf(ret_val
, "Initialization of module %s finished.",
652 (const char *)rt
.module__name()());
654 case TitanLoggerApi::ExecutorRuntime_reason::mtc__created
:
655 ret_val
= mputprintf(ret_val
, "MTC was created. Process id: %ld.",
658 case TitanLoggerApi::ExecutorRuntime_reason::overload__check
:
659 ret_val
= mputstr(ret_val
, "Trying to create a dummy child process"
660 " to verify if the host is still overloaded.");
662 case TitanLoggerApi::ExecutorRuntime_reason::overload__check__fail
:
663 ret_val
= mputstr(ret_val
, "Creation of the dummy child process failed.");
665 case TitanLoggerApi::ExecutorRuntime_reason::overloaded__no__more
:
666 // FIXME ret_val = mputstr(ret_val, "");
668 case TitanLoggerApi::ExecutorRuntime_reason::resuming__execution
:
669 ret_val
= mputstr(ret_val
, "Resuming execution.");
671 case TitanLoggerApi::ExecutorRuntime_reason::stopping__control__part__execution
:
672 ret_val
= mputstr(ret_val
, "Resuming control part execution.");
674 case TitanLoggerApi::ExecutorRuntime_reason::stopping__current__testcase
:
675 ret_val
= mputstr(ret_val
, "Stopping current testcase.");
677 case TitanLoggerApi::ExecutorRuntime_reason::stopping__test__component__execution
:
678 ret_val
= mputstr(ret_val
, "Stopping test component execution.");
680 case TitanLoggerApi::ExecutorRuntime_reason::terminating__execution
:
681 ret_val
= mputstr(ret_val
, "Terminating execution.");
683 case TitanLoggerApi::ExecutorRuntime_reason::user__paused__waiting__to__resume
:
684 ret_val
= mputstr(ret_val
, "User has paused execution. Waiting for continue.");
686 case TitanLoggerApi::ExecutorRuntime_reason::waiting__for__ptcs__to__finish
:
687 ret_val
= mputstr(ret_val
, "Waiting for PTCs to finish.");
692 case TitanLoggerApi::ExecutorEvent_choice::ALT_executorConfigdata
: {
693 TitanLoggerApi::ExecutorConfigdata
const& cfg
= eec
.executorConfigdata();
694 switch (cfg
.reason()) {
695 case TitanLoggerApi::ExecutorConfigdata_reason::UNBOUND_VALUE
:
696 case TitanLoggerApi::ExecutorConfigdata_reason::UNKNOWN_VALUE
:
700 case TitanLoggerApi::ExecutorConfigdata_reason::received__from__mc
:
701 ret_val
= mputstr(ret_val
, "Processing configuration data received from MC.");
703 case TitanLoggerApi::ExecutorConfigdata_reason::processing__failed
:
704 ret_val
= mputstr(ret_val
, "Processing of configuration data failed.");
706 case TitanLoggerApi::ExecutorConfigdata_reason::processing__succeeded
:
707 ret_val
= mputstr(ret_val
, "Configuration data was processed successfully.");
709 case TitanLoggerApi::ExecutorConfigdata_reason::module__has__parameters
:
710 // TODO: module logs its own parameters directly, change it ?
712 case TitanLoggerApi::ExecutorConfigdata_reason::using__config__file
:
713 ret_val
= mputprintf( ret_val
, "Using configuration file: `%s'.",
714 (const char *)cfg
.param__()());
716 case TitanLoggerApi::ExecutorConfigdata_reason::overriding__testcase__list
:
717 ret_val
= mputprintf(ret_val
, "Overriding testcase list: %s.",
718 (const char *)cfg
.param__()());
721 break; } // executorConfigdata
723 case TitanLoggerApi::ExecutorEvent_choice::ALT_executorComponent
: {
724 TitanLoggerApi::ExecutorComponent
const& cm
= eec
.executorComponent();
725 switch (cm
.reason()) {
726 case TitanLoggerApi::ExecutorComponent_reason::UNBOUND_VALUE
:
727 case TitanLoggerApi::ExecutorComponent_reason::UNKNOWN_VALUE
:
732 case TitanLoggerApi::ExecutorComponent_reason::mtc__started
:
733 ret_val
= mputprintf(ret_val
, "TTCN-3 Main Test Component started on %s."
734 " Version: " PRODUCT_NUMBER
".", TTCN_Runtime::get_host_name());
737 case TitanLoggerApi::ExecutorComponent_reason::mtc__finished
:
738 ret_val
= mputstr(ret_val
, "TTCN-3 Main Test Component finished.");
741 case TitanLoggerApi::ExecutorComponent_reason::ptc__started
:
744 case TitanLoggerApi::ExecutorComponent_reason::ptc__finished
:
745 ret_val
= mputstr(ret_val
, "TTCN-3 Parallel Test Component finished.");
748 case TitanLoggerApi::ExecutorComponent_reason::component__init__fail
:
749 ret_val
= mputstr(ret_val
, "Component type initialization failed. PTC terminates.");
752 break; } // executorComponent
754 case TitanLoggerApi::ExecutorEvent_choice::ALT_executorMisc
: {
755 TitanLoggerApi::ExecutorUnqualified
const& ex
= eec
.executorMisc();
756 const char *name
= ex
.name(), *ip_addr_str
= ex
.addr();
757 switch (ex
.reason()) {
758 case TitanLoggerApi::ExecutorUnqualified_reason::UNBOUND_VALUE
:
759 case TitanLoggerApi::ExecutorUnqualified_reason::UNKNOWN_VALUE
:
763 case TitanLoggerApi::ExecutorUnqualified_reason::address__of__mc__was__set
:
764 if (strcmp(name
, ip_addr_str
)) { // the IP address has a canonical name
765 ret_val
= mputprintf(ret_val
, "The address of MC was set to %s[%s]:%d.",
766 name
, ip_addr_str
, (int)ex
.port__());
767 } else { // the IP address does not have a canonical name
768 ret_val
= mputprintf(ret_val
, "The address of MC was set to %s:%d.",
769 ip_addr_str
, (int)ex
.port__());
772 case TitanLoggerApi::ExecutorUnqualified_reason::address__of__control__connection
:
773 ret_val
= mputprintf(ret_val
,
774 "The local IP address of the control connection to MC is %s.",
777 case TitanLoggerApi::ExecutorUnqualified_reason::host__support__unix__domain__sockets
:
778 if (ex
.port__() == 0) { // success
779 ret_val
= mputstr(ret_val
, "This host supports UNIX domain sockets for local communication.");
781 else { // failed with the errno
782 ret_val
= mputstr(ret_val
,
783 "This host does not support UNIX domain sockets for local communication.");
787 case TitanLoggerApi::ExecutorUnqualified_reason::local__address__was__set
:
788 if (strcmp(name
, ip_addr_str
)) { // the IP address has a canonical name
789 ret_val
= mputprintf(ret_val
,
790 "The local address was set to %s[%s].", name
, ip_addr_str
);
791 } else { // the IP address does not have a canonical name
792 ret_val
= mputprintf(ret_val
,
793 "The local address was set to %s.", ip_addr_str
);
799 case TitanLoggerApi::ExecutorEvent_choice::ALT_logOptions
: {
800 // Append plug-in specific settings to the logger options. It's still a
801 // plain string with no structure.
802 ret_val
= mputstr(ret_val
, eec
.logOptions());
803 char * pso
= LegacyLogger::plugin_specific_settings();
805 ret_val
= mputstr(ret_val
, pso
);
809 case TitanLoggerApi::ExecutorEvent_choice::ALT_extcommandStart
:
810 ret_val
= mputprintf(ret_val
, "Starting external command `%s'.",
811 (const char*)eec
.extcommandStart());
813 case TitanLoggerApi::ExecutorEvent_choice::ALT_extcommandSuccess
:
814 ret_val
= mputprintf(ret_val
,
815 "External command `%s' was executed successfully (exit status: 0).",
816 (const char*)eec
.extcommandSuccess());
819 case API::ExecutorEvent_choice::UNBOUND_VALUE
:
826 char *LegacyLogger::plugin_specific_settings()
828 const char *disk_full_action_type_names
[] =
829 { "Error", "Stop", "Retry", "Delete" };
830 char *disk_full_action_str
= NULL
;
832 if (myself
->disk_full_action_
.type
== TTCN_Logger::DISKFULL_RETRY
)
833 disk_full_action_str
= mprintf("Retry(%lu)",
834 (unsigned long)myself
->disk_full_action_
.retry_interval
);
836 disk_full_action_str
= mcopystr(
837 disk_full_action_type_names
[myself
->disk_full_action_
.type
]);
839 " LogFileSize:=%lu; LogFileNumber:=%lu; DiskFullAction:=%s",
840 (unsigned long)myself
->logfile_size_
,
841 (unsigned long)myself
->logfile_number_
,
842 disk_full_action_str
);
843 Free(disk_full_action_str
);
847 void portevent_str(char *& ret_val
, const TitanLoggerApi::PortEvent_choice
& pec
)
849 switch (pec
.get_selection()) {
850 case TitanLoggerApi::PortEvent_choice::ALT_portQueue
: {
851 TitanLoggerApi::Port__Queue
const& pq
= pec
.portQueue();
852 switch (pq
.operation()) {
853 case API::Port__Queue_operation::UNKNOWN_VALUE
:
854 case API::Port__Queue_operation::UNBOUND_VALUE
:
857 return; // can't happen
858 case API::Port__Queue_operation::enqueue__msg
:
859 ret_val
= mputstr(ret_val
, "Message");
862 case API::Port__Queue_operation::enqueue__call
:
863 ret_val
= mputstr(ret_val
, "Call");
866 case API::Port__Queue_operation::enqueue__reply
:
867 ret_val
= mputstr(ret_val
, "Reply");
870 case API::Port__Queue_operation::enqueue__exception
:
871 ret_val
= mputstr(ret_val
, "Exception");
873 char * cmpts
= COMPONENT::get_component_string(pq
.compref());
874 ret_val
= mputprintf(ret_val
, " enqueued on %s from %s%s%s id %u",
875 (const char*)pq
.port__name(), cmpts
,
876 (const char*)pq
.address__(), (const char*)pq
.param__(),
877 (unsigned int)pq
.msgid()
881 case API::Port__Queue_operation::extract__msg
:
882 ret_val
= mputstr(ret_val
, "Message");
885 case API::Port__Queue_operation::extract__op
:
886 ret_val
= mputstr(ret_val
, "Operation");
888 ret_val
= mputprintf(ret_val
, " with id %u was extracted from the queue of %s.",
889 (unsigned int)pq
.msgid(), (const char*)pq
.port__name());
894 case API::PortEvent_choice::ALT_portState
: {
895 API::Port__State
const& ps
= pec
.portState();
896 const char *what
= NULL
;
897 switch (ps
.operation()) {
898 case API::Port__State_operation::UNKNOWN_VALUE
:
899 case API::Port__State_operation::UNBOUND_VALUE
:
902 return; // can't happen
904 case API::Port__State_operation::started
:
907 case API::Port__State_operation::stopped
:
910 case API::Port__State_operation::halted
:
914 ret_val
= mputprintf(ret_val
, "Port %s was %s.",
915 (const char*)ps
.port__name(), what
);
918 case API::PortEvent_choice::ALT_procPortSend
: { // PORTEVENT_P[MC]OUT
919 API::Proc__port__out
const& ps
= pec
.procPortSend();
921 if (ps
.compref() == SYSTEM_COMPREF
) { // it's mapped
922 dest
= ps
.sys__name();
925 dest
= COMPONENT::get_component_string(ps
.compref());
928 switch (ps
.operation()) {
929 case API::Port__oper::UNBOUND_VALUE
:
930 case API::Port__oper::UNKNOWN_VALUE
:
935 case API::Port__oper::call__op
:
936 ret_val
= mputstr(ret_val
, "Called");
939 case API::Port__oper::reply__op
:
940 ret_val
= mputstr(ret_val
, "Replied");
943 case API::Port__oper::exception__op
:
944 ret_val
= mputstr(ret_val
, "Raised");
947 ret_val
= mputprintf(ret_val
, " on %s to %s %s",
948 (const char*)ps
.port__name(),
950 (const char*)ps
.parameter());
951 if (ps
.compref() != SYSTEM_COMPREF
) Free(const_cast<char*>(dest
));
954 case API::PortEvent_choice::ALT_procPortRecv
: { // PORTEVENT_P[MC]IN
955 API::Proc__port__in
const& ps
= pec
.procPortRecv();
957 switch (ps
.operation()) {
958 case API::Port__oper::UNBOUND_VALUE
:
959 case API::Port__oper::UNKNOWN_VALUE
:
964 case API::Port__oper::call__op
:
965 ret_val
= mputstr(ret_val
, ps
.check__() ? "Check-getcall" : "Getcall");
969 case API::Port__oper::reply__op
:
970 ret_val
= mputstr(ret_val
, ps
.check__() ? "Check-getreply" : "Getreply");
974 case API::Port__oper::exception__op
:
975 ret_val
= mputstr(ret_val
, ps
.check__() ? "Check-catch" : "Catch");
980 const char *source
= COMPONENT::get_component_string(ps
.compref());
981 ret_val
= mputprintf(ret_val
, " operation on port %s succeeded, %s from %s: %s id %d",
982 (const char*)ps
.port__name(), op2
, source
, (const char*)ps
.parameter(),
984 Free(const_cast<char*>(source
));
987 case API::PortEvent_choice::ALT_msgPortSend
: { // PORTEVENT_M[MC]SEND
988 API::Msg__port__send
const& ms
= pec
.msgPortSend();
990 const char *dest
= COMPONENT::get_component_string(ms
.compref());
991 ret_val
= mputprintf(ret_val
, "Sent on %s to %s%s",
992 (const char*)ms
.port__name(), dest
, (const char*)ms
.parameter());
993 //if (ms.compref() != SYSTEM_COMPREF)
994 Free(const_cast<char*>(dest
));
997 case API::PortEvent_choice::ALT_msgPortRecv
: { // PORTEVENT_M[MC]RECV
998 API::Msg__port__recv
const& ms
= pec
.msgPortRecv();
999 switch (ms
.operation()) {
1000 case API::Port__oper::UNBOUND_VALUE
:
1001 case API::Port__oper::UNKNOWN_VALUE
:
1005 case API::Msg__port__recv_operation::receive__op
:
1006 ret_val
= mputstr(ret_val
, "Receive");
1008 case API::Msg__port__recv_operation::check__receive__op
:
1009 ret_val
= mputstr(ret_val
, "Check-receive");
1011 case API::Msg__port__recv_operation::trigger__op
:
1012 ret_val
= mputstr(ret_val
, "Trigger");
1015 ret_val
= mputprintf(ret_val
, " operation on port %s succeeded, message from ",
1016 (const char *)ms
.port__name());
1018 if (ms
.compref() == SYSTEM_COMPREF
) { // mapped
1019 const char *sys
= ms
.sys__name(); // not dynamic alloc
1020 ret_val
= mputprintf(ret_val
, "system(%s)", sys
);
1022 const char *sys
= COMPONENT::get_component_string(ms
.compref()); // dynamic alloc
1023 ret_val
= mputstr(ret_val
, sys
);
1024 Free(const_cast<char *>(sys
));
1026 const char *ms_parameter
= (const char *)ms
.parameter();
1027 ret_val
= mputprintf(ret_val
, "%s id %d", ms_parameter
, (int)ms
.msgid());
1028 // Inconsistent dot...
1029 if (ms_parameter
== NULL
|| strlen(ms_parameter
) == 0)
1030 ret_val
= mputc(ret_val
, '.');
1033 case API::PortEvent_choice::ALT_dualMapped
: {
1034 API::Dualface__mapped
const& dual
= pec
.dualMapped();
1035 ret_val
= mputprintf(ret_val
, "%s message was mapped to %s : %s",
1036 (dual
.incoming() ? "Incoming" : "Outgoing"),
1037 (const char*)dual
.target__type(), (const char*)dual
.value__());
1039 if (dual
.incoming()) {
1040 ret_val
= mputprintf(ret_val
, " id %d", (int)dual
.msgid());
1044 case API::PortEvent_choice::ALT_dualDiscard
: {
1045 API::Dualface__discard
const& dualop
= pec
.dualDiscard();
1046 ret_val
= mputprintf(ret_val
, "%s message of type %s ",
1047 (dualop
.incoming() ? "Incoming" : "Outgoing"),
1048 (const char*)dualop
.target__type());
1050 ret_val
= mputprintf(ret_val
, (dualop
.unhandled()
1051 ? "could not be handled by the type mapping rules on port %s."
1052 " The message was discarded."
1053 : "was discarded on port %s."),
1054 (const char*) dualop
.port__name());
1057 case API::PortEvent_choice::ALT_portMisc
: {
1058 API::Port__Misc
const& pmisc
= pec
.portMisc();
1059 const char *comp_str
= COMPONENT::get_component_string(pmisc
.remote__component());
1060 switch (pmisc
.reason()) {
1061 case API::Port__Misc_reason::UNBOUND_VALUE
:
1062 case API::Port__Misc_reason::UNKNOWN_VALUE
:
1067 case API::Port__Misc_reason::removing__unterminated__connection
:
1068 ret_val
= mputprintf(ret_val
,
1069 "Removing unterminated connection between port %s and %s:%s.",
1070 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1072 case API::Port__Misc_reason::removing__unterminated__mapping
:
1073 ret_val
= mputprintf(ret_val
,
1074 "Removing unterminated mapping between port %s and system:%s.",
1075 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1077 case API::Port__Misc_reason::port__was__cleared
:
1078 ret_val
= mputprintf(ret_val
, "Port %s was cleared.",
1079 (const char*)pmisc
.port__name());
1081 case API::Port__Misc_reason::local__connection__established
:
1082 ret_val
= mputprintf(ret_val
,
1083 "Port %s has established the connection with local port %s.",
1084 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1086 case API::Port__Misc_reason::local__connection__terminated
:
1087 ret_val
= mputprintf(ret_val
,
1088 "Port %s has terminated the connection with local port %s.",
1089 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1091 case API::Port__Misc_reason::port__is__waiting__for__connection__tcp
:
1092 ret_val
= mputprintf(ret_val
,
1093 "Port %s is waiting for connection from %s:%s on TCP port %s:%d.",
1094 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1095 (const char*)pmisc
.ip__address(), (int)pmisc
.tcp__port());
1097 case API::Port__Misc_reason::port__is__waiting__for__connection__unix
:
1098 ret_val
= mputprintf(ret_val
,
1099 "Port %s is waiting for connection from %s:%s on UNIX pathname %s.",
1100 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1101 (const char*)pmisc
.ip__address());
1103 case API::Port__Misc_reason::connection__established
:
1104 ret_val
= mputprintf(ret_val
,
1105 "Port %s has established the connection with %s:%s using transport type %s.",
1106 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1107 (const char*)pmisc
.ip__address());
1109 case API::Port__Misc_reason::destroying__unestablished__connection
:
1110 ret_val
= mputprintf(ret_val
,
1111 "Destroying unestablished connection of port %s to %s:%s"
1112 " because the other endpoint has terminated.",
1113 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1115 case API::Port__Misc_reason::terminating__connection
:
1116 ret_val
= mputprintf(ret_val
,
1117 "Terminating the connection of port %s to %s:%s."
1118 " No more messages can be sent through this connection.",
1119 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1121 case API::Port__Misc_reason::sending__termination__request__failed
:
1122 ret_val
= mputprintf(ret_val
, "Sending the connection termination request"
1123 " on port %s to remote endpoint %s:%s failed.",
1124 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1126 case API::Port__Misc_reason::termination__request__received
:
1127 ret_val
= mputprintf(ret_val
,
1128 "Connection termination request was received on port %s from %s:%s."
1129 " No more data can be sent or received through this connection.",
1130 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1132 case API::Port__Misc_reason::acknowledging__termination__request__failed
:
1133 ret_val
= mputprintf(ret_val
,
1134 "Sending the acknowledgment for connection termination request"
1135 " on port %s to remote endpoint %s:%s failed.",
1136 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1138 case API::Port__Misc_reason::sending__would__block
:
1139 ret_val
= mputprintf(ret_val
,
1140 "Sending data on the connection of port %s to %s:%s would block execution."
1141 " The size of the outgoing buffer was increased from %d to %d bytes.",
1142 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port(),
1143 (int)pmisc
.tcp__port(), (int)pmisc
.new__size());
1145 case API::Port__Misc_reason::connection__accepted
:
1146 ret_val
= mputprintf(ret_val
, "Port %s has accepted the connection from %s:%s.",
1147 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1149 case API::Port__Misc_reason::connection__reset__by__peer
:
1150 ret_val
= mputprintf(ret_val
, "Connection of port %s to %s:%s was reset by the peer.",
1151 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1153 case API::Port__Misc_reason::connection__closed__by__peer
:
1154 ret_val
= mputprintf(ret_val
,
1155 "Connection of port %s to %s:%s was closed unexpectedly by the peer.",
1156 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1158 case API::Port__Misc_reason::port__disconnected
:
1159 ret_val
= mputprintf(ret_val
, "Port %s was disconnected from %s:%s.",
1160 (const char*)pmisc
.port__name(), comp_str
, (const char*)pmisc
.remote__port());
1162 case API::Port__Misc_reason::port__was__mapped__to__system
:
1163 ret_val
= mputprintf(ret_val
, "Port %s was mapped to system:%s.",
1164 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1166 case API::Port__Misc_reason::port__was__unmapped__from__system
:
1167 ret_val
= mputprintf(ret_val
, "Port %s was unmapped from system:%s.",
1168 (const char*)pmisc
.port__name(), (const char*)pmisc
.remote__port());
1172 Free(const_cast<char*>(comp_str
));
1177 case TitanLoggerApi::PortEvent_choice::UNBOUND_VALUE
:
1182 void matchingop_str(char *& ret_val
, const TitanLoggerApi::MatchingEvent_choice
& choice
)
1184 switch (choice
.get_selection()) {
1185 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingDone
: {
1186 TitanLoggerApi::MatchingDoneType
const& md
= choice
.matchingDone();
1187 switch (md
.reason()) {
1188 case TitanLoggerApi::MatchingDoneType_reason::UNBOUND_VALUE
:
1189 case TitanLoggerApi::MatchingDoneType_reason::UNKNOWN_VALUE
:
1193 case TitanLoggerApi::MatchingDoneType_reason::done__failed__no__return
:
1194 ret_val
= mputprintf(ret_val
, "Done operation with type %s on PTC %d"
1195 " failed: The started function did not return a value.",
1196 (const char*)md
.type__(), (int)md
.ptc());
1198 case TitanLoggerApi::MatchingDoneType_reason::done__failed__wrong__return__type
:
1199 ret_val
= mputprintf(ret_val
, "Done operation with type %s on PTC %d"
1200 " failed: The started function returned a value of type %s.",
1201 (const char*)md
.type__(), (int)md
.ptc(), (const char*)md
.return__type());
1203 case TitanLoggerApi::MatchingDoneType_reason::any__component__done__successful
:
1204 ret_val
= mputstr(ret_val
, "Operation 'any component.done' was successful.");
1206 case TitanLoggerApi::MatchingDoneType_reason::any__component__done__failed
:
1207 ret_val
= mputstr(ret_val
, "Operation 'any component.done' "
1208 "failed because no PTCs were created in the testcase.");
1210 case TitanLoggerApi::MatchingDoneType_reason::all__component__done__successful
:
1211 ret_val
= mputstr(ret_val
, "Operation 'all component.done' was successful.");
1213 case TitanLoggerApi::MatchingDoneType_reason::any__component__killed__successful
:
1214 ret_val
= mputstr(ret_val
, "Operation 'any component.killed' was successful.");
1216 case TitanLoggerApi::MatchingDoneType_reason::any__component__killed__failed
:
1217 ret_val
= mputstr(ret_val
, "Operation 'any component.killed' "
1218 "failed because no PTCs were created in the testcase.");
1220 case TitanLoggerApi::MatchingDoneType_reason::all__component__killed__successful
:
1221 ret_val
= mputstr(ret_val
, "Operation 'all component.killed' was successful.");
1226 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingFailure
: {
1227 boolean is_call
= FALSE
;
1228 TitanLoggerApi::MatchingFailureType
const& mf
= choice
.matchingFailure();
1229 switch (mf
.reason()) {
1230 case TitanLoggerApi::MatchingFailureType_reason::UNBOUND_VALUE
:
1231 case TitanLoggerApi::MatchingFailureType_reason::UNKNOWN_VALUE
:
1234 return; // can't happen
1235 case TitanLoggerApi::MatchingFailureType_reason::message__does__not__match__template
:
1236 ret_val
= mputprintf(ret_val
,
1237 "Matching on port %s "
1238 "%s: First message in the queue does not match the template: ",
1239 (const char*)mf
.port__name(), (const char*)mf
.info());
1241 case TitanLoggerApi::MatchingFailureType_reason::exception__does__not__match__template
:
1242 ret_val
= mputprintf(ret_val
,
1243 "Matching on port %s failed: "
1244 "The first exception in the queue does not match the template: %s",
1245 (const char*)mf
.port__name(), (const char*)mf
.info());
1247 case TitanLoggerApi::MatchingFailureType_reason::parameters__of__call__do__not__match__template
:
1248 is_call
= TRUE
; // fall through
1249 case TitanLoggerApi::MatchingFailureType_reason::parameters__of__reply__do__not__match__template
:
1250 ret_val
= mputprintf(ret_val
,
1251 "Matching on port %s failed: "
1252 "The parameters of the first %s in the queue do not match the template: %s",
1253 (is_call
? "call" : "reply"),
1254 (const char*)mf
.port__name(), (const char*)mf
.info());
1256 case TitanLoggerApi::MatchingFailureType_reason::sender__does__not__match__from__clause
:
1257 ret_val
= mputprintf(ret_val
,
1258 "Matching on port %s failed: "
1259 "Sender of the first entity in the queue does not match the from clause: %s",
1260 (const char*)mf
.port__name(), (const char*)mf
.info());
1262 case TitanLoggerApi::MatchingFailureType_reason::sender__is__not__system
:
1263 ret_val
= mputprintf(ret_val
,
1264 "Matching on port %s failed: "
1265 "Sender of the first entity in the queue is not the system.",
1266 (const char*)mf
.port__name());
1268 case TitanLoggerApi::MatchingFailureType_reason::not__an__exception__for__signature
:
1269 ret_val
= mputprintf(ret_val
,
1270 "Matching on port %s failed: "
1271 "The first entity in the queue is not an exception for signature %s.",
1272 (const char*)mf
.port__name(), (const char*)mf
.info());
1277 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingSuccess
: {
1278 TitanLoggerApi::MatchingSuccessType
const& ms
= choice
.matchingSuccess();
1279 ret_val
= mputprintf(ret_val
, "Matching on port %s succeeded: %s",
1280 (const char*)ms
.port__name(), (const char*)ms
.info());
1283 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingProblem
: {
1284 TitanLoggerApi::MatchingProblemType
const& mp
= choice
.matchingProblem();
1285 ret_val
= mputstr(ret_val
, "Operation `");
1286 if (mp
.any__port()) ret_val
= mputstr(ret_val
, "any port.");
1287 if (mp
.check__()) ret_val
= mputstr(ret_val
, "check(");
1288 switch (mp
.operation()) {
1289 case TitanLoggerApi::MatchingProblemType_operation::UNBOUND_VALUE
:
1290 case TitanLoggerApi::MatchingProblemType_operation::UNKNOWN_VALUE
:
1293 case TitanLoggerApi::MatchingProblemType_operation::receive__
:
1294 ret_val
= mputstr(ret_val
, "receive");
1296 case TitanLoggerApi::MatchingProblemType_operation::trigger__
:
1297 ret_val
= mputstr(ret_val
, "trigger");
1299 case TitanLoggerApi::MatchingProblemType_operation::getcall__
:
1300 ret_val
= mputstr(ret_val
, "getcall");
1302 case TitanLoggerApi::MatchingProblemType_operation::getreply__
:
1303 ret_val
= mputstr(ret_val
, "getreply");
1305 case TitanLoggerApi::MatchingProblemType_operation::catch__
:
1306 ret_val
= mputstr(ret_val
, "catch");
1308 case TitanLoggerApi::MatchingProblemType_operation::check__
:
1309 ret_val
= mputstr(ret_val
, "check");
1312 if (mp
.check__()) ret_val
= mputstr(ret_val
, ")");
1313 ret_val
= mputstr(ret_val
, "' ");
1315 if (mp
.port__name().is_bound()) ret_val
= mputprintf(ret_val
,
1316 "on port %s ", (const char*)mp
.port__name());
1317 // we could also check that any__port is false
1319 ret_val
= mputstr(ret_val
, "failed: ");
1321 switch (mp
.reason()) {
1322 case TitanLoggerApi::MatchingProblemType_reason::UNBOUND_VALUE
:
1323 case TitanLoggerApi::MatchingProblemType_reason::UNKNOWN_VALUE
:
1326 case TitanLoggerApi::MatchingProblemType_reason::component__has__no__ports
:
1327 ret_val
= mputstr(ret_val
, "The test component does not have ports.");
1329 case TitanLoggerApi::MatchingProblemType_reason::no__incoming__signatures
:
1330 ret_val
= mputstr(ret_val
, "The port type does not have any incoming signatures.");
1332 case TitanLoggerApi::MatchingProblemType_reason::no__incoming__types
:
1333 ret_val
= mputstr(ret_val
, "The port type does not have any incoming message types.");
1335 case TitanLoggerApi::MatchingProblemType_reason::no__outgoing__blocking__signatures
:
1336 ret_val
= mputstr(ret_val
, "The port type does not have any outgoing blocking signatures.");
1338 case TitanLoggerApi::MatchingProblemType_reason::no__outgoing__blocking__signatures__that__support__exceptions
:
1339 ret_val
= mputstr(ret_val
, "The port type does not have any outgoing blocking signatures that support exceptions.");
1341 case TitanLoggerApi::MatchingProblemType_reason::port__not__started__and__queue__empty
:
1342 ret_val
= mputstr(ret_val
, "Port is not started and the queue is empty.");
1345 break; } // matchingProblem
1347 case TitanLoggerApi::MatchingEvent_choice::ALT_matchingTimeout
: {
1348 TitanLoggerApi::MatchingTimeout
const& mt
= choice
.matchingTimeout();
1349 if (mt
.timer__name().ispresent()) {
1350 ret_val
= mputprintf(ret_val
, "Timeout operation on timer %s failed:"
1351 " The timer is not started.", (const char*)mt
.timer__name()());
1354 ret_val
= mputstr(ret_val
, "Operation `any timer.timeout' failed:"
1355 " The test component does not have active timers.");
1359 case TitanLoggerApi::MatchingEvent_choice::UNBOUND_VALUE
:
1366 void parallel_str(char *& ret_val
, const TitanLoggerApi::ParallelEvent_choice
& choice
)
1368 switch (choice
.get_selection()) {
1369 case TitanLoggerApi::ParallelEvent_choice::ALT_parallelPTC
: {
1370 TitanLoggerApi::ParallelPTC
const& ptc
= choice
.parallelPTC();
1371 switch (ptc
.reason()) {
1372 case TitanLoggerApi::ParallelPTC_reason::UNKNOWN_VALUE
:
1373 case TitanLoggerApi::ParallelPTC_reason::UNBOUND_VALUE
:
1377 case TitanLoggerApi::ParallelPTC_reason::init__component__start
:
1378 ret_val
= mputprintf(ret_val
,
1379 "Initializing variables, timers and ports of component type %s.%s",
1380 (const char*)ptc
.module__(), (const char*)ptc
.name());
1381 if (ptc
.tc__loc().lengthof()) ret_val
= mputprintf(ret_val
,
1382 " inside testcase %s", (const char*)ptc
.tc__loc());
1383 ret_val
= mputc(ret_val
, '.');
1385 case TitanLoggerApi::ParallelPTC_reason::init__component__finish
:
1386 ret_val
= mputprintf(ret_val
, "Component type %s.%s was initialized.",
1387 (const char*)ptc
.module__(), (const char*)ptc
.name());
1389 case TitanLoggerApi::ParallelPTC_reason::terminating__component
:
1390 ret_val
= mputprintf(ret_val
, "Terminating component type %s.%s.",
1391 (const char*)ptc
.module__(), (const char*)ptc
.name());
1393 case TitanLoggerApi::ParallelPTC_reason::component__shut__down
:
1394 ret_val
= mputprintf(ret_val
, "Component type %s.%s was shut down",
1395 (const char*)ptc
.module__(), (const char*)ptc
.name());
1396 if (ptc
.tc__loc().lengthof()) ret_val
= mputprintf(ret_val
,
1397 " inside testcase %s", (const char*)ptc
.tc__loc());
1398 ret_val
= mputc(ret_val
, '.');
1400 case TitanLoggerApi::ParallelPTC_reason::error__idle__ptc
:
1401 ret_val
= mputstr(ret_val
,
1402 "Error occurred on idle PTC. The component terminates.");
1404 case TitanLoggerApi::ParallelPTC_reason::ptc__created
:
1405 ret_val
= mputprintf(ret_val
, "PTC was created."
1406 " Component reference: %d, alive: %s, type: %s.%s",
1407 (int)ptc
.compref(), (ptc
.alive__pid() ? "yes" : "no"),
1408 (const char*)ptc
.module__(), (const char*)ptc
.name());
1409 // The "testcase" member is used for the component name
1410 if (ptc
.compname().lengthof() != 0) ret_val
= mputprintf(ret_val
,
1411 ", component name: %s", (const char*)ptc
.compname());
1412 if (ptc
.tc__loc().lengthof() != 0) ret_val
= mputprintf(ret_val
,
1413 ", location: %s", (const char*)ptc
.tc__loc());
1414 ret_val
= mputc(ret_val
, '.');
1417 case API::ParallelPTC_reason::ptc__created__pid
:
1418 ret_val
= mputprintf(ret_val
, "PTC was created. Component reference: %d, "
1419 "component type: %s.%s", (int)ptc
.compref(),
1420 (const char*)ptc
.module__(), (const char*)ptc
.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 ", testcase name: %s", (const char*)ptc
.tc__loc());
1425 ret_val
= mputprintf(ret_val
, ", process id: %d.", (int)ptc
.alive__pid());
1428 case TitanLoggerApi::ParallelPTC_reason::function__started
:
1429 ret_val
= mputstr(ret_val
, "Function was started.");
1431 case TitanLoggerApi::ParallelPTC_reason::function__stopped
:
1432 ret_val
= mputprintf(ret_val
, "Function %s was stopped. PTC terminates.",
1433 (const char*)ptc
.name());
1435 case TitanLoggerApi::ParallelPTC_reason::function__finished
:
1436 ret_val
= mputprintf(ret_val
, "Function %s finished. PTC %s.",
1437 (const char*)ptc
.name(),
1438 ptc
.alive__pid() ? "remains alive and is waiting for next start" : "terminates");
1440 case TitanLoggerApi::ParallelPTC_reason::function__error
:
1441 ret_val
= mputprintf(ret_val
, "Function %s finished with an error. PTC terminates.",
1442 (const char*)ptc
.name());
1444 case TitanLoggerApi::ParallelPTC_reason::ptc__done
:
1445 ret_val
= mputprintf(ret_val
, "PTC with component reference %d is done.",
1446 (int)ptc
.compref());
1448 case TitanLoggerApi::ParallelPTC_reason::ptc__killed
:
1449 ret_val
= mputprintf(ret_val
, "PTC with component reference %d is killed.",
1450 (int)ptc
.compref());
1452 case TitanLoggerApi::ParallelPTC_reason::stopping__mtc
:
1453 ret_val
= mputstr(ret_val
, "Stopping MTC. The current test case will be terminated.");
1455 case TitanLoggerApi::ParallelPTC_reason::ptc__stopped
:
1456 ret_val
= mputprintf(ret_val
, "PTC with component reference %d was stopped.",
1457 (int)ptc
.compref());
1459 case TitanLoggerApi::ParallelPTC_reason::all__comps__stopped
:
1460 ret_val
= mputstr(ret_val
, "All components were stopped.");
1462 case TitanLoggerApi::ParallelPTC_reason::ptc__was__killed
:
1463 ret_val
= mputprintf(ret_val
, "PTC with component reference %d was killed.",
1464 (int)ptc
.compref());
1466 case TitanLoggerApi::ParallelPTC_reason::all__comps__killed
:
1467 ret_val
= mputstr(ret_val
, "All components were killed.");
1469 case TitanLoggerApi::ParallelPTC_reason::kill__request__frm__mc
:
1470 ret_val
= mputstr(ret_val
, "Kill was requested from MC. Terminating idle PTC.");
1472 case TitanLoggerApi::ParallelPTC_reason::mtc__finished
:
1473 ret_val
= mputstr(ret_val
, "MTC finished.");
1474 goto mpt_ptc_together
;
1475 case TitanLoggerApi::ParallelPTC_reason::ptc__finished
: {
1476 if (ptc
.compname().lengthof() != 0) {
1477 ret_val
= mputprintf(ret_val
, "PTC %s(%d) finished.",
1478 (const char*)ptc
.compname(), (int)ptc
.compref());
1480 ret_val
= mputprintf(ret_val
, "PTC with component reference %d "
1481 "finished.", (int)ptc
.compref());
1484 ret_val
= mputprintf(ret_val
, " Process statistics: { "
1485 "process id: %d, ", (int)ptc
.alive__pid());
1486 int statuscode
= ptc
.status();
1487 if (WIFEXITED(statuscode
)) {
1488 ret_val
= mputprintf(ret_val
, "terminated normally, "
1489 "exit status: %d, ", WEXITSTATUS(statuscode
));
1490 } else if (WIFSIGNALED(statuscode
)) {
1491 int signal_number
= WTERMSIG(statuscode
);
1492 ret_val
= mputprintf(ret_val
, "terminated by a signal, "
1493 "signal number: %d (%s), ", signal_number
,
1494 TTCN_Runtime::get_signal_name(signal_number
));
1496 // this macro is not available on all platforms
1497 if (WCOREDUMP(statuscode
))
1498 ret_val
= mputstr(ret_val
, "core dump was created, ");
1501 ret_val
= mputprintf(ret_val
, "termination reason and status is "
1502 "unknown: %d, ", statuscode
);
1504 ret_val
= mputstr(ret_val
, (const char*)ptc
.tc__loc());
1506 case TitanLoggerApi::ParallelPTC_reason::starting__function
:
1509 break; } // parallelPTC
1511 case TitanLoggerApi::ParallelEvent_choice::ALT_parallelPTC__exit
: {
1512 TitanLoggerApi::PTC__exit
const& px
= choice
.parallelPTC__exit();
1513 const int compref
= px
.compref();
1514 if (compref
== MTC_COMPREF
) {
1515 ret_val
= mputstr(ret_val
, "MTC finished.");
1517 const char *comp_name
= COMPONENT::get_component_name(px
.compref());
1518 if (comp_name
) ret_val
= mputprintf(ret_val
, "PTC %s(%d) finished.",
1519 comp_name
, compref
);
1520 else ret_val
= mputprintf(ret_val
, "PTC with component reference %d "
1521 "finished.", compref
);
1523 ret_val
= mputprintf(ret_val
, " Process statistics: { process id: %d, ",
1529 case TitanLoggerApi::ParallelEvent_choice::ALT_parallelPort
: {
1530 TitanLoggerApi::ParPort
const& pp
= choice
.parallelPort();
1531 const char *direction
= "on";
1532 const char *preposition
= "and";
1533 switch(pp
.operation()) {
1534 case API::ParPort_operation::UNBOUND_VALUE
:
1535 case API::ParPort_operation::UNKNOWN_VALUE
:
1539 case API::ParPort_operation::connect__
:
1540 ret_val
= mputstr(ret_val
, "Connect");
1542 case API::ParPort_operation::disconnect__
:
1543 ret_val
= mputstr(ret_val
, "Disconnect");
1545 case API::ParPort_operation::map__
:
1546 ret_val
= mputstr(ret_val
, "Map");
1550 case API::ParPort_operation::unmap__
:
1551 ret_val
= mputstr(ret_val
, "Unmap");
1553 preposition
= "from";
1556 char *src
= COMPONENT::get_component_string(pp
.srcCompref());
1557 char *dst
= COMPONENT::get_component_string(pp
.dstCompref());
1558 ret_val
= mputprintf(ret_val
, " operation %s %s:%s %s %s:%s finished.",
1559 direction
, src
, (const char*)pp
.srcPort(), preposition
,
1560 dst
, (const char*)pp
.dstPort());
1565 case TitanLoggerApi::ParallelEvent_choice::UNBOUND_VALUE
:
1572 void testcaseop_str(char *& ret_val
, const TitanLoggerApi::TestcaseEvent_choice
& choice
)
1574 switch (choice
.get_selection()) {
1575 case TitanLoggerApi::TestcaseEvent_choice::ALT_testcaseStarted
: {
1576 ret_val
= mputprintf(ret_val
, "Test case %s started.",
1577 (const char *)choice
.testcaseStarted().testcase__name());
1580 case TitanLoggerApi::TestcaseEvent_choice::ALT_testcaseFinished
: {
1581 const TitanLoggerApi::TestcaseType
& testcase
= choice
.testcaseFinished();
1582 ret_val
= mputprintf(ret_val
, "Test case %s finished. Verdict: %s",
1583 (const char *)testcase
.name().testcase__name(),
1584 verdict_name
[testcase
.verdict()]);
1585 if (testcase
.reason().lengthof() > 0) {
1586 ret_val
= mputprintf(ret_val
, " reason: %s", (const char *)testcase
.reason());
1590 case TitanLoggerApi::TestcaseEvent_choice::UNBOUND_VALUE
:
1597 void verdictop_str(char *& ret_val
, const TitanLoggerApi::VerdictOp_choice
& choice
)
1599 switch (choice
.get_selection()) {
1600 case TitanLoggerApi::VerdictOp_choice::ALT_setVerdict
: {
1601 const TitanLoggerApi::SetVerdictType
& set
= choice
.setVerdict();
1602 if (set
.newVerdict() > set
.oldVerdict()) { // the verdict is changing
1603 if (!set
.oldReason().ispresent() && !set
.newReason().ispresent()) {
1604 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s",
1605 verdict_name
[set
.newVerdict()], verdict_name
[set
.oldVerdict()],
1606 verdict_name
[set
.localVerdict()]);
1608 // The reason text (oldReason() and newReason()) is always the same
1609 // for some reason. Why?
1610 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s reason: "
1611 "\"%s\", new component reason: \"%s\"",
1612 verdict_name
[set
.newVerdict()], verdict_name
[set
.oldVerdict()],
1613 verdict_name
[set
.localVerdict()], (const char *)set
.oldReason()(),
1614 (const char *)set
.newReason()());
1617 if (!set
.oldReason().ispresent() && !set
.newReason().ispresent()) {
1618 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s, component "
1619 "reason not changed", verdict_name
[set
.newVerdict()],
1620 verdict_name
[set
.oldVerdict()], verdict_name
[set
.localVerdict()]);
1622 ret_val
= mputprintf(ret_val
, "setverdict(%s): %s -> %s reason: "
1623 "\"%s\", component reason not changed",
1624 verdict_name
[set
.newVerdict()], verdict_name
[set
.oldVerdict()],
1625 verdict_name
[set
.localVerdict()], (const char *)set
.oldReason()());
1630 case TitanLoggerApi::VerdictOp_choice::ALT_getVerdict
: {
1631 ret_val
= mputprintf(ret_val
, "getverdict: %s",
1632 verdict_name
[choice
.getVerdict()]);
1635 case TitanLoggerApi::VerdictOp_choice::ALT_finalVerdict
: {
1636 switch (choice
.finalVerdict().choice().get_selection()) {
1637 case TitanLoggerApi::FinalVerdictType_choice::ALT_info
: {
1638 const TitanLoggerApi::FinalVerdictInfo
& info
= choice
.finalVerdict().choice().info();
1639 if (info
.is__ptc()) {
1640 if ((int)info
.ptc__compref().ispresent() && (int)info
.ptc__compref()() != UNBOUND_COMPREF
) {
1641 if (info
.ptc__name().ispresent() && info
.ptc__name()().lengthof() > 0) {
1642 ret_val
= mputprintf(ret_val
, "Local verdict of PTC %s(%d): ",
1643 (const char *)info
.ptc__name()(), (int)info
.ptc__compref()());
1645 ret_val
= mputprintf(ret_val
, "Local verdict of PTC with "
1646 "component reference %d: ", (int)info
.ptc__compref()());
1648 ret_val
= mputprintf(ret_val
, "%s (%s -> %s)",
1649 verdict_name
[info
.ptc__verdict()], verdict_name
[info
.local__verdict()],
1650 verdict_name
[info
.new__verdict()]);
1651 if (info
.verdict__reason().ispresent() &&
1652 info
.verdict__reason()().lengthof() > 0)
1653 ret_val
= mputprintf(ret_val
, " reason: \"%s\"",
1654 (const char *)info
.verdict__reason()());
1656 ret_val
= mputprintf(ret_val
, "Final verdict of PTC: %s",
1657 verdict_name
[info
.local__verdict()]);
1658 if (info
.verdict__reason().ispresent() &&
1659 info
.verdict__reason()().lengthof() > 0) {
1660 ret_val
= mputprintf(ret_val
, " reason: \"%s\"",
1661 (const char *)info
.verdict__reason()());
1665 ret_val
= mputprintf(ret_val
, "Local verdict of MTC: %s",
1666 verdict_name
[info
.local__verdict()]);
1667 if (info
.verdict__reason().ispresent() &&
1668 info
.verdict__reason()().lengthof() > 0) {
1669 ret_val
= mputprintf(ret_val
, " reason: \"%s\"",
1670 (const char *)info
.verdict__reason()());
1674 case TitanLoggerApi::FinalVerdictType_choice::ALT_notification
:
1675 switch (choice
.finalVerdict().choice().notification()) {
1676 case TitanLoggerApi::FinalVerdictType_choice_notification::no__ptcs__were__created
:
1677 ret_val
= mputstr(ret_val
, "No PTCs were created.");
1679 case TitanLoggerApi::FinalVerdictType_choice_notification::setting__final__verdict__of__the__test__case
:
1680 ret_val
= mputstr(ret_val
, "Setting final verdict of the test case.");
1682 case TitanLoggerApi::FinalVerdictType_choice_notification::UNBOUND_VALUE
:
1683 case TitanLoggerApi::FinalVerdictType_choice_notification::UNKNOWN_VALUE
:
1688 case TitanLoggerApi::FinalVerdictType_choice::UNBOUND_VALUE
:
1694 case TitanLoggerApi::VerdictOp_choice::UNBOUND_VALUE
:
1701 void statistics_str(char *& ret_val
, const TitanLoggerApi::StatisticsType_choice
& choice
)
1703 switch (choice
.get_selection()) {
1704 case TitanLoggerApi::StatisticsType_choice::ALT_verdictStatistics
: {
1705 const TitanLoggerApi::StatisticsType_choice_verdictStatistics
& statistics
=
1706 choice
.verdictStatistics();
1707 unsigned long none_count
= (size_t)statistics
.none__(),
1708 pass_count
= (size_t)statistics
.pass__(),
1709 inconc_count
= (size_t)statistics
.inconc__(),
1710 fail_count
= (size_t)statistics
.fail__(),
1711 error_count
= (size_t)statistics
.error__();
1712 if (none_count
> 0 || pass_count
> 0 || inconc_count
> 0 ||
1713 fail_count
> 0 || error_count
> 0) {
1714 ret_val
= mputprintf(ret_val
,
1715 "Verdict statistics: %lu none (%.2f %%), %lu pass (%.2f %%), %lu inconc "
1716 "(%.2f %%), %lu fail (%.2f %%), %lu error (%.2f %%).",
1717 none_count
, (float)statistics
.nonePercent(),
1718 pass_count
, (float)statistics
.passPercent(),
1719 inconc_count
, (float)statistics
.inconcPercent(),
1720 fail_count
, (float)statistics
.failPercent(),
1721 error_count
, (float)statistics
.errorPercent());
1723 ret_val
= mputstr(ret_val
,
1724 "Verdict statistics: 0 none, 0 pass, 0 inconc, 0 fail, 0 error.");
1728 case TitanLoggerApi::StatisticsType_choice::ALT_controlpartStart
:
1729 ret_val
= mputprintf(ret_val
, "Execution of control part in module %s %sed.",
1730 (const char*)choice
.controlpartStart(), "start");
1733 case TitanLoggerApi::StatisticsType_choice::ALT_controlpartFinish
:
1734 // The compiler might fold the two identical format strings
1735 ret_val
= mputprintf(ret_val
, "Execution of control part in module %s %sed.",
1736 (const char*)choice
.controlpartFinish(), "finish");
1739 case TitanLoggerApi::StatisticsType_choice::ALT_controlpartErrors
:
1740 ret_val
= mputprintf(ret_val
, "Number of errors outside test cases: %u",
1741 (unsigned int)choice
.controlpartErrors());
1744 case TitanLoggerApi::StatisticsType_choice::UNBOUND_VALUE
:
1751 char *event_to_str(const TitanLoggerApi::TitanLogEvent
& event
,
1752 bool without_header
)
1754 char *ret_val
= NULL
;
1755 if (!without_header
) {
1756 struct timeval timestamp
= { (time_t)event
.timestamp().seconds(),
1757 (suseconds_t
)event
.timestamp().microSeconds() };
1758 char *sourceinfo
= NULL
;
1759 if (event
.sourceInfo__list().is_bound()) {
1760 TTCN_Logger::source_info_format_t source_info_format
=
1761 TTCN_Logger::get_source_info_format();
1762 int stack_size
= event
.sourceInfo__list().size_of();
1763 if (stack_size
> 0) {
1765 switch (source_info_format
) {
1766 case TTCN_Logger::SINFO_NONE
:
1767 i
= stack_size
; // start == end; nothing printed
1769 case TTCN_Logger::SINFO_SINGLE
:
1770 i
= stack_size
- 1; // print just the last one
1772 case TTCN_Logger::SINFO_STACK
:
1773 // do nothing, start from the beginning
1777 for (; i
< stack_size
; ++i
) {
1778 API::LocationInfo
const& loc
= event
.sourceInfo__list()[i
];
1780 if (sourceinfo
) sourceinfo
= mputstr(sourceinfo
, "->");
1781 const char *file_name
= loc
.filename();
1782 int line_number
= loc
.line();
1783 const char *entity_name
= loc
.ent__name();
1784 API::LocationInfo_ent__type entity_type
= loc
.ent__type();
1785 sourceinfo
= mputprintf(sourceinfo
, "%s:%u", file_name
, line_number
);
1786 if (TTCN_Logger::get_log_entity_name()) {
1787 switch (entity_type
) {
1788 case API::LocationInfo_ent__type::controlpart
:
1789 sourceinfo
= mputprintf(sourceinfo
, "(controlpart:%s)", entity_name
);
1791 case API::LocationInfo_ent__type::testcase__
:
1792 sourceinfo
= mputprintf(sourceinfo
, "(testcase:%s)", entity_name
);
1794 case API::LocationInfo_ent__type::altstep__
:
1795 sourceinfo
= mputprintf(sourceinfo
, "(altstep:%s)", entity_name
);
1797 case API::LocationInfo_ent__type::function__
:
1798 sourceinfo
= mputprintf(sourceinfo
, "(function:%s)", entity_name
);
1800 case API::LocationInfo_ent__type::external__function
:
1801 sourceinfo
= mputprintf(sourceinfo
, "(externalfunction:%s)", entity_name
);
1803 case API::LocationInfo_ent__type::template__
:
1804 sourceinfo
= mputprintf(sourceinfo
, "(template:%s)", entity_name
);
1806 case API::LocationInfo_ent__type::UNBOUND_VALUE
:
1807 case API::LocationInfo_ent__type::UNKNOWN_VALUE
:
1808 case API::LocationInfo_ent__type::unknown
:
1815 if (source_info_format
== TTCN_Logger::SINFO_SINGLE
||
1816 source_info_format
== TTCN_Logger::SINFO_STACK
)
1817 sourceinfo
= mputc(sourceinfo
, '-');
1821 ret_val
= append_header(ret_val
, timestamp
,
1822 (const TTCN_Logger::Severity
)(int)event
.severity(), sourceinfo
);
1826 // Big, ugly switch to append the event message.
1827 // TODO: We need a fancier implementation.
1828 const TitanLoggerApi::LogEventType_choice
& choice
= event
.logEvent().choice();
1829 switch (choice
.get_selection()) {
1830 case TitanLoggerApi::LogEventType_choice::UNBOUND_VALUE
:
1833 case TitanLoggerApi::LogEventType_choice::ALT_unhandledEvent
: {
1834 ret_val
= mputstr(ret_val
,
1835 (const char *)choice
.unhandledEvent());
1838 case API::LogEventType_choice::ALT_timerEvent
:
1839 timer_event_str(ret_val
, choice
.timerEvent().choice());
1842 case TitanLoggerApi::LogEventType_choice::ALT_statistics
:
1843 statistics_str(ret_val
, choice
.statistics().choice());
1846 case TitanLoggerApi::LogEventType_choice::ALT_verdictOp
:
1847 verdictop_str(ret_val
, choice
.verdictOp().choice());
1851 case TitanLoggerApi::LogEventType_choice::ALT_testcaseOp
:
1852 testcaseop_str(ret_val
, choice
.testcaseOp().choice());
1855 case TitanLoggerApi::LogEventType_choice::ALT_actionEvent
:
1857 case TitanLoggerApi::LogEventType_choice::ALT_userLog
: {
1858 API::Strings_str__list
const& slist
=
1859 (choice
.get_selection() == TitanLoggerApi::LogEventType_choice::ALT_userLog
)
1860 ? choice
.userLog().str__list()
1861 : choice
.actionEvent().str__list();
1862 for (int i
= 0, size
= slist
.size_of(); i
< size
; ++i
) {
1863 ret_val
= mputstr(ret_val
, (const char *)slist
[i
]);
1867 case TitanLoggerApi::LogEventType_choice::ALT_debugLog
: {
1868 // TODO: We support multiple type of DEBUG_* events.
1869 ret_val
= mputstr(ret_val
, (const char *)choice
.debugLog().text());
1872 case TitanLoggerApi::LogEventType_choice::ALT_errorLog
: {
1873 ret_val
= mputstr(ret_val
, (const char *)choice
.errorLog().text());
1876 case TitanLoggerApi::LogEventType_choice::ALT_warningLog
: {
1877 ret_val
= mputstr(ret_val
, (const char *)choice
.warningLog().text());
1880 case TitanLoggerApi::LogEventType_choice::ALT_defaultEvent
:
1881 defaultop_event_str(ret_val
, choice
.defaultEvent().choice());
1884 case TitanLoggerApi::LogEventType_choice::ALT_executionSummary
: {
1885 // FIXME why is this empty?
1888 case TitanLoggerApi::LogEventType_choice::ALT_executorEvent
: {
1889 // En Taro Adun, executor!
1890 executor_event_str(ret_val
, choice
.executorEvent().choice());
1891 break; } // executorRuntime
1893 case TitanLoggerApi::LogEventType_choice::ALT_matchingEvent
:
1894 matchingop_str(ret_val
, choice
.matchingEvent().choice());
1897 case TitanLoggerApi::LogEventType_choice::ALT_functionEvent
:
1898 switch (choice
.functionEvent().choice().get_selection()) {
1899 case TitanLoggerApi::FunctionEvent_choice::ALT_random
: {
1900 TitanLoggerApi::FunctionEvent_choice_random
const& ra
= choice
.functionEvent().choice().random();
1901 switch (ra
.operation()) {
1902 case TitanLoggerApi::RandomAction::seed
: {
1903 long integer_seed
= ra
.intseed();
1904 ret_val
= mputprintf(ret_val
, "Random number generator was initialized with seed %f: "
1905 "srand48(%ld).", (double)ra
.retval(), integer_seed
);
1907 case TitanLoggerApi::RandomAction::read__out
:
1908 ret_val
= mputprintf(ret_val
, "Function rnd() returned %f.", (double)ra
.retval());
1910 case TitanLoggerApi::RandomAction::UNBOUND_VALUE
:
1911 case TitanLoggerApi::RandomAction::UNKNOWN_VALUE
:
1913 return NULL
; // something went wrong
1918 case TitanLoggerApi::FunctionEvent_choice::ALT_unqualified
:
1921 case TitanLoggerApi::FunctionEvent_choice::UNBOUND_VALUE
:
1927 case TitanLoggerApi::LogEventType_choice::ALT_parallelEvent
:
1928 parallel_str(ret_val
, choice
.parallelEvent().choice());
1931 case TitanLoggerApi::LogEventType_choice::ALT_portEvent
:
1932 portevent_str(ret_val
, choice
.portEvent().choice());
1936 return NULL
; // can't happen
1937 } // the big ugly switch
1942 #pragma GCC diagnostic pop
1945 void LegacyLogger::open_file(bool is_first
)
1949 if (!this->skeleton_given_
)
1950 set_file_name(TTCN_Runtime::is_single()
1951 ? (this->logfile_number_
== 1 ? "%e.%s" : "%e-part%i.%s")
1952 : (this->logfile_number_
== 1 ? "%e.%h-%r.%s" : "%e.%h-%r-part%i.%s"),
1955 // Logging_Bits have only effect on the actual plug-in. (Filtering is
1956 // implemented at higher level.)
1957 Free(this->current_filename_
);
1958 this->current_filename_
= get_file_name(this->logfile_index_
);
1959 if (this->current_filename_
!= NULL
) {
1960 create_parent_directories(this->current_filename_
);
1961 this->log_fp_
= fopen(this->current_filename_
,
1962 this->append_file_
? "a" : "w");
1963 if (this->log_fp_
== NULL
)
1964 fatal_error("Opening of log file `%s' for writing failed.",
1965 this->current_filename_
);
1966 if (!TTCN_Communication::set_close_on_exec(fileno(this->log_fp_
))) {
1967 fclose(this->log_fp_
);
1968 fatal_error("Setting the close-on-exec flag failed on log file `%s'.",
1969 this->current_filename_
);
1973 this->is_configured_
= true;
1974 this->logfile_bytes_
= 0;
1977 void LegacyLogger::close_file()
1979 if (!this->log_fp_
) return;
1980 fclose(this->log_fp_
);
1981 this->log_fp_
= NULL
;
1984 /** @brief Construct the log file name, performs substitutions.
1986 @return NULL if filename_skeleton is NULL or if the result would have been
1988 @return an expstring_t with the actual filename. The caller is
1989 responsible for deallocating it with Free().
1991 char *LegacyLogger::get_file_name(size_t idx
)
1993 if (this->filename_skeleton_
== NULL
) return NULL
;
1994 enum { SINGLE
, HC
, MTC
, PTC
} whoami
;
1995 if (TTCN_Runtime::is_single()) whoami
= SINGLE
;
1996 else if (TTCN_Runtime::is_hc()) whoami
= HC
;
1997 else if (TTCN_Runtime::is_mtc()) whoami
= MTC
;
1999 bool h_present
= false, p_present
= false, r_present
= false,
2001 this->format_c_present_
= false;
2002 this->format_t_present_
= false;
2003 char *ret_val
= memptystr();
2004 for (size_t i
= 0; this->filename_skeleton_
[i
] != '\0'; i
++) {
2005 if (this->filename_skeleton_
[i
] != '%') {
2006 ret_val
= mputc(ret_val
, this->filename_skeleton_
[i
]);
2009 switch (this->filename_skeleton_
[++i
]) {
2010 case 'c': // %c -> name of the current testcase (only on PTCs)
2011 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_testcase_name());
2012 this->format_c_present_
= true;
2014 case 'e': // %e -> name of executable
2015 ret_val
= mputstr(ret_val
, TTCN_Logger::get_executable_name());
2017 case 'h': // %h -> hostname
2018 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_host_name());
2021 case 'l': { // %l -> login name
2023 struct passwd
*p
= getpwuid(getuid());
2024 if (p
!= NULL
) ret_val
= mputstr(ret_val
, p
->pw_name
);
2027 case 'n': // %n -> component name (optional)
2031 ret_val
= mputstr(ret_val
, "MTC");
2034 ret_val
= mputstr(ret_val
, "HC");
2037 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_component_name());
2042 case 'p': // %p -> process id
2043 ret_val
= mputprintf(ret_val
, "%ld", (long)getpid());
2046 case 'r': // %r -> component reference
2049 ret_val
= mputstr(ret_val
, "single");
2052 ret_val
= mputstr(ret_val
, "hc");
2055 ret_val
= mputstr(ret_val
, "mtc");
2059 ret_val
= mputprintf(ret_val
, "%d", (component
)self
);
2064 case 's': // %s -> default suffix (currently: always "log")
2065 ret_val
= mputstr(ret_val
, "log");
2067 case 't': // %t -> component type (only on PTCs)
2068 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_component_type());
2069 this->format_t_present_
= true;
2071 case 'i': // %i -> log file index
2072 if (this->logfile_number_
!= 1)
2073 ret_val
= mputprintf(ret_val
, "%lu", (unsigned long)idx
);
2076 case '\0': // trailing single %: leave as it is
2077 i
--; // to avoid over-indexing in next iteration
2079 case '%': // escaping: %% -> %
2080 ret_val
= mputc(ret_val
, '%');
2082 default: // unknown sequence: leave as it is
2083 ret_val
= mputc(ret_val
, '%');
2084 ret_val
= mputc(ret_val
, this->filename_skeleton_
[i
]);
2089 static bool already_warned
= false;
2090 if (ret_val
[0] == '\0') { // result is empty
2093 } else if (whoami
== HC
&& !already_warned
) {
2094 already_warned
= true;
2095 if (!h_present
|| (!p_present
&& !r_present
))
2096 TTCN_warning("Skeleton `%s' does not guarantee unique log file name "
2097 "for every test system process. It may cause "
2098 "unpredictable results if several test components try to "
2099 "write into the same log file.", this->filename_skeleton_
);
2101 if (this->logfile_number_
!= 1 && !i_present
) {
2102 TTCN_warning("LogFileNumber = %lu, but `%%i' is missing from the log "
2103 "file name skeleton. `%%i' was appended to the skeleton.",
2104 (unsigned long)this->logfile_number_
);
2105 this->filename_skeleton_
= mputstr(this->filename_skeleton_
, "%i");
2106 ret_val
= mputprintf(ret_val
, "%lu", (unsigned long)idx
);
2111 /** @brief Create all directories in a full path.
2113 Ensures that all directories in the specified path exist (similar to mkdir
2114 -p). Existing directories are skipped, non-existing directories are
2115 created. Calls fatal_error() if a directory cannot be stat'ed or a
2116 non-existing directory cannot be created.
2118 @param path_name full path to log file name
2120 void LegacyLogger::create_parent_directories(const char *path_name
)
2122 char *path_backup
= NULL
;
2123 bool umask_saved
= false;
2124 mode_t old_umask
= 0;
2126 // if path_name is absolute skip the leading '/'(s)
2127 while (path_name
[i
] == '/') i
++;
2128 while (path_name
[i
] != '\0') {
2129 if (path_name
[i
] != '/') {
2133 // path_name up to index i should contain a directory name
2134 if (path_backup
== NULL
) path_backup
= mcopystr(path_name
);
2135 path_backup
[i
] = '\0';
2137 if (stat(path_backup
, &buf
) < 0) {
2138 if (errno
== ENOENT
) {
2139 // if the directory does not exist: create it
2142 old_umask
= umask(0);
2145 if (mkdir(path_backup
, 0755) < 0) {
2146 fatal_error("Creation of directory `%s' failed when trying to open "
2147 "log file `%s'.", path_backup
, path_name
);
2150 fatal_error("stat() system call failed on `%s' when creating parent "
2151 "directories for log file `%s'.", path_backup
, path_name
);
2154 path_backup
[i
] = '/';
2155 // skip over the duplicated slashes
2156 while (path_name
[++i
] == '/') ;
2158 if (umask_saved
) umask(old_umask
);
2162 void LegacyLogger::chk_logfile_data()
2164 if (this->logfile_size_
== 0 && this->logfile_number_
!= 1) {
2165 TTCN_warning("Invalid combination of LogFileSize (= %lu) and "
2166 "LogFileNumber (= %lu). LogFileNumber was reset to 1.",
2167 (unsigned long)this->logfile_size_
,
2168 (unsigned long)this->logfile_number_
);
2169 this->logfile_number_
= 1;
2171 if (this->logfile_size_
> 0 && this->logfile_number_
== 1) {
2172 TTCN_warning("Invalid combination of LogFileSize (= %lu) and "
2173 "LogFileNumber (= %lu). LogFileSize was reset to 0.",
2174 (unsigned long)this->logfile_size_
,
2175 (unsigned long)this->logfile_number_
);
2176 this->logfile_size_
= 0;
2178 if (this->logfile_number_
== 1 &&
2179 this->disk_full_action_
.type
== TTCN_Logger::DISKFULL_DELETE
) {
2180 TTCN_warning("Invalid combination of LogFileNumber (= 1) and "
2181 "DiskFullAction (= Delete). DiskFullAction was reset to "
2183 this->disk_full_action_
.type
= TTCN_Logger::DISKFULL_ERROR
;
2185 if (this->logfile_number_
!= 1 && this->append_file_
) {
2186 TTCN_warning("Invalid combination of LogFileNumber (= %lu) and "
2187 "AppendFile (= Yes). AppendFile was reset to No.",
2188 (unsigned long)this->logfile_number_
);
2189 this->append_file_
= false;
2193 void LegacyLogger::set_file_name(const char *new_filename_skeleton
,
2194 boolean from_config
)
2196 Free(this->filename_skeleton_
);
2197 this->filename_skeleton_
= mcopystr(new_filename_skeleton
);
2198 if (from_config
) this->skeleton_given_
= true;
2201 bool LegacyLogger::set_file_size(int p_size
)
2203 this->logfile_size_
= p_size
;
2207 bool LegacyLogger::set_file_number(int p_number
)
2209 this->logfile_number_
= p_number
;
2213 bool LegacyLogger::set_disk_full_action(
2214 TTCN_Logger::disk_full_action_t p_disk_full_action
)
2216 this->disk_full_action_
= p_disk_full_action
;
2220 // LegacyLogger should be the only provider of log2str().
2221 CHARSTRING
LegacyLogger::log2str(const TitanLoggerApi::TitanLogEvent
& event
)
2223 char *event_str
= event_to_str(event
, true);
2224 // mstrlen can handle NULL; it will result in a bound but empty CHARSTRING
2225 CHARSTRING
ret_val(mstrlen(event_str
), event_str
);
2226 if (event_str
== NULL
) {
2227 TTCN_warning("No text for event");
2229 else Free(event_str
);
2233 void LegacyLogger::set_append_file(bool new_append_file
)
2235 this->append_file_
= new_append_file
;