Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

-d and -D are not working as expected in tt #219

Closed
1 task done
Hearen opened this issue Oct 11, 2018 · 5 comments
Closed
1 task done

-d and -D are not working as expected in tt #219

Hearen opened this issue Oct 11, 2018 · 5 comments
Milestone

Comments

@Hearen
Copy link
Contributor

Hearen commented Oct 11, 2018

  • I have searched the issues of this repository and believe that this is not a duplicate.

Environment

  • Arthas version: 3.0.5.2018101114330
  • Operating System version: ubuntu 16.04
  • Java version of target JVM: jdk1.8.0_144
  • Java version of JVM used to attach: jdk1.8.0_144

Steps to reproduce this issue

    1. follow this to create the demo first: https://github.com/Hearen/arthas/blob/doc-with-consistent-demo/site/src/site/sphinx/en/quick-start.md
$ bin/as.sh

$ 3 # select the demo

$ tt -t -n 3 *Demo addTwoLists
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 54 ms.
 INDEX        TIMESTAMP                      COST(ms)        IS-RET      IS-EXP       OBJECT                  CLASS                                          METHOD                                        
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000         2018-10-11 19:21:58            1.930901        true        false        NULL                    Demo                                           addTwoLists                                   
 1001         2018-10-11 19:21:58            0.096511        true        false        NULL                    Demo                                           addTwoLists                                   
 1002         2018-10-11 19:21:58            0.09073         true        false        NULL                    Demo                                           addTwoLists                                   
Command execution times exceed limit: 3, so command will exit. You can set it with -n option.
$ tt -l
 INDEX        TIMESTAMP                      COST(ms)        IS-RET      IS-EXP       OBJECT                  CLASS                                          METHOD                                        
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000         2018-10-11 19:21:58            1.930901        true        false        NULL                    Demo                                           addTwoLists                                   
 1001         2018-10-11 19:21:58            0.096511        true        false        NULL                    Demo                                           addTwoLists                                   
 1002         2018-10-11 19:21:58            0.09073         true        false        NULL                    Demo                                           addTwoLists                                   
Affect(row-cnt:3) cost in 3 ms.
$ tt -D
Error during processing the command: Time fragment index is expected, please type -i to specify

Expected Result

delete all recorded items

Actual Result

$ tt -D
Error during processing the command: Time fragment index is expected, please type -i to specify

F.Y.I

01 2018-10-11 19:22:03.551 ERROR [as-command-execute-daemon:arthas] [] [] [] Error during processing the command:
java.lang.IllegalArgumentException: Time fragment index is expected, please type -i to specify
        at com.taobao.arthas.core.command.monitor200.TimeTunnelCommand.checkArguments(TimeTunnelCommand.java:209) ~[arthas-core.jar:3.0.5-SNAPSHOT]
        at com.taobao.arthas.core.command.monitor200.TimeTunnelCommand.process(TimeTunnelCommand.java:241) ~[arthas-core.jar:3.0.5-SNAPSHOT]
        at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82) ~[arthas-core.jar:3.0.5-SNAPSHOT]
        at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18) ~[arthas-core.jar:3.0.5-SNAPSHOT]
        at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111) ~[arthas-core.jar:3.0.5-SNAPSHOT]
        at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108) ~[arthas-core.jar:3.0.5-SNAPSHOT]
        at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:370) ~[arthas-core.jar:3.0.5-SNAPSHOT]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_144]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_144]
        at java.lang.Thread.run(Thread.java:748) [na:1.8.0_144]

This was referenced Oct 11, 2018
@Hearen
Copy link
Contributor Author

Hearen commented Oct 11, 2018

@ralf0131 @hengyunabc You can check this #220 branch.

Open another terminal, tracking the realtime log via tail -n 100 -f ~/logs/arthas/arthas.log

And then re-produce it as:

create a demo following: https://github.com/Hearen/arthas/blob/doc-with-consistent-demo/site/src/site/sphinx/en/quick-start.md

$ ./as-package.sh 

$ bin/as.sh 

1 # select demo/Demo

$ tt -t -n 3 *Demo addTwoLists
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 81 ms.                                                                                                                       INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000       2018-10-11 22:46:03       0.98869      true       false     NULL                Demo                                   addTwoLists                            
 1001       2018-10-11 22:46:03       0.124341     true       false     NULL                Demo                                   addTwoLists                            
 1002       2018-10-11 22:46:03       0.092858     true       false     NULL                Demo                                   addTwoLists                            
Command execution times exceed limit: 3, so command will exit. You can set it with -n option.
$ tt -l
 INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000       2018-10-11 22:46:03       0.98869      true       false     NULL                Demo                                   addTwoLists                            
 1001       2018-10-11 22:46:03       0.124341     true       false     NULL                Demo                                   addTwoLists                            
 1002       2018-10-11 22:46:03       0.092858     true       false     NULL                Demo                                   addTwoLists                            
Affect(row-cnt:3) cost in 1 ms.
$ tt -d -i 1000
Time fragments are cleaned.
Affect(row-cnt:3) cost in 0 ms.
$ tt -l
 INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
Affect(row-cnt:0) cost in 1 ms.
$ tt -t -n 3 *Demo addTwoLists
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 31 ms.
 INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1003       2018-10-11 22:46:33       0.136757     true       false     NULL                Demo                                   addTwoLists                            
 1004       2018-10-11 22:46:33       0.092886     true       false     NULL                Demo                                   addTwoLists                            
 1005       2018-10-11 22:46:33       0.08088      true       false     NULL                Demo                                   addTwoLists                            
Command execution times exceed limit: 3, so command will exit. You can set it with -n option.
$ tt -D
Time fragments are cleaned.
Affect(row-cnt:3) cost in 1 ms.

the log

01 2018-10-11 22:45:58.959 INFO [as-command-execute-daemon:arthas] [] [] [] isDelete: false, isDeleteAll: false
01 2018-10-11 22:45:59.044 INFO [as-command-execute-daemon:arthas] [] [] [] Success to batch transform classes: [class demo.Demo]
01 2018-10-11 22:46:06.079 INFO [as-command-execute-daemon:arthas] [] [] [] isDelete: false, isDeleteAll: false
01 2018-10-11 22:46:17.994 INFO [as-command-execute-daemon:arthas] [] [] [] isDelete: false, isDeleteAll: true
01 2018-10-11 22:46:25.475 INFO [as-command-execute-daemon:arthas] [] [] [] isDelete: false, isDeleteAll: false
01 2018-10-11 22:46:32.936 INFO [as-command-execute-daemon:arthas] [] [] [] isDelete: false, isDeleteAll: false
01 2018-10-11 22:46:32.965 INFO [as-command-execute-daemon:arthas] [] [] [] Success to batch transform classes: [class demo.Demo]
01 2018-10-11 22:46:36.689 INFO [as-command-execute-daemon:arthas] [] [] [] isDelete: false, isDeleteAll: true

@Hearen
Copy link
Contributor Author

Hearen commented Oct 11, 2018

But if I replaced -D with -Q in this #221 I will get it to work as expected -d just delete indexed record and -Q delete all as:

$ tt -t -n 3 *Demo addTwoLists
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 26 ms.
 INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1003       2018-10-11 22:41:12       0.276148     true       false     NULL                Demo                                   addTwoLists                            
 1004       2018-10-11 22:41:12       0.294        true       false     NULL                Demo                                   addTwoLists                            
 1005       2018-10-11 22:41:12       0.094652     true       false     NULL                Demo                                   addTwoLists                            
Command execution times exceed limit: 3, so command will exit. You can set it with -n option.
$ tt -l
 INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1003       2018-10-11 22:41:12       0.276148     true       false     NULL                Demo                                   addTwoLists                            
 1004       2018-10-11 22:41:12       0.294        true       false     NULL                Demo                                   addTwoLists                            
 1005       2018-10-11 22:41:12       0.094652     true       false     NULL                Demo                                   addTwoLists                            
Affect(row-cnt:3) cost in 2 ms.
$ tt -d -i 1003
Time fragment[1003] successfully deleted.
Affect(row-cnt:1) cost in 0 ms.
$ tt -l
 INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1004       2018-10-11 22:41:12       0.294        true       false     NULL                Demo                                   addTwoLists                            
 1005       2018-10-11 22:41:12       0.094652     true       false     NULL                Demo                                   addTwoLists                            
Affect(row-cnt:2) cost in 1 ms.
$ tt -d
Error during processing the command: Time fragment index is expected, please type -i to specify
$ tt -Q
Time fragments are cleaned.
Affect(row-cnt:2) cost in 0 ms.
$ tt -l
 INDEX      TIMESTAMP                 COST(ms)     IS-RET     IS-EXP    OBJECT              CLASS                                  METHOD                                 
Affect(row-cnt:0) cost in 0 ms.

F.Y.I

I am using Q instead of D for shortName:

    @Option(shortName = "Q", longName = "delete-all", flag = true)
    @Description("Delete all the time fragments")
    public void setDeleteAll(boolean deleteAll) {
        isDeleteAll = deleteAll;
    }

As #219 (comment) pointed out that when using them altogether, -d is working as -D deleting all records.

Where is the code to parse @Options?

@hengyunabc

@Hearen Hearen changed the title tt -D is not working -d and -D are not working as expected in command tt Oct 12, 2018
@Hearen Hearen changed the title -d and -D are not working as expected in command tt -d and -D are not working as expected in tt Oct 12, 2018
@Hearen
Copy link
Contributor Author

Hearen commented Oct 12, 2018

Since I can debug arthas.core now #222, it can be easily re-produced as:

$ rm -rf ~/.arthas/lib/3.0.5.2018101* # remove all local except 3.0.4 (avoid downloading)
$ ls ~/.arthas/lib/
3.0.4
$ ./as-package.sh
$ bin/as.sh
2 

$ tt -t -n 3 *Demo addTwoLists
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 71 ms.
 INDEX        TIMESTAMP                      COST(ms)        IS-RET      IS-EXP       OBJECT                  CLASS                                          METHOD                                        
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000         2018-10-12 10:52:44            1.889076        true        false        NULL                    Demo                                           addTwoLists                                   
 1001         2018-10-12 10:52:44            0.089873        true        false        NULL                    Demo                                           addTwoLists                                   
 1002         2018-10-12 10:52:44            0.087219        true        false        NULL                    Demo                                           addTwoLists                                   
Command execution times exceed limit: 3, so command will exit. You can set it with -n option.

$ tt -d -i 1000

image

As you @hengyunabc can see, isDeleteAll is true while isDelete is false.

I sought for long and only found this /home/hearen/.m2/repository/com/alibaba/middleware/cli/1.0.1/cli-1.0.1.jar!/com/taobao/middleware/cli/annotations/Option.class related to /home/hearen/.m2/repository/com/alibaba/middleware/cli/1.0.1/cli-1.0.1.jar!/com/taobao/middleware/cli/annotations/Option.class.

How you guys are parsing the Options in

    @Option(shortName = "D", longName = "delete-all", flag = true)
    @Description("Delete all the time fragments")
    public void setDeleteAll(boolean deleteAll) {
        isDeleteAll = deleteAll;
    }

    @Option(shortName = "d", longName = "delete", flag = true)
    @Description("Delete time fragment specified by index")
    public void setDelete(boolean delete) {
        isDelete = delete;
    }

This was referenced Oct 12, 2018
@Hearen
Copy link
Contributor Author

Hearen commented Oct 15, 2018

/home/hearen/.m2/repository/com/alibaba/middleware/cli/1.0.1/cli-1.0.1.jar!/com/taobao/middleware/cli/annotations/CLIConfigurator.class is parsing the Option

@Hearen
Copy link
Contributor Author

Hearen commented Oct 15, 2018

There is a bug in the option parser which directly caused this issue comparing optionShortName ignoring case in /home/hearen/.m2/repository/com/alibaba/middleware/cli/1.0.1/cli-1.0.1.jar!/com/taobao/middleware/cli/impl/DefaultParser.class

image

while(!opt.equalsIgnoreCase(option.getShortName()) && !opt.equalsIgnoreCase(option.getLongName()));

@hengyunabc For now, I think we:

  • either change D to Q to avoid the issue;
  • fix this issue in com/taobao/middleware/cli/impl/DefaultParser.java LINE - 448 with opt.equals(option.getShortName()) instead of opt.equalsIgnoreCase(option.getShortName())

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants