PHRAS-3476_subdefs-corrupted

fix : q-message "writemeta/document" is now sent after all synchronous exiftools.
added lot of traces, to be removed asap

lib/Alchemy/Phrasea/Border/Checker/Sha256.php

@@ -34,6 +34,10 @@ class Sha256 extends AbstractChecker
      */
     public function check(EntityManager $em, File $file)
     {
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("\n%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into checker sha256")
+        ), FILE_APPEND | LOCK_EX);
+
         $excludedCollIds = [];
         if (!empty($this->compareIgnoreCollections)) {
             foreach ($this->compareIgnoreCollections as $collection) {
@@ -46,6 +50,10 @@ class Sha256 extends AbstractChecker
 
         $boolean = empty($file->getCollection()->get_databox()->getRecordRepository()->findBySha256WithExcludedCollIds($file->getSha256(), $excludedCollIds));
 
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("return from checker sha256")
+        ), FILE_APPEND | LOCK_EX);
+
         return new Response($boolean, $this);
     }
 

lib/Alchemy/Phrasea/Border/Checker/UUID.php

@@ -33,6 +33,10 @@ class UUID extends AbstractChecker
      */
     public function check(EntityManager $em, File $file)
     {
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("\n%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into checker uuid")
+        ), FILE_APPEND | LOCK_EX);
+
         $excludedCollIds = [];
         if (!empty($this->compareIgnoreCollections)) {
             foreach ($this->compareIgnoreCollections as $collection) {
@@ -43,7 +47,22 @@ class UUID extends AbstractChecker
             }
         }
 
-        $boolean = empty($file->getCollection()->get_databox()->getRecordRepository()->findByUuidWithExcludedCollIds($file->getUUID(), $excludedCollIds));
+        $uuid = $file->getUUID(false, false);
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("found uuid=%s", $uuid ?: 'null')
+        ), FILE_APPEND | LOCK_EX);
+
+        if($uuid === null) {
+            // no uuid in file so no need to search for a match
+            $boolean = true;
+        }
+        else {
+            $boolean = empty($file->getCollection()->get_databox()->getRecordRepository()->findByUuidWithExcludedCollIds($uuid, $excludedCollIds));
+        }
+
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("return from checker uuid")
+        ), FILE_APPEND | LOCK_EX);
 
         return new Response($boolean, $this);
     }

lib/Alchemy/Phrasea/Border/File.php

@@ -63,6 +63,10 @@ class File
      */
     public function __construct(Application $app, MediaInterface $media, \collection $collection, $originalName = null)
     {
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into construct")
+        ), FILE_APPEND | LOCK_EX);
+
         $this->app = $app;
         $this->media = $media;
         $this->collection = $collection;
@@ -83,17 +87,21 @@ class File
     /**
      * Checks for UUID in metadatas
      *
-     * @todo Check if a file exists with the same checksum
-     * @todo Check if an UUID is contained in the attributes, replace It if
-     *              necessary
-     *
      * @param  boolean $generate if true, if no uuid found, a valid one is generated
      * @param  boolean $write    if true, writes uuid in all available metadatas
-     * @return File
+     * @return string
      */
     public function getUUID($generate = false, $write = false)
     {
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into getuuid with generate=%s, write=%s ; this->uuid=%s", $generate?'true':'false', $write?'true':'false', $this->uuid ?:'null')
+        ), FILE_APPEND | LOCK_EX);
+
         if ($this->uuid && !$write) {
+            file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("return known uuid %s", $this->uuid)
+            ), FILE_APPEND | LOCK_EX);
+
             return $this->uuid;
         }
 
@@ -107,6 +115,10 @@ class File
         ];
 
         if (!$this->uuid) {
+            file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("getMetadatas to get uuid")
+            ), FILE_APPEND | LOCK_EX);
+
             $metadatas = $this->media->getMetadatas();
 
             $uuid = null;
