Logging mutex fix (#205)

* speed up tx lock

* better logging

Co-authored-by: callebtc <93376500+callebtc@users.noreply.github.com>

internal/runtime/mutex/mutex.go

@@ -27,6 +27,7 @@ func checkSoftLock(s string) int {
 }
 
 // LockWithContext locks a mutex only if it hasn't been locked before in a context.
+// LockWithContext should be used to lock objects like faucets etc.
 // The context carries a uid that is unique the each request (message, button press, etc.).
 // If the uid has a lock already *for a certain object*, it increments the
 // nLocks in the mutexMap. If not, it locks the object. This is supposed to lock only if nLock == 0.
@@ -46,7 +47,8 @@ func LockWithContext(ctx context.Context, s string) {
 	Unlock(fmt.Sprintf("mutex-sync:%s:%s", s, uid))
 }
 
-// UnlockWithContext unlock a mutex only if it has been locked once within a context. If it has been locked more than once
+// UnlockWithContext unlock a mutex only if it has been locked once within a context.
+// If it has been locked more than once
 // it only decrements nLocks and skips the unlock of the mutex. This is supposed to unlock only for
 // nLocks == 1
 func UnlockWithContext(ctx context.Context, s string) {
@@ -64,29 +66,30 @@ func UnlockWithContext(ctx context.Context, s string) {
 	mutexMap.Remove(fmt.Sprintf("mutex-sync:%s:%s", s, uid))
 }
 
-// Lock locks a mutex in the mutexMap.
+// Lock locks a mutex in the mutexMap. If the mutex is already in the map, it locks the current call.
+// After it another call unlocks the mutex (and deletes it from the mutexMap) the mutex written again into the mutexMap.
+// If the mutex was not in the mutexMap before, a new mutext is created and locked and written into the mutexMap.
 func Lock(s string) {
 	log.Tracef("[Mutex] Attempt Lock %s", s)
 	if m, ok := mutexMap.Get(s); ok {
-		log.Tracef("[Mutex] Attempt %s already in mutexMap", s)
 		m.(*sync.Mutex).Lock()
 		mutexMap.Set(s, m)
 	} else {
-		log.Tracef("[Mutex] Attempt %s not in mutexMap", s)
 		m := &sync.Mutex{}
 		m.Lock()
 		mutexMap.Set(s, m)
 	}
-	log.Tracef("[Mutex] Lock %s", s)
+	log.Tracef("[Mutex] Locked %s", s)
 }
 
 // Unlock unlocks a mutex in the mutexMap.
 func Unlock(s string) {
 	if m, ok := mutexMap.Get(s); ok {
-		log.Tracef("[Mutex] Unlock %s", s)
 		mutexMap.Remove(s)
 		m.(*sync.Mutex).Unlock()
+		log.Tracef("[Mutex] Unlocked %s", s)
 	} else {
+		// this should never happen. Mutex should have been in the mutexMap.
 		log.Errorf("[Mutex] ⚠⚠⚠️ Unlock %s not in mutexMap. Skip.", s)
 	}
 }

internal/telegram/inline_faucet.go

@@ -198,7 +198,7 @@ func (bot TipBot) faucetHandler(ctx context.Context, m *tb.Message) {
 func (bot TipBot) handleInlineFaucetQuery(ctx context.Context, q *tb.Query) {
 	inlineFaucet, err := bot.makeQueryFaucet(ctx, q, false)
 	if err != nil {
-		log.Errorf("[handleInlineFaucetQuery] %s", err)
+		log.Errorf("[handleInlineFaucetQuery] %s", err.Error())
 		return
 	}
 	urls := []string{