rebase: logger is ported (Geth 1.6 logging)

This commit is contained in:
Victor Farazdagi 2017-05-02 17:30:11 +03:00
parent b7c38238bd
commit a0fef0a0b6
7 changed files with 206 additions and 367 deletions

View file

@ -3,17 +3,14 @@ package params
import (
"encoding/json"
"errors"
"fmt"
"io/ioutil"
"math/big"
"os"
"path/filepath"
"strings"
"github.com/ethereum/go-ethereum/common"
"github.com/ethereum/go-ethereum/core"
"github.com/ethereum/go-ethereum/logger"
"github.com/ethereum/go-ethereum/logger/glog"
"github.com/ethereum/go-ethereum/params"
"github.com/ethereum/go-ethereum/log"
)
// default node configuration options
@ -33,33 +30,6 @@ var (
ErrMissingNetworkId = errors.New("missing required 'NetworkId' parameter")
)
// ChainConfig holds core blockchain settings. It is stored in the database on a per block basis.
type ChainConfig struct {
// ChainId identifies the current chain and is used for replay protection
ChainId *big.Int
// HomesteadBlock is Homestead switch block (nil = no fork, 0 = already homestead)
HomesteadBlock *big.Int
// DAOForkBlock TheDAO hard-fork switch block (nil = no fork)
DAOForkBlock *big.Int
// DAOForkSupport Whether the nodes supports or opposes the DAO hard-fork
DAOForkSupport bool
// EIP150Block is EIP150 HF block (nil = no fork)
EIP150Block *big.Int
// EIP150Hash is EIP150 HF hash (fast sync aid)
EIP150Hash common.Hash
// EIP155Block is EIP155 HF block
EIP155Block *big.Int
// EIP158Block is EIP158 HF block
EIP158Block *big.Int
}
// LightEthConfig holds LES-related configuration
// Status nodes are always lightweight clients (due to mobile platform constraints)
type LightEthConfig struct {
@ -124,7 +94,7 @@ type NodeConfig struct {
TestNet bool
// NetworkId sets network to use for selecting peers to connect to
NetworkId int
NetworkId uint64
// DataDir is the file system folder the node should use for any data storage needs.
DataDir string
@ -187,11 +157,11 @@ type NodeConfig struct {
// LogFile is filename where exposed logs get written to
LogFile string
// LogLevel defines minimum log level. Valid names are "ERROR", "WARNING", "INFO", "DEBUG", and "DETAIL".
// LogLevel defines minimum log level. Valid names are "ERROR", "WARNING", "INFO", "DEBUG", and "TRACE".
LogLevel string
// ChainConfig extra configuration for blockchain
*ChainConfig `json:"ChainConfig,"`
// LogToStderr defines whether logged info should also be output to os.Stderr
LogToStderr bool
// LightEthConfig extra configuration for LES
LightEthConfig *LightEthConfig `json:"LightEthConfig,"`
@ -204,7 +174,7 @@ type NodeConfig struct {
}
// NewNodeConfig creates new node configuration object
func NewNodeConfig(dataDir string, networkId int) (*NodeConfig, error) {
func NewNodeConfig(dataDir string, networkId uint64) (*NodeConfig, error) {
nodeConfig := &NodeConfig{
NetworkId: networkId,
DataDir: dataDir,
@ -220,7 +190,7 @@ func NewNodeConfig(dataDir string, networkId int) (*NodeConfig, error) {
IPCFile: IPCFile,
LogFile: LogFile,
LogLevel: LogLevel,
ChainConfig: &ChainConfig{},
LogToStderr: LogToStderr,
LightEthConfig: &LightEthConfig{
Enabled: true,
DatabaseCache: DatabaseCache,
@ -235,14 +205,18 @@ func NewNodeConfig(dataDir string, networkId int) (*NodeConfig, error) {
}
// auto-populate some dependent values
nodeConfig.populateChainConfig()
nodeConfig.populateDirs()
if err := nodeConfig.populateGenesis(); err != nil {
return nil, err
}
if err := nodeConfig.populateDirs(); err != nil {
return nil, err
}
return nodeConfig, nil
}
// populateDirs updates directories that should be wrt to DataDir
func (c *NodeConfig) populateDirs() {
func (c *NodeConfig) populateDirs() error {
makeSubDirPath := func(baseDir, subDir string) string {
if len(baseDir) == 0 {
return ""
@ -257,51 +231,32 @@ func (c *NodeConfig) populateDirs() {
if len(c.WhisperConfig.DataDir) == 0 {
c.WhisperConfig.DataDir = makeSubDirPath(c.DataDir, WhisperDataDir)
}
return nil
}
// populateChainConfig does necessary adjustments to config object (depending on network node will be running on)
func (c *NodeConfig) populateChainConfig() {
// populateChainConfig does necessary adjustments to config object (depending on network node will be runnin on)
func (c *NodeConfig) populateGenesis() error {
c.TestNet = false
if c.NetworkId == TestNetworkId {
c.TestNet = true
}
var genesis *core.Genesis
if c.TestNet {
// Homestead fork
c.ChainConfig.HomesteadBlock = params.TestnetChainConfig.HomesteadBlock
// DAO fork
c.ChainConfig.DAOForkBlock = params.TestnetChainConfig.DAOForkBlock
c.ChainConfig.DAOForkSupport = params.TestnetChainConfig.DAOForkSupport
// DoS reprice fork
c.ChainConfig.EIP150Block = params.TestnetChainConfig.EIP150Block
c.ChainConfig.EIP150Hash = params.TestnetChainConfig.EIP150Hash
// DoS state cleanup fork
c.ChainConfig.EIP155Block = params.TestnetChainConfig.EIP155Block
c.ChainConfig.EIP158Block = params.TestnetChainConfig.EIP158Block
c.ChainConfig.ChainId = params.TestnetChainConfig.ChainId
c.LightEthConfig.Genesis = core.DefaultTestnetGenesisBlock()
genesis = core.DefaultTestnetGenesisBlock()
} else {
// Homestead fork
c.ChainConfig.HomesteadBlock = params.MainNetHomesteadBlock
// DAO fork
c.ChainConfig.DAOForkBlock = params.MainNetDAOForkBlock
c.ChainConfig.DAOForkSupport = true
// DoS reprice fork
c.ChainConfig.EIP150Block = params.MainNetHomesteadGasRepriceBlock
c.ChainConfig.EIP150Hash = params.MainNetHomesteadGasRepriceHash
// DoS state cleanup fork
c.ChainConfig.EIP155Block = params.MainNetSpuriousDragon
c.ChainConfig.EIP158Block = params.MainNetSpuriousDragon
c.ChainConfig.ChainId = params.MainNetChainID
c.LightEthConfig.Genesis = core.DefaultGenesisBlock()
genesis = core.DefaultGenesisBlock()
}
// encode the genesis into JSON
enc, err := json.Marshal(genesis)
if err != nil {
return err
}
c.LightEthConfig.Genesis = string(enc)
return nil
}
// LoadNodeConfig parses incoming JSON and returned it as Config
@ -320,8 +275,12 @@ func LoadNodeConfig(configJSON string) (*NodeConfig, error) {
}
// repopulate
nodeConfig.populateChainConfig()
nodeConfig.populateDirs()
if err := nodeConfig.populateGenesis(); err != nil {
return nil, err
}
if err := nodeConfig.populateDirs(); err != nil {
return nil, err
}
if len(nodeConfig.DataDir) == 0 {
return nil, ErrMissingDataDir
@ -350,7 +309,7 @@ func (c *NodeConfig) Save() error {
return err
}
glog.V(logger.Info).Infof("config file saved: %v", configFilePath)
log.Info(fmt.Sprintf("config file saved: %v", configFilePath))
return nil
}

View file

@ -1,12 +1,14 @@
package params_test
import (
"encoding/json"
"io/ioutil"
"os"
"path/filepath"
"strings"
"testing"
"github.com/ethereum/go-ethereum/core"
gethparams "github.com/ethereum/go-ethereum/params"
"github.com/status-im/status-go/geth"
"github.com/status-im/status-go/geth/params"
@ -190,7 +192,11 @@ var loadConfigTestCases = []struct {
t.Fatalf("unexpected error: %v", err)
}
chainConfig := nodeConfig.ChainConfig
genesis := new(core.Genesis)
if err := json.Unmarshal([]byte(nodeConfig.LightEthConfig.Genesis), genesis); err != nil {
t.Fatal(err)
}
chainConfig := genesis.Config
refChainConfig := gethparams.TestnetChainConfig
if chainConfig.HomesteadBlock.Cmp(refChainConfig.HomesteadBlock) != 0 {
@ -237,7 +243,11 @@ var loadConfigTestCases = []struct {
t.Fatalf("unexpected error: %v", err)
}
chainConfig := nodeConfig.ChainConfig
genesis := new(core.Genesis)
if err := json.Unmarshal([]byte(nodeConfig.LightEthConfig.Genesis), genesis); err != nil {
t.Fatal(err)
}
chainConfig := genesis.Config
if chainConfig.HomesteadBlock.Cmp(gethparams.MainNetHomesteadBlock) != 0 {
t.Fatal("invalid chainConfig.HomesteadBlock")
}
@ -272,10 +282,7 @@ var loadConfigTestCases = []struct {
"Name": "TestStatusNode",
"WSPort": 8546,
"IPCEnabled": true,
"WSEnabled": false,
"ChainConfig": {
"ChainId": 311
}
"WSEnabled": false
}`,
func(t *testing.T, dataDir string, nodeConfig *params.NodeConfig, err error) {
//nodeConfig.LightEthConfig.Genesis = nodeConfig.LightEthConfig.Genesis[:125]
@ -284,16 +291,10 @@ var loadConfigTestCases = []struct {
t.Fatalf("unexpected error: %v", err)
}
networkId := 311
networkId := uint64(311)
if nodeConfig.NetworkId != networkId {
t.Fatalf("unexpected NetworkId, expected: %v, got: %v", networkId, nodeConfig.NetworkId)
}
if nodeConfig.ChainId.Int64() != int64(networkId) {
t.Fatalf("unexpected ChainConfig.ChainId, expected: %v, got: %v", networkId, nodeConfig.ChainId)
}
},
},
}
@ -314,31 +315,36 @@ func TestLoadNodeConfig(t *testing.T) {
}
func TestConfigWriteRead(t *testing.T) {
tmpDir, err := ioutil.TempDir(os.TempDir(), "geth-config-tests")
if err != nil {
t.Fatal(err)
}
defer os.RemoveAll(tmpDir)
configReadWrite := func(networkId uint64, refFile string) {
tmpDir, err := ioutil.TempDir(os.TempDir(), "geth-config-tests")
if err != nil {
t.Fatal(err)
}
defer os.RemoveAll(tmpDir)
nodeConfig, err := params.NewNodeConfig(tmpDir, params.TestNetworkId)
if err != nil {
t.Fatalf("cannot create new config object: %v", err)
nodeConfig, err := params.NewNodeConfig(tmpDir, networkId)
if err != nil {
t.Fatalf("cannot create new config object: %v", err)
}
if err := nodeConfig.Save(); err != nil {
t.Fatalf("cannot persist configuration: %v", err)
}
loadedConfigData, err := ioutil.ReadFile(filepath.Join(nodeConfig.DataDir, "config.json"))
if err != nil {
t.Fatalf("cannot read configuration from disk: %v", err)
}
refConfigData := geth.LoadFromFile(refFile)
refConfigData = strings.Replace(refConfigData, "$TMPDIR", nodeConfig.DataDir, -1)
refConfigData = strings.Replace(refConfigData, "$VERSION", params.Version, -1)
if string(loadedConfigData) != refConfigData {
t.Fatalf("configuration mismatch,\nexpected: %v\ngot: %v", refConfigData, string(loadedConfigData))
}
}
if err := nodeConfig.Save(); err != nil {
t.Fatalf("cannot persist configuration: %v", err)
}
loadedConfigData, err := ioutil.ReadFile(filepath.Join(nodeConfig.DataDir, "config.json"))
if err != nil {
t.Fatalf("cannot read configuration from disk: %v", err)
}
refConfigData := geth.LoadFromFile("testdata/config.testnet.json")
refConfigData = strings.Replace(refConfigData, "$TMPDIR", nodeConfig.DataDir, -1)
refConfigData = strings.Replace(refConfigData, "$VERSION", params.Version, -1)
if string(loadedConfigData) != refConfigData {
t.Fatalf("configuration mismatch,\nexpected: %v\ngot: %v", refConfigData, string(loadedConfigData))
}
configReadWrite(params.TestNetworkId, "testdata/config.testnet.json")
configReadWrite(params.MainNetworkId, "testdata/config.mainnet.json")
}

View file

@ -1,11 +1,5 @@
package params
import (
"math/big"
"github.com/ethereum/go-ethereum/common"
)
const (
// ClientIdentifier is client identifier to advertise over the network
ClientIdentifier = "StatusIM"
@ -57,6 +51,9 @@ const (
// LogLevel defines the minimum log level to report
LogLevel = "INFO"
// LogToStderr defines whether logged info should also be output to os.Stderr
LogToStderr = true
// WhisperDataDir is directory where Whisper data is stored, relative to DataDir
WhisperDataDir = "wnode"
@ -69,17 +66,9 @@ const (
// WhisperTTL is time to live for messages, in seconds
WhisperTTL = 120
// MainNetworkId is id of the main network
MainNetworkId = 1
// TestNetworkId is id of a test network
TestNetworkId = 3
)
// Gas price settings
var (
GasPrice = new(big.Int).Mul(big.NewInt(20), common.Shannon) // Minimal gas price to accept for mining a transactions
GpoMinGasPrice = new(big.Int).Mul(big.NewInt(20), common.Shannon) // Minimum suggested gas price
GpoMaxGasPrice = new(big.Int).Mul(big.NewInt(500), common.Shannon) // Maximum suggested gas price
GpoFullBlockRatio = 80 // Full block threshold for gas price calculation (%)
GpobaseStepDown = 10 // Suggested gas price base step down ratio (1/1000)
GpobaseStepUp = 100 // Suggested gas price base step up ratio (1/1000)
GpobaseCorrectionFactor = 110 // Suggested gas price base correction factor (%)
)

View file

@ -1,145 +1,92 @@
package params
import (
"bufio"
"fmt"
"io"
"os"
"path/filepath"
"sync"
"github.com/ethereum/go-ethereum/logger"
"github.com/ethereum/go-ethereum/logger/glog"
"github.com/ethereum/go-ethereum/log"
)
// Logger is wrapper for custom logging
type Logger struct {
sync.Mutex
logFile *os.File
observer chan string
started chan struct{}
stopped chan struct{}
stopFlag bool
origHandler log.Handler
handler log.Handler
config *NodeConfig
}
var onceStartLogger sync.Once
var (
onceInitNodeLogger sync.Once
nodeLoggerInstance *Logger
)
// SetupLogger configs logger using parameters in config
func SetupLogger(config *NodeConfig) (nodeLogger *Logger, err error) {
func SetupLogger(config *NodeConfig) (*Logger, error) {
if !config.LogEnabled {
return nil, nil
}
nodeLogger = &Logger{
started: make(chan struct{}, 1),
stopped: make(chan struct{}, 1),
}
onceStartLogger.Do(func() {
err = nodeLogger.createAndStartLogger(config)
onceInitNodeLogger.Do(func() {
nodeLoggerInstance = &Logger{
config: config,
origHandler: log.Root().GetHandler(),
}
nodeLoggerInstance.handler = nodeLoggerInstance.makeLogHandler(log.LvlInfo)
})
return
if err := nodeLoggerInstance.Start(); err != nil {
return nil, err
}
return nodeLoggerInstance, nil
}
// SetV allows to dynamically change log level of messages being written
func (l *Logger) SetV(logLevel string) {
glog.SetV(parseLogLevel(logLevel))
log.Root().SetHandler(l.makeLogHandler(parseLogLevel(logLevel)))
}
// Stop marks logger as stopped, forcing to relinquish hold
// on os.Stderr and restore it back to the original
func (l *Logger) Stop() (stopped chan struct{}) {
l.Lock()
defer l.Unlock()
l.stopFlag = true
stopped = l.stopped
return
}
// Observe registers extra writer where logs should be written to.
// This method is used in unit tests, and should NOT be relied upon otherwise.
func (l *Logger) Observe(observer chan string) (started chan struct{}) {
l.observer = observer
started = l.started
return
}
// createAndStartLogger initializes and starts logger by replacing os.Stderr with custom writer.
// Custom writer intercepts all requests to os.Stderr, then forwards to multiple readers, which
// include log file and the original os.Stderr (so that logs output on screen as well)
func (l *Logger) createAndStartLogger(config *NodeConfig) error {
// customize glog
glog.CopyStandardLogTo("INFO")
glog.SetToStderr(true)
glog.SetV(parseLogLevel(config.LogLevel))
// create log file
logFile, err := os.OpenFile(filepath.Join(config.DataDir, config.LogFile), os.O_CREATE|os.O_APPEND|os.O_RDWR, 0666)
if err != nil {
return err
}
// inject reader to pipe all writes to Stderr
r, w, err := os.Pipe()
if err != nil {
return err
}
// replace Stderr
origStderr := os.Stderr
os.Stderr = w
scanner := bufio.NewScanner(r)
// configure writer, send to the original os.Stderr and log file
logWriter := io.MultiWriter(origStderr, logFile)
go func() {
defer func() { // restore original Stderr
os.Stderr = origStderr
logFile.Close()
close(l.stopped)
}()
// notify observer that it can start polling (unit test, normally)
close(l.started)
for scanner.Scan() {
fmt.Fprintln(logWriter, scanner.Text())
if l.observer != nil {
l.observer <- scanner.Text()
}
// allow to restore original os.Stderr if logger is stopped
if l.stopFlag {
return
}
}
if err := scanner.Err(); err != nil {
fmt.Fprintf(origStderr, "error reading logs: %v\n", err)
}
}()
// Start installs logger handler
func (l *Logger) Start() error {
log.Root().SetHandler(l.handler)
return nil
}
// parseLogLevel parses string and returns logger.* constant
func parseLogLevel(logLevel string) int {
switch logLevel {
case "ERROR":
return logger.Error
case "WARNING":
return logger.Warn
case "INFO":
return logger.Info
case "DEBUG":
return logger.Debug
case "DETAIL":
return logger.Detail
// Stop replaces our handler back to the original log handler
func (l *Logger) Stop() error {
log.Root().SetHandler(l.origHandler)
return nil
}
// makeLogHandler creates a log handler for a given level and node configuration
func (l *Logger) makeLogHandler(lvl log.Lvl) log.Handler {
var handler log.Handler
logFilePath := filepath.Join(l.config.DataDir, l.config.LogFile)
if l.config.LogToStderr {
handler = log.MultiHandler(
log.LvlFilterHandler(lvl, log.StreamHandler(os.Stderr, log.TerminalFormat(true))),
log.LvlFilterHandler(lvl, log.Must.FileHandler(logFilePath, log.LogfmtFormat())))
} else {
handler = log.LvlFilterHandler(lvl, log.Must.FileHandler(logFilePath, log.LogfmtFormat()))
}
return logger.Info
return handler
}
// parseLogLevel parses string and returns logger.* constant
func parseLogLevel(logLevel string) log.Lvl {
switch logLevel {
case "ERROR":
return log.LvlError
case "WARNING":
return log.LvlWarn
case "INFO":
return log.LvlInfo
case "DEBUG":
return log.LvlDebug
case "TRACE":
return log.LvlTrace
}
return log.LvlInfo
}

View file

@ -1,16 +1,13 @@
package params_test
import (
"fmt"
"io/ioutil"
"log"
"os"
"path/filepath"
"strings"
"testing"
"time"
"github.com/ethereum/go-ethereum/logger"
"github.com/ethereum/go-ethereum/logger/glog"
"github.com/ethereum/go-ethereum/log"
"github.com/status-im/status-go/geth/params"
)
@ -19,7 +16,7 @@ func TestLogger(t *testing.T) {
if err != nil {
t.Fatal(err)
}
defer os.RemoveAll(tmpDir)
//defer os.RemoveAll(tmpDir)
nodeConfig, err := params.NewNodeConfig(tmpDir, params.TestNetworkId)
if err != nil {
@ -34,6 +31,7 @@ func TestLogger(t *testing.T) {
}
nodeConfig.LogEnabled = true
nodeConfig.LogToStderr = false // just capture logs to file
nodeLogger, err = params.SetupLogger(nodeConfig)
if err != nil {
t.Fatal("cannot create logger object")
@ -42,104 +40,41 @@ func TestLogger(t *testing.T) {
t.Fatal("logger is empty (while logs are enabled)")
}
logReader := make(chan string, 100)
loggerStarted := nodeLogger.Observe(logReader)
<-loggerStarted // allow logger to setup itself
expectedLogTextInLogFile := "" // aggregate log contents accross all tests
validateLoggerObserverText := func(observer chan string, expectedLogText string) {
logText := ""
select {
case logText = <-observer:
expectedLogTextInLogFile += logText + "\n"
logText = logText[len(logText)-len(expectedLogText):] // as logs can be prepended with glog info
case <-time.After(3 * time.Second):
validateLogText := func(expectedLogText string) {
logFilePath := filepath.Join(nodeConfig.DataDir, nodeConfig.LogFile)
logBytes, err := ioutil.ReadFile(logFilePath)
if err != nil {
panic(err)
}
logText := string(logBytes)
logText = strings.Trim(logText, "\n")
logText = logText[len(logText)-len(expectedLogText):] // as logs can be prepended with log info
if logText != expectedLogText {
t.Fatalf("invalid log, expected: %#v, got: %#v", expectedLogText, logText)
if expectedLogText != logText {
t.Fatalf("invalid log, expected: [%s], got: [%s]", expectedLogText, string(logText))
} else {
t.Logf("log match found, expected: [%s], got: [%s]", expectedLogText, string(logText))
}
}
loggerTestCases := []struct {
name string
log func()
validate func()
}{
{
"log using standard log package",
func() {
log.Println("use standard log package")
},
func() {
validateLoggerObserverText(logReader, "use standard log package")
},
},
{
"log using standard glog package",
func() {
glog.V(logger.Info).Infoln("use glog package")
},
func() {
validateLoggerObserverText(logReader, "use glog package")
},
},
{
"log using os.Stderr (write directly to it)",
func() {
fmt.Fprintln(os.Stderr, "use os.Stderr package")
},
func() {
validateLoggerObserverText(logReader, "use os.Stderr package")
},
},
{
"log using DEBUG log level (with appropriate level set)",
func() {
nodeLogger.SetV("DEBUG")
glog.V(logger.Debug).Info("logged DEBUG log level message")
},
func() {
validateLoggerObserverText(logReader, "logged DEBUG log level message")
},
},
{
"log using DEBUG log level (with appropriate level NOT set)",
func() {
nodeLogger.SetV("INFO")
glog.V(logger.Info).Info("logged INFO log level message")
glog.V(logger.Debug).Info("logged DEBUG log level message")
},
func() {
validateLoggerObserverText(logReader, "logged INFO log level message")
},
},
}
// sample log message
log.Info("use log package")
validateLogText(`msg="use log package"`)
for _, testCase := range loggerTestCases {
t.Log("test: " + testCase.name)
testCase.log()
testCase.validate()
}
// log using DEBUG log level (with appropriate level set)
nodeLogger.SetV("DEBUG")
log.Info("logged DEBUG log level message")
validateLogText(`msg="logged DEBUG log level message"`)
logFileContents, err := ioutil.ReadFile(filepath.Join(tmpDir, nodeConfig.LogFile))
if err != nil {
t.Fatalf("cannot read logs file: %v", err)
}
if string(logFileContents) != expectedLogTextInLogFile {
t.Fatalf("wrong content of log file, expected:\n%v\ngot:\n%v", expectedLogTextInLogFile, string(logFileContents))
}
// log using DEBUG log level (with appropriate level set)
nodeLogger.SetV("INFO")
log.Info("logged INFO log level message")
validateLogText(`msg="logged INFO log level message"`)
log.Debug("logged DEBUG log level message")
validateLogText(`msg="logged INFO log level message"`) // debug level message is NOT logged
go func() {
for i := 0; i < 10; i++ {
glog.Infoln("logging message: ", i)
time.Sleep(1 * time.Millisecond)
}
}()
// stop logger and see if os.Stderr and gethlog continue functioning
nodeLogger.Stop()
// stop logger and see if os.Stderr and glog continue functioning
<-nodeLogger.Stop()
glog.Infoln("logging message: this message happens after custom logger has been stopped")
log.Info("logging message: this message happens after custom logger has been stopped")
}

File diff suppressed because one or more lines are too long

File diff suppressed because one or more lines are too long