Add support for specifying different files for flushing metrics #362

dianpopa · 2018-06-20T13:53:30Z

Changes

completed unit tests inside http_service.rs
modified firecracker.yaml specification to also mention the metrics_fifo field
added support for forwarding metrics to a named pipe
modified tests related to the logger to create the log file apriori to the logging

Testing

Build Time

Prerequisite

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

Build tests

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

Coverage report for related files

File	Coverage %
api_server/src/http_service.rs	73.3
api_server/src/request/sync/logger.rs	96.4
logger/src/error.rs	91.7
logger/src/writers.rs	95.2
logger/src/lib.rs	92.6
logger/src/metrics.rs	100
vmm/src/api_logger_config.rs	93.7

Overall reported by testrun.sh 73.1%.

Integration Testing

Start firecracker in a different terminal:

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

Create the two named pipes that are going to be used by the logger:

export metric_fifo=/tmp/metricfifo
export log_fifo=/tmp/logfifo
# create a script with the following contents
#!/bin/bash
pipe=$1

if [[ ! -p $pipe ]]; then
    mkfifo $pipe
fi

while true
do
    if read line; then
        if [[ "$line" == 'quit' ]]; then
            break
        fi
        echo $line
    fi
done <$pipe

echo "Reader exiting"

# the above script will be used as the consumer of the logs
# run the below commands in two different terminals
./create_fifo.sh $log_fifo
./create_fifo.sh $metric_fifo

Attach the logger to firecracker

curl --unix-socket /tmp/firecracker.socket -i      -X PUT "http://localhost/logger"      -H "accept: application/json"      -H "Content-Type: application/json"      -d "{ 
            \"log_fifo\": \"${log_fifo}\",
            \"metrics_fifo\": \"${metric_fifo}\", 
            \"level\": \"Info\", 
            \"show_level\": true, 
            \"show_log_origin\": true
         }"

You should start observing some output already in the terminal where $log_fifo is being consumed
Boot a VM

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}\" 
                },
	\"boot_args\": \"console=ttyS0 noapic reboot=k panic=1 pci=off nomodules\"
        }"

# 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"

Wait 60 seconds and check the terminal where $metric_fifo is being consumed.
Special behavior explained

if the consumer is stopped, no logs will be outputted anymore and no errors will be registered
if the consumer is stopped and more than 64k have been sent to the logger, two metrics were added to reflect the error received in this case (i.e EGAIN): "logger":{"missed_metrics_count":0,"missed_log_count":0.

andreeaflorescu

Pass 1, will do another one in a few hours.

andreeaflorescu · 2018-06-21T08:52:28Z

api_server/src/http_service.rs

+        );
+
+        // Test case when JSON is broken.
+        let json = "{


This is not testing that the JSON is broken. The JSON is correct. The problem here is that the state is a required field and since you misspelled it on purpose, Serde doesn't find it. You should update the comment or actually pass an invalid json.

I changed the comment. Take a look.

andreeaflorescu · 2018-06-21T08:54:23Z

api_server/src/http_service.rs

