Ixia-c-one 0.1.0-3 potential race condition with updating LocationMap

[bortok]

The latest changes to Ixia-c-one intermittently break LocationMap when running on an under-powered VM, see the failure to install the map for eth1. This is from https://github.com/open-traffic-generator/otg-examples/tree/keng-renaming/clab/ixia-c-b2b

{"level":"info","LocationMap":{"LocationMap":[]},"ts":"2023-10-20T04:50:51.959586387Z","msg":"AppConfigInfo"}
{"level":"info","Updated LocationMap":{"ConfigFileTime":"2023-10-20T04:50:46.886324868Z","ConfigFileSize":17,"LocationMap":{}},"ts":"2023-10-20T04:50:51.95967951Z","msg":"AppConfigInfo, PortType=all"}
{"level":"info","LocationMap":{"LocationMap":[{"Location":"eth2","Endpoint":"172.17.0.3:5555+172.17.0.3:50071"}]},"ts":"2023-10-20T04:50:53.643116936Z","msg":"AppConfigInfo"}
{"level":"info","Updated LocationMap":{"ConfigFileTime":"2023-10-20T04:50:53.094064679Z","ConfigFileSize":76,"LocationMap":{"eth2":"172.17.0.3:5555+172.17.0.3:50071"}},"ts":"2023-10-20T04:50:53.643181219Z","msg":"AppConfigInfo, PortType=all"}
{"level":"error","ctx":"http","status":{"Errors":[{"Msg":"could not find remapped location name for eth1 from map[eth2:172.17.0.3:5555+172.17.0.3:50071]","Type":1}],"Warnings":[]},"ts":"2023-10-20T04:50:53.643653162Z","msg":"SetConfig failed"}

while both eth1 and eth2 are running:

docker exec -it clab-ixcb2b-ixia-c sh
/home/keysight/ixia-c-one # docker ps
CONTAINER ID   IMAGE                               COMMAND                  CREATED         STATUS         PORTS                                                                        NAMES
fedb4ceab816   ixia-c-protocol-engine:1.00.0.337   "/docker_im/opt/Ixia…"   2 minutes ago   Up 2 minutes                                                                                ixia-c-port-cp-eth1
fb748bb2516c   ixia-c-traffic-engine:1.6.0.85      "./entrypoint.sh"        2 minutes ago   Up 2 minutes                                                                                ixia-c-port-dp-eth1
1c0f8325c6a9   ixia-c-protocol-engine:1.00.0.337   "/docker_im/opt/Ixia…"   2 minutes ago   Up 2 minutes                                                                                ixia-c-port-cp-eth2
52b2af86d372   ixia-c-traffic-engine:1.6.0.85      "./entrypoint.sh"        2 minutes ago   Up 2 minutes                                                                                ixia-c-port-dp-eth2
6bdf4e76b22b   keng-controller:0.1.0-3             "./bin/controller --…"   2 minutes ago   Up 2 minutes   0.0.0.0:8443->8443/tcp, 0.0.0.0:40051->40051/tcp, 0.0.0.0:50051->50051/tcp   keng-controller

Full controller log:

