Specify log file through API by dianpopa · Pull Request #250 · firecracker-microvm/firecracker

dianpopa · 2018-05-04T14:30:53Z

Changes

users can now attach a log path through an API call
the logger is thread safe
added unit tests for all the newly added functions

Testing

Build Time

Prerequisite

## add the necessary musl target to the active toolchain
rustup target add x86_64-unknown-linux-musl

Build tests

cargo fmt —all
cargo build # no warning
cargo build —release
sudo env "PATH=$PATH" cargo test --all
sudo env "PATH=$PATH" cargo kcov —all

Coverage report for logger related files

File	Coverage %
api_server/src/request/sync/logger.rs	96.2
vmm/src/logger_config.rs	97.2
logger/src/error.rs	91.7
logger/src/writers.rs	94.1
logger/src/lib.rs	95.7

Integration Testing

rm -f /tmp/firecracker.socket && \
target/x86_64-unknown-linux-musl/debug/firecracker --api-sock=/tmp/firecracker.socket

in another console start sending some logger-related curl requests for starting basic firecracker guest

# should return error as the log path is an empty one
curl --unix-socket /tmp/firecracker.socket -i \
     -X PUT "http://localhost/logger" \
     -H "accept: application/json" \
     -H "Content-Type: application/json" \
     -d "{ 
            \"path\": \"\", 
            \"level\": \"Info\", 
            \"show_level\": true, 
            \"show_log_origin\": true
         }"

# Output
HTTP/1.1 400 Bad Request
Content-Type: application/json
Transfer-Encoding: chunked
Date: Fri, 04 May 2018 14:25:38 GMT

{
  "fault_message": "Cannot initialize logging system! Failed to create log file. Error: entity not found"
}

set a valid local log_path

export log_path=tmp.log
curl --unix-socket /tmp/firecracker.socket -i      -X PUT "http://localhost/logger"      -H "accept: application/json"      -H "Content-Type: application/json"      -d "{ 
            \"path\": \"${log_path}\", 
            \"level\": \"Info\", 
            \"show_level\": true, 
            \"show_log_origin\": true
         }"
# Output:
HTTP/1.1 201 Created
Content-Length: 0
Date: Fri, 04 May 2018 14:26:40 GMT

try to initialize the logger a second time. Should output:

HTTP/1.1 400 Bad Request
Content-Type: application/json
Transfer-Encoding: chunked
Date: Fri, 04 May 2018 14:29:05 GMT

{
  "fault_message": "Cannot initialize logging system! Reinitialization of logger not allowed."
}

now try to boot up a machine:

curl --unix-socket /tmp/firecracker.socket -i  \
     -X PUT "http://localhost/boot-source" \
     -H "accept: application/json" \
     -H "Content-Type: application/json" \
     -d "{ 
           \"boot_source_id\": \"alinux_kernel\",
           \"source_type\": \"LocalImage\", 
           \"local_image\": 
                { 
                    \"kernel_image_path\": \"${kernel_path}\" 
                }
        }"

curl --unix-socket /tmp/firecracker.socket -i \
     -X PUT "http://localhost/machine-config" \
     -H "accept: application/json" \
     -H "Content-Type: application/json" \
     -d "{ \"vcpu_count\": 4, \"mem_size_mib\": 256}"

# Add root block device
curl --unix-socket /tmp/firecracker.socket -i \
     -X PUT "http://localhost/drives/root" \
     -H "accept: application/json" \
     -H "Content-Type: application/json" \
     -d "{ 
            \"drive_id\": \"root\",
            \"path_on_host\": \"${rootfs_path}\", 
            \"is_root_device\": true, 
            \"permissions\": \"rw\", 
            \"state\": \"Attached\"
         }"

curl --unix-socket /tmp/firecracker.socket -i \
     -X PUT "http://localhost/actions/start" \
     -H  "accept: application/json" \
     -H  "Content-Type: application/json" \
     -d "{  
            \"action_id\": \"start\",  
            \"action_type\": \"InstanceStart\"
         }"

# Get the response of starting the instance
curl --unix-socket /tmp/firecracker.socket -i \
     -X GET "http://localhost/actions/start" \
     -H "accept: application/json"

sudo ip link delete vmtap33

in the initial console the guest should start up

# login: ...
# reboot

