func TestLogger_Debugln(t *testing.T) {
now := time.Now()
util.Now = func() time.Time { return now }
defer func() { util.Now = time.Now }()
var buf bytes.Buffer
msg := "test log"
expected := "level:DEBUG\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\n"
for _, v := range []struct {
level log.Level
expected string
}{
{log.NONE, expected},
{log.DEBUG, expected},
{log.INFO, ""},
{log.WARN, ""},
{log.ERROR, ""},
{log.FATAL, ""},
{log.PANIC, ""},
} {
buf.Reset()
logger := log.New(&buf, &log.LTSVFormatter{}, v.level)
logger.Debugln(msg)
actual := buf.String()
expected := v.expected
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`log level => %v; logger.Debugln(%#v) prints %#v; want %#v`, v.level, msg, actual, expected)
}
}
}
func TestLogger_With_Errorf(t *testing.T) {
now := time.Now()
util.Now = func() time.Time { return now }
defer func() { util.Now = time.Now }()
var buf bytes.Buffer
format := "test log: %v"
msg := "this is test"
fields := log.Fields{
"first": 1,
"second": "two",
}
expected := "level:ERROR\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log: this is test\tfirst:1\tsecond:two\n"
for _, v := range []struct {
level log.Level
expected string
}{
{log.NONE, expected},
{log.DEBUG, expected},
{log.INFO, expected},
{log.WARN, expected},
{log.ERROR, expected},
{log.FATAL, ""},
{log.PANIC, ""},
} {
buf.Reset()
logger := log.New(&buf, &log.LTSVFormatter{}, v.level).With(fields)
logger.Errorf(format, msg)
actual := buf.String()
expected := v.expected
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`log level => %v; logger.With(%#v).Errorf(%#v, %#v) prints %#v; want %#v`, v.level, fields, format, msg, actual, expected)
}
}
}
func TestLogger_SetLevel(t *testing.T) {
now := time.Now()
util.Now = func() time.Time { return now }
defer func() { util.Now = time.Now }()
var buf bytes.Buffer
logger := log.New(&buf, &log.LTSVFormatter{}, log.DEBUG)
var actual interface{} = logger.Level()
var expected interface{} = log.DEBUG
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`logger.Level() => %v; want %v`, actual, expected)
}
msg := "test log"
logger.Debug(msg)
actual = buf.String()
expected = "level:DEBUG\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:" + msg + "\n"
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`logger.Debug(%#v) prints %#v; want %#v`, msg, actual, expected)
}
logger.SetLevel(log.INFO)
actual = logger.Level()
expected = log.INFO
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`After logger.SetLevel(%v); logger.Level() => %v; want %v`, log.INFO, actual, expected)
}
buf.Reset()
logger.Debug(msg)
actual = buf.String()
expected = ""
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`After logger.SetLevel(%v); logger.Debug(%#v) => %#v; want %#v`, log.INFO, msg, actual, expected)
}
}
func (app *Application) buildLogger() error {
if app.Config.Logger == nil {
app.Config.Logger = &LoggerConfig{}
}
if app.Config.Logger.Writer == nil {
app.Config.Logger.Writer = os.Stdout
}
if app.Config.Logger.Formatter == nil {
app.Config.Logger.Formatter = &log.LTSVFormatter{}
}
app.Logger = log.New(app.Config.Logger.Writer, app.Config.Logger.Formatter, app.Config.Logger.Level)
return nil
}
func TestLogger_Level(t *testing.T) {
for _, level := range []log.Level{
log.NONE,
log.DEBUG,
log.INFO,
log.WARN,
log.ERROR,
log.FATAL,
log.PANIC,
} {
logger := log.New(ioutil.Discard, &log.LTSVFormatter{}, level)
actual := logger.Level()
expected := level
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`log level => %v; logger.Level() => %v; want %v`, level, actual, expected)
}
}
}
func TestLogger_With_Output(t *testing.T) {
now := time.Now()
util.Now = func() time.Time { return now }
defer func() { util.Now = time.Now }()
var buf bytes.Buffer
msg := "test log"
fields := log.Fields{
"first": 1,
"second": "two",
}
for _, currentLevel := range []log.Level{
log.NONE,
log.DEBUG,
log.INFO,
log.WARN,
log.ERROR,
log.FATAL,
log.PANIC,
} {
for _, v := range []struct {
level log.Level
expected string
}{
{log.NONE, "level:NONE\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"},
{log.DEBUG, "level:DEBUG\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"},
{log.INFO, "level:INFO\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"},
{log.WARN, "level:WARN\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"},
{log.ERROR, "level:ERROR\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"},
{log.FATAL, "level:FATAL\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"},
{log.PANIC, "level:PANIC\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"},
} {
buf.Reset()
logger := log.New(&buf, &log.LTSVFormatter{}, currentLevel).With(fields)
logger.Output(v.level, msg)
actual := buf.String()
expected := v.expected
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`log level => %v; logger.With(%#v).Output(%v, %#v) prints %#v; want %#v`, currentLevel, fields, v.level, msg, actual, expected)
}
}
}
}
func TestLogger_With_Panicln(t *testing.T) {
now := time.Now()
util.Now = func() time.Time { return now }
defer func() { util.Now = time.Now }()
var buf bytes.Buffer
msg := "test log"
fields := log.Fields{
"first": 1,
"second": "two",
}
expected := "level:PANIC\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log\tfirst:1\tsecond:two\n"
for _, v := range []struct {
level log.Level
expected string
}{
{log.NONE, expected},
{log.DEBUG, expected},
{log.INFO, expected},
{log.WARN, expected},
{log.ERROR, expected},
{log.FATAL, expected},
{log.PANIC, expected},
} {
buf.Reset()
logger := log.New(&buf, &log.LTSVFormatter{}, v.level).With(fields)
func() {
defer func() {
if err := recover(); err == nil {
t.Errorf("log level => %v; logger.With(%#v).Panicln(%#v) isn't calling panic()", v.level, msg)
}
}()
logger.Panicln(msg)
}()
actual := buf.String()
expected := v.expected
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`log level => %v; logger.With(%#v).Panicln(%#v) prints %#v; want %#v`, v.level, fields, msg, actual, expected)
}
}
}
func TestLogger_Panicf(t *testing.T) {
now := time.Now()
util.Now = func() time.Time { return now }
defer func() { util.Now = time.Now }()
var buf bytes.Buffer
format := "test log: %v"
msg := "this is test"
expected := "level:PANIC\ttime:" + now.Format(time.RFC3339Nano) + "\tmessage:test log: this is test\n"
for _, v := range []struct {
level log.Level
expected string
}{
{log.NONE, expected},
{log.DEBUG, expected},
{log.INFO, expected},
{log.WARN, expected},
{log.ERROR, expected},
{log.FATAL, expected},
{log.PANIC, expected},
} {
buf.Reset()
logger := log.New(&buf, &log.LTSVFormatter{}, v.level)
func() {
defer func() {
if err := recover(); err == nil {
t.Errorf("log level => %v; logger.Panicf(%#v, %#v) isn't calling panic()", v.level, format, msg)
}
}()
logger.Panicf(format, msg)
}()
actual := buf.String()
expected := v.expected
if !reflect.DeepEqual(actual, expected) {
t.Errorf(`log level => %v; logger.Panicf(%#v, %#v) prints %#v; want %#v`, v.level, format, msg, actual, expected)
}
}
}
func TestContext_RenderError(t *testing.T) {
for _, v := range []struct {
status int
contentType string
expect string
}{
{http.StatusInternalServerError, "text/html", "500 error\n"},
{http.StatusBadRequest, "text/html", "400 error\n"},
{http.StatusInternalServerError, "application/json", "{\"error\":500}\n"},
{http.StatusTeapot, "text/html", http.StatusText(http.StatusTeapot)},
} {
c := newTestContext("testctrlr", "")
w := httptest.NewRecorder()
c.Response = &kocha.Response{ResponseWriter: w}
c.Response.ContentType = v.contentType
if err := c.RenderError(v.status, nil, nil); err != nil {
t.Fatal(err)
}
buf, err := ioutil.ReadAll(w.Body)
if err != nil {
t.Fatal(err)
}
var actual interface{} = string(buf)
var expect interface{} = v.expect
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`Context.RenderError(%#v, %#v, %#v) => %#v; want %#v`, v.status, nil, nil, actual, expect)
}
actual = c.Response.StatusCode
expect = v.status
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`Context.RenderError(%#v, %#v, %#v); HTTP status => %#v; want %#v`, v.status, nil, nil, actual, expect)
}
}
for _, v := range []struct {
err error
contentType string
expect error
}{
{nil, "unknown/content-type", fmt.Errorf("kocha: unknown Content-Type: unknown/content-type")},
{fmt.Errorf("expected error"), "unknown/content-type", fmt.Errorf("kocha: unknown Content-Type: unknown/content-type")},
} {
c := newTestContext("testctrlr", "")
var buf bytes.Buffer
c.App.Logger = log.New(&buf, c.App.Config.Logger.Formatter, c.App.Config.Logger.Level)
c.Response.ContentType = v.contentType
var actual interface{} = c.RenderError(http.StatusInternalServerError, v.err, nil)
_, file, line, _ := runtime.Caller(0)
line--
var expect interface{} = fmt.Errorf("%s:%d: %v", file, line, v.expect)
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`Context.RenderError(%#v, %#v, %#v) => %#v; want %#v`, http.StatusInternalServerError, nil, nil, actual, expect)
}
func() {
actual := buf.String()
expect := fmt.Sprintf("message:%s:%d: %v", file, line, v.err)
if v.err != nil && !strings.Contains(actual, expect) {
t.Errorf(`Context.RenderError(%#v, %#v, %#v); log => %#v; want %#v`, http.StatusInternalServerError, v.err, nil, actual, expect)
}
}()
}
}
func TestPanicRecoverMiddleware(t *testing.T) {
test := func(ident string, w *httptest.ResponseRecorder) {
var actual interface{} = w.Code
var expect interface{} = http.StatusInternalServerError
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`PanicRecoverMiddleware: %s; status => %#v; want %#v`, ident, actual, expect)
}
actual = w.Body.String()
expect = "This is layout\n500 error\n\n"
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`PanicRecoverMiddleware: %s => %#v; want %#v`, ident, actual, expect)
}
actual = w.Header().Get("Content-Type")
expect = "text/html"
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`PanicRecoverMiddleware: %s; Context-Type => %#v; want %#v`, ident, actual, expect)
}
}
func() {
req, err := http.NewRequest("GET", "/error", nil)
if err != nil {
t.Fatal(err)
}
app := kocha.NewTestApp()
app.Config.Middlewares = []kocha.Middleware{
&kocha.PanicRecoverMiddleware{},
&kocha.DispatchMiddleware{},
}
var buf bytes.Buffer
app.Logger = log.New(&buf, &log.LTSVFormatter{}, app.Config.Logger.Level)
w := httptest.NewRecorder()
app.ServeHTTP(w, req)
test(`GET "/error"`, w)
actual := strings.SplitN(buf.String(), "\n", 2)[0]
expect := "\tmessage:panic test"
if !strings.Contains(actual, expect) {
t.Errorf(`PanicRecoverMiddleware: GET "/error"; log => %#v; want contains => %#v`, actual, expect)
}
}()
func() {
req, err := http.NewRequest("GET", "/", nil)
if err != nil {
t.Fatal(err)
}
app := kocha.NewTestApp()
app.Config.Middlewares = []kocha.Middleware{
&kocha.PanicRecoverMiddleware{},
&TestPanicInBeforeMiddleware{},
&kocha.DispatchMiddleware{},
}
var buf bytes.Buffer
app.Logger = log.New(&buf, &log.LTSVFormatter{}, app.Config.Logger.Level)
w := httptest.NewRecorder()
app.ServeHTTP(w, req)
test(`GET "/"`, w)
actual := strings.SplitN(buf.String(), "\n", 2)[0]
expect := "\tmessage:before"
if !strings.Contains(actual, expect) {
t.Errorf(`PanicRecoverMiddleware: GET "/error"; log => %#v; want contains => %#v`, actual, expect)
}
}()
func() {
req, err := http.NewRequest("GET", "/", nil)
if err != nil {
t.Fatal(err)
}
app := kocha.NewTestApp()
app.Config.Middlewares = []kocha.Middleware{
&kocha.PanicRecoverMiddleware{},
&TestPanicInAfterMiddleware{},
&kocha.DispatchMiddleware{},
}
var buf bytes.Buffer
app.Logger = log.New(&buf, &log.LTSVFormatter{}, app.Config.Logger.Level)
w := httptest.NewRecorder()
app.ServeHTTP(w, req)
test(`GET "/"`, w)
actual := strings.SplitN(buf.String(), "\n", 2)[0]
expect := "\tmessage:after"
if !strings.Contains(actual, expect) {
t.Errorf(`PanicRecoverMiddleware: GET "/error"; log => %#v; want contains => %#v`, actual, expect)
}
}()
func() {
defer func() {
actual := recover()
expect := "before"
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`PanicRecoverMiddleware after panic middleware: GET "/" => %#v; want %#v`, actual, expect)
}
}()
req, err := http.NewRequest("GET", "/", nil)
if err != nil {
t.Fatal(err)
}
app := kocha.NewTestApp()
app.Config.Middlewares = []kocha.Middleware{
&TestPanicInBeforeMiddleware{},
&kocha.PanicRecoverMiddleware{},
&kocha.DispatchMiddleware{},
}
w := httptest.NewRecorder()
app.ServeHTTP(w, req)
}()
func() {
defer func() {
actual := recover()
expect := "after"
if !reflect.DeepEqual(actual, expect) {
t.Errorf(`PanicRecoverMiddleware after panic middleware: GET "/" => %#v; want %#v`, actual, expect)
}
}()
req, err := http.NewRequest("GET", "/", nil)
if err != nil {
t.Fatal(err)
}
app := kocha.NewTestApp()
app.Config.Middlewares = []kocha.Middleware{
&TestPanicInAfterMiddleware{},
&kocha.PanicRecoverMiddleware{},
&kocha.DispatchMiddleware{},
}
w := httptest.NewRecorder()
app.ServeHTTP(w, req)
}()
}
"fmt"
"strconv"
"strings"
"time"
"github.com/mrjones/oauth"
"github.com/naoina/kocha/log"
"github.com/wakuworks/retwitter/app/model"
"github.com/wakuworks/retwitter/app/model/twitter"
"github.com/wakuworks/retwitter/config"
"github.com/wakuworks/retwitter/db"
)
var logger = log.New(
config.AppConfig.Logger.Writer,
config.AppConfig.Logger.Formatter,
config.AppConfig.Logger.Level,
)
func Exec() {
logger.Info("auto retweet start.")
dbInst := db.Get("default")
defer func() {
if err := recover(); err != nil {
dbInst.Rollback()
} else {
dbInst.Commit()
}
}()
if err := dbInst.Begin(); err != nil {
