Skip to content

The log format of ceph-deploy-ceph.log is not right#1

Open
tone-zhang wants to merge 1 commit intoceph:masterfrom
tone-zhang:bug-06132016
Open

The log format of ceph-deploy-ceph.log is not right#1
tone-zhang wants to merge 1 commit intoceph:masterfrom
tone-zhang:bug-06132016

Conversation

@tone-zhang
Copy link

Open the log file with vi, the character '^M' can be
seen at the end of some lines. And if "cat" the log
file, some lines will not be displayed. '^M' is not
the line-end symbol used in Linux.

Signed-off-by: Tone Zhang tone.zhang@linaro.org

received = result.receive(timeout)
level_received, message = list(received.items())[0]
log_map[level_received](message.strip('\n'))
message = message.splitlines()

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this doesn't look right, message is a single line already. If you want to remove the ^M char just add it to the strip() call:

message.strip('\n^M')

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually, you can't remove ^M like that, but you still need to strip it:

message.strip('\n\r')

Also I wouldn't mind a test demonstrating the issue (and fix). Thanks!

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi alfredodeza,
Thanks a lot for the comments.
I did some tests to validate the code change.
Test 1: change message.strip('\n') to message.strip('\n^M'), the change does not work. The log refers to below:
[2016-06-20 02:25:10,510][arm-vm1][DEBUG ] Selecting previously unselected package ceph-common.^M
[2016-06-20 02:25:10,577][arm-vm1][DEBUG ] (Reading database ... ^M(Reading database ... 5%^M(Reading database ... 10%^M(Reading database ... 15%^M(Reading database ... 20%^M(Reading database ... 25%^M(Reading database ... 30%^M(Reading database ... 35%^M(Reading database ... 40%^M(Reading database ... 45%^M(Reading database ... 50%^M(Reading database ... 55%^M(Reading database ... 60%^M(Reading database ... 65%^M(Reading database ... 70%^M(Reading database ... 75%^M(Reading database ... 80%^M(Reading database ... 85%^M(Reading database ... 90%^M(Reading database ... 95%^M(Reading database ... 100%^M(Reading database ... 125715 files and directories currently installed.)^M
[2016-06-20 02:25:10,586][arm-vm1][DEBUG ] Preparing to unpack .../ceph-common_10.2.2-1xenial_arm64.deb ...^M

Test 2: change message.strip('\n') to message.strip('\n\r'). The result is better than test1. There is still ^M in the log. The log refers to below:
[2016-06-20 02:35:07,418][arm-vm1][DEBUG ] Selecting previously unselected package ceph-common.
[2016-06-20 02:35:07,483][arm-vm1][DEBUG ] (Reading database ... ^M(Reading database ... 5%^M(Reading database ... 10%^M(Reading database ... 15%^M(Reading database ... 20%^M(Reading database ... 25%^M(Reading database ... 30%^M(Reading database ... 35%^M(Reading database ... 40%^M(Reading database ... 45%^M(Reading database ... 50%^M(Reading database ... 55%^M(Reading database ... 60%^M(Reading database ... 65%^M(Reading database ... 70%^M(Reading database ... 75%^M(Reading database ... 80%^M(Reading database ... 85%^M(Reading database ... 90%^M(Reading database ... 95%^M(Reading database ... 100%^M(Reading database ... 125715 files and directories currently installed.)
[2016-06-20 02:35:07,492][arm-vm1][DEBUG ] Preparing to unpack .../ceph-common_10.2.2-1xenial_arm64.deb ...
Test3: change message.strip('\n') to
message = message.splitlines()
for i in range(len(message)):
log_maplevel_received
The log refers to below:
[2016-06-20 02:38:26,602][arm-vm1][DEBUG ] Selecting previously unselected package ceph-common.
[2016-06-20 02:38:26,667][arm-vm1][DEBUG ] (Reading database ...
[2016-06-20 02:38:26,668][arm-vm1][DEBUG ] (Reading database ... 5%
[2016-06-20 02:38:26,668][arm-vm1][DEBUG ] (Reading database ... 10%
[2016-06-20 02:38:26,669][arm-vm1][DEBUG ] (Reading database ... 15%
[2016-06-20 02:38:26,669][arm-vm1][DEBUG ] (Reading database ... 20%
[2016-06-20 02:38:26,670][arm-vm1][DEBUG ] (Reading database ... 25%
[2016-06-20 02:38:26,670][arm-vm1][DEBUG ] (Reading database ... 30%
[2016-06-20 02:38:26,671][arm-vm1][DEBUG ] (Reading database ... 35%
[2016-06-20 02:38:26,671][arm-vm1][DEBUG ] (Reading database ... 40%
[2016-06-20 02:38:26,671][arm-vm1][DEBUG ] (Reading database ... 45%
[2016-06-20 02:38:26,672][arm-vm1][DEBUG ] (Reading database ... 50%
[2016-06-20 02:38:26,673][arm-vm1][DEBUG ] (Reading database ... 55%
[2016-06-20 02:38:26,673][arm-vm1][DEBUG ] (Reading database ... 60%
[2016-06-20 02:38:26,677][arm-vm1][DEBUG ] (Reading database ... 65%
[2016-06-20 02:38:26,677][arm-vm1][DEBUG ] (Reading database ... 70%
[2016-06-20 02:38:26,678][arm-vm1][DEBUG ] (Reading database ... 75%
[2016-06-20 02:38:26,678][arm-vm1][DEBUG ] (Reading database ... 80%
[2016-06-20 02:38:26,679][arm-vm1][DEBUG ] (Reading database ... 85%
[2016-06-20 02:38:26,679][arm-vm1][DEBUG ] (Reading database ... 90%
[2016-06-20 02:38:26,679][arm-vm1][DEBUG ] (Reading database ... 95%
[2016-06-20 02:38:26,680][arm-vm1][DEBUG ] (Reading database ... 100%
[2016-06-20 02:38:26,680][arm-vm1][DEBUG ](Reading database ... 125715 files and directories currently installed.)
[2016-06-20 02:38:26,689][arm-vm1][DEBUG ] Preparing to unpack .../ceph-common_10.2.2-1xenial_arm64.deb ...
In the 3rd log, there is no ^M any more.
in the above three code changes, the 3rd can remove all the ^M, it works well.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To correct the copy/paste error, the 3rd change is as below:
message = message.splitlines()
for i in range(len(message)):
log_maplevel_received

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The last line "log_maplevel_received" can not be displayed correctly, it is strange.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I didn't think that the output could have ^M in the middle. The reason for why the Reading database... is still having ^M in there is because it is not supposed to be a new line, but rather, a line that will get replaced as the percentage grows. This is a terminal emulator behavior to show progress.

I don't see it correct to split the lines to convert that into proper lines.

You pasted some log output, but I still don't see unit tests. Would you mind adding them to this pull request to demonstrate the behavior (and fix)?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I pasted part of the error log above. in fact, without the correction (the 3rd one) the ^M can be seen in the log behind the "reading database". When run "ceph-deploy install" or "ceph-deploy purge", the error log can be seen easily.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Correct. I am saying that this is expected and correct behavior since the terminal is rewriting with \r and splitting lines should not be done.

This is a special case where a rewrite is being done on the same line. No correction is necessary there.

Open the log file with vi, the character '^M' can be
seen at the end of some lines. And if "cat" the log
file, some lines will not be displayed. '^M' is not
the line-end symbol used in Linux. It is better to
remove it from log.

Signed-off-by: Tone Zhang <tone.zhang@linaro.org>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants