From 068d68fdc716da1ad4443f66068b7494525e681f Mon Sep 17 00:00:00 2001 From: CamVan Nguyen Date: Mon, 8 Aug 2011 20:12:06 -0500 Subject: Add %s string formatting support to trace Change-Id: I14ea6717dfd8e98895345e86e32e82c637c26289 Reviewed-on: http://gfw160.austin.ibm.com:8080/gerrit/234 Tested-by: Jenkins Server Reviewed-by: CAMVAN T. NGUYEN --- src/include/usr/trace/trace.H | 3 +- src/include/util/align.H | 6 ++ src/usr/trace/test/tracetest.H | 46 ++++++++++++ src/usr/trace/trace.C | 165 +++++++++++++++++++++++++++++++---------- 4 files changed, 179 insertions(+), 41 deletions(-) create mode 100644 src/include/util/align.H diff --git a/src/include/usr/trace/trace.H b/src/include/usr/trace/trace.H index e4ea8922c..f30f2c0a3 100644 --- a/src/include/usr/trace/trace.H +++ b/src/include/usr/trace/trace.H @@ -22,6 +22,7 @@ /******************************************************************************/ const uint32_t TRACE_BUF_VERSION = 0x01; // Trace buffer version +const uint32_t TRACE_COMP_TRACE = 0x434F; // Component Field Trace - "CO" const uint32_t TRACE_FIELDTRACE = 0x4654; // Field Trace - "FT" const uint32_t TRACE_FIELDBIN = 0x4644; // Binary Field Trace - "FD" @@ -265,8 +266,6 @@ private: * * @param [in] i_comp Component name to retrieve trace descriptor for. * - * TODO - Not Supported Yet - * * @return Valid trace descriptor on success, NULL on failure. */ trace_desc_t * getTd(const char *i_comp); diff --git a/src/include/util/align.H b/src/include/util/align.H new file mode 100644 index 000000000..3edbff09a --- /dev/null +++ b/src/include/util/align.H @@ -0,0 +1,6 @@ +#ifndef __UTIL_ALIGN_H +#define __UTIL_ALIGN_H + +#define ALIGN_4(u) ((u + 0x3ull) & ~0x3ull) + +#endif diff --git a/src/usr/trace/test/tracetest.H b/src/usr/trace/test/tracetest.H index 06c9f9ea3..3082242b3 100644 --- a/src/usr/trace/test/tracetest.H +++ b/src/usr/trace/test/tracetest.H @@ -187,6 +187,52 @@ public: #undef __COMP_TD__ } + /** + * @test Test String Trace Interface + */ + void testTracString(void) + { + trace_desc_t *g_trac_test = NULL; + TRAC_INIT_BUFFER(&g_trac_test, "STRING", 4096); + + if(g_trac_test == NULL) + { + TS_FAIL("g_trac_test was returned as NULL!"); + } + else + { + TRACFCOMP(g_trac_test,"String at end '%s'", "Last"); + TRACFCOMP(g_trac_test,"%s: String at beginning", "FIRST"); + TRACFCOMP(g_trac_test,"Test '%s' string", "middle"); + + const char * str = "This is a \tlong string\nwith horizontal tab and newline."; + TRACFCOMP(g_trac_test,"Testing (c,u,s,X): %c, %u, %s 0x%X", 'b',0x11,str,10); + + TRACFCOMP(g_trac_test,"Testing string len 1: %s, %s, %s", "A", "B", "C"); + TRACFCOMP(g_trac_test,"Testing NULL string: %s", ""); + + TRACFCOMP(g_trac_test,"Testing string alignment: %s %s", "hello", "world"); + TRACFCOMP(g_trac_test,"Testing string alignment: %s %s", "Hostboot", "Software"); + TRACFCOMP(g_trac_test,"Testing string alignment: %s %s", "Hostboot2", "Software3"); + + TRACFCOMP(g_trac_test,"%s %s %s %s", "Four", "strings", "by", "themselves"); + + TRACFCOMP(g_trac_test,"Testing special characters: %s", + "?!@#$%^&*()\"/\'\\<>.,:;"); + + TRACFCOMP(g_trac_test,"Testing percent: %% %%%d %%%s 100%%", 50, "hello"); + + TRACFCOMP(g_trac_test, INFO_MRK"Testing all number types (s,c,u,X,d): %s, %c %u 0x%X %d", + "hello",'a',10,11,12); + TRACFCOMP(g_trac_test, "Testing all number types (c,u,s,X,d): %c %u %s 0x%X %d", + 'b',13,"world!",14,15); + TRACFCOMP(g_trac_test, "Testing all number types (c,u,X,d,s): %c %u 0x%X %d %s", + 'c',16,17,18,"Hostboot"); + TRACFCOMP(g_trac_test, "Testing all number types (s,c,s,u,s,X): %s %c %s %u %s 0x%X", + "Astring",'d',"Bstring12",19,"Cstring123",20); + } + } + /** * @test Test max number of buffers */ diff --git a/src/usr/trace/trace.C b/src/usr/trace/trace.C index d52274473..dcc48ca27 100644 --- a/src/usr/trace/trace.C +++ b/src/usr/trace/trace.C @@ -21,6 +21,7 @@ #include #include #include +#include #include @@ -280,83 +281,169 @@ void Trace::trace_adal_write_all(trace_desc_t *io_td, /* Local Variables */ /*------------------------------------------------------------------------*/ uint32_t l_entry_size = 0; - trace_entire_entry_t l_entry; + uint32_t l_data_size= 0; + //trace_entire_entry_t l_entry; + trace_bin_entry_t l_entry; + uint64_t l_str_map = 0; + /*------------------------------------------------------------------------*/ /* Code */ /*------------------------------------------------------------------------*/ - // This code is incorrect for determining formatting but will work for now. uint32_t num_args = 0; + uint32_t num_4byte_args = 0; //fsp-trace counts 8-byte args as 2 4-byte args const char* _fmt = i_fmt; - while ('\0' != *_fmt) - { - if ('%' == *_fmt) - num_args++; - _fmt++; - } - if((num_args <= TRAC_MAX_ARGS) && (io_td != NULL)) + va_list args; + va_start(args, i_type); + for (size_t i = 0; i <= strlen(_fmt); i++) { + if ('%' == _fmt[i]) + { + i++; - // Calculate total space needed - l_entry_size = sizeof(trace_entry_stamp_t); - l_entry_size += sizeof(trace_entry_head_t); + if ('%' == _fmt[i]) + { + continue; + } + else if ('s' == _fmt[i]) + { + // Set flag to indicate argument is a string + l_str_map = l_str_map | (1 << num_args); - // We always add the size of the entry at the end of the trace entry - // so the parsing tool can easily walk the trace buffer stack so we - // need to add that on to total size - l_entry_size += sizeof(uint32_t); + // String counts as one 4-byte arg + num_args++; + num_4byte_args++; - // Now add on size for actual number of arguments we're tracing - l_entry_size += (num_args * sizeof(uint64_t)); + char * l_str = va_arg(args, char *); + size_t l_strLen = strlen(l_str); - // Word align the entry - l_entry_size = (l_entry_size + 3) & ~3; + // Add to total size of number of arguments we're tracing + // and account for word alignment + l_data_size += l_strLen + 1; + l_data_size = ALIGN_4(l_data_size); + + //printk("Trace: STRING %s: strlen %d num_args %d l_data_size %d\n", + // l_str, static_cast(l_strLen), + // num_args, l_data_size); + //printk("Trace: l_str_map 0x%16llX\n", static_cast(l_str_map)); + } + else + { + // Numbers count as two 4-byte arg + num_args++; + num_4byte_args += 2; + + // Retrieve the argument to increment to next one + uint64_t l_tmpData = va_arg(args, uint64_t); + // Add to total size; data is word aligned + l_data_size += sizeof(l_tmpData); + } + } + } + va_end(args); + + if((num_4byte_args <= TRAC_MAX_ARGS) && (io_td != NULL)) + { // Fill in the entry structure l_entry.stamp.tid = static_cast(task_gettid()); // Length is equal to size of data - l_entry.head.length = (num_args * sizeof(uint64_t)); - l_entry.head.tag = TRACE_FIELDTRACE; + l_entry.head.length = l_data_size; + //l_entry.head.tag = TRACE_FIELDTRACE; + l_entry.head.tag = TRACE_COMP_TRACE; l_entry.head.hash = i_hash; l_entry.head.line = i_line; // Time stamp convertTime(&l_entry.stamp); - uint64_t* data = &l_entry.args[0]; + // Calculate total space needed + l_entry_size = l_data_size; + l_entry_size += sizeof(trace_entry_stamp_t); + l_entry_size += sizeof(trace_entry_head_t); + + // We always add the size of the entry at the end of the trace entry + // so the parsing tool can easily walk the trace buffer stack so we + // need to add that on to total size + l_entry_size += sizeof(uint32_t); + + // Word align the entry + l_entry_size = ALIGN_4(l_entry_size); + + // Allocate buffer for the arguments we're tracing + void * l_buffer = malloc(l_data_size); + memset(l_buffer, 0, l_data_size); + char * l_ptr = static_cast (l_buffer); + // Now copy the arguments to the buffer va_list args; va_start(args, i_type); for (size_t i = 0; i < num_args; i++) { - *data = va_arg(args, uint64_t); - data++; + uint32_t l_strLen = 0; + + if (l_str_map & (1 << i)) + { + // Save string to buffer + strcpy(l_ptr, va_arg(args, char *)); + + //printk("Trace: Saved String %s Arg[%d]\n", l_ptr, static_cast(i)); + + // Length = string length + NULL termination + l_strLen += (strlen(l_ptr) + 1); + + // Increment pointer to next word alignment + l_ptr += l_strLen; + l_ptr = reinterpret_cast( + ALIGN_4(reinterpret_cast(l_ptr)) ); + + //printk("Trace::trace_adal_write_all - l_buffer %p l_ptr %p l_strLen %d\n", + // l_buffer, l_ptr, l_strLen); + //printk("Trace::trace_adal_write_all - num_args %d l_data_size %d l_entry_size %d\n", + // num_args, l_data_size, l_entry_size); + } + else + { + // Save number to buffer & increment pointer (no need to align) + *(reinterpret_cast(l_ptr)) = va_arg(args, uint64_t); + l_ptr += sizeof(uint64_t); + } } va_end(args); - // Now put total size at end of buffer - // Note that fsp-trace assumes this to be a 32 bit long word - uint32_t *l_size = reinterpret_cast - (&(l_entry.args[num_args])); - *l_size = l_entry_size; - // We now have total size and need to reserve a part of the trace // buffer for this // CRITICAL REGION START mutex_lock(&iv_trac_mutex); + // Update the entry count io_td->te_count++; + // First write the header writeData(io_td, static_cast(&l_entry), - l_entry_size); + sizeof(l_entry)); + + // Now write the actual data + writeData(io_td, + l_buffer, + l_data_size); + + // Now write the size at the end + // Note that fsp-trace assumes this to be a 32 bit long word + writeData(io_td, + static_cast(&l_entry_size), + sizeof(l_entry_size)); mutex_unlock(&iv_trac_mutex); // CRITICAL REGION END + + // Free allocated memory + free(l_buffer); } return; @@ -397,11 +484,11 @@ void Trace::trace_adal_write_bin(trace_desc_t *io_td,const trace_hash_val i_hash // need to add that on to total size l_entry_size += sizeof(uint32_t); - // Now add on size for acutal size of the binary data + // Now add on size for actual size of the binary data l_entry_size += i_size; // Word align the entry - l_entry_size = (l_entry_size + 3) & ~3; + l_entry_size = ALIGN_4(l_entry_size); // Fill in the entry structure l_entry.stamp.tid = static_cast(task_gettid()); @@ -480,8 +567,8 @@ void Trace::writeData(trace_desc_t *io_td, // Get the pointer to current location in buffer l_buf_ptr = reinterpret_cast(io_td) + io_td->next_free; // Figure out the alignment - l_align = ( (reinterpret_cast(l_buf_ptr) + 3) & ~3) - - reinterpret_cast(l_buf_ptr); + l_align = ALIGN_4(reinterpret_cast(l_buf_ptr)) - + reinterpret_cast(l_buf_ptr); // Add on the alignment l_buf_ptr = reinterpret_cast(reinterpret_cast (l_buf_ptr) + l_align); @@ -500,8 +587,8 @@ void Trace::writeData(trace_desc_t *io_td, // Get the pointer to current location in buffer l_buf_ptr = reinterpret_cast(io_td) + io_td->next_free; // Figure out the alignment - l_align = ( (reinterpret_cast(l_buf_ptr) + 3) & ~3) - - reinterpret_cast(l_buf_ptr); + l_align = ALIGN_4(reinterpret_cast(l_buf_ptr)) - + reinterpret_cast(l_buf_ptr); // Add on the alignment l_buf_ptr = reinterpret_cast(reinterpret_cast (l_buf_ptr) + l_align); @@ -514,7 +601,7 @@ void Trace::writeData(trace_desc_t *io_td, // has the potential to be un-word aligned. If two parts of the binary // trace had this problem then this code would not work. // Note that fsp-trace will ignore garbage data in the unaligned areas. - l_total_size = (l_total_size + 3) & ~3; + l_total_size = ALIGN_4(l_total_size); io_td->next_free += l_total_size; }while(0); -- cgit v1.2.1