You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@phoenix.apache.org by "Jesse Yates (JIRA)" <ji...@apache.org> on 2014/08/21 19:03:11 UTC
[jira] [Commented] (PHOENIX-1191) Unable to turn tracing off
[ https://issues.apache.org/jira/browse/PHOENIX-1191?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14105593#comment-14105593 ]
Jesse Yates commented on PHOENIX-1191:
--------------------------------------
Once you have the sink installed, it catches all the HTrace traces, not just the ones that phoenix writes. That's actually the expected behavior - imagine if you wanted to profile what HBase is doing (e.g. how long is a WAL flush actually taking?), something that we care about internally.
Note that there are no *client* traces in that table - they are all the server actions. And you want those when profiling a phoenix query so you know which part is slow - is it the HBase write or the phoenix part?
Its hard (read: currently impossible) to differentiate them from phoenix traces because once we pass into HBase territory, there is no way to ensure child spans have any special properties (that we could differentiate on). Further, there is no fool-proof way to check for the parent spans being present in the target table before deciding to write the span or not because the client is async and may take a while to write the updates; we could say all the traces *should* be there after 5mins, but then we are buffering writes for 5mins(!) just to catch this case.
I'm open to suggestions for around changing this, but I'm not sure there is one beyond removing the configs and bouncing the regionserver to 'turn it off'
> Unable to turn tracing off
> --------------------------
>
> Key: PHOENIX-1191
> URL: https://issues.apache.org/jira/browse/PHOENIX-1191
> Project: Phoenix
> Issue Type: Bug
> Affects Versions: 4.1
> Environment: Hadoop2 profile
> Reporter: Mujtaba Chohan
> Assignee: Jesse Yates
>
> Following is set on all region servers and client:
> _hadoop-metrics2.properties_
> hbase.sink.tracing.class=org.apache.phoenix.trace.PhoenixMetricsSink
> hbase.sink.tracing.writer-class=org.apache.phoenix.trace.PhoenixTableMetricsWriter
> hbase.sink.tracing.context=tracing
> On connecting client with _phoenix.trace.frequency_ set to _always_ in either _hbase-site.xml_ or as a connection property, SYSTEM.TRACING_STATS table rows keep on incrementing at 1000+ rows per second (counted from HBase shell) even when client process ends or after client reconnects with _phoenix.trace.frequency_ set to _never_
> 100 rows of tracing_stats table:
> {code}
> TRACE_ID PARENT_ID SPAN_ID DESCRIPTION START_TIME END_TIME HOSTNAME COUNT COUNT
> -9157512308113706720 -8928786658075778325 5207142134792129332 Scanner opened on server 1408583549649 1408583549650 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -9192795988706086320 MemStoreFluser.reclaimMemStoreMemory 1408583551528 1408583551528 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -8637003514089555934 FSHlog.append 1408583550368 1408583550368 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -8508766066040491647 MemStoreFluser.reclaimMemStoreMemory 1408583550060 1408583550060 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -8166821003949758611 FSHlog.append 1408583550588 1408583550588 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -8106523596770346558 FSHlog.append 1408583551054 1408583551054 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -7890496175147324867 MemStoreFluser.reclaimMemStoreMemory 1408583551054 1408583551054 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -7138278303733201847 FSHlog.append 1408583550060 1408583550060 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -7015414110902962028 MemStoreFluser.reclaimMemStoreMemory 1408583549742 1408583549742 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -6683942055085044868 MemStoreFluser.reclaimMemStoreMemory 1408583550538 1408583550538 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -6416728707646102973 MemStoreFluser.reclaimMemStoreMemory 1408583551265 1408583551265 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -6356346151841867411 MemStoreFluser.reclaimMemStoreMemory 1408583551175 1408583551175 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -6333966944099265151 FSHlog.append 1408583549938 1408583549938 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -5957426975720435821 FSHlog.append 1408583549858 1408583549858 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -5956202218855606765 MemStoreFluser.reclaimMemStoreMemory 1408583550133 1408583550133 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -5710035646834892295 FSHlog.append 1408583551096 1408583551096 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -5474375611558308407 MemStoreFluser.reclaimMemStoreMemory 1408583550433 1408583550433 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -5022855873729817832 FSHlog.append 1408583549789 1408583549790 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -4892757344142166073 FSHlog.append 1408583550787 1408583550787 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -4832454597570064980 MemStoreFluser.reclaimMemStoreMemory 1408583549789 1408583549789 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -4773826273380917441 FSHlog.append 1408583550319 1408583550319 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -4481969984590303691 MemStoreFluser.reclaimMemStoreMemory 1408583550368 1408583550368 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -4240856821078097594 MemStoreFluser.reclaimMemStoreMemory 1408583551214 1408583551214 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -3970507565346024223 FSHlog.append 1408583551214 1408583551214 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -3743734363265187168 MemStoreFluser.reclaimMemStoreMemory 1408583550848 1408583550848 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -3528193689664464439 MemStoreFluser.reclaimMemStoreMemory 1408583551457 1408583551457 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -3159984967735826565 FSHlog.append 1408583550195 1408583550195 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -3087585990557619938 MemStoreFluser.reclaimMemStoreMemory 1408583549977 1408583549977 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -3032311163341471023 MemStoreFluser.reclaimMemStoreMemory 1408583551016 1408583551016 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -2450225057491610326 MemStoreFluser.reclaimMemStoreMemory 1408583549858 1408583549858 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -2286126597016536608 FSHlog.append 1408583551265 1408583551265 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -1662329457886250686 FSHlog.append 1408583551528 1408583551528 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -1206381678298560420 MemStoreFluser.reclaimMemStoreMemory 1408583550588 1408583550588 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -1012831725985223711 MemStoreFluser.reclaimMemStoreMemory 1408583550195 1408583550195 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -858071208745066920 FSHlog.append 1408583549977 1408583549977 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -822036300261329829 FSHlog.append 1408583549742 1408583549742 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -666080170093117547 MemStoreFluser.reclaimMemStoreMemory 1408583551096 1408583551096 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -219668523110513140 FSHlog.append 1408583551016 1408583551016 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -147755033262687072 FSHlog.append 1408583550245 1408583550245 vampire3 0 0
> -9157512308113706720 -8772742027214392277 -119454668012167994 FSHlog.append 1408583551413 1408583551413 vampire3 0 0
> -9157512308113706720 -8772742027214392277 1393983741752847990 MemStoreFluser.reclaimMemStoreMemory 1408583550882 1408583550882 vampire3 0 0
> -9157512308113706720 -8772742027214392277 1500126877698090608 MemStoreFluser.reclaimMemStoreMemory 1408583550787 1408583550787 vampire3 0 0
> -9157512308113706720 -8772742027214392277 1874700369095337044 MemStoreFluser.reclaimMemStoreMemory 1408583551413 1408583551413 vampire3 0 0
> -9157512308113706720 -8772742027214392277 1906849848459359708 FSHlog.append 1408583550433 1408583550433 vampire3 0 0
> -9157512308113706720 -8772742027214392277 1961933234584121575 FSHlog.append 1408583550848 1408583550848 vampire3 0 0
> -9157512308113706720 -8772742027214392277 2266343209448813140 MemStoreFluser.reclaimMemStoreMemory 1408583550646 1408583550646 vampire3 0 0
> -9157512308113706720 -8772742027214392277 2407757655210440059 FSHlog.append 1408583549892 1408583549892 vampire3 0 0
> -9157512308113706720 -8772742027214392277 2523011262667399269 FSHlog.append 1408583550882 1408583550882 vampire3 0 0
> -9157512308113706720 -8772742027214392277 3108736502762424918 FSHlog.append 1408583549816 1408583549816 vampire3 0 0
> -9157512308113706720 -8772742027214392277 3265253351462452999 FSHlog.append 1408583551353 1408583551353 vampire3 0 0
> -9157512308113706720 -8772742027214392277 3782290252072696548 FSHlog.append 1408583549691 1408583549691 vampire3 0 0
> -9157512308113706720 -8772742027214392277 3932617153218002399 FSHlog.append 1408583551117 1408583551117 vampire3 0 0
> -9157512308113706720 -8772742027214392277 4637467709265165671 FSHlog.append 1408583550930 1408583550930 vampire3 0 0
> -9157512308113706720 -8772742027214392277 4641504416272798886 FSHlog.append 1408583551175 1408583551175 vampire3 0 0
> -9157512308113706720 -8772742027214392277 4751895581931827226 FSHlog.append 1408583550730 1408583550730 vampire3 0 0
> -9157512308113706720 -8772742027214392277 4898702648391404471 MemStoreFluser.reclaimMemStoreMemory 1408583551487 1408583551487 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5030457036664931591 MemStoreFluser.reclaimMemStoreMemory 1408583551117 1408583551117 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5049761513730716063 MemStoreFluser.reclaimMemStoreMemory 1408583549691 1408583549691 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5094640009064004936 MemStoreFluser.reclaimMemStoreMemory 1408583549816 1408583549816 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5130610464420916990 MemStoreFluser.reclaimMemStoreMemory 1408583550319 1408583550319 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5320473260565471886 FSHlog.append 1408583550487 1408583550487 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5342135573783189194 MemStoreFluser.reclaimMemStoreMemory 1408583551353 1408583551353 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5369300667631333426 MemStoreFluser.reclaimMemStoreMemory 1408583549892 1408583549892 vampire3 0 0
> -9157512308113706720 -8772742027214392277 5885097507323228379 MemStoreFluser.reclaimMemStoreMemory 1408583550730 1408583550730 vampire3 0 0
> -9157512308113706720 -8772742027214392277 6490495825248396494 MemStoreFluser.reclaimMemStoreMemory 1408583550930 1408583550930 vampire3 0 0
> -9157512308113706720 -8772742027214392277 6932549808074670920 FSHlog.append 1408583551457 1408583551457 vampire3 0 0
> -9157512308113706720 -8772742027214392277 7173325847922442675 FSHlog.append 1408583550646 1408583550646 vampire3 0 0
> -9157512308113706720 -8772742027214392277 7212936129728780213 FSHlog.append 1408583550538 1408583550538 vampire3 0 0
> -9157512308113706720 -8772742027214392277 7383426442143867066 MemStoreFluser.reclaimMemStoreMemory 1408583550245 1408583550245 vampire3 0 0
> -9157512308113706720 -8772742027214392277 7433364962972107046 FSHlog.append 1408583551487 1408583551487 vampire3 0 0
> -9157512308113706720 -8772742027214392277 7474985993595701432 FSHlog.append 1408583550133 1408583550133 vampire3 0 0
> -9157512308113706720 -8772742027214392277 7614840281462751409 MemStoreFluser.reclaimMemStoreMemory 1408583549938 1408583549938 vampire3 0 0
> -9157512308113706720 -8772742027214392277 8170196673673687334 MemStoreFluser.reclaimMemStoreMemory 1408583550487 1408583550487 vampire3 0 0
> -9157512308113706720 -8689757211756490704 8862530699265124452 Scanner opened on server 1408583549643 1408583549646 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -8809628513124013789 MemStoreFluser.reclaimMemStoreMemory 1408583549866 1408583549866 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -8614147448825223373 FSHlog.append 1408583551258 1408583551258 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -8461301996922757447 MemStoreFluser.reclaimMemStoreMemory 1408583550924 1408583550924 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -8406764722244019587 FSHlog.append 1408583551551 1408583551551 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -7660014738376146778 FSHlog.append 1408583549866 1408583549866 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -7154302428326831666 MemStoreFluser.reclaimMemStoreMemory 1408583550095 1408583550095 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -6505446764892155301 FSHlog.append 1408583550477 1408583550477 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -6216626775812387413 MemStoreFluser.reclaimMemStoreMemory 1408583550070 1408583550070 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -5855537566178482876 MemStoreFluser.reclaimMemStoreMemory 1408583549712 1408583549712 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -5807251233982109133 MemStoreFluser.reclaimMemStoreMemory 1408583551477 1408583551477 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -5712823252385179638 MemStoreFluser.reclaimMemStoreMemory 1408583550577 1408583550577 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -5002829585791850823 FSHlog.append 1408583550404 1408583550404 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -3895120333441853704 MemStoreFluser.reclaimMemStoreMemory 1408583550515 1408583550515 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -3650302107984672290 MemStoreFluser.reclaimMemStoreMemory 1408583550404 1408583550404 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -3102207270801164734 FSHlog.append 1408583550364 1408583550364 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -2837246747317659180 FSHlog.append 1408583550797 1408583550797 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -2679104026417712272 MemStoreFluser.reclaimMemStoreMemory 1408583550477 1408583550477 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -2609632094534266010 MemStoreFluser.reclaimMemStoreMemory 1408583550364 1408583550364 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -2596746230658065592 FSHlog.append 1408583550224 1408583550224 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -2030464490250732194 FSHlog.append 1408583550577 1408583550577 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -1930085883177750249 FSHlog.append 1408583549660 1408583549660 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -1884675849350226195 MemStoreFluser.reclaimMemStoreMemory 1408583551258 1408583551258 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -1712675497421878397 MemStoreFluser.reclaimMemStoreMemory 1408583549822 1408583549822 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -527453899261806460 MemStoreFluser.reclaimMemStoreMemory 1408583550169 1408583550169 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -514631578044874950 MemStoreFluser.reclaimMemStoreMemory 1408583551311 1408583551311 vampire3 0 0
> -9157512308113706720 -8659004356330453160 -359482103605771343 FSHlog.append 1408583549739 1408583549739 vampire3 0 0
> {code}
> [~giacomotaylor]
--
This message was sent by Atlassian JIRA
(v6.2#6252)