/* IBM_PROLOG_BEGIN_TAG */ /* This is an automatically generated prolog. */ /* */ /* $Source: src/usr/trace/runtime/rt_service.C $ */ /* */ /* OpenPOWER HostBoot Project */ /* */ /* Contributors Listed Below - COPYRIGHT 2013,2018 */ /* [+] International Business Machines Corp. */ /* */ /* */ /* Licensed under the Apache License, Version 2.0 (the "License"); */ /* you may not use this file except in compliance with the License. */ /* You may obtain a copy of the License at */ /* */ /* http://www.apache.org/licenses/LICENSE-2.0 */ /* */ /* Unless required by applicable law or agreed to in writing, software */ /* distributed under the License is distributed on an "AS IS" BASIS, */ /* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or */ /* implied. See the License for the specific language governing */ /* permissions and limitations under the License. */ /* */ /* IBM_PROLOG_END_TAG */ #include "../service.H" #include "../compdesc.H" #include "../buffer.H" #include "../entry.H" #include #include #include #include #include #include #include #include #include #include #include #include #include "rt_rsvdtracebufservice.H" namespace TRACE { // Value was chosen empirically from trace lengths during the IPL. static const size_t DEFAULT_TRACE_LENGTH = 128; Service::Service() { // Only use one "fake" daemon for runtime and one valid buffer // BUFFER_FAST skips some blocking calls and is limited in pages iv_daemon = new TRACEDAEMON::Daemon(); iv_buffers[BUFFER_SLOW] = nullptr; iv_buffers[BUFFER_FAST] = new Buffer(iv_daemon); // Force create the Reserved Trace Buffer Service object iv_rsvdtracebufservice = &(Singleton::instance()); iv_compList = &(Singleton::instance()); } Service::~Service() { // No need to destruct the service. assert(0, "No need to destruct the Service"); } void Service::writeEntry(ComponentDesc* i_td, trace_hash_val i_hash, const char * i_fmt, uint32_t i_line, uint32_t i_type, va_list i_args) { if (unlikely(i_type == TRACE_DEBUG)) { if (!i_td->iv_debugEnabled) { return; } } size_t compName_len = strnlen(i_td->iv_compName, sizeof(i_td->iv_compName)); char output[DEFAULT_TRACE_LENGTH]; memcpy(output, i_td->iv_compName, compName_len); output[compName_len] = ':'; size_t length = vsnprintf(&output[compName_len+1], DEFAULT_TRACE_LENGTH-(compName_len+1), i_fmt, i_args); if (unlikely((compName_len + 1 + length + 1) > DEFAULT_TRACE_LENGTH)) { char* long_output = new char[compName_len + 1 + length + 1]; memcpy(long_output, i_td->iv_compName, compName_len); long_output[compName_len] = ':'; vsprintf(&long_output[compName_len+1], i_fmt, i_args); g_hostInterfaces->puts(long_output); delete[] long_output; } else { g_hostInterfaces->puts(output); } ////////////////////////////////////////////// // Try to use buffers ////////////////////////////////////////////// do { // Get the right buffer for this component. Buffer* l_buffer = iv_buffers[i_td->iv_bufferType]; if (l_buffer == nullptr) { break; } // Copy the current time. trace_entry_stamp_t l_time; _createTimeStamp(&l_time); // Sizes for trace entry. uint32_t l_size = 0; uint32_t l_num_args = 0; // Maps of arguments to special types. uint64_t l_str_map = 0, l_char_map = 0, l_double_map = 0; va_list l_args; va_copy(l_args, i_args); // Parse the fmt list to determine the types/sizes of each // argument. while(NULL != (i_fmt = strchr(i_fmt, '%'))) { i_fmt++; switch (*i_fmt) { case '%': break; case 's': // string. l_str_map |= (1 << l_num_args); l_num_args++; l_size += ALIGN_4(strlen(va_arg(l_args, char*)) + 1); break; case 'c': // character. l_char_map |= (1 << l_num_args); l_num_args++; va_arg(l_args, uint32_t); l_size += sizeof(uint32_t); break; case 'e': // doubles. case 'f': case 'g': l_double_map |= (1 << l_num_args); l_num_args++; va_arg(l_args, double); l_size += sizeof(double); break; default: // uint64_t-sized argument. l_num_args++; va_arg(l_args, uint64_t); l_size += sizeof(uint64_t); break; } i_fmt++; } va_end(l_args); // Ensure we don't have too many arguments. if (l_num_args > TRAC_MAX_ARGS) { // Simply reducing the number of arguments and continuing // causes FSP trace to crash. See defect 864438. //l_num_args = TRAC_MAX_ARGS; break; } // Claim an entry from the buffer. uint32_t l_realSize = ALIGN_4(sizeof(trace_bin_entry_t) + l_size); Entry* l_entry = l_buffer->claimEntry(i_td, l_realSize); if (nullptr == l_entry) { break; } // Copy contents into the 'fsp-trace'-style structure. trace_bin_entry_t* l_binEntry = reinterpret_cast(&l_entry->data[0]); l_binEntry->stamp = l_time; l_binEntry->head.length = l_size; l_binEntry->head.tag = TRACE_COMP_TRACE; l_binEntry->head.hash = i_hash; l_binEntry->head.line = i_line; // Copy arguments into the 'fsp-trace' entry's data section. char* l_dataOut = reinterpret_cast(&l_binEntry->data[0]); for (size_t i = 0; i < l_num_args; i++) { // String. if (l_str_map & (1 << i)) { char* str = va_arg(i_args, char*); uint32_t strSize = strlen(str); memcpy(l_dataOut, str, strSize+1); l_dataOut += ALIGN_4(strSize + 1); } // Single character. else if (l_char_map & (1 << i)) { *(reinterpret_cast(l_dataOut)) = va_arg(i_args, uint32_t); l_dataOut += sizeof(uint32_t); } // Doubles. else if (l_double_map & (1 << i)) { *(reinterpret_cast(l_dataOut)) = va_arg(i_args, double); l_dataOut += sizeof(double); } // All others (as uint64_t's). else { *(reinterpret_cast(l_dataOut)) = va_arg(i_args, uint64_t); l_dataOut += sizeof(uint64_t); } } // "Commit" entry to buffer. l_buffer->commitEntry(l_entry); // Copy the trace entry in to the Reserved Trace Buffer too iv_rsvdtracebufservice->writeEntry(i_td, reinterpret_cast(&l_entry->data[0]), l_realSize); } while(0); } void Service::writeBinEntry(ComponentDesc* i_td, trace_hash_val i_hash, const char * i_fmt, uint32_t i_line, const void* i_ptr, uint32_t i_size, uint32_t i_type) { if (unlikely(i_type == TRACE_DEBUG)) { if (!i_td->iv_debugEnabled) { return; } } size_t compName_len = strnlen(i_td->iv_compName, sizeof(i_td->iv_compName)); // Output header. char output[DEFAULT_TRACE_LENGTH]; memcpy(output, i_td->iv_compName, compName_len); output[compName_len] = ':'; size_t length = vsnprintf(&output[compName_len+1], DEFAULT_TRACE_LENGTH-(compName_len+1), i_fmt, NULL); if(unlikely((compName_len + 1 + length + 1) > DEFAULT_TRACE_LENGTH)) { char* long_output = new char[compName_len + length + 1]; memcpy(long_output, i_td->iv_compName, compName_len); long_output[compName_len] = ':'; vsprintf(&long_output[compName_len+1], i_fmt, NULL); g_hostInterfaces->puts(long_output); delete[] long_output; } else { g_hostInterfaces->puts(output); } // Output binary data. // Format is: // ~[0x0000] 01234567 01234567 01234567 01234567 *012345689abcdef* static size_t BINARY_FORMAT_LENGTH = 68 + sizeof(ComponentDesc::iv_compName) + 1; size_t pos = 0; while (pos < i_size) { char bin_output[BINARY_FORMAT_LENGTH]; memcpy(bin_output, i_td->iv_compName, compName_len); size_t output_pos = compName_len + sprintf(&bin_output[compName_len], ":~[0x%04hx]", (uint16_t) pos); for (int i = 0; i < 16; ++i) { if ((i % 4) == 0) { bin_output[output_pos++] = ' '; } if ((pos + i) < i_size) { output_pos += sprintf(&bin_output[output_pos], "%02x", ((const char*)i_ptr)[pos+i]); } else { bin_output[output_pos++] = ' '; bin_output[output_pos++] = ' '; } } for (int i = 0; i < 4; i++) { bin_output[output_pos++] = ' '; } bin_output[output_pos++] = '*'; for (int i = 0; i < 16; ++i) { char ch = ' '; if ((pos + i) < i_size) { ch = ((const char*) i_ptr)[pos+i]; if (!isprint(ch)) { ch = '.'; } } bin_output[output_pos++] = ch; } bin_output[output_pos++] = '*'; bin_output[output_pos++] = '\0'; g_hostInterfaces->puts(bin_output); pos += 16; } // Runtime traces do { // Get the right buffer for this component. Buffer* l_buffer = iv_buffers[i_td->iv_bufferType]; if(l_buffer == nullptr) { break; } // Copy the current time. trace_entry_stamp_t l_time; _createTimeStamp(&l_time); // Claim an entry from the buffer. uint32_t l_realSize = ALIGN_4(sizeof(trace_bin_entry_t) + i_size); Entry* l_entry = l_buffer->claimEntry(i_td, l_realSize); if (nullptr == l_entry) { break; } // Copy contents into the 'fsp-trace'-style structure. trace_bin_entry_t* l_binEntry = reinterpret_cast(&l_entry->data[0]); l_binEntry->stamp = l_time; l_binEntry->head.length = i_size; l_binEntry->head.tag = TRACE_FIELDBIN; l_binEntry->head.hash = i_hash; l_binEntry->head.line = i_line; // Copy bin-data into the 'fsp-trace' entry's data section. memcpy(&l_binEntry->data[0], i_ptr, i_size); // "Commit" entry to buffer. l_buffer->commitEntry(l_entry); // Copy the trace entry in to the Reserved Trace Buffer too iv_rsvdtracebufservice->writeEntry(i_td, reinterpret_cast(&l_entry->data[0]), l_realSize); } while(0); } size_t Service::getBuffer(ComponentDesc* i_comp, void * o_data, size_t i_size) { return iv_buffers[i_comp->iv_bufferType]->getTrace(i_comp,o_data,i_size); } void Service::flushBuffers() { // No-op in runtime. } void Service::_createTimeStamp(trace_entry_stamp_t *o_entry) { timespec_t curTime; clock_gettime(CLOCK_MONOTONIC, &curTime); o_entry->tbh = curTime.tv_sec; o_entry->tbl = curTime.tv_nsec; o_entry->tid = task_gettid(); } Service* Service::getGlobalInstance() { return &(Singleton::instance()); } }