search

biemond / biemond-orautils

OraUitls Puppet module with works together with WLS or ORAWLS puppet module
Apache License 2.0
1 stars 13 forks source link

nodemanagerautostart doesn't work #26

Open danielmenezesbr opened 6 years ago

danielmenezesbr commented 6 years ago

steps to reproduce:

git clone https://github.com/biemond/biemond-orawls-vagrant-12.2.1-puppet4

cd biemond-orawls-vagrant-12.2.1-puppet4

vagrant up admin

vagrant ssh admin

sudo -i

ps aux | grep java

oracle 17940 0.6 2.3 2605604 55500 ? Sl 18:53 0:28 /usr/java/latest/bin/java -server -Xms32m -Xmx200m -Djdk.tls.ephemeralDHKeySize=2048 -Dcoherence.home=/opt/oracle/middleware12c/wlserver/../coherence -Dbea.home=/opt/oracle/middleware12c/wlserver/.. -Dweblogic.ssl.JSSEEnabled=true -Dweblogic.security.SSL.enableJSSE=true -Dweblogic.security.TrustKeyStore=CustomTrust -Dweblogic.security.CustomTrustKeyStoreFileName=/vagrant/truststore.jks -Dweblogic.security.CustomTrustKeystorePassPhrase=welcome -Daa=1 -Dbb=2 -Dweblogic.RootDirectory=/opt/oracle/wlsdomains/domains/Wls1221 -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.nodemanager.JavaHome=/usr/java/latest weblogic.NodeManager -v

oracle 18047 0.4 2.8 2531456 65980 ? Sl 18:53 0:23 /usr/java/latest/bin/java -server -Xms32m -Xmx200m -Djdk.tls.ephemeralDHKeySize=2048 -Dcoherence.home=/opt/oracle/middleware12c/wlserver/../coherence -Dbea.home=/opt/oracle/middleware12c/wlserver/.. -Dweblogic.ssl.JSSEEnabled=true -Dweblogic.security.SSL.enableJSSE=true -Dweblogic.RootDirectory=/opt/oracle/wlsdomains/domains/plain_Wls -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.nodemanager.JavaHome=/usr/java/latest weblogic.NodeManager -v

oracle 18546 5.9 14.7 3691940 347680 ? Sl 18:56 4:27 /usr/java/latest/bin/java -server -Xms256m -Xmx512m -cp /opt/oracle/middleware12c/wlserver/server/lib/weblogic-launcher.jar -Dlaunch.use.env.classpath=true -Dweblogic.Name=AdminServer -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.ProductionModeEnabled=true -Dweblogic.system.BootIdentityFile=/opt/oracle/wlsdomains/domains/plain_Wls/servers/AdminServer/security/boot.properties -Dweblogic.nodemanager.ServiceEnabled=true -Dweblogic.nmservice.RotationEnabled=true -XX:PermSize=256m -XX:MaxPermSize=512m -Xms1024m -Xmx1024m -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -javaagent:/opt/oracle/middleware12c/wlserver/server/lib/debugpatch-agent.jar -da -Dwls.home=/opt/oracle/middleware12c/wlserver/server -Dweblogic.home=/opt/oracle/middleware12c/wlserver/server weblogic.Server

oracle 31725 0.2 1.6 2847896 39488 ? Sl 19:24 0:06 /usr/java/latest/bin/java -Dderby.system.home=/opt/oracle/wlsdomains/domains/Wls1221/common/db -classpath /opt/oracle/middleware12c/wlserver/common/derby/lib/derby.jar:/opt/oracle/middleware12c/wlserver/common/derby/lib/derbynet.jar:/opt/oracle/middleware12c/wlserver/common/derby/lib/derbytools.jar:/opt/oracle/middleware12c/wlserver/common/derby/lib/derbyclient.jar org.apache.derby.drda.NetworkServerControl start

