[Erledigt] NumberFormatException beim initialen Abruf PayPal-API

[torfbolt]

Hallo,

ich habe letzte Woche das Scripting Projekt entdeckt und die Release3 per plugin-manager installiert. DKB Visa funktioniert einwandfrei, aber bei PayPal kann ich keine Daten abrufen.
Getestete Versionen:
Mashup 0.7.7 und 0.7.8,
Hibiscus 2.6.15
Jameica Version: 2.6.2
SWT-Version: 4427 / gtk
Java-Version: 1.8.0_77 / Linux amd64
System: Debian GNU/Linux testing (stretch)

API Account und Passwort scheinen OK zu sein, der Login klappt. Aber immer am Ende des Abrufs versucht er irgendwo einen DateTime string in eine Zahl zu konvertieren. Ist auch unabhängig vom eingestellten Zeitfenster (getestet mit 100h, 1000h, 10000h).

Error Log:

Code: Alles auswählen

[Mon Apr 25 22:00:52 CEST 2016][INFO][de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run] BEGIN synchronization of account 1/1
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync] Installierte und aktive PlugIn-Versionen: [Finance.Websync ver. 0.7.7 - Build 95] [Hibiscus Mashup ver. 0.7.7 Build 83]
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:JavaCheck] Überprüfe Java-Version und den verwendeten Zeichensatz ...
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:JavaCheck] Java-Version 1.8.0_77 von 'Oracle Corporation' installiert, aktiv und verwendet Zeichensatz 'UTF-8'
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:HTMLUnitVersionCheck] Überprüfe HTMLUnit-Version ...
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:HTMLUnitVersionCheck] OK: HTMLUnit-Version 2.21 installiert und aktiv
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync] processing non-HBCI (Hibiscus Mashup) jobs
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute] Synchronisierung der 'Umsätze' gestartet für und mit Backend: non-HBCI (Hibiscus Mashup)
[Mon Apr 25 22:00:52 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute] Synchronisiere 'Umsätze' mit Institut und Umsetzung für: PayPal Pte. Ltd.
[Mon Apr 25 22:00:53 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:WebClientInit] Verbindung vorbereitet
[Mon Apr 25 22:00:53 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.interact.ApiAuth.Login] Passwort für Anmeldekennung mail******* wird abgefragt ...
[Mon Apr 25 22:00:54 CEST 2016][INFO][de.willuhn.jameica.services.UpdateService$Worker.run] check for updates needed?
[Mon Apr 25 22:00:54 CEST 2016][INFO][de.willuhn.jameica.services.UpdateService$Worker.run] no, last check: Mon Apr 25 21:58:23 CEST 2016, next check: Mon May 02 21:58:23 CEST 2016
[Mon Apr 25 22:10:28 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run] Rufe API-URLs auf und starte Aufbau des Kontoauszuges ...
[Mon Apr 25 22:10:28 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.interact.DataWorker.checkFromDate] Sie benutzen dieses Konto das erste Mal in Hibiscus oder der Saldo und das Datum wurden zurückgesetzt ...
[Mon Apr 25 22:10:28 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.interact.DataWorker.checkFromDate] ... es werden daher nun alle möglichen Umsätze abgerufen ...
[Mon Apr 25 22:10:28 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] API-Saldoabruf ... (GET Encoded: https://api-3t.paypal.com/nvp?USER=*******&PWD=*******&SIGNATURE=*******&VERSION=124&METHOD=GetBalance)
[Mon Apr 25 22:10:47 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] API-Transaktionsabruf ... (GET Encoded: https://api-3t.paypal.com/nvp?USER=*******&PWD=*******&SIGNATURE=*******&VERSION=124&METHOD=TransactionSearch&STARTDATE=2014-4-25T22:0:0Z&ENDDATE=2015-6-16T14:0:0Z)
[Mon Apr 25 22:10:47 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] Abrufzeitraum: von 25.04.2014 10:00:00 MESZ  bis  16.06.2015 02:00:00 MESZ
[Mon Apr 25 22:11:02 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] API-Transaktionsabruf ... (GET Encoded: https://api-3t.paypal.com/nvp?USER=*******&PWD=*******&SIGNATURE=*******&VERSION=124&METHOD=TransactionSearch&STARTDATE=2015-6-16T14:0:0Z&ENDDATE=2016-4-25T22:10:28Z)
[Mon Apr 25 22:11:02 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] Abrufzeitraum: von 16.06.2015 02:00:00 MESZ  bis  25.04.2016 10:10:28 MESZ
[Mon Apr 25 22:11:15 CEST 2016][INFO][org.apache.http.impl.execchain.RetryExec.execute] I/O exception (java.net.SocketException) caught when processing request to {s}->https://api-3t.paypal.com:443: Connection reset
[Mon Apr 25 22:11:15 CEST 2016][INFO][org.apache.http.impl.execchain.RetryExec.execute] Retrying request to {s}->https://api-3t.paypal.com:443
[Mon Apr 25 22:11:34 CEST 2016][ERROR][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.error] [WebSync:PayPal] Exception beim Abrufen der Kontoumsätze:
java.lang.NumberFormatException: For input string: "2016-04-24T13:29:37Z"
	at sun.misc.FloatingDecimal.readJavaFormatString(FloatingDecimal.java:2043)
	at sun.misc.FloatingDecimal.parseDouble(FloatingDecimal.java:110)
	at java.lang.Double.parseDouble(Double.java:538)
	at de.derrichter.finance.websync.institute.paypal.ApiPull.getTransData(ApiPull.java:462)
	at de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run(ApiRunner.java:180)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute(WebSynchronizeJobUmsaetze.java:75)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync(WebSynchronizeBackend.java:288)
	at de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run(AbstractSynchronizeBackend.java:388)
	at de.willuhn.jameica.gui.GUI$6.run(GUI.java:976)

[Mon Apr 25 22:11:34 CEST 2016][ERROR][de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run] Exception mit Stacktrace:
java.lang.Exception: Exception beim Abrufen der Kontoumsätze: For input string: "2016-04-24T13:29:37Z"
	at de.derrichter.finance.websync.institute.paypal.ApiPull.getTransData(ApiPull.java:1246)
	at de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run(ApiRunner.java:180)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute(WebSynchronizeJobUmsaetze.java:75)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync(WebSynchronizeBackend.java:288)
	at de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run(AbstractSynchronizeBackend.java:388)
	at de.willuhn.jameica.gui.GUI$6.run(GUI.java:976)

[Mon Apr 25 22:11:34 CEST 2016][ERROR][de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute] Fehlermeldung/Exception des Systems:
de.willuhn.util.ApplicationException: Exception beim Abrufen der Kontoumsätze: For input string: "2016-04-24T13:29:37Z"
	at de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run(ApiRunner.java:206)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute(WebSynchronizeJobUmsaetze.java:75)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync(WebSynchronizeBackend.java:288)
	at de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run(AbstractSynchronizeBackend.java:388)
	at de.willuhn.jameica.gui.GUI$6.run(GUI.java:976)

[Mon Apr 25 22:11:34 CEST 2016][INFO][de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.updateStatus] updating synchronization status to: ERROR
[Mon Apr 25 22:11:34 CEST 2016][INFO][de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run] stopping synchronization
[Mon Apr 25 22:11:34 CEST 2016][INFO][de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run] finished
[Mon Apr 25 22:11:34 CEST 2016][INFO][de.willuhn.jameica.hbci.messaging.SyncEngineStatusMessageConsumer$1.run] Reloading start view
[Mon Apr 25 22:12:04 CEST 2016][INFO][de.willuhn.jameica.gui.internal.parts.BackgroundTaskMonitor$1$1.run] auto closing monitor snapin

By the way: Gibt es eigentlich den Sourcecode irgendwo als repository? Dann hätte ich nämlich zuerst mal selbst den Fehler weiter eingegrenzt...

[Hibiscus-Scripter]

hmm also eigentlich würde ich nun um eine TRACE-Log per PM fragen ;) aber bei dir wurde offensichtlich mitten im Abruf die Verbindung unterbrochen

[Mon Apr 25 22:11:02 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] Abrufzeitraum: von 16.06.2015 02:00:00 MESZ bis 25.04.2016 10:10:28 MESZ
[Mon Apr 25 22:11:15 CEST 2016][INFO][org.apache.http.impl.execchain.RetryExec.execute] I/O exception (java.net.SocketException) caught when processing request to {s}->https://api-3t.paypal.com:443: Connection reset

was natürlich falsche Daten liefert ...
denn es wäre schon verdammt ungewöhnlich dass du nun einen anderen Datenaufbau erhältst als alle anderen ...
Kannst du das noch wo anders prüfen?


Das mit dem SourceCode hatten wir schon mal: kurze Antwort nein. Zudem hab ich unabhängig davon mit "eigenen" Fehleranalysen bisher leider überwiegend negative Erfahrungen gemacht (hat ja nix mit dir zu tun ;) ) da meist das Hintergrundwissen über lange Zeit und somit die Zusammenhänge aller Variationen fehlt ...

Gruß

[torfbolt]

Nope, das ist es leider nicht. Der retry hat damals offensichtlich funktioniert, denn er liefert die gleichen Daten und den gleichen Bug wie jedes mal. Hier zum Vergleich ein log von gerade eben:

Code: Alles auswählen

[Tue May 03 00:53:37 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run] Rufe API-URLs auf und starte Aufbau des Kontoauszuges ...
[Tue May 03 00:53:37 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.interact.DataWorker.checkFromDate] Sie benutzen dieses Konto das erste Mal in Hibiscus oder der Saldo und das Datum wurden zurückgesetzt ...
[Tue May 03 00:53:37 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.interact.DataWorker.checkFromDate] ... es werden daher nun alle möglichen Umsätze abgerufen ...
[Tue May 03 00:53:37 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] API-Saldoabruf ... (GET Encoded: https://api-3t.paypal.com/nvp?USER=*******&PWD=*******&SIGNATURE=*******&VERSION=124&METHOD=GetBalance)
[Tue May 03 00:53:38 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] API-Transaktionsabruf ... (GET Encoded: https://api-3t.paypal.com/nvp?USER=*******&PWD=*******&SIGNATURE=*******&VERSION=124&METHOD=TransactionSearch&STARTDATE=2014-5-3T22:0:0Z&ENDDATE=2015-6-24T14:0:0Z)
[Tue May 03 00:53:38 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] Abrufzeitraum: von 03.05.2014 10:00:00 MESZ  bis  24.06.2015 02:00:00 MESZ
[Tue May 03 00:53:43 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] API-Transaktionsabruf ... (GET Encoded: https://api-3t.paypal.com/nvp?USER=*******&PWD=*******&SIGNATURE=*******&VERSION=124&METHOD=TransactionSearch&STARTDATE=2015-6-24T14:0:0Z&ENDDATE=2016-5-3T0:53:37Z)
[Tue May 03 00:53:43 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.info] [WebSync:PayPal] Abrufzeitraum: von 24.06.2015 02:00:00 MESZ  bis  03.05.2016 12:53:37 MESZ
[Tue May 03 00:53:50 CEST 2016][ERROR][de.derrichter.hibiscus.mashup.crossover.callback.WebLogger.error] [WebSync:PayPal] Exception beim Abrufen der Kontoumsätze:
java.lang.NumberFormatException: For input string: "2016-04-24T13:29:37Z"
	at sun.misc.FloatingDecimal.readJavaFormatString(FloatingDecimal.java:2043)
	at sun.misc.FloatingDecimal.parseDouble(FloatingDecimal.java:110)
	at java.lang.Double.parseDouble(Double.java:538)
	at de.derrichter.finance.websync.institute.paypal.ApiPull.getTransData(ApiPull.java:462)
	at de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run(ApiRunner.java:180)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute(WebSynchronizeJobUmsaetze.java:75)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync(WebSynchronizeBackend.java:288)
	at de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run(AbstractSynchronizeBackend.java:388)
	at de.willuhn.jameica.gui.GUI$6.run(GUI.java:976)

[Tue May 03 00:53:50 CEST 2016][INFO][de.derrichter.hibiscus.mashup.crossover.interact.ApiAuth.ResetPassword] Passwort-Reset der API-Authentifizierung zur Anmeldekennung mail*******
[Tue May 03 00:53:50 CEST 2016][ERROR][de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run] Exception mit Stacktrace:
java.lang.Exception: Exception beim Abrufen der Kontoumsätze: For input string: "2016-04-24T13:29:37Z"
	at de.derrichter.finance.websync.institute.paypal.ApiPull.getTransData(ApiPull.java:1246)
	at de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run(ApiRunner.java:180)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute(WebSynchronizeJobUmsaetze.java:75)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync(WebSynchronizeBackend.java:288)
	at de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run(AbstractSynchronizeBackend.java:388)
	at de.willuhn.jameica.gui.GUI$6.run(GUI.java:976)

[Tue May 03 00:53:50 CEST 2016][ERROR][de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute] Fehlermeldung/Exception des Systems:
de.willuhn.util.ApplicationException: Exception beim Abrufen der Kontoumsätze: For input string: "2016-04-24T13:29:37Z"
	at de.derrichter.hibiscus.mashup.crossover.websync.institute.paypal.ApiRunner.run(ApiRunner.java:206)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeJobUmsaetze.execute(WebSynchronizeJobUmsaetze.java:75)
	at de.derrichter.hibiscus.mashup.crossover.websync.WebSynchronizeBackend$WebSyncJobGroup.sync(WebSynchronizeBackend.java:288)
	at de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run(AbstractSynchronizeBackend.java:388)
	at de.willuhn.jameica.gui.GUI$6.run(GUI.java:976)

[Tue May 03 00:53:50 CEST 2016][INFO][de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.updateStatus] updating synchronization status to: ERROR
[Tue May 03 00:53:50 CEST 2016][INFO][de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run] stopping synchronization
[Tue May 03 00:53:50 CEST 2016][INFO][de.willuhn.jameica.hbci.messaging.SyncEngineStatusMessageConsumer$1.run] Reloading start view
[Tue May 03 00:53:51 CEST 2016][INFO][de.willuhn.jameica.hbci.synchronize.AbstractSynchronizeBackend$Worker.run] finished

Sieht ganz so aus als hätte ich in meinen Transaktionen irgendeinen Datensatz, den der websync parser nicht mag.

Zum debugging: Ich weiss gut, dass Architekturüberblick und eigener Code da extrem weiterhelfen. Trotzdem glaube ich, dass eine "personal code" Lizenz bei den meisten Softwareprojekten auf lange Sicht nicht zur Vergrösserung der Entwicklerzahl und damit Fortbestand des Projekts beiträgt. Aber das kann je nach Umfeld auch anders sein und ist natürlich persönliche Entscheidungsfreiheit.

VG David

[Hibiscus-Scripter]

hmm, anschauen kann ichs mir ja mal ...

Installiere bitte die aktuelle Nightly-Build von finance.websync und schicke mir dann das TRACE-Log per PM
(Erklärung dazu, gibts in den Regeln)

[torfbolt]

Nightly-build hat nicht funktioniert, aber ich hab's mir nochmal selbst angeschaut und ich glaube ich hab das Problem gefunden:

Das besondere an meinem Paypal Abruf ist Transaktion Nr. 35 (Auszug aus meinem log vom 4.5.):

Code: Alles auswählen

DataMessage:
...L_TYPE35=Recurring Payment
...L_STATUS35=Created
...L_AMT33=-15.12&L_AMT34=15.12&L_AMT36=-17.96&L_AMT37=17.96
...

Auffällig ist, dass z.B. L_AMT35 und L_NETAMT35 fehlen. Wenn man sich den Code vom Parser anschaut wird klar, warum er dann versucht einen datestring als float zu parsen (aus getTransData()):

Code: Alles auswählen

...
int NettoStart = DataMessage.indexOf("L_NETAMT" + l + "=");
NettoStart = DataMessage.indexOf("=", NettoStart) + 1;
int NettoEnd = DataMessage.indexOf("&", NettoStart);
Netto = DataMessage.substring(NettoStart, NettoEnd);

NettoStart wird -1, dann sucht er das erste =, findet eines am Start von DataMessage (nach "L_TIMESTAMP0") und stopft den datestring in die Variable Netto.

Und hier crashed es dann:

Code: Alles auswählen

prevNetto = StringUtils.MathRound((double)Double.parseDouble(Netto), (int)2);

[Hibiscus-Scripter]

Da waren ganz andere Dinge zum beachten drin ...
Wie wär's einfach mit ner vollständigen "aktuellen" Trace-Log mit der "aktuellesten" Nightly-Build?

[torfbolt]

Ok, mit dem 0.7.9-nightly hat es heute funktioniert, danke. Gestern (auch 0.7.9-nightly) hatte ich den Fehler noch, seltsam.

Naja, hauptsache es tut jetzt.