更新相册无法启动

kaxa

设备环境：物理机

BUG现象：app 没法打开相册应用，提示需要升级，升级 fnOs 到0.9.9 同步更新相册，然后 “应用启动”失败

出现频率：必现

联系方式：wx:chenjianmircoblog

日志文件：

2025-06-16T23:34:11.931520+08:00 nas-sp trim[1770]: [Lingual]Cannot find event id:app.starting of service trim.app-center
2025-06-16T23:34:11.954493+08:00 nas-sp trim[1770]: [Lingual]Cannot find event id:entryChange of service trim.sac
2025-06-16T23:34:17.021706+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:34:17.022381+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:34:17.022479+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1002/Photos, mask:0x400007c8, level:0
2025-06-16T23:34:17.022959+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1002, mask:0x400007c8
2025-06-16T23:34:17.023458+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1002, ignore
2025-06-16T23:34:17.024966+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1002/Photos, mask:0x400007c8
2025-06-16T23:34:17.025103+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1002/Photos
2025-06-16T23:34:17.025467+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1002/Photos', error: Invalid cross-device link
2025-06-16T23:34:17.025552+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:34:17.025614+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:34:17.025680+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1001/Photos, mask:0x400007c8, level:0
2025-06-16T23:34:17.025740+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1001, mask:0x400007c8
2025-06-16T23:34:17.025802+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1001, ignore
2025-06-16T23:34:17.025889+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1001/Photos, mask:0x400007c8
2025-06-16T23:34:17.025959+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1001/Photos
2025-06-16T23:34:17.026055+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1001/Photos', error: Invalid cross-device link
2025-06-16T23:34:17.027057+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:34:17.027169+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:34:17.027245+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1000/Photos, mask:0x400007c8, level:0
2025-06-16T23:34:17.027309+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1000, mask:0x400007c8
2025-06-16T23:34:17.027382+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1000, ignore
2025-06-16T23:34:17.027446+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1000/Photos, mask:0x400007c8
2025-06-16T23:34:17.027538+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1000/Photos
2025-06-16T23:34:17.027613+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1000/Photos', error: Invalid cross-device link
2025-06-16T23:34:17.035979+08:00 nas-sp sysinfo_service[1791]: #033[0m#033[1;33m[ne]post_close_event to non-existent socket 22, session: 95307890699.
2025-06-16T23:34:17.036472+08:00 nas-sp rpc_broker[1781]: #033[0m#033[1;33m[ne]post_close_event to non-existent socket 24, session: 103897628699.
2025-06-16T23:34:27.026611+08:00 nas-sp trim_file_monitor[1798]: Saved done!
2025-06-16T23:34:31.751879+08:00 nas-sp trim[1770]: [Lingual]Cannot find event id:app.start.failed of service trim.app-center
2025-06-16T23:34:31.752854+08:00 nas-sp TRIMEVENT[1824]: TRIMEVENT:{"data":{"APP_GROUP":"","APP_ID":1,"APP_NAME":"trim.photos","APP_USERNAME":"","DISPLAY_NAME":"相册","INSTALL_VOLUME_ID":0,"META_VOLUME_ID":0,"PORT_USAGE":0},"datetime":1750088071,"eventId":"APP_START_FAILED_LOCAL_APP_RUN_EXCEPTION","from":"trim.app-center","level":0}
2025-06-16T23:34:31.755682+08:00 nas-sp trim[1770]: [Lingual]Cannot find event id:entryChange of service trim.sac
2025-06-16T23:34:38.787986+08:00 nas-sp TRIMEVENT[1824]: TRIMEVENT:{"data":{"APP_GROUP":"","APP_ID":1,"APP_NAME":"trim.photos","APP_USERNAME":"","DISPLAY_NAME":"相册","INSTALL_VOLUME_ID":0,"META_VOLUME_ID":0,"PORT_USAGE":0},"datetime":1750088078,"eventId":"APP_CRASH","from":"trim.app-center","level":1}
2025-06-16T23:34:38.788503+08:00 nas-sp trim[1770]: [Lingual]Cannot find event id:app.starting of service trim.app-center
2025-06-16T23:34:38.790106+08:00 nas-sp trim[1770]: [Lingual]Cannot find event id:entryChange of service trim.sac
2025-06-16T23:34:44.007882+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:34:44.008443+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:34:44.008815+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1001/Photos, mask:0x400007c8, level:0
2025-06-16T23:34:44.009144+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1001, mask:0x400007c8
2025-06-16T23:34:44.009658+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1001, ignore
2025-06-16T23:34:44.010400+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1001/Photos, mask:0x400007c8
2025-06-16T23:34:44.010476+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1001/Photos
2025-06-16T23:34:44.010573+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1001/Photos', error: Invalid cross-device link
2025-06-16T23:34:44.010638+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:34:44.010733+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:34:44.010855+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1000/Photos, mask:0x400007c8, level:0
2025-06-16T23:34:44.010919+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1000, mask:0x400007c8
2025-06-16T23:34:44.010977+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1000, ignore
2025-06-16T23:34:44.011035+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1000/Photos, mask:0x400007c8
2025-06-16T23:34:44.011202+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1000/Photos
2025-06-16T23:34:44.011269+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1000/Photos', error: Invalid cross-device link
2025-06-16T23:34:44.012064+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:34:44.013219+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:34:44.013545+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1002/Photos, mask:0x400007c8, level:0
2025-06-16T23:34:44.014130+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1002, mask:0x400007c8
2025-06-16T23:34:44.014485+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1002, ignore
2025-06-16T23:34:44.014741+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1002/Photos, mask:0x400007c8
2025-06-16T23:34:44.015030+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1002/Photos
2025-06-16T23:34:44.015468+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1002/Photos', error: Invalid cross-device link
2025-06-16T23:34:44.023887+08:00 nas-sp rpc_broker[1781]: #033[0m#033[1;33m[ne]post_close_event to non-existent socket 24, session: 72057697935556636.
2025-06-16T23:34:44.025146+08:00 nas-sp sysinfo_service[1791]: #033[0m#033[1;33m[ne]post_close_event to non-existent socket 22, session: 72057689345818636.
2025-06-16T23:34:54.008581+08:00 nas-sp trim_file_monitor[1798]: Saved done!
2025-06-16T23:35:01.933239+08:00 nas-sp CRON[5598]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
2025-06-16T23:36:39.454751+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:36:39.454922+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:36:39.454996+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1002/Photos, mask:0x400007c8, level:0
2025-06-16T23:36:39.455058+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1002, mask:0x400007c8
2025-06-16T23:36:39.455129+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1002, ignore
2025-06-16T23:36:39.455190+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1002/Photos, mask:0x400007c8
2025-06-16T23:36:39.455249+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1002/Photos
2025-06-16T23:36:39.455311+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1002/Photos', error: Invalid cross-device link
2025-06-16T23:36:39.456379+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:36:39.456481+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:36:39.456546+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1001/Photos, mask:0x400007c8, level:0
2025-06-16T23:36:39.456846+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1001, mask:0x400007c8
2025-06-16T23:36:39.456915+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1001, ignore
2025-06-16T23:36:39.456977+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1001/Photos, mask:0x400007c8
2025-06-16T23:36:39.457036+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1001/Photos
2025-06-16T23:36:39.457099+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1001/Photos', error: Invalid cross-device link
2025-06-16T23:36:39.457158+08:00 nas-sp monitor[1798]: Received command, data size: 68
2025-06-16T23:36:39.457216+08:00 nas-sp monitor[1798]: Command, id:101, length:60, data:#024
2025-06-16T23:36:39.457276+08:00 nas-sp monitor[1798]: Received command, id:2, path:/vol1/1000/Photos, mask:0x400007c8, level:0
2025-06-16T23:36:39.457334+08:00 nas-sp monitor[1798]: WatchFileSystem, /vol1/1000, mask:0x400007c8
2025-06-16T23:36:39.457392+08:00 nas-sp monitor[1798]: Had been registered the volume, /vol1/1000, ignore
2025-06-16T23:36:39.457452+08:00 nas-sp monitor[1798]: WatchDirectory, /vol1/1000/Photos, mask:0x400007c8
2025-06-16T23:36:39.457511+08:00 nas-sp monitor[1798]: Added flags: 265, mask 0x400007c8, path:/vol1/1000/Photos
2025-06-16T23:36:39.457598+08:00 nas-sp monitor[1798]: Couldn't add monitor '/vol1/1000/Photos', error: Invalid cross-device link
2025-06-16T23:36:39.467673+08:00 nas-sp sysinfo_service[1791]: #033[0m#033[1;33m[ne]post_close_event to non-existent socket 22, session: 72057689345818637.
2025-06-16T23:36:39.469563+08:00 nas-sp rpc_broker[1781]: #033[0m#033[1;33m[ne]post_close_event to non-existent socket 24, session: 72057697935556637.
2025-06-16T23:36:49.455965+08:00 nas-sp trim_file_monitor[1798]: Saved done!
2025-06-16T23:37:47.619557+08:00 nas-sp dbus-daemon[820]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.243' (uid=0 pid=1791 comm="/usr/trim/bin/sysinfo_service")
2025-06-16T23:37:47.644171+08:00 nas-sp systemd[1]: Starting systemd-timedated.service - Time & Date Service...
2025-06-16T23:37:47.729904+08:00 nas-sp dbus-daemon[820]: [system] Successfully activated service 'org.freedesktop.timedate1'
2025-06-16T23:37:47.730655+08:00 nas-sp systemd[1]: Started systemd-timedated.service - Time & Date Service.
2025-06-16T23:37:49.753009+08:00 nas-sp NetworkManager[880]: <info>  [1750088269.7524] dhcp6 (enp2s0): state changed new lease, address=2408:8256:aa0:d740::7f8b
2025-06-16T23:38:34.691999+08:00 nas-sp trim[1770]: [Lingual]Cannot find event id:app.start.failed of service trim.app-center
2025-06-16T23:38:46.059232+08:00 nas-sp systemd[1]: systemd-timedated.service: Deactivated successfully.
2025-06-16T23:42:33.232753+08:00 nas-sp dbus-daemon[820]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.262' (uid=0 pid=1791 comm="/usr/trim/bin/sysinfo_service")
2025-06-16T23:42:33.260357+08:00 nas-sp systemd[1]: Starting systemd-timedated.service - Time & Date Service...
2025-06-16T23:42:33.346622+08:00 nas-sp dbus-daemon[820]: [system] Successfully activated service 'org.freedesktop.timedate1'
2025-06-16T23:42:33.346799+08:00 nas-sp systemd[1]: Started systemd-timedated.service - Time & Date Service.
2025-06-16T23:43:03.382787+08:00 nas-sp systemd[1]: systemd-timedated.service: Deactivated successfully.
2025-06-16T23:45:01.943565+08:00 nas-sp CRON[6066]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)