now check that the file tmp.log contains the expected output

vim tmp.log
# it should contain 
# [INFO:vmm/src/lib.rs:810] vcpu requested shutdown

let s also test that the configuration does not fail
- kill the firecracker process and do the 0. step again
- set the show_log_origin to false

exprot log_path=tmp.log
curl --unix-socket /tmp/firecracker.socket -i      -X PUT "http://localhost/logger"      -H "accept: application/json"      -H "Content-Type: application/json"      -d "{ 
            \"path\": \"${log_path}\", 
            \"level\": \"Info\", 
            \"show_level\": true, 
            \"show_log_origin\": false
         }"
# Output:
HTTP/1.1 201 Created
Content-Length: 0
Date: Fri, 04 May 2018 14:26:40 GMT

* send commands from 4.
* reboot machine
* check again the tmp.log file. should now contain no file path and line number:

[INFO] vcpu requested shutdown

alxiord · 2018-05-04T14:56:47Z

+        assert!(&desc.into_parsed_request().is_ok());
+        // I will test this when the other unit tests are merged
+        //let (sender, receiver) = oneshot::channel();
+        //assert!(&desc.into_parsed_request().eq(&Ok(ParsedRequest::Sync(SyncRequest::PutLogger(desc, sender), receiver))));


In order for this to work, you need to implement the use case for PutLogger in impl PartialEq for SyncRequest.

Done. Thanks for the hint.

alxiord · 2018-05-04T14:58:11Z


-static INIT: Once = ONCE_INIT;
-static mut INIT_RES: Result<usize> = Ok(UNINITIALIZED);
+//static INIT: Once = ONCE_INIT;


If INIT isn't needed any more, please remove it instead of commenting it out.

alxiord · 2018-05-04T15:12:54Z

-                    INIT_RES = Err(LoggerError::NeverInitialized(format!("{}", e)))
+                Err(ref e) => {
+                    STATE.store(UNINITIALIZED, Ordering::SeqCst);
+                    return Err(LoggerError::NeverInitialized(format!("{}", e)));


Cosmetic concern: the error e is propagated all the way up from libstd::io::File::create and is one of libstd::io::error::ErrorKind, the string representations of which are all lowercase. So the error message (as seen in the tests run) looks like

{ "fault_message": "Cannot initialize logging system! Failed to create log file. entity not found" }

Can you please make the error message something like Failed to create log file. Error: <propagated error> ?

Solved it; Take a look at error.rs in impl fmt::Display for LoggerError.

alxiord · 2018-05-04T15:17:51Z

+                        }
+                    }
+                    SyncRequest::PutLogger(logger_description, sender) => {
+                        eprintln!(


Is this for debugging purposes only?

I mistakenly left it there. I removed it now.

acatangiu · 2018-05-07T22:07:00Z

+    description:
+      Describes the configuration option for the logger intitialization.
+    properties:
+      source_type:


This field is not necessary. Just use the path like all other resources currently do. When we move to FD passing, we will change all API calls from using path to using FDs.
I believe this field will never be used so I suggest removing it.

Are you confident that we will only support FD passing? Why not keep around both versions?

I am confident we will not support both versions at the same time 😃

hehe :) I will do the change.

done, take a look please

acatangiu · 2018-05-07T22:07:55Z

          schema:
            $ref: "#/definitions/Error"

+  /logger:


Please add these to firecracker-v1.0.yaml as well.

We discussed about it yesterday. firecracker-v1.0.yaml is very outdated. So we have here two possibilities: either update it to match what we have now in firecracker-beta, or we don't update it at all for now and only use it as a " What the future looks like" yaml. Since we are sort of time bound, I suggest we don't update it for now.

acatangiu · 2018-05-07T22:11:08Z

                path,
                str::from_utf8(body.as_ref()).unwrap()
+                // when time will come, we could better do
+                serde_json::from_slice(&body).unwrap()


Uncommenting this debug block breaks compilation with this change.

I know. I left it there to consider it as an option 'when time will come'. Do we want me to remove it or solve the compilation errors?

It's more of a nit, you could leave it as is, but I would add '//' to it so that the code still works when uncommenting the whole block.

I added a comment.

acatangiu · 2018-05-07T22:22:18Z

+
+type Result<T> = result::Result<T, APILoggerError>;
+
+pub fn init_logger(api_logger: APILoggerDescription) -> Result<()> {


Ideally you could've/should've used the new API<->VMM model that uses common data structs for both api_server and vmm.
This new model is the one proposed in @andreeaflorescu 's PR #248 in the data_model crate.

The code here looks very good and I'm personally fine with merging it, but do have a look at the aforementioned PR and decide for yourself.

So, if you take a closer look you will see that logger_config does not redefine any type; What #248 wants is to remove the necessity to redefine types inside vmm, which in my case does not happen.

acatangiu · 2018-05-07T22:30:01Z

-                "{:?}",
-                LoggerError::Poisoned(String::from("Never Initialized"))
-            ).contains("Poisoned")
+        println!(


Why do we want to print all of these (all the println!s in this test) during unit tests?

to increase coverage; this prints are the ones that exercise the Debug trait.

They exercise, but don't check anything thus giving us false coverage.
Without proper checking we could break something and unittests and coverage will still look good.

I suggest you find a way to actually check the Debug trait output, or otherwise remove this and leave it without coverage.

done, take a look.

through an API call. Signed-off-by: Diana Popa <dpopa@amazon.com>

* removed static variable for keeping status * used AtomicSize for safely sharing state between threads * appended relevant error on top of the low level one * removed Poison status error as it stopped us from being able to try reinitialization Signed-off-by: Diana Popa <dpopa@amazon.com>

* call asserts on the last code in the test_init * exercise Display for the LoggerError Signed-off-by: Diana Popa <dpopa@amazon.com>

Signed-off-by: Diana Popa <dpopa@amazon.com>

inside the vmm as an intermediate step in the logger setup triggered by the API. Signed-off-by: Diana Popa <dpopa@amazon.com>

dianpopa requested a review from a team May 4, 2018 14:31

dianpopa self-assigned this May 4, 2018

dianpopa added the Feature: Metrics and Metering label May 4, 2018

alxiord reviewed May 4, 2018

View reviewed changes

alxiord changed the title ~~Spcecify log file through API~~ Specify log file through API May 4, 2018

acatangiu reviewed May 7, 2018

View reviewed changes

acatangiu previously approved these changes May 8, 2018

View reviewed changes

dianpopa dismissed acatangiu’s stale review via d3bfc50 May 9, 2018 09:32

dianpopa added 5 commits May 9, 2018 04:47

api_server: adding support for specifying log file...

a4d8e32

through an API call. Signed-off-by: Diana Popa <dpopa@amazon.com>

logger: update unit tests

c44371f

* call asserts on the last code in the test_init * exercise Display for the LoggerError Signed-off-by: Diana Popa <dpopa@amazon.com>

api_server: added unit tests for the logger description

8fc25c5

Signed-off-by: Diana Popa <dpopa@amazon.com>

vmm: unit testing the logger configuration...

4c6bd25

inside the vmm as an intermediate step in the logger setup triggered by the API. Signed-off-by: Diana Popa <dpopa@amazon.com>

acatangiu approved these changes May 9, 2018

View reviewed changes

alxiord approved these changes May 9, 2018

View reviewed changes

acatangiu merged commit 17dfb1f into firecracker-microvm:master May 9, 2018

raduweiss mentioned this pull request May 10, 2018

Switch from syslog to some hostfile-backed mechanism #143

Closed

dianpopa deleted the i143 branch June 13, 2018 10:39

dianpopa mentioned this pull request Jun 13, 2018

Finalize Firecracker Metrics and Logging system #252

Closed

5 tasks


		type Result<T> = result::Result<T, APILoggerError>;

		pub fn init_logger(api_logger: APILoggerDescription) -> Result<()> {

Conversation

dianpopa commented May 4, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Changes

Testing

Build Time

Prerequisite

Build tests

Coverage report for logger related files

Integration Testing

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

alxiord May 4, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dianpopa May 8, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

andreeaflorescu May 8, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dianpopa May 8, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

dianpopa commented May 4, 2018 •

edited

Loading

alxiord May 4, 2018 •

edited

Loading

dianpopa May 8, 2018 •

edited

Loading

andreeaflorescu May 8, 2018 •

edited

Loading

dianpopa May 8, 2018 •

edited

Loading