AdvancedLogTest test fail

[halajohn]

2025-08-17T07:20:55.2974360Z [ RUN ] AdvancedLogTest.LogAdvancedFileReopen
2025-08-17T07:20:55.2976960Z 08-17 07:20:55.282 14942(86554) �[32mI�[0m �[35mten_extension_on_stop�[0m�[34m@extension.c:757�[0m �[37m[extension 2] on_stop()�[0m
2025-08-17T07:20:55.2991360Z 08-17 07:20:55.282 14942(86554) �[32mI�[0m �[35mten_extension_on_stop_done�[0m�[34m@on_xxx.c:344�[0m �[37m[extension 2] on_stop() done�[0m
2025-08-17T07:20:55.2994360Z 08-17 07:20:55.282 14942(86554) �[32mI�[0m �[35mten_extension_on_stop�[0m�[34m@extension.c:757�[0m �[37m[extension 3] on_stop()�[0m
2025-08-17T07:20:55.2998900Z 08-17 07:20:55.282 14942(86554) �[32mI�[0m �[35mten_extension_on_stop_done�[0m�[34m@on_xxx.c:344�[0m �[37m[extension 3] on_stop() done�[0m
2025-08-17T07:20:55.3008560Z 08-17 07:20:55.282 14942(86554) �[36mD�[0m �[35mten_timer_on_close�[0m�[34m@timer.c:67�[0m �[37m[0] Timer can be closed now�[0m
2025-08-17T07:20:55.3013610Z 08-17 07:20:55.282 14942(86554) �[36mD�[0m �[35mten_timer_on_close�[0m�[34m@timer.c:67�[0m �[37m[0] Timer can be closed now�[0m
2025-08-17T07:20:55.3017030Z 08-17 07:20:55.282 14942(86554) �[36mD�[0m �[35mten_extension_on_deinit�[0m�[34m@extension.c:781�[0m �[37m[extension 3] on_deinit()�[0m
2025-08-17T07:20:55.3053840Z 08-17 07:20:55.282 14942(86554) �[36mD�[0m �[35mten_extension_on_deinit_done�[0m�[34m@on_xxx.c:456�[0m �[37m[extension 3] on_deinit() done�[0m
2025-08-17T07:20:55.3056010Z 08-17 07:20:55.282 14942(86554) �[36mD�[0m �[35mten_env_close�[0m�[34m@ten_env.c:192�[0m �[37m[extension 3] Close ten of extension�[0m
2025-08-17T07:20:55.3057970Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_timer_on_close�[0m�[34m@timer.c:67�[0m �[37m[0] Timer can be closed now�[0m
2025-08-17T07:20:55.3059930Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_timer_on_close�[0m�[34m@timer.c:67�[0m �[37m[0] Timer can be closed now�[0m
2025-08-17T07:20:55.3061970Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_on_deinit�[0m�[34m@extension.c:781�[0m �[37m[extension 2] on_deinit()�[0m
2025-08-17T07:20:55.3064150Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_on_deinit_done�[0m�[34m@on_xxx.c:456�[0m �[37m[extension 2] on_deinit() done�[0m
2025-08-17T07:20:55.3066240Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_env_close�[0m�[34m@ten_env.c:192�[0m �[37m[extension 2] Close ten of extension�[0m
2025-08-17T07:20:55.3068200Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_timer_on_close�[0m�[34m@timer.c:67�[0m �[37m[0] Timer can be closed now�[0m
2025-08-17T07:20:55.3070130Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_timer_on_close�[0m�[34m@timer.c:67�[0m �[37m[0] Timer can be closed now�[0m
2025-08-17T07:20:55.3072170Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_on_deinit�[0m�[34m@extension.c:781�[0m �[37m[extension 1] on_deinit()�[0m
2025-08-17T07:20:55.3074340Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_on_deinit_done�[0m�[34m@on_xxx.c:456�[0m �[37m[extension 1] on_deinit() done�[0m
2025-08-17T07:20:55.3076430Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_env_close�[0m�[34m@ten_env.c:192�[0m �[37m[extension 1] Close ten of extension�[0m
2025-08-17T07:20:55.3079030Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_thread_del_extension�[0m�[34m@on_xxx.c:374�[0m �[37m[extension 3] Deleted from extension thread (test_extension_group)�[0m
2025-08-17T07:20:55.3082390Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_thread_del_extension�[0m�[34m@on_xxx.c:374�[0m �[37m[extension 2] Deleted from extension thread (test_extension_group)�[0m
2025-08-17T07:20:55.3085560Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_thread_del_extension�[0m�[34m@on_xxx.c:374�[0m �[37m[extension 1] Deleted from extension thread (test_extension_group)�[0m
2025-08-17T07:20:55.3088700Z 08-17 07:20:55.283 14942(86554) �[36mD�[0m �[35mten_extension_group_destroy_extensions�[0m�[34m@extension_group.c:196�[0m �[37m[test_extension_group] destroy_extensions�[0m
2025-08-17T07:20:55.3091140Z 08-17 07:20:55.283 14942(46331) �[32mI�[0m �[35mten_extension_destroy�[0m�[34m@extension.c:177�[0m �[37m[extension 1] Destroyed�[0m
2025-08-17T07:20:55.3093290Z 08-17 07:20:55.284 14942(46331) �[32mI�[0m �[35mten_extension_destroy�[0m�[34m@extension.c:177�[0m �[37m[extension 2] Destroyed�[0m
2025-08-17T07:20:55.3095420Z 08-17 07:20:55.284 14942(46331) �[32mI�[0m �[35mten_extension_destroy�[0m�[34m@extension.c:177�[0m �[37m[extension 3] Destroyed�[0m
2025-08-17T07:20:55.3098070Z 08-17 07:20:55.285 14942(86554) �[36mD�[0m �[35mten_extension_group_on_destroy_extensions_done�[0m�[34m@on_xxx.c:204�[0m �[37m[test_extension_group] destroy_extensions() done�[0m
2025-08-17T07:20:55.3100750Z 08-17 07:20:55.285 14942(86554) �[36mD�[0m �[35mten_extension_group_on_deinit_done�[0m�[34m@on_xxx.c:117�[0m �[37m[test_extension_group] on_deinit() done�[0m
2025-08-17T07:20:55.3103310Z 08-17 07:20:55.285 14942(86554) �[36mD�[0m �[35mten_env_close�[0m�[34m@ten_env.c:188�[0m �[37m[test_extension_group] Close ten of extension group.�[0m
2025-08-17T07:20:55.3107890Z 08-17 07:20:55.285 14942(86542) �[36mD�[0m �[35mten_engine_on_remove_extension_thread_from_engine�[0m�[34m@on_xxx.c:43�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Remove extension thread (0x60000329ca50) from engine�[0m
2025-08-17T07:20:55.3111370Z 08-17 07:20:55.286 14942(86554) �[36mD�[0m �[35mten_extension_thread_main_actual�[0m�[34m@extension_thread.c:296�[0m �[37m[test_extension_group] Notifying engine that we are closed�[0m
2025-08-17T07:20:55.3114490Z 08-17 07:20:55.286 14942(86554) �[36mD�[0m �[35mten_extension_thread_main_actual�[0m�[34m@extension_thread.c:301�[0m �[37m[test_extension_group] Extension thread is exited�[0m
2025-08-17T07:20:55.3117770Z 08-17 07:20:55.286 14942(86542) �[36mD�[0m �[35mten_engine_on_extension_thread_closed_task�[0m�[34m@on_xxx.c:72�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Waiting for extension thread (0x60000329ca50) be reclaimed�[0m
2025-08-17T07:20:55.3121190Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_engine_on_extension_thread_closed_task�[0m�[34m@on_xxx.c:81�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Extension thread (0x60000329ca50) is reclaimed�[0m
2025-08-17T07:20:55.3124440Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_extension_context_on_close�[0m�[34m@extension_context.c:202�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Extension context can be closed now�[0m
2025-08-17T07:20:55.3127360Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_env_close�[0m�[34m@ten_env.c:183�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Close ten of engine�[0m
2025-08-17T07:20:55.3130030Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_engine_on_extension_context_closed�[0m�[34m@close.c:316�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Extension context closed�[0m
2025-08-17T07:20:55.3132690Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_engine_on_close�[0m�[34m@close.c:285�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Engine can be closed now�[0m
2025-08-17T07:20:55.3135570Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_app_del_engine�[0m�[34m@engine_interface.c:139�[0m �[37m[msgpack://127.0.0.1:8001/:cc604368-5e4f-49c7-820b-955dab63e06f] Remove engine from app�[0m
2025-08-17T07:20:55.3138190Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_engine_destroy�[0m�[34m@engine.c:66�[0m �[37m[cc604368-5e4f-49c7-820b-955dab63e06f] Destroy engine�[0m
2025-08-17T07:20:55.3140560Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_app_close�[0m�[34m@close.c:164�[0m �[37m[msgpack://127.0.0.1:8001/] Try to close app�[0m
2025-08-17T07:20:55.3142850Z 08-17 07:20:55.287 14942(86542) �[36mD�[0m �[35mten_app_proceed_to_close�[0m�[34m@close.c:53�[0m �[37m[msgpack://127.0.0.1:8001/] Could not close alive app�[0m
2025-08-17T07:20:55.3145240Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_app_close_sync�[0m�[34m@close.c:82�[0m �[37m[msgpack://127.0.0.1:8001/] Try to close app�[0m
2025-08-17T07:20:55.3147650Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_protocol_close�[0m�[34m@close.c:120�[0m �[37m[msgpack://127.0.0.1:8001/] Try to close listening protocol�[0m
2025-08-17T07:20:55.3150340Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_protocol_integrated_on_close�[0m�[34m@close.c:107�[0m �[37m[msgpack://127.0.0.1:8001/] Integrated protocol can be closed now�[0m
2025-08-17T07:20:55.3152930Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_protocol_on_close�[0m�[34m@close.c:84�[0m �[37m[msgpack://127.0.0.1:8001/] Base protocol can be closed now�[0m
2025-08-17T07:20:55.3155180Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_app_proceed_to_close�[0m�[34m@close.c:56�[0m �[37m[msgpack://127.0.0.1:8001/] Close app�[0m
2025-08-17T07:20:55.3157300Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_env_close�[0m�[34m@ten_env.c:179�[0m �[37m[msgpack://127.0.0.1:8001/] Close ten of app�[0m
2025-08-17T07:20:55.3159680Z 08-17 07:20:55.288 14942(86542) �[32mI�[0m �[35mten_app_on_deinit_done�[0m�[34m@on_xxx.c:493�[0m �[37m[msgpack://127.0.0.1:8001/] App on_deinit_done()�[0m
2025-08-17T07:20:55.3161670Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_app_start�[0m�[34m@internal.c:82�[0m �[37mTEN app runloop ends�[0m
2025-08-17T07:20:55.3163700Z 08-17 07:20:55.288 14942(86542) �[36mD�[0m �[35mten_app_destroy�[0m�[34m@app.c:177�[0m �[37m[msgpack://127.0.0.1:8001/] Destroy app�[0m
2025-08-17T07:20:55.3165520Z 08-17 07:20:55.290 14942(86555) �[32mI�[0m �[35mten_app_routine�[0m�[34m@app.c:82�[0m �[37m[] App is created�[0m
2025-08-17T07:20:55.3167840Z 08-17 07:20:55.294 14942(86555) �[33mW�[0m �[35mten_find_app_base_dir�[0m�[34m@base_dir.c:52�[0m �[37mCould not get app home from module path, using TEN_APP_BASE_DIR instead�[0m
2025-08-17T07:20:55.3170260Z 08-17 07:20:55.294 14942(86555) �[36mD�[0m �[35mten_app_find_and_set_base_dir�[0m�[34m@base_dir.c:65�[0m �[37mFailed to determine app base directory�[0m
2025-08-17T07:20:55.3172910Z 08-17 07:20:55.299 14942(86555) �[32mI�[0m �[35mten_set_default_manifest_info�[0m�[34m@default.c:25�[0m �[37mSkip the loading of manifest.json because the base_dir of '' is missing�[0m
2025-08-17T07:20:55.3175640Z 08-17 07:20:55.314 14942(46331) �[32mI�[0m �[35mten_app_create_protocol_with_uri�[0m�[34m@protocol.c:200�[0m �[37m[] Loading protocol addon: msgpack�[0m
2025-08-17T07:20:58.7065880Z Received SIGHUP (1)
2025-08-17T07:21:01.7727690Z Received SIGHUP (1)
2025-08-17T07:21:01.9090590Z [ OK ] AdvancedLogTest.LogAdvancedFileReopen (6618 ms)
2025-08-17T07:21:01.9121440Z 08-17 07:21:01.909 14942(86981) �[32mI�[0m �[35mten_app_routine�[0m�[34m@app.c:82�[0m �[37m[] App is created�[0m
2025-08-17T07:21:01.9122580Z [ RUN ] AdvancedLogTest.LogAdvancedFileReopen2
2025-08-17T07:21:01.9159180Z 08-17 07:21:01.912 14942(86981) �[33mW�[0m �[35mten_find_app_base_dir�[0m�[34m@base_dir.c:52�[0m �[37mCould not get app home from module path, using TEN_APP_BASE_DIR instead�[0m
2025-08-17T07:21:01.9186630Z 08-17 07:21:01.912 14942(86981) �[36mD�[0m �[35mten_app_find_and_set_base_dir�[0m�[34m@base_dir.c:65�[0m �[37mFailed to determine app base directory�[0m
2025-08-17T07:21:01.9208430Z 08-17 07:21:01.917 14942(86981) �[32mI�[0m �[35mten_set_default_manifest_info�[0m�[34m@default.c:25�[0m �[37mSkip the loading of manifest.json because the base_dir of '' is missing�[0m
2025-08-17T07:21:01.9235680Z 08-17 07:21:01.922 14942(46331) �[32mI�[0m �[35mten_app_create_protocol_with_uri�[0m�[34m@protocol.c:200�[0m �[37m[] Loading protocol addon: msgpack�[0m
2025-08-17T07:21:05.1911900Z Received SIGHUP (1)
2025-08-17T07:21:08.2425490Z Received SIGHUP (1)
2025-08-17T07:21:11.4525150Z 08-17 07:21:11.451 14942(87432) �[32mI�[0m �[35mten_app_routine�[0m�[34m@app.c:82�[0m �[37m[] App is created�[0m
2025-08-17T07:21:11.4526210Z Expected 93 messages, but found 92
2025-08-17T07:21:11.4563580Z 08-17 07:21:11.455 14942(87432) �[33mW�[0m �[35mten_find_app_base_dir�[0m�[34m@base_dir.c:52�[0m �[37mCould not get app home from module path, using TEN_APP_BASE_DIR instead�[0m
2025-08-17T07:21:11.4565980Z ../../../tests/ten_runtime/smoke/advanced_log_test/log_advanced_file_reopen_2.cc:260: Failure
2025-08-17T07:21:11.4568940Z 08-17 07:21:11.455 14942(87432) �[36mD�[0m �[35mten_app_find_and_set_base_dir�[0m�[34m@base_dir.c:65�[0m �[37mFailed to determine app base directory�[0m
2025-08-17T07:21:11.4569990Z Failed
2025-08-17T07:21:11.4573560Z [ FAILED ] AdvancedLogTest.LogAdvancedFileReopen2 (9542 ms)