@@ -119,6 +131,11 @@ class File
                     }
                     if (Uuid::isValid($candidate)) {
                         $uuid = $candidate;
+
+                        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                            sprintf("found uuid from %s ; %s", $meta, $uuid)
+                        ), FILE_APPEND | LOCK_EX);
+
                         break;
                     }
                 }
@@ -126,12 +143,19 @@ class File
 
             if (!$uuid && $generate) {
                 $uuid = Uuid::uuid4();
+                file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                    sprintf("generated uuid %s", $uuid)
+                ), FILE_APPEND | LOCK_EX);
             }
 
             $this->uuid = $uuid;
         }
 
         if ($write) {
+            file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("writing uuid %s", $this->uuid)
+            ), FILE_APPEND | LOCK_EX);
+
             $value = new MonoValue($this->uuid);
             $metadatas = new ExiftoolMetadataBag();
 
@@ -148,6 +172,10 @@ class File
             }
         }
 
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("return uuid %s", $this->uuid ?: 'null')
+        ), FILE_APPEND | LOCK_EX);
+
         return $this->uuid;
     }
 
@@ -186,10 +214,18 @@ class File
      */
     public function getSha256()
     {
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into getSha256")
+        ), FILE_APPEND | LOCK_EX);
+
         if (!$this->sha256) {
             $this->sha256 = $this->media->getHash('sha256');
         }
 
+        file_put_contents($GLOBALS['app']['root.path'].'/logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("return from getSha256")
+        ), FILE_APPEND | LOCK_EX);
+
         return $this->sha256;
     }
 

lib/Alchemy/Phrasea/Border/Manager.php

@@ -12,20 +12,20 @@
 namespace Alchemy\Phrasea\Border;
 
 use Alchemy\Phrasea\Application;
-use Alchemy\Phrasea\Border\Checker\CheckerInterface;
 use Alchemy\Phrasea\Border\Attribute\AttributeInterface;
-use Alchemy\Phrasea\Core\Event\Record\RecordEvents;
-use Alchemy\Phrasea\Core\Event\Record\SubdefinitionCreateEvent;
-use Alchemy\Phrasea\Exception\RuntimeException;
-use Alchemy\Phrasea\Metadata\Tag\TfArchivedate;
-use Alchemy\Phrasea\Metadata\Tag\TfQuarantine;
-use Alchemy\Phrasea\Metadata\Tag\TfBasename;
-use Alchemy\Phrasea\Metadata\Tag\TfFilename;
-use Alchemy\Phrasea\Metadata\Tag\TfRecordid;
 use Alchemy\Phrasea\Border\Attribute\Metadata as MetadataAttr;
 use Alchemy\Phrasea\Border\Attribute\MetaField as MetafieldAttr;
 use Alchemy\Phrasea\Border\Attribute\Status as StatusAttr;
 use Alchemy\Phrasea\Border\Attribute\Story as StoryAttr;
+use Alchemy\Phrasea\Border\Checker\CheckerInterface;
+use Alchemy\Phrasea\Core\Event\Record\RecordEvents;
+use Alchemy\Phrasea\Core\Event\Record\SubdefinitionCreateEvent;
+use Alchemy\Phrasea\Exception\RuntimeException;
+use Alchemy\Phrasea\Metadata\Tag\TfArchivedate;
+use Alchemy\Phrasea\Metadata\Tag\TfBasename;
+use Alchemy\Phrasea\Metadata\Tag\TfFilename;
+use Alchemy\Phrasea\Metadata\Tag\TfQuarantine;
+use Alchemy\Phrasea\Metadata\Tag\TfRecordid;
 use Alchemy\Phrasea\Model\Entities\LazaretAttribute;
 use Alchemy\Phrasea\Model\Entities\LazaretCheck;
 use Alchemy\Phrasea\Model\Entities\LazaretFile;
@@ -105,27 +105,57 @@ class Manager
      */
     public function process(LazaretSession $session, File $file, $callable = null, $forceBehavior = null, $nosubdef = false)
     {
+        file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into process")
+        ), FILE_APPEND | LOCK_EX);
+
         $visa = $this->getVisa($file);
 
