Example #1
0
func TestLogger(t *testing.T) {
	Convey("logger", t, func() {
		c := Use(logging.SetLevel(context.Background(), logging.Debug))
		l := logging.Get(c)
		So(l, ShouldNotBeNil)
		l.Debugf("test %s", logging.Debug)
		l.Infof("test %s", logging.Info)
		l.Warningf("test %s", logging.Warning)
		l.Errorf("test %s", logging.Error)
		l.Errorf("test WAT: %s", logging.Level(9001))
		ml := l.(*MemLogger)
		mld := ml.data

		So(len(*mld), ShouldEqual, 5)
		So((*mld)[0], ShouldResemble, LogEntry{logging.Debug, "test debug", nil})
		So((*mld)[1], ShouldResemble, LogEntry{logging.Info, "test info", nil})
		So((*mld)[2], ShouldResemble, LogEntry{logging.Warning, "test warning", nil})
		So((*mld)[3], ShouldResemble, LogEntry{logging.Error, "test error", nil})
		So((*mld)[4], ShouldResemble, LogEntry{logging.Error, "test WAT: unknown", nil})
	})

	Convey("logger context", t, func() {
		c := Use(context.Background())
		l := logging.Get(c)
		So(l, ShouldNotBeNil)
		ml := l.(*MemLogger)

		l.Infof("totally works: %s", "yes")

		So(len(*ml.data), ShouldEqual, 1)
		So((*ml.data)[0], ShouldResemble, LogEntry{logging.Info, "totally works: yes", nil})
	})

	Convey("field data", t, func() {
		c := Use(context.Background())
		data := map[string]interface{}{
			"trombone": 50,
			"cat":      "amazing",
		}
		c = logging.SetFields(c, logging.NewFields(data))
		l := logging.Get(c)
		ml := l.(*MemLogger)

		l.Infof("Some unsuspecting log")
		So((*ml.data)[0].Data["trombone"], ShouldEqual, 50)
		So((*ml.data)[0].Data["cat"], ShouldEqual, "amazing")
	})
}
Example #2
0
func TestBasicDatastore(t *testing.T) {
	t.Parallel()

	Convey("basic", t, func() {
		inst, err := aetest.NewInstance(&aetest.Options{
			StronglyConsistentDatastore: true,
		})
		So(err, ShouldBeNil)
		defer inst.Close()

		req, err := inst.NewRequest("GET", "/", nil)
		So(err, ShouldBeNil)

		ctx := Use(context.Background(), req)
		ds := datastore.Get(ctx)
		mc := memcache.Get(ctx)
		inf := info.Get(ctx)

		Convey("logging allows you to tweak the level", func() {
			// You have to visually confirm that this actually happens in the stdout
			// of the test... yeah I know.
			logging.Debugf(ctx, "SHOULD NOT SEE")
			logging.Infof(ctx, "SHOULD SEE")

			ctx = logging.SetLevel(ctx, logging.Debug)
			logging.Debugf(ctx, "SHOULD SEE")
			logging.Infof(ctx, "SHOULD SEE (2)")
		})

		Convey("Can probe/change Namespace", func() {
			So(inf.GetNamespace(), ShouldEqual, "")
			ctx, err = inf.Namespace("wat")
			So(err, ShouldBeNil)
			inf = info.Get(ctx)
			So(inf.GetNamespace(), ShouldEqual, "wat")
			ds = datastore.Get(ctx)
			So(ds.MakeKey("Hello", "world").Namespace(), ShouldEqual, "wat")
		})

		Convey("Can get non-transactional context", func() {
			ctx, err := inf.Namespace("foo")
			So(err, ShouldBeNil)
			ds = datastore.Get(ctx)
			inf = info.Get(ctx)

			ds.RunInTransaction(func(ctx context.Context) error {
				So(ds.MakeKey("Foo", "bar").Namespace(), ShouldEqual, "foo")

				So(ds.Put(&TestStruct{ValueI: []int64{100}}), ShouldBeNil)

				err = datastore.GetNoTxn(ctx).RunInTransaction(func(ctx context.Context) error {
					ds = datastore.Get(ctx)
					So(ds.MakeKey("Foo", "bar").Namespace(), ShouldEqual, "foo")
					So(ds.Put(&TestStruct{ValueI: []int64{100}}), ShouldBeNil)
					return nil
				}, nil)
				So(err, ShouldBeNil)

				return nil
			}, nil)
		})

		Convey("Can Put/Get", func() {
			orig := TestStruct{
				ValueI: []int64{1, 7, 946688461000000, 996688461000000},
				ValueB: []bool{true, false},
				ValueS: []string{"hello", "world"},
				ValueF: []float64{1.0, 7.0, 946688461000000.0, 996688461000000.0},
				ValueBS: [][]byte{
					[]byte("allo"),
					[]byte("hello"),
					[]byte("world"),
					[]byte("zurple"),
				},
				ValueK: []*datastore.Key{
					ds.NewKey("Something", "Cool", 0, nil),
					ds.NewKey("Something", "", 1, nil),
					ds.NewKey("Something", "Recursive", 0,
						ds.NewKey("Parent", "", 2, nil)),
				},
				ValueBK: []blobstore.Key{"bellow", "hello"},
				ValueGP: []datastore.GeoPoint{
					{Lat: 120.7, Lng: 95.5},
				},
			}
			So(ds.Put(&orig), ShouldBeNil)

			ret := TestStruct{ID: orig.ID}
			So(ds.Get(&ret), ShouldBeNil)
			So(ret, ShouldResemble, orig)

			// can't be sure the indexes have caught up... so sleep
			time.Sleep(time.Second)

			Convey("Can query", func() {
				q := datastore.NewQuery("TestStruct")
				ds.Run(q, func(ts *TestStruct) {
					So(*ts, ShouldResemble, orig)
				})
				count, err := ds.Count(q)
				So(err, ShouldBeNil)
				So(count, ShouldEqual, 1)
			})

			Convey("Can project", func() {
				q := datastore.NewQuery("TestStruct").Project("ValueS")
				rslts := []datastore.PropertyMap{}
				So(ds.GetAll(q, &rslts), ShouldBeNil)
				So(rslts, ShouldResemble, []datastore.PropertyMap{
					{
						"$key":   {mpNI(ds.KeyForObj(&orig))},
						"ValueS": {mp("hello")},
					},
					{
						"$key":   {mpNI(ds.KeyForObj(&orig))},
						"ValueS": {mp("world")},
					},
				})

				q = datastore.NewQuery("TestStruct").Project("ValueBS")
				rslts = []datastore.PropertyMap{}
				So(ds.GetAll(q, &rslts), ShouldBeNil)
				So(rslts, ShouldResemble, []datastore.PropertyMap{
					{
						"$key":    {mpNI(ds.KeyForObj(&orig))},
						"ValueBS": {mp("allo")},
					},
					{
						"$key":    {mpNI(ds.KeyForObj(&orig))},
						"ValueBS": {mp("hello")},
					},
					{
						"$key":    {mpNI(ds.KeyForObj(&orig))},
						"ValueBS": {mp("world")},
					},
					{
						"$key":    {mpNI(ds.KeyForObj(&orig))},
						"ValueBS": {mp("zurple")},
					},
				})

				count, err := ds.Count(q)
				So(err, ShouldBeNil)
				So(count, ShouldEqual, 4)

				q = datastore.NewQuery("TestStruct").Lte("ValueI", 7).Project("ValueS").Distinct(true)
				rslts = []datastore.PropertyMap{}
				So(ds.GetAll(q, &rslts), ShouldBeNil)
				So(rslts, ShouldResemble, []datastore.PropertyMap{
					{
						"$key":   {mpNI(ds.KeyForObj(&orig))},
						"ValueI": {mp(1)},
						"ValueS": {mp("hello")},
					},
					{
						"$key":   {mpNI(ds.KeyForObj(&orig))},
						"ValueI": {mp(1)},
						"ValueS": {mp("world")},
					},
					{
						"$key":   {mpNI(ds.KeyForObj(&orig))},
						"ValueI": {mp(7)},
						"ValueS": {mp("hello")},
					},
					{
						"$key":   {mpNI(ds.KeyForObj(&orig))},
						"ValueI": {mp(7)},
						"ValueS": {mp("world")},
					},
				})

				count, err = ds.Count(q)
				So(err, ShouldBeNil)
				So(count, ShouldEqual, 4)
			})
		})

		Convey("Can Put/Get (time)", func() {
			// time comparisons in Go are wonky, so this is pulled out
			pm := datastore.PropertyMap{
				"$key": {mpNI(ds.NewKey("Something", "value", 0, nil))},
				"Time": {
					mp(time.Date(1938, time.January, 1, 1, 1, 1, 1, time.UTC)),
					mp(time.Time{}),
				},
			}
			So(ds.Put(&pm), ShouldBeNil)

			rslt := datastore.PropertyMap{}
			rslt.SetMeta("key", ds.KeyForObj(pm))
			So(ds.Get(&rslt), ShouldBeNil)

			So(pm["Time"][0].Value(), ShouldResemble, rslt["Time"][0].Value())

			q := datastore.NewQuery("Something").Project("Time")
			all := []datastore.PropertyMap{}
			So(ds.GetAll(q, &all), ShouldBeNil)
			So(len(all), ShouldEqual, 2)
			prop := all[0]["Time"][0]
			So(prop.Type(), ShouldEqual, datastore.PTInt)

			tval, err := prop.Project(datastore.PTTime)
			So(err, ShouldBeNil)
			So(tval, ShouldResemble, time.Time{}.UTC())

			tval, err = all[1]["Time"][0].Project(datastore.PTTime)
			So(err, ShouldBeNil)
			So(tval, ShouldResemble, pm["Time"][0].Value())

			ent := datastore.PropertyMap{
				"$key": {mpNI(ds.MakeKey("Something", "value"))},
			}
			So(ds.Get(&ent), ShouldBeNil)
			So(ent["Time"], ShouldResemble, pm["Time"])
		})

		Convey("memcache: Set (nil) is the same as Set ([]byte{})", func() {
			So(mc.Set(mc.NewItem("bob")), ShouldBeNil) // normally would panic because Value is nil

			bob, err := mc.Get("bob")
			So(err, ShouldBeNil)
			So(bob.Value(), ShouldResemble, []byte{})
		})
	})
}
Example #3
0
// mainImpl is the main execution function.
func mainImpl(args []string) int {
	// Use all of teh corez.
	if os.Getenv("GOMAXPROCS") == "" {
		runtime.GOMAXPROCS(runtime.NumCPU())
	}

	// Install a console logger by default.
	ctx := context.Background()
	ctx = gologger.Use(ctx)

	loggerConfig := newLoggerConfig() // Internal logging config (cloud logging).
	logConfig := log.Config{Level: log.Debug}
	config := config{}

	fs := flag.CommandLine
	config.addFlags(fs)
	loggerConfig.addFlags(fs)
	logConfig.AddFlags(fs)
	fs.Parse(args)

	// TODO(dnj): Fix this once LUCI logging CL lands.
	ctx = log.SetLevel(ctx, logConfig.Level)
	ctx = logConfig.Set(ctx)

	// Load authenticated client.
	client, err := config.createAuthenticatedClient(ctx)
	if err != nil {
		log.Errorf(log.SetError(ctx, err), "Failed to create authenticated service client.")
		return 1
	}

	// Setup local logging configuration.
	ctx, logFlushFunc, err := loggerConfig.use(ctx, client)
	if err == nil {
		defer logFlushFunc()
	} else {
		log.Warningf(log.SetError(ctx, err), "Failed to setup cloud logging.")
	}

	app := newApplication(config)
	if err := app.loadServices(ctx, client); err != nil {
		log.Errorf(log.SetError(ctx, err), "Failed to initialize services.")
		return 1
	}

	// Set up interrupt handler.
	signalC := make(chan os.Signal, 1)
	go func() {
		triggered := false
		for sig := range signalC {
			if !triggered {
				triggered = true

				log.Infof(log.SetField(ctx, "signal", sig),
					"Received signal; starting shutdown.")
				app.shutdown()
			} else {
				// Triggered multiple times; immediately shut down.
				os.Exit(1)
			}
		}
	}()
	signal.Notify(signalC, os.Interrupt, os.Kill)
	defer func() {
		signal.Stop(signalC)
		close(signalC)
	}()

	log.Infof(ctx, "Starting application execution...")
	if err := app.run(ctx); err != nil {
		log.Errorf(log.SetError(ctx, err), "Error during application execution.")
		return 1
	}

	return 0
}
Example #4
0
func TestGoLogger(t *testing.T) {
	Convey(`A new Go Logger instance`, t, func() {
		// Regex to pull log information from "formatString".

		buf := bytes.Buffer{}
		l := New(&buf, gol.DEBUG)

		for _, entry := range []struct {
			L logging.Level
			F func(string, ...interface{})
			T string
		}{
			{logging.Debug, l.Debugf, "DEBU"},
			{logging.Info, l.Infof, "INFO"},
			{logging.Warning, l.Warningf, "WARN"},
			{logging.Error, l.Errorf, "ERRO"},
		} {
			Convey(fmt.Sprintf("Can log to: %s", entry.L), func() {
				entry.F("Test logging %s", entry.L)
				matches := lre.FindAllStringSubmatch(normalizeLog(buf.String()), -1)
				So(len(matches), ShouldEqual, 1)
				So(len(matches[0]), ShouldEqual, 4)
				So(matches[0][1], ShouldEqual, "gologger_test.go")
				So(matches[0][2], ShouldEqual, entry.T)
				So(matches[0][3], ShouldEqual, fmt.Sprintf("Test logging %s", entry.L))
			})
		}
	})

	Convey(`A Go Logger instance installed in a Context at Info.`, t, func() {
		buf := bytes.Buffer{}
		lc := &LoggerConfig{
			Format: standardConfig.Format,
			Out:    &buf,
			Level:  gol.DEBUG,
		}
		c := logging.SetLevel(lc.Use(context.Background()), logging.Info)

		Convey(`Should log through top-level Context methods.`, func() {
			for _, entry := range []struct {
				L logging.Level
				F func(context.Context, string, ...interface{})
				T string
			}{
				{logging.Info, logging.Infof, "INFO"},
				{logging.Warning, logging.Warningf, "WARN"},
				{logging.Error, logging.Errorf, "ERRO"},
			} {
				Convey(fmt.Sprintf("Can log to: %s", entry.L), func() {
					entry.F(c, "Test logging %s", entry.L)
					matches := lre.FindAllStringSubmatch(normalizeLog(buf.String()), -1)
					So(len(matches), ShouldEqual, 1)
					So(len(matches[0]), ShouldEqual, 4)
					So(matches[0][1], ShouldEqual, "gologger_test.go")
					So(matches[0][2], ShouldEqual, entry.T)
					So(matches[0][3], ShouldEqual, fmt.Sprintf("Test logging %s", entry.L))
				})
			}
		})

		Convey(`With Fields installed in the Context`, func() {
			c = logging.SetFields(c, logging.Fields{
				logging.ErrorKey: "An error!",
				"reason":         "test",
			})

			Convey(`Should log Fields.`, func() {
				logging.Infof(c, "Here is a %s", "log")
				matches := lre.FindAllStringSubmatch(normalizeLog(buf.String()), -1)
				So(len(matches), ShouldEqual, 1)
				So(len(matches[0]), ShouldEqual, 4)
				So(matches[0][1], ShouldEqual, "gologger_test.go")
				So(matches[0][2], ShouldEqual, "INFO")
				So(matches[0][3], ShouldEqual,
					`Here is a log                               {"error":"An error!", "reason":"test"}`)
			})

			Convey(`Should log fields installed immediately`, func() {
				logging.Fields{
					"foo":    "bar",
					"reason": "override",
				}.Infof(c, "Here is another %s", "log")

				matches := lre.FindAllStringSubmatch(normalizeLog(buf.String()), -1)
				So(len(matches), ShouldEqual, 1)
				So(len(matches[0]), ShouldEqual, 4)
				So(matches[0][1], ShouldEqual, "gologger_test.go")
				So(matches[0][2], ShouldEqual, "INFO")
				So(matches[0][3], ShouldEqual,
					`Here is another log                         {"error":"An error!", "foo":"bar", "reason":"override"}`)
			})
		})

		Convey(`Will not log to Debug, as it's below level.`, func() {
			logging.Debugf(c, "Hello!")
			So(buf.Len(), ShouldEqual, 0)
		})
	})
}