fix: add userApplication error logs

[charankamarapu]

Related Issue

• Info about Issue or bug

Closes: #1019

Describe the changes you've made

Analysis

This issue mostly revolves around this code

err := cmd.Run()
	if err != nil {
		select {
		case <-stopper:
			return ErrInterrupted
		default:
			if exitError, ok := err.(*exec.ExitError); ok {
				if status, ok := exitError.Sys().(syscall.WaitStatus); ok {
					if status.Signaled() {
						return ErrInterrupted
					}
				}
			}
			h.logger.Error("couldn't start user application as command failed with error", zap.Error(err))
			return ErrCommandError
		}
	} else {
		return ErrUnExpected
	}

1. If we observe the error logs we can say that this error logs get fired after every test-set run in test mode. From the above code you can say that when ever the application is stopped there will be a error returned . By the error log we can say that when stopping the application it is giving exit code as 2 which is not expected.
2. The example used above is docker container of gin-mongo . This container normally exits with exit code 2 error even without using keploy. It is a normal behaviour of that container. But we usually expect error code 1 or -1 .
3. This behaviour is only seen in test and not in record because we exit record using control c . If you observer we used stopped to identify control-c interrupt and then throw interrupt error irrespective of the err we got which is wrong.

Changes

1. Firstly I have observed that when ever control-c is done all the child process like running userApp killed automatically . This is not preferred . Keploy should do it by using some functions rather than os doing it. So I have started running userApp in another process group.
2. As we don't know application behaviour, application can exit with any error code all we need is for the application to close . So I have a added check whether the err has the info regarding the closure of the process or not.
3. I have also added check of whether we are stopping the application or it is getting stopped by itself . Which will help sending different kind of logs.
4. Changed log statements according to the changes done.
5. In test service we were stopping the application which is already stopped added a check for that too.

Type of change

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)
• Code style update (formatting, local variables)
• Breaking change (fix or feature that would cause existing functionality to not work as expected)
• This change requires a documentation update

Please let us know if any test cases are added

Please describe the tests(if any). Provide instructions how its affecting the coverage.

Describe if there is any unusual behaviour of your code(Write NA if there isn't)

A clear and concise description of it.

Checklist:

• My code follows the style guidelines of this project.
• I have performed a self-review of my own code.
• I have commented my code, particularly in hard-to-understand areas.
• I have made corresponding changes to the documentation.
• My changes generate no new warnings.
• I have added tests that prove my fix is effective or that my feature works.
• New and existing unit tests pass locally with my changes.

Logs after changes

charankamarapu@lima-ubuntu-lts:~/charanpy/keploy/samples-go/gin-mongo$ keployV2 test -c "docker run -p 8080:8080 --name MongoApp --network keploy-network gin-app:1.0"

       ▓██▓▄
    ▓▓▓▓██▓█▓▄
     ████████▓▒
          ▀▓▓███▄      ▄▄   ▄               ▌
         ▄▌▌▓▓████▄    ██ ▓█▀  ▄▌▀▄  ▓▓▌▄   ▓█  ▄▌▓▓▌▄ ▌▌   ▓
       ▓█████████▌▓▓   ██▓█▄  ▓█▄▓▓ ▐█▌  ██ ▓█  █▌  ██  █▌ █▓
      ▓▓▓▓▀▀▀▀▓▓▓▓▓▓▌  ██  █▓  ▓▌▄▄ ▐█▓▄▓█▀ █▓█ ▀█▄▄█▀   █▓█
       ▓▌                           ▐█▌                   █▌
        ▓
  
v0.1.0-dev

Warning: delay is set to 5 seconds, incase your app takes more time to start use --delay to set custom delay
Example usage:
 keploy test -c "docker run -p 8080:808 --network myNetworkName myApplicationImageName" --delay 6\n
🐰 Keploy: 2023-10-16T17:02:49Z         INFO    cmd/test.go:125         {"keploy test and mock path": "/files/keploy", "keploy testReport path": "/files/keploy/testReports"}
🐰 Keploy: 2023-10-16T17:02:52Z         INFO    hooks/loader.go:748     keploy initialized and probes added to the kernel.
🐰 Keploy: 2023-10-16T17:02:52Z         INFO    proxy/proxy.go:394      Keploy has hijacked the DNS resolution mechanism, your application may misbehave in keploy test mode if you have provided wrong domain name in your application code.
🐰 Keploy: 2023-10-16T17:02:52Z         INFO    proxy/proxy.go:408      Proxy started at port:16789
🐰 Keploy: 2023-10-16T17:02:52Z         INFO    proxy/proxy.go:565      starting DNS server at addr :16789
🐰 Keploy: 2023-10-16T17:02:52Z         INFO    test/test.go:232        running user application for test run of test set       {"test-set": "test-set-0"}
🐰 Keploy: 2023-10-16T17:02:52Z         INFO    hooks/launch.go:536     trying to inject network:keploy-network to the keploy container
🐰 Keploy: 2023-10-16T17:02:52Z         INFO    hooks/launch.go:574     Successfully injected network to the keploy container   {"Keploy container": "keploy-v2", "appNetwork": "keploy-network"}
🐰 Keploy: 2023-10-16T17:02:53Z         INFO    hooks/launch.go:422     container & network found and processed successfully    {"time": 1697475773199162137}
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

PID: 1
[GIN-debug] GET    /:param                   --> main.getURL (3 handlers)
[GIN-debug] POST   /url                      --> main.putURL (3 handlers)
[GIN-debug] [WARNING] You trusted all proxies, this is NOT safe. We recommend you to set a value.
Please check https://pkg.go.dev/github.com/gin-gonic/gin#readme-don-t-trust-all-proxies for details.
[GIN-debug] Listening and serving HTTP on :8080
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    test/test.go:318                {"no of test cases": 2, "test-set": "test-set-0"}
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    pkg/util.go:65  making a http request   {"test case id": "test-1"}
[GIN] 2023/10/16 - 17:02:58 | 200 |    13.62505ms |             ::1 | POST     "/url"
Testrun failed for testcase with id: "test-1"

--------------------------------------------------------------------

+-------------------------------------------------------------------------------------------------------------+
|                                                DIFFS TEST-1                                                 |
+-------------------------------------------------------------------------------------------------------------+
|                      EXPECT BODY                     |                    ACTUAL BODY                       |
| -----------------------------------------------------+----------------------------------------------------- |
|    {                                                 |  {                                                   |
|   -  "ts": 1.6974324287323533e+18,                   | +  "ts": 1.697475778220299e+18,                      |
|      "url": "http://localhost:8080/Lhr4BWAi"         |    "url": "http://localhost:8080/Lhr4BWAi"           |
|    }                                                 |  }                                                   |
|                                                      |                                                      |
|                                                                                                             |
+-------------------------------------------------------------------------------------------------------------+
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    test/test.go:339        result  {"testcase id": "test-1", "passed": false}
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    test/test.go:318                {"no of test cases": 2, "test-set": "test-set-0"}
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    pkg/util.go:65  making a http request   {"test case id": "test-2"}
[GIN] 2023/10/16 - 17:02:58 | 200 |    2.989361ms |             ::1 | POST     "/url"
Testrun failed for testcase with id: "test-2"

--------------------------------------------------------------------

+-------------------------------------------------------------------------------------------------------------+
|                                                DIFFS TEST-2                                                 |
+-------------------------------------------------------------------------------------------------------------+
|                      EXPECT BODY                     |                    ACTUAL BODY                       |
| -----------------------------------------------------+----------------------------------------------------- |
|    {                                                 |  {                                                   |
|   -  "ts": 1.697432431670662e+18,                    | +  "ts": 1.6974757782309537e+18,                     |
|      "url": "http://localhost:8080/Lhr4BWAi"         |    "url": "http://localhost:8080/Lhr4BWAi"           |
|    }                                                 |  }                                                   |
|                                                      |                                                      |
|                                                                                                             |
+-------------------------------------------------------------------------------------------------------------+
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    test/test.go:339        result  {"testcase id": "test-2", "passed": false}
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    hooks/loader.go:328     keploy has initiated the shutdown of the user application.
🐰 Keploy: 2023-10-16T17:02:58Z         WARN    hooks/launch.go:518     userApplication has exited with exit code: 2
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    test/test.go:237        keploy terminated user application
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    test/test.go:232        running user application for test run of test set       {"test-set": "test-set-1"}
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    hooks/launch.go:536     trying to inject network:keploy-network to the keploy container
🐰 Keploy: 2023-10-16T17:02:58Z         INFO    hooks/launch.go:574     Successfully injected network to the keploy container   {"Keploy container": "keploy-v2", "appNetwork": "keploy-network"}
PID: 1
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

🐰 Keploy: 2023-10-16T17:02:58Z         INFO    hooks/launch.go:422     container & network found and processed successfully    {"time": 1697475778806046183}
[GIN-debug] GET    /:param                   --> main.getURL (3 handlers)
[GIN-debug] POST   /url                      --> main.putURL (3 handlers)
[GIN-debug] [WARNING] You trusted all proxies, this is NOT safe. We recommend you to set a value.
Please check https://pkg.go.dev/github.com/gin-gonic/gin#readme-don-t-trust-all-proxies for details.
[GIN-debug] Listening and serving HTTP on :8080
🐰 Keploy: 2023-10-16T17:03:03Z         INFO    test/test.go:318                {"no of test cases": 2, "test-set": "test-set-1"}
🐰 Keploy: 2023-10-16T17:03:03Z         INFO    pkg/util.go:65  making a http request   {"test case id": "test-1"}
Testrun failed for testcase with id: "test-1"

--------------------------------------------------------------------

[GIN] 2023/10/16 - 17:03:03 | 200 |   11.435016ms |             ::1 | POST     "/url"
+-------------------------------------------------------------------------------------------------------------+
|                                                DIFFS TEST-1                                                 |
+-------------------------------------------------------------------------------------------------------------+
|                      EXPECT BODY                     |                    ACTUAL BODY                       |
| -----------------------------------------------------+----------------------------------------------------- |
|    {                                                 |  {                                                   |
|   -  "ts": 1.697432462098131e+18,                    | +  "ts": 1.6974757838243684e+18,                     |
|      "url": "http://localhost:8080/Lhr4BWAi"         |    "url": "http://localhost:8080/Lhr4BWAi"           |
|    }                                                 |  }                                                   |
|                                                      |                                                      |
|                                                                                                             |
+-------------------------------------------------------------------------------------------------------------+
🐰 Keploy: 2023-10-16T17:03:03Z         INFO    test/test.go:339        result  {"testcase id": "test-1", "passed": false}
🐰 Keploy: 2023-10-16T17:03:03Z         INFO    test/test.go:318                {"no of test cases": 2, "test-set": "test-set-1"}
🐰 Keploy: 2023-10-16T17:03:03Z         INFO    pkg/util.go:65  making a http request   {"test case id": "test-2"}
Testrun failed for testcase with id: "test-2"

--------------------------------------------------------------------

+-------------------------------------------------------------------------------------------------------------+
|                                                DIFFS TEST-2                                                 |
+-------------------------------------------------------------------------------------------------------------+
|                      EXPECT BODY                     |                    ACTUAL BODY                       |
| -----------------------------------------------------+----------------------------------------------------- |
|    {                                                 |  {                                                   |
|   -  "ts": 1.697432463786897e+18,                    | +  "ts": 1.6974757838331965e+18,                     |
|      "url": "http://localhost:8080/Lhr4BWAi"         |    "url": "http://localhost:8080/Lhr4BWAi"           |
|    }                                                 |  }                                                   |
|                                                      |                                                      |
|                                                                                                             |
+-------------------------------------------------------------------------------------------------------------+
🐰 Keploy: 2023-10-16T17:03:03Z         INFO    test/test.go:339        result  {"testcase id": "test-2", "passed": false}
🐰 Keploy: 2023-10-16T17:03:03Z         INFO    hooks/loader.go:328     keploy has initiated the shutdown of the user application.
[GIN] 2023/10/16 - 17:03:03 | 200 |    3.061607ms |             ::1 | POST     "/url"
🐰 Keploy: 2023-10-16T17:03:04Z         WARN    hooks/launch.go:518     userApplication has exited with exit code: 2
🐰 Keploy: 2023-10-16T17:03:04Z         INFO    test/test.go:237        keploy terminated user application
🐰 Keploy: 2023-10-16T17:03:04Z         INFO    test/test.go:170        test run completed      {"passed overall": false}
🐰 Keploy: 2023-10-16T17:03:04Z         INFO    hooks/loader.go:384     Exiting keploy program gracefully.
🐰 Keploy: 2023-10-16T17:03:04Z         INFO    hooks/loader.go:434     eBPF resources released successfully...
🐰 Keploy: 2023-10-16T17:03:04Z         INFO    proxy/proxy.go:968      Dns server stopped
🐰 Keploy: 2023-10-16T17:03:04Z         INFO    proxy/proxy.go:970      proxy stopped...

[sweep-ai]

Apply Sweep Rules to your PR?

• Apply: Leftover TODOs in the code should be handled.
• Apply: All new business logic should have corresponding unit tests in the tests/ directory.
• Apply: Any clearly inefficient or repeated code should be optimized or refactored.

[gouravkrosx]

LGTM!