All apps stuck at 'deploying', no error in any container log

[TensorVortex]

Few days ago I tried to install more app, plex and stuff, and it stuck on deploying. At that time all my other app is working fine, but I decide to give it a reboot. After reboot all apps stucked at deploying. I gave it another reboot, all app went online after an hour or so, not sure how long but they went online.
However I restarted several times after that, and also fresh reinstalled truenas, still can't get apps pass deploying.

I checked logs didn't see anything too representative of the issue.

logs attached, worth noting before I generate this log, I had one time the debug log generation stuck at 'generate kubernetes log' forever.

Could anyone point me to a correct direction on how to debug and fix this?

Thanks.

 

[TensorVortex]

The only thing I did to the truenas box these days is to clear out snapshots

 

[TensorVortex]

Just tried to upgrade a pod, as it's the first time they are showing they are upgradable. Now I see in log there is

Code:

Nov 30 15:22:21 mothership dockerd[9473]: time="2021-11-30T15:22:21.340195040-05:00" level=error msg="Handler for POST /v1.41/containers/create returned error: exit status 2: \"/usr/sbin/zfs fs snapshot nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae@336530700\" => cannot open 'nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae': dataset does not exist\nusage:\n\tsnapshot [-r] [-o property=value] ... <filesystem|volume>@<snap> ...\n\nFor the property list, run: zfs set|get\n\nFor the delegated permission list, run: zfs allow|unallow\n"
Nov 30 15:22:21 mothership k3s[9903]: E1130 15:22:21.340424    9903 remote_runtime.go:228] "CreateContainer in sandbox from runtime service failed" err="rpc error: code = Unknown desc = Error response from daemon: exit status 2: \"/usr/sbin/zfs fs snapshot nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae@336530700\" => cannot open 'nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae': dataset does not exist\nusage:\n\tsnapshot [-r] [-o property=value] ... <filesystem|volume>@<snap> ...\n\nFor the property list, run: zfs set|get\n\nFor the delegated permission list, run: zfs allow|unallow" podSandboxID="eba9b00729254b8b8b4e1e5e7699bd38216d780a69f6eab8567db232809e9181"
Nov 30 15:22:21 mothership k3s[9903]: E1130 15:22:21.340482    9903 kuberuntime_manager.go:864] init container &Container{Name:autopermissions,Image:ghcr.io/truecharts/alpine:v3.14.2@sha256:a537d87e3d22c5b3f695218ca1fb5a031fb0ccafa0e3e256ef45188ab0575be6,Command:[/bin/sh -c echo 'Automatically correcting permissions...';],Args:[],WorkingDir:,Ports:[]ContainerPort{},Env:[]EnvVar{},Resources:ResourceRequirements{Limits:ResourceList{cpu: {{4 0} {<nil>} 4 DecimalSI},memory: {{8589934592 0} {<nil>}  BinarySI},},Requests:ResourceList{cpu: {{10 -3} {<nil>} 10m DecimalSI},memory: {{52428800 0} {<nil>} 50Mi BinarySI},},},VolumeMounts:[]VolumeMount{VolumeMount{Name:kube-api-access-t9xvg,ReadOnly:true,MountPath:/var/run/secrets/kubernetes.io/serviceaccount,SubPath:,MountPropagation:nil,SubPathExpr:,},},LivenessProbe:nil,ReadinessProbe:nil,Lifecycle:nil,TerminationMessagePath:/dev/termination-log,ImagePullPolicy:IfNotPresent,SecurityContext:&SecurityContext{Capabilities:&Capabilities{Add:[],Drop:[ALL],},Privileged:*false,SELinuxOptions:nil,RunAsUser:*0,RunAsNonRoot:nil,ReadOnlyRootFilesystem:nil,AllowPrivilegeEscalation:*false,RunAsGroup:nil,ProcMount:nil,WindowsOptions:nil,SeccompProfile:nil,},Stdin:false,StdinOnce:false,TTY:false,EnvFrom:[]EnvFromSource{},TerminationMessagePolicy:File,VolumeDevices:[]VolumeDevice{},StartupProbe:nil,} start failed in pod traefik-8d4fbf46-rvptz_ix-traefik(b2eb1512-6810-418b-955e-16fd9daf021c): CreateContainerError: Error response from daemon: exit status 2: "/usr/sbin/zfs fs snapshot nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae@336530700" => cannot open 'nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae': dataset does not exist
Nov 30 15:22:21 mothership k3s[9903]: usage:
Nov 30 15:22:21 mothership k3s[9903]:     snapshot [-r] [-o property=value] ... <filesystem|volume>@<snap> ...
Nov 30 15:22:21 mothership k3s[9903]: For the property list, run: zfs set|get
Nov 30 15:22:21 mothership k3s[9903]: For the delegated permission list, run: zfs allow|unallow
Nov 30 15:22:21 mothership k3s[9903]: E1130 15:22:21.340515    9903 pod_workers.go:190] "Error syncing pod, skipping" err="failed to \"StartContainer\" for \"autopermissions\" with CreateContainerError: \"Error response from daemon: exit status 2: \\\"/usr/sbin/zfs fs snapshot nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae@336530700\\\" => cannot open 'nvme/ix-applications/docker/6de892b31472e66f04cd1ff581cbe05a2b9a2b08432b31b4cb0c3941fe07b6ae': dataset does not exist\\nusage:\\n\\tsnapshot [-r] [-o property=value] ... <filesystem|volume>@<snap> ...\\n\\nFor the property list, run: zfs set|get\\n\\nFor the delegated permission list, run: zfs allow|unallow\"" pod="ix-traefik/traefik-8d4fbf46-rvptz" podUID=b2eb1512-6810-418b-955e-16fd9daf021c
Nov 30 15:22:22 mothership k3s[9903]: E1130 15:22:22.328667    9903 dns.go:126] "Search Line limits exceeded" err="Search Line limits were exceeded, some search paths have been omitted, the applied search line is: ix-openldap.svc.cluster.local svc.cluster.local cluster.local mingyaoliu.com tensorvortex.cn liumingyao.com"
Nov 30 15:22:23 mothership k3s[9903]: E1130 15:22:23.328892    9903 dns.go:126] "Search Line limits exceeded" err="Search Line limits were exceeded, some search paths have been omitted, the applied search line is: ix-jdownloader.svc.cluster.local svc.cluster.local cluster.local mingyaoliu.com tensorvortex.cn liumingyao.com"

