LogHash: le GPS de vos logs de debug - Brown Bag Lunch @ Deezer HQ

Les logs, c'est le bordel. Non ? Ben plus maintenant :) https://github.com/cmaneu/loghash-spec

Transcript

1. Let’s talk about logs
   Baby
   

   View Slide

2. View Slide

3. System.Windows.Data Error: BindingExpression path error: 'CanExecute' property not found on 'Deezer.UI.DelegateCommand' 'Deezer.UI.DelegateCommand'
   (HashCode=15035499). BindingExpression: Path='PlayCommand.CanExecute' DataItem='Deezer.DeezerAudioViewModel' (HashCode=1101770); target element is
   'System.Windows.Controls.Button' (Name=''); target property is 'IsEnabled' (type 'System.Boolean')..
   System.Windows.Data Error: BindingExpression path error: 'CanExecute' property not found on 'Deezer.UI.DelegateCommand' 'Deezer.UI.DelegateCommand'
   (HashCode=9915935). BindingExpression: Path='PauseCommand.CanExecute' DataItem='Deezer.DeezerAudioViewModel' (HashCode=1101770); target element is
   'System.Windows.Controls.Button' (Name=''); target property is 'IsEnabled' (type 'System.Boolean')..
   [15:18:22] App : DAVM Update Shuffle repeat status
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Globalization.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Collections.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.IO.ni.dll'. Cannot find or open the PDB file.
   $$$$$$$$$$$$$$$$$$ HasAccessToDeezer> result=True, request took (ms): 1136
   [15:18:22] DeezerRuntimeSettings : UpdateInternetAccess: [forced=False] before=True, after=True
   ROOT FRAME NAVIGATING (uri='/Login')
   BOOTSCREEN> ManageUnloggedUser - Time elapsed (ms): 1160
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Linq.ni.dll'. Cannot find or open the PDB file.
   BOOTSCREEN> END - Time elapsed (ms): 1252<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
   +++++++++++++++++++++++ PAGE CREATED 'LoginPage' +++++++++++++++++++++++
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Reflection.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\Data\Programs\{0AC0860A-B966-4004-817C-8AB50BD22511}\Install\microsoft.expression.drawing.DLL'.
   Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Runtime.Extensions.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Threading.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Dynamic.Runtime.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Linq.Expressions.ni.dll'. Cannot find or open the PDB file.
   [15:18:23] App : >>>>>>>>>>>>>>>>>>>>>>>>>> Resetting Navigation Stack (removeHome=True) <<<<<<<<<<<<<<<<<<<<<<<<
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.ServiceModel.Web.ni.dll'. Cannot find or open the PDB file.
   [15:18:23] DeezerDataProvider : MobileAuthenticate(buildId=WindowsPhone8, version=2.4.0.0, lang=us)
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Reflection.Extensions.ni.dll'. Cannot find or open the PDB file.
   [15:18:23] HttpDataClient : ExecuteQuery(uri=http://api.deezer.com?&buildId=WindowsPhone8&version=2.4.0.0&operator=Fake GSM Network&lang=us, postData=)
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.ObjectModel.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Xml.XDocument.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'C:\windows\system32\System.Text.RegularExpressions.ni.dll'. Cannot find or open the PDB file.
   'TaskHost.exe' (CoreCLR: Silverlight AppDomain): Loaded 'Anonymously Hosted DynamicMethods Assembly'.
   [15:18:25] DeezerDataProvider : >>>>>>>>>>>>>>>>>>>>>>> DataServerUrl changed -> doing auth on new server.
   [15:18:25] DeezerDataProvider : MobileAuthenticate(buildId=WindowsPhone8, version=2.4.0.0, lang=us)
   [15:18:25] HttpDataClient : ExecuteQuery(uri=https://api.deezer.com/? &buildId=WindowsPhone8&version=2.4.0.0&operator=Fake GSM Network&lang=us, postData=)
   

   View Slide

4. Donner du sens à ses logs : Semantic logging
   •TechLogs ? 
   •Microsoft Semantic Loggin AB (EntLib)
   

   View Slide

5. Donner du sens à ses logs : Semantic logging
   [Event(1, Message = "Application Failure: {0}",
   Level = EventLevel.Critical, Keywords = Keywords.Diagnostic)]
   internal void Failure(string message)
   {
   this.WriteEvent(1, message);
   }
   [Event(2, Message = "Starting up.", Keywords = Keywords.Perf,
   Level = EventLevel.Informational)]
   internal void Startup()
   

   View Slide

6. Les logs n’ont pas qu’une vie
   •Debug
   •Prod / DevOps
   •Analytics
   •Advertising, support, user testing, …
   

   View Slide

7. When Markdown ❤ logs
   It’s a #loghash !
   

   View Slide

8. Loghash Manifesto
   •Un moyen simple de sémantiser ses logs
   •Commencer petit, sans friction
   • Bring your own logs
   • Bring your own log library
   • Bring yourself only, not all your team
   • …
   •Rendre les logs pertinents sur tout le cycle de vie de
   l’app
   

   View Slide

9. www.loghash.com
   

   View Slide

10. Loghash 101
    Toute chaîne de caractère est une chaîne Loghash
    

    View Slide

11. Loghash 101 - Tagging
    Un hashtag permet de catégoriser une ligne de log
    Starting catalog import of Katy Perry
    album from EMI
    Starting #catalog #import of Katy Perry
    album from EMI
    

    View Slide

12. Loghash 101 - Tagging
    Starting #catalog #import of Katy Perry
    album from EMI
    Starting #catalog.import of Katy Perry
    album from EMI
    

    View Slide

13. Loghash 101 - Tagging
    #error #catalog.import of Katy Perry album
    from EMI failed
    • #error
    • #warn
    • #info
    • #debug
    • #trace
    

    View Slide

14. Loghash 101 - Identifiers
    #catalog.import started from
    @provider:emi for @artist:"Katy Perry"
    

    View Slide

15. Loghash 101 – Object dumps
    Google Play callback: #inapppurchase @userid:42
    @{"iap-product-id":42,"success":true}
    

    View Slide

16. Loghash 101 – Secure content
    User license renewed
    @$userEncryptionKey:"sdhq238hfkqsd82hf="
    

    View Slide

17. Loghash 101 – Mais encore…
    • Compteurs (Graphite ? Kibana ?)
    @{"__count":"user.offlinealbums","v":1}
    • Timings
    @{"__timing":"account creation","d":323}
    • Progressions
    @{"__progress":"demo","p":0.3721}
    • Custom viewers
    @{"__e":"android.activity.lifecycle","d":{"name":"feedactivit
    y","status":"created"}}
    

    View Slide

18. What’s next ?
    •Logstash ingestion plugin (log > Kibana)
    •Complete JS parser lib
    •Complete C# parser lib
    •Web interface
    •Logger libs
    •Visual Studio plugin, NSLogger app, ADB tool, …
    

    View Slide

19. Qui utilise ce machin là ?
    

    View Slide

20. Catalog team
    @date:"2015-03-17 14:43:11" #info #album @id:9727118 #publish
    @date:"2015-03-17 14:43:11" #info #track @id:68732528
    #publish
    @date:"2015-03-17 14:43:11" #warn #track @id:68732528
    #waiting
    @date:"2015-03-17 14:43:11" #error #album @id:9727118
    #exception @message:"THIS IS ERROR MESSAGE !"
    @date:"2015-03-17 14:43:11" #info #album @id:9727118 #publish
    @date:"2015-03-17 14:50:38" #info #track @id:101038241 #skip
    @date:"2015-03-17 14:50:38" #info #track @id:101037571 #skip
    

    View Slide

21. Qui utilise ce machin là ?
    

    View Slide

22. Avant
    command> nice -n 20 php -c ~/php.ini -d memory_limit=4000M script.php --debug --
    name='catalog/import/indexer' --provider-id='2' --host='172.16.1.103' --port='11112' >>
    /data/tmp/script_server/logs/romain_indexer_2015-03-18.log &
    command> nice -n 20 php -c ~/php.ini -d memory_limit=4000M script.php --debug --
    name='catalog/import/indexer' --provider-id='3' --host='172.16.1.103' --port='11112' >>
    /data/tmp/script_server/logs/romain_indexer_2015-03-18.log &
    command> nice -n 20 php -c ~/php.ini -d memory_limit=4000M script.php --debug --
    name='catalog/import/parser' --delivery-id='143081' --provider-id='2' --host='172.16.1.103'
    --port='11112' >> /data/tmp/script_server/logs/romain_parser_2015-03-18.log &
    command> nice -n 20 php -c ~/php.ini -d memory_limit=4000M script.php --debug --
    name='catalog/import/simulatevdo' --delivery-id='143081' --provider-id='2' --
    host='172.16.1.103' --port='11112' >> /data/tmp/script_server/logs/romain_simulatevdo_2015-
    03-18.log &
    command> nice -n 20 php -c ~/php.ini -d memory_limit=4000M script.php --debug --
    name='catalog/import/parser' --delivery-id='143091' --provider-id='2' --host='172.16.1.103'
    --port='11112' >> /data/tmp/script_server/logs/romain_parser_2015-03-18.log &
    command> nice -n 20 php -c ~/php.ini -d memory_limit=4000M script.php --debug --
    name='catalog/import/simulatevdo' --delivery-id='143091' --provider-id='2' --
    host='172.16.1.103' --port='11112' >> /data/tmp/script_server/logs/romain_simulatevdo_2015-
    03-18.log &
    command> nice -n 20 php -c ~/php.ini -d memory_limit=4000M script.php --debug --
    name='catalog/import/parser' --delivery-id='143101' --provider-id='2' --host='172.16.1.103'
    

    View Slide

23. Après
    @date:"2015-03-07 23:01:29" #indexer
    @{"provider_id":1,"host":"10.101.1.127","port":11111}
    @date:"2015-03-07 23:56:48" #importer
    @{"delivery_id":39654811,"provider_id":1,"host":"10.101.1.127","port":111
    11}
    @date:"2015-03-07 23:56:55" #importer
    @{"delivery_id":39654821,"provider_id":1,"host":"10.101.1.127","port":111
    11}
    @date:"2015-03-07 23:56:57" #importer
    @{"delivery_id":39654831,"provider_id":1,"host":"10.101.1.127","port":111
    11}
    @date:"2015-03-10 04:20:14" #indexer
    @{"provider_id":548,"host":"10.101.1.127","port":11111}
    @date:"2015-03-10 04:20:14" #indexer
    @{"provider_id":552,"host":"10.101.1.127","port":11111}
    @date:"2015-03-10 04:20:14" #indexer
    @{"provider_id":554,"host":"10.101.1.127","port":11111}
    

    View Slide

24. View Slide

25. View Slide

26. Qui utilise ce machin là ?
    •Deezer !
    • Windows Phone
    • Equipe Catalogue
    • Vous tous dès cet aprèm 
    • (moi, dans mes projets perso)
    

    View Slide

27. Questions ?
    

    View Slide