kaxa

还有 trim_app_center/error.log

===============================

time="2025-06-17T00:57:49+08:00" level=error msg="start app error" appName=trim.photos class=start error="10330:" file="/app/core/service/start.go:293" reqid=1750093050682338752 text=
appstore/core/service.(*StartService).run(0x16cf920?, 0xc0000f1290)
/app/core/service/start.go:293 +0x13d5
appstore/core/service.(*StartService).Run(0x46fc8e?, 0xc0000f1290)
/app/core/service/start.go:123 +0x1c
appstore/core/app/appqueue.(*Queue).handleTask.func1.(*Events).Call.2(0xc0000f1290, 0xc000649e8e, 0xc00029f880?, {0xf0c353?, 0xc00029f880?})
/app/core/app/appqueue/event.go:29 +0x72
appstore/core/app/appqueue.(*Events).Call(...)
/app/core/app/appqueue/event.go:30
appstore/core/app/appqueue.(*Queue).handleTask.func1(0xc00005e6f0?, 0xc000649ede, 0xda8380?)
/app/core/app/appqueue/queue.go:157 +0x5e
appstore/core/app/appqueue.(*Queue).handleTask(0xc000535720, 0xc0000f1290)
/app/core/app/appqueue/queue.go:158 +0xa5
created by appstore/core/app/appqueue.(*Queue).processTasks.func1 in goroutine 50
/app/core/app/appqueue/queue.go:128 +0xd8
time="2025-06-17T00:57:50+08:00" level=error msg="response error: &vo.Result{Code:10330, Msg:"", Data:(*vo.StartInfo)(nil)}, err=" file="/app/core/errorx/error.go:46"
time="2025-06-17T00:58:16+08:00" level=error msg="start app error" appName=trim.photos class=start error="10330:" file="/app/core/service/start.go:293" reqid=1750093081413987820 text=
appstore/core/service.(*StartService).run(0xc000043710?, 0xc000775290)
/app/core/service/start.go:293 +0x13d5
appstore/core/service.(*StartService).Run(0xc0003679e0?, 0xc000775290)
/app/core/service/start.go:123 +0x1c
appstore/core/service.(*HAStartService).Run(0x16cf920?, 0xc000774bd0)
/app/core/service/ha_start.go:117 +0x1fd
appstore/core/app/appqueue.(*Queue).handleTask.func1.(*Events).Call.2(0xc000774bd0, 0xc000043e8e, 0x10000000000?, {0xf148c7?, 0x7cd3b5?})
/app/core/app/appqueue/event.go:29 +0x72
appstore/core/app/appqueue.(*Events).Call(...)
/app/core/app/appqueue/event.go:30
appstore/core/app/appqueue.(*Queue).handleTask.func1(0xc0006eb8f0?, 0xc000043ede, 0x0?)
/app/core/app/appqueue/queue.go:157 +0x5e
appstore/core/app/appqueue.(*Queue).handleTask(0xc000535720, 0xc000774bd0)
/app/core/app/appqueue/queue.go:158 +0xa5
created by appstore/core/app/appqueue.(*Queue).processTasks.func1 in goroutine 50
/app/core/app/appqueue/queue.go:128 +0xd8

