[mpich-discuss] mpiexec kills the remote login shell

[Yu-Cheng Chou]

Hi,

Please check the attached smpd debug output for running hellow.

Thank you

On Wed, Feb 4, 2009 at 11:04 AM, Jayesh Krishna <jayesh at mcs.anl.gov> wrote:
>  Hi,
>   Can you also attach the corresponding smpd debug output ?
>
> Regards,
> Jayesh
>
> -----Original Message-----
> From: Yu-Cheng Chou [mailto:cycchou at ucdavis.edu]
> Sent: Wednesday, February 04, 2009 1:02 PM
> To: Jayesh Krishna
> Cc: mpich-discuss at mcs.anl.gov
> Subject: Re: [mpich-discuss] mpiexec kills the remote login shell
>
> Hi,
>
> Firstly, the previously attached mpiexec verbose output is a wrong one.
> I've attached the correct one to this email.
>
> Secondly, I want to point out that as long as mpiexec is initiated from
> Korebot to run a program, no matter it's a MPI or non-MPI program, no matter
> the program can be found or not, as soon as mpiexec is finished, the ssh
> connection to Korebot will be gone.
>
> Thank you
>
>
>> Hi,
>>   The mpiexec output shows the following error when running hellow,
>> ==================
>>
>> Unable to exec 'hello' on korebot
>>
>> Error 2 - No such file or directory
>>
>> ==================
>>
>>   Please provide the debug output of smpd (smpd -d 2>&1 | tee
>> smpd.out) along with mpiexec (mpiexec -verbose -n 2 ./hellow 2>&1 |
>> tee mpiexec.out).
>>
>> #  Can you run simple C programs (without using mpiexec) on Korbet ?
>> #  Is the ssh connection aborted when you run non-MPI programs
>> (mpiexec -n 2
>> hostname) ?
>> #  Can you send us your ".smpd" config file ?
>> #  Did you modify the MPICH2 code to run on Korbet (Please send us
>> your configure command & any env settings set to configure/make MPICH2)?
>>
>> Regards,
>> Jayesh
>>
>> ________________________________
>> From: mpich-discuss-bounces at mcs.anl.gov
>> [mailto:mpich-discuss-bounces at mcs.anl.gov] On Behalf Of Jayesh Krishna
>> Sent: Wednesday, February 04, 2009 8:41 AM
>> To: 'Yu-Cheng Chou'
>> Cc: mpich-discuss at mcs.anl.gov
>> Subject: Re: [mpich-discuss] mpiexec kills the remote login shell
>>
>>  Hi,
>>   I will take a look at the debug logs and get back to you. Meanwhile,
>> can you run simple C programs without using mpiexec on Korbet ?
>>   MPICH2 currently does not support heterogeneous systems (So you
>> won't be able to run your MPI job across ARM & other architectures).
>>
>> Regards,
>> Jayesh
>>
>> -----Original Message-----
>> From: Yu-Cheng Chou [mailto:cycchou at ucdavis.edu]
>> Sent: Tuesday, February 03, 2009 7:52 PM
>> To: Jayesh Krishna
>> Cc: mpich-discuss at mcs.anl.gov
>> Subject: Re: [mpich-discuss] mpiexec kills the remote login shell
>>
>>> # Can you run non-MPI programs using mpiexec (mpiexec -n 2 hostname) ?
>> Yes.
>>
>>> # Can you compile and run the hello world program (examples/hellow.c)
>>> provided with MPICH2 (mpiexec -n 2 ./hellow)?
>> Yes.
>>
>>> # How did you start smpd (the command used to start smpd) ? How did
>>> you run your MPI job (the command used to run your job)?
>> I have a ".smpd" file containing one line of information, which is
>> "phrase=123".
>> Thus, I started smpd using "smpd -s".
>> Then I used "mpiexec -n 1 hellow" to run hellow on Korebot.
>>
>>> # How did you find that mpiexec kills the sshd process (We typically
>>> ssh to unix machines and run mpiexec without any problems) ?
>> I logged in Korebot with two terminals.
>> >From #1 terminal, I checked all the processes running on Korebot.
>> >From #2 terminal, I started smpd and run hellow using the commands
>> mentioned above.
>> After hellow was finished, the connection to Korebot via #2 terminal
>> was closed.
>> >From #1 terminal, I knew that the sshd process associated with #2
>> >terminal
>> was gone.
>>
>>>  Can you run smpd/mpiexec in debug mode and provide us with the
>>> outputs (smpd -d / mpiexec -n 2 -verbose hostname) ?
>> The first attached text file is the output from running hellow in
>> mpiexec's verbose mode.
>>
>>
>> There is another issue.
>> This time, I used two machines. One is Korebot as mentioned above, and
>> the other is a laptop running Ubuntu Linux OS.
>> I started smpd with the same ".smpd" file and command as mentioned
>> above both on Korebot and the lap top.
>> There is a machine file called "hostfile" on Korebot. The file
>> contains the following information about the name of the two machines.
>>
>> korebot
>> shrimp
>>
>> Then from Korebot, I ran cpi using the following command.
>>
>> mpiexec -machinefile ./hostfile -verbose -n 2 cpi
>>
>>
>> But the value of pi is a huge number. I think it is related to "double
>> type variables" being transferred between processes running on an
>> ARM-based Linux and a general Linux machines.
>>
>> The second attached text file is the output from running cpi in
>> mpiexec's verbose mode.
>>
>>
>>>
>>> I am cross-compiling mpich2-1.0.8 with smpd for Khepera III mobile robot.
>>>
>>> This mobile robot has a Korebot board which is an ARM-based computer
>>> with a Linux operating system.
>>>
>>> The cross-compilation was fine.
>>>
>>> Firstly, I logged in to Korebot through ssh.
>>> Secondly, I started smpd.
>>> Thirdly, I ran mpiexec to execute an MPI program (cpi) that comes
>>> with the package.
>>>
>>> The result was correct, but when mpiexec was finished, the ssh
>>> connection to the Korebot was closed.
>>> I found that mpiexec kills the sshd process through which I was
>>> remotely connected to Korebot.
>>>
>>> I've been looking for the cause, but still have not found any clues.
>>>
>>> Could you give me any ideas to solve this problem?
>>>
>>> Thank you,
>>>
>>> Yu-Cheng
>>>
>>
>
-------------- next part --------------
~ # smpd -d
[-1:309]..\smpd_get_opt_int
[-1:309]../smpd_get_opt_int
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_int
[-1:309]../smpd_get_opt_int
[-1:309]..\smpd_get_opt_int
[-1:309]../smpd_get_opt_int
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt_string
[-1:309]../smpd_get_opt_string
[-1:309]..\smpd_get_opt
[-1:309]../smpd_get_opt
[-1:309]./smpd_parse_command_args
[-1:309].\smpd_get_smpd_data
[-1:309]..\smpd_hide_string_arg
[-1:309]...\first_token
[-1:309].../first_token
[-1:309]...\compare_token
[-1:309].../compare_token
[-1:309]...\next_token
[-1:309]....\first_token
[-1:309]..../first_token
[-1:309]....\first_token
[-1:309]..../first_token
[-1:309].../next_token
[-1:309]../smpd_hide_string_arg
[-1:309]../smpd_hide_string_arg
[-1:309]..\smpd_get_smpd_data_from_environment
[-1:309]../smpd_get_smpd_data_from_environment
[-1:309]..\smpd_parse_smpd_file
[-1:309]...\smpd_open_smpd_file
[-1:309].../smpd_open_smpd_file
[-1:309]...\str_replace
[-1:309].../str_replace
[-1:309]../smpd_parse_smpd_file
[-1:309]..\smpd_hide_string_arg
[-1:309]...\first_token
[-1:309].../first_token
[-1:309]...\compare_token
[-1:309].../compare_token
[-1:309]...\next_token
[-1:309]....\first_token
[-1:309]..../first_token
[-1:309]....\first_token
[-1:309]..../first_token
[-1:309].../next_token
[-1:309]../smpd_hide_string_arg
[-1:309]../smpd_hide_string_arg
[-1:309]./smpd_get_smpd_data
[-1:309].\smpd_entry_point
[00:309]..created a set for the listener: 1
[00:309]..smpd listening on port 8676
[00:309]..\smpd_create_context
[00:309]...\smpd_init_context
[00:309]....\smpd_init_command
[00:309]..../smpd_init_command
[00:309].../smpd_init_context
[00:309]../smpd_create_context
[00:309]..\smpd_option_on
[00:309]...\smpd_get_smpd_data
[00:309]....getting smpd data: no_dynamic_hosts
[00:309]....\smpd_get_smpd_data_from_environment
[00:309]..../smpd_get_smpd_data_from_environment
[00:309]....\smpd_parse_smpd_file
[00:309].....\smpd_open_smpd_file
[00:309]...../smpd_open_smpd_file
[00:309].....\str_replace
[00:309]...../str_replace
[00:309]..../smpd_parse_smpd_file
[00:309]....\smpd_get_smpd_data_default
[00:309]..../smpd_get_smpd_data_default
[00:309]....smpd data: failed to get no_dynamic_hosts
[00:309].../smpd_get_smpd_data
[00:309]../smpd_option_on
[00:309]..\smpd_insert_into_dynamic_hosts
[00:309]...\smpd_lock_smpd_data
[00:309].../smpd_lock_smpd_data
[00:309]...\smpd_get_smpd_data
[00:309]....getting smpd data: dynamic_hosts
[00:309]....\smpd_get_smpd_data_from_environment
[00:309]..../smpd_get_smpd_data_from_environment
[00:309]....\smpd_parse_smpd_file
[00:309].....\smpd_open_smpd_file
[00:309]...../smpd_open_smpd_file
[00:309].....\str_replace
[00:309]...../str_replace
[00:309]..../smpd_parse_smpd_file
[00:309]....smpd data: dynamic_hosts=korebot
[00:309].../smpd_get_smpd_data
[00:309]...\smpd_unlock_smpd_data
[00:309].../smpd_unlock_smpd_data
[00:309]...\smpd_get_hostname
[00:309].../smpd_get_hostname
[00:309]../smpd_insert_into_dynamic_hosts
[00:309]..\smpd_enter_at_state
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_ACCEPT
[00:309]...\smpd_handle_op_accept
[00:309]....\smpd_state_smpd_listening
[00:309].....authenticating new connection
[00:309].....\smpd_create_context
[00:309]......\smpd_init_context
[00:309].......\smpd_init_command
[00:309]......./smpd_init_command
[00:309]....../smpd_init_context
[00:309]...../smpd_create_context
[00:309].....\smpd_gen_authentication_strings
[00:309]......\smpd_hash
[00:309]....../smpd_hash
[00:309]...../smpd_gen_authentication_strings
[00:309].....posting a write of the challenge string: 1.0.8 1848987135
[00:309]..../smpd_state_smpd_listening
[00:309].../smpd_handle_op_accept
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_WRITE
[00:309]...\smpd_handle_op_write
[00:309]....\smpd_state_writing_challenge_string
[00:309].....wrote challenge string: '1.0.8 1848987135'
[00:309]..../smpd_state_writing_challenge_string
[00:309].../smpd_handle_op_write
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_READ
[00:309]...\smpd_handle_op_read
[00:309]....\smpd_state_reading_challenge_response
[00:309].....read challenge response: 'ffb78e27d5b8321932135fd1ede9d4a0'
[00:309]..../smpd_state_reading_challenge_response
[00:309].../smpd_handle_op_read
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_WRITE
[00:309]...\smpd_handle_op_write
[00:309]....\smpd_state_writing_connect_result
[00:309].....wrote connect result: 'SUCCESS'
[00:309]..../smpd_state_writing_connect_result
[00:309].../smpd_handle_op_write
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_READ
[00:309]...\smpd_handle_op_read
[00:309]....\smpd_state_reading_session_request
[00:309].....read session request: 'process'
[00:309]..../smpd_state_reading_session_request
[00:309].../smpd_handle_op_read
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_WRITE
[00:309]...\smpd_handle_op_write
[00:309]....\smpd_state_writing_no_cred_request
[00:309].....wrote no cred request: 'nocredentials'
[00:309].....smpd writing noreconnect request
[00:309]..../smpd_state_writing_no_cred_request
[00:309].../smpd_handle_op_write
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_WRITE
[00:309]...\smpd_handle_op_write
[00:309]....\smpd_state_writing_no_reconnect_request
[00:309].....wrote no reconnect request: '-1'
[00:309].....root closing sock(16777217) after fork.
[00:309]..../smpd_state_writing_no_reconnect_request
[00:309].../smpd_handle_op_write
[00:309]...sock_waiting for the next event.
[00:309]...SOCK_OP_CLOSE
[00:309]...\smpd_handle_op_close
[00:309]....\smpd_get_state_string
[00:309]..../smpd_get_state_string
[00:309]....op_close received - SMPD_CLOSING state.
[00:309]....Unaffiliated undetermined context closing.
[00:309]....\smpd_free_context
[00:309].....freeing undetermined context.
[00:309].....\smpd_init_context
[00:309]......\smpd_init_command
[00:309]....../smpd_init_command
[00:309]...../smpd_init_context
[00:309]..../smpd_free_context
[00:309].../smpd_handle_op_close
[00:309]...sock_waiting for the next event.
[00:314].....child closing listener sock(16777216) after fork.
[00:314]..../smpd_state_writing_no_reconnect_request
[00:314].../smpd_handle_op_write
[00:314]...sock_waiting for the next event.
[00:314]...SOCK_OP_CLOSE
[00:314]...\smpd_handle_op_close
[00:314]....\smpd_get_state_string
[00:314]..../smpd_get_state_string
[00:314]....op_close received - SMPD_CLOSING state.
[00:314]....Unaffiliated listener context closing.
[00:314]....\smpd_free_context
[00:314].....freeing listener context.
[00:314].....\smpd_init_context
[00:314]......\smpd_init_command
[00:314]....../smpd_init_command
[00:314]...../smpd_init_context
[00:314]..../smpd_free_context
[00:314].../smpd_handle_op_close
[00:314]...sock_waiting for the next event.
[00:314]...SOCK_OP_READ
[00:314]...\smpd_handle_op_read
[00:314]....\smpd_state_reading_session_header
[00:314].....read session header: 'id=1 parent=0 level=0'
[00:314].....\smpd_interpret_session_header
[00:314]......interpreting session header: "id=1 parent=0 level=0"
[00:314]...... id = 1
[01:314]...... parent = 0
[01:314]...... level = 0
[01:314]...../smpd_interpret_session_header
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the parent context, sock 16777217
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_session_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 34 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=start_dbs src=0 dest=1 tag=0 "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 0
[01:314]...... dest = 1
[01:314]...... cmd  = start_dbs
[01:314]...... tag  = 0
[01:314]...... ctx  = parent
[01:314]...... len  = 34
[01:314]...... str  = cmd=start_dbs src=0 dest=1 tag=0
[01:314]......\smpd_command_destination
[01:314].......1 -> 1 : returning NULL context
[01:314]....../smpd_command_destination
[01:314]......\smpd_handle_start_dbs_command
[01:314].......\smpd_dbs_init
[01:314]......./smpd_dbs_init
[01:314].......\smpd_create_command
[01:314]........\smpd_init_command
[01:314]......../smpd_init_command
[01:314]......./smpd_create_command
[01:314].......\smpd_add_command_int_arg
[01:314]......./smpd_add_command_int_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\smpd_dbs_create
[01:314]......./smpd_dbs_create
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......sending result command to parent context: "cmd=result src=1 dest=0 tag=0 cmd_tag=0 cmd_orig=start_dbs kvs_name=5025BEF03131526E7E15C5D37B0BF187 domain_name=5BC0A89F4ECAFD147EFC959B317B05E2 result=SUCCESS "
[01:314].......\smpd_post_write_command
[01:314]........\smpd_package_command
[01:314]......../smpd_package_command
[01:314]........smpd_post_write_command on the parent context sock 16777217: 175 bytes for command: "cmd=result src=1 dest=0 tag=0 cmd_tag=0 cmd_orig=start_dbs kvs_name=5025BEF03131526E7E15C5D37B0BF187 domain_name=5BC0A89F4ECAFD147EFC959B317B05E2 result=SUCCESS "
[01:314]......./smpd_post_write_command
[01:314]....../smpd_handle_start_dbs_command
[01:314]...../smpd_handle_command
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the parent context, sock 16777217
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to parent: "cmd=result src=1 dest=0 tag=0 cmd_tag=0 cmd_orig=start_dbs kvs_name=5025BEF03131526E7E15C5D37B0BF187 domain_name=5BC0A89F4ECAFD147EFC959B317B05E2 result=SUCCESS "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 146 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=launch src=0 dest=1 tag=1 c=hellow s=0 a=0 d=/root p=/bin q=0 i=0 n=1 k=5025BEF03131526E7E15C5D37B0BF187 kd=5BC0A89F4ECAFD147EFC959B317B05E2 "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 0
[01:314]...... dest = 1
[01:314]...... cmd  = launch
[01:314]...... tag  = 1
[01:314]...... ctx  = parent
[01:314]...... len  = 146
[01:314]...... str  = cmd=launch src=0 dest=1 tag=1 c=hellow s=0 a=0 d=/root p=/bin q=0 i=0 n=1 k=5025BEF03131526E7E15C5D37B0BF187 kd=5BC0A89F4ECAFD147EFC959B317B05E2
[01:314]......\smpd_command_destination
[01:314].......1 -> 1 : returning NULL context
[01:314]....../smpd_command_destination
[01:314]......\smpd_handle_launch_command
[01:314].......\smpd_create_process_struct
[01:314]........\smpd_create_context
[01:314].........\smpd_init_context
[01:314]..........\smpd_init_command
[01:314]........../smpd_init_command
[01:314]........./smpd_init_context
[01:314]......../smpd_create_context
[01:314]........\smpd_create_context
[01:314].........\smpd_init_context
[01:314]..........\smpd_init_command
[01:314]........../smpd_init_command
[01:314]........./smpd_init_context
[01:314]......../smpd_create_context
[01:314]........\smpd_create_context
[01:314].........\smpd_init_context
[01:314]..........\smpd_init_command
[01:314]........../smpd_init_command
[01:314]........./smpd_init_context
[01:314]......../smpd_create_context
[01:314]........\smpd_create_context
[01:314].........\smpd_init_context
[01:314]..........\smpd_init_command
[01:314]........../smpd_init_command
[01:314]........./smpd_init_context
[01:314]......../smpd_create_context
[01:314]......./smpd_create_process_struct
[01:314].......launching: 'hellow'
[01:314].......\smpd_launch_process
[01:314]........searching for 'hellow' in '/bin'
[01:314]........\smpd_search_path
[01:314]......../smpd_search_path
[01:314]........found: '/bin/hellow'
[01:314]........\smpd_post_read_command
[01:314].........posting a read for a command header on the pmi context, sock 16777220
[01:314]......../smpd_post_read_command
[01:314]......./smpd_launch_process
[01:314].......\smpd_create_command
[01:314]........\smpd_init_command
[01:314]......../smpd_init_command
[01:314]......./smpd_create_command
[01:314].......\smpd_add_command_int_arg
[01:314]......./smpd_add_command_int_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\smpd_add_command_int_arg
[01:314]......./smpd_add_command_int_arg
[01:314].......\smpd_add_command_int_arg
[01:314]......./smpd_add_command_int_arg
[01:314].......\smpd_post_write_command
[01:314]........\smpd_package_command
[01:314]......../smpd_package_command
[01:314]........smpd_post_write_command on the parent context sock 16777217: 143 bytes for command: "cmd=result src=1 dest=0 tag=1 cmd_tag=1 cmd_orig=launch result=SUCCESS pg_id=5025BEF03131526E7E15C5D37B0BF187 pg_rank=0 pg_ctx=0 "
[01:314]......./smpd_post_write_command
[01:314]....../smpd_handle_launch_command
[01:314]...../smpd_handle_command
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the parent context, sock 16777217
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:315]........client is alive and about to exec '/bin/hellow'
[01:315]........env: PMI_RANK=0
[01:315]........env: PMI_SIZE=1
[01:315]........env: PMI_KVS=5025BEF03131526E7E15C5D37B0BF187
[01:315]........env: PMI_DOMAIN=5BC0A89F4ECAFD147EFC959B317B05E2
[01:315]........env: PMI_SMPD_FD=12
[01:315]........env: PMI_SMPD_ID=1
[01:315]........env: PMI_SMPD_KEY=0
[01:315]........env: PMI_SPAWN=0
[01:315]........env: PMI_APPNUM=0
[01:315]........env: PMI_CLIQUE=0
[01:315]........\set_environment_variables
[01:315]......../set_environment_variables
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to parent: "cmd=result src=1 dest=0 tag=1 cmd_tag=1 cmd_orig=launch result=SUCCESS pg_id=5025BEF03131526E7E15C5D37B0BF187 pg_rank=0 pg_ctx=0 "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 101 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=init src=1 dest=0 tag=0 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 value=1 node_id=1 "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 1
[01:314]...... dest = 0
[01:314]...... cmd  = init
[01:314]...... tag  = 0
[01:314]...... ctx  = pmi
[01:314]...... len  = 101
[01:314]...... str  = cmd=init src=1 dest=0 tag=0 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 value=1 node_id=1
[01:314]......\smpd_command_destination
[01:314].......1 -> 0 : returning parent_context: 0 < 1
[01:314]....../smpd_command_destination
[01:314]......forwarding command to 0
[01:314]......\smpd_forward_command
[01:314].......\smpd_create_command_copy
[01:314]......./smpd_create_command_copy
[01:314].......posting write of forwarded command: "cmd=init src=1 dest=0 tag=0 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 value=1 node_id=1 "
[01:314].......\smpd_post_write_command
[01:314]........\smpd_package_command
[01:314]......../smpd_package_command
[01:314]........smpd_post_write_command on the parent context sock 16777217: 114 bytes for command: "cmd=init src=1 dest=0 tag=0 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 value=1 node_id=1 "
[01:314]......./smpd_post_write_command
[01:314]....../smpd_forward_command
[01:314]...../smpd_handle_command
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the pmi context, sock 16777220
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to parent: "cmd=init src=1 dest=0 tag=0 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 value=1 node_id=1 "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 66 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=result src=0 dest=1 tag=2 cmd_tag=0 ctx_key=0 result=SUCCESS "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 0
[01:314]...... dest = 1
[01:314]...... cmd  = result
[01:314]...... tag  = 2
[01:314]...... ctx  = parent
[01:314]...... len  = 66
[01:314]...... str  = cmd=result src=0 dest=1 tag=2 cmd_tag=0 ctx_key=0 result=SUCCESS
[01:314]......\smpd_command_destination
[01:314].......1 -> 1 : returning NULL context
[01:314]....../smpd_command_destination
[01:314]......\smpd_handle_result
[01:314].......forwarding the dbs result command to the pmi context 0.
[01:314].......\smpd_forward_command
[01:314]........\smpd_create_command_copy
[01:314]......../smpd_create_command_copy
[01:314]........posting write of forwarded command: "cmd=result src=0 dest=1 tag=2 cmd_tag=0 ctx_key=0 result=SUCCESS "
[01:314]........\smpd_post_write_command
[01:314].........\smpd_package_command
[01:314]........./smpd_package_command
[01:314].........smpd_post_write_command on the pmi context sock 16777220: 79 bytes for command: "cmd=result src=0 dest=1 tag=2 cmd_tag=0 ctx_key=0 result=SUCCESS "
[01:314]......../smpd_post_write_command
[01:314]......./smpd_forward_command
[01:314]....../smpd_handle_result
[01:314]...../smpd_handle_command
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the parent context, sock 16777217
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to pmi: "cmd=result src=0 dest=1 tag=2 cmd_tag=0 ctx_key=0 result=SUCCESS "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 154 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=dbput src=1 dest=1 tag=1 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=P0-businesscard value="port=1043 description=korebot ifname=10.0.0.15 " "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 1
[01:314]...... dest = 1
[01:314]...... cmd  = dbput
[01:314]...... tag  = 1
[01:314]...... ctx  = pmi
[01:314]...... len  = 154
[01:314]...... str  = cmd=dbput src=1 dest=1 tag=1 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=P0-businesscard value="port=1043 description=korebot ifname=10.0.0.15 "
[01:314]......\smpd_command_destination
[01:314].......1 -> 1 : returning NULL context
[01:314]....../smpd_command_destination
[01:314]......\smpd_handle_dbs_command
[01:314].......\smpd_create_command
[01:314]........\smpd_init_command
[01:314]......../smpd_init_command
[01:314]......./smpd_create_command
[01:314].......\smpd_add_command_int_arg
[01:314]......./smpd_add_command_int_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......\get_name_key_value
[01:314]......./get_name_key_value
[01:314].......\smpd_dbs_put
[01:314]......./smpd_dbs_put
[01:314].......sending reply to dbs command 'cmd=dbput src=1 dest=1 tag=1 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=P0-businesscard value="port=1043 description=korebot ifname=10.0.0.15 " '.
[01:314].......\smpd_add_command_arg
[01:314]......./smpd_add_command_arg
[01:314].......sending result command to pmi context: "cmd=result src=1 dest=1 tag=2 cmd_tag=1 cmd_orig=dbput ctx_key=0 result=DBS_SUCCESS "
[01:314].......\smpd_post_write_command
[01:314]........\smpd_package_command
[01:314]......../smpd_package_command
[01:314]........smpd_post_write_command on the pmi context sock 16777220: 98 bytes for command: "cmd=result src=1 dest=1 tag=2 cmd_tag=1 cmd_orig=dbput ctx_key=0 result=DBS_SUCCESS "
[01:314]......./smpd_post_write_command
[01:314]....../smpd_handle_dbs_command
[01:314]...../smpd_handle_command
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the pmi context, sock 16777220
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to pmi: "cmd=result src=1 dest=1 tag=2 cmd_tag=1 cmd_orig=dbput ctx_key=0 result=DBS_SUCCESS "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 97 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=finalize src=1 dest=0 tag=2 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 node_id=1 "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 1
[01:314]...... dest = 0
[01:314]...... cmd  = finalize
[01:314]...... tag  = 2
[01:314]...... ctx  = pmi
[01:314]...... len  = 97
[01:314]...... str  = cmd=finalize src=1 dest=0 tag=2 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 node_id=1
[01:314]......\smpd_command_destination
[01:314].......1 -> 0 : returning parent_context: 0 < 1
[01:314]....../smpd_command_destination
[01:314]......forwarding command to 0
[01:314]......\smpd_forward_command
[01:314].......\smpd_create_command_copy
[01:314]......./smpd_create_command_copy
[01:314].......posting write of forwarded command: "cmd=finalize src=1 dest=0 tag=2 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 node_id=1 "
[01:314].......\smpd_post_write_command
[01:314]........\smpd_package_command
[01:314]......../smpd_package_command
[01:314]........smpd_post_write_command on the parent context sock 16777217: 110 bytes for command: "cmd=finalize src=1 dest=0 tag=2 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 node_id=1 "
[01:314]......./smpd_post_write_command
[01:314]....../smpd_forward_command
[01:314]...../smpd_handle_command
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the pmi context, sock 16777220
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to parent: "cmd=finalize src=1 dest=0 tag=2 ctx_key=0 name=5025BEF03131526E7E15C5D37B0BF187 key=0 node_id=1 "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 66 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=result src=0 dest=1 tag=3 cmd_tag=2 ctx_key=0 result=SUCCESS "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 0
[01:314]...... dest = 1
[01:314]...... cmd  = result
[01:314]...... tag  = 3
[01:314]...... ctx  = parent
[01:314]...... len  = 66
[01:314]...... str  = cmd=result src=0 dest=1 tag=3 cmd_tag=2 ctx_key=0 result=SUCCESS
[01:314]......\smpd_command_destination
[01:314].......1 -> 1 : returning NULL context
[01:314]....../smpd_command_destination
[01:314]......\smpd_handle_result
[01:314].......forwarding the dbs result command to the pmi context 0.
[01:314].......\smpd_forward_command
[01:314]........\smpd_create_command_copy
[01:314]......../smpd_create_command_copy
[01:314]........posting write of forwarded command: "cmd=result src=0 dest=1 tag=3 cmd_tag=2 ctx_key=0 result=SUCCESS "
[01:314]........\smpd_post_write_command
[01:314].........\smpd_package_command
[01:314]........./smpd_package_command
[01:314].........smpd_post_write_command on the pmi context sock 16777220: 79 bytes for command: "cmd=result src=0 dest=1 tag=3 cmd_tag=2 ctx_key=0 result=SUCCESS "
[01:314]......../smpd_post_write_command
[01:314]......./smpd_forward_command
[01:314]....../smpd_handle_result
[01:314]...../smpd_handle_command
[01:314].....\smpd_post_read_command
[01:314]......posting a read for a command header on the parent context, sock 16777217
[01:314]...../smpd_post_read_command
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to pmi: "cmd=result src=0 dest=1 tag=3 cmd_tag=2 ctx_key=0 result=SUCCESS "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_stdouterr
[01:314].....read from stdout
[01:314].....32 bytes read from stdout
[01:314].....\smpd_create_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_create_command
[01:314].....\smpd_add_command_int_arg
[01:314]...../smpd_add_command_int_arg
[01:314].....\smpd_add_command_int_arg
[01:314]...../smpd_add_command_int_arg
[01:314].....\smpd_add_command_arg
[01:314]...../smpd_add_command_arg
[01:314].....\smpd_post_write_command
[01:314]......\smpd_package_command
[01:314]....../smpd_package_command
[01:314]......smpd_post_write_command on the parent context sock 16777217: 129 bytes for command: "cmd=stdout src=1 dest=0 tag=3 rank=0 first=1 data=48656C6C6F20776F726C642066726F6D2070726F636573732030206F6620310A "
[01:314]...../smpd_post_write_command
[01:314]..../smpd_state_reading_stdouterr
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...ERROR:op_read error on stderr context: socket connection closed, error stack:
MPIDU_Socki_handle_read(611): connection closed by peer (set=1,sock=16777219)
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_stdouterr
[01:314]..../smpd_state_reading_stdouterr
[01:314].../smpd_handle_op_read
[01:314]...SOCK_OP_READ failed - result = -1, closing stderr context.
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 39 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_CLOSE
[01:314]...\smpd_handle_op_close
[01:314]....\smpd_get_state_string
[01:314]..../smpd_get_state_string
[01:314]....op_close received - SMPD_CLOSING state.
[01:314]....process refcount == 2, stderr closed.
[01:314]....\smpd_free_context
[01:314].....freeing stderr context.
[01:314].....\smpd_init_context
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_init_context
[01:314]..../smpd_free_context
[01:314].../smpd_handle_op_close
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=done src=1 dest=1 tag=3 ctx_key=0 "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 1
[01:314]...... dest = 1
[01:314]...... cmd  = done
[01:314]...... tag  = 3
[01:314]...... ctx  = pmi
[01:314]...... len  = 39
[01:314]...... str  = cmd=done src=1 dest=1 tag=3 ctx_key=0
[01:314]......\smpd_command_destination
[01:314].......1 -> 1 : returning NULL context
[01:314]....../smpd_command_destination
[01:314]...../smpd_handle_command
[01:314].....not posting read for another command because SMPD_CLOSE returned
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to parent: "cmd=stdout src=1 dest=0 tag=3 rank=0 first=1 data=48656C6C6F20776F726C642066726F6D2070726F636573732030206F6620310A "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...ERROR:op_read error on stdout context: socket connection closed, error stack:
MPIDU_Socki_handle_read(611): connection closed by peer (set=1,sock=16777218)
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_stdouterr
[01:314]..../smpd_state_reading_stdouterr
[01:314].../smpd_handle_op_read
[01:314]...SOCK_OP_READ failed - result = -1, closing stdout context.
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_CLOSE
[01:314]...\smpd_handle_op_close
[01:314]....\smpd_get_state_string
[01:314]..../smpd_get_state_string
[01:314]....op_close received - SMPD_CLOSING state.
[01:314]....process refcount == 1, pmi closed.
[01:314]....\smpd_free_context
[01:314].....freeing pmi context.
[01:314].....\smpd_init_context
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_init_context
[01:314]..../smpd_free_context
[01:314].../smpd_handle_op_close
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_CLOSE
[01:314]...\smpd_handle_op_close
[01:314]....\smpd_get_state_string
[01:314]..../smpd_get_state_string
[01:314]....op_close received - SMPD_CLOSING state.
[01:314]....process refcount == 0, waiting for the process to finish exiting.
[01:314]....\smpd_wait_process
[01:314].....waiting for process 315
[01:314]..../smpd_wait_process
[01:314]....\smpd_create_command
[01:314].....\smpd_init_command
[01:314]...../smpd_init_command
[01:314]..../smpd_create_command
[01:314]....\smpd_add_command_int_arg
[01:314]..../smpd_add_command_int_arg
[01:314]....\smpd_add_command_int_arg
[01:314]..../smpd_add_command_int_arg
[01:314]....\smpd_add_command_arg
[01:314]..../smpd_add_command_arg
[01:314]....creating an exit command for rank 0, pid 315, exit code 0.
[01:314]....\smpd_post_write_command
[01:314].....\smpd_package_command
[01:314]...../smpd_package_command
[01:314].....smpd_post_write_command on the parent context sock 16777217: 93 bytes for command: "cmd=exit src=1 dest=0 tag=4 rank=0 code=0 kvs=5025BEF03131526E7E15C5D37B0BF187 "
[01:314]..../smpd_post_write_command
[01:314]....\smpd_free_process_struct
[01:314]..../smpd_free_process_struct
[01:314]....\smpd_free_context
[01:314].....freeing stdout context.
[01:314].....\smpd_init_context
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_init_context
[01:314]..../smpd_free_context
[01:314].../smpd_handle_op_close
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_CLOSE
[01:314]...\smpd_handle_op_close
[01:314]....\smpd_get_state_string
[01:314]..../smpd_get_state_string
[01:314]....op_close received - SMPD_CLOSING state.
[01:314]....Unaffiliated stdin context closing.
[01:314]....\smpd_free_context
[01:314].....freeing stdin context.
[01:314].....\smpd_init_context
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_init_context
[01:314]..../smpd_free_context
[01:314].../smpd_handle_op_close
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to parent: "cmd=exit src=1 dest=0 tag=4 rank=0 code=0 kvs=5025BEF03131526E7E15C5D37B0BF187 "
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd_header
[01:314].....read command header
[01:314].....command header read, posting read for data: 30 bytes
[01:314]..../smpd_state_reading_cmd_header
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_READ
[01:314]...\smpd_handle_op_read
[01:314]....\smpd_state_reading_cmd
[01:314].....read command
[01:314].....\smpd_parse_command
[01:314]...../smpd_parse_command
[01:314].....read command: "cmd=close src=0 dest=1 tag=4 "
[01:314].....\smpd_handle_command
[01:314]......handling command:
[01:314]...... src  = 0
[01:314]...... dest = 1
[01:314]...... cmd  = close
[01:314]...... tag  = 4
[01:314]...... ctx  = parent
[01:314]...... len  = 30
[01:314]...... str  = cmd=close src=0 dest=1 tag=4
[01:314]......\smpd_command_destination
[01:314].......1 -> 1 : returning NULL context
[01:314]....../smpd_command_destination
[01:314]......\smpd_handle_close_command
[01:314].......\smpd_create_command
[01:314]........\smpd_init_command
[01:314]......../smpd_init_command
[01:314]......./smpd_create_command
[01:314].......sending closed command to parent: "cmd=closed src=1 dest=0 tag=5 "
[01:314].......\smpd_post_write_command
[01:314]........\smpd_package_command
[01:314]......../smpd_package_command
[01:314]........smpd_post_write_command on the parent context sock 16777217: 44 bytes for command: "cmd=closed src=1 dest=0 tag=5 "
[01:314]......./smpd_post_write_command
[01:314].......posted closed command.
[01:314]....../smpd_handle_close_command
[01:314]...../smpd_handle_command
[01:314].....not posting read for another command because SMPD_CLOSE returned
[01:314]..../smpd_state_reading_cmd
[01:314].../smpd_handle_op_read
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_WRITE
[01:314]...\smpd_handle_op_write
[01:314]....\smpd_state_writing_cmd
[01:314].....wrote command
[01:314].....command written to parent: "cmd=closed src=1 dest=0 tag=5 "
[01:314].....closed command written, posting close of the sock.
[01:314].....MPIDU_Sock_post_close(16777217)
[01:314].....\smpd_free_command
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_free_command
[01:314]..../smpd_state_writing_cmd
[01:314].../smpd_handle_op_write
[01:314]...sock_waiting for the next event.
[01:314]...SOCK_OP_CLOSE
[01:314]...\smpd_handle_op_close
[01:314]....\smpd_get_state_string
[01:314]..../smpd_get_state_string
[01:314]....op_close received - SMPD_CLOSING state.
[01:314]....Unaffiliated parent context closing.
[01:314]....\smpd_free_context
[01:314].....freeing parent context.
[01:314].....\smpd_init_context
[01:314]......\smpd_init_command
[01:314]....../smpd_init_command
[01:314]...../smpd_init_context
[01:314]..../smpd_free_context
[01:314]....all contexts closed, exiting state machine.
[01:314].../smpd_handle_op_close
[01:314]../smpd_enter_at_state
[01:314]./smpd_entry_point
[01:314].\smpd_exit
[01:314]..\smpd_kill_all_processes
[01:314]../smpd_kill_all_processes
[01:314]..\smpd_dbs_finalize
[01:314]../smpd_dbs_finalize