deblan-mirror/dnote
1
0
Fork 0
mirror of https://github.com/dnote/dnote synced 2026-03-16 23:45:52 +01:00
Code Issues Projects Releases Packages Wiki Activity

Add debug logs

Browse source
This commit is contained in:
Sung 2025-10-26 09:54:55 -07:00
commit 6fec2455d8
6 changed files with 175 additions and 9 deletions
Download patch file Download diff file Expand all files Collapse all files

4
pkg/cli/client/client.go
View file

@ -176,7 +176,7 @@ func doReq(ctx context.DnoteCtx, method, path, body string, options *requestOpti
return nil, errors.Wrap(err, "getting request")
}
log.Debug("HTTP request: %+v\n", req)
log.Debug("HTTP %s %s\n", method, path)
hc := getHTTPClient(ctx, options)
res, err := hc.Do(req)
@ -184,7 +184,7 @@ func doReq(ctx context.DnoteCtx, method, path, body string, options *requestOpti
return res, errors.Wrap(err, "making http request")
}
log.Debug("HTTP response: %+v\n", res)
log.Debug("HTTP %d %s\n", res.StatusCode, res.Status)
if err = checkRespErr(res); err != nil {
return res, errors.Wrap(err, "server responded with an error")

155
pkg/cli/cmd/sync/sync.go
View file

@ -186,11 +186,68 @@ func getSyncFragments(ctx context.DnoteCtx, afterUSN int) ([]client.SyncFragment
}
}
log.Debug("received sync fragments: %+v\n", buf)
log.Debug("received sync fragments: %+v\n", redactSyncFragments(buf))
return buf, nil
}
// redactSyncFragments returns a deep copy of sync fragments with sensitive fields (note body, book label) removed for safe logging
func redactSyncFragments(fragments []client.SyncFragment) []client.SyncFragment {
redacted := make([]client.SyncFragment, len(fragments))
for i, frag := range fragments {
// Create new notes with redacted bodies
notes := make([]client.SyncFragNote, len(frag.Notes))
for j, note := range frag.Notes {
notes[j] = client.SyncFragNote{
UUID: note.UUID,
BookUUID: note.BookUUID,
USN: note.USN,
CreatedAt: note.CreatedAt,
UpdatedAt: note.UpdatedAt,
AddedOn: note.AddedOn,
EditedOn: note.EditedOn,
Body: func() string {
if note.Body != "" {
return "<redacted>"
}
return ""
}(),
Deleted: note.Deleted,
}
}
// Create new books with redacted labels
books := make([]client.SyncFragBook, len(frag.Books))
for j, book := range frag.Books {
books[j] = client.SyncFragBook{
UUID: book.UUID,
USN: book.USN,
CreatedAt: book.CreatedAt,
UpdatedAt: book.UpdatedAt,
AddedOn: book.AddedOn,
Label: func() string {
if book.Label != "" {
return "<redacted>"
}
return ""
}(),
Deleted: book.Deleted,
}
}
redacted[i] = client.SyncFragment{
FragMaxUSN: frag.FragMaxUSN,
UserMaxUSN: frag.UserMaxUSN,
CurrentTime: frag.CurrentTime,
Notes: notes,
Books: books,
ExpungedNotes: frag.ExpungedNotes,
ExpungedBooks: frag.ExpungedBooks,
}
}
return redacted
}
// resolveLabel resolves a book label conflict by repeatedly appending an increasing integer
// to the label until it finds a unique label. It returns the first non-conflicting label.
func resolveLabel(tx *database.DB, label string) (string, error) {
@ -546,6 +603,8 @@ func fullSync(ctx context.DnoteCtx, tx *database.DB) error {
log.Debug("performing a full sync\n")
log.Info("resolving delta.")
log.DebugNewline()
list, err := getSyncList(ctx, 0)
if err != nil {
return errors.Wrap(err, "getting sync list")
@ -553,6 +612,8 @@ func fullSync(ctx context.DnoteCtx, tx *database.DB) error {
fmt.Printf(" (total %d).", list.getLength())
log.DebugNewline()
// clean resources that are in erroneous states
if err := cleanLocalNotes(tx, &list); err != nil {
return errors.Wrap(err, "cleaning up local notes")
@ -598,6 +659,8 @@ func stepSync(ctx context.DnoteCtx, tx *database.DB, afterUSN int) error {
log.Info("resolving delta.")
log.DebugNewline()
list, err := getSyncList(ctx, afterUSN)
if err != nil {
return errors.Wrap(err, "getting sync list")
@ -757,9 +820,91 @@ func sendBooks(ctx context.DnoteCtx, tx *database.DB) (bool, error) {
return isBehind, nil
}
// findOrphanedNotes returns a list of all orphaned notes
func findOrphanedNotes(db *database.DB) (int, []struct{ noteUUID, bookUUID string }, error) {
var orphanCount int
err := db.QueryRow(`
SELECT COUNT(*) FROM notes n
WHERE NOT EXISTS (
SELECT 1 FROM books b
WHERE b.uuid = n.book_uuid
AND NOT b.deleted
)
`).Scan(&orphanCount)
if err != nil {
return 0, nil, err
}
if orphanCount == 0 {
return 0, nil, nil
}
rows, err := db.Query(`
SELECT n.uuid, n.book_uuid
FROM notes n
WHERE NOT EXISTS (
SELECT 1 FROM books b
WHERE b.uuid = n.book_uuid
AND NOT b.deleted
)
`)
if err != nil {
return orphanCount, nil, err
}
defer rows.Close()
var orphans []struct{ noteUUID, bookUUID string }
for rows.Next() {
var noteUUID, bookUUID string
if err := rows.Scan(&noteUUID, &bookUUID); err != nil {
continue
}
orphans = append(orphans, struct{ noteUUID, bookUUID string }{noteUUID, bookUUID})
}
return orphanCount, orphans, nil
}
func warnOrphanedNotes(tx *database.DB) {
count, orphans, err := findOrphanedNotes(tx)
if err != nil {
log.Debug("error checking orphaned notes: %v\n", err)
return
}
if count == 0 {
return
}
log.Debug("Found %d orphaned notes (book doesn't exist locally):\n", count)
for _, o := range orphans {
log.Debug("note %s (book %s)\n", o.noteUUID, o.bookUUID)
}
}
// checkPostSyncIntegrity checks for data integrity issues after sync and warns the user
func checkPostSyncIntegrity(db *database.DB) {
count, orphans, err := findOrphanedNotes(db)
if err != nil {
log.Debug("error checking orphaned notes: %v\n", err)
return
}
if count == 0 {
return
}
log.Warnf("Found %d orphaned notes (referencing non-existent or deleted books):\n", count)
for _, o := range orphans {
log.Plainf(" - note %s (missing book: %s)\n", o.noteUUID, o.bookUUID)
}
}
func sendNotes(ctx context.DnoteCtx, tx *database.DB) (bool, error) {
isBehind := false
warnOrphanedNotes(tx)
rows, err := tx.Query("SELECT uuid, book_uuid, body, deleted, usn, added_on FROM notes WHERE dirty")
if err != nil {
return isBehind, errors.Wrap(err, "getting syncable notes")
@ -773,7 +918,7 @@ func sendNotes(ctx context.DnoteCtx, tx *database.DB) (bool, error) {
return isBehind, errors.Wrap(err, "scanning a syncable note")
}
log.Debug("sending note %s\n", note.UUID)
log.Debug("sending note %s (book: %s)\n", note.UUID, note.BookUUID)
var respUSN int
@ -790,7 +935,7 @@ func sendNotes(ctx context.DnoteCtx, tx *database.DB) (bool, error) {
} else {
resp, err := client.CreateNote(ctx, note.BookUUID, note.Body)
if err != nil {
log.Debug("error creating note (will retry after stepSync): %v\n", err)
log.Debug("failed to create note %s (book: %s): %v\n", note.UUID, note.BookUUID, err)
isBehind = true
continue
}
@ -867,6 +1012,8 @@ func sendChanges(ctx context.DnoteCtx, tx *database.DB) (bool, error) {
fmt.Printf(" (total %d).", delta)
log.DebugNewline()
behind1, err := sendBooks(ctx, tx)
if err != nil {
return behind1, errors.Wrap(err, "sending books")
@ -1080,6 +1227,8 @@ func newRun(ctx context.DnoteCtx) infra.RunEFunc {
log.Success("success\n")
checkPostSyncIntegrity(ctx.DB)
if err := upgrade.Check(ctx); err != nil {
log.Error(errors.Wrap(err, "automatically checking updates").Error())
}

2
pkg/cli/infra/init.go
View file

@ -137,7 +137,7 @@ func Init(versionTag, apiEndpoint, dbPath string) (*context.DnoteCtx, error) {
return nil, errors.Wrap(err, "setting up the context")
}
log.Debug("Running with Dnote context: %+v\n", context.Redact(ctx))
log.Debug("context: %+v\n", context.Redact(ctx))
return &ctx, nil
}

19
pkg/cli/log/log.go
View file

@ -25,6 +25,11 @@ import (
"github.com/fatih/color"
)
const (
debugEnvName = "DNOTE_DEBUG"
debugEnvValue = "1"
)
var (
// ColorRed is a red foreground color
ColorRed = color.New(color.FgRed)
@ -105,9 +110,21 @@ func Askf(msg string, masked bool, v ...interface{}) {
fmt.Fprintf(color.Output, "%s%s %s: ", indent, symbol, fmt.Sprintf(msg, v...))
}
// isDebug returns true if debug mode is enabled
func isDebug() bool {
return os.Getenv(debugEnvName) == debugEnvValue
}
// Debug prints to the console if DNOTE_DEBUG is set
func Debug(msg string, v ...interface{}) {
if os.Getenv("DNOTE_DEBUG") == "1" {
if isDebug() {
fmt.Fprintf(color.Output, "%s %s", ColorGray.Sprint("DEBUG:"), fmt.Sprintf(msg, v...))
}
}
// DebugNewline prints a newline only in debug mode
func DebugNewline() {
if isDebug() {
fmt.Println()
}
}

2
pkg/cli/migrate/migrate.go
View file

@ -144,7 +144,7 @@ func Run(ctx context.DnoteCtx, migrations []migration, mode int) error {
return errors.Wrap(err, "getting the current schema")
}
log.Debug("current schema: %s %d of %d\n", consts.SystemSchema, schema, len(migrations))
log.Debug("%s: %d of %d\n", schemaKey, schema, len(migrations))
toRun := migrations[schema:]

2
pkg/server/controllers/notes.go
View file

@ -218,7 +218,7 @@ func (n *Notes) create(r *http.Request) (database.Note, error) {
var book database.Book
if err := n.app.DB.Where("uuid = ? AND user_id = ?", params.BookUUID, user.ID).First(&book).Error; err != nil {
return database.Note{}, errors.Wrap(err, "finding book")
return database.Note{}, errors.Wrapf(err, "finding book %s", params.BookUUID)
}
client := getClientType(r)