Le FAHlog est tout simplement un historique. Avec un client "console", la fenêtre ouverte transcrit tout ce qui se passe en temps réel. Il en est de même des logiciels Fahmon ou Fahspy qui affichent le log avec mise à jour en temps réel. Bien savoir lire le FAHlog est important car c'est bien comprendre ce qui est en train de se passer sous nos yeux et où on en est dans le processus de traitement. Lorsque j'ai débuté dans folding, il y a quelques années, la compréhension de ces lignes étaient bien difficile, malgré une traduction plutôt correcte de ma part. J'essaierai donc de fournir l'explication plutôt qu'une traduction inutile.

Et je profiterai de cette occasion pour décortiquer l'exemple d'un client qui ne peut pas retourner les résultats d'un traitement achevé et montrer qu'en général le processus automatisé s'en sort quand même bien tout seul malgré quelques péripéties.

Nous pouvons voir dans "Les événements dans l'historique FAHlog" que c'est le client qui gère automatiquement le téléchargement ("download") des cores (noyaux de calcul) et des WU (Work Unit = unité de travail) ainsi que le retour des résultats que l'on appelle "upload" dans notre jargon. Mais il arrive que l'upload ou le download rencontre quelques difficultés.

Lorsque les calculs se terminent et que tout se passe bien, l'historique du FAHlog ressemble sensiblement à ceci pour tous les clients :

