BrowserLogin i loop

[BjornGrylls]

Hej
Du burde nok flytte browserLogin ud af det loop den er i. Den laver en session for hver uge man vil hente. Lectio er ikke fan af at man logger ind 25 gange på under et sekund.

[soeren-b-c]

@BjornGrylls Tak for tippet - det vil jeg kigge på.

I øvrigt, ren nysgerrighed... hvad har fået dig til at kigge på koden her? Bruger du det selv, eller bare tilfældighedernes spil?

[BjornGrylls]

Lyder godt. Jeg har prøvet, men de Node js promises driller. Jeg har aldrig brugt Node js eller Puppeteer før.

Jeg ville hoste det selv på Heroku, men det har vist sig mere vanskeligt end som så. Btw tak for at dele koden ;)

[soeren-b-c]

@BjornGrylls Velbekomme.

Jeg lover intet, men hvis du deler dine fejlmeddelelser vil jeg gerne forsøge at kigge på det. (Jeg har dog aldrig brug Heroku.) Opret evt. et nyt Issue.

[BjornGrylls]

Logs ved 25 loginforsøg / sekundet:

2020-09-08T09:15:30.321728+00:00 heroku[router]: sock=backend at=error code=H18 desc="Server Request Interrupted" method=GET path="/?skole=575&elev=43439479846&uger=25" host=lectio2ics-service.herokuapp.com request_id=061e7712-6543-4d79-a607-9baf6399965c fwd="185.22.75.1" dyno=web.1 connect=1ms service=653ms status=503 bytes= protocol=https
2020-09-08T09:15:30.312459+00:00 app[web.1]: events.js:292
2020-09-08T09:15:30.312467+00:00 app[web.1]: throw er; // Unhandled 'error' event
2020-09-08T09:15:30.312468+00:00 app[web.1]: ^
2020-09-08T09:15:30.312468+00:00 app[web.1]:
2020-09-08T09:15:30.312469+00:00 app[web.1]: Error: read ENOTCONN
2020-09-08T09:15:30.312469+00:00 app[web.1]: at tryReadStart (net.js:573:20)
2020-09-08T09:15:30.312470+00:00 app[web.1]: at Socket._read (net.js:584:5)
2020-09-08T09:15:30.312470+00:00 app[web.1]: at Socket.Readable.read (_stream_readable.js:467:10)
2020-09-08T09:15:30.312471+00:00 app[web.1]: at Socket.read (net.js:624:39)
2020-09-08T09:15:30.312471+00:00 app[web.1]: at new Socket (net.js:376:12)
2020-09-08T09:15:30.312472+00:00 app[web.1]: at Object.Socket (net.js:267:41)
2020-09-08T09:15:30.312472+00:00 app[web.1]: at createSocket (internal/child_process.js:314:14)
2020-09-08T09:15:30.312472+00:00 app[web.1]: at ChildProcess.spawn (internal/child_process.js:437:23)
2020-09-08T09:15:30.312473+00:00 app[web.1]: at Object.spawn (child_process.js:548:9)
2020-09-08T09:15:30.312473+00:00 app[web.1]: at Launcher.launch (/app/node_modules/puppeteer/lib/Launcher.js:126:40)
2020-09-08T09:15:30.312474+00:00 app[web.1]: Emitted 'error' event on Socket instance at:
2020-09-08T09:15:30.312474+00:00 app[web.1]: at emitErrorNT (internal/streams/destroy.js:92:8)
2020-09-08T09:15:30.312474+00:00 app[web.1]: at emitErrorAndCloseNT (internal/streams/destroy.js:60:3)
2020-09-08T09:15:30.312475+00:00 app[web.1]: at processTicksAndRejections (internal/process/task_queues.js:84:21) {
2020-09-08T09:15:30.312475+00:00 app[web.1]: errno: 'ENOTCONN',
2020-09-08T09:15:30.312476+00:00 app[web.1]: code: 'ENOTCONN',
2020-09-08T09:15:30.312476+00:00 app[web.1]: syscall: 'read'
2020-09-08T09:15:30.312476+00:00 app[web.1]: }
2020-09-08T09:15:30.326491+00:00 app[web.1]: npm ERR! code ELIFECYCLE
2020-09-08T09:15:30.326742+00:00 app[web.1]: npm ERR! errno 1
2020-09-08T09:15:30.329398+00:00 app[web.1]: npm ERR! node-lectio@1.2.0 start: NODE_ENV=production node -r reify node-lectio.js
2020-09-08T09:15:30.329500+00:00 app[web.1]: npm ERR! Exit status 1
2020-09-08T09:15:30.329653+00:00 app[web.1]: npm ERR!
2020-09-08T09:15:30.329758+00:00 app[web.1]: npm ERR! Failed at the node-lectio@1.2.0 start script.
2020-09-08T09:15:30.329846+00:00 app[web.1]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
2020-09-08T09:15:30.348259+00:00 app[web.1]:
2020-09-08T09:15:30.348900+00:00 app[web.1]: npm ERR! A complete log of this run can be found in:
2020-09-08T09:15:30.349109+00:00 app[web.1]: npm ERR! /app/.npm/_logs/2020-09-08T09_15_30_331Z-debug.log

