[PATCH] systemd: Fix the problem of an empty journal on boot

[PATCH] systemd: Fix the problem of an empty journal on boot

[Randy Witt]

systemd by default tries to write the journal to /var/log/journal.
But base-files has a symlink /var/log -> /var/volatile/log. And
/var/volatile is a tmpfs mount in /etc/fstab.

If the journal service started before /var/volatile was mounted (which
was the typical scenario) then the journal would appear empty since
the old location was mounted over.

This change fixes the problem by ensuring that the journal doesn't start
until after the mount happens.

[Yocto #7388]

Signed-off-by: Randy Witt <randy.e.witt@linux.intel.com>
---
 meta/recipes-core/systemd/systemd/journald-volatile.conf | 6 ++++++
 meta/recipes-core/systemd/systemd_219.bb                 | 2 ++
 2 files changed, 8 insertions(+)
 create mode 100644 meta/recipes-core/systemd/systemd/journald-volatile.conf

diff --git a/meta/recipes-core/systemd/systemd/journald-volatile.conf b/meta/recipes-core/systemd/systemd/journald-volatile.conf
new file mode 100644
index 0000000..b11e160
--- /dev/null
+++ b/meta/recipes-core/systemd/systemd/journald-volatile.conf
@@ -0,0 +1,6 @@
+# If /var/volatile is a mount point then make sure to mount it before
+# the journal starts. This is because base-files creates a symlink
+# /var/log -> /var/volatile/log. And if the journal starts before the mount
+# happens, the journal will appear empty until restarted.
+[Unit]
+After=var-volatile.mount
diff --git a/meta/recipes-core/systemd/systemd_219.bb b/meta/recipes-core/systemd/systemd_219.bb
index 3c4b6cf..2be66af 100644
--- a/meta/recipes-core/systemd/systemd_219.bb
+++ b/meta/recipes-core/systemd/systemd_219.bb
@@ -48,6 +48,7 @@ SRC_URI = "git://anongit.freedesktop.org/systemd/systemd;branch=master;protocol=
            file://00-create-volatile.conf \
            file://init \
            file://run-ptest \
+           file://journald-volatile.conf \
           "
 
 S = "${WORKDIR}/git"
@@ -143,6 +144,7 @@ do_install() {
 	install -m 0644 ${WORKDIR}/*.rules ${D}${sysconfdir}/udev/rules.d/
 
 	install -m 0644 ${WORKDIR}/00-create-volatile.conf ${D}${sysconfdir}/tmpfiles.d/
+	install -D -m 0644 ${WORKDIR}/journald-volatile.conf ${D}${systemd_unitdir}/system/systemd-journald.service.d/journald-volatile.conf
 
 	if ${@bb.utils.contains('DISTRO_FEATURES','sysvinit','true','false',d)}; then
 		install -d ${D}${sysconfdir}/init.d
-- 
1.9.3

Re: [PATCH] systemd: Fix the problem of an empty journal on boot

[Khem Raj]

[-- Attachment #1: Type: text/plain, Size: 2878 bytes --]

On Mar 5, 2015 6:13 PM, "Randy Witt" <randy.e.witt@linux.intel.com> wrote:
>
> systemd by default tries to write the journal to /var/log/journal.
> But base-files has a symlink /var/log -> /var/volatile/log. And
> /var/volatile is a tmpfs mount in /etc/fstab.
>
> If the journal service started before /var/volatile was mounted (which
> was the typical scenario) then the journal would appear empty since
> the old location was mounted over.
>
> This change fixes the problem by ensuring that the journal doesn't start
> until after the mount happens.
>

What happens if folks have a different fstab then default? Will it still
work

> [Yocto #7388]
>
> Signed-off-by: Randy Witt <randy.e.witt@linux.intel.com>
> ---
>  meta/recipes-core/systemd/systemd/journald-volatile.conf | 6 ++++++
>  meta/recipes-core/systemd/systemd_219.bb                 | 2 ++
>  2 files changed, 8 insertions(+)
>  create mode 100644
meta/recipes-core/systemd/systemd/journald-volatile.conf
>
> diff --git a/meta/recipes-core/systemd/systemd/journald-volatile.conf
b/meta/recipes-core/systemd/systemd/journald-volatile.conf
> new file mode 100644
> index 0000000..b11e160
> --- /dev/null
> +++ b/meta/recipes-core/systemd/systemd/journald-volatile.conf
> @@ -0,0 +1,6 @@
> +# If /var/volatile is a mount point then make sure to mount it before
> +# the journal starts. This is because base-files creates a symlink
> +# /var/log -> /var/volatile/log. And if the journal starts before the
mount
> +# happens, the journal will appear empty until restarted.
> +[Unit]
> +After=var-volatile.mount
> diff --git a/meta/recipes-core/systemd/systemd_219.bb
b/meta/recipes-core/systemd/systemd_219.bb
> index 3c4b6cf..2be66af 100644
> --- a/meta/recipes-core/systemd/systemd_219.bb
> +++ b/meta/recipes-core/systemd/systemd_219.bb
> @@ -48,6 +48,7 @@ SRC_URI = "git://
anongit.freedesktop.org/systemd/systemd;branch=master;protocol=
>             file://00-create-volatile.conf \
>             file://init \
>             file://run-ptest \
> +           file://journald-volatile.conf \
>            "
>
>  S = "${WORKDIR}/git"
> @@ -143,6 +144,7 @@ do_install() {
>         install -m 0644 ${WORKDIR}/*.rules ${D}${sysconfdir}/udev/rules.d/
>
>         install -m 0644 ${WORKDIR}/00-create-volatile.conf
${D}${sysconfdir}/tmpfiles.d/
> +       install -D -m 0644 ${WORKDIR}/journald-volatile.conf
${D}${systemd_unitdir}/system/systemd-journald.service.d/journald-volatile.conf
>
>         if
${@bb.utils.contains('DISTRO_FEATURES','sysvinit','true','false',d)}; then
>                 install -d ${D}${sysconfdir}/init.d
> --
> 1.9.3
>
> --
> _______________________________________________
> Openembedded-core mailing list
> Openembedded-core@lists.openembedded.org
> http://lists.openembedded.org/mailman/listinfo/openembedded-core

[-- Attachment #2: Type: text/html, Size: 4011 bytes --]

Re: [PATCH] systemd: Fix the problem of an empty journal on boot

[randy.e.witt]

> On Mar 5, 2015 6:13 PM, "Randy Witt" <randy.e.witt@linux.intel.com> wrote:
>>
>> systemd by default tries to write the journal to /var/log/journal.
>> But base-files has a symlink /var/log -> /var/volatile/log. And
>> /var/volatile is a tmpfs mount in /etc/fstab.
>>
>> If the journal service started before /var/volatile was mounted (which
>> was the typical scenario) then the journal would appear empty since
>> the old location was mounted over.
>>
>> This change fixes the problem by ensuring that the journal doesn't start
>> until after the mount happens.
>>
>
> What happens if folks have a different fstab then default? Will it still
> work

Yes, the "After" only changes behavior if something else has caused
var-volatile.mount to be in the set of services to be started.

I verified that was the case by removing /var/volatile from /etc/fstab and
the journal still starts with no errors.

>> [Yocto #7388]
>>
>> Signed-off-by: Randy Witt <randy.e.witt@linux.intel.com>
>> ---
>>  meta/recipes-core/systemd/systemd/journald-volatile.conf | 6 ++++++
>>  meta/recipes-core/systemd/systemd_219.bb                 | 2 ++
>>  2 files changed, 8 insertions(+)
>>  create mode 100644
> meta/recipes-core/systemd/systemd/journald-volatile.conf
>>
>> diff --git a/meta/recipes-core/systemd/systemd/journald-volatile.conf
> b/meta/recipes-core/systemd/systemd/journald-volatile.conf
>> new file mode 100644
>> index 0000000..b11e160
>> --- /dev/null
>> +++ b/meta/recipes-core/systemd/systemd/journald-volatile.conf
>> @@ -0,0 +1,6 @@
>> +# If /var/volatile is a mount point then make sure to mount it before
>> +# the journal starts. This is because base-files creates a symlink
>> +# /var/log -> /var/volatile/log. And if the journal starts before the
> mount
>> +# happens, the journal will appear empty until restarted.
>> +[Unit]
>> +After=var-volatile.mount
>> diff --git a/meta/recipes-core/systemd/systemd_219.bb
> b/meta/recipes-core/systemd/systemd_219.bb
>> index 3c4b6cf..2be66af 100644
>> --- a/meta/recipes-core/systemd/systemd_219.bb
>> +++ b/meta/recipes-core/systemd/systemd_219.bb
>> @@ -48,6 +48,7 @@ SRC_URI = "git://
> anongit.freedesktop.org/systemd/systemd;branch=master;protocol=
>>             file://00-create-volatile.conf \
>>             file://init \
>>             file://run-ptest \
>> +           file://journald-volatile.conf \
>>            "
>>
>>  S = "${WORKDIR}/git"
>> @@ -143,6 +144,7 @@ do_install() {
>>         install -m 0644 ${WORKDIR}/*.rules
>> ${D}${sysconfdir}/udev/rules.d/
>>
>>         install -m 0644 ${WORKDIR}/00-create-volatile.conf
> ${D}${sysconfdir}/tmpfiles.d/
>> +       install -D -m 0644 ${WORKDIR}/journald-volatile.conf
> ${D}${systemd_unitdir}/system/systemd-journald.service.d/journald-volatile.conf
>>
>>         if
> ${@bb.utils.contains('DISTRO_FEATURES','sysvinit','true','false',d)}; then
>>                 install -d ${D}${sysconfdir}/init.d
>> --
>> 1.9.3
>>
>> --
>> _______________________________________________
>> Openembedded-core mailing list
>> Openembedded-core@lists.openembedded.org
>> http://lists.openembedded.org/mailman/listinfo/openembedded-core
>

Re: [PATCH] systemd: Fix the problem of an empty journal on boot

[Khem Raj]

> On Mar 5, 2015, at 10:01 PM, randy.e.witt@linux.intel.com wrote:
> 
>> On Mar 5, 2015 6:13 PM, "Randy Witt" <randy.e.witt@linux.intel.com> wrote:
>>> 
>>> systemd by default tries to write the journal to /var/log/journal.
>>> But base-files has a symlink /var/log -> /var/volatile/log. And
>>> /var/volatile is a tmpfs mount in /etc/fstab.
>>> 
>>> If the journal service started before /var/volatile was mounted (which
>>> was the typical scenario) then the journal would appear empty since
>>> the old location was mounted over.
>>> 
>>> This change fixes the problem by ensuring that the journal doesn't start
>>> until after the mount happens.
>>> 
>> 
>> What happens if folks have a different fstab then default? Will it still
>> work
> 
> Yes, the "After" only changes behavior if something else has caused
> var-volatile.mount to be in the set of services to be started.
> 
> I verified that was the case by removing /var/volatile from /etc/fstab and
> the journal still starts with no errors.

perfect thanks. I will test it out in few hrs myself.

> 
>>> [Yocto #7388]
>>> 
>>> Signed-off-by: Randy Witt <randy.e.witt@linux.intel.com>
>>> ---
>>> meta/recipes-core/systemd/systemd/journald-volatile.conf | 6 ++++++
>>> meta/recipes-core/systemd/systemd_219.bb                 | 2 ++
>>> 2 files changed, 8 insertions(+)
>>> create mode 100644
>> meta/recipes-core/systemd/systemd/journald-volatile.conf
>>> 
>>> diff --git a/meta/recipes-core/systemd/systemd/journald-volatile.conf
>> b/meta/recipes-core/systemd/systemd/journald-volatile.conf
>>> new file mode 100644
>>> index 0000000..b11e160
>>> --- /dev/null
>>> +++ b/meta/recipes-core/systemd/systemd/journald-volatile.conf
>>> @@ -0,0 +1,6 @@
>>> +# If /var/volatile is a mount point then make sure to mount it before
>>> +# the journal starts. This is because base-files creates a symlink
>>> +# /var/log -> /var/volatile/log. And if the journal starts before the
>> mount
>>> +# happens, the journal will appear empty until restarted.
>>> +[Unit]
>>> +After=var-volatile.mount
>>> diff --git a/meta/recipes-core/systemd/systemd_219.bb
>> b/meta/recipes-core/systemd/systemd_219.bb
>>> index 3c4b6cf..2be66af 100644
>>> --- a/meta/recipes-core/systemd/systemd_219.bb
>>> +++ b/meta/recipes-core/systemd/systemd_219.bb
>>> @@ -48,6 +48,7 @@ SRC_URI = "git://
>> anongit.freedesktop.org/systemd/systemd;branch=master;protocol=
>>>            file://00-create-volatile.conf \
>>>            file://init \
>>>            file://run-ptest \
>>> +           file://journald-volatile.conf \
>>>           "
>>> 
>>> S = "${WORKDIR}/git"
>>> @@ -143,6 +144,7 @@ do_install() {
>>>        install -m 0644 ${WORKDIR}/*.rules
>>> ${D}${sysconfdir}/udev/rules.d/
>>> 
>>>        install -m 0644 ${WORKDIR}/00-create-volatile.conf
>> ${D}${sysconfdir}/tmpfiles.d/
>>> +       install -D -m 0644 ${WORKDIR}/journald-volatile.conf
>> ${D}${systemd_unitdir}/system/systemd-journald.service.d/journald-volatile.conf
>>> 
>>>        if
>> ${@bb.utils.contains('DISTRO_FEATURES','sysvinit','true','false',d)}; then
>>>                install -d ${D}${sysconfdir}/init.d
>>> --
>>> 1.9.3
>>> 
>>> --
>>> _______________________________________________
>>> Openembedded-core mailing list
>>> Openembedded-core@lists.openembedded.org
>>> http://lists.openembedded.org/mailman/listinfo/openembedded-core

Re: [PATCH] systemd: Fix the problem of an empty journal on boot

[Khem Raj]

On Fri, Mar 6, 2015 at 1:18 AM, Khem Raj <raj.khem@gmail.com> wrote:
>
>> On Mar 5, 2015, at 10:01 PM, randy.e.witt@linux.intel.com wrote:
>>
>>> On Mar 5, 2015 6:13 PM, "Randy Witt" <randy.e.witt@linux.intel.com> wrote:
>>>>
>>>> systemd by default tries to write the journal to /var/log/journal.
>>>> But base-files has a symlink /var/log -> /var/volatile/log. And
>>>> /var/volatile is a tmpfs mount in /etc/fstab.
>>>>
>>>> If the journal service started before /var/volatile was mounted (which
>>>> was the typical scenario) then the journal would appear empty since
>>>> the old location was mounted over.
>>>>
>>>> This change fixes the problem by ensuring that the journal doesn't start
>>>> until after the mount happens.
>>>>
>>>
>>> What happens if folks have a different fstab then default? Will it still
>>> work
>>
>> Yes, the "After" only changes behavior if something else has caused
>> var-volatile.mount to be in the set of services to be started.
>>
>> I verified that was the case by removing /var/volatile from /etc/fstab and
>> the journal still starts with no errors.
>
> perfect thanks. I will test it out in few hrs myself.

for some reason, my console never comes up now. I am not sure if this
is the patch causing it. I will try to single it out.

>
>>
>>>> [Yocto #7388]
>>>>
>>>> Signed-off-by: Randy Witt <randy.e.witt@linux.intel.com>
>>>> ---
>>>> meta/recipes-core/systemd/systemd/journald-volatile.conf | 6 ++++++
>>>> meta/recipes-core/systemd/systemd_219.bb                 | 2 ++
>>>> 2 files changed, 8 insertions(+)
>>>> create mode 100644
>>> meta/recipes-core/systemd/systemd/journald-volatile.conf
>>>>
>>>> diff --git a/meta/recipes-core/systemd/systemd/journald-volatile.conf
>>> b/meta/recipes-core/systemd/systemd/journald-volatile.conf
>>>> new file mode 100644
>>>> index 0000000..b11e160
>>>> --- /dev/null
>>>> +++ b/meta/recipes-core/systemd/systemd/journald-volatile.conf
>>>> @@ -0,0 +1,6 @@
>>>> +# If /var/volatile is a mount point then make sure to mount it before
>>>> +# the journal starts. This is because base-files creates a symlink
>>>> +# /var/log -> /var/volatile/log. And if the journal starts before the
>>> mount
>>>> +# happens, the journal will appear empty until restarted.
>>>> +[Unit]
>>>> +After=var-volatile.mount
>>>> diff --git a/meta/recipes-core/systemd/systemd_219.bb
>>> b/meta/recipes-core/systemd/systemd_219.bb
>>>> index 3c4b6cf..2be66af 100644
>>>> --- a/meta/recipes-core/systemd/systemd_219.bb
>>>> +++ b/meta/recipes-core/systemd/systemd_219.bb
>>>> @@ -48,6 +48,7 @@ SRC_URI = "git://
>>> anongit.freedesktop.org/systemd/systemd;branch=master;protocol=
>>>>            file://00-create-volatile.conf \
>>>>            file://init \
>>>>            file://run-ptest \
>>>> +           file://journald-volatile.conf \
>>>>           "
>>>>
>>>> S = "${WORKDIR}/git"
>>>> @@ -143,6 +144,7 @@ do_install() {
>>>>        install -m 0644 ${WORKDIR}/*.rules
>>>> ${D}${sysconfdir}/udev/rules.d/
>>>>
>>>>        install -m 0644 ${WORKDIR}/00-create-volatile.conf
>>> ${D}${sysconfdir}/tmpfiles.d/
>>>> +       install -D -m 0644 ${WORKDIR}/journald-volatile.conf
>>> ${D}${systemd_unitdir}/system/systemd-journald.service.d/journald-volatile.conf
>>>>
>>>>        if
>>> ${@bb.utils.contains('DISTRO_FEATURES','sysvinit','true','false',d)}; then
>>>>                install -d ${D}${sysconfdir}/init.d
>>>> --
>>>> 1.9.3
>>>>
>>>> --
>>>> _______________________________________________
>>>> Openembedded-core mailing list
>>>> Openembedded-core@lists.openembedded.org
>>>> http://lists.openembedded.org/mailman/listinfo/openembedded-core
>

Re: [PATCH] systemd: Fix the problem of an empty journal on boot

[Khem Raj]

> On Mar 7, 2015, at 11:37 AM, Khem Raj <raj.khem@gmail.com> wrote:
> 
> On Fri, Mar 6, 2015 at 1:18 AM, Khem Raj <raj.khem@gmail.com> wrote:
>> 
>>> On Mar 5, 2015, at 10:01 PM, randy.e.witt@linux.intel.com wrote:
>>> 
>>>> On Mar 5, 2015 6:13 PM, "Randy Witt" <randy.e.witt@linux.intel.com> wrote:
>>>>> 
>>>>> systemd by default tries to write the journal to /var/log/journal.
>>>>> But base-files has a symlink /var/log -> /var/volatile/log. And
>>>>> /var/volatile is a tmpfs mount in /etc/fstab.
>>>>> 
>>>>> If the journal service started before /var/volatile was mounted (which
>>>>> was the typical scenario) then the journal would appear empty since
>>>>> the old location was mounted over.
>>>>> 
>>>>> This change fixes the problem by ensuring that the journal doesn't start
>>>>> until after the mount happens.
>>>>> 
>>>> 
>>>> What happens if folks have a different fstab then default? Will it still
>>>> work
>>> 
>>> Yes, the "After" only changes behavior if something else has caused
>>> var-volatile.mount to be in the set of services to be started.
>>> 
>>> I verified that was the case by removing /var/volatile from /etc/fstab and
>>> the journal still starts with no errors.
>> 
>> perfect thanks. I will test it out in few hrs myself.
> 
> for some reason, my console never comes up now. I am not sure if this
> is the patch causing it. I will try to single it out.

This patch should not be applied, but I see it has been applied anyway meanwhile, So we might have to solve this issue differently. 

This is actually the cause of my console not coming up. It was coming up after 15 minutes
systemd-analyse blame said systemd-tmpfiles-setup-dev.service is taking 14 mins to come up.
I then traced through it and the problem is evident that its trying to write journal when creating /dev entries but we have delayed the journald starting point and caused a use-before-define situation.
I deleted /var/volatile symlinks and let /var/log be proper directory and same for /var/tmp. All worked fine, without this patch. We should probably stop doing /var/volatile thing anyway its not in FHS standard either, for ro-rfs do something else ( may be copy-binds into /tmp/) and for general case just leave it alone. 

00:04:23 read(4, "#  This file is part of systemd."..., 4096) = 1244
00:04:23 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/user\" does not match"..., 62}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:04:33 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/user\" does not match"..., 62}, {"\n", 1}], 5) = 90
00:04:33 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/utmp\" does not match"..., 62}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:04:43 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/utmp\" does not match"..., 62}, {"\n", 1}], 5) = 90
00:04:43 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/ask-password"..., 78}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Resou
rce temporarily unavailable)
00:04:53 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/ask-password"..., 78}, {"\n", 1}], 5) = 106
00:04:53 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/seats\" does "..., 71}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:05:03 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/seats\" does "..., 71}, {"\n", 1}], 5) = 99
00:05:03 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/sessions\" do"..., 74}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:05:13 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/sessions\" do"..., 74}, {"\n", 1}], 5) = 102
00:05:13 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/users\" does "..., 71}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:05:23 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/users\" does "..., 71}, {"\n", 1}], 5) = 99
00:05:23 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/machines\" do"..., 74}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:05:33 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/machines\" do"..., 74}, {"\n", 1}], 5) = 102
00:05:33 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/shutdown\" do"..., 74}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:05:43 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/shutdown\" do"..., 74}, {"\n", 1}], 5) = 102
00:05:43 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/log\" does not match "..., 61}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:05:53 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/log\" does not match "..., 61}, {"\n", 1}], 5) = 89
00:05:53 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/log/journal\" does no"..., 69}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
urce temporarily unavailable)
00:06:03 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/log/journal\" does no"..., 69}, {"\n", 1}], 5) = 97
00:06:03 open("/etc/machine-id", O_RDONLY|O_NOCTTY|O_LARGEFILE|O_CLOEXEC) = 6

Re: [PATCH] systemd: Fix the problem of an empty journal on boot

[Khem Raj]

> On Mar 10, 2015, at 9:48 PM, Khem Raj <raj.khem@gmail.com> wrote:
> 
>> 
>> On Mar 7, 2015, at 11:37 AM, Khem Raj <raj.khem@gmail.com> wrote:
>> 
>> On Fri, Mar 6, 2015 at 1:18 AM, Khem Raj <raj.khem@gmail.com> wrote:
>>> 
>>>> On Mar 5, 2015, at 10:01 PM, randy.e.witt@linux.intel.com wrote:
>>>> 
>>>>> On Mar 5, 2015 6:13 PM, "Randy Witt" <randy.e.witt@linux.intel.com> wrote:
>>>>>> 
>>>>>> systemd by default tries to write the journal to /var/log/journal.
>>>>>> But base-files has a symlink /var/log -> /var/volatile/log. And
>>>>>> /var/volatile is a tmpfs mount in /etc/fstab.
>>>>>> 
>>>>>> If the journal service started before /var/volatile was mounted (which
>>>>>> was the typical scenario) then the journal would appear empty since
>>>>>> the old location was mounted over.
>>>>>> 
>>>>>> This change fixes the problem by ensuring that the journal doesn't start
>>>>>> until after the mount happens.
>>>>>> 
>>>>> 
>>>>> What happens if folks have a different fstab then default? Will it still
>>>>> work
>>>> 
>>>> Yes, the "After" only changes behavior if something else has caused
>>>> var-volatile.mount to be in the set of services to be started.
>>>> 
>>>> I verified that was the case by removing /var/volatile from /etc/fstab and
>>>> the journal still starts with no errors.
>>> 
>>> perfect thanks. I will test it out in few hrs myself.
>> 
>> for some reason, my console never comes up now. I am not sure if this
>> is the patch causing it. I will try to single it out.
> 
> This patch should not be applied, but I see it has been applied anyway meanwhile, So we might have to solve this issue differently. 


Remove mounting of /var/volatile from /etc/fstab

tmpfs                /var/volatile        tmpfs      defaults              0  0

Then add a mount unit file for it

/lib/systemd/system/var-volatile.mount


#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.

[Unit]
Description=Temporary Directory
Documentation=man:hier(7)
Documentation=http://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
ConditionPathIsSymbolicLink=!/var/volatile
DefaultDependencies=no
Conflicts=umount.target
Before=local-fs.target umount.target

[Mount]
What=tmpfs
Where=/var/volatile
Type=tmpfs
Options=mode=1777,strictatime


solves this use-before-define issue, even when /var/volatile is mounted as tmpfs as we do in OE.


Now encode this logic up under DISTRO_FEATURE = “systemd” and we have a complete solution :)

Ideally we should mount /var/volatile as tmpfs only when using ro-rfs and do this whole orchestration of

if systemd add the above mount service + the service created for holding journald start point ( that got added in the patch above )

no changes are required for sysvinit

> 
> This is actually the cause of my console not coming up. It was coming up after 15 minutes
> systemd-analyse blame said systemd-tmpfiles-setup-dev.service is taking 14 mins to come up.
> I then traced through it and the problem is evident that its trying to write journal when creating /dev entries but we have delayed the journald starting point and caused a use-before-define situation.
> I deleted /var/volatile symlinks and let /var/log be proper directory and same for /var/tmp. All worked fine, without this patch. We should probably stop doing /var/volatile thing anyway its not in FHS standard either, for ro-rfs do something else ( may be copy-binds into /tmp/) and for general case just leave it alone. 
> 
> 00:04:23 read(4, "#  This file is part of systemd."..., 4096) = 1244
> 00:04:23 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/user\" does not match"..., 62}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:04:33 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/user\" does not match"..., 62}, {"\n", 1}], 5) = 90
> 00:04:33 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/utmp\" does not match"..., 62}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:04:43 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/utmp\" does not match"..., 62}, {"\n", 1}], 5) = 90
> 00:04:43 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/ask-password"..., 78}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Resou
> rce temporarily unavailable)
> 00:04:53 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/ask-password"..., 78}, {"\n", 1}], 5) = 106
> 00:04:53 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/seats\" does "..., 71}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:05:03 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/seats\" does "..., 71}, {"\n", 1}], 5) = 99
> 00:05:03 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/sessions\" do"..., 74}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:05:13 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/sessions\" do"..., 74}, {"\n", 1}], 5) = 102
> 00:05:13 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/users\" does "..., 71}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:05:23 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/users\" does "..., 71}, {"\n", 1}], 5) = 99
> 00:05:23 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/machines\" do"..., 74}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:05:33 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/machines\" do"..., 74}, {"\n", 1}], 5) = 102
> 00:05:33 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/systemd/shutdown\" do"..., 74}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:05:43 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/systemd/shutdown\" do"..., 74}, {"\n", 1}], 5) = 102
> 00:05:43 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/log\" does not match "..., 61}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:05:53 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/log\" does not match "..., 61}, {"\n", 1}], 5) = 89
> 00:05:53 sendmsg(3, {msg_name(0)=NULL, msg_iov(4)=[{"PRIORITY=7\nSYSLOG_FACILITY=3\nCOD"..., 284}, {"MESSAGE=", 8}, {"Entry \"/run/log/journal\" does no"..., 69}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 EAGAIN (Reso
> urce temporarily unavailable)
> 00:06:03 writev(5, [{"<31>", 4}, {"systemd-tmpfiles", 16}, {"[114]: ", 7}, {"Entry \"/run/log/journal\" does no"..., 69}, {"\n", 1}], 5) = 97
> 00:06:03 open("/etc/machine-id", O_RDONLY|O_NOCTTY|O_LARGEFILE|O_CLOEXEC) = 6