[PATCH 0/5] Fixes for busybox-syslog with systemd

[PATCH 0/5] Fixes for busybox-syslog with systemd

[Aníbal Limón]

Changes can be reviewed at,

http://git.yoctoproject.org/cgit/cgit.cgi/poky-contrib/log/?h=alimon/simple_patches

Aníbal Limón (5):
  oeqa/runtime/syslog.py: Improve test_syslog_logger
  busybox-syslog.default: When systemd is enabled don't use circular
    buffer
  classes/testimage: When image is systemd, enable debug log level
  oeqa/runtime/syslog: test_syslog_logger Don't try to use logread when
    systemd is enabled
  oeqa/utils/commands.py: Command class improve validations/decoding in
    output

 meta/classes/testimage.bbclass                         | 5 ++++-
 meta/lib/oeqa/runtime/syslog.py                        | 9 +++++++--
 meta/lib/oeqa/utils/commands.py                        | 5 ++++-
 meta/recipes-core/busybox/files/busybox-syslog.default | 2 +-
 4 files changed, 16 insertions(+), 5 deletions(-)

-- 
2.1.4

[PATCH 1/5] oeqa/runtime/syslog.py: Improve test_syslog_logger

[Aníbal Limón]

Instead of make all the testing in a shell one liner, divide the
test into 3 operations to be able to know in what part is failing.

Parts,
	- Log message to syslog
	- Review if message exist in /var/log/messages
		- Review if message exist using logread

Signed-off-by: Aníbal Limón <anibal.limon@linux.intel.com>
---
 meta/lib/oeqa/runtime/syslog.py | 9 +++++++--
 1 file changed, 7 insertions(+), 2 deletions(-)

diff --git a/meta/lib/oeqa/runtime/syslog.py b/meta/lib/oeqa/runtime/syslog.py
index f7421ec..202a63f 100644
--- a/meta/lib/oeqa/runtime/syslog.py
+++ b/meta/lib/oeqa/runtime/syslog.py
@@ -18,8 +18,13 @@ class SyslogTestConfig(oeRuntimeTest):
     @testcase(1149)
     @skipUnlessPassed("test_syslog_running")
     def test_syslog_logger(self):
-        (status,output) = self.target.run('logger foobar && test -e /var/log/messages && grep foobar /var/log/messages || logread | grep foobar')
-        self.assertEqual(status, 0, msg="Test log string not found in /var/log/messages. Output: %s " % output)
+        (status, output) = self.target.run('logger foobar')
+        self.assertEqual(status, 0, msg="Can't log into syslog. Output: %s " % output)
+
+        (status, output) = self.target.run('grep foobar /var/log/messages')
+        if status != 0:
+            (status, output) = self.target.run('logread | grep foobar')
+        self.assertEqual(status, 0, msg="Test log string not found in /var/log/messages or logread. Output: %s " % output)
 
     @testcase(1150)
     @skipUnlessPassed("test_syslog_running")
-- 
2.1.4

[PATCH 2/5] busybox-syslog.default: When systemd is enabled don't use circular buffer

[Aníbal Limón]

Busybox syslog uses a shmmem circular buffer [1][2] when launch with -C option
when systemd (is enabled) takes the control of syslog messages and then forward
the messages to busybox syslog daemon, systemd journald don't usage of shmmem
circular buffer.

If -C is specified busybox-syslog never be able to read the forwarded
messages from systemd journald and don't wrote it to /var/log/messages.

This file is only installed when systemd is enabled [3].

[1] https://git.busybox.net/busybox/tree/sysklogd/syslogd.c?h=1_24_stable#n464
[2] https://git.busybox.net/busybox/tree/sysklogd/logread.c?h=1_24_stable#n82
[3] http://git.yoctoproject.org/cgit/cgit.cgi/poky/tree/meta/recipes-core/busybox/busybox.inc#n295

Signed-off-by: Aníbal Limón <anibal.limon@linux.intel.com>
---
 meta/recipes-core/busybox/files/busybox-syslog.default | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/meta/recipes-core/busybox/files/busybox-syslog.default b/meta/recipes-core/busybox/files/busybox-syslog.default
index e516caf..2dced80 100644
--- a/meta/recipes-core/busybox/files/busybox-syslog.default
+++ b/meta/recipes-core/busybox/files/busybox-syslog.default
@@ -1,4 +1,4 @@
-OPTIONS="-C"
+#OPTIONS="-C"
 # The above option means syslogd will log to 16K shm circular buffer.
 # You could use `logread' to read it.
 
