Completion Queue shutdown
16 views
Skip to first unread message
Colm Quinn
Jun 7, 2024, 2:28:32 PMJun 7
to grpc.io
I'm running 1.63.0 on Windows. I'm trying to get a sample gRPC client async framework which will proxy from a server environment. So I need an async client with a shared CompletionQueue. I think I have the theory correct and this seems to work on Linux but the Windows behavior has me puzzled. In particular I cannot shutdown a CompletionQueue cleanly.
Looking at the gRPC traces there is a thread still running that seems to be running a generic timer and this seems to be the cause of the problem. Once the QUEUE_COMPLETE has been handled should I not be able to tear everything down ? I've been looking at this for a week ! Any ideas welcome.
Am I mis reading the following :
Create the CQ..
I0605 17:42:14.340000000 24608 connectivity_state.cc:182] ConnectivityStateTracker client_channel[000001E5713B5520]: get current state: READY
2024-06-05 17:42:14.336697 95.64% [NOTICE] mod_grpc.c:66 gRPC Channel 192.168.1.195:50051 state 2
2024-06-05 17:42:14.336697 95.64% [NOTICE] mod_grpc.c:263 gRPC channel created, profile->name routetest, uri 192.168.1.195:50051
Start the Completion Queue and it trundles through some reads and writes successfully ..
I0605 17:42:14.826000000 24236 timer_manager.cc:207] wait ended: was_timed:1 kicked:0
D0605 17:42:14.827000000 24236 timer_generic.cc:696] TIMER CHECK BEGIN: now=3038 next=9223372036854775807 tls_min=2032 glob_min=3037
D0605 17:42:14.827000000 24236 timer_generic.cc:596] .. shard[0]->min_deadline = 3037
D0605 17:42:14.827000000 24236 timer_generic.cc:512] .. shard[0]: heap_empty=true
D0605 17:42:14.827000000 24236 timer_generic.cc:483] .. shard[0]->queue_deadline_cap --> 4037
D0605 17:42:14.827000000 24236 timer_generic.cc:556] .. shard[0] popped 0
D0605 17:42:14.827000000 24236 timer_generic.cc:615] .. result --> 1, shard[0]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.828000000 24236 timer_generic.cc:512] .. shard[1]: heap_empty=true
D0605 17:42:14.828000000 24236 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 4038
D0605 17:42:14.828000000 24236 timer_generic.cc:556] .. shard[1] popped 0
D0605 17:42:14.828000000 24236 timer_generic.cc:615] .. result --> 1, shard[1]->min_deadline 3037 --> 4039, now=3038
D0605 17:42:14.828000000 24236 timer_generic.cc:512] .. shard[2]: heap_empty=true
D0605 17:42:14.829000000 24236 timer_generic.cc:483] .. shard[2]->queue_deadline_cap --> 4037
D0605 17:42:14.829000000 24236 timer_generic.cc:556] .. shard[2] popped 0
D0605 17:42:14.829000000 24236 timer_generic.cc:615] .. result --> 1, shard[2]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.829000000 24236 timer_generic.cc:512] .. shard[3]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[3]->queue_deadline_cap --> 4038
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[3] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[3]->min_deadline 3037 --> 4039, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[4]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[4]->queue_deadline_cap --> 4037
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[4] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[4]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[5]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[5]->queue_deadline_cap --> 4037
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[5] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[5]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[6]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[6]->queue_deadline_cap --> 4037
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[6] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[6]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[7]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[7]->queue_deadline_cap --> 4037
D0605 17:42:14.831000000 24236 timer_generic.cc:556] .. shard[7] popped 0
D0605 17:42:14.831000000 24236 timer_generic.cc:615] .. result --> 1, shard[7]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.831000000 24236 timer_generic.cc:722] TIMER CHECK END: r=1; next=4038 tls_min=3037 glob_min=4038
D0605 17:42:26.852000000 24236 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 16062
D0605 17:42:26.852000000 24236 timer_generic.cc:556] .. shard[1] popped 0
D0605 17:42:26.852000000 24236 timer_generic.cc:615] .. result --> 1, shard[1]->min_deadline 15062 --> 16063, now=15062
D0605 17:42:26.852000000 24236 timer_generic.cc:722] TIMER CHECK END: r=1; next=16047
I0605 17:42:26.852000000 24236 timer_manager.cc:191] sleep for a 985 milliseconds
I0605 17:42:31.028000000 24236 timer_manager.cc:207] wait ended: was_timed:1 kicked:0
Call CQ->Shutdown()
I0605 17:42:31.028000000 24608 completion_queue.cc:1398] grpc_completion_queue_shutdown(cq=000001E571FF0360)
D0605 17:42:31.029000000 24236 timer_generic.cc:696] TIMER CHECK BEGIN: now=19240 next=9223372036854775807 tls_min=15062 glob_min=16047
I0605 17:42:31.029000000 24608 src/core/lib/gprpp/ref_counted.h:85] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:1101 ref 3 -> 4 shutting_down
D0605 17:42:31.029000000 24236 timer_generic.cc:596] .. shard[3]->min_deadline = 16047
I0605 17:42:31.029000000 24608 src/core/lib/gprpp/ref_counted.h:181] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:1116 unref 4 -> 3 shutting_down
D0605 17:42:31.029000000 25052 exec_ctx.cc:36] running closure 000001E571FF0460: created [C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:556]: scheduled [C:\Users\colm_\source\repos\grpc\src\core\lib\iomgr\pollset_windows.cc:150]
D0605 17:42:31.029000000 24236 timer_generic.cc:512] .. shard[3]: heap_empty=false
I0605 17:42:31.030000000 25052 src/core/lib/gprpp/ref_counted.h:181] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:616 unref 3 -> 2 pollset_destroy
D0605 17:42:31.030000000 24236 timer_generic.cc:525] .. check top timer deadline=16047 now=19240
D0605 17:42:31.030000000 25052 exec_ctx.cc:48] closure 000001E571FF0460 finished
D0605 17:42:31.030000000 24236 timer_generic.cc:532] TIMER 000001E57301ADB0: FIRE 3193ms late
I0605 17:42:31.030000000 25052 completion_queue.cc:1069] RETURN_EVENT[000001E571FF0360]: QUEUE_SHUTDOWN
But it just rolls on !
D0605 17:42:31.030000000 24236 timer_generic.cc:512] .. shard[3]: heap_empty=true
I0605 17:42:31.030000000 25052 src/core/lib/gprpp/ref_counted.h:181] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:1070 unref 2 -> 1 next
D0605 17:42:31.030000000 24236 timer_generic.cc:483] .. shard[3]->queue_deadline_cap --> 20240
D0605 17:42:31.030000000 24236 timer_generic.cc:556] .. shard[3] popped 1
D0605 17:42:31.030000000 24236 timer_generic.cc:615] .. result --> 2, shard[3]->min_deadline 16047 --> 20241, now=19240
D0605 17:42:31.030000000 24236 timer_generic.cc:512] .. shard[7]: heap_empty=true
2024-06-05 17:42:31.028548 0000000000000000000000000000000000000000000000000000 [NOTICE] grpc_channel.cpp:291 Completion queue ending 0
D0605 17:42:31.030000000 24236 timer_generic.cc:483] .. shard[7]->queue_deadline_cap --> 20240
D0605 17:42:31.031000000 24236 timer_generic.cc:556] .. shard[7] popped 0
D0605 17:42:31.032000000 24236 timer_generic.cc:615] .. result --> 2, shard[7]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.032000000 24236 timer_generic.cc:512] .. shard[6]: heap_empty=true
D0605 17:42:31.032000000 24236 timer_generic.cc:483] .. shard[6]->queue_deadline_cap --> 20240
D0605 17:42:31.032000000 24236 timer_generic.cc:556] .. shard[6] popped 0
D0605 17:42:31.032000000 24236 timer_generic.cc:615] .. result --> 2, shard[6]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.032000000 24236 timer_generic.cc:512] .. shard[5]: heap_empty=true
D0605 17:42:31.033000000 24236 timer_generic.cc:483] .. shard[5]->queue_deadline_cap --> 20240
D0605 17:42:31.033000000 24236 timer_generic.cc:556] .. shard[5] popped 0
D0605 17:42:31.033000000 24236 timer_generic.cc:615] .. result --> 2, shard[5]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.033000000 24236 timer_generic.cc:512] .. shard[4]: heap_empty=true
D0605 17:42:31.033000000 24236 timer_generic.cc:483] .. shard[4]->queue_deadline_cap --> 20240
D0605 17:42:31.034000000 24236 timer_generic.cc:556] .. shard[4] popped 0
D0605 17:42:31.034000000 24236 timer_generic.cc:615] .. result --> 2, shard[4]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.034000000 24236 timer_generic.cc:512] .. shard[2]: heap_empty=true
D0605 17:42:31.034000000 24236 timer_generic.cc:483] .. shard[2]->queue_deadline_cap --> 20240
D0605 17:42:31.034000000 24236 timer_generic.cc:556] .. shard[2] popped 0
D0605 17:42:31.034000000 24236 timer_generic.cc:615] .. result --> 2, shard[2]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.035000000 24236 timer_generic.cc:512] .. shard[0]: heap_empty=true
D0605 17:42:31.035000000 24236 timer_generic.cc:483] .. shard[0]->queue_deadline_cap --> 20240
D0605 17:42:31.035000000 24236 timer_generic.cc:556] .. shard[0] popped 0
D0605 17:42:31.035000000 24236 timer_generic.cc:615] .. result --> 2, shard[0]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.035000000 24236 timer_generic.cc:512] .. shard[1]: heap_empty=true
D0605 17:42:31.035000000 24236 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 20240
D0605 17:42:31.036000000 24236 timer_generic.cc:556] .. shard[1] popped 0
D0605 17:42:31.036000000 24236 timer_generic.cc:615] .. result --> 2, shard[1]->min_deadline 16063 --> 20241, now=19240
D0605 17:42:31.036000000 24236 timer_generic.cc:722] TIMER CHECK END: r=2; next=20241
I0605 17:42:31.036000000 24236 timer_manager.cc:127] kick untimed waiter
I0605 17:42:31.036000000 24236 timer_manager.cc:135] flush exec_ctx
I0605 17:42:31.036000000 22224 timer_manager.cc:207] wait ended: was_timed:0 kicked:0
D0605 17:42:31.036000000 24236 exec_ctx.cc:36] running closure 000001E57301ADF0: created [C:\Users\colm_\source\repos\grpc\src\core\client_channel\backup_poller.cc:144]: scheduled [C:\Users\colm_\source\repos\grpc\src\core\lib\iomgr\timer_generic.cc:550]
D0605 17:42:31.036000000 22224 timer_generic.cc:696] TIMER CHECK BEGIN: now=19247 next=9223372036854775807 tls_min=11048 glob_min=20241
D0605 17:42:31.036000000 24236 timer_generic.cc:341] TIMER 000001E57301ADB0: SET 24247 now 19247 call 000001E57301ADF0[000001E575D3F920]
D0605 17:42:31.036000000 22224 timer_generic.cc:722] TIMER CHECK END: r=1; next=20241
D0605 17:42:31.036000000 24236 timer_generic.cc:377] .. add to shard 3 with queue_deadline_cap=20240 => is_first_timer=false
I0605 17:42:31.036000000 22224 timer_manager.cc:191] sleep for a 994 milliseconds
D0605 17:42:31.036000000 24236 exec_ctx.cc:48] closure 000001E57301ADF0 finished
D0605 17:42:31.036000000 24236 timer_generic.cc:696] TIMER CHECK BEGIN: now=19247 next=9223372036854775807 tls_min=16047 glob_min=20241
D0605 17:42:31.036000000 24236 timer_generic.cc:722] TIMER CHECK END: r=1; next=20241
I0605 17:42:31.036000000 24236 timer_manager.cc:201] sleep until kicked
I0605 17:42:32.040000000 22224 timer_manager.cc:207] wait ended: was_timed:1 kicked:0
D0605 17:42:32.040000000 22224 timer_generic.cc:696] TIMER CHECK BEGIN: now=20251 next=9223372036854775807 tls_min=20241 glob_min=20241
2024-06-05 17:42:32.040155 0000000000000000000000000000000000000000000000000000 [NOTICE] switch_event.c:467 Subclass reservation deleted for C:\Users\colm_\source\repos\freeswitch\src\mod\applications\mod_spok1_asr\mod_spok_grpc.c:spok::grpc
D0605 17:42:32.040000000 22224 timer_generic.cc:596] .. shard[1]->min_deadline = 20241
D0605 17:42:32.043000000 22224 timer_generic.cc:512] .. shard[1]: heap_empty=true
D0605 17:42:32.044000000 22224 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 21251
2024-06-05 17:42:14.336697 95.64% [NOTICE] mod_grpc.c:66 gRPC Channel 192.168.1.195:50051 state 2
2024-06-05 17:42:14.336697 95.64% [NOTICE] mod_grpc.c:263 gRPC channel created, profile->name routetest, uri 192.168.1.195:50051
Start the Completion Queue and it trundles through some reads and writes successfully ..
I0605 17:42:14.826000000 24236 timer_manager.cc:207] wait ended: was_timed:1 kicked:0
D0605 17:42:14.827000000 24236 timer_generic.cc:696] TIMER CHECK BEGIN: now=3038 next=9223372036854775807 tls_min=2032 glob_min=3037
D0605 17:42:14.827000000 24236 timer_generic.cc:596] .. shard[0]->min_deadline = 3037
D0605 17:42:14.827000000 24236 timer_generic.cc:512] .. shard[0]: heap_empty=true
D0605 17:42:14.827000000 24236 timer_generic.cc:483] .. shard[0]->queue_deadline_cap --> 4037
D0605 17:42:14.827000000 24236 timer_generic.cc:556] .. shard[0] popped 0
D0605 17:42:14.827000000 24236 timer_generic.cc:615] .. result --> 1, shard[0]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.828000000 24236 timer_generic.cc:512] .. shard[1]: heap_empty=true
D0605 17:42:14.828000000 24236 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 4038
D0605 17:42:14.828000000 24236 timer_generic.cc:556] .. shard[1] popped 0
D0605 17:42:14.828000000 24236 timer_generic.cc:615] .. result --> 1, shard[1]->min_deadline 3037 --> 4039, now=3038
D0605 17:42:14.828000000 24236 timer_generic.cc:512] .. shard[2]: heap_empty=true
D0605 17:42:14.829000000 24236 timer_generic.cc:483] .. shard[2]->queue_deadline_cap --> 4037
D0605 17:42:14.829000000 24236 timer_generic.cc:556] .. shard[2] popped 0
D0605 17:42:14.829000000 24236 timer_generic.cc:615] .. result --> 1, shard[2]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.829000000 24236 timer_generic.cc:512] .. shard[3]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[3]->queue_deadline_cap --> 4038
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[3] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[3]->min_deadline 3037 --> 4039, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[4]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[4]->queue_deadline_cap --> 4037
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[4] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[4]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[5]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[5]->queue_deadline_cap --> 4037
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[5] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[5]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[6]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[6]->queue_deadline_cap --> 4037
D0605 17:42:14.830000000 24236 timer_generic.cc:556] .. shard[6] popped 0
D0605 17:42:14.830000000 24236 timer_generic.cc:615] .. result --> 1, shard[6]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.830000000 24236 timer_generic.cc:512] .. shard[7]: heap_empty=true
D0605 17:42:14.830000000 24236 timer_generic.cc:483] .. shard[7]->queue_deadline_cap --> 4037
D0605 17:42:14.831000000 24236 timer_generic.cc:556] .. shard[7] popped 0
D0605 17:42:14.831000000 24236 timer_generic.cc:615] .. result --> 1, shard[7]->min_deadline 3037 --> 4038, now=3038
D0605 17:42:14.831000000 24236 timer_generic.cc:722] TIMER CHECK END: r=1; next=4038 tls_min=3037 glob_min=4038
D0605 17:42:26.852000000 24236 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 16062
D0605 17:42:26.852000000 24236 timer_generic.cc:556] .. shard[1] popped 0
D0605 17:42:26.852000000 24236 timer_generic.cc:615] .. result --> 1, shard[1]->min_deadline 15062 --> 16063, now=15062
D0605 17:42:26.852000000 24236 timer_generic.cc:722] TIMER CHECK END: r=1; next=16047
I0605 17:42:26.852000000 24236 timer_manager.cc:191] sleep for a 985 milliseconds
I0605 17:42:31.028000000 24236 timer_manager.cc:207] wait ended: was_timed:1 kicked:0
Call CQ->Shutdown()
I0605 17:42:31.028000000 24608 completion_queue.cc:1398] grpc_completion_queue_shutdown(cq=000001E571FF0360)
D0605 17:42:31.029000000 24236 timer_generic.cc:696] TIMER CHECK BEGIN: now=19240 next=9223372036854775807 tls_min=15062 glob_min=16047
I0605 17:42:31.029000000 24608 src/core/lib/gprpp/ref_counted.h:85] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:1101 ref 3 -> 4 shutting_down
D0605 17:42:31.029000000 24236 timer_generic.cc:596] .. shard[3]->min_deadline = 16047
I0605 17:42:31.029000000 24608 src/core/lib/gprpp/ref_counted.h:181] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:1116 unref 4 -> 3 shutting_down
D0605 17:42:31.029000000 25052 exec_ctx.cc:36] running closure 000001E571FF0460: created [C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:556]: scheduled [C:\Users\colm_\source\repos\grpc\src\core\lib\iomgr\pollset_windows.cc:150]
D0605 17:42:31.029000000 24236 timer_generic.cc:512] .. shard[3]: heap_empty=false
I0605 17:42:31.030000000 25052 src/core/lib/gprpp/ref_counted.h:181] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:616 unref 3 -> 2 pollset_destroy
D0605 17:42:31.030000000 24236 timer_generic.cc:525] .. check top timer deadline=16047 now=19240
D0605 17:42:31.030000000 25052 exec_ctx.cc:48] closure 000001E571FF0460 finished
D0605 17:42:31.030000000 24236 timer_generic.cc:532] TIMER 000001E57301ADB0: FIRE 3193ms late
I0605 17:42:31.030000000 25052 completion_queue.cc:1069] RETURN_EVENT[000001E571FF0360]: QUEUE_SHUTDOWN
But it just rolls on !
D0605 17:42:31.030000000 24236 timer_generic.cc:512] .. shard[3]: heap_empty=true
I0605 17:42:31.030000000 25052 src/core/lib/gprpp/ref_counted.h:181] completion_queue:000001E571FF0360 C:\Users\colm_\source\repos\grpc\src\core\lib\surface\completion_queue.cc:1070 unref 2 -> 1 next
D0605 17:42:31.030000000 24236 timer_generic.cc:483] .. shard[3]->queue_deadline_cap --> 20240
D0605 17:42:31.030000000 24236 timer_generic.cc:556] .. shard[3] popped 1
D0605 17:42:31.030000000 24236 timer_generic.cc:615] .. result --> 2, shard[3]->min_deadline 16047 --> 20241, now=19240
D0605 17:42:31.030000000 24236 timer_generic.cc:512] .. shard[7]: heap_empty=true
2024-06-05 17:42:31.028548 0000000000000000000000000000000000000000000000000000 [NOTICE] grpc_channel.cpp:291 Completion queue ending 0
D0605 17:42:31.030000000 24236 timer_generic.cc:483] .. shard[7]->queue_deadline_cap --> 20240
D0605 17:42:31.031000000 24236 timer_generic.cc:556] .. shard[7] popped 0
D0605 17:42:31.032000000 24236 timer_generic.cc:615] .. result --> 2, shard[7]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.032000000 24236 timer_generic.cc:512] .. shard[6]: heap_empty=true
D0605 17:42:31.032000000 24236 timer_generic.cc:483] .. shard[6]->queue_deadline_cap --> 20240
D0605 17:42:31.032000000 24236 timer_generic.cc:556] .. shard[6] popped 0
D0605 17:42:31.032000000 24236 timer_generic.cc:615] .. result --> 2, shard[6]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.032000000 24236 timer_generic.cc:512] .. shard[5]: heap_empty=true
D0605 17:42:31.033000000 24236 timer_generic.cc:483] .. shard[5]->queue_deadline_cap --> 20240
D0605 17:42:31.033000000 24236 timer_generic.cc:556] .. shard[5] popped 0
D0605 17:42:31.033000000 24236 timer_generic.cc:615] .. result --> 2, shard[5]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.033000000 24236 timer_generic.cc:512] .. shard[4]: heap_empty=true
D0605 17:42:31.033000000 24236 timer_generic.cc:483] .. shard[4]->queue_deadline_cap --> 20240
D0605 17:42:31.034000000 24236 timer_generic.cc:556] .. shard[4] popped 0
D0605 17:42:31.034000000 24236 timer_generic.cc:615] .. result --> 2, shard[4]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.034000000 24236 timer_generic.cc:512] .. shard[2]: heap_empty=true
D0605 17:42:31.034000000 24236 timer_generic.cc:483] .. shard[2]->queue_deadline_cap --> 20240
D0605 17:42:31.034000000 24236 timer_generic.cc:556] .. shard[2] popped 0
D0605 17:42:31.034000000 24236 timer_generic.cc:615] .. result --> 2, shard[2]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.035000000 24236 timer_generic.cc:512] .. shard[0]: heap_empty=true
D0605 17:42:31.035000000 24236 timer_generic.cc:483] .. shard[0]->queue_deadline_cap --> 20240
D0605 17:42:31.035000000 24236 timer_generic.cc:556] .. shard[0] popped 0
D0605 17:42:31.035000000 24236 timer_generic.cc:615] .. result --> 2, shard[0]->min_deadline 16054 --> 20241, now=19240
D0605 17:42:31.035000000 24236 timer_generic.cc:512] .. shard[1]: heap_empty=true
D0605 17:42:31.035000000 24236 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 20240
D0605 17:42:31.036000000 24236 timer_generic.cc:556] .. shard[1] popped 0
D0605 17:42:31.036000000 24236 timer_generic.cc:615] .. result --> 2, shard[1]->min_deadline 16063 --> 20241, now=19240
D0605 17:42:31.036000000 24236 timer_generic.cc:722] TIMER CHECK END: r=2; next=20241
I0605 17:42:31.036000000 24236 timer_manager.cc:127] kick untimed waiter
I0605 17:42:31.036000000 24236 timer_manager.cc:135] flush exec_ctx
I0605 17:42:31.036000000 22224 timer_manager.cc:207] wait ended: was_timed:0 kicked:0
D0605 17:42:31.036000000 24236 exec_ctx.cc:36] running closure 000001E57301ADF0: created [C:\Users\colm_\source\repos\grpc\src\core\client_channel\backup_poller.cc:144]: scheduled [C:\Users\colm_\source\repos\grpc\src\core\lib\iomgr\timer_generic.cc:550]
D0605 17:42:31.036000000 22224 timer_generic.cc:696] TIMER CHECK BEGIN: now=19247 next=9223372036854775807 tls_min=11048 glob_min=20241
D0605 17:42:31.036000000 24236 timer_generic.cc:341] TIMER 000001E57301ADB0: SET 24247 now 19247 call 000001E57301ADF0[000001E575D3F920]
D0605 17:42:31.036000000 22224 timer_generic.cc:722] TIMER CHECK END: r=1; next=20241
D0605 17:42:31.036000000 24236 timer_generic.cc:377] .. add to shard 3 with queue_deadline_cap=20240 => is_first_timer=false
I0605 17:42:31.036000000 22224 timer_manager.cc:191] sleep for a 994 milliseconds
D0605 17:42:31.036000000 24236 exec_ctx.cc:48] closure 000001E57301ADF0 finished
D0605 17:42:31.036000000 24236 timer_generic.cc:696] TIMER CHECK BEGIN: now=19247 next=9223372036854775807 tls_min=16047 glob_min=20241
D0605 17:42:31.036000000 24236 timer_generic.cc:722] TIMER CHECK END: r=1; next=20241
I0605 17:42:31.036000000 24236 timer_manager.cc:201] sleep until kicked
I0605 17:42:32.040000000 22224 timer_manager.cc:207] wait ended: was_timed:1 kicked:0
D0605 17:42:32.040000000 22224 timer_generic.cc:696] TIMER CHECK BEGIN: now=20251 next=9223372036854775807 tls_min=20241 glob_min=20241
2024-06-05 17:42:32.040155 0000000000000000000000000000000000000000000000000000 [NOTICE] switch_event.c:467 Subclass reservation deleted for C:\Users\colm_\source\repos\freeswitch\src\mod\applications\mod_spok1_asr\mod_spok_grpc.c:spok::grpc
D0605 17:42:32.040000000 22224 timer_generic.cc:596] .. shard[1]->min_deadline = 20241
D0605 17:42:32.043000000 22224 timer_generic.cc:512] .. shard[1]: heap_empty=true
D0605 17:42:32.044000000 22224 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 21251
Reply all
Reply to author
Forward
0 new messages