Created
May 14, 2024 10:05
-
-
Save char-1ee/8fa7342bddf3cee3734178f5c2f13cc3 to your computer and use it in GitHub Desktop.
Firecracker debug logs
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Running Firecracker v1.4.1 | |
| 2024-04-25T08:55:23.499421130 [6:fc_api:INFO] The request was executed successfully. Status code: 204 No Content. | |
| 2024-04-25T08:55:23.499458726 [6:fc_api:DEBUG] Total previous API call duration: 132 us. | |
| 2024-04-25T08:55:23.499687521 [6:fc_api:INFO] The API server received a Put request on "/metrics" with body "{\"metrics_path\":\"/var/lib/firecracker-containerd/shim-base/firecracker-containerd#6/fc-metrics.fifo\"}\n". | |
| 2024-04-25T08:55:23.499730906 [6:fc_api:INFO] The request was executed successfully. Status code: 204 No Content. | |
| 2024-04-25T08:55:23.499739481 [6:fc_api:DEBUG] Total previous API call duration: 57 us. | |
| 2024-04-25T08:55:23.500157496 [6:fc_api:INFO] The API server received a Put request on "/snapshot/load" with body "{\"container_snapshot_path\":\"/dev/mapper/fc-dev-thinpool-snap-11\",\"mem_backend\":{\"backend_path\":\"/fccd/snapshots/2/mem_file\",\"backend_type\":\"File\"},\"resume_vm\":true,\"snapshot_path\":\"/fccd/snapshots/2/snap_file\"}\n". | |
| 2024-04-25T08:55:23.500184109 [6:main:WARN] [DevPreview] Virtual machine snapshots is in development preview. | |
| 2024-04-25T08:55:23.500580370 [6:main:INFO] Snapshot CPU vendor id: [71, 101, 110, 117, 105, 110, 101, 73, 110, 116, 101, 108] | |
| 2024-04-25T08:55:23.500876073 [6:main:DEBUG] ZZZ before create vmm. | |
| 2024-04-25T08:55:23.502978628 [6:main:WARN] Failed to register serial input fd: event_manager: failed to manage epoll file descriptor: Operation not permitted (os error 1) | |
| 2024-04-25T08:55:23.503032775 [6:main:DEBUG] ZZZ before vmm init. | |
| 2024-04-25T08:55:23.503044839 [6:main:DEBUG] ZZZ after vmm init. Returns vmm and vcpus. | |
| 2024-04-25T08:55:23.503054692 [6:main:DEBUG] ZZZ after create vmm. | |
| 2024-04-25T08:55:23.503066059 [6:main:DEBUG] ZZZ before restore state. | |
| 2024-04-25T08:55:23.503103787 [6:main:DEBUG] ZZZ after restore state. | |
| 2024-04-25T08:55:23.503112280 [6:main:DEBUG] ZZ after update config. | |
| 2024-04-25T08:55:23.503120412 [6:main:DEBUG] ZZZ after set boot source. | |
| 2024-04-25T08:55:23.503128551 [6:main:DEBUG] ZZZ after mmiodevman construct. | |
| 2024-04-25T08:55:23.503768878 [6:main:DEBUG] ZZZ after restore device manager. | |
| 2024-04-25T08:55:23.503791193 [6:main:DEBUG] ZZZ after emulate serial init. | |
| 2024-04-25T08:55:23.503927150 [6:main:DEBUG] ZZZ after start vcpu. | |
| 2024-04-25T08:55:23.504340754 [6:main:DEBUG] ZZZ after restore vcpu state. | |
| 2024-04-25T08:55:23.504386949 [6:main:DEBUG] ZZZ after add subs. | |
| 2024-04-25T08:55:23.504729825 [6:main:DEBUG] ZZZ returns vmm from build from snapshot. | |
| 2024-04-25T08:55:23.504761144 [6:main:INFO] Artificially kick devices. | |
| 2024-04-25T08:55:23.504779310 [6:main:INFO] kick net 1. | |
| 2024-04-25T08:55:23.504814993 [6:main:INFO] kick block root_drive. | |
| 2024-04-25T08:55:23.504840693 [6:main:INFO] kick block MN2HE43UOVRDA. | |
| 2024-04-25T08:55:23.504918969 [6:main:WARN] [DevPreview] Virtual machine snapshots is in development preview - 'load snapshot' VMM action took 4714 us. | |
| 2024-04-25T08:55:23.504957602 [6:fc_api:INFO] The request was executed successfully. Status code: 204 No Content. | |
| 2024-04-25T08:55:23.504977543 [6:fc_api:INFO] 'load snapshot' API request took 4829 us. | |
| 2024-04-25T08:55:23.504990819 [6:fc_api:DEBUG] Total previous API call duration: 4843 us. | |
| 2024-04-25T08:55:23.605703572 [6:main:DEBUG] vsock: backend event | |
| 2024-04-25T08:55:23.605737932 [6:main:DEBUG] vsock: muxer received kick | |
| 2024-04-25T08:55:23.605751711 [6:main:DEBUG] vsock: muxer processing event: fd=44, evset=IN | |
| 2024-04-25T08:55:23.605784361 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:23.605797725 [6:main:DEBUG] vsock: backend event | |
| 2024-04-25T08:55:23.605806088 [6:main:DEBUG] vsock: muxer received kick | |
| 2024-04-25T08:55:23.605816599 [6:main:DEBUG] vsock: muxer processing event: fd=51, evset=IN | |
| 2024-04-25T08:55:23.605870258 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:23.605879115 [6:main:DEBUG] vsock: process_rx() | |
| 2024-04-25T08:55:23.605892255 [6:main:DEBUG] vsock muxer: RX pkt: VsockPacketHeader { src_cid: 2, dst_cid: 0, src_port: 1073741824, dst_port: 10789, len: 0, type_: 1, op: 1, flags: 0, buf_alloc: 65536, fwd_cnt: 0 } | |
| 2024-04-25T08:55:23.605926572 [6:main:DEBUG] vsock: raising IRQ | |
| 2024-04-25T08:55:23.606171680 [6:main:DEBUG] vsock: event queue event | |
| 2024-04-25T08:55:23.606265586 [6:main:DEBUG] vsock: TX queue event | |
| 2024-04-25T08:55:23.606276922 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:23.606286154 [6:main:DEBUG] vsock: muxer.send[rxq.len=0]: VsockPacketHeader { src_cid: 0, dst_cid: 2, src_port: 10789, dst_port: 1073741824, len: 0, type_: 1, op: 2, flags: 0, buf_alloc: 262144, fwd_cnt: 0 } | |
| 2024-04-25T08:55:23.606316845 [6:main:DEBUG] vsock: raising IRQ | |
| 2024-04-25T08:55:23.606819648 [6:main:DEBUG] vsock: backend event | |
| 2024-04-25T08:55:23.606842391 [6:main:DEBUG] vsock: muxer received kick | |
| 2024-04-25T08:55:23.606871900 [6:main:DEBUG] vsock: muxer processing event: fd=51, evset=IN | |
| 2024-04-25T08:55:23.606889083 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:23.606901756 [6:main:DEBUG] vsock: process_rx() | |
| 2024-04-25T08:55:23.606936353 [6:main:DEBUG] vsock muxer: RX pkt: VsockPacketHeader { src_cid: 2, dst_cid: 0, src_port: 1073741824, dst_port: 10789, len: 121, type_: 1, op: 5, flags: 0, buf_alloc: 65536, fwd_cnt: 0 } | |
| 2024-04-25T08:55:23.606958558 [6:main:DEBUG] vsock: raising IRQ | |
| 2024-04-25T08:55:23.608491627 [6:fc_api:INFO] The API server received a Patch request on "/vm" with body "{\"state\":\"Resumed\"}\n". | |
| 2024-04-25T08:55:23.608545355 [6:main:INFO] Artificially kick devices. | |
| 2024-04-25T08:55:23.608566437 [6:main:INFO] kick net 1. | |
| 2024-04-25T08:55:23.608579588 [6:main:INFO] kick block root_drive. | |
| 2024-04-25T08:55:23.608590129 [6:main:INFO] kick block MN2HE43UOVRDA. | |
| 2024-04-25T08:55:23.608629027 [6:main:INFO] 'resume vm' VMM action took 84 us. | |
| 2024-04-25T08:55:23.608659060 [6:fc_api:INFO] The request was executed successfully. Status code: 204 No Content. | |
| 2024-04-25T08:55:23.608671096 [6:fc_api:INFO] 'resume vm' API request took 187 us. | |
| 2024-04-25T08:55:23.608684468 [6:fc_api:DEBUG] Total previous API call duration: 200 us. | |
| 2024-04-25T08:55:53.617205420 [6:fc_api:INFO] The API server received a Get request on "/". | |
| 2024-04-25T08:55:53.617324372 [6:fc_api:INFO] The request was executed successfully. Status code: 200 OK. | |
| 2024-04-25T08:55:53.617343650 [6:fc_api:DEBUG] Total previous API call duration: 143 us. | |
| 2024-04-25T08:55:53.617792186 [6:main:DEBUG] vsock: backend event | |
| 2024-04-25T08:55:53.617813874 [6:main:DEBUG] vsock: muxer received kick | |
| 2024-04-25T08:55:53.617824604 [6:main:DEBUG] vsock: muxer processing event: fd=51, evset=IN | |
| 2024-04-25T08:55:53.617834472 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:53.617851832 [6:main:DEBUG] vsock: process_rx() | |
| 2024-04-25T08:55:53.617880619 [6:main:DEBUG] vsock muxer: RX pkt: VsockPacketHeader { src_cid: 2, dst_cid: 0, src_port: 1073741824, dst_port: 10789, len: 112, type_: 1, op: 5, flags: 0, buf_alloc: 65536, fwd_cnt: 0 } | |
| 2024-04-25T08:55:53.617896371 [6:main:DEBUG] vsock: raising IRQ | |
| 2024-04-25T08:55:53.619170610 [6:main:DEBUG] vsock: TX queue event | |
| 2024-04-25T08:55:53.619195077 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:53.619207283 [6:main:DEBUG] vsock: muxer.send[rxq.len=0]: VsockPacketHeader { src_cid: 0, dst_cid: 2, src_port: 10789, dst_port: 1073741824, len: 10, type_: 1, op: 5, flags: 0, buf_alloc: 262144, fwd_cnt: 233 } | |
| 2024-04-25T08:55:53.619243745 [6:main:DEBUG] vsock: raising IRQ | |
| 2024-04-25T08:55:53.626052713 [6:main:DEBUG] vsock: TX queue event | |
| 2024-04-25T08:55:53.626092900 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:53.626102412 [6:main:DEBUG] vsock: muxer.send[rxq.len=0]: VsockPacketHeader { src_cid: 0, dst_cid: 2, src_port: 10789, dst_port: 1073741824, len: 32, type_: 1, op: 5, flags: 0, buf_alloc: 262144, fwd_cnt: 233 } | |
| 2024-04-25T08:55:53.626125370 [6:main:DEBUG] vsock: raising IRQ | |
| 2024-04-25T08:55:53.627327426 [6:main:DEBUG] vsock: TX queue event | |
| 2024-04-25T08:55:53.627352815 [6:main:DEBUG] vsock::process_tx() | |
| 2024-04-25T08:55:53.627371531 [6:main:DEBUG] vsock: muxer.send[rxq.len=0]: VsockPacketHeader { src_cid: 0, dst_cid: 2, src_port: 10789, dst_port: 1073741824, len: 0, type_: 1, op: 4, flags: 3, buf_alloc: 262144, fwd_cnt: 233 } | |
| 2024-04-25T08:55:53.627389227 [6:main:DEBUG] vsock: process_rx() | |
| 2024-04-25T08:55:53.627422645 [6:main:DEBUG] vsock muxer: RX pkt: VsockPacketHeader { src_cid: 2, dst_cid: 0, src_port: 1073741824, dst_port: 10789, len: 0, type_: 1, op: 3, flags: 0, buf_alloc: 65536, fwd_cnt: 42 } | |
| 2024-04-25T08:55:53.627442028 [6:main:DEBUG] vsock: raising IRQ |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment