github.com/vmware/govmomi@v0.43.0/govc/flags/debug.go (about)

     1  /*
     2  Copyright (c) 2014-2016 VMware, Inc. All Rights Reserved.
     3  
     4  Licensed under the Apache License, Version 2.0 (the "License");
     5  you may not use this file except in compliance with the License.
     6  You may obtain a copy of the License at
     7  
     8      http://www.apache.org/licenses/LICENSE-2.0
     9  
    10  Unless required by applicable law or agreed to in writing, software
    11  distributed under the License is distributed on an "AS IS" BASIS,
    12  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    13  See the License for the specific language governing permissions and
    14  limitations under the License.
    15  */
    16  
    17  package flags
    18  
    19  import (
    20  	"bufio"
    21  	"context"
    22  	"flag"
    23  	"fmt"
    24  	"io"
    25  	"os"
    26  	"os/exec"
    27  	"path/filepath"
    28  	"reflect"
    29  	"strings"
    30  	"sync"
    31  	"text/tabwriter"
    32  	"time"
    33  
    34  	"github.com/dougm/pretty"
    35  
    36  	"github.com/vmware/govmomi/vim25/debug"
    37  	"github.com/vmware/govmomi/vim25/soap"
    38  	"github.com/vmware/govmomi/vim25/types"
    39  )
    40  
    41  type cmdFormat struct {
    42  	path string
    43  	err  error
    44  	args []string
    45  }
    46  
    47  func (c *cmdFormat) lookPath(file string, args ...string) {
    48  	c.args = args
    49  	c.path, c.err = exec.LookPath(file)
    50  }
    51  
    52  func (c *cmdFormat) cmd() (*exec.Cmd, error) {
    53  	if c.err != nil {
    54  		return nil, c.err
    55  	}
    56  	return exec.Command(c.path, c.args...), nil
    57  }
    58  
    59  type DebugFlag struct {
    60  	common
    61  
    62  	enable  bool
    63  	trace   bool
    64  	verbose bool
    65  	dump    bool
    66  	xml     cmdFormat
    67  	json    cmdFormat
    68  }
    69  
    70  var debugFlagKey = flagKey("debug")
    71  
    72  func NewDebugFlag(ctx context.Context) (*DebugFlag, context.Context) {
    73  	if v := ctx.Value(debugFlagKey); v != nil {
    74  		return v.(*DebugFlag), ctx
    75  	}
    76  
    77  	v := &DebugFlag{}
    78  	ctx = context.WithValue(ctx, debugFlagKey, v)
    79  	return v, ctx
    80  }
    81  
    82  func (flag *DebugFlag) Verbose() bool {
    83  	return flag.verbose
    84  }
    85  
    86  func (flag *DebugFlag) Register(ctx context.Context, f *flag.FlagSet) {
    87  	flag.RegisterOnce(func() {
    88  		env := "GOVC_DEBUG"
    89  		enable := false
    90  		switch env := strings.ToLower(os.Getenv(env)); env {
    91  		case "1", "true":
    92  			enable = true
    93  		}
    94  
    95  		usage := fmt.Sprintf("Store debug logs [%s]", env)
    96  		f.BoolVar(&flag.enable, "debug", enable, usage)
    97  		f.BoolVar(&flag.trace, "trace", false, "Write SOAP/REST traffic to stderr")
    98  		f.BoolVar(&flag.verbose, "verbose", false, "Write request/response data to stderr")
    99  	})
   100  }
   101  
   102  type cmdFormatCloser struct {
   103  	rc  io.Closer
   104  	in  io.Closer
   105  	cmd *exec.Cmd
   106  	wg  *sync.WaitGroup
   107  }
   108  
   109  func (c *cmdFormatCloser) Close() error {
   110  	_ = c.rc.Close()
   111  	_ = c.in.Close()
   112  	c.wg.Wait()
   113  	return c.cmd.Wait()
   114  }
   115  
   116  func (flag *DebugFlag) newFormatReader(rc io.ReadCloser, w io.Writer, ext string) (io.ReadCloser, error) {
   117  	var err error
   118  	var cmd *exec.Cmd
   119  
   120  	switch ext {
   121  	case "json":
   122  		cmd, err = flag.json.cmd()
   123  		if err != nil {
   124  			return nil, err
   125  		}
   126  	case "xml":
   127  		cmd, err = flag.xml.cmd()
   128  		if err != nil {
   129  			return nil, err
   130  		}
   131  	default:
   132  		return nil, fmt.Errorf("unsupported type %s", ext)
   133  	}
   134  
   135  	cmd.Stderr = os.Stderr
   136  
   137  	stdin, err := cmd.StdinPipe()
   138  	if err != nil {
   139  		return nil, err
   140  	}
   141  
   142  	stdout, err := cmd.StdoutPipe()
   143  	if err != nil {
   144  		return nil, err
   145  	}
   146  
   147  	err = cmd.Start()
   148  	if err != nil {
   149  		return nil, err
   150  	}
   151  
   152  	var wg sync.WaitGroup
   153  	wg.Add(1)
   154  	go func() {
   155  		_, _ = io.Copy(w, stdout)
   156  		wg.Done()
   157  	}()
   158  
   159  	return debug.ReadCloser{
   160  		Reader: io.TeeReader(rc, stdin),
   161  		Closer: &cmdFormatCloser{rc, stdin, cmd, &wg},
   162  	}, nil
   163  }
   164  
   165  func (flag *DebugFlag) debugTrace(rc io.ReadCloser, w io.Writer, ext string) io.ReadCloser {
   166  	fr, err := flag.newFormatReader(rc, w, ext)
   167  	if err != nil {
   168  		return debug.NewTeeReader(rc, w)
   169  	}
   170  	return fr
   171  }
   172  
   173  func (flag *DebugFlag) Process(ctx context.Context) error {
   174  	// Base path for storing debug logs.
   175  	r := os.Getenv("GOVC_DEBUG_PATH")
   176  
   177  	if flag.trace {
   178  		if flag.verbose {
   179  			flag.dump = true // output req/res as Go code
   180  			return nil
   181  		}
   182  		r = "-"
   183  		flag.enable = true
   184  		if os.Getenv("GOVC_DEBUG_FORMAT") != "false" {
   185  			debugXML := os.Getenv("GOVC_DEBUG_XML")
   186  			if debugXML == "" {
   187  				debugXML = "xmlstarlet"
   188  			}
   189  			flag.xml.lookPath(debugXML, "fo")
   190  
   191  			debugJSON := os.Getenv("GOVC_DEBUG_JSON")
   192  			if debugJSON == "" {
   193  				debugJSON = "jq"
   194  			}
   195  			flag.json.lookPath(debugJSON, ".")
   196  
   197  			soap.Trace = flag.debugTrace
   198  		}
   199  	}
   200  
   201  	if !flag.enable {
   202  		return nil
   203  	}
   204  
   205  	return flag.ProcessOnce(func() error {
   206  		switch r {
   207  		case "-":
   208  			debug.SetProvider(&debug.LogProvider{})
   209  			return nil
   210  		case "":
   211  			r = home
   212  		}
   213  		r = filepath.Join(r, "debug")
   214  
   215  		// Path for this particular run.
   216  		run := os.Getenv("GOVC_DEBUG_PATH_RUN")
   217  		if run == "" {
   218  			now := time.Now().Format("2006-01-02T15-04-05.999999999")
   219  			r = filepath.Join(r, now)
   220  		} else {
   221  			// reuse the same path
   222  			r = filepath.Join(r, run)
   223  			_ = os.RemoveAll(r)
   224  		}
   225  
   226  		err := os.MkdirAll(r, 0700)
   227  		if err != nil {
   228  			return err
   229  		}
   230  
   231  		p := debug.FileProvider{
   232  			Path: r,
   233  		}
   234  
   235  		debug.SetProvider(&p)
   236  		return nil
   237  	})
   238  }
   239  
   240  type dump struct {
   241  	roundTripper soap.RoundTripper
   242  }
   243  
   244  func (d *dump) RoundTrip(ctx context.Context, req, res soap.HasFault) error {
   245  	vreq := reflect.ValueOf(req).Elem().FieldByName("Req").Elem()
   246  
   247  	pretty.Fprintf(os.Stderr, "%# v\n", vreq.Interface())
   248  
   249  	err := d.roundTripper.RoundTrip(ctx, req, res)
   250  	if err != nil {
   251  		if fault := res.Fault(); fault != nil {
   252  			pretty.Fprintf(os.Stderr, "%# v\n", fault)
   253  		}
   254  		return err
   255  	}
   256  
   257  	vres := reflect.ValueOf(res).Elem().FieldByName("Res").Elem()
   258  	pretty.Fprintf(os.Stderr, "%# v\n", vres.Interface())
   259  
   260  	return nil
   261  }
   262  
   263  type verbose struct {
   264  	roundTripper soap.RoundTripper
   265  }
   266  
   267  func (*verbose) mor(ref types.ManagedObjectReference) string {
   268  	if strings.HasPrefix(ref.Value, "session") {
   269  		ref.Value = "session[...]"
   270  		return ref.String()
   271  	}
   272  	return ref.Value
   273  }
   274  
   275  func (*verbose) str(val reflect.Value) string {
   276  	if !val.IsValid() {
   277  		return ""
   278  	}
   279  
   280  	switch val.Kind() {
   281  	case reflect.Ptr, reflect.Interface:
   282  		if val.IsNil() {
   283  			return "nil"
   284  		}
   285  	}
   286  
   287  	p := ""
   288  
   289  	switch pval := val.Interface().(type) {
   290  	case fmt.Stringer:
   291  		p = pval.String()
   292  	case string:
   293  		if len(pval) > 45 {
   294  			pval = pval[:42] + "..."
   295  		}
   296  		p = fmt.Sprintf("%s", pval)
   297  	case []string:
   298  		p = fmt.Sprintf("%v", pval)
   299  	case []types.ManagedObjectReference:
   300  		refs := make([]string, len(pval))
   301  		for i := range pval {
   302  			refs[i] = pval[i].Value
   303  		}
   304  		p = fmt.Sprintf("%v", refs)
   305  	default:
   306  		return ""
   307  	}
   308  
   309  	return p
   310  }
   311  
   312  func (v *verbose) value(val types.AnyType) string {
   313  	rval := reflect.ValueOf(val)
   314  	if rval.Kind() == reflect.Ptr && !rval.IsNil() {
   315  		rval = rval.Elem()
   316  	}
   317  	if rval.Kind() == reflect.Struct {
   318  		if strings.HasPrefix(rval.Type().Name(), "ArrayOf") {
   319  			rval = rval.Field(0)
   320  			val = rval.Interface()
   321  		}
   322  	}
   323  	s := v.str(rval)
   324  	if s != "" {
   325  		return s
   326  	}
   327  	return v.prettyPrint(val)
   328  }
   329  
   330  func (v *verbose) propertyValue(obj types.ManagedObjectReference, name string, pval types.AnyType) string {
   331  	val := v.value(pval)
   332  	if obj.Type != "Task" && !strings.HasPrefix(obj.Value, "session") {
   333  		if len(val) > 512 {
   334  			val = fmt.Sprintf("`govc object.collect -dump %s %s`", obj, name)
   335  		}
   336  	}
   337  	return fmt.Sprintf("%s\t%s:\t%s", v.mor(obj), name, val)
   338  }
   339  
   340  func (v *verbose) missingSet(o types.ManagedObjectReference, m []types.MissingProperty) []string {
   341  	var s []string
   342  	for _, p := range m {
   343  		s = append(s, fmt.Sprintf("%s\t%s:\t%s", v.mor(o), p.Path, v.prettyPrint(p.Fault.Fault)))
   344  	}
   345  	return s
   346  }
   347  
   348  func (v *verbose) updateSet(u *types.UpdateSet) []string {
   349  	var s []string
   350  	if u == nil {
   351  		return s
   352  	}
   353  	for _, f := range u.FilterSet {
   354  		for _, o := range f.ObjectSet {
   355  			for _, c := range o.ChangeSet {
   356  				s = append(s, v.propertyValue(o.Obj, c.Name, c.Val))
   357  			}
   358  			s = append(s, v.missingSet(o.Obj, o.MissingSet)...)
   359  		}
   360  	}
   361  	return s
   362  }
   363  
   364  func (v *verbose) objectContent(content []types.ObjectContent) []string {
   365  	var s []string
   366  	for _, o := range content {
   367  		for _, p := range o.PropSet {
   368  			s = append(s, v.propertyValue(o.Obj, p.Name, p.Val))
   369  		}
   370  		s = append(s, v.missingSet(o.Obj, o.MissingSet)...)
   371  	}
   372  	return s
   373  }
   374  
   375  func (v *verbose) prettyPrint(val interface{}) string {
   376  	p := pretty.Sprintf("%# v\n", val)
   377  	var res []string
   378  	scanner := bufio.NewScanner(strings.NewReader(p))
   379  	for scanner.Scan() {
   380  		line := scanner.Text()
   381  		if strings.Contains(line, "nil,") || strings.Contains(line, "(nil),") {
   382  			continue // nil pointer field
   383  		}
   384  		if strings.Contains(line, `"",`) {
   385  			continue // empty string field
   386  		}
   387  		if strings.Contains(line, `{},`) {
   388  			continue // empty embedded struct
   389  		}
   390  		if strings.Contains(line, "[context]") {
   391  			continue // noisy base64 encoded backtrace
   392  		}
   393  		res = append(res, line)
   394  	}
   395  	return strings.Join(res, "\n")
   396  }
   397  
   398  func (v *verbose) table(vals []string) {
   399  	tw := tabwriter.NewWriter(os.Stderr, 2, 0, 1, ' ', 0)
   400  	for _, val := range vals {
   401  		fmt.Fprintf(tw, "...%s\n", val)
   402  	}
   403  	tw.Flush()
   404  }
   405  
   406  func (v *verbose) RoundTrip(ctx context.Context, req, res soap.HasFault) error {
   407  	vreq := reflect.ValueOf(req).Elem().FieldByName("Req").Elem()
   408  	param := []string{""}
   409  	switch f := vreq.Field(0).Interface().(type) {
   410  	case types.ManagedObjectReference:
   411  		param[0] = v.mor(f)
   412  	default:
   413  		param[0] = fmt.Sprintf("%v", f)
   414  	}
   415  
   416  	for i := 1; i < vreq.NumField(); i++ {
   417  		val := vreq.Field(i)
   418  
   419  		if val.Kind() == reflect.Interface {
   420  			val = val.Elem()
   421  		}
   422  
   423  		p := v.str(val)
   424  		if p == "" {
   425  			switch val.Kind() {
   426  			case reflect.Ptr, reflect.Slice, reflect.Struct:
   427  				p = val.Type().String()
   428  			default:
   429  				p = fmt.Sprintf("%v", val.Interface())
   430  			}
   431  		}
   432  
   433  		param = append(param, p)
   434  	}
   435  
   436  	fmt.Fprintf(os.Stderr, "%s(%s)...\n", vreq.Type().Name(), strings.Join(param, ", "))
   437  
   438  	err := v.roundTripper.RoundTrip(ctx, req, res)
   439  	if err != nil {
   440  		if fault := res.Fault(); fault != nil {
   441  			fmt.Fprintln(os.Stderr, v.prettyPrint(fault))
   442  		} else {
   443  			fmt.Fprintf(os.Stderr, "...%s\n", err)
   444  		}
   445  		return err
   446  	}
   447  
   448  	vres := reflect.ValueOf(res).Elem().FieldByName("Res").Elem()
   449  	ret := vres.FieldByName("Returnval")
   450  	var s interface{} = "void"
   451  
   452  	if ret.IsValid() {
   453  		switch x := ret.Interface().(type) {
   454  		case types.ManagedObjectReference:
   455  			s = v.mor(x)
   456  		case *types.UpdateSet:
   457  			s = v.updateSet(x)
   458  		case []types.ObjectContent:
   459  			s = v.objectContent(x)
   460  		case fmt.Stringer:
   461  			s = x.String()
   462  		default:
   463  			s = v.value(x)
   464  		}
   465  	}
   466  	if vals, ok := s.([]string); ok {
   467  		v.table(vals)
   468  	} else {
   469  		fmt.Fprintf(os.Stderr, "...%s\n", s)
   470  	}
   471  	fmt.Fprintln(os.Stderr)
   472  
   473  	return err
   474  }