Update logs

Author: Илья

src/Auth/IamAuth.php

@@ -13,7 +13,8 @@ abstract class IamAuth extends Auth
      */
     public function requestToken($request_data)
     {
-        $this->logger()->info('YDB: Obtaining new IAM token...');
+        $this->logger()->debug('YDB: Request new IAM token...');
+        $startTime = microtime(true);
 
         $curl = curl_init(Iam::IAM_TOKEN_API_URL);
 
@@ -33,6 +34,8 @@ public function requestToken($request_data)
 
         $status = curl_getinfo($curl, CURLINFO_HTTP_CODE);
 
+        $this->logger->debug("YDB: Received IAM response in ".((microtime(true)-$startTime)*1000)." miliseconds");
+
         if ($status === 200) {
             $token = json_decode($result);
 

src/Iam.php

@@ -96,7 +96,7 @@ public function token($force = false)
      */
     public function newToken()
     {
-        $this->logger()->info('YDB: Obtaining new IAM token...');
+        $this->logger()->debug('YDB: Obtaining new token...');
 
         $tokenInfo = $this->config('credentials')->getTokenInfo();
         $this->iam_token = $tokenInfo->getToken();
@@ -383,7 +383,7 @@ protected function loadTokenFromFile()
                 $this->iam_token = $token->iamToken;
                 $this->expires_at = $token->expiresAt;
                 $this->refresh_at = $token->refreshAt ?? time();
-                $this->logger()->info('YDB: Reused IAM token [...' . substr($this->iam_token, -6) . '].');
+                $this->logger()->debug('YDB: Reused token [...' . substr($this->iam_token, -6) . '].');
                 return $token->iamToken;
             }
         }

src/Retry/Retry.php

@@ -77,22 +77,26 @@ public function retry(Closure $closure, bool $idempotent)
         $startTime = microtime(true);
         $retryCount = 0;
         $lastException = null;
-        while (microtime(true) < $startTime + $this->timeoutMs / 1000) {
+        $deadline = is_null($this->timeoutMs) ? PHP_INT_MAX : $startTime + $this->timeoutMs / 1000;
+        $this->logger->debug("YDB: begin retry function. Deadline: $deadline");
+        do {
             $this->logger->debug("YDB: Run user function. Retry count: $retryCount. s: ".(microtime(true) - $startTime));
             try {
                 return $closure();
-            } catch (Exception $e) {
-                $this->logger->warning("YDB: Received exception: ".$e->getMessage());
+            } catch (\Exception $e) {
+                $this->logger->debug("YDB: Received exception: ".$e->getMessage());
+                $lastException = $e;
                 if (!$this->canRetry($e, $idempotent)){
-                    $lastException = $e;
                     break;
                 }
                 $retryCount++;
-                $lastException = $e;
                 $delay = $this->retryDelay($retryCount, $this->backoffType(get_class($e)))*1000;
+                $this->logger->debug("YDB: Sleep $delay microseconds before retry");
                 usleep($delay);
             }
-        }
+        } while (microtime(true) < $deadline);
+        $this->logger->error("YDB: Timeout retry function. ms: "
+            .((microtime(true)-$startTime)*1000). "Retry count: $retryCount");
         throw $lastException;
     }
 
@@ -111,7 +115,7 @@ protected function alwaysRetry(string $exception)
         return in_array($exception, self::$alwaysRetry);
     }
 
-    protected function canRetry(Exception $e, bool $idempotent)
+    protected function canRetry(\Exception $e, bool $idempotent)
     {
         return is_a($e, RetryableException::class) && ($this->alwaysRetry(get_class($e)) || $idempotent);
     }