2019-03-06 01:28:46,355 INFO input command: pbs_benchpress -t TestQsubOptionsArguments.test_qsub_with_script_with_long_TMPDIR -o /root/test_qsub_with_script_with_long_TMPDIR_BeforeFix.ptl.txt 2019-03-06 01:28:46,355 INFO param: None 2019-03-06 01:28:46,355 INFO ptl version: 19.2.2.20190123192917 2019-03-06 01:28:46,356 INFO platform: Linux c7-dev 3.10.0-862.14.4.el7.x86_64 #1 SMP Wed Sep 26 15:12:11 UTC 2018 x86_64 x86_64 2019-03-06 01:28:46,356 INFO python version: 2.7.5 2019-03-06 01:28:46,356 INFO user: root 2019-03-06 01:28:46,356 INFO -------------------------------------------------------------------------------- 2019-03-06 01:28:46,356 INFO Cleaning up temporary files 2019-03-06 01:28:46,358 INFO Cleaning up /var/tmp dir 2019-03-06 01:28:46,358 INFO Cleaning up /tmp dir 2019-03-06 01:28:47,837 INFO ====================================================================== 2019-03-06 01:28:47,845 INFO suite name: TestQsubOptionsArguments 2019-03-06 01:28:47,845 INFO suite docstring: validate qsub submission with a script and executable. note: The no-arg test is an interactive job, which is tested in SmokeTest.test_interactive_job 2019-03-06 01:28:47,845 INFO ====================================================================== 2019-03-06 01:28:47,845 INFO ============================================ 2019-03-06 01:28:47,846 INFO Entered TestQsubOptionsArguments setUpClass 2019-03-06 01:28:47,846 INFO ============================================ 2019-03-06 01:28:47,846 INFOCLI2 c7-dev: id pbsuser 2019-03-06 01:28:47,868 INFOCLI2 c7-dev: id pbsuser1 2019-03-06 01:28:47,881 INFOCLI2 c7-dev: id pbsuser2 2019-03-06 01:28:47,891 INFOCLI2 c7-dev: id pbsuser3 2019-03-06 01:28:47,935 INFO server c7-dev: server operating mode set to cli 2019-03-06 01:28:47,936 INFOCLI c7-dev: /opt/pbs/bin/qstat -Bf c7-dev 2019-03-06 01:28:47,983 INFO server c7-dev: version 19.0.0 2019-03-06 01:28:47,983 INFO expect action: created new action kicksched 2019-03-06 01:28:47,983 INFO expect action: added action kicksched to server c7-dev 2019-03-06 01:28:48,074 INFOCLI2 c7-dev: sudo -H /opt/pbs/sbin/pbsfs 2019-03-06 01:28:48,164 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/resource_group 2019-03-06 01:28:48,205 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/holidays 2019-03-06 01:28:48,278 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c list sched default 2019-03-06 01:28:48,368 INFOCLI2 c7-dev: sudo -H /opt/pbs/sbin/pbsfs 2019-03-06 01:28:48,451 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/resource_group 2019-03-06 01:28:48,491 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/holidays 2019-03-06 01:28:48,572 INFO ============================================= 2019-03-06 01:28:48,572 INFO Completed TestQsubOptionsArguments setUpClass 2019-03-06 01:28:48,572 INFO ============================================= 2019-03-06 01:28:48,573 INFO test name: test_qsub_with_script_with_long_TMPDIR (tests.functional.pbs_qsub_opts_args.TestQsubOptionsArguments)... 2019-03-06 01:28:48,574 INFO test start time: Wed Mar 6 01:28:48 2019 2019-03-06 01:28:48,574 INFO test docstring: submit a job with a script and long TMPDIR 2019-03-06 01:28:48,574 INFO ======================================= 2019-03-06 01:28:48,574 INFO Entered TestQsubOptionsArguments setUp 2019-03-06 01:28:48,575 INFO ======================================= 2019-03-06 01:28:48,575 INFOCLI c7-dev: /opt/pbs/bin/qstat -Bf c7-dev 2019-03-06 01:28:48,613 INFO status on c7-dev: server 2019-03-06 01:28:48,614 INFOCLI c7-dev: /opt/pbs/bin/qstat -Bf c7-dev 2019-03-06 01:28:48,652 INFO manager on c7-dev: unset server managers 2019-03-06 01:28:48,653 INFOCLI c7-dev: sudo -H /opt/pbs/bin/qmgr -c unset server managers 2019-03-06 01:28:48,744 INFOCLI c7-dev: /opt/pbs/bin/qstat -Bf c7-dev 2019-03-06 01:28:48,797 INFO expect on server c7-dev: managers unset server c7-dev ... OK 2019-03-06 01:28:48,798 INFO manager on c7-dev: set server {'managers': (2, 'root@*')} 2019-03-06 01:28:48,798 INFOCLI c7-dev: sudo -H /opt/pbs/bin/qmgr -c set server managers+=root@* 2019-03-06 01:28:48,897 INFO server c7-dev: reverting configuration to defaults 2019-03-06 01:28:48,898 INFOCLI c7-dev: /opt/pbs/bin/qstat -Bf c7-dev 2019-03-06 01:28:48,928 INFO select on c7-dev: __ALL__ 2019-03-06 01:28:48,929 INFOCLI c7-dev: /opt/pbs/bin/qselect 2019-03-06 01:28:48,967 INFOCLI c7-dev: /opt/pbs/bin/qstat -f @c7-dev 2019-03-06 01:28:49,021 INFO expect on server c7-dev: job_state set 0 job ... OK 2019-03-06 01:28:49,022 INFOCLI c7-dev: /opt/pbs/bin/pbs_rstat -f 2019-03-06 01:28:49,063 INFO manager on c7-dev: unset server ['pbs_license_min', 'pbs_license_max'] 2019-03-06 01:28:49,064 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c unset server pbs_license_min,pbs_license_max 2019-03-06 01:28:49,122 INFOCLI c7-dev: sudo -H /opt/pbs/bin/qmgr -c list hook 2019-03-06 01:28:49,194 INFOCLI c7-dev: /opt/pbs/bin/qstat -Qf @c7-dev 2019-03-06 01:28:49,229 INFO status on c7-dev: node 2019-03-06 01:28:49,229 INFOCLI c7-dev: /opt/pbs/bin/pbsnodes -s c7-dev -v -a 2019-03-06 01:28:49,290 INFO manager on c7-dev: delete queue workq 2019-03-06 01:28:49,291 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c delete queue workq 2019-03-06 01:28:49,332 INFO server c7-dev: expect offset set to 0.5 2019-03-06 01:28:49,835 INFOCLI c7-dev: /opt/pbs/bin/qstat -Qf workq@c7-dev 2019-03-06 01:28:49,861 INFO expect on server c7-dev: unset queue workq ... OK 2019-03-06 01:28:49,862 INFO manager on c7-dev: create queue workq {'started': 'True', 'queue_type': 'Execution', 'enabled': 'True'} 2019-03-06 01:28:49,862 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c create queue workq started=True,queue_type=Execution,enabled=True 2019-03-06 01:28:49,910 INFO status on c7-dev: queue workq 2019-03-06 01:28:49,911 INFOCLI c7-dev: /opt/pbs/bin/qstat -Qf workq@c7-dev 2019-03-06 01:28:49,940 INFO server c7-dev: expect offset set to 0.5 2019-03-06 01:28:50,443 INFOCLI c7-dev: /opt/pbs/bin/qstat -Qf workq@c7-dev 2019-03-06 01:28:50,485 INFO expect on server c7-dev: started set True || queue_type set Execution || enabled set True queue workq ... OK 2019-03-06 01:28:50,487 INFO manager on c7-dev: list sched 2019-03-06 01:28:50,487 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c list sched 2019-03-06 01:28:50,586 INFOCLI2 c7-dev: sudo -H /opt/pbs/sbin/pbsfs 2019-03-06 01:28:50,645 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/resource_group 2019-03-06 01:28:50,692 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/holidays 2019-03-06 01:28:50,761 INFO manager on c7-dev: set server {'scheduler_iteration': '600', 'default_queue': 'workq'} 2019-03-06 01:28:50,762 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c set server scheduler_iteration=600,default_queue=workq 2019-03-06 01:28:50,831 INFO status on c7-dev: resource 2019-03-06 01:28:50,832 INFO manager on c7-dev: list resource 2019-03-06 01:28:50,832 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c list resource 2019-03-06 01:28:50,941 INFOCLI status on c7-dev: server license_count 2019-03-06 01:28:50,944 INFOCLI c7-dev: /opt/pbs/bin/qstat -Bf c7-dev 2019-03-06 01:28:50,991 INFO server: c7-dev licensed 2019-03-06 01:28:51,117 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/server_priv/comm.lock 2019-03-06 01:28:51,230 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/sched.lock 2019-03-06 01:28:51,314 INFO scheduler c7-dev: reverting configuration to defaults 2019-03-06 01:28:51,315 INFO manager on c7-dev: unset sched ['sched_priv', 'sched_cycle_length', 'preempt_prio', 'preempt_queue_prio', 'scheduler_iteration', 'preempt_order', 'scheduling', 'sched_log'] 2019-03-06 01:28:51,315 INFOCLI c7-dev: /opt/pbs/bin/qmgr -c unset sched sched_priv,sched_cycle_length,preempt_prio,preempt_queue_prio,scheduler_iteration,preempt_order,scheduling,sched_log 2019-03-06 01:28:51,418 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/dedicated_time 2019-03-06 01:28:51,471 INFOCLI2 c7-dev: sudo -H cmp /opt/pbs/etc/pbs_resource_group /var/spool/pbs/sched_priv/resource_group 2019-03-06 01:28:51,555 INFO scheduler c7-dev: reverting holidays file to default 2019-03-06 01:28:51,556 INFOCLI2 c7-dev: sudo -H cmp /opt/pbs/etc/pbs_holidays /var/spool/pbs/sched_priv/holidays 2019-03-06 01:28:51,640 INFOCLI2 c7-dev: sudo -H cmp /opt/pbs/etc/pbs_sched_config /var/spool/pbs/sched_priv/sched_config 2019-03-06 01:28:51,756 INFO scheduler c7-dev: sent signal -HUP 2019-03-06 01:28:51,757 INFOCLI2 c7-dev: sudo -H kill -HUP 57234 2019-03-06 01:28:51,820 INFOCLI2 c7-dev: sudo -H /opt/pbs/sbin/pbsfs -e -I default 2019-03-06 01:28:52,041 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/sched_priv/sched.lock 2019-03-06 01:28:52,163 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/mom_priv/mom.lock 2019-03-06 01:28:52,205 INFOCLI2 c7-dev: sudo -H /opt/pbs/sbin/pbs_mom --version 2019-03-06 01:28:52,267 INFO mom c7-dev: reverting configuration to defaults 2019-03-06 01:28:52,268 INFOCLI2 c7-dev: which rm 2019-03-06 01:28:52,276 INFOCLI2 c7-dev: sudo -H /bin/rm -f /var/spool/pbs/mom_priv/epilogue 2019-03-06 01:28:52,320 INFOCLI2 c7-dev: sudo -H /bin/rm -f /var/spool/pbs/mom_priv/prologue 2019-03-06 01:28:52,363 INFOCLI c7-dev: sudo -H /opt/pbs/sbin/pbs_mom -s list 2019-03-06 01:28:52,500 INFOCLI2 c7-dev: which cp 2019-03-06 01:28:52,528 INFOCLI2 c7-dev: sudo -H /bin/cp /tmp/PtlPbscuiOev /var/spool/pbs/mom_priv/config 2019-03-06 01:28:52,670 INFO mom c7-dev: sent signal -HUP 2019-03-06 01:28:52,671 INFOCLI2 c7-dev: sudo -H kill -HUP 57222 2019-03-06 01:28:52,899 INFOCLI2 c7-dev: sudo -H /bin/cat /var/spool/pbs/mom_priv/mom.lock 2019-03-06 01:28:52,968 INFOCLI c7-dev: /opt/pbs/bin/pbsnodes -s c7-dev -v -a 2019-03-06 01:28:53,075 INFO status on c7-dev: node c7-dev 2019-03-06 01:28:53,076 INFOCLI c7-dev: /opt/pbs/bin/pbsnodes -s c7-dev -v c7-dev 2019-03-06 01:28:53,112 INFOCLI c7-dev: /opt/pbs/bin/pbsnodes -s c7-dev -v c7-dev 2019-03-06 01:28:53,142 INFO expect on server c7-dev: state = free node c7-dev ... OK 2019-03-06 01:28:53,143 INFO ======================================== 2019-03-06 01:28:53,143 INFO Completed TestQsubOptionsArguments setUp 2019-03-06 01:28:53,143 INFO ======================================== 2019-03-06 01:28:53,144 INFOCLI2 c7-dev: /opt/pbs/bin/qsub /tmp/PtlPbsaakr6P 2019-03-06 01:28:53,284 INFO FAILED 2019-03-06 01:28:53,285 INFO ========================================== 2019-03-06 01:28:53,290 INFO Entered TestQsubOptionsArguments tearDown 2019-03-06 01:28:53,291 INFO ========================================== 2019-03-06 01:28:53,291 INFO =========================================== 2019-03-06 01:28:53,291 INFO Completed TestQsubOptionsArguments tearDown 2019-03-06 01:28:53,292 INFO =========================================== 2019-03-06 01:28:53,294 INFO 2019-03-06 01:28:53,308 INFO ====================================================================== 2019-03-06 01:28:53,309 INFO FAILED: test_qsub_with_script_with_long_TMPDIR (tests.functional.pbs_qsub_opts_args.TestQsubOptionsArguments) 2019-03-06 01:28:53,309 INFO ___m_oo_m___ 2019-03-06 01:28:53,309 INFO Traceback (most recent call last): File "/home/mohammh/github/riyazhakki/pbspro/test/tests/functional/pbs_qsub_opts_args.py", line 67, in test_qsub_with_script_with_long_TMPDIR self.assertEquals(rv['rc'], 0, 'qsub failed') AssertionError: qsub failed 2019-03-06 01:28:53,310 INFO ================================================================================ failed: test_qsub_with_script_with_long_TMPDIR (tests.functional.pbs_qsub_opts_args.TestQsubOptionsArguments) Test cases with failures: TestQsubOptionsArguments.test_qsub_with_script_with_long_TMPDIR Test suites with failures: TestQsubOptionsArguments run: 1, succeeded: 0, failed: 1, errors: 0, skipped: 0, timedout: 0 Tests run in 0:00:05.465887 2019-03-06 01:28:53,310 INFO Cleaning up temporary files 2019-03-06 01:28:53,310 INFO Cleaning up /var/tmp dir 2019-03-06 01:28:53,314 INFO Cleaning up /root/aaaaaaaaaa/bbbbbbbbbb/cccccccccc/eeeeeeeeee/ffffffffff/gggggggggg/hhhhhhhhhh/iiiiiiiiii/jj/afdj/hlppoo/jkloiytupoo/bhtiusabsdlg dir 2019-03-06 01:28:53,399 INFO Cleaning up /tmp dir