飞牛技术同学

提供的日志没有相册的部分

Couldn't add monitor '/vol1/1001/Photos', error: Invalid cross-device link可以先确认一下存储空间1是否正常

kaxa

已经确认过存储空间正常

06-22 发现有nas 新版本，更新后

相册还是没法启动，单独启动项目，

app有报错日志

time="2025-06-22T21:59:17+08:00" level=error msg="start app error" appName=trim.photos class=start error="10330:" file="/app/core/service/start.go:293" reqid=1750600738084822889 text=
appstore/core/service.(*StartService).run(0x16d1920?, 0xc00014d3b0)
/app/core/service/start.go:293 +0x13b5
appstore/core/service.(*StartService).Run(0x16d1920?, 0xc00014d3b0)
/app/core/service/start.go:123 +0x1c
appstore/core/app/appqueue.(*Queue).handleTask.func1.(*Events).Call.2(0xc00014d3b0, 0xc000919e8e, 0xc0005a21c0?, {0xf0da33?, 0x7cde95?})
/app/core/app/appqueue/event.go:29 +0x72
appstore/core/app/appqueue.(*Events).Call(...)
/app/core/app/appqueue/event.go:30
appstore/core/app/appqueue.(*Queue).handleTask.func1(0xc00058b560?, 0xc000919ede, 0xc0006af200?)
/app/core/app/appqueue/queue.go:157 +0x5e
appstore/core/app/appqueue.(*Queue).handleTask(0xc0005825f0, 0xc00014d3b0)
/app/core/app/appqueue/queue.go:158 +0xa5
created by appstore/core/app/appqueue.(*Queue).processTasks.func1 in goroutine 42
/app/core/app/appqueue/queue.go:128 +0xd8
time="2025-06-22T21:59:18+08:00" level=error msg="response error: &vo.Result{Code:10330, Msg:"", Data:(*vo.StartInfo)(nil)}, err=" file="/app/core/errorx/error.go:46"
time="2025-06-22T21:59:44+08:00" level=error msg="start app error" appName=trim.photos class=start error="10330:" file="/app/core/service/start.go:293" reqid=1750600769566941426 text=
appstore/core/service.(*StartService).run(0xc000739710?, 0xc000974a20)
/app/core/service/start.go:293 +0x13b5
appstore/core/service.(*StartService).Run(0xc000700d60?, 0xc000974a20)
/app/core/service/start.go:123 +0x1c
appstore/core/service.(*HAStartService).Run(0x16d1920?, 0xc0008ff3b0)
/app/core/service/ha_start.go:117 +0x1fd
appstore/core/app/appqueue.(*Queue).handleTask.func1.(*Events).Call.2(0xc0008ff3b0, 0xc000739e8e, 0x0?, {0xf15fad?, 0x7cde95?})
/app/core/app/appqueue/event.go:29 +0x72
appstore/core/app/appqueue.(*Events).Call(...)
/app/core/app/appqueue/event.go:30
appstore/core/app/appqueue.(*Queue).handleTask.func1(0xc000226ef8?, 0xc000739ede, 0x1fcf0f41433?)
/app/core/app/appqueue/queue.go:157 +0x5e
appstore/core/app/appqueue.(*Queue).handleTask(0xc0005825f0, 0xc0008ff3b0)
/app/core/app/appqueue/queue.go:158 +0xa5
created by appstore/core/app/appqueue.(*Queue).processTasks.func1 in goroutine 42
/app/core/app/appqueue/queue.go:128 +0xd8
time="2025-06-22T22:01:40+08:00" level=error msg="start app error" appName=trim.photos class=start error="10330:" file="/app/core/service/start.go:293" reqid=1750600885011392514 text=
appstore/core/service.(*StartService).run(0xc000043710?, 0xc00014ca20)
/app/core/service/start.go:293 +0x13b5
appstore/core/service.(*StartService).Run(0xc000700d60?, 0xc00014ca20)
/app/core/service/start.go:123 +0x1c
appstore/core/service.(*HAStartService).Run(0x16d1920?, 0xc0008ff3b0)
/app/core/service/ha_start.go:117 +0x1fd
appstore/core/app/appqueue.(*Queue).handleTask.func1.(*Events).Call.2(0xc0008ff3b0, 0xc000043e8e, 0x0?, {0xf15fad?, 0x7cde95?})
/app/core/app/appqueue/event.go:29 +0x72
appstore/core/app/appqueue.(*Events).Call(...)
/app/core/app/appqueue/event.go:30
appstore/core/app/appqueue.(*Queue).handleTask.func1(0xc000226ef8?, 0xc000043ede, 0x1fcf0f41433?)
/app/core/app/appqueue/queue.go:157 +0x5e
appstore/core/app/appqueue.(*Queue).handleTask(0xc0005825f0, 0xc0008ff3b0)
/app/core/app/appqueue/queue.go:158 +0xa5
created by appstore/core/app/appqueue.(*Queue).processTasks.func1 in goroutine 42
/app/core/app/appqueue/queue.go:128 +0xd8