Skip to content

Commit

Permalink
add log messages
Browse files Browse the repository at this point in the history
Signed-off-by: Benjamin Wang <benjamin.ahrtr@gmail.com>
  • Loading branch information
ahrtr committed Dec 19, 2023
1 parent 008e27b commit e5b6320
Show file tree
Hide file tree
Showing 3 changed files with 163 additions and 24 deletions.
60 changes: 54 additions & 6 deletions bucket.go
Original file line number Diff line number Diff line change
Expand Up @@ -145,7 +145,16 @@ func (b *Bucket) openBucket(value []byte) *Bucket {
// CreateBucket creates a new bucket at the given key and returns the new bucket.
// Returns an error if the key already exists, if the bucket name is blank, or if the bucket name is too long.
// The bucket instance is only valid for the lifetime of the transaction.
func (b *Bucket) CreateBucket(key []byte) (*Bucket, error) {
func (b *Bucket) CreateBucket(key []byte) (rb *Bucket, err error) {
lg := b.tx.db.Logger()
lg.Debugf("Creating bucket %q", string(key))
defer func() {
if err != nil {
lg.Errorf("Creating bucket %q failed: %v", string(key), err)
} else {
lg.Debugf("Creating bucket %q successfully", string(key))
}
}()
if b.tx.db == nil {
return nil, errors.ErrTxClosed
} else if !b.tx.writable {
Expand Down Expand Up @@ -192,7 +201,17 @@ func (b *Bucket) CreateBucket(key []byte) (*Bucket, error) {
// CreateBucketIfNotExists creates a new bucket if it doesn't already exist and returns a reference to it.
// Returns an error if the bucket name is blank, or if the bucket name is too long.
// The bucket instance is only valid for the lifetime of the transaction.
func (b *Bucket) CreateBucketIfNotExists(key []byte) (*Bucket, error) {
func (b *Bucket) CreateBucketIfNotExists(key []byte) (rb *Bucket, err error) {
lg := b.tx.db.Logger()
lg.Debugf("Creating bucket if not exist %q", string(key))
defer func() {
if err != nil {
lg.Errorf("Creating bucket if not exist %q failed: %v", string(key), err)
} else {
lg.Debugf("Creating bucket if not exist %q successfully", string(key))
}
}()

if b.tx.db == nil {
return nil, errors.ErrTxClosed
} else if !b.tx.writable {
Expand Down Expand Up @@ -249,7 +268,17 @@ func (b *Bucket) CreateBucketIfNotExists(key []byte) (*Bucket, error) {

// DeleteBucket deletes a bucket at the given key.
// Returns an error if the bucket does not exist, or if the key represents a non-bucket value.
func (b *Bucket) DeleteBucket(key []byte) error {
func (b *Bucket) DeleteBucket(key []byte) (err error) {
lg := b.tx.db.Logger()
lg.Debugf("Deleting bucket %q", string(key))
defer func() {
if err != nil {
lg.Errorf("Deleting bucket %q failed: %v", string(key), err)
} else {
lg.Debugf("Deleting bucket %q successfully", string(key))
}
}()

if b.tx.db == nil {
return errors.ErrTxClosed
} else if !b.Writable() {
Expand All @@ -269,7 +298,7 @@ func (b *Bucket) DeleteBucket(key []byte) error {

// Recursively delete all child buckets.
child := b.Bucket(key)
err := child.ForEachBucket(func(k []byte) error {
err = child.ForEachBucket(func(k []byte) error {
if err := child.DeleteBucket(k); err != nil {
return fmt.Errorf("delete bucket: %s", err)
}
Expand Down Expand Up @@ -316,7 +345,16 @@ func (b *Bucket) Get(key []byte) []byte {
// If the key exist then its previous value will be overwritten.
// Supplied value must remain valid for the life of the transaction.
// Returns an error if the bucket was created from a read-only transaction, if the key is blank, if the key is too large, or if the value is too large.
func (b *Bucket) Put(key []byte, value []byte) error {
func (b *Bucket) Put(key []byte, value []byte) (err error) {
lg := b.tx.db.Logger()
lg.Debugf("Putting key %q", string(key))
defer func() {
if err != nil {
lg.Errorf("Putting key %q failed: %v", string(key), err)
} else {
lg.Debugf("Putting key %q successfully", string(key))
}
}()
if b.tx.db == nil {
return errors.ErrTxClosed
} else if !b.Writable() {
Expand Down Expand Up @@ -353,7 +391,17 @@ func (b *Bucket) Put(key []byte, value []byte) error {
// Delete removes a key from the bucket.
// If the key does not exist then nothing is done and a nil error is returned.
// Returns an error if the bucket was created from a read-only transaction.
func (b *Bucket) Delete(key []byte) error {
func (b *Bucket) Delete(key []byte) (err error) {
lg := b.tx.db.Logger()
lg.Debugf("Deleting key %q", string(key))
defer func() {
if err != nil {
lg.Errorf("Deleting key %q failed: %v", string(key), err)
} else {
lg.Debugf("Deleting key %q successfully", string(key))
}
}()

if b.tx.db == nil {
return errors.ErrTxClosed
} else if !b.Writable() {
Expand Down
89 changes: 78 additions & 11 deletions db.go
Original file line number Diff line number Diff line change
Expand Up @@ -116,8 +116,7 @@ type DB struct {
// Supported only on Unix via mlock/munlock syscalls.
Mlock bool

// Logger is the logger used for bbolt.
Logger Logger
logger Logger

path string
openFile func(string, int, os.FileMode) (*os.File, error)
Expand Down Expand Up @@ -176,10 +175,11 @@ func (db *DB) String() string {
// If the file does not exist then it will be created automatically with a given file mode.
// Passing in nil options will cause Bolt to open the database with the default options.
// Note: For read/write transactions, ensure the owner has write permission on the created/opened database file, e.g. 0600
func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
db := &DB{
func Open(path string, mode os.FileMode, options *Options) (db *DB, err error) {
db = &DB{
opened: true,
}

// Set default options if no options are provided.
if options == nil {
options = DefaultOptions
Expand All @@ -198,11 +198,21 @@ func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
db.AllocSize = common.DefaultAllocSize

if options.Logger == nil {
db.Logger = getDiscardLogger()
db.logger = getDiscardLogger()
} else {
db.Logger = options.Logger
db.logger = options.Logger
}

lg := db.Logger()
lg.Infof("Opening db file (%s) with mode %x and with options: %s", path, mode, options)
defer func() {
if err != nil {
lg.Errorf("Opening bbolt db (%s) failed: %v", path, err)
} else {
lg.Infof("Opening bbolt db (%s) successfully", path)
}
}()

flag := os.O_RDWR
if options.ReadOnly {
flag = os.O_RDONLY
Expand All @@ -219,9 +229,9 @@ func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
}

// Open data file and separate sync handler for metadata writes.
var err error
if db.file, err = db.openFile(path, flag, mode); err != nil {
_ = db.close()
lg.Errorf("failed to open db file (%s): %v", path, err)
return nil, err
}
db.path = db.file.Name()
Expand All @@ -235,6 +245,7 @@ func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
// hold a lock at the same time) otherwise (options.ReadOnly is set).
if err := flock(db, !db.readOnly, options.Timeout); err != nil {
_ = db.close()
lg.Errorf("failed to lock db file (%s), readonly: %t, error: %v", path, db.readOnly, err)
return nil, err
}

Expand All @@ -249,12 +260,14 @@ func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
// Initialize the database if it doesn't exist.
if info, err := db.file.Stat(); err != nil {
_ = db.close()
lg.Errorf("failed to get db file's stats (%s): %v", path, err)
return nil, err
} else if info.Size() == 0 {
// Initialize new files with meta pages.
if err := db.init(); err != nil {
// clean up file descriptor on initialization fail
_ = db.close()
lg.Errorf("failed to initialize db file (%s): %v", path, err)
return nil, err
}
} else {
Expand All @@ -263,7 +276,8 @@ func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
db.pageSize = pgSize
} else {
_ = db.close()
return nil, berrors.ErrInvalid
lg.Errorf("failed to get page size from db file (%s): %v", path, err)
return nil, err
}
}

Expand All @@ -277,6 +291,7 @@ func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
// Memory map the data file.
if err := db.mmap(options.InitialMmapSize); err != nil {
_ = db.close()
lg.Errorf("failed to map db file (%s): %v", path, err)
return nil, err
}

Expand All @@ -296,13 +311,13 @@ func Open(path string, mode os.FileMode, options *Options) (*DB, error) {
err = tx.Commit()
}
if err != nil {
lg.Errorf("starting readwrite transaction failed: %v", err)
_ = db.close()
return nil, err
}
}

// Mark the database as opened and return.
db.Logger.Debug("bbolt opened successfully")
return db, nil
}

Expand Down Expand Up @@ -435,9 +450,12 @@ func (db *DB) mmap(minsz int) (err error) {
db.mmaplock.Lock()
defer db.mmaplock.Unlock()

lg := db.Logger()

// Ensure the size is at least the minimum size.
fileSize, err := db.fileSize()
if err != nil {
lg.Errorf("getting file size failed: %w", err)
return err
}
var size = fileSize
Expand All @@ -446,6 +464,7 @@ func (db *DB) mmap(minsz int) (err error) {
}
size, err = db.mmapSize(size)
if err != nil {
lg.Errorf("getting map size failed: %w", err)
return err
}

Expand All @@ -470,6 +489,7 @@ func (db *DB) mmap(minsz int) (err error) {
// gofail: var mapError string
// return errors.New(mapError)
if err = mmap(db, size); err != nil {
lg.Errorf("[GOOS: %s, GOARCH: %s] mmap failed, size: %d, error: %v", runtime.GOOS, runtime.GOARCH, size, err)
return err
}

Expand Down Expand Up @@ -500,6 +520,7 @@ func (db *DB) mmap(minsz int) (err error) {
err0 := db.meta0.Validate()
err1 := db.meta1.Validate()
if err0 != nil && err1 != nil {
lg.Errorf("both meta pages are invalid, meta0: %v, meta1: %v", err0, err1)
return err0
}

Expand All @@ -522,6 +543,7 @@ func (db *DB) munmap() error {
// gofail: var unmapError string
// return errors.New(unmapError)
if err := munmap(db); err != nil {
db.Logger().Errorf("[GOOS: %s, GOARCH: %s] munmap failed, db.datasz: %d, error: %v", runtime.GOOS, runtime.GOARCH, db.datasz, err)
return fmt.Errorf("unmap error: " + err.Error())
}

Expand Down Expand Up @@ -569,6 +591,7 @@ func (db *DB) munlock(fileSize int) error {
// gofail: var munlockError string
// return errors.New(munlockError)
if err := munlock(db, fileSize); err != nil {
db.Logger().Errorf("[GOOS: %s, GOARCH: %s] munlock failed, fileSize: %d, db.datasz: %d, error: %v", runtime.GOOS, runtime.GOARCH, fileSize, db.datasz, err)
return fmt.Errorf("munlock error: " + err.Error())
}
return nil
Expand All @@ -578,6 +601,7 @@ func (db *DB) mlock(fileSize int) error {
// gofail: var mlockError string
// return errors.New(mlockError)
if err := mlock(db, fileSize); err != nil {
db.Logger().Errorf("[GOOS: %s, GOARCH: %s] mlock failed, fileSize: %d, db.datasz: %d, error: %v", runtime.GOOS, runtime.GOARCH, fileSize, db.datasz, err)
return fmt.Errorf("mlock error: " + err.Error())
}
return nil
Expand Down Expand Up @@ -628,9 +652,11 @@ func (db *DB) init() error {

// Write the buffer to our data file.
if _, err := db.ops.writeAt(buf, 0); err != nil {
db.Logger().Errorf("writeAt failed: %w", err)
return err
}
if err := fdatasync(db); err != nil {
db.Logger().Errorf("[GOOS: %s, GOARCH: %s] fdatasync failed: %w", runtime.GOOS, runtime.GOARCH, err)
return err
}

Expand Down Expand Up @@ -713,13 +739,29 @@ func (db *DB) close() error {
//
// IMPORTANT: You must close read-only transactions after you are finished or
// else the database will not reclaim old pages.
func (db *DB) Begin(writable bool) (*Tx, error) {
func (db *DB) Begin(writable bool) (t *Tx, err error) {
db.Logger().Debugf("Starting a new transaction [writable: %t]", writable)
defer func() {
if err != nil {
db.Logger().Errorf("Starting a new transaction [writable: %t] failed: %v", writable, err)
} else {
db.Logger().Debugf("Starting a new transaction [writable: %t] successfully", writable)
}
}()

if writable {
return db.beginRWTx()
}
return db.beginTx()
}

func (db *DB) Logger() Logger {
if db == nil || db.logger == nil {
return getDiscardLogger()
}
return db.logger
}

func (db *DB) beginTx() (*Tx, error) {
// Lock the meta pages while we initialize the transaction. We obtain
// the meta lock before the mmap lock because that's the order that the
Expand Down Expand Up @@ -1053,7 +1095,18 @@ func safelyCall(fn func(*Tx) error, tx *Tx) (err error) {
//
// This is not necessary under normal operation, however, if you use NoSync
// then it allows you to force the database file to sync against the disk.
func (db *DB) Sync() error { return fdatasync(db) }
func (db *DB) Sync() (err error) {
db.Logger().Debug("Syncing bbolt db (%s)", db.path)
defer func() {
if err != nil {
db.Logger().Errorf("[GOOS: %s, GOARCH: %s] syncing bbolt db (%s) failed: %v", runtime.GOOS, runtime.GOARCH, db.path, err)
} else {
db.Logger().Debugf("Syncing bbolt db (%s) successfully", db.path)
}
}()

return fdatasync(db)
}

// Stats retrieves ongoing performance stats for the database.
// This is only updated when a transaction closes.
Expand Down Expand Up @@ -1142,8 +1195,10 @@ func (db *DB) allocate(txid common.Txid, count int) (*common.Page, error) {
// grow grows the size of the database to the given sz.
func (db *DB) grow(sz int) error {
// Ignore if the new size is less than available file size.
lg := db.Logger()
fileSize, err := db.fileSize()
if err != nil {
lg.Errorf("getting file size failed: %w", err)
return err
}
if sz <= fileSize {
Expand All @@ -1165,10 +1220,12 @@ func (db *DB) grow(sz int) error {
// gofail: var resizeFileError string
// return errors.New(resizeFileError)
if err := db.file.Truncate(int64(sz)); err != nil {
lg.Errorf("[GOOS: %s, GOARCH: %s] truncating file failed, size: %d, db.datasz: %d, error: %v", runtime.GOOS, runtime.GOARCH, sz, db.datasz, err)
return fmt.Errorf("file resize error: %s", err)
}
}
if err := db.file.Sync(); err != nil {
lg.Errorf("[GOOS: %s, GOARCH: %s] syncing file failed, db.datasz: %d, error: %v", runtime.GOOS, runtime.GOARCH, db.datasz, err)
return fmt.Errorf("file sync error: %s", err)
}
if db.Mlock {
Expand Down Expand Up @@ -1283,6 +1340,16 @@ type Options struct {
Logger Logger
}

func (o *Options) String() string {
if o == nil {
return "{}"
}

return fmt.Sprintf("{Timeout: %s, NoGrowSync: %t, NoFreelistSync: %t, PreLoadFreelist: %t, FreelistType: %s, ReadOnly: %t, MmapFlags: %x, InitialMmapSize: %d, PageSize: %d, NoSync: %t, OpenFile: %p, Mlock: %t, Logger: %p}",
o.Timeout, o.NoGrowSync, o.NoFreelistSync, o.PreLoadFreelist, o.FreelistType, o.ReadOnly, o.MmapFlags, o.InitialMmapSize, o.PageSize, o.NoSync, o.OpenFile, o.Mlock, o.Logger)

}

// DefaultOptions represent the options used if nil options are passed into Open().
// No timeout is used which will cause Bolt to wait indefinitely for a lock.
var DefaultOptions = &Options{
Expand Down
Loading

0 comments on commit e5b6320

Please sign in to comment.