-        // Generate UUID
+        // READ the uuid (possibly generates one) but DO NOT write (because we need the stripped file for sha compare ?)
+        file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("get uuid (generate, no write) from \"%s\"", $file->getFile()->getRealPath())
+        ), FILE_APPEND | LOCK_EX);
+
         $file->getUUID(true, false);
 
         if (($visa->isValid() || $forceBehavior === self::FORCE_RECORD) && $forceBehavior !== self::FORCE_LAZARET) {
 
             $this->addMediaAttributes($file);
 
+            // Write UUID
+            file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("get uuid (no generate, write) from \"%s\"", $file->getFile()->getRealPath())
+            ), FILE_APPEND | LOCK_EX);
+
+            $file->getUUID(false, true);
+
+            file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("creating record")
+            ), FILE_APPEND | LOCK_EX);
+
             $element = $this->createRecord($file, $nosubdef);
 
             $code = self::RECORD_CREATED;
         } else {
 
+            // Write UUID
+            file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("get uuid (no generate, write) from \"%s\"", $file->getFile()->getRealPath())
+            ), FILE_APPEND | LOCK_EX);
+
+            $file->getUUID(false, true);
+
             $element = $this->createLazaret($file, $visa, $session, $forceBehavior === self::FORCE_LAZARET);
 
             $code = self::LAZARET_CREATED;
         }
 
-        // Write UUID
+//        // Write UUID
-        $file->getUUID(false, true);
+//        file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+//            sprintf("get uuid (no generate, write) from \"%s\"", $file->getFile()->getRealPath())
+//        ), FILE_APPEND | LOCK_EX);
+//
+//        $file->getUUID(false, true);
 
         if (is_callable($callable)) {
             $callable($element, $visa, $code);
@@ -267,7 +297,17 @@ class Manager
      */
     protected function createRecord(File $file, $nosubdef=false)
     {
+        file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into createRecord")
+        ), FILE_APPEND | LOCK_EX);
+
         $element = \record_adapter::createFromFile($file, $this->app);
+
+        file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("created %s", $element->getRecordId())
+        ), FILE_APPEND | LOCK_EX);
+
+
         $date = new \DateTime();
 
         $file->addAttribute(
@@ -332,6 +372,10 @@ class Manager
             }
         }
 
+        file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("calling replaceMetadata")
+        ), FILE_APPEND | LOCK_EX);
+
         $this->app['phraseanet.metadata-setter']->replaceMetadata($newMetadata, $element);
 
         if(!$nosubdef) {

lib/Alchemy/Phrasea/Controller/Prod/UploadController.php

@@ -117,6 +117,10 @@ class UploadController extends Controller
      */
     public function upload(Request $request)
     {
+        file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into upload controller")
+        ), FILE_APPEND | LOCK_EX);
+
         $data = [
             'success' => false,
             'code'    => null,
@@ -194,12 +198,21 @@ class UploadController extends Controller
                 $renamedFilename = $file->getRealPath() . '.' . pathinfo($file->getClientOriginalName(), PATHINFO_EXTENSION);
             }
 
+            file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("rename \"%s\" to \"%s\"", $uploadedFilename, $renamedFilename)
+            ), FILE_APPEND | LOCK_EX);
+
             $this->getFilesystem()->rename($uploadedFilename, $renamedFilename);
 
             $originalName = $file->getClientOriginalName();
         }
 
         try {
+            file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("calling getMediaFromUri(\"%s\")", $renamedFilename)
+            ), FILE_APPEND | LOCK_EX);
+
+
             $media = $this->app->getMediaFromUri($renamedFilename);
             $collection = \collection::getByBaseId($this->app, $base_id);
 
