Uncategorized

    Dépannage Maven, versions instables et infrastructure open source

    Dépannage Maven, versions instables et infrastructure open source

    Donald Knuth a écrit que l’optimisation prématurée est la racine de tous les maux. Pour ma part, je crois que tout le mal vient de constructions faussement défaillantes. Rien ne vole ma confiance dans un projet aussi rapidement que des constructions instables alternant entre le vert et le rouge sans raison. Ceci est une histoire sur les builds instables et le dépannage. Plus important encore, cette histoire est écrite pour remercier tous les contributeurs à l’infrastructure logicielle de base – l’infrastructure que nous utilisons tous et tenons pour acquise.

    bande dessinée xkcd - Un jour, ImageMagick finira par se briser définitivement et nous aurons une longue période de brouillage alors que nous essayons de réassembler la civilisation à partir des décombres.

    Surprise dans les journaux

    Lors de la connexion à Azure Pipelines pour examiner les journaux de plusieurs builds ayant échoué, je me suis préparé mentalement à une session de dépannage potentiellement ardue. Je soupçonnais qu’une condition de course était le coupable qui provoquait des résultats non déterministes. Par conséquent, j’ai été surpris de découvrir les raisons réelles des récents échecs de construction. Ils ressemblaient tous à ceci :

    2023-02-22T13:57:55.6111290Z [ERROR] Plugin org.apache. Maven.plugins:maven-clean-plugin:3.2.0 or one of its dependencies could not be resolved: Failed to read artifact descriptor for org.apache.maven.plugins:maven-clean-plugin:jar:3.2.0: Could not transfer artifact org.apache.maven.plugins:maven-clean-plugin:pom:3.2.0 from/to central (https://repo.maven.apache.org/maven2): Connection reset -> [Help 1]2023-02-22T13:57:55.6113250Z [ERROR]2023-02-22T13:57:55.6126660Z [ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.2023-02-22T13:57:55.6127480Z [ERROR] Re-run Maven using the -X switch to enable full debug logging.2023-02-22T13:57:55.6127880Z [ERROR]2023-02-22T13:57:55.6128720Z [ERROR] For more information about the errors and possible solutions, please read the following articles:2023-02-22T13:57:55.6129520Z [ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/PluginResolutionException

    C’était la partie la plus intéressante : Could not transfer artifact org.apache.maven.plugins:maven-clean-plugin:pom:3.2.0 from/to central (https://repo.maven.apache.org/maven2): Connection reset -> [Help 1]

    L’erreur provient du projet Apache Maven, que nous utilisons pour construire QuestDB. Maven s’est plaint de ne pas pouvoir télécharger le plug-in Maven Clean à partir du référentiel central. Si cela n’avait été qu’une erreur ponctuelle, je l’aurais minimisé comme un hoquet de réseau. Cependant, nous recevions la même erreur plusieurs fois par jour !

    L’enquête, première partie

    Je ne suis pas un expert Maven, j’ai donc fait ce que tout développeur ferait lors du dépannage d’un élément technologique plutôt complexe : je l’ai cherché sur Google !

    Une photo de Yoda disant : "Utilisez Google, vous devez. Facile, ça l'est. Réponse, il fournira.

    Finalement, je suis tombé sur ce problème.

    Il indique qu’Azure Pipelines tue les connexions inactives, ce qui ne correspond pas bien à l’habitude de Maven de regrouper et de réutiliser les connexions HTTP. Ceci est cohérent avec ce que j’ai vu dans les journaux de construction : Maven a démarré les tests, qui ont duré plus de 20 minutes et ont réussi. Ensuite, Maven a voulu télécharger le plugin Clean pour faire autre chose, mais la tentative de téléchargement a échoué, ce qui a tué toute la construction.

    Il restait une question sans réponse : pourquoi n’avons-nous commencé à recevoir cette erreur que récemment ? Eh bien, j’avais aussi une explication à cela : nous avons continué à ajouter des tests, ils ont donc fonctionné plus longtemps. Azure Pipelines a tué des connexions car la durée totale du test a dépassé le délai d’inactivité de la connexion. Tout a commencé à avoir un sens.

    J’ai également trouvé une propriété de configuration Maven pour restreindre la durée de vie des connexions dans le pool. Le problème Maven que j’ai trouvé dit:

    Les utilisateurs d’Azure doivent définir le TTL sur 240 secondes ou moins.

    J’ai donc envoyé une Pull Request pour régler le TTL à 30s, l’ai annoncé dans la société Slack, et me sentais bien dans ma peau 🙂

    Une capture d'écran de Slack où je dis : les problèmes de réinitialisation de la connexion Maven doivent être résolus pour toutes les nouvelles versions de PR. Faites-moi savoir si vous en faites l'expérience à nouveau.

    Cela a pris moins de 30 minutes, et nous avons eu un autre échec : Une capture d'écran de Slack où mon collègue dit : Cela n'a pas aidé

    La panne avait la même cause que précédemment. Le correctif n’a pas fonctionné. Retour à la case départ.

    L’enquête, partie II

    Googling aveuglément combiné avec un peu de raisonnement logique n’a pas produit de résultats. Il n’y avait qu’une seule réponse : NOUS AVONS BESOIN DE MOAR LOGS ! L’exécution de Maven avec des journaux détaillés a produit une exception avec cette belle trace de pile :

    [...]
2023-02-23T11:20:01.6052340Z Caused by: java.net.SocketException: Connection reset
2023-02-23T11:20:01.6052680Z at java.net.SocketInputStream.read (SocketInputStream.java:186)
2023-02-23T11:20:01.6053040Z at java.net.SocketInputStream.read (SocketInputStream.java:140)
2023-02-23T11:20:01.6053580Z at sun.security.ssl.SSLSocketInputRecord.read (SSLSocketInputRecord.java:484)
2023-02-23T11:20:01.6054000Z at sun.security.ssl.SSLSocketInputRecord.readHeader (SSLSocketInputRecord.java:478)
2023-02-23T11:20:01.6055020Z at sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket (SSLSocketInputRecord.java:70)
2023-02-23T11:20:01.6055500Z at sun.security.ssl.SSLSocketImpl.readApplicationRecord (SSLSocketImpl.java:1455)
2023-02-23T11:20:01.6055900Z at sun.security.ssl.SSLSocketImpl$AppInputStream.read (SSLSocketImpl.java:1066)
2023-02-23T11:20:01.6056310Z at org.apache.http.impl.io.SessionInputBufferImpl.streamRead (SessionInputBufferImpl.java:137)
2023-02-23T11:20:01.6056730Z at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer (SessionInputBufferImpl.java:153)
2023-02-23T11:20:01.6057150Z at org.apache.http.impl.io.SessionInputBufferImpl.readLine (SessionInputBufferImpl.java:280)
2023-02-23T11:20:01.6059200Z at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead (DefaultHttpResponseParser.java:138)
2023-02-23T11:20:01.6059980Z at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead (DefaultHttpResponseParser.java:56)
2023-02-23T11:20:01.6060470Z at org.apache.http.impl.io.AbstractMessageParser.parse (AbstractMessageParser.java:259)
2023-02-23T11:20:01.6060940Z at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader (DefaultBHttpClientConnection.java:163)
2023-02-23T11:20:01.6061370Z at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader (CPoolProxy.java:157)
2023-02-23T11:20:01.6061790Z at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse (HttpRequestExecutor.java:273)
2023-02-23T11:20:01.6062210Z at org.apache.http.protocol.HttpRequestExecutor.execute (HttpRequestExecutor.java:125)
2023-02-23T11:20:01.6062610Z at org.apache.http.impl.execchain.MainClientExec.execute (MainClientExec.java:272)
2023-02-23T11:20:01.6063000Z at org.apache.http.impl.execchain.ProtocolExec.execute (ProtocolExec.java:186)
2023-02-23T11:20:01.6063370Z at org.apache.http.impl.execchain.RetryExec.execute (RetryExec.java:89)
2023-02-23T11:20:01.6063760Z at org.apache.http.impl.execchain.RedirectExec.execute (RedirectExec.java:110)
2023-02-23T11:20:01.6064170Z at org.apache.http.impl.client.InternalHttpClient.doExecute (InternalHttpClient.java:185)
2023-02-23T11:20:01.6064580Z at org.apache.http.impl.client.CloseableHttpClient.execute (CloseableHttpClient.java:72)
2023-02-23T11:20:01.6065000Z at org.eclipse.aether.transport.http.HttpTransporter.execute (HttpTransporter.java:363)
2023-02-23T11:20:01.6065400Z at org.eclipse.aether.transport.http.HttpTransporter.implGet (HttpTransporter.java:298)
2023-02-23T11:20:01.6065820Z at org.eclipse.aether.spi.connector.transport.AbstractTransporter.get (AbstractTransporter.java:72)
2023-02-23T11:20:01.6066260Z at org.eclipse.aether.connector.basic.BasicRepositoryConnector$GetTaskRunner.runTask (BasicRepositoryConnector.java:466)
2023-02-23T11:20:01.6066720Z at org.eclipse.aether.connector.basic.BasicRepositoryConnector$TaskRunner.run (BasicRepositoryConnector.java:383)
2023-02-23T11:20:01.6067180Z at org.eclipse.aether.util.concurrency.RunnableErrorForwarder.lambda$wrap$0 (RunnableErrorForwarder.java:73)
2023-02-23T11:20:01.6067660Z at org.eclipse.aether.connector.basic.BasicRepositoryConnector$DirectExecutor.execute (BasicRepositoryConnector.java:635)
2023-02-23T11:20:01.6068110Z at org.eclipse.aether.connector.basic.BasicRepositoryConnector.get (BasicRepositoryConnector.java:280)
2023-02-23T11:20:01.6068560Z at org.eclipse.aether.internal.impl.DefaultArtifactResolver.performDownloads (DefaultArtifactResolver.java:581)
2023-02-23T11:20:01.6069000Z at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve (DefaultArtifactResolver.java:478)
2023-02-23T11:20:01.6069440Z at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts (DefaultArtifactResolver.java:278)
2023-02-23T11:20:01.6069880Z at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifact (DefaultArtifactResolver.java:255)
2023-02-23T11:20:01.6070350Z at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.loadPom (DefaultArtifactDescriptorReader.java:228)
2023-02-23T11:20:01.6071370Z at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.readArtifactDescriptor (DefaultArtifactDescriptorReader.java:169)
2023-02-23T11:20:01.6071950Z at org.eclipse.aether.internal.impl.DefaultRepositorySystem.readArtifactDescriptor (DefaultRepositorySystem.java:286)
2023-02-23T11:20:01.6072420Z at org.apache.maven.plugin.internal.DefaultPluginDependenciesResolver.resolve (DefaultPluginDependenciesResolver.java:104)
2023-02-23T11:20:01.6072890Z at org.apache.maven.plugin.internal.DefaultMavenPluginManager.getPluginDescriptor (DefaultMavenPluginManager.java:180)
2023-02-23T11:20:01.6073360Z at org.apache.maven.plugin.internal.DefaultMavenPluginManager.getMojoDescriptor (DefaultMavenPluginManager.java:265)
2023-02-23T11:20:01.6073810Z at org.apache.maven.plugin.DefaultBuildPluginManager.getMojoDescriptor (DefaultBuildPluginManager.java:214)
2023-02-23T11:20:01.6074310Z at org.apache.maven.lifecycle.internal.DefaultLifecycleExecutionPlanCalculator.setupMojoExecution (DefaultLifecycleExecutionPlanCalculator.java:155)
2023-02-23T11:20:01.6074830Z at org.apache.maven.lifecycle.internal.DefaultLifecycleExecutionPlanCalculator.setupMojoExecutions (DefaultLifecycleExecutionPlanCalculator.java:143)
2023-02-23T11:20:01.6075360Z at org.apache.maven.lifecycle.internal.DefaultLifecycleExecutionPlanCalculator.calculateExecutionPlan (DefaultLifecycleExecutionPlanCalculator.java:122)
2023-02-23T11:20:01.6075950Z at...
    Share.
    Add A Comment

    Leave A Reply