Malformed Event(s) JSON using 1.10.2 SDK #134

mariusgherman · 2023-07-12T11:03:45Z

Expected Behavior

Generated events JSON should be valid

Current Behavior

Generated events JSON is invalid

Malformed JSON string #1

[{
"event_type": "[Amplitude] Deep Link Opened",
"user_id": "vqC3pq54Tj6Od096jMqr7w",
"device_id": "6a974754-0c50-4af7-af7f-3f6bc2b984e5",
"time": 1689158000413,
"event_properties": {
	"[Amplitude] Link Referrer": "android-app:\/\/org.myapp.app"
},
"user_properties": {},
"groups": {},
"group_properties": {},
"platform": "Android",
"os_name": "android",
"os_version": "13",
"device_brand": "google",
"device_manufacturer": "Google",
"device_model": "sdk_gphone64_arm64",
"carrier": "T-Mobile",
"language": "en",
"ip": "$remote",
"version_name": "local",
"adid": "94d655e5-cd08-41b5-be5c-0f2348d09c39",
"event_id": 69,
"session_id": 1689157052211,
"insert_id": "a2582cf2-b330-491f-80c1-5f994d0d98e2",
"library": "amplitude-analytics-android\/1.10.2"
}, {
"event_type": "[Amplitude] Deep Link Opened",
"user_id": "vqC3pq54Tj6Od096jMqr7w",
"device_id": "6a974754-0c50-4af7-af7f-3f6bc2b984e5",
"time": 1689158000414,
"event_properties": {
	"[Amplitude] Link Referrer": "android-app:\/\/org.myapp.app"
},
"user_properties": {},
"groups": {},
"group_properties": {},
"platform": "Android",
"os_name": "android",
"os_version": "13",
"device_brand": "google",
"device_manufacturer": "Google",
"device_model": "sdk_gphone64_arm64",
"carrier": "T-Mobile",
"language": "en",
"ip": "$remote",
"version_name": "local",
"adid": "94d655e5-cd08-41b5-be5c-0f2348d09c39",
"event_id": 37,
"session_id": 1689157052211,
"insert_id": "e847b4d5-a8db-4f96-bad8-f22b2a83a790",
"library": "amplitude-analytics-android\/1.10.2"
}, {
"event_type": "[Amplitude] Screen Viewed",
"user_id": "vqC3pq54Tj6Od096jMqr7w",
"device_id": "6a974754-0c50-4af7-af7f-3f6bc2b984e5",
"time": 1689158000510,
"event_properties": {
	"[Amplitude] Screen Name": "Settings"
},
"user_properties": {},
"groups": {},
"group_properties": {},
"platform": "Android",
"os_name": "android",
"os_version": "13",
"device_brand": "google",
"device_manufacturer": "Google",
"device_model": "sdk_gphone64_arm64",
"carrier": "T-Mobile",
"language": "en",
"ip": "$remote",
"version_name": "local",
"adid": "94d655e5-cd08-41b5-be5c-0f2348d09c39",
"event_id": 70,
"session_id": 1689157052211,
"insert_id": "7c018ed5-ef84-49ec-9edb-36273a4f894b",
"library": "amplitude-analytics-android\/1.10.2"
}, {
"event_type": "[Amplitude] Screen Viewed",
"user_id": "vqC3pq54Tj6Od096jMqr7w",
"device_id": "6a974754-0c50-4af7-af7f-3f6bc2b984e5",
"time": 1689158000510,
"event_properties": {
	"[Amplitude] Screen Name": "Settings"
},
"user_properties": {},
"groups": {},
"group_properties": {},
"platform": "Android",
"os_name": "android",
"os_version": "13",
"device_brand": "google",
"device_manufacturer": "Google",
"device_model": "sdk_gphone64_arm64",
"carrier": "T-Mobile",
"language": "en",
"ip": "$remote",
"version_name": "local",
"adid": "94d655e5-cd08-41b5-be5c-0f2348d09c39",
"event_id": 38,
"session_id": 1689157052211,
"insert_id": "82b03424-333b-4e27-9026-717abfbed5a8",
"library": "amplitude-analytics-android\/1.10.2"
}]]

Malformed JSON string example #2

[{
"event_type": "[Amplitude] Screen Viewed",
"user_id": "vqC3pq54Tj6Od096jMqr7w",
"device_id": "6a974754-0c50-4af7-af7f-3f6bc2b984e5",
"time": 1689158345037,
"event_properties": {
	"[Amplitude] Screen Name": "Screen Name"
},
"user_properties": {},
"groups": {},
"group_properties": {},
"platform": "Android",
"os_name": "android",
"os_version": "13",
"device_brand": "google",
"device_manufacturer": "Google",
"device_model": "sdk_gphone64_arm64",
"carrier": "T-Mobile",
"language": "en",
"ip": "$remote",
"version_name": "local",
"adid": "94d655e5-cd08-41b5-be5c-0f2348d09c39",
"event_id": 72,
"session_id": 1689157052211,
"insert_id": "20bedb1a-b5bc-4c9e-b58b-fd4ae430878a",
"library": "amplitude-analytics-android\/1.10.2"
}, {
"event_type": "[Amplitude] Screen Viewed",
"user_id": "vqC3pq54Tj6Od096jMqr7w",
"device_id": "6a974754-0c50-4af7-af7f-3f6bc2b984e5",
"time": 1689158345038,
"event_properties": {
	"[Amplitude] Screen Name": "Screen name"
},
"user_properties": {},
"groups": {},
"group_properties": {},
"platform": "Android",
"os_name": "android",
"os_version": "13",
"device_brand": "google",
"device_manufacturer": "Google",
"device_model": "sdk_gphone64_arm64",
"carrier": "T-Mobile",
"language": "en",
"ip": "$remote",
"version_name": "local",
"adid": "94d655e5-cd08-41b5-be5c-0f2348d09c39",
"event_id": 40,
"session_id": 1689157052211,
"insert_id": "dca283f0-d4b2-4973-8437-16d42feb2605",
"library": "amplitude-analytics-android\/1.10.2"
}]]

Possible Solution

extra ']' is inserted at the end of the event JSON Array should be removed
Issue seems to be only reproducing with com.amplitude.android.utilities.AndroidStorage implementation

Steps to Reproduce

Setup Amplitude Client

Amplitude(
            Configuration(
                context = context.applicationContext,
                apiKey = AMPLITUDE_API_KEY,
                trackingSessionEvents = true,
                defaultTracking = DefaultTrackingOptions.ALL,
            )
        )

Log events + deep links + screen views
Observe stored events JSON string and sent HTTP payloads

Environment

Device: Android Emulator sdk_gphone64_arm64
Device OS and Version: Android OS 13

The text was updated successfully, but these errors were encountered:

yuhao900914 · 2023-07-14T19:20:40Z

Thank you for choosing Amplitude. We are actively addressing this issue and will keep you updated on any progress.

Mercy811 · 2023-07-18T20:51:34Z

Hi @mariusgherman, did you have this issue with earlier versions or it starts happening after 1.10.2? I set up a local example and send several events. All events were sent successfully. Not sure how you observe stored events JSON string and sent HTTP payloads. Could you elaborate on it?

mariusgherman · 2023-07-19T07:01:03Z

@Mercy811 unfortunately i have only used the 1.10.2 (i will try with earlier versions to confirm and post my findings).
For HTTP content i setup a localhost simple server that does JSON payload validation and payload logging.
I used it as the SDK Configuration#serverUrl and posted events to it.

mariusgherman · 2023-07-19T09:27:04Z

@Mercy811 i've just tried with SDK version 1.10.1. I'm not seeing anymore malformed events in the server logs.
However, i've set up a SDK Logger using Configuration#loggerProvider and i'm seeing a few error messages Error when upload event: End of input at character 0 of

Mercy811 · 2023-07-20T17:55:19Z

Hi @mariusgherman, thanks for your clarification and confirmation. I will investigate more.

Mercy811 · 2023-07-26T21:19:40Z

Hi @mariusgherman, would like to keep you updated. v1.20.2 starts migrating legacy data. So it’s likely that something wrong in this PR.

Error when upload event: End of input at character 0 of
It is probably caused by getEventsString returning an invalid JSON string.

Thanks for the info you provided. They really help me narrow the bug down. I will continue working on this.

Mercy811 · 2023-07-26T22:26:50Z

@mariusgherman Did you use the legacy SDK on the same device?

justin-fiedler · 2023-07-27T16:00:03Z

Hi @mariusgherman is it possible you are creating/using multiple instances of the Amplitude()? We noticed the event_id's are out of order 69,37,70,38 which makes us think there could be 2 instances of Amplitude sharing the same storage.

mariusgherman · 2023-07-27T17:01:42Z

@mariusgherman Did you use the legacy SDK on the same device?

we are in the process of upgrading our amplitude legacy SDK to the kotlin SDK, so yes, this will be the production use case indeed

mariusgherman · 2023-07-27T17:02:28Z

Hi @mariusgherman is it possible you are creating/using multiple instances of the Amplitude()? We noticed the event_id's are out of order 69,37,70,38 which makes us think there could be 2 instances of Amplitude sharing the same storage.

Not the case. We are ensuring that we have a single instance of Amplitude though usage of Dagger injection scoping.Could it be the case that we are logging multiple events at the same time from different threads ?

justin-fiedler · 2023-07-28T18:06:17Z

Thanks @mariusgherman.

logging multiple events at the same time from different threads

I don't think this is the case the provided output. A single instance should maintain a single "latestEvenId" that is used to increate the event_id's. So I think in the multithread case both would read the same value latestEvenId, and the last set lastEventId would win vs having multiple intermixed eventIds.

We noticed each pair has the same event_type, event_properties, timestamp (+/- 1 millisecond), new library, etc - except insert_id. I think, it is highly unlikely that events 37, 38, 40 were migrated from old SDK - in this case they would have legacy library and old timestamps.

Can you please share the Dagger configuration you are using to enforce the single instance of Amplitude?

We also notice a difference in casing (Screen Name/ Screen name) in event_properties for events 72/40, maybe that can help locate where each is being tracked.

mariusgherman · 2023-07-28T18:56:16Z

@justin-fiedler
these are the relevant files where we have declared the analytics instance and the dagger module where we provide the Amplitude single instance wrapper

class AmplitudeAnalyticsProvider(
    context: Context,
    private val amplitudeConfigProvider: AmplitudeConfigProvider,
    coroutineDispatcher: CoroutineDispatcher
) {
    private val coroutineScope = CoroutineScope(coroutineDispatcher + SupervisorJob())
    private val coroutineExceptionHandler = CoroutineExceptionHandler { _, throwable ->
        Log.w("Amplitude Config", "Failed to configure device id for amplitude analytics", throwable)
    }

    internal val amplitudeClient by lazy {
        Amplitude(
            Configuration(
                context = context.applicationContext,
                apiKey = amplitudeConfigProvider.getKeyValue(),
                serverUrl = amplitudeConfigProvider.getServerUrl(),
                trackingSessionEvents = true,
                defaultTracking = DefaultTrackingOptions.ALL,
                loggerProvider = object : LoggerProvider {
                    override fun getLogger(amplitude: com.amplitude.core.Amplitude): Logger =
                        AmplitudeLogger(if (BuildConfig.DEBUG) Logger.LogMode.DEBUG else Logger.LogMode.INFO)
                }
            )
        )
    }

    fun initialize() {
        coroutineScope.launch(coroutineExceptionHandler) {
            val deviceId = amplitudeConfigProvider.getDeviceId()
            amplitudeClient.setDeviceId(deviceId)
        }
    }

    fun reset() {
        amplitudeClient.reset()
    }

    fun setUserId(userId: String?) {
        amplitudeClient.setUserId(userId)
    }

    fun identify(userProperties: Map<String, Any?>) {
        amplitudeClient.identify(userProperties)
    }

    fun setGroup(groupType: String, groupName: String, groupProperties: Map<String, Any?> = mutableMapOf()) {
        amplitudeClient.groupIdentify(groupType, groupName, groupProperties)
    }
}

class AmplitudeLogger(override var logMode: Logger.LogMode) : Logger {
    override fun debug(message: String) {
        Log.d(TAG, message)
    }

    override fun error(message: String) {
        Log.e(TAG, message)
    }

    override fun info(message: String) {
        Log.i(TAG, message)
    }

    override fun warn(message: String) {
        Log.w(TAG, message)
    }  
}

@Module
class AnalyticsModule {

    @ApplicationScope
    @Provides
    fun providesAmplitudeAnalyticsProvider(
        context: Context,
        amplitudeConfigProvider: AmplitudeConfigProvider,
        coroutineDispatcher: Dispatchers.Default
    ): AmplitudeAnalyticsProvider {
        return AmplitudeAnalyticsProvider(context, amplitudeConfigProvider, coroutineDispatcher)
    }
    ...
}

justin-fiedler · 2023-07-31T17:50:58Z

Thanks @mariusgherman, could you add some logging to confirm that only a single instance is created?

internal val amplitudeClient by lazy {
        // LOG 1
        Amplitude(
            Configuration(
                context = context.applicationContext,
                apiKey = amplitudeConfigProvider.getKeyValue(),
                serverUrl = amplitudeConfigProvider.getServerUrl(),
                trackingSessionEvents = true,
                defaultTracking = DefaultTrackingOptions.ALL,
                loggerProvider = object : LoggerProvider {
                    override fun getLogger(amplitude: com.amplitude.core.Amplitude): Logger =
                        AmplitudeLogger(if (BuildConfig.DEBUG) Logger.LogMode.DEBUG else Logger.LogMode.INFO)
                }
            )
        )
    }

    @ApplicationScope
    @Provides
    fun providesAmplitudeAnalyticsProvider(
        context: Context,
        amplitudeConfigProvider: AmplitudeConfigProvider,
        coroutineDispatcher: Dispatchers.Default
    ): AmplitudeAnalyticsProvider {
        // LOG 2
        return AmplitudeAnalyticsProvider(context, amplitudeConfigProvider, coroutineDispatcher)
    }

mariusgherman · 2023-08-08T11:18:38Z

@justin-fiedler sorry for the late reply
so the code looks now like this

class AmplitudeAnalyticsProvider(
    context: Context,
    private val amplitudeConfigProvider: AmplitudeConfigProvider,
    coroutineDispatcher: CoroutineDispatcher
) {
    private val coroutineScope = CoroutineScope(coroutineDispatcher + SupervisorJob())
    private val coroutineExceptionHandler = CoroutineExceptionHandler { _, throwable ->
        Log.w("Amplitude Config", "Failed to configure device id for amplitude analytics", throwable)
    }

    init {
        Log.w("AMPLITUDE_TAG", "Wrapper instance init hashcode ${[email protected]()}")
    }

    internal val amplitudeClient by lazy {
        Log.w("AMPLITUDE_TAG", "Wrapper instance lazy hashcode ${[email protected]()}")
        val client = Amplitude(
            Configuration(
                context = context.applicationContext,
                apiKey = amplitudeConfigProvider.getKeyValue(),
                trackingSessionEvents = true,
                defaultTracking = DefaultTrackingOptions.ALL,
                loggerProvider = object : LoggerProvider {
                    override fun getLogger(amplitude: Amplitude): Logger =
                        AmplitudeLogger(if (BuildConfig.DEBUG) Logger.LogMode.DEBUG else Logger.LogMode.INFO)
                }
            )
        )
        client
    }

@ApplicationScope
    @Provides
    fun providesAmplitudeAnalyticsProvider(
        context: Context,
        amplitudeConfigProvider: AmplitudeConfigProvider,
        coroutineDispatcher: Dispatchers.Default
    ): AmplitudeAnalyticsProvider {
        val amplitudeAnalyticsProvider = AmplitudeAnalyticsProvider(context, amplitudeConfigProvider, coroutineDispatcher)
        Log.w("AMPLITUDE_TAG", "Wrapper instance dagger hashcode ${amplitudeAnalyticsProvider.hashCode()}")
        return amplitudeAnalyticsProvider
    }

and here is the logcat output

ajay-nagarajan · 2023-11-03T02:04:20Z

Hey @justin-fiedler @yuhao900914 @Mercy811 Are there any updates regarding this. I'm facing this issue on 1.10.4 as well and it is impacting our customers.
I don't see any updates on the release notes regarding this fix either.
Will updating the SDK help with this issue?

ajay-nagarajan · 2023-11-03T02:10:40Z

Alternatively it would be great if we could have an option in the SDK to ignore very old events or even clear the old events from the system. If there already is, could you please let me know, it would be greatly appreciated

izaaz · 2024-08-08T23:40:32Z

@ajay-nagarajan this issue is fixed in our newer SDK versions. We validate the data to make sure its a valid json before we send it over to Amplitude. So this should no longer be happening.

izaaz closed this as completed Aug 8, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Malformed Event(s) JSON using 1.10.2 SDK #134

Malformed Event(s) JSON using 1.10.2 SDK #134

mariusgherman commented Jul 12, 2023 •

edited

Loading

yuhao900914 commented Jul 14, 2023

Mercy811 commented Jul 18, 2023

mariusgherman commented Jul 19, 2023

mariusgherman commented Jul 19, 2023

Mercy811 commented Jul 20, 2023

Mercy811 commented Jul 26, 2023

Mercy811 commented Jul 26, 2023

justin-fiedler commented Jul 27, 2023

mariusgherman commented Jul 27, 2023 •

edited

Loading

mariusgherman commented Jul 27, 2023 •

edited

Loading

justin-fiedler commented Jul 28, 2023

mariusgherman commented Jul 28, 2023

justin-fiedler commented Jul 31, 2023

mariusgherman commented Aug 8, 2023

ajay-nagarajan commented Nov 3, 2023

ajay-nagarajan commented Nov 3, 2023

izaaz commented Aug 8, 2024

Malformed Event(s) JSON using 1.10.2 SDK #134

Malformed Event(s) JSON using 1.10.2 SDK #134

Comments

mariusgherman commented Jul 12, 2023 • edited Loading

Expected Behavior

Current Behavior

Possible Solution

Steps to Reproduce

Environment

yuhao900914 commented Jul 14, 2023

Mercy811 commented Jul 18, 2023

mariusgherman commented Jul 19, 2023

mariusgherman commented Jul 19, 2023

Mercy811 commented Jul 20, 2023

Mercy811 commented Jul 26, 2023

Mercy811 commented Jul 26, 2023

justin-fiedler commented Jul 27, 2023

mariusgherman commented Jul 27, 2023 • edited Loading

mariusgherman commented Jul 27, 2023 • edited Loading

justin-fiedler commented Jul 28, 2023

mariusgherman commented Jul 28, 2023

justin-fiedler commented Jul 31, 2023

mariusgherman commented Aug 8, 2023

ajay-nagarajan commented Nov 3, 2023

ajay-nagarajan commented Nov 3, 2023

izaaz commented Aug 8, 2024

mariusgherman commented Jul 12, 2023 •

edited

Loading

mariusgherman commented Jul 27, 2023 •

edited

Loading

mariusgherman commented Jul 27, 2023 •

edited

Loading