Usa ftrace

ftrace è uno strumento di debug che consente di capire cosa succede all'interno del kernel Linux. Le seguenti sezioni descrivono nel dettaglio le funzionalità di base ftrace, ftrace utilizzo con atrace (che acquisisce gli eventi del kernel) e ftrace dinamica.

Per dettagli sulla funzionalità ftrace avanzata non disponibile da systrace, consulta la documentazione relativa a ftrace all'indirizzo <kernel tree>/Documentation/trace/ftrace.txt

Acquisire eventi kernel con atrace

atrace (frameworks/native/cmds/atrace) utilizza ftrace per acquisire eventi kernel. A sua volta, systrace.py (o run_systrace.py nelle versioni successive di Catapult) utilizza ADB per eseguire l'atrace sul dispositivo. atrace esegue le seguenti operazioni:

  • Configura il tracciamento della modalità utente impostando una proprietà (debug.atrace.tags.enableflags)
  • Abilita la funzionalità ftrace desiderata scrivendo nell'istanza appropriata ftrace sysfs node. Tuttavia, poiché ftrace supporta più funzionalità, puoi impostare alcuni nodi sysfs e poi utilizza atrace.

Con l'eccezione del tracciamento del tempo di avvio, utilizza l'atrace per impostare con il valore appropriato. La proprietà è una maschera di bit e non c'è niente di meglio un modo per determinare i valori corretti, senza limitarsi a esaminare l'intestazione appropriata (che potrebbe variare tra una release di Android e l'altra).

Attiva eventi ftrace

I nodi ftrace sysfs si trovano in /sys/kernel/tracing e tracciano eventi sono suddivisi in categorie in /sys/kernel/tracing/events.

Per abilitare gli eventi in base alla categoria, utilizza: 

echo 1 > /sys/kernel/tracing/events/irq/enable

Per attivare gli eventi per singolo evento, utilizza: 

echo 1 > /sys/kernel/tracing/events/sched/sched_wakeup/enable

Se sono stati abilitati eventi aggiuntivi tramite la scrittura sui nodi sysfs, non essere reimpostati da atrace. Un modello comune per la generazione di dispositivi Qualcomm è l'attivazione di kgsl (GPU) e mdss (tracciamento della pipeline) e poi usa l'atrace o systrace:

adb shell "echo 1 > /sys/kernel/tracing/events/mdss/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/kgsl/enable"
./systrace.py sched freq idle am wm gfx view binder_driver irq workq ss sync -t 10 -b 96000 -o full_trace.html

Puoi anche usare ftrace senza atrace o systrace, che utile quando vuoi tracce solo kernel (o se hai dedicato tempo a scrivere manualmente la proprietà di tracciamento in modalità utente). Per correre solo con ftrace:

  1. Imposta la dimensione del buffer su un valore abbastanza grande per la traccia: 
    echo 96000 > /sys/kernel/tracing/buffer_size_kb
  2. Attiva il tracciamento: 
    echo 1 > /sys/kernel/tracing/tracing_on
  3. Esegui il test, quindi disabilita il tracciamento: 
    echo 0 > /sys/kernel/tracing/tracing_on
  4. Esegui il dump della traccia: 
    cat /sys/kernel/tracing/trace > /data/local/tmp/trace_output

trace_output fornisce la traccia in formato testo. Per visualizzarla usando Catapulta, prendi Catapulta repository Git da GitHub ed esegui trace2html:

catapult/tracing/bin/trace2html ~/path/to/trace_file

Per impostazione predefinita, viene scritto trace_file.html nello stesso .

Correla eventi

Spesso è utile osservare la visualizzazione Catapulta e la ftrace. registrare simultaneamente; Ad esempio, alcuni eventi ftrace (soprattutto le specifiche del quelli) non vengono visualizzati da Catapult. Tuttavia, i timestamp di Catapult sono in relazione al primo evento nella traccia o a un timestamp specifico dumping da atrace, mentre i timestamp ftrace non elaborati si basano su un valore con orologio assoluto nel kernel Linux.

Per trovare un determinato evento ftrace da un evento Catapult:

  1. Apri il log ftrace non elaborato. Le tracce nelle versioni recenti di systrace sono sono compresse per impostazione predefinita:
    • Se hai acquisito la tua traccia di sistema con --no-compress, è in il file html nella sezione che inizia con BEGIN TRACE.
    • In caso contrario, esegui html2trace dal Catapulta struttura (tracing/bin/html2trace) per decomprimere la traccia.
  2. Trova il timestamp relativo nella visualizzazione Catapult.
  3. Trova una riga all'inizio della traccia contenente tracing_mark_sync. Dovrebbe avere il seguente aspetto: 
    <5134>-5134  (-----) [003] ...1    68.104349: tracing_mark_write: trace_event_clock_sync: parent_ts=68.104286

    Se questa linea non esiste (o se hai utilizzato ftrace senza atrace), i tempi saranno relativi al primo evento nel log ftrace.
    1. Somma il timestamp relativo (in millisecondi) al valore in parent_ts (in secondi).
    2. Cerca il nuovo timestamp.

Questi passaggi dovrebbero farti avvicinare (o almeno molto vicino) all'evento.

Usa ftrace dinamico

Quando systrace e ftrace standard sono insufficienti, ce n'è un'ultima ricorso disponibile: Dynamic ftrace. L'ftrace dinamico prevede la riscrittura di codice kernel dopo l'avvio e di conseguenza non è disponibile in produzione per motivi di sicurezza. Tuttavia, ogni singolo bug difficile Il 2015 e il 2016 sono stati la causa principale dell'utilizzo di ftrace dinamici. In particolare molto utile per eseguire il debug di periodi di sospensione senza interruzioni perché consente di ottenere un'analisi dello stack nel kernel ogni volta che premi la funzione che attiva un sonno senza interruzioni. Puoi anche eseguire il debug di sezioni in cui gli interrupt e i prerilasci disabilitati, molto utile per provare i problemi.

Per attivare ftrace dinamica, modifica la defconfig del kernel:

  1. Rimuovi CONFIG_STRICT_MEMORY_RWX (se presente). Se hai la versione 3.18 o e arm64, non c'è.
  2. Aggiungi quanto segue: CONFIG_DYNAMIC_FTRACE=y, CONFIG_FUNCTION_TRACER=y, CONFIG_IRQSOFF_TRACER=y, CONFIG_FUNCTION_PROFILER=y e CONFIG_PREEMPT_TRACER=y
  3. Ricrea e avvia il nuovo kernel.
  4. Esegui il comando seguente per verificare la presenza di utilità di traccia disponibili: 
    cat /sys/kernel/tracing/available_tracers
  5. Conferma che il comando restituisce function, irqsoff, preemptoff e preemptirqsoff.
  6. Esegui il comando seguente per assicurarti che ftrace dinamico funzioni: 
    cat /sys/kernel/tracing/available_filter_functions | grep <a function you care about>

Dopo aver completato questi passaggi, avrai ftrace dinamico, il profiler di funzione, il profiler irqsoff e il profiler prerilascio disponibile. Abbiamo fortemente consigliamo di leggere la documentazione di ftrace su questi argomenti prima di usare perché sono potenti ma complesse. irqsoff e preemptoff sono principalmente è utile per verificare se i conducenti possono lasciare interruzioni o prerilascio spento troppo a lungo.

Il profiler di funzioni è l'opzione migliore per i problemi di prestazioni ed è spesso usato per scoprire dove viene chiamata una funzione.

In questo problema, l'utilizzo di un Pixel XL per scattare una foto HDR+, quindi la rotazione del mirino causava ogni volta rottura. Abbiamo utilizzato la funzione profiler eseguire il debug del problema in meno di un'ora. Per seguire l'esempio, scaricare il file ZIP delle tracce (che include include altre tracce a cui si fa riferimento in questa sezione), decomprimi il file e apri trace_30898724.html nel browser.

La traccia mostra diversi thread nel processo cameraserver bloccati in di sonno senza interruzioni il giorno ion_client_destroy. È una soluzione costosa funzione, ma dovrebbe essere chiamata molto raramente perché i client ion dovrebbero prevedono molte allocazioni. Inizialmente, la colpa ricadde sul codice esagono in Halide, che è stata una delle cause del problema (ha creato un nuovo cliente per ogni di ionizzazione e ha distrutto il client quando l'allocazione è stata liberata, era troppo costoso). Trasferimento a un singolo client ion per tutti gli esagono allocazioni ha migliorato la situazione, ma il problema non è stato risolto.

A questo punto dobbiamo sapere chi sta chiamando ion_client_destroy, È il momento di usare la funzione profiler:

  1. Poiché a volte le funzioni vengono rinominate dal compilatore, verifica ion_client_destroy è presente utilizzando: 
    cat /sys/kernel/tracing/available_filter_functions | grep ion_client_destroy
  2. Dopo averlo verificato, utilizzalo come filtro ftrace: 
    echo ion_client_destroy > /sys/kernel/tracing/set_ftrace_filter
  3. Attiva il profiler di funzione: 
    echo function > /sys/kernel/tracing/current_tracer
  4. Attiva le analisi dello stack ogni volta che viene chiamata una funzione di filtro: 
    echo func_stack_trace > /sys/kernel/tracing/trace_options
  5. Aumenta la dimensione del buffer: 
    echo 64000 > /sys/kernel/tracing/buffer_size_kb
  6. Attiva il tracciamento: 
    echo 1 > /sys/kernel/tracing/trace_on
  7. Esegui il test e recupera la traccia: 
    cat /sys/kernel/tracing/trace > /data/local/tmp/trace
  8. Visualizza la traccia per vedere molte analisi dello stack: 
        cameraserver-643   [003] ...1    94.192991: ion_client_destroy <-ion_release
    cameraserver-643   [003] ...1    94.192997: <stack trace>
 => ftrace_ops_no_ops
 => ftrace_graph_call
 => ion_client_destroy
 => ion_release
 => __fput
 => ____fput
 => task_work_run
 => do_notify_resume
 => work_pending

Dall'ispezione del driver ionico possiamo vedere che ion_client_destroy è stato sottoposto a spam da una funzione dello spazio utente che si chiude un fd a /dev/ion, non un driver kernel casuale. Cercando Codebase Android per \"/dev/ion\", troviamo diversi driver di fornitore facendo la stessa cosa del cacciavite esagonale e di apertura/chiusura /dev/ion (creazione e eliminazione di un nuovo client ion) ogni volta che una nuova allocazione degli ioni. Modificale in usa un solo client ion per tutta la durata del processo ha corretto il bug.

Se i dati del profiler di funzione non sono abbastanza specifici, puoi combinare tracepoint ftrace con il profiler di funzione. gli eventi ftrace possono essere abilitati esattamente come al solito e saranno interlacciati con la tua traccia. Questa opzione è ideale se di tanto in tanto c'è un sonno lungo e ininterrotto in un determinato funzione di cui si desidera eseguire il debug: imposta il filtro ftrace sulla funzione desiderata, attivare i tracepoint, creare una traccia. Puoi analizzare la traccia risultante con trace2html, trova l'evento che ti interessa, poi recupera analisi dello stack nelle vicinanze nella traccia non elaborata.

Usa Lockstat

A volte, ftrace non è sufficiente e devi davvero eseguire il debug di ciò che sembra conflittuale del blocco kernel. C'è un'altra opzione kernel che vale la pena provare: CONFIG_LOCK_STAT. Questa è l'ultima risorsa perché è estremamente è difficile lavorare sui dispositivi Android perché aumenta le dimensioni oltre quello che è in grado di gestire la maggior parte dei dispositivi.

Lockstat utilizza invece il debug di blocco dell'infrastruttura, utile per molte altre app. Per tutti lavorare sulla visualizzazione del dispositivo dovrebbe trovare un modo per far funzionare quell'opzione su tutti i dispositivi perché ci sarà un momento in cui "Se solo potessi attivare LOCK_STAT, potrei confermare o confutare la richiesta come problema in cinque minuti invece che in cinque giorni".

In questo problema, il thread SCHED_FIFO si è bloccato quando tutti i core erano al massimo vengono caricati con thread non SCHED_FIFO. Abbiamo rilevato tracce di un blocco significativo contesa su un fd in app VR, ma non siamo riusciti a identificare facilmente il fd in uso. Per seguire l'esempio, scarica il file ZIP file di tracce (che include anche altre tracce a cui si fa riferimento nel decomprimi il file e apri il file trace_30905547.html nel browser.

Abbiamo ipotizzato che la piattaforma stessa fosse la fonte della contesa del blocco, quando un il thread a bassa priorità inizierà a scrivere in ftrace pipe e poi ottiene prerilasciata prima di poter rilasciare il blocco. Si tratta dello scenario peggiore che è stata esacerbata da un mix di thread a priorità estremamente bassa che scrivono al ftrace insieme ad alcuni thread con priorità più alta che ruotano sulle CPU simulare un dispositivo completamente caricato.

Poiché non è stato possibile utilizzare ftrace per il debug, abbiamo risolto LOCK_STAT e poi disattivato tutte le altre operazioni di tracciamento dall'app. I risultati mostravano la serratura la contesa proveniva in realtà da ftrace perché nessuna delle contese è apparsa in la traccia del blocco quando ftrace non era in esecuzione.

Se riesci ad avviare un kernel con l'opzione di configurazione, il tracciamento del blocco è simile ftrace:

  1. Attiva il tracciamento: 
    echo 1 > /proc/sys/kernel/lock_stat
  2. Esegui il test.
  3. Disattiva il tracciamento: 
    echo 0 > /proc/sys/kernel/lock_stat
  4. Esegui il dump della traccia: 
    cat /proc/lock_stat > /data/local/tmp/lock_stat

Per informazioni sull'interpretazione dell'output risultante, consulta la documentazione di lockstat alle ore <kernel>/Documentation/locking/lockstat.txt.

Utilizza i punti di traccia dei fornitori

Utilizza prima i tracepoint upstream, ma a volte dovrai usare quelli del fornitore:

  { "gfx",        "Graphics",         ATRACE_TAG_GRAPHICS, {
        { OPT,      "events/mdss/enable" },
        { OPT,      "events/sde/enable" },
        { OPT,      "events/mali_systrace/enable" },
    } },

I tracepoint sono estendibili dal servizio HAL che ti consente di aggiungere tracce specifiche del dispositivo punti/categorie. I tracepoint sono integrati con perfetto, atrace/systrace e con il sistema on-device app di tracciamento.

Le API per l'implementazione di tracepoint/categorie sono:

  • listCategories()genera (vec<TrackingCategory> categorie);
  • EnableCategories(vec<string>categories) genera (Status status);
  • disattivaAllCategories() genera (stato di stato);
di Gemini Advanced. Per ulteriori informazioni, fai riferimento alla definizione e all'implementazione predefinita dell'HAL in AOSP: