Skip to content

Conversation

@DaanHoogland
Copy link
Contributor

Description

A formatting of log messages bug that slipped through the cracks.

Types of changes

  • Breaking change (fix or feature that would cause existing functionality to change)
  • New feature (non-breaking change which adds functionality)
  • Bug fix (non-breaking change which fixes an issue)
  • Enhancement (improves an existing feature and functionality)
  • Cleanup (Code refactoring and cleanup, that may add test cases)

Screenshots (if appropriate):

How Has This Been Tested?

tested formatting is right in cli java

@DaanHoogland
Copy link
Contributor Author

@blueorangutan package

@blueorangutan
Copy link

@DaanHoogland a Jenkins job has been kicked to build packages. I'll keep you posted as I make progress.

Copy link
Contributor

@nvazquez nvazquez left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

Copy link
Contributor

@anuragaw anuragaw left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM from code. Haven't tested though.

@blueorangutan
Copy link

Packaging result: ✖centos6 ✔centos7 ✔debian. JID-581

@andrijapanicsb andrijapanicsb modified the milestones: 4.14.0.0, 4.13.1.0 Jan 13, 2020
@andrijapanicsb
Copy link
Contributor

andrijapanicsb commented Jan 13, 2020

Issue before fixing (visible while creating a new VPC VR):

2020-01-13 17:03:09,321 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgentCronJob-410:ctx-79fe5a35) (logid:b4b46ea5) Ping from 1(10.2.2.136)
2020-01-13 17:03:09,321 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-410:ctx-79fe5a35) (logid:b4b46ea5) Process host VM state report from ping process. host: 1
2020-01-13 17:03:09,321 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-410:ctx-79fe5a35) (logid:b4b46ea5) Process VM state report. host: 1, number of records in report: 0
2020-01-13 17:03:09,323 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-410:ctx-79fe5a35) (logid:b4b46ea5) Run missing VM report. current time: 1578934989323
2020-01-13 17:03:09,324 WARN [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-410:ctx-79fe5a35) (logid:b4b46ea5) VM power state update time is null, falling back to update time for vm id: 4
2020-01-13 17:03:09,325 WARN [c.c.a.m.DirectAgentAttache] (DirectAgentCronJob-410:ctx-79fe5a35) (logid:b4b46ea5) Unable to complete the ping task
java.util.UnknownFormatConversionException: Conversion = 'l'
at java.util.Formatter$FormatSpecifier.conversion(Formatter.java:2691)
at java.util.Formatter$FormatSpecifier.(Formatter.java:2720)
at java.util.Formatter.parse(Formatter.java:2560)
at java.util.Formatter.format(Formatter.java:2501)
at java.util.Formatter.format(Formatter.java:2455)
at java.lang.String.format(String.java:2940)
at com.cloud.vm.VirtualMachinePowerStateSyncImpl.processReport(VirtualMachinePowerStateSyncImpl.java:141)
at com.cloud.vm.VirtualMachinePowerStateSyncImpl.processHostVmStatePingReport(VirtualMachinePowerStateSyncImpl.java:66)
at com.cloud.vm.VirtualMachineManagerImpl.processCommands(VirtualMachineManagerImpl.java:3245)
at com.cloud.agent.manager.AgentManagerImpl.handleCommands(AgentManagerImpl.java:309)
at com.cloud.agent.manager.DirectAgentAttache$PingTask.runInContext(DirectAgentAttache.java:192)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)

@andrijapanicsb
Copy link
Contributor

Logs after the fix:

2020-01-13 17:16:05,817 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) Ping from 1(10.2.2.136)
2020-01-13 17:16:05,817 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) Process host VM state report from ping process. host: 1
2020-01-13 17:16:05,821 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) Unable to find matched VM in CloudStack DB. name: b8809d418a063b0bbdfb12912e68923c
2020-01-13 17:16:05,822 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) Process VM state report. host: 1, number of records in report: 1
2020-01-13 17:16:05,822 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) VM state report. host: 1, vm id: 5, power state: PowerOn
2020-01-13 17:16:05,829 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) VM state report is updated. host: 1, vm id: 5, power state: PowerOn
2020-01-13 17:16:05,832 INFO [c.c.v.VirtualMachineManagerImpl] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) There is pending job or HA tasks working on the VM. vm id: 5, postpone power-change report by resetting power-change counters
2020-01-13 17:16:05,839 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-10:ctx-57f6d3f6) (logid:c638f6a6) Done with process of VM state report. host: 1

@andrijapanicsb
Copy link
Contributor

LGTM

Tested by updating the problematic master env.

@andrijapanicsb
Copy link
Contributor

@blueorangutan help

@andrijapanicsb
Copy link
Contributor

@blueorangutan test centos7 vmware-65u2

@blueorangutan
Copy link

@andrijapanicsb a Trillian-Jenkins test job (centos7 mgmt + vmware-65u2) has been kicked to run smoke tests

@apache apache deleted a comment from blueorangutan Jan 13, 2020
Copy link
Member

@yadvr yadvr left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, I had actually fixed this in the jdk11 PR #3601

@DaanHoogland DaanHoogland changed the base branch from master to 4.13 January 14, 2020 09:37
@DaanHoogland DaanHoogland reopened this Jan 14, 2020
@blueorangutan
Copy link

Trillian test result (tid-768)
Environment: vmware-65u2 (x2), Advanced Networking with Mgmt server 7
Total time taken: 45954 seconds
Marvin logs: https://github.com/blueorangutan/acs-prs/releases/download/trillian/pr3806-t768-vmware-65u2.zip
Intermittent failure detected: /marvin/tests/smoke/test_templates.py
Intermittent failure detected: /marvin/tests/smoke/test_vpc_redundant.py
Smoke tests completed. 78 look OK, 0 have error(s)
Only failed tests results shown below:

Test Result Time (s) Test File

@DaanHoogland DaanHoogland reopened this Jan 15, 2020
@DaanHoogland DaanHoogland merged commit 8ef10c0 into apache:4.13 Jan 15, 2020
@DaanHoogland DaanHoogland deleted the logFormatError branch January 15, 2020 14:31
ustcweizhou pushed a commit to ustcweizhou/cloudstack that referenced this pull request Feb 28, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

7 participants