search

quarkslab / irma-frontend

IRMA frontend
25 stars 3 forks source link

Probes remain in "waiting" #5

Closed jhemp closed 10 years ago

jhemp commented 10 years ago

Description: Probes remain in "Probe still working... ", but progress bar shows completed and response with results was also sent.

Occurrence: /

When: Always

Log Trace: None

How to reproduce:

  1. Take your working copy of irma-frontend, irma-brain, irma-probes
  2. checkout testing branch
  3. restart everything
    • celeryd.brain
    • celeryd.results
    • celeryd.probe
    • cerleryd
    • uwsgi
    • nginx.
      1. scan a file
ch0k0bn commented 10 years ago

without any logs, it will be hard to help :). if probes sent back results, there are still two steps before showing the results to the user. celeryd.results@brain gather results to track missing one and celeryd@frontend insert results into mongo database. Does the two log files contains lines showing the results have been handled well ?

jhemp commented 10 years ago

Brain.log

[2014-05-12 09:36:58,693: INFO/MainProcess] Received task: brain.tasks.probe_list[a5ef95f8-2b48-4359-a9cc-8184bd92c286] [2014-05-12 09:36:59,758: INFO/MainProcess] Task brain.tasks.probe_list[a5ef95f8-2b48-4359-a9cc-8184bd92c286] succeeded in 1.06371689704s: (0, [u'Kaspersky', u'ComodoCAVL', u'ClamAV', u'Symantec']) [2014-05-12 09:37:00,337: INFO/MainProcess] Received task: brain.tasks.scan[3ddb69f7-ccee-4efe-9b4b-edcace5d82ef] [2014-05-12 09:37:00,383: INFO/MainProcess] Received task: brain.tasks.scan_progress[2f56b3f2-4cf6-414e-8285-4e39406ab3a9] [2014-05-12 09:37:00,391: INFO/MainProcess] Task brain.tasks.scan_progress[2f56b3f2-4cf6-414e-8285-4e39406ab3a9] succeeded in 0.00804683601018s: (1, 0) [2014-05-12 09:37:01,426: WARNING/Worker-7] Found user test1 quota disabled [2014-05-12 09:37:01,429: WARNING/Worker-7] 1 files receives / 4 active probe / 4 probe used / 4 jobs launched [2014-05-12 09:37:01,441: INFO/MainProcess] Task brain.tasks.scan[3ddb69f7-ccee-4efe-9b4b-edcace5d82ef] succeeded in 1.10207450099s: None [2014-05-12 09:37:01,936: INFO/MainProcess] Received task: brain.tasks.scan_progress[2ff9daad-64dc-48bf-ad25-5c66cc7c9955] [2014-05-12 09:37:01,944: INFO/MainProcess] Task brain.tasks.scan_progress[2ff9daad-64dc-48bf-ad25-5c66cc7c9955] succeeded in 0.00673598295543s: (0, {'successful': 0, 'finished': 0, 'total': 4}) [2014-05-12 09:37:03,479: INFO/MainProcess] Received task: brain.tasks.scan_progress[d7e0031f-2378-4368-adee-34d1081332a2] [2014-05-12 09:37:03,487: INFO/MainProcess] Task brain.tasks.scan_progress[d7e0031f-2378-4368-adee-34d1081332a2] succeeded in 0.00704893702641s: (0, {'successful': 3, 'finished': 3, 'total': 4})

Mongodb.log Mon May 12 09:37:00 [initandlisten] connection accepted from 127.0.0.1:54179 #50 Mon May 12 09:37:02 [initandlisten] connection accepted from 127.0.0.1:54191 #51 Mon May 12 09:37:02 [initandlisten] connection accepted from 127.0.0.1:54193 #52 Mon May 12 09:37:22 [initandlisten] connection accepted from 127.0.0.1:54197 #53

frontend.log [2014-05-12 09:37:00,205: INFO/MainProcess] Received task: frontend.tasks.scan_launch[bfc5463a-6d02-4360-be9c-b10cbe9141dd] [2014-05-12 09:37:00,342: INFO/MainProcess] Task frontend.tasks.scan_launch[bfc5463a-6d02-4360-be9c-b10cbe9141dd] succeeded in 0.135443834006s: (0, 'scan launched') [2014-05-12 09:37:02,068: INFO/MainProcess] Received task: frontend.tasks.scan_result[b8ef9d67-2e91-462c-bfd0-fb9ec100a2b7] [2014-05-12 09:37:02,084: WARNING/Worker-6] Scanid 53707a19f2d8ae4700a28067Result from Kaspersky probedone [u'Kaspersky'] [2014-05-12 09:37:02,085: INFO/MainProcess] Task frontend.tasks.scan_result[b8ef9d67-2e91-462c-bfd0-fb9ec100a2b7] succeeded in 0.0149964649463s: None [2014-05-12 09:37:02,415: INFO/MainProcess] Received task: frontend.tasks.scan_result[dcea51ba-0436-4fc6-a288-7cd9d3392a91] [2014-05-12 09:37:02,430: WARNING/Worker-5] Scanid 53707a19f2d8ae4700a28067Result from ClamAV probedone [u'ClamAV', u'Kaspersky'] [2014-05-12 09:37:02,431: INFO/MainProcess] Task frontend.tasks.scan_result[dcea51ba-0436-4fc6-a288-7cd9d3392a91] succeeded in 0.0159173220163s: None [2014-05-12 09:37:02,717: INFO/MainProcess] Received task: frontend.tasks.scan_result[b7b31f22-93b8-4421-b6bf-b157ae4b0472] [2014-05-12 09:37:02,730: WARNING/Worker-5] Scanid 53707a19f2d8ae4700a28067Result from Symantec probedone [u'Symantec', u'ClamAV', u'Kaspersky'] [2014-05-12 09:37:02,731: INFO/MainProcess] Task frontend.tasks.scan_result[b7b31f22-93b8-4421-b6bf-b157ae4b0472] succeeded in 0.0134093889501s: None [2014-05-12 09:37:04,365: INFO/MainProcess] Received task: frontend.tasks.scan_result[84c5a30c-2053-46d0-9096-6837b84191c4] [2014-05-12 09:37:04,396: WARNING/Worker-4] Scanid 53707a19f2d8ae4700a28067Result from ComodoCAVL probedone [u'ClamAV', u'Symantec', u'Kaspersky', u'ComodoCAVL'] [2014-05-12 09:37:04,403: INFO/MainProcess] Task frontend.tasks.scan_result[84c5a30c-2053-46d0-9096-6837b84191c4] succeeded in 0.0364155930001s: None [2014-05-12 09:37:22,714: INFO/MainProcess] Received task: frontend.tasks.scan_launch[074f74a5-ac78-4737-b37e-639b54d84366] [2014-05-12 09:37:22,844: INFO/MainProcess] Task frontend.tasks.scan_launch[074f74a5-ac78-4737-b37e-639b54d84366] succeeded in 0.128601614037s: (0, 'scan launched') [2014-05-12 09:37:23,406: INFO/MainProcess] Received task: frontend.tasks.scan_result[a4324c9f-168b-4aa9-9c85-ab0dd54f14b4] [2014-05-12 09:37:23,420: WARNING/Worker-8] Scanid 53707a30f2d8ae4700a28068Result from Kaspersky probedone [u'Kaspersky'] [2014-05-12 09:37:23,421: INFO/MainProcess] Task frontend.tasks.scan_result[a4324c9f-168b-4aa9-9c85-ab0dd54f14b4] succeeded in 0.0133223570883s: None [2014-05-12 09:37:23,843: INFO/MainProcess] Received task: frontend.tasks.scan_result[2dd38fec-5823-4b78-b8a2-6ea4869a7f83] [2014-05-12 09:37:23,856: WARNING/Worker-8] Scanid 53707a30f2d8ae4700a28068Result from ClamAV probedone [u'ClamAV', u'Kaspersky'] [2014-05-12 09:37:23,857: INFO/MainProcess] Task frontend.tasks.scan_result[2dd38fec-5823-4b78-b8a2-6ea4869a7f83] succeeded in 0.0133885770338s: None

ch0k0bn commented 10 years ago

on brain i meant results.log, not brain.log. But from frontend log it seems scan 53707a19f2d8ae4700a28067 successfully completed and 53707a30f2d8ae4700a28068 got only 2 results / 4 so far. If you saw nothing on webui, could you please try with the command line client (located https://github.com/quarkslab/irma-frontend/blob/master/frontend/cli/irma.py, just edit frontend address) ?

irma.py results 53707a19f2d8ae4700a28067 --partial irma.py results 53707a30f2d8ae4700a28068 --partial

(--partial show results even if scan is not fully finished)

jhemp commented 10 years ago

Missing results.log [2014-05-12 09:37:02,054: INFO/MainProcess] Received task: brain.tasks.scan_result[6ef2d51d-61df-4d15-aa56-095bc2ce681b] [2014-05-12 09:37:02,067: WARNING/Worker-9] scanid 53707a19f2d8ae4700a28067 sent result Kaspersky [2014-05-12 09:37:02,090: INFO/MainProcess] Task brain.tasks.scan_result[6ef2d51d-61df-4d15-aa56-095bc2ce681b] succeeded in 0.0341783000622s: None [2014-05-12 09:37:02,412: INFO/MainProcess] Received task: brain.tasks.scan_result[d21b6c2e-181d-45b4-9d80-324d00c7d487] [2014-05-12 09:37:02,414: WARNING/Worker-2] scanid 53707a19f2d8ae4700a28067 sent result ClamAV [2014-05-12 09:37:02,421: INFO/MainProcess] Task brain.tasks.scan_result[d21b6c2e-181d-45b4-9d80-324d00c7d487] succeeded in 0.00828590407036s: None [2014-05-12 09:37:02,715: INFO/MainProcess] Received task: brain.tasks.scan_result[2fdffc46-4dee-4f69-9510-f8470ccd1b7f] [2014-05-12 09:37:02,717: WARNING/Worker-9] scanid 53707a19f2d8ae4700a28067 sent result Symantec [2014-05-12 09:37:02,724: INFO/MainProcess] Task brain.tasks.scan_result[2fdffc46-4dee-4f69-9510-f8470ccd1b7f] succeeded in 0.00830252503511s: None [2014-05-12 09:37:04,362: INFO/MainProcess] Received task: brain.tasks.scan_result[42ba900b-af4b-4601-89ca-31d485e73915] [2014-05-12 09:37:04,364: WARNING/Worker-3] scanid 53707a19f2d8ae4700a28067 sent result ComodoCAVL [2014-05-12 09:37:04,441: INFO/MainProcess] Task brain.tasks.scan_result[42ba900b-af4b-4601-89ca-31d485e73915] succeeded in 0.0785086629912s: None [2014-05-12 09:37:23,402: INFO/MainProcess] Received task: brain.tasks.scan_result[90f94123-ea59-4bdf-a53e-aa7950ec6084] [2014-05-12 09:37:23,405: WARNING/Worker-6] scanid 53707a30f2d8ae4700a28068 sent result Kaspersky [2014-05-12 09:37:23,412: INFO/MainProcess] Task brain.tasks.scan_result[90f94123-ea59-4bdf-a53e-aa7950ec6084] succeeded in 0.00842188601382s: None [2014-05-12 09:37:23,841: INFO/MainProcess] Received task: brain.tasks.scan_result[9f289619-cc9e-44e2-b5ac-2f90b83e9895] [2014-05-12 09:37:23,843: WARNING/Worker-3] scanid 53707a30f2d8ae4700a28068 sent result ClamAV [2014-05-12 09:37:23,850: INFO/MainProcess] Task brain.tasks.scan_result[9f289619-cc9e-44e2-b5ac-2f90b83e9895] succeeded in 0.00792307697702s: None [2014-05-12 09:37:24,142: INFO/MainProcess] Received task: brain.tasks.scan_result[c8a9bc72-b551-4105-95c3-edb7e9fc013e] [2014-05-12 09:37:24,144: WARNING/Worker-11] scanid 53707a30f2d8ae4700a28068 sent result Symantec [2014-05-12 09:37:24,151: INFO/MainProcess] Task brain.tasks.scan_result[c8a9bc72-b551-4105-95c3-edb7e9fc013e] succeeded in 0.00780756003223s: None [2014-05-12 09:37:25,705: INFO/MainProcess] Received task: brain.tasks.scan_result[f1d48744-4434-4316-b5d9-be8959b606a3] [2014-05-12 09:37:25,707: WARNING/Worker-2] scanid 53707a30f2d8ae4700a28068 sent result ComodoCAVL [2014-05-12 09:37:25,763: INFO/MainProcess] Task brain.tasks.scan_result[f1d48744-4434-4316-b5d9-be8959b606a3] succeeded in 0.0569274940062s: None

And the cli shows what i expected Scan status : finished eicar.com [SHA256: 275a021bbfb6489e54d471899f7db9d1663fc695ec2fe2a2c4538aabf651fd0f] ClamAV Eicar-Test-Signature Symantec EICAR Test String Kaspersky EICAR-Test-File ComodoCAVL ApplicUnwnt

ch0k0bn commented 10 years ago

if the webapi frontend_addr/_api/scan/result/ send the same correct results, i have no clue where the bug come from. Have you tried to turn your browser off and on again ? (itcrowd style).

jhemp commented 10 years ago

There is definitely a something.

It seems like the front end does not redirect to the results page. The response however is correct and looks like the following:

{"msg": "success", "code": 0, "scan_results": {"275a021bbfb6489e54d471899f7db9d1663fc695ec2fe2a2c4538aabf651fd0f": {"results": {"ClamAV": {"version": "Clam AntiVirus Scanner", "probe_res": {"raw": null, "dependencies_data": [{"release": "3.2.0-4-amd64", "version": "#1 SMP Debian 3.2.57-3", "architecture": "x86_64", "system": "Linux", "description": "('debian', '7.5', '')"}], "data": {"version": "0.98.1", "scan_results": {"/tmp/tmpaXUaZK": null, "/tmp/tmpaxuazk": "Eicar-Test-Signature"}, "name": "Clam AntiVirus Scanner", "database": {"/var/lib/clamav/main_cvd": {"sha256": "b02e221fc03a3ab651db740a503aa1eff3eec80d45afbb20d75df247bf3d3683", "ctime": 1399453097.638763, "mtime": 1399453092.0467615}, "/var/lib/clamav/daily_cld": {"sha256": "a6fa442a20fa62910e16c8fe37b171373890d90c5880c3808efaca2a4d71fbd9", "ctime": 1399550262.6322105, "mtime": 1399550261.1282103}, "/var/lib/clamav/bytecode_cvd": {"sha256": "f7f805f0442849ae4f7dca32c7f79591b4c55a4a09368021169b860b5b5638db", "ctime": 1399453115.9147627, "mtime": 1399453115.6387632}}}, "result_code": 1, "metadata": {"duration": 0, "start_time": 1399893893.0, "end_time": 1399893893.0, "plugin": "ClamAV"}}, "result": "Eicar-Test-Signature"}}, "filename": "eicar.com"}}}

jhemp commented 10 years ago

I found finally an error with which you can do something:

Error: b.data.scan_results[c] is undefined a.fetchResults/b<@http://xxxxx/scripts/f9e99b90.scripts.js:1 Bc/h/g.promise.then/k@http://xxxxx/scripts/7d1f32e5.modules.js:5 Bc/h/g.promise.then/k@http://xxxxx/scripts/7d1f32e5.modules.js:5 Bc/i/<.then/<@http://xxxxx/scripts/7d1f32e5.modules.js:5 Dc/this.$get</k.prototype.$eval@http://xxxxx/scripts/7d1f32e5.modules.js:6 Dc/this.$get</k.prototype.$digest@http://xxxxx/scripts/7d1f32e5.modules.js:6 Dc/this.$get</k.prototype.$apply@http://xxxxx/scripts/7d1f32e5.modules.js:6 f@http://xxxxx/scripts/7d1f32e5.modules.js:5 r@http://xxxxx/scripts/7d1f32e5.modules.js:5 ac/</w.onreadystatechange@http://xxxxx/scripts/7d1f32e5.modules.js:5

...atus:c,headers:Wb(d),config:b,statusText:e})}function i(){var a=H(n.pendingReque...

This error occurs directly after the call GET http://xxxxxx/_api/scan/result/5370cd90f2d8ae6b322ded08

ch0k0bn commented 10 years ago

could you try the new web-data pkg issued as part of updated v1.0.1 tag ?

ch0k0bn commented 10 years ago

some race conditions have been fixed in version >= 1.0.4 (seems to be such an issue here)