feat: add logs for addressbook subscriptions (#6841)

monicahq · Sep 2, 2023 · 094916d · 094916d
1 parent 9ab75dc
commit 094916d
Show file tree

Hide file tree

Showing 29 changed files with 524 additions and 47 deletions.
diff --git a/app/Console/Kernel.php b/app/Console/Kernel.php
@@ -6,6 +6,7 @@
 use App\Domains\Contact\Dav\Jobs\CleanSyncToken;
 use App\Domains\Contact\DavClient\Jobs\UpdateAddressBooks;
 use App\Domains\Contact\ManageReminders\Jobs\ProcessScheduledContactReminders;
+use App\Logging\CleanLogs;
 use Illuminate\Console\Scheduling\Schedule;
 use Illuminate\Foundation\Console\Kernel as ConsoleKernel;
 use Illuminate\Support\Facades\App;
@@ -44,6 +45,7 @@ protected function schedule(Schedule $schedule)
         $this->scheduleJob($schedule, UpdateAddressBooks::class, 'hourly');
         $this->scheduleJob($schedule, ProcessScheduledContactReminders::class, 'minutes', 1);
         $this->scheduleJob($schedule, CleanSyncToken::class, 'daily');
+        $this->scheduleJob($schedule, CleanLogs::class, 'daily');
     }
 
     /**

diff --git a/app/Domains/Contact/Dav/Jobs/UpdateVCard.php b/app/Domains/Contact/Dav/Jobs/UpdateVCard.php
@@ -65,7 +65,7 @@ public function execute(array $data): void
             $newtag = $this->updateCard($this->data['uri'], $this->data['card']);
 
             if ($newtag !== null && ($etag = Arr::get($this->data, 'etag')) !== null && $newtag !== $etag) {
-                Log::warning(__CLASS__.' '.__FUNCTION__." wrong etag when updating contact. Expected [$etag], got [$newtag]", [
+                Log::channel('database')->warning(__CLASS__.' '.__FUNCTION__." wrong etag when updating contact. Expected [$etag], got [$newtag]", [
                     'contacturl' => $this->data['uri'],
                     'carddata' => $this->data['card'],
                 ]);
@@ -99,7 +99,7 @@ private function updateCard(string $uri, mixed $card): ?string
                 ]);
             }
         } catch (\Exception $e) {
-            Log::error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
+            Log::channel('database')->error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
                 'uri' => $uri,
                 'carddata' => $card,
                 $e,

diff --git a/app/Domains/Contact/Dav/Web/Backend/CardDAV/CardDAVBackend.php b/app/Domains/Contact/Dav/Web/Backend/CardDAV/CardDAVBackend.php
@@ -204,7 +204,7 @@ public function prepareCard(VCardResource $resource): array
                 'lastmodified' => $resource->updated_at->timestamp,
             ];
         } catch (\Exception $e) {
-            Log::error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
+            Log::channel('database')->error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
                 'carddata' => $carddata,
                 'id' => $resource->id,
                 $e,

diff --git a/app/Domains/Contact/DavClient/Jobs/DeleteLocalVCard.php b/app/Domains/Contact/DavClient/Jobs/DeleteLocalVCard.php
@@ -0,0 +1,54 @@
+<?php
+
+namespace App\Domains\Contact\DavClient\Jobs;
+
+use App\Domains\Contact\Dav\Web\Backend\CardDAV\CardDAVBackend;
+use App\Models\AddressBookSubscription;
+use Illuminate\Bus\Batchable;
+use Illuminate\Bus\Queueable;
+use Illuminate\Contracts\Queue\ShouldQueue;
+use Illuminate\Queue\InteractsWithQueue;
+use Illuminate\Queue\SerializesModels;
+use Illuminate\Support\Facades\Log;
+
+class DeleteLocalVCard implements ShouldQueue
+{
+    use Batchable, InteractsWithQueue, Queueable, SerializesModels;
+
+    /**
+     * Create a new job instance.
+     */
+    public function __construct(
+        private AddressBookSubscription $subscription,
+        private string $uri
+    ) {
+        $this->subscription = $subscription->withoutRelations();
+    }
+
+    /**
+     * Send Delete contact.
+     */
+    public function handle(): void
+    {
+        Log::shareContext([
+            'addressbook_subscription_id' => $this->subscription->id,
+        ]);
+
+        try {
+            $this->run();
+        } finally {
+            Log::flushSharedContext();
+        }
+    }
+
+    /**
+     * Run the job.
+     */
+    private function run(): void
+    {
+        Log::channel('database')->debug("Delete local card {$this->uri}");
+
+        $backend = app(CardDAVBackend::class)->withUser($this->subscription->user);
+        $backend->deleteCard($this->subscription->vault_id, $this->uri);
+    }
+}
diff --git a/app/Domains/Contact/DavClient/Jobs/DeleteMultipleVCard.php b/app/Domains/Contact/DavClient/Jobs/DeleteMultipleVCard.php
@@ -8,6 +8,7 @@
 use Illuminate\Contracts\Queue\ShouldQueue;
 use Illuminate\Queue\InteractsWithQueue;
 use Illuminate\Queue\SerializesModels;