/home/keysight/ixia-c-one # docker logs keng-controller
{"level":"info","ctx":"config","version":"0.1.0","revision":"3","commit":"07dd40b6","build date":"2023-Oct-19","ts":"2023-10-20T04:50:51.888341744Z","msg":"Build Meta"}
{"level":"info","ctx":"rscmgr","ts":"2023-10-20T04:50:51.958353533Z","msg":"Successfully created session."}
{"level":"info","LocationMap":{"LocationMap":[]},"ts":"2023-10-20T04:50:51.959586387Z","msg":"AppConfigInfo"}
{"level":"info","Updated LocationMap":{"ConfigFileTime":"2023-10-20T04:50:46.886324868Z","ConfigFileSize":17,"LocationMap":{}},"ts":"2023-10-20T04:50:51.95967951Z","msg":"AppConfigInfo, PortType=all"}
{"level":"info","ctx":"controller","ts":"2023-10-20T04:50:51.959738597Z","msg":"Location info processed successfully !"}
{"level":"info","ctx":"profile","api":"GetAggrCostAttributesForConfig","choice":"","scope":"validator","nanoseconds":10879,"ts":"2023-10-20T04:50:51.959885318Z"}
{"level":"info","ctx":"profile","api":"ValidateCostForCommunity","choice":"","scope":"validator","nanoseconds":9582,"ts":"2023-10-20T04:50:51.959947999Z"}
{"level":"info","ctx":"validator","ts":"2023-10-20T04:50:51.959993911Z","msg":"Configuration is within community limits"}
{"level":"info","ctx":"profile","api":"ValidateCommunityConfig","choice":"","scope":"validator","nanoseconds":231360,"ts":"2023-10-20T04:50:51.960049206Z"}
{"level":"info","ctx":"profile","api":"ValidateConfig","choice":"","scope":"validator","nanoseconds":315700,"ts":"2023-10-20T04:50:51.960098912Z"}
{"level":"info","ctx":"controller","ts":"2023-10-20T04:50:51.960141031Z","msg":"Config validated successfully !"}
{"level":"info","ctx":"profile","api":"SetConfig","choice":"","scope":"protocol","nanoseconds":41821,"ts":"2023-10-20T04:50:51.960632397Z"}
{"level":"info","ctx":"impl/licensing","License-server distribution of license unit(s) to release":{},"ts":"2023-10-20T04:50:51.96074109Z","msg":"Licenses to release"}
{"level":"info","ctx":"profile","api":"License Release","choice":"","scope":"licensing client service","nanoseconds":10180,"ts":"2023-10-20T04:50:51.960825928Z"}
{"level":"info","ctx":"impl/licensing","License(s) released successfully":{},"ts":"2023-10-20T04:50:51.960929132Z","msg":"Licenses released"}
{"level":"info","ctx":"profile","api":"processLicenseRelease","choice":"","scope":"licensing","nanoseconds":394649,"ts":"2023-10-20T04:50:51.960984127Z"}
{"level":"info","ctx":"traffic","ts":"2023-10-20T04:50:51.962263194Z","msg":"SetConfig [Traffic Part] Successful !"}
{"level":"info","ctx":"profile","api":"SetConfig","choice":"","scope":"traffic","nanoseconds":1899186,"ts":"2023-10-20T04:50:51.962799274Z"}
{"level":"info","ctx":"controller","ts":"2023-10-20T04:50:51.963095111Z","msg":"Config is set on the ports Successfully !"}
{"level":"info","ctx":"profile","api":"SetConfig","choice":"Empty Config","scope":"controller","nanoseconds":4827315,"ts":"2023-10-20T04:50:51.96313763Z"}
{"level":"info","ctx":"main","config":{"HTTPPort":8443,"GRPCPort":40051,"RootDir":"/home/ixia-c/controller","WebDir":"/home/ixia-c/controller/web","CertsDir":"/home/ixia-c/controller/certs","LogDir":"/home/ixia-c/controller/logs","AppConfigPath":"/home/ixia-c/controller/config/config.yaml","Debug":true,"Trace":false,"Cleanup":false,"DisableVersionCheck":false,"DisableUsageReport":false,"DisableStdOutLogging":false,"UsageReportHost":"https://localhost:5600","MaxLogSizeMB":25,"MaxLogBackups":25,"TEDialTimeoutSeconds":10,"PSDialTimeoutSeconds":10,"PSCallTimeoutSeconds":600,"TerminationTimeoutSeconds":3,"AcceptEULA":true,"LowCpuUtilMode":false,"KENGIxHWServer":"localhost:5001","LicenseServers":"","Version":{},"PortType":"all"},"ts":"2023-10-20T04:50:51.980029889Z","msg":"Initialized Config"}
{"level":"info","ctx":"usagereporter","ts":"2023-10-20T04:50:51.986286584Z","msg":"App Usage reporting routine initiated"}
{"level":"info","ctx":"impl/licensing","ts":"2023-10-20T04:50:51.986348866Z","msg":"No license servers configured"}
{"level":"info","ctx":"profile","api":"ProcessServers","choice":"","scope":"licensing","nanoseconds":58389,"ts":"2023-10-20T04:50:51.986402364Z"}
{"level":"info","ts":"2023-10-20T04:50:51.986439593Z","msg":"stdout logger routine initiated"}
{"level":"info","ctx":"http","addr":":8443","ts":"2023-10-20T04:50:51.987544291Z","msg":"HTTPS Server started"}
{"level":"info","ctx":"grpc","addr":"[::]:40051","ts":"2023-10-20T04:50:51.988502568Z","msg":"GRPC Server started"}
{"level":"info","ctx":"service","ts":"2023-10-20T04:50:51.988920173Z","msg":"Waiting for active routines"}
{"level":"error","ctx":"usagereporter","ts":"2023-10-20T04:50:51.989220103Z","msg":"App usage reporting service is down"}
[WARNING]: Capture is under review, There may be changes in filter configuration
[WARNING]: RxName property in schema FlowPort is deprecated, This property is deprecated in favor of property rx_names
[WARNING]: RxName property in schema FlowPort is deprecated, This property is deprecated in favor of property rx_names
{"level":"info","ctx":"http","ts":"2023-10-20T04:50:53.642419902Z","msg":"Invoked SetConfig"}
{"level":"debug","ctx":"service","username":"common","uuid":0,"ts":"2023-10-20T04:50:53.642501155Z","msg":"Session Credentials"}
{"level":"info","ctx":"rscmgr","ts":"2023-10-20T04:50:53.642618342Z","msg":"Destroying existing and creating new session ..."}
{"level":"info","ctx":"rscmgr","ts":"2023-10-20T04:50:53.642712571Z","msg":"Successfully created session."}
{"level":"info","LocationMap":{"LocationMap":[{"Location":"eth2","Endpoint":"172.17.0.3:5555+172.17.0.3:50071"}]},"ts":"2023-10-20T04:50:53.643116936Z","msg":"AppConfigInfo"}
{"level":"info","Updated LocationMap":{"ConfigFileTime":"2023-10-20T04:50:53.094064679Z","ConfigFileSize":76,"LocationMap":{"eth2":"172.17.0.3:5555+172.17.0.3:50071"}},"ts":"2023-10-20T04:50:53.643181219Z","msg":"AppConfigInfo, PortType=all"}
{"level":"info","ctx":"controller","ts":"2023-10-20T04:50:53.643212363Z","msg":"Location info processed successfully !"}
{"level":"info","ctx":"profile","api":"ValidateConfig","choice":"","scope":"validator","nanoseconds":213113,"ts":"2023-10-20T04:50:53.643496147Z"}
{"level":"info","ctx":"profile","api":"SetConfig","choice":"","scope":"controller","nanoseconds":943686,"ts":"2023-10-20T04:50:53.643538271Z"}
{"level":"error","ctx":"http","status":{"Errors":[{"Msg":"could not find remapped location name for eth1 from map[eth2:172.17.0.3:5555+172.17.0.3:50071]","Type":1}],"Warnings":[]},"ts":"2023-10-20T04:50:53.643653162Z","msg":"SetConfig failed"}
{"level":"info","ctx":"profile","api":"SetConfig","choice":"","scope":"http","nanoseconds":1494485,"ts":"2023-10-20T04:50:53.643908798Z"}
/home/keysight/ixia-c-one # docker logs keng-controller | grep -i map
{"level":"info","LocationMap":{"LocationMap":[]},"ts":"2023-10-20T04:50:51.959586387Z","msg":"AppConfigInfo"}
{"level":"info","Updated LocationMap":{"ConfigFileTime":"2023-10-20T04:50:46.886324868Z","ConfigFileSize":17,"LocationMap":{}},"ts":"2023-10-20T04:50:51.95967951Z","msg":"AppConfigInfo, PortType=all"}
{"level":"info","LocationMap":{"LocationMap":[{"Location":"eth2","Endpoint":"172.17.0.3:5555+172.17.0.3:50071"}]},"ts":"2023-10-20T04:50:53.643116936Z","msg":"AppConfigInfo"}
{"level":"info","Updated LocationMap":{"ConfigFileTime":"2023-10-20T04:50:53.094064679Z","ConfigFileSize":76,"LocationMap":{"eth2":"172.17.0.3:5555+172.17.0.3:50071"}},"ts":"2023-10-20T04:50:53.643181219Z","msg":"AppConfigInfo, PortType=all"}
{"level":"error","ctx":"http","status":{"Errors":[{"Msg":"could not find remapped location name for eth1 from map[eth2:172.17.0.3:5555+172.17.0.3:50071]","Type":1}],"Warnings":[]},"ts":"2023-10-20T04:50:53.643653162Z","msg":"SetConfig failed"}