I guess my manual removal of snapshots is the reason nothing is working? anyway I could fix this?

 

[TensorVortex]

Also have these error in middleware

Code:

[2021/11/30 15:01:14] (WARNING) DiskService.swaps_configure():143 - Failed to create swap mirror swap2: [EFAULT] Failed to create mirror swap2: mdadm: Cannot open /dev/sdd1: Device or resource busy

[2021/11/30 15:01:14] (WARNING) DiskService.swaps_configure():143 - Failed to create swap mirror swap2: [EFAULT] Failed to create mirror swap2: mdadm: Cannot open /dev/sdd1: Device or resource busy

[2021/11/30 15:01:14] (WARNING) DiskService.swaps_configure():143 - Failed to create swap mirror swap2: [EFAULT] Failed to create mirror swap2: mdadm: Cannot open /dev/sdd1: Device or resource busy

[2021/11/30 15:01:14] (WARNING) DiskService.swaps_configure():143 - Failed to create swap mirror swap2: [EFAULT] Failed to create mirror swap2: mdadm: Cannot open /dev/sdd1: Device or resource busy

[2021/11/30 15:01:14] (WARNING) DiskService.swaps_configure():143 - Failed to create swap mirror swap2: [EFAULT] Failed to create mirror swap2: mdadm: Cannot open /dev/sdd1: Device or resource busy