@@ -228,7 +241,15 @@ class UploadController extends Controller
             $elementCreated = null;
 
             $callback = function ($element, Visa $visa) use (&$reasons, &$elementCreated) {
+                file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                    sprintf("into callback")
+                ), FILE_APPEND | LOCK_EX);
+
                 foreach ($visa->getResponses() as $response) {
+                    file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                        sprintf("visa returned %s", $response->isOk() ? 'ok' : 'not ok')
+                    ), FILE_APPEND | LOCK_EX);
+
                     if (!$response->isOk()) {
                         $reasons[] = $response->getMessage($this->app['translator']);
                     }
@@ -237,10 +258,23 @@ class UploadController extends Controller
                 $elementCreated = $element;
             };
 
+            file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("process")
+            ), FILE_APPEND | LOCK_EX);
+
             $code = $this->getBorderManager()->process( $lazaretSession, $packageFile, $callback, $forceBehavior);
 
+            file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("processed, returned elementCreated class \"%s\"", get_class($elementCreated))
+            ), FILE_APPEND | LOCK_EX);
+
             if($renamedFilename !== $uploadedFilename) {
                 $this->getFilesystem()->rename($renamedFilename, $uploadedFilename);
+
+                file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                    sprintf("renamed \"%s\" back to \"%s\"", $renamedFilename, $uploadedFilename)
+                ), FILE_APPEND | LOCK_EX);
+
             }
 
             if (!!$forceBehavior) {
@@ -248,10 +282,19 @@ class UploadController extends Controller
             }
 
             if ($elementCreated instanceof \record_adapter) {
+
+                file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                    sprintf("record %s created", $elementCreated->getRecordId())
+                ), FILE_APPEND | LOCK_EX);
+
                 $id = $elementCreated->getId();
                 $element = 'record';
                 $message = $this->app->trans('The record was successfully created');
 
+                file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                    sprintf("dispatch event RECORD_UPLOAD")
+                ), FILE_APPEND | LOCK_EX);
+
                 $this->dispatch(PhraseaEvents::RECORD_UPLOAD, new RecordEdit($elementCreated));
 
                 // try to create thumbnail from data URI
@@ -261,8 +304,17 @@ class UploadController extends Controller
 
                         $fileName = $this->getTemporaryFilesystem()->createTemporaryFile('base_64_thumb', null, "png");
                         file_put_contents($fileName, $dataUri->getData());
+
+                        file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                            sprintf("calling getMediaFromUri(\"%s\")", $fileName)
+                        ), FILE_APPEND | LOCK_EX);
+
                         $media = $this->app->getMediaFromUri($fileName);
 
+                        file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                            sprintf("getMediaFromUri(...) done")
+                        ), FILE_APPEND | LOCK_EX);
+
                         $this->getSubDefinitionSubstituer()->substituteSubdef($elementCreated, 'thumbnail', $media);
                         $this->getDataboxLogger($elementCreated->getDatabox())
                             ->log($elementCreated, \Session_Logger::EVENT_SUBSTITUTE, 'thumbnail', '');
@@ -275,6 +327,10 @@ class UploadController extends Controller
                 }
             } else {
                 /** @var LazaretFile $elementCreated */
+                file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                    sprintf("dispatch event LAZARET_CREATE")
+                ), FILE_APPEND | LOCK_EX);
+
                 $this->dispatch(PhraseaEvents::LAZARET_CREATE, new LazaretEvent($elementCreated));
 
                 $id = $elementCreated->getId();
@@ -294,6 +350,10 @@ class UploadController extends Controller
             $data['message'] = $this->app->trans('Unable to add file to Phraseanet');
         }
 
+        file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("returns")
+        ), FILE_APPEND | LOCK_EX);
+
         $response = $this->app->json($data);
         // IE 7 and 8 does not correctly handle json response in file API
         // lets send them an html content-type header

lib/Alchemy/Phrasea/Metadata/PhraseanetMetadataSetter.php

@@ -42,6 +42,10 @@ class PhraseanetMetadataSetter
      */
     public function replaceMetadata($metadataCollection, \record_adapter $record)
     {
+        file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf(" =========== replaceMetadata for %s", $record->getRecordId())
+        ), FILE_APPEND | LOCK_EX);
+
         $metaStructure = $this->repository->find($record->getDataboxId())->get_meta_structure()->get_elements();
 
         $metadataPerField = $this->extractMetadataPerField($metaStructure, $metadataCollection);
