https://forge.in2p3.fr/
https://forge.in2p3.fr/favicon.ico?1678052116
2015-07-10T12:16:36Z
IN2P3-Forge
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26043
2015-07-10T12:16:36Z
Chambon Bernard
<ul></ul><p><strong>Running test 5k : ok</strong><br />Test with commit <a class="external" href="https://gitlab.in2p3.fr/treqs/treqs/commit/a7367690520a61d76b371030b7e43eb62cfb892c">https://gitlab.in2p3.fr/treqs/treqs/commit/a7367690520a61d76b371030b7e43eb62cfb892c</a></p>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26045
2015-07-10T12:23:27Z
Chambon Bernard
<ul><li><strong>File</strong> <a href="/attachments/9175">Test10k.pdf</a> <a class="icon-only icon-download" title="Download" href="/attachments/download/9175/Test10k.pdf">Test10k.pdf</a> added</li></ul><p><strong>Running test 10k : ok</strong><br />Test with commit <a class="external" href="https://gitlab.in2p3.fr/treqs/treqs/commit/5d26dc084b660ead6acbb0bffb7b4b1e2819776b">https://gitlab.in2p3.fr/treqs/treqs/commit/5d26dc084b660ead6acbb0bffb7b4b1e2819776b</a></p>
<p>10k successfully staged from 07/09/2015 17:20 to 07/10/2015 02:05 => all files in 8:30 hours</p>
<p>About Dispatching <br /> Query to HPSS : 88 s<br /> DB access duration : 1964 s<br /> Disp. duration : 5030 s (1 h and 23 mn)</p>
<p><em><strong>Caution :<br />Remember that total staging time is available if and only if on stager (was the case for this test) and one tape (was NOT the case for this tape)<br /></strong></em></p>
<p>For graphs, see Test10k.pdf above : [[<a class="external" href="https://forge.in2p3.fr/attachments/download/9175/Test10k.pdf">https://forge.in2p3.fr/attachments/download/9175/Test10k.pdf</a>]]</p>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26049
2015-07-10T15:57:08Z
Chambon Bernard
<ul></ul><p><strong>Running test 50k : ok</strong> (*)<br />Test with commit <a class="external" href="https://gitlab.in2p3.fr/treqs/treqs/commit/5d26dc084b660ead6acbb0bffb7b4b1e2819776b">https://gitlab.in2p3.fr/treqs/treqs/commit/5d26dc084b660ead6acbb0bffb7b4b1e2819776b</a></p>
<p>44352 "Successfully staged" from 07/10/2015 15:50:00 to 07/11/2015 05:10:00 => all files staged in 13 hours <br />2 'File is empty.'<br />3 'File is already on disk.'<br />5643 'File locked or HSM is currently unavailable'.</p>
<p>About Dispatching times<br /> Query to HPSS : 478 s<br /> DB access duration : 10,998 s<br /> Disp. duration : 28,498 s</p>
<p>For graphs, see Test50k.pdf and Test50k-FPOT.pdf above</p>
<p>(*)<br /><pre>
lundi 13/07/2015 bilan de Test50k, lancé le vendredi 10/07/2015
1/ Bilan rapide : 44357 "Successfully staged", 5643 "File locked or HSM is currently unavailable"
- donc tout semble ok
- mais trouve plusieurs cas d'exception et 4 relances de la JVM
(1 sur "No staging since a while" injustifie, 3 sur "Dispatcher Stopped" pour cause d'exception)
- enfin soucis avec la rotation des logs ?, il reste des fichiers .tmp
(les jtreqs.2015-07-xx.log etait bien en .gz, c'est moi qui les ai dezippe)
-rw-r--r-- 1 root root 156910820 Jul 11 00:00 jtreqs.2015-07-10.log
-rw-r--r-- 1 root root 16056221 Jul 12 00:00 jtreqs.2015-07-11.log
-rw-r--r-- 1 root root 5387443 Jul 13 00:00 jtreqs.2015-07-12.log
-rw-r--r-- 1 root root 2301027 Jul 13 10:15 jtreqs.log
-rw-r--r-- 1 root root 6386401 Jul 11 04:48 jtreqs.log813607467771380.tmp
-rw-r--r-- 1 root root 12339822 Jul 12 23:59 jtreqs.log900001870529060.tmp
-rw-r--r-- 1 root root 5273161 Jul 13 10:15 jtreqs.log986403522268819.tmp
Cela dit je constate un process java du 7 juillet !!!, est-ce un explication ?
root 29976 29974 0 Jul07 ? 00:36:32 java -d64 -server -DXss=128m ...
2/ Bilan detaillée
o Relance de l'appli sur "No staging since a while although there are submitted requests"
STATUS | wrapper | 2015/07/10 15:51:56 | Launching a JVM...
INFO | jvm 1 | 2015/07/10 15:51:56 | WrapperManager class initialized by thread: main Using classloader: sun.misc.Launcher$AppClassLoader@5bd44ae9
...
INFO | jvm 1 | 2015/07/10 15:58:24 | No staging since a while although there are submitted requests
STATUS | wrapper | 2015/07/10 15:58:55 | Launching a JVM...
INFO | jvm 2 | 2015/07/10 15:58:55 | WrapperManager class initialized by thread: main Using classloader: sun.misc.Launcher$AppClassLoader@3c818737
!!! Je vois pas pourquoi l'activator , puis le stager ne sont pas entre en action plus tot, a moins que fichier sur disque ou locked => pas de stager
!!! Solution revoir le parametrage de l'observer : garder OBSERVER_SAMPLING_PERIOD=10, mais passer OBSERVER_SAMPLES_MAX_COUNT=30 -> 90 (=> 15 mn au moins)
o 1ere relance de l'appli sur "Dispatcher Stopped"
INFO | jvm 2 | 2015/07/10 22:11:52 | Dispatcher Stopped
STATUS | wrapper | 2015/07/10 22:12:27 | Launching a JVM...
INFO | jvm 3 | 2015/07/10 22:12:28 | WrapperManager class initialized by thread: main Using classloader: sun.misc.Launcher$AppClassLoader@31eeeaed
Le Dispatcher a ete stoppe sur ceci
2015-07-10 22:11:52,316 [Dispatcher_req_211220] ERROR f.i.cc.storage.treqs.model.Queue - Unable to register file /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge0234.in2p3.fr.31487_000104Mb_0007.dat in Queue 'JS019200' with status: ENDED
2015-07-10 22:11:52,321 [Dispatcher_req_211220] ERROR f.i.c.s.t.c.dispatcher.Dispatcher - Stopping
fr.in2p3.cc.storage.treqs.control.dispatcher.DispatcherException: fr.in2p3.cc.storage.treqs.model.exception.InvalidStateException: Unable to register file /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge0234.in2p3.fr.31487_000104Mb_0007.dat in Queue 'JS019200' with status: ENDED
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:257) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.toStart(Dispatcher.java:1003) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.process.AbstractProcess.run(AbstractProcess.java:214) [treqs-java-1.0-SNAPSHOT.jar:na]
Caused by: fr.in2p3.cc.storage.treqs.model.exception.InvalidStateException: Unable to register file /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge0234.in2p3.fr.31487_000104Mb_0007.dat in Queue 'JS019200' with status: ENDED
at fr.in2p3.cc.storage.treqs.model.Queue.registerFileValidation(Queue.java:1005) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.model.Queue.registerFPOT(Queue.java:1044) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.controller.QueuesController.addFilePositionOnTape(QueuesController.java:201) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.submitRequest(Dispatcher.java:979) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.innerProcess(Dispatcher.java:616) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.process(Dispatcher.java:796) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:872) ~[treqs-java-1.0-SNAPSHOT.jar:na]
...
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:244) ~[treqs-java-1.0-SNAPSHOT.jar:na]
... 2 common frames omitted
2015-07-10 22:11:52,321 [Dispatcher_req_211220] WARN f.i.c.s.t.c.dispatcher.Dispatcher - Dispatcher Stopped
2015-07-10 22:11:52,321 [Dispatcher_req_211220] INFO f.i.c.s.t.c.process.AbstractProcess - Setting status to value STOPPED
o 2eme relance de l'appli sur "Dispatcher Stopped"
INFO | jvm 3 | 2015/07/11 04:48:56 | Dispatcher Stopped
STATUS | wrapper | 2015/07/11 04:49:32 | Launching a JVM...
INFO | jvm 4 | 2015/07/11 04:49:32 | WrapperManager class initialized by thread: main Using classloader: sun.misc.Launcher$AppClassLoader@31eeeaed
Le Dispatcher a ete stoppe sur ceci
2015-07-11 04:48:56,721 [Dispatcher] ERROR f.i.c.s.t.c.dispatcher.Dispatcher - Problem while cleaning references: fr.in2p3.cc.storage.treqs.persistence.helper.PersistenceHelperResourceAllocation cannot be cast to java.util.Collection. Stopping Dispatcher.
2015-07-11 04:48:56,745 [Dispatcher] ERROR f.i.c.s.t.c.dispatcher.Dispatcher - Stopping
fr.in2p3.cc.storage.treqs.control.dispatcher.DispatcherException: java.lang.ClassCastException: fr.in2p3.cc.storage.treqs.persistence.helper.PersistenceHelperResourceAllocation cannot be cast to java.util.Collection
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:239) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.toStart(Dispatcher.java:1003) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.process.AbstractProcess.run(AbstractProcess.java:214) [treqs-java-1.0-SNAPSHOT.jar:na]
Caused by: java.lang.ClassCastException: fr.in2p3.cc.storage.treqs.persistence.helper.PersistenceHelperResourceAllocation cannot be cast to java.util.Collection
at fr.in2p3.cc.storage.treqs.control.controller.ResourcesController.exist(ResourcesController.java:158) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.controller.UsersController.cleanup(UsersController.java:170) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.cleaningReferences(Dispatcher.java:346) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:234) ~[treqs-java-1.0-SNAPSHOT.jar:na]
... 2 common frames omitted
2015-07-11 04:48:56,745 [Dispatcher] WARN f.i.c.s.t.c.dispatcher.Dispatcher - Dispatcher Stopped
o 3eme relance de l'appli sur "Dispatcher Stopped"
INFO | jvm 4 | 2015/07/11 19:03:19 | Dispatcher Stopped
STATUS | wrapper | 2015/07/11 19:03:50 | Launching a JVM...
INFO | jvm 5 | 2015/07/11 19:03:50 | WrapperManager class initialized by thread: main Using classloader: sun.misc.Launcher$AppClassLoader@31eeeaed
Le Dispatcher a ete stoppe sur ceci
2015-07-11 19:03:19,005 [Dispatcher] ERROR f.i.c.s.t.c.dispatcher.Dispatcher - Problem while cleaning references: fr.in2p3.cc.storage.treqs.persistence.helper.PersistenceHelperResourceAllocation cannot be cast to java.util.Collection. Stopping Dispatcher.
2015-07-11 19:03:19,012 [Dispatcher] ERROR f.i.c.s.t.c.dispatcher.Dispatcher - Stopping
fr.in2p3.cc.storage.treqs.control.dispatcher.DispatcherException: java.lang.ClassCastException: fr.in2p3.cc.storage.treqs.persistence.helper.PersistenceHelperResourceAllocation cannot be cast to java.util.Collection
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:239) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.toStart(Dispatcher.java:1003) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.process.AbstractProcess.run(AbstractProcess.java:214) [treqs-java-1.0-SNAPSHOT.jar:na]
Caused by: java.lang.ClassCastException: fr.in2p3.cc.storage.treqs.persistence.helper.PersistenceHelperResourceAllocation cannot be cast to java.util.Collection
at fr.in2p3.cc.storage.treqs.control.controller.ResourcesController.exist(ResourcesController.java:158) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.controller.UsersController.cleanup(UsersController.java:170) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.cleaningReferences(Dispatcher.java:346) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:234) ~[treqs-java-1.0-SNAPSHOT.jar:na]
... 2 common frames omitted
3/ Actions
o Increase values of parameters used by Observer
o Try to limit scope of Exception from Dispatcher (to not restart dispatcher case previous Exception : ClassCastException, InvalidStateException)
o No change in Dispatcher loop, but keeping JVM restart on "Dispatcher Stopped" message
</pre></p>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26050
2015-07-10T15:59:00Z
Chambon Bernard
<ul><li><strong>Status</strong> changed from <i>New</i> to <i>In progress</i></li></ul>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26061
2015-07-13T11:46:36Z
Chambon Bernard
<ul><li><strong>File</strong> <a href="/attachments/9177">Test50k.pdf</a> <a class="icon-only icon-download" title="Download" href="/attachments/download/9177/Test50k.pdf">Test50k.pdf</a> added</li><li><strong>File</strong> <a href="/attachments/9178">Test50k-FPOT.pdf</a> <a class="icon-only icon-download" title="Download" href="/attachments/download/9178/Test50k-FPOT.pdf">Test50k-FPOT.pdf</a> added</li></ul>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26070
2015-07-15T09:16:41Z
Chambon Bernard
<ul></ul><p>Running test 50k : <strong>ok</strong> <br />Test with commit <a class="external" href="https://gitlab.in2p3.fr/treqs/treqs/commit/10f414f0a0c4b44a9a102ff50c97167501e1b108">https://gitlab.in2p3.fr/treqs/treqs/commit/10f414f0a0c4b44a9a102ff50c97167501e1b108</a></p>
<p>41049 "Successfully staged" from 07/13/2015 14:38:00 to 07/14/2015 00:27:00 => files staged in 10 hours <br />2 'File is empty.'<br />3 'File is already on disk.'<br />6942 'File locked or HSM is currently unavailable'. <br />NOT all requests inserted in DB (from trcp.pl) due to an unknow reason</p>
<p>Good news : <br /> NO exception in log file (cool !)<br /> Only one restart of JVM due to "No staging since a while although there are submitted requests"</p>
<p>About Dispatching times (for ~48k files)<br /> Query to HPSS : 420 s<br /> DB access duration : 9,373 s<br /> Disp. duration : 24,496 s</p>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26071
2015-07-15T09:18:06Z
Chambon Bernard
<ul><li><strong>Description</strong> updated (<a title="View differences" href="/journals/26071/diff?detail_id=26932">diff</a>)</li></ul>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=26353
2015-07-22T10:14:26Z
Chambon Bernard
<ul></ul><p>Running test 50k : <strong>ok</strong> <br />Test with commit <a class="external" href="https://gitlab.in2p3.fr/treqs/treqs/commit/f5cd26d9128cae3e48908387c9d4cdb676e3d0d0">https://gitlab.in2p3.fr/treqs/treqs/commit/f5cd26d9128cae3e48908387c9d4cdb676e3d0d0</a></p>
<p>4449x "Successfully staged" from 07/17/2015 13:55:00 to 07/17/2015 22:27:00 => files staged in 10 hours <br />2 'File is empty.'<br />11 'File is already on disk.'<br />5493 'File locked or HSM is currently unavailable'.</p>
<p>No more exception due to mysql (test done after setting innodb_lock_wait_timeout to 60s)<br />Two restarts of JVM due to "Dispatcher Stopped" due to ConcurrentModificationException (see below)</p>
<p>About Dispatching times (for 50k files)<br /> Query to HPSS : 483 s<br /> DB access duration : 10,410 s<br /> Disp. duration : 26,194 s</p>
<p>Found 'only' two exception like this one : <br />App is restarted on "Dispatcher Stopped" message => ok</p>
<pre>
2015-07-17 18:05:52,691 [Dispatcher_req_114181] INFO f.i.c.s.t.c.process.AbstractProcess - Setting status to value STOPPING
2015-07-17 18:05:52,691 [Dispatcher_req_114181] INFO f.i.c.s.t.c.process.AbstractProcess - Setting status to value STOPPING
2015-07-17 18:05:52,699 [Dispatcher_req_114181] ERROR f.i.c.s.t.c.dispatcher.Dispatcher - Stopping
fr.in2p3.cc.storage.treqs.control.dispatcher.DispatcherException: java.util.ConcurrentModificationException
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:257) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.toStart(Dispatcher.java:1003) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.process.AbstractProcess.run(AbstractProcess.java:214) [treqs-java-1.0-SNAPSHOT.jar:na]
Caused by: java.util.ConcurrentModificationException: null
at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:859) ~[na:1.7.0_79]
at java.util.ArrayList$Itr.next(ArrayList.java:831) ~[na:1.7.0_79]
at fr.in2p3.cc.storage.treqs.control.controller.StagersController.getActiveStagersForQueue(StagersController.java:223) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.controller.QueuesController.addFilePositionOnTape(QueuesController.java:193) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.submitRequest(Dispatcher.java:979) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.innerProcess(Dispatcher.java:616) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.process(Dispatcher.java:796) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:872) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.retrieveNewRequests(Dispatcher.java:881) ~[treqs-java-1.0-SNAPSHOT.jar:na]
at fr.in2p3.cc.storage.treqs.control.dispatcher.Dispatcher.action(Dispatcher.java:244) ~[treqs-java-1.0-SNAPSHOT.jar:na]
... 2 common frames omitted
2015-07-17 18:05:52,699 [Dispatcher_req_114181] WARN f.i.c.s.t.c.dispatcher.Dispatcher - Dispatcher Stopped
2015-07-17 18:05:52,699 [Dispatcher_req_114181] INFO f.i.c.s.t.c.process.AbstractProcess - Setting status to value STOPPED
2015-07-17 18:05:52,732 [Stager_QnJS023300_QId465_stagerNo_1] INFO f.i.c.s.t.p.mysql.dao.MySQLQueueDAO - Mysql access duration (MySQLQueueDAO.processUpdate method) took 38 ms (0 s)
2015-07-17 18:05:52,732 [Stager_QnJS023300_QId465_stagerNo_1] INFO f.i.c.s.t.p.mysql.dao.MySQLQueueDAO - Updated queue 465
2015-07-17 18:05:52,799 [Stager_QnJS019100_QId432_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - Staging duration for tape JS019100 at position 1497 and file /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge0337.in2p3.fr.6590_000102Mb_0094.dat of size 106954752 was 540 ms (0 s)
2015-07-17 18:05:52,839 [Stager_QnJS018000_QId437_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - Staging duration for tape JS018000 at position 622 and file /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge9997.in2p3.fr.28672_000103Mb_0063.dat of size 108003328 was 723 ms (0 s)
2015-07-17 18:05:52,857 [Stager_QnJS023300_QId465_stagerNo_1] INFO f.i.c.s.t.p.m.dao.MySQLReadingDAO - Mysql access duration (MySQLReadingDAO.processUpdate method) took 124 ms (0 s)
2015-07-17 18:05:52,857 [Stager_QnJS023300_QId465_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - File /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge0340.in2p3.fr.11992_000104Mb_0098.dat in tape JS023300 at, position { position: 681, offset: 0 }: Started.
2015-07-17 18:05:52,974 [Stager_QnJS019100_QId432_stagerNo_1] INFO f.i.c.s.t.p.m.dao.MySQLReadingDAO - Mysql access duration (MySQLReadingDAO.processUpdate method) took 117 ms (0 s)
2015-07-17 18:05:52,974 [Stager_QnJS019100_QId432_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - File /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge0337.in2p3.fr.6590_000102Mb_0094.dat successfully staged.
2015-07-17 18:05:52,983 [Stager_QnJS015500_QId462_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - Staging duration for tape JS015500 at position 521 and file /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge1159.in2p3.fr.15423_000004Mb_0001.dat of size 4194304 was 607 ms (0 s)
2015-07-17 18:05:53,099 [Stager_QnJS018000_QId437_stagerNo_1] INFO f.i.c.s.t.p.m.dao.MySQLReadingDAO - Mysql access duration (MySQLReadingDAO.processUpdate method) took 125 ms (0 s)
2015-07-17 18:05:53,099 [Stager_QnJS018000_QId437_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - File /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge9997.in2p3.fr.28672_000103Mb_0063.dat successfully staged.
2015-07-17 18:05:53,141 [Stager_QnJS019100_QId432_stagerNo_1] INFO f.i.c.s.t.p.mysql.dao.MySQLQueueDAO - Mysql access duration (MySQLQueueDAO.processUpdate method) took 42 ms (0 s)
2015-07-17 18:05:53,141 [Stager_QnJS019100_QId432_stagerNo_1] INFO f.i.c.s.t.p.mysql.dao.MySQLQueueDAO - Updated queue 432
2015-07-17 18:05:53,267 [Stager_QnJS015500_QId462_stagerNo_1] INFO f.i.c.s.t.p.m.dao.MySQLReadingDAO - Mysql access duration (MySQLReadingDAO.processUpdate method) took 125 ms (0 s)
2015-07-17 18:05:53,267 [Stager_QnJS015500_QId462_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - File /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge1159.in2p3.fr.15423_000004Mb_0001.dat successfully staged.
2015-07-17 18:05:53,309 [Stager_QnJS018000_QId437_stagerNo_1] INFO f.i.c.s.t.p.mysql.dao.MySQLQueueDAO - Mysql access duration (MySQLQueueDAO.processUpdate method) took 42 ms (0 s)
2015-07-17 18:05:53,309 [Stager_QnJS018000_QId437_stagerNo_1] INFO f.i.c.s.t.p.mysql.dao.MySQLQueueDAO - Updated queue 437
2015-07-17 18:05:53,434 [Stager_QnJS018000_QId437_stagerNo_1] INFO f.i.c.s.t.p.m.dao.MySQLReadingDAO - Mysql access duration (MySQLReadingDAO.processUpdate method) took 125 ms (0 s)
2015-07-17 18:05:53,434 [Stager_QnJS018000_QId437_stagerNo_1] INFO f.i.cc.storage.treqs.model.Reading - File /hpss/in2p3.fr/group/ccin2p3/treqs/run03/ccwsge0335.in2p3.fr.7125_000103Mb_0068.dat in tape JS018000 at, position { position: 623, offset: 0 }: Started.
</pre>
TReqS - Task #10331: Yet another test on dev instance (ccosvm0772)
https://forge.in2p3.fr/issues/10331?journal_id=27650
2015-09-21T15:28:42Z
Chambon Bernard
<ul><li><strong>Status</strong> changed from <i>In progress</i> to <i>Closed</i></li></ul>