Lockless trace implementation

RTC: 35396
Change-Id: I96ea0d95606f04abb4dc2b0470345ca475b53912
Reviewed-on: http://gfw160.austin.ibm.com:8080/gerrit/2520
Tested-by: Jenkins Server
Reviewed-by: Daniel M. Crowell <dcrowell@us.ibm.com>
Reviewed-by: A. Patrick Williams III <iawillia@us.ibm.com>

3 files changed, 192 insertions, 94 deletions

diff --git a/src/build/citest/autocitest b/src/build/citest/autocitest
index 7b2881387..b93bf405c 100755
--- a/src/build/citest/autocitest
+++ b/src/build/citest/autocitest
@@ -84,7 +84,7 @@ function    runtraceHB()
     #    exit 1
     #fi
     
-    autosim $NOWIN --simcmd   "hb-trace" --timeout 120
+    autosim $NOWIN --simcmd   "hb-trace" --timeout 300
     if [ $? -ne 0 ] ; then
         echo "ERROR 4 : Unable to run $?"
         stopsim
diff --git a/src/build/debug/Hostboot/Trace.pm b/src/build/debug/Hostboot/Trace.pm
index cdb3664ee..5e3adc05d 100755
--- a/src/build/debug/Hostboot/Trace.pm
+++ b/src/build/debug/Hostboot/Trace.pm
@@ -1,39 +1,50 @@
 #!/usr/bin/perl
-#  IBM_PROLOG_BEGIN_TAG
-#  This is an automatically generated prolog.
+# IBM_PROLOG_BEGIN_TAG
+# This is an automatically generated prolog.
 #
-#  $Source: src/build/debug/Hostboot/Trace.pm $
+# $Source: src/build/debug/Hostboot/Trace.pm $
 #
-#  IBM CONFIDENTIAL
+# IBM CONFIDENTIAL
 #
-#  COPYRIGHT International Business Machines Corp. 2011-2012
+# COPYRIGHT International Business Machines Corp. 2011,2012
 #
-#  p1
+# p1
 #
-#  Object Code Only (OCO) source materials
-#  Licensed Internal Code Source Materials
-#  IBM HostBoot Licensed Internal Code
+# Object Code Only (OCO) source materials
+# Licensed Internal Code Source Materials
+# IBM HostBoot Licensed Internal Code
 #
-#  The source code for this program is not published or other-
-#  wise divested of its trade secrets, irrespective of what has
-#  been deposited with the U.S. Copyright Office.
+# The source code for this program is not published or otherwise
+# divested of its trade secrets, irrespective of what has been
+# deposited with the U.S. Copyright Office.
 #
-#  Origin: 30
+# Origin: 30
 #
-#  IBM_PROLOG_END_TAG
+# IBM_PROLOG_END_TAG
 use strict;
 
 package Hostboot::Trace;
+use Hostboot::_DebugFrameworkVMM qw(NotFound NotPresent getPhysicalAddr);
+
 use Exporter;
 our @EXPORT_OK = ('main');
 
-use constant MAX_NUM_TRACE_BUFFERS => 48;
-use constant DESC_ARRAY_ENTRY_SIZE => 24;
-use constant OFFSET_TRAC_BUFFER_SIZE => 20;
-use constant OFFSET_BUFFER_ADDRESS => 16;
-use constant BUFFER_ADDRESS_SIZE => 8;
+use constant TRACE_BUFFER_COUNT => 2;
+use constant DAEMON_FIRST_BUFFER_PAGE_OFFSET => 8;
+use constant DAEMON_FIRST_TEMP_BUFFER_PAGE_OFFSET =>
+                    DAEMON_FIRST_BUFFER_PAGE_OFFSET + 16;
+use constant BUFFER_FIRST_PAGE_OFFSET => 16;
+use constant BUFFER_PAGE_NEXT_OFFSET => 0;
+use constant BUFFER_PAGE_PREV_OFFSET => BUFFER_PAGE_NEXT_OFFSET + 8;
+use constant BUFFER_PAGE_SIZE_OFFSET => BUFFER_PAGE_PREV_OFFSET + 12;
+use constant BUFFER_PAGE_DATA_OFFSET => BUFFER_PAGE_SIZE_OFFSET + 4;
+use constant ENTRY_COMP_OFFSET => 0;
+use constant ENTRY_SIZE_OFFSET => 26;
+use constant ENTRY_SIZE => 28;
+use constant BIN_ENTRY_SIZE_OFFSET => 12;
+use constant BIN_ENTRY_SIZE => 24;
 
-use File::Temp ('tempfile');
+use File::Temp qw(tempfile tempdir);
 
 sub main
 {
@@ -51,48 +62,106 @@ sub main
     }
 
     my $traceBuffers = $args->{"components"};
+    if (defined $traceBuffers)
+    {
+        $traceBuffers = uc $traceBuffers;
+    }
 
-    my ($symAddr, $symSize) = ::findSymbolAddress("TRACE::g_desc_array");
-    if (not defined $symAddr) { ::userDisplay "Cannot find symbol.\n"; die; }
-
-    my ($fh,$fname) = tempfile();
+    my $tmpdir = tempdir(CLEANUP => 1);
+    open (my $fh, ">", $tmpdir."/tracBINARY");
     binmode($fh);
+    my $foundBuffer = 0;
+    print $fh "\2";
 
-    # read the entire g_desc_array instead of reading each entry which is much slower in VBU
-    my $result = ::readData($symAddr, $symSize);
+    my ($daemonAddr, $daemonSize) =
+        ::findSymbolAddress("Singleton<TRACEDAEMON::Daemon>::instance()::instance");
 
-    $symAddr = 0;
-    my $foundBuffer = 0;
+    my ($serviceAddr, $serviceSize) =
+        ::findSymbolAddress("Singleton<TRACE::Service>::instance()::instance");
 
-    for (my $i = 0; $i < MAX_NUM_TRACE_BUFFERS; $i++)
+    if ((not defined $daemonAddr) || (not defined $serviceAddr))
     {
-        # component name is first in g_desc_array[$i]
-        my $compName = substr $result, $symAddr, OFFSET_BUFFER_ADDRESS;
-        # strip off null paddings
-        $compName = unpack('A*', $compName);
-        last if ($compName eq "");
+        ::userDisplay "Cannot find trace daemon and/or service.\n";
+        die;
+    }
+
+    my @bufferPages = ();
+    my %components = ();
+
 
-        if ((not defined $traceBuffers) or (uc($traceBuffers) =~ m/$compName/))
+    $daemonAddr = getPhysicalAddr($daemonAddr);
+    unless (($daemonAddr eq NotFound) || ($daemonAddr eq NotPresent))
+    {
+        my $firstPage = ::read64($daemonAddr + DAEMON_FIRST_BUFFER_PAGE_OFFSET);
+        readPage($firstPage, BUFFER_PAGE_PREV_OFFSET, \@bufferPages);
+
+        for(my $i = 0; $i < TRACE_BUFFER_COUNT; $i++)
         {
-            # get the pointer to its trace buffer
-            my $buffAddr = substr $result, $symAddr + OFFSET_BUFFER_ADDRESS, BUFFER_ADDRESS_SIZE;
-            $buffAddr= hex (unpack('H*',$buffAddr));
+            my $page =
+                ::read64($daemonAddr + DAEMON_FIRST_TEMP_BUFFER_PAGE_OFFSET +
+                         8*$i);
+
+            readPage($page, BUFFER_PAGE_PREV_OFFSET, \@bufferPages);
+        }
+    }
+
+    for(my $i = 0; $i < TRACE_BUFFER_COUNT; $i++)
+    {
+        my $buffer = ::read64($serviceAddr + 8*$i);
+        my $page = ::read64($buffer + BUFFER_FIRST_PAGE_OFFSET);
 
-            # get the size of this trace buffer
-            my $buffSize = ::read32($buffAddr + OFFSET_TRAC_BUFFER_SIZE);
+        readPage($page, BUFFER_PAGE_NEXT_OFFSET, \@bufferPages);
+    }
 