oracle 31726 7.6 34.1 3680164 802144 ? Sl 19:24 3:35 /usr/java/latest/bin/java -server -Xms256m -Xmx512m -cp /opt/oracle/middleware12c/wlserver/server/lib/weblogic-launcher.jar -Dlaunch.use.env.classpath=true -Dweblogic.Name=AdminServer -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.ProductionModeEnabled=true -Dweblogic.system.BootIdentityFile=/opt/oracle/wlsdomains/domains/Wls1221/servers/AdminServer/security/boot.properties -Dweblogic.nodemanager.ServiceEnabled=true -Dweblogic.nmservice.RotationEnabled=true -XX:PermSize=256m -XX:MaxPermSize=512m -Xms1024m -Xmx1024m -Dweblogic.Stdout=/var/log/weblogic/AdminServer.out -Dweblogic.Stderr=/var/log/weblogic/AdminServer_err.out -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -javaagent:/opt/oracle/middleware12c/wlserver/server/lib/debugpatch-agent.jar -da -Dwls.home=/opt/oracle/middleware12c/wlserver/server -Dweblogic.home=/opt/oracle/middleware12c/wlserver/server weblogic.Server

root 32169 0.0 0.0 9048 924 pts/0 S+ 20:11 0:00 grep --color=auto java

exit

vagrant reload admin

vagrant ssh admin

sudo -i

ps aux | grep java

root 11532 0.0 0.0 9044 664 pts/0 S+ 20:15 0:00 grep --color=auto java

journalctl -u nodemanager.service

-- Logs begin at Sun 2018-02-18 20:14:16 CET, end at Sun 2018-02-18 20:15:58 CET. -- Feb 18 20:14:36 admin.example.com systemd[1]: Started WebLogic nodemanager service. Feb 18 20:14:36 admin.example.com systemd[1]: Starting WebLogic nodemanager service... Feb 18 20:14:48 admin.example.com su[3729]: (to oracle) root on none Feb 18 20:14:49 admin.example.com nodemanager[973]: Starting nodemanager: Feb 18 20:14:50 admin.example.com nodemanager[973]: NODEMGR_HOME /opt/oracle/middleware12c/wlserver/../oracle_common/common/nodemanager does not exist, creating it.. Feb 18 20:14:50 admin.example.com nodemanager[973]: CLASSPATH=/usr/java/jdk1.8.0_151/lib/tools.jar:/opt/oracle/middleware12c/wlserver/server/lib/weblogic.jar:/opt/oracle/middleware12c/wlserver/../oracle_common/modules/thirdparty/ant-contrib-1.0b3.jar:/opt/oracle/middleware12c/wlserver/modules/features/oracle.wls.common.nodemanager.jar::/opt/oracle/middleware12c/wlserver/..:/opt/oracle/middleware12c/wlserver/modules/features/oracle.wls.common.grizzly.jar Feb 18 20:14:50 admin.example.com nodemanager[973]: + /usr/java/jdk1.8.0_151/bin/java -server -Xms32m -Xmx200m -Djdk.tls.ephemeralDHKeySize=2048 -Dweblogic.RootDirectory=/opt/oracle/middleware12c/wlserver/../oracle_common/common/nodemanager -Dcoherence.home=/opt/oracle/middleware12c/wlserver/../coherence -Dbea.home=/opt/oracle/middleware12c/wlserver/.. -Dweblogic.ssl.JSSEEnabled=true -Dweblogic.security.SSL.enableJSSE=true -Dweblogic.security.TrustKeyStore=CustomTrust -Dweblogic.security.CustomTrustKeyStoreFileName=/vagrant/truststore.jks -Dweblogic.security.CustomTrustKeystorePassPhrase=welcome -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.nodemanager.JavaHome=/usr/java/jdk1.8.0_151 weblogic.NodeManager -v Feb 18 20:15:02 admin.example.com nodemanager[973]: <Feb 18, 2018 8:15:02 PM CET> <Loading domains file: /opt/oracle/middleware12c/oracle_common/common/nodemanager/nodemanager.domains> Feb 18 20:15:02 admin.example.com nodemanager[973]: <Feb 18, 2018 8:15:02 PM CET> <Domains file not found: /opt/oracle/middleware12c/oracle_common/common/nodemanager/nodemanager.domains> Feb 18 20:15:04 admin.example.com nodemanager[973]: <Feb 18, 2018 8:15:04 PM CET> Feb 18 20:15:04 admin.example.com nodemanager[973]: <Feb 18, 2018 8:15:04 PM CET> Feb 18 20:15:04 admin.example.com nodemanager[973]: weblogic.nodemanager.common.ConfigException: Identity key store file not found: /opt/oracle/middleware12c/oracle_common/common/nodemanager/security/DemoIdentity.jks Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.nodemanager.server.SSLConfig.loadKeyStoreConfig(SSLConfig.java:225) Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.nodemanager.server.SSLConfig.access$000(SSLConfig.java:33) Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.nodemanager.server.SSLConfig$1.run(SSLConfig.java:118) Feb 18 20:15:04 admin.example.com nodemanager[973]: at java.security.AccessController.doPrivileged(Native Method) Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.nodemanager.server.SSLConfig.(SSLConfig.java:115) Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.nodemanager.server.NMServer.(NMServer.java:169) Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.nodemanager.server.NMServer.getInstance(NMServer.java:134) Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.nodemanager.server.NMServer.main(NMServer.java:589) Feb 18 20:15:04 admin.example.com nodemanager[973]: at weblogic.NodeManager.main(NodeManager.java:31) Feb 18 20:15:04 admin.example.com nodemanager[973]: + status=1 Feb 18 20:15:04 admin.example.com nodemanager[973]: + set +x Feb 18 20:15:04 admin.example.com nodemanager[973]: /home/oracle

cat /opt/oracle/middleware12c/oracle_common/common/nodemanager/nodemanager.log

<Feb 18, 2018 8:15:02 PM CET> <Loading domains file: /opt/oracle/middleware12c/oracle_common/common/nodemanager/nodemanager.domains> <Feb 18, 2018 8:15:02 PM CET> <Domains file not found: /opt/oracle/middleware12c/oracle_common/common/nodemanager/nodemanager.domains> <Feb 18, 2018 8:15:04 PM CET> <Feb 18, 2018 8:15:04 PM CET> weblogic.nodemanager.common.ConfigException: Identity key store file not found: /opt/oracle/middleware12c/oracle_common/common/nodemanager/security/DemoIdentity.jks at weblogic.nodemanager.server.SSLConfig.loadKeyStoreConfig(SSLConfig.java:225) at weblogic.nodemanager.server.SSLConfig.access$000(SSLConfig.java:33) at weblogic.nodemanager.server.SSLConfig$1.run(SSLConfig.java:118) at java.security.AccessController.doPrivileged(Native Method) at weblogic.nodemanager.server.SSLConfig.(SSLConfig.java:115) at weblogic.nodemanager.server.NMServer.(NMServer.java:169) at weblogic.nodemanager.server.NMServer.getInstance(NMServer.java:134) at weblogic.nodemanager.server.NMServer.main(NMServer.java:589) at weblogic.NodeManager.main(NodeManager.java:31)

biemond commented 6 years ago

Like I Saïd on the merge request use 1221 as version , you should the node manager started from the domain and not from the mdw home

danielmenezesbr commented 6 years ago

@biemond Thanks!

I put 1221 version like can you see in https://github.com/biemond/biemond-orawls-vagrant-12.2.1-puppet4/pull/8, and now it works fine.

I noticed that the NodeManger was started with different parameters comparing before and after the reboot of node1.

Before reboot node1: /usr/java/jdk1.8.0_151/bin/java -server -Xms32m -Xmx200m -Dcoherence.home=/opt/oracle/middleware12c/wlserver/../coherence -Dbea.home=/opt/oracle/middleware12c/wlserver/.. -Dweblogic.ssl.JSSEEnabled=true -Dweblogic.security.SSL.enableJSSE=true -Dweblogic.security.TrustKeyStore=CustomTrust -Dweblogic.security.CustomTrustKeyStoreFileName=/vagrant/truststore.jks -Dweblogic.security.CustomTrustKeystorePassPhrase=welcome -Daa=1 -Dbb=2 -Dweblogic.RootDirectory=/opt/oracle/wlsdomains/domains/Wls1221 -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.nodemanager.JavaHome=/usr/java/jdk1.8.0_151 weblogic.NodeManager -v