@@ -1081,7 +1081,8 @@ mod tests {
        let path = "/foo";


nit: you have an extra u in the commit message.

I think you are referring to another commit; This one 'metrics: add suuport for flushing metrics to...', right?

alxiord · 2018-06-21T12:50:43Z

api_server/src/http_service.rs

+
+        // PUT
+        let logger_deser = serde_json::from_slice::<request::APILoggerDescription>(&body);
+        match logger_deser {


This match tests serde functionalities instead of your code, please replace it with an unwrap and match only on the result of parse_logger_req.

alxiord · 2018-06-21T12:53:25Z

logger/src/lib.rs

+/// This is used by the internal logger to either flush human-readable logs or metrics.
+fn log_to_fifo(mut msg: String, fifo_writer: &mut PipeLogWriter) -> Result<()> {
+    msg = format!("{}\n", msg);
+    if let Err(e) = fifo_writer.write(&msg) {


Can't this be replaced with the ? operator?

Yes it can and it has been replaced.

alxiord · 2018-06-21T12:58:33Z

logger/src/lib.rs

+
+        File::create(&Path::new(&log_file_str())).expect("Failed to create temporary log file.");
+        File::create(&Path::new(&metrics_file_str()))
+            .expect("Failed to create temporary log file.");


Please choose another error message to differentiate between the temporary log and metrics files.

I did change it. Take a look where I initialize the two NamedTempFile.

alxiord · 2018-06-21T12:59:57Z

logger/src/lib.rs

+        File::create(&Path::new(&metrics_file_str()))
+            .expect("Failed to create temporary log file.");
+
+        assert!(


If any assert fails, the temporary files will not be cleaned up. Please store the results and assert on them after removing the files.

I think if there is no limitation and you just need a file, you can actually use the tempfile crate. Take a look at my PR #367 to see if tempfiles would be a good fit here as well.

I am now using NamedTempFile. Thanks @andreeaflorescu for the suggestion.

alxiord · 2018-06-21T13:07:20Z

logger/src/writers.rs

-        let res = FileLogWriter::new(&file);
+        let bad_file: String = "./inexistent/tmp.log".to_string();
+        assert!(PipeLogWriter::new(&bad_file).is_err());
+        format!("{:?}", PipeLogWriter::new(&bad_file));


This looks less like a test and more like a trick to increase coverage, I'd remove it

I removed all the formats.

alxiord · 2018-06-21T13:08:39Z

vmm/src/api_logger_config.rs

-        let filename = "tmp.log";
+        File::create(&Path::new(&log_filename)).expect("Failed to create temporary log file.");
+
+        File::create(&Path::new(&metrics_filename)).expect("Failed to create temporary log file.");


Please modify the error message to make it specific to the metrics file

...as part of the decision to use two named pipes as logging destinations: one for human readable logs and one for metrics. Signed-off-by: Diana Popa <[email protected]>

Signed-off-by: Diana Popa <[email protected]>

a secondary named pipe. Also do not flush metrics if the logging system was not initialized. Signed-off-by: Diana Popa <[email protected]>

and metrics being flushed to two different named pipes. Signed-off-by: Diana Popa <[email protected]>

dianpopa self-assigned this Jun 20, 2018

dianpopa requested a review from a team June 20, 2018 13:53

andreeaflorescu reviewed Jun 21, 2018

View reviewed changes

alxiord reviewed Jun 21, 2018

View reviewed changes

alxiord previously approved these changes Jun 28, 2018

View reviewed changes

dianpopa added 4 commits June 28, 2018 05:11

logger: change swagger specification...

5c4241d

...as part of the decision to use two named pipes as logging destinations: one for human readable logs and one for metrics. Signed-off-by: Diana Popa <[email protected]>

api_server: some more unit tests for http_service

fddc1ca

Signed-off-by: Diana Popa <[email protected]>

metrics: add support for flushing metrics to...

5e99d92

a secondary named pipe. Also do not flush metrics if the logging system was not initialized. Signed-off-by: Diana Popa <[email protected]>

README: adjust information on logs...

0db2e8e

and metrics being flushed to two different named pipes. Signed-off-by: Diana Popa <[email protected]>

dianpopa dismissed alxiord’s stale review via 0db2e8e June 28, 2018 10:13

dianpopa mentioned this pull request Jun 28, 2018

Add support for specifying different files for flushing metrics #339

Closed

alxiord approved these changes Jun 28, 2018

View reviewed changes

andreeaflorescu approved these changes Jun 28, 2018

View reviewed changes

alxiord merged commit a3ac997 into firecracker-microvm:master Jun 28, 2018

dianpopa deleted the i339 branch August 20, 2018 20:55

acatangiu mentioned this pull request Oct 2, 2018

Add microVM / Instance ID (issue #238) #500

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add support for specifying different files for flushing metrics #362

Add support for specifying different files for flushing metrics #362

dianpopa commented Jun 20, 2018 •

edited

Loading

andreeaflorescu left a comment

andreeaflorescu Jun 21, 2018

dianpopa Jun 22, 2018

andreeaflorescu Jun 21, 2018

dianpopa Jun 22, 2018

alxiord Jun 21, 2018

dianpopa Jun 22, 2018

alxiord Jun 21, 2018

dianpopa Jun 22, 2018

alxiord Jun 21, 2018

dianpopa Jun 22, 2018

alxiord Jun 21, 2018

andreeaflorescu Jun 21, 2018

dianpopa Jun 22, 2018

alxiord Jun 21, 2018

dianpopa Jun 22, 2018

alxiord Jun 21, 2018

dianpopa Jun 22, 2018

Add support for specifying different files for flushing metrics #362

Add support for specifying different files for flushing metrics #362

Conversation

dianpopa commented Jun 20, 2018 • edited Loading

Changes

Testing

Build Time

Prerequisite

Build tests

Coverage report for related files

Integration Testing

andreeaflorescu left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dianpopa commented Jun 20, 2018 •

edited

Loading