[2021/11/30 15:01:16] (DEBUG) EnclosureService.sync_zpool():240 - Enclosure not found, skipping enclosure sync
[2021/11/30 15:01:19] (DEBUG) EnclosureService.sync_zpool():240 - Enclosure not found, skipping enclosure sync
[2021/11/30 15:01:19] (DEBUG) EnclosureService.sync_zpool():240 - Enclosure not found, skipping enclosure sync
[2021/11/30 15:01:19] (DEBUG) EnclosureService.sync_zpool():240 - Enclosure not found, skipping enclosure sync
[2021/11/30 15:01:19] (DEBUG) EnclosureService.sync_zpool():240 - Enclosure not found, skipping enclosure sync
[2021/11/30 15:01:20] (DEBUG) EnclosureService.sync_zpool():240 - Enclosure not found, skipping enclosure sync
[2021/11/30 15:01:27] (DEBUG) middlewared.setup():286 - Root dataset for pool 'boot-pool' is not available, temporarily setting up system dataset on boot pool
[2021/11/30 15:01:27] (DEBUG) EtcService.generate():436 - No new changes for /etc/glusterfs/glusterd.vol
[2021/11/30 15:01:27] (DEBUG) EtcService.generate():436 - No new changes for /etc/default/syslog-ng
[2021/11/30 15:01:27] (DEBUG) EtcService.generate():436 - No new changes for /etc/smb4.conf
[2021/11/30 15:01:27] (DEBUG) EtcService.generate():436 - No new changes for /etc/security/pam_winbind.conf
[2021/11/30 15:01:28] (DEBUG) EtcService.generate():436 - No new changes for /etc/ganesha/ganesha.conf
[2021/11/30 15:01:28] (DEBUG) EtcService.generate():436 - No new changes for /etc/scst.conf
[2021/11/30 15:01:28] (DEBUG) EtcService.generate():436 - No new changes for /etc/apache2/Includes/webdav.conf
[2021/11/30 15:01:28] (DEBUG) EtcService.generate():436 - No new changes for /etc/glusterfs/glusterd.vol
[2021/11/30 15:01:28] (DEBUG) SMBService.reg_globals():85 - Failed to retrieve global share config from registry
[2021/11/30 15:01:28] (DEBUG) EtcService.generate():436 - No new changes for /etc/collectd/collectd.conf
[2021/11/30 15:01:29] (DEBUG) EtcService.generate():436 - No new changes for /etc/default/rrdcached
[2021/11/30 15:01:29] (DEBUG) EtcService.generate():436 - No new changes for /etc/rsyncd.conf
[2021/11/30 15:01:29] (DEBUG) EtcService.generate():436 - No new changes for /etc/security/pam_winbind.conf
[2021/11/30 15:01:29] (DEBUG) EtcService.generate():436 - No new changes for /etc/smb4_share.conf
[2021/11/30 15:01:29] (DEBUG) EtcService.generate():436 - No new changes for /etc/ctdb/ctdb.conf
[2021/11/30 15:01:29] (DEBUG) EtcService.generate():436 - No new changes for /etc/default/syslog-ng
[2021/11/30 15:01:30] (DEBUG) EtcService.generate():436 - No new changes for /etc/proftpd/proftpd.conf
[2021/11/30 15:01:30] (DEBUG) EtcService.generate():436 - No new changes for /etc/default/nfs-common
[2021/11/30 15:01:30] (DEBUG) EtcService.generate():436 - No new changes for /etc/ganesha/ganesha.conf
[2021/11/30 15:01:30] (DEBUG) EtcService.generate():436 - No new changes for /etc/apache2/apache2.conf
[2021/11/30 15:01:30] (DEBUG) EtcService.generate():436 - No new changes for /etc/apache2/Includes/webdav.conf
[2021/11/30 15:01:35] (DEBUG) EtcService.generate():436 - No new changes for /etc/collectd/collectd.conf
[2021/11/30 15:01:35] (DEBUG) EtcService.generate():385 - mako:local/smbusername.map file removed.
[2021/11/30 15:01:35] (DEBUG) EtcService.generate():436 - No new changes for /etc/default/rrdcached
[2021/11/30 15:01:36] (DEBUG) EtcService.generate():436 - No new changes for /etc/group
[2021/11/30 15:01:36] (DEBUG) EtcService.generate():436 - No new changes for /etc/passwd
[2021/11/30 15:01:37] (DEBUG) EtcService.generate():436 - No new changes for /etc/shadow
[2021/11/30 15:01:37] (DEBUG) SMBService.update_passdb_user():114 - User [ming] does not exist in the passdb.tdb file. Creating entry with rid [10026].
[2021/11/30 15:01:38] (INFO) ZFSSnapshot.do_create():1095 - Snapshot taken: boot-pool/.system/samba4@wbc-1638302498
[2021/11/30 15:01:39] (DEBUG) EtcService.generate():436 - No new changes for /etc/smb4.conf
[2021/11/30 15:01:39] (DEBUG) EtcService.generate():436 - No new changes for /etc/security/pam_winbind.conf
[2021/11/30 15:01:39] (DEBUG) EtcService.generate():436 - No new changes for /etc/smb4_share.conf
[2021/11/30 15:01:44] (ERROR) ServiceService.start():143 - Service 'collectd' not running after start
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task alert.flush_alerts to run every 3600 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task alert.process_alerts to run every 60 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task certificate.renew_certs to run every 86400 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task certificateauthority.crl_generation to run every 86400 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task chart.release.periodic_chart_releases_update_checks to run every 86400 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task clusterjob.process_queue to run every 3600 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task kerberos.keytab.check_updated_keytab to run every 3600 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task kmip.sync_keys to run every 86400 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task mail.send_mail_queue to run every 600 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task pool.dataset.sync_db_keys to run every 86400 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task smb.sharesec.check_share_info_tdb to run every 3600 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task truecommand.health_check to run every 1800 seconds
[2021/11/30 15:01:46] (DEBUG) middlewared._setup_periodic_tasks():983 - Setting up periodic task zettarepl.flush_state to run every 3600 seconds
[2021/11/30 15:01:47] (DEBUG) EtcService.generate():436 - No new changes for /etc/avahi/avahi-daemon.conf
[2021/11/30 15:01:49] (DEBUG) EtcService.generate():385 - mako:systemd/system/docker.service.d/http-proxy.conf file removed.
[2021/11/30 15:01:51] (DEBUG) EtcService.generate():436 - No new changes for /etc/wsdd.conf
[2021/11/30 15:02:07] (ERROR) KubernetesStorageClassService.setup_default_storage_class():61 - Failed to setup default storage class: [EFAULT] Failed to create storage class: (422)
Reason: Unprocessable Entity
HTTP response headers: <CIMultiDictProxy('Cache-Control': 'no-cache, private', 'Content-Type': 'application/json', 'X-Kubernetes-Pf-Flowschema-Uid': 'd17a6b9a-e1a0-498c-a1af-72323dad8aee', 'X-Kubernetes-Pf-Prioritylevel-Uid': 'c2c6cfba-c937-4ddb-b650-d35d8d1f38c1', 'Date': 'Tue, 30 Nov 2021 20:02:07 GMT', 'Content-Length': '452')>
HTTP response body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"StorageClass.storage.k8s.io \"openebs-zfspv-default\" is invalid: parameters: Forbidden: updates to parameters are forbidden.","reason":"Invalid","details":{"name":"openebs-zfspv-default","group":"storage.k8s.io","kind":"StorageClass","causes":[{"reason":"FieldValueForbidden","message":"Forbidden: updates to parameters are forbidden.","field":"parameters"}]},"code":422}