After reboot node1: /usr/java/jdk1.8.0_151/bin/java -server -Xms32m -Xmx200m -Djdk.tls.ephemeralDHKeySize=2048 -Dcoherence.home=/opt/oracle/middleware12c/wlserver/../coherence -Dbea.home=/opt/oracle/middleware12c/wlserver/.. -Dweblogic.ssl.JSSEEnabled=true -Dweblogic.security.SSL.enableJSSE=true -Dweblogic.security.TrustKeyStore=CustomTrust -Dweblogic.security.CustomTrustKeyStoreFileName=/vagrant/truststore.jks -Dweblogic.security.CustomTrustKeystorePassPhrase=welcome -Dweblogic.RootDirectory=/opt/oracle/wlsdomains/domains/Wls1221 -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.nodemanager.JavaHome=/usr/java/jdk1.8.0_151 weblogic.NodeManager -v

image

Do you know why this behavior occurred?

biemond commented 6 years ago

Hi,

first is started by orawls which supports $extra_arguments and 2nd by orautils which doesn't

danielmenezesbr commented 6 years ago

@biemond Is possible to use orawls to start NodeManager at startup boot on systemd Linux?

biemond commented 6 years ago

Just let puppet do it. It will detect the current and desired state

danielmenezesbr commented 6 years ago

@biemond Let puppet do it works fine with node1 and node2, but apparently not with admin.

Full log after vagrant reload admin https://gist.github.com/danielmenezesbr/d3fbe5966cd5558b61e19e6fab38bb2e

The log shows some errors:

==> admin: Error: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager]/Sleep[wake up nodemanager]: Failed to call refresh: 
==> admin: Error: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager]/Sleep[wake up nodemanager]: 
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/errors.rb:106:in `fail'
==> admin: /tmp/vagrant-puppet/environments/development/modules/sleep/lib/puppet/provider/sleep/ruby.rb:26:in `bedtime='
==> admin: /tmp/vagrant-puppet/environments/development/modules/sleep/lib/puppet/type/sleep.rb:34:in `sync'
==> admin: /tmp/vagrant-puppet/environments/development/modules/sleep/lib/puppet/type/sleep.rb:94:in `refresh'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:147:in `process_callback'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:34:in `block in process_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:119:in `block in queued_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:118:in `each'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:118:in `queued_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:33:in `process_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:250:in `eval_resource'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `call'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block (2 levels) in evaluate'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:507:in `block in thinmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:506:in `thinmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block in evaluate'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:154:in `evaluate'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:222:in `block in apply'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:155:in `with_destination'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/report.rb:146:in `as_logging_destination'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:221:in `apply'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:171:in `block in apply_catalog'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:224:in `block in benchmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:223:in `benchmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:170:in `apply_catalog'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:343:in `run_internal'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:221:in `block in run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:195:in `run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:350:in `apply_catalog'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:274:in `block in main'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:225:in `main'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:170:in `run_command'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:375:in `block in run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:662:in `exit_on_fail'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:375:in `run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:132:in `run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:72:in `execute'
==> admin: /opt/puppetlabs/puppet/bin/puppet:5:in `<main>'

...

==> admin: Error: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager_plain]/Sleep[wake up nodemanager_plain]: Failed to call refresh: 
==> admin: Error: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager_plain]/Sleep[wake up nodemanager_plain]: 
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/errors.rb:106:in `fail'
==> admin: /tmp/vagrant-puppet/environments/development/modules/sleep/lib/puppet/provider/sleep/ruby.rb:26:in `bedtime='
==> admin: /tmp/vagrant-puppet/environments/development/modules/sleep/lib/puppet/type/sleep.rb:34:in `sync'
==> admin: /tmp/vagrant-puppet/environments/development/modules/sleep/lib/puppet/type/sleep.rb:94:in `refresh'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:147:in `process_callback'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:34:in `block in process_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:119:in `block in queued_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:118:in `each'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:118:in `queued_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:33:in `process_events'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:250:in `eval_resource'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `call'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block (2 levels) in evaluate'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:507:in `block in thinmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:506:in `thinmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block in evaluate'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:154:in `evaluate'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:222:in `block in apply'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:155:in `with_destination'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/report.rb:146:in `as_logging_destination'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:221:in `apply'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:171:in `block in apply_catalog'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:224:in `block in benchmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:223:in `benchmark'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:170:in `apply_catalog'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:343:in `run_internal'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:221:in `block in run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:195:in `run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:350:in `apply_catalog'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:274:in `block in main'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:225:in `main'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:170:in `run_command'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:375:in `block in run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:662:in `exit_on_fail'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:375:in `run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:132:in `run'
==> admin: /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:72:in `execute'
==> admin: /opt/puppetlabs/puppet/bin/puppet:5:in `<main>'

Apparently the puppet executes all the scripts, but return with a non-zero exit status:

==> admin: Info: Connecting to wls on url t3://10.10.10.10:7101
==> admin: Notice: Applied catalog in 462.88 seconds
vagrant : The SSH command responded with a non-zero exit status. Vagrant
assumes that this means the command failed. The output for this command
should be in the log above. Please read the output to determine what
went wrong.
vagrant ssh admin
ps aux | grep java

[vagrant@admin ~]$ ps aux | grep java

oracle   14337  0.1  5.6 2538012 132888 ?      Sl   02:49   0:50 /usr/java/latest/bin/java -server -Xms32m -Xmx200m -Djdk.tls.ephemeralDHKeySize=2048 -Dcoherence.home=/opt/oracle/middleware12c/wlserver/../coherence -Dbea.home=/opt/oracle/middleware12c/wlserver/.. -Dweblogic.ssl.JSSEEnabled=true -Dweblogic.security.SSL.enableJSSE=true -Dweblogic.security.TrustKeyStore=CustomTrust -Dweblogic.security.CustomTrustKeyStoreFileName=/vagrant/truststore.jks -Dweblogic.security.CustomTrustKeystorePassPhrase=welcome -Daa=1 -Dbb=2 -Dweblogic.RootDirectory=/opt/oracle/wlsdomains/domains/Wls1221 -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.nodemanager.JavaHome=/usr/java/latest weblogic.NodeManager -v

oracle   14430  0.0  0.0 2847896  352 ?        Sl   02:50   0:25 /usr/java/latest/bin/java -Dderby.system.home=/opt/oracle/wlsdomains/domains/Wls1221/common/db -classpath /opt/oracle/middleware12c/wlserver/common/derby/lib/derby.jar:/opt/oracle/middleware12c/wlserver/common/derby/lib/derbynet.jar:/opt/oracle/middleware12c/wlserver/common/derby/lib/derbytools.jar:/opt/oracle/middleware12c/wlserver/common/derby/lib/derbyclient.jar org.apache.derby.drda.NetworkServerControl start

oracle   14431  0.8 26.3 3679040 618512 ?      Sl   02:50   5:08 /usr/java/latest/bin/java -server -Xms256m -Xmx512m -cp /opt/oracle/middleware12c/wlserver/server/lib/weblogic-launcher.jar -Dlaunch.use.env.classpath=true -Dweblogic.Name=AdminServer -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.ProductionModeEnabled=true -Dweblogic.system.BootIdentityFile=/opt/oracle/wlsdomains/domains/Wls1221/servers/AdminServer/security/boot.properties -Dweblogic.nodemanager.ServiceEnabled=true -Dweblogic.nmservice.RotationEnabled=true -XX:PermSize=256m -XX:MaxPermSize=512m -Xms1024m -Xmx1024m -Dweblogic.Stdout=/var/log/weblogic/AdminServer.out -Dweblogic.Stderr=/var/log/weblogic/AdminServer_err.out -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -javaagent:/opt/oracle/middleware12c/wlserver/server/lib/debugpatch-agent.jar -da -Dwls.home=/opt/oracle/middleware12c/wlserver/server -Dweblogic.home=/opt/oracle/middleware12c/wlserver/server weblogic.Server

oracle   14580  0.1  5.4 2531456 127148 ?      Sl   02:50   0:48 /usr/java/latest/bin/java -server -Xms32m -Xmx200m -Djdk.tls.ephemeralDHKeySize=2048 -Dcoherence.home=/opt/oracle/middleware12c/wlserver/../coherence -Dbea.home=/opt/oracle/middleware12c/wlserver/.. -Dweblogic.ssl.JSSEEnabled=true -Dweblogic.security.SSL.enableJSSE=true -Dweblogic.RootDirectory=/opt/oracle/wlsdomains/domains/plain_Wls -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.nodemanager.JavaHome=/usr/java/latest weblogic.NodeManager -v

oracle   14694  0.6 26.4 3683880 621072 ?      Sl   02:50   4:04 /usr/java/latest/bin/java -server -Xms256m -Xmx512m -cp /opt/oracle/middleware12c/wlserver/server/lib/weblogic-launcher.jar -Dlaunch.use.env.classpath=true -Dweblogic.Name=AdminServer -Djava.security.policy=/opt/oracle/middleware12c/wlserver/server/lib/weblogic.policy -Dweblogic.ProductionModeEnabled=true -Dweblogic.system.BootIdentityFile=/opt/oracle/wlsdomains/domains/plain_Wls/servers/AdminServer/security/boot.properties -Dweblogic.nodemanager.ServiceEnabled=true -Dweblogic.nmservice.RotationEnabled=true -XX:PermSize=256m -XX:MaxPermSize=512m -Xms1024m -Xmx1024m -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader -javaagent:/opt/oracle/middleware12c/wlserver/server/lib/debugpatch-agent.jar -da -Dwls.home=/opt/oracle/middleware12c/wlserver/server -Dweblogic.home=/opt/oracle/middleware12c/wlserver/server weblogic.Server

vagrant  20825  0.0  0.0   9048   928 pts/0    S+   13:06   0:00 grep --color=auto java

Note that these error messages do not appear in the first vagrant up. Error messages only appear after reboot (vagrant reload admin).

How to avoid error messages after vagrant reload admin?

biemond commented 6 years ago

I already fixed a nodemanager nohup issue. I don't know if it is solved by this.

biemond commented 6 years ago

it works, I increased the timeout

edwins-mbp:biemond-orawls-vagrant-12.2.1-puppet4 edwinbiemond$ vagrant reload admin
==> admin: Attempting graceful shutdown of VM...
==> admin: Clearing any previously set forwarded ports...
==> admin: Clearing any previously set network interfaces...
==> admin: Preparing network interfaces based on configuration...
    admin: Adapter 1: nat
    admin: Adapter 2: hostonly
==> admin: Forwarding ports...
    admin: 22 (guest) => 2222 (host) (adapter 1)
==> admin: Running 'pre-boot' VM customizations...
==> admin: Booting VM...
==> admin: Waiting for machine to boot. This may take a few minutes...
    admin: SSH address: 127.0.0.1:2222
    admin: SSH username: vagrant
    admin: SSH auth method: private key
==> admin: Machine booted and ready!
==> admin: Checking for guest additions in VM...
==> admin: Setting hostname...
==> admin: Configuring and enabling network interfaces...
    admin: SSH address: 127.0.0.1:2222
    admin: SSH username: vagrant
    admin: SSH auth method: private key
==> admin: Mounting shared folders...
    admin: /vagrant => /Users/edwinbiemond/projects/biemond-orawls-vagrant-12.2.1-puppet4
    admin: /software => /Users/edwinbiemond/projects/biemond-orawls-vagrant-12.2.1-puppet4/software
    admin: /tmp/vagrant-puppet/environments => /Users/edwinbiemond/projects/biemond-orawls-vagrant-12.2.1-puppet4/puppet/environments
    admin: /tmp/vagrant-puppet/manifests-2f329e84676fba04b7e4a879fc63af45 => /Users/edwinbiemond/projects/biemond-orawls-vagrant-12.2.1-puppet4/puppet/environments/development/manifests
==> admin: Machine already provisioned. Run `vagrant provision` or use the `--provision`
==> admin: flag to force provisioning. Provisioners marked to run always will still run.
==> admin: Running provisioner: puppet...
==> admin: Running Puppet with environment development...
==> admin: Info: Loading facts
==> admin: Info: Loading facts
==> admin: Info: Loading facts
==> admin: Info: Loading facts
==> admin: Info: Loading facts
==> admin: Info: Loading facts
==> admin: Warning: The function 'hiera' is deprecated in favor of using 'lookup'. See https://docs.puppet.com/puppet/4.10/reference/deprecated_language.html
==> admin:    (file & line not available)
==> admin: Warning: /vagrant/puppet/hiera.yaml: Use of 'hiera.yaml' version 3 is deprecated. It should be converted to version 5
==> admin:    (in /vagrant/puppet/hiera.yaml)
==> admin: Warning: Defining "data_provider": "hiera" in metadata.json is deprecated
==> admin:    (in /tmp/vagrant-puppet/environments/development/modules/orawls/metadata.json)
==> admin: Warning: Defining "data_provider": "hiera" in metadata.json is deprecated
==> admin:    (in /tmp/vagrant-puppet/environments/development/modules/jdk7/metadata.json)
==> admin: Info: orawls::domain_exists: full domain path /opt/oracle/wlsdomains/domains/wls1221
==> admin: Info: orawls::domain_exists: total domains 2
==> admin: Info: orawls::domain_exists: compare /opt/oracle/wlsdomains/domains/wls1221 with /opt/oracle/wlsdomains/domains/wls1221
==> admin: Info: orawls::domain_exists: full domain path /opt/oracle/wlsdomains/domains/plain_wls
==> admin: Info: orawls::domain_exists: total domains 2
==> admin: Info: orawls::domain_exists: compare /opt/oracle/wlsdomains/domains/plain_wls with /opt/oracle/wlsdomains/domains/wls1221
==> admin: Info: orawls::domain_exists: compare /opt/oracle/wlsdomains/domains/plain_wls with /opt/oracle/wlsdomains/domains/plain_wls
==> admin: Notice: Compiled catalog for admin.example.com in environment development in 6.89 seconds
==> admin: caution: filename not matched:  META-INF/MANIFEST.MF
==> admin: Info: Applying configuration version '1519674985'
==> admin: Notice: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager]/Exec[startNodemanager nodemanager]/returns: executed successfully
==> admin: Info: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager]/Exec[startNodemanager nodemanager]: Scheduling refresh of Sleep[wake up nodemanager]
==> admin: Notice: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager]/Sleep[wake up nodemanager]: Triggered 'refresh' from 1 events
==> admin: Notice: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager_plain]/Exec[startNodemanager nodemanager_plain]/returns: executed successfully
==> admin: Info: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager_plain]/Exec[startNodemanager nodemanager_plain]: Scheduling refresh of Sleep[wake up nodemanager_plain]
==> admin: Notice: /Stage[main]/Nodemanager/Orawls::Nodemanager[nodemanager_plain]/Sleep[wake up nodemanager_plain]: Triggered 'refresh' from 1 events
==> admin: Info: Starting the wls daemon for domain default
==> admin: Info: Executing wls-script /tmp/wlstCommonScript.py20180226-8835-zv09lx
==> admin: Info: Executing wls-script /tmp/wlstScript20180226-8835-1igmmqh.py with timeout = 120
==> admin: Info: Connecting to wls on url t3s://10.10.10.10:7002
==> admin: Info: Starting the wls daemon for domain plain
==> admin: Info: Executing wls-script /tmp/wlstCommonScript.py20180226-8835-1wes0dg
==> admin: Info: Executing wls-script /tmp/wlstScript20180226-8835-1igmmqh.py with timeout = 120
==> admin: Info: Connecting to wls on url t3://10.10.10.10:7101