Status unhealthy "ace.jar start: no such file or directory"

[LukeSteward]

Operating system

Ubuntu 20.04.3 LTS

UniFi Tag

latest

Docker run

docker run -d --restart=unless-stopped --net=host --name=unifi -e TZ='Europe/London' -e RUNAS_UID0=false -e UNIFI_UID=1001 -e UNIFI_GID=1001 -v /var/docks/unifi:/unifi jacobalberty/unifi:latest

Bug description

I have just updated to the latest verison and am now getting an error with it trying to start /usr/lib/unifi/lib/ace.jar

Steps to reproduce

No response

Relevant log output

[2021-12-10 20:03:35,743] <docker-entrypoint> Starting unifi controller service.

error: exec: "java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M\n  -Djava.awt.headless=true\n  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start": stat java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M

  -Djava.awt.headless=true

  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory

[2021-12-10 20:03:36,775] <docker-entrypoint> WARN: unifi service process ended without being signaled? Check for errors in /unifi/log.

[2021-12-10 20:03:37,483] <docker-entrypoint> Starting unifi controller service.

error: exec: "java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M\n  -Djava.awt.headless=true\n  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start": stat java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M

  -Djava.awt.headless=true

  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory

[jacobalberty]

What cpu architecture?

[LukeSteward]

Its a AMD 64bit

My setup is Hyper-V Host running a Ubuntu VM with docker installed that hosts the controller.

[jacobalberty]

Ok so that error is actually not saying ace.jar is missing it's saying the whole command is missing, likely actually referring to the java binary. I have just tested that exact command on an amd64 system and it's working for me. The error reminds me of the error i see when I forget to load qemu before building multi architecture images. Try running docker run --rm -it --name=unifi -e TZ='Europe/London' -e RUNAS_UID0=false -e UNIFI_UID=1001 -e UNIFI_GID=1001 -v /var/docks/unifi:/unifi jacobalberty/unifi:latest ls -al /usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java and tell me what it outputs.

[LukeSteward]

root@unifi-host:/home/administrator# docker run --rm -it --name=unifi -e TZ='Europe/London' -e RUNAS_UID0=false -e UNIFI_UID=1001 -e UNIFI_GID=1001 -v /var/docks/unifi:/unifi jacobalberty/unifi:latest ls -al /usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java [2021-12-10 20:36:42,262] <docker-entrypoint> Executing: ls -al /usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java -rwxr-xr-x 1 root root 6280 Apr 21 2021 /usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java

[rohanrns]

Similar after updating. AMD64:

ubuntu@ubnt:~$ docker run --rm -it --name=unifi jacobalberty/unifi:latest ls -al /usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java [2021-12-10 20:38:38,984] Executing: ls -al /usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java -rwxr-xr-x 1 root root 6280 Apr 21 2021 /usr/lib/jvm/java-8-openjdk-amd64/jre/bin/java

ubuntu@ubnt:~$ lscpu Architecture: x86_64 CPU op-mode(s): 32-bit, 64-bit Byte Order: Little Endian Address sizes: 46 bits physical, 48 bits virtual CPU(s): 2 On-line CPU(s) list: 0,1 Thread(s) per core: 1 Core(s) per socket: 2 Socket(s): 1 NUMA node(s): 1 Vendor ID: GenuineIntel CPU family: 6 Model: 63 Model name: Intel(R) Xeon(R) CPU E5-2676 v3 @ 2.40GHz Stepping: 2 CPU MHz: 2400.058 BogoMIPS: 4800.17 Hypervisor vendor: Xen Virtualization type: full L1d cache: 64 KiB L1i cache: 64 KiB L2 cache: 512 KiB L3 cache: 30 MiB NUMA node0 CPU(s): 0,1 Vulnerability Itlb multihit: KVM: Mitigation: VMX unsupported Vulnerability L1tf: Mitigation; PTE Inversion Vulnerability Mds: Vulnerable: Clear CPU buffers attempted, no microcode; SMT Host state unknown Vulnerability Meltdown: Mitigation; PTI Vulnerability Spec store bypass: Vulnerable Vulnerability Spectre v1: Mitigation; usercopy/swapgs barriers and __user pointer sanitization Vulnerability Spectre v2: Mitigation; Full generic retpoline, STIBP disabled, RSB filling Vulnerability Srbds: Not affected Vulnerability Tsx async abort: Not affected Flags: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx rdtscp lm constant_tsc rep_good nopl xtopology cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand hypervisor lahf_lm abm cpuid_fault invpcid_single pti fsgsbase bmi1 avx2 smep bmi2 erms invpcid xsaveopt

[brontide]

Same results here, just rolled back to v6.5.53

[jberkman]

Probably not it but just throwing this out there, commit 6ebd41d08166d6dd7c0890451155aa6945dbf2ed added a bunch of quotes, and I noticed the logs have a leading quote before java but not a trailing quote; is it possible it's trying to exec "java? (I'm also seeing this on a Synology NAS)

