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.

Sign up for GitHub

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

Jump to bottom

[Bug] Very slow load of Case Task list in UI in 4.1.2 #1927

Closed
DrJohn1 opened this issue Apr 3, 2021 · 11 comments
Closed

[Bug] Very slow load of Case Task list in UI in 4.1.2 #1927

DrJohn1 opened this issue Apr 3, 2021 · 11 comments
Assignees
@To-om
Labels
bug scope:performance TheHive4 TheHive4 related issues
Milestone
4.1.3

Comments

@DrJohn1
Copy link

DrJohn1 commented Apr 3, 2021

Request Type

Bug

Work Environment

Question Answer
OS version Ubuntu
TheHive version 4.1.2
Package Type DEB
Index Lucene
Mode Single server

Problem Description

The CaseTask list in the UI is very slow as the number of cases increase, taking 40 seconds on a server with 4000 cases/12000 tasks.

Example: only 1 open case with 3 waiting tasks, takes >35 seconds to load task list and counter:
task_page_not_load

tasks_not_loading

task_count

Seems to affect 5 calls of the UI:
query?name=task-stats-<ID>
query?name=case-attachments
query?name=case-attachments.count
query?name=case-tasks
query?name=case-tasks.count

The index status reports OK on all, also reindexed them; the case list and audit feed load fast, but the case task lists are slow.

Steps to Reproduce

  1. Create a new instance with 1 organisation
  2. Create many cases using the samples in thehive4py: test-case-create.py
  3. (optional) Close the cases, but it does not matter if tasks are Waiting, InProgress or Completed (delay is the same)
  4. Open any case (with or without tasks) : The case task list and count will be very slow to load.
@DrJohn1 DrJohn1 added TheHive4 TheHive4 related issues bug labels Apr 3, 2021
@nadouani
Copy link
Contributor

nadouani commented Apr 5, 2021

Thanks @DrJohn1 we are going to investigate this but we might need more details from you and the persons that have this same unexpected bahavior.

@nadouani
Copy link
Contributor

nadouani commented Apr 5, 2021

Could you share the platform status report, it contains some details that might help

@DrJohn1
Copy link
Author

DrJohn1 commented Apr 5, 2021

Platform report of our test instance:

{
    "indexStatus": {
        "Alert": {
            "mixedCount": 0,
            "compositeCount": 0,
            "status": "OK"
        },
        "Attachment": {
            "mixedCount": 0,
            "compositeCount": 0,
            "status": "OK"
        },
        "Audit": {
            "mixedCount": 53574,
            "compositeCount": 53574,
            "status": "OK"
        },
        "Case": {
            "mixedCount": 4724,
            "compositeCount": 4724,
            "status": "OK"
        },
        "Log": {
            "mixedCount": 1,
            "compositeCount": 1,
            "status": "OK"
        },
        "Observable": {
            "mixedCount": 4,
            "compositeCount": 4,
            "status": "OK"
        },
        "Tag": {
            "mixedCount": 7053,
            "compositeCount": 7053,
            "status": "OK"
        },
        "Task": {
            "mixedCount": 19524,
            "compositeCount": 19524,
            "status": "OK"
        }
    },
    "checkStatus": {
        "ObservableType": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "CaseTemplate": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "User": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "ImpactStatus": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "Data": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "CustomField": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "ResolutionStatus": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "Profile": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "Alert": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {
                    "duplicate": 0,
                    "duration": 52,
                    "iteration": 1
                },
                "last": {
                    "duplicate": 0,
                    "duration": 52
                },
                "lastDate": 1617626960733
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "Tag": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {
                    "duplicate": 0,
                    "duration": 13561,
                    "iteration": 1
                },
                "last": {
                    "duplicate": 0,
                    "duration": 13561
                },
                "lastDate": 1617626960682
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "Case": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        },
        "Organisation": {
            "needCheck": false,
            "duplicateTimer": false,
            "duplicateStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalStats": {
                "global": {},
                "last": {},
                "lastDate": 0
            },
            "globalCheckRequestTime": 0
        }
    },
    "schemaStatus": [
        {
            "name": "thehive-cortex",
            "currentVersion": 2,
            "expectedVersion": 2,
            "error": null,
            "$$hashKey": "object:22"
        },
        {
            "name": "thehive",
            "currentVersion": 69,
            "expectedVersion": 69,
            "error": null,
            "$$hashKey": "object:23"
        }
    ]
}

@crackytsi
Copy link

crackytsi commented Apr 5, 2021 •
edited
Loading

I can confirm that. On my System with 14982 Cases it takes arround 30 seconds to load a new page of case list. And the system has high amount resources (much higher then TH3 using the same data).
Actually I'm using Lucene Index.

Here some platform data:

{
	"indexStatus": {
		
	},
	"checkStatus": {
		"User": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duration": 41012,
					"duplicateCaseAssignments": 0,
					"duplicateTaskAssignments": 0,
					"iteration": 1,
					"duplicateUsers": 0
				},
				"last": {
					"duplicateTaskAssignments": 0,
					"duplicateCaseAssignments": 0,
					"duplicateUsers": 0,
					"duration": 41012
				},
				"lastDate": 1617334097132
			},
			"globalStats": {
				"global": {
					"duration": 1,
					"iteration": 26
				},
				"last": {
					"duration": 0
				},
				"lastDate": 1617610841939
			},
			"globalCheckRequestTime": 0
		},
		"Profile": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 46,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 46
				},
				"lastDate": 1617334056041
			},
			"globalStats": {
				"global": {
					"duration": 0,
					"iteration": 26
				},
				"last": {
					"duration": 0
				},
				"lastDate": 1617613792858
			},
			"globalCheckRequestTime": 0
		},
		"Organisation": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 6,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 6
				},
				"lastDate": 1617334105899
			},
			"globalStats": {
				"global": {
					"duration": 4,
					"iteration": 28
				},
				"last": {
					"duration": 0
				},
				"lastDate": 1617618748869
			},
			"globalCheckRequestTime": 0
		},
		"Data": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 6501,
					"duration": 1375275,
					"iteration": 1
				},
				"last": {
					"duplicate": 6501,
					"duration": 1375275
				},
				"lastDate": 1617335506724
			},
			"globalStats": {
				"global": {
					"duration": 4974172,
					"iteration": 27
				},
				"last": {
					"duration": 187026
				},
				"lastDate": 1617617833805
			},
			"globalCheckRequestTime": 0
		},
		"ImpactStatus": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 15,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 15
				},
				"lastDate": 1617334097181
			},
			"globalStats": {
				"global": {
					"duration": 0,
					"iteration": 28
				},
				"last": {
					"duration": 0
				},
				"lastDate": 1617619814879
			},
			"globalCheckRequestTime": 0
		},
		"ObservableType": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 84,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 84
				},
				"lastDate": 1617334056119
			},
			"globalStats": {
				"global": {
					"duration": 1,
					"iteration": 27
				},
				"last": {
					"duration": 0
				},
				"lastDate": 1617616890169
			},
			"globalCheckRequestTime": 0
		},
		"CustomField": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 34,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 34
				},
				"lastDate": 1617334097166
			},
			"globalStats": {
				"global": {
					"duration": 2,
					"iteration": 26
				},
				"last": {
					"duration": 0
				},
				"lastDate": 1617610449429
			},
			"globalCheckRequestTime": 0
		},
		"ResolutionStatus": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 23,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 23
				},
				"lastDate": 1617335506747
			},
			"globalStats": {
				"global": {
					"duration": 0,
					"iteration": 26
				},
				"last": {
					"duration": 0
				},
				"lastDate": 1617607818749
			},
			"globalCheckRequestTime": 0
		},
		"Alert": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 8588,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 8588
				},
				"lastDate": 1617334105892
			},
			"globalStats": {
				"global": {
					"multiImport": 0,
					"duration": 537584,
					"iteration": 26
				},
				"last": {
					"multiImport": 0,
					"duration": 21606
				},
				"lastDate": 1617606591194
			},
			"globalCheckRequestTime": 0
		},
		"Tag": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 297342,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 297342
				},
				"lastDate": 1617335804089
			},
			"globalStats": {
				"global": {
					"duration": 6817668,
					"iteration": 26
				},
				"last": {
					"duration": 269901
				},
				"lastDate": 1617614012990
			},
			"globalCheckRequestTime": 0
		},
		"Case": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 25551,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 25551
				},
				"lastDate": 1617334131449
			},
			"globalStats": {
				"global": {
					"duration": 2503057,
					"iteration": 26
				},
				"last": {
					"duration": 92466
				},
				"lastDate": 1617613896054
			},
			"globalCheckRequestTime": 0
		},
		"CaseTemplate": {
			"needCheck": false,
			"duplicateTimer": false,
			"duplicateStats": {
				"global": {
					"duplicate": 0,
					"duration": 123,
					"iteration": 1
				},
				"last": {
					"duplicate": 0,
					"duration": 123
				},
				"lastDate": 1617334097305
			},
			"globalStats": {
				"global": {
					"orphans": 0,
					"duration": 2362,
					"iteration": 28
				},
				"last": {
					"orphans": 0,
					"duration": 85
				},
				"lastDate": 1617619096443
			},
			"globalCheckRequestTime": 0
		}
	},
	"schemaStatus": [
		{
			"name": "thehive",
			"currentVersion": 69,
			"expectedVersion": 69,
			"error": null,
			"$$hashKey": "object:4271"
		}
	]
}

