Daemonize on Debian Causes "Internal Server Error"

Good day,

I updated Xojo from 2013r3 to 2014r4 and one of my clients cannot run my apps anymore without crashing when App.Daemonize is called.
To test, I had them run just a plain standalone webapp with just “Call Daemonize” in the App.Open event. When you go to the page in the browser it returns:

Internal Server Error The server encountered an unhandled IOException while executing this request.

No error handlers were called and the app is still online, but unusable.

My own test server (Ubuntu 16.04) works fine.
Other distributions I had them test but not working are:

Linux 4.9.0-6-amd64 #1 SMP Debian 4.9.88-1+deb9u1 (2018-05-07) x86_64 GNU/Linux (Debian 9.4)
Linux 4.9.0-5-amd64 #1 SMP Debian 4.9.65-3+deb9u2 (2018-01-04) x86_64 GNU/Linux (Debian 9.3)
Linux 4.19.1-gentoo #1 SMP Mon Nov 12 16:57:38 +04 2018 x86_64 (Gentoo)

Thanks in advance to anyone who can share some insight before I make a bug report.

[quote=418484:@Alex Bombay]Good day,

I updated Xojo from 2013r3 to 2014r4 and one of my clients cannot run my apps anymore without crashing when App.Daemonize is called.
To test, I had them run just a plain standalone webapp with just “Call Daemonize” in the App.Open event. When you go to the page in the browser it returns:

Internal Server Error The server encountered an unhandled IOException while executing this request.

No error handlers were called and the app is still online, but unusable.

My own test server (Ubuntu 16.04) works fine.
Other distributions I had them test but not working are:

Linux 4.9.0-6-amd64 #1 SMP Debian 4.9.88-1+deb9u1 (2018-05-07) x86_64 GNU/Linux (Debian 9.4)
Linux 4.9.0-5-amd64 #1 SMP Debian 4.9.65-3+deb9u2 (2018-01-04) x86_64 GNU/Linux (Debian 9.3)
Linux 4.19.1-gentoo #1 SMP Mon Nov 12 16:57:38 +04 2018 x86_64 (Gentoo)

Thanks in advance to anyone who can share some insight before I make a bug report.[/quote]

From the docs:

https://documentation.xojo.com/api/language/consoleapplication.html#consoleapplication-daemonize

@Derk Jochems, he said that it’s standalone. The daemonize docs don’t apply.

@Alex Bombay -
Put some code in Session.UnhandledException to write the stack to a file. I suspect that your app is unable to read a file for some reason, but the stack will tell you where to look.

Also, keep in mind that a daemonized app may have different permissions on a server than that of the user that launched it. It could simply be that a file is restricted to a particular user and the app isn’t running as that user or group.

It does not seem to trigger either App.UnhandledException or Session.UnhandledException. I put a button on the webpage with MsgBox() in the Action event and got this on page open:

Could not execute returned javascript: button is not defined Source: var langdir = document.getElementsByTagName('body')[0]; if(langdir) { langdir.removeAttribute('dir'); } var langdir = document.getElementsByTagName('body')[0]; if(langdir) { langdir.setAttribute('lang','en'); } new button('itnHPCkU',['Action']); Xojo.controls['itnHPCkU'].setEnabled(true); Xojo.controls.itnHPCkU.setAutoDisable(false); new frameworkObject('x3X0NbbN',['Close','Open','Shown']); Xojo.controls['x3X0NbbN'].setEnabled(true); Xojo.view.showPage('x3X0NbbN'); document.title = "Untitled"; Xojo.view.dismissLoader();

Update: Has nothing to do with Debian. Starting the process with “./MyApp” will change the CWD to root after Daemonization, however, starting the app with “/Path/To/MyApp” works correctly. There must have been some change between 2013r3 and 2014r4 that affected the way apps daemonize. Grateful if we could get this fixed, working on a bug report.

Thanks!

Basiclly everything below is just extra information at this point.

Here is an strace of the process right after it the Daemonize call:

