logging, upload, etc

This commit is contained in:
2025-08-19 12:44:15 +02:00
parent 0f9b423d2f
commit 47080e14db
12 changed files with 399 additions and 182 deletions

View File

@@ -14,7 +14,6 @@ import (
"git.blackforestbytes.com/BlackForestBytes/goext/timeext"
"github.com/fsnotify/fsnotify"
"mikescher.com/kpsync/assets"
"mikescher.com/kpsync/log"
)
func (app *Application) initSync() error {
@@ -27,8 +26,8 @@ func (app *Application) initSync() error {
app.dbFile = path.Join(app.config.WorkDir, path.Base(app.config.LocalFallback))
app.stateFile = path.Join(app.config.WorkDir, "kpsync.state")
if isKeepassRunning() {
log.LogError("keepassxc is already running!", nil)
if app.isKeepassRunning() {
app.LogError("keepassxc is already running!", nil)
return exerr.New(exerr.TypeInternal, "keepassxc is already running").Build()
}
@@ -39,20 +38,21 @@ func (app *Application) initSync() error {
if state != nil && fileExists(app.dbFile) {
localCS, err := app.calcLocalChecksum()
if err != nil {
log.LogError("Failed to calculate local database checksum", err)
app.LogError("Failed to calculate local database checksum", err)
} else if localCS == state.Checksum {
remoteETag, remoteLM, err := app.getRemoteETag()
if err != nil {
log.LogError("Failed to get remote ETag", err)
app.LogError("Failed to get remote ETag", err)
} else if remoteETag == state.ETag {
log.LogInfo(fmt.Sprintf("Found local database matching remote database - skip initial download"))
log.LogInfo(fmt.Sprintf("Checksum (cached) := %s", state.Checksum))
log.LogInfo(fmt.Sprintf("Checksum (local) := %s", localCS))
log.LogInfo(fmt.Sprintf("ETag (cached) := %s", state.ETag))
log.LogInfo(fmt.Sprintf("ETag (remote) := %s", remoteETag))
log.LogInfo(fmt.Sprintf("LastModified (cached) := %s", state.LastModified.Format(time.RFC3339)))
log.LogInfo(fmt.Sprintf("LastModified (remote) := %s", remoteLM.Format(time.RFC3339)))
app.LogInfo(fmt.Sprintf("Found local database matching remote database - skip initial download"))
app.LogDebug(fmt.Sprintf("Checksum (cached) := %s", state.Checksum))
app.LogDebug(fmt.Sprintf("Checksum (local) := %s", localCS))
app.LogDebug(fmt.Sprintf("ETag (cached) := %s", state.ETag))
app.LogDebug(fmt.Sprintf("ETag (remote) := %s", remoteETag))
app.LogDebug(fmt.Sprintf("LastModified (cached) := %s", state.LastModified.Format(time.RFC3339)))
app.LogDebug(fmt.Sprintf("LastModified (remote) := %s", remoteLM.Format(time.RFC3339)))
app.LogLine()
needsDownload = false
}
@@ -64,92 +64,97 @@ func (app *Application) initSync() error {
fin := app.setTrayState("Downloading database", assets.IconDownload)
defer fin()
log.LogInfo(fmt.Sprintf("Downloading remote database to %s", app.dbFile))
app.LogInfo(fmt.Sprintf("Downloading remote database to %s", app.dbFile))
etag, lm, sha, sz, err := app.downloadDatabase()
if err != nil {
log.LogError("Failed to download remote database", err)
app.LogError("Failed to download remote database", err)
return exerr.Wrap(err, "Failed to download remote database").Build()
}
log.LogInfo(fmt.Sprintf("Downloaded remote database to %s", app.dbFile))
log.LogInfo(fmt.Sprintf("Checksum := %s", sha))
log.LogInfo(fmt.Sprintf("ETag := %s", etag))
log.LogInfo(fmt.Sprintf("Size := %s", langext.FormatBytes(sz)))
log.LogInfo(fmt.Sprintf("LastModified := %s", lm.Format(time.RFC3339)))
app.LogInfo(fmt.Sprintf("Downloaded remote database to %s", app.dbFile))
app.LogInfo(fmt.Sprintf("Checksum := %s", sha))
app.LogInfo(fmt.Sprintf("ETag := %s", etag))
app.LogInfo(fmt.Sprintf("Size := %s (%d)", langext.FormatBytes(sz), sz))
app.LogInfo(fmt.Sprintf("LastModified := %s", lm.Format(time.RFC3339)))
err = app.saveState(etag, lm, sha, sz)
if err != nil {
log.LogError("Failed to save state", err)
app.LogError("Failed to save state", err)
return exerr.Wrap(err, "Failed to save state").Build()
}
app.LogLine()
return nil
}()
if err != nil {
return exerr.Wrap(err, "").Build()
}
} else {
log.LogInfo(fmt.Sprintf("Skip download - use existing local database %s", app.dbFile))
app.LogInfo(fmt.Sprintf("Skip download - use existing local database %s", app.dbFile))
app.LogLine()
}
return nil
}
func (app *Application) runKeepass() {
app.LogInfo("Starting keepassxc...")
cmd := exec.Command("keepassxc", app.dbFile)
go func() {
log.LogInfo("Starting keepassxc...")
cmd := exec.Command("keepassxc", app.dbFile)
go func() {
select {
case <-app.sigTermKeepassChan:
log.LogInfo("Received signal to terminate keepassxc")
if cmd != nil && cmd.Process != nil {
log.LogInfo(fmt.Sprintf("Terminating keepassxc %d", cmd.Process.Pid))
err := cmd.Process.Signal(syscall.SIGTERM)
if err != nil {
log.LogError("Failed to terminate keepassxc", err)
} else {
log.LogInfo("keepassxc terminated successfully")
}
select {
case <-app.sigTermKeepassChan:
app.LogInfo("Received signal to terminate keepassxc")
if cmd != nil && cmd.Process != nil {
app.LogInfo(fmt.Sprintf("Terminating keepassxc %d", cmd.Process.Pid))
err := cmd.Process.Signal(syscall.SIGTERM)
if err != nil {
app.LogError("Failed to terminate keepassxc", err)
} else {
log.LogInfo("No keepassxc process to terminate")
app.LogInfo("keepassxc terminated successfully")
}
} else {
app.LogInfo("No keepassxc process to terminate")
}
}()
err := cmd.Start()
if err != nil {
log.LogError("Failed to start keepassxc", err)
app.sigErrChan <- exerr.Wrap(err, "Failed to start keepassxc").Build()
return
}
}()
log.LogInfo(fmt.Sprintf("keepassxc started with PID %d", cmd.Process.Pid))
err := cmd.Start()
if err != nil {
app.LogError("Failed to start keepassxc", err)
app.sigErrChan <- exerr.Wrap(err, "Failed to start keepassxc").Build()
return
}
err = cmd.Wait()
app.LogInfo(fmt.Sprintf("keepassxc started with PID %d", cmd.Process.Pid))
app.LogLine()
exitErr := &exec.ExitError{}
if errors.As(err, &exitErr) {
err = cmd.Wait()
log.LogInfo(fmt.Sprintf("keepass exited with code %d", exitErr.ExitCode()))
app.sigStopChan <- true
return
exitErr := &exec.ExitError{}
if errors.As(err, &exitErr) {
}
if err != nil {
log.LogError("Failed to run keepassxc", err)
app.sigErrChan <- exerr.Wrap(err, "Failed to run keepassxc").Build()
return
}
log.LogInfo("keepassxc exited successfully")
app.LogInfo(fmt.Sprintf("keepass exited with code %d", exitErr.ExitCode()))
app.sigStopChan <- true
return
}()
}
if err != nil {
app.LogError("Failed to run keepassxc", err)
app.sigErrChan <- exerr.Wrap(err, "Failed to run keepassxc").Build()
return
}
app.LogInfo("keepassxc exited successfully")
app.LogLine()
app.sigStopChan <- true
return
return nil
}
func (app *Application) runSyncLoop() error {
@@ -167,45 +172,83 @@ func (app *Application) runSyncLoop() error {
for {
select {
case <-app.sigSyncLoopStopChan:
log.LogInfo("Stopping sync loop (received signal)")
app.LogInfo("Stopping sync loop (received signal)")
return nil
case event := <-watcher.Events:
log.LogInfo(fmt.Sprintf("inotify event: [%s] %s", event.Op.String(), event.Name))
app.LogDebug(fmt.Sprintf("Received inotify event: [%s] %s", event.Op.String(), event.Name))
if event.Has(fsnotify.Write) && event.Name == app.dbFile {
func() {
app.masterLock.Lock()
app.uploadRunning.Wait(false)
app.uploadRunning.Set(true)
app.masterLock.Unlock()
defer app.uploadRunning.Set(false)
log.LogInfo("Database file was modified")
log.LogInfo(fmt.Sprintf("Sleeping for %d seconds", app.config.Debounce))
time.Sleep(timeext.FromSeconds(app.config.Debounce))
state := app.readState()
localCS, err := app.calcLocalChecksum()
if err != nil {
log.LogError("Failed to calculate local database checksum", err)
return
}
if localCS == state.Checksum {
log.LogInfo("Local database still matches remote (via checksum) - no need to upload")
log.LogInfo(fmt.Sprintf("Checksum (remote/cached) := %s", state.Checksum))
log.LogInfo(fmt.Sprintf("Checksum (local) := %s", localCS))
return
}
//TODO upload with IfMatch
}()
if !event.Has(fsnotify.Write) {
app.LogDebug("Ignoring event - not a write event")
app.LogLine()
continue
}
if event.Name != app.dbFile {
app.LogDebug(fmt.Sprintf("Ignoring event - not the database file (%s)", app.dbFile))
app.LogLine()
continue
}
func() {
app.masterLock.Lock()
app.uploadRunning.Wait(false)
app.uploadRunning.Set(true)
app.masterLock.Unlock()
defer app.uploadRunning.Set(false)
app.LogInfo("Database file was modified")
app.LogInfo(fmt.Sprintf("Sleeping for %d seconds", app.config.Debounce))
time.Sleep(timeext.FromSeconds(app.config.Debounce))
state := app.readState()
localCS, err := app.calcLocalChecksum()
if err != nil {
app.LogError("Failed to calculate local database checksum", err)
app.showErrorNotification("Failed to calculate local database checksum")
return
}
if localCS == state.Checksum {
app.LogInfo("Local database still matches remote (via checksum) - no need to upload")
app.LogInfo(fmt.Sprintf("Checksum (remote/cached) := %s", state.Checksum))
app.LogInfo(fmt.Sprintf("Checksum (local) := %s", localCS))
return
}
etag, lm, sha, sz, err := app.uploadDatabase(langext.Ptr(state.ETag))
if errors.Is(err, ETagConflictError) {
//TODO - choice notification
} else if err != nil {
app.LogError("Failed to upload remote database", err)
app.showErrorNotification("Failed to upload remote database")
return
}
app.LogInfo(fmt.Sprintf("Uploaded database to remote"))
app.LogDebug(fmt.Sprintf("Checksum := %s", sha))
app.LogDebug(fmt.Sprintf("ETag := %s", etag))
app.LogDebug(fmt.Sprintf("Size := %s (%d)", langext.FormatBytes(sz), sz))
app.LogDebug(fmt.Sprintf("LastModified := %s", lm.Format(time.RFC3339)))
err = app.saveState(etag, lm, sha, sz)
if err != nil {
app.LogError("Failed to save state", err)
app.showErrorNotification("Failed to save state")
return
}
app.showSuccessNotification("Uploaded database successfully")
app.LogLine()
}()
case err := <-watcher.Errors:
log.LogError("Filewatcher reported an error", err)
app.LogError("Filewatcher reported an error", err)
}
}
}