-- 
2.1.4

[PATCH 3/5] classes/testimage: When image is systemd, enable debug log level

[Aníbal Limón]

In order to get more information about systemd boot process to
be able to debug random failures due to high I/O.

[YOCTO #9299]

Signed-off-by: Aníbal Limón <anibal.limon@linux.intel.com>
---
 meta/classes/testimage.bbclass | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/meta/classes/testimage.bbclass b/meta/classes/testimage.bbclass
index 0b6c779..e42c5ac 100644
--- a/meta/classes/testimage.bbclass
+++ b/meta/classes/testimage.bbclass
@@ -144,7 +144,10 @@ def testimage_main(d):
     tc.extract_packages()
     target.deploy()
     try:
-        target.start()
+        bootparams = None
+        if d.getVar('VIRTUAL-RUNTIME_init_manager', '') == 'systemd':
+            bootparams = 'systemd.log_level=debug systemd.log_target=console'
+        target.start(extra_bootparams=bootparams)
         starttime = time.time()
         result = tc.runTests()
         stoptime = time.time()
-- 
2.1.4

[PATCH 4/5] oeqa/runtime/syslog: test_syslog_logger Don't try to use logread when systemd is enabled

[Aníbal Limón]

Busybox logread uses shmmem circular buffer to retrive [1] syslog messages
when systemd is enabled this shmem circular buffer isn't enabled because
systemd journald doesn't provide it.

[1] https://git.busybox.net/busybox/tree/sysklogd/logread.c?id=accd9eeb719916da974584b33b1aeced5f3bb346#n121

Signed-off-by: Aníbal Limón <anibal.limon@linux.intel.com>
---
 meta/lib/oeqa/runtime/syslog.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/meta/lib/oeqa/runtime/syslog.py b/meta/lib/oeqa/runtime/syslog.py
index 202a63f..cce3c22 100644
--- a/meta/lib/oeqa/runtime/syslog.py
+++ b/meta/lib/oeqa/runtime/syslog.py
@@ -22,7 +22,7 @@ class SyslogTestConfig(oeRuntimeTest):
         self.assertEqual(status, 0, msg="Can't log into syslog. Output: %s " % output)
 
         (status, output) = self.target.run('grep foobar /var/log/messages')
-        if status != 0:
+        if status != 0 and not oeRuntimeTest.tc.d.getVar("VIRTUAL-RUNTIME_init_manager", "") == "systemd":
             (status, output) = self.target.run('logread | grep foobar')
         self.assertEqual(status, 0, msg="Test log string not found in /var/log/messages or logread. Output: %s " % output)
 
-- 
2.1.4

[PATCH 5/5] oeqa/utils/commands.py: Command class improve validations/decoding in output

[Aníbal Limón]

When run a command sometimes the output isn't provided so validate
before trying to encode to utf-8, also some output like BIOS/EFI
contains characters that can't be codified into utf-8 for this reason
set errors='replace'.

[YOCTO #10019]

Signed-off-by: Aníbal Limón <anibal.limon@linux.intel.com>
---
 meta/lib/oeqa/utils/commands.py | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/meta/lib/oeqa/utils/commands.py b/meta/lib/oeqa/utils/commands.py
index 4f79d15..a8e184d 100644
--- a/meta/lib/oeqa/utils/commands.py
+++ b/meta/lib/oeqa/utils/commands.py
@@ -78,7 +78,10 @@ class Command(object):
                 self.process.kill()
                 self.thread.join()
 
-        self.output = self.output.decode("utf-8").rstrip()
+        if not self.output:
+            self.output = ""
+        else:
+            self.output = self.output.decode("utf-8", errors='replace').rstrip()
         self.status = self.process.poll()
 
         self.log.debug("Command '%s' returned %d as exit code." % (self.cmd, self.status))
-- 
2.1.4

Re: [PATCH 5/5] oeqa/utils/commands.py: Command class improve validations/decoding in output

[Leonardo Sandoval]

Hi Anibal,


El 07/27/2016 a las 05:40 PM, Aníbal Limón escribió:
> When run a command sometimes the output isn't provided so validate
I wonder if this problem is related to a timeout, so at some point this 
is reached and no output is shown.
> before trying to encode to utf-8, also some output like BIOS/EFI
> contains characters that can't be codified into utf-8 for this reason
> set errors='replace'.
>
> [YOCTO #10019]
>
> Signed-off-by: Aníbal Limón <anibal.limon@linux.intel.com>
> ---
>   meta/lib/oeqa/utils/commands.py | 5 ++++-
>   1 file changed, 4 insertions(+), 1 deletion(-)
>
> diff --git a/meta/lib/oeqa/utils/commands.py b/meta/lib/oeqa/utils/commands.py
> index 4f79d15..a8e184d 100644
> --- a/meta/lib/oeqa/utils/commands.py
> +++ b/meta/lib/oeqa/utils/commands.py
> @@ -78,7 +78,10 @@ class Command(object):
>                   self.process.kill()
>                   self.thread.join()
>   
> -        self.output = self.output.decode("utf-8").rstrip()
> +        if not self.output:
> +            self.output = ""
> +        else:
> +            self.output = self.output.decode("utf-8", errors='replace').rstrip()
>           self.status = self.process.poll()
>   
>           self.log.debug("Command '%s' returned %d as exit code." % (self.cmd, self.status))

Re: [PATCH 5/5] oeqa/utils/commands.py: Command class improve validations/decoding in output

[Aníbal Limón]

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



On 07/27/2016 10:18 PM, Leonardo Sandoval wrote:
> Hi Anibal,
> 
> 
> El 07/27/2016 a las 05:40 PM, Aníbal Limón escribió:
>> When run a command sometimes the output isn't provided so validate
> I wonder if this problem is related to a timeout, so at some point this
> is reached and no output is shown.

This could be one scenario but the output needs to be validated in order
to don't crash trying to use a None var.

	alimon

>> before trying to encode to utf-8, also some output like BIOS/EFI
>> contains characters that can't be codified into utf-8 for this reason
>> set errors='replace'.
>>
>> [YOCTO #10019]
>>
>> Signed-off-by: Aníbal Limón <anibal.limon@linux.intel.com>
>> ---
>>   meta/lib/oeqa/utils/commands.py | 5 ++++-
>>   1 file changed, 4 insertions(+), 1 deletion(-)
>>
>> diff --git a/meta/lib/oeqa/utils/commands.py
>> b/meta/lib/oeqa/utils/commands.py
>> index 4f79d15..a8e184d 100644
>> --- a/meta/lib/oeqa/utils/commands.py
>> +++ b/meta/lib/oeqa/utils/commands.py
>> @@ -78,7 +78,10 @@ class Command(object):
>>                   self.process.kill()
>>                   self.thread.join()
>>   -        self.output = self.output.decode("utf-8").rstrip()
>> +        if not self.output:
>> +            self.output = ""
>> +        else:
>> +            self.output = self.output.decode("utf-8",
>> errors='replace').rstrip()
>>           self.status = self.process.poll()
>>             self.log.debug("Command '%s' returned %d as exit code." %
>> (self.cmd, self.status))
> 


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]

Re: [PATCH 0/5] Fixes for busybox-syslog with systemd

[Richard Purdie]

On Wed, 2016-07-27 at 17:40 -0500, Aníbal Limón wrote:
> Changes can be reviewed at,
> 
> http://git.yoctoproject.org/cgit/cgit.cgi/poky-contrib/log/?h=alimon/simple_patches
> 
> Aníbal Limón (5):
>   oeqa/runtime/syslog.py: Improve test_syslog_logger
>   busybox-syslog.default: When systemd is enabled don't use circular
>     buffer
>   classes/testimage: When image is systemd, enable debug log level
>   oeqa/runtime/syslog: test_syslog_logger Don't try to use logread when
>     systemd is enabled
>   oeqa/utils/commands.py: Command class improve validations/decoding in
>     output
> 
>  meta/classes/testimage.bbclass                         | 5 ++++-
>  meta/lib/oeqa/runtime/syslog.py                        | 9 +++++++--
>  meta/lib/oeqa/utils/commands.py                        | 5 ++++-
>  meta/recipes-core/busybox/files/busybox-syslog.default | 2 +-
>  4 files changed, 16 insertions(+), 5 deletions(-)

We did see:

https://autobuilder.yoctoproject.org/main/builders/nightly-qa-systemd/b
uilds/867/steps/Running%20Sanity%20Tests/logs/stdio

which means we're probably still missing a tweak in this series?

Cheers,

Richard