+++ exited with 0 +++ strace: Process 18122 attached open("/dev/null", O_RDWR) = 4 <0.000018> open("/proc/self/maps", O_RDONLY|O_CLOEXEC) = -1 EMFILE (Too many open files) <0.000006> write(2, "Runtime Error\ Please report what caused this error along with the information below.\ Universal/CrawlStack.cpp: 64\ Failure Condition: rc == 0\ pthread_getattr_np: 24\ ", 164) = 164 <0.000006> --- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=18122, si_uid=1000} --- +++ killed by SIGABRT +++

I increased the amount of max open files and I got this:

pipe([4, 5]) = 0 <0.000010> vfork(strace: Process 22829 attached <unfinished ...> [pid 22829] close(4) = 0 <0.000005> [pid 22829] dup2(5, 1) = 1 <0.000004> [pid 22829] dup2(1, 2) = 2 <0.000006> [pid 22829] close(5) = 0 <0.000005> [pid 22829] getrlimit(RLIMIT_NOFILE, {rlim_cur=40000, rlim_max=100000}) = 0 <0.000005> [pid 22829] close(3) = 0 <0.000005> [pid 22829] close(4) = -1 EBADF (Bad file descriptor) <0.000005> [pid 22829] close(5) = -1 EBADF (Bad file descriptor) <0.000004> ... (continues) [pid 22829] close(39997) = -1 EBADF (Bad file descriptor) <0.000005> [pid 22829] close(39998) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(39999) = -1 EBADF (Bad file descriptor) <0.000004> ... (some other stuff) ... [pid 22829] mprotect(0x56127c785000, 4096, PROT_READ) = 0 <0.000008> [pid 22829] mprotect(0x7f6575666000, 4096, PROT_READ) = 0 <0.000017> [pid 22829] munmap(0x7f657565b000, 28824) = 0 <0.000015> [pid 22829] getrlimit(RLIMIT_NOFILE, {rlim_cur=40000, rlim_max=100000}) = 0 <0.000005> [pid 22829] close(39999) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(39998) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(39997) = -1 EBADF (Bad file descriptor) <0.000004> ... (continues) [pid 22829] close(5) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(4) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(3) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] brk(NULL) = 0x56127e5bf000 <0.000005> [pid 22829] brk(0x56127e5e0000) = 0x56127e5e0000 <0.000007> [pid 22829] getuid() = 1000 <0.000004> [pid 22829] getgid() = 1000 <0.000004> [pid 22829] geteuid() = 1000 <0.000004> [pid 22829] getegid() = 1000 <0.000005> ... (some more stuff) ! (App.Daemonize) ! clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fe37f688990) = 22830 <0.000177> exit_group(0) = ? +++ exited with 0 +++ strace: Process 22830 attached set_robust_list(0x7fe37f6889a0, 24) = 0 <0.000005> setsid() = 22830 <0.000009> chdir("/") = 0 <0.000007> open("/dev/null", O_RDWR) = 4 <0.000009>

After all this there are a bunch of lstat “ENOENT (No such file or directory)” errors and rt_sigprocmask calls

rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0 <0.000006> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000005> rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0 <0.000005> rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], ~[KILL STOP RTMIN RT_1], 8) = 0 <0.000004> rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0 <0.000005>

[code]% time seconds usecs/call calls errors syscall


37.28 0.000334 0 161773 rt_sigprocmask
19.75 0.000177 0 67952 40457 lstat
12.50 0.000112 0 80076 79996 close[/code]

I am not quite sure what is going on with calling close on 40k files twice, but this bit right here “chdir(”/")" gives me the feeling that Xojo is attempting to change to the root directory when calling daemonize on debian systems. By symlinking the app in root “/” it woks without any problem.

Thanks for everyones help, hopefully we can get this resolved in one way or another.

feedback://showreport?report_id=54491

[quote=418663:@Alex Bombay]Update: Has nothing to do with Debian. Starting the process with “./MyApp” will change the CWD to root after Daemonization, however, starting the app with “/Path/To/MyApp” works correctly. There must have been some change between 2013r3 and 2014r4 that affected the way apps daemonize. Grateful if we could get this fixed, working on a bug report.

Thanks!

Basiclly everything below is just extra information at this point.

Here is an strace of the process right after it the Daemonize call:

+++ exited with 0 +++ strace: Process 18122 attached open("/dev/null", O_RDWR) = 4 <0.000018> open("/proc/self/maps", O_RDONLY|O_CLOEXEC) = -1 EMFILE (Too many open files) <0.000006> write(2, "Runtime Error\ Please report what caused this error along with the information below.\ Universal/CrawlStack.cpp: 64\ Failure Condition: rc == 0\ pthread_getattr_np: 24\ ", 164) = 164 <0.000006> --- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=18122, si_uid=1000} --- +++ killed by SIGABRT +++

