ewpatton / SemantEco

Source code for SemantEco
4 stars 5 forks source link

Documentation on debugging/logging facility/ debugging messages not always right level of granularity #12

Open apseyed opened 11 years ago

apseyed commented 11 years ago

Sometimes it mentions the module and not the method:

[INFO ] Module 'Species' executing query SemantEco.js:85

Sometimes it mentions the module and method:

[DEBUG] Invoking getCharacteristicsForSite of CharacteristicsModule SemantEco.js:79 [DEBUG] Invoking queryeBirdTaxonomyRoots of SpeciesDataProviderModule SemantEco.js:79

and sometimes it gives the correcting sparql query and others do not.

I would generally like to have documentation about the debugging/logging facilities so I can make updates as needed myself.


[DEBUG] Invoking getCharacteristicsForSite of CharacteristicsModule SemantEco.js:79 [DEBUG] Invoking queryeBirdTaxonomyRoots of SpeciesDataProviderModule SemantEco.js:79 [INFO ] Module 'Species' executing query SemantEco.js:85 [DEBUG] Letting modules visit query before execution SemantEco.js:79 [DEBUG] Time to augment: 0 ms SemantEco.js:79 [DEBUG] Endpoint: http://was.tw.rpi.edu/virtuoso/sparql SemantEco.js:79 [DEBUG] Query: PREFIX rdfs: http://www.w3.org/2000/01/rdf-schema# PREFIX xsd: http://www.w3.org/2001/XMLSchema# PREFIX owl: http://www.w3.org/2002/07/owl# PREFIX rdf: http://www.w3.org/1999/02/22-rdf-syntax-ns# SELECT ?child ?label ?parent WHERE { graph http://was.tw.rpi.edu/ebird-taxonomy { ?child http://www.w3.org/2000/01/rdf-schema#subClassOf ?parent . ?child http://www.w3.org/2000/01/rdf-schema#subClassOf http://ebird#birdTaxonomy . ?child http://www.w3.org/2000/01/rdf-schema#label ?label . } }

apseyed commented 11 years ago

right now, i want to see the sparql query in the console that corresponds to :+1: [DEBUG] Invoking queryForNearbySpeciesCounts of SpeciesDataProviderModule SemantEco.js:79

so I can debug some issue with plotting bird with water sites, but the sparql is not shown and semanteco.log does not give me the method and sparql query pair together either.

ewpatton commented 11 years ago

'Sometimes it mentions the module and not the method'

This is because it's non-trivial to know what method is doing the calling at that point in the execution of the application (i.e. this is during execution). We know the module because the ModuleManager provides a QueryExecutor per module. Without examining the frame stack you can't know what method actually initiated the query (again, non-trivial--also expensive in terms of computation time).

'Sometimes it mentions the module and method'

In this situation we are logging in direct response to a RESTful call and we know what method and module are going to be executed (i.e. this is pre-execution as compared to during execution above). Since the information is already available we log it.

'and sometimes it gives the correcting sparql query and others do not.'

It prints the contents of whatever Query object it is passed. If you're concerned that the query is wrong you need to fix your code that generates the query. If you have an actual example where you believe the code and the printed query are out of sync, report them as a ticket and I will look at it.

'I would generally like to have documentation about the debugging/logging facilities so I can make updates as needed myself.'

We use log4j for general logging capabilities (http://logging.apache.org/log4j/1.2/) and you should familiarize yourself with how it works. Beyond that the only custom debugging tool I've built is the semanteco-debugger package that can be used for executing arbitrary SPARQL queries on the model with & without reasoning.

'the sparql is not shown and semanteco.log does not give me the method and sparql query pair together either.'

The final query that is executed after the 'Invoking' debug statement is the one executed by the query method assuming you've written the query method correctly. In fact, you have yourself written a statement to log the query string on line 1037 of SpeciesDataProviderModule.java--so it should be printed out twice. Your request that 'the method and sparql query' be paired together can only be satisfied by addressing my response to the first item above.

apseyed commented 11 years ago

line 459 of SemantEcoUI.js calls:

SpeciesDataProviderModule.queryForNearbySpeciesCounts({}, queryForNearbySpeciesCountsCallback);

The else condition on line 395 is reached based on the return content being empty. Based on this I am getting "dummy" information in the bird jstree.

I added to the end of the Species Module line 1239:

request.getLogger().error("in SpeciesDataProviderModule.queryForNearbySpeciesCounts, query is : " + query.toString());

but I'm not getting this output in the console, so i'm not sure where the breakdown is.

On Sun, Feb 3, 2013 at 5:38 PM, Evan W. Patton notifications@github.comwrote:

'Sometimes it mentions the module and not the method'

This is because it's non-trivial to know what method is doing the calling at that point in the execution of the application (i.e. this is during execution). We know the module because the ModuleManager provides a QueryExecutor per module. Without examining the frame stack you can't know what method actually initiated the query (again, non-trivial--also expensive in terms of computation time).

'Sometimes it mentions the module and method'

In this situation we are logging in direct response to a RESTful call and we know what method and module are going to be executed (i.e. this is pre-execution as compared to during execution above). Since the information is already available we log it.

'and sometimes it gives the correcting sparql query and others do not.'

It prints the contents of whatever Query object it is passed. If you're concerned that the query is wrong you need to fix your code that generates the query. If you have an actual example where you believe the code and the printed query are out of sync, report them as a ticket and I will look at it.

'I would generally like to have documentation about the debugging/logging facilities so I can make updates as needed myself.'

We use log4j for general logging capabilities ( http://logging.apache.org/log4j/1.2/) and you should familiarize yourself with how it works. Beyond that the only custom debugging tool I've built is the semanteco-debugger package that can be used for executing arbitrary SPARQL queries on the model with & without reasoning.

'the sparql is not shown and semanteco.log does not give me the method and sparql query pair together either.'

The final query that is executed after the 'Invoking' debug statement is the one executed by the query method assuming you've written the query method correctly. In fact, you have yourself written a statement to log the query string on line 1037 of SpeciesDataProviderModule.java--so it should be printed out twice. Your request that 'the method and sparql query' be paired together can only be satisfied by addressing my response to the first item above.

— Reply to this email directly or view it on GitHubhttps://github.com/ewpatton/SemantEco/issues/12#issuecomment-13057008.

Patrice Seyed DataONE Postdoctoral Fellow, University of New Mexico & Tetherless World Constellation, Rensselaer Polytechnic Institute http://www.dataone.org/working_groups/data-integration-and-semantics http://tw.rpi.edu/web/person/PatriceSeyed Blog: http://apseyed.wordpress.com/

apseyed commented 11 years ago

Are you using the logger outside any of the modules? If so ,where?

On Mon, Feb 4, 2013 at 12:35 AM, Patrice Seyed apseyed@gmail.com wrote:

line 459 of SemantEcoUI.js calls:

SpeciesDataProviderModule.queryForNearbySpeciesCounts({}, queryForNearbySpeciesCountsCallback);

The else condition on line 395 is reached based on the return content being empty. Based on this I am getting "dummy" information in the bird jstree.

I added to the end of the Species Module line 1239:

request.getLogger().error("in SpeciesDataProviderModule.queryForNearbySpeciesCounts, query is : " + query.toString());

but I'm not getting this output in the console, so i'm not sure where the breakdown is.

On Sun, Feb 3, 2013 at 5:38 PM, Evan W. Patton notifications@github.comwrote:

'Sometimes it mentions the module and not the method'

This is because it's non-trivial to know what method is doing the calling at that point in the execution of the application (i.e. this is during execution). We know the module because the ModuleManager provides a QueryExecutor per module. Without examining the frame stack you can't know what method actually initiated the query (again, non-trivial--also expensive in terms of computation time).

'Sometimes it mentions the module and method'

In this situation we are logging in direct response to a RESTful call and we know what method and module are going to be executed (i.e. this is pre-execution as compared to during execution above). Since the information is already available we log it.

'and sometimes it gives the correcting sparql query and others do not.'

It prints the contents of whatever Query object it is passed. If you're concerned that the query is wrong you need to fix your code that generates the query. If you have an actual example where you believe the code and the printed query are out of sync, report them as a ticket and I will look at it.

'I would generally like to have documentation about the debugging/logging facilities so I can make updates as needed myself.'

We use log4j for general logging capabilities ( http://logging.apache.org/log4j/1.2/) and you should familiarize yourself with how it works. Beyond that the only custom debugging tool I've built is the semanteco-debugger package that can be used for executing arbitrary SPARQL queries on the model with & without reasoning.

'the sparql is not shown and semanteco.log does not give me the method and sparql query pair together either.'

The final query that is executed after the 'Invoking' debug statement is the one executed by the query method assuming you've written the query method correctly. In fact, you have yourself written a statement to log the query string on line 1037 of SpeciesDataProviderModule.java--so it should be printed out twice. Your request that 'the method and sparql query' be paired together can only be satisfied by addressing my response to the first item above.

— Reply to this email directly or view it on GitHubhttps://github.com/ewpatton/SemantEco/issues/12#issuecomment-13057008.

Patrice Seyed DataONE Postdoctoral Fellow, University of New Mexico & Tetherless World Constellation, Rensselaer Polytechnic Institute http://www.dataone.org/working_groups/data-integration-and-semantics http://tw.rpi.edu/web/person/PatriceSeyed Blog: http://apseyed.wordpress.com/

Patrice Seyed DataONE Postdoctoral Fellow, University of New Mexico & Tetherless World Constellation, Rensselaer Polytechnic Institute http://www.dataone.org/working_groups/data-integration-and-semantics http://tw.rpi.edu/web/person/PatriceSeyed Blog: http://apseyed.wordpress.com/

apseyed commented 11 years ago

if you are poking around this code tomorrow and have time, might want to briefly look at it. I will try to work on it tomorrow night. this bug is keeping me from taking some screenshots I need for thursday 12pm meeting. I select water and bird domains, select san francisco, and when i click on a water drop, there are no chemicals shown and the bird hierarchy show dummy data based on the else clause mentioned above.

apseyed commented 11 years ago

i was actually just going to check if i run into this with water, and i had the lag issue with bristol that I mentioned in an email just now.

apseyed commented 11 years ago

for logging purposes:

currently checking: http://localhost:8081/semanteco/#source%5B%5D=http%3A//sbcFish%23&source%5B%5D=http%3A//ebird%23&source%5B%5D=http%3A//sparql.tw.rpi.edu/source/epa-gov&source%5B%5D=http%3A//sparql.tw.rpi.edu/source/usgs-gov&type%5B%5D=clean-air&type%5B%5D=polluted-air&type%5B%5D=birds&type%5B%5D=fish&type%5B%5D=clean-water&type%5B%5D=clean-facility&type%5B%5D=polluted-water&type%5B%5D=polluted-facility&domain%5B%5D=http%3A//escience.rpi.edu/ontology/semanteco/2/0/bird.owl%23&domain%5B%5D=http%3A//escience.rpi.edu/ontology/semanteco/2/0/water.owl%23&industry=&regulation.air=http%3A//was.tw.rpi.edu/semanteco/regulations/EPA-air-regulation.owl&regulation.water=http%3A//escience.rpi.edu/ontology/semanteco/2/0/EPA-regulation.owl&time=&queryeBirdTaxonomySubClasses=http%3A//ebird%23Hirundinidae&species%5B%5D=http%3A//ebird%23Hirundinidae&zip=94107&state=CA&stateCode=06&county=075&lat=37.762147&lng=-122.397099&limits%5Bsite%5D%5Boffset%5D=0&limits%5Bsite%5D%5Bcount%5D=64&limits%5Bsite%5D%5Blimit%5D=6&limits%5Bfacility%5D%5Boffset%5D=0&limits%5Bfacility%5D%5Bcount%5D=4&limits%5Bfacility%5D%5Blimit%5D=4