perfSONAR User Q&A and Other Discussion

[Tao Zhang <>]

Thank Zachary,

The logstash service is running, however, from the log messages, there are some fatal errors there, "Unable to load opensearch plugin". Any suggestions?

[root@lat-sask1pfs1 init.d]# systemctl status logstash

● logstash.service - logstash

   Loaded: loaded (/etc/systemd/system/logstash.service; enabled; vendor preset: disabled)

   Active: active (running) since Thu 2023-04-27 12:49:07 CST; 15s ago

[2023-04-27T12:48:43,412][INFO ][logstash.runner          ] Log4j configuration path used is: /etc/logstash/log4j2.properties

[2023-04-27T12:48:43,420][INFO ][logstash.runner          ] Starting Logstash {"logstash.version"=>"7.17.9", "jruby.version"=>"jruby 9.2.20.1 (2.5.8) 2021-11-30 2a2962fbd1 OpenJDK 64-Bit Server VM 11.0.18+10 on 11.0.18+10 +indy +jit [linux-x86_64]"}

[2023-04-27T12:48:43,422][INFO ][logstash.runner          ] JVM bootstrap flags: [-Xms1g, -Xmx1g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djdk.io.File.enableADS=true, -Djruby.compile.invokedynamic=true, -Djruby.jit.threshold=0, -Djruby.regexp.interruptible=true, -XX:+HeapDumpOnOutOfMemoryError, -Djava.security.egd=file:/dev/urandom, -Dlog4j2.isThreadContextMapInheritable=true]

[2023-04-27T12:48:44,337][INFO ][logstash.config.source.local.configpathloader] No config files found in path {:path=>"/etc/logstash/conf.d/*.conf"}

[2023-04-27T12:48:44,347][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9601, :ssl_enabled=>false}

[2023-04-27T12:48:46,958][INFO ][org.reflections.Reflections] Reflections took 79 ms to scan 1 urls, producing 119 keys and 419 values

[2023-04-27T12:48:47,794][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_proxy_normalize.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:47,868][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_test_checksum.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:47,920][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_normalize_endpoints.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:47,932][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_iso8601_duration.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:48,029][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_histogram.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:48,037][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_histogram.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:48,055][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_iso8601_duration.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:48,077][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_iso8601_duration.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:48,100][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_iso8601_duration.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:48,106][INFO ][logstash.filters.ruby.script] Test run complete {:script_path=>"/usr/lib/perfsonar/logstash/ruby/pscheduler_trace.rb", :results=>{:passed=>0, :failed=>0, :errored=>0}}

[2023-04-27T12:48:48,215][ERROR][logstash.plugins.registry] Unable to load plugin. {:type=>"output", :name=>"opensearch"}

[2023-04-27T12:48:48,229][ERROR][logstash.agent           ] Failed to execute action {:action=">LogStash::PipelineAction::Create/pipeline_id:pscheduler," :exception=>"Java::JavaLang::IllegalStateException", :message=>"Unable to configure plugins: (PluginLoadingError) Couldn't find any output plugin named 'opensearch'. Are you sure this is correct? Trying to load the opensearch output plugin resulted in this error: Unable to load the requested plugin named opensearch of type output. The plugin is not installed.", :backtrace=>["org.logstash.config.ir.CompiledPipeline.<init>(CompiledPipeline.java:120)", "org.logstash.execution.JavaBasePipelineExt.initialize(JavaBasePipelineExt.java:86)", "org.logstash.execution.JavaBasePipelineExt$INVOKER$i$1$0$initialize.call(JavaBasePipelineExt$INVOKER$i$1$0$initialize.gen)", "org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:837)", "org.jruby.ir.runtime.IRRuntimeHelpers.instanceSuper(IRRuntimeHelpers.java:1169)", "org.jruby.ir.runtime.IRRuntimeHelpers.instanceSuperSplatArgs(IRRuntimeHelpers.java:1156)", "org.jruby.ir.targets.InstanceSuperInvokeSite.invoke(InstanceSuperInvokeSite.java:39)", "usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.RUBY$method$initialize$0(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:48)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:80)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:70)", "org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:333)", "org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:87)", "org.jruby.RubyClass.newInstance(RubyClass.java:939)", "org.jruby.RubyClass$INVOKER$i$newInstance.call(RubyClass$INVOKER$i$newInstance.gen)", "org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:207)", "usr.share.logstash.logstash_minus_core.lib.logstash.pipeline_action.create.RUBY$method$execute$0(/usr/share/logstash/logstash-core/lib/logstash/pipeline_action/create.rb:52)", "usr.share.logstash.logstash_minus_core.lib.logstash.pipeline_action.create.RUBY$method$execute$0$__VARARGS__(/usr/share/logstash/logstash-core/lib/logstash/pipeline_action/create.rb:50)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:80)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:70)", "org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:207)", "usr.share.logstash.logstash_minus_core.lib.logstash.agent.RUBY$block$converge_state$2(/usr/share/logstash/logstash-core/lib/logstash/agent.rb:392)", "org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:138)", "org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)", "org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:52)", "org.jruby.runtime.Block.call(Block.java:139)", "org.jruby.RubyProc.call(RubyProc.java:318)", "org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105)", "java.base/java.lang.Thread.run(Thread.java:829)"]}