I increased the amount of max open files and I got this:

pipe([4, 5]) = 0 <0.000010> vfork(strace: Process 22829 attached <unfinished ...> [pid 22829] close(4) = 0 <0.000005> [pid 22829] dup2(5, 1) = 1 <0.000004> [pid 22829] dup2(1, 2) = 2 <0.000006> [pid 22829] close(5) = 0 <0.000005> [pid 22829] getrlimit(RLIMIT_NOFILE, {rlim_cur=40000, rlim_max=100000}) = 0 <0.000005> [pid 22829] close(3) = 0 <0.000005> [pid 22829] close(4) = -1 EBADF (Bad file descriptor) <0.000005> [pid 22829] close(5) = -1 EBADF (Bad file descriptor) <0.000004> ... (continues) [pid 22829] close(39997) = -1 EBADF (Bad file descriptor) <0.000005> [pid 22829] close(39998) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(39999) = -1 EBADF (Bad file descriptor) <0.000004> ... (some other stuff) ... [pid 22829] mprotect(0x56127c785000, 4096, PROT_READ) = 0 <0.000008> [pid 22829] mprotect(0x7f6575666000, 4096, PROT_READ) = 0 <0.000017> [pid 22829] munmap(0x7f657565b000, 28824) = 0 <0.000015> [pid 22829] getrlimit(RLIMIT_NOFILE, {rlim_cur=40000, rlim_max=100000}) = 0 <0.000005> [pid 22829] close(39999) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(39998) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(39997) = -1 EBADF (Bad file descriptor) <0.000004> ... (continues) [pid 22829] close(5) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(4) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] close(3) = -1 EBADF (Bad file descriptor) <0.000004> [pid 22829] brk(NULL) = 0x56127e5bf000 <0.000005> [pid 22829] brk(0x56127e5e0000) = 0x56127e5e0000 <0.000007> [pid 22829] getuid() = 1000 <0.000004> [pid 22829] getgid() = 1000 <0.000004> [pid 22829] geteuid() = 1000 <0.000004> [pid 22829] getegid() = 1000 <0.000005> ... (some more stuff) ! (App.Daemonize) ! clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fe37f688990) = 22830 <0.000177> exit_group(0) = ? +++ exited with 0 +++ strace: Process 22830 attached set_robust_list(0x7fe37f6889a0, 24) = 0 <0.000005> setsid() = 22830 <0.000009> chdir("/") = 0 <0.000007> open("/dev/null", O_RDWR) = 4 <0.000009>

After all this there are a bunch of lstat “ENOENT (No such file or directory)” errors and rt_sigprocmask calls

rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0 <0.000006> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000005> rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0 <0.000005> rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], ~[KILL STOP RTMIN RT_1], 8) = 0 <0.000004> rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0 <0.000005>

[code]% time seconds usecs/call calls errors syscall


37.28 0.000334 0 161773 rt_sigprocmask
19.75 0.000177 0 67952 40457 lstat
12.50 0.000112 0 80076 79996 close[/code]

I am not quite sure what is going on with calling close on 40k files twice, but this bit right here “chdir(”/")" gives me the feeling that Xojo is attempting to change to the root directory when calling daemonize on debian systems. By symlinking the app in root “/” it woks without any problem.

Thanks for everyones help, hopefully we can get this resolved in one way or another.[/quote]
You didn’t happen to try this with a newer Xojo version did you? It’s possible that this was already fixed (assuming it’s a bug).

Woops, working in the wrong year here, I meant 2017r3 to 2018r4, my bad.