@@ -91,6 +95,10 @@ class PhraseanetMetadataSetter
             $record->set_metadatas($metadataInRecordFormat, true);
 
             // order to write meta in file
+            file_put_contents(dirname(__FILE__).'/../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("dispatch RECORDS_WRITE_META for %s.%s", $record->getDataboxId(), $record->getRecordId())
+            ), FILE_APPEND | LOCK_EX);
+
             $this->dispatcher->dispatch(WorkerEvents::RECORDS_WRITE_META,
                 new RecordsWriteMetaEvent([$record->getRecordId()], $record->getDataboxId()));
         }

lib/Alchemy/Phrasea/Model/Manipulator/LazaretManipulator.php

@@ -224,6 +224,10 @@ class LazaretManipulator
                 $record->set_metadatas($fields);
 
                 // order to write meta in file
+                file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                    sprintf("dispatch RECORDS_WRITE_META for %s.%s", $record->getDataboxId(), $record->getRecordId())
+                ), FILE_APPEND | LOCK_EX);
+
                 $this->app['dispatcher']->dispatch(WorkerEvents::RECORDS_WRITE_META,
                     new RecordsWriteMetaEvent([$record->getRecordId()], $record->getDataboxId()));
             }

lib/Alchemy/Phrasea/Model/Repositories/WorkerRunningJobRepository.php

@@ -78,10 +78,9 @@ class WorkerRunningJobRepository extends EntityRepository
 
         $databoxId      = $payload['databoxId'];
         $recordId       = $payload['recordId'];
-        $subdefName     = $payload['subdefName'];
 
         file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
-            sprintf('canDoJob("%s") for %s.%s.%s ?', $jobType, $databoxId, $recordId, $subdefName)
+            sprintf('canDoJob("%s") for %s.%s ?', $jobType, $databoxId, $recordId)
         ), FILE_APPEND | LOCK_EX);
 
         // first protect sql by a critical section
@@ -116,7 +115,7 @@ class WorkerRunningJobRepository extends EntityRepository
                 }
                 else {
                     file_put_contents(dirname(__FILE__) . '/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
-                        sprintf("!!! FAILED select on %s.%s.%s because (%s)", $databoxId, $recordId, $subdefName, $stmt->errorCode())
+                        sprintf("!!! FAILED select on %s.%s because (%s)", $databoxId, $recordId, $stmt->errorCode())
                     ), FILE_APPEND | LOCK_EX);
                 }
                 $stmt->closeCursor();
@@ -127,7 +126,7 @@ class WorkerRunningJobRepository extends EntityRepository
                 }
                 else {
                     file_put_contents(dirname(__FILE__) . '/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
-                        sprintf("job %s (id=%s) already running on %s.%s.%s", $row['work'], $row['id'], $databoxId, $recordId, $subdefName)
+                        sprintf("job %s (id=%s) already running on %s.%s", $row['work'], $row['id'], $databoxId, $recordId)
                     ), FILE_APPEND | LOCK_EX);
                 }
 
@@ -137,13 +136,13 @@ class WorkerRunningJobRepository extends EntityRepository
                 $cnx->rollBack();
 
                 file_put_contents(dirname(__FILE__) . '/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
-                    sprintf("!!! FAILED in transaction to select/create on %s.%s.%s because (%s)", $databoxId, $recordId, $subdefName, $e->getMessage())
+                    sprintf("!!! FAILED in transaction to select/create on %s.%s because (%s)", $databoxId, $recordId, $e->getMessage())
                 ), FILE_APPEND | LOCK_EX);
             }
         }
         else {
             file_put_contents(dirname(__FILE__) . '/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
-                sprintf("!!! FAILED to create transaction to select/create on %s.%s.%s", $databoxId, $recordId, $subdefName)
+                sprintf("!!! FAILED to create transaction to select/create on %s.%s", $databoxId, $recordId)
             ), FILE_APPEND | LOCK_EX);
         }
 

