[02/04 20:22:18] pbsdev@pbsdev-centos7-mky18-server:~ 51% time sudo $CV2_PTL_INSTALL_DIR/bin/pbs_benchpress --db-name $CV2_PBS_BUILD_DIR/test/tests/ptl_test_results.json -f $CV2_PTL_INSTALL_DIR/tests/functional/pbs_hook_modifyvnode_state_changes.py -t TestPbsModifyvnodeStateChanges.test_hook_state_changes_00 -p "moms=mom1:mom2" 2021-02-04 20:24:41,344 INFO input command: pbs_benchpress --db-name /home/pbsdev/pbs/build/test/tests/ptl_test_results.json -f /opt/ptl/tests/functional/pbs_hook_modifyvnode_state_changes.py -t TestPbsModifyvnodeStateChanges.test_hook_state_changes_00 -p moms=mom1:mom2 2021-02-04 20:24:41,344 INFO param: moms=mom1:mom2 2021-02-04 20:24:41,344 INFO ptl version: 19.1.1.1093.g7f30851.modified 2021-02-04 20:24:41,347 INFO platform: Linux pbsdev-centos7-mky18-server 4.19.121-linuxkit #1 SMP Tue Dec 1 17:50:32 UTC 2020 x86_64 x86_64 2021-02-04 20:24:41,347 INFO python version: 3.6.8 2021-02-04 20:24:41,347 INFO user: root 2021-02-04 20:24:41,348 INFO -------------------------------------------------------------------------------- 2021-02-04 20:24:41,348 INFO Cleaning up temporary files 2021-02-04 20:24:41,348 INFO Cleaning up /var/tmp dir 2021-02-04 20:24:41,348 INFO Cleaning up /tmp dir 2021-02-04 20:24:41,358 INFO ====================================================================== 2021-02-04 20:24:41,359 INFO suite name: TestPbsModifyvnodeStateChanges 2021-02-04 20:24:41,359 INFO suite docstring: Test the modifyvnode hook by inducing various vnode state changes and inspecting the pbs log for expected values. 2021-02-04 20:24:41,359 INFO ====================================================================== 2021-02-04 20:24:41,359 INFO ================================================== 2021-02-04 20:24:41,359 INFO Entered TestPbsModifyvnodeStateChanges setUpClass 2021-02-04 20:24:41,359 INFO ================================================== 2021-02-04 20:24:41,359 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser 2021-02-04 20:24:41,362 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser1 2021-02-04 20:24:41,364 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser2 2021-02-04 20:24:41,367 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser3 2021-02-04 20:24:41,369 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser4 2021-02-04 20:24:41,371 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser5 2021-02-04 20:24:41,373 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser6 2021-02-04 20:24:41,376 INFOCLI2 pbsdev-centos7-mky18-server: id pbsuser7 2021-02-04 20:24:41,379 INFOCLI2 pbsdev-centos7-mky18-server: id pbsother 2021-02-04 20:24:41,382 INFOCLI2 pbsdev-centos7-mky18-server: id pbstest 2021-02-04 20:24:41,385 INFOCLI2 pbsdev-centos7-mky18-server: id tstusr00 2021-02-04 20:24:41,388 INFOCLI2 pbsdev-centos7-mky18-server: id tstusr01 2021-02-04 20:24:41,391 INFOCLI2 pbsdev-centos7-mky18-server: id pbsoper 2021-02-04 20:24:41,394 INFOCLI2 pbsdev-centos7-mky18-server: id pbsmgr 2021-02-04 20:24:41,397 INFOCLI2 pbsdev-centos7-mky18-server: id pbsadmin 2021-02-04 20:24:41,399 INFOCLI2 pbsdev-centos7-mky18-server: id pbsdata 2021-02-04 20:24:41,401 INFOCLI2 pbsdev-centos7-mky18-server: id pbsroot 2021-02-04 20:24:41,403 INFOCLI2 pbsdev-centos7-mky18-server: id root 2021-02-04 20:24:41,405 INFOCLI2 pbsdev-centos7-mky18-server: id pbsbuild 2021-02-04 20:24:41,408 INFOCLI2 pbsdev-centos7-mky18-server: id root 2021-02-04 20:24:41,411 INFO FQDN name pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local differs from name provided pbsdev-centos7-mky18-server 2021-02-04 20:24:41,421 INFO server pbsdev-centos7-mky18-server: server operating mode set to cli 2021-02-04 20:24:41,421 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:41,430 INFO server pbsdev-centos7-mky18-server: version 19.1.1.1093.g7f30851.modified 2021-02-04 20:24:41,430 INFO expect action: created new action kicksched 2021-02-04 20:24:41,431 INFO expect action: added action kicksched to server pbsdev-centos7-mky18-server 2021-02-04 20:24:41,431 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:41,645 INFO FQDN name pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local differs from name provided pbsdev-centos7-mky18-server 2021-02-04 20:24:41,650 INFOCLI2 pbsdev-centos7-mky18-server: which chown 2021-02-04 20:24:41,652 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:41,662 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:41,673 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:41,689 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:41,700 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:41,710 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_logs 2021-02-04 20:24:41,721 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:24:41,735 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:41,745 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:41,757 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:41,773 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:41,784 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:41,795 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_logs 2021-02-04 20:24:41,806 INFO FQDN name pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local differs from name provided mom1 2021-02-04 20:24:41,807 INFOCLI2 mom1: ssh mom1 ls -1 /opt/pbs/python/bin/python 2021-02-04 20:24:41,825 INFOCLI2 mom1: ssh mom1 python3 -c "import os;print(os.environ.get("PBS_CONF_FILE", False))" 2021-02-04 20:24:41,908 INFO FQDN name pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local differs from name provided mom2 2021-02-04 20:24:41,910 INFOCLI2 mom2: ssh mom2 ls -1 /opt/pbs/python/bin/python 2021-02-04 20:24:41,928 INFOCLI2 mom2: ssh mom2 python3 -c "import os;print(os.environ.get("PBS_CONF_FILE", False))" 2021-02-04 20:24:42,012 INFO FQDN name pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local differs from name provided pbsdev-centos7-mky18-server 2021-02-04 20:24:42,017 INFO manager on pbsdev-centos7-mky18-server: set server {'pbs_license_min': 2} 2021-02-04 20:24:42,017 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c set server pbs_license_min=2 2021-02-04 20:24:42,037 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:42,051 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:24:42,063 INFO running init script to stop pbs server on pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=1', 'PBS_START_MOM=0', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'stop'] 2021-02-04 20:24:42,064 INFOCLI2 pbsdev-centos7-mky18-server: /tmp/PtlPbsgpsm61ts Contents of /tmp/PtlPbsgpsm61ts: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=1 PBS_START_MOM=0 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d stop ---------------------------------------- 2021-02-04 20:24:47,732 INFOCLI2 pbsdev-centos7-mky18-server: which rm 2021-02-04 20:24:47,735 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/rm /tmp/PtlPbsgpsm61ts 2021-02-04 20:24:47,740 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:24:47,750 INFO running init script to start pbs server on pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=1', 'PBS_START_MOM=0', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'start'] 2021-02-04 20:24:47,750 INFOCLI2 pbsdev-centos7-mky18-server: /tmp/PtlPbsxpb5yygz Contents of /tmp/PtlPbsxpb5yygz: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=1 PBS_START_MOM=0 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d start ---------------------------------------- 2021-02-04 20:24:51,749 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/rm /tmp/PtlPbsxpb5yygz 2021-02-04 20:24:51,756 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/server_priv/server.lock 2021-02-04 20:24:51,766 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:51,777 INFO =================================================== 2021-02-04 20:24:51,777 INFO Completed TestPbsModifyvnodeStateChanges setUpClass 2021-02-04 20:24:51,777 INFO =================================================== 2021-02-04 20:24:51,810 INFO mom pbsdev-centos7-mky18-mom1 log match: searching for "alps_client" - with existence - No match 2021-02-04 20:24:52,276 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local ls -l /etc/sgi-compute-node-release 2021-02-04 20:24:52,296 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local ls -l /etc/sgi-known-distributions 2021-02-04 20:24:52,314 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local ls -l /etc/sgi-compute-node-release 2021-02-04 20:24:52,331 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local ls -l /etc/sgi-known-distributions 2021-02-04 20:24:52,348 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/cat /proc/meminfo 2021-02-04 20:24:52,352 INFOCLI2 pbsdev-centos7-mky18-server: df -k /var/spool/pbs 2021-02-04 20:24:52,357 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H ls /var/spool/pbs/mom_priv 2021-02-04 20:24:52,368 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H ls /var/spool/pbs/server_priv 2021-02-04 20:24:52,378 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H ls /var/spool/pbs/sched_priv 2021-02-04 20:24:52,389 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser ls /home/pbsuser 2021-02-04 20:24:52,400 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser1 ls /home/pbsuser1 2021-02-04 20:24:52,410 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser2 ls /home/pbsuser2 2021-02-04 20:24:52,421 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser3 ls /home/pbsuser3 2021-02-04 20:24:52,432 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser4 ls /home/pbsuser4 2021-02-04 20:24:52,443 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser5 ls /home/pbsuser5 2021-02-04 20:24:52,453 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser6 ls /home/pbsuser6 2021-02-04 20:24:52,464 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsuser7 ls /home/pbsuser7 2021-02-04 20:24:52,475 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsother ls /home/pbsother 2021-02-04 20:24:52,486 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbstest ls /home/pbstest 2021-02-04 20:24:52,497 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u tstusr00 ls /home/tstusr00 2021-02-04 20:24:52,508 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u tstusr01 ls /home/tstusr01 2021-02-04 20:24:52,519 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsoper ls /home/pbsoper 2021-02-04 20:24:52,530 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsmgr ls /home/pbsmgr 2021-02-04 20:24:52,541 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsadmin ls /home/pbsadmin 2021-02-04 20:24:52,551 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsdata ls /home/pbsdata 2021-02-04 20:24:52,561 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsroot ls /home/pbsroot 2021-02-04 20:24:52,573 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u root ls /root 2021-02-04 20:24:52,583 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u pbsbuild ls /home/pbsbuild 2021-02-04 20:24:52,594 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H -u root ls /root 2021-02-04 20:24:52,605 INFOCLI2 mom2: ssh mom2 which cat 2021-02-04 20:24:52,623 INFOCLI2 mom2: ssh mom2 /usr/bin/cat /proc/meminfo 2021-02-04 20:24:52,656 INFOCLI2 mom2: ssh mom2 df -k /var/spool/pbs 2021-02-04 20:24:52,689 INFOCLI2 grep'ing for mom_priv in /var/spool/pbs 2021-02-04 20:24:52,689 INFOCLI2 mom2: ssh mom2 ls -l /var/spool/pbs 2021-02-04 20:24:52,706 INFOCLI2 mom2: ssh mom2 sudo -H ls /var/spool/pbs/mom_priv 2021-02-04 20:24:52,732 INFOCLI2 grep'ing for server_priv in /var/spool/pbs 2021-02-04 20:24:52,732 INFOCLI2 mom2: ssh mom2 ls -l /var/spool/pbs 2021-02-04 20:24:52,750 INFOCLI2 mom2: ssh mom2 sudo -H ls /var/spool/pbs/server_priv 2021-02-04 20:24:52,775 INFOCLI2 grep'ing for sched_priv in /var/spool/pbs 2021-02-04 20:24:52,775 INFOCLI2 mom2: ssh mom2 ls -l /var/spool/pbs 2021-02-04 20:24:52,796 INFOCLI2 mom2: ssh mom2 sudo -H ls /var/spool/pbs/sched_priv 2021-02-04 20:24:52,823 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser ls /home/pbsuser 2021-02-04 20:24:52,853 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser1 ls /home/pbsuser1 2021-02-04 20:24:52,879 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser2 ls /home/pbsuser2 2021-02-04 20:24:52,905 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser3 ls /home/pbsuser3 2021-02-04 20:24:52,931 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser4 ls /home/pbsuser4 2021-02-04 20:24:52,957 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser5 ls /home/pbsuser5 2021-02-04 20:24:52,982 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser6 ls /home/pbsuser6 2021-02-04 20:24:53,009 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsuser7 ls /home/pbsuser7 2021-02-04 20:24:53,036 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsother ls /home/pbsother 2021-02-04 20:24:53,062 INFOCLI2 mom2: ssh mom2 sudo -H -u pbstest ls /home/pbstest 2021-02-04 20:24:53,088 INFOCLI2 mom2: ssh mom2 sudo -H -u tstusr00 ls /home/tstusr00 2021-02-04 20:24:53,115 INFOCLI2 mom2: ssh mom2 sudo -H -u tstusr01 ls /home/tstusr01 2021-02-04 20:24:53,142 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsoper ls /home/pbsoper 2021-02-04 20:24:53,168 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsmgr ls /home/pbsmgr 2021-02-04 20:24:53,194 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsadmin ls /home/pbsadmin 2021-02-04 20:24:53,223 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsdata ls /home/pbsdata 2021-02-04 20:24:53,248 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsroot ls /home/pbsroot 2021-02-04 20:24:53,273 INFOCLI2 mom2: ssh mom2 sudo -H -u root ls /root 2021-02-04 20:24:53,299 INFOCLI2 mom2: ssh mom2 sudo -H -u pbsbuild ls /home/pbsbuild 2021-02-04 20:24:53,325 INFOCLI2 mom2: ssh mom2 sudo -H -u root ls /root 2021-02-04 20:24:53,350 INFOCLI2 mom1: ssh mom1 which cat 2021-02-04 20:24:53,367 INFOCLI2 mom1: ssh mom1 /usr/bin/cat /proc/meminfo 2021-02-04 20:24:53,400 INFOCLI2 mom1: ssh mom1 df -k /var/spool/pbs 2021-02-04 20:24:53,433 INFOCLI2 grep'ing for mom_priv in /var/spool/pbs 2021-02-04 20:24:53,433 INFOCLI2 mom1: ssh mom1 ls -l /var/spool/pbs 2021-02-04 20:24:53,451 INFOCLI2 mom1: ssh mom1 sudo -H ls /var/spool/pbs/mom_priv 2021-02-04 20:24:53,476 INFOCLI2 grep'ing for server_priv in /var/spool/pbs 2021-02-04 20:24:53,476 INFOCLI2 mom1: ssh mom1 ls -l /var/spool/pbs 2021-02-04 20:24:53,495 INFOCLI2 mom1: ssh mom1 sudo -H ls /var/spool/pbs/server_priv 2021-02-04 20:24:53,522 INFOCLI2 grep'ing for sched_priv in /var/spool/pbs 2021-02-04 20:24:53,523 INFOCLI2 mom1: ssh mom1 ls -l /var/spool/pbs 2021-02-04 20:24:53,541 INFOCLI2 mom1: ssh mom1 sudo -H ls /var/spool/pbs/sched_priv 2021-02-04 20:24:53,566 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser ls /home/pbsuser 2021-02-04 20:24:53,592 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser1 ls /home/pbsuser1 2021-02-04 20:24:53,618 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser2 ls /home/pbsuser2 2021-02-04 20:24:53,642 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser3 ls /home/pbsuser3 2021-02-04 20:24:53,667 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser4 ls /home/pbsuser4 2021-02-04 20:24:53,692 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser5 ls /home/pbsuser5 2021-02-04 20:24:53,717 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser6 ls /home/pbsuser6 2021-02-04 20:24:53,743 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsuser7 ls /home/pbsuser7 2021-02-04 20:24:53,771 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsother ls /home/pbsother 2021-02-04 20:24:53,796 INFOCLI2 mom1: ssh mom1 sudo -H -u pbstest ls /home/pbstest 2021-02-04 20:24:53,824 INFOCLI2 mom1: ssh mom1 sudo -H -u tstusr00 ls /home/tstusr00 2021-02-04 20:24:53,851 INFOCLI2 mom1: ssh mom1 sudo -H -u tstusr01 ls /home/tstusr01 2021-02-04 20:24:53,878 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsoper ls /home/pbsoper 2021-02-04 20:24:53,905 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsmgr ls /home/pbsmgr 2021-02-04 20:24:53,932 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsadmin ls /home/pbsadmin 2021-02-04 20:24:53,960 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsdata ls /home/pbsdata 2021-02-04 20:24:53,993 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsroot ls /home/pbsroot 2021-02-04 20:24:54,026 INFOCLI2 mom1: ssh mom1 sudo -H -u root ls /root 2021-02-04 20:24:54,054 INFOCLI2 mom1: ssh mom1 sudo -H -u pbsbuild ls /home/pbsbuild 2021-02-04 20:24:54,081 INFOCLI2 mom1: ssh mom1 sudo -H -u root ls /root 2021-02-04 20:24:54,109 INFO test name: test_hook_state_changes_00 (tests.functional.pbs_hook_modifyvnode_state_changes.TestPbsModifyvnodeStateChanges)... 2021-02-04 20:24:54,109 INFO test start time: Thu Feb 4 20:24:54 2021 2021-02-04 20:24:54,110 INFO test docstring: Test: induce a variety of vnode state changes with debug turned on and inspect the pbs log for expected entries 2021-02-04 20:24:54,110 INFO ============================================= 2021-02-04 20:24:54,110 INFO Entered TestPbsModifyvnodeStateChanges setUp 2021-02-04 20:24:54,110 INFO ============================================= 2021-02-04 20:24:54,110 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:54,120 INFO status on pbsdev-centos7-mky18-server: server 2021-02-04 20:24:54,120 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:54,334 INFO manager on pbsdev-centos7-mky18-server: unset server managers 2021-02-04 20:24:54,334 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c unset server managers 2021-02-04 20:24:54,354 INFO manager on pbsdev-centos7-mky18-server: unset server operators 2021-02-04 20:24:54,355 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c unset server operators 2021-02-04 20:24:54,373 INFO status on pbsdev-centos7-mky18-server: server ['managers', 'operators'] 2021-02-04 20:24:54,373 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:54,587 INFO manager on pbsdev-centos7-mky18-server: set server {'managers': (2, 'root@*,pbsmgr@*'), 'operators': (2, 'pbsoper@*')} 2021-02-04 20:24:54,587 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c set server managers+="root@*,pbsmgr@*",operators+=pbsoper@* 2021-02-04 20:24:54,605 INFO server pbsdev-centos7-mky18-server: reverting configuration to defaults 2021-02-04 20:24:54,606 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:54,822 INFO status on pbsdev-centos7-mky18-server: job 2021-02-04 20:24:54,822 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -f @pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:55,036 INFO status on pbsdev-centos7-mky18-server: sched 2021-02-04 20:24:55,037 INFO manager on pbsdev-centos7-mky18-server: list sched 2021-02-04 20:24:55,037 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched 2021-02-04 20:24:55,049 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:55,059 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:55,070 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:55,085 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:55,096 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:55,107 INFO manager on pbsdev-centos7-mky18-server as root: set sched default {'scheduling': 'False'} 2021-02-04 20:24:55,107 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set sched default scheduling=False 2021-02-04 20:24:55,120 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:24:55,130 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:55,140 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:55,152 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:55,169 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:55,180 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:55,191 INFO expect on server pbsdev-centos7-mky18-server: state != scheduling sched default ... OK 2021-02-04 20:24:55,192 INFO delete job on pbsdev-centos7-mky18-server as root: 2021-02-04 20:24:55,192 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -f @pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:55,407 INFO expect on server pbsdev-centos7-mky18-server: job_state set 0 job ... OK 2021-02-04 20:24:55,407 INFO manager on pbsdev-centos7-mky18-server as root: set sched default {'scheduling': 'True'} 2021-02-04 20:24:55,407 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set sched default scheduling=True 2021-02-04 20:24:55,419 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:24:55,428 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:55,439 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:55,449 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:55,465 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:55,476 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:55,486 INFO expect on server pbsdev-centos7-mky18-server: scheduling = True sched default ... OK 2021-02-04 20:24:55,486 INFO status on pbsdev-centos7-mky18-server as root: reservation 2021-02-04 20:24:55,486 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbs_rstat -f 2021-02-04 20:24:55,496 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:55,715 INFO status on pbsdev-centos7-mky18-server: job 2021-02-04 20:24:55,715 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -f @pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:55,930 INFO status on pbsdev-centos7-mky18-server: sched 2021-02-04 20:24:55,930 INFO manager on pbsdev-centos7-mky18-server: list sched 2021-02-04 20:24:55,930 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched 2021-02-04 20:24:55,942 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:55,951 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:55,962 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:55,977 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:55,987 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:55,998 INFO manager on pbsdev-centos7-mky18-server as root: set sched default {'scheduling': 'False'} 2021-02-04 20:24:55,998 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set sched default scheduling=False 2021-02-04 20:24:56,011 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:24:56,021 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:56,032 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:56,044 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:56,063 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:56,073 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:56,084 INFO expect on server pbsdev-centos7-mky18-server: state != scheduling sched default ... OK 2021-02-04 20:24:56,084 INFO delete job on pbsdev-centos7-mky18-server as root: 2021-02-04 20:24:56,085 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -f @pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:56,094 INFO expect on server pbsdev-centos7-mky18-server: job_state set 0 job ... OK 2021-02-04 20:24:56,095 INFO manager on pbsdev-centos7-mky18-server as root: set sched default {'scheduling': 'True'} 2021-02-04 20:24:56,095 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set sched default scheduling=True 2021-02-04 20:24:56,107 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:24:56,117 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:56,128 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:56,140 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:56,156 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:56,167 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:56,178 INFO expect on server pbsdev-centos7-mky18-server: scheduling = True sched default ... OK 2021-02-04 20:24:56,178 INFO status on pbsdev-centos7-mky18-server as root: reservation 2021-02-04 20:24:56,178 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbs_rstat -f 2021-02-04 20:24:56,187 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:56,401 INFO manager on pbsdev-centos7-mky18-server: unset server ['scheduling', 'log_events', 'mailer', 'mail_from', 'query_other_jobs', 'resources_default.ncpus', 'scheduler_iteration', 'resv_enable', 'max_array_size', 'pbs_license_max', 'pbs_license_linger_time', 'eligible_time_enable', 'max_concurrent_provision', 'sync_mom_hookfiles_timeout', 'max_job_sequence_id'] 2021-02-04 20:24:56,402 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c unset server scheduling,log_events,mailer,mail_from,query_other_jobs,resources_default.ncpus,scheduler_iteration,resv_enable,max_array_size,pbs_license_max,pbs_license_linger_time,eligible_time_enable,max_concurrent_provision,sync_mom_hookfiles_timeout,max_job_sequence_id 2021-02-04 20:24:56,417 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c list hook 2021-02-04 20:24:56,435 INFO manager on pbsdev-centos7-mky18-server: delete hook s1234 2021-02-04 20:24:56,435 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c delete hook s1234 2021-02-04 20:24:56,454 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Qf @pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:56,668 INFO status on pbsdev-centos7-mky18-server: node 2021-02-04 20:24:56,668 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v -a 2021-02-04 20:24:56,680 INFO manager on pbsdev-centos7-mky18-server: delete queue workq 2021-02-04 20:24:56,680 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c delete queue workq 2021-02-04 20:24:56,691 INFO manager on pbsdev-centos7-mky18-server: create queue workq {'queue_type': 'Execution', 'enabled': 'True', 'started': 'True'} 2021-02-04 20:24:56,691 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c create queue workq queue_type=Execution,enabled=True,started=True 2021-02-04 20:24:56,701 INFO status on pbsdev-centos7-mky18-server: queue workq 2021-02-04 20:24:56,701 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Qf workq@pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:56,918 INFO manager on pbsdev-centos7-mky18-server: list sched 2021-02-04 20:24:56,919 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched 2021-02-04 20:24:56,930 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:56,939 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:56,949 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:56,965 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:56,976 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:56,986 INFO manager on pbsdev-centos7-mky18-server: delete node @default 2021-02-04 20:24:56,986 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c delete node @default 2021-02-04 20:24:56,998 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c list hook 2021-02-04 20:24:57,017 INFO manager on pbsdev-centos7-mky18-server: set hook pbs_cgroups {'enabled': 'false'} 2021-02-04 20:24:57,018 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c set hook pbs_cgroups enabled=false 2021-02-04 20:24:57,040 INFO manager on pbsdev-centos7-mky18-server: set server {'default_queue': 'workq'} 2021-02-04 20:24:57,040 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set server default_queue=workq 2021-02-04 20:24:57,052 INFO status on pbsdev-centos7-mky18-server: resource 2021-02-04 20:24:57,052 INFO manager on pbsdev-centos7-mky18-server: list resource 2021-02-04 20:24:57,053 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list resource 2021-02-04 20:24:57,063 INFOCLI status on pbsdev-centos7-mky18-server: server license_count 2021-02-04 20:24:57,064 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:57,073 INFO server: pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local licensed 2021-02-04 20:24:57,073 INFO status on pbsdev-centos7-mky18-server: server pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:57,073 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:24:57,284 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local ls -1 /opt/pbs/python/bin/python 2021-02-04 20:24:57,301 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local python3 -c "import os;print(os.environ.get("PBS_CONF_FILE", False))" 2021-02-04 20:24:57,347 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local ls -1 /opt/pbs/python/bin/python 2021-02-04 20:24:57,365 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local python3 -c "import os;print(os.environ.get("PBS_CONF_FILE", False))" 2021-02-04 20:24:57,416 ERROR Couldn't revert PBS_DAEMON_SERVICE_USER in pbs.conf to its default value 2021-02-04 20:24:57,422 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/sched.lock 2021-02-04 20:24:57,433 INFO scheduler pbsdev-centos7-mky18-server: reverting configuration to defaults 2021-02-04 20:24:57,433 INFO manager on pbsdev-centos7-mky18-server: unset sched ['sched_cycle_length', 'throughput_mode', 'job_run_wait', 'opt_backfill_fuzzy', 'partition', 'sched_priv', 'sched_log', 'scheduling', 'scheduler_iteration', 'preempt_queue_prio', 'preempt_prio', 'preempt_order', 'preempt_sort', 'log_events', 'server_dyn_res_alarm'] 2021-02-04 20:24:57,433 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c unset sched sched_cycle_length,throughput_mode,job_run_wait,opt_backfill_fuzzy,partition,sched_priv,sched_log,scheduling,scheduler_iteration,preempt_queue_prio,preempt_prio,preempt_order,preempt_sort,log_events,server_dyn_res_alarm 2021-02-04 20:24:57,448 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:57,459 INFOCLI2 pbsdev-centos7-mky18-server: which cp 2021-02-04 20:24:57,463 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cp /tmp/PtlPbs_v7gv0ca /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:57,474 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H cmp /opt/pbs/etc/pbs_resource_group /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:57,486 INFO scheduler pbsdev-centos7-mky18-server: reverting holidays file to default 2021-02-04 20:24:57,486 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H cmp /opt/pbs/etc/pbs_holidays /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:57,497 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H cmp /opt/pbs/etc/pbs_sched_config /var/spool/pbs/sched_priv/sched_config 2021-02-04 20:24:57,507 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H cmp /opt/pbs/etc/pbs_dedicated /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:57,518 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cp /opt/pbs/etc/pbs_dedicated /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:57,529 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown root /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:57,539 INFO Scheduler sent signal -HUP 2021-02-04 20:24:57,539 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/sched.lock 2021-02-04 20:24:57,549 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H kill -HUP 46148 2021-02-04 20:24:57,559 INFOCLI2 pbsdev-centos7-mky18-server: /opt/pbs/sbin/pbsfs -e -I default 2021-02-04 20:24:57,582 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/sched.lock 2021-02-04 20:24:57,593 INFO status on pbsdev-centos7-mky18-server: sched default 2021-02-04 20:24:57,593 INFO manager on pbsdev-centos7-mky18-server: list sched default 2021-02-04 20:24:57,593 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:24:57,604 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:24:57,614 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:24:57,626 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:24:57,642 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:24:57,653 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:24:57,713 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local ls -1 /opt/pbs/python/bin/python 2021-02-04 20:24:57,748 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import sys; print(sys.platform)" 2021-02-04 20:24:57,798 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:24:57,822 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom1 2021-02-04 20:24:57,823 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:24:57,831 ERROR err: ['/opt/pbs/bin/pbsnodes: Server has no node list'] 2021-02-04 20:24:57,832 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local which rm 2021-02-04 20:24:57,850 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/rm -f /var/spool/pbs/mom_priv/epilogue 2021-02-04 20:24:57,874 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/rm -f /var/spool/pbs/mom_priv/prologue 2021-02-04 20:24:57,899 INFOCLI pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /opt/pbs/sbin/pbs_mom -s list 2021-02-04 20:24:57,989 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import tempfile;print(tempfile.mkstemp('PtlPbstmpcopy')[1])" 2021-02-04 20:24:58,038 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local which scp 2021-02-04 20:24:58,055 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp /tmp/PtlPbsm01wm92o pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local:/tmp/tmpfhq5cjhePtlPbstmpcopy 2021-02-04 20:24:58,081 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local which cp 2021-02-04 20:24:58,101 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/cp /tmp/tmpfhq5cjhePtlPbstmpcopy /var/spool/pbs/mom_priv/config 2021-02-04 20:24:58,126 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/tmpfhq5cjhePtlPbstmpcopy 2021-02-04 20:24:58,145 INFO MoM sent signal -HUP 2021-02-04 20:24:58,146 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:24:58,170 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H kill -HUP 14917 2021-02-04 20:24:58,215 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:24:58,240 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom1 2021-02-04 20:24:58,240 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:24:58,250 ERROR err: ['/opt/pbs/bin/pbsnodes: Server has no node list'] 2021-02-04 20:24:58,250 INFO manager on pbsdev-centos7-mky18-server: create node pbsdev-centos7-mky18-mom1 2021-02-04 20:24:58,250 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c create node pbsdev-centos7-mky18-mom1 2021-02-04 20:24:58,263 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom1 2021-02-04 20:24:58,264 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:24:58,273 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:24:58,283 INFO expect on server pbsdev-centos7-mky18-server: state = free node pbsdev-centos7-mky18-mom1 got: state = state-unknown,down 2021-02-04 20:24:59,287 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:24:59,300 INFO expect on server pbsdev-centos7-mky18-server: state = free node pbsdev-centos7-mky18-mom1 attempt: 2 got: state = state-unknown,down 2021-02-04 20:25:00,301 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:25:00,311 INFO expect on server pbsdev-centos7-mky18-server: state = free node pbsdev-centos7-mky18-mom1 attempt: 3 ... OK 2021-02-04 20:25:00,312 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom1 2021-02-04 20:25:00,312 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:25:00,371 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local ls -1 /opt/pbs/python/bin/python 2021-02-04 20:25:00,408 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import sys; print(sys.platform)" 2021-02-04 20:25:00,457 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:00,482 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,482 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,494 ERROR err: ['Node: pbsdev-centos7-mky18-mom2, Error: Unknown node '] 2021-02-04 20:25:00,494 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local which rm 2021-02-04 20:25:00,512 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/rm -f /var/spool/pbs/mom_priv/epilogue 2021-02-04 20:25:00,538 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/rm -f /var/spool/pbs/mom_priv/prologue 2021-02-04 20:25:00,564 INFOCLI pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /opt/pbs/sbin/pbs_mom -s list 2021-02-04 20:25:00,656 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import tempfile;print(tempfile.mkstemp('PtlPbstmpcopy')[1])" 2021-02-04 20:25:00,707 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local which scp 2021-02-04 20:25:00,724 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp /tmp/PtlPbsu01ayhgb pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local:/tmp/tmptda2qhmmPtlPbstmpcopy 2021-02-04 20:25:00,751 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local which cp 2021-02-04 20:25:00,770 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/cp /tmp/tmptda2qhmmPtlPbstmpcopy /var/spool/pbs/mom_priv/config 2021-02-04 20:25:00,796 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/tmptda2qhmmPtlPbstmpcopy 2021-02-04 20:25:00,814 INFO MoM sent signal -HUP 2021-02-04 20:25:00,815 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:00,839 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H kill -HUP 14867 2021-02-04 20:25:00,887 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:00,914 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,914 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,923 ERROR err: ['Node: pbsdev-centos7-mky18-mom2, Error: Unknown node '] 2021-02-04 20:25:00,924 INFO manager on pbsdev-centos7-mky18-server: create node pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,924 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c create node pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,937 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,937 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,946 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:00,956 INFO expect on server pbsdev-centos7-mky18-server: state = free node pbsdev-centos7-mky18-mom2 got: state = state-unknown,down 2021-02-04 20:25:01,959 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:01,972 INFO expect on server pbsdev-centos7-mky18-server: state = free node pbsdev-centos7-mky18-mom2 attempt: 2 got: state = state-unknown,down 2021-02-04 20:25:02,973 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:02,983 INFO expect on server pbsdev-centos7-mky18-server: state = free node pbsdev-centos7-mky18-mom2 attempt: 3 ... OK 2021-02-04 20:25:02,983 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom2 2021-02-04 20:25:02,983 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:02,992 INFO manager on pbsdev-centos7-mky18-server: set sched default {'opt_backfill_fuzzy': 'off'} 2021-02-04 20:25:02,992 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set sched default opt_backfill_fuzzy=off 2021-02-04 20:25:03,007 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/server_priv/comm.lock 2021-02-04 20:25:03,017 INFO ============================================== 2021-02-04 20:25:03,017 INFO Completed TestPbsModifyvnodeStateChanges setUp 2021-02-04 20:25:03,018 INFO ============================================== 2021-02-04 20:25:03,018 INFO manager on pbsdev-centos7-mky18-server: set server {'log_events': 4095} 2021-02-04 20:25:03,018 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set server log_events=4095 2021-02-04 20:25:03,028 INFO status on pbsdev-centos7-mky18-server: hook 2021-02-04 20:25:03,028 INFO manager on pbsdev-centos7-mky18-server: list hook 2021-02-04 20:25:03,028 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c list hook 2021-02-04 20:25:03,047 INFO manager on pbsdev-centos7-mky18-server: create hook m1234 2021-02-04 20:25:03,047 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c create hook m1234 2021-02-04 20:25:03,066 INFO status on pbsdev-centos7-mky18-server: hook m1234 2021-02-04 20:25:03,066 INFO manager on pbsdev-centos7-mky18-server: list hook m1234 2021-02-04 20:25:03,066 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c list hook m1234 2021-02-04 20:25:03,085 INFO status on pbsdev-centos7-mky18-server: hook m1234 2021-02-04 20:25:03,085 INFO manager on pbsdev-centos7-mky18-server: list hook m1234 2021-02-04 20:25:03,085 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c list hook m1234 2021-02-04 20:25:03,103 INFO manager on pbsdev-centos7-mky18-server: set hook m1234 {'event': 'modifyvnode', 'enabled': 'True', 'debug': 'True'} 2021-02-04 20:25:03,103 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c set hook m1234 event=modifyvnode,enabled=True,debug=True 2021-02-04 20:25:03,122 INFO status on pbsdev-centos7-mky18-server: server sync_mom_hookfiles_timeout 2021-02-04 20:25:03,123 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:25:03,132 INFO Setting sync_mom_hookfiles_timeout to 15s 2021-02-04 20:25:03,132 INFO manager on pbsdev-centos7-mky18-server: set server {'sync_mom_hookfiles_timeout': 15} 2021-02-04 20:25:03,132 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set server sync_mom_hookfiles_timeout=15 2021-02-04 20:25:03,143 INFO manager on pbsdev-centos7-mky18-server: import hook m1234 {'content-type': 'application/x-python', 'content-encoding': 'default', 'input-file': '/tmp/PtlPbs2a_67zip'} 2021-02-04 20:25:03,143 INFOCLI pbsdev-centos7-mky18-server: sudo -H /opt/pbs/bin/qmgr -c import hook m1234 application/x-python default /tmp/PtlPbs2a_67zip 2021-02-04 20:25:03,161 INFO server pbsdev-centos7-mky18-server: imported hook body --- import pbs import sys try: e = pbs.event() v = e.vnode v_o = e.vnode_o lsct = v.last_state_change_time lsct_o = v_o.last_state_change_time state_str_buf_v = ",".join(v.extract_state_strs()) state_str_buf_v_o = ",".join(v_o.extract_state_strs()) state_int_buf_v = ','.join([str(_) for _ in v.extract_state_ints()]) state_int_buf_v_o = ','.join( [str(_) for _ in v_o.extract_state_ints()]) # print show_vnode_state record (bi consumable) svs1_data = "v.state_hex=%s v_o.state_hex=%s v.state_strs=%s " "v_o.state_strs=%s" % (hex(v.state), hex(v_o.state), state_str_buf_v, state_str_buf_v_o) svs2_data = "v.state_ints=%s v_o.state_ints=%s v.lsct=%s " "v_o.lsct=%s" % (state_int_buf_v, state_int_buf_v_o, str(lsct), str(lsct_o)) svs_data = "%s %s" % (svs1_data, svs2_data) pbs.logmsg(pbs.LOG_DEBUG, "show_vnode_state;name=%s %s" % (v.name, svs_data)) # print additional hook parameter values pbs.logmsg(pbs.LOG_DEBUG, "name: v=%s, v_o=%s" % (v.name, v_o.name)) pbs.logmsg(pbs.LOG_DEBUG, "state: v=%s, v_o=%s" % (hex(v.state), hex(v_o.state))) pbs.logmsg(pbs.LOG_DEBUG, "last_state_change_time: v=%s, v_o=%s" % ( str(lsct), str(lsct_o))) pbs.logmsg(pbs.LOG_DEBUG, "comment: v=%s, v_o=%s" % (v.comment, v_o.comment)) pbs.logmsg(pbs.LOG_DEBUG, "aoe: v=%s, v_o=%s" % (v.current_aoe, v_o.current_aoe)) pbs.logmsg(pbs.LOG_DEBUG, "in_mvn_host: v=%s, v_o=%s" % ( v.in_multivnode_host, v_o.in_multivnode_host)) pbs.logmsg(pbs.LOG_DEBUG, "jobs: v=%s, v_o=%s" % (v.jobs, v_o.jobs)) pbs.logmsg(pbs.LOG_DEBUG, "Mom: v=%s, v_o=%s" % (v.Mom, v_o.Mom)) pbs.logmsg(pbs.LOG_DEBUG, "ntype: v=%s, v_o=%s" % (hex(v.ntype), hex(v_o.ntype))) pbs.logmsg(pbs.LOG_DEBUG, "pcpus: v=%s, v_o=%s" % (v.pcpus, v_o.pcpus)) pbs.logmsg(pbs.LOG_DEBUG, "pnames: v=%s, v_o=%s" % (v.pnames, v_o.pnames)) pbs.logmsg(pbs.LOG_DEBUG, "Port: v=%s, v_o=%s" % (v.Port, v_o.Port)) pbs.logmsg(pbs.LOG_DEBUG, "Priority: v=%s, v_o=%s" % (v.Priority, v_o.Priority)) pbs.logmsg(pbs.LOG_DEBUG, "provision_enable: v=%s, v_o=%s" % ( v.provision_enable, v_o.provision_enable)) pbs.logmsg(pbs.LOG_DEBUG, "queue: v=%s, v_o=%s" % (v.queue, v_o.queue)) pbs.logmsg(pbs.LOG_DEBUG, "res_assigned: v=%s, v_o=%s" % ( v.resources_assigned, v_o.resources_assigned)) pbs.logmsg(pbs.LOG_DEBUG, "res_avail: v=%s, v_o=%s" % ( v.resources_available, v_o.resources_available)) pbs.logmsg(pbs.LOG_DEBUG, "resv: v=%s, v_o=%s" % (v.resv, v_o.resv)) pbs.logmsg(pbs.LOG_DEBUG, "resv_enable: v=%s, v_o=%s" % ( v.resv_enable, v_o.resv_enable)) pbs.logmsg(pbs.LOG_DEBUG, "sharing: v=%s, v_o=%s" % (v.sharing, v_o.sharing)) # sanity test some values if (lsct < lsct_o) or (lsct_o <= 0): e.reject("last_state_change_time: bad timestamp value") else: pbs.logmsg(pbs.LOG_DEBUG, "last_state_change_time: good times") if (v.name != v_o.name) or (not v.name): e.reject( "name: vnode and vnode_o name values are null or mismatched") else: pbs.logmsg(pbs.LOG_DEBUG, "name: good names") if (isinstance(v.state, int)) and (isinstance(v_o.state, int)): pbs.logmsg(pbs.LOG_DEBUG, "state: good states") else: e.reject("state: bad state value") if len(v.extract_state_strs()) == len(v.extract_state_ints()): pbs.logmsg(pbs.LOG_DEBUG, "state sets: good v sets") else: e.reject("state sets: bad v sets") if len(v_o.extract_state_strs()) == len(v_o.extract_state_ints()): pbs.logmsg(pbs.LOG_DEBUG, "state sets: good v_o sets") else: e.reject("state sets: bad v_o sets") e.accept() except SystemExit: pass except: pbs.event().reject("%s hook failed with %s" % ( pbs.event().hook_name, sys.exc_info()[:2])) --- 2021-02-04 20:25:03,161 INFO status on pbsdev-centos7-mky18-server: node 2021-02-04 20:25:03,161 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v -a 2021-02-04 20:25:03,188 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:03,213 INFO running init script to stop pbs mom on pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'stop'] 2021-02-04 20:25:03,215 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbszi2gaewo pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local:/tmp/PtlPbszi2gaewo 2021-02-04 20:25:03,238 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /tmp/PtlPbszi2gaewo Contents of /tmp/PtlPbszi2gaewo: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d stop ---------------------------------------- 2021-02-04 20:25:04,303 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbszi2gaewo 2021-02-04 20:25:04,325 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:04,328 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:04,331 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:04,334 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:04,337 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:04,340 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:04,342 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:04,345 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:04,348 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:04,351 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:04,353 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node down" - with existence... OK 2021-02-04 20:25:04,356 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2" - with existence... OK 2021-02-04 20:25:04,359 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_DOWN,ND_STATE_VNODE_UNAVAILABLE" - with existence... OK 2021-02-04 20:25:04,362 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=2,409903" - with existence... OK 2021-02-04 20:25:04,380 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:04,404 INFO running init script to start pbs mom on pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'start'] 2021-02-04 20:25:04,406 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbsr0sb52t1 pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local:/tmp/PtlPbsr0sb52t1 2021-02-04 20:25:04,431 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /tmp/PtlPbsr0sb52t1 Contents of /tmp/PtlPbsr0sb52t1: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d start ---------------------------------------- 2021-02-04 20:25:04,530 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbsr0sb52t1 2021-02-04 20:25:04,567 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:04,595 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - No match 2021-02-04 20:25:05,801 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 2 2021-02-04 20:25:07,018 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 3 2021-02-04 20:25:08,219 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:08,226 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:08,230 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:08,232 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:08,235 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:08,237 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:08,240 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:08,243 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:08,246 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:08,248 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:08,252 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node up" - with existence... OK 2021-02-04 20:25:08,254 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:25:08,257 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:25:08,259 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:25:08,278 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:08,303 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom1 2021-02-04 20:25:08,303 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:25:08,316 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom1 2021-02-04 20:25:08,327 INFO expect on server pbsdev-centos7-mky18-server: state ~ free|provisioning|offline|job-busy node pbsdev-centos7-mky18-mom1 ... OK 2021-02-04 20:25:08,344 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:08,370 INFO running init script to stop pbs mom on pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'stop'] 2021-02-04 20:25:08,372 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbsszayg2ge pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local:/tmp/PtlPbsszayg2ge 2021-02-04 20:25:08,399 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /tmp/PtlPbsszayg2ge Contents of /tmp/PtlPbsszayg2ge: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d stop ---------------------------------------- 2021-02-04 20:25:09,467 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbsszayg2ge 2021-02-04 20:25:09,500 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:09,525 INFO running init script to start pbs mom on pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'start'] 2021-02-04 20:25:09,527 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbs_fqs_rnx pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local:/tmp/PtlPbs_fqs_rnx 2021-02-04 20:25:09,553 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /tmp/PtlPbs_fqs_rnx Contents of /tmp/PtlPbs_fqs_rnx: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d start ---------------------------------------- 2021-02-04 20:25:09,656 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbs_fqs_rnx 2021-02-04 20:25:09,696 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:09,725 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:09,728 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:09,731 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:09,735 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:09,738 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:09,742 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:09,745 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:09,749 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:09,752 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:09,756 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:09,762 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node up" - with existence - No match 2021-02-04 20:25:10,963 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node up" - with existence - attempt 2 2021-02-04 20:25:12,174 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node up" - with existence - attempt 3 2021-02-04 20:25:13,379 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node up" - with existence... OK 2021-02-04 20:25:13,387 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node down" - with existence - No match 2021-02-04 20:25:14,582 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local;node down" - with existence... OK 2021-02-04 20:25:14,589 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2" - with existence - No match 2021-02-04 20:25:15,790 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2" - with existence... OK 2021-02-04 20:25:15,797 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_DOWN,ND_STATE_VNODE_UNAVAILABLE" - with existence - No match 2021-02-04 20:25:16,997 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_DOWN,ND_STATE_VNODE_UNAVAILABLE" - with existence... OK 2021-02-04 20:25:17,008 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=2,409903" - with existence - No match 2021-02-04 20:25:18,202 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=2,409903" - with existence... OK 2021-02-04 20:25:18,208 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:25:18,211 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:25:18,214 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:25:18,214 INFO manager on pbsdev-centos7-mky18-server: set node pbsdev-centos7-mky18-mom1 {'state': (2, 'offline')} 2021-02-04 20:25:18,214 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set node pbsdev-centos7-mky18-mom1 state+=offline 2021-02-04 20:25:18,235 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:18,239 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:18,242 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:18,245 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:18,248 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:18,252 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:18,255 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:18,258 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:18,261 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:18,265 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:18,268 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x1" - with existence... OK 2021-02-04 20:25:18,272 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_OFFLINE,ND_STATE_VNODE_UNAVAILABLE" - with existence... OK 2021-02-04 20:25:18,276 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=1,409903" - with existence... OK 2021-02-04 20:25:18,276 INFO manager on pbsdev-centos7-mky18-server: set node pbsdev-centos7-mky18-mom1 {'state': (3, 'offline')} 2021-02-04 20:25:18,276 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set node pbsdev-centos7-mky18-mom1 state-=offline 2021-02-04 20:25:18,294 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:18,298 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:18,301 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:18,305 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:18,308 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:18,312 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:18,315 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:18,318 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:18,321 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:18,324 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:18,327 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:25:18,331 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:25:18,334 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:25:18,335 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbs_rsub -R 202102042025.33 -E 202102042025.34 --hosts pbsdev-centos7-mky18-mom1 2021-02-04 20:25:18,351 INFO submit to pbsdev-centos7-mky18-server as root: reservation M14.pbsdev-centos7-mky18-server CONFIRMED OrderedDict([('reserve_start', 1612470333.334764), ('reserve_end', 1612470334.334764)]) 2021-02-04 20:25:18,355 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - No match 2021-02-04 20:25:19,560 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 2 2021-02-04 20:25:20,763 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 3 2021-02-04 20:25:21,970 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 4 2021-02-04 20:25:23,154 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 5 2021-02-04 20:25:24,353 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 6 2021-02-04 20:25:25,552 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 7 2021-02-04 20:25:26,749 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 8 2021-02-04 20:25:27,963 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 9 2021-02-04 20:25:29,176 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 10 2021-02-04 20:25:30,371 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 11 2021-02-04 20:25:31,584 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 12 2021-02-04 20:25:32,797 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 13 2021-02-04 20:25:34,004 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 14 2021-02-04 20:25:35,227 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:35,235 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:35,238 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:35,241 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:35,245 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:35,249 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:35,254 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:35,258 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:35,261 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:35,264 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:35,268 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2000" - with existence - No match 2021-02-04 20:25:36,485 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2000" - with existence... OK 2021-02-04 20:25:36,492 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_RESV_EXCLUSIVE" - with existence - No match 2021-02-04 20:25:37,703 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_RESV_EXCLUSIVE" - with existence... OK 2021-02-04 20:25:37,710 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=8192" - with existence - No match 2021-02-04 20:25:38,912 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=8192" - with existence... OK 2021-02-04 20:25:38,918 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:25:38,921 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:25:38,923 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:25:38,923 INFO checkpreviousStateChain search_string=;show_vnode_state;name=pbsdev-centos7-mky18-mom1 start=1612470303.1716065 end=1612470338.923814 2021-02-04 20:25:38,959 INFO server pbsdev-centos7-mky18-server log match: searching for ";show_vnode_state;name=pbsdev-centos7-mky18-mom1" - on all matches - with existence... OK 2021-02-04 20:25:38,980 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:39,006 INFO running init script to stop pbs mom on pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'stop'] 2021-02-04 20:25:39,008 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbs5tdcfifi pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local:/tmp/PtlPbs5tdcfifi 2021-02-04 20:25:39,035 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /tmp/PtlPbs5tdcfifi Contents of /tmp/PtlPbs5tdcfifi: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d stop ---------------------------------------- 2021-02-04 20:25:40,102 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbs5tdcfifi 2021-02-04 20:25:40,123 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:40,127 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:40,131 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:40,135 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:40,138 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:40,141 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:40,146 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:40,151 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:40,155 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:40,159 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:40,163 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node down" - with existence... OK 2021-02-04 20:25:40,166 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2" - with existence... OK 2021-02-04 20:25:40,170 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_DOWN,ND_STATE_VNODE_UNAVAILABLE" - with existence... OK 2021-02-04 20:25:40,172 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=2,409903" - with existence... OK 2021-02-04 20:25:40,190 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:40,215 INFO running init script to start pbs mom on pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'start'] 2021-02-04 20:25:40,217 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbsa155juwa pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local:/tmp/PtlPbsa155juwa 2021-02-04 20:25:40,245 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /tmp/PtlPbsa155juwa Contents of /tmp/PtlPbsa155juwa: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d start ---------------------------------------- 2021-02-04 20:25:40,349 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbsa155juwa 2021-02-04 20:25:40,389 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:40,419 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - No match 2021-02-04 20:25:41,625 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 2 2021-02-04 20:25:42,835 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 3 2021-02-04 20:25:44,036 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:44,043 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:44,046 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:44,049 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:44,052 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:44,055 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:44,058 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:44,060 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:44,063 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:44,066 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:44,069 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node up" - with existence... OK 2021-02-04 20:25:44,073 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:25:44,077 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:25:44,081 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:25:44,102 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:44,128 INFO status on pbsdev-centos7-mky18-server: node pbsdev-centos7-mky18-mom2 2021-02-04 20:25:44,128 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:44,139 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbsnodes -s pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local -v pbsdev-centos7-mky18-mom2 2021-02-04 20:25:44,150 INFO expect on server pbsdev-centos7-mky18-server: state ~ free|provisioning|offline|job-busy node pbsdev-centos7-mky18-mom2 ... OK 2021-02-04 20:25:44,168 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:44,195 INFO running init script to stop pbs mom on pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'stop'] 2021-02-04 20:25:44,196 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbshzn_wksi pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local:/tmp/PtlPbshzn_wksi 2021-02-04 20:25:44,221 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /tmp/PtlPbshzn_wksi Contents of /tmp/PtlPbshzn_wksi: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d stop ---------------------------------------- 2021-02-04 20:25:45,291 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbshzn_wksi 2021-02-04 20:25:45,326 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H ls -l /opt/pbs/libexec/pbs_init.d 2021-02-04 20:25:45,352 INFO running init script to start pbs mom on pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local using /etc/pbs.conf init_cmd=['sudo', '-H', 'PBS_START_SERVER=0', 'PBS_START_MOM=1', 'PBS_START_SCHED=0', 'PBS_START_COMM=0', '/opt/pbs/libexec/pbs_init.d', 'start'] 2021-02-04 20:25:45,354 INFOCLI2 pbsdev-centos7-mky18-server: /usr/bin/scp -p /tmp/PtlPbsv5zllyuz pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local:/tmp/PtlPbsv5zllyuz 2021-02-04 20:25:45,379 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /tmp/PtlPbsv5zllyuz Contents of /tmp/PtlPbsv5zllyuz: ---------------------------------------- #!/bin/bash sudo -H PBS_START_SERVER=0 PBS_START_MOM=1 PBS_START_SCHED=0 PBS_START_COMM=0 /opt/pbs/libexec/pbs_init.d start ---------------------------------------- 2021-02-04 20:25:45,478 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/rm /tmp/PtlPbsv5zllyuz 2021-02-04 20:25:45,516 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local sudo -H /usr/bin/cat /var/spool/pbs/mom_priv/mom.lock 2021-02-04 20:25:45,546 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:45,550 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:45,554 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:45,558 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:45,561 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:45,564 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:45,568 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:45,571 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:45,576 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:45,581 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:45,586 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node up" - with existence - No match 2021-02-04 20:25:46,802 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node up" - with existence - attempt 2 2021-02-04 20:25:48,007 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node up" - with existence - attempt 3 2021-02-04 20:25:49,215 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node up" - with existence... OK 2021-02-04 20:25:49,223 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node down" - with existence - No match 2021-02-04 20:25:50,430 INFO server pbsdev-centos7-mky18-server log match: searching for "Node;pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local;node down" - with existence... OK 2021-02-04 20:25:50,437 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2" - with existence - No match 2021-02-04 20:25:51,639 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2" - with existence... OK 2021-02-04 20:25:51,647 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_DOWN,ND_STATE_VNODE_UNAVAILABLE" - with existence - No match 2021-02-04 20:25:52,822 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_DOWN,ND_STATE_VNODE_UNAVAILABLE" - with existence... OK 2021-02-04 20:25:52,829 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=2,409903" - with existence - No match 2021-02-04 20:25:54,044 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=2,409903" - with existence... OK 2021-02-04 20:25:54,051 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:25:54,054 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:25:54,059 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:25:54,059 INFO manager on pbsdev-centos7-mky18-server: set node pbsdev-centos7-mky18-mom2 {'state': (2, 'offline')} 2021-02-04 20:25:54,059 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set node pbsdev-centos7-mky18-mom2 state+=offline 2021-02-04 20:25:54,079 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:54,085 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:54,089 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:54,093 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:54,097 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:54,101 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:54,104 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:54,109 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:54,115 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:54,121 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:54,127 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x1" - with existence... OK 2021-02-04 20:25:54,131 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_OFFLINE,ND_STATE_VNODE_UNAVAILABLE" - with existence... OK 2021-02-04 20:25:54,135 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=1,409903" - with existence... OK 2021-02-04 20:25:54,135 INFO manager on pbsdev-centos7-mky18-server: set node pbsdev-centos7-mky18-mom2 {'state': (3, 'offline')} 2021-02-04 20:25:54,135 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set node pbsdev-centos7-mky18-mom2 state-=offline 2021-02-04 20:25:54,159 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:25:54,163 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:25:54,167 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:25:54,171 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:25:54,175 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:25:54,180 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:25:54,185 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:25:54,190 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:25:54,194 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:25:54,198 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:25:54,200 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:25:54,203 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:25:54,206 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:25:54,207 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/pbs_rsub -R 202102042026.09 -E 202102042026.10 --hosts pbsdev-centos7-mky18-mom2 2021-02-04 20:25:54,224 INFO submit to pbsdev-centos7-mky18-server as root: reservation M15.pbsdev-centos7-mky18-server CONFIRMED OrderedDict([('reserve_start', 1612470369.2070022), ('reserve_end', 1612470370.2070022)]) 2021-02-04 20:25:54,228 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - No match 2021-02-04 20:25:55,452 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 2 2021-02-04 20:25:56,681 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 3 2021-02-04 20:25:57,904 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 4 2021-02-04 20:25:59,112 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 5 2021-02-04 20:26:00,320 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 6 2021-02-04 20:26:01,531 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 7 2021-02-04 20:26:02,738 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 8 2021-02-04 20:26:03,950 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 9 2021-02-04 20:26:05,176 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 10 2021-02-04 20:26:06,389 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 11 2021-02-04 20:26:07,611 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 12 2021-02-04 20:26:08,820 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence - attempt 13 2021-02-04 20:26:10,027 INFO server pbsdev-centos7-mky18-server log match: searching for "set_vnode_state;vnode.state=" - with existence... OK 2021-02-04 20:26:10,035 INFO server pbsdev-centos7-mky18-server log match: searching for "show_vnode_state;name=" - with existence... OK 2021-02-04 20:26:10,038 INFO server pbsdev-centos7-mky18-server log match: searching for "name: v=" - with existence... OK 2021-02-04 20:26:10,041 INFO server pbsdev-centos7-mky18-server log match: searching for "state: v=" - with existence... OK 2021-02-04 20:26:10,043 INFO server pbsdev-centos7-mky18-server log match: searching for "last_state_change_time: v=" - with existence... OK 2021-02-04 20:26:10,046 INFO server pbsdev-centos7-mky18-server log match: searching for "good times" - with existence... OK 2021-02-04 20:26:10,050 INFO server pbsdev-centos7-mky18-server log match: searching for "good names" - with existence... OK 2021-02-04 20:26:10,054 INFO server pbsdev-centos7-mky18-server log match: searching for "good states" - with existence... OK 2021-02-04 20:26:10,058 INFO server pbsdev-centos7-mky18-server log match: searching for "good v sets" - with existence... OK 2021-02-04 20:26:10,061 INFO server pbsdev-centos7-mky18-server log match: searching for "good v_o sets" - with existence... OK 2021-02-04 20:26:10,064 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x2000" - with existence... OK 2021-02-04 20:26:10,066 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_RESV_EXCLUSIVE" - with existence... OK 2021-02-04 20:26:10,071 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=8192" - with existence... OK 2021-02-04 20:26:10,075 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence - No match 2021-02-04 20:26:11,286 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_hex=0x0" - with existence... OK 2021-02-04 20:26:11,293 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_strs=ND_STATE_FREE" - with existence... OK 2021-02-04 20:26:11,297 INFO server pbsdev-centos7-mky18-server log match: searching for "v.state_ints=0" - with existence... OK 2021-02-04 20:26:11,297 INFO checkpreviousStateChain search_string=;show_vnode_state;name=pbsdev-centos7-mky18-mom2 start=1612470338.960693 end=1612470371.2977176 2021-02-04 20:26:11,334 INFO server pbsdev-centos7-mky18-server log match: searching for ";show_vnode_state;name=pbsdev-centos7-mky18-mom2" - on all matches - with existence... OK 2021-02-04 20:26:11,335 INFO ================================================ 2021-02-04 20:26:11,335 INFO Entered TestPbsModifyvnodeStateChanges tearDown 2021-02-04 20:26:11,335 INFO ================================================ 2021-02-04 20:26:11,336 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -Bf pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:26:11,347 INFO status on pbsdev-centos7-mky18-server: job 2021-02-04 20:26:11,348 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -f @pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:26:11,563 INFO status on pbsdev-centos7-mky18-server: sched 2021-02-04 20:26:11,564 INFO manager on pbsdev-centos7-mky18-server: list sched 2021-02-04 20:26:11,564 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched 2021-02-04 20:26:11,576 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:26:11,586 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:26:11,597 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:26:11,614 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:26:11,627 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:26:11,640 INFO manager on pbsdev-centos7-mky18-server as root: set sched default {'scheduling': 'False'} 2021-02-04 20:26:11,641 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set sched default scheduling=False 2021-02-04 20:26:11,655 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:26:11,667 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:26:11,679 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:26:11,691 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:26:11,711 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:26:11,722 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:26:11,734 INFO expect on server pbsdev-centos7-mky18-server: state != scheduling sched default ... OK 2021-02-04 20:26:11,734 INFO delete job on pbsdev-centos7-mky18-server as root: 2021-02-04 20:26:11,734 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qstat -f @pbsdev-centos7-mky18-server.pbsdev-centos7-mky18.local 2021-02-04 20:26:11,953 INFO expect on server pbsdev-centos7-mky18-server: job_state set 0 job ... OK 2021-02-04 20:26:11,954 INFO manager on pbsdev-centos7-mky18-server as root: set sched default {'scheduling': 'True'} 2021-02-04 20:26:11,954 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c set sched default scheduling=True 2021-02-04 20:26:11,969 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched default 2021-02-04 20:26:11,980 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:26:11,993 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:26:12,007 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:26:12,026 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:26:12,038 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:26:12,053 INFO expect on server pbsdev-centos7-mky18-server: scheduling = True sched default ... OK 2021-02-04 20:26:12,054 INFO manager on pbsdev-centos7-mky18-server: list sched 2021-02-04 20:26:12,054 INFOCLI pbsdev-centos7-mky18-server: /opt/pbs/bin/qmgr -c list sched 2021-02-04 20:26:12,065 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/chown -R root /var/spool/pbs/sched_priv 2021-02-04 20:26:12,076 INFO scheduler pbsdev-centos7-mky18-server: setting dedicated time file to /var/spool/pbs/sched_priv/dedicated_time 2021-02-04 20:26:12,091 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /opt/pbs/sbin/pbsfs 2021-02-04 20:26:12,107 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/resource_group 2021-02-04 20:26:12,121 INFOCLI2 pbsdev-centos7-mky18-server: sudo -H /usr/bin/cat /var/spool/pbs/sched_priv/holidays 2021-02-04 20:26:12,132 INFO ================================================= 2021-02-04 20:26:12,133 INFO Completed TestPbsModifyvnodeStateChanges tearDown 2021-02-04 20:26:12,133 INFO ================================================= 2021-02-04 20:26:12,134 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import platform;print(' '.join(platform.uname()))" 2021-02-04 20:26:12,192 INFOCLI2 pbsdev-centos7-mky18-mom1: ssh pbsdev-centos7-mky18-mom1.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import platform; print(platform.platform())" 2021-02-04 20:26:12,250 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import platform;print(' '.join(platform.uname()))" 2021-02-04 20:26:12,306 INFOCLI2 pbsdev-centos7-mky18-mom2: ssh pbsdev-centos7-mky18-mom2.pbsdev-centos7-mky18.local /usr/bin/python3 -c "import platform; print(platform.platform())" 2021-02-04 20:26:12,367 INFO ok 2021-02-04 20:26:12,368 INFO ================================================================================ run: 1, succeeded: 1, failed: 0, errors: 0, skipped: 0, timedout: 0 Tests run in 0:01:31.009484 2021-02-04 20:26:12,368 INFO Cleaning up temporary files 2021-02-04 20:26:12,368 INFO Cleaning up /var/tmp dir 2021-02-04 20:26:12,368 INFO Cleaning up /tmp dir real 1m31.365s user 0m38.276s sys 0m4.732s [02/04 20:26:12] pbsdev@pbsdev-centos7-mky18-server:~ 52% [02/04 20:26:38] pbsdev@pbsdev-centos7-mky18-server:~ 52%