Skip to Content.
Sympa Menu

perfsonar-user - Re: [perfsonar-user] OWAMP tests not scheduling reliably in mesh

Subject: perfSONAR User Q&A and Other Discussion

List archive

Re: [perfsonar-user] OWAMP tests not scheduling reliably in mesh


Chronological Thread 
  • From: Casey Russell <>
  • To: "" <>
  • Subject: Re: [perfsonar-user] OWAMP tests not scheduling reliably in mesh
  • Date: Fri, 13 Apr 2018 10:45:14 -0500
  • Ironport-phdr: 9a23:JKKmAxJZJnyMdq8J69mcpTZWNBhigK39O0sv0rFitYgeIvvxwZ3uMQTl6Ol3ixeRBMOHs6kC07KempujcFRI2YyGvnEGfc4EfD4+ouJSoTYdBtWYA1bwNv/gYn9yNs1DUFh44yPzahANS47xaFLIv3K98yMZFAnhOgppPOT1HZPZg9iq2+yo9JDffwtFiCChbb9uMR67sRjfus4KjIV4N60/0AHJonxGe+RXwWNnO1eelAvi68mz4ZBu7T1et+ou+MBcX6r6eb84TaFDAzQ9L281/szrugLdQgaJ+3ART38ZkhtMAwjC8RH6QpL8uTb0u+ZhxCWXO9D9QLYpUjqg8qhrUgflhyUJNzA5/m/ZidF+grxHrx+6vRNz35TZbZuJOPZifK7Qe84RS2pbXsZWUixMGp2xYJEUD+UfPedTspXzp0YVrRulGwasAOfvwSJPi3Dqx606zv8hERrY0wwkG9IDq3fUo8/zNKcIT++1yrPEzTPdYPNKwDrw7pXDfB4mofGJR71wcMzRxFErFwPEiFWQqpLqMC6U1uQLqWSU8+1gVee3h247pQBxoySvxtsyhYnTnI4a1lfE9SBhzIY2P9K4TlR7bsCiEJdKsSGVKZd2T8U/SG9roCY30qMKtJ+ncCUIzZknyR3SZOebf4WN7R/vSPqdLDl9iX15ZL6/iRO//E2+xuDyVsS51ktBoDBfndnWrH8N0gTe6siZRft5+UeswTOP2BrS6uFAOEw0krbbJ4I4zr8/iJYev0TOEjX5mEXxi6+WeUEk9fay5+v7ZbXmo4eQN45yig7gLqQjgtKzDOUkPgUMWmWb9+ex26b/8UD8T7hGkuE6n6fcvZ/GOcgbqKu0DgpL3ost6xuzFzKm384ZnXkDIlJFYhWHj43xNl7SOvD4EOy/g0+ynzdvw/DLJb7hDY/LLnjZjrjhe6xx60hCxwov1dxf/Y5bCqkdIPLvXU/8rMTYAQEjMwy62ObnD9N92ZkEWW6WH6+ZK73dsUWT6+IrIumMf5MVuC3jJ/Q/5v7ui2M5lkEHfamvw5QXdG60Eu54LEqEfHq/yusGRC0SsxAwV+vsgUfHTCVefV6zWb4x/Dc2FNjgAIveDMj5mLGb0jy8GJRMI31dB0qkEHH0ep+CVutWLi+eP5kyvCYDUO2KQpQsxFmUqRThxr5jZr7f4DADrp/n0PB27uvJmBd08zFoWZfOm1qRRn15yztbDwQ927py9BRw
Group,

     I'm still chasing this problem scheduling latency tests reliably in my mesh.  I'm going to come at it from a slightly different angle today.  On the idea that the log messages I included last time may have been leading us astray.  Let's simplify...

     I have two nodes in my larger mesh, PSU, and FHSU.  There should be a constant latency test (IPv4) running from PSU to FHSU.  It appears that each day at approx 4:20am and again at approx 10:12am pscheduler schedules this test.

[crussell@ps-psu-bw ~]$ grep latencybg /var/log/pscheduler/pscheduler.log | grep fhsu | grep "version 4"
Apr  8 04:20:30 ps-psu-bw runner INFO     15244212: With powstream: latencybg --data-ports 8760-9960 --dest ps-fhsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr  9 04:20:30 ps-psu-bw runner INFO     15273040: With powstream: latencybg --data-ports 8760-9960 --dest ps-fhsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr  9 10:14:02 ps-psu-bw runner INFO     15289470: With powstream: latencybg --data-ports 8760-9960 --dest ps-psu-lt.perfsonar.kanren.net --packet-padding 0 --flip --source ps-fhsu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 10 04:20:30 ps-psu-bw runner INFO     15312685: With powstream: latencybg --data-ports 8760-9960 --dest ps-fhsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 10 10:12:05 ps-psu-bw runner INFO     15324555: With powstream: latencybg --data-ports 8760-9960 --dest ps-psu-lt.perfsonar.kanren.net --packet-padding 0 --flip --source ps-fhsu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 11 04:20:30 ps-psu-bw runner INFO     15358604: With powstream: latencybg --data-ports 8760-9960 --dest ps-fhsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 11 10:12:05 ps-psu-bw runner INFO     15369873: With powstream: latencybg --data-ports 8760-9960 --dest ps-psu-lt.perfsonar.kanren.net --packet-padding 0 --flip --source ps-fhsu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 12 04:20:30 ps-psu-bw runner INFO     15406256: With powstream: latencybg --data-ports 8760-9960 --dest ps-fhsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 12 10:12:05 ps-psu-bw runner INFO     15418015: With powstream: latencybg --data-ports 8760-9960 --dest ps-psu-lt.perfsonar.kanren.net --packet-padding 0 --flip --source ps-fhsu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 10:12:05 ps-psu-bw runner INFO     15463862: With powstream: latencybg --data-ports 8760-9960 --dest ps-psu-lt.perfsonar.kanren.net --packet-padding 0 --flip --source ps-fhsu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000

However you'll notice this morning (Apr 13) the test didn't schedule at 4:20am.  Let's see what pscheduler was doing around that time.

[crussell@ps-psu-bw ~]$ grep 'Apr 13 04:20:30' /var/log/pscheduler/pscheduler.log
Apr 13 04:20:30 ps-psu-bw runner INFO     15452182: With powstream: latencybg --data-ports 8760-9960 --dest ps-esu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451312: With powstream: latencybg --data-ports 8760-9960 --dest ps-esu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451311: With powstream: latencybg --data-ports 8760-9960 --dest ps-bryant-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15452185: With powstream: latencybg --data-ports 8760-9960 --dest ps-washburn-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451309: With powstream: latencybg --data-ports 8760-9960 --dest ps-washburn-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15452178: With powstream: latencybg --data-ports 8760-9960 --dest ps-bryant-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451239: With powstream: latencybg --data-ports 8760-9960 --dest ps-wsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451310: With powstream: latencybg --data-ports 8760-9960 --dest ps-fhsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15406254: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406253: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406257: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406252: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406255: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405617: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406256: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406260: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405618: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405619: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405622: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner WARNING  15451239: Starting 0:00:00.502363 later than scheduled
Apr 13 04:20:30 ps-psu-bw runner WARNING  15451309: Starting 0:00:00.507794 later than scheduled
Apr 13 04:20:30 ps-psu-bw runner WARNING  15451310: Starting 0:00:00.515842 later than scheduled

It scheduled a number of other tests, it just quietly declined scheduling that one.  So let's see what the SSL_ERROR_LOG says.

[crussell@ps-psu-bw ~]$ sudo grep 'Apr 13 04:2' /var/log/httpd/ssl_error_log
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1003::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-lt.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1003::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-lt.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1003::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-lt.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1003::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-lt.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1003::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-lt.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'
[Fri Apr 13 04:20:39 2018] [warn] [client 2001:49d0:23c0:1008::2] incomplete redirection target of '/toolkit/' for URI '/' modified to 'https://ps-psu-bw.perfsonar.kanren.net/toolkit/'

Nothing at all in the first half of that minute.  How about the bulk messages getting dumped to /var/log/messages?  

[crussell@ps-psu-bw ~]$ sudo grep 'Apr 13 04:20:30' /var/log/messages
Apr 13 04:20:30 ps-psu-bw runner INFO     15452182: With powstream: latencybg --data-ports 8760-9960 --dest ps-esu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451312: With powstream: latencybg --data-ports 8760-9960 --dest ps-esu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451311: With powstream: latencybg --data-ports 8760-9960 --dest ps-bryant-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15452185: With powstream: latencybg --data-ports 8760-9960 --dest ps-washburn-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451309: With powstream: latencybg --data-ports 8760-9960 --dest ps-washburn-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15452178: With powstream: latencybg --data-ports 8760-9960 --dest ps-bryant-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 4 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451239: With powstream: latencybg --data-ports 8760-9960 --dest ps-wsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw runner INFO     15451310: With powstream: latencybg --data-ports 8760-9960 --dest ps-fhsu-lt.perfsonar.kanren.net --packet-padding 0 --source ps-psu-lt.perfsonar.kanren.net --ip-version 6 --packet-interval 0.01 --duration PT86400S --packet-count 6000
Apr 13 04:20:30 ps-psu-bw powstream[27861]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[27853]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[27851]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[28787]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[9442]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[27861]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[27859]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[27859]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[27857]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[27853]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[27851]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[27860]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[27860]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[27844]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[28787]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[9442]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[30298]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[30298]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw powstream[27857]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406254: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406253: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406257: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406252: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406255: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405617: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406256: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15406260: Run succeeded.
Apr 13 04:20:30 ps-psu-bw powstream[27844]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405618: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405619: Run succeeded.
Apr 13 04:20:30 ps-psu-bw runner INFO     15405622: Run succeeded.
Apr 13 04:20:30 ps-psu-bw powstream[27856]: _OWPWriteStopSessions: called in wrong state.
Apr 13 04:20:30 ps-psu-bw powstream[27856]: SIGTERM/SIGINT Caught: Exiting.
Apr 13 04:20:30 ps-psu-bw runner WARNING  15451239: Starting 0:00:00.502363 later than scheduled
Apr 13 04:20:30 ps-psu-bw runner WARNING  15451309: Starting 0:00:00.507794 later than scheduled
Apr 13 04:20:30 ps-psu-bw runner WARNING  15451310: Starting 0:00:00.515842 later than scheduled

