[Q&A] Getting FINISHED:EXECUTION_EXCEPTION at the end of training, without real error or exception in the training loop

[gonzaq94]

Python version (python3 -V)

3.8

NVFlare version (python3 -m pip list | grep "nvflare")

2.3.8

NVFlare branch (if running examples, please use the branch that corresponds to the NVFlare version, git branch)

2.3.8

Operating system

Ubuntu 18.04.3 LTS

Have you successfully run any of the following examples?

• hello-numpy-sag with simulator
• hello-pt with simulator
• hello-numpy-sag with POC
• hello-pt with POC

Please describe your question

Hi,

I am getting "FINISHED:EXECUTION_EXCEPTION" at the end of the training (when the number of global rounds attains the "num_rounds" parameter set in "scatter_and_gather". However, while inspecting the logs of the clients and server there is no error or exception. I suspect that the problem is in the function "process_task_request" of the "nvflare.private.fed.server.server_runner module" class. Here is a copy of the last lines of the server log:

2024-02-28 00:54:07,337 - ScatterAndGather - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: End aggregation.
2024-02-28 00:54:07,358 - ScatterAndGather - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: Start persist model on server.
2024-02-28 00:54:09,017 - ScatterAndGather - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: End persist model on server.
2024-02-28 00:54:09,019 - ScatterAndGather - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: Round 349 finished.
2024-02-28 00:54:09,019 - ScatterAndGather - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: Finished ScatterAndGather Training.
2024-02-28 00:54:09,020 - ServerRunner - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: Workflow: scatter_and_gather finalizing ...
2024-02-28 00:54:09,203 - ServerRunner - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather, peer=site-2, peer_run=249e3281-2e66-4d7b-94e0-984d25b6a0b9]: no current workflow - asked client to try again later
2024-02-28 00:54:09,518 - ServerRunner - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: ABOUT_TO_END_RUN fired
2024-02-28 00:54:09,520 - ServerRunner - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: END_RUN fired
2024-02-28 00:54:09,521 - ServerRunner - INFO - [identity=mammo-classifier-two_sites-server_ama13, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, wf=scatter_and_gather]: Server runner finished.
2024-02-28 00:54:12,021 - FederatedServer - INFO - Server app stopped.


2024-02-28 00:54:13,541 - MPM - INFO - MPM: Good Bye!

and of one of the clients

2024-02-28 00:54:05,452 - FederatedClient - INFO - Starting to push execute result.
2024-02-28 00:54:06,433 - Communicator - INFO -  SubmitUpdate size: 44766699 Bytes. time: 0.9807114601135254 seconds
2024-02-28 00:54:06,440 - ClientRunner - INFO - [identity=site-1, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, peer=mammo-classifier-two_sites-server_ama13, peer_run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, task_name=train, task_id=2c296c79-8dd7-45c9-8b2b-8219b84b4dce]: task result sent to server
2024-02-28 00:54:09,524 - ClientRunner - INFO - [identity=site-1, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9, peer=mammo-classifier-two_sites-server_ama13, peer_run=249e3281-2e66-4d7b-94e0-984d25b6a0b9]: received aux request from Server to end current RUN
2024-02-28 00:54:09,530 - ClientRunner - INFO - [identity=site-1, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9]: ABORT (RUN) command received
2024-02-28 00:54:09,530 - ClientRunner - INFO - [identity=site-1, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9]: ABORT (RUN) requests end run events sequence
2024-02-28 00:54:09,531 - ClientRunner - INFO - [identity=site-1, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9]: ABOUT_TO_END_RUN fired
2024-02-28 00:54:09,532 - ClientRunner - INFO - [identity=site-1, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9]: END_RUN fired
2024-02-28 00:54:11,024 - ClientRunner - INFO - [identity=site-1, run=249e3281-2e66-4d7b-94e0-984d25b6a0b9]: run method requests end run events sequence
2024-02-28 00:54:11,033 - nvflare.fuel.f3.drivers.aio_grpc_driver.AioStreamSession - INFO - Closed GRPC Channel
2024-02-28 00:54:11,044 - nvflare.fuel.f3.drivers.aio_grpc_driver.AioGrpcDriver - INFO - CLIENT: connection [CN00003 Not Connected] closed
2024-02-28 00:54:11,046 - FederatedClient - INFO - Shutting down client run: site-1
2024-02-28 00:54:12,936 - MPM - INFO - MPM: Good Bye!

The "finalize" function of my learner is simply:

    def finalize(self, fl_ctx: FLContext):
        # collect threads, close files here
        pass

Thanks in advance for your help.

Gonzalo

[YuanTingHsieh]

@gonzaq94 can you share the full logs of server and clients?
And can you share your job folder?

[gonzaq94]

0f54ca35-4448-4e03-84fe-3f5b99583db5-server.zip
0f54ca35-4448-4e03-84fe-3f5b99583db5-client.zip

[gonzaq94]

Here you go @YuanTingHsieh

[YuanTingHsieh]

@gonzaq94 thanks for the logs, from the logs I think everything looks normal.
Can you share you job configs?
And when you run the experiment for the second time, do you still see this?
Can you update your version to 2.3.10 and try again?

[YuanTingHsieh]

close due to inactivity, feel free to re-open