[ https://issues.apache.org/jira/browse/IGNITE-1648?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Saikat Maitra updated IGNITE-1648: ---------------------------------- Description: --------------------------------------------- DESCRIPTION --------------------------------------------- The key '-t' works incorrectly when it is time to print query events into log - it prints topology snapshot as many times as events are in query. Log become difficult to read --------------------------------------------- STEPS FOR REPRODUCE --------------------------------------------- # Run two nodes in the grid # Run ignitevisorcmd.sh # Connect visor to the grid (open) # Run logging by command, for example: {noformat} log -l -p=30 -t=120 -f=../work/visor/test_log {noformat} # Generate several grid-wide events by, for example, start-stop one more node --------------------------------------------- ACTUAL RESULT --------------------------------------------- There is events query in the log every 30 seconds and topology snapshot every 2 minutes and every 30 seconds before events query logging - as many times as events are in query. Look at the part of log: {noformat} 10/09/15, 16:08:27 | Log started. 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:37 | <visor> => NODE_JOINED: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:38 | <visor> => NODE_LEFT: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:42 | <visor> => NODE_JOINED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:44 | <visor> => NODE_FAILED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:46 | <visor> => NODE_JOINED: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:50 | <visor> => NODE_LEFT: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:54 | <visor> => NODE_JOINED: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:59 | <visor> => NODE_LEFT: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:05 | <visor> => NODE_JOINED: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:09 | <visor> => NODE_LEFT: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_JOINED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_FAILED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:17 | <visor> => NODE_JOINED: id8=e15a193f, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:10:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:12:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:14:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:15:27 | Log stopped. {noformat} --------------------------------------------- EXPECTED RESULT --------------------------------------------- There is events query in the log every 30 seconds and topology snapshot every 2 minutes. Something like this: {noformat} 10/09/15, 16:08:27 | Log started. 10/09/15, 16:08:37 | <visor> => NODE_JOINED: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:38 | <visor> => NODE_LEFT: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:42 | <visor> => NODE_JOINED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:44 | <visor> => NODE_FAILED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:46 | <visor> => NODE_JOINED: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:50 | <visor> => NODE_LEFT: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:54 | <visor> => NODE_JOINED: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:59 | <visor> => NODE_LEFT: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:05 | <visor> => NODE_JOINED: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:09 | <visor> => NODE_LEFT: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_JOINED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_FAILED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:17 | <visor> => NODE_JOINED: id8=e15a193f, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:10:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:12:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:14:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:15:27 | Log stopped. {noformat} was: --------------------------------------------- DESCRIPTION --------------------------------------------- The key '-t' works incorrect when it's time to print querying events into log - it's print topology snapshot as many times as events are in query. Log became difficult to read --------------------------------------------- STEPS FOR REPRODUCE --------------------------------------------- # Run two nodes in the grid # Run ignitevisorcmd.sh # Connect visor to the grid (open) # Run logging by command, for example: {noformat} log -l -p=30 -t=120 -f=../work/visor/test_log {noformat} # Generate several grid-wide events by, for example, start-stop one more node --------------------------------------------- ACTUAL RESULT --------------------------------------------- There is events query in the log every 30 seconds and topology snapshot every 2 minutes and every 30 seconds before events query logging - as many times as events are in query. Look at the part of log: {noformat} 10/09/15, 16:08:27 | Log started. 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:37 | <visor> => NODE_JOINED: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:38 | <visor> => NODE_LEFT: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:42 | <visor> => NODE_JOINED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:44 | <visor> => NODE_FAILED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:46 | <visor> => NODE_JOINED: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:50 | <visor> => NODE_LEFT: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:54 | <visor> => NODE_JOINED: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:08:59 | <visor> => NODE_LEFT: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:05 | <visor> => NODE_JOINED: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:09 | <visor> => NODE_LEFT: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_JOINED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_FAILED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:17 | <visor> => NODE_JOINED: id8=e15a193f, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:10:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:12:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:14:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:15:27 | Log stopped. {noformat} --------------------------------------------- EXPECTED RESULT --------------------------------------------- There is events query in the log every 30 seconds and topology snapshot every 2 minutes. Something like this: {noformat} 10/09/15, 16:08:27 | Log started. 10/09/15, 16:08:37 | <visor> => NODE_JOINED: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:38 | <visor> => NODE_LEFT: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:42 | <visor> => NODE_JOINED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:44 | <visor> => NODE_FAILED: id8=b732d4c2, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:46 | <visor> => NODE_JOINED: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:50 | <visor> => NODE_LEFT: id8=52265274, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:54 | <visor> => NODE_JOINED: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:08:59 | <visor> => NODE_LEFT: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:05 | <visor> => NODE_JOINED: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:09 | <visor> => NODE_LEFT: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_JOINED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:13 | <visor> => NODE_FAILED: id8=ef2c76f7, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:09:17 | <visor> => NODE_JOINED: id8=e15a193f, ip=0:0:0:0:0:0:0:1%1 10/09/15, 16:10:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:12:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:14:27 | H/N/C|1 |2 |8 |^...................| 10/09/15, 16:15:27 | Log stopped. {noformat} > ignitevisorcmd: key "-t" for command "log" works incorrect > ---------------------------------------------------------- > > Key: IGNITE-1648 > URL: https://issues.apache.org/jira/browse/IGNITE-1648 > Project: Ignite > Issue Type: Bug > Components: general > Affects Versions: 1.5.0.final > Environment: Ubuntu 14.04, Apache-Ignite-1.5.0 build #29 > Reporter: Vasilisa Sidorova > Priority: Minor > Fix For: 1.8 > > > --------------------------------------------- > DESCRIPTION > --------------------------------------------- > The key '-t' works incorrectly when it is time to print query events into log > - it prints topology snapshot as many times as events are in query. Log > become difficult to read > --------------------------------------------- > STEPS FOR REPRODUCE > --------------------------------------------- > # Run two nodes in the grid > # Run ignitevisorcmd.sh > # Connect visor to the grid (open) > # Run logging by command, for example: > {noformat} > log -l -p=30 -t=120 -f=../work/visor/test_log > {noformat} > # Generate several grid-wide events by, for example, start-stop one more node > --------------------------------------------- > ACTUAL RESULT > --------------------------------------------- > There is events query in the log every 30 seconds and topology snapshot > every 2 minutes and every 30 seconds before events query logging - as many > times as events are in query. Look at the part of log: > {noformat} > 10/09/15, 16:08:27 | Log started. > 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:57 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:37 | <visor> => NODE_JOINED: id8=85d6f860, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:38 | <visor> => NODE_LEFT: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:42 | <visor> => NODE_JOINED: id8=b732d4c2, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:44 | <visor> => NODE_FAILED: id8=b732d4c2, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:46 | <visor> => NODE_JOINED: id8=52265274, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:50 | <visor> => NODE_LEFT: id8=52265274, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:54 | <visor> => NODE_JOINED: id8=12b6eaf9, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:09:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:08:59 | <visor> => NODE_LEFT: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:05 | <visor> => NODE_JOINED: id8=1666d860, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:09 | <visor> => NODE_LEFT: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:13 | <visor> => NODE_JOINED: id8=ef2c76f7, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:13 | <visor> => NODE_FAILED: id8=ef2c76f7, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:17 | <visor> => NODE_JOINED: id8=e15a193f, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:10:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:12:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:14:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:15:27 | Log stopped. > {noformat} > --------------------------------------------- > EXPECTED RESULT > --------------------------------------------- > There is events query in the log every 30 seconds and topology snapshot > every 2 minutes. Something like this: > {noformat} > 10/09/15, 16:08:27 | Log started. > 10/09/15, 16:08:37 | <visor> => NODE_JOINED: id8=85d6f860, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:38 | <visor> => NODE_LEFT: id8=85d6f860, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:42 | <visor> => NODE_JOINED: id8=b732d4c2, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:44 | <visor> => NODE_FAILED: id8=b732d4c2, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:46 | <visor> => NODE_JOINED: id8=52265274, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:50 | <visor> => NODE_LEFT: id8=52265274, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:54 | <visor> => NODE_JOINED: id8=12b6eaf9, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:08:59 | <visor> => NODE_LEFT: id8=12b6eaf9, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:05 | <visor> => NODE_JOINED: id8=1666d860, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:09 | <visor> => NODE_LEFT: id8=1666d860, ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:13 | <visor> => NODE_JOINED: id8=ef2c76f7, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:13 | <visor> => NODE_FAILED: id8=ef2c76f7, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:09:17 | <visor> => NODE_JOINED: id8=e15a193f, > ip=0:0:0:0:0:0:0:1%1 > 10/09/15, 16:10:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:12:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:14:27 | H/N/C|1 |2 |8 |^...................| > 10/09/15, 16:15:27 | Log stopped. > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)