Debug option or CLI to print the execution timestamp details

[dpasupathi]

Currently to debug the execution time i need to login to mongo db to view the details. Can we expose some CLI or debug option to print the details?

MongoDB server version: 3.4.11
> use st2
switched to db st2
> db.action_
db.action_alias_d_b             db.action_execution_d_b         db.action_execution_state_d_b
db.action_d_b                   db.action_execution_output_d_b
> db.action_execution_d_b.find({"_id": ObjectId("5a78f10dbb0f180b935f339f")})
{ "_id" : ObjectId("5a78f10dbb0f180b935f339f"), "trigger" : {  }, "trigger_type" : {  }, "trigger_instance" : {  }, "rule" : {  }, "action" : { "name" : "get_os_version", "parameters" : { "username" : { "position" : 1, "type" : "string", "description" : "Login user name to connect to the device" }, "password" : { "position" : 2, "secret" : true, "type" : "string", "description" : "Login password to connect to the device" }, "mgmt_ip" : { "position" : 0, "required" : true, "type" : "string", "description" : "Management IP address of the target device" } }, "tags" : [ ], "description" : "Get Operating System (OS) version of the network device", "enabled" : true, "entry_point" : "get_os_version.py", "notify" : {  }, "uid" : "action:network_essentials:get_os_version", "pack" : "network_essentials", "ref" : "network_essentials.get_os_version", "id" : "5a74b70fbb0f180b935f3358", "runner_type" : "run-python" }, "runner" : { "runner_module" : "python_runner", "uid" : "runner_type:run-python", "description" : "A runner for launching python actions.", "enabled" : true, "runner_parameters" : { "log_level" : { "default" : "DEBUG", "enum" : [ "AUDIT", "CRITICAL", "ERROR", "WARNING", "INFO", "DEBUG" ], "type" : "string", "description" : "Default log level for Python runner actions." }, "env" : { "type" : "object", "description" : "Environment variables which will be available to the script." }, "timeout" : { "default" : 600, "type" : "integer", "description" : "Action timeout in seconds. Action will get killed if it doesn't finish in timeout seconds." } }, "id" : "5a721756bb0f1842e6e462c8", "name" : "run-python" }, "liveaction" : { "runner_info" : { "hostname" : "bwcvagrant", "pid" : 1594 }, "parameters" : { "log_level" : "INFO", "mgmt_ip" : "10.24.12.106" }, "action_is_workflow" : false, "callback" : {  }, "action" : "network_essentials.get_os_version", "id" : "5a78f10dbb0f180b935f339e" }, "status" : "succeeded", "start_timestamp" : NumberLong("1517875469756192"), "parameters" : { "log_level" : "INFO", "mgmt_ip" : "10.24.12.106" }, "result" : { "exit_code" : 0, "result" : { "result" : "5.8.0fT183" }, "stderr" : "No handlers could be found for logger \"st2.st2common.util.api\"\nst2.actions.python.GetOsVersion: INFO     successfully connected to 10.24.12.106 to get OS Version\npyswitch.snmp.base.acl.Acl: INFO  successfully connected to 10.24.12.106 to get OS Version\nst2.actions.python.GetOsVersion: INFO     Closing connection to 10.24.12.106 after finding OS -- all done!\npyswitch.snmp.base.acl.Acl: INFO  Closing connection to 10.24.12.106 after finding OS -- all done!\n", "stdout" : "" }, "context" : { "user" : "st2admin", "pack" : "network_essentials" }, "children" : [ ], "log" : [ { "status" : "requested", "timestamp" : ISODate("2018-02-06T00:04:29.776Z") }, { "status" : "scheduled", "timestamp" : ISODate("2018-02-06T00:04:29.904Z") }, { "status" : "running", "timestamp" : ISODate("2018-02-06T00:04:30.013Z") }, { "status" : "succeeded", "timestamp" : ISODate("2018-02-06T00:04:34.080Z") } ], "web_url" : "https://bwcvagrant/#/history/5a78f10dbb0f180b935f339f/general", "end_timestamp" : NumberLong("1517875474045503") }
> 

[LindsayHill]

If you run something like st2 execution get 5a78f7d299c96b793e5c2493 -d, that shows start & end timestamps. Does that help?

extreme@EWC:~$ st2 execution get 5a78f7d299c96b793e5c2493 -d
+-----------------+--------------------------------------------------------------+
| Property        | Value                                                        |
+-----------------+--------------------------------------------------------------+
| id              | 5a78f7d299c96b793e5c2493                                     |
| action.ref      | core.local                                                   |
| context.user    | st2admin                                                     |
| parameters      | {                                                            |
|                 |     "cmd": "id"                                              |
|                 | }                                                            |
| status          | succeeded (1s elapsed)                                       |
| start_timestamp | Tue, 06 Feb 2018 00:33:22 UTC                                |
| end_timestamp   | Tue, 06 Feb 2018 00:33:23 UTC                                |
| result          | {                                                            |
|                 |     "succeeded": true,                                       |
|                 |     "failed": false,                                         |
|                 |     "return_code": 0,                                        |
|                 |     "stderr": "",                                            |
|                 |     "stdout": "uid=1001(stanley) gid=1001(stanley)           |
|                 | groups=1001(stanley)"                                        |
|                 | }                                                            |
| liveaction      | {                                                            |
|                 |     "runner_info": {                                         |
|                 |         "hostname": "EWC",                                   |
|                 |         "pid": 2178                                          |
|                 |     },                                                       |
|                 |     "parameters": {                                          |
|                 |         "cmd": "id"                                          |
|                 |     },                                                       |
|                 |     "action_is_workflow": false,                             |
|                 |     "callback": {},                                          |
|                 |     "action": "core.local",                                  |
|                 |     "id": "5a78f7d299c96b793e5c2492"                         |
|                 | }                                                            |
+-----------------+--------------------------------------------------------------+
extreme@EWC:~$

[dpasupathi]

@LindsayHill : i think this is not giving timestamp at all levels. e.g.{ "status" : "running", "timestamp" : ISODate("2018-02-06T00:04:30.013Z") }, { "status" : "succeeded", "timestamp" : ISODate("2018-02-06T00:04:34.080Z") }

I have raised this defect based on the request from @lakshmi-kannan

[stale[bot]]

Thanks for contributing to this issue. As it has been 90 days since the last activity, we are automatically marking is as stale. If this issue is not relevant or applicable anymore (problem has been fixed in a new version or similar), please close the issue or let us know so we can close it. On the contrary, if the issue is still relevant, there is nothing you need to do, but if you have any additional details or context which would help us when working on this issue, please include it as a comment to this issue.