Merge pull request #9 from tideways/dev

Multiple fixes and improvements

cmd/analyze-callgrind.go

@@ -2,6 +2,7 @@ package cmd
 
 import (
 	"fmt"
+	"strings"
 
 	"github.com/tideways/toolkit/xhprof"
 
@@ -10,8 +11,8 @@ import (
 
 func init() {
 	RootCmd.AddCommand(analyzeCallgrindCmd)
-	analyzeCallgrindCmd.Flags().StringVarP(&field, "field", "f", "excl_wt", "Field to view/sort (wt, excl_wt)")
-	analyzeCallgrindCmd.Flags().Float32VarP(&minPercent, "min", "m", 1, "Display items having minimum percentage (default 1%) of --field, with respect to main()")
+	analyzeCallgrindCmd.Flags().StringVarP(&field, "dimension", "d", "excl_wt", "Dimension to view/sort (wt, excl_wt)")
+	analyzeCallgrindCmd.Flags().Float32VarP(&minPercent, "min", "m", 1, "Display items having minimum percentage (default 1%) of --dimension, with respect to main()")
 }
 
 var analyzeCallgrindCmd = &cobra.Command{
@@ -23,18 +24,19 @@ var analyzeCallgrindCmd = &cobra.Command{
 }
 
 func analyzeCallgrind(cmd *cobra.Command, args []string) error {
-	profiles := make([]*xhprof.Profile, 0, len(args))
+	maps := make([]*xhprof.PairCallMap, 0, len(args))
 	for _, arg := range args {
 		f := xhprof.NewFile(arg, "callgrind")
-		profile, err := f.GetProfile()
+		m, err := f.GetPairCallMap()
 		if err != nil {
 			return err
 		}
 
-		profiles = append(profiles, profile)
+		maps = append(maps, m)
 	}
 
-	profile := xhprof.AvgProfiles(profiles)
+	avgMap := xhprof.AvgPairCallMaps(maps)
+	profile := avgMap.Flatten()
 
 	fieldInfo, ok := fieldsMap[field]
 	if !ok {
@@ -43,9 +45,16 @@ func analyzeCallgrind(cmd *cobra.Command, args []string) error {
 		fieldInfo = fieldsMap[field]
 	}
 
+	profile.SortBy(fieldInfo.Name)
+
+	// Change default to 10 for exclusive fields, only when user
+	// hasn't manually provided 1%
+	if strings.HasPrefix(field, "excl_") && !cmd.Flags().Changed("min") {
+		minPercent = float32(10)
+	}
 	minPercent = minPercent / 100.0
-	main := profile.GetMain()
-	minValue := minPercent * main.GetFloat32Field(fieldInfo.Name)
+	minValue := minPercent * profile.Calls[0].GetFloat32Field(fieldInfo.Name)
+	profile = profile.SelectGreater(fieldInfo.Name, minValue)
 	err := renderProfile(profile, field, fieldInfo, minValue)
 	if err != nil {
 		return err

cmd/analyze-xhprof.go

@@ -3,6 +3,7 @@ package cmd
 import (
 	"errors"
 	"fmt"
+	"strings"
 
 	"github.com/tideways/toolkit/xhprof"
 
@@ -11,8 +12,8 @@ import (
 
 func init() {
 	RootCmd.AddCommand(xhprofCmd)
-	xhprofCmd.Flags().StringVarP(&field, "field", "f", "excl_wt", "Field to view/sort (wt, excl_wt, cpu, excl_cpu, memory, excl_memory, io, excl_io)")
-	xhprofCmd.Flags().Float32VarP(&minPercent, "min", "m", 1, "Display items having minimum percentage (default 1%) of --field, with respect to main()")
+	xhprofCmd.Flags().StringVarP(&field, "dimension", "d", "excl_wt", "Dimension to view/sort (wt, excl_wt, cpu, excl_cpu, memory, excl_memory, io, excl_io)")
+	xhprofCmd.Flags().Float32VarP(&minPercent, "min", "m", 1, "Display items having minimum percentage (default 1% for inclusive, and 10% for exclusive dimensions) of --dimension, with respect to main()")
 	xhprofCmd.Flags().StringVarP(&outFile, "out-file", "o", "", "If provided, the path to store the resulting profile (e.g. after averaging)")
 	xhprofCmd.Flags().StringVarP(&function, "function", "", "", "If provided, one table for parents, and one for children of this function will be displayed")
 }
@@ -55,7 +56,14 @@ func analyzeXhprof(cmd *cobra.Command, args []string) error {
 	}
 
 	profile := avgMap.Flatten()
+
+	// Change default to 10 for exclusive fields, only when user
+	// hasn't manually provided 1%
+	if strings.HasPrefix(field, "excl_") && !cmd.Flags().Changed("min") {
+		minPercent = float32(10)
+	}
 	minPercent = minPercent / 100.0
+
 	if function == "" {
 		fieldInfo, ok := fieldsMap[field]
 		if !ok {
@@ -64,8 +72,9 @@ func analyzeXhprof(cmd *cobra.Command, args []string) error {
 			fieldInfo = fieldsMap[field]
 		}
 
-		main := profile.GetMain()
-		minValue := minPercent * main.GetFloat32Field(fieldInfo.Name)
+		profile.SortBy(fieldInfo.Name)
+		minValue := minPercent * profile.Calls[0].GetFloat32Field(fieldInfo.Name)
+		profile = profile.SelectGreater(fieldInfo.Name, minValue)
 		err := renderProfile(profile, field, fieldInfo, minValue)
 		if err != nil {
 			return err
@@ -77,12 +86,15 @@ func analyzeXhprof(cmd *cobra.Command, args []string) error {
 
 		field = "wt"
 		fieldInfo := fieldsMap[field]
+		minPercent = 0.1
 
 		functionCall := profile.GetCall(function)
 		if functionCall == nil {
 			return errors.New("Profile doesn't contain function")
 		}
 		minValue := minPercent * functionCall.GetFloat32Field(fieldInfo.Name)
+		profile.SortBy(fieldInfo.Name)
+		profile = profile.SelectGreater(fieldInfo.Name, minValue)
 
 		fmt.Printf("Parents of %s:\n", function)
 		err := renderProfile(parentsProfile, field, fieldInfo, minValue)

cmd/utils.go

@@ -79,22 +79,20 @@ var fieldsMap map[string]FieldInfo = map[string]FieldInfo{
 }
 
 func renderProfile(profile *xhprof.Profile, field string, fieldInfo FieldInfo, minValue float32) error {
-	profile.SortBy(fieldInfo.Name)
-
+	header := fieldInfo.Header
+	exclHeader := "Excl. " + fieldInfo.Header
 	var fields []FieldInfo
 	if strings.HasPrefix(field, "excl_") {
 		fields = []FieldInfo{fieldsMap[strings.TrimPrefix(field, "excl_")], fieldInfo}
+		exclHeader = fmt.Sprintf("%s (>= %2.2f %s)", exclHeader, minValue/fieldInfo.Unit.Divisor, fieldInfo.Unit.Name)
 	} else {
 		fields = []FieldInfo{fieldInfo, fieldsMap["excl_"+field]}
+		header = fmt.Sprintf("%s (>= %2.2f %s)", header, minValue/fieldInfo.Unit.Divisor, fieldInfo.Unit.Name)
 	}
 
 	table := tablewriter.NewWriter(os.Stdout)
-	table.SetHeader([]string{"Function", "Count", fieldInfo.Header, fmt.Sprintf("Excl. %s", fieldInfo.Header)})
+	table.SetHeader([]string{"Function", "Count", header, exclHeader})
 	for _, call := range profile.Calls {
-		if call.GetFloat32Field(fieldInfo.Name) < minValue {
-			break
-		}
-
 		table.Append(getRow(call, fields))
 	}
 

tests/integration_test.go

@@ -0,0 +1,130 @@
+package main
+
+import (
+	"testing"
+
+	"github.com/tideways/toolkit/xhprof"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestParseWPIndexXhprof(t *testing.T) {
+	f := xhprof.NewFile("data/wp-index.xhprof", "xhprof")
+	m, err := f.GetPairCallMap()
+	require.Nil(t, err)
+	require.IsType(t, m, new(xhprof.PairCallMap))
+	require.NotEmpty(t, m.M)
+
+	assert.Equal(t, m.M["main()"].WallTime, float32(60572))
+	assert.Equal(t, m.M["main()"].Count, 1)
+	assert.Equal(t, m.M["main()"].CpuTime, float32(54683))
+	assert.Equal(t, m.M["main()"].Memory, float32(2738112))
+	assert.Equal(t, m.M["main()"].PeakMemory, float32(2596544))
+	assert.Equal(t, m.M["wp_set_current_user==>setup_userdata"].WallTime, float32(74))
+	assert.Equal(t, m.M["wp_set_current_user==>setup_userdata"].Count, 1)
+	assert.Equal(t, m.M["wp_set_current_user==>setup_userdata"].CpuTime, float32(74))
+	assert.Equal(t, m.M["wp_set_current_user==>setup_userdata"].Memory, float32(4408))
+	assert.Equal(t, m.M["wp_set_current_user==>setup_userdata"].PeakMemory, float32(328))
+
+	p := m.Flatten()
+	require.IsType(t, p, new(xhprof.Profile))
+	require.NotEmpty(t, p.Calls)
+
+	assert.Equal(t, p.GetMain().WallTime, float32(60572))
+
+	c := p.GetCall("is_search")
+	require.IsType(t, c, new(xhprof.Call))
+
+	assert.Equal(t, c.Count, 5)
+	assert.Equal(t, c.WallTime, float32(5))
+	assert.Equal(t, c.ExclusiveWallTime, float32(4))
+	assert.Equal(t, c.CpuTime, float32(5))
+	assert.Equal(t, c.ExclusiveCpuTime, float32(3))
+	assert.Equal(t, c.IoTime, float32(1))
+	assert.Equal(t, c.ExclusiveIoTime, float32(1))
+	assert.Equal(t, c.Memory, float32(672))
+	assert.Equal(t, c.ExclusiveMemory, float32(560))
+
+	c = p.GetCall("vsprintf")
+	require.IsType(t, c, new(xhprof.Call))
+
+	assert.Equal(t, c.Count, 14)
+	assert.Equal(t, c.WallTime, float32(18))
+	assert.Equal(t, c.ExclusiveWallTime, float32(18))
+	assert.Equal(t, c.CpuTime, float32(17))
+	assert.Equal(t, c.ExclusiveCpuTime, float32(17))
+	assert.Equal(t, c.IoTime, float32(2))
+	assert.Equal(t, c.ExclusiveIoTime, float32(2))
+	assert.Equal(t, c.Memory, float32(4704))
+	assert.Equal(t, c.ExclusiveMemory, float32(4704))
+}
+
+func TestParseWPIndexCallgrind(t *testing.T) {
+	expected := xhprof.Profile{
+		Calls: []*xhprof.Call{
+			&xhprof.Call{
+				Name:              "main()",
+				Count:             1,
+				WallTime:          305039,
+				ExclusiveWallTime: 54,
+				IoTime:            305039,
+				ExclusiveIoTime:   54,
+			},
+			&xhprof.Call{
+				Name:              "require::/var/www/wordpress/wp-blog-header.php",
+				Count:             1,
+				WallTime:          304981,
+				ExclusiveWallTime: 86,
+				IoTime:            304981,
+				ExclusiveIoTime:   86,
+			},
+		},
+	}
+
+	f := xhprof.NewFile("data/cachegrind.out", "callgrind")
+	profile, err := f.GetProfile()
+	require.Nil(t, err)
+	require.NotNil(t, profile)
+
+	require.NotNil(t, profile.Main)
+	assert.EqualValues(t, expected.Calls[0], profile.Main)
+
+	for _, c := range profile.Calls {
+		if c.Name == expected.Calls[1].Name {
+			assert.EqualValues(t, expected.Calls[1], c)
+		}
+	}
+}
+
+func TestComputeNearestFamilyWPIndexXhprof(t *testing.T) {
+	expected := &xhprof.NearestFamily{
+		Children: &xhprof.PairCallMap{
+			M: map[string]*xhprof.PairCall{},
+		},
+		Parents: &xhprof.PairCallMap{
+			M: map[string]*xhprof.PairCall{
+				"wpdb::prepare": &xhprof.PairCall{
+					WallTime: float32(17),
+					Count:    11,
+				},
+				"get_custom_header": &xhprof.PairCall{
+					WallTime: float32(1),
+					Count:    3,
+				},
+			},
+		},
+		ChildrenCount: 0,
+		ParentsCount:  14,
+	}
+
+	f := xhprof.NewFile("data/wp-index.xhprof", "xhprof")
+	m, err := f.GetPairCallMap()
+	require.Nil(t, err)
+	require.IsType(t, m, new(xhprof.PairCallMap))
+	require.NotEmpty(t, m.M)
+
+	family := m.ComputeNearestFamily("vsprintf")
+	require.IsType(t, family, new(xhprof.NearestFamily))
+	assert.EqualValues(t, expected, family)
+}

xhprof/call.go

@@ -44,8 +44,15 @@ func (c *Call) AddPairCall(p *PairCall) *Call {
 	c.ExclusiveWallTime += p.WallTime
 	c.CpuTime += p.CpuTime
 	c.ExclusiveCpuTime += p.CpuTime
-	c.IoTime += (p.WallTime - p.CpuTime)
-	c.ExclusiveIoTime += (p.WallTime - p.CpuTime)
+
+	io := p.WallTime - p.CpuTime
+	if io < 0 {
+		io = 0
+	}
+
+	c.IoTime += io
+	c.ExclusiveIoTime += io
+
 	c.Memory += p.Memory
 	c.PeakMemory += p.PeakMemory
 	c.ExclusiveMemory += p.Memory
@@ -57,7 +64,13 @@ func (c *Call) SubtractExcl(p *PairCall) *Call {
 	c.ExclusiveWallTime -= p.WallTime
 	c.ExclusiveCpuTime -= p.CpuTime
 	c.ExclusiveMemory -= p.Memory
-	c.ExclusiveIoTime -= (p.WallTime - p.CpuTime)
+
+	io := p.WallTime - p.CpuTime
+	if io < 0 {
+		io = 0
+	}
+
+	c.ExclusiveIoTime -= io
 
 	return c
 }