Ligger på https://lectio2ics-service.herokuapp.com/?skole=575&elev=43439479846&uger=25 men du burde få samme resultat hvis du kører den lokalt.

[soeren-b-c]

@BjornGrylls

Opklarende spørgsmål:

• Du skriver "ved 25 loginforsøg / sekund". Skal det forstå sådan at du sagtens kan få det til at fungere ved bare at hente en enkelt persons skema for en enkelt uge, men når du skalerer op, så går det i stykker?
• Må jeg se indholdet af /app/.npm/_logs/2020-09-08T09_15_30_331Z-debug.log

[BjornGrylls]

@soeren-b-c

• Korrekt. Hvis jeg ikke bruger "uger" variablen i URL'en så henter den nuværende og næste uges skema. Men allerede ved 5 uger så dør den.

node-lectio.js:

    if (String(typeof qs.uger) == 'undefined') {
      var amount = 2;
    }
    else {
      var amount = Number(qs.uger);
    }

qs = query string.

• Jeg kan tilgå en bash konsol til appen, men mappen "app" findes ikke:
  

[soeren-b-c]

Jeg henter uden problemer 10 uger når jeg bruger scriptet, så der er nok en flaskehals et sted i dit setup.
(Alternativt har du som elev væsentligt mere i dit skema på en uge, end jeg har som lærer, og det er der skoen trykker.)

Bemærk / i starten af adressen til den logfil jeg spørger til.

Prøv evt.

cd /app/.npm/_logs/
less 2020-09-08T09_15_30_331Z-debug.log

[BjornGrylls]

Den kan være fordi den er for langsom. Når puppeteer lukker browseren så kan de resterende promises ikke forbinde?
Logs ved 4 uger:

2020-09-09T18:12:29.578623+00:00 heroku[web.1]: Starting process with command npm start
2020-09-09T18:12:31.530209+00:00 app[web.1]:
2020-09-09T18:12:31.530229+00:00 app[web.1]: > node-lectio@1.2.0 start /app
2020-09-09T18:12:31.530230+00:00 app[web.1]: > NODE_ENV=production node -r reify node-lectio.js
2020-09-09T18:12:31.530230+00:00 app[web.1]:
2020-09-09T18:12:31.816047+00:00 app[web.1]: Listening on 56236
2020-09-09T18:12:32.286932+00:00 heroku[web.1]: State changed from starting to up
2020-09-09T18:12:34.457024+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx
2020-09-09T18:12:34.516226+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx
2020-09-09T18:12:34.519662+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx
2020-09-09T18:12:34.522768+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx
2020-09-09T18:12:35.684839+00:00 app[web.1]: $Typing username in #username
2020-09-09T18:12:35.728186+00:00 app[web.1]: Typing password
2020-09-09T18:12:35.778854+00:00 app[web.1]: Clicking button
2020-09-09T18:12:36.174349+00:00 app[web.1]: $Typing username in #username
2020-09-09T18:12:36.175412+00:00 app[web.1]: $Typing username in #username
2020-09-09T18:12:36.207686+00:00 app[web.1]: $Typing username in #username
2020-09-09T18:12:36.226083+00:00 app[web.1]: Typing password
2020-09-09T18:12:36.231054+00:00 app[web.1]: Typing password
2020-09-09T18:12:36.264303+00:00 app[web.1]: Typing password
2020-09-09T18:12:36.279348+00:00 app[web.1]: Clicking button
2020-09-09T18:12:36.281851+00:00 app[web.1]: Clicking button
2020-09-09T18:12:36.318025+00:00 app[web.1]: Clicking button
2020-09-09T18:12:38.207645+00:00 app[web.1]: Button clicked
2020-09-09T18:12:38.275909+00:00 app[web.1]: Button clicked
2020-09-09T18:12:38.387347+00:00 app[web.1]: Fetching https://www.lectio.dk/lectio/575/SkemaNy.aspx?type=elev&elevid=43439479846&week=382020
2020-09-09T18:12:38.390585+00:00 app[web.1]: Fetching https://www.lectio.dk/lectio/575/SkemaNy.aspx?type=elev&elevid=43439479846&week=402020
2020-09-09T18:12:39.255483+00:00 app[web.1]: Button clicked
2020-09-09T18:12:39.292822+00:00 app[web.1]: Button clicked
2020-09-09T18:12:39.486994+00:00 app[web.1]: Stopping browser…
2020-09-09T18:12:39.516641+00:00 app[web.1]: Task complete.
2020-09-09T18:12:39.681855+00:00 app[web.1]: Stopping browser…
2020-09-09T18:12:39.715234+00:00 app[web.1]: Task complete.
2020-09-09T18:13:34.741342+00:00 heroku[router]: at=error code=H15 desc="Idle connection" method=GET path="/?skole=575&elev=43439479846&uger=4" host=lectio2ics-service.herokuapp.com request_id=11906fac-6459-4b2c-b358-4b2cf9acb298 fwd="212.98.73.119" dyno=web.1 connect=0ms service=60667ms status=503 bytes= protocol=https

Den sender uge 38 og 40, men resten dukker aldrig op (da puppteer er lukket) og den timer ud.

Desværre heller ikke.