-
Notifications
You must be signed in to change notification settings - Fork 0
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Always log xtrace to file #55
base: main
Are you sure you want to change the base?
Conversation
Signed-off-by: Michał Iwanicki <[email protected]>
And maybe write logs to permanent location so they aren't lost after reboot? This would probably require:
|
Unfortunately, most use cases involve iPXE. Is these cases, DTS boots from RAM and does not use any persistent storage, having logs saved when booting from USB still good thought. |
Signed-off-by: Michał Iwanicki <[email protected]>
I know but it'd still be useful. Added fix for error when entering There is also quite a slowdown at least on QEMU in one specific part:
And it gets stuck here for maybe 0.65 second before printing rest i.e.
Adding stop_trace_logging/start_trace_logging at the start/end of this functions fixes this but I'm not sure if it's best way to do it, what's your opinion? I guess it's easiest to implement. Maybe we shouldn't run this function on every menu refresh but only once in e.g. diff --git a/include/dts-functions.sh b/include/dts-functions.sh
index a46d19b9f382..2b08bb9e5b3b 100644
--- a/include/dts-functions.sh
+++ b/include/dts-functions.sh
@@ -1230,6 +1230,7 @@ You can find more info about HCL in docs.dasharo.com/glossary\r"
}
show_ram_inf() {
+ stop_trace_logging
# Get the data:
local data=""
data=$($DMIDECODE)
@@ -1272,6 +1273,7 @@ show_ram_inf() {
for entry in "${memory_devices_array[@]}"; do
echo -e "${BLUE}**${YELLOW} RAM ${entry}"
done
+ start_trace_logging "${DTS_LOG_FILE}"
}
show_header() { |
Slowdown is most likely due to printing timestamp. |
If no other solution can be found for the slowdown, then I guess we can stick with your workaround. |
Signed-off-by: Michał Iwanicki <[email protected]>
This function is called on each redraw of UI. Due to using external command 'date' to create timestamp, trace logging noticeably slows down UI draw time in the middle. Another possible fixes: - disable timestamp in trace logging - generate RAM info only once before UI shows as it is unlikely RAM will change while DTS is running Signed-off-by: Michał Iwanicki <[email protected]>
Combined with trace timestamps it'll be easier to match error to command Signed-off-by: Michał Iwanicki <[email protected]>
Signed-off-by: Michał Iwanicki <[email protected]>
Signed-off-by: Michał Iwanicki <[email protected]>
Signed-off-by: Michał Iwanicki <[email protected]>
Added 58de8df and 13b8a47 to deal with Dasharo/dasharo-issues#1165. Disabled trace logging in changed couple Added timestamp prefix when logging to I guess PR is ready for review, we could maybe move console logs to |
When using qemu with telnet I have 2 files for each log:
|
Each tty starts it's own dts-boot (serial, graphical QEMU, ssh), that way we don't mix logs from different tty. |
Signed-off-by: Michał Iwanicki <[email protected]>
@@ -888,7 +888,7 @@ check_blobs_in_binary() { | |||
|
|||
# If there is no descriptor, there is no ME as well, so skip the check | |||
if [ $BOARD_HAS_FD_REGION -ne 0 ]; then | |||
ME_OFFSET=$($IFDTOOL check_blobs_in_binary_mock -d $1 2> /dev/null | grep "Flash Region 2 (Intel ME):" | sed 's/Flash Region 2 (Intel ME)\://' | awk '{print $1;}') | |||
ME_OFFSET=$($IFDTOOL check_blobs_in_binary_mock -d $1 2>>"$ERR_LOG_FILE" | grep "Flash Region 2 (Intel ME):" | sed 's/Flash Region 2 (Intel ME)\://' | awk '{print $1;}') |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
You could redirect other STDERR too:
λ grep -rn "/dev/null"
include/hal/dts-hal.sh:106: if ! echo "$_mock_func" | grep "_mock" &> /dev/null; then
include/hal/dts-hal.sh:122: if [ -n "$_mock_func" ] && type $_mock_func &> /dev/null; then
include/hal/dts-hal.sh:124: elif type ${_tool}_${_mock_func} &> /dev/null; then
include/hal/dts-hal.sh:126: elif type ${_tool}_common_mock &> /dev/null; then
include/hal/dts-hal.sh:147: $DASHARO_ECTOOL check_for_opensource_firm_mock info > /dev/null 2>&1
include/hal/dts-hal.sh:193: _mode="$($SETPCI check_me_op_mode_mock -s 00:16.0 42.B 2> /dev/null | cut -c2-)"
include/dts-subscription.sh:42: _check_dwn_req_resp_uefi=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:46: _check_dwn_req_resp_uefi_cap=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:50: _check_dwn_req_resp_heads=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:54: _check_dwn_req_resp_seabios=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:57: _check_logs_req_resp=$(curl -L -I -s -f -H "$CLOUD_REQUEST" "$TEST_LOGS_URL" -o /dev/null -w "%{http_code}")
include/dts-functions.sh:153: if wget --spider cloud.3mdeb.com > /dev/null 2>&1; then
include/dts-functions.sh:326: elif ! $DASHARO_ECTOOL check_for_opensource_firm_mock info 2>/dev/null; then
include/dts-functions.sh:693: FLASH_CHIP_SIZE=$(($($FLASHROM flash_chip_size_mock -p "$PROGRAMMER_BIOS" --flash-size 2>> /dev/null | tail -n1) / 1024 / 1024))
include/dts-functions.sh:704: FLASH_CHIP_SIZE=$(($($FLASHROM flash_chip_size_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} --flash-size 2>> /dev/null | tail -n1) / 1024 / 1024))
include/dts-functions.sh:1003: $FLASHROM read_flash_layout_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} ${FLASHROM_ADD_OPT_UPDATE} -r $BIOS_DUMP_FILE > /dev/null 2>&1
include/dts-functions.sh:1007: diff <(echo "$BOARD_FMAP_LAYOUT") <(echo "$BINARY_FMAP_LAYOUT") > /dev/null 2>&1
include/dts-functions.sh:1113: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null
include/dts-functions.sh:1210: chronyc waitsync 10 0 0 5 >/dev/null 2>>ERR_LOG_FILE
include/dts-functions.sh:1316: if systemctl is-active sshd.service &> /dev/null; then
include/dts-functions.sh:1506: if systemctl is-active sshd.service &> /dev/null; then
include/dts-functions.sh:1526: if systemctl is-active sshd.service> /dev/null 2>&1; then
reports/touchpad-info:13:if ! $DMESG i2c_hid_detect_mock | grep hid-multitouch | grep "I2C HID" > /dev/null; then
reports/dasharo-hcl-report:25: ERR=$(stat -c%s "$ERRORFILE" 2> /dev/null)
reports/dasharo-hcl-report:26: LOG=$(stat -c%s "$LOGFILE" 2> /dev/null)
reports/dasharo-hcl-report:222:if pushd logs/acpi &> /dev/null; then
reports/dasharo-hcl-report:223: acpixtract -a ../acpidump.log >/dev/null 2>>"$ERR_LOG_FILE"
reports/dasharo-hcl-report:224: iasl -d ./*.dat >/dev/null 2>>"$ERR_LOG_FILE"
reports/dasharo-hcl-report:225: popd &> /dev/null || return 1
reports/dasharo-hcl-report:328:grep -rl "${MAC_ADDR}" logs > /dev/null && grep -rl "${MAC_ADDR}" logs | xargs sed -i 's/'${MAC_ADDR}'/MAC ADDRESS REMOVED/g'
scripts/local-deploy.sh:11: -o UserKnownHostsFile=/dev/null \
scripts/dasharo-deploy:83: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null
scripts/dasharo-deploy:91: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null
scripts/dasharo-deploy:99: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null
scripts/dasharo-deploy:107: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null
scripts/dasharo-deploy:520: dd if=/tmp/rom.bin of=/tmp/romhole.bin skip=$((0x17C0000)) bs=128K count=1 iflag=skip_bytes > /dev/null 2>&1
scripts/dasharo-deploy:604: $FLASHROM read_firm_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} ${FLASHROM_ADD_OPT_READ} -r $BIOS_DUMP_FILE > /dev/null 2>/dev/null
scripts/dasharo-deploy:607: diff <(echo "$BINARY_KEYS") <(echo "$FLASH_KEYS") > /dev/null 2>&1
tests/compare_version.sh:4:DTS_ENV=/dev/null source "$DTS_FUNCS"
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
A lot of those are stdout to /dev/null or to completely get rid of output e.g. in if
's where error is expected.
Some commands always output to stderr e.g. dd or flashrom:
bash-5.2# flashrom -p internal >/dev/null
Warning: Setting BIOS Control at 0xdc from 0x8b to 0x89 failed.
New value is 0x8b.
Which ones do you want redirected? Remember that the only way to connect those errors to lines is searching timestamps in trace logs (which won't be 1-to-1)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Logs from every command might be useful during debugging. For example these commands send their STDERR everywhere but error log file:
include/hal/dts-hal.sh:147: $DASHARO_ECTOOL check_for_opensource_firm_mock info > /dev/null 2>&1
include/hal/dts-hal.sh:193: _mode="$($SETPCI check_me_op_mode_mock -s 00:16.0 42.B 2> /dev/null | cut -c2-)"
include/dts-functions.sh:153: if wget --spider cloud.3mdeb.com > /dev/null 2>&1; then
include/dts-functions.sh:326: elif ! $DASHARO_ECTOOL check_for_opensource_firm_mock info 2>/dev/null; then
include/dts-functions.sh:693: FLASH_CHIP_SIZE=$(($($FLASHROM flash_chip_size_mock -p "$PROGRAMMER_BIOS" --flash-size 2>> /dev/null | tail -n1) / 1024 / 1024))
include/dts-functions.sh:704: FLASH_CHIP_SIZE=$(($($FLASHROM flash_chip_size_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} --flash-size 2>> /dev/null | tail -n1) / 1024 / 1024))
include/dts-functions.sh:1003: $FLASHROM read_flash_layout_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} ${FLASHROM_ADD_OPT_UPDATE} -r $BIOS_DUMP_FILE > /dev/null 2>&1
include/dts-functions.sh:1316: if systemctl is-active sshd.service &> /dev/null; then
include/dts-functions.sh:1506: if systemctl is-active sshd.service &> /dev/null; then
include/dts-functions.sh:1526: if systemctl is-active sshd.service> /dev/null 2>&1; then
reports/dasharo-hcl-report:222:if pushd logs/acpi &> /dev/null; then
reports/dasharo-hcl-report:225: popd &> /dev/null || return 1
scripts/dasharo-deploy:520: dd if=/tmp/rom.bin of=/tmp/romhole.bin skip=$((0x17C0000)) bs=128K count=1 iflag=skip_bytes > /dev/null 2>&1
scripts/dasharo-deploy:604: $FLASHROM read_firm_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} ${FLASHROM_ADD_OPT_READ} -r $BIOS_DUMP_FILE > /dev/null 2>/dev/null
scripts/dasharo-deploy:607: diff <(echo "$BINARY_KEYS") <(echo "$FLASH_KEYS") > /dev/null 2>&1
Maybe you could as well dump some info from these curls:
include/dts-subscription.sh:42: _check_dwn_req_resp_uefi=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:46: _check_dwn_req_resp_uefi_cap=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:50: _check_dwn_req_resp_heads=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:54: _check_dwn_req_resp_seabios=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null -w "%{http_code}")
include/dts-subscription.sh:57: _check_logs_req_resp=$(curl -L -I -s -f -H "$CLOUD_REQUEST" "$TEST_LOGS_URL" -o /dev/null -w "%{http_code}")
include/dts-functions.sh:1113: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null
scripts/dasharo-deploy:83: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null
scripts/dasharo-deploy:91: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null
scripts/dasharo-deploy:99: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null
scripts/dasharo-deploy:107: curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
As I said, dd always prints to stderr (whether there is error or not)
Do you want each curl output in error logs (even though they are not errors)? Should I create new ones? Add to DTS_LOG_FILE
? If to DTS_LOG_FILE
then should I also add timestamps there?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Do you want each curl output in error logs (even though they are not errors)? Should I create new ones? Add to DTS_LOG_FILE? If to DTS_LOG_FILE then should I also add timestamps there?
You should redirect curl errors to the error log file if it is possible and not too hard to achieve (no need to waste too much time here). Let me know why otherwise.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I was asking if you want curl output (-o /dev/null
== >/dev/null
) as in:
curl -L -I -f --silent -u 'abc:abc' 'https://cloud.3mdeb.com/public.php/webdav' -X PROPFIND -H "Depth: 5"
HTTP/1.1 401 Unauthorized
Server: nginx/1.22.1
Date: Fri, 20 Dec 2024 11:12:38 GMT
Content-Type: application/xml; charset=utf-8
Content-Length: 234
Connection: keep-alive
Strict-Transport-Security: max-age=15552000; includeSubDomains
Referrer-Policy: no-referrer
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
X-Permitted-Cross-Domain-Policies: none
X-Robots-Tag: noindex, nofollow
X-XSS-Protection: 1; mode=block
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Cache-Control: no-store, no-cache, must-revalidate
Pragma: no-cache
Set-Cookie:
path=/; secure; HttpOnly; SameSite=Lax
Content-Security-Policy: default-src 'none';
Set-Cookie: __Host-nc_sameSiteCookielax=true; path=/; httponly;secure; expires=Fri, 31-Dec-2100 23:59:59 GMT; SameSite=lax
Set-Cookie: __Host-nc_sameSiteCookiestrict=true; path=/; httponly;secure; expires=Fri, 31-Dec-2100 23:59:59 GMT; SameSite=strict
WWW-Authenticate: Basic realm="3mdeb", charset="UTF-8"
Strict-Transport-Security: max-age=31536000; includeSubDomains
It'll output this result whether it succeeds or not. Or do you want only errors?
As we are using --silent
flag curl doesn't return errors. I guess I could also add -S
flag so we can redirect:
curl: (22) The requested URL returned error: 401
Added -S
flag and error redirection to curls: 104527a
start_trace_logging | ||
start_logging | ||
if [ -z "$ERR_LOG_FILE" ]; then | ||
exec {ERR_LOG_FILE}> >(logger >> "$ERR_LOG_FILE_REALPATH") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
You could add some comments here. This is not a trivial code line.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@m-iwanicki, wrong commit?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
a90f235
Sometimes ctrl+c doesn't catch
include/dts-functions.sh
Outdated
@@ -1429,7 +1434,9 @@ main_menu_options(){ | |||
fi | |||
|
|||
# Use regular update process for everything else | |||
${CMD_DASHARO_DEPLOY} update | |||
if ! ${CMD_DASHARO_DEPLOY} update; then |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
dasharo_deploy update
will return 1
in case of platform does not have updates available, and will trigger your send_dts_logs ask
:
Enter an option:
2
Waiting for network connection ...
Network connection have been established!
Checking if board is Dasharo compatible.
Waiting for system clock to be synced ...
Current Dasharo version: 0.2.0
Latest available Dasharo version for your subscribtion: 0.2.0
No update available for your machine
Do you want to send console logs to 3mdeb? [N/y]:
This is counterintuitive, could you fix it?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Whole PR will need to be thoroughly tested
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
force-pushed: 47c8d38, quick patch job, should probably think of something better. Maybe you have some ideas? If it works then I guess it could stay as is an be either fixed later on be made obsolete when we migrate to GO.
56fd2d6
to
11c5048
Compare
Signed-off-by: Michał Iwanicki <[email protected]>
11c5048
to
a90f235
Compare
Signed-off-by: Michał Iwanicki <[email protected]>
Signed-off-by: Michał Iwanicki <[email protected]>
db1604c
to
106dd83
Compare
Signed-off-by: Michał Iwanicki <[email protected]>
Signed-off-by: Michał Iwanicki <[email protected]>
Signed-off-by: Michał Iwanicki <[email protected]>
c646824
to
c909bbf
Compare
/tmp/dts.log
/tmp/dts-verbose.log
When entering shell, logging to
dts.log
is disabled as redirecting output results in problems in interactive shell but verbose (xtrace) logs are still enabled just without timestamp:After returning to DTS UI by using
exit
normal logging is enabled again and verbose logs contain timestampThere is one problem, trying to enter
dts-boot
second time from shell results in errorafter which we end up back in shell.
@PLangowski what do you think?