| 2 | | |
| 3 | | |
| 4 | | Replying to [comment:10 socratis]: |
| 5 | | > You posted the comment in your duplicate ticket #18474, but I thought it would be better to reply here. |
| 6 | | > |
| 7 | | > Replying to [https://www.virtualbox.org/ticket/18474#comment:3 数组越界]: |
| 8 | | > > ''The problem is that if I used the following command'' |
| 9 | | > > {{{ |
| 10 | | > > VBoxManage debugvm "vm name" logflags --release time |
| 11 | | > > }}} |
| 12 | | > > ''In logs there is only time instead of date and time, since our vms have run a quite long time, I need to find out what happened inside release log when guest restarted.'' |
| 13 | | > |
| 14 | | > According to the User Manual, ch. [https://www.virtualbox.org/manual/ch08.html#vboxmanage-debugvm 8.42 VBoxManage debugvm]: |
| 15 | | > {{{ |
| 16 | | > VBoxManage debugvm <uuid|vmname> logflags [[--release] | [--debug]] [flags...] |
| 17 | | > }}} |
| 18 | | > and in the "`flags`" section, I can see: |
| 19 | | > > `time` |
| 20 | | > > Prefix each log line with the current UTC wall '''time'''. |
| 21 | | > My understanding is that you want the '''date''' as well. \\ |
| 22 | | > \\ |
| 23 | | > \\ |
| 24 | | > I entered the following command: |
| 25 | | > {{{ |
| 26 | | > VBoxManage startvm <VM>; VBoxManage debugvm <VM> logflags --release time |
| 27 | | > }}} |
| 28 | | > and although it doesn't start the time logging from the get-go, in my log I see the following: |
| 29 | | > |
| 30 | | > `00:00:00.918239 VirtualBox VM 6.0.97 r129161 darwin.amd64 (Mar 4 2019 14:44:21) ...` \\ |
| 31 | | > `00:00:00.918243 Log opened `'''__`2019-03-06T07:57:11.964346000Z`__''' \\ |
| 32 | | > `...` \\ |
| 33 | | > `00:00:01.062177 ******************* End of VT-x features ********************` \\ |
| 34 | | > `00:00:01.062192 VMEmt: Halt method global1 (5)` \\ |
| 35 | | > `00:00:01.062261 VMEmt: HaltedGlobal1 config: cNsSpinBlockThresholdCfg=2000` \\ |
| 36 | | > `00:00:01.062267 Changing the VM state from 'CREATING' to 'CREATED'` \\ |
| 37 | | > `00:00:01.067689 Changing the VM state from 'CREATED' to 'POWERING_ON'` \\ |
| 38 | | > `00:00:01.067754 Changing the VM state from 'POWERING_ON' to 'RUNNING'` \\ |
| 39 | | > `00:00:01.067772 Console: Machine state changed to 'Running'` \\ |
| 40 | | > `00:00:01.070337 VMMDev: Guest Log: BIOS: VirtualBox 6.0.97` \\ |
| 41 | | > `00:00:01.070472 PCI: Setting up resources and interrupts` \\ |
| 42 | | > `00:00:01.070876 PIT: mode=2 count=0x10000 (65536) - 18.20 Hz (ch=0)` \\ |
| 43 | | > `00:00:01.084837 Display::handleDisplayResize: uScreenId=0 ...` \\ |
| 44 | | > `00:00:01.084900 GUI: UIFrameBufferPrivate::NotifyChange: ...` \\ |
| 45 | | > `00:00:01.085589 VMMDev: Guest Log: CPUID EDX: 0x178bfbbf` \\ |
| 46 | | > `00:00:01.085638 PIIX3 ATA: Ctl#0: RESET, DevSel=0 AIOIf=0 ...` \\ |
| 47 | | > `00:00:01.085694 PIIX3 ATA: Ctl#0: finished processing RESET` \\ |
| 48 | | > `00:00:01.086284 VMMDev: Guest Log: BIOS: ata0-0: ...` \\ |
| 49 | | > `00:00:01.086977 PIIX3 ATA: Ctl#0: RESET, DevSel=1 AIOIf=0 ...` \\ |
| 50 | | > `00:00:01.087026 PIIX3 ATA: Ctl#0: finished processing RESET` \\ |
| 51 | | > `00:00:01.087132 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 ...` \\ |
| 52 | | > `00:00:01.087192 PIIX3 ATA: Ctl#1: finished processing RESET` \\ |
| 53 | | > `00:00:01.090711 PIT: mode=2 count=0x48d3 (18643) - 64.00 Hz (ch=0)` \\ |
| 54 | | > `00:00:01.106529 Display::handleDisplayResize: uScreenId=0 ...` \\ |
| 55 | | > `00:00:01.106579 GUI: UIFrameBufferPrivate::NotifyChange: ...` \\ |
| 56 | | > '''__`07:57:12.619070`__''' `00:00:01.572977 GUI: UIMachineViewNormal::resendSizeHint...` \\ |
| 57 | | > '''__`07:57:12.619126`__''' ` 00:00:01.573031 VMMDev: SetVideoModeHint: ...` \\ |
| 58 | | > '''__`07:57:12.619155`__''' ` 00:00:01.573061 GUI: UIMachineView::sltHandleNotifyChange:...` \\ |
| 59 | | > `...` \\ |
| 60 | | > |
| 61 | | > So, after the "`00:00:01.106579`" time mark, the UTC time is prepended to the relative time i the log. |
| 62 | | > |
| 63 | | > A couple (maybe more) year ago I remember seeing a VBox.log where the UTC time was logged from the first line, I asked, never got an answer, and I never bothered to look how it was done. |
| 64 | | > |
| 65 | | > Now, you can combine the log start time (the 2nd line in any log) with the time and get something meaningful? |
| 66 | | > |
| 67 | | > My understanding is that you are proposing this: |
| 68 | | > |
| 69 | | > `...` \\ |
| 70 | | > `00:00:01.106579 GUI: UIFrameBufferPrivate::NotifyChange: ...` \\ |
| 71 | | > '''__`2019-03-06T07:57:12.619070`__''' `00:00:01.572977 GUI: UIMachineViewNormal::resendSizeHint...` \\ |
| 72 | | > '''__`2019-03-06T07:57:12.619126`__''' ` 00:00:01.573031 VMMDev: SetVideoModeHint: ...` \\ |
| 73 | | > '''__`2019-03-06T07:57:12.619155`__''' ` 00:00:01.573061 GUI: UIMachineView::sltHandleNotifyChange:...` \\ |
| 74 | | > `...` |
| 75 | | > |
| 76 | | > Right? |