self-hosted web export produces extra garbage before json

Self-Hosted Version

22.8.0

CPU Architecture

x86_64

Docker Version

20.10.13

Docker Compose Version

1.29.2

Steps to Reproduce

cd /opt/sentry
docker-compose run --rm -T -e SENTRY_LOG_LEVEL=CRITICAL web export | less

Expected Result

json

Actual Result

first:

Updating certificates in /etc/ssl/certs...
0 added, 0 removed; done.
Running hooks in /etc/ca-certificates/update.d...
done.
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/sentry_sdk/integrations/redis.py", line 123, in setup_once
    _patch_rediscluster()
  File "/usr/local/lib/python3.8/site-packages/sentry_sdk/integrations/redis.py", line 88, in _patch_rediscluster
    pipeline_cls = rediscluster.ClusterPipeline
AttributeError: module 'rediscluster' has no attribute 'ClusterPipeline'
21:45:20 [ERROR] sentry_sdk.errors: Error occurred while patching `rediscluster` library

... and then json

Aug 23 '22 21:08 ilyaevseev

Hm, sounds like there is an issue with Redis, can you check the logs for Redis please?

Aug 24 '22 21:08 emmatyping

Redis container state:

# docker ps --filter name=edis
CONTAINER ID   IMAGE                COMMAND                  CREATED      STATUS                PORTS      NAMES
2e305fe53079   redis:6.2.4-alpine   "docker-entrypoint.s…"   3 days ago   Up 3 days (healthy)   6379/tcp   sentry_redis_1

Redis container logs:

# docker logs sentry_redis_1 2>&1 |
grep -v 'Background saving started by pid' |
grep -v 'Background saving terminated with success' |
grep -v 'DB saved on disk' |
grep -v '100 changes in 300 seconds. Saving' |
grep -v '10000 changes in 60 seconds. Saving' |
egrep -v 'RDB: . MB of memory used by copy-on-write'

1:C 21 Aug 2022 23:30:33.108 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 21 Aug 2022 23:30:33.108 # Redis version=6.2.4, bits=64, commit=00000000, modified=0, pid=1, just started
1:C 21 Aug 2022 23:30:33.108 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
1:M 21 Aug 2022 23:30:33.109 * monotonic clock: POSIX clock_gettime
1:M 21 Aug 2022 23:30:33.110 * Running mode=standalone, port=6379.
1:M 21 Aug 2022 23:30:33.110 # Server initialized
1:M 21 Aug 2022 23:30:33.110 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
1:M 21 Aug 2022 23:30:33.112 * Loading RDB produced by version 6.2.4
1:M 21 Aug 2022 23:30:33.112 * RDB age 5966 seconds
1:M 21 Aug 2022 23:30:33.112 * RDB memory usage when created 3.85 Mb
1:M 21 Aug 2022 23:30:33.127 * DB loaded from disk: 0.016 seconds
1:M 21 Aug 2022 23:30:33.127 * Ready to accept connections
1:signal-handler (1661124752) Received SIGTERM scheduling shutdown...
1:M 21 Aug 2022 23:32:32.814 # User requested shutdown...
1:M 21 Aug 2022 23:32:32.814 * Saving the final RDB snapshot before exiting.
1:M 21 Aug 2022 23:32:32.842 # Redis is now ready to exit, bye bye...
1:C 21 Aug 2022 23:34:02.130 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 21 Aug 2022 23:34:02.130 # Redis version=6.2.4, bits=64, commit=00000000, modified=0, pid=1, just started
1:C 21 Aug 2022 23:34:02.130 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
1:M 21 Aug 2022 23:34:02.130 * monotonic clock: POSIX clock_gettime
1:M 21 Aug 2022 23:34:02.131 * Running mode=standalone, port=6379.
1:M 21 Aug 2022 23:34:02.131 # Server initialized
1:M 21 Aug 2022 23:34:02.131 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
1:M 21 Aug 2022 23:34:02.131 * Loading RDB produced by version 6.2.4
1:M 21 Aug 2022 23:34:02.131 * RDB age 90 seconds
1:M 21 Aug 2022 23:34:02.131 * RDB memory usage when created 2.92 Mb
1:M 21 Aug 2022 23:34:02.155 * DB loaded from disk: 0.024 seconds
1:M 21 Aug 2022 23:34:02.155 * Ready to accept connections

Redis info:

# docker exec sentry_redis_1 redis-cli info
# Server
redis_version:6.2.4
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:44af72f812de1690
redis_mode:standalone
os:Linux 5.15.0-41-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:10.3.1
process_id:1
process_supervised:no
run_id:569cfd386b59d8b2ce1a056d60abf1c3e46ca0e9
tcp_port:6379
server_time_usec:1661410010115135
uptime_in_seconds:285168
uptime_in_days:3
hz:10
configured_hz:10
lru_clock:465626
executable:/data/redis-server
config_file:
io_threads_active:0

# Clients
connected_clients:70
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:5936
client_recent_max_output_buffer:0
blocked_clients:1
tracking_clients:0
clients_in_timeout_table:1