Here we see again the tests that ARE getting scheduled, but I'm not seeing anything about the one that FAILED to schedule.  Does anyone have any thoughts on where I should look next?  Are the powstream errors here related?  should I be concerned about them?



Sincerely,
Casey Russell
Network Engineer
KanREN
phone785-856-9809
2029 Becker Drive, Suite 282
Lawrence, Kansas 66047
linkedin twitter twitter


On Thu, Mar 22, 2018 at 6:53 PM, Mark Feit <> wrote:

Casey Russell writes:

 

     We've got a large mesh config, and for some time now (months) the owamp tests have not been scheduling reliably.  What I mean by that is tonight when the mesh config agent runs on them, somewhere around 30-40% of the latency tests in the mesh will fail to schedule (one way).  The same test, in the other direction between those hosts will probably schedule fine.  24 hours later, when it runs again, most of those will re-schedule just fine, but a new 30-40% fail to schedule.  

…

2018/03/21 04:21:34 (22276) WARN> perfsonar_meshconfig_agent:430 main:: - Problem adding test throughput(ps-fhsu-bw.perfsonar.kanren.net->ps-ksu-bw.perfsonar.kanren.net), continuing with rest of config: 500 INTERNAL SERVER ERROR: Error while tasking ps-ksu-bw.perfsonar.kanren.net: Unable to post task to ps-ksu-bw.perfsonar.kanren.net: Task already exists.  All participants must be on separate systems.

 

2018/03/18 23:16:27 (30529) WARN> perfsonar_meshconfig_agent:430 main:: - Problem adding test throughput(ps-ku-bw.perfsonar.kanren.net->ps-bryant-bw.perfsonar.kanren.net), continuing with rest of config: 500 INTERNAL SERVER ERROR: Error while tasking ps-bryant-bw.perfsonar.kanren.net: Unable to post task to ps-bryant-bw.perfsonar.kanren.net: Task already exists.  All participants must be on separate systems.

 

That’s a known error, but not expected under these circumstances.  Let me think aloud for a minute:

 

Meshconfig submits the task to the first participant (“A”), which assigns it an identifier.  A then submits the task to the second participant (“B”) under the same identifier.  The usual case is that B doesn’t have a task with that identifier and everything goes to plan.  If the task already exists on B, it will be rejected by B and, in turn, A with the error you see.  There are two things that can cause this to happen:  One is tasks from different systems having the same identifier.  The identifiers are version 4 (random) UUIDs.  The other is when the task has parameters that put both participants on the same system (e.g., pscheduler task throughput --dest localhost).  That makes A and B the same machine, and when A tries to task itself (as if it were B), it complains that the task is a duplicate.

 

I suspect that the latter is what’s going on here, because happenstance collisions in a 128-bit space should be exceedingly rare.  To the best of my knowledge, we’re not seeing this anywhere else, even at sites running large meshes.  This could be a case of something really weird happening network- or DNS-wise, but it’s also possible that Meshconfig is doing something silly like trying to task the wrong system.  Andy’s our resident guru on that subject and us out until next week, but I may have a peek at the Meshconfig sources to see if I can spot anything obvious.

 

 

2018/03/21 04:21:35 (22276) WARN> perfsonar_meshconfig_agent:430 main:: - Problem adding test latencybg(ps-fhsu-lt.perfsonar.kanren.net->ps-esu-lt.perfsonar.kanren.net), continuing with rest of config: 500 Internal Server Error: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">

…

 

For this one, you’ll probably find an error with the same timestamp (plus or minus a bit) in the Apache logs.

 

Can I take it that you’re not having trouble with the tasks that do get scheduled?

 

--Mark

 



Archive powered by MHonArc 2.6.19.

Top of Page