Eval bug: serve slow down after 1st request vulkan multigpu moe #30799

Name and Version

version: 0.7.0-dev (build 11718, commit 547208d)
built with GNU 11.4.0 for Linux x86_64

Operating systems

Linux

GGML backends

Vulkan

Hardware

4x XFX RX580 8GB (3 used while running this)

Models

Ornith-1.5-35B-A3B.APEX-I-MiniPlus-V2.1.gguf (based on qwen 3.6 35b)

Problem description & steps to reproduce

on 1st resuest avrage generation speed is about 30 tok/s
on 2nd request it becomes about 10 tok/s
on 3rd request it becomes 3 tok/s!

EDIT: i am pretty sure some parts of model gets loaded into igpu! even i disabled igpu set --devices vulkan1,vulkan2,vulkan3 but still some parts of model gets loaded into vulkan4! (vram increases on vulkan4 also load increses on it! ) i can check that on radeon 4
EDIT2: also when not using igpu and disabled not using --device (using all 4 rx580 devices) this same thing still happens!

First Bad Commit

No response

Relevant log output

aryan@hope:~/Documents/AI$ RADV_PERFTEST=nogttspill ./runtimes/llama-b11718-bin-ubuntu-vulkan-x64/llama-b11718/llama-server -m '/run/media/aryan/Ventoy/Local_Disk/1437-FILES/1437-AI/000-newmodels-uncat-good-downloads/000_ornith-1.5-35b/Ornith-1.5-35B-A3B.APEX-I-MiniPlus-V2.1.gguf' --device vulkan1,vulkan2,vulkan3 -c 32768
0.05.264.287 I srv llama_server: initializing ...
0.05.264.302 I cmn common_param: common_params_print_info: verbosity = 3 (adjust with the -lv N CLI arg)
0.05.264.848 W srv llama_server: security: no API key is set and CORS allows all origins (see #25655)
0.05.266.618 I srv load_model: loading model '/run/media/aryan/Ventoy/Local_Disk/1437-FILES/1437-AI/000-newmodels-uncat-good-downloads/000_ornith-1.5-35b/Ornith-1.5-35B-A3B.APEX-I-MiniPlus-V2.1.gguf'
0.07.007.099 W model has unused tensor blk.40.attn_norm.weight (size = 8192 bytes) -- ignoring
0.07.007.108 W model has unused tensor blk.40.post_attention_norm.weight (size = 8192 bytes) -- ignoring
0.07.007.118 W model has unused tensor blk.40.attn_q.weight (size = 9437184 bytes) -- ignoring
0.07.007.122 W model has unused tensor blk.40.attn_k.weight (size = 589824 bytes) -- ignoring
0.07.007.125 W model has unused tensor blk.40.attn_v.weight (size = 589824 bytes) -- ignoring
0.07.007.138 W model has unused tensor blk.40.attn_output.weight (size = 6881280 bytes) -- ignoring
0.07.007.142 W model has unused tensor blk.40.attn_q_norm.weight (size = 1024 bytes) -- ignoring
0.07.007.146 W model has unused tensor blk.40.attn_k_norm.weight (size = 1024 bytes) -- ignoring
0.07.007.150 W model has unused tensor blk.40.ffn_gate_inp.weight (size = 2097152 bytes) -- ignoring
0.07.007.154 W model has unused tensor blk.40.ffn_down_exps.weight (size = 150994944 bytes) -- ignoring
0.07.007.162 W model has unused tensor blk.40.ffn_gate_exps.weight (size = 150994944 bytes) -- ignoring
0.07.007.166 W model has unused tensor blk.40.ffn_up_exps.weight (size = 150994944 bytes) -- ignoring
0.07.007.170 W model has unused tensor blk.40.ffn_gate_inp_shexp.weight (size = 8192 bytes) -- ignoring
0.07.007.174 W model has unused tensor blk.40.ffn_gate_shexp.weight (size = 720896 bytes) -- ignoring
0.07.007.178 W model has unused tensor blk.40.ffn_up_shexp.weight (size = 720896 bytes) -- ignoring
0.07.007.182 W model has unused tensor blk.40.ffn_down_shexp.weight (size = 720896 bytes) -- ignoring
0.07.007.187 W model has unused tensor blk.40.nextn.eh_proj.weight (size = 4718592 bytes) -- ignoring
0.07.007.191 W model has unused tensor blk.40.nextn.enorm.weight (size = 8192 bytes) -- ignoring
0.07.007.196 W model has unused tensor blk.40.nextn.hnorm.weight (size = 8192 bytes) -- ignoring
0.07.007.208 W model has unused tensor blk.40.nextn.shared_head_norm.weight (size = 8192 bytes) -- ignoring
1.32.574.632 I cmn init: llama threadpool init, n_threads = 2
1.34.140.378 I srv load_model: initializing, n_slots = 4, n_ctx_slot = 32768, kv_unified = 'true'
1.34.146.639 W srv init: chat template supports preserving reasoning, it is enabled by default (may use more tokens, disable via --no-reasoning-preserve)
1.34.146.684 I srv llama_server: model loaded
1.34.146.689 I srv llama_server: listening on http://127.0.0.1:9931
3.13.180.827 I slot get_availabl: id 0 | task -1 | selected slot by LRU, n_tokens = 0, t_last = -1
3.13.181.028 I slot launch_slot_: id 0 | task 0 | processing task, is_child = 0
3.17.311.300 I slot print_timing: id 0 | task 0 | prompt processing, n_tokens = 755, progress = 0.99, t = 4.13 s / 182.80 tokens per second
3.22.469.557 I slot print_timing: id 0 | task 0 | n_gen = 100, tg = 26.46 t/s, tg_3s = 26.73 t/s
3.25.479.517 I slot print_timing: id 0 | task 0 | n_gen = 194, tg = 28.59 t/s, tg_3s = 31.23 t/s
3.28.490.993 I slot print_timing: id 0 | task 0 | n_gen = 288, tg = 29.40 t/s, tg_3s = 31.21 t/s
3.31.528.656 I slot print_timing: id 0 | task 0 | n_gen = 383, tg = 29.84 t/s, tg_3s = 31.27 t/s
3.34.559.022 I slot print_timing: id 0 | task 0 | n_gen = 478, tg = 30.13 t/s, tg_3s = 31.35 t/s
3.37.591.729 I slot print_timing: id 0 | task 0 | n_gen = 573, tg = 30.32 t/s, tg_3s = 31.33 t/s
3.40.602.716 I slot print_timing: id 0 | task 0 | n_gen = 660, tg = 30.13 t/s, tg_3s = 28.89 t/s
3.43.630.071 I slot print_timing: id 0 | task 0 | n_gen = 757, tg = 30.36 t/s, tg_3s = 32.04 t/s
3.46.652.790 I slot print_timing: id 0 | task 0 | n_gen = 851, tg = 30.44 t/s, tg_3s = 31.10 t/s
3.49.676.776 I slot print_timing: id 0 | task 0 | n_gen = 946, tg = 30.54 t/s, tg_3s = 31.42 t/s
3.52.689.556 I slot print_timing: id 0 | task 0 | n_gen = 1041, tg = 30.62 t/s, tg_3s = 31.53 t/s
3.55.690.979 I slot print_timing: id 0 | task 0 | n_gen = 1137, tg = 30.73 t/s, tg_3s = 31.98 t/s
3.58.701.204 I slot print_timing: id 0 | task 0 | n_gen = 1232, tg = 30.80 t/s, tg_3s = 31.56 t/s
4.01.719.252 I slot print_timing: id 0 | task 0 | n_gen = 1324, tg = 30.77 t/s, tg_3s = 30.48 t/s
4.04.732.456 I slot print_timing: id 0 | task 0 | n_gen = 1415, tg = 30.74 t/s, tg_3s = 30.20 t/s
4.07.762.358 I slot print_timing: id 0 | task 0 | n_gen = 1509, tg = 30.75 t/s, tg_3s = 31.02 t/s
4.10.768.467 I slot print_timing: id 0 | task 0 | n_gen = 1599, tg = 30.71 t/s, tg_3s = 29.94 t/s
4.13.784.073 I slot print_timing: id 0 | task 0 | n_gen = 1692, tg = 30.71 t/s, tg_3s = 30.84 t/s
4.16.802.819 I slot print_timing: id 0 | task 0 | n_gen = 1785, tg = 30.72 t/s, tg_3s = 30.81 t/s
4.19.832.961 I slot print_timing: id 0 | task 0 | n_gen = 1880, tg = 30.75 t/s, tg_3s = 31.35 t/s
4.22.860.912 I slot print_timing: id 0 | task 0 | n_gen = 1965, tg = 30.62 t/s, tg_3s = 28.07 t/s
4.25.875.912 I slot print_timing: id 0 | task 0 | n_gen = 2058, tg = 30.63 t/s, tg_3s = 30.85 t/s
4.28.879.857 I slot print_timing: id 0 | task 0 | n_gen = 2150, tg = 30.63 t/s, tg_3s = 30.63 t/s
4.31.884.742 I slot print_timing: id 0 | task 0 | n_gen = 2241, tg = 30.62 t/s, tg_3s = 30.28 t/s
4.34.884.775 I slot print_timing: id 0 | task 0 | n_gen = 2335, tg = 30.65 t/s, tg_3s = 31.33 t/s
4.37.889.806 I slot print_timing: id 0 | task 0 | n_gen = 2427, tg = 30.65 t/s, tg_3s = 30.62 t/s
4.40.918.431 I slot print_timing: id 0 | task 0 | n_gen = 2521, tg = 30.66 t/s, tg_3s = 31.04 t/s
4.43.934.803 I slot print_timing: id 0 | task 0 | n_gen = 2608, tg = 30.60 t/s, tg_3s = 28.84 t/s
4.46.954.951 I slot print_timing: id 0 | task 0 | n_gen = 2702, tg = 30.61 t/s, tg_3s = 31.12 t/s
4.49.968.115 I slot print_timing: id 0 | task 0 | n_gen = 2796, tg = 30.63 t/s, tg_3s = 31.20 t/s
4.52.998.499 I slot print_timing: id 0 | task 0 | n_gen = 2887, tg = 30.61 t/s, tg_3s = 30.03 t/s
4.56.015.211 I slot print_timing: id 0 | task 0 | n_gen = 2979, tg = 30.61 t/s, tg_3s = 30.50 t/s
4.59.024.913 I slot print_timing: id 0 | task 0 | n_gen = 3071, tg = 30.61 t/s, tg_3s = 30.57 t/s
5.02.040.467 I slot print_timing: id 0 | task 0 | n_gen = 3171, tg = 30.68 t/s, tg_3s = 33.16 t/s
5.05.041.055 I slot print_timing: id 0 | task 0 | n_gen = 3272, tg = 30.77 t/s, tg_3s = 33.66 t/s
5.08.056.419 I slot print_timing: id 0 | task 0 | n_gen = 3374, tg = 30.85 t/s, tg_3s = 33.83 t/s
5.11.073.879 I slot print_timing: id 0 | task 0 | n_gen = 3475, tg = 30.92 t/s, tg_3s = 33.47 t/s
5.14.091.605 I slot print_timing: id 0 | task 0 | n_gen = 3577, tg = 31.00 t/s, tg_3s = 33.80 t/s
5.17.102.536 I slot print_timing: id 0 | task 0 | n_gen = 3676, tg = 31.05 t/s, tg_3s = 32.88 t/s
5.20.123.095 I slot print_timing: id 0 | task 0 | n_gen = 3776, tg = 31.10 t/s, tg_3s = 33.11 t/s
5.23.139.962 I slot print_timing: id 0 | task 0 | n_gen = 3876, tg = 31.15 t/s, tg_3s = 33.15 t/s
5.26.153.565 I slot print_timing: id 0 | task 0 | n_gen = 3976, tg = 31.19 t/s, tg_3s = 33.18 t/s
5.29.183.331 I slot print_timing: id 0 | task 0 | n_gen = 4078, tg = 31.25 t/s, tg_3s = 33.67 t/s
5.32.186.950 I slot print_timing: id 0 | task 0 | n_gen = 4179, tg = 31.31 t/s, tg_3s = 33.63 t/s
5.35.190.089 I slot print_timing: id 0 | task 0 | n_gen = 4278, tg = 31.34 t/s, tg_3s = 32.97 t/s
5.38.215.489 I slot print_timing: id 0 | task 0 | n_gen = 4378, tg = 31.38 t/s, tg_3s = 33.05 t/s
5.41.243.699 I slot print_timing: id 0 | task 0 | n_gen = 4478, tg = 31.41 t/s, tg_3s = 33.02 t/s
5.44.268.167 I slot print_timing: id 0 | task 0 | n_gen = 4577, tg = 31.44 t/s, tg_3s = 32.73 t/s
5.47.268.488 I slot print_timing: id 0 | task 0 | n_gen = 4673, tg = 31.45 t/s, tg_3s = 32.00 t/s
5.50.282.716 I slot print_timing: id 0 | task 0 | n_gen = 4771, tg = 31.47 t/s, tg_3s = 32.51 t/s
5.53.311.209 I slot print_timing: id 0 | task 0 | n_gen = 4870, tg = 31.50 t/s, tg_3s = 32.69 t/s
5.56.338.288 I slot print_timing: id 0 | task 0 | n_gen = 4969, tg = 31.52 t/s, tg_3s = 32.70 t/s
5.59.359.339 I slot print_timing: id 0 | task 0 | n_gen = 5069, tg = 31.55 t/s, tg_3s = 33.10 t/s
6.02.362.051 I slot print_timing: id 0 | task 0 | n_gen = 5168, tg = 31.58 t/s, tg_3s = 32.97 t/s
6.05.373.061 I slot print_timing: id 0 | task 0 | n_gen = 5268, tg = 31.61 t/s, tg_3s = 33.21 t/s
6.08.375.994 I slot print_timing: id 0 | task 0 | n_gen = 5366, tg = 31.62 t/s, tg_3s = 32.63 t/s
6.11.378.742 I slot print_timing: id 0 | task 0 | n_gen = 5465, tg = 31.65 t/s, tg_3s = 32.97 t/s
6.14.386.541 I slot print_timing: id 0 | task 0 | n_gen = 5564, tg = 31.67 t/s, tg_3s = 32.91 t/s
6.17.405.299 I slot print_timing: id 0 | task 0 | n_gen = 5663, tg = 31.69 t/s, tg_3s = 32.79 t/s
6.20.424.312 I slot print_timing: id 0 | task 0 | n_gen = 5762, tg = 31.71 t/s, tg_3s = 32.79 t/s
6.23.443.610 I slot print_timing: id 0 | task 0 | n_gen = 5861, tg = 31.72 t/s, tg_3s = 32.79 t/s
6.26.468.320 I slot print_timing: id 0 | task 0 | n_gen = 5958, tg = 31.73 t/s, tg_3s = 32.07 t/s
6.29.487.556 I slot print_timing: id 0 | task 0 | n_gen = 6046, tg = 31.69 t/s, tg_3s = 29.15 t/s
6.32.511.406 I slot print_timing: id 0 | task 0 | n_gen = 6126, tg = 31.61 t/s, tg_3s = 26.46 t/s
6.35.542.035 I slot print_timing: id 0 | task 0 | n_gen = 6208, tg = 31.54 t/s, tg_3s = 27.06 t/s
6.38.545.345 I slot print_timing: id 0 | task 0 | n_gen = 6295, tg = 31.50 t/s, tg_3s = 28.97 t/s
6.41.565.295 I slot print_timing: id 0 | task 0 | n_gen = 6386, tg = 31.48 t/s, tg_3s = 30.13 t/s
6.44.567.704 I slot print_timing: id 0 | task 0 | n_gen = 6475, tg = 31.45 t/s, tg_3s = 29.64 t/s
6.47.576.244 I slot print_timing: id 0 | task 0 | n_gen = 6564, tg = 31.42 t/s, tg_3s = 29.58 t/s
6.50.606.804 I slot print_timing: id 0 | task 0 | n_gen = 6648, tg = 31.37 t/s, tg_3s = 27.72 t/s
6.53.630.448 I slot print_timing: id 0 | task 0 | n_gen = 6739, tg = 31.35 t/s, tg_3s = 30.10 t/s
6.56.648.295 I slot print_timing: id 0 | task 0 | n_gen = 6828, tg = 31.33 t/s, tg_3s = 29.49 t/s
6.59.659.083 I slot print_timing: id 0 | task 0 | n_gen = 6917, tg = 31.30 t/s, tg_3s = 29.56 t/s
7.02.685.940 I slot print_timing: id 0 | task 0 | n_gen = 7005, tg = 31.27 t/s, tg_3s = 29.07 t/s
7.05.694.838 I slot print_timing: id 0 | task 0 | n_gen = 7093, tg = 31.25 t/s, tg_3s = 29.25 t/s
7.08.716.516 I slot print_timing: id 0 | task 0 | n_gen = 7181, tg = 31.22 t/s, tg_3s = 29.12 t/s
7.11.731.250 I slot print_timing: id 0 | task 0 | n_gen = 7266, tg = 31.18 t/s, tg_3s = 28.19 t/s
7.14.753.976 I slot print_timing: id 0 | task 0 | n_gen = 7355, tg = 31.16 t/s, tg_3s = 29.44 t/s
7.17.776.421 I slot print_timing: id 0 | task 0 | n_gen = 7444, tg = 31.14 t/s, tg_3s = 29.45 t/s
7.20.784.426 I slot print_timing: id 0 | task 0 | n_gen = 7533, tg = 31.12 t/s, tg_3s = 29.59 t/s
7.23.815.850 I slot print_timing: id 0 | task 0 | n_gen = 7622, tg = 31.10 t/s, tg_3s = 29.36 t/s
7.26.838.414 I slot print_timing: id 0 | task 0 | n_gen = 7709, tg = 31.07 t/s, tg_3s = 28.78 t/s
7.29.842.747 I slot print_timing: id 0 | task 0 | n_gen = 7796, tg = 31.04 t/s, tg_3s = 28.96 t/s
7.32.847.218 I slot print_timing: id 0 | task 0 | n_gen = 7877, tg = 30.99 t/s, tg_3s = 26.96 t/s
7.35.867.954 I slot print_timing: id 0 | task 0 | n_gen = 7965, tg = 30.97 t/s, tg_3s = 29.13 t/s
7.38.888.993 I slot print_timing: id 0 | task 0 | n_gen = 8051, tg = 30.94 t/s, tg_3s = 28.47 t/s
7.41.893.859 I slot print_timing: id 0 | task 0 | n_gen = 8138, tg = 30.92 t/s, tg_3s = 28.95 t/s
7.44.905.493 I slot print_timing: id 0 | task 0 | n_gen = 8225, tg = 30.90 t/s, tg_3s = 28.89 t/s
7.47.915.079 I slot print_timing: id 0 | task 0 | n_gen = 8311, tg = 30.87 t/s, tg_3s = 28.58 t/s
7.50.945.967 I slot print_timing: id 0 | task 0 | n_gen = 8397, tg = 30.84 t/s, tg_3s = 28.37 t/s
7.53.970.461 I slot print_timing: id 0 | task 0 | n_gen = 8480, tg = 30.81 t/s, tg_3s = 27.44 t/s
7.56.982.838 I slot print_timing: id 0 | task 0 | n_gen = 8566, tg = 30.78 t/s, tg_3s = 28.55 t/s
7.58.445.033 I slot print_timing: id 0 | task 0 | prompt eval time = 5547.31 ms / 759 tokens ( 7.31 ms per token, 136.82 tokens per second)
7.58.445.408 I slot print_timing: id 0 | task 0 | eval time = 279716.54 ms / 8609 tokens ( 32.49 ms per token, 30.77 tokens per second)
7.58.445.446 I slot print_timing: id 0 | task 0 | total time = 285263.86 ms / 9368 tokens
7.58.445.482 I slot print_timing: id 0 | task 0 | graphs reused = 8574
7.58.445.578 I slot print_timing: id 0 | task 0 | graph reallocs = 0 / 0 (same size) / (changed size)
7.58.445.687 I slot release: id 0 | task 0 | stop processing: n_tokens = 9367, truncated = 0
12.02.117.987 I slot get_availabl: id 0 | task -1 | selected slot by LCP similarity, f_sim_best = 0.953 (> 0.100 thold), f_keep = 0.035
12.02.908.165 I slot launch_slot_: id 0 | task 8613 | processing task, is_child = 0
12.12.857.458 I slot print_timing: id 0 | task 8613 | n_gen = 100, tg = 11.20 t/s, tg_3s = 11.31 t/s
12.15.865.286 I slot print_timing: id 0 | task 8613 | n_gen = 134, tg = 11.23 t/s, tg_3s = 11.30 t/s
12.18.885.043 I slot print_timing: id 0 | task 8613 | n_gen = 167, tg = 11.17 t/s, tg_3s = 10.93 t/s
12.20.865.853 W srv stop: cancel task, id_task = 8613
12.20.951.733 I slot release: id 0 | task 8613 | stop processing: n_tokens = 530, truncated = 0
12.20.951.776 I slot get_availabl: id 1 | task -1 | selected slot by LRU, n_tokens = 0, t_last = -1
12.20.951.864 I slot launch_slot_: id 1 | task 8806 | processing task, is_child = 0
12.23.154.332 I slot print_timing: id 1 | task 8806 | prompt eval time = 1070.54 ms / 70 tokens ( 15.29 ms per token, 65.39 tokens per second)
12.23.154.383 I slot print_timing: id 1 | task 8806 | eval time = 799.60 ms / 10 tokens ( 88.84 ms per token, 11.26 tokens per second)
12.23.154.408 I slot print_timing: id 1 | task 8806 | total time = 1870.14 ms / 80 tokens
12.23.154.430 I slot print_timing: id 1 | task 8806 | graphs reused = 8769
12.23.154.476 I slot print_timing: id 1 | task 8806 | graph reallocs = 0 / 0 (same size) / (changed size)
12.23.154.518 I slot release: id 1 | task 8806 | stop processing: n_tokens = 79, truncated = 0
13.41.935.773 I slot get_availabl: id 2 | task -1 | selected slot by LRU, n_tokens = 0, t_last = -1
13.42.343.242 I slot launch_slot_: id 2 | task 8818 | processing task, is_child = 0
13.52.925.677 I slot print_timing: id 2 | task 8818 | n_gen = 100, tg = 10.05 t/s, tg_3s = 10.15 t/s
13.55.990.846 I slot print_timing: id 2 | task 8818 | n_gen = 130, tg = 9.98 t/s, tg_3s = 9.79 t/s
13.59.010.488 I slot print_timing: id 2 | task 8818 | n_gen = 160, tg = 9.97 t/s, tg_3s = 9.93 t/s
14.02.091.197 I slot print_timing: id 2 | task 8818 | n_gen = 189, tg = 9.88 t/s, tg_3s = 9.41 t/s
14.02.800.116 W srv stop: cancel task, id_task = 8818
14.02.902.467 I slot release: id 2 | task 8818 | stop processing: n_tokens = 537, truncated = 0
15.06.312.171 I slot get_availabl: id 2 | task -1 | selected slot by LCP similarity, f_sim_best = 1.000 (> 0.100 thold), f_keep = 0.635
15.06.312.330 I slot launch_slot_: id 2 | task 9017 | processing task, is_child = 0
15.10.303.348 W srv stop: cancel task, id_task = 9017
15.10.560.935 I slot release: id 2 | task 9017 | stop processing: n_tokens = 354, truncated = 0
15.17.458.180 I slot get_availabl: id 2 | task -1 | selected slot by LCP similarity, f_sim_best = 1.000 (> 0.100 thold), f_keep = 0.963
15.17.458.313 I slot launch_slot_: id 2 | task 9033 | processing task, is_child = 0
15.31.419.529 W srv stop: cancel task, id_task = 9033
15.31.419.584 I slot release: id 2 | task 9033 | stop processing: n_tokens = 391, truncated = 0
16.21.424.714 I slot get_availabl: id 2 | task -1 | selected slot by LCP similarity, f_sim_best = 1.000 (> 0.100 thold), f_keep = 0.872
16.21.424.886 I slot launch_slot_: id 2 | task 9086 | processing task, is_child = 0
16.47.915.540 I slot print_timing: id 2 | task 9086 | n_gen = 100, tg = 3.86 t/s, tg_3s = 3.90 t/s
16.50.527.432 W srv stop: cancel task, id_task = 9086
16.50.784.664 I slot release: id 2 | task 9086 | stop processing: n_tokens = 451, truncated = 0
19.50.967.943 I slot get_availabl: id 2 | task -1 | selected slot by LCP similarity, f_sim_best = 1.000 (> 0.100 thold), f_keep = 0.756
19.50.968.069 I slot launch_slot_: id 2 | task 9199 | processing task, is_child = 0
20.14.972.946 W srv stop: cancel task, id_task = 9199
20.14.973.223 I slot release: id 2 | task 9199 | stop processing: n_tokens = 430, truncated = 0
^C20.19.712.919 I srv operator(): operator(): cleaning up before exit...