@nadouani
Copy link
Contributor

nadouani commented Apr 6, 2021

@DrJohn1 @crackytsi what are the filters and sorts you use on lists that take a lot of time to load?

@DrJohn1
Copy link
Author

DrJohn1 commented Apr 6, 2021

I am not using sort/filters; the slowdown happens when loading/viewing a case from the web UI: everything loads fast (Details, Observables, TTPs and Audit Stream) except for the Tasks tab, which takes a long time to appear.

@nadouani
Copy link
Contributor

nadouani commented Apr 7, 2021

There is a fix that will be released in 4.1.3 to fix some queries. We will check the tasks related queries as well.

@nadouani nadouani added this to the 4.1.3 milestone Apr 7, 2021
@nadouani
Copy link
Contributor

nadouani commented Apr 9, 2021

The issue is related to slow performance for count queries that are also blocking the list as we need the counts to display the pagination.

@DrJohn1 can you tell how much time is taken for the tasks list api call?

@DrJohn1
Copy link
Author

DrJohn1 commented Apr 9, 2021

Running an api call to get all tasks takes 27 seconds. Using TheHive4py without any sort/query filters, takes also 27 seconds to get all cases (api.find_tasks()) and 44 seconds to get tasks from a specific case (api.get_case_tasks("~108306624")).

@nadouani
Copy link
Contributor

Running an api call to get all tasks takes 27 seconds. Using TheHive4py without any sort/query filters, takes also 27 seconds to get all cases (api.find_tasks()) and 44 seconds to get tasks from a specific case (api.get_case_tasks("~108306624")).

TheHive4py is still using /api/_search APIs for backward compatibility. We will build a TheHive4py 2.0 for TheHive 4, using optimized query APIs

@nadouani
Copy link
Contributor

nadouani commented Apr 11, 2021 •
edited
Loading

Closing this issue as it has been fixed by #1948

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@To-om To-om

Labels
bug scope:performance TheHive4 TheHive4 related issues
Projects
None yet
Milestone
4.1.3
Development

No branches or pull requests
4 participants
@nadouani @crackytsi @To-om @DrJohn1