lib/Alchemy/Phrasea/WorkerManager/Subscriber/RecordSubscriber.php

@@ -152,6 +152,10 @@ class RecordSubscriber implements EventSubscriberInterface
         $databoxId = $event->getDataboxId();
         $recordIds = $event->getRecordIds();
 
+        file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("handle RECORDS_WRITE_META for %s.[%s]", $databoxId, join(',', $recordIds))
+        ), FILE_APPEND | LOCK_EX);
+
         foreach ($recordIds as $recordId) {
             $mediaSubdefRepository = $this->getMediaSubdefRepository($databoxId);
             $mediaSubdefs = $mediaSubdefRepository->findByRecordIdsAndNames([$recordId]);
@@ -173,6 +177,10 @@ class RecordSubscriber implements EventSubscriberInterface
                     ];
 
                     if ($subdef->is_physically_present()) {
+                        file_put_contents(dirname(__FILE__).'/../../../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                            sprintf("q-publish  WRITE_METADATAS_TYPE for %s.%s.%s", $databoxId, $recordId, $subdef->get_name())
+                        ), FILE_APPEND | LOCK_EX);
+
                         $this->messagePublisher->publishMessage($payload, MessagePublisher::WRITE_METADATAS_TYPE);
                     }
                     else {

lib/classes/record/adapter.php

@@ -1669,6 +1669,10 @@ class record_adapter implements RecordInterface, cache_cacheableInterface
      */
     public static function createFromFile(File $file, Application $app)
     {
+        file_put_contents(dirname(__FILE__).'/../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into createFromFile")
+        ), FILE_APPEND | LOCK_EX);
+
         $collection = $file->getCollection();
 
         $record = self::_create(
@@ -1684,6 +1688,10 @@ class record_adapter implements RecordInterface, cache_cacheableInterface
             $pathhd = $filesystem->generateDataboxDocumentBasePath($databox);
             $newname = $filesystem->generateDocumentFilename($record, $file->getFile());
 
+            file_put_contents(dirname(__FILE__).'/../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("copy \"%s\" to \"%s\"", $file->getFile()->getRealPath(), $pathhd . $newname)
+            ), FILE_APPEND | LOCK_EX);
+
             $filesystem->copy($file->getFile()->getRealPath(), $pathhd . $newname);
 
             $media = $app->getMediaFromUri($pathhd . $newname);
@@ -1727,6 +1735,10 @@ class record_adapter implements RecordInterface, cache_cacheableInterface
      */
     private static function _create(collection $collection, Application $app, File $file=null)
     {
+        file_put_contents(dirname(__FILE__).'/../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("into _create")
+        ), FILE_APPEND | LOCK_EX);
+
         $databox = $collection->get_databox();
 
         $sql = "INSERT INTO record"
@@ -1749,6 +1761,10 @@ class record_adapter implements RecordInterface, cache_cacheableInterface
 
         $record_id = $connection->lastInsertId();
 
+        file_put_contents(dirname(__FILE__).'/../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+            sprintf("sql record::inserted %s", $record_id)
+        ), FILE_APPEND | LOCK_EX);
+
         $record = new self($app, $databox->get_sbas_id(), $record_id);
 
         try {
@@ -1765,6 +1781,12 @@ class record_adapter implements RecordInterface, cache_cacheableInterface
                 ':final'     => $collection->get_coll_id(),
             ]);
             $stmt->closeCursor();
+
+            file_put_contents(dirname(__FILE__).'/../../../logs/trace.txt', sprintf("%s [%s] : %s (%s); %s\n", (date('Y-m-d\TH:i:s')), getmypid(), __FILE__, __LINE__,
+                sprintf("sql log_docs::inserted add %s", $record_id)
+            ), FILE_APPEND | LOCK_EX);
+
+
         }
         catch (\Exception $e) {
             $record = null;