# Memory
used_memory:5757120
used_memory_human:5.49M
used_memory_rss:7733248
used_memory_rss_human:7.38M
used_memory_peak:7347600
used_memory_peak_human:7.01M
used_memory_peak_perc:78.35%
used_memory_overhead:3847704
used_memory_startup:809856
used_memory_dataset:1909416
used_memory_dataset_perc:38.60%
allocator_allocated:5736192
allocator_active:6451200
allocator_resident:9064448
total_system_memory:8337952768
total_system_memory_human:7.77G
used_memory_lua:77824
used_memory_lua_human:76.00K
used_memory_scripts:20552
used_memory_scripts_human:20.07K
number_of_cached_scripts:5
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.12
allocator_frag_bytes:715008
allocator_rss_ratio:1.41
allocator_rss_bytes:2613248
rss_overhead_ratio:0.85
rss_overhead_bytes:-1331200
mem_fragmentation_ratio:1.36
mem_fragmentation_bytes:2039872
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:1420552
mem_aof_buffer:0
mem_allocator:jemalloc-5.1.0
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:0

# Persistence
loading:0
current_cow_size:0
current_cow_size_age:0
current_fork_perc:0.00
current_save_keys_processed:0
current_save_keys_total:0
rdb_changes_since_last_save:3505
rdb_bgsave_in_progress:0
rdb_last_save_time:1661409812
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:0
rdb_current_bgsave_time_sec:-1
rdb_last_cow_size:618496
aof_enabled:0
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:-1
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_last_write_status:ok
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0

# Stats
total_connections_received:22439
total_commands_processed:5456650
instantaneous_ops_per_sec:2
total_net_input_bytes:2605163156
total_net_output_bytes:207332368
instantaneous_input_kbps:6.89
instantaneous_output_kbps:0.06
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:353627
expired_stale_perc:0.34
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:17900
evicted_keys:0
keyspace_hits:77770
keyspace_misses:119968
pubsub_channels:0
pubsub_patterns:1
latest_fork_usec:639
total_forks:949
migrate_cached_sockets:0
slave_expires_tracked_keys:0
active_defrag_hits:0
active_defrag_misses:0
active_defrag_key_hits:0
active_defrag_key_misses:0
tracking_total_keys:0
tracking_total_items:0
tracking_total_prefixes:0
unexpected_error_replies:0
total_error_replies:5
dump_payload_sanitizations:0
total_reads_processed:1613906
total_writes_processed:1585056
io_threaded_reads_processed:0
io_threaded_writes_processed:0

# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:b1cf9f0182e75033e107c5a33bffe1c6c0582dba
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:0
second_repl_offset:-1
repl_backlog_active:0
repl_backlog_size:1048576
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0

# CPU
used_cpu_sys:205.329179
used_cpu_user:334.564956
used_cpu_sys_children:4.050435
used_cpu_user_children:18.049300
used_cpu_sys_main_thread:204.654961
used_cpu_user_main_thread:333.960730

# Modules

# Errorstats
errorstat_NOSCRIPT:count=5

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=16745,expires=16738,avg_ttl=1211222754
db1:keys=10,expires=0,avg_ttl=0

Try to export:

# docker-compose run --rm -T -e SENTRY_LOG_LEVEL=CRITICAL web export > /tmp/1.json
Creating sentry_web_run ... done
>> Beginning export
>> Skipping model <Broadcast>
>> Skipping model <CommitAuthor>
...
>> Skipping model <IncidentSeen>
>> Skipping model <IncidentProject>

Result:

# cat /tmp/1.json
Updating certificates in /etc/ssl/certs...
0 added, 0 removed; done.
Running hooks in /etc/ca-certificates/update.d...
done.
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/sentry_sdk/integrations/redis.py", line 123, in setup_once
    _patch_rediscluster()
  File "/usr/local/lib/python3.8/site-packages/sentry_sdk/integrations/redis.py", line 88, in _patch_rediscluster
    pipeline_cls = rediscluster.ClusterPipeline
AttributeError: module 'rediscluster' has no attribute 'ClusterPipeline'
06:51:13 [ERROR] sentry_sdk.errors: Error occurred while patching `rediscluster` library
[
{
  "model": "sites.site",
  "pk": 1,
...

Aug 25 '22 06:08 ilyaevseev

same occurred when ./install.sh

Aug 30 '22 13:08 jyxjjj

I will try to reproduce this later today. Odd that Redis seems fine.

Aug 30 '22 17:08 emmatyping

Same problem here. But it seems like Redis is generally not working. In Sentry itself I receive alerts that Error 111 connecting to redis:6379. Connection refused.. And when workers run I see the same error in the logs as already mentioned in the issue - that module 'rediscluster' has no attribute 'ClusterPipeline'. Redis logs are clear and nothing suspicious.

Sep 03 '22 20:09 igorcoding

This issue has gone three weeks without activity. In another week, I will close it.

But! If you comment or otherwise update it, I will reset the clock, and if you label it Status: Backlog or Status: In Progress, I will leave it alone ... forever!

"A weed is but an unloved flower." ― Ella Wheeler Wilcox 🥀

Sep 25 '22 00:09 github-actions[bot]

Partially fixed after upgrading to 22.9:

no more Redis exception
but some garbage before JSON still exists..

Updating certificates in /etc/ssl/certs...
0 added, 0 removed; done.
Running hooks in /etc/ca-certificates/update.d...
done.
[
{
  "model": "sites.site",
  "pk": 1,
...

Sep 25 '22 04:09 ilyaevseev

This has been addressed with the backup script provided: https://github.com/getsentry/self-hosted/blob/master/scripts/backup.sh

Jul 19 '23 17:07 hubertdeng123

self-hosted self-hosted copied to clipboard

web export produces extra garbage before json

Self-Hosted Version

CPU Architecture

Docker Version

Docker Compose Version

Steps to Reproduce

Expected Result

Actual Result

Redis container state:

Redis container logs:

Redis info:

Try to export:

Result:

Partially fixed after upgrading to 22.9:

self-hosted
self-hosted copied to clipboard