Good morning everyone!
While running some tests using our Linux distro and a SuperMicro Intel D1521 board, we encounter a situation where a very long line (shown as a "broken line" in LAVA's logs - in the WEB UI) seems to interfere with the job run, in a sense that the job eventually ends in a timeout.
This does not happen when that particular set of tests is not run and I am wondering if this might be a LAVA issue.
-------------------- A bit of context, first.
SuperMicro boards "make sure" your board connection options are limited to using SoL (serial-over-lan), IPMI and a serial port (but in a very limited manner). One is not able to do a "typical" image load, since you may not specify hardware addresses or properly interact with the bootloader.
This led to an approach which is best illustrated in the attached diagram.
For short: LAVA instantiates an LXC container, from where we run a series of scripts to prepare the board (copy some images & files on an already available Linux instance, altering the Grub menu and then rebooting the board, making it start the image we wish to test) and then run remote commands via SSH. So, basically, the LXC container runs each and every command on the board, acting as the middleman. -------------------
Now, we have the following:
* https://paste.debian.net/993516/ -> plain log excerpt that contains the very long line I was talking about (please see line no. 90) * https://paste.debian.net/993517/ -> job definition * https://paste.debian.net/993518/ -> test definition
Is there a way to further investigate if this type of output is "giving LAVA a hard time"? Is there a setting that limits interpreted output, somehow?
May it be that this is a LAVA issue?
Kind regards! -- /Dragoş
On 31 October 2017 at 09:22, Dragos Iorgulescu Dragos.Iorgulescu@enea.com wrote:
Good morning everyone!
While running some tests using our Linux distro and a SuperMicro Intel D1521 board, we encounter a situation where a very long line (shown as a "broken line" in LAVA's logs - in the WEB UI) seems to interfere with the job run, in a sense that the job eventually ends in a timeout.
<< lava: broken line >> is just an indication that the line could not be parsed as ASCII or any obvious encoding - it probably contains binary sequences.
In the output.yaml on the master, you will have the original content, e.g. from a beaglebone-black job:
- {"dt": "2017-10-27T15:27:51.618988", "lvl": "target", "msg": !!binary "QvW1SrmBmqGVsbGBQg==\n"} - {"dt": "2017-10-27T15:27:51.622342", "lvl": "target", "msg": !!binary "zaGlalJU5YuVyYE6QpWxwZ0CMr3JgQ==\n"}
This is python's best guess at what was sent.
This does not happen when that particular set of tests is not run and I am wondering if this might be a LAVA issue.
Please attach the complete output.yaml (available via the Actions, plain log link)
A bit of context, first.
SuperMicro boards "make sure" your board connection options are limited to using SoL (serial-over-lan), IPMI and a serial port (but in a very limited manner). One is not able to do a "typical" image load, since you may not specify hardware addresses or properly interact with the bootloader.
This led to an approach which is best illustrated in the attached diagram.
For short: LAVA instantiates an LXC container, from where we run a series of scripts to prepare the board (copy some images & files on an already available Linux instance, altering the Grub menu and then rebooting the board, making it start the image we wish to test) and then run remote commands via SSH. So, basically, the LXC container runs each and every command on the board, acting as the middleman.
This is common to a range of boards. It adds an extra level of complexity compared to devices which do not need LXC but it not a problem in itself.
Now, we have the following:
- https://paste.debian.net/993516/ -> plain log excerpt that contains
the very long line I was talking about (please see line no. 90)
- https://paste.debian.net/993517/ -> job definition
- https://paste.debian.net/993518/ -> test definition
Is there a way to further investigate if this type of output is "giving LAVA a hard time"? Is there a setting that limits interpreted output, somehow?
May it be that this is a LAVA issue?
Kind regards!
/Dragoş
Lava-users mailing list Lava-users@lists.linaro.org https://lists.linaro.org/mailman/listinfo/lava-users
Hi, Neil!
Thanks for clearing things up :)
Attaching the whole plain log...
-- /Dragoş
On 2017-10-31 11:36:27+02:00 Neil Williams wrote:
On 31 October 2017 at 09:22, Dragos Iorgulescu <Dragos.Iorgulescu@enea.commailto:Dragos.Iorgulescu@enea.com> wrote: Good morning everyone!
While running some tests using our Linux distro and a SuperMicro Intel D1521 board, we encounter a situation where a very long line (shown as a "broken line" in LAVA's logs - in the WEB UI) seems to interfere with the job run, in a sense that the job eventually ends in a timeout. << lava: broken line >> is just an indication that the line could not be parsed as ASCII or any obvious encoding - it probably contains binary sequences. In the output.yaml on the master, you will have the original content, e.g. from a beaglebone-black job: - {"dt": "2017-10-27T15:27:51.618988", "lvl": "target", "msg": !!binary "QvW1SrmBmqGVsbGBQg==\n"} - {"dt": "2017-10-27T15:27:51.622342", "lvl": "target", "msg": !!binary "zaGlalJU5YuVyYE6QpWxwZ0CMr3JgQ==\n"} This is python's best guess at what was sent.
This does not happen when that particular set of tests is not run and I am wondering if this might be a LAVA issue. Please attach the complete output.yaml (available via the Actions, plain log link)
-------------------- A bit of context, first.
SuperMicro boards "make sure" your board connection options are limited to using SoL (serial-over-lan), IPMI and a serial port (but in a very limited manner). One is not able to do a "typical" image load, since you may not specify hardware addresses or properly interact with the bootloader.
This led to an approach which is best illustrated in the attached diagram.
For short: LAVA instantiates an LXC container, from where we run a series of scripts to prepare the board (copy some images & files on an already available Linux instance, altering the Grub menu and then rebooting the board, making it start the image we wish to test) and then run remote commands via SSH. So, basically, the LXC container runs each and every command on the board, acting as the middleman. This is common to a range of boards. It adds an extra level of complexity compared to devices which do not need LXC but it not a problem in itself. -------------------
Now, we have the following:
* https://paste.debian.net/993516/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=jGtf1Pr35a8kCBrDBXYuE3j94A8fhHrDDxde7OjlWBII8arXUs5Md2k3RKwC-3OJNJMSeYuNgk8z7Dkv1d8em8BXpENgB6LIzeMlGbSnsDKo84neWFJedo62xIHSIM4HmIjcghXmO2W4ZfBu0Mj_ulzqgW9ozhvXX3ORvpvo0zDyF1OBWmUTkLwHPcv5aNXO18XndiqaSVhFLOQY1pg6i8LnLTRazguY7BwUna4vOUQ -> plain log excerpt that contains the very long line I was talking about (please see line no. 90) * https://paste.debian.net/993517/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=LH6vHyWR68x18REVS6tU4rPUWtWyqYwPZzTWDSSoFYDa2VrckriloYMpjmqwQcuTikEqzLst1Y4b39wizkiPKb5_yJ4LFoymF-Bn6pcWpQxmDny-mGvOJmDAsPmlTE30NwbDq79ZmY42ZX-k5-CtX4M9pKvRds0hTEaySiKsX9ldijk63G7Sb7DlSuTn2tBRNU7JX7YJQG0BKYZrUtX5Olp1iPQzsQXTLPa2oCU1niA -> job definition * https://paste.debian.net/993518/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=Vt4p60zef057CQwIi9cdBcUT6PNLL7hUIJMI3Bjyj5plqf1gkhCYi6wQQnmOjDh7reALdcPmVSvyLNNvWcAA0qH-alGMNLBjHzFenV6XphCXLy3w7olZeVnAcA2CJG7X8SZRMTj_hQdttpx6KTcFUAwZPjoBqFIwpkwMRtRL3FLHNMrvXkjK-4FsKgWMXDmme6AMYinOrhv9i5AoK4KGxFE0I-QvT9prZLxmECxA6k8 -> test definition
Is there a way to further investigate if this type of output is "giving LAVA a hard time"? Is there a setting that limits interpreted output, somehow?
May it be that this is a LAVA issue?
Kind regards! -- /Dragoş
_______________________________________________ Lava-users mailing list Lava-users@lists.linaro.orgmailto:Lava-users@lists.linaro.org https://lists.linaro.org/mailman/listinfo/lava-usershttps://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=okUQzuGZbIdEWyzo8ZYsfjrcQdM5qhowD9za_VGnXBAGNrYa3-MCIHcV0RCAhB5aPTPs0XZSV9jHT1CpmzE_iZ27bkx1fMdhpBrbZYIstwTdKm8Y26O_p8dm1Uetrsxk4qDY8HIk0L5INh6oaXQgP2-nllBHy-ah3AxFai9bwXdB0drYQpf10RQdKZ5oXW_FKQ351biVqisWloeQqJh8gZROosaqesTsQzcmirYZwiZddIS-qXaceDpV1bFjqOd4
--
Neil Williams ============= neil.williams@linaro.orgmailto:neil.williams@linaro.org http://www.linux.codehelp.co.uk/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=V1ud2RPs1Rrrc4KCSyX4VEk6ksHFEI0w5K8hWNAXZ3JbGzqwKh9R1p_3sNSKQ7V8wMdX-IYHHGR4IViLfSTN3jymkxEyX56BiDeVh5pUZI6DFmiQln4DVKuHJt5GEzoSCoNuoVASeleU4yyhACwOdVoxBsiS4N080nK6GD15gi1od-aHKeLOMYe_-iMoKJXzSwRiPmUXq7azVtm_0xjnFTFjHI97Sm1oYbP_kjTcAZ0
On 31 October 2017 at 09:47, Dragos Iorgulescu Dragos.Iorgulescu@enea.com wrote:
Hi, Neil!
Thanks for clearing things up :)
Attaching the whole plain log...
-- /Dragoş
On 2017-10-31 11:36:27+02:00 Neil Williams wrote:
On 31 October 2017 at 09:22, Dragos Iorgulescu <Dragos.Iorgulescu@enea.com
wrote:
Good morning everyone!
While running some tests using our Linux distro and a SuperMicro Intel D1521 board, we encounter a situation where a very long line (shown as a "broken line" in LAVA's logs - in the WEB UI) seems to interfere with the job run, in a sense that the job eventually ends in a timeout.
<< lava: broken line >> is just an indication that the line could not be parsed as ASCII or any obvious encoding - it probably contains binary sequences. In the output.yaml on the master, you will have the original content, e.g. from a beaglebone-black job:
- {"dt": "2017-10-27T15:27:51.618988", "lvl": "target", "msg": !!binary
"QvW1SrmBmqGVsbGBQg==\n"}
- {"dt": "2017-10-27T15:27:51.622342", "lvl": "target", "msg": !!binary "
zaGlalJU5YuVyYE6QpWxwZ0CMr3JgQ==\n"} This is python's best guess at what was sent.
This does not happen when that particular set of tests is not run and I am wondering if this might be a LAVA issue.
Please attach the complete output.yaml (available via the Actions, plain log link)
It's not related to long lines. It's related to your device not handling the serial connection reliably:
LAVA sent setenv: - {"dt": "2017-10-27T16:09:07.663040", "lvl": "debug", "msg": {"sending": "setenv loadinitrd 'tftpboot 0x60000000 358/tftp-deploy-VLCRzw/ramdisk/ramdisk.ext4.gz.uboot'\n"}}
Your device dropped the first character but then failed to handle that as an error. - {"dt": "2017-10-27T16:09:07.856605", "lvl": "target", "msg": "etenv loadinitrd 'tftpboot 0x60000000 358/tftp-deploy-VLCRzw/ramdisk/ramdisk.ext4.gz.uboot'"}
This looks like it was related to the delays caused by running usb start.
If your bootloader supports a "sleep" type command or "true" or similar, it may be worth adding that to your device configuration *as a completely separate line* after usb start so that your device has time to catch up after doing the usb start work and produce a prompt without needing to do much that would actually affect the rest of the job.
Equally, your bootloader seems to just timeout instead of handling errors in commands - typing etenv instead of setenv should produce an error message and a new prompt, not just sit there without any output. Without a fix for that, this device is not going to be reliable in automation.
Avoid using semi-colons in the bootloader configuration for this board - you appear to have problems with some commands not being interpreted correctly, so you will need to know which commands have worked and which have not. Combining multiple commands on one line is not going to help anyone. Not because of a long line but because you won't be able to tell which part failed.
A bit of context, first.
SuperMicro boards "make sure" your board connection options are limited to using SoL (serial-over-lan), IPMI and a serial port (but in a very limited manner). One is not able to do a "typical" image load, since you may not specify hardware addresses or properly interact with the bootloader.
This led to an approach which is best illustrated in the attached diagram.
For short: LAVA instantiates an LXC container, from where we run a series of scripts to prepare the board (copy some images & files on an already available Linux instance, altering the Grub menu and then rebooting the board, making it start the image we wish to test) and then run remote commands via SSH. So, basically, the LXC container runs each and every command on the board, acting as the middleman.
This is common to a range of boards. It adds an extra level of complexity compared to devices which do not need LXC but it not a problem in itself.
Now, we have the following:
https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=jGtf1Pr35a8kCBrDBXYuE3j94A8fhHrDDxde7OjlWBII8arXUs5Md2k3RKwC-3OJNJMSeYuNgk8z7Dkv1d8em8BXpENgB6LIzeMlGbSnsDKo84neWFJedo62xIHSIM4HmIjcghXmO2W4ZfBu0Mj_ulzqgW9ozhvXX3ORvpvo0zDyF1OBWmUTkLwHPcv5aNXO18XndiqaSVhFLOQY1pg6i8LnLTRazguY7BwUna4vOUQ -> plain log excerpt that contains the very long line I was talking about (please see line no. 90)
Is there a way to further investigate if this type of output is "giving LAVA a hard time"? Is there a setting that limits interpreted output, somehow?
May it be that this is a LAVA issue?
Kind regards!
/Dragoş
Lava-users mailing list Lava-users@lists.linaro.org https://lists.linaro.org/mailman/listinfo/lava-users https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=okUQzuGZbIdEWyzo8ZYsfjrcQdM5qhowD9za_VGnXBAGNrYa3-MCIHcV0RCAhB5aPTPs0XZSV9jHT1CpmzE_iZ27bkx1fMdhpBrbZYIstwTdKm8Y26O_p8dm1Uetrsxk4qDY8HIk0L5INh6oaXQgP2-nllBHy-ah3AxFai9bwXdB0drYQpf10RQdKZ5oXW_FKQ351biVqisWloeQqJh8gZROosaqesTsQzcmirYZwiZddIS-qXaceDpV1bFjqOd4
--
Neil Williams
neil.williams@linaro.org http://www.linux.codehelp.co.uk/ https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=V1ud2RPs1Rrrc4KCSyX4VEk6ksHFEI0w5K8hWNAXZ3JbGzqwKh9R1p_3sNSKQ7V8wMdX-IYHHGR4IViLfSTN3jymkxEyX56BiDeVh5pUZI6DFmiQln4DVKuHJt5GEzoSCoNuoVASeleU4yyhACwOdVoxBsiS4N080nK6GD15gi1od-aHKeLOMYe_-iMoKJXzSwRiPmUXq7azVtm_0xjnFTFjHI97Sm1oYbP_kjTcAZ0
Hi again!
Just as a follow-up, in case it might be useful for someone else: the indications Neil gave in the previous mail are, unfortunatelly, unapplicable in our lab context (due to the limitations imposed by the board).
So, the only workaround that seems to work is to limit the output line length of those specific tests (community ptests, to be more precise). Since the test output is controlled by a big, strange & ugly awk code block, we added an instruction to truncate output.
Even though that big line should not have interfered with the job run, it seems that by limiting the output we managed to bypass that.
Thanks again for the input, Neil.
Kind regards!
-- /Dragoş
On 2017-10-31 11:57:58+02:00 Neil Williams wrote:
On 31 October 2017 at 09:47, Dragos Iorgulescu <Dragos.Iorgulescu@enea.commailto:Dragos.Iorgulescu@enea.com> wrote: Hi, Neil!
Thanks for clearing things up :)
Attaching the whole plain log...
-- /Dragoş
On 2017-10-31 11:36:27+02:00 Neil Williams wrote:
On 31 October 2017 at 09:22, Dragos Iorgulescu <Dragos.Iorgulescu@enea.commailto:Dragos.Iorgulescu@enea.com> wrote: Good morning everyone!
While running some tests using our Linux distro and a SuperMicro Intel D1521 board, we encounter a situation where a very long line (shown as a "broken line" in LAVA's logs - in the WEB UI) seems to interfere with the job run, in a sense that the job eventually ends in a timeout. << lava: broken line >> is just an indication that the line could not be parsed as ASCII or any obvious encoding - it probably contains binary sequences. In the output.yaml on the master, you will have the original content, e.g. from a beaglebone-black job: - {"dt": "2017-10-27T15:27:51.618988", "lvl": "target", "msg": !!binary "QvW1SrmBmqGVsbGBQg==\n"} - {"dt": "2017-10-27T15:27:51.622342", "lvl": "target", "msg": !!binary "zaGlalJU5YuVyYE6QpWxwZ0CMr3JgQ==\n"} This is python's best guess at what was sent.
This does not happen when that particular set of tests is not run and I am wondering if this might be a LAVA issue. Please attach the complete output.yaml (available via the Actions, plain log link) It's not related to long lines. It's related to your device not handling the serial connection reliably: LAVA sent setenv: - {"dt": "2017-10-27T16:09:07.663040", "lvl": "debug", "msg": {"sending": "setenv loadinitrd 'tftpboot 0x60000000 358/tftp-deploy-VLCRzw/ramdisk/ramdisk.ext4.gz.uboot'\n"}} Your device dropped the first character but then failed to handle that as an error. - {"dt": "2017-10-27T16:09:07.856605", "lvl": "target", "msg": "etenv loadinitrd 'tftpboot 0x60000000 358/tftp-deploy-VLCRzw/ramdisk/ramdisk.ext4.gz.uboot'"} This looks like it was related to the delays caused by running usb start. If your bootloader supports a "sleep" type command or "true" or similar, it may be worth adding that to your device configuration *as a completely separate line* after usb start so that your device has time to catch up after doing the usb start work and produce a prompt without needing to do much that would actually affect the rest of the job. Equally, your bootloader seems to just timeout instead of handling errors in commands - typing etenv instead of setenv should produce an error message and a new prompt, not just sit there without any output. Without a fix for that, this device is not going to be reliable in automation. Avoid using semi-colons in the bootloader configuration for this board - you appear to have problems with some commands not being interpreted correctly, so you will need to know which commands have worked and which have not. Combining multiple commands on one line is not going to help anyone. Not because of a long line but because you won't be able to tell which part failed. -------------------- A bit of context, first.
SuperMicro boards "make sure" your board connection options are limited to using SoL (serial-over-lan), IPMI and a serial port (but in a very limited manner). One is not able to do a "typical" image load, since you may not specify hardware addresses or properly interact with the bootloader.
This led to an approach which is best illustrated in the attached diagram.
For short: LAVA instantiates an LXC container, from where we run a series of scripts to prepare the board (copy some images & files on an already available Linux instance, altering the Grub menu and then rebooting the board, making it start the image we wish to test) and then run remote commands via SSH. So, basically, the LXC container runs each and every command on the board, acting as the middleman. This is common to a range of boards. It adds an extra level of complexity compared to devices which do not need LXC but it not a problem in itself. -------------------
Now, we have the following:
* https://paste.debian.net/993516/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=jGtf1Pr35a8kCBrDBXYuE3j94A8fhHrDDxde7OjlWBII8arXUs5Md2k3RKwC-3OJNJMSeYuNgk8z7Dkv1d8em8BXpENgB6LIzeMlGbSnsDKo84neWFJedo62xIHSIM4HmIjcghXmO2W4ZfBu0Mj_ulzqgW9ozhvXX3ORvpvo0zDyF1OBWmUTkLwHPcv5aNXO18XndiqaSVhFLOQY1pg6i8LnLTRazguY7BwUna4vOUQ -> plain log excerpt that contains the very long line I was talking about (please see line no. 90) * https://paste.debian.net/993517/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=LH6vHyWR68x18REVS6tU4rPUWtWyqYwPZzTWDSSoFYDa2VrckriloYMpjmqwQcuTikEqzLst1Y4b39wizkiPKb5_yJ4LFoymF-Bn6pcWpQxmDny-mGvOJmDAsPmlTE30NwbDq79ZmY42ZX-k5-CtX4M9pKvRds0hTEaySiKsX9ldijk63G7Sb7DlSuTn2tBRNU7JX7YJQG0BKYZrUtX5Olp1iPQzsQXTLPa2oCU1niA -> job definition * https://paste.debian.net/993518/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=Vt4p60zef057CQwIi9cdBcUT6PNLL7hUIJMI3Bjyj5plqf1gkhCYi6wQQnmOjDh7reALdcPmVSvyLNNvWcAA0qH-alGMNLBjHzFenV6XphCXLy3w7olZeVnAcA2CJG7X8SZRMTj_hQdttpx6KTcFUAwZPjoBqFIwpkwMRtRL3FLHNMrvXkjK-4FsKgWMXDmme6AMYinOrhv9i5AoK4KGxFE0I-QvT9prZLxmECxA6k8 -> test definition
Is there a way to further investigate if this type of output is "giving LAVA a hard time"? Is there a setting that limits interpreted output, somehow?
May it be that this is a LAVA issue?
Kind regards! -- /Dragoş
_______________________________________________ Lava-users mailing list Lava-users@lists.linaro.orgmailto:Lava-users@lists.linaro.org https://lists.linaro.org/mailman/listinfo/lava-usershttps://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=okUQzuGZbIdEWyzo8ZYsfjrcQdM5qhowD9za_VGnXBAGNrYa3-MCIHcV0RCAhB5aPTPs0XZSV9jHT1CpmzE_iZ27bkx1fMdhpBrbZYIstwTdKm8Y26O_p8dm1Uetrsxk4qDY8HIk0L5INh6oaXQgP2-nllBHy-ah3AxFai9bwXdB0drYQpf10RQdKZ5oXW_FKQ351biVqisWloeQqJh8gZROosaqesTsQzcmirYZwiZddIS-qXaceDpV1bFjqOd4
--
Neil Williams ============= neil.williams@linaro.orgmailto:neil.williams@linaro.org http://www.linux.codehelp.co.uk/https://url10.mailanyone.net/v1/?m=1e9Sy6-0000Ot-4K&i=57e1b682&c=V1ud2RPs1Rrrc4KCSyX4VEk6ksHFEI0w5K8hWNAXZ3JbGzqwKh9R1p_3sNSKQ7V8wMdX-IYHHGR4IViLfSTN3jymkxEyX56BiDeVh5pUZI6DFmiQln4DVKuHJt5GEzoSCoNuoVASeleU4yyhACwOdVoxBsiS4N080nK6GD15gi1od-aHKeLOMYe_-iMoKJXzSwRiPmUXq7azVtm_0xjnFTFjHI97Sm1oYbP_kjTcAZ0
--
Neil Williams ============= neil.williams@linaro.orgmailto:neil.williams@linaro.org http://www.linux.codehelp.co.uk/https://url10.mailanyone.net/v1/?m=1e9TIu-00068y-45&i=57e1b682&c=OAdoxTJV2AyIHWvtok19IWulfdKDLOBhUYmI71h3zFdvrOkvsWiuHxynTLLLqcNv9v3Z8-1lXiKKh1ht4NcasJLYNzKA6O-fu-ywG0fn4doo0n_Idikhj4MFYuEc3rqFUavZjmo7XIp53MkSvOjWKub9JsSoe_43UqXB-18Dl2g5fQmT7civaBJQFtdW7jM36f_ufrEn4D-y592HgBGgwrEILpLg542BBVONKEYBxEQ
-
Dragos Iorgulescu -
Neil Williams