Snapcraft looping on getent hosts snapcraft.io

When I try to build a package, the process enters an infinite loop of calling getent hosts snapcraft.io:

2023-11-07 18:41:07.069 Executing in container: lxc --project snapcraft exec local:snapcraft-brave-on-amd64-for-amd64-8526475 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin SNAPCRAFT_MANAGED_MODE=1 getent hosts snapcraft.io

This started today. Worked fine earlier. No local changes afaict.

Looks like this is only happening when I’m on a VPN. That’s new - it worked over a VPN with no issues for a long time. The command does return IPs and exits with 0, with and without the VPN, so what is the issue? There are no error messages.

Here’s the latest failure flavor (VPN disabled):

2023-11-17 17:05:55.464 The http error when checking the store for gtk-common-themes is 500 (retries left 5)                                                                                                                                  
2023-11-17 17:06:35.501 The http error when checking the store for gtk-common-themes is 500 (retries left 4)                                                                                                                                  
2023-11-17 17:07:15.519 The http error when checking the store for gtk-common-themes is 500 (retries left 3)                                                                                                                                  
2023-11-17 17:07:55.547 The http error when checking the store for gtk-common-themes is 500 (retries left 2)                                                                                                                                  
2023-11-17 17:08:35.571 The http error when checking the store for gtk-common-themes is 500 (retries left 1)                                                                                                                                  
2023-11-17 17:09:15.599 The http error when checking the store for gnome-42-2204-sdk is 500 (retries left 5)                                                                                                                                  
2023-11-17 17:09:55.621 The http error when checking the store for gnome-42-2204-sdk is 500 (retries left 4)                                                                                                                                  
2023-11-17 17:10:35.637 The http error when checking the store for gnome-42-2204-sdk is 500 (retries left 3)                                                                                                                                  
2023-11-17 17:11:15.649 The http error when checking the store for gnome-42-2204-sdk is 500 (retries left 2)                                                                                                                                  
2023-11-17 17:11:55.658 The http error when checking the store for gnome-42-2204-sdk is 500 (retries left 1)                                                                                                                                  
2023-11-17 17:12:35.665 The http error when checking the store for gnome-42-2204 is 500 (retries left 5)                                                                                                                                      
2023-11-17 17:13:15.695 The http error when checking the store for gnome-42-2204 is 500 (retries left 4)                                                                                                                                      
2023-11-17 17:13:55.701 The http error when checking the store for gnome-42-2204 is 500 (retries left 3)                                                                                                                                      
2023-11-17 17:14:35.709 The http error when checking the store for gnome-42-2204 is 500 (retries left 2)                                                                                                                                      
2023-11-17 17:15:15.716 The http error when checking the store for gnome-42-2204 is 500 (retries left 1)                                                                                                                                      
2023-11-17 17:15:55.724 The http error when checking the store for core22 is 500 (retries left 5)                                                                                                                                             
2023-11-17 17:16:35.734 The http error when checking the store for core22 is 500 (retries left 4)                                                                                                                                             
2023-11-17 17:17:15.744 The http error when checking the store for core22 is 500 (retries left 3)                                                                                                                                             
2023-11-17 17:17:55.757 The http error when checking the store for core22 is 500 (retries left 2)                                                                                                                                             
2023-11-17 17:18:35.763 The http error when checking the store for core22 is 500 (retries left 1)                                                                                                                                             
2023-11-17 17:18:35.775 verify plugin environment for part 'brave'                                                                                                                                                                            
2023-11-17 17:18:35.776 verify plugin environment for part 'gnome/sdk'                                                                                                                                                                        
2023-11-17 17:18:35.777 Executing parts lifecycle: repull brave ('source' property changed)                                                                                                                                                   
2023-11-17 17:18:35.777 Executing action                                                                                                                                                                                                      
2023-11-17 17:18:35.777 execute action brave:Action(part_name='brave', step=Step.PULL, action_type=ActionType.RERUN, reason="'source' property changed", project_vars=None, properties=ActionProperties(changed_files=None, changed_dirs=None))                                                                                                                                                                                                                                              
2023-11-17 17:18:35.777 clean brave:Step.PULL                                                                                                                                                                                                 
2023-11-17 17:18:35.777 remove directory /root/parts/brave/src                                                                                                                                                                                
2023-11-17 17:18:35.791 clean brave:Step.BUILD                                                                                                                                                                                                
2023-11-17 17:18:35.792 remove directory /root/parts/brave/build                                                                                                                                                                              
2023-11-17 17:18:35.805 remove directory /root/parts/brave/install                                                                                                                                                                            
2023-11-17 17:18:35.816 clean brave:Step.STAGE                                                                                                                                                                                                
2023-11-17 17:18:35.816 load state file: /root/parts/brave/state/stage                                                                                                                                                                        
2023-11-17 17:18:35.857 load state file: /root/parts/gnome/sdk/state/stage                                                                                                                                                                    
2023-11-17 17:18:35.868 clean brave:Step.PRIME                                                                                                                                                                                                
2023-11-17 17:18:35.868 load state file: /root/parts/brave/state/prime                                                                                                                                                                        
2023-11-17 17:18:35.890 load state file: /root/parts/gnome/sdk/state/prime                                                                                                                                                                    
2023-11-17 17:18:35.916 :: + set -eu                                                                                                                                                                                                          
2023-11-17 17:18:35.917 :: + craftctl default
2023-11-17 18:27:30.358 :: 2023-11-17 17:27:29.714 :: error: Network request error: network request failed (request=<PreparedRequest [GET]>, response=None).                                                                                  
2023-11-17 18:27:30.358 :: 2023-11-17 17:27:29.926 'override-pull' in part 'brave' failed with code 1.                                                                                                                                        
2023-11-17 18:27:30.359 :: Review the scriptlet and make sure it's correct.                                                                                                                                                                   
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950 Traceback (most recent call last):                                                                                                                                                         
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/snapcraft/parts/parts.py", line 191, in run                                                                                       
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     aex.execute(action, stdout=stream, stderr=stream)                                                                                                                                      
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/craft_parts/executor/executor.py", line 304, in execute                                                                           
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     self._executor.execute(actions, stdout=stdout, stderr=stderr)                                                                                                                          
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/craft_parts/executor/executor.py", line 128, in execute                                                                           
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     self._run_action(act, stdout=stdout, stderr=stderr)                                                                                                                                    
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/craft_parts/executor/executor.py", line 193, in _run_action                                                                       
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     handler.run_action(action, stdout=stdout, stderr=stderr)                                                                                                                               
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/craft_parts/executor/part_handler.py", line 172, in run_action                                                                    
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     state = handler(step_info, stdout=stdout, stderr=stderr)                                                                                                                               
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/craft_parts/executor/part_handler.py", line 198, in _run_pull                                                                     
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     self._run_step(                                                                                                                                                                        
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/craft_parts/executor/part_handler.py", line 485, in _run_step                                                                     
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     step_handler.run_scriptlet(                                                                                                                                                            
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950   File "/snap/snapcraft/9726/lib/python3.8/site-packages/craft_parts/executor/step_handler.py", line 278, in run_scriptlet                                                                 
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.950     raise errors.ScriptletRunError(                                                                                                                                                        
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951 craft_parts.errors.ScriptletRunError: 'override-pull' in part 'brave' failed with code 1.                                                                                                  
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951 Review the scriptlet and make sure it's correct.                                                                                                                                           
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951                                                                                                                                                                                            
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951 The above exception was the direct cause of the following exception:                                                                                                                       
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951 Traceback (most recent call last):                                                                                                                                                         
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951   File "/snap/snapcraft/9726/lib/python3.8/site-packages/snapcraft/parts/lifecycle.py", line 302, in _run_command                                                                          
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951     _run_lifecycle_and_pack(                                                                                                                                                               
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951   File "/snap/snapcraft/9726/lib/python3.8/site-packages/snapcraft/parts/lifecycle.py", line 345, in _run_lifecycle_and_pack                                                               
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951     lifecycle.run(                                                                                                                                                                         
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951   File "/snap/snapcraft/9726/lib/python3.8/site-packages/snapcraft/parts/parts.py", line 206, in run                                                                                       
2023-11-17 18:27:30.359 :: 2023-11-17 17:27:29.951     raise errors.PartsLifecycleError(str(err)) from err                                                                                                                                    
2023-11-17 18:27:30.360 :: 2023-11-17 17:27:29.951 snapcraft.errors.PartsLifecycleError: 'override-pull' in part 'brave' failed with code 1.                                                                                                  
2023-11-17 18:27:30.360 :: 2023-11-17 17:27:29.951 Review the scriptlet and make sure it's correct.                                                                                                                                           
2023-11-17 18:27:31.799 Failed to execute build in instance.                                                                                                                                                                                  
2023-11-17 18:27:31.799 Detailed information: Run the same command again with --debug to shell into the environment if you wish to introspect this failure.                                                                                   
2023-11-17 18:27:31.800 Traceback (most recent call last):                                                                                                                                                                                    
2023-11-17 18:27:31.800   File "/var/lib/snapd/snap/snapcraft/9726/lib/python3.8/site-packages/snapcraft/parts/lifecycle.py", line 577, in _run_in_provider                                                                                   
2023-11-17 18:27:31.800     instance.execute_run(cmd, check=True, cwd=output_dir)                                                                                                                                                             
2023-11-17 18:27:31.800   File "/var/lib/snapd/snap/snapcraft/9726/lib/python3.8/site-packages/craft_providers/lxd/lxd_instance.py", line 289, in execute_run                                                                                 
2023-11-17 18:27:31.800     return self.lxc.exec(                                                                                                                                                                                             
2023-11-17 18:27:31.800   File "/var/lib/snapd/snap/snapcraft/9726/lib/python3.8/site-packages/craft_providers/lxd/lxc.py", line 371, in exec                                                                                                 
2023-11-17 18:27:31.800     return runner(final_cmd, **kwargs)  # pylint: disable=subprocess-run-check                                                                                                                                        
2023-11-17 18:27:31.800   File "/var/lib/snapd/snap/snapcraft/9726/usr/lib/python3.8/subprocess.py", line 516, in run                                                                                                                         
2023-11-17 18:27:31.800     raise CalledProcessError(retcode, process.args,                                                                                                                                                                   
2023-11-17 18:27:31.800 subprocess.CalledProcessError: Command '['lxc', '--project', 'snapcraft', 'exec', 'local:snapcraft-brave-on-amd64-for-amd64-8526475', '--cwd', '/root/project', '--', 'env', 'PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin', 'SNAPCRAFT_MANAGED_MODE=1', 'snapcraft', 'build', '--verbosity=debug', '--build-for', 'amd64']' returned non-zero exit status 1.

Each of the retries above takes 40s, so that’s almost 15min wasted. There’s no indication of eventual success either. And then at the end the build just hangs on craftctl default for almost 10min before failing.

And now 10min later everything works, with and without the VPN. No loops, http 500s…

Hi @wknapik,

Sorry about that infinite loop for getent hosts snapcraft.io. A fix for that was recently added to snapcraft, but it hasn’t yet been released to the stable channel.

I’ve heard another report of snapcraft not working when using a VPN. It has something to do with LXD and the host’s network config, but I’m not sure what. Next time it occurs, will you create a bug report?