Maxorao opened a new issue, #5535:
URL: https://github.com/apache/openwhisk/issues/5535
I try to deploy openwhisk on two linux host: 192.168.35.5 as master and
192.168.35.8 as invoker
However I failed to invoker an action after all deploy steps
## hosts file:
```
; the first parameter in a host is the inventory_hostname
192.168.35.5 ansible_connection=local ansible_user=huazhang
192.168.35.8 ansible_connection=ssh ansible_user=huazhang
;192.168.35.28 ansible_connection=ssh ansible_user=ubuntu
ansible ansible_connection=local
[edge]
192.168.35.5 ansible_host=192.168.35.5 ansible_connection=local
[controllers]
192.168.35.5 ansible_host=192.168.35.5 ansible_connection=local
;
[kafkas]
192.168.35.5 ansible_host=192.168.35.5 ansible_connection=local
[zookeepers:children]
kafkas
[invokers]
192.168.35.8 ansible_host=192.168.35.8 ansible_connection=ssh
ansible_user=huazhang
;invoker1 ansible_host=192.168.35.28 ansible_connection=ssh
ansible_user=ubuntu
[schedulers]
192.168.35.5 ansible_host=192.168.35.5 ansible_connection=local
; db group is only used if db.provider is CouchDB
[db]
192.168.35.5 ansible_host=192.168.35.5 ansible_connection=local
[elasticsearch:children]
db
[redis]
192.168.35.5 ansible_host=192.168.35.5 ansible_connection=local
[apigateway]
192.168.35.5 ansible_host=192.168.35.5 ansible_connection=local
[etcd]
etcd0 ansible_host=192.168.35.5 ansible_connection=local
```
## $ENVIRONMENT/group_vars/all
```
openwhisk_tmp_dir: "{{ lookup('env', 'OPENWHISK_TMP_DIR')|default('/tmp' if
ansible_distribution == 'MacOSX' else '/var/tmp', true) }}"
config_root_dir: "{{ openwhisk_tmp_dir }}/wskconf"
whisk_logs_dir: "{{ openwhisk_tmp_dir }}/wsklogs"
coverage_enabled: "{{ lookup('env', 'GRADLE_COVERAGE') | default('false',
true) | bool}}"
coverage_logs_dir: "{{ openwhisk_tmp_dir }}/wskcov"
docker_registry: ""
docker_dns: ""
runtimes_bypass_pull_for_local_images: true
invoker_use_runc: "{{ ansible_distribution != 'MacOSX' }}"
db_prefix: whisk_local_
# API GW connection configuration
apigw_auth_user: ""
apigw_auth_pwd: ""
apigw_host_v2: "http://{{ groups['apigateway']|first
}}:{{apigateway.port.api}}/v2"
invoker_allow_multiple_instances: true
# Set kafka configuration
kafka_heap: '512m'
kafka_topics_completed_retentionBytes: 104857600
kafka_topics_completed_retentionMS: 300000
kafka_topics_health_retentionBytes: 104857600
kafka_topics_health_retentionMS: 300000
kafka_topics_invoker_retentionBytes: 104857600
kafka_topics_invoker_retentionMS: 300000
env_hosts_dir: "{{ playbook_dir }}/environments/distributed"
container_pool_akka_client: true
runtimes_enable_concurrency: true
limit_action_concurrency_max: 500
namespace_default_limit_action_concurrency_max: 500
scheduler_enable: true
db_activation_backend: ElasticSearch
elastic_protocol: "http"
elastic_index_pattern: "openwhisk-%s"
elastic_base_volume: "esdata"
elastic_cluster_name: "openwhisk"
elastic_java_opts: "-Xms1g -Xmx1g"
elastic_loglevel: "INFO"
elastic_username: "elastic"
elastic_password: "k+wt+1reRd8+Hvd*j7Q5"
```
## whisk.properties
```
openwhisk.home=/home/huazhang/zyq/openwhisk/ansible/..
python.27=python
nginx.conf.dir=/var/tmp/wskconf/nginx
testing.auth=/home/huazhang/zyq/openwhisk/ansible/../ansible/files/auth.guest
vcap.services.file=
whisk.logs.dir=/var/tmp/wsklogs
whisk.coverage.logs.dir=/var/tmp/wskcov
environment.type=local
whisk.ssl.client.verification=off
whisk.ssl.cert=/home/huazhang/zyq/openwhisk/ansible/roles/nginx/files/openwhisk-server-cert.pem
whisk.ssl.key=/home/huazhang/zyq/openwhisk/ansible/roles/nginx/files/openwhisk-server-key.pem
whisk.ssl.challenge=openwhisk
whisk.api.host.proto=https
whisk.api.host.port=443
whisk.api.host.name=192.168.35.5
whisk.api.localhost.name=localhost
whisk.api.vanity.subdomain.parts=1
whisk.action.concurrency=True
whisk.feature.requireApiKeyAnnotation=true
whisk.feature.requireResponsePayload=true
runtimes.manifest={"description": ["This file describes the different
languages (aka. managed action runtimes) supported by the system", "as well as
blackbox images that support the runtime specification.", "Only actions with
runtime families / kinds defined here can be created / read / updated / deleted
/ invoked.", "Define a list of runtime families (example: 'nodejs') with at
least one kind per family (example: 'nodejs:20').", "Each runtime family needs
a default kind (default: true).", "When removing or renaming runtime families
or runtime kinds from this file, preexisting actions", "with the affected kinds
can no longer be read / updated / deleted / invoked. In order to remove or
rename", "runtime families or runtime kinds, mark all affected runtime kinds as
deprecated (deprecated: true) and", "perform a manual migration of all affected
actions.", "", "This file is meant to list all stable runtimes supported by the
Apache Openwhisk community."], "runtimes": {"nodejs": [{"kind
": "nodejs:18", "default": false, "image": {"prefix": "openwhisk", "name":
"action-nodejs-v18", "tag": "nightly"}, "deprecated": false, "attached":
{"attachmentName": "codefile", "attachmentType": "text/plain"}}, {"kind":
"nodejs:20", "default": true, "image": {"prefix": "openwhisk", "name":
"action-nodejs-v20", "tag": "nightly"}, "deprecated": false, "attached":
{"attachmentName": "codefile", "attachmentType": "text/plain"}, "stemCells":
[{"initialCount": 2, "memory": "256 MB", "reactive": {"minCount": 1,
"maxCount": 4, "ttl": "2 minutes", "threshold": 1, "increment": 1}}]}],
"python": [{"kind": "python:3.10", "default": true, "image": {"prefix":
"openwhisk", "name": "action-python-v3.10", "tag": "nightly"}, "deprecated":
false, "attached": {"attachmentName": "codefile", "attachmentType":
"text/plain"}}, {"kind": "python:3.11", "default": false, "image": {"prefix":
"openwhisk", "name": "action-python-v3.11", "tag": "nightly"}, "deprecated":
false, "attached": {"attachmentName": "co
defile", "attachmentType": "text/plain"}}], "swift": [{"kind": "swift:5.3",
"default": true, "image": {"prefix": "openwhisk", "name": "action-swift-v5.3",
"tag": "nightly"}, "deprecated": false, "attached": {"attachmentName":
"codefile", "attachmentType": "text/plain"}}, {"kind": "swift:5.7", "default":
false, "image": {"prefix": "openwhisk", "name": "action-swift-v5.7", "tag":
"nightly"}, "deprecated": false, "attached": {"attachmentName": "codefile",
"attachmentType": "text/plain"}}], "java": [{"kind": "java:8", "default": true,
"image": {"prefix": "openwhisk", "name": "java8action", "tag": "nightly"},
"deprecated": false, "attached": {"attachmentName": "codefile",
"attachmentType": "text/plain"}, "requireMain": true}], "php": [{"kind":
"php:8.1", "default": true, "deprecated": false, "image": {"prefix":
"openwhisk", "name": "action-php-v8.1", "tag": "nightly"}, "attached":
{"attachmentName": "codefile", "attachmentType": "text/plain"}}], "ruby":
[{"kind": "ruby:2.5", "default": t
rue, "deprecated": false, "attached": {"attachmentName": "codefile",
"attachmentType": "text/plain"}, "image": {"prefix": "openwhisk", "name":
"action-ruby-v2.5", "tag": "nightly"}}], "go": [{"kind": "go:1.20", "default":
true, "deprecated": false, "attached": {"attachmentName": "codefile",
"attachmentType": "text/plain"}, "image": {"prefix": "openwhisk", "name":
"action-golang-v1.20", "tag": "nightly"}}], "dotnet": [{"kind": "dotnet:3.1",
"default": true, "deprecated": false, "requireMain": true, "image": {"prefix":
"openwhisk", "name": "action-dotnet-v3.1", "tag": "nightly"}, "attached":
{"attachmentName": "codefile", "attachmentType": "text/plain"}}, {"kind":
"dotnet:6.0", "default": false, "deprecated": false, "requireMain": true,
"image": {"prefix": "openwhisk", "name": "action-dotnet-v6.0", "tag":
"nightly"}, "attached": {"attachmentName": "codefile", "attachmentType":
"text/plain"}}], "rust": [{"kind": "rust:1.34", "default": true, "image":
{"prefix": "openwhisk", "name": "ac
tion-rust-v1.34", "tag": "nightly"}, "deprecated": false, "attached":
{"attachmentName": "codefile", "attachmentType": "text/plain"}}]},
"blackboxes": [{"prefix": "openwhisk", "name": "dockerskeleton", "tag":
"nightly"}]}
limits.actions.invokes.perMinute=60
limits.actions.invokes.concurrent=30
limits.triggers.fires.perMinute=60
limits.actions.sequence.maxLength=50
edge.host=192.168.35.5
kafka.hosts=192.168.35.5:9093
redis.host=192.168.35.5
router.host=192.168.35.5
zookeeper.hosts=192.168.35.5:2181
invoker.hosts=192.168.35.5
edge.host.apiport=443
kafkaras.host.port=8093
redis.host.port=6379
invoker.hosts.basePort=12001
invoker.username=invoker.user
invoker.password=invoker.pass
controller.hosts=192.168.35.5
controller.host.basePort=10001
controller.instances=1
controller.protocol=https
controller.username=controller.user
```
# Step to produce this problem
## Start elasticsearch
```bash
docker run --name es01 --net elastic -p 9200:9200 -d -m 1GB
docker.elastic.co/elasticsearch/elasticsearch:8.17.3
docker exec -it es01 bash
./bin/elasticsearch-reset-password -u elastic #get password of elastic here
```
## Follow instructions in README
1. set up $ENVIRONMENT=distributed and $OW_DB etc.
2. ansible-playbook -i environments/$ENVIRONMENT setup.yml
3. with `db_local.ini` and `ansible.cfg`:
```
[db_creds]
db_provider=CouchDB
db_username=admin
db_password=couchdb123456
db_protocol=http
db_host=192.168.35.5
db_port=5984
[controller]
db_username=whisk_local_controller0
db_password=some_controller_passw0rd
[invoker]
db_username=whisk_local_invoker0
db_password=some_invoker_passw0rd
[scheduler]
db_username=whisk_local_scheduler0
db_password=some_scheduler_passw0rd
```
```
[defaults]
callback_whitelist = profile_tasks
retry_files_enabled = False
host_key_checking = False
inventory = environments/distributed
callback_plugins = callbacks
hash_behaviour = merge
gather_timeout = 60
# 普通用户提权配置
[privilege_escalation]
# sudo时是否提示输入密码
become_ask_pass=False
# 以sudo方式提权
become_method=sudo
# 默认sudo到root
become_user=root
become = true
default_become = true
[ssh_connection]
scp_if_ssh = True
```
4. start following steps:
```
ansible-playbook -i environments/$ENVIRONMENT setup.yml
ansible-playbook -i environments/$ENVIRONMENT prereq.yml
cd ..
./gradlew distDocker
cd ansible
ansible-playbook -i environments/$ENVIRONMENT couchdb.yml
ansible-playbook -i environments/$ENVIRONMENT initdb.yml
ansible-playbook -i environments/$ENVIRONMENT wipe.yml
ansible-playbook -i environments/$ENVIRONMENT openwhisk.yml
```
5. there is an error which is ignored:
```
fatal: [192.168.35.5]: FAILED! => {"access_control_allow_headers":
"Authorization, Origin, X-Requested-With, Content-Type, Accept, User-Agent",
"access_control_allow_methods": "GET, DELETE, POST, PUT, HEAD",
"access_control_allow_origin": "*", "changed": false, "connection": "close",
"content_length": "92", "content_type": "application/json", "date": "Wed, 12
Mar 2025 09:04:52 GMT", "elapsed": 0, "json": {"code":
"VucqTNlmvZ42vhjnlNy6Rike8t62BOV0", "error": "The requested resource does not
exist."}, "msg": "Status code was 404 and not [200]: HTTP Error 404: Not
Found", "redirected": false, "server": "akka-http/10.2.4", "status": 404,
"url":
"https://789c46b1-71f6-4ed5-8c54-816aa4f8c502:abczO3xZCLrMN6v2BKK1dXYFpXlPkccOFqm12CdAsMgRU4VrNZ9lyGVCGuMDGIwP@192.168.35.5:10001/api/v1/namespaces/_/actions/invokerHealthTestAction0?blocking=false&result=false";,
"x_request_id": "VucqTNlmvZ42vhjnlNy6Rike8t62BOV0"}
...ignoring
Status code was 404 and not [200]: HTTP Error 404: Not Found
```
no other errors found
6. config wsk api-host as 192.168.35.5
7. wsk action create hello hello.py
```
error: Unable to create action 'hello': resource already exists (code
2f04c04c07e473be8d10494714c11beb)
```
8. wsk action invoke hello --result
```
error: Unable to invoke action 'hello': There was an internal server error.
(code 716aef8948ee83567c132939f405d2fc)
```
## log of controller
```
[2025-03-12T09:04:42.152Z] [INFO] Slf4jLogger started
[2025-03-12T09:04:42.335Z] [INFO] Remoting started with transport [Artery
tcp]; listening on address [akka://[email protected]:8000]
and bound to [akka://[email protected]:2551] with UID
[6704858333504117795]
[2025-03-12T09:04:42.345Z] [INFO] Cluster Node
[akka://[email protected]:8000] - Starting up, Akka version
[2.6.12] ...
[2025-03-12T09:04:42.373Z] [INFO] Cluster Node
[akka://[email protected]:8000] - Registered cluster JMX
MBean [akka:type=Cluster]
[2025-03-12T09:04:42.373Z] [INFO] Cluster Node
[akka://[email protected]:8000] - Started up successfully
[2025-03-12T09:04:42.391Z] [INFO] Cluster Node
[akka://[email protected]:8000] - No downing-provider-class
configured, manual cluster downing required, see
https://doc.akka.io/docs/akka/current/typed/cluster.html#downing
[2025-03-12T09:04:42.414Z] [INFO] Cluster Node
[akka://[email protected]:8000] - Node
[akka://[email protected]:8000] is JOINING itself (with
roles [dc-default], version [0.0.0]) and forming new cluster
[2025-03-12T09:04:42.415Z] [INFO] Cluster Node
[akka://[email protected]:8000] - is the new leader among
reachable nodes (more leaders may exist)
[2025-03-12T09:04:42.421Z] [INFO] Cluster Node
[akka://[email protected]:8000] - Leader is moving node
[akka://[email protected]:8000] to [Up]
[2025-03-12T09:04:42.637Z] [WARN] Failed to attach the instrumentation
because the Kamon Bundle is not present on the classpath
[2025-03-12T09:04:42.736Z] [INFO] Started the Kamon StatsD reporter
[2025-03-12T09:04:42.878Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for limits.triggers.fires.perMinute
[2025-03-12T09:04:42.878Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for limits.actions.sequence.maxLength
[2025-03-12T09:04:42.878Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for limits.actions.invokes.concurrent
[2025-03-12T09:04:42.879Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for limits.actions.invokes.perMinute
[2025-03-12T09:04:42.879Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for runtimes.manifest
[2025-03-12T09:04:42.879Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for kafka.hosts
[2025-03-12T09:04:42.879Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for port
[2025-03-12T09:04:43.396Z] [INFO] [#tid_sid_unknown]
[KafkaMessagingProvider] created topic completed0
[2025-03-12T09:04:43.523Z] [INFO] [#tid_sid_unknown]
[KafkaMessagingProvider] created topic health
[2025-03-12T09:04:43.643Z] [INFO] [#tid_sid_unknown]
[KafkaMessagingProvider] created topic cacheInvalidation
[2025-03-12T09:04:43.757Z] [INFO] [#tid_sid_unknown]
[KafkaMessagingProvider] created topic events
[2025-03-12T09:04:43.850Z] [INFO] [#tid_sid_controller] [Controller]
starting controller instance 0 [marker:controller_startup0_counter:980]
[2025-03-12T09:04:44.304Z] [INFO] [#tid_sid_dispatcher] [MessageFeed]
handler capacity = 128, pipeline fill at = 128, pipeline depth = 256
[2025-03-12T09:04:44.712Z] [INFO] [#tid_sid_unknown] [WatcherService] watch
endpoint:
WatchEndpoint(whisk/queue,,true,distributed-pool-balancer,Set(PutEvent,
DeleteEvent))
[2025-03-12T09:04:44.715Z] [INFO] [#tid_sid_unknown] [WatcherService] watch
endpoint:
WatchEndpoint(whisk/scheduler,,true,distributed-pool-balancer,Set(PutEvent,
DeleteEvent))
[2025-03-12T09:04:44.715Z] [INFO] [#tid_sid_unknown] [WatcherService] watch
endpoint:
WatchEndpoint(whisk/throttling,,true,distributed-pool-balancer,Set(PutEvent,
DeleteEvent))
[2025-03-12T09:04:44.726Z] [INFO] [#tid_sid_controller] [Controller]
loadbalancer initialized: FPCPoolBalancer
[2025-03-12T09:04:44.785Z] [INFO] [#tid_sid_dispatcher] [MessageFeed]
handler capacity = 128, pipeline fill at = 128, pipeline depth = 256
[2025-03-12T09:04:44.818Z] [INFO] [#tid_sid_controller] [KindRestrictor] all
kinds are allowed, the white-list is not specified
[2025-03-12T09:04:45.026Z] [INFO] Creating HTTP client on
http://192.168.35.5:9200
[2025-03-12T09:04:45.739Z] [INFO] [#tid_sid_controller] [ActionsApi]
actionSequenceLimit '50'
[2025-03-12T09:04:46.104Z] [WARN] Binding with a connection source not
supported with HTTP/2. Falling back to HTTP/1.1.
[2025-03-12T09:04:52.041Z] [INFO] [#tid_FaGhVxw1UklLnaLZoFdDpR1vxotqoZpH]
POST /api/v1/namespaces/_/actions/invokerHealthTestAction0
blocking=false&result=false
[2025-03-12T09:04:52.074Z] [INFO] [#tid_FaGhVxw1UklLnaLZoFdDpR1vxotqoZpH]
[BasicHttpService] [marker:http_post.401_counter:35:35]
[2025-03-12T09:04:52.102Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
POST /api/v1/namespaces/_/actions/invokerHealthTestAction0
blocking=false&result=false
[2025-03-12T09:04:52.175Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[Identity] [GET] serving from datastore:
CacheKey(789c46b1-71f6-4ed5-8c54-816aa4f8c502)
[marker:database_cacheMiss_counter:72]
[2025-03-12T09:04:52.209Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[CouchDbRestStore] [QUERY] 'whisk_local_subjects' searching
'subjects.v2.0.0/identities [marker:database_queryView_start:107]
[2025-03-12T09:04:52.285Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[CouchDbRestStore] [marker:database_queryView_finish:182:75]
[2025-03-12T09:04:52.317Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[WhiskActionMetaData] [GET] serving from datastore:
CacheKey(whisk.system/invokerHealthTestAction0)
[marker:database_cacheMiss_counter:214]
[2025-03-12T09:04:52.318Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[CouchDbRestStore] [GET] 'whisk_local_whisks' finding document: 'id:
whisk.system/invokerHealthTestAction0' [marker:database_getDocument_start:215]
[2025-03-12T09:04:52.325Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[CouchDbRestStore] [marker:database_getDocument_finish:223:8]
[2025-03-12T09:04:52.325Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[WhiskActionMetaData] invalidating
CacheKey(whisk.system/invokerHealthTestAction0)
[2025-03-12T09:04:52.330Z] [INFO] [#tid_VucqTNlmvZ42vhjnlNy6Rike8t62BOV0]
[BasicHttpService] [marker:http_post.404_counter:228:228]
[2025-03-12T09:05:08.169Z] [INFO] [#tid_sid_warmUp] [FPCPoolBalancer] Warm
up scheduler SchedulerEndpoints(192.168.35.5,13001,25520)
[2025-03-12T09:05:08.178Z] [INFO] [#tid_sid_warmUp] [FPCPoolBalancer]
[marker:controller_kafka_start:25309]
[2025-03-12T09:05:08.203Z] [INFO] [#tid_sid_warmUp] [FPCPoolBalancer] posted
to scheduler0[0][0] [marker:controller_kafka_finish:25334:25]
[2025-03-12T09:08:10.962Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
PUT /api/v1/namespaces/_/actions/hello overwrite=false
[2025-03-12T09:08:10.965Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[Identity] [GET] serving from datastore:
CacheKey(23bc46b1-71f6-4ed5-8c54-816aa4f8c502)
[marker:database_cacheMiss_counter:4]
[2025-03-12T09:08:10.965Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[CouchDbRestStore] [QUERY] 'whisk_local_subjects' searching
'subjects.v2.0.0/identities [marker:database_queryView_start:4]
[2025-03-12T09:08:10.998Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[CouchDbRestStore] [marker:database_queryView_finish:37:33]
[2025-03-12T09:08:11.023Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[WhiskAction] [GET] serving from datastore: CacheKey(guest/hello)
[marker:database_cacheMiss_counter:62]
[2025-03-12T09:08:11.024Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[CouchDbRestStore] [GET] 'whisk_local_whisks' finding document: 'id:
guest/hello' [marker:database_getDocument_start:62]
[2025-03-12T09:08:11.036Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[CouchDbRestStore] [marker:database_getDocument_finish:75:13]
[2025-03-12T09:08:11.055Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[WhiskAction] write initiated on new cache entry
[2025-03-12T09:08:11.056Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[WhiskAction] write all done, caching CacheKey(guest/hello) Cached
[2025-03-12T09:08:11.061Z] [INFO] [#tid_2f04c04c07e473be8d10494714c11beb]
[BasicHttpService] [marker:http_put.409_counter:100:100]
[2025-03-12T09:08:25.097Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
POST /api/v1/namespaces/_/actions/hello blocking=true&result=true
[2025-03-12T09:08:25.103Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[Identity] [GET] serving from cache:
CacheKey(23bc46b1-71f6-4ed5-8c54-816aa4f8c502)
[marker:database_cacheHit_counter:5]
[2025-03-12T09:08:25.106Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[WhiskActionMetaData] [GET] serving from datastore: CacheKey(guest/hello)
[marker:database_cacheMiss_counter:8]
[2025-03-12T09:08:25.106Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[CouchDbRestStore] [GET] 'whisk_local_whisks' finding document: 'id:
guest/hello' [marker:database_getDocument_start:8]
[2025-03-12T09:08:25.117Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[CouchDbRestStore] [marker:database_getDocument_finish:20:12]
[2025-03-12T09:08:25.125Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[ActionsApi] [marker:controller_blockingActivation_start:27]
[2025-03-12T09:08:25.125Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[ActionsApi] action activation id: 357e1a4cea91493bbe1a4cea91693b2f
[marker:controller_loadbalancer_start:28]
[2025-03-12T09:08:25.165Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[FPCPoolBalancer] [marker:controller_kafka_start:68]
[2025-03-12T09:08:25.170Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[FPCPoolBalancer] posted to scheduler0[0][1]
[marker:controller_kafka_finish:73:5]
[2025-03-12T09:08:25.171Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[ActionsApi] [marker:controller_loadbalancer_finish:74:46]
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by
com.esotericsoftware.kryo.util.UnsafeUtil (file:/controller/lib/kryo-4.0.2.jar)
to constructor java.nio.DirectByteBuffer(long,int,java.lang.Object)
WARNING: Please consider reporting this to the maintainers of
com.esotericsoftware.kryo.util.UnsafeUtil
WARNING: Use --illegal-access=warn to enable warnings of further illegal
reflective access operations
WARNING: All illegal access operations will be denied in a future release
[2025-03-12T09:08:25.606Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[FPCPoolBalancer] Created queue successfully for guest/guest/[email protected] on
scheduler0
[2025-03-12T09:08:40.185Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[ElasticSearchActivationStore] [GET] 'activations' finding activation:
'guest/357e1a4cea91493bbe1a4cea91693b2f'
[marker:database_getDocument_start:15088]
[2025-03-12T09:08:40.449Z] [ERROR] [#tid_716aef8948ee83567c132939f405d2fc]
[StoreUtils] [GET] 'activations' internal error, doc:
'guest/357e1a4cea91493bbe1a4cea91693b2f', failure:
'org.apache.http.ConnectionClosedException: Connection closed'
[JavaClientExceptionWrapper]
com.sksamuel.elastic4s.http.JavaClientExceptionWrapper:
org.apache.http.ConnectionClosedException: Connection closed
at
com.sksamuel.elastic4s.http.ElasticsearchJavaRestClient$$anon$1.onFailure(ElasticsearchJavaRestClient.scala:65)
at
org.elasticsearch.client.RestClient$FailureTrackingResponseListener.onDefinitiveFailure(RestClient.java:857)
at
org.elasticsearch.client.RestClient$1.retryIfPossible(RestClient.java:595)
at org.elasticsearch.client.RestClient$1.failed(RestClient.java:573)
at
org.apache.http.concurrent.BasicFuture.failed(BasicFuture.java:137)
at
org.apache.http.impl.nio.client.AbstractClientExchangeHandler.failed(AbstractClientExchangeHandler.java:419)
at
org.apache.http.nio.protocol.HttpAsyncRequestExecutor.endOfInput(HttpAsyncRequestExecutor.java:344)
at
org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:261)
at
org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:81)
at
org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39)
at
org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:114)
at
org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
at
org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
at
org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
at
org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
at
org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
at
org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)
at java.base/java.lang.Thread.run(Thread.java:866)
Caused by: org.apache.http.ConnectionClosedException: Connection closed
... 12 more
[marker:database_getDocument_error:15350:261]
[2025-03-12T09:08:40.449Z] [WARN] [#tid_716aef8948ee83567c132939f405d2fc]
[ActionsApi] org.apache.http.ConnectionClosedException: Connection closed
[marker:controller_blockingActivation_error:15352:15325]
[2025-03-12T09:08:40.449Z] [ERROR] [#tid_716aef8948ee83567c132939f405d2fc]
[ActionsApi] [POST] action activation failed:
org.apache.http.ConnectionClosedException: Connection closed
[2025-03-12T09:08:40.450Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[BasicHttpService] [marker:http_post.500_counter:15353:15353]
[2025-03-12T09:09:25.749Z] [WARN] [#tid_716aef8948ee83567c132939f405d2fc] []
The whisk/queue/guest/guest/hello/leader is deleted from ETCD, but there are
still unhandled activations for this action, try to create a new queue
[2025-03-12T09:09:25.749Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[WhiskActionMetaData] [GET] serving from cache: CacheKey(guest/hello)
[marker:database_cacheHit_counter:60652]
[2025-03-12T09:09:25.755Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[FPCPoolBalancer] received completion ack for
'357e1a4cea91493bbe1a4cea91693b2f', system error=true
[2025-03-12T09:09:25.756Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[FPCPoolBalancer] received result ack for '357e1a4cea91493bbe1a4cea91693b2f'
[2025-03-12T09:09:25.768Z] [INFO] [#tid_716aef8948ee83567c132939f405d2fc]
[FPCPoolBalancer] Created queue successfully for guest/guest/[email protected] on
scheduler0
[2025-03-12T09:15:56.195Z] [INFO] Stopping idle outbound control stream to
[akka://[email protected]:25520]
[2025-03-12T09:15:56.195Z] [INFO] Stopping idle outbound stream [2] to
[akka://[email protected]:25520]
[2025-03-12T09:15:56.200Z] [WARN] [outbound connection to
[akka://[email protected]:25520], control stream] Upstream
failed, cause: StreamTcpException: The connection has been aborted
[2025-03-12T09:15:56.201Z] [WARN] [outbound connection to
[akka://[email protected]:25520], message stream] Upstream
failed, cause: StreamTcpException: The connection has been aborted
```
## log of invoker on 192.168.35.8
```
[2025-03-12T09:05:34.050Z] [INFO] Slf4jLogger started
[2025-03-12T09:05:34.530Z] [INFO] Remoting started with transport [Artery
tcp]; listening on address [akka://[email protected]:25520] with
UID [-2510769248814326475]
[2025-03-12T09:05:34.547Z] [INFO] Cluster Node
[akka://[email protected]:25520] - Starting up, Akka version
[2.6.12] ...
[2025-03-12T09:05:34.633Z] [INFO] Cluster Node
[akka://[email protected]:25520] - Registered cluster JMX MBean
[akka:type=Cluster]
[2025-03-12T09:05:34.633Z] [INFO] Cluster Node
[akka://[email protected]:25520] - Started up successfully
[2025-03-12T09:05:34.703Z] [INFO] Cluster Node
[akka://[email protected]:25520] - No downing-provider-class
configured, manual cluster downing required, see
https://doc.akka.io/docs/akka/current/typed/cluster.html#downing
[2025-03-12T09:05:34.704Z] [INFO] Cluster Node
[akka://[email protected]:25520] - No seed nodes found in
configuration, relying on Cluster Bootstrap for joining
[2025-03-12T09:05:35.426Z] [INFO] [#tid_sid_unknown] [Invoker] invoker tags:
()
[2025-03-12T09:05:35.453Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for whisk.api.host.name
[2025-03-12T09:05:35.453Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for whisk.api.host.proto
[2025-03-12T09:05:35.453Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for whisk.api.host.port
[2025-03-12T09:05:35.453Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for runtimes.manifest
[2025-03-12T09:05:35.453Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for kafka.hosts
[2025-03-12T09:05:35.454Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for port
[2025-03-12T09:05:35.454Z] [INFO] [#tid_sid_unknown] [Config] environment
set value for zookeeper.hosts
[2025-03-12T09:05:35.597Z] [INFO] [#tid_sid_unknown] [Invoker] Command line
arguments parsed to yield CmdLineArgs(Some(0),Some(0),None,None)
[2025-03-12T09:05:35.598Z] [INFO] [#tid_sid_unknown] [Invoker] invokerReg:
using proposedInvokerId 0
[2025-03-12T09:05:35.644Z] [WARN] Failed to attach the instrumentation
because the Kamon Bundle is not present on the classpath
[2025-03-12T09:05:35.763Z] [INFO] Started the Kamon StatsD reporter
[2025-03-12T09:05:36.511Z] [INFO] [#tid_sid_unknown]
[KafkaMessagingProvider] created topic invoker0
[2025-03-12T09:05:36.689Z] [INFO] [#tid_sid_unknown] [FPCInvokerReactive]
LogStoreProvider: class
org.apache.openwhisk.core.containerpool.logging.DockerToActivationLogStore
[2025-03-12T09:05:37.626Z] [INFO] [#tid_sid_unknown]
[DockerClientWithFileAccess] Detected docker client version 23.0.6
[2025-03-12T09:05:37.708Z] [INFO] [#tid_sid_unknown] [LeaseKeepAliveService]
Granted a new lease Lease(7587885365396899601,10)
[2025-03-12T09:05:37.715Z] [INFO] [#tid_sid_invoker]
[DockerClientWithFileAccess] running /usr/bin/docker ps --quiet --no-trunc
--all --filter name=wsk00_ (timeout: 1 minute)
[marker:invoker_docker.ps_start:2301]
[2025-03-12T09:05:37.727Z] [INFO] [#tid_sid_unknown] [WatcherService] watch
endpoint:
WatchEndpoint(whisk/instance/invoker0/0/lease,7587885365396899601,false,lease-service,Set(DeleteEvent))
[2025-03-12T09:05:37.734Z] [INFO] [#tid_sid_unknown] [LeaseKeepAliveService]
send the lease(Lease(7587885365396899601,10)) to
Actor[akka://invoker-actor-system/user/$c/$a#2041035133]
[2025-03-12T09:05:37.816Z] [INFO] [#tid_sid_invoker]
[DockerClientWithFileAccess] [marker:invoker_docker.ps_finish:2402:38]
[2025-03-12T09:05:37.823Z] [INFO] [#tid_sid_invoker]
[DockerContainerFactory] removing 0 action containers.
[2025-03-12T09:05:38.527Z] [INFO] Creating HTTP client on
http://192.168.35.5:9200
[2025-03-12T09:05:38.780Z] [INFO] [#tid_sid_invoker] [CouchDbRestStore]
[QUERY] 'whisk_local_subjects' searching
'namespaceThrottlings/blockedNamespaces [marker:database_queryView_start:3366]
[2025-03-12T09:05:39.137Z] [INFO] [#tid_sid_invoker] [CouchDbRestStore]
[marker:database_queryView_finish:3724:357]
[2025-03-12T09:05:39.138Z] [INFO] [#tid_sid_unknown] [FPCInvokerReactive]
updated blacklist to 0 entries
[2025-03-12T09:05:39.383Z] [ERROR] cannot create test action for invoker
health because runtime manifest is not valid
java.lang.IllegalStateException: cannot create test action for invoker
health because runtime manifest is not valid
at
org.apache.openwhisk.core.containerpool.v2.InvokerHealthManager$.prepare(InvokerHealthManager.scala:343)
at
org.apache.openwhisk.core.containerpool.v2.InvokerHealthManager$$anonfun$1.applyOrElse(InvokerHealthManager.scala:64)
at
org.apache.openwhisk.core.containerpool.v2.InvokerHealthManager$$anonfun$1.applyOrElse(InvokerHealthManager.scala:58)
at
scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:38)
at akka.actor.FSM.processEvent(FSM.scala:804)
at akka.actor.FSM.processEvent$(FSM.scala:801)
at
org.apache.openwhisk.core.containerpool.v2.InvokerHealthManager.processEvent(InvokerHealthManager.scala:39)
at akka.actor.FSM.akka$actor$FSM$$processMsg(FSM.scala:798)
at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:793)
at akka.actor.Actor.aroundReceive(Actor.scala:537)
at akka.actor.Actor.aroundReceive$(Actor.scala:535)
at
org.apache.openwhisk.core.containerpool.v2.InvokerHealthManager.aroundReceive(InvokerHealthManager.scala:39)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:577)
at akka.actor.ActorCell.invoke(ActorCell.scala:547)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:270)
at akka.dispatch.Mailbox.run(Mailbox.scala:231)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:866)
[2025-03-12T09:05:39.419Z] [INFO] [#tid_sid_unknown] [WatcherService] watch
endpoint:
WatchEndpoint(whisk/invokers/0/0,{"busyMemory":0,"dedicatedNamespaces":[],"freeMemory":2048,"inProgressMemory":0,"status":"down","tags":[]},false,data-management-service,Set(DeleteEvent))
[2025-03-12T09:05:39.642Z] [INFO] [#tid_sid_dispatcher] [MessageFeed]
handler capacity = 500, pipeline fill at = 500, pipeline depth = 1000
[2025-03-12T09:05:39.686Z] [INFO] [#tid_sid_warmUp] [FPCInvokerReactive]
Warm up scheduler <ByteString@de20ac80 size=17 contents="whisk/scheduler/0">
[2025-03-12T09:05:40.095Z] [WARN] Binding with a connection source not
supported with HTTP/2. Falling back to HTTP/1.1.
[2025-03-12T09:05:40.536Z] [INFO] [#tid_sid_unknown] [FPCInvokerReactive]
Warmed up scheduler SchedulerEndpoints(192.168.35.5,13001,25520)
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