[2023-04-27T12:48:48,237][ERROR][logstash.agent           ] An exception happened when converging configuration {:exception=>LogStash::Error, :message=>"Don't know how to handle `Java::JavaLang::IllegalStateException` for `PipelineAction::Create<pscheduler>`"}

[2023-04-27T12:48:48,247][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<LogStash::Error: Don't know how to handle `Java::JavaLang::IllegalStateException` for `PipelineAction::Create<pscheduler>`>, :backtrace=>["org/logstash/execution/ConvergeResultExt.java:135:in `create'", "org/logstash/execution/ConvergeResultExt.java:60:in `add'", "/usr/share/logstash/logstash-core/lib/logstash/agent.rb:405:in `block in converge_state'"]}

[2023-04-27T12:48:48,256][FATAL][org.logstash.Logstash    ] Logstash stopped processing because of an error: (SystemExit) exit

org.jruby.exceptions.SystemExit: (SystemExit) exit

---

From: Zachary Newell <>
Sent: Thursday, April 27, 2023 2:38 PM
To: Mark Feit <>; <>; Tao Zhang <>
Subject: Re: Perfsonar (automatically) upgraded to 5.0 but testing data not archived

 

---

External This email originated from outside the organization. Use caution when following links as they could open malicious web sites.

---

HTTP 503 from apache2 likely means your logstash service is down.

Check that it's running:

systemctl status logstash

Look for errors in the log file:
/var/log/logstash/logstash-plain.log

--

Zachary Newell

Research Computing Engineer

NSHE System Computing Services

---

From: <> on behalf of Tao Zhang <>
Sent: Thursday, April 27, 2023 11:30 AM
To: Mark Feit <>; <>
Subject: Re: [perfsonar-user] Perfsonar (automatically) upgraded to 5.0 but testing data not archived

 

⚠ External Email: 

Hi Mark,

The testing data is still not archived to LogStash and OpenSearch. Not sure which part went wrong.

Here is the configuration:

[root@lat-sask1pfs1 tzhang]# cat /etc/perfsonar/psconfig/archives.d/http_logstash.json

{

    "archiver": "http",

    "data": {

        "schema": 2,

        "_url": "https://{% scheduled_by_address %}/logstash",

        "op": "put",

        "_headers": {

            "x-ps-observer": "{% scheduled_by_address %}",

            "content-type": "application/json",

            "Authorization":"Basic cGVyZnNvbmPyOmZmZkt1dGptdzF3SGhqOU5walTT"

        }

    }

} 

The LogStash and OpenSearch services are up.

[root@lat-sask1pfs1 tzhang]# service opensearch.service status

Redirecting to /bin/systemctl status opensearch.service

● opensearch.service - OpenSearch

   Loaded: loaded (/usr/lib/systemd/system/opensearch.service; enabled; vendor preset: disabled)

   Active: active (running) since Fri 2023-04-21 10:42:18 CST; 6 days ago

[root@lat-sask1pfs1 tzhang]# service logstash status

Redirecting to /bin/systemctl status logstash.service

● logstash.service - logstash

   Loaded: loaded (/etc/systemd/system/logstash.service; enabled; vendor preset: disabled)

   Active: active (running) since Thu 2023-04-27 12:21:19 CST; 18s ago

[root@lat-sask1pfs1 tzhang]# cat /var/log/pscheduler/pscheduler.log

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <html><head>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <html><head>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <title>503 Service Unavailable</title>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <title>503 Service Unavailable</title>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  </head><body>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <h1>Service Unavailable</h1>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <p>The server is temporarily unable to service your

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  request due to maintenance downtime or capacity

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  </head><body>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <h1>Service Unavailable</h1>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  <p>The server is temporarily unable to service your

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  request due to maintenance downtime or capacity

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  problems. Please try again later.</p>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  </body></html>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  problems. Please try again later.</p>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  </body></html>

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  121232484: Gave up archiving https://lat-sask1pfs1.network.canarie.ca/pscheduler/tasks/10931a73-ce1b-4033-9070-7bc3eab1bbb3/runs/eea47b71-7ebf-46fc-b95c-c629edfdf7bb to http

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  121232484: Gave up archiving https://lat-sask1pfs1.network.canarie.ca/pscheduler/tasks/10931a73-ce1b-4033-9070-7bc3eab1bbb3/runs/eea47b71-7ebf-46fc-b95c-c629edfdf7bb to http

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  121232485: Failed to archive https://lat-sask1pfs1.network.canarie.ca/pscheduler/tasks/3720e1cc-da4b-417f-a8f3-9be209195cb7/runs/30ff8da1-8d6b-4d95-b0a1-7da37c21e0ab to http: Failed to put result: 503: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">

Apr 27 12:13:49 lat-sask1pfs1 journal: archiver WARNING  121232485: Failed to archive https://lat-sask1pfs1.network.canarie.ca/pscheduler/tasks/3720e1cc-da4b-417f-a8f3-9be209195cb7/runs/30ff8da1-8d6b-4d95-b0a1-7da37c21e0ab to http: Failed to put result: 503: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">

.....

Thanks,

Tao

---

From: Mark Feit <>
Sent: Friday, April 21, 2023 4:52 PM
To: Tao Zhang <>; <>
Subject: Re: Perfsonar (automatically) upgraded to 5.0 but testing data not archived

 

---

External This email originated from outside the organization. Use caution when following links as they could open malicious web sites.

---

Tao Zhang writes:

 

All our perfSONAR boxes have been upgraded to 5.0, however, the archive shows empty. 

…

I checked the pscheduler log. The log filled with something like this:

Apr 21 12:27:31 lat-sask1pfs1 journal: archiver WARNING  120686191: Failed to archive https://lat-sask1pfs1.network.canarie.ca/pscheduler/tasks/b4843fdf-6d63-4a72-a29e-770134ccf853/runs/b7ed7962-377d-4842-90da-952c3e3670ea to esmond: Archiver permanently abandoned registering test after 1 attempt(s): 405: Invalid JSON returned

…

Apr 21 12:27:34 lat-sask1pfs1 journal: archiver WARNING  <title>503 Service Unavailable</title>

 

5.0 replaced Esmond with LogStash and OpenSearch.  There is a backward-compatibility layer for Esmond, but it is read-only.  If your tasks are archiving to the local system, they will need to use the HTTP archiver and post it to LogStash instead.  These two sections of the documentation should get you there:

 

• https://docs.perfsonar.net/multi_ma_install.html#authenticating-measurement-hosts
• https://docs.perfsonar.net/multi_ma_install.html#configuring-measurement-hosts

 

 

Apr 21 12:27:30 lat-sask1pfs1 journal: runner ERROR      File "/usr/libexec/pscheduler/classes/tool/traceroute/run", line 239, in <module>

Apr 21 12:27:30 lat-sask1pfs1 journal: runner ERROR        run_timeout += send_wait * hops

Apr 21 12:27:30 lat-sask1pfs1 journal: runner ERROR    TypeError: unsupported operand type(s) for +=: 'datetime.timedelta' and 'str'

 

This is a bug in pScheduler that appears to have been introduced in the last release.  I’ve already corrected it and added it to the pipeline for the next bugfix release, which should happen sometime during the week of May 1.

 

Based on what I could pull out of the API on your system, these are the tasks that are failing:

 

2023-04-21T14:27:24-06:00 - 2023-04-21T14:30:32-06:00 (Failed)

trace --dest lat-gp-mn.nbren.ca --length 40 --probe-type udp --source lat-sask1pfs1.network.canarie.ca --source-node lat-sask1pfs1.network.canarie.ca --hops 30 --wait PT30S --sendwait PT5S (Run with tool 'traceroute')

https://lat-sask1pfs1.network.canarie.ca/pscheduler/tasks/1aa55201-d3dd-49b4-bda6-99524115462e/runs/0c7a63c4-70bc-4eeb-8181-dfcb4195d148

 

As a stopgap, removing the ‘sendwait’ option from your trace tasks won’t trip the faulty code.  Note that this will alter the character of the measurement.

 

--Mark

 

PUBLIC RECORDS NOTICE: In accordance with NRS Chapter 239, this email and responses, unless otherwise made confidential by law, may be subject to the Nevada Public Records laws and may be disclosed to the public upon request.