TEN-framework
[BUG] ten_runtime/integration/nodejs/go_app_websocket_server_nodejs testing hang
Description
2025-04-28T16:42:51.5314598Z tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/test_case.py Assembling and building package "go_app_websocket_server_nodejs_app".
2025-04-28T16:42:51.5316804Z > Install app to /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app
2025-04-28T16:42:51.5319755Z > ['/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/../../../../../ten_manager/bin/tman', '--verbose', '--config-file=/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/../../../../../tests/local_registry/config.json', 'create', 'app', 'go_app_websocket_server_nodejs_app', '--template', 'default_app_go']
2025-04-28T16:42:51.5323975Z > { /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/../../../../../ten_manager/bin/tman --verbose --config-file=/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/../../../../../tests/local_registry/config.json create app go_app_websocket_server_nodejs_app --template default_app_go; }
2025-04-28T16:42:51.5325768Z > Replace files after install app
2025-04-28T16:42:51.5326739Z > Install_all: /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app
2025-04-28T16:42:51.5329097Z > { /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/../../../../../ten_manager/bin/tman --config-file=/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/../../../../../tests/local_registry/config.json --yes install; }
2025-04-28T16:42:51.5330525Z Get all installed packages...
2025-04-28T16:42:51.5330791Z Filter compatible packages...
2025-04-28T16:42:51.5331501Z Attempting to retrieve information about locked packages from manifest-lock.json...
2025-04-28T16:42:51.5332022Z Collect all candidate packages...
2025-04-28T16:42:51.5332270Z Resolving packages...
2025-04-28T16:42:51.5332627Z The following local packages do not appear in the dependency tree:
2025-04-28T16:42:51.5333032Z app:[email protected]
2025-04-28T16:42:51.5333274Z Creating manifest-lock.json...
2025-04-28T16:42:51.5333736Z + Installing packages...
2025-04-28T16:42:51.5334017Z :-) Install successfully in 2 seconds
2025-04-28T16:42:51.5334395Z > Replace files after install all
2025-04-28T16:42:51.5335479Z > Start to build package(go_app_websocket_server_nodejs_app) in /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app
2025-04-28T16:42:51.5336686Z go(14669) > 16:42:51 Go version [1.22.3] is found.
2025-04-28T16:42:51.5337882Z go(14669) > 16:42:51 Go app [/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app] is found.
2025-04-28T16:42:51.5560162Z go(14669) > 16:42:51 /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app/ten_packages/extension/http_server_extension_nodejs is not a GO extension, no go.mod
2025-04-28T16:42:51.5563967Z go(14669) > 16:42:51 /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app/ten_packages/extension/websocket_server_nodejs is not a GO extension, no go.mod
2025-04-28T16:42:51.5565716Z go(14669) > 16:42:51 Go env:
2025-04-28T16:42:51.5567484Z go(14669) > 16:42:51 GOGCCFLAGS='-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build2709644264=/tmp/go-build -gno-record-gcc-switches'
2025-04-28T16:42:51.5568974Z go(14669) > 16:42:51 CGO_ENABLED='1'
2025-04-28T16:42:51.5569503Z go(14669) > 16:42:51 CGO_FFLAGS='-O2 -g'
2025-04-28T16:42:51.5570045Z go(14669) > 16:42:51 GOHOSTARCH='amd64'
2025-04-28T16:42:51.5570523Z go(14669) > 16:42:51 AR='ar'
2025-04-28T16:42:51.5570842Z go(14669) > 16:42:51 CGO_CXXFLAGS='-O2 -g'
2025-04-28T16:42:51.5571327Z go(14669) > 16:42:51 GONOSUMDB='.agoralab.co'
2025-04-28T16:42:51.5571670Z go(14669) > 16:42:51 GOPRIVATE='.agoralab.co'
2025-04-28T16:42:51.5572004Z go(14669) > 16:42:51 PKG_CONFIG='pkg-config'
2025-04-28T16:42:51.5572321Z go(14669) > 16:42:51 GOHOSTOS='linux'
2025-04-28T16:42:51.5572637Z go(14669) > 16:42:51 GONOPROXY='*.agoralab.co'
2025-04-28T16:42:51.5572938Z go(14669) > 16:42:51 GOARCH='amd64'
2025-04-28T16:42:51.5573287Z go(14669) > 16:42:51 GOCACHE='/github/home/.cache/go-build'
2025-04-28T16:42:51.5574632Z go(14669) > 16:42:51 GOMOD='/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app/go.mod'
2025-04-28T16:42:51.5575574Z go(14669) > 16:42:51 GOTOOLCHAIN='auto'
2025-04-28T16:42:51.5575929Z go(14669) > 16:42:51 CC='clang'
2025-04-28T16:42:51.5576200Z go(14669) > 16:42:51 CGO_CPPFLAGS=''
2025-04-28T16:42:51.5576591Z go(14669) > 16:42:51 GOEXPERIMENT=''
2025-04-28T16:42:51.5576876Z go(14669) > 16:42:51 GOOS='linux'
2025-04-28T16:42:51.5577228Z go(14669) > 16:42:51 GOVERSION='go1.22.3'
2025-04-28T16:42:51.5577550Z go(14669) > 16:42:51 CXX='clang++'
2025-04-28T16:42:51.5577893Z go(14669) > 16:42:51 GOENV='/github/home/.config/go/env'
2025-04-28T16:42:51.5578318Z go(14669) > 16:42:51 GOINSECURE=''
2025-04-28T16:42:51.5578614Z go(14669) > 16:42:51 GOSUMDB='sum.golang.org'
2025-04-28T16:42:51.5579007Z go(14669) > 16:42:51 GOTMPDIR=''
2025-04-28T16:42:51.5579285Z go(14669) > 16:42:51 GCCGO='gccgo'
2025-04-28T16:42:51.5579589Z go(14669) > 16:42:51 GOFLAGS=''
2025-04-28T16:42:51.5579902Z go(14669) > 16:42:51 GOAMD64='v1'
2025-04-28T16:42:51.5580512Z go(14669) > 16:42:51 GOPROXY='https://proxy.golang.org,direct'
2025-04-28T16:42:51.5580907Z go(14669) > 16:42:51 GOROOT='/usr/local/go'
2025-04-28T16:42:51.5581391Z go(14669) > 16:42:51 GOTOOLDIR='/usr/local/go/pkg/tool/linux_amd64'
2025-04-28T16:42:51.5581739Z go(14669) > 16:42:51 GOVCS=''
2025-04-28T16:42:51.5582028Z go(14669) > 16:42:51 GOWORK=''
2025-04-28T16:42:51.5582360Z go(14669) > 16:42:51 CGO_CFLAGS='-O2 -g'
2025-04-28T16:42:51.5583207Z go(14669) > 16:42:51 CGO_LDFLAGS='-Lten_packages/system/ten_runtime_go/lib -lten_runtime_go -Wl,-rpath=$ORIGIN/../ten_packages/system/ten_runtime_go/lib -O2 -g'
2025-04-28T16:42:51.5584232Z go(14669) > 16:42:51 GOEXE=''
2025-04-28T16:42:51.5584562Z go(14669) > 16:42:51 GOMODCACHE='/github/home/go/pkg/mod'
2025-04-28T16:42:51.5585015Z go(14669) > 16:42:51 GOPATH='/github/home/go'
2025-04-28T16:42:51.5585670Z go(14669) > 16:42:51 GO111MODULE=''
2025-04-28T16:42:51.5586167Z go(14669) > 16:42:51 GOBIN=''
2025-04-28T16:42:51.5588012Z go(14669) > 16:42:51 Run 'go mod tidy' on [/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app].
2025-04-28T16:42:51.5895438Z go(14669) > 16:42:51 Run 'go generate' on [/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app].
2025-04-28T16:42:51.6034323Z go(14669) > 16:42:51 No extension is detected, no need to generate import file.
2025-04-28T16:42:51.6035537Z go(14669) > 16:42:51 No extension is detected, no need to require extension modules.
2025-04-28T16:42:51.6036719Z go(14669) > 16:42:51 Run 'go mod tidy' on [/__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app].
2025-04-28T16:42:51.6303707Z go(14669) > 16:42:51 Build GO app with command: go build -o bin/main -v .
2025-04-28T16:42:51.8102803Z go(14669) > 16:42:51 ten_framework/ten_runtime
2025-04-28T16:42:57.0250886Z go(14669) > 16:42:57 app
2025-04-28T16:42:57.4688276Z go(14669) > 16:42:57 Build GO app successfully.
2025-04-28T16:42:57.4947647Z Get all installed packages...
2025-04-28T16:42:57.5367073Z Filter compatible packages...
2025-04-28T16:42:57.5367916Z Attempting to retrieve information about locked packages from manifest-lock.json...
2025-04-28T16:42:57.5375097Z Collect all candidate packages...
2025-04-28T16:42:57.5481314Z Resolving packages...
2025-04-28T16:42:57.5510664Z The following local packages do not appear in the dependency tree:
2025-04-28T16:42:57.5511319Z app:[email protected]
2025-04-28T16:42:57.5515875Z + Installing packages...
2025-04-28T16:42:57.5516468Z :-) Install successfully in 0 seconds
2025-04-28T16:43:07.5129706Z 04-28 16:43:07.512 15079(15086) [33mW[0m [35mpthread_routine[0m[[email protected]:114[0m [37mFailed to set thread name: [0m
2025-04-28T16:43:07.5131183Z 04-28 16:43:07.512 15079(15086) [32mI[0m [35mten_app_routine[0m[[email protected]:82[0m [37m[] App is created.[0m
2025-04-28T16:43:07.5133054Z 04-28 16:43:07.512 15079(15079) [36mD[0m [35mten_app_wait[0m[[email protected]:253[0m [37mWait app thread ends.[0m
2025-04-28T16:43:07.5135015Z 04-28 16:43:07.513 15079(15086) [36mD[0m [35mOnConfigure[0m[[email protected]:33[0m [37m[] OnConfigure.[0m
2025-04-28T16:43:07.5136138Z 04-28 16:43:07.513 15079(15086) [36mD[0m [35mOnConfigureDone[0m[34m@ten_env.go:293[0m [37m[] OnConfigureDone[0m
2025-04-28T16:43:07.6051721Z 04-28 16:43:07.604 15079(15086) [36mD[0m [35mload_all_dynamic_libraries_under_path[0m[34m@addon_autoload.c:131[0m [37mLoaded module: /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app/ten_packages/addon_loader/nodejs_addon_loader/lib/libnodejs_addon_loader.so[0m
2025-04-28T16:43:07.6056973Z 04-28 16:43:07.604 15079(15086) [36mD[0m [35mload_all_dynamic_libraries_under_path[0m[34m@addon_autoload.c:131[0m [37mLoaded module: /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app/ten_packages/addon_loader/nodejs_addon_loader/lib/libnode.so[0m
2025-04-28T16:43:07.6060410Z 04-28 16:43:07.604 15079(15086) [36mD[0m [35mten_app_create_addon_instance[0m[[email protected]:386[0m [37mTry to find addon for nodejs_addon_loader[0m
2025-04-28T16:43:07.6062420Z 04-28 16:43:07.604 15079(15086) [32mI[0m [35mten_app_create_addon_instance[0m[[email protected]:393[0m [37mThe addon nodejs_addon_loader already exists; create an instance of it.[0m
2025-04-28T16:43:07.7017013Z ten_runtime_nodejs module loaded successfully
2025-04-28T16:43:07.7026767Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_app_create_engine[0m[34m@engine_interface.c:109[0m [37m[localhost] App creates an engine.[0m
2025-04-28T16:43:07.7028817Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_engine_create[0m[[email protected]:178[0m [37mCreate engine.[0m
2025-04-28T16:43:07.7030427Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mOnInit[0m[[email protected]:20[0m [37m[localhost] onInit[0m
2025-04-28T16:43:07.7032403Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_engine_handle_in_msgs_task[0m[[email protected]:222[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Handle incoming messages.[0m
2025-04-28T16:43:07.7035201Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_engine_handle_cmd_start_graph[0m[34m@start_graph.c:61[0m [37mNo more extensions need to be connected in the graph, enable the extension system now.[0m
2025-04-28T16:43:07.7037597Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_extension_context_create[0m[34m@extension_context.c:60[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Create Extension context.[0m
2025-04-28T16:43:07.7039852Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_app_create_addon_instance[0m[[email protected]:386[0m [37mTry to find addon for default_extension_group[0m
2025-04-28T16:43:07.7042393Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_app_create_addon_instance[0m[[email protected]:419[0m [37mThe addon default_extension_group is loaded and registered using native addon loader successfully.[0m
2025-04-28T16:43:07.7045004Z 04-28 16:43:07.702 15079(15098) [36mD[0m [35mten_extension_thread_main_actual[0m[34m@extension_thread.c:248[0m [37mExtension thread is started[0m
2025-04-28T16:43:07.7047112Z 04-28 16:43:07.702 15079(15098) [36mD[0m [35mten_extension_group_load_metadata[0m[[email protected]:24[0m [37m[default_extension_group] Load metadata.[0m
2025-04-28T16:43:07.7049173Z 04-28 16:43:07.702 15079(15098) [36mD[0m [35mten_extension_group_on_init_done[0m[34m@on_xxx.c:78[0m [37m[default_extension_group] on_init() done.[0m
2025-04-28T16:43:07.7051660Z 04-28 16:43:07.702 15079(15098) [32mI[0m [35mten_set_default_manifest_info[0m[[email protected]:25[0m [37mSkip the loading of manifest.json because the base_dir of default_extension_group is missing.[0m
2025-04-28T16:43:07.7054649Z 04-28 16:43:07.702 15079(15098) [32mI[0m [35mten_set_default_property_info[0m[[email protected]:51[0m [37mSkip the loading of property.json because the base_dir of default_extension_group is missing.[0m
2025-04-28T16:43:07.7057231Z 04-28 16:43:07.702 15079(15098) [36mD[0m [35mten_extension_group_create_extensions[0m[34m@extension_group.c:179[0m [37m[default_extension_group] create_extensions.[0m
2025-04-28T16:43:07.7059493Z 04-28 16:43:07.702 15079(15086) [36mD[0m [35mten_app_create_addon_instance[0m[[email protected]:386[0m [37mTry to find addon for http_server_extension_nodejs[0m
2025-04-28T16:43:07.7061983Z 04-28 16:43:07.702 15079(15086) [32mI[0m [35mten_addon_manager_register_specific_addon[0m[34m@addon_manager.c:243[0m [37mUnable to find 'extension:http_server_extension_nodejs' in registry.[0m
2025-04-28T16:43:07.7066873Z 04-28 16:43:07.703 15079(15086) [32mI[0m [35mten_addon_load_specific_addon_using_native_addon_loader[0m[34m@addon_autoload.c:351[0m [37mAddon lib/ folder does not exist or is not a directory: /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app/ten_packages/extension/http_server_extension_nodejs/lib[0m
2025-04-28T16:43:07.7070786Z 04-28 16:43:07.703 15079(15086) [36mD[0m [35mten_app_create_addon_instance[0m[[email protected]:426[0m [37mTry to load the addon http_server_extension_nodejs using all installed addon loaders.[0m
2025-04-28T16:43:07.7073055Z 04-28 16:43:07.703 15079(15086) [36mD[0m [35mten_app_create_addon_instance[0m[[email protected]:386[0m [37mTry to find addon for websocket_server_nodejs[0m
2025-04-28T16:43:07.7075723Z 04-28 16:43:07.703 15079(15086) [32mI[0m [35mten_addon_manager_register_specific_addon[0m[34m@addon_manager.c:243[0m [37mUnable to find 'extension:websocket_server_nodejs' in registry.[0m
2025-04-28T16:43:07.7080544Z 04-28 16:43:07.703 15079(15086) [32mI[0m [35mten_addon_load_specific_addon_using_native_addon_loader[0m[34m@addon_autoload.c:351[0m [37mAddon lib/ folder does not exist or is not a directory: /__w/ten-framework/ten-framework/out/linux/x64/tests/ten_runtime/integration/nodejs/go_app_websocket_server_nodejs/go_app_websocket_server_nodejs_app/ten_packages/extension/websocket_server_nodejs/lib[0m
2025-04-28T16:43:07.7084614Z 04-28 16:43:07.703 15079(15086) [36mD[0m [35mten_app_create_addon_instance[0m[[email protected]:426[0m [37mTry to load the addon websocket_server_nodejs using all installed addon loaders.[0m
2025-04-28T16:43:07.7556225Z 04-28 16:43:07.755 15079(15087) [36mD[0m [35mten_nodejs_addon_manager_add_extension_addon[0m[34m@addon_manager.c:397[0m [37mTEN JS Addon: ten_nodejs_addon_manager_add_extension_addon[0m
2025-04-28T16:43:07.7562710Z 04-28 16:43:07.755 15079(15087) [32mI[0m [35mten_nodejs_addon_manager_add_extension_addon[0m[34m@addon_manager.c:429[0m [37mAdding Nodejs addon: http_server_extension_nodejs to the native addon manager.[0m
2025-04-28T16:43:07.7564522Z RegisterAddonAsExtension http_server_extension_nodejs registered
2025-04-28T16:43:07.7565288Z Addon http_server_extension_nodejs loaded
2025-04-28T16:43:07.7567434Z 04-28 16:43:07.755 15079(15087) [36mD[0m [35mten_nodejs_addon_manager_register_addon_as_extension[0m[34m@addon_manager.c:282[0m [37mTEN JS Addon: ten_nodejs_addon_manager_register_addon_as_extension[0m
2025-04-28T16:43:07.7570168Z 04-28 16:43:07.755 15079(15087) [32mI[0m [35mten_nodejs_addon_manager_register_addon_as_extension[0m[34m@addon_manager.c:305[0m [37mRegistering addon: http_server_extension_nodejs[0m
2025-04-28T16:43:07.7571513Z Addon http_server_extension_nodejs registered
2025-04-28T16:43:07.7572737Z 04-28 16:43:07.755 15079(15086) [32mI[0m [35mproxy_on_init[0m[[email protected]:286[0m [37maddon proxy_on_init[0m
2025-04-28T16:43:07.7574857Z 04-28 16:43:07.755 15079(15086) [36mD[0m [35mten_nodejs_addon_register_func[0m[34m@addon_manager.c:388[0m [37mJS addon manager registerSingleAddon() completed.[0m
2025-04-28T16:43:07.7577021Z 04-28 16:43:07.755 15079(15086) [32mI[0m [35mproxy_on_create_instance[0m[[email protected]:349[0m [37maddon proxy_on_create_instance name: http_server_extension_nodejs[0m
2025-04-28T16:43:07.7595176Z DefaultAddon onInit
2025-04-28T16:43:07.7601743Z 04-28 16:43:07.759 15079(15098) [32mI[0m [35mon_addon_create_extension_done[0m[34m@builtin_extension_group.c:92[0m [37mSuccess to create extension http_server_extension_nodejs[0m
2025-04-28T16:43:07.7720647Z (node:15079) Warning: Closing directory handle on garbage collection
2025-04-28T16:43:07.8574419Z 04-28 16:43:07.856 15079(15087) [36mD[0m [35mten_nodejs_addon_manager_add_extension_addon[0m[34m@addon_manager.c:397[0m [37mTEN JS Addon: ten_nodejs_addon_manager_add_extension_addon[0m
2025-04-28T16:43:07.8576656Z 04-28 16:43:07.856 15079(15087) [32mI[0m [35mten_nodejs_addon_manager_add_extension_addon[0m[34m@addon_manager.c:429[0m [37mAdding Nodejs addon: websocket_server_nodejs to the native addon manager.[0m
2025-04-28T16:43:07.8578423Z RegisterAddonAsExtension websocket_server_nodejs registered
2025-04-28T16:43:07.8578900Z Addon websocket_server_nodejs loaded
2025-04-28T16:43:07.8580116Z 04-28 16:43:07.857 15079(15087) [36mD[0m [35mten_nodejs_addon_manager_register_addon_as_extension[0m[34m@addon_manager.c:282[0m [37mTEN JS Addon: ten_nodejs_addon_manager_register_addon_as_extension[0m
2025-04-28T16:43:07.8582671Z 04-28 16:43:07.857 15079(15087) [32mI[0m [35mten_nodejs_addon_manager_register_addon_as_extension[0m[34m@addon_manager.c:305[0m [37mRegistering addon: websocket_server_nodejs[0m
2025-04-28T16:43:07.8583457Z Addon websocket_server_nodejs registered
2025-04-28T16:43:07.8584822Z 04-28 16:43:07.858 15079(15086) [32mI[0m [35mproxy_on_init[0m[[email protected]:286[0m [37maddon proxy_on_init[0m
2025-04-28T16:43:07.8586334Z 04-28 16:43:07.858 15079(15086) [36mD[0m [35mten_nodejs_addon_register_func[0m[34m@addon_manager.c:388[0m [37mJS addon manager registerSingleAddon() completed.[0m
2025-04-28T16:43:07.8587594Z 04-28 16:43:07.858 15079(15086) [32mI[0m [35mproxy_on_create_instance[0m[[email protected]:349[0m [37maddon proxy_on_create_instance name: websocket_server_nodejs[0m
2025-04-28T16:43:07.8588166Z WS server addon onInit
2025-04-28T16:43:07.8591409Z 04-28 16:43:07.858 15079(15098) [32mI[0m [35mon_addon_create_extension_done[0m[34m@builtin_extension_group.c:92[0m [37mSuccess to create extension websocket_server_nodejs[0m
2025-04-28T16:43:07.8594014Z 04-28 16:43:07.858 15079(15098) [36mD[0m [35mten_extension_group_on_create_extensions_done[0m[34m@on_xxx.c:160[0m [37m[default_extension_group] create_extensions() done.[0m
2025-04-28T16:43:07.8595536Z 04-28 16:43:07.859 15079(15086) [36mD[0m [35mten_engine_on_all_extension_threads_are_ready[0m[34m@extension_interface.c:173[0m [37m[localhost] Engine is ready to handle messages.[0m
2025-04-28T16:43:07.8597812Z 04-28 16:43:07.859 15079(15086) [36mD[0m [35mten_app_handle_cmd_result[0m[[email protected]:374[0m [37mThe 'start_graph' flow is not completed, skip the cmd_result now.[0m
2025-04-28T16:43:07.8600038Z 04-28 16:43:07.859 15079(15086) [36mD[0m [35mten_engine_handle_in_msgs_task[0m[[email protected]:222[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Handle incoming messages.[0m
2025-04-28T16:43:07.8602146Z 04-28 16:43:07.859 15079(15098) [36mD[0m [35mten_extension_load_metadata[0m[[email protected]:888[0m [37m[http_server_extension_nodejs] Load metadata.[0m
2025-04-28T16:43:07.8604652Z 04-28 16:43:07.859 15079(15098) [36mD[0m [35mten_extension_on_configure[0m[[email protected]:628[0m [37m[http_server_extension_nodejs] on_configure().[0m
2025-04-28T16:43:07.8607432Z 04-28 16:43:07.859 15079(15098) [32mI[0m [35mproxy_on_configure[0m[[email protected]:635[0m [37mextension proxy_on_configure[0m
2025-04-28T16:43:07.8609484Z 04-28 16:43:07.859 15079(15098) [36mD[0m [35mten_extension_load_metadata[0m[[email protected]:888[0m [37m[websocket_server_nodejs] Load metadata.[0m
2025-04-28T16:43:07.8610984Z 04-28 16:43:07.859 15079(15098) [36mD[0m [35mten_extension_on_configure[0m[[email protected]:628[0m [37m[websocket_server_nodejs] on_configure().[0m
2025-04-28T16:43:07.8612222Z 04-28 16:43:07.859 15079(15098) [32mI[0m [35mproxy_on_configure[0m[[email protected]:635[0m [37mextension proxy_on_configure[0m
2025-04-28T16:43:07.8612741Z HttpServerExtension onConfigure
2025-04-28T16:43:07.8613793Z 04-28 16:43:07.859 15079(15098) [36mD[0m [35mten_extension_on_configure_done[0m[34m@on_xxx.c:96[0m [37m[http_server_extension_nodejs] on_configure() done.[0m
2025-04-28T16:43:07.8615118Z 04-28 16:43:07.859 15079(15098) [32mI[0m [35mten_set_default_manifest_info[0m[[email protected]:25[0m [37mSkip the loading of manifest.json because the base_dir of http_server_extension_nodejs is missing.[0m
2025-04-28T16:43:07.8617690Z 04-28 16:43:07.859 15079(15098) [32mI[0m [35mten_set_default_property_info[0m[[email protected]:51[0m [37mSkip the loading of property.json because the base_dir of http_server_extension_nodejs is missing.[0m
2025-04-28T16:43:07.8620284Z 04-28 16:43:07.859 15079(15098) [32mI[0m [35mten_extension_handle_ten_namespace_properties[0m[[email protected]:314[0m [37m[http_server_extension_nodejs] ten section is not found in the property, skip.[0m
2025-04-28T16:43:07.8621475Z 04-28 16:43:07.860 15079(15098) [36mD[0m [35mten_extension_on_init[0m[[email protected]:665[0m [37m[http_server_extension_nodejs] on_init().[0m
2025-04-28T16:43:07.8622371Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mproxy_on_init[0m[[email protected]:671[0m [37mextension proxy_on_init[0m
2025-04-28T16:43:07.8622852Z WebsocketServerExtension onConfigure
2025-04-28T16:43:07.8623872Z 04-28 16:43:07.860 15079(15098) [36mD[0m [35mten_extension_on_configure_done[0m[34m@on_xxx.c:96[0m [37m[websocket_server_nodejs] on_configure() done.[0m
2025-04-28T16:43:07.8625285Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mten_set_default_manifest_info[0m[[email protected]:25[0m [37mSkip the loading of manifest.json because the base_dir of websocket_server_nodejs is missing.[0m
2025-04-28T16:43:07.8626745Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mten_set_default_property_info[0m[[email protected]:51[0m [37mSkip the loading of property.json because the base_dir of websocket_server_nodejs is missing.[0m
2025-04-28T16:43:07.8628197Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mten_extension_handle_ten_namespace_properties[0m[[email protected]:314[0m [37m[websocket_server_nodejs] ten section is not found in the property, skip.[0m
2025-04-28T16:43:07.8629322Z 04-28 16:43:07.860 15079(15098) [36mD[0m [35mten_extension_on_init[0m[[email protected]:665[0m [37m[websocket_server_nodejs] on_init().[0m
2025-04-28T16:43:07.8630182Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mproxy_on_init[0m[[email protected]:671[0m [37mextension proxy_on_init[0m
2025-04-28T16:43:07.8630628Z HttpServerExtension onInit
2025-04-28T16:43:07.8630895Z WebsocketServerExtension onInit
2025-04-28T16:43:07.8631634Z 04-28 16:43:07.860 15079(15098) [36mD[0m [35mten_extension_on_init_done[0m[34m@on_xxx.c:248[0m [37m[http_server_extension_nodejs] on_init() done.[0m
2025-04-28T16:43:07.8632602Z 04-28 16:43:07.860 15079(15098) [36mD[0m [35mten_extension_on_init_done[0m[34m@on_xxx.c:248[0m [37m[websocket_server_nodejs] on_init() done.[0m
2025-04-28T16:43:07.8633706Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mten_extension_on_start[0m[[email protected]:697[0m [37m[http_server_extension_nodejs] on_start().[0m
2025-04-28T16:43:07.8634595Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mproxy_on_start[0m[[email protected]:711[0m [37mextension proxy_on_start[0m
2025-04-28T16:43:07.8635495Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mten_extension_on_start[0m[[email protected]:697[0m [37m[websocket_server_nodejs] on_start().[0m
2025-04-28T16:43:07.8636358Z 04-28 16:43:07.860 15079(15098) [32mI[0m [35mproxy_on_start[0m[[email protected]:711[0m [37mextension proxy_on_start[0m
2025-04-28T16:43:07.8636808Z HttpServerExtension onStart
2025-04-28T16:43:07.8637083Z WebsocketServerExtension onStart
2025-04-28T16:43:07.8638046Z 04-28 16:43:07.861 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] TenEnv::getPropertyNumber callback" (0x7f45cc07c350)[0m
2025-04-28T16:43:07.8668936Z 04-28 16:43:07.866 15079(15098) [32mI[0m [35mten_extension_on_start_done[0m[34m@on_xxx.c:307[0m [37m[http_server_extension_nodejs] on_start() done.[0m
2025-04-28T16:43:07.8670657Z Server running at http://127.0.0.1:8002/
2025-04-28T16:43:07.8672724Z 04-28 16:43:07.866 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] TenEnv::getPropertyNumber callback is finalized.[0m
2025-04-28T16:43:07.8675029Z 04-28 16:43:07.866 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] TenEnv::getPropertyNumber callback", its new ref count is 0[0m
2025-04-28T16:43:07.8676525Z 04-28 16:43:07.867 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] TenEnv::getPropertyNumber callback" (0x7f45cc07cd30)[0m
2025-04-28T16:43:07.8686525Z 04-28 16:43:07.868 15079(15098) [32mI[0m [35mten_extension_on_start_done[0m[34m@on_xxx.c:307[0m [37m[websocket_server_nodejs] on_start() done.[0m
2025-04-28T16:43:07.8687560Z Server running at http://127.0.0.1:8007/
2025-04-28T16:43:07.8688641Z 04-28 16:43:07.868 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] TenEnv::getPropertyNumber callback is finalized.[0m
2025-04-28T16:43:07.8690015Z 04-28 16:43:07.868 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] TenEnv::getPropertyNumber callback", its new ref count is 0[0m
2025-04-28T16:43:08.5156240Z Client connected
2025-04-28T16:43:08.5165444Z Received: Hello, World!
2025-04-28T16:43:08.5196737Z Client disconnected
2025-04-28T16:43:08.5225904Z Parsed JSON: { ten: { type: 'close_app' } }
2025-04-28T16:43:08.5232986Z 04-28 16:43:08.522 15079(15086) [32mI[0m [35mten_app_handle_close_app_cmd[0m[[email protected]:273[0m [37m[localhost] Close app due to 'close_app' cmd.[0m
2025-04-28T16:43:08.5234501Z 04-28 16:43:08.522 15079(15086) [36mD[0m [35mten_app_close[0m[[email protected]:164[0m [37m[localhost] Try to close app.[0m
2025-04-28T16:43:08.5235684Z 04-28 16:43:08.522 15079(15086) [36mD[0m [35mten_app_close_sync[0m[[email protected]:82[0m [37m[localhost] Try to close app.[0m
2025-04-28T16:43:08.5236949Z 04-28 16:43:08.522 15079(15086) [32mI[0m [35mten_engine_close_async[0m[[email protected]:179[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Try to close engine.[0m
2025-04-28T16:43:08.5238288Z 04-28 16:43:08.522 15079(15086) [32mI[0m [35mten_engine_close_sync[0m[[email protected]:41[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Start to close engine.[0m
2025-04-28T16:43:08.5239533Z 04-28 16:43:08.522 15079(15086) [36mD[0m [35mten_extension_context_close[0m[34m@extension_context.c:142[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Try to close extension context.[0m
2025-04-28T16:43:08.5240799Z 04-28 16:43:08.522 15079(15086) [36mD[0m [35mten_extension_thread_close[0m[34m@extension_thread.c:382[0m [37m[default_extension_group] Try to close extension thread.[0m
2025-04-28T16:43:08.5241860Z 04-28 16:43:08.522 15079(15098) [32mI[0m [35mten_extension_on_stop[0m[[email protected]:734[0m [37m[http_server_extension_nodejs] on_stop().[0m
2025-04-28T16:43:08.5242748Z 04-28 16:43:08.522 15079(15098) [32mI[0m [35mproxy_on_stop[0m[[email protected]:751[0m [37mextension proxy_on_stop[0m
2025-04-28T16:43:08.5243889Z 04-28 16:43:08.523 15079(15098) [32mI[0m [35mten_extension_on_stop[0m[[email protected]:734[0m [37m[websocket_server_nodejs] on_stop().[0m
2025-04-28T16:43:08.5244783Z 04-28 16:43:08.523 15079(15098) [32mI[0m [35mproxy_on_stop[0m[[email protected]:751[0m [37mextension proxy_on_stop[0m
2025-04-28T16:43:08.5255425Z WebsocketServerExtension onStop
2025-04-28T16:43:08.5259916Z 04-28 16:43:08.525 15079(15098) [32mI[0m [35mten_extension_on_stop_done[0m[34m@on_xxx.c:340[0m [37m[websocket_server_nodejs] on_stop() done.[0m
2025-04-28T16:43:08.5261704Z 04-28 16:43:08.525 15079(15098) [36mD[0m [35mten_timer_on_close[0m[[email protected]:67[0m [37m[0] Timer can be closed now.[0m
2025-04-28T16:43:08.5263327Z 04-28 16:43:08.525 15079(15098) [36mD[0m [35mten_timer_on_close[0m[[email protected]:67[0m [37m[0] Timer can be closed now.[0m
2025-04-28T16:43:08.5264927Z 04-28 16:43:08.525 15079(15098) [36mD[0m [35mten_extension_on_deinit[0m[[email protected]:758[0m [37m[websocket_server_nodejs] on_deinit().[0m
2025-04-28T16:43:08.5265859Z HttpServerExtension onStop
2025-04-28T16:43:08.5267106Z 04-28 16:43:08.525 15079(15098) [32mI[0m [35mproxy_on_deinit[0m[[email protected]:791[0m [37mextension proxy_on_deinit[0m
2025-04-28T16:43:08.5268901Z 04-28 16:43:08.526 15079(15098) [32mI[0m [35mten_extension_on_stop_done[0m[34m@on_xxx.c:340[0m [37m[http_server_extension_nodejs] on_stop() done.[0m
2025-04-28T16:43:08.5270708Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_timer_on_close[0m[[email protected]:67[0m [37m[0] Timer can be closed now.[0m
2025-04-28T16:43:08.5272251Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_timer_on_close[0m[[email protected]:67[0m [37m[0] Timer can be closed now.[0m
2025-04-28T16:43:08.5274163Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_extension_on_deinit[0m[[email protected]:758[0m [37m[http_server_extension_nodejs] on_deinit().[0m
2025-04-28T16:43:08.5275870Z 04-28 16:43:08.526 15079(15098) [32mI[0m [35mproxy_on_deinit[0m[[email protected]:791[0m [37mextension proxy_on_deinit[0m
2025-04-28T16:43:08.5276730Z WebsocketServerExtension onDeinit
2025-04-28T16:43:08.5278533Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onConfigure" (0x7f45cc2f4cc0)[0m
2025-04-28T16:43:08.5280690Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onInit" (0x7f45cc2f53b0)[0m
2025-04-28T16:43:08.5282260Z 04-28 16:43:08.526 15079(15098) [32mI[0m [35mten_env_proxy_release[0m[34m@ten_env_proxy.c:243[0m [37mPost task to ten_env's runloop to notify proxy is deleted.[0m
2025-04-28T16:43:08.5284803Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onStart" (0x7f45cc30b380)[0m
2025-04-28T16:43:08.5287041Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onStop" (0x7f45cc30bb00)[0m
2025-04-28T16:43:08.5289217Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onDeinit" (0x7f45cc30c280)[0m
2025-04-28T16:43:08.5290346Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_extension_on_deinit_done[0m[34m@on_xxx.c:443[0m [37m[websocket_server_nodejs] on_deinit() done.[0m
2025-04-28T16:43:08.5291452Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onCmd" (0x7f45cc30cc10)[0m
2025-04-28T16:43:08.5292433Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_env_close[0m[34m@ten_env.c:194[0m [37m[websocket_server_nodejs] Close ten of extension.[0m
2025-04-28T16:43:08.5293492Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onData" (0x7f45cc07a840)[0m
2025-04-28T16:43:08.5295001Z 04-28 16:43:08.526 15079(15098) [32mI[0m [35mten_extension_on_deinit_done[0m[34m@on_xxx.c:470[0m [37m[websocket_server_nodejs] Waiting for ten_env_proxy to be released, remaining 1 ten_env_proxy(s).[0m
2025-04-28T16:43:08.5296922Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onAudioFrame" (0x7f45cc07b250)[0m
2025-04-28T16:43:08.5298909Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onVideoFrame" (0x7f45cc07bc60)[0m
2025-04-28T16:43:08.5301072Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_extension_thread_del_extension[0m[34m@on_xxx.c:370[0m [37m[websocket_server_nodejs] Deleted from extension thread (default_extension_group).[0m
2025-04-28T16:43:08.5302247Z HttpServerExtension onDeinit
2025-04-28T16:43:08.5303947Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onConfigure" (0x7f45cc2a91a0)[0m
2025-04-28T16:43:08.5305872Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onInit" (0x7f45cc2a9940)[0m
2025-04-28T16:43:08.5307807Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onStart" (0x7f45cc2ab500)[0m
2025-04-28T16:43:08.5309951Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onStop" (0x7f45cc2abd00)[0m
2025-04-28T16:43:08.5312003Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onDeinit" (0x7f45cc2ac710)[0m
2025-04-28T16:43:08.5314155Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onCmd" (0x7f45cc2ad120)[0m
2025-04-28T16:43:08.5316133Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onData" (0x7f45cc2b4960)[0m
2025-04-28T16:43:08.5318236Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onAudioFrame" (0x7f45cc2b5370)[0m
2025-04-28T16:43:08.5320335Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] extension::onVideoFrame" (0x7f45cc2b5d80)[0m
2025-04-28T16:43:08.5322244Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onVideoFrame is finalized.[0m
2025-04-28T16:43:08.5324481Z 04-28 16:43:08.526 15079(15098) [32mI[0m [35mten_env_proxy_release[0m[34m@ten_env_proxy.c:243[0m [37mPost task to ten_env's runloop to notify proxy is deleted.[0m
2025-04-28T16:43:08.5326779Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onVideoFrame", its new ref count is 0[0m
2025-04-28T16:43:08.5328816Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_extension_on_deinit_done[0m[34m@on_xxx.c:443[0m [37m[http_server_extension_nodejs] on_deinit() done.[0m
2025-04-28T16:43:08.5330694Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onAudioFrame is finalized.[0m
2025-04-28T16:43:08.5332430Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_env_close[0m[34m@ten_env.c:194[0m [37m[http_server_extension_nodejs] Close ten of extension.[0m
2025-04-28T16:43:08.5334839Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onAudioFrame", its new ref count is 0[0m
2025-04-28T16:43:08.5337050Z 04-28 16:43:08.526 15079(15098) [36mD[0m [35mten_extension_flush_remaining_paths[0m[[email protected]:54[0m [37m[http_server_extension_nodejs] Flushing 1 remaining out paths.[0m
2025-04-28T16:43:08.5339072Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onData is finalized.[0m
2025-04-28T16:43:08.5341202Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onData", its new ref count is 0[0m
2025-04-28T16:43:08.5343183Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onCmd is finalized.[0m
2025-04-28T16:43:08.5345201Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onCmd", its new ref count is 0[0m
2025-04-28T16:43:08.5346338Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onDeinit is finalized.[0m
2025-04-28T16:43:08.5347558Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onDeinit", its new ref count is 0[0m
2025-04-28T16:43:08.5349867Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onVideoFrame is finalized.[0m
2025-04-28T16:43:08.5351167Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onVideoFrame", its new ref count is 0[0m
2025-04-28T16:43:08.5352982Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onAudioFrame is finalized.[0m
2025-04-28T16:43:08.5355473Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onAudioFrame", its new ref count is 0[0m
2025-04-28T16:43:08.5357714Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onData is finalized.[0m
2025-04-28T16:43:08.5360030Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onData", its new ref count is 0[0m
2025-04-28T16:43:08.5362097Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onCmd is finalized.[0m
2025-04-28T16:43:08.5364592Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onCmd", its new ref count is 0[0m
2025-04-28T16:43:08.5366166Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onDeinit is finalized.[0m
2025-04-28T16:43:08.5367368Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onDeinit", its new ref count is 0[0m
2025-04-28T16:43:08.5368486Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onStop is finalized.[0m
2025-04-28T16:43:08.5369660Z 04-28 16:43:08.526 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onStop", its new ref count is 0[0m
2025-04-28T16:43:08.5370793Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onStart is finalized.[0m
2025-04-28T16:43:08.5371988Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onStart", its new ref count is 0[0m
2025-04-28T16:43:08.5373100Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onInit is finalized.[0m
2025-04-28T16:43:08.5374532Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onInit", its new ref count is 0[0m
2025-04-28T16:43:08.5375672Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onConfigure is finalized.[0m
2025-04-28T16:43:08.5376895Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onConfigure", its new ref count is 0[0m
2025-04-28T16:43:08.5378018Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onStop is finalized.[0m
2025-04-28T16:43:08.5379194Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onStop", its new ref count is 0[0m
2025-04-28T16:43:08.5380303Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onStart is finalized.[0m
2025-04-28T16:43:08.5381596Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onStart", its new ref count is 0[0m
2025-04-28T16:43:08.5382701Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onInit is finalized.[0m
2025-04-28T16:43:08.5383985Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onInit", its new ref count is 0[0m
2025-04-28T16:43:08.5385123Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] extension::onConfigure is finalized.[0m
2025-04-28T16:43:08.5386423Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] extension::onConfigure", its new ref count is 0[0m
2025-04-28T16:43:08.5387925Z 04-28 16:43:08.527 15079(15098) [32mI[0m [35mten_extension_on_deinit_done[0m[34m@on_xxx.c:470[0m [37m[http_server_extension_nodejs] Waiting for ten_env_proxy to be released, remaining 1 ten_env_proxy(s).[0m
2025-04-28T16:43:08.5389371Z 04-28 16:43:08.527 15079(15098) [36mD[0m [35mten_extension_thread_del_extension[0m[34m@on_xxx.c:370[0m [37m[http_server_extension_nodejs] Deleted from extension thread (default_extension_group).[0m
2025-04-28T16:43:08.5390629Z 04-28 16:43:08.527 15079(15098) [36mD[0m [35mten_extension_group_destroy_extensions[0m[34m@extension_group.c:202[0m [37m[default_extension_group] destroy_extensions.[0m
2025-04-28T16:43:08.5391657Z 04-28 16:43:08.527 15079(15098) [32mI[0m [35mproxy_on_destroy_instance[0m[[email protected]:372[0m [37maddon proxy_on_destroy_instance[0m
2025-04-28T16:43:08.5392560Z 04-28 16:43:08.527 15079(15098) [32mI[0m [35mproxy_on_destroy_instance[0m[[email protected]:372[0m [37maddon proxy_on_destroy_instance[0m
2025-04-28T16:43:08.5393735Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] TenEnv::send_cmd callback" (0x7f45cc07c960)[0m
2025-04-28T16:43:08.5394834Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:41[0m [37mTSFN [TSFN] TenEnv::send_cmd callback is finalized.[0m
2025-04-28T16:43:08.5396068Z 04-28 16:43:08.527 15079(15087) [36mD[0m [35mten_nodejs_tsfn_finalize[0m[[email protected]:64[0m [37mRelease JS func ref pointed by TSFN "[TSFN] TenEnv::send_cmd callback", its new ref count is 0[0m
2025-04-28T16:43:08.5397296Z 04-28 16:43:08.527 15079(15098) [36mD[0m [35mten_extension_group_on_destroy_extensions_done[0m[34m@on_xxx.c:212[0m [37m[default_extension_group] destroy_extensions() done.[0m
2025-04-28T16:43:08.5398389Z 04-28 16:43:08.527 15079(15098) [36mD[0m [35mten_extension_group_on_deinit_done[0m[34m@on_xxx.c:116[0m [37m[default_extension_group] on_deinit() done.[0m
2025-04-28T16:43:08.5399399Z 04-28 16:43:08.527 15079(15098) [36mD[0m [35mten_env_close[0m[34m@ten_env.c:190[0m [37m[default_extension_group] Close ten of extension group.[0m
2025-04-28T16:43:08.5400708Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_engine_on_remove_extension_thread_from_engine[0m[34m@on_xxx.c:43[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Remove extension thread (0x7f45ca55a360) from engine.[0m
2025-04-28T16:43:08.5402063Z 04-28 16:43:08.527 15079(15098) [36mD[0m [35mten_extension_thread_main_actual[0m[34m@extension_thread.c:290[0m [37m[default_extension_group] Notifying engine that we are closed.[0m
2025-04-28T16:43:08.5403277Z 04-28 16:43:08.527 15079(15098) [36mD[0m [35mten_extension_thread_main_actual[0m[34m@extension_thread.c:295[0m [37m[default_extension_group] Extension thread is exited.[0m
2025-04-28T16:43:08.5404750Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_engine_on_extension_thread_closed_task[0m[34m@on_xxx.c:72[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Waiting for extension thread (0x7f45ca55a360) be reclaimed.[0m
2025-04-28T16:43:08.5406271Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_engine_on_extension_thread_closed_task[0m[34m@on_xxx.c:81[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Extension thread (0x7f45ca55a360) is reclaimed.[0m
2025-04-28T16:43:08.5407640Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_extension_context_on_close[0m[34m@extension_context.c:199[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Extension context can be closed now.[0m
2025-04-28T16:43:08.5408771Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_env_close[0m[34m@ten_env.c:185[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Close ten of engine.[0m
2025-04-28T16:43:08.5409961Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_engine_on_extension_context_closed[0m[[email protected]:318[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Extension context closed.[0m
2025-04-28T16:43:08.5411164Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_engine_on_close[0m[[email protected]:287[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Engine can be closed now.[0m
2025-04-28T16:43:08.5412331Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_app_del_engine[0m[34m@engine_interface.c:140[0m [37m[localhost:743ec7f6-2cd8-4762-9cd4-9cd253097a51] Remove engine from app.[0m
2025-04-28T16:43:08.5413469Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_engine_destroy[0m[[email protected]:66[0m [37m[743ec7f6-2cd8-4762-9cd4-9cd253097a51] Destroy engine.[0m
2025-04-28T16:43:08.5414635Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_app_close[0m[[email protected]:160[0m [37m[localhost] App is closing, do not close again.[0m
2025-04-28T16:43:08.5415507Z 04-28 16:43:08.527 15079(15086) [36mD[0m [35mten_app_proceed_to_close[0m[[email protected]:56[0m [37m[localhost] Close app.[0m
2025-04-28T16:43:08.5416312Z 04-28 16:43:08.527 15079(15086) [32mI[0m [35mproxy_on_deinit[0m[[email protected]:317[0m [37maddon proxy_on_deinit[0m
2025-04-28T16:43:08.5417084Z 04-28 16:43:08.527 15079(15086) [32mI[0m [35mproxy_on_deinit[0m[[email protected]:317[0m [37maddon proxy_on_deinit[0m
2025-04-28T16:43:08.5417509Z WS server addon onDeinit
2025-04-28T16:43:08.5418304Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] addon::onInit" (0x7f45cc2db310)[0m
2025-04-28T16:43:08.5419377Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] addon::onDeinit" (0x7f45cc2db960)[0m
2025-04-28T16:43:08.5420484Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] addon::onCreateInstance" (0x7f45cc2d3400)[0m
2025-04-28T16:43:08.5421023Z DefaultAddon onDeinit
2025-04-28T16:43:08.5421795Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] addon::onInit" (0x7f45cc1bb9e0)[0m
2025-04-28T16:43:08.5422867Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] addon::onDeinit" (0x7f45cc0ac5f0)[0m
2025-04-28T16:43:08.5424070Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] addon::onCreateInstance" (0x7f45cc2a6d00)[0m
2025-04-28T16:43:08.5425157Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_addon_manager_deinit[0m[34m@addon_manager.c:456[0m [37mTEN JS Addon: ten_nodejs_addon_manager_deinit[0m
2025-04-28T16:43:08.5426345Z 04-28 16:43:08.528 15079(15087) [36mD[0m [35mten_nodejs_tsfn_release[0m[[email protected]:234[0m [37mRelease TSFN "[TSFN] addon_manager::registerSingleAddon" (0x7f45cc1b5a20)[0m
2025-04-28T16:43:08.5426906Z gc done
2025-04-28T22:33:18.7002617Z ##[error]The operation was canceled.
2025-04-28T22:33:18.7071701Z Post job cleanup.
2025-04-28T22:33:18.7075774Z ##[command]/usr/bin/docker exec 2e1fb756e374740bff0cda6c93999354eb3f342cdd7f0aa4be9eefc1c8db20ba sh -c "cat /etc/*release | grep ^ID"
2025-04-28T22:33:18.9255142Z [command]/usr/bin/git version
2025-04-28T22:33:18.9308843Z git version 2.34.1
2025-04-28T22:33:18.9369180Z Copying '/github/home/.gitconfig' to '/__w/_temp/303201af-df37-40e0-ac43-eabdccf153da/.gitconfig'
2025-04-28T22:33:18.9382612Z Temporarily overriding HOME='/__w/_temp/303201af-df37-40e0-ac43-eabdccf153da' before making global git config changes
2025-04-28T22:33:18.9384722Z Adding repository directory to the temporary git global config as a safe directory
2025-04-28T22:33:18.9404973Z [command]/usr/bin/git config --global --add safe.directory /__w/ten-framework/ten-framework
2025-04-28T22:33:18.9445054Z [command]/usr/bin/git config --local --name-only --get-regexp core.sshCommand
2025-04-28T22:33:18.9482369Z [command]/usr/bin/git submodule foreach --recursive sh -c "git config --local --name-only --get-regexp 'core.sshCommand' && git config --local --unset-all 'core.sshCommand' || :"
2025-04-28T22:33:18.9765694Z Entering 'ai_agents/esp32-client/components/esp32-camera'
2025-04-28T22:33:18.9822643Z Entering 'core/ten_gn'
2025-04-28T22:33:18.9895877Z [command]/usr/bin/git config --local --name-only --get-regexp http.https://github.com/.extraheader
2025-04-28T22:33:18.9922574Z http.https://github.com/.extraheader
2025-04-28T22:33:18.9937679Z [command]/usr/bin/git config --local --unset-all http.https://github.com/.extraheader
2025-04-28T22:33:18.9977970Z [command]/usr/bin/git submodule foreach --recursive sh -c "git config --local --name-only --get-regexp 'http.https://github.com/.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :"
2025-04-28T22:33:19.0238139Z Entering 'ai_agents/esp32-client/components/esp32-camera'
2025-04-28T22:33:19.0278368Z Entering 'core/ten_gn'
2025-04-28T22:33:19.0466420Z Stop and remove container: 133fe5053cb041088d1a3b81fda64451_ghcriotenframeworkten_building_ubuntu2204_4ebab2
2025-04-28T22:33:19.0470891Z ##[command]/usr/bin/docker rm --force 2e1fb756e374740bff0cda6c93999354eb3f342cdd7f0aa4be9eefc1c8db20ba
2025-04-28T22:33:19.7995383Z 2e1fb756e374740bff0cda6c93999354eb3f342cdd7f0aa4be9eefc1c8db20ba
2025-04-28T22:33:19.8023494Z Remove container network: github_network_7e401e081ec64d0b811be6b8bd27570b
2025-04-28T22:33:19.8028347Z ##[command]/usr/bin/docker network rm github_network_7e401e081ec64d0b811be6b8bd27570b
2025-04-28T22:33:19.9429038Z github_network_7e401e081ec64d0b811be6b8bd27570b
2025-04-28T22:33:19.9484506Z Cleaning up orphan processes
Environment
linux clang release x64
Steps to reproduce
CI runs integration test
Expected behavior
could complete successfully
Severity
Critical
Additional Information
No response
