RE: [smartos-discuss] rotate-kvm-log

[Fred Liu]

> 
> Hi Fred,
> 
> That'll only be true if the KVM VM is never booted. Whenever it is booted, the
> file will be non-empty until it is rotated since there are always messages
> written to the log when a KVM VM boots.
> 

 All of my KVM VMs are definitely running now.  I think
It came from the 'copytruncate' by "logadm -c". Once rotate-kvm-logs.sh ends,
all the non-empty vm.log files are rotating into "/var/log/sdc/upload/qemu-xxx".
And if rotate-kvm-log.sh runs again, no new entry will be generated.

 
> 
> 
>   Plus, I also notice that there is logadm invocation during "vmadm 
> create"
> in lines from #625 to #641 of source
> (https://github.com/joyent/smartos-live/blob/64998c0b5a7c33287eb7dd118fef
> 4aea42e5a6f3/src/vm/sbin/vmadmd.js#L625
>  f4aea42e5a6f3/src/vm/sbin/vmadmd.js#L625> ) --
> 
> 
> 
> 
> You're right. I had forgotten about this code in vmadmd. I had looked only at
> vmadm.
> 
> I don't see how this changes anything though. Because it's still the
> rotate-kvm-logs.sh that it's calling to do the rotation. The same thing would
> have happened at the first cron execution after this if vmadmd didn't do it.
> 
> Since it seems that fixing the bug in logadm that causes this problem might be
> a while still in coming, I will look into the prospect of adding a workaround 
> that
> runs:
> 
> logadm -r /zones//root/tmp/vm.log
> 
> when deleting a KVM VM, or in the rotate-kvm-logs.sh itself when it sees a VM
> no longer exists. I've filed https://smartos.org/bugview/OS-6053 to look into
> this.

From my side, the intuitive and direct way is removing the entry by "vmadm 
destroy".
We can also add the similar cose in vmadmd source.


Thanks.

Fred


---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

Re: [smartos-discuss] rotate-kvm-log

[Josh Wilsdon]

>
>
> The reason why I haven't got the concerning entry is lines from  #36 to
> #38 of the source (https://github.com/joyent/smartos-live/blob/
> 64998c0b5a7c33287eb7dd118fef4aea42e5a6f3/src/vm/sbin/rotate-
> kvm-logs.sh#L36) --
>
> "
>  if [[ ! -s ${logfile} ]]; then
> # file doesn't exist or is empty
> return;
> fi
> ".
>
> Because all my ${logfile} has size of 0,   rotate_log() returns.
> And the script won't go to lines from #72 to #78(
> https://github.com/joyent/smartos-live/blob/64998c0b5a7c33287eb7dd118fef4a
> ea42e5a6f3/src/vm/sbin/rotate-kvm-logs.sh#L72) --
>
>
Hi Fred,

That'll only be true if the KVM VM is never booted. Whenever it is booted,
the file will be non-empty until it is rotated since there are always
messages written to the log when a KVM VM boots.



> Plus, I also notice that there is logadm invocation during "vmadm create"
> in lines from #625 to #641 of source (https://github.com/joyent/
> smartos-live/blob/64998c0b5a7c33287eb7dd118fef4a
> ea42e5a6f3/src/vm/sbin/vmadmd.js#L625) --
>
>
You're right. I had forgotten about this code in vmadmd. I had looked only
at vmadm.

I don't see how this changes anything though. Because it's still the
rotate-kvm-logs.sh
that it's calling to do the rotation. The same thing would have happened at
the first cron execution after this if vmadmd didn't do it.

Since it seems that fixing the bug in logadm that causes this problem might
be a while still in coming, I will look into the prospect of adding a
workaround that runs:

logadm -r /zones//root/tmp/vm.log

when deleting a KVM VM, or in the rotate-kvm-logs.sh itself when it sees a
VM no longer exists. I've filed https://smartos.org/bugview/OS-6053 to look
into this.

Thanks,
Josh



---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

RE: [smartos-discuss] rotate-kvm-log

[Fred Liu]

>From: Josh Wilsdon [mailto:jwils...@joyent.com] 
>Sent: 星期三, 四月 12, 2017 0:25
>To: smartos-discuss@lists.smartos.org
>Subject: Re: [smartos-discuss] rotate-kvm-log


>Yes. But "/usr/vm/sbin/rotate-kvm-logs.sh script" won't add entries in 
>"/var/logadm/timestamps" like following:
 
>"/zones/c3f09892-f36e-4784-9853-b4ceb3e762da/root/tmp/vm.log -P 'Wed Jan  4 
>05:20:15 2017'"

>The weirdness is how this type of entry has been added per every kvm instance?

>Fred,

>That's exactly what the entries look like that come from running 
>rotate-kvm-logs.sh. What evidence do you have that it's not that script? When 
>I manually ran rotate-kvm-logs.sh without any cron involved, it just generated 
>an entry:

>/zones/3d93a436-3a86-4406-ae69-fbaaf67b45b7/root/tmp/vm.log -P 'Tue Apr 11 
>16:20:40 2017'

Josh,

I think I see exactly the same issue 
(https://github.com/joyent/smartos-live/issues/319).
The reason why I haven't got the concerning entry is lines from  #36 to #38 of 
the source 
(https://github.com/joyent/smartos-live/blob/64998c0b5a7c33287eb7dd118fef4aea42e5a6f3/src/vm/sbin/rotate-kvm-logs.sh#L36)
 -- 

"
 if [[ ! -s ${logfile} ]]; then
# file doesn't exist or is empty
return;
fi
".

Because all my ${logfile} has size of 0,   rotate_log() returns.
And the script won't go to lines from #72 to 
#78(https://github.com/joyent/smartos-live/blob/64998c0b5a7c33287eb7dd118fef4aea42e5a6f3/src/vm/sbin/rotate-kvm-logs.sh#L72)
 -- 

"
logadm \
-c \
-s 1b \
-p now \
-t '$dirname/vm.log.rotating' \
-R "cat \$file >> ${destfile} && rm -f \$file" \
${logfile}
"

Plus, I also notice that there is logadm invocation during "vmadm create" in 
lines from #625 to #641 of source 
(https://github.com/joyent/smartos-live/blob/64998c0b5a7c33287eb7dd118fef4aea42e5a6f3/src/vm/sbin/vmadmd.js#L625)
 --

"
unction rotateKVMLog(vm_uuid)
{
setTimeout(function () {
execFile('/usr/vm/sbin/rotate-kvm-logs.sh', [vm_uuid],
function (error, stdout, stderr) {
if (error) {
log.error({err: error, stdout: stdout, stderr: stderr},
'failed to rotate kvm log for just-booted ' + vm_uuid);
return;
}
log.debug({stdout: stdout, stderr: stderr}, 'rotated kvm log '
+ 'for just-booted ' + vm_uuid);
return;
}
);
}, 30 * 1000);
}

"

Thanks.

Fred


---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

Re: [smartos-discuss] rotate-kvm-log

[Josh Wilsdon]

>
>
> Yes. But "/usr/vm/sbin/rotate-kvm-logs.sh script" won't add entries in
> "/var/logadm/timestamps" like following:
>


"/zones/c3f09892-f36e-4784-9853-b4ceb3e762da/root/tmp/vm.log -P 'Wed Jan  4
> 05:20:15 2017'"
>
> The weirdness is how this type of entry has been added per every kvm
> instance?
>

Fred,

That's exactly what the entries look like that come from running
rotate-kvm-logs.sh. What evidence do you have that it's not that script?
When I manually ran rotate-kvm-logs.sh without any cron involved, it just
generated an entry:

/zones/3d93a436-3a86-4406-ae69-fbaaf67b45b7/root/tmp/vm.log -P 'Tue Apr 11
16:20:40 2017'

Thanks,
Josh



---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

RE: [smartos-discuss] rotate-kvm-log

[Fred Liu]

>From: Josh Wilsdon [mailto:jwils...@joyent.com] 
>It doesn't go in logadm.conf. The rotation happens via the 
>/usr/vm/sbin/rotate-kvm-logs.sh script which is run by root's crontab in the 
>GZ.

Yes. But "/usr/vm/sbin/rotate-kvm-logs.sh script" won't add entries in 
"/var/logadm/timestamps" like following:

"/zones/c3f09892-f36e-4784-9853-b4ceb3e762da/root/tmp/vm.log -P 'Wed Jan  4 
05:20:15 2017'"

The weirdness is how this type of entry has been added per every kvm instance?


Thanks.

Fred





---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

Re: [smartos-discuss] rotate-kvm-log

[Josh Wilsdon]

> But there is  nothing about rotate-kvm-log in /etc/logadm.conf from stock.
> It is weird. How were these entries had been added in time stamp? It should
> be logadm command invoking. But where was it invoked? I haven't done it
> manually.
>
>
It doesn't go in logadm.conf. The rotation happens via
the /usr/vm/sbin/rotate-kvm-logs.sh script which is run by root's crontab
in the GZ.

Josh



---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

Re: [smartos-discuss] rotate-kvm-log

[Fred Liu]

But there is  nothing about rotate-kvm-log in /etc/logadm.conf from stock. It 
is weird. How were these entries had been added in time stamp? It should be 
logadm command invoking. But where was it invoked? I haven't done it manually.


Fred

Get Outlook for iOS



On Tue, Apr 11, 2017 at 3:52 AM +0800, "Josh Wilsdon" 
> wrote:


I am running joyent_20161013T025521Z now. It seems in this version 
rotate-kvm-log is done by cron not logadm.
But I also noticed when a kvm instance was created there was a corresponding 
entry occurred in /var/logadm/timestamp like following:
"/zones/c3f09892-f36e-4784-9853-b4ceb3e762da/root/tmp/vm.log -P 'Wed Jan  4 
05:20:15 2017'". Is this from the "vmadm create" operation?

And it looks because of this bug(https://smartos.org/bugview/OS-3097), if the 
kvm instance is destroyed, the corresponding logadm action won't be removed.


Hi Fred,

Using "vmadm create" does not do anything with log rotation, neither does 
"vmadm delete", but what you're seeing there does look like what ends up 
happening due to this logadm bug.

Thanks,
Josh
smartos-discuss | Archives 
[https://www.listbox.com/images/feed-icon-10x10.jpg96494be.jpg?uri=aHR0cHM6Ly93d3cubGlzdGJveC5jb20vaW1hZ2VzL2ZlZWQtaWNvbi0xMHgxMC5qcGc]
   | 
Modify Your Subscription   
[https://www.listbox.com/images/listbox-logo-small.png96494be.png?uri=aHR0cHM6Ly93d3cubGlzdGJveC5jb20vaW1hZ2VzL2xpc3Rib3gtbG9nby1zbWFsbC5wbmc]
 



---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

Re: [smartos-discuss] rotate-kvm-log

[Josh Wilsdon]

>
>
> I am running joyent_20161013T025521Z now. It seems in this version
> rotate-kvm-log is done by cron not logadm.
> But I also noticed when a kvm instance was created there was a
> corresponding entry occurred in /var/logadm/timestamp like following:
> "/zones/c3f09892-f36e-4784-9853-b4ceb3e762da/root/tmp/vm.log -P 'Wed Jan
> 4 05:20:15 2017'". Is this from the "vmadm create" operation?
>
> And it looks because of this bug(https://smartos.org/bugview/OS-3097), if
> the kvm instance is destroyed, the corresponding logadm action won't be
> removed.
>
>
Hi Fred,

Using "vmadm create" does not do anything with log rotation, neither does
"vmadm delete", but what you're seeing there does look like what ends up
happening due to this logadm bug.

Thanks,
Josh



---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

[smartos-discuss] rotate-kvm-log

[Fred Liu]

Hi,

I am running joyent_20161013T025521Z now. It seems in this version 
rotate-kvm-log is done by cron not logadm.
But I also noticed when a kvm instance was created there was a corresponding 
entry occurred in /var/logadm/timestamp like following:
"/zones/c3f09892-f36e-4784-9853-b4ceb3e762da/root/tmp/vm.log -P 'Wed Jan  4 
05:20:15 2017'". Is this from the "vmadm create" operation?

And it looks because of this bug(https://smartos.org/bugview/OS-3097), if the 
kvm instance is destroyed, the corresponding logadm action won't be removed.

Thanks.

Fred


---
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com