+use Illuminate\Support\Facades\Log;
 
 class DeleteMultipleVCard implements ShouldQueue
 {
@@ -32,17 +33,35 @@ public function handle(): void
             return; // @codeCoverageIgnore
         }
 
+        Log::shareContext([
+            'addressbook_subscription_id' => $this->subscription->id,
+        ]);
+
+        try {
+            $this->run();
+        } finally {
+            Log::flushSharedContext();
+        }
+    }
+
+    /**
+     * Run the job.
+     */
+    private function run(): void
+    {
         $jobs = collect($this->hrefs)
-            ->map(fn (string $href): DeleteVCard => $this->deleteVCard($href));
+            ->map(fn (string $href): DeleteLocalVCard => $this->deleteVCard($href));
+
+        Log::channel('database')->info("Delete {$jobs->count()} card(s) from distant server...");
 
         $this->batch()->add($jobs);
     }
 
     /**
      * Delete the contact.
      */
-    private function deleteVCard(string $href): DeleteVCard
+    private function deleteVCard(string $href): DeleteLocalVCard
     {
-        return new DeleteVCard($this->subscription, $href);
+        return new DeleteLocalVCard($this->subscription, $href);
     }
 }
diff --git a/app/Domains/Contact/DavClient/Jobs/DeleteVCard.php b/app/Domains/Contact/DavClient/Jobs/DeleteVCard.php
@@ -8,6 +8,7 @@
 use Illuminate\Contracts\Queue\ShouldQueue;
 use Illuminate\Queue\InteractsWithQueue;
 use Illuminate\Queue\SerializesModels;
+use Illuminate\Support\Facades\Log;
 
 class DeleteVCard implements ShouldQueue
 {
@@ -28,6 +29,24 @@ public function __construct(
      */
     public function handle(): void
     {
+        Log::shareContext([
+            'addressbook_subscription_id' => $this->subscription->id,
+        ]);
+
+        try {
+            $this->run();
+        } finally {
+            Log::flushSharedContext();
+        }
+    }
+
+    /**
+     * Run the job.
+     */
+    private function run(): void
+    {
+        Log::channel('database')->debug("Delete card {$this->uri}");
+
         $this->subscription->getClient()
             ->request('DELETE', $this->uri);
     }

diff --git a/app/Domains/Contact/DavClient/Jobs/GetMultipleVCard.php b/app/Domains/Contact/DavClient/Jobs/GetMultipleVCard.php
@@ -10,6 +10,7 @@
 use Illuminate\Queue\InteractsWithQueue;
 use Illuminate\Queue\SerializesModels;
 use Illuminate\Support\Arr;
+use Illuminate\Support\Facades\Log;
 use Sabre\CardDAV\Plugin as CardDav;
 
 class GetMultipleVCard implements ShouldQueue
@@ -35,13 +36,31 @@ public function handle(): void
             return; // @codeCoverageIgnore
         }
 
+        Log::shareContext([
+            'addressbook_subscription_id' => $this->subscription->id,
+        ]);
+
+        try {
+            $this->run();
+        } finally {
+            Log::flushSharedContext();
+        }
+    }
+
+    /**
+     * Run the job.
+     */
+    private function run(): void
+    {
         $data = $this->addressbookMultiget();
 
         $jobs = collect($data)
             ->filter(fn (array $contact): bool => is_array($contact) && $contact['status'] === '200')
             ->map(fn (array $contact, string $href): ?UpdateVCard => $this->updateVCard($contact, $href))
             ->filter();
 
+        Log::channel('database')->info("Get {$jobs->count()} card(s) from distant server...");
+
         $this->batch()->add($jobs);
     }
 

diff --git a/app/Domains/Contact/DavClient/Jobs/GetVCard.php b/app/Domains/Contact/DavClient/Jobs/GetVCard.php
@@ -10,6 +10,7 @@
 use Illuminate\Contracts\Queue\ShouldQueue;
 use Illuminate\Queue\InteractsWithQueue;
 use Illuminate\Queue\SerializesModels;
+use Illuminate\Support\Facades\Log;
 
 class GetVCard implements ShouldQueue
 {
@@ -34,6 +35,24 @@ public function handle(): void
             return; // @codeCoverageIgnore
         }
 
+        Log::shareContext([
+            'addressbook_subscription_id' => $this->subscription->id,
+        ]);
+
+        try {
+            $this->run();
+        } finally {
+            Log::flushSharedContext();
+        }
+    }
+
+    /**
+     * Run the job.
+     */
+    private function run(): void
+    {
+        Log::channel('database')->debug("Get card {$this->contact->uri}");
+
         $response = $this->subscription->getClient()
             ->request('GET', $this->contact->uri);
 

diff --git a/app/Domains/Contact/DavClient/Jobs/PushVCard.php b/app/Domains/Contact/DavClient/Jobs/PushVCard.php
@@ -45,6 +45,22 @@ public function __construct(
      * Push VCard data to the distance server.
      */
     public function handle(): void
+    {
+        Log::shareContext([
+            'addressbook_subscription_id' => $this->subscription->id,
+        ]);
+
+        try {
+            $this->run();
+        } finally {
+            Log::flushSharedContext();
+        }
+    }
+
+    /**
+     * Run the job.
+     */
+    private function run(): void
     {
         $contact = Contact::where('vault_id', $this->subscription->vault_id)
             ->findOrFail($this->contactId);
@@ -64,6 +80,8 @@ public function handle(): void
     private function pushDistant(int $depth = 1): string
     {
         try {
+            Log::channel('database')->debug("Push card {$this->uri}");
+
             $response = $this->subscription->getClient()
                 ->request('PUT', $this->uri, $this->card, $this->headers());
 
@@ -75,7 +93,7 @@ private function pushDistant(int $depth = 1): string
 
                 return $this->pushDistant(--$depth);
             } else {
-                Log::error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
+                Log::channel('database')->error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
                     'body' => $e->response->body(),
                     $e,
                 ]);

diff --git a/app/Domains/Contact/DavClient/Jobs/SynchronizeAddressBooks.php b/app/Domains/Contact/DavClient/Jobs/SynchronizeAddressBooks.php
@@ -16,6 +16,13 @@ class SynchronizeAddressBooks implements ShouldQueue
 {
     use Dispatchable, InteractsWithQueue, Queueable, SerializesModels, Localizable;
 
+    /**
+     * The number of times the job may be attempted.
+     *
+     * @var int
+     */
+    public $tries = 1;
+
     /**
      * Create a new job instance.
      */
@@ -31,19 +38,29 @@ public function __construct(
      */
     public function handle(): void
     {
-        $this->withLocale($this->subscription->user->preferredLocale(), fn () => $this->synchronize());
+        try {
+            $logid = $this->subscription->current_logid ?? 0;
+            $this->subscription->current_logid = $logid + 1;
+            $this->subscription->save();
+
+            Log::shareContext([
+                'addressbook_subscription_id' => $this->subscription->id,
+            ]);
+
+            $this->withLocale($this->subscription->user->preferredLocale(), fn () => $this->synchronize());
+        } finally {
+            Log::flushSharedContext();
+        }
     }
 
     /**
      * Run synchronization.
      */
     private function synchronize(): void
     {
-        try {
-            Log::withContext([
-                'addressbook_subscription_id' => $this->subscription->id,
-            ]);
+        Log::channel('database')->info("Synchronize addressbook '{$this->subscription->vault->name}'");
 
+        try {
             $batchId = app(SynchronizeAddressBook::class)->execute([
                 'account_id' => $this->subscription->user->account_id,
                 'addressbook_subscription_id' => $this->subscription->id,
@@ -52,13 +69,11 @@ private function synchronize(): void
 
             $this->subscription->last_batch = $batchId;
         } catch (\Exception $e) {
-            Log::error(__CLASS__.' '.__FUNCTION__.':'.$e->getMessage(), [$e]);
+            Log::stack([config('logging.default'), 'database'])->error(__CLASS__.' '.__FUNCTION__.':'.$e->getMessage(), [$e]);
             $this->fail($e);
         } finally {
             $this->subscription->last_synchronized_at = now();
             $this->subscription->save();
-
-            Log::withoutContext();
         }
     }
 }
diff --git a/app/Domains/Contact/DavClient/Services/SynchronizeAddressBook.php b/app/Domains/Contact/DavClient/Services/SynchronizeAddressBook.php
@@ -48,7 +48,7 @@ private function synchronize(bool $force): ?string
                 ->withSubscription($this->subscription)
                 ->execute($force);
         } catch (ClientException $e) {
-            Log::error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
+            Log::channel('database')->error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [
                 'body' => $e->hasResponse() ? $e->getResponse()->getBody() : null,
                 $e,
             ]);

diff --git a/app/Domains/Contact/DavClient/Services/Utils/AddressBookGetter.php b/app/Domains/Contact/DavClient/Services/Utils/AddressBookGetter.php
@@ -25,7 +25,7 @@ public function execute(): ?array
         try {
             return $this->getAddressBookData();
         } catch (ClientException $e) {
-            Log::error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [$e]);
+            Log::channel('database')->error(__CLASS__.' '.__FUNCTION__.': '.$e->getMessage(), [$e]);
             throw $e;
         }
     }