[brontide]

You might be right, looks like it's attempting to stat the whole string.

[jacobalberty]

Oh yeah, I was in the middle of running shellcheck on the scripts to clean them up and committed those changes early trying to rush the fix for the vulnerability. removed that quote and pushing. Though it's interesting that it broke for you guys and not me.

[jacobalberty]

Gonna need a minute to push the fix to docker hub i need to fix building real quick

[jacobalberty]

building on github now should take about 15 minutes to build

[brontide]

Pulled and same error. I'm going to clone this and see if I can figure out where the issue is.

unifi-controller_1  | [2021-12-10 17:43:43,453] <docker-entrypoint> INFO: Changing 'unifi' UID to '1000' and GID to '1000'
unifi-controller_1  | error: exec: "java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M\n  -Djava.awt.headless=true\n  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start": stat java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M
unifi-controller_1  |   -Djava.awt.headless=true
unifi-controller_1  |   -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory
unifi-controller_1  | [2021-12-10 17:44:05,579] <docker-entrypoint> WARN: unifi service process ended without being signaled? Check for errors in /unifi/log.
unifi-controller_1  | [2021-12-10 17:44:06,113] <docker-entrypoint> Starting unifi controller service.
unifi-controller_1  | error: exec: "java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M\n  -Djava.awt.headless=true\n  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start": stat java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M
unifi-controller_1  |   -Djava.awt.headless=true
unifi-controller_1  |   -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory
unifi-controller_1  | [2021-12-10 17:44:07,125] <docker-entrypoint> WARN: unifi service process ended without being signaled? Check for errors in /unifi/log.

[jacobalberty]

I'm away from the computer for a little bit. When I get back I'm going to revert those two commits that affect docker entry point and then push one with the old entry script and the new version. The quotes are important to add to some of the variables in the long run but they only got pushed now on accident.

On Fri, Dec 10, 2021, 4:47 PM Eric W @.***> wrote:

Pulled and same error. I'm going to clone this and see if I can figure out where the issue is.

unifi-controller_1 | [2021-12-10 17:43:43,453] INFO: Changing 'unifi' UID to '1000' and GID to '1000' unifi-controller_1 | error: exec: "java -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M\n -Djava.awt.headless=true\n -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start": stat java -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M unifi-controller_1 | -Djava.awt.headless=true unifi-controller_1 | -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory unifi-controller_1 | [2021-12-10 17:44:05,579] WARN: unifi service process ended without being signaled? Check for errors in /unifi/log. unifi-controller_1 | [2021-12-10 17:44:06,113] Starting unifi controller service. unifi-controller_1 | error: exec: "java -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M\n -Djava.awt.headless=true\n -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start": stat java -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M unifi-controller_1 | -Djava.awt.headless=true unifi-controller_1 | -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory unifi-controller_1 | [2021-12-10 17:44:07,125] WARN: unifi service process ended without being signaled? Check for errors in /unifi/log.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/jacobalberty/unifi-docker/issues/493#issuecomment-991354536, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPDNASKBBTP4FL3T7KPHQLUQJ7OTANCNFSM5JZ6JXUQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

[brontide]

I did some testing, yes rolling back docker-entrypoint.sh and rebuilt. The image works as expected again.

git checkout 6735a2ac2a3becfbb7cc82c45b7e859624367b40 docker-entrypoint.sh

[jacobalberty]

Well I did say I would rather it break than leave people vulnerable. Just didn't mean that literally.

New version is building on the hub now will update v6.5 v6.5.54 and latest tags with the fixes. That's very strange that it worked for me but not you guys. the only thing I can figure is kernel version. I run on debian bullseye kernel 5.10.70-1 (2021-09-30) what kernel are you guys using with the issue?

[LukeSteward]

Absolute legend - All working fine now.

I am running 5.4.0-91-generic on Ubuntu Server 20.04.

[allenporter]

Same for me 5.4.0-91-generic on Ubuntu 20.04.2 LTS

[jacobalberty]

So I fired up ubuntu 20.04.3 LTS in a vm (kernel 5.4.0-91-generic) to try and reproduce this issue with the updated docker-entrypoint I'm using docker run --rm -it --name unifitest jacobalberty/unifi:sha-6ebd41d0 to execute one of the old broken versions that's still on the hub and it is just workign fine for me. Can someone who was having the issue that is now fixed confirm that the sha-6ebd41d0 tag is still broken for you as well

[brontide]

Looks like the problem exists only in the RUNAS_UID0=false code path

[eric@docker-1 foo]$ docker run --rm -it --name unifitest jacobalberty/unifi:sha-6ebd41d0
Unable to find image 'jacobalberty/unifi:sha-6ebd41d0' locally
sha-6ebd41d0: Pulling from jacobalberty/unifi
Digest: sha256:f4053800718dd98588d95452f4958d14fce7f2e285020235bf77a8cfaa7d6279
Status: Downloaded newer image for jacobalberty/unifi:sha-6ebd41d0
[2021-12-11 23:59:39,766] <docker-entrypoint> Starting unifi controller service.
[2021-12-11 23:59:39,768] <docker-entrypoint> WARNING: Running UniFi in insecure (root) mode
WARN Unable to load properties from '/usr/lib/unifi/data/system.properties' - /usr/lib/unifi/data/system.properties (No such file or directory)
^C[2021-12-12 00:00:10,402] <docker-entrypoint> Exit signal received, shutting down
org.tuckey.web.filters.urlrewrite.UrlRewriteFilter INFO: destroy called
^C
[eric@docker-1 foo]$ docker run --rm -it --name unifitest -e RUNAS_UID0=false -e UNIFI_UID=1000 -e UNIFI_GID=1000 jacobalberty/unifi:sha-6ebd41d0
[2021-12-12 00:01:00,603] <docker-entrypoint> Starting unifi controller service.
[2021-12-12 00:01:01,611] <docker-entrypoint> INFO: Changing 'unifi' UID to '1000' and GID to '1000'
error: exec: "java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M\n  -Djava.awt.headless=true\n  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start": stat java  -Dunifi.datadir=/unifi/data -Dunifi.logdir=/unifi/log -Dunifi.rundir=/var/run/unifi -Xmx1024M
  -Djava.awt.headless=true
  -Dfile.encoding=UTF-8 -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory
[2021-12-12 00:01:23,781] <docker-entrypoint> WARN: unifi service process ended without being signaled? Check for errors in /unifi/log.

[brontide]

I can also get the identical error message by quoting the full java string

[eric@docker-1 foo]$ docker run --rm -it --name unifitest -e RUNAS_UID0=false -e UNIFI_UID=1000 -e UNIFI_GID=1000 jacobalberty/unifi:sha-6ebd41d0 -- gosu 1000:1000 "java -jar /usr/lib/unifi/lib/ace.jar start"
[2021-12-12 00:22:22,130] <docker-entrypoint> Executing: -- gosu 1000:1000 java -jar /usr/lib/unifi/lib/ace.jar start
error: exec: "java -jar /usr/lib/unifi/lib/ace.jar start": stat java -jar /usr/lib/unifi/lib/ace.jar start: no such file or directory

[eric@docker-1 foo]$ docker run --rm -it --name unifitest -e RUNAS_UID0=false -e UNIFI_UID=1000 -e UNIFI_GID=1000 jacobalberty/unifi:sha-6ebd41d0 -- gosu 1000:1000 java -jar /usr/lib/unifi/lib/ace.jar start
[2021-12-12 00:22:53,680] <docker-entrypoint> Executing: -- gosu 1000:1000 java -jar /usr/lib/unifi/lib/ace.jar start
2021-12-12 00:22:54,380 main ERROR Unable to create file logs/server.log java.io.IOException: Permission denied
        at java.io.UnixFileSystem.createFileExclusively(Native Method)
        at java.io.File.createNewFile(File.java:1023)
        at org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory.createManager(RollingFileManager.java:733)
        at org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory.createManager(RollingFileManager.java:716)
        at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:113)
        at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:100)
...

[jacobalberty]

Ok, I can reproduce it now. Thank you. that is still so strange that the exact same docker run command works fine with debian but not ubuntu

[jacobalberty]

oh weird, now it's failing on debian for me too.

[brontide]

I'm on Fedora so it's not the kernel. Are you positive that previous attempts were running docker-entrypoint.sh with RUNAS_UID0=false?

[jacobalberty]

I'm wondering if I didnt somehow pull the wrong version, I copied op's command exactly originally and just added --rm -it --name unifitest and deleted the -d. I do try to always docker pull the image because that's the most common issue. I must have forgotten to or something went wrong with the pull and i didn't notice. I did have a few times the pull did something weird while I was working on this yesterday.

[brontide]

We've all been there. Glad we were able to help you narrow this down. Maybe there is a way to sanity test the github action before pushing to docker hub to confirm that the image starts and has something running on port 8080?

[jacobalberty]

I'll have to look to see if theres a way to use the github actions to check the status of health check. I'm not sure that would have caught this anyway though due to it not being on the default path.

[allenporter]

For what it's worth for future releases: I would also suggest just incrementing to the next version if there is a problem with the existing release rather than trying to update an existing version. I realize it's messy to create another version, but it just helps be more clear. Now my pod is crashing and i need to ask: Did i have the bad version cached? or did i fetch the "new version" and it still has an issue? whereas having it explicit could make this more clear.

I don't want to take away from the fact that I appreciate you hopping to fix this issue quickly, so thank you for your effort here.

[hfreire]

@jacobalberty great work with patching this quickly, much appreciated.