-            $foundBuffer = 1;
-            print $fh (::readData($buffAddr, $buffSize ));
+    while(@bufferPages)
+    {
+        my $page = shift @bufferPages;
+
+        my $size = readBuf32($page, BUFFER_PAGE_SIZE_OFFSET) +
+                        BUFFER_PAGE_DATA_OFFSET;
+        my $offset = BUFFER_PAGE_DATA_OFFSET;
+
+        # Read each entry.
+        while($offset < $size)
+        {
+            my $entry_size = readBuf16($page, ENTRY_SIZE_OFFSET + $offset);
+            my $compAddr = readBuf64($page, ENTRY_COMP_OFFSET + $offset);
+
+            if (0 ne $compAddr)
+            {
+                my $component = lookupComponent($compAddr,
+                        \%components);
+
+                if ((not defined $traceBuffers) ||
+                    ($traceBuffers =~ m/$component/))
+                {
+                    $foundBuffer = 1;
+
+                    print $fh $component;
+                    print $fh "\0";
+
+                    my $entry_data =
+                        substr $page, ENTRY_SIZE + $offset, $entry_size;
+
+                    my $bin_entry_size = BIN_ENTRY_SIZE +
+                        readBuf16($entry_data, BIN_ENTRY_SIZE_OFFSET);
+
+                    $entry_data = substr $entry_data, 0, $bin_entry_size;
+
+                    print $fh $entry_data;
+                }
+            }
+
+            $offset += $entry_size + ENTRY_SIZE;
+            $offset = round8($offset);
         }
 
-        # increment to next item in g_desc_array[]
-        $symAddr += DESC_ARRAY_ENTRY_SIZE;
     }
 
     if ($foundBuffer)
     {
-        open TRACE, ($args->{"fsp-trace"}." -s ".
-                    ::getImgPath()."hbotStringFile $fsptrace_options $fname |");
+        open TRACE, ($args->{"fsp-trace"}." $tmpdir -s ".
+                    ::getImgPath()."hbotStringFile $fsptrace_options |");
         while (my $line = <TRACE>)
         {
             ::userDisplay $line;
@@ -102,8 +171,75 @@ sub main
     {
         ::userDisplay("No matching buffers found.\n");
     }
+}
+
+sub readPage
+{
+    my ($addr, $offset, $pageArray) = @_;
+    return if (0 == $addr);
+
+    my $buffer = ::readData($addr, 4096);
 
-    unlink($fname);
+    my $pointer = readBuf64($buffer, $offset);
+
+    push @{$pageArray}, $buffer;
+
+    readPage($pointer, $offset, $pageArray);
+}
+
+sub readBuf64
+{
+    my ($buffer, $offset) = @_;
+
+    my $data = substr $buffer, $offset, 8;
+    if (::littleendian()) { $data = reverse($data); }
+
+    return unpack("Q", $data);
+}
+
+sub readBuf32
+{
+    my ($buffer, $offset) = @_;
+
+    my $data = substr $buffer, $offset, 4;
+    if (::littleendian()) { $data = reverse($data); }
+
+    return unpack("L", $data);
+
+}
+
+sub readBuf16
+{
+    my ($buffer, $offset) = @_;
+
+    my $data = substr $buffer, $offset, 2;
+    if (::littleendian()) { $data = reverse($data); }
+
+    return unpack("S", $data);
+
+}
+
+sub round8
+{
+    my ($val) = @_;
+
+    if ($val % 8)
+    {
+        $val += (8 - ($val % 8));
+    }
+
+    return $val;
+}
+
+sub lookupComponent
+{
+    my ($ptr, $hash) = @_;
+
+    if (not defined $hash->{$ptr})
+    {
+        $hash->{$ptr} = ::readStr($ptr);
+    }
+    return $hash->{$ptr};
 }
 
 sub helpInfo
diff --git a/src/build/debug/simics-debug-framework.py b/src/build/debug/simics-debug-framework.py
index b7536eea7..2e7958438 100755
--- a/src/build/debug/simics-debug-framework.py
+++ b/src/build/debug/simics-debug-framework.py
@@ -486,8 +486,6 @@ def magic_instruction_callback(user_arg, cpu, arg):
     if arg == 7006:   # MAGIC_SHUTDOWN
         # KernelMisc::shutdown()
         print "KernelMisc::shutdown() called."
-        os.system( "fsp-trace ./ -s "+os.environ['HB_TOOLPATH']+
-                   "/hbotStringFile >>tracMERG  2>/dev/null" )
         # Could break/stop/pause the simics run, but presently
         # shutdown() is called four times. --Monte Jan 2012
         # SIM_break_simulation( "Shutdown. Simulation stopped." )
@@ -500,57 +498,21 @@ def magic_instruction_callback(user_arg, cpu, arg):
         magic_memoryleak_function(cpu)
 
     if arg == 7055:   # MAGIC_CONTINUOUS_TRACE
-        # Set execution environment flag to 0
-        writeLongLong(contTraceTrigInfo+32,0)
-        # Continuous trace.
-        # Residing at tracBinaryInfoAddr is the pointer to the tracBinary buffer
-        pTracBinaryBuffer = readLongLong(tracBinaryInfoAddr)
-        # Read the count of bytes used in the tracBinary buffer
-        cbUsed = readLongLong(tracBinaryInfoAddr+8)
-        if cbUsed == 1:
-            pTracBinaryBuffer = readLongLong(tracBinaryInfoAddr+24)
-            cbUsed = readLongLong(tracBinaryInfoAddr+32)
-            writeLong(tracBinaryInfoAddr+40,0)
-            # Reset the buffer byte count in Simics memory to 1, preserving
-            # the byte at offset 0 of the buffer which contains a 0x02 in
-            # fsp-trace style.
-            writeLongLong(tracBinaryInfoAddr+32,1)
-        else:
-            writeLong(tracBinaryInfoAddr+16,0)
-            # Reset the buffer byte count in Simics memory to 1, preserving
-            # the byte at offset 0 of the buffer which contains a 0x02 in
-            # fsp-trace style.
-            writeLongLong(tracBinaryInfoAddr+8,1)
+        hb_tracBinaryBuffer = cpu.r4
+        hb_tracBinaryBufferSz = cpu.r5
         # Figure out if we are running out of the cache or mainstore
         runStr = "(system_cmp0.phys_mem)->map[0][1]"
         ( result, out )  =   quiet_run_command( runStr, output_modes.regular )
         # Add the HRMOR if we're running from memory
         if 'cache' not in result:
-            pTracBinaryBuffer = pTracBinaryBuffer + getHRMOR()
+            hb_tracBinaryBuffer = hb_tracBinaryBuffer + getHRMOR()
         # Save the tracBinary buffer to a file named tracBINARY in current dir
-        saveCommand = "(system_cmp0.phys_mem)->map[0][1]->image.save tracBINARY 0x%x %d"%(pTracBinaryBuffer,cbUsed)
+        # and run fsp-trace on tracBINARY file (implied), append output to
+        # tracMERG.  Once we extract the trace buffer, we need to reset
+        # mailbox scratch 1 (to 0) so that the trace daemon knows it can
+        # continue.
+        saveCommand = "(system_cmp0.phys_mem)->map[0][1]->image.save tracBINARY 0x%x %d ; (shell \"fsp-trace ./ -s %s/hbotStringFile >> tracMERG 2>/dev/null\"); p8Proc0.proc_fsi2host_mbox->regs[95][1] = 0"%(hb_tracBinaryBuffer,hb_tracBinaryBufferSz,os.environ['HB_TOOLPATH'])
         SIM_run_alone(run_command, saveCommand )
-        # Run fsp-trace on tracBINARY file (implied), append output to tracMERG
-        os.system( "fsp-trace ./ -s "+os.environ['HB_TOOLPATH']+
-                   "/hbotStringFile >>tracMERG  2>/dev/null" )
-
-# Continuous trace:  Open the symbols and find the address for
-# "g_tracBinaryInfo"  Convert to a number and save in tracBinaryInfoAddr
-# The layout of g_tracBinaryInfo is a 64-bit pointer to the mixed buffer
-# followed by a 64-bit count of bytes used in the buffer.  See
-# src/usr/trace/trace.C and mixed_trace_info_t.
-for line in open(os.environ['HB_TOOLPATH']+'/hbicore.syms'):
-    if "g_tracBinaryInfo" in line:
-        words=line.split(",")
-        tracBinaryInfoAddr=int(words[1],16)
-        break
-# Find the address of the g_cont_trace_trigger_info and save it in
-# contTraceTrigInfo
-for line in open(os.environ['HB_TOOLPATH']+'/hbicore.syms'):
-    if "g_cont_trace_trigger_info" in line:
-        words=line.split(",")
-        contTraceTrigInfo=int(words[1],16)
-        break
 
 # Continuous trace: Clear these files.
 rc = os.system( "rm -f tracMERG" )