[2021/11/30 15:02:11] (WARNING) middlewared._loop_monitor_thread():1562 - Task seems blocked:
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 207, in __call_api
    return_data = self.deserialize(response_data, response_type)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 279, in deserialize
    return self.__deserialize(data, response_type)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 318, in __deserialize
    return self.__deserialize_model(data, klass)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 657, in __deserialize_model
    kwargs[attr] = self.__deserialize(value, attr_type)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 295, in __deserialize
    return [self.__deserialize(sub_data, sub_kls)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 295, in <listcomp>
    return [self.__deserialize(sub_data, sub_kls)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 318, in __deserialize
    return self.__deserialize_model(data, klass)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 657, in __deserialize_model
    kwargs[attr] = self.__deserialize(value, attr_type)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 318, in __deserialize
    return self.__deserialize_model(data, klass)
  File "/usr/lib/python3/dist-packages/kubernetes_asyncio/client/api_client.py", line 643, in __deserialize_model
    if (hasattr(klass, 'get_real_child_model')

[2021/11/30 15:21:14] (ERROR) middlewared.job.run():394 - Job <bound method accepts.<locals>.wrap.<locals>.nf of <middlewared.plugins.docker_linux.images.DockerImagesService object at 0x7f26ff1f14f0>> failed
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/middlewared/plugins/docker_linux/images.py", line 115, in pull
    response = await docker.images.pull(
  File "/usr/lib/python3/dist-packages/aiodocker/images.py", line 133, in _handle_list
    async with cm as response:
  File "/usr/lib/python3/dist-packages/aiodocker/utils.py", line 309, in __aenter__
    resp = await self._coro
  File "/usr/lib/python3/dist-packages/aiodocker/docker.py", line 268, in _do_query
    raise DockerError(response.status, json.loads(what.decode("utf8")))
aiodocker.exceptions.DockerError: DockerError(400, 'invalid reference format')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/middlewared/job.py", line 382, in run
    await self.future
  File "/usr/lib/python3/dist-packages/middlewared/job.py", line 418, in __run_body
    rv = await self.method(*([self] + args))
  File "/usr/lib/python3/dist-packages/middlewared/schema.py", line 1263, in nf
    return await func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/middlewared/schema.py", line 1131, in nf
    res = await f(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/middlewared/plugins/docker_linux/images.py", line 119, in pull
    raise CallError(f'Failed to pull image: {e.message}')
middlewared.service_exception.CallError: [EFAULT] Failed to pull image: invalid reference format
[2021/11/30 15:21:14] (INFO) ZFSSnapshot.do_create():1095 - Snapshot taken: nvme/ix-applications/releases/codeserver/volumes@6

 

[truecharts]

Be sure to remove that debug asap, debugs should never be published publically.

 

[TensorVortex]

Be sure to remove that debug asap, debugs should never be published publically.

ok removed. I suppose my option is to either remove all docker images, and reinstall, or restore from previous backup.

 

[truecharts]

Considering the names of the Apps, you are most likely running TrueCharts.
Please be aware we have our own support channels and don't offer our (quite active) support on this forum.