Jailer unable to use put logging correctly

[xibz]

I noticed that when I attempt to use the put logger API I receive a 400 bad request. Which is odd, because it is the literally the same request being sent when it is not jailed. I have created the fifos in the jailer's proper chroot. Also uses v0.16.0 of the jailer

Here is the error:

The API server received a synchronous Put request on "/logger" with body "{\"level\":\"Debug\",\"log_fifo\":\"/tmp/jailer-test118456457/firecracker/b/root/firecracker.log\",\"metrics_fifo\":\"/tmp/jailer-test118456457/firecracker/b/root/firecracker-metrics\",\"options\":[],\"show_level\":true,\"show_log_origin\":false}\n".
2019-05-20T21:50:15.863225585 [b:ERROR] Received Error on synchronous Put request on "/logger" with body "{\"level\":\"Debug\",\"log_fifo\":\"/tmp/jailer-test118456457/firecracker/b/root/firecracker.log\",\"metrics_fifo\":\"/tmp/jailer-test118456457/firecracker/b/root/firecracker-metrics\",\"options\":[],\"show_level\":true,\"show_log_origin\":false}\n". Status code: 400 Bad Request.

[andreeaflorescu]

It's very weird that you don't get any error message. This looks to be a bug on our side.

Are you sure the fifo path is the right one?

[alexandruag]

Hi @xibz,

Do paths like /tmp/jailer-test118456457/firecracker/b/root/firecracker.log exist inside the jail? It looks like the path you use when not running with the jailer. After the jailer starts, it effectively does a chroot which causes the Firecracker process to consider the jail folder as the filesystem root (/).

In your case, it seems /tmp/jailer-test118456457/firecracker/b/root/ is the jailer root folder, so you should specify the path inside the JSON body as just /firecracker.log (the same applies to the metrics file/pipe). Does this fix the problem?

[xibz]

@alexandruag - Looks like it is still failing with the same error

 time="2019-05-21T13:26:58-07:00" level=debug msg="Created metrics and logging fifos."                                   
 time="2019-05-21T13:26:58-07:00" level=debug msg="PUT /logger HTTP/1.1\r\nHost: localhost\r\nUser-Agent: Go-http-client/1.1\r\nContent-Length: 141\r\nAccept: application/json\r\nContent-Type: application/json\r\nAccept-Encoding: gzip\r\n\r\n{\"level\":\"Debug\",\"log_fifo\":\"/firecracker.log\",\"metrics_fifo\":\"/firecracker-metrics\",\"options\":[],\"show_level\":tr
 2019-05-21T20:26:58.789021902 [b:INFO] The API server received a synchronous Put request on "/logger" with body "{\"level\":\"Debug\",\"log_fifo\":\"/firecracker.log\",\"metrics_fifo\":\"/firecracker-metrics\",\"options\":[],\"show_level\":true,\"show_log_origin\":false}\n".
 2019-05-21T20:26:58.789066126 [b:ERROR] Received Error on synchronous Put request on "/logger" with body "{\"level\":\"Debug\",\"log_fifo\":\"/firecracker.log\",\"metrics_fifo\":\"/firecracker-metrics\",\"options\":[],\"show_level\":true,\"show_log_origin\":false}\n". Status code: 400 Bad Request.

I did, however, get some permission denied requests as well. The fifos' permission bits are 0700, so unsure why it can't read it.

 time="2019-05-21T13:29:09-07:00" level=debug msg="HTTP/1.1 400 Bad Request\r\nTransfer-Encoding: chunked\r\nContent-Type: application/json\r\nDate: Tue, 21 May 2019 20:29:09 GMT\r\n\r\n63\r\n{\n  \"fault_message\": \"Could not open logging fifo: Failed to open pipe. Error: permission denied\"\n}\r\n0\r\n\r\n\n"
 time="2019-05-21T13:29:09-07:00" level=warning msg="setupLogging() returned [PUT /logger][400] putLoggerBadRequest  &{FaultMessage:Could not open logging fifo: Failed to open pipe. Error: permission denied}. Continuing anyway."
 time="2019-05-21T13:29:09-07:00" level=debug msg="Running handler fcinit.CreateMachine"                                 
 time="2019-05-21T13:29:09-07:00" level=debug msg="PUT /machine-config HTTP/1.1\r\nHost: localhost\r\nUser-Agent: Go-http-client/1.1\r\nContent-Length: 56\r\nAccept: application/json\r\nContent-Type: application/json\r\nAccept-Encoding: gzip\r\n\r\n{\"cpu_template\":\"T2\",\"mem_size_mib\":256,\"vcpu_count\":2}\n\n"

If I set the UID and GID to the file then it is able to read it. However, I imagine setting the file permission bits to just 0700 should allow ano read it. So that seems a little strange.

[acatangiu]

This works for me on latest code (tested at b922c7d), following recent changes to our jailer and logger.

Closing the issue. Please reopen if are you still experiencing problems.