python-daemon

#19 uknown memory mapping delay when starting daemon process on raspberry pi
Closed: Insufficient data by bignose. Opened by victorclaessen.

Closed: Insufficient data
Reopen Issue

Thank you for releasing a new version. I've installed 2.2.0 on my raspberry pi. The behaviour is now different. There is now no more delay in closing file descriptors, which is great. However, now there seems to be a new delay that I didn't notice before. It takes about 20 seconds or so, and I believe that it occurs earlier in the code - i.e. before the location of close_all_open_files() - and has something to do with memory mapping?

The part of the strace output I believe is relevant:

clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb6f26068) = 28906
exit_group(0) = ?
strace: Process 28906 attached
[pid 28906] set_robust_list(0xb6f26070, 12) = 0
[pid 28906] getpid(
[pid 28902] +++ exited with 0 +++
<... getpid resumed> ) = 28906
setsid() = 28906
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb6f26068) = 28907
exit_group(0) = ?
+++ exited with 0 +++
strace: Process 28907 attached
set_robust_list(0xb6f26070, 12) = 0
getpid() = 28907
rt_sigaction(SIGHUP, {sa_handler=0x11dc94, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0xb6ce56b0}, {sa_handler=0x11dc94, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0xb6ce56b0}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=0x11dc94, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0xb6ce56b0}, {sa_handler=0x11dc94, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0xb6ce56b0}, 8) = 0
rt_sigaction(SIGUSR2, {sa_handler=0x11dc94, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0xb6ce56b0}, {sa_handler=0x11dc94, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0xb6ce56b0}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=0x11dc94, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0xb6ce56b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
mremap(0xb5d11000, 4198400, 4722688, MREMAP_MAYMOVE) = 0xb5d11000
brk(0x19a9000) = 0x19a9000
mmap2(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb649d000
brk(0x1993000) = 0x1993000
mmap2(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb639c000
munmap(0xb649d000, 266240) = 0
mmap2(NULL, 2101248, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb619b000
munmap(0xb639c000, 1052672) = 0
mmap2(NULL, 4198400, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb5910000
munmap(0xb619b000, 2101248) = 0
mmap2(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb510f000
munmap(0xb5910000, 4198400) = 0
mmap2(NULL, 16781312, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb410e000
munmap(0xb510f000, 8392704) = 0
prlimit64(0, RLIMIT_NOFILE, NULL, {rlim_cur=1024, rlim_max=1024*1024}) = 0
mmap2(NULL, 4198400, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb5910000
brk(0x19b4000) = 0x19b4000
brk(0x19d5000) = 0x19d5000
brk(0x19f6000) = 0x19f6000
brk(0x1a17000) = 0x1a17000
brk(0x1a38000) = 0x1a38000
brk(0x1a59000) = 0x1a59000
brk(0x1a7a000) = 0x1a7a000
brk(0x1a9b000) = 0x1a9b000
brk(0x1abc000) = 0x1abc000
brk(0x1add000) = 0x1add000

It seems to stall on those munmap calls near the end (before all the brk's).
I'm running Python 2.7.13 by the way.

On 17-Aug-2018, Victor Claessen wrote:

However, now there seems to be a new delay that I didn't notice
before. It takes about 20 seconds or so, and I believe that it
occurs earlier in the code - i.e. before the location of
close_all_open_files() - and has something to do with memory
mapping?

Thank you for investigating that far. As you might imagine, that
doesn't point clearly to where the delay might be.

Are you able to use a performance profiling tool, to better understand
exactly what Python code is slowing your program?

--=20
\ =E2=80=9CLet others praise ancient times; I am glad I was born=
in |
`\ these.=E2=80=9D =E2=80=94Ovid (43=
BCE=E2=80=9318 CE) |
_o__) |
Ben Finney ben@benfinney.id.au

I tried importing cProfile, and then using cProfile.run() on my daemon (i.e. cProfile.run("mydaemon.run()") . Unfortunately that gives no output...and it also won't output profiling information to a file. Any suggestions?

Unfortunately that gives no output...

As you've probably guessed, there is no output because the daemon process is detached from the controlling terminal.

and it also won't output profiling information to a file. Any suggestions?

The profile library documentation says:

Instead of printing the output at the end of the profile run, you can save the results to a file by specifying a filename to the run() function […]

Metadata Update from @bignose:
- Issue tagged with: moreinfo

Thanks for the report. I am closing this in the absence of the information needed to proceed.

Please feel free to open a new issue with the diagnostic information described above.

Metadata Update from @bignose:
- Issue close_status updated to: Insufficient data
- Issue status updated to: Closed (was: Open)
Metadata
None

more-info

None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.