GoogleCloudPlatform / GoogleCloudPlatform/osconfig
OS config agent hung - reporting "running" but OS unknown in patch consul / not patching / logging
- Dominant language
- Go
- Stars
- 99
- Forks
- 113
- Avg merge
- 2d 10h
- Merged PRs (30d)
- 5
Description
On a few of our hosts in google console is not reporting their os other info from the agent, agent is not running patching jobs or logging even though it is still reporting as running.
Logging onto the hosts I see that the agent is running. But hasn't written a new line to the log file in 15 days
```
systemctl status google-osconfig-agent
● google-osconfig-agent.service - Google OSConfig Agent
Loaded: loaded (/lib/systemd/system/google-osconfig-agent.service; enabled; preset: enabled)
Active: active (running) since Thu 2024-10-24 04:19:55 UTC; 2 weeks 4 days ago
Main PID: 660 (google_osconfig)
Tasks: 22 (limit: 4677)
Memory: 105.2M
CPU: 1h 8min 26.925s
CGroup: /system.slice/google-osconfig-agent.service
├─ 660 /usr/bin/google_osconfig_agent
├─1320421 /usr/bin/apt-get update
├─1320433 /usr/lib/apt/methods/https
├─1320434 /usr/lib/apt/methods/http
├─1320435 /usr/lib/apt/methods/ar+https
├─1320441 /usr/lib/apt/methods/http
└─1320443 /usr/lib/apt/methods/gpgv
Oct 26 23:20:11 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-26T23:20:11.0569Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 26 23:30:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-26T23:30:10.9839Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 26 23:40:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-26T23:40:10.6683Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 26 23:50:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-26T23:50:10.8159Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 27 00:00:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-27T00:00:10.7159Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 27 00:10:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-27T00:10:10.8140Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 27 00:20:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-27T00:20:10.8854Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 27 00:30:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-27T00:30:10.9676Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 27 00:40:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-27T00:40:10.9233Z OSConfigAgent Info: Writing inventory to guest attributes
Oct 27 00:50:10 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-27T00:50:10.5406Z OSConfigAgent Info: Writing inventory to guest attributes
```
Last logs that were not Writing inventory to guest attributes: looked like this.
```
Oct 24 04:20:56 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-24T04:20:56.0314Z OSConfigAgent Info: Successfully completed ApplyConfigTask
Oct 24 06:00:06 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-24T06:00:06.5103Z OSConfigAgent Error inventory.go:55: packages.GetPackageUpdates() error: error getting apt updates: exit status 100
Oct 24 12:19:01 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-24T12:19:01.1567Z OSConfigAgent Warning: Error waiting for task (attempt 1 of 10): rpc error: code = Unavailable desc = closing transport due to: connection error: desc = "error reading from server: EOF", received prior goaway: code: NO_ERROR, debug data: "server_shutting_down"
Oct 25 06:00:06 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-25T06:00:06.5184Z OSConfigAgent Error inventory.go:55: packages.GetPackageUpdates() error: error getting apt updates: exit status 100
Oct 26 06:00:06 lightstep-satellite-f8fh OSConfigAgent[660]: 2024-10-26T06:00:06.5876Z OSConfigAgent Error inventory.go:55: packages.GetPackageUpdates() error: error getting apt updates: exit status 100
```
```
UID PID PPID C SZ RSS PSR STIME TTY TIME CMD
root 660 1 0 311612 24516 1 Oct24 ? 00:02:13 /usr/bin/google_osconfig_agent
```
Doing a manual restart -- `systemctl restart google-osconfig-agent` returns the agent to a working state (at least temporarily) and google console shows proper operating system.
strace reveals most threads are blocked on futex call.
```
strace -p 660
strace: Process 660 attached
futex(0x1613f80, FUTEX_WAIT_PRIVATE, 0, NULL
ps -efL | grep google_osconfig_agent
root 660 1 660 0 11 Oct24 ? 00:02:13 /usr/bin/google_osconfig_agent
root 660 1 683 0 11 Oct24 ? 00:00:35 /usr/bin/google_osconfig_agent
root 660 1 684 0 11 Oct24 ? 00:00:03 /usr/bin/google_osconfig_agent
root 660 1 685 0 11 Oct24 ? 00:00:12 /usr/bin/google_osconfig_agent
root 660 1 686 0 11 Oct24 ? 00:00:12 /usr/bin/google_osconfig_agent
root 660 1 723 0 11 Oct24 ? 00:00:18 /usr/bin/google_osconfig_agent
root 660 1 725 0 11 Oct24 ? 00:00:00 /usr/bin/google_osconfig_agent
root 660 1 726 0 11 Oct24 ? 00:00:00 /usr/bin/google_osconfig_agent
root 660 1 727 0 11 Oct24 ? 00:00:19 /usr/bin/google_osconfig_agent
root 660 1 3016 0 11 Oct24 ? 00:00:17 /usr/bin/google_osconfig_agent
root 660 1 896728 0 11 Oct26 ? 00:00:16 /usr/bin/google_osconfig_agent
# strace -p 896728
strace: Process 896728 attached
futex(0xc00035a148, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 896728 detached
# strace -p 3016
strace: Process 3016 attached
futex(0xc0003fd148, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 3016 detached
# strace -p 727
strace: Process 727 attached
futex(0xc0003fc948, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 727 detached
# strace -p 726
strace: Process 726 attached
futex(0x1675278, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 726 detached
# strace -p 725
strace: Process 725 attached
futex(0x1675400, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 725 detached
# strace -p 723
strace: Process 723 attached
futex(0xc000090948, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 723 detached
# strace -p 686
strace: Process 686 attached
futex(0xc000090148, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 686 detached
# strace -p 685
strace: Process 685 attached
futex(0xc00006b148, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
write(6, "\0", 1) = 1
futex(0xc00006b148, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
epoll_pwait(4, [], 128, 0, NULL, 0) = 0
epoll_pwait(4, [], 128, 3825, NULL, 0) = 0
epoll_pwait(4, [], 128, 0, NULL, 0) = 0
futex(0xc0003fc948, FUTEX_WAKE_PRIVATE, 1) = 1
epoll_pwait(4, [], 128, 0, NULL, 0) = 0
futex(0xc00006b148, FUTEX_WAIT_PRIVATE, 0, NULL^Cstrace: Process 685 detached
# strace -p 684
strace: Process 684 attached
waitid(P_PID, 1320421, ^Cstrace: Process 684 detached
# strace -p 683
strace: Process 683 attached
restart_syscall(<... resuming interrupted read ...>) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=997095762}) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=76850051}) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=4, tv_nsec=921581186}) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=40000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=80000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=160000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=320000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=640000}, NULL) = 0
nanosleep({tv_sec=0, tv_nsec=1280000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=74422472}) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=2560000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=3, tv_nsec=918451268}) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=5120000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=994605225}) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=68601132}) = -1 ETIMEDOUT (Connection timed out)
nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
futex(0x16159a0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=4, tv_nsec=910377910}^Cstrace: Process 683 detached
```
Contributor guide
Research direction
Start by reviewing the reported systemctl status, process/thread traces, and the inventory.go:55 error context. Reproduce or investigate the stalled google_osconfig_agent behavior around apt updates and task waiting. Done means the agent no longer remains falsely running, reports the operating system, resumes patching, and continues logging without requiring a restart.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- devops, operating-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 28/100