FAHlog d'un client SMP Linux
...............
[14:39:14] Completed 245001 out of 250001 steps  (98%) (traitement achevé à 98 %)
[14:50:40] Completed 247501 out of 250001 steps  (99%) (traitement achevé à 99 %)
[15:02:07] Completed 250001 out of 250001 steps  (100%) (phase de calcul terminée)
...............
[15:05:42] Sending work to server (le client est prêt à envoyer la WU terminée au serveur)
[15:05:42] Project: 2677 (Run 24, Clone 92, Gen 17) (rappel de l'identifiant de la WU)
[15:05:42] + Attempting to send results [June 27 15:05:42 UTC] (tentative d'envoi des résultats)
[15:05:42] - Reading file work/wuresults_07.dat from core (lecture de la WU dans le slot n°7 de la file d'attente)
[15:05:42]   (Read 52724557 bytes from disk)
[15:05:42] Connecting to http://171.64.65.56:8080/ (connexion à l'url du serveur à l'origine de la WU)
[15:18:52] Posted data. (les données ont été envoyées)
[15:18:53] Initial: 0000; - Uploaded at ~64 kB/s (débit d'upload)
[15:19:04] - Averaged speed for that direction ~63 kB/s (débit moyen habituel)
[15:19:04] + Results successfully sent (Stanford informe du succès de l'envoi)
[15:19:04] Thank you for your contribution to Folding@Home. (de rien hihi)
[15:19:04] + Number of Units Completed: 57 (total de WU envoyées)
...............  et une autre WU est automatiquement téléchargée.

Mais il arrive qu'au moment d'envoyer les résultats vers le serveur qui a attribué la WU, celui-ci soit indisponible, pour diverses raisons (encombrement, maintenance, casse). Après plusieurs échecs, les résultats seront alors redirigés vers un "Collection server", une sorte de serveur de stockage et de transit. Si celui-ci se trouve dans le même état que le premier, le client stockera les résultats dans une file d'attente sur le disque dur de l'ordinateur et réclamera automatiquement le téléchargement d'une autre WU qu'il devrait obtenir :

FAHlog d'un client GPU

[18:44:32] Sending work to server (le client est prêt à envoyer la WU terminée au serveur)
[18:44:32] Project: 5772 (Run 1, Clone 46, Gen 746) (rappel de l'identifiant de la WU)
[18:44:32] - Read packet limit of 540015616... Set to 524286976.

[18:44:32] + Attempting to send results [June 25 18:44:32 UTC] (tentative d'envoi des résultats)
[18:44:32] - Reading file work/wuresults_04.dat from core (lecture de la WU dans le slot n°4 de la file d'attente)
[18:44:32]   (Read 100430 bytes from disk)
[18:44:32] Connecting to http://171.67.108.11:8080/ (connexion à l'url du serveur à l'origine de la WU)
[18:44:34] - Couldn't send HTTP request to server (la requête ne parvient pas au serveur)
[18:44:34] + Could not connect to Work Server (results) (impossible de se connecter au serveur)
[18:44:34]     (171.67.108.11:8080)                     
[18:44:34] + Retrying using alternative port (tentative avec un port alternatif)
[18:44:34] Connecting to http://171.67.108.11:80/ (connexion à l'url du serveur à l'origine de la WU)
[18:44:36] - Couldn't send HTTP request to server (la requête ne parvient pas au serveur)
[18:44:36] + Could not connect to Work Server (results) (impossible de se connecter au serveur)
[18:44:36]     (171.67.108.11:80)                       
[18:44:36] - Error: Could not transmit unit 04 (completed June 25) to work server.
                 (le client informe que la WU terminée stockée dans le slot n°4 de la file d'attente n'a pas pu être envoyée)
[18:44:36] - 1 failed uploads of this unit. (constat d'un 1er échec d'upload)
[18:44:36]   Keeping unit 04 in queue. (les résultats sont gardés dans le slot n°4 de la file d'attente)
[18:44:36] Trying to send all finished work units
                 (tentative d'envoi périodique automatique de toutes les WU de la file d'attente)
[18:44:36] Project: 5772 (Run 1, Clone 46, Gen 746) (rappel de l'identifiant de la WU en attente d'envoi)
[18:44:36] - Read packet limit of 540015616... Set to 524286976.

[18:44:36] + Attempting to send results [June 25 18:44:36 UTC] (nouvelle tentative d'upload)
[18:44:36] - Reading file work/wuresults_04.dat from core
[18:44:36]   (Read 100430 bytes from disk)
[18:44:36] Connecting to http://171.67.108.11:8080/
[18:44:38] - Couldn't send HTTP request to server
[18:44:38] + Could not connect to Work Server (results)
[18:44:38]     (171.67.108.11:8080)
[18:44:38] + Retrying using alternative port
[18:44:38] Connecting to http://171.67.108.11:80/
[18:44:40] - Couldn't send HTTP request to server
[18:44:40] + Could not connect to Work Server (results)
[18:44:40]     (171.67.108.11:80)
[18:44:40] - Error: Could not transmit unit 04 (completed June 25) to work server.
[18:44:40] - 2 failed uploads of this unit. (constat du 2ème échec d'upload)
[18:44:40] - Read packet limit of 540015616... Set to 524286976.

[18:44:40] + Attempting to send results [June 25 18:44:40 UTC] (3ème tentative d'upload)
[18:44:40] - Reading file work/wuresults_04.dat from core
[18:44:40]   (Read 100430 bytes from disk)
[18:44:40] Connecting to http://171.67.108.25:8080/ (redirection vers un "Collection server", stockage et transit)
[18:44:41] - Couldn't send HTTP request to server
[18:44:41]   (Got status 503) (c'est le code qui informe que le serveur est saturé)
[18:44:41] + Could not connect to Work Server (results)
[18:44:41]     (171.67.108.25:8080)
[18:44:41] + Retrying using alternative port
[18:44:41] Connecting to http://171.67.108.25:80/
[18:44:42] - Couldn't send HTTP request to server
[18:44:42]   (Got status 503)
[18:44:42] + Could not connect to Work Server (results)
[18:44:42]     (171.67.108.25:80)
[18:44:42]   Could not transmit unit 04 to Collection server; keeping in queue.
[18:44:42] + Sent 0 of 1 completed units to the server
...............  ici le client reconnaît momentanément son échec et va tenter de télécharger une WU, tout en continuant à faire des tentatives périodiques et automatiques d'upload ou bien des tentatives d'upload spécifiques à cette WU en attente :

[18:44:42] - Preparing to get new work unit... (le client informe qu'il lance la procédure d'appel d'une nouvelle WU)
[18:44:42] + Attempting to get work packet     (consultation du fichier de configuration
[18:44:42] - Will indicate memory of 2047 MB  pour le choix de la WU à télécharger)
[18:44:42] - Connecting to assignment server (tentative de connexion au serveur d'assignement d'une WU)
[18:44:42] Connecting to http://assign-GPU.stanford.edu:8080/ (connexion au port des serveurs d'assignement)
[18:44:44] Posted data.
[18:44:44] Initial: 40AB; - Successful: assigned to (171.64.65.20). (ce serveur est choisi pour l'attribution de la WU)
[18:44:44] + News From Folding@Home: Welcome to Folding@Home
[18:44:44] Loaded queue successfully.
[18:44:44] Connecting to http://171.64.65.20:8080/ (connexion à l'url du serveur)
[18:44:45] Posted data. (données reçues)
[18:44:45] Initial: 0000; - Receiving payload (expected size: 69068) (volume des données reçues)
[18:44:47] - Downloaded at ~33 kB/s (débit de téléchargement)
[18:44:47] - Averaged speed for that direction ~32 kB/s (débit moyen habituel)
[18:44:47] + Received work. (confirmation que la nouvelle WU a bien été reçue)
[18:44:47] Trying to send all finished work units
                 (tentative d'envoi périodique automatique de toutes les WU de la file d'attente)
[18:44:47] Project: 5772 (Run 1, Clone 46, Gen 746) (rappel de l'identifiant de la WU en attente d'envoi)
[18:44:47] - Read packet limit of 540015616... Set to 524286976.

[18:44:47] + Attempting to send results [June 25 18:44:47 UTC] (3ème tentative d'envoi spécifique)
[18:44:47] - Reading file work/wuresults_04.dat from core
[18:44:47]   (Read 100430 bytes from disk)
[18:44:47] Connecting to http://171.67.108.11:8080/ (connexion au serveur à l'origine de la WU)
[18:44:50] - Couldn't send HTTP request to server
[18:44:50] + Could not connect to Work Server (results)
[18:44:50]     (171.67.108.11:8080)
[18:44:50] + Retrying using alternative port
[18:44:50] Connecting to http://171.67.108.11:80/
[18:44:52] - Couldn't send HTTP request to server
[18:44:52] + Could not connect to Work Server (results)
[18:44:52]     (171.67.108.11:80)
[18:44:52] - Error: Could not transmit unit 04 (completed June 25) to work server.
[18:44:52] - 3 failed uploads of this unit. (constat du 3ème échec d'upload)
[18:44:52] - Read packet limit of 540015616... Set to 524286976.

[18:44:52] + Attempting to send results [June 25 18:44:52 UTC] (encore une tentative d'upload)
[18:44:52] - Reading file work/wuresults_04.dat from core
[18:44:52]   (Read 100430 bytes from disk)
[18:44:52] Connecting to http://171.67.108.25:8080/ (redirection vers un "Collection server")
[18:44:52] - Couldn't send HTTP request to server
[18:44:52]   (Got status 503) (le serveur est toujours encombré)
[18:44:52] + Could not connect to Work Server (results)
[18:44:52]     (171.67.108.25:8080)
[18:44:52] + Retrying using alternative port
[18:44:52] Connecting to http://171.67.108.25:80/
[18:44:53] - Couldn't send HTTP request to server
[18:44:53]   (Got status 503)
[18:44:53] + Could not connect to Work Server (results)
[18:44:53]     (171.67.108.25:80)
[18:44:53]   Could not transmit unit 04 to Collection server; keeping in queue.
[18:44:53] + Sent 0 of 1 completed units to the server
[18:44:53] + Closed connections
                
Cette fois-ci, le client informe qu'il abandonne l'upload spécifique de cette WU, laissant alors la main à l'upload périodique automatique. Et il va tranquillement continuer à s'occuper de la nouvelle WU qu'il a déjà téléchargée :

[18:44:53]
[18:44:53] + Processing work unit (le client lance la procédure de traitement de la nouvelle WU)
[18:44:53] Core required: FahCore_14.exe (il a besoin du FahCore_14 pour traiter la nouvelle WU)
[18:44:53] Core found. (ce core est présent dans le dossier)
[18:44:53] Working on queue slot 05 [June 25 18:44:53 UTC] (la WU est là aussi dans le slot n°5 de la file d'attente)
[18:44:53] + Working ...
[18:44:53] - Calling '.\FahCore_14.exe -dir work/ -suffix 05 -checkpoint 15 -verbose -lifeline 1304 -version 623'

[18:44:53]
[18:44:53] *------------------------------*
[18:44:53] Folding@Home GPU Core - Beta
[18:44:53] Version 1.25 (Mon Mar 2 19:49:32 PST 2009) (c'est la version du FahCore_14)
[18:44:53]
[18:44:53] Compiler  : Microsoft (R) 32-bit C/C++ Optimizing Compiler Version 14.00.50727.762 for 80x86
[18:44:53] Build host: vspm46
[18:44:53] Board Type: Nvidia
[18:44:53] Core      :
[18:44:53] Preparing to commence simulation
[18:44:53] - Looking at optimizations... (recherche des optimisations)
[18:44:53] - Created dyn
[18:44:53] - Files status OK
[18:44:53] - Expanded 68556 -> 357580 (decompressed 521.5 percent)
[18:44:53] Called DecompressByteArray: compressed_data_size=68556 data_size=357580, decompressed_data_size=357580 diff=0
[18:44:53] - Digital signature verified
[18:44:53]
[18:44:53] Project: 5911 (Run 1, Clone 41, Gen 6) (affichage de l'identifiant de la WU à traiter)
[18:44:53]
[18:44:54] Assembly optimizations on if available.
[18:44:54] Entering M.D.
[18:45:00] Tpr hash work/wudata_05.tpr:  3795242228 920204709 1867759447 445319904 3180685501
[18:45:01] Working on Protein
[18:45:02] Client config found, loading data.
[18:45:02] Starting GUI Server (les calculs peuvent commencer)
[18:50:04] Completed 1%
[18:54:04] Completed 2%
............... la nouvelle WU est en cours de traitement mais le client n'a pas dit son dernier mot pour la WU terminée et stockée sur le disque dur dans le slot n°4 de la file d'attente. Il a un programme d'upload périodique automatique :

[00:31:08] Completed 78%
[00:36:23] Completed 79%
[00:39:08] - Autosending finished units... [June 26 00:39:08 UTC] (lancement de la procédure automatique d'upload)
[00:39:08] Trying to send all finished work units
[00:39:08] Project: 5772 (Run 1, Clone 46, Gen 746) (rappel de l'identifiant de la WU en attente d'envoi)
[00:39:08] - Read packet limit of 540015616... Set to 524286976.

[00:39:08] + Attempting to send results [June 26 00:39:08 UTC] (tentative d'upload automatique)
[00:39:08] - Reading file work/wuresults_04.dat from core
[00:39:08]   (Read 100430 bytes from disk)
[00:39:08] Connecting to http://171.67.108.11:8080/ (connexion à l'url du serveur à l'origine de la WU)
[00:39:21] Posted data. (les résultats ont été envoyés)
[00:39:21] Initial: 0000; - Uploaded at ~7 kB/s (débit de l'upload, le serveur semble encore bien encombré)
[00:39:21] - Averaged speed for that direction ~21 kB/s (débit moyen habituel de l'upload)
[00:39:21] + Results successfully sent
[00:39:21] Thank you for your contribution to Folding@Home. (OUF)
[00:39:21] + Number of Units Completed: 1491

[00:39:21] + Sent 1 of 1 completed units to the server (la seule WU en attente dans la queue a bien été envoyée)
[00:39:21] - Autosend completed (fin de la procédure automatique d'upload)
[00:40:58] Completed 80% (le calcul de la WU en cours de traitement continue toujours)
[00:45:09] Completed 81%

Nous avons pu voir que le client est à même de gérer seul le téléchargement de la WU à traiter, le lancement de la procédure de calcul, le retour des résultats à son serveur d'origine ou à un "Collection server", et cela malgré quelques péripéties.

J'espère que mes annotations (même imparfaites) aideront les nouveaux plieurs à lire le FAHlog avec moins d'appréhension que moi, à mes débuts.