6fj
commented
11 months ago Hi @daydayuphere
- PSI大部分日志来自 c++代码
2023-12-06T20:31:08.040944984+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) INFO:root:sort_cmd:tail -n +2 /tmp/tmp3894o9us/psi-output-nosort.csv | LC_ALL=C sort --buffer-size=2G --parallel=8 --temporary-directory=./ --stable --field-separator=, --key=1,1 >>/home/kuscia/var/storage/data/psi-out-secretflow-2023120414042034011206.csv
这行log是在检查csv是否有duplicated key，还没有开始执行PSI。
walkovernamtso
NKcqx
通过kusciaAPI跑一个psi求交任务的日志如下，想通过日志统计下求交任务的时长，但是日志里面的时间线感觉有些乱，希望大佬们解答 任务开始时间--2023-12-06T20:30:51.412754209 任务结束时间--2023-12-06T20:31:10.204837077
几个疑问如下： 1、这样的日志是哪里的代码打出来的，查了secretflow里面的psi.py没有找到打印这个日志的地方 2023-12-06T20:31:00.148897994+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:165 [alice] -- rece input 2023-12-06T20:31:00.149022555+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:166 [alice] -- type: "sf.table.individual" 2、时间到20:31:08.040944984这里，求交已经做完了，结果写到了/home/kuscia/var/storage/data/psi-out-secretflow-2023120414042034011206.csv，但是为什么后面到20:31:10.204788362才开始执行spu的c++代码，到底哪个对呢 2023-12-06T20:31:08.040889821+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 recv 28 2023-12-06T20:31:08.040904006+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 recv 9 2023-12-06T20:31:08.040914428+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 recv last 9 2023-12-06T20:31:08.040924439+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 send 28 2023-12-06T20:31:08.040931294+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 send last 9 2023-12-06T20:31:08.040938112+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:intersection_count:8 join_count:8 2023-12-06T20:31:08.040944984+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) INFO:root:sort_cmd:tail -n +2 /tmp/tmp3894o9us/psi-output-nosort.csv | LC_ALL=C sort --buffer-size=2G --parallel=8 --temporary-directory=./ --stable --field-separator=, --key=1,1 >>/home/kuscia/var/storage/data/psi-out-secretflow-2023120414042034011206.csv
//spu的ecdh代码开始执行 2023-12-06T20:31:10.204788362+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.740 [info] [ecdh_psi.cc:MaskSelf:75] MaskSelf:root--finished, batch_count=1, self_item_count=8
原始日志文件如下： [root@root-kuscia-autonomy-alice secretflow]# cat 0.log 2023-12-06T20:30:51.412754209+08:00 stderr F WARNING:root:Since the GPL-licensed package:10001')
2023-12-06T20:30:54.495008367+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:801 -- To see the status of the cluster, use
2023-12-06T20:30:54.495012649+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:802 -- ray status
2023-12-06T20:30:54.495016912+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:812 -- If connection fails, check your firewall settings and network configuration.
2023-12-06T20:30:54.495021176+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:820 -- To terminate the Ray runtime, run
2023-12-06T20:30:54.495025395+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:821 -- ray stop
2023-12-06T20:30:54.495029346+08:00 stdout F
2023-12-06T20:30:54.495046481+08:00 stdout F 2023-12-06 12:30:54,494|alice|INFO|secretflow|entry.py:start_ray:73| Succeeded to start ray head node at secretflow-202312041404203401133-0-global.alice.svc.
2023-12-06T20:30:54.501733828+08:00 stdout F 2023-12-06 12:30:54,501|alice|WARNING|secretflow|driver.py:init:391| When connecting to an existing cluster, num_cpus must not be provided. Num_cpus is neglected at this moment.
2023-12-06T20:30:54.502605515+08:00 stderr F 2023-12-06 12:30:54,502 INFO worker.py:1352 -- Connecting to existing Ray cluster at address: secretflow-202312041404203401133-0-global.alice.svc:8081...
2023-12-06T20:30:54.512535234+08:00 stderr F [2023-12-06 12:30:54,512 I 7 7] global_state_accessor.cc:357: This node has an IP address of 10.88.0.4, while we can not find the matched Raylet address. This maybe come from when you connect the Ray cluster with a different IP address or connect a container.
2023-12-06T20:30:54.513702112+08:00 stderr F 2023-12-06 12:30:54,513 INFO worker.py:1538 -- Connected to Ray cluster.
2023-12-06T20:30:54.530230551+08:00 stderr F 2023-12-06 12:30:54 INFO api.py:202 [alice] -- Started rayfed with {'CLUSTER_ADDRESSES': {'bob': {'address': 'secretflow-202312041404203401133-0-fed.bob.svc:80'}, 'alice': {'address': '0.0.0.0:8080'}}, 'CURRENT_PARTY_NAME': 'alice', 'TLS_CONFIG': {}, 'CROSS_SILO_SERIALIZING_ALLOWED_LIST': None, 'CROSS_SILO_MESSAGES_MAX_SIZE_IN_BYTES': None, 'CROSS_SILO_TIMEOUT_IN_SECONDS': 3600}
2023-12-06T20:30:55.411275159+08:00 stderr F (raylet) [2023-12-06 12:30:54,233 I 153 153] logging.cc:230: Set ray log level from environment variable RAY_BACKEND_LOG_LEVEL to -1
2023-12-06T20:30:55.41128484+08:00 stderr F (pid=gcs_server) [2023-12-06 12:30:52,590 I 40 40] logging.cc:230: Set ray log level from environment variable RAY_BACKEND_LOG_LEVEL to -1
2023-12-06T20:30:55.411287577+08:00 stderr F (raylet) [2023-12-06 12:30:55,018 I 291 291] logging.cc:230: Set ray log level from environment variable RAY_BACKEND_LOG_LEVEL to -1
2023-12-06T20:30:55.41129007+08:00 stderr F 2023-12-06 12:30:55 INFO barriers.py:353 [alice] -- RecverProxy was successfully created.
2023-12-06T20:30:56.11118283+08:00 stderr F (RecverProxyActor pid=291) 2023-12-06 12:30:55 INFO barriers.py:114 [alice] -- Successfully start Grpc service without credentials.
2023-12-06T20:30:56.111191996+08:00 stderr F (raylet) [2023-12-06 12:30:55,867 I 350 350] logging.cc:230: Set ray log level from environment variable RAY_BACKEND_LOG_LEVEL to -1
2023-12-06T20:30:56.111194892+08:00 stderr F 2023-12-06 12:30:56 INFO barriers.py:388 [alice] -- SendProxy was successfully created.
2023-12-06T20:30:56.111197331+08:00 stderr F 2023-12-06 12:30:56 INFO barriers.py:463 [alice] -- Try ping ['bob'] at 0 attemp, up to 3600 attemps.
2023-12-06T20:30:56.114225652+08:00 stderr F 2023-12-06 12:30:56 INFO barriers.py:449 [alice] -- Failed to ping bob on secretflow-202312041404203401133-0-fed.bob.svc:80, this could be normal, the possible reason is bob has not yet started.
2023-12-06T20:30:58.114924925+08:00 stderr F 2023-12-06 12:30:58 INFO barriers.py:463 [alice] -- Try ping ['bob'] at 1 attemp, up to 3600 attemps.
2023-12-06T20:30:58.119840243+08:00 stderr F 2023-12-06 12:30:58 INFO barriers.py:449 [alice] -- Failed to ping bob on secretflow-202312041404203401133-0-fed.bob.svc:80, this could be normal, the possible reason is bob has not yet started.
2023-12-06T20:31:00.121612034+08:00 stderr F 2023-12-06 12:31:00 INFO barriers.py:463 [alice] -- Try ping ['bob'] at 2 attemp, up to 3600 attemps.
2023-12-06T20:31:00.14862548+08:00 stderr F 2023-12-06 12:31:00 INFO barriers.py:444 [alice] -- Succeeded to ping bob on secretflow-202312041404203401133-0-fed.bob.svc:80, the result: OK.
//ray启动结束，与另一侧握手成功
unidecodeis not installed, using Python'sunicodedatapackage which yields worse results. 2023-12-06T20:30:51.957327347+08:00 stdout F 2023-12-06 12:30:51,957|alice|INFO|secretflow|entry.py:start_ray:51| ray_conf: RayConfig(ray_node_ip_address='secretflow-202312041404203401133-0-global.alice.svc', ray_node_manager_port=0, ray_object_manager_port=0, ray_client_server_port=0, ray_worker_ports=[], ray_gcs_port=8081) 2023-12-06T20:30:51.957355058+08:00 stdout F 2023-12-06 12:30:51,957|alice|INFO|secretflow|entry.py:start_ray:55| Trying to start ray head node at secretflow-202312041404203401133-0-global.alice.svc, start command: RAY_BACKEND_LOG_LEVEL=debug RAY_grpc_enable_http_proxy=true OMP_NUM_THREADS=8 ray start --head --include-dashboard=false --disable-usage-stats --num-cpus=32 --node-ip-address=secretflow-202312041404203401133-0-global.alice.svc --port=8081 2023-12-06T20:30:54.494923479+08:00 stdout F 2023-12-06 12:30:54,494|alice|INFO|secretflow|entry.py:start_ray:72| 2023-12-06 12:30:52,491 INFO usage_lib.py:490 -- Usage stats collection is disabled. 2023-12-06T20:30:54.494942955+08:00 stdout F 2023-12-06 12:30:52,491 INFO scripts.py:702 -- Local node IP: secretflow-202312041404203401133-0-global.alice.svc 2023-12-06T20:30:54.494948849+08:00 stdout F 2023-12-06 12:30:54,353 SUCC scripts.py:739 -- -------------------- 2023-12-06T20:30:54.494953143+08:00 stdout F 2023-12-06 12:30:54,353 SUCC scripts.py:740 -- Ray runtime started. 2023-12-06T20:30:54.49495737+08:00 stdout F 2023-12-06 12:30:54,353 SUCC scripts.py:741 -- -------------------- 2023-12-06T20:30:54.494961814+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:743 -- Next steps 2023-12-06T20:30:54.494966221+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:744 -- To connect to this Ray runtime from another node, run 2023-12-06T20:30:54.49497048+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:747 -- ray start --address='secretflow-202312041404203401133-0-global.alice.svc:8081' 2023-12-06T20:30:54.494974679+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:763 -- Alternatively, use the following Python code: 2023-12-06T20:30:54.494979201+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:765 -- import ray 2023-12-06T20:30:54.494983341+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:769 -- ray.init(address='auto', _node_ip_address='secretflow-202312041404203401133-0-global.alice.svc') 2023-12-06T20:30:54.494987423+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:781 -- To connect to this Ray runtime from outside of the cluster, for example to 2023-12-06T20:30:54.494991565+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:785 -- connect to a remote cluster from your laptop directly, use the following 2023-12-06T20:30:54.494995648+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:789 -- Python code: 2023-12-06T20:30:54.494999839+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:791 -- import ray 2023-12-06T20:30:54.495004096+08:00 stdout F 2023-12-06 12:30:54,353 INFO scripts.py:792 -- ray.init(address='ray://2023-12-06T20:31:00.148897994+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:165 [alice] -- rece input 2023-12-06T20:31:00.149022555+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:166 [alice] -- type: "sf.table.individual" 2023-12-06T20:31:00.149038951+08:00 stderr F meta { 2023-12-06T20:31:00.149045996+08:00 stderr F type_url: "type.googleapis.com/secretflow.component.IndividualTable" 2023-12-06T20:31:00.149054781+08:00 stderr F value: "\n\256\003\n\003id1\022\003age\022\007balance\022\010campaign\022\003day\022\010default1\022\010duration\022\teducation\022\007housing\022\017job_blue_collar\022\020job_entrepreneur\022\rjob_housemaid\022\016job_management\022\013job_retired\022\021job_self_employed\022\014job_services\022\013job_student\022\016job_technician\022\016job_unemployed\022\004loan\022\020marital_divorced\022\017marital_married\022\016marital_single\022\005pdays\022\010previous\"\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\020\377\377\377\377\377\377\377\377\377\001" 2023-12-06T20:31:00.149078464+08:00 stderr F } 2023-12-06T20:31:00.149086589+08:00 stderr F data_refs { 2023-12-06T20:31:00.149092952+08:00 stderr F uri: "886aec7a-ac32-431a-8331-79084dcf4fa0-10alice.csv" 2023-12-06T20:31:00.14909903+08:00 stderr F party: "alice" 2023-12-06T20:31:00.149107819+08:00 stderr F format: "csv" 2023-12-06T20:31:00.149117745+08:00 stderr F } 2023-12-06T20:31:00.149125012+08:00 stderr F 2023-12-06T20:31:00.149157118+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:167 [alice] -- {'alice': DistdataInfo(uri='886aec7a-ac32-431a-8331-79084dcf4fa0-10alice.csv', format='csv')} 2023-12-06T20:31:00.149207418+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:170 [alice] -- rece party 2023-12-06T20:31:00.149282763+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:171 [alice] -- alice 2023-12-06T20:31:00.149460006+08:00 stderr F 2023-12-06 12:31:00 WARNING psi.py:186 [alice] -- {'cluster_def': {'nodes': [{'party': 'bob', 'address': 'http://secretflow-202312041404203401133-0-spu.bob.svc:80', 'listen_address': ''}, {'party': 'alice', 'address': '0.0.0.0:54509', 'listen_address': ''}], 'runtime_config': {'protocol': 1, 'field': 2}}, 'link_desc': {'connect_retry_times': 60, 'connect_retry_interval_ms': 1000, 'brpc_channel_protocol': 'http', 'brpc_channel_connection_type': 'pooled', 'recv_timeout_ms': 1200000, 'http_timeout_ms': 1200000}} 2023-12-06T20:31:00.149482013+08:00 stderr F 2023-12-06 12:31:00 INFO psi.py:187 [alice] -- testaaaaaaa 2023-12-06T20:31:00.193765949+08:00 stderr F 2023-12-06 12:31:00 INFO cleanup.py:83 [alice] -- Start check sending thread. 2023-12-06T20:31:00.194006361+08:00 stderr F 2023-12-06 12:31:00 INFO cleanup.py:89 [alice] -- Start check sending monitor thread. 2023-12-06T20:31:08.040850996+08:00 stderr F (raylet) [2023-12-06 12:31:00,619 I 396 396] logging.cc:230: Set ray log level from environment variable RAY_BACKEND_LOG_LEVEL to -1 2023-12-06T20:31:08.040874499+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:origin_table size:8,drop_duplicates size:8 2023-12-06T20:31:08.040889821+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 recv 28 2023-12-06T20:31:08.040904006+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 recv 9 2023-12-06T20:31:08.040914428+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 recv last 9 2023-12-06T20:31:08.040924439+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 send 28 2023-12-06T20:31:08.040931294+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:rank:0 send last 9 2023-12-06T20:31:08.040938112+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) WARNING:root:intersection_count:8 join_count:8 2023-12-06T20:31:08.040944984+08:00 stderr F (SPURuntime(device_id=None, party=alice) pid=396) INFO:root:sort_cmd:tail -n +2 /tmp/tmp3894o9us/psi-output-nosort.csv | LC_ALL=C sort --buffer-size=2G --parallel=8 --temporary-directory=./ --stable --field-separator=, --key=1,1 >>/home/kuscia/var/storage/data/psi-out-secretflow-2023120414042034011206.csv 2023-12-06T20:31:08.040951951+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:238 [alice] -- join_count 2023-12-06T20:31:08.040974145+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:239 [alice] -- 8 2023-12-06T20:31:08.04145427+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:141 [alice] -- new_meta 2023-12-06T20:31:08.041624506+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:142 [alice] -- schema { 2023-12-06T20:31:08.04164434+08:00 stderr F ids: "id1" 2023-12-06T20:31:08.041652687+08:00 stderr F features: "age" 2023-12-06T20:31:08.041660965+08:00 stderr F features: "balance" 2023-12-06T20:31:08.041671806+08:00 stderr F features: "campaign" 2023-12-06T20:31:08.041706229+08:00 stderr F features: "day" 2023-12-06T20:31:08.041721687+08:00 stderr F features: "default1" 2023-12-06T20:31:08.041738544+08:00 stderr F features: "duration" 2023-12-06T20:31:08.0417512+08:00 stderr F features: "education" 2023-12-06T20:31:08.041758601+08:00 stderr F features: "housing" 2023-12-06T20:31:08.041765275+08:00 stderr F features: "job_blue_collar" 2023-12-06T20:31:08.041771695+08:00 stderr F features: "job_entrepreneur" 2023-12-06T20:31:08.041778122+08:00 stderr F features: "job_housemaid" 2023-12-06T20:31:08.0417848+08:00 stderr F features: "job_management" 2023-12-06T20:31:08.041791216+08:00 stderr F features: "job_retired" 2023-12-06T20:31:08.041797652+08:00 stderr F features: "job_self_employed" 2023-12-06T20:31:08.041804037+08:00 stderr F features: "job_services" 2023-12-06T20:31:08.041810447+08:00 stderr F features: "job_student" 2023-12-06T20:31:08.041816869+08:00 stderr F features: "job_technician" 2023-12-06T20:31:08.041823208+08:00 stderr F features: "job_unemployed" 2023-12-06T20:31:08.041829583+08:00 stderr F features: "loan" 2023-12-06T20:31:08.041836629+08:00 stderr F features: "marital_divorced" 2023-12-06T20:31:08.041842988+08:00 stderr F features: "marital_married" 2023-12-06T20:31:08.041850057+08:00 stderr F features: "marital_single" 2023-12-06T20:31:08.041856574+08:00 stderr F features: "pdays" 2023-12-06T20:31:08.041863049+08:00 stderr F features: "previous" 2023-12-06T20:31:08.041869441+08:00 stderr F id_types: "str" 2023-12-06T20:31:08.041875729+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041882146+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041888468+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041894807+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041901206+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.04190756+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041913957+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041920385+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041926827+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041933256+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041939593+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041945982+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041952343+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041958696+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041965185+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041971645+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041977931+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041984318+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041991774+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.041998237+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042004726+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042011067+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042017384+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.04202375+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042030298+08:00 stderr F } 2023-12-06T20:31:08.042036984+08:00 stderr F num_lines: -1 2023-12-06T20:31:08.042043181+08:00 stderr F 2023-12-06T20:31:08.042081686+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:144 [alice] -- new_x 2023-12-06T20:31:08.042127011+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:145 [alice] -- type: "sf.table.individual" 2023-12-06T20:31:08.042143323+08:00 stderr F meta { 2023-12-06T20:31:08.042157519+08:00 stderr F type_url: "type.googleapis.com/secretflow.component.IndividualTable" 2023-12-06T20:31:08.042168525+08:00 stderr F value: "\n\256\003\n\003id1\022\003age\022\007balance\022\010campaign\022\003day\022\010default1\022\010duration\022\teducation\022\007housing\022\017job_blue_collar\022\020job_entrepreneur\022\rjob_housemaid\022\016job_management\022\013job_retired\022\021job_self_employed\022\014job_services\022\013job_student\022\016job_technician\022\016job_unemployed\022\004loan\022\020marital_divorced\022\017marital_married\022\016marital_single\022\005pdays\022\010previous\"\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\020\377\377\377\377\377\377\377\377\377\001" 2023-12-06T20:31:08.042180189+08:00 stderr F } 2023-12-06T20:31:08.042189063+08:00 stderr F data_refs { 2023-12-06T20:31:08.04219563+08:00 stderr F uri: "886aec7a-ac32-431a-8331-79084dcf4fa0-10alice.csv" 2023-12-06T20:31:08.042202269+08:00 stderr F party: "alice" 2023-12-06T20:31:08.042208725+08:00 stderr F format: "csv" 2023-12-06T20:31:08.042215052+08:00 stderr F } 2023-12-06T20:31:08.042221216+08:00 stderr F 2023-12-06T20:31:08.042348979+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:141 [alice] -- new_meta 2023-12-06T20:31:08.042564233+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:142 [alice] -- schema { 2023-12-06T20:31:08.042587097+08:00 stderr F ids: "id2" 2023-12-06T20:31:08.042599801+08:00 stderr F features: "contact_cellular" 2023-12-06T20:31:08.042611423+08:00 stderr F features: "contact_telephone" 2023-12-06T20:31:08.042622293+08:00 stderr F features: "contact_unknown" 2023-12-06T20:31:08.042631399+08:00 stderr F features: "month_apr" 2023-12-06T20:31:08.042637784+08:00 stderr F features: "month_aug" 2023-12-06T20:31:08.042644274+08:00 stderr F features: "month_dec" 2023-12-06T20:31:08.042650771+08:00 stderr F features: "month_feb" 2023-12-06T20:31:08.042657114+08:00 stderr F features: "month_jan" 2023-12-06T20:31:08.042663433+08:00 stderr F features: "month_jul" 2023-12-06T20:31:08.042669745+08:00 stderr F features: "month_jun" 2023-12-06T20:31:08.04267634+08:00 stderr F features: "month_mar" 2023-12-06T20:31:08.042682652+08:00 stderr F features: "month_may" 2023-12-06T20:31:08.042706312+08:00 stderr F features: "month_nov" 2023-12-06T20:31:08.042718087+08:00 stderr F features: "month_oct" 2023-12-06T20:31:08.042729985+08:00 stderr F features: "month_sep" 2023-12-06T20:31:08.042741445+08:00 stderr F features: "poutcome_failure" 2023-12-06T20:31:08.042753026+08:00 stderr F features: "poutcome_other" 2023-12-06T20:31:08.042764317+08:00 stderr F features: "poutcome_success" 2023-12-06T20:31:08.042771014+08:00 stderr F features: "poutcome_unknown" 2023-12-06T20:31:08.042777387+08:00 stderr F features: "y" 2023-12-06T20:31:08.042783914+08:00 stderr F id_types: "str" 2023-12-06T20:31:08.042790279+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042796739+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042803095+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042809478+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042815808+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042822105+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042828442+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042834776+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042841098+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042847571+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042853914+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042860478+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042866814+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042873138+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042879469+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042885877+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042903163+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042910538+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042917332+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042923743+08:00 stderr F feature_types: "str" 2023-12-06T20:31:08.042930141+08:00 stderr F } 2023-12-06T20:31:08.042936629+08:00 stderr F num_lines: -1 2023-12-06T20:31:08.042942816+08:00 stderr F 2023-12-06T20:31:08.042972529+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:144 [alice] -- new_x 2023-12-06T20:31:08.04301989+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:145 [alice] -- type: "sf.table.individual" 2023-12-06T20:31:08.043040032+08:00 stderr F meta { 2023-12-06T20:31:08.043047498+08:00 stderr F type_url: "type.googleapis.com/secretflow.component.IndividualTable" 2023-12-06T20:31:08.043056467+08:00 stderr F value: "\n\361\002\n\003id2\022\020contact_cellular\022\021contact_telephone\022\017contact_unknown\022\tmonth_apr\022\tmonth_aug\022\tmonth_dec\022\tmonth_feb\022\tmonth_jan\022\tmonth_jul\022\tmonth_jun\022\tmonth_mar\022\tmonth_may\022\tmonth_nov\022\tmonth_oct\022\tmonth_sep\022\020poutcome_failure\022\016poutcome_other\022\020poutcome_success\022\020poutcome_unknown\022\001y\"\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\020\377\377\377\377\377\377\377\377\377\001" 2023-12-06T20:31:08.043063409+08:00 stderr F } 2023-12-06T20:31:08.043069963+08:00 stderr F data_refs { 2023-12-06T20:31:08.043076572+08:00 stderr F uri: "a5c37264-2f27-4c11-b6df-e88ffef95811-bob.csv" 2023-12-06T20:31:08.043083179+08:00 stderr F party: "bob" 2023-12-06T20:31:08.043089694+08:00 stderr F format: "csv" 2023-12-06T20:31:08.043096126+08:00 stderr F } 2023-12-06T20:31:08.043102451+08:00 stderr F 2023-12-06T20:31:08.043413868+08:00 stderr F 2023-12-06 12:31:08 INFO psi.py:270 [alice] -- name: "psi-out-secretflow-2023120414042034011206.csv" 2023-12-06T20:31:08.043429656+08:00 stderr F type: "sf.table.vertical_table" 2023-12-06T20:31:08.043436748+08:00 stderr F sys_info { 2023-12-06T20:31:08.043443501+08:00 stderr F } 2023-12-06T20:31:08.043458178+08:00 stderr F meta { 2023-12-06T20:31:08.043469643+08:00 stderr F type_url: "type.googleapis.com/secretflow.component.VerticalTable" 2023-12-06T20:31:08.043480461+08:00 stderr F value: "\n\256\003\n\003id1\022\003age\022\007balance\022\010campaign\022\003day\022\010default1\022\010duration\022\teducation\022\007housing\022\017job_blue_collar\022\020job_entrepreneur\022\rjob_housemaid\022\016job_management\022\013job_retired\022\021job_self_employed\022\014job_services\022\013job_student\022\016job_technician\022\016job_unemployed\022\004loan\022\020marital_divorced\022\017marital_married\022\016marital_single\022\005pdays\022\010previous\"\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\n\361\002\n\003id2\022\020contact_cellular\022\021contact_telephone\022\017contact_unknown\022\tmonth_apr\022\tmonth_aug\022\tmonth_dec\022\tmonth_feb\022\tmonth_jan\022\tmonth_jul\022\tmonth_jun\022\tmonth_mar\022\tmonth_may\022\tmonth_nov\022\tmonth_oct\022\tmonth_sep\022\020poutcome_failure\022\016poutcome_other\022\020poutcome_success\022\020poutcome_unknown\022\001y\"\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\003str\020\010" 2023-12-06T20:31:08.043493012+08:00 stderr F } 2023-12-06T20:31:08.043499728+08:00 stderr F data_refs { 2023-12-06T20:31:08.043506393+08:00 stderr F uri: "psi-out-secretflow-2023120414042034011206.csv" 2023-12-06T20:31:08.043512878+08:00 stderr F party: "alice" 2023-12-06T20:31:08.043519511+08:00 stderr F format: "csv" 2023-12-06T20:31:08.043530947+08:00 stderr F } 2023-12-06T20:31:08.043537778+08:00 stderr F data_refs { 2023-12-06T20:31:08.043551259+08:00 stderr F uri: "psi-out-secretflow-2023120414042034011206.csv" 2023-12-06T20:31:08.043560384+08:00 stderr F party: "bob" 2023-12-06T20:31:08.043571461+08:00 stderr F format: "csv" 2023-12-06T20:31:08.043582735+08:00 stderr F } 2023-12-06T20:31:08.04359402+08:00 stderr F 2023-12-06T20:31:09.424987403+08:00 stderr F (raylet) [2023-12-06 12:31:08,683 I 487 487] logging.cc:230: Set ray log level from environment variable RAY_BACKEND_LOG_LEVEL to -1 2023-12-06T20:31:09.424996134+08:00 stderr F (raylet) [2023-12-06 12:31:08,709 I 486 486] logging.cc:230: Set ray log level from environment variable RAY_BACKEND_LOG_LEVEL to -1 2023-12-06T20:31:09.424999104+08:00 stderr F 2023-12-06 12:31:09 INFO cleanup.py:101 [alice] -- Notify check sending thread to exit. 2023-12-06T20:31:09.430676761+08:00 stderr F 2023-12-06 12:31:09 INFO cleanup.py:66 [alice] -- Check sending thread was exited. 2023-12-06T20:31:09.430707599+08:00 stderr F 2023-12-06 12:31:09 INFO cleanup.py:110 [alice] -- Clearing sending queue. 2023-12-06T20:31:10.130744601+08:00 stderr F 2023-12-06 12:31:10 INFO api.py:235 [alice] -- Shutdowned ray. 2023-12-06T20:31:10.203459855+08:00 stderr F 2023-12-06 12:31:10 INFO entry.py:249 [alice] -- Succeeded to run component. 2023-12-06T20:31:10.203940042+08:00 stderr F 2023-12-06 12:31:10 INFO cleanup.py:101 [alice] -- Notify check sending thread to exit. 2023-12-06T20:31:10.204732048+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.424 [info] [bucket_psi.cc:Init:234] bucket size set to 1048576 2023-12-06T20:31:10.204748953+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.424 [info] [bucket_psi.cc:CheckInput:148] Begin sanity check for input file: /tmp/tmp3894o9us/psi-input.csv, precheck_switch:false 2023-12-06T20:31:10.20475699+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.602 [info] [bucket_psi.cc:CheckInput:165] End sanity check for input file: /tmp/tmp3894o9us/psi-input.csv, size=8 2023-12-06T20:31:10.20476345+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.602 [info] [bucket_psi.cc:RunPsi:266] Run psi protocol=1, self_items_count=8 2023-12-06T20:31:10.20476951+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.622 [info] [cryptor_selector.cc:GetFourQCryptor:53] Using FourQ 2023-12-06T20:31:10.20477551+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.631 [info] [cipher_store.cc:DiskCipherStore:33] Disk cache choose num_bins=64 2023-12-06T20:31:10.204782039+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.708 [info] [thread_pool.cc:ThreadPool:30] Create a fixed thread pool with size 7 2023-12-06T20:31:10.204788362+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.740 [info] [ecdh_psi.cc:MaskSelf:75] MaskSelf:root--finished, batch_count=1, self_item_count=8 2023-12-06T20:31:10.204794448+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.786 [info] [ecdh_psi.cc:RecvDualMaskedSelf:149] root recv last batch finished, batch_count=1 2023-12-06T20:31:10.204800464+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.874 [info] [ecdh_psi.cc:MaskPeer:120] MaskPeer:root--finished, batch_count=3, peer_item_count=9892 2023-12-06T20:31:10.204806475+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.880 [info] [bucket_psi.cc:ProduceOutput:186] Begin post filtering, indices.size=8, should_sort=true 2023-12-06T20:31:10.204814873+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.881 [info] [utils.cc:MultiKeySort:88] Executing sort scripts: tail -n +2 /tmp/tmp3894o9us/tmp-sort-in-1701865867880967314 | LC_ALL=C sort --buffer-size=3G --parallel=8 --temporary-directory=./ --stable --field-separator=, --key=1,1 >>/tmp/tmp3894o9us/tmp-sort-out-1701865867880967314 2023-12-06T20:31:10.204830154+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.915 [info] [utils.cc:MultiKeySort:90] Finished sort scripts: tail -n +2 /tmp/tmp3894o9us/tmp-sort-in-1701865867880967314 | LC_ALL=C sort --buffer-size=3G --parallel=8 --temporary-directory=./ --stable --field-separator=, --key=1,1 >>/tmp/tmp3894o9us/tmp-sort-out-1701865867880967314, ret=0 2023-12-06T20:31:10.204837077+08:00 stdout F (SPURuntime(device_id=None, party=alice) pid=396) 2023-12-06 12:31:07.915 [info] [bucket_psi.cc:ProduceOutput:224] End post filtering, in=/tmp/tmp3894o9us/psi-input.csv, out=/tmp/tmp3894o9us/psi-output-join.csv [root@root-kuscia-autonomy-alice secretflow]#