search

thin-edge / thin-edge.io

The open edge framework for lightweight IoT devices
https://thin-edge.io
Apache License 2.0
210 stars 54 forks source link

tedge-agent fails to startup due to SoftwareManagerActor failing due to an existing file #2959

Open reubenmiller opened 1 week ago

reubenmiller commented 1 week ago

Describe the bug

tedge-agent exits shortly after starting due to the following error (see the Additional context for the full log)

2024-06-22T17:04:13.206357574Z ERROR Runtime: Actor SoftwareManagerActor-11 has finished unsuccessfully: ActorError(FromState(FromIo(Os { code: 17, kind: AlreadyExists, message: "File exists" })))

The error message is not very helpful as it does not show which file already "exists", so the user can't fix the issue easily.

To Reproduce

It is unclear how to reproduce the error as it was encountered when using a custom config-dir location on a very resource constrained device.

Expected behavior

The error message should list the path of the file which already exists, so the user has a chance to potentially "fix" the current situation.

Screenshots

Environment (please complete the following information):

Property Value
OS [incl. version] unknown
Hardware [incl. revision] unknown
System-Architecture Linux mdm9607 3.18.48 #1 PREEMPT Mon May 27 09:38:30 CEST 2024 armv7l GNU/Linux
thin-edge.io version tedge 1.1.2~118+g476783c

Additional context

The full logs from the tedge-agent are shown below:

2024-06-22T17:04:13.147691793Z  INFO tedge_agent::agent: tedge-agent starting
2024-06-22T17:04:13.148309293Z  INFO sm-agent: tedge_agent::agent: Starting tedge-agent v1.1.2~118+g476783c
2024-06-22T17:04:13.148817366Z  INFO Runtime: Started
2024-06-22T17:04:13.150195595Z  INFO sm-agent: tedge_config_manager::config: Using the configuration from /data/thin-edge.io/etc/tedge/plugins/tedge-configuration-plugin.toml
2024-06-22T17:04:13.151657991Z  INFO sm-agent: log_manager::config: Using the configuration from /data/thin-edge.io/etc/tedge/plugins/tedge-log-plugin.toml
2024-06-22T17:04:13.152286689Z  INFO sm-agent: tedge_agent::agent: Running as a main device, starting tedge_to_te_converter and File Transfer Service
2024-06-22T17:04:13.152505282Z  INFO Runtime: Running TedgetoTeConverter-0
2024-06-22T17:04:13.152872886Z  INFO sm-agent: HTTP Server: File transfer service has HTTPS disabled (configured in `http.cert_path`/`http.key_path`) and certificate authentication disabled (configured in `http.ca_path`)
2024-06-22T17:04:13.153162939Z  INFO Runtime: Running HttpFileTransferServer-1
2024-06-22T17:04:13.154127314Z  INFO Runtime: Running FileCacheActor-2
2024-06-22T17:04:13.154449657Z  INFO Runtime: Running Signal-Handler-3
2024-06-22T17:04:13.154973355Z  INFO Runtime: Running MQTT-4
2024-06-22T17:04:13.155792314Z  INFO mqtt_channel::connection: MQTT connecting to broker: host=127.0.0.1:1883, session_name=Some("tedge-agent#te/device/main//")
2024-06-22T17:04:13.158368407Z  INFO mqtt_channel::connection: MQTT connection established
2024-06-22T17:04:13.158644136Z  WARN sm-agent: tedge_agent::state_repository::state: Cannot use "/data/tedge/agent" to store tedge-agent state: No such file or directory (os error 2)
2024-06-22T17:04:13.161114449Z  INFO sm-agent: tedge_agent::state_repository::state: Use "/data/thin-edge.io/etc/tedge/.agent/restart-current-operation" to store tedge-agent restart-current-operation state
2024-06-22T17:04:13.161297366Z  WARN sm-agent: tedge_agent::state_repository::state: Cannot use "/data/tedge/agent" to store tedge-agent state: No such file or directory (os error 2)
2024-06-22T17:04:13.161432991Z  INFO sm-agent: tedge_agent::state_repository::state: Use "/data/thin-edge.io/etc/tedge/.agent/software-current-operation" to store tedge-agent software-current-operation state
2024-06-22T17:04:13.160993928Z  INFO Runtime: Running FsWatcher-5
2024-06-22T17:04:13.162001116Z  INFO Runtime: Running Downloader-6
2024-06-22T17:04:13.162109345Z  INFO Runtime: Running Uploader-7
2024-06-22T17:04:13.162687574Z  INFO Runtime: Running ConfigManager-8
2024-06-22T17:04:13.162814501Z  INFO Runtime: Running LogManager-9
2024-06-22T17:04:13.163053928Z  INFO Runtime: Running RestartManagerActor-10
2024-06-22T17:04:13.163172886Z  INFO Runtime: Running SoftwareManagerActor-11
2024-06-22T17:04:13.163278772Z  INFO Runtime: Running Script-12
2024-06-22T17:04:13.162422782Z  WARN sm-agent: tedge_agent::state_repository::state: Cannot use "/data/tedge/agent" to store tedge-agent state: No such file or directory (os error 2)
2024-06-22T17:04:13.164005491Z  INFO sm-agent: tedge_agent::state_repository::state: Use "/data/thin-edge.io/etc/tedge/.agent/workflows" to store tedge-agent workflows state
2024-06-22T17:04:13.166256011Z  INFO tedge_config_manager::config: Using the configuration from /data/thin-edge.io/etc/tedge/plugins/tedge-configuration-plugin.toml
2024-06-22T17:04:13.167168876Z  INFO tedge_log_manager::actor: Reloading supported log types
2024-06-22T17:04:13.167301376Z  INFO log_manager::config: Using the configuration from /data/thin-edge.io/etc/tedge/plugins/tedge-log-plugin.toml
2024-06-22T17:04:13.170859449Z  INFO plugin_sm::plugin_manager: Default plugin type: Not configured
2024-06-22T17:04:13.171488824Z  WARN tedge_agent::software_manager::actor: Couldn't load plugins from /data/thin-edge.io/etc/tedge/sm-plugins
2024-06-22T17:04:13.171669761Z  INFO Runtime: Running WorkflowActor-13
2024-06-22T17:04:13.171879657Z  INFO Runtime: Running HealthMonitorActor-14
2024-06-22T17:04:13.187266845Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.188363147Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.189546741Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.190440803Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.191490907Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.192298147Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.193320751Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.194118407Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.195017834Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.195809449Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.196383876Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.197312053Z  INFO tedge_agent::operation_workflows::actor: Waiting successful config_snapshot operation to be cleared
2024-06-22T17:04:13.197965959Z  INFO tedge_agent::operation_workflows::actor: Processing software_list operation executing step
2024-06-22T17:04:13.198902001Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.199479657Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.200099813Z  INFO tedge_agent::operation_workflows::actor: Processing software_list operation scheduled step
2024-06-22T17:04:13.201026532Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.201781116Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.202317157Z  INFO tedge_agent::operation_workflows::actor: Waiting successful software_list operation to be cleared
2024-06-22T17:04:13.203285178Z  INFO tedge_agent::operation_workflows::actor: Waiting successful config_snapshot operation to be cleared
2024-06-22T17:04:13.206357574Z ERROR Runtime: Actor SoftwareManagerActor-11 has finished unsuccessfully: ActorError(FromState(FromIo(Os { code: 17, kind: AlreadyExists, message: "File exists" })))
2024-06-22T17:04:13.206553668Z  INFO Runtime: Shutting down on error: File exists (os error 17)
2024-06-22T17:04:13.20785148Z  INFO Runtime: Actor has finished: FsWatcher-5
2024-06-22T17:04:13.20803898Z  INFO Runtime: Actor has finished: Downloader-6
2024-06-22T17:04:13.208171741Z  INFO Runtime: Actor has finished: FileCacheActor-2
2024-06-22T17:04:13.208340334Z  INFO Runtime: Actor has finished: MQTT-4
2024-06-22T17:04:13.209155491Z  INFO Runtime: Actor has finished: WorkflowActor-13
2024-06-22T17:04:13.209332834Z  INFO Runtime: Actor has finished: HealthMonitorActor-14
2024-06-22T17:04:13.209465022Z  INFO Runtime: Actor has finished: TedgetoTeConverter-0
2024-06-22T17:04:13.209747261Z  INFO tedge_agent::file_transfer_server::actor: Shutdown
2024-06-22T17:04:13.209880178Z  INFO Runtime: Actor has finished: HttpFileTransferServer-1
2024-06-22T17:04:13.210023251Z  INFO Runtime: Actor has finished: LogManager-9
2024-06-22T17:04:13.210142522Z  INFO Runtime: Actor has finished: Uploader-7
2024-06-22T17:04:13.210255855Z  INFO Runtime: Actor has finished: Script-12
2024-06-22T17:04:13.21046122Z  INFO Runtime: Actor has finished: ConfigManager-8
2024-06-22T17:04:13.210894605Z  INFO Runtime: Actor has finished: Signal-Handler-3
2024-06-22T17:04:13.212424136Z  INFO mqtt_channel::connection: MQTT connection closed
2024-06-22T17:04:13.221459657Z  INFO Runtime: Actor has finished: RestartManagerActor-10
2024-06-22T17:04:13.221917053Z  INFO Runtime: All actors have finished
2024-06-22T17:04:13.222105386Z ERROR sm-agent: tedge_actors::runtime: Aborted due to File exists (os error 17)